OK, I submitted the plugin to SVN and I thought it was working but it seems my recurring issue with the fresh playback stopping as soon as it starts is still a problem. When I finish the first RAR and start playing it, it shows the first second of video and then stops. My script detects that the player didn't keep playing the video, so it aborts the download, thinking that there's no movie in the RARs or that the RARs are passworded. But when I retry the same NZB, a par2.exe check will prevent having to redownload the first RAR again and it will immediately start playing - that time it always works even though the commands to play are the same.
Here's the log from the fresh play, when it stops working after a second:
22:29:04 T:3460 M:1969049600 NOTICE: DVDPlayer: Opening: rar://C%3A%5CUsers%5CMatt%20Chambers%5CAppData%5CRoaming%5CXBMC%5Cuserdata%5Cplugin_data%5CVideo%5CNZB%20Streamer%20svn%5Cbetter%2eoff%2eted%2es02e09%2ehdtv%2exvid%2dxii%5Cbetter%2eoff%2eted%2es02e09%2ehdtv%2exvid%2dxii%2erar/better.off.ted.s02e09.hdtv.xvid-xii.avi
22:29:04 T:3460 M:1969049600 WARNING: CDVDMessageQueue(player):
ut MSGQ_NOT_INITIALIZED
22:29:04 T:3612 M:1969049600 NOTICE: Creating InputStream
22:29:04 T:3612 M:1968779264 NOTICE: Creating Demuxer
22:29:04 T:3612 M:1967456256 NOTICE: Opening video stream: 0 source: 256
22:29:04 T:3612 M:1967456256 NOTICE: Creating video codec with codec id: 13
22:29:04 T:3612 M:1967435776 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: MPEG-4 part 2
22:29:04 T:3612 M:1967415296 NOTICE: Creating video thread
22:29:04 T:3612 M:1967403008 NOTICE: Opening audio stream: 1 source: 256
22:29:04 T:3612 M:1967398912 NOTICE: Finding audio codec for: 86017
22:29:04 T:5008 M:1967390720 NOTICE: running thread: video_thread
22:29:04 T:3612 M:1967349760 NOTICE: Creating audio thread
22:29:04 T:3056 M:1967337472 NOTICE: running thread: CDVDPlayerAudio:
rocess()
22:29:04 T:3056 M:1967153152 NOTICE: Creating audio device with codec id: 86017, channels: 2, sample rate: 48000, no pass-through
22:29:04 T:3056 M:1966075904 WARNING: CDVDMessageQueue(audio)::Get - retrieved last data packet of queue
22:29:04 T:5008 M:1965883392 NOTICE: fps: 23.976000, pwidth: 640, pheight: 352, dwidth: 640, dheight: 352
22:29:04 T:5008 M:1965883392 NOTICE: Display resolution DESKTOP : 1280x1024 @ 60.00 - Full Screen (12)
22:29:04 T:5008 M:1967808512 WARNING: CDVDMessageQueue(video)::Get - retrieved last data packet of queue
22:29:04 T:3612 M:1967804416 NOTICE: CDVDPlayer::OnExit()
22:29:04 T:3612 M:1967804416 NOTICE: DVDPlayer: eof, waiting for queues to empty
22:29:04 T:3612 M:1967804416 NOTICE: DVDPlayer: closing audio stream
22:29:04 T:3612 M:1967804416 NOTICE: Closing audio stream
22:29:04 T:3612 M:1967804416 NOTICE: CDVDMessageQueue(audio)::WaitUntilEmpty
22:29:04 T:3056 M:1967804416 NOTICE: thread end: CDVDPlayerAudio::OnExit()
22:29:04 T:3612 M:1967804416 NOTICE: Waiting for audio thread to exit
22:29:04 T:3612 M:1967808512 NOTICE: Closing audio device
22:29:04 T:3612 M:1967673344 NOTICE: Deleting audio codec
22:29:04 T:3612 M:1967673344 NOTICE: DVDPlayer: closing video stream
22:29:04 T:3612 M:1967673344 NOTICE: Closing video stream
22:29:04 T:3612 M:1967673344 NOTICE: CDVDMessageQueue(video)::WaitUntilEmpty
22:29:04 T:3612 M:1967673344 NOTICE: waiting for video thread to exit
22:29:04 T:5008 M:1967673344 ERROR: Got MSGQ_ABORT or MSGO_IS_ERROR return true
22:29:04 T:5008 M:1967673344 NOTICE: thread end: video_thread
22:29:04 T:3612 M:1967710208 NOTICE: deleting video codec
22:29:04 T:3612 M:1968033792 NOTICE: CDVDPlayer::OnExit() deleting demuxer
22:29:04 T:3612 M:1967828992 NOTICE: CDVDPlayer::OnExit() deleting input stream
22:29:05 T:3460 M:1964855296 NOTICE: CDVDPlayer::CloseFile()
22:29:05 T:3460 M:1964040192 WARNING: CDVDMessageQueue(player):
ut MSGQ_NOT_INITIALIZED
22:29:05 T:3460 M:1964040192 NOTICE: DVDPlayer: waiting for threads to exit
22:29:05 T:3460 M:1964040192 NOTICE: DVDPlayer: finished waiting
Here's the log from when I play it the second time and it works fine:
22:30:22 T:3460 M:1961615360 NOTICE: DVDPlayer: Opening: rar://C%3A%5CUsers%5CMatt%20Chambers%5CAppData%5CRoaming%5CXBMC%5Cuserdata%5Cplugin_data%5CVideo%5CNZB%20Streamer%20svn%5Cbetter%2eoff%2eted%2es02e09%2ehdtv%2exvid%2dxii%5Cbetter%2eoff%2eted%2es02e09%2ehdtv%2exvid%2dxii%2erar/better.off.ted.s02e09.hdtv.xvid-xii.avi
22:30:22 T:3460 M:1961615360 WARNING: CDVDMessageQueue(player):
ut MSGQ_NOT_INITIALIZED
22:30:22 T:1924 M:1961615360 NOTICE: Creating InputStream
22:30:22 T:1924 M:1961353216 NOTICE: Creating Demuxer
22:30:22 T:1924 M:1960583168 NOTICE: Opening video stream: 0 source: 256
22:30:22 T:1924 M:1960583168 NOTICE: Creating video codec with codec id: 13
22:30:22 T:1924 M:1960562688 NOTICE: CDVDVideoCodecFFmpeg::Open() Using codec: MPEG-4 part 2
22:30:22 T:1924 M:1960562688 NOTICE: Creating video thread
22:30:22 T:1924 M:1960562688 NOTICE: Opening audio stream: 1 source: 256
22:30:22 T:1924 M:1960562688 NOTICE: Finding audio codec for: 86017
22:30:22 T:4876 M:1960562688 NOTICE: running thread: video_thread
22:30:22 T:1924 M:1960554496 NOTICE: Creating audio thread
22:30:22 T:4588 M:1960554496 NOTICE: running thread: CDVDPlayerAudio:
rocess()
22:30:22 T:4588 M:1958944768 NOTICE: Creating audio device with codec id: 86017, channels: 2, sample rate: 48000, no pass-through
22:30:22 T:4588 M:1956040704 WARNING: CDVDMessageQueue(audio)::Get - retrieved last data packet of queue
22:30:22 T:4876 M:1956294656 NOTICE: fps: 23.976000, pwidth: 640, pheight: 352, dwidth: 640, dheight: 352
22:30:22 T:4876 M:1956294656 NOTICE: Display resolution DESKTOP : 1280x1024 @ 60.00 - Full Screen (12)
The only difference I see is an extra "retrieved last data packet of queue" in the fresh play, but I don't understand what would cause that. The first RAR is complete in both cases.