PDA

View Full Version : [VU+ Ultimo4K] TV Channel Failed to Record - Zero Filesize (Logs provided)



SkyFan
02-10-21, 09:05
I recently upgraded my Vix image to 5.4.014. Not had any issues over the past several days of using that image and I've been recording the exact same things every weekday via manually created repeat timers. Nothing failed to record until yesterday on Oct 1 when this failed to record and had a filesize of zero when looking at the filesize via FTP:
20211001 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts.

The following things were recording at the same time when the Good Morning Britain recording failed:



LBC Radio
BBC Radio 1
BBC Radio 2
BBC R1X (radio)
BBC WS (radio)
BBC One HD: BBC Breakfast
GB News HD: Great British Breakfast
ITV Border England HD: Good Morning Britain


I have Two S2X twin tuner cards installed with each port connected to a standard LNB.

Debug file and timers file attached: 62638

Could you please tell me what the problem is? I've only had this problem happen before when recording radio channels but now I'm getting it on TV channels. I've also noticed that I can do nothing and it will fail to record a show one day but then it records it fine the next day.

The tuners show this on my box
A= Simple, single, 28.2
B = Simple, single, 28.2
I = Simple, single, 28.2
J = Simple, single, 28.2

All the other 12 are FBC Automatic

ccs
02-10-21, 09:32
It doesn't start recording for some reason (error code -6)...

(Snips)



Line 46199: 06:05:02.3123 [eDVBServiceRecord] now running: †Good Morning Sunday‡ (10800 seconds)
Line 56776: 05:58:40.0102 [RecordTimer] Filename calculated as: '/media/hdd/movie/20210927 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am'
Line 57101: 05:59:00.0561 [eDVBServiceRecord] Recording to /media/hdd/movie/20210927 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts...
Line 57143: 06:00:02.4322 [eDVBServiceRecord] now running: †Good Morning Britain‡ (10800 seconds)
Line 58187: 09:01:00.5575 [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/20210927 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts

Line 71797: 05:58:40.0098 [RecordTimer] Filename calculated as: '/media/hdd/movie/20210928 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am'
Line 72119: 05:59:00.0629 [eDVBServiceRecord] Recording to /media/hdd/movie/20210928 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts...
Line 72155: 06:00:01.8806 [eDVBServiceRecord] now running: †Good Morning Britain‡ (10800 seconds)
Line 73150: 09:01:00.5091 [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/20210928 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts

Line 86662: 05:58:40.0101 [RecordTimer] Filename calculated as: '/media/hdd/movie/20210929 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am'
Line 86986: 05:59:00.0704 [eDVBServiceRecord] Recording to /media/hdd/movie/20210929 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts...
Line 87020: 06:00:00.6869 [eDVBServiceRecord] now running: †Good Morning Britain‡ (10800 seconds)
Line 88103: 09:01:00.5395 [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/20210929 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts

Line 102206: 05:58:40.0101 [RecordTimer] Filename calculated as: '/media/hdd/movie/20210930 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am'
Line 102538: 05:59:00.0863 [eDVBServiceRecord] Recording to /media/hdd/movie/20210930 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts...
Line 102572: 06:00:01.5326 [eDVBServiceRecord] now running: †Good Morning Britain‡ (10800 seconds)
Line 103850: 09:01:00.5520 [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/20210930 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am.ts

Line 119655: 05:58:40.0275 [RecordTimer] Filename calculated as: '/media/hdd/movie/20211001 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am'

05:58:40.0311 [eDVBServiceRecord] RECORD service event 0
05:58:40.0314 [RecordTimer] 'prepare' failed: error -6
05:58:40.0315 [RecordTimer] backoff: retry in 5 seconds
05:58:40.0315 [eDVBServiceRecord] stop recording!
05:58:40.0315 [eDVBServiceRecord] (was not recording)
05:58:40.0326 [Trashcan] Recording(s) in progress: 5
05:58:40.0331 [RecordTimer] prepare failed
05:58:40.0333 [RecordTimer] zap without asking
05:58:40.0335 [RecordTimer] ok, zapped away
05:58:40.0436 [Navigation] playing 1:0:19:1B1D:802:2:11A0000:0:0:0:
05:58:40.0440 [eDVBCAService] free slot 2 demux 0 for service 1:0:19:5172:810:2:11A0000:0:0:0::ITV Border England HD
05:58:40.0440 [eDVBCAService] free service 1:0:19:5172:810:2:11A0000:0:0:0::ITV Border England HD

ccs
02-10-21, 10:09
..... Error code -6 is errAllSourcesBusy.

SkyFan
02-10-21, 14:21
Any idea what all sources busy could mean? I should have plenty of tuners available so I don't see how it could be that.

My hard drive wasn't anywhere near full so it wasn't because there was no space left on the drive.

ccs
02-10-21, 14:30
My guess would be that the channel isn't available at that particular time.

I'll have a look at the timers file.

ccs
02-10-21, 15:18
Timestamps suggest the timer was "active" for 3 hours...


<log code="15" time="1632988860">record time changed, start prepare is now: Fri Oct 1 05:58:40 2021</log>
<log code="5" time="1633064320">activating state 1 (Prepared)</log>
<log code="0" time="1633064320">Found enough free space to record</log>
<log code="0" time="1633064320">Filename calculated as: &apos;/media/hdd/movie/20211001 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5&apos;59am-9&apos;01am&apos;</log>
<log code="6" time="1633064320">prepare ok, waiting for begin</log>
<log code="5" time="1633064340">activating state 2 (Running)</log>
<log code="11" time="1633064340">start recording on tuner: A</log>
<log code="5" time="1633075260">activating state 3 (Ended)</log>
<log code="12" time="1633075260">stop recording on tuner: A</log>

ccs
02-10-21, 16:22
Maybe this bit of the debug log makes it clearer (to someone) ?


05:58:40.0271 [RecordTimer] Found enough free space to record
05:58:40.0275 [RecordTimer] Filename calculated as: '/media/hdd/movie/20211001 0559 - ITV Border England HD - Good Morning Britain (Mon-Fri) 5'59am-9'01am'
05:58:40.0277 [Navigation] recording service: 1:0:19:5172:810:2:11A0000:0:0:0::ITV Border England HD
05:58:40.0280 [eDVBResourceManager] allocate channel.. 0810:0002
05:58:40.0280 [eDVBResourceManager] available channel.. 07fe:0002
05:58:40.0281 [eDVBResourceManager] available channel.. 07ff:0002
05:58:40.0281 [eDVBResourceManager] available channel.. 0831:0002
05:58:40.0281 [eDVBResourceManager] available channel.. 0810:0002
05:58:40.0281 [eDVBResourceManager] found shared channel..
05:58:40.0282 [eDVBServicePMTHandler] allocate Channel: res 0
05:58:40.0282 [eDVBCIInterfaces] addPMTHandler 1:0:19:5172:810:2:11A0000:0:0:0::ITV Border England HD
05:58:40.0282 [eDVBChannel] getDemux cap=00
05:58:40.0285 [eEPGCache] saveEventToFile epg event id 91
05:58:40.0288 [RecordTimer] prepare ok, waiting for begin
05:58:40.0290 [Trashcan] Recording(s) in progress: 5
05:58:40.0293 [RecordTimer] activating state 1 (Prepared)
05:58:40.0302 [RecordTimer] Found enough free space to record
05:58:40.0306 [RecordTimer] Filename calculated as: '/media/hdd/movie/20211001 0559 - BBC One HD - xNewsx - BBC Breakfast (Mon-Fri) 5'59am-9'16am'
05:58:40.0307 [Navigation] recording service: 1:0:19:1B1D:802:2:11A0000:0:0:0:
05:58:40.0310 [eDVBResourceManager] allocate channel.. 0802:0002
05:58:40.0310 [eDVBResourceManager] available channel.. 07fe:0002
05:58:40.0310 [eDVBResourceManager] available channel.. 07ff:0002
05:58:40.0310 [eDVBResourceManager] available channel.. 0831:0002
05:58:40.0311 [eDVBResourceManager] available channel.. 0810:0002
05:58:40.0311 [eDVBResourceManager] available channel.. 083e:0002
05:58:40.0311 [eDVBServicePMTHandler] allocate Channel: res -6
05:58:40.0311 [eDVBServiceRecord] RECORD service event 0
05:58:40.0314 [RecordTimer] 'prepare' failed: error -6
05:58:40.0315 [RecordTimer] backoff: retry in 5 seconds
05:58:40.0315 [eDVBServiceRecord] stop recording!
05:58:40.0315 [eDVBServiceRecord] (was not recording)
05:58:40.0326 [Trashcan] Recording(s) in progress: 5
05:58:40.0331 [RecordTimer] prepare failed
05:58:40.0333 [RecordTimer] zap without asking
05:58:40.0335 [RecordTimer] ok, zapped away
05:58:40.0436 [Navigation] playing 1:0:19:1B1D:802:2:11A0000:0:0:0:
05:58:40.0440 [eDVBCAService] free slot 2 demux 0 for service 1:0:19:5172:810:2:11A0000:0:0:0::ITV Border England HD
05:58:40.0440 [eDVBCAService] free service 1:0:19:5172:810:2:11A0000:0:0:0::ITV Border England HD
05:58:40.0576 [Pixmap] setPixmapNum(0) failed! defined pixmaps: []
05:58:40.0589 [eTSMPEGDecoder] decoder state: play, vpid=ffffffff, apid=ffffffff
05:58:40.0589 [eDVBPCR0] DEMUX_STOP ok
05:58:40.0590 [eDVBPCR0] destroy
05:58:40.0590 [eDVBVideo0] DEMUX_STOP ok
05:58:40.0598 [eDVBVideo0] VIDEO_STOP ok
05:58:40.0635 [eDVBVideo0] destroy
05:58:40.0636 [eDVBAudio0] AUDIO_STOP ok
05:58:40.0915 [eDVBAudio0] DEMUX_STOP ok
05:58:40.0915 [eDVBAudio0] AUDIO_CONTINUE ok
05:58:40.1003 [eDVBAudio0] destroy
05:58:40.1004 [eDVBText0] DEMUX_STOP ok
05:58:40.1009 [eDVBText0] destroy
05:58:40.1196 [Pixmap] setPixmapNum(0) failed! defined pixmaps: []
05:58:40.1203 [Pixmap] setPixmapNum(0) failed! defined pixmaps: []
05:58:40.1208 [Pixmap] setPixmapNum(0) failed! defined pixmaps: []
05:58:40.1213 [Notifications] RemovePopup, id = ZapError
05:58:40.1214 [eDVBResourceManager] allocate channel.. 0802:0002
05:58:40.1215 [eDVBResourceManager] available channel.. 07fe:0002
05:58:40.1215 [eDVBResourceManager] available channel.. 07ff:0002
05:58:40.1215 [eDVBResourceManager] available channel.. 0831:0002
05:58:40.1215 [eDVBResourceManager] available channel.. 0810:0002
05:58:40.1215 [eDVBResourceManager] available channel.. 083e:0002
05:58:40.1217 [eDVBServicePMTHandler] allocate Channel: res -6
05:58:40.1217 [eDVBServicePlay] DVB service failed to tune - error 0
05:58:40.1221 [Notifications] RemovePopup, id = ZapError
05:58:40.1221 [Notifications] AddPopup, id = ZapError
05:58:40.1841 [eDVBFrontend9] set static current limiting
05:58:40.1850 [eDVBFrontend9] invalidate current switch params
05:58:40.1851 [eDVBFrontend9] setVoltage 1
05:58:40.1851 [eDVBFrontend9] setVoltage FE_ENABLE_HIGH_LNB_VOLTAGE 0 FE_SET_VOLTAGE 0
05:58:40.1958 [eDVBFrontend9] sleep 10ms
05:58:40.2060 [eDVBFrontend9] set sequence pos 3
05:58:40.2061 [eDVBFrontend9] update current switch params
05:58:40.2061 [eDVBFrontend9] startTuneTimeout 5000
05:58:40.2062 [eDVBFrontend9] setFrontend 1
05:58:40.2063 [eDVBFrontend9] setting frontend
05:58:40.2155 [eDVBFrontend9] fe event: status 0, inversion off, m_tuning 1
05:58:40.2156 [eDVBFrontend9] sleep 500ms
05:58:40.2987 [eDVBFrontend9] fe event: status 1f, inversion off, m_tuning 2
05:58:40.2987 [eDVBChannel] OURSTATE: ok
05:58:40.2988 [eDVBLocalTimerHandler] channel 0x1b11c60 running
05:58:40.2988 [eDVBChannel] getDemux cap=00
05:58:40.2988 [eDVBDemux] open demux /dev/dvb/adapter0/demux3
05:58:40.2990 [eDVBSectionReader] DMX_SET_FILTER pid=20
05:58:40.2994 [eEPGTransponderDataReader] channel 0x1b11c60 running
05:58:40.2994 [eDVBChannel] getDemux cap=00
05:58:40.2994 [eDVBDemux] open demux /dev/dvb/adapter0/demux3
05:58:40.2995 [eDVBDemux] open demux /dev/dvb/adapter0/demux3
05:58:40.2995 [eDVBDemux] open demux /dev/dvb/adapter0/demux3

twol
02-10-21, 16:46
Any idea what all sources busy could mean? I should have plenty of tuners available so I don't see how it could be that.

My hard drive wasn't anywhere near full so it wasn't because there was no space left on the drive.

So whats attached to the tuners standard LNB‘s or mixture of unicable and standard?

abu baniaz
02-10-21, 19:28
He only has Universal LNBs.

ronand
02-10-21, 21:15
Not enough tuners by the looks of it. But the conflict detection should have picked that up when setting the timers.

ccs
02-10-21, 21:27
Could it be anything to do with this change the OP made about a week ago, when the timers were already set??



Thanks. I entered this and "ITV Border England HD" appears but ITV Border Scotland doesn't appear:


<insert target="004" source="803" provider="sat_282_sky_uk"></insert> <!-- ITV Border England HD -->
<insert target="005" source="1020" provider="sat_282_sky_uk"></insert> <!-- ITV Border Scotland SD -->

abu baniaz
02-10-21, 21:34
In his other thread, I asked him several times to say which polarisation and frequency he was trying to record. It will really help track issue down if it is a tuner issue. Somebody on another forum who is using universal LNBs posted an issue which may be similar.

Other thread is here:
I must apologise, I never got to test on Duo 4K.
https://www.world-of-satellite.com/showthread.php?64287-Some-recordings-fail-to-record-once-a-month

Also, he has two dishes for 28.2. One has reception issues on some frequencies/transponders. I am not sure if all 4 cables to the Ultimo 4k are from the same dish or if he has a mix-match

SkyFan
03-10-21, 12:13
In his other thread, I asked him several times to say which polarisation and frequency he was trying to record.

Other thread is here:
I must apologise, I never got to test on Duo 4K.
https://www.world-of-satellite.com/showthread.php?64287-Some-recordings-fail-to-record-once-a-month

Also, he has two dishes for 28.2. One has reception issues on some frequencies/transponders. I am not sure if all 4 cables to the Ultimo 4k are from the same dish or if he has a mix-match

All Universal LNB cables in my box in question are going to the same dish.

I have recorded way more stuff at the same time as each other before than what I posted in my original post so it doesn't make sense that there's not enough free tuners to record ITV. If it was a polorization issue then wouldn't it prevent stuff being recording on that channel later in the day? Yet 4 hours after the failed recording I recorded This Morning on the same channel at 9.49AM and that recorded fine.

I looked at that thread you mentioned. When watching a channel if I press Up, highlight the service and look at the screen then I can't see the frequency and polorization as it doesn't show in the Magic HD Night skin.

I instead pressed up when watching a channel > Menu > Show Transponder Info > Tuner Settings Values. It says
"Frequency & Polarization: 11067 MHz - Vertical". I assume that's the correct info you need?

If there's any more tests you need me to do please let me know and I'll get them done straight away. Thanks

abu baniaz
03-10-21, 16:05
As I mentioned in the other threads of yours, the sequence in which the tuners are used is also relevant. If there is a bug, we need to have a repeatable/reliable method to reproduce it. If it is a driver issue, we also need to describe this to the manufacturer so they can look at it.

You need to list the transponder details for all the services you are having issues. Use Simple 1080 or Vix Night HD or any other skin that has the details. Change back after you get the details. Which ITV are you referring to? There are so many of them on different transponders. Would be so much easier if the information was supplied.

If it is just that the service has moved to a different frequency on the satellite, the only solution is to record on the new one

BrokenUnusableAccount
03-10-21, 18:39
If the dish is slightly out of alignment so that it doesn't work well on every transponder, then it's totally possible that different clouds, rain, sunshine, gusts of wind, air temperature and so on can mean a transponder is unusable at one time but working fine at another time.

SkyFan
03-10-21, 19:41
As I mentioned in the other threads of yours, the sequence in which the tuners are used is also relevant. If there is a bug, we need to have a repeatable/reliable method to reproduce it. If it is a driver issue, we also need to describe this to the manufacturer so they can look at it.

You need to list the transponder details for all the services you are having issues. Use Simple 1080 or Vix Night HD or any other skin that has the details. Change back after you get the details. Which ITV are you referring to? There are so many of them on different transponders. Would be so much easier if the information was supplied.

If it is just that the service has moved to a different frequency on the satellite, the only solution is to record on the new one

Is the transponder details I posted in my previous post not correct? If that method I mentioned to get the details works then I'd rather not change Skins to get the details because won't it split my recordings in two when the GUI reboots? I'm always recording stuff you see such as radio stations 24/7.

The transponder details I posted were for ITV Border England HD. In the current image I'm using which I started using recently, I've only had one thing fail to record and it was on that channel.

If there's anything else you need me to do then please let me know.

adm
03-10-21, 21:13
If the dish is slightly out of alignment so that it doesn't work well on every transponder, then it's totally possible that different clouds, rain, sunshine, gusts of wind, air temperature and so on can mean a transponder is unusable at one time but working fine at another time.

There have also been some major problems in the last week with both UK satellite and terrestrial transmission control with backup facilities having to be used after a fire or the fire suppressant equipment damaged a lot of equipment. It's the reason that some of the "4" and "5" channels were off air for a while, AD and subtitles may not be working correctly, adverts may be missing, and probably the reason that "5" channels have a little on screen square coloured black and white indicating backup facilities. The BBC transmission control has also been moved. There have also been some knock-on problems.