MC7750 missing SIM until ModemManager restart
Bowden, Brendan
bbowden at presidio.com
Wed Oct 10 17:47:25 UTC 2018
> -----Original Message-----
> From: ModemManager-devel <modemmanager-devel-
> bounces at lists.freedesktop.org> On Behalf Of Bowden, Brendan
> Sent: Wednesday, October 10, 2018 1:30 PM
> To: Aleksander Morgado <aleksander at aleksander.es>
> Cc: ModemManager (development) <modemmanager-
> devel at lists.freedesktop.org>
> Subject: RE: MC7750 missing SIM until ModemManager restart
>
> EXTERNAL EMAIL
>
>
>
> > -----Original Message-----
> > From: Aleksander Morgado <aleksander at aleksander.es>
> > Sent: Wednesday, October 10, 2018 3:41 AM
> > To: Bowden, Brendan <bbowden at presidio.com>
> > Cc: ModemManager (development) <modemmanager-
> > devel at lists.freedesktop.org>
> > Subject: Re: MC7750 missing SIM until ModemManager restart
> >
> > EXTERNAL EMAIL
> >
> >
> >
> > Hey,
> >
> > > Having an odd issue where ModemManager has trouble reading SIM
> > PIN status from Sierra MC7750 (Verizon US, LTE+CDMA, QMI interface)
> > modules after a modem reset.
> > >
> > >
> > > At first system boot, MM has no issue detecting the modem and
> > activating a connection. These are in mobile devices, so it's common to
> > lose signal and later need to reconnect when back in a coverage area.
> > These modems can be a little cranky, and sometimes at this point
> won't
> > build a data connection after repeated attempts (known Qualcomm-
> level
> > issue according to Sierra), so we have a separate process that watches
> for
> > that and issues a Reset() via the MM DBus interface. Reset() on these
> > does a "full power cycle", as if the modem was unplugged from USB
> and
> > plugged back in.
> > >
> > >
> > > When the device turns back on, during detection NM says it doesn't
> > have a SIM object:
> > >
> > > NetworkManager[6651]: <info> [1539101206.9778]
> > > modem-broadband[cdc-wdm1]: failed to retrieve SIM object: No
> SIM
> > > object available
> > >
> > >
> > > MM reports this:
> > >
> > > ModemManager[8643]: <warn> Couldn't load unlock retries:
> 'Couldn't
> > get unlock retries: QMI protocol error (3): 'Internal''
> > > ModemManager[8643]: <warn> couldn't load list of Own Numbers:
> > 'Couldn't get MSISDN: QMI protocol error (25): 'DeviceUnsupported''
> > >
> > >
> > > Looking into MM debug logs, it's failing the "UIM Get PIN Status"
> step,
> > the first time for IncorrectPin, then Internal QMI error for the rest of
> the
> > retries. The SIMs don't have a PIN we're aware of.
> > >
> > > <debug> [1539101547.534249] [mm-iface-modem.c:3902]
> > > load_current_capabilities_ready(): Setting EPS network as supported
> > <debug> [1539101547.538395] [mm-iface-modem.c:3928]
> > load_current_capabilities_ready(): Checking if multimode device has a
> > SIM...
> > > <debug> [1539101547.542528] [mm-broadband-modem-qmi.c:1845]
> > load_unlock_required_context_step(): loading unlock required
> (DMS)...
> > > [/dev/cdc-wdm1] sent message...
> > > <<<<<< RAW:
> > > <<<<<< length = 13
> > > <<<<<< data = 01:0C:00:00:02:01:00:02:00:2B:00:00:00
> > > [/dev/cdc-wdm1] sent generic request (translated)...
> > > <<<<<< QMUX:
> > > <<<<<< length = 12
> > > <<<<<< flags = 0x00
> > > <<<<<< service = "dms"
> > > <<<<<< client = 1
> > > <<<<<< QMI:
> > > <<<<<< flags = "none"
> > > <<<<<< transaction = 2
> > > <<<<<< tlv_length = 0
> > > <<<<<< message = "UIM Get PIN Status" (0x002B)
> > > [/dev/cdc-wdm1] received message...
> > > <<<<<< RAW:
> > > <<<<<< length = 20
> > > <<<<<< data =
> > 01:13:00:80:02:01:02:02:00:2B:00:07:00:02:04:00:01:00:0C:00
> > > [/dev/cdc-wdm1] received generic response (translated)...
> > > <<<<<< QMUX:
> > > <<<<<< length = 19
> > > <<<<<< flags = 0x80
> > > <<<<<< service = "dms"
> > > <<<<<< client = 1
> > > <<<<<< QMI:
> > > <<<<<< flags = "response"
> > > <<<<<< transaction = 2
> > > <<<<<< tlv_length = 7
> > > <<<<<< message = "UIM Get PIN Status" (0x002B)
> > > <<<<<< TLV:
> > > <<<<<< type = "Result" (0x02)
> > > <<<<<< length = 4
> > > <<<<<< value = 01:00:0C:00
> > > <<<<<< translated = FAILURE: IncorrectPin
> > > <debug> [1539101547.550223] [mm-iface-modem.c:268]
> > load_unlock_required_ready(): Couldn't check if unlock required:
> > 'Couldn't get PIN status: QMI protocol error (12): 'IncorrectPin''
> > >
> > > (removed retries 1-5 here, they're identical)
> > >
> > >
> > > <debug> [1539101558.280189] [mm-iface-modem.c:292]
> > > load_unlock_required_ready(): Retrying (6) unlock required check
> > <debug> [1539101560.270256] [mm-broadband-modem-qmi.c:1845]
> > load_unlock_required_context_step(): loading unlock required
> (DMS)...
> > > [/dev/cdc-wdm1] sent message...
> > > <<<<<< RAW:
> > > <<<<<< length = 13
> > > <<<<<< data = 01:0C:00:00:02:01:00:08:00:2B:00:00:00
> > > [/dev/cdc-wdm1] sent generic request (translated)...
> > > <<<<<< QMUX:
> > > <<<<<< length = 12
> > > <<<<<< flags = 0x00
> > > <<<<<< service = "dms"
> > > <<<<<< client = 1
> > > <<<<<< QMI:
> > > <<<<<< flags = "none"
> > > <<<<<< transaction = 8
> > > <<<<<< tlv_length = 0
> > > <<<<<< message = "UIM Get PIN Status" (0x002B)
> > > [/dev/cdc-wdm1] received message...
> > > <<<<<< RAW:
> > > <<<<<< length = 20
> > > <<<<<< data =
> > 01:13:00:80:02:01:02:08:00:2B:00:07:00:02:04:00:01:00:03:00
> > > [/dev/cdc-wdm1] received generic response (translated)...
> > > <<<<<< QMUX:
> > > <<<<<< length = 19
> > > <<<<<< flags = 0x80
> > > <<<<<< service = "dms"
> > > <<<<<< client = 1
> > > <<<<<< QMI:
> > > <<<<<< flags = "response"
> > > <<<<<< transaction = 8
> > > <<<<<< tlv_length = 7
> > > <<<<<< message = "UIM Get PIN Status" (0x002B)
> > > <<<<<< TLV:
> > > <<<<<< type = "Result" (0x02)
> > > <<<<<< length = 4
> > > <<<<<< value = 01:00:03:00
> > > <<<<<< translated = FAILURE: Internal
> > > <debug> [1539101560.278384] [mm-iface-modem.c:268]
> > load_unlock_required_ready(): Couldn't check if unlock required:
> > 'Couldn't get PIN status (retry): QMI protocol error (3): 'Internal''
> > > <debug> [1539101560.282222] [mm-iface-modem.c:3864]
> > > current_capabilities_internal_load_unlock_required_ready():
> > Multimode
> > > device without SIM, no 3GPP capabilities
> > >
> > >
> > >
> > > Running (what I think is) the equivalent status command via qmicli
> > directly, it looks like it works:
> > >
> > > [root at hostname ~]# qmicli -p -d /dev/cdc-wdm1 --dms-uim-get-
> pin-
> > status
> > > [/dev/cdc-wdm1] PIN status retrieved successfully [/dev/cdc-wdm1]
> > > PIN1:
> > > Status: disabled
> > > Verify: 3
> > > Unblock: 10
> > > [/dev/cdc-wdm1] PIN2:
> > > Status: enabled-not-verified
> > > Verify: 3
> > > Unblock: 10
> > >
> > >
> > > Here's the odd part - this only happens if the modem is reset while
> MM
> > is running. If I do a 'systemctl restart ModemManager' at this point,
> the
> > modem+SIM are detected right away, and all is well. That's my
> > workaround right now, but I'd rather not be restarting services if I can
> > help it: we have 2 modules in the system (second one is either a
> MC7700
> > or MC7354) and restarting MM disrupts the other data session. No
> > detection issues from either one of those models.
> > >
> > >
> > > We're using the RHEL7 delivered MM build, 1.6.10, with libqmi 1.18.0.
> > Both appear unmodified according to the RPM specfile, no odd
> patches,
> > etc.
> > >
> > >
> > > Any ideas where to look next? Thanks in advance!
> > >
> >
> > This could be a timing issue of some sort, it doesnt' make sense that
> you
> > get a different reply when manually running the "DMS UIM Get Pin
> > Status" message. My assumption here is that we may need more
> retries,
> > or more time between retries, or something like that, but it will be an
> ugly
> > hack anyway as it's replying "IncorrectPin" for a while, then "Internal"
> > error and then finally that the PIN is disabled. Very weird.
> >
> > Could you try to manually run --uim-get-card-status as well during your
> > tests? Trying to see whether that will give us any better indication of
> > whether the sim info is still being loaded or fully ready, before we
> query
> > pin status.
> >
> > --
> > Aleksander
> > https://aleksander.es
>
> When you suggested timing, I ran some scripted tests to start checking
> these immediately after device reset (with MM disabled). I haven't
> caught the IncorrectPin state myself yet, it must only happen a very short
> time after modem power-on, and I keep getting stuck in a QMI timeout
> condition that early in the cycle. I do start to get the Internal protocol
> error responses to dms-uim-get-pin-status, while uim-get-card-status
> says the SIM is 'absent':
>
> 2018-10-10 13:03:43 uim-get-card-status -----------------------------------------
> --------------
> [/dev/cdc-wdm1] Successfully got card status Provisioning applications:
> Primary GW: session doesn't exist
> Primary 1X: session doesn't exist
> Secondary GW: session doesn't exist
> Secondary 1X: session doesn't exist Card [0]:
> Card state: 'absent'
> UPIN state: 'not-initialized'
> UPIN retries: '0'
> UPUK retries: '0'
>
> 2018-10-10 13:03:43 dms-uim-get-pin-status ------------------------------------
> ----------------
> error: couldn't get PIN status: QMI protocol error (3): 'Internal'
>
> And the same response when I check every second thereafter. Exactly 15
> seconds later card state changes to "present" and I start getting real
> status:
>
> 2018-10-10 13:03:57 uim-get-card-status -----------------------------------------
> --------------
> [/dev/cdc-wdm1] Successfully got card status Provisioning applications:
> Primary GW: slot '0', application '0'
> Primary 1X: slot '0', application '2'
> Secondary GW: session doesn't exist
> Secondary 1X: session doesn't exist
> Card [0]:
> Card state: 'present'
> UPIN state: 'not-initialized'
> UPIN retries: '0'
> UPUK retries: '0'
> Application [0]:
> Application type: 'usim (2)'
> Application state: 'check-personalization-state'
> Application ID:
> A0:00:00:00:87:10:02:F3:10:FF:FF:89:08:00:00:FF
> Personalization state: 'ready'
> UPIN replaces PIN1: 'no'
> PIN1 state: 'disabled'
> PIN1 retries: '0'
> PUK1 retries: '0'
> PIN2 state: 'enabled-not-verified'
> PIN2 retries: '0'
> PUK2 retries: '0'
> Application [1]:
> Application type: 'unknown (0)'
> Application state: 'detected'
> Application ID:
> A0:00:00:00:87:10:04:F3:10:FF:FF:89:08:00:00:FF
> Personalization state: 'unknown'
> UPIN replaces PIN1: 'no'
> PIN1 state: 'not-initialized'
> PIN1 retries: '0'
> PUK1 retries: '0'
> PIN2 state: 'not-initialized'
> PIN2 retries: '0'
> PUK2 retries: '0'
> Application [2]:
> Application type: 'csim (4)'
> Application state: 'check-personalization-state'
> Application ID:
> A0:00:00:03:43:10:02:F3:10:FF:FF:89:02:00:00:FF
> Personalization state: 'ready'
> UPIN replaces PIN1: 'no'
> PIN1 state: 'disabled'
> PIN1 retries: '0'
> PUK1 retries: '0'
> PIN2 state: 'enabled-not-verified'
> PIN2 retries: '0'
> PUK2 retries: '0'
> Application [3]:
> Application type: 'unknown (0)'
> Application state: 'detected'
> Application ID:
> A0:00:00:00:63:50:4B:43:53:2D:31:35
> Personalization state: 'unknown'
> UPIN replaces PIN1: 'no'
> PIN1 state: 'not-initialized'
> PIN1 retries: '0'
> PUK1 retries: '0'
> PIN2 state: 'not-initialized'
> PIN2 retries: '0'
> PUK2 retries: '0'
> 2018-10-10 13:03:57 dms-uim-get-pin-status ------------------------------------
> ----------------
> [/dev/cdc-wdm1] PIN status retrieved successfully [/dev/cdc-wdm1]
> PIN1:
> Status: disabled
> Verify: 3
> Unblock: 10
> [/dev/cdc-wdm1] PIN2:
> Status: enabled-not-verified
> Verify: 3
> Unblock: 10
>
> Out of curiosity I ran the same test against a MC7354 in the same system
> and it starts responding to both commands immediately after the cdc-
> wdm device is available.
>
> Any way to have MM delay its initialization -- either by detecting "Absent"
> and not-initialized SIM, or just waiting 15 seconds? Or increase number of
> retries so it'll keep trying a while longer until it works?
>
> As a stopgap, is there a way to externally trigger MM to re-initialize a
> device when we detect it's stuck (via DBus maybe?) without power cycling
> the modem?
>
> -- Brendan
>
>
One more test - I ran MM in debug mode and suspended the process for 5 seconds after a couple retries had run through. That was enough to let the 5th or 6th retry complete successfully and the modem detected properly afterwards.
-- Brendan
This message w/attachments (message) is intended solely for the use of the intended recipient(s) and may contain information that is privileged, confidential or proprietary. If you are not an intended recipient, please notify the sender, and then please delete and destroy all copies and attachments. Please be advised that any review or dissemination of, or the taking of any action in reliance on, the information contained in or attached to this message is prohibited.
More information about the ModemManager-devel
mailing list