November 2024 - jenkins-notifications

Jenkins build became unstable: ttcn3-bsc-test-latest #2234

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-latest/2234/display/…>

7 months, 4 weeks

1
0
0 0

Jenkins build became unstable: ttcn3-bsc-test-vamos-latest #11

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-vamos-latest/11/disp…>

7 months, 4 weeks

1
1
0 0

Jenkins build is back to stable : ttcn3-s1gw-test-latest #28

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-s1gw-test-latest/28/display/r…>

7 months, 4 weeks

1
0
0 0

Build failed in Jenkins: master-osmo-hnbgw » NFTABLES=1,PFCP=1,WITH_MANUALS=1,default,osmocom-master #10390

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/master-osmo-hnbgw/NFTABLES=1,PFCP=1…> Changes: ------------------------------------------ [...truncated 340.71 KiB...] checking how to print strings... printf checking for a sed that does not truncate output... /usr/bin/sed checking for grep that handles long lines and -e... /usr/bin/grep checking for egrep... /usr/bin/grep -E checking for fgrep... /usr/bin/grep -F checking for ld used by gcc... /usr/bin/ld checking if the linker (/usr/bin/ld) is GNU ld... yes checking for BSD- or MS-compatible name lister (nm)... /usr/bin/nm -B checking the name lister (/usr/bin/nm -B) interface... BSD nm checking whether ln -s works... yes checking the maximum length of command line arguments... 1572864 checking how to convert x86_64-pc-linux-gnu file names to x86_64-pc-linux-gnu format... func_convert_file_noop checking how to convert x86_64-pc-linux-gnu file names to toolchain format... func_convert_file_noop checking for /usr/bin/ld option to reload object files... -r checking for file... file checking for objdump... objdump checking how to recognize dependent libraries... pass_all checking for dlltool... no checking how to associate runtime and link libraries... printf %s\n checking for ar... ar checking for archiver @FILE support... @ checking for strip... strip checking for ranlib... ranlib checking command to parse /usr/bin/nm -B output from gcc object... ok checking for sysroot... no checking for a working dd... /usr/bin/dd checking how to truncate binary pipes... /usr/bin/dd bs=4096 count=1 checking for mt... no checking if : is a manifest tool... no checking for stdio.h... yes checking for stdlib.h... yes checking for string.h... yes checking for inttypes.h... yes checking for stdint.h... yes checking for strings.h... yes checking for sys/stat.h... yes checking for sys/types.h... yes checking for unistd.h... yes checking for dlfcn.h... yes checking for objdir... .libs checking if gcc supports -fno-rtti -fno-exceptions... no checking for gcc option to produce PIC... -fPIC -DPIC checking if gcc PIC flag -fPIC -DPIC works... yes checking if gcc static flag -static works... yes checking if gcc supports -c -o file.o... yes checking if gcc supports -c -o file.o... (cached) yes checking whether the gcc linker (/usr/bin/ld -m elf_x86_64) supports shared libraries... yes checking whether -lc should be explicitly linked in... no checking dynamic linker characteristics... GNU/Linux ld.so checking how to hardcode library paths into programs... immediate checking whether stripping libraries is possible... yes checking if libtool supports shared libraries... yes checking whether to build shared libraries... yes checking whether to build static libraries... yes checking for pkg-config... /usr/bin/pkg-config checking for pkg-config... /usr/bin/pkg-config checking pkg-config is at least version 0.20... yes checking for library containing sctp_recvmsg... -lsctp checking for libasn1c >= 0.9.30... yes checking for libosmocore >= 1.10.0... yes checking for libosmovty >= 1.10.0... yes checking for libosmoctrl >= 1.10.0... yes checking for libosmogsm >= 1.10.0... yes checking for libosmo-netif >= 1.5.0... yes checking for libosmo-sigtran >= 1.9.0... yes checking for libosmo-rua >= 1.6.0... yes checking for libosmo-ranap >= 1.6.0... yes checking for libosmo-hnbap >= 1.6.0... yes checking for libosmo-mgcp-client >= 1.13.0... yes checking for libosmo-pfcp >= 0.4.0... yes checking for libnftables >= 1.0.2... yes checking for egrep... (cached) /usr/bin/grep -E checking if gcc supports -fvisibility=hidden... yes checking whether to enable code coverage support... no checking for python3... yes checking for osmotestvty.py... yes checking whether to enable VTY/CTRL tests... yes checking for OSMO_GSM_MANUALS_DIR... /opt/osmo-gsm-manuals (from env) All dependencies installed! CFLAGS=" -std=gnu11 -fsanitize=address -fsanitize=undefined -Werror -Wno-error=deprecated -Wno-error=deprecated-declarations -Wno-error=cpp" CPPFLAGS=" -fsanitize=address -fsanitize=undefined -Werror -Wno-error=deprecated -Wno-error=deprecated-declarations -Wno-error=cpp" checking that generated files are newer than configure... done configure: creating ./config.status config.status: creating include/Makefile config.status: creating include/osmocom/Makefile config.status: creating include/osmocom/hnbgw/Makefile config.status: creating src/Makefile config.status: creating src/osmo-hnbgw/Makefile config.status: creating tests/Makefile config.status: creating tests/atlocal config.status: creating tests/ranap_rab_ass/Makefile config.status: creating tests/umts_cell_id/Makefile config.status: creating doc/Makefile config.status: creating doc/examples/Makefile config.status: creating doc/manuals/Makefile config.status: creating doc/charts/Makefile config.status: creating contrib/Makefile config.status: creating contrib/systemd/Makefile config.status: creating Makefile config.status: creating config.h config.status: executing tests/atconfig commands config.status: executing depfiles commands config.status: executing libtool commands + make -j 8 echo 1.6.0.14-1d48 > .version-t && mv .version-t .version make all-recursive make[1]: Entering directory '/build' Making all in include make[2]: Entering directory '/build/include' Making all in osmocom make[3]: Entering directory '/build/include/osmocom' Making all in hnbgw make[4]: Entering directory '/build/include/osmocom/hnbgw' make[4]: Nothing to be done for 'all'. make[4]: Leaving directory '/build/include/osmocom/hnbgw' make[4]: Entering directory '/build/include/osmocom' make[4]: Nothing to be done for 'all-am'. make[4]: Leaving directory '/build/include/osmocom' make[3]: Leaving directory '/build/include/osmocom' make[3]: Entering directory '/build/include' make[3]: Nothing to be done for 'all-am'. make[3]: Leaving directory '/build/include' make[2]: Leaving directory '/build/include' Making all in src make[2]: Entering directory '/build/src' Making all in osmo-hnbgw make[3]: Entering directory '/build/src/osmo-hnbgw' CC osmo_hnbgw_main.o CC hnbgw.lo CC hnbgw_hnbap.lo CC hnbgw_l3.lo CC hnbgw_rua.lo CC hnbgw_ranap.lo CC hnbgw_vty.lo CC context_map.lo CC context_map_rua.lo CC context_map_sccp.lo CC hnbgw_cn.lo CC cnlink.lo CC ranap_rab_ass.lo CC mgw_fsm.lo CC kpi_dtap.lo In file included from /build/deps/install/stow/libosmocore/include/osmocom/core/fsm.h:13, from context_map_sccp.c:26: context_map_sccp.c: In function 'handle_rx_sccp': context_map_sccp.c:244:103: error: invalid use of undefined type 'struct osmo_pfcp_cp_peer' 244 | osmo_sockaddr_to_str_c(OTC_SELECT, &g_hnbgw->pfcp.cp_peer->remote_addr)); | ^~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:105:82: note: in definition of macro 'LOGPSRCC' 105 | logp_stub(caller_file, caller_line, cont, fmt, ##args); \ | ^~~~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:50:9: note: in expansion of macro 'LOGPSRC' 50 | LOGPSRC(ss, level, NULL, 0, fmt, ## args) | ^~~~~~~ context_map_sccp.c:242:41: note: in expansion of macro 'LOGP' 242 | LOGP(DMAIN, LOGL_DEBUG, | ^~~~ context_map_sccp.c:244:103: error: invalid use of undefined type 'struct osmo_pfcp_cp_peer' 244 | osmo_sockaddr_to_str_c(OTC_SELECT, &g_hnbgw->pfcp.cp_peer->remote_addr)); | ^~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:107:76: note: in definition of macro 'LOGPSRCC' 107 | logp_stub(__FILE__, __LINE__, cont, fmt, ##args); \ | ^~~~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:50:9: note: in expansion of macro 'LOGPSRC' 50 | LOGPSRC(ss, level, NULL, 0, fmt, ## args) | ^~~~~~~ context_map_sccp.c:242:41: note: in expansion of macro 'LOGP' 242 | LOGP(DMAIN, LOGL_DEBUG, | ^~~~ context_map_sccp.c:244:103: error: invalid use of undefined type 'struct osmo_pfcp_cp_peer' 244 | osmo_sockaddr_to_str_c(OTC_SELECT, &g_hnbgw->pfcp.cp_peer->remote_addr)); | ^~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:112:89: note: in definition of macro 'LOGPSRCC' 112 | logp2(ss, level, caller_file, caller_line, cont, fmt, ##args); \ | ^~~~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:50:9: note: in expansion of macro 'LOGPSRC' 50 | LOGPSRC(ss, level, NULL, 0, fmt, ## args) | ^~~~~~~ context_map_sccp.c:242:41: note: in expansion of macro 'LOGP' 242 | LOGP(DMAIN, LOGL_DEBUG, | ^~~~ context_map_sccp.c:244:103: error: invalid use of undefined type 'struct osmo_pfcp_cp_peer' 244 | osmo_sockaddr_to_str_c(OTC_SELECT, &g_hnbgw->pfcp.cp_peer->remote_addr)); | ^~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:114:83: note: in definition of macro 'LOGPSRCC' 114 | logp2(ss, level, __FILE__, __LINE__, cont, fmt, ##args); \ | ^~~~ /build/deps/install/stow/libosmocore/include/osmocom/core/logging.h:50:9: note: in expansion of macro 'LOGPSRC' 50 | LOGPSRC(ss, level, NULL, 0, fmt, ## args) | ^~~~~~~ context_map_sccp.c:242:41: note: in expansion of macro 'LOGP' 242 | LOGP(DMAIN, LOGL_DEBUG, | ^~~~ make[3]: *** [Makefile:576: context_map_sccp.lo] Error 1 make[3]: *** Waiting for unfinished jobs.... mgw_fsm.c: In function 'mgw_fsm_crcx_hnb_onenter': mgw_fsm.c:180:9: warning: 'codecs' is deprecated: use ptmap[i].codec instead [-Wdeprecated-declarations] 180 | mgw_info.codecs[0] = CODEC_IUFP; | ^~~~~~~~ In file included from /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_endpoint_fsm.h:4, from mgw_fsm.c:48: /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_fsm.h:33:26: note: declared here 33 | enum mgcp_codecs codecs[MGCP_MAX_CODECS] | ^~~~~~ mgw_fsm.c:181:9: warning: 'codecs_len' is deprecated: use ptmap[] and ptmap_len instead [-Wdeprecated-declarations] 181 | mgw_info.codecs_len = 1; | ^~~~~~~~ /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_fsm.h:35:22: note: declared here 35 | unsigned int codecs_len | ^~~~~~~~~~ mgw_fsm.c: In function 'mgw_fsm_mdcx_hnb_onenter': mgw_fsm.c:368:9: warning: 'codecs' is deprecated: use ptmap[i].codec instead [-Wdeprecated-declarations] 368 | mgw_info.codecs[0] = CODEC_IUFP; | ^~~~~~~~ /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_fsm.h:33:26: note: declared here 33 | enum mgcp_codecs codecs[MGCP_MAX_CODECS] | ^~~~~~ mgw_fsm.c:369:9: warning: 'codecs_len' is deprecated: use ptmap[] and ptmap_len instead [-Wdeprecated-declarations] 369 | mgw_info.codecs_len = 1; | ^~~~~~~~ /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_fsm.h:35:22: note: declared here 35 | unsigned int codecs_len | ^~~~~~~~~~ mgw_fsm.c: In function 'mgw_fsm_crcx_msc_onenter': mgw_fsm.c:452:9: warning: 'codecs' is deprecated: use ptmap[i].codec instead [-Wdeprecated-declarations] 452 | mgw_info.codecs[0] = CODEC_IUFP; | ^~~~~~~~ /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_fsm.h:33:26: note: declared here 33 | enum mgcp_codecs codecs[MGCP_MAX_CODECS] | ^~~~~~ mgw_fsm.c:453:9: warning: 'codecs_len' is deprecated: use ptmap[] and ptmap_len instead [-Wdeprecated-declarations] 453 | mgw_info.codecs_len = 1; | ^~~~~~~~ /build/deps/install/stow/osmo-mgw/include/osmocom/mgcp_client/mgcp_client_fsm.h:35:22: note: declared here 35 | unsigned int codecs_len | ^~~~~~~~~~ make[3]: Leaving directory '/build/src/osmo-hnbgw' make[2]: Leaving directory '/build/src' make[2]: *** [Makefile:394: all-recursive] Error 1 make[1]: Leaving directory '/build' make[1]: *** [Makefile:463: all-recursive] Error 1 make: *** [Makefile:395: all] Error 2 Build step 'Execute shell' marked build as failure $ ssh-agent -k unset SSH_AUTH_SOCK; unset SSH_AGENT_PID; echo Agent pid 3188959 killed; [ssh-agent] Stopped. Archiving artifacts

7 months, 4 weeks

1
2
0 0

Jenkins build became unstable: ttcn3-pgw-test #952

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-pgw-test/952/display/redirect>

7 months, 4 weeks

1
1
0 0

Build failed in Jenkins: ttcn3-bts-test #2572

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-bts-test/2572/display/redirect> Changes: ------------------------------------------ [...truncated 3.04 MiB...] TC_pcu_ver_si13-RSL(495)@c40136dec42c: Mapped TRX#2 to TCP/IP conn_id=4 TC_pcu_ver_si13-RSL-IPA(494)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_ver_si13-RSL-IPA(494)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } MTC@c40136dec42c: 3/4 transceiver(s) connected TC_pcu_ver_si13-RSL(495)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=5): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } MTC@c40136dec42c: 3/4 RF Resource Indication(s) received TC_pcu_ver_si13-RSL(495)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_ver_si13-RSL(495)@c40136dec42c: Mapped TRX#3 to TCP/IP conn_id=5 MTC@c40136dec42c: 4/4 transceiver(s) connected MTC@c40136dec42c: 4/4 RF Resource Indication(s) received MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_3 (3): { header := { l2_plen := { l2_plen := 18, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_3 (27) }, payload := { si3 := { cell_id := 23, lai := { mcc_mnc := '262F42'H, lac := 42 }, ctrl_chan_desc := { msc_r99 := true, att := true, bs_ag_blks_res := 1, ccch_conf := CCHAN_DESC_1CCCH_COMBINED (1), si22ind := false, cbq3 := CBQ3_IU_MODE_NOT_SUPPORTED (0), spare := '00'B, bs_pa_mfrms := 0, t3212 := 1 }, cell_options := { dn_ind := false, pwrc := false, dtx := MS_MAY_USE_UL_DTX (0), radio_link_tout_div4 := 7 }, cell_sel_par := { cell_resel_hyst_2dB := 2, ms_txpwr_max_cch := 7, acs := '0'B, neci := true, rxlev_access_min := 0 }, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B }, rest_octets := { sel_params := { presence := '0'B, params := omit }, pwr_offset := { presence := '0'B, offset := omit }, si_2ter_ind := '0'B, early_cm_ind := '0'B, sched_where := { presence := '0'B, where := omit }, gprs_ind := { presence := '1'B, ind := { ra_colour := 0, si13_pos := '0'B } }, umts_early_cm_ind := '0'B, si2_quater_ind := { presence := '0'B, ind := omit }, iu_mode_ind := omit, si21_ind := { presence := '0'B, pos := omit } } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_3 (3): '49061B001762F224002AC90001074740E504002C2B2B2B'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_2 (2): { header := { l2_plen := { l2_plen := 22, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_2 (26) }, payload := { si2 := { bcch_freq_list := '00000000000000000000000000000000'O, ncc_permitted := '11111111'B, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_2 (2): '59061A00000000000000000000000000000000FFE50400'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_4 (4): { header := { l2_plen := { l2_plen := 12, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_4 (28) }, payload := { si4 := { lai := { mcc_mnc := '262F42'H, lac := 42 }, cell_sel_par := { cell_resel_hyst_2dB := 2, ms_txpwr_max_cch := 7, acs := '0'B, neci := true, rxlev_access_min := 0 }, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B }, cbch_chan_desc := omit, cbch_mobile_alloc := omit, rest_octets := { sel_params := { presence := '0'B, params := omit }, pwr_offset := { presence := '0'B, offset := omit }, gprs_ind := { presence := '1'B, ind := { ra_colour := 0, si13_pos := '0'B } }, s_presence := '0'B, s := omit } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_4 (4): '31061C62F224002A4740E50400012B2B2B2B2B2B2B2B2B'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_13 (40): '01010203040506070909'O MTC@c40136dec42c: setverdict(pass): none -> pass TC_pcu_ver_si13-RSL(495)@c40136dec42c: Final verdict of PTC: none IPA-CTRL-CLI-IPA(496)@c40136dec42c: Final verdict of PTC: none TC_pcu_ver_si13-RSL-IPA(494)@c40136dec42c: Final verdict of PTC: none MTC@c40136dec42c: Setting final verdict of the test case. MTC@c40136dec42c: Local verdict of MTC: pass MTC@c40136dec42c: Local verdict of PTC TC_pcu_ver_si13-RSL-IPA(494): none (pass -> pass) MTC@c40136dec42c: Local verdict of PTC TC_pcu_ver_si13-RSL(495): none (pass -> pass) MTC@c40136dec42c: Local verdict of PTC IPA-CTRL-CLI-IPA(496): none (pass -> pass) MTC@c40136dec42c: Test case TC_pcu_ver_si13 finished. Verdict: pass MTC@c40136dec42c: Starting external command `../ttcn3-tcpdump-stop.sh BTS_Tests.TC_pcu_ver_si13 pass'. Tue Nov 5 03:41:41 UTC 2024 [1;32m====== BTS_Tests.TC_pcu_ver_si13 pass ======[0m Saving talloc report from 172.18.222.20:4241 to BTS_Tests.TC_pcu_ver_si13.talloc Waiting for packet dumper to finish... 0 (prev_count=-1, count=1887154) Waiting for packet dumper to finish... 1 (prev_count=1887154, count=1892329) MTC@c40136dec42c: External command `../ttcn3-tcpdump-stop.sh BTS_Tests.TC_pcu_ver_si13 pass' was executed successfully (exit status: 0). MTC@c40136dec42c: Starting external command `../ttcn3-tcpdump-start.sh BTS_Tests.TC_pcu_data_req_pdtch'. ------ BTS_Tests.TC_pcu_data_req_pdtch ------ Tue Nov 5 03:41:44 UTC 2024 NOTE: unable to use dumpcap due to missing capabilities or suid bit /usr/bin/tcpdump -U -s 1520 -n -i any -w "/data/BTS_Tests.TC_pcu_data_req_pdtch.pcap" >/data/BTS_Tests.TC_pcu_data_req_pdtch.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@c40136dec42c: External command `../ttcn3-tcpdump-start.sh BTS_Tests.TC_pcu_data_req_pdtch' was executed successfully (exit status: 0). MTC@c40136dec42c: Test case TC_pcu_data_req_pdtch started. TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: Established a new IPA connection (conn_id=2) TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=2), waiting for IDENTITY RESPONSE... TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: Established a new IPA connection (conn_id=3) TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=3), waiting for IDENTITY RESPONSE... TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: Established a new IPA connection (conn_id=4) TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=4), waiting for IDENTITY RESPONSE... TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3000'O } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3000'O } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=2): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3000'O } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Mapped TRX#0 to TCP/IP conn_id=2 MTC@c40136dec42c: 1/4 transceiver(s) connected TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: Established a new IPA connection (conn_id=5) TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=5), waiting for IDENTITY RESPONSE... TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3100'O } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3100'O } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3200'O } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3200'O } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=3): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3100'O } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } MTC@c40136dec42c: 1/4 RF Resource Indication(s) received TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Mapped TRX#1 to TCP/IP conn_id=3 MTC@c40136dec42c: 2/4 transceiver(s) connected TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } } } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=4): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3200'O } } MTC@c40136dec42c: 2/4 RF Resource Indication(s) received TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Mapped TRX#2 to TCP/IP conn_id=4 MTC@c40136dec42c: 3/4 transceiver(s) connected TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=5): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } MTC@c40136dec42c: 3/4 RF Resource Indication(s) received TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Mapped TRX#3 to TCP/IP conn_id=5 MTC@c40136dec42c: 4/4 transceiver(s) connected MTC@c40136dec42c: 4/4 RF Resource Indication(s) received MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_3 (3): { header := { l2_plen := { l2_plen := 18, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_3 (27) }, payload := { si3 := { cell_id := 23, lai := { mcc_mnc := '262F42'H, lac := 42 }, ctrl_chan_desc := { msc_r99 := true, att := true, bs_ag_blks_res := 1, ccch_conf := CCHAN_DESC_1CCCH_COMBINED (1), si22ind := false, cbq3 := CBQ3_IU_MODE_NOT_SUPPORTED (0), spare := '00'B, bs_pa_mfrms := 0, t3212 := 1 }, cell_options := { dn_ind := false, pwrc := false, dtx := MS_MAY_USE_UL_DTX (0), radio_link_tout_div4 := 7 }, cell_sel_par := { cell_resel_hyst_2dB := 2, ms_txpwr_max_cch := 7, acs := '0'B, neci := true, rxlev_access_min := 0 }, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B }, rest_octets := { sel_params := { presence := '0'B, params := omit }, pwr_offset := { presence := '0'B, offset := omit }, si_2ter_ind := '0'B, early_cm_ind := '0'B, sched_where := { presence := '0'B, where := omit }, gprs_ind := { presence := '1'B, ind := { ra_colour := 0, si13_pos := '0'B } }, umts_early_cm_ind := '0'B, si2_quater_ind := { presence := '0'B, ind := omit }, iu_mode_ind := omit, si21_ind := { presence := '0'B, pos := omit } } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_3 (3): '49061B001762F224002AC90001074740E504002C2B2B2B'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_2 (2): { header := { l2_plen := { l2_plen := 22, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_2 (26) }, payload := { si2 := { bcch_freq_list := '00000000000000000000000000000000'O, ncc_permitted := '11111111'B, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_2 (2): '59061A00000000000000000000000000000000FFE50400'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_4 (4): { header := { l2_plen := { l2_plen := 12, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_4 (28) }, payload := { si4 := { lai := { mcc_mnc := '262F42'H, lac := 42 }, cell_sel_par := { cell_resel_hyst_2dB := 2, ms_txpwr_max_cch := 7, acs := '0'B, neci := true, rxlev_access_min := 0 }, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B }, cbch_chan_desc := omit, cbch_mobile_alloc := omit, rest_octets := { sel_params := { presence := '0'B, params := omit }, pwr_offset := { presence := '0'B, offset := omit }, gprs_ind := { presence := '1'B, ind := { ra_colour := 0, si13_pos := '0'B } }, s_presence := '0'B, s := omit } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_4 (4): '31061C62F224002A4740E50400012B2B2B2B2B2B2B2B2B'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: setverdict(pass): none -> pass MTC@c40136dec42c: setverdict(pass): pass -> pass, component reason not changed TC_pcu_data_req_pdtch-RSL(498)@c40136dec42c: Final verdict of PTC: none IPA-CTRL-CLI-IPA(499)@c40136dec42c: Final verdict of PTC: none TC_pcu_data_req_pdtch-RSL-IPA(497)@c40136dec42c: Final verdict of PTC: none MTC@c40136dec42c: Setting final verdict of the test case. MTC@c40136dec42c: Local verdict of MTC: pass MTC@c40136dec42c: Local verdict of PTC TC_pcu_data_req_pdtch-RSL-IPA(497): none (pass -> pass) MTC@c40136dec42c: Local verdict of PTC TC_pcu_data_req_pdtch-RSL(498): none (pass -> pass) MTC@c40136dec42c: Local verdict of PTC IPA-CTRL-CLI-IPA(499): none (pass -> pass) MTC@c40136dec42c: Test case TC_pcu_data_req_pdtch finished. Verdict: pass MTC@c40136dec42c: Starting external command `../ttcn3-tcpdump-stop.sh BTS_Tests.TC_pcu_data_req_pdtch pass'. Tue Nov 5 03:41:50 UTC 2024 [1;32m====== BTS_Tests.TC_pcu_data_req_pdtch pass ======[0m Saving talloc report from 172.18.222.20:4241 to BTS_Tests.TC_pcu_data_req_pdtch.talloc Waiting for packet dumper to finish... 0 (prev_count=-1, count=4600277) Waiting for packet dumper to finish... 1 (prev_count=4600277, count=4600904) MTC@c40136dec42c: External command `../ttcn3-tcpdump-stop.sh BTS_Tests.TC_pcu_data_req_pdtch pass' was executed successfully (exit status: 0). MTC@c40136dec42c: Starting external command `../ttcn3-tcpdump-start.sh BTS_Tests.TC_pcu_data_req_ptcch'. ------ BTS_Tests.TC_pcu_data_req_ptcch ------ Tue Nov 5 03:41:53 UTC 2024 NOTE: unable to use dumpcap due to missing capabilities or suid bit /usr/bin/tcpdump -U -s 1520 -n -i any -w "/data/BTS_Tests.TC_pcu_data_req_ptcch.pcap" >/data/BTS_Tests.TC_pcu_data_req_ptcch.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@c40136dec42c: External command `../ttcn3-tcpdump-start.sh BTS_Tests.TC_pcu_data_req_ptcch' was executed successfully (exit status: 0). MTC@c40136dec42c: Test case TC_pcu_data_req_ptcch started. TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: Established a new IPA connection (conn_id=2) TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=2), waiting for IDENTITY RESPONSE... TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: Established a new IPA connection (conn_id=3) TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=3), waiting for IDENTITY RESPONSE... TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: Established a new IPA connection (conn_id=4) TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=4), waiting for IDENTITY RESPONSE... TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3000'O } } } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3000'O } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=2): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3000'O } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: Established a new IPA connection (conn_id=5) TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Mapped TRX#0 to TCP/IP conn_id=2 MTC@c40136dec42c: 1/4 transceiver(s) connected TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: A new IPA/RSL connection has been established (conn_id=5), waiting for IDENTITY RESPONSE... TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3100'O } } } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3100'O } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3200'O } } } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3200'O } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } MTC@c40136dec42c: 1/4 RF Resource Indication(s) received TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=3): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3100'O } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Mapped TRX#1 to TCP/IP conn_id=3 TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } } } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: IPA ID RESP: { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } MTC@c40136dec42c: 2/4 transceiver(s) connected TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_pcu_data_req_ptcch-RSL-IPA(500)@c40136dec42c: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } MTC@c40136dec42c: 2/4 RF Resource Indication(s) received TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=4): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3200'O } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Mapped TRX#2 to TCP/IP conn_id=4 MTC@c40136dec42c: 3/4 transceiver(s) connected MTC@c40136dec42c: 3/4 RF Resource Indication(s) received TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Got IDENTITY RESPONSE (conn_id=5): { { len := 28, tag := IPAC_IDTAG_UNITNAME (1), data := '6F736D6F2D6274732D30322D34322D61632D31322D64652D313400'O }, { len := 10, tag := IPAC_IDTAG_UNITID (8), data := '313233342F302F3300'O } } TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Warning: dec_IpaUnitId(): Data remained at the end of the stream after successful decoding: '00'O TC_pcu_data_req_ptcch-RSL(501)@c40136dec42c: Mapped TRX#3 to TCP/IP conn_id=5 MTC@c40136dec42c: 4/4 transceiver(s) connected MTC@c40136dec42c: 4/4 RF Resource Indication(s) received MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_3 (3): { header := { l2_plen := { l2_plen := 18, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_3 (27) }, payload := { si3 := { cell_id := 23, lai := { mcc_mnc := '262F42'H, lac := 42 }, ctrl_chan_desc := { msc_r99 := true, att := true, bs_ag_blks_res := 1, ccch_conf := CCHAN_DESC_1CCCH_COMBINED (1), si22ind := false, cbq3 := CBQ3_IU_MODE_NOT_SUPPORTED (0), spare := '00'B, bs_pa_mfrms := 0, t3212 := 1 }, cell_options := { dn_ind := false, pwrc := false, dtx := MS_MAY_USE_UL_DTX (0), radio_link_tout_div4 := 7 }, cell_sel_par := { cell_resel_hyst_2dB := 2, ms_txpwr_max_cch := 7, acs := '0'B, neci := true, rxlev_access_min := 0 }, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B }, rest_octets := { sel_params := { presence := '0'B, params := omit }, pwr_offset := { presence := '0'B, offset := omit }, si_2ter_ind := '0'B, early_cm_ind := '0'B, sched_where := { presence := '0'B, where := omit }, gprs_ind := { presence := '1'B, ind := { ra_colour := 0, si13_pos := '0'B } }, umts_early_cm_ind := '0'B, si2_quater_ind := { presence := '0'B, ind := omit }, iu_mode_ind := omit, si21_ind := { presence := '0'B, pos := omit } } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_3 (3): '49061B001762F224002AC90001074740E504002C2B2B2B'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_2 (2): { header := { l2_plen := { l2_plen := 22, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_2 (26) }, payload := { si2 := { bcch_freq_list := '00000000000000000000000000000000'O, ncc_permitted := '11111111'B, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_2 (2): '59061A00000000000000000000000000000000FFE50400'O MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_4 (4): { header := { l2_plen := { l2_plen := 12, zero_one := '01'B }, skip_indicator := 0, rr_protocol_discriminator := 6, message_type := SYSTEM_INFORMATION_TYPE_4 (28) }, payload := { si4 := { lai := { mcc_mnc := '262F42'H, lac := 42 }, cell_sel_par := { cell_resel_hyst_2dB := 2, ms_txpwr_max_cch := 7, acs := '0'B, neci := true, rxlev_access_min := 0 }, rach_control := { max_retrans := RACH_MAX_RETRANS_7 (3), tx_integer := '1001'B, cell_barr_access := false, re_not_allowed := true, acc := '0000010000000000'B }, cbch_chan_desc := omit, cbch_mobile_alloc := omit, rest_octets := { sel_params := { presence := '0'B, params := omit }, pwr_offset := { presence := '0'B, offset := omit }, gprs_ind := { presence := '1'B, ind := { ra_colour := 0, si13_pos := '0'B } }, s_presence := '0'B, s := omit } } } } MTC@c40136dec42c: Setting RSL_SYSTEM_INFO_4 (4): '31061C62F224002A4740E50400012B2B2B2B2B2B2B2B2B'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O MTC@c40136dec42c: Warning: dec_TrxcMessage(): Data remained at the end of the stream after successful decoding: '00'O FATAL: command execution failed java.io.EOFException at java.base/java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source) at java.base/java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source) at java.base/java.io.ObjectInputStream.readStreamHeader(Unknown Source) at java.base/java.io.ObjectInputStream.<init>(Unknown Source) at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:50) at hudson.remoting.Command.readFrom(Command.java:142) at hudson.remoting.Command.readFrom(Command.java:128) at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35) at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:61) Caused: java.io.IOException: Unexpected termination of the channel at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:75) Caused: java.io.IOException: Backing channel 'build2-deb11build-ansible' is disconnected. at hudson.remoting.RemoteInvocationHandler.channelOrFail(RemoteInvocationHandler.java:215) at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:285) at jdk.proxy2/jdk.proxy2.$Proxy67.isAlive(Unknown Source) at hudson.Launcher$RemoteLauncher$ProcImpl.isAlive(Launcher.java:1212) at hudson.Launcher$RemoteLauncher$ProcImpl.join(Launcher.java:1204) at hudson.tasks.CommandInterpreter.join(CommandInterpreter.java:195) at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:145) at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:92) at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20) at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:818) at hudson.model.Build$BuildExecution.build(Build.java:199) at hudson.model.Build$BuildExecution.doRun(Build.java:164) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:526) at hudson.model.Run.execute(Run.java:1894) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44) at hudson.model.ResourceController.execute(ResourceController.java:101) at hudson.model.Executor.run(Executor.java:446) FATAL: Unable to delete script file /tmp/jenkins16607122148183656983.sh java.io.EOFException at java.base/java.io.ObjectInputStream$PeekInputStream.readFully(Unknown Source) at java.base/java.io.ObjectInputStream$BlockDataInputStream.readShort(Unknown Source) at java.base/java.io.ObjectInputStream.readStreamHeader(Unknown Source) at java.base/java.io.ObjectInputStream.<init>(Unknown Source) at hudson.remoting.ObjectInputStreamEx.<init>(ObjectInputStreamEx.java:50) at hudson.remoting.Command.readFrom(Command.java:142) at hudson.remoting.Command.readFrom(Command.java:128) at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35) at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:61) Caused: java.io.IOException: Unexpected termination of the channel at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:75) Caused: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@55473aec:build2-deb11build-ansible": Remote call on build2-deb11build-ansible failed. The channel is closing down or has closed down at hudson.remoting.Channel.call(Channel.java:1035) at hudson.FilePath.act(FilePath.java:1229) at hudson.FilePath.act(FilePath.java:1218) at hudson.FilePath.delete(FilePath.java:1765) at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:163) at hudson.tasks.CommandInterpreter.perform(CommandInterpreter.java:92) at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20) at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:818) at hudson.model.Build$BuildExecution.build(Build.java:199) at hudson.model.Build$BuildExecution.doRun(Build.java:164) at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:526) at hudson.model.Run.execute(Run.java:1894) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44) at hudson.model.ResourceController.execute(ResourceController.java:101) at hudson.model.Executor.run(Executor.java:446) Build step 'Execute shell' marked build as failure ERROR: Step ‘Publish JUnit test result report’ failed: no workspace for ttcn3-bts-test #2572

7 months, 4 weeks

1
0
0 0

Build failed in Jenkins: ttcn3-sgsn-test-io_uring #247

by jenkins＠lists.osmocom.org

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/247/displa…> Changes: [Pau Espin Pedrol] hnbgw: Introduce PfcpParameters in TestHdlrParameters [Oliver Smith] bsc: testenv: set MTU=1500 for lo [Pau Espin Pedrol] hnbgw: Merge TC_ps_rab_assignment_* testcases [Pau Espin Pedrol] hnbgw: Move normal condition Iu Release procedure to helper function [Pau Espin Pedrol] hnbgw: Tear down SCCP conn from CN under normal conditions ------------------------------------------ [...truncated 768.67 KiB...] -NSVCI97(159)@cf08b375ff3a: Provider Link came up: sending NS-RESET [38;5;63m20241104150046291 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046291 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20241104150046291 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20241104150046291 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20241104150046291 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became unavailable (gprs_ns.c:55) [38;5;63m20241104150046291 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20241104150046291 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20241104150046291 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20241104150046291 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI97(159)@cf08b375ff3a: NSVC 97 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20241104150046292 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046292 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20241104150046292 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20241104150046292 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046292 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20241104150046292 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20241104150046292 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20241104150046292 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20241104150046292 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became available (gprs_ns.c:44) [38;5;57m20241104150046292 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096)-NSVC(00097) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20241104150046292 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:59) [38;5;63m20241104150046293 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046293 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI97(159)@cf08b375ff3a: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI97(159)@cf08b375ff3a: NSVC 97 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20241104150046296 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb1-NS1(160)@cf08b375ff3a: Creating NSIP provider for "127.0.0.103":21011 SGSN_Test-Gb0-BSSGP0(156)@cf08b375ff3a: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb0-BSSGP0(156)@cf08b375ff3a: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-BSSGP1(161)@cf08b375ff3a: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) [38;5;57m20241104150046303 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20241104150046303 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13135-0 CI 20960 on BVCI 196 (gprs_bssgp.c:435)[0;m TC_attach_gsup_lu_timeout-BVCI196(158)@cf08b375ff3a: BVCI(196) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-NS1(160)@cf08b375ff3a: Starting NSVC component for { provider := { ip := { address_family := AF_INET (2), local_udp_port := 21011, local_ip := "127.0.0.103", remote_udp_port := 23000, remote_ip := "127.0.0.10", data_weight := 1, signalling_weight := 1 } }, nsvci := 98 } -NSVCI98(165)@cf08b375ff3a: NSVC 98 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI98(165)@cf08b375ff3a: Provider Link came up: sending NS-RESET SGSN_Test-Gb2-NS2(164)@cf08b375ff3a: Creating NSIP provider for "127.0.0.103":21012 [38;5;63m20241104150046313 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046313 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20241104150046313 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20241104150046313 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20241104150046313 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became unavailable (gprs_ns.c:55) [38;5;63m20241104150046313 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20241104150046313 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20241104150046313 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20241104150046313 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI98(165)@cf08b375ff3a: NSVC 98 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20241104150046314 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046314 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20241104150046314 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20241104150046314 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046314 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20241104150046314 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20241104150046314 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20241104150046314 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20241104150046314 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became available (gprs_ns.c:44) [38;5;57m20241104150046314 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097)-NSVC(00098) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20241104150046314 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:59) [38;5;63m20241104150046314 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046314 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI98(165)@cf08b375ff3a: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI98(165)@cf08b375ff3a: NSVC 98 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20241104150046316 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb1-BSSGP1(161)@cf08b375ff3a: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb1-BSSGP1(161)@cf08b375ff3a: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-BSSGP2(166)@cf08b375ff3a: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) [38;5;57m20241104150046320 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x564a0d09bec0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20241104150046320 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20961 on BVCI 210 (gprs_bssgp.c:435)[0;m TC_attach_gsup_lu_timeout-BVCI210(162)@cf08b375ff3a: BVCI(210) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-NS2(164)@cf08b375ff3a: Starting NSVC component for { provider := { ip := { address_family := AF_INET (2), local_udp_port := 21012, local_ip := "127.0.0.103", remote_udp_port := 23000, remote_ip := "127.0.0.10", data_weight := 1, signalling_weight := 1 } }, nsvci := 99 } -NSVCI99(169)@cf08b375ff3a: NSVC 99 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI99(169)@cf08b375ff3a: Provider Link came up: sending NS-RESET [38;5;63m20241104150046324 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046324 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20241104150046324 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20241104150046324 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20241104150046324 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became unavailable (gprs_ns.c:55) [38;5;63m20241104150046324 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20241104150046324 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20241104150046324 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20241104150046324 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI99(169)@cf08b375ff3a: NSVC 99 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20241104150046325 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046325 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20241104150046325 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20241104150046325 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046325 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20241104150046325 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20241104150046325 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20241104150046325 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20241104150046325 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became available (gprs_ns.c:44) [38;5;57m20241104150046325 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098)-NSVC(00099) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20241104150046325 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:59) [38;5;63m20241104150046326 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20241104150046326 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI99(169)@cf08b375ff3a: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI99(169)@cf08b375ff3a: NSVC 99 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20241104150046328 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb2-BSSGP2(166)@cf08b375ff3a: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb2-BSSGP2(166)@cf08b375ff3a: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20241104150046332 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x564a0d09d920]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20241104150046332 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20962 on BVCI 220 (gprs_bssgp.c:435)[0;m TC_attach_gsup_lu_timeout-BVCI220(168)@cf08b375ff3a: BVCI(220) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) [38;5;39m20241104150046743 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;23m20241104150046743 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m 127.0.0.103:4222 connection done (ipa.c:143)[0;m [38;5;39m20241104150046743 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 UP (gsup_client.c:151)[0;m [38;5;39m20241104150046743 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP sending PING (gsup_client.c:288)[0;m SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: Established a new IPA connection (conn_id=2) SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } [38;5;23m20241104150046747 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m received ID_GET for unit ID 0/0/0 (ipaccess.c:897)[0;m SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit } SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit } [38;5;39m20241104150046748 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP receiving PONG (gsup_client.c:225)[0;m SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 24, tag := IPAC_IDTAG_UNITNAME (1), data := '5347534E2D30302D30302D30302D30302D30302D303000'O }, { len := 7, tag := IPAC_IDTAG_UNITID (8), data := '302F302F3000'O } } } } SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: IPA ID RESP: { { len := 24, tag := IPAC_IDTAG_UNITNAME (1), data := '5347534E2D30302D30302D30302D30302D30302D303000'O }, { len := 7, tag := IPAC_IDTAG_UNITID (8), data := '302F302F3000'O } } SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_attach_gsup_lu_timeout-BVCI196(158)@cf08b375ff3a: Adding Client=TC_attach_gsup_lu_timeout(173), IMSI='262420000000005'H, TLLI='D183B9F0'O, index=0 SGSN_Test-GSUP(171)@cf08b375ff3a: Created GsupExpect[0] for "262420000000005" to be handled at TC_attach_gsup_lu_timeout(173) TC_attach_gsup_lu_timeout(173)@cf08b375ff3a: GSUP sends only 2G auth tuple{ tag := OSMO_GSUP_AUTH_TUPLE_IE (3), len := 0, val := { auth_tuple := { { tag := OSMO_GSUP_RAND_IE (32), len := 0, val := { rand := '4288CF8B19FDA0CC4618DBDB1E09B8F5'O } }, { tag := OSMO_GSUP_SRES_IE (33), len := 0, val := { sres := '4ACB3274'O } }, { tag := OSMO_GSUP_KC_IE (34), len := 0, val := { kc := 'C6E73EAC472F4164'O } } } } } [38;5;57m20241104150047832 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20241104150047832 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/d183b9f0){UNASSIGNED} LLC RX: unknown TLLI 0xd183b9f0, creating LLME on the fly (gprs_llc.c:552) 20241104150047832 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x24bf94 CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20241104150047832 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(---/ffffffff) -> GMM ATTACH REQUEST [0;m[1;33mMI(IMSI-262420000000005) type="GPRS attach" [0;m[1;33m (gprs_gmm.c:1266)[0;m [1;33m20241104150047832 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x564a0d09ef30]{Deregistered}: Allocated (fsm.c:456)[0;m [1;33m20241104150047832 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{Init}: Allocated (fsm.c:456)[0;m [1;33m20241104150047832 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb[0x564a0d09f190]{Idle}: Allocated (fsm.c:456)[0;m [1;33m20241104150047832 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x564a0d09f2c0]{Detached}: Allocated (fsm.c:456)[0;m [1;33m20241104150047833 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x564a0d09ef30]{Deregistered}: Received Event E_GMM_COMMON_PROC_INIT_REQ (gprs_gmm.c:1144)[0;m [1;33m20241104150047833 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x564a0d09ef30]{Deregistered}: state_chg to CommonProcedureInitiated (gprs_gmm_fsm.c:49)[0;m 20241104150047833 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/d183b9f0){UNASSIGNED} LLGM Assign pre (d183b9f0 => d88d157e) (gprs_llc.c:1079) 20241104150047833 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(d183b9f0/d88d157e){ASSIGNED} LLGM Assign post (d183b9f0 => d88d157e) (gprs_llc.c:1125) [1;33m20241104150047833 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{Init}: Received Event E_ATTACH_REQ_RECV (gprs_gmm.c:1370)[0;m [1;33m20241104150047833 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{Init}: state_chg to CheckIdentity (gprs_gmm_attach.c:52)[0;m [1;33m20241104150047833 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) <- GMM IDENTITY REQUEST: mi_type=IMEI (gprs_gmm.c:431)[0;m [38;5;57m20241104150047861 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20241104150047861 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x612fca CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x564a0d09f190]{Idle}: Received Event E_MM_PDU_RECEPTION (gprs_gmm.c:2341)[0;m [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) -> GMM IDENTITY RESPONSE: MI=IMEI-499990000000050 (gprs_gmm.c:1084)[0;m [1;33m20241104150047861 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000005/d88d157e) Stopping *inactive* MM timer 3370 (gprs_gmm.c:115)[0;m [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{CheckIdentity}: Received Event E_IDEN_RESP_RECV (gprs_gmm.c:1128)[0;m [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{CheckIdentity}: state_chg to Authenticate (gprs_gmm_attach.c:115)[0;m [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{Authenticate}: state_chg to AskVLR (gprs_gmm_attach.c:143)[0;m [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) Requesting authorization (sgsn_auth.c:160)[0;m [1;33m20241104150047861 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) Requesting authentication tuples (sgsn_auth.c:184)[0;m [1;33m20241104150047861 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) Requesting subscriber authentication info (gprs_subscriber.c:921)[0;m 20241104150047861 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000005) requesting auth info (gprs_subscriber.c:805) 20241104150047861 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000005) Sending GSUP, will send: 08 01 08 62 42 02 00 00 00 00 f5 28 01 01 (gprs_subscriber.c:210) SGSN_Test-GSUP(171)@cf08b375ff3a: Found GsupExpect[0] for "262420000000005" handled at TC_attach_gsup_lu_timeout(173) SGSN_Test-GSUP(171)@cf08b375ff3a: Added IMSI table entry 0TC_attach_gsup_lu_timeout(173)"262420000000005" 20241104150047867 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000005) Received GSUP message OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT (gprs_subscriber.c:723) 20241104150047867 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000005) Got SendAuthenticationInfoResult, num_auth_vectors = 1 (gprs_subscriber.c:242) 20241104150047867 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000005) Adding auth tuple, cksn = 0 (gprs_subscriber.c:255) 20241104150047867 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000005) Updating subscriber authentication info (gprs_subscriber.c:850) [1;33m20241104150047867 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) Subscriber data update (mmctx.c:445)[0;m [1;33m20241104150047867 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) Updating authorization (unknown -> authenticate) (sgsn_auth.c:217)[0;m [1;33m20241104150047867 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) Got authorization update: state unknown -> authenticate (sgsn_auth.c:246)[0;m [1;33m20241104150047867 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{AskVLR}: Received Event E_VLR_ANSWERED (gprs_gmm.c:991)[0;m [1;33m20241104150047867 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{AskVLR}: state_chg to Authenticate (gprs_gmm_attach.c:253)[0;m [1;33m20241104150047867 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) <- GMM AUTH AND CIPHERING REQ (rand = 42 88 cf 8b 19 fd a0 cc 46 18 db db 1e 09 b8 f5 , mmctx_is_r99=0, vec->auth_types=0x1[0;m[1;33m) (gprs_gmm.c:486)[0;m [38;5;57m20241104150047885 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x564a0d099f00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20241104150047885 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0xfcaae8 CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20241104150047885 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x564a0d09f190]{Idle}: Received Event E_MM_PDU_RECEPTION (gprs_gmm.c:2341)[0;m [1;33m20241104150047885 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) -> GMM AUTH AND CIPH RESPONSE (gprs_gmm.c:620)[0;m [1;33m20241104150047885 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000005/d88d157e) Stopping *inactive* MM timer 3360 (gprs_gmm.c:115)[0;m [1;33m20241104150047885 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) checking auth: received GSM SRES = 4a cb 32 74 (gprs_gmm.c:666)[0;m [1;33m20241104150047885 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{Authenticate}: Received Event E_AUTH_RESP_RECV_SUCCESS (gprs_gmm.c:681)[0;m [1;33m20241104150047885 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) Requesting authorization (sgsn_auth.c:160)[0;m [1;33m20241104150047885 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) Missing information, requesting subscriber data (sgsn_auth.c:195)[0;m [1;33m20241104150047885 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000005/d88d157e) Requesting subscriber data update (gprs_subscriber.c:894)[0;m 20241104150047885 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000005) subscriber data is not available (gprs_subscriber.c:818) 20241104150047885 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000005) Sending GSUP, will send: 04 01 08 62 42 02 00 00 00 00 f5 28 01 01 2a 01 01 (gprs_subscriber.c:210) [1;33m20241104150047885 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x564a0d09f060]{Authenticate}: state_chg to WaitAttachComplete (gprs_gmm_attach.c:181)[0;m [1;33m20241104150047885 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000005/d88d157e) <- GMM ATTACH ACCEPT (new P-TMSI=0xd88d157e) (gprs_gmm.c:300)[0;m TC_attach_gsup_lu_timeout(173)@cf08b375ff3a: setverdict(fail): none -> fail MC@cf08b375ff3a: Test Component 173 has requested to stop MTC. Terminating current testcase execution. 20241104150047903 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection r=127.0.0.1:60654<->l=127.0.0.10:4245 (telnet_interface.c:138) [38;5;23m20241104150047904 [1;31mDLINP[0;m[38;5;23m [1;31mERROR[0;m[38;5;23m 127.0.0.103:4222 connection closed with server (ipa.c:68)[0;m [38;5;39m20241104150047904 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m SGSN_Test-GSUP(171)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-GSUP-IPA(170)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-Gb1-NS1(160)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-Gb2-NS2(164)@cf08b375ff3a: Final verdict of PTC: none -NSVCI98(165)@cf08b375ff3a: Final verdict of PTC: none -NSVCI99(169)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-Gb2-BSSGP2(166)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-Gb0-NS0(155)@cf08b375ff3a: Final verdict of PTC: none -NSVCI97(159)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-Gb1-BSSGP1(161)@cf08b375ff3a: Final verdict of PTC: none TC_attach_gsup_lu_timeout-BVCI220(168)@cf08b375ff3a: Final verdict of PTC: none SGSN_Test-Gb0-BSSGP0(156)@cf08b375ff3a: Final verdict of PTC: none TC_attach_gsup_lu_timeout-BVCI210(162)@cf08b375ff3a: Final verdict of PTC: none TC_attach_gsup_lu_timeout-BVCI196(158)@cf08b375ff3a: Final verdict of PTC: none -NSVCI98-provIP(163)@cf08b375ff3a: Final verdict of PTC: none -NSVCI99-provIP(167)@cf08b375ff3a: Final verdict of PTC: none TC_attach_gsup_lu_timeout(173)@cf08b375ff3a: Final verdict of PTC: fail SGSN_Test-GGSN_GTP(172)@cf08b375ff3a: Final verdict of PTC: none -NSVCI97-provIP(157)@cf08b375ff3a: Final verdict of PTC: none MTC@cf08b375ff3a: Setting final verdict of the test case. MTC@cf08b375ff3a: Local verdict of MTC: none MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-Gb0-NS0(155): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-Gb0-BSSGP0(156): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC -NSVCI97-provIP(157): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC TC_attach_gsup_lu_timeout-BVCI196(158): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC -NSVCI97(159): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-Gb1-NS1(160): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-Gb1-BSSGP1(161): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC TC_attach_gsup_lu_timeout-BVCI210(162): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC -NSVCI98-provIP(163): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-Gb2-NS2(164): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC -NSVCI98(165): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-Gb2-BSSGP2(166): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC -NSVCI99-provIP(167): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC TC_attach_gsup_lu_timeout-BVCI220(168): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC -NSVCI99(169): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-GSUP-IPA(170): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-GSUP(171): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC SGSN_Test-GGSN_GTP(172): none (none -> none) MTC@cf08b375ff3a: Local verdict of PTC TC_attach_gsup_lu_timeout(173): fail (none -> fail) MTC@cf08b375ff3a: Test case TC_attach_gsup_lu_timeout finished. Verdict: fail MTC@cf08b375ff3a: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests.TC_attach_gsup_lu_timeout fail'. Mon Nov 4 15:00:47 UTC 2024 [1;31m------ SGSN_Tests.TC_attach_gsup_lu_timeout fail ------[0m Saving talloc report from 127.0.0.10:4245 to SGSN_Tests.TC_attach_gsup_lu_timeout.talloc 20241104150047997 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection r=127.0.0.1:60660<->l=127.0.0.10:4245 (telnet_interface.c:192) 20241104150048788 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection r=127.0.0.1:60660<->l=127.0.0.10:4245 (telnet_interface.c:138) Waiting for packet dumper to finish... 0 (prev_count=-1, count=44540) [38;5;39m20241104150048905 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20241104150048905 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m Waiting for packet dumper to finish... 1 (prev_count=44540, count=74796) [38;5;39m20241104150049906 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20241104150049906 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@cf08b375ff3a: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests.TC_attach_gsup_lu_timeout fail' was executed successfully (exit status: 0). [38;5;39m20241104150050907 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20241104150050907 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m [38;5;39m20241104150051908 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m ERROR: /tmp/watchdog was not created, exiting Error: OCI runtime error: crun: the container `cf08b375ff3a17bf44f8f98bc9209bea332dc3accc84c984325b9171a0508b67` is not running [1;91m[testenv] podman container crashed![0m [1;34m[testenv][generic] Looking for a coredump[0m [0;94m[testenv][generic] coredumpctl is not available, won't try to get coredump[0m [1;91m[testenv][generic] stp crashed![0m [1;34m[testenv][generic] Stopping testsuite (2565960)[0m [1;34m[testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/247/artifa… [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.

8 months