1200 DynDNS Email Notifications Every Night

sotirone

Hello, I am having a weird problem.

This began at a remote site 5 days ago.

Every night at 03:05:40 I start getting email notifications 3:05:40 DynDNS updated IP Address on WAN (pppoe0) to XXX.XXX.XXX.XXX

This starts precisely at 03:05:40 every night and ends sometime after 7AM (7:23, 7:24, 7:43, etc.)

During that time, I get ~1200 emails with the message above, with the time in the message being the same (3:05:40). It is as if pfSense thinks the notification was not sent and tries again and again.

I had a look at the logs but I could not find anything. The gateway is working fine at those hours and the DynDNS update is expected (it runs every 5 minutes), however my public IP has not changed for the last week and thus I am not expecting email notifications.

Any idea what could be wrong here?

stephenw10

Hmm, odd. Do you also see 1200 notifications in the webgui?

What do you see in: /var/db/notifyqueue.messages?

sotirone

@stephenw10 I do not see any notifications in the UI.

Just today I got this:

PHP ERROR: Type: 1, File: /usr/local/share/pear/Net/Socket.php, Line: 189, Message: Maximum execution time of 900 seconds exceeded @ 2022-09-06 16:24:06

Also, since I posted this thread, this behavior stopped, I did not get any more of these Email Notifications. Last day was on September 6. I checked and email notifications still work fine.

Also:

cat /var/db/notifyqueue.messages 
a:1:{s:5:"mails";a:1:{s:4:"item";a:1:{i:0;a:3:{s:4:"time";i:1662077140;s:4:"type";s:4:"mail";s:3:"msg";s:57:"DynDNS updated IP Address on WAN (pppoe0) to XXX.XXX.XXX.XXX;}}}}

Gertjan

@sotirone said in 1200 DynDNS Email Notifications Every Night:

Just today I got this:
PHP ERROR: Type: 1, File: /usr/local/share/pear/Net/Socket.php, Line: 189, Message: Maximum execution time of 900 seconds exceeded @ 2022-09-06 16:24:06

Also,

At 16:24:06 pfSense, using some GUI script code, wanted to to connect to 'somewhere'.
Most probably some where on the Internet - and it could be a mail. Or doing what I'll mention below.
Or, the connection could not be created for 15 minutes.
I presume the WAN interface was still up, routing tables still valid, etc, but no connection.
Could be anything, an isolated issue.

About the DynDNS issue : several suggestions :
Check if your drive is writeable.
Check if you have one or more files starting with dyndns_........ with the extension 'cache'
These file(s ) should contain the current WAN IP.
Visit http://checkip.dyndns.org - this should show the same IPv4. pfSEnse uses (connects to) http://checkip.dyndns.org to figure out what the WAN IP is.
Activate :

on the Dyndns settings page.
Observe the logs.

stephenw10

That DynDNS notification looks expected if the WAN IP changed.

Gertjan

@stephenw10 said in 1200 DynDNS Email Notifications Every Night:

That DynDNS notification looks expected if the WAN IP changed.

The message looks fine.
see https://github.com/pfsense/pfsense/blob/9484a1cbdc2fa73cfe24681c342327729ffb6d61/src/etc/inc/dyndns.class#L2941
But what happens when the file /cf/conf/dyndnswanxxxxxx.cache doesn't get written to disk ?

Normally,
dyndns get started, compares the file with the current WAN IP ( using http://checkip.dyndns.org ), and if the same, goes back to sleep.

If the file wasn't written, or doesn't contain correct info, there will be a renewal every x minutes.

Maybe a bit far fetched, but I've recall seening something like this in the past.
I can't get my hands on the forum message where a disk was mounted read only, or there was a part ion error, or disk full, and dyndns went wild.

A detailed dyndns log would be nice.

sotirone

@gertjan

Sep 17 17:36:10 	php-fpm 	75704 	/services_dyndns_edit.php: Configuration Change: admin@172.16.0.2 (Local Database): Dynamic DNS client configured.
Sep 17 17:36:10 	php-fpm 	75704 	/services_dyndns_edit.php: Beginning configuration backup to https://acb.netgate.com/save
Sep 17 17:36:10 	check_reload_status 	398 	Syncing firewall
Sep 17 17:36:10 	php-fpm 	75704 	/services_dyndns_edit.php: Dynamic DNS: updatedns() starting
Sep 17 17:36:10 	php-fpm 	75704 	/services_dyndns_edit.php: Dynamic DNS custom (): ip redacted extracted from local system.
Sep 17 17:36:10 	php-fpm 	75704 	/services_dyndns_edit.php: Dynamic DNS (): running get_failover_interface for wan. found pppoe0
Sep 17 17:36:11 	php-fpm 	75704 	/services_dyndns_edit.php: Dynamic DNS custom (): ip redacted extracted from local system.
Sep 17 17:36:11 	php-fpm 	75704 	/services_dyndns_edit.php: Dynamic Dns (): Current WAN IP: ip redacted Cached IP: ip redacted
Sep 17 17:36:11 	php-fpm 	75704 	/services_dyndns_edit.php: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Sep 17 17:36:11 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:36:23 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:36:34 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:36:46 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:36:58 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:37:04 	php 	24879 	/usr/local/sbin/acbupload.php: End of configuration backup to https://acb.netgate.com/save (success).
Sep 17 17:37:09 	php 	8219 	notify_monitor.php: Message sent to email redacted OK 
Sep 17 17:37:21 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:37:33 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:37:45 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:37:57 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:38:08 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:38:20 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:38:32 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:38:44 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:38:55 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:39:07 	php 	8219 	notify_monitor.php: Message sent to email redacted OK
Sep 17 17:39:19 	php 	8219 	notify_monitor.php: Message sent to email redacted OK

Edit: I had to kill 8219 to make it stop.

I don't think the drive is mounted ro or cannot be written. I can touch test files just fine on /

Gertjan

It ends with

@sotirone said in 1200 DynDNS Email Notifications Every Night:

Sep 17 17:36:11 php-fpm 75704 /services_dyndns_edit.php: phpDynDNS (): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS

so the file contains the same IP as the actual WAN IP
and
the file date is younger as 25 days from now.

So there is nothing to do : all looks fine.

Another look at :

Sep 17 17:39:07 php 8219 notify_monitor.php: Message sent to email redacted OK

The mail gets send, but some failure stops the mail from getting de-queued - and it will get send again.
So not a dynsds issue, as no further dyndns log lines are shown, but a notification system issue.