New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

no stack trace on uncaught exception in task #1420

Closed
John-Colvin opened this Issue Feb 12, 2016 · 7 comments

Comments

Projects
None yet
4 participants
@John-Colvin
Contributor

John-Colvin commented Feb 12, 2016

% cat source/app.d
import vibe.d;
void main()
{
    runTask((){throw new Exception("");});
    runEventLoop();
}
% dub
[ ... ]
Task terminated with uncaught exception: 

No sign of any stack trace.

@jdeschenes

This comment has been minimized.

Show comment
Hide comment
@jdeschenes

jdeschenes Mar 8, 2016

@John-Colvin

It's very similar to the issue in #1421. In these cases, the message should definitively send the full traceback and not only the error message as it does right now.

jdeschenes commented Mar 8, 2016

@John-Colvin

It's very similar to the issue in #1421. In these cases, the message should definitively send the full traceback and not only the error message as it does right now.

@s-ludwig

This comment has been minimized.

Show comment
Hide comment
@s-ludwig

s-ludwig Mar 9, 2016

Member

It doesn't make sense to present a stack track to the user by default. The application can be run with --vv or call setLogLevel(LogLevel.debug_); to enable debug messages and stack traces will appear.

Member

s-ludwig commented Mar 9, 2016

It doesn't make sense to present a stack track to the user by default. The application can be run with --vv or call setLogLevel(LogLevel.debug_); to enable debug messages and stack traces will appear.

@marcioapm

This comment has been minimized.

Show comment
Hide comment
@marcioapm

marcioapm Mar 9, 2016

Contributor

I think, ideally, stack traces should be on a separate log level, or perhaps just controlled with a version instead.

With LogLevel.debug_ you get bombarded with vibe's internal logging, which as a library user is not very useful.

Would maybe having a LogLevel.internal or what have you, where all vibe.d debug logging would go be more useful? This way users could use debug_ for application-level debugging and callstacks.

Contributor

marcioapm commented Mar 9, 2016

I think, ideally, stack traces should be on a separate log level, or perhaps just controlled with a version instead.

With LogLevel.debug_ you get bombarded with vibe's internal logging, which as a library user is not very useful.

Would maybe having a LogLevel.internal or what have you, where all vibe.d debug logging would go be more useful? This way users could use debug_ for application-level debugging and callstacks.

@jdeschenes

This comment has been minimized.

Show comment
Hide comment
@jdeschenes

jdeschenes Mar 9, 2016

Hi,

Logging stack traces in production is invaluable when a user has never recovered from the exception. It is a big indication of a bug and helps greatly in investigating the issue. Setting the default logging to debug_ is simply not viable in that case as there is too much verbosity.

as for @marcioapm's suggestion, I think this is a good idea. Having a lower tier of logging for vibe.d's internal would help when debugging issues.

jdeschenes commented Mar 9, 2016

Hi,

Logging stack traces in production is invaluable when a user has never recovered from the exception. It is a big indication of a bug and helps greatly in investigating the issue. Setting the default logging to debug_ is simply not viable in that case as there is too much verbosity.

as for @marcioapm's suggestion, I think this is a good idea. Having a lower tier of logging for vibe.d's internal would help when debugging issues.

@s-ludwig

This comment has been minimized.

Show comment
Hide comment
@s-ludwig

s-ludwig Mar 10, 2016

Member

Just noticed that I didn't submit my earlier reply... So I think that many of the logDebug calls within vibe.d should actually be logDebugV, at least those that definitely are happening in a server context. That would solve the noise issue without yet another log level.

In addition to that, it maybe makes sense to provide a default error logging mechanism within the HTTP server, which can currently be achieved by overriding the errorPageHandler.

However, both #1421 and this issue have in common that their exception handling is not ideal. #1421 should ideally have the callback marked as nothrow, as there is nothing that the WebSocket code can reasonably do with an exception anyway, other than closing the connection, which it does anyway.

For runTask, there are two options that I was thinking of - either require task functions to also be nothrow (way too much breakage at this point), or rethrow uncaught exceptions when another task joins the throwing task. However, the latter has a lot of corner cases that need to be handled, it requires additional bookkeeping, and at some point there might still be the situation that nobody handled the exception.

Member

s-ludwig commented Mar 10, 2016

Just noticed that I didn't submit my earlier reply... So I think that many of the logDebug calls within vibe.d should actually be logDebugV, at least those that definitely are happening in a server context. That would solve the noise issue without yet another log level.

In addition to that, it maybe makes sense to provide a default error logging mechanism within the HTTP server, which can currently be achieved by overriding the errorPageHandler.

However, both #1421 and this issue have in common that their exception handling is not ideal. #1421 should ideally have the callback marked as nothrow, as there is nothing that the WebSocket code can reasonably do with an exception anyway, other than closing the connection, which it does anyway.

For runTask, there are two options that I was thinking of - either require task functions to also be nothrow (way too much breakage at this point), or rethrow uncaught exceptions when another task joins the throwing task. However, the latter has a lot of corner cases that need to be handled, it requires additional bookkeeping, and at some point there might still be the situation that nobody handled the exception.

@jdeschenes

This comment has been minimized.

Show comment
Hide comment
@jdeschenes

jdeschenes Mar 10, 2016

Hi, this sounds like a much better approach!

The change seems to be fairly straightforward. Would something like this work for you?

HTTPServerRequestDelegateS handleWebSockets(void function(scope WebSocket) nothrow on_handshake)
{
    return handleWebSockets(toDelegate(on_handshake));
}

HTTPServerRequestDelegateS handleWebSockets(void function(scope WebSocket) on_handshake)
{
    logWarn("SOME DEPRECATION WARNING");
    return handleWebSockets(toDelegate(on_handshake));
}

Maybe we could use a similar approach for the runTask as well? Eventually deprecating it?

jdeschenes commented Mar 10, 2016

Hi, this sounds like a much better approach!

The change seems to be fairly straightforward. Would something like this work for you?

HTTPServerRequestDelegateS handleWebSockets(void function(scope WebSocket) nothrow on_handshake)
{
    return handleWebSockets(toDelegate(on_handshake));
}

HTTPServerRequestDelegateS handleWebSockets(void function(scope WebSocket) on_handshake)
{
    logWarn("SOME DEPRECATION WARNING");
    return handleWebSockets(toDelegate(on_handshake));
}

Maybe we could use a similar approach for the runTask as well? Eventually deprecating it?

@s-ludwig

This comment has been minimized.

Show comment
Hide comment
@s-ludwig

s-ludwig Oct 10, 2016

Member

@jdeschenes: I was worried that overloading based on nothrow'ness of a function pointer/delegate argument wouldn't work, but I just tried it and it works flawlessly. So this is indeed a pretty simple solution. The second overload can also get an ordinary deprecated attribute instead of the log message.

Member

s-ludwig commented Oct 10, 2016

@jdeschenes: I was worried that overloading based on nothrow'ness of a function pointer/delegate argument wouldn't work, but I just tried it and it works flawlessly. So this is indeed a pretty simple solution. The second overload can also get an ordinary deprecated attribute instead of the log message.

s-ludwig added a commit that referenced this issue Aug 12, 2017

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment