Bug 14263

Summary: AB-INT PTEST: lttng-tools ptest intermittent failure
Product: [QA/Testing] Package Testing (ptest) Reporter: Alexandre Belloni <alexandre.belloni>
Component: ptestAssignee: Mingli Yu <mingli.yu>
Status: RESOLVED WORKSFORME QA Contact:
Severity: normal    
Priority: Medium CC: alexandre.belloni, chee.yang.lee, flowergom, joaomarcos.costa, kexin.hao, luca.ceresoli, naveen.kumar.saini, oobitots, randy.macleod, richard.purdie, steve, thomas.perrot
Version: 3.3   
Target Milestone: 5.3   
Hardware: x86   
OS: Multiple   
Whiteboard: AB-INT AB-FREQUENT
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)
Attachments:
Description Flags
lttng test log
none
test_kernel log from the previous ptest failure none

Description Alexandre Belloni 2021-02-28 23:45:29 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/1840/steps/12/logs/stdio shows:

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': '2021-02-23T20:15\n'
                '2021-02-23T20:15\n'
                '\n'
                'ERROR: Exit status is 9\n'
                'DURATION: 310\n'}
Cannot run ptests without @expectedFailure as ptests are expected to fail
RESULTS:
RESULTS - ping.PingTest.test_ping: PASSED (0.65s)
RESULTS - ssh.SSHTest.test_ssh: PASSED (1.09s)
RESULTS - ptest.PtestRunnerTest.test_ptestrunner_expectsuccess: SKIPPED (0.00s)
RESULTS - ptest.PtestRunnerTest.test_ptestrunner_expectfail: EXPECTEDFAIL (10984.06s)
SUMMARY:
core-image-sato-sdk-ptest () - Ran 4 tests in 10985.803s
core-image-sato-sdk-ptest - OK - All required tests passed (successes=2, skipped=1, failures=0, errors=0)
NOTE: recipe core-image-sato-sdk-ptest-1.0-r0: task do_testimage: Succeeded
NOTE: Tasks Summary: Attempted 901 tasks of which 900 didn't need to be rerun and all succeeded.

This looks very much like a timeout
Comment 1 Alexandre Belloni 2021-03-11 14:43:09 UTC
This was on ubuntu1804-ty-2
Comment 2 Alexandre Belloni 2021-05-01 21:54:52 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2008/steps/13/logs/stdio

master-next on debian9-ty-2
Comment 4 Alexandre Belloni 2021-06-16 10:12:17 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2148/steps/12/logs/stdio

qemux86-64-ptest
ubuntu1804-ty-3

AssertionError: ERROR: Processes were killed by the OOM Killer:
ssh: connect to host 192.168.7.2 port 22: No route to host
Failed ptests:
{'lttng-tools': '2021-06-02T23:21\n'
                '2021-06-02T23:21\n'
                'PASS: test_kernel_data 1 - Create kernel session\n'
[...]
Comment 5 Alexandre Belloni 2021-06-16 17:09:13 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1890/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 6 Alexandre Belloni 2021-06-18 09:55:13 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1894/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 7 Alexandre Belloni 2021-06-20 16:59:35 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1906/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 8 Alexandre Belloni 2021-06-20 17:27:43 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1910/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 9 Alexandre Belloni 2021-06-24 14:30:05 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1914/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 10 Alexandre Belloni 2021-06-30 22:58:30 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1928/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 11 Alexandre Belloni 2021-06-30 23:07:42 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1937/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 12 Alexandre Belloni 2021-07-04 13:53:14 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1952/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 13 Alexandre Belloni 2021-07-15 13:41:08 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1981/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 14 Alexandre Belloni 2021-07-15 13:52:00 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1987/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 15 Alexandre Belloni 2021-07-22 12:36:32 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2009/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 16 Alexandre Belloni 2021-07-22 12:37:48 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2008/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 17 Alexandre Belloni 2021-07-22 12:46:20 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2000/steps/12/logs/stdio
qemuarm64-ptest ubuntu1804-arm-1
Comment 18 Alexandre Belloni 2021-07-22 12:58:56 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/1998/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 19 Alexandre Belloni 2021-07-22 13:16:15 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2279/steps/12/logs/stdio

qemux86-64-ptest debian10-ty-2
Comment 20 Alexandre Belloni 2021-08-11 10:28:06 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2322/steps/12/logs/stdio

qemux86-64-ptest ubuntu1804-ty-3
Comment 21 Alexandre Belloni 2021-08-11 20:27:44 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2058/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 22 Alexandre Belloni 2021-08-11 21:55:30 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2063/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 23 Randy MacLeod 2021-08-12 14:43:51 UTC
May be gone now that the ptest timeout has increased from 300 to 450.
Comment 24 Alexandre Belloni 2021-08-12 21:32:27 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2079/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 25 Alexandre Belloni 2021-08-13 12:50:52 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2085/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 26 Richard Purdie 2021-08-18 18:52:05 UTC
The timeout change hasn't helped. It is occurring on x86 too.

hardknott x86:
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2333
https://autobuilder.yocto.io/pub/non-release/20210731-9/testresults/qemux86-64-ptest/lttng-tools.log

master x86 (with 2.13 modules):

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2387
https://autobuilder.yocto.io/pub/non-release/20210818-6/testresults/qemux86-64-ptest/lttng-tools.log

Both ending around:

PASS: tools/clear/test_ust 680 - Stop lttng tracing for session nJIXDvYTFaN7px05
PASS: tools/clear/test_ust 681 - Validate empty trace
PASS: tools/clear/test_ust 682 - Destroy session nJIXDvYTFaN7px05
PASS: tools/clear/test_ust 683 - Create session MAjAiVUM6uiSp6M8 with uri:net://localhost and opts: --live
PASS: tools/clear/test_ust 684 - Enable chan
Comment 27 Richard Purdie 2021-08-18 19:00:12 UTC
In the dmesg for https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2387

[ 2062.251323] LTTng: block device enumeration is not supported by kernel
[ 2063.097478] LTTng: Unloaded modules v2.13.0 (Nordicité)
[ 2073.006713] LTTng: Loaded modules v2.13.0 (Nordicité)
[ 2192.446591] lttng-relayd[28473]: segfault at 28 ip 00005638268743aa sp 00007fba09d269a8 error 4 in lttng-relayd[56382684b000+48000]
[ 2192.448052] Code: 00 00 00 0f 94 c0 c3 66 0f 1f 84 00 00 00 00 00 b8 01 00 00 00 c3 66 2e 0f 1f 84 00 00 00 00 00 48 be ff ff ff ff ff ff ff 7f <48> 8b 57 28 eb 03 48 89 c2 48 85 d2 74 20 48 39 f2 74 1b 48 8d 4a
[ 3838.908502] scsi_debug:sdebug_driver_probe: scsi_debug: trim poll_queues to 0. poll_q/nr_hw = (0/1)
[ 3838.909597] scsi host6: scsi_debug: version 0190 [20200710]
[ 3838.909597]   dev_size_mb=90, opts=0x0, submit_queues=1, statistics=0

i.e. a segfault in lttng-relayd which may be related to the hang
Comment 28 Richard Purdie 2021-08-19 14:29:43 UTC
I have the lttng-relayd binary that faulted. Looking at the binary:

00033350: 4839 f774 3b48 85ff 0f95 c148 85f6 0f95  H9.t;H.....H....
00033360: c231 c038 d175 2e80 bfb0 0000 0000 b801  .1.8.u..........
00033370: 0000 0074 2048 8b86 b800 0000 4839 87b8  ...t H......H9..
00033380: 0000 000f 94c0 c366 0f1f 8400 0000 0000  .......f........
00033390: b801 0000 00c3 662e 0f1f 8400 0000 0000  ......f.........
000333a0: 48be ffff ffff ffff ff7f 488b 5728 eb03  H.........H.W(..
000333b0: 4889 c248 85d2 7420 4839 f274 1b48 8d4a  H..H..t H9.t.H.J
000333c0: 0148 89d0 f048 0fb1 4f28 4839 c275 e1b8  .H...H..O(H9.u..

which then disassembled gives:

0000000000033350 <lttng_trace_chunk_ids_equal>:
   33350:	48 39 f7             	cmp    %rsi,%rdi
   33353:	74 3b                	je     33390 <lttng_trace_chunk_ids_equal+0x40>
   33355:	48 85 ff             	test   %rdi,%rdi
   33358:	0f 95 c1             	setne  %cl
   3335b:	48 85 f6             	test   %rsi,%rsi
   3335e:	0f 95 c2             	setne  %dl
   33361:	31 c0                	xor    %eax,%eax
   33363:	38 d1                	cmp    %dl,%cl
   33365:	75 2e                	jne    33395 <lttng_trace_chunk_ids_equal+0x45>
   33367:	80 bf b0 00 00 00 00 	cmpb   $0x0,0xb0(%rdi)
   3336e:	b8 01 00 00 00       	mov    $0x1,%eax
   33373:	74 20                	je     33395 <lttng_trace_chunk_ids_equal+0x45>
   33375:	48 8b 86 b8 00 00 00 	mov    0xb8(%rsi),%rax
   3337c:	48 39 87 b8 00 00 00 	cmp    %rax,0xb8(%rdi)
   33383:	0f 94 c0             	sete   %al
   33386:	c3                   	retq   
   33387:	66 0f 1f 84 00 00 00 	nopw   0x0(%rax,%rax,1)
   3338e:	00 00 
   33390:	b8 01 00 00 00       	mov    $0x1,%eax
   33395:	c3                   	retq   
   33396:	66 2e 0f 1f 84 00 00 	nopw   %cs:0x0(%rax,%rax,1)
   3339d:	00 00 00
Comment 29 Richard Purdie 2021-08-19 15:53:21 UTC
I think I decoded that wrong and the fault was in the next function:

00000000000333a0 <lttng_trace_chunk_get>:
   333a0:	48 be ff ff ff ff ff 	movabs $0x7fffffffffffffff,%rsi
   333a7:	ff ff 7f 
   333aa:	48 8b 57 28          	mov    0x28(%rdi),%rdx
   333ae:	eb 03                	jmp    333b3 <lttng_trace_chunk_get+0x13>
   333b0:	48 89 c2             	mov    %rax,%rdx
   333b3:	48 85 d2             	test   %rdx,%rdx
   333b6:	74 20                	je     333d8 <lttng_trace_chunk_get+0x38>
   333b8:	48 39 f2             	cmp    %rsi,%rdx
   333bb:	74 1b                	je     333d8 <lttng_trace_chunk_get+0x38>
   333bd:	48 8d 4a 01          	lea    0x1(%rdx),%rcx
   333c1:	48 89 d0             	mov    %rdx,%rax
   333c4:	f0 48 0f b1 4f 28    	lock cmpxchg %rcx,0x28(%rdi)
   333ca:	48 39 c2             	cmp    %rax,%rdx
   333cd:	75 e1                	jne    333b0 <lttng_trace_chunk_get+0x10>
   333cf:	b8 01 00 00 00       	mov    $0x1,%eax
   333d4:	c3                   	retq   
   333d5:	0f 1f 00             	nopl   (%rax)
   333d8:	31 c0                	xor    %eax,%eax
   333da:	c3                   	retq   
   333db:	0f 1f 44 00 00       	nopl   0x0(%rax,%rax,1)
Comment 30 Richard Purdie 2021-08-26 16:17:24 UTC
https://bugs.lttng.org/issues/1323
Comment 31 Alexandre Belloni 2021-09-16 08:53:15 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2100/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 32 Alexandre Belloni 2021-09-23 11:56:31 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2545/steps/12/logs/stdio
qemux86-64-ptest fedora33-ty-1
Comment 33 Alexandre Belloni 2021-09-23 21:24:34 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2571/steps/13/logs/stdio
qemux86-64-ptest debian8-ty-1
Comment 34 Oleksiy Obitotskyy 2021-09-26 13:40:06 UTC
qemux86-64-ptest centos7-ty-4

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2589

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:
{'libevent': ['[monotonic_prc_fallback_FAILED]'],
 'lttng-tools': '2021-09-25T13:03\n'
                '2021-09-25T13:03\n'
                'PASS: ini_config/test_ini_config 1 - Successfully opened a '
                'config file, registered to all sections\n'
                'PASS: ini_config/test_ini_config 2 - Processed entries from '
                'each sections\n'
                'PASS: ini_config/test_ini_config 3 - Text value parsed '
                'correctly\n'
                'PASS: ini_config/test_ini_config 4 - Successfully opened a '
                'config file, registered to one section\n'
...
very long list skipped
Comment 35 Oleksiy Obitotskyy 2021-09-26 14:50:06 UTC
qemuarm64-ptest ubuntu1804-arm-1 

https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2299
Comment 36 Oleksiy Obitotskyy 2021-09-28 04:50:17 UTC
qemux86-64-ptest tumbleweed-ty-3 

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2602
Comment 37 Randy MacLeod 2021-09-30 15:14:48 UTC
If this happens again, collect the qemu dmesg and maybe ping AlexB or RP.
Comment 38 Naveen Saini 2021-10-04 05:10:33 UTC
qemuarm64-ptest ubuntu1804-arm-1 (master-next)

https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2332



AssertionError: Failed ptests:
{'lttng-tools': ['tools/notification/test_notification_multi_app_5_-_Waiting_message:_error_logged_see_file_content:_sync:_ready,_/tmp/tmp.XXXXXXXXXXmulti_app_output_dir.xs7hEX/low_app_output_file_0',
                 'tools/notification/test_notification_multi_app_6_-_Waiting_message:_error_logged_see_file_content:_sync:_ready,_/tmp/tmp.XXXXXXXXXXmulti_app_output_dir.xs7hEX/high_app_output_file_0',
                 'tools/notification/test_notification_multi_app_7_-_Start_tracing_for_session_my_session',
                 'tools/notification/test_notification_multi_app_8_-_Waiting_message:_error_logged_see_file_content:_notification:_high_0,_/tmp/tmp.XXXXXXXXXXmulti_app_output_dir.xs7hEX/high_app_output_file_0',
                 'tools/notification/test_notification_multi_app_9_-_Stop_lttng_tracing_for_session_my_session',
                 'tools/notification/test_notification_multi_app_10_-_Waiting_message:_error_logged_see_file_content:_notification:_low_0,_/tmp/tmp.XXXXXXXXXXmulti_app_output_dir.xs7hEX/low_app_output_file_0',
                 'tools/notification/test_notification_multi_app_11_-_Notifications_0_received',
                 'tools/notification/test_notification_multi_app_12_-_Waiting_message:_error_logged_see_file_content:_exit:_0,_/tmp/tmp.XXXXXXXXXXmulti_app_output_dir.xs7hEX/low_app_output_file_0',
                 'tools/notification/test_notification_multi_app_13_-_Application_for_low_notification_terminated_normally',
                 'tools/notification/test_notification_multi_app_14_-_Waiting_message:_error_logged_see_file_content:_exit:_0,_/tmp/tmp.XXXXXXXXXXmulti_app_output_dir.xs7hEX/high_app_output_file_0',
                 'tools/notification/test_notification_multi_app_15_-_Application_for_high_notification_terminated_normally',
                 'tools/notification/test_notification_multi_app_16_-_Destroy_session_my_session',
                 'tools/notification/test_notification_multi_app_17_-_No_session_daemon_to_kill'],
Comment 39 Naveen Saini 2021-10-04 05:34:48 UTC
On master-next:
qemux86-64-ptest, ubuntu1604-ty-1

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2627
Comment 40 Naveen Saini 2021-10-04 07:48:22 UTC
On master-next:

qemux86-64-ptest, debian10-ty-3
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2630


qemuarm64-ptest, ubuntu2004-arm-1
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2337
Comment 41 Thomas Perrot 2021-10-11 11:46:14 UTC
On master-next:

qemux86-64, debian10-ty-1

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2662/steps/12/logs/stdio
Comment 42 Thomas Perrot 2021-10-13 09:56:23 UTC
On master-next:

https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2388/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 43 Richard Purdie 2021-10-25 10:34:08 UTC
https://bugs.lttng.org/issues/1323 has updated info on where this is coming from with a better backtrace
Comment 44 Alexandre Belloni 2021-10-27 21:34:51 UTC
qemux86-64-ptest debian11-ty-1

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2731/steps/12/logs/stdio
Comment 46 Chee Yang 2021-11-08 14:08:51 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2741/steps/12/logs/stdio
debian10-ty-1
qemux86-64-ptest
Comment 47 Chee Yang 2021-11-09 02:29:43 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2761/steps/12/logs/stdio
ubuntu1804-ty-3
qemux86-64-ptest
Comment 48 Chee Yang 2021-11-09 09:59:29 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2770/steps/12/logs/stdio
fedora33-ty-1
qemux86-64-ptest
Comment 49 Chee Yang 2021-11-09 13:21:15 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2498/steps/12/logs/stdio
ubuntu2004-arm-1
qemuarm64-ptest
Comment 50 Chee Yang 2021-11-09 14:11:26 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2767/steps/12/logs/stdio
tumbleweed-ty-3  qemux86-64-ptest
Comment 51 Minjae Kim 2021-11-17 06:21:47 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2833/steps/12/logs/stdio
qemux86-64-ptest
AssertionError: Failed ptests:
{'lttng-tools': '2021-11-16T01:33\n'
                '2021-11-16T01:33\n'
                'PASS: ini_config/test_ini_config 1 - Successfully opened a '
                'config file, registered to all sections\n'
                'PASS: ini_config/test_ini_config 2 - Processed entries from '
                'each sections\n'
                'PASS: ini_config/test_ini_config 3 - Text value parsed '
                'correctly\n'
                'PASS: ini_config/test_ini_config 4 - Successfully opened a '
                'config file, registered to one section\n'
                'PASS: ini_config/test_ini_config 5 - Processed an entry from '
                'section1 only\n'
                'PASS: ini_config/test_ini_config 6 - Int value parsed '
                'correctly\n'
                'PASS: ini_config/test_ini_config 7 - Successfully opened a '
                'config file, registered to the global section\n'
                'PASS: ini_config/test_ini_config 8 - Processed an entry from '
                'the global section only\n'
                'PASS: test_action 1 - Create notify action\n'
                'PASS: test_action 2 - Action has type '
                'LTTNG_ACTION_TYPE_NOTIFY\n'
                'PASS: test_action 3 - Default policy is every n=1\n'
                'PASS: test_action 4 - Set rate policy\n'
Comment 52 Minjae Kim 2021-11-17 06:33:12 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2826/steps/12/logs/stdio

qemux86-64-ptest2826


AssertionError: Failed ptests:
{'lttng-tools': '2021-11-13T16:57\n'
                '2021-11-13T16:57\n'
                'PASS: ini_config/test_ini_config 1 - Successfully opened a '
                'config file, registered to all sections\n'
                'PASS: ini_config/test_ini_config 2 - Processed entries from '
Comment 53 Alexandre Belloni 2021-12-08 16:19:47 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2850

debian11-ty-1
Comment 54 Alexandre Belloni 2021-12-08 16:43:27 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2847/steps/12/logs/stdio

qemux86-64-ptest centos8-ty-1
Comment 57 Richard Purdie 2021-12-14 11:41:48 UTC
Even with the patch applied we still have https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2648/steps/12/logs/stdio on arm so I suspect we have at least two different issues in this bug.
Comment 58 Richard Purdie 2021-12-14 12:01:10 UTC
I did a quick analysis of the last few hangs. If you grep the log output for gawk, you can see which test was running nearby. My quick collation showed:


https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2826/steps/12/logs/stdio
qemux86-64-ptest
tools/notification/test_notification_kernel_instrumentation\

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2850/steps/12/logs/stdio
debian11-ty-1
tools/notification/test_notification_kernel_capture

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2847/steps/12/logs/stdio
qemux86-64-ptest centos8-ty-1
tools/notification/test_notification_ust_capture

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2900/steps/12/logs/stdio
qemux86-64-ptest ubuntu2004-ty-2
tools/notification/test_notification_kernel_capture

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2903/steps/12/logs/stdio
qemux86-64-ptest fedora33-ty-1
tools/notification/test_notification_kernel_error

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/2905/steps/12/logs/stdio
qemux86-64-ptest ubuntu1804-ty-3
tools/notification/test_notification_ust_buffer_usage

https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2648/steps/12/logs/stdio
ubuntu1804-arm-1
tools/notification/test_notification_kernel_userspace_probe

i.e. it seems to be the notification tests which hang
Comment 59 Alexandre Belloni 2022-01-07 16:28:51 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/2648/steps/12/logs/stdio
qemuarm64-ptest ubuntu1804-arm-1
Comment 60 Alexandre Belloni 2022-01-26 23:22:50 UTC
qemux86-64-ptest fedora35-ty-2 SSD

{'lttng-tools': ['tools/clear/test_kernel_376_-_Clear_session_mMbF3SDlSiZcAeu1',
                 'tools/clear/test_kernel_377_-_Start_tracing_for_session_mMbF3SDlSiZcAeu1',
                 'tools/clear/test_kernel_378_-_Stop_lttng_tracing_for_session_mMbF3SDlSiZcAeu1',
                 'tools/clear/test_kernel_379_-_Destroy_session_mMbF3SDlSiZcAeu1']}
Comment 61 Chee Yang 2022-03-02 06:09:35 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3162/steps/12/logs/stdio
qemux86-64-ptest ubuntu1804-ty-3 Non-SSD
Comment 62 Randy MacLeod 2022-04-11 16:13:18 UTC
There are 61 big fixes available if we upgrade on the stable branch: 
$ git log --oneline v2.13.4..v2.13.6 | wc -l
61
https://github.com/lttng/lttng-tools/releases/tag/v2.13.6
Comment 63 Alexandre Belloni 2022-04-11 16:16:37 UTC
This has been attempted and this release comes with its own set of ptest failures that needs to be fixed.
Comment 64 Luca Ceresoli 2022-05-03 14:36:50 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/3201/steps/12/logs/stdio

qemuarm64-ptest on ubuntu1804-arm-1
Comment 65 Randy MacLeod 2022-05-05 14:44:07 UTC
We may be able to have a student work on this later in May if Alex doesn't fix it first.
Comment 66 Luca Ceresoli 2022-05-11 12:45:39 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/3240/steps/12/logs/stdio

qemuarm64-ptest on ubuntu1804-arm-1
Comment 67 Alexandre Belloni 2022-05-19 11:10:36 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3427

qemux86-64-ptest alma8-ty-2
Comment 68 Alexandre Belloni 2022-05-19 12:49:35 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3449/steps/12/logs/stdio

qemux86-64-ptest alma8-ty-2
Comment 70 Steve Sakoman 2022-07-07 22:47:43 UTC
kirkstone

https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3702/steps/12/logs/stdio

qemux86-64-ptest ubuntu2204-ty2
Comment 71 Luca Ceresoli 2022-07-25 12:25:03 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3780/steps/13/logs/stdio

qemux86-64-ptest on alma8-ty-1

master-next
Comment 72 Alexandre Belloni 2022-08-11 12:57:54 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/3552/steps/12/logs/stdio

qemuarm64-ptest ubuntu2204-arm-1
Comment 73 Alexandre Belloni 2022-08-11 14:54:30 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3849/steps/12/logs/stdio

qemux86-64-ptest debian11-ty-2
Comment 74 Alexandre Belloni 2022-08-16 17:10:08 UTC
https://autobuilder.yoctoproject.org/typhoon/#builders/81/builds/3850/steps/12/logs/stdio

qemux86-64-ptest alma9-ty-2
Comment 75 Alexandre Belloni 2022-08-16 18:54:42 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/3857/steps/12/logs/stdio

qemux86-64-ptest alma9-ty-2
Comment 76 Alexandre Belloni 2022-09-07 21:25:29 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/3772/steps/12/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 77 Alexandre Belloni 2022-10-14 16:29:54 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/4115/steps/12/logs/stdio

This shows a kernel oops in lttng_stream_ring_buffer_ioctl which I suspect is what this bug is about
Comment 78 Alexandre Belloni 2022-11-03 10:07:23 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/3984/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 79 Alexandre Belloni 2022-11-10 13:28:36 UTC
https://autobuilder.yoctoproject.org/typhoon/#builders/82/builds/4007/steps/12/logs/stdio
qemuarm64-ptest ubuntu2004-arm-1
Comment 80 Alexandre Belloni 2022-12-22 16:00:48 UTC
https://autobuilder.yoctoproject.org/typhoon/#builders/82/builds/4208/steps/13/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 81 Alexandre Belloni 2023-02-16 15:50:36 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/4631/steps/13/logs/stdio

qemux86-64-ptest opensuse154-ty-1
Comment 82 Randy MacLeod 2023-06-15 14:51:36 UTC
Appears to have been fixed or gone away.
Comment 83 João Marcos Costa 2024-01-17 09:55:49 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/6117/steps/12/logs/stdio

qemux86-64-ptest ubuntu2204-ty-3
Comment 84 João Marcos Costa 2024-01-17 13:56:23 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/5824/steps/12/logs/stdio

qemux86-64-ptest ubuntu2204-ty-3
Comment 85 João Marcos Costa 2024-02-28 10:13:20 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/6211/steps/13/logs/stdio

qemux86-64-ptest opensuse154-ty-1
Comment 86 João Marcos Costa 2024-04-23 11:05:40 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/6341/steps/12/logs/stdio

qemuarm64-ptest ubuntu2004-arm-1
Comment 87 João Marcos Costa 2024-07-22 08:47:54 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/6828/steps/13/logs/stdio

qemux86-64-ptest opensuse154-ty-3
Comment 88 João Marcos Costa 2024-07-26 08:30:37 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/81/builds/6843/steps/12/logs/stdio

qemux86-64-ptest fedora38-ty-6

Reopening, since it is the second time it happened in the last 6 days.
Comment 89 Alexandre Belloni 2024-08-07 22:15:24 UTC
Created attachment 5065 [details]
lttng test log
Comment 90 João Marcos Costa 2024-08-19 12:28:07 UTC
different from the other timeout-like errors:

Failed ptests:
{'lttng-tools': ['tools/clear/test_kernel_649_-_Destroy_session_Xqenz4YPB3Ysr9vv',
                 'tools/clear/test_kernel']}


https://autobuilder.yoctoproject.org/typhoon/#/builders/82/builds/6696/steps/13/logs/stdio

qemuarm64-ptest ubuntu1804-arm-1
Comment 91 Alexandre Belloni 2024-08-21 18:00:32 UTC
Created attachment 5067 [details]
test_kernel log from the previous ptest failure
Comment 92 João Marcos Costa 2025-02-03 16:43:49 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/61/builds/864/steps/12/logs/stdio

Failed ptests:
{'lttng-tools': ['tools/clear/test_ust_984_-_Read_a_total_of_3_events,_expected_5',
                 'tools/clear/test_ust']}

qemuarm64-ptest ubuntu2204-vk-arm1
Comment 93 João Marcos Costa 2025-02-14 13:47:22 UTC
https://autobuilder.yoctoproject.org/valkyrie/?#/builders/73/builds/677/steps/12/logs/stdio

qemux86-64-ptest alma9-vk-1
Comment 94 João Marcos Costa 2025-02-14 13:48:52 UTC
https://valkyrie.yoctoproject.org/#/builders/73/builds/631/steps/12/logs/stdio

qemux86-64-ptest alma9-vk-1
Comment 95 João Marcos Costa 2025-02-21 08:48:55 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/987/steps/13/logs/stdio

qemux86-64-ptest opensuse156-vk-1
Comment 96 João Marcos Costa 2025-03-21 14:21:12 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/1166/steps/13/logs/stdio

qemux86-64-ptest opensuse156-vk-1
Comment 97 João Marcos Costa 2025-09-01 08:07:47 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/2198/steps/12/logs/stdio

qemux86-64-ptest ubuntu2204-vk-3
Comment 98 João Marcos Costa 2025-09-29 08:27:17 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/61/builds/2320/steps/13/logs/stdio

qemuarm64-ptest ubuntu2404-vk-arm1
Comment 100 João Marcos Costa 2026-08-31 09:21:20 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/61/builds/4406/steps/15/logs/stdio

qemuarm64-ptest stream10-vk-arm1

The last part of the logs, right before the boot logs, are here. I'm reopening this one, as I don't see any currently open lttng-tools bug that seems directly related to this timeout. Please correct me otherwise.

---

'PASS: tools/client/test_warn_on_shm_too_small.py 9 - Warning '
'not present in lttng client output when starting session\n'
'PASS: tools/client/test_warn_on_shm_too_small.py 10 - Warning '
'present in lttng client output when starting session\n'
'PASS: tools/client/test_warn_on_shm_too_small.py 11 - Warning '
'not present in lttng client output when starting session\n'
'PASS: tools/channel/test_channel_allocation_policy_per_cpu.py '
"1 - Cannot add `cpu_id' context when channel allocation "
"policy is 'per-cpu'\n"
'PASS: '
'tools/notification/test_notification_ust_buffer_usage.py 1 - '
'Subscription test program completed successfully: '
'returncode=0\n'
'PASS: '
'tools/notification/test_notification_ust_buffer_usage.py 2 - '
'Subscription test program completed successfully: '
'returncode=0\n'
'PASS: '
'tools/notification/test_notification_ust_buffer_usage.py 3 - '
'Trigger test program completed successfully: returncode=0\n'
'PASS: '
'tools/notification/test_notification_ust_buffer_usage.py 4 - '
'Trigger test program completed successfully: returncode=0\n'
'Timeout! System state:\n'
'Collected system state:\n'
'+ dmesg\n'
'[    0.000000] Booting Linux on physical CPU 0x0000000000 '
'[0x413fd0c1]\n'
'[    0.000000] Linux version 6.18.44-yocto-standard '
'(oe-user@oe-host) (aarch64-poky-linux-gcc (GCC) 16.2.0, GNU '
Comment 101 João Marcos Costa 2026-08-31 09:23:11 UTC
https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/4431/steps/15/logs/stdio

qemux86-64-ptest opensuse160-vk-2
Comment 102 Randy MacLeod 2026-09-03 14:54:13 UTC
Last issue happened on master-next, but a different version of lttng-tools upgrade was merged to master so this should not happen again.