Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    V123 - working fine for long time, now disconnects and high CPU

    Scheduled Pinned Locked Moved General pfSense Questions
    8 Posts 3 Posters 2.4k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • S
      sully
      last edited by

      Hello. Have some things going on in last couple days, need some guidance please.

      First, system is older Dell 1.5ghz pentium 4 with 512mb pc133 ram. Hdd is 20gb IBM ata66. 2 Intel 82550 Pro cards.

      Config is very simple. DSL modem to pfsense, PPPOE. Lan NIC is connected to switches, serving my house with 6 computers and a few laptops intermittently. Nothing special really, except I do have a synology NAS that I allowed remote connections to.

      Have had system up for maybe 6 months or more, no problems. I periodically look at logs and note CPU useage would be high at 30%, normally around 5% (RRD graphs). Do some gaming, a little streaming and occassional file download, but normally inactive while I am at work. The family browses/facebooks a bit, but not much throughput.

      Connection is 10m x 768. Have had connection for many years. Modem is newish.

      I did install squid and squidguard. I configured shallas blacklist and am using captive portal. The use is minimal, as I am only filtering traffic for 3 computers (kids). Simply allowing some access while blocking all access to sites they are not old enough to view. Bypassed for all other MAC addresses.

      I also use DHCP, but statically map IP to MAC.

      Like I mentioned, I have had no problems, everything been working great. Couple days ago, no internet, but could ping pfsense box. Restarted modem, then it worked. Worked fine all that night. Yesterday, intermittent disconnect of WAN IP. I thought it was modem, but seems to be related to pfsense box.

      When looking at RRD graphs, there is an unusual high CPU spike at the same time the WAN drops. The pfsense box will, after a couple minutes, reload things and get to working again. Then it works fine until the CPU spike hits again. This is new behaviour.

      I am a pretty advanced user for windows OS, but have minimal experience with unix flavors, so am unsure really how to proceed. I found a couple commands I can run from the console when I get home (I think it is top or something) that will show me a little data. I know I have the fxp NICs, and I already tried the "offload" setting both ways, with no difference. I have read it might be squid or squidguard as well, but haven't traveled that option yet.

      Here is what the system log shows, and it sort of repeats this sequence of events at every WAN disconnect. I would like to see more of the log, but don't know where to do that at or how to do that.

      I am seeking help in tracking this issue down. I have another box (slower) that I first tried pfsense on, I was thinking of trying that, to determine if the error is in the current box. I could also hook back up to my router (dlink) and see if the problem goes away as well.

      Thanks for any help.

      Nov 18 08:42:35	check_reload_status: reloading filter
Nov 18 08:42:32	php[489]: /pkg_edit.php: Reloading Squid for configuration sync
Nov 18 07:23:40	php: : phpDynDNS: (Success) IP Address Changed Successfully! (72.160.11.189)
Nov 18 07:23:40	php: : phpDynDNS: updating cache file /cf/conf/dyndns.cache: 72.160.11.189
Nov 18 07:23:40	php: : DynDns: Current Service: dyndns
Nov 18 07:23:40	php: : DynDns: DynDns _checkStatus() starting.
Nov 18 07:23:39	php: : DynDns: DynDns _update() starting. Dynamic
Nov 18 07:23:39	php: : DynDns: DynDns _update() starting.
Nov 18 07:23:39	php: : DynDns: cacheIP != wan_ip. Updating.
Nov 18 07:23:39	php: : DynDns: Cached IP: 72.160.15.227
Nov 18 07:23:39	php: : DynDns: Current WAN IP: 72.160.11.189
Nov 18 07:23:39	php: : DynDns: _detectChange() starting.
Nov 18 07:23:39	php: : DynDns: updatedns() starting
Nov 18 07:23:39	php: : DynDns: Running updatedns()
Nov 18 07:23:36	check_reload_status: updating dyndns
Nov 18 07:23:35	check_reload_status: reloading filter
Nov 18 07:23:34	php: : Configuring slbd
Nov 18 07:23:34	php: : pfSense package system has detected an ip change 72.160.15.227 -> 72.160.11.189 ... Restarting packages.
Nov 18 07:23:34	last message repeated 29 times
Nov 18 07:23:34	php: : The File Manager package is missing required dependencies and must be reinstalled.
Nov 18 07:23:32	php: : Reloading Squid for configuration sync
Nov 18 07:23:29	squid[29211]: Squid Parent: child process 29831 started
Nov 18 07:23:28	php: : Reloading Squid for configuration sync
Nov 18 07:23:26	squid[29211]: Squid Parent: child process 29214 exited due to signal 6
Nov 18 07:23:26	kernel: pid 29214 (squid), uid 62: exited on signal 6
Nov 18 07:23:26	squid[29214]: The url_rewriter helpers are crashing too rapidly, need help!
Nov 18 07:23:25	last message repeated 3 times
Nov 18 07:23:20	php: : Reloading Squid for configuration sync
Nov 18 07:23:17	Squid_Alarm[29278]: Squid has resumed. Reconfiguring filter.
Nov 18 07:23:17	Squid_Alarm[29269]: Squid has resumed. Reconfiguring filter.
Nov 18 07:23:16	squid[29211]: Squid Parent: child process 29214 started
Nov 18 07:23:16	php: : Starting Squid
Nov 18 07:23:05	php: : SQUID is installed but not started. Not installing "filter" rules.
Nov 18 07:23:05	php: : SQUID is installed but not started. Not installing "nat" rules.
Nov 18 07:23:04	php: : Reloading Squid for configuration sync
Nov 18 07:23:04	squid[28942]: Squid Parent: child process 28945 exited due to signal 9
Nov 18 07:23:03	Squid_Alarm[29021]: Reconfiguring filter...
Nov 18 07:23:02	php: : Reloading Squid for configuration sync
Nov 18 07:23:00	squid[28942]: Squid Parent: child process 28945 started
Nov 18 07:23:00	Squid_Alarm[28935]: Attempting restart...
Nov 18 07:23:00	Squid_Alarm[28933]: Squid has exited. Reconfiguring filter.
Nov 18 07:22:59	squid[54609]: Exiting due to unexpected forced shutdown
Nov 18 07:22:59	squid[54609]: Squid Parent: child process 54823 exited due to signal 15
Nov 18 07:22:59	php: : Resyncing configuration for all packages.
Nov 18 07:22:57	php: : Creating rrd update script
Nov 18 07:22:57	php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is wan - 72.160.11.189.
Nov 18 07:22:52	php: : rc.newwanip working with (IP address: 72.160.11.189) (interface: wan) (interface real: ng0).
Nov 18 07:22:52	php: : Informational: rc.newwanip is starting wan.
Nov 18 07:22:51	check_reload_status: rc.newwanip starting
Nov 18 07:22:48	mpd: 72.160.11.189 -> 72.160.11.1
Nov 18 07:22:48	mpd: IPADDR 72.160.11.1
Nov 18 07:22:48	mpd: 72.160.11.1 is OK
Nov 18 07:22:48	mpd: IPADDR 72.160.11.1
Nov 18 07:22:48	mpd: SECDNS 209.206.160.253
Nov 18 07:22:48	mpd: PRIDNS 209.206.184.249
Nov 18 07:22:48	mpd: IPADDR 72.160.11.189
Nov 18 07:22:48	mpd: SECDNS 209.206.160.253
Nov 18 07:22:48	mpd: PRIDNS 209.206.184.249
Nov 18 07:22:48	mpd: IPADDR 72.160.11.189
Nov 18 07:22:48	mpd: SECDNS 209.206.160.253
Nov 18 07:22:48	mpd: PRIDNS 209.206.184.249
Nov 18 07:22:48	mpd: 72.160.11.189 is OK
Nov 18 07:22:48	mpd: IPADDR 72.160.11.189
Nov 18 07:22:48	mpd: SECDNS 0.0.0.0
Nov 18 07:22:48	mpd: PRIDNS 0.0.0.0
Nov 18 07:22:48	mpd: IPADDR 0.0.0.0
Nov 18 07:22:48	mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 07:22:48	mpd: SECDNS 0.0.0.0
Nov 18 07:22:48	mpd: PRIDNS 0.0.0.0
Nov 18 07:22:48	mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 07:22:48	mpd: IPADDR 0.0.0.0
Nov 18 07:22:46	mpd: SECDNS 0.0.0.0
Nov 18 07:22:46	mpd: PRIDNS 0.0.0.0
Nov 18 07:22:46	mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 07:22:46	mpd: IPADDR 0.0.0.0
Nov 18 07:22:44	mpd: SECDNS 0.0.0.0
Nov 18 07:22:44	mpd: PRIDNS 0.0.0.0
Nov 18 07:22:44	mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 07:22:44	mpd: IPADDR 0.0.0.0
Nov 18 07:22:42	mpd: SECDNS 0.0.0.0
Nov 18 07:22:42	mpd: PRIDNS 0.0.0.0
Nov 18 07:22:42	mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 07:22:42	mpd: IPADDR 0.0.0.0
Nov 18 07:22:41	mpd: MAGICNUM 337e3806
Nov 18 07:22:41	mpd: MRU 1492
Nov 18 07:22:41	mpd: MAGICNUM 5b64e971
Nov 18 07:22:41	mpd: AUTHPROTO PAP
Nov 18 07:22:41	mpd: MRU 1492
Nov 18 07:22:41	mpd: MAGICNUM 5b64e971
Nov 18 07:22:41	mpd: AUTHPROTO PAP
Nov 18 07:22:41	mpd: MRU 1492
Nov 18 07:22:41	mpd: MAGICNUM 337e3806
Nov 18 07:22:41	mpd: MRU 1492
Nov 18 07:22:35	mpd: SECDNS 209.206.160.253
Nov 18 07:22:35	mpd: PRIDNS 209.206.184.249
Nov 18 07:22:35	mpd: IPADDR 72.160.15.69
Nov 18 07:22:33	mpd: SECDNS 209.206.160.253
Nov 18 07:22:33	mpd: PRIDNS 209.206.184.249
Nov 18 07:22:33	mpd: IPADDR 72.160.15.69
Nov 18 07:22:31	mpd: SECDNS 209.206.160.253
      1 Reply Last reply Reply Quote 0
      • W
        wallabybob
        last edited by

        @sully:

        When looking at RRD graphs, there is an unusual high CPU spike at the same time the WAN drops. The pfsense box will, after a couple minutes, reload things and get to working again. Then it works fine until the CPU spike hits again. This is new behaviour.

        The CPU spike is probably a consequence of the WAN link coming on again - some big processes re-initialising.

        @sully:

        Here is what the system log shows, and it sort of repeats this sequence of events at every WAN disconnect. I would like to see more of the log, but don't know where to do that at or how to do that.

        pfSense shell command clog /var/log/system.log will show the full log. You can execute a shell command through the web GUI by going to Diagnostics -> Command Prompt and typing the command in the Command box. There are other log files in /var/log (e.g. firewall log) that you can display using the same technique. I would look in the system log for a hint of the wan link going down, the post says the 10 lines before that and the 10 lines after it.

        @sully:

        I am seeking help in tracking this issue down. I have another box (slower) that I first tried pfsense on, I was thinking of trying that, to determine if the error is in the current box. I could also hook back up to my router (dlink) and see if the problem goes away as well.

        Using the two other systems for a while could provide useful comparison information.

        What sort of NICs are you using? I'm interested in the FreeBSD device names, e.g. sk0, re1 etc. It may be that the WAN nic in the box is "locking up", the driver resets it and this causes the wan link to go down the recover and the recovery causes the CPU spike.

        1 Reply Last reply Reply Quote 0
        • S
          sully
          last edited by

          2 Intel 82550 Pro cards

          I know I have the fxp NICs

          Do you need more than that? I can pull them, but thought those two pieces of data were what would be needed.

          The cpu spike on wan linking sounds logical, had not thought about that.

          I looked at the log. It is chock full of entries, some I can see and understand, other stuff I have no idea. I can see the even happening, both in RRD and now in this log. Here is the beginning of it, and multiple times it happens it appears very much the same, except of course IP is different due to dhcp

          Nov 18 15:57:56 pfsense mpd: [pppoe] LCP: no reply to 1 echo request(s)
Nov 18 15:58:06 pfsense mpd: [pppoe] LCP: no reply to 2 echo request(s)
Nov 18 15:58:16 pfsense mpd: [pppoe] LCP: no reply to 3 echo request(s)
Nov 18 15:58:26 pfsense mpd: [pppoe] LCP: no reply to 4 echo request(s)
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: no reply to 5 echo request(s)
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: peer not responding to echo requests
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: LayerFinish
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: LayerStart
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: state change Opened --> Starting
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: phase shift NETWORK --> DEAD
Nov 18 15:58:36 pfsense mpd: [pppoe] setting interface ng0 MTU to 1500 bytes
Nov 18 15:58:36 pfsense mpd: [pppoe] up: 0 links, total bandwidth 9600 bps
Nov 18 15:58:36 pfsense mpd: [pppoe] IPCP: Down event
Nov 18 15:58:36 pfsense mpd: [pppoe] IPCP: state change Opened --> Starting
Nov 18 15:58:36 pfsense mpd: [pppoe] IPCP: LayerDown
Nov 18 15:58:36 pfsense mpd: [pppoe] IFACE: Down event
Nov 18 15:58:36 pfsense mpd: [pppoe] exec: /sbin/route delete 0.0.0.0 72.160.11.1
Nov 18 15:58:36 pfsense mpd: [pppoe] exec: /sbin/route delete 72.160.11.189 -iface lo0
Nov 18 15:58:36 pfsense mpd: [pppoe] exec: /sbin/ifconfig ng0 down delete -link0
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: LayerDown
Nov 18 15:58:36 pfsense mpd: [pppoe] device: CLOSE event in state UP
Nov 18 15:58:36 pfsense mpd: [pppoe] device is now in state CLOSING
Nov 18 15:58:36 pfsense mpd: [pppoe] device: OPEN event in state CLOSING
Nov 18 15:58:36 pfsense mpd: [pppoe] device is now in state CLOSING
Nov 18 15:58:36 pfsense mpd: [pppoe] device: DOWN event in state CLOSING
Nov 18 15:58:36 pfsense mpd: [pppoe] device is now in state DOWN
Nov 18 15:58:36 pfsense mpd: [pppoe] link: DOWN event
Nov 18 15:58:36 pfsense mpd: [pppoe] LCP: Down event

          The last lines, device closing opening link down up etc, is repeated many times until this segment near the end of the event

          Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: Up event
Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: state change Starting --> Req-Sent
Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: phase shift DEAD --> ESTABLISH
Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: SendConfigReq #29
Nov 18 16:00:56 pfsense mpd:  MRU 1492
Nov 18 16:00:56 pfsense mpd:  MAGICNUM 27ae8972
Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: rec'd Configure Request #156 link 0 (Req-Sent)
Nov 18 16:00:56 pfsense mpd:  MRU 1492
Nov 18 16:00:56 pfsense mpd:  AUTHPROTO PAP
Nov 18 16:00:56 pfsense mpd:  MAGICNUM 3c2f9fec
Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: SendConfigAck #156
Nov 18 16:00:56 pfsense mpd:  MRU 1492
Nov 18 16:00:56 pfsense mpd:  AUTHPROTO PAP
Nov 18 16:00:56 pfsense mpd:  MAGICNUM 3c2f9fec
Nov 18 16:00:56 pfsense mpd: [pppoe] LCP: state change Req-Sent --> Ack-Sent
Nov 18 16:00:58 pfsense mpd: [pppoe] LCP: SendConfigReq #30
Nov 18 16:00:58 pfsense mpd:  MRU 1492
Nov 18 16:00:58 pfsense mpd:  MAGICNUM 27ae8972
Nov 18 16:01:00 pfsense mpd: [pppoe] LCP: SendConfigReq #31
Nov 18 16:01:00 pfsense mpd:  MRU 1492
Nov 18 16:01:00 pfsense mpd:  MAGICNUM 27ae8972
Nov 18 16:01:02 pfsense mpd: [pppoe] LCP: SendConfigReq #32
Nov 18 16:01:02 pfsense mpd:  MRU 1492
Nov 18 16:01:02 pfsense mpd:  MAGICNUM 27ae8972
Nov 18 16:01:02 pfsense mpd: [pppoe] PPPoE connection closed
Nov 18 16:01:02 pfsense mpd: [pppoe] device: DOWN event in state UP
Nov 18 16:01:02 pfsense mpd: [pppoe] device is now in state DOWN
Nov 18 16:01:02 pfsense mpd: [pppoe] link: DOWN event
Nov 18 16:01:02 pfsense mpd: [pppoe] LCP: Down event
Nov 18 16:01:02 pfsense mpd: [pppoe] LCP: state change Ack-Sent --> Starting
Nov 18 16:01:02 pfsense mpd: [pppoe] LCP: phase shift ESTABLISH --> DEAD
Nov 18 16:01:02 pfsense mpd: [pppoe] device: OPEN event in state DOWN
Nov 18 16:01:02 pfsense mpd: [pppoe] pausing 4 seconds before open
Nov 18 16:01:02 pfsense mpd: [pppoe] device is now in state DOWN
Nov 18 16:01:06 pfsense mpd: [pppoe] device: OPEN event in state DOWN
Nov 18 16:01:06 pfsense mpd: [pppoe] pausing 1 seconds before open
Nov 18 16:01:06 pfsense mpd: [pppoe] device is now in state DOWN
Nov 18 16:01:07 pfsense mpd: [pppoe] device: OPEN event in state DOWN
Nov 18 16:01:07 pfsense mpd: [pppoe] device is now in state OPENING
Nov 18 16:01:07 pfsense mpd: [pppoe] rec'd ACNAME "rb-bras.ka-0A014030500677"
Nov 18 16:01:07 pfsense mpd: [pppoe] PPPoE connection successful
Nov 18 16:01:07 pfsense mpd: [pppoe] device: UP event in state OPENING
Nov 18 16:01:07 pfsense mpd: [pppoe] device is now in state UP
Nov 18 16:01:07 pfsense mpd: [pppoe] link: UP event
Nov 18 16:01:07 pfsense mpd: [pppoe] link: origination is local
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: Up event
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: state change Starting --> Req-Sent
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: phase shift DEAD --> ESTABLISH
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: SendConfigReq #33
Nov 18 16:01:07 pfsense mpd:  MRU 1492
Nov 18 16:01:07 pfsense mpd:  MAGICNUM 33b63756
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: rec'd Configure Request #7 link 0 (Req-Sent)
Nov 18 16:01:07 pfsense mpd:  MRU 1492
Nov 18 16:01:07 pfsense mpd:  AUTHPROTO PAP
Nov 18 16:01:07 pfsense mpd:  MAGICNUM 2936b0f0
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: SendConfigAck #7
Nov 18 16:01:07 pfsense mpd:  MRU 1492
Nov 18 16:01:07 pfsense mpd:  AUTHPROTO PAP
Nov 18 16:01:07 pfsense mpd:  MAGICNUM 2936b0f0
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: state change Req-Sent --> Ack-Sent
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: rec'd Configure Ack #33 link 0 (Ack-Sent)
Nov 18 16:01:07 pfsense mpd:  MRU 1492
Nov 18 16:01:07 pfsense mpd:  MAGICNUM 33b63756
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: state change Ack-Sent --> Opened
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: phase shift ESTABLISH --> AUTHENTICATE
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: auth: peer wants PAP, I want nothing
Nov 18 16:01:07 pfsense mpd: [pppoe] PAP: using authname "<snipped>"
Nov 18 16:01:07 pfsense mpd: [pppoe] PAP: sending REQUEST
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: LayerUp
Nov 18 16:01:07 pfsense mpd: [pppoe] PAP: rec'd ACK #1
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: authorization successful
Nov 18 16:01:07 pfsense mpd: [pppoe] LCP: phase shift AUTHENTICATE --> NETWORK
Nov 18 16:01:07 pfsense mpd: [pppoe] setting interface ng0 MTU to 1492 bytes
Nov 18 16:01:07 pfsense mpd: [pppoe] up: 1 link, total bandwidth 64000 bps
Nov 18 16:01:07 pfsense mpd: [pppoe] IPCP: Up event
Nov 18 16:01:07 pfsense mpd: [pppoe] IPCP: state change Starting --> Req-Sent
Nov 18 16:01:07 pfsense mpd: [pppoe] IPCP: SendConfigReq #51
Nov 18 16:01:07 pfsense mpd:  IPADDR 0.0.0.0
Nov 18 16:01:07 pfsense mpd:  COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 16:01:07 pfsense mpd:  PRIDNS 0.0.0.0
Nov 18 16:01:07 pfsense mpd:  SECDNS 0.0.0.0
Nov 18 16:01:07 pfsense mpd: [pppoe] error writing len 32 frame to bypass: Network is down
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: SendConfigReq #52
Nov 18 16:01:09 pfsense mpd:  IPADDR 0.0.0.0
Nov 18 16:01:09 pfsense mpd:  COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 16:01:09 pfsense mpd:  PRIDNS 0.0.0.0
Nov 18 16:01:09 pfsense mpd:  SECDNS 0.0.0.0
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: rec'd Configure Reject #52 link 0 (Req-Sent)
Nov 18 16:01:09 pfsense mpd:  COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: SendConfigReq #53
Nov 18 16:01:09 pfsense mpd:  IPADDR 0.0.0.0
Nov 18 16:01:09 pfsense mpd:  PRIDNS 0.0.0.0
Nov 18 16:01:09 pfsense mpd:  SECDNS 0.0.0.0
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: rec'd Configure Nak #53 link 0 (Req-Sent)
Nov 18 16:01:09 pfsense mpd:  IPADDR 72.160.19.160
Nov 18 16:01:09 pfsense mpd:    72.160.19.160 is OK
Nov 18 16:01:09 pfsense mpd:  PRIDNS 209.206.184.249
Nov 18 16:01:09 pfsense mpd:  SECDNS 209.206.160.253
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: SendConfigReq #54
Nov 18 16:01:09 pfsense mpd:  IPADDR 72.160.19.160
Nov 18 16:01:09 pfsense mpd:  PRIDNS 209.206.184.249
Nov 18 16:01:09 pfsense mpd:  SECDNS 209.206.160.253
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: rec'd Configure Ack #54 link 0 (Req-Sent)
Nov 18 16:01:09 pfsense mpd:  IPADDR 72.160.19.160
Nov 18 16:01:09 pfsense mpd:  PRIDNS 209.206.184.249
Nov 18 16:01:09 pfsense mpd:  SECDNS 209.206.160.253
Nov 18 16:01:09 pfsense mpd: [pppoe] IPCP: state change Req-Sent --> Ack-Rcvd
Nov 18 16:01:10 pfsense mpd: [pppoe] IPCP: rec'd Configure Request #47 link 0 (Ack-Rcvd)
Nov 18 16:01:10 pfsense mpd:  IPADDR 72.160.19.1
Nov 18 16:01:10 pfsense mpd:    72.160.19.1 is OK
Nov 18 16:01:10 pfsense mpd: [pppoe] IPCP: SendConfigAck #47
Nov 18 16:01:10 pfsense mpd:  IPADDR 72.160.19.1
Nov 18 16:01:10 pfsense mpd: [pppoe] IPCP: state change Ack-Rcvd --> Opened
Nov 18 16:01:10 pfsense mpd: [pppoe] IPCP: LayerUp
Nov 18 16:01:10 pfsense mpd:   72.160.19.160 -> 72.160.19.1
Nov 18 16:01:10 pfsense mpd: [pppoe] IFACE: Up event
Nov 18 16:01:10 pfsense mpd: [pppoe] setting interface ng0 MTU to 1492 bytes
Nov 18 16:01:10 pfsense mpd: [pppoe] exec: /sbin/ifconfig ng0 72.160.19.160 72.160.19.1 netmask 0xffffffff -link0
Nov 18 16:01:10 pfsense mpd: [pppoe] exec: /sbin/route add 72.160.19.160 -iface lo0
Nov 18 16:01:10 pfsense mpd: [pppoe] exec: /sbin/route add 0.0.0.0 72.160.19.1
Nov 18 16:01:10 pfsense mpd: [pppoe] exec: /usr/local/sbin/ppp-linkup ng0 inet 72.160.19.160 72.160.19.1 <snipped> dns1 209.206.184.249 dns2 209.206.160.253
Nov 18 16:01:10 pfsense mpd: [pppoe] IFACE: Up event
Nov 18 16:01:11 pfsense check_reload_status: rc.newwanip starting</snipped></snipped>

          Then some data remains, which looks to be restarting of services such as squid, and delcarations that things were forced to stop and are now restarting, etc. This box seems to work fine other than this new problem. This weekend I will try other hardware like another machine, a couple routers and also use livecd for pfsense v2, and hopefully have more info.

          Thanks for taking the time to reply. Much appreciated.

          Sully.

          1 Reply Last reply Reply Quote 0
          • W
            wallabybob
            last edited by

            @sully:

            2 Intel 82550 Pro cards

            I know I have the fxp NICs

            Do you need more than that? I can pull them, but thought those two pieces of data were what would be needed.

            Sorry, I missed that. If you have another NIC you can put in the box (you could purchase one for "small change") you could try using that for the WAN connection and see if you get different behaviour. Even just swap the WAN and LAN cables over (and swap the assignments in pfSense) and see if the behaviour moves.

            Regarding your log, pfSense WAN link has lost contact with the ppp server and for a while. As previously speculated this could be due to a driver or hardware "lockup" in pfSense. Some NICs have more of a reputation for that than the fxps do. Perhaps there is a new intermittent problem in your modem. Perhaps some changes in telephone circuit wiring has affected DSL performance (that has happened to me a couple of times when the phone company made some adjustments on behalf of other subscribers). Perhaps someone has installed some new equipment which intermittently squirts a lot of noise over a telephone circuit. I cam across a puzzling problem with my internet connection a while ago. After an extended power outage I and my family noticed our home internet was very sluggish. After some investigation I discovered that pings between pfSense and ADSL modem were very lossy (up to 60% loss on 50 pings). Modem problem? Since I didn't have a replacement modem on hand I thought I would try a difference interface to the modem and used a USB to Ethernet device I had. This completely cured the problem: no losses in many tries of 50 pings. I am puzzled what went wrong. The modem was previously connected to a VLAN capable switch and pfSense was using the switch as a port multiplier in that a single pfSense physical port was carrying VLAN tagged traffic for both the modem and a server. Pings to the server didn't show any loss while concurrent pings to the modem were showing significant loss. The modem has extremely limited reporting of errors on its LAN interface. (Sometimes it is worth paying a bit more!) I'm not trying to hijack this thread looking for suggestions for my puzzle. I am recounting this experience to illustrate some of the strange problems that can be found in network troubleshooting.

            1 Reply Last reply Reply Quote 0
            • S
              sully
              last edited by

              This problem still persists but has morphed some.

              I stopped using the pfsense box to troubleshoot.

              I used a dlink dir-655 and original gamers lounge routers.

              I used 3 different dsl modems.

              I isolated switches and machines.

              It boils down to something the telco cannot find I guess.

              If I hook dsl modem up, set pppoe in it (modem routers) and connect, then pull network cable from modem so that no inside influence is available, within 24 hours the pppoe connection has been lost and a new ip assigned. I talked to a lean technician at telco, and they said the lease for IP should be indefinate until connection is interuppted, which is how it has been historically.

              Telco has sent service call to my house to check NID 2 times, and both times they say it clear, good signal strength and very low noise.

              I have a very hard time believing 3 modems and 2 routers + pfsense box could be the problem. 2 of the modems were pulled from active service, where they were not exhibiting this problem.

              Logs of modems, routers and pfsense box show nothing, only ppp lost and then reconnect a minute later.

              Now, in the past week, using pfsense again, the IP has not dropped the ppp, but every so often I lose all ability to send packes. If I am on teamspeak, I get a timeout. Happens with iether pfsense or one of the dlink routers. The ability of the router to "ping" is gone, 100% packet loss. Then, a minute or two later, all is normal, the IP does NOT change, speeds are up to par, ping times are normal.

              A number of hours later (variable), same thing happens, could be 1 hour or 12 hours later. Modem does not lose link, IP not changed, just an intermittent "pause" in all incoming/outgoing packets.

              Very strange, and it appears beyond what the telco has knowledge of (not suprising). However, they don't stay hooked up long enough to see the issue, as you cannot reproduce it at will.

              I don't suppose there is anyone who has help for this issue, so I am just posting it so anyone searching for such things in the future can maybe benefit from it.

              1 Reply Last reply Reply Quote 0
              • W
                wallabybob
                last edited by

                Perhaps your modem is restarting (rebooting). Some modems report an uptime. It could be worth checking the uptime after an "outage".

                On hot summer afternoons my pfSense box which has been located near a west facing window sometimes shuts down (I suspect due to overheating which is probably due in part to poorly performing fans).

                1 Reply Last reply Reply Quote 0
                • S
                  sully
                  last edited by

                  @wallabybob:

                  Perhaps your modem is restarting (rebooting). Some modems report an uptime. It could be worth checking the uptime after an "outage".

                  On hot summer afternoons my pfSense box which has been located near a west facing window sometimes shuts down (I suspect due to overheating which is probably due in part to poorly performing fans).

                  I thought to do that. The modem, if you set it to do the pppoe, is accesible and does contain logs. However, the logs in the modem are pretty much like the logs of the router - it only says the connection is down, then tells of getting a new IP. Never any internal errors like of the modem itself shutting down. So, uptime I am afraid is going to go nowhere that I can tell.

                  My pfsense box doesn't appear to overheat at all. If I install a windows OS on it, and use speedfan, all temps are low to medium at best, even running apps that would use more cpu than pfsense does.

                  I am at a loss. I don't think it is related to the hardware myself, but getting the telco to fess up is proving difficult.

                  1 Reply Last reply Reply Quote 0
                  • stephenw10S
                    stephenw10 Netgate Administrator
                    last edited by

                    It seems like you have done everything you possibly could to rule out a problem at your end. Multiplt routers, multiple modems etc.
                    I would bet good money on it being a faulty line card at your exchange but without a friendly telco engineer you are going to have a hard time getting anything done about it.  :(
                    Once enough people start having a problem (there are something like 20 lines per card) they will change it.  ::)

                    Steve

                    1 Reply Last reply Reply Quote 0
                    • First post
                      Last post
                    Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.