Changes between Version 1 and Version 4 of Ticket #287


Ignore:
Timestamp:
09/08/05 03:56:08 (20 years ago)
Author:
danielk
Comment:

Can you try the attached patch, it should fix the problem without breaking anything if I have diagnosed the problem correctly.

Legend:

Unmodified
Added
Removed
Modified

  • Ticket #287

    • Property Milestone → 0.19
    • Property Severity medium → low
    • Property Type defect → enhancement

  • Ticket #287 – Description

    v1 v4  
    11Whenever a XvMC is used, it sometimes works and sometimes it does not, I have found that when the same DVB-C (ts) stream is recognized as MPEG1 the XvMC-hardware decoding does not work ( AVFD: Stream #0, has id 0x33 codec id MPEG1VIDEO, type Video at 0x0x82a95a0 ), but when the same stream is recognized as MPEG2 everything works.( AVFD: Stream #0, has id 0x215 codec id MPEG2VIDEO, type Video at 0x0x827e940 )
    22
    3 below first debug output XvMC working, Second debug output below, XvMC broken.
    4 
    5 ----
    6 {{{
    7 working debug:
    8 
    9 ----
    10 
    11 2005-08-31 22:07:32.687 Using runtime prefix = /usr
    12 2005-08-31 22:07:32.705 New DB connection, total: 1
    13 2005-08-31 22:07:32.707 Total desktop dim: 720x576, with 1 screen[s].
    14 2005-08-31 22:07:32.709 Using screen 0, 720x576 at 0,0
    15 2005-08-31 22:07:32.713 mythfrontend version: 0.19.20050712-1 www.mythtv.org
    16 2005-08-31 22:07:32.713 Enabled verbose msgs :all
    17 2005-08-31 22:07:32.848 max_width: 720 max_height: 576
    18 2005-08-31 22:07:32.926 Total desktop dim: 720x576, with 1 screen[s].
    19 2005-08-31 22:07:32.927 Using screen 0, 720x576 at 0,0
    20 2005-08-31 22:07:32.928 Switching to square mode (blue)
    21 2005-08-31 22:07:33.119 Registering Internal as a media playback plugin.
    22 2005-08-31 22:07:33.134 Registering MythDVD DVD Media Handler as a media handler
    23 2005-08-31 22:07:33.135 Registering MythDVD VCD Media Handler as a media handler
    24 2005-08-31 22:07:33.468 Registering MythMusic Media Handler as a media handler
    25 SIP listening on IP Address 192.168.0.3:5060 NAT address 192.168.0.3
    26 SIP: Cannot register; proxy, username or password not set
    27 2005-08-31 22:07:33.771 generating cache image for: /usr/share/mythtv/themes/default/blank.png
    28 2005-08-31 22:07:34.059 Starting media monitor.
    29 2005-08-31 22:07:35.023 New DB connection, total: 2
    30 2005-08-31 22:07:35.066 Connecting to backend server: 127.0.0.1:6543 (try 1 of 5)
    31 2005-08-31 22:07:35.067 write -> 14 21      ANN Playback vdrtv1 0
    32 2005-08-31 22:07:35.080 read  <- 14 2       OK
    33 2005-08-31 22:07:35.082 write -> 14 29      GET_NEXT_FREE_RECORDER[]:[]-1
    34 2005-08-31 22:07:35.096 read  <- 14 24      1[]:[]127.0.0.1[]:[]6543
    35 2005-08-31 22:07:35.096 write -> 16 21      ANN Playback vdrtv1 1
    36 2005-08-31 22:07:35.100 Attempting to change from None to WatchingLiveTV
    37 2005-08-31 22:07:35.100 write -> 17 21      MYTH_PROTO_VERSION 18
    38 2005-08-31 22:07:35.112 read  <- 16 2       OK
    39 2005-08-31 22:07:35.116 read  <- 17 13      ACCEPT[]:[]18
    40 2005-08-31 22:07:35.116 Using protocol version 18
    41 2005-08-31 22:07:35.116 write -> 17 21      ANN Playback vdrtv1 0
    42 2005-08-31 22:07:35.132 read  <- 17 2       OK
    43 2005-08-31 22:07:35.132 write -> 17 44      QUERY_RECORDER 1[]:[]SETUP_RING_BUFFER[]:[]0
    44 2005-08-31 22:07:35.148 read  <- 17 92      ok[]:[]rbuf://127.0.0.1:6543/mnt/store/ringbuf1.nuv[]:[]2[]:[]-21...
    45 2005-08-31 22:07:35.149 write -> 18 21      ANN Playback vdrtv1 0
    46 2005-08-31 22:07:35.164 read  <- 18 2       OK
    47 2005-08-31 22:07:35.165 write -> 19 23      ANN RingBuffer vdrtv1 1
    48 2005-08-31 22:07:35.181 read  <- 19 2       OK
    49 2005-08-31 22:07:35.181 write -> 17 33      QUERY_RECORDER 1[]:[]SPAWN_LIVETV
    50 2005-08-31 22:07:35.213 read  <- 17 2       ok
    51 2005-08-31 22:07:35.213 write -> 17 33      QUERY_RECORDER 1[]:[]IS_RECORDING
    52 2005-08-31 22:07:35.229 read  <- 17 1       1
    53 2005-08-31 22:07:35.229 write -> 17 33      QUERY_RECORDER 1[]:[]IS_RECORDING
    54 2005-08-31 22:07:35.245 read  <- 17 1       1
    55 2005-08-31 22:07:35.245 write -> 17 34      QUERY_RECORDER 1[]:[]GET_FRAMERATE
    56 2005-08-31 22:07:35.261 read  <- 17 2       25
    57 2005-08-31 22:07:35.278 write -> 17 37      QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO
    58 2005-08-31 22:07:35.293 read  <- 17 103      []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10...
    59 2005-08-31 22:07:35.294 Output filters for this channel are: ''
    60 2005-08-31 22:07:35.297 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    61 2005-08-31 22:07:35.298 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    62 2005-08-31 22:07:35.314 read  <- 18 6       128000
    63 2005-08-31 22:07:35.314 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    64 2005-08-31 22:07:35.322 write -> 18 66      QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]2048
    65 2005-08-31 22:07:35.338 read  <- 18 7       0[]:[]0
    66 2005-08-31 22:07:35.346 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    67 2005-08-31 22:07:35.354 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    68 2005-08-31 22:07:35.354 read  <- 18 6       128000
    69 2005-08-31 22:07:35.354 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    70 2005-08-31 22:07:35.362 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    71 2005-08-31 22:07:35.370 read  <- 18 6       128000
    72 2005-08-31 22:07:35.371 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    73 2005-08-31 22:07:35.378 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    74 2005-08-31 22:07:35.387 read  <- 18 6       128000
    75 2005-08-31 22:07:35.387 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    76 2005-08-31 22:07:35.398 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    77 2005-08-31 22:07:35.407 read  <- 18 6       128000
    78 2005-08-31 22:07:35.407 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    79 2005-08-31 22:07:35.410 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    80 2005-08-31 22:07:35.418 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    81 2005-08-31 22:07:35.427 read  <- 18 6       128000
    82 2005-08-31 22:07:35.427 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    83 2005-08-31 22:07:35.438 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    84 2005-08-31 22:07:35.447 read  <- 18 6       128000
    85 2005-08-31 22:07:35.447 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    86 2005-08-31 22:07:35.458 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    87 2005-08-31 22:07:35.467 read  <- 18 6       128000
    88 2005-08-31 22:07:35.467 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    89 2005-08-31 22:07:35.467 write -> 18 68      QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]851968
    90 2005-08-31 22:07:35.486 read  <- 18 7       0[]:[]0
    91 2005-08-31 22:07:35.487 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    92 2005-08-31 22:07:35.499 read  <- 18 6       128000
    93 2005-08-31 22:07:35.499 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    94 2005-08-31 22:07:35.511 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    95 2005-08-31 22:07:35.523 read  <- 18 6       128000
    96 2005-08-31 22:07:35.523 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    97 2005-08-31 22:07:35.535 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    98 2005-08-31 22:07:35.547 read  <- 18 6       128000
    99 2005-08-31 22:07:35.547 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    100 2005-08-31 22:07:35.559 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    101 2005-08-31 22:07:35.571 read  <- 18 6       128000
    102 2005-08-31 22:07:35.571 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    103 2005-08-31 22:07:35.583 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    104 2005-08-31 22:07:35.591 read  <- 18 6       128000
    105 2005-08-31 22:07:35.591 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    106 2005-08-31 22:07:35.599 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    107 2005-08-31 22:07:35.608 read  <- 18 6       128000
    108 2005-08-31 22:07:35.608 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    109 2005-08-31 22:07:35.615 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    110 2005-08-31 22:07:35.624 read  <- 18 6       128000
    111 2005-08-31 22:07:35.624 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    112 2005-08-31 22:07:35.631 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    113 2005-08-31 22:07:35.640 read  <- 18 6       128000
    114 2005-08-31 22:07:35.640 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    115 2005-08-31 22:07:35.647 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    116 2005-08-31 22:07:35.657 read  <- 18 6       128000
    117 2005-08-31 22:07:35.657 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    118 2005-08-31 22:07:35.664 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    119 2005-08-31 22:07:35.673 read  <- 18 6       128000
    120 2005-08-31 22:07:35.673 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    121 2005-08-31 22:07:35.679 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    122 2005-08-31 22:07:35.689 read  <- 18 6       128000
    123 2005-08-31 22:07:35.689 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    124 2005-08-31 22:07:35.695 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    125 2005-08-31 22:07:35.705 read  <- 18 6       128000
    126 2005-08-31 22:07:35.705 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    127 2005-08-31 22:07:35.712 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    128 2005-08-31 22:07:35.721 read  <- 18 6       128000
    129 2005-08-31 22:07:35.721 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    130 2005-08-31 22:07:35.728 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    131 2005-08-31 22:07:35.737 read  <- 18 6       128000
    132 2005-08-31 22:07:35.737 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    133 2005-08-31 22:07:35.744 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    134 2005-08-31 22:07:35.753 read  <- 18 6       128000
    135 2005-08-31 22:07:35.753 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    136 2005-08-31 22:07:35.760 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    137 2005-08-31 22:07:35.769 read  <- 18 6       128000
    138 2005-08-31 22:07:35.769 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    139 2005-08-31 22:07:35.776 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    140 2005-08-31 22:07:35.785 read  <- 18 6       128000
    141 2005-08-31 22:07:35.785 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    142 2005-08-31 22:07:35.792 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    143 2005-08-31 22:07:35.801 read  <- 18 6       128000
    144 2005-08-31 22:07:35.801 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    145 2005-08-31 22:07:35.808 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    146 2005-08-31 22:07:35.817 read  <- 18 6       128000
    147 2005-08-31 22:07:35.817 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    148 2005-08-31 22:07:35.824 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    149 2005-08-31 22:07:35.833 read  <- 18 6       128000
    150 2005-08-31 22:07:35.833 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    151 2005-08-31 22:07:35.841 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    152 2005-08-31 22:07:35.849 read  <- 18 6       128000
    153 2005-08-31 22:07:35.849 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    154 2005-08-31 22:07:35.857 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    155 2005-08-31 22:07:35.865 read  <- 18 6       128000
    156 2005-08-31 22:07:35.865 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    157 2005-08-31 22:07:35.873 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    158 2005-08-31 22:07:35.881 read  <- 18 6       128000
    159 2005-08-31 22:07:35.881 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    160 2005-08-31 22:07:35.889 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    161 2005-08-31 22:07:35.898 read  <- 18 6       128000
    162 2005-08-31 22:07:35.898 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    163 2005-08-31 22:07:35.905 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    164 2005-08-31 22:07:35.913 read  <- 18 6       128000
    165 2005-08-31 22:07:35.913 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    166 2005-08-31 22:07:35.921 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    167 2005-08-31 22:07:35.929 read  <- 18 6       128000
    168 2005-08-31 22:07:35.930 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    169 2005-08-31 22:07:35.938 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    170 2005-08-31 22:07:35.945 read  <- 18 6       128000
    171 2005-08-31 22:07:35.946 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    172 2005-08-31 22:07:35.953 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    173 2005-08-31 22:07:35.966 read  <- 18 6       128000
    174 2005-08-31 22:07:35.966 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    175 2005-08-31 22:07:35.973 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    176 2005-08-31 22:07:35.982 read  <- 18 6       128000
    177 2005-08-31 22:07:35.982 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    178 2005-08-31 22:07:35.989 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    179 2005-08-31 22:07:36.002 read  <- 18 6       128000
    180 2005-08-31 22:07:36.002 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    181 2005-08-31 22:07:36.010 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    182 2005-08-31 22:07:36.018 read  <- 18 6       128000
    183 2005-08-31 22:07:36.018 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    184 2005-08-31 22:07:36.025 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    185 2005-08-31 22:07:36.036 read  <- 18 6       128000
    186 2005-08-31 22:07:36.036 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    187 2005-08-31 22:07:36.045 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    188 2005-08-31 22:07:36.054 read  <- 18 6       128000
    189 2005-08-31 22:07:36.054 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    190 2005-08-31 22:07:36.062 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    191 2005-08-31 22:07:36.071 read  <- 18 6       128000
    192 2005-08-31 22:07:36.071 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    193 2005-08-31 22:07:36.082 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    194 2005-08-31 22:07:36.091 read  <- 18 6       128000
    195 2005-08-31 22:07:36.091 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    196 2005-08-31 22:07:36.102 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    197 2005-08-31 22:07:36.111 read  <- 18 6       128000
    198 2005-08-31 22:07:36.111 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    199 2005-08-31 22:07:36.118 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    200 2005-08-31 22:07:36.126 read  <- 18 6       128000
    201 2005-08-31 22:07:36.127 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    202 2005-08-31 22:07:36.138 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    203 2005-08-31 22:07:36.147 read  <- 18 6       128000
    204 2005-08-31 22:07:36.147 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    205 2005-08-31 22:07:36.158 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    206 2005-08-31 22:07:36.167 read  <- 18 6       128000
    207 2005-08-31 22:07:36.167 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    208 2005-08-31 22:07:36.178 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    209 2005-08-31 22:07:36.187 read  <- 18 6       128000
    210 2005-08-31 22:07:36.187 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    211 2005-08-31 22:07:36.199 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    212 2005-08-31 22:07:36.346 read  <- 18 6       128000
    213 2005-08-31 22:07:36.346 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    214 2005-08-31 22:07:36.353 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    215 2005-08-31 22:07:36.652 read  <- 18 6       128000
    216 2005-08-31 22:07:36.652 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    217 2005-08-31 22:07:36.663 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    218 2005-08-31 22:07:36.861 read  <- 18 6       128000
    219 2005-08-31 22:07:36.861 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    220 2005-08-31 22:07:36.868 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    221 2005-08-31 22:07:37.054 read  <- 18 6       128000
    222 2005-08-31 22:07:37.054 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    223 2005-08-31 22:07:37.061 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    224 2005-08-31 22:07:37.242 read  <- 18 6       128000
    225 2005-08-31 22:07:37.242 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    226 2005-08-31 22:07:37.249 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    227 2005-08-31 22:07:37.438 read  <- 18 6       128000
    228 2005-08-31 22:07:37.438 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    229 2005-08-31 22:07:37.446 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    230 2005-08-31 22:07:37.626 read  <- 18 6       128000
    231 2005-08-31 22:07:37.626 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    232 2005-08-31 22:07:37.634 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    233 2005-08-31 22:07:37.814 read  <- 18 6       128000
    234 2005-08-31 22:07:37.814 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    235 2005-08-31 22:07:37.822 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    236 2005-08-31 22:07:38.011 read  <- 18 6       128000
    237 2005-08-31 22:07:38.011 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    238 2005-08-31 22:07:38.022 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    239 2005-08-31 22:07:38.263 read  <- 18 6       128000
    240 2005-08-31 22:07:38.263 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    241 2005-08-31 22:07:38.264 write -> 18 75      QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]6389760[]:[]0[]:[]0[]...
    242 2005-08-31 22:07:38.283 read  <- 18 13      0[]:[]6389760
    243 0: start_time: -9223372036854.775 duration: -9223372036854.775
    244 1: start_time: -9223372036854.775 duration: -9223372036854.775
    245 stream: start_time: -9223372036854.775 duration: -9223372036854.775 bitrate=5224 kb/s
    246 2005-08-31 22:07:38.283 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    247 2005-08-31 22:07:38.283 AVFD: Stream #0, has id 0x215 codec id MPEG2VIDEO, type Video at 0x0x827e940
    248 2005-08-31 22:07:38.285 XvMC version: 1.0
    249 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)
    250 2005-08-31 22:07:38.285 Trying XvMC port 270
    251 2005-08-31 22:07:38.286 Found a suitable XvMC surface 0
    252 2005-08-31 22:07:38.287 @ j=1 Looking for flag[s]: XvInputMask
    253 2005-08-31 22:07:38.287 Adaptor: 0 has flag[s]: XvInputMask XvImageMask
    254 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)
    255 2005-08-31 22:07:38.287 Trying XvMC port 270
    256 2005-08-31 22:07:38.287 Found a suitable XvMC surface 0
    257 2005-08-31 22:07:38.287 XvMC surface found with IDCT support on port 270
    258 2005-08-31 22:07:38.317 detectInterlace(Detect Scan, Detect Scan, 25, 576) ->Interlaced Scan
    259 2005-08-31 22:07:38.317 Interlaced: Interlaced Scan  video_height: 576  fps: 25
    260 2005-08-31 22:07:38.317 AVFD: Looking for decoder for MPEG2VIDEO_XVMC
    261 2005-08-31 22:07:38.317 AVFD: Opened codec 0x82a1310, id(MPEG2VIDEO_XVMC) type(Video)
    262 2005-08-31 22:07:38.317 AVFD: Stream #1, has id 0x888 codec id MP3, type Audio at 0x0x82a1610
    263 2005-08-31 22:07:38.317 AVFD: Looking for decoder for MP3
    264 2005-08-31 22:07:38.332 AVFD: Opened codec 0x829cea0, id(MP3) type(Audio)
    265 2005-08-31 22:07:38.332 AVFD: Stream #1 (audio track #0) is an audio stream with 2 channels.
    266 2005-08-31 22:07:38.333 Auto-selecting audio track #1 (stream #1).
    267 2005-08-31 22:07:38.333 It has 2 channels and we needed at least 1
    268 2005-08-31 22:07:38.333 Initializing audio parms from audio track #0.
    269 2005-08-31 22:07:38.334 Killing AudioOutputDSP
    270 2005-08-31 22:07:38.334 Opening audio device 'spdif'.
    271 2005-08-31 22:07:38.342 in SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=125000)
    272 2005-08-31 22:07:38.342 get_buffer_size returned 16384
    273 2005-08-31 22:07:38.343 set_period_time_near returned 85333
    274 2005-08-31 22:07:38.343 get_period_size returned 4096
    275 2005-08-31 22:07:38.343 Audio fragment size: 4096
    276 2005-08-31 22:07:38.344 Audio Stretch Factor: 1
    277 2005-08-31 22:07:38.344 Ending reconfigure
    278 2005-08-31 22:07:38.344 kickoffOutputAudioLoop: pid = 11615
    279 2005-08-31 22:07:38.344 OutputAudioLoop: Play Event
    280 2005-08-31 22:07:38.344 Broadcasting free space avail
    281 2005-08-31 22:07:38.355 Broadcasting free space avail
    282 2005-08-31 22:07:38.363 Broadcasting free space avail
    283 2005-08-31 22:07:38.371 Broadcasting free space avail
    284 2005-08-31 22:07:38.379 Broadcasting free space avail
    285 2005-08-31 22:07:38.387 Broadcasting free space avail
    286 2005-08-31 22:07:38.396 Broadcasting free space avail
    287 2005-08-31 22:07:38.404 Broadcasting free space avail
    288 2005-08-31 22:07:38.412 Broadcasting free space avail
    289 2005-08-31 22:07:38.420 Broadcasting free space avail
    290 2005-08-31 22:07:38.428 Broadcasting free space avail
    291 2005-08-31 22:07:38.436 Broadcasting free space avail
    292 2005-08-31 22:07:38.445 Broadcasting free space avail
    293 2005-08-31 22:07:38.453 Broadcasting free space avail
    294 2005-08-31 22:07:38.461 Broadcasting free space avail
    295 2005-08-31 22:07:38.469 Broadcasting free space avail
    296 2005-08-31 22:07:38.477 Broadcasting free space avail
    297 2005-08-31 22:07:38.485 Broadcasting free space avail
    298 2005-08-31 22:07:38.486 read  <- 18 6       128000
    299 2005-08-31 22:07:38.486 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    300 2005-08-31 22:07:38.486 Estimated bitrate = 5224
    301 2005-08-31 22:07:38.486 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
    302 2005-08-31 22:07:38.487 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    303 2005-08-31 22:07:38.494 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    304 2005-08-31 22:07:38.494 Broadcasting free space avail
    305 2005-08-31 22:07:38.502 Broadcasting free space avail
    306 2005-08-31 22:07:38.502 read  <- 17 8       0[]:[]53
    307 2005-08-31 22:07:38.502 Filling position map from 0 to 53
    308 2005-08-31 22:07:38.502 write -> 17 51      QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]0[]:[]53
    309 2005-08-31 22:07:38.510 Broadcasting free space avail
    310 2005-08-31 22:07:38.510 read  <- 17 119     0[]:[]11[]:[]0[]:[]5631164[]:[]0[]:[]23[]:[]0[]:[]5911660[]:[]0[]...
    311 2005-08-31 22:07:38.510 Position map filled from Encoder to: 47
    312 2005-08-31 22:07:38.511 SyncPositionMap liveTV, from Encoder: 4 entries
    313 2005-08-31 22:07:38.511 SyncPositionMap, new totframes: 47, new length: 1, posMap size: 4
    314 2005-08-31 22:07:38.511 Partial position map found
    315 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)
    316 2005-08-31 22:07:38.513 VideoOutputXv()
    317 2005-08-31 22:07:38.518 Broadcasting free space avail
    318 2005-08-31 22:07:38.520 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
    319 2005-08-31 22:07:38.526 Broadcasting free space avail
    320 2005-08-31 22:07:38.526 XvMC version: 1.0
    321 2005-08-31 22:07:38.527 @ j=1 Looking for flag[s]: XvInputMask
    322 2005-08-31 22:07:38.527 Adaptor: 0 has flag[s]: XvInputMask XvImageMask
    323 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)
    324 2005-08-31 22:07:38.527 Trying XvMC port 270
    325 2005-08-31 22:07:38.527 Found a suitable XvMC surface 0
    326 2005-08-31 22:07:38.527 XvMC surface found with IDCT support on port 270
    327 2005-08-31 22:07:38.534 Broadcasting free space avail
    328 2005-08-31 22:07:38.542 Broadcasting free space avail
    329 2005-08-31 22:07:38.550 Broadcasting free space avail
    330 2005-08-31 22:07:38.555 Couldn't get the color key color, and we need it.
    331 You likely won't get any video.
    332 2005-08-31 22:07:38.555 Image size. dispxoff 0, dispyoff: 0, dispwoff: 666, disphoff: 533
    333 2005-08-31 22:07:38.555 Image size. imgx 0, imgy: 0, imgw: 704, imgh: 576
    334 2005-08-31 22:07:38.558 Broadcasting free space avail
    335 2005-08-31 22:07:38.566 Broadcasting free space avail
    336 2005-08-31 22:07:38.574 Broadcasting free space avail
    337 2005-08-31 22:07:38.582 Broadcasting free space avail
    338 2005-08-31 22:07:38.590 Broadcasting free space avail
    339 2005-08-31 22:07:38.598 Broadcasting free space avail
    340 2005-08-31 22:07:38.606 Broadcasting free space avail
    341 2005-08-31 22:07:38.614 Broadcasting free space avail
    342 2005-08-31 22:07:38.622 Broadcasting free space avail
    343 2005-08-31 22:07:38.630 Broadcasting free space avail
    344 2005-08-31 22:07:38.638 Broadcasting free space avail
    345 2005-08-31 22:07:38.646 Broadcasting free space avail
    346 2005-08-31 22:07:38.654 Broadcasting free space avail
    347 2005-08-31 22:07:38.662 Broadcasting free space avail
    348 2005-08-31 22:07:38.670 Broadcasting free space avail
    349 2005-08-31 22:07:38.678 Broadcasting free space avail
    350 2005-08-31 22:07:38.686 Broadcasting free space avail
    351 2005-08-31 22:07:38.694 Broadcasting free space avail
    352 2005-08-31 22:07:38.702 Broadcasting free space avail
    353 2005-08-31 22:07:38.706 read  <- 18 6       128000
    354 2005-08-31 22:07:38.706 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    355 2005-08-31 22:07:38.710 Broadcasting free space avail
    356 2005-08-31 22:07:38.714 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    357 2005-08-31 22:07:38.718 Broadcasting free space avail
    358 2005-08-31 22:07:38.726 Broadcasting free space avail
    359 2005-08-31 22:07:38.734 Broadcasting free space avail
    360 2005-08-31 22:07:38.742 Broadcasting free space avail
    361 2005-08-31 22:07:38.750 Broadcasting free space avail
    362 2005-08-31 22:07:38.758 Broadcasting free space avail
    363 2005-08-31 22:07:38.766 Broadcasting free space avail
    364 2005-08-31 22:07:38.774 Broadcasting free space avail
    365 2005-08-31 22:07:38.782 Broadcasting free space avail
    366 2005-08-31 22:07:38.790 Broadcasting free space avail
    367 2005-08-31 22:07:38.798 Broadcasting free space avail
    368 2005-08-31 22:07:38.806 Broadcasting free space avail
    369 2005-08-31 22:07:38.814 Broadcasting free space avail
    370 2005-08-31 22:07:38.822 Broadcasting free space avail
    371 2005-08-31 22:07:38.830 Broadcasting free space avail
    372 2005-08-31 22:07:38.838 Broadcasting free space avail
    373 2005-08-31 22:07:38.846 Broadcasting free space avail
    374 2005-08-31 22:07:38.854 Broadcasting free space avail
    375 2005-08-31 22:07:38.862 Broadcasting free space avail
    376 2005-08-31 22:07:38.870 Broadcasting free space avail
    377 2005-08-31 22:07:38.878 Broadcasting free space avail
    378 2005-08-31 22:07:38.886 Broadcasting free space avail
    379 2005-08-31 22:07:38.894 Broadcasting free space avail
    380 2005-08-31 22:07:38.902 Broadcasting free space avail
    381 2005-08-31 22:07:38.910 Broadcasting free space avail
    382 2005-08-31 22:07:38.911 read  <- 18 6       128000
    383 2005-08-31 22:07:38.911 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    384 2005-08-31 22:07:38.918 Broadcasting free space avail
    385 2005-08-31 22:07:38.922 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    386 2005-08-31 22:07:38.926 Broadcasting free space avail
    387 2005-08-31 22:07:38.931 Using deinterlace method bobdeint
    388 2005-08-31 22:07:38.933 Using realtime priority.
    389 2005-08-31 22:07:38.934 Changing from None to WatchingLiveTV
    390 2005-08-31 22:07:38.934 write -> 17 35      QUERY_RECORDER 1[]:[]GET_INPUT_NAME
    391 2005-08-31 22:07:38.934 OutputAudioLoop: audio paused
    392 2005-08-31 22:07:38.934 65536 bytes free on soundcard
    393 2005-08-31 22:07:38.935 WriteAudio: Preparing 4096 bytes (1024 frames)
    394 2005-08-31 22:07:38.942 61440 bytes free on soundcard
    395 2005-08-31 22:07:38.942 WriteAudio: Preparing 4096 bytes (1024 frames)
    396 2005-08-31 22:07:38.949 _AddSamples bytes=4608, used=1, free=767999, timecode=13565894
    397 2005-08-31 22:07:38.950 read  <- 17 8       DVBInput
    398 2005-08-31 22:07:38.950 write -> 17 35      QUERY_RECORDER 1[]:[]FRONTEND_READY
    399 2005-08-31 22:07:38.950 _AddSamples bytes=4608, used=4609, free=763391, timecode=13565918
    400 2005-08-31 22:07:38.951 57344 bytes free on soundcard
    401 2005-08-31 22:07:38.951 _AddSamples bytes=4608, used=9217, free=758783, timecode=13565942
    402 2005-08-31 22:07:38.952 _AddSamples bytes=4608, used=13825, free=754175, timecode=13565966
    403 2005-08-31 22:07:38.952 _AddSamples bytes=4608, used=18433, free=749567, timecode=13565990
    404 2005-08-31 22:07:38.957 _AddSamples bytes=4608, used=23041, free=744959, timecode=13566014
    405 2005-08-31 22:07:38.957 _AddSamples bytes=4608, used=27649, free=740351, timecode=13566038
    406 2005-08-31 22:07:38.958 read  <- 17 2       ok
    407 2005-08-31 22:07:38.959 write -> 17 37      QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO
    408 2005-08-31 22:07:38.978 read  <- 17 103      []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10...
    409 2005-08-31 22:07:38.982 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    410 2005-08-31 22:07:38.998 read  <- 17 8       0[]:[]64
    411 2005-08-31 22:07:38.999 write -> 14 19      QUERY_GETALLPENDING
    412 2005-08-31 22:07:39.015 read  <- 14 7       0[]:[]0
    413 2005-08-31 22:07:39.035 write -> 17 37      QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO
    414 2005-08-31 22:07:39.039 nVidiaVideoSync: VBlank ioctl did not work, unimplemented in this driver?
    415 2005-08-31 22:07:39.039 DRMVideoSync: Could not open device /dev/dri/card0, No such file or directory
    416 2005-08-31 22:07:39.040 Set video sync frame interval to 40000
    417 2005-08-31 22:07:39.041 Using audio as timebase
    418 2005-08-31 22:07:39.041 Video timing method: RTC
    419 2005-08-31 22:07:39.041 Refresh rate: 20000, frame interval: 40000
    420 2005-08-31 22:07:39.041 waiting for prebuffer... 0
    421 2005-08-31 22:07:39.051 read  <- 17 103      []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10...
    422 2005-08-31 22:07:39.051 write -> 17 53      QUERY_RECORDER 1[]:[]GET_FREE_SPACE[]:[]0[]:[]6750208
    423 2005-08-31 22:07:39.068 read  <- 17 16      2[]:[]2084457672
    424 2005-08-31 22:07:39.068 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    425 2005-08-31 22:07:39.084 read  <- 17 8       0[]:[]67
    426 2005-08-31 22:07:39.122 read  <- 18 6       128000
    427 2005-08-31 22:07:39.122 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    428 2005-08-31 22:07:39.122 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    429 2005-08-31 22:07:39.123 _AddSamples bytes=4608, used=32257, free=735743, timecode=13566062
    430 2005-08-31 22:07:39.133 OutputAudioLoop: Play Event
    431 2005-08-31 22:07:39.133 Broadcasting free space avail
    432 2005-08-31 22:07:39.133 WriteAudio: Preparing 4096 bytes (1024 frames)
    433 2005-08-31 22:07:39.134 Broadcasting free space avail
    434 2005-08-31 22:07:39.134 WriteAudio: Preparing 4096 bytes (1024 frames)
    435 2005-08-31 22:07:39.134 Broadcasting free space avail
    436 2005-08-31 22:07:39.134 WriteAudio: Preparing 4096 bytes (1024 frames)
    437 2005-08-31 22:07:39.134 Broadcasting free space avail
    438 2005-08-31 22:07:39.134 WriteAudio: Preparing 4096 bytes (1024 frames)
    439 2005-08-31 22:07:39.134 Broadcasting free space avail
    440 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames)
    441 2005-08-31 22:07:39.135 Broadcasting free space avail
    442 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames)
    443 2005-08-31 22:07:39.135 Broadcasting free space avail
    444 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames)
    445 2005-08-31 22:07:39.135 Broadcasting free space avail
    446 2005-08-31 22:07:39.135 WriteAudio: Preparing 4096 bytes (1024 frames)
    447 2005-08-31 22:07:39.135 Broadcasting free space avail
    448 2005-08-31 22:07:39.136 WriteAudio: Preparing 4096 bytes (1024 frames)
    449 2005-08-31 22:07:39.136 Broadcasting free space avail
    450 2005-08-31 22:07:39.139 _AddSamples bytes=4608, used=1, free=767999, timecode=13566086
    451 2005-08-31 22:07:39.139 _AddSamples bytes=4608, used=4609, free=763391, timecode=13566110
    452 2005-08-31 22:07:39.144 Frame B w/children:  A        is being held for later discarding.
    453 2005-08-31 22:07:39.182 Broadcasting free space avail
    454 2005-08-31 22:07:39.182 WriteAudio: Preparing 4096 bytes (1024 frames)
    455 2005-08-31 22:07:39.182 Broadcasting free space avail
    456 2005-08-31 22:07:39.182 WriteAudio: Preparing 4096 bytes (1024 frames)
    457 2005-08-31 22:07:39.182 audio waiting for buffer to fill: have 1024 want 4096
    458 2005-08-31 22:07:39.183 Broadcasting free space avail
    459 2005-08-31 22:07:39.193 audio waiting for buffer to fill: have 1024 want 4096
    460 2005-08-31 22:07:39.222 Broadcasting free space avail
    461 2005-08-31 22:07:39.223 _AddSamples bytes=4608, used=1025, free=766975, timecode=13566134
    462 2005-08-31 22:07:39.223 _AddSamples bytes=4608, used=5633, free=762367, timecode=13566158
    463 2005-08-31 22:07:39.230 Broadcasting free space avail
    464 2005-08-31 22:07:39.231 WriteAudio: Preparing 4096 bytes (1024 frames)
    465 2005-08-31 22:07:39.231 Broadcasting free space avail
    466 2005-08-31 22:07:39.231 WriteAudio: Preparing 4096 bytes (1024 frames)
    467 2005-08-31 22:07:39.231 audio waiting for buffer to fill: have 2048 want 4096
    468 2005-08-31 22:07:39.231 Broadcasting free space avail
    469 2005-08-31 22:07:39.261 audio waiting for buffer to fill: have 2048 want 4096
    470 2005-08-31 22:07:39.262 Broadcasting free space avail
    471 2005-08-31 22:07:39.265 _AddSamples bytes=4608, used=2049, free=765951, timecode=13566182
    472 2005-08-31 22:07:39.271 Frame D w/children:    C      is being held for later discarding.
    473 2005-08-31 22:07:39.270 Broadcasting free space avail
    474 2005-08-31 22:07:39.306 WriteAudio: Preparing 4096 bytes (1024 frames)
    475 2005-08-31 22:07:39.306 _AddSamples bytes=4608, used=2561, free=765439, timecode=13566206
    476 2005-08-31 22:07:39.307 Broadcasting free space avail
    477 2005-08-31 22:07:39.307 WriteAudio: Preparing 4096 bytes (1024 frames)
    478 2005-08-31 22:07:39.307 audio waiting for buffer to fill: have 3072 want 4096
    479 2005-08-31 22:07:39.307 Broadcasting free space avail
    480 2005-08-31 22:07:39.307 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566230
    481 2005-08-31 22:07:39.341 Broadcasting free space avail
    482 2005-08-31 22:07:39.341 WriteAudio: Preparing 4096 bytes (1024 frames)
    483 2005-08-31 22:07:39.342 audio waiting for buffer to fill: have 3584 want 4096
    484 2005-08-31 22:07:39.342 Broadcasting free space avail
    485 2005-08-31 22:07:39.343 read  <- 18 6       128000
    486 2005-08-31 22:07:39.343 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    487 2005-08-31 22:07:39.343 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    488 2005-08-31 22:07:39.347 _AddSamples bytes=4608, used=3585, free=764415, timecode=13566254
    489 2005-08-31 22:07:39.347 _AddSamples bytes=4608, used=8193, free=759807, timecode=13566278
    490 2005-08-31 22:07:39.350 Broadcasting free space avail
    491 2005-08-31 22:07:39.351 WriteAudio: Preparing 4096 bytes (1024 frames)
    492 2005-08-31 22:07:39.381 Broadcasting free space avail
    493 2005-08-31 22:07:39.382 WriteAudio: Preparing 4096 bytes (1024 frames)
    494 2005-08-31 22:07:39.382 Broadcasting free space avail
    495 2005-08-31 22:07:39.382 WriteAudio: Preparing 4096 bytes (1024 frames)
    496 2005-08-31 22:07:39.382 audio waiting for buffer to fill: have 512 want 4096
    497 2005-08-31 22:07:39.382 Broadcasting free space avail
    498 2005-08-31 22:07:39.386 _AddSamples bytes=4608, used=513, free=767487, timecode=13566302
    499 2005-08-31 22:07:39.390 Broadcasting free space avail
    500 2005-08-31 22:07:39.391 WriteAudio: Preparing 4096 bytes (1024 frames)
    501 2005-08-31 22:07:39.391 Frame F w/children:    C E    is being held for later discarding.
    502 2005-08-31 22:07:39.421 audio waiting for buffer to fill: have 1024 want 4096
    503 2005-08-31 22:07:39.422 Broadcasting free space avail
    504 2005-08-31 22:07:39.428 _AddSamples bytes=4608, used=1025, free=766975, timecode=13566326
    505 2005-08-31 22:07:39.429 _AddSamples bytes=4608, used=5633, free=762367, timecode=13566350
    506 2005-08-31 22:07:39.430 Broadcasting free space avail
    507 2005-08-31 22:07:39.430 WriteAudio: Preparing 4096 bytes (1024 frames)
    508 2005-08-31 22:07:39.430 Frame F w/children:    C      is being held for later discarding.
    509 2005-08-31 22:07:39.431 Broadcasting free space avail
    510 2005-08-31 22:07:39.431 WriteAudio: Preparing 4096 bytes (1024 frames)
    511 2005-08-31 22:07:39.431 audio waiting for buffer to fill: have 2048 want 4096
    512 2005-08-31 22:07:39.431 Broadcasting free space avail
    513 2005-08-31 22:07:39.462 audio waiting for buffer to fill: have 2048 want 4096
    514 2005-08-31 22:07:39.462 Broadcasting free space avail
    515 2005-08-31 22:07:39.465 _AddSamples bytes=4608, used=2049, free=765951, timecode=13566374
    516 2005-08-31 22:07:39.466 _AddSamples bytes=4608, used=6657, free=761343, timecode=13566398
    517 2005-08-31 22:07:39.470 Broadcasting free space avail
    518 2005-08-31 22:07:39.471 WriteAudio: Preparing 4096 bytes (1024 frames)
    519 2005-08-31 22:07:39.471 Broadcasting free space avail
    520 2005-08-31 22:07:39.471 WriteAudio: Preparing 4096 bytes (1024 frames)
    521 2005-08-31 22:07:39.471 audio waiting for buffer to fill: have 3072 want 4096
    522 2005-08-31 22:07:39.472 Broadcasting free space avail
    523 2005-08-31 22:07:39.501 audio waiting for buffer to fill: have 3072 want 4096
    524 2005-08-31 22:07:39.501 Broadcasting free space avail
    525 2005-08-31 22:07:39.505 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566422
    526 2005-08-31 22:07:39.511 Frame G w/children:       F   is being held for later discarding.
    527 2005-08-31 22:07:39.511 Broadcasting free space avail
    528 2005-08-31 22:07:39.511 WriteAudio: Preparing 4096 bytes (1024 frames)
    529 2005-08-31 22:07:39.512 audio waiting for buffer to fill: have 3584 want 4096
    530 2005-08-31 22:07:39.512 Broadcasting free space avail
    531 2005-08-31 22:07:39.542 audio waiting for buffer to fill: have 3584 want 4096
    532 2005-08-31 22:07:39.542 Broadcasting free space avail
    533 2005-08-31 22:07:39.547 _AddSamples bytes=4608, used=3585, free=764415, timecode=13566446
    534 2005-08-31 22:07:39.547 _AddSamples bytes=4608, used=8193, free=759807, timecode=13566470
    535 2005-08-31 22:07:39.550 Broadcasting free space avail
    536 2005-08-31 22:07:39.581 WriteAudio: Preparing 4096 bytes (1024 frames)
    537 2005-08-31 22:07:39.581 Broadcasting free space avail
    538 2005-08-31 22:07:39.581 WriteAudio: Preparing 4096 bytes (1024 frames)
    539 2005-08-31 22:07:39.582 Broadcasting free space avail
    540 2005-08-31 22:07:39.582 WriteAudio: Preparing 4096 bytes (1024 frames)
    541 2005-08-31 22:07:39.582 audio waiting for buffer to fill: have 512 want 4096
    542 2005-08-31 22:07:39.582 Broadcasting free space avail
    543 2005-08-31 22:07:39.590 audio waiting for buffer to fill: have 512 want 4096
    544 2005-08-31 22:07:39.591 Broadcasting free space avail
    545 2005-08-31 22:07:39.591 read  <- 18 6       128000
    546 2005-08-31 22:07:39.592 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    547 2005-08-31 22:07:39.592 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    548 2005-08-31 22:07:39.623 audio waiting for buffer to fill: have 512 want 4096
    549 2005-08-31 22:07:39.623 Broadcasting free space avail
    550 2005-08-31 22:07:39.623 _AddSamples bytes=4608, used=513, free=767487, timecode=13566494
    551 2005-08-31 22:07:39.624 _AddSamples bytes=4608, used=5121, free=762879, timecode=13566518
    552 2005-08-31 22:07:39.629 _AddSamples bytes=4608, used=9729, free=758271, timecode=13566542
    553 2005-08-31 22:07:39.631 Frame B w/children:  A   E    is being held for later discarding.
    554 2005-08-31 22:07:39.663 Broadcasting free space avail
    555 2005-08-31 22:07:39.663 WriteAudio: Preparing 4096 bytes (1024 frames)
    556 2005-08-31 22:07:39.663 Broadcasting free space avail
    557 2005-08-31 22:07:39.663 WriteAudio: Preparing 4096 bytes (1024 frames)
    558 2005-08-31 22:07:39.663 Broadcasting free space avail
    559 2005-08-31 22:07:39.663 WriteAudio: Preparing 4096 bytes (1024 frames)
    560 2005-08-31 22:07:39.664 audio waiting for buffer to fill: have 2048 want 4096
    561 2005-08-31 22:07:39.664 Broadcasting free space avail
    562 2005-08-31 22:07:39.671 Frame B w/children:  A        is being held for later discarding.
    563 2005-08-31 22:07:39.703 audio waiting for buffer to fill: have 2048 want 4096
    564 2005-08-31 22:07:39.703 Broadcasting free space avail
    565 2005-08-31 22:07:39.708 _AddSamples bytes=4608, used=2049, free=765951, timecode=13566566
    566 2005-08-31 22:07:39.708 _AddSamples bytes=4608, used=6657, free=761343, timecode=13566590
    567 2005-08-31 22:07:39.743 Broadcasting free space avail
    568 2005-08-31 22:07:39.743 WriteAudio: Preparing 4096 bytes (1024 frames)
    569 2005-08-31 22:07:39.743 Broadcasting free space avail
    570 2005-08-31 22:07:39.743 WriteAudio: Preparing 4096 bytes (1024 frames)
    571 2005-08-31 22:07:39.748 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566614
    572 2005-08-31 22:07:39.748 _AddSamples bytes=4608, used=7681, free=760319, timecode=13566638
    573 2005-08-31 22:07:39.749 Broadcasting free space avail
    574 2005-08-31 22:07:39.749 WriteAudio: Preparing 4096 bytes (1024 frames)
    575 2005-08-31 22:07:39.749 Broadcasting free space avail
    576 2005-08-31 22:07:39.749 WriteAudio: Preparing 4096 bytes (1024 frames)
    577 2005-08-31 22:07:39.749 Broadcasting free space avail
    578 2005-08-31 22:07:39.749 WriteAudio: Preparing 4096 bytes (1024 frames)
    579 2005-08-31 22:07:39.749 Broadcasting free space avail
    580 2005-08-31 22:07:39.751 Frame H w/children:        G  is being held for later discarding.
    581 2005-08-31 22:07:39.783 Broadcasting free space avail
    582 2005-08-31 22:07:39.786 _AddSamples bytes=4608, used=1, free=767999, timecode=13566662
    583 2005-08-31 22:07:39.823 Broadcasting free space avail
    584 2005-08-31 22:07:39.823 WriteAudio: Preparing 4096 bytes (1024 frames)
    585 2005-08-31 22:07:39.823 audio waiting for buffer to fill: have 512 want 4096
    586 2005-08-31 22:07:39.823 Broadcasting free space avail
    587 2005-08-31 22:07:39.827 _AddSamples bytes=4608, used=513, free=767487, timecode=13566686
    588 2005-08-31 22:07:39.828 _AddSamples bytes=4608, used=5121, free=762879, timecode=13566710
    589 2005-08-31 22:07:39.863 Broadcasting free space avail
    590 2005-08-31 22:07:39.863 WriteAudio: Preparing 4096 bytes (1024 frames)
    591 2005-08-31 22:07:39.863 Broadcasting free space avail
    592 2005-08-31 22:07:39.863 WriteAudio: Preparing 4096 bytes (1024 frames)
    593 2005-08-31 22:07:39.864 audio waiting for buffer to fill: have 1536 want 4096
    594 2005-08-31 22:07:39.864 Broadcasting free space avail
    595 2005-08-31 22:07:39.864 read  <- 18 6       128000
    596 2005-08-31 22:07:39.864 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    597 2005-08-31 22:07:39.864 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    598 2005-08-31 22:07:39.865 _AddSamples bytes=4608, used=1537, free=766463, timecode=13566734
    599 2005-08-31 22:07:39.866 _AddSamples bytes=4608, used=6145, free=761855, timecode=13566758
    600 2005-08-31 22:07:39.870 _AddSamples bytes=4608, used=10753, free=757247, timecode=13566782
    601 2005-08-31 22:07:39.871 Frame F w/children:   B    G  is being held for later discarding.
    602 2005-08-31 22:07:39.903 Broadcasting free space avail
    603 2005-08-31 22:07:39.903 WriteAudio: Preparing 4096 bytes (1024 frames)
    604 2005-08-31 22:07:39.903 Broadcasting free space avail
    605 2005-08-31 22:07:39.904 WriteAudio: Preparing 4096 bytes (1024 frames)
    606 2005-08-31 22:07:39.904 Broadcasting free space avail
    607 2005-08-31 22:07:39.904 WriteAudio: Preparing 4096 bytes (1024 frames)
    608 2005-08-31 22:07:39.904 audio waiting for buffer to fill: have 3072 want 4096
    609 2005-08-31 22:07:39.904 Broadcasting free space avail
    610 2005-08-31 22:07:39.911 Frame F w/children:        G  is being held for later discarding.
    611 2005-08-31 22:07:39.943 audio waiting for buffer to fill: have 3072 want 4096
    612 2005-08-31 22:07:39.943 Broadcasting free space avail
    613 2005-08-31 22:07:39.945 _AddSamples bytes=4608, used=3073, free=764927, timecode=13566806
    614 2005-08-31 22:07:39.946 _AddSamples bytes=4608, used=7681, free=760319, timecode=13566830
    615 2005-08-31 22:07:39.949 _AddSamples bytes=4608, used=12289, free=755711, timecode=13566854
    616 2005-08-31 22:07:39.950 _AddSamples bytes=4608, used=16897, free=751103, timecode=13566878
    617 2005-08-31 22:07:39.983 Broadcasting free space avail
    618 2005-08-31 22:07:39.983 WriteAudio: Preparing 4096 bytes (1024 frames)
    619 2005-08-31 22:07:39.983 Broadcasting free space avail
    620 2005-08-31 22:07:39.983 WriteAudio: Preparing 4096 bytes (1024 frames)
    621 2005-08-31 22:07:39.983 Broadcasting free space avail
    622 2005-08-31 22:07:39.983 WriteAudio: Preparing 4096 bytes (1024 frames)
    623 2005-08-31 22:07:39.984 Broadcasting free space avail
    624 2005-08-31 22:07:39.984 WriteAudio: Preparing 4096 bytes (1024 frames)
    625 2005-08-31 22:07:39.984 Broadcasting free space avail
    626 2005-08-31 22:07:39.984 WriteAudio: Preparing 4096 bytes (1024 frames)
    627 2005-08-31 22:07:39.984 audio waiting for buffer to fill: have 1024 want 4096
    628 2005-08-31 22:07:39.984 Broadcasting free space avail
    629 2005-08-31 22:07:39.988 _AddSamples bytes=4608, used=1025, free=766975, timecode=13566902
    630 2005-08-31 22:07:39.991 Frame A w/children:   B       is being held for later discarding.
    631 2005-08-31 22:07:40.023 Broadcasting free space avail
    632 2005-08-31 22:07:40.023 WriteAudio: Preparing 4096 bytes (1024 frames)
    633 2005-08-31 22:07:40.023 audio waiting for buffer to fill: have 1536 want 4096
    634 2005-08-31 22:07:40.023 Broadcasting free space avail
    635 2005-08-31 22:07:40.028 _AddSamples bytes=4608, used=1537, free=766463, timecode=13566926
    636 2005-08-31 22:07:40.029 _AddSamples bytes=4608, used=6145, free=761855, timecode=13566950
    637 2005-08-31 22:07:40.063 Broadcasting free space avail
    638 2005-08-31 22:07:40.063 WriteAudio: Preparing 4096 bytes (1024 frames)
    639 2005-08-31 22:07:40.063 Broadcasting free space avail
    640 2005-08-31 22:07:40.063 WriteAudio: Preparing 4096 bytes (1024 frames)
    641 2005-08-31 22:07:40.063 audio waiting for buffer to fill: have 2560 want 4096
    642 2005-08-31 22:07:40.063 Broadcasting free space avail
    643 2005-08-31 22:07:40.067 _AddSamples bytes=4608, used=2561, free=765439, timecode=13566974
    644 2005-08-31 22:07:40.068 _AddSamples bytes=4608, used=7169, free=760831, timecode=13566998
    645 2005-08-31 22:07:40.103 Broadcasting free space avail
    646 2005-08-31 22:07:40.103 WriteAudio: Preparing 4096 bytes (1024 frames)
    647 2005-08-31 22:07:40.103 Broadcasting free space avail
    648 2005-08-31 22:07:40.104 WriteAudio: Preparing 4096 bytes (1024 frames)
    649 2005-08-31 22:07:40.104 audio waiting for buffer to fill: have 3584 want 4096
    650 2005-08-31 22:07:40.104 Broadcasting free space avail
    651 2005-08-31 22:07:40.104 read  <- 18 6       128000
    652 2005-08-31 22:07:40.105 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    653 2005-08-31 22:07:40.105 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    654 2005-08-31 22:07:40.108 _AddSamples bytes=4608, used=3585, free=764415, timecode=13567022
    655 2005-08-31 22:07:40.111 Frame E w/children:     D   H is being held for later discarding.
    656 2005-08-31 22:07:40.143 Broadcasting free space avail
    657 2005-08-31 22:07:40.143 WriteAudio: Preparing 4096 bytes (1024 frames)
    658 2005-08-31 22:07:40.143 Broadcasting free space avail
    659 2005-08-31 22:07:40.143 WriteAudio: Preparing 4096 bytes (1024 frames)
    660 2005-08-31 22:07:40.143 Broadcasting free space avail
    661 2005-08-31 22:07:40.149 _AddSamples bytes=4608, used=1, free=767999, timecode=13567046
    662 2005-08-31 22:07:40.150 _AddSamples bytes=4608, used=4609, free=763391, timecode=13567070
    663 2005-08-31 22:07:40.151 Frame E w/children:         H is being held for later discarding.
    664 2005-08-31 22:07:40.186 _AddSamples bytes=4608, used=9217, free=758783, timecode=13567094
    665 2005-08-31 22:07:40.187 _AddSamples bytes=4608, used=13825, free=754175, timecode=13567118
    666 2005-08-31 22:07:40.187 Broadcasting free space avail
    667 2005-08-31 22:07:40.187 WriteAudio: Preparing 4096 bytes (1024 frames)
    668 2005-08-31 22:07:40.187 Broadcasting free space avail
    669 2005-08-31 22:07:40.188 WriteAudio: Preparing 4096 bytes (1024 frames)
    670 2005-08-31 22:07:40.188 Broadcasting free space avail
    671 2005-08-31 22:07:40.188 WriteAudio: Preparing 4096 bytes (1024 frames)
    672 2005-08-31 22:07:40.188 Broadcasting free space avail
    673 2005-08-31 22:07:40.188 WriteAudio: Preparing 4096 bytes (1024 frames)
    674 2005-08-31 22:07:40.188 audio waiting for buffer to fill: have 2048 want 4096
    675 2005-08-31 22:07:40.188 Broadcasting free space avail
    676 2005-08-31 22:07:40.223 audio waiting for buffer to fill: have 2048 want 4096
    677 2005-08-31 22:07:40.223 Broadcasting free space avail
    678 2005-08-31 22:07:40.226 _AddSamples bytes=4608, used=2049, free=765951, timecode=13567142
    679 2005-08-31 22:07:40.232 Frame G w/children:  A        is being held for later discarding.
    680 2005-08-31 22:07:40.263 Broadcasting free space avail
    681 2005-08-31 22:07:40.263 WriteAudio: Preparing 4096 bytes (1024 frames)
    682 2005-08-31 22:07:40.263 audio waiting for buffer to fill: have 2560 want 4096
    683 2005-08-31 22:07:40.263 Broadcasting free space avail
    684 2005-08-31 22:07:40.267 _AddSamples bytes=4608, used=2561, free=765439, timecode=13567166
    685 2005-08-31 22:07:40.268 _AddSamples bytes=4608, used=7169, free=760831, timecode=13567190
    686 2005-08-31 22:07:40.306 _AddSamples bytes=4608, used=11777, free=756223, timecode=13567214
    687 2005-08-31 22:07:40.307 _AddSamples bytes=4608, used=16385, free=751615, timecode=13567238
    688 2005-08-31 22:07:40.307 Broadcasting free space avail
    689 2005-08-31 22:07:40.307 WriteAudio: Preparing 4096 bytes (1024 frames)
    690 2005-08-31 22:07:40.307 Broadcasting free space avail
    691 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames)
    692 2005-08-31 22:07:40.308 Broadcasting free space avail
    693 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames)
    694 2005-08-31 22:07:40.308 Broadcasting free space avail
    695 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames)
    696 2005-08-31 22:07:40.308 Broadcasting free space avail
    697 2005-08-31 22:07:40.308 WriteAudio: Preparing 4096 bytes (1024 frames)
    698 2005-08-31 22:07:40.308 audio waiting for buffer to fill: have 512 want 4096
    699 2005-08-31 22:07:40.308 Broadcasting free space avail
    700 2005-08-31 22:07:40.343 audio waiting for buffer to fill: have 512 want 4096
    701 2005-08-31 22:07:40.343 Broadcasting free space avail
    702 2005-08-31 22:07:40.352 Frame B w/children:     D     is being held for later discarding.
    703 2005-08-31 22:07:40.352 audio waiting for buffer to fill: have 512 want 4096
    704 2005-08-31 22:07:40.383 Broadcasting free space avail
    705 2005-08-31 22:07:40.385 read  <- 18 6       128000
    706 2005-08-31 22:07:40.385 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    707 2005-08-31 22:07:40.385 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    708 2005-08-31 22:07:40.386 _AddSamples bytes=4608, used=513, free=767487, timecode=13567262
    709 2005-08-31 22:07:40.391 Broadcasting free space avail
    710 2005-08-31 22:07:40.392 WriteAudio: Preparing 4096 bytes (1024 frames)
    711 2005-08-31 22:07:40.392 audio waiting for buffer to fill: have 1024 want 4096
    712 2005-08-31 22:07:40.423 Broadcasting free space avail
    713 2005-08-31 22:07:40.427 audio waiting for buffer to fill: have 1024 want 4096
    714 2005-08-31 22:07:40.428 Broadcasting free space avail
    715 2005-08-31 22:07:40.428 prebuffering pause
    716 2005-08-31 22:07:40.428 waiting for prebuffer... 0
    717 2005-08-31 22:07:40.431 _AddSamples bytes=4608, used=1025, free=766975, timecode=13567286
    718 2005-08-31 22:07:40.431 _AddSamples bytes=4608, used=5633, free=762367, timecode=13567310
    719 2005-08-31 22:07:40.435 _AddSamples bytes=4608, used=10241, free=757759, timecode=13567334
    720 2005-08-31 22:07:40.435 OutputAudioLoop: audio paused
    721 2005-08-31 22:07:40.436 41048 bytes free on soundcard
    722 2005-08-31 22:07:40.436 _AddSamples bytes=4608, used=14849, free=753151, timecode=13567358
    723 2005-08-31 22:07:40.439 _AddSamples bytes=4608, used=19457, free=748543, timecode=13567382
    724 2005-08-31 22:07:40.463 OutputAudioLoop: Play Event
    725 2005-08-31 22:07:40.463 Broadcasting free space avail
    726 2005-08-31 22:07:40.463 WriteAudio: Preparing 4096 bytes (1024 frames)
    727 2005-08-31 22:07:40.463 Broadcasting free space avail
    728 2005-08-31 22:07:40.463 WriteAudio: Preparing 4096 bytes (1024 frames)
    729 2005-08-31 22:07:40.464 Broadcasting free space avail
    730 2005-08-31 22:07:40.464 WriteAudio: Preparing 4096 bytes (1024 frames)
    731 2005-08-31 22:07:40.464 Broadcasting free space avail
    732 2005-08-31 22:07:40.464 WriteAudio: Preparing 4096 bytes (1024 frames)
    733 2005-08-31 22:07:40.464 Broadcasting free space avail
    734 2005-08-31 22:07:40.464 WriteAudio: Preparing 4096 bytes (1024 frames)
    735 2005-08-31 22:07:40.464 audio waiting for buffer to fill: have 3584 want 4096
    736 2005-08-31 22:07:40.464 Broadcasting free space avail
    737 2005-08-31 22:07:40.468 Frame C w/children:   B       is being held for later discarding.
    738 2005-08-31 22:07:40.504 audio waiting for buffer to fill: have 3584 want 4096
    739 2005-08-31 22:07:40.504 Broadcasting free space avail
    740 2005-08-31 22:07:40.543 _AddSamples bytes=4608, used=3585, free=764415, timecode=13567406
    741 2005-08-31 22:07:40.544 Broadcasting free space avail
    742 2005-08-31 22:07:40.544 WriteAudio: Preparing 4096 bytes (1024 frames)
    743 2005-08-31 22:07:40.544 Broadcasting free space avail
    744 2005-08-31 22:07:40.544 WriteAudio: Preparing 4096 bytes (1024 frames)
    745 2005-08-31 22:07:40.544 _AddSamples bytes=4608, used=1, free=767999, timecode=13567430
    746 2005-08-31 22:07:40.544 Broadcasting free space avail
    747 2005-08-31 22:07:40.544 WriteAudio: Preparing 4096 bytes (1024 frames)
    748 2005-08-31 22:07:40.545 audio waiting for buffer to fill: have 512 want 4096
    749 2005-08-31 22:07:40.545 Broadcasting free space avail
    750 2005-08-31 22:07:40.547 Attempting to change from WatchingLiveTV to None
    751 2005-08-31 22:07:40.548 TV::StopStuff() -- begin
    752 2005-08-31 22:07:40.548 TV::StopStuff(): stopping ring buffer[s]
    753 2005-08-31 22:07:40.550 _AddSamples bytes=4608, used=513, free=767487, timecode=13567454
    754 2005-08-31 22:07:40.550 _AddSamples bytes=4608, used=5121, free=762879, timecode=13567478
    755 2005-08-31 22:07:40.551 Broadcasting free space avail
    756 2005-08-31 22:07:40.552 WriteAudio: Preparing 4096 bytes (1024 frames)
    757 2005-08-31 22:07:40.552 Broadcasting free space avail
    758 2005-08-31 22:07:40.552 WriteAudio: Preparing 4096 bytes (1024 frames)
    759 2005-08-31 22:07:40.552 audio waiting for buffer to fill: have 1536 want 4096
    760 2005-08-31 22:07:40.552 Broadcasting free space avail
    761 2005-08-31 22:07:40.554 _AddSamples bytes=4608, used=1537, free=766463, timecode=13567502
    762 2005-08-31 22:07:40.558 _AddSamples bytes=4608, used=6145, free=761855, timecode=13567526
    763 2005-08-31 22:07:40.560 Broadcasting free space avail
    764 2005-08-31 22:07:40.560 WriteAudio: Preparing 4096 bytes (1024 frames)
    765 2005-08-31 22:07:40.560 Broadcasting free space avail
    766 2005-08-31 22:07:40.560 WriteAudio: Preparing 4096 bytes (1024 frames)
    767 2005-08-31 22:07:40.560 audio waiting for buffer to fill: have 2560 want 4096
    768 2005-08-31 22:07:40.560 Broadcasting free space avail
    769 2005-08-31 22:07:40.568 audio waiting for buffer to fill: have 2560 want 4096
    770 2005-08-31 22:07:40.568 Broadcasting free space avail
    771 2005-08-31 22:07:40.576 audio waiting for buffer to fill: have 2560 want 4096
    772 2005-08-31 22:07:40.576 Broadcasting free space avail
    773 2005-08-31 22:07:40.580 ~VideoOutputXv()
    774 2005-08-31 22:07:40.580 VideoOutputXv::DiscardFrames() 1: LAUUAdUA
    775 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 2: LAUUAdUA
    776 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 3: LAUUAdUA
    777 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 4: AAAAAddA -- done()
    778 2005-08-31 22:07:40.581 VideoOutputXv::DiscardFrames() 1: AAAAAddA
    779 2005-08-31 22:07:40.582 VideoOutputXv::DiscardFrames() 2: AAAAAdAA
    780 2005-08-31 22:07:40.582 VideoOutputXv::DiscardFrames() 3: AAAAAdAA
    781 2005-08-31 22:07:40.582 VideoOutputXv::DiscardFrames() 4: AAAAAdAA -- done()
    782 2005-08-31 22:07:40.584 audio waiting for buffer to fill: have 2560 want 4096
    783 2005-08-31 22:07:40.584 Broadcasting free space avail
    784 2005-08-31 22:07:40.592 audio waiting for buffer to fill: have 2560 want 4096
    785 2005-08-31 22:07:40.592 Broadcasting free space avail
    786 2005-08-31 22:07:40.594 read  <- 18 6       128000
    787 2005-08-31 22:07:40.594 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    788 2005-08-31 22:07:40.594 TV::StopStuff(): stopping player[s] (1/2)
    789 2005-08-31 22:07:40.594 TV::StopStuff(): stopping recorder[s]
    790 2005-08-31 22:07:40.594 write -> 17 32      QUERY_RECORDER 1[]:[]STOP_LIVETV
    791 2005-08-31 22:07:40.618 audio waiting for buffer to fill: have 2560 want 4096
    792 2005-08-31 22:07:40.619 Broadcasting free space avail
    793 2005-08-31 22:07:40.619 Killing AudioOutputDSP
    794 2005-08-31 22:07:40.628 OutputAudioLoop: Stop Event
    795 2005-08-31 22:07:40.628 kickoffOutputAudioLoop exiting
    796 2005-08-31 22:07:40.641 read  <- 16 48      BACKEND_MESSAGE[]:[]DONE_RECORDING 1 4[]:[]empty
    797 2005-08-31 22:07:40.673 read  <- 17 2       ok
    798 2005-08-31 22:07:40.673 TV::StopStuff(): stopping player[s] (2/2)
    799 2005-08-31 22:07:40.681 read  <- 16 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
    800 2005-08-31 22:07:40.689 read  <- 16 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
    801 2005-08-31 22:07:40.702 write -> 18 33      QUERY_RECORDER 1[]:[]DONE_RINGBUF
    802 2005-08-31 22:07:40.717 read  <- 18 2       OK
    803 2005-08-31 22:07:40.717 TV::StopStuff() -- end
    804 2005-08-31 22:07:40.718 Changing from WatchingLiveTV to None
    805 2005-08-31 22:07:40.725 Attempting to change from None to None
    806 2005-08-31 22:07:41.381 write -> 14 34      QUERY_IS_ACTIVE_BACKEND[]:[]vdrtv1
    807 2005-08-31 22:07:41.399 read  <- 14 4       TRUE
    808 Destroying SipFsm object
    809 
    810 
    811 
    812 ----
    813 and broken XvMC-debug:
    814 
    815 ----
    816 
    817 2005-08-31 22:09:26.087 Using runtime prefix = /usr
    818 2005-08-31 22:09:26.104 New DB connection, total: 1
    819 2005-08-31 22:09:26.107 Total desktop dim: 720x576, with 1 screen[s].
    820 2005-08-31 22:09:26.109 Using screen 0, 720x576 at 0,0
    821 2005-08-31 22:09:26.112 mythfrontend version: 0.19.20050712-1 www.mythtv.org
    822 2005-08-31 22:09:26.113 Enabled verbose msgs :all
    823 2005-08-31 22:09:26.247 max_width: 720 max_height: 576
    824 2005-08-31 22:09:26.325 Total desktop dim: 720x576, with 1 screen[s].
    825 2005-08-31 22:09:26.326 Using screen 0, 720x576 at 0,0
    826 2005-08-31 22:09:26.328 Switching to square mode (blue)
    827 2005-08-31 22:09:26.518 Registering Internal as a media playback plugin.
    828 2005-08-31 22:09:26.534 Registering MythDVD DVD Media Handler as a media handler
    829 2005-08-31 22:09:26.534 Registering MythDVD VCD Media Handler as a media handler
    830 2005-08-31 22:09:26.873 Registering MythMusic Media Handler as a media handler
    831 SIP listening on IP Address 192.168.0.3:5060 NAT address 192.168.0.3
    832 SIP: Cannot register; proxy, username or password not set
    833 2005-08-31 22:09:27.179 generating cache image for: /usr/share/mythtv/themes/default/blank.png
    834 2005-08-31 22:09:27.470 Starting media monitor.
    835 2005-08-31 22:09:28.567 New DB connection, total: 2
    836 2005-08-31 22:09:28.610 Connecting to backend server: 127.0.0.1:6543 (try 1 of 5)
    837 2005-08-31 22:09:28.610 write -> 14 21      ANN Playback vdrtv1 0
    838 2005-08-31 22:09:28.627 read  <- 14 2       OK
    839 2005-08-31 22:09:28.630 write -> 14 29      GET_NEXT_FREE_RECORDER[]:[]-1
    840 2005-08-31 22:09:28.647 read  <- 14 24      1[]:[]127.0.0.1[]:[]6543
    841 2005-08-31 22:09:28.648 write -> 16 21      ANN Playback vdrtv1 1
    842 2005-08-31 22:09:28.648 Attempting to change from None to WatchingLiveTV
    843 2005-08-31 22:09:28.649 write -> 17 21      MYTH_PROTO_VERSION 18
    844 2005-08-31 22:09:28.664 read  <- 16 2       OK
    845 2005-08-31 22:09:28.664 read  <- 17 13      ACCEPT[]:[]18
    846 2005-08-31 22:09:28.664 Using protocol version 18
    847 2005-08-31 22:09:28.664 write -> 17 21      ANN Playback vdrtv1 0
    848 2005-08-31 22:09:28.680 read  <- 17 2       OK
    849 2005-08-31 22:09:28.680 write -> 17 44      QUERY_RECORDER 1[]:[]SETUP_RING_BUFFER[]:[]0
    850 2005-08-31 22:09:28.696 read  <- 17 92      ok[]:[]rbuf://127.0.0.1:6543/mnt/store/ringbuf1.nuv[]:[]2[]:[]-21...
    851 2005-08-31 22:09:28.697 write -> 18 21      ANN Playback vdrtv1 0
    852 2005-08-31 22:09:28.712 read  <- 18 2       OK
    853 2005-08-31 22:09:28.712 write -> 19 23      ANN RingBuffer vdrtv1 1
    854 2005-08-31 22:09:28.728 read  <- 19 2       OK
    855 2005-08-31 22:09:28.728 write -> 17 33      QUERY_RECORDER 1[]:[]SPAWN_LIVETV
    856 2005-08-31 22:09:28.760 read  <- 17 2       ok
    857 2005-08-31 22:09:28.761 write -> 17 33      QUERY_RECORDER 1[]:[]IS_RECORDING
    858 2005-08-31 22:09:28.776 read  <- 17 1       1
    859 2005-08-31 22:09:28.777 write -> 17 33      QUERY_RECORDER 1[]:[]IS_RECORDING
    860 2005-08-31 22:09:28.793 read  <- 17 1       1
    861 2005-08-31 22:09:28.793 write -> 17 34      QUERY_RECORDER 1[]:[]GET_FRAMERATE
    862 2005-08-31 22:09:28.809 read  <- 17 2       25
    863 2005-08-31 22:09:28.823 write -> 17 37      QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO
    864 2005-08-31 22:09:28.833 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    865 2005-08-31 22:09:28.841 read  <- 17 103      []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10...
    866 2005-08-31 22:09:28.841 Output filters for this channel are: ''
    867 2005-08-31 22:09:28.842 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    868 2005-08-31 22:09:28.861 read  <- 18 6       128000
    869 2005-08-31 22:09:28.861 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    870 2005-08-31 22:09:28.869 write -> 18 66      QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]2048
    871 2005-08-31 22:09:28.885 read  <- 18 7       0[]:[]0
    872 2005-08-31 22:09:28.889 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    873 2005-08-31 22:09:28.893 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    874 2005-08-31 22:09:28.902 read  <- 18 6       128000
    875 2005-08-31 22:09:28.902 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    876 2005-08-31 22:09:28.913 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    877 2005-08-31 22:09:28.922 read  <- 18 6       128000
    878 2005-08-31 22:09:28.922 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    879 2005-08-31 22:09:28.933 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    880 2005-08-31 22:09:28.946 read  <- 18 6       128000
    881 2005-08-31 22:09:28.946 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    882 2005-08-31 22:09:28.957 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    883 2005-08-31 22:09:28.962 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    884 2005-08-31 22:09:28.966 read  <- 18 6       128000
    885 2005-08-31 22:09:28.966 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    886 2005-08-31 22:09:28.977 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    887 2005-08-31 22:09:28.987 read  <- 18 6       128000
    888 2005-08-31 22:09:28.987 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    889 2005-08-31 22:09:28.998 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    890 2005-08-31 22:09:29.006 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    891 2005-08-31 22:09:29.010 read  <- 18 6       128000
    892 2005-08-31 22:09:29.010 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    893 2005-08-31 22:09:29.022 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    894 2005-08-31 22:09:29.034 read  <- 18 6       128000
    895 2005-08-31 22:09:29.034 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    896 2005-08-31 22:09:29.035 write -> 18 68      QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]0[]:[]0[]:[]0[]:[]851968
    897 2005-08-31 22:09:29.054 read  <- 18 7       0[]:[]0
    898 2005-08-31 22:09:29.054 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    899 2005-08-31 22:09:29.066 read  <- 18 6       128000
    900 2005-08-31 22:09:29.066 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    901 2005-08-31 22:09:29.070 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    902 2005-08-31 22:09:29.074 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    903 2005-08-31 22:09:29.082 read  <- 18 6       128000
    904 2005-08-31 22:09:29.083 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    905 2005-08-31 22:09:29.090 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    906 2005-08-31 22:09:29.099 read  <- 18 6       128000
    907 2005-08-31 22:09:29.099 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    908 2005-08-31 22:09:29.106 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    909 2005-08-31 22:09:29.115 read  <- 18 6       128000
    910 2005-08-31 22:09:29.115 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    911 2005-08-31 22:09:29.122 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    912 2005-08-31 22:09:29.126 read  <- 16 475     BACKEND_MESSAGE[]:[]SIGNAL 1[]:[]Signal Lock[]:[]slock 1 1 0 1 30...
    913 2005-08-31 22:09:29.131 read  <- 18 6       128000
    914 2005-08-31 22:09:29.131 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    915 2005-08-31 22:09:29.138 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    916 2005-08-31 22:09:29.147 read  <- 18 6       128000
    917 2005-08-31 22:09:29.147 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    918 2005-08-31 22:09:29.154 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    919 2005-08-31 22:09:29.163 read  <- 18 6       128000
    920 2005-08-31 22:09:29.163 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    921 2005-08-31 22:09:29.171 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    922 2005-08-31 22:09:29.179 read  <- 18 6       128000
    923 2005-08-31 22:09:29.179 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    924 2005-08-31 22:09:29.187 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    925 2005-08-31 22:09:29.195 read  <- 18 6       128000
    926 2005-08-31 22:09:29.196 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    927 2005-08-31 22:09:29.203 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    928 2005-08-31 22:09:29.211 read  <- 18 6       128000
    929 2005-08-31 22:09:29.211 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    930 2005-08-31 22:09:29.219 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    931 2005-08-31 22:09:29.228 read  <- 18 6       128000
    932 2005-08-31 22:09:29.228 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    933 2005-08-31 22:09:29.235 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    934 2005-08-31 22:09:29.244 read  <- 18 6       128000
    935 2005-08-31 22:09:29.244 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    936 2005-08-31 22:09:29.251 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    937 2005-08-31 22:09:29.260 read  <- 18 6       128000
    938 2005-08-31 22:09:29.260 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    939 2005-08-31 22:09:29.267 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    940 2005-08-31 22:09:29.276 read  <- 18 6       128000
    941 2005-08-31 22:09:29.276 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    942 2005-08-31 22:09:29.283 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    943 2005-08-31 22:09:29.292 read  <- 18 6       128000
    944 2005-08-31 22:09:29.292 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    945 2005-08-31 22:09:29.299 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    946 2005-08-31 22:09:29.308 read  <- 18 6       128000
    947 2005-08-31 22:09:29.308 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    948 2005-08-31 22:09:29.315 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    949 2005-08-31 22:09:29.324 read  <- 18 6       128000
    950 2005-08-31 22:09:29.324 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    951 2005-08-31 22:09:29.331 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    952 2005-08-31 22:09:29.340 read  <- 18 6       128000
    953 2005-08-31 22:09:29.340 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    954 2005-08-31 22:09:29.347 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    955 2005-08-31 22:09:29.356 read  <- 18 6       128000
    956 2005-08-31 22:09:29.356 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    957 2005-08-31 22:09:29.364 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    958 2005-08-31 22:09:29.372 read  <- 18 6       128000
    959 2005-08-31 22:09:29.372 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    960 2005-08-31 22:09:29.380 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    961 2005-08-31 22:09:29.388 read  <- 18 6       128000
    962 2005-08-31 22:09:29.388 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    963 2005-08-31 22:09:29.396 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    964 2005-08-31 22:09:29.404 read  <- 18 6       128000
    965 2005-08-31 22:09:29.405 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    966 2005-08-31 22:09:29.412 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    967 2005-08-31 22:09:29.421 read  <- 18 6       128000
    968 2005-08-31 22:09:29.421 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    969 2005-08-31 22:09:29.428 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    970 2005-08-31 22:09:29.437 read  <- 18 6       128000
    971 2005-08-31 22:09:29.437 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    972 2005-08-31 22:09:29.444 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    973 2005-08-31 22:09:29.453 read  <- 18 6       128000
    974 2005-08-31 22:09:29.453 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    975 2005-08-31 22:09:29.460 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    976 2005-08-31 22:09:29.469 read  <- 18 6       128000
    977 2005-08-31 22:09:29.469 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    978 2005-08-31 22:09:29.477 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    979 2005-08-31 22:09:29.485 read  <- 18 6       128000
    980 2005-08-31 22:09:29.485 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    981 2005-08-31 22:09:29.493 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    982 2005-08-31 22:09:29.501 read  <- 18 6       128000
    983 2005-08-31 22:09:29.501 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    984 2005-08-31 22:09:29.508 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    985 2005-08-31 22:09:29.517 read  <- 18 6       128000
    986 2005-08-31 22:09:29.517 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    987 2005-08-31 22:09:29.524 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    988 2005-08-31 22:09:29.533 read  <- 18 6       128000
    989 2005-08-31 22:09:29.533 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    990 2005-08-31 22:09:29.540 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    991 2005-08-31 22:09:29.549 read  <- 18 6       128000
    992 2005-08-31 22:09:29.549 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    993 2005-08-31 22:09:29.557 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    994 2005-08-31 22:09:29.565 read  <- 18 6       128000
    995 2005-08-31 22:09:29.565 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    996 2005-08-31 22:09:29.573 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    997 2005-08-31 22:09:29.581 read  <- 18 6       128000
    998 2005-08-31 22:09:29.582 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    999 2005-08-31 22:09:29.589 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1000 2005-08-31 22:09:29.597 read  <- 18 6       128000
    1001 2005-08-31 22:09:29.597 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1002 2005-08-31 22:09:29.605 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1003 2005-08-31 22:09:29.614 read  <- 18 6       128000
    1004 2005-08-31 22:09:29.614 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1005 2005-08-31 22:09:29.625 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1006 2005-08-31 22:09:29.634 read  <- 18 6       128000
    1007 2005-08-31 22:09:29.634 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1008 2005-08-31 22:09:29.641 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1009 2005-08-31 22:09:29.650 read  <- 18 6       128000
    1010 2005-08-31 22:09:29.650 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1011 2005-08-31 22:09:29.657 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1012 2005-08-31 22:09:29.666 read  <- 18 6       128000
    1013 2005-08-31 22:09:29.666 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1014 2005-08-31 22:09:29.677 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1015 2005-08-31 22:09:29.690 read  <- 18 6       128000
    1016 2005-08-31 22:09:29.690 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1017 2005-08-31 22:09:29.701 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1018 2005-08-31 22:09:29.710 read  <- 18 6       128000
    1019 2005-08-31 22:09:29.710 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1020 2005-08-31 22:09:29.721 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1021 2005-08-31 22:09:29.742 read  <- 18 6       128000
    1022 2005-08-31 22:09:29.742 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1023 2005-08-31 22:09:29.754 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1024 2005-08-31 22:09:29.766 read  <- 18 6       128000
    1025 2005-08-31 22:09:29.767 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1026 2005-08-31 22:09:29.778 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1027 2005-08-31 22:09:29.790 read  <- 18 6       128000
    1028 2005-08-31 22:09:29.791 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1029 2005-08-31 22:09:29.802 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1030 2005-08-31 22:09:29.814 read  <- 18 6       128000
    1031 2005-08-31 22:09:29.814 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1032 2005-08-31 22:09:29.826 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1033 2005-08-31 22:09:29.838 read  <- 18 6       128000
    1034 2005-08-31 22:09:29.839 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1035 2005-08-31 22:09:29.846 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1036 2005-08-31 22:09:29.855 read  <- 18 6       128000
    1037 2005-08-31 22:09:29.855 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1038 2005-08-31 22:09:29.862 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1039 2005-08-31 22:09:29.871 read  <- 18 6       128000
    1040 2005-08-31 22:09:29.871 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1041 2005-08-31 22:09:29.878 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1042 2005-08-31 22:09:29.887 read  <- 18 6       128000
    1043 2005-08-31 22:09:29.887 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1044 2005-08-31 22:09:29.894 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1045 2005-08-31 22:09:29.903 read  <- 18 6       128000
    1046 2005-08-31 22:09:29.903 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1047 2005-08-31 22:09:29.910 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1048 2005-08-31 22:09:29.919 read  <- 18 6       128000
    1049 2005-08-31 22:09:29.919 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1050 2005-08-31 22:09:29.926 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1051 2005-08-31 22:09:29.935 read  <- 18 6       128000
    1052 2005-08-31 22:09:29.935 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1053 2005-08-31 22:09:29.943 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1054 2005-08-31 22:09:29.951 read  <- 18 6       128000
    1055 2005-08-31 22:09:29.951 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1056 2005-08-31 22:09:29.959 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1057 2005-08-31 22:09:29.967 read  <- 18 6       128000
    1058 2005-08-31 22:09:29.967 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1059 2005-08-31 22:09:29.975 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1060 2005-08-31 22:09:30.064 read  <- 18 6       128000
    1061 2005-08-31 22:09:30.064 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1062 2005-08-31 22:09:30.071 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1063 2005-08-31 22:09:30.116 read  <- 18 6       128000
    1064 2005-08-31 22:09:30.117 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1065 2005-08-31 22:09:30.124 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1066 2005-08-31 22:09:30.132 read  <- 18 6       128000
    1067 2005-08-31 22:09:30.132 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1068 2005-08-31 22:09:30.140 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1069 2005-08-31 22:09:30.213 read  <- 18 6       128000
    1070 2005-08-31 22:09:30.213 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1071 2005-08-31 22:09:30.220 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1072 2005-08-31 22:09:30.309 read  <- 18 6       128000
    1073 2005-08-31 22:09:30.309 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1074 2005-08-31 22:09:30.316 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1075 2005-08-31 22:09:30.369 read  <- 18 6       128000
    1076 2005-08-31 22:09:30.370 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1077 2005-08-31 22:09:30.377 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1078 2005-08-31 22:09:30.466 read  <- 18 6       128000
    1079 2005-08-31 22:09:30.466 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1080 2005-08-31 22:09:30.467 write -> 18 75      QUERY_RECORDER 1[]:[]SEEK_RINGBUF[]:[]0[]:[]7569408[]:[]0[]:[]0[]...
    1081 2005-08-31 22:09:30.485 read  <- 18 13      0[]:[]7569408
    1082 0: start_time: -9223372036854.775 duration: -9223372036854.775
    1083 stream: start_time: -9223372036854.775 duration: -9223372036854.775 bitrate=1152 kb/s
    1084 2005-08-31 22:09:30.486 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1085 2005-08-31 22:09:30.486 AVFD: Stream #0, has id 0x33 codec id MPEG1VIDEO, type Video at 0x0x82a95a0
    1086 2005-08-31 22:09:30.487 XvMC version: 1.0
    1087 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)
    1088 2005-08-31 22:09:30.488 Trying XvMC port 270
    1089 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)
    1090 2005-08-31 22:09:30.489 Trying XvMC port 271
    1091 2005-08-31 22:09:30.490 Trying XvMC port 272
    1092 2005-08-31 22:09:30.490 Trying XvMC port 273
    1093 2005-08-31 22:09:30.490 Trying XvMC port 274
    1094 2005-08-31 22:09:30.490 Trying XvMC port 275
    1095 2005-08-31 22:09:30.490 Trying XvMC port 276
    1096 2005-08-31 22:09:30.490 Trying XvMC port 277
    1097 2005-08-31 22:09:30.490 Trying XvMC port 278
    1098 2005-08-31 22:09:30.490 Trying XvMC port 279
    1099 2005-08-31 22:09:30.490 Trying XvMC port 280
    1100 2005-08-31 22:09:30.491 Trying XvMC port 281
    1101 2005-08-31 22:09:30.491 Trying XvMC port 282
    1102 2005-08-31 22:09:30.491 Trying XvMC port 283
    1103 2005-08-31 22:09:30.491 Trying XvMC port 284
    1104 2005-08-31 22:09:30.491 Trying XvMC port 285
    1105 2005-08-31 22:09:30.491 Trying XvMC port 286
    1106 2005-08-31 22:09:30.491 Trying XvMC port 287
    1107 2005-08-31 22:09:30.491 Trying XvMC port 288
    1108 2005-08-31 22:09:30.491 Trying XvMC port 289
    1109 2005-08-31 22:09:30.491 Trying XvMC port 290
    1110 2005-08-31 22:09:30.492 Trying XvMC port 291
    1111 2005-08-31 22:09:30.492 Trying XvMC port 292
    1112 2005-08-31 22:09:30.492 Trying XvMC port 293
    1113 2005-08-31 22:09:30.492 Trying XvMC port 294
    1114 2005-08-31 22:09:30.492 Trying XvMC port 295
    1115 2005-08-31 22:09:30.492 Trying XvMC port 296
    1116 2005-08-31 22:09:30.492 Trying XvMC port 297
    1117 2005-08-31 22:09:30.492 Trying XvMC port 298
    1118 2005-08-31 22:09:30.492 Trying XvMC port 299
    1119 2005-08-31 22:09:30.493 Trying XvMC port 300
    1120 2005-08-31 22:09:30.493 Trying XvMC port 301
    1121 2005-08-31 22:09:30.493 Trying XvMC port 302
    1122 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)
    1123 2005-08-31 22:09:30.493 Trying XvMC port 270
    1124 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)
    1125 2005-08-31 22:09:30.493 Trying XvMC port 271
    1126 2005-08-31 22:09:30.493 Trying XvMC port 272
    1127 2005-08-31 22:09:30.494 Trying XvMC port 273
    1128 2005-08-31 22:09:30.494 Trying XvMC port 274
    1129 2005-08-31 22:09:30.494 Trying XvMC port 275
    1130 2005-08-31 22:09:30.494 Trying XvMC port 276
    1131 2005-08-31 22:09:30.494 Trying XvMC port 277
    1132 2005-08-31 22:09:30.494 Trying XvMC port 278
    1133 2005-08-31 22:09:30.494 Trying XvMC port 279
    1134 2005-08-31 22:09:30.494 Trying XvMC port 280
    1135 2005-08-31 22:09:30.494 Trying XvMC port 281
    1136 2005-08-31 22:09:30.495 Trying XvMC port 282
    1137 2005-08-31 22:09:30.495 Trying XvMC port 283
    1138 2005-08-31 22:09:30.495 Trying XvMC port 284
    1139 2005-08-31 22:09:30.495 Trying XvMC port 285
    1140 2005-08-31 22:09:30.495 Trying XvMC port 286
    1141 2005-08-31 22:09:30.495 Trying XvMC port 287
    1142 2005-08-31 22:09:30.495 Trying XvMC port 288
    1143 2005-08-31 22:09:30.495 Trying XvMC port 289
    1144 2005-08-31 22:09:30.495 Trying XvMC port 290
    1145 2005-08-31 22:09:30.495 Trying XvMC port 291
    1146 2005-08-31 22:09:30.496 Trying XvMC port 292
    1147 2005-08-31 22:09:30.496 Trying XvMC port 293
    1148 2005-08-31 22:09:30.496 Trying XvMC port 294
    1149 2005-08-31 22:09:30.496 Trying XvMC port 295
    1150 2005-08-31 22:09:30.496 Trying XvMC port 296
    1151 2005-08-31 22:09:30.496 Trying XvMC port 297
    1152 2005-08-31 22:09:30.496 Trying XvMC port 298
    1153 2005-08-31 22:09:30.496 Trying XvMC port 299
    1154 2005-08-31 22:09:30.496 Trying XvMC port 300
    1155 2005-08-31 22:09:30.497 Trying XvMC port 301
    1156 2005-08-31 22:09:30.497 Trying XvMC port 302
    1157 2005-08-31 22:09:30.498 read  <- 18 6       128000
    1158 2005-08-31 22:09:30.498 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1159 2005-08-31 22:09:30.498 detectInterlace(Detect Scan, Detect Scan, 50, 576) ->Progressive Scan
    1160 2005-08-31 22:09:30.499 Interlaced: Progressive Scan  video_height: 576  fps: 50
    1161 2005-08-31 22:09:30.499 AVFD: Looking for decoder for MPEG1VIDEO
    1162 2005-08-31 22:09:30.499 AVFD: Opened codec 0x82a2860, id(MPEG1VIDEO) type(Video)
    1163 2005-08-31 22:09:30.500 Estimated bitrate = 1152
    1164 2005-08-31 22:09:30.500 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
    1165 2005-08-31 22:09:30.500 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    1166 2005-08-31 22:09:30.509 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1167 2005-08-31 22:09:30.518 read  <- 17 7       0[]:[]0
    1168 2005-08-31 22:09:30.518 PosMapFromEnc: Warning, tried to fetch PositionMap from Encoder but encoder returned framesWritten == 0
    1169 2005-08-31 22:09:30.518 SyncPositionMap liveTV, from Encoder: 0 entries
    1170 2005-08-31 22:09:30.518 recording has no position -- using libavformat
    1171 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)
    1172 2005-08-31 22:09:30.521 VideoOutputXv()
    1173 2005-08-31 22:09:30.527 Over/underscan. V: 0, H: 0, XOff: 0, YOff: 0
    1174 2005-08-31 22:09:30.533 @ j=3 Looking for flag[s]: XvInputMask XvImageMask
    1175 2005-08-31 22:09:30.533 Adaptor: 0 has flag[s]: XvInputMask XvImageMask
    1176 2005-08-31 22:09:30.533 XVideo surface found on port 270
    1177 2005-08-31 22:09:30.567 read  <- 18 6       128000
    1178 2005-08-31 22:09:30.567 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1179 2005-08-31 22:09:30.569 Couldn't get the color key color, and we need it.
    1180 You likely won't get any video.
    1181 2005-08-31 22:09:30.569 Image size. dispxoff 0, dispyoff: 38, dispwoff: 666, disphoff: 456
    1182 2005-08-31 22:09:30.569 Image size. imgx 0, imgy: 0, imgw: 768, imgh: 576
    1183 2005-08-31 22:09:30.578 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1184 2005-08-31 22:09:30.591 read  <- 18 6       128000
    1185 2005-08-31 22:09:30.591 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1186 2005-08-31 22:09:30.602 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1187 2005-08-31 22:09:30.719 read  <- 18 6       128000
    1188 2005-08-31 22:09:30.719 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1189 2005-08-31 22:09:30.730 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1190 2005-08-31 22:09:30.738 read  <- 18 6       128000
    1191 2005-08-31 22:09:30.738 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1192 2005-08-31 22:09:30.750 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1193 2005-08-31 22:09:30.791 read  <- 18 6       128000
    1194 2005-08-31 22:09:30.791 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1195 2005-08-31 22:09:30.802 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1196 2005-08-31 22:09:30.932 InputChanged()
    1197 2005-08-31 22:09:30.932 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
    1198 2005-08-31 22:09:30.933 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
    1199 2005-08-31 22:09:30.934 Changing from None to WatchingLiveTV
    1200 2005-08-31 22:09:30.935 write -> 17 35      QUERY_RECORDER 1[]:[]GET_INPUT_NAME
    1201 2005-08-31 22:09:30.944 Using realtime priority.
    1202 2005-08-31 22:09:30.954 read  <- 17 8       DVBInput
    1203 2005-08-31 22:09:31.045 nVidiaVideoSync: VBlank ioctl did not work, unimplemented in this driver?
    1204 2005-08-31 22:09:31.046 DRMVideoSync: Could not open device /dev/dri/card0, No such file or directory
    1205 2005-08-31 22:09:31.047 Using audio as timebase
    1206 2005-08-31 22:09:31.047 Video timing method: RTC
    1207 2005-08-31 22:09:31.047 Refresh rate: 20000, frame interval: 20000
    1208 2005-08-31 22:09:31.047 waiting for prebuffer... 0
    1209 2005-08-31 22:09:31.133 waiting for prebuffer... 1
    1210 2005-08-31 22:09:31.187 read  <- 18 6       128000
    1211 2005-08-31 22:09:31.187 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1212 2005-08-31 22:09:31.198 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1213 2005-08-31 22:09:31.217 waiting for prebuffer... 2
    1214 2005-08-31 22:09:31.284 write -> 17 35      QUERY_RECORDER 1[]:[]FRONTEND_READY
    1215 2005-08-31 22:09:31.284 detectInterlace(Detect Scan, Progressive Scan, 50, 576) ->Progressive Scan
    1216 2005-08-31 22:09:31.284 Interlaced: Progressive Scan  video_height: 576  fps: 50
    1217 2005-08-31 22:09:31.284 positionMap[ 0 ] == 74824.
    1218 2005-08-31 22:09:31.297 positionMap[ 0 ] == 897888.
    1219 2005-08-31 22:09:31.302 read  <- 17 2       ok
    1220 2005-08-31 22:09:31.307 write -> 17 37      QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO
    1221 2005-08-31 22:09:31.313 HandleGopStart: gopset not set, syncing positionMap
    1222 2005-08-31 22:09:31.314 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
    1223 2005-08-31 22:09:31.326 read  <- 17 103      []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10...
    1224 2005-08-31 22:09:31.326 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    1225 2005-08-31 22:09:31.346 read  <- 17 7       0[]:[]1
    1226 2005-08-31 22:09:31.346 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    1227 2005-08-31 22:09:31.346 Filling position map from 1 to 0
    1228 2005-08-31 22:09:31.366 read  <- 17 7       0[]:[]1
    1229 2005-08-31 22:09:31.366 write -> 14 19      QUERY_GETALLPENDING
    1230 2005-08-31 22:09:31.367 write -> 17 50      QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]1[]:[]0
    1231 2005-08-31 22:09:31.388 read  <- 14 7       0[]:[]0
    1232 2005-08-31 22:09:31.389 read  <- 17 2       ok
    1233 2005-08-31 22:09:31.389 Position map filled from Encoder to: 0
    1234 2005-08-31 22:09:31.390 SyncPositionMap liveTV, from Encoder: 2 entries
    1235 2005-08-31 22:09:31.390 Stream initial keyframedist: 11.
    1236 2005-08-31 22:09:31.391 positionMap[ 2 ] == 1720952.
    1237 2005-08-31 22:09:31.415 positionMap[ 3 ] == 2544016.
    1238 2005-08-31 22:09:31.419 write -> 17 37      QUERY_RECORDER 1[]:[]GET_PROGRAM_INFO
    1239 2005-08-31 22:09:31.434 read  <- 17 103      []:[] []:[] []:[] []:[] []:[] []:[]Nelonen[]:[]none[]:[]4[]:[]10...
    1240 2005-08-31 22:09:31.435 write -> 17 53      QUERY_RECORDER 1[]:[]GET_FREE_SPACE[]:[]0[]:[]7569408
    1241 2005-08-31 22:09:31.451 read  <- 17 16      2[]:[]2083570396
    1242 2005-08-31 22:09:31.451 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    1243 2005-08-31 22:09:31.467 read  <- 17 7       0[]:[]3
    1244 2005-08-31 22:09:31.530 read  <- 18 6       128000
    1245 2005-08-31 22:09:31.530 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1246 2005-08-31 22:09:31.540 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1247 2005-08-31 22:09:31.569 positionMap[ 4 ] == 3367080.
    1248 2005-08-31 22:09:31.789 positionMap[ 5 ] == 4190144.
    1249 2005-08-31 22:09:31.870 read  <- 18 6       128000
    1250 2005-08-31 22:09:31.871 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1251 2005-08-31 22:09:31.879 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1252 2005-08-31 22:09:32.009 positionMap[ 6 ] == 5013208.
    1253 2005-08-31 22:09:32.190 read  <- 18 6       128000
    1254 2005-08-31 22:09:32.190 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1255 2005-08-31 22:09:32.201 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1256 2005-08-31 22:09:32.229 positionMap[ 7 ] == 5836272.
    1257 2005-08-31 22:09:32.449 positionMap[ 8 ] == 6659336.
    1258 2005-08-31 22:09:32.534 read  <- 18 6       128000
    1259 2005-08-31 22:09:32.534 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1260 2005-08-31 22:09:32.549 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1261 2005-08-31 22:09:32.669 positionMap[ 9 ] == 7482400.
    1262 2005-08-31 22:09:32.736 read  <- 18 6       128000
    1263 2005-08-31 22:09:32.737 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1264 2005-08-31 22:09:32.744 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1265 2005-08-31 22:09:32.889 positionMap[ 10 ] == 8305464.
    1266 2005-08-31 22:09:32.909 streams_changed 0x825db90 -- stream count 2
    1267 2005-08-31 22:09:32.909 AvFormatDecoder::SeekReset(0, don't flush)
    1268 2005-08-31 22:09:32.909 AVFD: Stream #0, has id 0x215 codec id MPEG2VIDEO, type Video at 0x0x8494cc0
    1269 2005-08-31 22:09:32.911 XvMC version: 1.0
    1270 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)
    1271 2005-08-31 22:09:32.911 Trying XvMC port 270
    1272 2005-08-31 22:09:32.911 Found a suitable XvMC surface 0
    1273 2005-08-31 22:09:32.911 @ j=1 Looking for flag[s]: XvInputMask
    1274 2005-08-31 22:09:32.912 Adaptor: 0 has flag[s]: XvInputMask XvImageMask
    1275 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)
    1276 2005-08-31 22:09:32.912 Trying XvMC port 270
    1277 2005-08-31 22:09:32.912 Found a suitable XvMC surface 0
    1278 2005-08-31 22:09:32.912 Adaptor: 1 has flag[s]: XvInputMask XvImageMask
    1279 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)
    1280 2005-08-31 22:09:32.912 Trying XvMC port 271
    1281 2005-08-31 22:09:32.912 Trying XvMC port 272
    1282 2005-08-31 22:09:32.913 Trying XvMC port 273
    1283 2005-08-31 22:09:32.913 Trying XvMC port 274
    1284 2005-08-31 22:09:32.913 Trying XvMC port 275
    1285 2005-08-31 22:09:32.913 Trying XvMC port 276
    1286 2005-08-31 22:09:32.913 Trying XvMC port 277
    1287 2005-08-31 22:09:32.913 Trying XvMC port 278
    1288 2005-08-31 22:09:32.913 Trying XvMC port 279
    1289 2005-08-31 22:09:32.913 Trying XvMC port 280
    1290 2005-08-31 22:09:32.913 Trying XvMC port 281
    1291 2005-08-31 22:09:32.914 Trying XvMC port 282
    1292 2005-08-31 22:09:32.914 Trying XvMC port 283
    1293 2005-08-31 22:09:32.914 Trying XvMC port 284
    1294 2005-08-31 22:09:32.914 Trying XvMC port 285
    1295 2005-08-31 22:09:32.914 Trying XvMC port 286
    1296 2005-08-31 22:09:32.914 Trying XvMC port 287
    1297 2005-08-31 22:09:32.914 Trying XvMC port 288
    1298 2005-08-31 22:09:32.914 Trying XvMC port 289
    1299 2005-08-31 22:09:32.914 Trying XvMC port 290
    1300 2005-08-31 22:09:32.915 Trying XvMC port 291
    1301 2005-08-31 22:09:32.915 Trying XvMC port 292
    1302 2005-08-31 22:09:32.915 Trying XvMC port 293
    1303 2005-08-31 22:09:32.915 Trying XvMC port 294
    1304 2005-08-31 22:09:32.915 Trying XvMC port 295
    1305 2005-08-31 22:09:32.915 Trying XvMC port 296
    1306 2005-08-31 22:09:32.915 Trying XvMC port 297
    1307 2005-08-31 22:09:32.915 Trying XvMC port 298
    1308 2005-08-31 22:09:32.916 Trying XvMC port 299
    1309 2005-08-31 22:09:32.916 Trying XvMC port 300
    1310 2005-08-31 22:09:32.916 Trying XvMC port 301
    1311 2005-08-31 22:09:32.916 Trying XvMC port 302
    1312 2005-08-31 22:09:32.916 No suitible XVideo port found
    1313 2005-08-31 22:09:32.916 Could not open XvMC port...
    1314 
    1315                         You may wish to verify that your DISPLAY
    1316                         environment variable does not use an external
    1317                         network connection.
    1318 
    1319                         You may also wish to verify that
    1320                         /etc/X11/XvMCConfig contains the correct
    1321                         vendor's XvMC library.
    1322 
    1323 2005-08-31 22:09:32.917 detectInterlace(Detect Scan, Progressive Scan, 29.97, 480) ->Interlaced Scan
    1324 2005-08-31 22:09:32.917 Interlaced: Interlaced Scan  video_height: 480  fps: 29.97
    1325 2005-08-31 22:09:32.919 Using deinterlace method bobdeint
    1326 2005-08-31 22:09:32.919 Set video sync frame interval to 33366
    1327 2005-08-31 22:09:32.919 Video sync method can't support double framerate (refresh rate too low for bob deint)
    1328 2005-08-31 22:09:32.920 AVFD: Looking for decoder for MPEG2VIDEO
    1329 2005-08-31 22:09:32.920 AVFD: Opened codec 0x839aba0, id(MPEG2VIDEO) type(Video)
    1330 2005-08-31 22:09:32.921 AVFD: Stream #1, has id 0x888 codec id MP3, type Audio at 0x0x84f9b20
    1331 2005-08-31 22:09:32.921 AVFD: Looking for decoder for MP3
    1332 2005-08-31 22:09:32.940 AVFD: Opened codec 0x84682f0, id(MP3) type(Audio)
    1333 2005-08-31 22:09:32.940 AVFD: Stream #1 (audio track #0) is an audio stream with 0 channels.
    1334 2005-08-31 22:09:32.942 AvFormatDecoder: Video has changed from 0x0 to 704x576.
    1335 2005-08-31 22:09:32.943 InputChanged()
    1336 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): UUUUUUUUUUUUUUUUULAAUUUUUUUUUUU
    1337 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
    1338 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
    1339 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
    1340 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
    1341 2005-08-31 22:09:32.943 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
    1342 2005-08-31 22:09:32.954 prebuffering pause
    1343 2005-08-31 22:09:32.955 waiting for prebuffer... 0
    1344 2005-08-31 22:09:32.959 read  <- 18 6       128000
    1345 2005-08-31 22:09:32.959 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1346 2005-08-31 22:09:32.970 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1347 2005-08-31 22:09:32.986 Image size. dispxoff 0, dispyoff: 0, dispwoff: 666, disphoff: 533
    1348 2005-08-31 22:09:32.986 Image size. imgx 0, imgy: 0, imgw: 704, imgh: 576
    1349 2005-08-31 22:09:33.122 waiting for prebuffer... 1
    1350 2005-08-31 22:09:33.255 read  <- 18 6       128000
    1351 2005-08-31 22:09:33.255 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1352 2005-08-31 22:09:33.266 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1353 2005-08-31 22:09:33.290 waiting for prebuffer... 2
    1354 2005-08-31 22:09:33.312 detectInterlace(Detect Scan, Ignore Scan, 25, 576) ->Interlaced Scan
    1355 2005-08-31 22:09:33.312 Interlaced: Interlaced Scan  video_height: 576  fps: 25
    1356 2005-08-31 22:09:33.314 Using deinterlace method bobdeint
    1357 2005-08-31 22:09:33.314 Set video sync frame interval to 40000
    1358 2005-08-31 22:09:33.314 positionMap[ 11 ] == 8511324.
    1359 2005-08-31 22:09:33.321 Auto-selecting audio track #1 (stream #1).
    1360 2005-08-31 22:09:33.321 It has 2 channels and we needed at least 1
    1361 2005-08-31 22:09:33.321 Initializing audio parms from audio track #0.
    1362 2005-08-31 22:09:33.322 Killing AudioOutputDSP
    1363 2005-08-31 22:09:33.323 Opening audio device 'spdif'.
    1364 2005-08-31 22:09:33.330 in SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=125000)
    1365 2005-08-31 22:09:33.331 get_buffer_size returned 16384
    1366 2005-08-31 22:09:33.331 set_period_time_near returned 85333
    1367 2005-08-31 22:09:33.331 get_period_size returned 4096
    1368 2005-08-31 22:09:33.331 Audio fragment size: 4096
    1369 2005-08-31 22:09:33.332 Audio Stretch Factor: 1
    1370 2005-08-31 22:09:33.332 Ending reconfigure
    1371 2005-08-31 22:09:33.332 kickoffOutputAudioLoop: pid = 11695
    1372 2005-08-31 22:09:33.333 OutputAudioLoop: Play Event
    1373 2005-08-31 22:09:33.333 Broadcasting free space avail
    1374 2005-08-31 22:09:33.336 _AddSamples bytes=4608, used=1, free=767999, timecode=13678718
    1375 2005-08-31 22:09:33.337 _AddSamples bytes=4608, used=4609, free=763391, timecode=13678742
    1376 2005-08-31 22:09:33.337 _AddSamples bytes=4608, used=9217, free=758783, timecode=13678766
    1377 2005-08-31 22:09:33.341 _AddSamples bytes=4608, used=13825, free=754175, timecode=13678790
    1378 2005-08-31 22:09:33.341 _AddSamples bytes=4608, used=18433, free=749567, timecode=13678814
    1379 2005-08-31 22:09:33.342 _AddSamples bytes=4608, used=23041, free=744959, timecode=13678838
    1380 2005-08-31 22:09:33.342 _AddSamples bytes=4608, used=27649, free=740351, timecode=13678862
    1381 2005-08-31 22:09:33.342 Broadcasting free space avail
    1382 2005-08-31 22:09:33.342 WriteAudio: Preparing 4096 bytes (1024 frames)
    1383 2005-08-31 22:09:33.343 Broadcasting free space avail
    1384 2005-08-31 22:09:33.343 WriteAudio: Preparing 4096 bytes (1024 frames)
    1385 2005-08-31 22:09:33.343 _AddSamples bytes=4608, used=24065, free=743935, timecode=13678886
    1386 2005-08-31 22:09:33.343 Broadcasting free space avail
    1387 2005-08-31 22:09:33.343 WriteAudio: Preparing 4096 bytes (1024 frames)
    1388 2005-08-31 22:09:33.343 Broadcasting free space avail
    1389 2005-08-31 22:09:33.343 WriteAudio: Preparing 4096 bytes (1024 frames)
    1390 2005-08-31 22:09:33.343 Broadcasting free space avail
    1391 2005-08-31 22:09:33.344 WriteAudio: Preparing 4096 bytes (1024 frames)
    1392 2005-08-31 22:09:33.344 _AddSamples bytes=4608, used=16385, free=751615, timecode=13678910
    1393 2005-08-31 22:09:33.344 Broadcasting free space avail
    1394 2005-08-31 22:09:33.344 WriteAudio: Preparing 4096 bytes (1024 frames)
    1395 2005-08-31 22:09:33.344 Broadcasting free space avail
    1396 2005-08-31 22:09:33.344 WriteAudio: Preparing 4096 bytes (1024 frames)
    1397 2005-08-31 22:09:33.344 _AddSamples bytes=4608, used=12801, free=755199, timecode=13678934
    1398 2005-08-31 22:09:33.344 Broadcasting free space avail
    1399 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames)
    1400 2005-08-31 22:09:33.345 Broadcasting free space avail
    1401 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames)
    1402 2005-08-31 22:09:33.345 Broadcasting free space avail
    1403 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames)
    1404 2005-08-31 22:09:33.345 _AddSamples bytes=4608, used=5121, free=762879, timecode=13678958
    1405 2005-08-31 22:09:33.345 Broadcasting free space avail
    1406 2005-08-31 22:09:33.345 WriteAudio: Preparing 4096 bytes (1024 frames)
    1407 2005-08-31 22:09:33.346 Broadcasting free space avail
    1408 2005-08-31 22:09:33.346 WriteAudio: Preparing 4096 bytes (1024 frames)
    1409 2005-08-31 22:09:33.346 _AddSamples bytes=4608, used=1537, free=766463, timecode=13678982
    1410 2005-08-31 22:09:33.346 Broadcasting free space avail
    1411 2005-08-31 22:09:33.346 WriteAudio: Preparing 4096 bytes (1024 frames)
    1412 2005-08-31 22:09:33.346 _AddSamples bytes=4608, used=2049, free=765951, timecode=13679006
    1413 2005-08-31 22:09:33.347 Broadcasting free space avail
    1414 2005-08-31 22:09:33.347 WriteAudio: Preparing 4096 bytes (1024 frames)
    1415 2005-08-31 22:09:33.347 audio waiting for buffer to fill: have 2560 want 4096
    1416 2005-08-31 22:09:33.347 Broadcasting free space avail
    1417 2005-08-31 22:09:33.347 _AddSamples bytes=4608, used=2561, free=765439, timecode=13679030
    1418 2005-08-31 22:09:33.348 _AddSamples bytes=4608, used=7169, free=760831, timecode=13679054
    1419 2005-08-31 22:09:33.348 _AddSamples bytes=4608, used=11777, free=756223, timecode=13679078
    1420 2005-08-31 22:09:33.348 _AddSamples bytes=4608, used=16385, free=751615, timecode=13679102
    1421 2005-08-31 22:09:33.349 _AddSamples bytes=4608, used=20993, free=747007, timecode=13679126
    1422 2005-08-31 22:09:33.349 _AddSamples bytes=4608, used=25601, free=742399, timecode=13679150
    1423 2005-08-31 22:09:33.350 _AddSamples bytes=4608, used=30209, free=737791, timecode=13679174
    1424 2005-08-31 22:09:33.350 _AddSamples bytes=4608, used=34817, free=733183, timecode=13679198
    1425 2005-08-31 22:09:33.351 _AddSamples bytes=4608, used=39425, free=728575, timecode=13679222
    1426 2005-08-31 22:09:33.351 _AddSamples bytes=4608, used=44033, free=723967, timecode=13679246
    1427 2005-08-31 22:09:33.352 _AddSamples bytes=4608, used=48641, free=719359, timecode=13679270
    1428 2005-08-31 22:09:33.352 _AddSamples bytes=4608, used=53249, free=714751, timecode=13679294
    1429 2005-08-31 22:09:33.353 _AddSamples bytes=4608, used=57857, free=710143, timecode=13679318
    1430 2005-08-31 22:09:33.353 _AddSamples bytes=4608, used=62465, free=705535, timecode=13679342
    1431 2005-08-31 22:09:33.356 _AddSamples bytes=4608, used=67073, free=700927, timecode=13679366
    1432 2005-08-31 22:09:33.357 _AddSamples bytes=4608, used=71681, free=696319, timecode=13679390
    1433 2005-08-31 22:09:33.358 Broadcasting free space avail
    1434 2005-08-31 22:09:33.358 WriteAudio: Preparing 4096 bytes (1024 frames)
    1435 2005-08-31 22:09:33.359 Broadcasting free space avail
    1436 2005-08-31 22:09:33.359 WriteAudio: Preparing 4096 bytes (1024 frames)
    1437 2005-08-31 22:09:33.359 audio waiting for space on soundcard: have 2972 need 4096
    1438 2005-08-31 22:09:33.361 _AddSamples bytes=4608, used=68097, free=699903, timecode=13679414
    1439 2005-08-31 22:09:33.361 _AddSamples bytes=4608, used=72705, free=695295, timecode=13679438
    1440 2005-08-31 22:09:33.365 _AddSamples bytes=4608, used=77313, free=690687, timecode=13679462
    1441 2005-08-31 22:09:33.368 _AddSamples bytes=4608, used=81921, free=686079, timecode=13679486
    1442 2005-08-31 22:09:33.368 _AddSamples bytes=4608, used=86529, free=681471, timecode=13679510
    1443 2005-08-31 22:09:33.372 _AddSamples bytes=4608, used=91137, free=676863, timecode=13679534
    1444 2005-08-31 22:09:33.372 _AddSamples bytes=4608, used=95745, free=672255, timecode=13679558
    1445 2005-08-31 22:09:33.374 Broadcasting free space avail
    1446 2005-08-31 22:09:33.374 WriteAudio: Preparing 4096 bytes (1024 frames)
    1447 2005-08-31 22:09:33.375 audio waiting for space on soundcard: have 1892 need 4096
    1448 2005-08-31 22:09:33.376 _AddSamples bytes=4608, used=96257, free=671743, timecode=13679582
    1449 2005-08-31 22:09:33.376 HandleGopStart: gopset not set, syncing positionMap
    1450 2005-08-31 22:09:33.376 Resyncing position map. posmapStarted = 0 livetv(1) watchingRec(0)
    1451 2005-08-31 22:09:33.376 write -> 17 39      QUERY_RECORDER 1[]:[]GET_FRAMES_WRITTEN
    1452 2005-08-31 22:09:33.386 Broadcasting free space avail
    1453 2005-08-31 22:09:33.386 WriteAudio: Preparing 4096 bytes (1024 frames)
    1454 2005-08-31 22:09:33.387 audio waiting for space on soundcard: have 108 need 4096
    1455 2005-08-31 22:09:33.394 read  <- 17 8       0[]:[]49
    1456 2005-08-31 22:09:33.395 Filling position map from 12 to 4
    1457 2005-08-31 22:09:33.395 write -> 17 51      QUERY_RECORDER 1[]:[]FILL_POSITION_MAP[]:[]12[]:[]4
    1458 2005-08-31 22:09:33.398 audio waiting for space on soundcard: have 2392 need 4096
    1459 2005-08-31 22:09:33.411 read  <- 17 2       ok
    1460 2005-08-31 22:09:33.411 Broadcasting free space avail
    1461 2005-08-31 22:09:33.411 Position map filled from Encoder to: 11
    1462 2005-08-31 22:09:33.411 WriteAudio: Preparing 4096 bytes (1024 frames)
    1463 2005-08-31 22:09:33.411 SyncPositionMap liveTV, from Encoder: 12 entries
    1464 2005-08-31 22:09:33.411 audio waiting for space on soundcard: have 736 need 4096
    1465 2005-08-31 22:09:33.411 Stream initial keyframedist: 12.
    1466 2005-08-31 22:09:33.411 positionMap[ 11 ] == 8684472.
    1467 2005-08-31 22:09:33.415 _AddSamples bytes=4608, used=92673, free=675327, timecode=13679606
    1468 2005-08-31 22:09:33.416 _AddSamples bytes=4608, used=97281, free=670719, timecode=13679630
    1469 2005-08-31 22:09:33.420 _AddSamples bytes=4608, used=101889, free=666111, timecode=13679654
    1470 2005-08-31 22:09:33.420 _AddSamples bytes=4608, used=106497, free=661503, timecode=13679678
    1471 2005-08-31 22:09:33.423 audio waiting for space on soundcard: have 3004 need 4096
    1472 2005-08-31 22:09:33.425 _AddSamples bytes=4608, used=111105, free=656895, timecode=13679702
    1473 2005-08-31 22:09:33.435 Broadcasting free space avail
    1474 2005-08-31 22:09:33.435 WriteAudio: Preparing 4096 bytes (1024 frames)
    1475 2005-08-31 22:09:33.435 _AddSamples bytes=4608, used=111617, free=656383, timecode=13679726
    1476 2005-08-31 22:09:33.435 audio waiting for space on soundcard: have 1256 need 4096
    1477 2005-08-31 22:09:33.436 _AddSamples bytes=4608, used=116225, free=651775, timecode=13679750
    1478 2005-08-31 22:09:33.440 _AddSamples bytes=4608, used=120833, free=647167, timecode=13679774
    1479 2005-08-31 22:09:33.440 _AddSamples bytes=4608, used=125441, free=642559, timecode=13679798
    1480 2005-08-31 22:09:33.444 _AddSamples bytes=4608, used=130049, free=637951, timecode=13679822
    1481 2005-08-31 22:09:33.447 audio waiting for space on soundcard: have 3596 need 4096
    1482 2005-08-31 22:09:33.450 _AddSamples bytes=4608, used=134657, free=633343, timecode=13679846
    1483 2005-08-31 22:09:33.451 _AddSamples bytes=4608, used=139265, free=628735, timecode=13679870
    1484 2005-08-31 22:09:33.455 _AddSamples bytes=4608, used=143873, free=624127, timecode=13679894
    1485 2005-08-31 22:09:33.456 _AddSamples bytes=4608, used=148481, free=619519, timecode=13679918
    1486 2005-08-31 22:09:33.459 Broadcasting free space avail
    1487 2005-08-31 22:09:33.459 WriteAudio: Preparing 4096 bytes (1024 frames)
    1488 2005-08-31 22:09:33.459 audio waiting for space on soundcard: have 1756 need 4096
    1489 2005-08-31 22:09:33.460 _AddSamples bytes=4608, used=148993, free=619007, timecode=13679942
    1490 2005-08-31 22:09:33.465 _AddSamples bytes=4608, used=153601, free=614399, timecode=13679966
    1491 2005-08-31 22:09:33.465 _AddSamples bytes=4608, used=158209, free=609791, timecode=13679990
    1492 2005-08-31 22:09:33.470 _AddSamples bytes=4608, used=162817, free=605183, timecode=13680014
    1493 2005-08-31 22:09:33.470 _AddSamples bytes=4608, used=167425, free=600575, timecode=13680038
    1494 2005-08-31 22:09:33.471 audio waiting for space on soundcard: have 4008 need 4096
    1495 2005-08-31 22:09:33.475 _AddSamples bytes=4608, used=172033, free=595967, timecode=13680062
    1496 2005-08-31 22:09:33.475 positionMap[ 12 ] == 9011592.
    1497 2005-08-31 22:09:33.479 _AddSamples bytes=4608, used=176641, free=591359, timecode=13680086
    1498 2005-08-31 22:09:33.479 _AddSamples bytes=4608, used=181249, free=586751, timecode=13680110
    1499 2005-08-31 22:09:33.483 _AddSamples bytes=4608, used=185857, free=582143, timecode=13680134
    1500 2005-08-31 22:09:33.483 Broadcasting free space avail
    1501 2005-08-31 22:09:33.483 WriteAudio: Preparing 4096 bytes (1024 frames)
    1502 2005-08-31 22:09:33.483 audio waiting for space on soundcard: have 2292 need 4096
    1503 2005-08-31 22:09:33.484 _AddSamples bytes=4608, used=186369, free=581631, timecode=13680158
    1504 2005-08-31 22:09:33.488 _AddSamples bytes=4608, used=190977, free=577023, timecode=13680182
    1505 2005-08-31 22:09:33.492 _AddSamples bytes=4608, used=195585, free=572415, timecode=13680206
    1506 2005-08-31 22:09:33.492 _AddSamples bytes=4608, used=200193, free=567807, timecode=13680230
    1507 2005-08-31 22:09:33.495 Broadcasting free space avail
    1508 2005-08-31 22:09:33.496 WriteAudio: Preparing 4096 bytes (1024 frames)
    1509 2005-08-31 22:09:33.496 audio waiting for space on soundcard: have 636 need 4096
    1510 2005-08-31 22:09:33.496 _AddSamples bytes=4608, used=200705, free=567295, timecode=13680254
    1511 2005-08-31 22:09:33.497 _AddSamples bytes=4608, used=205313, free=562687, timecode=13680278
    1512 2005-08-31 22:09:33.501 _AddSamples bytes=4608, used=209921, free=558079, timecode=13680302
    1513 2005-08-31 22:09:33.505 _AddSamples bytes=4608, used=214529, free=553471, timecode=13680326
    1514 2005-08-31 22:09:33.508 audio waiting for space on soundcard: have 2824 need 4096
    1515 2005-08-31 22:09:33.508 _AddSamples bytes=4608, used=219137, free=548863, timecode=13680350
    1516 2005-08-31 22:09:33.512 _AddSamples bytes=4608, used=223745, free=544255, timecode=13680374
    1517 2005-08-31 22:09:33.519 Broadcasting free space avail
    1518 2005-08-31 22:09:33.519 WriteAudio: Preparing 4096 bytes (1024 frames)
    1519 2005-08-31 22:09:33.519 audio waiting for space on soundcard: have 1016 need 4096
    1520 2005-08-31 22:09:33.531 audio waiting for space on soundcard: have 3308 need 4096
    1521 2005-08-31 22:09:33.544 Broadcasting free space avail
    1522 2005-08-31 22:09:33.544 WriteAudio: Preparing 4096 bytes (1024 frames)
    1523 2005-08-31 22:09:33.544 audio waiting for space on soundcard: have 1600 need 4096
    1524 2005-08-31 22:09:33.546 A/V diverged by 3.87188 frames, extending frame to keep audio in sync
    1525 2005-08-31 22:09:33.556 audio waiting for space on soundcard: have 3904 need 4096
    1526 2005-08-31 22:09:33.568 Broadcasting free space avail
    1527 2005-08-31 22:09:33.568 WriteAudio: Preparing 4096 bytes (1024 frames)
    1528 2005-08-31 22:09:33.568 audio waiting for space on soundcard: have 2208 need 4096
    1529 2005-08-31 22:09:33.580 Broadcasting free space avail
    1530 2005-08-31 22:09:33.580 WriteAudio: Preparing 4096 bytes (1024 frames)
    1531 2005-08-31 22:09:33.580 audio waiting for space on soundcard: have 456 need 4096
    1532 2005-08-31 22:09:33.592 audio waiting for space on soundcard: have 2768 need 4096
    1533 2005-08-31 22:09:33.605 Broadcasting free space avail
    1534 2005-08-31 22:09:33.605 WriteAudio: Preparing 4096 bytes (1024 frames)
    1535 2005-08-31 22:09:33.605 audio waiting for space on soundcard: have 1104 need 4096
    1536 2005-08-31 22:09:33.617 audio waiting for space on soundcard: have 3408 need 4096
    1537 2005-08-31 22:09:33.626 A/V diverged by 5.06015 frames, extending frame to keep audio in sync
    1538 2005-08-31 22:09:33.628 read  <- 18 6       128000
    1539 2005-08-31 22:09:33.628 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1540 2005-08-31 22:09:33.629 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1541 2005-08-31 22:09:33.629 _AddSamples bytes=4608, used=207873, free=560127, timecode=13680398
    1542 2005-08-31 22:09:33.629 Broadcasting free space avail
    1543 2005-08-31 22:09:33.630 WriteAudio: Preparing 4096 bytes (1024 frames)
    1544 2005-08-31 22:09:33.630 audio waiting for space on soundcard: have 1724 need 4096
    1545 2005-08-31 22:09:33.633 _AddSamples bytes=4608, used=208385, free=559615, timecode=13680422
    1546 2005-08-31 22:09:33.637 _AddSamples bytes=4608, used=212993, free=555007, timecode=13680446
    1547 2005-08-31 22:09:33.638 _AddSamples bytes=4608, used=217601, free=550399, timecode=13680470
    1548 2005-08-31 22:09:33.641 audio waiting for space on soundcard: have 3960 need 4096
    1549 2005-08-31 22:09:33.642 _AddSamples bytes=4608, used=222209, free=545791, timecode=13680494
    1550 2005-08-31 22:09:33.642 _AddSamples bytes=4608, used=226817, free=541183, timecode=13680518
    1551 2005-08-31 22:09:33.646 _AddSamples bytes=4608, used=231425, free=536575, timecode=13680542
    1552 2005-08-31 22:09:33.646 positionMap[ 13 ] == 9215384.
    1553 2005-08-31 22:09:33.650 _AddSamples bytes=4608, used=236033, free=531967, timecode=13680566
    1554 2005-08-31 22:09:33.650 _AddSamples bytes=4608, used=240641, free=527359, timecode=13680590
    1555 2005-08-31 22:09:33.653 Broadcasting free space avail
    1556 2005-08-31 22:09:33.653 WriteAudio: Preparing 4096 bytes (1024 frames)
    1557 2005-08-31 22:09:33.654 audio waiting for space on soundcard: have 2220 need 4096
    1558 2005-08-31 22:09:33.666 Broadcasting free space avail
    1559 2005-08-31 22:09:33.666 WriteAudio: Preparing 4096 bytes (1024 frames)
    1560 2005-08-31 22:09:33.666 audio waiting for space on soundcard: have 484 need 4096
    1561 2005-08-31 22:09:33.678 audio waiting for space on soundcard: have 2792 need 4096
    1562 2005-08-31 22:09:33.690 Broadcasting free space avail
    1563 2005-08-31 22:09:33.690 WriteAudio: Preparing 4096 bytes (1024 frames)
    1564 2005-08-31 22:09:33.690 audio waiting for space on soundcard: have 1108 need 4096
    1565 2005-08-31 22:09:33.703 audio waiting for space on soundcard: have 3420 need 4096
    1566 2005-08-31 22:09:33.706 A/V diverged by 5.70135 frames, extending frame to keep audio in sync
    1567 2005-08-31 22:09:33.711 _AddSamples bytes=4608, used=232961, free=535039, timecode=13680614
    1568 2005-08-31 22:09:33.712 _AddSamples bytes=4608, used=237569, free=530431, timecode=13680638
    1569 2005-08-31 22:09:33.715 Broadcasting free space avail
    1570 2005-08-31 22:09:33.715 WriteAudio: Preparing 4096 bytes (1024 frames)
    1571 2005-08-31 22:09:33.715 audio waiting for space on soundcard: have 1704 need 4096
    1572 2005-08-31 22:09:33.727 audio waiting for space on soundcard: have 4044 need 4096
    1573 2005-08-31 22:09:33.739 Broadcasting free space avail
    1574 2005-08-31 22:09:33.739 WriteAudio: Preparing 4096 bytes (1024 frames)
    1575 2005-08-31 22:09:33.740 audio waiting for space on soundcard: have 2332 need 4096
    1576 2005-08-31 22:09:33.751 Broadcasting free space avail
    1577 2005-08-31 22:09:33.752 WriteAudio: Preparing 4096 bytes (1024 frames)
    1578 2005-08-31 22:09:33.752 audio waiting for space on soundcard: have 572 need 4096
    1579 2005-08-31 22:09:33.764 audio waiting for space on soundcard: have 2916 need 4096
    1580 2005-08-31 22:09:33.776 Broadcasting free space avail
    1581 2005-08-31 22:09:33.776 WriteAudio: Preparing 4096 bytes (1024 frames)
    1582 2005-08-31 22:09:33.776 audio waiting for space on soundcard: have 1232 need 4096
    1583 2005-08-31 22:09:33.786 A/V diverged by 5.93225 frames, extending frame to keep audio in sync
    1584 2005-08-31 22:09:33.788 audio waiting for space on soundcard: have 3516 need 4096
    1585 2005-08-31 22:09:33.791 _AddSamples bytes=4608, used=225793, free=542207, timecode=13680662
    1586 2005-08-31 22:09:33.801 Broadcasting free space avail
    1587 2005-08-31 22:09:33.801 WriteAudio: Preparing 4096 bytes (1024 frames)
    1588 2005-08-31 22:09:33.801 audio waiting for space on soundcard: have 1812 need 4096
    1589 2005-08-31 22:09:33.813 Broadcasting free space avail
    1590 2005-08-31 22:09:33.813 WriteAudio: Preparing 4096 bytes (1024 frames)
    1591 2005-08-31 22:09:33.813 audio waiting for space on soundcard: have 60 need 4096
    1592 2005-08-31 22:09:33.825 audio waiting for space on soundcard: have 2384 need 4096
    1593 2005-08-31 22:09:33.837 Broadcasting free space avail
    1594 2005-08-31 22:09:33.837 WriteAudio: Preparing 4096 bytes (1024 frames)
    1595 2005-08-31 22:09:33.838 audio waiting for space on soundcard: have 672 need 4096
    1596 2005-08-31 22:09:33.850 audio waiting for space on soundcard: have 2996 need 4096
    1597 2005-08-31 22:09:33.862 Broadcasting free space avail
    1598 2005-08-31 22:09:33.862 WriteAudio: Preparing 4096 bytes (1024 frames)
    1599 2005-08-31 22:09:33.862 audio waiting for space on soundcard: have 1304 need 4096
    1600 2005-08-31 22:09:33.866 A/V diverged by 5.85542 frames, extending frame to keep audio in sync
    1601 2005-08-31 22:09:33.871 _AddSamples bytes=4608, used=214017, free=553983, timecode=13680686
    1602 2005-08-31 22:09:33.872 _AddSamples bytes=4608, used=218625, free=549375, timecode=13680710
    1603 2005-08-31 22:09:33.878 Broadcasting free space avail
    1604 2005-08-31 22:09:33.878 WriteAudio: Preparing 4096 bytes (1024 frames)
    1605 2005-08-31 22:09:33.878 audio waiting for space on soundcard: have 340 need 4096
    1606 2005-08-31 22:09:33.891 audio waiting for space on soundcard: have 2648 need 4096
    1607 2005-08-31 22:09:33.903 Broadcasting free space avail
    1608 2005-08-31 22:09:33.903 WriteAudio: Preparing 4096 bytes (1024 frames)
    1609 2005-08-31 22:09:33.903 audio waiting for space on soundcard: have 952 need 4096
    1610 2005-08-31 22:09:33.915 audio waiting for space on soundcard: have 3256 need 4096
    1611 2005-08-31 22:09:33.927 Broadcasting free space avail
    1612 2005-08-31 22:09:33.927 WriteAudio: Preparing 4096 bytes (1024 frames)
    1613 2005-08-31 22:09:33.927 audio waiting for space on soundcard: have 1560 need 4096
    1614 2005-08-31 22:09:33.940 audio waiting for space on soundcard: have 3872 need 4096
    1615 2005-08-31 22:09:33.946 A/V diverged by 5.5478 frames, extending frame to keep audio in sync
    1616 2005-08-31 22:09:33.951 _AddSamples bytes=4608, used=210945, free=557055, timecode=13680734
    1617 2005-08-31 22:09:33.952 Broadcasting free space avail
    1618 2005-08-31 22:09:33.952 WriteAudio: Preparing 4096 bytes (1024 frames)
    1619 2005-08-31 22:09:33.952 audio waiting for space on soundcard: have 2148 need 4096
    1620 2005-08-31 22:09:33.962 read  <- 18 6       128000
    1621 2005-08-31 22:09:33.962 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1622 2005-08-31 22:09:33.963 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1623 2005-08-31 22:09:33.963 _AddSamples bytes=4608, used=211457, free=556543, timecode=13680758
    1624 2005-08-31 22:09:33.964 Broadcasting free space avail
    1625 2005-08-31 22:09:33.964 WriteAudio: Preparing 4096 bytes (1024 frames)
    1626 2005-08-31 22:09:33.964 audio waiting for space on soundcard: have 400 need 4096
    1627 2005-08-31 22:09:33.976 audio waiting for space on soundcard: have 2680 need 4096
    1628 2005-08-31 22:09:33.988 Broadcasting free space avail
    1629 2005-08-31 22:09:33.988 WriteAudio: Preparing 4096 bytes (1024 frames)
    1630 2005-08-31 22:09:33.989 audio waiting for space on soundcard: have 992 need 4096
    1631 2005-08-31 22:09:34.001 audio waiting for space on soundcard: have 3320 need 4096
    1632 2005-08-31 22:09:34.013 Broadcasting free space avail
    1633 2005-08-31 22:09:34.013 WriteAudio: Preparing 4096 bytes (1024 frames)
    1634 2005-08-31 22:09:34.013 audio waiting for space on soundcard: have 1648 need 4096
    1635 2005-08-31 22:09:34.025 audio waiting for space on soundcard: have 3928 need 4096
    1636 2005-08-31 22:09:34.028 A/V diverged by 5.0671 frames, extending frame to keep audio in sync
    1637 2005-08-31 22:09:34.033 _AddSamples bytes=4608, used=203777, free=564223, timecode=13680782
    1638 2005-08-31 22:09:34.037 Broadcasting free space avail
    1639 2005-08-31 22:09:34.037 WriteAudio: Preparing 4096 bytes (1024 frames)
    1640 2005-08-31 22:09:34.038 audio waiting for space on soundcard: have 2212 need 4096
    1641 2005-08-31 22:09:34.050 Broadcasting free space avail
    1642 2005-08-31 22:09:34.050 WriteAudio: Preparing 4096 bytes (1024 frames)
    1643 2005-08-31 22:09:34.050 audio waiting for space on soundcard: have 468 need 4096
    1644 2005-08-31 22:09:34.062 audio waiting for space on soundcard: have 2768 need 4096
    1645 2005-08-31 22:09:34.074 Broadcasting free space avail
    1646 2005-08-31 22:09:34.074 WriteAudio: Preparing 4096 bytes (1024 frames)
    1647 2005-08-31 22:09:34.074 audio waiting for space on soundcard: have 1088 need 4096
    1648 2005-08-31 22:09:34.087 audio waiting for space on soundcard: have 3424 need 4096
    1649 2005-08-31 22:09:34.099 Broadcasting free space avail
    1650 2005-08-31 22:09:34.099 WriteAudio: Preparing 4096 bytes (1024 frames)
    1651 2005-08-31 22:09:34.099 audio waiting for space on soundcard: have 1712 need 4096
    1652 2005-08-31 22:09:34.108 A/V diverged by 4.45033 frames, extending frame to keep audio in sync
    1653 2005-08-31 22:09:34.111 audio waiting for space on soundcard: have 4028 need 4096
    1654 2005-08-31 22:09:34.113 _AddSamples bytes=4608, used=192001, free=575999, timecode=13680806
    1655 2005-08-31 22:09:34.114 _AddSamples bytes=4608, used=196609, free=571391, timecode=13680830
    1656 2005-08-31 22:09:34.123 Broadcasting free space avail
    1657 2005-08-31 22:09:34.123 WriteAudio: Preparing 4096 bytes (1024 frames)
    1658 2005-08-31 22:09:34.123 audio waiting for space on soundcard: have 2312 need 4096
    1659 2005-08-31 22:09:34.135 Broadcasting free space avail
    1660 2005-08-31 22:09:34.136 WriteAudio: Preparing 4096 bytes (1024 frames)
    1661 2005-08-31 22:09:34.136 audio waiting for space on soundcard: have 572 need 4096
    1662 2005-08-31 22:09:34.148 audio waiting for space on soundcard: have 2888 need 4096
    1663 2005-08-31 22:09:34.160 Broadcasting free space avail
    1664 2005-08-31 22:09:34.160 WriteAudio: Preparing 4096 bytes (1024 frames)
    1665 2005-08-31 22:09:34.160 audio waiting for space on soundcard: have 1212 need 4096
    1666 2005-08-31 22:09:34.172 audio waiting for space on soundcard: have 3528 need 4096
    1667 2005-08-31 22:09:34.185 Broadcasting free space avail
    1668 2005-08-31 22:09:34.185 WriteAudio: Preparing 4096 bytes (1024 frames)
    1669 2005-08-31 22:09:34.185 audio waiting for space on soundcard: have 1852 need 4096
    1670 2005-08-31 22:09:34.188 A/V diverged by 3.73148 frames, extending frame to keep audio in sync
    1671 2005-08-31 22:09:34.193 _AddSamples bytes=4608, used=184833, free=583167, timecode=13680854
    1672 2005-08-31 22:09:34.194 _AddSamples bytes=4608, used=189441, free=578559, timecode=13680878
    1673 2005-08-31 22:09:34.197 Broadcasting free space avail
    1674 2005-08-31 22:09:34.197 WriteAudio: Preparing 4096 bytes (1024 frames)
    1675 2005-08-31 22:09:34.197 audio waiting for space on soundcard: have 72 need 4096
    1676 2005-08-31 22:09:34.209 audio waiting for space on soundcard: have 2392 need 4096
    1677 2005-08-31 22:09:34.221 Broadcasting free space avail
    1678 2005-08-31 22:09:34.221 WriteAudio: Preparing 4096 bytes (1024 frames)
    1679 2005-08-31 22:09:34.222 audio waiting for space on soundcard: have 668 need 4096
    1680 2005-08-31 22:09:34.234 audio waiting for space on soundcard: have 2996 need 4096
    1681 2005-08-31 22:09:34.246 Broadcasting free space avail
    1682 2005-08-31 22:09:34.246 WriteAudio: Preparing 4096 bytes (1024 frames)
    1683 2005-08-31 22:09:34.246 audio waiting for space on soundcard: have 1316 need 4096
    1684 2005-08-31 22:09:34.262 Broadcasting free space avail
    1685 2005-08-31 22:09:34.262 WriteAudio: Preparing 4096 bytes (1024 frames)
    1686 2005-08-31 22:09:34.262 audio waiting for space on soundcard: have 336 need 4096
    1687 2005-08-31 22:09:34.271 read  <- 18 6       128000
    1688 2005-08-31 22:09:34.271 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1689 2005-08-31 22:09:34.271 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1690 2005-08-31 22:09:34.274 _AddSamples bytes=4608, used=177665, free=590335, timecode=13680902
    1691 2005-08-31 22:09:34.274 audio waiting for space on soundcard: have 2624 need 4096
    1692 2005-08-31 22:09:34.287 Broadcasting free space avail
    1693 2005-08-31 22:09:34.287 WriteAudio: Preparing 4096 bytes (1024 frames)
    1694 2005-08-31 22:09:34.287 audio waiting for space on soundcard: have 960 need 4096
    1695 2005-08-31 22:09:34.299 audio waiting for space on soundcard: have 3260 need 4096
    1696 2005-08-31 22:09:34.311 Broadcasting free space avail
    1697 2005-08-31 22:09:34.311 WriteAudio: Preparing 4096 bytes (1024 frames)
    1698 2005-08-31 22:09:34.312 audio waiting for space on soundcard: have 1584 need 4096
    1699 2005-08-31 22:09:34.324 audio waiting for space on soundcard: have 3888 need 4096
    1700 2005-08-31 22:09:34.333 _AddSamples bytes=4608, used=174081, free=593919, timecode=13680926
    1701 2005-08-31 22:09:34.333 _AddSamples bytes=4608, used=178689, free=589311, timecode=13680950
    1702 2005-08-31 22:09:34.336 Broadcasting free space avail
    1703 2005-08-31 22:09:34.336 WriteAudio: Preparing 4096 bytes (1024 frames)
    1704 2005-08-31 22:09:34.336 audio waiting for space on soundcard: have 2148 need 4096
    1705 2005-08-31 22:09:34.348 Broadcasting free space avail
    1706 2005-08-31 22:09:34.348 WriteAudio: Preparing 4096 bytes (1024 frames)
    1707 2005-08-31 22:09:34.348 audio waiting for space on soundcard: have 460 need 4096
    1708 2005-08-31 22:09:34.360 audio waiting for space on soundcard: have 2712 need 4096
    1709 2005-08-31 22:09:34.372 Broadcasting free space avail
    1710 2005-08-31 22:09:34.373 WriteAudio: Preparing 4096 bytes (1024 frames)
    1711 2005-08-31 22:09:34.373 _AddSamples bytes=4608, used=171009, free=596991, timecode=13680974
    1712 2005-08-31 22:09:34.373 audio waiting for space on soundcard: have 1036 need 4096
    1713 2005-08-31 22:09:34.373 _AddSamples bytes=4608, used=175617, free=592383, timecode=13680998
    1714 2005-08-31 22:09:34.385 audio waiting for space on soundcard: have 3308 need 4096
    1715 2005-08-31 22:09:34.397 Broadcasting free space avail
    1716 2005-08-31 22:09:34.397 WriteAudio: Preparing 4096 bytes (1024 frames)
    1717 2005-08-31 22:09:34.397 audio waiting for space on soundcard: have 1624 need 4096
    1718 2005-08-31 22:09:34.409 audio waiting for space on soundcard: have 3936 need 4096
    1719 2005-08-31 22:09:34.413 _AddSamples bytes=4608, used=176129, free=591871, timecode=13681022
    1720 2005-08-31 22:09:34.421 Broadcasting free space avail
    1721 2005-08-31 22:09:34.421 WriteAudio: Preparing 4096 bytes (1024 frames)
    1722 2005-08-31 22:09:34.422 audio waiting for space on soundcard: have 2208 need 4096
    1723 2005-08-31 22:09:34.433 Broadcasting free space avail
    1724 2005-08-31 22:09:34.434 WriteAudio: Preparing 4096 bytes (1024 frames)
    1725 2005-08-31 22:09:34.434 audio waiting for space on soundcard: have 444 need 4096
    1726 2005-08-31 22:09:34.446 audio waiting for space on soundcard: have 2756 need 4096
    1727 2005-08-31 22:09:34.449 positionMap[ 14 ] == 9380636.
    1728 2005-08-31 22:09:34.453 _AddSamples bytes=4608, used=172545, free=595455, timecode=13681046
    1729 2005-08-31 22:09:34.454 _AddSamples bytes=4608, used=177153, free=590847, timecode=13681070
    1730 2005-08-31 22:09:34.458 Broadcasting free space avail
    1731 2005-08-31 22:09:34.458 WriteAudio: Preparing 4096 bytes (1024 frames)
    1732 2005-08-31 22:09:34.458 audio waiting for space on soundcard: have 1008 need 4096
    1733 2005-08-31 22:09:34.470 audio waiting for space on soundcard: have 3316 need 4096
    1734 2005-08-31 22:09:34.486 Broadcasting free space avail
    1735 2005-08-31 22:09:34.486 WriteAudio: Preparing 4096 bytes (1024 frames)
    1736 2005-08-31 22:09:34.487 audio waiting for space on soundcard: have 2400 need 4096
    1737 2005-08-31 22:09:34.492 _AddSamples bytes=4608, used=173569, free=594431, timecode=13681094
    1738 2005-08-31 22:09:34.492 _AddSamples bytes=4608, used=178177, free=589823, timecode=13681118
    1739 2005-08-31 22:09:34.498 Broadcasting free space avail
    1740 2005-08-31 22:09:34.498 WriteAudio: Preparing 4096 bytes (1024 frames)
    1741 2005-08-31 22:09:34.499 audio waiting for space on soundcard: have 620 need 4096
    1742 2005-08-31 22:09:34.511 audio waiting for space on soundcard: have 2916 need 4096
    1743 2005-08-31 22:09:34.523 Broadcasting free space avail
    1744 2005-08-31 22:09:34.523 WriteAudio: Preparing 4096 bytes (1024 frames)
    1745 2005-08-31 22:09:34.523 audio waiting for space on soundcard: have 1224 need 4096
    1746 'video_output' mean = '32238.02', std. dev. = '49833.19', fps = '31.02'
    1747 2005-08-31 22:09:34.532 _AddSamples bytes=4608, used=174593, free=593407, timecode=13681142
    1748 2005-08-31 22:09:34.535 audio waiting for space on soundcard: have 3504 need 4096
    1749 2005-08-31 22:09:34.547 Broadcasting free space avail
    1750 2005-08-31 22:09:34.547 WriteAudio: Preparing 4096 bytes (1024 frames)
    1751 2005-08-31 22:09:34.548 audio waiting for space on soundcard: have 1844 need 4096
    1752 2005-08-31 22:09:34.559 Broadcasting free space avail
    1753 2005-08-31 22:09:34.560 WriteAudio: Preparing 4096 bytes (1024 frames)
    1754 2005-08-31 22:09:34.560 audio waiting for space on soundcard: have 64 need 4096
    1755 2005-08-31 22:09:34.572 audio waiting for space on soundcard: have 2356 need 4096
    1756 2005-08-31 22:09:34.572 _AddSamples bytes=4608, used=171009, free=596991, timecode=13681166
    1757 2005-08-31 22:09:34.573 _AddSamples bytes=4608, used=175617, free=592383, timecode=13681190
    1758 2005-08-31 22:09:34.584 Broadcasting free space avail
    1759 2005-08-31 22:09:34.584 WriteAudio: Preparing 4096 bytes (1024 frames)
    1760 2005-08-31 22:09:34.584 audio waiting for space on soundcard: have 672 need 4096
    1761 2005-08-31 22:09:34.596 audio waiting for space on soundcard: have 2948 need 4096
    1762 2005-08-31 22:09:34.610 Broadcasting free space avail
    1763 2005-08-31 22:09:34.610 WriteAudio: Preparing 4096 bytes (1024 frames)
    1764 2005-08-31 22:09:34.610 audio waiting for space on soundcard: have 1528 need 4096
    1765 2005-08-31 22:09:34.613 _AddSamples bytes=4608, used=172033, free=595967, timecode=13681214
    1766 2005-08-31 22:09:34.613 _AddSamples bytes=4608, used=176641, free=591359, timecode=13681238
    1767 2005-08-31 22:09:34.621 audio waiting for space on soundcard: have 3548 need 4096
    1768 2005-08-31 22:09:34.633 Broadcasting free space avail
    1769 2005-08-31 22:09:34.633 WriteAudio: Preparing 4096 bytes (1024 frames)
    1770 2005-08-31 22:09:34.633 audio waiting for space on soundcard: have 1860 need 4096
    1771 2005-08-31 22:09:34.634 read  <- 18 6       128000
    1772 2005-08-31 22:09:34.634 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1773 2005-08-31 22:09:34.634 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1774 2005-08-31 22:09:34.645 Broadcasting free space avail
    1775 2005-08-31 22:09:34.645 WriteAudio: Preparing 4096 bytes (1024 frames)
    1776 2005-08-31 22:09:34.645 audio waiting for space on soundcard: have 124 need 4096
    1777 2005-08-31 22:09:34.654 _AddSamples bytes=4608, used=173057, free=594943, timecode=13681262
    1778 2005-08-31 22:09:34.657 audio waiting for space on soundcard: have 2384 need 4096
    1779 2005-08-31 22:09:34.669 Broadcasting free space avail
    1780 2005-08-31 22:09:34.669 WriteAudio: Preparing 4096 bytes (1024 frames)
    1781 2005-08-31 22:09:34.670 audio waiting for space on soundcard: have 676 need 4096
    1782 2005-08-31 22:09:34.681 audio waiting for space on soundcard: have 2956 need 4096
    1783 2005-08-31 22:09:34.693 Broadcasting free space avail
    1784 2005-08-31 22:09:34.694 WriteAudio: Preparing 4096 bytes (1024 frames)
    1785 2005-08-31 22:09:34.694 audio waiting for space on soundcard: have 1280 need 4096
    1786 2005-08-31 22:09:34.694 _AddSamples bytes=4608, used=169473, free=598527, timecode=13681286
    1787 2005-08-31 22:09:34.695 _AddSamples bytes=4608, used=174081, free=593919, timecode=13681310
    1788 2005-08-31 22:09:34.708 audio waiting for space on soundcard: have 4008 need 4096
    1789 2005-08-31 22:09:34.722 Broadcasting free space avail
    1790 2005-08-31 22:09:34.722 WriteAudio: Preparing 4096 bytes (1024 frames)
    1791 2005-08-31 22:09:34.722 audio waiting for space on soundcard: have 2536 need 4096
    1792 2005-08-31 22:09:34.734 _AddSamples bytes=4608, used=174593, free=593407, timecode=13681334
    1793 2005-08-31 22:09:34.735 _AddSamples bytes=4608, used=179201, free=588799, timecode=13681358
    1794 2005-08-31 22:09:34.735 Broadcasting free space avail
    1795 2005-08-31 22:09:34.735 WriteAudio: Preparing 4096 bytes (1024 frames)
    1796 2005-08-31 22:09:34.735 audio waiting for space on soundcard: have 1048 need 4096
    1797 2005-08-31 22:09:34.750 audio waiting for space on soundcard: have 3812 need 4096
    1798 2005-08-31 22:09:34.762 Broadcasting free space avail
    1799 2005-08-31 22:09:34.762 WriteAudio: Preparing 4096 bytes (1024 frames)
    1800 2005-08-31 22:09:34.762 audio waiting for space on soundcard: have 2132 need 4096
    1801 2005-08-31 22:09:34.774 _AddSamples bytes=4608, used=175617, free=592383, timecode=13681382
    1802 2005-08-31 22:09:34.778 Broadcasting free space avail
    1803 2005-08-31 22:09:34.778 WriteAudio: Preparing 4096 bytes (1024 frames)
    1804 2005-08-31 22:09:34.778 audio waiting for space on soundcard: have 1088 need 4096
    1805 2005-08-31 22:09:34.794 Broadcasting free space avail
    1806 2005-08-31 22:09:34.794 WriteAudio: Preparing 4096 bytes (1024 frames)
    1807 2005-08-31 22:09:34.795 audio waiting for space on soundcard: have 112 need 4096
    1808 2005-08-31 22:09:34.807 audio waiting for space on soundcard: have 2416 need 4096
    1809 2005-08-31 22:09:34.814 _AddSamples bytes=4608, used=172033, free=595967, timecode=13681406
    1810 2005-08-31 22:09:34.815 _AddSamples bytes=4608, used=176641, free=591359, timecode=13681430
    1811 2005-08-31 22:09:34.818 Broadcasting free space avail
    1812 2005-08-31 22:09:34.818 WriteAudio: Preparing 4096 bytes (1024 frames)
    1813 2005-08-31 22:09:34.819 audio waiting for space on soundcard: have 624 need 4096
    1814 2005-08-31 22:09:34.831 audio waiting for space on soundcard: have 2908 need 4096
    1815 2005-08-31 22:09:34.843 Broadcasting free space avail
    1816 2005-08-31 22:09:34.843 WriteAudio: Preparing 4096 bytes (1024 frames)
    1817 2005-08-31 22:09:34.843 audio waiting for space on soundcard: have 1172 need 4096
    1818 2005-08-31 22:09:34.854 _AddSamples bytes=4608, used=173057, free=594943, timecode=13681454
    1819 2005-08-31 22:09:34.855 _AddSamples bytes=4608, used=177665, free=590335, timecode=13681478
    1820 2005-08-31 22:09:34.856 audio waiting for space on soundcard: have 3628 need 4096
    1821 2005-08-31 22:09:34.867 Broadcasting free space avail
    1822 2005-08-31 22:09:34.867 WriteAudio: Preparing 4096 bytes (1024 frames)
    1823 2005-08-31 22:09:34.867 audio waiting for space on soundcard: have 1712 need 4096
    1824 2005-08-31 22:09:34.879 audio waiting for space on soundcard: have 4012 need 4096
    1825 2005-08-31 22:09:34.891 Broadcasting free space avail
    1826 2005-08-31 22:09:34.891 WriteAudio: Preparing 4096 bytes (1024 frames)
    1827 2005-08-31 22:09:34.891 audio waiting for space on soundcard: have 2268 need 4096
    1828 2005-08-31 22:09:34.906 Broadcasting free space avail
    1829 2005-08-31 22:09:34.906 WriteAudio: Preparing 4096 bytes (1024 frames)
    1830 2005-08-31 22:09:34.906 audio waiting for space on soundcard: have 992 need 4096
    1831 2005-08-31 22:09:34.911 _AddSamples bytes=4608, used=169985, free=598015, timecode=13681502
    1832 2005-08-31 22:09:34.915 audio waiting for space on soundcard: have 2752 need 4096
    1833 2005-08-31 22:09:34.928 Broadcasting free space avail
    1834 2005-08-31 22:09:34.928 WriteAudio: Preparing 4096 bytes (1024 frames)
    1835 2005-08-31 22:09:34.928 audio waiting for space on soundcard: have 1108 need 4096
    1836 2005-08-31 22:09:34.929 positionMap[ 15 ] == 9548332.
    1837 2005-08-31 22:09:34.934 _AddSamples bytes=4608, used=170497, free=597503, timecode=13681526
    1838 2005-08-31 22:09:34.934 _AddSamples bytes=4608, used=175105, free=592895, timecode=13681550
    1839 2005-08-31 22:09:34.939 audio waiting for space on soundcard: have 3304 need 4096
    1840 2005-08-31 22:09:34.951 Broadcasting free space avail
    1841 2005-08-31 22:09:34.952 WriteAudio: Preparing 4096 bytes (1024 frames)
    1842 2005-08-31 22:09:34.952 audio waiting for space on soundcard: have 1616 need 4096
    1843 2005-08-31 22:09:34.963 audio waiting for space on soundcard: have 3856 need 4096
    1844 2005-08-31 22:09:34.972 _AddSamples bytes=4608, used=175617, free=592383, timecode=13681574
    1845 2005-08-31 22:09:34.973 _AddSamples bytes=4608, used=180225, free=587775, timecode=13681598
    1846 2005-08-31 22:09:34.976 Broadcasting free space avail
    1847 2005-08-31 22:09:34.976 WriteAudio: Preparing 4096 bytes (1024 frames)
    1848 2005-08-31 22:09:34.976 audio waiting for space on soundcard: have 2124 need 4096
    1849 2005-08-31 22:09:34.988 Broadcasting free space avail
    1850 2005-08-31 22:09:34.988 WriteAudio: Preparing 4096 bytes (1024 frames)
    1851 2005-08-31 22:09:34.988 audio waiting for space on soundcard: have 368 need 4096
    1852 2005-08-31 22:09:35.000 audio waiting for space on soundcard: have 2624 need 4096
    1853 2005-08-31 22:09:35.012 Broadcasting free space avail
    1854 2005-08-31 22:09:35.012 WriteAudio: Preparing 4096 bytes (1024 frames)
    1855 2005-08-31 22:09:35.012 _AddSamples bytes=4608, used=172545, free=595455, timecode=13681622
    1856 2005-08-31 22:09:35.012 audio waiting for space on soundcard: have 924 need 4096
    1857 2005-08-31 22:09:35.024 audio waiting for space on soundcard: have 3244 need 4096
    1858 2005-08-31 22:09:35.036 Broadcasting free space avail
    1859 2005-08-31 22:09:35.036 WriteAudio: Preparing 4096 bytes (1024 frames)
    1860 2005-08-31 22:09:35.036 audio waiting for space on soundcard: have 1472 need 4096
    1861 2005-08-31 22:09:35.049 audio waiting for space on soundcard: have 3932 need 4096
    1862 2005-08-31 22:09:35.052 _AddSamples bytes=4608, used=173057, free=594943, timecode=13681646
    1863 2005-08-31 22:09:35.053 _AddSamples bytes=4608, used=177665, free=590335, timecode=13681670
    1864 2005-08-31 22:09:35.060 Broadcasting free space avail
    1865 2005-08-31 22:09:35.060 WriteAudio: Preparing 4096 bytes (1024 frames)
    1866 2005-08-31 22:09:35.061 audio waiting for space on soundcard: have 2016 need 4096
    1867 2005-08-31 22:09:35.073 Broadcasting free space avail
    1868 2005-08-31 22:09:35.073 WriteAudio: Preparing 4096 bytes (1024 frames)
    1869 2005-08-31 22:09:35.073 audio waiting for space on soundcard: have 296 need 4096
    1870 2005-08-31 22:09:35.081 read  <- 18 6       128000
    1871 2005-08-31 22:09:35.082 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1872 2005-08-31 22:09:35.082 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1873 2005-08-31 22:09:35.085 audio waiting for space on soundcard: have 2544 need 4096
    1874 2005-08-31 22:09:35.093 _AddSamples bytes=4608, used=174081, free=593919, timecode=13681694
    1875 2005-08-31 22:09:35.094 _AddSamples bytes=4608, used=178689, free=589311, timecode=13681718
    1876 2005-08-31 22:09:35.097 Broadcasting free space avail
    1877 2005-08-31 22:09:35.097 WriteAudio: Preparing 4096 bytes (1024 frames)
    1878 2005-08-31 22:09:35.097 audio waiting for space on soundcard: have 808 need 4096
    1879 2005-08-31 22:09:35.109 audio waiting for space on soundcard: have 3096 need 4096
    1880 2005-08-31 22:09:35.121 Broadcasting free space avail
    1881 2005-08-31 22:09:35.121 WriteAudio: Preparing 4096 bytes (1024 frames)
    1882 2005-08-31 22:09:35.121 audio waiting for space on soundcard: have 1392 need 4096
    1883 2005-08-31 22:09:35.132 _AddSamples bytes=4608, used=175105, free=592895, timecode=13681742
    1884 2005-08-31 22:09:35.133 audio waiting for space on soundcard: have 3656 need 4096
    1885 2005-08-31 22:09:35.145 Broadcasting free space avail
    1886 2005-08-31 22:09:35.145 WriteAudio: Preparing 4096 bytes (1024 frames)
    1887 2005-08-31 22:09:35.146 audio waiting for space on soundcard: have 1948 need 4096
    1888 2005-08-31 22:09:35.157 Broadcasting free space avail
    1889 2005-08-31 22:09:35.158 WriteAudio: Preparing 4096 bytes (1024 frames)
    1890 2005-08-31 22:09:35.158 audio waiting for space on soundcard: have 216 need 4096
    1891 2005-08-31 22:09:35.173 _AddSamples bytes=4608, used=171521, free=596479, timecode=13681766
    1892 2005-08-31 22:09:35.174 audio waiting for space on soundcard: have 3252 need 4096
    1893 2005-08-31 22:09:35.174 _AddSamples bytes=4608, used=176129, free=591871, timecode=13681790
    1894 2005-08-31 22:09:35.186 Broadcasting free space avail
    1895 2005-08-31 22:09:35.186 WriteAudio: Preparing 4096 bytes (1024 frames)
    1896 2005-08-31 22:09:35.186 audio waiting for space on soundcard: have 1548 need 4096
    1897 2005-08-31 22:09:35.198 audio waiting for space on soundcard: have 3808 need 4096
    1898 2005-08-31 22:09:35.210 Broadcasting free space avail
    1899 2005-08-31 22:09:35.210 WriteAudio: Preparing 4096 bytes (1024 frames)
    1900 2005-08-31 22:09:35.211 audio waiting for space on soundcard: have 2156 need 4096
    1901 2005-08-31 22:09:35.212 _AddSamples bytes=4608, used=172545, free=595455, timecode=13681814
    1902 2005-08-31 22:09:35.213 _AddSamples bytes=4608, used=177153, free=590847, timecode=13681838
    1903 2005-08-31 22:09:35.226 Broadcasting free space avail
    1904 2005-08-31 22:09:35.226 WriteAudio: Preparing 4096 bytes (1024 frames)
    1905 2005-08-31 22:09:35.227 audio waiting for space on soundcard: have 1140 need 4096
    1906 2005-08-31 22:09:35.238 audio waiting for space on soundcard: have 3416 need 4096
    1907 2005-08-31 22:09:35.253 _AddSamples bytes=4608, used=177665, free=590335, timecode=13681862
    1908 2005-08-31 22:09:35.254 Broadcasting free space avail
    1909 2005-08-31 22:09:35.254 WriteAudio: Preparing 4096 bytes (1024 frames)
    1910 2005-08-31 22:09:35.254 audio waiting for space on soundcard: have 2284 need 4096
    1911 2005-08-31 22:09:35.263 audio waiting for space on soundcard: have 3948 need 4096
    1912 2005-08-31 22:09:35.275 Broadcasting free space avail
    1913 2005-08-31 22:09:35.275 WriteAudio: Preparing 4096 bytes (1024 frames)
    1914 2005-08-31 22:09:35.275 audio waiting for space on soundcard: have 2236 need 4096
    1915 2005-08-31 22:09:35.287 Broadcasting free space avail
    1916 2005-08-31 22:09:35.287 WriteAudio: Preparing 4096 bytes (1024 frames)
    1917 2005-08-31 22:09:35.287 audio waiting for space on soundcard: have 468 need 4096
    1918 2005-08-31 22:09:35.291 _AddSamples bytes=4608, used=169985, free=598015, timecode=13681886
    1919 2005-08-31 22:09:35.292 _AddSamples bytes=4608, used=174593, free=593407, timecode=13681910
    1920 2005-08-31 22:09:35.299 audio waiting for space on soundcard: have 2704 need 4096
    1921 2005-08-31 22:09:35.311 Broadcasting free space avail
    1922 2005-08-31 22:09:35.311 WriteAudio: Preparing 4096 bytes (1024 frames)
    1923 2005-08-31 22:09:35.311 audio waiting for space on soundcard: have 1008 need 4096
    1924 2005-08-31 22:09:35.323 audio waiting for space on soundcard: have 3288 need 4096
    1925 2005-08-31 22:09:35.332 _AddSamples bytes=4608, used=175105, free=592895, timecode=13681934
    1926 2005-08-31 22:09:35.332 _AddSamples bytes=4608, used=179713, free=588287, timecode=13681958
    1927 2005-08-31 22:09:35.335 Broadcasting free space avail
    1928 2005-08-31 22:09:35.336 WriteAudio: Preparing 4096 bytes (1024 frames)
    1929 2005-08-31 22:09:35.336 audio waiting for space on soundcard: have 1584 need 4096
    1930 2005-08-31 22:09:35.347 audio waiting for space on soundcard: have 3848 need 4096
    1931 2005-08-31 22:09:35.360 Broadcasting free space avail
    1932 2005-08-31 22:09:35.360 WriteAudio: Preparing 4096 bytes (1024 frames)
    1933 2005-08-31 22:09:35.360 audio waiting for space on soundcard: have 2148 need 4096
    1934 2005-08-31 22:09:35.372 _AddSamples bytes=4608, used=176129, free=591871, timecode=13681982
    1935 2005-08-31 22:09:35.372 Broadcasting free space avail
    1936 2005-08-31 22:09:35.372 WriteAudio: Preparing 4096 bytes (1024 frames)
    1937 2005-08-31 22:09:35.372 audio waiting for space on soundcard: have 368 need 4096
    1938 2005-08-31 22:09:35.384 audio waiting for space on soundcard: have 2716 need 4096
    1939 2005-08-31 22:09:35.396 Broadcasting free space avail
    1940 2005-08-31 22:09:35.396 WriteAudio: Preparing 4096 bytes (1024 frames)
    1941 2005-08-31 22:09:35.397 audio waiting for space on soundcard: have 996 need 4096
    1942 2005-08-31 22:09:35.408 positionMap[ 16 ] == 9707380.
    1943 2005-08-31 22:09:35.413 audio waiting for space on soundcard: have 4088 need 4096
    1944 2005-08-31 22:09:35.413 _AddSamples bytes=4608, used=172545, free=595455, timecode=13682006
    1945 2005-08-31 22:09:35.414 _AddSamples bytes=4608, used=177153, free=590847, timecode=13682030
    1946 2005-08-31 22:09:35.425 Broadcasting free space avail
    1947 2005-08-31 22:09:35.425 WriteAudio: Preparing 4096 bytes (1024 frames)
    1948 2005-08-31 22:09:35.425 audio waiting for space on soundcard: have 2408 need 4096
    1949 2005-08-31 22:09:35.434 read  <- 18 6       128000
    1950 2005-08-31 22:09:35.434 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    1951 2005-08-31 22:09:35.434 write -> 18 53      QUERY_RECORDER 1[]:[]REQUEST_BLOCK_RINGBUF[]:[]128000
    1952 2005-08-31 22:09:35.437 Broadcasting free space avail
    1953 2005-08-31 22:09:35.437 WriteAudio: Preparing 4096 bytes (1024 frames)
    1954 2005-08-31 22:09:35.437 audio waiting for space on soundcard: have 640 need 4096
    1955 2005-08-31 22:09:35.450 audio waiting for space on soundcard: have 2984 need 4096
    1956 2005-08-31 22:09:35.453 _AddSamples bytes=4608, used=173569, free=594431, timecode=13682054
    1957 2005-08-31 22:09:35.454 _AddSamples bytes=4608, used=178177, free=589823, timecode=13682078
    1958 2005-08-31 22:09:35.461 Broadcasting free space avail
    1959 2005-08-31 22:09:35.462 WriteAudio: Preparing 4096 bytes (1024 frames)
    1960 2005-08-31 22:09:35.462 audio waiting for space on soundcard: have 1216 need 4096
    1961 2005-08-31 22:09:35.473 audio waiting for space on soundcard: have 3464 need 4096
    1962 2005-08-31 22:09:35.485 Broadcasting free space avail
    1963 2005-08-31 22:09:35.486 WriteAudio: Preparing 4096 bytes (1024 frames)
    1964 2005-08-31 22:09:35.486 audio waiting for space on soundcard: have 1760 need 4096
    1965 2005-08-31 22:09:35.493 _AddSamples bytes=4608, used=174593, free=593407, timecode=13682102
    1966 2005-08-31 22:09:35.498 audio waiting for space on soundcard: have 3992 need 4096
    1967 2005-08-31 22:09:35.510 Broadcasting free space avail
    1968 2005-08-31 22:09:35.510 WriteAudio: Preparing 4096 bytes (1024 frames)
    1969 2005-08-31 22:09:35.510 audio waiting for space on soundcard: have 2284 need 4096
    1970 2005-08-31 22:09:35.522 Broadcasting free space avail
    1971 2005-08-31 22:09:35.522 WriteAudio: Preparing 4096 bytes (1024 frames)
    1972 2005-08-31 22:09:35.522 audio waiting for space on soundcard: have 476 need 4096
    1973 2005-08-31 22:09:35.533 _AddSamples bytes=4608, used=171009, free=596991, timecode=13682126
    1974 2005-08-31 22:09:35.534 _AddSamples bytes=4608, used=175617, free=592383, timecode=13682150
    1975 2005-08-31 22:09:35.534 audio waiting for space on soundcard: have 2728 need 4096
    1976 2005-08-31 22:09:35.548 Broadcasting free space avail
    1977 2005-08-31 22:09:35.548 WriteAudio: Preparing 4096 bytes (1024 frames)
    1978 2005-08-31 22:09:35.549 audio waiting for space on soundcard: have 1500 need 4096
    1979 2005-08-31 22:09:35.562 audio waiting for space on soundcard: have 4008 need 4096
    1980 2005-08-31 22:09:35.573 _AddSamples bytes=4608, used=176129, free=591871, timecode=13682174
    1981 2005-08-31 22:09:35.574 _AddSamples bytes=4608, used=180737, free=587263, timecode=13682198
    1982 2005-08-31 22:09:35.574 Broadcasting free space avail
    1983 2005-08-31 22:09:35.574 WriteAudio: Preparing 4096 bytes (1024 frames)
    1984 2005-08-31 22:09:35.574 audio waiting for space on soundcard: have 2376 need 4096
    1985 2005-08-31 22:09:35.586 Attempting to change from WatchingLiveTV to None
    1986 2005-08-31 22:09:35.586 TV::StopStuff() -- begin
    1987 2005-08-31 22:09:35.586 TV::StopStuff(): stopping ring buffer[s]
    1988 2005-08-31 22:09:35.590 Broadcasting free space avail
    1989 2005-08-31 22:09:35.590 WriteAudio: Preparing 4096 bytes (1024 frames)
    1990 2005-08-31 22:09:35.590 audio waiting for space on soundcard: have 1244 need 4096
    1991 2005-08-31 22:09:35.602 audio waiting for space on soundcard: have 3496 need 4096
    1992 2005-08-31 22:09:35.613 _AddSamples bytes=4608, used=177153, free=590847, timecode=13682222
    1993 2005-08-31 22:09:35.614 Broadcasting free space avail
    1994 2005-08-31 22:09:35.614 WriteAudio: Preparing 4096 bytes (1024 frames)
    1995 2005-08-31 22:09:35.614 audio waiting for space on soundcard: have 1776 need 4096
    1996 2005-08-31 22:09:35.626 audio waiting for space on soundcard: have 4008 need 4096
    1997 2005-08-31 22:09:35.638 Broadcasting free space avail
    1998 2005-08-31 22:09:35.638 WriteAudio: Preparing 4096 bytes (1024 frames)
    1999 2005-08-31 22:09:35.638 audio waiting for space on soundcard: have 2264 need 4096
    2000 2005-08-31 22:09:35.650 Broadcasting free space avail
    2001 2005-08-31 22:09:35.650 WriteAudio: Preparing 4096 bytes (1024 frames)
    2002 2005-08-31 22:09:35.650 audio waiting for space on soundcard: have 544 need 4096
    2003 2005-08-31 22:09:35.653 _AddSamples bytes=4608, used=169473, free=598527, timecode=13682246
    2004 2005-08-31 22:09:35.653 _AddSamples bytes=4608, used=174081, free=593919, timecode=13682270
    2005 2005-08-31 22:09:35.666 audio waiting for space on soundcard: have 3496 need 4096
    2006 2005-08-31 22:09:35.678 Broadcasting free space avail
    2007 2005-08-31 22:09:35.678 WriteAudio: Preparing 4096 bytes (1024 frames)
    2008 2005-08-31 22:09:35.678 audio waiting for space on soundcard: have 1808 need 4096
    2009 2005-08-31 22:09:35.690 audio waiting for space on soundcard: have 4012 need 4096
    2010 2005-08-31 22:09:35.693 _AddSamples bytes=4608, used=174593, free=593407, timecode=13682294
    2011 2005-08-31 22:09:35.693 _AddSamples bytes=4608, used=179201, free=588799, timecode=13682318
    2012 2005-08-31 22:09:35.702 Broadcasting free space avail
    2013 2005-08-31 22:09:35.702 WriteAudio: Preparing 4096 bytes (1024 frames)
    2014 2005-08-31 22:09:35.702 audio waiting for space on soundcard: have 2276 need 4096
    2015 2005-08-31 22:09:35.714 Broadcasting free space avail
    2016 2005-08-31 22:09:35.714 WriteAudio: Preparing 4096 bytes (1024 frames)
    2017 2005-08-31 22:09:35.714 audio waiting for space on soundcard: have 488 need 4096
    2018 2005-08-31 22:09:35.726 audio waiting for space on soundcard: have 2740 need 4096
    2019 2005-08-31 22:09:35.733 _AddSamples bytes=4608, used=175617, free=592383, timecode=13682342
    2020 2005-08-31 22:09:35.738 Broadcasting free space avail
    2021 2005-08-31 22:09:35.738 WriteAudio: Preparing 4096 bytes (1024 frames)
    2022 2005-08-31 22:09:35.738 audio waiting for space on soundcard: have 1000 need 4096
    2023 2005-08-31 22:09:35.750 audio waiting for space on soundcard: have 3244 need 4096
    2024 2005-08-31 22:09:35.762 Broadcasting free space avail
    2025 2005-08-31 22:09:35.762 WriteAudio: Preparing 4096 bytes (1024 frames)
    2026 2005-08-31 22:09:35.762 audio waiting for space on soundcard: have 1544 need 4096
    2027 2005-08-31 22:09:35.772 _AddSamples bytes=4608, used=172033, free=595967, timecode=13682366
    2028 2005-08-31 22:09:35.772 _AddSamples bytes=4608, used=176641, free=591359, timecode=13682390
    2029 2005-08-31 22:09:35.774 audio waiting for space on soundcard: have 3840 need 4096
    2030 2005-08-31 22:09:35.786 Broadcasting free space avail
    2031 2005-08-31 22:09:35.786 WriteAudio: Preparing 4096 bytes (1024 frames)
    2032 2005-08-31 22:09:35.787 audio waiting for space on soundcard: have 2144 need 4096
    2033 2005-08-31 22:09:35.789 read  <- 18 6       128000
    2034 2005-08-31 22:09:35.789 Read(): reqd=128000, rcvd=128000, rept=128000, error=0
    2035 2005-08-31 22:09:35.789 TV::StopStuff(): stopping player[s] (1/2)
    2036 2005-08-31 22:09:35.789 TV::StopStuff(): stopping recorder[s]
    2037 2005-08-31 22:09:35.789 write -> 17 32      QUERY_RECORDER 1[]:[]STOP_LIVETV
    2038 2005-08-31 22:09:35.798 Broadcasting free space avail
    2039 2005-08-31 22:09:35.799 WriteAudio: Preparing 4096 bytes (1024 frames)
    2040 2005-08-31 22:09:35.799 audio waiting for space on soundcard: have 372 need 4096
    2041 2005-08-31 22:09:35.808 ~VideoOutputXv()
    2042 2005-08-31 22:09:35.808 VideoBuffers::DiscardFrames(): LUUUUUUAUUUUUUUUUUUUUUUUUUUUUUU
    2043 2005-08-31 22:09:35.808 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
    2044 2005-08-31 22:09:35.808 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
    2045 2005-08-31 22:09:35.809 VideoBuffers::DiscardFrames(): AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA -- done()
    2046 2005-08-31 22:09:35.818 read  <- 16 48      BACKEND_MESSAGE[]:[]DONE_RECORDING 1 4[]:[]empty
    2047 2005-08-31 22:09:35.819 Broadcasting free space avail
    2048 2005-08-31 22:09:35.820 WriteAudio: Preparing 4096 bytes (1024 frames)
    2049 2005-08-31 22:09:35.821 audio waiting for space on soundcard: have 504 need 4096
    2050 2005-08-31 22:09:35.822 Killing AudioOutputDSP
    2051 2005-08-31 22:09:35.831 OutputAudioLoop: Stop Event
    2052 2005-08-31 22:09:35.831 kickoffOutputAudioLoop exiting
    2053 2005-08-31 22:09:35.875 read  <- 17 2       ok
    2054 2005-08-31 22:09:35.875 TV::StopStuff(): stopping player[s] (2/2)
    2055 2005-08-31 22:09:35.884 write -> 18 33      QUERY_RECORDER 1[]:[]DONE_RINGBUF
    2056 2005-08-31 22:09:35.891 read  <- 16 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
    2057 2005-08-31 22:09:35.899 read  <- 16 51      BACKEND_MESSAGE[]:[]RECORDING_LIST_CHANGE[]:[]empty
    2058 2005-08-31 22:09:35.899 read  <- 18 2       OK
    2059 2005-08-31 22:09:35.900 TV::StopStuff() -- end
    2060 2005-08-31 22:09:35.900 Changing from WatchingLiveTV to None
    2061 2005-08-31 22:09:35.907 Attempting to change from None to None
    2062 2005-08-31 22:09:44.387 write -> 14 34      QUERY_IS_ACTIVE_BACKEND[]:[]vdrtv1
    2063 2005-08-31 22:09:44.406 read  <- 14 4       TRUE
    2064 Destroying SipFsm object
    2065 
    2066 
    2067 
    2068 }}}
     3Debug output attached.