Skills: продвинутое логирование и отладка
Базовая отладка опирается на print, продвинутая отладка — на систематические механизмы логирования.
В этой статье рассказывается, как настроить структурированное логирование для скриптов Skill, а также продвинутые приёмы поиска проблем в сложных потоках выполнения.
Замените print на logging
printПодходит для быстрой отладки, но в продакшене Skills следует перейти наloggingмодуль стандартной библиотеки Python.
Преимущество логирования в том, что вы можете управлять уровнем вывода — выводить информацию DEBUG во время разработки и только WARNING и выше в продакшене.
Пример
# Путь к файлу: scripts/logger_setup.py
import logging
import sys
from datetime import datetime
def get_logger(name: str, level: str = "INFO") -> logging.Logger:
"""
Создайте структурированный логгер
Параметры:
name: Имя логгера, обычно имя модуля (__name__)
level: Уровень логирования, DEBUG / INFO / WARNING / ERROR
"""
logger = logging.getLogger(name)
logger.setLevel(getattr(logging, level.upper(), logging.INFO))
# Избегайте повторного добавления обработчиков
if logger.handlers:
return logger
# Вывод в консоль: человекочитаемый формат
console = logging.StreamHandler(sys.stdout)
console.setFormatter(logging.Formatter(
"[%(asctime)s] [%(levelname)s] %(name)s - %(message)s",
datefmt="%H:%M:%S"
))
logger.addHandler(console)
# Вывод в файл: запись в лог-файл (необязательно)
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
# Пример использования
if __name__ == "__main__":
log = get_logger(__name__, level="DEBUG")
log.debug("Отладочная информация: путь к файлу = /mnt/user-data/uploads/example.csv")
log.info("Начало обработки файла")
log.warning("Размер файла превышает 50MB, обработка может быть медленной")
log.error("Не удалось прочитать файл: FileNotFoundError")
import logging
import sys
from datetime import datetime
def get_logger(name: str, level: str = "INFO") -> logging.Logger:
"""
Создайте структурированный логгер
Параметры:
name: Имя логгера, обычно имя модуля (__name__)
level: Уровень логирования, DEBUG / INFO / WARNING / ERROR
"""
logger = logging.getLogger(name)
logger.setLevel(getattr(logging, level.upper(), logging.INFO))
# Избегайте повторного добавления обработчиков
if logger.handlers:
return logger
# Вывод в консоль: человекочитаемый формат
console = logging.StreamHandler(sys.stdout)
console.setFormatter(logging.Formatter(
"[%(asctime)s] [%(levelname)s] %(name)s - %(message)s",
datefmt="%H:%M:%S"
))
logger.addHandler(console)
# Вывод в файл: запись в лог-файл (необязательно)
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
# Пример использования
if __name__ == "__main__":
log = get_logger(__name__, level="DEBUG")
log.debug("Отладочная информация: путь к файлу = /mnt/user-data/uploads/example.csv")
log.info("Начало обработки файла")
log.warning("Размер файла превышает 50MB, обработка может быть медленной")
log.error("Не удалось прочитать файл: 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
Отслеживание времени выполнения
Когда навык выполняется медленно, необходимо определить шаги, которые являются узким местом и потребляют время.
Пример
# Путь к файлу: scripts/timer.py
import time
import functools
import logging
log = logging.getLogger(__name__)
def timeit(func):
"""Декоратор: автоматически записывает время выполнения функции"""
@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__} занял {elapsed:.3f} секунд")
return result
return wrapper
# Использование: добавьте декоратор @timeit к функции, время выполнения которой вы хотите измерить
@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()
# Вы также можете использовать контекстный менеджер для ручного замера времени
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} занял {elapsed:.3f} секунд")
# Использование контекстного менеджера Timer
if __name__ == "__main__":
with Timer("Чтение и очистка данных"):
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):
"""Декоратор: автоматически записывает время выполнения функции"""
@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__} занял {elapsed:.3f} секунд")
return result
return wrapper
# Использование: добавьте декоратор @timeit к функции, время выполнения которой вы хотите измерить
@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()
# Вы также можете использовать контекстный менеджер для ручного замера времени
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} занял {elapsed:.3f} секунд")
# Использование контекстного менеджера Timer
if __name__ == "__main__":
with Timer("Чтение и очистка данных"):
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 秒
Структурированное логирование: вывод в формате JSON
Когда логи должны анализироваться программами (а не читаться людьми), формат JSON подходит лучше.
Пример
# Путь к файлу: scripts/json_logger.py
import json
import sys
from datetime import datetime
def log_event(level: str, event: str, **context):
"""
Вывод структурированных логов в формате JSON
Параметры:
level: Уровень логирования (info / warning / error)
event: Имя события
context: Дополнительные пары ключ-значение контекста
"""
entry = {
"timestamp": datetime.now().isoformat(),
"level": level,
"event": event,
**context
}
# Используйте stderr для вывода журнала, чтобы не смешивать его с обычным выводом скрипта
print(json.dumps(entry, ensure_ascii=False), file=sys.stderr)
# Пример использования
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="Кодировка не UTF-8")
import json
import sys
from datetime import datetime
def log_event(level: str, event: str, **context):
"""
Вывод структурированных логов в формате JSON
Параметры:
level: Уровень логирования (info / warning / error)
event: Имя события
context: Дополнительные пары ключ-значение контекста
"""
entry = {
"timestamp": datetime.now().isoformat(),
"level": level,
"event": event,
**context
}
# Используйте stderr для вывода журнала, чтобы не смешивать его с обычным выводом скрипта
print(json.dumps(entry, ensure_ascii=False), file=sys.stderr)
# Пример использования
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="Кодировка не 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"}
Отладка выполнения инструкций SKILL.md
Когда Claude не выполняет инструкции в SKILL.md, можно найти проблему, вставив "контрольные точки" в SKILL.md.
## 调试检查点（开发模式，发布前删除）
在执行每个步骤前，先以以下格式输出一行状态确认：
`[STEP N] 开始：{步骤名称}，输入：{关键参数}`
示例：
`[STEP 1] 开始：读取文件，输入：/mnt/user-data/uploads/example.csv`
`[STEP 2] 开始：数据清洗，输入：1024 行`
这样可以在出错时快速定位到哪个步骤失败。
Отладочные контрольные точки являются временными. После завершения отладки обязательно удалите эти инструкции из SKILL.md, иначе пользователи будут видеть лишний отладочный вывод при обычном использовании.
Краткий справочник по типичным сценариям отладки
| Сценарий | Метод отладки |
|---|---|
| Навык не срабатывает | Проверьте description, протестируйте со сложными промптами, запустите run_loop.py для оптимизации |
| Скрипт сообщает об ImportError | Запустите pip install, проверьте, совпадает ли имя пакета с именем импорта |
| Ошибка пути к файлу | Сначала выполните ls /mnt/user-data/uploads/, чтобы подтвердить имя файла |
| Искажённый вывод | Явно указывайте encoding="utf-8" при чтении файлов |
| Неправильный порядок выполнения шагов | Используйте нумерованный список в SKILL.md, чтобы уточнить порядок шагов |
| Пустой результат | Добавьте print в ключевых точках скрипта, чтобы определить, на каком шаге данные становятся пустыми |