PPP logs missing in the interface and in /var/logs

Started by wrobelda, February 12, 2025, 08:33:47 PM

Previous topic - Next topic
February 12, 2025, 08:33:47 PM Last Edit: February 12, 2025, 08:44:59 PM by wrobelda
As of 25.1, the Docs seem outdated, the location where PPP/Wireless logs files should be found is no longer available in the UI.
I also checked the /var/logs/ppps and only have some old logs there. Nothing of particular verbosity in /var/log/system/latest, either, except:

2025-02-12T20:29:06   Warning   opnsense   /interfaces.php: interface_ppps_configure() waiting threshold exceeded - device ppp0 is still not up   
2025-02-12T20:28:46   Notice   kernel   <6>ng0: changing name to 'ppp0'   
2025-02-12T20:28:24   Warning   rtsold   <rtsock_input_ifannounce> interface ppp0 removed   
2025-02-12T20:24:48   Notice   kernel   <118> aero2BDI (ppp0) ->   
2025-02-12T20:24:41   Warning   opnsense   /usr/local/etc/rc.bootup: interface_ppps_configure() waiting threshold exceeded - device ppp0 is still not up

I just discussed the outdated docs thing upstream here: https://github.com/opnsense/docs/issues/668#issuecomment-2654576884 and was told the logs are actually in general log. So am I missing something? Is there a way to make the PPP connectivity more verbose?

EDIT: OK, I see the manual suggests troubleshooting using standard FreeBSD procedures (https://docs.opnsense.org/manual/how-tos/cellular.html).

EDIT2. FreeBSD docs mention (https://docs.freebsd.org/en/books/handbook/ppp-and-slip/#_debugging) the syslog can be configured to output ppp logs to their own file. OPNSense's /etc/syslog.d/ppp.conf is configured to do that exactly, but /var/log/ppp.log doesn't exist. That's odd, isn't it?

Most of the things have been fixed in the docs repo already.  I'll change the mention in the cellular how-to now.

As far as release notes go:

o interfaces: move PPP and wireless logs to system log


Cheers,
Franco

February 12, 2025, 09:10:50 PM #2 Last Edit: February 12, 2025, 09:16:01 PM by wrobelda
I appreciate quick response here, but the docs inconsistencies aside, I am still struggling figuring out my connection and finding any relevant logs.

What I found as well is that OPNSense uses MPD to handle the PPP connections, but I still can't find any meaningful logs anywhere.

(Also, the docs directing users to PPP section of FreeBSD for additional debugging is probably also outdated, isn't it? I suppose it should be directing to MPD docs maybe, e.g. https://mpd.sourceforge.net/doc5/mpd63.html#63 ?)

So, digging further, I run the mpd command in the foreground:
root@gw:/var/etc # /usr/local/sbin/mpd5 -d /var/etc -f mpd_opt2.conf -p /var/run/ppp_opt2.pid -s ppp pppclient
And see the following:

EVENT: Registering event EVENT_TIMEOUT ChatTimeout() at chat.c:971
EVENT: Registering event EVENT_TIMEOUT ChatTimeout() done at chat.c:971
EVENT: Registering event EVENT_READ ChatRead() at chat.c:584
EVENT: Registering event EVENT_READ ChatRead() done at chat.c:584
EVENT: Processing event EVENT_READ ChatRead() done
EVENT: Processing event EVENT_READ ChatRead()
EVENT: Registering event EVENT_READ ChatRead() at chat.c:480
EVENT: Registering event EVENT_READ ChatRead() done at chat.c:480
EVENT: Processing event EVENT_READ ChatRead() done
EVENT: Processing event EVENT_READ ChatRead()
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  41 54 49 0d 0d                                   ATI..
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 4d 61 6e 75 66 61 63 74 75 72 65 72 3a 20 68  .Manufacturer: h
[opt2_link0] CHAT:  75 61 77 65 69 0d                                uawei.
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 4d 6f 64 65 6c 3a 20 45 33 31 33 31 0d        .Model: E3131.
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 52 65 76 69 73 69 6f 6e 3a 20 32 31 2e 31 35  .Revision: 21.15
[opt2_link0] CHAT:  38 2e 30 30 2e 30 30 2e 31 30 32 30 0d           8.00.00.1020.
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 49 4d 45 49 3a 20 38 36 33 36 32 35 30 32 34  .IMEI: 863625024
[opt2_link0] CHAT:  31 33 37 31 36 38 0d                             137168.
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 2b 47 43 41 50 3a 20 2b 43 47 53 4d 2c 2b 44  .+GCAP: +CGSM,+D
[opt2_link0] CHAT:  53 2c 2b 45 53 0d                                S,+ES.
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 0d                                            ..
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a 4f 4b 0d                                      .OK.
[opt2_link0] CHAT: read
[opt2_link0] CHAT:  0a                                               .
[opt2_link0] CHAT: matched set "", goto label "MomIdentGeneriicc"
EVENT: Unregistering event EVENT_TIMEOUT ChatTimeout() at chat.c:1401
EVENT: Unregistering event EVENT_TIMEOUT ChatTimeout() done at chat.c:1401
Label 'MomIdentGeneriicc' not found
[opt2_link0] CHAT: line 391: label "MomIdentGeneriicc" not found
EVENT: Unregistering event EVENT_READ ChatRead() at chat.c:874
EVENT: Unregistering event EVENT_READ ChatRead() done at chat.c:874
EVENT: Unregistering event (null) at chat.c:875
EVENT: Unregistering event (null) done at chat.c:875
[opt2_link0] MODEM: chat script failed

There's an upstream issue for this: https://github.com/opnsense/src/issues/214

That having said, not being able to find these errors anywhere in the logs is problematic, to be honest.


February 13, 2025, 03:11:06 PM #4 Last Edit: February 13, 2025, 03:14:59 PM by franco
From what I can gather mpd5 logs all as LOG_INFO which is a bit inconvenient since we only show LOG_NOTICE in the general log. This will require a build fix or I'm misreading this source code (which is difficult only being available as a tarball of a SVN dump from Sourceforge).


Cheers,
Franco

February 13, 2025, 04:40:46 PM #5 Last Edit: February 13, 2025, 05:19:37 PM by antunesls
I'm suffering the same issue of lack of logs.

I create a secondary pppoe and it looks like that system not even try dial up, the only logs whats I can get is :

<6>ng0: changing name to 'pppoe1'

/usr/local/etc/rc.configure_interface: interface_ppps_configure() waiting threshold exceeded - device pppoe1 is still not up


But the interface is on and connect to the modem (zyxel pmg2005-t20b) and if I try connect via laptop, it works perfectly.









For the record, I managed to get my modem working in NCM CDC mode by issuing USB control message to initialize it. I explained the process here: https://forum.opnsense.org/index.php?topic=46335.0

Thanks for the follow-up! Just as another data point: the MPD logging was fixed in 25.1.3 yesterday.


Cheers,
Franco