Project

General

Profile

Bug #7391

(syslog-ng), uid 0: exited on signal 6 (core dumped)

Added by Roger Wilco almost 6 years ago. Updated over 3 years ago.

Status:
Closed: Duplicate
Priority:
Nice to have
Assignee:
Josh Paetzel
Category:
Middleware
Target version:
Severity:
New
Reason for Closing:
Reason for Blocked:
Needs QA:
Yes
Needs Doc:
Yes
Needs Merging:
Yes
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:

FreeBSD 9.3-RELEASE-p28 #0 r288272+f229c79: Sat Dec 12 11:58:01 PST 2015
SuperMicro X10SL7-F, i3-4330, 16 GB RAM
Intel(R) Core(TM) i3-4330 CPU @ 3.50GHz

igb0: <Intel(R) PRO/1000 Network Connection version - 2.4.0> port 0xc000-0xc01f mem 0xf7500000-0xf757ffff,0xf7580000-0xf7583fff irq 18 at device 0.0 on pci5
igb1: <Intel(R) PRO/1000 Network Connection version - 2.4.0> port 0xb000-0xb01f mem 0xf7400000-0xf747ffff,0xf7480000-0xf7483fff irq 19 at device 0.0 on pci6
em0: <Intel(R) PRO/1000 Network Connection 7.4.2> port 0xa020-0xa03f mem 0xf7360000-0xf737ffff,0xf7340000-0xf735ffff irq 16 at device 0.0 on pci7
em1: <Intel(R) PRO/1000 Network Connection 7.4.2> port 0xa000-0xa01f mem 0xf7320000-0xf733ffff,0xf7300000-0xf731ffff irq 17 at device 0.1 on pci7
mps0: <Avago Technologies (LSI) SAS2308> (onboard)

ChangeLog Required:
No

Description

Hi,

since the update to FreeNAS-9.3-STABLE-201412312006 there seems to be an issue with syslog-ng (at least I haven't spotted it before, and I've updated to 201412312006 just today).
The issue is reproducible here.

I have a fresh 9.3 installation (not updated from 9.2) with updates till 201412312006. It's still a test installation without any data.
From my point of view the only "dirty" thing is dnsmasq in a jail, so that there is no name resolution during startup, until the jail is up and running.

I have rebooted the box a few times today and after a reboot I saw the (syslog-ng), uid 0: exited on signal 6 (core dumped) message in the console (i.e. on start up).
I rebooted the box again, and the massage appeared on shutdown.
Rebooted again, and the message appeared on startup...

Here an excerpt from the logs when it happened during shutdown:

Jan  5 01:23:40 freenas01 notifier: shutdown: [pid 23359]
Jan  5 01:23:40 freenas01 notifier: Shutdown NOW!
Jan  5 01:23:40 freenas01 shutdown: reboot by root: 
Jan  5 01:23:42 freenas01 notifier: Shutdown NOW!
Jan  5 01:23:42 freenas01 notifier: 
Jan  5 01:23:42 freenas01 notifier: System shutdown time has arrived^G^G
Jan  5 01:23:43 freenas01 kernel: epair0a: link state changed to DOWN
Jan  5 01:23:43 freenas01 kernel: epair0a: link state changed to DOWN
Jan  5 01:23:43 freenas01 kernel: epair0b: link state changed to DOWN
Jan  5 01:23:43 freenas01 kernel: epair0b: link state changed to DOWN
Jan  5 01:23:43 freenas01 kernel: bridge0: link state changed to DOWN
Jan  5 01:23:43 freenas01 kernel: bridge0: link state changed to DOWN
Jan  5 01:23:43 freenas01 kernel: bge0: promiscuous mode disabled
Jan  5 01:23:46 freenas01 kernel: ifa_del_loopback_route: deletion failed
Jan  5 01:23:46 freenas01 Freed UMA keg (udp_inpcb) was not empty (20 items).  Lost 2 pages of memory.
Jan  5 01:23:46 freenas01 Freed UMA keg (udpcb) was not empty (336 items).  Lost 2 pages of memory.
Jan  5 01:23:46 freenas01 Freed UMA keg (tcp_inpcb) was not empty (10 items).  Lost 1 pages of memory.
Jan  5 01:23:46 freenas01 Freed UMA keg (tcpcb) was not empty (4 items).  Lost 1 pages of memory.
Jan  5 01:23:46 freenas01 hhook_vnet_uninit: hhook_head type=1, id=1 cleanup required
Jan  5 01:23:46 freenas01 hhook_vnet_uninit: hhook_head type=1, id=0 cleanup required
Jan  5 01:23:46 freenas01 afpd[2658]: AFP Server shutting down
Jan  5 01:23:46 freenas01 cnid_metad[2659]: shutting down on SIGTERM
Jan  5 01:23:46 freenas01 netatalk[2643]: Netatalk AFP server exiting
Jan  5 01:23:46 freenas01 smbd[22993]: dnssd_clientstub DNSServiceProcessResult called with DNSServiceRef with no ProcessReply function
Jan  5 01:23:48 freenas01 syslog-ng[24036]: syslog-ng starting up; version='3.5.6'
Jan  5 01:23:48 freenas01 kernel: pid 1746 (syslog-ng), uid 0: exited on signal 6 (core dumped)
Jan  5 01:23:48 freenas01 ntpd[2082]: ntpd exiting on signal 15
Jan  5 01:23:49 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:23:49 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:23:49 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:23:50 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:23:50 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:23:50 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:23:51 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:23:51 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:23:51 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:23:52 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:7 Err:-1 Errno:61 Connection refused
Jan  5 01:23:52 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:4 Err:-1 Errno:61 Connection refused
Jan  5 01:23:52 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:8 Err:-1 Errno:61 Connection refused
Jan  5 01:23:55 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:23:55 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:23:55 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:23:56 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:23:56 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:23:56 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:23:57 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:23:57 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:23:57 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:23:58 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:7 Err:-1 Errno:61 Connection refused
Jan  5 01:23:58 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:8 Err:-1 Errno:61 Connection refused
Jan  5 01:23:58 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:4 Err:-1 Errno:61 Connection refused
Jan  5 01:24:01 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:24:01 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:24:01 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan  5 01:24:02 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:24:02 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:24:02 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan  5 01:24:03 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:24:03 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:24:03 freenas01 python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan  5 01:24:04 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:7 Err:-1 Errno:61 Connection refused
Jan  5 01:24:04 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:8 Err:-1 Errno:61 Connection refused
Jan  5 01:24:04 freenas01 python: dnssd_clientstub ConnectToServer: connect() failed Socket:4 Err:-1 Errno:61 Connection refused
Jan  5 01:24:06 freenas01 syslog-ng[24036]: syslog-ng shutting down; version='3.5.6'
Jan  5 01:28:07 freenas01 syslog-ng[1746]: syslog-ng starting up; version='3.5.6'
Jan  5 01:28:07 freenas01 Copyright (c) 1992-2014 The FreeBSD Project.
Jan  5 01:28:07 freenas01 Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
Jan  5 01:28:07 freenas01       The Regents of the University of California. All rights reserved.
Jan  5 01:28:07 freenas01 FreeBSD is a registered trademark of The FreeBSD Foundation.
Jan  5 01:28:07 freenas01 FreeBSD 9.3-RELEASE-p5 #1 r275790+7b75f75: Tue Dec 30 09:13:52 PST 2014

I can provide the whole /var/log/messages log file as well as the dump file. Please let me know if you need any other information....

Thanks,
Roger

Capture.PNG (33.2 KB) Capture.PNG Ted Chappell, 03/15/2015 06:15 AM
2438

Related issues

Is duplicate of FreeNAS - Bug #14983: receiving after last updateClosed: Duplicate2016-04-27

History

#1 Updated by Jordan Hubbard almost 6 years ago

  • Category set to 55
  • Assignee set to Jordan Hubbard
  • Target version set to 49

Please attach the core dump to this ticket. Not sure we'll be able to reproduce and/or fix it, but it's a start at least.

#2 Updated by Xin Li almost 6 years ago

Jordan Hubbard wrote:

Please attach the core dump to this ticket. Not sure we'll be able to reproduce and/or fix it, but it's a start at least.

I doubt there would be one: the system was shutting down at the time but it would be interesting to see if there is one saved.

My guess is that a syslogd-ng instance in jail have crashed.

#3 Updated by Jordan Hubbard almost 6 years ago

  • Status changed from Unscreened to 15

#4 Updated by Jordan Hubbard almost 6 years ago

  • Status changed from 15 to Investigation
  • Assignee changed from Jordan Hubbard to Josh Paetzel

BRB: Josh's theory is that this is a shutdown ordering problem and syslog-ng is freaking out when the system dataset is unmounted out from under it or the system is otherwise "shutdown improperly" - he has reproduced this.

#5 Updated by Roger Wilco almost 6 years ago

Hi,

do you still want the dump files? I have two of them, and can also provide the /var/log/messages file.
As the dump files were written to /var/db/system/cores I doubt that it is coming from the jail.
Unfortunately both files were created during shutdown. I do not have any created during startup (this is only visible in the log file).

#6 Updated by Josh Paetzel almost 6 years ago

Yes sir, please attach the core dumps.

#7 Updated by Roger Wilco almost 6 years ago

  • File syslog-ng.core.tar.bz added

Hi,

here are two core dumps and the logfile. The filenames contain the timestamp YYMMDD_HHMMSS so that you can reference each file in the logs.

Please let me know in case I can help you any further...

#8 Updated by Josh Paetzel almost 6 years ago

(gdb) bt
#0 0x0000000801cafd4c in thr_kill () from /lib/libc.so.7
#1 0x0000000801d4d97b in abort () from /lib/libc.so.7
#2 0x000000080087d59b in iv_fatal () from /usr/local/lib/libsyslog-ng-3.5.6.so
#3 0x00000008008807d6 in iv_time_get () from /usr/local/lib/libsyslog-ng-3.5.6.so
#4 0x000000080087f155 in iv_fd_poll_and_run () from /usr/local/lib/libsyslog-ng-3.5.6.so
#5 0x000000080087f78f in iv_main () from /usr/local/lib/libsyslog-ng-3.5.6.so
#6 0x0000000800858a37 in main_loop_run () from /usr/local/lib/libsyslog-ng-3.5.6.so
#7 0x00000000004017ce in main ()

#9 Updated by Xin Li almost 6 years ago

Josh Paetzel wrote:

(gdb) bt

Unfortunately the backtrace does not make sense: iv_time_get does not call iv_fatal at all.

I am, however, able to recover the following message from the core which seems to be related to that iv_fatal call:

iv_fd_kqueue_poll: got error 6[Device not configured] polling fd 29

So looks like __kevent_retry returned 6 (ENXIO), but it's not clear what was that file descriptor referring to.

#10 Updated by Roger Wilco almost 6 years ago

Hi,

I wasn't able to preovide a dump file for the core dump on boot.
A few minutes ago I was struggling with 7345 and booted into a previous SU. Then, after booting FreeNAS-9.3-STABLE-201412312006 again, syslog-ng dumped on boot.

Dou you want the dump file, or any other information?

#11 Updated by Dr K K almost 6 years ago

Just so everyone else is aware, I currently administer a box remotely for an associate that has this exact error on boot. syslog-ng dumps with the core dump on signal 6.

I have done basic trouble shooting. For example, is syslog-ng running after it boots? Yes. Could it be a syslog-ng in a jail? No. (This box has no jails). Is there anything telling in the messages or dmesg? No. Not that I saw.

Since nothing appears to be out of place in the system, I didn't pay much more attention to it. But I am positive this has been occurring since 9.3 was released (i.e., it's been happening since day 1 with 9.3), all of this guy's hardware is DrKK-built and hence new, and all recommended for FreeNAS (Supermicro X10, etc.)

What's strange is I have pretty much identical hardware, and I do NOT get this syslog-ng error.

Anyway, just thought I'd confirm that these users aren't PEBKACs, and I am experiencing the same message on my friend's box at boot.

#12 Updated by Jordan Hubbard almost 6 years ago

Yeah, we don't think it's PEBCAK either; Josh's current theory is that it's a race condition during shutdown - something is yanking syslog-ng's log file mount (system dataset) out from under it before it itself is shut down. The problem is benign in any case, but Josh is still investigating.

#13 Updated by Bryce M almost 6 years ago

I just noticed this same error in my console after a reboot today. Running 9.3-STABLE-201501150211

Jan 17 18:30:49 freenas syslog-ng[8448]: syslog-ng starting up; version='3.5.6'
Jan 17 18:30:49 freenas kernel: pid 1889 (syslog-ng), uid 0: exited on signal 6 (core dumped)

The reboot was dirty, as it hung for some reason (I neglected to copy the console output down, the last line or so was something along the lines of hhook_vnet_uninit hhook_head type=1 etc.).

I am running some CIFS shares and transmission and plex in their own separate jails.

#14 Updated by Bryce M almost 6 years ago

Had to reboot again today and saw that it actually happened on shutdown, where it hung the system entirely until I power cycled (you can see the system start to come back up on the last few lines of the below.

Here is the log:

Jan 18 11:52:03 freenas notifier: shutdown: [pid 68768]
Jan 18 11:52:03 freenas notifier: Shutdown NOW!
Jan 18 11:52:03 freenas shutdown: reboot by root:
Jan 18 11:52:05 freenas notifier: Shutdown NOW!
Jan 18 11:52:05 freenas notifier:
Jan 18 11:52:05 freenas notifier: System shutdown time has arrived^G^G
Jan 18 11:52:06 freenas kernel: epair0a: link state changed to DOWN
Jan 18 11:52:06 freenas kernel: epair0a: link state changed to DOWN
Jan 18 11:52:06 freenas kernel: epair0b: link state changed to DOWN
Jan 18 11:52:06 freenas kernel: epair0b: link state changed to DOWN
Jan 18 11:52:10 freenas kernel: epair1a: link state changed to DOWN
Jan 18 11:52:10 freenas kernel: epair1a: link state changed to DOWN
Jan 18 11:52:10 freenas kernel: epair1b: link state changed to DOWN
Jan 18 11:52:10 freenas kernel: epair1b: link state changed to DOWN
Jan 18 11:52:11 freenas kernel: em0: link state changed to DOWN
Jan 18 11:52:11 freenas kernel: em0: link state changed to DOWN
Jan 18 11:52:11 freenas kernel: bridge0: link state changed to DOWN
Jan 18 11:52:11 freenas kernel: bridge0: link state changed to DOWN
Jan 18 11:52:11 freenas kernel: em0: promiscuous mode disabled
Jan 18 11:52:14 freenas kernel: em0: link state changed to UP
Jan 18 11:52:14 freenas kernel: em0: link state changed to UP
Jan 18 11:52:15 freenas kernel: ifa_del_loopback_route: deletion failed
Jan 18 11:52:15 freenas Freed UMA keg (udp_inpcb) was not empty (20 items). Lost 2 pages of memory.
Jan 18 11:52:15 freenas Freed UMA keg (udpcb) was not empty (336 items). Lost 2 pages of memory.
Jan 18 11:52:15 freenas Freed UMA keg (tcptw) was not empty (100 items). Lost 2 pages of memory.
Jan 18 11:52:15 freenas Freed UMA keg (tcp_inpcb) was not empty (20 items). Lost 2 pages of memory.
Jan 18 11:52:15 freenas Freed UMA keg (tcpcb) was not empty (12 items). Lost 3 pages of memory.
Jan 18 11:52:15 freenas Freed UMA keg (ripcb) was not empty (10 items). Lost 1 pages of memory.
Jan 18 11:52:15 freenas hhook_vnet_uninit: hhook_head type=1, id=1 cleanup required
Jan 18 11:52:15 freenas hhook_vnet_uninit: hhook_head type=1, id=0 cleanup required
Jan 18 11:52:15 freenas smbd[2608]: dnssd_clientstub DNSServiceProcessResult called with DNSServiceRef with no ProcessReply function
Jan 18 11:52:16 freenas syslog-ng[70032]: syslog-ng starting up; version='3.5.6'
Jan 18 11:52:16 freenas kernel: pid 8448 (syslog-ng), uid 0: exited on signal 6 (core dumped)
Jan 18 11:52:18 freenas ntpd[2331]: ntpd exiting on signal 15
Jan 18 11:52:18 freenas python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan 18 11:52:18 freenas python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan 18 11:52:18 freenas python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Jan 18 11:52:19 freenas python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan 18 11:52:19 freenas python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan 18 11:52:19 freenas python: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan 18 11:52:19 freenas syslog-ng[70032]: syslog-ng shutting down; version='3.5.6'
Jan 18 12:33:14 freenas syslog-ng[1889]: syslog-ng starting up; version='3.5.6'
Jan 18 12:33:14 freenas Copyright (c) 1992-2014 The FreeBSD Project.

#15 Updated by Josh Paetzel almost 6 years ago

Was it actually hung on syslogd shutting down or is that just the last log message? ;)

#16 Updated by Bryce M over 5 years ago

No idea honestly, if you can give me any idea as to how to find out, I'll give it a shot...

#17 Updated by disk diddler over 5 years ago

I have deployed 9.3 this evening, imported a 9.2.1.9 backup and my pool, I too am having the same error in my log.
I am noticing no other issues with the machine and only noticed this accidentally.

If I can provide more information or log files which will assist, let me know.

#18 Updated by pollo mizzega over 5 years ago

  • File debug-freenas-20150301142421.tgz added
  • File syslog-ng.7z added

Hi all, I have noticed also this core dump right after boot. I hope the files I've uploaded may be useful.

#19 Updated by Cyber Jock over 5 years ago

There is a TrueNAS customer that had syslog crash on him on bootup with TrueNAS 9.2.1.10. Never got a chance to look into it though since other problems were being diagnosed.

#20 Updated by Ted Chappell over 5 years ago

2438

This has consistently been occurring on my box as well. All versions of 9.3 Beta and Stable (see attached screenshot).

#21 Updated by Ted Chappell over 5 years ago

vampire.miami changes in mounted filesystems:
10c10
< freenas-boot/ROOT/FreeNAS-9.3-STABLE-201503131809 / zfs rw,noatime,nfsv4acls 0 0
---

freenas-boot/ROOT/FreeNAS-9.3-STABLE-201503150158 / zfs rw,noatime,nfsv4acls 0 0

vampire.miami kernel log messages:

FreeBSD 9.3-RELEASE-p10 #0 r275790+c9242cc: Sat Mar 14 19:00:55 PDT 2015
:/tank/home/jkh/freenas/objs/os-base/amd64/tank/home/jkh/freenas/FreeBSD/src/sys/FREENAS.amd64 amd64
da0: cd0 at ata0 bus 0 scbus4 target 0 lun 0
< Patriot Memory PMAP> Removable Direct Access SCSI-6 device
Timecounter "TSC-low" frequency 1503759459 Hz quality 800
Trying to mount root from zfs:freenas-boot/ROOT/FreeNAS-9.3-STABLE-201503150158 []...
vboxdrv: fAsync=0 offMin=0x3fb offMax=0xc89
pid 1531 (syslog-ng), uid 0: exited on signal 6 (core dumped)

-- End of security output --

#22 Updated by Josh Paetzel over 5 years ago

  • Status changed from Investigation to Unscreened
  • Assignee changed from Josh Paetzel to Jordan Hubbard

#23 Updated by Jordan Hubbard over 5 years ago

  • Assignee changed from Jordan Hubbard to Suraj Ravichandran

#24 Updated by Suraj Ravichandran over 5 years ago

  • Status changed from Unscreened to Screened

#25 Updated by jeremy gonzales over 5 years ago

Hi,

I am having this same message come up on a fresh install of FreeNAS FreeBSD 9.3-RELEASE-p8 #0 r275790+4edb7b0.

I have had it come up occasionally when trying to fast forward/rewind a movie in plex. Progress bar show it starting to reload movie, then the system hangs, no FreeNAS, no PLEX. When I check the log "(syslog-ng), uid 0: exited on signal 6 (core dumped)" is the last line showing. Sometimes I have to hard cycle power, the last two times the system cycled itself and started working again after a couple of minutes.

#26 Updated by Peter C over 5 years ago

Just saw this on boot after updating to 9.3-STABLE-201506042008. I get the same backtrace as jpaetzel.

Fortunately logging still seems to be working. I just have a zombie PID corresponding to the core dump in addition to the currently active one reported by "service syslog-ng status".

#27 Updated by whorled services over 5 years ago

I am also having this issue:

Jun 21 10:40:50 nas syslog-ng5431: syslog-ng starting up; version='3.5.6'
Jun 21 10:40:50 nas kernel: <6>pid 1799 (syslog-ng), uid 0: exited on signal 6 (core dumped)

This wasn't happening, that I noticed, until I had decided to enable remote syslogging. I wasn't getting any messages at my receiving server, then saw this in the console log. After finding this bug report I see that Bryce had Plex installed. I had just installed Plex about a half hour before putting my server's ip in the syslog field.

I hadn't noticed the error after installing Plex, but I hadn't looked in the console and it may have already. I stopped the Plex plugin and rebooted freenas, but the error persisted.

I had saved a config just before installing Plex, so I uploaded it. after the reboot, no more installed plugin, no more error.

There was no change at all to my config after I saved it, other than installing Plex, and then trying to enable remote syslog. So it would seem there is some link.

Plex appears to be pretty aggressive in its behavior, perhapst it may be hanging shutdown in some way, keeping syslog-ng from terminating before its mount vanishes? But the issue persists even if the plugin is not started.

Jordon mentioned "The problem is benign in any case", which inclines me to wonder if there is some corrective measure that will allow syslog-ng to be restarted successfully? If so, some slight elaboration or a helpful clue would be sweet, as knowing how is beyond my current pay grade

HTH, thought I should take the time to add to the reports. I like to at least have console logging and can do without Plex if necessary. Unfortunately, my remote machine is still not receiving syslog messages, but that may be unrelated

FreeNAS-9.3-STABLE-201504100216
Intel(R) Dual Xeon(R) CPU E5345 @ 2.33GHz (Dell)
16353MB DELL SNP9W657CK2/4G KINGSTON ECC
IBM ServeRaid M1015 flashed IT
Intel Pro/1000 MT PCI Dual Port PWLA8492MT

#28 Updated by Dr K K over 5 years ago

So, let me add some information to this.

This has been going on for at least 6 months in some of the boxes I administer, but NOT my own.

UNTIL THIS MORNING'S SU Now, it's happening to my box. Perhaps this will help you to nail it down. Here is the relevant contextual except from the system messages:


[root@giskard] ~# tail /var/log/messages
Jun 30 06:38:24 giskard winbindd[2686]:   initialize_winbindd_cache: clearing cache and re-creating with version number 2
Jun 30 06:38:24 giskard winbindd[2686]: [2015/06/30 06:38:24.371824,  0] ../lib/util/become_daemon.c:136(daemon_ready)
Jun 30 06:38:24 giskard winbindd[2690]:   STATUS=daemon 'winbindd' finished starting up and ready to serve connectionsNo builtin backend found, trying to load plugin
Jun 30 06:38:24 giskard smbd[2683]: [2015/06/30 06:38:24.489775,  0] ../lib/util/become_daemon.c:136(daemon_ready)
Jun 30 06:38:24 giskard smbd[2683]:   STATUS=daemon 'smbd' finished starting up and ready to serve connectionswaiting for connections
Jun 30 06:38:36 giskard winbindd[6646]:   STATUS=daemon 'winbindd' finished starting up and ready to serve connectionsModule 'tdb' loaded
Jun 30 06:38:46 giskard ntpd[2387]: time reset -0.762242 s
Jun 30 06:39:08 giskard syslog-ng[7774]: syslog-ng starting up; version='3.5.6'
Jun 30 06:39:08 giskard kernel: pid 1860 (syslog-ng), uid 0: exited on signal 6 (core dumped)
Jun 30 06:40:35 giskard nmbd[2680]:   STATUS=daemon 'nmbd' finished starting up and ready to serve connectionsadded interface lo0 ip=127.0.0.1 bcast=127.255.255.255 netmask=255.0.0.0

#29 Updated by Dr K K over 5 years ago

s/except/excerpt

#30 Updated by Josh Paetzel over 5 years ago

Did it drop a core file in /var/db/system/cores?

#31 Updated by Josh Paetzel over 5 years ago

  • Status changed from Screened to Closed
  • Target version changed from 49 to Unspecified
  • Seen in changed from 9.3-RELEASE to 9.3-STABLE-201506232120

The latest software update "201506292332" has a fix for this issue. Please try upgrading to see if it resolves the problem with syslog-n bailing out.

commit cee495059107279ee9389e08b2fc800155bf94df
Author: Xin Li <>
Date: Wed Jun 10 18:13:02 2015 -0700

Use FreeBSD's pidfile(3) API instead of custom and racy implementation
shipped with syslog-ng.

#32 Updated by Dr K K over 5 years ago

Josh,

Just following up on this as you requested.

I am on the most updated SU. I rebooted the box tonight to see if I kept getting the syslog-ng core dump. Interestingly, when I shutdown the box, I did get a coredump. I have a file in /var/db/system/cores created at shutdown time. But, on reboot, I did not get a core dump on it. Here is the relevant grep out:

[root@giskard] /var/db/system/cores# cat /var/log/messages | grep syslog
Jul  3 00:00:00 giskard newsyslog[21902]: logfile turned over due to size>100K
Jul  3 00:00:00 giskard syslog-ng[7774]: Configuration reload request received, reloading configuration;
Jul  3 00:57:05 giskard syslog-ng[32258]: syslog-ng starting up; version='3.5.6'
Jul  3 00:57:05 giskard kernel: pid 7774 (syslog-ng), uid 0: exited on signal 6 (core dumped)
Jul  3 00:57:07 giskard syslog-ng[32258]: syslog-ng shutting down; version='3.5.6'
Jul  3 00:59:04 giskard syslog-ng[1860]: syslog-ng starting up; version='3.5.6'
[root@giskard] /var/db/system/cores# ll
total 20259
drwxrwxr-x  2 root  wheel         3 Dec 22  2014 ./
drwxr-xr-x  7 root  wheel        39 Jul  2 04:50 ../
-rw-------  1 root  wheel  20692992 Jul  3 00:57 syslog-ng.core

Obviously you can see the shutdown time at 00:57, and the reboot at 00:59. So, the core dump on the syslog-ng on bootup appears to be gone...but...now I'm getting one on shutdown.

Did you want this syslog-ng.core file? I mean, it is 21 MB...

#33 Updated by Josh Paetzel over 5 years ago

  • Status changed from Closed to Investigation
  • Assignee changed from Suraj Ravichandran to Josh Paetzel

Yes please.

#34 Updated by Dr K K over 5 years ago

  • File syslog-ng.zip added

OK here's the syslog-ng core file. I .zip'ed it, since it was compressible to 2% of its original size :)

#35 Updated by Josh Paetzel over 5 years ago

#0 0x0000000801ec2d4c in thr_kill () from /lib/libc.so.7
#1 0x0000000801f6097b in abort () from /lib/libc.so.7
#2 0x0000000800a9066b in iv_pending_tasks () from /usr/local/lib/libsyslog-ng-3.5.6.so
#3 0x716b5f64665f7669 in ?? ()
#4 0x6c6f705f65756575 in ?? ()
#5 0x6520746f67203a6c in ?? ()
#6 0x445b3620726f7272 in ?? ()
#7 0x6f6e206563697665 in ?? ()
#8 0x6769666e6f632074 in ?? ()
#9 0x6f70205d64657275 in ?? ()
#10 0x646620676e696c6c in ?? ()
#11 0x00007fff00313320 in ?? ()
#12 0x00007fffffff6650 in ?? ()
#13 0x0000000000000000 in ?? ()

I'll get you an image with debugging symbols so we can get a valid backtrace.

#36 Updated by whorled services over 5 years ago

I had gotten away from this after upgrading to FreeNAS-9.3-STABLE-201506162331, even with plex installed. But since the upgrade there has been a problem with the cifs shares coming up ro after a reboot or power cycle, so this morning I installed FreeNAS-9.3-STABLE-201506292130. That seems to have changed the cifs behavior, but now the syslog-ng problem is back

Jul 9 09:56:07 nas syslog-ng5521: syslog-ng starting up; version='3.5.6'
Jul 9 09:56:07 nas kernel: pid 1818 (syslog-ng), uid 0: exited on signal 6 (core dumped)

At least this time, 'service syslog-ng restart' does get it going, in my previous older version 201504100216 it would just start and immediately die again

I did make a small change, adding cifs to the syslog, trying to track down the other problem. don't know if it is related, haven't had time to test

#37 Updated by Anonymous about 5 years ago

whorled services wrote:

I had gotten away from this after upgrading to FreeNAS-9.3-STABLE-201506162331, even with plex installed. But since the upgrade there has been a problem with the cifs shares coming up ro after a reboot or power cycle, so this morning I installed FreeNAS-9.3-STABLE-201506292130. That seems to have changed the cifs behavior, but now the syslog-ng problem is back

Jul 9 09:56:07 nas syslog-ng5521: syslog-ng starting up; version='3.5.6'
Jul 9 09:56:07 nas kernel: pid 1818 (syslog-ng), uid 0: exited on signal 6 (core dumped)

At least this time, 'service syslog-ng restart' does get it going, in my previous older version 201504100216 it would just start and immediately die again

I did make a small change, adding cifs to the syslog, trying to track down the other problem. don't know if it is related, haven't had time to test

I don't know what caused this but I started getting this error today on version FreeNAS-9.3-Nightlies-201507240046

Jul 26 17:01:42 OrbitalHub syslog-ng6137: syslog-ng starting up; version='3.5.6'
Jul 26 17:01:42 OrbitalHub kernel: pid 1948 (syslog-ng), uid 0: exited on signal 6 (core dumped)

#38 Updated by Mike Stafford about 5 years ago

  • File syslog-ng.7z added

Cheradenine Zakalwe wrote:

I don't know what caused this but I started getting this error today on version FreeNAS-9.3-Nightlies-201507240046

Jul 26 17:01:42 OrbitalHub syslog-ng6137: syslog-ng starting up; version='3.5.6'
Jul 26 17:01:42 OrbitalHub kernel: pid 1948 (syslog-ng), uid 0: exited on signal 6 (core dumped)

I ran the 9.3 upgrade from 9.2.1.7 yesterday and immediately started seeing the same exit on signal 6 (core dumped) message for syslog-ng on boot. I'm not running PMS, and no user configured jails. It's pretty much a vanilla file server.

Hope this can help track it down.

FreeNAS-9.3-STABLE-201509220011
SuperMicro MBD-X9SCL+-F-O, E3-1230V2, 32 GB RAM
Intel(R) Xeon(R) CPU E3-1230 V2 @ 3.30GH
3xM1015 RAID cards flashed to IT mode
2x Intel 82574L GbE Controllers

#39 Updated by Chris McLeod almost 5 years ago

  • File syslog-ng.core added
  • Hardware Configuration updated (diff)

I have been experiencing the issue as well and have just found this bug and would like to add to it. Attached is the core dump and the please see the /var/log/messages leading up to the core. The box had rebooted on its own and this core happened on its way back up. No indication on local or syslog server what caused the inital reboot.

Jan 5 18:03:20 freenas smbd3195: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
Jan 5 18:03:21 freenas smbd3195: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
Jan 5 18:03:22 freenas smbd3195: dnssd_clientstub ConnectToServer: connect() failed Socket:33 Err:-1 Errno:2 No such file or directory
Jan 5 18:03:46 freenas nmbd3192: [2016/01/05 18:03:46.147151, 0] ../source3/nmbd/nmbd_become_lmb.c:397(become_local_master_stage2)
Jan 5 18:03:46 freenas nmbd3192: ***
Jan 5 18:03:47 freenas syslog-ng4812: syslog-ng starting up; version='3.5.6'
Jan 5 18:03:47 freenas kernel: pid 2186 (syslog-ng), uid 0: exited on signal 6 (core dumped)

FreeBSD 9.3-RELEASE-p28 #0 r288272+f229c79: Sat Dec 12 11:58:01 PST 2015
SuperMicro X10SL7-F, i3-4330, 16 GB RAM
Intel(R) Core(TM) i3-4330 CPU @ 3.50GHz
igb0: <Intel(R) PRO/1000 Network Connection version - 2.4.0> port 0xc000-0xc01f mem 0xf7500000-0xf757ffff,0xf7580000-0xf7583fff irq 18 at device 0.0 on pci5
igb1: <Intel(R) PRO/1000 Network Connection version - 2.4.0> port 0xb000-0xb01f mem 0xf7400000-0xf747ffff,0xf7480000-0xf7483fff irq 19 at device 0.0 on pci6
em0: <Intel(R) PRO/1000 Network Connection 7.4.2> port 0xa020-0xa03f mem 0xf7360000-0xf737ffff,0xf7340000-0xf735ffff irq 16 at device 0.0 on pci7
em1: <Intel(R) PRO/1000 Network Connection 7.4.2> port 0xa000-0xa01f mem 0xf7320000-0xf733ffff,0xf7300000-0xf731ffff irq 17 at device 0.1 on pci7
mps0: <Avago Technologies (LSI) SAS2308> (onboard)

#40 Updated by Jordan Hubbard over 4 years ago

BRB: Josh, didn't you eventually root cause this one? I'm wondering if there's a fix we should be trying to pursue with syslog-ng.

#41 Updated by William Grzybowski over 4 years ago

  • Is duplicate of Bug #14983: receiving after last update added

#42 Updated by Jordan Hubbard over 4 years ago

  • Status changed from Investigation to Closed: Duplicate

#43 Avatar?id=14398&size=24x24 Updated by Kris Moore over 3 years ago

  • Target version changed from Unspecified to N/A

#44 Updated by Dru Lavigne almost 3 years ago

  • File deleted (syslog-ng.core.tar.bz)

#45 Updated by Dru Lavigne almost 3 years ago

  • File deleted (debug-freenas-20150301142421.tgz)

#46 Updated by Dru Lavigne almost 3 years ago

  • File deleted (syslog-ng.7z)

#47 Updated by Dru Lavigne almost 3 years ago

  • File deleted (syslog-ng.7z)

#48 Updated by Dru Lavigne almost 3 years ago

  • File deleted (syslog-ng.core)

#49 Updated by Dru Lavigne almost 3 years ago

  • File deleted (syslog-ng.zip)

Also available in: Atom PDF