All logging has stopped



  • 2.2-RC (amd64)
    built on Wed Dec 24 14:16:30 CST 2014
    FreeBSD 10.1-RELEASE-p3

    Since yesterday at 11:33 all my logs have stopped working, I dont even get any firewall logging or blocking now.

    Anything I can check?

    Edit. What first alerted me, was the internet has become increasingly unresponsive ie failing to load pages from online newspapers, and then when I tried, I found I couldnt access the firewall from the lan either.


  • Rebel Alliance Developer Netgate

    Look at the output of:

    ps uxawww | grep syslog
    

    If nothing shows up, the logging daemon is not running which would explain the lack of logs.

    Pressing Save on the Settings tab of the logs or on System > General will restart syslogd, though it's probably a symptom of some larger problem on your firewall that needs to be figured out.



  • This is the output and still nothing has been logged since 11:33 the other day.

    $ ps uxawww | grep syslog
    root    28670  0.0  0.0  14540  2248  -  S    27Dec14    0:20.85 /usr/local/sbin/radvd -p /var/run/radvd.pid -C /var/etc/radvd.conf -m syslog
    root    51623  0.0  0.0  17144  2640  -  S    9:54PM    0:00.00 sh -c ps uxawww | grep syslog 2>&1
    root    51929  0.0  0.0  18884  2384  -  S    9:54PM    0:00.00 grep syslog

    Pressing Save on the Settings tab of the logs or on System > General will restart syslogd, though it's probably a symptom of some larger problem on your firewall that needs to be figured out.

    I did increase the log size from 750 to a figure above 2000 around that time to get some info out for another post, got this
    _"The following input errors were detected:

    Number of log entries to show must be between 5 and 2000."_

    so reduced it to 2000 and clicked save.

    I guess it doesnt like 2000 as I have just tried 2000 again and clicked save, no logging, I changed it 1000 starts logging, tried 1500 and it doesnt log, tried 1001 and it doesnt log, so I guess pf is accepting 1000 as a value but the php/html is allowing upto 2000.

    If its not reproducible, my settings are
    Forward/Reverse Display ticked
    1000
    blank
    4x log packets….. all ticked
    log errors ticked
    raw logs unticked
    filter description - dont load desc
    local logging unticked
    default (any)
    ipv4
    everything else blank and/or not filled in.

    edit.
    "so I guess pf is accepting 1000 as a value"
    should read
    "so I guess pf is accepting upto 1000 as a value"

    5 and below including negative numbers works as expected.



  • The "GUI log entries to display" field you're changing only impacts how many logs are shown on each logging tab, it doesn't actually affect syslogd except that it restarts it. Seems like that's failing on your system in some circumstances for some reason. If you leave that number alone and hit save, it'll do the same thing from syslogd's perspective.

    When it stops logging, is the last thing you see in the system log something like "syslogd: exiting on signal 15"?  When you hit Save on the Settings tab there, the logs you should get are:

    Jan  7 19:24:38 alix syslogd: exiting on signal 15
    Jan  7 19:24:38 alix syslogd: kernel boot file is /boot/kernel/kernel
    
    

    where it exits in the first line, then is restarted in the second. I'm guessing when it doesn't work you get the exit, and not the restart. Hard to tell why syslog isn't starting since it isn't going to log if it isn't up and running, but you might get something clear if you try to launch it manually after it being stopped. Run the following:

    /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /var/etc/syslog.conf
    

    and what output do you get from that?



  • Jan 8 11:16:04 syslogd: kernel boot file is /boot/kernel/kernel *******
    Jan 7 23:18:53 syslogd: exiting on signal 15
    Jan 7 23:18:53 check_reload_status: Syncing firewall
    Jan 7 23:15:20 syslogd: kernel boot file is /boot/kernel/kernel
    Jan 7 23:15:05 syslogd: exiting on signal 15
    Jan 7 23:15:05 check_reload_status: Syncing firewall
    Jan 7 22:40:00 php: snort_check_cron_misc.inc: [Snort] Alert pcap file cleanup job removed 1 pcap file(s) from /var/log/snort/snort_em061353/…
    Jan 7 22:19:44 syslogd: kernel boot file is /boot/kernel/kernel
    Jan 7 22:13:40 syslogd: exiting on signal 15
    Jan 7 22:13:40 check_reload_status: Syncing firewall
    Jan 7 22:05:45 syslogd: kernel boot file is /boot/kernel/kernel
    Jan 7 22:02:15 syslogd: exiting on signal 15
    Jan 7 22:02:15 check_reload_status: Syncing firewall
    Jan 7 22:01:57 kernel: 6 13:37:56 php-fpm[84641]: /rc.dyndns.update: DynDns: updatedns() starting
    Jan 7 22:01:57 syslogd: kernel boot file is /boot/kernel/kernel
    Jan 6 11:33:12 syslogd: exiting on signal 15
    Jan 6 11:33:12 check_reload_status: Syncing firewall
    Jan 6 11:19:49 check_reload_status: Syncing firewall
    Jan 6 10:39:46 php-fpm[88580]: /index.php: Successful login for user 'admin' from: 192.168.10.20

    The Jan7 entries from 22:01 are the logs from when I was changing the log number in the log settings, although its currently on 1000 and I can see the logging has stopped.

    *** is when I run your command
    /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /var/etc/syslog.conf

    I'm going to update from the 24th Dec build that I'm currently on and see if that makes any difference.

    Edit.

    Upgraded to
    2.2-RC (amd64)
    built on Thu Jan 08 03:14:18 CST 2015
    FreeBSD 10.1-RELEASE-p3

    and can see in the log which still has GUI Log Entries to Display = 1000
    Jan 8 13:10:58 syslogd: exiting on signal 15
    Jan 8 13:10:58 php: rc.bootup: Finished reinstalling all packages.
    Jan 8 13:10:58 php: rc.bootup: Finished installing package snort
    Jan 8 13:10:58 php: rc.bootup: Successfully installed package: snort.

    If I run
    /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /var/etc/syslog.conf

    and check the logs, this is what I see.
    Jan 8 13:23:53 syslogd: kernel boot file is /boot/kernel/kernel
    Jan 8 13:10:58 syslogd: exiting on signal 15
    Jan 8 13:10:58 php: rc.bootup: Finished reinstalling all packages.
    Jan 8 13:10:58 php: rc.bootup: Finished installing package snort
    Jan 8 13:10:58 php: rc.bootup: Successfully installed package: snort.



  • Just an observation on the forum software.

    I edited the post above after upgrading the fw, which meant getting assigned a new ip address, but I didnt get asked to log back in again to the forum when I edited the above post.

    Does the forum software use the cookies to decide who can stay logged in or some other method to determine that I'm who-I-say-I-am even though I've come from a different ip address?



  • so apparently there is no reason it can't start syslogd. I was hoping you'd get some kind of useful output out of it as to why it didn't start again. What are you running on there outside of defaults?

    @firewalluser:

    Does the forum software use the cookies to decide who can stay logged in or some other method to determine that I'm who-I-say-I-am even though I've come from a different ip address?

    The session cookies in SMF aren't tied to an IP. That's generally more trouble than it's worth (CGN, multi-WAN load balancing, mobile systems, etc. will normally change IPs).



  • Snort (2.9.7.0 pkg v3.2.1) is the only package installed and running at the moment although only using Snort Community & Emerging Threats for now.

    DynaDNS (Custom) for a couple domain names with various sub domains like www.domain.com & mail.domain.com, total entries 9.

    2 port forwards (25 & 465) with corresponding rules to an old 2005 AMD windows 7 laptop running a mail server & freeswitch with some apps I've written to plug gaps where stuff doesnt work in Freeswitch.

    Wan is variable ip home adsl, using an old router configured as a modem, pfsense doing the ppoe.

    Running on an Intel NUC 847 which is a Intel(R) Celeron(R) CPU 847 @ 1.10GHz 2 CPUs: 1 package(s) x 2 core(s), got 8Gb ram & a 128Gb mSata drive, and a http://plugable.com/products/usb2-e100 acting as the wan interface for a dual nic setup, so fairly quick and not really stressed hardware.

    Is there any additional/debug logging I can switch on at this end or is whats shown in the log the most amount of data I can get out it?



  • Problem is you have no logging under that circumstance. Try resetting your log files on the settings tab there, does that stop the issue?



  • I'll see how that goes, however as its possible other users might change the number of entries in the log and then click save, could something be added to advise resseting the logs after changing the number of entries so others avoid a similar situation?



  • Changing "GUI Log Entries to Display" has no impact on syslogd at all. That suggestion wasn't based on having changed that field.

    Did you also change "Log File Size (Bytes)" at some point?



  • Yes, I had changed Log File Size (Bytes) in the past, but currently its not set becuase a couple of upgrades had not gone smoothly so I'd reinstalled from a memstick install and not changed the log file size from its default of being blank since then.



  • 2.2-RC (amd64)
    built on Sat Jan 10 03:54:06 CST 2015
    FreeBSD 10.1-RELEASE-p3

    $ ps uxawww | grep syslog
    root    31633  0.0  0.0  14540  2248  -  S    Sat09PM    0:09.31 /usr/local/sbin/radvd -p /var/run/radvd.pid -C /var/etc/radvd.conf -m syslog
    root    60483  0.0  0.0  17144  2652  -  S    8:36AM    0:00.00 sh -c ps uxawww | grep syslog 2>&1
    root    60932  0.0  0.0  18884  2384  -  S    8:36AM    0:00.00 grep syslog
    root    96576  0.0  0.0  14664  2432  -  Ss  Sun12PM    2:20.21 /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /var/etc/syslog.conf

    Out of a possible 2000 firewall log entries, I've only got 765 which span from Jan 15 08:02:28 through to Jan 15 05:38:02, which would suggest the fw packet logging has stopped as its not logged any entries for the packets going to the the mail server thats had email in every hour through out the night.

    Whether this is linked to my other post https://forum.pfsense.org/index.php?topic=86087.msg476118#msg476118
    I dont know at this stage.



  • This is the root cause of the problem here, with a fix that can be installed using the system patches package.
    https://redmine.pfsense.org/issues/4393