MM support for access technology change
Jose, Shijo
Shijo.Jose at hughes.com
Thu Jun 21 05:54:16 UTC 2018
Hello,
I have ModemManager version 1.6.4 running on Yocto Linux and I am using it to communicate with a Telit LE910 V2 over MBIM.
Rarely, when the modem is connected to the network (default bearer is connected and I can pass data), I observe a change in access technology in MM logs (from LTE or UMTS/HSDPA) and the following sequence of events occur -
Bearer disconnection -> Registration state change to unknown -> Attached to UMTS network -> Registration state change to home
After this sequence, the bearer status on MM shows that it is still disconnected and if I attempt to establish the bearer again using simple connect at this point, MM fails to connect.
Basically I want to re-establish packet service again after a change in access technology and I am not sure if the problem lies with the modem or MM.
So my questions is, does MM seamlessly support bringing the packet bearer back up after an access tech change or if not what steps need to be taken in order to do so?
Please find MM logs snippets below.
Thanks,
Shijo
--------------------------------------------------------
Bearer disconnection:
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 80
>>>>>> data = 07:00:00:80:50:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0C:00:00:00:24:00:00:00:00:00:00:00:03:00:00:00:00:00:00:00:01:00:00:00:7E:5E:2A:7E:4E:6F:72:72:73:6B:65:6E:7E:5E:2A:7E:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 80
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'connect' (0x0000000c)
<debug> [1529483790.515973] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2249] device_notification_cb(): Received notification (service 'basic-connect', command 'connect')
<debug> [1529483790.516049] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2006] basic_connect_notification_connect(): Session ID '0' was deactivated.
<debug> [1529483790.516072] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:1969] bearer_list_report_disconnected_status(): Bearer '/org/freedesktop/ModemManager1/Bearer/0' was disconnected.
<debug> [1529483790.516101] [../../ModemManager-1.6.4/src/mm-port.c:95] mm_port_set_connected(): (wwan0): port now disconnected
<info> [1529483790.516181] [../../ModemManager-1.6.4/src/mm-iface-modem.c:1431] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connected -> registered)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 72
>>>>>> data = 07:00:00:80:48:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0A:00:00:00:1C:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:80:F0:FA:02:00:00:00:00:80:D1:F0:08:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 72
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'packet-service' (0x0000000a)
<debug> [1529483790.616677] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2249] device_notification_cb(): Received notification (service 'basic-connect', command 'packet-service')
<debug> [1529483790.616706] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2064] basic_connect_notification_packet_service(): Packet service state: 'attaching', data class: '(null)'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 92
>>>>>> data = 07:00:00:80:5C:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:09:00:00:00:30:00:00:00:00:00:00:00:01:00:00:00:01:00:00:00:20:00:00:00:01:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:02:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 92
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'register-state' (0x00000009)
<debug> [1529483790.716820] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2249] device_notification_cb(): Received notification (service 'basic-connect', command 'register-state')
<info> [1529483790.716912] [../../ModemManager-1.6.4/src/mm-iface-modem-3gpp.c:1186] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (home -> unknown)
<debug> [1529483790.717099] [../../ModemManager-1.6.4/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '0', MNC: '0', Location area code: '0', Cell ID: '0')
<debug> [1529483790.717251] [../../ModemManager-1.6.4/src/mm-base-bearer.c:373] modem_3gpp_registration_state_changed(): Bearer not allowed to connect, not registered in 3GPP network
<debug> [1529483790.717355] [../../ModemManager-1.6.4/src/mm-iface-modem.c:933] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (lte -> unknown)
Change in access tech
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 72
>>>>>> data = 07:00:00:80:48:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0A:00:00:00:1C:00:00:00:00:00:00:00:02:00:00:00:04:00:00:00:00:DC:05:00:00:00:00:00:00:DC:05:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 72
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'packet-service' (0x0000000a)
<debug> [1529483792.789721] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2249] device_notification_cb(): Received notification (service 'basic-connect', command 'packet-service')
<debug> [1529483792.789751] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2064] basic_connect_notification_packet_service(): Packet service state: 'attached', data class: 'umts'
Change in registration state and access tech
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 120
>>>>>> data = 07:00:00:80:78:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:09:00:00:00:4C:00:00:00:FF:00:00:00:03:00:00:00:01:00:00:00:04:00:00:00:01:00:00:00:30:00:00:00:0C:00:00:00:3C:00:00:00:10:00:00:00:00:00:00:00:00:00:00:00:02:00:00:00:33:00:31:00:30:00:32:00:36:00:30:00:54:00:2D:00:4D:00:6F:00:62:00:69:00:6C:00:65:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 120
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'register-state' (0x00000009)
<debug> [1529483792.890746] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2249] device_notification_cb(): Received notification (service 'basic-connect', command 'register-state')
<info> [1529483792.890843] [../../ModemManager-1.6.4/src/mm-iface-modem-3gpp.c:1171] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> registering)
<debug> [1529483792.891036] [../../ModemManager-1.6.4/src/mm-iface-modem.c:933] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown -> umts)
<debug> [1529483792.891238] [../../ModemManager-1.6.4/src/mm-iface-modem-location.c:297] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '310', MNC: '260', Location area code: '0', Cell ID: '0')
<info> [1529483792.892569] [../../ModemManager-1.6.4/src/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)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 72
>>>>>> data = 07:00:00:80:48:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0A:00:00:00:1C:00:00:00:00:00:00:00:02:00:00:00:18:00:00:00:A0:F9:56:00:00:00:00:00:00:97:49:01:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 72
>>>>>> type = indicate-status (0x80000007)
>>>>>> transaction = 0
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'packet-service' (0x0000000a)
<debug> [1529483792.993112] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2249] device_notification_cb(): Received notification (service 'basic-connect', command 'packet-service')
<debug> [1529483792.993151] [../../ModemManager-1.6.4/src/mm-broadband-modem-mbim.c:2064] basic_connect_notification_packet_service(): Packet service state: 'attached', data class: 'hsdpa, hsupa'
<debug> [1529483792.993355] [../../ModemManager-1.6.4/src/mm-iface-modem.c:933] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (umts -> hsdpa, hsupa)
Attempt to establish default bearer using simple connect API (libmm):
<info> [1529483793.371496] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:641] connect_auth_ready(): Simple connect started...
<debug> [1529483793.371561] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:651] connect_auth_ready(): PIN: unspecified
<debug> [1529483793.371576] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:653] connect_auth_ready(): Operator ID: unspecified
<debug> [1529483793.371590] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:655] connect_auth_ready(): Allowed roaming: yes
<debug> [1529483793.371605] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:657] connect_auth_ready(): APN: 10614.mcs
<debug> [1529483793.371643] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:665] connect_auth_ready(): IP family: unspecified
<debug> [1529483793.371660] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:673] connect_auth_ready(): Allowed authentication: unspecified
<debug> [1529483793.371675] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:675] connect_auth_ready(): User: unspecified
<debug> [1529483793.371689] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:677] connect_auth_ready(): Password: unspecified
<debug> [1529483793.371702] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:679] connect_auth_ready(): Number: unspecified
<info> [1529483793.371715] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:469] connection_step(): Simple connect state (4/8): Wait to get fully enabled
<info> [1529483793.371942] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:478] connection_step(): Simple connect state (5/8): Register
<debug> [1529483793.372034] [../../ModemManager-1.6.4/src/mm-iface-modem-3gpp.c:400] mm_iface_modem_3gpp_register_in_network(): Already registered in network '310260', automatic registration not launched...
<info> [1529483793.372134] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:501] connection_step(): Simple connect state (6/8): Bearer
<debug> [1529483793.372189] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:574] connection_step(): Using already existing bearer at '/org/freedesktop/ModemManager1/Bearer/0'...
<info> [1529483793.372206] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:583] connection_step(): Simple connect state (7/8): Connect
<debug> [1529483793.372245] [../../ModemManager-1.6.4/src/mm-base-bearer.c:703] mm_base_bearer_connect(): Connecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info> [1529483793.372324] [../../ModemManager-1.6.4/src/mm-iface-modem.c:1431] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
<debug> [1529483793.373287] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:1026] _connect(): Launching connection with data port (net/wwan0)
<debug> [1529483793.373368] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:785] connect_context_step(): Activating packet service...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<< length = 52
<<<<<< data = 03:00:00:00:34:00:00:00:F3:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0A:00:00:00:01:00:00:00:04:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<< length = 52
<<<<<< type = command (0x00000003)
<<<<<< transaction = 243
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<< cid = 'packet-service' (0x0000000a)
<<<<<< type = 'set' (0x00000001
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 76
>>>>>> data = 03:00:00:80:4C:00:00:00:F3:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0A:00:00:00:00:00:00:00:1C:00:00:00:00:00:00:00:02:00:00:00:18:00:00:00:A0:F9:56:00:00:00:00:00:00:97:49:01:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 76
>>>>>> type = command-done (0x80000003)
>>>>>> transaction = 243
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> status error = 'None' (0x00000000)
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'packet-service' (0x0000000a)
<debug> [1529483793.391728] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:724] packet_service_set_ready(): Packet service update:
<debug> [1529483793.391748] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:725] packet_service_set_ready(): state: 'attached'
<debug> [1529483793.391761] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:726] packet_service_set_ready(): data class: 'hsdpa, hsupa'
<debug> [1529483793.391773] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:727] packet_service_set_ready(): uplink: '5700000' bps
<debug> [1529483793.391786] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:728] packet_service_set_ready(): downlink: '21600000' bps
<debug> [1529483793.391802] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:806] connect_context_step(): Listing provisioned contexts...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<< length = 48
<<<<<< data = 03:00:00:00:30:00:00:00:F4:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0D:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<< length = 48
<<<<<< type = command (0x00000003)
<<<<<< transaction = 244
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<< cid = 'provisioned-contexts' (0x0000000d)
<<<<<< type = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 52
>>>>>> data = 03:00:00:80:34:00:00:00:F4:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0D:00:00:00:00:00:00:00:04:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 52
>>>>>> type = command-done (0x80000003)
>>>>>> transaction = 244
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> status error = 'None' (0x00000000)
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'provisioned-contexts' (0x0000000d)
<debug> [1529483793.396261] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:659] provisioned_contexts_query_ready(): Provisioned contexts found (0):
<debug> [1529483793.396297] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:870] connect_context_step(): No specific IP family requested, defaulting to ipv4
<debug> [1529483793.396313] [../../ModemManager-1.6.4/src/mm-bearer-mbim.c:901] connect_context_step(): Launching ipv4 connection with APN '10614.mcs'...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<< length = 128
<<<<<< data = 03:00:00:00:80:00:00:00:F5:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0C:00:00:00:01:00:00:00:50:00:00:00:00:00:00:00:01:00:00:00:3C:00:00:00:12:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:01:00:00:00:7E:5E:2A:7E:4E:6F:72:72:73:6B:65:6E:7E:5E:2A:7E:31:00:30:00:36:00:31:00:34:00:2E:00:6D:00:63:00:73:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<< length = 128
<<<<<< type = command (0x00000003)
<<<<<< transaction = 245
<<<<<< Fragment header:
<<<<<< total = 1
<<<<<< current = 0
<<<<<< Contents:
<<<<<< service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<< cid = 'connect' (0x0000000c)
<<<<<< type = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>> length = 48
>>>>>> data = 03:00:00:80:30:00:00:00:F5:00:00:00:01:00:00:00:00:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:0C:00:00:00:02:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>> length = 48
>>>>>> type = command-done (0x80000003)
>>>>>> transaction = 245
>>>>>> Fragment header:
>>>>>> total = 1
>>>>>> current = 0
>>>>>> Contents:
>>>>>> status error = 'Failure' (0x00000002)
>>>>>> service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>> cid = 'connect' (0x0000000c)
<debug> [1529483793.402516] [../../ModemManager-1.6.4/src/mm-base-bearer.c:578] connect_ready(): Couldn't connect bearer '/org/freedesktop/ModemManager1/Bearer/0': 'Unknown error (135500720)'
<info> [1529483793.402632] [../../ModemManager-1.6.4/src/mm-iface-modem.c:1431] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
<debug> [1529483793.404205] [../../ModemManager-1.6.4/src/mm-iface-modem-simple.c:221] connect_bearer_ready(): Couldn't connect bearer: 'Unknown error (135500720)'
2018-06-20T08:36:33.405904+00:00 ltesurfer07 lim: [Error:lim_mm.c:408] lim_mm_simple_connect ERROR: failed to connect - GDBus.Error:org.freedesktop.ModemManager1.Error.MobileEquipment.GprsUnknown: Unknown error (135500720)(148)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20180621/814f6a77/attachment-0001.html>
More information about the ModemManager-devel
mailing list