canonical / checkbox

Checkbox is a testing framework used to validate device compatibility with Ubuntu Linux. It’s the testing tool developed for the purposes of the Ubuntu Certification program.
https://checkbox.readthedocs.io
GNU General Public License v3.0
33 stars 50 forks source link

post-warm-reboot and post-cold-reboot tests are failing due to snap.checkbox.agent.service #1402

Open Sahanaaks opened 3 months ago

Sahanaaks commented 3 months ago

Bug Description

power-management/post-warm-reboot and power-management/post-cold-reboot are failing as after the warm/coldboot test

To Reproduce

To Reproduce Install Checkbox via the following commands $ sudo snap install checkbox22 $ sudo snap install checkbox --classic

Run "power-management/post-warm-reboot" and "power-management/post-cold-reboot" job via the following steps:

$ checkbox.checkbox-cli

Environment

OS: 24.04 Ubuntu Desktop Checkbox Type: Snap Checkbox version :: 4.1.0.dev25

Relevant log output

Found 1 failed units

Failed units:
  UNIT                        LOAD   ACTIVE SUB    DESCRIPTION
● snap.checkbox.agent.service loaded failed failed Service for snap application checkbox.agent

Legend: LOAD   → Reflects whether the unit definition was properly loaded.
        ACTIVE → The high-level unit activation state, i.e. generalization of SUB.
        SUB    → The low-level unit activation state, values depend on unit type.

1 loaded units listed.

Logs for snap.checkbox.agent.service:
Aug 07 09:20:35 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:36 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 5.
Aug 07 09:20:36 ubuntu systemd[1]: Started snap.checkbox.agent.service - Service for snap application checkbox.agent.
Aug 07 09:20:37 ubuntu checkbox.agent[2226]: $PROVIDERPATH is defined, so following provider sources are ignored ['/root/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
Aug 07 09:20:37 ubuntu sudo[2249]:     root : PWD=/var/snap/checkbox/7792 ; USER=root ; COMMAND=/usr/bin/true
Aug 07 09:20:37 ubuntu sudo[2249]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 07 09:20:37 ubuntu sudo[2249]: pam_unix(sudo:session): session closed for user root
Aug 07 09:20:37 ubuntu checkbox.agent[2226]: Found port 18871 is open. Is Checkbox agent already running?
Aug 07 09:20:37 ubuntu systemd[1]: snap.checkbox.agent.service: Main process exited, code=exited, status=1/FAILURE
Aug 07 09:20:37 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:38 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 6.
Aug 07 09:20:38 ubuntu systemd[1]: Started snap.checkbox.agent.service - Service for snap application checkbox.agent.
Aug 07 09:20:38 ubuntu checkbox.agent[2253]: $PROVIDERPATH is defined, so following provider sources are ignored ['/root/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
Aug 07 09:20:38 ubuntu sudo[2274]:     root : PWD=/var/snap/checkbox/7792 ; USER=root ; COMMAND=/usr/bin/true
Aug 07 09:20:38 ubuntu sudo[2274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 07 09:20:38 ubuntu sudo[2274]: pam_unix(sudo:session): session closed for user root
Aug 07 09:20:38 ubuntu checkbox.agent[2253]: Found port 18871 is open. Is Checkbox agent already running?
Aug 07 09:20:38 ubuntu systemd[1]: snap.checkbox.agent.service: Main process exited, code=exited, status=1/FAILURE
Aug 07 09:20:38 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:39 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 7.
Aug 07 09:20:39 ubuntu systemd[1]: Started snap.checkbox.agent.service - Service for snap application checkbox.agent.
Aug 07 09:20:40 ubuntu checkbox.agent[2278]: $PROVIDERPATH is defined, so following provider sources are ignored ['/root/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
Aug 07 09:20:40 ubuntu sudo[2298]:     root : PWD=/var/snap/checkbox/7792 ; USER=root ; COMMAND=/usr/bin/true
Aug 07 09:20:40 ubuntu sudo[2298]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 07 09:20:40 ubuntu sudo[2298]: pam_unix(sudo:session): session closed for user root
Aug 07 09:20:40 ubuntu checkbox.agent[2278]: Found port 18871 is open. Is Checkbox agent already running?
Aug 07 09:20:40 ubuntu systemd[1]: snap.checkbox.agent.service: Main process exited, code=exited, status=1/FAILURE
Aug 07 09:20:40 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:41 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 8.
Aug 07 09:20:41 ubuntu systemd[1]: Started snap.checkbox.agent.service - Service for snap application checkbox.agent.
Aug 07 09:20:42 ubuntu checkbox.agent[2303]: $PROVIDERPATH is defined, so following provider sources are ignored ['/root/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
Aug 07 09:20:42 ubuntu sudo[2324]:     root : PWD=/var/snap/checkbox/7792 ; USER=root ; COMMAND=/usr/bin/true
Aug 07 09:20:42 ubuntu sudo[2324]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 07 09:20:42 ubuntu sudo[2324]: pam_unix(sudo:session): session closed for user root
Aug 07 09:20:42 ubuntu checkbox.agent[2303]: Found port 18871 is open. Is Checkbox agent already running?
Aug 07 09:20:42 ubuntu systemd[1]: snap.checkbox.agent.service: Main process exited, code=exited, status=1/FAILURE
Aug 07 09:20:42 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:43 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 9.
Aug 07 09:20:43 ubuntu systemd[1]: Started snap.checkbox.agent.service - Service for snap application checkbox.agent.
Aug 07 09:20:44 ubuntu checkbox.agent[2328]: $PROVIDERPATH is defined, so following provider sources are ignored ['/root/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
Aug 07 09:20:44 ubuntu sudo[2350]:     root : PWD=/var/snap/checkbox/7792 ; USER=root ; COMMAND=/usr/bin/true
Aug 07 09:20:44 ubuntu sudo[2350]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Aug 07 09:20:44 ubuntu sudo[2350]: pam_unix(sudo:session): session closed for user root
Aug 07 09:20:44 ubuntu checkbox.agent[2328]: Found port 18871 is open. Is Checkbox agent already running?
Aug 07 09:20:44 ubuntu systemd[1]: snap.checkbox.agent.service: Main process exited, code=exited, status=1/FAILURE
Aug 07 09:20:44 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:45 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 10.
Aug 07 09:20:45 ubuntu systemd[1]: snap.checkbox.agent.service: Start request repeated too quickly.
Aug 07 09:20:45 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 07 09:20:45 ubuntu systemd[1]: Failed to start snap.checkbox.agent.service - Service for snap application checkbox.agent.

Additional context

Other Warm and Cold boot tests without post checks are passing fine on the same environment, the issue is with the post checking of the checkbox agent. Checkbox agent is active for a short duration even when you manually start the service. The status is shown as failed within few seconds.

root@ubuntu:/home/intel# sudo systemctl status snap.checkbox.agent.service
● snap.checkbox.agent.service - Service for snap application checkbox.agent
     Loaded: loaded (/etc/systemd/system/snap.checkbox.agent.service; enabled; preset: enabled)
     Active: active (running) since Thu 2024-08-08 10:14:14 UTC; 397ms ago
   Main PID: 3347 (python3)
      Tasks: 1 (limit: 37888)
     Memory: 23.3M (peak: 23.3M)
        CPU: 379ms
     CGroup: /system.slice/snap.checkbox.agent.service
             └─3347 python3 /snap/checkbox22/current/bin/checkbox-cli run-agent

Aug 08 10:14:14 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 4.
Aug 08 10:14:14 ubuntu systemd[1]: Started snap.checkbox.agent.service - Service for snap application checkbox.agent.
root@ubuntu:/home/intel# sudo systemctl status snap.checkbox.agent.service
× snap.checkbox.agent.service - Service for snap application checkbox.agent
     Loaded: loaded (/etc/systemd/system/snap.checkbox.agent.service; enabled; preset: enabled)
     Active: failed (Result: exit-code) since Thu 2024-08-08 10:14:16 UTC; 1s ago
   Duration: 704ms
    Process: 3347 ExecStart=/usr/bin/snap run checkbox.agent (code=exited, status=1/FAILURE)
   Main PID: 3347 (code=exited, status=1/FAILURE)
        CPU: 685ms

Aug 08 10:14:16 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 5.
Aug 08 10:14:16 ubuntu systemd[1]: snap.checkbox.agent.service: Start request repeated too quickly.
Aug 08 10:14:16 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 08 10:14:16 ubuntu systemd[1]: Failed to start snap.checkbox.agent.service - Service for snap application checkbox.agent.
root@ubuntu:/home/intel# sudo systemctl status snap.checkbox.agent.service
× snap.checkbox.agent.service - Service for snap application checkbox.agent
     Loaded: loaded (/etc/systemd/system/snap.checkbox.agent.service; enabled; preset: enabled)
     Active: failed (Result: exit-code) since Thu 2024-08-08 10:14:16 UTC; 3s ago
   Duration: 704ms
    Process: 3347 ExecStart=/usr/bin/snap run checkbox.agent (code=exited, status=1/FAILURE)
   Main PID: 3347 (code=exited, status=1/FAILURE)
        CPU: 685ms

Aug 08 10:14:16 ubuntu systemd[1]: snap.checkbox.agent.service: Scheduled restart job, restart counter is at 5.
Aug 08 10:14:16 ubuntu systemd[1]: snap.checkbox.agent.service: Start request repeated too quickly.
Aug 08 10:14:16 ubuntu systemd[1]: snap.checkbox.agent.service: Failed with result 'exit-code'.
Aug 08 10:14:16 ubuntu systemd[1]: Failed to start snap.checkbox.agent.service - Service for snap application checkbox.agent.
syncronize-issues-to-jira[bot] commented 3 months ago

Thank you for reporting us your feedback!

The internal ticket has been created: https://warthogs.atlassian.net/browse/CHECKBOX-1524.

This message was autogenerated

pieqq commented 3 months ago

Hello!

Can you provide the list of snaps running on this device? The output of snap list should be good enough.

Sahanaaks commented 3 months ago

Name Version Rev Tracking Publisher Notes bare 1.0 5 latest/stable canonical✓ base checkbox 4.0.0-dev333 7695 latest/stable ce-certification-qa classic checkbox22 4.0.0-dev333 1010 latest/stable ce-certification-qa - core22 20240408 1380 latest/stable canonical✓ base firefox 125.0.2-1 4173 latest/stable/… mozilla✓ - firmware-updater 0+git.5007558 127 latest/stable/… canonical✓ - gnome-42-2204 0+git.510a601 176 latest/stable/… canonical✓ - gtk-common-themes 0.1-81-g442e511 1535 latest/stable/… canonical✓ - snap-store 0+git.1419621 1124 latest/stable/… canonical✓ - snapd 2.63 21759 latest/stable canonical✓ snapd snapd-desktop-integration 0.9 157 latest/stable/… canonical✓ -

pieqq commented 3 months ago

The reason I asked your for the list of snaps is because I see this message in the systemd logs:

Aug 07 09:20:37 ubuntu checkbox.agent[2226]: Found port 18871 is open. Is Checkbox agent already running?

I was wondering if you had another version of Checkbox running as a snap.

Have you installed Checkbox as a Debian package in parallel of the snap version? Please check the output of dpkg -l | grep -i checkbox.

Usually, we see this message when Checkbox has been installed by two different methods, and one of the agent is tripping over the other.

Last option: you have something else on that system using port 18871...?

Sahanaaks commented 3 months ago

Hi Pierre,

You are correct, we faced issue with snap checkbox installation and had to do debian installation. On a different RVP with the same environment - with just the debian installation this bug is no longer seen. Thanks a lot for the input :)

Also, can you please suggest the stable installation method for canonical installation - snap or debian? In past, snap installation was suggested over debian - so we are using it.

Note that at with snap installation we saw tests gets struck at below stage:

========[ Running job 31 / 35. Estimated time left (at least): 0:08:02 ]======== --------------------------------[ Warm reboot ]--------------------------------- ID: com.canonical.certification::power-management/warm-reboot Category: com.canonical.plainbox::power-management Waiting for the system to shut down or reboot... Created symlink /etc/systemd/system/multi-user.target.wants/plainbox-autostart.service → /etc/systemd/system/plainbox-autostart.service. ... 8< ------------------------------------------------------------------------- dbus-send: /lib/x86_64-linux-gnu/libdbus-1.so.3: version `LIBDBUS_PRIVATE_1.12.20' not found (required by dbus-send) ------------------------------------------------------------------------- >8 ---

pieqq commented 2 months ago

Hello! Sorry for the late reply... see my answers below:

Hi Pierre,

You are correct, we faced issue with snap checkbox installation and had to do debian installation. On a different RVP with the same environment - with just the debian installation this bug is no longer seen. Thanks a lot for the input :)

Also, can you please suggest the stable installation method for canonical installation - snap or debian? In past, snap installation was suggested over debian - so we are using it.

We have a dedicated section in the Ubuntu Discourse to discuss about things related to Checkbox:

https://discourse.ubuntu.com/c/certification/checkbox/168

We post about new releases there, with some highlights on the new versions and some tips on how to run Checkbox. See for instance the last release notes for v4.1.0.

At that point, we recommend the snap version of Checkbox for most use cases. This is what we advertise in our tutorial, for instance.

Note that at with snap installation we saw tests gets struck at below stage:

========[ Running job 31 / 35. Estimated time left (at least): 0:08:02 ]======== --------------------------------[ Warm reboot ]--------------------------------- ID: com.canonical.certification::power-management/warm-reboot Category: com.canonical.plainbox::power-management Waiting for the system to shut down or reboot... Created symlink /etc/systemd/system/multi-user.target.wants/plainbox-autostart.service → /etc/systemd/system/plainbox-autostart.service. ... 8< ------------------------------------------------------------------------- dbus-send: /lib/x86_64-linux-gnu/libdbus-1.so.3: version `LIBDBUS_PRIVATE_1.12.20' not found (required by dbus-send) ------------------------------------------------------------------------- >8 ---

This is strange. If the DUT is running Ubuntu 24.04, could you install the checkbox24 snap instead of checkbox22 and see if you face the same issue or not?

Also, as I suggested in another issue, it's better to use Checkbox remote to run this kind of test:

  1. Install Checkbox on the DUT (the “agent”) and on another device, like your own laptop (that will be used as a “controller”)
  2. From the controller, launch Checkbox to control the agent with checkbox.checkbox-cli control <IP address of the agent>

You will then be able to select the test plan you want, but it will be run on the DUT while you are controlling it from your laptop. The log and output of each test cases will be shown on your laptop's screen, which helps reviewing or investigating as well.

Let me know if this works.