Bug 697611 – [MM 0.8] Infineon modem support

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 697611 - [MM 0.8] Infineon modem support


Summary:	[MM 0.8] Infineon modem support


Status:	RESOLVED NOTGNOME

Product:	NetworkManager
Classification:	Platform
Component:	ModemManager
Version:	0.6.6
Hardware:	Other Linux

Importance:	Normal normal
Target Milestone:	---
Assigned To:	NetworkManager maintainer(s)
QA Contact:	NetworkManager maintainer(s)

URL:
Whiteboard:

Depends on:
Blocks:

Reported:	2013-04-09 07:19 UTC by Marius Kotsbak
Modified:	2014-10-14 11:35 UTC

See Also:
GNOME target:	---
GNOME version:	---

Attachments
Attached lsusb of Nexus 7 3G (15.64 KB, text/plain) 2013-05-24 17:10 UTC, Marius Kotsbak	Details
ModemManager log of connection test using new rawip branch (98.65 KB, text/plain) 2013-05-28 12:36 UTC, Marius Kotsbak	Details
New connection problem (144.61 KB, text/plain) 2013-05-28 18:50 UTC, Marius Kotsbak	Details

Description Marius Kotsbak 2013-04-09 07:19:19 UTC

Originally reported at:
  https://bugs.launchpad.net/bugs/1091663

Repeated attempts to get 3G connectivity on my Nexus 7 fail. The same SIM worked fine under Android.

Very occasionally, a notification pops up saying that I have connected, but I am then immediately disconnected again. Most of the time, though, I get a 'disconnected' notification and nothing else.

My provider is giffgaff (UK). The mobile broadband hardware is definitely detected by Ubuntu, given that it appears in the network menu.

I can do further testing if asked.

Comment 1 Marius Kotsbak 2013-04-09 13:54:45 UTC

If someone are able to build an updated modemmanager, there is some work done here to test:

http://cgit.freedesktop.org/ModemManager/ModemManager/log/?h=aleksander/infineon

Please add debug logs to this bug report.

Comment 2 Marius Kotsbak 2013-05-16 13:26:21 UTC

Okay, now I got it running:

mmcli -m 0

/org/freedesktop/ModemManager1/Modem/0 (device id '27d915cfc3ffa8b9d415425dd511570fc40a35f5')
  -------------------------
  Hardware |   manufacturer: 'Infineon'
           |          model: 'XMM6260'
           |       revision: '1231_0.17.0_1205'
           |   capabilities: 'gsm-umts'
           |        current: 'gsm-umts'
           |   equipment id: 'XXXX'
  -------------------------
  System   |         device: '/sys/devices/platform/tegra-ehci.1/usb1/1-1'
           |        drivers: 'cdc_acm'
           |         plugin: 'Infineon'
           |   primary port: 'ttyACM0'
  -------------------------
  Numbers  |           own : 'unknown'
  -------------------------
  Status   |           lock: 'none'
           | unlock retries: 'unknown'
           |          state: 'disabled'
           |    power state: 'unknown'
           |    access tech: 'unknown'
           | signal quality: '0' (cached)
  -------------------------
  Modes    |      supported: '2g, 3g'
           |        allowed: '2g, 3g'
           |      preferred: 'none'
  -------------------------
  Bands    |      supported: 'unknown'
           |        current: 'unknown'
  -------------------------
  3GPP     |           imei: 'XXXX'
           |  enabled locks: 'sim'
           |    operator id: 'unknown'
           |  operator name: 'unknown'
           |   registration: 'unknown'
  -------------------------
  SIM      |           path: '/org/freedesktop/ModemManager1/SIM/0'


Then trying to connect: mmcli -m 0 --simple-connect="apn=internet.netcom.no"

gives the following debug log error:

ModemManager[30144]: <debug> [1368710564.454877] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT+CGDCONT=1,"IP","internet.netcom.no"<CR>'
ModemManager[30144]: <debug> [1368710564.527225] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
ModemManager[30144]: <debug> [1368710564.543790] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open)
ModemManager[30144]: <debug> [1368710564.550749] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 4 (open)
ModemManager[30144]: <debug> [1368710564.559054] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 3 (close)
ModemManager[30144]: <debug> [1368710564.564429] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT+XGAUTH=%u,0,"",""<CR>'
ModemManager[30144]: <debug> [1368710564.601111] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>+CME ERROR: 4<CR><LF>'
ModemManager[30144]: <debug> [1368710564.603559] [mm-serial-parsers.c:363] mm_serial_parser_v1_parse(): Got failure code 4: Operation not supported
ModemManager[30144]: <debug> [1368710564.608644] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close)
ModemManager[30144]: <debug> [1368710564.614718] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 1 (close)
ModemManager[30144]: <debug> [1368710564.620689] [mm-bearer.c:384] connect_ready(): Couldn't connect bearer '/org/freedesktop/ModemManager1/Bearer/0': 'Operation not supported'
ModemManager[30144]: <info>  [1368710564.627381] [mm-iface-modem.c:1203] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
ModemManager[30144]: <debug> [1368710564.645222] [mm-iface-modem-simple.c:228] connect_bearer_ready(): Couldn't connect bearer: 'Operation not supported'
ModemManager[30144]: <debug> [1368710595.040871] [mm-broadband-modem.c:1709] modem_load_signal_quality(): loading signal quality...
ModemManager[30144]: <debug> [1368710595.042171] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 2 (open)
ModemManager[30144]: <debug> [1368710595.043695] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT+CSQ<CR>'
ModemManager[30144]: <debug> [1368710595.120537] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>+CSQ: 10,1<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[30144]: <debug> [1368710595.140314] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 1 (close)
ModemManager[30144]: <info>  [1368710595.152905] [mm-iface-modem.c:976] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (32)ModemManager[30144]: <debug> [1368710564.608644] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close)
ModemManager[30144]: <debug> [1368710564.614718] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 1 (close)
ModemManager[30144]: <debug> [1368710564.620689] [mm-bearer.c:384] connect_ready(): Couldn't connect bearer '/org/freedesktop/ModemManager1/Bearer/0': 'Operation not supported'
ModemManager[30144]: <info>  [1368710564.627381] [mm-iface-modem.c:1203] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> registered)
ModemManager[30144]: <debug> [1368710564.645222] [mm-iface-modem-simple.c:228] connect_bearer_ready(): Couldn't connect bearer: 'Operation not supported'
ModemManager[30144]: <debug> [1368710595.040871] [mm-broadband-modem.c:1709] modem_load_signal_quality(): loading signal quality...
ModemManager[30144]: <debug> [1368710595.042171] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 2 (open)
ModemManager[30144]: <debug> [1368710595.043695] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT+CSQ<CR>'
ModemManager[30144]: <debug> [1368710595.120537] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>+CSQ: 10,1<CR><LF><CR><LF>OK<CR><LF>'
ModemManager[30144]: <debug> [1368710595.140314] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 1 (close)
ModemManager[30144]: <info>  [1368710595.152905] [mm-iface-modem.c:976] update_signal_quality(): Modem /org/freedesktop/ModemManager1/Modem/0: signal quality updated (32)

That is, it is able to register, but not connect.

Comment 3 Marius Kotsbak 2013-05-16 13:29:15 UTC

I see the failing command is for authenticating. I'm not required to do that for my provider, so is this command required at all then?

Comment 4 Dan Williams 2013-05-16 13:43:42 UTC

Fixed up the XGAUTH no-authentication case, please try again thanks!

Comment 5 Marius Kotsbak 2013-05-16 13:49:21 UTC

Now it works:

ModemManager[613]: <debug> [1368711998.277928] [mm-bearer.c:407] connect_ready(): Connected bearer '/org/freedesktop/ModemManager1/Bearer/0'
ModemManager[613]: <info>  [1368711998.284491] [mm-iface-modem.c:1203] __iface_modem_update_state_internal(): Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
ModemManager[613]: <info>  [1368711998.301004] [mm-iface-modem-simple.c:740] connection_step(): Simple connect state (10/10): All done

Only problem seen yet is this:

ModemManager[613]: <debug> [1368712026.011611] [mm-broadband-modem.c:1709] modem_load_signal_quality(): loading signal quality...
ModemManager[613]: <debug> [1368712026.012910] [mm-iface-modem.c:1032] signal_quality_check_ready(): Couldn't refresh signal quality: 'No AT port available to run command'
ModemManager[613]: <debug> [1368712056.012023] [mm-iface-modem.c:912] expire_signal_quality(): Signal quality value not updated in 60s, marking as not being recent
ModemManager[613]: <debug> [1368712056.019616] [mm-broadband-modem.c:1709] modem_load_signal_quality(): loading signal quality...
ModemManager[613]: <debug> [1368712056.042898] [mm-iface-modem.c:1032] signal_quality_check_ready(): Couldn't refresh signal quality: 'No AT port available to run command'
ModemManager[613]: <debug> [1368712086.012133] [mm-broadband-modem.c:1709] modem_load_signal_quality(): loading signal quality...
ModemManager[613]: <debug> [1368712086.013446] [mm-iface-modem.c:1032] signal_quality_check_ready(): Couldn't refresh signal quality: 'No AT port available to run command'
ModemManager[613]: <debug> [1368712116.011528] [mm-broadband-modem.c:1709] modem_load_signal_quality(): loading signal quality...
ModemManager[613]: <debug> [1368712116.012855] [mm-iface-modem.c:1032] signal_quality_check_ready(): Couldn't refresh signal quality: 'No AT port available to run command'

And also left to test the connection.

Comment 6 Marius Kotsbak 2013-05-16 13:57:17 UTC

There is both ttyACM0 and ttyACM1. Probably the other one could be used for signal monitoring.

Comment 7 Aleksander Morgado 2013-05-16 13:58:34 UTC

(In reply to comment #6)
> There is both ttyACM0 and ttyACM1. Probably the other one could be used for
> signal monitoring.

That should be done by default when the tty is detected as an AT port. Can you check the probing logs to see why the secondary port wasn't detected as being AT?

Comment 8 Marius Kotsbak 2013-05-16 14:05:39 UTC

Then there is a problem with the PPP:

ModemManager[613]: <debug> [1368712645.188460] [mm-manager.c:265] device_added(): (net/ppp0): could not get port's parent device

I'm not sure if that is because MM is not properly installed in the system.

Regarding ttyACM1:

May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.678780] [mm-plugin-manager.c:514] build_plugins_list(): (Plugin Manager) [ttyACM1] Found '2' plugins to try...
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.679069] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [ttyACM1]   Will try with plugin 'Infi
neon'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.679536] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [ttyACM1]   Will try with plugin 'Gene
ric'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.679891] [mm-plugin.c:751] mm_plugin_supports_port(): (Infineon) [ttyACM1] probe required: 'at'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.680382] [mm-port-probe.c:1178] mm_port_probe_run(): (tty/ttyACM1) launching port probing: 'at'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.681952] [mm-manager.c:288] device_added(): (tty/ttyHS1): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.683261] [mm-manager.c:288] device_added(): (tty/ttyHS2): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.684231] [mm-manager.c:288] device_added(): (tty/ttyHS3): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.685322] [mm-manager.c:288] device_added(): (tty/ttyHS4): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.690035] [mm-manager.c:288] device_added(): (net/usb0): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.691419] [mm-manager.c:288] device_added(): (net/wlan0): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.692423] [mm-manager.c:265] device_added(): (net/dummy0): could not get port's parent device
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.693211] [mm-manager.c:265] device_added(): (net/ip6tnl0): could not get port's parent device
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.694427] [mm-manager.c:265] device_added(): (net/sit0): could not get port's parent device
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.696269] [mm-serial-port.c:891] mm_serial_port_open(): (ttyACM0) opening serial port...
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.698631] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 1 (open)
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.699854] [mm-serial-port.c:891] mm_serial_port_open(): (ttyACM1) opening serial port...
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.701396] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM1) device open count is 1 (open)
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.804413] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT<CR>'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.806717] [mm-at-serial-port.c:408] debug_log(): (ttyACM1): --> 'AT<CR>'
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.013364] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.016832] [mm-port-probe.c:139] mm_port_probe_set_result_at(): (tty/ttyACM0) port is AT-capable
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.018748] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 0 (close)
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.020384] [mm-serial-port.c:1019] mm_serial_port_close(): (ttyACM0) closing serial port...
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.027523] [mm-serial-port.c:1050] mm_serial_port_close(): (ttyACM0) serial port closed
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.029021] [mm-serial-port.c:1118] mm_serial_port_close_force(): (ttyACM0) forced to close port
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.032832] [mm-plugin-manager.c:356] plugin_supports_port_ready(): (Plugin Manager) (Infineon) [ttyACM0] found best plugin for port
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.033513] [mm-plugin-manager.c:192] port_probe_context_finished(): (Plugin Manager) (Infineon) [ttyACM0]: found best plugin for device (/sys/devices/platform/tegra-ehci.1/usb1/1-1)
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.034241] [mm-plugin-manager.c:316] suggest_port_probe_result(): (Plugin Manager) (Infineon) [ttyACM1] suggested plugin for port
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.034876] [mm-plugin-manager.c:230] port_probe_context_finished(): (Plugin Manager) 'ttyACM0' port probe finished, still 1 running probes in this device (ttyACM1)May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.678780] [mm-plugin-manager.c:514] build_plugins_list(): (Plugin Manager) [ttyACM1] Found '2' plugins to try...
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.679069] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [ttyACM1]   Will try with plugin 'Infi
neon'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.679536] [mm-plugin-manager.c:518] build_plugins_list(): (Plugin Manager) [ttyACM1]   Will try with plugin 'Gene
ric'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.679891] [mm-plugin.c:751] mm_plugin_supports_port(): (Infineon) [ttyACM1] probe required: 'at'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.680382] [mm-port-probe.c:1178] mm_port_probe_run(): (tty/ttyACM1) launching port probing: 'at'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.681952] [mm-manager.c:288] device_added(): (tty/ttyHS1): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.683261] [mm-manager.c:288] device_added(): (tty/ttyHS2): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.684231] [mm-manager.c:288] device_added(): (tty/ttyHS3): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.685322] [mm-manager.c:288] device_added(): (tty/ttyHS4): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.690035] [mm-manager.c:288] device_added(): (net/usb0): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.691419] [mm-manager.c:288] device_added(): (net/wlan0): port's parent platform driver is not whitelisted
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.692423] [mm-manager.c:265] device_added(): (net/dummy0): could not get port's parent device
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.693211] [mm-manager.c:265] device_added(): (net/ip6tnl0): could not get port's parent device
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.694427] [mm-manager.c:265] device_added(): (net/sit0): could not get port's parent device
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.696269] [mm-serial-port.c:891] mm_serial_port_open(): (ttyACM0) opening serial port...
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.698631] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 1 (open)
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.699854] [mm-serial-port.c:891] mm_serial_port_open(): (ttyACM1) opening serial port...
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.701396] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM1) device open count is 1 (open)
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.804413] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT<CR>'
May 16 15:46:09 marius-Nexus7 ModemManager[613]: <debug> [1368711969.806717] [mm-at-serial-port.c:408] debug_log(): (ttyACM1): --> 'AT<CR>'
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.013364] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>OK<CR><LF>'
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.016832] [mm-port-probe.c:139] mm_port_probe_set_result_at(): (tty/ttyACM0) port is AT-capable
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.018748] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 0 (close)
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.020384] [mm-serial-port.c:1019] mm_serial_port_close(): (ttyACM0) closing serial port...
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.027523] [mm-serial-port.c:1050] mm_serial_port_close(): (ttyACM0) serial port closed
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.029021] [mm-serial-port.c:1118] mm_serial_port_close_force(): (ttyACM0) forced to close port
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.032832] [mm-plugin-manager.c:356] plugin_supports_port_ready(): (Plugin Manager) (Infineon) [ttyACM0] found best plugin for port
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.033513] [mm-plugin-manager.c:192] port_probe_context_finished(): (Plugin Manager) (Infineon) [ttyACM0]: found best plugin for device (/sys/devices/platform/tegra-ehci.1/usb1/1-1)
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.034241] [mm-plugin-manager.c:316] suggest_port_probe_result(): (Plugin Manager) (Infineon) [ttyACM1] suggested plugin for port
May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.034876] [mm-plugin-manager.c:230] port_probe_context_finished(): (Plugin Manager) 'ttyACM0' port probe finished, still 1 running probes in this device (ttyACM1)

[...]

May 16 15:46:10 marius-Nexus7 ModemManager[613]: <debug> [1368711970.034876] [mm-plugin-manager.c:230] port_probe_context_finished(): (Plugin Manager) 'ttyACM0' port probe finished, still 1 running probes in this device (ttyACM1)
May 16 15:46:12 marius-Nexus7 ModemManager[613]: <debug> [1368711972.012685] [mm-plugin-manager.c:584] min_probing_timeout_cb(): (Plugin Manager) [/sys/devices/platform/tegra-ehci.1/usb1/1-1] Minimum probing time consumed

May 16 15:46:13 marius-Nexus7 ModemManager[613]: <debug> [1368711973.014193] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
May 16 15:46:13 marius-Nexus7 ModemManager[613]: <debug> [1368711973.023774] [mm-at-serial-port.c:408] debug_log(): (ttyACM1): --> 'AT<CR>'
May 16 15:46:15 marius-Nexus7 kernel: [17290.375651] L2
May 16 15:46:15 marius-Nexus7 kernel: [17290.381159] CP L2->L0
May 16 15:46:15 marius-Nexus7 kernel: [17290.390488] L0
May 16 15:46:16 marius-Nexus7 ModemManager[613]: <debug> [1368711976.012890] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
May 16 15:46:16 marius-Nexus7 ModemManager[613]: <debug> [1368711976.014421] [mm-at-serial-port.c:408] debug_log(): (ttyACM1): --> 'AT<CR>'
May 16 15:46:18 marius-Nexus7 kernel: [17293.353389] L2
May 16 15:46:18 marius-Nexus7 kernel: [17293.358669] CP L2->L0
May 16 15:46:18 marius-Nexus7 kernel: [17293.367289] L0
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.013220] [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT got: 'Serial command timed out'
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.013705] [mm-port-probe.c:148] mm_port_probe_set_result_at(): (tty/ttyACM1) port is not AT-capable
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.014138] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM1) device open count is 0 (close)
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.014361] [mm-serial-port.c:1019] mm_serial_port_close(): (ttyACM1) closing serial port...
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.022110] [mm-serial-port.c:1050] mm_serial_port_close(): (ttyACM1) serial port closed
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.024200] [mm-serial-port.c:1118] mm_serial_port_close_force(): (ttyACM1) forced to close port
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.027433] [mm-plugin-manager.c:356] plugin_supports_port_ready(): (Plugin Manager) (Infineon) [ttyACM1] found best plugin for port
May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.030646] [mm-plugin-manager.c:241] port_probe_context_finished(): (Plugin Manager) 'ttyACM1' port probe finished, last one in device

Comment 9 Aleksander Morgado 2013-05-16 14:12:05 UTC

(In reply to comment #8)
> Then there is a problem with the PPP:
> 
> ModemManager[613]: <debug> [1368712645.188460] [mm-manager.c:265]
> device_added(): (net/ppp0): could not get port's parent device
> 
> I'm not sure if that is because MM is not properly installed in the system.
> 

That's nothing to worry about.

> Regarding ttyACM1:
> May 16 15:46:16 marius-Nexus7 ModemManager[613]: <debug> [1368711976.014421]
> [mm-at-serial-port.c:408] debug_log(): (ttyACM1): --> 'AT<CR>'
> May 16 15:46:18 marius-Nexus7 kernel: [17293.353389] L2
> May 16 15:46:18 marius-Nexus7 kernel: [17293.358669] CP L2->L0
> May 16 15:46:18 marius-Nexus7 kernel: [17293.367289] L0
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.013220]
> [mm-port-probe-at.c:43] mm_port_probe_response_processor_is_at(): Parsing AT
> got: 'Serial command timed out'
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.013705]
> [mm-port-probe.c:148] mm_port_probe_set_result_at(): (tty/ttyACM1) port is not
> AT-capable
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.014138]
> [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM1) device open count is
> 0 (close)
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.014361]
> [mm-serial-port.c:1019] mm_serial_port_close(): (ttyACM1) closing serial
> port...
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.022110]
> [mm-serial-port.c:1050] mm_serial_port_close(): (ttyACM1) serial port closed
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.024200]
> [mm-serial-port.c:1118] mm_serial_port_close_force(): (ttyACM1) forced to close
> port
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.027433]
> [mm-plugin-manager.c:356] plugin_supports_port_ready(): (Plugin Manager)
> (Infineon) [ttyACM1] found best plugin for port
> May 16 15:46:19 marius-Nexus7 ModemManager[613]: <debug> [1368711979.030646]
> [mm-plugin-manager.c:241] port_probe_context_finished(): (Plugin Manager)
> 'ttyACM1' port probe finished, last one in device

That tty didn't even reply to a simple "AT" command, so we assume it's not an AT port.

Comment 10 Marius Kotsbak 2013-05-16 14:17:53 UTC

That is strange, as I think it works properly with Android. Anyway, what should I do after this to get an IP connection up?:

ModemManager[613]: <debug> [1368713230.954845] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT+CGDATA="M-RAW_IP",1<CR>'
ModemManager[613]: <debug> [1368713230.982978] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>CONNECT<CR><LF>'
ModemManager[613]: (infineon/mm-broadband-bearer-infineon.c:164):data_ready: runtime check failed: (ctx->self->priv->current_ip_config == NULL)
ModemManager[613]: <debug> [1368713230.984353] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close)
ModemManager[613]: <debug> [1368713230.985098] [mm-port.c:149] mm_port_set_connected(): (ttyACM0): port now connected

Comment 11 Aleksander Morgado 2013-05-16 14:22:58 UTC

(In reply to comment #10)
> That is strange, as I think it works properly with Android. Anyway, what should
> I do after this to get an IP connection up?:
> 
> ModemManager[613]: <debug> [1368713230.954845] [mm-at-serial-port.c:408]
> debug_log(): (ttyACM0): --> 'AT+CGDATA="M-RAW_IP",1<CR>'
> ModemManager[613]: <debug> [1368713230.982978] [mm-at-serial-port.c:408]
> debug_log(): (ttyACM0): <-- '<CR><LF>CONNECT<CR><LF>'
> ModemManager[613]: (infineon/mm-broadband-bearer-infineon.c:164):data_ready:
> runtime check failed: (ctx->self->priv->current_ip_config == NULL)
> ModemManager[613]: <debug> [1368713230.984353] [mm-serial-port.c:1003]
> mm_serial_port_close(): (ttyACM0) device open count is 2 (close)
> ModemManager[613]: <debug> [1368713230.985098] [mm-port.c:149]
> mm_port_set_connected(): (ttyACM0): port now connected

Just wait... Still need to finish the implementation.

So far, the logs look really great, just give us some time to finish the support :)

Comment 12 Marius Kotsbak 2013-05-24 14:14:02 UTC

I verified manually with minicom that the second port does not respond to at commands. Could it be that that port is either is used as data port, or that it is only working then the first port is busy doing PPP?

Comment 13 Dan Williams 2013-05-24 16:12:18 UTC

Could be the case, but since the Infineon modem appears to have commands to get the static IP from the firmware, I'd assume that the modem doesn't use PPP normally but instead some kind of tun/tap or ethernet-type port instead.  Can you grab 'lsusb' for the device for me?

Comment 14 Marius Kotsbak 2013-05-24 17:10:29 UTC

Created attachment 245255 [details]
Attached lsusb of Nexus 7 3G

Japp, there is some CDC Data stuff there. Attached lsusb.

Comment 15 Dan Williams 2013-05-24 17:38:32 UTC

Ok, so it actually looks like the device exposes *4* CDC-ACM ports that are supposed to accept AT commands.  That's it; there's 8 interfaces, and every even-numbered interface is a CDC-ACM control interface, and every odd-numbered interface is that control itnerface's data interface.  That's all standard.

Do you see 4 ttyACMx interfaces?  Does MM try to probe all of them?

Comment 16 Marius Kotsbak 2013-05-24 17:46:57 UTC

Nope, just two:

[    8.669383] usb 1-1: new high speed USB device number 2 using tegra-ehci
[    8.707286] usb 1-1: New USB device found, idVendor=1519, idProduct=0020
[    8.707298] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    8.707308] usb 1-1: Product: HSIC Device
[    8.707315] usb 1-1: Manufacturer: Comneon
[    8.707322] usb 1-1: SerialNumber: 0123456789
[    8.725958] baseband_xmm_power_ipc_ap_wake_irq:no statechange required
[    8.726487] cdc_acm 1-1:1.0: This device cannot do calls on its own. It is not a modem.
[    8.727637] cdc_acm 1-1:1.0: ttyACM0: USB ACM device
[    8.730471] cdc_acm 1-1:1.2: Leaving this interface to raw_ip_net
[    8.731101] cdc_acm 1-1:1.3: Leaving this interface to raw_ip_net
[    8.731845] cdc_acm 1-1:1.4: Leaving this interface to raw_ip_net
[    8.732470] cdc_acm 1-1:1.5: Leaving this interface to raw_ip_net
[    8.733220] cdc_acm 1-1:1.6: This device cannot do calls on its own. It is not a modem.
[    8.734324] cdc_acm 1-1:1.6: ttyACM1: USB ACM device
[    8.735927] Add device 2 <Comneon HSIC Device>

Comment 17 Dan Williams 2013-05-24 18:12:34 UTC

Oh, fun, so those interfaces aren't actually AT or serial at all, even though the USB descriptors say they are, but instead are driven by something like:

https://android.googlesource.com/kernel/tegra/+/327461368f1470db28e0648febcfefb5445d4b51/drivers/net/usb/raw_ip_net.c

Looks like that driver names the devices 'rmnet%d' to apparently match the Qualcomm QMI netdevs; so I guess if the Nexus is actually using that driver we'd expect to see a few or so rmnet interfaces.

Comment 18 Marius Kotsbak 2013-05-24 18:16:59 UTC

$ ifconfig -a
dummy0    Link encap:Ethernet  HWaddr ***  
          BROADCAST NOARP  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

ip6tnl0   Link encap:UNSPEC  HWaddr 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  
          NOARP  MTU:1452  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:3804 errors:0 dropped:0 overruns:0 frame:0
          TX packets:3804 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:397359 (397.3 KB)  TX bytes:397359 (397.3 KB)

sit0      Link encap:IPv6-in-IPv4  
          NOARP  MTU:1480  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

usb0      Link encap:Ethernet  HWaddr   ***
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:0 (0.0 B)  TX bytes:0 (0.0 B)

wlan0     Link encap:Ethernet  HWaddr  ***
          inet addr:10.0.0.4  Bcast:10.0.0.255  Mask:255.255.255.0
          inet6 addr: fe80::a60:6eff:fe3c:1989/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:82968 errors:0 dropped:49 overruns:0 frame:0
          TX packets:52162 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:88296018 (88.2 MB)  TX bytes:9358326 (9.3 MB)

Comment 19 Dan Williams 2013-05-24 18:21:38 UTC

Ok, so probably not that Nvidia driver then, but likely usb0 that's the network device?  If you're able to test, can you connect with MM but then manually assign the addresses that MM gets to usb0 and see if that results in connectivity?

The infineon plugin should probably just grab whatever netdev the device exposes and use that.

Comment 20 Marius Kotsbak 2013-05-25 04:34:03 UTC

I have tried that before, running dhclient on usb0.

Seems like usb0 is USB gadget stuff for using it as a USB slave device:

[    2.329462] g_cdc gadget: using random self ethernet address
[    2.329479] g_cdc gadget: using random host ethernet address
[    2.329770] usb0: MAC 36:f9:50:85:34:d5
[    2.329779] usb0: HOST MAC 4a:f3:47:ca:a4:e8
[    2.329943] g_cdc gadget: controller 'fsl-tegra-udc' not recognized; trying CDC Composite (ECM + ACM)
[    2.329981] g_cdc gadget: CDC Composite Gadget, version: King Kamehameha Day 2008
[    2.329996] g_cdc gadget: g_cdc ready

Anyway, I see that I get an IP address:

May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.417475] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): --> 'AT+CGDCONT?<CR>'
May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.439924] [mm-at-serial-port.c:408] debug_log(): (ttyACM0): <-- '<CR><LF>+CGDCONT: 1,"IP","internet.netcom.no","46.15.3.2",0,0<CR><LF><CR><LF>OK<CR><LF>'
May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.440508] [mm-broadband-bearer.c:931] parse_pdp_list(): Found '1' PDP contexts
May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.440766] [mm-broadband-bearer.c:938] parse_pdp_list():   PDP context [cid=1] [type='ipv4'] [apn='internet.netcom.no']
May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.440989] [mm-broadband-bearer.c:959] parse_pdp_list(): Found PDP context with CID 1 and PDP type ipv4 for APN 'internet.netcom.no'
May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.441267] [mm-serial-port.c:958] mm_serial_port_open(): (ttyACM0) device open count is 3 (open)
May 25 06:25:38 marius-Nexus7 lt-ModemManager[24638]: <debug> [1369455938.441545] [mm-serial-port.c:1003] mm_serial_port_close(): (ttyACM0) device open count is 2 (close)

Comment 21 Marius Kotsbak 2013-05-25 04:46:40 UTC

Maybe that Android kernel module must be added to Linux then?

Comment 22 Aleksander Morgado 2013-05-27 23:28:49 UTC

New branch: aleksander/infineon-rawip

The branch tries to prepare a TUN device tunneling to the just-connected TTY. Completely untested for now...

Comment 23 Marius Kotsbak 2013-05-28 12:36:39 UTC

Created attachment 245451 [details]
ModemManager log of connection test using new rawip branch

Comment 24 Aleksander Morgado 2013-05-28 14:08:57 UTC

(In reply to comment #23)
> Created an attachment (id=245451) [details]
> ModemManager log of connection test un

ModemManager[19798]: (infineon/mm-broadband-bearer-infineon.c:422):authenticate_ready: code should not be reached
ModemManager[19798]: <debug> [1369743429.674429] [mm-serial-port.c:477] mm_serial_port_open(): (ttyACM0) device open count is 4 (open)
ModemManager[19798]: mm_at_serial_port_queue_command: assertion `command != NULL' failed

Pushed a fix to avoid that issue... new test welcome.

Comment 25 Marius Kotsbak 2013-05-28 18:50:10 UTC

Created attachment 245481 [details]
New connection problem

Comment 26 Dan Williams 2013-05-28 20:09:05 UTC

See Bug 701151 for the +CGDCONT thing, MM shouldn't be trying to create a new context with the same connection parameters as one that already exists, especially since it just found the one it wants to use.

Comment 27 Marius Kotsbak 2013-08-09 23:05:39 UTC

This almost works now, but this is what happens:

ModemManager[3803]: <debug> [1376089182.074139] [mm-at-serial-port.c:411] debug_log(): (ttyACM0): --> 'AT+CGDATA="M-RAW_IP",1<CR>'
ModemManager[3803]: <debug> [1376089182.113341] [mm-at-serial-port.c:411] debug_log(): (ttyACM0): <-- '<CR><LF>CONNECT<CR><LF>'
ModemManager[3803]: <debug> [1376089182.114151] [infineon/mm-broadband-bearer-infineon.c:200] data_ready(): Creating TUN device '/dev/ttyACM0<->bearer0'...
ModemManager: symbol lookup error: /usr/local/lib/ModemManager/libmm-plugin-infineon.so: undefined symbol: mm_rawip_serial_port_new

I have made a clean build from this branch so I don't think its mixing up any other code or system installed libs (modemmanager Ubuntu package removed).

I think there is a problem with the build system so that the new mm-rawip-serial-port is not built static or dynamic linked from libmm-plugin-infineon.

Comment 28 Aleksander Morgado 2014-10-14 11:35:43 UTC

Moving bugreport to the new ModemManager bugzilla in fd.o; summarized the issue
there as well. Please subscribe to the new bugreport to get new updates.

https://bugs.freedesktop.org/show_bug.cgi?id=84989

Closing this report as NOTGNOME.