Problem with Simple.Connect

[Pablo Martí Gamboa]

Hi all,

I'm getting a unreliable behavior with Simple.Connect, the first call will succeed, but further calls won't.

Going through the logs with Tambet, we have noticed that there is something weird going on with IPv6 code:

( http://pastebin.ca/1597233 )

Oct  6 10:26:43 lenovo NetworkManager: <info>  (/dev/ttyUSB0): device state change: 4 -> 5 (reason 0)

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 2 of 5 (Device Configure) successful.

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 2 of 5 (Device Configure) complete.

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 3 of 5 (IP Configure Start) started...

Oct  6 10:26:43 lenovo NetworkManager: <info>  (/dev/ttyUSB0): device state change: 5 -> 7 (reason 0)

Oct  6 10:26:43 lenovo NetworkManager: <info>  Starting pppd connection

Oct  6 10:26:43 lenovo NetworkManager: <debug> [1254817603.714520] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute /dev/ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/3 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so

Oct  6 10:26:43 lenovo NetworkManager: <debug> [1254817603.726521] nm_ppp_manager_start(): ppp started with pid 3625

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled...

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started...

Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation (/dev/ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete.

Oct  6 10:26:51 lenovo wpa_supplicant[1228]: CTRL-EVENT-SCAN-RESULTS 

Oct  6 10:27:04 lenovo NetworkManager: <WARN>  pppd_timed_out(): Looks like pppd didn't initialize our dbus module

Oct  6 10:27:04 lenovo NetworkManager: <info>  (/dev/ttyUSB0): device state change: 7 -> 9 (reason 14)

Oct  6 10:27:04 lenovo NetworkManager: <info>  Marking connection 'Vodafone (Airtel) connection' invalid.

As you can see, it starts stage 4/5 IP6, then goes to 3/5 of IP. After that I get a pppd_timed_out because it times out. It seems there is something weird going related to IPv6.

Tambet recommended me to create a simple test case that, issues a Connect.Simple call and then starts pppd manually without the ipparam argument. This results in a better reliability ( 5 successful connections in a row). Attached you can find the script.

At this stage I'm quite lost, Tambet has mentioned that there was a "recent" ipv6 merge that could be related to it. Any hints / ideas about what to try?

Best regards,

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"

[connect_simple.py]

---

#!/usr/bin/env python

import os
import sys
import time

import dbus
from wader.common.consts import (WADER_SERVICE, WADER_OBJPATH, WADER_INTFACE,
                                 SPL_INTFACE, MDM_INTFACE)

def usage():
    print "*" * 62
    print "usage:"
    print './connect_simple.py [/org/freedesktop/Hal/devices/usb_device_12d1_1003_noserial_if0_serial_usb_0]'
    print "*" * 62

def main():
    try:
        udi = sys.argv[1:]
    except:
        udi = None

    # obtain wader service and get the first available device
    if not udi:
        obj = dbus.SystemBus().get_object(WADER_SERVICE, WADER_OBJPATH)
        udi = obj.EnumerateDevices(dbus_interface=WADER_INTFACE)[0]

    print "GETTING REFERENCE TO UDI", udi
    device = dbus.SystemBus().get_object(WADER_SERVICE, udi)

    # .Enable the device (no PIN auth checking)
    device.Enable(True, dbus_interface=MDM_INTFACE)

    settings = {
        'network_mode' : 1,
        'apn' : 'ac.vodafone.es',
        'number' : '*99#',
    }

    device.Connect(settings, dbus_interface=SPL_INTFACE)
    time.sleep(1)

    os.system("/usr/sbin/pppd nodetach lock nodefaultroute /dev/ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so")
    time.sleep(40)

    device.Disconnect(dbus_interface=SPL_INTFACE)
    # now that we are done, issue an .Enable(False) to free resources
    device.Enable(False, dbus_interface=MDM_INTFACE)
    return 0


if __name__ == '__main__':
    sys.exit(main())

---

_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Dan Williams]

On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa wrote:
> Hi all,
>
> I'm getting a unreliable behavior with Simple.Connect, the first call
> will succeed, but further calls won't.
>
>
> Going through the logs with Tambet, we have noticed that there is
> something weird going on with IPv6 code:

I think that's mostly unrelated; NM will not finish the connection until
both IP4 and IP6 have completed, but of course in your case you don't
have IP6 configured since this is a mobile broadband connection, so that
stage is just a null-op.  The real problem seems to be:

Oct  6 10:27:04 lenovo NetworkManager: <WARN>  pppd_timed_out(): Looks
like pppd didn't initialize our dbus module

which indicates that PPP did not successfully complete, or that the NM
pppd plugin could not push the IP4 config information back to
NetworkManager.  Can you run NM like so:

NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

and then reproduce the issue?  That should show a lot more log output
(including pppd's stdout debugging info) that will allow us to figure
out what's going on here.

Also, did this just start happening, or has this been around for a bit?
Or did you just install something new?

Dan

>
> ( http://pastebin.ca/1597233 )
>
>
> Oct  6 10:26:43 lenovo NetworkManager: <info>  (/dev/ttyUSB0): device
> state change: 4 -> 5 (reason 0)
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 2 of 5 (Device Configure) successful.
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 2 of 5 (Device Configure) complete.
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
> Oct  6 10:26:43 lenovo NetworkManager: <info>  (/dev/ttyUSB0): device
> state change: 5 -> 7 (reason 0)
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Starting pppd
> connection
> Oct  6 10:26:43 lenovo NetworkManager: <debug> [1254817603.714520]
> nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock
> nodefaultroute /dev/ttyUSB0 noipdefault noauth usepeerdns
> lcp-echo-failure 0 lcp-echo-interval 0
> ipparam /org/freedesktop/NetworkManager/PPP/3
> plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
> Oct  6 10:26:43 lenovo NetworkManager: <debug> [1254817603.726521]
> nm_ppp_manager_start(): ppp started with pid 3625
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled...
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started...
> Oct  6 10:26:43 lenovo NetworkManager: <info>  Activation
> (/dev/ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete.
> Oct  6 10:26:51 lenovo wpa_supplicant[1228]: CTRL-EVENT-SCAN-RESULTS
> Oct  6 10:27:04 lenovo NetworkManager: <WARN>  pppd_timed_out(): Looks
> like pppd didn't initialize our dbus module
> Oct  6 10:27:04 lenovo NetworkManager: <info>  (/dev/ttyUSB0): device
> state change: 7 -> 9 (reason 14)
> Oct  6 10:27:04 lenovo NetworkManager: <info>  Marking connection
> 'Vodafone (Airtel) connection' invalid.
>
>
> As you can see, it starts stage 4/5 IP6, then goes to 3/5 of IP. After
> that I get a pppd_timed_out because it times out. It seems there is
> something weird going related to IPv6.
>
>
> Tambet recommended me to create a simple test case that, issues a
> Connect.Simple call and then starts pppd manually without the ipparam
> argument. This results in a better reliability ( 5 successful
> connections in a row). Attached you can find the script.
>
>
> At this stage I'm quite lost, Tambet has mentioned that there was a
> "recent" ipv6 merge that could be related to it. Any hints / ideas
> about what to try?
>
>
> Best regards,
>
>
> --
> Pablo Martí
> http://www.linkedin.com/in/pmarti || http://www.warp.es
> python -c "print '706d6172746940776172702e6573'.decode('hex')"
>
>
> _______________________________________________
> NetworkManager-list mailing list
> NetworkManager-list@...
> http://mail.gnome.org/mailman/listinfo/networkmanager-list

_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/7 Dan Williams <dcbw@...>

On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa wrote:
> Hi all,
>
> I'm getting a unreliable behavior with Simple.Connect, the first call
> will succeed, but further calls won't.
>
>
> Going through the logs with Tambet, we have noticed that there is
> something weird going on with IPv6 code:

I think that's mostly unrelated; NM will not finish the connection until
both IP4 and IP6 have completed, but of course in your case you don't
have IP6 configured since this is a mobile broadband connection, so that
stage is just a null-op.  The real problem seems to be:

Oct  6 10:27:04 lenovo NetworkManager: <WARN>  pppd_timed_out(): Looks
like pppd didn't initialize our dbus module

which indicates that PPP did not successfully complete, or that the NM
pppd plugin could not push the IP4 config information back to
NetworkManager.  Can you run NM like so:

NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

see successful.log and error.log (first and second attempts respectively)
 

and then reproduce the issue?  That should show a lot more log output
(including pppd's stdout debugging info) that will allow us to figure
out what's going on here.

Also, did this just start happening, or has this been around for a bit?
Or did you just install something new?

I forgot to mention that this with NetworkManager + Wader rather than NM + MM. I'm testing the integration of both packages before (hopefully) the release of Ubuntu 9.10 final. I hadn't tested Simple.Connect in a while.

Thanks a lot for your time and help!!

Pablo

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


[error.log]

---

NetworkManager: <info>  Activation (ttyUSB0) starting connection 'Vodafone'
NetworkManager: <info>  (ttyUSB0): device state change: 3 -> 4 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  (ttyUSB0): device state change: 4 -> 6 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  (ttyUSB0): device state change: 6 -> 4 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager: <info>  (ttyUSB0): device state change: 4 -> 5 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager: <info>  Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager: <info>  (ttyUSB0): device state change: 5 -> 7 (reason 0)
NetworkManager: <info>  Starting pppd connection
NetworkManager: <debug> [1254985070.460266] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute debug user vodafone ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/2 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
** Message: nm-ppp-plugin: (plugin_init): initializing
NetworkManager: <debug> [1254985070.468209] nm_ppp_manager_start(): ppp started with pid 3471
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started...
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete.
** Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
NetworkManager: <WARN>  pppd_timed_out(): Looks like pppd didn't initialize our dbus module
NetworkManager: <info>  (ttyUSB0): device state change: 7 -> 9 (reason 14)
NetworkManager: <info>  Marking connection 'Vodafone' invalid.
NetworkManager: Tried to set deprecated property gsm/puk
NetworkManager: <info>  Activation (ttyUSB0) failed.
NetworkManager: <info>  (ttyUSB0): device state change: 9 -> 3 (reason 0)
NetworkManager: <info>  (ttyUSB0): deactivating device (reason: 0).
NetworkManager: flush_routes: assertion `iface_idx >= 0' failed
NetworkManager: flush_addresses: assertion `iface_idx >= 0' failed
NetworkManager: <info>  Policy set 'Auto eth0' (eth0) as default for routing and DNS.
NetworkManager: <debug> [1254985093.001338] ensure_killed(): waiting for ppp pid 3471 to exit

---

[success.log]

---

NetworkManager: <info>  Activation (ttyUSB0) starting connection 'Vodafone'
NetworkManager: <info>  (ttyUSB0): device state change: 3 -> 4 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  (ttyUSB0): device state change: 4 -> 6 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) started...
NetworkManager: <info>  (ttyUSB0): device state change: 6 -> 4 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 1 of 5 (Device Prepare) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) starting...
NetworkManager: <info>  (ttyUSB0): device state change: 4 -> 5 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) successful.
NetworkManager: <info>  Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) scheduled.
NetworkManager: <info>  Activation (ttyUSB0) Stage 2 of 5 (Device Configure) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) started...
NetworkManager: <info>  (ttyUSB0): device state change: 5 -> 7 (reason 0)
NetworkManager: <info>  Starting pppd connection
NetworkManager: <debug> [1254985020.817535] nm_ppp_manager_start(): Command line: /usr/sbin/pppd nodetach lock nodefaultroute debug user vodafone ttyUSB0 noipdefault noauth usepeerdns lcp-echo-failure 0 lcp-echo-interval 0 ipparam /org/freedesktop/NetworkManager/PPP/1 plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so
NetworkManager: <debug> [1254985020.818679] nm_ppp_manager_start(): ppp started with pid 3360
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 3 of 5 (IP Configure Start) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) started...
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP6 Configure Get) complete.
Plugin /usr/lib/pppd/2.4.4/nm-pppd-plugin.so loaded.
** Message: nm-ppp-plugin: (plugin_init): initializing
** Message: nm-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
using channel 1
Using interface ppp0
Connect: ppp0 <--> /dev/ttyUSB0
** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x4f1346bc> <pcomp> <accomp>]
NetworkManager:    SCPlugin-Ifupdown: devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
NetworkManager:    SCPlugin-Ifupdown: device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no ifupdown configuration found.
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x1b3bb24> <pcomp> <accomp>]
sent [LCP ConfAck id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0x1b3bb24> <pcomp> <accomp>]
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x4f1346bc> <pcomp> <accomp>]
** Message: nm-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
rcvd [LCP DiscReq id=0x1 magic=0x1b3bb24]
rcvd [CHAP Challenge id=0x1 <3cf39c0074e82440923819378015d158>, name = "UMTS_CHAP_SRVR"]
** Message: nm-ppp-plugin: (get_credentials): passwd-hook, requesting credentials...
NetworkManager: Tried to set deprecated property gsm/puk
** Message: nm-ppp-plugin: (get_credentials): got credentials from NetworkManager
sent [CHAP Response id=0x1 <fe3493b049880774f03de9588b3aca26>, name = "vodafone"]
rcvd [CHAP Success id=0x1 ""]
CHAP authentication succeeded
CHAP authentication succeeded
** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]
Protocol-Reject for 'Compression Control Protocol' (0x80fd) received
rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
rcvd [IPCP ConfNak id=0x2 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x3 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
rcvd [IPCP ConfNak id=0x3 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x4 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
rcvd [IPCP ConfNak id=0x4 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> <ms-wins 10.11.12.13> <ms-wins 10.11.12.14>]
sent [IPCP ConfReq id=0x5 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
rcvd [IPCP ConfReq id=0x0]
sent [IPCP ConfNak id=0x0 <addr 0.0.0.0>]
rcvd [IPCP ConfRej id=0x5 <compress VJ 0f 01>]
sent [IPCP ConfReq id=0x6 <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
rcvd [IPCP ConfReq id=0x1]
sent [IPCP ConfAck id=0x1]
rcvd [IPCP ConfNak id=0x6 <addr 77.210.32.210> <ms-dns1 212.73.32.3> <ms-dns2 212.73.32.67>]
sent [IPCP ConfReq id=0x7 <addr 77.210.32.210> <ms-dns1 212.73.32.3> <ms-dns2 212.73.32.67>]
rcvd [IPCP ConfAck id=0x7 <addr 77.210.32.210> <ms-dns1 212.73.32.3> <ms-dns2 212.73.32.67>]
Could not determine remote IP address: defaulting to 10.64.64.64
Cannot determine ethernet address for proxy ARP
local  IP address 77.210.32.210
remote IP address 10.64.64.64
primary   DNS address 212.73.32.3
secondary DNS address 212.73.32.67
** Message: nm-ppp-plugin: (nm_phasechange): status 9 / phase 'running'
** Message: nm-ppp-plugin: (nm_ip_up): ip-up event
** Message: nm-ppp-plugin: (nm_ip_up): sending Ip4Config to NetworkManager...
Script /etc/ppp/ip-up started (pid 3371)
NetworkManager: <info>  PPP manager(IP Config Get) reply received.
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) started...
NetworkManager: <info>  Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) scheduled...
NetworkManager: <info>  Activation (ttyUSB0) Stage 4 of 5 (IP4 Configure Get) complete.
NetworkManager: <info>  Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) started...
Script /etc/ppp/ip-up finished (pid 3371), status = 0x0
NetworkManager: <info>  Policy set 'Auto eth0' (eth0) as default for routing and DNS.
NetworkManager: <info>  (ttyUSB0): device state change: 7 -> 8 (reason 0)
NetworkManager: <info>  Activation (ttyUSB0) successful, device activated.
NetworkManager: <info>  Activation (ttyUSB0) Stage 5 of 5 (IP Configure Commit) complete.
NetworkManager: <info>  (ttyUSB0): device state change: 8 -> 3 (reason 39)
NetworkManager: <info>  (ttyUSB0): deactivating device (reason: 39).
NetworkManager: <info>  Policy set 'Auto eth0' (eth0) as default for routing and DNS.
Terminating on signal 15
** Message: nm-ppp-plugin: (nm_phasechange): status 10 / phase 'terminate'
** Message: nm-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
Connect time 0.6 minutes.
Sent 0 bytes, received 52 bytes.
Script /etc/ppp/ip-down started (pid 3446)
** Message: nm-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
sent [LCP TermReq id=0x2 "User request"]
rcvd [LCP TermAck id=0x2]
** Message: nm-ppp-plugin: (nm_phasechange): status 11 / phase 'disconnect'
Connection terminated.
NetworkManager:    SCPlugin-Ifupdown: devices removed (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
** Message: nm-ppp-plugin: (nm_phasechange): status 1 / phase 'dead'
Script /etc/ppp/ip-down finished (pid 3446), status = 0x0
** Message: nm-ppp-plugin: (nm_exit_notify): cleaning up
NetworkManager: <debug> [1254985062.000334] ensure_killed(): waiting for ppp pid 3360 to exit
NetworkManager: <debug> [1254985062.000466] ensure_killed(): ppp pid 3360 cleaned up

---

_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/8 Pablo Martí Gamboa <pmarti@...>

2009/10/7 Dan Williams <dcbw@...>

On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa wrote:
> Hi all,
>
> I'm getting a unreliable behavior with Simple.Connect, the first call
> will succeed, but further calls won't.
>
>
> Going through the logs with Tambet, we have noticed that there is
> something weird going on with IPv6 code:

I think that's mostly unrelated; NM will not finish the connection until
both IP4 and IP6 have completed, but of course in your case you don't
have IP6 configured since this is a mobile broadband connection, so that
stage is just a null-op.  The real problem seems to be:

Oct  6 10:27:04 lenovo NetworkManager: <WARN>  pppd_timed_out(): Looks
like pppd didn't initialize our dbus module

which indicates that PPP did not successfully complete, or that the NM
pppd plugin could not push the IP4 config information back to
NetworkManager.  Can you run NM like so:

NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

see successful.log and error.log (first and second attempts respectively)
 

and then reproduce the issue?  That should show a lot more log output
(including pppd's stdout debugging info) that will allow us to figure
out what's going on here.

Also, did this just start happening, or has this been around for a bit?
Or did you just install something new?

I forgot to mention that this with NetworkManager + Wader rather than NM + MM. I'm testing the integration of both packages before (hopefully) the release of Ubuntu 9.10 final. I hadn't tested Simple.Connect in a while.

I forgot to mention that when I press "Disconnect" from nm-applet, that just issues an "Enable(false)" to the device rather than "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody seemed to recall why that decision had been made, they just remembered that it was more reliable for a particular device. In my case it is the other way around! will nm0.8 ship like this?

 

Thanks a lot for your time and help!!

Pablo

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Dan Williams]

On Thu, 2009-10-08 at 09:02 +0200, Pablo Martí Gamboa wrote:

>
>
> 2009/10/7 Dan Williams <dcbw@...>
>         On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa wrote:
>         > Hi all,
>         >
>         > I'm getting a unreliable behavior with Simple.Connect, the
>         first call
>         > will succeed, but further calls won't.
>         >
>         >
>         > Going through the logs with Tambet, we have noticed that
>         there is
>         > something weird going on with IPv6 code:
>        
>        
>         I think that's mostly unrelated; NM will not finish the
>         connection until
>         both IP4 and IP6 have completed, but of course in your case
>         you don't
>         have IP6 configured since this is a mobile broadband
>         connection, so that
>         stage is just a null-op.  The real problem seems to be:
>        
>         Oct  6 10:27:04 lenovo NetworkManager: <WARN>
>          pppd_timed_out(): Looks
>         like pppd didn't initialize our dbus module
>        
>        
>         which indicates that PPP did not successfully complete, or
>         that the NM
>         pppd plugin could not push the IP4 config information back to
>         NetworkManager.  Can you run NM like so:
>        
>         NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
>
> see successful.log and error.log (first and second attempts
> respectively)
>  
>
>        
>         and then reproduce the issue?  That should show a lot more log
>         output
>         (including pppd's stdout debugging info) that will allow us to
>         figure
>         out what's going on here.
>        
>         Also, did this just start happening, or has this been around
>         for a bit?
>         Or did you just install something new?
>
> I forgot to mention that this with NetworkManager + Wader rather than
> NM + MM. I'm testing the integration of both packages before
> (hopefully) the release of Ubuntu 9.10 final. I hadn't tested
> Simple.Connect in a while.

That logfile indicates that PPP isn't able to establish a session within
the timeout.  NM times PPP out after 20 seconds, which is a pretty long
time to give PPP.  I've actually never seen PPP take more than about 5
or 10 seconds to connect, even in marginal situations on any of my 25 or
so devices.

Dan



_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Dan Williams]

On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:

>
>
> 2009/10/8 Pablo Martí Gamboa <pmarti@...>
>        
>        
>         2009/10/7 Dan Williams <dcbw@...>
>        
>                 On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa
>                 wrote:
>                 > Hi all,
>                 >
>                 > I'm getting a unreliable behavior with
>                 Simple.Connect, the first call
>                 > will succeed, but further calls won't.
>                 >
>                 >
>                 > Going through the logs with Tambet, we have noticed
>                 that there is
>                 > something weird going on with IPv6 code:
>                
>                
>                 I think that's mostly unrelated; NM will not finish
>                 the connection until
>                 both IP4 and IP6 have completed, but of course in your
>                 case you don't
>                 have IP6 configured since this is a mobile broadband
>                 connection, so that
>                 stage is just a null-op.  The real problem seems to
>                 be:
>                
>                 Oct  6 10:27:04 lenovo NetworkManager: <WARN>
>                  pppd_timed_out(): Looks
>                 like pppd didn't initialize our dbus module
>                
>                
>                 which indicates that PPP did not successfully
>                 complete, or that the NM
>                 pppd plugin could not push the IP4 config information
>                 back to
>                 NetworkManager.  Can you run NM like so:
>                
>                 NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
>        
>         see successful.log and error.log (first and second attempts
>         respectively)
>          
>        
>                
>                 and then reproduce the issue?  That should show a lot
>                 more log output
>                 (including pppd's stdout debugging info) that will
>                 allow us to figure
>                 out what's going on here.
>                
>                 Also, did this just start happening, or has this been
>                 around for a bit?
>                 Or did you just install something new?
>        
>         I forgot to mention that this with NetworkManager + Wader
>         rather than NM + MM. I'm testing the integration of both
>         packages before (hopefully) the release of Ubuntu 9.10 final.
>         I hadn't tested Simple.Connect in a while.
>        
>
> I forgot to mention that when I press "Disconnect" from nm-applet,
> that just issues an "Enable(false)" to the device rather than
> "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody
> seemed to recall why that decision had been made, they just remembered
> that it was more reliable for a particular device. In my case it is
> the other way around! will nm0.8 ship like this?

Right now NM doesn't call disconnect at all, AFAIK.  It just calls
Enable(false).  We assume that also cleans up the connection and
disables the modem, since disabling the modem implies the connection is
torn down.  Is that not working?

BTW, how do you handle breaking into the ongoing PPP session on a 1-port
modem and hanging up the connection?   +++ATH?  Or AT &D1, setting the
serial port's DTR to off and then ATH?

Dan


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/9 Dan Williams <dcbw@...>

On Thu, 2009-10-08 at 09:02 +0200, Pablo Martí Gamboa wrote:
>
>
> 2009/10/7 Dan Williams <dcbw@...>
>         On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa wrote:
>         > Hi all,
>         >
>         > I'm getting a unreliable behavior with Simple.Connect, the
>         first call
>         > will succeed, but further calls won't.
>         >
>         >
>         > Going through the logs with Tambet, we have noticed that
>         there is
>         > something weird going on with IPv6 code:
>
>
>         I think that's mostly unrelated; NM will not finish the
>         connection until
>         both IP4 and IP6 have completed, but of course in your case
>         you don't
>         have IP6 configured since this is a mobile broadband
>         connection, so that
>         stage is just a null-op.  The real problem seems to be:
>
>         Oct  6 10:27:04 lenovo NetworkManager: <WARN>
>          pppd_timed_out(): Looks
>         like pppd didn't initialize our dbus module
>
>
>         which indicates that PPP did not successfully complete, or
>         that the NM
>         pppd plugin could not push the IP4 config information back to
>         NetworkManager.  Can you run NM like so:
>
>         NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
>
> see successful.log and error.log (first and second attempts
> respectively)
>
>
>
>         and then reproduce the issue?  That should show a lot more log
>         output
>         (including pppd's stdout debugging info) that will allow us to
>         figure
>         out what's going on here.
>
>         Also, did this just start happening, or has this been around
>         for a bit?
>         Or did you just install something new?
>
> I forgot to mention that this with NetworkManager + Wader rather than
> NM + MM. I'm testing the integration of both packages before
> (hopefully) the release of Ubuntu 9.10 final. I hadn't tested
> Simple.Connect in a while.

That logfile indicates that PPP isn't able to establish a session within
the timeout.  NM times PPP out after 20 seconds, which is a pretty long
time to give PPP.  I've actually never seen PPP take more than about 5
or 10 seconds to connect, even in marginal situations on any of my 25 or
so devices.

The puzzling thing is that the very first time it will connect no problem, it is the second and third attempts that fail. Nothing in the wader log indicates that there's been a problem (the log trace of a successful and unsuccessful attempts are exactly similar). So perhaps there is a problem with that ppp timeout?

Is not like Simple.Connect is complicated right, it is basically the old connect beefed up. And the old connect reliability was way better (i.e. several connection attempts in a row no problem)

Is there anything else I can do to help you figure out this one?

Regards,

-- 

Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/9 Dan Williams <dcbw@...>

On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:
>
>
> 2009/10/8 Pablo Martí Gamboa <pmarti@...>
>
>
>         2009/10/7 Dan Williams <dcbw@...>
>
>                 On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí Gamboa
>                 wrote:
>                 > Hi all,
>                 >
>                 > I'm getting a unreliable behavior with
>                 Simple.Connect, the first call
>                 > will succeed, but further calls won't.
>                 >
>                 >
>                 > Going through the logs with Tambet, we have noticed
>                 that there is
>                 > something weird going on with IPv6 code:
>
>
>                 I think that's mostly unrelated; NM will not finish
>                 the connection until
>                 both IP4 and IP6 have completed, but of course in your
>                 case you don't
>                 have IP6 configured since this is a mobile broadband
>                 connection, so that
>                 stage is just a null-op.  The real problem seems to
>                 be:
>
>                 Oct  6 10:27:04 lenovo NetworkManager: <WARN>
>                  pppd_timed_out(): Looks
>                 like pppd didn't initialize our dbus module
>
>
>                 which indicates that PPP did not successfully
>                 complete, or that the NM
>                 pppd plugin could not push the IP4 config information
>                 back to
>                 NetworkManager.  Can you run NM like so:
>
>                 NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
>
>         see successful.log and error.log (first and second attempts
>         respectively)
>
>
>
>                 and then reproduce the issue?  That should show a lot
>                 more log output
>                 (including pppd's stdout debugging info) that will
>                 allow us to figure
>                 out what's going on here.
>
>                 Also, did this just start happening, or has this been
>                 around for a bit?
>                 Or did you just install something new?
>
>         I forgot to mention that this with NetworkManager + Wader
>         rather than NM + MM. I'm testing the integration of both
>         packages before (hopefully) the release of Ubuntu 9.10 final.
>         I hadn't tested Simple.Connect in a while.
>
>
> I forgot to mention that when I press "Disconnect" from nm-applet,
> that just issues an "Enable(false)" to the device rather than
> "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody
> seemed to recall why that decision had been made, they just remembered
> that it was more reliable for a particular device. In my case it is
> the other way around! will nm0.8 ship like this?

Right now NM doesn't call disconnect at all, AFAIK.  It just calls
Enable(false).  We assume that also cleans up the connection and
disables the modem, since disabling the modem implies the connection is
torn down.  Is that not working?

That has caused some unreliability problems with HSO devices for us. I've added a small guard that before disabling a device will disconnect it if its connected and will carry on disabling it. This has improved the reliability and can connect with hso devices several times in a row.

BTW, how do you handle breaking into the ongoing PPP session on a 1-port
modem and hanging up the connection?   +++ATH?  Or AT &D1, setting the
serial port's DTR to off and then ATH?

We were using the DTR approach (without ATH), and that was working nicely for us (NM 0.7.1), then when we switched to NM 0.8 and faced all this Simple.Connect problems I tried switching to +++ATH, but it hasn't improved anything...

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Dan Williams]

On Fri, 2009-10-09 at 10:00 +0200, Pablo Martí Gamboa wrote:

>
>
> 2009/10/9 Dan Williams <dcbw@...>
>        
>         On Thu, 2009-10-08 at 09:02 +0200, Pablo Martí Gamboa wrote:
>         >
>         >
>         > 2009/10/7 Dan Williams <dcbw@...>
>         >         On Tue, 2009-10-06 at 12:43 +0200, Pablo Martí
>         Gamboa wrote:
>         >         > Hi all,
>         >         >
>         >         > I'm getting a unreliable behavior with
>         Simple.Connect, the
>         >         first call
>         >         > will succeed, but further calls won't.
>         >         >
>         >         >
>         >         > Going through the logs with Tambet, we have
>         noticed that
>         >         there is
>         >         > something weird going on with IPv6 code:
>         >
>         >
>         >         I think that's mostly unrelated; NM will not finish
>         the
>         >         connection until
>         >         both IP4 and IP6 have completed, but of course in
>         your case
>         >         you don't
>         >         have IP6 configured since this is a mobile broadband
>         >         connection, so that
>         >         stage is just a null-op.  The real problem seems to
>         be:
>         >
>         >         Oct  6 10:27:04 lenovo NetworkManager: <WARN>
>         >          pppd_timed_out(): Looks
>         >         like pppd didn't initialize our dbus module
>         >
>         >
>         >         which indicates that PPP did not successfully
>         complete, or
>         >         that the NM
>         >         pppd plugin could not push the IP4 config
>         information back to
>         >         NetworkManager.  Can you run NM like so:
>         >
>         >         NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
>         >
>         > see successful.log and error.log (first and second attempts
>         > respectively)
>         >
>         >
>         >
>         >         and then reproduce the issue?  That should show a
>         lot more log
>         >         output
>         >         (including pppd's stdout debugging info) that will
>         allow us to
>         >         figure
>         >         out what's going on here.
>         >
>         >         Also, did this just start happening, or has this
>         been around
>         >         for a bit?
>         >         Or did you just install something new?
>         >
>         > I forgot to mention that this with NetworkManager + Wader
>         rather than
>         > NM + MM. I'm testing the integration of both packages before
>         > (hopefully) the release of Ubuntu 9.10 final. I hadn't
>         tested
>         > Simple.Connect in a while.
>        
>        
>         That logfile indicates that PPP isn't able to establish a
>         session within
>         the timeout.  NM times PPP out after 20 seconds, which is a
>         pretty long
>         time to give PPP.  I've actually never seen PPP take more than
>         about 5
>         or 10 seconds to connect, even in marginal situations on any
>         of my 25 or
>         so devices.
>
>
> The puzzling thing is that the very first time it will connect no
> problem, it is the second and third attempts that fail. Nothing in the
> wader log indicates that there's been a problem (the log trace of a
> successful and unsuccessful attempts are exactly similar). So perhaps
> there is a problem with that ppp timeout?
>
>
> Is not like Simple.Connect is complicated right, it is basically the
> old connect beefed up. And the old connect reliability was way better
> (i.e. several connection attempts in a row no problem)
>
>
> Is there anything else I can do to help you figure out this one?

I'd hazard a guess that we're not disconnecting or hanging up the
previous connection correctly somewhere.  Disable implies disconnect of
course, so any Enable(False) handler should also be ensuring clean
disconnection.

Can you run NM with:

NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

and lets see what comes out?  That will provide the PPP spew which could
help us get closer.

Dan



_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Dan Williams]

On Fri, 2009-10-09 at 10:03 +0200, Pablo Martí Gamboa wrote:

>
>
> 2009/10/9 Dan Williams <dcbw@...>
>        
>         On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:
>         >
>         >
>         > 2009/10/8 Pablo Martí Gamboa <pmarti@...>
>         >
>         >
>         >         2009/10/7 Dan Williams <dcbw@...>
>         >
>         >                 On Tue, 2009-10-06 at 12:43 +0200, Pablo
>         Martí Gamboa
>         >                 wrote:
>         >                 > Hi all,
>         >                 >
>         >                 > I'm getting a unreliable behavior with
>         >                 Simple.Connect, the first call
>         >                 > will succeed, but further calls won't.
>         >                 >
>         >                 >
>         >                 > Going through the logs with Tambet, we
>         have noticed
>         >                 that there is
>         >                 > something weird going on with IPv6 code:
>         >
>         >
>         >                 I think that's mostly unrelated; NM will not
>         finish
>         >                 the connection until
>         >                 both IP4 and IP6 have completed, but of
>         course in your
>         >                 case you don't
>         >                 have IP6 configured since this is a mobile
>         broadband
>         >                 connection, so that
>         >                 stage is just a null-op.  The real problem
>         seems to
>         >                 be:
>         >
>         >                 Oct  6 10:27:04 lenovo NetworkManager:
>         <WARN>
>         >                  pppd_timed_out(): Looks
>         >                 like pppd didn't initialize our dbus module
>         >
>         >
>         >                 which indicates that PPP did not
>         successfully
>         >                 complete, or that the NM
>         >                 pppd plugin could not push the IP4 config
>         information
>         >                 back to
>         >                 NetworkManager.  Can you run NM like so:
>         >
>         >                 NM_PPP_DEBUG=1 /usr/sbin/NetworkManager
>         --no-daemon
>         >
>         >         see successful.log and error.log (first and second
>         attempts
>         >         respectively)
>         >
>         >
>         >
>         >                 and then reproduce the issue?  That should
>         show a lot
>         >                 more log output
>         >                 (including pppd's stdout debugging info)
>         that will
>         >                 allow us to figure
>         >                 out what's going on here.
>         >
>         >                 Also, did this just start happening, or has
>         this been
>         >                 around for a bit?
>         >                 Or did you just install something new?
>         >
>         >         I forgot to mention that this with NetworkManager +
>         Wader
>         >         rather than NM + MM. I'm testing the integration of
>         both
>         >         packages before (hopefully) the release of Ubuntu
>         9.10 final.
>         >         I hadn't tested Simple.Connect in a while.
>         >
>         >
>         > I forgot to mention that when I press "Disconnect" from
>         nm-applet,
>         > that just issues an "Enable(false)" to the device rather
>         than
>         > "Disconnect(); Enable(false);", I asked yesterday in #nm and
>         nobody
>         > seemed to recall why that decision had been made, they just
>         remembered
>         > that it was more reliable for a particular device. In my
>         case it is
>         > the other way around! will nm0.8 ship like this?
>        
>        
>         Right now NM doesn't call disconnect at all, AFAIK.  It just
>         calls
>         Enable(false).  We assume that also cleans up the connection
>         and
>         disables the modem, since disabling the modem implies the
>         connection is
>         torn down.  Is that not working?
>
>
> That has caused some unreliability problems with HSO devices for us.
> I've added a small guard that before disabling a device will
> disconnect it if its connected and will carry on disabling it. This
> has improved the reliability and can connect with hso devices several
> times in a row.
>
>
>        
>         BTW, how do you handle breaking into the ongoing PPP session
>         on a 1-port
>         modem and hanging up the connection?   +++ATH?  Or AT &D1,
>         setting the
>         serial port's DTR to off and then ATH?
>
>
> We were using the DTR approach (without ATH), and that was working
> nicely for us (NM 0.7.1), then when we switched to NM 0.8 and faced
> all this Simple.Connect problems I tried switching to +++ATH, but it
> hasn't improved anything...

But with DTR and without ATH, isn't the connection still active?  It
thought DTR transitions just broke into command mode so you *could* run
ATH.  I didn't think they terminated an active data connection too...

Dan


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Eugene Crosser]

Dan Williams wrote:

> But with DTR and without ATH, isn't the connection still active?  It
> thought DTR transitions just broke into command mode so you *could* run
> ATH.  I didn't think they terminated an active data connection too...

In the olden days of dialup modems, dropping DTR was the "official" way to
terminate the connection. The sequence of "<pause>+++<pause>ATH\r" was
considered a workaround, for the case when you had a three wire cable and the
modem was configured to ignore (the absence of) DTR.

Eugene



_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Herriot, Nicholas, VF UK - Technology (TS)]

I thought the +++ escape sequence was rarely used. I've read that it's usually disabled to avoid malfunction in case these characters are legitimately a part of the data stream?

If this is a workaround where do people suggest the intelligence be placed?


-----Original Message-----
From: Eugene Crosser [mailto:crosser@...]
Sent: 14 October 2009 07:05
To: Dan Williams
Cc: Pablo Martí Gamboa; Herriot, Nicholas, VF-Group; networkmanager-list@...
Subject: Re: Problem with Simple.Connect

Dan Williams wrote:

> But with DTR and without ATH, isn't the connection still active?  It
> thought DTR transitions just broke into command mode so you *could*
> run ATH.  I didn't think they terminated an active data connection too...

In the olden days of dialup modems, dropping DTR was the "official" way to terminate the connection. The sequence of "<pause>+++<pause>ATH\r" was considered a workaround, for the case when you had a three wire cable and the modem was configured to ignore (the absence of) DTR.

Eugene

_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Eugene Crosser]

Herriot, Nicholas, VF-Group wrote:
> I thought the +++ escape sequence was rarely used. I've read that it's usually disabled
> to avoid malfunction in case these characters are legitimately a part of the data stream?

Indeed. Though accidental misinterpretation was very unlikely, because
the modem treated the "+++" sequence special only if it was preceded by,
and followed by, a period of "silence" on the line.

I have no information how the modern devices behave in relation to DTR
transitions (which are "virtual" anyway since there is no real serial
line there), and "+++" sequence.

> If this is a workaround where do people suggest the intelligence be placed?
>
>
> -----Original Message-----
> From: Eugene Crosser [mailto:crosser@...]
> Sent: 14 October 2009 07:05
> To: Dan Williams
> Cc: Pablo Martí Gamboa; Herriot, Nicholas, VF-Group; networkmanager-list@...
> Subject: Re: Problem with Simple.Connect
>
> Dan Williams wrote:
>
>> But with DTR and without ATH, isn't the connection still active?  It
>> thought DTR transitions just broke into command mode so you *could*
>> run ATH.  I didn't think they terminated an active data connection too...
>
> In the olden days of dialup modems, dropping DTR was the "official" way to terminate the connection. The sequence of "<pause>+++<pause>ATH\r" was considered a workaround, for the case when you had a three wire cable and the modem was configured to ignore (the absence of) DTR.
>
> Eugene

_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/13 Dan Williams <dcbw@...>

On Fri, 2009-10-09 at 10:00 +0200, Pablo Martí Gamboa wrote:
>
>
> The puzzling thing is that the very first time it will connect no
> problem, it is the second and third attempts that fail. Nothing in the
> wader log indicates that there's been a problem (the log trace of a
> successful and unsuccessful attempts are exactly similar). So perhaps
> there is a problem with that ppp timeout?
>
>
> Is not like Simple.Connect is complicated right, it is basically the
> old connect beefed up. And the old connect reliability was way better
> (i.e. several connection attempts in a row no problem)
>
>
> Is there anything else I can do to help you figure out this one?

I'd hazard a guess that we're not disconnecting or hanging up the
previous connection correctly somewhere.  Disable implies disconnect of
course, so any Enable(False) handler should also be ensuring clean
disconnection.

Can you run NM with:

NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

and lets see what comes out?  That will provide the PPP spew which could
help us get closer.

Attached you can find success1.log and error2.log, the first attempt succeed and the second failed.

I've tried with:

 * plain '+++ATH\r'

 * lower & raise DTR

 * lower & raise DTR + 'ATH\r'

And the outcome was the same

Regards,

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"




_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/14 Pablo Martí Gamboa <pmarti@...>

2009/10/13 Dan Williams <dcbw@...>

On Fri, 2009-10-09 at 10:00 +0200, Pablo Martí Gamboa wrote:
>
>

> The puzzling thing is that the very first time it will connect no
> problem, it is the second and third attempts that fail. Nothing in the
> wader log indicates that there's been a problem (the log trace of a
> successful and unsuccessful attempts are exactly similar). So perhaps
> there is a problem with that ppp timeout?
>
>
> Is not like Simple.Connect is complicated right, it is basically the
> old connect beefed up. And the old connect reliability was way better
> (i.e. several connection attempts in a row no problem)
>
>
> Is there anything else I can do to help you figure out this one?

I'd hazard a guess that we're not disconnecting or hanging up the
previous connection correctly somewhere.  Disable implies disconnect of
course, so any Enable(False) handler should also be ensuring clean
disconnection.

Can you run NM with:

NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon

and lets see what comes out?  That will provide the PPP spew which could
help us get closer.

Attached you can find success1.log and error2.log, the first attempt succeed and the second failed.

I've tried with:

 * plain '+++ATH\r'

 * lower & raise DTR

 * lower & raise DTR + 'ATH\r'

Turns out that ModemManager actually uses a fourth one:

  * Set baudrate temporally to 0 and restore speed in some milliseconds

I tried this attempt with the same results (see attached files)

 

And the outcome was the same

Regards,

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"




_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Dan Williams]

On Wed, 2009-10-14 at 14:16 +0200, Pablo Martí Gamboa wrote:

>
>
> 2009/10/14 Pablo Martí Gamboa <pmarti@...>
>        
>        
>         2009/10/13 Dan Williams <dcbw@...>
>                
>                 On Fri, 2009-10-09 at 10:00 +0200, Pablo Martí Gamboa
>                 wrote:
>                 >
>                 >
>                
>                 > The puzzling thing is that the very first time it
>                 will connect no
>                 > problem, it is the second and third attempts that
>                 fail. Nothing in the
>                 > wader log indicates that there's been a problem (the
>                 log trace of a
>                 > successful and unsuccessful attempts are exactly
>                 similar). So perhaps
>                 > there is a problem with that ppp timeout?
>                 >
>                 >
>                 > Is not like Simple.Connect is complicated right, it
>                 is basically the
>                 > old connect beefed up. And the old connect
>                 reliability was way better
>                 > (i.e. several connection attempts in a row no
>                 problem)
>                 >
>                 >
>                 > Is there anything else I can do to help you figure
>                 out this one?
>                
>                
>                 I'd hazard a guess that we're not disconnecting or
>                 hanging up the
>                 previous connection correctly somewhere.  Disable
>                 implies disconnect of
>                 course, so any Enable(False) handler should also be
>                 ensuring clean
>                 disconnection.
>                
>                 Can you run NM with:
>                
>                 NM_PPP_DEBUG=1 /usr/sbin/NetworkManager --no-daemon
>                
>                
>                 and lets see what comes out?  That will provide the
>                 PPP spew which could
>                 help us get closer.
>                
>        
>        
>         Attached you can find success1.log and error2.log, the first
>         attempt succeed and the second failed.
>        
>        
>         I've tried with:
>          * plain '+++ATH\r'
>          * lower & raise DTR
>          * lower & raise DTR + 'ATH\r'
>
>
> Turns out that ModemManager actually uses a fourth one:
>   * Set baudrate temporally to 0 and restore speed in some
> milliseconds

Yeah, though depending on the modem and driver that might actually not
work, and I"ve had reports of it not working on some devices, hence my
interest.  I think maybe the combination of DTR + ATH and "flash"-ing
the modem would give us the best coverage, since +++ in the PPP data
stream is just too fragile.

Have you found any combination that apparently just works everywhere?
(hopeful, I know...)

Dan

>
> I tried this attempt with the same results (see attached files)
>
>
>
>
>  
>        
>        
>         And the outcome was the same
>        
>        
>         Regards,
>        
>        
>        
>         --
>         Pablo Martí
>         http://www.linkedin.com/in/pmarti || http://www.warp.es
>         python -c "print '706d6172746940776172702e6573'.decode('hex')"
>        
>        
>
>
>
> --
> Pablo Martí
> http://www.linkedin.com/in/pmarti || http://www.warp.es
> python -c "print '706d6172746940776172702e6573'.decode('hex')"
>

_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/9 Dan Williams <dcbw@...>

On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:
>
>
> I forgot to mention that when I press "Disconnect" from nm-applet,
> that just issues an "Enable(false)" to the device rather than
> "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody
> seemed to recall why that decision had been made, they just remembered
> that it was more reliable for a particular device. In my case it is
> the other way around! will nm0.8 ship like this?

Right now NM doesn't call disconnect at all, AFAIK.  It just calls
Enable(false).  We assume that also cleans up the connection and
disables the modem, since disabling the modem implies the connection is
torn down.  Is that not working?

For projects like NM this behaviour is acceptable, between every connection attempt you don't do any operations with the 3G device. However for projects like Wader, this is an unfortunate change. Now when we issue a DeactivateConnection, we get an "Enable(false)" sent to our device, deactivating the radio and leaving the device unusable for some operations. Why don't we stick to the original vocabulary? Enable(true); Connect(settings); Disconnect(); Enable(false);

Right now the harm is already done, and we are going to have to ship with a workaround for this behaviour (unless somehow the patch makes it into the distros before 0.8, which for Ubuntu is already too late).

Please please, go back to the old behaviour.

Pablo+

This was an unfortunate change and should be reverted as soon as possible

 

BTW, how do you handle breaking into the ongoing PPP session on a 1-port
modem and hanging up the connection?   +++ATH?  Or AT &D1, setting the
serial port's DTR to off and then ATH?

Dan

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/26 Pablo Martí Gamboa <pmarti@...>

2009/10/9 Dan Williams <dcbw@...>

On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:
>
>

> I forgot to mention that when I press "Disconnect" from nm-applet,
> that just issues an "Enable(false)" to the device rather than
> "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody
> seemed to recall why that decision had been made, they just remembered
> that it was more reliable for a particular device. In my case it is
> the other way around! will nm0.8 ship like this?

Right now NM doesn't call disconnect at all, AFAIK.  It just calls
Enable(false).  We assume that also cleans up the connection and
disables the modem, since disabling the modem implies the connection is
torn down.  Is that not working?

For projects like NM this behaviour is acceptable, between every connection attempt you don't do any operations with the 3G device. However for projects like Wader, this is an unfortunate change. Now when we issue a DeactivateConnection, we get an "Enable(false)" sent to our device, deactivating the radio and leaving the device unusable for some operations. Why don't we stick to the original vocabulary? Enable(true); Connect(settings); Disconnect(); Enable(false);

Right now the harm is already done, and we are going to have to ship with a workaround for this behaviour (unless somehow the patch makes it into the distros before 0.8, which for Ubuntu is already too late).

Please please, go back to the old behaviour.

Pablo+

This was an unfortunate change and should be reverted as soon as possible

Didn't want to repeat myself here, sorry

 

 

BTW, how do you handle breaking into the ongoing PPP session on a 1-port
modem and hanging up the connection?   +++ATH?  Or AT &D1, setting the
serial port's DTR to off and then ATH?

Dan

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Pablo Martí Gamboa]

2009/10/26 Pablo Martí Gamboa <pmarti@...>

2009/10/9 Dan Williams <dcbw@...>

On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:
>
>

> I forgot to mention that when I press "Disconnect" from nm-applet,
> that just issues an "Enable(false)" to the device rather than
> "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody
> seemed to recall why that decision had been made, they just remembered
> that it was more reliable for a particular device. In my case it is
> the other way around! will nm0.8 ship like this?

Right now NM doesn't call disconnect at all, AFAIK.  It just calls
Enable(false).  We assume that also cleans up the connection and
disables the modem, since disabling the modem implies the connection is
torn down.  Is that not working?

For projects like NM this behaviour is acceptable, between every connection attempt you don't do any operations with the 3G device. However for projects like Wader, this is an unfortunate change. Now when we issue a DeactivateConnection, we get an "Enable(false)" sent to our device, deactivating the radio and leaving the device unusable for some operations. Why don't we stick to the original vocabulary? Enable(true); Connect(settings); Disconnect(); Enable(false);

Right now the harm is already done, and we are going to have to ship with a workaround for this behaviour (unless somehow the patch makes it into the distros before 0.8, which for Ubuntu is already too late).

Please please, go back to the old behaviour.

I finally gave up and disabled NM compatibility, the reason is that NM does not respect current ModemManager vocabulary and adding so many workarounds is polluting my code:

    * When a device is announce via DeviceAdded, NM sends right away two "Enable(0)" (should be boolean). workaround #1

    * When a Simple.Connect call is issued, NM sends right away two "Enable(0)" (I assume that to make sure we are not connected) thus breaking my internal state, workaround #2

    * When I press "Disconnect" from nm-applet, it won't send a "Disconnect", it sends Enable(0) twice again. workaround #3 

    * When a Simple.Connect call is issued, NM does not bother to Enable(true) the device, it assumes that the internal simple state machine will do it for us. Not working around it :S

    

Also I'm having reliability problems with PPP devices and Simple.Connect, first attempt will work (most of the time) but the second will never.

 

Bear in mind that I am not dissing anyone's work here, this is just a summary of some of the problems that an alternate ModemManager implementor faces if she strives for total compatibility. Hopefully in the future I'll be able to re-enable the compatibility...

Best regards,

Pablo

 

BTW, how do you handle breaking into the ongoing PPP session on a 1-port
modem and hanging up the connection?   +++ATH?  Or AT &D1, setting the
serial port's DTR to off and then ATH?

Dan

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list

[Herriot, Nicholas, VF UK - Technology (TS)]

Dan,

 

If we could get some betavine developers to work on this, would you accept fixes from us (Vodafone) into NM to get the issues addressed highlighted by Pablo? Or should we wait for your team to help with this area?

 

We are just a bit concerned as we have demonstrations to give in the coming weeks of our integration work with Wader.

 

Kind regards, Nicholas Herriot.

---

From: Pablo Martí Gamboa [mailto:pmarti@...]
Sent: 26 October 2009 12:36
To: Dan Williams
Cc: networkmanager-list@...; Tambet Ingo; Herriot, Nicholas, VF-Group
Subject: Re: Problem with Simple.Connect

2009/10/26 Pablo Martí Gamboa <pmarti@...>

2009/10/9 Dan Williams <dcbw@...>

On Thu, 2009-10-08 at 10:33 +0200, Pablo Martí Gamboa wrote:
>
>

> I forgot to mention that when I press "Disconnect" from nm-applet,
> that just issues an "Enable(false)" to the device rather than
> "Disconnect(); Enable(false);", I asked yesterday in #nm and nobody
> seemed to recall why that decision had been made, they just remembered
> that it was more reliable for a particular device. In my case it is
> the other way around! will nm0.8 ship like this?

Right now NM doesn't call disconnect at all, AFAIK.  It just calls
Enable(false).  We assume that also cleans up the connection and
disables the modem, since disabling the modem implies the connection is
torn down.  Is that not working?

For projects like NM this behaviour is acceptable, between every connection attempt you don't do any operations with the 3G device. However for projects like Wader, this is an unfortunate change. Now when we issue a DeactivateConnection, we get an "Enable(false)" sent to our device, deactivating the radio and leaving the device unusable for some operations. Why don't we stick to the original vocabulary? Enable(true); Connect(settings); Disconnect(); Enable(false);

Right now the harm is already done, and we are going to have to ship with a workaround for this behaviour (unless somehow the patch makes it into the distros before 0.8, which for Ubuntu is already too late).

Please please, go back to the old behaviour.

I finally gave up and disabled NM compatibility, the reason is that NM does not respect current ModemManager vocabulary and adding so many workarounds is polluting my code:

    * When a device is announce via DeviceAdded, NM sends right away two "Enable(0)" (should be boolean). workaround #1

    * When a Simple.Connect call is issued, NM sends right away two "Enable(0)" (I assume that to make sure we are not connected) thus breaking my internal state, workaround #2

    * When I press "Disconnect" from nm-applet, it won't send a "Disconnect", it sends Enable(0) twice again. workaround #3 

    * When a Simple.Connect call is issued, NM does not bother to Enable(true) the device, it assumes that the internal simple state machine will do it for us. Not working around it :S

    

Also I'm having reliability problems with PPP devices and Simple.Connect, first attempt will work (most of the time) but the second will never.

 

Bear in mind that I am not dissing anyone's work here, this is just a summary of some of the problems that an alternate ModemManager implementor faces if she strives for total compatibility. Hopefully in the future I'll be able to re-enable the compatibility...

Best regards,

Pablo

 

BTW, how do you handle breaking into the ongoing PPP session on a 1-port
modem and hanging up the connection?   +++ATH?  Or AT &D1, setting the
serial port's DTR to off and then ATH?

Dan

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"

--
Pablo Martí
http://www.linkedin.com/in/pmarti || http://www.warp.es
python -c "print '706d6172746940776172702e6573'.decode('hex')"


_______________________________________________
NetworkManager-list mailing list
NetworkManager-list@...
http://mail.gnome.org/mailman/listinfo/networkmanager-list