Falcon Christmas

Falcon Christmas => Falcon Player (FPP) => Topic started by: JSOrange97 on January 10, 2019, 03:11:10 PM

Title: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 10, 2019, 03:11:10 PM
Running off of latest master branch on FPP on Pi3.  Status page appears to indicate playlist running as scheduled (time looks correct, etc.) but no output from any controller.  As soon as I hit "fppd restart" button, the playlist starts over and proper output via all downstream controllers.  Any ideas?
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 10, 2019, 03:17:31 PM
It sounds like the E1.31 code disabled the controllers because it couldn't talk to the briefly.  Does this happen every reboot or just this once?
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JonB256 on January 10, 2019, 03:20:04 PM
Is this after an initial power on? I know there have been updates since my show ended 5 days ago, but I never had this problem. (Master branch)

Does it occur EVERY time a scheduled playlist starts or just on Power up/Boot?  (I didn't power down my players - they ran for 40 days straight but they did get frequent FPPD restarts because I was running Master branch and updated when I noticed a release.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 10, 2019, 03:24:31 PM
To answer both questions above - this happens only on initial power up.  I don't believe I have my timers staggered, so disabling E1.31 seems to make sense given what I am seeing.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 10, 2019, 03:30:25 PM
Does it occur EVERY time a scheduled playlist starts or just on Power up/Boot?  (I didn't power down my players - they ran for 40 days straight but they did get frequent FPPD restarts because I was running Master branch and updated when I noticed a release.
I suppose to add more detail to my setup - I shutdown and power everything off every night via timers.  Every day, the timers kick on and power up.  So what you both have described, I may be bringing up FPP too early, before the downstream controllers are powered up. 

I could confirm by shutting everything down and not turning on the controllers.  Allow the Pi to boot and wait to see if the scheduler starts, then power up the downstream controllers.  Then do the reverse (controllers first, then Pi.)
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 10, 2019, 04:04:59 PM
It sounds like the E1.31 code disabled the controllers because it couldn't talk to the briefly.  Does this happen every reboot or just this once?


I ran a test because I thought it only happened on initial power up.  Here's what happened:
1) Started with sequence running with light output.  Turned off the downstream controllers and rebooted FPP.  On reboot, confirmed the playlist was "running".  Turned on controllers and  no light output.
2) From Step 1 - E1.31 controllers powered on, rebooted pi.  Playlist "running" but no output.  Restarted fppd and got light output


Does FPP save state from its last shutdown? Does it think there are no controllers and it is disabling output, even though the controllers are indeed powered on?
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 10, 2019, 04:18:41 PM
FPP sends out blanking data when it starts, so it may be detecting the controllers down due to that send taking too long.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 10, 2019, 04:33:17 PM
FPP sends out blanking data when it starts, so it may be detecting the controllers down due to that send taking too long.
Not sure that explains the behavior of the send taking "too long" if everything else was powered up and ready prior to FPP coming online.  Also, is FPP waiting for a return acknowledgement?
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JonB256 on January 10, 2019, 09:16:34 PM
I understand (but don't, myself) the reason for removing power to E1.31 controllers, but I really don't recommend starting and stopping RasPi or BBB based controllers. Check them via web browser occasionally and maybe reboot if you think it needs it, but leave it powered.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 11, 2019, 02:51:46 PM
I understand (but don't, myself) the reason for removing power to E1.31 controllers, but I really don't recommend starting and stopping RasPi or BBB based controllers. Check them via web browser occasionally and maybe reboot if you think it needs it, but leave it powered.
I understand your point, but I look at it this way: if something isn't going to be used for 16 hours a day, and only needs to be on a known schedule, only turn it on when it needs to be on.  I have my Pi, Ethernet router/switch, and radio transmitter all on the same timer.  The E1.31 controllers are on a separate timer.  I can look at separating it all so the Pi is always running, but I have been using this setup for 3 seasons now.  Something has changed in 2.x in that what used to work fine for two years now doesn't work.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 11, 2019, 03:08:31 PM
Something has changed in 2.x in that what used to work fine for two years now doesn't work.

FPP used to keep trying to send to your E1.31 controllers even if they weren't on the network.  This would in turn bog down on the network side of the OS because FPP was trying to send hundreds of packets per second to a non-existent host which in turn caused the rest of things to back up and the lights wouldn't blink properly anymore.  In FPP v2.x, Dan updated the E1.31/DDP/Artnet code to detect if a controller goes offline and stop sending data to it.  Every so often, FPP will re-check to see if the controller is back online and resume sending it data.  If your controllers aren't being marked as 'online' after powering up after fppd starts, then that is another issue that we need to look at, but the reason for the change was to solve a problem that quite a few have experienced, even when testing, when they were sending E1.31 to a non-existent (or down) controller.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: pixelpuppy on January 11, 2019, 03:13:11 PM
I look at it this way: if something isn't going to be used for 16 hours a day, and only needs to be on a known schedule, only turn it on when it needs to be on.  I have my Pi, Ethernet router/switch, and radio transmitter all on the same timer.  The E1.31 controllers are on a separate timer.  I can look at separating it all so the Pi is always running, but I have been using this setup for 3 seasons now.  Something has changed in 2.x in that what used to work fine for two years now doesn't work.


I do the same thing and have had no issues.  I think what has changed in v2 is the the blacklisting of offline controllers.  This is actually a performance enhancement since defined unicast controllers that are offline can cause delays if FPP keeps trying to send data to them.  The other thing is FPP v2.x boots a lot faster now.  But I'm still not seeing the problems you are. 


So the question seems to be, "why does FPP think your controllers are not online when it starts up?".  You say they are on different timers, so do you have them set so the controllers come on before the FPP?   Mine are all on the same timer so they all come on at once.  But I also turn them on at least an hour before showtime.  Since FPP boots so fast now, it may be possible that I'm getting some blacklisted controllers too but FPP keeps rechecking every few minutes and will clear them from the blacklist when it detects a controller is back online.  But it does take a few minutes for this to happen.   How much time do you allow between power up and when the show starts?
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 11, 2019, 03:15:35 PM
Something has changed in 2.x in that what used to work fine for two years now doesn't work.

FPP used to keep trying to send to your E1.31 controllers even if they weren't on the network.  This would in turn bog down on the network side of the OS because FPP was trying to send hundreds of packets per second to a non-existent host which in turn caused the rest of things to back up and the lights wouldn't blink properly anymore.  In FPP v2.x, Dan updated the E1.31/DDP/Artnet code to detect if a controller goes offline and stop sending data to it.  Every so often, FPP will re-check to see if the controller is back online and resume sending it data.  If your controllers aren't being marked as 'online' after powering up after fppd starts, then that is another issue that we need to look at, but the reason for the change was to solve a problem that quite a few have experienced, even when testing, when they were sending E1.31 to a non-existent (or down) controller.


This makes sense and now that I know about it I can try and work with it.  The "every so often" may need to be understood because on days that I noticed that I needed to do an fppd restart, it would be at least 5 minutes into the show. 
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 11, 2019, 03:18:56 PM
I do the same thing and have had no issues.  I think what has changed in v2 is the the blacklisting of offline controllers.  This is actually a performance enhancement since defined unicast controllers that are offline can cause delays if FPP keeps trying to send data to them.  The other thing is FPP v2.x boots a lot faster now.  But I'm still not seeing the problems you are. 


So the question seems to be, "why does FPP think your controllers are not online when it starts up?".  You say they are on different timers, so do you have them set so the controllers come on before the FPP?   Mine are all on the same timer so they all come on at once.  But I also turn them on at least an hour before showtime.  Since FPP boots so fast now, it may be possible that I'm getting some blacklisted controllers too but FPP keeps rechecking every few minutes and will clear them from the blacklist when it detects a controller is back online.  But it does take a few minutes for this to happen.   How much time do you allow between power up and when the show starts?
The need for improvement totally makes sense.  I would turn everything on at 4:50pm for a 5:00pm show start.  Maybe that isn't enough time to recheck the blacklisted controllers.  The easy fix is to turn the controllers on at 4:45 and then the pi at 4:50.  This amount of time shouldn't be needed but if I am home I can check to see that everything is online and ready and can debug in the few minutes before show start.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 11, 2019, 03:23:46 PM
This makes sense and now that I know about it I can try and work with it.  The "every so often" may need to be understood because on days that I noticed that I needed to do an fppd restart, it would be at least 5 minutes into the show.

The 'every so often' is every 10 seconds.  I couldn't remember if it was 30 or 10, but just checked the code in UDPOutput.cpp.   If you are seeing the lights not working for 5 minutes, then that is something we need to look into.  There should be some warnings in the fppd.log file when FPP disables outputs.  Can you take a look and see if you see any?  You will need to have the 'Channel Output' Log Mask checkbox checked on the FPP Settings page or else the entries won't show.  If you see those, can you clear the fppd.log file before shutting down sometime and then after you are booted back up and the problem is occurring, grab the logs zip and post it here and we can take a look to see what fppd logged when it started up and as the playlist started playing.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 11, 2019, 03:28:49 PM
The 'every so often' is every 10 seconds.  I couldn't remember if it was 30 or 10, but just checked the code in UDPOutput.cpp.   If you are seeing the lights not working for 5 minutes, then that is something we need to look into.  There should be some warnings in the fppd.log file when FPP disables outputs.  Can you take a look and see if you see any?  You will need to have the 'Channel Output' Log Mask checkbox checked on the FPP Settings page or else the entries won't show.  If you see those, can you clear the fppd.log file before shutting down sometime and then after you are booted back up and the problem is occurring, grab the logs zip and post it here and we can take a look to see what fppd logged when it started up and as the playlist started playing.
Thanks for letting me know about the debug as this answers a question that was coming next.  :)


I will try and re-create the problem over the weekend and grab the log files.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 11, 2019, 03:41:02 PM

The 'every so often' is every 10 seconds.  I couldn't remember if it was 30 or 10, but just checked the code in UDPOutput.cpp.   If you are seeing the lights not working for 5 minutes, then that is something we need to look into.  There should be some warnings in the fppd.log file when FPP disables outputs.  Can you take a look and see if you see any?  You will need to have the 'Channel Output' Log Mask checkbox checked on the FPP Settings page or else the entries won't show.  If you see those, can you clear the fppd.log file before shutting down sometime and then after you are booted back up and the problem is occurring, grab the logs zip and post it here and we can take a look to see what fppd logged when it started up and as the playlist started playing.


The existing log is littered with these:

channeloutput/UDPOutput.cpp:191:sendmmsg() failed for UDP output (output count: -1/97   time: 0 ms) with error: 22   Invalid argument
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 11, 2019, 03:49:06 PM
The existing log is littered with these:

channeloutput/UDPOutput.cpp:191:sendmmsg() failed for UDP output (output count: -1/97   time: 0 ms) with error: 22   Invalid argument

It looks like the -1 is indicating that sendmmsg returned with the error listed.  I'm wondering if there was an error setting up the socket.  I think we need to see the fppd.log file from right after the reboot when fppd starts up and then a little later starts playing the scheduled playlist.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 11, 2019, 04:17:13 PM
It looks like the -1 is indicating that sendmmsg returned with the error listed.  I'm wondering if there was an error setting up the socket.  I think we need to see the fppd.log file from right after the reboot when fppd starts up and then a little later starts playing the scheduled playlist.


Here you go.  This represents the power on with controllers off, verify fppd running, then turn controllers on.  Waited over a minute then did "fppd restart"
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 14, 2019, 03:12:31 PM
It looks like the -1 is indicating that sendmmsg returned with the error listed.  I'm wondering if there was an error setting up the socket.  I think we need to see the fppd.log file from right after the reboot when fppd starts up and then a little later starts playing the scheduled playlist.


Here you go.  This represents the power on with controllers off, verify fppd running, then turn controllers on.  Waited over a minute then did "fppd restart"
I'm curious if anything was gleaned from the logs?  Further testing shows that it doesn't matter if the controllers are on or not.  It only works with an "fppd restart".
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 14, 2019, 03:19:45 PM
The sendmmsg() errors started right away as soon as fppd started, so it couldn't contact that controllers for some reason.

Code: [Select]
2019-01-11 18:02:48 (1204) log.c:220:=========================================
2019-01-11 18:02:48 (1204) log.c:221:FPP 2.x-126-g65152480
2019-01-11 18:02:48 (1204) log.c:222:Branch: master
2019-01-11 18:02:48 (1204) log.c:223:=========================================
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:489:universes 0:  Determined range needed 0 - 49597
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:475:LOR 1:  Determined range needed 49598 - 49613
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:527:Determined range needed 0 - 49615
2019-01-11 18:02:49 (1254) channeloutput/UDPOutput.cpp:191:sendmmsg() failed for UDP output (output count: -1/97   time: 0 ms) with error: 22   Invalid argument

I'm wondering if this is fppd starting up before the networking is fully up.  I think Dan was looking into something similar in another thread.  How comfortable are you with the command line?  We could try a test and give you a command to add to a file to force fppd startup to wait a few seconds to make sure the network has some time to spin up.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 14, 2019, 03:26:44 PM
The sendmmsg() errors started right away as soon as fppd started, so it couldn't contact that controllers for some reason.

Code: [Select]
2019-01-11 18:02:48 (1204) log.c:220:=========================================
2019-01-11 18:02:48 (1204) log.c:221:FPP 2.x-126-g65152480
2019-01-11 18:02:48 (1204) log.c:222:Branch: master
2019-01-11 18:02:48 (1204) log.c:223:=========================================
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:489:universes 0:  Determined range needed 0 - 49597
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:475:LOR 1:  Determined range needed 49598 - 49613
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:527:Determined range needed 0 - 49615
2019-01-11 18:02:49 (1254) channeloutput/UDPOutput.cpp:191:sendmmsg() failed for UDP output (output count: -1/97   time: 0 ms) with error: 22   Invalid argument

I'm wondering if this is fppd starting up before the networking is fully up.  I think Dan was looking into something similar in another thread.  How comfortable are you with the command line?  We could try a test and give you a command to add to a file to force fppd startup to wait a few seconds to make sure the network has some time to spin up.


No issue with command line.  Fire away...
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 14, 2019, 03:43:47 PM
The sendmmsg() errors started right away as soon as fppd started, so it couldn't contact that controllers for some reason.

Code: [Select]
2019-01-11 18:02:48 (1204) log.c:220:=========================================
2019-01-11 18:02:48 (1204) log.c:221:FPP 2.x-126-g65152480
2019-01-11 18:02:48 (1204) log.c:222:Branch: master
2019-01-11 18:02:48 (1204) log.c:223:=========================================
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:489:universes 0:  Determined range needed 0 - 49597
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:475:LOR 1:  Determined range needed 49598 - 49613
2019-01-11 18:02:49 (1254) channeloutput/channeloutput.c:527:Determined range needed 0 - 49615
2019-01-11 18:02:49 (1254) channeloutput/UDPOutput.cpp:191:sendmmsg() failed for UDP output (output count: -1/97   time: 0 ms) with error: 22   Invalid argument

I'm wondering if this is fppd starting up before the networking is fully up.  I think Dan was looking into something similar in another thread.  How comfortable are you with the command line?  We could try a test and give you a command to add to a file to force fppd startup to wait a few seconds to make sure the network has some time to spin up.


No issue with command line.  Fire away...


BTW - you can also assume I know how to use vi and Linux command line stuff - don't need to get too crazy specific on the step-by-step.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 14, 2019, 04:06:14 PM
No issue with command line.  Fire away...

OK.  SSH into the Pi.  You can do this via ssh on your system or via the ssh web client under the 'Help' menu.  Login with as the 'fpp' user with password 'falcon'.

Once logged in, run "sudo nano /opt/fpp/scripts/fpp_boot"

Scroll down to the bottom of the file and above the "fppd_start" line, add a new line that says "sleep 5".  That will make the script pause for 5 seconds before starting fppd.

Hit CTRL-X to save, hit 'Y' for yes, hit ENTER to use the current filename.  Then you can type 'exit' to exit and reboot the Pi via the web browser.

EDIT: I sent this before seeing your other message about vi.  So while I didn't get too detailed, it evidently was still more than you needed. :)
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 14, 2019, 04:24:27 PM
No issue with command line.  Fire away...

OK.  SSH into the Pi.  You can do this via ssh on your system or via the ssh web client under the 'Help' menu.  Login with as the 'fpp' user with password 'falcon'.

Once logged in, run "sudo nano /opt/fpp/scripts/fpp_boot"

Scroll down to the bottom of the file and above the "fppd_start" line, add a new line that says "sleep 5".  That will make the script pause for 5 seconds before starting fppd.

Hit CTRL-X to save, hit 'Y' for yes, hit ENTER to use the current filename.  Then you can type 'exit' to exit and reboot the Pi via the web browser.

EDIT: I sent this before seeing your other message about vi.  So while I didn't get too detailed, it evidently was still more than you needed. :)


Made the edit.  4x reboots and one "cold start" with good behavior.  Needs more testing, but it looks like you may be onto something with this network timing issue. 
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: pixelpuppy on January 14, 2019, 04:31:28 PM
Made the edit.  4x reboots and one "cold start" with good behavior.  Needs more testing, but it looks like you may be onto something with this network timing issue.


Not to hi-jack anything The Captain wants you to do next.... but if it were me, I'd start trying shorter SLEEP times (4,3,2,1).  1 second may be plenty but won't know unless you try  ;)
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 14, 2019, 05:07:26 PM
Checking shorter would be good.  I think this is the same we saw in another forum thread and Dan commented about the fact that we might have to slow down the startup a bit by inserting a sleep.

Iím thinking that 1 second is probably good enough and little enough not to notice.  :)

If you can test, I would start with 1 and go up if needed.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 14, 2019, 06:00:57 PM
Checking shorter would be good.  I think this is the same we saw in another forum thread and Dan commented about the fact that we might have to slow down the startup a bit by inserting a sleep.

Iím thinking that 1 second is probably good enough and little enough not to notice.  :)

If you can test, I would start with 1 and go up if needed.
Sure - i can try a 1 second delay.  If that works maybe we can try iterations of usleep   ;)
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: dkulp on January 14, 2019, 06:09:04 PM
This likely needs to be a "Startup Delay" setting of some sort...   I have seen routers and such take quite a while to startup.   Heck, my cable modem takes almost 2 minutes to boot up.  If both the Pi and the router are powered on at the same time, it can easily be a while before sending out IGMP requests and such will actually work. 

Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: CaptainMurdoch on January 14, 2019, 08:22:50 PM
I added a Boot Delay setting to the advanced settings page in master.  It defaults to zero seconds.
Title: Re: FPPD running, playlist running but no output until FPPD restart
Post by: JSOrange97 on January 16, 2019, 03:19:23 PM
I added a Boot Delay setting to the advanced settings page in master.  It defaults to zero seconds.


Testing this again tonight. It looks like 1s is about all it needs.  I see in the comment on the Advanced Settings in that it allows the network gear to fully start up - the issue can be replicated with a 0s delay on a reboot (network is already up.)