Unexplained ERR_NET_SOCKET_ERROR

FMOD Engine
1

Info:

  • FMOD 2.02.11 (can’t upgrade because of this issue)
  • Unity 2021.3.25f1
  • MacPro 2013, OS X 10.14.6 (Mojave)
  • Only using FMOD Engine, not using Studio a t all
  • FMOD.MODE.CREATESTREAM | FMOD.MODE.NONBLOCKING

Hi,

So we have serve FMOD audio via http localhost for audio playback from a Go kernel that serves AV streams (supporting range requests)–it’s pretty neat!

However, when playing a stream after a few seconds of audio, getOpenState() returns ERR_NET_SOCKET_ERROR and FMOD’s appears to be borked (audio stops, current time ticks along, Unity crashes).

When using different size values for setStreamBufferSize(128*1024, FMOD.TIMEUNIT.RAWBYTES) (or not at all), the error will occur at a different time and for different streams (but consistent for that size value).

The issue seems to happen pretty often (1 out of 5 streams) and seems to happen within the first several seconds of playback. Have only been able to test with 160 ogg and mp3 streams 4-8 megs.

Happy to try other FMOD versions for regression on request.

Thanks in advance,
Drew

2

Hi Drew,

Could you please enable debugging with Debug_Initialize before creating your FMOD system, and post the resulting log here so that I can help diagnose the issue? Every error has an accompanying log that should provide some more info. Note that you’ll also have to use the logging version of FMOD instead of the normal one, which can be identified by the “L” suffix in the library name, e.g. fmodL.dll

1 Like
3

Hi Louis,

Attached 4 log files, each corresponding to a size set via setStreamBufferSize().

Notes & observations:

  • Each run was with a fresh Unity run (run the app, Unity audio disabled, no other sound playing, all playing the same ~6 mb ogg song served from a localhost port from a boilerplate Go http file server). In each log case, the same one stream and data was opened (the differing URLs are only bc the Go kernel serves a generated URI etc).
  • At first, I logged via FMOD’s file logger but could not get a repro. When I logged via callback proc the issue would repro, so the logs you see where a dump of that buffer to file once I got a NET_SOCKET_ERROR
  • For each stream buffer size case, it took an average of 4-6 fresh restart/retry cycles before I could get a repro.
  • Note for the 500k size, FMOD didn’t even get to playing audio before NET_SOCKET_ERROR. For the other 3, expected playback was going 2-5 seconds first.
  • Gun-to-my-head guess is that since Go’s http and net stack is very high performing (esp via localhost and in the same process), a race condition is being exposed that doesn’t otherwise appear under more “normal” connections. This would be consistent with that file-based logging and my initial attempts to troubleshoot with logging in Go cause the issue to not appear.

Thanks for your support, Louis. Hopefully this bug gets crushed.

fmod-socket-error-51200.log.txt (91.7 KB)
fmod-socket-error-169984.log.txt (110.7 KB)
fmod-socket-error-286720.log.txt (1.7 MB)
fmod-socket-error-512000.log.txt (203.4 KB)

4

After discussion with one of the developers, it’s likely that the issue is a timeout originating from your file server. As previously mentioned, most errors (socket errors included) in FMOD have their own additional log function that provides additional context - a notable exception to this is a socket error caused by a timeout that is caught in FMOD’s net read function, which is likely what is happening in this case.

You may also wish to test various timeout times with System::setNetworkTimeout and see whether you can find a setting that resolves the issue.

5

Hi Louis,

Thanks for helping look into this.

So I am hearing that the FMOD stream reader is timing (starving) out? The default value for setNetworkTimeout is 5 secs, so it would have to starve for 5 secs before it fails out if I understand things. Hmm, I am trying to reconcile this with the failure case at 50k and that failures were happening before 5 secs. It would seem the timer doesn’t start until the buffer is full?

The other mystery is: if the FMOD reader is timing out, why does the issue not show up when FMOD file logging is enabled – seems like a race condition.

Setting setNetworkTimeout above 30s (30000) decreases the occurrence rate but its character changes (1 out of 5 plays exhibit the issue but audio updates halt (audio loops 8k buffer), playback time halts, ~10 secs pass of this, then NET_SOCKET_ERROR shows up). Perhaps a clue: the connection is never closed in FMOD – it looks like it’s abandoned.

Very appreciative of you and folks time there looking into this.

Thanks,
Drew

7

Here’s a repro using:

  • setNetworkTimeout(30*1000)
  • setStreamBufferSize(128*1024, FMOD.TIMEUNIT.RAWBYTES);

After 0:06 secs playback:

  • time progress halts
  • audio starts to loop (OS audio buf likely no longer being updated)
  • no status or error msgs – getOpenState still returning PLAYING
  • 19 seconds later NET_SOCKET_ERROR shows up

fmod-socket-error-30s-128k.log.txt (89.1 KB)

EDIT:

In this repro I added time indexes to the log (playback time index and actual time elapsed):

fmod-socket-error-2-30s-128k.log.txt (117.1 KB)

The mysteries are explained if FMOD’s read timer doesn’t reset until its buffer is full and the issue is on our side. I will keep looking at things here, thank you.

8

Thanks for the extra logs and looking into it yourself in such detail.

I’ve done a little more looking at FMOD’s source, and as far as I can see, the only way FMOD throws NET_SOCKET_ERROR without an accompanying log with details is when FMOD calls recv and receives an exception that the operation would block, i.e. EWOULDBLOCK or WSAEWOULDBLOCK. No error is logged when receiving this exception, likely due to the frequency with which FMOD retries.

On receiving the exception FMOD will try reading again until the operation no longer blocks, a different exception is thrown by recv, or the network times out - the latter of which is where NET_SOCKET_ERROR is thrown.

As I’m unfamiliar with your fileserver I can’t necessarily offer a diagnosis, but I hope this info is indicative of the issue.

9

This was helpful my friend.

Sure enough, the issue was on my end. Please accept on my humble apologies for the goose chase, and many thanks for your time and attention on this Louis.

Our new product ships this fall and marks our switch to FMOD, so it’s reassuring to know there’s folks there that are large and in charge handing support inquiries. We are pre-revenue until then, but your support and attention makes me feel confident and content to release funds for our FMOD license when we approach release!

Best,
Drew

2 Likes
10

No problem, I’m glad that you’ve managed to resolve the issue!

1 Like