Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use fsinfo for cockpit.file.watch() #20017

Open
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

jelly
Copy link
Member

@jelly jelly commented Feb 13, 2024

@jelly jelly added the no-test For doc/workflow changes, or experiments which don't need a full CI run, label Feb 13, 2024
@jelly jelly force-pushed the cockpit-file-rewrite branch 2 times, most recently from b14f6cf to 249966d Compare February 13, 2024 19:22
@jelly jelly force-pushed the cockpit-file-rewrite branch 2 times, most recently from 86d9139 to 018fe63 Compare February 19, 2024 08:58
pkg/lib/cockpit.js Outdated Show resolved Hide resolved
@jelly jelly removed the no-test For doc/workflow changes, or experiments which don't need a full CI run, label Feb 19, 2024
@jelly
Copy link
Member Author

jelly commented Feb 19, 2024

TestPages.testFrameReload and TestMultiMachine.testFrameReload fail due to a difference of handling a non-existent file.

[jelle@t14s][~/projects/cockpit/main]%cpf open fsread1 path=/tmp/counter  | cockpit-bridge
963

{
  "capabilities": {
    "explicit-superuser": true
  },
  "command": "init",
  "os-release": {
    "NAME": "Arch Linux",
    "PRETTY_NAME": "Arch Linux",
    "ID": "arch",
    "BUILD_ID": "rolling",
    "ANSI_COLOR": "38;2;23;147;209",
    "HOME_URL": "https://archlinux.org/",
    "DOCUMENTATION_URL": "https://wiki.archlinux.org/",
    "SUPPORT_URL": "https://bbs.archlinux.org/",
    "BUG_REPORT_URL": "https://gitlab.archlinux.org/groups/archlinux/-/issues",
    "PRIVACY_POLICY_URL": "https://terms.archlinux.org/docs/privacy-policy/",
    "LOGO": "archlinux-logo"
  },
  "version": 1,
  "packages": {
    "apps": null,
    "base1": null,
    "playground": null,
    "users": null,
    "metrics": null,
    "system": null,
    "static": null,
    "network": null,
    "shell": null,
    "storage": null,
    "kdump": null,
    "updates": null,
    "sosreport": null,
    "iframewalk": null,
    "machines": null,
    "podman": null,
    "pcp": null
  }
}
45

{
  "channel": "ch1",
  "command": "done"
}
60

{
  "tag": "-",
  "command": "close",
  "channel": "ch1"
}

Versus:

[jelle@t14s][~/projects/cockpit/main]%cpf fsinfo /tmp/counter tag  : wait | cockpit-bridge
963

{
  "capabilities": {
    "explicit-superuser": true
  },
  "command": "init",
  "os-release": {
    "NAME": "Arch Linux",
    "PRETTY_NAME": "Arch Linux",
    "ID": "arch",
    "BUILD_ID": "rolling",
    "ANSI_COLOR": "38;2;23;147;209",
    "HOME_URL": "https://archlinux.org/",
    "DOCUMENTATION_URL": "https://wiki.archlinux.org/",
    "SUPPORT_URL": "https://bbs.archlinux.org/",
    "BUG_REPORT_URL": "https://gitlab.archlinux.org/groups/archlinux/-/issues",
    "PRIVACY_POLICY_URL": "https://terms.archlinux.org/docs/privacy-policy/",
    "LOGO": "archlinux-logo"
  },
  "version": 1,
  "packages": {
    "apps": null,
    "base1": null,
    "playground": null,
    "users": null,
    "metrics": null,
    "system": null,
    "static": null,
    "network": null,
    "shell": null,
    "storage": null,
    "kdump": null,
    "updates": null,
    "sosreport": null,
    "iframewalk": null,
    "machines": null,
    "podman": null,
    "pcp": null
  }
}
46

{
  "channel": "ch1",
  "command": "ready"
}
119
ch1
{
  "error": {
    "problem": "not-found",
    "message": "No such file or directory",
    "errno": "ENOENT"
  }
}

return self;
}

import cockpit from "./cockpit.js";
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Uh. That's unusual.

Please explain. :)

If having this at the end of the file is the full extent of your "ugly hack" then I could probably be convinced to live with it... but how does it work?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Soo I looked up some examples of folks trying to get around circular imports and it seems that loaders/import logic ignores imports at the end as cyclic. Possibly as the bundler first combines everything into one file? Either way this is a hack and we should resolve it.

I just didn't feel like doing a big bang rename of cockpit.js to cockpit.ts and merging the typing navigator? Let's discuss how we intend to integrate this all.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For the record: we can rename pkg/lib/cockpit.js to cockpit.ts with absolutely no other changes and nothing bad seems to happen.

Then we could just add this there...

Note: one thing that I didn't check is to do the rename and then to try to use cockpit from a TS-using project (like navigator) which carries its own cockpit.d.ts file. I wonder if that would make tsc get angry...

@jelly jelly marked this pull request as ready for review February 20, 2024 14:07
@jelly
Copy link
Member Author

jelly commented Feb 20, 2024

@martinpitt There are two open issues in this PR for which I'd like your opinion on:

  • Providing fsinfo in Cockpit, the current split out file relies on a hack by importing cockpit.js as last line, so we don't run into a circular import situation. Options are:

    • Move it untyped in cockpit.js
    • Convert cockpit.js to cockpit.ts and move it in there
    • Keep the hack around
  • fsinfo API, having a separate file in pkg/lib basically means we have declared the fsinfo api "stable". Can we live with that or do we want to hide it for now. Also we have a copy in navigator:

    • Keep it separate, but note that it's private
    • Put it into Cockpit.js and don't expose it, downside is that we have a copy in navigator

Ideally cockpit.file would get a cockpit.file.info which is our new fsinfo channel high level wrapper. I think this is a great idea, but I don't want to work on that now. After all I was only interested in fixing #19983 not exposing fsinfo in general :)

Also there was talk about fsinfo reading small files, possibly a great addition for cockpit.file.watch() like for watching /etc/hostname or crypto policies. So maybe we should wait on that first before declaring public.

Copy link
Member

@martinpitt martinpitt left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks! Some minor cleanups, but this is nice enough to land it even with the import hack IMHO.

Wrt. your questions above:

  • I don't like moving it here untyped, that feels like a step backwards. My preferred route would be to land this PR, then send a new one which renames cockpit.js to cockpit.ts (which according to Lis should be fine, except that we need to install and integrate tsc of course). Then you can re-integrate fsinfo.ts, or rearrange things differently to not require circular imports (but the latter is a huge task, let's not do that now).

  • I'm fine with declaring fsinfo "stable" now, but @allisonkarlitskaya is the one who has the last word on that. However, I don't see how that needs to be done for this PR -- all that it does is to move cockpit.file().watch() over to it, and we can adjust that in the future if necessary.

  • Agreed that cockpit.file().info() would be nice as next step, but not a blocker for navigator I think.

pkg/base1/test-file.js Outdated Show resolved Hide resolved
pkg/base1/test-file.js Outdated Show resolved Hide resolved
pkg/base1/test-file.js Outdated Show resolved Hide resolved
pkg/lib/cockpit-fsinfo.ts Show resolved Hide resolved
pkg/lib/cockpit.js Outdated Show resolved Hide resolved
@jelly
Copy link
Member Author

jelly commented Feb 21, 2024

Thanks! Some minor cleanups, but this is nice enough to land it even with the import hack IMHO.

Wrt. your questions above:

* I don't like moving it here untyped, that feels like a step backwards. My preferred route would be to land this PR, then send a new one which renames cockpit.js to cockpit.ts (which according to Lis should be fine, except that we need to install and integrate `tsc` of course). Then you can re-integrate fsinfo.ts, or rearrange things differently to not require circular imports (but the latter is a huge task, let's not do that now).

This was also my idea more of less. Plus at least typing the basics of Cockpit maybe with any?

* I'm fine with declaring fsinfo "stable" now, but @allisonkarlitskaya is the one who has the last word on that. However, I don't see how that needs to be done for this PR -- all that it does is to move `cockpit.file().watch()` over to it, and we can adjust that in the future if necessary.

Well it does make a pkg/lib/cockpit-fsinfo.ts so one could see that as "stable".

* Agreed that cockpit.file().info() would be nice as next step, but not a blocker for navigator I think.

👍

For now in navigator we vendor fsinfo.ts, but yeah we should declare this properly and write user docs, QUnit tests. All at least some work.

@martinpitt
Copy link
Member

Well it does make a pkg/lib/cockpit-fsinfo.ts so one could see that as "stable".

You mean because projects grab a particular SHA of pkg/lib, and if we change the bridge it would break. That's a good point. So if we do that, the bridge fsinfo channel needs to remain backwards compatible at least for the (rather limited) API that cockpit.file.watch() uses -- i.e. .effect(), state.info and so on.

So one thing about this: .effect() is really weird. The usual API is to have something like watch_channel.addEventListener("changed", state => {....}), or perhaps "event" or so. That's actually something I'd

@allisonkarlitskaya
Copy link
Member

Thanks! Some minor cleanups, but this is nice enough to land it even with the import hack IMHO.

I agree with everything in this comment, including "next steps".

For now in navigator we vendor fsinfo.ts

Can't vendor it if it isn't "upstream" yet 😅

martinpitt
martinpitt previously approved these changes Feb 21, 2024
Copy link
Member

@martinpitt martinpitt left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cheers!

const watch = file.watch((content, tag) => {
assert.equal(content, null, "non-existant because read is false");
assert.notEqual(tag, null, "non empty tag");
assert.equal(tag.startsWith("1:"), true, "tag always stars with 1:");
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

starts ⭐

@jelly
Copy link
Member Author

jelly commented Feb 22, 2024

I can't get testExpire to ever pass, I think it's due to the passwd -S flood

rhel4edge, fcos

@jelly
Copy link
Member Author

jelly commented Feb 26, 2024

testExpire is a legit issue, with limited access we don't fire a callback so getLogins does not seem to be called.

@jelly
Copy link
Member Author

jelly commented Feb 28, 2024

Blocked as we get an error now and close the channel when you are in limited access and try to watch /etc/shadow, potential fix:

so in filesystem.py line ~502 i'd try changing if err is None to if fd is not None and see what happens. depending on how /etc/shadow is updated (trunc vs. atomic) it may or may not work

@jelly jelly added the no-test For doc/workflow changes, or experiments which don't need a full CI run, label Mar 14, 2024
@jelly
Copy link
Member Author

jelly commented Mar 21, 2024

Only OSTree based images have a suspicious issue, where the accounts page does not load when we initially login and go to /users/#newuser. Pressing F5 makes the page load.

Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.SubprocessTransport object at 0x7f10757ea150> <cockpit.channels.stream.SubprocessStreamChannel object at 0x7f10756d98e0> 23
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   got EOF
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: sending control message None {'channel': '1:2!5', 'command': 'done'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.router-DEBUG: shutdown_endpoint(<cockpit.channels.stream.SubprocessStreamChannel object at 0x7f10756d98e0>, {}) will close {'1:2!5'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: sending control message {'exit-status': 0, 'message': ''} {'command': 'close', 'channel': '1:2!5'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.router-DEBUG: router dropped channel 1:2!5
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: won't attempt 15 to process 2356.  It exited already.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _got_data(b'\x00', [20, 22, 26])
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _invoke_command(bytearray(b'\nWe trust you have received the usual lecture from the local System\nAdministrator. It usually boils down to these three things:\n\n    #>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f1075648ad0> <cockpit.bridge.Bridge object at 0x7f10769d8d70> 0
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 1311 bytes
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 24013}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 24013}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 24013}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 24013}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 24013}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 97 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'call': ['/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', 'Subscribe', []], 'id': '3'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 119 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'call': ['/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', 'LoadUnit', ['insights-client.timer']], 'id': '4'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 136 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'call': ['/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', 'LoadUnit', ['dbus-org.freedesktop.timedate1.service']], 'id': >
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 123 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'call': ['/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', 'LoadUnit', ['systemd-timesyncd.service']], 'id': '6'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 113 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'call': ['/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', 'LoadUnit', ['chronyd.service']], 'id': '7'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 111 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'call': ['/org/freedesktop/systemd1', 'org.freedesktop.systemd1.Manager', 'LoadUnit', ['tuned.service']], 'id': '8'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 67 bytes of data for channel 1:4!1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request None {'add-match': {'path': '/superuser', 'interface': 'cockpit.Superuser'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 73 bytes of data for channel 1:4!1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request None {'watch': {'path': '/superuser', 'interface': 'cockpit.Superuser'}, 'id': '14'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 99 bytes of data for channel 1:4!1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request None {'type': 's', 'call': ['/user', 'org.freedesktop.DBus.Properties', 'GetAll', ['cockpit.User']], 'id': '15'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call None /superuser org.freedesktop.DBus.Introspectable Introspect  ()
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: run_command(ferny.askpass, (['/usr/libexec/cockpit-askpass', '[sudo] password for scruffy: '], {'SHELL': '/bin/bash', 'EDITOR': '/usr/bin/nano', 'PWD': '/var/home/scr>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: We trust you have received the usual lecture from the local System
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: Administrator. It usually boils down to these three things:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:     #1) Respect the privacy of others.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:     #2) Think before you type.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:     #3) With great power comes great responsibility.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: For security reasons, the password you type will not be visible.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: )
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _askpass_command((['/usr/libexec/cockpit-askpass', '[sudo] password for scruffy: '], {'SHELL': '/bin/bash', 'EDITOR': '/usr/bin/nano', 'PWD': '/var/home/scruffy', 'LO>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: We trust you have received the usual lecture from the local System
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: Administrator. It usually boils down to these three things:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:     #1) Respect the privacy of others.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:     #2) Think before you type.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:     #3) With great power comes great responsibility.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: For security reasons, the password you type will not be visible.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]:
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: )
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: do_askpass('\nWe trust you have received the usual lecture from the local System\nAdministrator. It usually boils down to these three things:\n\n    #1) Respect the p>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: sending control message None {'command': 'authorize', 'challenge': 'plain1:73637275666679', 'cookie': 'f2f68e61-e298-430c-b442-e9036fc44817'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: Doing introspection request for org.freedesktop.systemd1.Manager LoadUnit
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: Doing introspection request for org.freedesktop.systemd1.Manager LoadUnit
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: Doing introspection request for org.freedesktop.systemd1.Manager LoadUnit
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: Doing introspection request for org.freedesktop.systemd1.Manager LoadUnit
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: Doing introspection request for org.freedesktop.systemd1.Manager LoadUnit
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/superuser', 'interface': 'cockpit.Superuser'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call None /superuser org.freedesktop.DBus.Properties GetAll s ('cockpit.Superuser',)
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f1075648ad0> <cockpit.bridge.Bridge object at 0x7f10769d8d70> 0
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 95 bytes
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: transport control received {'command': 'authorize', 'cookie': 'f2f68e61-e298-430c-b442-e9036fc44817', 'response': 'foobar'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: do_askpass answer 'foobar'
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: <cockpit.superuser.AuthorizeResponder object at 0x7f107678f620> completed cleanly
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _consider_completion(<cockpit._vendor.ferny.interaction_agent.InteractionAgent object at 0x7f10758ab800>)
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG:   but not ready yet
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call None /superuser org.freedesktop.DBus.Introspectable Introspect  ()
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f1075648ad0> <cockpit.bridge.Bridge object at 0x7f10769d8d70> 0
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 558 bytes
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 125 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/insights_2dclient_2etimer', 'interface': 'org.freedesktop.systemd1.Unit'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 131 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/insights_2dclient_2etimer', 'interface': 'org.freedesktop.systemd1.Unit'}, 'id': '10'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 128 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/insights_2dclient_2etimer', 'interface': 'org.freedesktop.systemd1.Service'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 134 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/insights_2dclient_2etimer', 'interface': 'org.freedesktop.systemd1.Service'}, 'id': '12>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/insights_2dclient_2etimer', 'interface': 'org.freedesktop.systemd1.Unit'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/insights_2dclient_2etimer org.freedesktop.DBus.Introspectable Introspect  ()
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/insights_2dclient_2etimer', 'interface': 'org.freedesktop.systemd1.Service'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call None /superuser org.freedesktop.DBus.Properties GetAll s ('cockpit.Superuser',)
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f1075648ad0> <cockpit.bridge.Bridge object at 0x7f10769d8d70> 0
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 2192 bytes
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 129 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 135 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}, 'id': '1>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 132 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 138 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}, 'id':>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 129 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 135 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}, 'id': '1>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 132 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 138 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}, 'id':>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 117 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/chronyd_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 123 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/chronyd_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}, 'id': '22'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 120 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/chronyd_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 126 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/chronyd_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}, 'id': '24'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 115 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/tuned_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 121 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/tuned_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}, 'id': '26'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 118 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'add-match': {'path': '/org/freedesktop/systemd1/unit/tuned_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 124 bytes of data for channel 1:4!3
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request org.freedesktop.systemd1 {'watch': {'path': '/org/freedesktop/systemd1/unit/tuned_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}, 'id': '28'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/chronyd_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/chronyd_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/tuned_2eservice', 'interface': 'org.freedesktop.systemd1.Unit'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: adding match {'path': '/org/freedesktop/systemd1/unit/tuned_2eservice', 'interface': 'org.freedesktop.systemd1.Service'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/insights_2dclient_2etimer org.freedesktop.DBus.Properties GetAll s ('org.freedesktop.system>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: sending control message None {'channel': '1:4!3', 'command': 'ping', 'sequence': 42468}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/insights_2dclient_2etimer org.freedesktop.DBus.Introspectable Introspect  ()
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/insights_2dclient_2etimer org.freedesktop.DBus.Properties GetAll s ('org.freedesktop.system>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call None /superuser org.freedesktop.DBus.Introspectable Introspect  ()
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: got match
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f1075648ad0> <cockpit.bridge.Bridge object at 0x7f10769d8d70> 0
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 364 bytes
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 42468}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 42468}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 42468}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 42468}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: channel control received {'channel': '1:4!3', 'command': 'pong', 'sequence': 42468}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 70 bytes of data for channel 1:4!1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request None {'call': ['/LoginMessages', 'cockpit.LoginMessages', 'Get', []], 'id': '16'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice org.freedesktop.DBus.Introspectable Introspect  ()
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call None /superuser org.freedesktop.DBus.Properties GetAll s ('cockpit.Superuser',)
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: won't attempt 15 to process 2356.  It exited already.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: won't attempt 15 to process 2358.  It exited already.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: won't attempt 15 to process 2359.  It exited already.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/systemd_2dtimedated_2eservice org.freedesktop.DBus.Properties GetAll s ('org.freedesktop.sy>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 sudo[2346]:  scruffy : user NOT in sudoers ; PWD=/var/home/scruffy ; USER=root ; COMMAND=/usr/bin/cockpit-bridge --privileged
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.systemd_ctypes.bus-DEBUG: Doing async method call org.freedesktop.systemd1 /org/freedesktop/systemd1/unit/systemd_2dtimesyncd_2eservice org.freedesktop.DBus.Properties GetAll s ('org.freedesktop.sy>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _got_data(b'scruffy is not in the sudoers file.\n', [])
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.SubprocessTransport object at 0x7f107551b550> <cockpit.superuser.SuperuserPeer object at 0x7f10765463f0> 19
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   got EOF
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.peer-DEBUG: Peer SuperuserPeer received unexpected EOF
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Process exited with status 1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.peer-DEBUG: Peer SuperuserPeer exited, status 1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: connection_lost
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: won't attempt 15 to process 2346.  It exited already.
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.peer-DEBUG: Peer SuperuserPeer connection lost <class 'cockpit.peer.PeerExited'> 1
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.router-DEBUG: shutdown_endpoint(<cockpit.superuser.SuperuserPeer object at 0x7f10765463f0>, {'problem': 'terminated', 'message': 'Peer exited with status 1'}) will close {'1:4!7', '1:4!8', '1:2!2', '1:3!4'>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: sending control message None {'command': 'close', 'channel': '1:4!7', 'problem': 'terminated', 'message': 'Peer exited with status 1'}
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f1075648ad0>
Mar 21 17:02:35 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.router-DEBUG: router dropped channel 1:4!7

So this seems to be fatal?

More interesting obversations:

Mar 21 17:23:40 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f5b06801c90> <cockpit.bridge.Bridge object at 0x7f5b0768f050> 0
Mar 21 17:23:40 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 147 bytes
Mar 21 17:23:40 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 136 bytes of data for channel 1:3!31
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.StdioTransport object at 0x7f5b06801c90> <cockpit.bridge.Bridge object at 0x7f5b0768f050> 0
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   read 79 bytes
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: data received: 72 bytes of data for channel 1:7
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: receive dbus request None {'call': ['/superuser', 'cockpit.Superuser', 'Answer', ['foobar']], 'id': '5'}
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.channels.dbus-DEBUG: Doing introspection request for cockpit.Superuser Answer
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.superuser-DEBUG: responding to pending prompt
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: do_askpass answer 'foobar'
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: writing to transport <cockpit.transports.StdioTransport object at 0x7f5b06801c90>
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: <cockpit.superuser.SuperuserRoutingRule object at 0x7f5b06d023c0> completed cleanly
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _consider_completion(<cockpit._vendor.ferny.interaction_agent.InteractionAgent object at 0x7f5b06553f20>)
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG:   but not ready yet
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 audit[2905]: USER_AUTH pid=2905 uid=1002 auid=1002 ses=12 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:authentication grantors=pam_usertype,pam_localuser,pam_unix acct="scruffy" exe="/usr/bin/sudo">
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 audit[2905]: USER_ACCT pid=2905 uid=1002 auid=1002 ses=12 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:accounting grantors=pam_unix,pam_localuser acct="scruffy" exe="/usr/bin/sudo" hostname=? addr=>
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 audit[2905]: USER_CMD pid=2905 uid=1002 auid=1002 ses=12 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='cwd="/var/home/scruffy" cmd=636F636B7069742D627269646765202D2D70726976696C65676564 exe="/usr/bin/sudo">
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 sudo[2905]:  scruffy : user NOT in sudoers ; PWD=/var/home/scruffy ; USER=root ; COMMAND=/usr/bin/cockpit-bridge --privileged
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _got_data(b'scruffy is not in the sudoers file.\n', [])
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _got_data(b'', [])
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _result(<cockpit._vendor.ferny.interaction_agent.InteractionAgent object at 0x7f5b06553f20>, 'scruffy is not in the sudoers file.\n')
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG:   remove_reader(<socket.socket fd=17, family=1, type=1, proto=0>)
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG:   closing sockets
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG: _consider_completion(<cockpit._vendor.ferny.interaction_agent.InteractionAgent object at 0x7f5b06553f20>)
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit._vendor.ferny.interaction_agent-DEBUG:   submitting stderr ('scruffy is not in the sudoers file.\n') to completion_future
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Read ready on <cockpit.transports.SubprocessTransport object at 0x7f5b065e17d0> <cockpit.superuser.SuperuserPeer object at 0x7f5b06553ef0> 21
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG:   got EOF
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.peer-DEBUG: Peer SuperuserPeer received unexpected EOF
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: Process exited with status 1
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.peer-DEBUG: Peer SuperuserPeer exited, status 1
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.protocol-DEBUG: connection_lost
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.transports-DEBUG: won't attempt 15 to process 2905.  It exited already.
Mar 21 17:23:41 fedora-coreos-127-0-0-2-2301 ws[2270]: cockpit.peer-DEBUG: Peer SuperuserPeer connection lost <class 'cockpit.peer.PeerExited'> 1

SO HAH!

It seems that the first time we login we get a sudo lecture and this somehow fails the bridge, the second time we get no lecture and all is good.

@jelly
Copy link
Member Author

jelly commented Mar 21, 2024

So with the sudo lecture theory, I removed all the state in /var/db/sudo/lectured/* and then can't reproduce it again. Which is rather strange but then again this is coreos.

@jelly jelly removed needswork no-test For doc/workflow changes, or experiments which don't need a full CI run, labels Mar 22, 2024
@jelly
Copy link
Member Author

jelly commented Mar 22, 2024

Adding a close eventlistener and when it first on first load we get close events:

log: fsinfo {}
log: close fsinfo {"isTrusted":"false","detail":"Object","type":"close","target":"null","currentTarget":"null"} {"command":"close","channel":"1:3!57"}
log: base_channel {"superuser":"try","binary":"true"}
log: fsinfo {}
log: close fsinfo {"isTrusted":"false","detail":"Object","type":"close","target":"null","currentTarget":"null"} {"command":"close","channel":"1:3!107"}
log: base_channel {"superuser":"try","binary":"true"}
log: fsinfo {}
log: close fsinfo {"isTrusted":"false","detail":"Object","type":"close","target":"null","currentTarget":"null"} {"command":"close","channel":"1:3!155"}
log: base_channel {"superuser":"try","binary":"true"}
log: fsinfo {}
log: close fsinfo {"isTrusted":"false","detail":"Object","type":"close","target":"null","currentTarget":"null"} {"command":"close","channel":"1:3!160"}
log: base_channel {"superuser":"try","binary":"true"}
log: fsinfo {}
log: close fsinfo {"isTrusted":"false","detail":"Object","type":"close","target":"null","currentTarget":"null"} {"command":"close","channel":"1:3!167"}
log: base_channel {"superuser":"try","binary":"true"}
log: fsinfo {}
log: close fsinfo {"isTrusted":"false","detail":"Object","type":"close","target":"null","currentTarget":"null"} {"command":"close","channel":"1:3!217"}
log: base_channel {"superuser":"try","binary":"true"}
log: fsinfo {}

On refresh we get zero close events.

By using the new fsinfo channel fswatch1 can now read the tag without
reading the file when adding a new watch. As side-effect this no longer
reads the full file when `{ read: false }` is passed to `watch()`.

Closes: cockpit-project#19983

Co-Authored-By: Allison Karlitskaya <allison.karlitskaya@redhat.com>
@allisonkarlitskaya
Copy link
Member

I think I'd like to see a new test for anything that uses this. The expiry test is an obvious choice since it's already causing us all this trouble... The test should establish the watch when logged in as the superuser and then de-authenticate. That will break the watch, which ought to be reestablished at that point.

This will involve implementing handling of the channel closing unexpectedly.

@jelly
Copy link
Member Author

jelly commented Apr 4, 2024

I think I'd like to see a new test for anything that uses this. The expiry test is an obvious choice since it's already causing us all this trouble... The test should establish the watch when logged in as the superuser and then de-authenticate. That will break the watch, which ought to be reestablished at that point.

This will involve implementing handling of the channel closing unexpectedly.

This feels like new behavior to me, I can imagine we should do this but this feels like (another) follow up.

Copy link
Member

@allisonkarlitskaya allisonkarlitskaya left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This feels like new behavior to me, I can imagine we should do this but this feels like (another) follow up.

I mean, the entire thing is new behaviour, right?

You took some quick-and-dirty stuff I wrote for the purpose of one specific semi-experimental use-case in an unreleased piece of software (cockpit-files) and are importing it into cockpit now. The standard is definitely going to be higher...

There are definitely unanswered questions here, and top among them (and a point I've raised more than a couple of times) is the need to handle the channel closing...

I wrote the original code there and I'm happy to help with robustifying it, but we definitely still have some things to think through. We managed to "fix" the tests here hard enough that everything goes green, but did we even try running tests against all the other projects?

Copy link
Member

@martinpitt martinpitt left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I generally like this change, especially the .ts introduction. But it still needs a few cleanups. Thanks!

pkg/lib/cockpit-fsinfo.ts Show resolved Hide resolved
channel.close();
}

function effect(callback: (state: FileInfoState) => void) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I won't fight very hard for this, but at least a little: Let's please not call this effect(), it's super confusing as an API. The standard JS approach is to make this an EventTarget and attach a changed or similar event handler to it.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

My 2¢:

  • I hate the event mixin API
  • we have a lot of other areas in cockpit.js which implement their own callback list mechanism. We even have helper functions for it.
  • The name effect() is definitely suspect, as is the very react-flavoured API (returning the unregister callable).
  • Maybe we should change it anyway, just for uniformity with everything else in cockpit.js...

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we have a lot of other areas in cockpit.js which implement their own callback list mechanism

Yeah, but I wouldn't exactly call cockpit.js a role model for good/modern JS. It is really bad from today's POV, it was created pre-ES5 even, with jquery.

Copy link
Member Author

@jelly jelly Apr 5, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So this seems to be the only real blocker? I am happy to rewrite .effect into something else the question is.. what is a Modern JS API :)

(I am kinda inclined to make it like cockpit.js)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But should we then just move this into cockpit? The issue is kinda how we then expose fsinfo, cockpit.file.info?

self.login_and_go("/users", user="scruffy")
self.login_and_go("/users", user="scruffy", superuser=False)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This should be a separate commit with an explanation. It took you so long to figure out, let's please explain it in the commit message for our future selves 😁

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't like this change -at all-, and I absolutely veto it. It might be right for this test, but we're doing this to cover up a bug. At the same time, I agree that it's not directly related to this particular test scenario.

My proposal: in the same commit that "fixes" this testcase, we introduce a separate test case which tests this. I'm happy to have it marked as an xfail at first with a link to #20263 and (maybe or maybe not) #20262.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm happy to add an expected failing test, I assume you mean integration not pytest?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants