Very slow (over a minute) change between scrambled channels (1 Viewer)

Balazs

Portal Member
March 1, 2016
8
0
Netherlands Netherlands
MediaPortal Version: MediaPortal 2 Summer '15 Update 1 Release
Windows Version: Windows 7 Ultimate x64 SP1
CPU Type: Intel i3-2105
HDD: Samsung 850 EVO 250GB
Memory: 8GiB DDR3 1333MHz
Motherboard: ASUS P8H67-M EVO
Video Card: Integrated Intel HD Graphics
Video Card Driver: 8.15.10.2219
Sound Card: Realtek HDA (integrated on motherboard)
Sound Card Driver: 6.0.1.6251
1. TV Card: Digital Devices Cine CT V6
1. TV Card Type: DVB-C
1. TV Card Driver: 2.6.2.126
MPEG2 Video Codec: LAV Video Decoder
MPEG4 Video Codec: LAV Video Decoder
AVC Video Codec: LAV Video Decoder
HEVC Video Codec: LAV Video Decoder
MPEG1/2 Audio Codec: LAV Video Decoder
LATM-AAC Audio Codec: LAV Video Decoder
AAC Audio Codec: LAV Video Decoder
CableTV Provider: Ziggo (NL)
TV - HTPC Connection: HDMI

Hi,

One evening I installed a new CAM (AlphaCrypt Classic) with my SmartCard in the CI Expansion Module of the Cine CT tuner and for the first time ever I could watch TV during the entire evening, with quasi-negligible issues (the same tuner used to work with a Smargo card reader a long time ago). Then, I shut the PC down, started it the following afternoon and I do not recall having changed any particular settings. However, from then on something is strange with the scrambled channels: by attempting to watch the first encoded channel, it works fine. Then, to switch to another encoded channel (if I wait less than about 2 minutes after having stopped the first one), the subsequent channel needs about 65-85 seconds to tune to and the screen (preview window) is white/grey, only the audio works. By stopping this and starting the same channel again, it works fine (picture and audio after a few seconds at most), as if it was the first time I started the scrambled channel.

When one switches from an encoded channel to another encoded channel, it typically needs this 65-85 seconds to tune to the audio and a second tuning attempt to have picture as well (I believe, the log shows a rare exception).

The unscrambled channels work flawlessly. Furthermore, all channels (free and scrambled) work perfectly fine with DVBViewer Pro Demo. Switching between channels is quasi instantaneous.

I reinstalled completely Windows on the computer, but it did not bring even a temporary solution.

I also attempted to switch the "TVLibrary.dll", using the package published on this forum on 16 January 2014, but it made MP 2 and the TV Configuration tool crash.

I would appreciate any help that could resolve the issue. Some logs are attached from a single session with TV Configuration. The first few channels are unscrambled. Starting from "TV5 Monde" all the tested channels were scrambled and I waited systematically about 10-15 seconds after having heard the audio before I stopped the preview.

Kind regards,
Balazs
 

morpheus_xx

Lead Dev MP2
  • Team MediaPortal
  • March 24, 2007
    11,461
    7,010
    Germany Germany
    Country flag
    Hi,

    thanks for including log files, this is good :)

    Unfortunately the default loglevel is set to INFO, so it misses the DEBUG messages. Can you please adjust the log levels of both Client and Server as described here and then create a new set of logfiles for the slow channel change? Remember to restart the MP2-Server (i.e. via ServiceMonitor from tray) after you changed the config.
     

    Balazs

    Portal Member
    March 1, 2016
    8
    0
    Netherlands Netherlands
    Dear Morpheus_xx,

    Thank you very much for your quick reaction and I am sorry about the wrong setting! The new logs are now attached.

    Similarly to the previous session, "TV5 Monde" is the first scrambled and at each tuning I waited about 10-15 seconds from the moment I heard the audio before I closed the preview window. Once again, the first 2 scrambled channels worked fine.

    Kind regards,
    Balazs
     

    morpheus_xx

    Lead Dev MP2
  • Team MediaPortal
  • March 24, 2007
    11,461
    7,010
    Germany Germany
    Country flag
    Strange issue.

    The Server is able to tune the channel normal:
    Code:
    [2016-03-01 21:01:01,863] [164562 ] [29       ] [DEBUG] - dvbc: Tune:DVBC:tv:Ziggo Discovery HD Freq:378000 ONID:1536 TSID:2063 SID:19222 PMT:0x8FC FTA:False LCN:938 SymbolRate:6900 Modulation:Mod256Qam
    [2016-03-01 21:01:01,866] [164565 ] [29       ] [INFO ] - dvb:Submiting tunerequest Channel:Discovery HD subChannel:-1
    [2016-03-01 21:01:01,867] [164566 ] [29       ] [INFO ] - dvb:Getting new subchannel
    [2016-03-01 21:01:01,868] [164567 ] [29       ] [INFO ] - dvb:GetNewSubChannel:0 #0
    [2016-03-01 21:01:01,870] [164569 ] [29       ] [DEBUG] - TvDvbChannel ctor new subchIndex:0
    [2016-03-01 21:01:01,870] [164569 ] [29       ] [INFO ] - card: AddTuneEvent card: 3 / subch: 0
    [2016-03-01 21:01:01,871] [164570 ] [29       ] [INFO ] - dvb:Submit tunerequest size:1 new:0
    [2016-03-01 21:01:01,871] [164570 ] [29       ] [DEBUG] - subch:0 OnBeforeTune
    [2016-03-01 21:01:01,872] [164571 ] [29       ] [DEBUG] - dvb:Submit tunerequest calling put_TuneRequest
    [2016-03-01 21:01:01,873] [164572 ] [29       ] [DEBUG] - dvb:Submit tunerequest done calling put_TuneRequest
    [2016-03-01 21:01:01,874] [164573 ] [29       ] [DEBUG] - subch:0 OnAfterTune
    [2016-03-01 21:01:01,874] [164573 ] [29       ] [INFO ] - RunGraph
    [2016-03-01 21:01:01,875] [164574 ] [29       ] [DEBUG] - subch:0 OnGraphStart
    [2016-03-01 21:01:01,875] [164574 ] [29       ] [INFO ] - dvb:  RunGraph
    [2016-03-01 21:01:02,103] [164802 ] [29       ] [DEBUG] - dvb:  LockInOnSignal ok
    [2016-03-01 21:01:02,104] [164803 ] [29       ] [DEBUG] - subch:0 OnGraphStarted
    [2016-03-01 21:01:02,104] [164803 ] [29       ] [INFO ] - subch:0 SetupPmtGrabber:pid 8FC sid:4B16
    [2016-03-01 21:01:02,105] [164804 ] [29       ] [DEBUG] - subch:0 set pmt grabber pmt:8FC sid:4B16
    [2016-03-01 21:01:02,105] [164804 ] [29       ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
    [2016-03-01 21:01:02,106] [164805 ] [29       ] [DEBUG] - WaitForPMT: Waiting for PMT 8FC
    [2016-03-01 21:01:02,263] [164962 ] [45       ] [DEBUG] - subch:0 OnPMTReceived() pmt:8FC ran:True dynamic:False
    [2016-03-01 21:01:02,264] [164963 ] [29       ] [DEBUG] - WaitForPMT: Found PMT after 0.1580091 seconds.
    [2016-03-01 21:01:02,264] [164963 ] [29       ] [INFO ] - subch:0 SendPmt:4B16 4B16 FFFFFFFF 19
    [2016-03-01 21:01:02,265] [164964 ] [29       ] [DEBUG] - Decode pmt
    [2016-03-01 21:01:02,266] [164965 ] [29       ] [INFO ] - descr1 len:6 9 4 18 1 e0 30
    [2016-03-01 21:01:02,266] [164965 ] [29       ] [INFO ] - descr1 len:6 9 4 18 50 e0 31
    [2016-03-01 21:01:02,267] [164966 ] [29       ] [INFO ] - descr1 len:6 9 4 6 2 e0 c8
    [2016-03-01 21:01:02,268] [164967 ] [29       ] [INFO ] - descr1 len:6 9 4 6 4 e1 2d
    [2016-03-01 21:01:02,268] [164967 ] [29       ] [DEBUG] - Set descriptor data with length 6
    [2016-03-01 21:01:02,269] [164968 ] [29       ] [DEBUG] - Set descriptor data with length 6
    [2016-03-01 21:01:02,269] [164968 ] [29       ] [DEBUG] - subch:0 SendPMT version:25 len:75 19222
    [2016-03-01 21:01:02,270] [164969 ] [29       ] [DEBUG] - Digital Devices:--> Setting service id 19222 for decrypting returned 0
    [2016-03-01 21:01:02,270] [164969 ] [29       ] [DEBUG] - subch:0 cam flags:True
    [2016-03-01 21:01:02,271] [164970 ] [29       ] [DEBUG] - subch:0 SetMpegPidMapping
    [2016-03-01 21:01:02,271] [164970 ] [29       ] [DEBUG] - subch:0  pid:8FD pcr
    [2016-03-01 21:01:02,271] [164970 ] [29       ] [DEBUG] - subch:0  pid:8FC pmt
    [2016-03-01 21:01:02,272] [164971 ] [29       ] [DEBUG] - subch:0  pid:8FD video type:H.264
    [2016-03-01 21:01:02,272] [164971 ] [29       ] [DEBUG] - subch:0    map pid:8FD video type:H.264
    [2016-03-01 21:01:02,273] [164972 ] [29       ] [DEBUG] - subch:0  pid:907 audio lang:dut type:AC3
    [2016-03-01 21:01:02,273] [164972 ] [29       ] [DEBUG] - subch:0    map pid:907 audio lang:dut type:AC3
    [2016-03-01 21:01:02,274] [164973 ] [29       ] [DEBUG] - subch:0  pid:908 audio lang:dut type:MPEG-2
    [2016-03-01 21:01:02,274] [164973 ] [29       ] [DEBUG] - OnPMTReceived: MDAPI disabled. Possible reasons are _mdplugs=null or provider not listed
    [2016-03-01 21:01:02,275] [164974 ] [29       ] [INFO ] - subch:0 stop tif
    [2016-03-01 21:01:02,275] [164974 ] [29       ] [DEBUG] - WaitForPmt: PMT handling took 0.0110006 seconds.
    [2016-03-01 21:01:02,276] [164975 ] [29       ] [DEBUG] - card: Tuner locked: True
    [2016-03-01 21:01:02,276] [164975 ] [29       ] [INFO ] - **************************************************
    [2016-03-01 21:01:02,277] [164976 ] [29       ] [INFO ] - ***** SIGNAL LEVEL: 100, SIGNAL QUALITY: 85 *****
    [2016-03-01 21:01:02,277] [164976 ] [29       ] [INFO ] - **************************************************
    [2016-03-01 21:01:02,278] [164977 ] [29       ] [DEBUG] - card: tuned user: setuptv subchannel: 0
    [2016-03-01 21:01:02,278] [164977 ] [29       ] [INFO ] - user:setuptv add
    [2016-03-01 21:01:02,278] [164977 ] [29       ] [INFO ] - card2:setuptv 3 0
    [2016-03-01 21:01:02,279] [164978 ] [29       ] [DEBUG] - Controller: delete timeshift files C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts
    [2016-03-01 21:01:02,280] [164979 ] [29       ] [DEBUG] - Controller: epg stop
    [2016-03-01 21:01:02,284] [164983 ] [29       ] [DEBUG] - card: StartTimeShifting 3 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts
    [2016-03-01 21:01:02,285] [164984 ] [29       ] [DEBUG] - card: CAM enabled : True
    [2016-03-01 21:01:02,285] [164984 ] [29       ] [DEBUG] - subch:0 SetTimeShiftFileName:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts
    [2016-03-01 21:01:02,286] [164985 ] [29       ] [DEBUG] - Set video / audio observer
    [2016-03-01 21:01:02,287] [164986 ] [29       ] [DEBUG] - subch:0 SetTimeShiftFileName fill in pids
    [2016-03-01 21:01:02,288] [164987 ] [29       ] [DEBUG] - subch:0-0 tswriter StartTimeshifting...
    [2016-03-01 21:01:02,290] [164989 ] [29       ] [DEBUG] - card: WaitForFile - waiting _eventAudio & _eventVideo
    [2016-03-01 21:01:02,460] [165159 ] [45       ] [DEBUG] - PID seen - type = Audio
    [2016-03-01 21:01:02,461] [165160 ] [45       ] [INFO ] - audioVideoEventHandler Audio
    [2016-03-01 21:01:02,472] [165171 ] [45       ] [DEBUG] - PID seen - type = Video
    [2016-03-01 21:01:02,473] [165172 ] [45       ] [INFO ] - audioVideoEventHandler Video
    [2016-03-01 21:01:02,474] [165173 ] [29       ] [DEBUG] - card: WaitForFile - video and audio are seen after 0.1840105 seconds
    [2016-03-01 21:01:02,476] [165175 ] [29       ] [INFO ] - user:setuptv card:3 sub:0 add stream:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts.tsbuffer
    [2016-03-01 21:01:02,477] [165176 ] [29       ] [DEBUG] - RTSP: add stream stream3.0 file:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts.tsbuffer
    --> ~ 1 second for tuning.

    The SetupTv log shows very long times for playing back the stream:
    Code:
    [2016-03-01 21:01:02,501] [145286 ] [SetupTv  ] [INFO ] - preview Discovery HD user:-1 -1 setuptv C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts.tsbuffer
    [2016-03-01 21:01:02,502] [145287 ] [SetupTv  ] [DEBUG] - play:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live3-0.ts.tsbuffer
    [2016-03-01 21:01:02,506] [145291 ] [SetupTv  ] [INFO ] - TSReaderPlayer:add TsReader to graph
    [2016-03-01 21:01:02,506] [145291 ] [SetupTv  ] [DEBUG] - load file in Ts
    [2016-03-01 21:01:12,524] [155308 ] [SetupTv  ] [INFO ] - TSReaderPlayer:render TsReader outputs
    [2016-03-01 21:02:09,009] [211794 ] [SetupTv  ] [DEBUG] - run graph
    [2016-03-01 21:02:09,021] [211806 ] [SetupTv  ] [DEBUG] - TSReaderPlayer:running:1
    --> looks like playback graph construction takes 1 minute?!

    This sounds like an issue with DirectShow decoders that cause trouble when the playback graph is constructed. Did you install any new codec(packs) or similar stuff?

    Did you use "GraphEdit" or "GraphStudio" before? It can help to diagnose the graph construction issues.
     

    Balazs

    Portal Member
    March 1, 2016
    8
    0
    Netherlands Netherlands
    Dear Morpheus_xx,

    Thanks a lot for having looked into the logs!

    I did not install any codec packs this time. If I am not mistaken, LAV came with Media Portal 2. Unless some others were included with "MediaPlayer Classic HC" or "VLC Player", there should be nothing else on the PC.

    I never used "GraphEdit", nor "GraphStudio", but if prior experience is not mandatory, I can look into them, but please provide me with some instructions.

    Kind regards,
    Balazs
     

    morpheus_xx

    Lead Dev MP2
  • Team MediaPortal
  • March 24, 2007
    11,461
    7,010
    Germany Germany
    Country flag
    Ok, let's try :)

    1. Download and extract GraphStudio.(32Bit if choice)http://www.heise.de/download/graphstudionext-1184797.html
    2. Run SetupTv, tune a channel that cause delays
    3. Open GraphStudio(Next) as Administator (right click, "run as admin") (required becaue SetupTV runs also as admin)
    4. Select -> "File" ->"Connect to remote graph"
    5. Select SetupTV.exe
    6. Make a Screenshot, post it here
    7. Repeat the same with MP2-Client, tune channel, connect graph, make new screenshot.
    I.e. for me it looks like:
    upload_2016-3-2_18-49-15.png



    (There are expected differences: SetupTv uses complete automatic graph building, MP2-Client sets the user preferences for codecs)
     

    Balazs

    Portal Member
    March 1, 2016
    8
    0
    Netherlands Netherlands
    After having clicked on "Connect", the "Remote Graphs" sub-window disappears, but nothing else happens. This is the case for SetupTV as well as the MP2 Client (non-Administrator in the latter).

    20160302_-_GraphStudio_Screenshot.PNG
     

    morpheus_xx

    Lead Dev MP2
  • Team MediaPortal
  • March 24, 2007
    11,461
    7,010
    Germany Germany
    Country flag
    Hmm...

    Can you try to open GraphStudio -> File -> Render Media File. Then open a .ts recording. Does it build the graph quickly? Please post a screenshot.
     

    Balazs

    Portal Member
    March 1, 2016
    8
    0
    Netherlands Netherlands
    Dear Morpheus_xx,

    This worked without problems and all 5-6 .ts files I tried loaded quickly (order of a second). Here is a screenshot:

    20160303_-_StudioGraph_MediaFileRender.PNG
     

    morpheus_xx

    Lead Dev MP2
  • Team MediaPortal
  • March 24, 2007
    11,461
    7,010
    Germany Germany
    Country flag
    Ok, next step. TsReader usually creates log files, but the folder doesn't exists on MP2-only installations. Please open folder "C:\ProgramData\Team MediaPortal" (copy&paste into Explorer's address bar), create a folder "MediaPortal" and there in "Log".
    Then please try channel changings again, you will find a logfile created (C:\ProgramData\Team MediaPortal\MediaPortal\Log\TsReader.log).

    Use the MP2 LogCollector to create a new set of logfiles.
     

    Users Who Are Viewing This Thread (Users: 0, Guests: 1)

    Top Bottom