Widevine & hdmi / hdcp-handshake (android.hardware.drm@1.4)

situation: Fairphone 4 with e/os attached to external display (mirroring) through HDMI: DRM-Info: Widevine L1 – but also: ‘Current HDCP-Level: None’

problem, f.e.: while 1080p DRM-content is running in kodi without external Display, when attached to external display (mirroring, usbc-hdmi-adaptor, tried 4, incl. active / passive / powered) playback fails with:

W DrmHalHidl: Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
W System.err: CryptoException: ERROR_DRM_INSUFFICIENT_OUTPUT_PROTECTION
W HDCPManagerAdapter: isHDCPAvailable 0

Widevine CDM seem to load as v1.3 factory but returns v1.0 ICryptoPlugin, which the framework can’t upgrade to v1.4. maybe no @1.4 instance exists?

if yes, Questions:

  1. Is there a known fix or an update planned?

  2. Can the v1.4 ICryptoPlugin support be added via Magisk module or replacement?

  3. Is isHDCPAvailable 0 expected here, or should the display driver report HDCP as active when playing L1 content?

0-08 21:37:22.851  1100  6224 I QCOM-OEMCrypto: Idle mode enabled for external display :   No
10-08 21:37:22.853   678   690 D DrmLibTime: got the req here! ret=0
10-08 21:37:22.853   678   690 D DrmLibTime: command id, time_cmd_id = 770
10-08 21:37:22.853   678   690 D DrmLibTime: time_getutcsec starts!
10-08 21:37:22.853   678   690 D DrmLibTime: QSEE Time Listener: time_getutcsec
10-08 21:37:22.853   678   690 D DrmLibTime: QSEE Time Listener: get_utc_seconds
10-08 21:37:22.853   678   690 D DrmLibTime: QSEE Time Listener: time_get_modem_time
10-08 21:37:22.853   678   690 D DrmLibTime: QSEE Time Listener: Checking if ATS_MODEM is set or not.
10-08 21:37:22.854   678   690 D DrmLibTime: QSEE Time Listener: ATS_MODEM is set. Try to retrieve it.
10-08 21:37:22.856   678   690 D DrmLibTime: QSEE Time Listener: Time GenOff - seconds: 1791488317
10-08 21:37:22.856   678   690 D DrmLibTime: time_getutcsec returns 0, sec = 1791488317; nsec = 0
10-08 21:37:22.856   678   690 D DrmLibTime: time_getutcsec finished!
10-08 21:37:22.856   678   690 D DrmLibTime: iotcl_continue_command finished! and return 0
10-08 21:37:22.856   678   690 D DrmLibTime: before calling ioctl to read the next time_cmd
10-08 21:37:23.342 10852 10852 I MediaDrm: Drm event (2,0)
10-08 21:37:23.354   678   696 D OPS_SERVICE: set_display_clock_vote 1 driver fd 36
10-08 21:37:23.354   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 1
10-08 21:37:23.356   678   696 D OPS_SERVICE: set_display_clock_vote 0 driver fd 36
10-08 21:37:23.356   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 0
10-08 21:37:23.360  1155  1441 I libdisplayconfigqti: Register client:WVC1100
10-08 21:37:23.462  1558  2272 I InputDispatcher: Touch is slipping out of window Letterbox_left_ActivityRecord{95642694 u0 org.xbmc.kodi/.Main t24} into window a9ea7cf org.xbmc.kodi/org.xbmc.kodi.Main in display 0
10-08 21:37:23.639   678   696 D OPS_SERVICE: set_display_clock_vote 1 driver fd 36
10-08 21:37:23.639   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 1
10-08 21:37:23.642   678   696 D OPS_SERVICE: set_display_clock_vote 0 driver fd 36
10-08 21:37:23.642   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 0
10-08 21:37:23.691 10852 11032 I DrmUtils: found IDrmFactory. Instance name:[android.hardware.drm.IDrmFactory/clearkey]
10-08 21:37:23.694 10852 11032 D CryptoHalHidl: found drm@1.0 ICryptoFactory wfdhdcp
10-08 21:37:23.696 10852 11032 D CryptoHalHidl: found drm@1.0 ICryptoFactory widevine
10-08 21:37:23.699 10852 11032 D CryptoHalHidl: found drm@1.1 ICryptoFactory wfdhdcp
10-08 21:37:23.702 10852 11032 D CryptoHalHidl: found drm@1.1 ICryptoFactory widevine
10-08 21:37:23.702  1497  1585 W HDCPManagerAdapter: HDCPManagerAdapter::isHDCPAvailable 0
10-08 21:37:23.702  1100  1100 I WVCdm   : [app] calling virtual Return<void> wvdrm::hardware::drm::V1_3::widevine::WVCryptoFactory::createPlugin(const hidl_array<uint8_t, 16> &, const hidl_vec<uint8_t> &, android::hardware::drm::V1_3::ICryptoFactory::createPlugin_cb)
10-08 21:37:23.703  1497  1585 W HDCPManagerAdapter: HDCPManagerAdapter::isHDCPAvailable 0
10-08 21:37:23.703  1100  1100 I WVCdm   : [app] calling virtual Return<void> wvdrm::hardware::drm::V1_3::widevine::WVCryptoFactory::createPlugin(const hidl_array<uint8_t, 16> &, const hidl_vec<uint8_t> &, android::hardware::drm::V1_3::ICryptoFactory::createPlugin_cb)
10-08 21:37:23.729 10852 11032 I DrmUtils: found IDrmFactory. Instance name:[android.hardware.drm.IDrmFactory/clearkey]
10-08 21:37:23.731 10852 11032 D CryptoHalHidl: found drm@1.0 ICryptoFactory wfdhdcp
10-08 21:37:23.733 10852 11032 D CryptoHalHidl: found drm@1.0 ICryptoFactory widevine
10-08 21:37:23.734 10852 11032 D CryptoHalHidl: found drm@1.1 ICryptoFactory wfdhdcp
10-08 21:37:23.735 10852 11032 D CryptoHalHidl: found drm@1.1 ICryptoFactory widevine
10-08 21:37:23.735  1497  1585 W HDCPManagerAdapter: HDCPManagerAdapter::isHDCPAvailable 0
10-08 21:37:23.735  1100  1149 I WVCdm   : [app] calling virtual Return<void> wvdrm::hardware::drm::V1_3::widevine::WVCryptoFactory::createPlugin(const hidl_array<uint8_t, 16> &, const hidl_vec<uint8_t> &, android::hardware::drm::V1_3::ICryptoFactory::createPlugin_cb)
10-08 21:37:23.736  1497  1585 W HDCPManagerAdapter: HDCPManagerAdapter::isHDCPAvailable 0
10-08 21:37:23.736  1100  1149 I WVCdm   : [app] calling virtual Return<void> wvdrm::hardware::drm::V1_3::widevine::WVCryptoFactory::createPlugin(const hidl_array<uint8_t, 16> &, const hidl_vec<uint8_t> &, android::hardware::drm::V1_3::ICryptoFactory::createPlugin_cb)
10-08 21:37:23.784   678   696 D OPS_SERVICE: set_display_clock_vote 1 driver fd 36
10-08 21:37:23.784   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 1
10-08 21:37:23.786   678   696 D OPS_SERVICE: set_display_clock_vote 0 driver fd 36
10-08 21:37:23.786   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 0
10-08 21:37:23.787   678   696 D OPS_SERVICE: set_display_clock_vote 1 driver fd 36
10-08 21:37:23.787   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 1
10-08 21:37:23.788   678   696 D OPS_SERVICE: set_display_clock_vote 0 driver fd 36
10-08 21:37:23.788   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 0
10-08 21:37:23.980  1558  2272 I InputDispatcher: Touch is slipping out of window Letterbox_left_ActivityRecord{95642694 u0 org.xbmc.kodi/.Main t24} into window a9ea7cf org.xbmc.kodi/org.xbmc.kodi.Main in display 0
10-08 21:37:23.984  1155  1441 I libdisplayconfigqti: Register client:WVC1100
10-08 21:37:23.987   678   696 D OPS_SERVICE: set_display_clock_vote 1 driver fd 36
10-08 21:37:23.987   678   696 D OPS_SERVICE: drmIOCTL success at 1 time(s) for clk_vote 1
10-08 21:37:24.046 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ publishKeyEvent: seq=5, id=-843342123, deviceId=-1, source=KEYBOARD, action=DOWN, flags=0x48, keyCode=BACK, scanCode=0, metaState=0x0, repeatCount=0,downTime=1407082000000, eventTime=1407082000000
10-08 21:37:24.046 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ publishKeyEvent: seq=6, id=-489660962, deviceId=-1, source=KEYBOARD, action=UP, flags=0x48, keyCode=BACK, scanCode=0, metaState=0x0, repeatCount=0,downTime=1407082000000, eventTime=1407082000000
10-08 21:37:24.048 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ receiveConsumerResponse: finished: seq=5, handled=false
10-08 21:37:24.048 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ receiveConsumerResponse: finished: seq=6, handled=false
10-08 21:37:24.613 10852 11063 W DrmHalHidl: Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.614 10852 11063 W System.err: android.media.MediaCodec$CryptoException: Required output protections are not active: ERROR_DRM_INSUFFICIENT_OUTPUT_PROTECTION
10-08 21:37:24.614 10852 11063 W System.err: ============================== Beginning of DRM Plugin Log ==============================
10-08 21:37:24.614 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=wfdhdcp version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.614 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=widevine version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.614 10852 11063 W System.err:   10-08 21:37:24.614 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.614 10852 11063 W System.err: ============================== End of DRM Plugin Log ==============================
10-08 21:37:24.628 10852 11063 W DrmHalHidl: Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.628 10852 11063 W System.err: android.media.MediaCodec$CryptoException: Required output protections are not active: ERROR_DRM_INSUFFICIENT_OUTPUT_PROTECTION
10-08 21:37:24.628 10852 11063 W System.err: ============================== Beginning of DRM Plugin Log ==============================
10-08 21:37:24.628 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=wfdhdcp version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.628 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=widevine version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.628 10852 11063 W System.err:   10-08 21:37:24.614 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.628 10852 11063 W System.err:   10-08 21:37:24.628 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.628 10852 11063 W System.err: ============================== End of DRM Plugin Log ==============================
10-08 21:37:24.640 10852 11063 W DrmHalHidl: Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.640 10852 11063 W System.err: android.media.MediaCodec$CryptoException: Required output protections are not active: ERROR_DRM_INSUFFICIENT_OUTPUT_PROTECTION
10-08 21:37:24.640 10852 11063 W System.err: ============================== Beginning of DRM Plugin Log ==============================
10-08 21:37:24.640 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=wfdhdcp version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.640 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=widevine version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.640 10852 11063 W System.err:   10-08 21:37:24.614 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.640 10852 11063 W System.err:   10-08 21:37:24.628 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.640 10852 11063 W System.err:   10-08 21:37:24.640 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.640 10852 11063 W System.err: ============================== End of DRM Plugin Log ==============================
10-08 21:37:24.651 10852 11063 W DrmHalHidl: Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.651 10852 11063 W System.err: android.media.MediaCodec$CryptoException: Required output protections are not active: ERROR_DRM_INSUFFICIENT_OUTPUT_PROTECTION
10-08 21:37:24.651 10852 11063 W System.err: ============================== Beginning of DRM Plugin Log ==============================
10-08 21:37:24.651 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=wfdhdcp version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.651 10852 11063 W System.err:   10-08 21:35:34.212 I found instance=widevine version=android.hardware.drm@1.3::IDrmFactory
10-08 21:37:24.651 10852 11063 W System.err:   10-08 21:37:24.614 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.651 10852 11063 W System.err:   10-08 21:37:24.628 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.651 10852 11063 W System.err:   10-08 21:37:24.640 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.651 10852 11063 W System.err:   10-08 21:37:24.651 W Cannot cast android.hardware.drm@1.0::ICryptoPlugin obj to android.hardware.drm@1.4::ICryptoPlugin plugin
10-08 21:37:24.651 10852 11063 W System.err: ============================== End of DRM Plugin Log ==============================
10-08 21:37:25.384  1558  2272 I InputDispatcher: Touch is slipping out of window Letterbox_left_ActivityRecord{95642694 u0 org.xbmc.kodi/.Main t24} into window a9ea7cf org.xbmc.kodi/org.xbmc.kodi.Main in display 0
10-08 21:37:25.480 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ publishKeyEvent: seq=7, id=-832013030, deviceId=-1, source=KEYBOARD, action=DOWN, flags=0x48, keyCode=BACK, scanCode=0, metaState=0x0, repeatCount=0,downTime=1408516000000, eventTime=1408516000000
10-08 21:37:25.481 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ publishKeyEvent: seq=8, id=-87329738, deviceId=-1, source=KEYBOARD, action=UP, flags=0x48, keyCode=BACK, scanCode=0, metaState=0x0, repeatCount=0,downTime=1408516000000, eventTime=1408516000000
10-08 21:37:25.483 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ receiveConsumerResponse: finished: seq=7, handled=false
10-08 21:37:25.483 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ receiveConsumerResponse: finished: seq=8, handled=false
10-08 21:37:25.816  1558  1827 I DisplayDeviceRepository: Display device changed render timings: "Integrierter Bildschirm", renderFrameRate=60.000004, presentationDeadlineNanos=16666666, appVsyncOffsetNanos=1000000, frameRateOverrides=[]
10-08 21:37:26.135  1558  2272 I InputDispatcher: Touch is slipping out of window Letterbox_left_ActivityRecord{95642694 u0 org.xbmc.kodi/.Main t24} into window a9ea7cf org.xbmc.kodi/org.xbmc.kodi.Main in display 0
10-08 21:37:26.182  1558  1827 I DisplayDeviceRepository: Display device changed render timings: "Integrierter Bildschirm", renderFrameRate=60.000004, presentationDeadlineNanos=16666666, appVsyncOffsetNanos=1000000, frameRateOverrides=[{uid=10281 frameRateHz=60.000004}]
10-08 21:37:26.720  1558  2272 I InputDispatcher: Touch is slipping out of window Letterbox_left_ActivityRecord{95642694 u0 org.xbmc.kodi/.Main t24} into window a9ea7cf org.xbmc.kodi/org.xbmc.kodi.Main in display 0
10-08 21:37:26.790 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ publishKeyEvent: seq=9, id=-420190775, deviceId=-1, source=KEYBOARD, action=DOWN, flags=0x48, keyCode=BACK, scanCode=0, metaState=0x0, repeatCount=0,downTime=1409826000000, eventTime=1409826000000
10-08 21:37:26.791 10852 10852 D InputTransport: channel 'ClientState{f6c39af mUid=10281 mPid=10852 mSelfReportedDisplayId=0}' publisher ~ publishKeyEvent: seq=10, id=-47632998, deviceId=-1, source=KEYBOARD, action=UP, flags=0x48, keyCode=BACK, scanCode=0, metaState=0x0, repeatCount=0,downTime=1409826000000, eventTime=1409826000000