buggNewSense GNU/Linux - Bugs: bug #35352, pppd/NetworkManager behave...

 
 

bug #35352: pppd/NetworkManager behave strangely

Submitter:  Evgeniy Philippov <molchuvka>
Submitted:  Sun 22 Jan 2012 05:32:10 PM UTC
   
 
Category:  None Severity:  3 - Normal
Item Group:  None Status:  Need Info
Privacy:  Public Assigned to:  None
Open/Closed:  Open
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Mon 13 Jan 2014 07:38:08 PM UTC, comment #11: 

Is this still a problem in gNewSense 3.0?

Sam Geeraerts <samgee>
Group administrator
Fri 27 Jan 2012 12:45:19 PM UTC, comment #10: 


> I will see if this practice will have stable behavior everytime.


1. I've tested a few days, that practive works OK everytime.

2. Sometimes (rarely) NM connects OK during the OS startup. Usually I need poff -a / pon to connect.

Evgeniy Philippov <molchuvka>
Thu 26 Jan 2012 12:01:04 PM UTC, comment #9: 

More. Just for information how it behaves.

(Before these logs, I was logging out ouf GNOME into the gdm entry screen with login/password input screen.)

From the login and GNOME startup, NM tries to connect to wireless networks:

Jan 26 19:40:07 greenmeadow NetworkManager: <info>  Updating allowed wireless network lists.
Jan 26 19:40:07 greenmeadow NetworkManager: <WARN>  nm_dbus_get_networks_cb(): error received: org.freedesktop.NetworkManagerInfo.NoNetworks - There are no wireless networks stored..
Jan 26 19:43:22 greenmeadow NetworkManager: <info>  Updating allowed wireless network lists.
Jan 26 19:43:22 greenmeadow NetworkManager: <WARN>  nm_dbus_get_networks_cb(): error received: org.freedesktop.NetworkManagerInfo.NoNetworks - There are no wireless networks stored..
Jan 26 19:47:05 greenmeadow pppd[5760]: No response to 4 echo-requests
Jan 26 19:47:05 greenmeadow pppd[5760]: Serial link appears to be disconnected.
Jan 26 19:47:05 greenmeadow pppd[5760]: Connect time 351.6 minutes.
Jan 26 19:47:05 greenmeadow pppd[5760]: Sent 5565030 bytes, received 34541072 bytes.
Jan 26 19:47:05 greenmeadow pppd[5760]: Script /etc/ppp/ip-down started (pid 30100)
Jan 26 19:47:05 greenmeadow pppd[5760]: sent [LCP TermReq id=0x2 "Peer not responding"]
Jan 26 19:47:05 greenmeadow pppd[5760]: Script /etc/ppp/ip-down finished (pid 30100), status = 0x0
Jan 26 19:47:08 greenmeadow pppd[5760]: sent [LCP TermReq id=0x3 "Peer not responding"]
Jan 26 19:47:11 greenmeadow pppd[5760]: Connection terminated.
Jan 26 19:47:11 greenmeadow pppd[5760]: Modem hangup

Then, I issued poff -a:

Jan 26 19:47:24 greenmeadow pppd[5760]: Terminating on signal 15
Jan 26 19:47:24 greenmeadow pppd[5760]: Exit.

Then, pon dsl-provider:

Jan 26 19:47:39 greenmeadow pppd[30132]: Plugin rp-pppoe.so loaded.
Jan 26 19:47:39 greenmeadow pppd[30134]: pppd 2.4.4 started by root, uid 0
Jan 26 19:48:14 greenmeadow pppd[30134]: Timeout waiting for PADO packets
Jan 26 19:48:14 greenmeadow pppd[30134]: Unable to complete PPPoE Discovery

Then, I was impatient (I timed out) and I issued poff -a:

Jan 26 19:49:06 greenmeadow pppd[30134]: PADS: Service-Name: ''
Jan 26 19:49:06 greenmeadow pppd[30134]: PPP session is 5293
Jan 26 19:49:06 greenmeadow pppd[30134]: using channel 3
Jan 26 19:49:06 greenmeadow pppd[30134]: Using interface ppp0
Jan 26 19:49:06 greenmeadow pppd[30134]: Connect: ppp0 <--> eth0
Jan 26 19:49:06 greenmeadow pppd[30134]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xa7393aa6>]

Jan 26 19:49:06 greenmeadow pppd[30134]: Terminating on signal 15
Jan 26 19:49:06 greenmeadow pppd[30134]: sent [LCP TermReq id=0x2 "User request"]
Jan 26 19:49:09 greenmeadow pppd[30134]: sent [LCP TermReq id=0x3 "User request"]
Jan 26 19:49:12 greenmeadow pppd[30134]: Connection terminated.
Jan 26 19:49:12 greenmeadow pppd[30134]: Modem hangup
Jan 26 19:49:12 greenmeadow pppd[30134]: Exit.

pon:

Jan 26 19:49:19 greenmeadow pppd[30167]: Plugin rp-pppoe.so loaded.
Jan 26 19:49:19 greenmeadow pppd[30169]: pppd 2.4.4 started by root, uid 0
Jan 26 19:50:07 greenmeadow pppd[30169]: Timeout waiting for PADS packets
Jan 26 19:50:07 greenmeadow pppd[30169]: Unable to complete PPPoE Discovery

Was impatient (I timed out), issued poff -a:

Jan 26 19:50:15 greenmeadow pppd[30169]: Terminating on signal 15
Jan 26 19:50:15 greenmeadow pppd[30169]: Exit.

Then, I issued pon dsl-provider and it connected quickly.

Evgeniy Philippov <molchuvka>
Thu 26 Jan 2012 05:19:45 AM UTC, comment #8: 

P.S. I always have `lock' option in `/etc/ppp/options'.

Evgeniy Philippov <molchuvka>
Thu 26 Jan 2012 05:17:12 AM UTC, comment #7: 

It seems that solution is to call "sudo poff -a", then to make sure "less +F /var/log/syslog" displays that pppd finishes all of its activities and ends, then to call "sudo pon dsl-provider".

This probably solves this strangeness issue.

I will see if this practice will have stable behavior everytime.

Without poff, I had several "permission denied" messages today.

Evgeniy Philippov <molchuvka>
Tue 24 Jan 2012 12:27:06 AM UTC, comment #6: 

Thanks for including the extra information. I don't use NM in this way, so hopefully someone else will be able to think of a solution down the line.

Karl Goetz <kgoetz>
Mon 23 Jan 2012 05:06:02 PM UTC, comment #5: 

One more observation.

  • At deltah startup, no pppoe auto-connect occurs (despite that I have set it to occur, at pppoeconfig utility dialogs).
  • Sometimes, when I do "pon dsl-provider", it responds with "permission denied". When I do "pon dsl-provider" immediately after that, it says "auth success".
  • However LUbuntu's NM's pppoe connects happily everytime the system starts up. LUbuntu v.11.10.
Evgeniy Philippov <molchuvka>
Mon 23 Jan 2012 01:27:58 PM UTC, comment #4: 

After deltah bootup, all connects OK. After a hour of work, echoreq responses stop being received, and all disconnects.

This does not occur at neither lubuntu nor windows.

syslog of deltah:

Jan 23 21:05:18 greenmeadow pppd[4387]: No response to 4 echo-requests
Jan 23 21:05:18 greenmeadow pppd[4387]: Serial link appears to be disconnected.
Jan 23 21:05:18 greenmeadow pppd[4387]: Connect time 83.0 minutes.
Jan 23 21:05:18 greenmeadow pppd[4387]: Sent 665336 bytes, received 18017112 bytes.
Jan 23 21:05:18 greenmeadow pppd[4387]: Script /etc/ppp/ip-down started (pid 6223)
Jan 23 21:05:18 greenmeadow pppd[4387]: sent [LCP TermReq id=0x3 "Peer not responding"]
Jan 23 21:05:19 greenmeadow pppd[4387]: Script /etc/ppp/ip-down finished (pid 6223), status = 0x0
Jan 23 21:05:21 greenmeadow pppd[4387]: sent [LCP TermReq id=0x4 "Peer not responding"]
Jan 23 21:05:24 greenmeadow pppd[4387]: Connection terminated.
Jan 23 21:05:24 greenmeadow pppd[4387]: Modem hangup

Evgeniy Philippov <molchuvka>
Mon 23 Jan 2012 01:19:09 PM UTC, comment #3: 

Now it says "permission denied" at syslog after "sudo pon dsl-provider". Though the user and password are correct.

However the NetworkMgr at Lubuntu 11.10 connects OK.

syslog of gnewsense deltah:

Jan 23 21:06:36 greenmeadow pppd[6275]: Plugin rp-pppoe.so loaded.
Jan 23 21:06:36 greenmeadow pppd[6277]: pppd 2.4.4 started by root, uid 0
Jan 23 21:06:41 greenmeadow pppd[6277]: PADS: Service-Name: ''
Jan 23 21:06:41 greenmeadow pppd[6277]: PPP session is 10911
Jan 23 21:06:41 greenmeadow pppd[6277]: using channel 5
Jan 23 21:06:41 greenmeadow pppd[6277]: Using interface ppp0
Jan 23 21:06:41 greenmeadow pppd[6277]: Connect: ppp0 <--> eth0
Jan 23 21:06:41 greenmeadow pppd[6277]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x9a9512ba>]
Jan 23 21:06:47 greenmeadow last message repeated 2 times
Jan 23 21:06:49 greenmeadow pppd[6277]: rcvd [LCP ConfReq id=0x70 <mru 1492> <auth chap MD5> <magic 0x469bfcd3>]
Jan 23 21:06:49 greenmeadow pppd[6277]: sent [LCP ConfAck id=0x70 <mru 1492> <auth chap MD5> <magic 0x469bfcd3>]
Jan 23 21:06:49 greenmeadow pppd[6277]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x9a9512ba>]
Jan 23 21:06:49 greenmeadow pppd[6277]: sent [LCP EchoReq id=0x0 magic=0x9a9512ba]
Jan 23 21:06:49 greenmeadow pppd[6277]: rcvd [CHAP Challenge id=0xb7 <7c77a82a8cbcba7dfe72a156972ba3bb4be75ec4a894d24cb88585>, name = "yyyyyyyy"]
Jan 23 21:06:49 greenmeadow pppd[6277]: sent [CHAP Response id=0xb7 <890a65b82aad9b509fd0a5eb4ddde987>, name = "xxxxxxxx"]
Jan 23 21:06:49 greenmeadow pppd[6277]: rcvd [LCP EchoRep id=0x0 magic=0x469bfcd3]
Jan 23 21:06:50 greenmeadow pppd[6277]: rcvd [CHAP Failure id=0xb7 "permission denied"]
Jan 23 21:06:50 greenmeadow pppd[6277]: CHAP authentication failed: permission denied
Jan 23 21:06:50 greenmeadow pppd[6277]: CHAP authentication failed
Jan 23 21:06:50 greenmeadow pppd[6277]: sent [LCP TermReq id=0x2 "Failed to authenticate ourselves to peer"]
Jan 23 21:06:50 greenmeadow pppd[6277]: rcvd [LCP TermReq id=0x71]
Jan 23 21:06:50 greenmeadow pppd[6277]: sent [LCP TermAck id=0x71]
Jan 23 21:06:50 greenmeadow pppd[6277]: rcvd [LCP TermAck id=0x2]
Jan 23 21:06:50 greenmeadow pppd[6277]: Connection terminated.

Evgeniy Philippov <molchuvka>
Mon 23 Jan 2012 09:33:34 AM UTC, comment #2: 
  • I left-click on Network Manager (NM) tray icon;
  • The dropdown menu contains only one item: "Manual configuration";
  • I left-click "Manual configuration";
  • I choose Unlock at the settings dialog (see the screenshot attached), choose a location which I previously saved (added), and tick pppoe checkbox (red circle on a screenshot).


P.S. Currently I have run pppoeconfig and setup all, and use a manual command-line "pon dsl-provider" to connect. It connects safely, without a 15 signal.

(file #24875)

Evgeniy Philippov <molchuvka>
Mon 23 Jan 2012 09:00:26 AM UTC, comment #1: 

Where are you ticking that?

Karl Goetz <kgoetz>
Sun 22 Jan 2012 05:32:10 PM UTC, original submission:  

1) I check [v] pppoe in NM config applet
2) It auto-unchecks it


An excerpt from syslog (notice the "pppd"..."Terminating on signal 15"):

{{{
Jan 23 02:13:28 greenmeadow NetworkManager: <info>  /etc/network/interface changed: rebuilding the device list.
Jan 23 02:13:28 greenmeadow NetworkManager: <info>  Recreating the device list.
Jan 23 02:13:28 greenmeadow NetworkManager: <info>  Device list recreated successfully.
Jan 23 02:13:30 greenmeadow NetworkManager: <info>  Going to sleep.
Jan 23 02:13:30 greenmeadow NetworkManager: <info>  Waking up from sleep.
Jan 23 02:14:31 greenmeadow NetworkManager: <info>  /etc/network/interface changed: rebuilding the device list.
Jan 23 02:14:31 greenmeadow NetworkManager: <info>  Recreating the device list.
Jan 23 02:14:31 greenmeadow NetworkManager: <info>  Device list recreated successfully.
Jan 23 02:14:31 greenmeadow NetworkManager: <info>  /etc/network/interface changed: rebuilding the device list.
Jan 23 02:14:31 greenmeadow NetworkManager: <info>  Recreating the device list.
Jan 23 02:14:31 greenmeadow NetworkManager: <info>  Device list recreated successfully.
Jan 23 02:14:31 greenmeadow pppd[6237]: Plugin rp-pppoe.so loaded.
Jan 23 02:14:31 greenmeadow pppd[6239]: pppd 2.4.4 started by root, uid 0
Jan 23 02:14:31 greenmeadow pppd[6239]: PPP session is 1405
Jan 23 02:14:31 greenmeadow pppd[6239]: Using interface ppp0
Jan 23 02:14:31 greenmeadow pppd[6239]: Connect: ppp0 <--> eth0
Jan 23 02:14:31 greenmeadow pppd[6239]: CHAP authentication succeeded
Jan 23 02:14:31 greenmeadow pppd[6239]: CHAP authentication succeeded
Jan 23 02:14:31 greenmeadow pppd[6239]: peer from calling number xx:xx:xx:xx:xx:xx authorized
Jan 23 02:14:32 greenmeadow pppd[6239]: Cannot determine ethernet address for proxy ARP
Jan 23 02:14:32 greenmeadow pppd[6239]: local  IP address xx.xx.xx.xx
Jan 23 02:14:32 greenmeadow pppd[6239]: remote IP address xx.xx.xx.xx
Jan 23 02:14:32 greenmeadow pppd[6239]: primary   DNS address xx.xx.xx.xx
Jan 23 02:14:32 greenmeadow pppd[6239]: secondary DNS address xx.xx.xx.xx
Jan 23 02:14:33 greenmeadow dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 4
Jan 23 02:14:33 greenmeadow NetworkManager: <info>  Going to sleep.
Jan 23 02:14:33 greenmeadow pppd[6239]: Terminating on signal 15
Jan 23 02:14:33 greenmeadow pppd[6239]: Connect time 0.1 minutes.
Jan 23 02:14:33 greenmeadow pppd[6239]: Sent 0 bytes, received 0 bytes.
Jan 23 02:14:33 greenmeadow pppd[6239]: Connection terminated.
Jan 23 02:14:33 greenmeadow NetworkManager: <info>  Waking up from sleep.
Jan 23 02:14:33 greenmeadow pppd[6239]: Exit.
}}}

Evgeniy Philippov <molchuvka>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #24875:  settings.gif added by molchuvka (24KiB - image/gif)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by samgee (Posted a comment)
  • -email is unavailable- added by molchuvka (Submitted the item)
  •  

    Follow 2 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2014-01-13 samgee StatusNone Need Info
    2012-01-23 molchuvka Attached File- Added settings.gif, #24875

    Back to the top

    Powered by Savane 3.13-269c.
    Corresponding source code