Project

General

Profile

Bug #4616

osmo-sgsn PS paging an MS on each DL ip packet received for it

Added by pespin 18 days ago. Updated 8 days ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
06/16/2020
Due date:
% Done:

100%

Spec Reference:
TS 48.018 7.4 + 7.5

Description

2 phones attached to a network running current master of osmo-pcu, osmo-sgsn, osmo-ggsn, etc.

  1. phoneA (alcatel onetouch) is pinging 8.8.8.8 on a loop through adb shell.
  2. phoneB (motorola G something) calls phoneA, calls is established and works fine, and call is finished by phoneB.
  3. phoneB resumes ping (connecion becomes active) after call is finished, ping is working fine from MS point of view.

Then, at that point, each ICMP req (uplink) contains TLLI=0xABCD on bssgp, and SGSN forwards it to GGSN
When each ICMP REPLY is received from GGSN in the SGSN, the SGSN sends a PS-PAGING request in sgsn_libgtp.c:cb_data_ind() because it finds the MS in status ST_GMM_REGISTERED_SUSPENDED. At the same time it also allows the icmp reply to be forwarded back to the PCU so everything looks like working but the SGSN sends lots of PS-PAGING requests (one for each downlink icmp reply packet).

When each of these PS-PAGING requests arrive on the PCU, it sends a Paging Request Type 1 over CCCH, but the MS of course doesn't see those because it's already GPRS-attached and sending data....


Related issues

Related to OsmoBSC - Bug #2249: RR GPRS suspension request is not forwarded to the GMM/SGSNResolved05/09/2017

History

#1 Updated by pespin 18 days ago

I improved a bit the paging-realted logging to get more clear idea on what was going on, but it was already possible to figure out it was in GMM SUSPENDED due to other logs already available:
https://gerrit.osmocom.org/c/osmo-sgsn/+/18868 sgsn_libgtp: Improve ps-paging logging

I can always reproduce the issue with the MS, her e a short log snippet with the issue and with the patch explained above applied:

...
20200616192239812 DMM <0002> /osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2515180981)[0x6120000042a0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200616192239812 DSNDCP <0012> /osmo-sgsn/src/sgsn/gprs_sndcp.c:398 TLLI=0xdf70dcef NSAPI=5: Input PDU 1275 Segment 1 Length 76
20200616192239812 DSNDCP <0012> /osmo-sgsn/src/sgsn/gprs_sndcp.c:285 TLLI=0xdf70dcef NSAPI=5: Defragment output PDU 1275 num_seg=1 tot_len=569
20200616192239843 DGPRS <000e> /osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200616192239843 DMM <0002> /osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/df70dcef) Paging MS in GMM state Registered.SUSPENDED      <------ HERE
20200616192239843 DGPRS <000e> /osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=191
20200616192239843 DMM <0002> /osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/df70dcef) Paging MS in GMM state Registered.SUSPENDED      <------ HERE
20200616192239848 DBSSGP <0010> /libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xdf70dcef Rx UPLINK-UNITDATA
20200616192239848 DLLC <0011> /osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x774951 CMD=UI DATA
20200616192239848 DMM <0002> /osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2515180981)[0x6120000042a0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200616192239871 DBSSGP <0010> /libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xd26efd35 Rx UPLINK-UNITDATA
20200616192239871 DLLC <0011> /osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xa63376 CMD=UI DATA
20200616192239871 DMM <0002> /osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2802564973)[0x612000003b20]{Ready}: Received Event E_MM_PDU_RECEPTION
20200616192239882 DGPRS <000e> /osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200616192239882 DMM <0002> /osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015256/d26efd35) Paging MS in GMM state Registered.SUSPENDED       <------ HERE
20200616192239889 DBSSGP <0010> /libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xdf70dcef Rx UPLINK-UNITDATA
20200616192239889 DLLC <0011> /osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x98d559 CMD=UI DATA
20200616192239889 DMM <0002> /osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2515180981)[0x6120000042a0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200616192239930 DBSSGP <0010> /libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xdf70dcef Rx UPLINK-UNITDATA
...

I'm also attaching a pcapng I took where 2 MS are already registered and doing GPRS stuff and pcap more or less starts when phoneA calls phoneB, it closes the call after a few seconds and then the issue happens for a while.

Good first wireshark filter: gprs-ns || gtp || gsm_rlcmac
Good first starting point: first PAGING-PS, frame #859

#2 Updated by pespin 18 days ago

I recommend using wireshark from current master in .git due to EGPRS support in it.

Frame #734 shows a GPRS Suspension REquest in SDDCH reaching the BTS -> PCU which tens sends a BSSGP SUSPEND to SGSN. SGSN answers with a BSSGP SUSPEND ACK.

Looking at the whole pcap, it seems the continuous PS-PAGING issue starts from moment zero when the MS moves to SUSPEND state at the start of the call (#965).

In Frame #1218 there's another GPRS Suspend Request while the call is in process (probably from the MT mobile). This time also SUSPEND and SUSPEND-ACK in SGSN.

More PAGING-PS can be seen while the call is ongoing every time a DL IP packet arrives, for instance in #2112, and subsequent CCCH Paging Request Type 1 generatd by it in @2114, and so on.

After the call, one MS can be seen doing a RA Update in #6875.

#3 Updated by laforge 18 days ago

3GPP TS 48.018 Section 7.4:

If the MS signals to the BSS that it wishes its GPRS service to be suspended, the BSS shall send a SUSPEND PDU to the SGSN and start timer T3. Actions within the SGSN while an MS is suspended are not specified, but paging is typically stopped

So while suspended, the SGSN should not send any paging.

btw: I was also seeing a suspicously high amount of PS-PAGING in a pcap file
of a OsmoSGSN installation earlier today.

#4 Updated by laforge 18 days ago

On Tue, Jun 16, 2020 at 04:33:54PM +0000, pespin [REDMINE] wrote:

  1. phoneA (alcatel onetouch) is pinging 8.8.8.8 on a loop through adb shell.
  2. phoneB (motorola G something) calls phoneA, calls is established and works fine, and call is finished by phoneB.
  3. phoneB resumes ping (connecion becomes active) after call is finished, ping is working fine from MS point of view.

Then, at that point, each ICMP req (uplink) contains TLLI=0xABCD on bssgp, and SGSN forwards it to GGSN
When each ICMP REPLY is received from GGSN in the SGSN, the SGSN sends a PS-PAGING request in sgsn_libgtp.c:cb_data_ind() because it finds the MS in status ST_GMM_REGISTERED_SUSPENDED. At the same time it also allows the icmp reply to be forwarded back to the PCU so everything looks like working but the SGSN sends lots of PS-PAGING requests (one for each downlink icmp reply packet).

So the RESUME procedure is not implemented as expected. I think there is both explicit resume
by means of related signaling (causing a BSSGP RESUME on Gb), or implicit resume by means of RAU.

See Section 7.5 of 3GPP TS 48.018.

When each of these PS-PAGING requests arrive on the PCU, it sends a Paging Request Type 1 over CCCH, but the MS of course doesn't see those because it's already GPRS-attached and sending data....

This is likely a separate bug in the PCU, as
  • paging for a MS with active TBF should be delivered on PACCH, not PCH
  • paging for PS while active TBF doesn't really make sense.

#5 Updated by laforge 18 days ago

  • Spec Reference set to TS 48.018 7.4 + 7.5

#6 Updated by laforge 18 days ago

  • Related to Bug #2249: RR GPRS suspension request is not forwarded to the GMM/SGSN added

#7 Updated by laforge 18 days ago

Actually, my previous update regarding RR CHANNEL RELEASE was wrong. That messsage
is used in MT direction and the GPRS Resumption IE serves to inform the
MS on whether or not the BSS has already resumed GPRS services or not.
Absence of that IE is treated as 'not yet resumed'.

Only a BSC-colocated PCU would be able to perform the BSSGP RESUME
automatically at RR CHANNEL RELEASE, so that doesn't apply to the
current Osmocom architecture.

As a result of absence of that IE, the MS should perform some kind of
procedure (e.g. RAU) in order to resume itself for GPRS services.

So most likely OsmoSGSN is not processing such signalling correctly,
i.e. marking the MM context as GPRS resumed.

#8 Updated by laforge 18 days ago

the only instance at which OsmoSGSN resumes is on explicit reception of a PRIM_BSSGP_GMM_RESUME
primitive inside gprs_gmm_rx_resume(), which is triggered by receiving a BSSGP RESUME
message in bssgp_rx_resume, i.e. the explicit resume.

The implicit resume by RAU is not implemented, but shoul be.

#9 Updated by laforge 18 days ago

See 3GPP TS 23.060 section 16.2.1.1.1 clause 6:

The MS shall resume GPRS services by sending a Routeing Area Update Request message to the SGSN:
  • if the BSS did not successfully request the SGSN to resume GPRS services,
  • if the RR Channel Release message was not received before the MS left dedicated mode,
  • if the MS locally determines that the conditions for the GPRS suspension have disappeared

#10 Updated by laforge 17 days ago

  • Assignee set to laforge
  • % Done changed from 0 to 20

I have pushed an untested patch at https://gerrit.osmocom.org/c/osmo-sgsn/+/18877 which should solve one of the issues described here: The failure to resume GPRS on RAU. Feel free to test it manually.

#11 Updated by pespin 17 days ago

After applying the patch and re-testing same scenario, I can still reproduce the exact same issue. I attach a pcap file taken while call was ongoing and finished and then the 2 MS do RA update and one continues with the ping loop triggering continuous Paging-PS. Summary of the situation after call, around frame #660:

RAU REQ: TLLI - current - 0xf6939325
RAU ACC: IMSI: 901700000015254
RAU COMPL: TLLI: 0xd2d91452

RAU REQ: TLLI: 0xee60e5e8
RAU ACC: IMSI: 901700000015256
RAU COMPL: TLLI: 0xe7a80685   

ping messages sent with this TLLI: 0xe7a80685

PAGING-ps sent with IMSI: 901700000015256 and TMSI/P-TMSI: 0xe7a80685

So everything looks like fine but for some reason the MS still was kept into GMM SUSPENDED state (I would see so in the logs). I will retrigger issue again and store osmo-sgsn logs somewhere to find out why didn't it change to some other state.

#12 Updated by pespin 17 days ago

Tested again and got related log files from osmo-sgsn:


20200617135518502 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135518531 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=60
20200617135518533 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=86
20200617135518941 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xcbb524a0 Rx UPLINK-UNITDATA
20200617135518941 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x10abac CMD=UI DATA
20200617135518941 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135518952 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200617135519254 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:447 BSSGP BVCI=0 TLLI=0xf23e1395 Rx SUSPEND
20200617135519254 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:2211 GMM(gmm_fsm)[0x6120000039a0]{Registered.NORMAL}: Received Event E_GMM_SUSPEND
20200617135519255 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:64 GMM(gmm_fsm)[0x6120000039a0]{Registered.NORMAL}: state_chg to Registered.SUSPENDED
20200617135519255 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617135519255 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135520036 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=60
20200617135520036 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135521157 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:447 BSSGP BVCI=0 TLLI=0xcbb524a0 Rx SUSPEND
20200617135521157 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:2211 GMM(gmm_fsm)[0x612000004120]{Registered.NORMAL}: Received Event E_GMM_SUSPEND
20200617135521157 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:64 GMM(gmm_fsm)[0x612000004120]{Registered.NORMAL}: state_chg to Registered.SUSPENDED
20200617135522121 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617135522121 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135522563 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=60
20200617135522563 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135522845 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:820 BSSGP BVCI=1800 Rx Flow Control BVC
20200617135522915 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=60
20200617135522915 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135525253 DGPRS <000e> /git/osmo-sgsn/src/sgsn/gprs_sgsn.c:1012 Checking for inactive LLMEs, time = 6815
20200617135527135 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=1410
20200617135527135 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135527507 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617135527507 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135527534 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617135527534 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135528227 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=60
20200617135528227 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135530379 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617135530379 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135530755 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=60
20200617135530755 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/f23e1395) Paging MS in GMM state Registered.SUSPENDED
20200617135531560 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xf23e1395 Rx UPLINK-UNITDATA
20200617135531560 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x108c18 CMD=UI DATA
20200617135531560 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135531560 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1560 MM(901700000015254/f23e1395) -> GMM RA UPDATE REQUEST type="RA updating" 
20200617135531560 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1099 GMM(gmm_fsm)[0x6120000039a0]{Registered.SUSPENDED}: Received Event E_GMM_COMMON_PROC_INIT_REQ
20200617135531560 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1099 GMM(gmm_fsm)[0x6120000039a0]{Registered.SUSPENDED}: Event E_GMM_COMMON_PROC_INIT_REQ not permitted
20200617135531560 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(ffffffff/f23e1395){ASSIGNED} LLGM Assign pre (f23e1395 => c83880f6)
20200617135531560 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(f23e1395/c83880f6){ASSIGNED} LLGM Assign post (f23e1395 => c83880f6)
20200617135531560 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1430 MM(901700000015254/c83880f6) <- ROUTING AREA UPDATE ACCEPT
20200617135531680 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xcbb524a0 Rx UPLINK-UNITDATA
20200617135531680 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x202e43 CMD=UI DATA
20200617135531680 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135531680 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1560 MM(901700000015256/cbb524a0) -> GMM RA UPDATE REQUEST type="RA updating" 
20200617135531680 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1099 GMM(gmm_fsm)[0x612000004120]{Registered.SUSPENDED}: Received Event E_GMM_COMMON_PROC_INIT_REQ
20200617135531680 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1099 GMM(gmm_fsm)[0x612000004120]{Registered.SUSPENDED}: Event E_GMM_COMMON_PROC_INIT_REQ not permitted
20200617135531680 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(ffffffff/cbb524a0){ASSIGNED} LLGM Assign pre (cbb524a0 => da771c53)
20200617135531680 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(cbb524a0/da771c53){ASSIGNED} LLGM Assign post (cbb524a0 => da771c53)
20200617135531680 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1430 MM(901700000015256/da771c53) <- ROUTING AREA UPDATE ACCEPT
20200617135532201 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532201 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x0894b9 CMD=UI DATA
20200617135532201 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532201 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1757 MM(901700000015254/c83880f6) -> ROUTING AREA UPDATE COMPLETE
20200617135532201 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1762 GMM(gmm_fsm)[0x6120000039a0]{Registered.SUSPENDED}: Received Event E_GMM_COMMON_PROC_SUCCESS
20200617135532201 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1762 GMM(gmm_fsm)[0x6120000039a0]{Registered.SUSPENDED}: Event E_GMM_COMMON_PROC_SUCCESS not permitted
20200617135532201 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(f23e1395/c83880f6){ASSIGNED} LLGM Assign pre (ffffffff => c83880f6)
20200617135532201 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(ffffffff/c83880f6){ASSIGNED} LLGM Assign post (ffffffff => c83880f6)
20200617135532201 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1772 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_RA_UPDATE
20200617135532281 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532281 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x8c9e2a CMD=UI DATA
20200617135532281 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:865 TLLI=c83880f6 dropping UI, N(U=167) not in window V(URV(UR:171).
20200617135532282 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532282 DSNDCP <0012> /git/osmo-sgsn/src/sgsn/gprs_sndcp.c:398 TLLI=0xc83880f6 NSAPI=5: Input PDU 570 Segment 1 Length 83
20200617135532282 DSNDCP <0012> /git/osmo-sgsn/src/sgsn/gprs_sndcp.c:285 TLLI=0xc83880f6 NSAPI=5: Defragment output PDU 570 num_seg=1 tot_len=656
20200617135532282 DSNDCP <0012> /git/osmo-sgsn/src/sgsn/gprs_sndcp.c:302 Segment 0 missing
20200617135532307 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=471
20200617135532307 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/c83880f6) Paging MS in GMM state Registered.SUSPENDED
20200617135532322 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532322 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x89af0f CMD=UI DATA
20200617135532323 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532382 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532382 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xc32f9b CMD=UI DATA
20200617135532383 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532424 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532424 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xdc7e71 CMD=UI DATA
20200617135532425 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532455 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=86
20200617135532455 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/c83880f6) Paging MS in GMM state Registered.SUSPENDED
20200617135532484 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532484 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x8dddb9 CMD=UI DATA
20200617135532484 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532543 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532544 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x51c043 CMD=UI DATA
20200617135532544 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532581 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532581 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x1effca CMD=UI DATA
20200617135532581 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532624 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532624 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x48c525 CMD=UI DATA
20200617135532624 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532624 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xda771c53 Rx UPLINK-UNITDATA
20200617135532624 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x0894b9 CMD=UI DATA
20200617135532625 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532625 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1757 MM(901700000015256/da771c53) -> ROUTING AREA UPDATE COMPLETE
20200617135532625 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1762 GMM(gmm_fsm)[0x612000004120]{Registered.SUSPENDED}: Received Event E_GMM_COMMON_PROC_SUCCESS
20200617135532625 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1762 GMM(gmm_fsm)[0x612000004120]{Registered.SUSPENDED}: Event E_GMM_COMMON_PROC_SUCCESS not permitted
20200617135532625 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(cbb524a0/da771c53){ASSIGNED} LLGM Assign pre (ffffffff => da771c53)
20200617135532625 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(ffffffff/da771c53){ASSIGNED} LLGM Assign post (ffffffff => da771c53)
20200617135532625 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1772 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_RA_UPDATE
20200617135532701 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532701 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x561615 CMD=UI DATA
20200617135532701 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532701 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xda771c53 Rx UPLINK-UNITDATA
20200617135532701 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xfe94c6 CMD=UI DATA
20200617135532701 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532713 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200617135532713 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015256/da771c53) Paging MS in GMM state Registered.SUSPENDED
20200617135532724 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532724 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xe6971d CMD=UI DATA
20200617135532724 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532761 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532762 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xfb8545 CMD=UI DATA
20200617135532762 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532784 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xda771c53 Rx UPLINK-UNITDATA
20200617135532784 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xc46a77 CMD=UI DATA
20200617135532785 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532796 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200617135532796 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015256/da771c53) Paging MS in GMM state Registered.SUSPENDED
20200617135532821 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xc83880f6 Rx UPLINK-UNITDATA
20200617135532822 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x64beec CMD=UI DATA
20200617135532822 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2463700050)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532844 DNS <000f> /git/libosmocore/src/gb/gprs_ns.c:724 NSEI=1800 Tx NS ALIVE_ACK (NSVCI=1800)
20200617135532845 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:820 BSSGP BVCI=1800 Rx Flow Control BVC
20200617135532846 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xda771c53 Rx UPLINK-UNITDATA
20200617135532846 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x3ff146 CMD=UI DATA
20200617135532846 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2812806789)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617135532849 DNS <000f> /git/libosmocore/src/gb/gprs_ns.c:777 NSEI=1800 Timer expired in mode tns-test (30 seconds)
20200617135532849 DNS <000f> /git/libosmocore/src/gb/gprs_ns.c:711 NSEI=1800 Tx NS ALIVE (NSVCI=1800)
20200617135532849 DNS <000f> /git/libosmocore/src/gb/gprs_ns.c:749 NSEI=1800 Starting timer in mode tns-alive (3 seconds)
20200617135532849 DNS <000f> /git/libosmocore/src/gb/gprs_ns.c:1763 NSEI 1800 (NS-VCI=1800) setting state [ALIVE,UNBLOCKED,UNRESET] -> [ALIVE,UNBLOCKED,UNRESET]
20200617135532850 DNS <000f> /git/libosmocore/src/gb/gprs_ns.c:749 NSEI=1800 Starting timer in mode tns-test (30 seconds)
20200617135532858 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200617135532858 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015256/da771c53) Paging MS in GMM state Registered.SUSPENDED

So the patch looks wrong regarding which events to receive. I'll change it and check if it fixes the issue.

#13 Updated by pespin 17 days ago

  • Status changed from New to In Progress
  • Assignee changed from laforge to pespin

I submitted a new version of the patch and it's fixed now:

20200617141827917 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2591497299)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141827929 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200617141828305 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:447 BSSGP BVCI=0 TLLI=0xeb388c45 Rx SUSPEND
20200617141828306 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:2211 GMM(gmm_fsm)[0x6120000039a0]{Registered.NORMAL}: Received Event E_GMM_SUSPEND
20200617141828306 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:64 GMM(gmm_fsm)[0x6120000039a0]{Registered.NORMAL}: state_chg to Registered.SUSPENDED
20200617141828950 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=103
20200617141828950 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/eb388c45) Paging MS in GMM state Registered.SUSPENDED
20200617141829364 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617141829364 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/eb388c45) Paging MS in GMM state Registered.SUSPENDED
20200617141830207 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:447 BSSGP BVCI=0 TLLI=0xcdc83143 Rx SUSPEND
20200617141830207 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:2211 GMM(gmm_fsm)[0x612000004120]{Registered.NORMAL}: Received Event E_GMM_SUSPEND
20200617141830207 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:64 GMM(gmm_fsm)[0x612000004120]{Registered.NORMAL}: state_chg to Registered.SUSPENDED
20200617141830658 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617141830658 DMM <0002> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:664 MM(901700000015254/eb388c45) Paging MS in GMM state Registered.SUSPENDED
...
20200617141842797 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x2e5b75 CMD=UI DATA
20200617141842798 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(0)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141842798 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1560 MM(901700000015254/eb388c45) -> GMM RA UPDATE REQUEST type="RA updating" 
20200617141842798 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1099 GMM(gmm_fsm)[0x6120000039a0]{Registered.SUSPENDED}: Received Event E_GMM_COMMON_PROC_INIT_REQ
20200617141842798 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:76 GMM(gmm_fsm)[0x6120000039a0]{Registered.SUSPENDED}: state_chg to CommonProcedureInitiated
20200617141842798 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(ffffffff/eb388c45){ASSIGNED} LLGM Assign pre (eb388c45 => f412e175)
20200617141842798 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(eb388c45/f412e175){ASSIGNED} LLGM Assign post (eb388c45 => f412e175)
20200617141842798 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1430 MM(901700000015254/f412e175) <- ROUTING AREA UPDATE ACCEPT
20200617141842899 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xcdc83143 Rx UPLINK-UNITDATA
20200617141842899 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x202e43 CMD=UI DATA
20200617141842899 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2591497299)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141842899 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1560 MM(901700000015256/cdc83143) -> GMM RA UPDATE REQUEST type="RA updating" 
20200617141842899 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1099 GMM(gmm_fsm)[0x612000004120]{Registered.SUSPENDED}: Received Event E_GMM_COMMON_PROC_INIT_REQ
20200617141842899 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:76 GMM(gmm_fsm)[0x612000004120]{Registered.SUSPENDED}: state_chg to CommonProcedureInitiated
20200617141842899 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(ffffffff/cdc83143){ASSIGNED} LLGM Assign pre (cdc83143 => ff73cef7)
20200617141842899 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(cdc83143/ff73cef7){ASSIGNED} LLGM Assign post (cdc83143 => ff73cef7)
20200617141842899 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1430 MM(901700000015256/ff73cef7) <- ROUTING AREA UPDATE ACCEPT
20200617141843356 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xf412e175 Rx UPLINK-UNITDATA
20200617141843356 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x5e5fd5 CMD=UI DATA
20200617141843356 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(0)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141843356 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1757 MM(901700000015254/f412e175) -> ROUTING AREA UPDATE COMPLETE
20200617141843356 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1762 GMM(gmm_fsm)[0x6120000039a0]{CommonProcedureInitiated}: Received Event E_GMM_COMMON_PROC_SUCCESS
20200617141843356 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:46 GMM(gmm_fsm)[0x6120000039a0]{CommonProcedureInitiated}: state_chg to Registered.NORMAL
20200617141843357 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(eb388c45/f412e175){ASSIGNED} LLGM Assign pre (ffffffff => f412e175)
20200617141843357 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(ffffffff/f412e175){ASSIGNED} LLGM Assign post (ffffffff => f412e175)
20200617141843357 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1772 MM_STATE_Gb(0)[0x612000003ca0]{Ready}: Received Event E_MM_RA_UPDATE
20200617141843696 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xf412e175 Rx UPLINK-UNITDATA
20200617141843697 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x84483e CMD=UI DATA
20200617141843697 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:865 TLLI=f412e175 dropping UI, N(U=101) not in window V(URV(UR:102).
20200617141843697 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(0)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141843697 DSNDCP <0012> /git/osmo-sgsn/src/sgsn/gprs_sndcp.c:398 TLLI=0xf412e175 NSAPI=5: Input PDU 534 Segment 2 Length 420
20200617141843697 DSNDCP <0012> /git/osmo-sgsn/src/sgsn/gprs_sndcp.c:285 TLLI=0xf412e175 NSAPI=5: Defragment output PDU 534 num_seg=2 tot_len=1827
20200617141843697 DSNDCP <0012> /git/osmo-sgsn/src/sgsn/gprs_sndcp.c:302 Segment 0 missing
20200617141843776 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xff73cef7 Rx UPLINK-UNITDATA
20200617141843776 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=1 C   U GEA0 IOV-UI=0x000000 FCS=0x0894b9 CMD=UI DATA
20200617141843776 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2591497299)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141843777 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1757 MM(901700000015256/ff73cef7) -> ROUTING AREA UPDATE COMPLETE
20200617141843777 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1762 GMM(gmm_fsm)[0x612000004120]{CommonProcedureInitiated}: Received Event E_GMM_COMMON_PROC_SUCCESS
20200617141843777 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm_fsm.c:46 GMM(gmm_fsm)[0x612000004120]{CommonProcedureInitiated}: state_chg to Registered.NORMAL
20200617141843777 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1056 LLME(cdc83143/ff73cef7){ASSIGNED} LLGM Assign pre (ffffffff => ff73cef7)
20200617141843777 DLLC <0011> /git/osmo-sgsn/src/sgsn/gprs_llc.c:1102 LLME(ffffffff/ff73cef7){ASSIGNED} LLGM Assign post (ffffffff => ff73cef7)
20200617141843777 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gmm.c:1772 MM_STATE_Gb(2591497299)[0x612000004420]{Ready}: Received Event E_MM_RA_UPDATE
20200617141843862 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xf412e175 Rx UPLINK-UNITDATA
20200617141843862 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x259c5e CMD=UI DATA
20200617141843862 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(0)[0x612000003ca0]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141843862 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xff73cef7 Rx UPLINK-UNITDATA
20200617141843862 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0x804acd CMD=UI DATA
20200617141843862 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2591497299)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141843874 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015254, length=52
20200617141843874 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84
20200617141843937 DBSSGP <0010> /git/libosmocore/src/gb/gprs_bssgp.c:405 BSSGP TLLI=0xff73cef7 Rx UPLINK-UNITDATA
20200617141843937 DLLC <0011> /git/osmo-sgsn/src/gprs/gprs_llc_parse.c:78 LLC SAPI=3 C   U GEA0 IOV-UI=0x000000 FCS=0xeb62ec CMD=UI DATA
20200617141843937 DMM <0002> /git/osmo-sgsn/src/sgsn/gprs_gb.c:40 MM_STATE_Gb(2591497299)[0x612000004420]{Ready}: Received Event E_MM_PDU_RECEPTION
20200617141843949 DGPRS <000e> /git/osmo-sgsn/src/sgsn/sgsn_libgtp.c:638 GTP DATA IND from GGSN for 901700000015256, length=84

We may want to:
  • Add test for this scenario (SUSPEND + RAU + ICMP ping) in ttcn3-sgsn-test
  • Add test for scenario in ttcn3-pcu-tests: MS is attached but we receive a PS-PAGING (what shall we do here? probably not send a PAging Request Type 1 on CCCH...)

So keeping the ticket open to address those points above.

#14 Updated by pespin 17 days ago

  • Assignee changed from pespin to laforge

#15 Updated by laforge 17 days ago

I've just submitted some patches for the TTCN3 test suite, specifically in https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/18890

pespin: please take over and expand if you think more test cases are needed, and also similarly work on more SGSN fixes as needed.

#16 Updated by laforge 17 days ago

  • % Done changed from 20 to 40

#17 Updated by laforge 17 days ago

  • Assignee changed from laforge to pespin

#18 Updated by pespin 8 days ago

  • % Done changed from 40 to 80

The three tests passing after this patch is applied:
https://gerrit.osmocom.org/c/osmo-sgsn/+/19020 sgsn_libgtp: Avoid ps-paging MS on GMM Suspended state

#19 Updated by pespin 8 days ago

  • Status changed from In Progress to Feedback

Once merged the ticket can be closed.

#20 Updated by laforge 8 days ago

  • % Done changed from 80 to 100

patch merged.

#21 Updated by pespin 8 days ago

  • Status changed from Feedback to Resolved

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)