diff --git a/client/captcha_v2.go b/client/captcha_v2.go index 1a3b925..4a43653 100644 --- a/client/captcha_v2.go +++ b/client/captcha_v2.go @@ -172,6 +172,14 @@ func (s *captchaV2Session) solveOnce(captchaErr *VkCaptchaError) (string, error) return "", errors.New("failed to find slider captcha settings") } + pageShowType := "" + if page.Init != nil { + pageShowType = page.Init.Data.ShowCaptchaType + } + debugThrottledf("captcha-v2-page", + "[Captcha][debug] v2 page parsed show_type=%q pow_difficulty=%d slider_available=%t script=%s html_len=%d", + pageShowType, page.PowDifficulty, sliderSettings != "", page.ScriptURL, len(html)) + log.Printf("v2 captcha solving pow difficulty=%d", page.PowDifficulty) hash := solveCaptchaPoWV2(s.ctx, page.PowInput, page.PowDifficulty) if hash == "" { diff --git a/client/main.go b/client/main.go index 6e1bdaf..f470ecd 100644 --- a/client/main.go +++ b/client/main.go @@ -78,6 +78,58 @@ func debugf(format string, v ...any) { } } +// debugThrottleInterval is the minimum gap between two emissions of the same +// throttled debug key. It keeps verbose per-stream diagnostics readable when +// many streams hit the same code path at once (e.g. all of them getting the +// same captcha challenge within a second). +const debugThrottleInterval = 3 * time.Second + +var debugThrottleState sync.Map // key string -> *atomic.Int64 (last emit, unix nano) + +// debugThrottledf logs like debugf but at most once per debugThrottleInterval +// for a given key. Use distinct keys for distinct message groups. +func debugThrottledf(key, format string, v ...any) { + if !isDebug { + return + } + now := time.Now().UnixNano() + val, _ := debugThrottleState.LoadOrStore(key, new(atomic.Int64)) + last, ok := val.(*atomic.Int64) + if !ok { + return + } + prev := last.Load() + if prev != 0 && now-prev < int64(debugThrottleInterval) { + return + } + // CompareAndSwap ensures only one goroutine wins the slot per interval. + if !last.CompareAndSwap(prev, now) { + return + } + log.Printf(format, v...) +} + +// debugCaptchaError emits a throttled, human-readable breakdown of a captcha +// challenge: the parsed fields plus a redacted session_token preview, without +// dumping the multi-kilobyte raw redirect_uri on every stream. +func debugCaptchaError(streamID int, c *VkCaptchaError) { + if !isDebug || c == nil { + return + } + redirectBase := c.RedirectURI + if u, err := neturl.Parse(c.RedirectURI); err == nil { + redirectBase = u.Scheme + "://" + u.Host + u.Path + } + tokenPreview := c.SessionToken + if len(tokenPreview) > 12 { + tokenPreview = tokenPreview[:12] + "…" + } + debugThrottledf("captcha-error", + "[STREAM %d] [Captcha][debug] code=%d msg=%q captcha_sid=%q captcha_img=%t redirect=%s session_token=%s (len=%d)", + streamID, c.ErrorCode, c.ErrorMsg, c.CaptchaSid, c.CaptchaImg != "", + redirectBase, tokenPreview, len(c.SessionToken)) +} + type captchaSolveMode int const ( @@ -1160,6 +1212,7 @@ func getTokenChain(ctx context.Context, link string, streamID int, creds VKCrede if errObj, hasErr := resp["error"].(map[string]interface{}); hasErr { captchaErr := ParseVkCaptchaError(errObj) if captchaErr != nil && captchaErr.IsCaptchaError() { + debugCaptchaError(streamID, captchaErr) solveMode, hasSolveMode := captchaSolveModeForAttempt(attempt, manualCaptcha, autoCaptchaSliderPOC) if !hasSolveMode { log.Printf("[STREAM %d] [Captcha] No more solve modes available (attempt %d)", streamID, attempt+1) @@ -1175,6 +1228,10 @@ func getTokenChain(ctx context.Context, link string, streamID int, creds VKCrede return "", "", nil, fmt.Errorf("CAPTCHA_WAIT_REQUIRED") } + debugThrottledf("captcha-mode", + "[STREAM %d] [Captcha][debug] attempt=%d solving via %s", + streamID, attempt+1, captchaSolveModeLabel(solveMode)) + var successToken string var captchaKey string var solveErr error @@ -1286,6 +1343,14 @@ func getTokenChain(ctx context.Context, link string, streamID int, creds VKCrede } continue } + // error_code:14 that did not pass IsCaptchaError means VK changed the + // challenge shape again — surface the raw map under -debug so the next + // breakage is diagnosable without a code change. + if code, _ := errObj["error_code"].(float64); int(code) == 14 { + debugThrottledf("captcha-unrecognized", + "[STREAM %d] [Captcha][debug] error_code:14 not recognized as solvable captcha, raw=%v", + streamID, errObj) + } return "", "", nil, fmt.Errorf("VK API error: %v", errObj) } diff --git a/client/main_test.go b/client/main_test.go index 1a49653..1e4f2c0 100644 --- a/client/main_test.go +++ b/client/main_test.go @@ -1,6 +1,11 @@ package main -import "testing" +import ( + "bytes" + "log" + "strings" + "testing" +) func TestCaptchaSolveModeForAttempt(t *testing.T) { t.Parallel() @@ -111,3 +116,31 @@ func TestParseVkCaptchaErrorLegacySid(t *testing.T) { t.Fatal("expected captcha_img to be preserved") } } + +func TestDebugThrottledfSuppressesRepeats(t *testing.T) { + // Not parallel: mutates package-global isDebug and log output. + prevDebug := isDebug + isDebug = true + defer func() { isDebug = prevDebug }() + + var buf bytes.Buffer + prevOut := log.Writer() + prevFlags := log.Flags() + log.SetOutput(&buf) + log.SetFlags(0) + defer func() { + log.SetOutput(prevOut) + log.SetFlags(prevFlags) + }() + + key := "test-throttle-" + t.Name() + debugThrottleState.Delete(key) + + for i := 0; i < 5; i++ { + debugThrottledf(key, "tick %d", i) + } + + if got := strings.Count(buf.String(), "tick "); got != 1 { + t.Fatalf("expected throttle to emit exactly once within interval, got %d lines: %q", got, buf.String()) + } +}