Huawei me906s-158

Andreas Fett andreas.fett at secunet.com
Thu Mar 10 14:40:36 UTC 2016


Hi Bjørn,


On 08/03/16 19:05, Bjørn Mork wrote:
> But one simple change to test is this patch:
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/drivers/net/usb/cdc_ncm.c?id=48906f62c96cc2cd35753e59310cb70eb08cc6a5
> 
> Which will be in v4.5, and hopefully asserted stable releases too soon, if
> you don't want to do your own patching.  FWIW, this should not make any
> difference at all.  And I don't think it will. But I have been surprised
> before...

I had (somewhat limited) success.

Applying the patch to 4.4.2 did not help... So I build a 4.5-rc7+ kernel
directly from Linus' tree (I checked that it contained your patch).

I also placed the configuration switch in an udev rule that triggers as
soon as the xhci module is loaded and the devices on that bus appear.

In previous attempts I had a rule which disabled runtime power
management for all devices. I had to disable that one too.

I still have to load the mbim_module manually and sometimes I'm able to
"talk" to it. I have no clue which factors lead to success or failure here.

Attached you will find logs of an attempt where I could use mbimcli
and afterwards started the modem manager and did a successful connect.

Unfortunately when I configure the wwan0 interface with ip and routes
from the bearer I'm still not able to do a successful ping...

(Btw. for people "googeling" this. This modem is one of the options for
a lenovo Thinkpad x260).

Andreas



-------------- next part --------------

/org/freedesktop/ModemManager1/Modem/0 (device id '591fe4920e83854b04755c2f30d06bd99a8b1948')
  -------------------------
  Hardware |   manufacturer: 'Generic'
           |          model: 'MBIM [0000:0000]'
           |       revision: '11.617.00.00.00'
           |      supported: 'gsm-umts, lte'
           |        current: 'gsm-umts, lte'
           |   equipment id: '867160020031757'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3'
           |        drivers: 'cdc_mbim'
           |         plugin: 'Generic'
           |   primary port: 'cdc-wdm0'
           |          ports: 'cdc-wdm0 (mbim), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'sim-pin'
           | unlock retries: 'sim-pin (3)'
           |          state: 'locked'
           |    power state: 'low'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: 'allowed: 2g, 3g, 4g; preferred: none'
           |        current: 'allowed: 2g, 3g, 4g; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

  -------------------------
  Bearers  |          paths: 'none'

-------------- next part --------------

/org/freedesktop/ModemManager1/Modem/0 (device id '591fe4920e83854b04755c2f30d06bd99a8b1948')
  -------------------------
  Hardware |   manufacturer: 'Generic'
           |          model: 'MBIM [0000:0000]'
           |       revision: '11.617.00.00.00'
           |      supported: 'gsm-umts, lte'
           |        current: 'gsm-umts, lte'
           |   equipment id: '867160020031757'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3'
           |        drivers: 'cdc_mbim'
           |         plugin: 'Generic'
           |   primary port: 'cdc-wdm0'
           |          ports: 'cdc-wdm0 (mbim), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'none'
           | unlock retries: 'unknown (3)'
           |          state: 'connected'
           |    power state: 'on'
           |    access tech: 'lte'
           | signal quality: '70' (recent)
  -------------------------
  Modes    |      supported: 'allowed: 2g, 3g, 4g; preferred: none'
           |        current: 'allowed: 2g, 3g, 4g; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  3GPP     |           imei: '867160020031757'
           |  enabled locks: 'sim'
           |    operator id: '26201'
           |  operator name: 'Telekom.de'
           |   subscription: 'unknown'
           |   registration: 'home'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

  -------------------------
  Bearers  |          paths: '/org/freedesktop/ModemManager1/Bearer/0'

-------------- next part --------------

/org/freedesktop/ModemManager1/Modem/0 (device id '591fe4920e83854b04755c2f30d06bd99a8b1948')
  -------------------------
  Hardware |   manufacturer: 'Generic'
           |          model: 'MBIM [0000:0000]'
           |       revision: '11.617.00.00.00'
           |      supported: 'gsm-umts, lte'
           |        current: 'gsm-umts, lte'
           |   equipment id: '867160020031757'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3'
           |        drivers: 'cdc_mbim'
           |         plugin: 'Generic'
           |   primary port: 'cdc-wdm0'
           |          ports: 'cdc-wdm0 (mbim), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'none'
           | unlock retries: 'unknown (3)'
           |          state: 'disabled'
           |    power state: 'low'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: 'allowed: 2g, 3g, 4g; preferred: none'
           |        current: 'allowed: 2g, 3g, 4g; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  3GPP     |           imei: '867160020031757'
           |  enabled locks: 'sim'
           |    operator id: 'unknown'
           |  operator name: 'unknown'
           |   subscription: 'unknown'
           |   registration: 'unknown'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

  -------------------------
  Bearers  |          paths: 'none'

-------------- next part --------------
<info>  [1457538292.825007] [main.c:136] main(): ModemManager (version 1.4.12) starting in system bus...
<warn>  [1457538292.830396] [main.c:101] name_lost_cb(): Could not acquire the 'org.freedesktop.ModemManager1' service name
<info>  [1457538292.830405] [main.c:187] main(): ModemManager is shut down
<info>  [1457538400.989174] [main.c:136] main(): ModemManager (version 1.4.12) starting in system bus...
<debug> [1457538400.990530] [main.c:61] bus_acquired_cb(): Bus acquired, creating manager...
<debug> [1457538400.996711] [mm-plugin-manager.c:852] load_plugins(): Looking for plugins in '/usr/lib/ModemManager'
<debug> [1457538401.013500] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Altair LTE'
<debug> [1457538401.013610] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'AnyDATA'
<debug> [1457538401.015823] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Cinterion'
<debug> [1457538401.015914] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Generic'
<debug> [1457538401.015993] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Gobi'
<debug> [1457538401.017951] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Option High-Speed'
<debug> [1457538401.021337] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Huawei'
<debug> [1457538401.022965] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Iridium'
<debug> [1457538401.023058] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Linktop'
<debug> [1457538401.023144] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Longcheer'
<debug> [1457538401.025807] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Ericsson MBM'
<debug> [1457538401.025892] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Motorola'
<debug> [1457538401.025977] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'MTK'
<debug> [1457538401.028499] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Nokia (Icera)'
<debug> [1457538401.028587] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Nokia'
<debug> [1457538401.031236] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Novatel LTE'
<debug> [1457538401.031328] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Novatel'
<debug> [1457538401.031414] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Option'
<debug> [1457538401.033756] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Pantech'
<debug> [1457538401.033848] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Samsung'
<debug> [1457538401.036887] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Sierra'
<debug> [1457538401.039203] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'SimTech'
<debug> [1457538401.039287] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Telit'
<debug> [1457538401.039366] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Via CBP7'
<debug> [1457538401.039449] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Wavecom'
<debug> [1457538401.042224] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'X22X'
<debug> [1457538401.042327] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'ZTE'
<debug> [1457538401.042354] [mm-plugin-manager.c:902] load_plugins(): Successfully loaded 27 plugins
<debug> [1457538401.042660] [main.c:83] name_acquired_cb(): Service name 'org.freedesktop.ModemManager1' was acquired
<debug> [1457538401.042664] [mm-base-manager.c:485] mm_base_manager_start(): Starting automatic device scan...
<debug> [1457538401.043842] [mm-base-manager.c:524] mm_base_manager_start(): Finished device scan...
<debug> [1457538401.048600] [mm-plugin-manager.c:739] mm_plugin_manager_find_device_support(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3] Checking device support...
<debug> [1457538401.048624] [mm-device.c:327] mm_device_grab_port(): (/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3) could not get vendor/product ID
<debug> [1457538401.048642] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048645] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048648] [mm-plugin.c:326] apply_pre_probing_filters(): (Cinterion) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048650] [mm-plugin.c:253] apply_pre_probing_filters(): (Gobi) [wwan0] filtered by drivers
<debug> [1457538401.048652] [mm-plugin.c:253] apply_pre_probing_filters(): (Option High-Speed) [wwan0] filtered by drivers
<debug> [1457538401.048654] [mm-plugin.c:326] apply_pre_probing_filters(): (Huawei) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048655] [mm-plugin.c:212] apply_pre_probing_filters(): (Iridium) [wwan0] filtered by subsystem
<debug> [1457538401.048657] [mm-plugin.c:212] apply_pre_probing_filters(): (Linktop) [wwan0] filtered by subsystem
<debug> [1457538401.048659] [mm-plugin.c:212] apply_pre_probing_filters(): (Longcheer) [wwan0] filtered by subsystem
<debug> [1457538401.048660] [mm-plugin.c:380] apply_pre_probing_filters(): (Ericsson MBM) [wwan0] filtered by udev tags
<debug> [1457538401.048662] [mm-plugin.c:212] apply_pre_probing_filters(): (Motorola) [wwan0] filtered by subsystem
<debug> [1457538401.048663] [mm-plugin.c:212] apply_pre_probing_filters(): (MTK) [wwan0] filtered by subsystem
<debug> [1457538401.048665] [mm-plugin.c:326] apply_pre_probing_filters(): (Nokia (Icera)) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048667] [mm-plugin.c:212] apply_pre_probing_filters(): (Nokia) [wwan0] filtered by subsystem
<debug> [1457538401.048668] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel LTE) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048670] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048671] [mm-plugin.c:212] apply_pre_probing_filters(): (Option) [wwan0] filtered by subsystem
<debug> [1457538401.048673] [mm-plugin.c:326] apply_pre_probing_filters(): (Pantech) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048674] [mm-plugin.c:326] apply_pre_probing_filters(): (Samsung) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048676] [mm-plugin.c:253] apply_pre_probing_filters(): (Sierra) [wwan0] filtered by drivers
<debug> [1457538401.048677] [mm-plugin.c:212] apply_pre_probing_filters(): (SimTech) [wwan0] filtered by subsystem
<debug> [1457538401.048679] [mm-plugin.c:212] apply_pre_probing_filters(): (Telit) [wwan0] filtered by subsystem
<debug> [1457538401.048680] [mm-plugin.c:212] apply_pre_probing_filters(): (Via CBP7) [wwan0] filtered by subsystem
<debug> [1457538401.048682] [mm-plugin.c:212] apply_pre_probing_filters(): (Wavecom) [wwan0] filtered by subsystem
<debug> [1457538401.048683] [mm-plugin.c:326] apply_pre_probing_filters(): (X22X) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048685] [mm-plugin.c:326] apply_pre_probing_filters(): (ZTE) [wwan0] filtered by vendor/product IDs
<debug> [1457538401.048686] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [wwan0] Found '1' plugins to try...
<debug> [1457538401.048688] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [wwan0]   Will try with plugin 'Generic'
<debug> [1457538401.048692] [mm-plugin.c:689] mm_plugin_supports_port(): (Generic) [wwan0] probing deferred until result suggested
<debug> [1457538401.048785] [mm-device.c:327] mm_device_grab_port(): (/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3) could not get vendor/product ID
<debug> [1457538401.048795] [mm-plugin.c:212] apply_pre_probing_filters(): (Altair LTE) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048797] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048798] [mm-plugin.c:326] apply_pre_probing_filters(): (Cinterion) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048800] [mm-plugin.c:253] apply_pre_probing_filters(): (Gobi) [cdc-wdm0] filtered by drivers
<debug> [1457538401.048801] [mm-plugin.c:212] apply_pre_probing_filters(): (Option High-Speed) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048804] [mm-plugin.c:326] apply_pre_probing_filters(): (Huawei) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048805] [mm-plugin.c:212] apply_pre_probing_filters(): (Iridium) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048807] [mm-plugin.c:212] apply_pre_probing_filters(): (Linktop) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048808] [mm-plugin.c:212] apply_pre_probing_filters(): (Longcheer) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048810] [mm-plugin.c:380] apply_pre_probing_filters(): (Ericsson MBM) [cdc-wdm0] filtered by udev tags
<debug> [1457538401.048811] [mm-plugin.c:212] apply_pre_probing_filters(): (Motorola) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048813] [mm-plugin.c:212] apply_pre_probing_filters(): (MTK) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048814] [mm-plugin.c:212] apply_pre_probing_filters(): (Nokia (Icera)) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048816] [mm-plugin.c:212] apply_pre_probing_filters(): (Nokia) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048817] [mm-plugin.c:212] apply_pre_probing_filters(): (Novatel LTE) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048819] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048820] [mm-plugin.c:212] apply_pre_probing_filters(): (Option) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048821] [mm-plugin.c:326] apply_pre_probing_filters(): (Pantech) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048823] [mm-plugin.c:212] apply_pre_probing_filters(): (Samsung) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048824] [mm-plugin.c:253] apply_pre_probing_filters(): (Sierra) [cdc-wdm0] filtered by drivers
<debug> [1457538401.048826] [mm-plugin.c:212] apply_pre_probing_filters(): (SimTech) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048827] [mm-plugin.c:212] apply_pre_probing_filters(): (Telit) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048828] [mm-plugin.c:212] apply_pre_probing_filters(): (Via CBP7) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048830] [mm-plugin.c:212] apply_pre_probing_filters(): (Wavecom) [cdc-wdm0] filtered by subsystem
<debug> [1457538401.048831] [mm-plugin.c:326] apply_pre_probing_filters(): (X22X) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048833] [mm-plugin.c:326] apply_pre_probing_filters(): (ZTE) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1457538401.048834] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [cdc-wdm0] Found '1' plugins to try...
<debug> [1457538401.048836] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [cdc-wdm0]   Will try with plugin 'Generic'
<debug> [1457538401.048854] [mm-plugin.c:767] mm_plugin_supports_port(): (Generic) [cdc-wdm0] probe required: 'mbim'
<debug> [1457538401.048858] [mm-port-probe.c:1368] mm_port_probe_run(): (usbmisc/cdc-wdm0) launching port probing: 'mbim'
<debug> [1457538401.048869] [mm-plugin-manager.c:569] plugin_supports_port_ready(): (Plugin Manager) [wwan0] deferring support check until result suggested
<debug> [1457538401.048873] [mm-port-probe.c:525] wdm_probe_mbim(): (usbmisc/cdc-wdm0) probing MBIM...
opening device...cannot connect to proxy: Could not connect: Connection refusedspawning new mbim-proxy (try 1)...[/dev/cdc-wdm0] Read max control message size from descriptors file: 1024[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 88
<<<<<<   data   = 03:00:00:00:58:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:01:00:00:00:28:00:00:00:0C:00:00:00:1A:00:00:00:1E:00:00:00:2F:00:64:00:65:00:76:00:2F:00:63:00:64:00:63:00:2D:00:77:00:64:00:6D:00:30:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 88
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 1
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b)
<<<<<<   cid     = 'configuration' (0x00000001)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 48
>>>>>>   data   = 03:00:00:80:30:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 48
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 1
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b)
>>>>>>   cid          = 'configuration' (0x00000001)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:00:00:00:10:00:00:00:02:00:00:00:00:04:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 16
<<<<<<   type        = open (0x00000001)
<<<<<<   transaction = 2
<<<<<< Contents:
<<<<<<   max_control_transfer = 1024
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 16
>>>>>>   data   = 01:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00
<debug> [1457538401.215601] [mm-port-probe.c:303] mm_port_probe_set_result_mbim(): (usbmisc/cdc-wdm0) port is MBIM-capable
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 12
<<<<<<   data   = 02:00:00:00:0C:00:00:00:03:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 12
<<<<<<   type        = close (0x00000002)
<<<<<<   transaction = 3
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 16
>>>>>>   data   = 02:00:00:80:10:00:00:00:03:00:00:00:00:00:00:00
<debug> [1457538401.216351] [mm-plugin-manager.c:462] plugin_supports_port_ready(): (Plugin Manager) (Generic) [cdc-wdm0] found best plugin for port
<debug> [1457538401.216405] [mm-plugin-manager.c:361] suggest_single_port_probe_result(): (Plugin Manager) (Generic) [wwan0] deferred task completed, got suggested plugin
<debug> [1457538401.216434] [mm-plugin-manager.c:305] port_probe_context_finished(): (Plugin Manager) 'cdc-wdm0' port probe finished, still 1 running probes in this device (wwan0)
<debug> [1457538401.216487] [mm-plugin.c:689] mm_plugin_supports_port(): (Generic) [wwan0] probing deferred until result suggested
<debug> [1457538401.216511] [mm-plugin-manager.c:549] plugin_supports_port_ready(): (Plugin Manager) (Generic) [wwan0] task completed, got suggested plugin
<debug> [1457538401.216527] [mm-plugin-manager.c:313] port_probe_context_finished(): (Plugin Manager) 'wwan0' port probe finished, last one in device, but minimum probing time not consumed yet ('0.167916' seconds elapsed)
<debug> [1457538403.037644] [mm-plugin-manager.c:703] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3] Minimum probing time consumed and no more ports to probe
<debug> [1457538403.037689] [mm-plugin-manager.c:138] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3] device support check finished in '1.989078' seconds
<info>  [1457538403.037732] [mm-device.c:520] mm_device_create_modem(): Creating modem with plugin 'Generic' and '2' ports
<debug> [1457538403.037766] [generic/mm-plugin-generic.c:73] create_modem(): MBIM-powered generic modem found...
<debug> [1457538403.039957] [mm-base-modem.c:304] mm_base_modem_grab_port(): (cdc-wdm0) type 'mbim' claimed by /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3
<debug> [1457538403.040014] [mm-base-modem.c:304] mm_base_modem_grab_port(): (wwan0) type 'net' claimed by /sys/devices/pci0000:00/0000:00:14.0/usb1/1-3
<debug> [1457538403.040071] [mm-base-modem.c:970] log_port(): (/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3) net/wwan0 data (primary)
<debug> [1457538403.040083] [mm-base-modem.c:970] log_port(): (/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3) usb/cdc-wdm0 mbim (primary)
<info>  [1457538403.040506] [mm-base-manager.c:162] find_device_support_ready(): Modem for device at '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3' successfully created
opening device...[/dev/cdc-wdm0] Read max control message size from descriptors file: 1024[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 88
<<<<<<   data   = 03:00:00:00:58:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:01:00:00:00:28:00:00:00:0C:00:00:00:1A:00:00:00:1E:00:00:00:2F:00:64:00:65:00:76:00:2F:00:63:00:64:00:63:00:2D:00:77:00:64:00:6D:00:30:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 88
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 1
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b)
<<<<<<   cid     = 'configuration' (0x00000001)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 48
>>>>>>   data   = 03:00:00:80:30:00:00:00:01:00:00:00:01:00:00:00:00:00:00:00:83:8C:F7:FB:8D:0D:4D:7F:87:1E:D7:1D:BE:FB:B3:9B:01:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 48
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 1
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'proxy-control' (838cf7fb-8d0d-4d7f-871e-d71dbefbb39b)
>>>>>>   cid          = 'configuration' (0x00000001)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:00:00:00:10:00:00:00:02:00:00:00:00:04:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 16
<<<<<<   type        = open (0x00000001)
<<<<<<   transaction = 2
<<<<<< Contents:
<<<<<<   max_control_transfer = 1024
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 16
>>>>>>   data   = 01:00:00:80:10:00:00:00:02:00:00:00:00:00:00:00
<debug> [1457538403.042521] [mm-broadband-modem-mbim.c:1293] parent_initialization_started_ready(): Couldn't start parent initialization: Couldn't open ports during modem initialization: Couldn't get primary port
<debug> [1457538403.043944] [mm-broadband-modem-mbim.c:214] modem_load_current_capabilities(): loading current capabilities...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:03: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:01:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 3
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'device-caps' (0x00000001)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 208
>>>>>>   data   = 03:00:00:80:D0:00:00:00:03: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:01:00:00:00:00:00:00:00:A0:00:00:00:01:00:00:00:01:00:00:00:01:00:00:00:02:00:00:00:3F:00:00:80:03:00:00:00:03:00:00:00:03:00:00:00:40:00:00:00:0A:00:00:00:4C:00:00:00:1E:00:00:00:6C:00:00:00:1E:00:00:00:8C:00:00:00:14:00:00:00:48:00:53:00:50:00:41:00:2B:00:00:00:38:00:36:00:37:00:31:00:36:00:30:00:30:00:32:00:30:00:30:00:33:00:31:00:37:00:35:00:37:00:00:00:31:00:31:00:2E:00:36:00:31:00:37:00:2E:00:30:00:30:00:2E:00:30:00:30:00:2E:00:30:00:30:00:00:00:4D:00:4C:00:31:00:4D:00:45:00:39:00:30:00:36:00:53:00:4D:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 208
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 3
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'device-caps' (0x00000001)
<debug> [1457538403.254330] [mm-broadband-modem-mbim.c:140] modem_load_current_capabilities_finish(): loaded modem capabilities: gsm-umts, lte
<debug> [1457538403.254512] [mm-iface-modem.c:4306] interface_initialization_step(): Modem allows up to 1 bearers
<debug> [1457538403.254529] [mm-bearer-list.c:276] mm_bearer_list_new(): Creating bearer list (max: 1, max active: 1)
<debug> [1457538403.254863] [mm-modem-helpers.c:148] mm_create_device_identifier(): Device ID source '86716002003175711.617.00.00.00MBIM[0000:0000]Generic'
<debug> [1457538403.254879] [mm-modem-helpers.c:149] mm_create_device_identifier(): Device ID '591fe4920e83854b04755c2f30d06bd99a8b1948'
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:04: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:03:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 4
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'radio-state' (0x00000003)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 56
>>>>>>   data   = 03:00:00:80:38:00:00:00:04: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:03:00:00:00:00:00:00:00:08:00:00:00:01:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 56
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 4
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'radio-state' (0x00000003)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:05: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 5
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 116
>>>>>>   data   = 03:00:00:80:74:00:00:00:05: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:02:00:00:00:00:00:00:00:44:00:00:00:06:00:00:00:00:00:00:00:00:00:00:00:1C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 116
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 5
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:06: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:04:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 6
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'pin' (0x00000004)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 60
>>>>>>   data   = 03:00:00:80:3C:00:00:00:06: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:04:00:00:00:00:00:00:00:0C:00:00:00:02:00:00:00:01:00:00:00:03:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 60
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 6
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'pin' (0x00000004)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:07: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:04:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 7
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'pin' (0x00000004)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 60
>>>>>>   data   = 03:00:00:80:3C:00:00:00:07: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:04:00:00:00:00:00:00:00:0C:00:00:00:02:00:00:00:01:00:00:00:03:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 60
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 7
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'pin' (0x00000004)
<info>  [1457538403.692515] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem: state changed (unknown -> locked)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:08: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 8
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 116
>>>>>>   data   = 03:00:00:80:74:00:00:00:08: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:02:00:00:00:00:00:00:00:44:00:00:00:06:00:00:00:00:00:00:00:00:00:00:00:1C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 116
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 8
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:09: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 9
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 116
>>>>>>   data   = 03:00:00:80:74:00:00:00:09: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:02:00:00:00:00:00:00:00:44:00:00:00:06:00:00:00:00:00:00:00:00:00:00:00:1C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 116
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 9
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:0A: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:06:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 10
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'home-provider' (0x00000006)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 48
>>>>>>   data   = 03:00:00:80:30:00:00:00:0A: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:06:00:00:00:05:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 48
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 10
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'PinRequired' (0x00000005)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'home-provider' (0x00000006)
<warn>  [1457538404.092955] [mm-base-sim.c:1480] load_operator_identifier_ready(): couldn't load Operator identifier: 'PinRequired'
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:0B: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:06:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 11
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'home-provider' (0x00000006)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 48
>>>>>>   data   = 03:00:00:80:30:00:00:00:0B: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:06:00:00:00:05:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 48
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 11
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'PinRequired' (0x00000005)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'home-provider' (0x00000006)
<warn>  [1457538404.172825] [mm-base-sim.c:1481] load_operator_name_ready(): couldn't load Operator name: 'PinRequired'
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:0C: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 12
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 116
>>>>>>   data   = 03:00:00:80:74:00:00:00:0C: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:02:00:00:00:00:00:00:00:44:00:00:00:06:00:00:00:00:00:00:00:00:00:00:00:1C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 116
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 12
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
<debug> [1457538404.333543] [mm-broadband-modem.c:9168] iface_modem_firmware_initialize_ready(): Couldn't initialize interface: 'Firmware not supported'
<debug> [1457538404.333805] [mm-base-modem.c:950] initialize_ready(): Couldn't finish initialization in the current state: 'Modem is currently locked, cannot fully initialize'
<debug> [1457538404.334904] [mm-device.c:447] export_modem(): Exported modem '/sys/devices/pci0000:00/0000:00:14.0/usb1/1-3' at path '/org/freedesktop/ModemManager1/Modem/0'
<debug> [1457538404.334935] [mm-device.c:457] export_modem(): (/org/freedesktop/ModemManager1/Modem/0): 'Generic' modem, VID 0x0000 PID 0x0000 (usb)
<debug> [1457539714.595657] [mm-sim-mbim.c:431] send_pin(): Sending PIN...
<debug> [1457539714.595689] [mm-sim-mbim.c:41] inhibit_mbim_traces(): PIN logging enabled
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 80
<<<<<<   data   = 03:00:00:00:50:00:00:00:0D: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:04:00:00:00:01:00:00:00:20:00:00:00:02:00:00:00:00:00:00:00:18:00:00:00:08:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:35:00:38:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 80
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 13
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'pin' (0x00000004)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 60
>>>>>>   data   = 03:00:00:80:3C:00:00:00:0D: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:04:00:00:00:00:00:00:00:0C:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 60
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 13
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'pin' (0x00000004)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:0E: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 14
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 144
>>>>>>   data   = 07:00:00:80:90: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:02:00:00:00:64:00:00:00:01:00:00:00:1C:00:00:00:1E:00:00:00:3C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:32:00:30:00:31:00:36:00:34:00:34:00:31:00:30:00:33:00:30:00:35:00:35:00:36:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 144
>>>>>>   type        = indicate-status (0x80000007)
>>>>>>   transaction = 0
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid     = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 148
>>>>>>   data   = 03:00:00:80:94:00:00:00:0E: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:02:00:00:00:00:00:00:00:64:00:00:00:01:00:00:00:1C:00:00:00:1E:00:00:00:3C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:32:00:30:00:31:00:36:00:34:00:34:00:31:00:30:00:33:00:30:00:35:00:35:00:36:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 148
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 14
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:0F: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:04:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 15
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'pin' (0x00000004)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 60
>>>>>>   data   = 03:00:00:80:3C:00:00:00:0F: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:04:00:00:00:00:00:00:00:0C:00:00:00:00:00:00:00:00:00:00:00:03:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 60
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 15
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'pin' (0x00000004)
<debug> [1457539716.194771] [mm-iface-modem.c:3071] update_lock_info_context_step(): SIM is ready, and no need for the after SIM unlock step...
<info>  [1457539716.195372] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (locked -> initializing)
<debug> [1457539716.196631] [mm-broadband-modem-mbim.c:1293] parent_initialization_started_ready(): Couldn't start parent initialization: Couldn't open ports during modem initialization: Couldn't get primary port
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:10: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 16
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 148
>>>>>>   data   = 03:00:00:80:94:00:00:00:10: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:02:00:00:00:00:00:00:00:64:00:00:00:01:00:00:00:1C:00:00:00:1E:00:00:00:3C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:32:00:30:00:31:00:36:00:34:00:34:00:31:00:30:00:33:00:30:00:35:00:35:00:36:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 148
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 16
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:11: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:06:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 17
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'home-provider' (0x00000006)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 112
>>>>>>   data   = 03:00:00:80:70:00:00:00:11: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:06:00:00:00:00:00:00:00:40:00:00:00:20:00:00:00:0A:00:00:00:01:00:00:00:2C:00:00:00:14:00:00:00:01:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:32:00:30:00:31:00:00:00:54:00:65:00:6C:00:65:00:6B:00:6F:00:6D:00:2E:00:64:00:65:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 112
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 17
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'home-provider' (0x00000006)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:12: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:06:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 18
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'home-provider' (0x00000006)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 112
>>>>>>   data   = 03:00:00:80:70:00:00:00:12: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:06:00:00:00:00:00:00:00:40:00:00:00:20:00:00:00:0A:00:00:00:01:00:00:00:2C:00:00:00:14:00:00:00:01:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:32:00:30:00:31:00:00:00:54:00:65:00:6C:00:65:00:6B:00:6F:00:6D:00:2E:00:64:00:65:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 112
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 18
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'home-provider' (0x00000006)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:13: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:02:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 19
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'subscriber-ready-status' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 148
>>>>>>   data   = 03:00:00:80:94:00:00:00:13: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:02:00:00:00:00:00:00:00:64:00:00:00:01:00:00:00:1C:00:00:00:1E:00:00:00:3C:00:00:00:28:00:00:00:00:00:00:00:00:00:00:00:32:00:36:00:32:00:30:00:31:00:36:00:34:00:34:00:31:00:30:00:33:00:30:00:35:00:35:00:36:00:00:00:38:00:39:00:34:00:39:00:30:00:32:00:30:00:30:00:30:00:30:00:30:00:38:00:31:00:35:00:31:00:35:00:31:00:33:00:33:00:32:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 148
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 19
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'subscriber-ready-status' (0x00000002)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:14: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:05:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 20
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'pin-list' (0x00000005)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 208
>>>>>>   data   = 03:00:00:80:D0:00:00:00:14: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:05:00:00:00:00:00:00:00:A0:00:00:00:01:00:00:00:01:00:00:00:04:00:00:00:08: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: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:01:00:00:00:08:00:00:00:08: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: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: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:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 208
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 20
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'pin-list' (0x00000005)
<debug> [1457539717.235631] [mm-iface-modem-3gpp-ussd.c:786] check_support_ready(): USSD support check failed: 'No AT port available to run command'
<debug> [1457539717.235675] [mm-broadband-modem.c:9161] iface_modem_3gpp_ussd_initialize_ready(): Couldn't initialize interface: 'USSD not supported'
<debug> [1457539717.236681] [mm-broadband-modem-mbim.c:2596] messaging_check_support(): Messaging capabilities supported
<debug> [1457539717.236756] [mm-iface-modem-messaging.c:1148] load_supported_storages_ready(): Supported storages loaded:
<debug> [1457539717.236767] [mm-iface-modem-messaging.c:1149] load_supported_storages_ready():   mem1 (list/read/delete) storages: 'mt'
<debug> [1457539717.236790] [mm-iface-modem-messaging.c:1150] load_supported_storages_ready():   mem2 (write/send) storages:       'mt'
<debug> [1457539717.236799] [mm-iface-modem-messaging.c:1151] load_supported_storages_ready():   mem3 (reception) storages:        'mt'
<debug> [1457539717.237343] [mm-iface-modem-time.c:831] check_support_ready(): Time support check failed: 'No AT port available to run command'
<debug> [1457539717.237378] [mm-broadband-modem.c:9165] iface_modem_time_initialize_ready(): Couldn't initialize interface: 'Time not supported'
<debug> [1457539717.237614] [mm-broadband-modem.c:9166] iface_modem_signal_initialize_ready(): Couldn't initialize interface: 'Extended Signal information not supported'
<debug> [1457539717.237944] [mm-broadband-modem.c:9167] iface_modem_oma_initialize_ready(): Couldn't initialize interface: 'OMA not supported'
<debug> [1457539717.238061] [mm-broadband-modem.c:9168] iface_modem_firmware_initialize_ready(): Couldn't initialize interface: 'Firmware not supported'
<info>  [1457539717.238136] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (initializing -> disabled)
<info>  [1457539874.154797] [mm-iface-modem-simple.c:641] connect_auth_ready(): Simple connect started...
<debug> [1457539874.154806] [mm-iface-modem-simple.c:651] connect_auth_ready():    PIN: unspecified
<debug> [1457539874.154809] [mm-iface-modem-simple.c:653] connect_auth_ready():    Operator ID: unspecified
<debug> [1457539874.154812] [mm-iface-modem-simple.c:655] connect_auth_ready():    Allowed roaming: yes
<debug> [1457539874.154816] [mm-iface-modem-simple.c:657] connect_auth_ready():    APN: internet.t-mobile.de
<debug> [1457539874.154819] [mm-iface-modem-simple.c:665] connect_auth_ready():    IP family: unspecified
<debug> [1457539874.154822] [mm-iface-modem-simple.c:673] connect_auth_ready():    Allowed authentication: unspecified
<debug> [1457539874.154825] [mm-iface-modem-simple.c:675] connect_auth_ready():    User: unspecified
<debug> [1457539874.154828] [mm-iface-modem-simple.c:677] connect_auth_ready():    Password: unspecified
<debug> [1457539874.154831] [mm-iface-modem-simple.c:679] connect_auth_ready():    Number: unspecified
<info>  [1457539874.154833] [mm-iface-modem-simple.c:461] connection_step(): Simple connect state (3/8): Enable
<info>  [1457539874.154847] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
<debug> [1457539874.154964] [mm-broadband-modem.c:8166] enabling_started(): Skipping modem initialization: not required
<debug> [1457539874.154980] [mm-broadband-modem-mbim.c:1220] parent_enabling_started_ready(): Couldn't start parent enabling: Couldn't open ports during modem enabling: Couldn't get primary port
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:15: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:03:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 21
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'radio-state' (0x00000003)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 56
>>>>>>   data   = 03:00:00:80:38:00:00:00:15: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:03:00:00:00:00:00:00:00:08:00:00:00:01:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 56
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 21
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'radio-state' (0x00000003)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 52
<<<<<<   data   = 03:00:00:00:34:00:00:00:16: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:03:00:00:00:01:00:00:00:04:00:00:00:01:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 52
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 22
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'radio-state' (0x00000003)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 56
>>>>>>   data   = 03:00:00:80:38:00:00:00:16: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:03:00:00:00:00:00:00:00:08:00:00:00:01:00:00:00:01:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 56
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 22
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'radio-state' (0x00000003)
<debug> [1457539875.555352] [mm-iface-modem.c:3186] modem_power_up_ready(): Modem set in full-power mode...
<debug> [1457539875.555722] [mm-broadband-modem.c:8755] enabling_step(): Modem has 3GPP capabilities, enabling the Modem 3GPP interface...
<debug> [1457539875.555759] [mm-broadband-modem-mbim.c:1980] common_setup_cleanup_unsolicited_events(): Supported notifications: signal (yes), registration (no), sms (no), connect (yes), subscriber (yes), packet (yes)
<debug> [1457539875.555803] [mm-broadband-modem-mbim.c:2119] common_enable_disable_unsolicited_events(): Enabled notifications: signal (yes), registration (no), sms (no), connect (yes), subscriber (yes), packet (yes)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 96
<<<<<<   data   = 03:00:00:00:60:00:00:00:17: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:13:00:00:00:01:00:00:00:30:00:00:00:01:00:00:00:0C:00:00:00:24:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:04:00:00:00:0B:00:00:00:0C:00:00:00:02:00:00:00:0A:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 96
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 23
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'device-service-subscribe-list' (0x00000013)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 96
>>>>>>   data   = 03:00:00:80:60:00:00:00:17: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:13:00:00:00:00:00:00:00:30:00:00:00:01:00:00:00:0C:00:00:00:24:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:04:00:00:00:0B:00:00:00:0C:00:00:00:02:00:00:00:0A:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 96
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 23
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'device-service-subscribe-list' (0x00000013)
<debug> [1457539875.556621] [mm-broadband-modem-mbim.c:1980] common_setup_cleanup_unsolicited_events(): Supported notifications: signal (yes), registration (yes), sms (no), connect (yes), subscriber (yes), packet (yes)
<debug> [1457539875.556687] [mm-broadband-modem-mbim.c:2119] common_enable_disable_unsolicited_events(): Enabled notifications: signal (yes), registration (yes), sms (no), connect (yes), subscriber (yes), packet (yes)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 100
<<<<<<   data   = 03:00:00:00:64:00:00:00:18: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:13:00:00:00:01:00:00:00:34:00:00:00:01:00:00:00:0C:00:00:00:28:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:05:00:00:00:0B:00:00:00:09:00:00:00:0C:00:00:00:02:00:00:00:0A:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 100
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 24
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'device-service-subscribe-list' (0x00000013)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 100
>>>>>>   data   = 03:00:00:80:64:00:00:00:18: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:13:00:00:00:00:00:00:00:34:00:00:00:01:00:00:00:0C:00:00:00:28:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:05:00:00:00:0B:00:00:00:09:00:00:00:0C:00:00:00:02:00:00:00:0A:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 100
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 24
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'device-service-subscribe-list' (0x00000013)
<debug> [1457539875.557353] [mm-iface-modem-3gpp.c:761] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'no')
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:19: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:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 25
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'register-state' (0x00000009)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 124
>>>>>>   data   = 07:00:00:80:7C: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:50:00:00:00:00:00:00:00:03:00:00:00:01:00:00:00:20:00:00:00:01:00:00:00:30:00:00:00:0A:00:00:00:3C:00:00:00:14:00:00:00:00:00:00:00:00:00:00:00:02:00:00:00:32:00:36:00:32:00:30:00:31:00:00:00:54:00:65:00:6C:00:65:00:6B:00:6F:00:6D:00:2E:00:64:00:65:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 124
>>>>>>   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> [1457539875.895330] [mm-broadband-modem-mbim.c:1934] device_notification_cb(): Received notification (service 'basic-connect', command 'register-state')
<info>  [1457539875.895491] [mm-iface-modem-3gpp.c:1164] update_registration_state(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> registering)
<debug> [1457539875.895623] [mm-iface-modem.c:894] mm_iface_modem_update_access_technologies(): Modem /org/freedesktop/ModemManager1/Modem/0: access technology changed (unknown -> lte)
<info>  [1457539875.896652] [mm-iface-modem-3gpp.c:1089] update_registration_reload_current_registration_info_ready(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
<debug> [1457539875.896794] [mm-iface-modem.c:1561] get_updated_consolidated_state(): Will start keeping track of state for subsystem '3gpp'
[/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:20:00:00:00:00:00:00:00:00:00:00:00:00:00:00: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> [1457539875.975236] [mm-broadband-modem-mbim.c:1934] device_notification_cb(): Received notification (service 'basic-connect', command 'packet-service')
<debug> [1457539875.975271] [mm-broadband-modem-mbim.c:1749] basic_connect_notification_packet_service(): Packet service state: 'attached', data class: 'lte'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 128
>>>>>>   data   = 03:00:00:80:80:00:00:00:19: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:00:00:00:00:50:00:00:00:00:00:00:00:03:00:00:00:01:00:00:00:20:00:00:00:01:00:00:00:30:00:00:00:0A:00:00:00:3C:00:00:00:14:00:00:00:00:00:00:00:00:00:00:00:02:00:00:00:32:00:36:00:32:00:30:00:31:00:00:00:54:00:65:00:6C:00:65:00:6B:00:6F:00:6D:00:2E:00:64:00:65:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 128
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 25
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'register-state' (0x00000009)
<debug> [1457539876.275460] [mm-broadband-modem.c:8796] enabling_step(): Modem has location capabilities, enabling the Location interface...
<debug> [1457539876.275508] [mm-iface-modem-location.c:759] setup_gathering(): Need to enable the following location sources: '3gpp-lac-ci'
<debug> [1457539876.275629] [mm-iface-modem-3gpp.c:761] mm_iface_modem_3gpp_run_registration_checks(): Running registration checks (CS: 'yes', PS: 'yes', EPS: 'no')
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:1A: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:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 48
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 26
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'register-state' (0x00000009)
<<<<<<   type    = 'query' (0x00000000)
<debug> [1457539876.276202] [mm-iface-modem-location.c:295] notify_3gpp_location_update(): Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP location updated (MCC: '262', MNC: '1', Location area code: '0', Cell ID: '0')
<debug> [1457539876.276364] [mm-broadband-modem.c:8809] enabling_step(): Modem has messaging capabilities, enabling the Messaging interface...
<debug> [1457539876.276516] [mm-broadband-modem-mbim.c:2751] load_initial_sms_parts(): loading SMS parts...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 60
<<<<<<   data   = 03:00:00:00:3C:00:00:00:1B:00:00:00:01:00:00:00:00:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:02:00:00:00:00:00:00:00:0C:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 60
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 27
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f)
<<<<<<   cid     = 'read' (0x00000002)
<<<<<<   type    = 'query' (0x00000000)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 64
>>>>>>   data   = 07:00:00:80:40: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:0B:00:00:00:14:00:00:00:16:00:00:00:63:00:00:00:05:00:00:00:05:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 64
>>>>>>   type        = indicate-status (0x80000007)
>>>>>>   transaction = 0
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid     = 'signal-state' (0x0000000b)
<debug> [1457539876.315289] [mm-broadband-modem-mbim.c:1934] device_notification_cb(): Received notification (service 'basic-connect', command 'signal-state')
<debug> [1457539876.315315] [mm-broadband-modem-mbim.c:1547] basic_connect_notification_signal_state(): Signal state indication: 22 --> 70%
<debug> [1457539876.315479] [mm-iface-modem.c:1165] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (70)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 128
>>>>>>   data   = 03:00:00:80:80:00:00:00:1A: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:00:00:00:00:50:00:00:00:00:00:00:00:03:00:00:00:01:00:00:00:20:00:00:00:01:00:00:00:30:00:00:00:0A:00:00:00:3C:00:00:00:14:00:00:00:00:00:00:00:00:00:00:00:02:00:00:00:32:00:36:00:32:00:30:00:31:00:00:00:54:00:65:00:6C:00:65:00:6B:00:6F:00:6D:00:2E:00:64:00:65:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 128
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 26
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'register-state' (0x00000009)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 48
>>>>>>   data   = 03:00:00:80:30:00:00:00:1B:00:00:00:01:00:00:00:00:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:02:00:00:00:0E:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 48
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 27
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'NotInitialized' (0x0000000e)
>>>>>>   service      = 'sms' (533fbeeb-14fe-4467-9f90-33a223e56c3f)
>>>>>>   cid          = 'read' (0x00000002)
<debug> [1457539876.695356] [mm-iface-modem-messaging.c:775] load_initial_sms_parts_ready(): Couldn't load SMS parts from storage 'mt': 'NotInitialized'
<debug> [1457539876.695388] [mm-broadband-modem-mbim.c:1980] common_setup_cleanup_unsolicited_events(): Supported notifications: signal (yes), registration (yes), sms (yes), connect (yes), subscriber (yes), packet (yes)
<debug> [1457539876.695437] [mm-broadband-modem-mbim.c:2119] common_enable_disable_unsolicited_events(): Enabled notifications: signal (yes), registration (yes), sms (yes), connect (yes), subscriber (yes), packet (yes)
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 136
<<<<<<   data   = 03:00:00:00:88:00:00:00:1C: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:13:00:00:00:01:00:00:00:58:00:00:00:02:00:00:00:14:00:00:00:28:00:00:00:3C:00:00:00:1C:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:05:00:00:00:0B:00:00:00:09:00:00:00:0C:00:00:00:02:00:00:00:0A:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:02:00:00:00:02:00:00:00:05:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 136
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 28
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'device-service-subscribe-list' (0x00000013)
<<<<<<   type    = 'set' (0x00000001)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 136
>>>>>>   data   = 03:00:00:80:88:00:00:00:1C: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:13:00:00:00:00:00:00:00:58:00:00:00:02:00:00:00:14:00:00:00:28:00:00:00:3C:00:00:00:1C:00:00:00:A2:89:CC:33:BC:BB:8B:4F:B6:B0:13:3E:C2:AA:E6:DF:05:00:00:00:0B:00:00:00:09:00:00:00:0C:00:00:00:02:00:00:00:0A:00:00:00:53:3F:BE:EB:14:FE:44:67:9F:90:33:A2:23:E5:6C:3F:02:00:00:00:02:00:00:00:05:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 136
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 28
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'device-service-subscribe-list' (0x00000013)
<info>  [1457539876.696085] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> registered)
<debug> [1457539876.696611] [mm-iface-modem.c:1036] periodic_access_technologies_check_enable(): Periodic access technology checks enabled
<info>  [1457539876.696690] [mm-iface-modem-simple.c:469] connection_step(): Simple connect state (4/8): Wait to get fully enabled
<info>  [1457539876.696732] [mm-iface-modem-simple.c:478] connection_step(): Simple connect state (5/8): Register
<debug> [1457539876.696768] [mm-iface-modem-3gpp.c:400] mm_iface_modem_3gpp_register_in_network(): Already registered in network '26201', automatic registration not launched...
<info>  [1457539876.696811] [mm-iface-modem-simple.c:501] connection_step(): Simple connect state (6/8): Bearer
<debug> [1457539876.696834] [mm-iface-modem-simple.c:521] connection_step(): Creating new bearer...
<debug> [1457539876.696852] [mm-broadband-modem-mbim.c:1163] modem_create_bearer(): Creating MBIM bearer in MBIM modem
<debug> [1457539876.697835] [mm-broadband-modem-mbim.c:1077] modem_create_bearer_finish(): New bearer created at DBus path '/org/freedesktop/ModemManager1/Bearer/0'
<info>  [1457539876.698163] [mm-iface-modem-simple.c:583] connection_step(): Simple connect state (7/8): Connect
<debug> [1457539876.698194] [mm-base-bearer.c:590] mm_base_bearer_connect(): Connecting bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info>  [1457539876.698230] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
<debug> [1457539876.698729] [mm-bearer-mbim.c:897] _connect(): Launching connection with data port (net/wwan0)
<debug> [1457539876.698764] [mm-bearer-mbim.c:655] connect_context_step(): Activating packet service...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 52
<<<<<<   data   = 03:00:00:00:34:00:00:00:1D: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 = 29
<<<<<< 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 = 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:20:00:00:00:00:00:00:00:00:00:00:00:00:00:00: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> [1457539876.775319] [mm-broadband-modem-mbim.c:1934] device_notification_cb(): Received notification (service 'basic-connect', command 'packet-service')
<debug> [1457539876.775342] [mm-broadband-modem-mbim.c:1749] basic_connect_notification_packet_service(): Packet service state: 'attaching', data class: 'lte'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 76
>>>>>>   data   = 03:00:00:80:4C:00:00:00:1D: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:20:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 76
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 29
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'packet-service' (0x0000000a)
<debug> [1457539876.814921] [mm-bearer-mbim.c:594] packet_service_set_ready(): Packet service update:
<debug> [1457539876.814936] [mm-bearer-mbim.c:595] packet_service_set_ready():          state: 'attached'
<debug> [1457539876.814947] [mm-bearer-mbim.c:596] packet_service_set_ready():     data class: 'lte'
<debug> [1457539876.814956] [mm-bearer-mbim.c:597] packet_service_set_ready():         uplink: '0' bps
<debug> [1457539876.814964] [mm-bearer-mbim.c:598] packet_service_set_ready():       downlink: '0' bps
<debug> [1457539876.814974] [mm-bearer-mbim.c:676] connect_context_step(): Listing provisioned contexts...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 48
<<<<<<   data   = 03:00:00:00:30:00:00:00:1E: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 = 30
<<<<<< 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:1E: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 = 30
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'provisioned-contexts' (0x0000000d)
<debug> [1457539877.075327] [mm-bearer-mbim.c:529] provisioned_contexts_query_ready(): Provisioned contexts found (0):
<debug> [1457539877.075368] [mm-bearer-mbim.c:741] connect_context_step(): No specific IP family requested, defaulting to ipv4
<debug> [1457539877.075379] [mm-bearer-mbim.c:772] connect_context_step(): Launching connection with APN 'internet.t-mobile.de'...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 148
<<<<<<   data   = 03:00:00:00:94:00:00:00:1F: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:64:00:00:00:00:00:00:00:01:00:00:00:3C:00:00:00:28: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:69:00:6E:00:74:00:65:00:72:00:6E:00:65:00:74:00:2E:00:74:00:2D:00:6D:00:6F:00:62:00:69:00:6C:00:65:00:2E:00:64:00:65:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 148
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 31
<<<<<< 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 = 84
>>>>>>   data   = 03:00:00:80:54:00:00:00:1F: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:00:00:00:00:24:00:00:00:00:00:00:00:01:00:00:00:00:00:00:00:03: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      = 84
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 31
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'connect' (0x0000000c)
<debug> [1457539877.731311] [mm-bearer-mbim.c:484] connect_set_ready(): Session ID '0': activated (IP type: ipv4v6)
<debug> [1457539877.731330] [mm-bearer-mbim.c:803] connect_context_step(): Querying IP configuration...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 108
<<<<<<   data   = 03:00:00:00:6C:00:00:00:20: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:0F:00:00:00:00:00:00:00:3C: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: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:00:00:00:00:00:00:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< Header:
<<<<<<   length      = 108
<<<<<<   type        = command (0x00000003)
<<<<<<   transaction = 32
<<<<<< Fragment header:
<<<<<<   total   = 1
<<<<<<   current = 0
<<<<<< Contents:
<<<<<<   service = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
<<<<<<   cid     = 'ip-configuration' (0x0000000f)
<<<<<<   type    = 'query' (0x00000000)
[/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:20:00:00:00:80:D1:F0:08: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> [1457539877.825285] [mm-broadband-modem-mbim.c:1934] device_notification_cb(): Received notification (service 'basic-connect', command 'packet-service')
<debug> [1457539877.825308] [mm-broadband-modem-mbim.c:1749] basic_connect_notification_packet_service(): Packet service state: 'attached', data class: 'lte'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 196
>>>>>>   data   = 03:00:00:80:C4:00:00:00:20: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:0F:00:00:00:00:00:00:00:94:00:00:00:00:00:00:00:0F:00:00:00:00:00:00:00:01:00:00:00:80:00:00:00:00:00:00:00:00:00:00:00:88:00:00:00:00:00:00:00:02:00:00:00:8C:00:00:00:00:00:00:00:00:00:00:00:DC:05: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: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:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:00:1E:00:00:00:0A:EA:EB:1E:0A:EA:EB:1D:0A:4A:D2:D2:0A:4A:D2:D3
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> Header:
>>>>>>   length      = 196
>>>>>>   type        = command-done (0x80000003)
>>>>>>   transaction = 32
>>>>>> Fragment header:
>>>>>>   total   = 1
>>>>>>   current = 0
>>>>>> Contents:
>>>>>>   status error = 'None' (0x00000000)
>>>>>>   service      = 'basic-connect' (a289cc33-bcbb-8b4f-b6b0-133ec2aae6df)
>>>>>>   cid          = 'ip-configuration' (0x0000000f)
<debug> [1457539877.865366] [mm-bearer-mbim.c:212] ip_configuration_query_ready(): IPv4 configuration available: 'address, gateway, dns, mtu'
<debug> [1457539877.865383] [mm-bearer-mbim.c:218] ip_configuration_query_ready():   IP addresses (1)
<debug> [1457539877.865605] [mm-bearer-mbim.c:222] ip_configuration_query_ready():     IP [0]: '10.234.235.30/30'
<debug> [1457539877.865638] [mm-bearer-mbim.c:231] ip_configuration_query_ready():   Gateway: '10.234.235.29'
<debug> [1457539877.865649] [mm-bearer-mbim.c:239] ip_configuration_query_ready():   DNS addresses (2)
<debug> [1457539877.865672] [mm-bearer-mbim.c:244] ip_configuration_query_ready():     DNS [0]: '10.74.210.210'
<debug> [1457539877.865693] [mm-bearer-mbim.c:244] ip_configuration_query_ready():     DNS [1]: '10.74.210.211'
<debug> [1457539877.865704] [mm-bearer-mbim.c:252] ip_configuration_query_ready():   MTU: '1500'
<debug> [1457539877.865714] [mm-bearer-mbim.c:258] ip_configuration_query_ready(): IPv6 configuration available: 'none'
<debug> [1457539877.865838] [mm-port.c:95] mm_port_set_connected(): (wwan0): port now connected
<debug> [1457539877.865884] [mm-base-bearer.c:488] connect_ready(): Connected bearer '/org/freedesktop/ModemManager1/Bearer/0'
<info>  [1457539877.866175] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
<info>  [1457539877.866631] [mm-iface-modem-simple.c:602] connection_step(): Simple connect state (8/8): All done
<debug> [1457539937.066309] [mm-iface-modem.c:1101] expire_signal_quality(): Signal quality value not updated in 60s, marking as not being recent
-------------- next part --------------
A non-text attachment was scrubbed...
Name: usbmon1.pcap
Type: application/vnd.tcpdump.pcap
Size: 37910 bytes
Desc: not available
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20160310/b77b83a4/attachment-0001.pcap>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 198 bytes
Desc: OpenPGP digital signature
URL: <https://lists.freedesktop.org/archives/modemmanager-devel/attachments/20160310/b77b83a4/attachment-0001.sig>


More information about the ModemManager-devel mailing list