|
4 | 4 |
|
5 | 5 | Take a look at the following two pseudo-code snippets (see below for explanations). |
6 | 6 |
|
7 | | -``` |
8 | | -Executor pool = Executors.newFixedThreadPool(10) |
| 7 | +```java |
| 8 | +Executor pool = Executors.newFixedThreadPool(10); |
9 | 9 |
|
10 | 10 | public void doGet(HttpServletRequest request, HttpServletResponse response) { |
11 | | - Future f1 = pool.submit(() -> { |
12 | | - return userRepository.queryShippingAddress(request) |
13 | | - }) |
14 | | - Future f2 = pool.submit(() -> { |
15 | | - return warehouse.currentState(request) |
16 | | - }) |
17 | | - writeResponse(response, f1.get(), f2.get()) |
| 11 | + Future f1 = pool.submit(() -> { |
| 12 | + return userRepository.queryShippingAddress(request); |
| 13 | + }); |
| 14 | + Future f2 = pool.submit(() -> { |
| 15 | + return warehouse.currentState(request); |
| 16 | + }); |
| 17 | + writeResponse(response, f1.get(), f2.get()); |
18 | 18 | } |
19 | 19 | ``` |
20 | 20 |
|
21 | | -``` |
22 | | -Executor pool = Executors.newFixedThreadPool(10) |
| 21 | +```java |
| 22 | +Executor pool = Executors.newFixedThreadPool(10); |
23 | 23 |
|
24 | 24 | public void doGet(HttpServletRequest request, HttpServletResponse response) { |
25 | | - final AsyncContext acontext = request.startAsync(); |
26 | | - acontext.start(() -> { |
27 | | - String address = userRepository.queryShippingAddress(request) |
28 | | - HttpServletResponse response = acontext.getResponse(); |
29 | | - writeResponse(response, address) |
30 | | - acontext.complete(); |
31 | | - } |
| 25 | + final AsyncContext asyncContext = request.startAsync(); |
| 26 | + acontext.start(() -> { |
| 27 | + String address = userRepository.queryShippingAddress(request); |
| 28 | + HttpServletResponse response = asyncContext.getResponse(); |
| 29 | + writeResponse(response, address); |
| 30 | + asyncContext.complete(); |
| 31 | + }); |
32 | 32 | } |
33 | 33 | ``` |
34 | 34 |
|
35 | | -In both cases, the request processing requires some potentially long operation and the application |
| 35 | +In both cases, the request processing requires some potentially long operations and the application |
36 | 36 | developer wants to do them off the main thread. In the first case this hand-off between the request |
37 | 37 | accepting thread and the request processing thread happens manually by submitting work into some |
38 | 38 | thread pool. In the second case it is the framework that handles the separate thread pool and |
39 | 39 | passing work to it. |
40 | 40 |
|
41 | | -In cases like this, a proper tracing solution should still combine into a single trace all the work |
42 | | -required for request processing, regardless in what thread that work happened. With proper |
43 | | -parent-child relationship between span: span representing shipping address query should be the child |
44 | | -of the span which denotes accepting HTTP request. |
| 41 | +In cases like this, a proper tracing solution should still combine all the work required for request |
| 42 | +processing into a single trace, regardless of what thread that work happened on. With a proper |
| 43 | +parent-child relationship between spans, the span representing the shipping address query should be |
| 44 | +the child of the span which denotes accepting HTTP request. |
45 | 45 |
|
46 | 46 | ## The solution |
47 | 47 |
|
48 | | -Java auto instrumentation uses an obvious solution to the requirement above: we attach current execution |
49 | | -context (represented in the code by `Context`) with each `Runnable`, `Callable` and `ForkJoinTask`. |
50 | | -"Current" means the context active on the thread which calls `Executor.execute` (and its analogues |
51 | | -such as `submit`, `invokeAll` etc) at the moment of that call. Whenever some other thread starts |
52 | | -actual execution of that `Runnable` (or `Callable` or `ForkJoinTask`), that context get restored |
53 | | -on that thread for the duration of the execution. This can be illustrated by the following pseudo-code: |
54 | | - |
55 | | -``` |
56 | | - var job = () -> { |
57 | | - try(Scope scope = this.context.makeCurrent()) { |
58 | | - return userRepository.queryShippingAddress(request) |
59 | | - }} |
60 | | - job.context = Context.current() |
61 | | - Future f1 = pool.submit() |
62 | | -
|
| 48 | +Java auto instrumentation uses an obvious solution to the requirement above: we attach the current |
| 49 | +execution context (represented in the code by `Context`) with each `Runnable`, `Callable` and |
| 50 | +`ForkJoinTask`. "Current" means the context that is active on the thread which calls |
| 51 | +`Executor.execute` (and its analogues such as `submit`, `invokeAll` etc) at the moment of the call. |
| 52 | +Whenever some other thread starts the actual execution of the `Runnable` (or `Callable` or |
| 53 | +`ForkJoinTask`), that context get restored on that thread for the duration of the execution. This |
| 54 | +can be illustrated by the following pseudo-code: |
| 55 | + |
| 56 | +```java |
| 57 | +var job = () -> { |
| 58 | + try(Scope scope = this.context.makeCurrent()) { |
| 59 | + return userRepository.queryShippingAddress(request); |
| 60 | + } |
| 61 | +}; |
| 62 | +job.context = Context.current(); |
| 63 | +Future f1 = pool.submit(); |
63 | 64 | ``` |
64 | 65 |
|
65 | 66 | ## The drawback |
66 | 67 |
|
67 | | -Here is a simplified example of what async servlet processing may look like |
| 68 | +Here is a simplified example of what async servlet processing may look like: |
68 | 69 |
|
69 | | -``` |
| 70 | +```java |
70 | 71 | protected void service(HttpServletRequest req, HttpServletResponse resp) { |
71 | | - //This method is instrumented and we start new scope here |
72 | | - AsyncContext context = req.startAsync() |
73 | | - // When the runnable below is being submitted by servlet engine to an executor service |
74 | | - // it will capture the current context (together with the current span) with it |
75 | | - context.start { |
76 | | - // When Runnable starts, we reactive the captured context |
77 | | - // So this method is executed with the same context as the original "service" method |
78 | | - resp.writer.print("Hello world!") |
79 | | - context.complete() |
80 | | - } |
| 72 | + // This method is instrumented and we start new scope here |
| 73 | + AsyncContext context = req.startAsync(); |
| 74 | + // When the runnable below is being submitted by the servlet engine to an executor service |
| 75 | + // it will capture the current context (together with the current span) with it |
| 76 | + context.start { |
| 77 | + // When Runnable starts, we reactivate the captured context |
| 78 | + // So this method is executed with the same context as the original "service" method |
| 79 | + resp.writer.print("Hello world!"); |
| 80 | + context.complete(); |
| 81 | + } |
81 | 82 | } |
82 | 83 | ``` |
83 | 84 |
|
84 | | -If we now take a look inside `context.complete` method from above it may be implemented like this: |
| 85 | +If we now take a look inside the `context.complete` method from above it may be implemented like |
| 86 | +this: |
85 | 87 |
|
86 | | -``` |
87 | | -//Here we still have the same context from above active |
88 | | -//It gets attached to this new runnable |
| 88 | +```java |
| 89 | +// Here we still have the same active context from above. |
| 90 | +// It then gets attached to this new runnable |
89 | 91 | pool.submit(new AcceptRequestRunnable() { |
90 | | -// The same context from above is propagated here as well |
91 | | -// Thus new reqeust processing will start while having a context active with some span inside |
92 | | -// That span will be used as parent spans for new spans created for a new request |
93 | | - ... |
94 | | -}) |
| 92 | + // The same context from above is propagated here as well |
| 93 | + // Thus new request processing will start while having a context active with some span inside |
| 94 | + // That span will be used as parent spans for new spans created for a new request |
| 95 | + ... |
| 96 | +}); |
95 | 97 | ``` |
96 | 98 |
|
97 | | -This means that mechanism described in the previous section will propagate the execution context |
98 | | -of one request processing to a thread accepting some next, unrelated, request. |
99 | | -This will result in spans representing the accepting and processing of the second request will join |
100 | | -the same trace as those of the first span. This mistakenly correlates unrelated requests and may lead |
101 | | -to huge traces being active for hours and hours. |
| 99 | +This means that the mechanism described in the previous section can inadvertently propagate the |
| 100 | +execution context of one request to a thread handling an entirely unrelated request. As a result, |
| 101 | +the spans representing the acceptance and processing of the second request may be incorrectly linked |
| 102 | +to the same trace as those of the first request. This erroneous correlation of unrelated requests |
| 103 | +can lead to excessively large traces that remain active for extended periods, potentially lasting |
| 104 | +hours. |
102 | 105 |
|
103 | | -In addition this makes some of our tests extremely flaky. |
| 106 | +In addition, this makes some of our tests extremely flaky. |
104 | 107 |
|
105 | 108 | ## The currently accepted trade-offs |
106 | 109 |
|
107 | | -We acknowledge the problem with too active context propagation. We still think that out of the box |
108 | | -support for asynchronous multi-threaded traces is very important. We have diagnostics in place to |
109 | | -help us with detecting when we too eagerly propagate the execution context too far. We hope to |
110 | | -gradually find framework-specific countermeasures to such problem and solve them one by one. |
| 110 | +We recognize the issue of overly aggressive context propagation. However, we believe that providing |
| 111 | +out-of-the-box support for asynchronous multi-threaded traces is crucial. To address this, we have |
| 112 | +implemented diagnostics to help detect instances where the execution context is propagated too |
| 113 | +eagerly. Our goal is to gradually identify and implement framework-specific countermeasures to |
| 114 | +address these issues, resolving them one by one. |
111 | 115 |
|
112 | | -In the meantime, processing new incoming request in the given JVM and creating new `SERVER` span |
113 | | -always starts with a clean context. |
| 116 | +In the meantime, processing a new incoming request within the given JVM and creating a new `SERVER` |
| 117 | +span will always begin with a clean context. |
0 commit comments