Some more detailed logging.
authorCarl Hetherington <cth@carlh.net>
Mon, 16 May 2022 19:35:03 +0000 (21:35 +0200)
committerCarl Hetherington <cth@carlh.net>
Mon, 16 May 2022 19:39:18 +0000 (21:39 +0200)
src/lib/dcpomatic_log.h
src/lib/j2k_encoder.cc
src/lib/log_entry.cc
src/lib/log_entry.h
src/lib/player.cc
src/lib/reel_writer.cc
src/lib/writer.cc

index 6a1c3a6ec54ccf170d24a56ebf2e7a0d7cca33d3..ff1346958a2f501114a9811a41e8041190d5dc06 100644 (file)
@@ -42,6 +42,8 @@ extern std::shared_ptr<Log> dcpomatic_log;
 #define LOG_DISK_NC(...)      dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DISK);
 #define LOG_DEBUG_PLAYER(...)    dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_PLAYER);
 #define LOG_DEBUG_PLAYER_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DEBUG_PLAYER);
+#define LOG_DEBUG_WRITER(...)    dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_WRITER);
+#define LOG_DEBUG_WRITER_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DEBUG_WRITER);
 #define LOG_DEBUG_AUDIO_ANALYSIS(...)    dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS);
 #define LOG_DEBUG_AUDIO_ANALYSIS_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS);
 
index 985708f054a762e4ab6bc468efdf7fd5b2d41bca..160bfd50a61c2f2db3eed392c8c202819db036be 100644 (file)
@@ -222,19 +222,19 @@ J2KEncoder::encode (shared_ptr<PlayerVideo> pv, DCPTime time)
 
        if (_writer->can_fake_write (position)) {
                /* We can fake-write this frame */
-               LOG_DEBUG_ENCODE("Frame @ %1 FAKE", to_string(time));
+               LOG_DEBUG_ENCODE("Frame @ %1 %2 FAKE", to_string(time), static_cast<int>(pv->eyes()));
                _writer->fake_write (position, pv->eyes ());
                frame_done ();
        } else if (pv->has_j2k() && !_film->reencode_j2k()) {
-               LOG_DEBUG_ENCODE("Frame @ %1 J2K", to_string(time));
+               LOG_DEBUG_ENCODE("Frame @ %1 %2 J2K", to_string(time), static_cast<int>(pv->eyes()));
                /* This frame already has J2K data, so just write it */
                _writer->write (pv->j2k(), position, pv->eyes ());
                frame_done ();
        } else if (_last_player_video[static_cast<int>(pv->eyes())] && _writer->can_repeat(position) && pv->same (_last_player_video[static_cast<int>(pv->eyes())])) {
-               LOG_DEBUG_ENCODE("Frame @ %1 REPEAT", to_string(time));
+               LOG_DEBUG_ENCODE("Frame @ %1 %2 REPEAT", to_string(time), static_cast<int>(pv->eyes()));
                _writer->repeat (position, pv->eyes ());
        } else {
-               LOG_DEBUG_ENCODE("Frame @ %1 ENCODE", to_string(time));
+               LOG_DEBUG_ENCODE("Frame @ %1 %2 ENCODE", to_string(time), static_cast<int>(pv->eyes()));
                /* Queue this new frame for encoding */
                LOG_TIMING ("add-frame-to-queue queue=%1", _queue.size ());
                _queue.push_back (DCPVideo(
index 2980e438b084555d5718ddb52900355fc3e79280..b22eaf2b87fe459092ce20fdb36a31ba96b8e0f0 100644 (file)
@@ -37,6 +37,7 @@ int const LogEntry::TYPE_DEBUG_VIDEO_VIEW = 0x080;
 int const LogEntry::TYPE_DISK         = 0x100;
 int const LogEntry::TYPE_DEBUG_PLAYER = 0x200;
 int const LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS = 0x400;
+int const LogEntry::TYPE_DEBUG_WRITER         = 0x800;
 
 
 using std::string;
index 95c4e4f1f851e31a57230722a1239ce62b1838a8..36e9477a9e7d0639177d3a0d2664abd177fc7bf7 100644 (file)
@@ -42,6 +42,7 @@ public:
        static const int TYPE_DISK;
        static const int TYPE_DEBUG_PLAYER;     ///< the Player class
        static const int TYPE_DEBUG_AUDIO_ANALYSIS; ///< audio analysis job
+       static const int TYPE_DEBUG_WRITER;         ///< Writer and ReelWriter classes
 
        explicit LogEntry (int type);
        virtual ~LogEntry () {}
index cf286f4a582fb0a4de592a6511ef347b8c0ae38f..66b731645a1d4ef74521d2e4f116ed2aea57b90f 100644 (file)
@@ -1334,6 +1334,7 @@ Player::do_emit_video (shared_ptr<PlayerVideo> pv, DCPTime time)
                pv->set_text (subtitles.get ());
        }
 
+       LOG_DEBUG_PLAYER("Player --> Video %1 %2", to_string(time), static_cast<int>(pv->eyes()));
        Video (pv, time);
 }
 
index 94920b95bce0cd82232e94c9aca0e9275ccf70c1..cad9bcf64a824628d75af2d77521aff77856c33d 100644 (file)
@@ -309,6 +309,8 @@ ReelWriter::check_existing_picture_asset (boost::filesystem::path asset)
 void
 ReelWriter::write (shared_ptr<const Data> encoded, Frame frame, Eyes eyes)
 {
+       LOG_DEBUG_WRITER("ReelWriter::write frame=%1 eyes=%2", frame, static_cast<int>(eyes));
+
        if (!_picture_asset_writer) {
                /* We're not writing any data */
                return;
@@ -351,6 +353,8 @@ ReelWriter::fake_write (int size)
 void
 ReelWriter::repeat_write (Frame frame, Eyes eyes)
 {
+       LOG_DEBUG_WRITER("ReelWriter::repeat_write frame=%1 eyes=%2", frame, static_cast<int>(eyes));
+
        if (!_picture_asset_writer) {
                /* We're not writing any data */
                return;
index 3aca2ab89c96328445907dbbd88ae64156b722ac..b14dabc805de6a8403ff37ab003a5dc3e629c419 100644 (file)
@@ -448,7 +448,7 @@ try
                                ++_fake_written;
                                break;
                        case QueueItem::Type::REPEAT:
-                               LOG_DEBUG_ENCODE (N_("Writer REPEAT-writes %1"), qi.frame);
+                               LOG_DEBUG_ENCODE (N_("Writer REPEAT-writes %1 %2"), qi.frame, static_cast<int>(qi.eyes));
                                reel.repeat_write (qi.frame, qi.eyes);
                                ++_repeat_written;
                                break;