Bug 1318965 - Improves the logging in Clearkey r=cpearce

MozReview-Commit-ID: DTQAI7ffMm7

--HG--
extra : rebase_source : 432ab764dcec12da295294615e8024a9fdfe7662
extra : histedit_source : bf2a4bdaadf44f7da935ce2c659a7f039e562388
This commit is contained in:
Jay Harris 2017-01-18 14:49:58 +13:00
parent 845adb059f
commit 21c0f1fb53
2 changed files with 39 additions and 21 deletions

View File

@ -77,6 +77,8 @@ ClearKeySessionManager::CreateSession(uint32_t aPromiseId,
uint32_t aInitDataSize,
SessionType aSessionType)
{
CK_LOGD("ClearKeySessionManager::CreateSession type:%u", aInitDataType);
// Copy the init data so it is correctly captured by the lambda
vector<uint8_t> initData(aInitData, aInitData + aInitDataSize);
@ -93,11 +95,10 @@ ClearKeySessionManager::CreateSession(uint32_t aPromiseId,
// If we haven't loaded, don't do this yet
if (MaybeDeferTillInitialized(deferrer)) {
CK_LOGD("Deferring CreateSession");
return;
}
CK_LOGD("ClearKeySessionManager::CreateSession type:%s", aInitDataType);
CK_LOGARRAY("ClearKeySessionManager::CreateSession initdata: ",
aInitData,
aInitDataSize);
@ -105,7 +106,7 @@ ClearKeySessionManager::CreateSession(uint32_t aPromiseId,
// If 'DecryptingComplete' has been called mHost will be null so we can't
// won't be able to resolve our promise
if (!mHost) {
CK_LOGD("ClearKeySessionManager::CreateSession: mHost is nullptr")
CK_LOGD("ClearKeySessionManager::CreateSession: mHost is nullptr");
return;
}
@ -186,6 +187,8 @@ ClearKeySessionManager::LoadSession(uint32_t aPromiseId,
const char* aSessionId,
uint32_t aSessionIdLength)
{
CK_LOGD("ClearKeySessionManager::LoadSession");
// Copy the sessionId into a string so the lambda captures it properly.
string sessionId(aSessionId, aSessionId + aSessionIdLength);
@ -199,11 +202,10 @@ ClearKeySessionManager::LoadSession(uint32_t aPromiseId,
};
if (MaybeDeferTillInitialized(deferrer)) {
CK_LOGD("Deferring LoadSession");
return;
}
CK_LOGD("ClearKeySessionManager::LoadSession");
// If the SessionManager has been shutdown mHost will be null and we won't
// be able to resolve the promise.
if (!mHost) {
@ -315,6 +317,8 @@ ClearKeySessionManager::UpdateSession(uint32_t aPromiseId,
const uint8_t* aResponse,
uint32_t aResponseSize)
{
CK_LOGD("ClearKeySessionManager::UpdateSession");
// Copy the method arguments so we can capture them in the lambda
string sessionId(aSessionId, aSessionId + aSessionIdLength);
vector<uint8_t> response(aResponse, aResponse + aResponseSize);
@ -334,6 +338,7 @@ ClearKeySessionManager::UpdateSession(uint32_t aPromiseId,
// If we haven't fully loaded, defer calling this method
if (MaybeDeferTillInitialized(deferrer)) {
CK_LOGD("Deferring LoadSession");
return;
}
@ -343,7 +348,6 @@ ClearKeySessionManager::UpdateSession(uint32_t aPromiseId,
return;
}
CK_LOGD("ClearKeySessionManager::UpdateSession");
CK_LOGD("Updating session: %s", sessionId.c_str());
auto itr = mSessions.find(sessionId);
@ -469,6 +473,8 @@ ClearKeySessionManager::CloseSession(uint32_t aPromiseId,
const char* aSessionId,
uint32_t aSessionIdLength)
{
CK_LOGD("ClearKeySessionManager::CloseSession");
// Copy the sessionId into a string so we capture it properly.
string sessionId(aSessionId, aSessionId + aSessionIdLength);
// Hold a reference to the session manager, so it doesn't get deleted
@ -482,11 +488,10 @@ ClearKeySessionManager::CloseSession(uint32_t aPromiseId,
// If we haven't loaded, call this method later.
if (MaybeDeferTillInitialized(deferrer)) {
CK_LOGD("Deferring CloseSession");
return;
}
CK_LOGD("ClearKeySessionManager::CloseSession");
// If DecryptingComplete has been called mHost will be null and we won't
// be able to resolve our promise.
if (!mHost) {
@ -526,6 +531,8 @@ ClearKeySessionManager::RemoveSession(uint32_t aPromiseId,
const char* aSessionId,
uint32_t aSessionIdLength)
{
CK_LOGD("ClearKeySessionManager::RemoveSession");
// Copy the sessionId into a string so it can be captured for the lambda.
string sessionId(aSessionId, aSessionId + aSessionIdLength);
@ -540,6 +547,7 @@ ClearKeySessionManager::RemoveSession(uint32_t aPromiseId,
// If we haven't fully loaded, defer calling this method.
if (MaybeDeferTillInitialized(deferrer)) {
CK_LOGD("Deferring RemoveSession");
return;
}
@ -549,7 +557,6 @@ ClearKeySessionManager::RemoveSession(uint32_t aPromiseId,
return;
}
CK_LOGD("ClearKeySessionManager::RemoveSession");
auto itr = mSessions.find(sessionId);
if (itr == mSessions.end()) {
CK_LOGW("ClearKey CDM couldn't remove non-existent session.");

View File

@ -30,6 +30,8 @@ VideoDecoder::VideoDecoder(Host_8 *aHost)
: mHost(aHost)
, mHasShutdown(false)
{
CK_LOGD("VideoDecoder created");
// We drop the ref in DecodingComplete().
AddRef();
@ -41,12 +43,14 @@ VideoDecoder::VideoDecoder(Host_8 *aHost)
VideoDecoder::~VideoDecoder()
{
CK_LOGD("VideoDecoder destroyed");
}
Status
VideoDecoder::InitDecode(const VideoDecoderConfig& aConfig)
{
CK_LOGD("VideoDecoder::InitDecode");
if (!mDecoder) {
CK_LOGD("VideoDecoder::InitDecode failed to init WMFH264Decoder");
@ -59,12 +63,13 @@ VideoDecoder::InitDecode(const VideoDecoderConfig& aConfig)
Status
VideoDecoder::Decode(const InputBuffer& aInputBuffer, VideoFrame* aVideoFrame)
{
CK_LOGD("VideoDecoder::Decode");
// If the input buffer we have been passed has a null buffer, it means we
// should drain.
if (!aInputBuffer.data) {
// This will drain the decoder until there are no frames left to drain,
// whereupon it will return 'NeedsMoreData'.
CK_LOGD("Input buffer null: Draining");
CK_LOGD("VideoDecoder::Decode Input buffer null: Draining");
return Drain(aVideoFrame);
}
@ -73,7 +78,6 @@ VideoDecoder::Decode(const InputBuffer& aInputBuffer, VideoFrame* aVideoFrame)
data->mTimestamp = aInputBuffer.timestamp;
data->mCrypto = CryptoMetaData(&aInputBuffer);
CK_LOGD("VideoDecoder::DecodeTask");
AutoPtr<DecodeData> d(data);
HRESULT hr;
@ -100,13 +104,13 @@ VideoDecoder::Decode(const InputBuffer& aInputBuffer, VideoFrame* aVideoFrame)
buffer.size(),
data->mTimestamp);
CK_LOGD("VideoDecoder::DecodeTask() Input ret hr=0x%x\n", hr);
CK_LOGD("VideoDecoder::Decode() Input ret hr=0x%x", hr);
if (FAILED(hr)) {
assert(hr != MF_E_TRANSFORM_NEED_MORE_INPUT);
CK_LOGE("VideoDecoder::DecodeTask() decode failed ret=0x%x%s\n",
CK_LOGE("VideoDecoder::Decode() decode failed ret=0x%x%s",
hr,
((hr == MF_E_NOTACCEPTING) ? " (MF_E_NOTACCEPTING)" : ""));
CK_LOGD("Decode failed. The decoder is not accepting input");
@ -117,6 +121,8 @@ VideoDecoder::Decode(const InputBuffer& aInputBuffer, VideoFrame* aVideoFrame)
}
Status VideoDecoder::OutputFrame(VideoFrame* aVideoFrame) {
CK_LOGD("VideoDecoder::OutputFrame");
HRESULT hr = S_OK;
// Read all the output from the decoder. Ideally, this would be a while loop
@ -131,10 +137,10 @@ Status VideoDecoder::OutputFrame(VideoFrame* aVideoFrame) {
break;
}
CK_LOGD("VideoDecoder::DecodeTask() output ret=0x%x\n", hr);
CK_LOGD("VideoDecoder::OutputFrame Decoder output ret=0x%x", hr);
mOutputQueue.push(output);
CK_LOGD("Queue size: %u", mOutputQueue.size());
CK_LOGD("VideoDecoder::OutputFrame: Queue size: %u", mOutputQueue.size());
}
// If we don't have any inputs, we need more data.
@ -146,7 +152,7 @@ Status VideoDecoder::OutputFrame(VideoFrame* aVideoFrame) {
// We will get a MF_E_TRANSFORM_NEED_MORE_INPUT every time, as we always
// consume everything in the buffer.
if (hr != MF_E_TRANSFORM_NEED_MORE_INPUT && FAILED(hr)) {
CK_LOGD("Decode failed output ret=0x%x\n", hr);
CK_LOGD("Decode failed output ret=0x%x", hr);
return Status::kDecodeError;
}
@ -156,6 +162,7 @@ Status VideoDecoder::OutputFrame(VideoFrame* aVideoFrame) {
// The Chromium CDM API doesn't have support for negative strides, though
// they are theoretically possible in real world data.
if (mDecoder->GetStride() <= 0) {
CK_LOGD("VideoDecoder::OutputFrame Failed! (negative stride)");
return Status::kDecodeError;
}
@ -165,10 +172,11 @@ Status VideoDecoder::OutputFrame(VideoFrame* aVideoFrame) {
mDecoder->GetStride(),
aVideoFrame);
if (FAILED(hr)) {
CK_LOGD("VideoDecoder::OutputFrame Failed!");
return Status::kDecodeError;
}
CK_LOGD("Decode succeeded.");
CK_LOGD("VideoDecoder::OutputFrame Succeeded.");
return Status::kSuccess;
}
@ -179,8 +187,7 @@ VideoDecoder::SampleToVideoFrame(IMFSample* aSample,
int32_t aStride,
VideoFrame* aVideoFrame)
{
CK_LOGD("[%p] VideoDecoder::SampleToVideoFrame()\n", this);
assert(aSample);
CK_LOGD("[%p] VideoDecoder::SampleToVideoFrame()", this);
ENSURE(aSample != nullptr, E_POINTER);
ENSURE(aVideoFrame != nullptr, E_POINTER);
@ -234,7 +241,8 @@ VideoDecoder::SampleToVideoFrame(IMFSample* aSample,
// If the buffer is bigger than the max for a 32 bit, fail to avoid buffer
// overflows.
if (bufferSize > UINT32_MAX) {
return Status::kDecodeError;
CK_LOGD("VideoDecoder::SampleToFrame Buffersize bigger than UINT32_MAX");
return E_FAIL;
}
// Get the buffer from the host.
@ -244,6 +252,7 @@ VideoDecoder::SampleToVideoFrame(IMFSample* aSample,
// Make sure the buffer is non-null (allocate guarantees it will be of
// sufficient size).
if (!buffer) {
CK_LOGD("VideoDecoder::SampleToFrame Out of memory");
return E_OUTOFMEMORY;
}
@ -309,6 +318,8 @@ VideoDecoder::Drain(VideoFrame* aVideoFrame)
void
VideoDecoder::DecodingComplete()
{
CK_LOGD("VideoDecoder::DecodingComplete()");
mHasShutdown = true;
// Release the reference we added in the constructor. There may be