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

5 Nov 2024


      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