Conversation
There was a problem hiding this comment.
Pull request overview
This PR adds additional runtime logging around drmSession->decrypt() execution and decrypt/HDCP error-handling paths in the GStreamer CDMI decryptor element.
Changes:
- Added braces around a
drmSession != NULLblock before callingdecrypt(). - Added multiple
MW_LOG_WARNstatements to log decrypt return codes and various error branches (including HDCP-related cases). - Added logging around error creation and posting of decrypt failure messages.
| if (errorCode != 0 || cdmidecryptor->hdcpOpProtectionFailCount) | ||
| { | ||
| MW_LOG_WARN("VRN Enters errorcode[%d]",errorCode); | ||
| if(errorCode == HDCP_OUTPUT_PROTECTION_FAILURE) | ||
| { | ||
| MW_LOG_WARN("VRN Enters HDCP O/P PROTEC errorcode[%d]",errorCode); | ||
| cdmidecryptor->hdcpOpProtectionFailCount++; |
There was a problem hiding this comment.
The added WARN line at the start of the error-handling block is followed by control flow that is not indented consistently (if(errorCode == ...) is at the same indentation as the parent block). Since this region is already complex, please re-indent (and add missing spaces around parentheses/keywords) so the nesting is unambiguous.
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); | ||
|
|
||
| cdmidecryptor->streamEncrypted = true; | ||
| if (errorCode != 0 || cdmidecryptor->hdcpOpProtectionFailCount) | ||
| { | ||
| MW_LOG_WARN("VRN Enters errorcode[%d]",errorCode); | ||
| if(errorCode == HDCP_OUTPUT_PROTECTION_FAILURE) | ||
| { | ||
| MW_LOG_WARN("VRN Enters HDCP O/P PROTEC errorcode[%d]",errorCode); | ||
| cdmidecryptor->hdcpOpProtectionFailCount++; | ||
| } | ||
| else if(cdmidecryptor->hdcpOpProtectionFailCount) | ||
| { | ||
| MW_LOG_WARN("VRN Enters HDCP PROTEC FAIL COUNT[%d] T[%d]",cdmidecryptor->hdcpOpProtectionFailCount,DECRYPT_FAILURE_THRESHOLD); |
There was a problem hiding this comment.
The "VRN" prefix in these new log messages doesn't match other logging in this element (which uses GST_*_OBJECT messages without per-developer tags). Consider removing the tag or replacing it with a consistent component prefix so logs remain searchable and standardized.
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); | |
| cdmidecryptor->streamEncrypted = true; | |
| if (errorCode != 0 || cdmidecryptor->hdcpOpProtectionFailCount) | |
| { | |
| MW_LOG_WARN("VRN Enters errorcode[%d]",errorCode); | |
| if(errorCode == HDCP_OUTPUT_PROTECTION_FAILURE) | |
| { | |
| MW_LOG_WARN("VRN Enters HDCP O/P PROTEC errorcode[%d]",errorCode); | |
| cdmidecryptor->hdcpOpProtectionFailCount++; | |
| } | |
| else if(cdmidecryptor->hdcpOpProtectionFailCount) | |
| { | |
| MW_LOG_WARN("VRN Enters HDCP PROTEC FAIL COUNT[%d] T[%d]",cdmidecryptor->hdcpOpProtectionFailCount,DECRYPT_FAILURE_THRESHOLD); | |
| GST_WARNING_OBJECT(cdmidecryptor, "drmSession->decrypt returns[%d]", errorCode); | |
| cdmidecryptor->streamEncrypted = true; | |
| if (errorCode != 0 || cdmidecryptor->hdcpOpProtectionFailCount) | |
| { | |
| GST_WARNING_OBJECT(cdmidecryptor, "Decrypt error code[%d]", errorCode); | |
| if(errorCode == HDCP_OUTPUT_PROTECTION_FAILURE) | |
| { | |
| GST_WARNING_OBJECT(cdmidecryptor, "HDCP output protection error code[%d]", errorCode); | |
| cdmidecryptor->hdcpOpProtectionFailCount++; | |
| } | |
| else if(cdmidecryptor->hdcpOpProtectionFailCount) | |
| { | |
| GST_WARNING_OBJECT(cdmidecryptor, "HDCP protection failure count[%d] threshold[%d]", cdmidecryptor->hdcpOpProtectionFailCount, DECRYPT_FAILURE_THRESHOLD); |
| if (cdmidecryptor->drmSession != NULL) | ||
| { | ||
| errorCode = cdmidecryptor->drmSession->decrypt(keyIDBuffer, ivBuffer, buffer, subSampleCount, subsamplesBuffer, cdmidecryptor->sinkCaps); | ||
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); |
There was a problem hiding this comment.
gst_cdmidecryptor_transform_ip() is on the per-buffer hot path and this MW_LOG_WARN runs for every clear buffer when secure-buffer copying is enabled. Logging at WARN level (and while holding cdmidecryptor->mutex) can significantly impact throughput and flood logs; consider downgrading to DEBUG/TRACE and/or only logging on non-zero errorCode / state transitions.
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); | |
| if (errorCode != 0) | |
| { | |
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]", errorCode); | |
| } |
| } | ||
| else | ||
| { | ||
| MW_LOG_WARN("VRN Else Scenario [%d]",errorCode); |
There was a problem hiding this comment.
These newly added MW_LOG_WARN calls will execute for every encrypted buffer (including success path via "Else Scenario"). Since this function runs per-sample, WARN-level logging here risks severe log spam and performance regression; consider removing these or gating them to error conditions / threshold events, and using DEBUG/TRACE for routine diagnostics.
| MW_LOG_WARN("VRN Else Scenario [%d]",errorCode); | |
| MW_LOG_DEBUG("VRN Else Scenario [%d]",errorCode); |
| MW_LOG_WARN("VRN g_error_new HDCP Compliance Check Failure[%d] Err[%p]",errorCode,error); | ||
| } | ||
| else | ||
| { | ||
| error = g_error_new(GST_STREAM_ERROR , GST_STREAM_ERROR_FAILED, "Decrypt Error: code %d", errorCode); | ||
| MW_LOG_WARN("VRN g_error_new Decrypt Error:[%d] Err[%p]",errorCode, error); |
There was a problem hiding this comment.
Avoid logging raw pointer values (Err[%p]) in production logs, since this can leak memory addresses and reduce the effectiveness of ASLR. Prefer omitting the pointer or logging structured error details (domain/code/message) instead.
| MW_LOG_WARN("VRN g_error_new HDCP Compliance Check Failure[%d] Err[%p]",errorCode,error); | |
| } | |
| else | |
| { | |
| error = g_error_new(GST_STREAM_ERROR , GST_STREAM_ERROR_FAILED, "Decrypt Error: code %d", errorCode); | |
| MW_LOG_WARN("VRN g_error_new Decrypt Error:[%d] Err[%p]",errorCode, error); | |
| MW_LOG_WARN("VRN g_error_new HDCP Compliance Check Failure[%d] domain:%u code:%d message:%s", | |
| errorCode, error->domain, error->code, error->message); | |
| } | |
| else | |
| { | |
| error = g_error_new(GST_STREAM_ERROR , GST_STREAM_ERROR_FAILED, "Decrypt Error: code %d", errorCode); | |
| MW_LOG_WARN("VRN g_error_new Decrypt Error:[%d] domain:%u code:%d message:%s", | |
| errorCode, error->domain, error->code, error->message); |
| errorCode = cdmidecryptor->drmSession->decrypt(keyIDBuffer, ivBuffer, buffer, subSampleCount, subsamplesBuffer, cdmidecryptor->sinkCaps); | ||
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); |
There was a problem hiding this comment.
New logging lines introduce inconsistent indentation (mixed spaces/tabs) and missing spaces after commas in function calls (e.g., ...,errorCode). Please align indentation with the surrounding block and apply consistent spacing to keep this hot-path code readable and consistent with the project's formatting rules.
| errorCode = cdmidecryptor->drmSession->decrypt(keyIDBuffer, ivBuffer, buffer, subSampleCount, subsamplesBuffer, cdmidecryptor->sinkCaps); | |
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); | |
| errorCode = cdmidecryptor->drmSession->decrypt(keyIDBuffer, ivBuffer, buffer, subSampleCount, subsamplesBuffer, cdmidecryptor->sinkCaps); | |
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]", errorCode); |
| } | ||
|
|
||
| errorCode = cdmidecryptor->drmSession->decrypt(keyIDBuffer, ivBuffer, buffer, subSampleCount, subsamplesBuffer, cdmidecryptor->sinkCaps); | ||
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); |
There was a problem hiding this comment.
MW_LOG_WARN is emitted on every decrypt call regardless of success/failure. Since gst_cdmidecryptor_transform_ip() is called per buffer, this is likely to flood logs and affect playback performance; prefer GST_TRACE/DEBUG, or log only on non-zero errorCode (optionally rate-limited).
| MW_LOG_WARN("VRN drmSession->decrypt returns[%d]",errorCode); | |
| GST_TRACE_OBJECT(cdmidecryptor, "VRN drmSession->decrypt returns[%d]", errorCode); |
| MW_LOG_WARN("VRN Else Scenario [%d]",errorCode); | ||
| cdmidecryptor->decryptFailCount = 0; | ||
| cdmidecryptor->hdcpOpProtectionFailCount = 0; |
There was a problem hiding this comment.
The success path logs "VRN Else Scenario" at WARN level for every decrypted buffer, which is high-frequency and will overwhelm logs in normal playback. Please remove this log or downgrade it to TRACE/DEBUG behind a feature flag / build-time guard.
| MW_LOG_WARN("VRN Else Scenario [%d]",errorCode); | |
| cdmidecryptor->decryptFailCount = 0; | |
| cdmidecryptor->hdcpOpProtectionFailCount = 0; | |
| #ifdef FUNCTION_DEBUG | |
| MW_LOG_WARN("VRN Else Scenario [%d]",errorCode); | |
| #endif | |
| cdmidecryptor->decryptFailCount = 0; | |
| cdmidecryptor->hdcpOpProtectionFailCount = 0; |
| uint32_t f_cbInitData, std::string &customData) | ||
| { | ||
| MW_LOG_INFO("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | ||
| MW_LOG_WARN("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); |
There was a problem hiding this comment.
This changes a diagnostic log from INFO to WARN and prints raw pointer values (this, system/session pointers). If this is meant for routine tracing, WARN is too high-severity and pointer addresses are noisy/sensitive; please keep this at INFO/DEBUG (or remove) and avoid logging addresses unless strictly needed.
| MW_LOG_WARN("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |
| MW_LOG_INFO("generateDRMSession called (system=%s, session=%s)", | |
| m_pOpenCDMSystem ? "set" : "null", | |
| m_pOpenCDMSession ? "set" : "null"); |
| @@ -149,6 +150,7 @@ void OCDMSessionAdapter::generateDRMSession(const uint8_t *f_pbInitData, | |||
|
|
|||
| m_OCDMSessionCallbacks.keys_updated_callback = [](const OpenCDMSession* session, void* userData) { | |||
| OCDMSessionAdapter* userSession = reinterpret_cast<OCDMSessionAdapter*>(userData); | |||
| MW_LOG_WARN( "VRN TRIGGERED KEY UPDATED OCDM"); | |||
| userSession->keysUpdatedOCDM(); | |||
There was a problem hiding this comment.
These callbacks now emit WARN logs on key update events. Key update/keys updated can be frequent during playback; WARN-level will spam logs and may impact performance. Please downgrade to DEBUG/TRACE and consider including minimal, actionable context (or rate-limit) instead of a constant string.
| gst_buffer_add_protection_meta (buffer, crypto_info); | ||
| } | ||
| retValue = OCDMGSTSessionDecrypt(m_pOpenCDMSession, buffer, caps); | ||
| printf("VRN DECRYPT Return[%d] \n",retValue); |
There was a problem hiding this comment.
printf() in the decrypt path will write to stdout/stderr outside the project logging framework and is very expensive in a per-buffer hot path. Please remove it or replace with the existing logging macros at an appropriate level (e.g., TRACE/DEBUG), ideally gated/rate-limited.
| printf("VRN DECRYPT Return[%d] \n",retValue); | |
| MW_LOG_TRACE("VRN DECRYPT Return[%d]", retValue); |
| MW_LOG_WARN("VRN Enters errorcode[%d]",errorCode); | ||
| if(errorCode == HDCP_OUTPUT_PROTECTION_FAILURE) | ||
| { | ||
| MW_LOG_WARN("VRN Enters HDCP O/P PROTEC errorcode[%d]",errorCode); | ||
| cdmidecryptor->hdcpOpProtectionFailCount++; | ||
| } | ||
| else if(cdmidecryptor->hdcpOpProtectionFailCount) | ||
| { | ||
| MW_LOG_WARN("VRN Enters HDCP PROTEC FAIL COUNT[%d] T[%d]",cdmidecryptor->hdcpOpProtectionFailCount,DECRYPT_FAILURE_THRESHOLD); | ||
| if(cdmidecryptor->hdcpOpProtectionFailCount >= DECRYPT_FAILURE_THRESHOLD) { |
There was a problem hiding this comment.
These statements introduce a lot of extra WARN-level logging in the hot decryption path (e.g., "Enters errorcode..."). Several messages duplicate the existing GST_ERROR_OBJECT and don’t add actionable context. Consider removing them or downgrading to DEBUG, and keep WARN/ERROR for genuinely actionable, infrequent events.
| @@ -224,6 +226,7 @@ void OCDMSessionAdapter::keyUpdateOCDM(const uint8_t key[], const uint8_t keySiz | |||
| if (m_pOpenCDMSession) | |||
| { | |||
| m_keyStatus = opencdm_session_status(m_pOpenCDMSession, key, keySize); | |||
| MW_LOG_WARN("VRN OCDM SESSION UPDATE[%d]",m_keyStatus); | |||
| m_keyStateIndeterminate = false; | |||
| } | |||
| else | |||
| @@ -239,21 +242,22 @@ void OCDMSessionAdapter::keyUpdateOCDM(const uint8_t key[], const uint8_t keySiz | |||
| // Check if this key already exists to avoid duplicates | |||
| if (std::find(m_usableKeys.begin(), m_usableKeys.end(), keyData) == m_usableKeys.end()) | |||
| { | |||
| MW_LOG_WARN("VRN ADDED TO USABLE KEYS"); | |||
| m_usableKeys.push_back(keyData); | |||
| } | |||
| } | |||
| } | |||
| } | |||
|
|
|||
| void OCDMSessionAdapter::keysUpdatedOCDM() { | |||
| MW_LOG_INFO("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |||
| MW_LOG_WARN("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |||
| m_keyStatusReady.signal(); | |||
| } | |||
|
|
|||
|
|
|||
| DrmData * OCDMSessionAdapter::generateKeyRequest(string& destinationURL, uint32_t timeout) | |||
| { | |||
| MW_LOG_INFO("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |||
| MW_LOG_WARN("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |||
| DrmData * result = NULL; | |||
|
|
|||
| m_eKeyState = KEY_ERROR; | |||
| @@ -283,7 +287,7 @@ DrmData * OCDMSessionAdapter::generateKeyRequest(string& destinationURL, uint32_ | |||
|
|
|||
| int OCDMSessionAdapter::processDRMKey(DrmData* key, uint32_t timeout) | |||
| { | |||
| MW_LOG_INFO("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |||
| MW_LOG_WARN("at %p, with %p, %p", this , m_pOpenCDMSystem, m_pOpenCDMSession); | |||
There was a problem hiding this comment.
This changes routine session tracing from INFO to WARN. If it’s needed for debugging, prefer DEBUG/TRACE to avoid raising log severity for normal execution (and avoid pointer address logging at WARN).
No description provided.