1616
1717import asyncio
1818import sys
19+ import time
1920import unittest
2021from timeit import default_timer
2122from unittest import mock
5758 "http.server.request.size" : _duration_attrs ,
5859}
5960
61+ simulated_background_task_execution_time_s = 0.01
62+
6063
6164async def http_app (scope , receive , send ):
6265 message = await receive ()
@@ -99,6 +102,50 @@ async def simple_asgi(scope, receive, send):
99102 await websocket_app (scope , receive , send )
100103
101104
105+ async def long_response_asgi (scope , receive , send ):
106+ assert isinstance (scope , dict )
107+ assert scope ["type" ] == "http"
108+ message = await receive ()
109+ scope ["headers" ] = [(b"content-length" , b"128" )]
110+ assert scope ["type" ] == "http"
111+ if message .get ("type" ) == "http.request" :
112+ await send (
113+ {
114+ "type" : "http.response.start" ,
115+ "status" : 200 ,
116+ "headers" : [
117+ [b"Content-Type" , b"text/plain" ],
118+ [b"content-length" , b"1024" ],
119+ ],
120+ }
121+ )
122+ await send ({"type" : "http.response.body" , "body" : b"*" , "more_body" : True })
123+ await send ({"type" : "http.response.body" , "body" : b"*" , "more_body" : True })
124+ await send ({"type" : "http.response.body" , "body" : b"*" , "more_body" : True })
125+ await send ({"type" : "http.response.body" , "body" : b"*" , "more_body" : False })
126+
127+
128+ async def background_execution_asgi (scope , receive , send ):
129+ assert isinstance (scope , dict )
130+ assert scope ["type" ] == "http"
131+ message = await receive ()
132+ scope ["headers" ] = [(b"content-length" , b"128" )]
133+ assert scope ["type" ] == "http"
134+ if message .get ("type" ) == "http.request" :
135+ await send (
136+ {
137+ "type" : "http.response.start" ,
138+ "status" : 200 ,
139+ "headers" : [
140+ [b"Content-Type" , b"text/plain" ],
141+ [b"content-length" , b"1024" ],
142+ ],
143+ }
144+ )
145+ await send ({"type" : "http.response.body" , "body" : b"*" , })
146+ time .sleep (simulated_background_task_execution_time_s )
147+
148+
102149async def error_asgi (scope , receive , send ):
103150 assert isinstance (scope , dict )
104151 assert scope ["type" ] == "http"
@@ -127,14 +174,14 @@ def validate_outputs(self, outputs, error=None, modifiers=None):
127174 # Ensure modifiers is a list
128175 modifiers = modifiers or []
129176 # Check for expected outputs
130- self .assertEqual (len (outputs ), 2 )
131177 response_start = outputs [0 ]
132- response_body = outputs [1 ]
178+ response_final_body = outputs [- 1 ]
133179 self .assertEqual (response_start ["type" ], "http.response.start" )
134- self .assertEqual (response_body ["type" ], "http.response.body" )
180+ self .assertEqual (response_final_body ["type" ], "http.response.body" )
181+ self .assertEqual (response_final_body .get ("more_body" , False ), False )
135182
136183 # Check http response body
137- self .assertEqual (response_body ["body" ], b"*" )
184+ self .assertEqual (response_final_body ["body" ], b"*" )
138185
139186 # Check http response start
140187 self .assertEqual (response_start ["status" ], 200 )
@@ -153,7 +200,6 @@ def validate_outputs(self, outputs, error=None, modifiers=None):
153200
154201 # Check spans
155202 span_list = self .memory_exporter .get_finished_spans ()
156- self .assertEqual (len (span_list ), 4 )
157203 expected = [
158204 {
159205 "name" : "GET / http receive" ,
@@ -194,6 +240,7 @@ def validate_outputs(self, outputs, error=None, modifiers=None):
194240 for modifier in modifiers :
195241 expected = modifier (expected )
196242 # Check that output matches
243+ self .assertEqual (len (span_list ), len (expected ))
197244 for span , expected in zip (span_list , expected ):
198245 self .assertEqual (span .name , expected ["name" ])
199246 self .assertEqual (span .kind , expected ["kind" ])
@@ -232,6 +279,41 @@ def test_asgi_exc_info(self):
232279 outputs = self .get_all_output ()
233280 self .validate_outputs (outputs , error = ValueError )
234281
282+ def test_long_response (self ):
283+ """Test that the server span is ended on the final response body message. If the server span is ended early then this test will fail due discrepancies in the expected list of spans and the emitted list of spans."""
284+ app = otel_asgi .OpenTelemetryMiddleware (long_response_asgi )
285+ self .seed_app (app )
286+ self .send_default_request ()
287+ outputs = self .get_all_output ()
288+
289+ def add_more_body_spans (expected : list ):
290+ more_body_span = {
291+ "name" : "GET / http send" ,
292+ "kind" : trace_api .SpanKind .INTERNAL ,
293+ "attributes" : {"type" : "http.response.body" },
294+ }
295+ extra_spans = [more_body_span ] * 3
296+ expected [2 :2 ] = extra_spans
297+ return expected
298+
299+ self .validate_outputs (outputs , modifiers = [add_more_body_spans ])
300+
301+ def test_background_execution (self ):
302+ """Test that the server span is ended BEFORE the background task is finished."""
303+ app = otel_asgi .OpenTelemetryMiddleware (background_execution_asgi )
304+ self .seed_app (app )
305+ self .send_default_request ()
306+ outputs = self .get_all_output ()
307+ self .validate_outputs (outputs )
308+ span_list = self .memory_exporter .get_finished_spans ()
309+ server_span = span_list [- 1 ]
310+ assert server_span .kind == SpanKind .SERVER
311+ span_duration_nanos = server_span .end_time - server_span .start_time
312+ print (span_duration_nanos )
313+ self .assertLessEqual (
314+ span_duration_nanos ,
315+ simulated_background_task_execution_time_s * 10 ** 9 )
316+
235317 def test_override_span_name (self ):
236318 """Test that default span_names can be overwritten by our callback function."""
237319 span_name = "Dymaxion"
0 commit comments