All of lore.kernel.org
 help / color / mirror / Atom feed
* ReplayKernelNormal.test_mips_malta functional test timeouting
@ 2021-03-19 10:34 Philippe Mathieu-Daudé
  2021-03-22  7:06 ` Pavel Dovgalyuk
  0 siblings, 1 reply; 2+ messages in thread
From: Philippe Mathieu-Daudé @ 2021-03-19 10:34 UTC (permalink / raw)
  To: Pavel Dovgalyuk, Alex Bennée, Thomas Huth; +Cc: qemu-devel

Hi Pavel,

The "normal" test_mips_malta timeouted on acceptance-system-fedora job:

 (23/36)
tests/acceptance/replay_kernel.py:ReplayKernelNormal.test_mips_malta:
INTERRUPTED: Test interrupted by SIGTERM\nRunner error occurred: Timeout
reached\nOriginal status: ERROR\n{'name':
'23-tests/acceptance/replay_kernel.py:ReplayKernelNormal.test_mips_malta',
'logdir':
'/builds/philmd/qemu2/build/tests/results/job-2021-03-19T09.38-e5751b5/...
(120.52 s)

artifact's debug.log:

09:43:04 DEBUG| PARAMS (key=arch, path=*, default=mips) => 'mips'
09:43:04 DEBUG| PARAMS (key=machine, path=*, default=malta) => 'malta'
09:43:04 DEBUG| PARAMS (key=qemu_bin, path=*,
default=./qemu-system-mips) => './qemu-system-mips'
09:43:04 INFO | Running 'ar t
/builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb'
09:43:04 DEBUG| [stdout] debian-binary
09:43:04 INFO | Command 'ar t
/builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb'
finished with 0 after 0.0019164085388183594s
09:43:04 DEBUG| [stdout] control.tar.gz
09:43:04 DEBUG| [stdout] data.tar.gz
09:43:04 INFO | Running 'ar x
/builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb
data.tar.gz'
09:43:04 INFO | Command 'ar x
/builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb
data.tar.gz' finished with 0 after 0.047913551330566406s
09:43:05 INFO | recording the execution...
09:43:05 DEBUG| VM launch command: './qemu-system-mips -display none
-vga none -chardev
socket,id=mon,path=/var/tmp/avo_qemu_sock_z2x1qvna/qemu-601-monitor.sock
-mon chardev=mon,mode=control -machine malta -chardev
socket,id=console,path=/var/tmp/avo_qemu_sock_z2x1qvna/qemu-601-console.sock,server=on,wait=off
-serial chardev:console -icount
shift=5,rr=record,rrfile=/var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/replay.bin
-kernel
/var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/boot/vmlinux-2.6.32-5-4kc-malta
-append printk.time=1 panic=-1 console=ttyS0 -net none -no-reboot'
09:43:05 DEBUG| >>> {'execute': 'qmp_capabilities'}
09:43:05 DEBUG| <<< {'return': {}}
09:43:05 DEBUG| [    0.000000] Initrd not found or empty - disabling initrd
09:43:05 DEBUG| [    0.000000] Zone PFN ranges:
09:43:05 DEBUG| [    0.000000]   DMA      0x00000000 -> 0x00001000
09:43:05 DEBUG| [    0.000000]   Normal   0x00001000 -> 0x00007fff
09:43:05 DEBUG| [    0.000000] Movable zone start PFN for each node
09:43:05 DEBUG| [    0.000000] early_node_map[1] active PFN ranges
09:43:05 DEBUG| [    0.000000]     0: 0x00000000 -> 0x00007fff
09:43:05 DEBUG| [    0.000000] Built 1 zonelists in Zone order, mobility
grouping on.  Total pages: 32511
09:43:05 DEBUG| [    0.000000] Kernel command line: printk.time=1
panic=-1 console=ttyS0
09:43:05 DEBUG| >>> {'execute': 'quit'}
09:43:05 DEBUG| <<< {'return': {}}
09:43:05 INFO | finished the recording with log size 21979 bytes
09:43:05 INFO | elapsed time 0.13 sec
09:43:05 INFO | replaying the execution...
09:43:05 DEBUG| VM launch command: './qemu-system-mips -display none
-vga none -chardev
socket,id=mon,path=/var/tmp/avo_qemu_sock_opalepcn/qemu-601-monitor.sock
-mon chardev=mon,mode=control -machine malta -chardev
socket,id=console,path=/var/tmp/avo_qemu_sock_opalepcn/qemu-601-console.sock,server=on,wait=off
-serial chardev:console -icount
shift=5,rr=replay,rrfile=/var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/replay.bin
-kernel
/var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/boot/vmlinux-2.6.32-5-4kc-malta
-append printk.time=1 panic=-1 console=ttyS0 -net none -no-reboot'
09:43:05 DEBUG| >>> {'execute': 'qmp_capabilities'}
09:43:05 DEBUG| <<< {'return': {}}
09:43:06 DEBUG| [    0.000000] Initrd not found or empty - disabling initrd
09:43:06 DEBUG| [    0.000000] Zone PFN ranges:
09:43:06 DEBUG| [    0.000000]   DMA      0x00000000 -> 0x00001000
09:43:06 DEBUG| [    0.000000]   Normal   0x00001000 -> 0x00007fff
09:43:06 DEBUG| [    0.000000] Movable zone start PFN for each node
09:43:06 DEBUG| [    0.000000] early_node_map[1] active PFN ranges
09:43:06 DEBUG| [    0.000000]
09:45:05 ERROR|
09:45:05 ERROR| Reproduced traceback from:
/builds/philmd/qemu2/build/tests/venv/lib64/python3.9/site-packages/avocado/core/test.py:767
09:45:05 ERROR| Traceback (most recent call last):
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/acceptance/replay_kernel.py", line
114, in test_mips_malta
09:45:05 ERROR|     self.run_rr(kernel_path, kernel_command_line,
console_pattern, shift=5)
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/acceptance/replay_kernel.py", line 75,
in run_rr
09:45:05 ERROR|     t2 = self.run_vm(kernel_path, kernel_command_line,
console_pattern,
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/acceptance/replay_kernel.py", line 58,
in run_vm
09:45:05 ERROR|     self.wait_for_console_pattern(console_pattern, vm)
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/acceptance/boot_linux_console.py",
line 52, in wait_for_console_pattern
09:45:05 ERROR|     wait_for_console_pattern(self, success_message,
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/acceptance/avocado_qemu/__init__.py",
line 140, in wait_for_console_pattern
09:45:05 ERROR|     _console_interaction(test, success_message,
failure_message, None, vm=vm)
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/acceptance/avocado_qemu/__init__.py",
line 92, in _console_interaction
09:45:05 ERROR|     msg = console.readline().strip()
09:45:05 ERROR|   File "/usr/lib64/python3.9/socket.py", line 704, in
readinto
09:45:05 ERROR|     return self._sock.recv_into(b)
09:45:05 ERROR|   File
"/builds/philmd/qemu2/build/tests/venv/lib64/python3.9/site-packages/avocado/plugins/runner.py",
line 77, in sigterm_handler
09:45:05 ERROR|     raise RuntimeError("Test interrupted by SIGTERM")
09:45:05 ERROR| RuntimeError: Test interrupted by SIGTERM

What to do, simply implement the timeout again?
Allow failure?

Thanks,

Phil.


^ permalink raw reply	[flat|nested] 2+ messages in thread

* Re: ReplayKernelNormal.test_mips_malta functional test timeouting
  2021-03-19 10:34 ReplayKernelNormal.test_mips_malta functional test timeouting Philippe Mathieu-Daudé
@ 2021-03-22  7:06 ` Pavel Dovgalyuk
  0 siblings, 0 replies; 2+ messages in thread
From: Pavel Dovgalyuk @ 2021-03-22  7:06 UTC (permalink / raw)
  To: Philippe Mathieu-Daudé,
	Pavel Dovgalyuk, Alex Bennée, Thomas Huth, Cleber Rosa
  Cc: qemu-devel

On 19.03.2021 13:34, Philippe Mathieu-Daudé wrote:
> Hi Pavel,
> 
> The "normal" test_mips_malta timeouted on acceptance-system-fedora job:
> 
>   (23/36)
> tests/acceptance/replay_kernel.py:ReplayKernelNormal.test_mips_malta:
> INTERRUPTED: Test interrupted by SIGTERM\nRunner error occurred: Timeout
> reached\nOriginal status: ERROR\n{'name':
> '23-tests/acceptance/replay_kernel.py:ReplayKernelNormal.test_mips_malta',
> 'logdir':
> '/builds/philmd/qemu2/build/tests/results/job-2021-03-19T09.38-e5751b5/...
> (120.52 s)
> 
> artifact's debug.log:
> 
> 09:43:04 DEBUG| PARAMS (key=arch, path=*, default=mips) => 'mips'
> 09:43:04 DEBUG| PARAMS (key=machine, path=*, default=malta) => 'malta'
> 09:43:04 DEBUG| PARAMS (key=qemu_bin, path=*,
> default=./qemu-system-mips) => './qemu-system-mips'
> 09:43:04 INFO | Running 'ar t
> /builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb'
> 09:43:04 DEBUG| [stdout] debian-binary
> 09:43:04 INFO | Command 'ar t
> /builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb'
> finished with 0 after 0.0019164085388183594s
> 09:43:04 DEBUG| [stdout] control.tar.gz
> 09:43:04 DEBUG| [stdout] data.tar.gz
> 09:43:04 INFO | Running 'ar x
> /builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb
> data.tar.gz'
> 09:43:04 INFO | Command 'ar x
> /builds/philmd/qemu2/avocado-cache/by_location/44bac84408e676508a64ecba77e99389ac8fe10d/linux-image-2.6.32-5-4kc-malta_2.6.32-48_mips.deb
> data.tar.gz' finished with 0 after 0.047913551330566406s
> 09:43:05 INFO | recording the execution...
> 09:43:05 DEBUG| VM launch command: './qemu-system-mips -display none
> -vga none -chardev
> socket,id=mon,path=/var/tmp/avo_qemu_sock_z2x1qvna/qemu-601-monitor.sock
> -mon chardev=mon,mode=control -machine malta -chardev
> socket,id=console,path=/var/tmp/avo_qemu_sock_z2x1qvna/qemu-601-console.sock,server=on,wait=off
> -serial chardev:console -icount
> shift=5,rr=record,rrfile=/var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/replay.bin
> -kernel
> /var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/boot/vmlinux-2.6.32-5-4kc-malta
> -append printk.time=1 panic=-1 console=ttyS0 -net none -no-reboot'
> 09:43:05 DEBUG| >>> {'execute': 'qmp_capabilities'}
> 09:43:05 DEBUG| <<< {'return': {}}
> 09:43:05 DEBUG| [    0.000000] Initrd not found or empty - disabling initrd
> 09:43:05 DEBUG| [    0.000000] Zone PFN ranges:
> 09:43:05 DEBUG| [    0.000000]   DMA      0x00000000 -> 0x00001000
> 09:43:05 DEBUG| [    0.000000]   Normal   0x00001000 -> 0x00007fff
> 09:43:05 DEBUG| [    0.000000] Movable zone start PFN for each node
> 09:43:05 DEBUG| [    0.000000] early_node_map[1] active PFN ranges
> 09:43:05 DEBUG| [    0.000000]     0: 0x00000000 -> 0x00007fff
> 09:43:05 DEBUG| [    0.000000] Built 1 zonelists in Zone order, mobility
> grouping on.  Total pages: 32511
> 09:43:05 DEBUG| [    0.000000] Kernel command line: printk.time=1
> panic=-1 console=ttyS0
> 09:43:05 DEBUG| >>> {'execute': 'quit'}
> 09:43:05 DEBUG| <<< {'return': {}}
> 09:43:05 INFO | finished the recording with log size 21979 bytes
> 09:43:05 INFO | elapsed time 0.13 sec
> 09:43:05 INFO | replaying the execution...
> 09:43:05 DEBUG| VM launch command: './qemu-system-mips -display none
> -vga none -chardev
> socket,id=mon,path=/var/tmp/avo_qemu_sock_opalepcn/qemu-601-monitor.sock
> -mon chardev=mon,mode=control -machine malta -chardev
> socket,id=console,path=/var/tmp/avo_qemu_sock_opalepcn/qemu-601-console.sock,server=on,wait=off
> -serial chardev:console -icount
> shift=5,rr=replay,rrfile=/var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/replay.bin
> -kernel
> /var/tmp/avocado__uxji4xt/avocado_job_j3sdjxv9/23-tests_acceptance_replay_kernel.py_ReplayKernelNormal.test_mips_malta/boot/vmlinux-2.6.32-5-4kc-malta
> -append printk.time=1 panic=-1 console=ttyS0 -net none -no-reboot'
> 09:43:05 DEBUG| >>> {'execute': 'qmp_capabilities'}
> 09:43:05 DEBUG| <<< {'return': {}}
> 09:43:06 DEBUG| [    0.000000] Initrd not found or empty - disabling initrd
> 09:43:06 DEBUG| [    0.000000] Zone PFN ranges:
> 09:43:06 DEBUG| [    0.000000]   DMA      0x00000000 -> 0x00001000
> 09:43:06 DEBUG| [    0.000000]   Normal   0x00001000 -> 0x00007fff
> 09:43:06 DEBUG| [    0.000000] Movable zone start PFN for each node
> 09:43:06 DEBUG| [    0.000000] early_node_map[1] active PFN ranges
> 09:43:06 DEBUG| [    0.000000]
> 09:45:05 ERROR|
> 09:45:05 ERROR| Reproduced traceback from:
> /builds/philmd/qemu2/build/tests/venv/lib64/python3.9/site-packages/avocado/core/test.py:767
> 09:45:05 ERROR| Traceback (most recent call last):
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/acceptance/replay_kernel.py", line
> 114, in test_mips_malta
> 09:45:05 ERROR|     self.run_rr(kernel_path, kernel_command_line,
> console_pattern, shift=5)
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/acceptance/replay_kernel.py", line 75,
> in run_rr
> 09:45:05 ERROR|     t2 = self.run_vm(kernel_path, kernel_command_line,
> console_pattern,
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/acceptance/replay_kernel.py", line 58,
> in run_vm
> 09:45:05 ERROR|     self.wait_for_console_pattern(console_pattern, vm)
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/acceptance/boot_linux_console.py",
> line 52, in wait_for_console_pattern
> 09:45:05 ERROR|     wait_for_console_pattern(self, success_message,
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/acceptance/avocado_qemu/__init__.py",
> line 140, in wait_for_console_pattern
> 09:45:05 ERROR|     _console_interaction(test, success_message,
> failure_message, None, vm=vm)
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/acceptance/avocado_qemu/__init__.py",
> line 92, in _console_interaction
> 09:45:05 ERROR|     msg = console.readline().strip()
> 09:45:05 ERROR|   File "/usr/lib64/python3.9/socket.py", line 704, in
> readinto
> 09:45:05 ERROR|     return self._sock.recv_into(b)
> 09:45:05 ERROR|   File
> "/builds/philmd/qemu2/build/tests/venv/lib64/python3.9/site-packages/avocado/plugins/runner.py",
> line 77, in sigterm_handler
> 09:45:05 ERROR|     raise RuntimeError("Test interrupted by SIGTERM")
> 09:45:05 ERROR| RuntimeError: Test interrupted by SIGTERM
> 
> What to do, simply implement the timeout again?

I thought that it could be a RR bug and tried it on my machine without 
non-upstreamed patches.
The test didn't fail in ~10 runs.

> Allow failure?

CC'ed Cleber.
I think it could be the already seen avocado/qemu socket problem.

Pavel Dovgalyuk


^ permalink raw reply	[flat|nested] 2+ messages in thread

end of thread, other threads:[~2021-03-22  7:07 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-03-19 10:34 ReplayKernelNormal.test_mips_malta functional test timeouting Philippe Mathieu-Daudé
2021-03-22  7:06 ` Pavel Dovgalyuk

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.