Skip to content

src: lava_callback: improve logging #1159

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
May 21, 2025
Merged

src: lava_callback: improve logging #1159

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion docker-compose-production.yaml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ services:

lava-callback:
# With uWSGI in socket mode, to use with reverse proxy e.g. Nginx and SSL
command: uvicorn lava_callback:app --host 0.0.0.0 --port 8000 --app-dir /home/kernelci/pipeline/
command: uvicorn lava_callback:app --host 0.0.0.0 --port 8000 --app-dir /home/kernelci/pipeline/ --log-level debug
#command:
# - '/usr/local/bin/uwsgi'
# - '--master'
Expand Down
37 changes: 19 additions & 18 deletions src/lava_callback.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@

app = FastAPI()
executor = ThreadPoolExecutor(max_workers=16)
logger = logging.getLogger('uvicorn.error')


class ManualCheckout(BaseModel):
Expand Down Expand Up @@ -200,7 +201,7 @@ def async_job_submit(api_helper, node_id, job_callback):
job_node = api_helper.api.node.get(node_id)
if not job_node:
metrics.add('lava_callback_late_fail_total', 1)
logging.error(f'Node {node_id} not found')
logger.error(f'Node {node_id} not found')
return
# TODO: Verify lab_name matches job node lab name
# Also extract job_id and compare with node job_id (future)
Expand All @@ -215,14 +216,14 @@ def async_job_submit(api_helper, node_id, job_callback):
log_txt_url = _upload_log(log_parser, job_node, storage)
if log_txt_url:
job_node['artifacts']['lava_log'] = log_txt_url
print(f"Log uploaded to {log_txt_url}")
logger.info(f"Log uploaded to {log_txt_url}")
else:
print("Failed to upload log")
logger.warning("Failed to upload log")
metrics.add('lava_callback_late_fail_total', 1)
callback_json_url = _upload_callback_data(callback_data, job_node, storage)
if callback_json_url:
job_node['artifacts']['callback_data'] = callback_json_url
print(f"Callback data uploaded to {callback_json_url}")
logger.info(f"Callback data uploaded to {callback_json_url}")
else:
metrics.add('lava_callback_late_fail_total', 1)
# failed LAVA job should have result set to 'incomplete'
Expand Down Expand Up @@ -282,7 +283,7 @@ async def callback(node_id: str, request: Request):
try:
data = await request.json()
except Exception as e:
logging.error(f'Error decoding JSON: {e}')
logger.error(f'Error decoding JSON: {e}')
item = {}
item['message'] = 'Error decoding JSON'
return JSONResponse(content=item, status_code=400)
Expand All @@ -306,7 +307,7 @@ def decode_jwt(jwtstr):
'''
secret = SETTINGS.get('jwt', {}).get('secret')
if not secret:
logging.error('No JWT secret configured')
logger.error('No JWT secret configured')
return None
return jwt.decode(jwtstr, secret, algorithms=['HS256'])

Expand All @@ -317,17 +318,17 @@ def validate_permissions(jwtoken, permission):
try:
decoded = decode_jwt(jwtoken)
except Exception as e:
logging.error(f'Error decoding JWT: {e}')
logger.error(f'Error decoding JWT: {e}')
return False
if not decoded:
logging.error('Invalid JWT')
logger.error('Invalid JWT')
return False
permissions = decoded.get('permissions')
if not permissions:
logging.error('No permissions in JWT')
logger.error('No permissions in JWT')
return False
if permission not in permissions:
logging.error(f'Permission {permission} not in JWT')
logger.error(f'Permission {permission} not in JWT')
return False
return decoded

Expand Down Expand Up @@ -388,7 +389,7 @@ async def jobretry(data: JobRetry, request: Request,
return JSONResponse(content=item, status_code=401)

email = decoded.get('email')
logging.info(f"User {email} is retrying job {data.nodeid}")
logger.info(f"User {email} is retrying job {data.nodeid}")
api_config_name = SETTINGS.get('DEFAULT', {}).get('api_config')
if not api_config_name:
item['message'] = 'No default API name set'
Expand All @@ -398,7 +399,7 @@ async def jobretry(data: JobRetry, request: Request,
try:
node = api_helper.api.node.get(data.nodeid)
except Exception as e:
logging.error(f'Error getting node {data.nodeid}: {e}')
logger.error(f'Error getting node {data.nodeid}: {e}')
item['message'] = 'Error getting node'
return JSONResponse(content=item, status_code=500)
if not node:
Expand Down Expand Up @@ -437,7 +438,7 @@ async def jobretry(data: JobRetry, request: Request,
evnode = {'data': knode}
# Now we can submit custom kbuild node to the API(pub/sub)
api_helper.api.send_event('node', evnode)
logging.info(f"Job retry for node {data.nodeid} submitted")
logger.info(f"Job retry for node {data.nodeid} submitted")
item['message'] = 'OK'
return JSONResponse(content=item, status_code=200)

Expand Down Expand Up @@ -524,7 +525,7 @@ async def checkout(data: ManualCheckout, request: Request,
item['message'] = 'Unauthorized'
return JSONResponse(content=item, status_code=401)

logging.info(f"User {email} is checking out {data.nodeid} at custom commit {data.commit}")
logger.info(f"User {email} is checking out {data.nodeid} at custom commit {data.commit}")
api_config_name = SETTINGS.get('DEFAULT', {}).get('api_config')
if not api_config_name:
item['message'] = 'No default API name set'
Expand Down Expand Up @@ -630,7 +631,7 @@ async def checkout(data: ManualCheckout, request: Request,
item['message'] = 'Failed to submit checkout node'
return JSONResponse(content=item, status_code=500)
else:
logging.info(f"Checkout node {r['id']} submitted")
logger.info(f"Checkout node {r['id']} submitted")
item['message'] = 'OK'
item['node'] = r
return JSONResponse(content=item, status_code=200)
Expand Down Expand Up @@ -659,7 +660,7 @@ async def patchset(data: PatchSet, request: Request,
item['message'] = 'Unauthorized'
return JSONResponse(content=item, status_code=401)

logging.info(f"User {email} is testing patchset on {data.nodeid}")
logger.info(f"User {email} is testing patchset on {data.nodeid}")
api_config_name = SETTINGS.get('DEFAULT', {}).get('api_config')
if not api_config_name:
item['message'] = 'No default API name set'
Expand Down Expand Up @@ -733,7 +734,7 @@ async def patchset(data: PatchSet, request: Request,
item['message'] = 'Failed to submit patchset node'
return JSONResponse(content=item, status_code=500)
else:
logging.info(f"Patchset node {r['id']} submitted")
logger.info(f"Patchset node {r['id']} submitted")
item['message'] = 'OK'
item['node'] = r
return JSONResponse(content=item, status_code=200)
Expand Down Expand Up @@ -766,4 +767,4 @@ async def apimetrics():
api_token = os.getenv('KCI_API_TOKEN')
if not api_token:
print('No API token set')
uvicorn.run(app, host='0.0.0.0', port=8000)
uvicorn.run(app, host='0.0.0.0', port=8000, log_level="debug")