home
products
contribute
download
documentation
forum
Home
Forums
New posts
Search forums
What's new
New posts
All posts
Latest activity
Members
Registered members
Current visitors
Donate
Log in
Register
What's new
Search
Search
Search titles only
By:
New posts
Search forums
Search titles only
By:
Menu
Log in
Register
Navigation
Install the app
Install
More options
Contact us
Close Menu
Forums
MediaPortal 1
Support
Watch / Listen Media
Television (MyTV frontend and TV-Server)
MP1.16 RecordingFileHandler: Error while deleting a recording from disk.
Contact us
RSS
JavaScript is disabled. For a better experience, please enable JavaScript in your browser before proceeding.
You are using an out of date browser. It may not display this or other websites correctly.
You should upgrade or use an
alternative browser
.
Reply to thread
Message
<blockquote data-quote="mm1352000" data-source="post: 1220662" data-attributes="member: 82144"><p>Hi Ron</p><p></p><p></p><p>I think you've almost answered the question yourself:</p><p></p><p></p><p>Explanation using your example for NBC Nightly News 29 April...</p><p></p><p>A client starts viewing the recording of the 29 April episode:</p><p>[2017-04-29 16:04:08,459] [Log ] [7 ] [INFO ] - RTSP: add stream BB6FFAD file:K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-29 16:04:08,468] [Log ] [7 ] [INFO ] - Controller: streaming url:rtsp://MePoTVS:554/BB6FFAD file:K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p></p><p>This implies that the RTSP streaming server will be accessing the recording file. Obviously it has to in order to be able to provide the stream:</p><p>[collapse]</p><p>[2017-04-29 16:04:08,461] [3554] - Stream server: add mpeg-2 ts stream BB6FFAD filename:K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-29 16:04:08,462] [3554] - CTsDuration::ctor</p><p>[2017-04-29 16:04:08,463] [3554] - TsMp2TFSMediaSubsession::InitFileDuration(): K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-29 16:04:08,464] [3554] - TsMp2TFSMediaSubsession::ctor - filename K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-29 16:04:08,467] [3554] - Stream server: url for stream is rtsp://192.168.0.102/BB6FFAD</p><p>[2017-04-29 16:04:08,502] [2884] - ts<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite9" alt=":eek:" title="Eek! :eek:" loading="lazy" data-shortname=":eek:" />pen K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-29 16:04:08,503] [2884] - CTSBuffer::ctor</p><p>[2017-04-29 16:04:08,503] [2884] - ts:ctor:5c006d0</p><p>[2017-04-29 16:04:08,503] [2884] - CTSBuffer:<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />etChannelType() - Read size set to TV (42112)</p><p>[2017-04-29 16:04:08,503] [2884] - ts:size 458515456</p><p>[2017-04-29 16:04:08,505] [2884] - TsMp2TFSMediaSubsession::duration(), actual: 301.510010 s, total: 301.510010 s</p><p>[2017-04-29 16:04:08,505] [2884] - ts:dtor:5c006d0</p><p>[2017-04-29 16:04:08,506] [2884] - CTSBuffer::dtor</p><p>[2017-04-29 16:04:08,516] [2884] - ts<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite9" alt=":eek:" title="Eek! :eek:" loading="lazy" data-shortname=":eek:" />pen K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-29 16:04:08,517] [2884] - CTSBuffer::ctor</p><p>[2017-04-29 16:04:08,517] [2884] - ts:ctor:5bffe10</p><p>[2017-04-29 16:04:08,518] [2884] - CTSBuffer:<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />etChannelType() - Read size set to TV (42112)</p><p>[2017-04-29 16:04:08,518] [2884] - ts:size 458515456</p><p>[2017-04-29 16:04:08,520] [2884] - ts:seek 0</p><p>[2017-04-29 16:04:08,521] [2884] - CTSBuffer - m_maxReqSize: 1316)</p><p>[2017-04-29 16:04:08,522] [2884] - CTSBuffer - m_minReqSize: 1316)</p><p>[2017-04-29 16:04:08,522] [2884] - CTSBuffer::Require() - m_maxReadIterations: 1</p><p>[2017-04-29 16:04:08,523] [2884] - TsMp2TSFramer - Average bitrate at start: 9391.416992 kbit/s calculated over 231 TS packets[/collapse]</p><p></p><p>Note the stream URL which contains the stream ID:</p><p>rtsp://192.168.0.102/<strong>BB6FFAD</strong></p><p><strong></strong></p><p>This will be important later.</p><p></p><p>For now, the streaming server log shows the client merrily viewing the recording, skipping ads when relevant, until...</p><p>[2017-04-29 16:24:33,015] [2884] - TsMp2TFSMediaSubsession::duration(), actual: 1526.095947 s, total: 1526.095947 s</p><p>[2017-04-29 16:24:36,301] [2884] - ts:dtor:5bffe10</p><p>[2017-04-29 16:24:36,303] [2884] - CTSBuffer::dtor</p><p></p><p>...they've reached the end of the recording. No more to view. Presumably the client moves on to other things at this time.</p><p></p><p>There's now a gap of about 25 hours during which nothing relevant happens in the log files. The next relevant event is, as you've identified, the start of the recording for the 30 April episode:</p><p>[2017-04-30 17:29:06,515] [Log ] [scheduler thread] [INFO ] - Scheduler: Time to record KNTV HD 5:29 PM-6:00 PM NBC Nightly News With Lester Holt</p><p>...</p><p>[2017-04-30 17:29:06,710] [Log ] [scheduler thread] [INFO ] - card: WaitForFile - video and audio are seen after 0.0580944 seconds</p><p></p><p>That episode finishes and recording stops:</p><p>[2017-04-30 18:01:02,912] [Log ] [scheduler thread] [INFO ] - Scheduler: stop record KNTV HD 4/30/2017 5:29:06 PM-4/30/2017 6:00:00 PM NBC Nightly News With Lester Holt</p><p>...</p><p>[2017-04-30 18:01:02,933] [Log ] [scheduler thread] [INFO ] - dvb<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />topGraph filterstate already stopped, returning.</p><p></p><p>Immediately following that we see the start of the failing attempts to delete the recording from the 29th:</p><p>[collapse]</p><p>[2017-04-30 18:01:02,940] [Log ] [scheduler thread] [INFO ] - diskmanagement: recording NBC Nightly News With Lester Holt ended. type:Once max episodes:1</p><p>[2017-04-30 18:01:02,944] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:01:02,945] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:01:02,945] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.edl'</p><p>[2017-04-30 18:01:02,947] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.log'</p><p>[2017-04-30 18:01:02,949] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.logo.txt'</p><p>[2017-04-30 18:01:02,950] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:01:02,951] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:01:02,958] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: adding filename to list of pending deletions: K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-30 18:01:02,967] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:01:02,967] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:01:02,968] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:01:02,968] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.[/collapse]</p><p></p><p>...and so on <strong>until you stop the TV service</strong>.</p><p></p><p>Critical point here:</p><p>[collapse][2017-04-30 18:05:19,416] [Log ] [TVService] [INFO ] - TV Service is being stopped</p><p>[2017-04-30 18:05:19,417] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,419] [Log ] [TVService] [INFO ] - TV Service: stopping</p><p>[2017-04-30 18:05:19,420] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,421] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,421] [Log ] [TVService] [INFO ] - TV Service: Stop plugins</p><p>[2017-04-30 18:05:19,422] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,424] [Log ] [TVService] [INFO ] - plugin: ComSkipLauncher stop</p><p>[2017-04-30 18:05:19,426] [Log ] [TVService] [INFO ] - plugin: xmltv stopped</p><p>[2017-04-30 18:05:19,427] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,428] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,428] [Log ] [TVService] [DEBUG] - xmltv: UnRegistered xmltv as PowerEventHandler to tvservice</p><p>[2017-04-30 18:05:19,429] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,430] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,432] [Log ] [TVService] [INFO ] - TV Service: Plugins stopped</p><p>[2017-04-30 18:05:19,433] [Log ] [TVService] [INFO ] - TV service StopRemoting</p><p>[2017-04-30 18:05:19,435] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,435] [Log ] [TVService] [INFO ] - Remoting stopped</p><p>[2017-04-30 18:05:19,437] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,437] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,438] [Log ] [TVService] [INFO ] - Controller: DeInit.</p><p>[2017-04-30 18:05:19,439] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,440] [Log ] [TVService] [INFO ] - Controller: HeartBeat monitor stopped...</p><p>[2017-04-30 18:05:19,445] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,446] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,447] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,447] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,451] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,452] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,453] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,453] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,455] [Log ] [TVService] [INFO ] - Controller: stop streamer...</p><p>[2017-04-30 18:05:19,457] [Log ] [TVService] [INFO ] - RTSP: stop streamer</p><p>[2017-04-30 18:05:19,458] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,458] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,459] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,460] [Log ] [TVService] [INFO ] - RTSP: stop all streams (9)</p><p>[2017-04-30 18:05:19,461] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,463] [Log ] [TVService] [INFO ] - RTSP: remove stream 9D80D7D4</p><p>[2017-04-30 18:05:19,465] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,466] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,466] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,467] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,471] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,472] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,472] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,473] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,476] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,477] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,477] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,478] [Log ] [TVService] [INFO ] - RTSP: remove stream D182F9A9</p><p>[2017-04-30 18:05:19,479] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.</p><p>[2017-04-30 18:05:19,480] [Log ] [TVService] [INFO ] - RTSP: remove stream BB6FFAD</p><p>[2017-04-30 18:05:19,483] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM</p><p>[2017-04-30 18:05:19,483] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,488] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts'</p><p>[2017-04-30 18:05:19,489] [Log ] [TVService] [INFO ] - RTSP: remove stream 9F876309</p><p>[2017-04-30 18:05:19,491] [Log ] [TVService] [INFO ] - RTSP: remove stream 9D5FD7D4</p><p>[2017-04-30 18:05:19,494] [Log ] [TVService] [INFO ] - RTSP: remove stream 615FDF60</p><p>[2017-04-30 18:05:19,496] [Log ] [TVService] [INFO ] - RTSP: remove stream 56E9E5CB</p><p>[2017-04-30 18:05:19,572] [Log ] [TVService] [INFO ] - RTSP: remove stream CB7007A8</p><p>[2017-04-30 18:05:19,622] [Log ] [TVService] [INFO ] - RTSP: remove stream 2008D12F</p><p>[2017-04-30 18:05:19,625] [Log ] [TVService] [INFO ] - Controller: streamer stopped...</p><p>[2017-04-30 18:05:19,626] [Log ] [TVService] [INFO ] - Controller: stop thumb processor...</p><p>[2017-04-30 18:05:19,627] [Log ] [TVService] [INFO ] - ThumbProcessor.Stop()</p><p>[2017-04-30 18:05:19,628] [Log ] [TVService] [INFO ] - Controller: thumb processor stopped...</p><p>[2017-04-30 18:05:19,629] [Log ] [TVService] [INFO ] - Controller: stop scheduler...</p><p>[2017-04-30 18:05:19,632] [Log ] [TVService] [INFO ] - Scheduler: stopped</p><p>[2017-04-30 18:05:19,667] [Log ] [RTSP Streaming thread] [INFO ] - RTSP: Streamer stopped</p><p>[2017-04-30 18:05:19,873] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.txt'</p><p>[2017-04-30 18:05:19,874] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.xml'</p><p>[2017-04-30 18:05:19,875] [Log ] [scheduler thread] [DEBUG] - - deleting 'C:\ProgramData\Team MediaPortal\MediaPortal TV Server\thumbs\NBC Nightly News With Lester Holt - 2017-04-29.jpg'</p><p>[2017-04-30 18:05:19,877] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Clean orphan recording dirs for K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts</p><p>[2017-04-30 18:05:19,878] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Checking 1 path(s) for cleanup</p><p>[2017-04-30 18:05:19,878] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Origin for recording NBC Nightly News With Lester Holt - 2017-04-29.ts found: K:\MePo1\recordings</p><p>[2017-04-30 18:05:19,879] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Found irrelevant file NBC Nightly News With Lester Holt - 2017-04-30.ts in recording path K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt - not cleaning[/collapse]</p><p></p><p>In short, over and over again we see the file can't be deleted until <strong>suddenly it is successfully deleted after stream BB6FFAD is removed from the streaming server</strong> (as part of the TV service shutdown process). As I pointed out above, stream BB6FFAD is the stream that corresponds with the episode that TV Server was failing to delete. In other words: the streaming server's use of the file is preventing TV Server from deleting it. The question is: why is the streaming server still using the file 25 hours after the client finished viewing it?</p><p></p><p>Well, when the stream is removed from the streaming server, the streaming server log shows:</p><p>[2017-04-30 18:05:19,482] [594] - Stream server<img src="data:image/gif;base64,R0lGODlhAQABAIAAAAAAAP///yH5BAEAAAAALAAAAAABAAEAAAIBRAA7" class="smilie smilie--sprite smilie--sprite5" alt=":confused:" title="Confused :confused:" loading="lazy" data-shortname=":confused:" />tream server: remove stream BB6FFAD</p><p>[2017-04-30 18:05:19,488] [594] - CTsDuration::dtor</p><p>[2017-04-30 18:05:19,489] [594] - TsMp2TFSMediaSubsession::dtor (K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts)</p><p></p><p>I traced this back in the code and found that the CTsDuration instance - a necessary object used for keeping track of the stream duration - has the file open until this point.</p><p></p><p>[USER=83973]@Owlsroost[/USER] </p><p>According to the code history, it looks like the pulling in of TsReader's file handling in MP 1.16 PR has introduced a critical change in the duration calculation handling.</p><p></p><p>Previously:</p><p><a href="https://github.com/MediaPortal/MediaPortal-1/blob/9595740a336776945bb8ec6da3c45dc473378270/DirectShowFilters/StreamingServer/Source/TsMPEG2TransportFileServerMediaSubsession.cpp" target="_blank">MediaPortal-1/TsMPEG2TransportFileServerMediaSubsession.cpp at 9595740a336776945bb8ec6da3c45dc473378270 · MediaPortal/MediaPortal-1 · GitHub</a></p><p></p><p>Now:</p><p><a href="https://github.com/MediaPortal/MediaPortal-1/blob/master/DirectShowFilters/StreamingServer/Source/TsMPEG2TransportFileServerMediaSubsession.cpp" target="_blank">MediaPortal-1/TsMPEG2TransportFileServerMediaSubsession.cpp at master · MediaPortal/MediaPortal-1 · GitHub</a></p><p></p><p>Note how in the old code the duration() and fileLength() members do:</p><p>[code]</p><p>FileReader *pFileDuration = OpenFileDuration();</p><p>if (pFileDuration)</p><p>{</p><p> // work here</p><p> CloseFileDuration(pFileDuration);</p><p> // return success result</p><p>}</p><p>// return fail result</p><p>[/code]</p><p></p><p>...whereas the new code opens the file once when the CTsDuration instance is constructed, and only gets around to closing it in the CTsDuration destructor. The optimisation is a nice idea and seems to work fine for time-shift streams. However as Ron's log files show, it poses a problem for streaming of recordings. I'm surprised nobody using KODI as a front end has reported a problem because the KODI plugin creates streams for all recordings at TV Server startup. The current streaming server code would presumably prevent recordings from being deleted from the front end!</p><p></p><p>Are you able to revise the streaming server code?</p></blockquote><p></p>
[QUOTE="mm1352000, post: 1220662, member: 82144"] Hi Ron I think you've almost answered the question yourself: Explanation using your example for NBC Nightly News 29 April... A client starts viewing the recording of the 29 April episode: [2017-04-29 16:04:08,459] [Log ] [7 ] [INFO ] - RTSP: add stream BB6FFAD file:K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-29 16:04:08,468] [Log ] [7 ] [INFO ] - Controller: streaming url:rtsp://MePoTVS:554/BB6FFAD file:K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts This implies that the RTSP streaming server will be accessing the recording file. Obviously it has to in order to be able to provide the stream: [collapse] [2017-04-29 16:04:08,461] [3554] - Stream server: add mpeg-2 ts stream BB6FFAD filename:K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-29 16:04:08,462] [3554] - CTsDuration::ctor [2017-04-29 16:04:08,463] [3554] - TsMp2TFSMediaSubsession::InitFileDuration(): K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-29 16:04:08,464] [3554] - TsMp2TFSMediaSubsession::ctor - filename K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-29 16:04:08,467] [3554] - Stream server: url for stream is rtsp://192.168.0.102/BB6FFAD [2017-04-29 16:04:08,502] [2884] - ts:open K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-29 16:04:08,503] [2884] - CTSBuffer::ctor [2017-04-29 16:04:08,503] [2884] - ts:ctor:5c006d0 [2017-04-29 16:04:08,503] [2884] - CTSBuffer::SetChannelType() - Read size set to TV (42112) [2017-04-29 16:04:08,503] [2884] - ts:size 458515456 [2017-04-29 16:04:08,505] [2884] - TsMp2TFSMediaSubsession::duration(), actual: 301.510010 s, total: 301.510010 s [2017-04-29 16:04:08,505] [2884] - ts:dtor:5c006d0 [2017-04-29 16:04:08,506] [2884] - CTSBuffer::dtor [2017-04-29 16:04:08,516] [2884] - ts:open K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-29 16:04:08,517] [2884] - CTSBuffer::ctor [2017-04-29 16:04:08,517] [2884] - ts:ctor:5bffe10 [2017-04-29 16:04:08,518] [2884] - CTSBuffer::SetChannelType() - Read size set to TV (42112) [2017-04-29 16:04:08,518] [2884] - ts:size 458515456 [2017-04-29 16:04:08,520] [2884] - ts:seek 0 [2017-04-29 16:04:08,521] [2884] - CTSBuffer - m_maxReqSize: 1316) [2017-04-29 16:04:08,522] [2884] - CTSBuffer - m_minReqSize: 1316) [2017-04-29 16:04:08,522] [2884] - CTSBuffer::Require() - m_maxReadIterations: 1 [2017-04-29 16:04:08,523] [2884] - TsMp2TSFramer - Average bitrate at start: 9391.416992 kbit/s calculated over 231 TS packets[/collapse] Note the stream URL which contains the stream ID: rtsp://192.168.0.102/[B]BB6FFAD [/B] This will be important later. For now, the streaming server log shows the client merrily viewing the recording, skipping ads when relevant, until... [2017-04-29 16:24:33,015] [2884] - TsMp2TFSMediaSubsession::duration(), actual: 1526.095947 s, total: 1526.095947 s [2017-04-29 16:24:36,301] [2884] - ts:dtor:5bffe10 [2017-04-29 16:24:36,303] [2884] - CTSBuffer::dtor ...they've reached the end of the recording. No more to view. Presumably the client moves on to other things at this time. There's now a gap of about 25 hours during which nothing relevant happens in the log files. The next relevant event is, as you've identified, the start of the recording for the 30 April episode: [2017-04-30 17:29:06,515] [Log ] [scheduler thread] [INFO ] - Scheduler: Time to record KNTV HD 5:29 PM-6:00 PM NBC Nightly News With Lester Holt ... [2017-04-30 17:29:06,710] [Log ] [scheduler thread] [INFO ] - card: WaitForFile - video and audio are seen after 0.0580944 seconds That episode finishes and recording stops: [2017-04-30 18:01:02,912] [Log ] [scheduler thread] [INFO ] - Scheduler: stop record KNTV HD 4/30/2017 5:29:06 PM-4/30/2017 6:00:00 PM NBC Nightly News With Lester Holt ... [2017-04-30 18:01:02,933] [Log ] [scheduler thread] [INFO ] - dvb:StopGraph filterstate already stopped, returning. Immediately following that we see the start of the failing attempts to delete the recording from the 29th: [collapse] [2017-04-30 18:01:02,940] [Log ] [scheduler thread] [INFO ] - diskmanagement: recording NBC Nightly News With Lester Holt ended. type:Once max episodes:1 [2017-04-30 18:01:02,944] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:01:02,945] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:01:02,945] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.edl' [2017-04-30 18:01:02,947] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.log' [2017-04-30 18:01:02,949] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.logo.txt' [2017-04-30 18:01:02,950] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:01:02,951] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:01:02,958] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: adding filename to list of pending deletions: K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-30 18:01:02,967] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:01:02,967] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:01:02,968] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:01:02,968] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process.[/collapse] ...and so on [B]until you stop the TV service[/B]. Critical point here: [collapse][2017-04-30 18:05:19,416] [Log ] [TVService] [INFO ] - TV Service is being stopped [2017-04-30 18:05:19,417] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,419] [Log ] [TVService] [INFO ] - TV Service: stopping [2017-04-30 18:05:19,420] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,421] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,421] [Log ] [TVService] [INFO ] - TV Service: Stop plugins [2017-04-30 18:05:19,422] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,424] [Log ] [TVService] [INFO ] - plugin: ComSkipLauncher stop [2017-04-30 18:05:19,426] [Log ] [TVService] [INFO ] - plugin: xmltv stopped [2017-04-30 18:05:19,427] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,428] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,428] [Log ] [TVService] [DEBUG] - xmltv: UnRegistered xmltv as PowerEventHandler to tvservice [2017-04-30 18:05:19,429] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,430] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,432] [Log ] [TVService] [INFO ] - TV Service: Plugins stopped [2017-04-30 18:05:19,433] [Log ] [TVService] [INFO ] - TV service StopRemoting [2017-04-30 18:05:19,435] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,435] [Log ] [TVService] [INFO ] - Remoting stopped [2017-04-30 18:05:19,437] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,437] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,438] [Log ] [TVService] [INFO ] - Controller: DeInit. [2017-04-30 18:05:19,439] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,440] [Log ] [TVService] [INFO ] - Controller: HeartBeat monitor stopped... [2017-04-30 18:05:19,445] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,446] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,447] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,447] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,451] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,452] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,453] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,453] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,455] [Log ] [TVService] [INFO ] - Controller: stop streamer... [2017-04-30 18:05:19,457] [Log ] [TVService] [INFO ] - RTSP: stop streamer [2017-04-30 18:05:19,458] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,458] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,459] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,460] [Log ] [TVService] [INFO ] - RTSP: stop all streams (9) [2017-04-30 18:05:19,461] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,463] [Log ] [TVService] [INFO ] - RTSP: remove stream 9D80D7D4 [2017-04-30 18:05:19,465] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,466] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,466] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,467] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,471] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,472] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,472] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,473] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,476] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,477] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,477] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,478] [Log ] [TVService] [INFO ] - RTSP: remove stream D182F9A9 [2017-04-30 18:05:19,479] [Log ] [scheduler thread] [ERROR] - RecordingFileHandler: Error while deleting a recording from disk: The process cannot access the file 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' because it is being used by another process. [2017-04-30 18:05:19,480] [Log ] [TVService] [INFO ] - RTSP: remove stream BB6FFAD [2017-04-30 18:05:19,483] [Log ] [scheduler thread] [INFO ] - diskmanagement: Delete episode TvDatabase.Channel NBC Nightly News With Lester Holt Saturday, April 29, 2017 3:59:07 PM [2017-04-30 18:05:19,483] [Log ] [scheduler thread] [DEBUG] - DeleteRecordingOnDisk: 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,488] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts' [2017-04-30 18:05:19,489] [Log ] [TVService] [INFO ] - RTSP: remove stream 9F876309 [2017-04-30 18:05:19,491] [Log ] [TVService] [INFO ] - RTSP: remove stream 9D5FD7D4 [2017-04-30 18:05:19,494] [Log ] [TVService] [INFO ] - RTSP: remove stream 615FDF60 [2017-04-30 18:05:19,496] [Log ] [TVService] [INFO ] - RTSP: remove stream 56E9E5CB [2017-04-30 18:05:19,572] [Log ] [TVService] [INFO ] - RTSP: remove stream CB7007A8 [2017-04-30 18:05:19,622] [Log ] [TVService] [INFO ] - RTSP: remove stream 2008D12F [2017-04-30 18:05:19,625] [Log ] [TVService] [INFO ] - Controller: streamer stopped... [2017-04-30 18:05:19,626] [Log ] [TVService] [INFO ] - Controller: stop thumb processor... [2017-04-30 18:05:19,627] [Log ] [TVService] [INFO ] - ThumbProcessor.Stop() [2017-04-30 18:05:19,628] [Log ] [TVService] [INFO ] - Controller: thumb processor stopped... [2017-04-30 18:05:19,629] [Log ] [TVService] [INFO ] - Controller: stop scheduler... [2017-04-30 18:05:19,632] [Log ] [TVService] [INFO ] - Scheduler: stopped [2017-04-30 18:05:19,667] [Log ] [RTSP Streaming thread] [INFO ] - RTSP: Streamer stopped [2017-04-30 18:05:19,873] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.txt' [2017-04-30 18:05:19,874] [Log ] [scheduler thread] [DEBUG] - - deleting 'K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.xml' [2017-04-30 18:05:19,875] [Log ] [scheduler thread] [DEBUG] - - deleting 'C:\ProgramData\Team MediaPortal\MediaPortal TV Server\thumbs\NBC Nightly News With Lester Holt - 2017-04-29.jpg' [2017-04-30 18:05:19,877] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Clean orphan recording dirs for K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts [2017-04-30 18:05:19,878] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Checking 1 path(s) for cleanup [2017-04-30 18:05:19,878] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Origin for recording NBC Nightly News With Lester Holt - 2017-04-29.ts found: K:\MePo1\recordings [2017-04-30 18:05:19,879] [Log ] [scheduler thread] [DEBUG] - RecordingFileHandler: Found irrelevant file NBC Nightly News With Lester Holt - 2017-04-30.ts in recording path K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt - not cleaning[/collapse] In short, over and over again we see the file can't be deleted until [B]suddenly it is successfully deleted after stream BB6FFAD is removed from the streaming server[/B] (as part of the TV service shutdown process). As I pointed out above, stream BB6FFAD is the stream that corresponds with the episode that TV Server was failing to delete. In other words: the streaming server's use of the file is preventing TV Server from deleting it. The question is: why is the streaming server still using the file 25 hours after the client finished viewing it? Well, when the stream is removed from the streaming server, the streaming server log shows: [2017-04-30 18:05:19,482] [594] - Stream server:Stream server: remove stream BB6FFAD [2017-04-30 18:05:19,488] [594] - CTsDuration::dtor [2017-04-30 18:05:19,489] [594] - TsMp2TFSMediaSubsession::dtor (K:\MePo1\recordings\KNTV HD\NBC Nightly News With Lester Holt\NBC Nightly News With Lester Holt - 2017-04-29.ts) I traced this back in the code and found that the CTsDuration instance - a necessary object used for keeping track of the stream duration - has the file open until this point. [USER=83973]@Owlsroost[/USER] According to the code history, it looks like the pulling in of TsReader's file handling in MP 1.16 PR has introduced a critical change in the duration calculation handling. Previously: [URL="https://github.com/MediaPortal/MediaPortal-1/blob/9595740a336776945bb8ec6da3c45dc473378270/DirectShowFilters/StreamingServer/Source/TsMPEG2TransportFileServerMediaSubsession.cpp"]MediaPortal-1/TsMPEG2TransportFileServerMediaSubsession.cpp at 9595740a336776945bb8ec6da3c45dc473378270 · MediaPortal/MediaPortal-1 · GitHub[/URL] Now: [URL="https://github.com/MediaPortal/MediaPortal-1/blob/master/DirectShowFilters/StreamingServer/Source/TsMPEG2TransportFileServerMediaSubsession.cpp"]MediaPortal-1/TsMPEG2TransportFileServerMediaSubsession.cpp at master · MediaPortal/MediaPortal-1 · GitHub[/URL] Note how in the old code the duration() and fileLength() members do: [code] FileReader *pFileDuration = OpenFileDuration(); if (pFileDuration) { // work here CloseFileDuration(pFileDuration); // return success result } // return fail result [/code] ...whereas the new code opens the file once when the CTsDuration instance is constructed, and only gets around to closing it in the CTsDuration destructor. The optimisation is a nice idea and seems to work fine for time-shift streams. However as Ron's log files show, it poses a problem for streaming of recordings. I'm surprised nobody using KODI as a front end has reported a problem because the KODI plugin creates streams for all recordings at TV Server startup. The current streaming server code would presumably prevent recordings from being deleted from the front end! Are you able to revise the streaming server code? [/QUOTE]
Insert quotes…
Verification
Post reply
Forums
MediaPortal 1
Support
Watch / Listen Media
Television (MyTV frontend and TV-Server)
MP1.16 RecordingFileHandler: Error while deleting a recording from disk.
Contact us
RSS
Top
Bottom