Skip to content

Commit ec8109d

Browse files
leplatremleplatrem
authored
Use typed log contexts (fixes #211) (#216)
* Use typed log contexts (fixes #211) * Fix tests and validation * Add schema for requests summary * Add more constraints for context 'extra' field * Use copy() instead of `setattr()` * Forbid extra field in log contexts * Test that action and bug are logged in context
1 parent 8850bae commit ec8109d

File tree

7 files changed

+169
-113
lines changed

7 files changed

+169
-113
lines changed

‎jbi/actions/default.py

Lines changed: 47 additions & 57 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,12 @@
1212
from jbi import ActionResult, Operation
1313
from jbi.environment import get_settings
1414
from jbi.errors import ActionError
15-
from jbi.models import BugzillaBug, BugzillaWebhookRequest
15+
from jbi.models import (
16+
ActionLogContext,
17+
BugzillaBug,
18+
BugzillaWebhookRequest,
19+
JiraContext,
20+
)
1621
from jbi.services import get_bugzilla, get_jira
1722

1823
settings = get_settings()
@@ -60,10 +65,10 @@ def __call__( # pylint: disable=inconsistent-return-statements
6065
logger.debug(
6166
"Ignore event target %r",
6267
target,
63-
extra={
64-
"request": payload.dict(),
65-
"operation": Operation.IGNORE,
66-
},
68+
extra=ActionLogContext(
69+
request=payload,
70+
operation=Operation.IGNORE,
71+
).dict(),
6772
)
6873
return False, {}
6974

@@ -72,28 +77,28 @@ def comment_create_or_noop(self, payload: BugzillaWebhookRequest) -> ActionResul
7277
bug_obj = payload.bugzilla_object
7378
linked_issue_key = bug_obj.extract_from_see_also()
7479

75-
log_context = {
76-
"request": payload.dict(),
77-
"bug": bug_obj.dict(),
78-
"operation": Operation.COMMENT,
79-
"jira": {
80-
"issue": linked_issue_key,
81-
"project": self.jira_project_key,
82-
},
83-
}
80+
log_context = ActionLogContext(
81+
request=payload,
82+
bug=bug_obj,
83+
operation=Operation.COMMENT,
84+
jira=JiraContext(
85+
issue=linked_issue_key,
86+
project=self.jira_project_key,
87+
),
88+
)
8489
if not linked_issue_key:
8590
logger.debug(
8691
"No Jira issue linked to Bug %s",
8792
bug_obj.id,
88-
extra=log_context,
93+
extra=log_context.dict(),
8994
)
9095
return False, {}
9196

9297
comment = payload.map_as_jira_comment()
9398
if comment is None:
9499
logger.debug(
95100
"No matching comment found in payload",
96-
extra=log_context,
101+
extra=log_context.dict(),
97102
)
98103
return False, {}
99104

@@ -104,7 +109,7 @@ def comment_create_or_noop(self, payload: BugzillaWebhookRequest) -> ActionResul
104109
logger.debug(
105110
"Comment added to Jira issue %s",
106111
linked_issue_key,
107-
extra=log_context,
112+
extra=log_context.dict(),
108113
)
109114
return True, {"jira_response": jira_response}
110115

@@ -144,22 +149,21 @@ def bug_create_or_update(
144149
if not linked_issue_key:
145150
return self.create_and_link_issue(payload, bug_obj)
146151

147-
log_context = {
148-
"request": payload.dict(),
149-
"bug": bug_obj.dict(),
150-
"jira": {
151-
"issue": linked_issue_key,
152-
"project": self.jira_project_key,
153-
},
154-
}
152+
log_context = ActionLogContext(
153+
request=payload,
154+
bug=bug_obj,
155+
operation=Operation.LINK,
156+
jira=JiraContext(
157+
issue=linked_issue_key,
158+
project=self.jira_project_key,
159+
),
160+
)
161+
155162
logger.debug(
156163
"Update fields of Jira issue %s for Bug %s",
157164
linked_issue_key,
158165
bug_obj.id,
159-
extra={
160-
**log_context,
161-
"operation": Operation.LINK,
162-
},
166+
extra=log_context.dict(),
163167
)
164168
jira_response_update = self.jira_client.update_issue_field(
165169
key=linked_issue_key, fields=self.jira_fields(bug_obj)
@@ -172,10 +176,7 @@ def bug_create_or_update(
172176
"Create comment #%s on Jira issue %s",
173177
i + 1,
174178
linked_issue_key,
175-
extra={
176-
**log_context,
177-
"operation": Operation.COMMENT,
178-
},
179+
extra=log_context.update(operation=Operation.COMMENT).dict(),
179180
)
180181
jira_response_comments.append(
181182
self.jira_client.issue_add_comment(
@@ -191,20 +192,18 @@ def create_and_link_issue( # pylint: disable=too-many-locals
191192
self, payload, bug_obj
192193
) -> ActionResult:
193194
"""create jira issue and establish link between bug and issue; rollback/delete if required"""
194-
log_context = {
195-
"request": payload.dict(),
196-
"bug": bug_obj.dict(),
197-
"jira": {
198-
"project": self.jira_project_key,
199-
},
200-
}
195+
log_context = ActionLogContext(
196+
request=payload,
197+
bug=bug_obj,
198+
operation=Operation.CREATE,
199+
jira=JiraContext(
200+
project=self.jira_project_key,
201+
),
202+
)
201203
logger.debug(
202204
"Create new Jira issue for Bug %s",
203205
bug_obj.id,
204-
extra={
205-
**log_context,
206-
"operation": Operation.CREATE,
207-
},
206+
extra=log_context.dict(),
208207
)
209208
comment_list = self.bugzilla_client.get_comments(idlist=[bug_obj.id])
210209
description = comment_list["bugs"][str(bug_obj.id)]["comments"][0]["text"][
@@ -235,7 +234,7 @@ def create_and_link_issue( # pylint: disable=too-many-locals
235234

236235
jira_key_in_response = jira_response_create.get("key")
237236

238-
log_context["jira"]["issue"] = jira_key_in_response
237+
log_context.jira.issue = jira_key_in_response
239238

240239
# In the time taken to create the Jira issue the bug may have been updated so
241240
# re-retrieve it to ensure we have the latest data.
@@ -250,10 +249,7 @@ def create_and_link_issue( # pylint: disable=too-many-locals
250249
"Delete duplicated Jira issue %s from Bug %s",
251250
jira_key_in_response,
252251
bug_obj.id,
253-
extra={
254-
**log_context,
255-
"operation": Operation.DELETE,
256-
},
252+
extra=log_context.update(operation=Operation.DELETE).dict(),
257253
)
258254
jira_response_delete = self.jira_client.delete_issue(
259255
issue_id_or_key=jira_key_in_response
@@ -265,10 +261,7 @@ def create_and_link_issue( # pylint: disable=too-many-locals
265261
"Link %r on Bug %s",
266262
jira_url,
267263
bug_obj.id,
268-
extra={
269-
**log_context,
270-
"operation": Operation.LINK,
271-
},
264+
extra=log_context.update(operation=Operation.LINK).dict(),
272265
)
273266
update = self.bugzilla_client.build_update(see_also_add=jira_url)
274267
bugzilla_response = self.bugzilla_client.update_bugs([bug_obj.id], update)
@@ -278,10 +271,7 @@ def create_and_link_issue( # pylint: disable=too-many-locals
278271
"Link %r on Jira issue %s",
279272
bugzilla_url,
280273
jira_key_in_response,
281-
extra={
282-
**log_context,
283-
"operation": Operation.LINK,
284-
},
274+
extra=log_context.update(operation=Operation.LINK).dict(),
285275
)
286276
jira_response = self.jira_client.create_or_update_issue_remote_links(
287277
issue_key=jira_key_in_response,

‎jbi/actions/default_with_assignee_and_status.py

Lines changed: 28 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,12 @@
1414
JIRA_REQUIRED_PERMISSIONS as DEFAULT_JIRA_REQUIRED_PERMISSIONS,
1515
)
1616
from jbi.actions.default import DefaultExecutor
17-
from jbi.models import BugzillaBug, BugzillaWebhookRequest
17+
from jbi.models import (
18+
ActionLogContext,
19+
BugzillaBug,
20+
BugzillaWebhookRequest,
21+
JiraContext,
22+
)
1823

1924
logger = logging.getLogger(__name__)
2025

@@ -53,25 +58,23 @@ def update_issue(
5358
):
5459
changed_fields = payload.event.changed_fields() or []
5560

56-
log_context = {
57-
"bug": {
58-
"id": bug_obj.id,
59-
"status": bug_obj.status,
60-
"resolution": bug_obj.resolution,
61-
"assigned_to": bug_obj.assigned_to,
62-
},
63-
"jira": {
64-
"issue": linked_issue_key,
65-
"project": self.jira_project_key,
61+
log_context = ActionLogContext(
62+
request=payload,
63+
bug=bug_obj,
64+
operation=Operation.UPDATE,
65+
jira=JiraContext(
66+
project=self.jira_project_key,
67+
issue=linked_issue_key,
68+
),
69+
extra={
70+
"changed_fields": ", ".join(changed_fields),
6671
},
67-
"changed_fields": changed_fields,
68-
"operation": Operation.UPDATE,
69-
}
72+
)
7073

7174
def clear_assignee():
7275
# New tickets already have no assignee.
7376
if not is_new:
74-
logger.debug("Clearing assignee", extra=log_context)
77+
logger.debug("Clearing assignee", extra=log_context.dict())
7578
self.jira_client.update_issue_field(
7679
key=linked_issue_key, fields={"assignee": None}
7780
)
@@ -84,7 +87,7 @@ def clear_assignee():
8487
else:
8588
logger.debug(
8689
"Attempting to update assignee",
87-
extra=log_context,
90+
extra=log_context.dict(),
8891
)
8992
# Look up this user in Jira
9093
users = self.jira_client.user_find_by_user_string(
@@ -101,15 +104,17 @@ def clear_assignee():
101104
)
102105
except IOError as exception:
103106
logger.debug(
104-
"Setting assignee failed: %s", exception, extra=log_context
107+
"Setting assignee failed: %s",
108+
exception,
109+
extra=log_context.dict(),
105110
)
106111
# If that failed then just fall back to clearing the
107112
# assignee.
108113
clear_assignee()
109114
else:
110115
logger.debug(
111116
"No assignee found",
112-
extra={**log_context, "operation": Operation.IGNORE},
117+
extra=log_context.update(operation=Operation.IGNORE).dict(),
113118
)
114119
clear_assignee()
115120

@@ -123,17 +128,16 @@ def clear_assignee():
123128
logger.debug(
124129
"Updating Jira status to %s",
125130
self.status_map[status],
126-
extra=log_context,
131+
extra=log_context.dict(),
127132
)
128133
self.jira_client.set_issue_status(
129134
linked_issue_key, self.status_map[status]
130135
)
131136
else:
132137
logger.debug(
133138
"Bug status was not in the status map.",
134-
extra={
135-
**log_context,
136-
"status_map": self.status_map,
137-
"operation": Operation.IGNORE,
138-
},
139+
extra=log_context.update(
140+
operation=Operation.IGNORE,
141+
extra={**log_context.extra, "status_map": self.status_map},
142+
).dict(),
139143
)

‎jbi/log.py

Lines changed: 25 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
from datetime import datetime
99

1010
from fastapi import Request
11+
from pydantic import BaseModel
1112

1213
from jbi.environment import get_settings
1314

@@ -43,21 +44,33 @@
4344
}
4445

4546

47+
class RequestSummary(BaseModel):
48+
"""Request summary as specified by MozLog format"""
49+
50+
agent: str
51+
path: str
52+
method: str
53+
querystring: str
54+
errno: int
55+
t: int
56+
time: str
57+
status_code: int
58+
59+
4660
def format_request_summary_fields(
4761
request: Request, request_time: float, status_code: int
4862
) -> dict:
4963
"""Prepare Fields for Mozlog request summary"""
5064

5165
current_time = time.time()
52-
fields = {
53-
"agent": request.headers.get("User-Agent"),
54-
"path": request.url.path,
55-
"method": request.method,
56-
"lang": request.headers.get("Accept-Language"),
57-
"querystring": str(dict(request.query_params)),
58-
"errno": 0,
59-
"t": int((current_time - request_time) * 1000.0),
60-
"time": datetime.fromtimestamp(current_time).isoformat(),
61-
"status_code": status_code,
62-
}
63-
return fields
66+
return RequestSummary(
67+
agent=request.headers.get("User-Agent"),
68+
path=request.url.path,
69+
method=request.method,
70+
lang=request.headers.get("Accept-Language"),
71+
querystring=str(dict(request.query_params)),
72+
errno=0,
73+
t=int((current_time - request_time) * 1000.0),
74+
time=datetime.fromtimestamp(current_time).isoformat(),
75+
status_code=status_code,
76+
).dict()

0 commit comments

Comments
 (0)