[Spice-devel] [PATCH spice-streaming-agent 1/9] Separate the code for logging frames/times into a class
Lukáš Hrázký
lhrazky at redhat.com
Thu Jun 14 15:29:50 UTC 2018
On Thu, 2018-06-14 at 16:22 +0200, Christophe de Dinechin wrote:
> > On 13 Jun 2018, at 14:06, Lukáš Hrázký <lhrazky at redhat.com> wrote:
> >
> > The FrameLog class provides RAII for the FILE and encapsulates the
> > logging functionality.
> >
> > Signed-off-by: Lukáš Hrázký <lhrazky at redhat.com>
> > ---
> > While I retained all the behaviour of the original implementation, I
> > don't like it as it is.
> >
> > 1. The class is doing two different things:
> > a) logging the binary frames for later replay
> > b) writing a time-stamped log for diagnostics
> >
> > 2. The time-stamped diagnostics lines seem quite rudimentary, like
> > some short helper messages I put in my code when debugging a problem.
> > Doesn't look like something we'd want to release, god forbid we'd have
> > to keep the log format backwards compatible in the future :)
> >
> > However, I don't know how the frame log is used (I guess it's mostly
> > Frediano who uses it?), so I didn't try to improve it, as I don't really
> > know how. I'd like to:
> >
> > a) either get some input on how to improve it - address the two mentioned
> > issues, or (much rather)
> >
> > b) merge this separation and have someone post a followup that cleans it
> > up.
> >
> >
> > src/Makefile.am | 2 +
> > src/frame-log.cpp | 76 +++++++++++++++++++++++++++++++++++
> > src/frame-log.hpp | 39 ++++++++++++++++++
> > src/spice-streaming-agent.cpp | 71 ++++++++------------------------
> > 4 files changed, 134 insertions(+), 54 deletions(-)
> > create mode 100644 src/frame-log.cpp
> > create mode 100644 src/frame-log.hpp
> >
> > diff --git a/src/Makefile.am b/src/Makefile.am
> > index 18ed22c..fead680 100644
> > --- a/src/Makefile.am
> > +++ b/src/Makefile.am
> > @@ -54,6 +54,8 @@ spice_streaming_agent_SOURCES = \
> > concrete-agent.hpp \
> > error.cpp \
> > error.hpp \
> > + frame-log.cpp \
> > + frame-log.hpp \
> > mjpeg-fallback.cpp \
> > mjpeg-fallback.hpp \
> > jpeg.cpp \
> > diff --git a/src/frame-log.cpp b/src/frame-log.cpp
> > new file mode 100644
> > index 0000000..b0bd09e
> > --- /dev/null
> > +++ b/src/frame-log.cpp
> > @@ -0,0 +1,76 @@
> > +/* A utility logger for logging frames and/or time information.
> > + *
> > + * \copyright
> > + * Copyright 2018 Red Hat Inc. All rights reserved.
> > + */
> > +
> > +#include "frame-log.hpp"
> > +
> > +#include "error.hpp"
> > +#include "hexdump.h"
> > +
> > +#include <cstdarg>
> > +#include <string.h>
> > +#include <sys/time.h>
> > +
> > +
> > +namespace spice {
> > +namespace streaming_agent {
> > +
> > +FrameLog::FrameLog(const char *log_name, bool log_binary, bool log_frames) :
> > + log_binary(log_binary),
> > + log_frames(log_frames)
> > +{
> > + if (log_name) {
> > + log_file = fopen(log_name, "wb");
> > + if (!log_file) {
> > + throw Error(std::string("Failed to open log file '") + log_name + "': " + strerror(errno));
> > + }
> > + if (!log_binary) {
> > + setlinebuf(log_file);
> > + }
> > + }
> > +}
> > +
> > +FrameLog::~FrameLog()
> > +{
> > + if (log_file) {
> > + fclose(log_file);
> > + }
> > +}
> > +
> > +void FrameLog::log_stat(const char* format, ...)
> > +{
> > + if (log_file && !log_binary) {
> > + fprintf(log_file, "%" PRIu64 ": ", get_time());
> > + va_list ap;
> > + va_start(ap, format);
> > + vfprintf(log_file, format, ap);
> > + va_end(ap);
> > + fputs("\n", log_file);
> > + }
> > +}
> > +
> > +void FrameLog::log_frame(const void* buffer, size_t buffer_size)
> > +{
> > + if (log_file) {
> > + if (log_binary) {
> > + fwrite(buffer, buffer_size, 1, log_file);
> > + } else if (log_frames) {
> > + hexdump(buffer, buffer_size, log_file);
> > + }
> > + }
> > +}
> > +
> > +/**
> > + * Returns current time in microseconds.
> > + */
> > +uint64_t FrameLog::get_time()
> > +{
> > + struct timeval now;
> > + gettimeofday(&now, NULL);
> > +
> > + return (uint64_t)now.tv_sec * 1000000 + (uint64_t)now.tv_usec;
> > +}
>
> Does this really belong to the class?
Well, it's used directly inside it in the log_stat() method and twice
outside of it, but ultimately to log the time with the class.
So I stuck it in there, it's also kind of specific by returning the
microseconds, not that much potential it will be used elsewhere. And if
it will, we can always move it.
Didn't want to create a "utils.cpp" with 4 lines of code either (and I
dislike "utils.cpp"s in general :))
> > +
> > +}} // namespace spice::streaming_agent
> > diff --git a/src/frame-log.hpp b/src/frame-log.hpp
> > new file mode 100644
> > index 0000000..2ebe01b
> > --- /dev/null
> > +++ b/src/frame-log.hpp
> > @@ -0,0 +1,39 @@
> > +/* A utility logger for logging frames and/or time information.
> > + *
> > + * \copyright
> > + * Copyright 2018 Red Hat Inc. All rights reserved.
> > + */
> > +
> > +#ifndef SPICE_STREAMING_AGENT_FRAME_LOG_HPP
> > +#define SPICE_STREAMING_AGENT_FRAME_LOG_HPP
> > +
> > +#include <cinttypes>
> > +#include <stddef.h>
> > +#include <stdio.h>
> > +
> > +
> > +namespace spice {
> > +namespace streaming_agent {
> > +
> > +class FrameLog {
> > +public:
> > + FrameLog(const char *log_name, bool log_binary, bool log_frames);
> > + FrameLog(const FrameLog &) = delete;
> > + FrameLog &operator=(const FrameLog &) = delete;
> > + ~FrameLog();
> > +
> > + __attribute__ ((format (printf, 2, 3)))
> > + void log_stat(const char* format, ...);
> > + void log_frame(const void* buffer, size_t buffer_size);
> > +
> > + static uint64_t get_time();
> > +
> > +private:
> > + FILE *log_file = NULL;
> > + bool log_binary = false;
> > + bool log_frames = false;
> > +};
> > +
> > +}} // namespace spice::streaming_agent
> > +
> > +#endif // SPICE_STREAMING_AGENT_FRAME_LOG_HPP
> > diff --git a/src/spice-streaming-agent.cpp b/src/spice-streaming-agent.cpp
> > index 1121f35..aef49c7 100644
> > --- a/src/spice-streaming-agent.cpp
> > +++ b/src/spice-streaming-agent.cpp
> > @@ -5,8 +5,8 @@
> > */
> >
> > #include "concrete-agent.hpp"
> > -#include "hexdump.h"
> > #include "mjpeg-fallback.hpp"
> > +#include "frame-log.hpp"
> > #include "stream-port.hpp"
> > #include "error.hpp"
> >
> > @@ -57,8 +57,6 @@ struct SpiceStreamDataMessage
> >
> > static bool streaming_requested = false;
> > static bool quit_requested = false;
> > -static bool log_binary = false;
> > -static bool log_frames = false;
> > static std::set<SpiceVideoCodecType> client_codecs;
> >
> > static bool have_something_to_read(StreamPort &stream_port, bool blocking)
> > @@ -221,17 +219,6 @@ static void spice_stream_send_frame(StreamPort &stream_port, const void *buf, co
> > syslog(LOG_DEBUG, "Sent a frame of size %u\n", size);
> > }
> >
> > -/* returns current time in micro-seconds */
> > -static uint64_t get_time(void)
> > -{
> > - struct timeval now;
> > -
> > - gettimeofday(&now, NULL);
> > -
> > - return (uint64_t)now.tv_sec * 1000000 + (uint64_t)now.tv_usec;
> > -
> > -}
> > -
> > static void handle_interrupt(int intr)
> > {
> > syslog(LOG_INFO, "Got signal %d, exiting", intr);
> > @@ -330,14 +317,8 @@ static void cursor_changes(StreamPort *stream_port, Display *display, int event_
> > }
> > }
> >
> > -#define STAT_LOG(format, ...) do { \
> > - if (f_log && !log_binary) { \
> > - fprintf(f_log, "%" PRIu64 ": " format "\n", get_time(), ## __VA_ARGS__); \
> > - } \
> > -} while(0)
> > -
> > static void
> > -do_capture(StreamPort &stream_port, FILE *f_log)
> > +do_capture(StreamPort &stream_port, FrameLog &frame_log)
> > {
> > unsigned int frame_count = 0;
> > while (!quit_requested) {
> > @@ -361,13 +342,13 @@ do_capture(StreamPort &stream_port, FILE *f_log)
> > if (++frame_count % 100 == 0) {
> > syslog(LOG_DEBUG, "SENT %d frames\n", frame_count);
> > }
> > - uint64_t time_before = get_time();
> > + uint64_t time_before = FrameLog::get_time();
> >
> > - STAT_LOG("Capturing...");
> > + frame_log.log_stat("Capturing...");
> > FrameInfo frame = capture->CaptureFrame();
> > - STAT_LOG("Captured");
> > + frame_log.log_stat("Captured");
> >
> > - uint64_t time_after = get_time();
> > + uint64_t time_after = FrameLog::get_time();
> > syslog(LOG_DEBUG,
> > "got a frame -- size is %zu (%" PRIu64 " ms) "
> > "(%" PRIu64 " ms from last frame)(%" PRIu64 " us)\n",
> > @@ -385,18 +366,12 @@ do_capture(StreamPort &stream_port, FILE *f_log)
> > codec = capture->VideoCodecType();
> >
> > syslog(LOG_DEBUG, "wXh %uX%u codec=%u\n", width, height, codec);
> > - STAT_LOG("Started new stream wXh %uX%u codec=%u", width, height, codec);
> > + frame_log.log_stat("Started new stream wXh %uX%u codec=%u", width, height, codec);
> >
> > spice_stream_send_format(stream_port, width, height, codec);
> > }
> > - STAT_LOG("Frame of %zu bytes:", frame.buffer_size);
> > - if (f_log) {
> > - if (log_binary) {
> > - fwrite(frame.buffer, frame.buffer_size, 1, f_log);
> > - } else if (log_frames) {
> > - hexdump(frame.buffer, frame.buffer_size, f_log);
> > - }
> > - }
> > + frame_log.log_stat("Frame of %zu bytes:", frame.buffer_size);
> > + frame_log.log_frame(frame.buffer, frame.buffer_size);
> >
> > try {
> > spice_stream_send_frame(stream_port, frame.buffer, frame.buffer_size);
> > @@ -404,7 +379,7 @@ do_capture(StreamPort &stream_port, FILE *f_log)
> > syslog(e);
> > break;
> > }
> > - STAT_LOG("Sent");
> > + frame_log.log_stat("Sent");
> >
> > read_command(stream_port, false);
> > }
> > @@ -418,6 +393,8 @@ int main(int argc, char* argv[])
> > const char *stream_port_name = "/dev/virtio-ports/org.spice-space.stream.0";
> > int opt;
> > const char *log_filename = NULL;
> > + bool log_binary = false;
> > + bool log_frames = false;
> > int logmask = LOG_UPTO(LOG_WARNING);
> > const char *pluginsdir = PLUGINSDIR;
> > enum {
> > @@ -493,20 +470,10 @@ int main(int argc, char* argv[])
> >
> > register_interrupts();
> >
> > - FILE *f_log = NULL;
> > - if (log_filename) {
> > - f_log = fopen(log_filename, "wb");
> > - if (!f_log) {
> > - syslog(LOG_ERR, "Failed to open log file '%s': %s\n",
> > - log_filename, strerror(errno));
> > - return EXIT_FAILURE;
> > - }
> > - if (!log_binary) {
> > - setlinebuf(f_log);
> > - }
> > - for (const std::string& arg: old_args) {
> > - STAT_LOG("Args: %s", arg.c_str());
> > - }
> > + FrameLog frame_log(log_filename, log_binary, log_frames);
> > +
> > + for (const std::string& arg: old_args) {
> > + frame_log.log_stat("Args: %s", arg.c_str());
> > }
> > old_args.clear();
> >
> > @@ -531,17 +498,13 @@ int main(int argc, char* argv[])
> > std::thread cursor_th(cursor_changes, &stream_port, display, event_base);
> > cursor_th.detach();
> >
> > - do_capture(stream_port, f_log);
> > + do_capture(stream_port, frame_log);
> > }
> > catch (std::exception &err) {
> > syslog(LOG_ERR, "%s\n", err.what());
> > ret = EXIT_FAILURE;
> > }
> >
> > - if (f_log) {
> > - fclose(f_log);
> > - f_log = NULL;
> > - }
> > closelog();
> > return ret;
> > }
> > --
> > 2.17.1
> >
> > _______________________________________________
> > Spice-devel mailing list
> > Spice-devel at lists.freedesktop.org
> > https://lists.freedesktop.org/mailman/listinfo/spice-devel
>
>
More information about the Spice-devel
mailing list