[mythtv-users] Problems playing old recordings on 0.20

[Matt Wright]

Hi,

I upgraded my myth setup to 0.20 the other day and since then none of  
the recordings made during 0.19 will play anymore. The frontend  
switches to a blank screen and then the video never appears, also the  
video preview doesn't appear in the recordings listing. I've checked  
the obvious things (file exists, is accessibly by the backend, is  
playable in a media player, recordings table entry looks sane, etc).  
I also checked that this happens on the linux frontend (all my  
usually frontends are run on macs) which it does.

A couple of days after the upgrade I noticed that the 0.20 recordings  
all work ok, something I'd missed at the start as the backend hadn't  
had time to record anything. I had a play and moved one of the 0.19  
recording files to the name of a 0.20 recording and that wouldn't  
play. So it points to something to do with the file or file format.

I've included what I hope are some interesting bits of the frontend/ 
backend logs, I can include a full log of either if needed.

The frontend does this:

2006-09-18 15:03:32.490 TV: Attempting to change from None to  
WatchingPreRecorded
0: start_time: 5265.165 duration: 188.942
1: start_time: 5265.109 duration: 188.955
2: start_time: 5265.107 duration: 188.957
3: start_time: 5265.107 duration: 189.000
stream: start_time: 58501.185 duration: 2100.005 bitrate=3195 kb/s
2006-09-18 15:03:33.350 AFD: Opened codec 0x1926610, id(MPEG2VIDEO)  
type(Video)
2006-09-18 15:03:33.361 AFD: Opened codec 0x1923010, id(MP3) type(Audio)
2006-09-18 15:03:33.362 AFD: Opened codec 0x1923410, id(MP3) type(Audio)
2006-09-18 15:03:33.362 AFD: Opened codec 0x1928a10, id(MPEG2VIDEO)  
type(Video)
2006-09-18 15:03:35.537 TV: Changing from None to WatchingPreRecorded
2006-09-18 15:03:35.540 Video timing method: USleep with busy wait
2006-09-18 15:03:36.871 NVP: Prebuffer wait timed out 10 times.
2006-09-18 15:03:38.202 NVP: Prebuffer wait timed out 10 times.
2006-09-18 15:03:39.533 NVP: Prebuffer wait timed out 10 times.
2006-09-18 15:03:40.864 NVP: Prebuffer wait timed out 10 times.

This last line then repeats till you kill the frontend or it gets fed  
up and goes back to the recordings screen.

The backend logs (-v all,nodatabase,notimestamp)

2006-09-18 15:03:29.628 Local file path: /filestore/one/TV// 
1010_20060810230500.mpg
2006-09-18 15:03:29.628 write -> 16 1       1
2006-09-18 15:03:29.629 MythSocket(81b4170:16): DownRef: 1
2006-09-18 15:03:29.713 MythSocket(81b7098:21): new socket
2006-09-18 15:03:29.713 MythSocket(81b7098:21): setSocket: 20
2006-09-18 15:03:29.713 MythSocket(81b7098:20): state change Idle ->  
Connected
2006-09-18 15:03:29.715 MythSocket(81b7098:20): UpRef: 1
2006-09-18 15:03:29.719 MythSocket(81b7098:20): socket is readable
2006-09-18 15:03:29.719 MythSocket(81b7098:20): cb->readyRead()
2006-09-18 15:03:29.719 MythSocket(81b7098:20): UpRef: 2
2006-09-18 15:03:29.720 read  <- 20 31      ANN Playback  
caesium.internal 0
2006-09-18 15:03:29.720 MainServer::HandleAnnounce Playback
2006-09-18 15:03:29.720 adding: caesium.internal as a client (events: 0)
2006-09-18 15:03:29.720 write -> 20 2       OK
2006-09-18 15:03:29.720 MythSocket(81b7098:20): DownRef: 1
2006-09-18 15:03:29.721 MythSocket(81bc808:22): new socket
2006-09-18 15:03:29.721 MythSocket(81bc808:22): setSocket: 21
2006-09-18 15:03:29.721 MythSocket(81bc808:21): state change Idle ->  
Connected
2006-09-18 15:03:29.722 MythSocket(81bc808:21): UpRef: 1
2006-09-18 15:03:29.722 MythSocket(81bc808:21): socket is readable
2006-09-18 15:03:29.722 MythSocket(81bc808:21): cb->readyRead()
2006-09-18 15:03:29.722 MythSocket(81bc808:21): UpRef: 2
2006-09-18 15:03:29.722 read  <- 21 67      ANN FileTransfer  
caesium.internal 1 -1[]:[]/1010_20060810230500.mpg
2006-09-18 15:03:29.723 MainServer::HandleAnnounce FileTransfer
2006-09-18 15:03:29.723 adding: caesium.internal as a remote file  
transfer
2006-09-18 15:03:29.723 Local file path: /filestore/one/TV// 
1010_20060810230500.mpg
2006-09-18 15:03:29.724 RingBuf(/filestore/one/TV// 
1010_20060810230500.mpg): OpenFile(/filestore/one/TV// 
1010_20060810230500.mpg, 12)
2006-09-18 15:03:29.724 RingBuf(/filestore/one/TV// 
1010_20060810230500.mpg): CalcReadAheadThresh(4000 KB)
                          -> threshhold(146 KB) min read(32 KB) blk  
size(64 KB)
2006-09-18 15:03:29.724 write -> 21 29      OK[]:[]21[]:[]0[]:[] 
838944924
2006-09-18 15:03:29.725 MythSocket(81bc808:21): DownRef: 1
2006-09-18 15:03:29.772 MythSocket(81b4170:16): socket is readable
2006-09-18 15:03:29.772 MythSocket(81b4170:16): cb->readyRead()
2006-09-18 15:03:29.772 MythSocket(81b4170:16): UpRef: 2
2006-09-18 15:03:29.773 read  <- 16 33      MESSAGE[]:[] 
RECORDING_LIST_CHANGE
2006-09-18 15:03:29.774 write -> 16 2       OK
2006-09-18 15:03:29.775 MythSocket(81b4170:16): DownRef: 1
2006-09-18 15:03:29.776 MythSocket(81b4170:16): UpRef: 2
2006-09-18 15:03:29.776 MythSocket(81b4170:16): DownRef: 1
2006-09-18 15:03:29.777 MythSocket(81b6f50:19): UpRef: 2
2006-09-18 15:03:29.778 write -> 19 51      BACKEND_MESSAGE[]:[] 
RECORDING_LIST_CHANGE[]:[]empty
2006-09-18 15:03:29.779 MythSocket(81b6f50:19): DownRef: 1
2006-09-18 15:03:29.780 MythSocket(81b7098:20): UpRef: 2
2006-09-18 15:03:29.780 MythSocket(81b7098:20): DownRef: 1
2006-09-18 15:03:29.788 MythSocket(81b7098:20): socket is readable
2006-09-18 15:03:29.788 MythSocket(81b7098:20): cb->readyRead()
2006-09-18 15:03:29.788 MythSocket(81b7098:20): UpRef: 2
2006-09-18 15:03:29.788 read  <- 20 49      QUERY_FILETRANSFER 21[]:[] 
REQUEST_BLOCK[]:[]32768
2006-09-18 15:03:29.794 write -> 20 5       32768
2006-09-18 15:03:29.794 MythSocket(81b7098:20): DownRef: 1
2006-09-18 15:03:29.795 MythSocket(81b7098:20): socket is readable
2006-09-18 15:03:29.795 MythSocket(81b7098:20): cb->readyRead()
2006-09-18 15:03:29.796 MythSocket(81b7098:20): UpRef: 2

This last block (the QUERY_FILETRANSFER) then repeats until the  
frontend is closed.

Any ideas?

Mat