Sierra Wireless MC7354 remains in Registered - RRC Idle indefinitely on LTE mode

Dan Williams dcbw at redhat.com
Fri Apr 29 15:38:41 UTC 2016


On Fri, 2016-04-29 at 17:35 +0200, Diego López wrote:
> Hi Dan,
> 
> Thank you for the information, it helped a lot for approaching the
> problem.
> 
> I've been making more tests but sending traffic doesn't wake up the
> modem.
> 
> I'm going to continue working on it because I suspect that my MMC
> has 
> EMM states are wrong implemented (I see my UE deregistered on my MME 
> when this happens) .
> 
> UE should be transition to ECM connected when:
> 
> * There is new traffic
> * On a Tracking Area Update (TAU) request.
> 
> I just want to confirm, Modem Manager has nothing to do with wake up
>> modem that remains in RRC-Idle indefinitely?

Correct.  MM relies on the UE/modem to correctly report its state.  MM
doesn't have any way of triggering a state change here without drastic
operations like a network scan or tearing down the bearer and
reconnecting it.  But unfortunately, the modem hasn't told MM that the
connection has dropped (because it doesn't report disconnection and it
still reports 'registered' and that packet bearer status is 'attached')
so MM has no idea.  This does really seem like a modem firmware or
network-side issue to me.

Dan

> Diego
> 
> > 
> > On Tue, 2016-04-26 at 17:27 +0200, Diego López wrote:
> > > 
> > > Hi,
> > > 
> > > I'm still working with Sierra Wireless MC7354 modem, this time
> > > with
> > > only
> > > LTE connection. My tests are made by using a signal attenuator
> > > with
> > > only
> > > one cell.
> > > 
> > > Bringing the modem al low signal levels I discovered two
> > > different
> > > cases:
> > > 
> > > * Case 1 - High signal - low signal - high signal (slowly) OK:
> > > 
> > > Modem state machine transist correctly
> > > (connected->disconnecting->enabled->searching->registered-
> > > > 
> > > > connecting->connected)
> > > * Case 2 - High signal - low signal - high signal (slowly)
> > > FAILURE:
> > > 
> > > This test case attempts to simulate something similar to the
> > > entrance/exit of a tunnel.
> > > 
> > > ModemManager state machine doesn't transist, it remains connected
> > > and
> > > the bearer doesn't disconnect. Reset MM service doesn't recover
> > > connection, only reset modem works.
> > MM follows the modem's idea of whether the bearer is disconnected
> > or
> > not.  I'll bet in the first case, you got status indications that
> > the
> > bearer was detached, but in the second case you didn't because the
> > firmware doesn't think the bearer is destroyed.
> > 
> > > 
> > > But querying Modem by AT!GSTATUS? command, we can see that it is
> > > on
> > > RRC
> > > Idle indefinitely:
> > EMM-Registered & RRC-Idle means network resources are allocated for
> > the
> > bearer, but not all radio resources are allocated.  If you try to
> > send
> > traffic does that wake up the modem?  Looking at some documentation
> > it
> > seems in the RRC Idle state the modem is waiting for something to
> > happen before it will ask the network to re-allocate downlink
> > resources
> > for actual communication.  Supposedly the uplink resources are
> > still
> > allocated and available to the modem (hence why it is still
> > Registered
> > & Attached), but the modem doesn't think it has anything to do.
> > 
> > If IP data doesn't work try sending an SMS; does that wake it
> > up?  If
> > not, do you see any indications/status from the modem via QMI that
> > the
> > bearer has disconnected?  They'd come from the NAS or WDS services.
> > 
> > Dan
> > 
> > > 
> > > !GSTATUS:
> > > Current Time:  1518        Temperature: 40
> > > Bootup Time:   0        Mode:        ONLINE
> > > System mode:   LTE            PS state:    Attached
> > > LTE band:      B13            LTE bw:      5 MHz
> > > LTE Rx chan:   5230        LTE Tx chan: 23230
> > > EMM state:     Registered         No Cell
> > > RRC state:     RRC Idle
> > > IMS reg state: No Srv
> > > 
> > > RSSI (dBm):    -87        Tx Power:    0
> > > RSRP (dBm):    -106        TAC:         0001 (1)
> > > RSRQ (dB):     -6        Cell ID:     00000100 (256)
> > > SINR (dB):     19.2
> > > 
> > > MM log between RRC connected and RRC Idle states:
> > > 
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message
> > > (translated)...
> > >   >>>>>> QMUX:
> > >   >>>>>>   length  = 31
> > >   >>>>>>   flags   = 0x80
> > >   >>>>>>   service = "nas"
> > >   >>>>>>   client  = 2
> > >   >>>>>> QMI:
> > >   >>>>>>   flags       = "response"
> > >   >>>>>>   transaction = 14
> > >   >>>>>>   tlv_length  = 19
> > >   >>>>>>   message     = "Get Signal Strength" (0x0020)
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Result" (0x02)
> > >   >>>>>>   length     = 4
> > >   >>>>>>   value      = 00:00:00:00
> > >   >>>>>>   translated = SUCCESS
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Signal Strength" (0x01)
> > >   >>>>>>   length     = 2
> > >   >>>>>>   value      = 9E:08
> > >   >>>>>>   translated = [ strength = '-98' radio_interface =
> > > 'lte' ]
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Strength List" (0x10)
> > >   >>>>>>   length     = 4
> > >   >>>>>>   value      = 01:00:83:02
> > >   >>>>>>   translated = { [0] = '[ strength = '-125'
> > > radio_interface
> > > =
> > > 'cdma-1xevdo' ] '}
> > > ModemManager[11185]: <debug> [1461671245.821746]
> > > [mm-broadband-modem-qmi.c:2841]
> > > signal_strength_get_quality_and_access_tech(): Signal strength
> > > (lte):
> > > -98 dBm
> > > ModemManager[11185]: <debug> [1461671245.821772]
> > > [mm-broadband-modem-qmi.c:2860]
> > > signal_strength_get_quality_and_access_tech(): Signal strength
> > > (cdma-1xevdo): -125 dBm
> > > ModemManager[11185]: <debug> [1461671245.821794]
> > > [mm-broadband-modem-qmi.c:2874]
> > > signal_strength_get_quality_and_access_tech(): Signal strength:
> > > -98
> > > dBm
> > > --> 25%
> > > ModemManager[11185]: <debug> [1461671245.821866] [mm-iface-
> > > modem.c:1204]
> > > update_signal_quality(): Modem
> > > /org/freedesktop/ModemManager1/Modem/0:
> > > signal quality updated (25)
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message...
> > >   >>>>>> RAW:
> > >   >>>>>>   length = 42
> > >   >>>>>>   data   =
> > > 01:29:00:80:01:09:02:05:00:24:00:1D:00:02:04:00:00:00:00:00:1A:08
> > > :00:
> > > D8:09:00:00:00:00:00:00:19:08:00:E1:18:00:00:00:00:00:00
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message
> > > (translated)...
> > >   >>>>>> QMUX:
> > >   >>>>>>   length  = 41
> > >   >>>>>>   flags   = 0x80
> > >   >>>>>>   service = "wds"
> > >   >>>>>>   client  = 9
> > >   >>>>>> QMI:
> > >   >>>>>>   flags       = "response"
> > >   >>>>>>   transaction = 5
> > >   >>>>>>   tlv_length  = 29
> > >   >>>>>>   message     = "Get Packet Statistics" (0x0024)
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Result" (0x02)
> > >   >>>>>>   length     = 4
> > >   >>>>>>   value      = 00:00:00:00
> > >   >>>>>>   translated = SUCCESS
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Rx Bytes Ok" (0x1a)
> > >   >>>>>>   length     = 8
> > >   >>>>>>   value      = D8:09:00:00:00:00:00:00
> > >   >>>>>>   translated = 2520
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Tx Bytes Ok" (0x19)
> > >   >>>>>>   length     = 8
> > >   >>>>>>   value      = E1:18:00:00:00:00:00:00
> > >   >>>>>>   translated = 6369
> > > ModemManager[11185]: <debug> [1461671250.815327] [mm-port-
> > > serial.c:1288]
> > > mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
> > > ModemManager[11185]: <debug> [1461671250.815749]
> > > [mm-port-serial-at.c:459] debug_log(): (ttyUSB2): -->
> > > 'AT!GSTATUS?<CR>'
> > > ModemManager[11185]: <debug> [1461671250.932135]
> > > [mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <--
> > > '<CR><LF>!GSTATUS:
> > > <CR><LF>Current Time: 1506\9\9Temperature: 40<CR><LF>Bootup Time:
> > > 0\9\9Mode:        ONLINE         <CR><LF>System mode:
> > > LTE        \9PS
> > > state:    Attached     <CR><LF>LTE band:      B13    \9\9LTE
> > > bw:      5
> > > MHz   <CR><LF>LTE Rx chan:   5230\9\9LTE Tx chan:
> > > 23230<CR><LF>EMM
> > > state:     Registered     \9Normal Service <CR><LF>RRC
> > > state:     RRC
> > > Connected  <CR><LF>IMS reg state: No Srv \9\9<CR><LF><CR><LF>RSSI
> > > (dBm):    -98\9\9Tx Power:    0<CR><LF>RSRP (dBm):    -
> > > 126\9\9TAC:
> > > 0001
> > > (1)<CR><LF>RSRQ (dB):     -9\9\9Cell ID: 00000100
> > > (256)<CR><LF>SINR
> > > (dB): 0.2<CR><LF><CR><LF><CR><LF>OK<CR><LF>'
> > > ModemManager[11185]: <debug> [1461671250.932764] [mm-port-
> > > serial.c:1345]
> > > _close_internal(): (ttyUSB2) device open count is 1 (close)
> > > ModemManager[11185]: <debug> [1461671256.942383] [mm-port-
> > > serial.c:1288]
> > > mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
> > > ModemManager[11185]: <debug> [1461671256.943353]
> > > [mm-port-serial-at.c:459] debug_log(): (ttyUSB2): -->
> > > 'AT!GSTATUS?<CR>'
> > > ModemManager[11185]: <debug> [1461671257.061151]
> > > [mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <--
> > > '<CR><LF>!GSTATUS:
> > > <CR><LF>Current Time: 1512\9\9Temperature: 40<CR><LF>Bootup Time:
> > > 0\9\9Mode:        ONLINE         <CR><LF>System mode:
> > > LTE        \9PS
> > > state:    Attached     <CR><LF>LTE band:      B13    \9\9LTE
> > > bw:      5
> > > MHz   <CR><LF>LTE Rx chan:   5230\9\9LTE Tx chan:
> > > 23230<CR><LF>EMM
> > > state:     Registered     \9Normal Service <CR><LF>RRC
> > > state:     RRC
> > > Connected  <CR><LF>IMS reg state: No Srv \9\9<CR><LF><CR><LF>RSSI
> > > (dBm):    -98\9\9Tx Power:    0<CR><LF>RSRP (dBm):    -
> > > 122\9\9TAC:
> > > 0001
> > > (1)<CR><LF>RSRQ (dB):     -14\9\9Cell ID: 00000100
> > > (256)<CR><LF>SINR
> > > (dB): 2.6<CR><LF><CR><LF><CR><LF>OK<CR><LF>'
> > > ModemManager[11185]: <debug> [1461671257.061991] [mm-port-
> > > serial.c:1345]
> > > _close_internal(): (ttyUSB2) device open count is 1 (close)
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message...
> > >   >>>>>> RAW:
> > >   >>>>>>   length = 50
> > >   >>>>>>   data   =
> > > 01:31:00:80:03:02:04:00:00:24:00:25:00:29:05:00:A8:01:A8:01:01:12
> > > :0C:
> > > 00:A8:01:A8:01:07:34:32:34:2D:34:32:34:11:02:00:01:0B:01:06:00:01
> > > :01:
> > > 01:02:01:08
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message
> > > (translated)...
> > >   >>>>>> QMUX:
> > >   >>>>>>   length  = 49
> > >   >>>>>>   flags   = 0x80
> > >   >>>>>>   service = "nas"
> > >   >>>>>>   client  = 2
> > >   >>>>>> QMI:
> > >   >>>>>>   flags       = "indication"
> > >   >>>>>>   transaction = 0
> > >   >>>>>>   tlv_length  = 37
> > >   >>>>>>   message     = "Serving System" (0x0024)
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "MNC PCS Digit Include Status" (0x29)
> > >   >>>>>>   length     = 5
> > >   >>>>>>   value      = A8:01:A8:01:01
> > >   >>>>>>   translated = [ mcc = '424' mnc = '424'
> > > includes_pcs_digit
> > > =
> > > 'yes' ]
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Current PLMN" (0x12)
> > >   >>>>>>   length     = 12
> > >   >>>>>>   value      = A8:01:A8:01:07:34:32:34:2D:34:32:34
> > >   >>>>>>   translated = [ mcc = '424' mnc = '424' description =
> > > '424-
> > > 424' ]
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Data Service Capability" (0x11)
> > >   >>>>>>   length     = 2
> > >   >>>>>>   value      = 01:0B
> > >   >>>>>>   translated = { [0] = 'lte '}
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Serving System" (0x01)
> > >   >>>>>>   length     = 6
> > >   >>>>>>   value      = 01:01:01:02:01:08
> > >   >>>>>>   translated = [ registration_state = 'registered'
> > > cs_attach_state = 'attached' ps_attach_state = 'attached'
> > > selected_network = '3gpp' radio_interfaces = '{ [0] = 'lte '}' ]
> > > ModemManager[11185]: <debug> [1461671260.670856]
> > > [mm-broadband-modem-qmi.c:4607]
> > > common_process_serving_system_3gpp():
> > > Processing 3GPP info...
> > > ModemManager[11185]: <info>  [1461671260.671082]
> > > [mm-iface-modem-3gpp.c:1171] update_registration_state(): Modem
> > > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
> > > changed
> > > (roaming -> registering)
> > > ModemManager[11185]: <info>  [1461671260.671336]
> > > [mm-iface-modem-3gpp.c:1096]
> > > update_registration_reload_current_registration_info_ready():
> > > Modem
> > > /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state
> > > changed
> > > (registering -> home)
> > > ModemManager[11185]: <debug> [1461671263.072413] [mm-port-
> > > serial.c:1288]
> > > mm_port_serial_open(): (ttyUSB2) device open count is 2 (open)
> > > ModemManager[11185]: <debug> [1461671263.072658]
> > > [mm-port-serial-at.c:459] debug_log(): (ttyUSB2): -->
> > > 'AT!GSTATUS?<CR>'
> > > ModemManager[11185]: <debug> [1461671263.092805]
> > > [mm-port-serial-at.c:459] debug_log(): (ttyUSB2): <--
> > > '<CR><LF>!GSTATUS:
> > > <CR><LF>Current Time: 1518\9\9Temperature: 40<CR><LF>Bootup Time:
> > > 0\9\9Mode:        ONLINE         <CR><LF>System mode:
> > > LTE        \9PS
> > > state:    Attached     <CR><LF>LTE band:      B13    \9\9LTE
> > > bw:      5
> > > MHz   <CR><LF>LTE Rx chan:   5230\9\9LTE Tx chan:
> > > 23230<CR><LF>EMM
> > > state:     Registered     \9No Cell        <CR><LF>RRC
> > > state:     RRC
> > > Idle       <CR><LF>IMS reg state: No Srv \9\9<CR><LF><CR><LF>RSSI
> > > (dBm):    -87\9\9Tx Power:    0<CR><LF>RSRP (dBm):    -
> > > 106\9\9TAC:
> > > 0001
> > > (1)<CR><LF>RSRQ (dB):     -6\9\9Cell ID: 00000100
> > > (256)<CR><LF>SINR
> > > (dB): 19.2<CR><LF><CR><LF><CR><LF>OK<CR><LF>'
> > > ModemManager[11185]: <debug> [1461671263.093076] [mm-port-
> > > serial.c:1345]
> > > _close_internal(): (ttyUSB2) device open count is 1 (close)
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message...
> > >   >>>>>> RAW:
> > >   >>>>>>   length = 18
> > >   >>>>>>   data   =
> > > 01:11:00:80:03:02:04:00:00:02:00:05:00:10:02:00:B5:08
> > > ModemManager[11185]: [/dev/cdc-wdm0] Received message
> > > (translated)...
> > >   >>>>>> QMUX:
> > >   >>>>>>   length  = 17
> > >   >>>>>>   flags   = 0x80
> > >   >>>>>>   service = "nas"
> > >   >>>>>>   client  = 2
> > >   >>>>>> QMI:
> > >   >>>>>>   flags       = "indication"
> > >   >>>>>>   transaction = 0
> > >   >>>>>>   tlv_length  = 5
> > >   >>>>>>   message     = "Event Report" (0x0002)
> > >   >>>>>> TLV:
> > >   >>>>>>   type       = "Signal Strength" (0x10)
> > >   >>>>>>   length     = 2
> > >   >>>>>>   value      = B5:08
> > >   >>>>>>   translated = [ strength = '-75' radio_interface =
> > > 'lte' ]
> > > ModemManager[11185]: <debug> [1461671266.334031]
> > > [mm-broadband-modem-qmi.c:7030] event_report_indication_cb():
> > > Signal
> > > strength indication (lte): -75 dBm --> 62%
> > > ModemManager[11185]: <debug> [1461671266.334135] [mm-iface-
> > > modem.c:1204]
> > > update_signal_quality(): Modem
> > > /org/freedesktop/ModemManager1/Modem/0:
> > > signal quality updated (62)
> > > 
> > > Diego López
> > > Teltronic
> > > _______________________________________________
> > > ModemManager-devel mailing list
> > > ModemManager-devel at lists.freedesktop.org
> > > https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
> _______________________________________________
> ModemManager-devel mailing list
> ModemManager-devel at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel


More information about the ModemManager-devel mailing list