Bug #16409
closedif_pppoe not writing to /var/log/ppp.log
0%
Description
When using if_pppoe kernel module activated through GUI option System/Advanced/Networking/Use if_pppoe kernel module for PPPoE client, no logs are writting to /var/log/ppp.log other than an occasional "failed to set default route 17 message". On disabling if_pppoe and reverting to using mpd5, logs are written again. It's been an issue in both 2.8.0 and 2.8.1
ppp.log when using if_pppoe:
Aug 13 10:32:15     kernel         if_pppoe: pppoe1: failed to set default route 17
Aug 9 05:54:27     kernel         if_pppoe: pppoe1: failed to set default route 17
Jul 19 06:32:34     kernel         if_pppoe: pppoe1: failed to set default route 17
Jul 8 06:37:15     kernel         if_pppoe: pppoe1: failed to set default route 17
Jul 7 05:35:15     kernel         if_pppoe: pppoe1: failed to set default route 17
ppp.log when using mpd5:
Sep 5 10:42:27     ppp     34772     [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Sep 5 10:42:27     ppp     34772     [wan_link0] Link: Join bundle "wan" 
Sep 5 10:42:27     ppp     34772     [wan_link0] Link: Matched action 'bundle "wan" ""'
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: authorization successful
Sep 5 10:42:27     ppp     34772     [wan_link0] MESG: CHAP authentication success
Sep 5 10:42:27     ppp     34772     [wan_link0] CHAP: rec'd SUCCESS #1 len: 31
Sep 5 10:42:27     ppp     34772     [wan_link0] CHAP: sending RESPONSE #1 len: 46
Sep 5 10:42:27     ppp     34772     [wan_link0] CHAP: Using authname "########" 
Sep 5 10:42:27     ppp     34772     [wan_link0] Name: "########" 
Sep 5 10:42:27     ppp     34772     [wan_link0] CHAP: rec'd CHALLENGE #1 len: 54
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: LayerUp
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: auth: peer wants CHAP, I want nothing
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: state change Ack-Sent --> Opened
Sep 5 10:42:27     ppp     34772     [wan_link0] MAGICNUM ########
Sep 5 10:42:27     ppp     34772     [wan_link0] MRU 1500
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
Sep 5 10:42:27     ppp     34772     [wan_link0] MAGICNUM ########
Sep 5 10:42:27     ppp     34772     [wan_link0] MRU 1500
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: SendConfigReq #2
Sep 5 10:42:27     ppp     34772     [wan_link0] PROTOCOMP
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: rec'd Configure Reject #1 (Ack-Sent)
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: state change Req-Sent --> Ack-Sent
Sep 5 10:42:27     ppp     34772     [wan_link0] MAGICNUM ########
Sep 5 10:42:27     ppp     34772     [wan_link0] AUTHPROTO CHAP MD5
Sep 5 10:42:27     ppp     34772     [wan_link0] MRU 1500
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: SendConfigAck #27
Sep 5 10:42:27     ppp     34772     [wan_link0] MAGICNUM ########
Sep 5 10:42:27     ppp     34772     [wan_link0] AUTHPROTO CHAP MD5
Sep 5 10:42:27     ppp     34772     [wan_link0] MRU 1500
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: rec'd Configure Request #27 (Req-Sent)
Sep 5 10:42:27     ppp     34772     [wan_link0] MAGICNUM ########
Sep 5 10:42:27     ppp     34772     [wan_link0] MRU 1500
Sep 5 10:42:27     ppp     34772     [wan_link0] PROTOCOMP
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: SendConfigReq #1
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: state change Starting --> Req-Sent
Sep 5 10:42:27     ppp     34772     [wan_link0] LCP: Up event
Sep 5 10:42:27     ppp     34772     [wan_link0] Link: UP event
Sep 5 10:42:27     ppp     34772     [wan_link0] PPPoE: connection successful
Sep 5 10:42:27     ppp     34772     [wan_link0] PPPoE: rec'd PPP-Max-Payload '1500'
Sep 5 10:42:27     ppp     34772     PPPoE: rec'd ACNAME "#######" 
Sep 5 10:42:27     ppp     34772     [wan_link0] PPPoE: Connecting to ''
Sep 5 10:42:27     ppp     34772     [wan_link0] PPPoE: Set PPP-Max-Payload to '1500'
Sep 5 10:42:26     ppp     34772     [wan_link0] LCP: LayerStart
Sep 5 10:42:26     ppp     34772     [wan_link0] LCP: state change Initial --> Starting
Sep 5 10:42:26     ppp     34772     [wan_link0] LCP: Open event
Sep 5 10:42:26     ppp     34772     [wan_link0] Link: OPEN event
Sep 5 10:42:26     ppp     34772     [undefined] GetSystemIfaceMTU: SIOCGIFMTU failed: Device not configured
Sep 5 10:42:26     ppp     34772     [wan] Bundle: Interface ng0 created
Sep 5 10:42:26     ppp     34772     web: web is not running
Sep 5 10:42:26     ppp     34772     process 34772 started, version 5.9
Sep 5 10:42:26     ppp     34772     Multi-link PPP daemon for FreeBSD
WAN link operates correctly under both options, routing internet traffic as expected.
      
      Updated by Marcos M about 2 months ago
      
    
    - Status changed from New to Not a Bug
 
That log is only for mpd5. You can see some logs for the kernel module in the system logs but there's not much by default. Using ifconfig pppoe0 debug will enable very verbose logging. Additionally running pppcfg pppoe0 will show some status info.