| Summary: | AB-INT PTEST: python3 ptest intermittent failure | ||
|---|---|---|---|
| Product: | [QA/Testing] Package Testing (ptest) | Reporter: | Köry Maincent <kory.maincent> |
| Component: | ptest | Assignee: | Randy MacLeod <randy.macleod> |
| Status: | RESOLVED WORKSFORME | QA Contact: | |
| Severity: | normal | ||
| Priority: | Medium | CC: | alexandre.belloni, bluelightning, chee.yang.lee, flowergom, jon.mason, randy.macleod, richard.purdie, thomas.perrot, tim.orling |
| Version: | unspecified | ||
| Target Milestone: | 4.1 | ||
| Hardware: | x86 | ||
| OS: | Multiple | ||
| Whiteboard: | AB-INT | ||
| OS type for building Yocto: | --- | Type of Regression: | --- |
| Verified: | Documentation change: | No (bug/feature does not impact docs) | |
|
Description
Köry Maincent
2021-03-09 16:21:09 UTC
Python3 and lttng-tools intermittent failure. https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/1893/steps/13/logs/stdio NOTE: recipe core-image-sato-sdk-ptest-1.0-r0: task do_testimage: Started Bitbake still alive (5000s) Bitbake still alive (10000s) WARNING: core-image-sato-sdk-ptest-1.0-r0 do_testimage: There were failing ptests. Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemux86-64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemux86-64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemux86-64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemux86-64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 25, in test_ptestrunner_expectfail self.do_ptestrunner() File "/home/pokybuild/yocto-worker/qemux86-64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 112, in do_ptestrunner self.fail(failmsg) AssertionError: Failed ptests: {'lttng-tools': ['tools/notification/test_notification_multi_app_28_-_Waiting_message:_error_logged_see_file_content:_notification:_high_4,_/tmp/tmp.XXXXXXXXXX/high_app_output_file_0', 'tools/notification/test_notification_multi_app_29_-_Stop_lttng_tracing_for_session_my_session', 'tools/notification/test_notification_multi_app_30_-_Waiting_message:_error_logged_see_file_content:_notification:_low_4,_/tmp/tmp.XXXXXXXXXX/low_app_output_file_0', 'tools/notification/test_notification_multi_app_31_-_Notifications_4_received', 'tools/notification/test_notification_multi_app_32_-_Waiting_message:_error_logged_see_file_content:_exit:_0,_/tmp/tmp.XXXXXXXXXX/low_app_output_file_0', 'tools/notification/test_notification_multi_app_33_-_Application_for_low_notification_terminated_normally', 'tools/notification/test_notification_multi_app_34_-_Waiting_message:_error_logged_see_file_content:_exit:_0,_/tmp/tmp.XXXXXXXXXX/high_app_output_file_0', 'tools/notification/test_notification_multi_app_35_-_Application_for_high_notification_terminated_normally', 'tools/notification/test_notification_multi_app_36_-_Destroy_session_my_session'], 'python3': ['test_many_processes']} > {'python3': ['test_wait_integer']} https://github.com/python/cpython/blob/63298930fb531ba2bb4f23bc3b915dbf1e17e9e1/Lib/test/_test_multiprocessing.py#L4718 > 'python3': ['test_many_processes']} https://github.com/python/cpython/blob/63298930fb531ba2bb4f23bc3b915dbf1e17e9e1/Lib/test/_test_multiprocessing.py#L571 This seems similar (ignoring the non-python3 failures, though they might be indicative of load at the time): https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1662/steps/12/logs/stdio WARNING: core-image-sato-sdk-ptest-1.0-r0 do_testimage: There were failing ptests. Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 25, in test_ptestrunner_expectfail self.do_ptestrunner() File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 112, in do_ptestrunner self.fail(failmsg) AssertionError: Failed ptests: {'python3': ['test_process_time'], 'tcl': ['interp.test'], 'valgrind': ['memcheck/tests/linux/timerfd-syscall']} The load is highish, the test tests for cpu time consumed for a sleep. https://autobuilder.yocto.io/pub/non-release/20210328-5/testresults/qemuarm64-ptest/python3.log OK 0:38:55 load avg: 1.20 [356/425] test_time [SNIP] FAIL: test_process_time (test.test_time.TimeTestCase) PASS: test_pthread_getcpuclockid (test.test_time.TimeTestCase) PASS: test_sleep (test.test_time.TimeTestCase) PASS: test_strftime (test.test_time.TimeTestCase) PASS: test_strftime_bounding_check (test.test_time.TimeTestCase) PASS: test_strftime_format_check (test.test_time.TimeTestCase) PASS: test_strptime (test.test_time.TimeTestCase) PASS: test_strptime_bytes (test.test_time.TimeTestCase) PASS: test_strptime_exception_context (test.test_time.TimeTestCase) PASS: test_thread_time (test.test_time.TimeTestCase) PASS: test_time (test.test_time.TimeTestCase) PASS: test_time_ns_type (test.test_time.TimeTestCase) test test_time failed PASS: test_tzset (test.test_time.TimeTestCase) ====================================================================== FAIL: test_process_time (test.test_time.TimeTestCase) ---------------------------------------------------------------------- Traceback (most recent call last): File "/usr/lib/python3.9/test/test_time.py", line 483, in test_process_time self.assertLess(stop - start, 0.020) AssertionError: 0.06567554000002929 not less than 0.02 ------------------------------------------------------------ will send a patch to disable these timing related tests from looking at the stack trace, I don't think they are actual failures, only slightly off from the expected value and the failure is not reproducible locally. the previous commit ripped out the 3 failing tests. Also fixed on 3.3 by: https://git.openembedded.org/openembedded-core/commit/?id=7c67bc2476b784083acbc7a55ecf3627ec8f2b6b $ git tag --contains 7c67bc2476b784083acbc7a55ecf3627ec8f2b6b 2021-04 2021-04-hardknott yocto-3.3 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1696/steps/12/logs/stdio This is still qemuarm64 on ubuntu1804-arm-1. I'm not sure which test failed, the relevant output seems to be: '(test.test_concurrent_futures.ProcessPoolSpawnProcessPoolExecutorTest) ' '... 0.92s ok\n' 'Exception in thread Thread-403:\n' 'Traceback (most recent call last):\n' ' File "/usr/lib/python3.9/threading.py", line 954, in ' '_bootstrap_inner\n' ' self.run()\n' ' File "/usr/lib/python3.9/concurrent/futures/process.py", line ' '317, in run\n' ' result_item, is_broken, cause = ' 'self.wait_result_broken_or_wakeup()\n' ' File "/usr/lib/python3.9/concurrent/futures/process.py", line ' '376, in wait_result_broken_or_wakeup\n' ' worker_sentinels = [p.sentinel for p in ' 'self.processes.values()]\n' ' File "/usr/lib/python3.9/concurrent/futures/process.py", line ' '376, in <listcomp>\n' ' worker_sentinels = [p.sentinel for p in ' 'self.processes.values()]\n' 'RuntimeError: dictionary changed size during iteration\n' '\n' 'ERROR: Exit status is 9\n' 'DURATION: 800\n'} Might be similar reason/root cause, but the failing test case--to the best of my ability to find it--is: https://github.com/python/cpython/blob/63298930fb531ba2bb4f23bc3b915dbf1e17e9e1/Lib/test/test_concurrent_futures.py#L1008 The key line to me is: 'RuntimeError: dictionary changed size during iteration\n' This implies either a file or data in memory changed during the test execution. https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2056/steps/13/logs/stdio qemux86-64 master-next on centos7-ty-4 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1742/steps/12/logs/stdio qemuarm64 master-next on ubuntu2004-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2033/steps/12/logs/stdio qemux86-64 master-next on ubuntu2004-ty-2 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1746/steps/12/logs/stdio qemuarm64 master on ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1756/steps/12/logs/stdio qemuarm64 master-next on ubuntu1804-arm-1 http://autobuilder.yocto.io/pub/non-release/20210501-17/testresults/testresult-report.txt testseries | result_id : qemux86-64-ptest | runtime_core-image-sato-sdk-ptest_qemux86-64_20210501191514 ptestresult.python3.test_cancel_futures Alex will go over the recent failures and provide data as to which ptest failed. https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2099/steps/12/logs/stdio qemux86-64-ptest centos8-ty-2 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2095/steps/12/logs/stdio qemux86-64-ptest centos8-ty-1 Latest tests look like OOM failures. From https://autobuilder.yocto.io/pub/non-release/20210516-3/testresults/qemux86-64-ptest/python3.log: ... PASS: test_popen_error_with_stdin_pipe (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_read_stdout_after_process_exit (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_send_signal (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_shell (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_shell_loop_deprecated (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_start_new_session (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_stdin_broken_pipe (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_stdin_not_inheritable (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_stdin_stdout (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) PASS: test_terminate (test.test_asyncio.test_subprocess.SubprocessFastWatcherTests) ERROR: Exit status is 9 DURATION: 404 Happend again: https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1852/steps/12/logs/stdio https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2198/steps/13/logs/stdio {'python3': ['test_shell']} qemux86-64-ptest ubuntu1604-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1940/steps/12/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2233/steps/12/logs/stdio qemux86-64-ptest ubuntu1804-ty-1 Hasn't happened in months, Trevor will try one more time and then close if he can't reproduce it. Re-open if seen again. https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2130/steps/12/logs/stdio qemuarm64-ptest ubuntu2004-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2157/steps/12/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2368/steps/12/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2656/steps/12/logs/stdio qemux86-64-ptest centos8-ty-1 https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2396/steps/12/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 25, in test_ptestrunner_expectfail self.do_ptestrunner() File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 112, in do_ptestrunner self.fail(failmsg) AssertionError: Failed ptests: {'python3': ['test_thread_time'], 'strace': ['count.test']} https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2465/steps/12/logs/stdio {'python3': ['test_control_and_wait']} ubuntu1804-arm-1 qemuarm64-ptest https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2413/steps/12/logs/stdio {'python3': ['test_waitfor_timeout'], 'tcl': ['socket.test']} master next on ubuntu1804-arm-1 qemuarm64-ptest https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2549/steps/12/logs/stdio Traceback (most recent call last): File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f return func(*args, **kwargs) File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 25, in test_ptestrunner_expectfail self.do_ptestrunner() File "/home/pokybuild/yocto-worker/qemuarm64-ptest/build/meta/lib/oeqa/runtime/cases/ptest.py", line 108, in do_ptestrunner self.fail(failmsg) AssertionError: Failed ptests: {'python3': ['test_thread_time']} Cannot run ptests without @expectedFailure as ptests are expected to fail https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2648/steps/12/logs/stdio qemuarm64-ptest ubuntu1804-arm-1 We have mitigated the load and moved to SSDs and likely upgraded python all of which may have resulted in this failure stopping 4 months ago. |