[PATCH] ffprobe: Support adding av_log output to frames
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread. doc/ffprobe.xsd update missing (TODO & help welcome) Fixes Ticket5521 Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-) diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h" +#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif + typedef struct InputStream { AVStream *st; @@ -84,6 +97,7 @@ static int do_show_library_versions = 0; static int do_show_pixel_formats = 0; static int do_show_pixel_format_flags = 0; static int do_show_pixel_format_components = 0; +static int do_show_log = 0; static int do_show_chapter_tags = 0; static int do_show_format_tags = 0; @@ -92,6 +106,7 @@ static int do_show_program_tags = 0; static int do_show_stream_tags = 0; static int do_show_packet_tags = 0; + static int show_value_unit = 0; static int use_value_prefix = 0; static int use_byte_value_binary_prefix = 0; @@ -146,6 +161,8 @@ typedef enum { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_SIDE_DATA, + SECTION_ID_FRAME_LOG, + SECTION_ID_FRAME_LOGS, SECTION_ID_LIBRARY_VERSION, SECTION_ID_LIBRARY_VERSIONS, SECTION_ID_PACKET, @@ -185,10 +202,12 @@ static struct section sections[] = { [SECTION_ID_FORMAT] = { SECTION_ID_FORMAT, "format", 0, { SECTION_ID_FORMAT_TAGS, -1 } }, [SECTION_ID_FORMAT_TAGS] = { SECTION_ID_FORMAT_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "format_tags" }, [SECTION_ID_FRAMES] = { SECTION_ID_FRAMES, "frames", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME, SECTION_ID_SUBTITLE, -1 } }, - [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, -1 } }, + [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_LOGS, -1 } }, [SECTION_ID_FRAME_TAGS] = { SECTION_ID_FRAME_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "frame_tags" }, [SECTION_ID_FRAME_SIDE_DATA_LIST] ={ SECTION_ID_FRAME_SIDE_DATA_LIST, "side_data_list", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_SIDE_DATA, -1 } }, [SECTION_ID_FRAME_SIDE_DATA] = { SECTION_ID_FRAME_SIDE_DATA, "side_data", 0, { -1 } }, + [SECTION_ID_FRAME_LOGS] = { SECTION_ID_FRAME_LOGS, "logs", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_LOG, -1 } }, + [SECTION_ID_FRAME_LOG] = { SECTION_ID_FRAME_LOG, "log", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 } }, [SECTION_ID_LIBRARY_VERSIONS] = { SECTION_ID_LIBRARY_VERSIONS, "library_versions", SECTION_FLAG_IS_ARRAY, { SECTION_ID_LIBRARY_VERSION, -1 } }, [SECTION_ID_LIBRARY_VERSION] = { SECTION_ID_LIBRARY_VERSION, "library_version", 0, { -1 } }, [SECTION_ID_PACKETS] = { SECTION_ID_PACKETS, "packets", SECTION_FLAG_IS_ARRAY, { SECTION_ID_PACKET, -1} }, @@ -255,11 +274,73 @@ static uint64_t *nb_streams_packets; static uint64_t *nb_streams_frames; static int *selected_streams; +#if HAVE_PTHREADS +pthread_mutex_t log_mutex; +#endif +typedef struct LogBuffer { + char *context_name; + int log_level; + char *log_message; + AVClassCategory category; + char *parent_name; + AVClassCategory parent_category; +}LogBuffer; + +static LogBuffer *log_buffer; +static int log_buffer_size; + +static void log_callback(void *ptr, int level, const char *fmt, va_list vl) +{ + AVClass* avc = ptr ? *(AVClass **) ptr : NULL; + va_list vl2; + char line[1024]; + static int print_prefix = 1; + void *new_log_buffer; + + va_copy(vl2, vl); + av_log_default_callback(ptr, level, fmt, vl); + av_log_format_line(ptr, level, fmt, vl2, line, sizeof(line), &print_prefix); + va_end(vl2); + +#if HAVE_PTHREADS + pthread_mutex_lock(&log_mutex); + + new_log_buffer = av_realloc_array(log_buffer, log_buffer_size + 1, sizeof(*log_buffer)); + if (new_log_buffer) { + log_buffer = new_log_buffer; + memset(&log_buffer[log_buffer_size], 0, sizeof(log_buffer[log_buffer_size])); + log_buffer[log_buffer_size].context_name= avc ? av_strdup(avc->item_name(ptr)) : NULL; + if (avc) { + if (avc->get_category) log_buffer[log_buffer_size].category = avc->get_category(ptr); + else log_buffer[log_buffer_size].category = avc->category; + } + log_buffer[log_buffer_size].log_level = level; + log_buffer[log_buffer_size].log_message = av_strdup(line); + if (avc && avc->parent_log_context_offset) { + AVClass** parent = *(AVClass ***) (((uint8_t *) ptr) + + avc->parent_log_context_offset); + if (parent && *parent) { + log_buffer[log_buffer_size].parent_name = av_strdup((*parent)->item_name(parent)); + log_buffer[log_buffer_size].parent_category = + (*parent)->get_category ? (*parent)->get_category(parent) :(*parent)->category; + } + } + log_buffer_size ++; + } + + pthread_mutex_unlock(&log_mutex); +#endif +} + static void ffprobe_cleanup(int ret) { int i; for (i = 0; i < FF_ARRAY_ELEMS(sections); i++) av_dict_free(&(sections[i].entries_to_show)); + +#if HAVE_PTHREADS + pthread_mutex_destroy(&log_mutex); +#endif } struct unit_value { @@ -1759,6 +1840,56 @@ static inline int show_tags(WriterContext *w, AVDictionary *tags, int section_id return ret; } +static void clear_log(int need_lock) +{ + int i; + + if (need_lock) + pthread_mutex_lock(&log_mutex); + for (i=0; i<log_buffer_size; i++) { + av_freep(&log_buffer[i].context_name); + av_freep(&log_buffer[i].log_message); + } + log_buffer_size = 0; + if(need_lock) + pthread_mutex_unlock(&log_mutex); +} + +static int show_log(WriterContext *w, int section_ids, int section_id, int log_level) +{ + int i; + pthread_mutex_lock(&log_mutex); + if (!log_buffer_size) { + pthread_mutex_unlock(&log_mutex); + return 0; + } + writer_print_section_header(w, section_ids); + + for (i=0; i<log_buffer_size; i++) { + if (log_buffer[i].log_level <= log_level) { + writer_print_section_header(w, section_id); + print_str("context", log_buffer[i].context_name); + print_int("level", log_buffer[i].log_level); + print_int("category", log_buffer[i].category); + if (log_buffer[i].parent_name) { + print_str("parent_context", log_buffer[i].parent_name); + print_int("parent_category", log_buffer[i].parent_category); + } else { + print_str_opt("parent_context", "N/A"); + print_str_opt("parent_category", "N/A"); + } + print_str("message", log_buffer[i].log_message); + writer_print_section_footer(w); + } + } + clear_log(0); + pthread_mutex_unlock(&log_mutex); + + writer_print_section_footer(w); + + return 0; +} + static void show_packet(WriterContext *w, InputFile *ifile, AVPacket *pkt, int packet_idx) { char val_str[128]; @@ -1917,6 +2048,8 @@ static void show_frame(WriterContext *w, AVFrame *frame, AVStream *stream, } if (do_show_frame_tags) show_tags(w, av_frame_get_metadata(frame), SECTION_ID_FRAME_TAGS); + if (do_show_log) + show_log(w, SECTION_ID_FRAME_LOGS, SECTION_ID_FRAME_LOG, do_show_log); if (frame->nb_side_data) { writer_print_section_header(w, SECTION_ID_FRAME_SIDE_DATA_LIST); for (i = 0; i < frame->nb_side_data; i++) { @@ -1956,6 +2089,7 @@ static av_always_inline int process_frame(WriterContext *w, AVSubtitle sub; int ret = 0, got_frame = 0; + clear_log(1); if (dec_ctx && dec_ctx->codec) { switch (par->codec_type) { case AVMEDIA_TYPE_VIDEO: @@ -2604,6 +2738,13 @@ static int open_input_file(InputFile *ifile, const char *filename) if (err < 0) exit(1); + if (do_show_log) { + // For loging it is needed to disable at least frame threads as otherwise + // the log information would need to be reordered and matches up to contexts and frames + // That is in fact possible but not trivial + av_dict_set(&codec_opts, "threads", "1", 0); + } + ist->dec_ctx->pkt_timebase = stream->time_base; #if FF_API_LAVF_AVCTX ist->dec_ctx->time_base = stream->codec->time_base; @@ -3191,6 +3332,9 @@ static const OptionDef real_options[] = { "show a particular entry from the format/container info", "entry" }, { "show_entries", HAS_ARG, {.func_arg = opt_show_entries}, "show a set of specified entries", "entry_list" }, +#if HAVE_PTHREADS + { "show_log", OPT_INT|HAS_ARG, {(void*)&do_show_log}, "show log" }, +#endif { "show_packets", 0, {(void*)&opt_show_packets}, "show packets info" }, { "show_programs", 0, {(void*)&opt_show_programs}, "show programs info" }, { "show_streams", 0, {(void*)&opt_show_streams}, "show streams info" }, @@ -3235,6 +3379,14 @@ int main(int argc, char **argv) char *w_name = NULL, *w_args = NULL; int ret, i; +#if HAVE_PTHREADS + ret = pthread_mutex_init(&log_mutex, NULL); + if (ret != 0) { + goto end; + } +#endif + av_log_set_callback(log_callback); + av_log_set_flags(AV_LOG_SKIP_REPEATED); register_exit(ffprobe_cleanup); -- 1.7.9.5
On May 31, 2016, at 3:23 PM, Michael Niedermayer <michael@niedermayer.cc> wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
I'll volunteer to do the ffprobe.xsd output. Thanks much. Dave Rice
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif + typedef struct InputStream { AVStream *st;
@@ -84,6 +97,7 @@ static int do_show_library_versions = 0; static int do_show_pixel_formats = 0; static int do_show_pixel_format_flags = 0; static int do_show_pixel_format_components = 0; +static int do_show_log = 0;
static int do_show_chapter_tags = 0; static int do_show_format_tags = 0; @@ -92,6 +106,7 @@ static int do_show_program_tags = 0; static int do_show_stream_tags = 0; static int do_show_packet_tags = 0;
+ static int show_value_unit = 0; static int use_value_prefix = 0; static int use_byte_value_binary_prefix = 0; @@ -146,6 +161,8 @@ typedef enum { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_SIDE_DATA, + SECTION_ID_FRAME_LOG, + SECTION_ID_FRAME_LOGS, SECTION_ID_LIBRARY_VERSION, SECTION_ID_LIBRARY_VERSIONS, SECTION_ID_PACKET, @@ -185,10 +202,12 @@ static struct section sections[] = { [SECTION_ID_FORMAT] = { SECTION_ID_FORMAT, "format", 0, { SECTION_ID_FORMAT_TAGS, -1 } }, [SECTION_ID_FORMAT_TAGS] = { SECTION_ID_FORMAT_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "format_tags" }, [SECTION_ID_FRAMES] = { SECTION_ID_FRAMES, "frames", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME, SECTION_ID_SUBTITLE, -1 } }, - [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, -1 } }, + [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_LOGS, -1 } }, [SECTION_ID_FRAME_TAGS] = { SECTION_ID_FRAME_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "frame_tags" }, [SECTION_ID_FRAME_SIDE_DATA_LIST] ={ SECTION_ID_FRAME_SIDE_DATA_LIST, "side_data_list", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_SIDE_DATA, -1 } }, [SECTION_ID_FRAME_SIDE_DATA] = { SECTION_ID_FRAME_SIDE_DATA, "side_data", 0, { -1 } }, + [SECTION_ID_FRAME_LOGS] = { SECTION_ID_FRAME_LOGS, "logs", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_LOG, -1 } }, + [SECTION_ID_FRAME_LOG] = { SECTION_ID_FRAME_LOG, "log", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 } }, [SECTION_ID_LIBRARY_VERSIONS] = { SECTION_ID_LIBRARY_VERSIONS, "library_versions", SECTION_FLAG_IS_ARRAY, { SECTION_ID_LIBRARY_VERSION, -1 } }, [SECTION_ID_LIBRARY_VERSION] = { SECTION_ID_LIBRARY_VERSION, "library_version", 0, { -1 } }, [SECTION_ID_PACKETS] = { SECTION_ID_PACKETS, "packets", SECTION_FLAG_IS_ARRAY, { SECTION_ID_PACKET, -1} }, @@ -255,11 +274,73 @@ static uint64_t *nb_streams_packets; static uint64_t *nb_streams_frames; static int *selected_streams;
+#if HAVE_PTHREADS +pthread_mutex_t log_mutex; +#endif +typedef struct LogBuffer { + char *context_name; + int log_level; + char *log_message; + AVClassCategory category; + char *parent_name; + AVClassCategory parent_category; +}LogBuffer; + +static LogBuffer *log_buffer; +static int log_buffer_size; + +static void log_callback(void *ptr, int level, const char *fmt, va_list vl) +{ + AVClass* avc = ptr ? *(AVClass **) ptr : NULL; + va_list vl2; + char line[1024]; + static int print_prefix = 1; + void *new_log_buffer; + + va_copy(vl2, vl); + av_log_default_callback(ptr, level, fmt, vl); + av_log_format_line(ptr, level, fmt, vl2, line, sizeof(line), &print_prefix); + va_end(vl2); + +#if HAVE_PTHREADS + pthread_mutex_lock(&log_mutex); + + new_log_buffer = av_realloc_array(log_buffer, log_buffer_size + 1, sizeof(*log_buffer)); + if (new_log_buffer) { + log_buffer = new_log_buffer; + memset(&log_buffer[log_buffer_size], 0, sizeof(log_buffer[log_buffer_size])); + log_buffer[log_buffer_size].context_name= avc ? av_strdup(avc->item_name(ptr)) : NULL; + if (avc) { + if (avc->get_category) log_buffer[log_buffer_size].category = avc->get_category(ptr); + else log_buffer[log_buffer_size].category = avc->category; + } + log_buffer[log_buffer_size].log_level = level; + log_buffer[log_buffer_size].log_message = av_strdup(line); + if (avc && avc->parent_log_context_offset) { + AVClass** parent = *(AVClass ***) (((uint8_t *) ptr) + + avc->parent_log_context_offset); + if (parent && *parent) { + log_buffer[log_buffer_size].parent_name = av_strdup((*parent)->item_name(parent)); + log_buffer[log_buffer_size].parent_category = + (*parent)->get_category ? (*parent)->get_category(parent) :(*parent)->category; + } + } + log_buffer_size ++; + } + + pthread_mutex_unlock(&log_mutex); +#endif +} + static void ffprobe_cleanup(int ret) { int i; for (i = 0; i < FF_ARRAY_ELEMS(sections); i++) av_dict_free(&(sections[i].entries_to_show)); + +#if HAVE_PTHREADS + pthread_mutex_destroy(&log_mutex); +#endif }
struct unit_value { @@ -1759,6 +1840,56 @@ static inline int show_tags(WriterContext *w, AVDictionary *tags, int section_id return ret; }
+static void clear_log(int need_lock) +{ + int i; + + if (need_lock) + pthread_mutex_lock(&log_mutex); + for (i=0; i<log_buffer_size; i++) { + av_freep(&log_buffer[i].context_name); + av_freep(&log_buffer[i].log_message); + } + log_buffer_size = 0; + if(need_lock) + pthread_mutex_unlock(&log_mutex); +} + +static int show_log(WriterContext *w, int section_ids, int section_id, int log_level) +{ + int i; + pthread_mutex_lock(&log_mutex); + if (!log_buffer_size) { + pthread_mutex_unlock(&log_mutex); + return 0; + } + writer_print_section_header(w, section_ids); + + for (i=0; i<log_buffer_size; i++) { + if (log_buffer[i].log_level <= log_level) { + writer_print_section_header(w, section_id); + print_str("context", log_buffer[i].context_name); + print_int("level", log_buffer[i].log_level); + print_int("category", log_buffer[i].category); + if (log_buffer[i].parent_name) { + print_str("parent_context", log_buffer[i].parent_name); + print_int("parent_category", log_buffer[i].parent_category); + } else { + print_str_opt("parent_context", "N/A"); + print_str_opt("parent_category", "N/A"); + } + print_str("message", log_buffer[i].log_message); + writer_print_section_footer(w); + } + } + clear_log(0); + pthread_mutex_unlock(&log_mutex); + + writer_print_section_footer(w); + + return 0; +} + static void show_packet(WriterContext *w, InputFile *ifile, AVPacket *pkt, int packet_idx) { char val_str[128]; @@ -1917,6 +2048,8 @@ static void show_frame(WriterContext *w, AVFrame *frame, AVStream *stream, } if (do_show_frame_tags) show_tags(w, av_frame_get_metadata(frame), SECTION_ID_FRAME_TAGS); + if (do_show_log) + show_log(w, SECTION_ID_FRAME_LOGS, SECTION_ID_FRAME_LOG, do_show_log); if (frame->nb_side_data) { writer_print_section_header(w, SECTION_ID_FRAME_SIDE_DATA_LIST); for (i = 0; i < frame->nb_side_data; i++) { @@ -1956,6 +2089,7 @@ static av_always_inline int process_frame(WriterContext *w, AVSubtitle sub; int ret = 0, got_frame = 0;
+ clear_log(1); if (dec_ctx && dec_ctx->codec) { switch (par->codec_type) { case AVMEDIA_TYPE_VIDEO: @@ -2604,6 +2738,13 @@ static int open_input_file(InputFile *ifile, const char *filename) if (err < 0) exit(1);
+ if (do_show_log) { + // For loging it is needed to disable at least frame threads as otherwise + // the log information would need to be reordered and matches up to contexts and frames + // That is in fact possible but not trivial + av_dict_set(&codec_opts, "threads", "1", 0); + } + ist->dec_ctx->pkt_timebase = stream->time_base; #if FF_API_LAVF_AVCTX ist->dec_ctx->time_base = stream->codec->time_base; @@ -3191,6 +3332,9 @@ static const OptionDef real_options[] = { "show a particular entry from the format/container info", "entry" }, { "show_entries", HAS_ARG, {.func_arg = opt_show_entries}, "show a set of specified entries", "entry_list" }, +#if HAVE_PTHREADS + { "show_log", OPT_INT|HAS_ARG, {(void*)&do_show_log}, "show log" }, +#endif { "show_packets", 0, {(void*)&opt_show_packets}, "show packets info" }, { "show_programs", 0, {(void*)&opt_show_programs}, "show programs info" }, { "show_streams", 0, {(void*)&opt_show_streams}, "show streams info" }, @@ -3235,6 +3379,14 @@ int main(int argc, char **argv) char *w_name = NULL, *w_args = NULL; int ret, i;
+#if HAVE_PTHREADS + ret = pthread_mutex_init(&log_mutex, NULL); + if (ret != 0) { + goto end; + } +#endif + av_log_set_callback(log_callback); + av_log_set_flags(AV_LOG_SKIP_REPEATED); register_exit(ffprobe_cleanup);
-- 1.7.9.5
_______________________________________________ ffmpeg-devel mailing list ffmpeg-devel@ffmpeg.org http://ffmpeg.org/mailman/listinfo/ffmpeg-devel
On date Tuesday 2016-05-31 21:23:27 +0200, Michael Niedermayer encoded:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif +
any chance to move this ifdeffery to lavu?
typedef struct InputStream { AVStream *st;
@@ -84,6 +97,7 @@ static int do_show_library_versions = 0; static int do_show_pixel_formats = 0; static int do_show_pixel_format_flags = 0; static int do_show_pixel_format_components = 0; +static int do_show_log = 0;
static int do_show_chapter_tags = 0; static int do_show_format_tags = 0; @@ -92,6 +106,7 @@ static int do_show_program_tags = 0; static int do_show_stream_tags = 0; static int do_show_packet_tags = 0;
+ static int show_value_unit = 0; static int use_value_prefix = 0; static int use_byte_value_binary_prefix = 0; @@ -146,6 +161,8 @@ typedef enum { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_SIDE_DATA, + SECTION_ID_FRAME_LOG, + SECTION_ID_FRAME_LOGS, SECTION_ID_LIBRARY_VERSION, SECTION_ID_LIBRARY_VERSIONS, SECTION_ID_PACKET, @@ -185,10 +202,12 @@ static struct section sections[] = { [SECTION_ID_FORMAT] = { SECTION_ID_FORMAT, "format", 0, { SECTION_ID_FORMAT_TAGS, -1 } }, [SECTION_ID_FORMAT_TAGS] = { SECTION_ID_FORMAT_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "format_tags" }, [SECTION_ID_FRAMES] = { SECTION_ID_FRAMES, "frames", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME, SECTION_ID_SUBTITLE, -1 } }, - [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, -1 } }, + [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_LOGS, -1 } }, [SECTION_ID_FRAME_TAGS] = { SECTION_ID_FRAME_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "frame_tags" }, [SECTION_ID_FRAME_SIDE_DATA_LIST] ={ SECTION_ID_FRAME_SIDE_DATA_LIST, "side_data_list", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_SIDE_DATA, -1 } }, [SECTION_ID_FRAME_SIDE_DATA] = { SECTION_ID_FRAME_SIDE_DATA, "side_data", 0, { -1 } }, + [SECTION_ID_FRAME_LOGS] = { SECTION_ID_FRAME_LOGS, "logs", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_LOG, -1 } }, + [SECTION_ID_FRAME_LOG] = { SECTION_ID_FRAME_LOG, "log", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 } }, [SECTION_ID_LIBRARY_VERSIONS] = { SECTION_ID_LIBRARY_VERSIONS, "library_versions", SECTION_FLAG_IS_ARRAY, { SECTION_ID_LIBRARY_VERSION, -1 } }, [SECTION_ID_LIBRARY_VERSION] = { SECTION_ID_LIBRARY_VERSION, "library_version", 0, { -1 } }, [SECTION_ID_PACKETS] = { SECTION_ID_PACKETS, "packets", SECTION_FLAG_IS_ARRAY, { SECTION_ID_PACKET, -1} }, @@ -255,11 +274,73 @@ static uint64_t *nb_streams_packets; static uint64_t *nb_streams_frames; static int *selected_streams;
+#if HAVE_PTHREADS +pthread_mutex_t log_mutex; +#endif +typedef struct LogBuffer { + char *context_name; + int log_level; + char *log_message; + AVClassCategory category; + char *parent_name; + AVClassCategory parent_category; +}LogBuffer; + +static LogBuffer *log_buffer; +static int log_buffer_size; + +static void log_callback(void *ptr, int level, const char *fmt, va_list vl) +{ + AVClass* avc = ptr ? *(AVClass **) ptr : NULL; + va_list vl2; + char line[1024]; + static int print_prefix = 1; + void *new_log_buffer; + + va_copy(vl2, vl); + av_log_default_callback(ptr, level, fmt, vl); + av_log_format_line(ptr, level, fmt, vl2, line, sizeof(line), &print_prefix); + va_end(vl2); + +#if HAVE_PTHREADS + pthread_mutex_lock(&log_mutex); + + new_log_buffer = av_realloc_array(log_buffer, log_buffer_size + 1, sizeof(*log_buffer)); + if (new_log_buffer) { + log_buffer = new_log_buffer; + memset(&log_buffer[log_buffer_size], 0, sizeof(log_buffer[log_buffer_size])); + log_buffer[log_buffer_size].context_name= avc ? av_strdup(avc->item_name(ptr)) : NULL; + if (avc) { + if (avc->get_category) log_buffer[log_buffer_size].category = avc->get_category(ptr); + else log_buffer[log_buffer_size].category = avc->category; + } + log_buffer[log_buffer_size].log_level = level; + log_buffer[log_buffer_size].log_message = av_strdup(line); + if (avc && avc->parent_log_context_offset) { + AVClass** parent = *(AVClass ***) (((uint8_t *) ptr) + + avc->parent_log_context_offset); + if (parent && *parent) { + log_buffer[log_buffer_size].parent_name = av_strdup((*parent)->item_name(parent)); + log_buffer[log_buffer_size].parent_category = + (*parent)->get_category ? (*parent)->get_category(parent) :(*parent)->category; + } + } + log_buffer_size ++; + } + + pthread_mutex_unlock(&log_mutex); +#endif +} + static void ffprobe_cleanup(int ret) { int i; for (i = 0; i < FF_ARRAY_ELEMS(sections); i++) av_dict_free(&(sections[i].entries_to_show)); + +#if HAVE_PTHREADS + pthread_mutex_destroy(&log_mutex); +#endif }
struct unit_value { @@ -1759,6 +1840,56 @@ static inline int show_tags(WriterContext *w, AVDictionary *tags, int section_id return ret; }
+static void clear_log(int need_lock) +{ + int i; + + if (need_lock) + pthread_mutex_lock(&log_mutex); + for (i=0; i<log_buffer_size; i++) { + av_freep(&log_buffer[i].context_name); + av_freep(&log_buffer[i].log_message); + } + log_buffer_size = 0; + if(need_lock) + pthread_mutex_unlock(&log_mutex); +} + +static int show_log(WriterContext *w, int section_ids, int section_id, int log_level) +{ + int i; + pthread_mutex_lock(&log_mutex); + if (!log_buffer_size) { + pthread_mutex_unlock(&log_mutex); + return 0; + } + writer_print_section_header(w, section_ids); + + for (i=0; i<log_buffer_size; i++) { + if (log_buffer[i].log_level <= log_level) { + writer_print_section_header(w, section_id); + print_str("context", log_buffer[i].context_name); + print_int("level", log_buffer[i].log_level); + print_int("category", log_buffer[i].category); + if (log_buffer[i].parent_name) { + print_str("parent_context", log_buffer[i].parent_name); + print_int("parent_category", log_buffer[i].parent_category); + } else { + print_str_opt("parent_context", "N/A"); + print_str_opt("parent_category", "N/A"); + } + print_str("message", log_buffer[i].log_message); + writer_print_section_footer(w); + } + } + clear_log(0); + pthread_mutex_unlock(&log_mutex); + + writer_print_section_footer(w); + + return 0; +} + static void show_packet(WriterContext *w, InputFile *ifile, AVPacket *pkt, int packet_idx) { char val_str[128]; @@ -1917,6 +2048,8 @@ static void show_frame(WriterContext *w, AVFrame *frame, AVStream *stream, } if (do_show_frame_tags) show_tags(w, av_frame_get_metadata(frame), SECTION_ID_FRAME_TAGS); + if (do_show_log) + show_log(w, SECTION_ID_FRAME_LOGS, SECTION_ID_FRAME_LOG, do_show_log); if (frame->nb_side_data) { writer_print_section_header(w, SECTION_ID_FRAME_SIDE_DATA_LIST); for (i = 0; i < frame->nb_side_data; i++) { @@ -1956,6 +2089,7 @@ static av_always_inline int process_frame(WriterContext *w, AVSubtitle sub; int ret = 0, got_frame = 0;
+ clear_log(1); if (dec_ctx && dec_ctx->codec) { switch (par->codec_type) { case AVMEDIA_TYPE_VIDEO: @@ -2604,6 +2738,13 @@ static int open_input_file(InputFile *ifile, const char *filename) if (err < 0) exit(1);
+ if (do_show_log) { + // For loging it is needed to disable at least frame threads as otherwise + // the log information would need to be reordered and matches up to contexts and frames + // That is in fact possible but not trivial + av_dict_set(&codec_opts, "threads", "1", 0); + } + ist->dec_ctx->pkt_timebase = stream->time_base; #if FF_API_LAVF_AVCTX ist->dec_ctx->time_base = stream->codec->time_base; @@ -3191,6 +3332,9 @@ static const OptionDef real_options[] = { "show a particular entry from the format/container info", "entry" }, { "show_entries", HAS_ARG, {.func_arg = opt_show_entries}, "show a set of specified entries", "entry_list" }, +#if HAVE_PTHREADS + { "show_log", OPT_INT|HAS_ARG, {(void*)&do_show_log}, "show log" }, +#endif { "show_packets", 0, {(void*)&opt_show_packets}, "show packets info" }, { "show_programs", 0, {(void*)&opt_show_programs}, "show programs info" }, { "show_streams", 0, {(void*)&opt_show_streams}, "show streams info" }, @@ -3235,6 +3379,14 @@ int main(int argc, char **argv) char *w_name = NULL, *w_args = NULL; int ret, i;
+#if HAVE_PTHREADS + ret = pthread_mutex_init(&log_mutex, NULL); + if (ret != 0) { + goto end; + } +#endif + av_log_set_callback(log_callback); + av_log_set_flags(AV_LOG_SKIP_REPEATED); register_exit(ffprobe_cleanup);
I'm not really sure about storing the log in frame, since they could come from any context, not necessarily related to decoding. OTOH, I'm not really sure how such feature could be implemented in a really clean way. About frame decoding errors, we could store an error in the decoded frame itself. -- FFmpeg = Free and Frightening MultiPurpose Enlightened Geek
On Sun, Jun 05, 2016 at 12:56:08PM +0200, Stefano Sabatini wrote:
On date Tuesday 2016-05-31 21:23:27 +0200, Michael Niedermayer encoded:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif +
any chance to move this ifdeffery to lavu?
iam not sure what you suggest exactly ?
typedef struct InputStream { AVStream *st;
@@ -84,6 +97,7 @@ static int do_show_library_versions = 0; static int do_show_pixel_formats = 0; static int do_show_pixel_format_flags = 0; static int do_show_pixel_format_components = 0; +static int do_show_log = 0;
static int do_show_chapter_tags = 0; static int do_show_format_tags = 0; @@ -92,6 +106,7 @@ static int do_show_program_tags = 0; static int do_show_stream_tags = 0; static int do_show_packet_tags = 0;
+ static int show_value_unit = 0; static int use_value_prefix = 0; static int use_byte_value_binary_prefix = 0; @@ -146,6 +161,8 @@ typedef enum { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_SIDE_DATA, + SECTION_ID_FRAME_LOG, + SECTION_ID_FRAME_LOGS, SECTION_ID_LIBRARY_VERSION, SECTION_ID_LIBRARY_VERSIONS, SECTION_ID_PACKET, @@ -185,10 +202,12 @@ static struct section sections[] = { [SECTION_ID_FORMAT] = { SECTION_ID_FORMAT, "format", 0, { SECTION_ID_FORMAT_TAGS, -1 } }, [SECTION_ID_FORMAT_TAGS] = { SECTION_ID_FORMAT_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "format_tags" }, [SECTION_ID_FRAMES] = { SECTION_ID_FRAMES, "frames", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME, SECTION_ID_SUBTITLE, -1 } }, - [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, -1 } }, + [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_LOGS, -1 } }, [SECTION_ID_FRAME_TAGS] = { SECTION_ID_FRAME_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "frame_tags" }, [SECTION_ID_FRAME_SIDE_DATA_LIST] ={ SECTION_ID_FRAME_SIDE_DATA_LIST, "side_data_list", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_SIDE_DATA, -1 } }, [SECTION_ID_FRAME_SIDE_DATA] = { SECTION_ID_FRAME_SIDE_DATA, "side_data", 0, { -1 } }, + [SECTION_ID_FRAME_LOGS] = { SECTION_ID_FRAME_LOGS, "logs", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_LOG, -1 } }, + [SECTION_ID_FRAME_LOG] = { SECTION_ID_FRAME_LOG, "log", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 } }, [SECTION_ID_LIBRARY_VERSIONS] = { SECTION_ID_LIBRARY_VERSIONS, "library_versions", SECTION_FLAG_IS_ARRAY, { SECTION_ID_LIBRARY_VERSION, -1 } }, [SECTION_ID_LIBRARY_VERSION] = { SECTION_ID_LIBRARY_VERSION, "library_version", 0, { -1 } }, [SECTION_ID_PACKETS] = { SECTION_ID_PACKETS, "packets", SECTION_FLAG_IS_ARRAY, { SECTION_ID_PACKET, -1} }, @@ -255,11 +274,73 @@ static uint64_t *nb_streams_packets; static uint64_t *nb_streams_frames; static int *selected_streams;
+#if HAVE_PTHREADS +pthread_mutex_t log_mutex; +#endif +typedef struct LogBuffer { + char *context_name; + int log_level; + char *log_message; + AVClassCategory category; + char *parent_name; + AVClassCategory parent_category; +}LogBuffer; + +static LogBuffer *log_buffer; +static int log_buffer_size; + +static void log_callback(void *ptr, int level, const char *fmt, va_list vl) +{ + AVClass* avc = ptr ? *(AVClass **) ptr : NULL; + va_list vl2; + char line[1024]; + static int print_prefix = 1; + void *new_log_buffer; + + va_copy(vl2, vl); + av_log_default_callback(ptr, level, fmt, vl); + av_log_format_line(ptr, level, fmt, vl2, line, sizeof(line), &print_prefix); + va_end(vl2); + +#if HAVE_PTHREADS + pthread_mutex_lock(&log_mutex); + + new_log_buffer = av_realloc_array(log_buffer, log_buffer_size + 1, sizeof(*log_buffer)); + if (new_log_buffer) { + log_buffer = new_log_buffer; + memset(&log_buffer[log_buffer_size], 0, sizeof(log_buffer[log_buffer_size])); + log_buffer[log_buffer_size].context_name= avc ? av_strdup(avc->item_name(ptr)) : NULL; + if (avc) { + if (avc->get_category) log_buffer[log_buffer_size].category = avc->get_category(ptr); + else log_buffer[log_buffer_size].category = avc->category; + } + log_buffer[log_buffer_size].log_level = level; + log_buffer[log_buffer_size].log_message = av_strdup(line); + if (avc && avc->parent_log_context_offset) { + AVClass** parent = *(AVClass ***) (((uint8_t *) ptr) + + avc->parent_log_context_offset); + if (parent && *parent) { + log_buffer[log_buffer_size].parent_name = av_strdup((*parent)->item_name(parent)); + log_buffer[log_buffer_size].parent_category = + (*parent)->get_category ? (*parent)->get_category(parent) :(*parent)->category; + } + } + log_buffer_size ++; + } + + pthread_mutex_unlock(&log_mutex); +#endif +} + static void ffprobe_cleanup(int ret) { int i; for (i = 0; i < FF_ARRAY_ELEMS(sections); i++) av_dict_free(&(sections[i].entries_to_show)); + +#if HAVE_PTHREADS + pthread_mutex_destroy(&log_mutex); +#endif }
struct unit_value { @@ -1759,6 +1840,56 @@ static inline int show_tags(WriterContext *w, AVDictionary *tags, int section_id return ret; }
+static void clear_log(int need_lock) +{ + int i; + + if (need_lock) + pthread_mutex_lock(&log_mutex); + for (i=0; i<log_buffer_size; i++) { + av_freep(&log_buffer[i].context_name); + av_freep(&log_buffer[i].log_message); + } + log_buffer_size = 0; + if(need_lock) + pthread_mutex_unlock(&log_mutex); +} + +static int show_log(WriterContext *w, int section_ids, int section_id, int log_level) +{ + int i; + pthread_mutex_lock(&log_mutex); + if (!log_buffer_size) { + pthread_mutex_unlock(&log_mutex); + return 0; + } + writer_print_section_header(w, section_ids); + + for (i=0; i<log_buffer_size; i++) { + if (log_buffer[i].log_level <= log_level) { + writer_print_section_header(w, section_id); + print_str("context", log_buffer[i].context_name); + print_int("level", log_buffer[i].log_level); + print_int("category", log_buffer[i].category); + if (log_buffer[i].parent_name) { + print_str("parent_context", log_buffer[i].parent_name); + print_int("parent_category", log_buffer[i].parent_category); + } else { + print_str_opt("parent_context", "N/A"); + print_str_opt("parent_category", "N/A"); + } + print_str("message", log_buffer[i].log_message); + writer_print_section_footer(w); + } + } + clear_log(0); + pthread_mutex_unlock(&log_mutex); + + writer_print_section_footer(w); + + return 0; +} + static void show_packet(WriterContext *w, InputFile *ifile, AVPacket *pkt, int packet_idx) { char val_str[128]; @@ -1917,6 +2048,8 @@ static void show_frame(WriterContext *w, AVFrame *frame, AVStream *stream, } if (do_show_frame_tags) show_tags(w, av_frame_get_metadata(frame), SECTION_ID_FRAME_TAGS); + if (do_show_log) + show_log(w, SECTION_ID_FRAME_LOGS, SECTION_ID_FRAME_LOG, do_show_log); if (frame->nb_side_data) { writer_print_section_header(w, SECTION_ID_FRAME_SIDE_DATA_LIST); for (i = 0; i < frame->nb_side_data; i++) { @@ -1956,6 +2089,7 @@ static av_always_inline int process_frame(WriterContext *w, AVSubtitle sub; int ret = 0, got_frame = 0;
+ clear_log(1); if (dec_ctx && dec_ctx->codec) { switch (par->codec_type) { case AVMEDIA_TYPE_VIDEO: @@ -2604,6 +2738,13 @@ static int open_input_file(InputFile *ifile, const char *filename) if (err < 0) exit(1);
+ if (do_show_log) { + // For loging it is needed to disable at least frame threads as otherwise + // the log information would need to be reordered and matches up to contexts and frames + // That is in fact possible but not trivial + av_dict_set(&codec_opts, "threads", "1", 0); + } + ist->dec_ctx->pkt_timebase = stream->time_base; #if FF_API_LAVF_AVCTX ist->dec_ctx->time_base = stream->codec->time_base; @@ -3191,6 +3332,9 @@ static const OptionDef real_options[] = { "show a particular entry from the format/container info", "entry" }, { "show_entries", HAS_ARG, {.func_arg = opt_show_entries}, "show a set of specified entries", "entry_list" }, +#if HAVE_PTHREADS + { "show_log", OPT_INT|HAS_ARG, {(void*)&do_show_log}, "show log" }, +#endif { "show_packets", 0, {(void*)&opt_show_packets}, "show packets info" }, { "show_programs", 0, {(void*)&opt_show_programs}, "show programs info" }, { "show_streams", 0, {(void*)&opt_show_streams}, "show streams info" }, @@ -3235,6 +3379,14 @@ int main(int argc, char **argv) char *w_name = NULL, *w_args = NULL; int ret, i;
+#if HAVE_PTHREADS + ret = pthread_mutex_init(&log_mutex, NULL); + if (ret != 0) { + goto end; + } +#endif + av_log_set_callback(log_callback); + av_log_set_flags(AV_LOG_SKIP_REPEATED); register_exit(ffprobe_cleanup);
I'm not really sure about storing the log in frame, since they could come from any context, not necessarily related to decoding.
OTOH, I'm not really sure how such feature could be implemented in a really clean way.
About frame decoding errors, we could store an error in the decoded frame itself.
I dont know what exactly is wanted ? What i found interresting was to partition all av_log into closest related sections like decoder/demuxer/filter/... and add them there so that detailed information, not limited to errors about frame and packet related information can be associated with them this patch was just a step toward that if that feature isnt wanted we can drop the patch [...] -- Michael GnuPG fingerprint: 9FF2128B147EF6730BADF133611EC787040B0FAB I am the wisest man alive, for I know one thing, and that is that I know nothing. -- Socrates
On date Wednesday 2016-06-08 18:20:39 +0200, Michael Niedermayer encoded:
On Sun, Jun 05, 2016 at 12:56:08PM +0200, Stefano Sabatini wrote:
On date Tuesday 2016-05-31 21:23:27 +0200, Michael Niedermayer encoded:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif +
any chance to move this ifdeffery to lavu?
iam not sure what you suggest exactly ?
Forget about it. [...]
+#if HAVE_PTHREADS + ret = pthread_mutex_init(&log_mutex, NULL); + if (ret != 0) { + goto end; + } +#endif + av_log_set_callback(log_callback); + av_log_set_flags(AV_LOG_SKIP_REPEATED); register_exit(ffprobe_cleanup);
I'm not really sure about storing the log in frame, since they could come from any context, not necessarily related to decoding.
OTOH, I'm not really sure how such feature could be implemented in a really clean way.
About frame decoding errors, we could store an error in the decoded frame itself.
I dont know what exactly is wanted ?
I mean, we already have the AVFrame.decode_error_flags we could expose to the user.
What i found interresting was to partition all av_log into closest related sections like decoder/demuxer/filter/... and add them there so that detailed information, not limited to errors about frame and packet related information can be associated with them this patch was just a step toward that if that feature isnt wanted we can drop the patch
I think this patch is interesting, but I don't want to clutter the code too much, especially if we found a more general design which could deprecate this one. The problem with this approach is that the log is contained in the frame element, when it could come from other parts of the code as well. One option could be to define a -show_logs options, and optionally add a filter specifying the contexts. Just storing the log in the frame elements sounds a bit weird to me. -- FFmpeg = Fanciful and Friendly Merciless Plastic EnGine
On Tue, Jun 14, 2016 at 05:55:47PM +0200, Stefano Sabatini wrote:
On date Wednesday 2016-06-08 18:20:39 +0200, Michael Niedermayer encoded:
On Sun, Jun 05, 2016 at 12:56:08PM +0200, Stefano Sabatini wrote:
On date Tuesday 2016-05-31 21:23:27 +0200, Michael Niedermayer encoded:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521 [...] I'm not really sure about storing the log in frame, since they could come from any context, not necessarily related to decoding.
OTOH, I'm not really sure how such feature could be implemented in a really clean way.
About frame decoding errors, we could store an error in the decoded frame itself.
I dont know what exactly is wanted ?
I mean, we already have the AVFrame.decode_error_flags we could expose to the user.
What i found interresting was to partition all av_log into closest related sections like decoder/demuxer/filter/... and add them there so that detailed information, not limited to errors about frame and packet related information can be associated with them this patch was just a step toward that if that feature isnt wanted we can drop the patch
I think this patch is interesting, but I don't want to clutter the code too much, especially if we found a more general design which could deprecate this one.
has anyone found a more general design ?
The problem with this approach is that the log is contained in the frame element, when it could come from other parts of the code as well.
when decoding a frame triggers a log message then its caused by the frame. It may come ultimately from the experssion evaluator for example but knowig that the message comes from the experssion evaluator is of little use, a grep would tell one that already. Knowing which frame triggers it seems more usefull to me
One option could be to define a -show_logs options, and optionally add a filter specifying the contexts. Just storing the log in the frame elements sounds a bit weird to me.
its certainly possible to extend this patch to also cover demuxer and other areas and then add a -show_logs to select what should be enabled is that what you meant ? it seems thats not a argument against the patch as it is, just something that can be done as additional work afterwards but quite possibly i misunderstand [...] -- Michael GnuPG fingerprint: 9FF2128B147EF6730BADF133611EC787040B0FAB Everything should be made as simple as possible, but not simpler. -- Albert Einstein
On date Thursday 2016-12-01 22:21:17 +0100, Michael Niedermayer encoded:
On Tue, Jun 14, 2016 at 05:55:47PM +0200, Stefano Sabatini wrote:
On date Wednesday 2016-06-08 18:20:39 +0200, Michael Niedermayer encoded:
On Sun, Jun 05, 2016 at 12:56:08PM +0200, Stefano Sabatini wrote:
On date Tuesday 2016-05-31 21:23:27 +0200, Michael Niedermayer encoded:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521 [...] I'm not really sure about storing the log in frame, since they could come from any context, not necessarily related to decoding.
OTOH, I'm not really sure how such feature could be implemented in a really clean way.
About frame decoding errors, we could store an error in the decoded frame itself.
I dont know what exactly is wanted ?
I mean, we already have the AVFrame.decode_error_flags we could expose to the user.
What i found interresting was to partition all av_log into closest related sections like decoder/demuxer/filter/... and add them there so that detailed information, not limited to errors about frame and packet related information can be associated with them this patch was just a step toward that if that feature isnt wanted we can drop the patch
I think this patch is interesting, but I don't want to clutter the code too much, especially if we found a more general design which could deprecate this one.
has anyone found a more general design ?
The problem with this approach is that the log is contained in the frame element, when it could come from other parts of the code as well.
when decoding a frame triggers a log message then its caused by the frame. It may come ultimately from the experssion evaluator for example but knowig that the message comes from the experssion evaluator is of little use, a grep would tell one that already. Knowing which frame triggers it seems more usefull to me
One option could be to define a -show_logs options, and optionally add a filter specifying the contexts. Just storing the log in the frame elements sounds a bit weird to me.
its certainly possible to extend this patch to also cover demuxer and other areas and then add a -show_logs to select what should be enabled is that what you meant ?
it seems thats not a argument against the patch as it is, just something that can be done as additional work afterwards
but quite possibly i misunderstand
Feel free to push the patch as is. The other thing I don't like is the threading dependency but probably there is not much we can do about it. -- FFmpeg = Fostering and Free Mystic Patchable Egregious Ghost
On Mon, Dec 05, 2016 at 09:30:12AM +0100, Stefano Sabatini wrote:
On date Thursday 2016-12-01 22:21:17 +0100, Michael Niedermayer encoded:
On Tue, Jun 14, 2016 at 05:55:47PM +0200, Stefano Sabatini wrote:
On date Wednesday 2016-06-08 18:20:39 +0200, Michael Niedermayer encoded:
On Sun, Jun 05, 2016 at 12:56:08PM +0200, Stefano Sabatini wrote:
On date Tuesday 2016-05-31 21:23:27 +0200, Michael Niedermayer encoded:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521 [...] I'm not really sure about storing the log in frame, since they could come from any context, not necessarily related to decoding.
OTOH, I'm not really sure how such feature could be implemented in a really clean way.
About frame decoding errors, we could store an error in the decoded frame itself.
I dont know what exactly is wanted ?
I mean, we already have the AVFrame.decode_error_flags we could expose to the user.
What i found interresting was to partition all av_log into closest related sections like decoder/demuxer/filter/... and add them there so that detailed information, not limited to errors about frame and packet related information can be associated with them this patch was just a step toward that if that feature isnt wanted we can drop the patch
I think this patch is interesting, but I don't want to clutter the code too much, especially if we found a more general design which could deprecate this one.
has anyone found a more general design ?
The problem with this approach is that the log is contained in the frame element, when it could come from other parts of the code as well.
when decoding a frame triggers a log message then its caused by the frame. It may come ultimately from the experssion evaluator for example but knowig that the message comes from the experssion evaluator is of little use, a grep would tell one that already. Knowing which frame triggers it seems more usefull to me
One option could be to define a -show_logs options, and optionally add a filter specifying the contexts. Just storing the log in the frame elements sounds a bit weird to me.
its certainly possible to extend this patch to also cover demuxer and other areas and then add a -show_logs to select what should be enabled is that what you meant ?
it seems thats not a argument against the patch as it is, just something that can be done as additional work afterwards
but quite possibly i misunderstand
Feel free to push the patch as is. The other thing I don't like is the threading dependency but probably there is not much we can do about it.
fixed some issues, dave rice added doc & ffprobe.xsd update applied thanks [...] -- Michael GnuPG fingerprint: 9FF2128B147EF6730BADF133611EC787040B0FAB Dictatorship: All citizens are under surveillance, all their steps and actions recorded, for the politicians to enforce control. Democracy: All politicians are under surveillance, all their steps and actions recorded, for the citizens to enforce control.
On May 31, 2016, at 3:23 PM, Michael Niedermayer <michael@niedermayer.cc> wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
I’ve been testing this patch, but currently the logging does not appear within the log node. For instance with a fuzzed mpeg2video in QuickTime when I run: ./ffprobe -i /Users/davidrice/fuzzed_mpeg2video.mov -show_log 1 -show_frames -of xml Then the output is like: ffprobe version N-80154-g9c023a7 Copyright (c) 2007-2016 the FFmpeg developers built with Apple LLVM version 7.3.0 (clang-703.0.31) configuration: --disable-dwt libavutil 55. 24.100 / 55. 24.100 libavcodec 57. 44.100 / 57. 44.100 libavformat 57. 37.101 / 57. 37.101 libavdevice 57. 0.101 / 57. 0.101 libavfilter 6. 46.100 / 6. 46.100 libswscale 4. 1.100 / 4. 1.100 libswresample 2. 0.101 / 2. 0.101 <?xml version="1.0" encoding="UTF-8"?> <ffprobe> Input #0, mov,mp4,m4a,3gp,3g2,mj2, from '/Users/davidrice/fuzzed_mpeg2video.mov': Metadata: major_brand : qt minor_version : 512 compatible_brands: qt encoder : Lavf57.34.103 Duration: 00:00:04.00, start: 0.000000, bitrate: 2668 kb/s Stream #0:0(eng): Video: mpeg2video (Main) (m2v1 / 0x3176326D), yuv420p(tv), 640x480 [SAR 1:1 DAR 4:3], 2666 kb/s, 25 fps, 25 tbr, 12800 tbn (default) Metadata: handler_name : DataHandler encoder : Lavc57.38.100 mpeg2video <frames> [mpeg2video @ 0x7fcfda817600] skipped MB in I frame at 3 18 [mpeg2video @ 0x7fcfda817600] Warning MVs not available [mpeg2video @ 0x7fcfda817600] concealing 40 DC, 40 AC, 40 MV errors in I frame <frame media_type="video" stream_index="0" key_frame="1" pkt_pts="0" pkt_pts_time="0.000000" pkt_dts="0" pkt_dts_time="0.000000" best_effort_timestamp="0" best_effort_timestamp_time="0.000000" pkt_duration="512" pkt_duration_time="0.040000" pkt_pos="36" pkt_size="29682" width="640" height="480" pix_fmt="yuv420p" sample_aspect_ratio="1:1" pict_type="I" coded_picture_number="0" display_picture_number="0" interlaced_frame="0" top_field_first="0" repeat_pict="0"> <logs> </logs> <side_data_list> <side_data side_data_type="GOP timecode" side_data_size="8" timecode="00:00:00:01"/> </side_data_list> </frame> [mpeg2video @ 0x7fcfda817600] skipped MB in I frame at 27 6 [mpeg2video @ 0x7fcfda817600] Warning MVs not available [mpeg2video @ 0x7fcfda817600] concealing 40 DC, 40 AC, 40 MV errors in I frame <frame media_type="video" stream_index="0" key_frame="1" pkt_pts="512" pkt_pts_time="0.040000" pkt_dts="512" pkt_dts_time="0.040000" best_effort_timestamp="512" best_effort_timestamp_time="0.040000" pkt_duration="512" pkt_duration_time="0.040000" pkt_pos="29718" pkt_size="45833" width="640" height="480" pix_fmt="yuv420p" sample_aspect_ratio="1:1" pict_type="I" coded_picture_number="1" display_picture_number="0" interlaced_frame="0" top_field_first="0" repeat_pict="0"> <logs> </logs> <side_data_list> <side_data side_data_type="GOP timecode" side_data_size="8" timecode="00:00:00:02"/> </side_data_list> </frame> <frame media_type="video" stream_index="0" key_frame="1" pkt_pts="1024" pkt_pts_time="0.080000" pkt_dts="1024" pkt_dts_time="0.080000" best_effort_timestamp="1024" best_effort_timestamp_time="0.080000" pkt_duration="512" pkt_duration_time="0.040000" pkt_pos="75551" pkt_size="45751" width="640" height="480" pix_fmt="yuv420p" sample_aspect_ratio="1:1" pict_type="I" coded_picture_number="2" display_picture_number="0" interlaced_frame="0" top_field_first="0" repeat_pict="0"> <side_data_list> <side_data side_data_type="GOP timecode" side_data_size="8" timecode="00:00:00:03"/> </side_data_list> </frame> <frame media_type="video" stream_index="0" key_frame="1" pkt_pts="1536" pkt_pts_time="0.120000" pkt_dts="1536" pkt_dts_time="0.120000" best_effort_timestamp="1536" best_effort_timestamp_time="0.120000" pkt_duration="512" pkt_duration_time="0.040000" pkt_pos="121302" pkt_size="46273" width="640" height="480" pix_fmt="yuv420p" sample_aspect_ratio="1:1" pict_type="I" coded_picture_number="3" display_picture_number="0" interlaced_frame="0" top_field_first="0" repeat_pict="0"> <side_data_list> <side_data side_data_type="GOP timecode" side_data_size="8" timecode="00:00:00:04"/> </side_data_list> </frame> <frame media_type="video" stream_index="0" key_frame="1" pkt_pts="2048" pkt_pts_time="0.160000" pkt_dts="2048" pkt_dts_time="0.160000" best_effort_timestamp="2048" best_effort_timestamp_time="0.160000" pkt_duration="512" pkt_duration_time="0.040000" pkt_pos="167575" pkt_size="30432" width="640" height="480" pix_fmt="yuv420p" sample_aspect_ratio="1:1" pict_type="I" coded_picture_number="4" display_picture_number="0" interlaced_frame="0" top_field_first="0" repeat_pict="0"> <side_data_list> <side_data side_data_type="GOP timecode" side_data_size="8" timecode="00:00:00:05"/> </side_data_list> </frame> [mpeg2video @ 0x7fcfda817600] skipped MB in I frame at 16 13 [mpeg2video @ 0x7fcfda817600] skipped MB in I frame at 29 25 [mpeg2video @ 0x7fcfda817600] Warning MVs not available [mpeg2video @ 0x7fcfda817600] concealing 80 DC, 80 AC, 80 MV errors in I frame <frame media_type="video" stream_index="0" key_frame="1" pkt_pts="2560" pkt_pts_time="0.200000" pkt_dts="2560" pkt_dts_time="0.200000" best_effort_timestamp="2560" best_effort_timestamp_time="0.200000" pkt_duration="512" pkt_duration_time="0.040000" pkt_pos="198007" pkt_size="21454" width="640" height="480" pix_fmt="yuv420p" sample_aspect_ratio="1:1" pict_type="I" coded_picture_number="5" display_picture_number="0" interlaced_frame="0" top_field_first="0" repeat_pict="0"> <logs> </logs> <side_data_list> <side_data side_data_type="GOP timecode" side_data_size="8" timecode="00:00:00:06"/> </side_data_list> </frame> </frames> </ffprobe> When the mpeg2video decoding log appears in sdterr, then the <logs> node is written but empty. During a frame when there is no logged message, there is no <logs> node. Also I’m uncertain what the value to use with -show_log means. I’m using -show_log 1 for now. Is this for verbosity? Dave Rice
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif + typedef struct InputStream { AVStream *st;
@@ -84,6 +97,7 @@ static int do_show_library_versions = 0; static int do_show_pixel_formats = 0; static int do_show_pixel_format_flags = 0; static int do_show_pixel_format_components = 0; +static int do_show_log = 0;
static int do_show_chapter_tags = 0; static int do_show_format_tags = 0; @@ -92,6 +106,7 @@ static int do_show_program_tags = 0; static int do_show_stream_tags = 0; static int do_show_packet_tags = 0;
+ static int show_value_unit = 0; static int use_value_prefix = 0; static int use_byte_value_binary_prefix = 0; @@ -146,6 +161,8 @@ typedef enum { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_SIDE_DATA, + SECTION_ID_FRAME_LOG, + SECTION_ID_FRAME_LOGS, SECTION_ID_LIBRARY_VERSION, SECTION_ID_LIBRARY_VERSIONS, SECTION_ID_PACKET, @@ -185,10 +202,12 @@ static struct section sections[] = { [SECTION_ID_FORMAT] = { SECTION_ID_FORMAT, "format", 0, { SECTION_ID_FORMAT_TAGS, -1 } }, [SECTION_ID_FORMAT_TAGS] = { SECTION_ID_FORMAT_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "format_tags" }, [SECTION_ID_FRAMES] = { SECTION_ID_FRAMES, "frames", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME, SECTION_ID_SUBTITLE, -1 } }, - [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, -1 } }, + [SECTION_ID_FRAME] = { SECTION_ID_FRAME, "frame", 0, { SECTION_ID_FRAME_TAGS, SECTION_ID_FRAME_SIDE_DATA_LIST, SECTION_ID_FRAME_LOGS, -1 } }, [SECTION_ID_FRAME_TAGS] = { SECTION_ID_FRAME_TAGS, "tags", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 }, .element_name = "tag", .unique_name = "frame_tags" }, [SECTION_ID_FRAME_SIDE_DATA_LIST] ={ SECTION_ID_FRAME_SIDE_DATA_LIST, "side_data_list", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_SIDE_DATA, -1 } }, [SECTION_ID_FRAME_SIDE_DATA] = { SECTION_ID_FRAME_SIDE_DATA, "side_data", 0, { -1 } }, + [SECTION_ID_FRAME_LOGS] = { SECTION_ID_FRAME_LOGS, "logs", SECTION_FLAG_IS_ARRAY, { SECTION_ID_FRAME_LOG, -1 } }, + [SECTION_ID_FRAME_LOG] = { SECTION_ID_FRAME_LOG, "log", SECTION_FLAG_HAS_VARIABLE_FIELDS, { -1 } }, [SECTION_ID_LIBRARY_VERSIONS] = { SECTION_ID_LIBRARY_VERSIONS, "library_versions", SECTION_FLAG_IS_ARRAY, { SECTION_ID_LIBRARY_VERSION, -1 } }, [SECTION_ID_LIBRARY_VERSION] = { SECTION_ID_LIBRARY_VERSION, "library_version", 0, { -1 } }, [SECTION_ID_PACKETS] = { SECTION_ID_PACKETS, "packets", SECTION_FLAG_IS_ARRAY, { SECTION_ID_PACKET, -1} }, @@ -255,11 +274,73 @@ static uint64_t *nb_streams_packets; static uint64_t *nb_streams_frames; static int *selected_streams;
+#if HAVE_PTHREADS +pthread_mutex_t log_mutex; +#endif +typedef struct LogBuffer { + char *context_name; + int log_level; + char *log_message; + AVClassCategory category; + char *parent_name; + AVClassCategory parent_category; +}LogBuffer; + +static LogBuffer *log_buffer; +static int log_buffer_size; + +static void log_callback(void *ptr, int level, const char *fmt, va_list vl) +{ + AVClass* avc = ptr ? *(AVClass **) ptr : NULL; + va_list vl2; + char line[1024]; + static int print_prefix = 1; + void *new_log_buffer; + + va_copy(vl2, vl); + av_log_default_callback(ptr, level, fmt, vl); + av_log_format_line(ptr, level, fmt, vl2, line, sizeof(line), &print_prefix); + va_end(vl2); + +#if HAVE_PTHREADS + pthread_mutex_lock(&log_mutex); + + new_log_buffer = av_realloc_array(log_buffer, log_buffer_size + 1, sizeof(*log_buffer)); + if (new_log_buffer) { + log_buffer = new_log_buffer; + memset(&log_buffer[log_buffer_size], 0, sizeof(log_buffer[log_buffer_size])); + log_buffer[log_buffer_size].context_name= avc ? av_strdup(avc->item_name(ptr)) : NULL; + if (avc) { + if (avc->get_category) log_buffer[log_buffer_size].category = avc->get_category(ptr); + else log_buffer[log_buffer_size].category = avc->category; + } + log_buffer[log_buffer_size].log_level = level; + log_buffer[log_buffer_size].log_message = av_strdup(line); + if (avc && avc->parent_log_context_offset) { + AVClass** parent = *(AVClass ***) (((uint8_t *) ptr) + + avc->parent_log_context_offset); + if (parent && *parent) { + log_buffer[log_buffer_size].parent_name = av_strdup((*parent)->item_name(parent)); + log_buffer[log_buffer_size].parent_category = + (*parent)->get_category ? (*parent)->get_category(parent) :(*parent)->category; + } + } + log_buffer_size ++; + } + + pthread_mutex_unlock(&log_mutex); +#endif +} + static void ffprobe_cleanup(int ret) { int i; for (i = 0; i < FF_ARRAY_ELEMS(sections); i++) av_dict_free(&(sections[i].entries_to_show)); + +#if HAVE_PTHREADS + pthread_mutex_destroy(&log_mutex); +#endif }
struct unit_value { @@ -1759,6 +1840,56 @@ static inline int show_tags(WriterContext *w, AVDictionary *tags, int section_id return ret; }
+static void clear_log(int need_lock) +{ + int i; + + if (need_lock) + pthread_mutex_lock(&log_mutex); + for (i=0; i<log_buffer_size; i++) { + av_freep(&log_buffer[i].context_name); + av_freep(&log_buffer[i].log_message); + } + log_buffer_size = 0; + if(need_lock) + pthread_mutex_unlock(&log_mutex); +} + +static int show_log(WriterContext *w, int section_ids, int section_id, int log_level) +{ + int i; + pthread_mutex_lock(&log_mutex); + if (!log_buffer_size) { + pthread_mutex_unlock(&log_mutex); + return 0; + } + writer_print_section_header(w, section_ids); + + for (i=0; i<log_buffer_size; i++) { + if (log_buffer[i].log_level <= log_level) { + writer_print_section_header(w, section_id); + print_str("context", log_buffer[i].context_name); + print_int("level", log_buffer[i].log_level); + print_int("category", log_buffer[i].category); + if (log_buffer[i].parent_name) { + print_str("parent_context", log_buffer[i].parent_name); + print_int("parent_category", log_buffer[i].parent_category); + } else { + print_str_opt("parent_context", "N/A"); + print_str_opt("parent_category", "N/A"); + } + print_str("message", log_buffer[i].log_message); + writer_print_section_footer(w); + } + } + clear_log(0); + pthread_mutex_unlock(&log_mutex); + + writer_print_section_footer(w); + + return 0; +} + static void show_packet(WriterContext *w, InputFile *ifile, AVPacket *pkt, int packet_idx) { char val_str[128]; @@ -1917,6 +2048,8 @@ static void show_frame(WriterContext *w, AVFrame *frame, AVStream *stream, } if (do_show_frame_tags) show_tags(w, av_frame_get_metadata(frame), SECTION_ID_FRAME_TAGS); + if (do_show_log) + show_log(w, SECTION_ID_FRAME_LOGS, SECTION_ID_FRAME_LOG, do_show_log); if (frame->nb_side_data) { writer_print_section_header(w, SECTION_ID_FRAME_SIDE_DATA_LIST); for (i = 0; i < frame->nb_side_data; i++) { @@ -1956,6 +2089,7 @@ static av_always_inline int process_frame(WriterContext *w, AVSubtitle sub; int ret = 0, got_frame = 0;
+ clear_log(1); if (dec_ctx && dec_ctx->codec) { switch (par->codec_type) { case AVMEDIA_TYPE_VIDEO: @@ -2604,6 +2738,13 @@ static int open_input_file(InputFile *ifile, const char *filename) if (err < 0) exit(1);
+ if (do_show_log) { + // For loging it is needed to disable at least frame threads as otherwise + // the log information would need to be reordered and matches up to contexts and frames + // That is in fact possible but not trivial + av_dict_set(&codec_opts, "threads", "1", 0); + } + ist->dec_ctx->pkt_timebase = stream->time_base; #if FF_API_LAVF_AVCTX ist->dec_ctx->time_base = stream->codec->time_base; @@ -3191,6 +3332,9 @@ static const OptionDef real_options[] = { "show a particular entry from the format/container info", "entry" }, { "show_entries", HAS_ARG, {.func_arg = opt_show_entries}, "show a set of specified entries", "entry_list" }, +#if HAVE_PTHREADS + { "show_log", OPT_INT|HAS_ARG, {(void*)&do_show_log}, "show log" }, +#endif { "show_packets", 0, {(void*)&opt_show_packets}, "show packets info" }, { "show_programs", 0, {(void*)&opt_show_programs}, "show programs info" }, { "show_streams", 0, {(void*)&opt_show_streams}, "show streams info" }, @@ -3235,6 +3379,14 @@ int main(int argc, char **argv) char *w_name = NULL, *w_args = NULL; int ret, i;
+#if HAVE_PTHREADS + ret = pthread_mutex_init(&log_mutex, NULL); + if (ret != 0) { + goto end; + } +#endif + av_log_set_callback(log_callback); + av_log_set_flags(AV_LOG_SKIP_REPEATED); register_exit(ffprobe_cleanup);
-- 1.7.9.5
_______________________________________________ ffmpeg-devel mailing list ffmpeg-devel@ffmpeg.org http://ffmpeg.org/mailman/listinfo/ffmpeg-devel
On Tue, Jun 07, 2016 at 08:06:35PM -0400, Dave Rice wrote:
On May 31, 2016, at 3:23 PM, Michael Niedermayer <michael@niedermayer.cc> wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
I’ve been testing this patch, but currently the logging does not appear within the log node. For instance with a fuzzed mpeg2video in QuickTime when I run:
./ffprobe -i /Users/davidrice/fuzzed_mpeg2video.mov -show_log 1 -show_frames -of xml
[...]
When the mpeg2video decoding log appears in sdterr, then the <logs> node is written but empty. During a frame when there is no logged message, there is no <logs> node.
Also I’m uncertain what the value to use with -show_log means. I’m using -show_log 1 for now. Is this for verbosity?
you need to set the log level in -show_log high enough so the messages that you are interrested in are included all messages are still printed to stderr too, maybe that is confusing but feels consistent behavior [...] -- Michael GnuPG fingerprint: 9FF2128B147EF6730BADF133611EC787040B0FAB If you think the mosad wants you dead since a long time then you are either wrong or dead since a long time.
On Jun 8, 2016, at 12:30 PM, Michael Niedermayer <michael@niedermayer.cc> wrote:
On Tue, Jun 07, 2016 at 08:06:35PM -0400, Dave Rice wrote:
On May 31, 2016, at 3:23 PM, Michael Niedermayer <michael@niedermayer.cc> wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
I’ve been testing this patch, but currently the logging does not appear within the log node. For instance with a fuzzed mpeg2video in QuickTime when I run:
./ffprobe -i /Users/davidrice/fuzzed_mpeg2video.mov -show_log 1 -show_frames -of xml
[...]
When the mpeg2video decoding log appears in sdterr, then the <logs> node is written but empty. During a frame when there is no logged message, there is no <logs> node.
Also I’m uncertain what the value to use with -show_log means. I’m using -show_log 1 for now. Is this for verbosity?
you need to set the log level in -show_log high enough so the messages that you are interrested in are included
OK, the value just needs to be higher than I expected. I created a test file with: ffmpeg -f lavfi -i testsrc -bsf noise -t 1 -c:v mpeg2video fuzzed_mpeg2video.mov I don't actually get log info until the -show_log value is up to 16. Then this works: ffprobe fuzzed_mpeg2video.mov -show_log 16 -show_frames -of xml But it outputs invalid xml: <logs> <(null) key="context" value="mpeg2video"/> level="16" category="6" <(null) key="message" value="[mpeg2video @ 0x7fa4a3800000] skipped MB in I frame at 3 0 "/> <(null) key="context" value="mpeg2video"/> level="16" category="6" <(null) key="message" value="[mpeg2video @ 0x7fa4a3800000] ac-tex damaged at 16 9 "/> <(null) key="context" value="mpeg2video"/> level="16" category="6" <(null) key="message" value="[mpeg2video @ 0x7fa4a3800000] ac-tex damaged at 11 11 "/> <(null) key="context" value="mpeg2video"/> level="16" category="6" <(null) key="message" value="[mpeg2video @ 0x7fa4a3800000] invalid mb type in I Frame at 9 13 "/> <(null) key="context" value="mpeg2video"/> level="16" category="6" <(null) key="message" value="[mpeg2video @ 0x7fa4a3800000] Warning MVs not available "/> </logs> The 'log' node is called '(null)' and the level and category attributes are outside of a node.
all messages are still printed to stderr too, maybe that is confusing but feels consistent behavior
I agree. [...] Dave Rice
On 5/31/2016 4:23 PM, Michael Niedermayer wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif
Why are you not using the compat wrappers here? These are simple mutex locks that don't even use static init, so i don't see why they wouldn't work with w32threads or os2threads. You can either include the compat headers directly and keep using pthread_mutex*, or use lavu's thread.h and use ff_mutex_*
On Wed, Jun 08, 2016 at 12:04:44AM -0300, James Almer wrote:
On 5/31/2016 4:23 PM, Michael Niedermayer wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif
Why are you not using the compat wrappers here? These are simple mutex locks that don't even use static init, so i don't see why they wouldn't work with w32threads or os2threads.
i just used the same as ffmpeg.c does but locally changed as: no idea if it works on os2 or w32 diff --git a/ffprobe.c b/ffprobe.c index 07b61ec..ef6d4db 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,9 +49,9 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h" -#if HAVE_PTHREADS -# include <pthread.h> -#else +#include "libavutil/thread.h" + +#if !HAVE_THREADS # ifdef pthread_mutex_lock # undef pthread_mutex_lock # endif @@ -274,7 +274,7 @@ static uint64_t *nb_streams_packets; static uint64_t *nb_streams_frames; static int *selected_streams; -#if HAVE_PTHREADS +#if HAVE_THREADS pthread_mutex_t log_mutex; #endif typedef struct LogBuffer { @@ -302,7 +302,7 @@ static void log_callback(void *ptr, int level, const char *fmt, va_list vl) av_log_format_line(ptr, level, fmt, vl2, line, sizeof(line), &print_prefix); va_end(vl2); -#if HAVE_PTHREADS +#if HAVE_THREADS pthread_mutex_lock(&log_mutex); new_log_buffer = av_realloc_array(log_buffer, log_buffer_size + 1, sizeof(*log_buffer)); @@ -338,7 +338,7 @@ static void ffprobe_cleanup(int ret) for (i = 0; i < FF_ARRAY_ELEMS(sections); i++) av_dict_free(&(sections[i].entries_to_show)); -#if HAVE_PTHREADS +#if HAVE_THREADS pthread_mutex_destroy(&log_mutex); #endif } @@ -3332,7 +3332,7 @@ static const OptionDef real_options[] = { "show a particular entry from the format/container info", "entry" }, { "show_entries", HAS_ARG, {.func_arg = opt_show_entries}, "show a set of specified entries", "entry_list" }, -#if HAVE_PTHREADS +#if HAVE_THREADS { "show_log", OPT_INT|HAS_ARG, {(void*)&do_show_log}, "show log" }, #endif { "show_packets", 0, {(void*)&opt_show_packets}, "show packets info" }, @@ -3379,7 +3379,7 @@ int main(int argc, char **argv) char *w_name = NULL, *w_args = NULL; int ret, i; -#if HAVE_PTHREADS +#if HAVE_THREADS ret = pthread_mutex_init(&log_mutex, NULL); if (ret != 0) { goto end; [...] -- Michael GnuPG fingerprint: 9FF2128B147EF6730BADF133611EC787040B0FAB It is what and why we do it that matters, not just one of them.
On 6/8/2016 1:49 PM, Michael Niedermayer wrote:
On Wed, Jun 08, 2016 at 12:04:44AM -0300, James Almer wrote:
On 5/31/2016 4:23 PM, Michael Niedermayer wrote:
adding demuxer and other logs should be easy This forces single threaded decoding for simplicity It also requires pthreads, this could be avoided either with some lockless tricks or simply by assuming av_log would never be called from another thread.
doc/ffprobe.xsd update missing (TODO & help welcome)
Fixes Ticket5521
Signed-off-by: Michael Niedermayer <michael@niedermayer.cc> --- ffprobe.c | 154 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 153 insertions(+), 1 deletion(-)
diff --git a/ffprobe.c b/ffprobe.c index a7e329c..07b61ec 100644 --- a/ffprobe.c +++ b/ffprobe.c @@ -49,6 +49,19 @@ #include "libpostproc/postprocess.h" #include "cmdutils.h"
+#if HAVE_PTHREADS +# include <pthread.h> +#else +# ifdef pthread_mutex_lock +# undef pthread_mutex_lock +# endif +# define pthread_mutex_lock(a) +# ifdef pthread_mutex_unlock +# undef pthread_mutex_unlock +# endif +# define pthread_mutex_unlock(a) +#endif
Why are you not using the compat wrappers here? These are simple mutex locks that don't even use static init, so i don't see why they wouldn't work with w32threads or os2threads.
i just used the same as ffmpeg.c does
That one should also be checked. Seems to be only pthread_join, pthread_create, both supported by the wrappers, and lavu's threaded message API, which also uses the wrappers.
but locally changed as: no idea if it works on os2 or w32
Compiles and seems to work after a quick test with mingw-w64.
participants (4)
-
Dave Rice -
James Almer -
Michael Niedermayer -
Stefano Sabatini