Remove unused LOG_DEBUG_DECODE and re-use it to add some 3D shuffler logging.

diff --git a/src/lib/dcpomatic_log.h b/src/lib/dcpomatic_log.h
index 2cec0c40558a23661c0c01215ad9b20c274a6de6..dbc850036681be89a101736366f03a7784276acd 100644 (file)
--- a/src/lib/dcpomatic_log.h
+++ b/src/lib/dcpomatic_log.h
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2018 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2018-2020 Carl Hetherington <cth@carlh.net>
 
     This file is part of DCP-o-matic.
 
@@ -34,3 +34,5 @@ extern boost::shared_ptr<Log> dcpomatic_log;
 #define LOG_TIMING(...)       dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_TIMING);
 #define LOG_DEBUG_ENCODE(...) dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_ENCODE);
 #define LOG_DEBUG_PLAYER(...) dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_PLAYER);
+#define LOG_DEBUG_THREED(...) dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_THREED);
+#define LOG_DEBUG_THREED_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DEBUG_THREED);

diff --git a/src/lib/log_entry.cc b/src/lib/log_entry.cc
index 6a36c3383aa5d575ef85ca7020dc0cc992deba7d..54f9bfc53db3bc7e4a428c72cbdf20786239dc93 100644 (file)
--- a/src/lib/log_entry.cc
+++ b/src/lib/log_entry.cc
@@ -27,7 +27,7 @@
 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_THREED = 0x8;
 int const LogEntry::TYPE_DEBUG_ENCODE = 0x10;
 int const LogEntry::TYPE_TIMING       = 0x20;
 int const LogEntry::TYPE_DEBUG_EMAIL  = 0x40;

diff --git a/src/lib/log_entry.h b/src/lib/log_entry.h
index 50bbf63a09d9516761c9e272d3ea958e4ddcd230..c15a006d13e1f9b66ce5bb4d66da6aad4648216f 100644 (file)
--- a/src/lib/log_entry.h
+++ b/src/lib/log_entry.h
@@ -31,7 +31,7 @@ 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_THREED;
        static const int TYPE_DEBUG_ENCODE;
        static const int TYPE_TIMING;
        static const int TYPE_DEBUG_EMAIL;

diff --git a/src/lib/shuffler.cc b/src/lib/shuffler.cc
index a46b26da0f85ee652fdd83f6e18fa1f1f7382e10..f6f05d41d466dbd8da1fa9efdd9f20ea9f568643 100644 (file)
--- a/src/lib/shuffler.cc
+++ b/src/lib/shuffler.cc
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2018-2019 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2018-2020 Carl Hetherington <cth@carlh.net>
 
     This file is part of DCP-o-matic.
 
@@ -23,9 +23,11 @@
 #include "dcpomatic_assert.h"
 #include "dcpomatic_log.h"
 #include <boost/foreach.hpp>
+#include <string>
 #include <iostream>
 
 using std::make_pair;
+using std::string;
 using boost::weak_ptr;
 using boost::shared_ptr;
 using boost::optional;
@@ -45,6 +47,8 @@ struct Comparator
 void
 Shuffler::video (weak_ptr<Piece> weak_piece, ContentVideo video)
 {
+       LOG_DEBUG_THREED ("Shuffler::video frame=%1 eyes=%2 part=%3", video.frame, static_cast<int>(video.eyes), static_cast<int>(video.part));
+
        if (video.eyes != EYES_LEFT && video.eyes != EYES_RIGHT) {
                /* Pass through anything that we don't care about */
                Video (weak_piece, video);
@@ -55,6 +59,7 @@ Shuffler::video (weak_ptr<Piece> weak_piece, ContentVideo video)
        DCPOMATIC_ASSERT (piece);
 
        if (!_last && video.eyes == EYES_LEFT) {
+               LOG_DEBUG_THREED_NC ("Shuffler first after clear");
                /* We haven't seen anything since the last clear() and we have some eyes-left so assume everything is OK */
                Video (weak_piece, video);
                _last = video;
@@ -74,6 +79,12 @@ Shuffler::video (weak_ptr<Piece> weak_piece, ContentVideo video)
                                (_store.front().second.frame >= (_last->frame + 1) && _store.front().second.eyes == EYES_LEFT  && _last->eyes == EYES_RIGHT)
                                );
 
+               if (!store_front_in_sequence) {
+                       string const store = _store.empty() ? "store empty" : String::compose("store front frame=%1 eyes=%2", _store.front().second.frame, static_cast<int>(_store.front().second.eyes));
+                       string const last = _last ? String::compose("last frame=%1 eyes=%2", _last->frame, static_cast<int>(_last->eyes)) : "no last";
+                       LOG_DEBUG_THREED("Shuffler not in sequence: %1 %2", store, last);
+               }
+
                if (!store_front_in_sequence && _store.size() <= _max_size) {
                        /* store_front_in_sequence means everything is ok; otherwise if the store is getting too big just
                           start emitting things as best we can.  This can easily happen if, for example, there is only content
@@ -86,6 +97,7 @@ Shuffler::video (weak_ptr<Piece> weak_piece, ContentVideo video)
                        LOG_WARNING ("Shuffler is full after receiving frame %1; 3D sync may be incorrect.", video.frame);
                }
 
+               LOG_DEBUG_THREED("Shuffler emits frame=%1 eyes=%2 store=%3", _store.front().second.frame, static_cast<int>(_store.front().second.eyes, _store.size()));
                Video (_store.front().first, _store.front().second);
                _last = _store.front().second;
                _store.pop_front ();
@@ -95,6 +107,7 @@ Shuffler::video (weak_ptr<Piece> weak_piece, ContentVideo video)
 void
 Shuffler::clear ()
 {
+       LOG_DEBUG_THREED_NC ("Shuffler::clear");
        _store.clear ();
        _last = optional<ContentVideo>();
 }

diff --git a/src/wx/full_config_dialog.cc b/src/wx/full_config_dialog.cc
index ce199e58aae87b3975e3210c65caba1d66cc097a..370ec35a1a90ea0b13cfd5ceb1780595658fe814 100644 (file)
--- a/src/wx/full_config_dialog.cc
+++ b/src/wx/full_config_dialog.cc
@@ -1233,7 +1233,7 @@ public:
                , _log_warning (0)
                , _log_error (0)
                , _log_timing (0)
-               , _log_debug_decode (0)
+               , _log_debug_threed (0)
                , _log_debug_encode (0)
                , _log_debug_email (0)
        {}
@@ -1346,8 +1346,8 @@ private:
                        /// TRANSLATORS: translate the word "Timing" here; do not include the "Config|" prefix
                        _log_timing = new CheckBox (_panel, S_("Config|Timing"));
                        t->Add (_log_timing, 1, wxEXPAND | wxALL);
-                       _log_debug_decode = new CheckBox (_panel, _("Debug: decode"));
-                       t->Add (_log_debug_decode, 1, wxEXPAND | wxALL);
+                       _log_debug_threed = new CheckBox (_panel, _("Debug: 3D"));
+                       t->Add (_log_debug_threed, 1, wxEXPAND | wxALL);
                        _log_debug_encode = new CheckBox (_panel, _("Debug: encode"));
                        t->Add (_log_debug_encode, 1, wxEXPAND | wxALL);
                        _log_debug_email = new CheckBox (_panel, _("Debug: email sending"));
@@ -1377,7 +1377,7 @@ private:
                _log_warning->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
                _log_error->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
                _log_timing->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
-               _log_debug_decode->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
+               _log_debug_threed->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
                _log_debug_encode->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
                _log_debug_email->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
 #ifdef DCPOMATIC_WINDOWS
@@ -1406,7 +1406,7 @@ private:
                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_threed, config->log_types() & LogEntry::TYPE_DEBUG_THREED);
                checked_set (_log_debug_encode, config->log_types() & LogEntry::TYPE_DEBUG_ENCODE);
                checked_set (_log_debug_email, config->log_types() & LogEntry::TYPE_DEBUG_EMAIL);
                checked_set (_frames_in_memory_multiplier, config->frames_in_memory_multiplier());
@@ -1479,8 +1479,8 @@ private:
                if (_log_timing->GetValue ()) {
                        types |= LogEntry::TYPE_TIMING;
                }
-               if (_log_debug_decode->GetValue ()) {
-                       types |= LogEntry::TYPE_DEBUG_DECODE;
+               if (_log_debug_threed->GetValue ()) {
+                       types |= LogEntry::TYPE_DEBUG_THREED;
                }
                if (_log_debug_encode->GetValue ()) {
                        types |= LogEntry::TYPE_DEBUG_ENCODE;
@@ -1511,7 +1511,7 @@ private:
        wxCheckBox* _log_warning;
        wxCheckBox* _log_error;
        wxCheckBox* _log_timing;
-       wxCheckBox* _log_debug_decode;
+       wxCheckBox* _log_debug_threed;
        wxCheckBox* _log_debug_encode;
        wxCheckBox* _log_debug_email;
 #ifdef DCPOMATIC_WINDOWS

diff --git a/src/wx/player_config_dialog.cc b/src/wx/player_config_dialog.cc
index 5a21d231bd840eb6b33a8c6a6d490d3ecc1178ec..c270abd856c8962bf75f717e4f9e06df119b57dc 100644 (file)
--- a/src/wx/player_config_dialog.cc
+++ b/src/wx/player_config_dialog.cc
@@ -279,7 +279,6 @@ public:
                , _log_warning (0)
                , _log_error (0)
                , _log_timing (0)
-               , _log_debug_decode (0)
        {}
 
 private:
@@ -312,8 +311,6 @@ private:
                        /// TRANSLATORS: translate the word "Timing" here; do not include the "Config|" prefix
                        _log_timing = new CheckBox (_panel, S_("Config|Timing"));
                        t->Add (_log_timing, 1, wxEXPAND | wxALL);
-                       _log_debug_decode = new CheckBox (_panel, _("Debug"));
-                       t->Add (_log_debug_decode, 1, wxEXPAND | wxALL);
                        table->Add (t, 0, wxALL, 6);
                }
 
@@ -327,7 +324,6 @@ private:
                _log_warning->Bind (wxEVT_CHECKBOX, boost::bind (&PlayerAdvancedPage::log_changed, this));
                _log_error->Bind (wxEVT_CHECKBOX, boost::bind (&PlayerAdvancedPage::log_changed, this));
                _log_timing->Bind (wxEVT_CHECKBOX, boost::bind (&PlayerAdvancedPage::log_changed, this));
-               _log_debug_decode->Bind (wxEVT_CHECKBOX, boost::bind (&PlayerAdvancedPage::log_changed, this));
 #ifdef DCPOMATIC_WINDOWS
                _win32_console->Bind (wxEVT_CHECKBOX, boost::bind (&PlayerAdvancedPage::win32_console_changed, this));
 #endif
@@ -341,7 +337,6 @@ private:
                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);
 #ifdef DCPOMATIC_WINDOWS
                checked_set (_win32_console, config->win32_console());
 #endif
@@ -362,9 +357,6 @@ private:
                if (_log_timing->GetValue ()) {
                        types |= LogEntry::TYPE_TIMING;
                }
-               if (_log_debug_decode->GetValue ()) {
-                       types |= LogEntry::TYPE_DEBUG_DECODE;
-               }
                Config::instance()->set_log_types (types);
        }
 
@@ -379,7 +371,6 @@ private:
        wxCheckBox* _log_warning;
        wxCheckBox* _log_error;
        wxCheckBox* _log_timing;
-       wxCheckBox* _log_debug_decode;
 #ifdef DCPOMATIC_WINDOWS
        wxCheckBox* _win32_console;
 #endif