Stieneee / mumble-discord-bridge

A simple voice bridge between Mumble and Discord.
MIT License
149 stars 16 forks source link

4008: Rate limited #20

Closed namtsui closed 3 years ago

namtsui commented 3 years ago

If I hold down the push to talk key on mumble for 20 seconds I will get rate limited by discord and the bridge disconnects. I also get rate limited and booted off if I speak in bursts normally. I also noticed that the discord bot blinks repeatedly on discord.

Possibly related: https://github.com/bwmarrin/discordgo/issues/830 https://github.com/bwmarrin/discordgo/issues/829

umurmur hosting mumble on openbsd bridge running on openbsd

2021/04/06 06:18:48 Discord Bot Connected
2021/04/06 06:18:48 Discord bot looking for command !mumble-discord
2021/04/06 06:18:48 bridge starting in constant mode
2021/04/06 06:18:48 Attempting to join Discord voice channel
2021/04/06 06:18:48 CREATE event registered
2021/04/06 06:18:49 Discord Voice Connected
2021/04/06 06:18:49 Attempting to join Mumble
2021/04/06 06:18:49 Mumble Connected
2021/04/06 06:19:51 new mumble audio stream namtsui2
2021/04/06 06:20:05 User joined Discord namtsui
2021/04/06 06:21:18 [DG0] voice.go:378:wsListen() voice endpoint us-west2242.discord.media:443 websocket closed unexpectantly, websocket: close 4008: Rate limited.
2021/04/06 06:21:18 [DG0] voice.go:199:Close() error closing websocket, websocket: close sent
2021/04/06 06:21:18 dgVoice: Discordgo not ready for opus packets. false : 0xc00012c240
2021/04/06 06:21:19 [DG0] voice.go:107:Speaking() Speaking() write json error, websocket: close sent
2021/04/06 06:21:31 [DG1] wsapi.go:648:ChannelVoiceJoin() error waiting for voice to connect, timeout waiting for voice
Discordgo ready to send opus packets
Stieneee commented 3 years ago

Interesting, there could be a concurrency issue between discordSendPCM and fromMumbleMixer functions. My theory is that there is some thrashing between Discord speaking states (true and false) which could trigger the rate limiter.

If you are willing to do some debugging I pushed a separate branch with some debug messages added. If I'm right we would see a high cycle rate in the log. Here is some output from my local dev.

issue-20

image

You can see that there are few instances in which the timing is not quite right and the speaking state "flickers".

If this doesn't yield any insight on the weekend I can try replicating your env.

namtsui commented 3 years ago

That sounds like a good theory. With your debug branch there is a lot of activity when I say, "Can you hear me?" No wonder it sounds choppy.

2021/04/08 15:11:49 User joined Discord namtsui
2021/04/08 15:11:59 new mumble audio stream namtsui2
2021/04/08 15:11:59 Debug: Discord start speaking
2021/04/08 15:11:59 Debug: Discord stop speaking 38 ms
2021/04/08 15:11:59 Debug: Discord start speaking
2021/04/08 15:11:59 Debug: Discord stop speaking 0 ms
2021/04/08 15:11:59 Debug: Discord start speaking
2021/04/08 15:11:59 Debug: Discord stop speaking 86 ms
2021/04/08 15:11:59 Debug: Discord start speaking
2021/04/08 15:11:59 Debug: Discord stop speaking 42 ms
2021/04/08 15:11:59 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 43 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 85 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 46 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 42 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 29 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 35 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 45 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 46 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 47 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 41 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 42 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:00 Debug: Discord stop speaking 42 ms
2021/04/08 15:12:00 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 59 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 19 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 19 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 58 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 55 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 19 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 57 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 57 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 56 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 57 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 1 ms
2021/04/08 15:12:01 Debug: Discord start speaking
2021/04/08 15:12:01 Debug: Discord stop speaking 39 ms
Stieneee commented 3 years ago

@namtsui I have pushed another commit to the issue-20 branch which implements configurable buffer size. While I can't quite reproduce your issue the buffer eliminated any extra Discord speaking state transitions. A 50 ms buffer seemed to be more than enough for my dev setup. I would suggest trying a larger buffer size if you see the speaking state cycling even though mumble transmission is contious.

In addition, I added frames of silence on state transitions recommend by the Discord documentation. This should increase the quality of the interpolation if everything is working fine but if the timing issue occurs my best guess is that these frames will stack up in the buffer and reduce the cycling.

Give it a try and let me know what you think. If things are not quite right on your end I could try introducing some fake packet timing issue on my dev env to see if I can get something similar to what you saw.

A reference for me could you describe the hardware you are running the bridge on? uMurmur? The network connection between them?

namtsui commented 3 years ago

-to-discord-buffer 50: flickers frequently " 100: flickers occasionally so it cuts off once in a while when continuously pressing " 250: similar to 100

it seems like I can't hold down for 10 seconds and speak. In the 250 output, you can see me trying to speak for 10 seconds but it gets broken up.

delay 50:

2021/04/10 18:08:44 Debug: Discord start speaking                               
2021/04/10 18:08:44 Debug: Discord stop speaking 169 ms                         
2021/04/10 18:08:44 Debug: Discord start speaking                               
2021/04/10 18:08:45 Debug: Discord stop speaking 359 ms                         
2021/04/10 18:08:45 Debug: Discord start speaking                               
2021/04/10 18:08:45 Debug: Discord stop speaking 159 ms                         
2021/04/10 18:08:45 Debug: Discord start speaking                               
2021/04/10 18:08:45 Debug: Discord stop speaking 364 ms                         
2021/04/10 18:08:45 Debug: Discord start speaking                               
2021/04/10 18:08:46 Debug: Discord stop speaking 349 ms                         
2021/04/10 18:08:46 Debug: Discord start speaking                               
2021/04/10 18:08:46 Debug: Discord stop speaking 139 ms                         
2021/04/10 18:08:46 Debug: Discord start speaking                               
2021/04/10 18:08:46 Debug: Discord stop speaking 245 ms                         
2021/04/10 18:08:46 Debug: Discord start speaking                               
2021/04/10 18:08:47 Debug: Discord stop speaking 209 ms                         
2021/04/10 18:08:47 Debug: Discord start speaking                               
2021/04/10 18:08:47 Debug: Discord stop speaking 139 ms                         
2021/04/10 18:08:47 Debug: Discord start speaking                               
2021/04/10 18:08:47 Debug: Discord stop speaking 99 ms                          
2021/04/10 18:08:47 Debug: Discord start speaking                               
2021/04/10 18:08:47 Debug: Discord stop speaking 120 ms                         
2021/04/10 18:08:48 Debug: Discord start speaking                               
2021/04/10 18:08:48 Debug: Discord stop speaking 139 ms
2021/04/10 18:08:48 Debug: Discord start speaking
2021/04/10 18:08:48 Debug: Discord stop speaking 120 ms
2021/04/10 18:08:48 Debug: Discord start speaking
2021/04/10 18:08:48 Debug: Discord stop speaking 119 ms
2021/04/10 18:08:48 Debug: Discord start speaking
2021/04/10 18:08:48 Debug: Discord stop speaking 119 ms
2021/04/10 18:08:50 Debug: Discord start speaking
2021/04/10 18:08:50 Debug: Discord stop speaking 198 ms
2021/04/10 18:08:51 Debug: Discord start speaking
2021/04/10 18:08:51 Debug: Discord stop speaking 279 ms
2021/04/10 18:08:51 Debug: Discord start speaking
2021/04/10 18:08:51 Debug: Discord stop speaking 189 ms
2021/04/10 18:08:51 Debug: Discord start speaking
2021/04/10 18:08:52 Debug: Discord stop speaking 359 ms
2021/04/10 18:08:52 Debug: Discord start speaking
2021/04/10 18:08:52 Debug: Discord stop speaking 219 ms
2021/04/10 18:08:52 Debug: Discord start speaking
2021/04/10 18:08:52 Debug: Discord stop speaking 129 ms
2021/04/10 18:08:52 Debug: Discord start speaking
2021/04/10 18:08:52 Debug: Discord stop speaking 119 ms
2021/04/10 18:08:53 Debug: Discord start speaking
2021/04/10 18:08:53 Debug: Discord stop speaking 119 ms
2021/04/10 18:08:53 Debug: Discord start speaking
2021/04/10 18:08:53 Debug: Discord stop speaking 79 ms
2021/04/10 18:08:53 Warning: Short Mumble to Discord speaking cycle. Consider in
creaseing the size of the TO_DISCORD_BUFFER
2021/04/10 18:08:54 Debug: Discord start speaking
2021/04/10 18:08:54 Debug: Discord stop speaking 181 ms
2021/04/10 18:08:54 Debug: Discord start speaking
2021/04/10 18:08:54 Debug: Discord stop speaking 139 ms

delay 100

2021/04/10 18:07:01 Debug: Discord start speaking
2021/04/10 18:07:03 Debug: Discord stop speaking 1679 ms
2021/04/10 18:07:05 Debug: Discord start speaking
2021/04/10 18:07:07 Debug: Discord stop speaking 2399 ms
2021/04/10 18:07:07 Debug: Discord start speaking
2021/04/10 18:07:10 Debug: Discord stop speaking 2539 ms
2021/04/10 18:07:10 Debug: Discord start speaking
2021/04/10 18:07:10 Debug: Discord stop speaking 199 ms
2021/04/10 18:07:14 Debug: Discord start speaking
2021/04/10 18:07:18 Debug: Discord stop speaking 4059 ms
2021/04/10 18:07:18 Debug: Discord start speaking
2021/04/10 18:07:21 Debug: Discord stop speaking 2728 ms
2021/04/10 18:07:21 Debug: Discord start speaking
2021/04/10 18:07:23 Debug: Discord stop speaking 1859 ms
2021/04/10 18:07:23 Debug: Discord start speaking
2021/04/10 18:07:23 Debug: Discord stop speaking 199 ms
2021/04/10 18:07:27 Debug: Discord start speaking
2021/04/10 18:07:31 Debug: Discord stop speaking 3598 ms
2021/04/10 18:07:31 Debug: Discord start speaking
2021/04/10 18:07:31 Debug: Discord stop speaking 514 ms
2021/04/10 18:07:31 Debug: Discord start speaking
2021/04/10 18:07:32 Debug: Discord stop speaking 119 ms

delay 200

2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Discord start speaking     
2021/04/10 18:18:36 Debug: Warning Discord buffer size 
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size
2021/04/10 18:18:36 Debug: Warning Discord buffer size 
2021/04/10 18:18:37 Debug: Discord stop speaking 799 ms
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size 
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Discord start speaking
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:37 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Discord stop speaking 951 ms
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Discord start speaking
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:38 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Discord stop speaking 550 ms
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:39 Debug: Warning Discord buffer size
2021/04/10 18:18:40 Debug: Discord start speaking
2021/04/10 18:18:40 Debug: Warning Discord buffer size
2021/04/10 18:18:40 Debug: Warning Discord buffer size
2021/04/10 18:18:40 Debug: Warning Discord buffer size
2021/04/10 18:18:40 Debug: Warning Discord buffer size
2021/04/10 18:18:40 Debug: Discord stop speaking 499 ms
namtsui commented 3 years ago

bridge is running on a vultr.com vps with 512 MB and 1 core. I actually am using murmur instead of umurmur because I don't want to reboot the vps and I couldn't figure out how to relaunch umurmur.

I have 70 ms from my mumble client (linux) in california to the bridge/mumble server (openbsd) in florida.

One thing I haven't tested is bridge + mumble server on my LAN. Let me try that.

If that is still choppy, it seems like it is likely either a firewall issue or an OS issue. OpenBSD does use 100 ticks timing for the kernel so that may affect things.

namtsui commented 3 years ago

I initially tested mumble (linux) and bridge/umurmur (openbsd) on my LAN. It experienced the same issue as the vps with choppiness no matter what the buffer is.

If that is still choppy, it seems like it is likely either a firewall issue or an OS issue. OpenBSD does use 100 ticks timing for the kernel so that may affect things.

Using 100 ticks is the problem. When I compile a 1000 tick kernel for openbsd, it works! It is smooth, and I can hold down the microphone for 10 seconds even with the default buffer of 50ms. Perhaps this can give you ideas about some timing issues in the program?

2021/04/10 19:01:21 Debug: Discord start speaking
2021/04/10 19:01:28 Debug: Discord stop speaking 7119 ms
2021/04/10 19:01:30 Debug: Discord start speaking
2021/04/10 19:01:39 Debug: Discord stop speaking 9320 ms
2021/04/10 19:01:43 Debug: Discord start speaking
2021/04/10 19:01:46 Debug: Discord stop speaking 2318 ms
Stieneee commented 3 years ago

Awesome glad to see it's working.

The audio passed through series of goroutines that handle steps like mixing and encoding. There is variability in the length of encoded data which complicates the matter. I use the least common denominator of 10 ms of audio to pass around internally. When sending to Discord I need to stack up two internal messages into 20ms of audio before encoding and passing it to the discordgo library. The timing issues are twofold. Internally we tick at the audio rates so it's possible to mix and send data at an appropriate rate if packets do not arrive in time it can result in poor audio quality especially when mixing. Buffers tend to help with this. Second, the scheduling and the evaluation of sleeping goroutines play an important role in how latency and jitter of the audio passing through the bridge. At the moment I'm counting on the internal scheduler to be sufficiently fast to ensure each step evaluates at approximately the right time.

I put together a little image that shows the flow of audio.

https://github.com/Stieneee/mumble-discord-bridge/blob/issue-20/docs/audio-flow.drawio.png

I know the bridge is far from perfect. While putting this diagram together I had several ideas on ways to improve the flow.

I am not familiar with OpenBSD and the tick rate you mentioned. Any idea on how that kernel setting would affect the networking stack? How long processes can sleep? Go process scheduling goroutines?

namtsui commented 3 years ago

here is a good article regarding how to enable 1000 Hz clocks. https://openbsd.amsterdam/clock.html

I've come across this problem before in some games where the 100 Hz clock affected the framerate. Since it is 100 ticks / second, that's a resolution of 10 ms. You won't be able to get 1 ms resolution, so that might explain the bad performance.

I do not know golang but I looked up maybe you can tell me if my interpretation of your code is correct.

https://github.com/Stieneee/mumble-discord-bridge/blob/a18df282133d2ce7432ae84fa79eda2bfbb34b08/discord.go#L72

This line reads from the ticker's channel and blocks. Once the next tick (initialized to 10 ms) is available it dequeues the time from the channel and doesn't make use of it. So the purpose is to kind of slow down the infinite for loop while allowing for channels to communicate (as opposed to sleeping)? So this is a common go idiom?

https://golang.org/pkg/time/#NewTicker

The ticker will adjust the time interval or drop ticks to make up for slow receivers

There's nothing receiving this right? In any case, normally on linux systems, say, you might be able to get a tick at 13 ms, but on openbsd it would round up to 20 ms, resulting in poor performance. (Linux is tickless though apparently.)

namtsui commented 3 years ago

There's no guarantee on the tickers, too, as it seems like it is a minimum. So if you since you set it to 10 ms, but it happens at 13 ms, we get punished because we must wait until the next openbsd tick at 20 ms.

Stieneee commented 3 years ago

@namtsui I built a ticker that will minimize drift. I noticed an individual that had a long mic on time that was causing the buffer to fill up on my test server. The new ticker is designed not to drift even if the system is busy for several ticks. It's a little less efficient but I did a pprof side-by-side and I'm not concerned with the additional overhead.

I'm curious to see what running "go test" produces on your hardware. As a reference, I took a screenshot of the result on my dev machine.

image

namtsui commented 3 years ago

default (100 tick) openbsd kernel:

Ticker after 1m40s drifts 1m39.995885097s
TickerCT after 1m40s drifts 2m12.1868959s
PASS
ok      github.com/namtsui/mumble-discord-bridge        432.195s

custom (1000 tick) openbsd kernel:

Ticker after 1m40s drifts 5.911163995s
TickerCT after 1m40s drifts 1.041635ms
PASS
ok      github.com/namtsui/mumble-discord-bridge        205.919s
Stieneee commented 3 years ago

That first result :confused:

Gald to see the new ticker improvement is replicated.

I set up OpenBSD in a VM tonight and got a similar result. (I have not tried the BIOS tweak) I ran into issues building in OpenBSD which ultimately resolved by editing line 5 of https://github.com/layeh/gopus/blob/master/opus_nonshared.go to include OpenBSD. How have you been building and running tests?

I'm thinking that would trough the ticker out and just put the goroutine to sleep using the math I implemented in the ticker. That would reduce the need to spawn goroutines and block using channels. Will try it tomorrow night.

namtsui commented 3 years ago

I ended up just building it as a user (go test) and not using the ports system. Dependencies are automatically pulled into ~/go.

At first I used a golang port generator for openbsd, which tries to automatically create a golang port.

see: https://www.namtsui.com/cgi-bin/cvsweb/ports/audio/mumble-discord-bridge/

However, I have to manually patch /usr/obj/pobj/mumble-discord-bridge-0.3.1/go/pkg/mod/layeh.com/gopus@v0.0.0-20161224163843-0ebf989153aa/opus_nonshared.go as you have found. I haven't yet figured out how to patch a dependency like gopus in the port.

doas -u _pbuild chmod 644 opus_nonshared.go
doas -u _pbuild vi opus_nonshared.go
add openbsd to the -lm line
fix permissions 444 --> 644 for this file

Then when I run make test from the port directory, it only prints the last line of OK. It doesn't print the ticker drift output. If I run in the ${WRKSRC} directory as the _pbuild user, make test complains about not having internet access because _pbuild usually does not have net access. (_pfetch fetches packages and _pbuild builds the port without net access.)

Stieneee commented 3 years ago

Ok, so I tested it by replacing the ticker with a sleep implementation. Here are some new results.

Linux image

OpenBSD in VM image

Some conclusions:

It might be best at this time to simply suggest that the users tweak their kernel to a faster clock.

To close this issue off maybe we update the README for any future OpenBSD adventurers and bring in some of these updates implemented. Any other thoughts? ideas? suggestions? Any code you would like to contribute back?

namtsui commented 3 years ago

Something like this could be added: "OpenBSD users should consider compiling a custom kernel to use 1000 ticks for the best possible performance."

If I submit it as an OpenBSD port in the future I can also note this in either the package MESSAGE (printed when installing a package) or README.

I don't really have any other input. It is nice to hear that setting out to solve one problem uncovered another more serious problem.

namtsui commented 3 years ago

I guess I didn't fully test it. mumble --> discord works. However, I never thought to test the converse until now. discord --> mumble throws errors and nothing is audible. Similar to: https://github.com/Stieneee/mumble-discord-bridge/issues/4#issuecomment-753750647

2021/05/03 01:08:06 dgVoice: Error decoding opus data: buffer is too small
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: buffer is too small
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: buffer is too small
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 Opus size error
2021/05/03 01:08:06 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 Opus size error
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 Opus size error
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: buffer is too small
2021/05/03 01:08:07 Opus size error
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 Opus size error
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: buffer is too small
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
2021/05/03 01:08:07 dgVoice: Error decoding opus data: invalid packet
namtsui commented 3 years ago

it also eventually segfaults. Here is a backtrace without debugging enabled. Maybe gopus or gumble related.

dust2$ egdb ./mm3 ./mm3.core   
GNU gdb (GDB) 7.12.1
Copyright (C) 2017 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-unknown-openbsd6.9".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./mm3...done.
[New process 167492]
[New process 573832]
[New process 502482]
[New process 564131]
[New process 523643]
[New process 236662]
Core was generated by `mm3'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000000000064b195 in runtime.(*sigctxt).preparePanic (c=0xc00042da50, 
    sig=<optimized out>, gp=0xc00016b500)
    at /usr/local/go/src/runtime/signal_amd64.go:66
66              sp := uintptr(c.rsp())
[Current thread is 1 (process 167492)]
warning: File "/usr/local/go/src/runtime/runtime-gdb.py" auto-loading has been declined by your `auto-load safe-path' set to "/usr/local/share/gdb/auto-load".
To enable execution of this file add
        add-auto-load-safe-path /usr/local/go/src/runtime/runtime-gdb.py
line to your configuration file "/home/mumble/.gdbinit".
To completely disable this security protection add
        set auto-load safe-path /
line to your configuration file "/home/mumble/.gdbinit".
For more information about this security protection see the
"Auto-loading safe path" section in the GDB manual.  E.g., run from the shell:
        info "(gdb)Auto-loading safe path"
(gdb) bt
#0  0x000000000064b195 in runtime.(*sigctxt).preparePanic (c=0xc00042da50, 
    sig=<optimized out>, gp=0xc00016b500)
    at /usr/local/go/src/runtime/signal_amd64.go:66
#1  0x000000000064c694 in runtime.sighandler (sig=11, info=0xc00042dc30, 
    ctxt=0xc00042db40, gp=0xc00016b500)
    at /usr/local/go/src/runtime/signal_unix.go:589
#2  0x000000000064bb25 in runtime.sigtrampgo (sig=11, info=0xc00042dc30, 
    ctx=0xc00042db40) at /usr/local/go/src/runtime/signal_unix.go:459
#3  0x000000000066dd9f in runtime.sigtramp ()
    at /usr/local/go/src/runtime/sys_openbsd_amd64.s:90
#4  <signal handler called>
#5  0x0000000000ab3830 in opus_encode (st=0xc000194000, pcm=0xc0002bfc00, 
    analysis_frame_size=477, data=0xc00027c6f0 "", max_data_bytes=40)
    at /home/mumble/go/pkg/mod/layeh.com/gopus@v0.0.0-20161224163843-0ebf989153aa/opus-1.1.2/src/opus_encoder.c:2040
#6  0x0000000000abbe0a in _cgo_1ac4a83e58b0_Cfunc_opus_encode (v=0xc00054dd78)
    at cgo-gcc-prolog:229
#7  0x000000000066c2d0 in runtime.asmcgocall ()
    at /usr/local/go/src/runtime/asm_amd64.s:667
#8  0x00000002edb57810 in ?? ()
#9  0x000000000063f05d in runtime.park_m (gp=0xc00012c000)
    at /usr/local/go/src/runtime/proc.go:3274
#10 0x000000000066a7fb in runtime.mcall ()
    at /usr/local/go/src/runtime/asm_amd64.s:327
#11 0x23b55015e121a0ba in ?? ()
#12 0x0000000000080000 in ?? ()
#13 0x00000002edb578a0 in ?? ()
#14 0x0000000000abeb8c in crosscall_amd64 ()
#15 0x000000000063aa60 in ?? () at /usr/local/go/src/runtime/stubs.go:12
#16 0x000000c00016b500 in ?? ()
---Type <return> to continue, or q <return> to quit---
#17 0x0000000221654a28 in ?? ()
#18 0x0000000000abea90 in _cgo_sys_thread_start (ts=<optimized out>)
    at gcc_openbsd_amd64.c:51
#19 0x0000000000a24b48 in layeh.com/gopus._Cfunc_opus_encode (
    p0=<optimized out>, p1=0xc0002bfc00, p2=477, p3=0xc00027c6f0 "", p4=40, 
    r1=0) at _cgo_gotypes.go:389
#20 0x0000000000a259c5 in layeh.com/gopus.(*Encoder).Encode.func1 (
    e=0xc0002f0ce0, pcmPtr=0xc0002bfc00, frameSize=477, 
    dataPtr=0xc00027c6f0 "", 
    data=<error reading variable: access outside bounds of object referenced via synthetic pointer>, ~r0=<optimized out>)
    at /home/mumble/go/pkg/mod/layeh.com/gopus@v0.0.0-20161224163843-0ebf989153aa/opus_nonshared.go:250
#21 0x0000000000a2505f in layeh.com/gopus.(*Encoder).Encode (e=0xc0002f0ce0, 
    pcm=<error reading variable: access outside bounds of object referenced via synthetic pointer>, frameSize=477, maxDataBytes=40, ~r3=..., ~r4=...)
    at /home/mumble/go/pkg/mod/layeh.com/gopus@v0.0.0-20161224163843-0ebf989153aa/opus_nonshared.go:250
#22 0x0000000000a26fad in layeh.com/gumble/opus.(*Encoder).Encode (
    e=0xc000010878, pcm=..., mframeSize=477, maxDataBytes=40, ~r3=..., ~r4=...)
    at /home/mumble/go/pkg/mod/layeh.com/gumble@v0.0.0-20200818122324-146f9205029b/opus/opus.go:52
#23 0x0000000000a0def6 in layeh.com/gumble/gumble.AudioBuffer.writeAudio (
    a=..., client=0xc00010a900, seq=14, final=false, ~r3=...)
    at /home/mumble/go/pkg/mod/layeh.com/gumble@v0.0.0-20200818122324-146f9205029b/gumble/audio.go:59
#24 0x0000000000a1ebae in layeh.com/gumble/gumble.(*Client).AudioOutgoing.func1
    (ch=0xc000279500, c=0xc00010a900)
    at /home/mumble/go/pkg/mod/layeh.com/gumble@v0.0.0-20200818122324-146f9205029b/gumble/client.go:184
#25 0x000000000066c641 in runtime.goexit ()
    at /usr/local/go/src/runtime/asm_amd64.s:1371
#26 0x000000c000279500 in ?? ()
#27 0x000000c00010a900 in ?? ()
#28 0x0000000000000000 in ?? ()