Project

General

Profile

Actions

Bug #5472

closed

osmo-pcu: {SEND_ASS}: Event SCHED_ASS not permitted

Added by pespin about 2 years ago. Updated 10 months ago.

Status:
Resolved
Priority:
Normal
Assignee:
Target version:
-
Start date:
03/01/2022
Due date:
% Done:

100%

Spec Reference:

Description

Mar  1 20:20:03 OsmoPCU: DTBF NOTICE tbf_ul_ass_fsm.c:241 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) Timeout for polling PACKET CONTROL ACK for PACKET UPLINK ASSIGNMENT: |Assignment was on PACCH|
Uplink data was received|
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_ul_ass_fsm.c:244 UL_ASS_TBF(UL-TFI_0)[0x7cd840]{WAIT_ACK}: state_chg to SEND_ASS
Mar  1 20:20:03 OsmoPCU: DLBSSGP INFO gprs_bssgp_pcu.c:181 LLC [SGSN -> PCU] = TLLI: 0xe5751051 IMSI: <ERASED_A> len: 62
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl.cpp:133 MS(TLLI=0xe5751051, IMSI=<ERASED_A>, TA=0, 12/12, UL) Allocating DL TBF
Mar  1 20:20:03 OsmoPCU: DTBF INFO fsm.c:461 TBF[0x83e380]{NEW}: Allocated
Mar  1 20:20:03 OsmoPCU: DTBF INFO fsm.c:461 UL_ASS_TBF[0x838650]{NONE}: Allocated
Mar  1 20:20:03 OsmoPCU: DTBF INFO fsm.c:461 DL_ASS_TBF[0x83bd30]{NONE}: Allocated
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO gprs_rlcmac_ts_alloc.cpp:943 [DL] algo B <multi> (suggested TRX: 1): using 3 slots
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO pdch.cpp:1171 PDCH(bts=0,trx=1,ts=4) Attaching TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS), 3 TBFs, USFs = 00, TFIs = 00000016.
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO pdch.cpp:1171 PDCH(bts=0,trx=1,ts=5) Attaching TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS), 6 TBFs, USFs = 07, TFIs = 0000003f.
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO pdch.cpp:1171 PDCH(bts=0,trx=1,ts=6) Attaching TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS), 6 TBFs, USFs = 3f, TFIs = 0000003f.
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf.cpp:345 TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) Setting Control TS 5
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf.cpp:680 TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) Allocated: trx = 1, ul_slots = 20, dl_slots = 70
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO gprs_ms.c:321 MS(TLLI=0xe5751051, IMSI=<ERASED_A>, TA=0, 12/12, UL) Attaching DL TBF: TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS)
Mar  1 20:20:03 OsmoPCU: DTBFDL INFO tbf_dl.cpp:1380 TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) setting EGPRS DL window size to 64, base(64) slots(3) ws_pdch(0)
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO rlc.cpp:249 ws(64)
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl.cpp:611 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{NONE}: Received Event SCHED_ASS
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl_ass_fsm.c:141 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{NONE}: state_chg to SEND_ASS
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl.cpp:614 TBF(DL-TFI_4)[0x83e380]{NEW}: Received Event ASSIGN_ADD_PACCH
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_fsm.c:89 TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) set ass. type PACCH [prev CCCH:0, PACCH:0]
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_fsm.c:111 TBF(DL-TFI_4)[0x83e380]{NEW}: state_chg to ASSIGN
Mar  1 20:20:03 OsmoPCU: DTBFDL INFO tbf_dl.cpp:983 TBF(TFI=3 TLLI=0xca1cd311 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=628762, TS=6
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl_ass_fsm.c:249 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{SEND_ASS}: Received Event CREATE_RLCMAC_MSG
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl_ass_fsm.c:101 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) start Packet Downlink Assignment (PACCH) for TBF(TFI=4 TLLI=0xe5751051 DIR=DL STATE=ASSIGN EGPRS)
Mar  1 20:20:03 OsmoPCU: DTBFDL INFO tbf_dl_ass_fsm.c:122 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) Scheduled DL Assignment polling on PACCH (FN=628762, TS=7)
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl_ass_fsm.c:159 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{SEND_ASS}: state_chg to WAIT_ACK
Mar  1 20:20:03 OsmoPCU: DRLCMACUL INFO pdch.cpp:1014 PDCH(bts=0,trx=1,ts=5) Got MCS-4 RLC block: R=0, SI=0, TFI=1, CPS=0, RSB=0, rc=385
Mar  1 20:20:03 OsmoPCU: DLBSSGP INFO tbf_ul.cpp:548 LLC [PCU -> SGSN] TBF(TFI=1 TLLI=0xcc5e8e11 DIR=UL STATE=FLOW EGPRS) len=67
Mar  1 20:20:03 OsmoPCU: DLNSDATA INFO gprs_ns2_message.c:426 NSE(00138)-NSVC(00138) Tx NS-UNITDATA
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO pdch_ul_controller.c:323 PDCH(bts=0,trx=1,ts=6) Timeout for registered USF (FN=628732): TBF(TFI=1 TLLI=0xcc5e8e11 DIR=UL STATE=FLOW EGPRS)
Mar  1 20:20:03 OsmoPCU: DRLCMACUL INFO pdch.cpp:1014 PDCH(bts=0,trx=1,ts=7) Got MCS-4 RLC block: R=0, SI=0, TFI=5, CPS=1, RSB=1, rc=385
Mar  1 20:20:03 OsmoPCU: DTBFUL INFO tbf_ul.cpp:537 UL_ACK_TBF(UL-TFI_5)[0x838a50]{WAIT_ACK}: Received Event SCHED_ACK
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_ul_ass_fsm.c:342 UL_ASS_TBF(UL-TFI_0)[0x7cd840]{SEND_ASS}: Received Event CREATE_RLCMAC_MSG
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_ul_ass_fsm.c:117 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
Mar  1 20:20:03 OsmoPCU: DTBFUL INFO tbf_ul_ass_fsm.c:137 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) Scheduled UL Assignment polling on PACCH (FN=628766, TS=7)
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_ul_ass_fsm.c:197 UL_ASS_TBF(UL-TFI_0)[0x7cd840]{SEND_ASS}: state_chg to WAIT_ACK
...
Mar  1 20:20:03 OsmoPCU: DTBF NOTICE tbf.cpp:552 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) poll timeout for FN=628762, TS=7 (curr FN 628762)
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf.cpp:610 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{WAIT_ACK}: Received Event ASS_POLL_TIMEOUT
Mar  1 20:20:03 OsmoPCU: DTBF NOTICE tbf_dl_ass_fsm.c:177 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) Timeout for polling PACKET CONTROL ACK for PACKET DOWNLINK ASSIGNMENT: |Assignment was on PACCH|Uplink data was received|
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_dl_ass_fsm.c:179 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{WAIT_ACK}: state_chg to SEND_ASS
Mar  1 20:20:03 OsmoPCU: DTBFDL INFO tbf_dl.cpp:983 TBF(TFI=2 TLLI=0xcc5e8e11 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=628797, TS=5
Mar  1 20:20:03 OsmoPCU: DRLCMACUL INFO pdch.cpp:1014 PDCH(bts=0,trx=1,ts=5) Got MCS-4 RLC block: R=0, SI=0, TFI=1, CPS=0, RSB=0, rc=385
Mar  1 20:20:03 OsmoPCU: DRLCMAC INFO pdch_ul_controller.c:323 PDCH(bts=0,trx=1,ts=6) Timeout for registered USF (FN=628766): TBF(TFI=1 TLLI=0xcc5e8e11 DIR=UL STATE=FLOW EGPRS)
Mar  1 20:20:03 OsmoPCU: DRLCMAC NOTICE pdch_ul_controller.c:330 PDCH(bts=0,trx=1,ts=7) Timeout for registered POLL (FN=628766, reason=UL_ASS): TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS)
Mar  1 20:20:03 OsmoPCU: DTBF NOTICE tbf.cpp:552 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) poll timeout for FN=628766, TS=7 (curr FN 628766)
Mar  1 20:20:03 OsmoPCU: DTBF NOTICE tbf.cpp:394 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=ASSIGN EGPRS) N3105 exceeded MAX (8)
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf.cpp:585 TBF(UL-TFI_0)[0x815f00]{ASSIGN}: Received Event MAX_N3105
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_fsm.c:194 UL_ASS_TBF(UL-TFI_0)[0x7cd840]{WAIT_ACK}: Received Event ABORT
Mar  1 20:20:03 OsmoPCU: DTBF INFO tbf_fsm.c:196 TBF(UL-TFI_0)[0x815f00]{ASSIGN}: state_chg to RELEASING
...
Mar  1 20:20:06 OsmoPCU: DLBSSGP INFO gprs_bssgp_pcu.c:181 LLC [SGSN -> PCU] = TLLI: 0xe5751051 IMSI: <ERASED_A> len: 62
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf_dl.cpp:133 MS(TLLI=0xe5751051, IMSI=<ERASED_A>, TA=0, 12/12, UL) Allocating DL TBF
Mar  1 20:20:06 OsmoPCU: DTBF INFO fsm.c:461 TBF[0x83a560]{NEW}: Allocated
Mar  1 20:20:06 OsmoPCU: DTBF INFO fsm.c:461 UL_ASS_TBF[0x838e30]{NONE}: Allocated
Mar  1 20:20:06 OsmoPCU: DTBF INFO fsm.c:461 DL_ASS_TBF[0x881f70]{NONE}: Allocated
Mar  1 20:20:06 OsmoPCU: DRLCMAC INFO gprs_rlcmac_ts_alloc.cpp:943 [DL] algo B <multi> (suggested TRX: 1): using 3 slots
Mar  1 20:20:06 OsmoPCU: DRLCMAC INFO pdch.cpp:1171 PDCH(bts=0,trx=1,ts=4) Attaching TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS), 3 TBFs, USFs = 00, TFIs = 00000045.
Mar  1 20:20:06 OsmoPCU: DRLCMAC INFO pdch.cpp:1171 PDCH(bts=0,trx=1,ts=5) Attaching TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS), 5 TBFs, USFs = 05, TFIs = 0000006d.
Mar  1 20:20:06 OsmoPCU: DRLCMAC INFO pdch.cpp:1171 PDCH(bts=0,trx=1,ts=6) Attaching TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS), 5 TBFs, USFs = 07, TFIs = 0000006d.
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf.cpp:345 TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) Setting Control TS 5
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf.cpp:680 TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) Allocated: trx = 1, ul_slots = 20, dl_slots = 70
Mar  1 20:20:06 OsmoPCU: DRLCMAC INFO gprs_ms.c:321 MS(TLLI=0xe5751051, IMSI=<ERASED_A>, TA=0, 12/12, UL) Attaching DL TBF: TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS)
Mar  1 20:20:06 OsmoPCU: DTBFDL INFO tbf_dl.cpp:1380 TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) setting EGPRS DL window size to 64, base(64) slots(3) ws_pdch(0)
Mar  1 20:20:06 OsmoPCU: DRLCMAC INFO rlc.cpp:249 ws(64)
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf_dl.cpp:611 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{SEND_ASS}: Received Event SCHED_ASS
Mar  1 20:20:06 OsmoPCU: DTBF ERROR tbf_dl.cpp:611 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{SEND_ASS}: Event SCHED_ASS not permitted  //UNEXPECTED EVENT HERE!!!!
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf_dl.cpp:614 TBF(DL-TFI_0)[0x83a560]{NEW}: Received Event ASSIGN_ADD_PACCH
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf_fsm.c:89 TBF(TFI=0 TLLI=0xe5751051 DIR=DL STATE=NEW EGPRS) set ass. type PACCH [prev CCCH:0, PACCH:0]
Mar  1 20:20:06 OsmoPCU: DTBF INFO tbf_fsm.c:111 TBF(DL-TFI_0)[0x83a560]{NEW}: state_chg to ASSIGN
...
Mar  1 20:20:08 OsmoPCU: DRLCMAC INFO pdch_ul_controller.c:323 PDCH(bts=0,trx=1,ts=7) Timeout for registered USF (FN=629845): TBF(TFI=2 TLLI=0xf35df111 DIR=UL STATE=FLOW EGPRS)
Mar  1 20:20:08 OsmoPCU: DTBF INFO fsm.c:322 TBF(UL-TFI_0)[0x815f00]{RELEASING}: Timeout of T3195
Mar  1 20:20:08 OsmoPCU: DTBF INFO tbf.cpp:292 TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=RELEASING EGPRS) free
Mar  1 20:20:08 OsmoPCU: DRLCMAC INFO pdch.cpp:1181 PDCH(bts=0,trx=1,ts=5) Detaching TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=RELEASING EGPRS), 2 TBFs, USFs = 05, TFIs = 00000003.
Mar  1 20:20:08 OsmoPCU: DRLCMAC INFO pdch.cpp:1181 PDCH(bts=0,trx=1,ts=6) Detaching TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=RELEASING EGPRS), 4 TBFs, USFs = 0f, TFIs = 0000000f.
Mar  1 20:20:08 OsmoPCU: DRLCMAC INFO gprs_ms.c:369 MS(TLLI=0xe5751051, IMSI=<ERASED_A>, TA=0, 12/12,) Detaching TBF: TBF(TFI=0 TLLI=0xe5751051 DIR=UL STATE=RELEASING EGPRS)
Mar  1 20:20:08 OsmoPCU: DTBFUL INFO fsm.c:573 UL_ACK_TBF(UL-TFI_0)[0x837630]{NONE}: Deallocated
Mar  1 20:20:08 OsmoPCU: DTBF INFO fsm.c:573 TBF(UL-TFI_0)[0x815f00]{RELEASING}: Deallocated
Mar  1 20:20:08 OsmoPCU: DTBF INFO fsm.c:573 UL_ASS_TBF(UL-TFI_0)[0x7cd840]{WAIT_ACK}: Deallocated
Mar  1 20:20:08 OsmoPCU: DTBF INFO fsm.c:573 DL_ASS_TBF(UL-TFI_0)[0x8160b0]{SEND_ASS}: Deallocated
Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)