YouTube Plugin

[whurlston]

Ah, the error is occuring when trying to get the streams, not the buffering. I should be handling that but apparently not. I can fix it.

Re: the few more seconds buffering. Not a problem. I'm currently buffering 20% before reporting it as watchable. I can bump that up.

It will have to wait until tomorrow night or Friday though. I've got a long day tomorrow.

[mvallevand]

No problem whurlston, it's looking pretty good now.

Martin

[UncleJohnsBand]

Not working for me either.....starts to hand off to NMT but flicks back to NPVR. Below are the logs...waited for list to load.....selected video.....buffering....then it looks like it tries to switch over to NMT.......but then if flicks back to NPVR....

MVP Log:

Code:

[...startup]
2012-01-26 17:22:51.225    [DEBUG][3]    MVP Service Locator will resolve media port: 6337
2012-01-26 17:22:51.231    [INFO][4]    ServiceLocatorThread() Hostname:  Den
2012-01-26 17:22:51.231    [INFO][4]    ServiceLocatorThread() Hostname:  Den
2012-01-26 17:22:51.231    [INFO][3]    MVP Control thread Listening on port: 5917
2012-01-26 17:22:51.232    [INFO][6]    BOOTPWorkerThread() Hostname:  Den
2012-01-26 17:22:51.244    [INFO][4]    IP Address 192.168.1.3
2012-01-26 17:22:51.244    [INFO][4]    IP Address 169.254.195.187
2012-01-26 17:22:51.245    [INFO][6]    BOOTPWorkerThread IP Address 192.168.1.3
2012-01-26 17:22:51.245    [INFO][6]    BOOTPWorkerThread IP Address 169.254.195.187
2012-01-26 17:22:51.246    [INFO][7]    MVP Streaming thread Listening on port: 8338
2012-01-26 17:22:51.246    [DEBUG][7]    MVP Service Locator will resolve media port: 8338

Web Log

Code:

[...startup]
2012-01-26 17:24:01.912    [DEBUG][15]    Got Web Request (192.168.1.8): /stream
2012-01-26 17:24:02.145    [DEBUG][15]    SharedMemoryHelper::Open()
2012-01-26 17:24:02.147    [DEBUG][15]    Unable to find in 'Global', about to check 'Local'
2012-01-26 17:24:02.148    [DEBUG][15]    Unable to find in either 'Global' or 'Local'
2012-01-26 17:24:02.150    [DEBUG][15]    RollingFile(//DEN\Media\Live TV Buffer\youtube-qrO4YZeyl0I.PCH-0006DC420041.mp4)..
2012-01-26 17:24:02.150    [DEBUG][15]    SharedMemoryHelper::Open()
2012-01-26 17:24:02.150    [DEBUG][15]    Unable to find in 'Global', about to check 'Local'
2012-01-26 17:24:02.150    [DEBUG][15]    Unable to find in either 'Global' or 'Local'
2012-01-26 17:24:02.152    [DEBUG][15]    RollingFile.Seek(0)
2012-01-26 17:24:02.152    [DEBUG][15]    RollingFile.Position returning 0
2012-01-26 17:24:02.159    [DEBUG][15]    about to read 200000 from location 0  (current length = 16728514)
2012-01-26 17:24:02.159    [DEBUG][15]    RollingFile.Position returning 200000
2012-01-26 17:24:02.159    [DEBUG][15]    about to read 200000 from location 200000  (current length = 16728514)
2012-01-26 17:24:02.160    [DEBUG][15]    RollingFile.Position returning 400000
2012-01-26 17:24:02.160    [DEBUG][15]    about to read 200000 from location 400000  (current length = 16728514)
2012-01-26 17:24:02.447    [DEBUG][15]    RollingFile.Position returning 600000
2012-01-26 17:24:02.448    [DEBUG][15]    about to read 200000 from location 600000  (current length = 17498690)
2012-01-26 17:24:02.448    [DEBUG][15]    RollingFile.Position returning 800000
2012-01-26 17:24:02.448    [DEBUG][15]    about to read 200000 from location 800000  (current length = 17502786)
2012-01-26 17:24:02.491    [ERROR][15]    Unexpected error streaming file: System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Send(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Cassini.Request.StreamFile()
2012-01-26 17:24:02.492    [DEBUG][15]    RollingFile.Close()
2012-01-26 17:24:02.571    [DEBUG][15]    Got Web Request (192.168.1.8): /stream
2012-01-26 17:24:02.749    [DEBUG][4]    Got Web Request (192.168.1.8): /stream
2012-01-26 17:24:02.929    [DEBUG][4]    Got Web Request (192.168.1.8): /stream
2012-01-26 17:24:03.110    [DEBUG][15]    Got Web Request (192.168.1.8): /stream
2012-01-26 17:24:03.260    [DEBUG][15]    Got Web Request (192.168.1.8): /stream
2012-01-26 17:24:03.268    [DEBUG][15]    SharedMemoryHelper::Open()
2012-01-26 17:24:03.268    [DEBUG][15]    Unable to find in 'Global', about to check 'Local'
2012-01-26 17:24:03.268    [DEBUG][15]    Unable to find in either 'Global' or 'Local'
2012-01-26 17:24:03.268    [DEBUG][15]    RollingFile(//DEN\Media\Live TV Buffer\youtube-qrO4YZeyl0I.PCH-0006DC420041.mp4)..
2012-01-26 17:24:03.268    [DEBUG][15]    SharedMemoryHelper::Open()
2012-01-26 17:24:03.268    [DEBUG][15]    Unable to find in 'Global', about to check 'Local'
2012-01-26 17:24:03.268    [DEBUG][15]    Unable to find in either 'Global' or 'Local'
2012-01-26 17:24:03.269    [DEBUG][15]    RollingFile.Seek(0)
2012-01-26 17:24:03.269    [DEBUG][15]    RollingFile.Position returning 0
2012-01-26 17:24:03.269    [DEBUG][15]    about to read 200000 from location 0  (current length = 19606258)
2012-01-26 17:24:03.269    [DEBUG][15]    RollingFile.Position returning 200000
2012-01-26 17:24:03.270    [DEBUG][15]    about to read 200000 from location 200000  (current length = 19606258)
2012-01-26 17:24:03.270    [DEBUG][15]    RollingFile.Position returning 400000
2012-01-26 17:24:03.270    [DEBUG][15]    about to read 200000 from location 400000  (current length = 19606258)
2012-01-26 17:24:03.284    [ERROR][15]    Unexpected error streaming file: System.Net.Sockets.SocketException: An existing connection was forcibly closed by the remote host
   at System.Net.Sockets.Socket.Send(Byte[] buffer, Int32 offset, Int32 size, SocketFlags socketFlags)
   at Cassini.Request.StreamFile()
2012-01-26 17:24:03.284    [DEBUG][15]    RollingFile.Close()

NMT Putty Log:

Code:

c ss timeout 285212672 mode 65 un1 5c un2 20
20 ss timeout 0 mode 0 un1 0 un2 0
Starting mvp timer
Starting mvp media writer
Starting mvp key reader
Changing server width 1220
Changing server height 712
(*) em86remote: received command 0xA8
f002 f000 12
(*) em86remote: received command 0xA8
f002 f000 12
(*) em86remote: received command 0x0D
f00c f000 d
(*) em86remote: received command 0xAB
f001 f000 11
(*) em86remote: received command 0xA9
f003 f000 13
(*) em86remote: received command 0x0D
f00c f000 d
-1 -1
Crap
bps 6500 length 123030741 dropoff 5000000
Starting to play audio file '\\DEN\Media\LIVETV~1\YOUTUB~1.MP4'
is universe 0
check file .MP4
(*) SMP863x: ------------------------ em86_free_layer_surface layer=0 scaler=6 ------------------------
(*) SMP863x: ------------------------ em86_free_layer_surface layer=1 scaler=1 ------------------------
(*) SMP863x: ------------------------ em86_free_layer_surface layer=3 scaler=4 ------------------------
(*) SMP863x: em86_main_video_scaler_deinterlace: mode=0
(*) Deinterlacing config: Discard/Bob; using_xlacing_motion_scaler=0
[src/mem_mngr.c:699] MRUA memory map ID MMAP_DirectFB_BASE (0xfc800e) released
[src/mem_mngr.c:699] MRUA memory map ID MMAP_VIDEO_2_BASE (0x80000a) released
[src/mem_mngr.c:856] DCC-HD MRUA memory allocator uninitalized
(!) System is going down !!
(!) System is down!!
Fork Child 25705
Fork Parent -1 25705
Ignoring yuv2 data
mono.c: 1956  ...  
Starting mono with command >> [/bin/mono] [-nogui] [http://192.168.1.3:8866/stream?f=//DEN\Media\LIVETV~1\YOUTUB~1.MP4] [-dram] [1] [-single]

mono.c: 2742  ...  ===> repeat mode: 0
mono.c: 2821  ...  ===> subtitle: 0
apply_tvmode  >> 11 [HDMI 1080p 60Hz]
tvmode param: [-f HDMI_1080p60 -o dvi_24 -asp 16 9 -dvi_hdmi siI9030 -hdmi2c 2 -cs rgb_16_235]

[HDMI] ========================== creating pDH ==========================
[HDMI] Detected part at I2C device address 0x72: vendor 0x0001, device 9253, rev.0x02 (Silicon Image)
[HDMI] Using the part: SiI9030 (4), Vendor ID is 0x0001 / 0x9253
[HDMI]    ***   HotPlug changed, is now ON
[HDMI]    ***   Rx changed, is now ON
[HDMI]    ***   Clock changed, is now STABLE
[HDMI] DHCancelHDCP()

  HH  HH  HHHHH   HH   HH  HHHH      HHHH   HH   HH
  HH  HH  HH  HH  HHH HHH   HH      HH  HH  HHH  HH
  HHHHHH  HH  HH  HH H HH   HH      HH  HH  HH H HH
  HH  HH  HH  HH  HH   HH   HH      HH  HH  HH  HHH
  HH  HH  HHHHH   HH   HH  HHHH      HHHH   HH   HH

[HDMI] DHGetVideoModeFromEDID(): Looking for 16:9 mode in YCbCr
Monitor is HDMI
[HDMI] DHSetHDMIMode(TRUE)
[HDMI] Sending blank AudioInfoFrames
[HDMI] Sending null packet
[HDMI] DHUpdateVideoPixelClock(148500000)
[HDMI] Setting the HDMI Audio Clock, PixClk=148500000, SampleClk=44100
HDMI Colorspace is now: RGB limited range
Monitor is HDMI
[HDMI]    ***   Clock changed, is now STABLE
Cannot insert picture inside surface 7
rm: cannot remove '/tmp/temp.jpg': No such file or directory
mono.c: 3323  ...  open_path: [http://192.168.1.3:8866/stream?f=//DEN\Media\LIVETV~1\YOUTUB~1.MP4]
mp4
mono.c: 3607  ...  [mono] apptype=7
mono.c: 3696  ...  [mono] app_params.play_opt->prebuf_max: 16777216
mono.c: 3716  ...  [mono] start play_file_app
Using app: 7
rm: cannot remove '/tmp/is_wma.txt': No such file or directory
Error opening file http://192.168.1.3:8866/stream?f=//DEN\Media\LIVETV~1\YOUTUB~1.MP4
mono.c: 4196  ...  MONO cleanup done and exit...
Child exit |65280|
Last key was -1
(*) DirectFB/Config: Active DTV signal 1080p
hdtv60 1280x720

     =======================|  DirectFB 1.0.0  |=======================
          (c) 2001-2007  The DirectFB Organization (directfb.org)
          (c) 2000-2004  Convergence (integrated media) GmbH
        ------------------------------------------------------------

[mvallevand]

Those are similar to mine, it needs more time to grow.

Martin

[UncleJohnsBand]

Lowering the resolution to 720p for some and 420p for most allows playing on NMT.....with no chunking! I would like to be able to get up to the 1080P......

[whurlston]

Here's two for you to test:

50percent.zip will buffer half the video before attempting to play.
100percent.zip will complete the download before attempting to play.

[mvallevand]

I tried the 50 percent solution but I lost the attributes in YouTube.xml and it doesn't write them anymore so I can't test http streaming

On the PC it is fine but on the NMT still hit and miss (here I am playing the same file first one worked second didn't. Deleting from temp didn't help

Code:

2012-01-26 23:32:03.539    [DEBUG][3]    YOUTUBE_PLUGIN_PLAY
2012-01-26 23:32:03.539    [DEBUG][3]    YouTube: IEventNotification(YOUTUBE_PLUGIN_PLAY, System.Collections.Hashtable)
2012-01-26 23:32:04.567    [DEBUG][13]    YouTube: Video Downloader Status Change: Started : Starting download of "C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4" : Filesize is 41352902
2012-01-26 23:32:58.566    [DEBUG][13]    YouTube: Video Downloader Status Change: ReadyToWatch : C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4
2012-01-26 23:32:58.566    [DEBUG][13]    YOUTUBE_PLUGIN_PLAY_CALLBACK
2012-01-26 23:32:58.566    [DEBUG][13]    YouTube: IEventNotification(YOUTUBE_PLUGIN_PLAY_CALLBACK, System.Collections.Hashtable)
2012-01-26 23:32:58.650    [DEBUG][3]    Playing video file: C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4
2012-01-26 23:32:58.809    [DEBUG][3]    StartVideoPlayback: C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4


2012-01-26 23:34:38.508    [DEBUG][3]    YOUTUBE_PLUGIN_PLAY
2012-01-26 23:34:38.508    [DEBUG][3]    YouTube: IEventNotification(YOUTUBE_PLUGIN_PLAY, System.Collections.Hashtable)
2012-01-26 23:34:39.838    [DEBUG][14]    YouTube: Video Downloader Status Change: Started : Starting download of "C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4" : Filesize is 41352902
2012-01-26 23:34:48.620    [DEBUG][14]    YouTube: Video Downloader Status Change: ReadyToWatch : C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4
2012-01-26 23:34:48.620    [DEBUG][14]    YOUTUBE_PLUGIN_PLAY_CALLBACK
2012-01-26 23:34:48.620    [DEBUG][14]    YouTube: IEventNotification(YOUTUBE_PLUGIN_PLAY_CALLBACK, System.Collections.Hashtable)
2012-01-26 23:34:48.663    [DEBUG][3]    Playing video file: C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4
2012-01-26 23:34:48.663    [DEBUG][3]    StartVideoPlayback: C:\temp\youtube-WcN392H2jx0.PCH-0006DC41CE68.mp4

On a positive note I do get back the YOUTUBE_PLUGIN_PLAY_CALLBACK_ERROR

Martin

[whurlston]

I tried the 50 percent solution but I lost the attributes in YouTube.xml and it doesn't write them anymore so I can't test http streaming

Can you post the full log? I didn't change anything that should have affected that.

On a positive note I do get back the YOUTUBE_PLUGIN_PLAY_CALLBACK_ERROR

Martin

Great.

Edit:

The plugin will only write the youtube.xml settings to disc when you exit the YouTube plugin itself (if sticky settings are enabled) or when clicking "OK" on the NextPVR settings screen. It does not save them when called from another plugin, it only reads them in that case.

[mvallevand]

I found YouTube.xml in the the data folder, I was looking in plugins\YouTube I must have found it by accident yesterday.

Changing to streaming PC is great definitely I would recommend this. On the NMT no luck. On both PC/NMT I get the ShowMessage() about buffering even in streaming mode I assume is just connecting On the NMT it never losses this message but I do get a callback error in the log.

Martin

[whurlston]

Yeah, I much prefer streaming to buffering myself. It's so much faster. The "please wait ... buffering" message is the same whether buffering or streaming.

I'll look into why the popup isn't going away tomorrow. I should get some time to test on the NMT then. It's just hard to do it at night while my wife is sleeping.