New subject: Jenkins build is back to normal : ttcn3-bsc-test-sccplite #3050

18 Aug 2026


      See https://jenkins.osmocom.org/jenkins/job/ttcn3-bsc-test-sccplite/3049/display/redirect
Changes:
------------------------------------------
[...truncated 178.19 MiB...]
VirtMSC-SCCP(1637)@77052f219e3d: Message enqueued on MTP3_SCCP_PORT from VirtMSC-IPA(1638) @MTP3asp_Types.ASP_MTP3_TRANSFERind : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 0, dpc := 0, sls := 0, data := '05CF48F3000072'O } id 10
VirtMSC-SCCP(1637)@77052f219e3d: Incoming message was mapped to @SCCP_Types.PDU_SCCP : { relcomp := { messageType := 5, destLocRef := 'CF48F3'O, sourceLocRef := '000072'O } } id 10
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT succeeded:  matched
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port MTP3_SCCP_PORT succeeded:  matched
VirtMSC-SCCP(1637)@77052f219e3d: Receive operation on port MTP3_SCCP_PORT succeeded, message from VirtMSC-IPA(1638): @SCCP_Types.PDU_SCCP : { relcomp := { messageType := 5, destLocRef := 'CF48F3'O, sourceLocRef := '000072'O } } id 10
VirtMSC-SCCP(1637)@77052f219e3d: Message with id 10 was extracted from the queue of MTP3_SCCP_PORT.
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Receive operation on port IPA_PORT succeeded, message from system(): @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '082101200300060403030100050664204367720004000D0718001F00'O } id 31
VirtMSC-SCCP(1637)@77052f219e3d: Session index based on local reference:0
VirtMSC-SCCP(1637)@77052f219e3d: RLC received in state:disconnect_pending 
VirtMSC-SCCP(1637)@77052f219e3d: Stop timer T_rel[0]: 20 s
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message with id 31 was extracted from the queue of IPA_PORT.
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Sent on IPA_RSL_PORT to mtc @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_ACT_TYPE (3), body := { act_type := { reactivation := false, reserved := 0, a_bits := ACT_REL_TO_IMM_ASSIGN (0) } } }, { iei := RSL_IE_CHAN_MODE (6), body := { chan_mode := { len := 4, reserved := '000000'B, dtx_d := true, dtx_u := true, spd_ind := RSL_SPDI_SIGN (3), ch_rate_type := RSL_CHRT_SDCCH (1), u := { sign := RSL_CMOD_NO_RESOURCE (0) } } } }, { iei := RSL_IE_CHAN_IDENT (5), body := { chan_ident := { len := 6, ch_desc := { iei := '64'O ("d"), v := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 }, tsc := 2, h := false, arfcn := 871, maio_hsn := omit } }, ma := { iei := '72'O ("r"), v := { len := 0, ma := ''B } } } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 7 } } }, { iei := RSL_IE_TIMING_ADVANCE (24), body := { timing_adv := 0 } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 0, params := ''O } } } } } }
MTC@77052f219e3d: Message enqueued on IPA_RSL[0][0] from IPA-BTS0-TRX0-RSL-IPA(1642) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_ACT_TYPE (3), body := { act_type := { reactivation := false, reserved := 0, a_bits := ACT_REL_TO_IMM_ASSIGN (0) } } }, { iei := RSL_IE_CHAN_MODE (6), body := { chan_mode := { len := 4, reserved := '000000'B, dtx_d := true, dtx_u := true, spd_ind := RSL_SPDI_SIGN (3), ch_rate_type := RSL_CHRT_SDCCH (1), u := { sign := RSL_CMOD_NO_RESOURCE (0) } } } }, { iei := RSL_IE_CHAN_IDENT (5), body := { chan_ident := { len := 6, ch_desc := { iei := '64'O ("d"), v := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 }, tsc := 2, h := false, arfcn := 871, maio_hsn := omit } }, ma := { iei := '72'O ("r"), v := { len := 0, ma := ''B } } } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 7 } } }, { iei := RSL_IE_TIMING_ADVANCE (24), body := { timing_adv := 0 } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 0, params := ''O } } } } } } id 31
MTC@77052f219e3d: Matching on port IPA_RSL[0][0] succeeded:  matched
MTC@77052f219e3d: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(1642): @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_CHAN_ACTIV (33), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_ACT_TYPE (3), body := { act_type := { reactivation := false, reserved := 0, a_bits := ACT_REL_TO_IMM_ASSIGN (0) } } }, { iei := RSL_IE_CHAN_MODE (6), body := { chan_mode := { len := 4, reserved := '000000'B, dtx_d := true, dtx_u := true, spd_ind := RSL_SPDI_SIGN (3), ch_rate_type := RSL_CHRT_SDCCH (1), u := { sign := RSL_CMOD_NO_RESOURCE (0) } } } }, { iei := RSL_IE_CHAN_IDENT (5), body := { chan_ident := { len := 6, ch_desc := { iei := '64'O ("d"), v := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 }, tsc := 2, h := false, arfcn := 871, maio_hsn := omit } }, ma := { iei := '72'O ("r"), v := { len := 0, ma := ''B } } } } }, { iei := RSL_IE_BS_POWER (4), body := { bs_power := { reserved := 0, epc := false, fpc := false, power_level := 0 } } }, { iei := RSL_IE_MS_POWER (13), body := { ms_power := { reserved := 0, fpc_epc := false, power_level := 7 } } }, { iei := RSL_IE_TIMING_ADVANCE (24), body := { timing_adv := 0 } }, { iei := RSL_IE_MS_POWER_PARAM (31), body := { ms_power_params := { len := 0, params := ''O } } } } } } id 31
MTC@77052f219e3d: Message with id 31 was extracted from the queue of IPA_RSL[0][0].
MTC@77052f219e3d: Stop timer T: 2 s
MTC@77052f219e3d: Sent on IPA_RSL[0][0] to IPA-BTS0-TRX0-RSL-IPA(1642) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_CHAN_ACTIV_ACK (34), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_FRAME_NUMBER (8), body := { frame_nr := { t1_p := 0, t3 := 36, t2 := 10 } } } } } }
MTC@77052f219e3d: Start timer T: 2 s
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: 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_DCHAN (4), transparent := false }, msg_type := RSL_MT_CHAN_ACTIV_ACK (34), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_FRAME_NUMBER (8), body := { frame_nr := { t1_p := 0, t3 := 36, t2 := 10 } } } } } } id 14
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_RSL_PORT succeeded:  matched
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Receive operation on port IPA_RSL_PORT succeeded, message from mtc: @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_CHAN_ACTIV_ACK (34), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_FRAME_NUMBER (8), body := { frame_nr := { t1_p := 0, t3 := 36, t2 := 10 } } } } } } id 14
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message with id 14 was extracted from the queue of IPA_RSL_PORT.
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Sent on IPA_PORT to system @IPA_CodecPort.IPA_Send : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '0822012008048A'O }
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Outgoing message was mapped to @IPL4asp_Types.ASP_Send : { connId := 1, proto := { tcp := { } }, msg := '0007000822012008048A'O }
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message enqueued on IPA_PORT from system @IPL4asp_Types.ASP_RecvFrom : { connId := 1, remName := "127.0.0.1", remPort := 3003, locName := "127.0.0.1", locPort := 10000, proto := { tcp := { } }, userData := 0, msg := '001D000C1601902B172D063F0320436703034000002B2B2B2B2B2B2B2B2B2B2B'O } id 32
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Incoming message was mapped to @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '0C1601902B172D063F0320436703034000002B2B2B2B2B2B2B2B2B2B2B'O } id 32
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT IPAC_PROTO_RSL_TRX0 (0) with IPAC_PROTO_CCM (254) unmatched: First message in the queue does not match the template: 
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT succeeded:  matched
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Receive operation on port IPA_PORT succeeded, message from system(): @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '0C1601902B172D063F0320436703034000002B2B2B2B2B2B2B2B2B2B2B'O } id 32
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message with id 32 was extracted from the queue of IPA_PORT.
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Sent on IPA_RSL_PORT to mtc @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_IMMEDIATE_ASSIGN_CMD (22), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_PCH_AGCH (18) }, tn := 0 } } }, { iei := RSL_IE_FULL_IMM_ASS_INFO (43), body := { full_imm_ass_info := { len := 23, payload := '2D063F0320436703034000002B2B2B2B2B2B2B2B2B2B2B'O } } } } } }
MTC@77052f219e3d: Message enqueued on IPA_RSL[0][0] from IPA-BTS0-TRX0-RSL-IPA(1642) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_IMMEDIATE_ASSIGN_CMD (22), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_PCH_AGCH (18) }, tn := 0 } } }, { iei := RSL_IE_FULL_IMM_ASS_INFO (43), body := { full_imm_ass_info := { len := 23, payload := '2D063F0320436703034000002B2B2B2B2B2B2B2B2B2B2B'O } } } } } } id 32
MTC@77052f219e3d: Matching on port IPA_RSL[0][0] succeeded:  matched
MTC@77052f219e3d: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(1642): @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_CCHAN (6), transparent := false }, msg_type := RSL_MT_IMMEDIATE_ASSIGN_CMD (22), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_PCH_AGCH (18) }, tn := 0 } } }, { iei := RSL_IE_FULL_IMM_ASS_INFO (43), body := { full_imm_ass_info := { len := 23, payload := '2D063F0320436703034000002B2B2B2B2B2B2B2B2B2B2B'O } } } } } } id 32
MTC@77052f219e3d: Message with id 32 was extracted from the queue of IPA_RSL[0][0].
MTC@77052f219e3d: Stop timer T: 2 s
MTC@77052f219e3d: Sent on IPA_RSL[0][0] to IPA-BTS0-TRX0-RSL-IPA(1642) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_RLL (1), transparent := false }, msg_type := RSL_MT_EST_IND (6), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_LINK_IDENT (2), body := { link_id := { c := FACCH_SDCCH (0), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 0, payload := '050802123456172A52080910105180031958'O } } } } } }
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: 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_RLL (1), transparent := false }, msg_type := RSL_MT_EST_IND (6), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_LINK_IDENT (2), body := { link_id := { c := FACCH_SDCCH (0), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 0, payload := '050802123456172A52080910105180031958'O } } } } } } id 15
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_RSL_PORT succeeded:  matched
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Receive operation on port IPA_RSL_PORT succeeded, message from mtc: @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := omit, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_RLL (1), transparent := false }, msg_type := RSL_MT_EST_IND (6), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_LINK_IDENT (2), body := { link_id := { c := FACCH_SDCCH (0), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 0, payload := '050802123456172A52080910105180031958'O } } } } } } id 15
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message with id 15 was extracted from the queue of IPA_RSL_PORT.
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Sent on IPA_PORT to system @IPA_CodecPort.IPA_Send : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '0206012002000B0012050802123456172A52080910105180031958'O }
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Outgoing message was mapped to @IPL4asp_Types.ASP_Send : { connId := 1, proto := { tcp := { } }, msg := '001B000206012002000B0012050802123456172A52080910105180031958'O }
VirtMSC-IPA(1638)@77052f219e3d: Message enqueued on IPA_PORT from system @IPL4asp_Types.ASP_RecvFrom : { connId := 2, remName := "127.0.0.1", remPort := 4000, locName := "127.0.0.1", locPort := 5000, proto := { tcp := { } }, userData := 0, msg := '0036FD010000730202060443B900FE040443BB00FE0F21001F5705080000F110000100001712050802123456172A5208091010518003195800'O } id 14
VirtMSC-IPA(1638)@77052f219e3d: Incoming message was mapped to @IPA_CodecPort.IPA_RecvFrom : { connId := 2, streamId := IPAC_PROTO_SCCP (253), streamIdExt := omit, msg := '010000730202060443B900FE040443BB00FE0F21001F5705080000F110000100001712050802123456172A5208091010518003195800'O } id 14
VirtMSC-IPA(1638)@77052f219e3d: Matching on port IPA_PORT IPAC_PROTO_SCCP (253) with IPAC_PROTO_CCM (254) unmatched: First message in the queue does not match the template: 
VirtMSC-IPA(1638)@77052f219e3d: Matching on port IPA_PORT succeeded:  matched
VirtMSC-IPA(1638)@77052f219e3d: Receive operation on port IPA_PORT succeeded, message from system(): @IPA_CodecPort.IPA_RecvFrom : { connId := 2, streamId := IPAC_PROTO_SCCP (253), streamIdExt := omit, msg := '010000730202060443B900FE040443BB00FE0F21001F5705080000F110000100001712050802123456172A5208091010518003195800'O } id 14
VirtMSC-IPA(1638)@77052f219e3d: Message with id 14 was extracted from the queue of IPA_PORT.
VirtMSC-IPA(1638)@77052f219e3d: Sent on MTP3_SP_PORT to VirtMSC-SCCP(1637) @MTP3asp_Types.ASP_MTP3_TRANSFERind : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 0, dpc := 0, sls := 0, data := '010000730202060443B900FE040443BB00FE0F21001F5705080000F110000100001712050802123456172A5208091010518003195800'O }
VirtMSC-SCCP(1637)@77052f219e3d: Message enqueued on MTP3_SCCP_PORT from VirtMSC-IPA(1638) @MTP3asp_Types.ASP_MTP3_TRANSFERind : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 0, dpc := 0, sls := 0, data := '010000730202060443B900FE040443BB00FE0F21001F5705080000F110000100001712050802123456172A5208091010518003195800'O } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Incoming message was mapped to @SCCP_Types.PDU_SCCP : { connrequest := { messageType := 1, sourceLocRef := '000073'O, protClass := { class := '0010'B, messageHandling := '0000'B }, pointer1 := 2, pointer2 := 6, calledPAddress := { paramLength := 4, addr := '43B900FE'O }, optionalPart := { credit := omit, callingPAddress := { paramName := 4, paramLength := 4, addr := '43BB00FE'O }, data := { paramName := 15, paramLength := 33, data := '001F5705080000F110000100001712050802123456172A52080910105180031958'O }, hopCounter := omit, importance := omit }, eop := { paramName := 0 } } } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port MTP3_SCCP_PORT succeeded:  matched
VirtMSC-SCCP(1637)@77052f219e3d: Receive operation on port MTP3_SCCP_PORT succeeded, message from VirtMSC-IPA(1638): @SCCP_Types.PDU_SCCP : { connrequest := { messageType := 1, sourceLocRef := '000073'O, protClass := { class := '0010'B, messageHandling := '0000'B }, pointer1 := 2, pointer2 := 6, calledPAddress := { paramLength := 4, addr := '43B900FE'O }, optionalPart := { credit := omit, callingPAddress := { paramName := 4, paramLength := 4, addr := '43BB00FE'O }, data := { paramName := 15, paramLength := 33, data := '001F5705080000F110000100001712050802123456172A52080910105180031958'O }, hopCounter := omit, importance := omit }, eop := { paramName := 0 } } } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Message with id 11 was extracted from the queue of MTP3_SCCP_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: First idle individual index:0
VirtMSC-SCCP(1637)@77052f219e3d: Warning: Re-starting timer T_guard[0], which is already active (running or expired).
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_guard[0]: 120 s
VirtMSC-SCCP(1637)@77052f219e3d: Sent on SCCP_SP_PORT to mtc @SCCPasp_Types.ASP_SCCP_N_CONNECT_ind : { calledAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111001'B, subsystemNumber := 254, globalTitle := omit }, callingAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111011'B, subsystemNumber := 254, globalTitle := omit }, qualityOfService := omit, userData := '001F5705080000F110000100001712050802123456172A52080910105180031958'O, connectionId := 15740719, importance := omit }
VirtMSC-SCCP(1637)@77052f219e3d: Warning: Stopping inactive timer T_ias[0].
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_ias[0]: 600 s
MTC@77052f219e3d: Message enqueued on BSSAP from VirtMSC-SCCP(1637) @SCCPasp_Types.ASP_SCCP_N_CONNECT_ind : { calledAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111001'B, subsystemNumber := 254, globalTitle := omit }, callingAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111011'B, subsystemNumber := 254, globalTitle := omit }, qualityOfService := omit, userData := '001F5705080000F110000100001712050802123456172A52080910105180031958'O, connectionId := 15740719, importance := omit } id 8
MTC@77052f219e3d: Incoming message was mapped to @BSSAP_CodecPort.BSSAP_N_CONNECT_ind : { calledAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111001'B, subsystemNumber := 254, globalTitle := omit }, callingAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111011'B, subsystemNumber := 254, globalTitle := omit }, qualityOfService := omit, userData := { discriminator := '0'B, spare := '0000000'B, dlci := omit, lengthIndicator := 31, pdu := { bssmap := { completeLayer3Information := { messageType := '57'O ("W"), cellIdentifier := { elementIdentifier := '05'O, lengthIndicator := 8, cellIdentifierDiscriminator := '0000'B, spare1_4 := '0000'B, cellIdentification := { cI_CGI := { mcc_mnc := '00F110'O, lac := '0001'O, ci := '0000'O } } }, layer3Information := { elementIdentifier := '17'O, lengthIndicator := 18, layer3info := '050802123456172A52080910105180031958'O }, chosenChannel := omit, lSAIdentifier := omit, aPDU := omit, codecList := omit, redirectAttemptFlag := omit, sendSequenceNumber := omit, iMSI := omit } } } }, connectionId := 15740719, importance := omit } id 8
MTC@77052f219e3d: Matching on port BSSAP succeeded:  matched
MTC@77052f219e3d: Receive operation on port BSSAP succeeded, message from VirtMSC-SCCP(1637): @BSSAP_CodecPort.BSSAP_N_CONNECT_ind : { calledAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111001'B, subsystemNumber := 254, globalTitle := omit }, callingAddress := { addressIndicator := { pointCodeIndic := '1'B, ssnIndicator := '1'B, globalTitleIndic := '0000'B, routingIndicator := '1'B }, signPointCode := '00000010111011'B, subsystemNumber := 254, globalTitle := omit }, qualityOfService := omit, userData := { discriminator := '0'B, spare := '0000000'B, dlci := omit, lengthIndicator := 31, pdu := { bssmap := { completeLayer3Information := { messageType := '57'O ("W"), cellIdentifier := { elementIdentifier := '05'O, lengthIndicator := 8, cellIdentifierDiscriminator := '0000'B, spare1_4 := '0000'B, cellIdentification := { cI_CGI := { mcc_mnc := '00F110'O, lac := '0001'O, ci := '0000'O } } }, layer3Information := { elementIdentifier := '17'O, lengthIndicator := 18, layer3info := '050802123456172A52080910105180031958'O }, chosenChannel := omit, lSAIdentifier := omit, aPDU := omit, codecList := omit, redirectAttemptFlag := omit, sendSequenceNumber := omit, iMSI := omit } } } }, connectionId := 15740719, importance := omit } id 8
MTC@77052f219e3d: Message with id 8 was extracted from the queue of BSSAP.
MTC@77052f219e3d: Sent on BSSAP to VirtMSC-SCCP(1637) @BSSAP_CodecPort.BSSAP_N_CONNECT_res : { respondingAddress := omit, expeditedDataSel := omit, qualityOfService := omit, userData := omit, connectionId := 15740719, importance := omit }
MTC@77052f219e3d: Outgoing message was mapped to @SCCPasp_Types.ASP_SCCP_N_CONNECT_res : { respondingAddress := omit, expeditedDataSel := omit, qualityOfService := omit, userData := omit, connectionId := 15740719, importance := omit }
VirtMSC-SCCP(1637)@77052f219e3d: Message enqueued on SCCP_SP_PORT from mtc @SCCPasp_Types.ASP_SCCP_N_CONNECT_res : { respondingAddress := omit, expeditedDataSel := omit, qualityOfService := omit, userData := omit, connectionId := 15740719, importance := omit } id 11
MTC@77052f219e3d: Sent on BSSAP to VirtMSC-SCCP(1637) @BSSAP_CodecPort.BSSAP_N_DATA_req : { userData := { discriminator := '0'B, spare := '0000000'B, dlci := omit, lengthIndicator := 0, pdu := { bssmap := { clearCommand := { messageType := '20'O (" "), layer3HeaderInfo := omit, cause := { elementIdentifier := '04'O, lengthIndicator := 0, causeValue := '0001001'B, extensionCauseValue := '0'B, spare1 := omit }, cSFB_Indication := omit } } } }, connectionId := 15740719, importance := omit }
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT succeeded.
VirtMSC-SCCP(1637)@77052f219e3d: Check-receive operation on port SCCP_SP_PORT succeeded, message from mtc: @SCCPasp_Types.ASP_SCCP_N_CONNECT_res: { respondingAddress := omit, expeditedDataSel := omit, qualityOfService := omit, userData := omit, connectionId := 15740719, importance := omit } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT failed: Type of the first message in the queue is not @SCCPasp_Types.ASP_SCCP_N_DATA_req.
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT failed: Type of the first message in the queue is not @SCCPasp_Types.ASP_SCCP_N_UNITDATA_req.
MTC@77052f219e3d: Outgoing message was mapped to @SCCPasp_Types.ASP_SCCP_N_DATA_req : { userData := '000420040109'O, connectionId := 15740719, importance := omit }
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT failed: Type of the first message in the queue is not @SCCPasp_Types.ASP_SCCP_N_CONNECT_req.
MTC@77052f219e3d: Start timer T: 12 s
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT succeeded:  matched
VirtMSC-SCCP(1637)@77052f219e3d: Receive operation on port SCCP_SP_PORT succeeded, message from mtc: @SCCPasp_Types.ASP_SCCP_N_CONNECT_res : { respondingAddress := omit, expeditedDataSel := omit, qualityOfService := omit, userData := omit, connectionId := 15740719, importance := omit } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Message with id 11 was extracted from the queue of SCCP_SP_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: Session index based on connection ID:0
VirtMSC-SCCP(1637)@77052f219e3d: Sent on MTP3_SCCP_PORT to VirtMSC-IPA(1638) @SCCP_Types.ASP_MTP3_TRANSFERreq_sccp : { sio := '03'O, opc := 185, dpc := 187, sls := 0, data := { connconfirm := { messageType := 2, destLocRef := '000073'O, sourceLocRef := '95F22F'O, protClass := { class := '0010'B, messageHandling := '0000'B }, pointer1 := 0, optionalPart := omit, eop := omit } } }
VirtMSC-SCCP(1637)@77052f219e3d: Outgoing message was mapped to @MTP3asp_Types.ASP_MTP3_TRANSFERreq : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 185, dpc := 187, sls := 0, data := '0200007395F22F0200'O }
VirtMSC-SCCP(1637)@77052f219e3d: Warning: Re-starting timer T_ias[0], which is already active (running or expired).
VirtMSC-IPA(1638)@77052f219e3d: Message enqueued on MTP3_SP_PORT from VirtMSC-SCCP(1637) @MTP3asp_Types.ASP_MTP3_TRANSFERreq : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 185, dpc := 187, sls := 0, data := '0200007395F22F0200'O } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_ias[0]: 600 s
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_iar[0]: 1260 s
VirtMSC-IPA(1638)@77052f219e3d: Matching on port MTP3_SP_PORT succeeded:  matched
VirtMSC-IPA(1638)@77052f219e3d: Receive operation on port MTP3_SP_PORT succeeded, message from VirtMSC-SCCP(1637): @MTP3asp_Types.ASP_MTP3_TRANSFERreq : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 185, dpc := 187, sls := 0, data := '0200007395F22F0200'O } id 11
VirtMSC-SCCP(1637)@77052f219e3d: Message enqueued on SCCP_SP_PORT from mtc @SCCPasp_Types.ASP_SCCP_N_DATA_req : { userData := '000420040109'O, connectionId := 15740719, importance := omit } id 12
VirtMSC-IPA(1638)@77052f219e3d: Message with id 11 was extracted from the queue of MTP3_SP_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT succeeded.
VirtMSC-IPA(1638)@77052f219e3d: Sent on IPA_PORT to system @IPA_CodecPort.IPA_Send : { connId := 2, streamId := IPAC_PROTO_SCCP (253), streamIdExt := omit, msg := '0200007395F22F0200'O }
VirtMSC-SCCP(1637)@77052f219e3d: Check-receive operation on port SCCP_SP_PORT succeeded, message from mtc: @SCCPasp_Types.ASP_SCCP_N_DATA_req: { userData := '000420040109'O, connectionId := 15740719, importance := omit } id 12
VirtMSC-IPA(1638)@77052f219e3d: Outgoing message was mapped to @IPL4asp_Types.ASP_Send : { connId := 2, proto := { tcp := { } }, msg := '0009FD0200007395F22F0200'O }
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port SCCP_SP_PORT succeeded:  matched
VirtMSC-SCCP(1637)@77052f219e3d: Receive operation on port SCCP_SP_PORT succeeded, message from mtc: @SCCPasp_Types.ASP_SCCP_N_DATA_req : { userData := '000420040109'O, connectionId := 15740719, importance := omit } id 12
VirtMSC-SCCP(1637)@77052f219e3d: Message with id 12 was extracted from the queue of SCCP_SP_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: Session index based on connection ID:0
VirtMSC-SCCP(1637)@77052f219e3d: vl_len:6
VirtMSC-SCCP(1637)@77052f219e3d: vl_from0
VirtMSC-SCCP(1637)@77052f219e3d: Sent on MTP3_SCCP_PORT to VirtMSC-IPA(1638) @SCCP_Types.ASP_MTP3_TRANSFERreq_sccp : { sio := '03'O, opc := 185, dpc := 187, sls := 0, data := { dataform1 := { messageType := 6, destLocRef := '000073'O, segmentingReassembl := { more := '0'B, reserved := '0000000'B }, pointer1 := 1, data := { paramLength := 6, data := '000420040109'O } } } }
VirtMSC-SCCP(1637)@77052f219e3d: Outgoing message was mapped to @MTP3asp_Types.ASP_MTP3_TRANSFERreq : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 185, dpc := 187, sls := 0, data := '06000073000106000420040109'O }
VirtMSC-SCCP(1637)@77052f219e3d: data sent by MTP3_SCCP_PORT: '000420040109'O
VirtMSC-IPA(1638)@77052f219e3d: Message enqueued on MTP3_SP_PORT from VirtMSC-SCCP(1637) @MTP3asp_Types.ASP_MTP3_TRANSFERreq : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 185, dpc := 187, sls := 0, data := '06000073000106000420040109'O } id 12
VirtMSC-SCCP(1637)@77052f219e3d: Stop timer T_ias[0]: 600 s
VirtMSC-IPA(1638)@77052f219e3d: Matching on port MTP3_SP_PORT succeeded:  matched
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_ias[0]: 600 s
VirtMSC-IPA(1638)@77052f219e3d: Receive operation on port MTP3_SP_PORT succeeded, message from VirtMSC-SCCP(1637): @MTP3asp_Types.ASP_MTP3_TRANSFERreq : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 185, dpc := 187, sls := 0, data := '06000073000106000420040109'O } id 12
VirtMSC-IPA(1638)@77052f219e3d: Message with id 12 was extracted from the queue of MTP3_SP_PORT.
VirtMSC-IPA(1638)@77052f219e3d: Sent on IPA_PORT to system @IPA_CodecPort.IPA_Send : { connId := 2, streamId := IPAC_PROTO_SCCP (253), streamIdExt := omit, msg := '06000073000106000420040109'O }
VirtMSC-IPA(1638)@77052f219e3d: Outgoing message was mapped to @IPL4asp_Types.ASP_Send : { connId := 2, proto := { tcp := { } }, msg := '000DFD06000073000106000420040109'O }
VirtMSC-IPA(1638)@77052f219e3d: Message enqueued on IPA_PORT from system @IPL4asp_Types.ASP_RecvFrom : { connId := 2, remName := "127.0.0.1", remPort := 4000, locName := "127.0.0.1", locPort := 5000, proto := { tcp := { } }, userData := 0, msg := '000AFD0695F22F000103000121'O } id 15
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message enqueued on IPA_PORT from system @IPL4asp_Types.ASP_RecvFrom : { connId := 1, remName := "127.0.0.1", remPort := 3003, locName := "127.0.0.1", locPort := 10000, proto := { tcp := { } }, userData := 0, msg := '000C000301012002000B0003060D00'O } id 33
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Incoming message was mapped to @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '0301012002000B0003060D00'O } id 33
VirtMSC-IPA(1638)@77052f219e3d: Incoming message was mapped to @IPA_CodecPort.IPA_RecvFrom : { connId := 2, streamId := IPAC_PROTO_SCCP (253), streamIdExt := omit, msg := '0695F22F000103000121'O } id 15
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message enqueued on IPA_PORT from system @IPL4asp_Types.ASP_RecvFrom : { connId := 1, remName := "127.0.0.1", remPort := 3003, locName := "127.0.0.1", locPort := 10000, proto := { tcp := { } }, userData := 0, msg := '00040008250120'O } id 34
VirtMSC-IPA(1638)@77052f219e3d: Matching on port IPA_PORT IPAC_PROTO_SCCP (253) with IPAC_PROTO_CCM (254) unmatched: First message in the queue does not match the template: 
VirtMSC-IPA(1638)@77052f219e3d: Matching on port IPA_PORT succeeded:  matched
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Incoming message was mapped to @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '08250120'O } id 34
VirtMSC-IPA(1638)@77052f219e3d: Receive operation on port IPA_PORT succeeded, message from system(): @IPA_CodecPort.IPA_RecvFrom : { connId := 2, streamId := IPAC_PROTO_SCCP (253), streamIdExt := omit, msg := '0695F22F000103000121'O } id 15
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT IPAC_PROTO_RSL_TRX0 (0) with IPAC_PROTO_CCM (254) unmatched: First message in the queue does not match the template: 
VirtMSC-IPA(1638)@77052f219e3d: Message with id 15 was extracted from the queue of IPA_PORT.
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT succeeded:  matched
VirtMSC-IPA(1638)@77052f219e3d: Sent on MTP3_SP_PORT to VirtMSC-SCCP(1637) @MTP3asp_Types.ASP_MTP3_TRANSFERind : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 0, dpc := 0, sls := 0, data := '0695F22F000103000121'O }
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Receive operation on port IPA_PORT succeeded, message from system(): @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '0301012002000B0003060D00'O } id 33
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message with id 33 was extracted from the queue of IPA_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: Message enqueued on MTP3_SCCP_PORT from VirtMSC-IPA(1638) @MTP3asp_Types.ASP_MTP3_TRANSFERind : { sio := { ni := '00'B, prio := '00'B, si := '0011'B }, opc := 0, dpc := 0, sls := 0, data := '0695F22F000103000121'O } id 12
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Sent on IPA_RSL_PORT to mtc @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_RLL (1), transparent := true }, msg_type := RSL_MT_DATA_REQ (1), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_LINK_IDENT (2), body := { link_id := { c := FACCH_SDCCH (0), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 3, payload := '060D00'O } } } } } }
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT IPAC_PROTO_RSL_TRX0 (0) with IPAC_PROTO_CCM (254) unmatched: First message in the queue does not match the template: 
VirtMSC-SCCP(1637)@77052f219e3d: Incoming message was mapped to @SCCP_Types.PDU_SCCP : { dataform1 := { messageType := 6, destLocRef := '95F22F'O, segmentingReassembl := { more := '0'B, reserved := '0000000'B }, pointer1 := 1, data := { paramLength := 3, data := '000121'O } } } id 12
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Matching on port IPA_PORT succeeded:  matched
MTC@77052f219e3d: Message enqueued on IPA_RSL[0][0] from IPA-BTS0-TRX0-RSL-IPA(1642) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_RLL (1), transparent := true }, msg_type := RSL_MT_DATA_REQ (1), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_LINK_IDENT (2), body := { link_id := { c := FACCH_SDCCH (0), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 3, payload := '060D00'O } } } } } } id 33
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Receive operation on port IPA_PORT succeeded, message from system(): @IPA_CodecPort.IPA_RecvFrom : { connId := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), streamIdExt := omit, msg := '08250120'O } id 34
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Message with id 34 was extracted from the queue of IPA_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: Matching on port MTP3_SCCP_PORT succeeded:  matched
MTC@77052f219e3d: Matching on port IPA_RSL[0][0] RSL_MDISC_RLL (1) with RSL_MDISC_DCHAN (4) unmatchedRSL_MT_DATA_REQ (1) with RSL_MT_RF_CHAN_REL (46) unmatched: First message in the queue does not match the template: 
VirtMSC-SCCP(1637)@77052f219e3d: Receive operation on port MTP3_SCCP_PORT succeeded, message from VirtMSC-IPA(1638): @SCCP_Types.PDU_SCCP : { dataform1 := { messageType := 6, destLocRef := '95F22F'O, segmentingReassembl := { more := '0'B, reserved := '0000000'B }, pointer1 := 1, data := { paramLength := 3, data := '000121'O } } } id 12
MTC@77052f219e3d: Matching on port IPA_RSL[0][0] succeeded.
VirtMSC-SCCP(1637)@77052f219e3d: Message with id 12 was extracted from the queue of MTP3_SCCP_PORT.
VirtMSC-SCCP(1637)@77052f219e3d: Session index based on local reference:0
VirtMSC-SCCP(1637)@77052f219e3d: Stop timer T_iar[0]: 1260 s
MTC@77052f219e3d: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(1642): @IPA_Emulation.ASP_RSL_Unitdata: { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_RLL (1), transparent := true }, msg_type := RSL_MT_DATA_REQ (1), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } }, { iei := RSL_IE_LINK_IDENT (2), body := { link_id := { c := FACCH_SDCCH (0), na := false, prio := SAPI0_PRIO_NORMAL (0), sapi := 0 } } }, { iei := RSL_IE_L3_INFO (11), body := { l3_info := { len := 3, payload := '060D00'O } } } } } } id 33
MTC@77052f219e3d: Message with id 33 was extracted from the queue of IPA_RSL[0][0].
IPA-BTS0-TRX0-RSL-IPA(1642)@77052f219e3d: Sent on IPA_RSL_PORT to mtc @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_DEACTIVATE_SACCH (37), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } } } } }
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_iar[0]: 1260 s
VirtMSC-SCCP(1637)@77052f219e3d: DT1 will be put to the reassembly buffer
VirtMSC-SCCP(1637)@77052f219e3d: DT1 data has been put to the reassembly buffer
VirtMSC-SCCP(1637)@77052f219e3d: DT1/segmentingReassembl/more==0 received=> send ASP_SCCP_N_DATA comes
VirtMSC-SCCP(1637)@77052f219e3d: Sent on SCCP_SP_PORT to mtc @SCCPasp_Types.ASP_SCCP_N_DATA_ind : { userData := '000121'O, connectionId := 15740719, importance := omit }
MTC@77052f219e3d: Message enqueued on IPA_RSL[0][0] from IPA-BTS0-TRX0-RSL-IPA(1642) @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_DEACTIVATE_SACCH (37), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } } } } } id 34
VirtMSC-SCCP(1637)@77052f219e3d: Stop timer T_ias[0]: 600 s
VirtMSC-SCCP(1637)@77052f219e3d: Start timer T_ias[0]: 600 s
MTC@77052f219e3d: Matching on port IPA_RSL[0][0] RSL_MT_DEACTIVATE_SACCH (37) with RSL_MT_RF_CHAN_REL (46) unmatched: First message in the queue does not match the template: 
MTC@77052f219e3d: Matching on port IPA_RSL[0][0] succeeded.
MTC@77052f219e3d: Receive operation on port IPA_RSL[0][0] succeeded, message from IPA-BTS0-TRX0-RSL-IPA(1642): @IPA_Emulation.ASP_RSL_Unitdata: { conn_id := 1, streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_DCHAN (4), transparent := false }, msg_type := RSL_MT_DEACTIVATE_SACCH (37), ies := { { iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { sdcch4 := { tag := '001'B, sub_chan := 0 } }, tn := 0 } } } } } } id 34
MTC@77052f219e3d: Message with id 34 was extracted from the queue of IPA_RSL[0][0].
MTC@77052f219e3d: Message enqueued on BSSAP from VirtMSC-SCCP(1637) @SCCPasp_Types.ASP_SCCP_N_DATA_ind : { userData := '000121'O, connectionId := 15740719, importance := omit } id 9
MTC@77052f219e3d: Incoming message was mapped to @BSSAP_CodecPort.BSSAP_N_DATA_ind : { userData := { discriminator := '0'B, spare := '0000000'B, dlci := omit, lengthIndicator := 1, pdu := { bssmap := { clearComplete := { messageType := '21'O ("!") } } } }, connectionId := 15740719, importance := omit } id 9
MTC@77052f219e3d: Matching on port BSSAP failed: Type of the first message in the queue is not @BSSAP_CodecPort.BSSAP_N_UNITDATA_ind.
MTC@77052f219e3d: Matching on port BSSAP failed: Type of the first message in the queue is not @SCCPasp_Types.ASP_SCCP_N_PCSTATE_ind.
MTC@77052f219e3d: Matching on port BSSAP failed: Type of the first message in the queue is not @BSSAP_CodecPort.BSSAP_N_UNITDATA_ind.
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:141)
    at hudson.remoting.Command.readFrom(Command.java:127)
    at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:62)
Caused: java.io.IOException: Unexpected termination of the channel
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:80)
Caused: java.io.IOException: Backing channel 'build5-deb12build-ansible' is disconnected.
    at hudson.remoting.RemoteInvocationHandler.channelOrFail(RemoteInvocationHandler.java:227)
    at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:306)
    at jdk.proxy2/jdk.proxy2.$Proxy111.isAlive(Unknown Source)
    at hudson.Launcher$RemoteLauncher$ProcImpl.isAlive(Launcher.java:1227)
    at hudson.Launcher$RemoteLauncher$ProcImpl.join(Launcher.java:1219)
    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:817)
    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:1843)
    at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44)
    at hudson.model.ResourceController.execute(ResourceController.java:97)
    at hudson.model.Executor.run(Executor.java:456)
FATAL: Unable to delete script file /tmp/jenkins18264790041142823967.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:141)
    at hudson.remoting.Command.readFrom(Command.java:127)
    at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:62)
Caused: java.io.IOException: Unexpected termination of the channel
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:80)
Caused: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@1ae98fce:build5-deb12build-ansible": Remote call on build5-deb12build-ansible failed. The channel is closing down or has closed down
    at hudson.remoting.Channel.call(Channel.java:1101)
    at hudson.FilePath.act(FilePath.java:1220)
    at hudson.FilePath.act(FilePath.java:1209)
    at hudson.FilePath.delete(FilePath.java:1756)
    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:817)
    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:1843)
    at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44)
    at hudson.model.ResourceController.execute(ResourceController.java:97)
    at hudson.model.Executor.run(Executor.java:456)
Build step 'Execute shell' marked build as failure
FATAL: Channel "hudson.remoting.Channel@1ae98fce:build5-deb12build-ansible": Remote call on build5-deb12build-ansible failed. The channel is closing down or has closed down
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:141)
    at hudson.remoting.Command.readFrom(Command.java:127)
    at hudson.remoting.AbstractSynchronousByteArrayCommandTransport.read(AbstractSynchronousByteArrayCommandTransport.java:35)
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:62)
Caused: java.io.IOException: Unexpected termination of the channel
    at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:80)
Caused: hudson.remoting.ChannelClosedException: Channel "hudson.remoting.Channel@1ae98fce:build5-deb12build-ansible": Remote call on build5-deb12build-ansible failed. The channel is closing down or has closed down
    at hudson.remoting.Channel.call(Channel.java:1101)
    at hudson.Launcher$RemoteLauncher.kill(Launcher.java:1162)
    at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:538)
    at hudson.model.Run.execute(Run.java:1843)
    at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:44)
    at hudson.model.ResourceController.execute(ResourceController.java:97)
    at hudson.model.Executor.run(Executor.java:456)
Recording test results
Agent went offline during the build
ERROR: Disconnected by laforge : NVME repair
Build step 'Publish JUnit test result report' marked build as failure

Build failed in Jenkins: ttcn3-bsc-test-sccplite #3049