Notification always sent twice via email: DynDNS updated IP Address on WAN (pppoe0) to
-
Hi all!
When I get a new IP from my provider I always get two emails about this event. E.g.Notifications in this message: 1 ================================ 1:51:39 DynDNS updated IP Address on WAN (pppoe0) to 87.188.204.91
The log entries of notify_monitor.php shows this:
May 25 01:51:40 pfsense php-cgi: notify_monitor.php: Message sent to message.****@*****.delikom.de OK May 25 01:51:50 pfsense php-cgi: notify_monitor.php: Message sent to message.****@*****.delikom.de OK
10 seconds later a second email was sent with same content. Other notifications was sent only once.
Is this normal behaviour?
Here is the complete intervall of the system.log:
May 25 01:49:45 pfsense rc.gateway_alarm[5785]: >>> Gateway alarm: GW_WAN (Addr:217.237.151.51 Alarm:1 RTT:10080ms RTTsd:380ms Loss:22%) May 25 01:49:45 pfsense check_reload_status: updating dyndns GW_WAN May 25 01:49:45 pfsense check_reload_status: Restarting ipsec tunnels May 25 01:49:45 pfsense check_reload_status: Restarting OpenVPN tunnels/interfaces May 25 01:49:45 pfsense check_reload_status: Reloading filter May 25 01:49:47 pfsense php-fpm[54221]: /rc.dyndns.update: phpDynDNS (*****.no-ip.biz): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. May 25 01:49:48 pfsense php-fpm[54221]: /rc.dyndns.update: phpDynDNS (*****.strangled.net): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. May 25 01:49:49 pfsense php-fpm[54221]: /rc.dyndns.update: phpDynDNS (*****.selfhost.eu): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. May 25 01:49:49 pfsense ppp: [wan_link0] LCP: no reply to 1 echo request(s) May 25 01:49:59 pfsense ppp: [wan_link0] LCP: no reply to 2 echo request(s) May 25 01:50:09 pfsense ppp: [wan_link0] LCP: no reply to 3 echo request(s) May 25 01:50:19 pfsense ppp: [wan_link0] LCP: no reply to 4 echo request(s) May 25 01:50:29 pfsense ppp: [wan_link0] LCP: no reply to 5 echo request(s) May 25 01:50:29 pfsense ppp: [wan_link0] LCP: peer not responding to echo requests May 25 01:50:29 pfsense ppp: [wan_link0] LCP: state change Opened --> Stopping May 25 01:50:29 pfsense ppp: [wan_link0] Link: Leave bundle "wan" May 25 01:50:29 pfsense ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps May 25 01:50:29 pfsense ppp: [wan] IPCP: Close event May 25 01:50:29 pfsense ppp: [wan] IPCP: state change Opened --> Closing May 25 01:50:29 pfsense ppp: [wan] IPCP: SendTerminateReq #8 May 25 01:50:29 pfsense ppp: [wan] IPCP: LayerDown May 25 01:50:30 pfsense check_reload_status: Rewriting resolv.conf May 25 01:50:30 pfsense ppp: [wan] IPV6CP: Close event May 25 01:50:30 pfsense ppp: [wan] IPV6CP: state change Opened --> Closing May 25 01:50:30 pfsense ppp: [wan] IPV6CP: SendTerminateReq #4 May 25 01:50:30 pfsense ppp: [wan] IPV6CP: LayerDown May 25 01:50:30 pfsense check_reload_status: Rewriting resolv.conf May 25 01:50:30 pfsense ppp: [wan] IFACE: Down event May 25 01:50:30 pfsense ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0 May 25 01:50:30 pfsense ppp: [wan] IPCP: Down event May 25 01:50:30 pfsense ppp: [wan] IPCP: LayerFinish May 25 01:50:30 pfsense ppp: [wan] IPCP: state change Closing --> Initial May 25 01:50:30 pfsense ppp: [wan] IPV6CP: Down event May 25 01:50:30 pfsense ppp: [wan] IPV6CP: LayerFinish May 25 01:50:30 pfsense ppp: [wan] Bundle: No NCPs left. Closing links... May 25 01:50:30 pfsense ppp: [wan] IPV6CP: state change Closing --> Initial May 25 01:50:30 pfsense ppp: [wan_link0] LCP: SendTerminateReq #5 May 25 01:50:30 pfsense ppp: [wan_link0] LCP: LayerDown May 25 01:50:31 pfsense siproxd[96988]: sock.c:445 ERROR:sendto() [217.0.0.143:10000 size=28] call failed: Network is unreachable May 25 01:50:33 pfsense ppp: [wan_link0] LCP: SendTerminateReq #6 May 25 01:50:35 pfsense ppp: [wan_link0] LCP: state change Stopping --> Stopped May 25 01:50:35 pfsense ppp: [wan_link0] LCP: LayerFinish May 25 01:50:35 pfsense ppp: [wan_link0] PPPoE: connection closed May 25 01:50:35 pfsense ppp: [wan_link0] Link: DOWN event May 25 01:50:35 pfsense ppp: [wan_link0] LCP: Down event May 25 01:50:35 pfsense ppp: [wan_link0] LCP: state change Stopped --> Starting May 25 01:50:35 pfsense ppp: [wan_link0] LCP: LayerStart May 25 01:50:35 pfsense ppp: [wan_link0] Link: reconnection attempt 1 in 2 seconds May 25 01:50:37 pfsense ppp: [wan_link0] Link: reconnection attempt 1 May 25 01:50:37 pfsense ppp: [wan_link0] PPPoE: Connecting to '' May 25 01:50:44 pfsense siproxd[96988]: sock.c:445 ERROR:sendto() [217.0.0.143:10000 size=28] call failed: Network is unreachable May 25 01:50:46 pfsense ppp: [wan_link0] PPPoE connection timeout after 9 seconds May 25 01:50:46 pfsense ppp: [wan_link0] Link: DOWN event May 25 01:50:46 pfsense ppp: [wan_link0] LCP: Down event May 25 01:50:46 pfsense ppp: [wan_link0] Link: reconnection attempt 2 in 3 seconds May 25 01:50:49 pfsense ppp: [wan_link0] Link: reconnection attempt 2 May 25 01:50:49 pfsense ppp: [wan_link0] PPPoE: Connecting to '' May 25 01:50:56 pfsense siproxd[96988]: sock.c:445 ERROR:sendto() [217.0.0.143:10000 size=28] call failed: Network is unreachable May 25 01:50:58 pfsense ppp: [wan_link0] PPPoE connection timeout after 9 seconds May 25 01:50:58 pfsense ppp: [wan_link0] Link: DOWN event May 25 01:50:58 pfsense ppp: [wan_link0] LCP: Down event May 25 01:50:58 pfsense ppp: [wan_link0] Link: reconnection attempt 3 in 2 seconds May 25 01:51:00 pfsense ppp: [wan_link0] Link: reconnection attempt 3 May 25 01:51:00 pfsense ppp: [wan_link0] PPPoE: Connecting to '' May 25 01:51:09 pfsense ppp: [wan_link0] PPPoE connection timeout after 9 seconds May 25 01:51:09 pfsense ppp: [wan_link0] Link: DOWN event May 25 01:51:09 pfsense ppp: [wan_link0] LCP: Down event May 25 01:51:09 pfsense ppp: [wan_link0] Link: reconnection attempt 4 in 4 seconds May 25 01:51:14 pfsense ppp: [wan_link0] Link: reconnection attempt 4 May 25 01:51:14 pfsense ppp: [wan_link0] PPPoE: Connecting to '' May 25 01:51:16 pfsense siproxd[96988]: sock.c:445 ERROR:sendto() [217.0.0.143:10000 size=28] call failed: Network is unreachable May 25 01:51:23 pfsense ppp: [wan_link0] PPPoE connection timeout after 9 seconds May 25 01:51:23 pfsense ppp: [wan_link0] Link: DOWN event May 25 01:51:23 pfsense ppp: [wan_link0] LCP: Down event May 25 01:51:23 pfsense ppp: [wan_link0] Link: reconnection attempt 5 in 3 seconds May 25 01:51:26 pfsense ppp: [wan_link0] Link: reconnection attempt 5 May 25 01:51:26 pfsense ppp: [wan_link0] PPPoE: Connecting to '' May 25 01:51:26 pfsense siproxd[96988]: sock.c:445 ERROR:sendto() [217.0.0.143:10000 size=28] call failed: Network is unreachable May 25 01:51:28 pfsense ppp: PPPoE: rec'd ACNAME "BERJ23" May 25 01:51:28 pfsense ppp: [wan_link0] PPPoE: connection successful May 25 01:51:28 pfsense ppp: [wan_link0] Link: UP event May 25 01:51:28 pfsense ppp: [wan_link0] LCP: Up event May 25 01:51:28 pfsense ppp: [wan_link0] LCP: state change Starting --> Req-Sent May 25 01:51:28 pfsense ppp: [wan_link0] LCP: SendConfigReq #7 May 25 01:51:28 pfsense ppp: [wan_link0] PROTOCOMP May 25 01:51:28 pfsense ppp: [wan_link0] MRU 1492 May 25 01:51:28 pfsense ppp: [wan_link0] MAGICNUM 0xa493c7cd May 25 01:51:28 pfsense ppp: [wan_link0] LCP: rec'd Configure Request #16 (Req-Sent) May 25 01:51:28 pfsense ppp: [wan_link0] MRU 1492 May 25 01:51:28 pfsense ppp: [wan_link0] AUTHPROTO PAP May 25 01:51:28 pfsense ppp: [wan_link0] MAGICNUM 0x2cb65730 May 25 01:51:28 pfsense ppp: [wan_link0] LCP: SendConfigAck #16 May 25 01:51:28 pfsense ppp: [wan_link0] MRU 1492 May 25 01:51:28 pfsense ppp: [wan_link0] AUTHPROTO PAP May 25 01:51:28 pfsense ppp: [wan_link0] MAGICNUM 0x2cb65730 May 25 01:51:28 pfsense ppp: [wan_link0] LCP: state change Req-Sent --> Ack-Sent May 25 01:51:28 pfsense ppp: [wan_link0] LCP: rec'd Configure Ack #7 (Ack-Sent) May 25 01:51:28 pfsense ppp: [wan_link0] PROTOCOMP May 25 01:51:28 pfsense ppp: [wan_link0] MRU 1492 May 25 01:51:28 pfsense ppp: [wan_link0] MAGICNUM 0xa493c7cd May 25 01:51:28 pfsense ppp: [wan_link0] LCP: state change Ack-Sent --> Opened May 25 01:51:28 pfsense ppp: [wan_link0] LCP: auth: peer wants PAP, I want nothing May 25 01:51:28 pfsense ppp: [wan_link0] PAP: using authname "001*******************0001@t-online.de" May 25 01:51:28 pfsense ppp: [wan_link0] PAP: sending REQUEST #1 len: 54 May 25 01:51:28 pfsense ppp: [wan_link0] LCP: LayerUp May 25 01:51:28 pfsense ppp: [wan_link0] PAP: rec'd ACK #1 len: 24 May 25 01:51:28 pfsense ppp: [wan_link0] MESG: SRU=9460#SRD=52260# May 25 01:51:28 pfsense ppp: [wan_link0] LCP: authorization successful May 25 01:51:28 pfsense ppp: [wan_link0] Link: Matched action 'bundle "wan" ""' May 25 01:51:28 pfsense ppp: [wan_link0] Link: Join bundle "wan" May 25 01:51:28 pfsense ppp: [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps May 25 01:51:28 pfsense ppp: [wan] IPCP: Open event May 25 01:51:28 pfsense ppp: [wan] IPCP: state change Initial --> Starting May 25 01:51:28 pfsense ppp: [wan] IPCP: LayerStart May 25 01:51:28 pfsense ppp: [wan] IPV6CP: Open event May 25 01:51:28 pfsense ppp: [wan] IPV6CP: state change Initial --> Starting May 25 01:51:28 pfsense ppp: [wan] IPV6CP: LayerStart May 25 01:51:28 pfsense ppp: [wan] IPCP: Up event May 25 01:51:28 pfsense ppp: [wan] IPCP: state change Starting --> Req-Sent May 25 01:51:28 pfsense ppp: [wan] IPCP: SendConfigReq #9 May 25 01:51:28 pfsense ppp: [wan] IPADDR 0.0.0.0 May 25 01:51:28 pfsense ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid May 25 01:51:28 pfsense ppp: [wan] PRIDNS 0.0.0.0 May 25 01:51:28 pfsense ppp: [wan] SECDNS 0.0.0.0 May 25 01:51:28 pfsense ppp: [wan] IPV6CP: Up event May 25 01:51:28 pfsense ppp: [wan] IPV6CP: state change Starting --> Req-Sent May 25 01:51:28 pfsense ppp: [wan] IPV6CP: SendConfigReq #5 May 25 01:51:28 pfsense ppp: [wan] IPCP: rec'd Configure Request #25 (Req-Sent) May 25 01:51:28 pfsense ppp: [wan] IPADDR 62.155.240.55 May 25 01:51:28 pfsense ppp: [wan] 62.155.240.55 is OK May 25 01:51:28 pfsense ppp: [wan] IPCP: SendConfigAck #25 May 25 01:51:28 pfsense ppp: [wan] IPADDR 62.155.240.55 May 25 01:51:28 pfsense ppp: [wan] IPCP: state change Req-Sent --> Ack-Sent May 25 01:51:28 pfsense ppp: [wan] IPCP: rec'd Configure Reject #9 (Ack-Sent) May 25 01:51:28 pfsense ppp: [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid May 25 01:51:28 pfsense ppp: [wan] IPCP: SendConfigReq #10 May 25 01:51:28 pfsense ppp: [wan] IPADDR 0.0.0.0 May 25 01:51:28 pfsense ppp: [wan] PRIDNS 0.0.0.0 May 25 01:51:28 pfsense ppp: [wan] SECDNS 0.0.0.0 May 25 01:51:28 pfsense ppp: [wan] IPV6CP: rec'd Configure Request #36 (Req-Sent) May 25 01:51:28 pfsense ppp: [wan] IPV6CP: SendConfigAck #36 May 25 01:51:28 pfsense ppp: [wan] IPV6CP: state change Req-Sent --> Ack-Sent May 25 01:51:28 pfsense ppp: [wan] IPCP: rec'd Configure Nak #10 (Ack-Sent) May 25 01:51:28 pfsense ppp: [wan] IPADDR 87.188.204.91 May 25 01:51:28 pfsense ppp: [wan] 87.188.204.91 is OK May 25 01:51:28 pfsense ppp: [wan] PRIDNS 217.237.151.51 May 25 01:51:28 pfsense ppp: [wan] SECDNS 217.237.149.205 May 25 01:51:28 pfsense ppp: [wan] IPCP: SendConfigReq #11 May 25 01:51:28 pfsense ppp: [wan] IPADDR 87.188.204.91 May 25 01:51:28 pfsense ppp: [wan] PRIDNS 217.237.151.51 May 25 01:51:28 pfsense ppp: [wan] SECDNS 217.237.149.205 May 25 01:51:28 pfsense ppp: [wan] IPV6CP: rec'd Configure Ack #5 (Ack-Sent) May 25 01:51:28 pfsense ppp: [wan] IPV6CP: state change Ack-Sent --> Opened May 25 01:51:28 pfsense ppp: [wan] IPV6CP: LayerUp May 25 01:51:28 pfsense ppp: [wan] 020c:29ff:fe83:95fc -> 0105:0105:3e9b:f037 May 25 01:51:28 pfsense check_reload_status: Rewriting resolv.conf May 25 01:51:29 pfsense check_reload_status: rc.newwanipv6 starting pppoe0 May 25 01:51:29 pfsense ppp: [wan] IFACE: Up event May 25 01:51:29 pfsense ppp: [wan] IFACE: Rename interface ng0 to pppoe0 May 25 01:51:29 pfsense ppp: [wan] IPCP: rec'd Configure Ack #11 (Ack-Sent) May 25 01:51:29 pfsense ppp: [wan] IPADDR 87.188.204.91 May 25 01:51:29 pfsense ppp: [wan] PRIDNS 217.237.151.51 May 25 01:51:29 pfsense ppp: [wan] SECDNS 217.237.149.205 May 25 01:51:29 pfsense ppp: [wan] IPCP: state change Ack-Sent --> Opened May 25 01:51:29 pfsense ppp: [wan] IPCP: LayerUp May 25 01:51:29 pfsense ppp: [wan] 87.188.204.91 -> 62.155.240.55 May 25 01:51:30 pfsense check_reload_status: Rewriting resolv.conf May 25 01:51:30 pfsense php-fpm[59063]: /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0. May 25 01:51:30 pfsense php-fpm[59063]: /rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface WAN [wan]. May 25 01:51:31 pfsense check_reload_status: rc.newwanip starting pppoe0 May 25 01:51:31 pfsense ppp: [wan_link0] rec'd unexpected protocol IP May 25 01:51:31 pfsense ppp: [wan_link0] rec'd unexpected protocol IP May 25 01:51:31 pfsense ppp: [wan_link0] rec'd unexpected protocol IP May 25 01:51:31 pfsense ppp: [wan_link0] rec'd unexpected protocol IP May 25 01:51:32 pfsense php-fpm[59063]: /rc.newwanip: rc.newwanip: Info: starting on pppoe0. May 25 01:51:32 pfsense php-fpm[59063]: /rc.newwanip: rc.newwanip: on (IP address: 87.188.204.91) (interface: WAN[wan]) (real interface: pppoe0). May 25 01:51:32 pfsense php-fpm[59063]: /rc.newwanip: IP Address has changed, killing states on former IP Address 79.198.230.165. May 25 01:51:33 pfsense php-fpm[59063]: /rc.newwanip: ROUTING: setting default route to 62.155.240.55 May 25 01:51:33 pfsense php-fpm[59063]: /rc.newwanip: ROUTING: setting IPv6 default route to fe80::105:105:3e9b:f037%pppoe0 May 25 01:51:33 pfsense php-fpm[59063]: /rc.newwanip: Removing static route for monitor 217.237.151.51 and adding a new route through 62.155.240.55 May 25 01:51:39 pfsense php-fpm[59063]: /rc.newwanip: phpDynDNS: updating cache file /conf/dyndns_wannoip'*****.no-ip.biz'1.cache: 87.188.204.91 May 25 01:51:39 pfsense php-fpm[59063]: /rc.newwanip: phpDynDNS (*****.no-ip.biz): (Success) DNS hostname update successful. May 25 01:51:40 pfsense php-cgi: notify_monitor.php: Message sent to message.****@*****.delikom.de OK May 25 01:51:42 pfsense php-fpm[59063]: /rc.newwanip: phpDynDNS: updating cache file /conf/dyndns_wanfreedns'*****.strangled.net'2.cache: 87.188.204.91 May 25 01:51:42 pfsense php-fpm[59063]: /rc.newwanip: phpDynDNS (*****.strangled.net): (Success) IP Address Changed Successfully! May 25 01:51:43 pfsense php-fpm[59063]: /rc.newwanip: phpDynDNS: updating cache file /conf/dyndns_wanselfhost'*****.selfhost.eu'3.cache: 87.188.204.91 May 25 01:51:43 pfsense php-fpm[59063]: /rc.newwanip: phpDynDNS (*****.selfhost.eu): (Success) IP Address Changed Successfully! (87.188.204.91) May 25 01:51:44 pfsense php-fpm[59063]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN. May 25 01:51:44 pfsense php-fpm[59063]: /rc.newwanip: Creating rrd update script May 25 01:51:46 pfsense php-fpm[59063]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 79.198.230.165 -> 87.188.204.91 - Restarting packages. May 25 01:51:46 pfsense check_reload_status: Starting packages May 25 01:51:47 pfsense php-fpm[43775]: /rc.start_packages: Restarting/Starting all packages. May 25 01:51:50 pfsense php-cgi: notify_monitor.php: Message sent to message.****@*****.delikom.de OK May 25 01:51:50 pfsense siproxd[65025]: siproxd.c:233 INFO:siproxd-0.8.2-7996 amd64-portbld-freebsd11.1 starting up May 25 01:51:50 pfsense siproxd[65213]: siproxd.c:290 INFO:daemonized, pid=65213 May 25 01:51:50 pfsense siproxd[65213]: plugins.c:116 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40 May 25 01:51:50 pfsense siproxd[65213]: plugin_stun.c:109 INFO:plugin_stun is initialized, using stun.t-online.de:10000 as STUN server May 25 01:51:50 pfsense siproxd[65213]: plugins.c:116 INFO:Plugin 'plugin_stun' [Use an external STUN server to determine my public IP] loaded with success, exemask=0x5 May 25 01:51:50 pfsense siproxd[65213]: plugin_fix_DTAG.c:88 INFO:plugin_fix_DTAG is initialized May 25 01:51:50 pfsense siproxd[65213]: plugins.c:116 INFO:Plugin 'plugin_fix_DTAG' [Fixes issues with DTAG (t-online.de) broken SIP headers] loaded with success, exemask=0x40 May 25 01:51:50 pfsense siproxd[65213]: rtpproxy_relay.c:121 INFO:Current thread stacksize is 2048 kB May 25 01:51:50 pfsense siproxd[65213]: sock.c:131 INFO:bound to port 5060 May 25 01:51:50 pfsense siproxd[65213]: siproxd.c:344 INFO:siproxd-0.8.2-7996 amd64-portbld-freebsd11.1 started May 25 01:51:53 pfsense check_reload_status: Reloading filter May 25 01:51:53 pfsense siproxd[65772]: siproxd.c:233 INFO:siproxd-0.8.2-7996 amd64-portbld-freebsd11.1 starting up May 25 01:51:53 pfsense siproxd[66122]: siproxd.c:290 INFO:daemonized, pid=66122 May 25 01:51:53 pfsense siproxd[66122]: plugins.c:116 INFO:Plugin 'plugin_logcall' [Logs calls to syslog] loaded with success, exemask=0x40 May 25 01:51:53 pfsense siproxd[66122]: plugin_stun.c:109 INFO:plugin_stun is initialized, using stun.t-online.de:10000 as STUN server May 25 01:51:53 pfsense siproxd[66122]: plugins.c:116 INFO:Plugin 'plugin_stun' [Use an external STUN server to determine my public IP] loaded with success, exemask=0x5 May 25 01:51:53 pfsense siproxd[66122]: plugin_fix_DTAG.c:88 INFO:plugin_fix_DTAG is initialized May 25 01:51:53 pfsense siproxd[66122]: plugins.c:116 INFO:Plugin 'plugin_fix_DTAG' [Fixes issues with DTAG (t-online.de) broken SIP headers] loaded with success, exemask=0x40 May 25 01:51:53 pfsense siproxd[66122]: rtpproxy_relay.c:121 INFO:Current thread stacksize is 2048 kB May 25 01:51:53 pfsense siproxd[66122]: sock.c:543 ERROR:bind failed: Address already in use May 25 01:51:53 pfsense siproxd[66122]: siproxd.c:332 ERROR:unable to bind to SIP listening socket - aborting
Thank you for reading.
Kind regards,
routerfreak. -
I'm also wondering about this behavior.
I've three DynDNS host names which are to be updated on WAN IP change and I get two notification mails on every IP change.
Is it possible to prevent the double notification or is there an explanation for that?