f40/firefox TestApps.testBasic often fails with: Could not determine kpatch packages: {}

[martinpitt]

This is #1 unexpected message on the weather report, and most PRs fail on it now, like this:

> warning: PackageKit went away during transaction /38_edbdebea : {"command":"close","channel":"1:5!5"}
> log: PackageKit went away from D-Bus
> log: PackageKit went away from D-Bus
> error: Could not determine kpatch packages: {}

> warning: can't remove watch: Invalid argument
can't remove watch: Invalid argument
can't add watch for <ctypes.c_char_Array_21 object at 0x7fc6f3dbb850>: Permission denied
can't add watch for <ctypes.c_char_Array_20 object at 0x7fc6f3dbb850>: Permission denied
Traceback (most recent call last):
  File "<string>", line 445, in <module>
  File "<string>", line 442, in watch_db
  File "<string>", line 156, in run
  File "<string>", line 72, in run
  File "<string>", line 68, in process
  File "<string>", line 155, in event
  File "<string>", line 128, in handler
  File "<string>", line 137, in reset
  File "<string>", line 148, in watch_directory
PermissionError: [Errno 13] Permission denied: '/usr/share/metainfo'

> warning: {"problem":null,"exit_status":1,"exit_signal":null,"message":"can't remove watch: Invalid argument\ncan't remove watch: Invalid argument\ncan't add watch for <ctypes.c_char_Array_21 object at 0x7fc6f3dbb850>: Permission denied\ncan't add watch for <ctypes.c_char_Array_20 object at 0x7fc6f3dbb850>: Permission denied\nTraceback (most recent call last):\n  File \"<string>\", line 445, in <module>\n  File \"<string>\", line 442, in watch_db\n  File \"<string>\", line 156, in run\n  File \"<string>\", line 72, in run\n  File \"<string>\", line 68, in process\n  File \"<string>\", line 155, in event\n  File \"<string>\", line 128, in handler\n  File \"<string>\", line 137, in reset\n  File \"<string>\", line 148, in watch_directory\nPermissionError: [Errno 13] Permission denied: '/usr/share/metainfo'"}
> log: PackageKit went away from D-Bus

So there are multiple issues here. Broken packagekit? Bridge inotify problem? And the broken error message. It really shouldn't be {}. We have other places where a "regular" error in our usual {problem: "blah", ...} form gets printed correctly.

I'll start with trying to reproduce this locally, or alternatively do an amplification PR with extra logging.

[martinpitt]

I've run

TEST_OS=fedora-40 TEST_BROWSER=firefox test/verify/check-apps TestApps.testBasic -stv $RUNC

in a loop, and so far haven't been able to reproduce. I also tried to run the previous tests in the same VM.

TEST_OS=fedora-40 TEST_BROWSER=firefox test/common/run-tests --test-dir test/verify TestMenu.testSessionTimeout TestApps.test{OsMap,Basic}

also works. So debugging on CI it is.

[martinpitt]

A successful run also shows all these PackageKit/watch errors, they are just because the page is still running when the nondestructive cleanup happens:

+ rm -rf /usr/share/metainfo; mv /var/lib/cockpittest/_usr_share_metainfo /usr/share/metainfo
+ mv /var/lib/cockpittest/_var_lib_PackageKit_transactions.db /var/lib/PackageKit/transactions.db
> warning: can't remove watch: Invalid argument
can't add watch for <ctypes.c_char_Array_21 object at 0x7f9aed107750>: Permission denied
can't add watch for <ctypes.c_char_Array_20 object at 0x7f9aed107750>: Permission denied
Traceback (most recent call last):
  File "<string>", line 445, in <module>
  File "<string>", line 442, in watch_db
  File "<string>", line 156, in run
  File "<string>", line 72, in run
  File "<string>", line 68, in process
  File "<string>", line 155, in event
  File "<string>", line 128, in handler
  File "<string>", line 137, in reset
  File "<string>", line 148, in watch_directory
PermissionError: [Errno 13] Permission denied: '/usr/share/metainfo'

so this is mostly us not stopping the cockpit session before restoring directories. But doesn't explain the empty error message. Debugging in #20448

[martinpitt]

A-ha! That's better. I have no idea why it's sometimes not logged correctly with the old code..

We could of course just paper over this by ignoring the message, but then we wouldn't know why it didn't work in an actual kpatch test. It would really be better to fix #20450 first, I'll take another stab at that.