Extron SMP352 and Opencast - Sometimes ingest fails

[marcusm7]

Issue:

For unknown reasons the SMP352 fails to ingest some recordings.
Does anyone know that behaviour and how to fix it?
I'm not sure, what causes it.

1. Events are created in Opencast
2. The SMP352 fetches them in his role as Opencast capture agent
3. The events are displayed/ listed in the recorders own scheduled event list/ recording calendar
4. The recorder starts the scheduled recording at the scheduled time
5. The recorder start to complain about failed to add entry due to schedule overlap
   ...

• No ingest is happening, re-ingest in the recorder isn't possible (invalid state of the event or recording is dissociated from the opencast event - namely the opencast uid)
• when the recording is prematurely stopped, the recorder starts another recording for the remaining time and ingests this instead of the original one

Workarounds:

• re-ingest? -> fails, because the recorder can't find the recording for the recording calendar entry or the state of the recording in the recording calendar is wrong
• fetching the recordings (via SFTP from the recorder) and manually ingesting them to Opencast is possible.
• clicking "remove future events" in the recorder seems to fix the issue. For a while.

Not yet tried:

• (net safe) factory reset and reconfiguration
• periodic "remove future event" via script (sis)
• oc index/db out of sync? https://github.com/orgs/opencast/discussions/7343#discussioncomment-15642683
• time drift between oc and smps? https://github.com/orgs/opencast/discussions/7343#discussioncomment-15648229

Details

Log Entries (smp352)

• Log-file while trying to start the same recording twice

2026-01-26T12:20:29Z, info, schd, Ingest Complete: Total Events 6, Invalid Events 1, Added Entries 5
2026-01-26T12:20:25Z, info, 743552, ICAL: Failed to add entry due to schedule overlap, start time:Mon Jan 26 10:40:00 2026

• log-file while failing to stop an already stopped recording

2026-01-22T11:36:00Z, info, undefined, Record control received command 'stop' via Schedule Ingest
2026-01-22T11:36:00Z, info, 708372, ICAL: stopping active recording on event end time change to Thu Jan 22 11:36:00 2026

episode.xml of the not-ingested recording:

• dcterms:identifier is missing
• dcterms:isPartOf is correct

Extron SMP352:

• 3.07 build 0001-b004
• Opencast-Plugin 1.00.0011

Opencast

• Opencast 17.8 – e596a54

[mtneug]

Is this happening for all CAs? This somehow reads to me like the Opencast index/DB is out of sync and you have planned events that are not correctly stored.

[marcusm7]

I will take a look into the logs. RN I can see the issue on 3 or more devices. Not sure if all SMP352 show the behaviour.

How would I verify that the the Opencast index and DB are in sync? Is rebuilding the index sufficient?

[reiferschris]

I've checked a bunch (not all) of our smps for this kind of log entry. I found two devices where this log entry came up in the last weeks. Though I couldn't find a case where this caused an issue with the recording.
In some cases there was indeed what you could call an overlap in Opencast. There are multiple instances where the end time of one recording matched the start time of the recording 17:40 for example. This was logged:

2026-01-19T16:43:31Z, info, schd, Ingest Error String: All errors categorized (location/past/overlap)
2026-01-19T16:43:31Z, info, schd, Ingest Errors: Invalid Location 0, No Location 0, Past Entries 0, Overlaps 1, Other 0
2026-01-19T16:43:31Z, info, schd, Ingest Complete: Total Events 32, Invalid Events 1, Added Entries 30
2026-01-19T16:43:27Z, info, 6408, ICAL: Failed to add entry due to schedule overlap, start time:Mon Jan 19 16:40:00 2026
2026-01-19T16:40:25Z, info, 6387, Opencast ingest started
2026-01-19T16:40:20Z, alert, 6408,  warning alert 'audio_loss' was triggered when value 'No audio' met threshold 'Audio dropped below threshold for 10 seconds during recording'
2026-01-19T16:40:07Z, info, undefined, RTMP resolved IP 134.XXX.XXX.XXX from URL rtmp://XXXXXXXXX:1935/extron/exa-105-ha1
2026-01-19T16:40:02Z, info, 6408, Recording initiated/resumed 
2026-01-19T16:40:02Z, info, 6408, Recording started 
2026-01-19T16:40:02Z, info, 6387, Recording stopped 

It's not quite like what you described. There is no stopped recording just a subsequent event that has the same start/end time. I will have to investigate how this can happen, this should have been a conflict when scheduling.

Do you have a significant drift in the times of the smp and opencast? Maybe the smp thinks it still has something to record when refetching the events from opencast? After all the smps also start recordings that should already be running according to opencast.

What does the full log for this event look like?

Log-file while trying to start the same recording twice

[reiferschris]

when the recording is prematurely stopped
Does this happen for manual stops (on purpose) or only for stops that are introduced by e.g. a reboot or power loss?

[marcusm7]

when the recording is prematurely stopped
Does this happen for manual stops (on purpose) or only for stops that are introduced by e.g. a reboot or power loss?

I know the "start a recording after reboot behaviour". But this seems different.

I have seen a case where the recorder complained about an overlap periodically as soon as the recording started. The lecturer manually stopped the recording (SIS command) after she was done with the lecture. Afterwards the recorder started the planned/ duplicate/ overlapping recording.
R512_logs_filtered_2026-01-29_duplicateRecording.md

[marcusm7]

About NTP:

• Both systems (OC and SMP352) get their time via the same NTP-servers.
• I can see NTP communication issue messages in the SMP352 log (twice in 2025-01, but both resolved and days before the incident).