missing epg data - opentv

[satteliter]

i have a duo 4k se with unicable(8 tuners) and aerial(2 tuners). latest openvix 6.3.002.
The box is a few days old. I had been having issues with epg not loading information on startup from the hard drive so I switched the epg to use a usb (hoping the flash drive would rule out any issues with hard drive spin up time etc.)

However, I'm still seeing the same situation with the usb. I have confirmed the epg.dat is only being written to usb and not hdd.

This time, the aerial channels in the epg are showing 7 day guide but all the satellite channels are not showing any epg data.
This has been a reoccuring problem for the last few days.

It does not seem to matter if the box is coming out of standby or deep standby.
I had debug logs enabled which I've attached.

The later debug logs have the local time in the logs as well.


Is there any way to better troubleshoot this? Would switching to CrossEPG or some other plugin solve this?

648546485564856648576485864859


epg.dat is ~8mb and i can see some satellite channel epg info in there.

[satteliter]

here are logs from after a reboot when the epg data was still missing from satellite channels64860

[satteliter]

doing a 'force opentv download' populates the epg.

after monitoring the tuners in use(thus knowing when opentv finishes), i can see that the epg when epg is fully populated is 2364kb(roughly quarter of size of epg.dat when it was not populating on screen(8157kb))

this is headwrecking!

[abu baniaz]

During acquisition, the epg is held in RAM. It is only saved on graceful shutdown/restart. Acquiring and checking i snot a good test. You have to acquire and then restart.

EDIT:
There is nothing in your log to show why EPG is being dropped.

[satteliter]

there are now some later logs all of which say


Continued from /home/root/logs/Enigma2_debug_2023-02-25_17-45-07.log
< 438.7103> 17:45:54.2754 [huffman] Error. Cannot decode Huffman data
< 438.7103> 17:45:54.2754 [huffman] Error. Cannot decode Huffman data
< 438.7104> 17:45:54.2755 [convertDVBUTF8] reserved 0
< 438.7106> 17:45:54.2756 [convertDVBUTF8] reserved 0
< 438.7107> 17:45:54.2757 [convertDVBUTF8] reserved 0
< 438.7108> 17:45:54.2758 [convertDVBUTF8] reserved 0
< 438.7109> 17:45:54.2759 [convertDVBUTF8] reserved 0
< 438.7110> 17:45:54.2761 [convertDVBUTF8] reserved 0
< 438.7128> 17:45:54.2778 [huffman] Error. Cannot decode Huffman data
< 438.7128> 17:45:54.2778 [huffman] Error. Cannot decode Huffman data
< 438.7128> 17:45:54.2779 [huffman] Error. Cannot decode Huffman data
< 438.7129> 17:45:54.2779 [huffman] Error. Cannot decode Huffman data
< 438.7129> 17:45:54.2779 [huffman] Error. Cannot decode Huffman data
< 438.7129> 17:45:54.2780 [huffman] Error. Cannot decode Huffman data
< 438.7130> 17:45:54.2780 [huffman] Error. Cannot decode Huffman data



after turning box on from standby and checking epg, the sat epg data is missing again and the epg.dat size has gone up to 7995kb.


logs attached(zipped as filesize of 10mb too big)64861

[satteliter]

the entries preceeding the huffman errors(take from Enigma2_debug_2023-02-25_17-38-56.log):


< 330.4837> 17:44:06.0487 [eDVBSectionReader] DMX_SET_FILTER pid=1903
< 330.5509> 17:44:06.1159 [eDVBFrontend2] setVoltage 1
< 330.5509> 17:44:06.1159 [eDVBFrontend0] setVoltage FE_ENABLE_HIGH_LNB_VOLTAGE 0 FE_SET_VOLTAGE 0
< 330.5601> 17:44:06.1252 [eDVBFrontend2] update current switch params
< 330.5602> 17:44:06.1253 [eDVBFrontend2] startTuneTimeout 5000
< 330.5603> 17:44:06.1253 [eDVBFrontend2] setFrontend 1
< 330.5603> 17:44:06.1253 [eDVBFrontend2] setting frontend
< 330.5728> 17:44:06.1378 [eDVBFrontend2] fe event: status 0, inversion off, m_tuning 1
< 330.5728> 17:44:06.1378 [eDVBFrontend2] sleep 500ms
< 330.5803> 17:44:06.1453 [eDVBDemux] open demux /dev/dvb/adapter0/demux1
< 330.5803> 17:44:06.1454 [eDVBSectionReader] DMX_SET_FILTER pid=1904
< 330.6414> 17:44:06.2065 [eDVBFrontend2] fe event: status 7, inversion off, m_tuning 2
< 330.6415> 17:44:06.2066 [eDVBFrontend0] fe event: status 1f, inversion off, m_tuning 2
< 330.6621> 17:44:06.2272 [eDVBDemux] open demux /dev/dvb/adapter0/demux1
< 330.6622> 17:44:06.2272 [eDVBSectionReader] DMX_SET_FILTER pid=1905
< 330.7264> 17:44:06.2915 [eDVBFrontend2] fe event: status 1f, inversion off, m_tuning 3
< 330.7265> 17:44:06.2915 [eDVBChannel] OURSTATE: ok
< 330.7265> 17:44:06.2915 [eDVBLocalTimerHandler] channel 0xfb6c70 running
< 330.7266> 17:44:06.2916 [eDVBChannel] getDemux cap=00
< 330.7266> 17:44:06.2916 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7267> 17:44:06.2917 [eDVBSectionReader] DMX_SET_FILTER pid=20
< 330.7283> 17:44:06.2933 [eEPGTransponderDataReader] channel 0xfb6c70 running
< 330.7283> 17:44:06.2934 [eDVBChannel] getDemux cap=00
< 330.7283> 17:44:06.2934 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7284> 17:44:06.2934 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7284> 17:44:06.2935 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7285> 17:44:06.2935 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7285> 17:44:06.2935 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7285> 17:44:06.2936 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7286> 17:44:06.2936 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7286> 17:44:06.2937 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7287> 17:44:06.2937 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7287> 17:44:06.2937 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7287> 17:44:06.2938 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7288> 17:44:06.2938 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7288> 17:44:06.2938 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7289> 17:44:06.2939 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7289> 17:44:06.2939 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7289> 17:44:06.2940 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7290> 17:44:06.2940 [eDVBResourceManager] stop release channel timer
< 330.7290> 17:44:06.2940 [eDVBChannel] getDemux cap=01
< 330.7290> 17:44:06.2941 [eEPGChannelData] next update in 2 sec
< 330.7290> 17:44:06.2941 [eDVBResourceManager] allocate demux cap=01
< 330.7291> 17:44:06.2941 [eDVBResourceManager] allocating shared demux adapter=0, demux=2, source=2
< 330.7291> 17:44:06.2941 [eDVBServicePMTHandler] ok ... now we start!!
< 330.7291> 17:44:06.2941 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7291> 17:44:06.2942 [eDVBSectionReader] DMX_SET_FILTER pid=0
< 330.7297> 17:44:06.2948 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7298> 17:44:06.2948 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 330.7302> 17:44:06.2952 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.7303> 17:44:06.2953 [eDVBSectionReader] DMX_SET_FILTER pid=0
< 330.7602> 17:44:06.3252 [eDVBDemux] open demux /dev/dvb/adapter0/demux1
< 330.7602> 17:44:06.3253 [eDVBSectionReader] DMX_SET_FILTER pid=1906
< 330.7733> 17:44:06.3384 [eDVBDemux] open demux /dev/dvb/adapter0/demux1
< 330.7734> 17:44:06.3384 [eDVBSectionReader] DMX_SET_FILTER pid=1907
< 330.8113> 17:44:06.3763 [eDVBServicePMTHandler] PATready
< 330.8113> 17:44:06.3764 [eDVBServicePMTHandler] use pmtpid 0100 for service_id 18a4
< 330.8114> 17:44:06.3764 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.8114> 17:44:06.3764 [eDVBSectionReader] DMX_SET_FILTER pid=256
< 330.8117> 17:44:06.3767 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.8117> 17:44:06.3768 [eDVBSectionReader] DMX_SET_FILTER pid=0
< 330.8127> 17:44:06.3778 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.8128> 17:44:06.3778 [eDVBSectionReader] DMX_SET_FILTER pid=256
< 330.8134> 17:44:06.3785 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 330.8135> 17:44:06.3785 [eDVBSectionReader] DMX_SET_FILTER pid=17
< 330.8681> 17:44:06.4331 [eDVBDemux] open demux /dev/dvb/adapter0/demux1
< 330.8682> 17:44:06.4332 [eDVBSectionReader] DMX_SET_FILTER pid=1908
< 330.9088> 17:44:06.4739 [eDVBLocalTimerHandler] diff is 0
< 330.9088> 17:44:06.4739 [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
< 330.9089> 17:44:06.4739 [eDVBLocalTimerHandler] not changed
< 330.9091> 17:44:06.4741 [eDVBChannel] getDemux cap=00
< 331.0055> 17:44:06.5706 [eDVBServicePMTHandler] sdt update done!
< 331.0523> 17:44:06.6173 [eDVBServicePMTHandler] sdt update done!
< 331.0729> 17:44:06.6380 [eDVBFrontend2] set dynamic current limiting
< 331.2807> 17:44:06.8457 [eDVBServiceFCCPlay] eventNewProgramInfo 0 0 0
< 331.2808> 17:44:06.8458 [eDVBServiceFCCPlay] updateFCCDecoder [1:0:19:18A4:7FD:2:11A0000:0:0:0:]
have 1 video stream(s) (1518), and 1 audio stream(s) (1519), and the pcr pid is 1518, and the text pid is 151b< 331.2812> 17:44:06.8463
< 331.2812> 17:44:06.8463 [eDVBChannel] getDemux cap=01
< 331.2813> 17:44:06.8463 [decoder][eDVBText] initCache
< 331.2814> 17:44:06.8464 [eFCCDecoder] Alloc /dev/fcc1
< 331.2819> 17:44:06.8469 [eTSMPEGDecoder] FCC_START OK!
< 331.2820> 17:44:06.8470 [eDVBCAService] new service 1:0:19:18A4:7FD:2:11A0000:0:0:0:
< 331.2820> 17:44:06.8470 [eDVBCAService] add demux 2 to slot 0 service 1:0:19:18A4:7FD:2:11A0000:0:0:0:
< 331.2822> 17:44:06.8472 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 331.2823> 17:44:06.8473 [eDVBSectionReader] DMX_SET_FILTER pid=256
< 331.7280> 17:44:07.2931 [eEPGChannelData] start reading events(1677347047)
< 331.7281> 17:44:07.2932 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 331.7289> 17:44:07.2939 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 331.7297> 17:44:07.2948 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 331.7308> 17:44:07.2959 [huffman] read.. '/usr/share/enigma2/otv_011a0000_0002_07d4.dict'
< 331.7330> 17:44:07.2980 [huffman] read.. dictionary completed, read 512 values
< 331.7330> 17:44:07.2981 [eDVBSectionReader] DMX_SET_FILTER pid=17
< 332.0326> 17:44:07.5976 [eDVBDemux] open demux /dev/dvb/adapter0/demux2
< 332.0327> 17:44:07.5977 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 332.7290> 17:44:08.2941 [eEPGChannelData] start reading events(1677347048)
< 332.7294> 17:44:08.2944 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 332.7315> 17:44:08.2965 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 332.7325> 17:44:08.2976 [eDVBSectionReader] DMX_SET_FILTER pid=18
< 332.7338> 17:44:08.2989 [huffman] read.. '/usr/share/enigma2/otv_011a0000_0002_07fd.dict'
< 332.7341> 17:44:08.2992 [eEPGChannelData] abort non avail OpenTV EIT reading
< 335.4826> 17:44:11.0477 [eDVBLocalTimerHandler] diff is -10
< 335.4827> 17:44:11.0477 [eDVBLocalTimerHandler] diff < 120 .. use Transponder Time
< 335.5934> 17:44:11.1584 [eDVBLocalTimerHandler] update RTC
< 335.5934> 17:44:11.1585 [eDVBLocalTimerHandler] time update to 17:44:01
< 335.5935> 17:44:11.1585 [eDVBLocalTimerHandler] m_time_difference is -10
< 335.5935> 17:44:11.1585 [eDVBLocalTimerHandler] slewing Linux Time by -10 seconds
< 335.5938> 17:44:11.1588 [eDVBChannel] getDemux cap=00
< 339.7344> 17:44:15.2994 [eEPGChannelData] abort non avail schedule reading
< 339.7356> 17:44:15.3007 [eEPGChannelData] abort non avail schedule other reading
< 339.8138> 17:44:15.3788 [eEPGChannelData] nownext finished(1677347055)
< 339.8143> 17:44:15.3793 [eEPGChannelData] stop caching events(1677347055)
< 339.8143> 17:44:15.3793 [eEPGChannelData] next update in 60 min
< 341.7857> 17:44:17.3507 [eEPGChannelData] OpenTV channels, found=833
< 341.7860> 17:44:17.3510 [eDVBSectionReader] DMX_SET_FILTER pid=48
< 341.7928> 17:44:17.3578 [huffman] Error. Cannot decode Huffman data

this is then followed by thousands of entries of "[huffman] Error. Cannot decode Huffman data"

[Joe_90]

The OpenTV zapper will (should) automatically start 5 minutes after a boot. The EPG data is then populated in RAM and is only written back to epg.dat on a controlled shutdown. The log seems to show a successful run of OpenTV zapper, but unless the box is shut down gracefully, the epg.dat file won't be be written.

I too am getting occasional issues when running the zapper and I'm tuned to RTE1 on terrestrial (as in your example at 17:44:07). The logfile will contain thousands of huffman error messages and the logs will grow to 4MB and then start a new log. I'm not sure what is triggering the huffman error messages, though. Your and my usage cases (Saorview terrestrial and 28.2 sat) may be a factor.

[satteliter]

but unless the box is shut down gracefully.

So far, has always been standby or reboot through ui. no power cuts/button pushing or direct linux commands executed.
i have 2 gigablue trio 4k boxes, each of which has 1 sat/1 aerial and haven't seen any epg issues. all running latest openvix etc..

are you using a vu+ duo 4k se by any chance?

i'm guessing switching to some internet source/crossepg for epg would not have these issues but i'm unsure what issues they might introduce.

[Joe_90]

No - I'm using a GB Quad Plus with 2xDVB-T and 2xDVB-S tuners. I think this is happening for me if I tune another channel while the OpenTV zapper is running. I'll see if I can get log review by a developer.


EDIT - have attached an extract of a debug log from today. When the Huffman Error messages start, they fill five logfiles, each of over 4MB, in the space of about three minutes while the zapper is running. Once the zapper finishes (with only partial EPG), the messages stop.

[satteliter]

interesting. thanks for sharing.

out of curiosity, does you box/setup have FCC (fast channel change) or equivalent?

[Joe_90]

interesting. thanks for sharing.

out of curiosity, does you box/setup have FCC (fast channel change) or equivalent?

Nope - it's an old box (2014 ish).

[satteliter]

just to add some more things. since the last post on 25/02, I disabled the 2nd satellite root tuner and also disabled fast channel changing.
no issues with epg since then.

earlier today, I re-enabled FCC (but left the 2nd satellite root tuner disabled), epg issue re-appeared. Box had not been powered off(i.e. has been used or standby or deep standby every day since).

so, with FCC, if any of the terrestrial muxes were watched before watching satellite, the box had the tuner 'active' (due to FCC being enabled).

I think this ties in with your observed behaviour ("getting occasional issues when running the zapper and I'm tuned to RTE1 on terrestrial ")

i've since disabled FCC.

unfortunately, some logs were overwritten as max total log size was reached before i got a chance to copy them over to see the log entries preceding the huffman error.

on a related note, later today , i switched to a terrestrial channel (tried both muxes) and manually ran 'opentv epg forced download'. i was unable to recreate the huffman error issue.
the log entries when i ran it read:


< 12724.4137> 22:41:57.2126 [opentv_zapper]currentlyPlayingNIM 8
< 12724.4139> 22:41:57.2127 [opentv_zapper]available tuners [0, 2, 3, 4, 5, 6, 7]

(available tuner 1 being the disabled sat root tuner)

'currentlyPlayingNIM 8' when either terrestrial mux was being viewed.

have you any steps to manually invoke the issue?

[Joe_90]

I've reported it as a possible bug, but had no feedback since. I'll chase it up again.

[abu baniaz]

Have you tried zapping with EPG refresh instead of openTV EPG zapper? If so, are results the same?

[satteliter]

Just added plugin and set it up. Will monitor and report back if issue re-appears.

[abu baniaz]

Please just use one plugin, not both.

[satteliter]

yip. should have mentioned i disabled opentv downloader before setting up epgrefresh

[satteliter]

Unfortunately, despite the EPGRefresh method working manually yesterday, I woke up this morning and epg was empty. I had it set for 07.30.
Box would have been in deep standby since earlier.
Logs attached. 64891648926489364894

Here is epgrefresh setting (i've since changed the service for terrestrial in use to be a 'Saorview Information' instead of 'RTE one' and have also increased the record time to 300 secs.64898

[satteliter]

Also relevant: the usb flash drive wasn't mounted when I looked at box this morning so I've (after above issue/logs) switched epg.dat back to using hard drive.

[satteliter]

invoked epgrefresh manually. huffman error issue occurred again.64900 [zipped as log file > 4mb]

[Joe_90]

I think you are not setting the correct channel for EPGRefresh to tune. Looks like ITV London. Should be the IEPG channel from your Sky bouquet (Freq 11778000 Pol 1 SR 27500000 INV 2 FEC 2 orbpos 282 ).

I don't bother with specifically running EPGRefresh on Saorview. I have RTE1 set as the startup channel and when it boots from deep standby it automatically tunes RTE1 and then goes into standby. The Saorview EPG is so small (11'ish channels x 8 days) that the schedule is downloaded in seconds.

[satteliter]

I think you are not setting the correct channel for EPGRefresh to tune. Looks like ITV London. Should be the IEPG channel from your Sky bouquet (Freq 11778000 Pol 1 SR 27500000 INV 2 FEC 2 orbpos 282 ).

I don't bother with specifically running EPGRefresh on Saorview. I have RTE1 set as the startup channel and when it boots from deep standby it automatically tunes RTE1 and then goes into standby. The Saorview EPG is so small (11'ish channels x 8 days) that the schedule is downloaded in seconds.

I think I just had ITV London on but the EPGRefresh setting was 100% on the IEPG channel 64904

[Joe_90]

EPGRefresh is failing to run in any of your logfiles in post #18. The log message indicates that the box is not in standby or is otherwise busy.

[satteliter]

EPGRefresh is failing to run in any of your logfiles in post #18. The log message indicates that the box is not in standby or is otherwise busy.

The box definitely came out of deep standby itself. maybe it went straight to active(instead of just standby) but all tuners would have been available anyway.
First human interaction with box was after 8.30am local. Entries for eInputDeviceInit in log at 08:37 onwards in 2023-03-02_07-28-03.log

[satteliter]

Some more logs from this mornings run.
Crashed again. Came out of deep standby itself again at 07.30.
Box on 02 Feb was put to sleep at ~23:30. Then came on the next day (03 Feb) at ~07.30.

It seems EPGRefresh takes box out of deep standby and puts it to active (rather than just standby) which then results in the
Box still in use, rescheduling message thus it doesn't run.
I have now set EpgRefresh to 'Force scan' so will provide updates later/tmw64915649166491764918

[Joe_90]

I didn't think EPGRefresh would boot the box from deep standby? Are you sure you don't have a PowerTimer set? The time window in the EPGRefresh settings is just when the plugin will run. Yes - you have to set the "force scan" option in the plugin, otherwise it won't run unless it's in standby.


EDIT - I looked through all the logs. At 09.57 you put the box in standby and EPGRefresh started and tuned to the IEPG channel and started pulling the EPG normally. Shortly afterwards, you took the box out of standby and started changing the EPGRefresh config and it would not run, because it was already running. I think that whatever you are using to start the box at 07.30 (A PowerTimer or some scheduled ABM run or XMLTV run or whatever) is starting in normal running mode (not standby) as it seems to tune multiple channels. I'm pretty sure EPGRefresh does not boot the box. It's been a while since I used it, but I always used it in conjunction with a separate PowerTimer.

[BrianG61UK]

On my Zgemma H7S I get the same effect sometimes where it's like the text is missing from the EPG so that multiple EPG entries look blank on the EPG.

I've been experimenting to try and figure out what's going on but I haven't really got very far yet.
I'm hindered by knowing C pretty well but not C++.

I find one thing that makes it go wrong on my Zgemma H7S is if I happen to be flicking through the channels at a time when the EPG is being read (by either OpenTV Zapper or by EPG Refresh).

[Joe_90]

On my Zgemma H7S I get the same effect sometimes where it's like the text is missing from the EPG so that multiple EPG entries look blank on the EPG.

I've been experimenting to try and figure out what's going on but I haven't really got very far yet.
I'm hindered by knowing C pretty well but not C++.

I find one thing that makes it go wrong on my Zgemma H7S is if I happen to be flicking through the channels at a time when the EPG is being read (by either OpenTV Zapper or by EPG Refresh).

Hi Brian - I've been experimenting with running OpenTVZapper at a fixed time each day. My GB Quad+ boots at 17.50 from deep and goes into standby after tuning RTE1 (to get the time and that will automatically refresh the EIT EPG schedule info from Saorview). At 17.52 I have scheduled the zapper to run and this tunes the Sky OpenTV provider and runs for about three minutes. All works flawlessly providing I don't take the box out of standby and start tuning while the zapper is running. Yesterday, I deliberately took the box out of standby at 17.53 and started tuning through DVB-T channels. After the zapper had completed I checked the EPG and could see that the cache had not changed from the day before, so it obviously impacted on the running zapper in some way, even though I didn't try tuning any sat channels. I didn't trigger any "huffman error" messages, though. I'll test a few more scenarios to see if I can repeat the errors. It may give @Huevos some clue as to what's happening.

[satteliter]

I didn't think EPGRefresh would boot the box from deep standby? Are you sure you don't have a PowerTimer set?

ABM set to run at 03.00.
Only power time is a deep standby which kicks in after 60 mins of standby.

I'll change EPGRefresh to 06.30 in config and see if box turns on tmw at 06.30

[satteliter]

I set EPGRefresh to 06.30. Box came on at 06.30.

logs attached(incl crash). epgrefresh did run though. And epg was populated when I checked at ~09.00

initial log and crash 6492464925

log where epgrefresh ran64926


< 167.6608> 06:30:01.0003 [EPGRefresh] Timer added <EPGRefreshTimerEntry (Sat 04 Mar 2023 06:30:31 GMT, 0, <bound method EPGRefresh.prepareRefresh of <Plugins.Extensions.EPGRefresh.EPGRefresh.EPGRefres h object at 0xadaeb410>>)>
< 198.6614> 06:30:32.0009 [EPGRefresh] In Timespan, will check if we're in Standby and have no Recordings running next
< 198.6621> 06:30:32.0016 [EPGRefresh] About to start refreshing EPG
< 198.6631> 06:30:32.0026 [EPGRefresh] Services we're going to scan: <EPGRefreshService (1:0:16:848:3EA:2174:EEEE0000:0:0:0:, ?)>, <EPGRefreshService (1:0:1:105D:7D4:2:11A0000:0:0:0:, ?)>
< 198.6649> 06:30:32.0043 [EPGRefresh] flushing EPG cache...
......
< 198.8389> 06:30:32.1784 [EPGRefresh] Maybe zap to next service
< 198.8393> 06:30:32.1787 [EPGRefresh] DEBUG: ParentalControl not configured
< 198.8396> 06:30:32.1791 [EPGRefresh.RecordAdapter.play]
< 198.8400> 06:30:32.1794 [Navigation] recording service: 1:0:16:848:3EA:2174:EEEE0000:0:0:0:
.....
< 499.6607> 06:35:33.0002 [EPGRefresh] Maybe zap to next service
< 499.6612> 06:35:33.0007 [EPGRefresh] DEBUG: ParentalControl not configured
< 499.6616> 06:35:33.0011 [EPGRefresh.RecordAdapter.play]
< 499.6619> 06:35:33.0013 [eDVBServiceRecord] stop recording!
< 499.6622> 06:35:33.0016 [eDVBServiceRecord] fetching cutlist failed because tstools failed
< 499.6656> 06:35:33.0050 [eDVBCAService] free slot 0 demux 0 for service 1:0:16:848:3EA:2174:EEEE0000:0:0:0:
< 499.6660> 06:35:33.0055 [eDVBCAService] free service 1:0:16:848:3EA:2174:EEEE0000:0:0:0:
< 499.6672> 06:35:33.0066 [Navigation] recording service: 1:0:1:105D:7D4:2:11A0000:0:0:0:
....
< 800.6608> 06:40:34.0002 [EPGRefresh] Maybe zap to next service
< 800.6613> 06:40:34.0007 [EPGRefresh] Done refreshing EPG
< 800.6615> 06:40:34.0010 [EPGRefresh] Debug: Cleanup
< 800.6637> 06:40:34.0031 [EPGRefresh] Debug: Calling nextTodo
< 800.6640> 06:40:34.0035 [EPGRefresh] Debug: Call <bound method EPGRefresh._ToDoCallAutotimer of <Plugins.Extensions.EPGRefresh.EPGRefresh.EPGRefres h object at 0xadaeb410>>
< 800.6645> 06:40:34.0040 [EPGRefresh] Debug: Call AutoTimer: True
....
< 800.6701> 06:40:34.0096 [EPGRefresh] Debug: Calling nextTodo
< 800.6705> 06:40:34.0100 [EPGRefresh] Debug: Call <bound method EPGRefresh._ToDoAutotimerCalled of <Plugins.Extensions.EPGRefresh.EPGRefresh.EPGRefres h object at 0xadaeb410>>
< 800.6712> 06:40:34.0106 [EPGRefresh] Debug: Calling nextTodo
< 800.6715> 06:40:34.0110 [EPGRefresh] Debug: Call <bound method EPGRefresh._callFinishNotifiers of <Plugins.Extensions.EPGRefresh.EPGRefresh.EPGRefres h object at 0xadaeb410>>
< 800.6721> 06:40:34.0115 [EPGRefresh] Debug: Calling nextTodo
< 800.6724> 06:40:34.0119 [EPGRefresh] Debug: Call <bound method EPGRefresh.finish of <Plugins.Extensions.EPGRefresh.EPGRefresh.EPGRefres h object at 0xadaeb410>>
< 800.6729> 06:40:34.0124 [EPGRefresh] Debug: Refresh finished!

[satteliter]

Also just to document it. First human interaction with box was around 9 local time.
Had this message on screen:



2 jobs are running in the background!
2 jobs are running in the background!

Really shutdown now?

[Yes]
[No]


64927

[BrianG61UK]

On my Zgemma H7S I get the same effect sometimes where it's like the text is missing from the EPG so that multiple EPG entries look blank on the EPG.

I've been experimenting to try and figure out what's going on but I haven't really got very far yet.
I'm hindered by knowing C pretty well but not C++.

I find one thing that makes it go wrong on my Zgemma H7S is if I happen to be flicking through the channels at a time when the EPG is being read (by either OpenTV Zapper or by EPG Refresh).

I should add. For me this is not a new problem. I have always found the EPG would occasionally corrupt in this way (lots of blank entries).

I've been trying to make everything that's involved with reading the OpenTV EPG run at a high priority, but it doesn't seem to make any difference. But I may have missed something.
Weirdly, it looks like the current code actually runs (or is intended to run - it looks wrong to me) the EPG reading stuff at a low priority!?

[Joe_90]

Also just to document it. First human interaction with box was around 9 local time.
Had this message on screen:



64927

I was curious as to why your box didn't return to deep standby after 20 minutes (you said you had a PowerTimer set and I could see it mentioned in the log during startup). But I can see in the log that the box seems to be tuning various channels by itself (not related to EPGRefresh). Is this something to do with Unicable? Something to keep the LNB powered? The fact that two jobs (whatever they are) are running is what is keeping the box from reverting to deep standby. The crash at initial startup is worrying. Maybe you should do a clean flash and restore? Maybe it's a hardware/driver issue - wouldn't be the first with Gigablue. My own GB Quad+ will throw a C++ crash/error every few months for no apparent reason. Has been stable for months now, though - fingers crossed!

I just use a conventional LNB and the only channel that is tuned by the box after a PowerTimer boot is RTE1 (as this is set as the startup channel). If I don't interact with the box while it is in standby, nothing else is ever tuned unless ABM/OpenTVZapper is set to run.

[satteliter]

Is this something to do with Unicable? Something to keep the LNB powered?

Yip, I added 'Satellite equipment setup' plugin to solve an issue.i can't remember 100% what issue i initially changed it for - think it may have been to reduce/remove initial tune failed messages. Although I will add that there had been a power timer putting the box to deep standby after being standby for 60 mins - this behaved with no issues - i will leave sat equipment plugin active and disable after next run if it fails.

Box is a Vu+ Duo 4k SE .

So, for this morning's run, I had the following settings in play.

I had set a power timer to take the box out of deep standby into standby at 7.30 and go back to deep standby at 07:55
I then had ABM set to run at 07.32 and epgrefresh set to run at 07:40.
From there, it had Saorview Information(terrestrial) and IEPG data 1 (satellite) to run,
The other thing I had set was for rte1 to be the default startup channel.
I will change EPGRefresh to not attempt shutdown just in case it's interfering with AutoTimer (power timer already set to take care of shutdown)

Still not sure what was taking the box out of standby into active such that message was on screen (assuming EPGRefresh and ABM can run in standby - thinking this may have been setting rte1 as the startup channel - now disabled) edit: I think EPGRefresh needs to be out of standby judging the wording of the description for setting 'Wakeup up from standby for EPG refresh' - i have left this set to Yes

Logs attached for this morning. Crash again - i had updated to 6.3.003 yesterday I think but will get a full flash in this week.
649356493664937

All relevant setting screens attached as they were for this morning's run.
64943649426494164940649396493864944

On a positive note, no huffman encode errors in the last couple of runs!

On the crash side, I will just leave the error message here for web/search indexing as Google returned no results. When I loosened search terms, I got one results with that numeric string having to do with Greek ISO entry or something.


< 36.4421> 07:30:49.0585 [eDVBLocalTimerHandler] remove channel 0x69f738
< 36.4423> 07:30:49.0587 [eEPGTransponderDataReader] remove channel 0x69f738
< 36.4457> 07:30:49.0622 PC: 00000000
< 36.4458> 07:30:49.0622 Fault Address: 00000000
< 36.4458> 07:30:49.0623 Error Code: 2147484167
< 36.4460> 07:30:49.0625 Backtrace:
< 36.4462> 07:30:49.0627 /usr/bin/enigma2(_Z17handleFatalSignaliP9siginfo_tPv) [0x889D4]
< 36.4464> 07:30:49.0629 /lib/libc.so.6(__default_rt_sa_restorer) [0xB5B111D0]
< 36.4464> 07:30:49.0629 -------FATAL SIGNAL (11)

[Joe_90]

I've no idea what's causing the crash at initial startup from deep. One of the devs would need to take a look.

I think you're making things more complex than they need be. You have ABM and EPGRefresh and a PowerTimer set to wake the box. You have ABM and the PowerTimer trying to put the box in deep standby. To be honest, I would just disable EPGRefresh completely and let the built-in OpenTVZapper do the necessary. Both of these utilities tune the box to the Sky IEPG channel and the OpenTV reader downloads the schedule data for the EPG. I would leave the setting having RTE1 as the startup channel. The mere fact that it tunes RTE1 will download the Saorview EPG in seconds, assuming you have Enable EIT EPG set to YES.

What I would suggest is to leave the PowerTimer set to boot to standby at 07.30 daily and go back into deep standby at 07.55. Have ABM set to run at 07.35 on whatever days you wish, but do not set any wake or shutdown options for ABM (you are already controlling the startup/shutdown with the PowerTimer). Have OpenTVZapper enabled in the EPG options. Set a schedule time (rater than the automatic interval) in the zapper settings - you could do this at 07.40 if you wanted to wait until after ABM had run. This means that the PowerTimer is controlling the startup/shutdown and you are scheduling events to happen during the period. If one of the other plugins related to unicable or FCC or whatever is affecting the EPG acquisition, then it is a matter of eliminating the plugins one by one until the culprit is located.

My routine is that the box is scheduled to boot at 17.49 (my box is slow to boot - it's old), then at 17.52 the zapper runs and finishes by 17.55. At 18.01 I have a timer set to record the news from RTE1. If no-one is around, the box will automatically go back into deep standby after the recording is done. I have a separate ABM schedule set to run at 04.30 on Tuesday and Thursday to update any bouquet changes. It uses the ABM scheduler to boot and shutdown the box - no PowerTimer used. Here are my EPG, PowerTimer and zapper settings:

[satteliter]

I think you're making things more complex than they need be

Agreed! I updated things after this morning's run to only have the power time dealing with standby on/off.

I've disabled ABM & EPGRefresh from wake/shutdown actions.

OpenTV EPG corruption was causing the issues.
If these issues persist past tomorrow, I will just use OpenTV scheduled for satellite and let terrestrial populate on boot as you've recommended.
Thanks for the screenshots.



I've no idea what's causing the crash at initial startup from deep. One of the devs would need to take a look.

Is that on this forum or some enigma forum/github?

[satteliter]

Just realised how to narrow down that crash. Started when I started using EPGRefresh. I've been keeping all the logs.
I'm curious to see if it's a coincidence or not.64948

[Joe_90]

Agreed! I updated things after this morning's run to only have the power time dealing with standby on/off.

I've disabled ABM & EPGRefresh from wake/shutdown actions.

OpenTV EPG corruption was causing the issues.
If these issues persist past tomorrow, I will just use OpenTV scheduled for satellite and let terrestrial populate on boot as you've recommended.
Thanks for the screenshots.




Is that on this forum or some enigma forum/github?

A couple of the OpenVix devs should be able to identify the offending module. In the meantime, if you've disabled EPGRefresh, let's see if the crashes stop.

[satteliter]

So todays update is:

- everything worked! no crashes. EPG populated(both terrestrial & sat). EPGRefresh did it's job/ No huffman encode errors! No messages on screen -> Box was in deep standby when i went to check it.

[just to add some unrelated - i switched wifi off and went with wired for network connection.
Log(singular!) attached

64950


wifi info in log is just fake name & pwd i set]

[Joe_90]

That's a better results - hopefully will remain stable. By the way, there is no need to set the Saorview channel in EPGRefresh - the initial tune to RTE will download the Saorview EPG in seconds. I think you also may have the OpenTV Zapper enabled as I can see entries in the log for it. I suggest that you use either OpenTV zapper or EPGRefresh - not both.

[satteliter]

update:

yesterday morning(7th) ran fine with no crash.
this morning(8th) - i had ABM set to run(& wake from deep standby) at ~03.30. There was a crash at that time.

There was also a later crash near when EPGRefresh(not set to wake up from deep standby) ran at ~07.40.


03.30 crash:


< 38.4470> 03:29:53.0296 [eDVBLocalTimerHandler] remove channel 0x1027468
< 38.4474> 03:29:53.0299 [eEPGTransponderDataReader] remove channel 0x1027468
< 38.4510> 03:29:53.0335 PC: 00553308
< 38.4510> 03:29:53.0336 Fault Address: 00553308
< 38.4511> 03:29:53.0336 Error Code: 2147484175
< 38.4512> 03:29:53.0338 Backtrace:
< 38.4514> 03:29:53.0340 /usr/bin/enigma2(_Z17handleFatalSignaliP9siginfo_tPv) [0x889D4]
< 38.4516> 03:29:53.0341 /lib/libc.so.6(__default_rt_sa_restorer) [0xB5B511D0]
< 38.4516> 03:29:53.0342 -------FATAL SIGNAL (11)


07.37 crash:

< 39.3109> 07:37:53.2914 [eDVBLocalTimerHandler] remove channel 0x1024d50
< 39.3113> 07:37:53.2918 [eEPGTransponderDataReader] remove channel 0x1024d50
< 39.3143> 07:37:53.2948 PC: 17b4aecc
< 39.3144> 07:37:53.2949 Fault Address: 17b4aecc
< 39.3144> 07:37:53.2949 Error Code: 2147484166
< 39.3146> 07:37:53.2951 Backtrace:
< 39.3148> 07:37:53.2953 /usr/bin/enigma2(_Z17handleFatalSignaliP9siginfo_tPv) [0x889D4]
< 39.3150> 07:37:53.2955 /lib/libc.so.6(__default_rt_sa_restorer) [0xB5BA11D0]
< 39.3151> 07:37:53.2955 -------FATAL SIGNAL (11)

64969
64968
64970

64971
64972
64973

What's interesting to note is ABM did not put box back to deep standby. i think this is because i had hdmi-cec settings which took tv out of standby when box came out of standby (which ABM (i think) did)). The TV then must have been sending the wakeup hdmi-cec signal such that the box never went back to standby(judging from log entries)

I've since moved ABM to run after the scheduled auto power timer turns box on(~07.30) and turned off 'wake/return to standby' settings for ABM.
Also disabled HDMI-CEC turn on tv settings for the time being.

I've attached log from the successful run yesterday just for the record:

64974

Will monitor and update.

[satteliter]

I think you also may have the OpenTV Zapper enabled as I can see entries in the log for it. I suggest that you use either OpenTV zapper or EPGRefresh - not both. .

It was disabled when I installed EPGRefresh. I think those entries will be present regardless of status.


[OpentvZapper] < 1066.1597> 07:55:00.1402 [OpentvZapper] next wake up due -1
....
< 34.5017> 07:37:48.4822 [OpentvZapper-Scheduler][Scheduleautostart] AutoStart Enabled
< 34.5019> 07:37:48.4824 [OpentvZapper-Scheduler][AutoScheduleTimer] Schedule Disabled at Wed 08 Mar 2023 07:37:48 GMT

[satteliter]

So just to close this issue off, the days since the last post have been trouble free. No crashes, no huffman errors & most importantly - no empty EPGs.

The following are the settings that were in play. The brief version is ABM and EPGRefresh no longer handled wake up or shutdown. They ran within the power timer scheduled on/off.650006500165002


Here are the logs for the morning run logs for the last few days in case it provides any historical/future troubleshooting use:


9th 65003
10th 65004
11th 65005
12th 65006

If any crashes/errors discussed in this thread appear again I'll open new thread.

Thank you all for your assistance!

[BrianG61UK]

On my Zgemma H7S I get the same effect sometimes where it's like the text is missing from the EPG so that multiple EPG entries look blank on the EPG.

I've been experimenting to try and figure out what's going on but I haven't really got very far yet.
I'm hindered by knowing C pretty well but not C++.

I find one thing that makes it go wrong on my Zgemma H7S is if I happen to be flicking through the channels at a time when the EPG is being read (by either OpenTV Zapper or by EPG Refresh).

I should add. For me this is not a new problem. I have always found the EPG would occasionally corrupt in this way (lots of blank entries).

I've been trying to make everything that's involved with reading the OpenTV EPG run at a high priority, but it doesn't seem to make any difference. But I may have missed something.
Weirdly, it looks like the current code actually runs (or is intended to run - it looks wrong to me) the EPG reading stuff at a low priority!?

Do no other people find that flicking from channel to channel (satellite channels) while OpenTV EPG download starts doesn't cause a problem?

I'm wondering if it's some weird bug that's specific to Zgemma or to the Zgemma H7.

[abu baniaz]

Sky UK changes are normally Tuesday/Thursday. Consider changing your days to Wednesday/Friday.

[urie]

@abu baniaz, with reguards to OpenTV zapper do you think it could be ported to openatv, I use epg refresh I select a few channels only for freeview bbc one and E4 but with reguards to IEPG data 1 when I select that in epgrefresh obviously no signal as to speak in autobouqets maker I don't want to have bouquet sky info shown and in epg main setting i have nothing enabled
I know I can just select a channel on freeview and epg will be pulled in but would be good to have epg there without having to zap to a channel if possible
65007

[abu baniaz]

You will have to ask ATV, but it is just a zapper. You can select iepg from service list instead of bouquet.

[Joe_90]

Do no other people find that flicking from channel to channel (satellite channels) while OpenTV EPG download starts doesn't cause a problem?

I'm wondering if it's some weird bug that's specific to Zgemma or to the Zgemma H7.

Definitely causes an issue (sometimes!). I can't pin it down. I know if I don't disturb the download, then I have no issues with the EPG.

[LraiZer]

So this huffman issue only happens when a user zapperdy zap zap zaps on multi-tuner box... eg. zapping tuner 1 while opentv zapper has also initiated an epg download on tuner 2?

Many..

< 438.7103> 17:45:54.2754 [huffman] Error. Cannot decode Huffman data

huffman_root is being reset to NULL each zap prior to the check for valid epg transpoder in the call to the huffman_read_dictionary() function.

I think moving the code in huffman.cpp for the epg transponder validation check so that it is above the huffman_root NULL should stop those huffman decode errors.


diff --git a/lib/base/huffman.cpp b/lib/base/huffman.cpp
index 70ef87c8a8..a8e6be661c 100644
--- a/lib/base/huffman.cpp
+++ b/lib/base/huffman.cpp
@@ -12,6 +12,13 @@ type_huffman_node huffman_root;
bool huffman_read_dictionary (char *file)
{
FILE *fd;
+ fd = fopen (file, "r");
+
+ if (!fd)
+ return false;
+ else
+ eDebug("[huffman] read.. '%s'", file);
+
char line[512];
char value[256];
char code[256];
@@ -24,15 +31,6 @@ bool huffman_read_dictionary (char *file)
huffman_root.p0 = NULL;
huffman_root.p1 = NULL;

- eDebug("[huffman] read.. '%s'", file);
-
- fd = fopen (file, "r");
- if (!fd)
- {
- //eDebug("[huffman] Cannot open dictionary file");
- return false;
- }
-
while (fgets (line, sizeof(line), fd))
{
memset (value, 0, sizeof (value));

[Joe_90]

So this huffman issue only happens when a user zapperdy zap zap zaps on multi-tuner box... eg. zapping tuner 1 while opentv zapper has also initiated an epg download on tuner 2?

Many..


huffman_root is being reset to NULL each zap prior to the check for valid epg transpoder in the call to the huffman_read_dictionary() function.

I think moving the code in huffman.cpp for the epg transponder validation check so that it is above the huffman_root NULL should stop those huffman decode errors.

...


Yep - I think that about describes the error situation - zapping while the OpenTVzapper is running seems to trigger the runaway error messages. It would be great if a code change could be made. Happy to test.

[abu baniaz]

I have submitted a pull request here: https://github.com/OpenViX/enigma2/pull/849
A build will need to be run for it to be tested

[LraiZer]

patch missing this line from above...

- eDebug("[huffman] read.. '%s'", file);

[abu baniaz]

@joe_90
Any update on the change. If OK, we can submit pull request to other images.

[Joe_90]

Waiting on dev build 6.3.004.013 - the 011 and 012 builds did not work for me as there was a bug in menu.py which surfaced in my sorted menu. I did run the 012 build for a couple of days unattended on my single tuner HD61and the scheduled run of OpenTVzapper worked fine, but I didn't try to provoke the huffman error. Once 013 is available I will download later tonight on my Quad Plus and test.

[Joe_90]

Dev build 013 does not seem to have completed for ax61HD. I did flash the 013 build for the QuadPlus early this morning and will test it.

[Joe_90]

Dev build 014 has completed for the AX61HD. Have downloaded and flashed ok. Looks good so far. My AX61HD has only a single DVB-S tuner, so can't verify huffman issue on it. I am testing that on the Quad Plus.

[Joe_90]

Dev build 014 for Quad Plus tested for the "huffman error" bug. I can't provoke the runaway log error, despite switching DVB-S and DVB-T channels and starting recordings etc. while the OpenTVZapper is running. Problem seems fixed on the development/test image. Should be good for Release. Thanks @LraiZer and @abu baniaz!

[BrianG61UK]

I just built myself a 6.3.004.015 developer image for my Zgemma H7S and I too am unable to provoke it into showing blank EPG entries by doing things like channel zapping while OpenTV EPG download is occurring.

This is most excellent news.

Thank you @LraiZer. :):):):):):) :thumbsup: