2005-08-31 22:07:32.687 Using runtime prefix = /usr 2005-08-31 22:07:32.705 New DB connection, total: 1 2005-08-31 22:07:32.707 Total desktop dim: 720x576, with 1 screen[s]. 2005-08-31 22:07:32.709 Using screen 0, 720x576 at 0,0 2005-08-31 22:07:32.713 mythfrontend version: 0.19.20050712-1 www.mythtv.org 2005-08-31 22:07:32.713 Enabled verbose msgs :all 2005-08-31 22:07:32.848 max_width: 720 max_height: 576 2005-08-31 22:07:32.926 Total desktop dim: 720x576, with 1 screen[s]. 2005-08-31 22:07:32.927 Using screen 0, 720x576 at 0,0 2005-08-31 22:07:32.928 Switching to square mode (blue) 2005-08-31 22:07:33.119 Registering Internal as a media playback plugin. 2005-08-31 22:07:33.134 Registering MythDVD DVD Media Handler as a media handler 2005-08-31 22:07:33.135 Registering MythDVD VCD Media Handler as a media handler 2005-08-31 22:07:33.468 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:07:33.771 generating cache image for: /usr/share/mythtv/themes/default/blank.png 2005-08-31 22:07:34.059 Starting media monitor. 2005-08-31 22:07:35.023 New DB connection, total: 2 2005-08-31 22:07:35.066 Connecting to backend server: 127.0.0.1:6543 (try 1 of 5) 2005-08-31 22:07:35.067 write -> 14 21 ANN Playback vdrtv1 0 2005-08-31 22:07:35.080 read <- 14 2 OK 2005-08-31 22:07:35.082 write -> 14 29 GET_NEXT_FREE_RECORDER[]:[]-1 2005-08-31 22:07:35.096 read <- 14 24 1[]:[]127.0.0.1[]:[]6543 2005-08-31 22:07:35.096 write -> 16 21 ANN Playback vdrtv1 1 2005-08-31 22:07:35.100 Attempting to change from None to WatchingLiveTV 2005-08-31 22:07:35.100 write -> 17 21 MYTH_PROTO_VERSION 18 2005-08-31 22:07:35.112 read <- 16 2 OK 2005-08-31 22:07:35.116 read <- 17 13 ACCEPT[]:[]18 2005-08-31 22:07:35.116 Using protocol version 18 2005-08-31 22:07:35.116 write -> 17 21 ANN Playback vdrtv1 0 2005-08-31 22:07:35.132 read <- 17 2 OK 2005-08-31 22:07:35.132 write -> 17 44 QUERY_RECORDER 1[]:[]SETUP_RING_BUFFER[]:[]0 2005-08-31 22:07:35.148 read <- 17 92 ok[]:[]rbuf://127.0.0.1:6543/mnt/store/ringbuf1.nuv[]:[]2[]:[]-21... 2005-08-31 22:07:35.149 write -> 18 21 ANN Playback vdrtv1 0 2005-08-31 22:07:35.164 read <- 18 2 OK 2005-08-31 22:07:35.165 write -> 19 23 ANN RingBuffer vdrtv1 1 2005-08-31 22:07:35.181 read <- 19 2 OK 2005-08-31 22:07:35.181 write -> 17 33 QUERY_RECORDER 1[]:[]SPAWN_LIVETV 2005-08-31 22:07:35.213 read <- 17 2 ok 2005-08-31 22:07:35.213 write -> 17 33 QUERY_RECORDER 1[]:[]IS_RECORDING 2005-08-31 22:07:35.229 read <- 17 1 1 2005-08-31 22:07:35.229 write -> 17 33 QUERY_RECORDER 1[]:[]IS_RECORDING 2005-08-31 22:07:35.245 read <- 17 1 1 2005-08-31 22:07:35.245 write -> 17 34 QUERY_RECORDER 1[]:[]GET_FRAMERATE 2005-08-31 22:07:35.261 read <- 17 2 25 2005-08-31 22:07:35.278 write -> 17 37 QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO 2005-08-31 22:07:35.293 read <- 17 103 []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10... 2005-08-31 22:07:35.294 Output filters for this channel are: '' 2005-08-31 22:07:35.297 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:07:35.298 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.314 read <- 18 6 128000 2005-08-31 22:07:35.314 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.322 write -> 18 66 QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]2048 2005-08-31 22:07:35.338 read <- 18 7 0[]:[]0 2005-08-31 22:07:35.346 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.354 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:07:35.354 read <- 18 6 128000 2005-08-31 22:07:35.354 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.362 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.370 read <- 18 6 128000 2005-08-31 22:07:35.371 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.378 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.387 read <- 18 6 128000 2005-08-31 22:07:35.387 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.398 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.407 read <- 18 6 128000 2005-08-31 22:07:35.407 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.410 read <- 16 475 BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30... 2005-08-31 22:07:35.418 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.427 read <- 18 6 128000 2005-08-31 22:07:35.427 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.438 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.447 read <- 18 6 128000 2005-08-31 22:07:35.447 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.458 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.467 read <- 18 6 128000 2005-08-31 22:07:35.467 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.467 write -> 18 68 QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]851968 2005-08-31 22:07:35.486 read <- 18 7 0[]:[]0 2005-08-31 22:07:35.487 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.499 read <- 18 6 128000 2005-08-31 22:07:35.499 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.511 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.523 read <- 18 6 128000 2005-08-31 22:07:35.523 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.535 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.547 read <- 18 6 128000 2005-08-31 22:07:35.547 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.559 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.571 read <- 18 6 128000 2005-08-31 22:07:35.571 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.583 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.591 read <- 18 6 128000 2005-08-31 22:07:35.591 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.599 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.608 read <- 18 6 128000 2005-08-31 22:07:35.608 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.615 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.624 read <- 18 6 128000 2005-08-31 22:07:35.624 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.631 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.640 read <- 18 6 128000 2005-08-31 22:07:35.640 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.647 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.657 read <- 18 6 128000 2005-08-31 22:07:35.657 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.664 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.673 read <- 18 6 128000 2005-08-31 22:07:35.673 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.679 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.689 read <- 18 6 128000 2005-08-31 22:07:35.689 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.695 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.705 read <- 18 6 128000 2005-08-31 22:07:35.705 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.712 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.721 read <- 18 6 128000 2005-08-31 22:07:35.721 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.728 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.737 read <- 18 6 128000 2005-08-31 22:07:35.737 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.744 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.753 read <- 18 6 128000 2005-08-31 22:07:35.753 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.760 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.769 read <- 18 6 128000 2005-08-31 22:07:35.769 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.776 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.785 read <- 18 6 128000 2005-08-31 22:07:35.785 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.792 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.801 read <- 18 6 128000 2005-08-31 22:07:35.801 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.808 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.817 read <- 18 6 128000 2005-08-31 22:07:35.817 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.824 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.833 read <- 18 6 128000 2005-08-31 22:07:35.833 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.841 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.849 read <- 18 6 128000 2005-08-31 22:07:35.849 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.857 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.865 read <- 18 6 128000 2005-08-31 22:07:35.865 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.873 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.881 read <- 18 6 128000 2005-08-31 22:07:35.881 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.889 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.898 read <- 18 6 128000 2005-08-31 22:07:35.898 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.905 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.913 read <- 18 6 128000 2005-08-31 22:07:35.913 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.921 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.929 read <- 18 6 128000 2005-08-31 22:07:35.930 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.938 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.945 read <- 18 6 128000 2005-08-31 22:07:35.946 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.953 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.966 read <- 18 6 128000 2005-08-31 22:07:35.966 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.973 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:35.982 read <- 18 6 128000 2005-08-31 22:07:35.982 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:35.989 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.002 read <- 18 6 128000 2005-08-31 22:07:36.002 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.010 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.018 read <- 18 6 128000 2005-08-31 22:07:36.018 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.025 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.036 read <- 18 6 128000 2005-08-31 22:07:36.036 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.045 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.054 read <- 18 6 128000 2005-08-31 22:07:36.054 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.062 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.071 read <- 18 6 128000 2005-08-31 22:07:36.071 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.082 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.091 read <- 18 6 128000 2005-08-31 22:07:36.091 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.102 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.111 read <- 18 6 128000 2005-08-31 22:07:36.111 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.118 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.126 read <- 18 6 128000 2005-08-31 22:07:36.127 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.138 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.147 read <- 18 6 128000 2005-08-31 22:07:36.147 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.158 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.167 read <- 18 6 128000 2005-08-31 22:07:36.167 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.178 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.187 read <- 18 6 128000 2005-08-31 22:07:36.187 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.199 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.346 read <- 18 6 128000 2005-08-31 22:07:36.346 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.353 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.652 read <- 18 6 128000 2005-08-31 22:07:36.652 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.663 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:36.861 read <- 18 6 128000 2005-08-31 22:07:36.861 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:36.868 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:37.054 read <- 18 6 128000 2005-08-31 22:07:37.054 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:37.061 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:37.242 read <- 18 6 128000 2005-08-31 22:07:37.242 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:37.249 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:37.438 read <- 18 6 128000 2005-08-31 22:07:37.438 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:37.446 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:37.626 read <- 18 6 128000 2005-08-31 22:07:37.626 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:37.634 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:37.814 read <- 18 6 128000 2005-08-31 22:07:37.814 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:37.822 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:38.011 read <- 18 6 128000 2005-08-31 22:07:38.011 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:38.022 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:38.263 read <- 18 6 128000 2005-08-31 22:07:38.263 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:38.264 write -> 18 75 QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]6389760[]:[]0[]:[]0[]... 2005-08-31 22:07:38.283 read <- 18 13 0[]:[]6389760 0: start_time: -9223372036854.775 duration: -9223372036854.775 1: start_time: -9223372036854.775 duration: -9223372036854.775 stream: start_time: -9223372036854.775 duration: -9223372036854.775 bitrate=5224 kb/s 2005-08-31 22:07:38.283 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:38.283 AVFD: Stream #0, has id 0x215 codec id MPEG2VIDEO, type Video at 0x0x827e940 2005-08-31 22:07:38.285 XvMC version: 1.0 2005-08-31 22:07:38.285 XvMCSurfaceTypes::find(w 704, h 576, chroma 1, vld 0, idct 1, mpeg2, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:07:38.285 Trying XvMC port 270 2005-08-31 22:07:38.286 Found a suitable XvMC surface 0 2005-08-31 22:07:38.287 @ j=1 Looking for flag[s]: XvInputMask 2005-08-31 22:07:38.287 Adaptor: 0 has flag[s]: XvInputMask XvImageMask 2005-08-31 22:07:38.287 XvMCSurfaceTypes::find(w 704, h 576, chroma 1, vld 0, idct 1, mpeg2, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:07:38.287 Trying XvMC port 270 2005-08-31 22:07:38.287 Found a suitable XvMC surface 0 2005-08-31 22:07:38.287 XvMC surface found with IDCT support on port 270 2005-08-31 22:07:38.317 detectInterlace(Detect Scan, Detect Scan, 25, 576) ->Interlaced Scan 2005-08-31 22:07:38.317 Interlaced: Interlaced Scan video_height: 576 fps: 25 2005-08-31 22:07:38.317 AVFD: Looking for decoder for MPEG2VIDEO_XVMC 2005-08-31 22:07:38.317 AVFD: Opened codec 0x82a1310, id(MPEG2VIDEO_XVMC) type(Video) 2005-08-31 22:07:38.317 AVFD: Stream #1, has id 0x888 codec id MP3, type Audio at 0x0x82a1610 2005-08-31 22:07:38.317 AVFD: Looking for decoder for MP3 2005-08-31 22:07:38.332 AVFD: Opened codec 0x829cea0, id(MP3) type(Audio) 2005-08-31 22:07:38.332 AVFD: Stream #1 (audio track #0) is an audio stream with 2 channels. 2005-08-31 22:07:38.333 Auto-selecting audio track #1 (stream #1). 2005-08-31 22:07:38.333 It has 2 channels and we needed at least 1 2005-08-31 22:07:38.333 Initializing audio parms from audio track #0. 2005-08-31 22:07:38.334 Killing AudioOutputDSP 2005-08-31 22:07:38.334 Opening audio device 'spdif'. 2005-08-31 22:07:38.342 in SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=125000) 2005-08-31 22:07:38.342 get_buffer_size returned 16384 2005-08-31 22:07:38.343 set_period_time_near returned 85333 2005-08-31 22:07:38.343 get_period_size returned 4096 2005-08-31 22:07:38.343 Audio fragment size: 4096 2005-08-31 22:07:38.344 Audio Stretch Factor: 1 2005-08-31 22:07:38.344 Ending reconfigure 2005-08-31 22:07:38.344 kickoffOutputAudioLoop: pid = 11615 2005-08-31 22:07:38.344 OutputAudioLoop: Play Event 2005-08-31 22:07:38.344 Broadcasting free space avail 2005-08-31 22:07:38.355 Broadcasting free space avail 2005-08-31 22:07:38.363 Broadcasting free space avail 2005-08-31 22:07:38.371 Broadcasting free space avail 2005-08-31 22:07:38.379 Broadcasting free space avail 2005-08-31 22:07:38.387 Broadcasting free space avail 2005-08-31 22:07:38.396 Broadcasting free space avail 2005-08-31 22:07:38.404 Broadcasting free space avail 2005-08-31 22:07:38.412 Broadcasting free space avail 2005-08-31 22:07:38.420 Broadcasting free space avail 2005-08-31 22:07:38.428 Broadcasting free space avail 2005-08-31 22:07:38.436 Broadcasting free space avail 2005-08-31 22:07:38.445 Broadcasting free space avail 2005-08-31 22:07:38.453 Broadcasting free space avail 2005-08-31 22:07:38.461 Broadcasting free space avail 2005-08-31 22:07:38.469 Broadcasting free space avail 2005-08-31 22:07:38.477 Broadcasting free space avail 2005-08-31 22:07:38.485 Broadcasting free space avail 2005-08-31 22:07:38.486 read <- 18 6 128000 2005-08-31 22:07:38.486 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:38.486 Estimated bitrate = 5224 2005-08-31 22:07:38.486 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0) 2005-08-31 22:07:38.487 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:07:38.494 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:38.494 Broadcasting free space avail 2005-08-31 22:07:38.502 Broadcasting free space avail 2005-08-31 22:07:38.502 read <- 17 8 0[]:[]53 2005-08-31 22:07:38.502 Filling position map from 0 to 53 2005-08-31 22:07:38.502 write -> 17 51 QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]0[]:[]53 2005-08-31 22:07:38.510 Broadcasting free space avail 2005-08-31 22:07:38.510 read <- 17 119 0[]:[]11[]:[]0[]:[]5631164[]:[]0[]:[]23[]:[]0[]:[]5911660[]:[]0[]... 2005-08-31 22:07:38.510 Position map filled from Encoder to: 47 2005-08-31 22:07:38.511 SyncPositionMap liveTV, from Encoder: 4 entries 2005-08-31 22:07:38.511 SyncPositionMap, new totframes: 47, new length: 1, posMap size: 4 2005-08-31 22:07:38.511 Partial position map found 2005-08-31 22:07:38.511 AvFormatDecoder: Successfully opened decoder for file: "rbuf://127.0.0.1:6543/mnt/store/ringbuf1.nuv". novideo(0) 2005-08-31 22:07:38.513 VideoOutputXv() 2005-08-31 22:07:38.518 Broadcasting free space avail 2005-08-31 22:07:38.520 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0 2005-08-31 22:07:38.526 Broadcasting free space avail 2005-08-31 22:07:38.526 XvMC version: 1.0 2005-08-31 22:07:38.527 @ j=1 Looking for flag[s]: XvInputMask 2005-08-31 22:07:38.527 Adaptor: 0 has flag[s]: XvInputMask XvImageMask 2005-08-31 22:07:38.527 XvMCSurfaceTypes::find(w 704, h 576, chroma 1, vld 0, idct 1, mpeg2, sub-width 0, sub-height 0, disp, p<= 270, 2700 <=p, port, surfNum) 2005-08-31 22:07:38.527 Trying XvMC port 270 2005-08-31 22:07:38.527 Found a suitable XvMC surface 0 2005-08-31 22:07:38.527 XvMC surface found with IDCT support on port 270 2005-08-31 22:07:38.534 Broadcasting free space avail 2005-08-31 22:07:38.542 Broadcasting free space avail 2005-08-31 22:07:38.550 Broadcasting free space avail 2005-08-31 22:07:38.555 Couldn't get the color key color, and we need it. You likely won't get any video. 2005-08-31 22:07:38.555 Image size. dispxoff 0, dispyoff: 0, dispwoff: 666, disphoff: 533 2005-08-31 22:07:38.555 Image size. imgx 0, imgy: 0, imgw: 704, imgh: 576 2005-08-31 22:07:38.558 Broadcasting free space avail 2005-08-31 22:07:38.566 Broadcasting free space avail 2005-08-31 22:07:38.574 Broadcasting free space avail 2005-08-31 22:07:38.582 Broadcasting free space avail 2005-08-31 22:07:38.590 Broadcasting free space avail 2005-08-31 22:07:38.598 Broadcasting free space avail 2005-08-31 22:07:38.606 Broadcasting free space avail 2005-08-31 22:07:38.614 Broadcasting free space avail 2005-08-31 22:07:38.622 Broadcasting free space avail 2005-08-31 22:07:38.630 Broadcasting free space avail 2005-08-31 22:07:38.638 Broadcasting free space avail 2005-08-31 22:07:38.646 Broadcasting free space avail 2005-08-31 22:07:38.654 Broadcasting free space avail 2005-08-31 22:07:38.662 Broadcasting free space avail 2005-08-31 22:07:38.670 Broadcasting free space avail 2005-08-31 22:07:38.678 Broadcasting free space avail 2005-08-31 22:07:38.686 Broadcasting free space avail 2005-08-31 22:07:38.694 Broadcasting free space avail 2005-08-31 22:07:38.702 Broadcasting free space avail 2005-08-31 22:07:38.706 read <- 18 6 128000 2005-08-31 22:07:38.706 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:38.710 Broadcasting free space avail 2005-08-31 22:07:38.714 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:38.718 Broadcasting free space avail 2005-08-31 22:07:38.726 Broadcasting free space avail 2005-08-31 22:07:38.734 Broadcasting free space avail 2005-08-31 22:07:38.742 Broadcasting free space avail 2005-08-31 22:07:38.750 Broadcasting free space avail 2005-08-31 22:07:38.758 Broadcasting free space avail 2005-08-31 22:07:38.766 Broadcasting free space avail 2005-08-31 22:07:38.774 Broadcasting free space avail 2005-08-31 22:07:38.782 Broadcasting free space avail 2005-08-31 22:07:38.790 Broadcasting free space avail 2005-08-31 22:07:38.798 Broadcasting free space avail 2005-08-31 22:07:38.806 Broadcasting free space avail 2005-08-31 22:07:38.814 Broadcasting free space avail 2005-08-31 22:07:38.822 Broadcasting free space avail 2005-08-31 22:07:38.830 Broadcasting free space avail 2005-08-31 22:07:38.838 Broadcasting free space avail 2005-08-31 22:07:38.846 Broadcasting free space avail 2005-08-31 22:07:38.854 Broadcasting free space avail 2005-08-31 22:07:38.862 Broadcasting free space avail 2005-08-31 22:07:38.870 Broadcasting free space avail 2005-08-31 22:07:38.878 Broadcasting free space avail 2005-08-31 22:07:38.886 Broadcasting free space avail 2005-08-31 22:07:38.894 Broadcasting free space avail 2005-08-31 22:07:38.902 Broadcasting free space avail 2005-08-31 22:07:38.910 Broadcasting free space avail 2005-08-31 22:07:38.911 read <- 18 6 128000 2005-08-31 22:07:38.911 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:38.918 Broadcasting free space avail 2005-08-31 22:07:38.922 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:38.926 Broadcasting free space avail 2005-08-31 22:07:38.931 Using deinterlace method bobdeint 2005-08-31 22:07:38.933 Using realtime priority. 2005-08-31 22:07:38.934 Changing from None to WatchingLiveTV 2005-08-31 22:07:38.934 write -> 17 35 QUERY_RECORDER 1[]:[]GET_INPUT_NAME 2005-08-31 22:07:38.934 OutputAudioLoop: audio paused 2005-08-31 22:07:38.934 65536 bytes free on soundcard 2005-08-31 22:07:38.935 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:38.942 61440 bytes free on soundcard 2005-08-31 22:07:38.942 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:38.949 _AddSamples bytes=4608, used=1, free=767999, timecode=13565894 2005-08-31 22:07:38.950 read <- 17 8 DVBInput 2005-08-31 22:07:38.950 write -> 17 35 QUERY_RECORDER 1[]:[]FRONTEND_READY 2005-08-31 22:07:38.950 _AddSamples bytes=4608, used=4609, free=763391, timecode=13565918 2005-08-31 22:07:38.951 57344 bytes free on soundcard 2005-08-31 22:07:38.951 _AddSamples bytes=4608, used=9217, free=758783, timecode=13565942 2005-08-31 22:07:38.952 _AddSamples bytes=4608, used=13825, free=754175, timecode=13565966 2005-08-31 22:07:38.952 _AddSamples bytes=4608, used=18433, free=749567, timecode=13565990 2005-08-31 22:07:38.957 _AddSamples bytes=4608, used=23041, free=744959, timecode=13566014 2005-08-31 22:07:38.957 _AddSamples bytes=4608, used=27649, free=740351, timecode=13566038 2005-08-31 22:07:38.958 read <- 17 2 ok 2005-08-31 22:07:38.959 write -> 17 37 QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO 2005-08-31 22:07:38.978 read <- 17 103 []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10... 2005-08-31 22:07:38.982 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:07:38.998 read <- 17 8 0[]:[]64 2005-08-31 22:07:38.999 write -> 14 19 QUERY_GETALLPENDING 2005-08-31 22:07:39.015 read <- 14 7 0[]:[]0 2005-08-31 22:07:39.035 write -> 17 37 QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO 2005-08-31 22:07:39.039 nVidiaVideoSync: VBlank ioctl did not work, unimplemented in this driver? 2005-08-31 22:07:39.039 DRMVideoSync: Could not open device /dev/dri/card0, No such file or directory 2005-08-31 22:07:39.040 Set video sync frame interval to 40000 2005-08-31 22:07:39.041 Using audio as timebase 2005-08-31 22:07:39.041 Video timing method: RTC 2005-08-31 22:07:39.041 Refresh rate: 20000, frame interval: 40000 2005-08-31 22:07:39.041 waiting for prebuffer... 0 2005-08-31 22:07:39.051 read <- 17 103 []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10... 2005-08-31 22:07:39.051 write -> 17 53 QUERY_RECORDER 1[]:[]GET_FREE_SPACE[]:[]0[]:[]6750208 2005-08-31 22:07:39.068 read <- 17 16 2[]:[]2084457672 2005-08-31 22:07:39.068 write -> 17 39 QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN 2005-08-31 22:07:39.084 read <- 17 8 0[]:[]67 2005-08-31 22:07:39.122 read <- 18 6 128000 2005-08-31 22:07:39.122 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:39.122 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:39.123 _AddSamples bytes=4608, used=32257, free=735743, timecode=13566062 2005-08-31 22:07:39.133 OutputAudioLoop: Play Event 2005-08-31 22:07:39.133 Broadcasting free space avail 2005-08-31 22:07:39.133 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.134 Broadcasting free space avail 2005-08-31 22:07:39.134 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.134 Broadcasting free space avail 2005-08-31 22:07:39.134 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.134 Broadcasting free space avail 2005-08-31 22:07:39.134 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.134 Broadcasting free space avail 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.135 Broadcasting free space avail 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.135 Broadcasting free space avail 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.135 Broadcasting free space avail 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.135 Broadcasting free space avail 2005-08-31 22:07:39.136 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.136 Broadcasting free space avail 2005-08-31 22:07:39.139 _AddSamples bytes=4608, used=1, free=767999, timecode=13566086 2005-08-31 22:07:39.139 _AddSamples bytes=4608, used=4609, free=763391, timecode=13566110 2005-08-31 22:07:39.144 Frame B w/children: A is being held for later discarding. 2005-08-31 22:07:39.182 Broadcasting free space avail 2005-08-31 22:07:39.182 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.182 Broadcasting free space avail 2005-08-31 22:07:39.182 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.182 audio waiting for buffer to fill: have 1024 want 4096 2005-08-31 22:07:39.183 Broadcasting free space avail 2005-08-31 22:07:39.193 audio waiting for buffer to fill: have 1024 want 4096 2005-08-31 22:07:39.222 Broadcasting free space avail 2005-08-31 22:07:39.223 _AddSamples bytes=4608, used=1025, free=766975, timecode=13566134 2005-08-31 22:07:39.223 _AddSamples bytes=4608, used=5633, free=762367, timecode=13566158 2005-08-31 22:07:39.230 Broadcasting free space avail 2005-08-31 22:07:39.231 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.231 Broadcasting free space avail 2005-08-31 22:07:39.231 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.231 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:39.231 Broadcasting free space avail 2005-08-31 22:07:39.261 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:39.262 Broadcasting free space avail 2005-08-31 22:07:39.265 _AddSamples bytes=4608, used=2049, free=765951, timecode=13566182 2005-08-31 22:07:39.271 Frame D w/children: C is being held for later discarding. 2005-08-31 22:07:39.270 Broadcasting free space avail 2005-08-31 22:07:39.306 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.306 _AddSamples bytes=4608, used=2561, free=765439, timecode=13566206 2005-08-31 22:07:39.307 Broadcasting free space avail 2005-08-31 22:07:39.307 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.307 audio waiting for buffer to fill: have 3072 want 4096 2005-08-31 22:07:39.307 Broadcasting free space avail 2005-08-31 22:07:39.307 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566230 2005-08-31 22:07:39.341 Broadcasting free space avail 2005-08-31 22:07:39.341 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.342 audio waiting for buffer to fill: have 3584 want 4096 2005-08-31 22:07:39.342 Broadcasting free space avail 2005-08-31 22:07:39.343 read <- 18 6 128000 2005-08-31 22:07:39.343 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:39.343 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:39.347 _AddSamples bytes=4608, used=3585, free=764415, timecode=13566254 2005-08-31 22:07:39.347 _AddSamples bytes=4608, used=8193, free=759807, timecode=13566278 2005-08-31 22:07:39.350 Broadcasting free space avail 2005-08-31 22:07:39.351 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.381 Broadcasting free space avail 2005-08-31 22:07:39.382 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.382 Broadcasting free space avail 2005-08-31 22:07:39.382 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.382 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:39.382 Broadcasting free space avail 2005-08-31 22:07:39.386 _AddSamples bytes=4608, used=513, free=767487, timecode=13566302 2005-08-31 22:07:39.390 Broadcasting free space avail 2005-08-31 22:07:39.391 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.391 Frame F w/children: C E is being held for later discarding. 2005-08-31 22:07:39.421 audio waiting for buffer to fill: have 1024 want 4096 2005-08-31 22:07:39.422 Broadcasting free space avail 2005-08-31 22:07:39.428 _AddSamples bytes=4608, used=1025, free=766975, timecode=13566326 2005-08-31 22:07:39.429 _AddSamples bytes=4608, used=5633, free=762367, timecode=13566350 2005-08-31 22:07:39.430 Broadcasting free space avail 2005-08-31 22:07:39.430 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.430 Frame F w/children: C is being held for later discarding. 2005-08-31 22:07:39.431 Broadcasting free space avail 2005-08-31 22:07:39.431 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.431 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:39.431 Broadcasting free space avail 2005-08-31 22:07:39.462 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:39.462 Broadcasting free space avail 2005-08-31 22:07:39.465 _AddSamples bytes=4608, used=2049, free=765951, timecode=13566374 2005-08-31 22:07:39.466 _AddSamples bytes=4608, used=6657, free=761343, timecode=13566398 2005-08-31 22:07:39.470 Broadcasting free space avail 2005-08-31 22:07:39.471 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.471 Broadcasting free space avail 2005-08-31 22:07:39.471 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.471 audio waiting for buffer to fill: have 3072 want 4096 2005-08-31 22:07:39.472 Broadcasting free space avail 2005-08-31 22:07:39.501 audio waiting for buffer to fill: have 3072 want 4096 2005-08-31 22:07:39.501 Broadcasting free space avail 2005-08-31 22:07:39.505 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566422 2005-08-31 22:07:39.511 Frame G w/children: F is being held for later discarding. 2005-08-31 22:07:39.511 Broadcasting free space avail 2005-08-31 22:07:39.511 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.512 audio waiting for buffer to fill: have 3584 want 4096 2005-08-31 22:07:39.512 Broadcasting free space avail 2005-08-31 22:07:39.542 audio waiting for buffer to fill: have 3584 want 4096 2005-08-31 22:07:39.542 Broadcasting free space avail 2005-08-31 22:07:39.547 _AddSamples bytes=4608, used=3585, free=764415, timecode=13566446 2005-08-31 22:07:39.547 _AddSamples bytes=4608, used=8193, free=759807, timecode=13566470 2005-08-31 22:07:39.550 Broadcasting free space avail 2005-08-31 22:07:39.581 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.581 Broadcasting free space avail 2005-08-31 22:07:39.581 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.582 Broadcasting free space avail 2005-08-31 22:07:39.582 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.582 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:39.582 Broadcasting free space avail 2005-08-31 22:07:39.590 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:39.591 Broadcasting free space avail 2005-08-31 22:07:39.591 read <- 18 6 128000 2005-08-31 22:07:39.592 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:39.592 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:39.623 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:39.623 Broadcasting free space avail 2005-08-31 22:07:39.623 _AddSamples bytes=4608, used=513, free=767487, timecode=13566494 2005-08-31 22:07:39.624 _AddSamples bytes=4608, used=5121, free=762879, timecode=13566518 2005-08-31 22:07:39.629 _AddSamples bytes=4608, used=9729, free=758271, timecode=13566542 2005-08-31 22:07:39.631 Frame B w/children: A E is being held for later discarding. 2005-08-31 22:07:39.663 Broadcasting free space avail 2005-08-31 22:07:39.663 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.663 Broadcasting free space avail 2005-08-31 22:07:39.663 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.663 Broadcasting free space avail 2005-08-31 22:07:39.663 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.664 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:39.664 Broadcasting free space avail 2005-08-31 22:07:39.671 Frame B w/children: A is being held for later discarding. 2005-08-31 22:07:39.703 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:39.703 Broadcasting free space avail 2005-08-31 22:07:39.708 _AddSamples bytes=4608, used=2049, free=765951, timecode=13566566 2005-08-31 22:07:39.708 _AddSamples bytes=4608, used=6657, free=761343, timecode=13566590 2005-08-31 22:07:39.743 Broadcasting free space avail 2005-08-31 22:07:39.743 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.743 Broadcasting free space avail 2005-08-31 22:07:39.743 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.748 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566614 2005-08-31 22:07:39.748 _AddSamples bytes=4608, used=7681, free=760319, timecode=13566638 2005-08-31 22:07:39.749 Broadcasting free space avail 2005-08-31 22:07:39.749 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.749 Broadcasting free space avail 2005-08-31 22:07:39.749 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.749 Broadcasting free space avail 2005-08-31 22:07:39.749 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.749 Broadcasting free space avail 2005-08-31 22:07:39.751 Frame H w/children: G is being held for later discarding. 2005-08-31 22:07:39.783 Broadcasting free space avail 2005-08-31 22:07:39.786 _AddSamples bytes=4608, used=1, free=767999, timecode=13566662 2005-08-31 22:07:39.823 Broadcasting free space avail 2005-08-31 22:07:39.823 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.823 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:39.823 Broadcasting free space avail 2005-08-31 22:07:39.827 _AddSamples bytes=4608, used=513, free=767487, timecode=13566686 2005-08-31 22:07:39.828 _AddSamples bytes=4608, used=5121, free=762879, timecode=13566710 2005-08-31 22:07:39.863 Broadcasting free space avail 2005-08-31 22:07:39.863 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.863 Broadcasting free space avail 2005-08-31 22:07:39.863 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.864 audio waiting for buffer to fill: have 1536 want 4096 2005-08-31 22:07:39.864 Broadcasting free space avail 2005-08-31 22:07:39.864 read <- 18 6 128000 2005-08-31 22:07:39.864 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:39.864 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:39.865 _AddSamples bytes=4608, used=1537, free=766463, timecode=13566734 2005-08-31 22:07:39.866 _AddSamples bytes=4608, used=6145, free=761855, timecode=13566758 2005-08-31 22:07:39.870 _AddSamples bytes=4608, used=10753, free=757247, timecode=13566782 2005-08-31 22:07:39.871 Frame F w/children: B G is being held for later discarding. 2005-08-31 22:07:39.903 Broadcasting free space avail 2005-08-31 22:07:39.903 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.903 Broadcasting free space avail 2005-08-31 22:07:39.904 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.904 Broadcasting free space avail 2005-08-31 22:07:39.904 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.904 audio waiting for buffer to fill: have 3072 want 4096 2005-08-31 22:07:39.904 Broadcasting free space avail 2005-08-31 22:07:39.911 Frame F w/children: G is being held for later discarding. 2005-08-31 22:07:39.943 audio waiting for buffer to fill: have 3072 want 4096 2005-08-31 22:07:39.943 Broadcasting free space avail 2005-08-31 22:07:39.945 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566806 2005-08-31 22:07:39.946 _AddSamples bytes=4608, used=7681, free=760319, timecode=13566830 2005-08-31 22:07:39.949 _AddSamples bytes=4608, used=12289, free=755711, timecode=13566854 2005-08-31 22:07:39.950 _AddSamples bytes=4608, used=16897, free=751103, timecode=13566878 2005-08-31 22:07:39.983 Broadcasting free space avail 2005-08-31 22:07:39.983 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.983 Broadcasting free space avail 2005-08-31 22:07:39.983 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.983 Broadcasting free space avail 2005-08-31 22:07:39.983 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.984 Broadcasting free space avail 2005-08-31 22:07:39.984 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.984 Broadcasting free space avail 2005-08-31 22:07:39.984 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:39.984 audio waiting for buffer to fill: have 1024 want 4096 2005-08-31 22:07:39.984 Broadcasting free space avail 2005-08-31 22:07:39.988 _AddSamples bytes=4608, used=1025, free=766975, timecode=13566902 2005-08-31 22:07:39.991 Frame A w/children: B is being held for later discarding. 2005-08-31 22:07:40.023 Broadcasting free space avail 2005-08-31 22:07:40.023 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.023 audio waiting for buffer to fill: have 1536 want 4096 2005-08-31 22:07:40.023 Broadcasting free space avail 2005-08-31 22:07:40.028 _AddSamples bytes=4608, used=1537, free=766463, timecode=13566926 2005-08-31 22:07:40.029 _AddSamples bytes=4608, used=6145, free=761855, timecode=13566950 2005-08-31 22:07:40.063 Broadcasting free space avail 2005-08-31 22:07:40.063 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.063 Broadcasting free space avail 2005-08-31 22:07:40.063 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.063 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.063 Broadcasting free space avail 2005-08-31 22:07:40.067 _AddSamples bytes=4608, used=2561, free=765439, timecode=13566974 2005-08-31 22:07:40.068 _AddSamples bytes=4608, used=7169, free=760831, timecode=13566998 2005-08-31 22:07:40.103 Broadcasting free space avail 2005-08-31 22:07:40.103 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.103 Broadcasting free space avail 2005-08-31 22:07:40.104 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.104 audio waiting for buffer to fill: have 3584 want 4096 2005-08-31 22:07:40.104 Broadcasting free space avail 2005-08-31 22:07:40.104 read <- 18 6 128000 2005-08-31 22:07:40.105 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:40.105 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:40.108 _AddSamples bytes=4608, used=3585, free=764415, timecode=13567022 2005-08-31 22:07:40.111 Frame E w/children: D H is being held for later discarding. 2005-08-31 22:07:40.143 Broadcasting free space avail 2005-08-31 22:07:40.143 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.143 Broadcasting free space avail 2005-08-31 22:07:40.143 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.143 Broadcasting free space avail 2005-08-31 22:07:40.149 _AddSamples bytes=4608, used=1, free=767999, timecode=13567046 2005-08-31 22:07:40.150 _AddSamples bytes=4608, used=4609, free=763391, timecode=13567070 2005-08-31 22:07:40.151 Frame E w/children: H is being held for later discarding. 2005-08-31 22:07:40.186 _AddSamples bytes=4608, used=9217, free=758783, timecode=13567094 2005-08-31 22:07:40.187 _AddSamples bytes=4608, used=13825, free=754175, timecode=13567118 2005-08-31 22:07:40.187 Broadcasting free space avail 2005-08-31 22:07:40.187 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.187 Broadcasting free space avail 2005-08-31 22:07:40.188 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.188 Broadcasting free space avail 2005-08-31 22:07:40.188 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.188 Broadcasting free space avail 2005-08-31 22:07:40.188 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.188 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:40.188 Broadcasting free space avail 2005-08-31 22:07:40.223 audio waiting for buffer to fill: have 2048 want 4096 2005-08-31 22:07:40.223 Broadcasting free space avail 2005-08-31 22:07:40.226 _AddSamples bytes=4608, used=2049, free=765951, timecode=13567142 2005-08-31 22:07:40.232 Frame G w/children: A is being held for later discarding. 2005-08-31 22:07:40.263 Broadcasting free space avail 2005-08-31 22:07:40.263 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.263 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.263 Broadcasting free space avail 2005-08-31 22:07:40.267 _AddSamples bytes=4608, used=2561, free=765439, timecode=13567166 2005-08-31 22:07:40.268 _AddSamples bytes=4608, used=7169, free=760831, timecode=13567190 2005-08-31 22:07:40.306 _AddSamples bytes=4608, used=11777, free=756223, timecode=13567214 2005-08-31 22:07:40.307 _AddSamples bytes=4608, used=16385, free=751615, timecode=13567238 2005-08-31 22:07:40.307 Broadcasting free space avail 2005-08-31 22:07:40.307 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.307 Broadcasting free space avail 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.308 Broadcasting free space avail 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.308 Broadcasting free space avail 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.308 Broadcasting free space avail 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.308 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:40.308 Broadcasting free space avail 2005-08-31 22:07:40.343 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:40.343 Broadcasting free space avail 2005-08-31 22:07:40.352 Frame B w/children: D is being held for later discarding. 2005-08-31 22:07:40.352 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:40.383 Broadcasting free space avail 2005-08-31 22:07:40.385 read <- 18 6 128000 2005-08-31 22:07:40.385 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:40.385 write -> 18 53 QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000 2005-08-31 22:07:40.386 _AddSamples bytes=4608, used=513, free=767487, timecode=13567262 2005-08-31 22:07:40.391 Broadcasting free space avail 2005-08-31 22:07:40.392 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.392 audio waiting for buffer to fill: have 1024 want 4096 2005-08-31 22:07:40.423 Broadcasting free space avail 2005-08-31 22:07:40.427 audio waiting for buffer to fill: have 1024 want 4096 2005-08-31 22:07:40.428 Broadcasting free space avail 2005-08-31 22:07:40.428 prebuffering pause 2005-08-31 22:07:40.428 waiting for prebuffer... 0 2005-08-31 22:07:40.431 _AddSamples bytes=4608, used=1025, free=766975, timecode=13567286 2005-08-31 22:07:40.431 _AddSamples bytes=4608, used=5633, free=762367, timecode=13567310 2005-08-31 22:07:40.435 _AddSamples bytes=4608, used=10241, free=757759, timecode=13567334 2005-08-31 22:07:40.435 OutputAudioLoop: audio paused 2005-08-31 22:07:40.436 41048 bytes free on soundcard 2005-08-31 22:07:40.436 _AddSamples bytes=4608, used=14849, free=753151, timecode=13567358 2005-08-31 22:07:40.439 _AddSamples bytes=4608, used=19457, free=748543, timecode=13567382 2005-08-31 22:07:40.463 OutputAudioLoop: Play Event 2005-08-31 22:07:40.463 Broadcasting free space avail 2005-08-31 22:07:40.463 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.463 Broadcasting free space avail 2005-08-31 22:07:40.463 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.464 Broadcasting free space avail 2005-08-31 22:07:40.464 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.464 Broadcasting free space avail 2005-08-31 22:07:40.464 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.464 Broadcasting free space avail 2005-08-31 22:07:40.464 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.464 audio waiting for buffer to fill: have 3584 want 4096 2005-08-31 22:07:40.464 Broadcasting free space avail 2005-08-31 22:07:40.468 Frame C w/children: B is being held for later discarding. 2005-08-31 22:07:40.504 audio waiting for buffer to fill: have 3584 want 4096 2005-08-31 22:07:40.504 Broadcasting free space avail 2005-08-31 22:07:40.543 _AddSamples bytes=4608, used=3585, free=764415, timecode=13567406 2005-08-31 22:07:40.544 Broadcasting free space avail 2005-08-31 22:07:40.544 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.544 Broadcasting free space avail 2005-08-31 22:07:40.544 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.544 _AddSamples bytes=4608, used=1, free=767999, timecode=13567430 2005-08-31 22:07:40.544 Broadcasting free space avail 2005-08-31 22:07:40.544 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.545 audio waiting for buffer to fill: have 512 want 4096 2005-08-31 22:07:40.545 Broadcasting free space avail 2005-08-31 22:07:40.547 Attempting to change from WatchingLiveTV to None 2005-08-31 22:07:40.548 TV::StopStuff() -- begin 2005-08-31 22:07:40.548 TV::StopStuff(): stopping ring buffer[s] 2005-08-31 22:07:40.550 _AddSamples bytes=4608, used=513, free=767487, timecode=13567454 2005-08-31 22:07:40.550 _AddSamples bytes=4608, used=5121, free=762879, timecode=13567478 2005-08-31 22:07:40.551 Broadcasting free space avail 2005-08-31 22:07:40.552 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.552 Broadcasting free space avail 2005-08-31 22:07:40.552 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.552 audio waiting for buffer to fill: have 1536 want 4096 2005-08-31 22:07:40.552 Broadcasting free space avail 2005-08-31 22:07:40.554 _AddSamples bytes=4608, used=1537, free=766463, timecode=13567502 2005-08-31 22:07:40.558 _AddSamples bytes=4608, used=6145, free=761855, timecode=13567526 2005-08-31 22:07:40.560 Broadcasting free space avail 2005-08-31 22:07:40.560 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.560 Broadcasting free space avail 2005-08-31 22:07:40.560 WriteAudio: Preparing 4096 bytes (1024 frames) 2005-08-31 22:07:40.560 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.560 Broadcasting free space avail 2005-08-31 22:07:40.568 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.568 Broadcasting free space avail 2005-08-31 22:07:40.576 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.576 Broadcasting free space avail 2005-08-31 22:07:40.580 ~VideoOutputXv() 2005-08-31 22:07:40.580 VideoOutputXv::DiscardFrames() 1: LAUUAdUA 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 2: LAUUAdUA 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 3: LAUUAdUA 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 4: AAAAAddA -- done() 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 1: AAAAAddA 2005-08-31 22:07:40.582 VideoOutputXv::DiscardFrames() 2: AAAAAdAA 2005-08-31 22:07:40.582 VideoOutputXv::DiscardFrames() 3: AAAAAdAA 2005-08-31 22:07:40.582 VideoOutputXv::DiscardFrames() 4: AAAAAdAA -- done() 2005-08-31 22:07:40.584 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.584 Broadcasting free space avail 2005-08-31 22:07:40.592 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.592 Broadcasting free space avail 2005-08-31 22:07:40.594 read <- 18 6 128000 2005-08-31 22:07:40.594 Read(): reqd=128000, rcvd=128000, rept=128000, error=0 2005-08-31 22:07:40.594 TV::StopStuff(): stopping player[s] (1/2) 2005-08-31 22:07:40.594 TV::StopStuff(): stopping recorder[s] 2005-08-31 22:07:40.594 write -> 17 32 QUERY_RECORDER 1[]:[]STOP_LIVETV 2005-08-31 22:07:40.618 audio waiting for buffer to fill: have 2560 want 4096 2005-08-31 22:07:40.619 Broadcasting free space avail 2005-08-31 22:07:40.619 Killing AudioOutputDSP 2005-08-31 22:07:40.628 OutputAudioLoop: Stop Event 2005-08-31 22:07:40.628 kickoffOutputAudioLoop exiting 2005-08-31 22:07:40.641 read <- 16 48 BACKEND_MESSAGE[]:[]DONE_RECORDING 1 4[]:[]empty 2005-08-31 22:07:40.673 read <- 17 2 ok 2005-08-31 22:07:40.673 TV::StopStuff(): stopping player[s] (2/2) 2005-08-31 22:07:40.681 read <- 16 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty 2005-08-31 22:07:40.689 read <- 16 51 BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty 2005-08-31 22:07:40.702 write -> 18 33 QUERY_RECORDER 1[]:[]DONE_RINGBUF 2005-08-31 22:07:40.717 read <- 18 2 OK 2005-08-31 22:07:40.717 TV::StopStuff() -- end 2005-08-31 22:07:40.718 Changing from WatchingLiveTV to None 2005-08-31 22:07:40.725 Attempting to change from None to None 2005-08-31 22:07:41.381 write -> 14 34 QUERY_IS_ACTIVE_BACKEND[]:[]vdrtv1 2005-08-31 22:07:41.399 read <- 14 4 TRUE Destroying SipFsm object