Hls.js requesting the same AES-128 decryption key twice for audio tracks

[foliovision]

What version of Hls.js are you using?

v1.0.3

What browser and OS (including versions) are you using?

macOS 10.14.6 with Safari 13.1.1 and Chrome 90.0.4430.212

Test stream:

https://foliovision.com/hls/master.m3u8

Configuration:

Checklist

• The issue observed is not already reported by searching on Github under https://github.com/video-dev/hls.js/issues
• The issue occurs in the stable client on https://hls-js.netlify.com/demo and not just on my page
• The issue occurs in the latest client on https://hls-js-dev.netlify.com/demo and not just on my page
• The stream has correct Access-Control-Allow-Origin headers (CORS)
• There are no network errors such as 404s in the browser console when trying to play the stream

Steps to reproduce

1. Play the https://foliovision.com/hls/master.m3u8 stream directly in Safari or on iPhone with developer tools attached and notice key.bin is only requested once:

That's because the HLS is supported natively.

2. Play the https://foliovision.com/hls/master.m3u8 stream on https://hls-js-dev.netlify.app/demo/ and notice it loads key.bin twice, even though it's the same file:

Expected behavior

Since https://foliovision.com/hls/key.bin was loaded once for the stream, I would expect the second load to not happen.

Otherwise the HLS.js behavior is different from what you get in devices with native HLS support where HLS.js cannot be used - like the iPhones.

Actual behavior

The https://foliovision.com/hls/key.bin file is loaded twice, lowering the security of the encrypted stream.

We limit the access to the AES-128 decryption key and because of this flaw we have to treat iPhone users differently from other browsers which can use HLS.js.

In Hls.js 0.11.0 it used to only request to decryption key once.

Console output

main.js:338 Using Hls.js config: {debug: true, enableWorker: true, lowLatencyMode: true, backBufferLength: 90}
logger.ts:74 [log] >
hls.ts:363 [log] > stopLoad
hls.ts:331 [log] > loadSource:https://foliovision.com/hls/master.m3u8
stream-controller.ts:552 [log] > [stream-controller]: Trigger BUFFER_RESET
hls.ts:302 [log] > attachMedia
buffer-controller.ts:742 [log] > [buffer-controller]: Media source opened
base-stream-controller.ts:1310 [log] > [subtitle-stream-controller]: STOPPED->IDLE
level-controller.ts:171 [log] > [level-controller]: manifest loaded, 1 level(s) found, first bitrate: 1468268
buffer-controller.ts:136 [log] > 2 bufferCodec event(s) expected
hls.ts:353 [log] > startLoad(-1)
level-controller.ts:250 [log] > [level-controller]: switching to level 0 from -1
audio-track-controller.ts:134 [log] > [audio-track-controller]: Updating audio tracks, 1 track(s) found in "audio_aac" group-id
audio-track-controller.ts:185 [log] > [audio-track-controller]: Now switching to audio-track index 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: STOPPED->IDLE
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->WAITING_TRACK
level-controller.ts:523 [log] > [level-controller]: Attempt loading level index 0 with URL-id 0 https://foliovision.com/hls/media-1/stream.m3u8
base-stream-controller.ts:1310 [log] > [stream-controller]: STOPPED->IDLE
audio-track-controller.ts:258 [log] > [audio-track-controller]: loading audio-track playlist for id: 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: WAITING_TRACK->STOPPED
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: STOPPED->WAITING_TRACK
base-stream-controller.ts:1310 [log] > [subtitle-stream-controller]: IDLE->STOPPED
base-stream-controller.ts:1310 [log] > [subtitle-stream-controller]: STOPPED->IDLE
stream-controller.ts:616 [log] > [stream-controller]: Level 0 loaded [0,3], cc [0, 0] duration:29.519999999999996
buffer-controller.ts:635 [log] > [buffer-controller]: Updating Media Source duration to 29.520
base-stream-controller.ts:281 [log] > [stream-controller]: Loading key for 0 of [0-3], level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->KEY_LOADING
audio-track-controller.ts:87 [log] > [audio-track-controller]: audioTrack 0 loaded [0-4]
audio-stream-controller.ts:437 [log] > [audio-stream-controller]: Track 0 loaded [0,4],duration:29.546667
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: WAITING_TRACK->IDLE
base-stream-controller.ts:281 [log] > [audio-stream-controller]: Loading key for 0 of [0-4], track 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [stream-controller]: Loading fragment 0 cc: 0 of [0-3] level: 0, target: 0
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [audio-stream-controller]: Loading fragment 0 cc: 0 of [0-4] track: 0, target: 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
transmuxer-interface.ts:66 [log] > demuxing in webworker
audio-stream-controller.ts:541 [log] > Unknown video PTS for cc 0, waiting for video PTS before demuxing audio frag 0 of [0 ,4],track 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: FRAG_LOADING->WAITING_INIT_PTS
base-stream-controller.ts:341 [log] > [audio-stream-controller]: Loaded fragment 0 of level 0
bbfa2fe6-a738-4519-9e56-586eda49b72e:603 [log] >
transmuxer-interface.ts:66 [log] > demuxing in webworker
transmuxer-interface.ts:180 [log] > [transmuxer-interface, main]: Starting new transmux session for sn: 0 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: true
        timeOffset: 0
base-stream-controller.ts:341 [log] > [stream-controller]: Loaded fragment 0 of level 0
b954bd21-eca0-4561-9281-118c691083be:603 [log] >
b954bd21-eca0-4561-9281-118c691083be:6786 [log] > [decrypter.ts]: JS AES decrypt
b954bd21-eca0-4561-9281-118c691083be:2692 [log] > [mp4-remuxer]: ISGenerated flag reset
b954bd21-eca0-4561-9281-118c691083be:2681 [log] > [mp4-remuxer]: initPTS & initDTS reset
b954bd21-eca0-4561-9281-118c691083be:935 [log] > [transmuxer.ts]: Flushed fragment 0 of level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: FRAG_LOADING->PARSING
stream-controller.ts:1233 [log] > [stream-controller]: Init video buffer, container:video/mp4, codecs[level/parsed]=[avc1.4D401F/avc1.4d401f]
audio-stream-controller.ts:113 [log] > [audio-stream-controller]: InitPTS for cc: 0 found from main: 10000
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: WAITING_INIT_PTS->FRAG_LOADING
transmuxer-interface.ts:180 [log] > [transmuxer-interface, audio]: Starting new transmux session for sn: 0 p: -1 level: 0 id: 1
        discontinuity: true
        trackSwitch: true
        contiguous: false
        accurateTimeOffset: false
        timeOffset: 0
bbfa2fe6-a738-4519-9e56-586eda49b72e:6786 [log] > [decrypter.ts]: JS AES decrypt
base-stream-controller.ts:1310 [log] > [stream-controller]: PARSING->PARSED
bbfa2fe6-a738-4519-9e56-586eda49b72e:7925 [log] > ADTS sync word found !
bbfa2fe6-a738-4519-9e56-586eda49b72e:2692 [log] > [mp4-remuxer]: ISGenerated flag reset
bbfa2fe6-a738-4519-9e56-586eda49b72e:2681 [log] > [mp4-remuxer]: initPTS & initDTS reset
bbfa2fe6-a738-4519-9e56-586eda49b72e:7560 [log] > manifest codec:mp4a.40.2, ADTS type:2, samplingIndex:3
bbfa2fe6-a738-4519-9e56-586eda49b72e:7722 [log] > parsed codec:mp4a.40.5, rate:48000, channels:6
bbfa2fe6-a738-4519-9e56-586eda49b72e:935 [log] > [transmuxer.ts]: Flushed fragment 0 of level 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
audio-stream-controller.ts:821 [log] > [audio-stream-controller]: Switching audio track : flushing all audio
audio-stream-controller.ts:769 [log] > [audio-stream-controller]: Init audio buffer, container:audio/mp4, codecs[parsed]=[mp4a.40.5]
buffer-controller.ts:704 [log] > [buffer-controller]: creating sourceBuffer(video/mp4;codecs=avc1.4D401F)
buffer-controller.ts:704 [log] > [buffer-controller]: creating sourceBuffer(audio/mp4;codecs=mp4a.40.5)
stream-controller.ts:822 [log] > [stream-controller]: Alternate track found, use video.buffered to schedule main fragment loading
buffer-controller.ts:816 [log] > [buffer-controller]: Removing [0,29.519999999999996] from the audio SourceBuffer
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:481 [log] > [audio-stream-controller]: Buffered audio sn: 0 of track 0 [0.017,5.905]
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [audio-stream-controller]: Loading key for 1 of [0-4], track 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [audio-stream-controller]: Loading fragment 1 cc: 0 of [0-4] track: 0, target: 5.905
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:481 [log] > [stream-controller]: Buffered main sn: 0 of level 0 [0.000,8.400]
base-stream-controller.ts:1310 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [stream-controller]: Loading key for 1 of [0-3], level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [stream-controller]: Loading fragment 1 cc: 0 of [0-3] level: 0, target: 8.4
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->FRAG_LOADING
gap-controller.ts:241 [warn] > skipping hole, adjusting currentTime from 0 to 0.1
_trySkipBufferHole @ gap-controller.ts:241
poll @ gap-controller.ts:130
checkBuffer @ stream-controller.ts:930
onTickEnd @ stream-controller.ts:201
doTick @ stream-controller.ts:196
tick @ task-loop.ts:110
setInterval (async)
setInterval @ task-loop.ts:72
startLoad @ stream-controller.ts:117
(anonymous) @ hls.ts:355
startLoad @ hls.ts:354
onManifestLoaded @ level-controller.ts:195
emit @ index.js:203
emit @ hls.ts:242
trigger @ hls.ts:250
handleMasterPlaylist @ playlist-loader.ts:445
loadsuccess @ playlist-loader.ts:342
readystatechange @ xhr-loader.ts:190
XMLHttpRequest.send (async)
loadInternal @ xhr-loader.ts:127
load @ xhr-loader.ts:72
load @ playlist-loader.ts:304
onManifestLoading @ playlist-loader.ts:149
emit @ index.js:203
emit @ hls.ts:242
trigger @ hls.ts:250
loadSource @ hls.ts:342
loadSelectedStream @ main.js:371
(anonymous) @ main.js:142
dispatch @ jquery.min.js:3
r.handle @ jquery.min.js:3
base-stream-controller.ts:195 [log] > [stream-controller]: media seeking to 0.100, state: FRAG_LOADING
base-stream-controller.ts:195 [log] > [audio-stream-controller]: media seeking to 0.100, state: FRAG_LOADING
base-stream-controller.ts:195 [log] > [subtitle-stream-controller]: media seeking to 0.100, state: IDLE
stream-controller.ts:543 [log] > [stream-controller]: Media seeked to 0.105
base-stream-controller.ts:341 [log] > [audio-stream-controller]: Loaded fragment 1 of level 0
base-stream-controller.ts:341 [log] > [stream-controller]: Loaded fragment 1 of level 0
bbfa2fe6-a738-4519-9e56-586eda49b72e:935 [log] > [transmuxer.ts]: Flushed fragment 1 of level 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:481 [log] > [audio-stream-controller]: Buffered audio sn: 1 of track 0 [0.017,11.921]
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [audio-stream-controller]: Loading key for 2 of [0-4], track 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [audio-stream-controller]: Loading fragment 2 cc: 0 of [0-4] track: 0, target: 11.921
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
b954bd21-eca0-4561-9281-118c691083be:935 [log] > [transmuxer.ts]: Flushed fragment 1 of level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:1310 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:481 [log] > [stream-controller]: Buffered main sn: 1 of level 0 [0.000,16.080]
base-stream-controller.ts:1310 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [stream-controller]: Loading key for 2 of [0-3], level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [stream-controller]: Loading fragment 2 cc: 0 of [0-3] level: 0, target: 16.08
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:341 [log] > [audio-stream-controller]: Loaded fragment 2 of level 0
bbfa2fe6-a738-4519-9e56-586eda49b72e:935 [log] > [transmuxer.ts]: Flushed fragment 2 of level 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:481 [log] > [audio-stream-controller]: Buffered audio sn: 2 of track 0 [0.017,17.937]
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [audio-stream-controller]: Loading key for 3 of [0-4], track 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [audio-stream-controller]: Loading fragment 3 cc: 0 of [0-4] track: 0, target: 17.937
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:341 [log] > [stream-controller]: Loaded fragment 2 of level 0
b954bd21-eca0-4561-9281-118c691083be:935 [log] > [transmuxer.ts]: Flushed fragment 2 of level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:1310 [log] > [stream-controller]: PARSING->PARSED
base-stream-controller.ts:481 [log] > [stream-controller]: Buffered main sn: 2 of level 0 [0.000,23.600]
base-stream-controller.ts:1310 [log] > [stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [stream-controller]: Loading key for 3 of [0-3], level 0
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [stream-controller]: Loading fragment 3 cc: 0 of [0-3] level: 0, target: 23.6
base-stream-controller.ts:1310 [log] > [stream-controller]: IDLE->FRAG_LOADING
base-stream-controller.ts:341 [log] > [audio-stream-controller]: Loaded fragment 3 of level 0
bbfa2fe6-a738-4519-9e56-586eda49b72e:935 [log] > [transmuxer.ts]: Flushed fragment 3 of level 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: FRAG_LOADING->PARSING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSING->PARSED
base-stream-controller.ts:481 [log] > [audio-stream-controller]: Buffered audio sn: 3 of track 0 [0.017,23.953]
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: PARSED->IDLE
base-stream-controller.ts:281 [log] > [audio-stream-controller]: Loading key for 4 of [0-4], track 0
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->KEY_LOADING
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: KEY_LOADING->IDLE
base-stream-controller.ts:570 [log] > [audio-stream-controller]: Loading fragment 4 cc: 0 of [0-4] track: 0, target: 23.953
base-stream-controller.ts:1310 [log] > [audio-stream-controller]: IDLE->FRAG_LOADING

[robwalch]

The audio-stream-controller and stream-controller are responsible for loading keys and segments in their respective playlists. They don't share any information about what has been loaded or has the same URL across files so keys in each playlist with the same URL are loaded once per playlist.

[foliovision]

Hello robwatch,

my point is that this should be mimicking the iOS and Safari behavior as that might be the most wildly used HLS player our there - not counting HLS.js.

Please let us know if you plan to work on this improvement or if it might take a while.

Thanks,
Martin

[robwalch]

Hi @foliovision,

this should be mimicking the iOS and Safari behavior

Agreed.

Please let us know if you plan to work on this improvement

I have no plans to work on this. I have provided information on why a key listed in two playlists is loaded twice.

If this issue is important to you, and you use HLS.js, consider making a contribution to open-source.

[robwalch]

Fixed by #4861 scheduled for v1.3.0.

[foliovision]

Hello @robwalch

I compiled HLS.js from the master branch where your fix was already merged.

I tested it and I see no difference in the way our HLS streams load - it's the same with HLS.js 1.2.3 and the current master branch:

So it seems your improvement did not change anything in our case.

Also, this issue is about the difference of how Safari plays the HLS natively (one request for decryption key) and how HLS.js plays it (once request for video and one for audio). Unfortunately that was not improved either.