Open smarquard opened 7 years ago
We don't know the underlying cause of the "Timeout getting recorder status" failed startup, but that's another issue.
This change seems to have broken the auto-recover.
Tested on a CA in idle state. Reboot the IP camera (so the rtsp connection is broken). The camera comes back online, but the CA never switches out of error state.
galicaster 2017-04-18 10:28:05,655 INFO recorder/service Starting recording service in the preview status
galicaster 2017-04-18 10:28:05,655 INFO recorder/service Using profile with name Default and path /usr/share/galicaster/conf-d ist.ini
galicaster 2017-04-18 10:28:05,655 DEBUG recorder/recorder Init bin presenter galicaster.recorder.bins.rtp
galicaster 2017-04-18 10:28:05,657 DEBUG recorder/utils Video sink: sink-presenter -> xvimagesink
galicaster 2017-04-18 10:28:05,657 DEBUG recorder/utils Audio sink: sink-audio-presenter -> alsasink
galicaster 2017-04-18 10:28:05,659 DEBUG recorder/recorder Init bin presentation galicaster.recorder.bins.blackmagic
galicaster 2017-04-18 10:28:05,660 DEBUG recorder/utils Video sink: sink-presentation -> xvimagesink
galicaster 2017-04-18 10:28:05,661 DEBUG recorder/utils Audio sink: sink-audio-presentation -> alsasink
galicaster 2017-04-18 10:28:05,698 INFO opencast/service Process ical
galicaster 2017-04-18 10:28:05,703 DEBUG recorder/recorder Init bin presentation2 galicaster.recorder.bins.blackmagic
galicaster 2017-04-18 10:28:05,703 DEBUG recorder/utils Video sink: sink-presentation2 -> xvimagesink
galicaster 2017-04-18 10:28:05,703 DEBUG recorder/utils Audio sink: sink-audio-presentation2 -> alsasink
galicaster 2017-04-18 10:28:05,709 INFO opencast/client iCal Not modified
galicaster 2017-04-18 10:28:05,734 DEBUG recorder/recorder Init bin audio galicaster.recorder.bins.pulse
galicaster 2017-04-18 10:28:05,735 DEBUG recorder/utils Audio sink: sink-audio -> alsasink
galicaster 2017-04-18 10:28:05,822 INFO opencast/service Updating series from server
galicaster 2017-04-18 10:28:05,825 DEBUG scheduler/heartbeat galicaster-notify-long in 60
galicaster 2017-04-18 10:28:15,653 DEBUG scheduler/heartbeat galicaster-notify-short in 10
galicaster 2017-04-18 10:28:15,654 INFO opencast/service Set status unknown to server
galicaster 2017-04-18 10:28:15,654 INFO opencast/client Sending state unknown
Should be tested along with #473 as these are different aspects of the error handling.
Thanks, the latest commits have fixed this issue for us. Autorecover is working correctly.
So autorecover works correctly now but there's still a timing issue with sending a status idle.
Here's an example from a CA where the IP cam is made unavailable while GC is in preview.
At 11:53:43,709 there's a "status idle" which is misleading - the CA has tried auto-recover, preview starts, then it sends idle but the error is triggered again shortly afterwards because the IP cam is not actually available.
So I would say there should be some delay after a preview starts before updating the status otherwise the "idle" here is misleading.
It's not a serious issue though so if there's no easy way to handle this correctly, we could live with the current behaviour.
galicaster 2017-04-21 11:53:33,710 INFO opencast/service Set status unknown to server
galicaster 2017-04-21 11:53:33,710 INFO opencast/client Sending state unknown
galicaster 2017-04-21 11:53:42,710 INFO recorder/service Handle recover from error
galicaster 2017-04-21 11:53:42,710 INFO recorder/service Disconnecting recover recorder callback
galicaster 2017-04-21 11:53:42,710 INFO opencast/service Process ical
galicaster 2017-04-21 11:53:42,711 DEBUG scheduler/heartbeat galicaster-notify-long in 60
galicaster 2017-04-21 11:53:42,711 INFO recorder/service Resetting recorder after reloading the profile
galicaster 2017-04-21 11:53:42,711 INFO recorder/service Starting recording service in the preview status
galicaster 2017-04-21 11:53:42,711 INFO recorder/service Using profile with name Default and path /usr/share/galicaster/conf-dist.ini
galicaster 2017-04-21 11:53:42,711 DEBUG recorder/recorder Init bin presenter galicaster.recorder.bins.rtp
galicaster 2017-04-21 11:53:42,712 DEBUG recorder/utils Video sink: sink-presenter -> xvimagesink
galicaster 2017-04-21 11:53:42,712 DEBUG recorder/utils Audio sink: sink-audio-presenter -> alsasink
galicaster 2017-04-21 11:53:42,713 DEBUG recorder/recorder Init bin presentation galicaster.recorder.bins.blackmagic
galicaster 2017-04-21 11:53:42,713 DEBUG recorder/utils Video sink: sink-presentation -> xvimagesink
galicaster 2017-04-21 11:53:42,713 DEBUG recorder/utils Audio sink: sink-audio-presentation -> alsasink
galicaster 2017-04-21 11:53:42,718 INFO opencast/client iCal Not modified
galicaster 2017-04-21 11:53:42,754 DEBUG recorder/recorder Init bin presentation2 galicaster.recorder.bins.blackmagic
galicaster 2017-04-21 11:53:42,755 DEBUG recorder/utils Video sink: sink-presentation2 -> xvimagesink
galicaster 2017-04-21 11:53:42,755 DEBUG recorder/utils Audio sink: sink-audio-presentation2 -> alsasink
galicaster 2017-04-21 11:53:42,811 INFO opencast/service Updating series from server
galicaster 2017-04-21 11:53:42,812 DEBUG recorder/recorder Init bin audio galicaster.recorder.bins.pulse
galicaster 2017-04-21 11:53:42,812 DEBUG recorder/utils Audio sink: sink-audio -> alsasink
galicaster 2017-04-21 11:53:42,818 DEBUG recorder/recorder recorder preview
galicaster 2017-04-21 11:53:43,709 DEBUG scheduler/heartbeat galicaster-notify-short in 10
galicaster 2017-04-21 11:53:43,709 INFO opencast/service Set status idle to server
galicaster 2017-04-21 11:53:43,710 INFO opencast/client Sending state idle
galicaster 2017-04-21 11:53:43,823 ERROR recorder/recorder gst-resource-error-quark: Could not open resource for reading and writing. (7) (gstrtspsrc.c(6819): gst_rtspsrc_retrieve_sdp (): /GstPipeline:galicaster_recorder/galicaster+recorder+bins+rtp+GCrtp:galicaster+recorder+bins+rtp+gcrtp7/GstBin:bin28/GstRTSPSrc:gc-rtp-src:
Failed to connect. (Generic error))
galicaster 2017-04-21 11:53:44,923 ERROR recorder/service Handle error (gst-resource-error-quark: Could not open resource for reading and writing. (7) (gstrtspsrc.c(6819): gst_rtspsrc_retrieve_sdp (): /GstPipeline:galicaster_recorder/galicaster+recorder+bins+rtp+GCrtp:galicaster+recorder+bins+rtp+gcrtp7/GstBin:bin28/GstRTSPSrc:gc-rtp-src:
Failed to connect. (Generic error)))
galicaster 2017-04-21 11:53:44,923 INFO recorder/service Connecting recover recorder callback
galicaster 2017-04-21 11:53:53,710 DEBUG scheduler/heartbeat galicaster-notify-short in 10
galicaster 2017-04-21 11:53:53,711 INFO opencast/service Set status unknown to server
galicaster 2017-04-21 11:53:53,711 INFO opencast/client Sending state unknown
In a case where galicaster does not initialize properly (or possibly some error happens and it goes into error state), the error handler can incorrectly reset the status which is set to the server to idle, so as far as Opencast is concerned, the CA is fine whereas in fact it's in a continuous error loop.
The status should not be idle here unless the CA is actually started and fully operational.
If this is a startup issue, it would be fine for the CA status to be "unknown" until it's actually started fully in which case it goes either to idle (fine) or error (can't record).