Blasting issue with us built and dish vip211k (1 Viewer)

madas

Portal Pro
November 5, 2007
66
1
Hello

I'm having some problems getting a stable setup with my usbuirt on two dish vip211k receivers which are each connected to a hauppauge colossus. My setup was stable before under sage so I don't believe my issue to be a hardware one.

When I change channel sometimes I get an extra digit, sometimes I get one less. Say channel 112, 5 out of 6 times it works..on the error it'll do 1122. Other times it seems to miss a digit altogether, 12 instead of 112.

I have messed with the delays, prechange command, and repeats. I cannot seem to get things to be stable. One thing I have noticed is that during the channel change media portal freezes the video for about 5 seconds. The freeze normally occurs after either the first or second digit. Any chance this is causing it?

I appreciate any input

Thank you all

M
 

mm1352000

Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Hi madas

    I hope you're well. :)
    Are you able to supply any logs? Its just that it is more that a little difficult to try and help you without them.

    Log Files - MediaPortal Wiki

    In this case I would use the procedure for non-reproducible problems and specify the time when the problem occurred. If you could also grab the IRSS logs (I don't think they're automatically included in the zip file generated by the watchdog tool) then that would also be helpful.

    mm
     

    madas

    Portal Pro
    November 5, 2007
    66
    1
    Hey mm,

    Long time no speak. Hows things in NZ?

    I've attached the logs. Also, here is a list of the channel changes i made (i wiped all the logs before hand) and which ones worked/didn't work


    110
    111
    112
    113 - FAILED GOT CH 3
    110
    112
    113
    114
    111
    112
    111
    114
    107
    110 - FAILED GOT CH 2 (closest to 0)

    Appreciate your help

    M
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Hi Madas

    To me it looks like it is a timing problem. In the first case where ch 113 fails I see:

    [COLLAPSE]2011-12-11 14:22:59.269612 [(20)]: Controller: StartTimeShifting 113 COOKHD 2805

    2011-12-11 14:22:59.270615 [(20)]: Controller: find free card for channel 113 COOKHD

    2011-12-11 14:22:59.271618 [(20)]: Controller: find card for channel 113 COOKHD

    2011-12-11 14:22:59.273624 [(20)]: Controller: got 1 tuning details for 113 COOKHD

    2011-12-11 14:22:59.274627 [(20)]: Controller: channel #1 tv:113 COOKHD Freq:0 Channel:113 Country:United States Tuner:Cable Video:HdmiInput1 Audio:Automatic

    2011-12-11 14:22:59.275630 [(20)]: Controller: card:1 type:DvbIP cannot tune to channel

    2011-12-11 14:22:59.276633 [(20)]: Controller: card:4 type:Atsc cannot tune to channel

    2011-12-11 14:22:59.277636 [(20)]: Controller: card:5 type:Atsc cannot tune to channel

    2011-12-11 14:22:59.279642 [(20)]: Controller: card:3 type:Analog can tune to channel

    2011-12-11 14:22:59.280645 [(20)]: Controller: card:3 type:Analog users: 0

    2011-12-11 14:22:59.282651 [(20)]: Controller: card:2 type:Analog can tune to channel

    2011-12-11 14:22:59.283654 [(20)]: Controller: card:2 type:Analog users: 0

    2011-12-11 14:22:59.284657 [(20)]: Controller: card:6 type:RadioWebStream cannot tune to channel

    2011-12-11 14:22:59.285660 [(20)]: Controller: found 2 card(s) for channel

    2011-12-11 14:22:59.286663 [(20)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 14 msec

    2011-12-11 14:22:59.287666 [(20)]: Controller: card:3 type:Analog is available

    2011-12-11 14:22:59.288669 [(20)]: Controller: card:2 type:Analog is available

    2011-12-11 14:22:59.289672 [(20)]: Controller: found 2 free card(s)

    2011-12-11 14:22:59.290675 [(20)]: AdvancedCardAllocation.GetFreeCardsForChannel took 19 msec

    2011-12-11 14:22:59.291678 [(20)]: Controller: try max 2 of 2 cards for timeshifting

    2011-12-11 14:22:59.293684 [(20)]: TV3BlasterPlugin: Received TV Server Event "StartZapChannel"

    2011-12-11 14:22:59.294687 [(20)]: TV3BlasterPlugin: Analog channel input source "HdmiInput1"

    2011-12-11 14:22:59.295690 [(20)]: TV3BlasterPlugin: Tune request - Card: 3, Channel: 113, 113 COOKHD

    2011-12-11 14:22:59.296693 [ProcessExternalChannel(25)]: TV3BlasterPlugin: ProcessExternalCommand("Blast: ENTER|Port 1", -1, 113)

    2011-12-11 14:22:59.297696 [ProcessExternalChannel(25)]: TV3BlasterPlugin - BlastIR(): C:\ProgramData\IR Server Suite\IR Commands\ENTER.IR, Port 1

    2011-12-11 14:22:59.299702 [(20)]: card: CardTune 3 113 COOKHD Media-US:3:-1

    2011-12-11 14:22:59.301708 [(20)]: card: Tune 3 to 113 COOKHD

    2011-12-11 14:22:59.302711 [(20)]: card: user: Media-US:3:-1 tune tv:113 COOKHD Freq:0 Channel:113 Country:United States Tuner:Cable Video:HdmiInput1 Audio:Automatic

    2011-12-11 14:22:59.307726 [(20)]: TimeShifter.OnBeforeTune: resetting audio/video events

    2011-12-11 14:22:59.309732 [(20)]: HDPVR: Tune:-1, tv:113 COOKHD Freq:0 Channel:113 Country:United States Tuner:Cable Video:HdmiInput1 Audio:Automatic

    2011-12-11 14:22:59.310735 [(20)]: HDPVR: GetNewSubChannel:0 #0

    2011-12-11 14:22:59.313744 [(20)]: subch:0 OnBeforeTune

    2011-12-11 14:22:59.315750 [(20)]: HDPVR: Tune

    2011-12-11 14:22:59.316753 [(20)]: HDPVR: audio input -> (auto)

    2011-12-11 14:22:59.317756 [(20)]: HDPVR: Tuned to channel 113 COOKHD

    2011-12-11 14:22:59.318759 [(20)]: subch:0 OnAfterTune

    2011-12-11 14:22:59.319762 [(20)]: subch:0 OnGraphStart

    2011-12-11 14:22:59.320765 [(20)]: HDPVR: RunGraph

    2011-12-11 14:22:59.408026 [(20)]: HDPVR: Graph running

    2011-12-11 14:22:59.409029 [(20)]: subch:0 OnGraphStarted

    2011-12-11 14:22:59.410032 [(20)]: subch:0 SetupPmtGrabber:pid 100 sid:1

    2011-12-11 14:22:59.411035 [(20)]: subch:0 set pmt grabber pmt:100 sid:1

    2011-12-11 14:22:59.413041 [(20)]: TimeShifter.OnAfterTune: resetting audio/video time

    2011-12-11 14:22:59.623671 [(19)]: HDPVR: OnPMTReceived() subch:0 pid 0x100

    2011-12-11 14:22:59.625677 [(20)]: HDPVR: found PMT after 0.21063 seconds

    2011-12-11 14:22:59.627683 [(20)]: HDPVR: PMT sid=0x1 pid=0x100 version=0x0

    2011-12-11 14:22:59.628686 [(20)]: Decode pmt

    2011-12-11 14:22:59.631695 [(20)]: subch:0 SetMpegPidMapping

    2011-12-11 14:22:59.633701 [(20)]: subch:0 pid:1001 pcr

    2011-12-11 14:22:59.634704 [(20)]: subch:0 pid:100 pmt

    2011-12-11 14:22:59.635707 [(20)]: subch:0 pid:1011 video type:H.264

    2011-12-11 14:22:59.648746 [(20)]: subch:0 map pid:1011 video type:H.264

    2011-12-11 14:22:59.651755 [(20)]: subch:0 pid:1100 audio lang: type:AC3

    2011-12-11 14:22:59.652758 [(20)]: subch:0 map pid:1100 audio lang: type:AC3

    2011-12-11 14:22:59.654764 [(20)]: card: Tuner locked: True

    2011-12-11 14:22:59.656770 [(20)]: **************************************************

    2011-12-11 14:22:59.657773 [(20)]: ***** SIGNAL LEVEL: 100, SIGNAL QUALITY: 100 *****

    2011-12-11 14:22:59.658776 [(20)]: **************************************************

    2011-12-11 14:22:59.659779 [(20)]: card: tuned user: Media-US subchannel: 0

    2011-12-11 14:22:59.660782 [(20)]: user:Media-US add

    2011-12-11 14:22:59.661785 [(20)]: card2:Media-US 3 0

    2011-12-11 14:22:59.663791 [(20)]: Controller: Media-US 3 0

    2011-12-11 14:22:59.665797 [(20)]: TV3BlasterPlugin: Received TV Server Event "EndZapChannel"

    2011-12-11 14:22:59.666800 [(20)]: control2:Media-US 3 0

    2011-12-11 14:22:59.669809 [(20)]: Controller: delete timeshift files D:\Media\Temp\live3-0.ts

    2011-12-11 14:22:59.672818 [(20)]: TV3BlasterPlugin: Received TV Server Event "StartTimeShifting"

    2011-12-11 14:22:59.673821 [TvDbThread(14)]: SD-TvDb: No episode match for series: Giada at Home, seriesId: 85062, episodeName: Giada's Christmas Dinner

    2011-12-11 14:22:59.676830 [(20)]: card: StartTimeShifting 3 D:\Media\Temp\live3-0.ts

    2011-12-11 14:22:59.678836 [(20)]: card: CAM enabled : False

    2011-12-11 14:22:59.679839 [(20)]: analog: Encoder mode setting to ConstantBitRate

    2011-12-11 14:22:59.681845 [(20)]: analog: Encoder mode set to ConstantBitRate

    2011-12-11 14:22:59.684854 [(20)]: analog: Encoder BitRate setting to Default

    2011-12-11 14:22:59.685857 [(20)]: analog: Encoder BitRate Min 1000000 Max 20000000 Delta 500000

    2011-12-11 14:22:59.686860 [(20)]: analog: Encoder BitRate set to 9000000

    2011-12-11 14:22:59.687863 [(20)]: subch:0 SetTimeShiftFileName:D:\Media\Temp\live3-0.ts

    2011-12-11 14:22:59.688866 [(20)]: Set video / audio observer

    2011-12-11 14:22:59.691875 [(20)]: subch:0 SetTimeShiftFileName fill in pids

    2011-12-11 14:22:59.697893 [(20)]: subch:0-0 tswriter StartTimeshifting...

    2011-12-11 14:22:59.701905 [(20)]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo

    2011-12-11 14:22:59.725977 [GenericPCQueue(15)]: TV3BlasterPlugin: Received Message "BlastIR"

    2011-12-11 14:22:59.726980 [GenericPCQueue(15)]: TV3BlasterPlugin: Blast successful

    2011-12-11 14:22:59.731995 [(19)]: PID seen - type = Video

    2011-12-11 14:22:59.732998 [(19)]: audioVideoEventHandler Video

    2011-12-11 14:22:59.801202 [ProcessExternalChannel(25)]: TV3BlasterPlugin: ProcessExternalCommand("STB: Dish 301\1|Port 1", 1, 113)

    2011-12-11 14:22:59.802205 [ProcessExternalChannel(25)]: TV3BlasterPlugin - BlastIR(): C:\ProgramData\IR Server Suite\Set Top Boxes\Dish 301\1.IR, Port 1

    2011-12-11 14:23:00.120156 [(19)]: PID seen - type = Audio

    2011-12-11 14:23:00.125171 [(19)]: audioVideoEventHandler Audio

    2011-12-11 14:23:00.129183 [(20)]: card: WaitForTimeShiftFile - video and audio are seen after 0.424269 seconds

    2011-12-11 14:23:00.138210 [(20)]: user:Media-US card:3 sub:0 add stream:D:\Media\Temp\live3-0.ts.tsbuffer

    2011-12-11 14:23:00.140216 [(20)]: Controller: StartTimeShifting started on card:3 to D:\Media\Temp\live3-0.ts.tsbuffer

    2011-12-11 14:23:00.147237 [(20)]: user:Media-US remove

    2011-12-11 14:23:00.150246 [(20)]: subch:0-0 tswriter StopTimeshifting...

    2011-12-11 14:23:00.163285 [(20)]: tvcard:FreeSubChannel: subchannels count 1 subch#0 keep graph=False

    2011-12-11 14:23:00.165291 [(20)]: DVB subch:0 Decompose()

    2011-12-11 14:23:00.172312 [(20)]: FreeSubChannel CA: freeing sub channel : 0

    2011-12-11 14:23:00.173315 [(20)]: tvcard:FreeSubChannel : no subchannels present, pausing graph

    2011-12-11 14:23:00.175321 [(20)]: dvb:confused:topGraph called

    2011-12-11 14:23:00.176324 [(20)]: tvcard:FreeAllSubChannels

    2011-12-11 14:23:00.178330 [(20)]: dvb:confused:topGraph

    2011-12-11 14:23:00.189363 [TS_File_Cleanup(23)]: card: delete timeshift files D:\Media\Temp\live4-0.ts

    2011-12-11 14:23:00.191369 [TS_File_Cleanup(23)]: card: trying to delete D:\Media\Temp\live4-0.ts.tsbuffer

    2011-12-11 14:23:00.192372 [(20)]: dvb:confused:topGraph called

    2011-12-11 14:23:00.193375 [(20)]: tvcard:FreeAllSubChannels

    2011-12-11 14:23:00.194378 [(20)]: dvb:confused:topGraph filterstate already stopped, returning.

    2011-12-11 14:23:00.203405 [(20)]: CiMenuSupported called cardid 3

    2011-12-11 14:23:00.204408 [(20)]: CiMenuSupported card Hauppauge Colossus Crossbar 1 supported: False

    2011-12-11 14:23:00.304708 [ProcessExternalChannel(25)]: TV3BlasterPlugin: ProcessExternalCommand("STB: Dish 301\1|Port 1", 1, 113)

    2011-12-11 14:23:00.305711 [ProcessExternalChannel(25)]: TV3BlasterPlugin - BlastIR(): C:\ProgramData\IR Server Suite\Set Top Boxes\Dish 301\1.IR, Port 1

    2011-12-11 14:23:00.477224 [GenericPCQueue(15)]: TV3BlasterPlugin: Received Message "BlastIR"

    2011-12-11 14:23:00.478227 [GenericPCQueue(15)]: TV3BlasterPlugin: Blast successful

    2011-12-11 14:23:00.709920 [TvDbThread(14)]: SD-TvDb: No episode match for series: Giada at Home, seriesId: 85062, episodeName: Giada's Christmas Dinner

    2011-12-11 14:23:00.808214 [ProcessExternalChannel(25)]: TV3BlasterPlugin: ProcessExternalCommand("STB: Dish 301\3|Port 1", 3, 113)

    2011-12-11 14:23:00.809217 [ProcessExternalChannel(25)]: TV3BlasterPlugin - BlastIR(): C:\ProgramData\IR Server Suite\Set Top Boxes\Dish 301\3.IR, Port 1

    2011-12-11 14:23:00.928574 [GenericPCQueue(15)]: TV3BlasterPlugin: Received Message "BlastIR"

    2011-12-11 14:23:00.934592 [GenericPCQueue(15)]: TV3BlasterPlugin: Blast successful

    2011-12-11 14:23:01.314729 [ProcessExternalChannel(25)]: TV3BlasterPlugin: ProcessExternalCommand("STB: Dish 301\ENTER|Port 1", -1, 113)

    2011-12-11 14:23:01.319744 [ProcessExternalChannel(25)]: TV3BlasterPlugin - BlastIR(): C:\ProgramData\IR Server Suite\Set Top Boxes\Dish 301\ENTER.IR, Port 1

    2011-12-11 14:23:01.541407 [GenericPCQueue(15)]: TV3BlasterPlugin: Received Message "BlastIR"

    2011-12-11 14:23:01.543413 [GenericPCQueue(15)]: TV3BlasterPlugin: Blast successful

    2011-12-11 14:23:01.786139 [GenericPCQueue(15)]: TV3BlasterPlugin: Received Message "BlastIR"

    2011-12-11 14:23:01.789148 [GenericPCQueue(15)]: TV3BlasterPlugin: Blast successful

    2011-12-11 14:23:02.173297 [TvDbThread(14)]: SD-TvDb: No episode match for series: Giada at Home, seriesId: 85062, episodeName: Giada's Christmas Dinner

    2011-12-11 14:23:02.278612 [TvDbThread(14)]: SD-TvDb: Update tvdb.com info for Cooking for Real

    2011-12-11 14:23:02.662761 [(19)]: HDPVR: OnPMTReceived() subch:0 pid 0x100

    2011-12-11 14:23:02.663764 [(19)]: HDPVR: PMT sid=0x1 pid=0x100 version=0x1

    2011-12-11 14:23:02.664767 [(19)]: Decode pmt

    2011-12-11 14:23:02.665770 [(19)]: subch:0 SetMpegPidMapping

    2011-12-11 14:23:02.666773 [(19)]: subch:0 pid:1001 pcr

    2011-12-11 14:23:02.668779 [(19)]: subch:0 pid:100 pmt

    2011-12-11 14:23:02.669782 [(19)]: subch:0 pid:1011 video type:H.264

    2011-12-11 14:23:02.671788 [(19)]: subch:0 map pid:1011 video type:H.264

    2011-12-11 14:23:02.674797 [(19)]: subch:0 pid:1100 audio lang: type:AAC

    2011-12-11 14:23:02.675800 [(19)]: subch:0 map pid:1100 audio lang: type:AAC

    2011-12-11 14:23:02.683824 [(19)]: PID seen - type = Video

    2011-12-11 14:23:02.684827 [(19)]: audioVideoEventHandler Video

    2011-12-11 14:23:02.713914 [(19)]: PID seen - type = Audio

    2011-12-11 14:23:02.715920 [(19)]: audioVideoEventHandler Audio

    2011-12-11 14:23:04.405975 [TvDbThread(14)]: SD-TvDb: No episode match for series: Cooking for Real, seriesId: 249738, episodeName: No Ho-Hum Holiday

    2011-12-11 14:23:04.747998 [(19)]: HDPVR: OnPMTReceived() subch:0 pid 0x100

    2011-12-11 14:23:04.750004 [(19)]: HDPVR: PMT sid=0x1 pid=0x100 version=0x2

    2011-12-11 14:23:04.752010 [(19)]: Decode pmt

    2011-12-11 14:23:04.754016 [(19)]: subch:0 SetMpegPidMapping

    2011-12-11 14:23:04.756022 [(19)]: subch:0 pid:1001 pcr

    2011-12-11 14:23:04.758028 [(19)]: subch:0 pid:100 pmt

    2011-12-11 14:23:04.759031 [(19)]: subch:0 pid:1011 video type:H.264

    2011-12-11 14:23:04.761037 [(19)]: subch:0 map pid:1011 video type:H.264

    2011-12-11 14:23:04.765049 [(19)]: subch:0 pid:1100 audio lang: type:AC3

    2011-12-11 14:23:04.767055 [(19)]: subch:0 map pid:1100 audio lang: type:AC3

    2011-12-11 14:23:04.775079 [(19)]: PID seen - type = Audio

    2011-12-11 14:23:04.776082 [(19)]: audioVideoEventHandler Audio

    2011-12-11 14:23:04.780094 [(19)]: PID seen - type = Video

    2011-12-11 14:23:04.781097 [(19)]: audioVideoEventHandler Video[/COLLAPSE]

    So it almost looks like you gave up on that channel before the blaster had finished doing its thing. What the STB would have been feeding you would certainly not have had a chance to show up on the screen yet. The blaster seems like it is the slowest common denominator so maybe you could improve the situation by decreasing the delay between key code blasts.

    The same issue doesn't seem to apply with the 110 failure - to be honest I have no idea what happened there as everything looks like it worked perfectly. Is it possible that there is a reliability issue between the blaster and the STB?

    mm
     

    madas

    Portal Pro
    November 5, 2007
    66
    1
    Hi mm

    I'm pretty sure that the blaster was finished on the previous change before I issued another. In all cases I waited till I saw the channel change on the screen (otherwise I wasn't able to test). I have already tried reducing the delay all the way down to 50ms...it doesn't make any difference.

    With respect to hardware..I don't believe it to be a hardware issue as the setup is unchanged from my sagetv install. I will check tomorrow to make sure.

    Any thoughts about the video freeze? When I change channel I see a digit or two then the video freezes for about 5 seconds...any chance this is related? Any chance this freeze is pausing the IRblast too?

    Thanks

    M
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    I'm pretty sure that the blaster was finished on the previous change before I issued another. In all cases I waited till I saw the channel change on the screen (otherwise I wasn't able to test). I have already tried reducing the delay all the way down to 50ms...it doesn't make any difference.
    Right, okay.

    With respect to hardware..I don't believe it to be a hardware issue as the setup is unchanged from my sagetv install. I will check tomorrow to make sure.
    When I say hardware I'm thinking specifically of IR interference. All the blast results in your logs look fine. If there are occasional extra or missing digits then it makes me think there is some inaccuracy in the STBs reception of the IR commands from the blaster because the logic behind the blaster commands should be very solid. At least the logic should not throw in or skip digits randomly.

    Any thoughts about the video freeze? When I change channel I see a digit or two then the video freezes for about 5 seconds...any chance this is related? Any chance this freeze is pausing the IRblast too?
    I don't think so. What you see is likely a combination of channel changing in MediaPortal + channel changing on the STB + the Colossus encoder getting itself sorted out. One thing you could do is to check the zap timeout setting in MP configuration (wiki documentation here). That *might* have a bearing on that 5 second delay but I think there is very little chance that it has any effect on the blaster.

    Best regards,
    mm
     

    madas

    Portal Pro
    November 5, 2007
    66
    1
    mm,

    Thanks for the update. I guess i'll have a fiddle with the hardware again and see if there is anything phyiscally that can be causing this. I haven't touched the STB or the IR stuff in about a year.

    I've changed the zap delay but as you said it doesn't sound like this will make any change. From what i see on-screen it looks like the freeze is the colossus encoder getting itself sorted out. Wonder if there is anything else that can be done to speed this up. I've also noticed in the last couple of weeks that sometimes after a recording the colossus card does not get released. Last night it said it was recording a show that was on at 9am-9.30am, this was about 8pm. I had to restart the tvservice to clear it.



    M
     

    madas

    Portal Pro
    November 5, 2007
    66
    1
    I had a spare USBUIRT hanging around so i switched it out..new cable...re-taped all the IR emitters....still the same.

    Is there anyway to vary the amount of time that the ir signal is sent for?

    I see

    Delay between digits
    Numer of Repeats

    Maybe the IR signal is being emitted for to long?
     

    Users who are viewing this thread

    Top Bottom