Skills Logging and Debugging Advanced
Basic debugging relies on print, advanced debugging relies on systematic logging mechanisms.
This article introduces how to establish structured logging for Skill scripts, as well as advanced techniques for locating problems in complex execution flows.
Replace print with logging
printSuitable for quick debugging, but in production Skills you should switch to Python's standard libraryloggingmodule.
The advantage of logging is that you can control the output level — output DEBUG information during development, and only WARNING and above in production.
Example
# File path: scripts/logger_setup.py
import logging
import sys
from datetime import datetime
def get_logger(name: str, level: str = "INFO") -> logging.Logger:
"""
Create a structured logger
Parameters:
name: Logger name, usually the module name (__name__)
level: Log level, DEBUG / INFO / WARNING / ERROR
"""
logger = logging.getLogger(name)
logger.setLevel(getattr(logging, level.upper(), logging.INFO))
# Avoid adding handlers repeatedly
if logger.handlers:
return logger
# Console output: human-readable format
console = logging.StreamHandler(sys.stdout)
console.setFormatter(logging.Formatter(
"[%(asctime)s] [%(levelname)s] %(name)s - %(message)s",
datefmt="%H:%M:%S"
))
logger.addHandler(console)
# File output: write to log file (optional)
log_file = f"/home/claude/skill_{datetime.now().strftime('%Y%m%d')}.log"
file_handler = logging.FileHandler(log_file, encoding="utf-8")
file_handler.setFormatter(logging.Formatter(
"%(asctime)s [%(levelname)s] %(name)s:%(lineno)d - %(message)s"
))
logger.addHandler(file_handler)
return logger
# Usage example
if __name__ == "__main__":
log = get_logger(__name__, level="DEBUG")
log.debug("Debug info: file path = /mnt/user-data/uploads/example.csv")
log.info("Start processing file")
log.warning("File size exceeds 50MB, processing may be slow")
log.error("File read failed: FileNotFoundError")
import logging
import sys
from datetime import datetime
def get_logger(name: str, level: str = "INFO") -> logging.Logger:
"""
Create a structured logger
Parameters:
name: Logger name, usually the module name (__name__)
level: Log level, DEBUG / INFO / WARNING / ERROR
"""
logger = logging.getLogger(name)
logger.setLevel(getattr(logging, level.upper(), logging.INFO))
# Avoid adding handlers repeatedly
if logger.handlers:
return logger
# Console output: human-readable format
console = logging.StreamHandler(sys.stdout)
console.setFormatter(logging.Formatter(
"[%(asctime)s] [%(levelname)s] %(name)s - %(message)s",
datefmt="%H:%M:%S"
))
logger.addHandler(console)
# File output: write to log file (optional)
log_file = f"/home/claude/skill_{datetime.now().strftime('%Y%m%d')}.log"
file_handler = logging.FileHandler(log_file, encoding="utf-8")
file_handler.setFormatter(logging.Formatter(
"%(asctime)s [%(levelname)s] %(name)s:%(lineno)d - %(message)s"
))
logger.addHandler(file_handler)
return logger
# Usage example
if __name__ == "__main__":
log = get_logger(__name__, level="DEBUG")
log.debug("Debug info: file path = /mnt/user-data/uploads/example.csv")
log.info("Start processing file")
log.warning("File size exceeds 50MB, processing may be slow")
log.error("File read failed: FileNotFoundError")
[10:23:01] [DEBUG] __main__ - 调试信息：文件路径 = /mnt/user-data/uploads/example.csv [10:23:01] [INFO] __main__ - 开始处理文件 [10:23:01] [WARNING] __main__ - 文件大小超过 50MB，处理可能较慢 [10:23:01] [ERROR] __main__ - 文件读取失败：FileNotFoundError
Execution Time Tracking
When a Skill executes slowly, you need to identify the bottleneck steps that consume time.
Example
# File path: scripts/timer.py
import time
import functools
import logging
log = logging.getLogger(__name__)
def timeit(func):
"""Decorator: automatically records function execution time"""
@functools.wraps(func)
def wrapper(*args, **kwargs):
start = time.perf_counter()
result = func(*args, **kwargs)
elapsed = time.perf_counter() - start
log.info(f"{func.__name__} took {elapsed:.3f} seconds")
return result
return wrapper
# Usage: add the @timeit decorator to the function you want to time
@timeit
def load_csv(file_path: str):
import pandas as pd
return pd.read_csv(file_path)
@timeit
def calculate_stats(df):
return df.describe()
# You can also use a context manager for manual timing
class Timer:
def __init__(self, label: str):
self.label = label
def __enter__(self):
self.start = time.perf_counter()
return self
def __exit__(self, *args):
elapsed = time.perf_counter() - self.start
log.info(f"{self.label} took {elapsed:.3f} seconds")
# Use the Timer context manager
if __name__ == "__main__":
with Timer("Read and clean data"):
import pandas as pd
df = pd.read_csv("/mnt/user-data/uploads/example_data.csv")
df = df.dropna()
import time
import functools
import logging
log = logging.getLogger(__name__)
def timeit(func):
"""Decorator: automatically records function execution time"""
@functools.wraps(func)
def wrapper(*args, **kwargs):
start = time.perf_counter()
result = func(*args, **kwargs)
elapsed = time.perf_counter() - start
log.info(f"{func.__name__} took {elapsed:.3f} seconds")
return result
return wrapper
# Usage: add the @timeit decorator to the function you want to time
@timeit
def load_csv(file_path: str):
import pandas as pd
return pd.read_csv(file_path)
@timeit
def calculate_stats(df):
return df.describe()
# You can also use a context manager for manual timing
class Timer:
def __init__(self, label: str):
self.label = label
def __enter__(self):
self.start = time.perf_counter()
return self
def __exit__(self, *args):
elapsed = time.perf_counter() - self.start
log.info(f"{self.label} took {elapsed:.3f} seconds")
# Use the Timer context manager
if __name__ == "__main__":
with Timer("Read and clean data"):
import pandas as pd
df = pd.read_csv("/mnt/user-data/uploads/example_data.csv")
df = df.dropna()
[10:23:05] [INFO] load_csv 耗时 0.342 秒 [10:23:05] [INFO] calculate_stats 耗时 0.018 秒 [10:23:05] [INFO] 读取并清洗数据 耗时 0.361 秒
Structured Logging: Output JSON Format
When logs need to be parsed by programs (rather than read by humans), the JSON format is more suitable.
Example
# File path: scripts/json_logger.py
import json
import sys
from datetime import datetime
def log_event(level: str, event: str, **context):
"""
Output structured JSON logs
Parameters:
level: Log level (info / warning / error)
event: Event name
context: Additional context key-value pairs
"""
entry = {
"timestamp": datetime.now().isoformat(),
"level": level,
"event": event,
**context
}
# Use stderr for log output to avoid mixing with the script's normal output
print(json.dumps(entry, ensure_ascii=False), file=sys.stderr)
# Usage example
log_event("info", "file_loaded", file="/mnt/user-data/uploads/example.csv", rows=1024)
log_event("warning", "null_detected", column="score", count=12)
log_event("error", "parse_failed", reason="Encoding is not UTF-8")
import json
import sys
from datetime import datetime
def log_event(level: str, event: str, **context):
"""
Output structured JSON logs
Parameters:
level: Log level (info / warning / error)
event: Event name
context: Additional context key-value pairs
"""
entry = {
"timestamp": datetime.now().isoformat(),
"level": level,
"event": event,
**context
}
# Use stderr for log output to avoid mixing with the script's normal output
print(json.dumps(entry, ensure_ascii=False), file=sys.stderr)
# Usage example
log_event("info", "file_loaded", file="/mnt/user-data/uploads/example.csv", rows=1024)
log_event("warning", "null_detected", column="score", count=12)
log_event("error", "parse_failed", reason="Encoding is not UTF-8")
{"timestamp": "2026-05-18T10:23:05", "level": "info", "event": "file_loaded", "file": "/mnt/user-data/uploads/example.csv", "rows": 1024}
{"timestamp": "2026-05-18T10:23:05", "level": "warning", "event": "null_detected", "column": "score", "count": 12}
{"timestamp": "2026-05-18T10:23:05", "level": "error", "event": "parse_failed", "reason": "编码不是 UTF-8"}
Debugging SKILL.md Instruction Execution
When Claude does not execute according to the instructions in SKILL.md, you can locate the problem by inserting "checkpoints" in SKILL.md.
## 调试检查点（开发模式，发布前删除）
在执行每个步骤前，先以以下格式输出一行状态确认：
`[STEP N] 开始：{步骤名称}，输入：{关键参数}`
示例：
`[STEP 1] 开始：读取文件，输入：/mnt/user-data/uploads/example.csv`
`[STEP 2] 开始：数据清洗，输入：1024 行`
这样可以在出错时快速定位到哪个步骤失败。
Debugging checkpoints are temporary. After debugging is complete, be sure to delete these instructions from SKILL.md, otherwise users will see redundant debug output during normal use.
Common Debugging Scenarios Quick Reference
| Scenario | Debugging method |
|---|---|
| Skill not triggered | Check description, test with complex prompts, run run_loop.py to optimize |
| Script reports ImportError | Run pip install, check whether the package name matches the import name |
| File path error | First run ls /mnt/user-data/uploads/ to confirm the file name |
| Garbled output | Explicitly specify encoding="utf-8" when reading files |
| Wrong execution order of steps | Use a numbered list in SKILL.md to clarify the step order |
| Empty result | Add print at key points in the script to confirm at which step the data becomes empty |