[confirm] Recording failing on some channels (1 Viewer)

[Kaoh]

MediaPortal Version: 1.1.0.0 RC1
MediaPortal Skin: Blue3wide
Windows Version: windows 7 ultimate
1. TV Card: 2xFloppyDTV
2. TV Card Type: DVB-T

Problem with recording the second recording or the channel I am not sure.
But it is recording one channel fine, then a second recording starts and it can not create the file or something. But the file is never created and the recording stops after 15 sec trying again and again for some time.

I did not have these problems on Vista where it was running before.

 

[Kaoh]

Testing the fix posted here: https://forum.team-mediaportal.com/.../tvservice-dying-very-often-78740/index6.html by morpheus
But now it seems it can no longer use my second tuner, the second recording now never starts any more and using a client to access a second channel gives me a unknown error dialog.

It does seem to fix this problem for me: https://forum.team-mediaportal.com/general-support-51/tv-service-freezes-watching-live-tv-80247/

 

[Kaoh]

See the logs attached, it does try to tune the second tuner but fails and the error log fills up with exceptions

 

[elliottmc]

You have two of the same tuner cards, correct?

If so, try removing one, to test each in turn. Maybe you have a faulty tuner?

Could you please post full logs rather than being selective? Otherwise the team has to guess!

Mark

 

[Kaoh]

Depending on wich tuner is used for the first recording the other fails, this always worked till the reinstall last weekend.
Since it moves from one tuner to the other I am not going to take appart the server to remove one
i will make new clean logs tonight and post them all. I did not see any relevant lines in those logs so that is why they where not posted.

 

[elliottmc]

Depending on wich tuner is used for the first recording the other fails, this always worked till the reinstall last weekend.
Since it moves from one tuner to the other I am not going to take appart the server to remove one
i will make new clean logs tonight and post them all. I did not see any relevant lines in those logs so that is why they where not posted.

Hi,

Even if there is nothing in the logs to indicate what the problem is, a 'normal' clean log will at least show what is working correctly on your system, and can therefore be of use to the team in finding out what your problem is.

Regards,

Mark

 

[Kaoh]

Well in an attempt to create clean logs with the problems in them I banned the family to watch recordings or live tv using mediaportal and told them to watch the recordings using the my video version that was mapped to the recordings share.
I scheduled a lot of recordings during the last two days, some single and some that would require both tuners.
And offcourse, it is all working fine now.
It recorded every schedule and both tuners worked fine.
I keep the ban on the live tv and let them use the my videos to watch the recordings and see how long it keeps running.
Else it is clearly related to using the client. But that is a problem allready looking at the many bugs on that part (for example: https://forum.team-mediaportal.com/...dying-very-often-78740/index6.html#post601137) so I guess waiting for RC2 and retest everything is now the best solution unless I get this problem again.

 

[Kaoh]

I finally got the problem back. So I attached the logs. The only thing it is that it now responded that the channel was scrambled. Although I have a subscribtion and a working cam. I had to shutdown the server and then boot it again to get the channels unscrambled again on that tuner.
The thing with this setup is that I have two different CAM modules inside two FloppyDTV tuners (except one is a FirDTV).
So it may be a CAM issue or a tuner issue in this case. The weird thing is that it does work after the shutdown/boot cycle again. So it does work in the basics.
The recording failed some minutes into the recording that started at 16:15 in the logs and then later on at 20:00 it tried another channel that was scrambled, it also recorded a unscrambled channel with success but that recording never stopped anymore. So the guestion is why did it suddenly fail the unscrambling? Does anyone know if there is a known issue with using different CAM modules with Fire/Floppy DTV tuners?

Btw, I could not attach the error.log since it as 0 bytes.

 

[Kaoh]

Hi now it it really failed, I had 3 programs scheduled. One seemes to have started but no files generated and the rest never even got an attempt.
This is what I originally reported.
The logs are attached.
What is strange is that the tswriter log is not updated at the recording time.
The first show was scheduled to start at 20:15 and the two other where shows that trailed that one.
Again no errors in the error log (0b) so it could not be attached. The server was freshly booted this morning. Nothing recorded since the boot.

 

[riksmith]

The tv.log seems a bit short of logging after new subchannel. There should be a lot more logging. for instance:

2010-04-05 11:25:43.289489 [(16)]: dvb:Submiting tunerequest Channel:SBS 6 subChannel:-1 
2010-04-05 11:25:43.290489 [(16)]: dvb:Getting new subchannel
2010-04-05 11:25:43.290489 [(16)]: dvb:GetNewSubChannel:0 #0
2010-04-05 11:25:43.293489 [(16)]: TvDvbChannel ctor new subchIndex:0
2010-04-05 11:25:43.294489 [(16)]: dvb:Submit tunerequest size:1 new:0
2010-04-05 11:25:43.294489 [(16)]: subch:0 OnBeforeTune
2010-04-05 11:25:43.296490 [(16)]: dvb:Submit tunerequest calling put_TuneRequest
2010-04-05 11:25:43.296490 [(16)]: dvb:Submit tunerequest done calling put_TuneRequest
2010-04-05 11:25:43.297490 [(16)]: subch:0 OnAfterTune
2010-04-05 11:25:43.298490 [(16)]: FireDTV: HW Filtering disabled.
2010-04-05 11:25:43.298490 [(16)]: FireDTV: Set H/W pid filtering is not supported
2010-04-05 11:25:43.299490 [(16)]: subch:0 OnGraphStart
2010-04-05 11:25:43.299490 [(16)]: dvb:  RunGraph
2010-04-05 11:25:43.637509 [(16)]: dvb:  LockedInOnSignal ok
2010-04-05 11:25:43.638509 [(16)]: subch:0 OnGraphStarted
2010-04-05 11:25:43.639509 [(16)]: subch:0 SetupPmtGrabber:pid 0 sid:4A3B
2010-04-05 11:25:43.640509 [(16)]: subch:0 set pmt grabber pmt:0 sid:4A3B
2010-04-05 11:25:43.641509 [(16)]: WaitForPMT: Using new way for PMT grabbing via PAT
2010-04-05 11:25:43.642509 [(16)]: WaitForPMT: Waiting for SID 19003
2010-04-05 11:25:43.847521 [(14)]: subch:0 OnPMTReceived() pmt:DC ran:True dynamic:False
2010-04-05 11:25:43.848521 [(16)]: WaitForPMT: Found PMT after 0,2060118 seconds.
2010-04-05 11:25:43.849521 [(16)]: subch:0 SendPmt:4A3B 4A3B FFFFFFFF 1A
2010-04-05 11:25:43.849521 [(16)]: Decode pmt
2010-04-05 11:25:43.850521 [(16)]: descr1 len:6 9 4 6 4 ef a2 
2010-04-05 11:25:43.851521 [(16)]: descr1 len:6 9 4 6 2 f3 8a 
2010-04-05 11:25:43.852521 [(16)]: Set descriptor data with length 6
2010-04-05 11:25:43.852521 [(16)]: Set descriptor data with length 7
2010-04-05 11:25:43.853521 [(16)]: subch:0 SendPMT version:26 len:73 19003
2010-04-05 11:25:43.857522 [(16)]: FireDTV:GetCAMStatus() finished
2010-04-05 11:25:43.858522 [(16)]:   FireDTV:cam is inserted
2010-04-05 11:25:43.859522 [(16)]:   FireDTV:cam is valid
2010-04-05 11:25:43.860522 [(16)]:   FireDTV:cam is ready
2010-04-05 11:25:43.861522 [(16)]:   FireDTV:cam is able to descramble
2010-04-05 11:25:43.865522 [(16)]: FireDTV cam manufacturer_code=8266, application_manufacturer=8266
2010-04-05 11:25:43.866522 [(16)]: FireDTV cam name: "AlphaCrypt" 
2010-04-05 11:25:43.867522 [(16)]: FireDTV: #0/1 pmt data:0x0 0x2 0x0 0x0 0x0 0x0 0x0 0x0 0x0 0x4B 0x3 0x1 0x2 0xB0 0x49 0x4A 0x3B 0xF5 0x0 0x0 0xE0 0xDD 0xF0 0x1D 0xE 0x3 0xC0 0x57 0x98 0x10 0x6 0xC0 0x2 0x71 0xC0 0x4 0x0 0xB 0x2 0x42 0x3F 0x9 0x4 0x6 0x4 0xEF 0xA2 0x9 0x4 0x6 0x2 0xF3 0x8A 0x2 0xE0 0xDD 0xF0 0x3 0x6 0x1 0x2 0x4 0xE0 0xDE 0xF0 0x6 0xA 0x4 0x64 0x75 0x74 0x0 0x6 0xE0 0xEA 0xF0 0x7 0x56 0x5 0x64 0x75 0x74 0x9 0x0 0xCE 
2010-04-05 11:25:43.976528 [(16)]: FireDTV:GetCAMStatus() finished
2010-04-05 11:25:43.977528 [(16)]:   FireDTV:cam is inserted
2010-04-05 11:25:43.978529 [(16)]:   FireDTV:cam is valid
2010-04-05 11:25:43.979529 [(16)]:   FireDTV:cam is ready
2010-04-05 11:25:43.980529 [(16)]:   FireDTV:cam is able to descramble
2010-04-05 11:25:43.981529 [(16)]: subch:0 cam flags:True
2010-04-05 11:25:43.982529 [(16)]: subch:0 SetMpegPidMapping
2010-04-05 11:25:43.983529 [(16)]: subch:0  pid:DD pcr
2010-04-05 11:25:43.984529 [(16)]: subch:0  pid:DC pmt
2010-04-05 11:25:43.985529 [(16)]: subch:0  pid:DD video type:MPEG-2
2010-04-05 11:25:43.986529 [(16)]: subch:0    map pid:DD video type:MPEG-2
2010-04-05 11:25:43.987529 [(16)]: subch:0  pid:DE audio lang:dut type:MPEG-2
2010-04-05 11:25:43.988529 [(16)]: subch:0    map pid:DE audio lang:dut type:MPEG-2
2010-04-05 11:25:43.990529 [(16)]: subch:0  pid:EA teletext type:6
2010-04-05 11:25:43.991529 [(16)]: subch:0    map pid:EA teletext type:6
2010-04-05 11:25:43.992529 [(16)]: FireDTV: HW Filtering disabled.
2010-04-05 11:25:43.993529 [(16)]: FireDTV: Set H/W pid filtering is not supported
2010-04-05 11:25:43.993529 [(16)]: subch:0 stop tif
2010-04-05 11:25:43.994529 [(16)]: WaitForPmt: PMT handling took 0,1460083 seconds.
2010-04-05 11:25:44.137538 [(16)]: card: Tuner locked: True
2010-04-05 11:25:44.138538 [(16)]: **************************************************
2010-04-05 11:25:44.139538 [(16)]: ***** SIGNAL LEVEL: 100, SIGNAL QUALITY: 100 *****
2010-04-05 11:25:44.140538 [(16)]: **************************************************
2010-04-05 11:25:44.141538 [(16)]: card: tuned user: scheduler747 subchannel: 0
2010-04-05 11:25:44.142538 [(16)]: user:scheduler747 add
2010-04-05 11:25:44.143538 [(16)]: Scheduler: MakeFileName() using "moviesformat" (_isSerie=False)
2010-04-05 11:25:44.149538 [(16)]: Scheduler : record to F:\recorded tv\Tommy Teleshopping - SBS 6 - 2010-04-05.ts
2010-04-05 11:25:44.153539 [(16)]: Recorder.start add audioVideoEventHandler
2010-04-05 11:25:44.154539 [(16)]: card: StartRecording 13 F:\recorded tv\Tommy Teleshopping - SBS 6 - 2010-04-05.ts
2010-04-05 11:25:44.154539 [(16)]: StartRecording to F:\recorded tv\Tommy Teleshopping - SBS 6 - 2010-04-05.ts
2010-04-05 11:25:44.155539 [(16)]: subch:0 StartRecord(F:\recorded tv\Tommy Teleshopping - SBS 6 - 2010-04-05.ts)
2010-04-05 11:25:44.156539 [(16)]: subch:0-0 tswriter StartRecording...
2010-04-05 11:25:44.156539 [(16)]: SetRecorderPids
2010-04-05 11:25:44.160539 [(16)]: Set video / audio observer
2010-04-05 11:25:44.161539 [(16)]: DVB subch:0 Started recording
2010-04-05 11:25:44.163539 [(16)]: card: WaitForRecordingFile - waiting _eventAudio & _eventVideo
2010-04-05 11:25:44.547561 [(14)]: PID seen - type = Audio
2010-04-05 11:25:44.548561 [(14)]: Recorder audioVideoEventHandler Audio
2010-04-05 11:25:44.614565 [(14)]: PID seen - type = Video
2010-04-05 11:25:44.614565 [(14)]: Recorder audioVideoEventHandler Video
2010-04-05 11:25:44.616565 [(16)]: card: WaitForRecordingFile - video and audio are seen after 0,4530259 seconds

In some earlier postings this logging is present, in the last not.