342 replies to this topic

[Huevos]

Transponders being tuned are 10847 V and 10964 H. These frequencies correspond to the services being recorded.

The IFs being tuned are 1211 MHz and 1421 MHz. This corresponds with SCR1 and SCR2 of my LNB.

So to me those look correct in the log excert posted above.

Sorry if I have not understood the question.

[Huevos]

BTW, my LNB is 32 channel so definitely JESS.

[Rob van der Does]

So my first question is here, when does this problem appear, is it with Unicable, JESS, or both?

As I said before: I've always encountered this problem, using a simple 4-SCR Inverto Unicable LNB (IDLP-40UNIQD+S). I use that one since I have the DUO, so years ago.
But: the issue didn't/doesn't always show, but say in around 30% of the times of simultaneous starting recordings.

I always record the 07.00 & 08.00 news from RTL4 and NPO1 (two different transponders on 23.5E); that's where I first noticed the issue of one of the two having a 'zero length' recording. Work-around is starting one of the two a minute earlier.

 

BTW:

1- This setup has another (probably not related) issue: if a recording is active, there will be a 'glitch' the moment a recording starts on the second tuner.

2- Changing STB/LNB/image (PLi/ViX/ATV) never made any difference for these issues.

 

 

PS: atm I can't test anything around this issue, as I'm not near this set-up.

[littlesat]

Here are indeed things that can be cleaned there regarding unicable as there is still a lot of redundant code there.

[Huevos]

Just because some people can't reproduce the bug with their specific hardware doesn't mean other hardware is to blame. Is it really correct to send 2 comands to the LNB just 1 milli-second apart. I doubt it, even if some devices can cope with that.

 

How/where can a command queue be added to stop the commands being sent on top of each other?

Edited by Huevos, 21 September 2018 - 12:30.

[WanWizard]

Unfortunately, my theoretical base is a lot better than my C and Python skills. So I know the best way to solve it, but I lack the knowledge to do so myself....

[ccs]

Maybe the process setting up the recording timer queue could add an extra few seconds if timers are found with the same start time?

 

Probably nothing like how it really works, but just a thought.

 

No need to go near the LNB then.

Edited by ccs, 21 September 2018 - 17:53.

[Pr2]

It is not the timer that need to fix it, a FIFO queue is needed to be set to send all the commands to the LNB with a small delay.

[Huevos]

Erik, what STB are you using?

[athoik]

Can you try that patch?

diff --git a/lib/dvb/frontend.cpp b/lib/dvb/frontend.cpp
index 30918be..5e60a3c 100644
--- a/lib/dvb/frontend.cpp
+++ b/lib/dvb/frontend.cpp
@@ -2324,6 +2324,7 @@ RESULT eDVBFrontend::prepare_sat(const eDVBFrontendParametersSatellite &feparm,
                eWarning("[eDVBFrontend] no SEC module active!");
                return -ENOENT;
        }
+       eSingleLocker s(lock);
        res = m_sec->prepare(*this, feparm, satfrequency, 1 << m_slotid, tunetimeout);
        if (!res)
        {
diff --git a/lib/dvb/frontend.h b/lib/dvb/frontend.h
index 46228c1..d64fe1a 100644
--- a/lib/dvb/frontend.h
+++ b/lib/dvb/frontend.h
@@ -6,6 +6,7 @@
 #endif

 #include <map>
+#include <lib/base/elock.h>
 #include <lib/dvb/idvb.h>
 #include <lib/dvb/frontendparms.h>

@@ -127,6 +128,8 @@ private:

        static int PriorityOrder;
        static int PreferredFrontendIndex;
+
+       eSingleLock lock;
 public:
        eDVBFrontend(const char *devidenodename, int fe, int &ok, bool simulate=false, eDVBFrontend *simulate_fe=NULL);
        virtual ~eDVBFrontend();

It will try to lock access to prepare command, so each command will executed sequentially.

(at least that is what I understand as the problem, some kind of racing).

[Huevos]

Thanks Athoik,

 

Patch didn't work for me. https://github.com/H...c26b51370cd307e

 

Started 3 simultaneous recordings. All 3 were zero length.

 

So far bug shows on Vu Solo 4K, Vu Ultimo 4K, GB UE 4K, using Inverto and Gsat LNBs.

<  1155.812> [RecordTimer] activating state 1
<  1155.813> [RecordTimer] Found enough free space to record
<  1155.814> [RecordTimer] Filename calculated as: '/media/hdd/movie/20180923 0041 - BBC One HD - Match of the Day'
<  1155.814> [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1155.814> [eDVBResourceManager] allocate channel.. 0802:0002
<  1155.814> [eDVBResourceManager] available channel.. 080e:0002
<  1155.814> [eDVBFrontend] opening frontend 0
<  1155.818> [eDVBFrontend] (0)tune
<  1155.818> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<  1155.818> **** Tuning JESS
<  1155.818> **** frequency_mhz: 10847
<  1155.818> **** lo_mhz: 9750
<  1155.818> **** T: 997
<  1155.818> **** position: 0
<  1155.818> **** ub: 0
<  1155.818> **** mode: 0
<  1155.818> **** JESS: 70 03 e5 00
<  1155.818> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1155.818> [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
<  1155.818> [eDVBFrontend] tuning to 1211 mhz
<  1155.818> [eDVBChannel] OURSTATE: tuning
<  1155.818> [eDVBServicePMTHandler] allocate Channel: res 0
<  1155.818> [eDVBCIInterfaces] addPMTHandler 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1155.818> [eDVBChannel] getDemux cap=00
<  1155.819> [eDVBResourceManager] allocate demux cap=00
<  1155.819> [eDVBResourceManager] allocating demux adapter=0, demux=1, source=0 fesource=0
<  1155.819> [eDVBDemux] open demux /dev/dvb/adapter0/demux1
<  1155.819> [eEPGCache] saveEventToFile epg event id c746
<  1155.820> [RecordTimer] prepare ok, waiting for begin
<  1155.821> [Trashcan] probing folders
<  1155.823> [Trashcan] found following trashcan's: ['/media/hdd/.Trash', '/media/hdd/movie/.Trash']
<  1155.824> [Trashcan] looking in trashcan /media/hdd/.Trash
<  1155.824> [Trashcan] /media/hdd/.Trash: Size: 0
<  1155.824> [Trashcan] /media/hdd/.Trash: Size now: 0
<  1155.824> [Trashcan] looking in trashcan /media/hdd/movie/.Trash
<  1155.827> [RecordTimer] activating state 1
<  1155.829> [RecordTimer] Found enough free space to record
<  1155.829> [RecordTimer] Filename calculated as: '/media/hdd/movie/20180923 0041 - ITV London HD - Van Helsing'
<  1155.829> [Navigation] recording service: 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1155.830> [eDVBResourceManager] allocate channel.. 0812:0002
<  1155.830> [eDVBResourceManager] available channel.. 080e:0002
<  1155.830> [eDVBResourceManager] available channel.. 0802:0002
<  1155.830> [eDVBFrontend] opening frontend 3
<  1155.832> [eDVBFrontend] (3)tune
<  1155.832> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  1155.832> **** Tuning JESS
<  1155.832> **** frequency_mhz: 11097
<  1155.832> **** lo_mhz: 9750
<  1155.832> **** T: 1247
<  1155.832> **** position: 0
<  1155.832> **** ub: 1
<  1155.832> **** mode: 0
<  1155.832> **** JESS: 70 0c df 00
<  1155.832> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1155.832> [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
<  1155.832> [eDVBFrontend] tuning to 1421 mhz
<  1155.832> [eDVBChannel] OURSTATE: tuning
<  1155.832> [eDVBServicePMTHandler] allocate Channel: res 0
<  1155.833> [eDVBCIInterfaces] addPMTHandler 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1155.833> [eDVBChannel] getDemux cap=00
<  1155.833> [eDVBResourceManager] allocate demux cap=00
<  1155.833> [eDVBResourceManager] allocating demux adapter=0, demux=2, source=4 fesource=3
<  1155.833> [eDVBDemux] open demux /dev/dvb/adapter0/demux2
<  1155.833> [eEPGCache] saveEventToFile epg event id 398
<  1155.834> [RecordTimer] prepare ok, waiting for begin
<  1155.835> [RecordTimer] prepare ok, waiting for begin
 [Trashcan] /media/hdd/movie/.Trash: Size: 11823690824
<  1155.840> [Trashcan] Cleanup already running
<  1155.841> [RecordTimer] activating state 1
<  1155.842> [RecordTimer] Found enough free space to record
<  1155.842> [RecordTimer] Filename calculated as: '/media/hdd/movie/20180923 0041 - Channel 5 HD - Shrunken Heads Of The Amazon'
<  1155.843> [Navigation] recording service: 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1155.843> [eDVBResourceManager] allocate channel.. 0809:0002
<  1155.843> [eDVBResourceManager] available channel.. 080e:0002
<  1155.843> [eDVBResourceManager] available channel.. 0802:0002
<  1155.843> [eDVBResourceManager] available channel.. 0812:0002
<  1155.843> [eDVBFrontend] opening frontend 4
<  1155.845> [eDVBFrontend] (4)tune
<  1155.845> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  1155.845> **** Tuning JESS
<  1155.845> **** frequency_mhz: 10964
<  1155.845> **** lo_mhz: 9750
<  1155.845> **** T: 1114
<  1155.845> **** position: 0
<  1155.845> **** ub: 2
<  1155.845> **** mode: 2
<  1155.845> **** JESS: 70 14 5a 02
<  1155.845> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1155.845> [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
<  1155.846> [eDVBFrontend] tuning to 1681 mhz
<  1155.846> [eDVBChannel] OURSTATE: tuning
<  1155.846> [eDVBServicePMTHandler] allocate Channel: res 0
<  1155.846> [eDVBCIInterfaces] addPMTHandler 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1155.846> [eDVBChannel] getDemux cap=00
<  1155.846> [eDVBResourceManager] allocate demux cap=00
<  1155.846> [eDVBResourceManager] allocating demux adapter=0, demux=3, source=-1 fesource=4
<  1155.846> [eDVBDemux] open demux /dev/dvb/adapter0/demux3
<  1155.846> [eEPGCache] saveEventToFile epg event id 93d1
<  1155.847> [RecordTimer] prepare ok, waiting for begin
<  1155.849> [RecordTimer] prepare ok, waiting for begin
 [Trashcan] /media/hdd/movie/.Trash: Size now: 11823690824
<  1155.850> [Trashcan] Cleanup already running
<  1155.852> [Task] job Components.Task.Job name=Cleaning Trashes #tasks=1 completed with [] in None
<  1155.852> [eDVBFrontend] set static current limiting
<  1155.852> [eDVBFrontend] set static current limiting
<  1155.852> [eDVBFrontend] set static current limiting
<  1155.852> [eDVBFrontend] invalidate current switch params
<  1155.852> [eDVBFrontend] invalidate current switch params
<  1155.852> [eDVBFrontend] invalidate current switch params
<  1155.852> [eDVBFrontend] setVoltage 1
<  1155.853> [eDVBFrontend] setVoltage 1
<  1155.854> [eDVBFrontend] setVoltage 1
<  1155.855> [eDVBFrontend] sleep 1500ms
<  1155.855> [eDVBFrontend] sleep 1500ms
<  1155.855> [eDVBFrontend] sleep 1500ms
<  1157.355> [eDVBFrontend] setVoltage 2
<  1157.355> [eDVBFrontend] setVoltage 2
<  1157.356> [eDVBFrontend] setVoltage 2
<  1157.357> [eDVBFrontend] setTone 0
<  1157.357> [eDVBFrontend] setTone 0
<  1157.358> [eDVBFrontend] setTone 0
<  1157.358> [eDVBFrontend] sleep 75ms
<  1157.359> [eDVBFrontend] sleep 75ms
<  1157.359> [eDVBFrontend] sleep 75ms
<  1157.489> [eDVBFrontend] sendDiseqc: 7003e500(?)
<  1157.545> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<  1157.601> [eDVBFrontend] sendDiseqc: 70145a02(?)
<  1157.601> [eDVBFrontend] sleep 100ms
<  1157.601> [eDVBFrontend] sleep 100ms
<  1157.601> [eDVBFrontend] sleep 100ms
<  1157.701> [eDVBFrontend] setVoltage 1
<  1157.702> [eDVBFrontend] setVoltage 1
<  1157.703> [eDVBFrontend] setVoltage 1
<  1157.703> [eDVBFrontend] update current switch params
<  1157.703> [eDVBFrontend] update current switch params
<  1157.703> [eDVBFrontend] update current switch params
<  1157.703> [eDVBFrontend] startTuneTimeout 5000
<  1157.703> [eDVBFrontend] startTuneTimeout 5000
<  1157.703> [eDVBFrontend] startTuneTimeout 5000
<  1157.703> [eDVBFrontend] setFrontend 1
<  1157.703> [eDVBFrontend] setting frontend 0
<  1157.706> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<  1157.706> [eDVBFrontend] setFrontend 1
<  1157.706> [eDVBFrontend] setting frontend 3
<  1157.708> [eDVBFrontend] setFrontend 1
<  1157.708> [eDVBFrontend] setting frontend 4
<  1157.708> [eDVBFrontend] sleep 500ms
<  1157.711> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<  1157.717> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<  1157.717> [eDVBFrontend] sleep 500ms
<  1157.717> [eDVBFrontend] sleep 500ms
<  1157.750> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<  1157.750> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<  1157.760> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<  1158.208> [eDVBFrontend] set dynamic current limiting
<  1158.217> [eDVBFrontend] set dynamic current limiting
<  1158.217> [eDVBFrontend] set dynamic current limiting
<  1162.703> [eDVBChannel] OURSTATE: failed, retune
<  1162.703> [eDVBFrontend] (0)tune
<  1162.703> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<  1162.703> **** Tuning JESS
<  1162.703> **** frequency_mhz: 10847
<  1162.703> **** lo_mhz: 9750
<  1162.703> **** T: 997
<  1162.703> **** position: 0
<  1162.703> **** ub: 0
<  1162.704> **** mode: 0
<  1162.704> **** JESS: 70 03 e5 00
<  1162.704> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1162.704> [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
<  1162.704> [eDVBFrontend] tuning to 1211 mhz
<  1162.704> [eDVBChannel] OURSTATE: tuning
<  1162.704> [eDVBServicePMTHandler] tune failed.
<  1162.704> [eDVBServiceRecord] RECORD service event 1
<  1162.704> [eDVBServiceRecord] record failed to tune
<  1162.704> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1162.704> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1162.704> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 802 current: ffffffff
<  1162.704> [eDVBServicePMTHandler] incorrect namespace. expected: 2 current: ffffffff
<  1162.704> [eDVBChannel] OURSTATE: failed, retune
<  1162.704> [eDVBFrontend] (3)tune
<  1162.704> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  1162.704> **** Tuning JESS
<  1162.704> **** frequency_mhz: 11097
<  1162.704> **** lo_mhz: 9750
<  1162.704> **** T: 1247
<  1162.704> **** position: 0
<  1162.704> **** ub: 1
<  1162.704> **** mode: 0
<  1162.704> **** JESS: 70 0c df 00
<  1162.704> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1162.704> [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
<  1162.704> [eDVBFrontend] tuning to 1421 mhz
<  1162.704> [eDVBChannel] OURSTATE: tuning
<  1162.704> [eDVBServicePMTHandler] tune failed.
<  1162.704> [eDVBServiceRecord] RECORD service event 1
<  1162.704> [eDVBServiceRecord] record failed to tune
<  1162.705> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1162.705> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1162.705> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 812 current: ffffffff
<  1162.705> [eDVBServicePMTHandler] incorrect namespace. expected: 2 current: ffffffff
<  1162.705> [eDVBChannel] OURSTATE: failed, retune
<  1162.705> [eDVBFrontend] (4)tune
<  1162.705> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  1162.705> **** Tuning JESS
<  1162.705> **** frequency_mhz: 10964
<  1162.705> **** lo_mhz: 9750
<  1162.705> **** T: 1114
<  1162.705> **** position: 0
<  1162.705> **** ub: 2
<  1162.705> **** mode: 2
<  1162.705> **** JESS: 70 14 5a 02
<  1162.705> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1162.705> [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
<  1162.705> [eDVBFrontend] tuning to 1681 mhz
<  1162.705> [eDVBChannel] OURSTATE: tuning
<  1162.705> [eDVBServicePMTHandler] tune failed.
<  1162.705> [eDVBServiceRecord] RECORD service event 1
<  1162.705> [eDVBServiceRecord] record failed to tune
<  1162.705> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1162.705> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1162.705> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 809 current: ffffffff
<  1162.705> [eDVBServicePMTHandler] incorrect namespace. expected: 2 current: ffffffff
<  1162.705> [eDVBFrontend] set static current limiting
<  1162.705> [eDVBFrontend] set static current limiting
<  1162.705> [eDVBFrontend] set static current limiting
<  1162.705> [eDVBFrontend] invalidate current switch params
<  1162.705> [eDVBFrontend] invalidate current switch params
<  1162.705> [eDVBFrontend] invalidate current switch params
<  1162.705> [eDVBFrontend] set sequence pos 3
<  1162.706> [eDVBFrontend] set sequence pos 3
<  1162.706> [eDVBFrontend] set sequence pos 3
<  1162.706> [eDVBFrontend] setVoltage 2
<  1162.706> [eDVBFrontend] setVoltage 2
<  1162.707> [eDVBFrontend] setVoltage 2
<  1162.707> [eDVBFrontend] setTone 0
<  1162.708> [eDVBFrontend] setTone 0
<  1162.709> [eDVBFrontend] setTone 0
<  1162.709> [eDVBFrontend] sleep 75ms
<  1162.709> [eDVBFrontend] sleep 75ms
<  1162.709> [eDVBFrontend] sleep 75ms
<  1162.840> [eDVBFrontend] sendDiseqc: 7003e500(?)
<  1162.896> [eDVBFrontend] sendDiseqc: 700cdf00(?)
<  1162.952> [eDVBFrontend] sendDiseqc: 70145a02(?)
<  1162.952> [eDVBFrontend] sleep 100ms
<  1162.952> [eDVBFrontend] sleep 100ms
<  1162.952> [eDVBFrontend] sleep 100ms
<  1163.052> [eDVBFrontend] setVoltage 1
<  1163.053> [eDVBFrontend] setVoltage 1
<  1163.054> [eDVBFrontend] setVoltage 1
<  1163.055> [eDVBFrontend] update current switch params
<  1163.055> [eDVBFrontend] update current switch params
<  1163.055> [eDVBFrontend] update current switch params
<  1163.055> [eDVBFrontend] startTuneTimeout 5000
<  1163.055> [eDVBFrontend] startTuneTimeout 5000
<  1163.055> [eDVBFrontend] startTuneTimeout 5000
<  1163.055> [eDVBFrontend] setFrontend 1
<  1163.055> [eDVBFrontend] setting frontend 0
<  1163.055> [eDVBFrontend] (0)fe event: status 0, inversion off, m_tuning 1
<  1163.055> [eDVBFrontend] setFrontend 1
<  1163.055> [eDVBFrontend] setting frontend 3
<  1163.055> [eDVBFrontend] setFrontend 1
<  1163.055> [eDVBFrontend] setting frontend 4
<  1163.055> [eDVBFrontend] sleep 500ms
<  1163.055> [eDVBFrontend] (3)fe event: status 0, inversion off, m_tuning 1
<  1163.055> [eDVBFrontend] (4)fe event: status 0, inversion off, m_tuning 1
<  1163.055> [eDVBFrontend] sleep 500ms
<  1163.055> [eDVBFrontend] sleep 500ms
<  1163.100> [eDVBFrontend] (0)fe event: status 7, inversion off, m_tuning 2
<  1163.101> [eDVBFrontend] (3)fe event: status 7, inversion off, m_tuning 2
<  1163.101> [eDVBFrontend] (4)fe event: status 7, inversion off, m_tuning 2
<  1163.555> [eDVBFrontend] set dynamic current limiting
<  1163.555> [eDVBFrontend] set dynamic current limiting
<  1163.555> [eDVBFrontend] set dynamic current limiting
<  1168.055> [eDVBChannel] OURSTATE: failed, retune
<  1168.055> [eDVBFrontend] (0)tune
<  1168.055> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0xe3, guard_offset 0
<  1168.055> **** Tuning JESS
<  1168.055> **** frequency_mhz: 10847
<  1168.055> **** lo_mhz: 9750
<  1168.055> **** T: 997
<  1168.055> **** position: 0
<  1168.055> **** ub: 0
<  1168.055> **** mode: 0
<  1168.055> **** JESS: 70 03 e5 00
<  1168.055> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1168.055> [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
<  1168.055> [eDVBFrontend] tuning to 1211 mhz
<  1168.055> [eDVBChannel] OURSTATE: tuning
<  1168.055> [eDVBServicePMTHandler] tune failed.
<  1168.055> [eDVBServiceRecord] RECORD service event 1
<  1168.055> [eDVBServiceRecord] record failed to tune
<  1168.055> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1168.055> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1168.055> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 802 current: ffffffff
<  1168.055> [eDVBServicePMTHandler] incorrect namespace. expected: 2 current: ffffffff
<  1168.056> [eDVBChannel] OURSTATE: failed, retune
<  1168.056> [eDVBFrontend] (3)tune
<  1168.056> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x2156, guard_offset 0
<  1168.056> **** Tuning JESS
<  1168.056> **** frequency_mhz: 11097
<  1168.056> **** lo_mhz: 9750
<  1168.056> **** T: 1247
<  1168.056> **** position: 0
<  1168.056> **** ub: 1
<  1168.056> **** mode: 0
<  1168.056> **** JESS: 70 0c df 00
<  1168.056> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1168.056> [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
<  1168.056> [eDVBFrontend] tuning to 1421 mhz
<  1168.056> [eDVBChannel] OURSTATE: tuning
<  1168.056> [eDVBServicePMTHandler] tune failed.
<  1168.056> [eDVBServiceRecord] RECORD service event 1
<  1168.056> [eDVBServiceRecord] record failed to tune
<  1168.056> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1168.056> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1168.056> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 812 current: ffffffff
<  1168.056> [eDVBServicePMTHandler] incorrect namespace. expected: 2 current: ffffffff
<  1168.056> [eDVBChannel] OURSTATE: failed, retune
<  1168.056> [eDVBFrontend] (4)tune
<  1168.056> [eDVBSatelliteEquipmentControl] [prepare] UnicableTuningWord 0x4976, guard_offset 0
<  1168.056> **** Tuning JESS
<  1168.056> **** frequency_mhz: 10964
<  1168.056> **** lo_mhz: 9750
<  1168.056> **** T: 1114
<  1168.056> **** position: 0
<  1168.056> **** ub: 2
<  1168.056> **** mode: 2
<  1168.056> **** JESS: 70 14 5a 02
<  1168.056> [eDVBSatelliteEquipmentControl] RotorCmd ffffffff, lastRotorCmd ffffffff
<  1168.056> [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
<  1168.056> [eDVBFrontend] tuning to 1681 mhz
<  1168.056> [eDVBChannel] OURSTATE: tuning
<  1168.056> [eDVBServicePMTHandler] tune failed.
<  1168.056> [eDVBServiceRecord] RECORD service event 1
<  1168.056> [eDVBServiceRecord] record failed to tune
<  1168.056> [eDVBServicePMTHandler] ignore sdt update data.... incorrect transponder tuned!!!
<  1168.056> [eDVBServicePMTHandler] incorrect namespace. expected: 11a0000 current: ffffffff
<  1168.056> [eDVBServicePMTHandler] incorrect transport_stream_id. expected: 809 current: ffffffff
<  1168.056> [eDVBServicePMTHandler] incorrect namespace. expected: 2 current: ffffffff

[athoik]

Prepare seems fine now, all prepare are not done together.

Now we need to avoid this:

< 1155.852> [eDVBFrontend] set static current limiting 
< 1155.852> [eDVBFrontend] set static current limiting 
< 1155.852> [eDVBFrontend] set static current limiting

Can you try another locker in tuneInternal?

void eDVBFrontend::tuneLoop()
{
+       eSingleLocker s(lock);
	tuneLoopInt();
}

Also running timer with a single second delay fixes the problem? (And I am not suggesting adding delay as a fix, just to understand if this is some kind of racing)

[Erik Slagter]

Transponders being tuned are 10847 V and 10964 H. These frequencies correspond to the services being recorded.

The IFs being tuned are 1211 MHz and 1421 MHz. This corresponds with SCR1 and SCR2 of my LNB.

So to me those look correct in the log excert posted above.

Sorry if I have not understood the question.

No sorry, that is what I wanted to know. So the calculations are correct, so if there is a problem, it's not there. The "mode" also says hi/lo and vertical/horizontal.

[Erik Slagter]

Just because some people can't reproduce the bug with their specific hardware doesn't mean other hardware is to blame. Is it really correct to send 2 comands to the LNB just 1 milli-second apart. I doubt it, even if some devices can cope with that.

 

How/where can a command queue be added to stop the commands being sent on top of each other?

That is an interesting question. I have never, however, encountered any restriction on this in both Unicable and JESS documentation.

 

AFAIK there is a "delay" command. But also there is already standard a mechanism to delay DiSEqC commands (using the DiSEqC timing plugin).

[Erik Slagter]

Erik, what STB are you using?

I have had connected to the JESS switch:

 

- VU+ Ultimo4

- VU+ Solo4k

- GB quad4k

- MaxDigital XP1000

- Formuler F3

- VU+ Zero4k

- Mut@nt HD51

- Xsarius Galaxy4k

 

and maybe a few more.

[Pr2]

Hi,
 
I just saw this:
 
<  1155.814> [RecordTimer] Filename calculated as: '/media/hdd/movie/20180923 0041 - BBC One HD - Match of the Day'
<  1155.814> [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
<  1155.814> [eDVBResourceManager] allocate channel.. 0802:0002
<  1155.814> [eDVBResourceManager] available channel.. 080e:0002
 
<  1155.829> [RecordTimer] Filename calculated as: '/media/hdd/movie/20180923 0041 - ITV London HD - Van Helsing'
<  1155.829> [Navigation] recording service: 1:0:19:5208:812:2:11A0000:0:0:0::ITV London HD
<  1155.830> [eDVBResourceManager] allocate channel.. 0812:0002
<  1155.830> [eDVBResourceManager] available channel.. 080e:0002
<  1155.830> [eDVBResourceManager] available channel.. 0802:0002
 
<  1155.842> [RecordTimer] Filename calculated as: '/media/hdd/movie/20180923 0041 - Channel 5 HD - Shrunken Heads Of The Amazon'
<  1155.843> [Navigation] recording service: 1:0:19:1E46:809:2:11A0000:0:0:0:
<  1155.843> [eDVBResourceManager] allocate channel.. 0809:0002
<  1155.843> [eDVBResourceManager] available channel.. 080e:0002
<  1155.843> [eDVBResourceManager] available channel.. 0802:0002
<  1155.843> [eDVBResourceManager] available channel.. 0812:0002
 
 
Recording on BBC One decide to  allocate channel.. 0802:0002
Then recording for ITV London decide to allocate channel.. 0812:0002

But why then the allocate channel.. 0802:0002 is reported has available, if I understand it right it is not available since it was allocated for BBC One HD.

 

Look at the last recording (Channel 5) we have the same problem, channels that are normally allocated are reported has available.

 

Pr2

[Huevos]

Prepare seems fine now, all prepare are not done together.

Now we need to avoid this:
 

< 1155.852> [eDVBFrontend] set static current limiting 
< 1155.852> [eDVBFrontend] set static current limiting 
< 1155.852> [eDVBFrontend] set static current limiting

Can you try another locker in tuneInternal?

void eDVBFrontend::tuneLoop()
{
+       eSingleLocker s(lock);
	tuneLoopInt();
}

Also running timer with a single second delay fixes the problem? (And I am not suggesting adding delay as a fix, just to understand if this is some kind of racing)

 

https://github.com/H...437cac421a9d35a

 

Enigma doesn't start. Log ends like this...

 

<    61.368> [eDVBFrontend] opening frontend 1
 

Then the spinner comes up and And I am stuck at a black screen.

 

Tuner B is my normal tuner for watching TV so that is what it is trying to open.

Edited by Huevos, 23 September 2018 - 12:01.

[athoik]

Obviously locking the tunerLoop is not the right approach

(I guess there is a recursion going on, so first loop, lock, second loop cannot enter due to lockage).

What about adding 1 second delay between timers?

10:19:21
10:19:22
...

Instead starting all timers the same second!

Edited by athoik, 23 September 2018 - 12:32.

[Pr2]

The problem should not be fixed at the timer side, it must be fixed on the tuner side. Fixing it at the timer is just a work-around.

There must be a fifo queue created to send all the command through it, so all commands are sequentially sent to tuner and we can add a small delay between every command.

And what about if somebody start a streaming from a client and locally a zap is done exactly at the same time?  Then the fix on the timer side is useless, while if it is done on the tuner side it will work.

[athoik]

Also running timer with a single second delay fixes the problem? (And I am not suggesting adding delay as a fix, just to understand if this is some kind of racing)

Read one more time, carefully.