More player debugging for butler video-full states.
[dcpomatic.git] / src / tools / dcpomatic_player.cc
index b39e59d6ba302dc1caa80cdf88e3bc4361dcd2fe..6e4f9960c167feb5d71db5ccd258b5d26dce2829 100644 (file)
@@ -53,6 +53,7 @@
 #include "lib/lock_file_checker.h"
 #include "lib/ffmpeg_content.h"
 #include "lib/dcpomatic_log.h"
+#include "lib/file_log.h"
 #include <dcp/dcp.h>
 #include <dcp/raw_convert.h>
 #include <dcp/exceptions.h>
@@ -147,7 +148,7 @@ public:
 #endif
 
                _config_changed_connection = Config::instance()->Changed.connect (boost::bind (&DOMFrame::config_changed, this, _1));
-               update_from_config ();
+               update_from_config (Config::PLAYER_DEBUG_LOG);
 
                Bind (wxEVT_MENU, boost::bind (&DOMFrame::file_open, this), ID_file_open);
                Bind (wxEVT_MENU, boost::bind (&DOMFrame::file_add_ov, this), ID_file_add_ov);
@@ -184,7 +185,6 @@ public:
                _viewer->set_dcp_decode_reduction (Config::instance()->decode_reduction ());
                _viewer->PlaybackPermitted.connect (bind(&DOMFrame::playback_permitted, this));
                _viewer->Started.connect (bind(&DOMFrame::playback_started, this, _1));
-               _viewer->Seeked.connect (bind(&DOMFrame::playback_seeked, this, _1));
                _viewer->Stopped.connect (bind(&DOMFrame::playback_stopped, this, _1));
                _info = new PlayerInformation (_overall_panel, _viewer);
                setup_main_sizer (Config::instance()->player_mode());
@@ -288,13 +288,6 @@ public:
 
        void playback_started (DCPTime time)
        {
-               optional<boost::filesystem::path> log = Config::instance()->player_log_file();
-               if (!log) {
-                       return;
-               }
-
-               FILE* f = fopen_boost(*log, "a");
-
                /* XXX: this only logs the first piece of content; probably should be each piece? */
 
                shared_ptr<DCPContent> dcp = dynamic_pointer_cast<DCPContent>(_film->content().front());
@@ -308,40 +301,26 @@ public:
                        }
                        DCPOMATIC_ASSERT (playing_cpl);
 
-                       fprintf (
-                               f,
-                               "%s playback-started %s %s %s\n",
-                               dcp::LocalTime().as_string().c_str(),
-                               time.timecode(_film->video_frame_rate()).c_str(),
-                               dcp->directories().front().string().c_str(),
-                               playing_cpl->annotation_text().c_str()
+                       _controls->log (
+                               wxString::Format(
+                                       "playback-started %s %s %s",
+                                       time.timecode(_film->video_frame_rate()).c_str(),
+                                       dcp->directories().front().string().c_str(),
+                                       playing_cpl->annotation_text().c_str()
+                                       )
                                );
                }
 
                shared_ptr<FFmpegContent> ffmpeg = dynamic_pointer_cast<FFmpegContent>(_film->content().front());
                if (ffmpeg) {
-                       fprintf (
-                               f,
-                               "%s playback-started %s %s\n",
-                               dcp::LocalTime().as_string().c_str(),
-                               time.timecode(_film->video_frame_rate()).c_str(),
-                               ffmpeg->path(0).string().c_str()
+                       _controls->log (
+                               wxString::Format(
+                                       "playback-started %s %s",
+                                       time.timecode(_film->video_frame_rate()).c_str(),
+                                       ffmpeg->path(0).string().c_str()
+                                       )
                                );
                }
-
-               fclose (f);
-       }
-
-       void playback_seeked (DCPTime time)
-       {
-               optional<boost::filesystem::path> log = Config::instance()->player_log_file();
-               if (!log) {
-                       return;
-               }
-
-               FILE* f = fopen_boost(*log, "a");
-               fprintf (f, "%s playback-seeked %s\n", dcp::LocalTime().as_string().c_str(), time.timecode(_film->video_frame_rate()).c_str());
-               fclose (f);
        }
 
        void playback_stopped (DCPTime time)
@@ -354,14 +333,7 @@ public:
                }
 #endif
 
-               optional<boost::filesystem::path> log = Config::instance()->player_log_file();
-               if (!log) {
-                       return;
-               }
-
-               FILE* f = fopen_boost(*log, "a");
-               fprintf (f, "%s playback-stopped %s\n", dcp::LocalTime().as_string().c_str(), time.timecode(_film->video_frame_rate()).c_str());
-               fclose (f);
+               _controls->log (wxString::Format("playback-stopped %s", time.timecode(_film->video_frame_rate()).c_str()));
        }
 
        void set_decode_reduction (optional<int> reduction)
@@ -383,7 +355,9 @@ public:
                        if (!ok || !report_errors_from_last_job(this)) {
                                return;
                        }
+#ifndef DCPOMATIC_VARIANT_SWAROOP
                        Config::instance()->add_to_player_history (dir);
+#endif
                } catch (dcp::DCPReadError& e) {
                        error_dialog (this, wxString::Format(_("Could not load a DCP from %s"), std_to_wx(dir.string())), std_to_wx(e.what()));
                }
@@ -853,10 +827,10 @@ private:
                                );
                }
 
-               update_from_config ();
+               update_from_config (prop);
        }
 
-       void update_from_config ()
+       void update_from_config (Config::Property prop)
        {
                for (int i = 0; i < _history_items; ++i) {
                        delete _file_menu->Remove (ID_file_history + i);
@@ -887,6 +861,16 @@ private:
                }
 
                _history_items = history.size ();
+
+               if (prop == Config::PLAYER_DEBUG_LOG) {
+                       optional<boost::filesystem::path> p = Config::instance()->player_debug_log_file();
+                       if (p) {
+                               dcpomatic_log.reset (new FileLog(*p));
+                       } else {
+                               dcpomatic_log.reset (new NullLog());
+                       }
+                       dcpomatic_log->set_types (LogEntry::TYPE_GENERAL | LogEntry::TYPE_WARNING | LogEntry::TYPE_ERROR | LogEntry::TYPE_DEBUG_PLAYER);
+               }
        }
 
        void set_menu_sensitivity ()
@@ -987,85 +971,90 @@ public:
 private:
 
        bool OnInit ()
-       try
        {
-               wxInitAllImageHandlers ();
+               wxSplashScreen* splash = 0;
+               try {
+                       wxInitAllImageHandlers ();
 
-               Config::FailedToLoad.connect (boost::bind (&App::config_failed_to_load, this));
-               Config::Warning.connect (boost::bind (&App::config_warning, this, _1));
+                       Config::FailedToLoad.connect (boost::bind (&App::config_failed_to_load, this));
+                       Config::Warning.connect (boost::bind (&App::config_warning, this, _1));
 
-               wxSplashScreen* splash = maybe_show_splash ();
+                       splash = maybe_show_splash ();
 
-               SetAppName (_("DCP-o-matic Player"));
+                       SetAppName (_("DCP-o-matic Player"));
 
-               if (!wxApp::OnInit()) {
-                       return false;
-               }
+                       if (!wxApp::OnInit()) {
+                               return false;
+                       }
 
 #ifdef DCPOMATIC_LINUX
-               unsetenv ("UBUNTU_MENUPROXY");
+                       unsetenv ("UBUNTU_MENUPROXY");
 #endif
 
 #ifdef __WXOSX__
-               ProcessSerialNumber serial;
-               GetCurrentProcess (&serial);
-               TransformProcessType (&serial, kProcessTransformToForegroundApplication);
+                       ProcessSerialNumber serial;
+                       GetCurrentProcess (&serial);
+                       TransformProcessType (&serial, kProcessTransformToForegroundApplication);
 #endif
 
-               dcpomatic_setup_path_encoding ();
-
-               /* Enable i18n; this will create a Config object
-                  to look for a force-configured language.  This Config
-                  object will be wrong, however, because dcpomatic_setup
-                  hasn't yet been called and there aren't any filters etc.
-                  set up yet.
-               */
-               dcpomatic_setup_i18n ();
-
-               /* Set things up, including filters etc.
-                  which will now be internationalised correctly.
-               */
-               dcpomatic_setup ();
-
-               /* Force the configuration to be re-loaded correctly next
-                  time it is needed.
-               */
-               Config::drop ();
+                       dcpomatic_setup_path_encoding ();
+
+                       /* Enable i18n; this will create a Config object
+                          to look for a force-configured language.  This Config
+                          object will be wrong, however, because dcpomatic_setup
+                          hasn't yet been called and there aren't any filters etc.
+                          set up yet.
+                       */
+                       dcpomatic_setup_i18n ();
+
+                       /* Set things up, including filters etc.
+                          which will now be internationalised correctly.
+                       */
+                       dcpomatic_setup ();
+
+                       /* Force the configuration to be re-loaded correctly next
+                          time it is needed.
+                       */
+                       Config::drop ();
+
+                       signal_manager = new wxSignalManager (this);
+
+                       _frame = new DOMFrame ();
+                       SetTopWindow (_frame);
+                       _frame->Maximize ();
+                       if (splash) {
+                               splash->Destroy ();
+                               splash = 0;
+                       }
+                       _frame->Show ();
 
-               signal_manager = new wxSignalManager (this);
+                       PlayServer* server = new PlayServer (_frame);
+                       new thread (boost::bind (&PlayServer::run, server));
 
-               _frame = new DOMFrame ();
-               SetTopWindow (_frame);
-               _frame->Maximize ();
-               if (splash) {
-                       splash->Destroy ();
-               }
-               _frame->Show ();
+                       if (!_dcp_to_load.empty() && boost::filesystem::is_directory (_dcp_to_load)) {
+                               try {
+                                       _frame->load_dcp (_dcp_to_load);
+                               } catch (exception& e) {
+                                       error_dialog (0, std_to_wx (String::compose (wx_to_std (_("Could not load DCP %1.")), _dcp_to_load)), std_to_wx(e.what()));
+                               }
+                       }
 
-               PlayServer* server = new PlayServer (_frame);
-               new thread (boost::bind (&PlayServer::run, server));
+                       Bind (wxEVT_IDLE, boost::bind (&App::idle, this));
 
-               if (!_dcp_to_load.empty() && boost::filesystem::is_directory (_dcp_to_load)) {
-                       try {
-                               _frame->load_dcp (_dcp_to_load);
-                       } catch (exception& e) {
-                               error_dialog (0, std_to_wx (String::compose (wx_to_std (_("Could not load DCP %1.")), _dcp_to_load)), std_to_wx(e.what()));
+                       if (Config::instance()->check_for_updates ()) {
+                               UpdateChecker::instance()->run ();
                        }
                }
-
-               Bind (wxEVT_IDLE, boost::bind (&App::idle, this));
-
-               if (Config::instance()->check_for_updates ()) {
-                       UpdateChecker::instance()->run ();
+               catch (exception& e)
+               {
+                       if (splash) {
+                               splash->Destroy ();
+                       }
+                       error_dialog (0, _("DCP-o-matic Player could not start."), std_to_wx(e.what()));
                }
 
                return true;
        }
-       catch (exception& e)
-       {
-               error_dialog (0, _("DCP-o-matic Player could not start."), std_to_wx(e.what()));
-               return true;
-       }
 
        void OnInitCmdLine (wxCmdLineParser& parser)
        {