Provide useful exception trace in TimeoutCancellationToken

[kelunik]

Without this, the exception trace is pretty useless, because it only includes Loop::run() and other internal loop calls, giving absolutely no indication which kind of thing had a timeout.

Relates to amphp/http-client#260.

[enumag]

This is a clever trick, I'll have to remember this. 👍

[trowski]

This is the exact reason I added the custom message recently.

The downside here is that an Exception instance is created every time an instance is created, regardless of whether it's used or not, which most often it is not. So that means the entire debug backtrace is generated even though it won't often be used. I'd like to know how expensive this is before merging.

[kelunik]

@trowski Even with a custom message, you need to search through your entire dependencies to find the correct place. With this patch, it was very easy to track down the origin of the issue.

[trowski]

@kelunik I know, it wasn't a perfect solution, but I wanted to avoid constructing the exception object if it wasn't necessary. All you really want to know is what operation timed out and the message can tell you that. I don't think building a TimeoutException with every operation is a good idea.

[kelunik]

It will be really hard to consistently write that good exception messages that they're equally useful as the stack trace.

I doubt that the performance impact is worth talking about. Operations that use these timeouts are almost always IO related and therefore the impact will be negligible compared to the operation the timeout is applied to and the benefit of having debugging information is invaluable.

[trowski]

I asked in room 11: https://chat.stackoverflow.com/transcript/message/48805672#48805672

I'm concerned about @nikic's note that it could change destruction behavior.

I don't think we use TimeoutCancellationToken in any performance-critical paths, so I suppose performance is less of a concern than my initial reaction.

What about @bwoebi's suggestion of using AMP_DEBUG as a switch for this behavior?

[trowski]

As a suggested message style we could use in our libs:

$token = new TimeoutCancellationToken(\sprintf("Connecting to %s initiated in %s:%d timed out", $host, __FILE__, __LINE__);

It's not a backtrace, but Amp's backtraces are usually not terribly useful anyway.

[enumag]

Aren't FILE and LINE even in the current not-so-good backtrace?

[trowski]

Aren't FILE and LINE even in the current not-so-good backtrace?

Yes, they are included. But using adding them in the way I did to the message doesn't require a backtrace to be generated, which includes references to any objects in the backtrace, either objects with methods being invoked or objects used as arguments.

[kelunik]

@trowski I've pushed another approach that shouldn't have the possible GC impact.