22:50:22 DEBUG| PARAMS (key=arch, path=*, default=or1k) => 'or1k' 22:50:22 DEBUG| PARAMS (key=machine, path=*, default=or1k-sim) => 'or1k-sim' 22:50:22 DEBUG| PARAMS (key=qemu_bin, path=*, default=./qemu-system-or1k) => './qemu-system-or1k' 22:50:22 DEBUG| VM launch command: './qemu-system-or1k -display none -vga none -chardev socket,id=mon,path=/var/tmp/avo_qemu_sock_sk_2kyqq/qemu-989-monitor.sock -mon chardev=mon,mode=control -machine or1k-sim -chardev socket,id=console,path=/var/tmp/avo_qemu_sock_sk_2kyqq/qemu-989-console.sock,server=on,wait=off -serial chardev:console -kernel /var/tmp/avocado_dlewrnd4/avocado_job_k8m44k90/09-tests_acceptance_boot_linux_console.py_BootLinuxConsole.test_or1k_sim/day20/vmlinux' 22:50:22 DEBUG| >>> {'execute': 'qmp_capabilities'} 22:50:22 DEBUG| <<< {'return': {}} 22:50:22 DEBUG| Compiled-in FDT at c0312000 22:50:22 DEBUG| Linux version 4.13.3 (thuth@thuth.remote.csb) (gcc version 5.4.0 (Buildroot 2018.05.2)) #7 Sat Dec 15 20:13:34 CET 2018 22:50:22 DEBUG| CPU: OpenRISC-13 (revision 8) @20 MHz 22:50:22 DEBUG| -- dcache disabled 22:50:22 DEBUG| -- icache disabled 22:50:22 DEBUG| -- dmmu: 128 entries, 1 way(s) 22:50:22 DEBUG| -- immu: 128 entries, 1 way(s) 22:50:22 DEBUG| -- additional features: 22:50:22 DEBUG| -- power management 22:50:22 DEBUG| -- PIC 22:50:22 DEBUG| -- timer 22:50:22 DEBUG| setup_memory: Memory: 0x0-0x2000000 22:50:22 DEBUG| Setting up paging and PTEs. 22:50:22 DEBUG| map_ram: Memory: 0x0-0x2000000 22:50:22 DEBUG| itlb_miss_handler c0002160 22:50:22 DEBUG| dtlb_miss_handler c0002000 22:50:22 DEBUG| OpenRISC Linux -- http://openrisc.io 22:50:22 DEBUG| Built 1 zonelists in Zone order, mobility grouping off. Total pages: 4080 22:50:22 DEBUG| Kernel command line: console=uart,mmio,0x90000000,115200 22:50:22 DEBUG| earlycon: uart0 at MMIO 0x90000000 (options '115200') 22:50:22 DEBUG| bootconsole [uart0] enabled 22:50:22 DEBUG| PID hash table entries: 128 (order: -4, 512 bytes) 22:50:22 DEBUG| Dentry cache hash table entries: 4096 (order: 1, 16384 bytes) 22:50:22 DEBUG| Inode-cache hash table entries: 2048 (order: 0, 8192 bytes) 22:50:22 DEBUG| Sorting __ex_table... 22:50:22 DEBUG| Memory: 28144K/32768K available (2322K kernel code, 109K rwdata, 592K rodata, 1176K init, 188K bss, 4624K reserved, 0K cma-reserved) 22:50:22 DEBUG| mem_init_done ........................................... 22:50:22 DEBUG| SLUB: HWalign=16, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 22:50:22 DEBUG| NR_IRQS: 32, nr_irqs: 32, preallocated irqs: 0 22:50:23 DEBUG| clocksource: openrisc_timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 95563022313 ns 22:50:23 DEBUG| Console: colour dummy device 80x25 22:50:23 DEBUG| 40.00 BogoMIPS (lpj=80000) 22:50:23 DEBUG| pid_max: default: 32768 minimum: 301 22:50:23 DEBUG| Mount-cache hash table entries: 2048 (order: 0, 8192 bytes) 22:50:23 DEBUG| Mountpoint-cache hash table entries: 2048 (order: 0, 8192 bytes) 22:50:23 DEBUG| devtmpfs: initialized 22:50:23 DEBUG| clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns 22:50:23 DEBUG| futex hash table entries: 256 (order: -2, 3072 bytes) 22:50:23 DEBUG| clocksource: Switched to clocksource openrisc_timer 22:50:23 DEBUG| workingset: timestamp_bits=30 max_order=12 bucket_order=0 22:50:23 DEBUG| random: fast init done 22:50:23 DEBUG| Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253) 22:50:23 DEBUG| io scheduler noop registered 22:50:23 DEBUG| io scheduler deadline registered 22:50:23 DEBUG| io scheduler cfq registered (default) 22:50:23 DEBUG| io scheduler mq-deadline registered 22:50:23 DEBUG| io scheduler kyber registered 22:50:23 DEBUG| Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled 22:50:23 DEBUG| 90000000.serial: ttyS0 at MMIO 0x90000000 (irq = 2, base_baud = 1250000) is a 16550A 22:50:23 DEBUG| console [ttyS0] enabled 22:50:23 DEBUG| console [ttyS0] enabled 22:50:23 DEBUG| bootconsole [uart0] disabled 22:50:23 DEBUG| bootconsole [uart0] disabled 22:50:23 DEBUG| Freeing unused kernel memory: 1176K 22:50:23 DEBUG| This architecture does not have kernel memory protection. 22:51:53 ERROR| 22:51:53 ERROR| Reproduced traceback from: build/tests/venv/lib64/python3.6/site-packages/avocado/core/test.py:767 22:51:53 ERROR| Traceback (most recent call last): 22:51:53 ERROR| File "build/tests/acceptance/boot_linux_console.py", line 1065, in test_or1k_sim 22:51:53 ERROR| self.do_test_advcal_2018('20', tar_hash, 'vmlinux') 22:51:53 ERROR| File "build/tests/acceptance/boot_linux_console.py", line 1040, in do_test_advcal_2018 22:51:53 ERROR| self.wait_for_console_pattern('QEMU advent calendar') 22:51:53 ERROR| File "build/tests/acceptance/boot_linux_console.py", line 54, in wait_for_console_pattern 22:51:53 ERROR| vm=vm) 22:51:53 ERROR| File "build/tests/acceptance/avocado_qemu/__init__.py", line 130, in wait_for_console_pattern 22:51:53 ERROR| _console_interaction(test, success_message, failure_message, None, vm=vm) 22:51:53 ERROR| File "build/tests/acceptance/avocado_qemu/__init__.py", line 82, in _console_interaction 22:51:53 ERROR| msg = console.readline().strip() 22:51:53 ERROR| File "/usr/lib64/python3.6/socket.py", line 586, in readinto 22:51:53 ERROR| return self._sock.recv_into(b) 22:51:53 ERROR| File "build/tests/venv/lib64/python3.6/site-packages/avocado/plugins/runner.py", line 77, in sigterm_handler 22:51:53 ERROR| raise RuntimeError("Test interrupted by SIGTERM") 22:51:53 ERROR| RuntimeError: Test interrupted by SIGTERM 22:51:53 ERROR| 22:51:53 DEBUG| Local variables: 22:51:53 DEBUG| -> tar_hash : 20334cdaf386108c530ff0badaecc955693027dd 22:51:53 DEBUG| -> self : 09-tests/acceptance/boot_linux_console.py:BootLinuxConsole.test_or1k_sim 22:51:53 DEBUG| >>> {'execute': 'quit'} 22:51:53 DEBUG| <<< {'return': {}} 22:51:53 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file) 22:51:53 DEBUG| DATA (filename=stdout.expected) => NOT FOUND (data sources: variant, test, file) 22:51:53 DEBUG| DATA (filename=stderr.expected) => NOT FOUND (data sources: variant, test, file) 22:51:53 ERROR| Traceback (most recent call last): 22:51:53 ERROR| File "build/tests/venv/lib64/python3.6/site-packages/avocado/core/test.py", line 856, in _run_avocado raise test_exception 22:51:53 ERROR| File "build/tests/venv/lib64/python3.6/site-packages/avocado/core/test.py", line 762, in _run_avocado testMethod() 22:51:53 ERROR| File "build/tests/acceptance/boot_linux_console.py", line 1065, in test_or1k_sim self.do_test_advcal_2018('20', tar_hash, 'vmlinux') 22:51:53 ERROR| File "build/tests/acceptance/boot_linux_console.py", line 1040, in do_test_advcal_2018 self.wait_for_console_pattern('QEMU advent calendar') 22:51:53 ERROR| File "build/tests/acceptance/boot_linux_console.py", line 54, in wait_for_console_pattern vm=vm) 22:51:53 ERROR| File "build/tests/acceptance/avocado_qemu/__init__.py", line 130, in wait_for_console_pattern _console_interaction(test, success_message, failure_message, None, vm=vm) 22:51:53 ERROR| File "build/tests/acceptance/avocado_qemu/__init__.py", line 82, in _console_interaction msg = console.readline().strip() 22:51:53 ERROR| File "/usr/lib64/python3.6/socket.py", line 586, in readinto return self._sock.recv_into(b) 22:51:53 ERROR| File "build/tests/venv/lib64/python3.6/site-packages/avocado/plugins/runner.py", line 77, in sigterm_handler raise RuntimeError("Test interrupted by SIGTERM") 22:51:53 ERROR| RuntimeError: Test interrupted by SIGTERM 22:51:53 ERROR| ERROR 09-tests/acceptance/boot_linux_console.py:BootLinuxConsole.test_or1k_sim -> RuntimeError: Test interrupted by SIGTERM 22:51:53 INFO | Runner error occurred: Timeout reached Original status: ERROR {'name': '09-tests/acceptance/boot_linux_console.py:BootLinuxConsole.test_or1k_sim', 'logdir': 'build/tests/results/job-2021-02-10T22.50-0d5d33e/test-results/09-tests_acceptance_boot_linux_console.py_BootLinuxConsole.test_or1k_sim', 'logfile': 'build/tests/results/job-2021-02-10T22.50-0d5d33e/test-results/09-tests_acceptance_boot_linux_console.py_BootLinuxConsole.test_or1k_sim/debug.log', 'status': 'ERROR', 'running': False, 'paused': False, 'time_start': 1612997422.4942405, 'time_elapsed': 90.74333953857422, 'time_end': 1612997513.23758, 'fail_reason': 'Test interrupted by SIGTERM', 'fail_class': 'RuntimeError', 'traceback': 'Traceback (most recent call last):\n File "build/tests/venv/lib64/python3.6/site-packages/avocado/core/test.py", line 856, in _run_avocado\n raise test_exception\n File "build/tests/venv/lib64/python3.6/site-packages/avocado/core/test.py", line 762, in _run_avocado\n testMethod()\n File "build/tests/acceptance/boot_linux_console.py", line 1065, in test_or1k_sim\n self.do_test_advcal_2018(\'20\', tar_hash, \'vmlinux\')\n File "build/tests/acceptance/boot_linux_console.py", line 1040, in do_test_advcal_2018\n self.wait_for_console_pattern(\'QEMU advent calendar\')\n File "build/tests/acceptance/boot_linux_console.py", line 54, in wait_for_console_pattern\n vm=vm)\n File "build/tests/acceptance/avocado_qemu/__init__.py", line 130, in wait_for_console_pattern\n _console_interaction(test, success_message, failure_message, None, vm=vm)\n File "build/tests/acceptance/avocado_qemu/__init__.py", line 82, in _console_interaction\n msg = console.readline().strip()\n File "/usr/lib64/python3.6/socket.py", line 586, in readinto\n return self._sock.recv_into(b)\n File "build/tests/venv/lib64/python3.6/site-packages/avocado/plugins/runner.py", line 77, in sigterm_handler\n raise RuntimeError("Test interrupted by SIGTERM")\nRuntimeError: Test interrupted by SIGTERM\n', 'timeout': 90, 'whiteboard': '', 'phase': 'FINISHED', 'class_name': 'BootLinuxConsole', 'job_logdir': 'build/tests/results/job-2021-02-10T22.50-0d5d33e', 'job_unique_id': '0d5d33e13c6ac6c949aa9382f0ca12f47bc19e2a', 'params': []}