search

CasparCG / server

CasparCG Server is a Windows and Linux software used to play out professional graphics, audio and video to multiple outputs. It has been in 24/7 broadcast production since 2006. Ready-to-use downloads are available under the Releases tab https://casparcg.com.
GNU General Public License v3.0
901 stars 269 forks source link

INFO command fails sometimes (501 INFO FAILED) #528

Closed toontoet closed 7 years ago

toontoet commented 7 years ago

To monitor the status of my CasparCG instance I run a monitoring script that issues a 'INFO 1' command every 90 seconds.

Most of the time this works great. But every now and then a error '501 INFO FAILED' is returned.

I'm running CasparCG the 'a8775b634ba22e0d2fa17cfc078a47a31ee77bcb' version from the builds on Ubuntu 16.04.

Last time it happened just after a LOADBG was issued. Maybe this is related to https://github.com/CasparCG/Server/issues/515 ?

Logs at the moment of the 501:

[2017-01-02 20:24:49.716] [17247] [debug]   Executed command (0.028s): LOADBG
[2017-01-02 20:24:49.716] [17247] [info]    Sent message to 127.0.0.1:202 LOADBG OK\r\n
[2017-01-02 20:24:49.716] [17247] [trace]   Ready for a new command
[2017-01-02 20:24:50.605] [17174] [info]    async_event_server[:5250] Accepted connection from 127.0.0.1 (2 connections).
[2017-01-02 20:24:50.605] [17174] [info]    Received message from 127.0.0.1: INFO 1\r\n
[2017-01-02 20:24:50.609] [17247] [error]   Dynamic exception type: boost::bad_rational
[2017-01-02 20:24:50.609] [17247] [error]   std::exception::what: bad rational: zero denominator
[2017-01-02 20:24:50.609] [17247] [error]   Caught at (AMCPCommandQueue Channel 1 for TCP Port 5250):
[2017-01-02 20:24:50.609] [17247] [error]
[2017-01-02 20:24:50.609] [17247] [error]      bin/casparcg : std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::
__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future
_base::_Result_base::_Deleter>, void> >::_M_invoke(std::_Any_data const&) + 0x17
[2017-01-02 20:24:50.609] [17247] [error]      bin/casparcg : std::__future_base::_State_base::_M_do_set(std::function<std::unique_ptr<std::
__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>&, bool&) + 0x1e
[2017-01-02 20:24:50.609] [17247] [error]      bin/casparcg : std::packaged_task<void ()>::operator()() + 0x2c
[2017-01-02 20:24:50.609] [17247] [error]      bin/casparcg : caspar::executor::run() + 0x114
[2017-01-02 20:24:50.609] [17247] [error]
[2017-01-02 20:24:50.609] [17247] [error]   Failed to execute command:INFO
[2017-01-02 20:24:50.609] [17247] [info]    Sent message to 127.0.0.1:501 INFO FAILED\r\n
[2017-01-02 20:24:50.610] [17247] [trace]   Ready for a new command
[2017-01-02 20:24:50.610] [17174] [info]    async_event_server[:5250] Client 127.0.0.1 disconnected (1 connections).
[2017-01-02 20:24:50.610] [17174] [debug]   async_event_server[:5250] connection destroyed.
[2017-01-02 20:24:50.687] [17174] [info]    Received message from 127.0.0.1: PLAY 1-1\r\n
krzyc commented 7 years ago

Is it happening when there is paused clip loaded? If yes this is indeed duplicate of #515 and I proposed a fix in pull request #520. I have included a fix in my compilation of Caspar supporting repeat module - you can check it at https://github.com/krzyc/CasparCG-Server/releases/tag/2.1.0b1_MAV_9 (fixed binary is in patch2 archive).

toontoet commented 7 years ago

Thanks @krzyc The current clip shouldn't be paused but maybe it is. I'll have to look into this.

toontoet commented 7 years ago

Ok, it's confirmed and indeed the error appears when a clip is LOADBG'ed and an INFO is requested afterwards.

Will close this issue cause it's a duplicate of https://github.com/CasparCG/Server/issues/515 And a solution is here: https://github.com/CasparCG/Server/pull/520