Browse code

avfilter/avf_showcqt: add performance debugging log

for easier development

Signed-off-by: Muhammad Faiz <mfcc64@gmail.com>

Muhammad Faiz authored on 2016/03/06 14:54:32
Showing 2 changed files
... ...
@@ -25,6 +25,7 @@
25 25
 #include "libavutil/xga_font_data.h"
26 26
 #include "libavutil/eval.h"
27 27
 #include "libavutil/pixdesc.h"
28
+#include "libavutil/time.h"
28 29
 #include "avfilter.h"
29 30
 #include "internal.h"
30 31
 #include "lavfutils.h"
... ...
@@ -90,7 +91,33 @@ AVFILTER_DEFINE_CLASS(showcqt);
90 90
 static void common_uninit(ShowCQTContext *s)
91 91
 {
92 92
     int k;
93
-
93
+    int level = AV_LOG_DEBUG;
94
+    int64_t plot_time;
95
+
96
+    if (s->fft_time)
97
+        av_log(s->ctx, level, "fft_time         = %16.3f s.\n", s->fft_time * 1e-6);
98
+    if (s->cqt_time)
99
+        av_log(s->ctx, level, "cqt_time         = %16.3f s.\n", s->cqt_time * 1e-6);
100
+    if (s->process_cqt_time)
101
+        av_log(s->ctx, level, "process_cqt_time = %16.3f s.\n", s->process_cqt_time * 1e-6);
102
+    if (s->update_sono_time)
103
+        av_log(s->ctx, level, "update_sono_time = %16.3f s.\n", s->update_sono_time * 1e-6);
104
+    if (s->alloc_time)
105
+        av_log(s->ctx, level, "alloc_time       = %16.3f s.\n", s->alloc_time * 1e-6);
106
+    if (s->bar_time)
107
+        av_log(s->ctx, level, "bar_time         = %16.3f s.\n", s->bar_time * 1e-6);
108
+    if (s->axis_time)
109
+        av_log(s->ctx, level, "axis_time        = %16.3f s.\n", s->axis_time * 1e-6);
110
+    if (s->sono_time)
111
+        av_log(s->ctx, level, "sono_time        = %16.3f s.\n", s->sono_time * 1e-6);
112
+
113
+    plot_time = s->fft_time + s->cqt_time + s->process_cqt_time + s->update_sono_time
114
+              + s->alloc_time + s->bar_time + s->axis_time + s->sono_time;
115
+    if (plot_time)
116
+        av_log(s->ctx, level, "plot_time        = %16.3f s.\n", plot_time * 1e-6);
117
+
118
+    s->fft_time = s->cqt_time = s->process_cqt_time = s->update_sono_time
119
+                = s->alloc_time = s->bar_time = s->axis_time = s->sono_time = 0;
94 120
     /* axis_frame may be non reference counted frame */
95 121
     if (s->axis_frame && !s->axis_frame->buf[0]) {
96 122
         av_freep(s->axis_frame->data);
... ...
@@ -961,25 +988,52 @@ static int plot_cqt(AVFilterContext *ctx, AVFrame **frameout)
961 961
 {
962 962
     AVFilterLink *outlink = ctx->outputs[0];
963 963
     ShowCQTContext *s = ctx->priv;
964
+    int64_t last_time, cur_time;
965
+
966
+#define UPDATE_TIME(t) \
967
+    cur_time = av_gettime(); \
968
+    t += cur_time - last_time; \
969
+    last_time = cur_time
970
+
971
+    last_time = av_gettime();
964 972
 
965 973
     memcpy(s->fft_result, s->fft_data, s->fft_len * sizeof(*s->fft_data));
966 974
     av_fft_permute(s->fft_ctx, s->fft_result);
967 975
     av_fft_calc(s->fft_ctx, s->fft_result);
968 976
     s->fft_result[s->fft_len] = s->fft_result[0];
977
+    UPDATE_TIME(s->fft_time);
978
+
969 979
     s->cqt_calc(s->cqt_result, s->fft_result, s->coeffs, s->cqt_len, s->fft_len);
980
+    UPDATE_TIME(s->cqt_time);
981
+
970 982
     process_cqt(s);
971
-    if (s->sono_h)
983
+    UPDATE_TIME(s->process_cqt_time);
984
+
985
+    if (s->sono_h) {
972 986
         s->update_sono(s->sono_frame, s->c_buf, s->sono_idx);
987
+        UPDATE_TIME(s->update_sono_time);
988
+    }
989
+
973 990
     if (!s->sono_count) {
974 991
         AVFrame *out = *frameout = ff_get_video_buffer(outlink, outlink->w, outlink->h);
975 992
         if (!out)
976 993
             return AVERROR(ENOMEM);
977
-        if (s->bar_h)
994
+        UPDATE_TIME(s->alloc_time);
995
+
996
+        if (s->bar_h) {
978 997
             s->draw_bar(out, s->h_buf, s->rcp_h_buf, s->c_buf, s->bar_h);
979
-        if (s->axis_h)
998
+            UPDATE_TIME(s->bar_time);
999
+        }
1000
+
1001
+        if (s->axis_h) {
980 1002
             s->draw_axis(out, s->axis_frame, s->c_buf, s->bar_h);
981
-        if (s->sono_h)
1003
+            UPDATE_TIME(s->axis_time);
1004
+        }
1005
+
1006
+        if (s->sono_h) {
982 1007
             s->draw_sono(out, s->sono_frame, s->bar_h + s->axis_h, s->sono_idx);
1008
+            UPDATE_TIME(s->sono_time);
1009
+        }
983 1010
         out->pts = s->next_pts;
984 1011
         s->next_pts += PTS_STEP;
985 1012
     }
... ...
@@ -79,6 +79,15 @@ typedef struct {
79 79
     void                (*draw_axis)(AVFrame *out, AVFrame *axis, const ColorFloat *c, int off);
80 80
     void                (*draw_sono)(AVFrame *out, AVFrame *sono, int off, int idx);
81 81
     void                (*update_sono)(AVFrame *sono, const ColorFloat *c, int idx);
82
+    /* performance debugging */
83
+    int64_t             fft_time;
84
+    int64_t             cqt_time;
85
+    int64_t             process_cqt_time;
86
+    int64_t             update_sono_time;
87
+    int64_t             alloc_time;
88
+    int64_t             bar_time;
89
+    int64_t             axis_time;
90
+    int64_t             sono_time;
82 91
     /* option */
83 92
     int                 width, height;
84 93
     AVRational          rate;