** Description changed:
I'm getting the feeling that the error logging of `ssh-setup/nova` is
working inconsistently. Consider the following two log excerpts from one
of the autopkgtest-cloud-worker journals:
-
autopkgtest [22:23:29]: test launch-test:
preparing testbed
-
Waiting...
-
Creating nova instance
adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9
f
+
autopkgtest [22:23:29]: test launch-test: preparing testbed
+
Waiting...
+
Creating nova instance
adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9
f
rom image adt/ubuntu-lunar-s390x-server-20230103.img (UUID
2a986d1c-2fa0-4a0e-b9bc-2915b9deda73)...
-
Waiting...
-
Creating nova instance
adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9
f
+
Waiting...
+
Creating nova instance
adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9
f
rom image adt/ubuntu-lunar-s390x-server-20230103.img (UUID
2a986d1c-2fa0-4a0e-b9bc-2915b9deda73)...
-
Timed out waiting for ssh. Aborting! Console log:
-
------- nova console-log
8f057152-58df-4517-984b-4e8621df8424
(adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9)
------
+
Timed out waiting for ssh. Aborting! Console log:
+
------- nova console-log 8f057152-58df-4517-984b-4e8621df8424
(adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9)
------
+ Ubuntu Lunar Lobster (development branch) auto-syncubuntu-lunar-
+ daily-s390x-server-20221227-disk1 sclp_line0
-
Ubuntu Lunar Lobster (development branch)
auto-syncubuntu-lunar-daily-s390x-server-20221227-disk1 sclp_line0
-
-
auto-syncubuntu-lunar-daily-s390x-server-20221227-disk1 login:
-
---------------------------------------------------
-
------- nova show
8f057152-58df-4517-984b-4e8621df8424
(adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9)
------
+
auto-syncubuntu-lunar-daily-s390x-server-20221227-disk1 login:
+
---------------------------------------------------
+
------- nova show 8f057152-58df-4517-984b-4e8621df8424
(adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9)
------
In the above excerpt we can see "Timed out waiting for ssh" and then the
`nova show` and `nova console-log`. However, here we have very little
information about what went wrong:
-
autopkgtest [22:51:16]: test clone-reprepro:
preparing testbed
-
Waiting...
-
Creating nova instance
adt-jammy-s390x-dgit-20230104-215159-juju-4d1272-prod-proposed-migration-9 from
i
- mage adt/ubuntu-jammy-s390x-server-20230103.img (UUID
0a7a472d-9a85-43af-ab6b-26b50466bd6e)...
-
Waiting...
-
Creating nova instance
adt-jammy-s390x-dgit-20230104-215159-juju-4d1272-prod-proposed-migration-9 from
i
- mage adt/ubuntu-jammy-s390x-server-20230103.img (UUID
0a7a472d-9a85-43af-ab6b-26b50466bd6e)...
-
ERROR (CommandError): Unable to delete the
specified server(s).
-
Unexpected error:
-
Traceback (most recent call last):
-
File
"/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 740, in mainloop
-
command()
-
File
"/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 669, in command
-
r = f(c, ce)
-
File
"/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 302, in cmd_revert
-
caller.hook_revert()
-
File
"/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 444, in hook_revert
-
host_setup('revert')
-
File
"/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 263, in host_setup
-
execute_setup_script(command)
-
File
"/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 202, in
execute_setup_script
-
(status, out, err) =
VirtSubproc.execute_timeout(
-
File
"/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 144, in execute_timeout
-
(out, err) = sp.communicate(instr)
-
File "/usr/lib/python3.8/subprocess.py", line
1028, in communicate
-
stdout, stderr = self._communicate(input,
endtime, timeout)
-
File "/usr/lib/python3.8/subprocess.py", line
1868, in _communicate
-
ready = selector.select(timeout)
-
File "/usr/lib/python3.8/selectors.py", line
415, in select
-
fd_event_list = self._selector.poll(timeout)
-
File
"/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 64, in alarm_handler
-
raise Timeout()
-
VirtSubproc.Timeout
-
autopkgtest [23:23:51]: ERROR: testbed failure:
cannot send to testbed: [Errno 32] Broken pipe
+
autopkgtest [22:51:16]: test clone-reprepro: preparing testbed
+
Waiting...
+
Creating nova instance
adt-jammy-s390x-dgit-20230104-215159-juju-4d1272-prod-proposed-migration-9 from
image adt/ubuntu-jammy-s390x-server-20230103.img (UUID
0a7a472d-9a85-43af-ab6b-26b50466bd6e)...
+
Waiting...
+
Creating nova instance
adt-jammy-s390x-dgit-20230104-215159-juju-4d1272-prod-proposed-migration-9 from
image adt/ubuntu-jammy-s390x-server-20230103.img (UUID
0a7a472d-9a85-43af-ab6b-26b50466bd6e)...
+
ERROR (CommandError): Unable to delete the specified server(s).
+
Unexpected error:
+
Traceback (most recent call last):
+
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 740, in mainloop
+
command()
+
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 669, in command
+
r = f(c, ce)
+
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 302, in cmd_revert
+
caller.hook_revert()
+
File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 444, in
hook_revert
+
host_setup('revert')
+
File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 263, in
host_setup
+
execute_setup_script(command)
+
File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 202, in
execute_setup_script
+
(status, out, err) =
VirtSubproc.execute_timeout(
+
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 144, in execute_timeout
+
(out, err) = sp.communicate(instr)
+
File "/usr/lib/python3.8/subprocess.py", line 1028, in communicate
+
stdout, stderr = self._communicate(input,
endtime, timeout)
+
File "/usr/lib/python3.8/subprocess.py", line 1868, in _communicate
+
ready = selector.select(timeout)
+
File "/usr/lib/python3.8/selectors.py", line 415, in select
+
fd_event_list = self._selector.poll(timeout)
+
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 64, in alarm_handler
+
raise Timeout()
+
VirtSubproc.Timeout
+
autopkgtest [23:23:51]: ERROR: testbed failure: cannot send to testbed [Errno
32] Broken pipe
--
You received this bug notification because you are a member of
Canonical's Ubuntu QA, which is subscribed to autopkgtest in Ubuntu.
https://bugs.launchpad.net/bugs/2002036
Title:
error logging works incosistently
Status in autopkgtest package in Ubuntu:
New
Bug description:
I'm getting the feeling that the error logging of `ssh-setup/nova` is
working inconsistently. Consider the following two log excerpts from
one of the autopkgtest-cloud-worker journals:
autopkgtest [22:23:29]: test launch-test: preparing testbed
Waiting...
Creating nova instance
adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9
f
rom image adt/ubuntu-lunar-s390x-server-20230103.img (UUID
2a986d1c-2fa0-4a0e-b9bc-2915b9deda73)...
Waiting...
Creating nova instance
adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9
f
rom image adt/ubuntu-lunar-s390x-server-20230103.img (UUID
2a986d1c-2fa0-4a0e-b9bc-2915b9deda73)...
Timed out waiting for ssh. Aborting! Console log:
------- nova console-log 8f057152-58df-4517-984b-4e8621df8424
(adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9)
------
Ubuntu Lunar Lobster (development branch) auto-syncubuntu-lunar-
daily-s390x-server-20221227-disk1 sclp_line0
auto-syncubuntu-lunar-daily-s390x-server-20221227-disk1 login:
---------------------------------------------------
------- nova show 8f057152-58df-4517-984b-4e8621df8424
(adt-lunar-s390x-libomxmad-20230104-220149-juju-4d1272-prod-proposed-migration-9)
------
In the above excerpt we can see "Timed out waiting for ssh" and then
the `nova show` and `nova console-log`. However, here we have very
little information about what went wrong:
autopkgtest [22:51:16]: test clone-reprepro: preparing testbed
Waiting...
Creating nova instance
adt-jammy-s390x-dgit-20230104-215159-juju-4d1272-prod-proposed-migration-9 from
image adt/ubuntu-jammy-s390x-server-20230103.img (UUID
0a7a472d-9a85-43af-ab6b-26b50466bd6e)...
Waiting...
Creating nova instance
adt-jammy-s390x-dgit-20230104-215159-juju-4d1272-prod-proposed-migration-9 from
image adt/ubuntu-jammy-s390x-server-20230103.img (UUID
0a7a472d-9a85-43af-ab6b-26b50466bd6e)...
ERROR (CommandError): Unable to delete the specified server(s).
Unexpected error:
Traceback (most recent call last):
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 740, in mainloop
command()
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 669, in command
r = f(c, ce)
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 302, in cmd_revert
caller.hook_revert()
File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 444, in
hook_revert
host_setup('revert')
File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 263, in
host_setup
execute_setup_script(command)
File "/home/ubuntu/autopkgtest/virt/autopkgtest-virt-ssh", line 202, in
execute_setup_script
(status, out, err) =
VirtSubproc.execute_timeout(
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 144, in execute_timeout
(out, err) = sp.communicate(instr)
File "/usr/lib/python3.8/subprocess.py", line 1028, in communicate
stdout, stderr = self._communicate(input,
endtime, timeout)
File "/usr/lib/python3.8/subprocess.py", line 1868, in _communicate
ready = selector.select(timeout)
File "/usr/lib/python3.8/selectors.py", line 415, in select
fd_event_list = self._selector.poll(timeout)
File "/home/ubuntu/autopkgtest/lib/VirtSubproc.py", line 64, in alarm_handler
raise Timeout()
VirtSubproc.Timeout
autopkgtest [23:23:51]: ERROR: testbed failure: cannot send to testbed [Errno
32] Broken pipe
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/autopkgtest/+bug/2002036/+subscriptions
--
Mailing list: https://launchpad.net/~canonical-ubuntu-qa
Post to : [email protected]
Unsubscribe : https://launchpad.net/~canonical-ubuntu-qa
More help : https://help.launchpad.net/ListHelp
