Skip to content

Commit 912126f

Browse files
author
Francesco Faraone
committed
add request logger, add running_tasks on qs
1 parent 057cd9f commit 912126f

File tree

7 files changed

+317
-79
lines changed

7 files changed

+317
-79
lines changed

‎connect/eaas/logging.py‎

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,5 @@
1+
import json
2+
13
from logzio.handler import LogzioHandler
24

35

@@ -10,3 +12,48 @@ def extra_fields(self, message):
1012
extra_fields = super().extra_fields(message)
1113
extra_fields.update(self.default_extra_fields)
1214
return extra_fields
15+
16+
17+
class RequestLogger:
18+
19+
def __init__(self, logger):
20+
self.logger = logger
21+
22+
def log_request(self, method, url, kwargs):
23+
other_args = {k: v for k, v in kwargs.items() if k not in ('headers', 'json', 'params')}
24+
25+
if 'params' in kwargs:
26+
url += '&' if '?' in url else '?'
27+
url += '&'.join([f'{k}={v}' for k, v in kwargs['params'].items()])
28+
29+
lines = [
30+
'--- HTTP Request ---',
31+
f'{method.upper()} {url} {other_args if other_args else ""}',
32+
]
33+
34+
if 'headers' in kwargs:
35+
for k, v in kwargs['headers'].items():
36+
lines.append(f'{k}: {v}')
37+
38+
if 'json' in kwargs:
39+
lines.append(json.dumps(kwargs['json'], indent=4))
40+
41+
lines.append('')
42+
self.logger.debug('\n'.join(lines))
43+
44+
def log_response(self, response):
45+
reason = response.raw.reason if getattr(response, 'raw', None) else response.reason_phrase
46+
lines = [
47+
'--- HTTP Response ---',
48+
f'{response.status_code} {reason}',
49+
]
50+
51+
for k, v in response.headers.items():
52+
lines.append(f'{k}: {v}')
53+
54+
if response.headers.get('Content-Type', None) == 'application/json':
55+
lines.append(json.dumps(response.json(), indent=4))
56+
57+
lines.append('')
58+
59+
self.logger.debug('\n'.join(lines))

‎connect/eaas/worker.py‎

Lines changed: 12 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,7 @@
2323
get_extension_class,
2424
get_extension_type,
2525
)
26-
from connect.eaas.logging import ExtensionLogHandler
26+
from connect.eaas.logging import ExtensionLogHandler, RequestLogger
2727
from connect.eaas.manager import TasksManager
2828

2929

@@ -103,6 +103,9 @@ def get_client(self):
103103
self.api_key,
104104
endpoint=f'https://{self.api_address}/public/v1',
105105
use_specs=False,
106+
logger=RequestLogger(
107+
self.get_extension_logger(self.logging_api_key),
108+
),
106109
)
107110

108111
def get_extension_logger(self, token):
@@ -140,7 +143,12 @@ def ensure_tasks_manager_running(self):
140143
self.start_tasks_manager()
141144

142145
def get_url(self):
143-
return f'{self.base_ws_url}/{self.environment_id}/{self.instance_id}'
146+
running_tasks = (
147+
self.tasks_manager.running_tasks
148+
if self.tasks_manager else 0
149+
)
150+
url = f'{self.base_ws_url}/{self.environment_id}/{self.instance_id}'
151+
return f'{url}?running_tasks={running_tasks}'
144152

145153
def get_extension(self):
146154
return self.extension_class(
@@ -224,6 +232,7 @@ async def configuration(self, data):
224232
if data.environment_type:
225233
self.environment_type = data.environment_type
226234
if data.log_level:
235+
logger.info(f'Change extesion logger level to {data.log_level}')
227236
logging.getLogger('eaas.extension').setLevel(
228237
getattr(logging, data.log_level),
229238
)
@@ -267,5 +276,5 @@ async def start(self):
267276
logger.info('Control worker stopped')
268277

269278
def stop(self):
270-
logger.info('Stopping control worker.....')
279+
logger.info('Stopping control worker...')
271280
self.run_event.clear()

‎poetry.lock‎

Lines changed: 87 additions & 64 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎pyproject.toml‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@ cextrun = 'connect.eaas.main:main'
2727
[tool.poetry.dependencies]
2828
python = "^3.8"
2929
websockets = "^9.0.1"
30-
connect-openapi-client = "^22.0.7"
30+
connect-openapi-client = "^22.0.8"
3131
logzio-python-handler = "^3.0.0"
3232

3333
[tool.poetry.dev-dependencies]

‎tests/test_logging.py‎

Lines changed: 155 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,9 @@
11
import logging
22

3-
from connect.eaas.logging import ExtensionLogHandler
3+
from urllib3.response import HTTPResponse
4+
from requests.models import Response
5+
6+
from connect.eaas.logging import ExtensionLogHandler, RequestLogger
47

58

69
def test_extension_log_handler():
@@ -17,3 +20,154 @@ def test_extension_log_handler():
1720
None,
1821
))
1922
assert extra_fields['field'] == 'value'
23+
24+
25+
def test_request_logger_request(caplog):
26+
rl = RequestLogger(logging.getLogger('eaas.extension'))
27+
28+
with caplog.at_level(logging.DEBUG):
29+
rl.log_request('POST', 'https://example.com', {})
30+
31+
assert '\n'.join(
32+
[
33+
'--- HTTP Request ---',
34+
"POST https://example.com ",
35+
'',
36+
],
37+
) == caplog.records[0].message
38+
39+
40+
def test_request_logger_request_params(caplog):
41+
rl = RequestLogger(logging.getLogger('eaas.extension'))
42+
43+
with caplog.at_level(logging.DEBUG):
44+
rl.log_request('POST', 'https://example.com', {'params': {'a': 'va'}})
45+
46+
assert '\n'.join(
47+
[
48+
'--- HTTP Request ---',
49+
"POST https://example.com?a=va ",
50+
'',
51+
],
52+
) == caplog.records[0].message
53+
54+
55+
def test_request_logger_request_with_qs(caplog):
56+
rl = RequestLogger(logging.getLogger('eaas.extension'))
57+
58+
with caplog.at_level(logging.DEBUG):
59+
rl.log_request('GET', 'https://example.com?queryparam=value', {})
60+
61+
assert '\n'.join(
62+
[
63+
'--- HTTP Request ---',
64+
"GET https://example.com?queryparam=value ",
65+
'',
66+
],
67+
) == caplog.records[0].message
68+
69+
70+
def test_request_logger_request_with_headers(caplog):
71+
rl = RequestLogger(logging.getLogger('eaas.extension'))
72+
73+
headers = {
74+
'Authorization': 'ApiKey SU-000:xxxx',
75+
}
76+
77+
with caplog.at_level(logging.DEBUG):
78+
rl.log_request('GET', 'https://example.com', {'headers': headers})
79+
80+
assert '\n'.join(
81+
[
82+
'--- HTTP Request ---',
83+
"GET https://example.com ",
84+
'Authorization: ApiKey SU-000:xxxx',
85+
'',
86+
],
87+
) == caplog.records[0].message
88+
89+
90+
def test_request_logger_request_with_json_body(caplog):
91+
rl = RequestLogger(logging.getLogger('eaas.extension'))
92+
93+
json = {
94+
'test': 'data',
95+
}
96+
97+
with caplog.at_level(logging.DEBUG):
98+
rl.log_request('GET', 'https://example.com', {'json': json})
99+
100+
assert '\n'.join(
101+
[
102+
'--- HTTP Request ---',
103+
"GET https://example.com ",
104+
'{',
105+
' "test": "data"',
106+
'}',
107+
'',
108+
],
109+
) == caplog.records[0].message
110+
111+
112+
def test_request_logger_response(caplog):
113+
rl = RequestLogger(logging.getLogger('eaas.extension'))
114+
115+
rsp = Response()
116+
rsp.raw = HTTPResponse()
117+
118+
rsp.status_code = 200
119+
rsp.raw.reason = 'OK'
120+
121+
with caplog.at_level(logging.DEBUG):
122+
rl.log_response(rsp)
123+
124+
assert '\n'.join(
125+
[
126+
'--- HTTP Response ---',
127+
'200 OK',
128+
'',
129+
],
130+
) == caplog.records[0].message
131+
132+
rsp = Response()
133+
rsp.status_code = 200
134+
rsp.reason_phrase = 'OK'
135+
136+
with caplog.at_level(logging.DEBUG):
137+
rl.log_response(rsp)
138+
139+
assert '\n'.join(
140+
[
141+
'--- HTTP Response ---',
142+
'200 OK',
143+
'',
144+
],
145+
) == caplog.records[0].message
146+
147+
148+
def test_request_logger_response_json(mocker, caplog):
149+
json = {'id': 'XX-1234', 'name': 'XXX'}
150+
mocker.patch('requests.models.Response.json', return_value=json)
151+
152+
rl = RequestLogger(logging.getLogger('eaas.extension'))
153+
154+
rsp = Response()
155+
rsp.raw = HTTPResponse()
156+
rsp.headers = {'Content-Type': 'application/json'}
157+
rsp.status_code = 200
158+
rsp.raw.reason = 'OK'
159+
160+
with caplog.at_level(logging.DEBUG):
161+
rl.log_response(rsp)
162+
assert '\n'.join(
163+
[
164+
'--- HTTP Response ---',
165+
'200 OK',
166+
'Content-Type: application/json',
167+
'{',
168+
' "id": "XX-1234",',
169+
' "name": "XXX"',
170+
'}',
171+
'',
172+
],
173+
) == caplog.records[0].message

‎tests/test_worker.py‎

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -63,7 +63,7 @@ def get_descriptor(cls):
6363
).to_json()
6464

6565
handler = WSHandler(
66-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
66+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
6767
data_to_send,
6868
['receive', 'send'],
6969
)
@@ -144,7 +144,7 @@ def process_asset_purchase_request(self, request):
144144
]
145145

146146
handler = WSHandler(
147-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
147+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
148148
data_to_send,
149149
['receive', 'send', 'send', 'receive'],
150150
)
@@ -234,7 +234,7 @@ def process_tier_config_setup_request(self, request):
234234
]
235235

236236
handler = WSHandler(
237-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
237+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
238238
data_to_send,
239239
['receive', 'send', 'send', 'receive'],
240240
)
@@ -307,7 +307,7 @@ def get_descriptor(cls):
307307
]
308308

309309
handler = WSHandler(
310-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
310+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
311311
data_to_send,
312312
['receive', 'send', 'send'],
313313
)
@@ -362,7 +362,7 @@ def get_descriptor(cls):
362362
]
363363

364364
handler = WSHandler(
365-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
365+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
366366
data_to_send,
367367
['receive', 'send', 'send', 'send'],
368368
)
@@ -416,7 +416,7 @@ def get_descriptor(cls):
416416
]
417417

418418
handler = WSHandler(
419-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
419+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
420420
data_to_send,
421421
['receive', 'send', 'send'],
422422
)
@@ -444,7 +444,7 @@ async def test_connection_closed_error(mocker, ws_server, unused_port, caplog):
444444
},
445445
)
446446
handler = WSHandler(
447-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
447+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
448448
None,
449449
[],
450450
)
@@ -461,7 +461,7 @@ async def test_connection_closed_error(mocker, ws_server, unused_port, caplog):
461461

462462
assert (
463463
f'Disconnected from: ws://127.0.0.1:{unused_port}'
464-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002, retry in 2s'
464+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0, retry in 2s'
465465
) in caplog.text
466466

467467

@@ -480,7 +480,7 @@ async def test_connection_websocket_exception(mocker, ws_server, unused_port, ca
480480
},
481481
)
482482
handler = WSHandler(
483-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
483+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
484484
None,
485485
[],
486486
)
@@ -529,7 +529,7 @@ def get_descriptor(cls):
529529
mocker.patch('connect.eaas.worker.get_extension_type', return_value='sync')
530530

531531
handler = WSHandler(
532-
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002',
532+
'/public/v1/devops/ws/ENV-000-0001/INS-000-0002?running_tasks=0',
533533
None,
534534
['receive', 'send'],
535535
)

‎tests/utils.py‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,9 +4,13 @@
44
# Copyright (c) 2021 Ingram Micro. All Rights Reserved.
55
#
66
import asyncio
7+
import logging
78
import json
89

910

11+
logger = logging.getLogger('connect.eaas')
12+
13+
1014
class WSHandler:
1115
def __init__(self, path, data, actions):
1216
self.path = path
@@ -37,6 +41,7 @@ async def receive_data(self, ws):
3741
data = await ws.recv()
3842
if data:
3943
self.received.append(json.loads(data))
44+
logger.info(f'received: {self.received}')
4045

4146
def assert_received(self, data):
4247
assert data in self.received

0 commit comments

Comments
 (0)