TVMosaic, TVButler, Synology -> 0 Byte recordings

TVMosaic live and recorded TV products for Desktop/NAS/Raspbery Pi
floschi
Posts: 11
Joined: Tue Aug 21, 2018 5:16 pm

TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by floschi » Tue Aug 21, 2018 5:23 pm

Hi,

I got 0 Byte recordings for some time and doing a TVMosaic restart via cronjob was fine as a workaround. But now I'm getting again these 0 Byte recs.

My setup:
Synology DS216play, DSM 6.2
TVMosaic 1.0.0-16509
TVButler USB-Stick with DVB-C

And this says the logfile (I think TVButler sleeps and won't come back when the recording starts...?):

Code: Select all

2018-Aug-20 23:19:36:   [I] device_epg_manager_t::epg_manager_thread_func. EPG scan is finished. Next scan will be at 1534821576 (in 21600 seconds)
2018-Aug-20 23:19:37:   [I] device_manager_t::idle_timer_func. Device dvb#tvbutler#0#1:1 is idle. Unloading it.
2018-Aug-20 23:19:37:   [I] CTVSStreamSource::Term. Waiting for streaming thread to stop
2018-Aug-20 23:19:37:   [I] CTVSStreamSource::Term. Streaming is stopped
2018-Aug-20 23:19:37:   [I] CTVSStreamSource::Term. Stream source is stopped
2018-Aug-20 23:19:58:   [I] stream_power_manager_t::thread_function. Device manager is idle. Enable standby
2018-Aug-20 23:19:58:   [I] power_manager::set_power_state. Standby mode is allowed
2018-Aug-20 23:40:02:   [I] recorder_engine_impl::start_active_recording. Starting recording for timer 6-6376557037165120640-1534801500 on channel 2:122000:61441:10000:53626
2018-Aug-20 23:40:02:   [I] source_manager_t::start_channel. Channel 2:122000:61441:10000:53626, priority 250
2018-Aug-20 23:40:02:   [I] source_manager_t::start_channel. Channel 2:122000:61441:10000:53626 will start on device dvb#tvbutler#0#1:1 (0)
2018-Aug-20 23:40:02:   [I] device_manager_t::add_streamer. Channel 2:122000:61441:10000:53626, device dvb#tvbutler#0#1:1, streamer id 1f78077c-8008-4b74-a459-2aabd35d98bb 
2018-Aug-20 23:40:02:   [I] device_reactor_t::create_device dvb#tvbutler#0#1:1
2018-Aug-20 23:40:02:   [I] device_manager_t::add_streamer. Adding new streamer container for channel 2:122000:61441:10000:53626 on device device dvb#tvbutler#0#1:1.
2018-Aug-20 23:40:02:   [I] tvs_plugin_collection::init. Initialized 0 plugins
2018-Aug-20 23:40:02:   [I] transponder_streamer::start_idle_timer
2018-Aug-20 23:40:02:   [I] tvs_program_streamer::tvs_program_streamer. Select program for nid 61441, tid 10000, sid 53626
2018-Aug-20 23:40:02:   [I] streamer_container_t::control_thread. Added streamer 1f78077c-8008-4b74-a459-2aabd35d98bb
2018-Aug-20 23:40:02:   [I] streamer_container_t::control_thread. First streamer was added. Start program streamer
2018-Aug-20 23:40:02:   [I] dvb_program_streamer_t::start. Starting program streamer for channel 2:122000:61441:10000:53626
2018-Aug-20 23:40:02:   [I] transponder_streamer::start_channel. Start request for channel 2:122000:61441:10000:53626
2018-Aug-20 23:40:02:   [I] transponder_streamer::stop_idle_timer
2018-Aug-20 23:40:07:   [I] recorder_engine::recordings_check_func: starting scan for non-existent recording files
2018-Aug-20 23:40:09:   [E] onetv_factory::StartDevice. Device 1:1 not found
2018-Aug-20 23:40:09:   [E] CTVSStreamSource::LoadAndInitDriver. Failed to start device path 1:1, type 2, frontend 0
2018-Aug-20 23:40:09:   [E] tune_transponder. Unable to tune transponder
2018-Aug-20 23:40:09:   [E] transponder_streamer::start_channel. Tuning stransponder for channel 2:122000:61441:10000:53626 failed
2018-Aug-20 23:40:09:   [I] transponder_streamer::start_idle_timer
2018-Aug-20 23:40:09:   [E] streamer_container_t::control_thread. program_streamer_->start() failed for streamer 1f78077c-8008-4b74-a459-2aabd35d98bb
2018-Aug-20 23:40:09:   [I] source_manager_t::start_channel. Removing device dvb#tvbutler#0#1:1 from candidates and retrying
2018-Aug-20 23:40:09:   [E] active_recording::start_recording. Start channel 2:122000:61441:10000:53626 failed
2018-Aug-20 23:40:09:   [I] device_manager_t::idle_timer_func. Device dvb#tvbutler#0#1:1 is idle. Unloading it.
2018-Aug-20 23:40:09:   [I] transponder_streamer::stop_idle_timer
2018-Aug-20 23:40:09:   [I] CTVSStreamSource::Term. Waiting for streaming thread to stop
2018-Aug-20 23:40:09:   [I] CTVSStreamSource::Term. Streaming is stopped
2018-Aug-20 23:40:09:   [I] CTVSStreamSource::Term. Stream source is stopped
2018-Aug-20 23:40:09:   [I] CTVSStreamSource::Term. Stream source is stopped
2018-Aug-20 23:40:09:   [I] recorder_engine_impl::update_wakeup_timers. Setting wakeup timer to fire at 1535406000
2018-Aug-20 23:40:09:   [I] recorder_engine_impl::update_wakeup_timers. Wakeup timer successfully set to 1535406000
2018-Aug-20 23:40:09:   [I] recorder_engine::run_active: PeekCommand: recGetCompletedRecordings
2018-Aug-20 23:40:09:   [I] recorder_engine::recordings_check_func: starting scan for deleted schedules without recordings
2018-Aug-20 23:40:09:   [I] Completing recording for timer 6-6376557037165120640-1534801500, started at 1534801500 on channel 2:122000:61441:10000:53626. Recording state 0
2018-Aug-20 23:40:09:   [I] timeline_builder::remove_timer. Timer 6-6376557037165120640-1534801500 was removed from timeline
2018-Aug-20 23:40:09:   [I] recorder_engine::run_active: PeekCommand: recGetSchedules
2018-Aug-20 23:40:09:   [I] recorder_engine::run_active: PeekCommand: recGetSchedules
2018-Aug-20 23:40:09:   [I] recorder_engine::run_active: PeekCommand: recGetCompletedRecordings
2018-Aug-20 23:40:10:   [I] transponder_streamer::idle_thread_func finished
2018-Aug-21 00:10:09:   [I] recorder_engine::recordings_check_func: starting scan for non-existent recording files
2018-Aug-21 00:10:09:   [I] recorder_engine::run_active: PeekCommand: recGetCompletedRecordings
2018-Aug-21 00:10:09:   [I] recorder_engine::recordings_check_func: starting scan for deleted schedules without recordings
2018-Aug-21 00:10:09:   [I] recorder_engine::run_active: PeekCommand: recGetSchedules
2018-Aug-21 00:40:09:   [I] recorder_engine::recordings_check_func: starting scan for non-existent recording files
2018-Aug-21 00:40:09:   [I] recorder_engine::run_active: PeekCommand: recGetCompletedRecordings
2018-Aug-21 00:40:09:   [I] recorder_engine::recordings_check_func: starting scan for deleted schedules without recordings
2018-Aug-21 00:40:09:   [I] recorder_engine::run_active: PeekCommand: recGetSchedules
What could I do?

Oberon
Posts: 1130
Joined: Thu Jan 26, 2017 8:45 am

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by Oberon » Thu Aug 23, 2018 11:55 am

First of all you need to disable "deep sleep" on your NAS (if you are using it) as TVButler drivers are not compatible with it.
If it does not help, set log level to info, reproduce the issue and attach full log files here. We will have a look.

floschi
Posts: 11
Joined: Tue Aug 21, 2018 5:16 pm

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by floschi » Thu Aug 23, 2018 7:11 pm

Thanks. According to Synology Knowledge Center I had "HDD Advanced Hibernation" activated. I disabled this and will try.

floschi
Posts: 11
Joined: Tue Aug 21, 2018 5:16 pm

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by floschi » Sat Sep 22, 2018 11:22 am

Again the 0 Byte recordings.

1st example:

Code: Select all

2018-Sep-19 21:10:03:   [I] recorder_engine_impl::start_active_recording. Starting recording for timer 7-7600379320459633998-1537384500 on channel 2:442000:61441:10008:53621
2018-Sep-19 21:10:03:   [I] source_manager_t::start_channel. Channel 2:442000:61441:10008:53621, priority 250
2018-Sep-19 21:10:03:   [I] source_manager_t::start_channel. Channel 2:442000:61441:10008:53621 will start on device dvb#tvbutler#0#1:1 (0)
2018-Sep-19 21:10:03:   [I] device_manager_t::add_streamer. Channel 2:442000:61441:10008:53621, device dvb#tvbutler#0#1:1, streamer id d3d4fbe9-924b-40a4-bf20-60e889cd21ab 
2018-Sep-19 21:10:03:   [I] device_reactor_t::create_device dvb#tvbutler#0#1:1
2018-Sep-19 21:10:03:   [I] device_manager_t::add_streamer. Adding new streamer container for channel 2:442000:61441:10008:53621 on device device dvb#tvbutler#0#1:1.
2018-Sep-19 21:10:03:   [I] tvs_plugin_collection::init. Initialized 0 plugins
2018-Sep-19 21:10:03:   [I] transponder_streamer::start_idle_timer
2018-Sep-19 21:10:03:   [I] tvs_program_streamer::tvs_program_streamer. Select program for nid 61441, tid 10008, sid 53621
2018-Sep-19 21:10:03:   [I] streamer_container_t::control_thread. Added streamer d3d4fbe9-924b-40a4-bf20-60e889cd21ab
2018-Sep-19 21:10:03:   [I] streamer_container_t::control_thread. First streamer was added. Start program streamer
2018-Sep-19 21:10:03:   [I] dvb_program_streamer_t::start. Starting program streamer for channel 2:442000:61441:10008:53621
2018-Sep-19 21:10:03:   [I] transponder_streamer::start_channel. Start request for channel 2:442000:61441:10008:53621
2018-Sep-19 21:10:03:   [I] transponder_streamer::stop_idle_timer
2018-Sep-19 21:10:10:   [E] onetv_factory::StartDevice. Device 1:1 not found
2018-Sep-19 21:10:10:   [E] CTVSStreamSource::LoadAndInitDriver. Failed to start device path 1:1, type 2, frontend 0
2018-Sep-19 21:10:10:   [E] tune_transponder. Unable to tune transponder
2018-Sep-19 21:10:10:   [E] transponder_streamer::start_channel. Tuning stransponder for channel 2:442000:61441:10008:53621 failed
2018-Sep-19 21:10:10:   [I] transponder_streamer::start_idle_timer
2018-Sep-19 21:10:10:   [E] streamer_container_t::control_thread. program_streamer_->start() failed for streamer d3d4fbe9-924b-40a4-bf20-60e889cd21ab
2018-Sep-19 21:10:10:   [I] source_manager_t::start_channel. Removing device dvb#tvbutler#0#1:1 from candidates and retrying
2018-Sep-19 21:10:10:   [E] active_recording::start_recording. Start channel 2:442000:61441:10008:53621 failed
2018-Sep-19 21:10:10:   [I] device_manager_t::idle_timer_func. Device dvb#tvbutler#0#1:1 is idle. Unloading it.
2018-Sep-19 21:10:10:   [I] recorder_engine_impl::update_wakeup_timers. Setting wakeup timer to fire at 1537467000
2018-Sep-19 21:10:10:   [I] recorder_engine_impl::update_wakeup_timers. Wakeup timer successfully set to 1537467000
2018-Sep-19 21:10:10:   [I] Completing recording for timer 7-7600379320459633998-1537384500, started at 1537384500 on channel 2:442000:61441:10008:53621. Recording state 0
2018-Sep-19 21:10:10:   [I] timeline_builder::remove_timer. Timer 7-7600379320459633998-1537384500 was removed from timeline
2018-Sep-19 21:10:10:   [I] recorder_engine::run_active: PeekCommand: recGetSchedules
2018-Sep-19 21:10:10:   [I] transponder_streamer::stop_idle_timer
2018-Sep-19 21:10:10:   [I] CTVSStreamSource::Term. Waiting for streaming thread to stop
2018-Sep-19 21:10:10:   [I] recorder_engine::run_active: PeekCommand: recGetCompletedRecordings
2018-Sep-19 21:10:10:   [I] CTVSStreamSource::Term. Streaming is stopped
2018-Sep-19 21:10:10:   [I] CTVSStreamSource::Term. Stream source is stopped
2018-Sep-19 21:10:10:   [I] CTVSStreamSource::Term. Stream source is stopped
2018-Sep-19 21:10:11:   [I] transponder_streamer::idle_thread_func finished
2nd example:

Code: Select all

2018-Sep-20 20:10:03:   [I] recorder_engine_impl::start_active_recording. Starting recording for timer 9-6376557037165120640-1537467300 on channel 2:122000:61441:10000:53626
2018-Sep-20 20:10:03:   [I] source_manager_t::start_channel. Channel 2:122000:61441:10000:53626, priority 250
2018-Sep-20 20:10:03:   [I] source_manager_t::start_channel. Channel 2:122000:61441:10000:53626 will start on device dvb#tvbutler#0#1:1 (0)
2018-Sep-20 20:10:03:   [I] device_manager_t::add_streamer. Channel 2:122000:61441:10000:53626, device dvb#tvbutler#0#1:1, streamer id 33142cf1-a2ad-4ab3-8c69-e33c1c8621f1 
2018-Sep-20 20:10:03:   [I] device_reactor_t::create_device dvb#tvbutler#0#1:1
2018-Sep-20 20:10:03:   [I] device_manager_t::add_streamer. Adding new streamer container for channel 2:122000:61441:10000:53626 on device device dvb#tvbutler#0#1:1.
2018-Sep-20 20:10:03:   [I] tvs_plugin_collection::init. Initialized 0 plugins
2018-Sep-20 20:10:03:   [I] transponder_streamer::start_idle_timer
2018-Sep-20 20:10:03:   [I] tvs_program_streamer::tvs_program_streamer. Select program for nid 61441, tid 10000, sid 53626
2018-Sep-20 20:10:03:   [I] streamer_container_t::control_thread. Added streamer 33142cf1-a2ad-4ab3-8c69-e33c1c8621f1
2018-Sep-20 20:10:03:   [I] streamer_container_t::control_thread. First streamer was added. Start program streamer
2018-Sep-20 20:10:03:   [I] dvb_program_streamer_t::start. Starting program streamer for channel 2:122000:61441:10000:53626
2018-Sep-20 20:10:03:   [I] transponder_streamer::start_channel. Start request for channel 2:122000:61441:10000:53626
2018-Sep-20 20:10:03:   [I] transponder_streamer::stop_idle_timer
2018-Sep-20 20:10:03:   [I] onetv_factory::StartDevice. Found device: 1:1
2018-Sep-20 20:10:03:   [I] CTVSStreamSource::TuneTransponder. Transponder tuning request: diseqc 0, freq 122000, modulation 0, polarization 0, symbol rate 6900000, LOF 5, LNB selection signal 0, FEC 0
2018-Sep-20 20:10:03:   [I] onetv_factory::SetTuner. Tuning request. 122000, 5, 6900000
2018-Sep-20 20:10:03:   [I] onetv_factory::GetTunerState. Signal stats: 1, 0, 255
2018-Sep-20 20:10:03:   [I] transponder_streamer::tune_transponder_impl. Signal stats: 100, 100, 1
2018-Sep-20 20:10:03:   [I] tvs_program_streamer::tuning_thread. Starting tuning thread for program 2:122000:61441:10000:53626
2018-Sep-20 20:10:03:   [I] tvs_program_streamer::SetPATScanState. Waiting for PAT...
2018-Sep-20 20:10:03:   [I] CTVSStreamSource::AddPID. Requesting PID 0, client 2:122000:61441:10000:53626
2018-Sep-20 20:10:03:   [I] CTVSStreamSource::AddPID. Requesting PID 1, client 2:122000:61441:10000:53626
2018-Sep-20 20:10:03:   [I] stream_power_manager_t::thread_function. Device manager is active. Disable standby
2018-Sep-20 20:10:03:   [I] power_manager::set_power_state. Standby mode is forbiden
2018-Sep-20 20:10:03:   [I] recorder_engine_impl::update_wakeup_timers. Setting wakeup timer to fire at 1537470600
2018-Sep-20 20:10:03:   [I] recorder_engine_impl::update_wakeup_timers. Wakeup timer successfully set to 1537470600
2018-Sep-20 20:10:08:   [I] recorder_engine::recordings_check_func: starting scan for non-existent recording files
2018-Sep-20 20:10:08:   [I] recorder_engine::run_active: PeekCommand: recGetCompletedRecordings
2018-Sep-20 20:10:08:   [I] recorder_engine::recordings_check_func: starting scan for deleted schedules without recordings
2018-Sep-20 20:10:08:   [I] recorder_engine::run_active: PeekCommand: recGetSchedules
Any ideas?

I rebooted my Synology and the last recording was fine. But this couldn't be the solution, imho.

tehax
Posts: 29
Joined: Sat Mar 24, 2018 9:10 am

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by tehax » Mon Sep 24, 2018 7:33 pm

I notice also from time to time 0 byte recordings on my windows 10 system. Will investigate in the next time.

Plantje
Posts: 61
Joined: Fri May 11, 2018 6:53 am

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by Plantje » Tue Sep 25, 2018 4:57 am

I have had 0 bytes recordings in the past. Back then it was always caused by the channel not being decrypted. Can something similar be going on here?

Oberon
Posts: 1130
Joined: Thu Jan 26, 2017 8:45 am

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by Oberon » Tue Sep 25, 2018 11:33 am

floschi wrote:
Sat Sep 22, 2018 11:22 am
Again the 0 Byte recordings.
I rebooted my Synology and the last recording was fine. But this couldn't be the solution, imho.
First of all, we need full zipped log files for a proper investigation.
From what I see - there is no stream coming in, although the signal is reported. This may be because of number of reasons - deep sleep activated, not enough power on the USB port, another high power peripheral (like USB disk) connected to the same (internal) USB hub etc.

floschi
Posts: 11
Joined: Tue Aug 21, 2018 5:16 pm

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by floschi » Tue Sep 25, 2018 2:27 pm

Hi,

OK, thanks, log file attached.
  • deep sleep activated ==> deactivated, see above
  • not enough power on the USB port ==> there are two on my synology DS216play, don't know why they shouldn't be OK
  • another high power peripheral (like USB disk) connected to the same (internal) USB hub ==> no, just this one
Thx for investigation!
Attachments
tvmosaic-log-20180921-2206.zip
(47.09 KiB) Downloaded 10 times

floschi
Posts: 11
Joined: Tue Aug 21, 2018 5:16 pm

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by floschi » Tue Sep 25, 2018 2:38 pm

Another example from yesterday, recordings at 22:10h and 23:05h are 0 Byte files.
Attachments
tvmosaic-log-20180925-1636.zip
(38.5 KiB) Downloaded 12 times

floschi
Posts: 11
Joined: Tue Aug 21, 2018 5:16 pm

Re: TVMosaic, TVButler, Synology -> 0 Byte recordings

Post by floschi » Wed Oct 03, 2018 5:05 pm

Any idea what happened and how to fix? A hardware stick and a recording software which doesn't record don't help very much...

Post Reply