Unexplained assert on line 180 in vibe.core.stream

[schveiguy]

This is version 1.8.1 of vibe-core.

I got a stray assert in otherwise working code. Very difficult to tell what the problem is, since it appears as a final function in the OutputStream interface. Running again the problem does not reoccur. It seems to be an assert possibly triggered by an environmental issue. It also might really be an error in vibe.d. I'm not sure exactly what the stream is that is not fulfilling this contract requirement, as things seem nested and hidden behind derivatives.

Here is the line of code: https://github.com/vibe-d/vibe-core/blob/v1.8.1/source/vibe/core/stream.d#L180

Not sure if this is helpful, but this is the stack trace.

core.exception.AssertError@/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/core/stream.d(180): Assertion failure
----------------
??:? _d_assertp [0x55b9a9560261]
/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/core/stream.d:180 @safe void vibe.core.stream.OutputStream.write(const(ubyte[])) [0x55b9a94c49ad]
/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/internal/interfaceproxy.d-mixin-302:302 @safe void vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy.ProxyImpl!(vibe.internal.freelistref.FreeListRef!(vibe.stream.counting.CountingOutputStream, true).FreeListRef).ProxyImpl.__mixin8.__mixin2.write(void[], const(ubyte[])) [0x55b9a93e579c]
/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/internal/interfaceproxy.d-mixin-191:191 @safe void vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy.__mixin22.__mixin2.write(const(ubyte[])) [0x55b9a933ae41]
../../git/vibe.d/stream/vibe/stream/wrapper.d:338 @safe void vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 256uL).StreamOutputRange.put(const(ubyte)[]) [0x55b9a916534d]
../../git/vibe.d/http/vibe/http/common.d:610 @safe void vibe.http.common.ChunkedOutputStream.writeChunk(const(ubyte[])) [0x55b9a938c79a]
../../git/vibe.d/http/vibe/http/common.d:579 @safe void vibe.http.common.ChunkedOutputStream.flush() [0x55b9a938c4f7]
../../git/vibe.d/http/vibe/http/common.d:567 @safe ulong vibe.http.common.ChunkedOutputStream.write(const(ubyte[]), eventcore.driver.IOMode) [0x55b9a938c368]
/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/core/stream.d:180 @safe void vibe.core.stream.OutputStream.write(const(ubyte[])) [0x55b9a94c4992]
/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/internal/interfaceproxy.d-mixin-302:302 @safe void vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy.ProxyImpl!(vibe.internal.freelistref.FreeListRef!(vibe.http.common.ChunkedOutputStream, true).FreeListRef).ProxyImpl.__mixin8.__mixin2.write(void[], const(ubyte[])) [0x55b9a93b6150]
/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/internal/interfaceproxy.d-mixin-191:191 @safe void vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy.__mixin22.__mixin2.write(const(ubyte[])) [0x55b9a933ae41]
../../git/vibe.d/stream/vibe/stream/wrapper.d:318 @safe void vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange.flush() [0x55b9a8ff55e1]
../../git/vibe.d/stream/vibe/stream/wrapper.d:347 @safe void vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange.put(const(ubyte)[]) [0x55b9a8ff5827]
../../git/vibe.d/stream/vibe/stream/wrapper.d:352 @safe void vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange.put(const(char)[]) [0x55b9a8ff5887]
/home/steves/.dvm/compilers/dmd-2.091.1/linux/bin/../../src/phobos/std/range/primitives.d:277 @safe void std.range.primitives.doPut!(vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange, immutable(char)[]).doPut(ref vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange, ref immutable(char)[]) [0x55b9a90727a2]
/home/steves/.dvm/compilers/dmd-2.091.1/linux/bin/../../src/phobos/std/range/primitives.d:380 @safe void std.range.primitives.put!(vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange, immutable(char)[]).put(ref vibe.stream.wrapper.StreamOutputRange!(vibe.internal.interfaceproxy.InterfaceProxy!(vibe.core.stream.OutputStream).InterfaceProxy, 1024uL).StreamOutputRange, immutable(char)[]) [0x55b9a9072774]

[schveiguy]

Similar error now in the network module:

core.exception.AssertError@/home/steves/.dub/packages/vibe-core-1.8.1/vibe-core/source/vibe/core/net.d(780): Assertion failure

Seems very similar, basically we wrote data, and the amount of data written didn't match the request.

[schveiguy]

I still get these regularly. It crashes my server probably once a day or every other day. I'm going to attempt to switch to the latest release (Trying a workaround for #205), but this is definitely something that needs fixing if it's still in the latest version. Given the stray failures I've seen, I think there's something wrong somewhere deep in vibe-core (an error condition not handled maybe?).

A further manifestation (I think) is occasionally, the socket to the MySQL server is closed prematurely (the Exception from vibe-core says "Reached end of stream while reading data."

I noticed this one more prevalently, because I was not handling the exception and some structures related to permissions did not get fully initialized. So for 24 hours some people didn't have permissions they should have had. I never saw this before about a month ago, so I'm pretty sure this wasn't happening in a prior version of vibe-core.

[schveiguy]

I've updated to 1.9.2, and enabled the VibeHighEventPriority, which has worked around #205 and also seems to have cleared up this issue (been running over a week and haven't seen it once).

I'm going to leave this open, because it probably still is an issue at least in 1.8.1, and as always there is a possibility the bug is still present in the latest version but hasn't happened in my code.

[dedupely]

I've had a similar issue for the past few weeks. Crashing multiple times a day. I'm using 1.7.0 however.

[s-ludwig]

I'm wondering if this is still an issue without VibeHighEventPriority - personally I've never encountered this, but it appears as if this is or was an issue in the Posix socket implementation of eventcore, not handling IOMode.all correctly (i.e. not returning an error, but instead returning less than the requested number of bytes).

[schveiguy]

What are the consequences of turning it off? Should I try the latest release without this and see if things get better? I'd have to look at my logs to see if this is still happening regardless, this was almost 4 years ago...

[s-ludwig]

The issue that the new behavior aimed to fix was that in I/O (or other file descriptor triggered operations) heavy applications, code that yielded for non-I/O related reasons (timers/sleep, single-threaded synchronization etc) could simply starve. The new behavior treats both kinds of triggers more equally in terms of priority.

If you get the chance to verify the issue still exists without VibeHighEventPriority, that would definitely be great - in that case I'll try to do a more thorough audit of the socket code to see if I can find the issue that way. In any case, it sounds more like VibeHighEventPriority would hide the issue somewhat and not fix it in the strict sense.