Tue 5/23 17:59:49.438 user.dir2=C:\Program Files\SageTV\SageTV Tue 5/23 17:59:49.441 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\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_autoaspect.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 Tue 5/23 17:59:49.442 JVM version=1.5.0_05 Tue 5/23 17:59:49.442 OS=Windows XP 5.1 Tue 5/23 17:59:49.443 Succesfully setup system shell hook Tue 5/23 17:59:49.444 not specifiy WinkeyboardHook in registery, load default one Tue 5/23 17:59:50.632 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/splash.gif Tue 5/23 17:59:50.748 ImageUtils creating BI copy sun.awt.image.ToolkitImage@b4d3d5 Tue 5/23 17:59:50.802 SageTV V5.0.2.90 Tue 5/23 17:59:50.826 hostname=hammer Tue 5/23 17:59:50.902 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon.gif Tue 5/23 17:59:50.905 ImageUtils creating BI copy sun.awt.image.ToolkitImage@85af80 Tue 5/23 17:59:50.991 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim0.gif Tue 5/23 17:59:50.992 ImageUtils creating BI copy sun.awt.image.ToolkitImage@2a340e Tue 5/23 17:59:50.993 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim1.gif Tue 5/23 17:59:50.994 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1050169 Tue 5/23 17:59:50.996 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim2.gif Tue 5/23 17:59:50.997 ImageUtils creating BI copy sun.awt.image.ToolkitImage@9fef6f Tue 5/23 17:59:50.998 ImageUtils loading URL jar:file:/C:/Program%20Files/SageTV/SageTV/Sage.jar!/images/tvicon_anim3.gif Tue 5/23 17:59:51.000 ImageUtils creating BI copy sun.awt.image.ToolkitImage@17172ea Tue 5/23 17:59:51.063 Wizard starting to load database info... Tue 5/23 17:59:51.064 Wizard DONE loading database info. loadTime=0.0020 sec Tue 5/23 17:59:52.138 Error establishing server connection of:java.net.ConnectException: Connection refused: connect Tue 5/23 17:59:52.141 NetworkClient fullCleanup null Tue 5/23 17:59:55.638 Error establishing server connection of:java.net.ConnectException: Connection refused: connect Tue 5/23 17:59:55.640 NetworkClient fullCleanup null Tue 5/23 17:59:59.138 Error establishing server connection of:java.net.ConnectException: Connection refused: connect Tue 5/23 17:59:59.141 NetworkClient fullCleanup null Tue 5/23 18:00:02.687 SageTV received connection from:Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:03.487 Received command of:PROPERTY_SYNC 396 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:03.582 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:03.583 Wizard allocating table for Year of size 100 Tue 5/23 18:00:03.583 Wizard loading main index for Year Tue 5/23 18:00:03.584 Wizard allocating table for Network of size 29 Tue 5/23 18:00:03.584 Wizard loading main index for Network Tue 5/23 18:00:03.585 Wizard allocating table for Title of size 4477 Tue 5/23 18:00:03.585 Wizard loading main index for Title Tue 5/23 18:00:03.645 Wizard building alt. index 0 for Title Tue 5/23 18:00:03.652 Wizard allocating table for Channel of size 365 Tue 5/23 18:00:03.653 Wizard loading main index for Channel Tue 5/23 18:00:03.662 Wizard allocating table for People of size 22841 Tue 5/23 18:00:03.663 Wizard loading main index for People Tue 5/23 18:00:03.859 Wizard building alt. index 0 for People Tue 5/23 18:00:03.892 Wizard allocating table for SubCategory of size 120 Tue 5/23 18:00:03.892 Wizard loading main index for SubCategory Tue 5/23 18:00:03.893 Wizard allocating table for Rated of size 7 Tue 5/23 18:00:03.894 Wizard loading main index for Rated Tue 5/23 18:00:03.894 Wizard allocating table for ParentalRating of size 0 Tue 5/23 18:00:03.894 Wizard allocating table for ExtendedRating of size 10 Tue 5/23 18:00:03.895 Wizard loading main index for ExtendedRating Tue 5/23 18:00:03.895 Wizard allocating table for Category of size 79 Tue 5/23 18:00:03.895 Wizard loading main index for Category Tue 5/23 18:00:03.897 Wizard allocating table for PrimeTitle of size 0 Tue 5/23 18:00:03.897 Wizard allocating table for Bonus of size 540 Tue 5/23 18:00:03.897 Wizard loading main index for Bonus Tue 5/23 18:00:03.903 Wizard allocating table for Show of size 16313 Tue 5/23 18:00:03.904 Wizard loading main index for Show Tue 5/23 18:00:05.385 Wizard building alt. index 0 for Show Tue 5/23 18:00:05.416 Wizard allocating table for Airing of size 41930 Tue 5/23 18:00:05.416 Wizard loading main index for Airing Tue 5/23 18:00:05.962 Wizard building alt. index 0 for Airing Tue 5/23 18:00:05.986 Wizard building alt. index 1 for Airing Tue 5/23 18:00:06.010 Wizard allocating table for ManualRecord of size 26 Tue 5/23 18:00:06.010 Wizard loading main index for ManualRecord Tue 5/23 18:00:06.014 Wizard allocating table for MediaFile of size 235 Tue 5/23 18:00:06.014 Wizard loading main index for MediaFile Tue 5/23 18:00:06.033 Wizard building alt. index 0 for MediaFile Tue 5/23 18:00:06.034 Wizard allocating table for Watched of size 4097 Tue 5/23 18:00:06.034 Wizard loading main index for Watched Tue 5/23 18:00:06.128 Wizard building alt. index 0 for Watched Tue 5/23 18:00:06.131 Wizard allocating table for Agent of size 2988 Tue 5/23 18:00:06.131 Wizard loading main index for Agent Tue 5/23 18:00:06.258 Wizard building alt. index 0 for Agent Tue 5/23 18:00:06.262 Wizard allocating table for Wasted of size 3373 Tue 5/23 18:00:06.263 Wizard loading main index for Wasted Tue 5/23 18:00:06.276 Wizard allocating table for Playlist of size 2 Tue 5/23 18:00:06.277 Wizard loading main index for Playlist Tue 5/23 18:00:06.298 Received command of:CARNY_SYNC_CAUSEMAP 4880 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:06.334 Received command of:CARNY_SYNC_WPMAP 4761 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:06.364 Received command of:CARNY_SYNC_MUSTSEE 165 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:06.372 Received command of:CARNY_SYNC_LOVE 2193 from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:06.386 SageTV received connection from:Socket[addr=localhost/127.0.0.1,port=42024,localport=1040] Tue 5/23 18:00:06.669 MMC calling detectCaptureDevices on sage.o@14382c6 Tue 5/23 18:00:06.689 devices detected=[Hauppauge WinTV PVR PCI II Capture, Hauppauge WinTV PVR PCI II Capture #2, Hauppauge WinTV PVR PCI II Capture #3, SGraphRecorder on 127.0.0.1:6969] Tue 5/23 18:00:06.689 EncoderMap={Hauppauge WinTV PVR PCI II Capture #2=Hauppauge WinTV PVR PCI II Capture #2, SGraphRecorder on 127.0.0.1:6969=SGraphRecorder on 127.0.0.1:6969, 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} Tue 5/23 18:00:07.036 DShowFilters=[.RAM file Parser, 9x8Resize, AC3 Parser Filter, 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, Audio Source, AVI Decompressor, AVI Draw, AVI Mux, AVI Splitter, AVI/WAV File Source, Bitmap Generate, Color Converter, Color Space Converter, CyberLink Audio Decoder, CyberLink Audio Effect, CyberLink DxVA Filter 2, CyberLink Video/SP Decoder, Deinterlace Filter, Disk Record Queue, Dump, DV Muxer, DV Scenes, DV Source Filter, 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, Hauppauge WinTV Color Format Converter 2, Hauppauge WinTV File Reader, Hauppauge WinTV File Writer, Hauppauge WinTV MPEG Splitter, Hauppauge WinTV SnapShot, I-Media Multiple MPEG2 Source, 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, InterVideo Audio Decoder, IVF source filter, LAME MPEG Layer III Audio Encoder, Ligos MPEG Splitter, Line 21 Decoder, Line 21 Decoder 2, Lyric Parser, Microsoft MPEG-4 Video Decompressor, Microsoft Screen Video Decompressor, MIDI Parser, Minimal Null, 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, Nero Audio CD Filter, Nero Audio CD Navigator, Nero Audio Processor, Nero Audio Sample Renderer, Nero Audio Stream Renderer, Nero Digital Audio Decoder, Nero Digital AVC Audio Encoder, Nero Digital AVC File Writer, Nero Digital AVC Muxer, Nero Digital AVC Null Renderer, Nero Digital AVC Subpicture Enc, Nero Digital AVC Video Enc, Nero Digital Parser, Nero DV Splitter, Nero DVD Decoder, Nero DVD Navigator, Nero ES Video Reader, Nero File Source, Nero File Source (Async.), Nero File Source / Splitter, Nero Format Converter, Nero Frame Capture, Nero InteractiveGraphics Decoder, Nero Mpeg2 Encoder, Nero Overlay Mixer, Nero Photo Source, Nero PresentationGraphics Decoder, Nero PS Muxer, Nero QuickTime(tm) Audio Decoder, Nero QuickTime(tm) Video Decoder, Nero Resize, Nero Scene Detector, Nero Scene Detector 2, Nero Splitter, Nero Stream Buffer Sink, Nero Stream Buffer Source, Nero Subpicture Decoder, Nero Vcd Navigator, Nero Video Analyzer, Nero Video Decoder, Nero Video Decoder HD, Nero Video Processor, Nero Video Sample Renderer, Nero Video Stream Renderer, 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, SBDARecorderDump, Screen Capture filter, Screen Capture filter, Shared File Source (Async.), ShotBoundaryDet, Smart Tee, 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, Video Source, WAV Dest, Wave Parser, WIA Stream Snapshot Filter, Windows Media Audio Decoder, Windows Media Multiplexer, Windows Media Pad VU Data Grabber, 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] Tue 5/23 18:00:07.183 sage.aw@11ce012 needs an update in 0:34:18 Tue 5/23 18:00:07.183 sage.aw@15e68d needs an update in 5:54:09 Tue 5/23 18:00:07.184 EPG needs an update in 34 minutes Tue 5/23 18:00:07.184 EPG's works is done. Waiting... Tue 5/23 18:00:07.333 VF thread is now running... Tue 5/23 18:00:07.334 VF thread is now waiting for 0:00:00.000 Tue 5/23 18:00:07.334 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:07.335 MsgSend thread spawned for /127.0.0.1:42024 Tue 5/23 18:00:07.336 MsgRecv thread has spawned for /127.0.0.1:42024 Tue 5/23 18:00:07.336 Loading startup runnable:net.sf.sageplugins.webserver.StartServer Tue 5/23 18:00:07.338 Loaded startup runnable:net.sf.sageplugins.webserver.StartServer Tue 5/23 18:00:07.339 StorageDeviceDetector started... Tue 5/23 18:00:07.547 SetFullScreen(true) Tue 5/23 18:00:07.547 FullScreen set to true Tue 5/23 18:00:07.549 UIMgr loading UI from: C:\Program Files\SageTV\SageTV\STVs\SageTV3\SageTV3-5.xml Tue 5/23 18:00:07.564 Starting webserver with args: [-p, 8080, -root, webserver, -t, throttles.properties, -s, servlets.properties, -r, realms.properties, -a, aliases.properties, -nohup] Tue 5/23 18:00:07.618 Acme httpd hammer:8080 listening. Tue 5/23 18:00:08.348 AWTThread Hang Detected - hang time = 752 Tue 5/23 18:00:08.691 locale = en Tue 5/23 18:00:09.019 DatePat=EEE, MMM d orgPat=EEEE, MMMM d, yyyy Tue 5/23 18:00:09.044 setUI(sage.bz@5f0e7d[Main Menu]) histIdx=0 uiHistory=[sage.bz@5f0e7d[Main Menu]] Tue 5/23 18:00:09.102 AWTThread Hang Detected - hang time = 1506 Tue 5/23 18:00:09.241 VF processing job null nPlayin=false Tue 5/23 18:00:09.242 VF thread is now waiting for 0:00:00.000 Tue 5/23 18:00:09.565 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=29] numGlyphs=1674 numCachedGlyphs=280 numImages=3 Tue 5/23 18:00:09.740 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=23] numGlyphs=1674 numCachedGlyphs=292 numImages=2 Tue 5/23 18:00:09.853 VF processing job null nPlayin=false Tue 5/23 18:00:09.854 VF thread is now waiting for 0:00:00.000 Tue 5/23 18:00:09.863 VF processing job null nPlayin=false Tue 5/23 18:00:09.864 VF thread is now waiting for 0:00:00.000 Tue 5/23 18:00:09.953 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=bold,size=42] numGlyphs=1674 numCachedGlyphs=242 numImages=5 Tue 5/23 18:00:10.320 Rendered new font to cache font=java.awt.Font[family=Arial,name=Arial,style=plain,size=45] numGlyphs=1674 numCachedGlyphs=258 numImages=7 Tue 5/23 18:00:10.429 Initializing DirectX9 Tue 5/23 18:00:10.440 Using DX9 Full Screen Exclusive Mode Tue 5/23 18:00:10.441 Creating D3D Device Tue 5/23 18:00:10.526 Done Initializing DirectX9 Tue 5/23 18:00:10.527 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\Background.jpg Tue 5/23 18:00:10.568 ImageUtils creating BI copy sun.awt.image.ToolkitImage@12cdd20 Tue 5/23 18:00:10.579 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.652 Creating DirectX9 Texture from memory w=600 h=450 Tue 5/23 18:00:10.655 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\SageLogo256.png Tue 5/23 18:00:10.676 ImageUtils creating BI copy sun.awt.image.ToolkitImage@66b06b Tue 5/23 18:00:10.676 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.689 Creating DirectX9 Texture from memory w=256 h=78 Tue 5/23 18:00:10.690 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\GoWindowed.png Tue 5/23 18:00:10.701 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1e20a9a Tue 5/23 18:00:10.702 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.705 Creating DirectX9 Texture from memory w=117 h=102 Tue 5/23 18:00:10.705 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\GoSleep.png Tue 5/23 18:00:10.709 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1325aef Tue 5/23 18:00:10.710 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.713 Creating DirectX9 Texture from memory w=97 h=121 Tue 5/23 18:00:10.713 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.725 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:10.726 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.739 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:10.740 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.752 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:10.753 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.765 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:10.766 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MenuBarLong.png Tue 5/23 18:00:10.771 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1995c9a Tue 5/23 18:00:10.772 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.779 Creating DirectX9 Texture from memory w=586 h=47 Tue 5/23 18:00:10.780 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.792 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:10.793 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.806 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:10.807 Premultiplying alpha for BuffImage... Tue 5/23 18:00:10.820 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:12.326 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:17.327 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:22.327 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:27.328 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:32.327 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:36.472 setUI(sage.bz@f65b5b[SageRecordings SHORTCUTS]) histIdx=1 uiHistory=[sage.bz@5f0e7d[Main Menu], sage.bz@f65b5b[SageRecordings SHORTCUTS]] Tue 5/23 18:00:36.484 setUI(sage.bz@1fd9726[SageRecordings STYLE LINKS]) histIdx=1 uiHistory=[sage.bz@5f0e7d[Main Menu], sage.bz@1fd9726[SageRecordings STYLE LINKS]] Tue 5/23 18:00:36.912 setUI(sage.bz@12394f8[Xtra: SageTV Recordings by malore]) histIdx=1 uiHistory=[sage.bz@5f0e7d[Main Menu], sage.bz@12394f8[Xtra: SageTV Recordings by malore]] Tue 5/23 18:00:36.958 setUI(sage.bz@1b75be2[Xtra: SageTV Recordings by malore]) histIdx=1 uiHistory=[sage.bz@5f0e7d[Main Menu], sage.bz@1b75be2[Xtra: SageTV Recordings by malore]] Tue 5/23 18:00:37.115 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\guideLeft.png Tue 5/23 18:00:37.118 ImageUtils creating BI copy sun.awt.image.ToolkitImage@17b6178 Tue 5/23 18:00:37.119 Premultiplying alpha for BuffImage... Tue 5/23 18:00:37.120 Creating DirectX9 Texture from memory w=14 h=71 Tue 5/23 18:00:37.328 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:37.887 Rendered new font to cache font=java.awt.Font[family=Verdana,name=Verdana,style=bold,size=19] numGlyphs=893 numCachedGlyphs=322 numImages=2 Tue 5/23 18:00:37.888 Premultiplying alpha for BuffImage... Tue 5/23 18:00:37.910 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:38.147 Rendered new font to cache font=java.awt.Font[family=Verdana,name=Verdana,style=bold,size=22] numGlyphs=893 numCachedGlyphs=251 numImages=2 Tue 5/23 18:00:38.147 Premultiplying alpha for BuffImage... Tue 5/23 18:00:38.169 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:38.326 Rendered new font to cache font=java.awt.Font[family=Tahoma,name=Tahoma,style=bold,size=19] numGlyphs=2034 numCachedGlyphs=354 numImages=2 Tue 5/23 18:00:38.327 Premultiplying alpha for BuffImage... Tue 5/23 18:00:38.348 Creating DirectX9 Texture from memory w=256 h=256 Tue 5/23 18:00:38.353 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerFirstRun.png Tue 5/23 18:00:38.358 ImageUtils creating BI copy sun.awt.image.ToolkitImage@347cdb Tue 5/23 18:00:38.359 Premultiplying alpha for BuffImage... Tue 5/23 18:00:38.362 Creating DirectX9 Texture from memory w=121 h=121 Tue 5/23 18:00:42.329 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Tue 5/23 18:00:45.284 ImageUtils loading file C:\Program Files\SageTV\SageTV\STVs\SageTV3\MarkerHDTV.png Tue 5/23 18:00:45.290 ImageUtils creating BI copy sun.awt.image.ToolkitImage@1363271 Tue 5/23 18:00:45.291 Premultiplying alpha for BuffImage... Tue 5/23 18:00:45.298 Creating DirectX9 Texture from memory w=121 h=121 Tue 5/23 18:00:47.328 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] REMOVED A BUNCH OF STUFF IN THE MIDDLE Wed 5/24 21:13:39.600 VF thread is now waiting for 0:00:00.000 Wed 5/24 21:13:39.687 Received command of:WIZARD_SYNC from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:13:39.689 setUI(sage.bz@f65b5b[SageRecordings SHORTCUTS]) histIdx=9 uiHistory=[sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@f65b5b[SageRecordings SHORTCUTS]] Wed 5/24 21:13:39.692 setUI(sage.bz@1fd9726[SageRecordings STYLE LINKS]) histIdx=9 uiHistory=[sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1fd9726[SageRecordings STYLE LINKS]] Wed 5/24 21:13:39.694 setUI(sage.bz@12394f8[Xtra: SageTV Recordings by malore]) histIdx=9 uiHistory=[sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@12394f8[Xtra: SageTV Recordings by malore]] Wed 5/24 21:13:39.841 setUI(sage.bz@1b75be2[Xtra: SageTV Recordings by malore]) histIdx=9 uiHistory=[sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore]] Wed 5/24 21:13:39.896 setUI(sage.bz@f65b5b[SageRecordings SHORTCUTS]) histIdx=9 uiHistory=[sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@f65b5b[SageRecordings SHORTCUTS]] Wed 5/24 21:13:39.899 setUI(sage.bz@1fd9726[SageRecordings STYLE LINKS]) histIdx=9 uiHistory=[sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1fd9726[SageRecordings STYLE LINKS]] Wed 5/24 21:13:39.901 setUI(sage.bz@12394f8[Xtra: SageTV Recordings by malore]) histIdx=9 uiHistory=[sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@12394f8[Xtra: SageTV Recordings by malore]] Wed 5/24 21:13:39.905 setUI(sage.bz@1b75be2[Xtra: SageTV Recordings by malore]) histIdx=9 uiHistory=[sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore]] Wed 5/24 21:13:41.329 VideoFrame.watch(A[1941243,1941208,"Scrubs",21785@0516.21:30,30]) Wed 5/24 21:13:41.330 watchThisFile=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] Wed 5/24 21:13:41.331 Watch airing is a file & over, do that instead dvd=false Wed 5/24 21:13:41.332 VF.submitJob(VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] ifn=null]) Wed 5/24 21:13:41.333 VF processing job VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] ifn=null] nPlayin=false Wed 5/24 21:13:41.334 VF processing on UI Thread VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] ifn=null] Wed 5/24 21:13:41.335 VF digital TV playback detected: false Wed 5/24 21:13:41.335 VideoFrame creating new media player for file:MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] Wed 5/24 21:13:41.335 VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] ifn=null] nPlayin=false Wed 5/24 21:13:41.336 VF network encoder playback detected: false Wed 5/24 21:13:41.337 VF processing on UI Thread VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] ifn=null] Wed 5/24 21:13:41.338 VF file=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] targetTime = Tue 5/16 21:30:49.939 Wed 5/24 21:13:41.338 VideoFrame.timeSelected(Tue 5/16 21:30:49.939, true) currFile=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] Wed 5/24 21:13:41.339 DShowPlayer setVideoRendererFilter0({51B4ABF3-748F-4E3B-A276-C828330E926A}) called Wed 5/24 21:13:41.367 Setting up VMR9 deinterlacing Wed 5/24 21:13:41.367 Curr Mix Prefs=0x1015 Wed 5/24 21:13:41.367 Set to 0x2015, hr=0x0, New Mix Prefs=0x2015 Wed 5/24 21:13:41.367 DShowPlayer setTimeshift=0 buffer=0 Wed 5/24 21:13:41.367 Using the default source filter Wed 5/24 21:13:41.367 NATIVE Loading the source file Wed 5/24 21:13:41.388 AutoAspect: Setting Aspect Ratio to Source as Default aspect ratio for TV files Wed 5/24 21:13:41.389 NATIVE Setting up the MPEG demux Wed 5/24 21:13:41.421 NATIVE RenderAudio called Wed 5/24 21:13:41.421 NATIVE RenderAudio step 1 Wed 5/24 21:13:41.421 NATIVE RenderAudio step 2 Wed 5/24 21:13:41.421 NATIVE RenderAudio step 3 Wed 5/24 21:13:41.421 NATIVE RenderAudio step 4 Wed 5/24 21:13:41.531 NATIVE RenderVideo called Wed 5/24 21:13:41.532 NATIVE RenderVideo step 1 Wed 5/24 21:13:41.532 NATIVE RenderVideo step 2 Wed 5/24 21:13:41.532 Video source pin information: Wed 5/24 21:13:41.532 PIN is not connected yet!Wed 5/24 21:13:41.532 M type MEDIATYPE_Video S type MEDIASUBTYPE_MPEG2_VIDEO F type FORMAT_MPEG2_VIDEO Wed 5/24 21:13:41.532 NATIVE RenderVideo step 3 Wed 5/24 21:13:41.599 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:13:41.867 VMR9 alloc 1920x1080 Offscreen DefaultPool format=NV12 minBuffs=1 arx=16 ary=9 nativeWidth=1920 nativeHeight=1080 reqNumBuff=1 allocNumBuff=1 hr=0x0 Wed 5/24 21:13:41.870 Setting up VMR9 deinterlacing Wed 5/24 21:13:41.870 VM9Deinterlacing Tech: BOBVerticalStretch Wed 5/24 21:13:41.870 Actual deinterlace: hr=0x0 guid={335AA36E-7884-43A4-9C91-7F87FAF3E37E} Wed 5/24 21:13:41.871 deinterlace mode: hr=0x1 guid={00000000-0000-0000-0000-000000000000} Wed 5/24 21:13:41.871 Setting deinterlace mode to actual mode... Wed 5/24 21:13:41.871 deinterlace mode: hr=0x0 guid={335AA36E-7884-43A4-9C91-7F87FAF3E37E} Wed 5/24 21:13:41.871 Filter Graph Video Renderer Info: Wed 5/24 21:13:41.871 Video Renderer:CLSID_VideoMixingRenderer9 Wed 5/24 21:13:41.871 M type MEDIATYPE_Video S type Unknown GUID Name F type FORMAT_VideoInfo2 Wed 5/24 21:13:41.871 Interlaced video Wed 5/24 21:13:41.871 Both fields per sample Wed 5/24 21:13:41.871 Field 2 first Wed 5/24 21:13:41.871 Stream never contains a Field 2 Wed 5/24 21:13:41.871 Either bob or weave mode. Wed 5/24 21:13:41.871 VMR9 filter detected, using line 21 decoder 2.Wed 5/24 21:13:41.872 DShowGraphFilters=Default DirectSound Device,VidRend,Line21 Decoder,NVIDIA Audio Decoder,NVIDIA Video Decoder,SageTV MPEG2 Demultiplexer,D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Wed 5/24 21:13:41.873 VideoFrame.timeSelected2(Tue 5/16 21:30:49.939, true) currFile=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] realDur=1797451 Wed 5/24 21:13:41.873 About to perform media time selection for 49740 Wed 5/24 21:13:41.873 Running the playback graph. Wed 5/24 21:13:41.873 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:41.877 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:41.878 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:41.879 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:41.879 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:41.879 Event: 0xd Wed 5/24 21:13:41.880 Event: 0xe Wed 5/24 21:13:41.880 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:41.880 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:41.880 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:41.881 VF processing job null nPlayin=true Wed 5/24 21:13:41.881 isRec=false rd=1797451 base=49740 Wed 5/24 21:13:41.881 VF thread is now waiting for 0:29:07.461 Wed 5/24 21:13:41.932 AutoAspect: Setting Aspect Ratio to Source as Default aspect ratio for TV files Wed 5/24 21:13:42.403 VF processing job null nPlayin=true Wed 5/24 21:13:42.404 isRec=false rd=1797451 base=50183 Wed 5/24 21:13:42.404 VF thread is now waiting for 0:29:07.018 Wed 5/24 21:13:42.464 VMR9 alloc 1934x1088 Offscreen DefaultPool format=NV12 minBuffs=1 arx=16 ary=9 nativeWidth=1934 nativeHeight=1088 reqNumBuff=1 allocNumBuff=1 hr=0x0 Wed 5/24 21:13:42.475 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.476 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.477 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.477 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.478 Event: 0x8065 Wed 5/24 21:13:42.478 VF processing job null nPlayin=true Wed 5/24 21:13:42.478 isRec=false rd=1797451 base=50258 Wed 5/24 21:13:42.478 VF thread is now waiting for 0:29:06.943 Wed 5/24 21:13:42.487 VMR9 rendering began VRAM free=254803968 Wed 5/24 21:13:42.491 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.491 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.492 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.492 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.493 Event: 0x8065 Wed 5/24 21:13:42.493 VF processing job null nPlayin=true Wed 5/24 21:13:42.493 isRec=false rd=1797451 base=50272 Wed 5/24 21:13:42.494 VF thread is now waiting for 0:29:06.928 Wed 5/24 21:13:42.497 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.498 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.499 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.499 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.500 Event: 0x8065 Wed 5/24 21:13:42.500 VF processing job null nPlayin=true Wed 5/24 21:13:42.500 isRec=false rd=1797451 base=50279 Wed 5/24 21:13:42.501 VF thread is now waiting for 0:29:06.921 Wed 5/24 21:13:42.503 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.504 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.504 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.504 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.505 Event: 0x8065 Wed 5/24 21:13:42.505 VF processing job null nPlayin=true Wed 5/24 21:13:42.505 isRec=false rd=1797451 base=50284 Wed 5/24 21:13:42.505 VF thread is now waiting for 0:29:06.917 Wed 5/24 21:13:42.517 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.518 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.518 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.519 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.520 Event: 0x8065 Wed 5/24 21:13:42.520 VF processing job null nPlayin=true Wed 5/24 21:13:42.520 isRec=false rd=1797451 base=50299 Wed 5/24 21:13:42.520 VF thread is now waiting for 0:29:06.902 Wed 5/24 21:13:42.523 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.523 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.524 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.524 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.524 Event: 0x8065 Wed 5/24 21:13:42.524 VF processing job null nPlayin=true Wed 5/24 21:13:42.525 isRec=false rd=1797451 base=50303 Wed 5/24 21:13:42.525 VF thread is now waiting for 0:29:06.898 Wed 5/24 21:13:42.525 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.526 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.526 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.526 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.527 Event: 0x8065 Wed 5/24 21:13:42.527 VF processing job null nPlayin=true Wed 5/24 21:13:42.527 isRec=false rd=1797451 base=50305 Wed 5/24 21:13:42.527 VF thread is now waiting for 0:29:06.895 Wed 5/24 21:13:42.527 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.528 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.528 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.529 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.529 Event: 0x8065 Wed 5/24 21:13:42.529 VF processing job null nPlayin=true Wed 5/24 21:13:42.529 isRec=false rd=1797451 base=50308 Wed 5/24 21:13:42.530 VF thread is now waiting for 0:29:06.893 Wed 5/24 21:13:42.530 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.530 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.531 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.531 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.531 Event: 0x8065 Wed 5/24 21:13:42.531 VF processing job null nPlayin=true Wed 5/24 21:13:42.532 isRec=false rd=1797451 base=50310 Wed 5/24 21:13:42.532 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.533 VF thread is now waiting for 0:29:06.890 Wed 5/24 21:13:42.533 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.533 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.534 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.534 Event: 0x8065 Wed 5/24 21:13:42.534 VF processing job null nPlayin=true Wed 5/24 21:13:42.534 isRec=false rd=1797451 base=50313 Wed 5/24 21:13:42.535 VF thread is now waiting for 0:29:06.888 Wed 5/24 21:13:42.535 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.535 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.536 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.536 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.536 Event: 0x8065 Wed 5/24 21:13:42.536 VF processing job null nPlayin=true Wed 5/24 21:13:42.536 isRec=false rd=1797451 base=50315 Wed 5/24 21:13:42.537 VF thread is now waiting for 0:29:06.885 Wed 5/24 21:13:42.537 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.537 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.538 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.538 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.538 Event: 0x8065 Wed 5/24 21:13:42.538 VF processing job null nPlayin=true Wed 5/24 21:13:42.539 isRec=false rd=1797451 base=50318 Wed 5/24 21:13:42.539 VF thread is now waiting for 0:29:06.883 Wed 5/24 21:13:42.541 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.541 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.542 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.542 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.542 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.543 Event: 0x8065 Wed 5/24 21:13:42.543 Event: 0x8065 Wed 5/24 21:13:42.543 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.543 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.544 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.544 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.544 Event: 0x8065 Wed 5/24 21:13:42.544 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.546 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.546 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.546 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.547 Event: 0x8065 Wed 5/24 21:13:42.547 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.547 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.547 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.548 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.548 Event: 0x8065 Wed 5/24 21:13:42.548 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.548 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.550 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.550 VF processing job null nPlayin=true Wed 5/24 21:13:42.550 isRec=false rd=1797451 base=50330 Wed 5/24 21:13:42.551 VF thread is now waiting for 0:29:06.871 Wed 5/24 21:13:42.553 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.554 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.554 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.555 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.556 Event: 0x8065 Wed 5/24 21:13:42.557 VF processing job null nPlayin=true Wed 5/24 21:13:42.557 isRec=false rd=1797451 base=50335 Wed 5/24 21:13:42.557 VF thread is now waiting for 0:29:06.865 Wed 5/24 21:13:42.565 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.566 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.566 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.566 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.567 Event: 0x8065 Wed 5/24 21:13:42.567 VF processing job null nPlayin=true Wed 5/24 21:13:42.567 isRec=false rd=1797451 base=50345 Wed 5/24 21:13:42.567 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.568 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.568 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.568 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.568 Event: 0x8065 Wed 5/24 21:13:42.568 VF processing job null nPlayin=true Wed 5/24 21:13:42.569 isRec=false rd=1797451 base=50347 Wed 5/24 21:13:42.569 VF thread is now waiting for 0:29:06.853 Wed 5/24 21:13:42.569 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:13:42.570 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:13:42.570 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:13:42.570 DShowMediaPlayer is consuming the events... Wed 5/24 21:13:42.570 Event: 0x8065 Wed 5/24 21:13:42.570 VF processing job null nPlayin=true Wed 5/24 21:13:42.571 isRec=false rd=1797451 base=50349 Wed 5/24 21:13:42.571 VF thread is now waiting for 0:29:06.852 Wed 5/24 21:13:42.954 setUI(sage.bz@c9a375[MediaPlayer OSD]) histIdx=9 uiHistory=[sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@1b75be2[Xtra: SageTV Recordings by malore], sage.bz@c9a375[MediaPlayer OSD]] Wed 5/24 21:13:46.600 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:13:51.601 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:13:56.602 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:01.603 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:06.605 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:11.606 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:16.606 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:21.606 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:26.607 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:31.608 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:36.608 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:41.609 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:46.611 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:51.611 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:14:56.612 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:01.613 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:06.615 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:11.616 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:16.613 VF.submitJob(VFJob[TimeSet r=0.0 t=1147840494193 file=null ifn=null]) Wed 5/24 21:15:16.614 VF processing job VFJob[TimeSet r=0.0 t=1147840494193 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.615 VF processing on UI Thread VFJob[TimeSet r=0.0 t=1147840494193 file=null ifn=null] Wed 5/24 21:15:16.616 VideoFrame.timeSelected(Tue 5/16 21:34:54.193, true) currFile=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] Wed 5/24 21:15:16.616 VideoFrame.timeSelected2(Tue 5/16 21:34:54.193, true) currFile=MediaFile[id=1998413 A[1941243,1941208,"Scrubs",21785@0516.21:30,30] host=hammer encodedBy=SGraphRecorder on 127.0.0.1:6969 DVD Long Play D:\Sage\Scrubs-MyTransition-1941243-0.mpg, Seg0[Tue 5/16 21:30:00.132-Tue 5/16 22:00:00.018]] realDur=1797451 Wed 5/24 21:15:16.617 About to perform media time selection for 293663 Wed 5/24 21:15:16.617 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:16.623 VF processing job null nPlayin=true Wed 5/24 21:15:16.624 isRec=false rd=1797451 base=293663 Wed 5/24 21:15:16.625 VF thread is now waiting for 0:25:03.538 Wed 5/24 21:15:16.642 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.642 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.643 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.644 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.645 Event: 0x8065 Wed 5/24 21:15:16.645 VF processing job null nPlayin=true Wed 5/24 21:15:16.645 isRec=false rd=1797451 base=293675 Wed 5/24 21:15:16.646 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.646 VF thread is now waiting for 0:25:03.526 Wed 5/24 21:15:16.647 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.647 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.649 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.651 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.654 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.656 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.657 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.658 Event: 0x8065 Wed 5/24 21:15:16.659 Event: 0x8065 Wed 5/24 21:15:16.659 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.660 Event: 0x8065 Wed 5/24 21:15:16.660 Event: 0x8065 Wed 5/24 21:15:16.660 Event: 0x8065 Wed 5/24 21:15:16.661 Event: 0x8065 Wed 5/24 21:15:16.661 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.662 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.662 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.664 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.666 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.668 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.670 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.672 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.687 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.689 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.689 Event: 0x8065 Wed 5/24 21:15:16.689 Event: 0x8065 Wed 5/24 21:15:16.689 Event: 0x8065 Wed 5/24 21:15:16.690 Event: 0x8065 Wed 5/24 21:15:16.690 Event: 0x8065 Wed 5/24 21:15:16.690 Event: 0x8065 Wed 5/24 21:15:16.690 Event: 0x8065 Wed 5/24 21:15:16.691 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.691 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.692 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.693 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.694 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.695 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.696 VF.submitJob(VFJob[DirectControl r=0.0 t=0 file=null ifn=null]) Wed 5/24 21:15:16.713 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.714 Event: 0x8065 Wed 5/24 21:15:16.714 Event: 0x8065 Wed 5/24 21:15:16.714 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.715 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.716 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.716 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.717 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.718 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.719 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.720 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.720 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.721 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.722 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.722 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.723 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.723 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.724 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.725 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.725 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.726 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.727 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.728 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.728 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.729 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.730 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.731 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.731 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.732 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.733 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.734 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.735 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.736 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.736 VF processing job VFJob[DirectControl r=0.0 t=0 file=null ifn=null] nPlayin=true Wed 5/24 21:15:16.737 VF processing on UI Thread VFJob[DirectControl r=0.0 t=0 file=null ifn=null] Wed 5/24 21:15:16.737 DShowMediaPlayer is consuming the events... Wed 5/24 21:15:16.738 VF processing job null nPlayin=true Wed 5/24 21:15:16.738 isRec=false rd=1797451 base=293706 Wed 5/24 21:15:16.739 VF thread is now waiting for 0:25:03.495 Wed 5/24 21:15:21.617 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:26.618 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:31.619 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:36.620 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:41.620 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:46.621 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:51.622 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:15:56.622 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:16:01.623 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:16:06.625 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:16:11.626 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:16:16.627 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038] Wed 5/24 21:16:21.629 Received command of:NOOP from Socket[addr=localhost/127.0.0.1,port=42024,localport=1038]