summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
Diffstat
-rw-r--r--DOCS/man/en/options.rst8
-rwxr-xr-xTOOLS/stats-conv.py88
-rw-r--r--audio/decode/dec_audio.c11
-rw-r--r--common/msg.c42
-rw-r--r--common/msg.h6
-rw-r--r--common/msg_control.h2
-rw-r--r--options/options.c1
-rw-r--r--options/options.h1
-rw-r--r--player/main.c8
-rw-r--r--player/playloop.c19
-rw-r--r--video/decode/dec_video.c4
11 files changed, 181 insertions, 9 deletions
diff --git a/DOCS/man/en/options.rst b/DOCS/man/en/options.rst
index 9e139c0578..d46ba0e959 100644
--- a/DOCS/man/en/options.rst
+++ b/DOCS/man/en/options.rst
@@ -759,6 +759,14 @@ OPTIONS
Time in milliseconds to recognize two consecutive button presses as a
double-click (default: 300).
+``--dump-stats=<filename>``
+ Write certain statistics to the given file. The file is truncated on
+ opening. The file will contain raw samples, each with a timestamp. To
+ make this file into a readable, the script ``TOOLS/stats-conv.py`` can be
+ used (which currently displays it as a graph).
+
+ This option is useful for debugging only.
+
``--dvbin=<options>``
Pass the following parameters to the DVB input module, in order to
override the default ones:
diff --git a/TOOLS/stats-conv.py b/TOOLS/stats-conv.py
new file mode 100755
index 0000000000..941cb1539e
--- /dev/null
+++ b/TOOLS/stats-conv.py
@@ -0,0 +1,88 @@
+#!/usr/bin/env python3
+import matplotlib.pyplot as plot
+import sys
+
+filename = sys.argv[1]
+
+"""
+This script is meant to display stats written by mpv --dump-stats=filename.
+In general, each line in that file is an event of the form:
+
+ <timestamp in microseconds> <text> '#' <comment>
+
+e.g.:
+
+ 10474959 start flip #cplayer
+
+<text> is what MP_STATS(log, "...") writes. The rest is added by msg.c.
+
+Currently, the following event types are supported:
+
+ 'start' <name> start of the named event
+ 'end' <name> end of the named event
+ 'value' <float> <name> a normal value (as opposed to event)
+ <event> singular event
+
+"""
+
+class G:
+ events = {}
+ sevents = [] # events, deterministically sorted
+ start = None
+
+class Event:
+ pass
+
+def get_event(event):
+ if event not in G.events:
+ e = Event()
+ G.events[event] = e
+ e.name = event
+ e.vals = []
+ e.type = "unknown"
+ G.sevents = list(G.events.values())
+ G.sevents.sort(key=lambda x: x.name)
+ return G.events[event]
+
+for line in [line.split("#")[0].strip() for line in open(filename, "r")]:
+ ts, event = line.split(" ", 1)
+ ts = int(ts) / 1000 # milliseconds
+ if G.start is None:
+ G.start = ts
+ ts = ts - G.start
+ if event.startswith("start "):
+ e = get_event(event[6:])
+ e.type = "event"
+ e.vals.append((ts, 0))
+ e.vals.append((ts, 1))
+ elif event.startswith("end "):
+ e = get_event(event[4:])
+ e.type = "event"
+ e.vals.append((ts, 1))
+ e.vals.append((ts, 0))
+ elif event.startswith("value "):
+ _, val, name = event.split(" ", 2)
+ val = float(val)
+ e = get_event(name)
+ e.type = "value"
+ e.vals.append((ts, val))
+ else:
+ e = get_event(event)
+ e.type = "event-signal"
+ e.vals.append((ts, 1))
+
+plot.hold(True)
+mainpl = plot.subplot(2, 1, 1)
+legend = []
+for e in G.sevents:
+ if e.type == "value":
+ plot.subplot(2, 1, 2, sharex=mainpl)
+ else:
+ plot.subplot(2, 1, 1)
+ pl, = plot.plot([x for x,y in e.vals], [y for x,y in e.vals], label=e.name)
+ if e.type == "event-signal":
+ plot.setp(pl, marker = "o", linestyle = "None")
+ legend.append(pl)
+plot.subplot(2, 1, 1)
+plot.legend(legend, [pl.get_label() for pl in legend])
+plot.show()
diff --git a/audio/decode/dec_audio.c b/audio/decode/dec_audio.c
index b44216ec00..46009c6fdd 100644
--- a/audio/decode/dec_audio.c
+++ b/audio/decode/dec_audio.c
@@ -317,7 +317,9 @@ int audio_decode(struct dec_audio *d_audio, struct mp_audio_buffer *outbuf,
double filter_multiplier = af_calc_filter_multiplier(d_audio->afilter);
int prev_buffered = -1;
- while (minsamples >= 0) {
+ int res = 0;
+ MP_STATS(d_audio, "start audio");
+ while (res >= 0 && minsamples >= 0) {
int buffered = mp_audio_buffer_samples(outbuf);
if (minsamples < buffered || buffered == prev_buffered)
break;
@@ -343,11 +345,10 @@ int audio_decode(struct dec_audio *d_audio, struct mp_audio_buffer *outbuf,
* of buffering in filters */
huge_filter_buffer = 1;
- int res = filter_n_bytes(d_audio, outbuf, decsamples);
- if (res < 0)
- return res;
+ res = filter_n_bytes(d_audio, outbuf, decsamples);
}
- return 0;
+ MP_STATS(d_audio, "end audio");
+ return res;
}
void audio_reset_decoding(struct dec_audio *d_audio)
diff --git a/common/msg.c b/common/msg.c
index 9ee0651a1a..2caa048e40 100644
--- a/common/msg.c
+++ b/common/msg.c
@@ -23,6 +23,7 @@
#include <unistd.h>
#include <assert.h>
#include <pthread.h>
+#include <stdint.h>
#include "talloc.h"
@@ -59,6 +60,7 @@ struct mp_log_root {
bool force_stderr;
struct mp_log_buffer **buffers;
int num_buffers;
+ FILE *stats_file;
// --- semi-atomic access
bool mute;
// --- must be accessed atomically
@@ -119,6 +121,8 @@ static void update_loglevel(struct mp_log *log)
}
for (int n = 0; n < log->root->num_buffers; n++)
log->level = MPMAX(log->level, log->root->buffers[n]->level);
+ if (log->root->stats_file)
+ log->level = MPMAX(log->level, MSGL_STATS);
log->reload_counter = log->root->reload_counter;
pthread_mutex_unlock(&mp_msg_lock);
}
@@ -200,7 +204,7 @@ bool mp_msg_has_status_line(struct mpv_global *global)
static void set_msg_color(FILE* stream, int lev)
{
- static const int v_colors[] = {9, 1, 3, -1, -1, 2, 8, 8, -1};
+ static const int v_colors[] = {9, 1, 3, -1, -1, 2, 8, 8, 8, -1};
terminal_set_foreground_color(stream, v_colors[lev]);
}
@@ -256,6 +260,8 @@ static void print_msg_on_terminal(struct mp_log *log, int lev, char *text)
flush_status_line(root);
size_t len = strlen(text);
root->header = len && text[len - 1] == '\n';
+ if (lev == MSGL_STATS)
+ terminate = "\n";
}
if (root->color)
@@ -320,6 +326,15 @@ static void write_msg_to_buffers(struct mp_log *log, int lev, char *text)
}
}
+static void dump_stats(struct mp_log *log, int lev, char *text)
+{
+ struct mp_log_root *root = log->root;
+ if (lev == MSGL_STATS && root->stats_file) {
+ fprintf(root->stats_file, "%"PRId64" %s #%s\n", mp_time_us(), text,
+ log->verbose_prefix);
+ }
+}
+
void mp_msg_va(struct mp_log *log, int lev, const char *format, va_list va)
{
if (!mp_msg_test(log, lev))
@@ -336,6 +351,7 @@ void mp_msg_va(struct mp_log *log, int lev, const char *format, va_list va)
print_msg_on_terminal(log, lev, text);
write_msg_to_buffers(log, lev, text);
+ dump_stats(log, lev, text);
pthread_mutex_unlock(&mp_msg_lock);
}
@@ -438,7 +454,10 @@ void mp_msg_force_stderr(struct mpv_global *global, bool force_stderr)
void mp_msg_uninit(struct mpv_global *global)
{
- talloc_free(global->log->root);
+ struct mp_log_root *root = global->log->root;
+ if (root->stats_file)
+ fclose(root->stats_file);
+ talloc_free(root);
global->log = NULL;
}
@@ -514,6 +533,24 @@ struct mp_log_buffer_entry *mp_msg_log_buffer_read(struct mp_log_buffer *buffer)
return ptr;
}
+int mp_msg_open_stats_file(struct mpv_global *global, const char *path)
+{
+ struct mp_log_root *root = global->log->root;
+ int r;
+
+ pthread_mutex_lock(&mp_msg_lock);
+
+ if (root->stats_file)
+ fclose(root->stats_file);
+ root->stats_file = fopen(path, "wb");
+ r = root->stats_file ? 0 : -1;
+
+ pthread_mutex_unlock(&mp_msg_lock);
+
+ mp_msg_update_msglevels(global);
+ return r;
+}
+
// Thread-safety: fully thread-safe, but keep in mind that the lifetime of
// log must be guaranteed during the call.
// Never call this from signal handlers.
@@ -534,6 +571,7 @@ char *mp_log_levels[MSGL_MAX + 1] = {
[MSGL_V] = "v",
[MSGL_DEBUG] = "debug",
[MSGL_TRACE] = "trace",
+ [MSGL_STATS] = "stats",
};
int mp_msg_split_msglevel(struct bstr *s, struct bstr *out_mod, int *out_level)
diff --git a/common/msg.h b/common/msg.h
index d56ce13976..61997e946d 100644
--- a/common/msg.h
+++ b/common/msg.h
@@ -41,6 +41,7 @@ enum {
MSGL_V, // -v
MSGL_DEBUG, // -v -v
MSGL_TRACE, // -v -v -v
+ MSGL_STATS, // dumping fine grained stats (--dump-stats)
MSGL_SMODE, // old slave mode (-identify)
MSGL_MAX = MSGL_SMODE,
@@ -78,4 +79,9 @@ bool mp_msg_test(struct mp_log *log, int lev);
#define MP_TRACE(obj, ...) MP_MSG(obj, MSGL_TRACE, __VA_ARGS__)
#define MP_SMODE(obj, ...) MP_MSG(obj, MSGL_SMODE, __VA_ARGS__)
+// This is a bit special. See TOOLS/stats-conv.py what rules text passed
+// to these functions should follow. Also see --dump-stats.
+#define mp_stats(obj, ...) mp_msg(obj, MSGL_STATS, __VA_ARGS__)
+#define MP_STATS(obj, ...) MP_MSG(obj, MSGL_STATS, __VA_ARGS__)
+
#endif /* MPLAYER_MP_MSG_H */
diff --git a/common/msg_control.h b/common/msg_control.h
index ecce7ca0eb..49eeee025c 100644
--- a/common/msg_control.h
+++ b/common/msg_control.h
@@ -24,6 +24,8 @@ struct mp_log_buffer *mp_msg_log_buffer_new(struct mpv_global *global,
void mp_msg_log_buffer_destroy(struct mp_log_buffer *buffer);
struct mp_log_buffer_entry *mp_msg_log_buffer_read(struct mp_log_buffer *buffer);
+int mp_msg_open_stats_file(struct mpv_global *global, const char *path);
+
struct bstr;
int mp_msg_split_msglevel(struct bstr *s, struct bstr *out_mod, int *out_level);
diff --git a/options/options.c b/options/options.c
index 82b81b049d..eabdeb0520 100644
--- a/options/options.c
+++ b/options/options.c
@@ -217,6 +217,7 @@ const m_option_t mp_opts[] = {
OPT_FLAG("terminal", use_terminal, CONF_GLOBAL | CONF_PRE_PARSE),
OPT_GENERAL(char*, "msglevel", msglevels, CONF_GLOBAL|CONF_PRE_PARSE,
.type = &m_option_type_msglevels),
+ OPT_STRING("dump-stats", dump_stats, CONF_GLOBAL | CONF_PRE_PARSE),
OPT_FLAG("msgcolor", msg_color, CONF_GLOBAL | CONF_PRE_PARSE),
OPT_FLAG("msgmodule", msg_module, CONF_GLOBAL),
OPT_FLAG("msgtime", msg_time, CONF_GLOBAL),
diff --git a/options/options.h b/options/options.h
index 3572789c5a..9bd60c2630 100644
--- a/options/options.h
+++ b/options/options.h
@@ -46,6 +46,7 @@ typedef struct mp_vo_opts {
typedef struct MPOpts {
int use_terminal;
char *msglevels;
+ char *dump_stats;
int verbose;
int msg_identify;
int msg_color;
diff --git a/player/main.c b/player/main.c
index 3a6084658c..dc685b84f7 100644
--- a/player/main.c
+++ b/player/main.c
@@ -366,6 +366,12 @@ int mp_initialize(struct MPContext *mpctx)
assert(!mpctx->initialized);
+ if (opts->dump_stats && opts->dump_stats[0]) {
+ if (mp_msg_open_stats_file(mpctx->global, opts->dump_stats) < 0)
+ MP_ERR(mpctx, "Failed to open stats file '%s'\n", opts->dump_stats);
+ }
+ MP_STATS(mpctx, "start init");
+
if (mpctx->opts->use_terminal && !terminal_initialized) {
terminal_initialized = true;
terminal_init();
@@ -452,6 +458,8 @@ int mp_initialize(struct MPContext *mpctx)
if (!mpctx->playlist->current)
mpctx->playlist->current = mpctx->playlist->first;
+ MP_STATS(mpctx, "end init");
+
return 0;
}
diff --git a/player/playloop.c b/player/playloop.c
index 84da8d231a..2495579c39 100644
--- a/player/playloop.c
+++ b/player/playloop.c
@@ -1030,6 +1030,7 @@ void run_playloop(struct MPContext *mpctx)
}
mpctx->time_frame -= get_relative_time(mpctx);
+ double audio_pts = playing_audio_pts(mpctx);
if (full_audio_buffers && !mpctx->restart_playback) {
buffered_audio = ao_get_delay(mpctx->ao);
MP_TRACE(mpctx, "audio delay=%f\n", buffered_audio);
@@ -1076,14 +1077,21 @@ void run_playloop(struct MPContext *mpctx)
//=================== FLIP PAGE (VIDEO BLT): ======================
+ MP_STATS(mpctx, "vo draw frame");
+
vo_new_frame_imminent(vo);
mpctx->video_pts = mpctx->video_next_pts;
mpctx->last_vo_pts = mpctx->video_pts;
mpctx->playback_pts = mpctx->video_pts;
+
update_subtitles(mpctx);
update_osd_msg(mpctx);
+
+ MP_STATS(mpctx, "draw OSD");
draw_osd(mpctx);
+ MP_STATS(mpctx, "vo sleep");
+
mpctx->time_frame -= get_relative_time(mpctx);
mpctx->time_frame -= vo->flip_queue_offset;
if (mpctx->time_frame > 0.001)
@@ -1120,7 +1128,13 @@ void run_playloop(struct MPContext *mpctx)
}
if (mpctx->restart_playback)
duration = -1;
+
+ MP_STATS(mpctx, "start flip");
vo_flip_page(vo, pts_us | 1, duration);
+ MP_STATS(mpctx, "end flip");
+
+ if (audio_pts != MP_NOPTS_VALUE)
+ MP_STATS(mpctx, "value %f ptsdiff", mpctx->video_pts - audio_pts);
mpctx->last_vo_flip_duration = (mp_time_us() - t2) * 0.000001;
if (vo->driver->flip_page_timed) {
@@ -1256,8 +1270,11 @@ void run_playloop(struct MPContext *mpctx)
if (handle_osd_redraw(mpctx))
sleeptime = 0;
}
- if (sleeptime > 0)
+ if (sleeptime > 0) {
+ MP_STATS(mpctx, "start sleep");
mp_input_get_cmd(mpctx->input, sleeptime * 1000, true);
+ MP_STATS(mpctx, "end sleep");
+ }
}
handle_metadata_update(mpctx);
diff --git a/video/decode/dec_video.c b/video/decode/dec_video.c
index 5c75194e75..cb541e6207 100644
--- a/video/decode/dec_video.c
+++ b/video/decode/dec_video.c
@@ -303,9 +303,11 @@ struct mp_image *video_decode(struct dec_video *d_video,
double prev_codec_pts = d_video->codec_pts;
double prev_codec_dts = d_video->codec_dts;
+ MP_STATS(d_video, "start decode video");
+
struct mp_image *mpi = d_video->vd_driver->decode(d_video, packet, drop_frame);
- //------------------------ frame decoded. --------------------
+ MP_STATS(d_video, "end decode video");
if (!mpi || drop_frame) {
talloc_free(mpi);
generated by cgit v1.2.3 (git 2.25.1) at 2024-04-26 15:44:17 +0000