canonical-ubuntu-qa team mailing list archive
-
canonical-ubuntu-qa team
-
Mailing list archive
-
Message #05989
[Bug 2092885] Re: Leftover process from ubuntu_kselftests_net/tls make test unable to finish properly on f/ein
Tested with test case in f-5.15, there are still ./tls processes after the test. With similar dmesg output:
[ 36.976649] audit: type=1400 audit(1735870467.499:103): apparmor="DENIED" operation="open" profile="/usr/sbin/ntpd" name="/snap/bin/" pid=2211 comm="ntpd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
[ 1088.454878] INFO: task tls:2797 blocked for more than 120 seconds.
[ 1088.454909] Not tainted 5.4.0-1062-ein #70-Ubuntu
[ 1088.454924] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1088.454946] tls D 0 2797 1 0x00000001
[ 1088.454955] Call trace:
[ 1088.454973] __switch_to+0x100/0x150
[ 1088.454984] __schedule+0x33c/0x890
[ 1088.454990] schedule+0x4c/0xe8
[ 1088.455001] schedule_timeout+0x290/0x368
[ 1088.455010] wait_for_completion+0xa0/0x130
[ 1088.455032] tls_encrypt_async_wait+0xb8/0xc8 [tls]
[ 1088.455045] tls_push_record+0x5f4/0x948 [tls]
[ 1088.455060] bpf_exec_tx_verdict+0x98/0x620 [tls]
[ 1088.455075] tls_sw_sendmsg+0x26c/0x690 [tls]
[ 1088.455086] inet_sendmsg+0x50/0x78
[ 1088.455093] __sock_sendmsg+0x58/0x68
[ 1088.455102] __sys_sendto+0xe8/0x158
[ 1088.455110] __arm64_sys_sendto+0x34/0x48
[ 1088.455119] el0_svc_common.constprop.0+0xf4/0x200
[ 1088.455127] el0_svc_handler+0x38/0xb8
[ 1088.455135] el0_svc+0x10/0x140
--
You received this bug notification because you are a member of Canonical
Platform QA Team, which is subscribed to ubuntu-kernel-tests.
https://bugs.launchpad.net/bugs/2092885
Title:
Leftover process from ubuntu_kselftests_net/tls make test unable to
finish properly on f/ein
Status in ubuntu-kernel-tests:
New
Bug description:
Issue found on f/ein-5.4.0-1062.70
Test output:
$ sudo ./tls
[==========] Running 48 tests from 3 test cases.
[ RUN ] tls_basic.base_base
[ OK ] tls_basic.base_base
[ RUN ] tls.sendfile
[ OK ] tls.sendfile
[ RUN ] tls.send_then_sendfile
[ OK ] tls.send_then_sendfile
[ RUN ] tls.recv_max
[ OK ] tls.recv_max
[ RUN ] tls.recv_small
[ OK ] tls.recv_small
[ RUN ] tls.msg_more
[ OK ] tls.msg_more
[ RUN ] tls.msg_more_unsent
[ OK ] tls.msg_more_unsent
[ RUN ] tls.sendmsg_single
[ OK ] tls.sendmsg_single
[ RUN ] tls.sendmsg_fragmented
[ OK ] tls.sendmsg_fragmented
[ RUN ] tls.sendmsg_large
[ OK ] tls.sendmsg_large
[ RUN ] tls.sendmsg_multiple
[ OK ] tls.sendmsg_multiple
[ RUN ] tls.sendmsg_multiple_stress
[ OK ] tls.sendmsg_multiple_stress
[ RUN ] tls.splice_from_pipe
[ OK ] tls.splice_from_pipe
[ RUN ] tls.splice_from_pipe2
[ OK ] tls.splice_from_pipe2
[ RUN ] tls.send_and_splice
[ OK ] tls.send_and_splice
[ RUN ] tls.splice_to_pipe
[ OK ] tls.splice_to_pipe
[ RUN ] tls.recvmsg_single
[ OK ] tls.recvmsg_single
[ RUN ] tls.recvmsg_single_max
[ OK ] tls.recvmsg_single_max
[ RUN ] tls.recvmsg_multiple
[ OK ] tls.recvmsg_multiple
[ RUN ] tls.single_send_multiple_recv
[ OK ] tls.single_send_multiple_recv
[ RUN ] tls.multiple_send_single_recv
[ OK ] tls.multiple_send_single_recv
[ RUN ] tls.single_send_multiple_recv_non_align
[ OK ] tls.single_send_multiple_recv_non_align
[ RUN ] tls.recv_partial
[ OK ] tls.recv_partial
[ RUN ] tls.recv_nonblock
[ OK ] tls.recv_nonblock
[ RUN ] tls.recv_peek
[ OK ] tls.recv_peek
[ RUN ] tls.recv_peek_multiple
[ OK ] tls.recv_peek_multiple
[ RUN ] tls.recv_peek_multiple_records
[ OK ] tls.recv_peek_multiple_records
[ RUN ] tls.recv_peek_large_buf_mult_recs
[ OK ] tls.recv_peek_large_buf_mult_recs
[ RUN ] tls.recv_lowat
[ OK ] tls.recv_lowat
[ RUN ] tls.bidir
[ OK ] tls.bidir
[ RUN ] tls.pollin
[ OK ] tls.pollin
[ RUN ] tls.poll_wait
[ OK ] tls.poll_wait
[ RUN ] tls.poll_wait_split
[ OK ] tls.poll_wait_split
[ RUN ] tls.blocking
[ OK ] tls.blocking
[ RUN ] tls.nonblocking
tls.c:903:tls.nonblocking:Expected 0 (0) != eagain (0)
tls.nonblocking: Test failed at step #8
[ FAIL ] tls.nonblocking
[ RUN ] tls.mutliproc_even
Alarm clock
And there will be leftover tls processes:
$ ps aux |grep tls
root 2677 0.0 0.0 1984 88 pts/0 S 10:28 0:00 ./tls
root 2678 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2679 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2681 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2682 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2683 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2684 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2685 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2686 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2687 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2688 0.0 0.0 1984 140 pts/0 D 10:28 0:00 ./tls
root 2689 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
root 2690 0.0 0.0 1984 140 pts/0 S 10:28 0:00 ./tls
Consequently these leftover processes will make the
ubuntu_kselftests_net test unable to finish properly. And leads to a
sut-test failure in the end.
syslog output:
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1270] dhcp4 (eno1): option dhcp_lease_time => '600'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1271] dhcp4 (eno1): option domain_name => 'maas'
Jan 2 10:31:32 asus-pe100a dbus-daemon[929]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.10' (uid=0 pid=930 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1272] dhcp4 (eno1): option domain_name_servers => '10.102.160.1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1273] dhcp4 (eno1): option domain_search => 'maas'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1273] dhcp4 (eno1): option expiry => '1735814492'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1274] dhcp4 (eno1): option ip_address => '10.102.163.95'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1274] dhcp4 (eno1): option next_server => '10.102.160.2'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1275] dhcp4 (eno1): option ntp_servers => '10.102.160.2'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1275] dhcp4 (eno1): option requested_broadcast_address => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1276] dhcp4 (eno1): option requested_domain_name => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1277] dhcp4 (eno1): option requested_domain_name_servers => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1277] dhcp4 (eno1): option requested_domain_search => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1278] dhcp4 (eno1): option requested_host_name => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1278] dhcp4 (eno1): option requested_interface_mtu => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1279] dhcp4 (eno1): option requested_ms_classless_static_routes => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1279] dhcp4 (eno1): option requested_nis_domain => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1280] dhcp4 (eno1): option requested_nis_servers => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1281] dhcp4 (eno1): option requested_ntp_servers => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1281] dhcp4 (eno1): option requested_rfc3442_classless_static_routes => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1282] dhcp4 (eno1): option requested_root_path => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1283] dhcp4 (eno1): option requested_routers => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1283] dhcp4 (eno1): option requested_static_routes => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1284] dhcp4 (eno1): option requested_subnet_mask => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1284] dhcp4 (eno1): option requested_time_offset => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1285] dhcp4 (eno1): option requested_wpad => '1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1285] dhcp4 (eno1): option routers => '10.102.160.1'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1286] dhcp4 (eno1): option subnet_mask => '255.255.252.0'
Jan 2 10:31:32 asus-pe100a NetworkManager[930]: <info> [1735813892.1287] dhcp4 (eno1): state changed bound -> extended
Jan 2 10:31:32 asus-pe100a systemd[1]: Starting Network Manager Script Dispatcher Service...
Jan 2 10:31:32 asus-pe100a dbus-daemon[929]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Jan 2 10:31:32 asus-pe100a systemd[1]: Started Network Manager Script Dispatcher Service.
Jan 2 10:31:35 asus-pe100a dbus-daemon[929]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.19' (uid=0 pid=948 comm="/usr/lib/snapd/snapd " label="unconfined")
Jan 2 10:31:35 asus-pe100a systemd[1]: Starting Time & Date Service...
Jan 2 10:31:35 asus-pe100a dbus-daemon[929]: [system] Successfully activated service 'org.freedesktop.timedate1'
Jan 2 10:31:35 asus-pe100a systemd[1]: Started Time & Date Service.
Jan 2 10:31:42 asus-pe100a systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Jan 2 10:32:05 asus-pe100a systemd[1]: systemd-timedated.service: Succeeded.
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485041] INFO: task tls:2688 blocked for more than 120 seconds.
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485071] Not tainted 5.4.0-1062-ein #70-Ubuntu
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485087] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485108] tls D 0 2688 2677 0x00000000
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485118] Call trace:
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485134] __switch_to+0x100/0x150
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485144] __schedule+0x33c/0x890
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485151] schedule+0x4c/0xe8
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485162] schedule_timeout+0x290/0x368
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485171] wait_for_completion+0xa0/0x130
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485192] tls_encrypt_async_wait+0xb8/0xc8 [tls]
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485206] tls_push_record+0x5f4/0x948 [tls]
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485221] bpf_exec_tx_verdict+0x98/0x620 [tls]
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485234] tls_sw_sendmsg+0x26c/0x690 [tls]
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485244] inet_sendmsg+0x50/0x78
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485252] __sock_sendmsg+0x58/0x68
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485261] __sys_sendto+0xe8/0x158
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485267] __arm64_sys_sendto+0x34/0x48
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485276] el0_svc_common.constprop.0+0xf4/0x200
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485283] el0_svc_handler+0x38/0xb8
Jan 2 10:32:10 asus-pe100a kernel: [ 363.485290] el0_svc+0x10/0x140
^[
To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-kernel-tests/+bug/2092885/+subscriptions
References