Skip to content

Commit e8ec62e

Browse files
Essozclaude
andcommitted
fix: silence instrumentor noise during traincheck-collect
- collect_trace: use force=True + WARNING default level so basicConfig format actually applies and INFO chatter is suppressed at runtime - source_file: demote all annotate_stage insertion logger.info → debug - dumper: demote attribute-dump failure logger.warning → debug (torch internals routinely fail, not actionable) - call_graph_parser: convert all print() → logger.debug(); add logger Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
1 parent 09c9ea7 commit e8ec62e

4 files changed

Lines changed: 22 additions & 21 deletions

File tree

traincheck/collect_trace.py

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -431,13 +431,13 @@ def main():
431431
if args.warm_up_steps is None:
432432
args.warm_up_steps = config.INSTRUMENTATION_POLICY["warm_up"]
433433

434-
# set up logging
434+
# set up logging (force=True overrides any handler already added by imported libs)
435435
_log_fmt = "[TrainCheck] %(levelname)s: %(message)s"
436436
if args.debug_mode:
437-
logging.basicConfig(level=logging.DEBUG, format=_log_fmt)
437+
logging.basicConfig(level=logging.DEBUG, format=_log_fmt, force=True)
438438
os.environ["TRAINCHECK_DEBUG"] = "1"
439439
else:
440-
logging.basicConfig(level=logging.INFO, format=_log_fmt)
440+
logging.basicConfig(level=logging.WARNING, format=_log_fmt, force=True)
441441

442442
logger = logging.getLogger(__name__)
443443

traincheck/instrumentor/dumper.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -392,7 +392,7 @@ def convert_var_to_dict(var, include_tensor_data=True, dump_config=None) -> dict
392392
and isinstance(var, torch.Tensor)
393393
and not include_tensor_data
394394
):
395-
logger.warning(
395+
logger.debug(
396396
f"Failed to get attribute {attr_name} of object type {type(var)}, skipping it for all following dumps for this attribute."
397397
)
398398
if var_type not in skip_attrs_due_to_errs:

traincheck/instrumentor/source_file.py

Lines changed: 8 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -736,7 +736,7 @@ def has_stage(src: str, name: str) -> bool:
736736

737737
for stage_name, present in orig_has.items():
738738
if present:
739-
logger.info(
739+
logger.debug(
740740
_ctx(
741741
f"Stage '{stage_name}' already present in source; skip adding this stage."
742742
)
@@ -819,13 +819,13 @@ def at_attr(name: str) -> bool:
819819
indent = m.group(0)
820820
new_lines.append(f'{indent}annotate_stage("{stage}")\n')
821821
inserted_count[stage] += 1
822-
logger.info(
822+
logger.debug(
823823
_ctx(
824824
f"Inserted stage '{stage}' before line {lineno}: {line.strip()}"
825825
)
826826
)
827827
else:
828-
logger.info(
828+
logger.debug(
829829
_ctx(
830830
f"Skip inserting '{stage}' at line {lineno} (previous non-empty line already has it)."
831831
)
@@ -858,7 +858,7 @@ def _find_annotate_import_idx(lines):
858858
lines_list.insert(insert_idx, "from traincheck import annotate_stage\n")
859859
annot_import_idx = insert_idx
860860
inserted_count["import"] += 1
861-
logger.info(
861+
logger.debug(
862862
_ctx(
863863
f"Inserted import 'from traincheck import annotate_stage' at line {annot_import_idx + 1}."
864864
)
@@ -917,13 +917,13 @@ def is_single_line_triple_quoted_string(line: str, quote: str) -> bool:
917917
if not (("annotate_stage" in prev) and ("init" in prev)):
918918
nl.insert(insert_at, f'{body_indent}annotate_stage("init")\n')
919919
inserted_count["init"] += 1
920-
logger.info(
920+
logger.debug(
921921
_ctx(
922922
f"Inserted stage 'init' at start of main() body (line {insert_at + 1})."
923923
)
924924
)
925925
else:
926-
logger.info(
926+
logger.debug(
927927
_ctx(
928928
"Skip inserting 'init' inside main(): previous non-empty line already has it."
929929
)
@@ -966,13 +966,13 @@ def is_single_line_triple_quoted_string(line: str, quote: str) -> bool:
966966
if not (("annotate_stage" in next_line) and ("init" in next_line)):
967967
lines2.insert(insert_at, 'annotate_stage("init")\n')
968968
inserted_count["init"] += 1
969-
logger.info(
969+
logger.debug(
970970
_ctx(
971971
f"Inserted stage 'init' right after annotate_stage import at line {insert_at + 1}."
972972
)
973973
)
974974
else:
975-
logger.info(
975+
logger.debug(
976976
_ctx(
977977
"Skip inserting 'init': next non-empty line after annotate_stage import is already init."
978978
)

traincheck/static_analyzer/graph_generator/call_graph_parser.py

Lines changed: 10 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,14 @@
11
## Step 1: filer out the lines from func_level.log with the format <Node function:module_name.function_name> - function_depth, e.g. <Node function:torch.optim.lr_scheduler._format_param._copy> - 2
22

33
import importlib
4+
import logging
45
import os
56
import re
67

78
from traincheck.instrumentor.proxy_wrapper.proxy_observer import add_observer_to_func
89

10+
logger = logging.getLogger(__name__)
11+
912

1013
def unparse_module(module_name, level=0):
1114
if level > 3:
@@ -19,10 +22,9 @@ def unparse_module(module_name, level=0):
1922
last_name = module_name.split(".")[-1]
2023
try:
2124
func_obj = getattr(module, last_name)
22-
# print(f"object {last_name} found in module {'.'.join(module_name.split('.')[:-1])}")
2325
return func_obj
2426
except AttributeError:
25-
print(
27+
logger.debug(
2628
f"object {last_name} not found in module {'.'.join(module_name.split('.')[:-1])}"
2729
)
2830
# Ziming: from out observation this typically just mean a function call contains a local class or function call, so we can just pass
@@ -39,7 +41,9 @@ def add_observer(module_name, function_name, observe_then_unproxy=False):
3941
# module could be a class here, load the class and get the function
4042
module = unparse_module(module_name)
4143
if module is None:
42-
print(f"error finding {function_name}: module {module_name} not found")
44+
logger.debug(
45+
f"error finding {function_name}: module {module_name} not found"
46+
)
4347

4448
try:
4549
# Retrieve the function or property
@@ -48,23 +52,22 @@ def add_observer(module_name, function_name, observe_then_unproxy=False):
4852

4953
# Check if it's a property before proceeding
5054
if isinstance(function, property):
51-
print(
55+
logger.debug(
5256
f"Skipping property function: {function_name} in module: {module_name}"
5357
)
5458
return
5559

5660
# Apply observer to non-property functions
57-
print(f"Observe function: {function_name} found in module: {module}")
61+
logger.debug(f"Observe function: {function_name} found in module: {module}")
5862
setattr(
5963
module,
6064
function_name,
6165
add_observer_to_func(function, observe_then_unproxy),
6266
)
6367

6468
except AttributeError:
65-
print(f"function {function_name} not found in module {module_name}")
69+
logger.debug(f"function {function_name} not found in module {module_name}")
6670
return
67-
# print(f'function: {function} found in module: {module}')
6871

6972

7073
# read the func_level.log file
@@ -104,11 +107,9 @@ def add_observer_given_call_graph(
104107
# save those with function_depth <= depth
105108
if observe_up_to_depth:
106109
if int(function_depth) <= depth:
107-
# print(f'module_name: {module_name}, function_name: {function_name}, function_depth: {function_depth}')
108110
add_observer(module_name, function_name, observe_then_unproxy)
109111
else:
110112
if int(function_depth) == depth:
111-
# print(f'module_name: {module_name}, function_name: {function_name}, function_depth: {function_depth}')
112113
add_observer(module_name, function_name, observe_then_unproxy)
113114

114115

0 commit comments

Comments
 (0)