Re: NetworkManager not starting ppp connection. SOLVED!

["A. F. Cano" <afc shibaya lonestar org>]

On Mon, Sep 05, 2016 at 12:25:20AM +0200, Thomas Haller wrote:
> On Sun, 2016-09-04 at 16:12 -0400, A. F. Cano wrote:
> > On Sat, Sep 03, 2016 at 11:14:28PM +0200, Thomas Haller wrote:
>
> > $ sudo nmcli con add con-name "ppp" ifname "ppp0" type cdma
>
> you don't need sudo, unless you system is configured in an unsual way.

Yes, for security reasons root logins are not allowed and so the only
way to run certain commands is with sudo from the administrative
account.

> Anyway, this restricts the connection to 'ifname "ppp0"', but later you

That was the main mistake it seems.  I used that in the nmcli command that
created the connection.

> see 
>
>
> > $ nmcli dev
> > DEVICE   TYPE      STATE         CONNECTION            
> > enp1s0   ethernet  connected     FreedomBox WAN        
> > enp3s0   ethernet  connected     FreedomBox LAN enp3s0 
> > ttyACM0  cdma      disconnected  --                    
> > enp2s0   ethernet  unavailable   --                    
> > lo       loopback  unmanaged     --                
>
> that you device is called ttyACM0
>
> nmcli connection modify ppp connection.interface-name ""

That was the trick.  Now ppp connects via NM.  Thank you very much!

Details below:

As before, the kernel detection of the usb device:

Sep  4 22:58:35 fbx kernel: [ 2698.111804] usb 4-1: new full-speed USB
device number 3 using ohci-pci
Sep  4 22:58:35 fbx kernel: [ 2698.278969] usb 4-1: New USB device
found, idVendor=22b8, idProduct=2a62
Sep  4 22:58:35 fbx kernel: [ 2698.278986] usb 4-1: New USB device
strings: Mfr=1, Product=2, SerialNumber=0
Sep  4 22:58:35 fbx kernel: [ 2698.278994] usb 4-1: Product: Motorola
E815
Sep  4 22:58:35 fbx kernel: [ 2698.279002] usb 4-1: Manufacturer:
Motorola, Inc.
Sep  4 22:58:35 fbx kernel: [ 2698.283664] cdc_acm 4-1:1.0: ttyACM0: USB
ACM device

Now, NM detects the device:

Sep  4 22:58:51 fbx NetworkManager[1223]: <info>  [1473044331.5151]
manager: (ttyACM0): new Broadband device
(/org/freedesktop/NetworkManager/Devices/6)
Sep  4 22:58:51 fbx NetworkManager[1223]: <info>  [1473044331.5172]
device (ttyACM0): state change: unmanaged -> unavailable (reason
'managed') [10 20 2]
Sep  4 22:58:51 fbx NetworkManager[1223]: <info>  [1473044331.5188]
device (ttyACM0): modem state 'enabling'
Sep  4 22:58:51 fbx NetworkManager[1223]: <warn>  [1473044331.5194]
(ttyACM0): failed to retrieve SIM object: No SIM object available
Sep  4 22:58:51 fbx NetworkManager[1223]: <info>  [1473044331.5207]
device (ttyACM0): state change: unavailable -> disconnected (reason
'none') [20 30 0]

And now, the connection gets activated:

Sep  4 23:00:42 fbx NetworkManager[1223]: <info>  [1473044442.8932]
device (ttyACM0): Activation: starting connection 'ppp'
(f2cc6f30-1726-42c2-b580-3ac8a98a21ec)
Sep  4 23:00:42 fbx NetworkManager[1223]: <info>  [1473044442.8954]
audit: op="connection-activate"
uuid="f2cc6f30-1726-42c2-b580-3ac8a98a21ec" name="ppp" pid=3587 uid=0
result="success"
Sep  4 23:00:42 fbx NetworkManager[1223]: <info>  [1473044442.8971]
device (ttyACM0): state change: disconnected -> prepare (reason 'none')
[30 40 0]
Sep  4 23:00:42 fbx NetworkManager[1223]: <info>  [1473044442.8994]
manager: NetworkManager state is now CONNECTING
Sep  4 23:00:42 fbx NetworkManager[1223]: <info>  [1473044442.9045]
device (ttyACM0): state change: prepare -> need-auth (reason 'none') [40
60 0]
Sep  4 23:00:42 fbx NetworkManager[1223]: <info>  [1473044442.9463]
device (ttyACM0): state change: need-auth -> prepare (reason 'none') [60
40 0]
Sep  4 23:00:51 fbx NetworkManager[1223]: <warn>  [1473044451.5218]
device (ttyACM0): failed to look up interface index
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.5224]
device (ttyACM0): state change: prepare -> config (reason 'none') [40 50
0]
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.5785]
device (ttyACM0): state change: config -> ip-config (reason 'none') [50
70 0]
Sep  4 23:00:51 fbx NetworkManager[1223]: <warn>  [1473044451.5792]
device (ttyACM0): interface ttyACM0 not up for IP configuration
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.5792]
(ttyACM0): using modem-specified IP timeout: 20 seconds

And now ppp gets started:

Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.5803]
ppp-manager: starting PPP connection
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.5867]
ppp-manager: pppd started with pid 3595
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.5870]
(ttyACM0): IPv6 configuration disabled
Sep  4 23:00:51 fbx pppd[3595]: Plugin
/usr/lib/pppd/2.4.7/nm-pppd-plugin.so loaded.
Sep  4 23:00:51 fbx pppd[3595]: pppd 2.4.7 started by root, uid 0
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.6327]
manager: (ppp0): new Generic device
(/org/freedesktop/NetworkManager/Devices/7)

Success!

Sep  4 23:00:51 fbx pppd[3595]: Using interface ppp0
Sep  4 23:00:51 fbx pppd[3595]: Connect: ppp0 <--> /dev/ttyACM0
Sep  4 23:00:51 fbx pppd[3595]: local  IP address 75.213.252.136
Sep  4 23:00:51 fbx pppd[3595]: remote IP address 66.174.121.64
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.6688]
ppp-manager: (IPv4 Config Get) reply received.
Sep  4 23:00:51 fbx pppd[3595]: primary   DNS address 198.224.186.135
Sep  4 23:00:51 fbx pppd[3595]: secondary DNS address 198.224.187.135
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.6931]
device (ttyACM0): state change: ip-config -> ip-check (reason 'none')
[70 80 0]
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7422]
devices added (path: /sys/devices/virtual/net/ppp0, iface: ppp0)
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7423]
device added (path: /sys/devices/virtual/net/ppp0, iface: ppp0): no
ifupdown configuration found.

Now: IP...

Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7708]
device (ttyACM0): state change: ip-check -> secondaries (reason 'none')
[80 90 0]
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7721]
device (ttyACM0): state change: secondaries -> activated (reason 'none')
[90 100 0]
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7725]
manager: NetworkManager state is now CONNECTED_LOCAL
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7856]
manager: NetworkManager state is now CONNECTED_GLOBAL

And DNS...

Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7876]
policy: set 'ppp' (ppp0) as default for IPv4 routing and DNS
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.7880]
dns-mgr: Writing DNS information to /sbin/resolvconf
Sep  4 23:00:51 fbx NetworkManager[1223]: <info>  [1473044451.8711]
device (ttyACM0): Activation: successful, device activated.

The following, not necessary any more, I removed from
/etc/NetworkManager/dispatcher.d.   Interesting that it's being
called with blank IFACE and ACTION paramaters...

Sep  4 23:00:52 fbx root: 10-ppp.sh executed, IFACE =  ACTION =