We've a strange situation where a purepath in a correct state is incompleted.
Purepath response time is around 20seconds, but if we look at Elapsed Time we can see a final time of 23ms.
It seems like purepath is not completed (even selecting "show all nodes"):
This is Method Hotspots from this Purepath:
Solved! Go to Solution.
the purepath is complete. The second web server node consumes the 20 seconds after the application server returns. The elapsed time of 23 ms means that the request was forwarded in that time to the backend, which returned 256 ms later, and then the web server spent 20 seconds doing unknown things.
Unfortunately I don't know enough about web servers to help you find out what it has been doing there, maybe reading some large file? How large is the response? Or it was blocking for some other, non-instrumented service? Maybe there's something in the log files? Best regards,
Thank you so much for your answer, but I don't understand some of your sentences. Could you please illuminate me? Sure I'm reading the purepath tree badly...
- You say "The second web server node": but I only see one web server node ("WEBPROTEOOFI_APA_PRO10")
- "The elapsed time of 23 ms means that the request was forwarded in that time to the backend": I think I see the request arriving to the backend at elapsed time of: 0.48ms, isn't it? Then it appears the backend node.
- I only see backend steps as the final steps, not returning to the web server.
with "the second web server node" I meant the item in the purepath tree that has the "balancer:" in the URI. With "node" in general, I always mean items in purepath trees.
The 0.48 ms is the time that we measure when the web server sends out the request to the backend (still measured inside the web server). According to our measurements, the request then spends a mysterious 1.43 ms between the layers to arrive at the "toFilter" method of the backend at 2.11ms pp time (presumably due to the "balancing"). The filter chain (by default we omit the different toFilter calls, those can be enabled somewhere I think) then takes 20 ms to forward the request to the actual consumer, the "doPost" method of the application server. This method takes 256 ms to complete, then the filters going out take another 25 ms and in total, the backend took 302.82 ms to assemble the response.
At this point, dynatrace can't measure any more, because all the instrumented pieces have completed their course, except for the last measure point, the time when the response finally leaves the web server.
This is the point where we have a bit of a blind spot. We see that dynatrace thinks that the response leaves the web server a whopping 20 seconds after it entered. This can have two causes:
a) The time is actually wasted somewhere in the system, either during some post-processing on the web server or in the network or the balancer or any other place in between
b) It's a dynatrace bug (while unlikely, that's also a possibility).
The way to tell whether it's a or b is to look at the access logs of the web server and see if you can observe these times there as well (ideally for the same request), or to manually measure one of the requests. If it's b, please open a support ticket. If it's a, it will be hard to find out where the time gets consumed without a further tool like a network sniffer, because there's some places that we can't instrument. Hope that helps, best regards,