recent error when trying to view multi-hour recorded files (1 Viewer)

[mm1352000]

Hmmm, the log is different this time.
It took 4 whole minutes, but MediaInfo finally managed to read the details for the unplayable file:
[2016-02-16 21:04:59,920] [Log ] [MPMain ] [INFO ] - PlayRecording:J:\Recorded TV\WMTV-HD\NHL Hockey\NHL Hockey - 2016-02-14 - S- - E- - Boston Bruins at Detroit Red Wings.ts - using rtsp mode:False
[2016-02-16 21:04:59,925] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: Opening file : J:\Recorded TV\WMTV-HD\NHL Hockey\NHL Hockey - 2016-02-14 - S- - E- - Boston Bruins at Detroit Red Wings.ts
[2016-02-16 21:08:25,684] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: DLL Version : MediaInfoLib - v0.7.69
[collapse]
[2016-02-16 21:08:25,692] [Log ] [MPMain ] [INFO ] - MediaInfoWrapper.MediaInfoWrapper: Inspecting media : J:\Recorded TV\WMTV-HD\NHL Hockey\NHL Hockey - 2016-02-14 - S- - E- - Boston Bruins at Detroit Red Wings.ts
[2016-02-16 21:08:25,700] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: Parse speed : 0.3
[2016-02-16 21:08:25,707] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: FrameRate : 29.97
[2016-02-16 21:08:25,711] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: Width : 0
[2016-02-16 21:08:25,714] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: Height : 0
[2016-02-16 21:08:25,718] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: AspectRatio : widescreen
[2016-02-16 21:08:25,721] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: VideoCodec : MPEG VIDEO VERSION 2 MAIN@L4.0 [ "mpeg video version 2 main@l4.0.png" ]
[2016-02-16 21:08:25,723] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: Scan type :
[2016-02-16 21:08:25,726] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: IsInterlaced : False
[2016-02-16 21:08:25,728] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: VideoResolution : SD
[2016-02-16 21:08:25,731] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: VideoDuration : 8809
[2016-02-16 21:08:25,733] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: AudioRate : 48000
[2016-02-16 21:08:25,735] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: AudioChannels : 6 [ "5.1.png" ]
[2016-02-16 21:08:25,737] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: AudioCodec : AC-3 [ "ac-3.png" ]
[2016-02-16 21:08:25,739] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: HasAudio : True
[2016-02-16 21:08:25,742] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: HasVideo : True
[2016-02-16 21:08:25,744] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: HasSubtitles : False
[2016-02-16 21:08:25,747] [Log ] [MPMain ] [DEBUG] - MediaInfoWrapper.MediaInfoWrapper: NumSubtitles : 0[/collapse]

As you can see, MediaInfo thinks the recording is only 8.8 seconds long ("VideoDuration : 8809"). That's really odd for a recording that's meant to be multiple hours long. Something is seriously wrong here.

I note that the Windows system event log contains more HDD-related entries. This time they're for disk 1:
"2/16/2016 9:08:25 PM";"disk";"(0)";"Warning";"The IO operation at logical block address 0x266fbef7 for Disk 1 was retried.";"2147745945"
"2/16/2016 9:08:25 PM";"disk";"(0)";"Warning";"The IO operation at logical block address 0x266fbeff for Disk 1 was retried.";"2147745945"
"2/16/2016 9:08:25 PM";"disk";"(0)";"Warning";"The IO operation at logical block address 0x266fbf07 for Disk 1 was retried.";"2147745945"
etc.

...and they're happening right at the time MP is attempting to play the file.

To add to the weirdness, the USB drive seems to spontaneously disconnect and reconnect itself right around the time that MP attempts to play the file:
[collapse]
[2016-02-16 21:08:25,773] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
[2016-02-16 21:08:25,775] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: WD SES Device
[2016-02-16 21:08:25,777] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
[2016-02-16 21:08:25,779] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: WD My Passport 0730 USB Device
[2016-02-16 21:08:25,781] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
[2016-02-16 21:08:25,783] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: USB Mass Storage Device
[2016-02-16 21:08:25,785] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
[2016-02-16 21:08:25,787] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name:
[2016-02-16 21:08:25,789] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
[2016-02-16 21:08:25,790] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name:
[2016-02-16 21:08:25,792] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
[2016-02-16 21:08:25,794] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name:
...
[2016-02-16 21:08:26,437] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVNODES_CHANGED)
[2016-02-16 21:08:26,888] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
[2016-02-16 21:08:26,898] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: USB Mass Storage Device
[2016-02-16 21:08:27,105] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
[2016-02-16 21:08:27,124] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: WD My Passport 0730 USB Device
[2016-02-16 21:08:27,131] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
[2016-02-16 21:08:27,136] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: WD SES Device
[2016-02-16 21:08:27,148] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
[2016-02-16 21:08:27,150] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name:
[2016-02-16 21:08:27,431] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVNODES_CHANGED)
[2016-02-16 21:08:28,588] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
[2016-02-16 21:08:28,598] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name:
[2016-02-16 21:08:28,605] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
[2016-02-16 21:08:28,611] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name:
[2016-02-16 21:08:28,655] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVNODES_CHANGED)[/collapse]


With regard to the file "J:\Recorded TV\WMTV-HD\NHL Hockey\NHL Hockey - 2016-02-14 - S- - E- - Boston Bruins at Detroit Red Wings.ts"...
How big is the file?
Is this one of the ones that is playable in other software?
Are you able to simply copy the file off the USB drive onto the internal drive?
If yes, can the file be played from the internal drive?

You said this problem started the other day. Problems don't just start for no reason. Can you think of anything you changed at or around that time? Windows updates installed, device drivers updated, new deviced connected, new software installed...?

As I mentioned earlier, when recordings are unplayable, it's often because the recording is corrupted due to poor signal strength/quality at the time of the recording. Have you had bad weather recently? If yes, have you checked the state of your antenna/aerial?

 

[sieve]

As you can see, MediaInfo thinks the recording is only 8.8 seconds long ("VideoDuration : 8809"). That's really odd for a recording that's meant to be multiple hours long. Something is seriously wrong here.

Any idea why it would be misreading the length?

I note that the Windows system event log contains more HDD-related entries. This time they're for disk 1:
"2/16/2016 9:08:25 PM";"disk";"(0)";"Warning";"The IO operation at logical block address 0x266fbef7 for Disk 1 was retried.";"2147745945"
etc....and they're happening right at the time MP is attempting to play the file.

Disk 1 is the external HD that the video files reside on.

To add to the weirdness, the USB drive seems to spontaneously disconnect and reconnect itself right around the time that MP attempts to play the file

I can't think of a reason why it would. I assume that this doesn't happen in the first part of the log with the file that plays correctly?

How big is the file?

Approximately 19mb

Is this one of the ones that is playable in other software?

Yes, specifically VLC. It's a 3 hour recording that plays start to finish.

Are you able to simply copy the file off the USB drive onto the internal drive? If yes, can the file be played from the internal drive?

I should be able to copy it over. But I'll have to do this when I get back home later.

You said this problem started the other day. Problems don't just start for no reason. Can you think of anything you changed at or around that time? Windows updates installed, device drivers updated, new deviced connected, new software installed...?

There was probably Windows updates. Those seem to come out every Tuesday. Other than that, no changes.

As I mentioned earlier, when recordings are unplayable, it's often because the recording is corrupted due to poor signal strength/quality at the time of the recording. Have you had bad weather recently? If yes, have you checked the state of your antenna/aerial?

No bad weather. Both recordings (the one that plays in MP and the one that doesn't were over the air, with a HD antenna. Same channel. Approximately same time of day, just 1 week apart. And the one that doesn't play in MP plays fine using a different player (VLC).

I don't know if file size is the issue or if it's just a coincidence. But shorter length recordings continue to play normally.

The HD read errors and drive disconnects are a bit concerning. I don't know if that is a hardware problem, an OS problem, or a software (MP) problem. The fact that the file does play fine in a different program is confusing.

 

[mm1352000]

Any idea why it would be misreading the length?

If the file size is only 19 MB then I don't think the length is being misread. There's no way a 19 MB file could contain multiple hours of video. It'd be a couple minutes at most.

I can't think of a reason why it would. I assume that this doesn't happen in the first part of the log with the file that plays correctly?

Correct - it does not happen with the file that plays properly.

Yes, specifically VLC. It's a 3 hour recording that plays start to finish.

That can't be right. It's impossible that a 19 MB file would contain 3 hours of video. Are you sure the file size is not 19 GB?

No bad weather. Both recordings (the one that plays in MP and the one that doesn't were over the air, with a HD antenna. Same channel. Approximately same time of day, just 1 week apart. And the one that doesn't play in MP plays fine using a different player (VLC).

Okay.

I don't know if file size is the issue or if it's just a coincidence. But shorter length recordings continue to play normally.

From a MediaPortal perspective I can't formulate any explanation for longer recordings being unplayable, so I lean towards coincidence.
I'd at least expect consistency. Any given recording should be always playable... or always unplayable.

The HD read errors and drive disconnects are a bit concerning. I don't know if that is a hardware problem, an OS problem, or a software (MP) problem. The fact that the file does play fine in a different program is confusing.

I 100% agree - concerning and confusing.

Aside from the copy-to-internal HDD test and confirmation of the file size, there's one other test which would be useful. Up until now I've been unable to check the TV Server log files for errors during the recording process. So, the test would be to set up 2 new recordings - one short and one long; ideally on the same channel; ideally back-to-back or even overlapping - and see what happens. After the recordings complete, I'd want to confirm that the short recording plays fine and the long recording does not, and I'd also want to look at the TV Server log files. The TV Server log files are included by the Watchdog tool that you've been using, so you can use the same play-playable-followed-by-play-unplayable procedure with the Watchdog.

 

[sieve]

Update:
I've been doing all kinds of diagnostics on the system and hardware. All pass with good health.... which does not agree with all of the errors reported in the system log. So, I did the nuclear option and reinstalled OS. Now I have to reinstall all the software and settings. Once that's done, I'll see if this problem still exists and figure out what to do next.

 

[sieve]

Update:
Upgrading the OS did not solve the problem. I got a new internal HD and reinstalled everything onto it. After that, no more problems.
I guess the lesson is, take the SMART diagnostics for HDDs with some skepticism.

Thanks for your assistance.