2005-08-31 22:09:26.087 Using runtime prefix = /usr 2005-08-31 22:09:26.104 New DB connection, total: 1 2005-08-31 22:09:26.107 Total desktop dim: 720x576, with 1 screen[s]. 2005-08-31 22:09:26.109 Using screen 0, 720x576 at 0,0 2005-08-31 22:09:26.112 mythfrontend version: 0.19.20050712-1 www.mythtv.org 2005-08-31 22:09:26.113 Enabled verbose msgs :all 2005-08-31 22:09:26.247 max_width: 720 max_height: 576 2005-08-31 22:09:26.325 Total desktop dim: 720x576, with 1 screen[s]. 2005-08-31 22:09:26.326 Using screen 0, 720x576 at 0,0 2005-08-31 22:09:26.328 Switching to square mode (blue) 2005-08-31 22:09:26.518 Registering Internal as a media playback plugin. 2005-08-31 22:09:26.534 Registering MythDVD DVD Media Handler as a media handler 2005-08-31 22:09:26.534 Registering MythDVD VCD Media Handler as a media handler 2005-08-31 22:09:26.873 Registering MythMusic Media Handler as a media handler SIP listening on IP Address 192.168.0.3:5060 NAT address 192.168.0.3 SIP: Cannot register; proxy, username or password not set 2005-08-31 22:09:27.179 generating cache image for: /usr/share/mythtv/themes/default/blank.png 2005-08-31 22:09:27.470 Starting media monitor. 2005-08-31 22:09:28.567 New DB connection, total: 2 2005-08-31 22:09:28.610 Connecting to backend server: 127.0.0.1:6543 (try 1 of 5) 2005-08-31 22:09:28.610 write -> 14 21 ANN Playback vdrtv1 0 2005-08-31 22:09:28.627 read <- 14 2 OK 2005-08-31 22:09:28.630 write -> 14 29 GET_NEXT_FREE_RECORDER[]:[]-1 2005-08-31 22:09:28.647 read <- 14 24 1[]:[]127.0.0.1[]:[]6543 2005-08-31 22:09:28.648 write -> 16 21 ANN Playback vdrtv1 1 2005-08-31 22:09:28.648 Attempting to change from None to WatchingLiveTV 2005-08-31 22:09:28.649 write -> 17 21 MYTH_PROTO_VERSION 18 2005-08-31 22:09:28.664 read <- 16 2 OK 2005-08-31 22:09:28.664 read <- 17 13 ACCEPT[]:[]18 2005-08-31 22:09:28.664 Using protocol version 18 2005-08-31 22:09:28.664 write -> 17 21 ANN Playback vdrtv1 0 2005-08-31 22:09:28.680 read <- 17 2 OK 2005-08-31 22:09:28.680 write -> 17 44 QUERY_RECORDER 1[]:[]SETUP_RING_BUFFER[]:[]0 2005-08-31 22:09:28.696 read <- 17 92 ok[]:[]rbuf://127.0.0.1:6543/mnt/store/ringbuf1.nuv[]:[]2[]:[]-21... 2005-08-31 22:09:28.697 write -> 18 21 ANN Playback vdrtv1 0 2005-08-31 22:09:28.712 read <- 18 2 OK 2005-08-31 22:09:28.712 write -> 19 23 ANN RingBuffer vdrtv1 1 2005-08-31 22:09:28.728 read <- 19 2 OK 2005-08-31 22:09:28.728 write -> 17 33 QUERY_RECORDER 1[]:[]SPAWN_LIVETV 2005-08-31 22:09:28.760 read <- 17 2 ok 2005-08-31 22:09:28.761 write -> 17 33 QUERY_RECORDER 1[]:[]IS_RECORDING 2005-08-31 22:09:28.776 read <- 17 1 1 2005-08-31 22:09:28.777 write -> 17 33 QUERY_RECORDER 1[]:[]IS_RECORDING 2005-08-31 22:09:28.793 read <- 17 1 1 2005-08-31 22:09:28.793 write -> 17 34 QUERY_RECORDER 1[]:[]GET_FRAMERATE 2005-08-31 22:09:28.809 read <- 17 2 25 2005-08-31 22:09:28.823 write -> 17 37 QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO 2005-08-31 22:09:28.833 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:09:28.841 read <- 17 103 []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10... 2005-08-31 22:09:28.841 Output filters for this channel are: '' 2005-08-31 22:09:28.842 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:28.861 read <- 18 6 128000 2005-08-31 22:09:28.861 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:28.869 write -> 18 66 QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]2048 2005-08-31 22:09:28.885 read <- 18 7 0[]:[]0 2005-08-31 22:09:28.889 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:09:28.893 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:28.902 read <- 18 6 128000 2005-08-31 22:09:28.902 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:28.913 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:28.922 read <- 18 6 128000 2005-08-31 22:09:28.922 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:28.933 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:28.946 read <- 18 6 128000 2005-08-31 22:09:28.946 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:28.957 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:28.962 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:09:28.966 read <- 18 6 128000 2005-08-31 22:09:28.966 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:28.977 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:28.987 read <- 18 6 128000 2005-08-31 22:09:28.987 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:28.998 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.006 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:09:29.010 read <- 18 6 128000 2005-08-31 22:09:29.010 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.022 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.034 read <- 18 6 128000 2005-08-31 22:09:29.034 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.035 write -> 18 68 QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]851968 2005-08-31 22:09:29.054 read <- 18 7 0[]:[]0 2005-08-31 22:09:29.054 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.066 read <- 18 6 128000 2005-08-31 22:09:29.066 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.070 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:09:29.074 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.082 read <- 18 6 128000 2005-08-31 22:09:29.083 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.090 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.099 read <- 18 6 128000 2005-08-31 22:09:29.099 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.106 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.115 read <- 18 6 128000 2005-08-31 22:09:29.115 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.122 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.126 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:09:29.131 read <- 18 6 128000 2005-08-31 22:09:29.131 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.138 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.147 read <- 18 6 128000 2005-08-31 22:09:29.147 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.154 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.163 read <- 18 6 128000 2005-08-31 22:09:29.163 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.171 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.179 read <- 18 6 128000 2005-08-31 22:09:29.179 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.187 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.195 read <- 18 6 128000 2005-08-31 22:09:29.196 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.203 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.211 read <- 18 6 128000 2005-08-31 22:09:29.211 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.219 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.228 read <- 18 6 128000 2005-08-31 22:09:29.228 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.235 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.244 read <- 18 6 128000 2005-08-31 22:09:29.244 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.251 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.260 read <- 18 6 128000 2005-08-31 22:09:29.260 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.267 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.276 read <- 18 6 128000 2005-08-31 22:09:29.276 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.283 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.292 read <- 18 6 128000 2005-08-31 22:09:29.292 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.299 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.308 read <- 18 6 128000 2005-08-31 22:09:29.308 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.315 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.324 read <- 18 6 128000 2005-08-31 22:09:29.324 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.331 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.340 read <- 18 6 128000 2005-08-31 22:09:29.340 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.347 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.356 read <- 18 6 128000 2005-08-31 22:09:29.356 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.364 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.372 read <- 18 6 128000 2005-08-31 22:09:29.372 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.380 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.388 read <- 18 6 128000 2005-08-31 22:09:29.388 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.396 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.404 read <- 18 6 128000 2005-08-31 22:09:29.405 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.412 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.421 read <- 18 6 128000 2005-08-31 22:09:29.421 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.428 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.437 read <- 18 6 128000 2005-08-31 22:09:29.437 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.444 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.453 read <- 18 6 128000 2005-08-31 22:09:29.453 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.460 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.469 read <- 18 6 128000 2005-08-31 22:09:29.469 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.477 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.485 read <- 18 6 128000 2005-08-31 22:09:29.485 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.493 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.501 read <- 18 6 128000 2005-08-31 22:09:29.501 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.508 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.517 read <- 18 6 128000 2005-08-31 22:09:29.517 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.524 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.533 read <- 18 6 128000 2005-08-31 22:09:29.533 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.540 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.549 read <- 18 6 128000 2005-08-31 22:09:29.549 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.557 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.565 read <- 18 6 128000 2005-08-31 22:09:29.565 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.573 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.581 read <- 18 6 128000 2005-08-31 22:09:29.582 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.589 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.597 read <- 18 6 128000 2005-08-31 22:09:29.597 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.605 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.614 read <- 18 6 128000 2005-08-31 22:09:29.614 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.625 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.634 read <- 18 6 128000 2005-08-31 22:09:29.634 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.641 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.650 read <- 18 6 128000 2005-08-31 22:09:29.650 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.657 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.666 read <- 18 6 128000 2005-08-31 22:09:29.666 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.677 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.690 read <- 18 6 128000 2005-08-31 22:09:29.690 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.701 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.710 read <- 18 6 128000 2005-08-31 22:09:29.710 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.721 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.742 read <- 18 6 128000 2005-08-31 22:09:29.742 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.754 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.766 read <- 18 6 128000 2005-08-31 22:09:29.767 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.778 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.790 read <- 18 6 128000 2005-08-31 22:09:29.791 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.802 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.814 read <- 18 6 128000 2005-08-31 22:09:29.814 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.826 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.838 read <- 18 6 128000 2005-08-31 22:09:29.839 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.846 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.855 read <- 18 6 128000 2005-08-31 22:09:29.855 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.862 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.871 read <- 18 6 128000 2005-08-31 22:09:29.871 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.878 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.887 read <- 18 6 128000 2005-08-31 22:09:29.887 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.894 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.903 read <- 18 6 128000 2005-08-31 22:09:29.903 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.910 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.919 read <- 18 6 128000 2005-08-31 22:09:29.919 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.926 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.935 read <- 18 6 128000 2005-08-31 22:09:29.935 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.943 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.951 read <- 18 6 128000 2005-08-31 22:09:29.951 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.959 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:29.967 read <- 18 6 128000 2005-08-31 22:09:29.967 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:29.975 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.064 read <- 18 6 128000 2005-08-31 22:09:30.064 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.071 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.116 read <- 18 6 128000 2005-08-31 22:09:30.117 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.124 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.132 read <- 18 6 128000 2005-08-31 22:09:30.132 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.140 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.213 read <- 18 6 128000 2005-08-31 22:09:30.213 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.220 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.309 read <- 18 6 128000 2005-08-31 22:09:30.309 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.316 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.369 read <- 18 6 128000 2005-08-31 22:09:30.370 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.377 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.466 read <- 18 6 128000 2005-08-31 22:09:30.466 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.467 write -> 18 75 QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]7569408[]:[]0[]:[]0[]... 2005-08-31 22:09:30.485 read <- 18 13 0[]:[]7569408 0: start_time: -9223372036854.775 duration: -9223372036854.775 stream: start_time: -9223372036854.775 duration: -9223372036854.775 bitrate=1152 kb/s 2005-08-31 22:09:30.486 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.486 AVFD: Stream #0, has id 0x33 codec id MPEG1VIDEO, type Video at 0x0x82a95a0 2005-08-31 22:09:30.487 XvMC version: 1.0 2005-08-31 22:09:30.488 XvMCSurfaceTypes::find(w 768, h 576, chroma 1, vld 0, idct 1, mpeg1, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:09:30.488 Trying XvMC port 270 2005-08-31 22:09:30.489 XvMCSurfaceTypes::find(w 768, h 576, chroma 1, vld 0, idct 1, mpeg1, sub-width 0, sub-height 0, disp, p<= 302, 2710 <=p, port, surfNum) 2005-08-31 22:09:30.489 Trying XvMC port 271 2005-08-31 22:09:30.490 Trying XvMC port 272 2005-08-31 22:09:30.490 Trying XvMC port 273 2005-08-31 22:09:30.490 Trying XvMC port 274 2005-08-31 22:09:30.490 Trying XvMC port 275 2005-08-31 22:09:30.490 Trying XvMC port 276 2005-08-31 22:09:30.490 Trying XvMC port 277 2005-08-31 22:09:30.490 Trying XvMC port 278 2005-08-31 22:09:30.490 Trying XvMC port 279 2005-08-31 22:09:30.490 Trying XvMC port 280 2005-08-31 22:09:30.491 Trying XvMC port 281 2005-08-31 22:09:30.491 Trying XvMC port 282 2005-08-31 22:09:30.491 Trying XvMC port 283 2005-08-31 22:09:30.491 Trying XvMC port 284 2005-08-31 22:09:30.491 Trying XvMC port 285 2005-08-31 22:09:30.491 Trying XvMC port 286 2005-08-31 22:09:30.491 Trying XvMC port 287 2005-08-31 22:09:30.491 Trying XvMC port 288 2005-08-31 22:09:30.491 Trying XvMC port 289 2005-08-31 22:09:30.491 Trying XvMC port 290 2005-08-31 22:09:30.492 Trying XvMC port 291 2005-08-31 22:09:30.492 Trying XvMC port 292 2005-08-31 22:09:30.492 Trying XvMC port 293 2005-08-31 22:09:30.492 Trying XvMC port 294 2005-08-31 22:09:30.492 Trying XvMC port 295 2005-08-31 22:09:30.492 Trying XvMC port 296 2005-08-31 22:09:30.492 Trying XvMC port 297 2005-08-31 22:09:30.492 Trying XvMC port 298 2005-08-31 22:09:30.492 Trying XvMC port 299 2005-08-31 22:09:30.493 Trying XvMC port 300 2005-08-31 22:09:30.493 Trying XvMC port 301 2005-08-31 22:09:30.493 Trying XvMC port 302 2005-08-31 22:09:30.493 XvMCSurfaceTypes::find(w 768, h 576, chroma 1, vld 0, idct 0, mpeg1, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:09:30.493 Trying XvMC port 270 2005-08-31 22:09:30.493 XvMCSurfaceTypes::find(w 768, h 576, chroma 1, vld 0, idct 0, mpeg1, sub-width 0, sub-height 0, disp, p<= 302, 2710 <=p, port, surfNum) 2005-08-31 22:09:30.493 Trying XvMC port 271 2005-08-31 22:09:30.493 Trying XvMC port 272 2005-08-31 22:09:30.494 Trying XvMC port 273 2005-08-31 22:09:30.494 Trying XvMC port 274 2005-08-31 22:09:30.494 Trying XvMC port 275 2005-08-31 22:09:30.494 Trying XvMC port 276 2005-08-31 22:09:30.494 Trying XvMC port 277 2005-08-31 22:09:30.494 Trying XvMC port 278 2005-08-31 22:09:30.494 Trying XvMC port 279 2005-08-31 22:09:30.494 Trying XvMC port 280 2005-08-31 22:09:30.494 Trying XvMC port 281 2005-08-31 22:09:30.495 Trying XvMC port 282 2005-08-31 22:09:30.495 Trying XvMC port 283 2005-08-31 22:09:30.495 Trying XvMC port 284 2005-08-31 22:09:30.495 Trying XvMC port 285 2005-08-31 22:09:30.495 Trying XvMC port 286 2005-08-31 22:09:30.495 Trying XvMC port 287 2005-08-31 22:09:30.495 Trying XvMC port 288 2005-08-31 22:09:30.495 Trying XvMC port 289 2005-08-31 22:09:30.495 Trying XvMC port 290 2005-08-31 22:09:30.495 Trying XvMC port 291 2005-08-31 22:09:30.496 Trying XvMC port 292 2005-08-31 22:09:30.496 Trying XvMC port 293 2005-08-31 22:09:30.496 Trying XvMC port 294 2005-08-31 22:09:30.496 Trying XvMC port 295 2005-08-31 22:09:30.496 Trying XvMC port 296 2005-08-31 22:09:30.496 Trying XvMC port 297 2005-08-31 22:09:30.496 Trying XvMC port 298 2005-08-31 22:09:30.496 Trying XvMC port 299 2005-08-31 22:09:30.496 Trying XvMC port 300 2005-08-31 22:09:30.497 Trying XvMC port 301 2005-08-31 22:09:30.497 Trying XvMC port 302 2005-08-31 22:09:30.498 read <- 18 6 128000 2005-08-31 22:09:30.498 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.498 detectInterlace(Detect Scan, Detect Scan, 50, 576) ->Progressive Scan 2005-08-31 22:09:30.499 Interlaced: Progressive Scan video_height: 576 fps: 50 2005-08-31 22:09:30.499 AVFD: Looking for decoder for MPEG1VIDEO 2005-08-31 22:09:30.499 AVFD: Opened codec 0x82a2860, id(MPEG1VIDEO) type(Video) 2005-08-31 22:09:30.500 Estimated bitrate = 1152 2005-08-31 22:09:30.500 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0) 2005-08-31 22:09:30.500 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:09:30.509 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.518 read <- 17 7 0[]:[]0 2005-08-31 22:09:30.518 PosMapFromEnc: Warning, tried to fetch PositionMap from Encoder but encoder returned framesWritten == 0 2005-08-31 22:09:30.518 SyncPositionMap liveTV, from Encoder: 0 entries 2005-08-31 22:09:30.518 recording has no position -- using libavformat 2005-08-31 22:09:30.518 AvFormatDecoder: Successfully opened decoder for file: "rbuf://127.0.0.1:6543/mnt/store/ringbuf1.nuv". novideo(0) 2005-08-31 22:09:30.521 VideoOutputXv() 2005-08-31 22:09:30.527 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0 2005-08-31 22:09:30.533 @ j=3 Looking for flag[s]: XvInputMask XvImageMask 2005-08-31 22:09:30.533 Adaptor: 0 has flag[s]: XvInputMask XvImageMask 2005-08-31 22:09:30.533 XVideo surface found on port 270 2005-08-31 22:09:30.567 read <- 18 6 128000 2005-08-31 22:09:30.567 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.569 Couldn't get the color key color, and we need it. You likely won't get any video. 2005-08-31 22:09:30.569 Image size. dispxoff 0, dispyoff: 38, dispwoff: 666, disphoff: 456 2005-08-31 22:09:30.569 Image size. imgx 0, imgy: 0, imgw: 768, imgh: 576 2005-08-31 22:09:30.578 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.591 read <- 18 6 128000 2005-08-31 22:09:30.591 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.602 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.719 read <- 18 6 128000 2005-08-31 22:09:30.719 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.730 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.738 read <- 18 6 128000 2005-08-31 22:09:30.738 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.750 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.791 read <- 18 6 128000 2005-08-31 22:09:30.791 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:30.802 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:30.932 InputChanged() 2005-08-31 22:09:30.932 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA 2005-08-31 22:09:30.933 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2005-08-31 22:09:30.934 Changing from None to WatchingLiveTV 2005-08-31 22:09:30.935 write -> 17 35 QUERY_RECORDER 1[]:[]GET_INPUT_NAME 2005-08-31 22:09:30.944 Using realtime priority. 2005-08-31 22:09:30.954 read <- 17 8 DVBInput 2005-08-31 22:09:31.045 nVidiaVideoSync: VBlank ioctl did not work, unimplemented in this driver? 2005-08-31 22:09:31.046 DRMVideoSync: Could not open device /dev/dri/card0, No such file or directory 2005-08-31 22:09:31.047 Using audio as timebase 2005-08-31 22:09:31.047 Video timing method: RTC 2005-08-31 22:09:31.047 Refresh rate: 20000, frame interval: 20000 2005-08-31 22:09:31.047 waiting for prebuffer... 0 2005-08-31 22:09:31.133 waiting for prebuffer... 1 2005-08-31 22:09:31.187 read <- 18 6 128000 2005-08-31 22:09:31.187 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:31.198 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:31.217 waiting for prebuffer... 2 2005-08-31 22:09:31.284 write -> 17 35 QUERY_RECORDER 1[]:[]FRONTEND_READY 2005-08-31 22:09:31.284 detectInterlace(Detect Scan, Progressive Scan, 50, 576) ->Progressive Scan 2005-08-31 22:09:31.284 Interlaced: Progressive Scan video_height: 576 fps: 50 2005-08-31 22:09:31.284 positionMap[ 0 ] == 74824. 2005-08-31 22:09:31.297 positionMap[ 0 ] == 897888. 2005-08-31 22:09:31.302 read <- 17 2 ok 2005-08-31 22:09:31.307 write -> 17 37 QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO 2005-08-31 22:09:31.313 HandleGopStart: gopset not set, syncing positionMap 2005-08-31 22:09:31.314 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0) 2005-08-31 22:09:31.326 read <- 17 103 []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10... 2005-08-31 22:09:31.326 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:09:31.346 read <- 17 7 0[]:[]1 2005-08-31 22:09:31.346 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:09:31.346 Filling position map from 1 to 0 2005-08-31 22:09:31.366 read <- 17 7 0[]:[]1 2005-08-31 22:09:31.366 write -> 14 19 QUERY_GETALLPENDING 2005-08-31 22:09:31.367 write -> 17 50 QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]1[]:[]0 2005-08-31 22:09:31.388 read <- 14 7 0[]:[]0 2005-08-31 22:09:31.389 read <- 17 2 ok 2005-08-31 22:09:31.389 Position map filled from Encoder to: 0 2005-08-31 22:09:31.390 SyncPositionMap liveTV, from Encoder: 2 entries 2005-08-31 22:09:31.390 Stream initial keyframedist: 11. 2005-08-31 22:09:31.391 positionMap[ 2 ] == 1720952. 2005-08-31 22:09:31.415 positionMap[ 3 ] == 2544016. 2005-08-31 22:09:31.419 write -> 17 37 QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO 2005-08-31 22:09:31.434 read <- 17 103 []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10... 2005-08-31 22:09:31.435 write -> 17 53 QUERY_RECORDER 1[]:[]GET_FREE_SPACE[]:[]0[]:[]7569408 2005-08-31 22:09:31.451 read <- 17 16 2[]:[]2083570396 2005-08-31 22:09:31.451 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:09:31.467 read <- 17 7 0[]:[]3 2005-08-31 22:09:31.530 read <- 18 6 128000 2005-08-31 22:09:31.530 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:31.540 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:31.569 positionMap[ 4 ] == 3367080. 2005-08-31 22:09:31.789 positionMap[ 5 ] == 4190144. 2005-08-31 22:09:31.870 read <- 18 6 128000 2005-08-31 22:09:31.871 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:31.879 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:32.009 positionMap[ 6 ] == 5013208. 2005-08-31 22:09:32.190 read <- 18 6 128000 2005-08-31 22:09:32.190 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:32.201 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:32.229 positionMap[ 7 ] == 5836272. 2005-08-31 22:09:32.449 positionMap[ 8 ] == 6659336. 2005-08-31 22:09:32.534 read <- 18 6 128000 2005-08-31 22:09:32.534 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:32.549 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:32.669 positionMap[ 9 ] == 7482400. 2005-08-31 22:09:32.736 read <- 18 6 128000 2005-08-31 22:09:32.737 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:32.744 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:32.889 positionMap[ 10 ] == 8305464. 2005-08-31 22:09:32.909 streams_changed 0x825db90 -- stream count 2 2005-08-31 22:09:32.909 AvFormatDecoder::SeekReset(0, don't flush) 2005-08-31 22:09:32.909 AVFD: Stream #0, has id 0x215 codec id MPEG2VIDEO, type Video at 0x0x8494cc0 2005-08-31 22:09:32.911 XvMC version: 1.0 2005-08-31 22:09:32.911 XvMCSurfaceTypes::find(w 0, h 0, chroma 1, vld 0, idct 1, mpeg2, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:09:32.911 Trying XvMC port 270 2005-08-31 22:09:32.911 Found a suitable XvMC surface 0 2005-08-31 22:09:32.911 @ j=1 Looking for flag[s]: XvInputMask 2005-08-31 22:09:32.912 Adaptor: 0 has flag[s]: XvInputMask XvImageMask 2005-08-31 22:09:32.912 XvMCSurfaceTypes::find(w 0, h 0, chroma 1, vld 0, idct 1, mpeg2, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:09:32.912 Trying XvMC port 270 2005-08-31 22:09:32.912 Found a suitable XvMC surface 0 2005-08-31 22:09:32.912 Adaptor: 1 has flag[s]: XvInputMask XvImageMask 2005-08-31 22:09:32.912 XvMCSurfaceTypes::find(w 0, h 0, chroma 1, vld 0, idct 1, mpeg2, sub-width 0, sub-height 0, disp, p<= 302, 2710 <=p, port, surfNum) 2005-08-31 22:09:32.912 Trying XvMC port 271 2005-08-31 22:09:32.912 Trying XvMC port 272 2005-08-31 22:09:32.913 Trying XvMC port 273 2005-08-31 22:09:32.913 Trying XvMC port 274 2005-08-31 22:09:32.913 Trying XvMC port 275 2005-08-31 22:09:32.913 Trying XvMC port 276 2005-08-31 22:09:32.913 Trying XvMC port 277 2005-08-31 22:09:32.913 Trying XvMC port 278 2005-08-31 22:09:32.913 Trying XvMC port 279 2005-08-31 22:09:32.913 Trying XvMC port 280 2005-08-31 22:09:32.913 Trying XvMC port 281 2005-08-31 22:09:32.914 Trying XvMC port 282 2005-08-31 22:09:32.914 Trying XvMC port 283 2005-08-31 22:09:32.914 Trying XvMC port 284 2005-08-31 22:09:32.914 Trying XvMC port 285 2005-08-31 22:09:32.914 Trying XvMC port 286 2005-08-31 22:09:32.914 Trying XvMC port 287 2005-08-31 22:09:32.914 Trying XvMC port 288 2005-08-31 22:09:32.914 Trying XvMC port 289 2005-08-31 22:09:32.914 Trying XvMC port 290 2005-08-31 22:09:32.915 Trying XvMC port 291 2005-08-31 22:09:32.915 Trying XvMC port 292 2005-08-31 22:09:32.915 Trying XvMC port 293 2005-08-31 22:09:32.915 Trying XvMC port 294 2005-08-31 22:09:32.915 Trying XvMC port 295 2005-08-31 22:09:32.915 Trying XvMC port 296 2005-08-31 22:09:32.915 Trying XvMC port 297 2005-08-31 22:09:32.915 Trying XvMC port 298 2005-08-31 22:09:32.916 Trying XvMC port 299 2005-08-31 22:09:32.916 Trying XvMC port 300 2005-08-31 22:09:32.916 Trying XvMC port 301 2005-08-31 22:09:32.916 Trying XvMC port 302 2005-08-31 22:09:32.916 No suitible XVideo port found 2005-08-31 22:09:32.916 Could not open XvMC port... You may wish to verify that your DISPLAY environment variable does not use an external network connection. You may also wish to verify that /etc/X11/XvMCConfig contains the correct vendor's XvMC library. 2005-08-31 22:09:32.917 detectInterlace(Detect Scan, Progressive Scan, 29.97, 480) ->Interlaced Scan 2005-08-31 22:09:32.917 Interlaced: Interlaced Scan video_height: 480 fps: 29.97 2005-08-31 22:09:32.919 Using deinterlace method bobdeint 2005-08-31 22:09:32.919 Set video sync frame interval to 33366 2005-08-31 22:09:32.919 Video sync method can't support double framerate (refresh rate too low for bob deint) 2005-08-31 22:09:32.920 AVFD: Looking for decoder for MPEG2VIDEO 2005-08-31 22:09:32.920 AVFD: Opened codec 0x839aba0, id(MPEG2VIDEO) type(Video) 2005-08-31 22:09:32.921 AVFD: Stream #1, has id 0x888 codec id MP3, type Audio at 0x0x84f9b20 2005-08-31 22:09:32.921 AVFD: Looking for decoder for MP3 2005-08-31 22:09:32.940 AVFD: Opened codec 0x84682f0, id(MP3) type(Audio) 2005-08-31 22:09:32.940 AVFD: Stream #1 (audio track #0) is an audio stream with 0 channels. 2005-08-31 22:09:32.942 AvFormatDecoder: Video has changed from 0x0 to 704x576. 2005-08-31 22:09:32.943 InputChanged() 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): UUUUUUUUUUUUUUUUULAAUUUUUUUUUUU 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2005-08-31 22:09:32.954 prebuffering pause 2005-08-31 22:09:32.955 waiting for prebuffer... 0 2005-08-31 22:09:32.959 read <- 18 6 128000 2005-08-31 22:09:32.959 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:32.970 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:32.986 Image size. dispxoff 0, dispyoff: 0, dispwoff: 666, disphoff: 533 2005-08-31 22:09:32.986 Image size. imgx 0, imgy: 0, imgw: 704, imgh: 576 2005-08-31 22:09:33.122 waiting for prebuffer... 1 2005-08-31 22:09:33.255 read <- 18 6 128000 2005-08-31 22:09:33.255 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:33.266 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:33.290 waiting for prebuffer... 2 2005-08-31 22:09:33.312 detectInterlace(Detect Scan, Ignore Scan, 25, 576) ->Interlaced Scan 2005-08-31 22:09:33.312 Interlaced: Interlaced Scan video_height: 576 fps: 25 2005-08-31 22:09:33.314 Using deinterlace method bobdeint 2005-08-31 22:09:33.314 Set video sync frame interval to 40000 2005-08-31 22:09:33.314 positionMap[ 11 ] == 8511324. 2005-08-31 22:09:33.321 Auto-selecting audio track #1 (stream #1). 2005-08-31 22:09:33.321 It has 2 channels and we needed at least 1 2005-08-31 22:09:33.321 Initializing audio parms from audio track #0. 2005-08-31 22:09:33.322 Killing AudioOutputDSP 2005-08-31 22:09:33.323 Opening audio device 'spdif'. 2005-08-31 22:09:33.330 in SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=125000) 2005-08-31 22:09:33.331 get_buffer_size returned 16384 2005-08-31 22:09:33.331 set_period_time_near returned 85333 2005-08-31 22:09:33.331 get_period_size returned 4096 2005-08-31 22:09:33.331 Audio fragment size: 4096 2005-08-31 22:09:33.332 Audio Stretch Factor: 1 2005-08-31 22:09:33.332 Ending reconfigure 2005-08-31 22:09:33.332 kickoffOutputAudioLoop: pid = 11695 2005-08-31 22:09:33.333 OutputAudioLoop: Play Event 2005-08-31 22:09:33.333 Broadcasting free space avail 2005-08-31 22:09:33.336 _AddSamples bytes=4608, used=1, free=767999, timecode=13678718 2005-08-31 22:09:33.337 _AddSamples bytes=4608, used=4609, free=763391, timecode=13678742 2005-08-31 22:09:33.337 _AddSamples bytes=4608, used=9217, free=758783, timecode=13678766 2005-08-31 22:09:33.341 _AddSamples bytes=4608, used=13825, free=754175, timecode=13678790 2005-08-31 22:09:33.341 _AddSamples bytes=4608, used=18433, free=749567, timecode=13678814 2005-08-31 22:09:33.342 _AddSamples bytes=4608, used=23041, free=744959, timecode=13678838 2005-08-31 22:09:33.342 _AddSamples bytes=4608, used=27649, free=740351, timecode=13678862 2005-08-31 22:09:33.342 Broadcasting free space avail 2005-08-31 22:09:33.342 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.343 Broadcasting free space avail 2005-08-31 22:09:33.343 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.343 _AddSamples bytes=4608, used=24065, free=743935, timecode=13678886 2005-08-31 22:09:33.343 Broadcasting free space avail 2005-08-31 22:09:33.343 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.343 Broadcasting free space avail 2005-08-31 22:09:33.343 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.343 Broadcasting free space avail 2005-08-31 22:09:33.344 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.344 _AddSamples bytes=4608, used=16385, free=751615, timecode=13678910 2005-08-31 22:09:33.344 Broadcasting free space avail 2005-08-31 22:09:33.344 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.344 Broadcasting free space avail 2005-08-31 22:09:33.344 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.344 _AddSamples bytes=4608, used=12801, free=755199, timecode=13678934 2005-08-31 22:09:33.344 Broadcasting free space avail 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.345 Broadcasting free space avail 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.345 Broadcasting free space avail 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.345 _AddSamples bytes=4608, used=5121, free=762879, timecode=13678958 2005-08-31 22:09:33.345 Broadcasting free space avail 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.346 Broadcasting free space avail 2005-08-31 22:09:33.346 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.346 _AddSamples bytes=4608, used=1537, free=766463, timecode=13678982 2005-08-31 22:09:33.346 Broadcasting free space avail 2005-08-31 22:09:33.346 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.346 _AddSamples bytes=4608, used=2049, free=765951, timecode=13679006 2005-08-31 22:09:33.347 Broadcasting free space avail 2005-08-31 22:09:33.347 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.347 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:09:33.347 Broadcasting free space avail 2005-08-31 22:09:33.347 _AddSamples bytes=4608, used=2561, free=765439, timecode=13679030 2005-08-31 22:09:33.348 _AddSamples bytes=4608, used=7169, free=760831, timecode=13679054 2005-08-31 22:09:33.348 _AddSamples bytes=4608, used=11777, free=756223, timecode=13679078 2005-08-31 22:09:33.348 _AddSamples bytes=4608, used=16385, free=751615, timecode=13679102 2005-08-31 22:09:33.349 _AddSamples bytes=4608, used=20993, free=747007, timecode=13679126 2005-08-31 22:09:33.349 _AddSamples bytes=4608, used=25601, free=742399, timecode=13679150 2005-08-31 22:09:33.350 _AddSamples bytes=4608, used=30209, free=737791, timecode=13679174 2005-08-31 22:09:33.350 _AddSamples bytes=4608, used=34817, free=733183, timecode=13679198 2005-08-31 22:09:33.351 _AddSamples bytes=4608, used=39425, free=728575, timecode=13679222 2005-08-31 22:09:33.351 _AddSamples bytes=4608, used=44033, free=723967, timecode=13679246 2005-08-31 22:09:33.352 _AddSamples bytes=4608, used=48641, free=719359, timecode=13679270 2005-08-31 22:09:33.352 _AddSamples bytes=4608, used=53249, free=714751, timecode=13679294 2005-08-31 22:09:33.353 _AddSamples bytes=4608, used=57857, free=710143, timecode=13679318 2005-08-31 22:09:33.353 _AddSamples bytes=4608, used=62465, free=705535, timecode=13679342 2005-08-31 22:09:33.356 _AddSamples bytes=4608, used=67073, free=700927, timecode=13679366 2005-08-31 22:09:33.357 _AddSamples bytes=4608, used=71681, free=696319, timecode=13679390 2005-08-31 22:09:33.358 Broadcasting free space avail 2005-08-31 22:09:33.358 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.359 Broadcasting free space avail 2005-08-31 22:09:33.359 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.359 audio waiting for space on soundcard: have 2972 need 4096 2005-08-31 22:09:33.361 _AddSamples bytes=4608, used=68097, free=699903, timecode=13679414 2005-08-31 22:09:33.361 _AddSamples bytes=4608, used=72705, free=695295, timecode=13679438 2005-08-31 22:09:33.365 _AddSamples bytes=4608, used=77313, free=690687, timecode=13679462 2005-08-31 22:09:33.368 _AddSamples bytes=4608, used=81921, free=686079, timecode=13679486 2005-08-31 22:09:33.368 _AddSamples bytes=4608, used=86529, free=681471, timecode=13679510 2005-08-31 22:09:33.372 _AddSamples bytes=4608, used=91137, free=676863, timecode=13679534 2005-08-31 22:09:33.372 _AddSamples bytes=4608, used=95745, free=672255, timecode=13679558 2005-08-31 22:09:33.374 Broadcasting free space avail 2005-08-31 22:09:33.374 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.375 audio waiting for space on soundcard: have 1892 need 4096 2005-08-31 22:09:33.376 _AddSamples bytes=4608, used=96257, free=671743, timecode=13679582 2005-08-31 22:09:33.376 HandleGopStart: gopset not set, syncing positionMap 2005-08-31 22:09:33.376 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0) 2005-08-31 22:09:33.376 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:09:33.386 Broadcasting free space avail 2005-08-31 22:09:33.386 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.387 audio waiting for space on soundcard: have 108 need 4096 2005-08-31 22:09:33.394 read <- 17 8 0[]:[]49 2005-08-31 22:09:33.395 Filling position map from 12 to 4 2005-08-31 22:09:33.395 write -> 17 51 QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]12[]:[]4 2005-08-31 22:09:33.398 audio waiting for space on soundcard: have 2392 need 4096 2005-08-31 22:09:33.411 read <- 17 2 ok 2005-08-31 22:09:33.411 Broadcasting free space avail 2005-08-31 22:09:33.411 Position map filled from Encoder to: 11 2005-08-31 22:09:33.411 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.411 SyncPositionMap liveTV, from Encoder: 12 entries 2005-08-31 22:09:33.411 audio waiting for space on soundcard: have 736 need 4096 2005-08-31 22:09:33.411 Stream initial keyframedist: 12. 2005-08-31 22:09:33.411 positionMap[ 11 ] == 8684472. 2005-08-31 22:09:33.415 _AddSamples bytes=4608, used=92673, free=675327, timecode=13679606 2005-08-31 22:09:33.416 _AddSamples bytes=4608, used=97281, free=670719, timecode=13679630 2005-08-31 22:09:33.420 _AddSamples bytes=4608, used=101889, free=666111, timecode=13679654 2005-08-31 22:09:33.420 _AddSamples bytes=4608, used=106497, free=661503, timecode=13679678 2005-08-31 22:09:33.423 audio waiting for space on soundcard: have 3004 need 4096 2005-08-31 22:09:33.425 _AddSamples bytes=4608, used=111105, free=656895, timecode=13679702 2005-08-31 22:09:33.435 Broadcasting free space avail 2005-08-31 22:09:33.435 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.435 _AddSamples bytes=4608, used=111617, free=656383, timecode=13679726 2005-08-31 22:09:33.435 audio waiting for space on soundcard: have 1256 need 4096 2005-08-31 22:09:33.436 _AddSamples bytes=4608, used=116225, free=651775, timecode=13679750 2005-08-31 22:09:33.440 _AddSamples bytes=4608, used=120833, free=647167, timecode=13679774 2005-08-31 22:09:33.440 _AddSamples bytes=4608, used=125441, free=642559, timecode=13679798 2005-08-31 22:09:33.444 _AddSamples bytes=4608, used=130049, free=637951, timecode=13679822 2005-08-31 22:09:33.447 audio waiting for space on soundcard: have 3596 need 4096 2005-08-31 22:09:33.450 _AddSamples bytes=4608, used=134657, free=633343, timecode=13679846 2005-08-31 22:09:33.451 _AddSamples bytes=4608, used=139265, free=628735, timecode=13679870 2005-08-31 22:09:33.455 _AddSamples bytes=4608, used=143873, free=624127, timecode=13679894 2005-08-31 22:09:33.456 _AddSamples bytes=4608, used=148481, free=619519, timecode=13679918 2005-08-31 22:09:33.459 Broadcasting free space avail 2005-08-31 22:09:33.459 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.459 audio waiting for space on soundcard: have 1756 need 4096 2005-08-31 22:09:33.460 _AddSamples bytes=4608, used=148993, free=619007, timecode=13679942 2005-08-31 22:09:33.465 _AddSamples bytes=4608, used=153601, free=614399, timecode=13679966 2005-08-31 22:09:33.465 _AddSamples bytes=4608, used=158209, free=609791, timecode=13679990 2005-08-31 22:09:33.470 _AddSamples bytes=4608, used=162817, free=605183, timecode=13680014 2005-08-31 22:09:33.470 _AddSamples bytes=4608, used=167425, free=600575, timecode=13680038 2005-08-31 22:09:33.471 audio waiting for space on soundcard: have 4008 need 4096 2005-08-31 22:09:33.475 _AddSamples bytes=4608, used=172033, free=595967, timecode=13680062 2005-08-31 22:09:33.475 positionMap[ 12 ] == 9011592. 2005-08-31 22:09:33.479 _AddSamples bytes=4608, used=176641, free=591359, timecode=13680086 2005-08-31 22:09:33.479 _AddSamples bytes=4608, used=181249, free=586751, timecode=13680110 2005-08-31 22:09:33.483 _AddSamples bytes=4608, used=185857, free=582143, timecode=13680134 2005-08-31 22:09:33.483 Broadcasting free space avail 2005-08-31 22:09:33.483 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.483 audio waiting for space on soundcard: have 2292 need 4096 2005-08-31 22:09:33.484 _AddSamples bytes=4608, used=186369, free=581631, timecode=13680158 2005-08-31 22:09:33.488 _AddSamples bytes=4608, used=190977, free=577023, timecode=13680182 2005-08-31 22:09:33.492 _AddSamples bytes=4608, used=195585, free=572415, timecode=13680206 2005-08-31 22:09:33.492 _AddSamples bytes=4608, used=200193, free=567807, timecode=13680230 2005-08-31 22:09:33.495 Broadcasting free space avail 2005-08-31 22:09:33.496 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.496 audio waiting for space on soundcard: have 636 need 4096 2005-08-31 22:09:33.496 _AddSamples bytes=4608, used=200705, free=567295, timecode=13680254 2005-08-31 22:09:33.497 _AddSamples bytes=4608, used=205313, free=562687, timecode=13680278 2005-08-31 22:09:33.501 _AddSamples bytes=4608, used=209921, free=558079, timecode=13680302 2005-08-31 22:09:33.505 _AddSamples bytes=4608, used=214529, free=553471, timecode=13680326 2005-08-31 22:09:33.508 audio waiting for space on soundcard: have 2824 need 4096 2005-08-31 22:09:33.508 _AddSamples bytes=4608, used=219137, free=548863, timecode=13680350 2005-08-31 22:09:33.512 _AddSamples bytes=4608, used=223745, free=544255, timecode=13680374 2005-08-31 22:09:33.519 Broadcasting free space avail 2005-08-31 22:09:33.519 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.519 audio waiting for space on soundcard: have 1016 need 4096 2005-08-31 22:09:33.531 audio waiting for space on soundcard: have 3308 need 4096 2005-08-31 22:09:33.544 Broadcasting free space avail 2005-08-31 22:09:33.544 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.544 audio waiting for space on soundcard: have 1600 need 4096 2005-08-31 22:09:33.546 A/V diverged by 3.87188 frames, extending frame to keep audio in sync 2005-08-31 22:09:33.556 audio waiting for space on soundcard: have 3904 need 4096 2005-08-31 22:09:33.568 Broadcasting free space avail 2005-08-31 22:09:33.568 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.568 audio waiting for space on soundcard: have 2208 need 4096 2005-08-31 22:09:33.580 Broadcasting free space avail 2005-08-31 22:09:33.580 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.580 audio waiting for space on soundcard: have 456 need 4096 2005-08-31 22:09:33.592 audio waiting for space on soundcard: have 2768 need 4096 2005-08-31 22:09:33.605 Broadcasting free space avail 2005-08-31 22:09:33.605 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.605 audio waiting for space on soundcard: have 1104 need 4096 2005-08-31 22:09:33.617 audio waiting for space on soundcard: have 3408 need 4096 2005-08-31 22:09:33.626 A/V diverged by 5.06015 frames, extending frame to keep audio in sync 2005-08-31 22:09:33.628 read <- 18 6 128000 2005-08-31 22:09:33.628 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:33.629 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:33.629 _AddSamples bytes=4608, used=207873, free=560127, timecode=13680398 2005-08-31 22:09:33.629 Broadcasting free space avail 2005-08-31 22:09:33.630 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.630 audio waiting for space on soundcard: have 1724 need 4096 2005-08-31 22:09:33.633 _AddSamples bytes=4608, used=208385, free=559615, timecode=13680422 2005-08-31 22:09:33.637 _AddSamples bytes=4608, used=212993, free=555007, timecode=13680446 2005-08-31 22:09:33.638 _AddSamples bytes=4608, used=217601, free=550399, timecode=13680470 2005-08-31 22:09:33.641 audio waiting for space on soundcard: have 3960 need 4096 2005-08-31 22:09:33.642 _AddSamples bytes=4608, used=222209, free=545791, timecode=13680494 2005-08-31 22:09:33.642 _AddSamples bytes=4608, used=226817, free=541183, timecode=13680518 2005-08-31 22:09:33.646 _AddSamples bytes=4608, used=231425, free=536575, timecode=13680542 2005-08-31 22:09:33.646 positionMap[ 13 ] == 9215384. 2005-08-31 22:09:33.650 _AddSamples bytes=4608, used=236033, free=531967, timecode=13680566 2005-08-31 22:09:33.650 _AddSamples bytes=4608, used=240641, free=527359, timecode=13680590 2005-08-31 22:09:33.653 Broadcasting free space avail 2005-08-31 22:09:33.653 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.654 audio waiting for space on soundcard: have 2220 need 4096 2005-08-31 22:09:33.666 Broadcasting free space avail 2005-08-31 22:09:33.666 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.666 audio waiting for space on soundcard: have 484 need 4096 2005-08-31 22:09:33.678 audio waiting for space on soundcard: have 2792 need 4096 2005-08-31 22:09:33.690 Broadcasting free space avail 2005-08-31 22:09:33.690 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.690 audio waiting for space on soundcard: have 1108 need 4096 2005-08-31 22:09:33.703 audio waiting for space on soundcard: have 3420 need 4096 2005-08-31 22:09:33.706 A/V diverged by 5.70135 frames, extending frame to keep audio in sync 2005-08-31 22:09:33.711 _AddSamples bytes=4608, used=232961, free=535039, timecode=13680614 2005-08-31 22:09:33.712 _AddSamples bytes=4608, used=237569, free=530431, timecode=13680638 2005-08-31 22:09:33.715 Broadcasting free space avail 2005-08-31 22:09:33.715 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.715 audio waiting for space on soundcard: have 1704 need 4096 2005-08-31 22:09:33.727 audio waiting for space on soundcard: have 4044 need 4096 2005-08-31 22:09:33.739 Broadcasting free space avail 2005-08-31 22:09:33.739 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.740 audio waiting for space on soundcard: have 2332 need 4096 2005-08-31 22:09:33.751 Broadcasting free space avail 2005-08-31 22:09:33.752 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.752 audio waiting for space on soundcard: have 572 need 4096 2005-08-31 22:09:33.764 audio waiting for space on soundcard: have 2916 need 4096 2005-08-31 22:09:33.776 Broadcasting free space avail 2005-08-31 22:09:33.776 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.776 audio waiting for space on soundcard: have 1232 need 4096 2005-08-31 22:09:33.786 A/V diverged by 5.93225 frames, extending frame to keep audio in sync 2005-08-31 22:09:33.788 audio waiting for space on soundcard: have 3516 need 4096 2005-08-31 22:09:33.791 _AddSamples bytes=4608, used=225793, free=542207, timecode=13680662 2005-08-31 22:09:33.801 Broadcasting free space avail 2005-08-31 22:09:33.801 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.801 audio waiting for space on soundcard: have 1812 need 4096 2005-08-31 22:09:33.813 Broadcasting free space avail 2005-08-31 22:09:33.813 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.813 audio waiting for space on soundcard: have 60 need 4096 2005-08-31 22:09:33.825 audio waiting for space on soundcard: have 2384 need 4096 2005-08-31 22:09:33.837 Broadcasting free space avail 2005-08-31 22:09:33.837 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.838 audio waiting for space on soundcard: have 672 need 4096 2005-08-31 22:09:33.850 audio waiting for space on soundcard: have 2996 need 4096 2005-08-31 22:09:33.862 Broadcasting free space avail 2005-08-31 22:09:33.862 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.862 audio waiting for space on soundcard: have 1304 need 4096 2005-08-31 22:09:33.866 A/V diverged by 5.85542 frames, extending frame to keep audio in sync 2005-08-31 22:09:33.871 _AddSamples bytes=4608, used=214017, free=553983, timecode=13680686 2005-08-31 22:09:33.872 _AddSamples bytes=4608, used=218625, free=549375, timecode=13680710 2005-08-31 22:09:33.878 Broadcasting free space avail 2005-08-31 22:09:33.878 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.878 audio waiting for space on soundcard: have 340 need 4096 2005-08-31 22:09:33.891 audio waiting for space on soundcard: have 2648 need 4096 2005-08-31 22:09:33.903 Broadcasting free space avail 2005-08-31 22:09:33.903 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.903 audio waiting for space on soundcard: have 952 need 4096 2005-08-31 22:09:33.915 audio waiting for space on soundcard: have 3256 need 4096 2005-08-31 22:09:33.927 Broadcasting free space avail 2005-08-31 22:09:33.927 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.927 audio waiting for space on soundcard: have 1560 need 4096 2005-08-31 22:09:33.940 audio waiting for space on soundcard: have 3872 need 4096 2005-08-31 22:09:33.946 A/V diverged by 5.5478 frames, extending frame to keep audio in sync 2005-08-31 22:09:33.951 _AddSamples bytes=4608, used=210945, free=557055, timecode=13680734 2005-08-31 22:09:33.952 Broadcasting free space avail 2005-08-31 22:09:33.952 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.952 audio waiting for space on soundcard: have 2148 need 4096 2005-08-31 22:09:33.962 read <- 18 6 128000 2005-08-31 22:09:33.962 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:33.963 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:33.963 _AddSamples bytes=4608, used=211457, free=556543, timecode=13680758 2005-08-31 22:09:33.964 Broadcasting free space avail 2005-08-31 22:09:33.964 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.964 audio waiting for space on soundcard: have 400 need 4096 2005-08-31 22:09:33.976 audio waiting for space on soundcard: have 2680 need 4096 2005-08-31 22:09:33.988 Broadcasting free space avail 2005-08-31 22:09:33.988 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:33.989 audio waiting for space on soundcard: have 992 need 4096 2005-08-31 22:09:34.001 audio waiting for space on soundcard: have 3320 need 4096 2005-08-31 22:09:34.013 Broadcasting free space avail 2005-08-31 22:09:34.013 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.013 audio waiting for space on soundcard: have 1648 need 4096 2005-08-31 22:09:34.025 audio waiting for space on soundcard: have 3928 need 4096 2005-08-31 22:09:34.028 A/V diverged by 5.0671 frames, extending frame to keep audio in sync 2005-08-31 22:09:34.033 _AddSamples bytes=4608, used=203777, free=564223, timecode=13680782 2005-08-31 22:09:34.037 Broadcasting free space avail 2005-08-31 22:09:34.037 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.038 audio waiting for space on soundcard: have 2212 need 4096 2005-08-31 22:09:34.050 Broadcasting free space avail 2005-08-31 22:09:34.050 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.050 audio waiting for space on soundcard: have 468 need 4096 2005-08-31 22:09:34.062 audio waiting for space on soundcard: have 2768 need 4096 2005-08-31 22:09:34.074 Broadcasting free space avail 2005-08-31 22:09:34.074 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.074 audio waiting for space on soundcard: have 1088 need 4096 2005-08-31 22:09:34.087 audio waiting for space on soundcard: have 3424 need 4096 2005-08-31 22:09:34.099 Broadcasting free space avail 2005-08-31 22:09:34.099 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.099 audio waiting for space on soundcard: have 1712 need 4096 2005-08-31 22:09:34.108 A/V diverged by 4.45033 frames, extending frame to keep audio in sync 2005-08-31 22:09:34.111 audio waiting for space on soundcard: have 4028 need 4096 2005-08-31 22:09:34.113 _AddSamples bytes=4608, used=192001, free=575999, timecode=13680806 2005-08-31 22:09:34.114 _AddSamples bytes=4608, used=196609, free=571391, timecode=13680830 2005-08-31 22:09:34.123 Broadcasting free space avail 2005-08-31 22:09:34.123 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.123 audio waiting for space on soundcard: have 2312 need 4096 2005-08-31 22:09:34.135 Broadcasting free space avail 2005-08-31 22:09:34.136 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.136 audio waiting for space on soundcard: have 572 need 4096 2005-08-31 22:09:34.148 audio waiting for space on soundcard: have 2888 need 4096 2005-08-31 22:09:34.160 Broadcasting free space avail 2005-08-31 22:09:34.160 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.160 audio waiting for space on soundcard: have 1212 need 4096 2005-08-31 22:09:34.172 audio waiting for space on soundcard: have 3528 need 4096 2005-08-31 22:09:34.185 Broadcasting free space avail 2005-08-31 22:09:34.185 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.185 audio waiting for space on soundcard: have 1852 need 4096 2005-08-31 22:09:34.188 A/V diverged by 3.73148 frames, extending frame to keep audio in sync 2005-08-31 22:09:34.193 _AddSamples bytes=4608, used=184833, free=583167, timecode=13680854 2005-08-31 22:09:34.194 _AddSamples bytes=4608, used=189441, free=578559, timecode=13680878 2005-08-31 22:09:34.197 Broadcasting free space avail 2005-08-31 22:09:34.197 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.197 audio waiting for space on soundcard: have 72 need 4096 2005-08-31 22:09:34.209 audio waiting for space on soundcard: have 2392 need 4096 2005-08-31 22:09:34.221 Broadcasting free space avail 2005-08-31 22:09:34.221 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.222 audio waiting for space on soundcard: have 668 need 4096 2005-08-31 22:09:34.234 audio waiting for space on soundcard: have 2996 need 4096 2005-08-31 22:09:34.246 Broadcasting free space avail 2005-08-31 22:09:34.246 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.246 audio waiting for space on soundcard: have 1316 need 4096 2005-08-31 22:09:34.262 Broadcasting free space avail 2005-08-31 22:09:34.262 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.262 audio waiting for space on soundcard: have 336 need 4096 2005-08-31 22:09:34.271 read <- 18 6 128000 2005-08-31 22:09:34.271 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:34.271 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:34.274 _AddSamples bytes=4608, used=177665, free=590335, timecode=13680902 2005-08-31 22:09:34.274 audio waiting for space on soundcard: have 2624 need 4096 2005-08-31 22:09:34.287 Broadcasting free space avail 2005-08-31 22:09:34.287 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.287 audio waiting for space on soundcard: have 960 need 4096 2005-08-31 22:09:34.299 audio waiting for space on soundcard: have 3260 need 4096 2005-08-31 22:09:34.311 Broadcasting free space avail 2005-08-31 22:09:34.311 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.312 audio waiting for space on soundcard: have 1584 need 4096 2005-08-31 22:09:34.324 audio waiting for space on soundcard: have 3888 need 4096 2005-08-31 22:09:34.333 _AddSamples bytes=4608, used=174081, free=593919, timecode=13680926 2005-08-31 22:09:34.333 _AddSamples bytes=4608, used=178689, free=589311, timecode=13680950 2005-08-31 22:09:34.336 Broadcasting free space avail 2005-08-31 22:09:34.336 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.336 audio waiting for space on soundcard: have 2148 need 4096 2005-08-31 22:09:34.348 Broadcasting free space avail 2005-08-31 22:09:34.348 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.348 audio waiting for space on soundcard: have 460 need 4096 2005-08-31 22:09:34.360 audio waiting for space on soundcard: have 2712 need 4096 2005-08-31 22:09:34.372 Broadcasting free space avail 2005-08-31 22:09:34.373 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.373 _AddSamples bytes=4608, used=171009, free=596991, timecode=13680974 2005-08-31 22:09:34.373 audio waiting for space on soundcard: have 1036 need 4096 2005-08-31 22:09:34.373 _AddSamples bytes=4608, used=175617, free=592383, timecode=13680998 2005-08-31 22:09:34.385 audio waiting for space on soundcard: have 3308 need 4096 2005-08-31 22:09:34.397 Broadcasting free space avail 2005-08-31 22:09:34.397 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.397 audio waiting for space on soundcard: have 1624 need 4096 2005-08-31 22:09:34.409 audio waiting for space on soundcard: have 3936 need 4096 2005-08-31 22:09:34.413 _AddSamples bytes=4608, used=176129, free=591871, timecode=13681022 2005-08-31 22:09:34.421 Broadcasting free space avail 2005-08-31 22:09:34.421 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.422 audio waiting for space on soundcard: have 2208 need 4096 2005-08-31 22:09:34.433 Broadcasting free space avail 2005-08-31 22:09:34.434 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.434 audio waiting for space on soundcard: have 444 need 4096 2005-08-31 22:09:34.446 audio waiting for space on soundcard: have 2756 need 4096 2005-08-31 22:09:34.449 positionMap[ 14 ] == 9380636. 2005-08-31 22:09:34.453 _AddSamples bytes=4608, used=172545, free=595455, timecode=13681046 2005-08-31 22:09:34.454 _AddSamples bytes=4608, used=177153, free=590847, timecode=13681070 2005-08-31 22:09:34.458 Broadcasting free space avail 2005-08-31 22:09:34.458 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.458 audio waiting for space on soundcard: have 1008 need 4096 2005-08-31 22:09:34.470 audio waiting for space on soundcard: have 3316 need 4096 2005-08-31 22:09:34.486 Broadcasting free space avail 2005-08-31 22:09:34.486 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.487 audio waiting for space on soundcard: have 2400 need 4096 2005-08-31 22:09:34.492 _AddSamples bytes=4608, used=173569, free=594431, timecode=13681094 2005-08-31 22:09:34.492 _AddSamples bytes=4608, used=178177, free=589823, timecode=13681118 2005-08-31 22:09:34.498 Broadcasting free space avail 2005-08-31 22:09:34.498 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.499 audio waiting for space on soundcard: have 620 need 4096 2005-08-31 22:09:34.511 audio waiting for space on soundcard: have 2916 need 4096 2005-08-31 22:09:34.523 Broadcasting free space avail 2005-08-31 22:09:34.523 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.523 audio waiting for space on soundcard: have 1224 need 4096 'video_output' mean = '32238.02', std. dev. = '49833.19', fps = '31.02' 2005-08-31 22:09:34.532 _AddSamples bytes=4608, used=174593, free=593407, timecode=13681142 2005-08-31 22:09:34.535 audio waiting for space on soundcard: have 3504 need 4096 2005-08-31 22:09:34.547 Broadcasting free space avail 2005-08-31 22:09:34.547 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.548 audio waiting for space on soundcard: have 1844 need 4096 2005-08-31 22:09:34.559 Broadcasting free space avail 2005-08-31 22:09:34.560 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.560 audio waiting for space on soundcard: have 64 need 4096 2005-08-31 22:09:34.572 audio waiting for space on soundcard: have 2356 need 4096 2005-08-31 22:09:34.572 _AddSamples bytes=4608, used=171009, free=596991, timecode=13681166 2005-08-31 22:09:34.573 _AddSamples bytes=4608, used=175617, free=592383, timecode=13681190 2005-08-31 22:09:34.584 Broadcasting free space avail 2005-08-31 22:09:34.584 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.584 audio waiting for space on soundcard: have 672 need 4096 2005-08-31 22:09:34.596 audio waiting for space on soundcard: have 2948 need 4096 2005-08-31 22:09:34.610 Broadcasting free space avail 2005-08-31 22:09:34.610 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.610 audio waiting for space on soundcard: have 1528 need 4096 2005-08-31 22:09:34.613 _AddSamples bytes=4608, used=172033, free=595967, timecode=13681214 2005-08-31 22:09:34.613 _AddSamples bytes=4608, used=176641, free=591359, timecode=13681238 2005-08-31 22:09:34.621 audio waiting for space on soundcard: have 3548 need 4096 2005-08-31 22:09:34.633 Broadcasting free space avail 2005-08-31 22:09:34.633 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.633 audio waiting for space on soundcard: have 1860 need 4096 2005-08-31 22:09:34.634 read <- 18 6 128000 2005-08-31 22:09:34.634 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:34.634 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:34.645 Broadcasting free space avail 2005-08-31 22:09:34.645 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.645 audio waiting for space on soundcard: have 124 need 4096 2005-08-31 22:09:34.654 _AddSamples bytes=4608, used=173057, free=594943, timecode=13681262 2005-08-31 22:09:34.657 audio waiting for space on soundcard: have 2384 need 4096 2005-08-31 22:09:34.669 Broadcasting free space avail 2005-08-31 22:09:34.669 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.670 audio waiting for space on soundcard: have 676 need 4096 2005-08-31 22:09:34.681 audio waiting for space on soundcard: have 2956 need 4096 2005-08-31 22:09:34.693 Broadcasting free space avail 2005-08-31 22:09:34.694 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.694 audio waiting for space on soundcard: have 1280 need 4096 2005-08-31 22:09:34.694 _AddSamples bytes=4608, used=169473, free=598527, timecode=13681286 2005-08-31 22:09:34.695 _AddSamples bytes=4608, used=174081, free=593919, timecode=13681310 2005-08-31 22:09:34.708 audio waiting for space on soundcard: have 4008 need 4096 2005-08-31 22:09:34.722 Broadcasting free space avail 2005-08-31 22:09:34.722 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.722 audio waiting for space on soundcard: have 2536 need 4096 2005-08-31 22:09:34.734 _AddSamples bytes=4608, used=174593, free=593407, timecode=13681334 2005-08-31 22:09:34.735 _AddSamples bytes=4608, used=179201, free=588799, timecode=13681358 2005-08-31 22:09:34.735 Broadcasting free space avail 2005-08-31 22:09:34.735 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.735 audio waiting for space on soundcard: have 1048 need 4096 2005-08-31 22:09:34.750 audio waiting for space on soundcard: have 3812 need 4096 2005-08-31 22:09:34.762 Broadcasting free space avail 2005-08-31 22:09:34.762 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.762 audio waiting for space on soundcard: have 2132 need 4096 2005-08-31 22:09:34.774 _AddSamples bytes=4608, used=175617, free=592383, timecode=13681382 2005-08-31 22:09:34.778 Broadcasting free space avail 2005-08-31 22:09:34.778 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.778 audio waiting for space on soundcard: have 1088 need 4096 2005-08-31 22:09:34.794 Broadcasting free space avail 2005-08-31 22:09:34.794 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.795 audio waiting for space on soundcard: have 112 need 4096 2005-08-31 22:09:34.807 audio waiting for space on soundcard: have 2416 need 4096 2005-08-31 22:09:34.814 _AddSamples bytes=4608, used=172033, free=595967, timecode=13681406 2005-08-31 22:09:34.815 _AddSamples bytes=4608, used=176641, free=591359, timecode=13681430 2005-08-31 22:09:34.818 Broadcasting free space avail 2005-08-31 22:09:34.818 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.819 audio waiting for space on soundcard: have 624 need 4096 2005-08-31 22:09:34.831 audio waiting for space on soundcard: have 2908 need 4096 2005-08-31 22:09:34.843 Broadcasting free space avail 2005-08-31 22:09:34.843 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.843 audio waiting for space on soundcard: have 1172 need 4096 2005-08-31 22:09:34.854 _AddSamples bytes=4608, used=173057, free=594943, timecode=13681454 2005-08-31 22:09:34.855 _AddSamples bytes=4608, used=177665, free=590335, timecode=13681478 2005-08-31 22:09:34.856 audio waiting for space on soundcard: have 3628 need 4096 2005-08-31 22:09:34.867 Broadcasting free space avail 2005-08-31 22:09:34.867 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.867 audio waiting for space on soundcard: have 1712 need 4096 2005-08-31 22:09:34.879 audio waiting for space on soundcard: have 4012 need 4096 2005-08-31 22:09:34.891 Broadcasting free space avail 2005-08-31 22:09:34.891 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.891 audio waiting for space on soundcard: have 2268 need 4096 2005-08-31 22:09:34.906 Broadcasting free space avail 2005-08-31 22:09:34.906 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.906 audio waiting for space on soundcard: have 992 need 4096 2005-08-31 22:09:34.911 _AddSamples bytes=4608, used=169985, free=598015, timecode=13681502 2005-08-31 22:09:34.915 audio waiting for space on soundcard: have 2752 need 4096 2005-08-31 22:09:34.928 Broadcasting free space avail 2005-08-31 22:09:34.928 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.928 audio waiting for space on soundcard: have 1108 need 4096 2005-08-31 22:09:34.929 positionMap[ 15 ] == 9548332. 2005-08-31 22:09:34.934 _AddSamples bytes=4608, used=170497, free=597503, timecode=13681526 2005-08-31 22:09:34.934 _AddSamples bytes=4608, used=175105, free=592895, timecode=13681550 2005-08-31 22:09:34.939 audio waiting for space on soundcard: have 3304 need 4096 2005-08-31 22:09:34.951 Broadcasting free space avail 2005-08-31 22:09:34.952 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.952 audio waiting for space on soundcard: have 1616 need 4096 2005-08-31 22:09:34.963 audio waiting for space on soundcard: have 3856 need 4096 2005-08-31 22:09:34.972 _AddSamples bytes=4608, used=175617, free=592383, timecode=13681574 2005-08-31 22:09:34.973 _AddSamples bytes=4608, used=180225, free=587775, timecode=13681598 2005-08-31 22:09:34.976 Broadcasting free space avail 2005-08-31 22:09:34.976 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.976 audio waiting for space on soundcard: have 2124 need 4096 2005-08-31 22:09:34.988 Broadcasting free space avail 2005-08-31 22:09:34.988 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:34.988 audio waiting for space on soundcard: have 368 need 4096 2005-08-31 22:09:35.000 audio waiting for space on soundcard: have 2624 need 4096 2005-08-31 22:09:35.012 Broadcasting free space avail 2005-08-31 22:09:35.012 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.012 _AddSamples bytes=4608, used=172545, free=595455, timecode=13681622 2005-08-31 22:09:35.012 audio waiting for space on soundcard: have 924 need 4096 2005-08-31 22:09:35.024 audio waiting for space on soundcard: have 3244 need 4096 2005-08-31 22:09:35.036 Broadcasting free space avail 2005-08-31 22:09:35.036 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.036 audio waiting for space on soundcard: have 1472 need 4096 2005-08-31 22:09:35.049 audio waiting for space on soundcard: have 3932 need 4096 2005-08-31 22:09:35.052 _AddSamples bytes=4608, used=173057, free=594943, timecode=13681646 2005-08-31 22:09:35.053 _AddSamples bytes=4608, used=177665, free=590335, timecode=13681670 2005-08-31 22:09:35.060 Broadcasting free space avail 2005-08-31 22:09:35.060 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.061 audio waiting for space on soundcard: have 2016 need 4096 2005-08-31 22:09:35.073 Broadcasting free space avail 2005-08-31 22:09:35.073 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.073 audio waiting for space on soundcard: have 296 need 4096 2005-08-31 22:09:35.081 read <- 18 6 128000 2005-08-31 22:09:35.082 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:35.082 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:35.085 audio waiting for space on soundcard: have 2544 need 4096 2005-08-31 22:09:35.093 _AddSamples bytes=4608, used=174081, free=593919, timecode=13681694 2005-08-31 22:09:35.094 _AddSamples bytes=4608, used=178689, free=589311, timecode=13681718 2005-08-31 22:09:35.097 Broadcasting free space avail 2005-08-31 22:09:35.097 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.097 audio waiting for space on soundcard: have 808 need 4096 2005-08-31 22:09:35.109 audio waiting for space on soundcard: have 3096 need 4096 2005-08-31 22:09:35.121 Broadcasting free space avail 2005-08-31 22:09:35.121 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.121 audio waiting for space on soundcard: have 1392 need 4096 2005-08-31 22:09:35.132 _AddSamples bytes=4608, used=175105, free=592895, timecode=13681742 2005-08-31 22:09:35.133 audio waiting for space on soundcard: have 3656 need 4096 2005-08-31 22:09:35.145 Broadcasting free space avail 2005-08-31 22:09:35.145 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.146 audio waiting for space on soundcard: have 1948 need 4096 2005-08-31 22:09:35.157 Broadcasting free space avail 2005-08-31 22:09:35.158 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.158 audio waiting for space on soundcard: have 216 need 4096 2005-08-31 22:09:35.173 _AddSamples bytes=4608, used=171521, free=596479, timecode=13681766 2005-08-31 22:09:35.174 audio waiting for space on soundcard: have 3252 need 4096 2005-08-31 22:09:35.174 _AddSamples bytes=4608, used=176129, free=591871, timecode=13681790 2005-08-31 22:09:35.186 Broadcasting free space avail 2005-08-31 22:09:35.186 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.186 audio waiting for space on soundcard: have 1548 need 4096 2005-08-31 22:09:35.198 audio waiting for space on soundcard: have 3808 need 4096 2005-08-31 22:09:35.210 Broadcasting free space avail 2005-08-31 22:09:35.210 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.211 audio waiting for space on soundcard: have 2156 need 4096 2005-08-31 22:09:35.212 _AddSamples bytes=4608, used=172545, free=595455, timecode=13681814 2005-08-31 22:09:35.213 _AddSamples bytes=4608, used=177153, free=590847, timecode=13681838 2005-08-31 22:09:35.226 Broadcasting free space avail 2005-08-31 22:09:35.226 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.227 audio waiting for space on soundcard: have 1140 need 4096 2005-08-31 22:09:35.238 audio waiting for space on soundcard: have 3416 need 4096 2005-08-31 22:09:35.253 _AddSamples bytes=4608, used=177665, free=590335, timecode=13681862 2005-08-31 22:09:35.254 Broadcasting free space avail 2005-08-31 22:09:35.254 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.254 audio waiting for space on soundcard: have 2284 need 4096 2005-08-31 22:09:35.263 audio waiting for space on soundcard: have 3948 need 4096 2005-08-31 22:09:35.275 Broadcasting free space avail 2005-08-31 22:09:35.275 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.275 audio waiting for space on soundcard: have 2236 need 4096 2005-08-31 22:09:35.287 Broadcasting free space avail 2005-08-31 22:09:35.287 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.287 audio waiting for space on soundcard: have 468 need 4096 2005-08-31 22:09:35.291 _AddSamples bytes=4608, used=169985, free=598015, timecode=13681886 2005-08-31 22:09:35.292 _AddSamples bytes=4608, used=174593, free=593407, timecode=13681910 2005-08-31 22:09:35.299 audio waiting for space on soundcard: have 2704 need 4096 2005-08-31 22:09:35.311 Broadcasting free space avail 2005-08-31 22:09:35.311 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.311 audio waiting for space on soundcard: have 1008 need 4096 2005-08-31 22:09:35.323 audio waiting for space on soundcard: have 3288 need 4096 2005-08-31 22:09:35.332 _AddSamples bytes=4608, used=175105, free=592895, timecode=13681934 2005-08-31 22:09:35.332 _AddSamples bytes=4608, used=179713, free=588287, timecode=13681958 2005-08-31 22:09:35.335 Broadcasting free space avail 2005-08-31 22:09:35.336 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.336 audio waiting for space on soundcard: have 1584 need 4096 2005-08-31 22:09:35.347 audio waiting for space on soundcard: have 3848 need 4096 2005-08-31 22:09:35.360 Broadcasting free space avail 2005-08-31 22:09:35.360 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.360 audio waiting for space on soundcard: have 2148 need 4096 2005-08-31 22:09:35.372 _AddSamples bytes=4608, used=176129, free=591871, timecode=13681982 2005-08-31 22:09:35.372 Broadcasting free space avail 2005-08-31 22:09:35.372 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.372 audio waiting for space on soundcard: have 368 need 4096 2005-08-31 22:09:35.384 audio waiting for space on soundcard: have 2716 need 4096 2005-08-31 22:09:35.396 Broadcasting free space avail 2005-08-31 22:09:35.396 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.397 audio waiting for space on soundcard: have 996 need 4096 2005-08-31 22:09:35.408 positionMap[ 16 ] == 9707380. 2005-08-31 22:09:35.413 audio waiting for space on soundcard: have 4088 need 4096 2005-08-31 22:09:35.413 _AddSamples bytes=4608, used=172545, free=595455, timecode=13682006 2005-08-31 22:09:35.414 _AddSamples bytes=4608, used=177153, free=590847, timecode=13682030 2005-08-31 22:09:35.425 Broadcasting free space avail 2005-08-31 22:09:35.425 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.425 audio waiting for space on soundcard: have 2408 need 4096 2005-08-31 22:09:35.434 read <- 18 6 128000 2005-08-31 22:09:35.434 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:35.434 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:09:35.437 Broadcasting free space avail 2005-08-31 22:09:35.437 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.437 audio waiting for space on soundcard: have 640 need 4096 2005-08-31 22:09:35.450 audio waiting for space on soundcard: have 2984 need 4096 2005-08-31 22:09:35.453 _AddSamples bytes=4608, used=173569, free=594431, timecode=13682054 2005-08-31 22:09:35.454 _AddSamples bytes=4608, used=178177, free=589823, timecode=13682078 2005-08-31 22:09:35.461 Broadcasting free space avail 2005-08-31 22:09:35.462 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.462 audio waiting for space on soundcard: have 1216 need 4096 2005-08-31 22:09:35.473 audio waiting for space on soundcard: have 3464 need 4096 2005-08-31 22:09:35.485 Broadcasting free space avail 2005-08-31 22:09:35.486 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.486 audio waiting for space on soundcard: have 1760 need 4096 2005-08-31 22:09:35.493 _AddSamples bytes=4608, used=174593, free=593407, timecode=13682102 2005-08-31 22:09:35.498 audio waiting for space on soundcard: have 3992 need 4096 2005-08-31 22:09:35.510 Broadcasting free space avail 2005-08-31 22:09:35.510 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.510 audio waiting for space on soundcard: have 2284 need 4096 2005-08-31 22:09:35.522 Broadcasting free space avail 2005-08-31 22:09:35.522 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.522 audio waiting for space on soundcard: have 476 need 4096 2005-08-31 22:09:35.533 _AddSamples bytes=4608, used=171009, free=596991, timecode=13682126 2005-08-31 22:09:35.534 _AddSamples bytes=4608, used=175617, free=592383, timecode=13682150 2005-08-31 22:09:35.534 audio waiting for space on soundcard: have 2728 need 4096 2005-08-31 22:09:35.548 Broadcasting free space avail 2005-08-31 22:09:35.548 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.549 audio waiting for space on soundcard: have 1500 need 4096 2005-08-31 22:09:35.562 audio waiting for space on soundcard: have 4008 need 4096 2005-08-31 22:09:35.573 _AddSamples bytes=4608, used=176129, free=591871, timecode=13682174 2005-08-31 22:09:35.574 _AddSamples bytes=4608, used=180737, free=587263, timecode=13682198 2005-08-31 22:09:35.574 Broadcasting free space avail 2005-08-31 22:09:35.574 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.574 audio waiting for space on soundcard: have 2376 need 4096 2005-08-31 22:09:35.586 Attempting to change from WatchingLiveTV to None 2005-08-31 22:09:35.586 TV::StopStuff() -- begin 2005-08-31 22:09:35.586 TV::StopStuff(): stopping ring buffer[s] 2005-08-31 22:09:35.590 Broadcasting free space avail 2005-08-31 22:09:35.590 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.590 audio waiting for space on soundcard: have 1244 need 4096 2005-08-31 22:09:35.602 audio waiting for space on soundcard: have 3496 need 4096 2005-08-31 22:09:35.613 _AddSamples bytes=4608, used=177153, free=590847, timecode=13682222 2005-08-31 22:09:35.614 Broadcasting free space avail 2005-08-31 22:09:35.614 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.614 audio waiting for space on soundcard: have 1776 need 4096 2005-08-31 22:09:35.626 audio waiting for space on soundcard: have 4008 need 4096 2005-08-31 22:09:35.638 Broadcasting free space avail 2005-08-31 22:09:35.638 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.638 audio waiting for space on soundcard: have 2264 need 4096 2005-08-31 22:09:35.650 Broadcasting free space avail 2005-08-31 22:09:35.650 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.650 audio waiting for space on soundcard: have 544 need 4096 2005-08-31 22:09:35.653 _AddSamples bytes=4608, used=169473, free=598527, timecode=13682246 2005-08-31 22:09:35.653 _AddSamples bytes=4608, used=174081, free=593919, timecode=13682270 2005-08-31 22:09:35.666 audio waiting for space on soundcard: have 3496 need 4096 2005-08-31 22:09:35.678 Broadcasting free space avail 2005-08-31 22:09:35.678 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.678 audio waiting for space on soundcard: have 1808 need 4096 2005-08-31 22:09:35.690 audio waiting for space on soundcard: have 4012 need 4096 2005-08-31 22:09:35.693 _AddSamples bytes=4608, used=174593, free=593407, timecode=13682294 2005-08-31 22:09:35.693 _AddSamples bytes=4608, used=179201, free=588799, timecode=13682318 2005-08-31 22:09:35.702 Broadcasting free space avail 2005-08-31 22:09:35.702 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.702 audio waiting for space on soundcard: have 2276 need 4096 2005-08-31 22:09:35.714 Broadcasting free space avail 2005-08-31 22:09:35.714 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.714 audio waiting for space on soundcard: have 488 need 4096 2005-08-31 22:09:35.726 audio waiting for space on soundcard: have 2740 need 4096 2005-08-31 22:09:35.733 _AddSamples bytes=4608, used=175617, free=592383, timecode=13682342 2005-08-31 22:09:35.738 Broadcasting free space avail 2005-08-31 22:09:35.738 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.738 audio waiting for space on soundcard: have 1000 need 4096 2005-08-31 22:09:35.750 audio waiting for space on soundcard: have 3244 need 4096 2005-08-31 22:09:35.762 Broadcasting free space avail 2005-08-31 22:09:35.762 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.762 audio waiting for space on soundcard: have 1544 need 4096 2005-08-31 22:09:35.772 _AddSamples bytes=4608, used=172033, free=595967, timecode=13682366 2005-08-31 22:09:35.772 _AddSamples bytes=4608, used=176641, free=591359, timecode=13682390 2005-08-31 22:09:35.774 audio waiting for space on soundcard: have 3840 need 4096 2005-08-31 22:09:35.786 Broadcasting free space avail 2005-08-31 22:09:35.786 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.787 audio waiting for space on soundcard: have 2144 need 4096 2005-08-31 22:09:35.789 read <- 18 6 128000 2005-08-31 22:09:35.789 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:09:35.789 TV::StopStuff(): stopping player[s] (1/2) 2005-08-31 22:09:35.789 TV::StopStuff(): stopping recorder[s] 2005-08-31 22:09:35.789 write -> 17 32 QUERY_RECORDER 1[]:[]STOP_LIVETV 2005-08-31 22:09:35.798 Broadcasting free space avail 2005-08-31 22:09:35.799 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.799 audio waiting for space on soundcard: have 372 need 4096 2005-08-31 22:09:35.808 ~VideoOutputXv() 2005-08-31 22:09:35.808 VideoBuffers::DiscardFrames(): LUUUUUUAUUUUUUUUUUUUUUUUUUUUUUU 2005-08-31 22:09:35.808 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2005-08-31 22:09:35.808 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA 2005-08-31 22:09:35.809 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done() 2005-08-31 22:09:35.818 read <- 16 48 BACKEND_MESSAGE[]:[]DONE_RECORDING 1 4[]:[]empty 2005-08-31 22:09:35.819 Broadcasting free space avail 2005-08-31 22:09:35.820 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:09:35.821 audio waiting for space on soundcard: have 504 need 4096 2005-08-31 22:09:35.822 Killing AudioOutputDSP 2005-08-31 22:09:35.831 OutputAudioLoop: Stop Event 2005-08-31 22:09:35.831 kickoffOutputAudioLoop exiting 2005-08-31 22:09:35.875 read <- 17 2 ok 2005-08-31 22:09:35.875 TV::StopStuff(): stopping player[s] (2/2) 2005-08-31 22:09:35.884 write -> 18 33 QUERY_RECORDER 1[]:[]DONE_RINGBUF 2005-08-31 22:09:35.891 read <- 16 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty 2005-08-31 22:09:35.899 read <- 16 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty 2005-08-31 22:09:35.899 read <- 18 2 OK 2005-08-31 22:09:35.900 TV::StopStuff() -- end 2005-08-31 22:09:35.900 Changing from WatchingLiveTV to None 2005-08-31 22:09:35.907 Attempting to change from None to None 2005-08-31 22:09:44.387 write -> 14 34 QUERY_IS_ACTIVE_BACKEND[]:[]vdrtv1 2005-08-31 22:09:44.406 read <- 14 4 TRUE Destroying SipFsm object