unsloth/studio/backend/utils/models/checkpoints.py
Daniel Han a6aa4fff10
Studio: quiet noisy logs, log real progress, and speed up Windows/macOS dataset prep (#7087)
* Studio: exclude /api/export/status from request access logs

The frontend polls /api/export/status every 5s to detect export start, so it
fires continuously even when idle. Each poll emitted an info request_completed
access line, making up most of the server access logs. Add it to _EXCLUDED_PATHS
alongside /api/train/status. The endpoint is unchanged; export state is still
logged by the export modules and streamed over SSE, so no signal is lost.

* Studio: collapse hub download-progress polls in the access log

download-status and gguf-download-progress (plus the dataset equivalents)
are polled about twice a second for the whole download, so each emitted an
info request_completed line. Add them to _QUIET_POLL_PATHS so they collapse
to one heartbeat line per 10s instead of one per poll.

* Studio: log hub download progress at 10% steps

The access log carried no real progress, only poll pings. Emit one
hub_download_progress line per 10% step from the shared snapshot progress
reader, so an active download shows actual percentage without a line per
poll. Throttled per job and resynced if the same download restarts.

* [pre-commit.ci] auto fixes from pre-commit.com hooks

for more information, see https://pre-commit.ci

* Studio: drop successful chat thread/project CRUD from the access log

A single chat turn fans out about twenty requests under /api/chat/threads
and /api/chat/projects (list, fetch, per-message forks, and the message
writes) that only reflect the UI re-rendering. Suppress their 2xx access
line so the log keeps the signal (generation, tool calls, code execution,
engine stats) and errors. Non-2xx on these paths still log.

* Studio: silence transformers torch_dtype deprecation warning

transformers logs "`torch_dtype` is deprecated! Use `dtype` instead!" once at
model-config load via logger.warning_once (logging, not warnings), so a warnings
filter cannot catch it. Attach a small logging.Filter in setup_logging, which
runs before any model config is parsed, to drop that record on the transformers
loggers that emit it.

* Studio: quiet inference load-progress polls and log throttled load progress

The frontend polls /api/inference/load-progress about twice a second for the
whole model load, so each emitted a request_completed line. Add it to
_QUIET_POLL_PATHS (heartbeat) and emit one inference_load_progress line per 10%
step from the load-progress route, so a load shows real percentage instead of a
line per poll.

* Studio: fully suppress download/load progress poll access lines

The download-status, download-progress, gguf-download-progress, active-downloads
and transport-status polls (model and dataset), plus inference load-progress,
fire ~2x/s for the whole download or load. Their progress is now reported by the
hub_download_progress / inference_load_progress events (and the viewer's progress
line), so the per-poll access line adds nothing. Drop it on 2xx and keep it on
errors, instead of the prior 10s heartbeat. Chat CRUD suppression is folded into
the same _is_quiet_success helper.

* Studio: suppress training-tab model/dataset download-progress polls

The training tab polls /api/models/download-progress and
/api/datasets/download-progress about twice a second for the whole prep phase.
These are separate routes from the /api/hub equivalents and only scan the cache,
so their 2xx access line adds nothing (on Windows they always read 0 since the
bytes live in snapshots/, not blobs/). Suppress the 2xx line and keep errors,
alongside /api/models/gguf-download-progress.

* Studio: drop transient pre-auth 401 on chat thread/project polls

On first load the SPA fires chat thread/project GETs before the initial token
refresh, so they 401 until /api/auth/refresh runs and the retries succeed. That
pre-auth 401 is a bootstrap artifact, not an error; suppress it alongside the
already-quiet 2xx line. Genuine 4xx/5xx on these paths, the download/load poll
401s, and all /api/auth/* still log.

* Studio: quiet tab-switch list polls and per-poll scan/reconnect logs

Switching between the Train, Export, and Chat tabs refetches list endpoints on a
timer, and each hit re-logs internal detail. Heartbeat /api/train/runs,
/api/models/checkpoints, /api/models/local and /api/rag/knowledge-bases (10s
window, first hit and errors still log), and downgrade two per-poll INFO lines to
debug: the checkpoints scan summary ("Found N training runs") and the
per-reconnect SSE resume line. The meaningful "replayed N missed steps" line,
logged only when steps were actually replayed, stays at info.

* Studio: enable tokenizer parallelism for dataset prep on Windows/macOS

TOKENIZERS_PARALLELISM was forced off everywhere to stop datasets' forked map()
workers from deadlocking, but that fork only happens on Linux. On spawn platforms
(Windows/macOS) dataset.map() runs in-process (dataset_map_num_proc returns None),
so disabling tokenizer parallelism leaves the fast tokenizer single-threaded and
dataset prep runs serially on one core. Keep it off on Linux (fork safety) and on
for spawn platforms, where there is no fork to deadlock. Measured ~7x faster
tokenization (12.5s -> 1.7s for 20k rows on a 32-core Windows box).

* [pre-commit.ci] auto fixes from pre-commit.com hooks

for more information, see https://pre-commit.ci

* Studio: log throttled training status to the server log

Training step/loss/epoch only went to the UI via SSE, so the server log showed
inference engine_stats and train/runs heartbeats but nothing about the actual
run. Emit one throttled training_progress line (step/total, percent, loss, epoch,
eta) from the CUDA event pump: the first step, then at most every 30s, plus the
final step, resyncing when a new run restarts the counter. Per-step UI streaming
is unchanged.

* Studio: quiet llama.cpp update-status polls and log throttled update progress

The prebuilt llama.cpp update polls /api/llama/update-status about twice a second
for the whole download and install. Suppress its 2xx access line (errors still
log) and emit one throttled llama_update_progress line per 10% step from the
status route, so the update shows progress without a line per poll. The existing
"llama update: installing" and "llama update: success" events still bracket it.

* Studio: quiet the export log-tail poll

The Export tab polls /api/export/logs about once a second to stream the export
subprocess output into the UI panel. Suppress its 2xx access line; the real
progress is already logged as event-driven "Export subprocess status: <phase>"
lines plus the subprocess start and checkpoint-loaded events, and errors still log.

* studio: keep errors and mutations visible in access-log suppression

Make the quiet-success access-log suppression GET-only so chat thread/project
mutations (POST/PUT/DELETE) still log; only their list-poll 2xx and the
transient pre-auth 401 are dropped.

Suppress /api/export/status 2xx only (move it out of the all-status exclude
set) so a 401/403/500 on it stays visible.

Legacy /api/models and /api/datasets download-progress polls emit no
hub_download_progress events, so heartbeat them via the 10s quiet-poll window
instead of suppressing outright, keeping download visibility (notably on
Linux). The event-emitting /api/hub download polls stay fully suppressed.

Update and extend the middleware tests to cover GET-only suppression, the
export-status error path, and the legacy download heartbeat.

* [pre-commit.ci] auto fixes from pre-commit.com hooks

for more information, see https://pre-commit.ci

* studio: tighten access-log and training-progress comments

Comment-only pass: collapse the multi-line explanations in the logging
middleware and the throttled training-progress logger to fewer lines while
keeping the rationale. No behavior change.

* studio: log structured export_progress phases

Emit a structured export_progress event per phase (consolidated in the server
log like training and download progress) instead of a plain status string, and
add a phase milestone at the start of the heavy export step so the
merge/save/convert is visible in the server log, not only in the forwarded
stdout panel.

* Studio: reset training-progress log throttle on each new run

start_training rebuilds the per-run progress state but left _last_progress_log_ts/_last_progress_log_step at their prior values. A run started within 30s of a previous one whose last logged step matched the new run's first step would hit the step == prev short-circuit and drop the promised first training_progress line, then stay suppressed until the old 30s window expired. Reset both fields when a new job is accepted.

* Studio: keep post-bootstrap chat 401s visible in the access log

The chat thread/project 401 suppression dropped every GET 401 on those prefixes, so a genuine expired-session 401 vanished alongside the transient pre-auth race. Gate the 401 drop on a per-middleware bootstrap latch that flips once /api/auth/refresh first succeeds: before that the 401s are the pre-refresh race and are suppressed; after it any chat 401 is a real failure and logs. Add a test for the post-refresh case.

* [pre-commit.ci] auto fixes from pre-commit.com hooks

for more information, see https://pre-commit.ci

* Studio: limit chat access-log suppression to the exact list polls

The chat thread/project suppression matched by startswith, so it also dropped the 2xx access line for detail and message reads (/threads/{id}, /threads/{id}/messages, /threads/{id}/messages/{id}, /projects/{id}) that are not the high-frequency list polls, losing their access and latency logging. Match the two list paths exactly instead, so only the intended list polls (and their pre-auth 401 race) are suppressed while detail and message reads keep their access line. Add a regression test.

* Studio: reset inference load-progress throttle for each load

The load-progress throttle (_last_load_progress_step) is a module global that persisted across loads, so a cached or small load whose first sampled /api/inference/load-progress response already reported fraction=1.0 hit step == prev (10) from a prior completed load and emitted no inference_load_progress line, while that endpoint's access log is suppressed, leaving the new load with no progress signal. Arm the throttle at load initiation in _load_model_impl so each load's first step always logs. Add a regression test.

* Studio: tighten logging comments

Collapse a few verbose comments (tokenizer-parallelism note, torch_dtype filter, legacy download-poll heartbeat, chat list-path suppression) to fewer lines without changing intent or code.

---------

Co-authored-by: pre-commit-ci[bot] <66853113+pre-commit-ci[bot]@users.noreply.github.com>
2026-07-15 06:49:52 -07:00

317 lines
11 KiB
Python

# SPDX-License-Identifier: AGPL-3.0-only
# Copyright 2026-present the Unsloth AI Inc. team. All rights reserved. See /studio/LICENSE.AGPL-3.0
"""Checkpoint scanning utilities for discovering training runs and checkpoints."""
import json
import re
import structlog
from loggers import get_logger
from pathlib import Path
from typing import List, Optional, Tuple
from storage.studio_db import get_connection
from utils.training_runs import (
build_default_output_dir_name,
extract_project_name,
model_segment_from_default_output_dir_name,
)
from utils.paths import outputs_root, resolve_output_dir
logger = get_logger(__name__)
_CHECKPOINT_STEP_RE = re.compile(r"^checkpoint-(\d+)$")
def _checkpoint_step(checkpoint_name: str) -> Optional[int]:
match = _CHECKPOINT_STEP_RE.fullmatch(checkpoint_name)
if match is None:
return None
return int(match.group(1))
def _checkpoint_sort_key(checkpoint_path: Path) -> tuple[int, int, str]:
step = _checkpoint_step(checkpoint_path.name)
if step is not None:
return (0, -step, checkpoint_path.name)
return (1, 0, str(checkpoint_path))
def _infer_base_model_from_history(checkpoint_dir: Path) -> Optional[str]:
"""Best-effort base-model lookup using persisted Studio run metadata."""
checkpoint_name = checkpoint_dir.name
resolved_checkpoint_dir = str(checkpoint_dir.resolve())
try:
conn = get_connection()
except Exception:
return None
try:
exact_rows = conn.execute(
"""
SELECT model_name
FROM training_runs
WHERE output_dir IN (?, ?)
ORDER BY started_at DESC
""",
(
resolved_checkpoint_dir,
str(checkpoint_dir),
),
).fetchall()
for row in exact_rows:
model_name = row["model_name"]
if model_name:
return model_name
suffix_rows = conn.execute(
"""
SELECT model_name, output_dir
FROM training_runs
WHERE output_dir IS NOT NULL
ORDER BY started_at DESC
"""
).fetchall()
for row in suffix_rows:
output_dir = str(row["output_dir"] or "").rstrip("/\\")
if not (
output_dir.endswith(f"/{checkpoint_name}")
or output_dir.endswith(f"\\{checkpoint_name}")
):
continue
model_name = row["model_name"]
if model_name:
return model_name
parts = checkpoint_name.rsplit("_", 1)
if len(parts) != 2 or not parts[1].isdigit():
return None
timestamp = int(parts[1])
generated_rows = conn.execute(
"""
SELECT model_name, config_json
FROM training_runs
ORDER BY started_at DESC
"""
).fetchall()
for row in generated_rows:
model_name = row["model_name"]
if not model_name:
continue
project_name = None
config_json = row["config_json"]
if config_json:
try:
project_name = extract_project_name(json.loads(config_json))
except (TypeError, json.JSONDecodeError):
project_name = None
expected_dir_name = build_default_output_dir_name(
model_name,
project_name,
timestamp = timestamp,
)
if expected_dir_name == checkpoint_name:
return model_name
except Exception:
return None
finally:
conn.close()
return None
def _read_checkpoint_loss(checkpoint_path: Path) -> Optional[float]:
"""Read loss from the last log_history entry of trainer_state.json, or None."""
trainer_state = checkpoint_path / "trainer_state.json"
if not trainer_state.exists():
return None
try:
with open(trainer_state) as f:
state = json.load(f)
log_history = state.get("log_history", [])
if log_history:
return log_history[-1].get("loss")
except Exception as e:
logger.debug(f"Could not read loss from {trainer_state}: {e}")
return None
def scan_checkpoints(
outputs_dir: str = str(outputs_root()),
) -> List[Tuple[str, List[Tuple[str, str, Optional[float]]], dict]]:
"""Scan outputs folder for training runs and their checkpoints.
Returns:
[(model_name, [(display_name, checkpoint_path, loss), ...], metadata), ...]
metadata keys (optional): base_model, peft_type, lora_rank.
First checkpoint entry is the main adapter; its loss mirrors the latest
(highest-step) intermediate checkpoint. Numbered checkpoints are sorted
by numeric step descending; non-numbered checkpoint-* dirs keep the
previous lexicographic directory order.
"""
models = []
outputs_path = resolve_output_dir(outputs_dir)
if not outputs_path.exists():
logger.warning(f"Outputs directory not found: {outputs_dir}")
return models
try:
for item in outputs_path.iterdir():
if not item.is_dir():
continue
config_file = item / "config.json"
adapter_config = item / "adapter_config.json"
if not (config_file.exists() or adapter_config.exists()):
continue
# Training metadata from adapter_config.json / config.json
metadata: dict = {}
try:
if adapter_config.exists():
cfg = json.loads(adapter_config.read_text())
metadata["base_model"] = cfg.get("base_model_name_or_path")
metadata["peft_type"] = cfg.get("peft_type")
metadata["lora_rank"] = cfg.get("r")
elif config_file.exists():
cfg = json.loads(config_file.read_text())
metadata["base_model"] = cfg.get("_name_or_path")
# Detect BNB quantization from config.json
if config_file.exists():
if "cfg" not in dir():
cfg = json.loads(config_file.read_text())
quant_cfg = cfg.get("quantization_config")
if (
isinstance(quant_cfg, dict)
and quant_cfg.get("quant_method") == "bitsandbytes"
):
metadata["is_quantized"] = True
logger.info("Detected BNB-quantized model: %s", item.name)
except Exception:
pass
# Fallback: extract base model name from the folder name, e.g.
# "unsloth_Llama-3.2-3B-Instruct_1771227800" → "unsloth/Llama-3.2-3B-Instruct"
if not metadata.get("base_model"):
metadata["base_model"] = _infer_base_model_from_history(item)
if not metadata.get("base_model"):
name_part = model_segment_from_default_output_dir_name(item.name)
if name_part:
idx = name_part.find("_")
if idx > 0:
metadata["base_model"] = name_part[:idx] + "/" + name_part[idx + 1 :]
else:
metadata["base_model"] = name_part
# Valid training run.
checkpoints = []
# Main adapter placeholder — loss filled from the last checkpoint below.
checkpoints.append((item.name, str(item), None))
# Scan for intermediate checkpoints (checkpoint-N subdirs).
valid_checkpoints = []
for sub in item.iterdir():
if not sub.is_dir() or not sub.name.startswith("checkpoint-"):
continue
sub_config = sub / "config.json"
sub_adapter = sub / "adapter_config.json"
if sub_config.exists() or sub_adapter.exists():
valid_checkpoints.append(sub)
intermediate_checkpoints = []
for sub in sorted(valid_checkpoints, key = _checkpoint_sort_key):
loss = _read_checkpoint_loss(sub)
intermediate_checkpoints.append((sub.name, str(sub), loss))
checkpoints.extend(intermediate_checkpoints)
# Assign the latest checkpoint's loss to the main adapter entry.
if intermediate_checkpoints:
last_checkpoint_loss = intermediate_checkpoints[0][2]
checkpoints[0] = (
checkpoints[0][0],
checkpoints[0][1],
last_checkpoint_loss,
)
models.append((item.name, checkpoints, metadata))
logger.debug(f"Found model: {item.name} with {len(checkpoints)} checkpoint(s)")
# Sort by modification time (newest first)
models.sort(key = lambda x: Path(x[1][0][1]).stat().st_mtime, reverse = True)
logger.debug(f"Found {len(models)} training runs in {outputs_dir}")
return models
except Exception as e:
logger.error(f"Error scanning checkpoints: {e}")
return []
def _is_model_dir(path: Path) -> bool:
return (path / "config.json").exists() or (path / "adapter_config.json").exists()
def has_preview_model(output_dir: Optional[str]) -> bool:
"""True when ``output_dir`` holds a previewable root model (what ``/p/{run}``
resolves). A cancelled run keeps ``output_dir`` but saves no root adapter."""
if not output_dir:
return False
path = Path(output_dir)
return path.is_dir() and _is_model_dir(path)
def preview_ref(output_dir: Optional[str]) -> Optional[str]:
"""``/p`` ref (``run`` or ``run/checkpoint``) relative to outputs_root, or None.
Posix-joined so a nested output dir keeps a working link instead of collapsing
to its basename. None when not previewable, outside outputs_root, or deeper than
the two path segments the ``/p`` route matches (so the UI omits a dead link).
"""
if not has_preview_model(output_dir):
return None
try:
rel = Path(output_dir).resolve().relative_to(outputs_root().resolve())
except (ValueError, OSError):
return None
parts = rel.parts
if not parts or len(parts) > 2:
return None
return "/".join(parts)
def resolve_preview_checkpoint(run: str, checkpoint: Optional[str] = None) -> Path:
relative = run if not checkpoint else f"{run}/{checkpoint}"
path = resolve_output_dir(relative)
if not path.is_dir() or not _is_model_dir(path):
raise FileNotFoundError(
f"No trained checkpoint at '{relative}'. Check the run/checkpoint name (see GET /p)."
)
return path
def list_preview_targets(outputs_dir: str = str(outputs_root())) -> List[dict]:
targets: List[dict] = []
for run_name, checkpoints, metadata in scan_checkpoints(outputs_dir):
for display_name, path, loss in checkpoints:
is_latest = display_name == run_name
checkpoint = None if is_latest else Path(path).name
targets.append(
{
"run": run_name,
"checkpoint": checkpoint,
"ref": run_name if is_latest else f"{run_name}/{checkpoint}",
"is_latest": is_latest,
"loss": loss,
"base_model": metadata.get("base_model"),
}
)
return targets