Syslog remote logging problem after reboot

athurdent · Feb 1, 2013, 10:17 AM

I also tried a reset to factory defaults now. After that I just disabled IPv6 on the LAN/WAN interface, set a DNS and went straight to the remote syslog settings, remote logging works. After a reboot it stops working. The first message in /var/log/system.log is:

syslogd: sendto: Network is unreachable

I'm getting this error on all my pfSense hosts: An ALIX board, a KVM and an old Dell Notebook.
The config says:

	 <syslog><nentries>50</nentries>
		<remoteserver>192.168.1.100</remoteserver>
		 <remoteserver2><remoteserver3><logall><enable></enable></logall></remoteserver3></remoteserver2></syslog>

What am I doing wrong?

mrzaz · Feb 2, 2013, 5:21 PM

I am NOT seeing any "syslogd: sendto: Network is unreachable" in my system.log.
And it works fine even after reboot.

And my config looks like this:

	 <syslog><nentries>50</nentries>
		<remoteserver>192.168.120.62</remoteserver>
		 <remoteserver2><remoteserver3><enable><logall></logall></enable></remoteserver3></remoteserver2></syslog>

//Dan

jimp · Feb 3, 2013, 10:18 PM

Where is 192.168.120.62? On your LAN? Across a VPN? Somewhere else? If it's local, what type of interface is it on? Captive portal enabled there?

I've got a router on 2.1 just installed on Friday that does remote syslog across OpenVPN and it works fine after a reboot, no problems there at all.

athurdent · Feb 4, 2013, 7:31 AM

My devices are all in the same LAN subnet, even on the same switch. I played a little with an ALIX Board, no VLANs, just plain vr interfaces. LAN static, WAN DHCP. No captive portal, just the freeradius2 package installed, OpenVPN and IPsec VPN enabled.
Strangely logging works when I use my local IPv6 net. As that does not rely on ARP, I had a look at my switch configuration (Cisco SG300), but playing with ARP and MAC age settings did not help. Then I tried the hardware settings on the ALIX, but after enabling Device Polling it became unreachable after reboot. I have power cycle it tonight, I was doing the tests remote.
Is it normal for dmesg printing those after reboot? I always get those…

Trying to mount root from ufs:/dev/ufs/pfsense1
vr1: link state changed to DOWN
vr1: link state changed to UP
vr0: link state changed to DOWN
pflog0: promiscuous mode enabled
vr0: link state changed to UP

mrzaz · Feb 4, 2013, 8:14 AM

@jimp:

Where is 192.168.120.62? On your LAN? Across a VPN? Somewhere else? If it's local, what type of interface is it on? Captive portal enabled there?

I've got a router on 2.1 just installed on Friday that does remote syslog across OpenVPN and it works fine after a reboot, no problems there at all.

Jimp: My system is working OK and the 192.168.120.62 is on the local LAN subnet and normal NIC interface. And not using captive portal.
It is "athurdent" who has problems. Just briefing him that it is not generic problem with 2.1 but seems to be a local problem.

The reason to why I included my config was just to show him how my working one looks like. :)

//Dan

bardelot · Feb 4, 2013, 1:28 PM

@athurdent:

Strangely logging works when I use my local IPv6 net.

There is a fix that restarts syslog at the end of the booting process when an IPv6 address is being used. The reason for that fix was very similar to the problem you are experiencing, where syslog would not send logs over IPv6 at bootup. Here is that note http://redmine.pfsense.org/issues/2370#note-12.

athurdent · Feb 5, 2013, 5:58 AM

Thanks, I think I'll stick with IPv6 for now. I know it used to work after a reboot, I am using and updating my pfSense 2.1 KVM for approx. a year now. If I changed something relevant to that in my network, I cannot find it. As it works everywhere else, I'll keep on looking and report back when I find the cause. Thanks for the help so far!

Ocid · Feb 5, 2013, 9:04 AM

I have the same problem with my test server (built on Mon Feb 4 03:44:55 EST 2013), no entries in remote syslog.


	 <syslog><reverse><nentries>50</nentries>
		 <logall><nologdefaultblock><remoteserver>192.168.10.10</remoteserver>
		 <remoteserver2><remoteserver3><enable></enable></remoteserver3></remoteserver2></nologdefaultblock></logall></reverse></syslog>

Remote syslog server is in same LAN.

My "production" pfSense machine (built on Mon Jan 28 07:27:34 EST 2013 [not updated, before new Status Queues page works]) does send events to remote syslog.


	 <syslog><nentries>100</nentries>
		 <reverse><remoteserver>192.168.10.10</remoteserver>
		 <remoteserver2><remoteserver3><enable><nologdefaultblock><dhcp><portalauth><vpn><apinger><relayd><hostapd></hostapd></relayd></apinger></vpn></portalauth></dhcp></nologdefaultblock></enable></remoteserver3></remoteserver2></reverse></syslog>

athurdent · Feb 5, 2013, 9:08 AM

Interesting, what is the first entry in /var/log/system.log?

Ocid · Feb 5, 2013, 9:48 AM

@athurdent:

Interesting, what is the first entry in /var/log/system.log?

Feb 5 11:25:06	kernel: Copyright (c) 1992-2012 The FreeBSD Project.

And because I don't think that that is enough, so here's a bit more:


Feb 5 11:25:06	kernel: Copyright (c) 1992-2012 The FreeBSD Project.
Feb 5 11:25:06	kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Feb 5 11:25:06	kernel: The Regents of the University of California. All rights reserved.
Feb 5 11:25:06	kernel: FreeBSD is a registered trademark of The FreeBSD Foundation.
Feb 5 11:25:06	kernel: FreeBSD 8.3-RELEASE-p5 #1: Mon Feb 4 04:12:41 EST 2013
Feb 5 11:25:06	kernel: root@snapshots-8_3-i386.builders.pfsense.org:/usr/obj./usr/pfSensesrc/src/sys/pfSense_SMP.8 i386
Feb 5 11:25:06	kernel: Timecounter "i8254" frequency 1193182 Hz quality 0
Feb 5 11:25:06	kernel: CPU: Intel(R) Core(TM)2 Duo CPU T7700 @ 2.40GHz (2488.27-MHz 686-class CPU)
Feb 5 11:25:06	kernel: Origin = "GenuineIntel" Id = 0x6fa Family = 6 Model = f Stepping = 10
Feb 5 11:25:06	kernel: Features=0xfa3fbff <fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,dts,mmx,fxsr,sse,sse2,ss>Feb 5 11:25:06	kernel: Features2=0x80202201 <sse3,ssse3,cx16,x2apic,hv>Feb 5 11:25:06	kernel: AMD Features=0x20100000 <nx,lm>Feb 5 11:25:06	kernel: AMD Features2=0x1 <lahf>Feb 5 11:25:06	kernel: TSC: P-state invariant
Feb 5 11:25:06	kernel: real memory = 268435456 (256 MB)
Feb 5 11:25:06	kernel: avail memory = 238817280 (227 MB)
Feb 5 11:25:06	kernel: ACPI APIC Table: <ptltd apic="">Feb 5 11:25:06	kernel: MADT: Forcing active-low polarity and level trigger for SCI
Feb 5 11:25:06	kernel: ioapic0 <version 1.1="">irqs 0-23 on motherboard
Feb 5 11:25:06	kernel: wlan: mac acl policy registered
Feb 5 11:25:06	kernel: ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
Feb 5 11:25:06	kernel: ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Feb 5 11:25:06	kernel: module_register_init: MOD_LOAD (ipw_bss_fw, 0xc07b9a10, 0) error 1
Feb 5 11:25:06	kernel: ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
Feb 5 11:25:06	kernel: ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Feb 5 11:25:06	kernel: module_register_init: MOD_LOAD (ipw_ibss_fw, 0xc07b9ab0, 0) error 1
Feb 5 11:25:06	kernel: ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
Feb 5 11:25:06	kernel: ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Feb 5 11:25:06	kernel: module_register_init: MOD_LOAD (ipw_monitor_fw, 0xc07b9b50, 0) error 1
Feb 5 11:25:06	kernel: kbd1 at kbdmux0
Feb 5 11:25:06	kernel: cryptosoft0: <software crypto="">on motherboard
Feb 5 11:25:06	kernel: padlock0: No ACE support.
Feb 5 11:25:06	kernel: acpi0: <intel 440bx="">on motherboard
Feb 5 11:25:06	kernel: acpi0: [ITHREAD]
Feb 5 11:25:06	kernel: acpi0: Power Button (fixed)
Feb 5 11:25:06	kernel: Timecounter "HPET" frequency 14318180 Hz quality 900
Feb 5 11:25:06	kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
Feb 5 11:25:06	kernel: acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
Feb 5 11:25:06	kernel: cpu0: <acpi cpu="">on acpi0
Feb 5 11:25:06	kernel: pcib0: <acpi host-pci="" bridge="">port 0xcf8-0xcff on acpi0
Feb 5 11:25:06	kernel: pci0: <acpi pci="" bus="">on pcib0
Feb 5 11:25:06	kernel: pcib1: <acpi pci-pci="" bridge="">at device 1.0 on pci0
Feb 5 11:25:06	kernel: pci1: <acpi pci="" bus="">on pcib1
Feb 5 11:25:06	kernel: isab0: <pci-isa bridge="">at device 7.0 on pci0
Feb 5 11:25:06	kernel: isa0: <isa bus="">on isab0
Feb 5 11:25:06	kernel: atapci0: <intel piix4="" udma33="" controller="">port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x10c0-0x10cf at device 7.1 on pci0
Feb 5 11:25:06	kernel: ata0: <ata channel="">at channel 0 on atapci0
Feb 5 11:25:06	kernel: ata0: [ITHREAD]
Feb 5 11:25:06	kernel: ata1: <ata channel="">at channel 1 on atapci0
Feb 5 11:25:06	kernel: ata1: [ITHREAD]
Feb 5 11:25:06	kernel: pci0: <bridge>at device 7.3 (no driver attached)
Feb 5 11:25:06	kernel: pci0: <base peripheral=""> at device 7.7 (no driver attached)
Feb 5 11:25:06	kernel: vgapci0: <vga-compatible display="">port 0x10d0-0x10df mem 0xd0000000-0xd7ffffff,0xc8800000-0xc8ffffff irq 16 at device 15.0 on pci0
Feb 5 11:25:06	kernel: pcib2: <acpi pci-pci="" bridge="">at device 17.0 on pci0
Feb 5 11:25:06	kernel: pci2: <acpi pci="" bus="">on pcib2
Feb 5 11:25:06	kernel: em0: <intel(r) 1000="" pro="" legacy="" network="" connection="" 1.0.4="">port 0x2000-0x203f mem 0xc9020000-0xc903ffff,0xc9000000-0xc900ffff irq 18 at device 0.0 on pci2
Feb 5 11:25:06	kernel: em0: Memory Access and/or Bus Master bits were not set!
Feb 5 11:25:06	kernel: em0: [FILTER]
Feb 5 11:25:06	kernel: em1: <intel(r) 1000="" pro="" legacy="" network="" connection="" 1.0.4="">port 0x2040-0x207f mem 0xc9040000-0xc905ffff,0xc9010000-0xc901ffff irq 19 at device 1.0 on pci2
Feb 5 11:25:06	kernel: em1: Memory Access and/or Bus Master bits were not set!
Feb 5 11:25:06	kernel: em1: [FILTER]
Feb 5 11:25:06	kernel: pcib3: <acpi pci-pci="" bridge="">at device 21.0 on pci0
Feb 5 11:25:06	kernel: pci3: <acpi pci="" bus="">on pcib3
Feb 5 11:25:06	kernel: pcib4: <acpi pci-pci="" bridge="">at device 21.1 on pci0
Feb 5 11:25:06	kernel: pci4: <acpi pci="" bus="">on pcib4
Feb 5 11:25:06	kernel: pcib5: <acpi pci-pci="" bridge="">at device 21.2 on pci0
Feb 5 11:25:06	kernel: pci5: <acpi pci="" bus="">on pcib5
Feb 5 11:25:06	kernel: pcib6: <acpi pci-pci="" bridge="">at device 21.3 on pci0
Feb 5 11:25:06	kernel: pci6: <acpi pci="" bus="">on pcib6
Feb 5 11:25:06	kernel: pcib7: <acpi pci-pci="" bridge="">at device 21.4 on pci0
Feb 5 11:25:06	kernel: pci7: <acpi pci="" bus="">on pcib7
Feb 5 11:25:06	kernel: pcib8: <acpi pci-pci="" bridge="">at device 21.5 on pci0
Feb 5 11:25:06	kernel: pci8: <acpi pci="" bus="">on pcib8
Feb 5 11:25:06	kernel: pcib9: <acpi pci-pci="" bridge="">at device 21.6 on pci0
Feb 5 11:25:06	kernel: pci9: <acpi pci="" bus="">on pcib9
Feb 5 11:25:06	kernel: pcib10: <acpi pci-pci="" bridge="">at device 21.7 on pci0
Feb 5 11:25:06	kernel: pci10: <acpi pci="" bus="">on pcib10
Feb 5 11:25:06	kernel: pcib11: <acpi pci-pci="" bridge="">at device 22.0 on pci0
Feb 5 11:25:06	kernel: pci11: <acpi pci="" bus="">on pcib11
Feb 5 11:25:06	kernel: pcib12: <acpi pci-pci="" bridge="">at device 22.1 on pci0
Feb 5 11:25:06	kernel: pci12: <acpi pci="" bus="">on pcib12
Feb 5 11:25:06	kernel: pcib13: <acpi pci-pci="" bridge="">at device 22.2 on pci0
Feb 5 11:25:06	kernel: pci13: <acpi pci="" bus="">on pcib13
Feb 5 11:25:06	kernel: pcib14: <acpi pci-pci="" bridge="">at device 22.3 on pci0
Feb 5 11:25:06	kernel: pci14: <acpi pci="" bus="">on pcib14
Feb 5 11:25:06	kernel: pcib15: <acpi pci-pci="" bridge="">at device 22.4 on pci0
Feb 5 11:25:06	kernel: pci15: <acpi pci="" bus="">on pcib15
Feb 5 11:25:06	kernel: pcib16: <acpi pci-pci="" bridge="">at device 22.5 on pci0
Feb 5 11:25:06	kernel: pci16: <acpi pci="" bus="">on pcib16
Feb 5 11:25:06	kernel: pcib17: <acpi pci-pci="" bridge="">at device 22.6 on pci0
Feb 5 11:25:06	kernel: pci17: <acpi pci="" bus="">on pcib17
Feb 5 11:25:06	kernel: pcib18: <acpi pci-pci="" bridge="">at device 22.7 on pci0
Feb 5 11:25:06	kernel: pci18: <acpi pci="" bus="">on pcib18
Feb 5 11:25:06	kernel: pcib19: <acpi pci-pci="" bridge="">at device 23.0 on pci0
Feb 5 11:25:06	kernel: pci19: <acpi pci="" bus="">on pcib19
Feb 5 11:25:06	kernel: pcib20: <acpi pci-pci="" bridge="">at device 23.1 on pci0
Feb 5 11:25:06	kernel: pci20: <acpi pci="" bus="">on pcib20
Feb 5 11:25:06	kernel: pcib21: <acpi pci-pci="" bridge="">at device 23.2 on pci0
Feb 5 11:25:06	kernel: pci21: <acpi pci="" bus="">on pcib21
Feb 5 11:25:06	kernel: pcib22: <acpi pci-pci="" bridge="">at device 23.3 on pci0
Feb 5 11:25:06	kernel: pci22: <acpi pci="" bus="">on pcib22
Feb 5 11:25:06	kernel: pcib23: <acpi pci-pci="" bridge="">at device 23.4 on pci0
Feb 5 11:25:06	kernel: pci23: <acpi pci="" bus="">on pcib23
Feb 5 11:25:06	kernel: pcib24: <acpi pci-pci="" bridge="">at device 23.5 on pci0
Feb 5 11:25:06	kernel: pci24: <acpi pci="" bus="">on pcib24
Feb 5 11:25:06	kernel: pcib25: <acpi pci-pci="" bridge="">at device 23.6 on pci0
Feb 5 11:25:06	kernel: pci25: <acpi pci="" bus="">on pcib25
Feb 5 11:25:06	kernel: pcib26: <acpi pci-pci="" bridge="">at device 23.7 on pci0
Feb 5 11:25:06	kernel: pci26: <acpi pci="" bus="">on pcib26
Feb 5 11:25:06	kernel: pcib27: <acpi pci-pci="" bridge="">at device 24.0 on pci0
Feb 5 11:25:06	kernel: pci27: <acpi pci="" bus="">on pcib27
Feb 5 11:25:06	kernel: pcib28: <acpi pci-pci="" bridge="">at device 24.1 on pci0
Feb 5 11:25:06	kernel: pci28: <acpi pci="" bus="">on pcib28
Feb 5 11:25:06	kernel: pcib29: <acpi pci-pci="" bridge="">at device 24.2 on pci0
Feb 5 11:25:06	kernel: pci29: <acpi pci="" bus="">on pcib29
Feb 5 11:25:06	kernel: pcib30: <acpi pci-pci="" bridge="">at device 24.3 on pci0
Feb 5 11:25:06	kernel: pci30: <acpi pci="" bus="">on pcib30
Feb 5 11:25:06	kernel: pcib31: <acpi pci-pci="" bridge="">at device 24.4 on pci0
Feb 5 11:25:06	kernel: pci31: <acpi pci="" bus="">on pcib31
Feb 5 11:25:06	kernel: pcib32: <acpi pci-pci="" bridge="">at device 24.5 on pci0
Feb 5 11:25:06	kernel: pci32: <acpi pci="" bus="">on pcib32
Feb 5 11:25:06	kernel: pcib33: <acpi pci-pci="" bridge="">at device 24.6 on pci0
Feb 5 11:25:06	kernel: pci33: <acpi pci="" bus="">on pcib33
Feb 5 11:25:06	kernel: pcib34: <acpi pci-pci="" bridge="">at device 24.7 on pci0
Feb 5 11:25:06	kernel: pci34: <acpi pci="" bus="">on pcib34
Feb 5 11:25:06	kernel: acpi_acad0: <ac adapter="">on acpi0
Feb 5 11:25:06	kernel: atrtc0: <at realtime="" clock="">port 0x70-0x71 irq 8 on acpi0
Feb 5 11:25:06	kernel: atkbdc0: <keyboard controller="" (i8042)="">port 0x60,0x64 irq 1 on acpi0
Feb 5 11:25:06	kernel: atkbd0: <at keyboard="">irq 1 on atkbdc0
Feb 5 11:25:06	kernel: kbd0 at atkbd0
Feb 5 11:25:06	kernel: atkbd0: [GIANT-LOCKED]
Feb 5 11:25:06	kernel: atkbd0: [ITHREAD]
Feb 5 11:25:06	kernel: psm0: <ps 2="" mouse="">irq 12 on atkbdc0
Feb 5 11:25:06	kernel: psm0: [GIANT-LOCKED]
Feb 5 11:25:06	kernel: psm0: [ITHREAD]
Feb 5 11:25:06	kernel: psm0: model IntelliMouse, device ID 3
Feb 5 11:25:06	kernel: ppc0: <parallel port="">port 0x378-0x37f irq 7 on acpi0
Feb 5 11:25:06	kernel: ppc0: Generic chipset (NIBBLE-only) in COMPATIBLE mode
Feb 5 11:25:06	kernel: ppc0: [ITHREAD]
Feb 5 11:25:06	kernel: ppbus0: <parallel port="" bus="">on ppc0
Feb 5 11:25:06	kernel: plip0: <plip network="" interface="">on ppbus0
Feb 5 11:25:06	kernel: plip0: [ITHREAD]
Feb 5 11:25:06	kernel: lpt0: <printer>on ppbus0
Feb 5 11:25:06	kernel: lpt0: [ITHREAD]
Feb 5 11:25:06	kernel: lpt0: Interrupt-driven port
Feb 5 11:25:06	kernel: ppi0: <parallel i="" o="">on ppbus0
Feb 5 11:25:06	kernel: uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
Feb 5 11:25:06	kernel: uart0: [FILTER]
Feb 5 11:25:06	kernel: uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
Feb 5 11:25:06	kernel: uart1: [FILTER]
Feb 5 11:25:06	kernel: fdc0: <floppy drive="" controller="">port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
Feb 5 11:25:06	kernel: fdc0: [FILTER]
Feb 5 11:25:06	kernel: fd0: <1440-KB 3.5" drive> on fdc0 drive 0
Feb 5 11:25:06	kernel: pmtimer0 on isa0
Feb 5 11:25:06	kernel: orm0: <isa option="" roms="">at iomem 0xc0000-0xc7fff,0xc8000-0xc8fff,0xc9000-0xc9fff,0xdc000-0xdffff,0xe0000-0xe7fff pnpid ORM0000 on isa0
Feb 5 11:25:06	kernel: sc0: <system console="">at flags 0x100 on isa0
Feb 5 11:25:06	kernel: sc0: VGA <16 virtual consoles, flags=0x300>
Feb 5 11:25:06	kernel: vga0: <generic isa="" vga="">at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
Feb 5 11:25:06	kernel: acpi_throttle0: <acpi cpu="" throttling="">on cpu0
Feb 5 11:25:06	kernel: Timecounter "TSC" frequency 2488273863 Hz quality 800
Feb 5 11:25:06	kernel: Timecounters tick every 10.000 msec
Feb 5 11:25:06	kernel: IPsec: Initialized Security Association Processing.
Feb 5 11:25:06	kernel: ad0: 20480MB <vmware virtual="" ide="" hard="" drive="" 00000001="">at ata0-master UDMA33
Feb 5 11:25:06	kernel: acd0: DVDR <vmware virtual="" ide="" cdrom="" drive="" 00000001="">at ata1-master UDMA33
Feb 5 11:25:06	kernel: Trying to mount root from ufs:/dev/ad0s1a
Feb 5 11:25:06	kernel: ad0: FAILURE - SETFEATURES 0x85 status=41 <ready,error>error=4 <aborted>Feb 5 11:25:07	dhclient: PREINIT
Feb 5 11:25:07	dhclient: Starting delete_old_states()
Feb 5 11:25:07	dhclient: Comparing IPs: Old: New:
Feb 5 11:25:07	dhclient: Comparing Routers: Old: New:
Feb 5 11:25:07	dhclient[6557]: DHCPREQUEST on em0 to 255.255.255.255 port 67
Feb 5 11:25:07	dhclient[6557]: DHCPACK from 192.168.86.254
Feb 5 11:25:07	dhclient: REBOOT
Feb 5 11:25:07	dhclient: Starting delete_old_states()
Feb 5 11:25:07	dhclient: Comparing IPs: Old: New: 192.168.86.132
Feb 5 11:25:07	dhclient: Comparing Routers: Old: New: 192.168.86.2
Feb 5 11:25:07	dhclient: Removing states through old gateway '' (new gateway '192.168.86.2')
Feb 5 11:25:07	dhclient: Starting add_new_address()
Feb 5 11:25:08	dhclient: ifconfig em0 inet 192.168.86.132 netmask 255.255.255.0 broadcast 192.168.86.255
Feb 5 11:25:08	dhclient: New IP Address (em0): 192.168.86.132
Feb 5 11:25:08	dhclient: New Subnet Mask (em0): 255.255.255.0
Feb 5 11:25:08	dhclient: New Broadcast Address (em0): 192.168.86.255
Feb 5 11:25:08	dhclient: New Routers (em0): 192.168.86.2
Feb 5 11:25:08	dhclient: Adding new routes to interface: em0
Feb 5 11:25:08	dhclient: /sbin/route add default 192.168.86.2
Feb 5 11:25:08	dhclient: Creating resolv.conf
Feb 5 11:25:08	dhclient[6557]: bound to 192.168.86.132 -- renewal in 900 seconds.
Feb 5 11:25:08	php: : Accept router advertisements on interface em0
Feb 5 11:25:08	dhcp6c[14467]: dhcp6_ctl_authinit: failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
Feb 5 11:25:08	dhcp6c[14467]: client6_init: failed initialize control message authentication
Feb 5 11:25:08	dhcp6c[14467]: client6_init: skip opening control port
Feb 5 11:25:08	check_reload_status: rc.newwanip starting em0
Feb 5 11:25:09	dhcp6c[14558]: client6_send: transmit failed: Can't assign requested address
Feb 5 11:25:11	php: : rc.newwanip: Informational is starting em0.
Feb 5 11:25:11	php: : rc.newwanip: on (IP address: 192.168.86.132) (interface: wan) (real interface: em0).
Feb 5 11:25:11	php: : ROUTING: setting default route to 83.145.208.254
Feb 5 11:25:11	php: : The command '/sbin/route change -inet default '83.145.208.254'' returned exit code '1', the output was 'route: writing to routing socket: Network is unreachable route: writing to routing socket: Network is unreachable change net default: gateway 83.145.208.254: Network is unreachable'
Feb 5 11:25:12	check_reload_status: Reloading filter
Feb 5 11:25:15	kernel: pflog0: promiscuous mode enabled
Feb 5 11:25:18	php: : Resyncing OpenVPN instances for interface WAN.
Feb 5 11:25:18	kernel: tun1: changing name to 'ovpns1'
Feb 5 11:25:18	kernel: ovpns1: link state changed to UP
Feb 5 11:25:18	check_reload_status: rc.newwanip starting ovpns1
Feb 5 11:25:20	php: : Resyncing OpenVPN instances.
Feb 5 11:25:20	dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
Feb 5 11:25:20	kernel: ovpns1: link state changed to DOWN
Feb 5 11:25:20	kernel: ovpns1: link state changed to UP
Feb 5 11:25:21	php: : rc.newwanip: Informational is starting ovpns1.
Feb 5 11:25:21	php: : rc.newwanip: on (IP address: 192.168.37.201) (interface: ) (real interface: ovpns1).
Feb 5 11:25:21	php: : pfSense package system has detected an ip change -> ... Restarting packages.
Feb 5 11:25:21	check_reload_status: Starting packages
Feb 5 11:25:23	php: : ROUTING: setting default route to 83.145.208.254
Feb 5 11:25:23	php: : The command '/sbin/route change -inet default '83.145.208.254'' returned exit code '1', the output was 'route: writing to routing socket: Network is unreachable route: writing to routing socket: Network is unreachable change net default: gateway 83.145.208.254: Network is unreachable'
Feb 5 11:25:23	dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
Feb 5 11:25:23	dhcpleases: kqueue error: unkown
Feb 5 11:25:23	check_reload_status: Updating all dyndns
Feb 5 11:25:24	php: : Restarting/Starting all packages.
Feb 5 11:25:26	check_reload_status: Restarting ipsec tunnels
Feb 5 11:25:27	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:27	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:28	php: : Creating rrd update script
Feb 5 11:25:28	php: : miniupnpd: Starting service on interface: lan
Feb 5 11:25:28	miniupnpd[71662]: HTTP listening on port 2189
Feb 5 11:25:28	miniupnpd[71662]: Listening for NAT-PMP traffic on port 5351
Feb 5 11:25:29	php: : Restarting/Starting all packages.
Feb 5 11:25:29	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:31	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:31	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:32	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:33	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:34	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:36	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:37	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:38	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:39	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:40	radiusd[47567]: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Feb 5 11:25:40	radiusd[47567]: rlm_sql (sql): Attempting to connect to radius@192.168.10.10:3306/radius
Feb 5 11:25:40	radiusd[47567]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Feb 5 11:25:40	radiusd[47567]: rlm_sql_mysql: Starting connect to MySQL server for #0
Feb 5 11:25:40	radiusd[47567]: rlm_sql (sql): Connected new DB handle, #0
Feb 5 11:25:40	radiusd[47567]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
Feb 5 11:25:40	radiusd[47567]: rlm_sql_mysql: Starting connect to MySQL server for #1
Feb 5 11:25:40	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:41	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:43	radiusd[60380]: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Feb 5 11:25:43	radiusd[60380]: rlm_sql (sql): Attempting to connect to radius@192.168.10.10:3306/radius
Feb 5 11:25:43	radiusd[60380]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Feb 5 11:25:43	radiusd[60380]: rlm_sql_mysql: Starting connect to MySQL server for #0
Feb 5 11:25:43	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:44	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:45	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Attempting to connect to radius@192.168.10.10:3306/radius
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Feb 5 11:25:46	radiusd[75792]: rlm_sql_mysql: Starting connect to MySQL server for #0
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Connected new DB handle, #0
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
Feb 5 11:25:46	radiusd[75792]: rlm_sql_mysql: Starting connect to MySQL server for #1
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Connected new DB handle, #1
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
Feb 5 11:25:46	radiusd[75792]: rlm_sql_mysql: Starting connect to MySQL server for #2
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Connected new DB handle, #2
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
Feb 5 11:25:46	radiusd[75792]: rlm_sql_mysql: Starting connect to MySQL server for #3
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Connected new DB handle, #3
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
Feb 5 11:25:46	radiusd[75792]: rlm_sql_mysql: Starting connect to MySQL server for #4
Feb 5 11:25:46	radiusd[75792]: rlm_sql (sql): Connected new DB handle, #4
Feb 5 11:25:46	radiusd[75792]: Loaded virtual server <default>Feb 5 11:25:46	radiusd[76076]: Ready to process requests.
Feb 5 11:25:47	radiusd[76076]: Signalled to terminate
Feb 5 11:25:47	radiusd[76076]: Exiting normally.
Feb 5 11:25:47	radiusd[76076]: rlm_sql (sql): Closing sqlsocket 4
Feb 5 11:25:47	radiusd[76076]: rlm_sql (sql): Closing sqlsocket 3
Feb 5 11:25:47	radiusd[76076]: rlm_sql (sql): Closing sqlsocket 2
Feb 5 11:25:47	radiusd[76076]: rlm_sql (sql): Closing sqlsocket 1
Feb 5 11:25:47	radiusd[76076]: rlm_sql (sql): Closing sqlsocket 0
Feb 5 11:25:47	php: : The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Attempting to connect to radius@192.168.10.10:3306/radius
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
Feb 5 11:25:48	radiusd[84135]: rlm_sql_mysql: Starting connect to MySQL server for #0
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Connected new DB handle, #0
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
Feb 5 11:25:48	radiusd[84135]: rlm_sql_mysql: Starting connect to MySQL server for #1
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Connected new DB handle, #1
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
Feb 5 11:25:48	radiusd[84135]: rlm_sql_mysql: Starting connect to MySQL server for #2
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Connected new DB handle, #2
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
Feb 5 11:25:48	radiusd[84135]: rlm_sql_mysql: Starting connect to MySQL server for #3
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Connected new DB handle, #3
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
Feb 5 11:25:48	radiusd[84135]: rlm_sql_mysql: Starting connect to MySQL server for #4
Feb 5 11:25:48	radiusd[84135]: rlm_sql (sql): Connected new DB handle, #4
Feb 5 11:25:48	radiusd[84135]: Loaded virtual server <default>Feb 5 11:25:48	radiusd[84242]: Ready to process requests.
Feb 5 11:25:52	login: login on ttyv0 as root
Feb 5 11:25:52	sshlockout[91168]: sshlockout/webConfigurator v3.0 starting up
Feb 5 11:40:47	dhclient[13939]: DHCPREQUEST on em0 to 192.168.86.254 port 67
Feb 5 11:40:47	dhclient[13939]: DHCPACK from 192.168.86.254
Feb 5 11:40:47	dhclient: RENEW
Feb 5 11:40:47	dhclient: Creating resolv.conf
Feb 5 11:40:47	dhclient[13939]: bound to 192.168.86.132 -- renewal in 900 seconds.
Feb 5 11:45:39	php: /diag_logs.php: Successful login for user 'admin' from: 192.168.10.118
Feb 5 11:45:39	php: /diag_logs.php: Successful login for user 'admin' from: 192.168.10.118
Feb 5 11:48:59	check_reload_status: Syncing firewall
Feb 5 11:49:00	syslogd: exiting on signal 15
Feb 5 11:49:00	syslogd: kernel boot file is /boot/kernel/kernel
Feb 5 11:49:00	kernel: pflog0: promiscuous mode disabled</default></default></aborted></ready,error></vmware></vmware></acpi></generic></system></isa></floppy></parallel></printer></plip></parallel></parallel></ps></at></keyboard></at></ac></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></intel(r)></intel(r)></acpi></acpi></vga-compatible></bridge></ata></ata></intel></isa></pci-isa></acpi></acpi></acpi></acpi></acpi></intel></software></version></ptltd></lahf></nx,lm></sse3,ssse3,cx16,x2apic,hv></fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,dts,mmx,fxsr,sse,sse2,ss>

athurdent · Feb 5, 2013, 9:51 AM

Hmm, then you might be facing a different problem or my first entry is unrelated to remote syslogging. I always get:

syslogd: sendto: Network is unreachable

Ocid · Feb 5, 2013, 11:02 AM

Yes, it's something diffrent, because now my test server is sending events to remote syslog.

Last events from this server before today were at 2013-01-25 10:55:43, so after that time I might have abused my test server too much…

elgo · Feb 11, 2013, 3:45 PM

Hi,

I have the same problem with 2.1 (02 feb build).
My syslog server is directly attached to a static NIC of the pfsense box, not using IPv6 but it's not globally disabled. WAN link is pppoe though, if that matter.

After a fresh reboot of the pfsense box:

nothing on syslog server.
if I do some modification on the pfsense syslog parameters page and click on save, I get in remote syslog:

Feb  8 17:04:02 192.168.10.254 syslogd: restart
Feb  8 17:04:02 192.168.10.254 syslogd: kernel boot file is /boot/kernel/kernel
Feb  8 17:04:02 192.168.10.254 kernel: pflog0: promiscuous mode disabled
Feb  8 17:04:02 192.168.10.254 pf:

if I go into a shell on pfsense box, stop syslogd process and restart it, issue is fixed.

Additionnal data:

Seeing the "syslogd: sendto: Network is unreachable" message in pfsense logs.
no package installed
Config:

        <syslog><nentries>50</nentries>
                <logall><remoteserver>192.168.10.1</remoteserver>
                <remoteserver2><remoteserver3><enable><reverse><nologdefaultblock></nologdefaultblock></reverse></enable></remoteserver3></remoteserver2></logall></syslog>

jimp · Feb 11, 2013, 7:24 PM

Try editing this file on your firewall and remove the if statement and closing bracket, so it just runs system_syslogd_start(); no matter what.
See if that helps.

athurdent · Feb 12, 2013, 6:27 AM

Hi jimp,
which file should we edit?

jimp · Feb 12, 2013, 1:28 PM

Whoops there should have been a link in there.

http://redmine.pfsense.org/projects/pfsense/repository/revisions/25ed9cf8a4c1bd4155ee4e1881821b9e10501916/diff/etc/rc.bootup

athurdent · Feb 12, 2013, 3:13 PM

Fine, that works for me.

jimp · Feb 12, 2013, 4:30 PM

So that change fixes the problem?

Or you're OK with testing the change?

athurdent · Feb 12, 2013, 5:11 PM

Oh, sorry! I meant to say, the change worked for my setup (ALIX Board), it fixes the problem. And thanks for looking into this!

jimp · Feb 12, 2013, 5:22 PM

OK, I took the if statement out and updated the comment. Should be in later snapshots.