From ecb4e9189dec6c1df4fadcae8644bb982cfec4e1 Mon Sep 17 00:00:00 2001
From: Carl Hetherington <cth@carlh.net>
Date: Wed, 26 May 2021 15:35:43 +0200
Subject: [PATCH] Add some logging to the KDM part of DCP examination.

---
 src/lib/dcp_examiner.cc | 14 ++++++++++++++
 1 file changed, 14 insertions(+)

diff --git a/src/lib/dcp_examiner.cc b/src/lib/dcp_examiner.cc
index b431cec26..2d7e514e1 100644
--- a/src/lib/dcp_examiner.cc
+++ b/src/lib/dcp_examiner.cc
@@ -20,6 +20,7 @@
 
 #include "dcp_examiner.h"
 #include "dcp_content.h"
+#include "dcpomatic_log.h"
 #include "exceptions.h"
 #include "image.h"
 #include "config.h"
@@ -120,6 +121,8 @@ DCPExaminer::DCPExaminer (shared_ptr<const DCPContent> content, bool tolerant)
 		return boost::none;
 	};
 
+	LOG_GENERAL("Examining DCP with CPL %1", _cpl);
+
 	for (auto i: cpl->reels()) {
 
 		if (i->main_picture ()) {
@@ -232,9 +235,11 @@ DCPExaminer::DCPExaminer (shared_ptr<const DCPContent> content, bool tolerant)
 	 * asset in each reel.  This checks that when we do have a key it's the right one.
 	 */
 	try {
+		LOG_GENERAL("Checking that everything in %1 reels has keys", cpl->reels().size());
 		for (auto i: cpl->reels()) {
 			auto pic = i->main_picture()->asset();
 			if (pic->encrypted() && !pic->key()) {
+				LOG_WARNING("KDM is invalid because picture asset %1 is encrypted and there is no key", pic->id());
 				_kdm_valid = false;
 			}
 			auto mono = dynamic_pointer_cast<dcp::MonoPictureAsset>(pic);
@@ -249,6 +254,7 @@ DCPExaminer::DCPExaminer (shared_ptr<const DCPContent> content, bool tolerant)
 			if (i->main_sound()) {
 				auto sound = i->main_sound()->asset ();
 				if (sound->encrypted() && !sound->key()) {
+					LOG_WARNING("KDM is invalid because sound asset %1 is encrypted and there is no key", sound->id());
 					_kdm_valid = false;
 				}
 				i->main_sound()->asset()->start_read()->get_frame(0);
@@ -258,6 +264,7 @@ DCPExaminer::DCPExaminer (shared_ptr<const DCPContent> content, bool tolerant)
 				auto sub = i->main_subtitle()->asset();
 				auto mxf_sub = dynamic_pointer_cast<dcp::MXF>(sub);
 				if (mxf_sub && mxf_sub->encrypted() && !mxf_sub->key()) {
+					LOG_WARNING("KDM is invalid because subtitle asset %1 is encrypted and there is no key", sub->id());
 					_kdm_valid = false;
 				}
 				sub->subtitles ();
@@ -266,17 +273,24 @@ DCPExaminer::DCPExaminer (shared_ptr<const DCPContent> content, bool tolerant)
 			if (i->atmos()) {
 				auto atmos = i->atmos()->asset();
 				if (atmos->encrypted() && !atmos->key()) {
+					LOG_WARNING("KDM is invalid because ATMOS asset %1 is encrypted and there is no key", atmos->id());
 					_kdm_valid = false;
 				}
 				atmos->start_read()->get_frame(0);
 			}
 		}
 	} catch (dcp::ReadError& e) {
+		LOG_WARNING("KDM is invalid because ReadError %1 occurred.", e.what());
 		_kdm_valid = false;
 	} catch (dcp::MiscError& e) {
+		LOG_WARNING("KDM is invalid because MiscError %1 occurred.", e.what());
 		_kdm_valid = false;
 	}
 
+	if (_kdm_valid) {
+		LOG_GENERAL_NC("KDM seems OK!");
+	}
+
 	_standard = cpl->standard();
 	_three_d = !cpl->reels().empty() && cpl->reels().front()->main_picture() &&
 		dynamic_pointer_cast<dcp::StereoPictureAsset> (cpl->reels().front()->main_picture()->asset());
-- 
2.30.2