Bug 1318965 - Improves the logging in Clearkey r?cpearce
MozReview-Commit-ID: DTQAI7ffMm7
--- a/media/gmp-clearkey/0.1/ClearKeySessionManager.cpp
+++ b/media/gmp-clearkey/0.1/ClearKeySessionManager.cpp
@@ -72,45 +72,46 @@ ClearKeySessionManager::Init(bool aDisti
void
ClearKeySessionManager::CreateSession(uint32_t aPromiseId,
InitDataType aInitDataType,
const uint8_t* aInitData,
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);
RefPtr<ClearKeySessionManager> self(this);
function<void()> deferrer =
[self, aPromiseId, aInitDataType, initData, aSessionType] ()
{
self->CreateSession(aPromiseId,
aInitDataType,
initData.data(),
initData.size(),
aSessionType);
};
// 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);
// 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;
}
// initDataType must be "cenc", "keyids", or "webm".
if (aInitDataType != InitDataType::kCenc &&
aInitDataType != InitDataType::kKeyIds &&
aInitDataType != InitDataType::kWebM) {
@@ -181,34 +182,35 @@ ClearKeySessionManager::CreateSession(ui
0);
}
void
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);
// Hold a reference to the SessionManager so that it isn't released before
// we try to use it.
RefPtr<ClearKeySessionManager> self(this);
function<void()> deferrer =
[self, aPromiseId, sessionId] ()
{
self->LoadSession(aPromiseId, sessionId.data(), sessionId.size());
};
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) {
return;
}
if (!ClearKeyUtils::IsValidSessionId(aSessionId, aSessionIdLength)) {
mHost->OnResolveNewSessionPromise(aPromiseId, nullptr, 0);
@@ -310,16 +312,18 @@ ClearKeySessionManager::PersistentSessio
void
ClearKeySessionManager::UpdateSession(uint32_t aPromiseId,
const char* aSessionId,
uint32_t aSessionIdLength,
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);
// Hold a reference to the SessionManager so it isn't released before we
// callback.
RefPtr<ClearKeySessionManager> self(this);
function<void()> deferrer =
@@ -329,26 +333,26 @@ ClearKeySessionManager::UpdateSession(ui
sessionId.data(),
sessionId.size(),
response.data(),
response.size());
};
// If we haven't fully loaded, defer calling this method
if (MaybeDeferTillInitialized(deferrer)) {
+ CK_LOGD("Deferring LoadSession");
return;
}
// Make sure the SessionManager has not been shutdown before we try and
// resolve any promises.
if (!mHost) {
return;
}
- CK_LOGD("ClearKeySessionManager::UpdateSession");
CK_LOGD("Updating session: %s", sessionId.c_str());
auto itr = mSessions.find(sessionId);
if (itr == mSessions.end() || !(itr->second)) {
CK_LOGW("ClearKey CDM couldn't resolve session ID in UpdateSession.");
CK_LOGD("Unable to find session: %s", sessionId.c_str());
mHost->OnRejectPromise(aPromiseId,
Error::kInvalidAccessError,
@@ -464,34 +468,35 @@ ClearKeySessionManager::Serialize(const
}
}
void
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
// before we need to use it.
RefPtr<ClearKeySessionManager> self(this);
function<void()> deferrer =
[self, aPromiseId, sessionId] ()
{
self->CloseSession(aPromiseId, sessionId.data(), sessionId.size());
};
// 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) {
return;
}
auto itr = mSessions.find(sessionId);
if (itr == mSessions.end()) {
@@ -521,40 +526,42 @@ ClearKeySessionManager::ClearInMemorySes
delete aSession;
}
void
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);
// Hold a reference to the SessionManager, so it isn't released before we
// try and use it.
RefPtr<ClearKeySessionManager> self(this);
function<void()> deferrer =
[self, aPromiseId, sessionId] ()
{
self->RemoveSession(aPromiseId, sessionId.data(), sessionId.size());
};
// If we haven't fully loaded, defer calling this method.
if (MaybeDeferTillInitialized(deferrer)) {
+ CK_LOGD("Deferring RemoveSession");
return;
}
// Check that the SessionManager has not been shutdown before we try and
// resolve any promises.
if (!mHost) {
return;
}
- CK_LOGD("ClearKeySessionManager::RemoveSession");
auto itr = mSessions.find(sessionId);
if (itr == mSessions.end()) {
CK_LOGW("ClearKey CDM couldn't remove non-existent session.");
mHost->OnRejectPromise(aPromiseId,
Error::kInvalidAccessError,
0,
nullptr,
--- a/media/gmp-clearkey/0.1/VideoDecoder.cpp
+++ b/media/gmp-clearkey/0.1/VideoDecoder.cpp
@@ -25,60 +25,64 @@
using namespace wmf;
using namespace cdm;
VideoDecoder::VideoDecoder(Host_8 *aHost)
: mHost(aHost)
, mHasShutdown(false)
{
+ CK_LOGD("VideoDecoder created");
+
// We drop the ref in DecodingComplete().
AddRef();
mDecoder = new WMFH264Decoder();
uint32_t cores = std::max(1u, std::thread::hardware_concurrency());
HRESULT hr = mDecoder->Init(cores);
}
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");
return Status::kDecodeError;
}
return Status::kSuccess;
}
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);
}
DecodeData* data = new DecodeData();
Assign(data->mBuffer, aInputBuffer.data, aInputBuffer.data_size);
data->mTimestamp = aInputBuffer.timestamp;
data->mCrypto = CryptoMetaData(&aInputBuffer);
- CK_LOGD("VideoDecoder::DecodeTask");
AutoPtr<DecodeData> d(data);
HRESULT hr;
if (!data || !mDecoder) {
CK_LOGE("Decode job not set up correctly!");
return Status::kDecodeError;
}
@@ -95,97 +99,100 @@ VideoDecoder::Decode(const InputBuffer&
return rv;
}
}
hr = mDecoder->Input(buffer.data(),
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");
return Status::kDecodeError;
}
return OutputFrame(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
// where we read the output and check the result as the condition. However,
// this produces a memory leak connected to assigning a new CComPtr to the
// address of the old one, which avoids the CComPtr cleaning up.
while (true) {
CComPtr<IMFSample> output;
hr = mDecoder->Output(&output);
if (hr != S_OK) {
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.
if (mOutputQueue.empty()) {
CK_LOGD("Decode failed. Not enought data; Requesting more input");
return Status::kNeedMoreData;
}
// 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;
}
CComPtr<IMFSample> result = mOutputQueue.front();
mOutputQueue.pop();
// 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;
}
hr = SampleToVideoFrame(result,
mDecoder->GetFrameWidth(),
mDecoder->GetFrameHeight(),
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;
}
HRESULT
VideoDecoder::SampleToVideoFrame(IMFSample* aSample,
int32_t aWidth,
int32_t aHeight,
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);
HRESULT hr;
CComPtr<IMFMediaBuffer> mediaBuffer;
aVideoFrame->SetFormat(kI420);
@@ -229,26 +236,28 @@ VideoDecoder::SampleToVideoFrame(IMFSamp
aVideoFrame->SetSize(Size(aWidth, aHeight));
uint64_t bufferSize = ySize + 2 * uSize;
// 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.
Buffer* buffer = mHost->Allocate(bufferSize);
aVideoFrame->SetFrameBuffer(buffer);
// 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;
}
uint8_t* outBuffer = buffer->Data();
aVideoFrame->SetPlaneOffset(VideoFrame::kYPlane, 0);
// Offset is the size of the copied y data.
@@ -304,15 +313,17 @@ VideoDecoder::Drain(VideoFrame* aVideoFr
// Return any pending output.
return OutputFrame(aVideoFrame);
}
void
VideoDecoder::DecodingComplete()
{
+ CK_LOGD("VideoDecoder::DecodingComplete()");
+
mHasShutdown = true;
// Release the reference we added in the constructor. There may be
// WrapRefCounted tasks that also hold references to us, and keep
// us alive a little longer.
Release();
}