1873424 - Perma tier2 dom/media/test/test_eme_createMediaKeys_iframes.html | iframe should have posted us a message saying keys were successfully created - got "failureCreatingMediaKeys InvalidStateError: WMFCDMProxy::Init: WMFCDM init error"

Status: RESOLVED FIXED

(Core :: Audio/Video: Playback, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=442496076&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZL41y6GgQIKRbRj0uWRYMw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2024-01-08T10:49:19.250Z] 10:49:19     INFO - TEST-START | dom/media/test/test_eme_createMediaKeys_iframes.html
[task 2024-01-08T10:49:21.025Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMFactory::CreateContentDecryptionModuleAccess [0000022A96946040]
[task 2024-01-08T10:49:21.026Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMFactory::CreateContentDecryptionModuleAccess [0000022A96946040]: Created CDM access!
[task 2024-01-08T10:49:21.028Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMAccess::CreateContentDecryptionModule [0000022A98F138E0]
[task 2024-01-08T10:49:21.028Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDM::RuntimeClassInitialize [0000022A9690C970]
[task 2024-01-08T10:49:21.029Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFPMPServer::RuntimeClassInitialize [0000022A98F3D040]
[task 2024-01-08T10:49:21.030Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey (MFCreatePMPMediaSession(MFPMPSESSION_IN_PROCESS, nullptr, &mMediaSession, nullptr)) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.031Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey ((MakeAndInitialize< WMFPMPServer, ABI::Windows::Media::Protection::IMediaProtectionPMPServer>( &mPMPServer, propertyPmp.Get()))) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.032Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDM::~WMFClearKeyCDM [0000022A9690C970]
[task 2024-01-08T10:49:21.032Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey ((MakeAndInitialize<WMFClearKeyCDM, IMFContentDecryptionModule>( &cdm, aProperties))) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.036Z] 10:49:21     INFO - TEST-INFO | started process screenshot
[task 2024-01-08T10:49:21.173Z] 10:49:21     INFO - TEST-INFO | screenshot: exit 0
[task 2024-01-08T10:49:21.174Z] 10:49:21     INFO - Buffered messages logged at 10:49:20
[task 2024-01-08T10:49:21.175Z] 10:49:21     INFO - TEST-PASS | dom/media/test/test_eme_createMediaKeys_iframes.html | A valid string reason is expected 
[task 2024-01-08T10:49:21.176Z] 10:49:21     INFO - TEST-PASS | dom/media/test/test_eme_createMediaKeys_iframes.html | Reason cannot be empty 
[task 2024-01-08T10:49:21.176Z] 10:49:21     INFO - add_task | Entering 
[task 2024-01-08T10:49:21.177Z] 10:49:21     INFO - Starting same origin iframe, using src attribute, wait for onload test
[task 2024-01-08T10:49:21.178Z] 10:49:21     INFO - iframe loaded
[task 2024-01-08T10:49:21.178Z] 10:49:21     INFO - Buffered messages finished
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_createMediaKeys_iframes.html | iframe should have posted us a message saying keys were successfully created - got "failureCreatingMediaKeys InvalidStateError: WMFCDMProxy::Init: WMFCDM init error", expected "successCreatingMediaKeys"
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - SimpleTest.is@https://example.com/tests/SimpleTest/SimpleTest.js:509:14
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - iframeMessagePromise</window.onmessage@https://example.com/tests/dom/media/test/test_eme_createMediaKeys_iframes.html:70:9
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - EventHandlerNonNull*iframeMessagePromise<@https://example.com/tests/dom/media/test/test_eme_createMediaKeys_iframes.html:69:5
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - @https://example.com/tests/dom/media/test/test_eme_createMediaKeys_iframes.html:68:30
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - async*add_task/nextTick/<@https://example.com/tests/SimpleTest/SimpleTest.js:2189:34
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - nextTick@https://example.com/tests/SimpleTest/SimpleTest.js:2233:11
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - setTimeout handler*SimpleTest_setTimeoutShim@https://example.com/tests/SimpleTest/SimpleTest.js:922:41
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - add_task@https://example.com/tests/SimpleTest/SimpleTest.js:2137:17
[task 2024-01-08T10:49:21.180Z] 10:49:21     INFO - @https://example.com/tests/dom/media/test/test_eme_createMediaKeys_iframes.html:53:9
[task 2024-01-08T10:49:21.181Z] 10:49:21     INFO - add_task | Leaving 
[task 2024-01-08T10:49:21.181Z] 10:49:21     INFO - add_task | Entering 
[task 2024-01-08T10:49:21.182Z] 10:49:21     INFO - Starting same origin iframe, call via JS, wait for onload test
[task 2024-01-08T10:49:21.182Z] 10:49:21     INFO - iframe loaded
[task 2024-01-08T10:49:21.183Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMFactory::CreateContentDecryptionModuleAccess [0000022A96946040]
[task 2024-01-08T10:49:21.183Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMFactory::CreateContentDecryptionModuleAccess [0000022A96946040]: Created CDM access!
[task 2024-01-08T10:49:21.184Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMAccess::CreateContentDecryptionModule [0000022A98F13940]
[task 2024-01-08T10:49:21.185Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDM::RuntimeClassInitialize [0000022A9690C510]
[task 2024-01-08T10:49:21.185Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFPMPServer::RuntimeClassInitialize [0000022A98F3D6A0]
[task 2024-01-08T10:49:21.186Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey (MFCreatePMPMediaSession(MFPMPSESSION_IN_PROCESS, nullptr, &mMediaSession, nullptr)) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.187Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey ((MakeAndInitialize< WMFPMPServer, ABI::Windows::Media::Protection::IMediaProtectionPMPServer>( &mPMPServer, propertyPmp.Get()))) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.187Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDM::~WMFClearKeyCDM [0000022A9690C510]
[task 2024-01-08T10:49:21.188Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey ((MakeAndInitialize<WMFClearKeyCDM, IMFContentDecryptionModule>( &cdm, aProperties))) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.189Z] 10:49:21     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-01-08T10:49:21.190Z] 10:49:21     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_eme_createMediaKeys_iframes.html | Should not get any errors while trying to get media keys, got InvalidStateError: WMFCDMProxy::Init: WMFCDM init error 
[task 2024-01-08T10:49:21.190Z] 10:49:21     INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:426:16
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - @https://example.com/tests/dom/media/test/test_eme_createMediaKeys_iframes.html:103:7
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - async*add_task/nextTick/<@https://example.com/tests/SimpleTest/SimpleTest.js:2189:34
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - async*nextTick@https://example.com/tests/SimpleTest/SimpleTest.js:2233:11
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - setTimeout handler*SimpleTest_setTimeoutShim@https://example.com/tests/SimpleTest/SimpleTest.js:922:41
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - add_task@https://example.com/tests/SimpleTest/SimpleTest.js:2137:17
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - @https://example.com/tests/dom/media/test/test_eme_createMediaKeys_iframes.html:53:9
[task 2024-01-08T10:49:21.191Z] 10:49:21     INFO - add_task | Leaving 
[task 2024-01-08T10:49:21.192Z] 10:49:21     INFO - add_task | Entering 
[task 2024-01-08T10:49:21.192Z] 10:49:21     INFO - Starting same origin iframe, call via JS, *do not* wait for onload test
[task 2024-01-08T10:49:21.193Z] 10:49:21     INFO - iframe appended (we're not waiting for load)
[task 2024-01-08T10:49:21.193Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMFactory::CreateContentDecryptionModuleAccess [0000022A96946040]
[task 2024-01-08T10:49:21.194Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMFactory::CreateContentDecryptionModuleAccess [0000022A96946040]: Created CDM access!
[task 2024-01-08T10:49:21.194Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDMAccess::CreateContentDecryptionModule [0000022A98F136A0]
[task 2024-01-08T10:49:21.195Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDM::RuntimeClassInitialize [0000022A9690C560]
[task 2024-01-08T10:49:21.195Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFPMPServer::RuntimeClassInitialize [0000022A98F3D0A0]
[task 2024-01-08T10:49:21.196Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey (MFCreatePMPMediaSession(MFPMPSESSION_IN_PROCESS, nullptr, &mMediaSession, nullptr)) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.196Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey ((MakeAndInitialize< WMFPMPServer, ABI::Windows::Media::Protection::IMediaProtectionPMPServer>( &mPMPServer, propertyPmp.Get()))) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.197Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey auto mozilla::WMFClearKeyCDM::~WMFClearKeyCDM [0000022A9690C560]
[task 2024-01-08T10:49:21.198Z] 10:49:21     INFO - GECKO(8016) | [Thread 3462459380]: D/WMFClearKey ((MakeAndInitialize<WMFClearKeyCDM, IMFContentDecryptionModule>( &cdm, aProperties))) failed, rv=c00d3e85
[task 2024-01-08T10:49:21.198Z] 10:49:21     INFO - Not taking screenshot here: see the one that was previously logged

Comment 1

[Noemi Erli[:noemi_erli]]

Alastor, this seems to be a regression from changes in Bug 1872973, could you please take a look?
Thanks,

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1872973

Comment 3

[Alastor Wu [:alwu]]

This will be solved in bug 1873011 as well.

Comment 4

[Alastor Wu [:alwu]]

This should be fixed now, feel free to reopen it if it happens again.

Comment 5

[Intermittent Failures Robot]

10 failures in 3217 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 10

Platform and build breakdown:

• windows11-64-2009-ccov-qr: 9
  • opt: 9
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1873424&startday=2024-01-08&endday=2024-01-14&tree=all