Bug #6477
openstream test fails on jenkins due to different loop iterations in the test
0%
Description
The timestamps at the start of the line differed here:
https://jenkins.osmocom.org/jenkins/job/master-libosmo-netif/a1=default,a2=default,a3=default,a4=default,label=osmocom-master/9036/
Assigning to Daniel as discussed in the weekly meeting.
======================== ./libosmo-netif-1.4.0.55-6930/_build/sub/tests/testsuite.dir/1/testsuite.log
# -*- compilation -*-
1. testsuite.at:4: testing stream_test ...
../../../tests/testsuite.at:8: $abs_top_builddir/tests/stream/stream_test
--- expout 2024-06-04 00:47:30.121741976 +0000
+++ /build/libosmo-netif-1.4.0.55-6930/_build/sub/tests/testsuite.dir/at-groups/1/stdout 2024-06-04 00:47:30.397747245 +0000
@@ -169,21 +169,21 @@
{20.625031} [NA|OK] Server's send_last_third_srv(): Sending:[ Last third of IPAC_MSGT_ID_GET | IPAC_MSGT_PONG | IPAC_MSGT_PONG ]
{20.625031} [NA|OK] Server's send_last_third_srv(): (msg dump: 01 01 00 01 fe 01 00 01 fe 01 )
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): [5-cli] Received message from stream (len = 3)
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): msg buff data: 04 01 01
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): IPA payload: 04 01 01
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): Type: IPAC_MSGT_ID_GET
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): (msg dump (including stripped headers): 00 03 fe 04 01 01 )
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): [6-cli] Received message from stream (len = 1)
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): msg buff data: 01
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): IPA payload: 01
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): Type: IPAC_MSGT_PONG
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): (msg dump (including stripped headers): 00 01 fe 01 )
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): [7-cli] Received message from stream (len = 1)
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): msg buff data: 01
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): IPA payload: 01
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): Type: IPAC_MSGT_PONG
-{20.625033} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): (msg dump (including stripped headers): 00 01 fe 01 )
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): [5-cli] Received message from stream (len = 3)
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): msg buff data: 04 01 01
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): IPA payload: 04 01 01
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): Type: IPAC_MSGT_ID_GET
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): (msg dump (including stripped headers): 00 03 fe 04 01 01 )
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): [6-cli] Received message from stream (len = 1)
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): msg buff data: 01
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): IPA payload: 01
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): Type: IPAC_MSGT_PONG
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): (msg dump (including stripped headers): 00 01 fe 01 )
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): [7-cli] Received message from stream (len = 1)
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): msg buff data: 01
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): IPA payload: 01
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): Type: IPAC_MSGT_PONG
+{20.633117} [NA] Client's test_segm_ipa_stream_cli_cli_read_cb(): (msg dump (including stripped headers): 00 01 fe 01 )
==================================Test test_segm_ipa_stream_cli complete========================================
Updated by daniel 5 days ago
- Subject changed from stream test fails on jenkins to stream test fails on jenkins due to different loop iterations in the test
- Status changed from New to Stalled
- Priority changed from Normal to Low
This was a one-off failure, all subsequent tests in jenkins succeeded and I was also unable to reproduce it locally.
I think there's merit in keeping the timestamps (in the test they are incremented every main loop iteration) and it's very unclear to me why we would run the main loop 8084 times more (625031 vs 625033/633117) in one execution while it usually only takes two iterations.
I have increased the log level to debug in the test so maybe next time we will know more:
https://gerrit.osmocom.org/c/libosmo-netif/+/37232