Add detailed logging to model linker and sources
Add extensive observability/logging across ModelLinker and source search modules. __init__.py: introduce summarize_result and log_search_result helpers, replace ad-hoc logger calls with log_info/log_exception, and add start/result/summary logs for local, popular, model_list, HuggingFace and CivitAI searches (including extra metadata like confidence, files_count, results_count). core/sources/civitai.py: log cache hits, API call start, response counts, model/version/file checks, no-result info and improved exception logging. core/sources/huggingface.py: log cache hits, API call start, response counts, per-repo debug info, repo tree sizes, no-result info and improved exception logging. Changes are focused on diagnostics and do not alter core search logic.
This commit is contained in:
Dariusz L
+81
-6
@@ -766,6 +766,37 @@ class ModelLinkerExtension:
|
||||
async def search_sources(request):
|
||||
"""Search for model download sources."""
|
||||
try:
|
||||
def summarize_result(source_name, result, extra=None):
|
||||
if isinstance(result, dict):
|
||||
summary = {
|
||||
"source": source_name,
|
||||
"name": result.get("name"),
|
||||
"filename": result.get("filename"),
|
||||
"match_type": result.get("match_type"),
|
||||
"repo_id": result.get("repo_id"),
|
||||
"model_id": result.get("model_id"),
|
||||
"version_id": result.get("version_id"),
|
||||
"url": result.get("url"),
|
||||
"download_url": result.get("download_url"),
|
||||
"size": result.get("size"),
|
||||
}
|
||||
else:
|
||||
summary = {"source": source_name, "result": result}
|
||||
|
||||
if extra:
|
||||
summary.update(extra)
|
||||
|
||||
return summary
|
||||
|
||||
def log_search_result(source_name, result, extra=None):
|
||||
details = summarize_result(source_name, result, extra)
|
||||
if result and (
|
||||
not isinstance(result, list) or len(result) > 0
|
||||
):
|
||||
log_info(f"Search source [{source_name}] FOUND: {details}")
|
||||
else:
|
||||
log_info(f"Search source [{source_name}] no result: {details}")
|
||||
|
||||
data = await request.json()
|
||||
filename = data.get("filename", "")
|
||||
category = data.get("category", "")
|
||||
@@ -809,8 +840,7 @@ class ModelLinkerExtension:
|
||||
search_huggingface_source = "huggingface" in normalized_sources
|
||||
search_civitai_source = "civitai" in normalized_sources
|
||||
|
||||
# Debug logging
|
||||
self.logger.info(
|
||||
log_info(
|
||||
f"Search request: filename={filename}, category={category}, is_urn={is_urn}, model_id={data.get('model_id')}, version_id={data.get('version_id')}, sources={sorted(normalized_sources)}"
|
||||
)
|
||||
|
||||
@@ -825,7 +855,11 @@ class ModelLinkerExtension:
|
||||
|
||||
# 1. Search local databases (curated + model-list)
|
||||
if search_local:
|
||||
log_info(
|
||||
f"Search source [local] start: filename={filename}, category={category}"
|
||||
)
|
||||
popular_info = get_popular_model_url(filename)
|
||||
log_search_result("popular", popular_info)
|
||||
if popular_info:
|
||||
results["popular"] = {
|
||||
"source": "popular",
|
||||
@@ -835,6 +869,15 @@ class ModelLinkerExtension:
|
||||
results["found"] = True
|
||||
|
||||
model_list_result = search_model_list(filename)
|
||||
log_search_result(
|
||||
"model_list",
|
||||
model_list_result,
|
||||
{
|
||||
"confidence": model_list_result.get("confidence")
|
||||
if model_list_result
|
||||
else None
|
||||
},
|
||||
)
|
||||
if model_list_result:
|
||||
confidence = model_list_result.get("confidence", 0)
|
||||
if is_urn and confidence >= 70:
|
||||
@@ -846,13 +889,18 @@ class ModelLinkerExtension:
|
||||
|
||||
# 2. Search HuggingFace for exact file match
|
||||
if search_huggingface_source:
|
||||
log_info(f"Search source [huggingface] start: filename={filename}")
|
||||
hf_result = search_huggingface_for_file(filename)
|
||||
log_search_result("huggingface", hf_result)
|
||||
if hf_result:
|
||||
results["huggingface"] = hf_result
|
||||
results["found"] = True
|
||||
|
||||
# 3. Search CivitAI - use direct download for URNs
|
||||
if search_civitai_source:
|
||||
log_info(
|
||||
f"Search source [civitai] start: filename={filename}, category={category}, is_urn={is_urn}"
|
||||
)
|
||||
# For URNs, use direct model_id/version_id to get download URL
|
||||
if is_urn:
|
||||
# Get model_id and version_id from request data
|
||||
@@ -897,15 +945,40 @@ class ModelLinkerExtension:
|
||||
"base_model": model_info.get("base_model"),
|
||||
"tags": model_info.get("tags", []),
|
||||
}
|
||||
log_search_result(
|
||||
"civitai/urn",
|
||||
results["civitai"],
|
||||
{
|
||||
"files_count": len(
|
||||
model_info.get("files", [])
|
||||
)
|
||||
},
|
||||
)
|
||||
results["found"] = True
|
||||
else:
|
||||
log_search_result(
|
||||
"civitai/urn",
|
||||
None,
|
||||
{
|
||||
"model_id": model_id,
|
||||
"version_id": version_id,
|
||||
},
|
||||
)
|
||||
elif category:
|
||||
# Fallback to search if no IDs
|
||||
self.logger.info(
|
||||
log_info(
|
||||
f"URN: No model_id/version_id, falling back to CivitAI search"
|
||||
)
|
||||
civitai_results = search_civitai(
|
||||
filename, model_type=category
|
||||
)
|
||||
log_search_result(
|
||||
"civitai/fallback",
|
||||
civitai_results[0] if civitai_results else None,
|
||||
{
|
||||
"results_count": len(civitai_results),
|
||||
},
|
||||
)
|
||||
if civitai_results:
|
||||
first_result = civitai_results[0]
|
||||
results["civitai"] = {
|
||||
@@ -924,16 +997,18 @@ class ModelLinkerExtension:
|
||||
results["found"] = True
|
||||
else:
|
||||
civitai_result = search_civitai_for_file(filename)
|
||||
log_search_result("civitai", civitai_result)
|
||||
if civitai_result:
|
||||
results["civitai"] = civitai_result
|
||||
results["found"] = True
|
||||
|
||||
log_info(
|
||||
f"Search summary: found={results['found']}, searched_sources={results['searched_sources']}"
|
||||
)
|
||||
return web.json_response(results)
|
||||
|
||||
except Exception as e:
|
||||
self.logger.error(
|
||||
f"Model Linker search error: {e}", exc_info=True
|
||||
)
|
||||
log_exception(f"Model Linker search error: {e}")
|
||||
return web.json_response({"error": str(e)}, status=500)
|
||||
|
||||
@routes.post("/model_linker/download")
|
||||
|
||||
+20
-2
@@ -133,6 +133,7 @@ def search_civitai_for_file(
|
||||
|
||||
cache_key = f"civit_{filename}_exact{exact_only}"
|
||||
if cache_key in _search_cache:
|
||||
log_debug(f"CivitAI search cache hit for {filename} (exact_only={exact_only})")
|
||||
return _search_cache[cache_key]
|
||||
|
||||
try:
|
||||
@@ -144,14 +145,22 @@ def search_civitai_for_file(
|
||||
headers["Authorization"] = f"Bearer {api_key}"
|
||||
|
||||
search_url = f"{CIVITAI_API_URL}/models?query={quote(search_term)}&limit=10"
|
||||
log_info(
|
||||
f"CivitAI search start: filename={filename}, query={search_term}, exact_only={exact_only}"
|
||||
)
|
||||
|
||||
response = requests.get(search_url, headers=headers, timeout=15)
|
||||
if response.status_code != 200:
|
||||
log_debug(f"CivitAI search returned {response.status_code}")
|
||||
log_warn(
|
||||
f"CivitAI search returned {response.status_code} for query={search_term}"
|
||||
)
|
||||
return None
|
||||
|
||||
data = response.json()
|
||||
items = data.get("items", [])
|
||||
log_info(
|
||||
f"CivitAI search API returned {len(items)} models for query={search_term}"
|
||||
)
|
||||
|
||||
filename_base = os.path.splitext(filename.lower())[0]
|
||||
|
||||
@@ -159,11 +168,17 @@ def search_civitai_for_file(
|
||||
model_id = item.get("id")
|
||||
model_name = item.get("name", "")
|
||||
model_type = item.get("type", "")
|
||||
log_debug(
|
||||
f"CivitAI checking model_id={model_id}, model_name={model_name}, model_type={model_type}"
|
||||
)
|
||||
|
||||
model_versions = item.get("modelVersions", [])
|
||||
for version in model_versions:
|
||||
version_id = version.get("id")
|
||||
files = version.get("files", [])
|
||||
log_debug(
|
||||
f"CivitAI checking version_id={version_id} with {len(files)} files for model_id={model_id}"
|
||||
)
|
||||
|
||||
for file_info in files:
|
||||
file_name = file_info.get("name", "")
|
||||
@@ -220,10 +235,13 @@ def search_civitai_for_file(
|
||||
|
||||
# Not found
|
||||
_search_cache[cache_key] = None
|
||||
log_info(
|
||||
f"CivitAI search no result: filename={filename}, query={search_term}, models_checked={len(items)}"
|
||||
)
|
||||
return None
|
||||
|
||||
except Exception as e:
|
||||
log_error(f"CivitAI search error: {e}")
|
||||
log_exception(f"CivitAI search error for {filename}: {e}")
|
||||
return None
|
||||
|
||||
|
||||
|
||||
@@ -98,6 +98,7 @@ def search_huggingface_for_file(
|
||||
|
||||
cache_key = f"hf_{filename}_exact{exact_only}"
|
||||
if cache_key in _search_cache:
|
||||
log_debug(f"HuggingFace search cache hit for {filename} (exact_only={exact_only})")
|
||||
return _search_cache[cache_key]
|
||||
|
||||
try:
|
||||
@@ -110,19 +111,29 @@ def search_huggingface_for_file(
|
||||
|
||||
# Search for repos containing this filename
|
||||
search_url = f"{HF_API_URL}/models?search={quote(filename_base)}&limit=10"
|
||||
log_info(
|
||||
f"HuggingFace search start: filename={filename}, query={filename_base}, exact_only={exact_only}"
|
||||
)
|
||||
|
||||
response = requests.get(search_url, headers=headers, timeout=10)
|
||||
if response.status_code != 200:
|
||||
log_debug(f"HuggingFace search returned {response.status_code}")
|
||||
log_warn(
|
||||
f"HuggingFace search returned {response.status_code} for query={filename_base}"
|
||||
)
|
||||
return None
|
||||
|
||||
repos = response.json()
|
||||
log_info(
|
||||
f"HuggingFace search API returned {len(repos)} repos for query={filename_base}"
|
||||
)
|
||||
|
||||
for repo in repos:
|
||||
repo_id = repo.get("id", "")
|
||||
if not repo_id:
|
||||
continue
|
||||
|
||||
log_debug(f"HuggingFace checking repo {repo_id} for filename={filename}")
|
||||
|
||||
# Check if this repo actually has a matching file
|
||||
files_url = f"{HF_API_URL}/models/{repo_id}/tree/main"
|
||||
|
||||
@@ -130,6 +141,9 @@ def search_huggingface_for_file(
|
||||
files_response = requests.get(files_url, headers=headers, timeout=10)
|
||||
if files_response.status_code == 200:
|
||||
files = files_response.json()
|
||||
log_debug(
|
||||
f"HuggingFace repo {repo_id} returned {len(files)} tree items"
|
||||
)
|
||||
|
||||
for file_info in files:
|
||||
file_path = file_info.get("path", "")
|
||||
@@ -178,15 +192,18 @@ def search_huggingface_for_file(
|
||||
return result
|
||||
|
||||
except Exception as e:
|
||||
log_debug(f"Error checking repo {repo_id}: {e}")
|
||||
log_debug(f"Error checking HuggingFace repo {repo_id}: {e}")
|
||||
continue
|
||||
|
||||
# Not found
|
||||
_search_cache[cache_key] = None
|
||||
log_info(
|
||||
f"HuggingFace search no result: filename={filename}, query={filename_base}, repos_checked={len(repos)}"
|
||||
)
|
||||
return None
|
||||
|
||||
except Exception as e:
|
||||
log_error(f"HuggingFace search error: {e}")
|
||||
log_exception(f"HuggingFace search error for {filename}: {e}")
|
||||
return None
|
||||
|
||||
|
||||
|
||||
Reference in New Issue
Block a user