[mythtv-commits] Ticket #13536: Refine AVSync2 Algorithm

MythTV noreply at mythtv.org
Fri Dec 13 10:06:44 UTC 2019 

#13536: Refine AVSync2 Algorithm
-------------------------------------+------------------------------
 Reporter:  pletch                   |          Owner:  mark-kendall
     Type:  Patch - Feature          |         Status:  closed
 Priority:  minor                    |      Milestone:  31.0
Component:  MythTV - Video Playback  |        Version:  Master Head
 Severity:  medium                   |     Resolution:  Fixed
 Keywords:  AVSync2 AVSync sync      |  Ticket locked:  0
-------------------------------------+------------------------------

Comment (by mark-kendall):

 Tinkering with the gain value, from a purely audiovisual (i.e. user
 experience) perspective, I don't see any difference. An example of the
 logging 'issues' I see is shown below. This is after a skip in a 4kHDR,
 HEVC file using VAAPI. On reflection this is probably just a personal
 reaction to seeing all of that logging, although in this case it seems
 that the response time is quite long.

 {{{
 2019-12-13 09:58:08.269284 I [16394/16394] CoreContext
 mythplayer.cpp:3868:ClearAfterSeek  Player(1): ClearAfterSeek(0)
 2019-12-13 09:58:08.269321 I [16394/16394] CoreContext
 mythplayer.cpp:1849:SetBuffering  Player(1): Waiting for video buffers...
 2019-12-13 09:58:08.446657 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 134 ms
 2019-12-13 09:58:08.488384 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 142 ms
 2019-12-13 09:58:08.532132 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 140 ms
 2019-12-13 09:58:08.575929 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 138 ms
 2019-12-13 09:58:08.620249 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 136 ms
 2019-12-13 09:58:08.663469 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 133 ms
 2019-12-13 09:58:08.708222 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 132 ms
 2019-12-13 09:58:08.753846 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 130 ms
 2019-12-13 09:58:08.754199 I [16394/16394] CoreContext
 jitterometer.cpp:131:RecordEndTime  Player(1): FPS:   22.31 Mean: 44823
 Std.Dev: 22306 CPUs: 39% 38%
 2019-12-13 09:58:08.795125 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 128 ms
 2019-12-13 09:58:08.839258 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 126 ms
 2019-12-13 09:58:08.883294 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 122 ms
 2019-12-13 09:58:08.926492 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 121 ms
 2019-12-13 09:58:08.970423 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 119 ms
 2019-12-13 09:58:09.017472 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 117 ms
 2019-12-13 09:58:09.057390 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 114 ms
 2019-12-13 09:58:09.101274 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 112 ms
 2019-12-13 09:58:09.145157 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 111 ms
 2019-12-13 09:58:09.188299 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 110 ms
 2019-12-13 09:58:09.231832 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 106 ms
 2019-12-13 09:58:09.277382 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 104 ms
 2019-12-13 09:58:09.318376 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 104 ms
 2019-12-13 09:58:09.362042 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 102 ms
 2019-12-13 09:58:09.405710 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 101 ms
 2019-12-13 09:58:09.448444 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 97 ms
 2019-12-13 09:58:09.492078 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 97 ms
 2019-12-13 09:58:09.537641 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 95 ms
 2019-12-13 09:58:09.578285 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 94 ms
 2019-12-13 09:58:09.621835 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 92 ms
 2019-12-13 09:58:09.665986 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 90 ms
 2019-12-13 09:58:09.707847 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 90 ms
 2019-12-13 09:58:09.751343 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 88 ms
 2019-12-13 09:58:09.797212 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 87 ms
 2019-12-13 09:58:09.797567 I [16394/16394] CoreContext
 jitterometer.cpp:131:RecordEndTime  Player(1): FPS:   23.01 Mean: 43456
 Std.Dev:  1690 CPUs: 29% 30%
 2019-12-13 09:58:09.837316 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 84 ms
 2019-12-13 09:58:09.880629 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 83 ms
 2019-12-13 09:58:09.924070 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 82 ms
 2019-12-13 09:58:09.966397 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 80 ms
 2019-12-13 09:58:10.011644 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 80 ms
 2019-12-13 09:58:10.053116 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 79 ms
 2019-12-13 09:58:10.095429 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 77 ms
 2019-12-13 09:58:10.139064 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 76 ms
 2019-12-13 09:58:10.182034 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 73 ms
 2019-12-13 09:58:10.224189 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 73 ms
 2019-12-13 09:58:10.269143 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 72 ms
 2019-12-13 09:58:10.310586 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 71 ms
 2019-12-13 09:58:10.352816 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 68 ms
 2019-12-13 09:58:10.395966 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 67 ms
 2019-12-13 09:58:10.439062 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 67 ms
 2019-12-13 09:58:10.481142 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 66 ms
 2019-12-13 09:58:10.526681 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 64 ms
 2019-12-13 09:58:10.567324 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 64 ms
 2019-12-13 09:58:10.609748 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 63 ms
 2019-12-13 09:58:10.652423 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 62 ms
 2019-12-13 09:58:10.695466 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 61 ms
 2019-12-13 09:58:10.737472 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 59 ms
 2019-12-13 09:58:10.782828 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 59 ms
 2019-12-13 09:58:10.823565 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 58 ms
 2019-12-13 09:58:10.823936 I [16394/16394] CoreContext
 jitterometer.cpp:131:RecordEndTime  Player(1): FPS:   23.39 Mean: 42746
 Std.Dev:  1484 CPUs: 31% 32%
 2019-12-13 09:58:10.865570 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 57 ms
 2019-12-13 09:58:10.908425 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 55 ms
 2019-12-13 09:58:10.951290 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 55 ms
 2019-12-13 09:58:10.993158 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 54 ms
 2019-12-13 09:58:11.037832 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 52 ms
 2019-12-13 09:58:11.079475 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 51 ms
 2019-12-13 09:58:11.120888 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 50 ms
 2019-12-13 09:58:11.163708 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 51 ms
 2019-12-13 09:58:11.206934 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 50 ms
 2019-12-13 09:58:11.248289 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 49 ms
 2019-12-13 09:58:11.292856 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 48 ms
 2019-12-13 09:58:11.333950 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 47 ms
 2019-12-13 09:58:11.375774 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 46 ms
 2019-12-13 09:58:11.418522 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 46 ms
 2019-12-13 09:58:11.461215 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 44 ms
 2019-12-13 09:58:11.504776 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 43 ms
 2019-12-13 09:58:11.546088 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 42 ms
 2019-12-13 09:58:11.588412 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 43 ms
 2019-12-13 09:58:11.630144 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 42 ms
 2019-12-13 09:58:11.672840 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 42 ms
 2019-12-13 09:58:11.715562 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 41 ms
 2019-12-13 09:58:11.759231 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 39 ms
 2019-12-13 09:58:11.799834 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 39 ms
 2019-12-13 09:58:11.842527 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 39 ms
 2019-12-13 09:58:11.842913 I [16394/16394] CoreContext
 jitterometer.cpp:131:RecordEndTime  Player(1): FPS:   23.56 Mean: 42436
 Std.Dev:  1041 CPUs: 27% 34%
 2019-12-13 09:58:11.884133 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 38 ms
 2019-12-13 09:58:11.927019 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 36 ms
 2019-12-13 09:58:11.969428 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 36 ms
 2019-12-13 09:58:12.013084 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 37 ms
 2019-12-13 09:58:12.054119 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 36 ms
 2019-12-13 09:58:12.096204 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 34 ms
 2019-12-13 09:58:12.137796 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 34 ms
 2019-12-13 09:58:12.180331 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 34 ms
 2019-12-13 09:58:12.222973 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 34 ms
 2019-12-13 09:58:12.266931 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 33 ms
 2019-12-13 09:58:12.307016 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 31 ms
 2019-12-13 09:58:12.349549 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 31 ms
 2019-12-13 09:58:12.391022 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 31 ms
 2019-12-13 09:58:12.433584 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 31 ms
 2019-12-13 09:58:12.476134 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 31 ms
 2019-12-13 09:58:12.520090 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 30 ms
 2019-12-13 09:58:12.560100 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 28 ms
 2019-12-13 09:58:12.602613 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 29 ms
 2019-12-13 09:58:12.644033 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 29 ms
 2019-12-13 09:58:12.686528 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 28 ms
 2019-12-13 09:58:12.729035 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 26 ms
 2019-12-13 09:58:12.772581 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 27 ms
 2019-12-13 09:58:12.812969 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 26 ms
 2019-12-13 09:58:12.855337 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 26 ms
 2019-12-13 09:58:12.855721 I [16394/16394] CoreContext
 jitterometer.cpp:131:RecordEndTime  Player(1): FPS:   23.71 Mean: 42181
 Std.Dev:  1101 CPUs: 28% 30%
 2019-12-13 09:58:12.896759 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 24 ms
 2019-12-13 09:58:12.939187 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 25 ms
 2019-12-13 09:58:12.981578 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 24 ms
 2019-12-13 09:58:13.025797 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 24 ms
 2019-12-13 09:58:13.065393 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 23 ms
 2019-12-13 09:58:13.108074 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 24 ms
 2019-12-13 09:58:13.149155 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 23 ms
 2019-12-13 09:58:13.191566 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 21 ms
 2019-12-13 09:58:13.233925 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 22 ms
 2019-12-13 09:58:13.277114 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 22 ms
 2019-12-13 09:58:13.317645 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 21 ms
 2019-12-13 09:58:13.443857 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 21 ms
 2019-12-13 09:58:13.485995 I [16394/16394] CoreContext
 mythplayer.cpp:1669:AVSync  Player(1): AV Sync: Audio behind by 21 ms
 2019-12-13 09:58:13.863097 I [16394/16394] CoreContext
 jitterometer.cpp:131:RecordEndTime  Player(1): FPS:   23.83 Mean: 41955
 Std.Dev:  1074 CPUs: 30% 25%
 }}}

-- 
Ticket URL: <https://code.mythtv.org/trac/ticket/13536#comment:7>
MythTV <http://www.mythtv.org>
MythTV Media Center

More information about the mythtv-commits mailing list