Ticket #1036: mythfrontend.debug.lockup

File mythfrontend.debug.lockup, 16.6 KB (added by anonymous, 20 years ago)
Line 
12006-01-15 07:48:57.361 write -> 16 21 MYTH_PROTO_VERSION 23
22006-01-15 07:48:57.424 read <- 16 13 ACCEPT[]:[]23
32006-01-15 07:48:57.425 write -> 16 27 ANN Playback pvr.home.net 0
42006-01-15 07:48:57.448 read <- 16 2 OK
52006-01-15 07:48:57.449 write -> 16 81 QUERY_RECORDER 1[]:[]SPAWN_LIVETV[]:[]live-pvr.home.net-2006-01-1...
62006-01-15 07:48:58.360 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
72006-01-15 07:48:58.507 read <- 16 2 ok
82006-01-15 07:48:58.521 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): ReloadAll(): Added new recording
92006-01-15 07:48:58.535 RingBuf(myth://127.0.0.1:6543/1002_20060115074858.mpg): OpenFile(myth://127.0.0.1:6543/1002_20060115074858.mpg, 6)
102006-01-15 07:48:58.536 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
112006-01-15 07:48:58.547 Invalid file handle when opening /video/recordings/1002_20060115074858.mpg. 6 retries remaining.
122006-01-15 07:48:59.051 Invalid file handle when opening /video/recordings/1002_20060115074858.mpg. 5 retries remaining.
132006-01-15 07:48:59.553 write -> 16 33 QUERY_RECORDER 1[]:[]IS_RECORDING
142006-01-15 07:48:59.563 read <- 16 1 1
152006-01-15 07:48:59.564 write -> 16 33 QUERY_RECORDER 1[]:[]IS_RECORDING
162006-01-15 07:48:59.574 read <- 16 1 1
172006-01-15 07:48:59.575 TV: StartRecorder(): took 22 ms to start recorder.
182006-01-15 07:48:59.578 TV: GetLockTimeout(1): Set lock timeout to 4294967295 ms
192006-01-15 07:48:59.578 write -> 16 34 QUERY_RECORDER 1[]:[]GET_FRAMERATE
202006-01-15 07:48:59.588 read <- 16 5 29.97
212006-01-15 07:48:59.632 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
222006-01-15 07:48:59.642 read <- 13 2 OK
232006-01-15 07:48:59.642 TV: Output filters for this channel are: ''
242006-01-15 07:48:59.647 detectInterlace(Ignore Scan, Detect Scan, 29.97, 480) ->Ignore Scan
252006-01-15 07:48:59.648 Interlaced: Ignore Scan video_height: 480 fps: 29.97
262006-01-15 07:48:59.648 RingBuf:CalcReadAheadThresh(8000 KB) -> threshhold(250 KB) readblocksize(125 KB)
272006-01-15 07:48:59.648 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
282006-01-15 07:48:59.651 Position map filled from DB to: 1
292006-01-15 07:48:59.653 SyncPositionMap watchingrecording, from DB: 1 entries
302006-01-15 07:48:59.654 write -> 16 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
312006-01-15 07:48:59.658 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
322006-01-15 07:48:59.664 read <- 16 7 0[]:[]0
332006-01-15 07:48:59.665 PosMapFromEnc: Warning, tried to fetch PositionMap from Encoder but encoder returned framesWritten == 0
342006-01-15 07:48:59.665 SyncPositionMap watchingrecording no entries from encoder, try DB
352006-01-15 07:48:59.667 Position map filled from DB to: 1
362006-01-15 07:48:59.668 SyncPositionMap watchingrecording total: 1 entries
372006-01-15 07:48:59.669 SyncPositionMap, new totframes: 15, new length: 0, posMap size: 1
382006-01-15 07:48:59.669 Partial position map found
392006-01-15 07:48:59.671 NVP: Disabling Audio, params(16,2,0)
402006-01-15 07:48:59.672 IVD: Init() -- begin
412006-01-15 07:48:59.672 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
422006-01-15 07:48:59.688 Snapping height to avoid scaling: disphoff 480, dispyoff: 0
432006-01-15 07:48:59.701 Snapping width to avoid scaling: dispwoff 720, dispxoff: 0
442006-01-15 07:48:59.701 Image size. dispxoff 0, dispyoff: 0, dispwoff: 720, disphoff: 480
452006-01-15 07:48:59.701 Image size. imgx 0, imgy: 0, imgw: 720, imgh: 480
462006-01-15 07:48:59.701 Snapping height to avoid scaling: disphoff 480, dispyoff: 0
472006-01-15 07:48:59.701 Snapping width to avoid scaling: dispwoff 720, dispxoff: 0
482006-01-15 07:48:59.701 Image size. dispxoff 0, dispyoff: 0, dispwoff: 720, disphoff: 480
492006-01-15 07:48:59.701 Image size. imgx 0, imgy: 0, imgw: 720, imgh: 480
502006-01-15 07:48:59.701 IVD: Open() -- begin
512006-01-15 07:48:59.702 IVD: Open() -- end
522006-01-15 07:48:59.788 Using the PVR-350 decoder/TV-out
532006-01-15 07:48:59.789 IVD: Init() -- end
542006-01-15 07:49:00.356 NVP: ClearAfterSeek()
552006-01-15 07:49:00.357 TV: StartPlayer(): took 715 ms to start player.
562006-01-15 07:49:00.357 TV: Changing from None to WatchingLiveTV
572006-01-15 07:49:00.360 write -> 16 35 QUERY_RECORDER 1[]:[]FRONTEND_READY
582006-01-15 07:49:00.360 The realtime priority setting is not enabled.
592006-01-15 07:49:00.392 read <- 16 2 ok
602006-01-15 07:49:00.688 keyframedist changed to 15
612006-01-15 07:51:22.833 write -> 16 47 QUERY_RECORDER 1[]:[]CHECK_CHANNEL_PREFIX[]:[]1
622006-01-15 07:51:22.971 read <- 16 7 1[]:[]0
632006-01-15 07:51:23.438 write -> 16 48 QUERY_RECORDER 1[]:[]CHECK_CHANNEL_PREFIX[]:[]11
642006-01-15 07:51:23.453 read <- 16 7 1[]:[]0
652006-01-15 07:51:25.987 TV: CommitQueuedInput() livetv(1) qchannum(11) qchanid(0)
662006-01-15 07:51:25.987 write -> 16 41 QUERY_RECORDER 1[]:[]CHECK_CHANNEL[]:[]11
672006-01-15 07:51:26.001 read <- 16 1 1
682006-01-15 07:51:26.001 TV: ChangeChannel(0, '11')
692006-01-15 07:51:26.001 write -> 16 48 QUERY_RECORDER 1[]:[]CHECK_CHANNEL_PREFIX[]:[]11
702006-01-15 07:51:26.015 read <- 16 7 1[]:[]0
712006-01-15 07:51:26.015 write -> 16 41 QUERY_RECORDER 1[]:[]CHECK_CHANNEL[]:[]11
722006-01-15 07:51:26.027 read <- 16 1 1
732006-01-15 07:51:26.027 TV: PauseLiveTV()
742006-01-15 07:51:26.085 NVP: Changing speed to 0
752006-01-15 07:51:26.086 IVD: Pause() -- begin
762006-01-15 07:51:26.097 IVD: Pause() -- end
772006-01-15 07:51:26.098 rate: 29.97 speed: 1 skip: 1 = interval 33366
782006-01-15 07:51:26.099 write -> 16 26 QUERY_RECORDER 1[]:[]PAUSE
792006-01-15 07:51:26.111 read <- 16 2 ok
802006-01-15 07:51:26.111 write -> 16 39 QUERY_RECORDER 1[]:[]SET_CHANNEL[]:[]11
812006-01-15 07:51:29.158 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
822006-01-15 07:51:29.926 read <- 16 2 ok
832006-01-15 07:51:29.926 TV: UnpauseLiveTV()
842006-01-15 07:51:29.929 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): ReloadAll(): Added new recording
852006-01-15 07:51:29.933 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(-1)
862006-01-15 07:51:29.934 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@1: '1011_20060115075129'
872006-01-15 07:51:29.934 TV: Output filters for this channel are: ''
882006-01-15 07:51:29.934 NVP: Play( 1.0, normal 1, unpause audio 0)
892006-01-15 07:51:29.935 NVP: Changing speed to 1
902006-01-15 07:51:29.935 NVP: DoPlay: rate: 29.97 speed: 1 skip: 1 => new interval 33366
912006-01-15 07:51:29.935 IVD: Play(1, 1, 2)
922006-01-15 07:51:29.985 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
932006-01-15 07:51:29.999 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
942006-01-15 07:51:30.028 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
952006-01-15 07:51:30.031 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
962006-01-15 07:51:30.033 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(1)
972006-01-15 07:51:30.033 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@1: '1011_20060115075129'
982006-01-15 07:51:30.137 Position map filled from DB to: 294
992006-01-15 07:51:30.137 SyncPositionMap watchingrecording, from DB: 294 entries
1002006-01-15 07:51:30.137 SyncPositionMap watchingrecording no entries from encoder, try DB
1012006-01-15 07:51:30.139 read <- 13 2 OK
1022006-01-15 07:51:30.162 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
1032006-01-15 07:51:30.168 Position map filled from DB to: 294
1042006-01-15 07:51:30.169 SyncPositionMap watchingrecording total: 294 entries
1052006-01-15 07:51:30.169 SyncPositionMap, new totframes: 4410, new length: 147, posMap size: 294
1062006-01-15 07:51:30.174 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1072006-01-15 07:51:30.177 read <- 13 2 OK
1082006-01-15 07:51:30.179 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1092006-01-15 07:51:30.182 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1102006-01-15 07:51:30.187 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1112006-01-15 07:51:30.211 RingBuf(/video/recordings/1002_20060115074858.mpg): OpenFile(myth://127.0.0.1:6543/1011_20060115075129.mpg, 4)
1122006-01-15 07:51:30.211 NVP: ClearAfterSeek()
1132006-01-15 07:51:30.211 IVD: SeekReset(0, 0, do flush, do discard)
1142006-01-15 07:51:30.212 IVD: Stop(0) -- begin
1152006-01-15 07:51:30.236 IVD: Stop(0) -- end
1162006-01-15 07:51:30.237 IVD: Flush()
1172006-01-15 07:51:30.237 IVD: Start(0 skipped, 5 muted) -- begin
1182006-01-15 07:51:30.237 IVD: Start(0 skipped, 5 muted) -- end
1192006-01-15 07:51:30.237 IVD: Play(1, 1, 2)
1202006-01-15 07:51:30.297 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(1)
1212006-01-15 07:51:30.299 Position map filled from DB to: 6
1222006-01-15 07:51:30.299 SyncPositionMap watchingrecording, from DB: 6 entries
1232006-01-15 07:51:30.299 write -> 16 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
1242006-01-15 07:51:30.346 read <- 16 9 0[]:[]105
1252006-01-15 07:51:30.347 Filling position map from 7 to 7
1262006-01-15 07:51:30.347 write -> 16 50 QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]7[]:[]7
1272006-01-15 07:51:30.550 read <- 16 25 0[]:[]7[]:[]0[]:[]4573248
1282006-01-15 07:51:30.550 Position map filled from Encoder to: 7
1292006-01-15 07:51:30.550 SyncPositionMap watchingrecording total: 7 entries
1302006-01-15 07:51:30.550 SyncPositionMap, new totframes: 105, new length: 3, posMap size: 7
1312006-01-15 08:00:01.364 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1322006-01-15 08:00:01.452 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1332006-01-15 08:00:01.472 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): ReloadAll(): Added new recording
1342006-01-15 08:00:01.473 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
1352006-01-15 08:00:01.572 Position map filled from DB to: 1016
1362006-01-15 08:00:01.572 SyncPositionMap watchingrecording, from DB: 1016 entries
1372006-01-15 08:00:01.572 SyncPositionMap watchingrecording no entries from encoder, try DB
1382006-01-15 08:00:01.599 Position map filled from DB to: 1017
1392006-01-15 08:00:01.599 SyncPositionMap watchingrecording total: 1017 entries
1402006-01-15 08:00:01.604 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1412006-01-15 08:00:01.709 read <- 15 46 BACKEND_MESSAGE[]:[]LIVETV_WATCH 1 0[]:[]empty
1422006-01-15 08:00:03.069 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1432006-01-15 08:00:03.475 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(2)
1442006-01-15 08:00:03.475 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@2: '1011_20060115080001'
1452006-01-15 08:00:03.842 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(2)
1462006-01-15 08:00:03.843 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@2: '1011_20060115080001'
1472006-01-15 08:00:04.207 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(2)
1482006-01-15 08:00:04.208 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@2: '1011_20060115080001'
1492006-01-15 08:00:04.572 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(2)
1502006-01-15 08:00:04.573 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@2: '1011_20060115080001'
1512006-01-15 08:00:04.839 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
1522006-01-15 08:00:04.852 read <- 13 2 OK
1532006-01-15 08:00:04.856 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
1542006-01-15 08:00:04.870 read <- 13 2 OK
1552006-01-15 08:00:04.874 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1562006-01-15 08:00:04.876 RingBuf(/video/recordings/1011_20060115075129.mpg): OpenFile(myth://127.0.0.1:6543/1011_20060115080001.mpg, 10)
1572006-01-15 08:00:04.880 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1582006-01-15 08:00:05.103 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(1)
1592006-01-15 08:00:05.105 Position map filled from DB to: 1
1602006-01-15 08:00:05.106 SyncPositionMap watchingrecording, from DB: 1 entries
1612006-01-15 08:00:05.106 write -> 16 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
1622006-01-15 08:00:05.118 read <- 16 8 0[]:[]60
1632006-01-15 08:00:05.118 Filling position map from 2 to 4
1642006-01-15 08:00:05.118 write -> 16 50 QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]2[]:[]4
1652006-01-15 08:00:05.139 read <- 16 85 0[]:[]2[]:[]0[]:[]1472512[]:[]0[]:[]3[]:[]0[]:[]2154496[]:[]0[]:[...
1662006-01-15 08:00:05.139 Position map filled from Encoder to: 4
1672006-01-15 08:00:05.139 SyncPositionMap watchingrecording total: 4 entries
1682006-01-15 08:00:05.140 SyncPositionMap, new totframes: 60, new length: 2, posMap size: 4
1692006-01-15 08:00:08.377 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1702006-01-15 08:00:16.958 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1712006-01-15 08:30:10.446 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1722006-01-15 08:30:18.988 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1732006-01-15 09:00:01.258 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1742006-01-15 09:00:01.374 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1752006-01-15 09:00:01.518 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1762006-01-15 09:00:01.520 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): ReloadAll(): Added new recording
1772006-01-15 09:00:01.521 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
1782006-01-15 09:00:01.892 Position map filled from DB to: 7175
1792006-01-15 09:00:01.895 SyncPositionMap watchingrecording, from DB: 7175 entries
1802006-01-15 09:00:01.895 SyncPositionMap watchingrecording no entries from encoder, try DB
1812006-01-15 09:00:02.080 Position map filled from DB to: 7191
1822006-01-15 09:00:02.083 SyncPositionMap watchingrecording total: 7191 entries
1832006-01-15 09:00:02.091 read <- 15 46 BACKEND_MESSAGE[]:[]LIVETV_WATCH 1 0[]:[]empty
1842006-01-15 09:00:02.396 read <- 15 87 BACKEND_MESSAGE[]:[]LIVETV_CHAIN UPDATE live-pvr.home.net-2006-01...
1852006-01-15 09:00:03.129 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(3)
1862006-01-15 09:00:03.130 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@3: '1011_20060115090001'
1872006-01-15 09:00:03.494 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(3)
1882006-01-15 09:00:03.494 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@3: '1011_20060115090001'
1892006-01-15 09:00:03.859 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(3)
1902006-01-15 09:00:03.859 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@3: '1011_20060115090001'
1912006-01-15 09:00:04.225 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(3)
1922006-01-15 09:00:04.225 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@3: '1011_20060115090001'
1932006-01-15 09:00:04.590 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): SwitchTo(3)
1942006-01-15 09:00:04.590 LiveTVChain(live-pvr.home.net-2006-01-15T07:48:57): Entry@3: '1011_20060115090001'
1952006-01-15 09:00:04.641 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
1962006-01-15 09:00:04.655 read <- 13 2 OK
1972006-01-15 09:00:04.658 write -> 13 33 MESSAGE[]:[]RECORDING_LIST_CHANGE
1982006-01-15 09:00:04.686 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
1992006-01-15 09:00:04.693 read <- 13 2 OK
2002006-01-15 09:00:04.704 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2012006-01-15 09:00:04.707 RingBuf(/video/recordings/1011_20060115080001.mpg): OpenFile(myth://127.0.0.1:6543/1011_20060115090001.mpg, 10)
2022006-01-15 09:00:12.807 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2032006-01-15 09:00:21.180 read <- 15 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
2042006-01-15 09:08:41.161 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(1)
2052006-01-15 09:08:41.257 Position map filled from DB to: 1016
2062006-01-15 09:08:41.257 SyncPositionMap watchingrecording, from DB: 1016 entries
2072006-01-15 09:08:41.257 write -> 16 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
2082006-01-15 09:08:41.272 read <- 16 11 0[]:[]15540
2092006-01-15 09:08:41.272 Filling position map from 1017 to 1036
2102006-01-15 09:08:41.272 write -> 16 56 QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]1017[]:[]1036
2112006-01-15 09:08:41.283 read <- 16 695 0[]:[]1017[]:[]0[]:[]684455936[]:[]0[]:[]1018[]:[]0[]:[]685117440...
2122006-01-15 09:08:41.284 Position map filled from Encoder to: 1036
2132006-01-15 09:08:41.284 SyncPositionMap watchingrecording total: 1036 entries
2142006-01-15 09:08:41.284 SyncPositionMap, new totframes: 15540, new length: 518, posMap size: 1036