June 2023 - gerrit-log - lists.osmocom.org

[S] Change in osmo-pcu[master]: cosmetic: Improve comment
by pespin 13 Jun '23

13 Jun '23

pespin has posted comments on this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33303 ) Change subject: cosmetic: Improve comment ...................................................................... Set Ready For Review -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33303 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: I8c963ba7421faf2b3dcab006ea629c4628d17b44 Gerrit-Change-Number: 33303 Gerrit-PatchSet: 1 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Comment-Date: Tue, 13 Jun 2023 15:25:13 +0000 Gerrit-HasComments: No Gerrit-Has-Labels: No Gerrit-MessageType: comment

1 0

[M] Change in pysim[master]: docs: Add section on pySim-trace to user manual
by laforge 13 Jun '23

13 Jun '23

laforge has submitted this change. ( https://gerrit.osmocom.org/c/pysim/+/33251 ) Change subject: docs: Add section on pySim-trace to user manual ...................................................................... docs: Add section on pySim-trace to user manual Change-Id: I5edb222818f00e36ed5b067e0f8d5786f39ae887 --- M docs/index.rst A docs/trace.rst M pySim-trace.py 3 files changed, 91 insertions(+), 7 deletions(-) Approvals: laforge: Looks good to me, approved fixeria: Looks good to me, but someone else must approve Jenkins Builder: Verified diff --git a/docs/index.rst b/docs/index.rst index 471802a..a46aee0 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -31,6 +31,7 @@ * a python :ref:`library<pySim library>` containing plenty of objects and methods that can be used for writing custom programs interfacing with SIM cards. * the [new] :ref:`interactive pySim-shell command line program<pySim-shell>` +* the [new] :ref:`pySim-trace APDU trace decoder<pySim-trace>` * the [legacy] :ref:`pySim-prog and pySim-read tools<Legacy tools>` .. toctree:: @@ -38,6 +39,7 @@ :caption: Contents: shell + trace legacy library diff --git a/docs/trace.rst b/docs/trace.rst new file mode 100644 index 0000000..637491a --- /dev/null +++ b/docs/trace.rst @@ -0,0 +1,64 @@ +pySim-trace +=========== + +pySim-trace is a utility for high-level decode of APDU protocol traces such as those obtained with +`Osmocom SIMtrace2 <https://osmocom.org/projects/simtrace2/wiki>`_ or `osmo-qcdiag <https://osmocom.org/projects/osmo-qcdiag/wiki>`_. + +pySim-trace leverages the existing knowledge of pySim-shell on anything related to SIM cards, +including the structure/encoding of the various files on SIM/USIM/ISIM/HPSIM cards, and applies this +to decoding protocol traces. This means that it shows not only the name of the command (like READ +BINARY), but actually understands what the currently selected file is, and how to decode the +contents of that file. + +pySim-trace also understands the parameters passed to commands and how to decode them, for example +of the AUTHENTICATE command within the USIM/ISIM/HPSIM application. + + +Demo +---- + +To get an idea how pySim-trace usage looks like, you can watch the relevant part of the 11/2022 +SIMtrace2 tutorial whose `recording is freely accessible <https://media.ccc.de/v/osmodevcall-20221019-laforge-simtrace2-tutorial#t=21…>`_. + + +Running pySim-trace +------------------- + +Running pySim-trace requires you to specify the *source* of the to-be-decoded APDUs. There are several +supported options, each with their own respective parameters (like a file name for PCAP decoding). + +See the detailed command line reference below for details. + +A typical execution of pySim-trace for doing live decodes of *GSMTAP (SIM APDU)* e.g. from SIMtrace2 or +osmo-qcdiag would look like this: + +:: + + ./pySim-trace.py gsmtap-udp + +This binds to the default UDP port 4729 (GSMTAP) on localhost (127.0.0.1), and decodes any APDUs received +there. + + + +pySim-trace command line reference +---------------------------------- + +.. argparse:: + :module: pySim-trace + :func: option_parser + :prog: pySim-trace.py + + +Constraints +----------- + +* In order to properly track the current location in the filesystem tree and other state, it is + important that the trace you're decoding includes all of the communication with the SIM, ideally + from the very start (power up). + +* pySim-trace currently only supports ETSI UICC (USIM/ISIM/HPSIM) and doesn't yet support legacy GSM + SIM. This is not a fundamental technical constraint, it's just simply that nobody got around + developing and testing that part. Contributions are most welcome. + + diff --git a/pySim-trace.py b/pySim-trace.py index 79069a6..bb1805c 100755 --- a/pySim-trace.py +++ b/pySim-trace.py @@ -114,36 +114,45 @@ #print(inst) self.format_capdu(inst) -option_parser = argparse.ArgumentParser(prog='pySim-trace', description='Osmocom pySim high-level SIM card trace decoder', +option_parser = argparse.ArgumentParser(description='Osmocom pySim high-level SIM card trace decoder', formatter_class=argparse.ArgumentDefaultsHelpFormatter) global_group = option_parser.add_argument_group('General Options') global_group.add_argument('--no-suppress-select', action='store_false', dest='suppress_select', - help="Don't suppress displaying SELECT APDUs") + help=""" + Don't suppress displaying SELECT APDUs. We normally suppress them as they just clutter up + the output without giving any useful information. Any subsequent READ/UPDATE/... operations + on the selected file will log the file name most recently SELECTed.""") global_group.add_argument('--no-suppress-status', action='store_false', dest='suppress_status', - help="Don't suppress displaying STATUS APDUs") + help=""" + Don't suppress displaying STATUS APDUs. We normally suppress them as they don't provide any + information that was not already received in resposne to the most recent SEELCT.""") subparsers = option_parser.add_subparsers(help='APDU Source', dest='source', required=True) -parser_gsmtap = subparsers.add_parser('gsmtap-udp', help='Live capture of GSMTAP-SIM on UDP port') +parser_gsmtap = subparsers.add_parser('gsmtap-udp', help=""" + Read APDUs from live capture by receiving GSMTAP-SIM packets on specified UDP port. + Use this for live capture from SIMtrace2 or osmo-qcdiag.""") parser_gsmtap.add_argument('-i', '--bind-ip', default='127.0.0.1', help='Local IP address to which to bind the UDP port') parser_gsmtap.add_argument('-p', '--bind-port', default=4729, help='Local UDP port') parser_gsmtap_pyshark_pcap = subparsers.add_parser('gsmtap-pyshark-pcap', help=""" - PCAP file containing GSMTAP (SIM APDU) communication; processed via pyshark.""") + Read APDUs from PCAP file containing GSMTAP (SIM APDU) communication; processed via pyshark. + Use this if you have recorded a PCAP file containing GSMTAP (SIM APDU) e.g. via tcpdump or + wireshark/tshark.""") parser_gsmtap_pyshark_pcap.add_argument('-f', '--pcap-file', required=True, help='Name of the PCAP[ng] file to be read') parser_rspro_pyshark_pcap = subparsers.add_parser('rspro-pyshark-pcap', help=""" - PCAP file containing RSPRO (osmo-remsim) communication; processed via pyshark. + Read APDUs from PCAP file containing RSPRO (osmo-remsim) communication; processed via pyshark. REQUIRES OSMOCOM PATCHED WIRESHARK!""") parser_rspro_pyshark_pcap.add_argument('-f', '--pcap-file', required=True, help='Name of the PCAP[ng] file to be read') parser_rspro_pyshark_live = subparsers.add_parser('rspro-pyshark-live', help=""" - Live capture of RSPRO (osmo-remsim) communication; processed via pyshark. + Read APDUs from live capture of RSPRO (osmo-remsim) communication; processed via pyshark. REQUIRES OSMOCOM PATCHED WIRESHARK!""") parser_rspro_pyshark_live.add_argument('-i', '--interface', required=True, help='Name of the network interface to capture on') -- To view, visit https://gerrit.osmocom.org/c/pysim/+/33251 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: pysim Gerrit-Branch: master Gerrit-Change-Id: I5edb222818f00e36ed5b067e0f8d5786f39ae887 Gerrit-Change-Number: 33251 Gerrit-PatchSet: 2 Gerrit-Owner: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: dexter <pmaier(a)sysmocom.de> Gerrit-Reviewer: fixeria <vyanitskiy(a)sysmocom.de> Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-MessageType: merged

1 0

[M] Change in pysim[master]: docs: Add section on pySim-trace to user manual
by laforge 13 Jun '23

13 Jun '23

Attention is currently required from: dexter. laforge has posted comments on this change. ( https://gerrit.osmocom.org/c/pysim/+/33251 ) Change subject: docs: Add section on pySim-trace to user manual ...................................................................... Patch Set 1: Code-Review+2 -- To view, visit https://gerrit.osmocom.org/c/pysim/+/33251 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: pysim Gerrit-Branch: master Gerrit-Change-Id: I5edb222818f00e36ed5b067e0f8d5786f39ae887 Gerrit-Change-Number: 33251 Gerrit-PatchSet: 1 Gerrit-Owner: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: dexter <pmaier(a)sysmocom.de> Gerrit-Reviewer: fixeria <vyanitskiy(a)sysmocom.de> Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-Attention: dexter <pmaier(a)sysmocom.de> Gerrit-Comment-Date: Tue, 13 Jun 2023 15:10:22 +0000 Gerrit-HasComments: No Gerrit-Has-Labels: Yes Gerrit-MessageType: comment

1 0

[S] Change in osmo-pcu[master]: Remove unused GPRS_RLCMAC_FLAG_TO_MASK
by pespin 13 Jun '23

13 Jun '23

pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33271 ) Change subject: Remove unused GPRS_RLCMAC_FLAG_TO_MASK ...................................................................... Remove unused GPRS_RLCMAC_FLAG_TO_MASK We are no longer making use of the 4 high bits in state_flags, so we can safely drop masking them. Change-Id: I1402310919578a09669530786296f34bf3b23ef2 --- M src/tbf.h M src/tbf_dl_fsm.c M src/tbf_ul_fsm.c 3 files changed, 18 insertions(+), 11 deletions(-) Approvals: Jenkins Builder: Verified laforge: Looks good to me, but someone else must approve osmith: Looks good to me, approved diff --git a/src/tbf.h b/src/tbf.h index 878c77b..37756b0 100644 --- a/src/tbf.h +++ b/src/tbf.h @@ -111,7 +111,6 @@ #define GPRS_RLCMAC_FLAG_PACCH 1 /* assignment on PACCH */ #define GPRS_RLCMAC_FLAG_DL_ACK 2 /* DL TBF: At least one DL ACK/NACK was recieved since it was assigned */ #define GPRS_RLCMAC_FLAG_TO_DL_ACK 3 /* DL TBF: Failed to receive last polled DL ACK/NACK */ -#define GPRS_RLCMAC_FLAG_TO_MASK 0xf0 /* timeout bits */ #define TBF_TFI_UNSET 0xff diff --git a/src/tbf_dl_fsm.c b/src/tbf_dl_fsm.c index 7db2cca..c7cc535 100644 --- a/src/tbf_dl_fsm.c +++ b/src/tbf_dl_fsm.c @@ -77,12 +77,10 @@ !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)), !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))); - if (set) { + if (set) ctx->state_flags |= (1 << t); - } else { - ctx->state_flags &= GPRS_RLCMAC_FLAG_TO_MASK; /* keep to flags */ + else ctx->state_flags &= ~(1 << t); - } } @@ -322,8 +320,8 @@ * one slot assigned send another DL assignment via PDCH. */ - /* keep TO flags */ - ctx->state_flags &= GPRS_RLCMAC_FLAG_TO_MASK; + /* Reset state flags */ + ctx->state_flags = 0x00; rc = dl_tbf_upgrade_to_multislot(ctx->dl_tbf); if (rc < 0) diff --git a/src/tbf_ul_fsm.c b/src/tbf_ul_fsm.c index e5c84ed..f6615a8 100644 --- a/src/tbf_ul_fsm.c +++ b/src/tbf_ul_fsm.c @@ -76,12 +76,10 @@ !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)), !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))); - if (set) { + if (set) ctx->state_flags |= (1 << t); - } else { - ctx->state_flags &= GPRS_RLCMAC_FLAG_TO_MASK; /* keep to flags */ + else ctx->state_flags &= ~(1 << t); - } } -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33271 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: I1402310919578a09669530786296f34bf3b23ef2 Gerrit-Change-Number: 33271 Gerrit-PatchSet: 1 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-MessageType: merged

1 0

[M] Change in osmo-pcu[master]: Abort UL TBF PACCH Ass based on T3168
by pespin 13 Jun '23

13 Jun '23

pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33270 ) Change subject: Abort UL TBF PACCH Ass based on T3168 ...................................................................... Abort UL TBF PACCH Ass based on T3168 It makes no sense to continue trying to assign the UL TBF over PACCH after T3168 * 4 retrans time out. This helps in releasing the TBF after we got rid of incorrect use of N3015 in UL TBFs. While at it, update tbf_ul_fsm to use T3168 instead of X2001, since it really needs to match T3168. Ideally it would not even have a timer itself and receive an event from tbf_ul_ass_fsm, but that's left as a TODO (it was already before) and simply the timer is updated. Change-Id: I87dff68dedd06b60501e7586d20faf02bb1f0c93 --- M src/bts.cpp M src/gprs_pcu.c M src/pcu_l1_if.cpp M src/tbf_ul_ass_fsm.c M src/tbf_ul_fsm.c M tests/tbf/TbfTest.err 6 files changed, 103 insertions(+), 31 deletions(-) Approvals: Jenkins Builder: Verified laforge: Looks good to me, but someone else must approve osmith: Looks good to me, but someone else must approve pespin: Looks good to me, approved diff --git a/src/bts.cpp b/src/bts.cpp index 44acbed..44e98c0 100644 --- a/src/bts.cpp +++ b/src/bts.cpp @@ -77,6 +77,7 @@ static struct osmo_tdef T_defs_bts[] = { { .T=3142, .default_val=20, .unit=OSMO_TDEF_S, .desc="Wait Indication used in Imm Ass Reject during TBF Establishment (CCCH)", .val=0, .min_val = 0, .max_val = 255 }, /* TS 44.018 10.5.2.43, TS 44.060 7.1.3.2.1 (T3172) */ + { .T=3168, .default_val=4000, .unit=OSMO_TDEF_MS, .desc="Time MS waits for PACKET UPLINK ACK when establishing a UL TBF", .val=0 }, { .T=3169, .default_val=5, .unit=OSMO_TDEF_S, .desc="Reuse of USF and TFI(s) after the MS uplink TBF assignment is invalid", .val=0 }, { .T=3191, .default_val=5, .unit=OSMO_TDEF_S, .desc="Reuse of TFI(s) after sending (1) last RLC Data Block on TBF(s), or (2) PACKET TBF RELEASE for an MBMS radio bearer", .val=0 }, { .T=3193, .default_val=100, .unit=OSMO_TDEF_MS, .desc="Reuse of TFI(s) after reception of final PACKET DOWNLINK ACK/NACK from MS for TBF", .val=0 }, diff --git a/src/gprs_pcu.c b/src/gprs_pcu.c index 2ad5c71..069f170 100644 --- a/src/gprs_pcu.c +++ b/src/gprs_pcu.c @@ -41,7 +41,7 @@ { .T=-101, .default_val=30, .unit=OSMO_TDEF_S, .desc="BSSGP (un)blocking procedures timer (s)", .val=0 }, { .T=-102, .default_val=30, .unit=OSMO_TDEF_S, .desc="BSSGP reset procedure timer (s)", .val=0 }, { .T=-2000, .default_val=0, .unit=OSMO_TDEF_MS, .desc="Delay release of UL TBF after tx Packet Access Reject (PACCH) (ms)", .val=0 }, - { .T=-2001, .default_val=2, .unit=OSMO_TDEF_S, .desc="PACCH assignment timeout (s)", .val=0 }, + { .T=-2001, .default_val=2, .unit=OSMO_TDEF_S, .desc="DL TBF PACCH assignment timeout (s)", .val=0 }, { .T=-2002, .default_val=200, .unit=OSMO_TDEF_MS, .desc="Waiting after IMM.ASS confirm timer (ms)", .val=0 }, { .T=-2030, .default_val=60, .unit=OSMO_TDEF_S, .desc="Time to keep an idle MS object alive (s)", .val=0 }, /* slightly above T3314 (default 44s, 24.008, 11.2.2) */ { .T=-2031, .default_val=2000, .unit=OSMO_TDEF_MS, .desc="Time to keep an idle DL TBF alive (ms)", .val=0 }, diff --git a/src/pcu_l1_if.cpp b/src/pcu_l1_if.cpp index 0370aeb..7437e16 100644 --- a/src/pcu_l1_if.cpp +++ b/src/pcu_l1_if.cpp @@ -436,6 +436,8 @@ si_ro = ((struct gsm48_system_information_type_13*)data)->rest_octets; if (osmo_gsm48_rest_octets_si13_decode(&bts->si13_ro_decoded, si_ro) < 0) LOGP(DPCU, LOGL_ERROR, "Error decoding SI13\n"); + /* Update our cached T3168 from it: */ + osmo_tdef_set(bts->T_defs_bts, 3168, bts->si13_ro_decoded.cell_opts.t3168, OSMO_TDEF_MS); break; default: LOGP(DL1IF, LOGL_ERROR, diff --git a/src/tbf_ul_ass_fsm.c b/src/tbf_ul_ass_fsm.c index 0fea902..7412107 100644 --- a/src/tbf_ul_ass_fsm.c +++ b/src/tbf_ul_ass_fsm.c @@ -33,9 +33,9 @@ static const struct osmo_tdef_state_timeout tbf_ul_ass_fsm_timeouts[32] = { [TBF_UL_ASS_NONE] = {}, - [TBF_UL_ASS_SEND_ASS] = {}, + [TBF_UL_ASS_SEND_ASS] = { .keep_timer = true }, [TBF_UL_ASS_SEND_ASS_REJ] = {}, - [TBF_UL_ASS_WAIT_ACK] = {}, + [TBF_UL_ASS_WAIT_ACK] = { .keep_timer = true }, }; static const struct value_string tbf_ul_ass_fsm_event_names[] = { @@ -188,6 +188,32 @@ } } +static void st_send_ass_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state) +{ + struct tbf_ul_ass_fsm_ctx *ctx = (struct tbf_ul_ass_fsm_ctx *)fi->priv; + unsigned long val; + unsigned int sec, micro; + struct GprsMs *ms = tbf_ms(ctx->tbf); + + /* Here it's time where received PKT RES REQ or DL ACK/NACK to request a new UL TBF, + * so MS will be gone after T3168 (* 4 retrans, 8.1.1.1.2) if we are unable to seize it. + * Hence, attempt re-scheduling PKT UL ASS (states SEND_ASS<->WAIT_ACK ping-pong) + * until T3168 we announced to the MS expires: + */ + if (prev_state == TBF_UL_ASS_NONE) { + /* tbf_free() called upon trigger */ + fi->T = 3168; + val = osmo_tdef_get(ms->bts->T_defs_bts, fi->T, OSMO_TDEF_MS, -1); + val *= 4; /* 4 PKT RES REQ retransmit */ + sec = val / 1000; + micro = (val % 1000) * 1000; + LOGPTBF(ctx->tbf, LOGL_DEBUG, "starting timer T3168 [PKT UL ASS PACCH] with %u sec. %u microsec\n", + sec, micro); + osmo_timer_schedule(&fi->timer, sec, micro); + } + +} + static void st_send_ass(struct osmo_fsm_inst *fi, uint32_t event, void *data) { struct tbf_ul_ass_fsm_ctx *ctx = (struct tbf_ul_ass_fsm_ctx *)fi->priv; @@ -268,6 +294,7 @@ struct tbf_ul_ass_fsm_ctx *ctx = (struct tbf_ul_ass_fsm_ctx *)fi->priv; switch (fi->T) { case -2000: + case 3168: tbf_free(ctx->tbf); break; default: @@ -298,6 +325,7 @@ X(TBF_UL_ASS_NONE), .name = "SEND_ASS", .action = st_send_ass, + .onenter = st_send_ass_on_enter, }, [TBF_UL_ASS_SEND_ASS_REJ] = { .in_event_mask = diff --git a/src/tbf_ul_fsm.c b/src/tbf_ul_fsm.c index 6160584..e5c84ed 100644 --- a/src/tbf_ul_fsm.c +++ b/src/tbf_ul_fsm.c @@ -106,6 +106,7 @@ static void st_assign_on_enter(struct osmo_fsm_inst *fi, uint32_t prev_state) { struct tbf_ul_fsm_ctx *ctx = (struct tbf_ul_fsm_ctx *)fi->priv; + struct GprsMs *ms = tbf_ms(ctx->tbf); unsigned long val; unsigned int sec, micro; @@ -118,12 +119,13 @@ * other TBF always signal us assignment failure (we already get * assignment success through TBF_EV_ASSIGN_ACK_PACCH) */ if (ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH)) { - fi->T = -2001; - val = osmo_tdef_get(the_pcu->T_defs, fi->T, OSMO_TDEF_MS, -1); + fi->T = 3168; + val = osmo_tdef_get(ms->bts->T_defs_bts, fi->T, OSMO_TDEF_MS, -1); + val *= 4; /* 4 PKT RES REQ retransmit */ sec = val / 1000; micro = (val % 1000) * 1000; LOGPTBFUL(ctx->ul_tbf, LOGL_DEBUG, - "Starting timer X2001 [assignment (PACCH)] with %u sec. %u microsec\n", + "Starting timer T3168 [UL TBF Ass (PACCH)] with %u sec. %u microsec\n", sec, micro); osmo_timer_schedule(&fi->timer, sec, micro); } @@ -259,8 +261,8 @@ { struct tbf_ul_fsm_ctx *ctx = (struct tbf_ul_fsm_ctx *)fi->priv; switch (fi->T) { - case -2001: - LOGPTBFUL(ctx->ul_tbf, LOGL_NOTICE, "releasing due to PACCH assignment timeout.\n"); + case 3168: + LOGPTBFUL(ctx->ul_tbf, LOGL_NOTICE, "Releasing due to UL TBF PACCH assignment timeout\n"); /* fall-through */ case 3169: tbf_free(ctx->tbf); diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err index 9e75001..1797c79 100644 --- a/tests/tbf/TbfTest.err +++ b/tests/tbf/TbfTest.err @@ -55,7 +55,7 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0x00002342){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec Modifying MS object, TLLI: 0xffffffff -> 0x00002342, already confirmed partly The MS object cannot fully confirm an unexpected TLLI: 0x00004232, partly confirmed Modifying MS object, TLLI: 0x00002342 -> 0x00004232, already confirmed partly @@ -2222,10 +2222,11 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -2332,10 +2333,11 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -2507,10 +2509,11 @@ UL_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-1:G:TLLI-0xf5667788){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf5667788:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=2654348 but previous FN=2654301 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered USF (FN=2654301): TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){FLOW} @@ -2648,10 +2651,11 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -2766,10 +2770,11 @@ UL_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(IMSI-0011223344:TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654327 + 13 = 2654340 @@ -2873,10 +2878,11 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -3063,10 +3069,11 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-0:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:G:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -4298,10 +4305,11 @@ UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -4416,10 +4424,11 @@ UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -7550,10 +7559,11 @@ UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -7771,10 +7781,11 @@ UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -8231,10 +8242,11 @@ UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xf1223344:TA-7:MSCLS-1-1:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xf1223344){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654270 + 13 = 2654283 @@ -9599,10 +9611,11 @@ UL_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddcc:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) UL_ASS_TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){SEND_ASS}: Received Event CREATE_RLCMAC_MSG PDCH(bts=0,trx=0,ts=7) POLL scheduled at FN 2654218 + 13 = 2654231 @@ -9649,10 +9662,11 @@ UL_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddcd:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=56 but previous FN=2654231 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} @@ -9705,10 +9719,11 @@ UL_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddce:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=60 but previous FN=2654231 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} @@ -9761,10 +9776,11 @@ UL_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-3:E:TLLI-0xffeeddcf){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddcf:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=65 but previous FN=2654231 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} @@ -9817,10 +9833,11 @@ UL_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-4:E:TLLI-0xffeeddd0){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddd0:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=69 but previous FN=2654231 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-0:E:TLLI-0xffeeddcc){ASSIGN} @@ -9873,10 +9890,11 @@ UL_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-5:E:TLLI-0xffeeddd1){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddd1:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=73 but previous FN=2654231 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-2:E:TLLI-0xffeeddce){ASSIGN} @@ -9929,10 +9947,11 @@ UL_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} Change control TS PDCH(bts=0,trx=0,ts=7) -> PDCH(bts=0,trx=0,ts=7) until assignment is complete. UL_ASS_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NONE}: Received Event SCHED_ASS UL_ASS_TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){NONE}: state_chg to SEND_ASS +TBF(UL:TFI-0-0-6:E:TLLI-0xffeeddd2){ASSIGN} starting timer T3168 [PKT UL ASS PACCH] with 16 sec. 0 microsec MS(TLLI-0xffeeddd2:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=7) Expiring FN=78 but previous FN=2654231 is still reserved! PDCH(bts=0,trx=0,ts=7) Timeout for registered POLL (FN=2654231, reason=UL_ASS): TBF(UL:TFI-0-0-1:E:TLLI-0xffeeddcd){ASSIGN} @@ -9983,7 +10002,7 @@ UL_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec UL_ASS_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NONE}: Received Event SCHED_ASS_REJ UL_ASS_TBF(UL:TFI-0-0--1:E:TLLI-0xffeeddd3){NONE}: state_chg to SEND_ASS_REJ MS(TLLI-0xffeeddd3:TA-7:MSCLS-11-11:UL): - rcv_resource_request: now used by 1 (tbf) @@ -10043,7 +10062,7 @@ UL_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec UL_ASS_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NONE}: Received Event SCHED_ASS_REJ UL_ASS_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){NONE}: state_chg to SEND_ASS_REJ UL_ASS_TBF(UL:TFI-0-0--1:G:TLLI-0xffeeddcc){SEND_ASS_REJ}: Received Event CREATE_RLCMAC_MSG @@ -10140,7 +10159,7 @@ UL_TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){NEW}: Received Event ASSIGN_ADD_PACCH TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){NEW} set ass. type PACCH [prev CCCH:0, PACCH:0] UL_TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){NEW}: state_chg to ASSIGN -TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){ASSIGN} Starting timer X2001 [assignment (PACCH)] with 2 sec. 0 microsec +TBF(UL:TFI-0-0-0:G:TLLI-0xecc1f953){ASSIGN} Starting timer T3168 [UL TBF Ass (PACCH)] with 16 sec. 0 microsec There is a new MS object for the same MS: (0xa3c2f953, '001001000000001') -> (0xecc1f953, '') MS(IMSI-001001000000001:TLLI-0xa3c2f953:TA-220:MSCLS-11-0:DL): + ms_merge_and_clear_ms: now used by 2 (tbf,ms_merge_and_clear_ms) MS(TLLI-0xecc1f953:TA-220:MSCLS-0-0:UL) Merge MS: MS(IMSI-001001000000001:TLLI-0xa3c2f953:TA-220:MSCLS-11-0:DL) -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33270 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: I87dff68dedd06b60501e7586d20faf02bb1f0c93 Gerrit-Change-Number: 33270 Gerrit-PatchSet: 1 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-MessageType: merged

1 0

[M] Change in osmo-pcu[master]: Improve logging in bts_snd_dl_ass()
by pespin 13 Jun '23

13 Jun '23

pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33272 ) Change subject: Improve logging in bts_snd_dl_ass() ...................................................................... Improve logging in bts_snd_dl_ass() Change macro to LOGPTBFDL since it's assigning a DL TBF. Clarify and join log lines. Change-Id: Ic5e01289f97bc113ba0a376a535e0cce5bccc5d1 --- M src/bts.cpp M tests/tbf/TbfTest.err M tests/types/TypesTest.cpp M tests/types/TypesTest.err M tests/ulc/PdchUlcTest.err 5 files changed, 90 insertions(+), 144 deletions(-) Approvals: Jenkins Builder: Verified osmith: Looks good to me, but someone else must approve pespin: Looks good to me, approved diff --git a/src/bts.cpp b/src/bts.cpp index 44e98c0..77d8738 100644 --- a/src/bts.cpp +++ b/src/bts.cpp @@ -1099,12 +1099,12 @@ void bts_snd_dl_ass(struct gprs_rlcmac_bts *bts, const struct gprs_rlcmac_dl_tbf *tbf) { int plen; - const struct gprs_rlcmac_pdch *pdch; - - LOGPTBF(tbf, LOGL_INFO, "TX: START Immediate Assignment Downlink (PCH)\n"); /* Only one TS can be assigned through PCH, hence the first one is the only one: */ - pdch = tbf_get_first_ts_const(tbf); + const struct gprs_rlcmac_pdch *pdch = tbf_get_first_ts_const(tbf); + OSMO_ASSERT(pdch); + + LOGPTBFDL(tbf, LOGL_INFO, "Tx CCCH (PCH) Immediate Assignment [PktDlAss=%s] TA=%d\n", pdch_name(pdch), tbf->ta()); bitvec *immediate_assignment = bitvec_alloc(22, tall_pcu_ctx); /* without plen */ bitvec_unhex(immediate_assignment, DUMMY_VEC); /* standard '2B'O padding */ @@ -1113,8 +1113,6 @@ * that the resource reference cannot be confused with any CHANNEL REQUEST * message sent by a mobile station. Use last_rts_fn + 21216 (16 TDMA * super-frame periods, or ~21.3 seconds) to achieve a decent distance. */ - LOGP(DRLCMAC, LOGL_DEBUG, " - TRX=%d (%d) TS=%d TA=%d\n", - tbf->trx->trx_no, tbf->trx->arfcn, pdch->ts_no, tbf->ta()); plen = Encoding::write_immediate_assignment(pdch, tbf, immediate_assignment, true, 125, fn2rfn(GSM_TDMA_FN_SUM(pdch->last_rts_fn, 21216)), diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err index 1797c79..cc42ea4 100644 --- a/tests/tbf/TbfTest.err +++ b/tests/tbf/TbfTest.err @@ -28,8 +28,7 @@ DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=2 TA=220 +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=2)] TA=220 The MS object cannot fully confirm an unexpected TLLI: 0x00002342, partly confirmed Modifying MS object, TLLI = 0x00002342, TA 220 -> 4 [UL] algo A <multi> (suggested TRX: 0): Alloc start @@ -95,8 +94,7 @@ DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS @@ -221,8 +219,7 @@ DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS @@ -347,8 +344,7 @@ DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS @@ -626,8 +622,7 @@ DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS @@ -666,8 +661,7 @@ DL_TBF(DL:TFI-0-0-1:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-1:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-1:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-1:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-1:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-1:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-1:G){NONE}: state_chg to SEND_ASS @@ -742,8 +736,7 @@ DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000000000:TLLI-0xc0000000){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G:IMSI-001001000000000:TLLI-0xc0000000){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000000000:TLLI-0xc0000000){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G:IMSI-001001000000000:TLLI-0xc0000000){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G:IMSI-001001000000000:TLLI-0xc0000000){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000000:TLLI-0xc0000000:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -775,8 +768,7 @@ DL_TBF(DL:TFI-0-0-1:G:IMSI-001001000000001:TLLI-0xc0000001){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-1:G:IMSI-001001000000001:TLLI-0xc0000001){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-1:G:IMSI-001001000000001:TLLI-0xc0000001){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-1:G:IMSI-001001000000001:TLLI-0xc0000001){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-1:G:IMSI-001001000000001:TLLI-0xc0000001){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000001:TLLI-0xc0000001:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -808,8 +800,7 @@ DL_TBF(DL:TFI-0-0-2:G:IMSI-001001000000002:TLLI-0xc0000002){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-2:G:IMSI-001001000000002:TLLI-0xc0000002){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-2:G:IMSI-001001000000002:TLLI-0xc0000002){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-2:G:IMSI-001001000000002:TLLI-0xc0000002){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-2:G:IMSI-001001000000002:TLLI-0xc0000002){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000002:TLLI-0xc0000002:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -841,8 +832,7 @@ DL_TBF(DL:TFI-0-0-3:G:IMSI-001001000000003:TLLI-0xc0000003){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-3:G:IMSI-001001000000003:TLLI-0xc0000003){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-3:G:IMSI-001001000000003:TLLI-0xc0000003){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-3:G:IMSI-001001000000003:TLLI-0xc0000003){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-3:G:IMSI-001001000000003:TLLI-0xc0000003){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000003:TLLI-0xc0000003:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -874,8 +864,7 @@ DL_TBF(DL:TFI-0-0-4:G:IMSI-001001000000004:TLLI-0xc0000004){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-4:G:IMSI-001001000000004:TLLI-0xc0000004){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-4:G:IMSI-001001000000004:TLLI-0xc0000004){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-4:G:IMSI-001001000000004:TLLI-0xc0000004){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-4:G:IMSI-001001000000004:TLLI-0xc0000004){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000004:TLLI-0xc0000004:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -907,8 +896,7 @@ DL_TBF(DL:TFI-0-0-5:G:IMSI-001001000000005:TLLI-0xc0000005){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-5:G:IMSI-001001000000005:TLLI-0xc0000005){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-5:G:IMSI-001001000000005:TLLI-0xc0000005){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-5:G:IMSI-001001000000005:TLLI-0xc0000005){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-5:G:IMSI-001001000000005:TLLI-0xc0000005){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000005:TLLI-0xc0000005:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -940,8 +928,7 @@ DL_TBF(DL:TFI-0-0-6:G:IMSI-001001000000006:TLLI-0xc0000006){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-6:G:IMSI-001001000000006:TLLI-0xc0000006){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-6:G:IMSI-001001000000006:TLLI-0xc0000006){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-6:G:IMSI-001001000000006:TLLI-0xc0000006){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-6:G:IMSI-001001000000006:TLLI-0xc0000006){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000006:TLLI-0xc0000006:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -973,8 +960,7 @@ DL_TBF(DL:TFI-0-0-7:G:IMSI-001001000000007:TLLI-0xc0000007){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-7:G:IMSI-001001000000007:TLLI-0xc0000007){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-7:G:IMSI-001001000000007:TLLI-0xc0000007){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-7:G:IMSI-001001000000007:TLLI-0xc0000007){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-7:G:IMSI-001001000000007:TLLI-0xc0000007){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000007:TLLI-0xc0000007:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1006,8 +992,7 @@ DL_TBF(DL:TFI-0-0-8:G:IMSI-001001000000008:TLLI-0xc0000008){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-8:G:IMSI-001001000000008:TLLI-0xc0000008){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-8:G:IMSI-001001000000008:TLLI-0xc0000008){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-8:G:IMSI-001001000000008:TLLI-0xc0000008){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-8:G:IMSI-001001000000008:TLLI-0xc0000008){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000008:TLLI-0xc0000008:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1039,8 +1024,7 @@ DL_TBF(DL:TFI-0-0-9:G:IMSI-001001000000009:TLLI-0xc0000009){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-9:G:IMSI-001001000000009:TLLI-0xc0000009){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-9:G:IMSI-001001000000009:TLLI-0xc0000009){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-9:G:IMSI-001001000000009:TLLI-0xc0000009){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-9:G:IMSI-001001000000009:TLLI-0xc0000009){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000009:TLLI-0xc0000009:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1072,8 +1056,7 @@ DL_TBF(DL:TFI-0-0-10:G:IMSI-001001000000010:TLLI-0xc000000a){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-10:G:IMSI-001001000000010:TLLI-0xc000000a){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-10:G:IMSI-001001000000010:TLLI-0xc000000a){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-10:G:IMSI-001001000000010:TLLI-0xc000000a){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-10:G:IMSI-001001000000010:TLLI-0xc000000a){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000010:TLLI-0xc000000a:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1105,8 +1088,7 @@ DL_TBF(DL:TFI-0-0-11:G:IMSI-001001000000011:TLLI-0xc000000b){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-11:G:IMSI-001001000000011:TLLI-0xc000000b){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-11:G:IMSI-001001000000011:TLLI-0xc000000b){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-11:G:IMSI-001001000000011:TLLI-0xc000000b){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-11:G:IMSI-001001000000011:TLLI-0xc000000b){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000011:TLLI-0xc000000b:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1138,8 +1120,7 @@ DL_TBF(DL:TFI-0-0-12:G:IMSI-001001000000012:TLLI-0xc000000c){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-12:G:IMSI-001001000000012:TLLI-0xc000000c){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-12:G:IMSI-001001000000012:TLLI-0xc000000c){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-12:G:IMSI-001001000000012:TLLI-0xc000000c){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-12:G:IMSI-001001000000012:TLLI-0xc000000c){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000012:TLLI-0xc000000c:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1171,8 +1152,7 @@ DL_TBF(DL:TFI-0-0-13:G:IMSI-001001000000013:TLLI-0xc000000d){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-13:G:IMSI-001001000000013:TLLI-0xc000000d){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-13:G:IMSI-001001000000013:TLLI-0xc000000d){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-13:G:IMSI-001001000000013:TLLI-0xc000000d){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-13:G:IMSI-001001000000013:TLLI-0xc000000d){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000013:TLLI-0xc000000d:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1204,8 +1184,7 @@ DL_TBF(DL:TFI-0-0-14:G:IMSI-001001000000014:TLLI-0xc000000e){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-14:G:IMSI-001001000000014:TLLI-0xc000000e){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-14:G:IMSI-001001000000014:TLLI-0xc000000e){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-14:G:IMSI-001001000000014:TLLI-0xc000000e){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-14:G:IMSI-001001000000014:TLLI-0xc000000e){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000014:TLLI-0xc000000e:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1237,8 +1216,7 @@ DL_TBF(DL:TFI-0-0-15:G:IMSI-001001000000015:TLLI-0xc000000f){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-15:G:IMSI-001001000000015:TLLI-0xc000000f){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-15:G:IMSI-001001000000015:TLLI-0xc000000f){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-15:G:IMSI-001001000000015:TLLI-0xc000000f){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-15:G:IMSI-001001000000015:TLLI-0xc000000f){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000015:TLLI-0xc000000f:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1270,8 +1248,7 @@ DL_TBF(DL:TFI-0-0-16:G:IMSI-001001000000016:TLLI-0xc0000010){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-16:G:IMSI-001001000000016:TLLI-0xc0000010){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-16:G:IMSI-001001000000016:TLLI-0xc0000010){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-16:G:IMSI-001001000000016:TLLI-0xc0000010){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-16:G:IMSI-001001000000016:TLLI-0xc0000010){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000016:TLLI-0xc0000010:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1303,8 +1280,7 @@ DL_TBF(DL:TFI-0-0-17:G:IMSI-001001000000017:TLLI-0xc0000011){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-17:G:IMSI-001001000000017:TLLI-0xc0000011){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-17:G:IMSI-001001000000017:TLLI-0xc0000011){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-17:G:IMSI-001001000000017:TLLI-0xc0000011){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-17:G:IMSI-001001000000017:TLLI-0xc0000011){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000017:TLLI-0xc0000011:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1336,8 +1312,7 @@ DL_TBF(DL:TFI-0-0-18:G:IMSI-001001000000018:TLLI-0xc0000012){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-18:G:IMSI-001001000000018:TLLI-0xc0000012){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-18:G:IMSI-001001000000018:TLLI-0xc0000012){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-18:G:IMSI-001001000000018:TLLI-0xc0000012){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-18:G:IMSI-001001000000018:TLLI-0xc0000012){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000018:TLLI-0xc0000012:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1369,8 +1344,7 @@ DL_TBF(DL:TFI-0-0-19:G:IMSI-001001000000019:TLLI-0xc0000013){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-19:G:IMSI-001001000000019:TLLI-0xc0000013){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-19:G:IMSI-001001000000019:TLLI-0xc0000013){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-19:G:IMSI-001001000000019:TLLI-0xc0000013){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-19:G:IMSI-001001000000019:TLLI-0xc0000013){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000019:TLLI-0xc0000013:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1402,8 +1376,7 @@ DL_TBF(DL:TFI-0-0-20:G:IMSI-001001000000020:TLLI-0xc0000014){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-20:G:IMSI-001001000000020:TLLI-0xc0000014){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-20:G:IMSI-001001000000020:TLLI-0xc0000014){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-20:G:IMSI-001001000000020:TLLI-0xc0000014){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-20:G:IMSI-001001000000020:TLLI-0xc0000014){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000020:TLLI-0xc0000014:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1435,8 +1408,7 @@ DL_TBF(DL:TFI-0-0-21:G:IMSI-001001000000021:TLLI-0xc0000015){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-21:G:IMSI-001001000000021:TLLI-0xc0000015){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-21:G:IMSI-001001000000021:TLLI-0xc0000015){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-21:G:IMSI-001001000000021:TLLI-0xc0000015){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-21:G:IMSI-001001000000021:TLLI-0xc0000015){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000021:TLLI-0xc0000015:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1468,8 +1440,7 @@ DL_TBF(DL:TFI-0-0-22:G:IMSI-001001000000022:TLLI-0xc0000016){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-22:G:IMSI-001001000000022:TLLI-0xc0000016){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-22:G:IMSI-001001000000022:TLLI-0xc0000016){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-22:G:IMSI-001001000000022:TLLI-0xc0000016){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-22:G:IMSI-001001000000022:TLLI-0xc0000016){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000022:TLLI-0xc0000016:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1501,8 +1472,7 @@ DL_TBF(DL:TFI-0-0-23:G:IMSI-001001000000023:TLLI-0xc0000017){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-23:G:IMSI-001001000000023:TLLI-0xc0000017){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-23:G:IMSI-001001000000023:TLLI-0xc0000017){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-23:G:IMSI-001001000000023:TLLI-0xc0000017){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-23:G:IMSI-001001000000023:TLLI-0xc0000017){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000023:TLLI-0xc0000017:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1534,8 +1504,7 @@ DL_TBF(DL:TFI-0-0-24:G:IMSI-001001000000024:TLLI-0xc0000018){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-24:G:IMSI-001001000000024:TLLI-0xc0000018){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-24:G:IMSI-001001000000024:TLLI-0xc0000018){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-24:G:IMSI-001001000000024:TLLI-0xc0000018){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-24:G:IMSI-001001000000024:TLLI-0xc0000018){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000024:TLLI-0xc0000018:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1567,8 +1536,7 @@ DL_TBF(DL:TFI-0-0-25:G:IMSI-001001000000025:TLLI-0xc0000019){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-25:G:IMSI-001001000000025:TLLI-0xc0000019){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-25:G:IMSI-001001000000025:TLLI-0xc0000019){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-25:G:IMSI-001001000000025:TLLI-0xc0000019){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-25:G:IMSI-001001000000025:TLLI-0xc0000019){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000025:TLLI-0xc0000019:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1600,8 +1568,7 @@ DL_TBF(DL:TFI-0-0-26:G:IMSI-001001000000026:TLLI-0xc000001a){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-26:G:IMSI-001001000000026:TLLI-0xc000001a){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-26:G:IMSI-001001000000026:TLLI-0xc000001a){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-26:G:IMSI-001001000000026:TLLI-0xc000001a){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-26:G:IMSI-001001000000026:TLLI-0xc000001a){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000026:TLLI-0xc000001a:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1633,8 +1600,7 @@ DL_TBF(DL:TFI-0-0-27:G:IMSI-001001000000027:TLLI-0xc000001b){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-27:G:IMSI-001001000000027:TLLI-0xc000001b){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-27:G:IMSI-001001000000027:TLLI-0xc000001b){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-27:G:IMSI-001001000000027:TLLI-0xc000001b){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-27:G:IMSI-001001000000027:TLLI-0xc000001b){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000027:TLLI-0xc000001b:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1666,8 +1632,7 @@ DL_TBF(DL:TFI-0-0-28:G:IMSI-001001000000028:TLLI-0xc000001c){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-28:G:IMSI-001001000000028:TLLI-0xc000001c){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-28:G:IMSI-001001000000028:TLLI-0xc000001c){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-28:G:IMSI-001001000000028:TLLI-0xc000001c){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-28:G:IMSI-001001000000028:TLLI-0xc000001c){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000028:TLLI-0xc000001c:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1699,8 +1664,7 @@ DL_TBF(DL:TFI-0-0-29:G:IMSI-001001000000029:TLLI-0xc000001d){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-29:G:IMSI-001001000000029:TLLI-0xc000001d){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-29:G:IMSI-001001000000029:TLLI-0xc000001d){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-29:G:IMSI-001001000000029:TLLI-0xc000001d){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-29:G:IMSI-001001000000029:TLLI-0xc000001d){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000029:TLLI-0xc000001d:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1732,8 +1696,7 @@ DL_TBF(DL:TFI-0-0-30:G:IMSI-001001000000030:TLLI-0xc000001e){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-30:G:IMSI-001001000000030:TLLI-0xc000001e){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-30:G:IMSI-001001000000030:TLLI-0xc000001e){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-30:G:IMSI-001001000000030:TLLI-0xc000001e){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-30:G:IMSI-001001000000030:TLLI-0xc000001e){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000030:TLLI-0xc000001e:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1765,8 +1728,7 @@ DL_TBF(DL:TFI-0-0-31:G:IMSI-001001000000031:TLLI-0xc000001f){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-31:G:IMSI-001001000000031:TLLI-0xc000001f){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-31:G:IMSI-001001000000031:TLLI-0xc000001f){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-31:G:IMSI-001001000000031:TLLI-0xc000001f){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-31:G:IMSI-001001000000031:TLLI-0xc000001f){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000000031:TLLI-0xc000001f:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Creating MS object MS(TA-220:MSCLS-0-0): + dl_tbf_handle: now used by 1 (dl_tbf_handle) @@ -1908,8 +1870,7 @@ DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001000123456:TLLI-0xc0123456:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) Modifying MS object, TLLI = 0xc0123456, TA 220 -> 0 MS(IMSI-001001000123456:TLLI-0xc0123456:TA-0:MSCLS-45-0:DL) appending 19 bytes to DL LLC queue @@ -1948,8 +1909,7 @@ DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=0 +TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=0 DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN}: Received Event ASSIGN_PCUIF_CNF TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 0 microsec DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN}: Timeout of X2002 @@ -2175,8 +2135,7 @@ DL_TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=7 TA=7 +TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=7)] TA=7 MS(IMSI-0011223344:TLLI-0xf1223344:TA-7:MSCLS-0-0:DL): - st_finished: now used by 1 (tbf) === end test_tbf_single_phase2 === MS(IMSI-0011223344:TLLI-0xf1223344:TA-7:MSCLS-0-0:DL) Destroying MS object @@ -4159,8 +4118,7 @@ DL_TBF(DL:TFI-0-0-0:G:IMSI-001001123456789:TLLI-0xc0006789){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G:IMSI-001001123456789:TLLI-0xc0006789){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G:IMSI-001001123456789:TLLI-0xc0006789){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G:IMSI-001001123456789:TLLI-0xc0006789){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G:IMSI-001001123456789:TLLI-0xc0006789){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 MS(IMSI-001001123456789:TLLI-0xc0006789:TA-220:MSCLS-45-0:DL): - dl_tbf_handle: now used by 1 (tbf) === end test_tbf_gprs_egprs === MS(IMSI-001001123456789:TLLI-0xc0006789:TA-220:MSCLS-45-0:DL) Destroying MS object @@ -4201,8 +4159,7 @@ DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 DL TBF slots: 0x10, N: 1, WS: 64test_tbf_ws(): DL TBF FAILED: dl_slots = 1 (exp. 4), WS = 64 (exp. 384) TBF(DL:TFI-0-0-0:G){ASSIGN} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:G){ASSIGN}, 1 TBFs, USFs = 00, TFIs = 00000001. @@ -4247,8 +4204,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 DL TBF slots: 0x10, N: 1, WS: 192test_tbf_ws(): DL TBF FAILED: dl_slots = 1 (exp. 4), WS = 192 (exp. 384) TBF(DL:TFI-0-0-0:E){ASSIGN} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E){ASSIGN}, 1 TBFs, USFs = 00, TFIs = 00000001. @@ -4655,8 +4611,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -4974,8 +4929,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -5240,8 +5194,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -5466,8 +5419,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -5676,8 +5628,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -5870,8 +5821,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6040,8 +5990,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6219,8 +6168,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6389,8 +6337,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6551,8 +6498,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6630,8 +6576,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6708,8 +6653,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6786,8 +6730,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6889,8 +6832,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -6991,8 +6933,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -7093,8 +7034,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -7198,8 +7138,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -7283,8 +7222,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -7368,8 +7306,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -7453,8 +7390,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -7695,8 +7631,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 DL TBF slots: 0x10, N: 1, WS: 192 TBF(DL:TFI-0-0-0:E){ASSIGN} Upgrade to multislot PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E){ASSIGN}, 1 TBFs, USFs = 00, TFIs = 00000001. @@ -7900,8 +7835,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -9508,8 +9442,7 @@ DL_TBF(DL:TFI-0-0-0:E){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-0-0:E){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-0-0:E){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-0-0:E){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=0 (0) TS=4 TA=220 +TBF(DL:TFI-0-0-0:E){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=220 Modifying MS object, TLLI = 0xffffffff, TA 220 -> 0 DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS @@ -10122,8 +10055,7 @@ DL_TBF(DL:TFI-0-1-0:G:IMSI-001001000000001:TLLI-0xa3c2f953){NEW}: Received Event ASSIGN_ADD_CCCH TBF(DL:TFI-0-1-0:G:IMSI-001001000000001:TLLI-0xa3c2f953){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] DL_TBF(DL:TFI-0-1-0:G:IMSI-001001000000001:TLLI-0xa3c2f953){NEW}: state_chg to ASSIGN -TBF(DL:TFI-0-1-0:G:IMSI-001001000000001:TLLI-0xa3c2f953){ASSIGN} TX: START Immediate Assignment Downlink (PCH) - - TRX=1 (0) TS=5 TA=220 +TBF(DL:TFI-0-1-0:G:IMSI-001001000000001:TLLI-0xa3c2f953){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=1,ts=5)] TA=220 MS(IMSI-001001000000001:TLLI-0xa3c2f953:TA-220:MSCLS-11-0:DL): - dl_tbf_handle: now used by 1 (tbf) PDCH(bts=0,trx=0,ts=1) PDCH state: disabled => enabled PDCH(bts=0,trx=0,ts=2) PDCH state: disabled => enabled diff --git a/tests/types/TypesTest.cpp b/tests/types/TypesTest.cpp index 0628497..fdfbe40 100644 --- a/tests/types/TypesTest.cpp +++ b/tests/types/TypesTest.cpp @@ -962,6 +962,7 @@ log_set_category_filter(osmo_stderr_target, DTBF, 1, LOGL_INFO); log_set_category_filter(osmo_stderr_target, DTBFUL, 1, LOGL_INFO); + log_set_category_filter(osmo_stderr_target, DTBFDL, 1, LOGL_INFO); osmo_fsm_log_addr(false); the_pcu = gprs_pcu_alloc(tall_pcu_ctx); diff --git a/tests/types/TypesTest.err b/tests/types/TypesTest.err index 9ace2ef..4c20672 100644 --- a/tests/types/TypesTest.err +++ b/tests/types/TypesTest.err @@ -1,9 +1,13 @@ MS(TA-220:MSCLS-1-0) Allocating DL TBF UL_ASS_TBF{NONE}: Allocated DL_ASS_TBF{NONE}: Allocated +DL_TBF{NEW}: Allocated TBF(DL:TFI-0-0-0:G){NEW} Setting Control TS PDCH(bts=0,trx=0,ts=2) TBF(DL:TFI-0-0-0:G){NEW} Allocated: trx = 0, ul_slots = 04, dl_slots = 04 -TBF(DL:TFI-0-0-0:G){ASSIGN} TX: START Immediate Assignment Downlink (PCH) +DL_TBF(DL:TFI-0-0-0:G){NEW}: Received Event ASSIGN_ADD_CCCH +TBF(DL:TFI-0-0-0:G){NEW} set ass. type CCCH [prev CCCH:0, PACCH:0] +DL_TBF(DL:TFI-0-0-0:G){NEW}: state_chg to ASSIGN +TBF(DL:TFI-0-0-0:G){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=2)] TA=220 PCU socket not connected, dropping message MS(TA-220:MSCLS-1-0) Allocating UL TBF UL_ASS_TBF{NONE}: Allocated diff --git a/tests/ulc/PdchUlcTest.err b/tests/ulc/PdchUlcTest.err index 9183d45..04ae438 100644 --- a/tests/ulc/PdchUlcTest.err +++ b/tests/ulc/PdchUlcTest.err @@ -20,7 +20,6 @@ PDCH(bts=0,trx=0,ts=0) Attaching TBF(DL:TFI-0-0-0:G:TLLI-0x12345678){NEW}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0x12345678:TA-220:MSCLS-0-0) Attaching DL TBF: TBF(DL:TFI-0-0-0:G:TLLI-0x12345678){NEW} MS(TLLI-0x12345678:TA-220:MSCLS-0-0:DL): + tbf: now used by 1 (tbf) - - TRX=0 (0) TS=0 TA=220 PDCH(bts=0,trx=0,ts=0) Reserving FN 2715608 for type POLL PDCH(bts=0,trx=0,ts=0) Reserving FN 2715613 for type POLL PDCH(bts=0,trx=0,ts=0) Reserving FN 2715617 for type POLL -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33272 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: Ic5e01289f97bc113ba0a376a535e0cce5bccc5d1 Gerrit-Change-Number: 33272 Gerrit-PatchSet: 1 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-MessageType: merged

1 0

[S] Change in osmo-pcu[master]: tbf_{ul,dl}_fsm: Abort on unexpected path
by pespin 13 Jun '23

13 Jun '23

pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33274 ) Change subject: tbf_{ul,dl}_fsm: Abort on unexpected path ...................................................................... tbf_{ul,dl}_fsm: Abort on unexpected path That path should not really happen. It happening would mean a totally wrong code being used. Hence, just abort() to simplify the code. Change-Id: Iaf65e909e45cc279e5be4b045c15174f910ffc12 --- M src/tbf_dl_fsm.c M src/tbf_ul_fsm.c 2 files changed, 14 insertions(+), 8 deletions(-) Approvals: Jenkins Builder: Verified osmith: Looks good to me, approved diff --git a/src/tbf_dl_fsm.c b/src/tbf_dl_fsm.c index 9cc2007..abcd0c4 100644 --- a/src/tbf_dl_fsm.c +++ b/src/tbf_dl_fsm.c @@ -60,10 +60,7 @@ ch = "PACCH"; break; default: - LOGPTBFDL(ctx->dl_tbf, LOGL_ERROR, - "attempted to %sset unexpected ass. type %d - FIXME!\n", - set ? "" : "un", t); - return; + OSMO_ASSERT(0); } if (set && prev_set) diff --git a/src/tbf_ul_fsm.c b/src/tbf_ul_fsm.c index f6615a8..5d02032 100644 --- a/src/tbf_ul_fsm.c +++ b/src/tbf_ul_fsm.c @@ -59,10 +59,7 @@ ch = "PACCH"; break; default: - LOGPTBFUL(ctx->ul_tbf, LOGL_ERROR, - "attempted to %sset unexpected ass. type %d - FIXME!\n", - set ? "" : "un", t); - return; + OSMO_ASSERT(0); } if (set && prev_set) -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33274 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: Iaf65e909e45cc279e5be4b045c15174f910ffc12 Gerrit-Change-Number: 33274 Gerrit-PatchSet: 2 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-MessageType: merged

1 0

[S] Change in osmo-pcu[master]: tbf_dl_fsm: Fix wrong lchan specified in log line
by pespin 13 Jun '23

13 Jun '23

pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33273 ) Change subject: tbf_dl_fsm: Fix wrong lchan specified in log line ...................................................................... tbf_dl_fsm: Fix wrong lchan specified in log line Change-Id: I30111989c85001b0d9b98bf6f19c2247ab144433 --- M src/tbf_dl_fsm.c M tests/tbf/TbfTest.err 2 files changed, 11 insertions(+), 2 deletions(-) Approvals: Jenkins Builder: Verified laforge: Looks good to me, but someone else must approve osmith: Looks good to me, approved diff --git a/src/tbf_dl_fsm.c b/src/tbf_dl_fsm.c index c7cc535..9cc2007 100644 --- a/src/tbf_dl_fsm.c +++ b/src/tbf_dl_fsm.c @@ -179,7 +179,7 @@ sec = val / 1000; micro = (val % 1000) * 1000; LOGPTBFDL(ctx->dl_tbf, LOGL_DEBUG, - "Starting timer X2002 [assignment (AGCH)] with %u sec. %u microsec\n", + "Starting timer X2002 [assignment (PCH)] with %u sec. %u microsec\n", sec, micro); osmo_timer_schedule(&fi->timer, sec, micro); break; diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err index cc42ea4..0c9aa58 100644 --- a/tests/tbf/TbfTest.err +++ b/tests/tbf/TbfTest.err @@ -1911,7 +1911,7 @@ DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){NEW}: state_chg to ASSIGN TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} Tx CCCH (PCH) Immediate Assignment [PktDlAss=PDCH(bts=0,trx=0,ts=4)] TA=0 DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN}: Received Event ASSIGN_PCUIF_CNF -TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} Starting timer X2002 [assignment (AGCH)] with 0 sec. 0 microsec +TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN} Starting timer X2002 [assignment (PCH)] with 0 sec. 0 microsec DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN}: Timeout of X2002 DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN}: Received Event ASSIGN_READY_CCCH DL_TBF(DL:TFI-0-0-0:G:IMSI-001001000123456:TLLI-0xc0123456){ASSIGN}: state_chg to FLOW -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33273 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: I30111989c85001b0d9b98bf6f19c2247ab144433 Gerrit-Change-Number: 33273 Gerrit-PatchSet: 1 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-MessageType: merged

1 0

[M] Change in osmo-pcu[master]: tbf_{ul,dl}_fsm.c: Rearrange code/logs in mod_ass_type()
by pespin 13 Jun '23

13 Jun '23

pespin has submitted this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33275 ) Change subject: tbf_{ul,dl}_fsm.c: Rearrange code/logs in mod_ass_type() ...................................................................... tbf_{ul,dl}_fsm.c: Rearrange code/logs in mod_ass_type() First print what is going to be attempted, later alarm about the possible error, finally early return. Change-Id: I417e9689f60e7f5d3c8ef67543e56fea87c8eebd --- M src/tbf_dl_fsm.c M src/tbf_ul_fsm.c M tests/tbf/TbfTest.err 3 files changed, 81 insertions(+), 39 deletions(-) Approvals: laforge: Looks good to me, but someone else must approve Jenkins Builder: Verified osmith: Looks good to me, approved diff --git a/src/tbf_dl_fsm.c b/src/tbf_dl_fsm.c index abcd0c4..6c3f4f1 100644 --- a/src/tbf_dl_fsm.c +++ b/src/tbf_dl_fsm.c @@ -63,17 +63,20 @@ OSMO_ASSERT(0); } - if (set && prev_set) - LOGPTBFDL(ctx->dl_tbf, LOGL_ERROR, - "attempted to set ass. type %s which is already set.\n", ch); - else if (!set && !prev_set) - return; - LOGPTBFDL(ctx->dl_tbf, LOGL_INFO, "%sset ass. type %s [prev CCCH:%u, PACCH:%u]\n", set ? "" : "un", ch, !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)), !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))); + if (set && prev_set) { + LOGPTBFDL(ctx->dl_tbf, LOGL_ERROR, + "Attempted to set ass. type %s which is already set\n", ch); + return; + } + + if (!set && !prev_set) + return; + if (set) ctx->state_flags |= (1 << t); else diff --git a/src/tbf_ul_fsm.c b/src/tbf_ul_fsm.c index 5d02032..a26d161 100644 --- a/src/tbf_ul_fsm.c +++ b/src/tbf_ul_fsm.c @@ -62,17 +62,20 @@ OSMO_ASSERT(0); } - if (set && prev_set) - LOGPTBFUL(ctx->ul_tbf, LOGL_ERROR, - "attempted to set ass. type %s which is already set.\n", ch); - else if (!set && !prev_set) - return; - LOGPTBFUL(ctx->ul_tbf, LOGL_INFO, "%sset ass. type %s [prev CCCH:%u, PACCH:%u]\n", set ? "" : "un", ch, !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_CCCH)), !!(ctx->state_flags & (1 << GPRS_RLCMAC_FLAG_PACCH))); + if (set && prev_set) { + LOGPTBFUL(ctx->ul_tbf, LOGL_ERROR, + "Attempted to set ass. type %s which is already set\n", ch); + return; + } + + if (!set && !prev_set) + return; + if (set) ctx->state_flags |= (1 << t); else diff --git a/tests/tbf/TbfTest.err b/tests/tbf/TbfTest.err index 0c9aa58..a4b94cf 100644 --- a/tests/tbf/TbfTest.err +++ b/tests/tbf/TbfTest.err @@ -99,8 +99,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:G){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:G){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:G){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -143,6 +143,7 @@ TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:G){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:G){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] [DL] algo A <multi> (suggested TRX: 0): Alloc start - Skipping TS 0, because not enabled - Skipping TS 1, because not enabled @@ -224,8 +225,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:G){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:G){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:G){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -268,6 +269,7 @@ TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:G){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:G){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] [DL] algo A <multi> (suggested TRX: 0): Alloc start - Skipping TS 0, because not enabled - Skipping TS 1, because not enabled @@ -349,8 +351,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:G){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:G){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:G){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -583,6 +585,7 @@ TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){FINISHED} Final ACK received. DL_TBF(DL:TFI-0-0-0:G){FINISHED}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:G){FINISHED}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:G:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-45-0:DL) Detaching TBF: TBF(DL:G:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -627,8 +630,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:G){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:G){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:G){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:G){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:G){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:G){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -666,8 +669,8 @@ DL_ASS_TBF(DL:TFI-0-0-1:G){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-1:G){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-1:G){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-1:G){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-1:G){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-1:G){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-1:G){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-1:G){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-1:G){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -3820,6 +3823,7 @@ TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){FINISHED} Final ACK received. DL_TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){FINISHED}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){FINISHED}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:G:IMSI-0011223344:TLLI-0xf1223344){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] [DL] algo A <multi> (suggested TRX: 0): Alloc start - Skipping TS 0, because not enabled - Skipping TS 1, because not enabled @@ -4616,8 +4620,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -4888,6 +4892,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -4934,8 +4939,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -5153,6 +5158,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -5199,8 +5205,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -5378,6 +5384,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -5424,8 +5431,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -5587,6 +5594,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -5633,8 +5641,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -5780,6 +5788,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -5826,8 +5835,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -5949,6 +5958,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -5995,8 +6005,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6127,6 +6137,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6173,8 +6184,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6296,6 +6307,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6342,8 +6354,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6454,6 +6466,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6503,8 +6516,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6535,6 +6548,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6581,8 +6595,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6612,6 +6626,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6658,8 +6673,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6689,6 +6704,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6735,8 +6751,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6791,6 +6807,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6837,8 +6854,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6892,6 +6909,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -6938,8 +6956,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -6993,6 +7011,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -7039,8 +7058,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -7094,6 +7113,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -7143,8 +7163,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -7181,6 +7201,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -7227,8 +7248,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -7265,6 +7286,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -7311,8 +7333,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -7349,6 +7371,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -7395,8 +7418,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -7440,6 +7463,7 @@ TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){FLOW} Final ACK received. DL_TBF(DL:TFI-0-0-0:E){FLOW}: Received Event FINAL_ACK_RECVD DL_TBF(DL:TFI-0-0-0:E){FLOW}: state_chg to WAIT_RELEASE +TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} unset ass. type CCCH [prev CCCH:0, PACCH:1] TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE} free PDCH(bts=0,trx=0,ts=4) Detaching TBF(DL:TFI-0-0-0:E:TLLI-0xffeeddcc){WAIT_RELEASE}, 1 TBFs, USFs = 00, TFIs = 00000001. MS(TLLI-0xffeeddcc:TA-0:MSCLS-11-11:DL) Detaching TBF: TBF(DL:E:TLLI-0xffeeddcc){WAIT_RELEASE} @@ -7840,8 +7864,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] @@ -9447,8 +9471,8 @@ DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: Received Event SCHED_ASS DL_ASS_TBF(DL:TFI-0-0-0:E){NONE}: state_chg to SEND_ASS DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ADD_CCCH -TBF(DL:TFI-0-0-0:E){ASSIGN} attempted to set ass. type CCCH which is already set. TBF(DL:TFI-0-0-0:E){ASSIGN} set ass. type CCCH [prev CCCH:1, PACCH:0] +TBF(DL:TFI-0-0-0:E){ASSIGN} Attempted to set ass. type CCCH which is already set DL_TBF(DL:TFI-0-0-0:E){ASSIGN}: Received Event ASSIGN_ACK_PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} The TBF has been confirmed on the PACCH, changed type from CCCH to PACCH TBF(DL:TFI-0-0-0:E){ASSIGN} unset ass. type CCCH [prev CCCH:1, PACCH:0] -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33275 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: I417e9689f60e7f5d3c8ef67543e56fea87c8eebd Gerrit-Change-Number: 33275 Gerrit-PatchSet: 3 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: laforge <laforge(a)osmocom.org> Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-MessageType: merged

1 0

[M] Change in osmo-pcu[master]: Improve logging in bts_snd_dl_ass()
by pespin 13 Jun '23

13 Jun '23

pespin has posted comments on this change. ( https://gerrit.osmocom.org/c/osmo-pcu/+/33272 ) Change subject: Improve logging in bts_snd_dl_ass() ...................................................................... Patch Set 1: Code-Review+2 -- To view, visit https://gerrit.osmocom.org/c/osmo-pcu/+/33272 To unsubscribe, or for help writing mail filters, visit https://gerrit.osmocom.org/settings Gerrit-Project: osmo-pcu Gerrit-Branch: master Gerrit-Change-Id: Ic5e01289f97bc113ba0a376a535e0cce5bccc5d1 Gerrit-Change-Number: 33272 Gerrit-PatchSet: 1 Gerrit-Owner: pespin <pespin(a)sysmocom.de> Gerrit-Reviewer: Jenkins Builder Gerrit-Reviewer: osmith <osmith(a)sysmocom.de> Gerrit-Reviewer: pespin <pespin(a)sysmocom.de> Gerrit-Comment-Date: Tue, 13 Jun 2023 14:52:46 +0000 Gerrit-HasComments: No Gerrit-Has-Labels: Yes Gerrit-MessageType: comment

1 0