Degraded audio transcoder performance when decoding 5.1 channel

[naanlizard]

Describe the bug Tonight I noticed llHLS playback was very choppy and buffery, with frequent errors. Upon checking the logs I found quite a lot of errors

Server.xml

Logs newerror.zip

zipped, for convenience. I can get more logs if needed, but it seemed repetitive after only an hour even. Note that if you scroll or ctrl F for "partial" you will see 404s and such

• OvenMediaEngine Version: 0.15.10

[getroot]

Can you share your encoder information and settings? This seems to be a problem with the audio input.

[naanlizard]

Unfortunately I can't share the encoder settings - this was with ~40 streams live, all with their own encoder settings that I'm not privy to. If you tell me which stream is the problem, I can ask for their settings though

[getroot]

I'll do more analysis and let you know if I need any info. Thank you

[naanlizard]

newerrorbig.txt.gz

Here is 20 hours of log file

I believe it's stream 27357 causing the problems, they start on line 650925

Here are their OBS settings

https://obsproject.com/logs/azCwzQmQzZruVJQb

[getroot]

Thank you! It seems to help a lot.

[naanlizard]

I believe it's the channels: 5.1 setting they're using, maybe in combination with a missing device or the device lagging in the obs log

21:05:25.538: Source Voicemeter audio is lagging (over by 284483.25 ms) at max audio buffering. Restarting source audio.

We tested with the stream off, no log errors. Then when they started, errors started up again, and then when they changed from 5.1 to stereo the errors stopped

[naanlizard]

A slightly off topic question, is it normal to see a lot of very rapid lines like this in the log?

[2023-05-17 04:13:16.711] I [SPLLHLS-t799:22] Monitor | stream_metrics.cpp:163  | 1 sessions has been stopped playing #default#live/30852 on the LLHLS publisher. Concurrent Viewers[LLHLS(0)/Stream total(0)/App total(82)]
[2023-05-17 04:13:16.791] I [StreamWorker:447] Monitor | stream_metrics.cpp:114  | A new session has started playing #default#live/11120 on the LLHLS publisher. LLHLS(2)/Stream total(10)/App total(83)
[2023-05-17 04:13:16.792] I [SPLLHLS-t799:22] Monitor | stream_metrics.cpp:163  | 1 sessions has been stopped playing #default#live/11120 on the LLHLS publisher. Concurrent Viewers[LLHLS(1)/Stream total(9)/App total(82)]
[2023-05-17 04:13:16.810] I [SPLLHLS-t799:22] Monitor | stream_metrics.cpp:163  | 1 sessions has been stopped playing #default#live/56907 on the LLHLS publisher. Concurrent Viewers[LLHLS(0)/Stream total(2)/App total(81)]

We don't have that many viewers popping in constantly like that, it seems more like maybe viewers on LLHLS triggering that line every time they request a segment

[getroot]

@naanlizard There are two possibilities.

[1] HLS players with HTTP/1.1 usually connect and disconnect 4 TCP connections repeatedly. We've added a bunch of logic to make sure access stats are calculated correctly in most possible situations, but it may not be perfect. Because HLS players constantly open and close connections, it is actually almost impossible to find exact concurrent users.

Since HLS players with HTTP/2 use one connection, it is relatively easy to determine whether the player is connected, but they use only one connection even when playing multiple streams on one PC, so it is difficult to determine the exact number of plays.

[2] It may be the case that the player cannot play and an error occurs and continuously initializes/reconnects.

[naanlizard]

EDIT: The rapid reconnects seem to have stopped now, so apologies it was probably just a result of this bug. The logs are much slower now :) Sorry for the tangent

EDIT 2: Nevermind it's back, no idea, but it's not urgent so don't worry about it

[getroot]

thank you Now that I've finished an important task, I'll start looking at your problems.

[Keukhan]

@naanlizard

The audio layout supported by OME had the constraint of supporting only mono/stereo. This patch allows the input stream to support various audio channel layouts. You can test on the master branch, and we will release it as soon as possible.

https://github.com/AirenSoft/OvenMediaEngine/commit/e8545c4b8548e04cbd586a29d1742428631c049b

Thanks 👍

[naanlizard]

Still seeing

[2023-05-23 02:40:32.609] E [Resampler:1385] FFmpeg | third_parties.cpp:111  | [AVFilter: 0x7f48df1c70c0] Changing audio frame properties on the fly is not supported.
[2023-05-23 02:40:32.609] E [Resampler:1385] Transcoder | filter_resampler.cpp:209  | An error occurred while feeding the audio filtergraph: pts: -9223372036854775808, linesize: 0, srate: 0, layout: 0, channels: 0, format: -1, rq: 0
[2023-05-23 02:40:32.629] I [Resampler:1385] FFmpeg | third_parties.cpp:119  | [AVFilter: 0x7f48df1c70c0] filter context - fmt: fltp r: 48000 layout: 3 ch: 2, incoming frame - fmt: fltp r: 48000 layout: 3F ch: 6 pts_time: 6.848

in the logs after updating OME (in our dockerfile, FROM airensoft/ovenmediaengine@sha256:85dd79a47adcd018c2f74e3c6a868b0737fb4de470adb2b27b0f07e82903b8dd)

[Keukhan]

This patch has not yet been released. Are you using the master branch built with Docker? Could you please share the full log of that stream?

[naanlizard]

There was a dev image that I assumed had the patch, that's what the Sha hash is. You can cross reference it with docker hub to see exactly what I'm running, or just run it yourself. The only thing I changed in my OBS settings was to make it 5.1 audio

[getroot]

@naanlizard As of now, I tested with the most recent dev image, and in my tests, the OBS 5.1 channel was working without problems.

Unfortunately, since we are using Docker Hub for free, we cannot find the checksum history of dev tagged images, only the most recent overwritten checksum. So I can't tell when the image was created with the checksum information. But I'm sure you're using our patch included since you probably downloaded it after @Keukhan commented.

Does the problem reproduce if you do a 5.1 channel broadcast from OBS to OME? Or is that log output from one of your customer's streams?

[getroot]

@naanlizard Do you have any updated information? Is the issue still reproducing?

[naanlizard]

I will test again, but I don't see why it wouldn't still happen.

Has there been a new version released? That would make things easier to test

[getroot]

@naanlizard No new version has been released yet. I'll comment again after the new version is released. The 5.1 channel of OBS has been resolved, but I think that maybe another case could cause a problem. We're looking for such a case, but it's difficult. We'd appreciate it if you could help out in that case after a new version is released.

[naanlizard]

The only settings I had changed before were to set my obs audio to 5.1, but once we update to a new version I'll test again and provide OBS logs and server logs

[naanlizard]

Updating to 0.15.12 seems to have fixed it. I'm unsure why I didn't have the fix in the previous update I did to a specific docker sha256, but I wasn't getting crashes which means at least I got some of the patches.

Anyway, this can be closed, thank you for the hard work and apologies about the confusion wrt docker image versions.