Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MQTT Stop Now command sometimes overriden by schedule (restart), sometimes not #1215

Open
stromnet opened this issue Dec 20, 2021 · 1 comment
Labels

Comments

@stromnet
Copy link

Please answer the following:

FPP Version and Hardware:
5.x-master-644-g467e93f1 on docker

Describe the bug and Steps to reproduce:

  1. Setup simple playlist with 1 item
  2. Setup simple scheduled with 1 sequence (or 1 playlist, behavior seems to be same), being active at time of test.
  3. Send MQTT set/playlists/ALLPLAYLISTS/stop/now
  4. Sometimes output fully stops
  5. Sometimes auto-restarted immediately; from logs it seems like by scheduler.

Expected behavior:
Output fully stops.
Or at least the same thing every time.
Not sure if "playlists stop now" is supposed to affect scheduled stuff?
But in any case, if I start it with playlist/${PLAYLISTNAME}/start and then Stop as above, I also get same behavior.

If using Stop Now button in UI, it seems to stop fine every time.

Additional context:
Example of stop behavior (1 scheduled sequence, not playlist):

2021-12-20 18:14:26.455 (11167) [Control] /opt/fpp/src/mqtt.cpp:544: Received Mosquitto message: ' ' on topic 'falcon/player/fpp-docker/set/playlist/ALLPLAYLISTS/stop/now'
2021-12-20 18:14:26.456 (11167) [Control] /opt/fpp/src/mqtt.cpp:627: MosquittoClient::CacheSetMessage('falcon/player/fpp-docker/set/playlist/ALLPLAYLISTS/stop/now', ' ')
2021-12-20 18:14:26.456 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/playlist/name/set'                      
2021-12-20 18:14:26.456 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/playlist/repeat/set'
2021-12-20 18:14:26.456 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/playlist/sectionPosition/set'                  
2021-12-20 18:14:26.456 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/set/command'                
2021-12-20 18:14:26.456 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/set/command/#'                                    
2021-12-20 18:14:26.457 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/set/playlist/#'                                
2021-12-20 18:14:26.457 (11167) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:1604: Playlist::MQTTHandler('ALLPLAYLISTS/stop/now', ' ') while playing 'idle-seq-withline.fseq'
2021-12-20 18:14:26.457 (11167) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:567: Playlist::StopNow(1)                  
2021-12-20 18:14:26.457 (11167) [Playlist] /opt/fpp/src/playlist/PlaylistEntrySequence.cpp:133: PlaylistEntrySequence::Stop()                         
2021-12-20 18:14:26.457 (11167) [Sequence] /opt/fpp/src/Sequence.cpp:674: CloseSequenceFile() idle-seq-withline.fseq               
2021-12-20 18:14:26.457 (11167) [Sequence] /opt/fpp/src/Sequence.cpp:656: SendBlankingData()                                                          
2021-12-20 18:14:26.463 (11167) [ChannelData] /opt/fpp/src/common.cpp:150: Channel Data starting at channel 0: (16 bytes)                              
2021-12-20 18:14:26.463 (11167) [ChannelData] /opt/fpp/src/common.cpp:205: 000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
2021-12-20 18:14:26.463 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/sequence/status'
2021-12-20 18:14:26.463 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/sequence/secondsTotal'
2021-12-20 18:14:26.464 (11167) [Playlist] /opt/fpp/src/playlist/PlaylistEntryBase.cpp:167: PlaylistEntryBase::Stop()    
2021-12-20 18:14:26.464 (11167) [Playlist] /opt/fpp/src/playlist/PlaylistEntryBase.cpp:113: PlaylistEntryBase::FinishPlay()                           
2021-12-20 18:14:26.464 (11167) [Sequence] /opt/fpp/src/Sequence.cpp:656: SendBlankingData()                                                                                                          
2021-12-20 18:14:26.469 (11167) [ChannelData] /opt/fpp/src/common.cpp:150: Channel Data starting at channel 0: (16 bytes)
2021-12-20 18:14:26.469 (11167) [ChannelData] /opt/fpp/src/common.cpp:205: 000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message 'idle' on topic 'falcon/player/fpp-docker/status'
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/name/status'   
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/section/status'
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '0' on topic 'falcon/player/fpp-docker/playlist/sectionPosition/status'
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '0' on topic 'falcon/player/fpp-docker/playlist/repeat/status'
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:198: exit playlist_callback (MQTT)                                                    
2021-12-20 18:14:26.470 (11167) [Control] /opt/fpp/src/mqtt.cpp:571: Found and Completed Callback for 'falcon/player/fpp-docker/set/playlist/#'       
2021-12-20 18:14:26.472 (11503) [ChannelData] /opt/fpp/src/common.cpp:150: Channel Data starting at channel 0: (16 bytes)                             
2021-12-20 18:14:26.472 (11503) [ChannelData] /opt/fpp/src/common.cpp:205: 000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
2021-12-20 18:14:26.522 (11503) [ChannelData] /opt/fpp/src/common.cpp:150: Channel Data starting at channel 0: (16 bytes)                             
2021-12-20 18:14:26.523 (11503) [ChannelData] /opt/fpp/src/common.cpp:205: 000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
2021-12-20 18:14:29.023 (11503) [ChannelOut] /opt/fpp/src/channeloutput/channeloutputthread.cpp:292: RunChannelOutputThread() completed               

Example of restarting behavior (same config, 1 scheduled sequence, not playlist):

2021-12-20 18:14:36.814 (11167) [Control] /opt/fpp/src/mqtt.cpp:544: Received Mosquitto message: ' ' on topic 'falcon/player/fpp-docker/set/playlist/ALLPLAYLISTS/stop/now'
2021-12-20 18:14:36.814 (11167) [Control] /opt/fpp/src/mqtt.cpp:627: MosquittoClient::CacheSetMessage('falcon/player/fpp-docker/set/playlist/ALLPLAYLISTS/stop/now', ' ')
2021-12-20 18:14:36.814 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/playlist/name/set'
2021-12-20 18:14:36.815 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/playlist/repeat/set'
2021-12-20 18:14:36.815 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/playlist/sectionPosition/set'
2021-12-20 18:14:36.815 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/set/command'
2021-12-20 18:14:36.815 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/set/command/#'
2021-12-20 18:14:36.815 (11167) [Control] /opt/fpp/src/mqtt.cpp:565: Testing Callback 'falcon/player/fpp-docker/set/playlist/#'
2021-12-20 18:14:36.815 (11167) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:1604: Playlist::MQTTHandler('ALLPLAYLISTS/stop/now', ' ') while playing 'test'
2021-12-20 18:14:36.815 (11167) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:567: Playlist::StopNow(1)
2021-12-20 18:14:36.815 (11167) [Playlist] /opt/fpp/src/playlist/PlaylistEntrySequence.cpp:133: PlaylistEntrySequence::Stop()
2021-12-20 18:14:36.815 (11167) [Sequence] /opt/fpp/src/Sequence.cpp:674: CloseSequenceFile() idle-seq-withline.fseq
2021-12-20 18:14:36.816 (11167) [Sequence] /opt/fpp/src/Sequence.cpp:656: SendBlankingData()
2021-12-20 18:14:36.821 (11167) [ChannelData] /opt/fpp/src/common.cpp:150: Channel Data starting at channel 0: (16 bytes)
2021-12-20 18:14:36.821 (11167) [ChannelData] /opt/fpp/src/common.cpp:205: 000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
2021-12-20 18:14:36.821 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/sequence/status'
2021-12-20 18:14:36.822 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/sequence/secondsTotal'
2021-12-20 18:14:36.822 (11167) [Playlist] /opt/fpp/src/playlist/PlaylistEntryBase.cpp:167: PlaylistEntryBase::Stop()
2021-12-20 18:14:36.822 (11167) [Playlist] /opt/fpp/src/playlist/PlaylistEntryBase.cpp:113: PlaylistEntryBase::FinishPlay()
2021-12-20 18:14:36.822 (11167) [Sequence] /opt/fpp/src/Sequence.cpp:656: SendBlankingData()
2021-12-20 18:14:36.824 (11166) [Schedule] /opt/fpp/src/Scheduler.cpp:127: CheckIfShouldBePlayingNow(0, -1)
2021-12-20 18:14:36.824 (11166) [Schedule] /opt/fpp/src/Scheduler.cpp:486: Checking scheduled 'Start Playlist'
2021-12-20 18:14:36.824 (11166) [Schedule] /opt/fpp/src/Scheduler.cpp:425: Mon Dec 20 15:05:27 2021:  1 'Start Playlist' - '"idle-seq-withline.fseq" "true" "false" '
2021-12-20 18:14:36.825 (11166) [Schedule] /opt/fpp/src/Scheduler.cpp:568: Starting Scheduled Playlist:
2021-12-20 18:14:36.825 (11166) [Schedule] /opt/fpp/src/Scheduler.cpp:425: Mon Dec 20 15:05:27 2021:  1 'Start Playlist' - '"idle-seq-withline.fseq" "true" "false" '
2021-12-20 18:14:36.825 (11166) [Playlist] /opt/fpp/src/Player.cpp:85: Starting repeating playlist 'idle-seq-withline.fseq' with scheduled 'Hard Stop' in 17124 seconds
2021-12-20 18:14:36.825 (11166) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:1044: Playlist::Play('idle-seq-withline.fseq', 0, 1, 1)
2021-12-20 18:14:36.827 (11167) [ChannelData] /opt/fpp/src/common.cpp:150: Channel Data starting at channel 0: (16 bytes)
2021-12-20 18:14:36.827 (11167) [ChannelData] /opt/fpp/src/common.cpp:205: 000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00    ................
2021-12-20 18:14:36.828 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message 'idle' on topic 'falcon/player/fpp-docker/status'
2021-12-20 18:14:36.828 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/name/status'
2021-12-20 18:14:36.828 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '' on topic 'falcon/player/fpp-docker/playlist/section/status'
2021-12-20 18:14:36.828 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '0' on topic 'falcon/player/fpp-docker/playlist/sectionPosition/status'
2021-12-20 18:14:36.828 (11167) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message '0' on topic 'falcon/player/fpp-docker/playlist/repeat/status'
2021-12-20 18:14:36.829 (11167) [Control] /opt/fpp/src/mqtt.cpp:198: exit playlist_callback (MQTT)
2021-12-20 18:14:36.829 (11166) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:292: Playlist::Load(idle-seq-withline.fseq)
2021-12-20 18:14:36.829 (11166) [Control] /opt/fpp/src/mqtt.cpp:377: Publishing message 'idle-seq-withline.fseq' on topic 'falcon/player/fpp-docker/playlist/name/status'
2021-12-20 18:14:36.829 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:508: Read VariableHeader: sp, length: 27 bytes
2021-12-20 18:14:36.829 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:1065:   Prepared to read/write a ZSTD compress fseq file.
2021-12-20 18:14:36.829 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:347: Sequence File Information
2021-12-20 18:14:36.829 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:348: seqFilename           : /home/fpp/media/sequences/idle-seq-withline.fseq
2021-12-20 18:14:36.829 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:349: seqVersion            : 2.1
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:350: seqChanDataOffset     : 708
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:351: seqChannelCount       : 5072
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:352: seqNumPeriods         : 909
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:353: seqStepTime           : 33ms
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:1709: Sequence File Information
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:1710: compressionType       : 1
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:1711: numBlocks             : 76
2021-12-20 18:14:36.830 (11166) [Sequence] /opt/fpp/src/fseq/FSEQFile.cpp:1716: numRanges             : 3
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:342: Generated an on-the-fly playlist for idle-seq-withline.fseq
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:156: Playlist::Load(JSON)
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:182: Loading MainPlaylist:
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/PlaylistEntryBase.cpp:44: PlaylistEntryBase::PlaylistEntryBase()
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/PlaylistEntrySequence.cpp:39: PlaylistEntrySequence::PlaylistEntrySequence()
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/PlaylistEntrySequence.cpp:51: PlaylistEntrySequence::Init()
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/PlaylistEntryBase.cpp:59: PlaylistEntryBase::Init(): 'sequence'
2021-12-20 18:14:36.830 (11166) [Playlist] /opt/fpp/src/playlist/Playlist.cpp:1169: Playlist: idle-seq-withline.fseq
@cpinkham
Copy link
Contributor

This is happening because Playlist::MQTTHandler() calls Playlist::StopNow() instead of Player::StopNow() so the Player instance doesn't know that the playlist was force stopped. For now, we may need to bubble up the Playlist::* functions up to call Player::* instead. The long-term plan would be to allow multiple playing playlists, but that is a huge change.

@darylc darylc added the bug label Jan 13, 2024
@cpinkham cpinkham added this to FPP 8.0 Jan 13, 2024
@ghormann ghormann moved this to Wishlist in FPP 8.0 Jan 13, 2024
@darylc darylc removed this from FPP 8.0 Aug 29, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants