Logging improvements to allow prettier displays in the server GUI.
authorCarl Hetherington <cth@carlh.net>
Fri, 9 Oct 2015 12:44:10 +0000 (13:44 +0100)
committerCarl Hetherington <cth@carlh.net>
Fri, 9 Oct 2015 12:45:12 +0000 (13:45 +0100)
32 files changed:
src/lib/audio_decoder_stream.cc
src/lib/config.cc
src/lib/cross.cc
src/lib/dcp_video.cc
src/lib/encoded_log_entry.cc [new file with mode: 0644]
src/lib/encoded_log_entry.h [new file with mode: 0644]
src/lib/encoder.cc
src/lib/environment_info.cc
src/lib/ffmpeg.cc
src/lib/ffmpeg_content.cc
src/lib/ffmpeg_decoder.cc
src/lib/file_log.cc
src/lib/file_log.h
src/lib/film.cc
src/lib/job.cc
src/lib/log.cc
src/lib/log.h
src/lib/log_entry.cc [new file with mode: 0644]
src/lib/log_entry.h [new file with mode: 0644]
src/lib/null_log.h
src/lib/player.cc
src/lib/server.cc
src/lib/string_log_entry.cc [new file with mode: 0644]
src/lib/string_log_entry.h [new file with mode: 0644]
src/lib/transcode_job.cc
src/lib/upload_job.cc
src/lib/video_content.cc
src/lib/video_decoder.cc
src/lib/writer.cc
src/lib/wscript
src/tools/dcpomatic_server.cc
src/wx/config_dialog.cc

index 97db8a9..274bf2d 100644 (file)
@@ -62,7 +62,7 @@ AudioDecoderStream::get (Frame frame, Frame length, bool accurate)
 {
        shared_ptr<ContentAudio> dec;
 
-       _content->film()->log()->log (String::compose ("-> ADS has request for %1 %2", frame, length), Log::TYPE_DEBUG_DECODE);
+       _content->film()->log()->log (String::compose ("-> ADS has request for %1 %2", frame, length), LogEntry::TYPE_DEBUG_DECODE);
 
        Frame const end = frame + length - 1;
 
@@ -136,7 +136,7 @@ AudioDecoderStream::get (Frame frame, Frame length, bool accurate)
 void
 AudioDecoderStream::audio (shared_ptr<const AudioBuffers> data, ContentTime time)
 {
-       _content->film()->log()->log (String::compose ("ADS receives %1 %2", time, data->frames ()), Log::TYPE_DEBUG_DECODE);
+       _content->film()->log()->log (String::compose ("ADS receives %1 %2", time, data->frames ()), LogEntry::TYPE_DEBUG_DECODE);
 
        if (_resampler) {
                data = _resampler->run (data);
index 64d794b..f00d8d1 100644 (file)
@@ -98,7 +98,7 @@ Config::set_defaults ()
        _check_for_updates = false;
        _check_for_test_updates = false;
        _maximum_j2k_bandwidth = 250000000;
-       _log_types = Log::TYPE_GENERAL | Log::TYPE_WARNING | Log::TYPE_ERROR;
+       _log_types = LogEntry::TYPE_GENERAL | LogEntry::TYPE_WARNING | LogEntry::TYPE_ERROR;
        _automatic_audio_analysis = false;
 #ifdef DCPOMATIC_WINDOWS
        _win32_console = false;
@@ -234,7 +234,7 @@ Config::read ()
        _maximum_j2k_bandwidth = f.optional_number_child<int> ("MaximumJ2KBandwidth").get_value_or (250000000);
        _allow_any_dcp_frame_rate = f.optional_bool_child ("AllowAnyDCPFrameRate").get_value_or (false);
 
-       _log_types = f.optional_number_child<int> ("LogTypes").get_value_or (Log::TYPE_GENERAL | Log::TYPE_WARNING | Log::TYPE_ERROR);
+       _log_types = f.optional_number_child<int> ("LogTypes").get_value_or (LogEntry::TYPE_GENERAL | LogEntry::TYPE_WARNING | LogEntry::TYPE_ERROR);
        _automatic_audio_analysis = f.optional_bool_child ("AutomaticAudioAnalysis").get_value_or (false);
 #ifdef DCPOMATIC_WINDOWS
        _win32_console = f.optional_bool_child ("Win32Console").get_value_or (false);
index 2689be2..9ca3fe2 100644 (file)
@@ -46,9 +46,9 @@
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_ERROR(...) log->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
-#define LOG_ERROR_NC(...) log->log (__VA_ARGS__, Log::TYPE_ERROR);
+#define LOG_GENERAL(...) log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_ERROR(...) log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
+#define LOG_ERROR_NC(...) log->log (__VA_ARGS__, LogEntry::TYPE_ERROR);
 
 using std::pair;
 using std::list;
index 82206c0..35cc282 100644 (file)
@@ -51,9 +51,9 @@
 #include <iomanip>
 #include <iostream>
 
-#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_DEBUG_ENCODE(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_DEBUG_ENCODE);
-#define LOG_TIMING(...) _log->microsecond_log (String::compose (__VA_ARGS__), Log::TYPE_TIMING);
+#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_DEBUG_ENCODE(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
+#define LOG_TIMING(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
 
 #include "i18n.h"
 
diff --git a/src/lib/encoded_log_entry.cc b/src/lib/encoded_log_entry.cc
new file mode 100644 (file)
index 0000000..a818034
--- /dev/null
@@ -0,0 +1,49 @@
+/*
+    Copyright (C) 2015 Carl Hetherington <cth@carlh.net>
+
+    This program is free software; you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation; either version 2 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program; if not, write to the Free Software
+    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+
+*/
+
+#include "encoded_log_entry.h"
+#include "safe_stringstream.h"
+
+using std::string;
+using std::fixed;
+
+EncodedLogEntry::EncodedLogEntry (int frame, string ip, double receive, double encode, double send)
+       : LogEntry (LogEntry::TYPE_GENERAL)
+       , _frame (frame)
+       , _ip (ip)
+       , _receive (receive)
+       , _encode (encode)
+       , _send (send)
+{
+
+}
+
+string
+EncodedLogEntry::message () const
+{
+       SafeStringStream m;
+       m.precision (2);
+       m << fixed
+         << "Encoded frame " << _frame << " from " << _ip << ": "
+         << "receive " << _receive << "s "
+         << "encode " << _encode << "s "
+         << "send " << _send << "s.";
+
+       return m.str ();
+}
diff --git a/src/lib/encoded_log_entry.h b/src/lib/encoded_log_entry.h
new file mode 100644 (file)
index 0000000..0037d8b
--- /dev/null
@@ -0,0 +1,35 @@
+/*
+    Copyright (C) 2015 Carl Hetherington <cth@carlh.net>
+
+    This program is free software; you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation; either version 2 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program; if not, write to the Free Software
+    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+
+*/
+
+#include "log_entry.h"
+
+class EncodedLogEntry : public LogEntry
+{
+public:
+       EncodedLogEntry (int frame, std::string ip, double receive, double encode, double send);
+
+       std::string message () const;
+
+private:
+       int _frame;
+       std::string _ip;
+       double _receive;
+       double _encode;
+       double _send;
+};
index ef58ca0..f7a6670 100644 (file)
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_GENERAL);
-#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
-#define LOG_TIMING(...) _film->log()->microsecond_log (String::compose (__VA_ARGS__), Log::TYPE_TIMING);
+#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
+#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
+#define LOG_TIMING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
 
 using std::list;
 using std::cout;
index 364973f..ecb80fc 100644 (file)
@@ -42,8 +42,8 @@ extern "C" {
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) log->log (__VA_ARGS__, Log::TYPE_GENERAL);
+#define LOG_GENERAL(...) log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) log->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
 
 using std::string;
 using std::list;
index 29dee2c..6103ccd 100644 (file)
@@ -99,7 +99,7 @@ FFmpeg::ffmpeg_log_callback (void* ptr, int level, const char* fmt, va_list vl)
        if (log) {
                string str (line);
                boost::algorithm::trim (str);
-               log->log (String::compose ("FFmpeg: %1", str), Log::TYPE_GENERAL);
+               log->log (String::compose ("FFmpeg: %1", str), LogEntry::TYPE_GENERAL);
        } else {
                cerr << line;
        }
index 84e474a..2c2d36a 100644 (file)
@@ -42,7 +42,7 @@ extern "C" {
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
+#define LOG_GENERAL(...) film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
 
 using std::string;
 using std::vector;
index 3fdb2f2..83bce18 100644 (file)
@@ -47,10 +47,10 @@ extern "C" {
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_ERROR(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
-#define LOG_WARNING_NC(...) _log->log (__VA_ARGS__, Log::TYPE_WARNING);
-#define LOG_WARNING(...) _log->log (String::compose (__VA_ARGS__), Log::TYPE_WARNING);
+#define LOG_GENERAL(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_ERROR(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
+#define LOG_WARNING_NC(...) _log->log (__VA_ARGS__, LogEntry::TYPE_WARNING);
+#define LOG_WARNING(...) _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_WARNING);
 
 using std::cout;
 using std::vector;
index b3c9797..1557bbd 100644 (file)
@@ -25,6 +25,7 @@
 using std::cout;
 using std::string;
 using std::max;
+using boost::shared_ptr;
 
 /** @param file Filename to write log to */
 FileLog::FileLog (boost::filesystem::path file)
@@ -34,15 +35,15 @@ FileLog::FileLog (boost::filesystem::path file)
 }
 
 void
-FileLog::do_log (string m)
+FileLog::do_log (shared_ptr<const LogEntry> entry)
 {
        FILE* f = fopen_boost (_file, "a");
        if (!f) {
-               cout << "(could not log to " << _file.string() << "): " << m << "\n";
+               cout << "(could not log to " << _file.string() << "): " << entry.get() << "\n";
                return;
        }
 
-       fprintf (f, "%s\n", m.c_str ());
+       fprintf (f, "%s\n", entry->get().c_str ());
        fclose (f);
 }
 
index 1051ad1..6499920 100644 (file)
@@ -27,7 +27,7 @@ public:
        std::string head_and_tail (int amount = 1024) const;
 
 private:
-       void do_log (std::string m);
+       void do_log (boost::shared_ptr<const LogEntry> entry);
        /** filename to write to */
        boost::filesystem::path _file;
 };
index 37d5c34..a50aad8 100644 (file)
@@ -86,8 +86,8 @@ using boost::dynamic_pointer_cast;
 using boost::optional;
 using boost::is_any_of;
 
-#define LOG_GENERAL(...) log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) log()->log (__VA_ARGS__, Log::TYPE_GENERAL);
+#define LOG_GENERAL(...) log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
 
 /* 5 -> 6
  * AudioMapping XML changed.
index 42d6160..35f5834 100644 (file)
@@ -42,7 +42,7 @@ using boost::shared_ptr;
 using boost::optional;
 using boost::function;
 
-#define LOG_ERROR_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_ERROR);
+#define LOG_ERROR_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_ERROR);
 
 /** @param film Associated film, or 0 */
 Job::Job (shared_ptr<const Film> film)
@@ -325,7 +325,7 @@ Job::set_error (string s, string d)
        if (_film) {
                LOG_ERROR_NC (s);
                LOG_ERROR_NC (d);
-               _film->log()->log (String::compose ("Error in job: %1 (%2)", s, d), Log::TYPE_ERROR);
+               _film->log()->log (String::compose ("Error in job: %1 (%2)", s, d), LogEntry::TYPE_ERROR);
        }
 
        boost::mutex::scoped_lock lm (_state_mutex);
index 2e5cc54..0f7a59f 100644 (file)
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2015 Carl Hetherington <cth@carlh.net>
 
     This program is free software; you can redistribute it and/or modify
     it under the terms of the GNU General Public License as published by
 #include "cross.h"
 #include "config.h"
 #include "safe_stringstream.h"
+#include "string_log_entry.h"
 #include <time.h>
 #include <cstdio>
 
 #include "i18n.h"
 
-using namespace std;
-
-int const Log::TYPE_GENERAL      = 0x1;
-int const Log::TYPE_WARNING      = 0x2;
-int const Log::TYPE_ERROR        = 0x4;
-int const Log::TYPE_DEBUG_DECODE = 0x8;
-int const Log::TYPE_DEBUG_ENCODE = 0x10;
-int const Log::TYPE_TIMING       = 0x20;
+using std::string;
+using boost::shared_ptr;
 
 Log::Log ()
        : _types (0)
@@ -52,50 +47,29 @@ Log::config_changed ()
        set_types (Config::instance()->log_types ());
 }
 
-/** @param n String to log */
 void
-Log::log (string message, int type)
+Log::log (shared_ptr<const LogEntry> e)
 {
        boost::mutex::scoped_lock lm (_mutex);
 
-       if ((_types & type) == 0) {
+       if ((_types & e->type()) == 0) {
                return;
        }
 
-       time_t t;
-       time (&t);
-       string a = ctime (&t);
-
-       SafeStringStream s;
-       s << a.substr (0, a.length() - 1) << N_(": ");
-
-       if (type & TYPE_ERROR) {
-               s << "ERROR: ";
-       }
-
-       if (type & TYPE_WARNING) {
-               s << "WARNING: ";
-       }
-
-       s << message;
-       do_log (s.str ());
+       do_log (e);
 }
 
+/** @param n String to log */
 void
-Log::microsecond_log (string m, int t)
+Log::log (string message, int type)
 {
        boost::mutex::scoped_lock lm (_mutex);
 
-       if ((_types & t) == 0) {
+       if ((_types & type) == 0) {
                return;
        }
 
-       struct timeval tv;
-       gettimeofday (&tv, 0);
-
-       SafeStringStream s;
-       s << tv.tv_sec << N_(":") << tv.tv_usec << N_(" ") << m;
-       do_log (s.str ());
+       do_log (shared_ptr<const LogEntry> (new StringLogEntry (type, message)));
 }
 
 void
@@ -103,13 +77,13 @@ Log::dcp_log (dcp::NoteType type, string m)
 {
        switch (type) {
        case dcp::DCP_PROGRESS:
-               log (m, TYPE_GENERAL);
+               do_log (shared_ptr<const LogEntry> (new StringLogEntry (LogEntry::TYPE_GENERAL, m)));
                break;
        case dcp::DCP_ERROR:
-               log (m, TYPE_ERROR);
+               do_log (shared_ptr<const LogEntry> (new StringLogEntry (LogEntry::TYPE_ERROR, m)));
                break;
        case dcp::DCP_NOTE:
-               log (m, TYPE_WARNING);
+               do_log (shared_ptr<const LogEntry> (new StringLogEntry (LogEntry::TYPE_WARNING, m)));
                break;
        }
 }
index 2acef66..2c44f32 100644 (file)
@@ -24,6 +24,7 @@
  *  @brief A very simple logging class.
  */
 
+#include "log_entry.h"
 #include <dcp/types.h>
 #include <boost/thread/mutex.hpp>
 #include <boost/filesystem.hpp>
@@ -39,15 +40,8 @@ public:
        Log ();
        virtual ~Log () {}
 
-       static const int TYPE_GENERAL;
-       static const int TYPE_WARNING;
-       static const int TYPE_ERROR;
-       static const int TYPE_DEBUG_DECODE;
-       static const int TYPE_DEBUG_ENCODE;
-       static const int TYPE_TIMING;
-
+       void log (boost::shared_ptr<const LogEntry> entry);
        void log (std::string message, int type);
-       void microsecond_log (std::string message, int type);
        void dcp_log (dcp::NoteType type, std::string message);
 
        void set_types (int types);
@@ -63,7 +57,7 @@ protected:
        mutable boost::mutex _mutex;
 
 private:
-       virtual void do_log (std::string m) = 0;
+       virtual void do_log (boost::shared_ptr<const LogEntry> entry) = 0;
        void config_changed ();
 
        /** bit-field of log types which should be put into the log (others are ignored) */
diff --git a/src/lib/log_entry.cc b/src/lib/log_entry.cc
new file mode 100644 (file)
index 0000000..9b399e4
--- /dev/null
@@ -0,0 +1,70 @@
+/*
+    Copyright (C) 2015 Carl Hetherington <cth@carlh.net>
+
+    This program is free software; you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation; either version 2 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program; if not, write to the Free Software
+    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+
+*/
+
+#include "log_entry.h"
+#include "safe_stringstream.h"
+
+#include "i18n.h"
+
+int const LogEntry::TYPE_GENERAL      = 0x1;
+int const LogEntry::TYPE_WARNING      = 0x2;
+int const LogEntry::TYPE_ERROR        = 0x4;
+int const LogEntry::TYPE_DEBUG_DECODE = 0x8;
+int const LogEntry::TYPE_DEBUG_ENCODE = 0x10;
+int const LogEntry::TYPE_TIMING       = 0x20;
+
+using std::string;
+
+LogEntry::LogEntry (int type)
+       : _type (type)
+{
+       gettimeofday (&_time, 0);
+}
+
+string
+LogEntry::get () const
+{
+       SafeStringStream s;
+       if (_type & TYPE_TIMING) {
+               s << _time.tv_sec << ":" << _time.tv_usec;
+       } else {
+               char buffer[64];
+               struct tm* t = localtime (&_time.tv_sec);
+               strftime (buffer, 64, "%c", t);
+               string a (buffer);
+               s << a.substr (0, a.length() - 1) << N_(": ");
+       }
+
+       if (_type & TYPE_ERROR) {
+               s << "ERROR: ";
+       }
+
+       if (_type & TYPE_WARNING) {
+               s << "WARNING: ";
+       }
+
+       s << message ();
+       return s.str ();
+}
+
+double
+LogEntry::seconds () const
+{
+       return _time.tv_sec + double (_time.tv_usec / 1000000);
+}
diff --git a/src/lib/log_entry.h b/src/lib/log_entry.h
new file mode 100644 (file)
index 0000000..29c7090
--- /dev/null
@@ -0,0 +1,51 @@
+/*
+    Copyright (C) 2015 Carl Hetherington <cth@carlh.net>
+
+    This program is free software; you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation; either version 2 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program; if not, write to the Free Software
+    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+
+*/
+
+#ifndef DCPOMATIC_LOG_ENTRY_H
+#define DCPOMATIC_LOG_ENTRY_H
+
+#include <string>
+
+class LogEntry
+{
+public:
+
+       static const int TYPE_GENERAL;
+       static const int TYPE_WARNING;
+       static const int TYPE_ERROR;
+       static const int TYPE_DEBUG_DECODE;
+       static const int TYPE_DEBUG_ENCODE;
+       static const int TYPE_TIMING;
+
+       LogEntry (int type);
+
+       virtual std::string message () const = 0;
+
+       int type () const {
+               return _type;
+       }
+       std::string get () const;
+       double seconds () const;
+
+private:
+       struct timeval _time;
+       int _type;
+};
+
+#endif
index 304c5ec..6e29ad3 100644 (file)
@@ -27,5 +27,5 @@ public:
        }
 
 private:
-       void do_log (std::string) {}
+       void do_log (boost::shared_ptr<const LogEntry>) {}
 };
index d316711..0606a93 100644 (file)
@@ -57,7 +57,7 @@
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
+#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
 
 using std::list;
 using std::cout;
index f0b2d98..5d85d88 100644 (file)
@@ -35,6 +35,7 @@
 #include "raw_convert.h"
 #include "compose.hpp"
 #include "log.h"
+#include "encoded_log_entry.h"
 #include <libcxml/cxml.h>
 #include <libxml++/libxml++.h>
 #include <boost/algorithm/string.hpp>
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...)    _log->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) _log->log (__VA_ARGS__, Log::TYPE_GENERAL);
-#define LOG_ERROR(...)      _log->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
-#define LOG_ERROR_NC(...)   _log->log (__VA_ARGS__, Log::TYPE_ERROR);
+#define LOG_GENERAL(...)    _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) _log->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
+#define LOG_ERROR(...)      _log->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
+#define LOG_ERROR_NC(...)   _log->log (__VA_ARGS__, LogEntry::TYPE_ERROR);
 
 using std::string;
 using std::vector;
@@ -187,19 +188,20 @@ Server::worker_thread ()
                        struct timeval end;
                        gettimeofday (&end, 0);
 
-                       SafeStringStream message;
-                       message.precision (2);
-                       message << fixed
-                               << "Encoded frame " << frame << " from " << ip << ": "
-                               << "receive " << (seconds(after_read) - seconds(start)) << "s "
-                               << "encode " << (seconds(after_encode) - seconds(after_read)) << "s "
-                               << "send " << (seconds(end) - seconds(after_encode)) << "s.";
+                       shared_ptr<EncodedLogEntry> e (
+                               new EncodedLogEntry (
+                                       frame, ip,
+                                       seconds(after_read) - seconds(start),
+                                       seconds(after_encode) - seconds(after_read),
+                                       seconds(end) - seconds(after_encode)
+                                       )
+                               );
 
                        if (_verbose) {
-                               cout << message.str() << "\n";
+                               cout << e->get() << "\n";
                        }
 
-                       LOG_GENERAL_NC (message.str ());
+                       _log->log (e);
                }
 
                _full_condition.notify_all ();
diff --git a/src/lib/string_log_entry.cc b/src/lib/string_log_entry.cc
new file mode 100644 (file)
index 0000000..9763726
--- /dev/null
@@ -0,0 +1,32 @@
+/*
+    Copyright (C) 2015 Carl Hetherington <cth@carlh.net>
+
+    This program is free software; you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation; either version 2 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program; if not, write to the Free Software
+    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+
+*/
+
+#include "string_log_entry.h"
+#include "safe_stringstream.h"
+
+#include "i18n.h"
+
+using std::string;
+
+StringLogEntry::StringLogEntry (int type, string message)
+       : LogEntry (type)
+       , _message (message)
+{
+
+}
diff --git a/src/lib/string_log_entry.h b/src/lib/string_log_entry.h
new file mode 100644 (file)
index 0000000..365463f
--- /dev/null
@@ -0,0 +1,34 @@
+/*
+    Copyright (C) 2015 Carl Hetherington <cth@carlh.net>
+
+    This program is free software; you can redistribute it and/or modify
+    it under the terms of the GNU General Public License as published by
+    the Free Software Foundation; either version 2 of the License, or
+    (at your option) any later version.
+
+    This program is distributed in the hope that it will be useful,
+    but WITHOUT ANY WARRANTY; without even the implied warranty of
+    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+    GNU General Public License for more details.
+
+    You should have received a copy of the GNU General Public License
+    along with this program; if not, write to the Free Software
+    Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
+
+*/
+
+#include "log_entry.h"
+#include <string>
+
+class StringLogEntry : public LogEntry
+{
+public:
+       StringLogEntry (int type, std::string message);
+
+       std::string message () const {
+               return _message;
+       }
+
+private:
+       std::string _message;
+};
index f10078f..7d11d51 100644 (file)
@@ -32,8 +32,8 @@
 
 #include "i18n.h"
 
-#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_GENERAL);
-#define LOG_ERROR_NC(...)   _film->log()->log (__VA_ARGS__, Log::TYPE_ERROR);
+#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
+#define LOG_ERROR_NC(...)   _film->log()->log (__VA_ARGS__, LogEntry::TYPE_ERROR);
 
 using std::string;
 using std::fixed;
index 44114b8..90ebafd 100644 (file)
@@ -32,7 +32,7 @@
 
 #include "i18n.h"
 
-#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
 
 using std::string;
 using std::min;
index 5a2bef1..ff54c40 100644 (file)
@@ -38,7 +38,7 @@
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
+#define LOG_GENERAL(...) film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
 
 int const VideoContentProperty::VIDEO_SIZE       = 0;
 int const VideoContentProperty::VIDEO_FRAME_RATE  = 1;
index e87fa2e..88f88c1 100644 (file)
@@ -75,7 +75,7 @@ VideoDecoder::get_video (Frame frame, bool accurate)
           one after the end of _decoded_video we need to seek.
        */
 
-       _video_content->film()->log()->log (String::compose ("VD has request for %1", frame), Log::TYPE_DEBUG_DECODE);
+       _video_content->film()->log()->log (String::compose ("VD has request for %1", frame), LogEntry::TYPE_DEBUG_DECODE);
 
        if (_decoded_video.empty() || frame < _decoded_video.front().frame || frame > (_decoded_video.back().frame + 1)) {
                seek (ContentTime::from_frames (frame, _video_content->video_frame_rate()), accurate);
@@ -240,7 +240,7 @@ VideoDecoder::video (shared_ptr<const ImageProxy> image, Frame frame)
                return;
        }
 
-       _video_content->film()->log()->log (String::compose ("VD receives %1", frame), Log::TYPE_DEBUG_DECODE);
+       _video_content->film()->log()->log (String::compose ("VD receives %1", frame), LogEntry::TYPE_DEBUG_DECODE);
 
        /* We may receive the same frame index twice for 3D, and we need to know
           when that happens.
index 3f85673..0653daa 100644 (file)
 
 #include "i18n.h"
 
-#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_GENERAL);
-#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_GENERAL);
-#define LOG_DEBUG_ENCODE(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_DEBUG_ENCODE);
-#define LOG_TIMING(...) _film->log()->microsecond_log (String::compose (__VA_ARGS__), Log::TYPE_TIMING);
-#define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, Log::TYPE_WARNING);
-#define LOG_WARNING(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_WARNING);
-#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), Log::TYPE_ERROR);
+#define LOG_GENERAL(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_GENERAL);
+#define LOG_GENERAL_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_GENERAL);
+#define LOG_DEBUG_ENCODE(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
+#define LOG_TIMING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_TIMING);
+#define LOG_WARNING_NC(...) _film->log()->log (__VA_ARGS__, LogEntry::TYPE_WARNING);
+#define LOG_WARNING(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_WARNING);
+#define LOG_ERROR(...) _film->log()->log (String::compose (__VA_ARGS__), LogEntry::TYPE_ERROR);
 
 /* OS X strikes again */
 #undef set_key
index bc61c87..6e06d67 100644 (file)
@@ -55,6 +55,7 @@ sources = """
           dolby_cp750.cc
           emailer.cc
           encoder.cc
+          encoded_log_entry.cc
           environment_info.cc
           examine_content_job.cc
           exceptions.cc
@@ -84,6 +85,7 @@ sources = """
           job_manager.cc
           json_server.cc
           log.cc
+          log_entry.cc
           magick_image_proxy.cc
           md5_digester.cc
           mid_side_decoder.cc
@@ -110,6 +112,7 @@ sources = """
           sndfile_content.cc
           sndfile_decoder.cc
           sndfile_examiner.cc
+          string_log_entry.cc
           subrip.cc
           subrip_content.cc
           subrip_decoder.cc
index 37fcc34..d876832 100644 (file)
 #include "wx/wx_util.h"
 #include "wx/wx_signal_manager.h"
 #include "lib/util.h"
+#include "lib/encoded_log_entry.h"
 #include "lib/server.h"
 #include "lib/config.h"
 #include "lib/log.h"
+#include "lib/raw_convert.h"
 #include "lib/signaller.h"
 #include <wx/taskbar.h>
 #include <wx/icon.h>
 #include <boost/thread.hpp>
 #include <boost/foreach.hpp>
+#include <boost/optional.hpp>
 #include <iostream>
 
 using std::cout;
 using std::string;
 using std::exception;
 using std::list;
+using std::fixed;
+using std::setprecision;
 using boost::shared_ptr;
 using boost::thread;
 using boost::bind;
+using boost::optional;
+using boost::dynamic_pointer_cast;
 
 enum {
        ID_status = 1,
@@ -46,7 +53,7 @@ enum {
 
 static int const log_lines = 32;
 
-class MemoryLog : public Log, public Signaller
+class ServerLog : public Log, public Signaller
 {
 public:
 
@@ -63,24 +70,66 @@ public:
                return "";
        }
 
+       float fps () const {
+               boost::mutex::scoped_lock lm (_state_mutex);
+               return _fps;
+       }
+
        boost::signals2::signal<void(string)> Appended;
        boost::signals2::signal<void(int)> Removed;
 
 private:
-       void do_log (string m)
+       void do_log (shared_ptr<const LogEntry> entry)
        {
-               _log.push_back (m);
-               emit (boost::bind (boost::ref (Appended), m));
+               time_t const s = entry->seconds ();
+               struct tm* local = localtime (&s);
+               if (
+                       !_last_time ||
+                       local->tm_yday != _last_time->tm_yday ||
+                       local->tm_year != _last_time->tm_year ||
+                       local->tm_hour != _last_time->tm_hour ||
+                       local->tm_min != _last_time->tm_min
+                       ) {
+                       char buffer[64];
+                       strftime (buffer, 64, "%c", local);
+                       append (buffer);
+               }
+
+               append (entry->message ());
                if (_log.size() > log_lines) {
                        emit (boost::bind (boost::ref (Removed), _log.front().length()));
                        _log.pop_front ();
                }
+               _last_time = *local;
+
+               shared_ptr<const EncodedLogEntry> encoded = dynamic_pointer_cast<const EncodedLogEntry> (entry);
+               if (encoded) {
+                       _history.push_back (encoded->seconds ());
+                       if (_history.size() > 48) {
+                               _history.pop_front ();
+                       }
+                       if (_history.size() > 2) {
+                               boost::mutex::scoped_lock lm (_state_mutex);
+                               _fps = _history.size() / (_history.back() - _history.front());
+                       }
+               }
+       }
+
+       void append (string s)
+       {
+               _log.push_back (s);
+               emit (boost::bind (boost::ref (Appended), s));
        }
 
        list<string> _log;
+       optional<struct tm> _last_time;
+       std::list<double> _history;
+
+       mutable boost::mutex _state_mutex;
+       float _fps;
 };
 
-static shared_ptr<MemoryLog> memory_log (new MemoryLog);
+static shared_ptr<ServerLog> server_log (new ServerLog);
 
 class StatusDialog : public wxDialog
 {
@@ -92,8 +141,14 @@ public:
                        wxDEFAULT_DIALOG_STYLE | wxRESIZE_BORDER
                        )
        {
-               _sizer = new wxFlexGridSizer (1, DCPOMATIC_SIZER_GAP, DCPOMATIC_SIZER_GAP);
-               _sizer->AddGrowableCol (0, 1);
+               wxFlexGridSizer* state_sizer = new wxFlexGridSizer (2, DCPOMATIC_SIZER_GAP, DCPOMATIC_SIZER_GAP);
+
+               add_label_to_sizer (state_sizer, this, _("Frames per second"), true);
+               _fps = new wxStaticText (this, wxID_ANY, wxT(""));
+               state_sizer->Add (_fps);
+
+               wxFlexGridSizer* log_sizer = new wxFlexGridSizer (1, DCPOMATIC_SIZER_GAP, DCPOMATIC_SIZER_GAP);
+               log_sizer->AddGrowableCol (0, 1);
 
                wxClientDC dc (this);
                wxSize size = dc.GetTextExtent (wxT ("This is the length of the file label it should be quite long"));
@@ -101,17 +156,24 @@ public:
                SetSize (700, height + DCPOMATIC_SIZER_GAP * 2);
 
                _text = new wxTextCtrl (
-                       this, wxID_ANY, std_to_wx (memory_log->get()), wxDefaultPosition, wxSize (-1, height),
+                       this, wxID_ANY, std_to_wx (server_log->get()), wxDefaultPosition, wxSize (-1, height),
                        wxTE_READONLY | wxTE_MULTILINE
                        );
 
-               _sizer->Add (_text, 1, wxEXPAND | wxALL, DCPOMATIC_SIZER_GAP);
+               log_sizer->Add (_text, 1, wxEXPAND);
 
-               SetSizer (_sizer);
-               _sizer->Layout ();
+               wxBoxSizer* overall_sizer = new wxBoxSizer (wxVERTICAL);
+               overall_sizer->Add (state_sizer, 0, wxALL, DCPOMATIC_SIZER_GAP);
+               overall_sizer->Add (log_sizer, 1, wxEXPAND | wxALL, DCPOMATIC_SIZER_GAP);
+               SetSizer (overall_sizer);
+               overall_sizer->Layout ();
+
+               Bind (wxEVT_TIMER, boost::bind (&StatusDialog::update_state, this));
+               _timer.reset (new wxTimer (this));
+               _timer->Start (1000);
 
-               memory_log->Appended.connect (bind (&StatusDialog::appended, this, _1));
-               memory_log->Removed.connect (bind (&StatusDialog::removed, this, _1));
+               server_log->Appended.connect (bind (&StatusDialog::appended, this, _1));
+               server_log->Removed.connect (bind (&StatusDialog::removed, this, _1));
        }
 
 private:
@@ -125,8 +187,16 @@ private:
                _text->Remove (0, n + 1);
        }
 
-       wxFlexGridSizer* _sizer;
+       void update_state ()
+       {
+               SafeStringStream s;
+               s << fixed << setprecision(1) << server_log->fps ();
+               _fps->SetLabel (std_to_wx (s.str()));
+       }
+
        wxTextCtrl* _text;
+       wxStaticText* _fps;
+       boost::shared_ptr<wxTimer> _timer;
 };
 
 class TaskBarIcon : public wxTaskBarIcon
@@ -218,7 +288,7 @@ private:
 
        void main_thread ()
        try {
-               Server server (memory_log, false);
+               Server server (server_log, false);
                server.run (Config::instance()->num_local_encoding_threads ());
        } catch (...) {
                store_current ();
index 722fa59..f3dbaf6 100644 (file)
@@ -1357,12 +1357,12 @@ private:
                checked_set (_maximum_j2k_bandwidth, config->maximum_j2k_bandwidth() / 1000000);
                checked_set (_allow_any_dcp_frame_rate, config->allow_any_dcp_frame_rate ());
                checked_set (_only_servers_encode, config->only_servers_encode ());
-               checked_set (_log_general, config->log_types() & Log::TYPE_GENERAL);
-               checked_set (_log_warning, config->log_types() & Log::TYPE_WARNING);
-               checked_set (_log_error, config->log_types() & Log::TYPE_ERROR);
-               checked_set (_log_timing, config->log_types() & Log::TYPE_TIMING);
-               checked_set (_log_debug_decode, config->log_types() & Log::TYPE_DEBUG_DECODE);
-               checked_set (_log_debug_encode, config->log_types() & Log::TYPE_DEBUG_ENCODE);
+               checked_set (_log_general, config->log_types() & LogEntry::TYPE_GENERAL);
+               checked_set (_log_warning, config->log_types() & LogEntry::TYPE_WARNING);
+               checked_set (_log_error, config->log_types() & LogEntry::TYPE_ERROR);
+               checked_set (_log_timing, config->log_types() & LogEntry::TYPE_TIMING);
+               checked_set (_log_debug_decode, config->log_types() & LogEntry::TYPE_DEBUG_DECODE);
+               checked_set (_log_debug_encode, config->log_types() & LogEntry::TYPE_DEBUG_ENCODE);
 #ifdef DCPOMATIC_WINDOWS
                checked_set (_win32_console, config->win32_console());
 #endif
@@ -1387,22 +1387,22 @@ private:
        {
                int types = 0;
                if (_log_general->GetValue ()) {
-                       types |= Log::TYPE_GENERAL;
+                       types |= LogEntry::TYPE_GENERAL;
                }
                if (_log_warning->GetValue ()) {
-                       types |= Log::TYPE_WARNING;
+                       types |= LogEntry::TYPE_WARNING;
                }
                if (_log_error->GetValue ())  {
-                       types |= Log::TYPE_ERROR;
+                       types |= LogEntry::TYPE_ERROR;
                }
                if (_log_timing->GetValue ()) {
-                       types |= Log::TYPE_TIMING;
+                       types |= LogEntry::TYPE_TIMING;
                }
                if (_log_debug_decode->GetValue ()) {
-                       types |= Log::TYPE_DEBUG_DECODE;
+                       types |= LogEntry::TYPE_DEBUG_DECODE;
                }
                if (_log_debug_encode->GetValue ()) {
-                       types |= Log::TYPE_DEBUG_ENCODE;
+                       types |= LogEntry::TYPE_DEBUG_ENCODE;
                }
                Config::instance()->set_log_types (types);
        }