Interpretation of Xserver Xorg.0.log output when frame rate control is active

The following log output typically is seen after starting video replay.

    |<- -20ms                               0                              +20ms ->|      R                    958351
    -------|--------------------------------*---------------------------------------   -265  -16590 [ -3-168]  999986
    -------|--------------------------------+-*-------------------------------------   1009  -16687 [-28-156] 1000916
    --------|-------------------------------*---------------------------------------   -243  -16284 [-37-165]  999081
    ---------|------------------------------+*--------------------------------------    564  -15511 [-37-149]  999834
    ----------|-----------------------------+*--------------------------------------    736  -15076 [-37-143] 1000008
    ------------|---------------------------+*--------------------------------------    718  -14349 [-37-136]  999990
    -------------|--------------------------+*--------------------------------------    732  -13619 [-37-128] 1000003
    ---------------|------------------------+*--------------------------------------    744  -12891 [-37-121] 1000016
    ----------------|-----------------------+*--------------------------------------    671  -12163 [-37-114]  999943
    ------------------|---------------------+--*------------------------------------   1678  -11397 [-37 -97] 1000949
    -------------------|--------------------*---------------------------------------   -175  -10703 [-37-108]  999097
    ---------------------|------------------+*--------------------------------------    719   -9973 [-37 -92]  999992
    ----------------------|-----------------+*--------------------------------------    737   -9246 [-37 -85] 1000009
    -----------------------|----------------+*--------------------------------------    727   -8517 [-37 -77]  999995
    -------------------------|--------------+*--------------------------------------    742   -7787 [-37 -70] 1000014
    --------------------------|-------------+*--------------------------------------    744   -7058 [-37 -63] 1000015
    ----------------------------|-----------+*--------------------------------------    696   -6330 [-37 -56]  999968
    -----------------------------|----------+*--------------------------------------    769   -5599 [-37 -48] 1000041
    -------------------------------|--------+*--------------------------------------    709   -4860 [-37 -41]  999958
    --------------------------------|-------+*--------------------------------------    725   -4122 [-37 -33]  999998
    ----------------------------------|-----+*--------------------------------------    719   -3129 [-37 -24]  999992
    -----------------------------------|----+*--------------------------------------    747   -2665 [-37 -19] 1000016
    -------------------------------------|--+*--------------------------------------    742   -1938 [-37 -11] 1000016
    --------------------------------------|-+*--------------------------------------    722   -1207 [-37  -4]  999996
    ----------------------------------------|*--------------------------------------    943    -471 [-37  +4] 1000215
    ----------------------------------------*---------------------------------------    433     341 [-33  +7]  999806
    ----------------------------------------*|--------------------------------------    403     729 [-26 +11]  999962
    ----------------------------------------*-|-------------------------------------    168    1048 [-15 +12]  999997
    ----------------------------------------*-|-------------------------------------   -164    1044 [ -3  +8]  999994
    ----------------------------------------*|--------------------------------------   -392     727 [  5  +3] 1000050
    ----------------------------------------*---------------------------------------   -339     392 [  8  +0] 1000224
    ---------------------------------------*|---------------------------------------   -816    -352 [  8 -11]  999753
    ---------------------------------------|*---------------------------------------   -334    -825 [ -3 -11]  999997
    ---------------------------------------|*---------------------------------------      0    -989 [-14  -9] 1000010
    ---------------------------------------|*---------------------------------------    257    -845 [-23  -5]  999983
    ----------------------------------------*---------------------------------------    446    -467 [-28  +0]  999994
    ----------------------------------------|*--------------------------------------    731     110 [-28  +8] 1000261
    ----------------------------------------*|--------------------------------------     19     509 [-20  +5]  999741
    ----------------------------------------*|--------------------------------------    118     564 [-15  +6] 1000007
    ----------------------------------------*|--------------------------------------    -55     592 [ -9  +5]  999998
                                                                                         ^       ^     ^   ^       ^
                                                                                         /       |     |   |       |
                  25 frame average of drift speed VGA-video timing against xine-lib calls        |     |   |       |
                  to XvPutimage(). it's represented by asterisks '*' in debug output             |     |   |       |
                                                                                                 |     |   |       |
                                                                                                 /     |   |       |
                            sync point displacement indicated by bars '|' in debug output. it's a      |   |       |
                            25 frame average of where frame updates hit the 40ms update interval       |   |       |
                                                                                                       |   |       |
                                                                                                       /   |       |
                                                   frame rate adjustement active for the last 25 frames    |       |
                                                                                                           |       |
                                                                                                           /       |
                                                              yet unclipped relative frame rate adjustement        |
                                                              calculated for upcoming 25 frames                    |
                                                                                                                   |
                                                                                                                   /
                                                                 time elapsed since last 25 frames sent by xine-lib
  • legend:

     |   syncpoint: frame update position within 40ms interval averaged over 25 frames
     *   driftspeed: skew between video stream frame (input rate) and VGA video timing (output rate) averaged over 25 frames
    
  • algorithm:

    by altering the drift speed accordingly we let the sync point drift towards the center region of 40ms update interval