342 replies to this topic

[athoik]

diff --git a/lib/dvb/frontend.cpp b/lib/dvb/frontend.cpp
index 30918be..44e9b24 100644
--- a/lib/dvb/frontend.cpp
+++ b/lib/dvb/frontend.cpp
@@ -1583,6 +1583,10 @@ int eDVBFrontend::tuneLoopInt()  // called by m_tuneTimer
                                prev->inc_use();
                        }
                }
+               else if (sec_fe != this && sec_fe->m_state == stateTuning)
+               {
+                       eDebug("[eDVBFrontend] frontend %d is in stateTuning, maybe we should delay current tune on frontend %d?", sec_fe->getDVBID(), m_dvbid);
+               }
        }

        if ( m_sec_sequence && m_sec_sequence.current() != m_sec_sequence.end() )

@Huevos, can you test above (without the solution adding 1 sec in timers).

It will not solve the problem, I expect to detect linked tuners, and display a message when another linked tuner is in Tuning state.


PS. Adding the delay in the above code, I think it will cause spinner, because tunerLoopInt seems to running on MainLoop.

So maybe we need to add SLEEP command in m_sec_sequence, instead. This will add the required delay (most probably).

[Huevos]

Ok, step one: https://github.com/H...b802c2ab477343d

<   607.254> [RecordTimer] activating state 1
<   607.255> [RecordTimer] Found enough free space to record
<   607.256> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181001 2212 - BBC One HD - Drowning in Plastic'
<   607.256> [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
<   607.257> [eDVBResourceManager] allocate channel.. 0802:0002
<   607.257> [eDVBResourceManager] available channel.. 080e:0002
<   607.257> [eDVBFrontend] opening frontend 0
<   607.260> [eDVBFrontend] (0)tune
<   607.261> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<   607.261> **** Tuning JESS
<   607.261> **** frequency_mhz: 10847
<   607.261> **** lo_mhz: 9750
<   607.261> **** T: 997
<   607.261> **** position: 0
<   607.261> **** ub: 0
<   607.261> **** mode: 0
<   607.261> **** JESS: 70 03 e5 00
<   607.261> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   607.261> [eDVBFrontend] prepare_sat System 1 Freq 10847000 Pol 1 SR 23000000 INV 2 FEC 2 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<   607.261> [eDVBFrontend] tuning to 1211 mhz
<   607.261> [eDVBChannel] OURSTATE: tuning
<   607.261> [eDVBServicePMTHandler] allocate Channel: res 0
<   607.261> [eDVBCIInterfaces] addPMTHandler 1:0:19:1B1D:802:2:11A0000:0:0:0:
<   607.261> [eDVBChannel] getDemux cap=00
<   607.261> [eDVBResourceManager] allocate demux cap=00
<   607.261> [eDVBResourceManager] allocating demux adapter=0, demux=1, source=-1 fesource=0
<   607.261> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<   607.262> [eEPGCache] saveEventToFile epg event id dea0
<   607.262> [RecordTimer] prepare ok, waiting for begin
<   607.264> [RecordTimer] activating state 1
<   607.264> [Trashcan] probing folders
<   607.266> [RecordTimer] Found enough free space to record
<   607.267> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181001 2212 - ITV London HD - New_ Strangers'
<   607.267> [Navigation] recording service: 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<   607.267> [eDVBResourceManager] allocate channel.. 0812:0002
<   607.267> [eDVBResourceManager] available channel.. 080e:0002
<   607.267> [eDVBResourceManager] available channel.. 0802:0002
<   607.267> [eDVBFrontend] opening frontend 3
<   607.270> [eDVBFrontend] (3)tune
<   607.270> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<   607.270> **** Tuning JESS
<   607.270> **** frequency_mhz: 11097
<   607.270> **** lo_mhz: 9750
<   607.270> **** T: 1247
<   607.270> **** position: 0
<   607.270> **** ub: 1
<   607.270> **** mode: 0
<   607.270> **** JESS: 70 0c df 00
<   607.270> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   607.270> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<   607.270> [eDVBFrontend] tuning to 1421 mhz
<   607.270> [eDVBChannel] OURSTATE: tuning
<   607.270> [eDVBServicePMTHandler] allocate Channel: res 0
<   607.270> [eDVBCIInterfaces] addPMTHandler 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<   607.270> [eDVBChannel] getDemux cap=00
<   607.270> [eDVBResourceManager] allocate demux cap=00
<   607.270> [eDVBResourceManager] allocating demux adapter=0, demux=2, source=-1 fesource=3
<   607.270> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<   607.272> [eEPGCache] saveEventToFile epg event id 7954
<   607.272> [RecordTimer] prepare ok, waiting for begin
<   607.273> [Trashcan] Cleanup already running
<   607.273> [RecordTimer] activating state 1
<   607.274> [RecordTimer] Found enough free space to record
<   609.966> [gRC] main thread is non-idle! display spinner!
<   610.419> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181001 2212 - Channel 5 HD - New_ Paddington Station 24_7'
<   610.419> [Navigation] recording service: 1:0:19:1E46:809:2:11A0000:0:0:0:
<   610.420> [eDVBResourceManager] allocate channel.. 0809:0002
<   610.420> [eDVBResourceManager] available channel.. 080e:0002
<   610.420> [eDVBResourceManager] available channel.. 0802:0002
<   610.420> [eDVBResourceManager] available channel.. 0812:0002
<   610.420> [eDVBFrontend] opening frontend 4
<   610.422> [eDVBFrontend] (4)tune
<   610.422> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<   610.422> **** Tuning JESS
<   610.422> **** frequency_mhz: 10964
<   610.422> **** lo_mhz: 9750
<   610.422> **** T: 1114
<   610.422> **** position: 0
<   610.422> **** ub: 2
<   610.422> **** mode: 2
<   610.422> **** JESS: 70 14 5a 02
<   610.422> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   610.422> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<   610.422> [eDVBFrontend] tuning to 1681 mhz
<   610.422> [eDVBChannel] OURSTATE: tuning
<   610.422> [eDVBServicePMTHandler] allocate Channel: res 0
<   610.422> [eDVBCIInterfaces] addPMTHandler 1:0:19:1E46:809:2:11A0000:0:0:0:
<   610.423> [eDVBChannel] getDemux cap=00
<   610.423> [eDVBResourceManager] allocate demux cap=00
<   610.423> [eDVBResourceManager] allocating demux adapter=0, demux=3, source=-1 fesource=4
<   610.423> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<   610.424> [eEPGCache] saveEventToFile epg event id 9313
<   610.424> [RecordTimer] prepare ok, waiting for begin
<   610.426> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash']
<   610.426> [Trashcan] looking in trashcan /media/hdd/.Trash
<   610.426> [Trashcan] Cleanup already running
<   610.427> [eDVBFrontend] set static current limiting
<   610.427> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   610.428> [eDVBFrontend] set static current limiting
<   610.434> [Trashcan] /media/hdd/.Trash: Size: 0
<   610.435> [Trashcan] /media/hdd/.Trash: Size now: 0
<   610.435> [Trashcan] looking in trashcan /media/hdd/movie/.Trash
<   610.441> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.441> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.441> [eDVBFrontend] set static current limiting
<   610.441> [eDVBFrontend] invalidate current switch params
<   610.442> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   610.442> [eDVBFrontend] invalidate current switch params
<   610.442> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.442> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.442> [eDVBFrontend] invalidate current switch params
<   610.442> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   610.442> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.442> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.442> [eDVBFrontend] setVoltage 1
<   610.442> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   610.442> [eDVBFrontend] setVoltage 1
<   610.443> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.443> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.443> [eDVBFrontend] setVoltage 1
<   610.444> [eDVBFrontend] sleep 1500ms
<   610.444> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   610.444> [eDVBFrontend] sleep 1500ms
<   610.444> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.444> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   610.444> [eDVBFrontend] sleep 1500ms
<   610.477> [Trashcan] /media/hdd/movie/.Trash: Size: 40135420894
<   610.507> [Trashcan] /media/hdd/movie/.Trash: Size now: 40135420894
<   610.509> [Task] job Components.Task.Job name=Cleaning Trashes #tasks=1 completed with [] in None
<   611.944> [eDVBFrontend] setVoltage 2
<   611.945> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   611.947> [eDVBFrontend] setVoltage 2
<   611.948> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   611.948> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   611.948> [eDVBFrontend] setVoltage 2
<   611.948> [eDVBFrontend] setTone 0
<   611.949> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   611.949> [eDVBFrontend] setTone 0
<   611.950> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   611.950> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   611.950> [eDVBFrontend] setTone 0
<   611.950> [eDVBFrontend] sleep 75ms
<   611.950> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   611.950> [eDVBFrontend] sleep 75ms
<   611.950> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   611.950> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   611.950> [eDVBFrontend] sleep 75ms
<   612.081> [eDVBFrontend] sendDiseqc: 7003e500(?)
<   612.081> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.137> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<   612.137> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.137> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.193> [eDVBFrontend] sendDiseqc: 70145a02(?)
<   612.193> [eDVBFrontend] sleep 100ms
<   612.193> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.193> [eDVBFrontend] sleep 100ms
<   612.193> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.193> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.193> [eDVBFrontend] sleep 100ms
<   612.293> [eDVBFrontend] setVoltage 1
<   612.294> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.294> [eDVBFrontend] setVoltage 1
<   612.294> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.294> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.294> [eDVBFrontend] setVoltage 1
<   612.295> [eDVBFrontend] update current switch params
<   612.295> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.295> [eDVBFrontend] update current switch params
<   612.295> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.295> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.295> [eDVBFrontend] update current switch params
<   612.295> [eDVBFrontend] startTuneTimeout 5000
<   612.295> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.295> [eDVBFrontend] startTuneTimeout 5000
<   612.295> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.295> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.295> [eDVBFrontend] startTuneTimeout 5000
<   612.295> [eDVBFrontend] setFrontend 1
<   612.295> [eDVBFrontend] setting frontend 0
<   612.298> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<   612.298> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.298> [eDVBFrontend] setFrontend 1
<   612.298> [eDVBFrontend] setting frontend 3
<   612.298> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.298> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.298> [eDVBFrontend] setFrontend 1
<   612.298> [eDVBFrontend] setting frontend 4
<   612.298> [eDVBFrontend] sleep 500ms
<   612.301> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<   612.305> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<   612.305> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.305> [eDVBFrontend] sleep 500ms
<   612.305> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.305> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.305> [eDVBFrontend] sleep 500ms
<   612.340> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<   612.350> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<   612.350> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<   612.798> [eDVBFrontend] set dynamic current limiting
<   612.805> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.805> [eDVBFrontend] set dynamic current limiting
<   612.805> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.805> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.805> [eDVBFrontend] set dynamic current limiting
<   612.805> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   612.805> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   612.805> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.295> [eDVBChannel] OURSTATE: failed, retune
<   617.295> [eDVBFrontend] (0)tune
<   617.295> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<   617.295> **** Tuning JESS
<   617.295> **** frequency_mhz: 10847
<   617.295> **** lo_mhz: 9750
<   617.295> **** T: 997
<   617.295> **** position: 0
<   617.296> **** ub: 0
<   617.296> **** mode: 0
<   617.296> **** JESS: 70 03 e5 00
<   617.296> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   617.296> [eDVBFrontend] prepare_sat System 1 Freq 10847000 Pol 1 SR 23000000 INV 2 FEC 2 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<   617.296> [eDVBFrontend] tuning to 1211 mhz
<   617.296> [eDVBChannel] OURSTATE: tuning
<   617.296> [eDVBServicePMTHandler] tune failed.
<   617.296> [eDVBServiceRecord] RECORD service event 1
<   617.296> [eDVBServiceRecord] record failed to tune
<   617.296> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<   617.296> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<   617.296> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 802 current: ffffffff
<   617.296> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<   617.296> [eDVBChannel] OURSTATE: failed, retune
<   617.296> [eDVBFrontend] (3)tune
<   617.296> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<   617.296> **** Tuning JESS
<   617.296> **** frequency_mhz: 11097
<   617.296> **** lo_mhz: 9750
<   617.296> **** T: 1247
<   617.296> **** position: 0
<   617.296> **** ub: 1
<   617.296> **** mode: 0
<   617.296> **** JESS: 70 0c df 00
<   617.296> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   617.296> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<   617.296> [eDVBFrontend] tuning to 1421 mhz
<   617.296> [eDVBChannel] OURSTATE: tuning
<   617.296> [eDVBServicePMTHandler] tune failed.
<   617.296> [eDVBServiceRecord] RECORD service event 1
<   617.296> [eDVBServiceRecord] record failed to tune
<   617.297> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<   617.297> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<   617.297> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 812 current: ffffffff
<   617.297> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<   617.297> [eDVBChannel] OURSTATE: failed, retune
<   617.297> [eDVBFrontend] (4)tune
<   617.297> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<   617.297> **** Tuning JESS
<   617.297> **** frequency_mhz: 10964
<   617.297> **** lo_mhz: 9750
<   617.297> **** T: 1114
<   617.297> **** position: 0
<   617.297> **** ub: 2
<   617.297> **** mode: 2
<   617.297> **** JESS: 70 14 5a 02
<   617.297> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   617.297> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<   617.297> [eDVBFrontend] tuning to 1681 mhz
<   617.297> [eDVBChannel] OURSTATE: tuning
<   617.297> [eDVBServicePMTHandler] tune failed.
<   617.297> [eDVBServiceRecord] RECORD service event 1
<   617.297> [eDVBServiceRecord] record failed to tune
<   617.297> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<   617.297> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<   617.297> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 809 current: ffffffff
<   617.297> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<   617.297> [eDVBFrontend] set static current limiting
<   617.297> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.297> [eDVBFrontend] set static current limiting
<   617.297> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.297> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.297> [eDVBFrontend] set static current limiting
<   617.297> [eDVBFrontend] invalidate current switch params
<   617.297> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.298> [eDVBFrontend] invalidate current switch params
<   617.298> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.298> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.298> [eDVBFrontend] invalidate current switch params
<   617.298> [eDVBFrontend] set sequence pos 3
<   617.298> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.298> [eDVBFrontend] set sequence pos 3
<   617.298> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.298> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.298> [eDVBFrontend] set sequence pos 3
<   617.298> [eDVBFrontend] setVoltage 2
<   617.298> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.298> [eDVBFrontend] setVoltage 2
<   617.299> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.299> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.300> [eDVBFrontend] setVoltage 2
<   617.300> [eDVBFrontend] setTone 0
<   617.301> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.301> [eDVBFrontend] setTone 0
<   617.301> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.301> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.301> [eDVBFrontend] setTone 0
<   617.302> [eDVBFrontend] sleep 75ms
<   617.302> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.302> [eDVBFrontend] sleep 75ms
<   617.302> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.302> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.302> [eDVBFrontend] sleep 75ms
<   617.433> [eDVBFrontend] sendDiseqc: 7003e500(?)
<   617.433> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.489> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<   617.489> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.489> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.545> [eDVBFrontend] sendDiseqc: 70145a02(?)
<   617.545> [eDVBFrontend] sleep 100ms
<   617.545> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.545> [eDVBFrontend] sleep 100ms
<   617.545> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.545> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.546> [eDVBFrontend] sleep 100ms
<   617.645> [eDVBFrontend] setVoltage 1
<   617.646> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.646> [eDVBFrontend] setVoltage 1
<   617.647> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.647> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.647> [eDVBFrontend] setVoltage 1
<   617.647> [eDVBFrontend] update current switch params
<   617.647> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.647> [eDVBFrontend] update current switch params
<   617.647> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.647> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.647> [eDVBFrontend] update current switch params
<   617.647> [eDVBFrontend] startTuneTimeout 5000
<   617.647> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.647> [eDVBFrontend] startTuneTimeout 5000
<   617.647> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.647> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.647> [eDVBFrontend] startTuneTimeout 5000
<   617.647> [eDVBFrontend] setFrontend 1
<   617.647> [eDVBFrontend] setting frontend 0
<   617.648> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<   617.648> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.648> [eDVBFrontend] setFrontend 1
<   617.648> [eDVBFrontend] setting frontend 3
<   617.648> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.648> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.648> [eDVBFrontend] setFrontend 1
<   617.648> [eDVBFrontend] setting frontend 4
<   617.648> [eDVBFrontend] sleep 500ms
<   617.648> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<   617.648> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<   617.648> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   617.648> [eDVBFrontend] sleep 500ms
<   617.648> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.648> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   617.648> [eDVBFrontend] sleep 500ms
<   617.690> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<   617.690> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<   617.691> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<   618.148> [eDVBFrontend] set dynamic current limiting
<   618.148> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   618.148> [eDVBFrontend] set dynamic current limiting
<   618.148> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   618.148> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   618.148> [eDVBFrontend] set dynamic current limiting
<   618.148> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   618.148> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   618.148> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.647> [eDVBChannel] OURSTATE: failed, retune
<   622.648> [eDVBFrontend] (0)tune
<   622.654> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<   622.654> **** Tuning JESS
<   622.654> **** frequency_mhz: 10847
<   622.654> **** lo_mhz: 9750
<   622.654> **** T: 997
<   622.654> **** position: 0
<   622.654> **** ub: 0
<   622.654> **** mode: 0
<   622.655> **** JESS: 70 03 e5 00
<   622.655> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   622.655> [eDVBFrontend] prepare_sat System 1 Freq 10847000 Pol 1 SR 23000000 INV 2 FEC 2 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<   622.655> [eDVBFrontend] tuning to 1211 mhz
<   622.655> [eDVBChannel] OURSTATE: tuning
<   622.655> [eDVBServicePMTHandler] tune failed.
<   622.655> [eDVBServiceRecord] RECORD service event 1
<   622.655> [eDVBServiceRecord] record failed to tune
<   622.655> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<   622.655> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<   622.655> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 802 current: ffffffff
<   622.655> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<   622.655> [eDVBChannel] OURSTATE: failed, retune
<   622.655> [eDVBFrontend] (3)tune
<   622.655> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<   622.655> **** Tuning JESS
<   622.655> **** frequency_mhz: 11097
<   622.655> **** lo_mhz: 9750
<   622.655> **** T: 1247
<   622.655> **** position: 0
<   622.655> **** ub: 1
<   622.655> **** mode: 0
<   622.655> **** JESS: 70 0c df 00
<   622.655> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   622.655> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<   622.655> [eDVBFrontend] tuning to 1421 mhz
<   622.655> [eDVBChannel] OURSTATE: tuning
<   622.655> [eDVBServicePMTHandler] tune failed.
<   622.655> [eDVBServiceRecord] RECORD service event 1
<   622.655> [eDVBServiceRecord] record failed to tune
<   622.656> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<   622.656> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<   622.656> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 812 current: ffffffff
<   622.656> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<   622.656> [eDVBChannel] OURSTATE: failed, retune
<   622.656> [eDVBFrontend] (4)tune
<   622.656> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<   622.656> **** Tuning JESS
<   622.656> **** frequency_mhz: 10964
<   622.656> **** lo_mhz: 9750
<   622.656> **** T: 1114
<   622.656> **** position: 0
<   622.656> **** ub: 2
<   622.656> **** mode: 2
<   622.656> **** JESS: 70 14 5a 02
<   622.656> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<   622.656> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<   622.656> [eDVBFrontend] tuning to 1681 mhz
<   622.656> [eDVBChannel] OURSTATE: tuning
<   622.656> [eDVBServicePMTHandler] tune failed.
<   622.656> [eDVBServiceRecord] RECORD service event 1
<   622.656> [eDVBServiceRecord] record failed to tune
<   622.656> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<   622.656> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<   622.656> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 809 current: ffffffff
<   622.656> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<   622.656> [eDVBFrontend] set static current limiting
<   622.656> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.656> [eDVBFrontend] set static current limiting
<   622.656> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.657> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.657> [eDVBFrontend] set static current limiting
<   622.657> [eDVBFrontend] invalidate current switch params
<   622.657> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.657> [eDVBFrontend] invalidate current switch params
<   622.657> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.657> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.657> [eDVBFrontend] invalidate current switch params
<   622.657> [eDVBFrontend] set sequence pos 3
<   622.657> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.657> [eDVBFrontend] set sequence pos 3
<   622.657> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.657> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.657> [eDVBFrontend] set sequence pos 3
<   622.657> [eDVBFrontend] setVoltage 2
<   622.658> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.658> [eDVBFrontend] setVoltage 2
<   622.658> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.658> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.658> [eDVBFrontend] setVoltage 2
<   622.659> [eDVBFrontend] setTone 0
<   622.660> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.660> [eDVBFrontend] setTone 0
<   622.660> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.660> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.660> [eDVBFrontend] setTone 0
<   622.661> [eDVBFrontend] sleep 75ms
<   622.661> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.661> [eDVBFrontend] sleep 75ms
<   622.661> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.661> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.661> [eDVBFrontend] sleep 75ms
<   622.792> [eDVBFrontend] sendDiseqc: 7003e500(?)
<   622.792> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.848> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<   622.848> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.848> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.904> [eDVBFrontend] sendDiseqc: 70145a02(?)
<   622.904> [eDVBFrontend] sleep 100ms
<   622.904> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   622.904> [eDVBFrontend] sleep 100ms
<   622.904> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.905> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   622.905> [eDVBFrontend] sleep 100ms
<   623.004> [eDVBFrontend] setVoltage 1
<   623.005> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   623.005> [eDVBFrontend] setVoltage 1
<   623.006> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   623.006> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   623.006> [eDVBFrontend] setVoltage 1
<   623.007> [eDVBFrontend] update current switch params
<   623.007> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   623.007> [eDVBFrontend] update current switch params
<   623.007> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   623.007> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<   623.007> [eDVBFrontend] update current switch params
<   623.007> [eDVBFrontend] startTuneTimeout 5000
<   623.007> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<   623.007> [eDVBFrontend] startTuneTimeout 5000
<   623.007> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<   623.007> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?

[Huevos]

BTW, 1 of 3 did started 5 minutes late but the other 2 didn't.start at all.

[athoik]

So, the patch seems in the right direction. We can definitely detect that another tuner is currently in state tuning.


Now let's try to make it sleep, but only the very first time.
 

diff --git a/lib/dvb/frontend.cpp b/lib/dvb/frontend.cpp
index 30918be..abc015e 100644
--- a/lib/dvb/frontend.cpp
+++ b/lib/dvb/frontend.cpp
@@ -1583,6 +1583,15 @@ int eDVBFrontend::tuneLoopInt()  // called by m_tuneTimer
                                prev->inc_use();
                        }
                }
+               else if (sec_fe != this && sec_fe->m_state == stateTuning)
+               {
+                       eDebug("[eDVBFrontend] frontend %d is in stateTuning, maybe we should delay current tune on frontend %d?", sec_fe->getDVBID(), m_dvbid);
+                       if (delay == -1 && m_sec_sequence && m_sec_sequence.front() == m_sec_sequence.current())
+                       {
+                               m_sec_sequence.push_front(eSecCommand(eSecCommand::SLEEP, 1000 + 10 * sec_fe->getDVBID()); // need to use m_params from m_sec?
+                               delay = 0;
+                       }
+               }
        }

        if ( m_sec_sequence && m_sec_sequence.current() != m_sec_sequence.end() )

If the m_sec_sequence is currently not iterated yet, and stateTuning detected, the first (and only the first time) it will add an extra delay using SLEEP.

Will it work? I have no idea, but logic seems fine (at least is an generic approach).

PS. You might need to add extra debug inside if to know that SLEEP command was set.

PPS. If m_sec_sequence.front() line fails try also the following:

diff --git a/lib/dvb/frontend.cpp b/lib/dvb/frontend.cpp
index 30918be..43bb18e 100644
--- a/lib/dvb/frontend.cpp
+++ b/lib/dvb/frontend.cpp
@@ -1583,6 +1583,17 @@ int eDVBFrontend::tuneLoopInt()  // called by m_tuneTimer
                                prev->inc_use();
                        }
                }
+               else if (sec_fe != this && sec_fe->m_state == stateTuning)
+               {
+                       eDebug("[eDVBFrontend] frontend %d is in stateTuning, maybe we should delay current tune on frontend %d?", sec_fe->getDVBID(), m_dvbid);
+                       if (delay == -1 && m_sec_sequence && m_sec_sequence.begin() == m_sec_sequence.current())
+                       {
+                               eDebug("[eDVBFrontend] setting SLEEP to %d ms", 1000 + 10 * sec_fe->getDVBID());
+                               m_sec_sequence.push_front(eSecCommand(eSecCommand::SLEEP, 1000 + 10 * sec_fe->getDVBID()); // need to use m_params from m_sec?
+                               m_sec_sequence.current() = m_sec_sequence.begin();
+                               delay = 0;
+                       }
+               }
        }

        if ( m_sec_sequence && m_sec_sequence.current() != m_sec_sequence.end() )

Edited by athoik, 1 October 2018 - 21:47.

[Huevos]

m_sec_sequence.front() line fails.

 

Trying the second patch now.

[Huevos]

Syntax error:

 m_sec_sequence.push_front(eSecCommand(eSecCommand::SLEEP, 1000 + 10 * sec_fe->getDVBID()); // need to use m_params from m_sec?

Test:

•  
• frontend.cpp patch applied. https://github.com/H...e93e11aa8782c98
• RecordTimer.py (version prior to "Force "simultaneous" recordings to start with a one second interval between them"). https://github.com/H....py#L1170-L1172
• Set 3 recordings with simultaneous start times.

 

Result:

 

• All recordings succeeded.
• Debug log needs looking at. Is this expected behaviour?

 

Debug:

<  1925.907> [RecordTimer] activating state 1
<  1925.908> [RecordTimer] Found enough free space to record
<  1925.909> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181002 1148 - BBC One HD - Homes Under the Hammer'
<  1925.909> [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1925.910> [eDVBResourceManager] allocate channel.. 0802:0002
<  1925.910> [eDVBResourceManager] available channel.. 082b:0002
<  1925.910> [eDVBFrontend] opening frontend 0
<  1925.914> [eDVBFrontend] (0)tune
<  1925.914> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<  1925.914> **** Tuning JESS
<  1925.914> **** frequency_mhz: 10847
<  1925.914> **** lo_mhz: 9750
<  1925.914> **** T: 997
<  1925.914> **** position: 0
<  1925.914> **** ub: 0
<  1925.914> **** mode: 0
<  1925.914> **** JESS: 70 03 e5 00
<  1925.914> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1925.914> [eDVBFrontend] prepare_sat System 1 Freq 10847000 Pol 1 SR 23000000 INV 2 FEC 2 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  1925.914> [eDVBFrontend] tuning to 1211 mhz
<  1925.914> [eDVBChannel] OURSTATE: tuning
<  1925.914> [eDVBServicePMTHandler] allocate Channel: res 0
<  1925.914> [eDVBCIInterfaces] addPMTHandler 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1925.915> [eDVBChannel] getDemux cap=00
<  1925.915> [eDVBResourceManager] allocate demux cap=00
<  1925.915> [eDVBResourceManager] allocating demux adapter=0, demux=1, source=-1 fesource=0
<  1925.915> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1925.915> [eEPGCache] saveEventToFile epg event id d65b
<  1925.916> [RecordTimer] prepare ok, waiting for begin
<  1925.918> [RecordTimer] activating state 1
<  1925.918> [Trashcan] probing folders
<  1925.920> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash']
<  1925.920> [Trashcan] looking in trashcan /media/hdd/.Trash
<  1925.921> [Trashcan] /media/hdd/.Trash: Size: 0
<  1925.921> [Trashcan] /media/hdd/.Trash: Size now: 0
<  1925.921> [Trashcan] looking in trashcan /media/hdd/movie/.Trash
<  1925.930> [RecordTimer] Found enough free space to record
<  1925.931> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181002 1148 - ITV London HD - This Morning'
<  1925.931> [Navigation] recording service: 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1925.932> [eDVBResourceManager] allocate channel.. 0812:0002
<  1925.932> [eDVBResourceManager] available channel.. 082b:0002
<  1925.932> [eDVBResourceManager] available channel.. 0802:0002
<  1925.932> [eDVBFrontend] opening frontend 3
<  1925.935> [eDVBFrontend] (3)tune
<  1925.935> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  1925.935> **** Tuning JESS
<  1925.935> **** frequency_mhz: 11097
<  1925.935> **** lo_mhz: 9750
<  1925.935> **** T: 1247
<  1925.935> **** position: 0
<  1925.935> **** ub: 1
<  1925.935> **** mode: 0
<  1925.935> **** JESS: 70 0c df 00
<  1925.935> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1925.935> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  1925.935> [eDVBFrontend] tuning to 1421 mhz
<  1925.935> [eDVBChannel] OURSTATE: tuning
<  1925.935> [eDVBServicePMTHandler] allocate Channel: res 0
<  1925.935> [eDVBCIInterfaces] addPMTHandler 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1925.935> [eDVBChannel] getDemux cap=00
<  1925.935> [eDVBResourceManager] allocate demux cap=00
<  1925.935> [eDVBResourceManager] allocating demux adapter=0, demux=2, source=-1 fesource=3
<  1925.935> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1925.936> [eEPGCache] saveEventToFile epg event id 3a8
<  1925.936> [RecordTimer] prepare ok, waiting for begin
<  1925.937> [Trashcan] Cleanup already running
<  1925.938> [RecordTimer] activating state 1
<  1925.939> [RecordTimer] Found enough free space to record
<  1925.940> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181002 1148 - Channel 5 HD - Jeremy Vine'
<  1925.940> [Navigation] recording service: 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1925.940> [eDVBResourceManager] allocate channel.. 0809:0002
<  1925.940> [eDVBResourceManager] available channel.. 082b:0002
<  1925.940> [eDVBResourceManager] available channel.. 0802:0002
<  1925.940> [eDVBResourceManager] available channel.. 0812:0002
<  1925.940> [eDVBFrontend] opening frontend 4
<  1925.943> [eDVBFrontend] (4)tune
<  1925.943> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  1925.943> **** Tuning JESS
<  1925.943> **** frequency_mhz: 10964
<  1925.943> **** lo_mhz: 9750
<  1925.943> **** T: 1114
<  1925.943> **** position: 0
<  1925.943> **** ub: 2
<  1925.943> **** mode: 2
<  1925.943> **** JESS: 70 14 5a 02
<  1925.943> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1925.943> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<  1925.943> [eDVBFrontend] tuning to 1681 mhz
<  1925.943> [eDVBChannel] OURSTATE: tuning
<  1925.943> [eDVBServicePMTHandler] allocate Channel: res 0
<  1925.943> [eDVBCIInterfaces] addPMTHandler 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1925.943> [eDVBChannel] getDemux cap=00
<  1925.943> [eDVBResourceManager] allocate demux cap=00
<  1925.943> [eDVBResourceManager] allocating demux adapter=0, demux=3, source=-1 fesource=4
<  1925.943> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1925.944> [eEPGCache] saveEventToFile epg event id 529
<  1925.944> [RecordTimer] prepare ok, waiting for begin
<  1925.945> [Trashcan] Cleanup already running
<  1925.946> [eDVBFrontend] set static current limiting
<  1925.946> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1925.946> [eDVBFrontend] setting SLEEP to 1000 ms
<  1925.946> [eDVBFrontend] sleep 1000ms
<  1925.946> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1925.946> [eDVBFrontend] setting SLEEP to 1030 ms
<  1925.946> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1925.946> [eDVBFrontend] sleep 1030ms
<  1925.946> [eDVBFrontend] invalidate current switch params
<  1925.946> [eDVBFrontend] setVoltage 1
<  1925.956> [Trashcan] /media/hdd/movie/.Trash: Size: 42350583344
<  1925.957> [eDVBFrontend] sleep 1500ms
<  1925.984> [Trashcan] /media/hdd/movie/.Trash: Size now: 42350583344
<  1925.985> [Task] job Components.Task.Job name=Cleaning Trashes #tasks=1 completed with [] in None
<  1926.946> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1926.946> [eDVBFrontend] set static current limiting
<  1926.946> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1926.946> [eDVBFrontend] invalidate current switch params
<  1926.946> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1926.946> [eDVBFrontend] set sequence pos 3
<  1926.947> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1926.947> [eDVBFrontend] setVoltage 2
<  1926.947> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1926.947> [eDVBFrontend] setTone 0
<  1926.948> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1926.948> [eDVBFrontend] sleep 75ms
<  1926.976> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.976> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.976> [eDVBFrontend] set static current limiting
<  1926.976> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.976> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.976> [eDVBFrontend] invalidate current switch params
<  1926.976> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.976> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.977> [eDVBFrontend] set sequence pos 3
<  1926.977> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.977> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.977> [eDVBFrontend] setVoltage 2
<  1926.977> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.977> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.977> [eDVBFrontend] setTone 0
<  1926.978> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.978> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1926.978> [eDVBFrontend] sleep 75ms
<  1927.023> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.079> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<  1927.079> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.079> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.135> [eDVBFrontend] sendDiseqc: 70145a02(?)
<  1927.136> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.136> [eDVBFrontend] sleep 100ms
<  1927.136> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.136> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.136> [eDVBFrontend] sleep 100ms
<  1927.236> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.236> [eDVBFrontend] setVoltage 1
<  1927.237> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.237> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.237> [eDVBFrontend] setVoltage 1
<  1927.238> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.238> [eDVBFrontend] update current switch params
<  1927.238> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.238> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.238> [eDVBFrontend] update current switch params
<  1927.238> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.238> [eDVBFrontend] startTuneTimeout 5000
<  1927.238> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.238> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.238> [eDVBFrontend] startTuneTimeout 5000
<  1927.238> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.238> [eDVBFrontend] setFrontend 1
<  1927.238> [eDVBFrontend] setting frontend 3
<  1927.245> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<  1927.245> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.245> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.245> [eDVBFrontend] setFrontend 1
<  1927.245> [eDVBFrontend] setting frontend 4
<  1927.247> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.247> [eDVBFrontend] sleep 500ms
<  1927.247> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<  1927.248> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.248> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.248> [eDVBFrontend] sleep 500ms
<  1927.291> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<  1927.291> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<  1927.458> [eDVBFrontend] setVoltage 2
<  1927.458> [eDVBFrontend] setTone 0
<  1927.459> [eDVBFrontend] sleep 75ms
<  1927.590> [eDVBFrontend] sendDiseqc: 7003e500(?)
<  1927.592> [eDVBFrontend] sleep 100ms
<  1927.692> [eDVBFrontend] setVoltage 1
<  1927.693> [eDVBFrontend] update current switch params
<  1927.693> [eDVBFrontend] startTuneTimeout 5000
<  1927.693> [eDVBFrontend] setFrontend 1
<  1927.693> [eDVBFrontend] setting frontend 0
<  1927.701> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<  1927.701> [eDVBFrontend] sleep 500ms
<  1927.747> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.747> [eDVBFrontend] set dynamic current limiting
<  1927.747> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 3?
<  1927.748> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.748> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.748> [eDVBFrontend] set dynamic current limiting
<  1927.748> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.748> [eDVBFrontend] frontend 0 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1927.750> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<  1927.802> [eDVBFrontend] (0)fe event: status 1f, inversion off, m_tuning 3
<  1927.802> [eDVBChannel] OURSTATE: ok
<  1927.802> [eDVBLocalTimerHandler] channel 0x193e388 running
<  1927.802> [eDVBChannel] getDemux cap=00
<  1927.802> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.802> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  1927.803> [eEPGCache] channel 0x193e388 running
<  1927.803> [eDVBChannel] getDemux cap=00
<  1927.803> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.803> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.803> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.803> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.803> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.803> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.804> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.805> [eDVBChannel] getDemux cap=01
<  1927.805> [eDVBResourceManager] allocate demux cap=01
<  1927.805> [eDVBResourceManager] allocating shared demux adapter=0, demux=1, source=0
<  1927.805> [eDVBServicePMTHandler] ok ... now we start!!
<  1927.805> [eDVBServiceRecord] RECORD service event 5
<  1927.805> [eDVBCAService] new service 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1927.805> [eDVBCAService] add demux 1 to slot 0 service 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1927.805> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.805> [eEPGCache] next update in 2 sec
<  1927.805> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1927.806> [eDVBServiceRecord] RECORD service event 6
<  1927.806> [eDVBServiceRecord] tuned..
<  1927.806> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.806> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1927.807> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.807> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1927.875> [eDVBServicePMTHandler] PATready
<  1927.875> [eDVBServicePMTHandler] use pmtpid 0104 for service_id 1b1d
<  1927.875> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.876> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1927.876> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.876> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1927.877> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.877> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1927.878> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1927.878> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  1928.191> [eDVBServiceRecord] RECORD service event 5
<  1928.192> [eDVBCIInterfaces] gotPMT
<  1928.193> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1928.194> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1928.195> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1928.195> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1928.201> [eDVBFrontend] set dynamic current limiting
<  1928.392> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1928.392> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  1928.679> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1928.680> [eDVBSectionReader] DMX_SET_FILTER pid=259
<  1928.991> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1928.991> [eDVBSectionReader] DMX_SET_FILTER pid=264
<  1929.107> [eDVBServiceRecord] now running: †Homes Under the Hammer‡ (3600 seconds)
<  1929.108> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1929.108> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1929.295> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1929.296> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  1929.355> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1929.355> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1929.526> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1929.527> [eDVBSectionReader] DMX_SET_FILTER pid=263
<  1929.635> [eDVBServicePMTHandler] sdt update done!
<  1929.805> [eEPGCache] start caching events(1538473663)
<  1929.805> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  1929.806> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  1929.806> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1929.807> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1929.808> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1929.808> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1929.809> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1929.809> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1929.810> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1929.810> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  1931.498> [eDVBLocalTimerHandler] diff is 0
<  1931.498> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  1931.498> [eDVBLocalTimerHandler] not changed
<  1931.499> [eDVBChannel] getDemux cap=00
<  1932.238> [eDVBChannel] OURSTATE: failed, retune
<  1932.238> [eDVBFrontend] (3)tune
<  1932.238> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  1932.238> **** Tuning JESS
<  1932.238> **** frequency_mhz: 11097
<  1932.238> **** lo_mhz: 9750
<  1932.238> **** T: 1247
<  1932.238> **** position: 0
<  1932.238> **** ub: 1
<  1932.238> **** mode: 0
<  1932.238> **** JESS: 70 0c df 00
<  1932.238> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1932.238> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  1932.238> [eDVBFrontend] tuning to 1421 mhz
<  1932.238> [eDVBChannel] OURSTATE: tuning
<  1932.238> [eDVBServicePMTHandler] tune failed.
<  1932.238> [eDVBServiceRecord] RECORD service event 1
<  1932.238> [eDVBServiceRecord] record failed to tune
<  1932.238> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1932.238> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1932.238> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 812 current: ffffffff
<  1932.238> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<  1932.239> [eDVBChannel] OURSTATE: failed, retune
<  1932.239> [eDVBFrontend] (4)tune
<  1932.239> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  1932.239> **** Tuning JESS
<  1932.239> **** frequency_mhz: 10964
<  1932.239> **** lo_mhz: 9750
<  1932.239> **** T: 1114
<  1932.239> **** position: 0
<  1932.239> **** ub: 2
<  1932.239> **** mode: 2
<  1932.239> **** JESS: 70 14 5a 02
<  1932.239> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1932.239> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<  1932.239> [eDVBFrontend] tuning to 1681 mhz
<  1932.239> [eDVBChannel] OURSTATE: tuning
<  1932.239> [eDVBServicePMTHandler] tune failed.
<  1932.239> [eDVBServiceRecord] RECORD service event 1
<  1932.239> [eDVBServiceRecord] record failed to tune
<  1932.239> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1932.239> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1932.239> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 809 current: ffffffff
<  1932.239> [eDVBServicePMTHandler] incorrect original_network_id. expected: 2 current: ffffffff
<  1932.239> [eDVBFrontend] set static current limiting
<  1932.239> [eDVBFrontend] frontend 3 is in stateTuning, maybe we should delay current tune on frontend 4?
<  1932.239> [eDVBFrontend] setting SLEEP to 1030 ms
<  1932.239> [eDVBFrontend] sleep 1030ms
<  1932.239> [eDVBFrontend] invalidate current switch params
<  1932.239> [eDVBFrontend] set sequence pos 3
<  1932.239> [eDVBFrontend] setVoltage 2
<  1932.240> [eDVBFrontend] setTone 0
<  1932.241> [eDVBFrontend] sleep 75ms
<  1932.372> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<  1932.372> [eDVBFrontend] sleep 100ms
<  1932.472> [eDVBFrontend] setVoltage 1
<  1932.473> [eDVBFrontend] update current switch params
<  1932.473> [eDVBFrontend] startTuneTimeout 5000
<  1932.473> [eDVBFrontend] setFrontend 1
<  1932.473> [eDVBFrontend] setting frontend 3
<  1932.473> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<  1932.473> [eDVBFrontend] sleep 500ms
<  1932.520> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<  1932.542> [eDVBFrontend] (0)fe event: status 1f, inversion off, m_tuning 3
<  1932.572> [eDVBFrontend] (3)fe event: status 1f, inversion off, m_tuning 3
<  1932.572> [eDVBChannel] OURSTATE: ok
<  1932.572> [eDVBLocalTimerHandler] channel 0x1968dd0 running
<  1932.572> [eDVBChannel] getDemux cap=00
<  1932.572> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.572> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  1932.573> [eEPGCache] channel 0x1968dd0 running
<  1932.573> [eDVBChannel] getDemux cap=00
<  1932.573> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.573> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.573> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.573> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.573> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.575> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.575> [eDVBChannel] getDemux cap=01
<  1932.575> [eDVBResourceManager] allocate demux cap=01
<  1932.575> [eDVBResourceManager] allocating shared demux adapter=0, demux=2, source=3
<  1932.575> [eDVBServicePMTHandler] ok ... now we start!!
<  1932.575> [eDVBServiceRecord] RECORD service event 5
<  1932.575> [eDVBCAService] new service 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1932.575> [eDVBCAService] add demux 2 to slot 0 service 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1932.575> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.575> [eEPGCache] next update in 2 sec
<  1932.575> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1932.576> [eDVBServiceRecord] RECORD service event 6
<  1932.576> [eDVBServiceRecord] tuned..
<  1932.576> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.576> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1932.577> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.577> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1932.771> [eDVBServicePMTHandler] PATready
<  1932.771> [eDVBServicePMTHandler] use pmtpid 0102 for service_id 5208
<  1932.771> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.772> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1932.772> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.773> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1932.774> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.774> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1932.775> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.775> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  1932.973> [eDVBFrontend] set dynamic current limiting
<  1932.976> [eDVBServiceRecord] RECORD service event 5
<  1932.977> [eDVBCIInterfaces] gotPMT
<  1932.978> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.978> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1932.979> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1932.980> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1933.175> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1933.175> [eDVBSectionReader] DMX_SET_FILTER pid=261
<  1933.269> [eDVBFrontend] set static current limiting
<  1933.270> [eDVBFrontend] invalidate current switch params
<  1933.270> [eDVBFrontend] set sequence pos 3
<  1933.270> [eDVBFrontend] setVoltage 2
<  1933.271> [eDVBFrontend] setTone 0
<  1933.271> [eDVBFrontend] sleep 75ms
<  1933.402> [eDVBFrontend] sendDiseqc: 70145a02(?)
<  1933.403> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1933.403> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  1933.404> [eDVBFrontend] sleep 100ms
<  1933.504> [eDVBFrontend] setVoltage 1
<  1933.505> [eDVBFrontend] update current switch params
<  1933.505> [eDVBFrontend] startTuneTimeout 5000
<  1933.505> [eDVBFrontend] setFrontend 1
<  1933.505> [eDVBFrontend] setting frontend 4
<  1933.505> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<  1933.505> [eDVBFrontend] sleep 500ms
<  1933.551> [eDVBFrontend] (4)fe event: status 1f, inversion off, m_tuning 2
<  1933.551> [eDVBChannel] OURSTATE: ok
<  1933.551> [eDVBLocalTimerHandler] channel 0x196aa38 running
<  1933.552> [eDVBChannel] getDemux cap=00
<  1933.552> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.552> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  1933.552> [eEPGCache] channel 0x196aa38 running
<  1933.552> [eDVBChannel] getDemux cap=00
<  1933.553> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.553> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.553> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.553> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.553> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.553> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.554> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.555> [eDVBResourceManager] stop release channel timer
<  1933.555> [eDVBChannel] getDemux cap=01
<  1933.555> [eDVBResourceManager] allocate demux cap=01
<  1933.555> [eDVBResourceManager] allocating shared demux adapter=0, demux=3, source=4
<  1933.555> [eDVBServicePMTHandler] ok ... now we start!!
<  1933.555> [eDVBServiceRecord] RECORD service event 5
<  1933.555> [eDVBCAService] new service 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1933.555> [eDVBCAService] add demux 3 to slot 0 service 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1933.555> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.555> [eEPGCache] next update in 2 sec
<  1933.555> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1933.556> [eDVBServiceRecord] RECORD service event 6
<  1933.556> [eDVBServiceRecord] tuned..
<  1933.556> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.556> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1933.556> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.557> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1933.574> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1933.574> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  1933.606> [eDVBServicePMTHandler] PATready
<  1933.606> [eDVBServicePMTHandler] use pmtpid 0101 for service_id 1e46
<  1933.606> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.607> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1933.607> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.607> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1933.608> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.608> [eDVBSectionReader] DMX_SET_FILTER pid=267
<  1933.609> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.609> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  1933.776> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1933.777> [eDVBSectionReader] DMX_SET_FILTER pid=263
<  1933.807> [eDVBServiceRecord] RECORD service event 5
<  1933.808> [eDVBCIInterfaces] gotPMT
<  1933.809> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.809> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1933.812> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1933.813> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1933.840> [eDVBServiceRecord] now running: †This Morning‡ (7200 seconds)
<  1933.840> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1933.841> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1933.961> [eDVBFrontend] (0)fe event: status 1f, inversion off, m_tuning 0
<  1934.005> [eDVBFrontend] set dynamic current limiting
<  1934.011> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1934.011> [eDVBSectionReader] DMX_SET_FILTER pid=259
<  1934.210> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1934.210> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1934.408> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1934.409> [eDVBSectionReader] DMX_SET_FILTER pid=261
<  1934.575> [eEPGCache] start caching events(1538473668)
<  1934.575> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  1934.576> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  1934.576> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1934.577> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1934.578> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1934.579> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1934.579> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1934.580> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1934.580> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1934.581> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  1934.608> [eDVBServicePMTHandler] sdt update done!
<  1934.614> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1934.614> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  1934.709> [eDVBServicePMTHandler] sdt update done!
<  1934.808> [eDVBServiceRecord] now running: †Jeremy Vine‡ (7200 seconds)
<  1934.808> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1934.809> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1934.889> [eDVBLocalTimerHandler] diff is 0
<  1934.889> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  1934.889> [eDVBLocalTimerHandler] not changed
<  1934.890> [eDVBChannel] getDemux cap=00
<  1935.555> [eEPGCache] start caching events(1538473669)
<  1935.555> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  1935.556> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  1935.556> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1935.557> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1935.558> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1935.559> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1935.559> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1935.559> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1935.560> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1935.560> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  1936.810> [eEPGCache] abort non avail schedule reading
<  1936.812> [eEPGCache] abort non avail schedule other reading
<  1936.814> [eEPGCache] abort non avail virgin nownext reading
<  1936.814> [eEPGCache] abort non avail virgin schedule reading
<  1936.814> [eEPGCache] abort non avail netmed schedule reading
<  1936.815> [eEPGCache] abort non avail netmed schedule other reading
<  1936.815> [eEPGCache] abort non avail viasat reading
<  1936.864> [eEPGCache] nownext finished(1538473670)
<  1937.778> [eDVBLocalTimerHandler] diff is 0
<  1937.778> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  1937.778> [eDVBLocalTimerHandler] not changed
<  1937.779> [eDVBChannel] getDemux cap=00
<  1941.581> [eEPGCache] abort non avail schedule reading
<  1941.583> [eEPGCache] abort non avail schedule other reading
<  1941.583> [eEPGCache] abort non avail virgin nownext reading
<  1941.584> [eEPGCache] abort non avail virgin schedule reading
<  1941.584> [eEPGCache] abort non avail netmed schedule reading
<  1941.585> [eEPGCache] abort non avail netmed schedule other reading
<  1941.585> [eEPGCache] abort non avail viasat reading
<  1941.755> [eEPGCache] nownext finished(1538473675)
<  1942.561> [eEPGCache] abort non avail schedule reading
<  1942.562> [eEPGCache] abort non avail schedule other reading
<  1942.563> [eEPGCache] abort non avail virgin nownext reading
<  1942.563> [eEPGCache] abort non avail virgin schedule reading
<  1942.563> [eEPGCache] abort non avail netmed schedule reading
<  1942.564> [eEPGCache] abort non avail netmed schedule other reading
<  1942.564> [eEPGCache] abort non avail viasat reading
<  1942.607> [eEPGCache] nownext finished(1538473676)
<  1943.150> [Timezones] AutoTimer poll running
<  1943.151> [Timezones] AutoTimer parseEPG
<  1943.163> [eEPGCache] event 40ad not found in epgcache
<  1943.163> [eEPGCache] event 0110 not found in epgcache
<  1943.163> [eEPGCache] event 7633 not found in epgcache
<  1943.163> [eEPGCache] event 6380 not found in epgcache
<  1943.163> [eEPGCache] event dac4 not found in epgcache
<  1943.166> [eEPGCache] lookup events with 'Britain's Got More Talent' in title (ignore case)
<  1943.696> [eEPGCache] lookup events with 'Call the Midwife' in title (ignore case)
<  1944.278> [eEPGCache] lookup events with 'Dragons' Den' in title (ignore case)
<  1944.809> [eEPGCache] lookup events with 'Eat Well for Less?' in title (ignore case)
<  1945.616> [eEPGCache] lookup events with 'Eurocup Tractor Pulling' as title (case sensitive)
<  1945.945> [RecordTimer] activating state 2
<  1945.947> [eDVBServiceRecord] Recording to /media/hdd/movie/20181002 1148 - BBC One HD - Homes Under the Hammer.ts...
<  1945.947> [eDVBServiceRecord] start recording...
<  1945.947> [eDVBServiceRecord] RECORD: have 1 video stream(s) (1518), and 2 audio stream(s) (151a, 1519) (151c, 151b), and the pcr pid is 1518, and the text pid is 151b
<  1945.948> [eDVBServiceRecord] ADD PID: 0000
<  1945.948> [eDVBServiceRecord] ADD PID: 0104
<  1945.948> [eDVBServiceRecord] ADD PID: 1518
<  1945.948> [eDVBServiceRecord] ADD PID: 1519
<  1945.948> [eDVBServiceRecord] ADD PID: 151a
<  1945.948> [eDVBServiceRecord] ADD PID: 151b
<  1945.948> [eDVBServiceRecord] ADD PID: 151c
<  1945.950> [setIoPrio] realtime level 7 ok
<  1945.950> [eFilePushThreadRecorder] THREAD START
<  1945.951> [RecordTimer] start recording on tuner: A
<  1945.952> [RecordTimer] activating state 2
<  1945.952> [eDVBServiceRecord] Recording to /media/hdd/movie/20181002 1148 - ITV London HD - This Morning.ts...
<  1945.953> [eDVBServiceRecord] start recording...
<  1945.953> [eDVBServiceRecord] RECORD: have 1 video stream(s) (0901), and 2 audio stream(s) (0903, 0902) (0905, 0904), and the pcr pid is 0901, and the text pid is 0904
<  1945.953> [eDVBServiceRecord] ADD PID: 0000
<  1945.953> [eDVBServiceRecord] ADD PID: 0102
<  1945.953> [eDVBServiceRecord] ADD PID: 0901
<  1945.953> [eDVBServiceRecord] ADD PID: 0902
<  1945.953> [eDVBServiceRecord] ADD PID: 0903
<  1945.953> [eDVBServiceRecord] ADD PID: 0904
<  1945.953> [eDVBServiceRecord] ADD PID: 0905
<  1945.955> [setIoPrio] realtime level 7 ok
<  1945.955> [eFilePushThreadRecorder] THREAD START
<  1945.956> [RecordTimer] start recording on tuner: D
<  1945.957> [RecordTimer] activating state 2
<  1945.957> [eDVBServiceRecord] Recording to /media/hdd/movie/20181002 1148 - Channel 5 HD - Jeremy Vine.ts...
<  1945.957> [eDVBServiceRecord] start recording...
<  1945.958> [eDVBServiceRecord] RECORD: have 1 video stream(s) (0901), and 2 audio stream(s) (0903, 0902) (0905, 0904), and the pcr pid is 0901, and the text pid is 0904
<  1945.958> [eDVBServiceRecord] ADD PID: 0000
<  1945.958> [eDVBServiceRecord] ADD PID: 0101
<  1945.958> [eDVBServiceRecord] ADD PID: 0901
<  1945.958> [eDVBServiceRecord] ADD PID: 0902
<  1945.958> [eDVBServiceRecord] ADD PID: 0903
<  1945.958> [eDVBServiceRecord] ADD PID: 0904
<  1945.958> [eDVBServiceRecord] ADD PID: 0905
<  1945.959> [setIoPrio] realtime level 7 ok
<  1945.959> [eFilePushThreadRecorder] THREAD START
<  1945.961> [RecordTimer] start recording on tuner: E

[athoik]

Maybe log is noisy, but it seems the extra SLEEP did the job


Now try this one:

diff --git a/lib/dvb/frontend.cpp b/lib/dvb/frontend.cpp
index 30918be..20dedf9 100644
--- a/lib/dvb/frontend.cpp
+++ b/lib/dvb/frontend.cpp
@@ -1583,6 +1583,14 @@ int eDVBFrontend::tuneLoopInt()  // called by m_tuneTimer
                                prev->inc_use();
                        }
                }
+               else if (delay == -1 && sec_fe != this && sec_fe->m_state == stateTuning &&
+                       m_sec_sequence && m_sec_sequence.begin() == m_sec_sequence.current())
+               {
+                       eDebug("[eDVBFrontend] %d linked on %d is also in stateTuning, adding 1000ms SLEEP to avoid collision!", m_dvbid, sec_fe->getDVBID());
+                       m_sec_sequence.push_front(eSecCommand(eSecCommand::SLEEP, 1000)); // need to use m_params from m_sec?
+                       m_sec_sequence.current() = m_sec_sequence.begin();
+                       delay = 0;
+               }
        }

        if ( m_sec_sequence && m_sec_sequence.current() != m_sec_sequence.end() )

Log will be less, less noisy.

[Huevos]

Hi, Athoik,

 

I'll build now, but... maybe I am not understanding something properly.

 

Would it not be helpful if the delay was random? e.g. a random value between 200-1000 milliseconds? That way any repeated commands will be out of sync.

Edited by Huevos, 2 October 2018 - 19:55.

[athoik]

Sure, you can play with the SLEEP command, eg 250 + rand() % 750, will give you numbers from 250 to 999.

But is the 250ms the minimum when another linked tuner currently is in tuning state?

Edited by athoik, 2 October 2018 - 20:20.

[Huevos]

Sure, you can play with the SLEEP command, eg 250 + rand() % 750, will give you numbers from 250 to 999.

But is the 250ms the minimum when another linked tuner currently is in tuning state?

Not sure. The document I posted above (JESS.pdf) says random delay up to 1 second so any collision won't happen on subsequent tries.

[athoik]

Agreed, up to 1s but what is the minimum? 250ms, 75ms ?

Let's start with the fixed 1s and see if it requires more fixes.

Edited by athoik, 2 October 2018 - 21:30.

[Huevos]

Timeslots of 1.0 seconds are repeated, within these slots the repeat should be started by random. The commands are sent out endlessly until the correct signal is received.
This repeat function must also be started if no signal is received at power-up of receiver.

To me that is not clear. How I read that is the time is split into 1 second blocks. The repeat can be sent at any time within that 1 second slot, but no 2 commands can be sent in that same 1 second block. If you implement that randomly your minimum between commands will be 1ms and maximum of 1999 ms.

 

To me that doesn't make sense. To me sending randomly between 200-1000ms would be good, but the the next timeslot should not begin until the whole 1 second timeslot has expired.

Edited by Huevos, 2 October 2018 - 22:09.

[Huevos]

<  1310.488> [RecordTimer] activating state 1
<  1310.489> [RecordTimer] Found enough free space to record
<  1310.490> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181002 2346 - BBC One HD - George Shelley_ Learning to Grieve'
<  1310.490> [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1310.491> [eDVBResourceManager] allocate channel.. 0802:0002
<  1310.491> [eDVBResourceManager] available channel.. 080e:0002
<  1310.491> [eDVBFrontend] opening frontend 0
<  1310.494> [eDVBFrontend] (0)tune
<  1310.494> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<  1310.495> **** Tuning JESS
<  1310.495> **** frequency_mhz: 10847
<  1310.495> **** lo_mhz: 9750
<  1310.495> **** T: 997
<  1310.495> **** position: 0
<  1310.495> **** ub: 0
<  1310.495> **** mode: 0
<  1310.495> **** JESS: 70 03 e5 00
<  1310.495> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1310.495> [eDVBFrontend] prepare_sat System 1 Freq 10847000 Pol 1 SR 23000000 INV 2 FEC 2 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  1310.495> [eDVBFrontend] tuning to 1211 mhz
<  1310.495> [eDVBChannel] OURSTATE: tuning
<  1310.495> [eDVBServicePMTHandler] allocate Channel: res 0
<  1310.495> [eDVBCIInterfaces] addPMTHandler 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1310.495> [eDVBChannel] getDemux cap=00
<  1310.495> [eDVBResourceManager] allocate demux cap=00
<  1310.495> [eDVBResourceManager] allocating demux adapter=0, demux=1, source=-1 fesource=0
<  1310.495> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1310.496> [eEPGCache] saveEventToFile epg event id dea9
<  1310.496> [RecordTimer] prepare ok, waiting for begin
<  1310.498> [RecordTimer] activating state 1
<  1310.499> [Trashcan] probing folders
<  1310.501> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash']
<  1310.501> [Trashcan] looking in trashcan /media/hdd/.Trash
<  1310.501> [Trashcan] /media/hdd/.Trash: Size: 0
<  1310.501> [Trashcan] /media/hdd/.Trash: Size now: 0
<  1310.501> [Trashcan] looking in trashcan /media/hdd/movie/.Trash
<  1310.507> [RecordTimer] Found enough free space to record
<  1310.508> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181002 2346 - ITV London HD - Heathrow_ Britain's Busiest Airport'
<  1310.508> [Navigation] recording service: 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1310.509> [eDVBResourceManager] allocate channel.. 0812:0002
<  1310.509> [eDVBResourceManager] available channel.. 080e:0002
<  1310.509> [eDVBResourceManager] available channel.. 0802:0002
<  1310.509> [eDVBFrontend] opening frontend 3
<  1310.512> [eDVBFrontend] (3)tune
<  1310.512> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  1310.512> **** Tuning JESS
<  1310.512> **** frequency_mhz: 11097
<  1310.512> **** lo_mhz: 9750
<  1310.512> **** T: 1247
<  1310.512> **** position: 0
<  1310.512> **** ub: 1
<  1310.512> **** mode: 0
<  1310.512> **** JESS: 70 0c df 00
<  1310.512> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1310.512> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  1310.512> [eDVBFrontend] tuning to 1421 mhz
<  1310.512> [eDVBChannel] OURSTATE: tuning
<  1310.512> [eDVBServicePMTHandler] allocate Channel: res 0
<  1310.512> [eDVBCIInterfaces] addPMTHandler 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1310.512> [eDVBChannel] getDemux cap=00
<  1310.512> [eDVBResourceManager] allocate demux cap=00
<  1310.512> [eDVBResourceManager] allocating demux adapter=0, demux=2, source=-1 fesource=3
<  1310.512> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1310.513> [eEPGCache] saveEventToFile epg event id 3088
<  1310.514> [RecordTimer] prepare ok, waiting for begin
<  1310.514> [Trashcan] Cleanup already running
<  1310.515> [RecordTimer] activating state 1
<  1310.516> [RecordTimer] Found enough free space to record
<  1310.517> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181002 2346 - Channel 5 HD - New_ Big Brother'
<  1310.517> [Navigation] recording service: 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1310.517> [eDVBResourceManager] allocate channel.. 0809:0002
<  1310.517> [eDVBResourceManager] available channel.. 080e:0002
<  1310.517> [eDVBResourceManager] available channel.. 0802:0002
<  1310.517> [eDVBResourceManager] available channel.. 0812:0002
<  1310.517> [eDVBFrontend] opening frontend 4
<  1310.520> [eDVBFrontend] (4)tune
<  1310.520> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  1310.520> **** Tuning JESS
<  1310.520> **** frequency_mhz: 10964
<  1310.520> **** lo_mhz: 9750
<  1310.520> **** T: 1114
<  1310.520> **** position: 0
<  1310.520> **** ub: 2
<  1310.520> **** mode: 2
<  1310.520> **** JESS: 70 14 5a 02
<  1310.520> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1310.520> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<  1310.520> [eDVBFrontend] tuning to 1681 mhz
<  1310.520> [eDVBChannel] OURSTATE: tuning
<  1310.520> [eDVBServicePMTHandler] allocate Channel: res 0
<  1310.520> [eDVBCIInterfaces] addPMTHandler 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1310.520> [eDVBChannel] getDemux cap=00
<  1310.520> [eDVBResourceManager] allocate demux cap=00
<  1310.520> [eDVBResourceManager] allocating demux adapter=0, demux=3, source=-1 fesource=4
<  1310.520> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1310.521> [eEPGCache] saveEventToFile epg event id 9341
<  1310.521> [RecordTimer] prepare ok, waiting for begin
<  1310.522> [Trashcan] Cleanup already running
<  1310.523> [eDVBFrontend] set static current limiting
<  1310.523> [eDVBFrontend] 3 linked on 0 is also in stateTuning, adding 1000ms SLEEP to avoid collision!
<  1310.523> [eDVBFrontend] sleep 1000ms
<  1310.523> [eDVBFrontend] 4 linked on 3 is also in stateTuning, adding 1000ms SLEEP to avoid collision!
<  1310.523> [eDVBFrontend] sleep 1000ms
<  1310.523> [eDVBFrontend] invalidate current switch params
<  1310.523> [eDVBFrontend] setVoltage 1
<  1310.524> [eDVBFrontend] sleep 1500ms
<  1310.536> [Trashcan] /media/hdd/movie/.Trash: Size: 42350583344
<  1310.564> [Trashcan] /media/hdd/movie/.Trash: Size now: 42350583344
<  1310.565> [Task] job Components.Task.Job name=Cleaning Trashes #tasks=1 completed with [] in None
<  1311.523> [eDVBFrontend] set static current limiting
<  1311.524> [eDVBFrontend] set static current limiting
<  1311.524> [eDVBFrontend] invalidate current switch params
<  1311.524> [eDVBFrontend] invalidate current switch params
<  1311.524> [eDVBFrontend] set sequence pos 3
<  1311.524> [eDVBFrontend] set sequence pos 3
<  1311.524> [eDVBFrontend] setVoltage 2
<  1311.525> [eDVBFrontend] setVoltage 2
<  1311.525> [eDVBFrontend] setTone 0
<  1311.526> [eDVBFrontend] setTone 0
<  1311.527> [eDVBFrontend] sleep 75ms
<  1311.527> [eDVBFrontend] sleep 75ms
<  1311.657> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<  1311.713> [eDVBFrontend] sendDiseqc: 70145a02(?)
<  1311.713> [eDVBFrontend] sleep 100ms
<  1311.713> [eDVBFrontend] sleep 100ms
<  1311.813> [eDVBFrontend] setVoltage 1
<  1311.814> [eDVBFrontend] setVoltage 1
<  1311.815> [eDVBFrontend] update current switch params
<  1311.815> [eDVBFrontend] update current switch params
<  1311.815> [eDVBFrontend] startTuneTimeout 5000
<  1311.815> [eDVBFrontend] startTuneTimeout 5000
<  1311.815> [eDVBFrontend] setFrontend 1
<  1311.815> [eDVBFrontend] setting frontend 3
<  1311.818> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<  1311.818> [eDVBFrontend] setFrontend 1
<  1311.818> [eDVBFrontend] setting frontend 4
<  1311.820> [eDVBFrontend] sleep 500ms
<  1311.821> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<  1311.821> [eDVBFrontend] sleep 500ms
<  1311.860> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<  1311.871> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<  1311.912> [eDVBFrontend] (3)fe event: status 1f, inversion off, m_tuning 3
<  1311.912> [eDVBChannel] OURSTATE: ok
<  1311.912> [eDVBLocalTimerHandler] channel 0x196b908 running
<  1311.912> [eDVBChannel] getDemux cap=00
<  1311.912> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.912> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  1311.913> [eEPGCache] channel 0x196b908 running
<  1311.913> [eDVBChannel] getDemux cap=00
<  1311.913> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.913> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.913> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.913> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.913> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.913> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.914> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.915> [eEPGCache] next update in 2 sec
<  1311.915> [eDVBChannel] getDemux cap=01
<  1311.915> [eDVBResourceManager] allocate demux cap=01
<  1311.915> [eDVBResourceManager] allocating shared demux adapter=0, demux=2, source=3
<  1311.915> [eDVBServicePMTHandler] ok ... now we start!!
<  1311.915> [eDVBServiceRecord] RECORD service event 5
<  1311.915> [eDVBCAService] new service 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1311.915> [eDVBCAService] add demux 2 to slot 0 service 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1311.915> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.916> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1311.916> [eDVBServiceRecord] RECORD service event 6
<  1311.916> [eDVBServiceRecord] tuned..
<  1311.916> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.916> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1311.917> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.917> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1311.918> [eDVBServicePMTHandler] PATready
<  1311.918> [eDVBServicePMTHandler] use pmtpid 0102 for service_id 5208
<  1311.918> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.919> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1311.919> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1311.919> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1311.922> [eDVBFrontend] (4)fe event: status 1f, inversion off, m_tuning 3
<  1311.922> [eDVBChannel] OURSTATE: ok
<  1311.922> [eDVBLocalTimerHandler] channel 0x1941a50 running
<  1311.922> [eDVBChannel] getDemux cap=00
<  1311.922> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.922> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  1311.922> [eEPGCache] channel 0x1941a50 running
<  1311.922> [eDVBChannel] getDemux cap=00
<  1311.922> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.924> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.924> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.924> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.924> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.924> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.924> [eEPGCache] next update in 2 sec
<  1311.924> [eDVBResourceManager] stop release channel timer
<  1311.924> [eDVBChannel] getDemux cap=01
<  1311.924> [eDVBResourceManager] allocate demux cap=01
<  1311.924> [eDVBResourceManager] allocating shared demux adapter=0, demux=3, source=4
<  1311.924> [eDVBServicePMTHandler] ok ... now we start!!
<  1311.924> [eDVBServiceRecord] RECORD service event 5
<  1311.925> [eDVBCAService] new service 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1311.925> [eDVBCAService] add demux 3 to slot 0 service 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1311.925> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.925> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1311.925> [eDVBServiceRecord] RECORD service event 6
<  1311.925> [eDVBServiceRecord] tuned..
<  1311.926> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.926> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1311.926> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1311.926> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1312.024> [eDVBFrontend] setVoltage 2
<  1312.025> [eDVBFrontend] setTone 0
<  1312.026> [eDVBFrontend] sleep 75ms
<  1312.157> [eDVBFrontend] sendDiseqc: 7003e500(?)
<  1312.157> [eDVBServiceRecord] RECORD service event 5
<  1312.158> [eDVBCIInterfaces] gotPMT
<  1312.158> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.159> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1312.160> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.160> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1312.161> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.161> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  1312.162> [eDVBServicePMTHandler] PATready
<  1312.162> [eDVBServicePMTHandler] use pmtpid 0101 for service_id 1e46
<  1312.162> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.162> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1312.163> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.163> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1312.164> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.164> [eDVBSectionReader] DMX_SET_FILTER pid=267
<  1312.164> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.164> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  1312.165> [eDVBFrontend] sleep 100ms
<  1312.265> [eDVBFrontend] setVoltage 1
<  1312.265> [eDVBFrontend] update current switch params
<  1312.265> [eDVBFrontend] startTuneTimeout 5000
<  1312.266> [eDVBFrontend] setFrontend 1
<  1312.266> [eDVBFrontend] setting frontend 0
<  1312.268> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<  1312.268> [eDVBFrontend] sleep 500ms
<  1312.310> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<  1312.320> [eDVBFrontend] set dynamic current limiting
<  1312.321> [eDVBFrontend] set dynamic current limiting
<  1312.322> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.323> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1312.346> [eDVBServiceRecord] RECORD service event 5
<  1312.347> [eDVBCIInterfaces] gotPMT
<  1312.347> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.348> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1312.351> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.351> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1312.361> [eDVBFrontend] (0)fe event: status 1f, inversion off, m_tuning 3
<  1312.361> [eDVBChannel] OURSTATE: ok
<  1312.361> [eDVBLocalTimerHandler] channel 0x1975580 running
<  1312.361> [eDVBChannel] getDemux cap=00
<  1312.362> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.362> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  1312.362> [eEPGCache] channel 0x1975580 running
<  1312.362> [eDVBChannel] getDemux cap=00
<  1312.362> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.362> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.362> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.363> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.364> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.364> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.364> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.364> [eEPGCache] next update in 2 sec
<  1312.364> [eDVBChannel] getDemux cap=01
<  1312.364> [eDVBResourceManager] allocate demux cap=01
<  1312.364> [eDVBResourceManager] allocating shared demux adapter=0, demux=1, source=0
<  1312.364> [eDVBServicePMTHandler] ok ... now we start!!
<  1312.364> [eDVBServiceRecord] RECORD service event 5
<  1312.364> [eDVBCAService] new service 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1312.364> [eDVBCAService] add demux 1 to slot 0 service 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1312.365> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.365> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1312.365> [eDVBServiceRecord] RECORD service event 6
<  1312.365> [eDVBServiceRecord] tuned..
<  1312.365> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.365> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1312.366> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.366> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1312.420> [eDVBServicePMTHandler] PATready
<  1312.420> [eDVBServicePMTHandler] use pmtpid 0104 for service_id 1b1d
<  1312.420> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.421> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1312.421> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.421> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  1312.422> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.422> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  1312.423> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.423> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  1312.453> [eDVBServiceRecord] now running: Heathrow: Britain's... (1800 seconds)
<  1312.454> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.454> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1312.521> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.521> [eDVBSectionReader] DMX_SET_FILTER pid=261
<  1312.549> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.549> [eDVBSectionReader] DMX_SET_FILTER pid=259
<  1312.607> [eDVBServiceRecord] now running: †New: Big Brother‡ (3600 seconds)
<  1312.607> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.608> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1312.705> [eDVBServiceRecord] RECORD service event 5
<  1312.706> [eDVBCIInterfaces] gotPMT
<  1312.707> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.707> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1312.708> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.709> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1312.718> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.719> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  1312.748> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.748> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  1312.769> [eDVBFrontend] set dynamic current limiting
<  1312.906> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1312.906> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  1312.920> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1312.920> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  1312.946> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1312.947> [eDVBSectionReader] DMX_SET_FILTER pid=261
<  1313.024> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1313.024> [eDVBSectionReader] DMX_SET_FILTER pid=259
<  1313.122> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1313.123> [eDVBSectionReader] DMX_SET_FILTER pid=263
<  1313.152> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1313.152> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  1313.238> [eDVBServicePMTHandler] sdt update done!
<  1313.254> [eDVBLocalTimerHandler] diff is 0
<  1313.254> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  1313.254> [eDVBLocalTimerHandler] not changed
<  1313.254> [eDVBChannel] getDemux cap=00
<  1313.304> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1313.304> [eDVBSectionReader] DMX_SET_FILTER pid=264
<  1313.351> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1313.351> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  1313.549> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1313.550> [eDVBSectionReader] DMX_SET_FILTER pid=266
<  1313.604> [eDVBServiceRecord] now running: This Is BBC One HD (900 seconds)
<  1313.604> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1313.605> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.609> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1313.609> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  1313.699> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1313.699> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1313.747> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1313.747> [eDVBSectionReader] DMX_SET_FILTER pid=264
<  1313.870> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1313.871> [eDVBSectionReader] DMX_SET_FILTER pid=263
<  1313.893> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1313.893> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  1313.920> [eEPGCache] start caching events(1538516743)
<  1313.920> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  1313.920> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  1313.920> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.921> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.922> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.923> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1313.947> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1313.949> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1313.949> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1313.950> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  1313.950> [eEPGCache] start caching events(1538516743)
<  1313.950> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  1313.951> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  1313.951> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.952> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.952> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1313.954> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1313.954> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1313.954> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1313.955> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1313.955> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  1314.020> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1314.021> [eDVBSectionReader] DMX_SET_FILTER pid=265
<  1314.031> [eDVBServicePMTHandler] sdt update done!
<  1314.264> [eDVBServicePMTHandler] sdt update done!
<  1314.364> [eEPGCache] start caching events(1538516743)
<  1314.364> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  1314.365> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  1314.365> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1314.366> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1314.367> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  1314.368> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1314.368> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  1314.369> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1314.369> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  1314.370> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  1315.334> [eDVBLocalTimerHandler] diff is 0
<  1315.334> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  1315.334> [eDVBLocalTimerHandler] not changed
<  1315.335> [eDVBChannel] getDemux cap=00
<  1318.450> [eDVBLocalTimerHandler] diff is 0
<  1318.450> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  1318.450> [eDVBLocalTimerHandler] not changed
<  1318.451> [eDVBChannel] getDemux cap=00
<  1320.950> [eEPGCache] abort non avail schedule reading
<  1320.952> [eEPGCache] abort non avail schedule other reading
<  1320.952> [eEPGCache] abort non avail virgin nownext reading
<  1320.953> [eEPGCache] abort non avail virgin schedule reading
<  1320.953> [eEPGCache] abort non avail netmed schedule reading
<  1320.953> [eEPGCache] abort non avail netmed schedule other reading
<  1320.954> [eEPGCache] abort non avail viasat reading
<  1320.955> [eEPGCache] abort non avail schedule reading
<  1320.957> [eEPGCache] abort non avail schedule other reading
<  1320.957> [eEPGCache] abort non avail virgin nownext reading
<  1320.958> [eEPGCache] abort non avail virgin schedule reading
<  1320.958> [eEPGCache] abort non avail netmed schedule reading
<  1320.958> [eEPGCache] abort non avail netmed schedule other reading
<  1320.959> [eEPGCache] abort non avail viasat reading
<  1321.054> [eEPGCache] nownext finished(1538516750)
<  1321.058> [eEPGCache] nownext finished(1538516750)
<  1321.370> [eEPGCache] abort non avail schedule reading
<  1321.372> [eEPGCache] abort non avail schedule other reading
<  1321.372> [eEPGCache] abort non avail virgin nownext reading
<  1321.373> [eEPGCache] abort non avail virgin schedule reading
<  1321.373> [eEPGCache] abort non avail netmed schedule reading
<  1321.373> [eEPGCache] abort non avail netmed schedule other reading
<  1321.374> [eEPGCache] abort non avail viasat reading
<  1321.475> [eEPGCache] nownext finished(1538516750)
<  1330.522> [RecordTimer] activating state 2
<  1330.524> [eDVBServiceRecord] Recording to /media/hdd/movie/20181002 2346 - BBC One HD - George Shelley_ Learning to Grieve.ts...
<  1330.525> [eDVBServiceRecord] start recording...
<  1330.525> [eDVBServiceRecord] RECORD: have 1 video stream(s) (1518), and 2 audio stream(s) (151a, 1519) (151c, 151b), and the pcr pid is 1518, and the text pid is 151b
<  1330.525> [eDVBServiceRecord] ADD PID: 0000
<  1330.525> [eDVBServiceRecord] ADD PID: 0104
<  1330.525> [eDVBServiceRecord] ADD PID: 1518
<  1330.525> [eDVBServiceRecord] ADD PID: 1519
<  1330.525> [eDVBServiceRecord] ADD PID: 151a
<  1330.525> [eDVBServiceRecord] ADD PID: 151b
<  1330.525> [eDVBServiceRecord] ADD PID: 151c
<  1330.527> [setIoPrio] realtime level 7 ok
<  1330.527> [eFilePushThreadRecorder] THREAD START
<  1330.528> [RecordTimer] start recording on tuner: A
<  1330.529> [RecordTimer] activating state 2
<  1330.529> [eDVBServiceRecord] Recording to /media/hdd/movie/20181002 2346 - ITV London HD - Heathrow_ Britain's Busiest Airport.ts...
<  1330.530> [eDVBServiceRecord] start recording...
<  1330.530> [eDVBServiceRecord] RECORD: have 1 video stream(s) (0901), and 2 audio stream(s) (0903, 0902) (0905, 0904), and the pcr pid is 0901, and the text pid is 0904
<  1330.530> [eDVBServiceRecord] ADD PID: 0000
<  1330.530> [eDVBServiceRecord] ADD PID: 0102
<  1330.530> [eDVBServiceRecord] ADD PID: 0901
<  1330.530> [eDVBServiceRecord] ADD PID: 0902
<  1330.530> [eDVBServiceRecord] ADD PID: 0903
<  1330.531> [eDVBServiceRecord] ADD PID: 0904
<  1330.531> [eDVBServiceRecord] ADD PID: 0905
<  1330.532> [setIoPrio] realtime level 7 ok
<  1330.532> [eFilePushThreadRecorder] THREAD START
<  1330.533> [RecordTimer] start recording on tuner: D
<  1330.534> [RecordTimer] activating state 2
<  1330.534> [eDVBServiceRecord] Recording to /media/hdd/movie/20181002 2346 - Channel 5 HD - New_ Big Brother.ts...
<  1330.535> [eDVBServiceRecord] start recording...
<  1330.535> [eDVBServiceRecord] RECORD: have 1 video stream(s) (0901), and 2 audio stream(s) (0903, 0902) (0905, 0904), and the pcr pid is 0901, and the text pid is 0904
<  1330.535> [eDVBServiceRecord] ADD PID: 0000
<  1330.535> [eDVBServiceRecord] ADD PID: 0101
<  1330.535> [eDVBServiceRecord] ADD PID: 0901
<  1330.535> [eDVBServiceRecord] ADD PID: 0902
<  1330.535> [eDVBServiceRecord] ADD PID: 0903
<  1330.535> [eDVBServiceRecord] ADD PID: 0904
<  1330.535> [eDVBServiceRecord] ADD PID: 0905
<  1330.536> [setIoPrio] realtime level 7 ok
<  1330.536> [eFilePushThreadRecorder] THREAD START
<  1330.538> [RecordTimer] start recording on tuner: E

[Huevos]

Agreed, up to 1s but what is the minimum? 250ms, 75ms ?

Let's start with the fixed 1s and see if it requires more fixes.

Here is a picture which I hope makes clear what I was trying to explain. The red dots are the tuning events. The tuning events are completely random within the 1 second time slot... but there can only be 1 dot in any 1 slot.

 

 tune.jpg   14.87KB   0 downloads

 

Also note in my log the whole process of tuning lasted from <  1310.488> to <  1330.538>. That seems like a long time to me, but it did result in successful recordings.

Edited by Huevos, 3 October 2018 - 10:37.

[Huevos]

Agreed, up to 1s but what is the minimum? 250ms, 75ms ?

I think a reasonable minimum for "guard silence" between commands would be 100ms.

[Huevos]

No idea if this is correct code because I am not a CPP coder...

 

I added the rand(). Code here: https://github.com/H...32e3fad865dd973

 

The following is the debug output from that code.

<  4508.005> [RecordTimer] activating state 1
<  4508.006> [RecordTimer] Found enough free space to record
<  4508.007> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181003 1640 - BBC One HD - Escape to the Country'
<  4508.007> [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  4508.007> [eDVBResourceManager] allocate channel.. 0802:0002
<  4508.007> [eDVBResourceManager] available channel.. 080e:0002
<  4508.007> [eDVBFrontend] opening frontend 0
<  4508.011> [eDVBFrontend] (0)tune
<  4508.011> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<  4508.011> **** Tuning JESS
<  4508.011> **** frequency_mhz: 10847
<  4508.011> **** lo_mhz: 9750
<  4508.011> **** T: 997
<  4508.011> **** position: 0
<  4508.011> **** ub: 0
<  4508.011> **** mode: 0
<  4508.011> **** JESS: 70 03 e5 00
<  4508.011> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  4508.011> [eDVBFrontend] prepare_sat System 1 Freq 10847000 Pol 1 SR 23000000 INV 2 FEC 2 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  4508.011> [eDVBFrontend] tuning to 1211 mhz
<  4508.011> [eDVBChannel] OURSTATE: tuning
<  4508.011> [eDVBServicePMTHandler] allocate Channel: res 0
<  4508.011> [eDVBCIInterfaces] addPMTHandler 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  4508.011> [eDVBChannel] getDemux cap=00
<  4508.011> [eDVBResourceManager] allocate demux cap=00
<  4508.011> [eDVBResourceManager] allocating demux adapter=0, demux=1, source=-1 fesource=0
<  4508.012> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4508.305> [eEPGCache] saveEventToFile epg event id d67e
<  4508.306> [RecordTimer] prepare ok, waiting for begin
<  4508.307> [Trashcan] probing folders
<  4508.310> [RecordTimer] activating state 1
<  4508.311> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash']
<  4508.311> [Trashcan] looking in trashcan /media/hdd/.Trash
<  4508.312> [RecordTimer] Found enough free space to record
<  4508.313> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181003 1640 - ITV London HD - New_ Tenable'
<  4508.313> [Navigation] recording service: 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  4508.313> [eDVBResourceManager] allocate channel.. 0812:0002
<  4508.313> [eDVBResourceManager] available channel.. 080e:0002
<  4508.313> [eDVBResourceManager] available channel.. 0802:0002
<  4508.313> [eDVBFrontend] opening frontend 3
<  4508.316> [eDVBFrontend] (3)tune
<  4508.316> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  4508.316> **** Tuning JESS
<  4508.316> **** frequency_mhz: 11097
<  4508.316> **** lo_mhz: 9750
<  4508.316> **** T: 1247
<  4508.316> **** position: 0
<  4508.316> **** ub: 1
<  4508.316> **** mode: 0
<  4508.316> **** JESS: 70 0c df 00
<  4508.316> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  4508.316> [eDVBFrontend] prepare_sat System 1 Freq 11097000 Pol 1 SR 23000000 INV 2 FEC 3 orbpos 282 system 1 modulation 2 pilot 2, rolloff 1, is_id -1, pls_mode 1, pls_code 0
<  4508.316> [eDVBFrontend] tuning to 1421 mhz
<  4508.316> [eDVBChannel] OURSTATE: tuning
<  4508.316> [eDVBServicePMTHandler] allocate Channel: res 0
<  4508.316> [eDVBCIInterfaces] addPMTHandler 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  4508.316> [eDVBChannel] getDemux cap=00
<  4508.316> [eDVBResourceManager] allocate demux cap=00
<  4508.316> [eDVBResourceManager] allocating demux adapter=0, demux=2, source=-1 fesource=3
<  4508.316> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4508.317> [eEPGCache] saveEventToFile epg event id 80f7
<  4508.317> [RecordTimer] prepare ok, waiting for begin
<  4508.318> [Trashcan] Cleanup already running
<  4508.318> [RecordTimer] activating state 1
<  4508.319> [Trashcan] /media/hdd/.Trash: Size: 0
<  4508.319> [Trashcan] /media/hdd/.Trash: Size now: 0
<  4508.319> [Trashcan] looking in trashcan /media/hdd/movie/.Trash
<  4508.321> [RecordTimer] Found enough free space to record
<  4508.322> [RecordTimer] Filename calculated as: '/media/hdd/movie/20181003 1640 - Channel 5 HD - The Neighbourhood Nightmare'
<  4508.322> [Navigation] recording service: 1:0:19:1E46:809:2:11A0000:0:0:0:
<  4508.322> [eDVBResourceManager] allocate channel.. 0809:0002
<  4508.322> [eDVBResourceManager] available channel.. 080e:0002
<  4508.322> [eDVBResourceManager] available channel.. 0802:0002
<  4508.322> [eDVBResourceManager] available channel.. 0812:0002
<  4508.322> [eDVBFrontend] opening frontend 4
<  4508.332> [eDVBFrontend] (4)tune
<  4508.332> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  4508.332> **** Tuning JESS
<  4508.332> **** frequency_mhz: 10964
<  4508.332> **** lo_mhz: 9750
<  4508.332> **** T: 1114
<  4508.332> **** position: 0
<  4508.332> **** ub: 2
<  4508.332> **** mode: 2
<  4508.332> **** JESS: 70 14 5a 02
<  4508.332> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  4508.332> [eDVBFrontend] prepare_sat System 0 Freq 10964250 Pol 0 SR 22000000 INV 2 FEC 4 orbpos 282 system 0 modulation 1 pilot 2, rolloff 0, is_id -1, pls_mode 1, pls_code 0
<  4508.332> [eDVBFrontend] tuning to 1681 mhz
<  4508.332> [eDVBChannel] OURSTATE: tuning
<  4508.332> [eDVBServicePMTHandler] allocate Channel: res 0
<  4508.332> [eDVBCIInterfaces] addPMTHandler 1:0:19:1E46:809:2:11A0000:0:0:0:
<  4508.332> [eDVBChannel] getDemux cap=00
<  4508.332> [eDVBResourceManager] allocate demux cap=00
<  4508.332> [eDVBResourceManager] allocating demux adapter=0, demux=3, source=-1 fesource=4
<  4508.332> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.333> [eEPGCache] saveEventToFile epg event id 9364
<  4508.333> [RecordTimer] prepare ok, waiting for begin
<  4508.334> [Trashcan] Cleanup already running
<  4508.335> [eDVBFrontend] set static current limiting
<  4508.335> [eDVBFrontend] 3 linked on 0 is also in stateTuning, adding 351ms SLEEP to avoid collision!
<  4508.335> [eDVBFrontend] sleep 351ms
<  4508.335> [eDVBFrontend] 4 linked on 3 is also in stateTuning, adding 219ms SLEEP to avoid collision!
<  4508.335> [eDVBFrontend] sleep 219ms
<  4508.335> [eDVBFrontend] invalidate current switch params
<  4508.335> [eDVBFrontend] setVoltage 1
<  4508.336> [eDVBFrontend] sleep 1500ms
<  4508.348> [Trashcan] /media/hdd/movie/.Trash: Size: 49149609300
<  4508.362> [setIoPrio] best-effort level 7 ok
<  4508.362> [eBackgroundFileEraser] deleting '/media/hdd/movie/.Trash/20180924 0427 - Extreme Sports_ - Drag Racing_ NHRA Sportsman Series.ts.ap.del'
<  4508.363> [eBackgroundFileEraser] deleting '/media/hdd/movie/.Trash/20180925 0045 - Channel 5 HD - New_ Big Brother's Bit On The___.ts.meta.del'
<  4508.374> [eBackgroundFileEraser] deleting '/media/hdd/movie/.Trash/20180925 0045 - BBC One HD - Segregated America_ A School in the___.ts.meta.del'
<  4508.374> [eBackgroundFileEraser] deleting '/media/hdd/movie/.Trash/20180924 1057 - Extreme Sports_ - Drag Racing_ NHRA Sportsman Series.ts.cuts.del'
<  4508.374> [eBackgroundFileEraser] deleting '/media/hdd/movie/.Trash/20180924 0427 - Extreme Sports_ - Drag Racing_ NHRA Sportsman Series.ts.del'
<  4508.384> [Trashcan] /media/hdd/movie/.Trash: Size now: 41655338032
<  4508.386> [Task] job Components.Task.Job name=Cleaning Trashes #tasks=1 completed with [] in None
<  4508.554> [eDVBFrontend] set static current limiting
<  4508.554> [eDVBFrontend] invalidate current switch params
<  4508.555> [eDVBFrontend] set sequence pos 3
<  4508.555> [eDVBFrontend] setVoltage 2
<  4508.555> [eDVBFrontend] setTone 0
<  4508.556> [eDVBFrontend] sleep 75ms
<  4508.687> [eDVBFrontend] sendDiseqc: 70145a02(?)
<  4508.687> [eDVBFrontend] set static current limiting
<  4508.687> [eDVBFrontend] sleep 100ms
<  4508.687> [eDVBFrontend] invalidate current switch params
<  4508.687> [eDVBFrontend] set sequence pos 3
<  4508.687> [eDVBFrontend] setVoltage 2
<  4508.688> [eDVBFrontend] setTone 0
<  4508.688> [eDVBFrontend] sleep 75ms
<  4508.819> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<  4508.819> [eDVBFrontend] setVoltage 1
<  4508.820> [eDVBFrontend] sleep 100ms
<  4508.820> [eDVBFrontend] update current switch params
<  4508.820> [eDVBFrontend] startTuneTimeout 5000
<  4508.820> [eDVBFrontend] setFrontend 1
<  4508.820> [eDVBFrontend] setting frontend 4
<  4508.874> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<  4508.875> [eDVBFrontend] sleep 500ms
<  4508.920> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<  4508.920> [eDVBFrontend] setVoltage 1
<  4508.922> [eDVBFrontend] update current switch params
<  4508.922> [eDVBFrontend] startTuneTimeout 5000
<  4508.922> [eDVBFrontend] setFrontend 1
<  4508.922> [eDVBFrontend] setting frontend 3
<  4508.925> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<  4508.925> [eDVBFrontend] sleep 500ms
<  4508.970> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<  4508.972> [eDVBFrontend] (4)fe event: status 1f, inversion off, m_tuning 3
<  4508.972> [eDVBChannel] OURSTATE: ok
<  4508.972> [eDVBLocalTimerHandler] channel 0x19706c0 running
<  4508.972> [eDVBChannel] getDemux cap=00
<  4508.972> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.972> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  4508.973> [eEPGCache] channel 0x19706c0 running
<  4508.973> [eDVBChannel] getDemux cap=00
<  4508.973> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.973> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.973> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.973> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.973> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.974> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.975> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.975> [eEPGCache] next update in 2 sec
<  4508.975> [eDVBResourceManager] stop release channel timer
<  4508.975> [eDVBChannel] getDemux cap=01
<  4508.975> [eDVBResourceManager] allocate demux cap=01
<  4508.975> [eDVBResourceManager] allocating shared demux adapter=0, demux=3, source=4
<  4508.975> [eDVBServicePMTHandler] ok ... now we start!!
<  4508.975> [eDVBServiceRecord] RECORD service event 5
<  4508.975> [eDVBCAService] new service 1:0:19:1E46:809:2:11A0000:0:0:0:
<  4508.975> [eDVBCAService] add demux 3 to slot 0 service 1:0:19:1E46:809:2:11A0000:0:0:0:
<  4508.975> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.976> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4508.976> [eDVBServiceRecord] RECORD service event 6
<  4508.976> [eDVBServiceRecord] tuned..
<  4508.976> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.976> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4508.977> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4508.977> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4509.021> [eDVBFrontend] (3)fe event: status 1f, inversion off, m_tuning 3
<  4509.021> [eDVBChannel] OURSTATE: ok
<  4509.021> [eDVBLocalTimerHandler] channel 0x18963a0 running
<  4509.021> [eDVBChannel] getDemux cap=00
<  4509.021> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.022> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  4509.022> [eEPGCache] channel 0x18963a0 running
<  4509.022> [eDVBChannel] getDemux cap=00
<  4509.022> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.022> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.023> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.024> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.024> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.024> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.024> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.024> [eEPGCache] next update in 2 sec
<  4509.024> [eDVBChannel] getDemux cap=01
<  4509.024> [eDVBResourceManager] allocate demux cap=01
<  4509.024> [eDVBResourceManager] allocating shared demux adapter=0, demux=2, source=3
<  4509.024> [eDVBServicePMTHandler] ok ... now we start!!
<  4509.024> [eDVBServiceRecord] RECORD service event 5
<  4509.025> [eDVBCAService] new service 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  4509.025> [eDVBCAService] add demux 2 to slot 0 service 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  4509.025> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.025> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4509.025> [eDVBServiceRecord] RECORD service event 6
<  4509.025> [eDVBServiceRecord] tuned..
<  4509.025> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.025> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4509.026> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.026> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4509.111> [eDVBServicePMTHandler] PATready
<  4509.111> [eDVBServicePMTHandler] use pmtpid 0102 for service_id 5208
<  4509.111> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.112> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  4509.112> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.112> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4509.113> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.114> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  4509.114> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.115> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  4509.127> [eDVBServicePMTHandler] PATready
<  4509.127> [eDVBServicePMTHandler] use pmtpid 0101 for service_id 1e46
<  4509.127> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.127> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  4509.127> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.128> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4509.129> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.129> [eDVBSectionReader] DMX_SET_FILTER pid=267
<  4509.129> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.129> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  4509.166> [eDVBLocalTimerHandler] diff is 0
<  4509.166> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  4509.166> [eDVBLocalTimerHandler] not changed
<  4509.166> [eDVBChannel] getDemux cap=00
<  4509.244> [eDVBServiceRecord] now running: The †Neighbourhood Nightmare‡ (6300 seconds)
<  4509.244> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.244> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4509.316> [eDVBServiceRecord] RECORD service event 5
<  4509.317> [eDVBCIInterfaces] gotPMT
<  4509.317> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.318> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  4509.319> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.319> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  4509.328> [eDVBServiceRecord] RECORD service event 5
<  4509.329> [eDVBCIInterfaces] gotPMT
<  4509.329> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.329> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  4509.333> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.333> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  4509.373> [eDVBLocalTimerHandler] diff is 0
<  4509.373> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  4509.373> [eDVBLocalTimerHandler] not changed
<  4509.373> [eDVBChannel] getDemux cap=00
<  4509.375> [eDVBFrontend] set dynamic current limiting
<  4509.425> [eDVBFrontend] set dynamic current limiting
<  4509.515> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.515> [eDVBSectionReader] DMX_SET_FILTER pid=261
<  4509.531> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.531> [eDVBSectionReader] DMX_SET_FILTER pid=259
<  4509.713> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.713> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  4509.730> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.730> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  4509.776> [eDVBServiceRecord] now running: New: †Tenable‡ (3600 seconds)
<  4509.777> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.777> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4509.836> [eDVBFrontend] setVoltage 2
<  4509.837> [eDVBFrontend] setTone 0
<  4509.838> [eDVBFrontend] sleep 75ms
<  4509.968> [eDVBFrontend] sendDiseqc: 7003e500(?)
<  4509.969> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  4509.969> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  4509.970> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4509.971> [eDVBSectionReader] DMX_SET_FILTER pid=261
<  4509.971> [eDVBFrontend] sleep 100ms
<  4510.071> [eDVBFrontend] setVoltage 1
<  4510.072> [eDVBFrontend] update current switch params
<  4510.072> [eDVBFrontend] startTuneTimeout 5000
<  4510.072> [eDVBFrontend] setFrontend 1
<  4510.072> [eDVBFrontend] setting frontend 0
<  4510.075> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<  4510.075> [eDVBFrontend] sleep 500ms
<  4510.103> [eDVBServicePMTHandler] sdt update done!
<  4510.120> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<  4510.134> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4510.135> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  4510.172> [eDVBFrontend] (0)fe event: status 1f, inversion off, m_tuning 3
<  4510.172> [eDVBChannel] OURSTATE: ok
<  4510.172> [eDVBLocalTimerHandler] channel 0x196d570 running
<  4510.172> [eDVBChannel] getDemux cap=00
<  4510.172> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.172> [eDVBSectionReader] DMX_SET_FILTER pid=20
<  4510.172> [eEPGCache] channel 0x196d570 running
<  4510.172> [eDVBChannel] getDemux cap=00
<  4510.172> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.173> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.173> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.173> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.173> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.173> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.173> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.174> [eEPGCache] next update in 2 sec
<  4510.175> [eDVBChannel] getDemux cap=01
<  4510.175> [eDVBResourceManager] allocate demux cap=01
<  4510.175> [eDVBResourceManager] allocating shared demux adapter=0, demux=1, source=0
<  4510.175> [eDVBServicePMTHandler] ok ... now we start!!
<  4510.175> [eDVBServiceRecord] RECORD service event 5
<  4510.175> [eDVBCAService] new service 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  4510.175> [eDVBCAService] add demux 1 to slot 0 service 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  4510.175> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.175> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4510.176> [eDVBServiceRecord] RECORD service event 6
<  4510.176> [eDVBServiceRecord] tuned..
<  4510.176> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.176> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4510.176> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.177> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4510.212> [eDVBServicePMTHandler] PATready
<  4510.212> [eDVBServicePMTHandler] use pmtpid 0104 for service_id 1b1d
<  4510.212> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.213> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  4510.213> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.213> [eDVBSectionReader] DMX_SET_FILTER pid=0
<  4510.214> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.215> [eDVBSectionReader] DMX_SET_FILTER pid=258
<  4510.215> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.215> [eDVBSectionReader] DMX_SET_FILTER pid=17
<  4510.334> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4510.334> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  4510.489> [eDVBServiceRecord] RECORD service event 5
<  4510.490> [eDVBCIInterfaces] gotPMT
<  4510.490> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.491> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  4510.492> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.492> [eDVBSectionReader] DMX_SET_FILTER pid=260
<  4510.532> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4510.532> [eDVBSectionReader] DMX_SET_FILTER pid=266
<  4510.575> [eDVBFrontend] set dynamic current limiting
<  4510.689> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.690> [eDVBSectionReader] DMX_SET_FILTER pid=256
<  4510.729> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  4510.730> [eDVBSectionReader] DMX_SET_FILTER pid=264
<  4510.773> [eDVBServicePMTHandler] sdt update done!
<  4510.816> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.816> [eDVBSectionReader] DMX_SET_FILTER pid=259
<  4510.923> [eDVBServiceRecord] now running: †Escape to the Country‡ (2700 seconds)
<  4510.923> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4510.923> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4510.979> [eEPGCache] start caching events(1538577584)
<  4510.979> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  4510.979> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  4510.980> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4510.980> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4510.981> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4510.982> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  4510.983> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  4510.983> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  4510.984> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  4510.984> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  4511.024> [eEPGCache] start caching events(1538577584)
<  4511.024> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  4511.025> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  4511.025> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4511.050> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4511.051> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4511.052> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  4511.053> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  4511.053> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  4511.053> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  4511.054> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  4511.088> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4511.089> [eDVBSectionReader] DMX_SET_FILTER pid=264
<  4511.393> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4511.393> [eDVBSectionReader] DMX_SET_FILTER pid=262
<  4511.492> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4511.492> [eDVBSectionReader] DMX_SET_FILTER pid=257
<  4511.663> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4511.664> [eDVBSectionReader] DMX_SET_FILTER pid=263
<  4511.813> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  4511.813> [eDVBSectionReader] DMX_SET_FILTER pid=265
<  4511.905> [eDVBServicePMTHandler] sdt update done!
<  4512.175> [eEPGCache] start caching events(1538577585)
<  4512.175> [eDVBSectionReader] DMX_SET_FILTER pid=3842
<  4512.175> [eDVBSectionReader] DMX_SET_FILTER pid=3003
<  4512.175> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4512.176> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4512.177> [eDVBSectionReader] DMX_SET_FILTER pid=18
<  4512.178> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  4512.178> [eDVBSectionReader] DMX_SET_FILTER pid=700
<  4512.179> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  4512.179> [eDVBSectionReader] DMX_SET_FILTER pid=5000
<  4512.180> [eDVBSectionReader] DMX_SET_FILTER pid=57
<  4517.984> [eEPGCache] abort non avail schedule reading
<  4517.986> [eEPGCache] abort non avail schedule other reading
<  4517.987> [eEPGCache] abort non avail virgin nownext reading
<  4517.987> [eEPGCache] abort non avail virgin schedule reading
<  4517.988> [eEPGCache] abort non avail netmed schedule reading
<  4517.988> [eEPGCache] abort non avail netmed schedule other reading
<  4517.988> [eEPGCache] abort non avail viasat reading
<  4518.013> [eEPGCache] nownext finished(1538577591)
<  4518.054> [eEPGCache] abort non avail schedule reading
<  4518.056> [eEPGCache] abort non avail schedule other reading
<  4518.056> [eEPGCache] abort non avail virgin nownext reading
<  4518.057> [eEPGCache] abort non avail virgin schedule reading
<  4518.057> [eEPGCache] abort non avail netmed schedule reading
<  4518.057> [eEPGCache] abort non avail netmed schedule other reading
<  4518.057> [eEPGCache] abort non avail viasat reading
<  4518.162> [eEPGCache] nownext finished(1538577591)
<  4519.133> [eDVBLocalTimerHandler] diff is 0
<  4519.134> [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
<  4519.134> [eDVBLocalTimerHandler] not changed
<  4519.134> [eDVBChannel] getDemux cap=00
<  4519.181> [eEPGCache] abort non avail schedule reading
<  4519.182> [eEPGCache] abort non avail schedule other reading
<  4519.183> [eEPGCache] abort non avail virgin nownext reading
<  4519.183> [eEPGCache] abort non avail virgin schedule reading
<  4519.183> [eEPGCache] abort non avail netmed schedule reading
<  4519.184> [eEPGCache] abort non avail netmed schedule other reading
<  4519.184> [eEPGCache] abort non avail viasat reading
<  4519.270> [eEPGCache] nownext finished(1538577592)
<  4527.192> [RecordTimer] activating state 2
<  4527.194> [eDVBServiceRecord] Recording to /media/hdd/movie/20181003 1640 - BBC One HD - Escape to the Country.ts...
<  4527.195> [eDVBServiceRecord] start recording...
<  4527.195> [eDVBServiceRecord] RECORD: have 1 video stream(s) (1518), and 2 audio stream(s) (151a, 1519) (151c, 151b), and the pcr pid is 1518, and the text pid is 151b
<  4527.195> [eDVBServiceRecord] ADD PID: 0000
<  4527.195> [eDVBServiceRecord] ADD PID: 0104
<  4527.195> [eDVBServiceRecord] ADD PID: 1518
<  4527.195> [eDVBServiceRecord] ADD PID: 1519
<  4527.195> [eDVBServiceRecord] ADD PID: 151a
<  4527.195> [eDVBServiceRecord] ADD PID: 151b
<  4527.195> [eDVBServiceRecord] ADD PID: 151c
<  4527.196> [setIoPrio] realtime level 7 ok
<  4527.196> [eFilePushThreadRecorder] THREAD START
<  4527.198> [RecordTimer] start recording on tuner: A
<  4527.199> [RecordTimer] activating state 2
<  4527.199> [eDVBServiceRecord] Recording to /media/hdd/movie/20181003 1640 - ITV London HD - New_ Tenable.ts...
<  4527.200> [eDVBServiceRecord] start recording...
<  4527.200> [eDVBServiceRecord] RECORD: have 1 video stream(s) (0901), and 2 audio stream(s) (0903, 0902) (0905, 0904), and the pcr pid is 0901, and the text pid is 0904
<  4527.200> [eDVBServiceRecord] ADD PID: 0000
<  4527.200> [eDVBServiceRecord] ADD PID: 0102
<  4527.200> [eDVBServiceRecord] ADD PID: 0901
<  4527.200> [eDVBServiceRecord] ADD PID: 0902
<  4527.200> [eDVBServiceRecord] ADD PID: 0903
<  4527.200> [eDVBServiceRecord] ADD PID: 0904
<  4527.200> [eDVBServiceRecord] ADD PID: 0905
<  4527.202> [setIoPrio] realtime level 7 ok
<  4527.202> [eFilePushThreadRecorder] THREAD START
<  4527.203> [RecordTimer] start recording on tuner: D
<  4527.204> [RecordTimer] activating state 2
<  4527.204> [eDVBServiceRecord] Recording to /media/hdd/movie/20181003 1640 - Channel 5 HD - The Neighbourhood Nightmare.ts...
<  4527.205> [eDVBServiceRecord] start recording...
<  4527.205> [eDVBServiceRecord] RECORD: have 1 video stream(s) (0901), and 2 audio stream(s) (0903, 0902) (0905, 0904), and the pcr pid is 0901, and the text pid is 0904
<  4527.205> [eDVBServiceRecord] ADD PID: 0000
<  4527.205> [eDVBServiceRecord] ADD PID: 0101
<  4527.205> [eDVBServiceRecord] ADD PID: 0901
<  4527.205> [eDVBServiceRecord] ADD PID: 0902
<  4527.205> [eDVBServiceRecord] ADD PID: 0903
<  4527.205> [eDVBServiceRecord] ADD PID: 0904
<  4527.205> [eDVBServiceRecord] ADD PID: 0905
<  4527.206> [setIoPrio] realtime level 7 ok
<  4527.206> [eFilePushThreadRecorder] THREAD START
<  4527.208> [RecordTimer] start recording on tuner: E

Just to avoid confusion... this... <  4508.335> [eDVBFrontend] setVoltage 1, <  4508.336> [eDVBFrontend] sleep 1500ms is config.sec.delay_after_enable_voltage_before_switch_command to allow the LNB to boot from cold state.

[athoik]

Looks good to me.

What others are saying for the C++ patch?

@pieterg, @erik, @betacentauri, @littlesat review final patch (with rand delay 100-999 ms).

[Huevos]

For the bug this code seems to cure it but I am going to ask a few other people with affected equipment to test.

But, for fear of going off topic...

What happens when the tuners are not linked? e.g. 2 STBs sharing the same unicable LNB? If there is a collision and the retry interval is fixed length the collision will continue forever. Anyway just theoretical.

[Abu Baniaz]

This did not work for me on the solo 4k on your image. I flashed yesterday's afternoon image last night, I update it this morning and scheduled simultaneous recordings for BBC One HD and Ch5 HD. Waking box from standby resulted in a tune failed on both services. Cancelling one recording caused the other service to start working.

Attached Files

•  Enigma2_debug_2018-10-04_08-32-57.log   386.31KB   1 downloads

Edited by Abu Baniaz, 4 October 2018 - 08:59.

[Erik Slagter]

 

 

If that is already the case, it shouldn't be too difficult to add a delay before processing the next command in the code, ideally based on both a config item (diseqc delay yes/no) and the unicable/jess code puting a "delay command" in the queue?

Which I am already telling over and over, is functionality that is already included, for ages. You just need to install the "DiSEqC delay" plugin which let's you control the various delays. The in enigma is already there. If that appears to be the solution, someone could make a specific plugin for this case.

 

Which DiSEqC delay relates to SCR commands that are sent from different tuners over the same cable?

 

https://github.com/O....py#L1088-L1105

Good question, I don't know. I'd say, let's try