"check_reload_status: syncing firewall" every 5 minutes in log



  • Hi all pfSense experts  :),
    I have 2.0-RC1 (i386) built on Sat Feb 26 15:30:26 EST 2011  and %subj% alert I get every 5 minutes in my System log so it looks like this:

    
    May 27 05:17:34 	check_reload_status: syncing firewall
    May 27 05:12:33 	check_reload_status: syncing firewall
    May 27 05:07:33 	check_reload_status: syncing firewall
    May 27 05:02:33 	check_reload_status: syncing firewall
    May 27 04:57:32 	check_reload_status: syncing firewall
    May 27 04:52:32 	check_reload_status: syncing firewall
    May 27 04:47:32 	check_reload_status: syncing firewall
    May 27 04:42:31 	check_reload_status: syncing firewall
    May 27 04:37:31 	check_reload_status: syncing firewall
    May 27 04:32:31 	check_reload_status: syncing firewall
    May 27 04:27:30 	check_reload_status: syncing firewall
    May 27 04:22:30 	check_reload_status: syncing firewall
    May 27 04:17:30 	check_reload_status: syncing firewall
    
    

    and it's much longer - like I say, every five minutes during a few recent days.

    What is it the firewall sychronizes with? I surely didn't set up any sort of synchronization. It even happens in the deep night when noone could change firewall configuration. These messages mess up my log and push others down out of view.

    I run Captive portal on this machine, home use - usually only one voucher active at a time, but none was active during these night hours that I pasted in.

    On my another pfSense box I nearly cannot see them.


  • Rebel Alliance Developer Netgate

    That just means that it reloaded the firewall rules. That can happen for a lot of different reasons.



  • This looks like a Microsoft support answer  ;) - but no offense, I understand it is quite complicated inside. It seems to me like there is some sort of a scheduled task reloading the firewall rules every five minutes that I accidentally set up and now don't know how.
    OK, I'll have to accept this behaviour or reinstall. Maybe I can put an article into Redmine…



  • I have turned packet filtering off, but my log also shows this every 5 minutes.


  • Rebel Alliance Developer Netgate

    It's the most accurate answer anyone can give with the minimal information provided. GIGO. :-)

    If you have captive portal enabled, it may be related to something there.



  • Yes, I have the Captive portal enabled - this and DHCP server are the only services I work with. No VPNs, no packages.

    What about you, wk? Do you use CP as well?



  • Yes.
    I only use CP. No other services, no other packages.


  • Rebel Alliance Developer Netgate

    Vouchers or no vouchers?



  • I do use vouchers. The rules still keep reloading every 5 minutes, days and nights, no matter if a voucher is active or not. (actually I mentioned this in my first post, but let's have it confirmed)
    wk?


  • Rebel Alliance Developer Netgate

    Check the output of these two commands:

    $ ps uxawww | grep minicron
    $ cat /etc/crontab
    

    See what entries you have that might be executing every 5 minutes. (Though it could easily not be a cron job…)



  • The first one:

    
    $ ps uxawww | grep minicron
    root   27262  0.0  0.2  3316  1036  ??  Is   19May11   0:00.97 /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local/bin/ping_hosts.sh
    root   27584  0.0  0.2  3316  1036  ??  Is   19May11   0:00.07 /usr/local/bin/minicron 3600 /var/run/expire_accounts.pid /etc/rc.expireaccounts
    root   27746  0.0  0.2  3316  1036  ??  Is   19May11   0:00.00 /usr/local/bin/minicron 86400 /var/run/update_alias_url_data.pid /etc/rc.update_alias_url_data
    root   37975  0.0  0.3  3656  1476  ??  S     2:04PM   0:00.00 sh -c ps uxawww | grep minicron
    root   38435  0.0  0.3  3524  1268  ??  S     2:04PM   0:00.00 grep minicron
    root   58830  0.0  0.2  3316  1040  ??  Is   19May11   0:04.06 /usr/local/bin/minicron 60 /var/run/cp_prunedb.pid /etc/rc.prunecaptiveportal
    root   59217  0.0  0.2  3316  1040  ??  Is   19May11   0:00.82 /usr/local/bin/minicron 300 /var/run/vouchercron.pid /etc/rc.savevoucher
    
    

    and the other:

    
    $ cat /etc/crontab
    SHELL=/bin/sh
    PATH=/etc:/bin:/sbin:/usr/bin:/usr/sbin
    HOME=/var/log
    #minute hour    mday    month   wday    who      command
    #
    #
    # pfSense specific crontab entries
    # Created: May 19, 2011, 7:50 am
    #
    
    0	*	*	*	*	root	/usr/bin/nice -n20 newsyslog
    1,31	0-5	*	*	*	root	/usr/bin/nice -n20 adjkerntz -a
    1	3	1	*	*	root	/usr/bin/nice -n20 /etc/rc.update_bogons.sh
    */60	*	*	*	*	root	/usr/bin/nice -n20 /usr/local/sbin/expiretable -v -t 3600 sshlockout
    1	1	*	*	*	root	/usr/bin/nice -n20 /etc/rc.dyndns.update
    */60	*	*	*	*	root	/usr/bin/nice -n20 /usr/local/sbin/expiretable -v -t 3600 virusprot
    30	12	*	*	*	root	/usr/bin/nice -n20 /etc/rc.update_urltables
    #
    # If possible do not add items to this file manually.
    # If you do so, this file must be terminated with a blank line (e.g. new line)
    #
    
    

  • Rebel Alliance Developer Netgate

    If you run /etc/rc.savevoucher by hand, does it make that message appear in the logs? That appears to be the only thing running every five minutes.



  • Ok, I sent the "/etc/rc.savevoucher" command to the pfSense box through "Execute Shell Command" field - but since then the system's been unresponsive (five minutes). Are you sure that was a good idea?  :)
    I am awaiting a desperate call from my employer any minute…



  • I'm using vouchers too.

    I executed the command via ssh and it worked as jimp said.
    The message appeares in the log.



  • I'm running captive portal and vouchers and I see those messages in the system log:

    clog /var/log/system.log | grep syncing | more

    May 28 18:38:38 pfsense2 check_reload_status: syncing firewall
    May 28 18:43:42 pfsense2 check_reload_status: syncing firewall
    May 28 18:48:45 pfsense2 check_reload_status: syncing firewall
    May 28 18:53:48 pfsense2 check_reload_status: syncing firewall
    May 28 18:58:51 pfsense2 check_reload_status: syncing firewall
    May 28 19:03:55 pfsense2 check_reload_status: syncing firewall
    May 28 19:08:59 pfsense2 check_reload_status: syncing firewall
    May 28 19:14:02 pfsense2 check_reload_status: syncing firewall
    May 28 19:19:06 pfsense2 check_reload_status: syncing firewall
    May 28 19:24:09 pfsense2 check_reload_status: syncing firewall
    May 28 19:29:13 pfsense2 check_reload_status: syncing firewall
    May 28 19:34:15 pfsense2 check_reload_status: syncing firewall
    May 28 19:39:19 pfsense2 check_reload_status: syncing firewall
    May 28 19:44:22 pfsense2 check_reload_status: syncing firewall
    May 28 19:49:25 pfsense2 check_reload_status: syncing firewall
    May 28 19:54:28 pfsense2 check_reload_status: syncing firewall
    May 28 19:59:32 pfsense2 check_reload_status: syncing firewall
    May 28 20:04:35 pfsense2 check_reload_status: syncing firewall
    May 28 20:09:38 pfsense2 check_reload_status: syncing firewall
    May 28 20:14:42 pfsense2 check_reload_status: syncing firewall
    May 28 20:19:46 pfsense2 check_reload_status: syncing firewall
    May 28 20:24:49 pfsense2 check_reload_status: syncing firewall
    May 28 20:29:52 pfsense2 check_reload_status: syncing firewall
    May 28 20:34:55 pfsense2 check_reload_status: syncing firewall
    May 28 20:39:58 pfsense2 check_reload_status: syncing firewall
    May 28 20:45:01 pfsense2 check_reload_status: syncing firewall
    May 28 20:50:04 pfsense2 check_reload_status: syncing firewall
    May 28 20:55:08 pfsense2 check_reload_status: syncing firewall
    May 28 21:00:11 pfsense2 check_reload_status: syncing firewall
    . . .

    On my other pfSense system where I'm not running captive portal:

    clog /var/log/system.log | grep syncing | more

    uname -a

    FreeBSD pfsense.example.org 8.1-RELEASE-p3 FreeBSD 8.1-RELEASE-p3 #1: Sat May 21 21:30:20 EDT 2011     sullrich@FreeBSD_8.0_pfSense_2.0-snaps.pfsense.org:/usr/obj.pfSense/usr/pfSensesrc/src/sys/pfSense.8  i386

    uptime

    11:09PM  up 8 days, 14:54, 2 users, load averages: 0.15, 0.10, 0.07

    I'm running the same pfSense build on both systems.


  • Rebel Alliance Developer Netgate

    So mystery solved. It's the voucher saving process every five minutes causing the log message.

    It's also writing out the config every five minutes in that case, too, so I imagine that your backup history under Diagnostics > Backup/Restore is quite useless.



  • Jimp,

    you are right. The Config History also tells every 5 minutes: (system): made unknown change

    Thanks for helping.



  • Well, does that mean something for devs? Do you consider that bug? May we look forward to this to be fixed in the post-RC version?  :)


  • Rebel Alliance Developer Netgate

    If you enable the voucher save feature, it will always happen. You can change how often this happens in the voucher config options.

    Without saving the vouchers periodically, a sudden reboot would lose voucher usage data.



  • jimp,

    the text in the gui tells: 'No save is done if no new vouchers have been activated.'

    There are no new vouchers or active vouchers.


  • Rebel Alliance Developer Netgate

    I don't see any checks to prevent that write in the backend code. The function called writes the db out whenever it's called. Perhaps that was intended to be added later.

    https://github.com/bsdperimeter/pfsense/blob/master/etc/inc/voucher.inc#L622



  • Maybe. But right now we consider this a little bug, right? So I created a new issue in Redmine. Thank you guys for your cooperation.  :)



  • I can confirm, that since I'm using built Sat Jun 11 the bug is corrected and there are no more log entries and the history is no longer flooded.
    There is also no more possibility to adjust the time of storing to database. I assume, it's still done all 5 minutes, but now silencely.


Locked