ExoPlayer: DrmSession$DrmSessionException: java.lang.IllegalArgumentException: Failed to restore keys: BAD_VALUE

Bug

Hi!

DrmSession$DrmSessionException: java.lang.IllegalArgumentException: Failed to restore keys: BAD_VALUE occurs when trying to play downloaded content offline using the ExoPlayer library version 2.18.2.

Log attached. If you need to provide additional information about the implementation or other logs, I will be happy to help resolve the issue.

The problem is compounded by the fact that the bug only reproduces on Samsung S23 / S23 Ultra devices, but does not reproduce on other real devices and on emulators.

Ideas, hypotheses, assumptions?

Thanks in advance for your reply.

Caused by: com.google.android.exoplayer2.drm.DrmSession$DrmSessionException: java.lang.IllegalArgumentException: Failed to restore keys: BAD_VALUE
============================== Beginning of DRM Plugin Log ==============================
  06-05 17:35:02.306 I [oemcrypto_adapter_dynamic.cpp(943):Initialize] Level 1 Build Info (v17): Build Information: API_Version: 17.0 LibOEMCrypto_Version: 1.63 TA_Version: 1.12
  06-05 17:35:02.308 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 17:35:02.311 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid17
  06-05 17:35:02.311 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid17
  06-05 17:35:02.312 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid17, playback_id = eHNgqF5yFHXTlMPq
  06-05 17:35:02.315 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid17, key_set_id = <empty>, license_type = Streaming
  06-05 17:35:02.345 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:02.345 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid17
  06-05 17:35:02.388 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:02.792 I [cdm_engine.cpp(353):AddKey] session_id = sid17, key_set_id = <empty>
  06-05 17:35:13.375 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid18
  06-05 17:35:13.375 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid18
  06-05 17:35:13.376 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid18, key_set_id = <empty>, license_type = Offline
  06-05 17:35:13.481 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid19
  06-05 17:35:13.481 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid19
  06-05 17:35:13.482 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid19, playback_id = OqJpprUlvFI7YWWb
  06-05 17:35:13.483 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid19, key_set_id = <empty>, license_type = Streaming
  06-05 17:35:13.509 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:13.509 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid19
  06-05 17:35:13.553 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:13.586 I [cdm_engine.cpp(353):AddKey] session_id = sid18, key_set_id = <empty>
  06-05 17:35:13.625 I [cdm_engine.cpp(421):AddKey] key_set_id = ksidB78129D7
  06-05 17:35:13.626 I [cdm_engine.cpp(232):CloseSession] session_id = sid18
  06-05 17:35:13.876 I [cdm_engine.cpp(232):CloseSession] session_id = sid17
  06-05 17:35:14.337 I [cdm_engine.cpp(353):AddKey] session_id = sid19, key_set_id = <empty>
  06-05 17:35:39.761 I [cdm_engine.cpp(232):CloseSession] session_id = sid19
  06-05 17:35:39.764 E [oemcrypto_adapter_dynamic.cpp(955):Level1Terminate] L1 Terminate
  06-05 17:35:39.764 I [(0):] L3 Terminate.
  06-05 17:36:01.524 I [oemcrypto_adapter_dynamic.cpp(900):Initialize] Level 3 Build Info (v17): OEMCrypto Level3 Code May 20 2022 21:36:54
  06-05 17:36:01.525 I [(0):] Level3 Library 22594 May 20 2022 21:36:54
  06-05 17:36:01.527 I [oemcrypto_adapter_dynamic.cpp(914):Initialize] L3 Initialized. Trying L1.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1137):LoadLevel1] Could not load L1 _oecc113.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1140):LoadLevel1] Could not load L1 _oecc124.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1134):LoadLevel1] Could not load L1 _oecc119.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1131):LoadLevel1] Could not load L1 _oecc116.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1110):LoadLevel1] Could not load L1 _oecc23.
  06-05 17:36:01.608 I [oemcrypto_adapter_dynamic.cpp(943):Initialize] Level 1 Build Info (v17): Build Information: API_Version: 17.0 LibOEMCrypto_Version: 1.63 TA_Version: 1.12
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1145):LoadLevel1] Could not load L1 _oecc129.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1132):LoadLevel1] Could not load L1 _oecc117.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1139):LoadLevel1] Could not load L1 _oecc123.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1138):LoadLevel1] Could not load L1 _oecc114.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1068):LoadLevel1] Could not load L1 _oecc90.
  06-05 17:36:01.609 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 17:36:01.612 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid20
  06-05 17:36:01.612 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid20
  06-05 17:36:01.613 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid20, playback_id = v8AcsXDUlZXd54CD
  06-05 17:36:01.614 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid20, key_set_id = <empty>, license_type = Streaming
  06-05 17:36:01.640 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:36:01.641 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid20
  06-05 17:36:01.679 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:36:01.947 I [cdm_engine.cpp(353):AddKey] session_id = sid20, key_set_id = <empty>
  06-05 17:38:14.449 I [cdm_engine.cpp(232):CloseSession] session_id = sid20
  06-05 17:48:28.436 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 17:48:28.480 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid21
  06-05 17:48:28.480 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid21
  06-05 17:48:28.481 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid21, playback_id = 5x6cqvJgBZQvfF-O
  06-05 17:48:28.482 I [cdm_engine.cpp(445):RestoreKey] session_id = sid21, key_set_id = ksidB78129D7
  06-05 17:48:28.482 E [device_files.cpp(876):RetrieveLicense] Unable to retrieve key set license file: result = NotFound
  06-05 17:48:28.482 E [cdm_session.cpp(236):RestoreOfflineSession] Failed to retrieve license: sub_error_code = NotFound, key_set_id = ksidB78129D7
  06-05 17:48:28.482 E [cdm_engine.cpp(464):RestoreKey] Restore offline session failed: session_id = sid21, status = 347
  06-05 17:48:28.482 W [device_files.cpp(1989):RetrieveHashedFile] File does not exist: path = /data/vendor/mediadrm/IDM1013/L1/ksidB78129D7.lic
  06-05 17:48:28.490 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid21
  06-05 17:48:28.490 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:48:28.571 I [cdm_engine.cpp(232):CloseSession] session_id = sid21
  06-05 17:48:38.938 I [(0):] L3 Terminate.
  06-05 17:48:38.938 E [oemcrypto_adapter_dynamic.cpp(955):Level1Terminate] L1 Terminate
  06-05 19:03:35.378 I No hidl drm factories found
  06-05 19:03:35.379 E Failed to find passthrough drm factories
  06-05 19:03:36.734 I No hidl drm factories found
  06-05 19:03:36.734 E Failed to find passthrough drm factories
  06-05 19:03:36.748 I No hidl drm factories found
  06-05 19:03:36.749 E Failed to find passthrough drm factories
  06-05 19:03:36.771 I [oemcrypto_adapter_dynamic.cpp(900):Initialize] Level 3 Build Info (v17): OEMCrypto Level3 Code May 20 2022 21:36:54
  06-05 19:03:36.771 I [(0):] Level3 Library 22594 May 20 2022 21:36:54
  06-05 19:03:36.779 I [oemcrypto_adapter_dynamic.cpp(914):Initialize] L3 Initialized. Trying L1.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1134):LoadLevel1] Could not load L1 _oecc119.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1138):LoadLevel1] Could not load L1 _oecc114.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1140):LoadLevel1] Could not load L1 _oecc124.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1145):LoadLevel1] Could not load L1 _oecc129.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1068):LoadLevel1] Could not load L1 _oecc90.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1110):LoadLevel1] Could not load L1 _oecc23.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1131):LoadLevel1] Could not load L1 _oecc116.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1132):LoadLevel1] Could not load L1 _oecc117.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1139):LoadLevel1] Could not load L1 _oecc123.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1137):LoadLevel1] Could not load L1 _oecc113.
  06-05 19:03:36.844 I [oemcrypto_adapter_dynamic.cpp(943):Initialize] Level 1 Build Info (v17): Build Information: API_Version: 17.0 LibOEMCrypto_Version: 1.63 TA_Version: 1.12
  06-05 19:03:36.845 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 19:03:36.875 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid22
  06-05 19:03:36.875 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid22
  06-05 19:03:36.877 W [device_files.cpp(1989):RetrieveHashedFile] File does not exist: path = /data/vendor/mediadrm/IDM1013/L1/ksidB78129D7.lic
  06-05 19:03:36.877 E [cdm_engine.cpp(464):RestoreKey] Restore offline session failed: session_id = sid22, status = 347
  06-05 19:03:36.877 E [device_files.cpp(876):RetrieveLicense] Unable to retrieve key set license file: result = NotFound
  06-05 19:03:36.877 E [cdm_session.cpp(236):RestoreOfflineSession] Failed to retrieve license: sub_error_code = NotFound, key_set_id = ksidB78129D7
  06-05 19:03:36.877 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid22, playback_id = HhuYp6Sb4AbuAM3t
  06-05 19:03:36.877 I [cdm_engine.cpp(445):RestoreKey] session_id = sid22, key_set_id = ksidB78129D7
  06-05 19:03:36.881 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 19:03:36.881 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid22
  06-05 19:03:36.952 I [cdm_engine.cpp(232):CloseSession] session_id = sid22
  06-05 19:04:03.055 I No hidl drm factories found
  06-05 19:04:03.056 E Failed to find passthrough drm factories
  06-05 19:04:03.062 E Failed to find passthrough drm factories
  06-05 19:04:03.062 I No hidl drm factories found
  06-05 19:04:03.073 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid23
  06-05 19:04:03.073 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid23
  06-05 19:04:03.074 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid23, playback_id = jBUp0cQ25vTbpd3T
  06-05 19:04:03.074 I [cdm_engine.cpp(445):RestoreKey] session_id = sid23, key_set_id = ksidB78129D7
  06-05 19:04:03.074 W [device_files.cpp(1989):RetrieveHashedFile] File does not exist: path = /data/vendor/mediadrm/IDM1013/L1/ksidB78129D7.lic
  06-05 19:04:03.074 E [device_files.cpp(876):RetrieveLicense] Unable to retrieve key set license file: result = NotFound
  06-05 19:04:03.074 E [cdm_session.cpp(236):RestoreOfflineSession] Failed to retrieve license: sub_error_code = NotFound, key_set_id = ksidB78129D7
  06-05 19:04:03.074 E [cdm_engine.cpp(464):RestoreKey] Restore offline session failed: session_id = sid23, status = 347
============================== End of DRM Plugin Log ==============================
	at com.google.android.exoplayer2.drm.DefaultDrmSession.onError(DefaultDrmSession.java:94)
	at com.google.android.exoplayer2.drm.DefaultDrmSession.doLicense(DefaultDrmSession.java:87)
	at com.google.android.exoplayer2.drm.DefaultDrmSession.acquire(DefaultDrmSession.java:148)
	at com.google.android.exoplayer2.drm.DefaultDrmSessionManager.createAndAcquireSession(DefaultDrmSessionManager.java:54)
	at com.google.android.exoplayer2.drm.DefaultDrmSessionManager.createAndAcquireSessionWithRetry(DefaultDrmSessionManager.java:1)
	at com.google.android.exoplayer2.drm.DefaultDrmSessionManager.acquireSession(DefaultDrmSessionManager.java:35)
	at com.google.android.exoplayer2.drm.DefaultDrmSessionManager$PreacquiredSessionReference$$ExternalSyntheticLambda0.run(R8$$SyntheticClass:24)
	at android.os.Handler.handleCallback(Handler.java:942)
	at android.os.Handler.dispatchMessage(Handler.java:99)
	at android.os.Looper.loopOnce(Looper.java:226)
	at android.os.Looper.loop(Looper.java:313)
	at android.os.HandlerThread.run(HandlerThread.java:67)
Caused by: java.lang.IllegalArgumentException: Failed to restore keys: BAD_VALUE
============================== Beginning of DRM Plugin Log ==============================
  06-05 17:35:02.306 I [oemcrypto_adapter_dynamic.cpp(943):Initialize] Level 1 Build Info (v17): Build Information: API_Version: 17.0 LibOEMCrypto_Version: 1.63 TA_Version: 1.12
  06-05 17:35:02.308 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 17:35:02.311 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid17
  06-05 17:35:02.311 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid17
  06-05 17:35:02.312 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid17, playback_id = eHNgqF5yFHXTlMPq
  06-05 17:35:02.315 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid17, key_set_id = <empty>, license_type = Streaming
  06-05 17:35:02.345 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:02.345 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid17
  06-05 17:35:02.388 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:02.792 I [cdm_engine.cpp(353):AddKey] session_id = sid17, key_set_id = <empty>
  06-05 17:35:13.375 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid18
  06-05 17:35:13.375 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid18
  06-05 17:35:13.376 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid18, key_set_id = <empty>, license_type = Offline
  06-05 17:35:13.481 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid19
  06-05 17:35:13.481 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid19
  06-05 17:35:13.482 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid19, playback_id = OqJpprUlvFI7YWWb
  06-05 17:35:13.483 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid19, key_set_id = <empty>, license_type = Streaming
  06-05 17:35:13.509 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:13.509 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid19
  06-05 17:35:13.553 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:35:13.586 I [cdm_engine.cpp(353):AddKey] session_id = sid18, key_set_id = <empty>
  06-05 17:35:13.625 I [cdm_engine.cpp(421):AddKey] key_set_id = ksidB78129D7
  06-05 17:35:13.626 I [cdm_engine.cpp(232):CloseSession] session_id = sid18
  06-05 17:35:13.876 I [cdm_engine.cpp(232):CloseSession] session_id = sid17
  06-05 17:35:14.337 I [cdm_engine.cpp(353):AddKey] session_id = sid19, key_set_id = <empty>
  06-05 17:35:39.761 I [cdm_engine.cpp(232):CloseSession] session_id = sid19
  06-05 17:35:39.764 E [oemcrypto_adapter_dynamic.cpp(955):Level1Terminate] L1 Terminate
  06-05 17:35:39.764 I [(0):] L3 Terminate.
  06-05 17:36:01.524 I [oemcrypto_adapter_dynamic.cpp(900):Initialize] Level 3 Build Info (v17): OEMCrypto Level3 Code May 20 2022 21:36:54
  06-05 17:36:01.525 I [(0):] Level3 Library 22594 May 20 2022 21:36:54
  06-05 17:36:01.527 I [oemcrypto_adapter_dynamic.cpp(914):Initialize] L3 Initialized. Trying L1.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1137):LoadLevel1] Could not load L1 _oecc113.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1140):LoadLevel1] Could not load L1 _oecc124.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1134):LoadLevel1] Could not load L1 _oecc119.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1131):LoadLevel1] Could not load L1 _oecc116.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1110):LoadLevel1] Could not load L1 _oecc23.
  06-05 17:36:01.608 I [oemcrypto_adapter_dynamic.cpp(943):Initialize] Level 1 Build Info (v17): Build Information: API_Version: 17.0 LibOEMCrypto_Version: 1.63 TA_Version: 1.12
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1145):LoadLevel1] Could not load L1 _oecc129.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1132):LoadLevel1] Could not load L1 _oecc117.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1139):LoadLevel1] Could not load L1 _oecc123.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1138):LoadLevel1] Could not load L1 _oecc114.
  06-05 17:36:01.608 W [oemcrypto_adapter_dynamic.cpp(1068):LoadLevel1] Could not load L1 _oecc90.
  06-05 17:36:01.609 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 17:36:01.612 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid20
  06-05 17:36:01.612 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid20
  06-05 17:36:01.613 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid20, playback_id = v8AcsXDUlZXd54CD
  06-05 17:36:01.614 I [cdm_engine.cpp(274):GenerateKeyRequest] session_id = sid20, key_set_id = <empty>, license_type = Streaming
  06-05 17:36:01.640 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:36:01.641 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid20
  06-05 17:36:01.679 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:36:01.947 I [cdm_engine.cpp(353):AddKey] session_id = sid20, key_set_id = <empty>
  06-05 17:38:14.449 I [cdm_engine.cpp(232):CloseSession] session_id = sid20
  06-05 17:48:28.436 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 17:48:28.480 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid21
  06-05 17:48:28.480 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid21
  06-05 17:48:28.481 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid21, playback_id = 5x6cqvJgBZQvfF-O
  06-05 17:48:28.482 I [cdm_engine.cpp(445):RestoreKey] session_id = sid21, key_set_id = ksidB78129D7
  06-05 17:48:28.482 E [device_files.cpp(876):RetrieveLicense] Unable to retrieve key set license file: result = NotFound
  06-05 17:48:28.482 E [cdm_session.cpp(236):RestoreOfflineSession] Failed to retrieve license: sub_error_code = NotFound, key_set_id = ksidB78129D7
  06-05 17:48:28.482 E [cdm_engine.cpp(464):RestoreKey] Restore offline session failed: session_id = sid21, status = 347
  06-05 17:48:28.482 W [device_files.cpp(1989):RetrieveHashedFile] File does not exist: path = /data/vendor/mediadrm/IDM1013/L1/ksidB78129D7.lic
  06-05 17:48:28.490 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid21
  06-05 17:48:28.490 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 17:48:28.571 I [cdm_engine.cpp(232):CloseSession] session_id = sid21
  06-05 17:48:38.938 I [(0):] L3 Terminate.
  06-05 17:48:38.938 E [oemcrypto_adapter_dynamic.cpp(955):Level1Terminate] L1 Terminate
  06-05 19:03:35.378 I No hidl drm factories found
  06-05 19:03:35.379 E Failed to find passthrough drm factories
  06-05 19:03:36.734 I No hidl drm factories found
  06-05 19:03:36.734 E Failed to find passthrough drm factories
  06-05 19:03:36.748 I No hidl drm factories found
  06-05 19:03:36.749 E Failed to find passthrough drm factories
  06-05 19:03:36.771 I [oemcrypto_adapter_dynamic.cpp(900):Initialize] Level 3 Build Info (v17): OEMCrypto Level3 Code May 20 2022 21:36:54
  06-05 19:03:36.771 I [(0):] Level3 Library 22594 May 20 2022 21:36:54
  06-05 19:03:36.779 I [oemcrypto_adapter_dynamic.cpp(914):Initialize] L3 Initialized. Trying L1.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1134):LoadLevel1] Could not load L1 _oecc119.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1138):LoadLevel1] Could not load L1 _oecc114.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1140):LoadLevel1] Could not load L1 _oecc124.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1145):LoadLevel1] Could not load L1 _oecc129.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1068):LoadLevel1] Could not load L1 _oecc90.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1110):LoadLevel1] Could not load L1 _oecc23.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1131):LoadLevel1] Could not load L1 _oecc116.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1132):LoadLevel1] Could not load L1 _oecc117.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1139):LoadLevel1] Could not load L1 _oecc123.
  06-05 19:03:36.843 W [oemcrypto_adapter_dynamic.cpp(1137):LoadLevel1] Could not load L1 _oecc113.
  06-05 19:03:36.844 I [oemcrypto_adapter_dynamic.cpp(943):Initialize] Level 1 Build Info (v17): Build Information: API_Version: 17.0 LibOEMCrypto_Version: 1.63 TA_Version: 1.12
  06-05 19:03:36.845 I [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 0
  06-05 19:03:36.875 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid22
  06-05 19:03:36.875 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid22
  06-05 19:03:36.877 W [device_files.cpp(1989):RetrieveHashedFile] File does not exist: path = /data/vendor/mediadrm/IDM1013/L1/ksidB78129D7.lic
  06-05 19:03:36.877 E [cdm_engine.cpp(464):RestoreKey] Restore offline session failed: session_id = sid22, status = 347
  06-05 19:03:36.877 E [device_files.cpp(876):RetrieveLicense] Unable to retrieve key set license file: result = NotFound
  06-05 19:03:36.877 E [cdm_session.cpp(236):RestoreOfflineSession] Failed to retrieve license: sub_error_code = NotFound, key_set_id = ksidB78129D7
  06-05 19:03:36.877 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid22, playback_id = HhuYp6Sb4AbuAM3t
  06-05 19:03:36.877 I [cdm_engine.cpp(445):RestoreKey] session_id = sid22, key_set_id = ksidB78129D7
  06-05 19:03:36.881 I [cdm_engine.cpp(994):IsSecurityLevelSupported] level = L1
  06-05 19:03:36.881 I [cdm_engine.cpp(888):QuerySessionStatus] session_id = sid22
  06-05 19:03:36.952 I [cdm_engine.cpp(232):CloseSession] session_id = sid22
  06-05 19:04:03.055 I No hidl drm factories found
  06-05 19:04:03.056 E Failed to find passthrough drm factories
  06-05 19:04:03.062 E Failed to find passthrough drm factories
  06-05 19:04:03.062 I No hidl drm factories found
  06-05 19:04:03.073 I [cdm_engine.cpp(187):OpenSession] New session: session_id = sid23
  06-05 19:04:03.073 I [cdm_engine.cpp(983):QueryOemCryptoSessionId] session_id = sid23
  06-05 19:04:03.074 I [cdm_engine.cpp(2141):SetPlaybackId] session_id = sid23, playback_id = jBUp0cQ25vTbpd3T
  06-05 19:04:03.074 I [cdm_engine.cpp(445):RestoreKey] session_id = sid23, key_set_id = ksidB78129D7
  06-05 19:04:03.074 W [device_files.cpp(1989):RetrieveHashedFile] File does not exist: path = /data/vendor/mediadrm/IDM1013/L1/ksidB78129D7.lic
  06-05 19:04:03.074 E [device_files.cpp(876):RetrieveLicense] Unable to retrieve key set license file: result = NotFound
  06-05 19:04:03.074 E [cdm_session.cpp(236):RestoreOfflineSession] Failed to retrieve license: sub_error_code = NotFound, key_set_id = ksidB78129D7
  06-05 19:04:03.074 E [cdm_engine.cpp(464):RestoreKey] Restore offline session failed: session_id = sid23, status = 347
============================== End of DRM Plugin Log ==============================

About this issue

  • Original URL
  • State: open
  • Created a year ago
  • Reactions: 2
  • Comments: 22

Commits related to this issue

Most upvoted comments

We have identified the issue and are working on making the patch available to OEM partners. They will need to pick up the patch and include it in an upcoming update. We also let Samsung know about this and see if we can update this tracker with information about availability of an update.

@rrfrias I sent a new batch of resources and observations via email.

In the Google Drive link from the email you’ll find:

  • The source code for a sample app that is prepared to reproduce the issue (I did not share it here as it contains credentials to access a test account on our api)
  • Videos:
    • Video 1 - Shows the app on Android 13 (where the issue is reproduced).
    • Video 2 - Observations from video 1 and log analysis: You can see that some native c++ logic deletes all the downloaded licenses up until the point when the function is triggered. In my case, I expected to have 231 downloaded licenses at the end of the test, but I only got 30, that’s because, as you can see in the logs, the first 201 licenses were automatically removed. I don’t know what triggers this, and why it doesn’t happen on Android 11 or below, but this is the root cause of my issue - i.e. Failed to restore keys: BAD_VALUE error when attempting to play content and the license file is not found.
    • Video 3 - Shows the same test as Video 1, but this time running on Android 11 - here you can see that licenses are not removed, which is the behavior I expect on all Android versions.
  • Adb bugreport for the test that ran in video 1

The exact logs that leave a clue to what’s happening - found in the bugreport log file:

08-21 22:56:04.189 media   385   385 D WVCdm   : [crypto_session.cpp(860):Open] Opening crypto session: requested_security_level = Default
08-21 22:56:04.189 media   385   385 D WVCdm   : [usage_table_header.cpp(162):Init] security_level = L3
08-21 22:56:04.189 media   385   385 D WVCdm   : [usage_table_header.cpp(504):DetermineTableCapacity] capacity = unlimited, security_level = L3
08-21 22:56:04.189 media   385   385 I WVCdm   : [usage_table_header.cpp(203):RestoreTable] Found usage table to restore: entry_count = 201
08-21 22:56:04.191 media   385   385 D WVCdm   : [crypto_session.cpp(860):Open] Opening crypto session: requested_security_level = L3
08-21 22:56:04.191 media   385   385 D WVCdm   : [usage_table_header.cpp(258):AddEntry] key_set_id = DummyKsid, type = OfflineLicense, current_size = 201
08-21 22:56:04.191 media   385   385 I WVCdm   : [usage_table_header.cpp(533):CreateEntry] usage_entry_number = 201
08-21 22:56:04.195 media   385   385 D WVCdm   : [usage_table_header.cpp(358):InvalidateEntry] usage_entry_number = 201
08-21 22:56:04.195 media   385   385 D WVCdm   : [usage_table_header.cpp(990):DefragTable] Removing all entries after the last valid entry: count = 1
08-21 22:56:04.195 media   385   385 D WVCdm   : [usage_table_header.cpp(876):Shrink] table_size = 202, number_to_delete = 1
08-21 22:56:04.195 media   385   385 D WVCdm   : [usage_table_header.cpp(393):InvalidateEntryInternal] Table was not stored during defrag, storing now
08-21 22:56:04.197 media   385   385 E WVCdm   : [usage_table_header.cpp(488):CapacityCheck] Failed to shrink table for capacity test
08-21 22:56:04.197 media   385   385 E WVCdm   : [usage_table_header.cpp(221):RestoreTable] Cannot restore table due to failing capacity check
08-21 22:56:04.197 media   385   385 D WVCdm   : [usage_table_header.cpp(229):CreateNewTable] Removing all usage table files

It’s easier to see what’s happening in real time if you gain root access to the emulator and then navigate to the directory where licenses are saved:

adb root
adb shell
cd /data/vendor/mediadrm/IDM1013/L3

You can use this command to query how many licenses are saved (assuming you are in the L3 directory):

ls -1 ksid* | wc -l

If you want to check the I/O activity in real time, use this command - this monitors operations on files that contain “ksid” in the name:

inotifyd - . | grep ksid

If you want to save the output and analyze it later, use this:

inotifyd - . | grep ksid > /sdcard/inotifyd_1.txt 2>&1

Then press the download button, wait for it to finish and then exit the process. Get the inotifyd_1.txt and check when files are deleted (unexpectedly). Here is the table from the help menu that maps letters to I/O operations: Screenshot 2023-08-19 at 09 43 57

In video 1 at 2:27, exactly when the logs in the phone show Chapter 201, watch the top terminal from the background, it is filled with d (Delete) operations for all licenses.

Reproduced with Android Emulator (Pixel XL arm64-v8a API 33 on Mac M1 Pro host) - full build numbers shown in the videos.

According to error reports from users, the Failed to restore keys: BAD_VALUE error happens only on Android 12 and up, so this is congruent with the test results from above:

Screenshot 2023-08-21 at 21 39 28

Do you know why this is happening?

Do you know if Samsung made any progress on adopting this fix in their OS updates.

I forgot to answer this part of the question. Samsung is working on integrating fixes. It might be in android 14 updates for some of these devices. We will check with them after they have completed integration, for dates for when users should expect to see updates.