See https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/1/display/redirect
Changes:
------------------------------------------ [...truncated 5.84 MiB...] IPA-CTRL-CLI-IPA(102)@f40282a245d3: Terminating component type IPA_Emulation.IPA_Emulation_CT. MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies[0].body{ ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } with { sysinfo_type := ? } unmatched.rsl.ies[1].body{ bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } with { l3_info := { len := ?, payload := ? } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f40282a245d3: Removing unterminated mapping between port IPA_PORT and system:IPA_CODEC_PT. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_PORT was unmapped from system:IPA_CODEC_PT. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Function main_client was stopped. PTC remains alive and is waiting for next start. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port CFG_PORT was stopped. MTC@f40282a245d3: Message enqueued on IPA_RSL[0][0] from IPA-BTS0-TRX0-RSL-IPA(104) @IPA_Emulation.ASP_IPA_Event : { ev_type := ASP_IPA_EVENT_DOWN (0), conn_id := 1, id_resp := omit } id 16 IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port MTP3_SP_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_MGCP_PORT was stopped. MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_RSL_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_OML_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Removing unterminated connection between port IPA_CTRL_PORT and mtc:IPA_CTRL. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_CTRL_PORT was stopped. MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } }, { iei := ?, body := { other := { len := ?, payload := ? } } }, * } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f40282a245d3: Port IPA_SP_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Component type IPA_Emulation.IPA_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. IPA-CTRL-CLI-IPA(102)@f40282a245d3: Final verdict of PTC: none MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies[0].body{ ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } with { sysinfo_type := ? } unmatched.rsl.ies[1].body{ bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } with { l3_info := { len := ?, payload := ? } } unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Connection of port IPA_CTRL to IPA-CTRL-CLI-IPA(102):IPA_CTRL_PORT was closed unexpectedly by the peer. MTC@f40282a245d3: Port IPA_CTRL was disconnected from IPA-CTRL-CLI-IPA(102):IPA_CTRL_PORT. MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } }, { iei := ?, body := { other := { len := ?, payload := ? } } }, * } unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies[0].body{ ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } with { sysinfo_type := ? } unmatched.rsl.ies[1].body{ bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } with { l3_info := { len := ?, payload := ? } } unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Timeout T: 5 s MTC@f40282a245d3: RSL 0 SYSTEM INFORMATION: { si1 := { cell_chan_desc := '8FB38000000000000000000000000000'O, 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 := '2B'O ("+") }, 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 } }, si2bis := omit, si2ter := { extd_bcch_freq_list := '8E320000000000000000000000000800'O, rest_octets := '2B2B2B2B'O ("++++") }, si2quater := { { ba_ind := '0'B, ba_3g_ind := '1'B, mp_change_mark := '0'B, si2quater_index := 0, si2quater_count := 0, meas_params_desc := { presence := '0'B, desc := omit }, gprs := { rt_diff_desc := { presence := '0'B, desc := omit }, bsic_desc := { presence := '0'B, desc := omit }, rep_prio_desc := { presence := '0'B, desc := omit }, meas_params_desc := { presence := '0'B, desc := omit } }, nc_meas_params := { presence := '0'B, params := omit }, ext_info := { presence := '0'B, info := omit }, utran_neigh_desc := { presence := '0'B, desc := omit }, utran_meas_params_desc := { presence := '0'B, desc := omit }, utran_gprs_meas_params_desc := { presence := '0'B, desc := omit }, rel_additions := { rel5_presence := '1'B, rel5 := { umts_add_meas_params_desc := { presence := '0'B, desc := omit }, umts_add_meas_params_desc2 := { presence := '0'B, desc := omit }, rel6_presence := '1'B, rel6 := { umts_ccn_active := '0'B, rel7_presence := '1'B, rel7 := { rep700 := { presence := '0'B, val := omit }, rep810 := { presence := '0'B, val := omit }, rel8_presence := '1'B, rel8 := { prio_eutran_params_desc := { presence := '1'B, desc := { sc_prio_params_desc := { presence := '1'B, desc := { geran_priority := 0, thresh_priority_search := 0, thresh_gsm_low := 0, h_prio := 0, t_reselection := 0 } }, utran_prio_params_desc := { presence := '0'B, desc := omit }, eutran_params_desc := { presence := '1'B, desc := { ccn_active := '0'B, e_start := '1'B, e_stop := '1'B, meas_params_desc := { presence := '0'B, desc := omit }, gprs_meas_params_desc := { presence := '0'B, desc := omit }, repeated_neigh_cells := { { item_ind := '1'B, cell_desc_list := { { item_ind := '1'B, e_arfcn := 111, meas_bw_presence := '1'B, meas_bw := 3 }, { item_ind := '1'B, e_arfcn := 1, meas_bw_presence := '1'B, meas_bw := 3 }, { item_ind := '1'B, e_arfcn := 0, meas_bw_presence := '1'B, meas_bw := 3 } }, cell_desc_list_term := '0'B, prio_presence := '1'B, prio := 3, thresh_high := 20, thresh_low_presence := '1'B, thresh_low := 10, qrxlevmin_presence := '1'B, qrxlevmin := 22 } }, repeated_neigh_cells_term := '0'B, repeated_not_allowed_cells := omit, repeated_not_allowed_cells_term := '0'B, pcid2ta_map_list := omit, pcid2ta_map_list_term := '0'B } } } }, utran_csg_desc := { presence := '0'B, desc := omit }, eutran_csg_desc := { presence := '0'B, desc := omit } } } } } } } }, si3 := { cell_id := 0, lai := { mcc_mnc := '001F01'H, lac := 1 }, 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 := 3, t3212 := 30 }, cell_options := { dn_ind := false, pwrc := false, dtx := MS_SHALL_USE_UL_DTX (1), 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 := '1'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 := '1'B, si2_quater_ind := { presence := '1'B, ind := '0'B }, iu_mode_ind := omit, si21_ind := { presence := '0'B, pos := omit } } }, si4 := { lai := { mcc_mnc := '001F01'H, lac := 1 }, 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 := { iei := '64'O ("d"), v := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 2 } }, tn := 0 }, tsc := 2, h := false, arfcn := 871, maio_hsn := 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 } }, si13 := { rest_octets := { presence := '1'B, bcch_change_mark := 1, si_change_field := '0000'B, presence2 := '0'B, si13_change_mark := omit, gprs_ma := omit, zero := '0'B, rac := 0, spgc_ccch_sup := '0'B, priority_access_thr := '110'B, network_control_order := '00'B, gprs_cell_opts := { nmo := '01'B, t3168 := '011'B, t3192 := '010'B, drx_timer_max := '011'B, access_burst_type := '0'B, control_ack_type := '1'B, bs_cv_max := 15, pan_presence := '1'B, pan_dec := 1, pan_inc := 1, pan_max := '111'B, ext_info_presence := '1'B, ext_info_length := '000101'B, ext_info := { egprs_supported := '0'B, egprs_pkt_channel_req := omit, bep_period := omit, pfc_feature_mode := '0'B, dtm_support := '0'B, bss_paging_coordination := '1'B, ccn_active := '1'B, nw_ext_utbf := '0'B } }, gprs_pwr_ctrl_params := { alpha := 0, t_avg_w := '10000'B, t_avg_t := '10000'B, pc_meas_chan := '0'B, n_avg_i := '1000'B } } }, si5 := { bcch_freq_list := '10000000000000000000000000000000'O }, si5bis := omit, si5ter := { extd_bcch_freq_list := '9E050020000000000000000000000000'O }, si6 := { cell_id := 0, lai := { mcc_mnc := '001F01'H, lac := 1 }, cell_options := { dtx_ext := '1'B, pwrc := false, dtx := '01'B, radio_link_timeout := '0111'B }, ncc_permitted := '11111111'B, rest_octets := { pch_nch_info := { presence := '0'B, info := omit }, vbs_vgcs_options := { presence := '0'B, options := omit }, dtm_support := '0'B, rac := omit, max_lapdm := omit, band_ind := '0'B } } } MTC@f40282a245d3: Default with id 2 (altstep as_catch_RSL_sysinfo) was deactivated. MTC@f40282a245d3: setverdict(pass): none -> pass MTC@f40282a245d3: Sent on IPA_RSL[0][0] to IPA-BTS0-TRX0-RSL-IPA(104) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_CHAN_RQD (19), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_RACH (17) }, tn := 0 } } }, { iei := RSL_IE_REQ_REFERENCE (19), body := { req_ref := { ra := '23'O ("#"), frame_nr := { t1_p := 0, t3 := 23, t2 := 23 } } } }, { iei := RSL_IE_ACCESS_DELAY (17), body := { access_delay := 0 } } } } } MTC@f40282a245d3: Start timer T: 2 s MTC@f40282a245d3: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_DCHAN (4) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_CHAN_ACTIV (33) unmatched: First message in the queue does not match the template: MTC@f40282a245d3: Matching on port IPA_RSL[0][0] succeeded. MTC@f40282a245d3: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(104): @IPA_Emulation.ASP_RSL_Unitdata: { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_TRX_MGMT (8), transparent := false }, msg_type := RSL_MT_IPAC_MEAS_PREPROC_DFT (96), ies := { { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } } } id 15 MTC@f40282a245d3: Message with id 15 was extracted from the queue of IPA_RSL[0][0]. MTC@f40282a245d3: Matching on port IPA_RSL[0][0] failed: Type of the first message in the queue is not @IPA_Emulation.ASP_RSL_Unitdata. MTC@f40282a245d3: Matching on port IPA_RSL[0][0] succeeded. MTC@f40282a245d3: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(104): @IPA_Emulation.ASP_IPA_Event: { ev_type := ASP_IPA_EVENT_DOWN (0), conn_id := 1, id_resp := omit } id 16 MTC@f40282a245d3: Message with id 16 was extracted from the queue of IPA_RSL[0][0]. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Message enqueued on IPA_RSL_PORT from mtc @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_CHAN_RQD (19), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_RACH (17) }, tn := 0 } } }, { iei := RSL_IE_REQ_REFERENCE (19), body := { req_ref := { ra := '23'O ("#"), frame_nr := { t1_p := 0, t3 := 23, t2 := 23 } } } }, { iei := RSL_IE_ACCESS_DELAY (17), body := { access_delay := 0 } } } } } id 1 [1;34m[testenv][sccplite] Looking for a coredump on lxc host[0m [0;94m[testenv][sccplite] + ['ip', '-j', '-o', '-4', 'addr', 'show', 'dev', 'eth0'][0m [0;94m[testenv][sccplite] No coredump found[0m [1;91m[testenv][sccplite] bsc unexpected exit during BSC_Tests.TC_si2quater_3_earfcns! rc=0[0m [0;94m[testenv][sccplite] Waiting until test has stopped...[0m MTC@f40282a245d3: Timeout T: 2 s MTC@f40282a245d3: setverdict(fail): pass -> fail reason: "Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * }", new component reason: "Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * }" MTC@f40282a245d3: Stopping test component execution. MTC@f40282a245d3: Test case TC_si2quater_3_earfcns was stopped. MTC@f40282a245d3: Terminating component type BSC_Tests.test_CT. MTC@f40282a245d3: Default with id 1 (altstep as_Tguard) was deactivated. MTC@f40282a245d3: Stop timer T_guard: 30 s MTC@f40282a245d3: Message with id 4 was extracted from the queue of IPA_CTRL. MTC@f40282a245d3: Port IPA_CTRL was stopped. MTC@f40282a245d3: Port RSL_CCHAN[0] was stopped. MTC@f40282a245d3: Port RSL_CCHAN[1] was stopped. MTC@f40282a245d3: Port RSL_CCHAN[2] was stopped. MTC@f40282a245d3: Removing unterminated connection between port IPA_RSL[0][0] and IPA-BTS0-TRX0-RSL-IPA(104):IPA_RSL_PORT. MTC@f40282a245d3: Port IPA_RSL[0][0] was stopped. MTC@f40282a245d3: Port IPA_RSL[0][1] was stopped. MTC@f40282a245d3: Port IPA_RSL[0][2] was stopped. MTC@f40282a245d3: Port IPA_RSL[0][3] was stopped. MTC@f40282a245d3: Port IPA_RSL[1][0] was stopped. MTC@f40282a245d3: Port IPA_RSL[1][1] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Connection of port IPA_RSL_PORT to mtc:IPA_RSL[0][0] was closed unexpectedly by the peer. MTC@f40282a245d3: Port IPA_RSL[1][2] was stopped. MTC@f40282a245d3: Port IPA_RSL[1][3] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_RSL_PORT was disconnected from mtc:IPA_RSL[0][0]. MTC@f40282a245d3: Port IPA_RSL[2][0] was stopped. MTC@f40282a245d3: Port IPA_RSL[2][1] was stopped. MTC@f40282a245d3: Port IPA_RSL[2][2] was stopped. MTC@f40282a245d3: Port IPA_RSL[2][3] was stopped. MTC@f40282a245d3: Port IPA was stopped. MTC@f40282a245d3: Port SCCPLITE_IPA_CTRL was stopped. MTC@f40282a245d3: Removing unterminated connection between port IPA_CFG_PORT[0][0] and IPA-BTS0-TRX0-RSL-IPA(104):CFG_PORT. MTC@f40282a245d3: Port IPA_CFG_PORT[0][0] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[0][1] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[0][2] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[0][3] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[1][0] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Connection of port CFG_PORT to mtc:IPA_CFG_PORT[0][0] was closed unexpectedly by the peer. MTC@f40282a245d3: Port IPA_CFG_PORT[1][1] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[1][2] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[1][3] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[2][0] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[2][1] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[2][2] was stopped. MTC@f40282a245d3: Port IPA_CFG_PORT[2][3] was stopped. MTC@f40282a245d3: Removing unterminated mapping between port BSCVTY and system:BSCVTY. MTC@f40282a245d3: Port BSCVTY was unmapped from system:BSCVTY. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port CFG_PORT was disconnected from mtc:IPA_CFG_PORT[0][0]. MTC@f40282a245d3: Message with id 41 was extracted from the queue of BSCVTY. MTC@f40282a245d3: Port BSCVTY was stopped. MTC@f40282a245d3: Port STPVTY was stopped. MTC@f40282a245d3: Removing unterminated connection between port SCCPLITE_IPA_CFG_PORT[0] and VirtMSC-IPA(100):CFG_PORT. MTC@f40282a245d3: Port SCCPLITE_IPA_CFG_PORT[0] was stopped. MTC@f40282a245d3: Port SCCPLITE_IPA_CFG_PORT[1] was stopped. MTC@f40282a245d3: Port SCCPLITE_IPA_CFG_PORT[2] was stopped. VirtMSC-IPA(100)@f40282a245d3: Connection of port CFG_PORT to mtc:SCCPLITE_IPA_CFG_PORT[0] was closed unexpectedly by the peer. MTC@f40282a245d3: Removing unterminated connection between port BSSAP and VirtMSC-SCCP(99):SCCP_SP_PORT. VirtMSC-IPA(100)@f40282a245d3: Port CFG_PORT was disconnected from mtc:SCCPLITE_IPA_CFG_PORT[0]. MTC@f40282a245d3: Port BSSAP was stopped. MTC@f40282a245d3: Port BSSAP_LE was stopped. MTC@f40282a245d3: Component type BSC_Tests.test_CT was shut down inside testcase TC_si2quater_3_earfcns. MTC@f40282a245d3: Waiting for PTCs to finish. VirtMSC-IPA(100)@f40282a245d3: Kill was requested from MC. Terminating idle PTC. VirtMSC-SCCP(99)@f40282a245d3: Connection of port SCCP_SP_PORT to mtc:BSSAP was closed unexpectedly by the peer. VirtMSC-SCCP(99)@f40282a245d3: Port SCCP_SP_PORT was disconnected from mtc:BSSAP. VirtMSC-STATS(98)@f40282a245d3: Kill was requested from MC. VirtMSC-STATS(98)@f40282a245d3: Terminating test component execution. VirtMGW-MGCP-0(103)@f40282a245d3: Kill was requested from MC. VirtMSC-IPA-WAIT(101)@f40282a245d3: Kill was requested from MC. Terminating idle PTC. VirtMSC-SCCP(99)@f40282a245d3: Kill was requested from MC. VirtMSC-SCCP(99)@f40282a245d3: Terminating test component execution. VirtMGW-MGCP-0(103)@f40282a245d3: Terminating test component execution. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Kill was requested from MC. Terminating idle PTC. VirtMSC-IPA-WAIT(101)@f40282a245d3: Terminating component type IPA_Emulation.IPA_EventWaiter_CT. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Terminating component type IPA_Emulation.IPA_Emulation_CT. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Removing unterminated mapping between port IPA_PORT and system:IPA_CODEC_PT. VirtMSC-IPA-WAIT(101)@f40282a245d3: Port IPA_SP_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_PORT was unmapped from system:IPA_CODEC_PT. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_PORT was stopped. VirtMSC-IPA-WAIT(101)@f40282a245d3: Component type IPA_Emulation.IPA_EventWaiter_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMSC-IPA(100)@f40282a245d3: Terminating component type IPA_Emulation.IPA_Emulation_CT. VirtMSC-IPA(100)@f40282a245d3: Removing unterminated mapping between port IPA_PORT and system:IPA_CODEC_PT. VirtMSC-IPA-WAIT(101)@f40282a245d3: Final verdict of PTC: pass IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port CFG_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port MTP3_SP_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_MGCP_PORT was stopped. VirtMSC-SCCP(99)@f40282a245d3: Function SCCPStart was stopped. PTC terminates. VirtMSC-STATS(98)@f40282a245d3: Function main was stopped. PTC terminates. VirtMSC-SCCP(99)@f40282a245d3: Terminating component type SCCP_Emulation.SCCP_CT. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Message with id 1 was extracted from the queue of IPA_RSL_PORT. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_RSL_PORT was stopped. VirtMSC-IPA(100)@f40282a245d3: Port IPA_PORT was unmapped from system:IPA_CODEC_PT. VirtMSC-IPA(100)@f40282a245d3: Port IPA_PORT was stopped. VirtMSC-STATS(98)@f40282a245d3: Terminating component type StatsD_Checker.StatsD_Checker_CT. VirtMSC-STATS(98)@f40282a245d3: Removing unterminated mapping between port STATSVTY and system:STATSVTY. VirtMSC-STATS(98)@f40282a245d3: Port STATSVTY was unmapped from system:STATSVTY. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_OML_PORT was stopped. VirtMSC-IPA(100)@f40282a245d3: Port CFG_PORT was stopped. VirtMSC-SCCP(99)@f40282a245d3: Port SCCP_SP_PORT was stopped. VirtMSC-SCCP(99)@f40282a245d3: Removing unterminated connection between port MTP3_SCCP_PORT and VirtMSC-IPA(100):MTP3_SP_PORT. VirtMSC-IPA(100)@f40282a245d3: Removing unterminated connection between port MTP3_SP_PORT and VirtMSC-SCCP(99):MTP3_SCCP_PORT. VirtMSC-SCCP(99)@f40282a245d3: Port MTP3_SCCP_PORT was stopped. VirtMSC-STATS(98)@f40282a245d3: Message with id 4 was extracted from the queue of STATSVTY. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_CTRL_PORT was stopped. VirtMSC-STATS(98)@f40282a245d3: Port STATSVTY was stopped. VirtMSC-IPA(100)@f40282a245d3: Port MTP3_SP_PORT was stopped. VirtMSC-SCCP(99)@f40282a245d3: Component type SCCP_Emulation.SCCP_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMGW-MGCP-0(103)@f40282a245d3: Function main was stopped. PTC terminates. VirtMSC-IPA(100)@f40282a245d3: Port IPA_MGCP_PORT was stopped. VirtMSC-STATS(98)@f40282a245d3: Port STATSD_PROC was stopped. VirtMSC-STATS(98)@f40282a245d3: Removing unterminated mapping between port STATS and system:STATS. VirtMGW-MGCP-0(103)@f40282a245d3: Terminating component type MGCP_Emulation.MGCP_Emulation_CT. VirtMGW-MGCP-0(103)@f40282a245d3: Removing unterminated mapping between port MGCP and system:MGCP_CODEC_PT. VirtMSC-STATS(98)@f40282a245d3: Port STATS was unmapped from system:STATS. VirtMSC-SCCP(99)@f40282a245d3: Final verdict of PTC: none VirtMSC-IPA(100)@f40282a245d3: Port IPA_RSL_PORT was stopped. VirtMSC-IPA(100)@f40282a245d3: Port IPA_OML_PORT was stopped. VirtMSC-IPA(100)@f40282a245d3: Port IPA_CTRL_PORT was stopped. VirtMSC-IPA(100)@f40282a245d3: Port IPA_SP_PORT was stopped. VirtMSC-IPA(100)@f40282a245d3: Component type IPA_Emulation.IPA_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMSC-IPA(100)@f40282a245d3: Final verdict of PTC: none IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Port IPA_SP_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Component type IPA_Emulation.IPA_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. IPA-BTS0-TRX0-RSL-IPA(104)@f40282a245d3: Final verdict of PTC: none VirtMSC-STATS(98)@f40282a245d3: Port STATS was stopped. VirtMGW-MGCP-0(103)@f40282a245d3: Port MGCP was unmapped from system:MGCP_CODEC_PT. VirtMGW-MGCP-0(103)@f40282a245d3: Port MGCP was stopped. VirtMSC-STATS(98)@f40282a245d3: Component type StatsD_Checker.StatsD_Checker_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMGW-MGCP-0(103)@f40282a245d3: Port MGCP_CLIENT was stopped. VirtMSC-STATS(98)@f40282a245d3: Final verdict of PTC: none VirtMGW-MGCP-0(103)@f40282a245d3: Port MGCP_CLIENT_MULTI was stopped. VirtMGW-MGCP-0(103)@f40282a245d3: Port MGCP_PROC was stopped. VirtMGW-MGCP-0(103)@f40282a245d3: Component type MGCP_Emulation.MGCP_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMGW-MGCP-0(103)@f40282a245d3: Final verdict of PTC: none MTC@f40282a245d3: Setting final verdict of the test case. MTC@f40282a245d3: Local verdict of MTC: fail reason: "Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * }" MTC@f40282a245d3: Local verdict of PTC VirtMSC-STATS(98): none (fail -> fail) MTC@f40282a245d3: Local verdict of PTC VirtMSC-SCCP(99): none (fail -> fail) MTC@f40282a245d3: Local verdict of PTC VirtMSC-IPA(100): none (fail -> fail) MTC@f40282a245d3: Local verdict of PTC VirtMSC-IPA-WAIT(101): pass (fail -> fail) MTC@f40282a245d3: Local verdict of PTC IPA-CTRL-CLI-IPA(102): none (fail -> fail) MTC@f40282a245d3: Local verdict of PTC VirtMGW-MGCP-0(103): none (fail -> fail) MTC@f40282a245d3: Local verdict of PTC IPA-BTS0-TRX0-RSL-IPA(104): none (fail -> fail) MTC@f40282a245d3: Test case TC_si2quater_3_earfcns finished. Verdict: fail reason: Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * } MTC@f40282a245d3: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/ws/ttcn3-tcpdump-stop.sh BSC_Tests.TC_si2quater_3_earfcns fail'. Fri Jul 4 13:21:19 UTC 2025 [1;31m------ BSC_Tests.TC_si2quater_3_earfcns fail ------[0m
Saving talloc report from 127.0.0.1:4242 to BSC_Tests.TC_si2quater_3_earfcns.talloc [1;36m[1;31mDOML[0;m[1;36m bts_shutdown_fsm.c:228 BTS_SHUTDOWN(bts0)[0x6120000006a0]{WAIT_TRX_CLOSED}: Timer expired waiting for TRX close[0;m [1;36m[1;33mDOML[0;m[1;36m bts_shutdown_fsm.c:171 BTS_SHUTDOWN(bts0)[0x6120000006a0]{EXIT}: Shutdown process completed successfully, exiting process[0;m [1;36m[1;31mDOML[0;m[1;36m bts_shutdown_fsm.c:228 BTS_SHUTDOWN(bts0)[0x6120000006a0]{WAIT_TRX_CLOSED}: Timer expired waiting for TRX close[0;m [1;36m[1;33mDOML[0;m[1;36m bts_shutdown_fsm.c:171 BTS_SHUTDOWN(bts0)[0x6120000006a0]{EXIT}: Shutdown process completed successfully, exiting process[0;m [1;36m[1;31mDOML[0;m[1;36m bts_shutdown_fsm.c:228 BTS_SHUTDOWN(bts0)[0x6120000006a0]{WAIT_TRX_CLOSED}: Timer expired waiting for TRX close[0;m [1;36m[1;33mDOML[0;m[1;36m bts_shutdown_fsm.c:171 BTS_SHUTDOWN(bts0)[0x6120000006a0]{EXIT}: Shutdown process completed successfully, exiting process[0;m respawn: 10: stopped pid 12520 with status 0 respawn: 11: starting: osmo-bts-omldummy -fCCN,EGPRS,GPRS,IPv6_NSVC,PAGING_COORDINATION,OSMUX 127.0.0.1 1234 1 respawn: 2: stopped pid 12162 with status 0 respawn: 1: stopped pid 12164 with status 0 respawn: 3: starting: osmo-bts-omldummy -fCCN,EGPRS,GPRS,IPv6_NSVC,PAGING_COORDINATION,OSMUX 127.0.0.1 1235 1 respawn: 2: starting: osmo-bts-omldummy -fCCN,EGPRS,GPRS,IPv6_NSVC,PAGING_COORDINATION,OSMUX 127.0.0.1 1236 4 [1;33mDABIS[0;m abis.c:170 A-bis connection establishment to BSC (127.0.0.1) in progress... [38;5;23m[1;33mDLINP[0;m[38;5;23m input/ipaccess.c:1078 E1TS(0:1) enabling ipaccess BTS mode, OML connecting to 127.0.0.1:3002[0;m [38;5;23m[1;31mDLINP[0;m[38;5;23m stream_cli.c:424 CLICONN(ts-0-1-oml,){CONNECTING} connect failed (-111)[0;m [1;31mDABIS[0;m abis.c:429 E1L(0) Signalling link down [1;33mDABIS[0;m abis.c:170 A-bis connection establishment to BSC (127.0.0.1) in progress... [38;5;23m[1;33mDLINP[0;m[38;5;23m input/ipaccess.c:1078 E1TS(0:1) enabling ipaccess BTS mode, OML connecting to 127.0.0.1:3002[0;m [38;5;23m[1;31mDLINP[0;m[38;5;23m stream_cli.c:424 CLICONN(ts-0-1-oml,){CONNECTING} connect failed (-111)[0;m [1;31mDABIS[0;m abis.c:429 E1L(0) Signalling link down [1;33mDABIS[0;m abis.c:170 A-bis connection establishment to BSC (127.0.0.1) in progress... [38;5;23m[1;33mDLINP[0;m[38;5;23m input/ipaccess.c:1078 E1TS(0:1) enabling ipaccess BTS mode, OML connecting to 127.0.0.1:3002[0;m [38;5;23m[1;31mDLINP[0;m[38;5;23m stream_cli.c:424 CLICONN(ts-0-1-oml,){CONNECTING} connect failed (-111)[0;m [1;31mDABIS[0;m abis.c:429 E1L(0) Signalling link down Traceback (most recent call last): File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 420, in main_run_commands interact.connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/vty.py", line 84, in connect super().connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 88, in connect self.socket.connect((self.host, int(self.port))) ConnectionRefusedError: [Errno 111] Connection refused Waiting for packet dumper to finish... 0 (prev_count=-1, count=125644) Waiting for packet dumper to finish... 1 (prev_count=125644, count=127016) MTC@f40282a245d3: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/ws/ttcn3-tcpdump-stop.sh BSC_Tests.TC_si2quater_3_earfcns fail' was executed successfully (exit status: 0). MTC@f40282a245d3: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/ws/ttcn3-tcpdump-start.sh BSC_Tests.TC_si2quater_4_earfcns'. ------ BSC_Tests.TC_si2quater_4_earfcns ------ Fri Jul 4 13:21:24 UTC 2025 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/1/artifact/logs/testsuite/BSC_Tests.TC_si2quater_4_earfcns.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/1/artifact/logs/testsuite/BSC_Tests.TC_si2quater_4_earfcns.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [1;34m[testenv][sccplite] Stopping podman container[0m [0;94m[testenv][sccplite] + ['podman', 'kill', 'testenv-bsc-sccplite-osmocom-nightly-asan-20250704-1317-a75c3780-0'][0m testenv-bsc-sccplite-osmocom-nightly-asan-20250704-1317-a75c3780-0 [1;34m[testenv][sccplite] Stopping testsuite (2419737)[0m [0;94m[testenv] feed_watchdog_loop: podman container has stopped[0m [1;34m[testenv][sccplite] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/1/artif... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 1.37, 1.20, 1.01[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.
See https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/2/display/redirect?page=changes
Changes:
[Oliver Smith] Cosmetic: testenv: tweak argparse formatting
[Oliver Smith] testenv: add run --asan
------------------------------------------ [...truncated 5.82 MiB...] MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies[0].body{ ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } with { sysinfo_type := ? } unmatched.rsl.ies[1].body{ bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } with { l3_info := { len := ?, payload := ? } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Terminating component type IPA_Emulation.IPA_Emulation_CT. IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Removing unterminated mapping between port IPA_PORT and system:IPA_CODEC_PT. MTC@f2c28f886b10: Message enqueued on IPA_RSL[0][0] from IPA-BTS0-TRX0-RSL-IPA(104) @IPA_Emulation.ASP_IPA_Event : { ev_type := ASP_IPA_EVENT_DOWN (0), conn_id := 1, id_resp := omit } id 16 IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_PORT was unmapped from system:IPA_CODEC_PT. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port CFG_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port MTP3_SP_PORT was stopped. IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_MGCP_PORT was stopped. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } }, { iei := ?, body := { other := { len := ?, payload := ? } } }, * } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_RSL_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Function main_client was stopped. PTC remains alive and is waiting for next start. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_OML_PORT was stopped. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies[0].body{ ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } with { sysinfo_type := ? } unmatched.rsl.ies[1].body{ bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } with { l3_info := { len := ?, payload := ? } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Removing unterminated connection between port IPA_CTRL_PORT and mtc:IPA_CTRL. MTC@f2c28f886b10: Connection of port IPA_CTRL to IPA-CTRL-CLI-IPA(102):IPA_CTRL_PORT was closed unexpectedly by the peer. IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_CTRL_PORT was stopped. MTC@f2c28f886b10: Port IPA_CTRL was disconnected from IPA-CTRL-CLI-IPA(102):IPA_CTRL_PORT. IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Port IPA_SP_PORT was stopped. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Component type IPA_Emulation.IPA_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_CCHAN (6) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_BCCH_INFO (17) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_BCCH (16) }, tn := 0 } } }, { iei := ?, body := { sysinfo_type := ? } }, { iei := ?, body := { other := { len := ?, payload := ? } } }, * } unmatched: First message in the queue does not match the template: IPA-CTRL-CLI-IPA(102)@f2c28f886b10: Final verdict of PTC: none MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies{ { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } with { { iei := ?, body := { sysinfo_type := ? } } } unmatched: First message in the queue does not match the template: MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_SACCH_FILL (26) unmatched.rsl.ies[0].body{ ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } with { sysinfo_type := ? } unmatched.rsl.ies[1].body{ bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } with { l3_info := { len := ?, payload := ? } } unmatched: First message in the queue does not match the template: [1;34m[testenv][sccplite] Looking for a coredump on lxc host[0m [0;94m[testenv][sccplite] + ['ip', '-j', '-o', '-4', 'addr', 'show', 'dev', 'eth0'][0m [0;94m[testenv][sccplite] No coredump found[0m [1;91m[testenv][sccplite] bsc unexpected exit during BSC_Tests.TC_si2quater_3_earfcns! rc=0[0m [0;94m[testenv][sccplite] Waiting until test has stopped...[0m MTC@f2c28f886b10: Timeout T: 5 s MTC@f2c28f886b10: RSL 0 SYSTEM INFORMATION: { si1 := { cell_chan_desc := '8FB38000000000000000000000000000'O, 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 := '2B'O ("+") }, 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 } }, si2bis := omit, si2ter := { extd_bcch_freq_list := '8E320000000000000000000000000800'O, rest_octets := '2B2B2B2B'O ("++++") }, si2quater := { { ba_ind := '0'B, ba_3g_ind := '1'B, mp_change_mark := '0'B, si2quater_index := 0, si2quater_count := 0, meas_params_desc := { presence := '0'B, desc := omit }, gprs := { rt_diff_desc := { presence := '0'B, desc := omit }, bsic_desc := { presence := '0'B, desc := omit }, rep_prio_desc := { presence := '0'B, desc := omit }, meas_params_desc := { presence := '0'B, desc := omit } }, nc_meas_params := { presence := '0'B, params := omit }, ext_info := { presence := '0'B, info := omit }, utran_neigh_desc := { presence := '0'B, desc := omit }, utran_meas_params_desc := { presence := '0'B, desc := omit }, utran_gprs_meas_params_desc := { presence := '0'B, desc := omit }, rel_additions := { rel5_presence := '1'B, rel5 := { umts_add_meas_params_desc := { presence := '0'B, desc := omit }, umts_add_meas_params_desc2 := { presence := '0'B, desc := omit }, rel6_presence := '1'B, rel6 := { umts_ccn_active := '0'B, rel7_presence := '1'B, rel7 := { rep700 := { presence := '0'B, val := omit }, rep810 := { presence := '0'B, val := omit }, rel8_presence := '1'B, rel8 := { prio_eutran_params_desc := { presence := '1'B, desc := { sc_prio_params_desc := { presence := '1'B, desc := { geran_priority := 0, thresh_priority_search := 0, thresh_gsm_low := 0, h_prio := 0, t_reselection := 0 } }, utran_prio_params_desc := { presence := '0'B, desc := omit }, eutran_params_desc := { presence := '1'B, desc := { ccn_active := '0'B, e_start := '1'B, e_stop := '1'B, meas_params_desc := { presence := '0'B, desc := omit }, gprs_meas_params_desc := { presence := '0'B, desc := omit }, repeated_neigh_cells := { { item_ind := '1'B, cell_desc_list := { { item_ind := '1'B, e_arfcn := 111, meas_bw_presence := '1'B, meas_bw := 3 }, { item_ind := '1'B, e_arfcn := 1, meas_bw_presence := '1'B, meas_bw := 3 }, { item_ind := '1'B, e_arfcn := 0, meas_bw_presence := '1'B, meas_bw := 3 } }, cell_desc_list_term := '0'B, prio_presence := '1'B, prio := 3, thresh_high := 20, thresh_low_presence := '1'B, thresh_low := 10, qrxlevmin_presence := '1'B, qrxlevmin := 22 } }, repeated_neigh_cells_term := '0'B, repeated_not_allowed_cells := omit, repeated_not_allowed_cells_term := '0'B, pcid2ta_map_list := omit, pcid2ta_map_list_term := '0'B } } } }, utran_csg_desc := { presence := '0'B, desc := omit }, eutran_csg_desc := { presence := '0'B, desc := omit } } } } } } } }, si3 := { cell_id := 0, lai := { mcc_mnc := '001F01'H, lac := 1 }, 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 := 3, t3212 := 30 }, cell_options := { dn_ind := false, pwrc := false, dtx := MS_SHALL_USE_UL_DTX (1), 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 := '1'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 := '1'B, si2_quater_ind := { presence := '1'B, ind := '0'B }, iu_mode_ind := omit, si21_ind := { presence := '0'B, pos := omit } } }, si4 := { lai := { mcc_mnc := '001F01'H, lac := 1 }, 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 := { iei := '64'O ("d"), v := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 2 } }, tn := 0 }, tsc := 2, h := false, arfcn := 871, maio_hsn := 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 } }, si13 := { rest_octets := { presence := '1'B, bcch_change_mark := 1, si_change_field := '0000'B, presence2 := '0'B, si13_change_mark := omit, gprs_ma := omit, zero := '0'B, rac := 0, spgc_ccch_sup := '0'B, priority_access_thr := '110'B, network_control_order := '00'B, gprs_cell_opts := { nmo := '01'B, t3168 := '011'B, t3192 := '010'B, drx_timer_max := '011'B, access_burst_type := '0'B, control_ack_type := '1'B, bs_cv_max := 15, pan_presence := '1'B, pan_dec := 1, pan_inc := 1, pan_max := '111'B, ext_info_presence := '1'B, ext_info_length := '000101'B, ext_info := { egprs_supported := '0'B, egprs_pkt_channel_req := omit, bep_period := omit, pfc_feature_mode := '0'B, dtm_support := '0'B, bss_paging_coordination := '1'B, ccn_active := '1'B, nw_ext_utbf := '0'B } }, gprs_pwr_ctrl_params := { alpha := 0, t_avg_w := '10000'B, t_avg_t := '10000'B, pc_meas_chan := '0'B, n_avg_i := '1000'B } } }, si5 := { bcch_freq_list := '10000000000000000000000000000000'O }, si5bis := omit, si5ter := { extd_bcch_freq_list := '9E050020000000000000000000000000'O }, si6 := { cell_id := 0, lai := { mcc_mnc := '001F01'H, lac := 1 }, cell_options := { dtx_ext := '1'B, pwrc := false, dtx := '01'B, radio_link_timeout := '0111'B }, ncc_permitted := '11111111'B, rest_octets := { pch_nch_info := { presence := '0'B, info := omit }, vbs_vgcs_options := { presence := '0'B, options := omit }, dtm_support := '0'B, rac := omit, max_lapdm := omit, band_ind := '0'B } } } MTC@f2c28f886b10: Default with id 2 (altstep as_catch_RSL_sysinfo) was deactivated. MTC@f2c28f886b10: setverdict(pass): none -> pass MTC@f2c28f886b10: Sent on IPA_RSL[0][0] to IPA-BTS0-TRX0-RSL-IPA(104) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_CHAN_RQD (19), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_RACH (17) }, tn := 0 } } }, { iei := RSL_IE_REQ_REFERENCE (19), body := { req_ref := { ra := '23'O ("#"), frame_nr := { t1_p := 0, t3 := 23, t2 := 23 } } } }, { iei := RSL_IE_ACCESS_DELAY (17), body := { access_delay := 0 } } } } } MTC@f2c28f886b10: Start timer T: 2 s MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] RSL_MDISC_TRX_MGMT (8) with RSL_MDISC_DCHAN (4) unmatchedRSL_MT_IPAC_MEAS_PREPROC_DFT (96) with RSL_MT_CHAN_ACTIV (33) unmatched: First message in the queue does not match the template: MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] succeeded. MTC@f2c28f886b10: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(104): @IPA_Emulation.ASP_RSL_Unitdata: { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_TRX_MGMT (8), transparent := false }, msg_type := RSL_MT_IPAC_MEAS_PREPROC_DFT (96), ies := { { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 0 } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 55, params := '062026300A0A0C131405070F120242F10C000000000000000000000000F218000000000000000000000000000000000000000000000000'O } } } } } } id 15 IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Message enqueued on IPA_RSL_PORT from mtc @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_CHAN_RQD (19), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_RACH (17) }, tn := 0 } } }, { iei := RSL_IE_REQ_REFERENCE (19), body := { req_ref := { ra := '23'O ("#"), frame_nr := { t1_p := 0, t3 := 23, t2 := 23 } } } }, { iei := RSL_IE_ACCESS_DELAY (17), body := { access_delay := 0 } } } } } id 1 MTC@f2c28f886b10: Message with id 15 was extracted from the queue of IPA_RSL[0][0]. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] failed: Type of the first message in the queue is not @IPA_Emulation.ASP_RSL_Unitdata. MTC@f2c28f886b10: Matching on port IPA_RSL[0][0] succeeded. MTC@f2c28f886b10: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(104): @IPA_Emulation.ASP_IPA_Event: { ev_type := ASP_IPA_EVENT_DOWN (0), conn_id := 1, id_resp := omit } id 16 MTC@f2c28f886b10: Message with id 16 was extracted from the queue of IPA_RSL[0][0]. MTC@f2c28f886b10: Timeout T: 2 s MTC@f2c28f886b10: setverdict(fail): pass -> fail reason: "Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * }", new component reason: "Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * }" MTC@f2c28f886b10: Stopping test component execution. MTC@f2c28f886b10: Test case TC_si2quater_3_earfcns was stopped. MTC@f2c28f886b10: Terminating component type BSC_Tests.test_CT. MTC@f2c28f886b10: Default with id 1 (altstep as_Tguard) was deactivated. MTC@f2c28f886b10: Stop timer T_guard: 30 s MTC@f2c28f886b10: Message with id 4 was extracted from the queue of IPA_CTRL. MTC@f2c28f886b10: Port IPA_CTRL was stopped. MTC@f2c28f886b10: Port RSL_CCHAN[0] was stopped. MTC@f2c28f886b10: Port RSL_CCHAN[1] was stopped. MTC@f2c28f886b10: Port RSL_CCHAN[2] was stopped. MTC@f2c28f886b10: Removing unterminated connection between port IPA_RSL[0][0] and IPA-BTS0-TRX0-RSL-IPA(104):IPA_RSL_PORT. MTC@f2c28f886b10: Port IPA_RSL[0][0] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Connection of port IPA_RSL_PORT to mtc:IPA_RSL[0][0] was closed unexpectedly by the peer. MTC@f2c28f886b10: Port IPA_RSL[0][1] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_RSL_PORT was disconnected from mtc:IPA_RSL[0][0]. MTC@f2c28f886b10: Port IPA_RSL[0][2] was stopped. MTC@f2c28f886b10: Port IPA_RSL[0][3] was stopped. MTC@f2c28f886b10: Port IPA_RSL[1][0] was stopped. MTC@f2c28f886b10: Port IPA_RSL[1][1] was stopped. MTC@f2c28f886b10: Port IPA_RSL[1][2] was stopped. MTC@f2c28f886b10: Port IPA_RSL[1][3] was stopped. MTC@f2c28f886b10: Port IPA_RSL[2][0] was stopped. MTC@f2c28f886b10: Port IPA_RSL[2][1] was stopped. MTC@f2c28f886b10: Port IPA_RSL[2][2] was stopped. MTC@f2c28f886b10: Port IPA_RSL[2][3] was stopped. MTC@f2c28f886b10: Port IPA was stopped. MTC@f2c28f886b10: Port SCCPLITE_IPA_CTRL was stopped. MTC@f2c28f886b10: Removing unterminated connection between port IPA_CFG_PORT[0][0] and IPA-BTS0-TRX0-RSL-IPA(104):CFG_PORT. MTC@f2c28f886b10: Port IPA_CFG_PORT[0][0] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[0][1] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Connection of port CFG_PORT to mtc:IPA_CFG_PORT[0][0] was closed unexpectedly by the peer. MTC@f2c28f886b10: Port IPA_CFG_PORT[0][2] was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port CFG_PORT was disconnected from mtc:IPA_CFG_PORT[0][0]. MTC@f2c28f886b10: Port IPA_CFG_PORT[0][3] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[1][0] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[1][1] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[1][2] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[1][3] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[2][0] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[2][1] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[2][2] was stopped. MTC@f2c28f886b10: Port IPA_CFG_PORT[2][3] was stopped. MTC@f2c28f886b10: Removing unterminated mapping between port BSCVTY and system:BSCVTY. MTC@f2c28f886b10: Port BSCVTY was unmapped from system:BSCVTY. MTC@f2c28f886b10: Message with id 41 was extracted from the queue of BSCVTY. MTC@f2c28f886b10: Port BSCVTY was stopped. MTC@f2c28f886b10: Port STPVTY was stopped. MTC@f2c28f886b10: Removing unterminated connection between port SCCPLITE_IPA_CFG_PORT[0] and VirtMSC-IPA(100):CFG_PORT. MTC@f2c28f886b10: Port SCCPLITE_IPA_CFG_PORT[0] was stopped. VirtMSC-IPA(100)@f2c28f886b10: Connection of port CFG_PORT to mtc:SCCPLITE_IPA_CFG_PORT[0] was closed unexpectedly by the peer. MTC@f2c28f886b10: Port SCCPLITE_IPA_CFG_PORT[1] was stopped. VirtMSC-IPA(100)@f2c28f886b10: Port CFG_PORT was disconnected from mtc:SCCPLITE_IPA_CFG_PORT[0]. MTC@f2c28f886b10: Port SCCPLITE_IPA_CFG_PORT[2] was stopped. MTC@f2c28f886b10: Removing unterminated connection between port BSSAP and VirtMSC-SCCP(99):SCCP_SP_PORT. MTC@f2c28f886b10: Port BSSAP was stopped. VirtMSC-SCCP(99)@f2c28f886b10: Connection of port SCCP_SP_PORT to mtc:BSSAP was closed unexpectedly by the peer. MTC@f2c28f886b10: Port BSSAP_LE was stopped. VirtMSC-SCCP(99)@f2c28f886b10: Port SCCP_SP_PORT was disconnected from mtc:BSSAP. MTC@f2c28f886b10: Component type BSC_Tests.test_CT was shut down inside testcase TC_si2quater_3_earfcns. MTC@f2c28f886b10: Waiting for PTCs to finish. VirtMSC-SCCP(99)@f2c28f886b10: Kill was requested from MC. VirtMSC-IPA(100)@f2c28f886b10: Kill was requested from MC. Terminating idle PTC. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Kill was requested from MC. Terminating idle PTC. VirtMSC-SCCP(99)@f2c28f886b10: Terminating test component execution. VirtMSC-IPA(100)@f2c28f886b10: Terminating component type IPA_Emulation.IPA_Emulation_CT. VirtMSC-IPA-WAIT(101)@f2c28f886b10: Kill was requested from MC. Terminating idle PTC. VirtMGW-MGCP-0(103)@f2c28f886b10: Kill was requested from MC. VirtMSC-STATS(98)@f2c28f886b10: Kill was requested from MC. VirtMSC-STATS(98)@f2c28f886b10: Terminating test component execution. VirtMSC-IPA-WAIT(101)@f2c28f886b10: Terminating component type IPA_Emulation.IPA_EventWaiter_CT. VirtMGW-MGCP-0(103)@f2c28f886b10: Terminating test component execution. VirtMSC-IPA(100)@f2c28f886b10: Removing unterminated mapping between port IPA_PORT and system:IPA_CODEC_PT. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Terminating component type IPA_Emulation.IPA_Emulation_CT. VirtMSC-IPA-WAIT(101)@f2c28f886b10: Port IPA_SP_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Removing unterminated mapping between port IPA_PORT and system:IPA_CODEC_PT. VirtMSC-IPA-WAIT(101)@f2c28f886b10: Component type IPA_Emulation.IPA_EventWaiter_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMSC-IPA-WAIT(101)@f2c28f886b10: Final verdict of PTC: pass IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_PORT was unmapped from system:IPA_CODEC_PT. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_PORT was unmapped from system:IPA_CODEC_PT. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_PORT was stopped. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port CFG_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port MTP3_SP_PORT was stopped. VirtMSC-IPA(100)@f2c28f886b10: Port CFG_PORT was stopped. VirtMSC-IPA(100)@f2c28f886b10: Removing unterminated connection between port MTP3_SP_PORT and VirtMSC-SCCP(99):MTP3_SCCP_PORT. VirtMSC-SCCP(99)@f2c28f886b10: Function SCCPStart was stopped. PTC terminates. VirtMSC-STATS(98)@f2c28f886b10: Function main was stopped. PTC terminates. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_MGCP_PORT was stopped. VirtMSC-IPA(100)@f2c28f886b10: Port MTP3_SP_PORT was stopped. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_MGCP_PORT was stopped. VirtMSC-STATS(98)@f2c28f886b10: Terminating component type StatsD_Checker.StatsD_Checker_CT. VirtMSC-STATS(98)@f2c28f886b10: Removing unterminated mapping between port STATSVTY and system:STATSVTY. VirtMSC-SCCP(99)@f2c28f886b10: Terminating component type SCCP_Emulation.SCCP_CT. VirtMSC-STATS(98)@f2c28f886b10: Port STATSVTY was unmapped from system:STATSVTY. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_RSL_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Message with id 1 was extracted from the queue of IPA_RSL_PORT. VirtMGW-MGCP-0(103)@f2c28f886b10: Function main was stopped. PTC terminates. VirtMSC-SCCP(99)@f2c28f886b10: Port SCCP_SP_PORT was stopped. VirtMSC-SCCP(99)@f2c28f886b10: Removing unterminated connection between port MTP3_SCCP_PORT and VirtMSC-IPA(100):MTP3_SP_PORT. VirtMGW-MGCP-0(103)@f2c28f886b10: Terminating component type MGCP_Emulation.MGCP_Emulation_CT. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_OML_PORT was stopped. VirtMSC-STATS(98)@f2c28f886b10: Message with id 4 was extracted from the queue of STATSVTY. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_RSL_PORT was stopped. VirtMGW-MGCP-0(103)@f2c28f886b10: Removing unterminated mapping between port MGCP and system:MGCP_CODEC_PT. VirtMSC-SCCP(99)@f2c28f886b10: Port MTP3_SCCP_PORT was stopped. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_CTRL_PORT was stopped. VirtMSC-STATS(98)@f2c28f886b10: Port STATSVTY was stopped. VirtMSC-SCCP(99)@f2c28f886b10: Component type SCCP_Emulation.SCCP_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMSC-IPA(100)@f2c28f886b10: Port IPA_SP_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_OML_PORT was stopped. VirtMSC-STATS(98)@f2c28f886b10: Port STATSD_PROC was stopped. VirtMSC-IPA(100)@f2c28f886b10: Component type IPA_Emulation.IPA_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMSC-SCCP(99)@f2c28f886b10: Final verdict of PTC: none IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_CTRL_PORT was stopped. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Port IPA_SP_PORT was stopped. VirtMSC-STATS(98)@f2c28f886b10: Removing unterminated mapping between port STATS and system:STATS. IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Component type IPA_Emulation.IPA_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMSC-IPA(100)@f2c28f886b10: Final verdict of PTC: none IPA-BTS0-TRX0-RSL-IPA(104)@f2c28f886b10: Final verdict of PTC: none VirtMGW-MGCP-0(103)@f2c28f886b10: Port MGCP was unmapped from system:MGCP_CODEC_PT. VirtMSC-STATS(98)@f2c28f886b10: Port STATS was unmapped from system:STATS. VirtMGW-MGCP-0(103)@f2c28f886b10: Port MGCP was stopped. VirtMGW-MGCP-0(103)@f2c28f886b10: Port MGCP_CLIENT was stopped. VirtMSC-STATS(98)@f2c28f886b10: Port STATS was stopped. VirtMGW-MGCP-0(103)@f2c28f886b10: Port MGCP_CLIENT_MULTI was stopped. VirtMSC-STATS(98)@f2c28f886b10: Component type StatsD_Checker.StatsD_Checker_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMGW-MGCP-0(103)@f2c28f886b10: Port MGCP_PROC was stopped. VirtMSC-STATS(98)@f2c28f886b10: Final verdict of PTC: none VirtMGW-MGCP-0(103)@f2c28f886b10: Component type MGCP_Emulation.MGCP_Emulation_CT was shut down inside testcase TC_si2quater_3_earfcns. VirtMGW-MGCP-0(103)@f2c28f886b10: Final verdict of PTC: none MTC@f2c28f886b10: Setting final verdict of the test case. MTC@f2c28f886b10: Local verdict of MTC: fail reason: "Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * }" MTC@f2c28f886b10: Local verdict of PTC VirtMSC-STATS(98): none (fail -> fail) MTC@f2c28f886b10: Local verdict of PTC VirtMSC-SCCP(99): none (fail -> fail) MTC@f2c28f886b10: Local verdict of PTC VirtMSC-IPA(100): none (fail -> fail) MTC@f2c28f886b10: Local verdict of PTC VirtMSC-IPA-WAIT(101): pass (fail -> fail) MTC@f2c28f886b10: Local verdict of PTC IPA-CTRL-CLI-IPA(102): none (fail -> fail) MTC@f2c28f886b10: Local verdict of PTC VirtMGW-MGCP-0(103): none (fail -> fail) MTC@f2c28f886b10: Local verdict of PTC IPA-BTS0-TRX0-RSL-IPA(104): none (fail -> fail) MTC@f2c28f886b10: Test case TC_si2quater_3_earfcns finished. Verdict: fail reason: Timeout expecting { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := ? }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := * } MTC@f2c28f886b10: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/ws/ttcn3-tcpdump-stop.sh BSC_Tests.TC_si2quater_3_earfcns fail'. Fri Jul 4 16:26:26 UTC 2025 [1;31m------ BSC_Tests.TC_si2quater_3_earfcns fail ------[0m
Saving talloc report from 127.0.0.1:4242 to BSC_Tests.TC_si2quater_3_earfcns.talloc [1;36m[1;31mDOML[0;m[1;36m bts_shutdown_fsm.c:228 BTS_SHUTDOWN(bts0)[0x6120000006a0]{WAIT_TRX_CLOSED}: Timer expired waiting for TRX close[0;m [1;36m[1;33mDOML[0;m[1;36m bts_shutdown_fsm.c:171 BTS_SHUTDOWN(bts0)[0x6120000006a0]{EXIT}: Shutdown process completed successfully, exiting process[0;m [1;36m[1;31mDOML[0;m[1;36m bts_shutdown_fsm.c:228 BTS_SHUTDOWN(bts0)[0x6120000006a0]{WAIT_TRX_CLOSED}: Timer expired waiting for TRX close[0;m [1;36m[1;33mDOML[0;m[1;36m bts_shutdown_fsm.c:171 BTS_SHUTDOWN(bts0)[0x6120000006a0]{EXIT}: Shutdown process completed successfully, exiting process[0;m [1;36m[1;31mDOML[0;m[1;36m bts_shutdown_fsm.c:228 BTS_SHUTDOWN(bts0)[0x6120000006a0]{WAIT_TRX_CLOSED}: Timer expired waiting for TRX close[0;m [1;36m[1;33mDOML[0;m[1;36m bts_shutdown_fsm.c:171 BTS_SHUTDOWN(bts0)[0x6120000006a0]{EXIT}: Shutdown process completed successfully, exiting process[0;m respawn: 2: stopped pid 10273 with status 0 respawn: 10: stopped pid 10632 with status 0 respawn: 1: stopped pid 10269 with status 0 respawn: 3: starting: osmo-bts-omldummy -fCCN,EGPRS,GPRS,IPv6_NSVC,PAGING_COORDINATION,OSMUX 127.0.0.1 1235 1 respawn: 11: starting: osmo-bts-omldummy -fCCN,EGPRS,GPRS,IPv6_NSVC,PAGING_COORDINATION,OSMUX 127.0.0.1 1234 1 respawn: 2: starting: osmo-bts-omldummy -fCCN,EGPRS,GPRS,IPv6_NSVC,PAGING_COORDINATION,OSMUX 127.0.0.1 1236 4 [1;33mDABIS[0;m abis.c:170 A-bis connection establishment to BSC (127.0.0.1) in progress... [1;33mDABIS[0;m abis.c:170 A-bis connection establishment to BSC (127.0.0.1) in progress... [38;5;23m[1;33mDLINP[0;m[38;5;23m input/ipaccess.c:1078 E1TS(0:1) enabling ipaccess BTS mode, OML connecting to 127.0.0.1:3002[0;m [38;5;23m[1;33mDLINP[0;m[38;5;23m input/ipaccess.c:1078 E1TS(0:1) enabling ipaccess BTS mode, OML connecting to 127.0.0.1:3002[0;m [38;5;23m[1;31mDLINP[0;m[38;5;23m stream_cli.c:424 CLICONN(ts-0-1-oml,){CONNECTING} connect failed (-111)[0;m [1;31mDABIS[0;m abis.c:429 E1L(0) Signalling link down [38;5;23m[1;31mDLINP[0;m[38;5;23m stream_cli.c:424 CLICONN(ts-0-1-oml,){CONNECTING} connect failed (-111)[0;m [1;31mDABIS[0;m abis.c:429 E1L(0) Signalling link down [1;33mDABIS[0;m abis.c:170 A-bis connection establishment to BSC (127.0.0.1) in progress... [38;5;23m[1;33mDLINP[0;m[38;5;23m input/ipaccess.c:1078 E1TS(0:1) enabling ipaccess BTS mode, OML connecting to 127.0.0.1:3002[0;m [38;5;23m[1;31mDLINP[0;m[38;5;23m stream_cli.c:424 CLICONN(ts-0-1-oml,){CONNECTING} connect failed (-111)[0;m [1;31mDABIS[0;m abis.c:429 E1L(0) Signalling link down Traceback (most recent call last): File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 420, in main_run_commands interact.connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/vty.py", line 84, in connect super().connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 88, in connect self.socket.connect((self.host, int(self.port))) ConnectionRefusedError: [Errno 111] Connection refused Waiting for packet dumper to finish... 0 (prev_count=-1, count=125236) Waiting for packet dumper to finish... 1 (prev_count=125236, count=126608) MTC@f2c28f886b10: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/ws/ttcn3-tcpdump-stop.sh BSC_Tests.TC_si2quater_3_earfcns fail' was executed successfully (exit status: 0). MTC@f2c28f886b10: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/ws/ttcn3-tcpdump-start.sh BSC_Tests.TC_si2quater_4_earfcns'. ------ BSC_Tests.TC_si2quater_4_earfcns ------ Fri Jul 4 16:26:31 UTC 2025 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/2/artifact/logs/testsuite/BSC_Tests.TC_si2quater_4_earfcns.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/2/artifact/logs/testsuite/BSC_Tests.TC_si2quater_4_earfcns.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [1;34m[testenv][sccplite] Stopping podman container[0m [0;94m[testenv][sccplite] + ['podman', 'kill', 'testenv-bsc-sccplite-osmocom-nightly-asan-20250704-1623-8bc3784a-0'][0m testenv-bsc-sccplite-osmocom-nightly-asan-20250704-1623-8bc3784a-0 [1;34m[testenv][sccplite] Stopping testsuite (3808459)[0m [0;94m[testenv] feed_watchdog_loop: podman container has stopped[0m [1;34m[testenv][sccplite] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite-asan/2/artif... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 0.70, 0.56, 1.63[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.
jenkins-notifications@lists.osmocom.org