Potential bug when writing to `opus_slot` in `mix_symph_indiv` for Opus Passthrough. about songbird HOT 10 CLOSED

I just did some testing using different pieces of music to see if whether that would have any impact (i.e different sizes for each 20ms frame, unnatural spikes in packet size that could be causing this, etc.), and did not find any. I tried a few songs, and they all were around 250 bytes in size for 20ms, and the error was happening very consistently after the same amount of time for all the songs.

from songbird.

I think I can guarantee we always have more than 250B; the packet buffer slots are all at least 1KiB. Can you insert a print or breakpoint here and find out what the slice lengths actually are believed to be?

from songbird.

We (should) have 1460B per call per packet total. You have a bit less once you've paid for RTP headers + encryption tag storage, but this is all less than ~24B.

from songbird.

I think I can guarantee we always have more than 250B; the packet buffer slots are all at least 1KiB. Can you insert a print or breakpoint here and find out what the slice lengths actually are believed to be?

As in the slot length? I can do that. I'll get back with that info in a bit

We (should) have 1460B per call per packet total. You have a bit less once you've paid for RTP headers + encryption tag storage, but this is all less than ~24B.

This makes far more sense. Perhaps the vec is not being reserved with_capacity or with something that reserves that memory? Seems unlikely, but I have not found where it sets the slot size in code so can't comment on that.

from songbird.

I think I can guarantee we always have more than 250B; the packet buffer slots are all at least 1KiB. Can you insert a print or breakpoint here and find out what the slice lengths actually are believed to be?

As in the slot length? I can do that. I'll get back with that info in a bit

I think ideally we want to see both the slot length and what songbird believes the length of your packet is. :)

from songbird.

Frame size info... 248
Actual data... 248
SLOT LEN: 1432, BUF LEN: 14089
thread '<unnamed>' panicked at C:\Users\prana.LAPTOP-MODAKBGP\.cargo\registry\src\index.crates.io-6f17d22bba15001f\songbird-0.4.1\src\driver\tasks\mixer\mix_logic.rs:88:30: Bounds check performed, and failure will block passthrough.: Error { kind: WriteZero, message: "failed to write whole buffer" }

Alright, it is not the slot. I added a print statement and recompiled songbird, and it is definitely the buffer. For whatever reason, the buffer is huge in size here. The "Frame size info ..." here refers to the first 2 bytes in a DCA frame that describe the size to expect. So on my Read implementation, it has detected 248. The "Actual data ..." is the length of the data returned to symphonia, again detected 248. It's bizarre that the buf has such a massive length here... I'll look into this and update.

from songbird.

Okay, I found something interesting. The problem is not with Songbird, as the error above shows. It might be with symphonia... It seems that Symphonia's Read implementation for MediaSourceStream does not fully read the buffer. For a buffer size of 248, there is one iteration where it only reads 182. This leaves 66 in the buffer, which it tries to reuse for the subsequent few reads, which eventually causes an error and thread panic.

The error above happens if I do NOT restart the bot but try again by starting another track and playing the music. Potentially similar to the first panic, perhaps due to reuse of the half-consumed buffer, the unused buffers start piling up internally till it finally takes the new buffer's entire collected data together? I am unsure if songbird is the cause here, so I'll leave this issue open. I'll keep this thread updated with anything I find.

from songbird.

Ok, finally managed to trip the system stepping through the debugger. Here is what I found:

1. There is a bug in the opus passthrough in songbird. buf_size_fatal is not set and used properly:
   

   songbird/src/driver/tasks/mixer/mix_logic.rs

   Lines 80 to 85 in 8f60cf5

   	let buf_size_fatal = buf.len() <= slot.len();
   	if match sample_ct {
   	Ok(MONO_FRAME_SIZE) => true,
   	_ => !local_state.record_and_check_passthrough_strike_final(buf_size_fatal),
   	} {

   
   As you can see, buf_size_fatal is true only when the buffer is less than or equal in size to the slot. This should be reversed, it should be fatal if the buffer size is greater than or equal to the slot size. This is sent into record_and_check_passthrough_strike_final (heck of a name lol).
   

   songbird/src/driver/tasks/mixer/state.rs

   Lines 70 to 77 in 8f60cf5

   	pub fn record_and_check_passthrough_strike_final(&mut self, fatal: bool) -> bool {
   	self.passthrough_violations = self.passthrough_violations.saturating_add(1);
   	let blocked = fatal || self.passthrough_violations > OPUS_PASSTHROUGH_STRIKE_LIMIT;
   	if blocked {
   	self.passthrough = Passthrough::Block;
   	}
   	blocked
   	}

   
   Here, passthrough is blocked if fatal is true or if the packet has accrued too many strikes. Notice it expects fatal to be true if passthrough needs to be blocked, and buf_size fatal is false if passthrough needs to be blocked.

2. Symphonia reads opus frames only partially if it reaches the end of its internal ringbuffer. Its ringbuffer has a max size of 65535 (u16 max), after which it wraps around and starts reusing from index 0. The point I made in the comment above, about Symphonia not reading the full 248 byte buffer is because it was discarding anything that went over it's ringbuffer limit. This throws the entire thing out of sync as the code thinks this frame has been fully read and moves on to process the next DCA frame length. It takes these 2 bytes, however, from the previously half read frame. This number can be anything, there is no guarantee, and is returned to songbird as the frame length passed in by my read implementation. This corrupted (?) size is used by the DCA format reader to request the next frame, and the size is usually far too large to fit in a packet.

I think using mp4 or PCM or any other format that does not require frame times to be reported like DCA, symphonia's system would work just fine. Songbird probably do this for most of its other supported formats, and this ringbuffer only needs to handle decoded PCM, that is then encoded using audiopus, hence why this issue has not been brought up (I couldn't find one in issues yet, at least.)

On a side note something in here could perhaps explain why I was experiencing consistent stuttering in #223.

from songbird.

As you can see, buf_size_fatal is true only when the buffer is less than or equal in size to the slot. This should be reversed, it should be fatal if the buffer size is greater than or equal to the slot size. This is sent into record_and_check_passthrough_strike_final (heck of a name lol).

Good catch, thanks!

2. Symphonia reads opus frames only partially if it reaches the end of its internal ringbuffer.

Symphonia is allowed to do this, and you need to be able to handle straddled reads -- practically speaking, an impl Read should even be able to handle a caller who decides to read your contents in 1-byte chunks. It looks to me like you're not quite doing that and are assuming you get a sufficiently large buffer:

https://github.com/Pranav-Badrinathan/minstrel-bot/blob/98574a93b76d502c1c10094850d100e2d174da7c/src/bot.rs#L200-L202

You need to actually add size to the current position, and only remove the current frame once you know it has been fully read. The sketch code in #223 includes this.

    // else
    //   fill buf from current_frame
    //   update pos, chunk_pos
    //   unset current_frame if done (chunk_pos == current_frame.len() + 2) <----- Here

Subsequent reads then use (chunk_pos - 2) as an index to know where to resume reading.

from songbird.

You need to actually add size to the current position, and only remove the current frame once you know it has been fully read. The sketch code in #223 includes this.

This was what I was attempting to figure out after I realized what I needed to do, didn't quite get it yesterday. Thanks for the guidance. I'll close this issue now that any actual bugs/problems have been fixed. Thanks!

from songbird.