fix: AxiosPlugin async() / resync() #21
Conversation
|
Ok, well this still has problems but curious if it solves the double span so let me know on that. |
|
This doesn't seem to fix the bug of duplicate spans, |
I need a test case I can use to be able to track this down locally on my side. |
$ pwd
~/workspace/skywalking-nodejs
$ npx ts-node tests/plugins/axios/server.ts &
$ npx ts-node tests/plugins/axios/client.ts &
$ curl http://localhost:5001/axiosAnd because this generates invalid spans, the Web UI only renders the correct one, hence you need to see the raw spans in the storage, or via Replace the trace id with the one on the web ui |
|
The problem was that on return from the request hook before there was no way to tell if then next exit span was going to be another axios request or the http request for this axios request or even if it would be a completely unrelated http request (no easy way to tell if it belongs to this axios request), so either async() needed to be applied or no. The solution was to do a deeper axios hook as close to the http request as it could be and luckily this was possible so that the http request even wound up being in the same async context as the hook, so no need for async() here. I discovered another problem though which is not even axios but more general since it exists with normal http request as well. I am not sure if it was working before or if I just did not notice, but if I do my test with the multiple async requests like: await Promise.all(new Array(100).fill().map(() => downloadPageA('localhost', 8100, '/')));Only the first 14-21 or so have a correlated entry span in express server. This is the case whether the request is axios or just simple http. Not sure if this is a hard-coded limit somewhere or some resource is being exhausted, could you take a look? |
|
Review this error please? |
Will take a look today. Thanks. UPDATE: checking |
|
Well this doesn't look good even on web UI Actual: Expected: Ignore the component name in latter picture, just for reference of the hierarchy |
Ok, well this version actually solves all the problems I was having in my stuff with Axios so this has to be a tweak somewhere, will check. But the double spans (http + axios) for outgoing requests are gone no? |
I'd say it is worse, the duplicated spans are gone but the segments are duplicated now. |
THE DATA
2021-01-04T00:10:01.8592483Z console.info |
Actually I see what the problem is and it is not Axios (at least not directly). First of all, since Axios is async the test case client.ts should be creating an async request handler function and awaiting it (like the server.ts does correctly). The second and more important part is that the http plugin does not handle async request handlers AT ALL, so need to add that. |
|
I am using a slightly condensed debug log for easier reading, have a look at both the client and server below and notice the first 4 lines of each, that is the entry span being created and closed BEFORE the async exit spans even get executed. That segment close needs to be deferred via await until the async http request handler terminates. client.ts: server.ts |
|
There we go, segment finishes after everything else: Also threw in a fix for http server peer tag for free :) |
|
Maybe error due to changed peer. |
|
Note, there is still an out of order span stop between the async axios request and async http handler, so not quite done, looking. |
|
Well, it turns out that |
|
So have a look, if you update the expected data for the tests I think this is better than ever. Wound up fixing something we didn't even know was a problem - lack of http async server handlers. But take these post-release problems as a demonstration of how important regression tests will be for this agent. Async programming can be tricky and it is very easy to break something, even with minor changes. I suggest you add a lot of tests to this agent, especially multiple concurrent requests like my test example. If you do not, I guarantee you the next person who adds a plugin and is not familiar with the inner workings of this will break everything. |
|
@tom-pytel I'm finding a method to test more than simple cases we have now, do you have more tests want to complement except for the tests given above? |
My test is more of a quick hack, a more thorough test would be something like the following:
The difficulty with something like this is the order of execution is guaranteed non-deterministic so checking output is tricky. But if you have this test you will very very safe against inadvertent breakage. |
@kezhenxu94 This fixes my problem, let me know if it fixes the double span record problem for you.