Ticket #2493: baskend-full

File baskend-full, 13.4 KB (added by ajlill@…, 14 years ago)

Full trace

Line 
12006-09-28 03:27:06.688 [-1314714704] AutoExpire: Adding Programs to 'Do Not Expire' List
22006-09-28 03:27:06.699 [-1314714704]     3275 @ Thu Sep 28 02:00:00 2006 in use by flagger on freevo
32006-09-28 03:27:48.873 [-1398600784] MythSocket(862d388:17): socket is readable
42006-09-28 03:27:48.896 [-1398600784] MythSocket(862d388:17): cb->readyRead()
52006-09-28 03:27:48.897 [-1398600784] MythSocket(862d388:17): UpRef: 2
62006-09-28 03:27:48.898 [-1356657744] read  <- 17 33      MESSAGE[]:[]RECORDING_LIST_CHANGE
72006-09-28 03:27:48.899 [-1356657744] write -> 17 2       OK
82006-09-28 03:27:48.900 [-1356657744] MythSocket(862d388:17): DownRef: 1
92006-09-28 03:27:48.900 [-1254958752] MythSocket(8a38b80:18): UpRef: 2
102006-09-28 03:27:48.902 [-1254958752] MythSocket(8a38b80:18): DownRef: 1
112006-09-28 03:27:48.903 [-1254958752] MythSocket(88f6238:19): UpRef: 2
122006-09-28 03:27:48.904 [-1254958752] write -> 19 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
132006-09-28 03:27:48.904 [-1254958752] MythSocket(88f6238:19): DownRef: 1
142006-09-28 03:27:48.905 [-1254958752] MythSocket(88f4510:23): UpRef: 2
152006-09-28 03:27:48.906 [-1254958752] write -> 23 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
162006-09-28 03:27:48.907 [-1254958752] MythSocket(88f4510:23): DownRef: 1
172006-09-28 03:27:48.908 [-1254958752] MythSocket(862d388:17): UpRef: 2
182006-09-28 03:27:48.908 [-1254958752] MythSocket(862d388:17): DownRef: 1
192006-09-28 03:27:48.909 [-1254958752] MythSocket(87e11c8:20): UpRef: 2
202006-09-28 03:27:48.910 [-1254958752] write -> 20 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
212006-09-28 03:27:48.911 [-1254958752] MythSocket(87e11c8:20): DownRef: 1
222006-09-28 03:27:49.011 [-1398600784] MythSocket(862d388:17): socket is readable
232006-09-28 03:27:49.089 [-1398600784] MythSocket(862d388:17): socket closed
242006-09-28 03:27:49.090 [-1398600784] MythSocket(862d388:17): state change Connected -> Idle
252006-09-28 03:27:49.091 [-1398600784] MythSocket(862d388:-1): cb->connectionClosed()
262006-09-28 03:27:49.241 [-1398600784] MythSocket(87e11c8:20): socket is readable
272006-09-28 03:27:49.242 [-1398600784] MythSocket(87e11c8:20): socket closed
282006-09-28 03:27:49.243 [-1398600784] MythSocket(87e11c8:20): state change Connected -> Idle
292006-09-28 03:27:49.244 [-1398600784] MythSocket(87e11c8:-1): cb->connectionClosed()
300: start_time: 0.036 duration: 334.144
311: start_time: 0.026 duration: 334.115
32stream: start_time: 0.289 duration: 3712.820 bitrate=5190 kb/s
332006-09-28 03:27:49.348 [-1523582032] commflag: Commercial Flagging Finished: Life on Mars recorded from channel 3275 at Thu Sep 28 02:00:00 2006: 6 commercial break(s)
342006-09-28 03:27:49.366 [-1523582032] JobQueue: Commercial Flagging Finished, 6 break(s) found.
352006-09-28 03:27:49.367 [-1254958752] MythSocket(8a38b80:18): UpRef: 2
362006-09-28 03:27:49.369 [-1254958752] MythSocket(8a38b80:18): DownRef: 1
372006-09-28 03:27:49.369 [-1254958752] MythSocket(88f6238:19): UpRef: 2
382006-09-28 03:27:49.370 [-1254958752] write -> 19 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
392006-09-28 03:27:49.371 [-1254958752] MythSocket(88f6238:19): DownRef: 1
402006-09-28 03:27:49.372 [-1254958752] MythSocket(88f4510:23): UpRef: 2
412006-09-28 03:27:49.373 [-1254958752] write -> 23 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
422006-09-28 03:27:49.373 [-1254958752] MythSocket(88f4510:23): DownRef: 1
432006-09-28 03:27:49.370 [-1523582032] RingBuf(/u/myth/3275_20060928020000.mpg): OpenFile(/u/myth/3275_20060928020000.mpg, 0)
442006-09-28 03:27:49.395 [-1523582032] RingBuf(/u/myth/3275_20060928020000.mpg): CalcReadAheadThresh(4000 KB)
45                         -> threshhold(146 KB) min read(32 KB) blk size(64 KB)
460: start_time: 0.036 duration: 334.144
471: start_time: 0.026 duration: 334.115
48stream: start_time: 0.289 duration: 3712.820 bitrate=5190 kb/s
492006-09-28 03:27:49.505 [-1523582032] AFD: Stream #0, has id 0x480 codec id MPEG2VIDEO, type Video, bitrate 6000000 at 0x0x8d98ae0
502006-09-28 03:27:49.531 [-1523582032] detectInterlace(Detect Scan, Interlaced Scan, 29.97, 480) ->Interlaced Scan
512006-09-28 03:27:49.533 [-1523582032] AFD: Looking for decoder for MPEG2VIDEO
522006-09-28 03:27:49.533 [-1523582032] AFD: Opened codec 0x89c3a10, id(MPEG2VIDEO) type(Video)
532006-09-28 03:27:49.534 [-1523582032] AFD: Stream #1, has id 0x448 codec id MP2, type Audio, bitrate 384000 at 0x0x8e16bc0
542006-09-28 03:27:49.535 [-1523582032] AFD: Looking for decoder for MP2
552006-09-28 03:27:49.535 [-1523582032] AFD: Opened codec 0x8f106c0, id(MP2) type(Audio)
562006-09-28 03:27:49.536 [-1523582032] AFD: Audio Track #1 is A/V stream #1 and has 2 channels in the Unknown language(0).
572006-09-28 03:27:49.537 [-1523582032] RingBuf(/u/myth/3275_20060928020000.mpg): CalcReadAheadThresh(6384 KB)
58                         -> threshhold(233 KB) min read(32 KB) blk size(128 KB)
592006-09-28 03:27:49.537 [-1523582032] AFD: Selected track 1: Unknown MP2 2ch (A/V Stream #1)
602006-09-28 03:27:49.538 [-1523582032] AFD: Initializing audio parms from audio track #1
612006-09-28 03:27:49.539 [-1523582032] AFD: Audio format changed
62                        from id(NONE)    -1Hz -1ch   0bps    ; id(NONE)    -1Hz -1ch   0bps   
63                        to   id( MP2) 48000Hz  2ch  16bps    ; id( MP2) 48000Hz  2ch  16bps   
642006-09-28 03:27:49.539 [-1523582032] Dec: Trying to select track (w/lang)
652006-09-28 03:27:49.540 [-1523582032] Dec: Selecting first track
662006-09-28 03:27:49.541 [-1523582032] Dec: Selected track #1 in the Unknown language(0)
672006-09-28 03:27:49.542 [-1523582032] Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0)
682006-09-28 03:27:49.602 [-1523582032] Position map filled from DB to: 7419
692006-09-28 03:27:49.613 [-1523582032] SyncPositionMap prerecorded, from DB: 7419 entries
702006-09-28 03:27:49.625 [-1523582032] SyncPositionMap, new totframes: 111285, new length: 3713, posMap size: 7419
71Input #0, mpeg, from '/u/myth/3275_20060928020000.mpg':
72  Duration: 01:01:52.8, start: 0.289467, bitrate: 5190 kb/s
73  Stream #0.0[0x1e0], 1/90000: Video: mpeg2video, yuv420p, 480x480, 1001/30000, 6000 kb/s, 29.97 fps(r)
74  Stream #0.1[0x1c0], 1/90000: Audio: mp2, 48000 Hz, stereo, 384 kb/s
752006-09-28 03:27:49.671 [-1523582032] AFD: Position map found
762006-09-28 03:27:49.672 [-1523582032] AFD: Successfully opened decoder for file: "/u/myth/3275_20060928020000.mpg". novideo(0)
772006-09-28 03:27:49.676 [-1523582032] VideoOutputNull()
782006-09-28 03:27:49.677 [-1523582032] Display Rect  left: 0, top: 0, width: 0, height: 0, aspect: 1.33333
792006-09-28 03:27:49.678 [-1523582032] Video Rect    left: 0, top: 0, width: 480, height: 480, aspect: 1.33333
802006-09-28 03:27:49.679 [-1523582032] Created data @0x8e4d8d0->0x8ea1ed2
812006-09-28 03:27:49.680 [-1523582032] Created data @0x8ea9690->0x8efdc92
822006-09-28 03:27:49.681 [-1523582032] Created data @0x8c93b90->0x8ce8192
832006-09-28 03:27:49.682 [-1523582032] Created data @0x8beaec0->0x8c3f4c2
842006-09-28 03:27:49.683 [-1523582032] Created data @0x8c3f520->0x8c93b22
852006-09-28 03:27:49.683 [-1523582032] Created data @0x81bdbf0->0x82121f2
862006-09-28 03:27:49.690 [-1523582032] Created data @0x8212250->0x8266852
872006-09-28 03:27:49.691 [-1523582032] Created data @0x82668c0->0x82baec2
882006-09-28 03:27:49.692 [-1523582032] Created data @0xac1dc020->0xac230622
892006-09-28 03:27:49.692 [-1523582032] Created data @0xac187020->0xac1db622
902006-09-28 03:27:49.693 [-1523582032] Created data @0xac132020->0xac186622
912006-09-28 03:27:49.694 [-1523582032] Created data @0xac0dd020->0xac131622
922006-09-28 03:27:49.695 [-1523582032] Created data @0xac088020->0xac0dc622
932006-09-28 03:27:49.695 [-1523582032] Created data @0xac033020->0xac087622
942006-09-28 03:27:49.696 [-1523582032] Created data @0xabeab020->0xabeff622
952006-09-28 03:27:49.697 [-1523582032] Created data @0xabe56020->0xabeaa622
962006-09-28 03:27:49.697 [-1523582032] Created data @0xabe01020->0xabe55622
972006-09-28 03:27:49.698 [-1523582032] Created data @0xabcab020->0xabcff622
982006-09-28 03:27:49.699 [-1523582032] Created data @0xabc56020->0xabcaa622
992006-09-28 03:27:49.700 [-1523582032] Created data @0xabc01020->0xabc55622
1002006-09-28 03:27:49.700 [-1523582032] Created data @0xabaab020->0xabaff622
1012006-09-28 03:27:49.701 [-1523582032] Created data @0xaba56020->0xabaaa622
1022006-09-28 03:27:49.701 [-1523582032] Created data @0xab6ab020->0xab6ff622
1032006-09-28 03:27:49.702 [-1523582032] Created data @0xab656020->0xab6aa622
1042006-09-28 03:27:49.703 [-1523582032] Created data @0xab601020->0xab655622
1052006-09-28 03:27:49.703 [-1523582032] Created data @0xab4ab020->0xab4ff622
1062006-09-28 03:27:49.705 [-1523582032] Created data @0xab456020->0xab4aa622
1072006-09-28 03:27:49.705 [-1523582032] Created data @0xab401020->0xab455622
1082006-09-28 03:27:49.706 [-1523582032] Created data @0xab2ab020->0xab2ff622
1092006-09-28 03:27:49.707 [-1523582032] Created data @0xab256020->0xab2aa622
1102006-09-28 03:27:49.709 [-1523582032] Created data @0xab201020->0xab255622
1112006-09-28 03:27:49.709 [-1523582032] Created data @0xab0ab020->0xab0ff622
1122006-09-28 03:27:49.730 [-1523582032] Display Rect  left: 0, top: 0, width: 0, height: 0, aspect: 1.33333
1132006-09-28 03:27:49.731 [-1523582032] Video Rect    left: 0, top: 0, width: 480, height: 480, aspect: 1.33333
1142006-09-28 03:27:49.735 [-1523582032] NVP: ClearAfterSeek(1)
1152006-09-28 03:27:49.744 [-1523582032] AFD: video timecode 18996 9987 110 0
1162006-09-28 03:27:49.745 [-1523582032] AFD: DoFastForward(7191 (1), do discard frames)
1172006-09-28 03:27:49.748 [-1523582032] Dec: DoFastForward(7191 (1), do discard frames)
1182006-09-28 03:27:49.748 [-1523582032] AFD: SeekReset(7185, 0, do flush, do discard)
1192006-09-28 03:27:49.749 [-1523582032] AFD: SeekReset() flushing
1202006-09-28 03:27:49.750 [-1523582032] VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
1212006-09-28 03:27:49.750 [-1523582032] VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
1222006-09-28 03:27:49.751 [-1523582032] VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done
1232006-09-28 03:27:49.753 [-1523582032] NVP: ClearAfterSeek(0)
1242006-09-28 03:27:49.777 [-1523582032] AFD: video timecode 21595551 21586542 239850 239615
1252006-09-28 03:27:49.838 [-1523582032] ~VideoOutputNull()
1262006-09-28 03:27:49.909 [-1398600784] MythSocket(8a38b80:18): socket is readable
1272006-09-28 03:27:49.938 [-1398600784] MythSocket(8a38b80:18): cb->readyRead()
1282006-09-28 03:27:49.970 [-1398600784] MythSocket(8a38b80:18): UpRef: 2
1292006-09-28 03:27:49.972 [-1356657744] read  <- 18 23      QUERY_RECORDINGS Delete
1302006-09-28 03:28:06.712 [-1314714704] AutoExpire: ExpireLiveTV(10000)
1312006-09-28 03:28:06.732 [-1314714704] AutoExpire: SendDeleteMessages. Nothing to expire.
1322006-09-28 03:28:19.929 [-1254958752] MythSocket(8d1cac8:20): new socket
1332006-09-28 03:28:19.960 [-1254958752] MythSocket(8d1cac8:20): setSocket: 17
1342006-09-28 03:28:19.960 [-1254958752] MythSocket(8d1cac8:17): state change Idle -> Connected
1352006-09-28 03:28:19.961 [-1254958752] MythSocket(8d1cac8:17): UpRef: 1
1362006-09-28 03:28:19.962 [-1398600784] MythSocket(8d1cac8:17): socket is readable
1372006-09-28 03:28:19.964 [-1398600784] MythSocket(8d1cac8:17): cb->readyRead()
1382006-09-28 03:28:19.964 [-1398600784] MythSocket(8d1cac8:17): UpRef: 2
1392006-09-28 03:28:19.965 [-1381823568] read  <- 17 21      MYTH_PROTO_VERSION 30
1402006-09-28 03:28:19.966 [-1381823568] write -> 17 13      ACCEPT[]:[]30
1412006-09-28 03:28:19.967 [-1381823568] MythSocket(8d1cac8:17): DownRef: 1
1422006-09-28 03:28:19.968 [-1398600784] MythSocket(8d1cac8:17): socket is readable
1432006-09-28 03:28:19.970 [-1398600784] MythSocket(8d1cac8:17): cb->readyRead()
1442006-09-28 03:28:19.971 [-1398600784] MythSocket(8d1cac8:17): UpRef: 2
1452006-09-28 03:28:19.972 [-1381823568] read  <- 17 20      ANN Monitor freevo 0
1462006-09-28 03:28:19.974 [-1381823568] MainServer::HandleAnnounce Monitor
1472006-09-28 03:28:19.975 [-1381823568] adding: freevo as a client (events: 0)
1482006-09-28 03:28:19.980 [-1381823568] write -> 17 2       OK
1492006-09-28 03:28:19.981 [-1381823568] MythSocket(8d1cac8:17): DownRef: 1
1502006-09-28 03:28:21.922 [-1356657744] write -> 18 433866  834[]:[]Life on Mars[]:[][]:[]Sam finds himself investigating a s...
1512006-09-28 03:28:21.936 [-1356657744] MythSocket(8a38b80:18): state change Connected -> Idle
1522006-09-28 03:28:21.949 [-1356657744] MythSocket(8a38b80:-1): cb->connectionClosed()
1532006-09-28 03:28:21.951 [-1356657744] MythSocket(8a38b80:-1): writeStringList: Error, socket went unconnected.
1542006-09-28 03:28:21.966 [-1356657744] MythSocket(8a38b80:-1): DownRef: 1
1552006-09-28 03:28:43.207 [-1254958752] MythSocket(862d388:-1): DownRef: 0
1562006-09-28 03:28:43.223 [-1254958752] MythSocket(87e11c8:-1): DownRef: 0
1572006-09-28 03:28:43.223 [-1398600784] MythSocket(862d388:-1): DownRef: -1
1582006-09-28 03:28:43.229 [-1398600784] MythSocket(862d388:-1): delete socket
1592006-09-28 03:28:43.237 [-1398600784] MythSocket(87e11c8:-1): DownRef: -1
1602006-09-28 03:28:43.238 [-1398600784] MythSocket(87e11c8:-1): delete socket
1612006-09-28 03:28:49.985 [-1398600784] MythSocket(8d1cac8:17): socket is readable
1622006-09-28 03:28:50.001 [-1398600784] MythSocket(8d1cac8:17): socket closed
1632006-09-28 03:28:50.014 [-1398600784] MythSocket(8d1cac8:17): state change Connected -> Idle
1642006-09-28 03:28:50.014 [-1398600784] MythSocket(8d1cac8:-1): cb->connectionClosed()
1652006-09-28 03:29:13.207 [-1254958752] MythSocket(8a38b80:-1): DownRef: 0
1662006-09-28 03:29:13.219 [-1398600784] MythSocket(8a38b80:-1): DownRef: -1
1672006-09-28 03:29:13.220 [-1398600784] MythSocket(8a38b80:-1): delete socket
1682006-09-28 03:29:43.207 [-1254958752] MythSocket(8d1cac8:-1): DownRef: 0
1692006-09-28 03:29:43.221 [-1398600784] MythSocket(8d1cac8:-1): DownRef: -1
1702006-09-28 03:29:43.222 [-1398600784] MythSocket(8d1cac8:-1): delete socket