Getting ICCID from locked qmi modem

Andreas Fett andreas.fett at secunet.com
Fri Nov 7 05:34:34 PST 2014


Hi,

We are trying to identify sim cards to send stored pin information and 
unlock them via the ModemManager DBus interface.

For some systems this works, but unfortunately ModemManger won't display 
any sim identification for a locked Gobi2000 based card.

With the qmicli debug tool we can however read the ICCID from the card 
even when it is locked.

Is this a Bug or just not implemented?

Attached you will find output from mmcli, the corresponding ModemManager 
debug logs and from qmicli (same modem State but without ModemManager 
running).

We use unmodified sources from the git repos ModemManger tag 1.4.0
and libqmi tag 1.10.2

Gruesse
Andreas


-------------- next part --------------
# mmcli -m 0
/org/freedesktop/ModemManager1/Modem/0 (device id 'dc8d3d26baefdd35a6f6cff49c0942d1fb432217')
  -------------------------
  Hardware |   manufacturer: 'Qualcomm Incorporated'
           |          model: 'Qualcomm Gobi 2000'
           |       revision: 'D1025-STUTABGD-3600  1  [Jan 14 2010 14:00:00]'
           |      supported: 'gsm-umts'
           |        current: 'gsm-umts'
           |   equipment id: '353093033456136'
  -------------------------
  System   |         device: '/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4'
           |        drivers: 'qcserial, qmi_wwan'
           |         plugin: 'Gobi'
           |   primary port: 'cdc-wdm0'
           |          ports: 'ttyUSB0 (qcdm), ttyUSB1 (at), cdc-wdm0 (qmi), wwan0 (net)'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'sim-pin'
           | unlock retries: 'sim-pin (3), sim-pin2 (2), sim-puk (10), sim-puk2 (10)'
           |          state: 'locked'
           |    power state: 'on'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: 'allowed: 2g; preferred: none
           |                  allowed: 3g; preferred: none
           |                  allowed: 2g, 3g; preferred: none
           |                  allowed: 2g, 3g; preferred: 2g
           |                  allowed: 2g, 3g; preferred: 3g'
           |        current: 'allowed: any; preferred: none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  IP       |      supported: 'ipv4, ipv6, ipv4v6'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'

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

-------------- next part --------------
# mmcli -i 0
SIM '/org/freedesktop/ModemManager1/SIM/0'
  -------------------------
  Properties |          imsi : 'unknown'
             |            id : 'unknown'
             |   operator id : 'unknown'
             | operator name : 'unknown'
-------------- next part --------------
<info>  [1415360799.731542] [main.c:140] main(): ModemManager (version 1.4.0) starting in system bus...
<debug> [1415360799.843511] [main.c:65] bus_acquired_cb(): Bus acquired, creating manager...
<debug> [1415360799.878907] [mm-plugin-manager.c:852] load_plugins(): Looking for plugins in '/usr/lib/ModemManager'
<debug> [1415360799.901862] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Altair LTE'
<debug> [1415360799.905789] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'AnyDATA'
<debug> [1415360799.912006] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Cinterion'
<debug> [1415360799.916295] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Generic'
<debug> [1415360799.916470] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Gobi'
<debug> [1415360799.924255] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Option High-Speed'
<debug> [1415360799.929784] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Huawei'
<debug> [1415360799.932713] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Iridium'
<debug> [1415360799.932898] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Linktop'
<debug> [1415360799.933852] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Longcheer'
<debug> [1415360799.938904] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Ericsson MBM'
<debug> [1415360799.945990] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Motorola'
<debug> [1415360799.946293] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'MTK'
<debug> [1415360799.954142] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Nokia (Icera)'
<debug> [1415360799.954336] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Nokia'
<debug> [1415360799.961749] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Novatel LTE'
<debug> [1415360799.961968] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Novatel'
<debug> [1415360799.962173] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Option'
<debug> [1415360799.967331] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Pantech'
<debug> [1415360799.967549] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Samsung'
<debug> [1415360799.974653] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Sierra'
<debug> [1415360799.979095] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'SimTech'
<debug> [1415360799.979870] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Telit'
<debug> [1415360799.980581] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Via CBP7'
<debug> [1415360799.980794] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'Wavecom'
<debug> [1415360799.988375] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'X22X'
<debug> [1415360799.989470] [mm-plugin-manager.c:877] load_plugins(): Loaded plugin 'ZTE'
<debug> [1415360799.989489] [mm-plugin-manager.c:902] load_plugins(): Successfully loaded 27 plugins
<debug> [1415360799.990058] [main.c:87] name_acquired_cb(): Service name 'org.freedesktop.ModemManager1' was acquired
<debug> [1415360799.990068] [mm-base-manager.c:479] mm_base_manager_start(): Starting automatic device scan...
<debug> [1415360799.993095] [mm-base-manager.c:518] mm_base_manager_start(): Finished device scan...
<debug> [1415360800.001726] [mm-plugin-manager.c:739] mm_plugin_manager_find_device_support(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:16.3] Checking device support...
<debug> [1415360800.001819] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001828] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001835] [mm-plugin.c:253] apply_pre_probing_filters(): (Gobi) [ttyS0] filtered by drivers
<debug> [1415360800.001840] [mm-plugin.c:253] apply_pre_probing_filters(): (Option High-Speed) [ttyS0] filtered by drivers
<debug> [1415360800.001844] [mm-plugin.c:326] apply_pre_probing_filters(): (Huawei) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001850] [mm-plugin.c:326] apply_pre_probing_filters(): (Linktop) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001858] [mm-plugin.c:326] apply_pre_probing_filters(): (Longcheer) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001864] [mm-plugin.c:380] apply_pre_probing_filters(): (Ericsson MBM) [ttyS0] filtered by udev tags
<debug> [1415360800.001869] [mm-plugin.c:326] apply_pre_probing_filters(): (Motorola) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001875] [mm-plugin.c:380] apply_pre_probing_filters(): (MTK) [ttyS0] filtered by udev tags
<debug> [1415360800.001879] [mm-plugin.c:326] apply_pre_probing_filters(): (Nokia (Icera)) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001884] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel LTE) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001889] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001893] [mm-plugin.c:253] apply_pre_probing_filters(): (Option) [ttyS0] filtered by drivers
<debug> [1415360800.001897] [mm-plugin.c:326] apply_pre_probing_filters(): (Pantech) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001902] [mm-plugin.c:326] apply_pre_probing_filters(): (Samsung) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001906] [mm-plugin.c:253] apply_pre_probing_filters(): (Sierra) [ttyS0] filtered by drivers
<debug> [1415360800.001910] [mm-plugin.c:326] apply_pre_probing_filters(): (SimTech) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001914] [mm-plugin.c:326] apply_pre_probing_filters(): (Telit) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001919] [mm-plugin.c:326] apply_pre_probing_filters(): (Wavecom) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001923] [mm-plugin.c:326] apply_pre_probing_filters(): (X22X) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001926] [mm-plugin.c:326] apply_pre_probing_filters(): (ZTE) [ttyS0] filtered by vendor/product IDs
<debug> [1415360800.001930] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [ttyS0] Found '5' plugins to try...
<debug> [1415360800.001935] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyS0]   Will try with plugin 'Cinterion'
<debug> [1415360800.001939] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyS0]   Will try with plugin 'Iridium'
<debug> [1415360800.001942] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyS0]   Will try with plugin 'Nokia'
<debug> [1415360800.001946] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyS0]   Will try with plugin 'Via CBP7'
<debug> [1415360800.001950] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyS0]   Will try with plugin 'Generic'
<debug> [1415360800.001969] [mm-plugin.c:767] mm_plugin_supports_port(): (Cinterion) [ttyS0] probe required: 'at, at-vendor'
<debug> [1415360800.001981] [mm-port-probe.c:1353] mm_port_probe_run(): (tty/ttyS0) launching port probing: 'at, at-vendor'
<debug> [1415360800.002261] [mm-plugin-manager.c:739] mm_plugin_manager_find_device_support(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4] Checking device support...
<debug> [1415360800.002297] [mm-device.c:316] mm_device_grab_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) could not get vendor/product ID
<debug> [1415360800.002320] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [ttyUSB0] filtered by vendor/product IDs
<debug> [1415360800.002326] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [ttyUSB0] filtered by vendor/product IDs
<debug> [1415360800.002334] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [ttyUSB0] Found '2' plugins to try...
<debug> [1415360800.002338] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyUSB0]   Will try with plugin 'Gobi'
<debug> [1415360800.002342] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyUSB0]   Will try with plugin 'Generic'
<debug> [1415360800.002353] [mm-plugin.c:767] mm_plugin_supports_port(): (Gobi) [ttyUSB0] probe required: 'at, qcdm'
<debug> [1415360800.002361] [mm-port-probe.c:1353] mm_port_probe_run(): (tty/ttyUSB0) launching port probing: 'at, qcdm'
<debug> [1415360800.002622] [mm-device.c:316] mm_device_grab_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) could not get vendor/product ID
<debug> [1415360800.002648] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [ttyUSB1] filtered by vendor/product IDs
<debug> [1415360800.002653] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [ttyUSB1] filtered by vendor/product IDs
<debug> [1415360800.002659] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [ttyUSB1] Found '2' plugins to try...
<debug> [1415360800.002663] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyUSB1]   Will try with plugin 'Gobi'
<debug> [1415360800.002667] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyUSB1]   Will try with plugin 'Generic'
<debug> [1415360800.002675] [mm-plugin.c:767] mm_plugin_supports_port(): (Gobi) [ttyUSB1] probe required: 'at, qcdm'
<debug> [1415360800.002682] [mm-port-probe.c:1353] mm_port_probe_run(): (tty/ttyUSB1) launching port probing: 'at, qcdm'
<debug> [1415360800.002943] [mm-device.c:316] mm_device_grab_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) could not get vendor/product ID
<debug> [1415360800.002966] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [ttyUSB2] filtered by vendor/product IDs
<debug> [1415360800.002972] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [ttyUSB2] filtered by vendor/product IDs
<debug> [1415360800.002978] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [ttyUSB2] Found '2' plugins to try...
<debug> [1415360800.002982] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyUSB2]   Will try with plugin 'Gobi'
<debug> [1415360800.002986] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [ttyUSB2]   Will try with plugin 'Generic'
<debug> [1415360800.002994] [mm-plugin.c:767] mm_plugin_supports_port(): (Gobi) [ttyUSB2] probe required: 'at, qcdm'
<debug> [1415360800.003018] [mm-port-probe.c:1353] mm_port_probe_run(): (tty/ttyUSB2) launching port probing: 'at, qcdm'
<debug> [1415360800.003143] [mm-base-manager.c:314] device_added(): (tty/ttyS1): port's parent platform driver is not whitelisted
<debug> [1415360800.003259] [mm-base-manager.c:314] device_added(): (tty/ttyS2): port's parent platform driver is not whitelisted
<debug> [1415360800.003374] [mm-base-manager.c:314] device_added(): (tty/ttyS3): port's parent platform driver is not whitelisted
<debug> [1415360800.003599] [mm-base-manager.c:290] device_added(): (tty/ptyp0): could not get port's parent device
<debug> [1415360800.003673] [mm-base-manager.c:290] device_added(): (tty/ptyp1): could not get port's parent device
<debug> [1415360800.003745] [mm-base-manager.c:290] device_added(): (tty/ptyp2): could not get port's parent device
<debug> [1415360800.003817] [mm-base-manager.c:290] device_added(): (tty/ptyp3): could not get port's parent device
<debug> [1415360800.003888] [mm-base-manager.c:290] device_added(): (tty/ptyp4): could not get port's parent device
<debug> [1415360800.003957] [mm-base-manager.c:290] device_added(): (tty/ptyp5): could not get port's parent device
<debug> [1415360800.004038] [mm-base-manager.c:290] device_added(): (tty/ptyp6): could not get port's parent device
<debug> [1415360800.004112] [mm-base-manager.c:290] device_added(): (tty/ptyp7): could not get port's parent device
<debug> [1415360800.004735] [mm-base-manager.c:290] device_added(): (tty/ttyp0): could not get port's parent device
<debug> [1415360800.004808] [mm-base-manager.c:290] device_added(): (tty/ttyp1): could not get port's parent device
<debug> [1415360800.004884] [mm-base-manager.c:290] device_added(): (tty/ttyp2): could not get port's parent device
<debug> [1415360800.004960] [mm-base-manager.c:290] device_added(): (tty/ttyp3): could not get port's parent device
<debug> [1415360800.005044] [mm-base-manager.c:290] device_added(): (tty/ttyp4): could not get port's parent device
<debug> [1415360800.005118] [mm-base-manager.c:290] device_added(): (tty/ttyp5): could not get port's parent device
<debug> [1415360800.005190] [mm-base-manager.c:290] device_added(): (tty/ttyp6): could not get port's parent device
<debug> [1415360800.005261] [mm-base-manager.c:290] device_added(): (tty/ttyp7): could not get port's parent device
<debug> [1415360800.005391] [mm-plugin-manager.c:739] mm_plugin_manager_find_device_support(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:19.0] Checking device support...
<debug> [1415360800.005432] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005439] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005443] [mm-plugin.c:326] apply_pre_probing_filters(): (Cinterion) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005447] [mm-plugin.c:253] apply_pre_probing_filters(): (Gobi) [eth0-link] filtered by drivers
<debug> [1415360800.005451] [mm-plugin.c:253] apply_pre_probing_filters(): (Option High-Speed) [eth0-link] filtered by drivers
<debug> [1415360800.005455] [mm-plugin.c:326] apply_pre_probing_filters(): (Huawei) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005459] [mm-plugin.c:212] apply_pre_probing_filters(): (Iridium) [eth0-link] filtered by subsystem
<debug> [1415360800.005463] [mm-plugin.c:212] apply_pre_probing_filters(): (Linktop) [eth0-link] filtered by subsystem
<debug> [1415360800.005467] [mm-plugin.c:212] apply_pre_probing_filters(): (Longcheer) [eth0-link] filtered by subsystem
<debug> [1415360800.005471] [mm-plugin.c:380] apply_pre_probing_filters(): (Ericsson MBM) [eth0-link] filtered by udev tags
<debug> [1415360800.005475] [mm-plugin.c:212] apply_pre_probing_filters(): (Motorola) [eth0-link] filtered by subsystem
<debug> [1415360800.005479] [mm-plugin.c:212] apply_pre_probing_filters(): (MTK) [eth0-link] filtered by subsystem
<debug> [1415360800.005483] [mm-plugin.c:326] apply_pre_probing_filters(): (Nokia (Icera)) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005486] [mm-plugin.c:212] apply_pre_probing_filters(): (Nokia) [eth0-link] filtered by subsystem
<debug> [1415360800.005490] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel LTE) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005494] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005498] [mm-plugin.c:212] apply_pre_probing_filters(): (Option) [eth0-link] filtered by subsystem
<debug> [1415360800.005502] [mm-plugin.c:326] apply_pre_probing_filters(): (Pantech) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005506] [mm-plugin.c:326] apply_pre_probing_filters(): (Samsung) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005510] [mm-plugin.c:253] apply_pre_probing_filters(): (Sierra) [eth0-link] filtered by drivers
<debug> [1415360800.005513] [mm-plugin.c:212] apply_pre_probing_filters(): (SimTech) [eth0-link] filtered by subsystem
<debug> [1415360800.005517] [mm-plugin.c:212] apply_pre_probing_filters(): (Telit) [eth0-link] filtered by subsystem
<debug> [1415360800.005521] [mm-plugin.c:212] apply_pre_probing_filters(): (Via CBP7) [eth0-link] filtered by subsystem
<debug> [1415360800.005525] [mm-plugin.c:212] apply_pre_probing_filters(): (Wavecom) [eth0-link] filtered by subsystem
<debug> [1415360800.005528] [mm-plugin.c:326] apply_pre_probing_filters(): (X22X) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005532] [mm-plugin.c:326] apply_pre_probing_filters(): (ZTE) [eth0-link] filtered by vendor/product IDs
<debug> [1415360800.005536] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [eth0-link] Found '1' plugins to try...
<debug> [1415360800.005540] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [eth0-link]   Will try with plugin 'Generic'
<debug> [1415360800.005549] [mm-plugin.c:689] mm_plugin_supports_port(): (Generic) [eth0-link] probing deferred until result suggested
<debug> [1415360800.005688] [mm-plugin-manager.c:739] mm_plugin_manager_find_device_support(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0] Checking device support...
<debug> [1415360800.005751] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005758] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005763] [mm-plugin.c:326] apply_pre_probing_filters(): (Cinterion) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005767] [mm-plugin.c:253] apply_pre_probing_filters(): (Gobi) [wlan0] filtered by drivers
<debug> [1415360800.005771] [mm-plugin.c:253] apply_pre_probing_filters(): (Option High-Speed) [wlan0] filtered by drivers
<debug> [1415360800.005775] [mm-plugin.c:326] apply_pre_probing_filters(): (Huawei) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005779] [mm-plugin.c:212] apply_pre_probing_filters(): (Iridium) [wlan0] filtered by subsystem
<debug> [1415360800.005782] [mm-plugin.c:212] apply_pre_probing_filters(): (Linktop) [wlan0] filtered by subsystem
<debug> [1415360800.005786] [mm-plugin.c:212] apply_pre_probing_filters(): (Longcheer) [wlan0] filtered by subsystem
<debug> [1415360800.005791] [mm-plugin.c:380] apply_pre_probing_filters(): (Ericsson MBM) [wlan0] filtered by udev tags
<debug> [1415360800.005795] [mm-plugin.c:212] apply_pre_probing_filters(): (Motorola) [wlan0] filtered by subsystem
<debug> [1415360800.005798] [mm-plugin.c:212] apply_pre_probing_filters(): (MTK) [wlan0] filtered by subsystem
<debug> [1415360800.005802] [mm-plugin.c:326] apply_pre_probing_filters(): (Nokia (Icera)) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005806] [mm-plugin.c:212] apply_pre_probing_filters(): (Nokia) [wlan0] filtered by subsystem
<debug> [1415360800.005810] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel LTE) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005814] [mm-plugin.c:326] apply_pre_probing_filters(): (Novatel) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005818] [mm-plugin.c:212] apply_pre_probing_filters(): (Option) [wlan0] filtered by subsystem
<debug> [1415360800.005821] [mm-plugin.c:326] apply_pre_probing_filters(): (Pantech) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005825] [mm-plugin.c:326] apply_pre_probing_filters(): (Samsung) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005829] [mm-plugin.c:253] apply_pre_probing_filters(): (Sierra) [wlan0] filtered by drivers
<debug> [1415360800.005833] [mm-plugin.c:212] apply_pre_probing_filters(): (SimTech) [wlan0] filtered by subsystem
<debug> [1415360800.005837] [mm-plugin.c:212] apply_pre_probing_filters(): (Telit) [wlan0] filtered by subsystem
<debug> [1415360800.005840] [mm-plugin.c:212] apply_pre_probing_filters(): (Via CBP7) [wlan0] filtered by subsystem
<debug> [1415360800.005844] [mm-plugin.c:212] apply_pre_probing_filters(): (Wavecom) [wlan0] filtered by subsystem
<debug> [1415360800.005848] [mm-plugin.c:326] apply_pre_probing_filters(): (X22X) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005852] [mm-plugin.c:326] apply_pre_probing_filters(): (ZTE) [wlan0] filtered by vendor/product IDs
<debug> [1415360800.005856] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [wlan0] Found '1' plugins to try...
<debug> [1415360800.005860] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [wlan0]   Will try with plugin 'Generic'
<debug> [1415360800.005866] [mm-plugin.c:689] mm_plugin_supports_port(): (Generic) [wlan0] probing deferred until result suggested
<debug> [1415360800.006112] [mm-plugin.c:326] apply_pre_probing_filters(): (Altair LTE) [wwan0] filtered by vendor/product IDs
<debug> [1415360800.006119] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [wwan0] filtered by vendor/product IDs
<debug> [1415360800.006127] [mm-plugin.c:326] apply_pre_probing_filters(): (Cinterion) [wwan0] filtered by vendor/product IDs
<debug> [1415360800.006132] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [wwan0] Found '2' plugins to try...
<debug> [1415360800.006136] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [wwan0]   Will try with plugin 'Gobi'
<debug> [1415360800.006140] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [wwan0]   Will try with plugin 'Generic'
<debug> [1415360800.006145] [mm-plugin.c:689] mm_plugin_supports_port(): (Gobi) [wwan0] probing deferred until result suggested
<debug> [1415360800.006225] [mm-base-manager.c:290] device_added(): (net/eth0): could not get port's parent device
<debug> [1415360800.006297] [mm-base-manager.c:290] device_added(): (net/ipsec0): could not get port's parent device
<debug> [1415360800.006369] [mm-base-manager.c:290] device_added(): (net/ipsec1): could not get port's parent device
<debug> [1415360800.006439] [mm-base-manager.c:290] device_added(): (net/ipsec2): could not get port's parent device
<debug> [1415360800.006510] [mm-base-manager.c:290] device_added(): (net/ipsec3): could not get port's parent device
<debug> [1415360800.006643] [mm-base-manager.c:290] device_added(): (net/tap0): could not get port's parent device
<debug> [1415360800.006714] [mm-base-manager.c:290] device_added(): (net/tap1): could not get port's parent device
<debug> [1415360800.006785] [mm-base-manager.c:290] device_added(): (net/tap2): could not get port's parent device
<debug> [1415360800.006855] [mm-base-manager.c:290] device_added(): (net/tap3): could not get port's parent device
<debug> [1415360800.006925] [mm-base-manager.c:290] device_added(): (net/tap4): could not get port's parent device
<debug> [1415360800.006996] [mm-base-manager.c:290] device_added(): (net/tap5): could not get port's parent device
<debug> [1415360800.007235] [mm-plugin.c:212] apply_pre_probing_filters(): (Altair LTE) [cdc-wdm0] filtered by subsystem
<debug> [1415360800.007243] [mm-plugin.c:326] apply_pre_probing_filters(): (AnyDATA) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1415360800.007248] [mm-plugin.c:326] apply_pre_probing_filters(): (Cinterion) [cdc-wdm0] filtered by vendor/product IDs
<debug> [1415360800.007253] [mm-plugin-manager.c:640] build_plugins_list(): (Plugin Manager) [cdc-wdm0] Found '2' plugins to try...
<debug> [1415360800.007257] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [cdc-wdm0]   Will try with plugin 'Gobi'
<debug> [1415360800.007261] [mm-plugin-manager.c:644] build_plugins_list(): (Plugin Manager) [cdc-wdm0]   Will try with plugin 'Generic'
<debug> [1415360800.007270] [mm-plugin.c:767] mm_plugin_supports_port(): (Gobi) [cdc-wdm0] probe required: 'qmi'
<debug> [1415360800.007276] [mm-port-probe.c:1353] mm_port_probe_run(): (usbmisc/cdc-wdm0) launching port probing: 'qmi'
<debug> [1415360800.007300] [mm-plugin-manager.c:569] plugin_supports_port_ready(): (Plugin Manager) [eth0-link] deferring support check until result suggested
<debug> [1415360800.007309] [mm-plugin-manager.c:569] plugin_supports_port_ready(): (Plugin Manager) [wlan0] deferring support check until result suggested
<debug> [1415360800.007315] [mm-plugin-manager.c:569] plugin_supports_port_ready(): (Plugin Manager) [wwan0] deferring support check until result suggested
<debug> [1415360800.007510] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyS0) opening serial port...
<debug> [1415360800.007723] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyS0) device open count is 1 (open)
<debug> [1415360800.007820] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyUSB0) opening serial port...
<warn>  [1415360800.007876] [mm-port-serial.c:515] real_config_fd(): (ttyUSB0): port attributes not fully set
<debug> [1415360800.007889] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB0) device open count is 1 (open)
<debug> [1415360800.007966] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyUSB1) opening serial port...
<warn>  [1415360800.008025] [mm-port-serial.c:515] real_config_fd(): (ttyUSB1): port attributes not fully set
<debug> [1415360800.008042] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB1) device open count is 1 (open)
<debug> [1415360800.008117] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyUSB2) opening serial port...
<warn>  [1415360800.008159] [mm-port-serial.c:515] real_config_fd(): (ttyUSB2): port attributes not fully set
<debug> [1415360800.008176] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
<debug> [1415360800.008193] [mm-port-probe.c:456] wdm_probe_qmi(): (usbmisc/cdc-wdm0) probing QMI...
[/dev/cdc-wdm0] Opening device with flags 'version-info, proxy'...cannot connect to proxy: Could not connect: Connection refusedspawning new qmi-proxy (try 1)...<debug> [1415360800.108741] [mm-port-serial-at.c:440] debug_log(): (ttyS0): --> 'AT^SQPORT?<CR>'
<debug> [1415360800.108788] [mm-port-serial-at.c:440] debug_log(): (ttyUSB0): --> 'AT<CR>'
<debug> [1415360800.108807] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'AT<CR>'
<debug> [1415360800.108816] [mm-port-serial-at.c:440] debug_log(): (ttyUSB2): --> 'AT<CR>'
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 28
<<<<<<   data   = 01:1B:00:00:00:00:00:01:00:FF:10:00:01:0D:00:2F:64:65:76:2F:63:64:63:2D:77:64:6D:30
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 27
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 16
<<<<<<   message     = "Internal Proxy Open" (0xFF00)
<<<<<< TLV:
<<<<<<   type       = "Device Path" (0x01)
<<<<<<   length     = 13
<<<<<<   value      = 2F:64:65:76:2F:63:64:63:2D:77:64:6D:30
<<<<<<   translated = /dev/cdc-wdm0
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 19
>>>>>>   data   = 01:12:00:00:00:00:01:01:00:FF:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 18
>>>>>>   flags   = 0x00
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 7
>>>>>>   message     = "Internal Proxy Open" (0xFF00)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
[/dev/cdc-wdm0] Checking version info (10 retries)...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 12
<<<<<<   data   = 01:0B:00:00:00:00:00:02:21:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 11
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 2
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Version Info" (0x0021)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 116
>>>>>>   data   = 01:73:00:80:00:00:01:02:21:00:68:00:02:04:00:00:00:00:00:01:2E:00:09:00:01:00:03:00:01:01:00:02:00:02:01:00:01:00:03:01:00:00:00:05:01:00:00:00:06:01:00:00:00:07:01:00:00:00:E0:01:00:00:00:E1:01:00:00:00:10:2D:00:08:55:4E:44:50:20:31:2E:30:07:01:02:00:01:00:02:02:00:01:00:03:02:00:01:00:05:02:00:00:00:06:02:00:01:00:E0:02:00:00:00:E1:02:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 115
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 2
>>>>>>   tlv_length  = 104
>>>>>>   message     = "Get Version Info" (0x0021)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Service list" (0x01)
>>>>>>   length     = 46
>>>>>>   value      = 09:00:01:00:03:00:01:01:00:02:00:02:01:00:01:00:03:01:00:00:00:05:01:00:00:00:06:01:00:00:00:07:01:00:00:00:E0:01:00:00:00:E1:01:00:00:00
>>>>>>   translated = { [0] = '[ service = 'ctl' major_version = '1' minor_version = '3' ] ' [1] = '[ service = 'wds' major_version = '1' minor_version = '2' ] ' [2] = '[ service = 'dms' major_version = '1' minor_version = '1' ] ' [3] = '[ service = 'nas' major_version = '1' minor_version = '0' ] ' [4] = '[ service = 'wms' major_version = '1' minor_version = '0' ] ' [5] = '[ service = 'pds' major_version = '1' minor_version = '0' ] ' [6] = '[ service = 'auth' major_version = '1' minor_version = '0' ] ' [7] = '[ service = 'cat' major_version = '1' minor_version = '0' ] ' [8] = '[ service = 'rms' major_version = '1' minor_version = '0' ] '}
>>>>>> TLV:
>>>>>>   type   = 0x10
>>>>>>   length = 45
>>>>>>   value  = 08:55:4E:44:50:20:31:2E:30:07:01:02:00:01:00:02:02:00:01:00:03:02:00:01:00:05:02:00:00:00:06:02:00:01:00:E0:02:00:00:00:E1:02:00:00:00
[/dev/cdc-wdm0] QMI Device supports 9 services:[/dev/cdc-wdm0]    ctl (1.3)[/dev/cdc-wdm0]    wds (1.2)[/dev/cdc-wdm0]    dms (1.1)[/dev/cdc-wdm0]    nas (1.0)[/dev/cdc-wdm0]    wms (1.0)[/dev/cdc-wdm0]    pds (1.0)[/dev/cdc-wdm0]    auth (1.0)[/dev/cdc-wdm0]    cat (1.0)[/dev/cdc-wdm0]    rms (1.0)<debug> [1415360800.165796] [mm-port-probe.c:271] mm_port_probe_set_result_qmi(): (usbmisc/cdc-wdm0) port is QMI-capable
<debug> [1415360800.308895] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- 'AT'
<debug> [1415360800.308977] [mm-plugin-manager.c:462] plugin_supports_port_ready(): (Plugin Manager) (Gobi) [cdc-wdm0] found best plugin for port
<debug> [1415360800.308984] [mm-plugin-manager.c:232] port_probe_context_finished(): (Plugin Manager) (Gobi) [cdc-wdm0]: found best plugin for device (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4)
<debug> [1415360800.309009] [mm-plugin-manager.c:361] suggest_single_port_probe_result(): (Plugin Manager) (Gobi) [wwan0] deferred task completed, got suggested plugin
<debug> [1415360800.309023] [mm-plugin-manager.c:407] suggest_single_port_probe_result(): (Plugin Manager) (Gobi) [ttyUSB2] suggested plugin for port
<debug> [1415360800.309027] [mm-plugin-manager.c:407] suggest_single_port_probe_result(): (Plugin Manager) (Gobi) [ttyUSB1] suggested plugin for port
<debug> [1415360800.309030] [mm-plugin-manager.c:407] suggest_single_port_probe_result(): (Plugin Manager) (Gobi) [ttyUSB0] suggested plugin for port
<debug> [1415360800.309036] [mm-plugin-manager.c:305] port_probe_context_finished(): (Plugin Manager) 'cdc-wdm0' port probe finished, still 4 running probes in this device (wwan0, ttyUSB2, ttyUSB1, ttyUSB0)
<debug> [1415360800.309058] [mm-plugin.c:689] mm_plugin_supports_port(): (Gobi) [wwan0] probing deferred until result suggested
<debug> [1415360800.309068] [mm-plugin-manager.c:549] plugin_supports_port_ready(): (Plugin Manager) (Gobi) [wwan0] task completed, got suggested plugin
<debug> [1415360800.309073] [mm-plugin-manager.c:305] port_probe_context_finished(): (Plugin Manager) 'wwan0' port probe finished, still 3 running probes in this device (ttyUSB2, ttyUSB1, ttyUSB0)
<debug> [1415360800.311990] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR>'
<debug> [1415360800.312421] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
<debug> [1415360800.312478] [mm-port-probe.c:152] mm_port_probe_set_result_at(): (tty/ttyUSB1) port is AT-capable
<debug> [1415360800.312506] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB1) device open count is 0 (close)
<debug> [1415360800.312513] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyUSB1) closing serial port...
<debug> [1415360800.313652] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyUSB1) serial port closed
<debug> [1415360800.313664] [mm-port-serial.c:1415] port_serial_close_force(): (ttyUSB1) forced to close port
<debug> [1415360800.313703] [mm-plugin-manager.c:462] plugin_supports_port_ready(): (Plugin Manager) (Gobi) [ttyUSB1] found best plugin for port
<debug> [1415360800.313711] [mm-plugin-manager.c:305] port_probe_context_finished(): (Plugin Manager) 'ttyUSB1' port probe finished, still 2 running probes in this device (ttyUSB2, ttyUSB0)
<debug> [1415360802.000533] [mm-plugin-manager.c:710] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:16.3] Minimum probing time consumed
<debug> [1415360802.000565] [mm-plugin-manager.c:710] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4] Minimum probing time consumed
<debug> [1415360802.000575] [mm-plugin-manager.c:710] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:19.0] Minimum probing time consumed
<debug> [1415360802.000586] [mm-plugin-manager.c:368] suggest_single_port_probe_result(): (Plugin Manager) [eth0-link] deferred task cancelled, no suggested plugin
<debug> [1415360802.000601] [mm-plugin-manager.c:710] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0] Minimum probing time consumed
<debug> [1415360802.000611] [mm-plugin-manager.c:368] suggest_single_port_probe_result(): (Plugin Manager) [wlan0] deferred task cancelled, no suggested plugin
<debug> [1415360802.000631] [mm-plugin-manager.c:195] port_probe_context_finished(): (Plugin Manager) [eth0-link] not supported by any plugin
<debug> [1415360802.000643] [mm-device.c:357] mm_device_ignore_port(): Fully ignoring port 'net/eth0-link' from now on
<debug> [1415360802.000651] [mm-plugin-manager.c:316] port_probe_context_finished(): (Plugin Manager) 'eth0-link' port probe finished, last one in device
<debug> [1415360802.000665] [mm-plugin-manager.c:138] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:19.0] device support check finished in '1.995262' seconds
<warn>  [1415360802.000738] [mm-base-manager.c:153] find_device_support_ready(): Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:19.0': not supported by any plugin
<debug> [1415360802.000770] [mm-plugin-manager.c:195] port_probe_context_finished(): (Plugin Manager) [wlan0] not supported by any plugin
<debug> [1415360802.000777] [mm-device.c:357] mm_device_ignore_port(): Fully ignoring port 'net/wlan0' from now on
<debug> [1415360802.000783] [mm-plugin-manager.c:316] port_probe_context_finished(): (Plugin Manager) 'wlan0' port probe finished, last one in device
<debug> [1415360802.000788] [mm-plugin-manager.c:138] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0] device support check finished in '1.995087' seconds
<warn>  [1415360802.000799] [mm-base-manager.c:153] find_device_support_ready(): Couldn't find support for device at '/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0': not supported by any plugin
<debug> [1415360804.002160] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360804.002214] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360804.002298] [mm-port-serial-at.c:440] debug_log(): (ttyUSB0): --> 'AT<CR>'
<debug> [1415360804.002326] [mm-port-serial-at.c:440] debug_log(): (ttyUSB2): --> 'AT<CR>'
<debug> [1415360804.002342] [mm-port-serial-at.c:440] debug_log(): (ttyS0): --> 'AT<CR>'
<debug> [1415360807.003807] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360807.003865] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360807.003883] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360807.003930] [mm-port-serial-at.c:440] debug_log(): (ttyUSB0): --> 'AT<CR>'
<debug> [1415360807.003956] [mm-port-serial-at.c:440] debug_log(): (ttyUSB2): --> 'AT<CR>'
<debug> [1415360807.003971] [mm-port-serial-at.c:440] debug_log(): (ttyS0): --> 'AT<CR>'
<debug> [1415360810.003103] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360810.003130] [mm-port-probe.c:162] mm_port_probe_set_result_at(): (tty/ttyUSB0) port is not AT-capable
<debug> [1415360810.003165] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360810.003181] [mm-port-probe.c:162] mm_port_probe_set_result_at(): (tty/ttyUSB2) port is not AT-capable
<debug> [1415360810.003201] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360810.003219] [mm-port-probe.c:658] serial_probe_qcdm(): (tty/ttyUSB0) probing QCDM...
<debug> [1415360810.003230] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB0) device open count is 0 (close)
<debug> [1415360810.003236] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyUSB0) closing serial port...
<debug> [1415360810.005111] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyUSB0) serial port closed
<debug> [1415360810.005128] [mm-port-serial.c:1415] port_serial_close_force(): (ttyUSB0) forced to close port
<debug> [1415360810.005236] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyUSB0) opening serial port...
<debug> [1415360810.005324] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB0) device open count is 1 (open)
<debug> [1415360810.005353] [mm-port-probe.c:658] serial_probe_qcdm(): (tty/ttyUSB2) probing QCDM...
<debug> [1415360810.005362] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB2) device open count is 0 (close)
<debug> [1415360810.005368] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyUSB2) closing serial port...
<debug> [1415360810.006641] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyUSB2) serial port closed
<debug> [1415360810.006656] [mm-port-serial.c:1415] port_serial_close_force(): (ttyUSB2) forced to close port
<debug> [1415360810.006694] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyUSB2) opening serial port...
<debug> [1415360810.006756] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB2) device open count is 1 (open)
<debug> [1415360810.006797] [mm-port-serial-qcdm.c:201] debug_log(): (ttyUSB0): --> 7e 00 78 f0 7e
<debug> [1415360810.006821] [mm-port-serial-qcdm.c:201] debug_log(): (ttyUSB2): --> 7e 00 78 f0 7e
<debug> [1415360810.006834] [mm-port-serial-at.c:440] debug_log(): (ttyS0): --> 'AT<CR>'
<debug> [1415360810.008606] [mm-port-serial-qcdm.c:201] debug_log(): (ttyUSB0): <-- 00 4a 61 6e 20 31 34 20 32 30 31 30 31 35 3a 30 34 3a 35 33 4a 61 6e 20 31 34 20 32 30 31 30 31 34 3a 30 30 3a 30 30 53 54 55 54 41 42 47 44 00 00 0c 00 00 00 01 b2 7a 00 7e
<debug> [1415360810.008657] [mm-port-probe.c:240] mm_port_probe_set_result_qcdm(): (tty/ttyUSB0) port is QCDM-capable
<debug> [1415360810.008687] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB0) device open count is 0 (close)
<debug> [1415360810.008696] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyUSB0) closing serial port...
<debug> [1415360810.010342] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyUSB0) serial port closed
<debug> [1415360810.010358] [mm-port-serial.c:1415] port_serial_close_force(): (ttyUSB0) forced to close port
<debug> [1415360810.010397] [mm-plugin-manager.c:462] plugin_supports_port_ready(): (Plugin Manager) (Gobi) [ttyUSB0] found best plugin for port
<debug> [1415360810.010410] [mm-plugin-manager.c:305] port_probe_context_finished(): (Plugin Manager) 'ttyUSB0' port probe finished, still 1 running probes in this device (ttyUSB2)
<debug> [1415360813.003847] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
<debug> [1415360813.003867] [mm-port-probe.c:162] mm_port_probe_set_result_at(): (tty/ttyS0) port is not AT-capable
<debug> [1415360813.003901] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyS0) device open count is 0 (close)
<debug> [1415360813.003911] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyS0) closing serial port...
<debug> [1415360813.003994] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyS0) serial port closed
<debug> [1415360813.004054] [mm-port-serial.c:1415] port_serial_close_force(): (ttyS0) forced to close port
<debug> [1415360813.004084] [mm-plugin.c:429] apply_post_probing_filters(): (Cinterion) [ttyS0] filtered by vendor strings
<debug> [1415360813.004120] [mm-plugin.c:767] mm_plugin_supports_port(): (Iridium) [ttyS0] probe required: 'at, at-vendor, at-product'
<debug> [1415360813.004139] [mm-plugin.c:454] apply_post_probing_filters(): (Iridium) [ttyS0] filtered as no vendor/product strings given
<debug> [1415360813.004163] [mm-plugin.c:767] mm_plugin_supports_port(): (Nokia) [ttyS0] probe required: 'at, at-vendor, at-icera'
<debug> [1415360813.004178] [mm-plugin.c:429] apply_post_probing_filters(): (Nokia) [ttyS0] filtered by vendor strings
<debug> [1415360813.004198] [mm-plugin.c:767] mm_plugin_supports_port(): (Via CBP7) [ttyS0] probe required: 'at, at-vendor, at-product'
<debug> [1415360813.004213] [mm-plugin.c:454] apply_post_probing_filters(): (Via CBP7) [ttyS0] filtered as no vendor/product strings given
<debug> [1415360813.004230] [mm-plugin.c:767] mm_plugin_supports_port(): (Generic) [ttyS0] probe required: 'at, qcdm'
<debug> [1415360813.004238] [mm-port-probe.c:1353] mm_port_probe_run(): (tty/ttyS0) launching port probing: 'qcdm'
<debug> [1415360813.004255] [mm-port-serial-qcdm.c:201] debug_log(): (ttyUSB2): --> 7e 00 78 f0 7e
<debug> [1415360813.004275] [mm-port-probe.c:658] serial_probe_qcdm(): (tty/ttyS0) probing QCDM...
<debug> [1415360813.004375] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyS0) opening serial port...
<debug> [1415360813.004571] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyS0) device open count is 1 (open)
<debug> [1415360813.004600] [mm-port-serial-qcdm.c:201] debug_log(): (ttyS0): --> 7e 00 78 f0 7e
<debug> [1415360816.003739] [mm-port-probe.c:258] mm_port_probe_set_result_qcdm(): (tty/ttyUSB2) port is not QCDM-capable
<debug> [1415360816.003858] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB2) device open count is 0 (close)
<debug> [1415360816.003869] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyUSB2) closing serial port...
<debug> [1415360816.005037] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyUSB2) serial port closed
<debug> [1415360816.005045] [mm-port-serial.c:1415] port_serial_close_force(): (ttyUSB2) forced to close port
<debug> [1415360816.005065] [mm-plugin-manager.c:462] plugin_supports_port_ready(): (Plugin Manager) (Gobi) [ttyUSB2] found best plugin for port
<debug> [1415360816.005073] [mm-plugin-manager.c:316] port_probe_context_finished(): (Plugin Manager) 'ttyUSB2' port probe finished, last one in device
<debug> [1415360816.005078] [mm-plugin-manager.c:138] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4] device support check finished in '16.002802' seconds
<info>  [1415360816.005091] [mm-device.c:509] mm_device_create_modem(): Creating modem with plugin 'Gobi' and '5' ports
<debug> [1415360816.005106] [gobi/mm-plugin-gobi.c:49] create_modem(): QMI-powered Gobi modem found...
<debug> [1415360816.006019] [mm-base-modem.c:304] mm_base_modem_grab_port(): (cdc-wdm0) type 'qmi' claimed by /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4
<debug> [1415360816.006036] [mm-base-modem.c:304] mm_base_modem_grab_port(): (wwan0) type 'net' claimed by /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4
<warn>  [1415360816.006046] [mm-plugin.c:905] mm_plugin_create_modem(): Could not grab port (tty/ttyUSB2): 'Cannot add port 'tty/ttyUSB2', unhandled serial type'
<debug> [1415360816.006096] [mm-base-modem.c:304] mm_base_modem_grab_port(): (ttyUSB1) type 'at' claimed by /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4
<debug> [1415360816.006114] [mm-base-modem.c:304] mm_base_modem_grab_port(): (ttyUSB0) type 'qcdm' claimed by /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4
<debug> [1415360816.006121] [mm-base-modem.c:970] log_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) tty/ttyUSB1 at (primary)
<debug> [1415360816.006125] [mm-base-modem.c:970] log_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) net/wwan0 data (primary)
<debug> [1415360816.006127] [mm-base-modem.c:970] log_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) tty/ttyUSB0 qcdm
<debug> [1415360816.006130] [mm-base-modem.c:970] log_port(): (/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4) usb/cdc-wdm0 qmi (primary)
<info>  [1415360816.006394] [mm-base-manager.c:162] find_device_support_ready(): Modem for device at '/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4' successfully created
<debug> [1415360816.006422] [mm-port-serial-qcdm.c:201] debug_log(): (ttyS0): --> 7e 00 78 f0 7e
[/dev/cdc-wdm0] Opening device with flags 'version-info, net-802-3, net-no-qos-header, proxy'...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 28
<<<<<<   data   = 01:1B:00:00:00:00:00:01:00:FF:10:00:01:0D:00:2F:64:65:76:2F:63:64:63:2D:77:64:6D:30
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 27
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 16
<<<<<<   message     = "Internal Proxy Open" (0xFF00)
<<<<<< TLV:
<<<<<<   type       = "Device Path" (0x01)
<<<<<<   length     = 13
<<<<<<   value      = 2F:64:65:76:2F:63:64:63:2D:77:64:6D:30
<<<<<<   translated = /dev/cdc-wdm0
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 19
>>>>>>   data   = 01:12:00:00:00:00:01:01:00:FF:07:00:02:04:00:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 18
>>>>>>   flags   = 0x00
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 7
>>>>>>   message     = "Internal Proxy Open" (0xFF00)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
[/dev/cdc-wdm0] Checking version info (10 retries)...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 12
<<<<<<   data   = 01:0B:00:00:00:00:00:02:21:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 11
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 2
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Version Info" (0x0021)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 116
>>>>>>   data   = 01:73:00:80:00:00:01:02:21:00:68:00:02:04:00:00:00:00:00:01:2E:00:09:00:01:00:03:00:01:01:00:02:00:02:01:00:01:00:03:01:00:00:00:05:01:00:00:00:06:01:00:00:00:07:01:00:00:00:E0:01:00:00:00:E1:01:00:00:00:10:2D:00:08:55:4E:44:50:20:31:2E:30:07:01:02:00:01:00:02:02:00:01:00:03:02:00:01:00:05:02:00:00:00:06:02:00:01:00:E0:02:00:00:00:E1:02:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 115
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 2
>>>>>>   tlv_length  = 104
>>>>>>   message     = "Get Version Info" (0x0021)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Service list" (0x01)
>>>>>>   length     = 46
>>>>>>   value      = 09:00:01:00:03:00:01:01:00:02:00:02:01:00:01:00:03:01:00:00:00:05:01:00:00:00:06:01:00:00:00:07:01:00:00:00:E0:01:00:00:00:E1:01:00:00:00
>>>>>>   translated = { [0] = '[ service = 'ctl' major_version = '1' minor_version = '3' ] ' [1] = '[ service = 'wds' major_version = '1' minor_version = '2' ] ' [2] = '[ service = 'dms' major_version = '1' minor_version = '1' ] ' [3] = '[ service = 'nas' major_version = '1' minor_version = '0' ] ' [4] = '[ service = 'wms' major_version = '1' minor_version = '0' ] ' [5] = '[ service = 'pds' major_version = '1' minor_version = '0' ] ' [6] = '[ service = 'auth' major_version = '1' minor_version = '0' ] ' [7] = '[ service = 'cat' major_version = '1' minor_version = '0' ] ' [8] = '[ service = 'rms' major_version = '1' minor_version = '0' ] '}
>>>>>> TLV:
>>>>>>   type   = 0x10
>>>>>>   length = 45
>>>>>>   value  = 08:55:4E:44:50:20:31:2E:30:07:01:02:00:01:00:02:02:00:01:00:03:02:00:01:00:05:02:00:00:00:06:02:00:01:00:E0:02:00:00:00:E1:02:00:00:00
[/dev/cdc-wdm0] QMI Device supports 9 services:[/dev/cdc-wdm0]    ctl (1.3)[/dev/cdc-wdm0]    wds (1.2)[/dev/cdc-wdm0]    dms (1.1)[/dev/cdc-wdm0]    nas (1.0)[/dev/cdc-wdm0]    wms (1.0)[/dev/cdc-wdm0]    pds (1.0)[/dev/cdc-wdm0]    auth (1.0)[/dev/cdc-wdm0]    cat (1.0)[/dev/cdc-wdm0]    rms (1.0)[/dev/cdc-wdm0] Setting network port data format...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 21
<<<<<<   data   = 01:14:00:00:00:00:00:03:26:00:09:00:10:02:00:01:00:01:01:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 20
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 3
<<<<<<   tlv_length  = 9
<<<<<<   message     = "Set Data Format" (0x0026)
<<<<<< TLV:
<<<<<<   type       = "Protocol" (0x10)
<<<<<<   length     = 2
<<<<<<   value      = 01:00
<<<<<<   translated = 802-3
<<<<<< TLV:
<<<<<<   type       = "Format" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 00
<<<<<<   translated = absent
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:03:26:00:0C:00:02:04:00:00:00:00:00:10:02:00:01:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 3
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Set Data Format" (0x0026)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Protocol" (0x10)
>>>>>>   length     = 2
>>>>>>   value      = 01:00
>>>>>>   translated = 802-3
[/dev/cdc-wdm0] Network port data format operation finished[/dev/cdc-wdm0] Allocating new client ID...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:04:22:00:04:00:01:01:00:02
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 4
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 02
<<<<<<   translated = dms
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:04:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:01
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 4
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Allocate CID" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Allocation Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 02:01
>>>>>>   translated = [ service = 'dms' cid = '1' ]
[/dev/cdc-wdm0] Registered 'dms' (version 1.1) client with ID '1'[/dev/cdc-wdm0] Allocating new client ID...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:05:22:00:04:00:01:01:00:03
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 5
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 03
<<<<<<   translated = nas
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:05:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:03:01
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 5
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Allocate CID" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Allocation Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 03:01
>>>>>>   translated = [ service = 'nas' cid = '1' ]
[/dev/cdc-wdm0] Registered 'nas' (version 1.0) client with ID '1'[/dev/cdc-wdm0] Allocating new client ID...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:06:22:00:04:00:01:01:00:05
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 6
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 05
<<<<<<   translated = wms
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:06:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:05:01
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 6
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Allocate CID" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Allocation Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 05:01
>>>>>>   translated = [ service = 'wms' cid = '1' ]
[/dev/cdc-wdm0] Registered 'wms' (version 1.0) client with ID '1'[/dev/cdc-wdm0] Allocating new client ID...[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:07:22:00:04:00:01:01:00:06
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 7
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 06
<<<<<<   translated = pds
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:07:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:06:01
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 7
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Allocate CID" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Allocation Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 06:01
>>>>>>   translated = [ service = 'pds' cid = '1' ]
[/dev/cdc-wdm0] Registered 'pds' (version 1.0) client with ID '1'<debug> [1415360816.047639] [mm-broadband-modem-qmi.c:9995] qmi_port_allocate_client_ready(): Couldn't allocate client for service 'oma': Couldn't create client for service 'oma': Service 'oma' not supported by the device
<debug> [1415360816.047650] [mm-port-serial.c:1099] mm_port_serial_open(): (ttyUSB1) opening serial port...
<warn>  [1415360816.047768] [mm-port-serial.c:515] real_config_fd(): (ttyUSB1): port attributes not fully set
<debug> [1415360816.047787] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB1) device open count is 1 (open)
<debug> [1415360816.047791] [mm-port-serial-at.c:476] mm_port_serial_at_run_init_sequence(): (ttyUSB1): running init sequence...
<debug> [1415360816.047814] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB1) device open count is 2 (open)
<debug> [1415360816.047829] [mm-port-serial.c:1237] mm_port_serial_open(): (ttyUSB1) device open count is 3 (open)
<debug> [1415360816.048521] [mm-broadband-modem-qmi.c:531] modem_load_current_capabilities(): loading current capabilities...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:03:01:00:01:00:2B:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "nas"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Technology Preference" (0x002B)
<debug> [1415360816.048608] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'ATE0<CR>'
<debug> [1415360816.052782] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- 'A'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 26
>>>>>>   data   = 01:19:00:80:03:01:02:01:00:2B:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 25
>>>>>>   flags   = 0x80
>>>>>>   service = "nas"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 13
>>>>>>   message     = "Get Technology Preference" (0x002B)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Active" (0x01)
>>>>>>   length     = 3
>>>>>>   value      = 00:00:00
>>>>>>   translated = [ technology_preference = 'auto' technology_preference_duration = 'permanent' ]
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:01:00:20:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Capabilities" (0x0020)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 36
>>>>>>   data   = 01:23:00:80:02:01:02:01:00:20:00:17:00:02:04:00:00:00:00:00:01:0D:00:B0:9D:57:00:00:DD:6D:00:04:02:02:04:05
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 35
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 23
>>>>>>   message     = "Get Capabilities" (0x0020)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Info" (0x01)
>>>>>>   length     = 13
>>>>>>   value      = B0:9D:57:00:00:DD:6D:00:04:02:02:04:05
>>>>>>   translated = [ max_tx_channel_rate = '5742000' max_rx_channel_rate = '7200000' data_service_capability = 'non-simultaneous-cs-ps' sim_capability = 'supported' radio_interface_list = '{ [0] = 'gsm ' [1] = 'umts '}' ]
<debug> [1415360816.058034] [mm-modem-helpers-qmi.c:1268] mm_modem_capability_from_qmi_capabilities_context(): Current capabilities built: 'gsm-umts'
  SSP mode preference: 'unknown'
  TP: 'auto'
  DMS Capabilities: 'gsm-umts'
<debug> [1415360816.058076] [mm-broadband-modem-qmi.c:693] modem_load_supported_capabilities(): loading supported capabilities...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:02:00:20:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 2
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Capabilities" (0x0020)
<debug> [1415360816.058196] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- 'T'
<debug> [1415360816.059248] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- 'E'
<debug> [1415360816.059390] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '0<CR>'
<debug> [1415360816.059791] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
<debug> [1415360816.059820] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'ATV1<CR>'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 36
>>>>>>   data   = 01:23:00:80:02:01:02:02:00:20:00:17:00:02:04:00:00:00:00:00:01:0D:00:B0:9D:57:00:00:DD:6D:00:04:02:02:04:05
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 35
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 2
>>>>>>   tlv_length  = 23
>>>>>>   message     = "Get Capabilities" (0x0020)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Info" (0x01)
>>>>>>   length     = 13
>>>>>>   value      = B0:9D:57:00:00:DD:6D:00:04:02:02:04:05
>>>>>>   translated = [ max_tx_channel_rate = '5742000' max_rx_channel_rate = '7200000' data_service_capability = 'non-simultaneous-cs-ps' sim_capability = 'supported' radio_interface_list = '{ [0] = 'gsm ' [1] = 'umts '}' ]
<debug> [1415360816.062118] [mm-iface-modem.c:4327] interface_initialization_step(): Modem allows up to 1 bearers
<debug> [1415360816.062124] [mm-bearer-list.c:276] mm_bearer_list_new(): Creating bearer list (max: 1, max active: 1)
<debug> [1415360816.062155] [mm-broadband-modem-qmi.c:995] modem_load_manufacturer(): loading manufacturer...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:03:00:21:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 3
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Manufacturer" (0x0021)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 44
>>>>>>   data   = 01:2B:00:80:02:01:02:03:00:21:00:1F:00:02:04:00:00:00:00:00:01:15:00:51:75:61:6C:63:6F:6D:6D:20:49:6E:63:6F:72:70:6F:72:61:74:65:64
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 43
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 3
>>>>>>   tlv_length  = 31
>>>>>>   message     = "Get Manufacturer" (0x0021)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Manufacturer" (0x01)
>>>>>>   length     = 21
>>>>>>   value      = 51:75:61:6C:63:6F:6D:6D:20:49:6E:63:6F:72:70:6F:72:61:74:65:64
>>>>>>   translated = Qualcomm Incorporated
<debug> [1415360816.069737] [mm-broadband-modem-qmi.c:942] modem_load_manufacturer_finish(): loaded manufacturer: Qualcomm Incorporated
<debug> [1415360816.069758] [mm-broadband-modem-qmi.c:1071] modem_load_model(): loading model...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:04:00:22:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 4
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Model" (0x0022)
<debug> [1415360816.071910] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
<debug> [1415360816.071974] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'AT+CMEE=1<CR>'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 41
>>>>>>   data   = 01:28:00:80:02:01:02:04:00:22:00:1C:00:02:04:00:00:00:00:00:01:12:00:51:75:61:6C:63:6F:6D:6D:20:47:6F:62:69:20:32:30:30:30
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 40
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 4
>>>>>>   tlv_length  = 28
>>>>>>   message     = "Get Model" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Model" (0x01)
>>>>>>   length     = 18
>>>>>>   value      = 51:75:61:6C:63:6F:6D:6D:20:47:6F:62:69:20:32:30:30:30
>>>>>>   translated = Qualcomm Gobi 2000
<debug> [1415360816.077630] [mm-broadband-modem-qmi.c:1018] modem_load_model_finish(): loaded model: Qualcomm Gobi 2000
<debug> [1415360816.077646] [mm-broadband-modem-qmi.c:1147] modem_load_revision(): loading revision...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:05:00:23:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 5
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Revision" (0x0023)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 102
>>>>>>   data   = 01:65:00:80:02:01:02:05:00:23:00:59:00:02:04:00:00:00:00:00:01:2E:00:44:31:30:32:35:2D:53:54:55:54:41:42:47:44:2D:33:36:30:30:20:20:31:20:20:5B:4A:61:6E:20:31:34:20:32:30:31:30:20:31:34:3A:30:30:3A:30:30:5D:10:13:00:44:31:30:32:35:2D:53:54:55:54:41:42:4D:44:2D:33:35:37:35:11:08:00:30:61:30:39:30:30:31:32
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 101
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 5
>>>>>>   tlv_length  = 89
>>>>>>   message     = "Get Revision" (0x0023)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Revision" (0x01)
>>>>>>   length     = 46
>>>>>>   value      = 44:31:30:32:35:2D:53:54:55:54:41:42:47:44:2D:33:36:30:30:20:20:31:20:20:5B:4A:61:6E:20:31:34:20:32:30:31:30:20:31:34:3A:30:30:3A:30:30:5D
>>>>>>   translated = D1025-STUTABGD-3600  1  [Jan 14 2010 14:00:00]
>>>>>> TLV:
>>>>>>   type   = 0x10
>>>>>>   length = 19
>>>>>>   value  = 44:31:30:32:35:2D:53:54:55:54:41:42:4D:44:2D:33:35:37:35
>>>>>> TLV:
>>>>>>   type   = 0x11
>>>>>>   length = 8
>>>>>>   value  = 30:61:30:39:30:30:31:32
<debug> [1415360816.081981] [mm-broadband-modem-qmi.c:1094] modem_load_revision_finish(): loaded revision: D1025-STUTABGD-3600  1  [Jan 14 2010 14:00:00]
<debug> [1415360816.082016] [mm-broadband-modem-qmi.c:1289] modem_load_equipment_identifier(): loading equipment identifier...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:06:00:25:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 6
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get IDs" (0x0025)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 66
>>>>>>   data   = 01:41:00:80:02:01:02:06:00:25:00:35:00:02:04:00:00:00:00:00:12:0E:00:41:31:30:30:30:30:31:37:36:46:41:46:36:32:10:08:00:38:30:39:38:44:35:46:43:11:0F:00:33:35:33:30:39:33:30:33:33:34:35:36:31:33:36
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 65
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 6
>>>>>>   tlv_length  = 53
>>>>>>   message     = "Get IDs" (0x0025)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Meid" (0x12)
>>>>>>   length     = 14
>>>>>>   value      = 41:31:30:30:30:30:31:37:36:46:41:46:36:32
>>>>>>   translated = A10000176FAF62
>>>>>> TLV:
>>>>>>   type       = "Esn" (0x10)
>>>>>>   length     = 8
>>>>>>   value      = 38:30:39:38:44:35:46:43
>>>>>>   translated = 8098D5FC
>>>>>> TLV:
>>>>>>   type       = "Imei" (0x11)
>>>>>>   length     = 15
>>>>>>   value      = 33:35:33:30:39:33:30:33:33:34:35:36:31:33:36
>>>>>>   translated = 353093033456136
<debug> [1415360816.121907] [mm-broadband-modem-qmi.c:1186] modem_load_equipment_identifier_finish(): loaded equipment identifier: 353093033456136
<debug> [1415360816.121926] [mm-broadband-modem-qmi.c:1324] modem_load_device_identifier(): loading device identifier...
<debug> [1415360816.121957] [mm-modem-helpers.c:148] mm_create_device_identifier(): Device ID source '000005c600009205353093033456136D1025-STUTABGD-36001[Jan14201014:00:00]QualcommGobi2000QualcommIncorporated'
<debug> [1415360816.121963] [mm-modem-helpers.c:149] mm_create_device_identifier(): Device ID 'dc8d3d26baefdd35a6f6cff49c0942d1fb432217'
<debug> [1415360816.121981] [mm-broadband-modem-qmi.c:1312] modem_load_device_identifier_finish(): loaded device identifier: dc8d3d26baefdd35a6f6cff49c0942d1fb432217
<debug> [1415360816.122052] [mm-broadband-modem-qmi.c:1727] modem_load_supported_bands(): loading band capabilities...
<warn>  [1415360816.122085] [mm-iface-modem.c:3982] load_supported_bands_ready(): couldn't load Supported Bands: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.1''
<debug> [1415360816.122111] [mm-broadband-modem-qmi.c:2682] load_power_state(): Getting device operating mode...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:08:00:2D:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 8
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Operating Mode" (0x002D)
<debug> [1415360816.122173] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
<debug> [1415360816.122232] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'ATX4<CR>'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:02:01:02:08:00:2D:00:0B:00:02:04:00:00:00:00:00:01:01:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 8
>>>>>>   tlv_length  = 11
>>>>>>   message     = "Get Operating Mode" (0x002D)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Mode" (0x01)
>>>>>>   length     = 1
>>>>>>   value      = 00
>>>>>>   translated = online
<debug> [1415360816.127607] [mm-broadband-modem-qmi.c:1533] modem_load_unlock_required(): loading unlock required...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:09:00:2B:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 9
<<<<<<   tlv_length  = 0
<<<<<<   message     = "UIM Get PIN Status" (0x002B)
<debug> [1415360816.132629] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>ERROR<CR><LF>'
<debug> [1415360816.132755] [mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
<debug> [1415360816.132804] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'AT&C1<CR>'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 32
>>>>>>   data   = 01:1F:00:80:02:01:02:09:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:02:0A:11:03:00:01:03:0A
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 31
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 9
>>>>>>   tlv_length  = 19
>>>>>>   message     = "UIM Get PIN Status" (0x002B)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "PIN2 Status" (0x12)
>>>>>>   length     = 3
>>>>>>   value      = 01:02:0A
>>>>>>   translated = [ current_status = 'enabled-not-verified' verify_retries_left = '2' unblock_retries_left = '10' ]
>>>>>> TLV:
>>>>>>   type       = "PIN1 Status" (0x11)
>>>>>>   length     = 3
>>>>>>   value      = 01:03:0A
>>>>>>   translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<debug> [1415360816.134047] [mm-broadband-modem-qmi.c:1626] modem_load_unlock_retries(): loading unlock retries...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:0A:00:2B:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 10
<<<<<<   tlv_length  = 0
<<<<<<   message     = "UIM Get PIN Status" (0x002B)
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 32
>>>>>>   data   = 01:1F:00:80:02:01:02:0A:00:2B:00:13:00:02:04:00:00:00:00:00:12:03:00:01:02:0A:11:03:00:01:03:0A
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 31
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 10
>>>>>>   tlv_length  = 19
>>>>>>   message     = "UIM Get PIN Status" (0x002B)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "PIN2 Status" (0x12)
>>>>>>   length     = 3
>>>>>>   value      = 01:02:0A
>>>>>>   translated = [ current_status = 'enabled-not-verified' verify_retries_left = '2' unblock_retries_left = '10' ]
>>>>>> TLV:
>>>>>>   type       = "PIN1 Status" (0x11)
>>>>>>   length     = 3
>>>>>>   value      = 01:03:0A
>>>>>>   translated = [ current_status = 'enabled-not-verified' verify_retries_left = '3' unblock_retries_left = '10' ]
<info>  [1415360816.141619] [mm-iface-modem.c:1392] __iface_modem_update_state_internal(): Modem: state changed (unknown -> locked)
<debug> [1415360816.141981] [mm-sim-qmi.c:148] load_sim_identifier(): loading SIM identifier...
<debug> [1415360816.142020] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>ERROR<CR><LF>'
<debug> [1415360816.142039] [mm-serial-parsers.c:364] mm_serial_parser_v1_parse(): Got failure code 100: Unknown error
<debug> [1415360816.142061] [mm-sim-qmi.c:148] load_sim_identifier(): loading SIM identifier...
<warn>  [1415360816.142083] [mm-base-sim.c:1428] load_sim_identifier_ready(): couldn't load SIM identifier: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.1''
<debug> [1415360816.142100] [mm-sim-qmi.c:224] load_imsi(): loading IMSI...
<warn>  [1415360816.142131] [mm-base-sim.c:1464] load_imsi_ready(): couldn't load IMSI: 'QMI operation failed: Cannot send message: QMI service 'dms' version '1.3' required, got version '1.1''
<debug> [1415360816.142189] [mm-broadband-modem-qmi.c:1408] modem_load_own_numbers(): loading own numbers...
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:01:00:0E:00:24:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 14
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get MSISDN" (0x0024)
<debug> [1415360816.142238] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'ATE0<CR>'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 20
>>>>>>   data   = 01:13:00:80:02:01:02:0E:00:24:00:07:00:02:04:00:01:00:10:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 19
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 14
>>>>>>   tlv_length  = 7
>>>>>>   message     = "Get MSISDN" (0x0024)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 01:00:10:00
>>>>>>   translated = FAILURE: NotProvisioned
<warn>  [1415360816.152202] [mm-iface-modem.c:4112] load_own_numbers_ready(): couldn't load list of Own Numbers: 'Couldn't get MSISDN: QMI protocol error (16): 'NotProvisioned''
[/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:03:01:00:02:00:2B:00:00:00
[/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "nas"
<<<<<<   client  = 1
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 2
<<<<<<   tlv_length  = 0
<<<<<<   message     = "Get Technology Preference" (0x002B)
<debug> [1415360816.152631] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
<debug> [1415360816.152676] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB1) device open count is 2 (close)
<debug> [1415360816.152709] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): --> 'AT+CMEE=1<CR>'
[/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 26
>>>>>>   data   = 01:19:00:80:03:01:02:02:00:2B:00:0D:00:02:04:00:00:00:00:00:01:03:00:00:00:00
[/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 25
>>>>>>   flags   = 0x80
>>>>>>   service = "nas"
>>>>>>   client  = 1
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 2
>>>>>>   tlv_length  = 13
>>>>>>   message     = "Get Technology Preference" (0x002B)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Active" (0x01)
>>>>>>   length     = 3
>>>>>>   value      = 00:00:00
>>>>>>   translated = [ technology_preference = 'auto' technology_preference_duration = 'permanent' ]
<debug> [1415360816.155746] [mm-broadband-modem-qmi.c:2869] get_technology_preference_ready(): Unsupported modes reported: 'auto'
<warn>  [1415360816.155781] [mm-iface-modem.c:4141] load_current_modes_ready(): couldn't load current allowed/preferred modes: 'Loading current modes is not supported by this device'
<debug> [1415360816.155793] [mm-broadband-modem-qmi.c:1875] modem_load_current_bands(): loading current bands...
<warn>  [1415360816.155816] [mm-iface-modem.c:4162] load_current_bands_ready(): couldn't load current Bands: 'QMI operation failed: Cannot send message: QMI service 'nas' version '1.1' required, got version '1.0''
<debug> [1415360816.155990] [mm-broadband-modem-qmi.c:9090] firmware_check_support(): loading firmware images...
<debug> [1415360816.156044] [mm-broadband-modem.c:9005] iface_modem_firmware_initialize_ready(): Couldn't initialize interface: 'Firmware not supported'
<debug> [1415360816.156120] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB1) device open count is 1 (close)
<debug> [1415360816.156132] [mm-base-modem.c:950] initialize_ready(): Couldn't finish initialization in the current state: 'Modem is currently locked, cannot fully initialize'
<debug> [1415360816.156440] [mm-device.c:436] export_modem(): Exported modem '/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.4' at path '/org/freedesktop/ModemManager1/Modem/0'
<debug> [1415360816.156449] [mm-device.c:446] export_modem(): (/org/freedesktop/ModemManager1/Modem/0): 'Gobi' modem, VID 0x05C6 PID 0x9205 (usb)
<debug> [1415360816.171190] [mm-port-serial-at.c:440] debug_log(): (ttyUSB1): <-- '<CR><LF>OK<CR><LF>'
<debug> [1415360816.171227] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyUSB1) device open count is 0 (close)
<debug> [1415360816.171236] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyUSB1) closing serial port...
<debug> [1415360816.172594] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyUSB1) serial port closed
<debug> [1415360819.003587] [mm-port-probe.c:258] mm_port_probe_set_result_qcdm(): (tty/ttyS0) port is not QCDM-capable
<debug> [1415360819.003647] [mm-port-serial.c:1296] mm_port_serial_close(): (ttyS0) device open count is 0 (close)
<debug> [1415360819.003661] [mm-port-serial.c:1312] mm_port_serial_close(): (ttyS0) closing serial port...
<debug> [1415360819.003746] [mm-port-serial.c:1361] mm_port_serial_close(): (ttyS0) serial port closed
<debug> [1415360819.003756] [mm-port-serial.c:1415] port_serial_close_force(): (ttyS0) forced to close port
<debug> [1415360819.003785] [mm-plugin-manager.c:462] plugin_supports_port_ready(): (Plugin Manager) (Generic) [ttyS0] found best plugin for port
<debug> [1415360819.003808] [mm-plugin-manager.c:316] port_probe_context_finished(): (Plugin Manager) 'ttyS0' port probe finished, last one in device
<debug> [1415360819.003816] [mm-plugin-manager.c:138] find_device_support_context_complete_and_free(): (Plugin Manager) [/sys/devices/pci0000:00/0000:00:16.3] device support check finished in '19.002068' seconds
<info>  [1415360819.003832] [mm-device.c:509] mm_device_create_modem(): Creating modem with plugin 'Generic' and '1' ports
<warn>  [1415360819.004180] [mm-plugin.c:905] mm_plugin_create_modem(): Could not grab port (tty/ttyS0): 'Cannot add port 'tty/ttyS0', unhandled serial type'
<debug> [1415360819.004216] [mm-base-modem.c:1485] finalize(): Modem (Generic) '/sys/devices/pci0000:00/0000:00:16.3' completely disposed
<warn>  [1415360819.004224] [mm-base-manager.c:158] find_device_support_ready(): Couldn't create modem for device at '/sys/devices/pci0000:00/0000:00:16.3': Failed to find primary AT port
-------------- next part --------------
# qmicli -d /dev/cdc-wdm0 --dms-uim-get-iccid --verbose > qmicli.output
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Opening device with flags 'none'...
[07 Nov 2014, 11:48:00] [Debug] QMI Device at '/dev/cdc-wdm0' ready
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Assuming service 'dms' is supported...
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Allocating new client ID...
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 16
<<<<<<   data   = 01:0F:00:00:00:00:00:01:22:00:04:00:01:01:00:02

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 15
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 4
<<<<<<   message     = "Allocate CID" (0x0022)
<<<<<< TLV:
<<<<<<   type       = "Service" (0x01)
<<<<<<   length     = 1
<<<<<<   value      = 02
<<<<<<   translated = dms

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:01:22:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:03

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Allocate CID" (0x0022)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Allocation Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 02:03
>>>>>>   translated = [ service = 'dms' cid = '3' ]

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Registered 'dms' (version unknown) client with ID '3'
[07 Nov 2014, 11:48:00] [Debug] Asynchronously getting UIM ICCID...
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 13
<<<<<<   data   = 01:0C:00:00:02:03:00:01:00:3C:00:00:00

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 12
<<<<<<   flags   = 0x00
<<<<<<   service = "dms"
<<<<<<   client  = 3
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 1
<<<<<<   tlv_length  = 0
<<<<<<   message     = "UIM Get ICCID" (0x003C)

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 43
>>>>>>   data   = 01:2A:00:80:02:03:02:01:00:3C:00:1E:00:02:04:00:00:00:00:00:01:14:00:38:39:34:39:32:30:32:39:33:30:37:35:35:31:37:36:32:30:38:30

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 42
>>>>>>   flags   = 0x80
>>>>>>   service = "dms"
>>>>>>   client  = 3
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 1
>>>>>>   tlv_length  = 30
>>>>>>   message     = "UIM Get ICCID" (0x003C)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "ICCID" (0x01)
>>>>>>   length     = 20
>>>>>>   value      = 38:39:34:39:32:30:32:39:33:30:37:35:35:31:37:36:32:30:38:30
>>>>>>   translated = 89492029307551762080

[/dev/cdc-wdm0] UIM ICCID retrieved:
	ICCID: '89492029307551762080'
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Releasing 'dms' client with flags 'release-cid'...
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Unregistered 'dms' client with ID '3'
[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Sent message...
<<<<<< RAW:
<<<<<<   length = 17
<<<<<<   data   = 01:10:00:00:00:00:00:02:23:00:05:00:01:02:00:02:03

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Sent message (translated)...
<<<<<< QMUX:
<<<<<<   length  = 16
<<<<<<   flags   = 0x00
<<<<<<   service = "ctl"
<<<<<<   client  = 0
<<<<<< QMI:
<<<<<<   flags       = "none"
<<<<<<   transaction = 2
<<<<<<   tlv_length  = 5
<<<<<<   message     = "Release CID" (0x0023)
<<<<<< TLV:
<<<<<<   type       = "Release Info" (0x01)
<<<<<<   length     = 2
<<<<<<   value      = 02:03
<<<<<<   translated = [ service = 'dms' cid = '3' ]

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Received message...
>>>>>> RAW:
>>>>>>   length = 24
>>>>>>   data   = 01:17:00:80:00:00:01:02:23:00:0C:00:02:04:00:00:00:00:00:01:02:00:02:03

[07 Nov 2014, 11:48:00] [Debug] [/dev/cdc-wdm0] Received message (translated)...
>>>>>> QMUX:
>>>>>>   length  = 23
>>>>>>   flags   = 0x80
>>>>>>   service = "ctl"
>>>>>>   client  = 0
>>>>>> QMI:
>>>>>>   flags       = "response"
>>>>>>   transaction = 2
>>>>>>   tlv_length  = 12
>>>>>>   message     = "Release CID" (0x0023)
>>>>>> TLV:
>>>>>>   type       = "Result" (0x02)
>>>>>>   length     = 4
>>>>>>   value      = 00:00:00:00
>>>>>>   translated = SUCCESS
>>>>>> TLV:
>>>>>>   type       = "Release Info" (0x01)
>>>>>>   length     = 2
>>>>>>   value      = 02:03
>>>>>>   translated = [ service = 'dms' cid = '3' ]

[07 Nov 2014, 11:48:00] [Debug] Client released


More information about the ModemManager-devel mailing list