Modified: trunk/Source/WebCore/platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp (221928 => 221929)
--- trunk/Source/WebCore/platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp 2017-09-12 18:01:22 UTC (rev 221928)
+++ trunk/Source/WebCore/platform/graphics/avfoundation/MediaPlayerPrivateAVFoundation.cpp 2017-09-12 18:34:22 UTC (rev 221929)
@@ -41,6 +41,7 @@
#include "URL.h"
#include <CoreMedia/CoreMedia.h>
#include <heap/HeapInlines.h>
+#include <pal/Logger.h>
#include <runtime/DataView.h>
#include <runtime/TypedArrayInlines.h>
#include <runtime/Uint16Array.h>
@@ -60,6 +61,10 @@
, m_networkState(MediaPlayer::Empty)
, m_readyState(MediaPlayer::HaveNothing)
, m_preload(MediaPlayer::Auto)
+#if !RELEASE_LOG_DISABLED
+ , m_logger(player->mediaPlayerLogger())
+ , m_logIdentifier(player->mediaPlayerLogIdentifier())
+#endif
, m_cachedDuration(MediaTime::invalidTime())
, m_reportedDuration(MediaTime::invalidTime())
, m_maxTimeLoadedAtLastDidLoadingProgress(MediaTime::invalidTime())
@@ -81,12 +86,12 @@
, m_shouldMaintainAspectRatio(true)
, m_seeking(false)
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::MediaPlayerPrivateAVFoundation(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
}
MediaPlayerPrivateAVFoundation::~MediaPlayerPrivateAVFoundation()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::~MediaPlayerPrivateAVFoundation(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
setIgnoreLoadStateChanges(true);
}
@@ -126,10 +131,7 @@
if (currentMode == preferredMode && currentMode != MediaRenderingNone)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundation::setUpVideoRendering(%p) - current mode = %d, preferred mode = %d",
- this, static_cast<int>(currentMode), static_cast<int>(preferredMode));
-
- if (currentMode != MediaRenderingNone)
+ if (currentMode != MediaRenderingNone)
tearDownVideoRendering();
switch (preferredMode) {
@@ -144,15 +146,13 @@
}
// If using a movie layer, inform the client so the compositing tree is updated.
- if (currentMode == MediaRenderingToLayer || preferredMode == MediaRenderingToLayer) {
- LOG(Media, "MediaPlayerPrivateAVFoundation::setUpVideoRendering(%p) - calling mediaPlayerRenderingModeChanged()", this);
+ if (currentMode == MediaRenderingToLayer || preferredMode == MediaRenderingToLayer)
m_player->client().mediaPlayerRenderingModeChanged(m_player);
- }
}
void MediaPlayerPrivateAVFoundation::tearDownVideoRendering()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::tearDownVideoRendering(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
destroyContextVideoRenderer();
@@ -167,7 +167,7 @@
void MediaPlayerPrivateAVFoundation::load(const String& url)
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::load(%p)", this);
+ ALWAYS_LOG(LOGIDENTIFIER);
setNetworkState(m_preload == MediaPlayer::None ? MediaPlayer::Idle : MediaPlayer::Loading);
setReadyState(MediaPlayer::HaveNothing);
@@ -191,16 +191,14 @@
void MediaPlayerPrivateAVFoundation::playabilityKnown()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::playabilityKnown(%p)", this);
+ INFO_LOG(LOGIDENTIFIER, "metadata loaded = ", assetStatus() > MediaPlayerAVAssetStatusLoading);
if (m_assetIsPlayable)
return;
// Nothing more to do if we already have all of the item's metadata.
- if (assetStatus() > MediaPlayerAVAssetStatusLoading) {
- LOG(Media, "MediaPlayerPrivateAVFoundation::playabilityKnown(%p) - all metadata loaded", this);
+ if (assetStatus() > MediaPlayerAVAssetStatusLoading)
return;
- }
// At this point we are supposed to load metadata. It is OK to ask the asset to load the same
// information multiple times, because if it has already been loaded the completion handler
@@ -211,14 +209,13 @@
void MediaPlayerPrivateAVFoundation::prepareToPlay()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::prepareToPlay(%p)", this);
-
+ ALWAYS_LOG(LOGIDENTIFIER);
setPreload(MediaPlayer::Auto);
}
void MediaPlayerPrivateAVFoundation::play()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::play(%p)", this);
+ ALWAYS_LOG(LOGIDENTIFIER);
// If the file has video, don't request playback until the first frame of video is ready to display
// or the audio may start playing before we can render video.
@@ -225,7 +222,7 @@
if (!m_cachedHasVideo || hasAvailableVideoFrame())
platformPlay();
else {
- LOG(Media, "MediaPlayerPrivateAVFoundation::play(%p) - waiting for first video frame", this);
+ INFO_LOG(LOGIDENTIFIER, "waiting for first video frame");
m_playWhenFramesAvailable = true;
}
}
@@ -232,7 +229,7 @@
void MediaPlayerPrivateAVFoundation::pause()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::pause(%p)", this);
+ ALWAYS_LOG(LOGIDENTIFIER);
m_playWhenFramesAvailable = false;
platformPause();
}
@@ -247,7 +244,7 @@
return MediaTime::zeroTime();
m_cachedDuration = duration;
- LOG(Media, "MediaPlayerPrivateAVFoundation::duration(%p) - caching %s", this, toString(m_cachedDuration).utf8().data());
+
return m_cachedDuration;
}
@@ -261,7 +258,7 @@
MediaTime time = mediaTime;
if (m_seeking) {
- LOG(Media, "MediaPlayerPrivateAVFoundation::seekWithTolerance(%p) - save pending seek", this);
+ ALWAYS_LOG(LOGIDENTIFIER, "saving pending seek");
m_pendingSeek = [this, time, negativeTolerance, positiveTolerance]() {
seekWithTolerance(time, negativeTolerance, positiveTolerance);
};
@@ -278,7 +275,7 @@
if (currentTextTrack())
currentTextTrack()->beginSeeking();
- LOG(Media, "MediaPlayerPrivateAVFoundation::seek(%p) - seeking to %s", this, toString(time).utf8().data());
+ ALWAYS_LOG(LOGIDENTIFIER, "seeking to ", time);
seekToTime(time, negativeTolerance, positiveTolerance);
}
@@ -316,12 +313,12 @@
void MediaPlayerPrivateAVFoundation::setNaturalSize(FloatSize size)
{
- LOG(Media, "MediaPlayerPrivateAVFoundation:setNaturalSize(%p) - size = %f x %f", this, size.width(), size.height());
-
FloatSize oldSize = m_cachedNaturalSize;
m_cachedNaturalSize = size;
- if (oldSize != m_cachedNaturalSize)
+ if (oldSize != m_cachedNaturalSize) {
+ INFO_LOG(LOGIDENTIFIER, "was ", oldSize.width(), " x ", oldSize.height(), ", is ", size.width(), " x ", size.height());
m_player->sizeChanged();
+ }
}
void MediaPlayerPrivateAVFoundation::setHasVideo(bool b)
@@ -403,11 +400,12 @@
if (!metaDataAvailable())
return MediaTime::zeroTime();
- if (!m_cachedMaxTimeSeekable)
+ if (!m_cachedMaxTimeSeekable) {
m_cachedMaxTimeSeekable = platformMaxTimeSeekable();
+ INFO_LOG(LOGIDENTIFIER, "caching ", m_cachedMaxTimeSeekable);
+ }
- LOG(Media, "MediaPlayerPrivateAVFoundation::maxTimeSeekable(%p) - returning %s", this, toString(m_cachedMaxTimeSeekable).utf8().data());
- return m_cachedMaxTimeSeekable;
+ return m_cachedMaxTimeSeekable;
}
MediaTime MediaPlayerPrivateAVFoundation::minMediaTimeSeekable() const
@@ -415,10 +413,11 @@
if (!metaDataAvailable())
return MediaTime::zeroTime();
- if (!m_cachedMinTimeSeekable)
+ if (!m_cachedMinTimeSeekable) {
m_cachedMinTimeSeekable = platformMinTimeSeekable();
+ INFO_LOG(LOGIDENTIFIER, "caching ", m_cachedMinTimeSeekable);
+ }
- LOG(Media, "MediaPlayerPrivateAVFoundation::minTimeSeekable(%p) - returning %s", this, toString(m_cachedMinTimeSeekable).utf8().data());
return m_cachedMinTimeSeekable;
}
@@ -564,12 +563,10 @@
} else if (!hasAvailableVideoFrame())
m_haveReportedFirstVideoFrame = false;
-#if !LOG_DISABLED
- if (m_networkState != newNetworkState || m_readyState != newReadyState) {
- LOG(Media, "MediaPlayerPrivateAVFoundation::updateStates(%p) - entered with networkState = %i, readyState = %i, exiting with networkState = %i, readyState = %i",
- this, static_cast<int>(m_networkState), static_cast<int>(m_readyState), static_cast<int>(newNetworkState), static_cast<int>(newReadyState));
- }
-#endif
+ if (m_networkState != newNetworkState)
+ ALWAYS_LOG(LOGIDENTIFIER, "entered with networkState ", static_cast<int>(m_networkState), ", exiting with ", static_cast<int>(newNetworkState));
+ if (m_readyState != newReadyState)
+ ALWAYS_LOG(LOGIDENTIFIER, "entered with readyState ", static_cast<int>(m_readyState), ", exiting with ", static_cast<int>(newReadyState));
setNetworkState(newNetworkState);
setReadyState(newReadyState);
@@ -619,8 +616,8 @@
void MediaPlayerPrivateAVFoundation::rateChanged()
{
+
#if ENABLE(WIRELESS_PLAYBACK_TARGET) && PLATFORM(IOS)
- LOG(Media, "MediaPlayerPrivateAVFoundation::rateChanged(%p) - rate = %f, requested rate = %f, item status = %i", this, rate(), requestedRate(), playerItemStatus());
if (isCurrentPlaybackTargetWireless() && playerItemStatus() >= MediaPlayerAVPlayerItemStatusPlaybackBufferFull) {
double rate = this->rate();
if (rate != requestedRate()) {
@@ -648,14 +645,14 @@
void MediaPlayerPrivateAVFoundation::timeChanged(const MediaTime& time)
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::timeChanged(%p) - time = %s", this, toString(time).utf8().data());
UNUSED_PARAM(time);
+ INFO_LOG(LOGIDENTIFIER, "- ", time);
}
void MediaPlayerPrivateAVFoundation::seekCompleted(bool finished)
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::seekCompleted(%p) - finished = %d", this, finished);
UNUSED_PARAM(finished);
+ ALWAYS_LOG(LOGIDENTIFIER, "finished = ", finished);
m_seeking = false;
@@ -663,7 +660,7 @@
std::swap(pendingSeek, m_pendingSeek);
if (pendingSeek) {
- LOG(Media, "MediaPlayerPrivateAVFoundation::seekCompleted(%p) - issuing pending seek", this);
+ ALWAYS_LOG(LOGIDENTIFIER, "issuing pending seek");
pendingSeek();
return;
}
@@ -695,6 +692,7 @@
// so report duration changed when the estimate is upated.
MediaTime duration = this->durationMediaTime();
if (duration != m_reportedDuration) {
+ INFO_LOG(LOGIDENTIFIER, "- ", m_cachedDuration);
if (m_reportedDuration.isValid())
m_player->durationChanged();
m_reportedDuration = duration;
@@ -720,6 +718,7 @@
void MediaPlayerPrivateAVFoundation::setPreload(MediaPlayer::Preload preload)
{
+ ALWAYS_LOG(LOGIDENTIFIER, " - ", static_cast<int>(preload));
m_preload = preload;
if (!m_assetURL.length())
return;
@@ -754,8 +753,6 @@
void MediaPlayerPrivateAVFoundation::mainThreadCallback()
{
- LOG(Media, "MediaPlayerPrivateAVFoundation::mainThreadCallback(%p)", this);
-
clearMainThreadPendingFlag();
dispatchNotification();
}
@@ -776,26 +773,8 @@
scheduleMainThreadNotification(Notification(type, finished));
}
-#if !LOG_DISABLED
-static const char* notificationName(MediaPlayerPrivateAVFoundation::Notification& notification)
-{
-#define DEFINE_TYPE_STRING_CASE(type) case MediaPlayerPrivateAVFoundation::Notification::type: return #type;
- switch (notification.type()) {
- FOR_EACH_MEDIAPLAYERPRIVATEAVFOUNDATION_NOTIFICATION_TYPE(DEFINE_TYPE_STRING_CASE)
- case MediaPlayerPrivateAVFoundation::Notification::FunctionType: return "FunctionType";
- default: ASSERT_NOT_REACHED(); return "";
- }
-#undef DEFINE_TYPE_STRING_CASE
-}
-#endif // !LOG_DISABLED
-
-
void MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(Notification&& notification)
{
- auto notificationType = notification.type();
- if (notificationType != Notification::FunctionType)
- LOG(Media, "MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(%p) - notification %s", this, notificationName(notification));
-
m_queueMutex.lock();
// It is important to always process the properties in the order that we are notified,
@@ -820,11 +799,8 @@
m_queueMutex.unlock();
- if (delayDispatch) {
- if (notificationType != Notification::FunctionType)
- LOG(Media, "MediaPlayerPrivateAVFoundation::scheduleMainThreadNotification(%p) - early return", this);
+ if (delayDispatch)
return;
- }
dispatchNotification();
}
@@ -858,9 +834,6 @@
return;
}
- if (notification.type() != Notification::FunctionType)
- LOG(Media, "MediaPlayerPrivateAVFoundation::dispatchNotification(%p) - dispatching %s", this, notificationName(notification));
-
switch (notification.type()) {
case Notification::ItemDidPlayToEndTime:
didEnd();
@@ -989,8 +962,9 @@
}
}
+ unsigned trackCount = m_textTracks.size();
unsigned inBandCount = 0;
- for (unsigned i = 0; i < m_textTracks.size(); ++i) {
+ for (unsigned i = 0; i < trackCount; ++i) {
RefPtr<InbandTextTrackPrivateAVF> track = m_textTracks[i];
#if ENABLE(AVF_CAPTIONS)
@@ -1006,21 +980,20 @@
track->setHasBeenReported(true);
player()->addTextTrack(*track);
}
- LOG(Media, "MediaPlayerPrivateAVFoundation::processNewAndRemovedTextTracks(%p) - found %lu text tracks", this, m_textTracks.size());
+
+ if (trackCount != m_textTracks.size())
+ INFO_LOG(LOGIDENTIFIER, "found ", m_textTracks.size(), " text tracks");
}
#if ENABLE(WIRELESS_PLAYBACK_TARGET)
-
void MediaPlayerPrivateAVFoundation::playbackTargetIsWirelessChanged()
{
if (m_player)
m_player->currentPlaybackTargetIsWirelessChanged();
}
-
#endif
#if ENABLE(LEGACY_ENCRYPTED_MEDIA)
-
bool MediaPlayerPrivateAVFoundation::extractKeyURIKeyIDAndCertificateFromInitData(Uint8Array* initData, String& keyURI, String& keyID, RefPtr<Uint8Array>& certificate)
{
// initData should have the following layout:
@@ -1070,7 +1043,6 @@
return true;
}
-
#endif
URL MediaPlayerPrivateAVFoundation::resolvedURL() const
@@ -1122,6 +1094,13 @@
return false;
}
+#if !RELEASE_LOG_DISABLED
+WTFLogChannel& MediaPlayerPrivateAVFoundation::logChannel() const
+{
+ return LogMedia;
+}
+#endif
+
const HashSet<String, ASCIICaseInsensitiveHash>& MediaPlayerPrivateAVFoundation::staticMIMETypeList()
{
static const auto cache = makeNeverDestroyed(HashSet<String, ASCIICaseInsensitiveHash> {
Modified: trunk/Source/WebCore/platform/graphics/avfoundation/objc/MediaPlayerPrivateAVFoundationObjC.mm (221928 => 221929)
--- trunk/Source/WebCore/platform/graphics/avfoundation/objc/MediaPlayerPrivateAVFoundationObjC.mm 2017-09-12 18:01:22 UTC (rev 221928)
+++ trunk/Source/WebCore/platform/graphics/avfoundation/objc/MediaPlayerPrivateAVFoundationObjC.mm 2017-09-12 18:34:22 UTC (rev 221929)
@@ -352,13 +352,6 @@
static NSArray *playerKVOProperties();
static AVAssetTrack* firstEnabledTrack(NSArray* tracks);
-#if !LOG_DISABLED
-static const char *boolString(bool val)
-{
- return val ? "true" : "false";
-}
-#endif
-
#if HAVE(AVFOUNDATION_LOADER_DELEGATE)
static dispatch_queue_t globalLoaderDelegateQueue()
{
@@ -478,8 +471,6 @@
void MediaPlayerPrivateAVFoundationObjC::clearMediaCache(const String& path, std::chrono::system_clock::time_point modifiedSince)
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::clearMediaCache()");
-
AVAssetCacheType* assetCache = assetCacheForPath(path);
for (NSString *key in [assetCache allKeys]) {
@@ -522,7 +513,6 @@
void MediaPlayerPrivateAVFoundationObjC::clearMediaCacheForOrigins(const String& path, const HashSet<RefPtr<SecurityOrigin>>& origins)
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::clearMediaCacheForOrigins()");
AVAssetCacheType* assetCache = assetCacheForPath(path);
for (NSString *key in [assetCache allKeys]) {
URL keyAsURL = URL(URL(), key);
@@ -592,7 +582,7 @@
void MediaPlayerPrivateAVFoundationObjC::cancelLoad()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::cancelLoad(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
tearDownVideoRendering();
[[NSNotificationCenter defaultCenter] removeObserver:m_objcObserver.get()];
@@ -681,7 +671,7 @@
void MediaPlayerPrivateAVFoundationObjC::createImageGenerator()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createImageGenerator(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
if (!m_avAsset || m_imageGenerator)
return;
@@ -692,8 +682,6 @@
[m_imageGenerator.get() setAppliesPreferredTrackTransform:YES];
[m_imageGenerator.get() setRequestedTimeToleranceBefore:kCMTimeZero];
[m_imageGenerator.get() setRequestedTimeToleranceAfter:kCMTimeZero];
-
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createImageGenerator(%p) - returning %p", this, m_imageGenerator.get());
}
void MediaPlayerPrivateAVFoundationObjC::destroyContextVideoRenderer()
@@ -710,7 +698,7 @@
if (!m_imageGenerator)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::destroyImageGenerator(%p) - destroying %p", this, m_imageGenerator.get());
+ INFO_LOG(LOGIDENTIFIER);
m_imageGenerator = 0;
}
@@ -755,7 +743,7 @@
updateVideoLayerGravity();
[m_videoLayer setContentsScale:player()->client().mediaPlayerContentsScale()];
IntSize defaultSize = snappedIntRect(player()->client().mediaPlayerContentBoxRect()).size();
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createVideoLayer(%p) - returning %p", this, m_videoLayer.get());
+ INFO_LOG(LOGIDENTIFIER);
#if PLATFORM(IOS) || (PLATFORM(MAC) && ENABLE(VIDEO_PRESENTATION_MODE))
m_videoFullscreenLayerManager->setVideoLayer(m_videoLayer.get(), defaultSize);
@@ -773,7 +761,7 @@
if (!m_videoLayer)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::destroyVideoLayer(%p) - destroying %p", this, m_videoLayer.get());
+ INFO_LOG(LOGIDENTIFIER);
[m_videoLayer removeObserver:m_objcObserver.get() forKeyPath:@"readyForDisplay"];
[m_videoLayer setPlayer:nil];
@@ -911,7 +899,7 @@
if (m_avAsset)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createAVAssetForURL(%p) - url = "" this, url.utf8().data());
+ INFO_LOG(LOGIDENTIFIER);
setDelayCallbacks(true);
@@ -1048,7 +1036,7 @@
if (m_avPlayer)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createAVPlayer(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
setDelayCallbacks(true);
@@ -1097,7 +1085,7 @@
if (m_avPlayerItem)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createAVPlayerItem(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
setDelayCallbacks(true);
@@ -1144,7 +1132,7 @@
return;
m_haveCheckedPlayability = true;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::checkPlayability(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
auto weakThis = createWeakPtr();
[m_avAsset.get() loadValuesAsynchronouslyForKeys:[NSArray arrayWithObjects:@"playable", @"tracks", nil] completionHandler:^{
@@ -1157,7 +1145,7 @@
void MediaPlayerPrivateAVFoundationObjC::beginLoadingMetadata()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::beginLoadingMetadata(%p) - requesting metadata loading", this);
+ INFO_LOG(LOGIDENTIFIER);
OSObjectPtr<dispatch_group_t> metadataLoadingGroup = adoptOSObject(dispatch_group_create());
dispatch_group_enter(metadataLoadingGroup.get());
@@ -1206,7 +1194,7 @@
PlatformMedia MediaPlayerPrivateAVFoundationObjC::platformMedia() const
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::platformMedia(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
PlatformMedia pm;
pm.type = PlatformMedia::AVFoundationMediaPlayerType;
pm.media.avfMediaPlayer = m_avPlayer.get();
@@ -1324,7 +1312,7 @@
void MediaPlayerPrivateAVFoundationObjC::platformPlay()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::platformPlay(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
if (!metaDataAvailable())
return;
@@ -1336,7 +1324,7 @@
void MediaPlayerPrivateAVFoundationObjC::platformPause()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::platformPause(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
if (!metaDataAvailable())
return;
@@ -1367,7 +1355,7 @@
if (CMTIME_IS_INDEFINITE(cmDuration))
return MediaTime::positiveInfiniteTime();
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::platformDuration(%p) - invalid duration, returning %s", this, toString(MediaTime::invalidTime()).utf8().data());
+ INFO_LOG(LOGIDENTIFIER, "returning invalid time");
return MediaTime::invalidTime();
}
@@ -1401,8 +1389,6 @@
auto weakThis = createWeakPtr();
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::seekToTime(%p) - calling seekToTime", this);
-
[m_avPlayerItem.get() seekToTime:cmTime toleranceBefore:cmBefore toleranceAfter:cmAfter completionHandler:^(BOOL finished) {
callOnMainThread([weakThis, finished] {
auto _this = weakThis.get();
@@ -1434,7 +1420,7 @@
if (m_muted == muted)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setMuted(%p) - set to %s", this, boolString(muted));
+ INFO_LOG(LOGIDENTIFIER, "- ", muted);
m_muted = muted;
@@ -1451,7 +1437,7 @@
if (!metaDataAvailable())
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setClosedCaptionsVisible(%p) - set to %s", this, boolString(closedCaptionsVisible));
+ INFO_LOG(LOGIDENTIFIER, "- ", closedCaptionsVisible);
}
void MediaPlayerPrivateAVFoundationObjC::setRateDouble(double rate)
@@ -1593,10 +1579,9 @@
for (NSString *keyName in assetMetadataKeyNames()) {
NSError *error = nil;
AVKeyValueStatus keyStatus = [m_avAsset.get() statusOfValueForKey:keyName error:&error];
-#if !LOG_DISABLED
+
if (error)
- LOG(Media, "MediaPlayerPrivateAVFoundation::assetStatus - statusOfValueForKey failed for %s, error = %s", [keyName UTF8String], [[error localizedDescription] UTF8String]);
-#endif
+ ERROR_LOG(LOGIDENTIFIER, "failed for ", [keyName UTF8String], ", error = ", [[error localizedDescription] UTF8String]);
if (keyStatus < AVKeyValueStatusLoaded)
return MediaPlayerAVAssetStatusLoading;// At least one key is not loaded yet.
@@ -1676,7 +1661,7 @@
void MediaPlayerPrivateAVFoundationObjC::paintWithImageGenerator(GraphicsContext& context, const FloatRect& rect)
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::paintWithImageGenerator(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
RetainPtr<CGImageRef> image = createImageForTimeInRect(currentTime(), rect);
if (image) {
@@ -1695,7 +1680,7 @@
createImageGenerator();
ASSERT(m_imageGenerator);
-#if !LOG_DISABLED
+#if !RELEASE_LOG_DISABLED
double start = monotonicallyIncreasingTime();
#endif
@@ -1703,9 +1688,8 @@
RetainPtr<CGImageRef> rawImage = adoptCF([m_imageGenerator.get() copyCGImageAtTime:CMTimeMakeWithSeconds(time, 600) actualTime:nil error:nil]);
RetainPtr<CGImageRef> image = adoptCF(CGImageCreateCopyWithColorSpace(rawImage.get(), sRGBColorSpaceRef()));
-#if !LOG_DISABLED
- double duration = monotonicallyIncreasingTime() - start;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createImageForTimeInRect(%p) - creating image took %.4f", this, narrowPrecisionToFloat(duration));
+#if !RELEASE_LOG_DISABLED
+ DEBUG_LOG(LOGIDENTIFIER, "creating image took ", monotonicallyIncreasingTime() - start);
#endif
return image;
@@ -1713,7 +1697,6 @@
void MediaPlayerPrivateAVFoundationObjC::getSupportedTypes(HashSet<String, ASCIICaseInsensitiveHash>& supportedTypes)
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::getSupportedTypes");
supportedTypes = AVFoundationMIMETypeCache::singleton().types();
}
@@ -2042,8 +2025,7 @@
setHasClosedCaptions(hasCaptions);
- LOG(Media, "MediaPlayerPrivateAVFoundation:tracksChanged(%p) - hasVideo = %s, hasAudio = %s, hasCaptions = %s",
- this, boolString(hasVideo()), boolString(hasAudio()), boolString(hasClosedCaptions()));
+ INFO_LOG(LOGIDENTIFIER, "has video = ", hasVideo(), ", has audio = ", hasAudio(), ", has captions = ", hasClosedCaptions());
sizeChanged();
@@ -2170,7 +2152,7 @@
void MediaPlayerPrivateAVFoundationObjC::updateAudioTracks()
{
-#if !LOG_DISABLED
+#if !RELEASE_LOG_DISABLED
size_t count = m_audioTracks.size();
#endif
@@ -2190,14 +2172,14 @@
for (auto& track : m_audioTracks)
track->resetPropertiesFromTrack();
-#if !LOG_DISABLED
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::updateAudioTracks(%p) - audio track count was %lu, is %lu", this, count, m_audioTracks.size());
+#if !RELEASE_LOG_DISABLED
+ INFO_LOG(LOGIDENTIFIER, "track count was ", count, ", is ", m_audioTracks.size());
#endif
}
void MediaPlayerPrivateAVFoundationObjC::updateVideoTracks()
{
-#if !LOG_DISABLED
+#if !RELEASE_LOG_DISABLED
size_t count = m_videoTracks.size();
#endif
@@ -2216,8 +2198,8 @@
for (auto& track : m_audioTracks)
track->resetPropertiesFromTrack();
-#if !LOG_DISABLED
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::updateVideoTracks(%p) - video track count was %lu, is %lu", this, count, m_videoTracks.size());
+#if !RELEASE_LOG_DISABLED
+ INFO_LOG(LOGIDENTIFIER, "track count was ", count, ", is ", m_videoTracks.size());
#endif
}
@@ -2318,7 +2300,7 @@
void MediaPlayerPrivateAVFoundationObjC::createVideoOutput()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createVideoOutput(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
if (!m_avPlayerItem || m_videoOutput)
return;
@@ -2334,8 +2316,6 @@
[m_videoOutput setDelegate:m_videoOutputDelegate.get() queue:globalPullDelegateQueue()];
[m_avPlayerItem.get() addOutput:m_videoOutput.get()];
-
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createVideoOutput(%p) - returning %p", this, m_videoOutput.get());
}
void MediaPlayerPrivateAVFoundationObjC::destroyVideoOutput()
@@ -2345,8 +2325,9 @@
if (m_avPlayerItem)
[m_avPlayerItem.get() removeOutput:m_videoOutput.get()];
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::destroyVideoOutput(%p) - destroying %p", this, m_videoOutput.get());
+ INFO_LOG(LOGIDENTIFIER);
+
m_videoOutput = 0;
}
@@ -2397,15 +2378,14 @@
m_pixelBufferConformer = std::make_unique<PixelBufferConformerCV>((CFDictionaryRef)attributes);
}
-#if !LOG_DISABLED
+#if !RELEASE_LOG_DISABLED
double start = monotonicallyIncreasingTime();
#endif
m_lastImage = m_pixelBufferConformer->createImageFromPixelBuffer(pixelBuffer.get());
-#if !LOG_DISABLED
- double duration = monotonicallyIncreasingTime() - start;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::updateLastImage(%p) - creating buffer took %.4f", this, narrowPrecisionToFloat(duration));
+#if !RELEASE_LOG_DISABLED
+ DEBUG_LOG(LOGIDENTIFIER, "creating buffer took ", monotonicallyIncreasingTime() - start);
#endif
}
@@ -2423,7 +2403,7 @@
if (!firstEnabledVideoTrack)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::paintWithVideoOutput(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
GraphicsContextStateSaver stateSaver(context);
FloatRect imageRect(0, 0, CGImageGetWidth(m_lastImage.get()), CGImageGetHeight(m_lastImage.get()));
@@ -2442,7 +2422,7 @@
void MediaPlayerPrivateAVFoundationObjC::createOpenGLVideoOutput()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createOpenGLVideoOutput(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
if (!m_avPlayerItem || m_openGLVideoOutput)
return;
@@ -2456,8 +2436,6 @@
ASSERT(m_openGLVideoOutput);
[m_avPlayerItem.get() addOutput:m_openGLVideoOutput.get()];
-
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::createOpenGLVideoOutput(%p) - returning %p", this, m_openGLVideoOutput.get());
}
void MediaPlayerPrivateAVFoundationObjC::destroyOpenGLVideoOutput()
@@ -2465,9 +2443,10 @@
if (!m_openGLVideoOutput)
return;
+ INFO_LOG(LOGIDENTIFIER);
+
if (m_avPlayerItem)
[m_avPlayerItem.get() removeOutput:m_openGLVideoOutput.get()];
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::destroyOpenGLVideoOutput(%p) - destroying %p", this, m_videoOutput.get());
m_openGLVideoOutput = 0;
}
@@ -2533,7 +2512,7 @@
long result = dispatch_semaphore_wait(m_videoOutputSemaphore, dispatch_time(0, 1 * NSEC_PER_SEC));
if (result)
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::waitForVideoOutputMediaDataWillChange(%p) timed out", this);
+ ERROR_LOG(LOGIDENTIFIER, "timed out");
}
void MediaPlayerPrivateAVFoundationObjC::outputMediaDataWillChange(AVPlayerItemVideoOutputType *)
@@ -2684,7 +2663,7 @@
{
AVMediaSelectionGroupType *legibleGroup = safeMediaSelectionGroupForLegibleMedia();
if (!legibleGroup) {
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::processMediaSelectionOptions(%p) - nil mediaSelectionGroup", this);
+ INFO_LOG(LOGIDENTIFIER, "no mediaSelectionGroup");
return;
}
@@ -2758,7 +2737,7 @@
void MediaPlayerPrivateAVFoundationObjC::flushCues()
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::flushCues(%p)", this);
+ INFO_LOG(LOGIDENTIFIER);
if (!m_currentTextTrack)
return;
@@ -2773,8 +2752,8 @@
if (m_currentTextTrack == track)
return;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setCurrentTextTrack(%p) - selecting track %p, language = %s", this, track, track ? track->language().string().utf8().data() : "");
-
+ INFO_LOG(LOGIDENTIFIER, "selecting track with language ", track ? track->language() : "");
+
m_currentTextTrack = track;
if (track) {
@@ -2820,7 +2799,7 @@
#pragma clang diagnostic pop
if (currentlySelectedAudibleOption) {
m_languageOfPrimaryAudioTrack = [[currentlySelectedAudibleOption locale] localeIdentifier];
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::languageOfPrimaryAudioTrack(%p) - returning language of selected audible option: %s", this, m_languageOfPrimaryAudioTrack.utf8().data());
+ INFO_LOG(LOGIDENTIFIER, "language of selected audible option ", m_languageOfPrimaryAudioTrack);
return m_languageOfPrimaryAudioTrack;
}
@@ -2831,7 +2810,7 @@
NSArray *tracks = [m_avAsset.get() tracksWithMediaType:AVMediaTypeAudio];
if (!tracks || [tracks count] != 1) {
m_languageOfPrimaryAudioTrack = emptyString();
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::languageOfPrimaryAudioTrack(%p) - %lu audio tracks, returning emptyString()", this, static_cast<unsigned long>(tracks ? [tracks count] : 0));
+ INFO_LOG(LOGIDENTIFIER, tracks ? [tracks count] : 0, " audio tracks, returning empty");
return m_languageOfPrimaryAudioTrack;
}
@@ -2838,12 +2817,7 @@
AVAssetTrack *track = [tracks objectAtIndex:0];
m_languageOfPrimaryAudioTrack = AVTrackPrivateAVFObjCImpl::languageForAVAssetTrack(track);
-#if !LOG_DISABLED
- if (m_languageOfPrimaryAudioTrack == emptyString())
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::languageOfPrimaryAudioTrack(%p) - single audio track has no language, returning emptyString()", this);
- else
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::languageOfPrimaryAudioTrack(%p) - returning language of single audio track: %s", this, m_languageOfPrimaryAudioTrack.utf8().data());
-#endif
+ INFO_LOG(LOGIDENTIFIER, "single audio track has language \"", m_languageOfPrimaryAudioTrack, "\"");
return m_languageOfPrimaryAudioTrack;
}
@@ -2864,7 +2838,7 @@
wirelessTarget = m_avPlayer && m_avPlayer.get().externalPlaybackActive;
#endif
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::isCurrentPlaybackTargetWireless(%p) - returning %s", this, boolString(wirelessTarget));
+ INFO_LOG(LOGIDENTIFIER, "- ", wirelessTarget);
return wirelessTarget;
}
@@ -2904,7 +2878,6 @@
#else
wirelessTargetName = wkExernalDeviceDisplayNameForPlayer(m_avPlayer.get());
#endif
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::wirelessPlaybackTargetName(%p) - returning %s", this, wirelessTargetName.utf8().data());
return wirelessTargetName;
}
@@ -2915,7 +2888,7 @@
return !m_allowsWirelessVideoPlayback;
m_allowsWirelessVideoPlayback = [m_avPlayer.get() allowsExternalPlayback];
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::wirelessVideoPlaybackDisabled(%p) - returning %s", this, boolString(!m_allowsWirelessVideoPlayback));
+ INFO_LOG(LOGIDENTIFIER, "- ", !m_allowsWirelessVideoPlayback);
return !m_allowsWirelessVideoPlayback;
}
@@ -2922,7 +2895,7 @@
void MediaPlayerPrivateAVFoundationObjC::setWirelessVideoPlaybackDisabled(bool disabled)
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setWirelessVideoPlaybackDisabled(%p) - %s", this, boolString(disabled));
+ INFO_LOG(LOGIDENTIFIER, "- ", disabled);
m_allowsWirelessVideoPlayback = !disabled;
if (!m_avPlayer)
return;
@@ -2940,7 +2913,7 @@
m_outputContext = m_playbackTarget->targetType() == MediaPlaybackTarget::AVFoundation ? toMediaPlaybackTargetMac(m_playbackTarget.get())->outputContext() : nullptr;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setWirelessPlaybackTarget(%p) - target = %p, device name = %s", this, m_outputContext.get(), m_playbackTarget->deviceName().utf8().data());
+ INFO_LOG(LOGIDENTIFIER);
if (!m_playbackTarget->hasActiveRoute())
setShouldPlayToPlaybackTarget(false);
@@ -2956,11 +2929,11 @@
if (!m_playbackTarget)
return;
+ INFO_LOG(LOGIDENTIFIER, "- ", shouldPlay);
+
if (m_playbackTarget->targetType() == MediaPlaybackTarget::AVFoundation) {
AVOutputContext *newContext = shouldPlay ? m_outputContext.get() : nil;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setShouldPlayToPlaybackTarget(%p) - target = %p, shouldPlay = %s", this, newContext, boolString(shouldPlay));
-
if (!m_avPlayer)
return;
@@ -2977,8 +2950,6 @@
ASSERT(m_playbackTarget->targetType() == MediaPlaybackTarget::Mock);
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::setShouldPlayToPlaybackTarget(%p) - target = {Mock}, shouldPlay = %s", this, boolString(shouldPlay));
-
setDelayCallbacks(true);
auto weakThis = createWeakPtr();
scheduleMainThreadNotification(MediaPlayerPrivateAVFoundation::Notification([weakThis] {
@@ -3084,7 +3055,8 @@
void MediaPlayerPrivateAVFoundationObjC::setShouldBufferData(bool shouldBuffer)
{
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::shouldBufferData(%p) - %s", this, boolString(shouldBuffer));
+ INFO_LOG(LOGIDENTIFIER, "- ", shouldBuffer);
+
if (m_shouldBufferData == shouldBuffer)
return;
@@ -3126,7 +3098,7 @@
{
m_currentMetaData = metadata && ![metadata isKindOfClass:[NSNull class]] ? metadata : nil;
- LOG(Media, "MediaPlayerPrivateAVFoundationObjC::metadataDidArrive(%p) - adding %i cues at time %s", this, m_currentMetaData ? static_cast<int>([m_currentMetaData.get() count]) : 0, toString(mediaTime).utf8().data());
+ DEBUG_LOG(LOGIDENTIFIER, "adding ", m_currentMetaData ? [m_currentMetaData.get() count] : 0, " at time ", mediaTime);
#if ENABLE(DATACUE_VALUE)
if (seeking())
@@ -3369,16 +3341,7 @@
return;
bool willChange = [[change valueForKey:NSKeyValueChangeNotificationIsPriorKey] boolValue];
-
-#if !LOG_DISABLED
- if (willChange)
- LOG(Media, "WebCoreAVFMovieObserver::observeValueForKeyPath(%p) - will change, keyPath = %s", self, [keyPath UTF8String]);
- else {
- RetainPtr<NSString> valueString = adoptNS([[NSString alloc] initWithFormat:@"%@", newValue]);
- LOG(Media, "WebCoreAVFMovieObserver::observeValueForKeyPath(%p) - did change, keyPath = %s, value = %s", self, [keyPath UTF8String], [valueString.get() UTF8String]);
- }
-#endif
-
+ bool shouldLogValue = true;
WTF::Function<void ()> function;
if (context == MediaPlayerAVFoundationObservationContextAVPlayerLayer) {
@@ -3410,15 +3373,19 @@
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::playbackBufferEmptyDidChange, m_callback, [newValue boolValue]);
else if ([keyPath isEqualToString:@"playbackBufferFull"])
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::playbackBufferFullDidChange, m_callback, [newValue boolValue]);
- else if ([keyPath isEqualToString:@"asset"])
+ else if ([keyPath isEqualToString:@"asset"]) {
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::setAsset, m_callback, RetainPtr<id>(newValue));
- else if ([keyPath isEqualToString:@"loadedTimeRanges"])
+ shouldLogValue = false;
+ } else if ([keyPath isEqualToString:@"loadedTimeRanges"]) {
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::loadedTimeRangesDidChange, m_callback, RetainPtr<NSArray>(newValue));
- else if ([keyPath isEqualToString:@"seekableTimeRanges"])
+ shouldLogValue = false;
+ } else if ([keyPath isEqualToString:@"seekableTimeRanges"]) {
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::seekableTimeRangesDidChange, m_callback, RetainPtr<NSArray>(newValue));
- else if ([keyPath isEqualToString:@"tracks"])
+ shouldLogValue = false;
+ } else if ([keyPath isEqualToString:@"tracks"]) {
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::tracksDidChange, m_callback, RetainPtr<NSArray>(newValue));
- else if ([keyPath isEqualToString:@"hasEnabledAudio"])
+ shouldLogValue = false;
+ } else if ([keyPath isEqualToString:@"hasEnabledAudio"])
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::hasEnabledAudioDidChange, m_callback, [newValue boolValue]);
else if ([keyPath isEqualToString:@"presentationSize"])
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::presentationSizeDidChange, m_callback, FloatSize([newValue sizeValue]));
@@ -3430,6 +3397,7 @@
if (CMTIME_IS_NUMERIC(itemTime))
now = std::max(toMediaTime(itemTime), MediaTime::zeroTime());
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::metadataDidArrive, m_callback, RetainPtr<NSArray>(newValue), now);
+ shouldLogValue = false;
} else if ([keyPath isEqualToString:@"canPlayFastReverse"])
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::canPlayFastReverseDidChange, m_callback, [newValue boolValue]);
else if ([keyPath isEqualToString:@"canPlayFastForward"])
@@ -3449,7 +3417,26 @@
function = std::bind(&MediaPlayerPrivateAVFoundationObjC::outputObscuredDueToInsufficientExternalProtectionChanged, m_callback, [newValue boolValue]);
#endif
}
-
+
+#if !RELEASE_LOG_DISABLED
+ if (m_callback->logger().willLog(m_callback->logChannel(), WTFLogLevelDebug)) {
+
+ if (willChange)
+ m_callback->logger().debug(m_callback->logChannel(), PAL::Logger::LogSiteIdentifier("MediaPlayerPrivateAVFoundation", "observeValueForKeyPath", m_callback->logIdentifier()), "will change '", [keyPath UTF8String], "'");
+ else {
+ if (shouldLogValue) {
+ if ([keyPath isEqualToString:@"duration"])
+ m_callback->logger().debug(m_callback->logChannel(), PAL::Logger::LogSiteIdentifier("MediaPlayerPrivateAVFoundation", "observeValueForKeyPath", m_callback->logIdentifier()), "did change '", [keyPath UTF8String], "' to ", toMediaTime([newValue CMTimeValue]));
+ else {
+ RetainPtr<NSString> valueString = adoptNS([[NSString alloc] initWithFormat:@"%@", newValue]);
+ m_callback->logger().debug(m_callback->logChannel(), PAL::Logger::LogSiteIdentifier("MediaPlayerPrivateAVFoundation", "observeValueForKeyPath", m_callback->logIdentifier()), "did change '", [keyPath UTF8String], "' to ", [valueString.get() UTF8String]);
+ }
+ } else
+ m_callback->logger().debug(m_callback->logChannel(), PAL::Logger::LogSiteIdentifier("MediaPlayerPrivateAVFoundation", "observeValueForKeyPath", m_callback->logIdentifier()), "did change '", [keyPath UTF8String], "'");
+ }
+ }
+#endif
+
if (!function)
return;
