|
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 request processing requires some potentially long operation and application developer |
36 | | -wants to do them off the main thread. In the first case this hand-off between request accepting thread |
37 | | -and request processing thread happens manually, by submitting work into some thread pool. |
38 | | -In the second case it is the framework that handles separate thread pool and passing work to it. |
| 35 | +In both cases, the request processing requires some potentially long operations and the application |
| 36 | +developer wants to do them off the main thread. In the first case this hand-off between the request |
| 37 | +accepting thread and the request processing thread happens manually by submitting work into some |
| 38 | +thread pool. In the second case it is the framework that handles the separate thread pool and |
| 39 | +passing work to it. |
39 | 40 |
|
40 | | -In cases like this proper tracing solution should still combine into a single trace all the work |
41 | | -required for request processing, regardless in what thread that work happened. With proper |
42 | | -parent-child relationship between span: span representing shipping address query should be the child |
43 | | -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. |
44 | 45 |
|
45 | 46 | ## The solution |
46 | 47 |
|
47 | | -Java auto instrumentation uses an obvious solution to the requirement above: we attach current execution |
48 | | -context (represented in the code by `Context`) with each `Runnable`, `Callable` and `ForkJoinTask`. |
49 | | -"Current" means the context active on the thread which calls `Executor.execute` (and its analogues |
50 | | -such as `submit`, `invokeAll` etc) at the moment of that call. Whenever some other thread starts |
51 | | -actual execution of that `Runnable` (or `Callable` or `ForkJoinTask`), that context get restored |
52 | | -on that thread for the duration of the execution. This can be illustrated by the following pseudo-code: |
53 | | - |
54 | | -``` |
55 | | - var job = () -> { |
56 | | - try(Scope scope = this.context.makeCurrent()) { |
57 | | - return userRepository.queryShippingAddress(request) |
58 | | - }} |
59 | | - job.context = Context.current() |
60 | | - Future f1 = pool.submit() |
61 | | -
|
| 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(); |
62 | 64 | ``` |
63 | 65 |
|
64 | 66 | ## The drawback |
65 | 67 |
|
66 | | -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: |
67 | 69 |
|
68 | | -``` |
| 70 | +```java |
69 | 71 | protected void service(HttpServletRequest req, HttpServletResponse resp) { |
70 | | - //This method is instrumented and we start new scope here |
71 | | - AsyncContext context = req.startAsync() |
72 | | - // When the runnable below is being submitted by servlet engine to an executor service |
73 | | - // it will capture the current context (together with the current span) with it |
74 | | - context.start { |
75 | | - // When Runnable starts, we reactive the captured context |
76 | | - // So this method is executed with the same context as the original "service" method |
77 | | - resp.writer.print("Hello world!") |
78 | | - context.complete() |
79 | | - } |
| 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 | + } |
80 | 82 | } |
81 | 83 | ``` |
82 | 84 |
|
83 | | -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: |
84 | 87 |
|
85 | | -``` |
86 | | -//Here we still have the same context from above active |
87 | | -//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 |
88 | 91 | pool.submit(new AcceptRequestRunnable() { |
89 | | -// The same context from above is propagated here as well |
90 | | -// Thus new reqeust processing will start while having a context active with some span inside |
91 | | -// That span will be used as parent spans for new spans created for a new request |
92 | | - ... |
93 | | -}) |
| 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 | +}); |
94 | 97 | ``` |
95 | 98 |
|
96 | | -This means that mechanism described in the previous section will propagate the execution context |
97 | | -of one request processing to a thread accepting some next, unrelated, request. |
98 | | -This will result in spans representing the accepting and processing of the second request will join |
99 | | -the same trace as those of the first span. This mistakenly correlates unrelated requests and may lead |
100 | | -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. |
101 | 105 |
|
102 | | -In addition this makes some of our tests extremely flaky. |
| 106 | +In addition, this makes some of our tests extremely flaky. |
103 | 107 |
|
104 | 108 | ## The currently accepted trade-offs |
105 | 109 |
|
106 | | -We acknowledge the problem with too active context propagation. We still think that out of the box |
107 | | -support for asynchronous multi-threaded traces is very important. We have diagnostics in place to |
108 | | -help us with detecting when we too eagerly propagate the execution context too far. We hope to |
109 | | -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. |
110 | 115 |
|
111 | | -In the meantime, processing new incoming request in the given JVM and creating new `SERVER` span |
112 | | -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