(4929) fppd.c:92:Crash handler called: 11

[gsrunion]

So I just mapped the xlights around the world show over to my layout. Things running fine till the 3:04 mark. To debug I put the sequence by itself in a playlist, ran that, and captured watched the logs. This is what I found.




2018-12-01 19:53:15 (4929) fppd.c:92:Crash handler called:  11                                                                                                         
2018-12-01 19:53:15 (4929) fppd.c:98:  /opt/fpp/src() [0x5cb34]                                                                                                       
2018-12-01 19:53:15 (4929) fppd.c:98:  /lib/arm-linux-gnueabihf/libc.so.6(__default_sa_restorer+0) [0x7531e6b0]                                                       
2018-12-01 19:53:15 (4929) fppd.c:98:  /lib/arm-linux-gnueabihf/libc.so.6(_IO_vfprintf+0xfc4) [0x753327d8]                                                             
2018-12-01 19:53:15 (4929) fppd.c:98:  /opt/fpp/src(_Z9_LogWritePciiiPKcz+0xec) [0x5e218]                                                                             
2018-12-01 19:53:15 (4929) fppd.c:98:  /opt/fpp/src(_Z7HexDumpPcPvi+0x2c0) [0x53654]                                                                                   
2018-12-01 19:53:15 (4929) fppd.c:98:  /opt/fpp/src(_Z15SendChannelDataPc+0x64) [0x35188]                                                                             
2018-12-01 19:53:15 (4929) fppd.c:98:  /opt/fpp/src(_ZN8Sequence16SendSequenceDataEv+0xc) [0x88130]                                                                   
2018-12-01 19:53:15 (4929) fppd.c:98:  /opt/fpp/src(_Z22RunChannelOutputThreadPv+0x3c8) [0x38ca0]                                                                     
2018-12-01 19:53:15 (4929) common.c:161:000000: 0c 0a 34 10 25 6e 04 05 32 02 03 32 02 03 36 01    ..4.

[gsrunion]

Am I reading this and the source correct....that it is logging that is causing the crash? One of the calls to vfprintf in LogWrite?

[gsrunion]

Sure enough...Turning off logging appears to have stopped the issue.

[CaptainMurdoch]

I'm wondering if there was a case with minimumNeededChannel being set to an invalid number.  This could have caused channelData[minimumNeededChannel] to be out of bounds.  I updated the HexDump call in the master branch to use the more verbose log string that Dan added to display the minimumNeededChannel as part of the debug log so we can see if this is the issue if it happens to someone again.

[gsrunion]

Is there an easy way for me to update to the latest master such that I can exercise the changes and maybe make the issue tell on itself? I mean I quite familiar with git but not the FPP build process so I am willing give it a go.

[dkulp]

No... I think the hex dump is finding a channel with value of either 37 (%) or 92 (\) which are both values that the logging would want to treat special.   

[dkulp]

If you go to the /developer.php page on the Pi/BBB, you can select "master" from the drop down to flip over.   


If you want to dig into the code, you can edit anything in /opt/fpp/src/ (HexDump is in common.c) and then in /opt/fpp/src, just run "make optimized" and it will rebuild.  Restart FPPD like normal and give things a try.

[CaptainMurdoch]

No... I think the hex dump is finding a channel with value of either 37 (%) or 92 (\) which are both values that the logging would want to treat special.

Could be, I don't know if I've ever run into that, but might make sense.

[andyaz]

Sure enough...Turning off logging appears to have stopped the issue.

I just had a similar issue with a virtual matrix tonight. Played fine until 3:27 and then FPPD crashed. Did this several times and always crashed at the exact same spot. I realized by the huge FPPD logs I had turned the logging on to "All". Turned off all logging and no more crash.

[gsrunion]

Sure enough...Turning off logging appears to have stopped the issue.

I just had a similar issue with a virtual matrix tonight. Played fine until 3:27 and then FPPD crashed. Did this several times and always crashed at the exact same spot. I realized by the huge FPPD logs I had turned the logging on to "All". Turned off all logging and no more crash.

Can you turn logging back on. Run that particular sequence then upload your fppd.log here? Logs can be found under content setup->file manager->logs. Last few lines of the file after the crash happens should be telling as to if it is the same issue I am having.

[gsrunion]

If you go to the /developer.php page on the Pi/BBB, you can select "master" from the drop down to flip over.   


If you want to dig into the code, you can edit anything in /opt/fpp/src/ (HexDump is in common.c) and then in /opt/fpp/src, just run "make optimized" and it will rebuild.  Restart FPPD like normal and give things a try.

Do you guys rely on logging for debugging or are there other options such as local/remote gdb?

[Babybear]

after about 3 hours of running my show last night the FPPD stopped the only way to start was a reboot  but it kept crashing. it did go away after doing a shut down and a restart 
Logs at crash

2018-12-01 10:00:52 (1194) MultiSync.cpp:1439:ProcessPingPacket()
2018-12-01 10:02:42 (1194) mediaoutput/mediaoutput.c:279:CloseMediaOutput()
2018-12-01 10:02:42 (1194) MultiSync.cpp:764:ShutdownSync()
2018-12-01 10:02:42 (1194) fppd.c:92:Crash handler called:  7
2018-12-01 10:02:42 (1194) fppd.c:98:  /opt/fpp/src() [0x5cc98]
2018-12-01 10:02:42 (1194) fppd.c:98:  /lib/arm-linux-gnueabihf/libc.so.6(__default_sa_restorer+0) [0x752bf6b0]
2018-12-01 10:04:51 (19843) log.c:220:=========================================
 
Anything as to same as you're talking about. 

[dkulp]

Do you guys rely on logging for debugging or are there other options such as local/remote gdb?

Well, if things are easily repeatable, I have on many occasions asked if an ssh port can be opened up to the device so I can get in and try things.   No one has ever taken me up on it though.  That's why for 2.5.2, I added code to try and get stack traces in the logs.   It's at least a step better than the "It just crashes" we were getting.


If I had gotten in, I would have installed gdb and run fppd in gdb until it crashed.   For the last 4 days, I've had all of my FPPD instances running in either GDB or Valgrind (within a screen instance) to see if I can  catch anything.

[Babybear]

One thing I forgot to say this remote just runs the mp4s for my show. as for the rest I wish I could help
I could easily build you a house but when it comes to coding and all this fun stuff i'm so lost. 

[jaysdisaster]

I am having the same issue when I turn logging on it causes one particular sequence to crash. but with logging is off the sequence runs fine.



2018-12-23 12:25:47 (4937) playlist/Playlist.cpp:449:Playlist::Process: spideybells, section MainPlaylist, position: 0
2018-12-23 12:25:47 (4939) channeloutput/ThreadedChannelOutputBase.cpp:230:ThreadedChannelOutputBase thread: sent: 1545596747673340, elapsed: 17252
2018-12-23 12:25:47 (4937) playlist/Playlist.cpp:449:Playlist::Process: spideybells, section MainPlaylist, position: 0
2018-12-23 12:25:47 (6662) common.c:112:Channel Data starting at channel 0: (16 bytes)
2018-12-23 12:25:47 (6662) fppd.c:92:Crash handler called:  11
2018-12-23 12:25:47 (6662) fppd.c:98:  /opt/fpp/src() [0x5ccb4]
2018-12-23 12:25:47 (6662) fppd.c:98:  /lib/arm-linux-gnueabihf/libc.so.6(__default_sa_restorer+0) [0x752956b0]
2018-12-23 12:25:47 (6662) fppd.c:98:  /lib/arm-linux-gnueabihf/libc.so.6(_IO_vfprintf+0xfc4) [0x752a97d8]
2018-12-23 12:25:47 (6662) fppd.c:98:  /opt/fpp/src(_Z9_LogWritePciiiPKcz+0xec) [0x5e398]
2018-12-23 12:25:47 (6662) fppd.c:98:  /opt/fpp/src(_Z7HexDumpPcPvi+0x314) [0x537dc]
2018-12-23 12:25:47 (6662) fppd.c:98:  /opt/fpp/src(_Z15SendChannelDataPc+0x64) [0x35228]
2018-12-23 12:25:47 (6662) fppd.c:98:  /opt/fpp/src(_ZN8Sequence16SendSequenceDataEv+0xc) [0x88778]
2018-12-23 12:25:47 (6662) fppd.c:98:  /opt/fpp/src(_Z22RunChannelOutputThreadPv+0x3c8) [0x38d40]
2018-12-23 12:25:47 (4937) playlist/Playlist.cpp:449:Playlist::Process: spideybells, section MainPlaylist, position: 0
2018-12-23 12:25:47 (6662) common.c:167:000000: 0c 58 00 00 00 00 60 c0 00 90 25 6e 00 00 1f 00    .X....`...


whats weird is it calling for alot of events I dont even have (I Have 2 set up)



2018-12-23 12:25:47 (6662) events.c:83:Unable to open Event file /home/fpp/media/events/15_15.fevt
2018-12-23 12:25:47 (6662) events.c:346:Unable to load event 15_15



2018-12-23 12:25:47 (6662) events.c:83:Unable to open Event file /home/fpp/media/events/14_14.fevt
2018-12-23 12:25:47 (6662) events.c:346:Unable to load event 14_14


and on and on