Title: [271270] trunk/Source
Revision
271270
Author
[email protected]
Date
2021-01-07 16:18:32 -0800 (Thu, 07 Jan 2021)

Log Message

[Mac] Add runtime logging to format reader and WebM parser
https://bugs.webkit.org/show_bug.cgi?id=220423
<rdar://problem/72896655>

Reviewed by Andy Estes.

Source/WebCore:

Add a shared Logger to Document that can be used by singletons or objects that don't
have access to a Document. To ensure that the shared logger doesn't log activity
from a private session, it is disabled if *any* Document in the process doesn't
allow logging.

* WebCore.xcodeproj/project.pbxproj:
* dom/Document.cpp:
(WebCore::sharedLoggerOwner):
(WebCore::staticSharedLogger):
(WebCore::Document::sharedLogger):
(WebCore::Document::configureSharedLogger):
(WebCore::Document::addToDocumentsMap):
(WebCore::Document::removeFromDocumentsMap):
(WebCore::m_selection):
(WebCore::Document::~Document):
* dom/Document.h:
* platform/graphics/cocoa/SourceBufferParserWebM.cpp:
(WTF::LogArgument<webm::TrackType>::toString):
(WebCore::logChannel):
(WebCore::logClassName):
(WebCore::SourceBufferParserWebM::appendData):
(WebCore::SourceBufferParserWebM::setLogger):
(WebCore::SourceBufferParserWebM::OnElementBegin):
(WebCore::SourceBufferParserWebM::OnElementEnd):
(WebCore::SourceBufferParserWebM::OnEbml):
(WebCore::SourceBufferParserWebM::OnSegmentBegin):
(WebCore::SourceBufferParserWebM::OnInfo):
(WebCore::SourceBufferParserWebM::OnClusterBegin):
(WebCore::SourceBufferParserWebM::OnTrackEntry):
(WebCore::SourceBufferParserWebM::OnBlockBegin):
(WebCore::SourceBufferParserWebM::OnBlockEnd):
(WebCore::SourceBufferParserWebM::OnSimpleBlockBegin):
(WebCore::SourceBufferParserWebM::OnSimpleBlockEnd):
(WebCore::SourceBufferParserWebM::OnBlockGroupBegin):
(WebCore::SourceBufferParserWebM::OnBlockGroupEnd):
(WebCore::SourceBufferParserWebM::OnFrame):
* platform/graphics/cocoa/SourceBufferParserWebM.h:

Source/WebKit:

Use the Document::sharedLogger to log format and track reader state changes
and errors.

* Shared/mac/MediaFormatReader/MediaFormatReader.cpp:
(WebKit::nextLogIdentifier):
(WebKit::logChannel):
(WebKit::logClassName):
(WebKit::MediaFormatReader::parseByteSource):
(WebKit::MediaFormatReader::didParseTracks):
(WebKit::MediaFormatReader::copyProperty):
(WebKit::MediaFormatReader::nextTrackReaderLogIdentifier const):
* Shared/mac/MediaFormatReader/MediaFormatReader.h:
* Shared/mac/MediaFormatReader/WebKit::MediaTrackReader.cpp:
(WebKit::MediaTrackReader::MediaTrackReader):
(WebKit::MediaTrackReader::finishParsing):
(WebKit::MediaTrackReader::mediaTypeString const):
(WebKit::MediaTrackReader::copyProperty):
(WebKit::MediaTrackReader::finalize):
(WebKit::MediaTrackReader::logChannel const):
* Shared/mac/MediaFormatReader/WebKit::MediaTrackReader.h:

Modified Paths

Diff

Modified: trunk/Source/WebCore/ChangeLog (271269 => 271270)


--- trunk/Source/WebCore/ChangeLog	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebCore/ChangeLog	2021-01-08 00:18:32 UTC (rev 271270)
@@ -1,3 +1,49 @@
+2021-01-07  Eric Carlson  <[email protected]>
+
+        [Mac] Add runtime logging to format reader and WebM parser
+        https://bugs.webkit.org/show_bug.cgi?id=220423
+        <rdar://problem/72896655>
+
+        Reviewed by Andy Estes.
+
+        Add a shared Logger to Document that can be used by singletons or objects that don't
+        have access to a Document. To ensure that the shared logger doesn't log activity
+        from a private session, it is disabled if *any* Document in the process doesn't
+        allow logging.
+
+        * WebCore.xcodeproj/project.pbxproj:
+        * dom/Document.cpp:
+        (WebCore::sharedLoggerOwner):
+        (WebCore::staticSharedLogger):
+        (WebCore::Document::sharedLogger):
+        (WebCore::Document::configureSharedLogger):
+        (WebCore::Document::addToDocumentsMap):
+        (WebCore::Document::removeFromDocumentsMap):
+        (WebCore::m_selection):
+        (WebCore::Document::~Document):
+        * dom/Document.h:
+        * platform/graphics/cocoa/SourceBufferParserWebM.cpp:
+        (WTF::LogArgument<webm::TrackType>::toString):
+        (WebCore::logChannel):
+        (WebCore::logClassName):
+        (WebCore::SourceBufferParserWebM::appendData):
+        (WebCore::SourceBufferParserWebM::setLogger):
+        (WebCore::SourceBufferParserWebM::OnElementBegin):
+        (WebCore::SourceBufferParserWebM::OnElementEnd):
+        (WebCore::SourceBufferParserWebM::OnEbml):
+        (WebCore::SourceBufferParserWebM::OnSegmentBegin):
+        (WebCore::SourceBufferParserWebM::OnInfo):
+        (WebCore::SourceBufferParserWebM::OnClusterBegin):
+        (WebCore::SourceBufferParserWebM::OnTrackEntry):
+        (WebCore::SourceBufferParserWebM::OnBlockBegin):
+        (WebCore::SourceBufferParserWebM::OnBlockEnd):
+        (WebCore::SourceBufferParserWebM::OnSimpleBlockBegin):
+        (WebCore::SourceBufferParserWebM::OnSimpleBlockEnd):
+        (WebCore::SourceBufferParserWebM::OnBlockGroupBegin):
+        (WebCore::SourceBufferParserWebM::OnBlockGroupEnd):
+        (WebCore::SourceBufferParserWebM::OnFrame):
+        * platform/graphics/cocoa/SourceBufferParserWebM.h:
+
 2021-01-07  Alexey Shvayka  <[email protected]>
 
         [JSC] Simplify get*PropertyNames() methods and EnumerationMode

Modified: trunk/Source/WebCore/WebCore.xcodeproj/project.pbxproj (271269 => 271270)


--- trunk/Source/WebCore/WebCore.xcodeproj/project.pbxproj	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebCore/WebCore.xcodeproj/project.pbxproj	2021-01-08 00:18:32 UTC (rev 271270)
@@ -3427,7 +3427,7 @@
 		A818721E0977D3C0005826D9 /* NameNodeList.h in Headers */ = {isa = PBXBuildFile; fileRef = A81872130977D3C0005826D9 /* NameNodeList.h */; settings = {ATTRIBUTES = (Private, ); }; };
 		A81872200977D3C0005826D9 /* ChildNodeList.h in Headers */ = {isa = PBXBuildFile; fileRef = A81872150977D3C0005826D9 /* ChildNodeList.h */; };
 		A81872230977D3C0005826D9 /* NamedNodeMap.h in Headers */ = {isa = PBXBuildFile; fileRef = A81872180977D3C0005826D9 /* NamedNodeMap.h */; settings = {ATTRIBUTES = (Private, ); }; };
-		A8239E0109B3CF8A00B60641 /* Logging.h in Headers */ = {isa = PBXBuildFile; fileRef = A8239DFF09B3CF8A00B60641 /* Logging.h */; };
+		A8239E0109B3CF8A00B60641 /* Logging.h in Headers */ = {isa = PBXBuildFile; fileRef = A8239DFF09B3CF8A00B60641 /* Logging.h */; settings = {ATTRIBUTES = (Private, ); }; };
 		A824B4650E2EF2EA0081A7B7 /* TextRun.h in Headers */ = {isa = PBXBuildFile; fileRef = A824B4640E2EF2EA0081A7B7 /* TextRun.h */; settings = {ATTRIBUTES = (Private, ); }; };
 		A833C7CA0A2CF06B00D57664 /* SVGNames.cpp in Sources */ = {isa = PBXBuildFile; fileRef = 656581E809D1508D000E61D7 /* SVGNames.cpp */; };
 		A833C7CC0A2CF07400D57664 /* XLinkNames.cpp in Sources */ = {isa = PBXBuildFile; fileRef = 656581EA09D1508D000E61D7 /* XLinkNames.cpp */; };

Modified: trunk/Source/WebCore/dom/Document.cpp (271269 => 271270)


--- trunk/Source/WebCore/dom/Document.cpp	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebCore/dom/Document.cpp	2021-01-08 00:18:32 UTC (rev 271270)
@@ -515,6 +515,56 @@
 
 uint64_t Document::s_globalTreeVersion = 0;
 
+static const void* sharedLoggerOwner()
+{
+    static uint64_t owner = cryptographicallyRandomNumber();
+    return reinterpret_cast<const void*>(owner);
+}
+
+static Logger*& staticSharedLogger()
+{
+    static Logger* logger;
+    return logger;
+}
+
+const Logger& Document::sharedLogger()
+{
+    if (!staticSharedLogger()) {
+        staticSharedLogger() = &Logger::create(sharedLoggerOwner()).leakRef();
+        configureSharedLogger();
+    }
+    
+    return *staticSharedLogger();
+}
+
+void Document::configureSharedLogger()
+{
+    auto logger = staticSharedLogger();
+    if (!logger)
+        return;
+
+    bool alwaysOnLoggingAllowed = !allDocumentsMap().isEmpty() && WTF::allOf(allDocumentsMap().values(), [](auto* document) {
+        auto* page = document->page();
+        return !page || page->sessionID().isAlwaysOnLoggingAllowed();
+    });
+    logger->setEnabled(sharedLoggerOwner(), alwaysOnLoggingAllowed);
+}
+
+auto Document::addToDocumentsMap() -> DocumentsMap::AddResult
+{
+    auto addResult = allDocumentsMap().add(m_identifier, this);
+    configureSharedLogger();
+    
+    return addResult;
+}
+
+void Document::removeFromDocumentsMap()
+{
+    ASSERT(allDocumentsMap().contains(m_identifier));
+    allDocumentsMap().remove(m_identifier);
+    configureSharedLogger();
+}
+
 auto Document::allDocumentsMap() -> DocumentsMap&
 {
     static NeverDestroyed<DocumentsMap> documents;
@@ -589,7 +639,7 @@
     , m_editor(makeUniqueRef<Editor>(*this))
     , m_selection(makeUniqueRef<FrameSelection>(this))
 {
-    auto addResult = allDocumentsMap().add(m_identifier, this);
+    auto addResult = addToDocumentsMap();
     ASSERT_UNUSED(addResult, addResult.isNewEntry);
 
     // We depend on the url getting immediately set in subframes, but we
@@ -649,8 +699,8 @@
     }
 #endif
 
-    ASSERT(allDocumentsMap().contains(m_identifier));
-    allDocumentsMap().remove(m_identifier);
+    removeFromDocumentsMap();
+
     // We need to remove from the contexts map very early in the destructor so that calling postTask() on this Document from another thread is safe.
     removeFromContextsMap();
 

Modified: trunk/Source/WebCore/dom/Document.h (271269 => 271270)


--- trunk/Source/WebCore/dom/Document.h	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebCore/dom/Document.h	2021-01-08 00:18:32 UTC (rev 271270)
@@ -1492,6 +1492,7 @@
     void setMayBeDetachedFromFrame(bool mayBeDetachedFromFrame) { m_mayBeDetachedFromFrame = mayBeDetachedFromFrame; }
 
     Logger& logger();
+    WEBCORE_EXPORT static const Logger& sharedLogger();
 
     WEBCORE_EXPORT void setConsoleMessageListener(RefPtr<StringCallback>&&); // For testing.
 
@@ -1718,7 +1719,11 @@
     bool isBodyPotentiallyScrollable(HTMLBodyElement&);
 
     void didLogMessage(const WTFLogChannel&, WTFLogLevel, Vector<JSONLogValue>&&) final;
+    static void configureSharedLogger();
 
+    DocumentsMap::AddResult addToDocumentsMap();
+    void removeFromDocumentsMap();
+
     const Ref<const Settings> m_settings;
 
     UniqueRef<Quirks> m_quirks;

Modified: trunk/Source/WebCore/platform/graphics/cocoa/SourceBufferParserWebM.cpp (271269 => 271270)


--- trunk/Source/WebCore/platform/graphics/cocoa/SourceBufferParserWebM.cpp	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebCore/platform/graphics/cocoa/SourceBufferParserWebM.cpp	2021-01-08 00:18:32 UTC (rev 271270)
@@ -61,6 +61,22 @@
 
 template<typename> struct LogArgument;
 
+template<> struct LogArgument<webm::TrackType> {
+    static String toString(webm::TrackType type)
+    {
+        switch (type) {
+        case webm::TrackType::kVideo: return "Video"_s;
+        case webm::TrackType::kAudio: return "Audio"_s;
+        case webm::TrackType::kComplex: return "Complex"_s;
+        case webm::TrackType::kLogo: return "Logo"_s;
+        case webm::TrackType::kSubtitle: return "Subtitle"_s;
+        case webm::TrackType::kButtons: return "Buttons"_s;
+        case webm::TrackType::kControl: return "Control"_s;
+        }
+        return "Unknown"_s;
+    }
+};
+
 template<> struct LogArgument<webm::Id> {
     static String toString(webm::Id id)
     {
@@ -243,10 +259,8 @@
 
 using namespace PAL;
 
-#if !RELEASE_LOG_DISABLED
-static WTFLogChannel& logChannel() { return LogMediaSource; }
+static WTFLogChannel& logChannel() { return LogMedia; }
 static const char* logClassName() { return "SourceBufferParserWebM"; }
-#endif
 
 // FIXME: Remove this once kCMVideoCodecType_VP9 is added to CMFormatDescription.h
 constexpr CMVideoCodecType kCMVideoCodecType_VP9 { 'vp09' };
@@ -627,7 +641,7 @@
         // position of the incoming Ebml Element, and reset the parser, which will cause the Ebml element to be
         // parsed as a top-level element, rather than as a child of the Segment.
         if (!m_reader->rewindTo(*m_rewindToPosition)) {
-            ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "failed to rewind reader, bailing");
+            ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "failed to rewind reader");
             break;
         }
 
@@ -688,13 +702,11 @@
     m_currentBlock.reset();
 }
 
-#if !RELEASE_LOG_DISABLED
 void SourceBufferParserWebM::setLogger(const Logger& logger, const void* logIdentifier)
 {
     m_logger = makeRefPtr(logger);
     m_logIdentifier = logIdentifier;
 }
-#endif
 
 auto SourceBufferParserWebM::trackDataForTrackNumber(uint64_t trackNumber) -> TrackData*
 {
@@ -720,15 +732,13 @@
 
     if ((m_state == State::None && metadata.id != Id::kEbml && metadata.id != Id::kSegment)
         || (m_state == State::ReadingSegment && metadata.id != Id::kInfo && metadata.id != Id::kTracks && metadata.id != Id::kCluster)) {
-        DEBUG_LOG_IF_POSSIBLE(LOGIDENTIFIER, "state(", m_state, "), id(", metadata.id, "), position(", metadata.position, "), headerSize(", metadata.header_size, "), size(", metadata.size, "), skipping");
+        INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER, "state(", m_state, "), id(", metadata.id, "), position(", metadata.position, "), headerSize(", metadata.header_size, "), size(", metadata.size, "), skipping");
 
         *action = ""
         return Status(Status::kOkCompleted);
     }
 
-#if !RELEASE_LOG_DISABLED
     auto oldState = m_state;
-#endif
 
     if (metadata.id == Id::kEbml)
         m_state = State::ReadingEbml;
@@ -743,7 +753,7 @@
     else if (metadata.id == Id::kCluster)
         m_state = State::ReadingCluster;
 
-    DEBUG_LOG_IF_POSSIBLE(LOGIDENTIFIER, "state(", oldState, "->", m_state, "), id(", metadata.id, "), position(", metadata.position, "), headerSize(", metadata.header_size, "), size(", metadata.size, ")");
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER, "state(", oldState, "->", m_state, "), id(", metadata.id, "), position(", metadata.position, "), headerSize(", metadata.header_size, "), size(", metadata.size, ")");
 
     return Status(Status::kOkCompleted);
 }
@@ -751,10 +761,9 @@
 Status SourceBufferParserWebM::OnElementEnd(const ElementMetadata& metadata)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
 
-#if !RELEASE_LOG_DISABLED
     auto oldState = m_state;
-#endif
 
     if (metadata.id == Id::kEbml || metadata.id == Id::kSegment)
         m_state = State::None;
@@ -763,7 +772,7 @@
     else if (metadata.id == Id::kTrackEntry)
         m_state = State::ReadingTracks;
 
-    DEBUG_LOG_IF_POSSIBLE(LOGIDENTIFIER, "state(", oldState, "->", m_state, "), id(", metadata.id, "), size(", metadata.size, ")");
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER, "state(", oldState, "->", m_state, "), id(", metadata.id, "), size(", metadata.size, ")");
 
     return Status(Status::kOkCompleted);
 }
@@ -771,6 +780,8 @@
 Status SourceBufferParserWebM::OnEbml(const ElementMetadata& metadata, const Ebml& ebml)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     if (ebml.doc_type.is_present() && ebml.doc_type.value().compare("webm"))
         return Status(Status::Code(ErrorCode::InvalidDocType));
 
@@ -783,8 +794,10 @@
 Status SourceBufferParserWebM::OnSegmentBegin(const ElementMetadata& metadata, Action* action)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     if (!m_initializationSegmentEncountered) {
-        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered Segment before Embl, bailing");
+        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered Segment before Embl");
         return Status(Status::Code(ErrorCode::InvalidInitSegment));
     }
 
@@ -799,8 +812,10 @@
 Status SourceBufferParserWebM::OnInfo(const ElementMetadata& metadata, const Info& info)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     if (!m_initializationSegmentEncountered || !m_initializationSegment) {
-        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered Info outside Segment, bailing");
+        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered Info outside Segment");
         return Status(Status::Code(ErrorCode::InvalidInitSegment));
     }
 
@@ -814,7 +829,8 @@
 Status SourceBufferParserWebM::OnClusterBegin(const ElementMetadata& metadata, const Cluster& cluster, Action* action)
 {
     UNUSED_PARAM(metadata);
-    UNUSED_PARAM(cluster);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     ASSERT(action);
     if (!action)
         return Status(Status::kNotEnoughMemory);
@@ -849,20 +865,29 @@
     auto trackType = trackEntry.track_type.value();
     String codecId { trackEntry.codec_id.value().data(), (unsigned)trackEntry.codec_id.value().length() };
 
+    ALWAYS_LOG_IF_POSSIBLE(LOGIDENTIFIER, trackType, ", codec ", codecId);
+
     if (trackType == TrackType::kVideo && !supportedVideoCodecs().contains(codecId)) {
-        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered unsupported video codec ID \"", codecId, "\", bailing");
+        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered unsupported video codec ID ", codecId);
         return Status(Status::Code(ErrorCode::UnsupportedVideoCodec));
     }
 
     if (trackType == TrackType::kAudio && !supportedAudioCodecs().contains(codecId)) {
-        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered unsupported audio codec ID \"", codecId, "\", bailing");
+        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "Encountered unsupported audio codec ID ", codecId);
         return Status(Status::Code(ErrorCode::UnsupportedAudioCodec));
     }
 
-    if (trackType == TrackType::kVideo)
-        m_initializationSegment->videoTracks.append({ MediaDescriptionWebM::create(TrackEntry(trackEntry)), VideoTrackPrivateWebM::create(TrackEntry(trackEntry)) });
-    else if (trackType == TrackType::kAudio)
-        m_initializationSegment->audioTracks.append({ MediaDescriptionWebM::create(TrackEntry(trackEntry)), AudioTrackPrivateWebM::create(TrackEntry(trackEntry)) });
+    if (trackType == TrackType::kVideo) {
+        auto track = VideoTrackPrivateWebM::create(TrackEntry(trackEntry));
+        if (m_logger)
+            track->setLogger(*m_logger, LoggerHelper::childLogIdentifier(m_logIdentifier, ++m_nextChildIdentifier));
+        m_initializationSegment->videoTracks.append({ MediaDescriptionWebM::create(TrackEntry(trackEntry)), WTFMove(track) });
+    } else if (trackType == TrackType::kAudio) {
+        auto track = AudioTrackPrivateWebM::create(TrackEntry(trackEntry));
+        if (m_logger)
+            track->setLogger(*m_logger, LoggerHelper::childLogIdentifier(m_logIdentifier, ++m_nextChildIdentifier));
+        m_initializationSegment->audioTracks.append({ MediaDescriptionWebM::create(TrackEntry(trackEntry)), WTFMove(track) });
+    }
 
     StringView codecString { trackEntry.codec_id.value().data(), (unsigned)trackEntry.codec_id.value().length() };
 #if ENABLE(VP9)
@@ -897,6 +922,8 @@
 webm::Status SourceBufferParserWebM::OnBlockBegin(const ElementMetadata& metadata, const Block& block, Action* action)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     ASSERT(action);
     if (!action)
         return Status(Status::kNotEnoughMemory);
@@ -912,6 +939,7 @@
 {
     UNUSED_PARAM(metadata);
     UNUSED_PARAM(block);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
 
     m_currentBlock = WTF::nullopt;
 
@@ -921,6 +949,8 @@
 webm::Status SourceBufferParserWebM::OnSimpleBlockBegin(const ElementMetadata& metadata, const SimpleBlock& block, Action* action)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     ASSERT(action);
     if (!action)
         return Status(Status::kNotEnoughMemory);
@@ -935,6 +965,8 @@
 webm::Status SourceBufferParserWebM::OnSimpleBlockEnd(const ElementMetadata& metadata, const SimpleBlock& block)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     UNUSED_PARAM(block);
 
     m_currentBlock = WTF::nullopt;
@@ -945,6 +977,8 @@
 webm::Status SourceBufferParserWebM::OnBlockGroupBegin(const webm::ElementMetadata& metadata, webm::Action* action)
 {
     UNUSED_PARAM(metadata);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
+
     ASSERT(action);
     if (!action)
         return Status(Status::kNotEnoughMemory);
@@ -957,6 +991,7 @@
 {
     UNUSED_PARAM(metadata);
     UNUSED_PARAM(blockGroup);
+    INFO_LOG_IF_POSSIBLE(LOGIDENTIFIER);
     return Status(Status::kOkCompleted);
 }
 
@@ -966,8 +1001,10 @@
     if (!reader)
         return Status(Status::kNotEnoughMemory);
 
-    if (!m_currentBlock)
+    if (!m_currentBlock) {
+        ERROR_LOG_IF_POSSIBLE(LOGIDENTIFIER, "no current block!");
         return Status(Status::kInvalidElementId);
+    }
 
     auto* block = WTF::switchOn(*m_currentBlock, [](Block& block) {
         return &block;

Modified: trunk/Source/WebCore/platform/graphics/cocoa/SourceBufferParserWebM.h (271269 => 271270)


--- trunk/Source/WebCore/platform/graphics/cocoa/SourceBufferParserWebM.h	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebCore/platform/graphics/cocoa/SourceBufferParserWebM.h	2021-01-08 00:18:32 UTC (rev 271270)
@@ -270,6 +270,7 @@
 
     RefPtr<const WTF::Logger> m_logger;
     const void* m_logIdentifier { nullptr };
+    uint64_t m_nextChildIdentifier { 0 };
 };
 
 }

Modified: trunk/Source/WebKit/ChangeLog (271269 => 271270)


--- trunk/Source/WebKit/ChangeLog	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebKit/ChangeLog	2021-01-08 00:18:32 UTC (rev 271270)
@@ -1,3 +1,32 @@
+2021-01-07  Eric Carlson  <[email protected]>
+
+        [Mac] Add runtime logging to format reader and WebM parser
+        https://bugs.webkit.org/show_bug.cgi?id=220423
+        <rdar://problem/72896655>
+
+        Reviewed by Andy Estes.
+
+        Use the Document::sharedLogger to log format and track reader state changes
+        and errors.
+
+        * Shared/mac/MediaFormatReader/MediaFormatReader.cpp:
+        (WebKit::nextLogIdentifier):
+        (WebKit::logChannel):
+        (WebKit::logClassName):
+        (WebKit::MediaFormatReader::parseByteSource):
+        (WebKit::MediaFormatReader::didParseTracks):
+        (WebKit::MediaFormatReader::copyProperty):
+        (WebKit::MediaFormatReader::nextTrackReaderLogIdentifier const):
+        * Shared/mac/MediaFormatReader/MediaFormatReader.h:
+        * Shared/mac/MediaFormatReader/WebKit::MediaTrackReader.cpp:
+        (WebKit::MediaTrackReader::MediaTrackReader):
+        (WebKit::MediaTrackReader::finishParsing):
+        (WebKit::MediaTrackReader::mediaTypeString const):
+        (WebKit::MediaTrackReader::copyProperty):
+        (WebKit::MediaTrackReader::finalize):
+        (WebKit::MediaTrackReader::logChannel const):
+        * Shared/mac/MediaFormatReader/WebKit::MediaTrackReader.h:
+
 2021-01-07  Alexey Shvayka  <[email protected]>
 
         [JSC] Simplify get*PropertyNames() methods and EnumerationMode

Modified: trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaFormatReader.cpp (271269 => 271270)


--- trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaFormatReader.cpp	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaFormatReader.cpp	2021-01-08 00:18:32 UTC (rev 271270)
@@ -31,11 +31,14 @@
 #include "MediaTrackReader.h"
 #include <WebCore/AudioTrackPrivate.h>
 #include <WebCore/ContentType.h>
+#include <WebCore/Document.h>
 #include <WebCore/InbandTextTrackPrivate.h>
+#include <WebCore/Logging.h>
 #include <WebCore/MediaSample.h>
 #include <WebCore/SourceBufferParserWebM.h>
 #include <WebCore/VideoTrackPrivate.h>
 #include <pal/avfoundation/MediaTimeAVFoundation.h>
+#include <wtf/LoggerHelper.h>
 #include <wtf/WorkQueue.h>
 
 #include <pal/cocoa/MediaToolboxSoftLink.h>
@@ -47,6 +50,15 @@
 using namespace PAL;
 using namespace WebCore;
 
+static const void* nextLogIdentifier()
+{
+    static uint64_t logIdentifier = cryptographicallyRandomNumber();
+    return reinterpret_cast<const void*>(++logIdentifier);
+}
+
+static WTFLogChannel& logChannel() { return WebCore::LogMedia; }
+static const char* logClassName() { return "MediaFormatReader"; }
+
 CMBaseClassID MediaFormatReader::wrapperClassID()
 {
     return MTPluginFormatReaderGetClassID();
@@ -97,6 +109,14 @@
         return;
     }
 
+    if (!m_logger) {
+        m_logger = makeRefPtr(Document::sharedLogger());
+        m_logIdentifier = nextLogIdentifier();
+    }
+
+    ALWAYS_LOG(LOGIDENTIFIER);
+    parser->setLogger(*m_logger, m_logIdentifier);
+
     // Set a minimum audio sample duration of 0 so the parser creates indivisible samples with byte source ranges.
     parser->setMinimumAudioSampleDuration(0);
 
@@ -140,6 +160,10 @@
     ASSERT(m_duration.isInvalid());
     ASSERT(m_trackReaders.isEmpty());
 
+    ALWAYS_LOG(LOGIDENTIFIER);
+    if (errorCode)
+        ERROR_LOG(LOGIDENTIFIER, errorCode);
+
     m_parseTracksStatus = errorCode ? kMTPluginFormatReaderError_ParsingFailure : noErr;
     m_duration = WTFMove(segment.duration);
 
@@ -186,6 +210,7 @@
 void MediaFormatReader::finishParsing(Ref<SourceBufferParser>&& parser)
 {
     ASSERT(!isMainThread());
+    ALWAYS_LOG(LOGIDENTIFIER);
 
     auto locker = holdLock(m_parseTracksLock);
     ASSERT(m_parseTracksStatus.hasValue());
@@ -213,6 +238,7 @@
         }
     }
 
+    ERROR_LOG(LOGIDENTIFIER, "asked for unsupported property ", String(key));
     return kCMBaseObjectError_ValueNotAvailable;
 }
 
@@ -234,6 +260,11 @@
     return noErr;
 }
 
+const void* MediaFormatReader::nextTrackReaderLogIdentifier(uint64_t trackID) const
+{
+    return LoggerHelper::childLogIdentifier(m_logIdentifier, trackID);
+}
+
 } // namespace WebKit
 
 #endif // ENABLE(WEBM_FORMAT_READER)

Modified: trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaFormatReader.h (271269 => 271270)


--- trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaFormatReader.h	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaFormatReader.h	2021-01-08 00:18:32 UTC (rev 271270)
@@ -31,6 +31,7 @@
 #include <WebCore/SourceBufferPrivateClient.h>
 #include <wtf/Condition.h>
 #include <wtf/Lock.h>
+#include <wtf/Logger.h>
 
 DECLARE_CORE_MEDIA_TRAITS(FormatReader);
 
@@ -55,6 +56,9 @@
     void startOnMainThread(MTPluginByteSourceRef);
     const MediaTime& duration() const { return m_duration; }
 
+    const Logger& logger() const { ASSERT(m_logger); return *m_logger.get(); }
+    const void* nextTrackReaderLogIdentifier(uint64_t) const;
+
 private:
     explicit MediaFormatReader(Allocator&&);
 
@@ -71,6 +75,8 @@
 
     // WrapperClass
     OSStatus copyTrackArray(CFArrayRef*);
+    
+    const void* logIdentifier() const { return m_logIdentifier; }
 
     RetainPtr<MTPluginByteSourceRef> m_byteSource;
     Condition m_parseTracksCondition;
@@ -78,6 +84,8 @@
     MediaTime m_duration;
     Optional<OSStatus> m_parseTracksStatus;
     Vector<Ref<MediaTrackReader>> m_trackReaders;
+    RefPtr<const Logger> m_logger;
+    const void* m_logIdentifier;
 };
 
 constexpr MediaFormatReader::WrapperClass MediaFormatReader::wrapperClass()

Modified: trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaTrackReader.cpp (271269 => 271270)


--- trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaTrackReader.cpp	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaTrackReader.cpp	2021-01-08 00:18:32 UTC (rev 271270)
@@ -33,6 +33,7 @@
 #include "MediaSampleCursor.h"
 #include <WebCore/AudioTrackPrivate.h>
 #include <WebCore/InbandTextTrackPrivate.h>
+#include <WebCore/Logging.h>
 #include <WebCore/MediaDescription.h>
 #include <WebCore/SampleMap.h>
 #include <WebCore/VideoTrackPrivate.h>
@@ -73,9 +74,12 @@
     , m_trackID(trackID)
     , m_mediaType(mediaType)
     , m_duration(formatReader.duration())
+    , m_logger(formatReader.logger())
+    , m_logIdentifier(formatReader.nextTrackReaderLogIdentifier(trackID))
 {
     ASSERT(!isMainThread());
 
+    ALWAYS_LOG(LOGIDENTIFIER, mediaTypeString(), " ", trackID);
     if (enabled)
         m_isEnabled = enabled.value() ? Enabled::True : Enabled::False;
 }
@@ -112,15 +116,37 @@
 void MediaTrackReader::finishParsing()
 {
     ASSERT(!isMainThread());
+
+    ALWAYS_LOG(LOGIDENTIFIER);
     auto locker = holdLock(m_sampleStorageLock);
     if (!m_sampleStorage)
         m_sampleStorage = makeUnique<SampleStorage>();
     m_sampleStorage->hasAllSamples = true;
-    if (m_isEnabled == Enabled::Unknown)
+    if (m_isEnabled == Enabled::Unknown) {
         m_isEnabled = m_sampleStorage->sampleMap.empty() ? Enabled::False : Enabled::True;
+        if (m_isEnabled == Enabled::False)
+            ERROR_LOG(LOGIDENTIFIER, "ignoring empty ", mediaTypeString(), " track");
+    }
     m_sampleStorageCondition.notifyAll();
 }
 
+const char* MediaTrackReader::mediaTypeString() const
+{
+    switch (m_mediaType) {
+    case kCMMediaType_Video:
+        return "video";
+        break;
+    case kCMMediaType_Audio:
+        return "audio";
+        break;
+    case kCMMediaType_Text:
+        return "text";
+        break;
+    }
+    ASSERT_NOT_REACHED();
+    return "unknown";
+}
+
 OSStatus MediaTrackReader::copyProperty(CFStringRef key, CFAllocatorRef allocator, void* copiedValue)
 {
     // Don't block waiting for media if the we know the enabled state.
@@ -137,15 +163,20 @@
     auto& sampleMap = m_sampleStorage->sampleMap;
 
     if (CFEqual(key, PAL::get_MediaToolbox_kMTPluginTrackReaderProperty_Enabled())) {
-        if (m_isEnabled == Enabled::Unknown)
+        if (m_isEnabled == Enabled::Unknown) {
             m_isEnabled = sampleMap.empty() ? Enabled::False : Enabled::True;
+            if (m_isEnabled == Enabled::False)
+                ERROR_LOG(LOGIDENTIFIER, "ignoring empty ", mediaTypeString(), " track");
+        }
 
         *reinterpret_cast<CFBooleanRef*>(copiedValue) = retainPtr(m_isEnabled == Enabled::True ? kCFBooleanTrue : kCFBooleanFalse).leakRef();
         return noErr;
     }
 
-    if (sampleMap.empty())
+    if (sampleMap.empty()) {
+        ERROR_LOG(LOGIDENTIFIER, "sample table empty when asked for ", String(key));
         return kCMBaseObjectError_ValueNotAvailable;
+    }
 
     auto& lastSample = *sampleMap.decodeOrder().rbegin()->second;
 
@@ -162,6 +193,7 @@
         return noErr;
     }
 
+    ERROR_LOG(LOGIDENTIFIER, "asked for unsupported property ", String(key));
     return kCMBaseObjectError_ValueNotAvailable;
 }
 
@@ -199,6 +231,11 @@
     return noErr;
 }
 
+WTFLogChannel& MediaTrackReader::logChannel() const
+{
+    return WebCore::LogMedia;
+}
+
 } // namespace WebKit
 
 #endif // ENABLE(WEBM_FORMAT_READER)

Modified: trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaTrackReader.h (271269 => 271270)


--- trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaTrackReader.h	2021-01-07 23:56:37 UTC (rev 271269)
+++ trunk/Source/WebKit/Shared/mac/MediaFormatReader/MediaTrackReader.h	2021-01-08 00:18:32 UTC (rev 271270)
@@ -90,6 +90,12 @@
         bool hasAllSamples { false };
     };
 
+    const char* mediaTypeString() const;
+    const WTF::Logger& logger() const { return m_logger; }
+    const char* logClassName() const { return "MediaTrackReader"; }
+    const void* logIdentifier() const { return m_logIdentifier; }
+    WTFLogChannel& logChannel() const;
+
     enum Enabled : uint8_t { Unknown, False, True };
 
     const uint64_t m_trackID;
@@ -99,6 +105,8 @@
     mutable Condition m_sampleStorageCondition;
     mutable Lock m_sampleStorageLock;
     mutable std::unique_ptr<SampleStorage> m_sampleStorage;
+    Ref<const Logger> m_logger;
+    const void* m_logIdentifier;
 };
 
 constexpr MediaTrackReader::WrapperClass MediaTrackReader::wrapperClass()
_______________________________________________
webkit-changes mailing list
[email protected]
https://lists.webkit.org/mailman/listinfo/webkit-changes

Reply via email to