Andal.LND/edx-platform
6
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

feat: Improve codejail darklaunch logging (#36671)

Browse Source 
This is intended to make logs more or less a standalone source for
analyzing mismatches.

- Only log mismatches or exceptions
- Merge local and remote log messages into one so they can be correlated
  more easily
- Different log messages for mismatch vs. unexpected exceptions
- Include course ID (as limit overrides context) in log message
This commit is contained in:
Tim McCormack
2025-05-06 16:42:55 -04:00
committed by GitHub
parent 0d20b49d17
commit 5bc05810dc
2 changed files with 45 additions and 42 deletions
Download Patch File Download Diff File Expand all files Collapse all files

35
xmodule/capa/safe_exec/safe_exec.py
View File

@@ -272,7 +272,7 @@ def safe_exec(
local_exc_unexpected = None if isinstance(exception, SafeExecException) else exception
report_darklaunch_results(
slug=slug,
limit_overrides_context=limit_overrides_context, slug=slug,
globals_local=globals_dict, emsg_local=emsg, unexpected_exc_local=local_exc_unexpected,
globals_remote=darklaunch_globals, emsg_remote=remote_emsg, unexpected_exc_remote=remote_exception,
)
@@ -347,14 +347,19 @@ def normalize_error_message(emsg):
def report_darklaunch_results(
*, slug,
*, limit_overrides_context, slug,
globals_local, emsg_local, unexpected_exc_local,
globals_remote, emsg_remote, unexpected_exc_remote,
):
"""Send telemetry for results of darklaunch."""
can_compare_output = True
def report_arm(arm, globals_dict, emsg, unexpected_exception):
def report_arm(arm, emsg, unexpected_exception):
"""
Set custom attributes for each arm of the darklaunch experiment.
`arm` should be 'local' or 'remote'.
"""
nonlocal can_compare_output
if unexpected_exception:
# .. custom_attribute_name: codejail.darklaunch.status.{local,remote}
@@ -373,25 +378,33 @@ def report_darklaunch_results(
set_custom_attribute(f'codejail.darklaunch.status.{arm}', 'ok' if emsg is None else 'safe_error')
set_custom_attribute(f'codejail.darklaunch.exception.{arm}', None)
# Logs include full globals and emsg
log.info(
f"Codejail darklaunch {arm} results for slug={slug}: globals={globals_dict!r}, "
f"emsg={emsg!r}, exception={unexpected_exception!r}"
)
report_arm('local', globals_local, emsg_local, unexpected_exc_local)
report_arm('remote', globals_remote, emsg_remote, unexpected_exc_remote)
report_arm('local', emsg_local, unexpected_exc_local)
report_arm('remote', emsg_remote, unexpected_exc_remote)
# If the arms can't be compared (unexpected errors), stop early -- the rest
# is about output comparison.
if not can_compare_output:
set_custom_attribute('codejail.darklaunch.globals_match', 'N/A')
set_custom_attribute('codejail.darklaunch.emsg_match', 'N/A')
log.info(
"Codejail darklaunch had unexpected exception for "
f"course={limit_overrides_context!r}, slug={slug!r}:\n"
f"Local exception: {unexpected_exc_local!r}\n"
f"Remote exception: {unexpected_exc_remote!r}"
)
return
globals_match = globals_local == globals_remote
emsg_match = normalize_error_message(emsg_local) == normalize_error_message(emsg_remote)
if not globals_match or not emsg_match:
log.info(
f"Codejail darklaunch had mismatch for course={limit_overrides_context!r}, slug={slug!r}:\n"
f"{emsg_match=}, {globals_match=}\n"
f"Local: globals={globals_local!r}, emsg={emsg_local!r}\n"
f"Remote: globals={globals_remote!r}, emsg={emsg_remote!r}"
)
# .. custom_attribute_name: codejail.darklaunch.globals_match
# .. custom_attribute_description: True if local and remote globals_dict
# values match, False otherwise. 'N/A' when either arm raised an

52
xmodule/capa/safe_exec/tests/test_safe_exec.py
View File

@@ -195,7 +195,10 @@ class TestCodeJailDarkLaunch(unittest.TestCase):
mock_remote_exec.side_effect = remote
try:
safe_exec("<IGNORED BY MOCKS>", globals_dict)
safe_exec(
"<IGNORED BY MOCKS>", globals_dict,
limit_overrides_context="course-v1:org+course+run", slug="hw1",
)
except BaseException as e:
safe_exec_e = e
else:
@@ -215,8 +218,8 @@ class TestCodeJailDarkLaunch(unittest.TestCase):
# These don't change between the tests
standard_codejail_attr_calls = [
call('codejail.slug', None),
call('codejail.limit_overrides_context', None),
call('codejail.slug', 'hw1'),
call('codejail.limit_overrides_context', 'course-v1:org+course+run'),
call('codejail.extra_files_count', 0),
]
@@ -256,12 +259,11 @@ class TestCodeJailDarkLaunch(unittest.TestCase):
],
expect_log_info_calls=[
call(
"Codejail darklaunch local results for slug=None: globals={'overwrite': 'mock local'}, "
"emsg=None, exception=None"
),
call(
"Codejail darklaunch remote results for slug=None: globals={'overwrite': 'mock remote'}, "
"emsg=None, exception=None"
"Codejail darklaunch had mismatch for "
"course='course-v1:org+course+run', slug='hw1':\n"
"emsg_match=True, globals_match=False\n"
"Local: globals={'overwrite': 'mock local'}, emsg=None\n"
"Remote: globals={'overwrite': 'mock remote'}, emsg=None"
),
],
# Should only see behavior of local exec
@@ -296,12 +298,10 @@ class TestCodeJailDarkLaunch(unittest.TestCase):
],
expect_log_info_calls=[
call(
"Codejail darklaunch local results for slug=None: globals={}, "
"emsg='unexpected', exception=BaseException('unexpected')"
),
call(
"Codejail darklaunch remote results for slug=None: globals={}, "
"emsg=None, exception=None"
"Codejail darklaunch had unexpected exception "
"for course='course-v1:org+course+run', slug='hw1':\n"
"Local exception: BaseException('unexpected')\n"
"Remote exception: None"
),
],
expect_globals_contains={},
@@ -332,12 +332,11 @@ class TestCodeJailDarkLaunch(unittest.TestCase):
],
expect_log_info_calls=[
call(
"Codejail darklaunch local results for slug=None: globals={}, "
"emsg='oops', exception=None"
),
call(
"Codejail darklaunch remote results for slug=None: globals={}, "
"emsg='OH NO', exception=None"
"Codejail darklaunch had mismatch for "
"course='course-v1:org+course+run', slug='hw1':\n"
"emsg_match=False, globals_match=True\n"
"Local: globals={}, emsg='oops'\n"
"Remote: globals={}, emsg='OH NO'"
),
],
expect_globals_contains={},
@@ -365,16 +364,7 @@ class TestCodeJailDarkLaunch(unittest.TestCase):
call('codejail.darklaunch.globals_match', True),
call('codejail.darklaunch.emsg_match', True), # even though not exact match
],
expect_log_info_calls=[
call(
"Codejail darklaunch local results for slug=None: globals={}, "
"emsg='stack trace involving /tmp/codejail-1234567/whatever.py', exception=None"
),
call(
"Codejail darklaunch remote results for slug=None: globals={}, "
"emsg='stack trace involving /tmp/codejail-abcd_EFG/whatever.py', exception=None"
),
],
expect_log_info_calls=[],
expect_globals_contains={},
)
assert isinstance(results['raised'], SafeExecException)