def process_mdc(step, name):
log_util.add_update_mdc_key_value_in_task("process_stage_name", name)
log_util.add_update_mdc_key_value_in_task("process_stage_step", step)
logger.info(step + ": " + name)
# Remove the fields now
log_util.remove_mdc_key_in_task("process_stage_step")
log_util.remove_mdc_key_in_task("process_stage_name")
def process_mdc(step, name):
log_util.add_update_mdc_key_value_in_task("process_stage_name", name)
log_util.add_update_mdc_key_value_in_task("process_stage_step", step)
# set the logger to what we want
current_logger_name = getattr(asyncio.current_task(), "loggerName", None)
# NCL-7133: use different logger name for process stage update
asyncio.current_task(
).loggerName = "org.jboss.pnc._userlog_.process-stage-update"
logger.info(step + ": " + name)
if current_logger_name:
asyncio.current_task().loggerName = current_logger_name
# Remove the fields now
log_util.remove_mdc_key_in_task("process_stage_step")
log_util.remove_mdc_key_in_task("process_stage_name")
async def handler(request):
c = await config.get_configuration()
log_context = request.headers.get("LOG-CONTEXT", "").strip()
if log_context == "":
log_context = create_log_context_id()
log_user_id = request.headers.get("log-user-id", "").strip()
log_request_context = request.headers.get("log-request-context",
"").strip()
log_process_context = request.headers.get("log-process-context",
"").strip()
log_expires = request.headers.get("log-expires", "").strip()
log_tmp = request.headers.get("log-tmp", "").strip()
callback_id = create_callback_id()
asyncio.Task.current_task().log_context = log_context
log_util.add_update_mdc_key_value_in_task("userId", log_user_id)
log_util.add_update_mdc_key_value_in_task("requestContext",
log_request_context)
log_util.add_update_mdc_key_value_in_task("processContext",
log_process_context)
log_util.add_update_mdc_key_value_in_task("expires", log_expires)
log_util.add_update_mdc_key_value_in_task("tmp", log_tmp)
asyncio.Task.current_task().callback_id = callback_id
try:
spec = await request.json()
except ValueError:
logger.error(
"Rejected {method} {path}: body is not parsable as json".
format(method=request.method, path=request.path))
rejected_data = await request.text()
ERROR_VALIDATION_JSON_COUNTER.inc()
logger.error("Request data: {data}".format(data=rejected_data))
return web.Response(
status=400,
content_type="application/json",
text=json.dumps(
obj=[{
"error_message": "expected json",
"error_type": "json parsability",
"path": [],
}],
ensure_ascii=False,
),
)
try:
validator(spec)
except voluptuous.MultipleInvalid as x:
logger.error(
"Rejected {method} {path}: body failed input validation".
format(method=request.method, path=request.path))
ERROR_VALIDATION_JSON_COUNTER.inc()
logger.error("Request data: {data}".format(data=spec))
return web.Response(
status=400,
content_type="application/json",
text=json.dumps(obj=[e.__dict__ for e in x.errors],
ensure_ascii=False),
)
logger.info("Accepted {method} {path}: {params}".format(
method=request.method, path=request.path, params=spec))
try:
validation.callback(spec)
except voluptuous.MultipleInvalid as x:
callback_mode = False
else:
callback_mode = True
# Set the task_id if provided in the request
task_id = spec.get("taskId", None)
if task_id:
asyncio.Task.current_task().task_id = task_id
async def do_call():
try:
ret = await coro(spec, **request.app)
except cfutures.CancelledError as e:
# do nothing else
logger.info("Cancellation request received")
raise e
except exception.DescribedError as e:
status = 400
traceback_id, obj = described_error_to_obj(e)
ERROR_RESPONSE_400_COUNTER.inc()
logger.error(
"Failed ({e.__class__.__name__}), traceback hash: {traceback_id}"
.format(**locals()))
log_traceback_multi_line()
except Exception as e:
status = 500
traceback_id, obj = exception_to_obj(e)
ERROR_RESPONSE_500_COUNTER.inc()
logger.error(
"Internal failure ({e.__class__.__name__}), traceback hash: {traceback_id}"
.format(**locals()))
log_traceback_multi_line()
else:
status = 200
obj = ret
logger.info("Completed ok")
log_file = file_callback_log.get_callback_log_path(callback_id)
logs = ""
if os.path.isfile(log_file):
with open(log_file, "r") as f:
logs = f.read()
obj["log"] = logs
return status, obj
if callback_mode:
async def do_callback(callback_spec):
status, obj = await do_call()
obj["callback"] = {"status": status, "id": callback_id}
logger.info("Callback data: {}".format(obj))
@time(REQ_TIME)
@time(REQ_HISTOGRAM_TIME)
async def send_result():
try:
# TODO refactor this into auth.py, we cannot use middleware for callbacks
headers = {}
current_task = asyncio.Task.current_task()
auth_provider = c.get("auth", {}).get("provider", None)
if auth_provider == "oauth2_jwt" and request.headers.get(
"Authorization", None):
auth_header = {
"Authorization":
request.headers["Authorization"]
}
context_headers = {
"log-user-id":
current_task.mdc["userId"],
"log-request-context":
current_task.mdc["requestContext"],
"log-process-context":
current_task.mdc["processContext"],
"log-expires":
current_task.mdc["expires"],
"log_tmp":
current_task.mdc["tmp"],
}
logger.debug(
"Authorization enabled, adding header to callback: "
+ str(auth_header))
headers.update(auth_header)
headers.update(context_headers)
resp = await client_session.request(
callback_spec.get("method", "POST"),
callback_spec["url"],
headers=headers,
data=json.dumps(
obj=obj, ensure_ascii=False).encode("utf-8"),
)
except Exception as e:
ERROR_CALLBACK_COUNTER.inc()
logger.error(
"Unable to send result of callback, exception {ename}, attempt {backoff}/{max_attempts}"
.format(
ename=e.__class__.__name__,
backoff=backoff,
max_attempts=max_attempts,
))
logger.error(e)
resp = None
return resp
backoff = 1
max_attempts = 9
resp = await send_result()
while resp is None or resp.status // 100 != 2:
if resp is not None:
logger.info(
"Unable to send result of callback, status {resp.status}, attempt {backoff}/{max_attempts}"
.format(**locals()))
sleep_period = 2**backoff
logger.debug(
"Sleeping for {sleep_period}".format(**locals()))
await asyncio.sleep(sleep_period)
backoff += 1
if backoff > max_attempts:
logger.error(
"Giving up on callback after {max_attempts} attempts"
.format(**locals()))
break
resp = await send_result()
if backoff <= max_attempts:
logger.info("Callback result sent successfully")
logger.info(
"Creating callback task {callback_id}, returning ID now".
format(**locals()))
callback_task = request.app.loop.create_task(
do_callback(spec["callback"]))
callback_task.log_context = log_context
callback_task.mdc = asyncio.Task.current_task().mdc
callback_task.callback_id = callback_id
# Set the task_id if provided in the request
task_id = spec.get("taskId", None)
if task_id:
callback_task.task_id = task_id
status = 202
obj = {
"callback": {
"id": callback_id,
"websocket":
"ws://" + repour_url + "/callback/" + callback_id,
}
}
else:
status, obj = await do_call()
response = web.Response(
status=status,
content_type="application/json",
text=json.dumps(obj=obj, ensure_ascii=False),
)
return response