Issue with HLS Stream Parser (AUD-566)

[spbkaizo]

Hi,

There is an issue within the HLS stream parser - under certain conditions.

In the UK, the BBC HLS streams endpoint contains a playlist like this:

Contents of: http://a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/uk/sbr_high/ak/bbc_6music.m3u8

...

EXTM3U

EXT-X-VERSION:3

EXT-X-STREAM-INF:PROGRAM-ID=1,BANDWIDTH=339200,CODECS="mp4a.40.2"

http://as-hls-uk-live.akamaized.net/pool_904/live/uk/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8` ...

This follow on URL contains the actual references to the AAC streams:

Contents of http://as-hls-uk-live.akamaized.net/pool_904/live/uk/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8

... bbc_6music-audio=320000-244033939.ts

EXTINF:6.4, no desc

bbc_6music-audio=320000-244033940.ts

EXTINF:6.4, no desc

bbc_6music-audio=320000-244033941.ts

EXTINF:6.4, no desc

bbc_6music-audio=320000-244033942.ts

EXTINF:6.4, no desc

bbc_6music-audio=320000-244033943.ts ... The issue is, when it has followed those the parser then loops around, and tries to get the next URI content to add t the playlist.

However, it appears to loop back around to the first file, which already exists in the playlist. At this point it gets stuck, e.g. using the living stream example this happens:

W (32317) HTTP_STREAM: No more data,errno:0, total_bytes:268088 I (32318) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0 I (32318) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1 I (32428) HTTP_STREAM: total_bytes=268088 W (38715) HTTP_STREAM: No more data,errno:0, total_bytes:268088 I (38716) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0 I (38716) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1 I (38723) 6MUSIC_PLAYER: jhdfjh I (38826) HTTP_STREAM: total_bytes=212 I (38975) HTTP_STREAM: total_bytes=569 W (38976) HTTP_STREAM: No more data,errno:0, total_bytes:569 I (38991) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0 I (38992) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1 I (38992) 6MUSIC_PLAYER: jhdfjh I (39038) HTTP_STREAM: total_bytes=212 W (39039) HTTP_STREAM: URI exist I (39039) 6MUSIC_PLAYER: jhdfjh I (39078) HTTP_STREAM: total_bytes=212 W (39080) HTTP_STREAM: URI exist I (39080) 6MUSIC_PLAYER: jhdfjh I (39106) HTTP_STREAM: total_bytes=212 W (39107) HTTP_STREAM: URI exist I (39108) 6MUSIC_PLAYER: jhdfjh I (39147) HTTP_STREAM: total_bytes=212 W (39148) HTTP_STREAM: URI exist I (39148) 6MUSIC_PLAYER: jhdfjh sync_byte errorE (39170) AAC_READER: ts decoding meet with error I (39186) HTTP_STREAM: total_bytes=212 W (39187) HTTP_STREAM: URI exist I (39187) 6MUSIC_PLAYER: jhdfjh I (39212) HTTP_STREAM: total_bytes=212

Issue lies around here in http_stream.c (when it tries to free the track, leaving it with no entries I suspect)

    track_t *find = NULL;
    STAILQ_FOREACH(find, &playlist->tracks, next) {
        if (strcmp(find->uri, track->uri) == 0) {
            ESP_LOGW(TAG, "URI exist");
            free(track->uri);
            free(track);
            return;
        }
    }

[vikramdattu]

Hi,

Are you trying with master branch?

In your application, please use code like below to create http_stream and let us know the results.

    http_stream_cfg_t http_cfg = HTTP_STREAM_CFG_DEFAULT();
    http_cfg.enable_playlist_parser = true;
    http_cfg.auto_connect_next_track = true;
    http_stream_reader = http_stream_init(&http_cfg);

Please notice this line: http_cfg.auto_connect_next_track = true;

I have tried multi-level m3u8 URIs from other sources and those work fine. I am not able to try with your URL as http://as-hls-uk-live.akamaized.net/pool_904/live/uk/bbc_6music/bbc_6music.isml/bbc_6music-audio%3d320000.norewind.m3u8 returns 403 for me.

Thanks

[colinmcardell]

Hopefully to keep this conversation going, I'm having some issues with the BBC HLS streams as well.

I'm currently using the example HTTP streaming project pipeline_living_stream on the master branch of esp-adf with the latest stable of esp-idf.

Because I'm outside of the UK, I'm using this HLS url: http://a.files.bbci.co.uk/media/live/manifesto/audio/simulcast/hls/nonuk/sbr_low/llnw/bbc_radio_one.m3u8

Below you will find two example project configurations including the resulting logs.

Configuration 1:

Vanilla pipeline_living_stream example project pointing to the above BBC HLS url.

Notes:

Playback works for a duration that I'm assuming is equal to the provided segments within the manifest. The logs then seem to indicate properly requested additional sections of data (see W (11841), W (18242), W (24641), W (31042), W (37442) in the logs below) and continues to play without any artifacts. Then it gets a small section of data (W (38283)), and ultimately begins rapidly receiving very small amounts of data and warns HTTP_STREAM: URI exist (I (38435) onward). Playback stops after a period of clicking distortion being output via the I2S stream.

Configuration 1 Log:

I (7252) I2S_STREAM: AUDIO_STREAM_WRITER
I (7257) AUDIO_PIPELINE: Pipeline started
I (7319) HTTP_STREAM: total_bytes=226
I (7398) HTTP_STREAM: total_bytes=0
I (7660) HTTP_STREAM: total_bytes=579
I (7718) HTTP_STREAM: total_bytes=0
I (7789) HTTP_STREAM: total_bytes=81592
I (7791) AAC_DECODER: new aduio song
I (7792) AAC_DECODER: this audio is TS AAC
I (7829) AAC_DECODER: I2S setup: sample_rate = 24000 : channels = 2
I (7830) AAC_DECODER: M4A sampleRate = 24000, Channels = 2, frameSize = 1024
I (8245) HTTP_LIVINGSTREAM_EXAMPLE: [ * ] Receive music info from aac decoder, sample_rates=24000, bits=16, ch=2
I (8545) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_PAUSE
I (8548) I2S: APLL: Req RATE: 24000, real rate: 23999.980, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 6143995.000, SCLK: 767999.375000, diva: 1, divb: 0
I (8553) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:3
I (8559) I2S_STREAM: AUDIO_STREAM_WRITER
W (11841) HTTP_STREAM: No more data,errno:0, total_bytes:81592
I (11842) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (11842) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
I (11933) HTTP_STREAM: total_bytes=0
I (12069) HTTP_STREAM: total_bytes=81592
W (18242) HTTP_STREAM: No more data,errno:0, total_bytes:81592
I (18243) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (18244) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
I (18334) HTTP_STREAM: total_bytes=0
I (18430) HTTP_STREAM: total_bytes=81592
W (24641) HTTP_STREAM: No more data,errno:0, total_bytes:81592
I (24642) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (24643) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
I (24734) HTTP_STREAM: total_bytes=0
I (24868) HTTP_STREAM: total_bytes=81592
W (31042) HTTP_STREAM: No more data,errno:0, total_bytes:81592
I (31043) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (31043) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
I (31134) HTTP_STREAM: total_bytes=0
I (31230) HTTP_STREAM: total_bytes=81592
W (37442) HTTP_STREAM: No more data,errno:0, total_bytes:81592
I (37443) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (37443) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
I (37561) HTTP_STREAM: total_bytes=226
I (37661) HTTP_STREAM: total_bytes=0
I (38282) HTTP_STREAM: total_bytes=579
W (38283) HTTP_STREAM: No more data,errno:0, total_bytes:579
I (38283) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (38287) AUDIO_ELEMENT: [http] AEL_MSG_CMD_RESUME,state:1
I (38435) HTTP_STREAM: total_bytes=226
W (38436) HTTP_STREAM: URI exist
I (38473) HTTP_STREAM: total_bytes=226
W (38474) HTTP_STREAM: URI exist
I (38523) HTTP_STREAM: total_bytes=226
W (38524) HTTP_STREAM: URI exist
I (38576) HTTP_STREAM: total_bytes=226
W (38577) HTTP_STREAM: URI exist
I (38611) HTTP_STREAM: total_bytes=226
W (38612) HTTP_STREAM: URI exist
I (38656) HTTP_STREAM: total_bytes=226
W (38658) HTTP_STREAM: URI exist
I (38694) HTTP_STREAM: total_bytes=226
W (38695) HTTP_STREAM: URI exist
I (38739) HTTP_STREAM: total_bytes=226
W (38740) HTTP_STREAM: URI exist
I (38772) HTTP_STREAM: total_bytes=226
W (38773) HTTP_STREAM: URI exist
I (38821) HTTP_STREAM: total_bytes=226
W (38822) HTTP_STREAM: URI exist
I (38859) HTTP_STREAM: total_bytes=226
W (38861) HTTP_STREAM: URI exist
I (38901) HTTP_STREAM: total_bytes=226
W (38903) HTTP_STREAM: URI exist
I (38947) HTTP_STREAM: total_bytes=226
W (38948) HTTP_STREAM: URI exist
I (38986) HTTP_STREAM: total_bytes=226
W (38987) HTTP_STREAM: URI exist
sync_byte errorE (39032) AAC_READER: ts decoding meet with error
I (39036) HTTP_STREAM: total_bytes=226
W (39037) HTTP_STREAM: URI exist
I (39074) HTTP_STREAM: total_bytes=226
W (39075) HTTP_STREAM: URI exist
I (39111) HTTP_STREAM: total_bytes=226
W (39112) HTTP_STREAM: URI exist
I (39160) HTTP_STREAM: total_bytes=226
W (39161) HTTP_STREAM: URI exist
I (39178) AAC_DECODER: aac playing done
I (39178) AAC_DECODER: Closed
I (39197) HTTP_STREAM: total_bytes=226
W (39198) HTTP_STREAM: URI exist
I (39228) HTTP_STREAM: total_bytes=226
W (39229) HTTP_STREAM: URI exist
I (39253) HTTP_STREAM: total_bytes=226
W (39254) HTTP_STREAM: URI exist
I (39285) HTTP_STREAM: total_bytes=226
W (39286) HTTP_STREAM: URI exist
I (39290) AUDIO_ELEMENT: IN-[i2s] AEL_IO_DONE,-2
I (39318) HTTP_STREAM: total_bytes=226
W (39319) HTTP_STREAM: URI exist
I (39348) HTTP_STREAM: total_bytes=226
W (39349) HTTP_STREAM: URI exist
I (39378) HTTP_STREAM: total_bytes=226
W (39379) HTTP_STREAM: URI exist
I (39406) HTTP_STREAM: total_bytes=226
W (39407) HTTP_STREAM: URI exist...
...

Configuration 2:

Modified pipeline_living_stream example project pointing to the above BBC HLS url. Attempting the suggestion provided by @vikramdattu to use auto_connection_next_track within the http_cfg:

    http_cfg.enable_playlist_parser = true;
    http_cfg.auto_connect_next_track = true;

Notes:

Playback works similarly to configuration 1. Playback ends after a period of time... the logs below indicate that the initial request is the same size of 81592, then the HTTP stream warns with "No more data" at 407960 (see W (33014) in the logs below). This value seems to be the same amount of properly received data as the logs indicate above in configuration 1 (81592 * 5). The difference in this configuration is that the warning with HTTP_STREAM: URI exist is not present, instead the playback ends with logs indicating aac playing done. The expected behavior should be that the live stream continues playing.

Configuration 2 Log:

I (2741) I2S_STREAM: AUDIO_STREAM_WRITER
I (2745) AUDIO_PIPELINE: Pipeline started
I (2832) HTTP_STREAM: total_bytes=226
I (2906) HTTP_STREAM: total_bytes=0
I (3172) HTTP_STREAM: total_bytes=579
I (3219) HTTP_STREAM: total_bytes=0
I (3285) HTTP_STREAM: total_bytes=81592
I (3288) AAC_DECODER: new aduio song
I (3289) AAC_DECODER: this audio is TS AAC
I (3325) AAC_DECODER: I2S setup: sample_rate = 24000 : channels = 2
I (3326) AAC_DECODER: M4A sampleRate = 24000, Channels = 2, frameSize = 1024
I (3919) HTTP_LIVINGSTREAM_EXAMPLE: [ * ] Receive music info from aac decoder, sample_rates=24000, bits=16, ch=2
I (3942) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_PAUSE
I (3945) I2S: APLL: Req RATE: 24000, real rate: 23999.980, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 6143995.000, SCLK: 767999.375000, diva: 1, divb: 0
I (3950) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:3
I (3956) I2S_STREAM: AUDIO_STREAM_WRITER
W (33014) HTTP_STREAM: No more data,errno:0, total_bytes:407960
I (33015) AUDIO_ELEMENT: IN-[http] AEL_IO_DONE,0
I (34601) AUDIO_ELEMENT: IN-[aac] AEL_IO_DONE,-2
I (34749) AAC_DECODER: aac playing done
I (34750) AAC_DECODER: Closed
I (34861) AUDIO_ELEMENT: IN-[i2s] AEL_IO_DONE,-2

[spbkaizo]

In a pinch, you can use the embedded URL to move you forward: http://as-hls-ww-live.bbcfmt.hs.llnwd.net/pool_904/live/ww/bbc_radio_one/bbc_radio_one.isml/bbc_radio_one-audio%3d96000.norewind.m3u8

[spbkaizo]

Should others wish to repeat the issue, choose an existing stream from somewhere, and use ffmpeg to convert that stream into a HLS stream, in a directory exposed by a webserver. Connect an ESP32 to the URI exposed by the webserver.

For example: ffmpeg -i http://SOMESOURCE/SOMEFILE.MP3 \ -codec copy -hls_time 5 -hls_list_size 12 \ -hls_flags delete_segments \ -hls_flags program_date_time \ -hls_delete_threshold 20 \ -hls_wrap 20 \ -hls_start_number_source epoch \ -f hls /SOME/WWWSERVER/DIRECTORY/index.m3u8

[spbkaizo]

The following appears to work - but I'd be curious to see if it works for others, or indeed - breaks something which was working,

simonb@tich MINGW32 ~/esp/esp-adf/components/audio_stream
$ git diff http_stream.c
diff --git a/components/audio_stream/http_stream.c b/components/audio_stream/http_stream.c
index 4af0187..a52eefe 100644
--- a/components/audio_stream/http_stream.c
+++ b/components/audio_stream/http_stream.c
@@ -286,10 +286,8 @@ static void _insert_to_playlist(playlist_t *playlist, char *track_uri, const cha
     track_t *find = NULL;
     STAILQ_FOREACH(find, &playlist->tracks, next) {
         if (strcmp(find->uri, track->uri) == 0) {
-            ESP_LOGW(TAG, "URI exist");
-            free(track->uri);
-            free(track);
-            return;
+            ESP_LOGW(TAG, "URI %s already exists, resetting is_played to false", track->uri);
+           track->is_played = false;
         }
     }

[vikramdattu]

@spbkaizo @colinmcardell this is now fixed on adf tip.

[baofdodo]

Dear @colinmcardell , Now in 2021 I still get the issues. How do you fix that?