Wed 5/24 7:22:10.006 user.dir2=C:\Program Files\SageTV\SageTV
Wed 5/24 7:22:10.008 classpath=C:\Program Files\SageTV\SageTV\Sage.jar;C:\Program Files\SageTV\SageTV\xerces.jar;C:\Program Files\SageTV\SageTV\plugin.jar;C:\Program Files\SageTV\SageTV\;;JARs\commons-jxpath-1.1.jar;JARs\commons-logging-api.jar;JARs\commons-logging.jar;JARs\Copy of nielm_sageutls.jar;JARs\df_sageplugins.jar;JARs\df_sageutils.jar;JARs\jcifs-1.1.6.jar;JARs\jdic.jar;JARs\mx4j-impl.jar;JARs\mx4j-jmx.jar;JARs\mx4j-remote.jar;JARs\mx4j-tools.jar;JARs\nielm_getrssnews.jar;JARs\nielm_sagemenureader.jar;JARs\nielm_sageutls.jar;JARs\nielm_sagewebserver.jar;JARs\nielm_sagexmlinfo.jar;JARs\sbbi-jmx-1.0.jar;JARs\sbbi-upnplib-1.0.3.jar;JARs\servlet.jar
Wed 5/24 7:22:10.009 JVM version=1.5.0_05
Wed 5/24 7:22:10.017 OS=Windows XP 5.1
Wed 5/24 7:22:10.019 Succesfully setup system shell hook
Wed 5/24 7:22:10.020 specifiy RawInputHook Enable 1 in registery
Wed 5/24 7:22:10.020 Succesfully setup win raw input
Wed 5/24 7:22:10.021 not specifiy WinkeyboardHook in registery, load default one
Wed 5/24 7:22:10.240 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/splash.gif
Wed 5/24 7:22:10.260 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1bf52a5
Wed 5/24 7:22:10.312 Backing up properties file for SageTV upgrade...
Wed 5/24 7:22:10.323 SageTV V5.0.3.92
Wed 5/24 7:22:10.329 hostname=mediaserver
Wed 5/24 7:22:10.394 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon.gif
Wed 5/24 7:22:10.396 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1891d8f
Wed 5/24 7:22:10.449 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim0.gif
Wed 5/24 7:22:10.451 ImageUtils creating BI copy sun.awt.image.ToolkitImage@bfbdb0
Wed 5/24 7:22:10.452 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim1.gif
Wed 5/24 7:22:10.453 ImageUtils creating BI copy sun.awt.image.ToolkitImage@19fcc69
Wed 5/24 7:22:10.454 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim2.gif
Wed 5/24 7:22:10.456 ImageUtils creating BI copy sun.awt.image.ToolkitImage@209f4e
Wed 5/24 7:22:10.457 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim3.gif
Wed 5/24 7:22:10.459 ImageUtils creating BI copy sun.awt.image.ToolkitImage@12f6684
Wed 5/24 7:22:10.539 Wizard starting to load database info...
Wed 5/24 7:22:10.541 Wizard DONE loading database info. loadTime=0.0010 sec
Wed 5/24 7:22:10.580 SageTV received connection from:Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:11.428 Received command of:PROPERTY_SYNC 555 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:11.530 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:11.532 Wizard allocating table for Year of size 90
Wed 5/24 7:22:11.532 Wizard loading main index for Year
Wed 5/24 7:22:11.534 Wizard allocating table for Network of size 40
Wed 5/24 7:22:11.535 Wizard loading main index for Network
Wed 5/24 7:22:11.536 Wizard allocating table for Title of size 4058
Wed 5/24 7:22:11.537 Wizard loading main index for Title
Wed 5/24 7:22:11.616 Wizard building alt. index 0 for Title
Wed 5/24 7:22:11.630 Wizard allocating table for Channel of size 234
Wed 5/24 7:22:11.631 Wizard loading main index for Channel
Wed 5/24 7:22:11.640 Wizard allocating table for People of size 18670
Wed 5/24 7:22:11.649 Wizard loading main index for People
Wed 5/24 7:22:11.902 Wizard building alt. index 0 for People
Wed 5/24 7:22:11.927 Wizard allocating table for SubCategory of size 117
Wed 5/24 7:22:11.928 Wizard loading main index for SubCategory
Wed 5/24 7:22:11.929 Wizard allocating table for Rated of size 7
Wed 5/24 7:22:11.930 Wizard loading main index for Rated
Wed 5/24 7:22:11.930 Wizard allocating table for ParentalRating of size 0
Wed 5/24 7:22:11.931 Wizard allocating table for ExtendedRating of size 10
Wed 5/24 7:22:11.931 Wizard loading main index for ExtendedRating
Wed 5/24 7:22:11.932 Wizard allocating table for Category of size 89
Wed 5/24 7:22:11.932 Wizard loading main index for Category
Wed 5/24 7:22:11.933 Wizard allocating table for PrimeTitle of size 0
Wed 5/24 7:22:11.934 Wizard allocating table for Bonus of size 439
Wed 5/24 7:22:11.934 Wizard loading main index for Bonus
Wed 5/24 7:22:11.940 Wizard allocating table for Show of size 16281
Wed 5/24 7:22:11.940 Wizard loading main index for Show
Wed 5/24 7:22:15.096 Wizard building alt. index 0 for Show
Wed 5/24 7:22:15.130 Wizard allocating table for Airing of size 43861
Wed 5/24 7:22:15.136 Wizard loading main index for Airing
Wed 5/24 7:22:16.029 Wizard building alt. index 0 for Airing
Wed 5/24 7:22:16.060 Wizard building alt. index 1 for Airing
Wed 5/24 7:22:16.084 Wizard allocating table for ManualRecord of size 10
Wed 5/24 7:22:16.084 Wizard loading main index for ManualRecord
Wed 5/24 7:22:16.088 Wizard allocating table for MediaFile of size 444
Wed 5/24 7:22:16.088 Wizard loading main index for MediaFile
Wed 5/24 7:22:16.177 Wizard building alt. index 0 for MediaFile
Wed 5/24 7:22:16.179 Wizard allocating table for Watched of size 4373
Wed 5/24 7:22:16.180 Wizard loading main index for Watched
Wed 5/24 7:22:16.320 Wizard building alt. index 0 for Watched
Wed 5/24 7:22:16.324 Wizard allocating table for Agent of size 952
Wed 5/24 7:22:16.324 Wizard loading main index for Agent
Wed 5/24 7:22:16.371 Wizard building alt. index 0 for Agent
Wed 5/24 7:22:16.375 Wizard allocating table for Wasted of size 198
Wed 5/24 7:22:16.375 Wizard loading main index for Wasted
Wed 5/24 7:22:16.376 Wizard allocating table for Playlist of size 2
Wed 5/24 7:22:16.377 Wizard loading main index for Playlist
Wed 5/24 7:22:16.402 Received command of:CARNY_SYNC_CAUSEMAP 4501 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:16.461 Received command of:CARNY_SYNC_WPMAP 4225 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:16.504 Received command of:CARNY_SYNC_MUSTSEE 26 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:16.507 Received command of:CARNY_SYNC_LOVE 215 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:16.509 SageTV received connection from:Socket[addr=localhost/127.0.0.1,port=42024,localport=1038]
Wed 5/24 7:22:16.773 MMC calling detectCaptureDevices on sage.o@489c42
Wed 5/24 7:22:16.817 devices detected=[FusionHDTV, WDM Video Capture, Hauppauge WinTV PVR PCI II Capture #2, Hauppauge WinTV PVR PCI II Capture, Hauppauge WinTV PVR PCI II Capture #4, Hauppauge WinTV PVR PCI II Capture #3, FusionHDTV, WDM Video Capture #2]
Wed 5/24 7:22:16.818 EncoderMap={FusionHDTV, WDM Video Capture=FusionHDTV, WDM Video Capture, Hauppauge WinTV PVR PCI II Capture #2=Hauppauge WinTV PVR PCI II Capture #2, FusionHDTV, WDM Video Capture #2=FusionHDTV, WDM Video Capture #2, Hauppauge WinTV PVR PCI II Capture #4=Hauppauge WinTV PVR PCI II Capture #4, Hauppauge WinTV PVR PCI II Capture=Hauppauge WinTV PVR PCI II Capture, Hauppauge WinTV PVR PCI II Capture #3=Hauppauge WinTV PVR PCI II Capture #3}
Wed 5/24 7:22:17.320 DShowFilters=[.RAM file Parser, 9x8Resize, AC3 Parser Filter, AC3Filter, ACELP.net Sipro Lab Audio Decoder, ACM Wrapper, Allocator Fix, ASF ACM Handler, ASF DIB Handler, ASF DJPEG Handler, ASF embedded stuff Handler, ASF ICM Handler, ASF JPEG Handler, ASF URL Handler, ASX file Parser, ASX v.2 file Parser, AVI Decompressor, AVI Draw, AVI Mux, AVI Splitter, AVI/WAV File Source, BDA MPEG2 Transport Information Filter, Bitmap Generate, Color Space Converter, Deinterlace Filter, DV Muxer, DV Splitter, DV Video Decoder, DVD Navigator, File Source (Async.), File Source (Netshow URL), File Source (URL), File stream renderer, File writer, Frame Eater, Full Screen Renderer, G.711 Codec, Hauppauge WinTV Color Format Converter 2, Indeo® audio software, Indeo® video 4.4 Compression Filter, Indeo® video 4.4 Decompression Filter, Indeo® video 5.10 Compression Filter, Indeo® video 5.10 Decompression Filter, Infinite Pin Tee Filter, Internal Script Command Renderer, Line 21 Decoder, Line 21 Decoder 2, Microsoft MPEG-4 Video Decompressor, Microsoft Screen Video Decompressor, MIDI Parser, MJPEG Decompressor, MPEG Audio Decoder, MPEG Layer-3 Decoder, MPEG Video Decoder, MPEG-2 Demultiplexer, MPEG-2 Sections and Tables, MPEG-2 Splitter, MPEG-2 Video Stream Analyzer, MPEG-I Stream Splitter, MPEG2Dump, Mpeg4 Decoder DMO, Mpeg43 Decoder DMO, Mpeg4s Decoder DMO, Multi-file Parser, NSC file Parser, Null Renderer, NVIDIA ATSC File, NVIDIA Audio Decoder, NVIDIA Cd Audio Reader, NVIDIA MultiSource Filter, NVIDIA Navigator, NVIDIA Transport Demux, NVIDIA TS Info Parser, NVIDIA Video Decoder, NVIDIA Video Post Processor, Overlay Mixer, Overlay Mixer2, QT Decompressor, QuickTime Movie Parser, Record Queue, SageTV MPEG Audio Decoder, SageTV MPEG Audio Encoder, SageTV MPEG Encoder, SageTV MPEG Layer II Audio Encoder, SageTV MPEG Multiplexer, SageTV MPEG Splitter, SageTV MPEG Video Decoder, SageTV MPEG Video Encoder, SageTV MpegDeMux, SageTV MpegMux, SageTV Music Visualization, SageTV TS Splitter 1.0, SAMI (CC) Parser, SampleGrabber, Screen Capture filter, Shared File Source (Async.), Smart Tee, Sonic Cinemaster® DS Video Decoder, Sonic Cinemaster® MCE Audio Decoder, StreamBufferSink, StreamBufferSource, Stretch Video, Uncompressed Domain Shot Detection Filter, VBI Surface Allocator, VGA 16 Color Ditherer, Video Mixing Renderer 9, Video Port Manager, Video Renderer, Video Renderer, Wave Parser, WIA Stream Snapshot Filter, Windows Media Audio Decoder, Windows Media Multiplexer, Windows Media source filter, Windows Media Update Filter, Windows Media Video Decoder, Windows Media Video Decoder, WM ASF Reader, WM ASF Writer, WMAPro over S/PDIF DMO, WMAudio Decoder DMO, WMSpeech Decoder DMO, WMT AudioAnalyzer, WMT Black Frame Generator, WMT DirectX Transform Wrapper, WMT DV Extract, WMT Format Conversion, WMT Import Filter, WMT Interlacer, WMT Log Filter, WMT MuxDeMux Filter, WMT Sample Information Filter, WMT Screen Capture filter, WMT Switch Filter, WMT VIH2 Fix, WMT Virtual Renderer, WMT Virtual Source, WMT Volume, WMV Screen decoder DMO, WMVideo Advanced Decoder DMO, WMVideo Decoder DMO, WST Decoder, XML Playlist]
Wed 5/24 7:22:17.510 sage.aw@67ec28 needs an update in 10:19:30
Wed 5/24 7:22:17.511 sage.aw@1cb048e needs an update in 10:19:01
Wed 5/24 7:22:17.512 sage.aw@1983ad7 needs an update in 2562047788015:12:55
Wed 5/24 7:22:17.513 EPG needs an update in 619 minutes
Wed 5/24 7:22:17.513 EPG's works is done. Waiting...
Wed 5/24 7:22:17.719 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:17.720 VF thread is now running...
Wed 5/24 7:22:17.722 MsgRecv thread has spawned for /127.0.0.1:42024
Wed 5/24 7:22:17.724 MsgSend thread spawned for /127.0.0.1:42024
Wed 5/24 7:22:17.729 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:17.730 SetFullScreen(true)
Wed 5/24 7:22:17.731 FullScreen set to true
Wed 5/24 7:22:17.734 UIMgr loading UI from: C:\Program Files\SageTV\SageTV\STVs\SageTV3\SageTV3-2.xml
Wed 5/24 7:22:17.749 StorageDeviceDetector started...
Wed 5/24 7:22:17.857 ERROR loading STV of:tv.sage.b: kind=1; Module.loadXML failure
Wed 5/24 7:22:19.141 AWTThread Hang Detected - hang time = 882
Wed 5/24 7:22:19.150 locale = en
Wed 5/24 7:22:19.885 AWTThread Hang Detected - hang time = 1626
Wed 5/24 7:22:20.073 DatePat=EEE, MMM d orgPat=EEEE, MMMM d, yyyy
Wed 5/24 7:22:20.093 setUI(sage.bz@c393a1[Main Menu]) histIdx=0 uiHistory=[sage.bz@c393a1[Main Menu]]
Wed 5/24 7:22:20.821 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=34] numGlyphs=1674 numCachedGlyphs=277 numImages=4
Wed 5/24 7:22:20.895 VF processing job null nPlayin=false
Wed 5/24 7:22:20.896 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:21.142 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=29] numGlyphs=1674 numCachedGlyphs=280 numImages=3
Wed 5/24 7:22:21.462 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=49] numGlyphs=1674 numCachedGlyphs=262 numImages=8
Wed 5/24 7:22:21.766 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=plain,size=53] numGlyphs=1674 numCachedGlyphs=247 numImages=8
Wed 5/24 7:22:21.798 Initializing DirectX9
Wed 5/24 7:22:21.801 Using DX9 Full Screen Exclusive Mode
Wed 5/24 7:22:21.802 Creating D3D Device
Wed 5/24 7:22:21.882 Done Initializing DirectX9
Wed 5/24 7:22:21.885 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\Background.jpg
Wed 5/24 7:22:21.933 ImageUtils creating BI copy sun.awt.image.ToolkitImage@171b246
Wed 5/24 7:22:21.945 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.054 Creating DirectX9 Texture from memory w=600 h=450
Wed 5/24 7:22:22.057 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\SageLogo256.png
Wed 5/24 7:22:22.079 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1735602
Wed 5/24 7:22:22.080 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.091 Creating DirectX9 Texture from memory w=256 h=78
Wed 5/24 7:22:22.092 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.108 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.109 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.124 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.125 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.142 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.144 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.159 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.160 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.174 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.175 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.190 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.191 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MenuBarLong.png
Wed 5/24 7:22:22.205 ImageUtils creating BI copy sun.awt.image.ToolkitImage@19d96b1
Wed 5/24 7:22:22.206 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.215 Creating DirectX9 Texture from memory w=586 h=47
Wed 5/24 7:22:22.216 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.230 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.231 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.246 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.247 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:22.262 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:22.714 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:27.715 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:27.828 VF.submitJob(VFJob[CloseMF r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:27.829 VF processing job VFJob[CloseMF r=0.0 t=0 file=null ifn=null] nPlayin=false
Wed 5/24 7:22:27.830 VF processing on UI Thread VFJob[CloseMF r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:27.831 VF processing job null nPlayin=false
Wed 5/24 7:22:27.831 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:28.605 setUI(sage.bz@2219b4[MediaPlayer OSD]) histIdx=1 uiHistory=[sage.bz@c393a1[Main Menu], sage.bz@2219b4[MediaPlayer OSD]]
Wed 5/24 7:22:28.636 VF.submitJob(VFJob[TimeSet r=0.0 t=1148469748636 file=null ifn=null])
Wed 5/24 7:22:28.637 VF processing job VFJob[TimeSet r=0.0 t=1148469748636 file=null ifn=null] nPlayin=false
Wed 5/24 7:22:28.638 VF discarding job VFJob[TimeSet r=0.0 t=1148469748636 file=null ifn=null]
Wed 5/24 7:22:28.639 VF processing job null nPlayin=false
Wed 5/24 7:22:28.639 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:28.730 VideoFrame.watch(A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60])
Wed 5/24 7:22:28.731 watchThisFile=null
Wed 5/24 7:22:28.732 Sending requestWatch to server for A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60]
Wed 5/24 7:22:28.749 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:28.972 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=38] numGlyphs=1674 numCachedGlyphs=259 numImages=5
Wed 5/24 7:22:28.973 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:28.980 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:28.990 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:29.311 Received command of:PROPERTY_SYNC 1 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:30.950 VF.submitJob(VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] ifn=null])
Wed 5/24 7:22:30.951 VF processing job VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:22:30.952 VF processing on UI Thread VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:22:30.954 VF digital TV playback detected: false
Wed 5/24 7:22:30.955 VideoFrame creating new media player for file:MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]]
Wed 5/24 7:22:30.957 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:22:30.958 VF network encoder playback detected: false
Wed 5/24 7:22:30.999 VF waiting for data to appear in new file...liveWait=-2210
Wed 5/24 7:22:31.000 VF thread is now waiting for 0:00:00.200
Wed 5/24 7:22:31.073 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:31.093 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:31.094 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDChDisplay.png
Wed 5/24 7:22:31.096 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1dffb78
Wed 5/24 7:22:31.097 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:31.104 Creating DirectX9 Texture from memory w=35 h=26
Wed 5/24 7:22:31.105 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDStatusPause.png
Wed 5/24 7:22:31.106 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1f920cf
Wed 5/24 7:22:31.107 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:31.107 Creating DirectX9 Texture from memory w=6 h=8
Wed 5/24 7:22:31.108 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDVolOn.png
Wed 5/24 7:22:31.109 ImageUtils creating BI copy sun.awt.image.ToolkitImage@4e229e
Wed 5/24 7:22:31.109 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:31.110 Creating DirectX9 Texture from memory w=16 h=13
Wed 5/24 7:22:31.110 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDVolBar.png
Wed 5/24 7:22:31.111 ImageUtils creating BI copy sun.awt.image.ToolkitImage@abaf8c
Wed 5/24 7:22:31.112 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:31.113 Creating DirectX9 Texture from memory w=64 h=4
Wed 5/24 7:22:31.113 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDVolSlider.png
Wed 5/24 7:22:31.114 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1ff8506
Wed 5/24 7:22:31.115 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:31.116 Creating DirectX9 Texture from memory w=9 h=15
Wed 5/24 7:22:31.201 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:22:31.202 VF network encoder playback detected: false
Wed 5/24 7:22:31.214 VF processing on UI Thread VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:22:31.218 VF file=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] targetTime = Wed 5/24 7:22:28.751
Wed 5/24 7:22:31.219 VideoFrame.timeSelected(Wed 5/24 7:22:28.751, true) currFile=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]]
Wed 5/24 7:22:31.226 DShowPlayer setVideoRendererFilter0({51B4ABF3-748F-4E3B-A276-C828330E926A}) called
Wed 5/24 7:22:31.270 Setting up VMR9 deinterlacing
Wed 5/24 7:22:31.271 Curr Mix Prefs=0x1015
Wed 5/24 7:22:31.271 Set to 0x2015, hr=0x0, New Mix Prefs=0x2015
Wed 5/24 7:22:31.271 DShowPlayer setVideoDecoderFilter0(NVIDIA Video Decoder) called
Wed 5/24 7:22:31.522 DShowPlayer setAudioDecoderFilter0(Sonic Cinemaster@ MCE Audio Decoder) called
Wed 5/24 7:22:31.691 DShowPlayer setTimeshift=1 buffer=0
Wed 5/24 7:22:31.725 NATIVE Loading the source file
Wed 5/24 7:22:31.739 NATIVE Setting up the MPEG demux
Wed 5/24 7:22:31.791 NATIVE RenderAudio called
Wed 5/24 7:22:31.791 NATIVE RenderAudio step 1
Wed 5/24 7:22:31.792 NATIVE RenderAudio step 2
Wed 5/24 7:22:31.792 NATIVE RenderAudio step 3
Wed 5/24 7:22:31.792 NATIVE RenderAudio step 4
Wed 5/24 7:22:32.001 NATIVE RenderVideo called
Wed 5/24 7:22:32.002 NATIVE RenderVideo step 1
Wed 5/24 7:22:32.028 NATIVE RenderVideo step 2
Wed 5/24 7:22:32.029 Video source pin information:
Wed 5/24 7:22:32.029 PIN is not connected yet!Wed 5/24 7:22:32.034 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.035 Interlaced video
Wed 5/24 7:22:32.035 Both fields per sample
Wed 5/24 7:22:32.035 Field 2 first
Wed 5/24 7:22:32.035 Stream never contains a Field 2
Wed 5/24 7:22:32.036 Either bob or weave mode.
Wed 5/24 7:22:32.036 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.036 Interlaced video
Wed 5/24 7:22:32.036 Both fields per sample
Wed 5/24 7:22:32.037 Field 2 first
Wed 5/24 7:22:32.037 Stream never contains a Field 2
Wed 5/24 7:22:32.037 Either bob or weave mode.
Wed 5/24 7:22:32.037 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.038 Interlaced video
Wed 5/24 7:22:32.038 Both fields per sample
Wed 5/24 7:22:32.038 Field 2 first
Wed 5/24 7:22:32.039 Stream never contains a Field 2
Wed 5/24 7:22:32.039 Either bob or weave mode.
Wed 5/24 7:22:32.039 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.039 Interlaced video
Wed 5/24 7:22:32.040 Both fields per sample
Wed 5/24 7:22:32.040 Field 2 first
Wed 5/24 7:22:32.040 Stream never contains a Field 2
Wed 5/24 7:22:32.040 Either bob or weave mode.
Wed 5/24 7:22:32.041 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.041 Interlaced video
Wed 5/24 7:22:32.041 Both fields per sample
Wed 5/24 7:22:32.041 Field 2 first
Wed 5/24 7:22:32.042 Stream never contains a Field 2
Wed 5/24 7:22:32.042 Either bob or weave mode.
Wed 5/24 7:22:32.042 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.043 Interlaced video
Wed 5/24 7:22:32.043 Both fields per sample
Wed 5/24 7:22:32.043 Field 2 first
Wed 5/24 7:22:32.043 Stream never contains a Field 2
Wed 5/24 7:22:32.044 Either bob or weave mode.
Wed 5/24 7:22:32.044 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.044 Interlaced video
Wed 5/24 7:22:32.044 Both fields per sample
Wed 5/24 7:22:32.045 Field 2 first
Wed 5/24 7:22:32.045 Stream never contains a Field 2
Wed 5/24 7:22:32.045 Either bob or weave mode.
Wed 5/24 7:22:32.045 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.046 Interlaced video
Wed 5/24 7:22:32.046 Both fields per sample
Wed 5/24 7:22:32.046 Field 2 first
Wed 5/24 7:22:32.046 Stream never contains a Field 2
Wed 5/24 7:22:32.047 Either bob or weave mode.
Wed 5/24 7:22:32.047 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YUY2 F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.047 Interlaced video
Wed 5/24 7:22:32.048 Both fields per sample
Wed 5/24 7:22:32.048 Field 2 first
Wed 5/24 7:22:32.048 Stream never contains a Field 2
Wed 5/24 7:22:32.048 Either bob or weave mode.
Wed 5/24 7:22:32.049 M type MEDIATYPE_Video  S type MEDIASUBTYPE_UYVY F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.050 Interlaced video
Wed 5/24 7:22:32.050 Both fields per sample
Wed 5/24 7:22:32.051 Field 2 first
Wed 5/24 7:22:32.051 Stream never contains a Field 2
Wed 5/24 7:22:32.051 Either bob or weave mode.
Wed 5/24 7:22:32.052 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YV12 F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.052 Interlaced video
Wed 5/24 7:22:32.052 Both fields per sample
Wed 5/24 7:22:32.052 Field 2 first
Wed 5/24 7:22:32.053 Stream never contains a Field 2
Wed 5/24 7:22:32.053 Either bob or weave mode.
Wed 5/24 7:22:32.053 NATIVE RenderVideo step 3
Wed 5/24 7:22:32.216 AWTThread Hang Detected - hang time = 750
Wed 5/24 7:22:32.226 VMR9 alloc 720x540 Offscreen DefaultPool  format=NV12 minBuffs=1 arx=4 ary=3 nativeWidth=720 nativeHeight=540 reqNumBuff=1 allocNumBuff=1 hr=0x0
Wed 5/24 7:22:32.254 Setting up VMR9 deinterlacing
Wed 5/24 7:22:32.254 VM9Deinterlacing Tech: PixelAdaptive
Wed 5/24 7:22:32.254 VM9Deinterlacing Tech: BOBVerticalStretch
Wed 5/24 7:22:32.255 Actual deinterlace: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:22:32.255 deinterlace mode: hr=0x1 guid={00000000-0000-0000-0000-000000000000}
Wed 5/24 7:22:32.255 Setting deinterlace mode to actual mode...
Wed 5/24 7:22:32.256 deinterlace mode: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:22:32.256 Filter Graph Video Renderer Info:
Wed 5/24 7:22:32.256 Video Renderer:CLSID_VideoMixingRenderer9
Wed 5/24 7:22:32.256 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:32.257 Interlaced video
Wed 5/24 7:22:32.257 Both fields per sample
Wed 5/24 7:22:32.257 Field 2 first
Wed 5/24 7:22:32.257 Stream never contains a Field 2
Wed 5/24 7:22:32.258 Either bob or weave mode.
Wed 5/24 7:22:32.258 VMR9 filter detected, using line 21 decoder 2.Wed 5/24 7:22:32.262 DShowGraphFilters=Default DirectSound Device,VidRend,Line21 Decoder,AC3Filter,Video Decoder,Audio Decoder,SageTV MPEG2 Demultiplexer,E:\media\TV\BreakfastWithBear-617963-0.mpg,
Wed 5/24 7:22:32.277 VideoFrame.timeSelected2(Wed 5/24 7:22:28.751, true) currFile=MediaFile[id=688668 A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\BreakfastWithBear-617963-0.mpg, Seg0[Wed 5/24 7:22:28.751-Wed 12/31 19:00:00.000]] realDur=0
Wed 5/24 7:22:32.278 About to perform media time selection for 0
Wed 5/24 7:22:32.278 Running the playback graph.
Wed 5/24 7:22:32.279 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.293 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.295 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.297 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.298 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.299 Event: 0xd
Wed 5/24 7:22:32.299 Event: 0xe
Wed 5/24 7:22:32.300 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.303 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.304 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.310 VF processing job null nPlayin=true
Wed 5/24 7:22:32.310 isRec=true rd=3559 base=7
Wed 5/24 7:22:32.318 VF thread is now waiting for 0:07:30.985
Wed 5/24 7:22:32.377 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.378 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.379 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.380 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.381 Event: 0x8065
Wed 5/24 7:22:32.381 VF processing job null nPlayin=true
Wed 5/24 7:22:32.382 isRec=true rd=3631 base=82
Wed 5/24 7:22:32.383 VF thread is now waiting for 0:07:30.916
Wed 5/24 7:22:32.385 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.386 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.387 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.388 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.389 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.392 Event: 0x8065
Wed 5/24 7:22:32.392 Event: 0x8065
Wed 5/24 7:22:32.392 Event: 0x8065
Wed 5/24 7:22:32.393 Event: 0x8065
Wed 5/24 7:22:32.394 Event: 0x8065
Wed 5/24 7:22:32.394 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.395 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.396 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.396 Event: 0x8065
Wed 5/24 7:22:32.397 VF processing job null nPlayin=true
Wed 5/24 7:22:32.397 isRec=true rd=3646 base=98
Wed 5/24 7:22:32.398 VF thread is now waiting for 0:07:30.900
Wed 5/24 7:22:32.399 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.400 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.401 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.402 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.402 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.403 Event: 0x8065
Wed 5/24 7:22:32.404 Event: 0x8065
Wed 5/24 7:22:32.404 Event: 0x8065
Wed 5/24 7:22:32.405 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.406 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.407 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.408 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.409 Event: 0x8065
Wed 5/24 7:22:32.411 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.411 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.412 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.413 VF processing job null nPlayin=true
Wed 5/24 7:22:32.414 isRec=true rd=3663 base=115
Wed 5/24 7:22:32.415 VF thread is now waiting for 0:07:30.883
Wed 5/24 7:22:32.417 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.420 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.421 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.422 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.422 Event: 0x8065
Wed 5/24 7:22:32.423 Event: 0x8065
Wed 5/24 7:22:32.423 Event: 0x8065
Wed 5/24 7:22:32.423 VF processing job null nPlayin=true
Wed 5/24 7:22:32.424 isRec=true rd=3673 base=125
Wed 5/24 7:22:32.425 VF thread is now waiting for 0:07:30.874
Wed 5/24 7:22:32.427 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.428 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.429 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.429 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.431 VF processing job null nPlayin=true
Wed 5/24 7:22:32.432 isRec=true rd=3681 base=133
Wed 5/24 7:22:32.433 VF thread is now waiting for 0:07:30.866
Wed 5/24 7:22:32.433 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.434 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.435 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.436 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.439 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.441 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.441 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.443 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.443 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.445 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.446 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.446 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.447 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:32.448 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.449 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.450 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.451 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.452 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.453 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.455 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.455 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.456 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:32.457 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:32.458 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:32.458 VF processing job null nPlayin=true
Wed 5/24 7:22:32.459 isRec=true rd=3708 base=161
Wed 5/24 7:22:32.460 VF thread is now waiting for 0:07:30.838
Wed 5/24 7:22:32.497 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDStatusPlay.png
Wed 5/24 7:22:32.498 ImageUtils creating BI copy sun.awt.image.ToolkitImage@5ef79f
Wed 5/24 7:22:32.499 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:32.500 Creating DirectX9 Texture from memory w=8 h=8
Wed 5/24 7:22:32.516 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:32.518 Creating DirectX9 Texture from memory w=32 h=32
Wed 5/24 7:22:32.702 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:32.858 VMR9 rendering began VRAM free=339738624
Wed 5/24 7:22:32.859 Created alternate surface
Wed 5/24 7:22:32.871 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:32.873 Creating DirectX9 Texture from memory w=32 h=32
Wed 5/24 7:22:32.879 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:32.883 Creating DirectX9 Texture from memory w=32 h=32
Wed 5/24 7:22:32.897 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:32.899 Creating DirectX9 Texture from memory w=32 h=32
Wed 5/24 7:22:34.772 VF processing job null nPlayin=true
Wed 5/24 7:22:34.773 isRec=true rd=6022 base=2474
Wed 5/24 7:22:34.774 VF thread is now waiting for 0:07:28.524
Wed 5/24 7:22:37.704 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:38.115 Processing channel change request isDown=true targetChan=056
Wed 5/24 7:22:38.146 VideoFrame.watch(A[618324,618279,"All Grown Up",11006@0524.07:00,30])
Wed 5/24 7:22:38.146 watchThisFile=null
Wed 5/24 7:22:38.147 Sending requestWatch to server for A[618324,618279,"All Grown Up",11006@0524.07:00,30]
Wed 5/24 7:22:38.155 VF.submitJob(VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\BreakfastWithBear-617963-0.mpg])
Wed 5/24 7:22:38.156 VF processing job VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\BreakfastWithBear-617963-0.mpg] nPlayin=true
Wed 5/24 7:22:38.157 VF processing on UI Thread VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\BreakfastWithBear-617963-0.mpg]
Wed 5/24 7:22:38.158 VF notified of Inactive File
Wed 5/24 7:22:38.159 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:38.160 VF processing job null nPlayin=true
Wed 5/24 7:22:38.161 isRec=false rd=9415 base=5863
Wed 5/24 7:22:38.161 VF thread is now waiting for 0:00:03.301
Wed 5/24 7:22:38.164 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:38.166 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:38.650 Received command of:PROPERTY_SYNC 1 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:38.658 VF.submitJob(VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null])
Wed 5/24 7:22:38.659 VF processing job VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=true
Wed 5/24 7:22:38.661 VF processing on UI Thread VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:22:38.664 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:38.666 VF logFileWatch doneAir=A[617963,13147,"Breakfast With Bear",10171@0524.06:30,60] theTime=Wed 5/24 7:22:35.115 recTime=Wed 5/24 7:22:28.751
Wed 5/24 7:22:38.667 Stopping the playback graph.
Wed 5/24 7:22:38.706 VF digital TV playback detected: false
Wed 5/24 7:22:38.707 VIDEOFRAME Needs to do A FULL SWITCH on the file due to ENCODING CHANGE
Wed 5/24 7:22:38.708 Tearing down playback graph
Wed 5/24 7:22:38.708 NATIVE Deallocating the CPlayerData object
Wed 5/24 7:22:38.717 VMR9 rendering done VRAM free=357564416
Wed 5/24 7:22:38.832 NATIVE Finished destroying the playback graph
Wed 5/24 7:22:38.834 VideoFrame creating new media player for file:MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]]
Wed 5/24 7:22:38.835 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:22:38.836 VF network encoder playback detected: false
Wed 5/24 7:22:38.843 VF waiting for data to appear in new file...liveWait=-661
Wed 5/24 7:22:38.843 VF thread is now waiting for 0:00:00.200
Wed 5/24 7:22:39.044 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:22:39.045 VF network encoder playback detected: false
Wed 5/24 7:22:39.054 VF waiting for data to appear in new file...liveWait=-870
Wed 5/24 7:22:39.058 VF thread is now waiting for 0:00:00.200
Wed 5/24 7:22:39.258 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:22:39.259 VF network encoder playback detected: false
Wed 5/24 7:22:39.265 VF processing on UI Thread VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:22:39.266 VF file=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] targetTime = Wed 5/24 7:22:38.176
Wed 5/24 7:22:39.267 VideoFrame.timeSelected(Wed 5/24 7:22:38.176, true) currFile=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]]
Wed 5/24 7:22:39.270 DShowPlayer setVideoRendererFilter0({51B4ABF3-748F-4E3B-A276-C828330E926A}) called
Wed 5/24 7:22:39.289 Setting up VMR9 deinterlacing
Wed 5/24 7:22:39.289 Curr Mix Prefs=0x1015
Wed 5/24 7:22:39.289 Set to 0x2015, hr=0x0, New Mix Prefs=0x2015
Wed 5/24 7:22:39.290 DShowPlayer setVideoDecoderFilter0(NVIDIA Video Decoder) called
Wed 5/24 7:22:39.445 DShowPlayer setAudioDecoderFilter0(Sonic Cinemaster@ MCE Audio Decoder) called
Wed 5/24 7:22:39.471 DShowPlayer setTimeshift=1 buffer=0
Wed 5/24 7:22:39.473 NATIVE Loading the source file
Wed 5/24 7:22:39.475 NATIVE Setting up the MPEG demux
Wed 5/24 7:22:39.479 NATIVE RenderAudio called
Wed 5/24 7:22:39.480 NATIVE RenderAudio step 1
Wed 5/24 7:22:39.481 NATIVE RenderAudio step 2
Wed 5/24 7:22:39.481 NATIVE RenderAudio step 3
Wed 5/24 7:22:39.481 NATIVE RenderAudio step 4
Wed 5/24 7:22:39.532 NATIVE RenderVideo called
Wed 5/24 7:22:39.533 NATIVE RenderVideo step 1
Wed 5/24 7:22:39.534 NATIVE RenderVideo step 2
Wed 5/24 7:22:39.535 Video source pin information:
Wed 5/24 7:22:39.535 PIN is not connected yet!Wed 5/24 7:22:39.535 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.536 Interlaced video
Wed 5/24 7:22:39.536 Both fields per sample
Wed 5/24 7:22:39.536 Field 2 first
Wed 5/24 7:22:39.536 Stream never contains a Field 2
Wed 5/24 7:22:39.537 Either bob or weave mode.
Wed 5/24 7:22:39.537 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.537 Interlaced video
Wed 5/24 7:22:39.537 Both fields per sample
Wed 5/24 7:22:39.538 Field 2 first
Wed 5/24 7:22:39.538 Stream never contains a Field 2
Wed 5/24 7:22:39.538 Either bob or weave mode.
Wed 5/24 7:22:39.538 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.539 Interlaced video
Wed 5/24 7:22:39.539 Both fields per sample
Wed 5/24 7:22:39.539 Field 2 first
Wed 5/24 7:22:39.540 Stream never contains a Field 2
Wed 5/24 7:22:39.540 Either bob or weave mode.
Wed 5/24 7:22:39.540 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.540 Interlaced video
Wed 5/24 7:22:39.541 Both fields per sample
Wed 5/24 7:22:39.541 Field 2 first
Wed 5/24 7:22:39.541 Stream never contains a Field 2
Wed 5/24 7:22:39.541 Either bob or weave mode.
Wed 5/24 7:22:39.542 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.542 Interlaced video
Wed 5/24 7:22:39.543 Both fields per sample
Wed 5/24 7:22:39.543 Field 2 first
Wed 5/24 7:22:39.543 Stream never contains a Field 2
Wed 5/24 7:22:39.543 Either bob or weave mode.
Wed 5/24 7:22:39.544 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.544 Interlaced video
Wed 5/24 7:22:39.544 Both fields per sample
Wed 5/24 7:22:39.545 Field 2 first
Wed 5/24 7:22:39.545 Stream never contains a Field 2
Wed 5/24 7:22:39.545 Either bob or weave mode.
Wed 5/24 7:22:39.545 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.546 Interlaced video
Wed 5/24 7:22:39.546 Both fields per sample
Wed 5/24 7:22:39.546 Field 2 first
Wed 5/24 7:22:39.546 Stream never contains a Field 2
Wed 5/24 7:22:39.547 Either bob or weave mode.
Wed 5/24 7:22:39.547 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.547 Interlaced video
Wed 5/24 7:22:39.548 Both fields per sample
Wed 5/24 7:22:39.548 Field 2 first
Wed 5/24 7:22:39.548 Stream never contains a Field 2
Wed 5/24 7:22:39.548 Either bob or weave mode.
Wed 5/24 7:22:39.549 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YUY2 F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.549 Interlaced video
Wed 5/24 7:22:39.549 Both fields per sample
Wed 5/24 7:22:39.550 Field 2 first
Wed 5/24 7:22:39.550 Stream never contains a Field 2
Wed 5/24 7:22:39.550 Either bob or weave mode.
Wed 5/24 7:22:39.551 M type MEDIATYPE_Video  S type MEDIASUBTYPE_UYVY F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.551 Interlaced video
Wed 5/24 7:22:39.551 Both fields per sample
Wed 5/24 7:22:39.552 Field 2 first
Wed 5/24 7:22:39.552 Stream never contains a Field 2
Wed 5/24 7:22:39.552 Either bob or weave mode.
Wed 5/24 7:22:39.552 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YV12 F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.553 Interlaced video
Wed 5/24 7:22:39.553 Both fields per sample
Wed 5/24 7:22:39.553 Field 2 first
Wed 5/24 7:22:39.553 Stream never contains a Field 2
Wed 5/24 7:22:39.554 Either bob or weave mode.
Wed 5/24 7:22:39.554 NATIVE RenderVideo step 3
Wed 5/24 7:22:39.641 VMR9 alloc 720x540 Offscreen DefaultPool  format=NV12 minBuffs=1 arx=4 ary=3 nativeWidth=720 nativeHeight=540 reqNumBuff=1 allocNumBuff=1 hr=0x0
Wed 5/24 7:22:39.653 Setting up VMR9 deinterlacing
Wed 5/24 7:22:39.653 VM9Deinterlacing Tech: PixelAdaptive
Wed 5/24 7:22:39.653 VM9Deinterlacing Tech: BOBVerticalStretch
Wed 5/24 7:22:39.654 Actual deinterlace: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:22:39.654 deinterlace mode: hr=0x1 guid={00000000-0000-0000-0000-000000000000}
Wed 5/24 7:22:39.654 Setting deinterlace mode to actual mode...
Wed 5/24 7:22:39.654 deinterlace mode: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:22:39.655 Filter Graph Video Renderer Info:
Wed 5/24 7:22:39.655 Video Renderer:CLSID_VideoMixingRenderer9
Wed 5/24 7:22:39.655 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:22:39.656 Interlaced video
Wed 5/24 7:22:39.656 Both fields per sample
Wed 5/24 7:22:39.656 Field 2 first
Wed 5/24 7:22:39.656 Stream never contains a Field 2
Wed 5/24 7:22:39.657 Either bob or weave mode.
Wed 5/24 7:22:39.657 VMR9 filter detected, using line 21 decoder 2.Wed 5/24 7:22:39.659 DShowGraphFilters=Default DirectSound Device,VidRend,Line21 Decoder,AC3Filter,Video Decoder,Audio Decoder,SageTV MPEG2 Demultiplexer,E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg,
Wed 5/24 7:22:39.661 VideoFrame.timeSelected2(Wed 5/24 7:22:38.176, true) currFile=MediaFile[id=688669 A[618324,618279,"All Grown Up",11006@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg, Seg0[Wed 5/24 7:22:38.176-Wed 12/31 19:00:00.000]] realDur=0
Wed 5/24 7:22:39.662 About to perform media time selection for 0
Wed 5/24 7:22:39.662 Running the playback graph.
Wed 5/24 7:22:39.663 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.677 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.684 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.686 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.687 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.689 Event: 0xd
Wed 5/24 7:22:39.689 Event: 0xe
Wed 5/24 7:22:39.689 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.694 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.694 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.696 VF processing job null nPlayin=true
Wed 5/24 7:22:39.696 isRec=true rd=1520 base=10
Wed 5/24 7:22:39.697 VF thread is now waiting for 0:07:21.563
Wed 5/24 7:22:39.773 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.775 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.776 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.777 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.778 Event: 0x8065
Wed 5/24 7:22:39.778 VF processing job null nPlayin=true
Wed 5/24 7:22:39.779 isRec=true rd=1603 base=117
Wed 5/24 7:22:39.780 VF thread is now waiting for 0:07:21.456
Wed 5/24 7:22:39.783 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.784 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.784 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.785 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.786 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.786 Event: 0x8065
Wed 5/24 7:22:39.787 Event: 0x8065
Wed 5/24 7:22:39.787 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.788 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.788 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.789 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.789 Event: 0x8065
Wed 5/24 7:22:39.790 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.791 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.792 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.792 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.793 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.794 Event: 0x8065
Wed 5/24 7:22:39.794 Event: 0x8065
Wed 5/24 7:22:39.795 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.795 Event: 0x8065
Wed 5/24 7:22:39.796 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.797 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.797 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.798 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.799 Event: 0x8065
Wed 5/24 7:22:39.799 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.799 Event: 0x8065
Wed 5/24 7:22:39.800 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.801 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.801 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.802 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.802 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.803 Event: 0x8065
Wed 5/24 7:22:39.803 Event: 0x8065
Wed 5/24 7:22:39.804 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.805 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.806 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.807 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.807 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.808 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.809 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.810 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.810 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.811 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.812 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.813 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.813 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.814 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.815 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.816 VF processing job null nPlayin=true
Wed 5/24 7:22:39.816 isRec=true rd=1640 base=154
Wed 5/24 7:22:39.817 VF thread is now waiting for 0:07:21.419
Wed 5/24 7:22:39.936 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.937 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.938 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:39.942 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.943 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.944 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.945 Event: 0x8065
Wed 5/24 7:22:39.945 Event: 0x8065
Wed 5/24 7:22:39.945 Event: 0x8065
Wed 5/24 7:22:39.946 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.946 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.947 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.948 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:39.951 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:39.952 DShowMediaPlayer is consuming the events...
Wed 5/24 7:22:39.952 VF processing job null nPlayin=true
Wed 5/24 7:22:39.953 isRec=true rd=1777 base=269
Wed 5/24 7:22:39.954 VF thread is now waiting for 0:07:21.304
Wed 5/24 7:22:40.252 VMR9 rendering began VRAM free=338690048
Wed 5/24 7:22:42.406 VF processing job null nPlayin=true
Wed 5/24 7:22:42.407 isRec=true rd=4231 base=2696
Wed 5/24 7:22:42.408 VF thread is now waiting for 0:07:18.877
Wed 5/24 7:22:42.705 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:46.375 VF processing job null nPlayin=true
Wed 5/24 7:22:46.376 isRec=true rd=8200 base=6667
Wed 5/24 7:22:46.377 VF thread is now waiting for 0:07:14.907
Wed 5/24 7:22:47.708 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:47.936 VF.submitJob(VFJob[CloseMF r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:47.936 VF processing job VFJob[CloseMF r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:22:47.937 VF processing on UI Thread VFJob[CloseMF r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:47.940 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:47.942 VF logFileWatch doneAir=A[618324,618279,"All Grown Up",11006@0524.07:00,30] theTime=Wed 5/24 7:22:46.403 recTime=Wed 5/24 7:22:38.176
Wed 5/24 7:22:47.943 Stopping the playback graph.
Wed 5/24 7:22:48.037 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:22:48.037 Tearing down playback graph
Wed 5/24 7:22:48.038 NATIVE Deallocating the CPlayerData object
Wed 5/24 7:22:48.048 VMR9 rendering done VRAM free=357564416
Wed 5/24 7:22:48.163 NATIVE Finished destroying the playback graph
Wed 5/24 7:22:48.165 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=false
Wed 5/24 7:22:48.166 VF discarding job VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:22:48.166 VF processing job null nPlayin=false
Wed 5/24 7:22:48.167 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:48.168 VF.submitJob(VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg])
Wed 5/24 7:22:48.169 VF processing job VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg] nPlayin=false
Wed 5/24 7:22:48.170 VF discarding job VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\AllGrownUp-TheBigScore-618324-0.mpg]
Wed 5/24 7:22:48.170 VF processing job null nPlayin=false
Wed 5/24 7:22:48.171 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:48.174 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:48.259 VF processing job null nPlayin=false
Wed 5/24 7:22:48.260 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:48.611 setUI(sage.bz@3534c1[LiveTVGuide w/ Optional Preview]) histIdx=2 uiHistory=[sage.bz@c393a1[Main Menu], sage.bz@2219b4[MediaPlayer OSD], sage.bz@3534c1[LiveTVGuide w/ Optional Preview]]
Wed 5/24 7:22:48.651 setUI(sage.bz@1135cd9[LiveTVGuide w/ Optional Preview]) histIdx=2 uiHistory=[sage.bz@c393a1[Main Menu], sage.bz@2219b4[MediaPlayer OSD], sage.bz@1135cd9[LiveTVGuide w/ Optional Preview]]
Wed 5/24 7:22:49.082 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\guideLeft.png
Wed 5/24 7:22:49.085 ImageUtils creating BI copy sun.awt.image.ToolkitImage@b55c7f
Wed 5/24 7:22:49.086 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:49.087 Creating DirectX9 Texture from memory w=14 h=71
Wed 5/24 7:22:49.088 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\guideRight.png
Wed 5/24 7:22:49.091 ImageUtils creating BI copy sun.awt.image.ToolkitImage@22b29a
Wed 5/24 7:22:49.092 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:49.093 Creating DirectX9 Texture from memory w=15 h=71
Wed 5/24 7:22:49.094 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerFirstRunDot.png
Wed 5/24 7:22:49.096 ImageUtils creating BI copy sun.awt.image.ToolkitImage@aa4c7c
Wed 5/24 7:22:49.097 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:49.098 Creating DirectX9 Texture from memory w=20 h=20
Wed 5/24 7:22:51.607 VF processing job null nPlayin=false
Wed 5/24 7:22:51.608 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:52.711 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:22:53.212 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bolditalic,size=34] numGlyphs=956 numCachedGlyphs=270 numImages=4
Wed 5/24 7:22:53.213 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:53.237 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:53.238 Premultiplying alpha for BuffImage...
Wed 5/24 7:22:53.262 Creating DirectX9 Texture from memory w=256 h=256
Wed 5/24 7:22:54.687 VF processing job null nPlayin=false
Wed 5/24 7:22:54.688 VF thread is now waiting for 0:00:00.000
Wed 5/24 7:22:57.714 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:02.715 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:06.427 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerFirstRun.png
Wed 5/24 7:23:06.446 ImageUtils creating BI copy sun.awt.image.ToolkitImage@668387
Wed 5/24 7:23:06.447 Premultiplying alpha for BuffImage...
Wed 5/24 7:23:06.452 Creating DirectX9 Texture from memory w=121 h=121
Wed 5/24 7:23:07.716 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:09.575 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerWatched.png
Wed 5/24 7:23:09.588 ImageUtils creating BI copy sun.awt.image.ToolkitImage@52d654
Wed 5/24 7:23:09.589 Premultiplying alpha for BuffImage...
Wed 5/24 7:23:09.594 Creating DirectX9 Texture from memory w=121 h=121
Wed 5/24 7:23:12.718 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:17.719 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:22.722 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:27.724 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:32.726 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:35.350 processOptionsMenu optionsMenu=default:null|OptionsMenu:Show Options for an Airing, Recording, File, etc. context=Context[parent=Context[parent=Context[parent=Context[parent=Context[parent=Context[parent=Context[parent=Context[parent=null map={newNumRows=5, newNumCols=3, newFontSize=18}] map={EPGFontSize=18, NumChannelRows=5, FadePastAiringColors=true, ScheduledRecordings=[Lsage.cm;@b08f1, NumericEntry=, NumChannelCols=3, MaxChannel=158, CurrTimeSpan=1148468400000}] map=null] map={IsLastPage=false, NumCols=2, IsLastVPage=false, IsFirstHPage=false, IsFirstVPage=false, IsFirstPage=false, NumRows=99, NumPages=0, IsLastHPage=false}] map={ChanRow=Channel[stationID=10093, Name=FAM, Network=Satellite], TableCol=1, TableRow=63, TimeCol=[Ljava.lang.Long;@781dd4}] map={Airing=A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30]}] map={ChanRow=Channel[stationID=10093, Name=FAM, Network=Satellite], TableCol=1, MarkIRRecordings=true, TableRow=63, TimeCol=[Ljava.lang.Long;@781dd4, Airing=A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30]}] map={AddDetailedInfoOption=true, MediaFile=null, UseBackAfterDelete=false}]
Wed 5/24 7:23:35.453 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDPlay.png
Wed 5/24 7:23:35.454 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1ed7524
Wed 5/24 7:23:35.455 Premultiplying alpha for BuffImage...
Wed 5/24 7:23:35.456 Creating DirectX9 Texture from memory w=30 h=26
Wed 5/24 7:23:35.456 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\OSDRecord.png
Wed 5/24 7:23:35.457 ImageUtils creating BI copy sun.awt.image.ToolkitImage@150ed68
Wed 5/24 7:23:35.458 Premultiplying alpha for BuffImage...
Wed 5/24 7:23:35.459 Creating DirectX9 Texture from memory w=30 h=26
Wed 5/24 7:23:35.459 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerInfo.png
Wed 5/24 7:23:35.465 ImageUtils creating BI copy sun.awt.image.ToolkitImage@17e5307
Wed 5/24 7:23:35.466 Premultiplying alpha for BuffImage...
Wed 5/24 7:23:35.472 Creating DirectX9 Texture from memory w=146 h=146
Wed 5/24 7:23:35.473 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerUnChecked.png
Wed 5/24 7:23:35.477 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1930ebb
Wed 5/24 7:23:35.478 Premultiplying alpha for BuffImage...
Wed 5/24 7:23:35.484 Creating DirectX9 Texture from memory w=155 h=138
Wed 5/24 7:23:35.951 VideoFrame.watch(A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30])
Wed 5/24 7:23:35.952 watchThisFile=null
Wed 5/24 7:23:35.952 Sending requestWatch to server for A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30]
Wed 5/24 7:23:35.955 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:35.957 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:36.273 Received command of:PROPERTY_SYNC 1 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:37.109 VF.submitJob(VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] ifn=null])
Wed 5/24 7:23:37.111 setUI(sage.bz@2219b4[MediaPlayer OSD]) histIdx=3 uiHistory=[sage.bz@c393a1[Main Menu], sage.bz@2219b4[MediaPlayer OSD], sage.bz@1135cd9[LiveTVGuide w/ Optional Preview], sage.bz@2219b4[MediaPlayer OSD]]
Wed 5/24 7:23:37.111 VF processing job VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:23:37.117 VF processing on UI Thread VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:23:37.118 VF digital TV playback detected: false
Wed 5/24 7:23:37.119 VideoFrame creating new media player for file:MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]]
Wed 5/24 7:23:37.120 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:23:37.121 VF network encoder playback detected: false
Wed 5/24 7:23:37.130 VF waiting for data to appear in new file...liveWait=-1153
Wed 5/24 7:23:37.131 VF thread is now waiting for 0:00:00.200
Wed 5/24 7:23:37.331 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:23:37.332 VF network encoder playback detected: false
Wed 5/24 7:23:37.338 VF processing on UI Thread VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:23:37.339 VF file=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] targetTime = Wed 5/24 7:23:35.968
Wed 5/24 7:23:37.339 VideoFrame.timeSelected(Wed 5/24 7:23:35.968, true) currFile=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]]
Wed 5/24 7:23:37.343 DShowPlayer setVideoRendererFilter0({51B4ABF3-748F-4E3B-A276-C828330E926A}) called
Wed 5/24 7:23:37.365 Setting up VMR9 deinterlacing
Wed 5/24 7:23:37.365 Curr Mix Prefs=0x1015
Wed 5/24 7:23:37.366 Set to 0x2015, hr=0x0, New Mix Prefs=0x2015
Wed 5/24 7:23:37.367 DShowPlayer setVideoDecoderFilter0(NVIDIA Video Decoder) called
Wed 5/24 7:23:37.416 DShowPlayer setAudioDecoderFilter0(Sonic Cinemaster@ MCE Audio Decoder) called
Wed 5/24 7:23:37.443 DShowPlayer setTimeshift=1 buffer=0
Wed 5/24 7:23:37.444 NATIVE Loading the source file
Wed 5/24 7:23:37.459 NATIVE Setting up the MPEG demux
Wed 5/24 7:23:37.465 NATIVE RenderAudio called
Wed 5/24 7:23:37.465 NATIVE RenderAudio step 1
Wed 5/24 7:23:37.465 NATIVE RenderAudio step 2
Wed 5/24 7:23:37.466 NATIVE RenderAudio step 3
Wed 5/24 7:23:37.466 NATIVE RenderAudio step 4
Wed 5/24 7:23:37.500 NATIVE RenderVideo called
Wed 5/24 7:23:37.501 NATIVE RenderVideo step 1
Wed 5/24 7:23:37.502 NATIVE RenderVideo step 2
Wed 5/24 7:23:37.502 Video source pin information:
Wed 5/24 7:23:37.503 PIN is not connected yet!Wed 5/24 7:23:37.503 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.503 Interlaced video
Wed 5/24 7:23:37.504 Both fields per sample
Wed 5/24 7:23:37.504 Field 2 first
Wed 5/24 7:23:37.504 Stream never contains a Field 2
Wed 5/24 7:23:37.504 Either bob or weave mode.
Wed 5/24 7:23:37.504 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.505 Interlaced video
Wed 5/24 7:23:37.505 Both fields per sample
Wed 5/24 7:23:37.505 Field 2 first
Wed 5/24 7:23:37.505 Stream never contains a Field 2
Wed 5/24 7:23:37.506 Either bob or weave mode.
Wed 5/24 7:23:37.506 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.506 Interlaced video
Wed 5/24 7:23:37.506 Both fields per sample
Wed 5/24 7:23:37.507 Field 2 first
Wed 5/24 7:23:37.507 Stream never contains a Field 2
Wed 5/24 7:23:37.507 Either bob or weave mode.
Wed 5/24 7:23:37.507 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.508 Interlaced video
Wed 5/24 7:23:37.508 Both fields per sample
Wed 5/24 7:23:37.508 Field 2 first
Wed 5/24 7:23:37.508 Stream never contains a Field 2
Wed 5/24 7:23:37.508 Either bob or weave mode.
Wed 5/24 7:23:37.509 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.509 Interlaced video
Wed 5/24 7:23:37.509 Both fields per sample
Wed 5/24 7:23:37.509 Field 2 first
Wed 5/24 7:23:37.510 Stream never contains a Field 2
Wed 5/24 7:23:37.510 Either bob or weave mode.
Wed 5/24 7:23:37.510 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.510 Interlaced video
Wed 5/24 7:23:37.511 Both fields per sample
Wed 5/24 7:23:37.511 Field 2 first
Wed 5/24 7:23:37.511 Stream never contains a Field 2
Wed 5/24 7:23:37.511 Either bob or weave mode.
Wed 5/24 7:23:37.512 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.512 Interlaced video
Wed 5/24 7:23:37.512 Both fields per sample
Wed 5/24 7:23:37.512 Field 2 first
Wed 5/24 7:23:37.512 Stream never contains a Field 2
Wed 5/24 7:23:37.513 Either bob or weave mode.
Wed 5/24 7:23:37.513 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.513 Interlaced video
Wed 5/24 7:23:37.513 Both fields per sample
Wed 5/24 7:23:37.514 Field 2 first
Wed 5/24 7:23:37.514 Stream never contains a Field 2
Wed 5/24 7:23:37.514 Either bob or weave mode.
Wed 5/24 7:23:37.514 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YUY2 F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.515 Interlaced video
Wed 5/24 7:23:37.515 Both fields per sample
Wed 5/24 7:23:37.515 Field 2 first
Wed 5/24 7:23:37.515 Stream never contains a Field 2
Wed 5/24 7:23:37.515 Either bob or weave mode.
Wed 5/24 7:23:37.516 M type MEDIATYPE_Video  S type MEDIASUBTYPE_UYVY F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.516 Interlaced video
Wed 5/24 7:23:37.516 Both fields per sample
Wed 5/24 7:23:37.516 Field 2 first
Wed 5/24 7:23:37.517 Stream never contains a Field 2
Wed 5/24 7:23:37.517 Either bob or weave mode.
Wed 5/24 7:23:37.517 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YV12 F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.517 Interlaced video
Wed 5/24 7:23:37.518 Both fields per sample
Wed 5/24 7:23:37.518 Field 2 first
Wed 5/24 7:23:37.518 Stream never contains a Field 2
Wed 5/24 7:23:37.518 Either bob or weave mode.
Wed 5/24 7:23:37.518 NATIVE RenderVideo step 3
Wed 5/24 7:23:37.629 VMR9 alloc 720x540 Offscreen DefaultPool  format=NV12 minBuffs=1 arx=4 ary=3 nativeWidth=720 nativeHeight=540 reqNumBuff=1 allocNumBuff=1 hr=0x0
Wed 5/24 7:23:37.636 Setting up VMR9 deinterlacing
Wed 5/24 7:23:37.638 VM9Deinterlacing Tech: PixelAdaptive
Wed 5/24 7:23:37.638 VM9Deinterlacing Tech: BOBVerticalStretch
Wed 5/24 7:23:37.639 Actual deinterlace: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:23:37.639 deinterlace mode: hr=0x1 guid={00000000-0000-0000-0000-000000000000}
Wed 5/24 7:23:37.639 Setting deinterlace mode to actual mode...
Wed 5/24 7:23:37.639 deinterlace mode: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:23:37.640 Filter Graph Video Renderer Info:
Wed 5/24 7:23:37.640 Video Renderer:CLSID_VideoMixingRenderer9
Wed 5/24 7:23:37.640 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:23:37.640 Interlaced video
Wed 5/24 7:23:37.641 Both fields per sample
Wed 5/24 7:23:37.641 Field 2 first
Wed 5/24 7:23:37.641 Stream never contains a Field 2
Wed 5/24 7:23:37.641 Either bob or weave mode.
Wed 5/24 7:23:37.642 VMR9 filter detected, using line 21 decoder 2.Wed 5/24 7:23:37.645 DShowGraphFilters=Default DirectSound Device,VidRend,Line21 Decoder,AC3Filter,Video Decoder,Audio Decoder,SageTV MPEG2 Demultiplexer,E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg,
Wed 5/24 7:23:37.646 VideoFrame.timeSelected2(Wed 5/24 7:23:35.968, true) currFile=MediaFile[id=688672 A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg, Seg0[Wed 5/24 7:23:35.968-Wed 12/31 19:00:00.000]] realDur=0
Wed 5/24 7:23:37.647 About to perform media time selection for 0
Wed 5/24 7:23:37.647 Running the playback graph.
Wed 5/24 7:23:37.648 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.664 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.671 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.675 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.675 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.676 Event: 0xd
Wed 5/24 7:23:37.676 Event: 0xe
Wed 5/24 7:23:37.677 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.679 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.679 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.682 VF processing job null nPlayin=true
Wed 5/24 7:23:37.683 isRec=true rd=1715 base=10
Wed 5/24 7:23:37.684 VF thread is now waiting for 0:06:23.772
Wed 5/24 7:23:37.727 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:37.788 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.791 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.792 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.793 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.793 Event: 0x8065
Wed 5/24 7:23:37.794 VF processing job null nPlayin=true
Wed 5/24 7:23:37.794 isRec=true rd=1826 base=125
Wed 5/24 7:23:37.795 VF thread is now waiting for 0:06:23.657
Wed 5/24 7:23:37.796 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.797 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.798 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.799 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.799 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.800 Event: 0x8065
Wed 5/24 7:23:37.800 Event: 0x8065
Wed 5/24 7:23:37.801 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.801 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.802 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.803 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.803 Event: 0x8065
Wed 5/24 7:23:37.804 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.804 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.805 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.806 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.806 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.807 Event: 0x8065
Wed 5/24 7:23:37.810 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.811 Event: 0x8065
Wed 5/24 7:23:37.811 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.811 Event: 0x8065
Wed 5/24 7:23:37.812 Event: 0x8065
Wed 5/24 7:23:37.812 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.813 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.814 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.815 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.816 Event: 0x8065
Wed 5/24 7:23:37.816 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.817 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.817 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.818 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.819 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.819 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.820 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.821 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.821 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.822 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.823 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.823 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.824 VF processing job null nPlayin=true
Wed 5/24 7:23:37.824 isRec=true rd=1856 base=154
Wed 5/24 7:23:37.825 VF thread is now waiting for 0:06:23.627
Wed 5/24 7:23:37.890 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.891 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.893 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.894 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.894 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.895 Event: 0x8065
Wed 5/24 7:23:37.895 Event: 0x8065
Wed 5/24 7:23:37.896 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.901 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.903 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.904 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.904 Event: 0x8065
Wed 5/24 7:23:37.905 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.906 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.907 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.908 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.909 Event: 0x8065
Wed 5/24 7:23:37.909 Event: 0x8065
Wed 5/24 7:23:37.909 VF processing job null nPlayin=true
Wed 5/24 7:23:37.910 isRec=true rd=1942 base=223
Wed 5/24 7:23:37.911 VF thread is now waiting for 0:06:23.559
Wed 5/24 7:23:37.911 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:23:37.912 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.912 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.913 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.914 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:23:37.914 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:23:37.915 DShowMediaPlayer is consuming the events...
Wed 5/24 7:23:37.915 VF processing job null nPlayin=true
Wed 5/24 7:23:37.916 isRec=true rd=1948 base=223
Wed 5/24 7:23:37.917 VF thread is now waiting for 0:06:23.559
Wed 5/24 7:23:38.378 VMR9 rendering began VRAM free=337641472
Wed 5/24 7:23:41.195 VF processing job null nPlayin=true
Wed 5/24 7:23:41.196 isRec=true rd=5228 base=3369
Wed 5/24 7:23:41.196 VF thread is now waiting for 0:06:20.413
Wed 5/24 7:23:41.336 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:42.729 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:47.731 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:52.732 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:23:57.734 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:02.735 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:07.737 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:12.738 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:17.741 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:22.742 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:27.744 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:32.747 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:37.748 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:42.750 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:47.752 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:52.753 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:24:57.755 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:02.756 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:07.758 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:12.759 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:17.761 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:22.762 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:27.763 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:32.765 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:37.766 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:42.768 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:47.770 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:52.771 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:25:57.773 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:02.774 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:07.776 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:12.777 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:17.780 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:22.781 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:27.782 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:32.784 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:37.785 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:42.788 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:47.789 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:52.791 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:26:57.792 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:02.793 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:07.795 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:12.796 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:17.798 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:22.799 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:27.801 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:32.802 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:37.803 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:42.805 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:47.807 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:52.809 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:27:57.811 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:02.813 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:07.815 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:12.817 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:17.819 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:22.820 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:27.822 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:32.722 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:37.723 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:41.345 VF processing job null nPlayin=true
Wed 5/24 7:28:41.348 isRec=true rd=305380 base=303484
Wed 5/24 7:28:41.349 VF thread is now waiting for 0:01:20.297
Wed 5/24 7:28:42.725 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:47.726 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:52.728 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:28:57.729 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:02.732 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:07.733 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:12.735 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:17.737 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:22.739 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:27.741 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:32.742 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:37.744 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:42.746 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:47.749 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:52.751 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:29:57.753 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:00.011 VF.submitJob(VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg])
Wed 5/24 7:30:00.012 VF processing job VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg] nPlayin=true
Wed 5/24 7:30:00.012 VF processing on UI Thread VFJob[InactiveFile r=0.0 t=0 file=null ifn=E:\media\TV\KongTheAnimatedSeries-PrimalPower-617576-0.mpg]
Wed 5/24 7:30:00.013 VF notified of Inactive File
Wed 5/24 7:30:00.014 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:00.014 VF processing job null nPlayin=true
Wed 5/24 7:30:00.015 isRec=false rd=384055 base=382082
Wed 5/24 7:30:00.015 VF thread is now waiting for 0:00:01.722
Wed 5/24 7:30:00.017 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:00.019 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:00.446 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:00.447 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:00.447 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:00.447 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:00.448 Event: 0x8065
Wed 5/24 7:30:00.448 VF processing job null nPlayin=true
Wed 5/24 7:30:00.449 isRec=false rd=384055 base=382515
Wed 5/24 7:30:00.449 VF thread is now waiting for 0:00:01.290
Wed 5/24 7:30:00.490 Received command of:PROPERTY_SYNC 1 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:00.497 VF processing job null nPlayin=true
Wed 5/24 7:30:00.498 isRec=false rd=384055 base=382564
Wed 5/24 7:30:00.498 VF thread is now waiting for 0:00:01.240
Wed 5/24 7:30:01.739 VF processing job null nPlayin=true
Wed 5/24 7:30:01.740 isRec=false rd=384055 base=383806
Wed 5/24 7:30:01.741 VideoFrame watching a live old airing, fixing it.
Wed 5/24 7:30:01.743 watchMe=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]]
Wed 5/24 7:30:01.743 Sending requestWatch to server for A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30]
Wed 5/24 7:30:01.746 VF processing job VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=true
Wed 5/24 7:30:01.748 VF processing on UI Thread VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:30:01.750 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:01.752 VF logFileWatch doneAir=A[617576,617531,"Kong: The Animated Series",10093@0524.07:00,30] theTime=Wed 5/24 7:29:59.783 recTime=Wed 5/24 7:23:35.968
Wed 5/24 7:30:01.753 Stopping the playback graph.
Wed 5/24 7:30:01.788 VF digital TV playback detected: false
Wed 5/24 7:30:01.788 VIDEOFRAME Needs to do A FULL SWITCH on the file due to ENCODING CHANGE
Wed 5/24 7:30:01.789 Tearing down playback graph
Wed 5/24 7:30:01.789 NATIVE Deallocating the CPlayerData object
Wed 5/24 7:30:01.801 VMR9 rendering done VRAM free=357564416
Wed 5/24 7:30:01.808 NATIVE Finished destroying the playback graph
Wed 5/24 7:30:01.809 VideoFrame creating new media player for file:MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]]
Wed 5/24 7:30:01.811 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]] ifn=null] nPlayin=false
Wed 5/24 7:30:01.811 VF network encoder playback detected: false
Wed 5/24 7:30:01.834 VF processing on UI Thread VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]] ifn=null]
Wed 5/24 7:30:01.835 VF file=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]] targetTime = Wed 5/24 7:30:00.029
Wed 5/24 7:30:01.836 VideoFrame.timeSelected(Wed 5/24 7:30:00.029, true) currFile=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]]
Wed 5/24 7:30:01.837 DShowPlayer setVideoRendererFilter0({51B4ABF3-748F-4E3B-A276-C828330E926A}) called
Wed 5/24 7:30:01.855 Setting up VMR9 deinterlacing
Wed 5/24 7:30:01.856 Curr Mix Prefs=0x1015
Wed 5/24 7:30:01.856 Set to 0x2015, hr=0x0, New Mix Prefs=0x2015
Wed 5/24 7:30:01.856 DShowPlayer setVideoDecoderFilter0(NVIDIA Video Decoder) called
Wed 5/24 7:30:01.905 DShowPlayer setAudioDecoderFilter0(Sonic Cinemaster@ MCE Audio Decoder) called
Wed 5/24 7:30:01.930 DShowPlayer setTimeshift=1 buffer=0
Wed 5/24 7:30:01.930 NATIVE Loading the source file
Wed 5/24 7:30:01.933 NATIVE Setting up the MPEG demux
Wed 5/24 7:30:01.935 NATIVE RenderAudio called
Wed 5/24 7:30:01.936 NATIVE RenderAudio step 1
Wed 5/24 7:30:01.936 NATIVE RenderAudio step 2
Wed 5/24 7:30:01.936 NATIVE RenderAudio step 3
Wed 5/24 7:30:01.936 NATIVE RenderAudio step 4
Wed 5/24 7:30:01.963 NATIVE RenderVideo called
Wed 5/24 7:30:01.963 NATIVE RenderVideo step 1
Wed 5/24 7:30:01.964 NATIVE RenderVideo step 2
Wed 5/24 7:30:01.965 Video source pin information:
Wed 5/24 7:30:01.965 PIN is not connected yet!Wed 5/24 7:30:01.965 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.965 Interlaced video
Wed 5/24 7:30:01.966 Both fields per sample
Wed 5/24 7:30:01.966 Field 2 first
Wed 5/24 7:30:01.966 Stream never contains a Field 2
Wed 5/24 7:30:01.966 Either bob or weave mode.
Wed 5/24 7:30:01.966 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.967 Interlaced video
Wed 5/24 7:30:01.967 Both fields per sample
Wed 5/24 7:30:01.967 Field 2 first
Wed 5/24 7:30:01.967 Stream never contains a Field 2
Wed 5/24 7:30:01.968 Either bob or weave mode.
Wed 5/24 7:30:01.968 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.968 Interlaced video
Wed 5/24 7:30:01.968 Both fields per sample
Wed 5/24 7:30:01.968 Field 2 first
Wed 5/24 7:30:01.969 Stream never contains a Field 2
Wed 5/24 7:30:01.969 Either bob or weave mode.
Wed 5/24 7:30:01.969 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.969 Interlaced video
Wed 5/24 7:30:01.969 Both fields per sample
Wed 5/24 7:30:01.970 Field 2 first
Wed 5/24 7:30:01.970 Stream never contains a Field 2
Wed 5/24 7:30:01.970 Either bob or weave mode.
Wed 5/24 7:30:01.970 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.970 Interlaced video
Wed 5/24 7:30:01.971 Both fields per sample
Wed 5/24 7:30:01.971 Field 2 first
Wed 5/24 7:30:01.971 Stream never contains a Field 2
Wed 5/24 7:30:01.971 Either bob or weave mode.
Wed 5/24 7:30:01.971 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.972 Interlaced video
Wed 5/24 7:30:01.972 Both fields per sample
Wed 5/24 7:30:01.972 Field 2 first
Wed 5/24 7:30:01.972 Stream never contains a Field 2
Wed 5/24 7:30:01.973 Either bob or weave mode.
Wed 5/24 7:30:01.973 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.973 Interlaced video
Wed 5/24 7:30:01.973 Both fields per sample
Wed 5/24 7:30:01.973 Field 2 first
Wed 5/24 7:30:01.974 Stream never contains a Field 2
Wed 5/24 7:30:01.974 Either bob or weave mode.
Wed 5/24 7:30:01.974 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.974 Interlaced video
Wed 5/24 7:30:01.974 Both fields per sample
Wed 5/24 7:30:01.975 Field 2 first
Wed 5/24 7:30:01.975 Stream never contains a Field 2
Wed 5/24 7:30:01.975 Either bob or weave mode.
Wed 5/24 7:30:01.975 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YUY2 F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.975 Interlaced video
Wed 5/24 7:30:01.976 Both fields per sample
Wed 5/24 7:30:01.976 Field 2 first
Wed 5/24 7:30:01.976 Stream never contains a Field 2
Wed 5/24 7:30:01.976 Either bob or weave mode.
Wed 5/24 7:30:01.976 M type MEDIATYPE_Video  S type MEDIASUBTYPE_UYVY F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.977 Interlaced video
Wed 5/24 7:30:01.977 Both fields per sample
Wed 5/24 7:30:01.977 Field 2 first
Wed 5/24 7:30:01.977 Stream never contains a Field 2
Wed 5/24 7:30:01.977 Either bob or weave mode.
Wed 5/24 7:30:01.978 M type MEDIATYPE_Video  S type MEDIASUBTYPE_YV12 F type FORMAT_VideoInfo2
Wed 5/24 7:30:01.978 Interlaced video
Wed 5/24 7:30:01.978 Both fields per sample
Wed 5/24 7:30:01.978 Field 2 first
Wed 5/24 7:30:01.978 Stream never contains a Field 2
Wed 5/24 7:30:01.979 Either bob or weave mode.
Wed 5/24 7:30:01.979 NATIVE RenderVideo step 3
Wed 5/24 7:30:02.051 VMR9 alloc 720x540 Offscreen DefaultPool  format=NV12 minBuffs=1 arx=4 ary=3 nativeWidth=720 nativeHeight=540 reqNumBuff=1 allocNumBuff=1 hr=0x0
Wed 5/24 7:30:02.060 Setting up VMR9 deinterlacing
Wed 5/24 7:30:02.060 VM9Deinterlacing Tech: PixelAdaptive
Wed 5/24 7:30:02.061 VM9Deinterlacing Tech: BOBVerticalStretch
Wed 5/24 7:30:02.061 Actual deinterlace: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:30:02.061 deinterlace mode: hr=0x1 guid={00000000-0000-0000-0000-000000000000}
Wed 5/24 7:30:02.061 Setting deinterlace mode to actual mode...
Wed 5/24 7:30:02.062 deinterlace mode: hr=0x0 guid={212DC724-3235-44A4-BD29-E1652BBCC71C}
Wed 5/24 7:30:02.062 Filter Graph Video Renderer Info:
Wed 5/24 7:30:02.062 Video Renderer:CLSID_VideoMixingRenderer9
Wed 5/24 7:30:02.063 M type MEDIATYPE_Video  S type Unknown GUID Name F type FORMAT_VideoInfo2
Wed 5/24 7:30:02.063 Interlaced video
Wed 5/24 7:30:02.063 Both fields per sample
Wed 5/24 7:30:02.063 Field 2 first
Wed 5/24 7:30:02.063 Stream never contains a Field 2
Wed 5/24 7:30:02.064 Either bob or weave mode.
Wed 5/24 7:30:02.064 VMR9 filter detected, using line 21 decoder 2.Wed 5/24 7:30:02.065 DShowGraphFilters=Default DirectSound Device,VidRend,Line21 Decoder,AC3Filter,Video Decoder,Audio Decoder,SageTV MPEG2 Demultiplexer,E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg,
Wed 5/24 7:30:02.066 VideoFrame.timeSelected2(Wed 5/24 7:30:00.029, true) currFile=MediaFile[id=688673 A[617579,617535,"Spider-Man and His Amazing Friends",10093@0524.07:30,30] host=mediaserver encodedBy=Hauppauge WinTV PVR PCI II Capture #3 Best E:\media\TV\SpiderManandHisAmazingFriends-VengeanceofLoki-617579-0.mpg, Seg0[Wed 5/24 7:30:00.029-Wed 12/31 19:00:00.000]] realDur=0
Wed 5/24 7:30:02.067 About to perform media time selection for 0
Wed 5/24 7:30:02.067 Running the playback graph.
Wed 5/24 7:30:02.068 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.081 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.086 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.099 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.100 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.101 Event: 0xd
Wed 5/24 7:30:02.101 Event: 0xe
Wed 5/24 7:30:02.101 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.102 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.103 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.104 VF processing job null nPlayin=true
Wed 5/24 7:30:02.115 isRec=true rd=2086 base=22
Wed 5/24 7:30:02.116 VF thread is now waiting for 0:29:59.699
Wed 5/24 7:30:02.185 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.185 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.187 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.187 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.188 Event: 0x8065
Wed 5/24 7:30:02.188 VF processing job null nPlayin=true
Wed 5/24 7:30:02.189 isRec=true rd=2160 base=66
Wed 5/24 7:30:02.189 VF thread is now waiting for 0:29:59.655
Wed 5/24 7:30:02.192 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.193 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.193 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.194 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.195 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.195 Event: 0x8065
Wed 5/24 7:30:02.195 Event: 0x8065
Wed 5/24 7:30:02.196 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.196 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.197 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.198 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.198 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.199 Event: 0x8065
Wed 5/24 7:30:02.199 Event: 0x8065
Wed 5/24 7:30:02.199 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.200 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.201 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.201 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.202 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.203 Event: 0x8065
Wed 5/24 7:30:02.203 Event: 0x8065
Wed 5/24 7:30:02.203 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.204 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.205 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.206 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.206 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.207 Event: 0x8065
Wed 5/24 7:30:02.207 Event: 0x8065
Wed 5/24 7:30:02.207 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.208 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.209 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.209 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.210 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.210 Event: 0x8065
Wed 5/24 7:30:02.211 Event: 0x8065
Wed 5/24 7:30:02.211 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.212 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.212 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.213 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.214 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.214 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.215 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.216 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.216 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.217 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.217 Event: 0x8065
Wed 5/24 7:30:02.218 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.219 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.219 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.220 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.220 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null])
Wed 5/24 7:30:02.221 Event: 0x8065
Wed 5/24 7:30:02.221 Event: 0x8065
Wed 5/24 7:30:02.222 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.222 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.223 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.224 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.224 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.225 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.226 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.226 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.227 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.228 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true
Wed 5/24 7:30:02.228 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null]
Wed 5/24 7:30:02.229 DShowMediaPlayer is consuming the events...
Wed 5/24 7:30:02.230 VF processing job null nPlayin=true
Wed 5/24 7:30:02.230 isRec=true rd=2201 base=107
Wed 5/24 7:30:02.231 VF thread is now waiting for 0:29:59.613
Wed 5/24 7:30:02.683 VMR9 rendering began VRAM free=337641472
Wed 5/24 7:30:02.756 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:04.039 VF processing job null nPlayin=true
Wed 5/24 7:30:04.039 isRec=true rd=4010 base=1916
Wed 5/24 7:30:04.040 VF thread is now waiting for 0:29:57.804
Wed 5/24 7:30:04.163 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:07.226 VF processing job null nPlayin=true
Wed 5/24 7:30:07.227 isRec=true rd=7198 base=5104
Wed 5/24 7:30:07.228 VF thread is now waiting for 0:29:54.616
Wed 5/24 7:30:07.758 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:12.759 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:17.761 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:22.762 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:27.764 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:32.765 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:37.768 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:42.770 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:47.772 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:52.774 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:30:57.775 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:02.778 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:07.780 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:12.781 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:17.783 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:22.785 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:27.787 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:32.788 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:37.790 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:42.791 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:47.793 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:52.795 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:31:57.796 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:02.799 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:07.809 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:12.811 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:17.814 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:22.815 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:27.817 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:32.818 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:37.819 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:42.821 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:47.822 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:52.825 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:32:57.826 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:02.828 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:07.829 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:12.831 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:17.833 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:22.834 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:27.836 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:32.837 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:37.839 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:42.840 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:47.842 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:52.845 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:33:57.846 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:02.848 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:07.850 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:12.851 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:17.853 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:22.855 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:27.756 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:32.757 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:37.760 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:42.761 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:47.762 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:52.764 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:34:57.765 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:02.767 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:07.347 VF processing job null nPlayin=true
Wed 5/24 7:35:07.348 isRec=true rd=307319 base=305372
Wed 5/24 7:35:07.348 VF thread is now waiting for 0:24:54.348
Wed 5/24 7:35:07.768 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:12.770 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:17.771 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:22.773 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:27.775 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:32.776 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:37.779 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:42.780 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:47.782 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:52.783 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:35:57.784 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:02.786 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:07.787 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:12.789 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:17.790 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:22.792 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:27.793 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:32.794 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:37.797 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:42.798 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:47.800 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:52.801 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:36:57.803 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:02.804 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:07.805 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:12.807 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:17.808 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:22.810 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:27.811 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:32.813 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:37.814 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:42.815 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:47.817 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:52.818 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:37:57.820 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:02.821 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:07.824 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:12.825 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:17.827 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:22.829 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:27.830 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:32.832 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:37.835 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:42.836 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:47.838 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:52.839 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:38:57.841 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:02.843 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:07.846 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:12.847 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:17.848 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:22.850 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:27.851 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:32.853 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:37.855 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:42.858 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:47.859 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:52.860 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:39:57.862 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:02.864 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:07.597 VF processing job null nPlayin=true
Wed 5/24 7:40:07.604 isRec=true rd=607575 base=605674
Wed 5/24 7:40:07.605 VF thread is now waiting for 0:19:54.046
Wed 5/24 7:40:07.866 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:12.868 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:17.768 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:22.771 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:27.772 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:32.774 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:37.775 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:42.776 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:47.779 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:52.781 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:40:57.783 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:02.784 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:07.786 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:12.788 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:17.789 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:22.791 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:27.792 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:32.794 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:37.795 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:42.797 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:47.798 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:52.801 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:41:57.803 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:02.804 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:07.806 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:12.807 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:17.809 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:22.810 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:27.811 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:32.813 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:37.814 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:42.816 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:47.817 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:52.820 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:42:57.822 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:02.823 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:07.825 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:12.826 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:17.828 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:22.830 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:27.831 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:32.833 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:37.835 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:42.837 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:47.838 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:52.840 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:43:57.842 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:02.843 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:07.845 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:12.847 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:17.849 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:22.850 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:27.852 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:32.853 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:37.855 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:42.857 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:47.859 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:52.861 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:44:57.862 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:02.864 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:07.724 VF processing job null nPlayin=true
Wed 5/24 7:45:07.724 isRec=true rd=907695 base=905942
Wed 5/24 7:45:07.725 VF thread is now waiting for 0:14:53.779
Wed 5/24 7:45:07.865 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:12.868 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:17.870 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:22.871 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:27.873 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:32.874 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:37.875 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:42.877 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:47.878 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:52.880 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:45:57.881 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:02.883 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:07.884 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:12.786 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:17.788 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:22.790 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:27.792 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:32.793 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:37.795 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:42.796 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:47.797 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:52.799 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:46:57.800 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:02.802 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:07.803 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:12.805 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:17.806 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:22.807 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:27.809 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:32.810 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:37.813 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:42.814 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:47.816 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:52.817 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:47:57.819 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:02.821 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:07.822 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:12.824 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:17.826 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:22.829 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:27.830 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:32.832 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:37.834 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:42.835 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:47.837 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:52.838 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:48:57.840 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:02.841 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:07.842 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:12.845 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:17.847 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:22.849 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:27.850 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:32.852 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:37.853 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:42.854 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:47.856 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:52.857 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:49:57.859 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:02.861 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:07.118 Screen Saver Timeout expired....tv=true playin=true fs=true sleepy=false currSS=false
Wed 5/24 7:50:07.848 VF processing job null nPlayin=true
Wed 5/24 7:50:07.851 isRec=true rd=1207822 base=1206216
Wed 5/24 7:50:07.852 VF thread is now waiting for 0:09:53.505
Wed 5/24 7:50:07.863 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:12.864 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:17.865 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:22.868 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:27.869 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:32.872 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:37.875 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:42.876 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:47.879 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:52.880 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:50:57.882 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:02.884 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:07.886 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:12.888 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:17.891 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:22.893 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:27.894 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:32.896 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:37.897 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:42.900 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:47.902 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:52.903 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:51:57.905 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:02.906 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:07.806 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:12.808 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:17.809 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:22.812 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:27.813 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:32.815 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:37.816 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:42.817 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:47.819 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:52.822 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:52:57.824 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:02.826 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:07.828 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:12.829 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:17.830 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:22.832 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:27.833 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:32.835 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:37.837 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:42.839 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:47.840 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:52.842 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:53:57.844 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:02.846 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:07.848 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:12.849 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:17.850 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:22.852 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:27.853 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:32.855 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:37.857 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:42.859 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:47.860 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:52.862 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:54:57.863 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:02.865 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:07.867 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:07.965 VF processing job null nPlayin=true
Wed 5/24 7:55:07.966 isRec=true rd=1507937 base=1506478
Wed 5/24 7:55:07.967 VF thread is now waiting for 0:04:53.242
Wed 5/24 7:55:12.868 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:17.870 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:22.871 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:27.872 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:32.874 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:37.875 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:42.877 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:47.878 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:52.880 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:55:57.881 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:02.884 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:07.886 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:12.888 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:17.890 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:22.891 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:27.894 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:32.895 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:37.897 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:42.899 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:47.900 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:52.902 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:56:57.903 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:02.905 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:07.906 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:12.908 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:17.910 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:22.912 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:27.914 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:32.916 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:37.918 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:42.920 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:47.922 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:52.924 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]
Wed 5/24 7:57:57.825 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1036]