// Temporary local full verification: Sync A1 + live LLM ProcessJob. // Do not commit. package main import ( "context" "encoding/json" "fmt" "io" "log" "net/http" "os" "os/signal" "path/filepath" "strings" "syscall" "time" "unicode" "github.com/descrybe/descrybe-v2/apps/api/internal/aiprompts" "github.com/descrybe/descrybe-v2/apps/api/internal/aiprovider" "github.com/descrybe/descrybe-v2/apps/api/internal/billing" "github.com/descrybe/descrybe-v2/apps/api/internal/config" "github.com/descrybe/descrybe-v2/apps/api/internal/db" "github.com/descrybe/descrybe-v2/apps/api/internal/eprel" "github.com/descrybe/descrybe-v2/apps/api/internal/logredact" "github.com/descrybe/descrybe-v2/apps/api/internal/platformsettings" "github.com/descrybe/descrybe-v2/apps/api/internal/processing" "github.com/google/uuid" "github.com/jackc/pgx/v5/pgxpool" ) func main() { out := os.Getenv("PROBE_OUT_DIR") if out == "" { out = `F:\laragon\www\_MY\descrybe-v2\.codehelper\_final_verify_20260817` } _ = os.MkdirAll(out, 0o755) logPath := filepath.Join(out, "inproc_run.log") logFile, err := os.Create(logPath) if err != nil { log.Fatalf("log file: %v", err) } defer logFile.Close() log.SetOutput(logredact.Writer(io.MultiWriter(os.Stderr, logFile))) // Repo seed only — no Downloads / admin upload path. repoRoot := `F:\laragon\www\_MY\descrybe-v2` wpPath := filepath.Join(repoRoot, "scripts", "seed", "wp_product_categories.sql") wpBytes, err := os.ReadFile(wpPath) if err != nil { log.Fatalf("read repo seed wp categories: %v", err) } _ = os.Setenv("SEED_A1_WP_CATEGORIES", wpPath) // Prefer issue EANs + mapped-category mix (TV, monitor, headphones, appliance). // 4 mapped-category products (LIVE A1; ~2–4 min/item). eans := []string{ "4548736132597", // Slušalke "195348253666", // Gaming monitorji "8806097118565", // Televizorji "3838782459856", // Pomivalni stroji } issueEAN := "" // skip uncategorized issue EAN this pass companyID := uuid.MustParse("604f23a8-b66e-4b21-8b45-0d72b68f4790") // A1 Slovenija demoID := uuid.MustParse("2b3159b0-fc08-415b-b248-35ed02a6baab") // Platform Demo userID := uuid.MustParse("6bf00877-a693-4d77-b28e-8c8292adac98") // a1-primary@descrybe.local cfg, err := config.Load() if err != nil { log.Fatalf("config: %v", err) } ctx, cancel := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM) defer cancel() pool, err := db.NewPool(ctx, cfg.DatabaseURL, db.PoolOptions{ MaxConns: int32(cfg.DBMaxConns), MinConns: int32(cfg.DBMinConns), MaxConnLifetime: cfg.DBMaxConnLifetime, MaxConnLifetimeJitter: cfg.DBMaxConnLifetimeJitter, MaxConnIdleTime: cfg.DBMaxConnIdleTime, HealthCheckPeriod: cfg.DBHealthCheckPeriod, StatementTimeout: cfg.DBStatementTimeout, }) if err != nil { log.Fatalf("db: %v", err) } defer pool.Close() syncReport := map[string]any{ "wp_path": wpPath, "wp_bytes": len(wpBytes), "companies": []any{}, "generated": time.Now().UTC().Format(time.RFC3339), } for _, co := range []struct { ID uuid.UUID Name string }{ {companyID, "A1 Slovenija"}, {demoID, "Platform Demo"}, } { var legacy string _ = pool.QueryRow(ctx, `SELECT COALESCE(legacy_company_id,'') FROM companies WHERE id=$1`, co.ID).Scan(&legacy) a1Cohort := billing.IsA1CohortCompany(legacy, co.Name) res, serr := processing.SyncCompanyA1(ctx, pool, co.ID, co.Name, a1Cohort, processing.SyncCompanyA1Opts{ MySQLDumpPath: "", // unused — repo seed only (no Downloads dump) SkipDumpBackfill: true, // do not auto-detect ~/Downloads MySQL dump FixCompanyCatalogOpts: processing.FixCompanyCatalogOpts{ BackfillCategories: true, ReprocessSampleLimit: 8, WPCategoriesSQL: wpBytes, // scripts/seed/wp_product_categories.sql AIPrompts: aiprompts.NewService(pool), }, }) entry := map[string]any{ "company_id": co.ID.String(), "company_name": co.Name, "a1_cohort": a1Cohort, "error": nil, "result": res, } if serr != nil { entry["error"] = serr.Error() log.Printf("SyncCompanyA1 %s: %v", co.Name, serr) } else { log.Printf("SyncCompanyA1 %s dump=%s prompts_updated=%d already_ok=%d wp_entries=%d weak_hashes=%d mapped_with=%d", co.Name, res.DumpStatus, res.CategoryPromptsUpdated, res.CategoryPromptsAlreadyOK, res.WPCategoriesEntries, res.WeakHashesCleared, res.MappedWithCategory) } syncReport["companies"] = append(syncReport["companies"].([]any), entry) } writeJSON(out, "sync.json", syncReport) // Confirm sectioned prompts on A1. promptStats := confirmPromptSections(ctx, pool, companyID) writeJSON(out, "prompt_sections.json", promptStats) platEnv := platformsettings.EnvConfig{ AppEncryptionKey: cfg.AppEncryptionKey, CredentialsEncryptionKey: cfg.CredentialsEncryptionKey, TokenSigningSecret: cfg.TokenSigningSecret, DatabaseURL: cfg.DatabaseURL, OpenAIAPIKey: cfg.OpenAIAPIKey, OpenAIBaseURL: cfg.OpenAIBaseURL, OpenAIModel: cfg.OpenAIModel, OpenAIEmbeddingAPIKey: cfg.OpenAIEmbeddingAPIKey, OpenAIEmbeddingBaseURL: cfg.OpenAIEmbeddingBaseURL, OpenAIEmbeddingModel: cfg.OpenAIEmbeddingModel, } platSettings := platformsettings.NewService(pool, platEnv) aiSvc := aiprovider.NewService(pool, aiprovider.EnvConfig{ AppEncryptionKey: cfg.AppEncryptionKey, CredentialsEncryptionKey: cfg.CredentialsEncryptionKey, TokenSigningSecret: cfg.TokenSigningSecret, DatabaseURL: cfg.DatabaseURL, OpenAIAPIKey: cfg.OpenAIAPIKey, OpenAIBaseURL: cfg.OpenAIBaseURL, OpenAIModel: cfg.OpenAIModel, ProcessingRPM: cfg.ProcessingRPM, ProcessingMaxRetries: cfg.ProcessingMaxRetries, }) aiSvc.Platform = platSettings roleCfg, rerr := platSettings.ResolveAIConfig(ctx, platformsettings.AIRoleProcessing) if rerr != nil { failResolve(out, fmt.Sprintf("ResolveAIConfig: %v", rerr)) } completer, modeLabel, byok, cerr := aiSvc.ResolveCompleterForRole(ctx, companyID, aiprovider.RoleProcessing) if cerr != nil { failResolve(out, fmt.Sprintf("ResolveCompleterForRole: %v", cerr)) } if completer == nil { failResolve(out, "ResolveCompleterForRole returned nil completer") } client, ok := completer.(*processing.OpenAIClient) if !ok { failResolve(out, fmt.Sprintf("completer type %T is not *OpenAIClient", completer)) } base := strings.TrimSpace(client.BaseURL) model := strings.TrimSpace(client.Model) resolveInfo := map[string]any{ "role_source": roleCfg.Source, "role_provider": roleCfg.Provider, "role_base_url": roleCfg.BaseURL, "role_model": roleCfg.Model, "role_enabled": roleCfg.Enabled, "completer_base": base, "completer_model": model, "mode_label": modeLabel, "byok": byok, "env_base_url": cfg.OpenAIBaseURL, "env_model": cfg.OpenAIModel, "live": true, } if processing.IsMockOrLoopbackBaseURL(base) || strings.Contains(strings.ToLower(base), "18767") { resolveInfo["live"] = false resolveInfo["fail_reason"] = "resolved completer is mock/loopback — refuse silent mock fallback" writeJSON(out, "resolve.json", resolveInfo) log.Fatalf("LIVE LLM REQUIRED: resolved base=%s model=%s source=%s mode=%s — refuse mock", base, model, roleCfg.Source, modeLabel) } if strings.TrimSpace(client.APIKey) == "" { resolveInfo["live"] = false resolveInfo["fail_reason"] = "empty API key" writeJSON(out, "resolve.json", resolveInfo) log.Fatal("LIVE LLM REQUIRED: API key empty after resolve") } // Connectivity probe — fail clearly on 502. modelsURL := strings.TrimRight(base, "/") + "/models" keyHint := "" if k := strings.TrimSpace(client.APIKey); len(k) > 8 { keyHint = k[:4] + "…" + k[len(k)-4:] } resolveInfo["api_key_hint"] = keyHint modelsCtx, modelsCancel := context.WithTimeout(ctx, 30*time.Second) defer modelsCancel() modelsReq, merr := http.NewRequestWithContext(modelsCtx, http.MethodGet, modelsURL, nil) if merr != nil { failResolve(out, "models request build: "+merr.Error()) } modelsReq.Header.Set("Authorization", "Bearer "+client.APIKey) modelsReq.Header.Set("Accept", "application/json") modelsStart := time.Now() modelsResp, merr := http.DefaultClient.Do(modelsReq) modelsElapsed := time.Since(modelsStart).Round(time.Millisecond) if merr != nil { resolveInfo["probe_ok"] = false resolveInfo["models_error"] = processing.TruncateError(merr) resolveInfo["fail_reason"] = "GET /v1/models network error" writeJSON(out, "resolve.json", resolveInfo) log.Fatalf("LIVE LLM CONNECTION ERROR: GET %s err=%s", modelsURL, processing.TruncateError(merr)) } modelsBody, _ := io.ReadAll(io.LimitReader(modelsResp.Body, 2048)) _ = modelsResp.Body.Close() snippet := strings.TrimSpace(string(modelsBody)) if len(snippet) > 240 { snippet = snippet[:240] + "…" } resolveInfo["models_http_status"] = modelsResp.StatusCode resolveInfo["models_elapsed"] = modelsElapsed.String() resolveInfo["models_body_snippet"] = snippet if modelsResp.StatusCode == http.StatusBadGateway { resolveInfo["probe_ok"] = false resolveInfo["fail_reason"] = "GET /v1/models returned HTTP 502 (OverloadedBot/upstream)" writeJSON(out, "resolve.json", resolveInfo) log.Fatalf("LIVE LLM 502: GET %s — OverloadedBot upstream unavailable — restart note; no mock", modelsURL) } // 200 = healthy; 401 = gateway up (auth) — both allow ProcessJob with resolved key. if modelsResp.StatusCode != http.StatusOK && modelsResp.StatusCode != http.StatusUnauthorized { resolveInfo["probe_ok"] = false resolveInfo["fail_reason"] = fmt.Sprintf("GET /v1/models HTTP %d", modelsResp.StatusCode) writeJSON(out, "resolve.json", resolveInfo) log.Fatalf("LIVE LLM CONNECTION ERROR: GET %s status=%d snippet=%q", modelsURL, modelsResp.StatusCode, snippet) } resolveInfo["models_auth_ok"] = modelsResp.StatusCode == http.StatusOK if model == "code-fast" && strings.Contains(string(modelsBody), `"green/code-fast"`) { client.Model = "green/code-fast" model = client.Model resolveInfo["completer_model_adjusted"] = model log.Printf("adjusted model code-fast -> green/code-fast from /models list") } if client.HTTPClient != nil { client.HTTPClient.Timeout = 180 * time.Second } client.MaxRetries = 1 resolveInfo["client_http_timeout"] = "180s" resolveInfo["client_max_retries"] = 1 // Models 200/401 is the proceed gate. Chat probe is best-effort (retry); only 502 hard-stops. var probeOK bool var probeErr string var probeElapsed time.Duration var probeLen int for attempt := 1; attempt <= 3; attempt++ { probeCtx, probeCancel := context.WithTimeout(ctx, 90*time.Second) probeStart := time.Now() comp, perr := client.Complete(probeCtx, "Reply with exactly: PONG", "Say PONG") probeElapsed = time.Since(probeStart).Round(time.Millisecond) probeCancel() if perr == nil { probeOK = true probeLen = len(comp.Text) break } probeErr = processing.TruncateError(perr) log.Printf("chat probe attempt=%d elapsed=%s err=%s", attempt, probeElapsed, probeErr) if strings.Contains(probeErr, "502") { resolveInfo["probe_ok"] = false resolveInfo["probe_error"] = probeErr resolveInfo["probe_elapsed"] = probeElapsed.String() resolveInfo["fail_reason"] = "chat/completions HTTP 502" writeJSON(out, "resolve.json", resolveInfo) log.Fatalf("LIVE LLM 502: chat probe failed — restart note; no mock — %s", probeErr) } time.Sleep(time.Duration(attempt) * 2 * time.Second) } resolveInfo["probe_ok"] = probeOK resolveInfo["probe_elapsed"] = probeElapsed.String() resolveInfo["probe_response_len"] = probeLen if !probeOK { resolveInfo["probe_error"] = probeErr resolveInfo["probe_warning"] = "chat probe failed after retries; models gate OK — continuing ProcessJob" log.Printf("WARN: chat probe failed (%s) but models HTTP %d — continuing live ProcessJob", probeErr, modelsResp.StatusCode) } writeJSON(out, "resolve.json", resolveInfo) log.Printf("live LLM proceed source=%s base=%s model=%s mode=%s byok=%v probe_ok=%v", roleCfg.Source, base, model, modeLabel, byok, probeOK) pipeline := processing.NewPipeline(pool) pipeline.BatchSize = cfg.ProcessingBatchSize pipeline.AI = aiSvc pipeline.Prompts = aiprompts.NewService(pool) eprelClient := eprel.NewClient(eprel.Options{Enabled: true, Timeout: 20 * time.Second}) pipeline.Engine = &processing.Engine{ Completer: nil, Vector: processing.NoopVectorCategorizer{}, EPREL: eprelClient, ProviderMode: processing.AIProviderInternal, } // Prefer mapped-category EANs; include issue EAN if raw exists. selected := append([]string{}, eans...) if strings.TrimSpace(issueEAN) != "" { var issueExists bool _ = pool.QueryRow(ctx, `SELECT EXISTS(SELECT 1 FROM raw_products WHERE company_id=$1 AND gtin=$2)`, companyID, issueEAN).Scan(&issueExists) if issueExists { selected = append(selected, issueEAN) } } rawIDs := make([]uuid.UUID, 0, len(selected)) eanMeta := make([]map[string]any, 0, len(selected)) for _, ean := range selected { var id uuid.UUID var cat, catName, title string err := pool.QueryRow(ctx, ` SELECT r.id, COALESCE(r.mapped_data->>'category',''), COALESCE(c.name,''), COALESCE(NULLIF(r.mapped_data->>'name',''), NULLIF(r.mapped_data->>'title',''), '') FROM raw_products r LEFT JOIN categories c ON c.company_id=r.company_id AND c.unique_id=r.mapped_data->>'category' WHERE r.company_id=$1 AND r.gtin=$2`, companyID, ean).Scan(&id, &cat, &catName, &title) if err != nil { log.Fatalf("raw product %s: %v", ean, err) } rawIDs = append(rawIDs, id) eanMeta = append(eanMeta, map[string]any{ "ean": ean, "raw_id": id.String(), "category": cat, "category_name": catName, "title": title, }) log.Printf("ean=%s raw=%s cat=%s/%s", ean, id, cat, catName) } writeJSON(out, "selected_eans.json", eanMeta) // Force re-enhance. tag, cerr2 := pool.Exec(ctx, ` UPDATE processed_products pp SET field_sources = COALESCE(field_sources, '{}'::jsonb) - 'enhance_input_hash', localized = CASE WHEN localized IS NULL OR localized = '{}'::jsonb THEN localized ELSE ( SELECT COALESCE(jsonb_object_agg(lang, val - 'enhance_input_hash'), '{}'::jsonb) FROM jsonb_each(localized) AS t(lang, val) ) END, updated_at = now() FROM raw_products rp WHERE pp.company_id = $1 AND pp.raw_product_id = rp.id AND rp.gtin = ANY($2::text[])`, companyID, selected) if cerr2 != nil { log.Printf("clear enhance hash: %v", cerr2) } else { log.Printf("cleared enhance_input_hash rows=%d", tag.RowsAffected()) } _, _ = pool.Exec(ctx, ` UPDATE processing_jobs SET status = 'failed', error = 'yielded to final verify 20260817', updated_at = now() WHERE company_id = $1 AND status IN ('pending','running','processing')`, companyID) jobs, err := pipeline.StartJob(ctx, companyID, userID, rawIDs, "full") if err != nil { log.Fatalf("StartJob: %v", err) } if len(jobs) == 0 { log.Fatal("StartJob returned no jobs") } jobID := jobs[0].ID log.Printf("job_id=%s chunks=%d", jobID, len(jobs)) _ = os.WriteFile(filepath.Join(out, "process_id.txt"), []byte(jobID.String()+"\n"), 0o644) // Start sample expectation: pending + processed_items=0. startSample := map[string]any{ "data": map[string]any{ "process_id": jobID.String(), "status": strings.ToLower(jobs[0].Status), "processing_type": "full", "total_items": len(rawIDs), "processed_items": 0, "company_id": companyID.String(), }, } var dbStatus string var processedCount int _ = pool.QueryRow(ctx, `SELECT lower(status), COALESCE(processed_count,0) FROM processing_jobs WHERE id=$1`, jobID).Scan(&dbStatus, &processedCount) startSample["data"].(map[string]any)["db_status"] = dbStatus startSample["data"].(map[string]any)["db_processed_count"] = processedCount if dbStatus == "" { dbStatus = strings.ToLower(jobs[0].Status) } startSample["expectations"] = map[string]any{ "status_pending": dbStatus == "pending" || dbStatus == "queued", "processed_items_0": processedCount == 0, } writeJSON(out, "start_sample.json", startSample) defend := make(chan struct{}) go func() { t := time.NewTicker(500 * time.Millisecond) defer t.Stop() for { select { case <-defend: return case <-ctx.Done(): return case <-t.C: _, _ = pool.Exec(context.Background(), ` UPDATE processing_jobs SET status = 'failed', error = 'yielded to final verify 20260817', updated_at = now() WHERE company_id = $1 AND status IN ('pending','running','processing') AND id <> $2`, companyID, jobID) _, _ = pool.Exec(context.Background(), ` UPDATE processing_jobs SET status = 'running', error = NULL, updated_at = now() WHERE id = $1 AND status IN ('failed','cancelled') AND (error ILIKE '%P0%' OR error ILIKE '%parked%' OR error ILIKE '%yield%' OR error ILIKE '%reclaim%' OR error ILIKE '%cleared%' OR error ILIKE '%superseded%' OR error ILIKE '%exclusive%' OR error ILIKE '%batch_%' OR error ILIKE '%inproc%' OR error ILIKE '%formula%' OR error ILIKE '%live LLM%' OR error ILIKE '%final verify%')`, jobID) _, _ = pool.Exec(context.Background(), ` UPDATE processing_job_products SET status = 'pending', error = NULL, updated_at = now() WHERE job_id = $1 AND status IN ('failed','cancelled') AND processed_product_id IS NULL AND (error ILIKE '%P0%' OR error ILIKE '%parked%' OR error ILIKE '%yield%' OR error ILIKE '%reclaim%' OR error ILIKE '%cleared%' OR error ILIKE '%superseded%' OR error ILIKE '%exclusive%' OR error ILIKE '%batch_%' OR error ILIKE '%inproc%' OR error ILIKE '%formula%' OR error ILIKE '%live LLM%' OR error ILIKE '%final verify%')`, jobID) } } }() _, _ = pool.Exec(ctx, ` UPDATE processing_jobs SET status = 'running', started_at = COALESCE(started_at, now()), updated_at = now() WHERE id = $1`, jobID) runCtx, runCancel := context.WithTimeout(ctx, 18*time.Minute) defer runCancel() if err := pipeline.ProcessJob(runCtx, jobID); err != nil { close(defend) log.Fatalf("ProcessJob: %v", err) } close(defend) items, err := pipeline.LoadV1ProcessJobItems(ctx, companyID, jobID, "full") if err != nil { log.Fatalf("LoadV1ProcessJobItems: %v", err) } finalPayload := map[string]any{ "data": map[string]any{ "process_id": jobID.String(), "status": "COMPLETED", "processing_type": "full", "total_items": len(items), "items": items, "llm": map[string]any{ "base": base, "model": model, "source": roleCfg.Source, "mode": modeLabel, "byok": byok, }, }, } writeJSON(out, "final.json", finalPayload) logBytes, _ := os.ReadFile(logPath) logText := string(logBytes) aiEnhanceSeen := strings.Contains(logText, "ai_enhance") skipBlocked := extractSkipBlocked(logText) scorecards := make([]map[string]any, 0, len(items)) htmlExcerpts := make([]map[string]any, 0, 2) allPass := true startOK := (dbStatus == "pending" || dbStatus == "queued") && processedCount == 0 for _, item := range items { ean := str(item["ean"]) if ean == "" { ean = str(item["product_id"]) } title := firstNonEmpty(str(item["name"]), str(item["title"])) desc := str(item["description"]) catName := str(item["category_name"]) if catName == "" { if m, ok := item["category"].(map[string]any); ok { catName = str(m["name"]) } } catID := "" switch c := item["category"].(type) { case string: catID = c case map[string]any: catID = firstNonEmpty(str(c["category_id"]), str(c["id"]), str(c["unique_id"])) if catName == "" { catName = str(c["name"]) } } if catID == "" { catID = str(item["category_id"]) } _, hasMetaTitle := item["meta_title"] _, hasMetaDesc := item["meta_description"] _, hasID := item["id"] _, hasPPID := item["processed_product_id"] _, hasRawID := item["raw_product_id"] invent := looksLikeInventBoilerplate(desc) hasHTML := strings.Contains(strings.ToLower(desc), "