From 9d7d7547402bc78fa269cefb78730ba2861732dc Mon Sep 17 00:00:00 2001 From: samosvalishe Date: Wed, 20 May 2026 11:23:05 +0300 Subject: [PATCH] =?UTF-8?q?refactor(logging):=20=D1=83=D0=BD=D0=B8=D1=84?= =?UTF-8?q?=D0=B8=D1=86=D0=B8=D1=80=D0=BE=D0=B2=D0=B0=D1=82=D1=8C=20stdlib?= =?UTF-8?q?=20log.*=20=D0=B2=20logx=20=D0=BF=D0=BE=20client/cmd?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit internal/client/captcha, captcha/manual, dnsdial: добавить package-level Log + SetLogger; убрать прямой обход -debug через stdlib log.Printf. cmd/{client, server}/main.go: сначала строить logger, весь вывод через logger.{Info,Warn, Error}f; оставлен один log.Fatalf только для сбоя разбора конфига до логгера. dnsdial: log.Panicf → panic(fmt.Sprintf). Исправлены уровни: - vkauth/token.go: пути [FATAL] теперь Errorf; Auto/Manual captcha failed → Warnf; ignored-cleanup-error → Debugf. - vkauth/client.go: HandleAuthError/cache invalidated → Warnf; throttle wait → Debugf; Failed-with-client_id → Warnf. - udprelay: "Backing off 60s" + SetDeadline failed → Warnf. - captcha: PoW/show_type/check status/debug_info → Debugf; endSession/close-body/ script-drift → Warnf. Префиксы нормализованы к [STREAM %d] [Pkg] msg / [Pkg] msg. --- cmd/vk-turn-client/main.go | 41 +++++++++++++++--------- cmd/vk-turn-server/main.go | 41 ++++++++++++++---------- internal/client/captcha/captcha.go | 33 +++++++++++-------- internal/client/captcha/errors.go | 13 ++++---- internal/client/captcha/manual/manual.go | 41 ++++++++++++++---------- internal/client/captcha/slider.go | 11 +++---- internal/client/dnsdial/doh.go | 31 +++++++++++------- internal/client/vkauth/auto_solver.go | 7 ++-- internal/client/vkauth/client.go | 12 +++---- internal/client/vkauth/token.go | 24 +++++++------- internal/proxy/udprelay/udprelay.go | 4 +-- 11 files changed, 146 insertions(+), 112 deletions(-) diff --git a/cmd/vk-turn-client/main.go b/cmd/vk-turn-client/main.go index cc6ac64..3c55eff 100644 --- a/cmd/vk-turn-client/main.go +++ b/cmd/vk-turn-client/main.go @@ -39,51 +39,58 @@ func manualCaptchaSolver(_ context.Context, e *captcha.Error, d net.Dialer) (str } func main() { + cfg, err := config.ParseClient(os.Args[1:], os.Stderr) + if err != nil { + // logger not built yet — config parse failure is the only pre-logger fatal. + log.Fatalf("%v", err) + } + + logger := logx.New(cfg.Log.Debug) + captcha.SetLogger(logger) + manualcaptcha.SetLogger(logger) + dnsdial.SetLogger(logger) + manualcaptcha.Debug = cfg.Log.Debug + ctx, cancel := context.WithCancel(context.Background()) defer cancel() signalChan := make(chan os.Signal, 1) signal.Notify(signalChan, syscall.SIGTERM, syscall.SIGINT) go func() { <-signalChan - log.Printf("Terminating...\n") + logger.Infof("Terminating...") cancel() select { case <-signalChan: case <-time.After(5 * time.Second): } - log.Fatalf("Exit...\n") + logger.Errorf("Exit...") + os.Exit(1) }() - cfg, err := config.ParseClient(os.Args[1:], os.Stderr) - if err != nil { - log.Fatalf("%v", err) - } - if cfg.DNS.Servers != nil { dnsdial.SetUDPDNSServers(cfg.DNS.Servers) - log.Printf("[DNS] using custom UDP servers: %v", cfg.DNS.Servers) + logger.Infof("[DNS] using custom UDP servers: %v", cfg.DNS.Servers) } appDialer := dnsdial.AppDialer(cfg.DNS.Mode) dnsdial.InstallGlobalResolver(cfg.DNS.Mode) if cfg.Obf.GenWrapKey { key, gerr := srtpmimicry.GenKeyHex() if gerr != nil { - log.Panicf("%v", gerr) + logger.Errorf("gen-wrap-key: %v", gerr) + os.Exit(1) } fmt.Println(key) return } peer, err := net.ResolveUDPAddr("udp", cfg.Proxy.Peer) if err != nil { - panic(err) + logger.Errorf("resolve peer addr: %v", err) + os.Exit(1) } if cfg.Obf.WrapMode { - log.Printf("WRAP mode enabled: peer server must use matching -wrap-key") + logger.Infof("WRAP mode enabled: peer server must use matching -wrap-key") } - logger := logx.New(cfg.Log.Debug) - manualcaptcha.Debug = cfg.Log.Debug - var connectedStreams atomic.Int32 vkAuth := vkauth.New(vkauth.Config{ @@ -112,7 +119,8 @@ func main() { GetCreds: tcpfwd.GetCredsFunc(vkAuth.GetCredentials), } if err := tcpfwd.Run(ctx, vlessDeps, vlessParams, peer, cfg.Proxy.Listen, cfg.TURN.N, cfg.Proxy.Mode == config.ProxyModeTCPFwdBond); err != nil { - log.Fatalf("tcpfwd: %v", err) + logger.Errorf("tcpfwd: %v", err) + os.Exit(1) } return } @@ -130,6 +138,7 @@ func main() { GetCreds: udprelay.GetCredsFunc(vkAuth.GetCredentials), } if err := udprelay.Run(ctx, udpDtlsDialer, vkAuth, logger, &connectedStreams, cancel, udpParams, peer, cfg.Proxy.Listen, cfg.TURN.N); err != nil { - log.Fatalf("udprelay: %v", err) + logger.Errorf("udprelay: %v", err) + os.Exit(1) } } diff --git a/cmd/vk-turn-server/main.go b/cmd/vk-turn-server/main.go index edfd1c1..c0df945 100644 --- a/cmd/vk-turn-server/main.go +++ b/cmd/vk-turn-server/main.go @@ -24,6 +24,7 @@ import ( func main() { cfg, err := config.ParseServer(os.Args[1:], os.Stderr) if err != nil { + // logger not built yet — config parse failure is the only pre-logger fatal. log.Fatalf("%v", err) } logger := logx.New(cfg.Log.Debug) @@ -32,7 +33,8 @@ func main() { if cfg.Obf.GenWrapKey { key, gerr := srtpmimicry.GenKeyHex() if gerr != nil { - log.Fatalf("gen-wrap-key: %v", gerr) + logger.Errorf("gen-wrap-key: %v", gerr) + os.Exit(1) } fmt.Println(key) return @@ -44,22 +46,25 @@ func main() { signal.Notify(signalChan, syscall.SIGTERM, syscall.SIGINT) go func() { <-signalChan - log.Printf("Terminating...\n") + logger.Infof("Terminating...") cancel() <-signalChan - log.Fatalf("Exit...\n") + logger.Errorf("Exit...") + os.Exit(1) }() addr, err := net.ResolveUDPAddr("udp", cfg.Proxy.Listen) if err != nil { - panic(err) + logger.Errorf("resolve listen addr: %v", err) + os.Exit(1) } - log.Printf("Starting server listen=%s connect=%s vless=%t wrap=%t bond-autodetect=true", + logger.Infof("Starting server listen=%s connect=%s vless=%t wrap=%t bond-autodetect=true", cfg.Proxy.Listen, cfg.Proxy.Connect, cfg.Proxy.Mode == config.ProxyModeTCPFwd, cfg.Obf.WrapMode) certificate, genErr := selfsign.GenerateSelfSigned() if genErr != nil { - panic(genErr) + logger.Errorf("self-signed cert: %v", genErr) + os.Exit(1) } dtlsOpts := []dtls.ServerOption{ @@ -70,25 +75,27 @@ func main() { } var listener net.Listener if cfg.Obf.WrapMode { - log.Printf("WRAP mode enabled: listener only accepts clients with matching -wrap-key") + logger.Infof("WRAP mode enabled: listener only accepts clients with matching -wrap-key") wrapListener, werr := srtpmimicry.Listen(addr, cfg.Obf.WrapKey) if werr != nil { - panic(werr) + logger.Errorf("wrap listen: %v", werr) + os.Exit(1) } listener, err = dtls.NewListenerWithOptions(wrapListener, dtlsOpts...) } else { listener, err = dtls.ListenWithOptions("udp", addr, dtlsOpts...) } if err != nil { - panic(err) + logger.Errorf("dtls listen: %v", err) + os.Exit(1) } context.AfterFunc(ctx, func() { if err = listener.Close(); err != nil { - panic(err) + logger.Errorf("listener close: %v", err) } }) - fmt.Println("Listening") + logger.Infof("Listening on %s", cfg.Proxy.Listen) var wg sync.WaitGroup for { @@ -100,7 +107,7 @@ func main() { } conn, err := listener.Accept() if err != nil { - log.Println(err) + logger.Warnf("accept: %v", err) continue } wg.Go(func() { @@ -112,22 +119,22 @@ func main() { func handleAccepted(ctx context.Context, logger logx.Logger, registry *bondserver.Registry, conn net.Conn, cfg *config.Server) { defer func() { if closeErr := conn.Close(); closeErr != nil { - log.Printf("failed to close incoming connection: %s", closeErr) + logger.Warnf("failed to close incoming connection: %s", closeErr) } }() - logger.Debugf("Connection from %s\n", conn.RemoteAddr()) + logger.Debugf("Connection from %s", conn.RemoteAddr()) ctx1, cancel1 := context.WithTimeout(ctx, 30*time.Second) defer cancel1() dtlsConn, ok := conn.(*dtls.Conn) if !ok { - log.Println("Type error: expected *dtls.Conn") + logger.Errorf("Type error: expected *dtls.Conn") return } logger.Debugf("Start handshake") if err := dtlsConn.HandshakeContext(ctx1); err != nil { - log.Printf("Handshake failed: %v", err) + logger.Warnf("Handshake failed: %v", err) return } logger.Debugf("Handshake done") @@ -138,5 +145,5 @@ func handleAccepted(ctx context.Context, logger logx.Logger, registry *bondserve udpserver.Handle(ctx, logger, conn, cfg.Proxy.Connect) } - logger.Debugf("Connection closed: %s\n", conn.RemoteAddr()) + logger.Debugf("Connection closed: %s", conn.RemoteAddr()) } diff --git a/internal/client/captcha/captcha.go b/internal/client/captcha/captcha.go index 3372831..a597561 100644 --- a/internal/client/captcha/captcha.go +++ b/internal/client/captcha/captcha.go @@ -11,7 +11,6 @@ import ( "errors" "fmt" "io" - "log" mathrand "math/rand" "regexp" "strconv" @@ -23,8 +22,16 @@ import ( tlsclient "github.com/bogdanfinn/tls-client" "github.com/cacggghp/vk-turn-proxy/internal/client/browserprofile" + "github.com/cacggghp/vk-turn-proxy/internal/logx" ) +// Log is the package-level logger. Defaults to no-op; main wires it via +// SetLogger so captcha output respects the global -debug flag and levels. +var Log logx.Logger = logx.Nop() + +// SetLogger installs a logger for this package. Safe to call once at startup. +func SetLogger(l logx.Logger) { Log = logx.OrNop(l) } + const ( captchaAPIVersion = "5.131" captchaScriptVersion = "1.1.1324" @@ -121,7 +128,7 @@ func Solve( if captchaErr == nil || captchaErr.SessionToken == "" { return "", fmt.Errorf("no session_token in redirect_uri") } - log.Printf("[STREAM %d] [Captcha] Solving VK Smart Captcha automatically...", streamID) + Log.Infof("[STREAM %d] [Captcha] Solving VK Smart Captcha automatically...", streamID) s := &captchaSession{ctx: ctx, client: client, profile: profile, savedProfile: savedProfile} @@ -130,7 +137,7 @@ func Solve( if solveErr == nil { return token, nil } - log.Printf("[STREAM %d] [Captcha] captcha solve attempt %d failed: %v", streamID, attempt, solveErr) + Log.Warnf("[STREAM %d] [Captcha] solve attempt %d failed: %v", streamID, attempt, solveErr) if errors.Is(solveErr, errCaptchaRateLimit) { return "", solveErr } @@ -176,12 +183,12 @@ func (s *captchaSession) solveOnce(captchaErr *Error) (string, error) { return "", errors.New("failed to find slider captcha settings") } - log.Printf("captcha solving pow difficulty=%d", page.PowDifficulty) + Log.Debugf("[Captcha] solving pow difficulty=%d", page.PowDifficulty) hash := solveCaptchaPoW(s.ctx, page.PowInput, page.PowDifficulty) if hash == "" { return "", errors.New("captcha pow failed") } - log.Printf("captcha pow solved") + Log.Debugf("[Captcha] pow solved") base := captchaBaseValues(captchaErr.SessionToken) if _, settingsErr := s.captchaRequest("captchaNotRobot.settings", base); settingsErr != nil { @@ -198,7 +205,7 @@ func (s *captchaSession) solveOnce(captchaErr *Error) (string, error) { if m := reCaptchaVersion.FindStringSubmatch(page.ScriptURL); len(m) > 1 { if m[1] != captchaScriptVersion { - log.Printf("captcha script version drift: known=%s latest=%s", captchaScriptVersion, m[1]) + Log.Warnf("[Captcha] script version drift: known=%s latest=%s", captchaScriptVersion, m[1]) } } @@ -213,7 +220,7 @@ func (s *captchaSession) solveOnce(captchaErr *Error) (string, error) { } var token string for { - log.Printf("captcha solving show_type=%s", showType) + Log.Debugf("[Captcha] solving show_type=%s", showType) switch showType { case "slider": token, err = s.solveSliderCaptcha(captchaErr.SessionToken, browserFP, hash, sliderSettings, debugInfo) @@ -226,7 +233,7 @@ func (s *captchaSession) solveOnce(captchaErr *Error) (string, error) { break } if errors.Is(err, errCaptchaBot) && !strings.EqualFold(showType, "slider") && sliderSettings != "" { - log.Printf("captcha checkbox returned BOT, trying slider challenge from page settings") + Log.Infof("[Captcha] checkbox returned BOT, trying slider challenge") showType = "slider" continue } @@ -238,7 +245,7 @@ func (s *captchaSession) solveOnce(captchaErr *Error) (string, error) { } if _, endErr := s.captchaRequest("captchaNotRobot.endSession", base); endErr != nil { - log.Printf("captcha endSession failed: %v", endErr) + Log.Warnf("[Captcha] endSession failed: %v", endErr) } return token, nil } @@ -293,7 +300,7 @@ func (s *captchaSession) fetchDebugInfo(scriptURL string) (string, error) { } v := string(m[1]) captchaDebugCache.Store(scriptURL, v) - log.Printf("captcha debug_info fetched url=%s", scriptURL) + Log.Debugf("[Captcha] debug_info fetched url=%s", scriptURL) return v, nil } @@ -386,9 +393,9 @@ func (s *captchaSession) performCaptchaCheck( return nil, err } if check.ShowType != "" { - log.Printf("captcha check status=%s show_type=%s", check.Status, check.ShowType) + Log.Debugf("[Captcha] check status=%s show_type=%s", check.Status, check.ShowType) } else { - log.Printf("captcha check status=%s", check.Status) + Log.Debugf("[Captcha] check status=%s", check.Status) } return check, nil } @@ -521,7 +528,7 @@ func (s *captchaSession) doRaw( } defer func() { if closeErr := resp.Body.Close(); closeErr != nil { - log.Printf("captcha close body: %s", closeErr) + Log.Warnf("[Captcha] close body: %s", closeErr) } }() return io.ReadAll(resp.Body) diff --git a/internal/client/captcha/errors.go b/internal/client/captcha/errors.go index 80a74c9..35db0f1 100644 --- a/internal/client/captcha/errors.go +++ b/internal/client/captcha/errors.go @@ -2,7 +2,6 @@ package captcha import ( "fmt" - "log" neturl "net/url" ) @@ -25,14 +24,14 @@ type Error struct { func ParseError(errData map[string]any) *Error { codeFloat, ok := errData["error_code"].(float64) if !ok { - log.Printf("missing error_code in captcha error data") + Log.Warnf("[Captcha] missing error_code in error data") return nil } code := int(codeFloat) redirectURI, ok := errData["redirect_uri"].(string) if !ok { - log.Printf("missing redirect_uri in captcha error data") + Log.Warnf("[Captcha] missing redirect_uri in error data") return nil } @@ -41,20 +40,20 @@ func ParseError(errData map[string]any) *Error { if sidNum, ok2 := errData["captcha_sid"].(float64); ok2 { captchaSid = fmt.Sprintf("%.0f", sidNum) } else { - log.Printf("missing captcha_sid in captcha error data") + Log.Warnf("[Captcha] missing captcha_sid in error data") return nil } } captchaImg, ok := errData["captcha_img"].(string) if !ok { - log.Printf("missing captcha_img in captcha error data") + Log.Warnf("[Captcha] missing captcha_img in error data") return nil } errorMsg, ok := errData["error_msg"].(string) if !ok { - log.Printf("missing error_msg in captcha error data") + Log.Warnf("[Captcha] missing error_msg in error data") return nil } @@ -63,7 +62,7 @@ func ParseError(errData map[string]any) *Error { if parsed, err := neturl.Parse(redirectURI); err == nil { sessionToken = parsed.Query().Get("session_token") } else { - log.Printf("failed to parse redirect_uri: %v", err) + Log.Warnf("[Captcha] failed to parse redirect_uri: %v", err) return nil } } diff --git a/internal/client/captcha/manual/manual.go b/internal/client/captcha/manual/manual.go index f60d005..f3cb9aa 100644 --- a/internal/client/captcha/manual/manual.go +++ b/internal/client/captcha/manual/manual.go @@ -14,7 +14,6 @@ import ( "errors" "fmt" "io" - "log" "net" "net/http" "net/http/httputil" @@ -27,12 +26,20 @@ import ( "github.com/cacggghp/vk-turn-proxy/internal/client/browserprofile" "github.com/cacggghp/vk-turn-proxy/internal/client/ish" + "github.com/cacggghp/vk-turn-proxy/internal/logx" ) // Debug toggles verbose request/response logging for the proxied browser // traffic. Set from main once cfg is parsed. var Debug bool +// Log is the package-level logger; defaults to no-op. main wires it via +// SetLogger so manual-captcha output respects -debug and levels. +var Log logx.Logger = logx.Nop() + +// SetLogger installs a logger for this package. +func SetLogger(l logx.Logger) { Log = logx.OrNop(l) } + const captchaListenPort = "8765" type browserCommand struct { @@ -516,12 +523,12 @@ func startCaptchaServer(srv *http.Server, logPrefix string) error { listening = true wrappedListener, err := ish.WrapListener(listener) if err != nil { - log.Printf("%s: failed to wrap listener for iSH: %v", logPrefix, err) + Log.Warnf("%s: failed to wrap listener for iSH: %v", logPrefix, err) wrappedListener = listener } go func(listener net.Listener) { if err := srv.Serve(listener); err != nil && !errors.Is(err, http.ErrServerClosed) { - log.Printf("%s: %s", logPrefix, err) + Log.Errorf("%s: %s", logPrefix, err) } }(wrappedListener) } @@ -548,7 +555,7 @@ func runCaptchaServerAndWait(handler http.Handler, captchaURL string, keyCh <-ch fmt.Println("==============================================") fmt.Println() - log.Printf("[%s] Opening browser...", logPrefix) + Log.Infof("[%s] Opening browser...", logPrefix) openBrowser(captchaURL) key := <-keyCh @@ -560,7 +567,7 @@ func runCaptchaServerAndWait(handler http.Handler, captchaURL string, keyCh <-ch shutCtx, shutCancel := context.WithTimeout(context.Background(), 3*time.Second) defer shutCancel() if err := srv.Shutdown(shutCtx); err != nil { - log.Printf("%s: shutdown warning (token already received): %v", logPrefix, err) + Log.Warnf("%s: shutdown warning (token already received): %v", logPrefix, err) } return key, nil @@ -620,22 +627,22 @@ func (t *loggingTransport) RoundTrip(req *http.Request) (*http.Response, error) if isCaptchaRequest { b, err := io.ReadAll(req.Body) if err != nil { - log.Printf("[Captcha Proxy] Failed to read request body: %v", err) + Log.Warnf("[Captcha Proxy] failed to read request body: %v", err) b = nil } req.Body = io.NopCloser(bytes.NewReader(b)) if Debug { - log.Printf("[Captcha Proxy] Real browser sent %s data: %s", req.URL.Path, string(b)) + Log.Debugf("[Captcha Proxy] real browser sent %s data: %s", req.URL.Path, string(b)) for k, v := range req.Header { - log.Printf("[Captcha Proxy] Header (%s): %s = %s", req.URL.Path, k, strings.Join(v, ", ")) + Log.Debugf("[Captcha Proxy] header (%s): %s = %s", req.URL.Path, k, strings.Join(v, ", ")) } } if strings.Contains(req.URL.Path, "captchaNotRobot.componentDone") || strings.Contains(req.URL.Path, "captchaNotRobot.check") { parsedBody, err := neturl.ParseQuery(string(b)) if err != nil { - log.Printf("[Captcha Proxy] Failed to parse request body: %v", err) + Log.Warnf("[Captcha Proxy] failed to parse request body: %v", err) } device := parsedBody.Get("device") browserFp := parsedBody.Get("browser_fp") @@ -653,9 +660,9 @@ func (t *loggingTransport) RoundTrip(req *http.Request) (*http.Response, error) BrowserFp: browserFp, } if err := browserprofile.Save(sp); err != nil { - log.Printf("[Captcha Proxy] Failed to save browser profile: %v", err) + Log.Warnf("[Captcha Proxy] failed to save browser profile: %v", err) } else { - log.Printf("[Captcha Proxy] Successfully intercepted and saved real browser profile!") + Log.Infof("[Captcha Proxy] saved real browser profile") } } } @@ -683,7 +690,7 @@ func SolveViaProxy(redirectURI string, dialer net.Dialer) (string, error) { rewriteProxyRequest(req.Out, targetURL) }, ErrorHandler: func(w http.ResponseWriter, r *http.Request, err error) { - log.Printf("[Captcha Proxy] ERROR for %s %s: %v", r.Method, r.URL.String(), err) + Log.Errorf("[Captcha Proxy] %s %s: %v", r.Method, r.URL.String(), err) w.Header().Set("Content-Type", "text/html; charset=utf-8") w.WriteHeader(http.StatusBadGateway) _, _ = fmt.Fprintf(w, `

Captcha proxy error

%s %s

%v

`, r.Method, r.URL.String(), err) @@ -705,7 +712,7 @@ func SolveViaProxy(redirectURI string, dialer net.Dialer) (string, error) { contentType := res.Header.Get("Content-Type") contentEncoding := res.Header.Get("Content-Encoding") if Debug { - log.Printf("[Captcha Proxy] %s %d | Content-Type: %q, Encoding: %q", res.Request.Method, res.StatusCode, contentType, contentEncoding) + Log.Debugf("[Captcha Proxy] %s %d | Content-Type: %q, Encoding: %q", res.Request.Method, res.StatusCode, contentType, contentEncoding) } shouldInspectBody := strings.Contains(contentType, "text/html") || @@ -723,7 +730,7 @@ func SolveViaProxy(redirectURI string, dialer net.Dialer) (string, error) { reader = gzReader defer func() { if err := gzReader.Close(); err != nil { - log.Printf("failed to close gzip reader: %v", err) + Log.Warnf("[Captcha Proxy] close gzip reader: %v", err) } }() } @@ -773,10 +780,10 @@ func SolveViaProxy(redirectURI string, dialer net.Dialer) (string, error) { mux.HandleFunc("/local-captcha-result", func(w http.ResponseWriter, r *http.Request) { token := r.FormValue("token") if token != "" { - log.Printf("[Captcha] Received success token from browser (%d bytes)", len(token)) + Log.Infof("[Captcha] received success token from browser (%d bytes)", len(token)) notifyKey(keyCh, token) } else { - log.Printf("[Captcha] Received empty token from browser") + Log.Warnf("[Captcha] received empty token from browser") } w.Header().Set("Access-Control-Allow-Origin", "*") w.Header().Set("Content-Type", "text/plain") @@ -838,7 +845,7 @@ func SolveViaProxy(redirectURI string, dialer net.Dialer) (string, error) { }) mux.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) { - log.Printf("[Captcha Proxy] HTTP %s %s", r.Method, r.URL.Path) + Log.Debugf("[Captcha Proxy] HTTP %s %s", r.Method, r.URL.Path) if r.URL.Path == "/" && targetURL.Path != "" && targetURL.Path != "/" && r.URL.RawQuery == "" { // Don't log the full redirect URL to keep console clean http.Redirect(w, r, localCaptchaURLForTarget(targetURL), http.StatusTemporaryRedirect) diff --git a/internal/client/captcha/slider.go b/internal/client/captcha/slider.go index f9659bb..8d84d03 100644 --- a/internal/client/captcha/slider.go +++ b/internal/client/captcha/slider.go @@ -9,7 +9,6 @@ import ( "image" "image/color" _ "image/jpeg" // register JPEG decoder for image.Decode - "log" "math" mathrand "math/rand" "runtime" @@ -59,7 +58,7 @@ func (s *captchaSession) solveSliderCaptcha( if err != nil { return "", err } - log.Printf("slider puzzle decoded: grid=%d attempts=%d swaps=%d", puzzle.Size, puzzle.Attempts, len(puzzle.Swaps)) + Log.Debugf("[Captcha] slider puzzle decoded: grid=%d attempts=%d swaps=%d", puzzle.Size, puzzle.Attempts, len(puzzle.Swaps)) guesses, err := rankSliderGuesses(puzzle.Image, puzzle.Size, puzzle.Swaps) if err != nil { @@ -73,7 +72,7 @@ func (s *captchaSession) solveSliderCaptcha( if limit <= 0 { return "", errors.New("slider has no attempts available") } - log.Printf("slider guesses ranked: total=%d limit=%d", len(guesses), limit) + Log.Debugf("[Captcha] slider guesses ranked: total=%d limit=%d", len(guesses), limit) deviceJSON := captchaDeviceInfo if s.savedProfile != nil && strings.TrimSpace(s.savedProfile.DeviceJSON) != "" { @@ -91,7 +90,7 @@ func (s *captchaSession) solveSliderCaptcha( } for i := 0; i < limit; i++ { - log.Printf("slider attempt %d/%d (guess #%d)", i+1, limit, guesses[i].Index) + Log.Debugf("[Captcha] slider attempt %d/%d (guess #%d)", i+1, limit, guesses[i].Index) answerData, err := json.Marshal(struct { Value []int `json:"value"` }{Value: guesses[i].Swaps}) @@ -113,7 +112,7 @@ func (s *captchaSession) solveSliderCaptcha( if check.SuccessToken == "" { return "", errors.New("captcha success token not found") } - log.Printf("slider accepted on attempt %d", i+1) + Log.Infof("[Captcha] slider accepted on attempt %d", i+1) return check.SuccessToken, nil } if strings.EqualFold(check.Status, "error_limit") { @@ -185,7 +184,7 @@ func splitSliderSteps(steps []int) (int, []int, int, error) { if len(tail)%2 != 0 { attempts = tail[len(tail)-1] tail = tail[:len(tail)-1] - log.Printf("slider payload had odd-length tail; fallback attempts=%d", attempts) + Log.Warnf("[Captcha] slider payload had odd-length tail; fallback attempts=%d", attempts) } if attempts <= 0 { attempts = 4 diff --git a/internal/client/dnsdial/doh.go b/internal/client/dnsdial/doh.go index 3790f0e..60d308a 100644 --- a/internal/client/dnsdial/doh.go +++ b/internal/client/dnsdial/doh.go @@ -10,7 +10,6 @@ import ( "errors" "fmt" "io" - "log" "net" "net/http" "strings" @@ -20,10 +19,19 @@ import ( "github.com/miekg/dns" + "github.com/cacggghp/vk-turn-proxy/internal/logx" + // Embedded Mozilla CA roots for CGO_ENABLED=0 builds (Android). _ "golang.org/x/crypto/x509roots/fallback" ) +// Log is the package-level logger. Defaults to no-op; main wires it via +// SetLogger so DNS-mode output respects the global -debug flag and levels. +var Log logx.Logger = logx.Nop() + +// SetLogger installs a logger for this package. +func SetLogger(l logx.Logger) { Log = logx.OrNop(l) } + const ( dohQueryTimeout = 6 * time.Second // Total budget across all endpoint attempts in forwardRaw. Must be a @@ -178,7 +186,7 @@ func (r *DohResolver) forwardRaw(ctx context.Context, query []byte) ([]byte, Doh body, err := r.postWire(epCtx, ep, query) cancel() if err != nil { - log.Printf("[DoH] %s: %v", ep.Hostname, err) + Log.Warnf("[DoH] %s: %v", ep.Hostname, err) lastErr = err continue } @@ -263,7 +271,7 @@ func startDohForwarder(r *DohResolver) (_ *dohForwarder, err error) { udpAddr: udpConn.LocalAddr().String(), tcpAddr: tcpLn.Addr().String(), } - log.Printf("[DoH] forwarder listening udp=%s tcp=%s", fwd.udpAddr, fwd.tcpAddr) + Log.Infof("[DoH] forwarder listening udp=%s tcp=%s", fwd.udpAddr, fwd.tcpAddr) go fwd.serveUDP(udpConn, r) go fwd.serveTCP(tcpLn, r) @@ -276,7 +284,7 @@ func (f *dohForwarder) serveUDP(conn *net.UDPConn, r *DohResolver) { for { n, client, err := conn.ReadFromUDP(buf) if err != nil { - log.Printf("[DoH] udp read: %v", err) + Log.Errorf("[DoH] udp read: %v", err) return } query := append([]byte(nil), buf[:n]...) @@ -285,11 +293,11 @@ func (f *dohForwarder) serveUDP(conn *net.UDPConn, r *DohResolver) { defer cancel() resp, _, err := r.forwardRaw(ctx, q) if err != nil { - log.Printf("[DoH] udp forward failed: %v", err) + Log.Warnf("[DoH] udp forward failed: %v", err) return } if _, err := conn.WriteToUDP(resp, c); err != nil { - log.Printf("[DoH] udp write: %v", err) + Log.Warnf("[DoH] udp write: %v", err) } }(query, client) } @@ -300,7 +308,7 @@ func (f *dohForwarder) serveTCP(ln *net.TCPListener, r *DohResolver) { for { conn, err := ln.Accept() if err != nil { - log.Printf("[DoH] tcp accept: %v", err) + Log.Errorf("[DoH] tcp accept: %v", err) return } go handleDohForwarderTCP(conn, r) @@ -328,7 +336,7 @@ func handleDohForwarderTCP(conn net.Conn, r *DohResolver) { resp, _, err := r.forwardRaw(ctx, query) cancel() if err != nil { - log.Printf("[DoH] tcp forward failed: %v", err) + Log.Warnf("[DoH] tcp forward failed: %v", err) return } out := make([]byte, 2+len(resp)) @@ -421,8 +429,7 @@ func buildDialer(mode string, r *DohResolver) net.Dialer { case DNSModeAuto: return newAppDialer(autoDial(r)) default: - log.Panicf("unknown DNS mode %q", mode) - return net.Dialer{} + panic(fmt.Sprintf("unknown DNS mode %q", mode)) } } @@ -472,9 +479,9 @@ func autoDial(r *DohResolver) dialFunc { return func(ctx context.Context, network, addr string) (net.Conn, error) { probed.Do(func() { if udpProbe(autoUDPBudget) { - log.Printf("[DNS] UDP/53 probe OK, using UDP") + Log.Infof("[DNS] UDP/53 probe OK, using UDP") } else { - log.Printf("[DNS] UDP/53 unreachable; sticky-switching to DoH") + Log.Warnf("[DNS] UDP/53 unreachable; sticky-switching to DoH") useDoH.Store(true) } }) diff --git a/internal/client/vkauth/auto_solver.go b/internal/client/vkauth/auto_solver.go index 1b27d09..696192b 100644 --- a/internal/client/vkauth/auto_solver.go +++ b/internal/client/vkauth/auto_solver.go @@ -3,7 +3,6 @@ package vkauth import ( "context" "fmt" - "log" "github.com/cacggghp/vk-turn-proxy/internal/client/browserprofile" "github.com/cacggghp/vk-turn-proxy/internal/client/captcha" @@ -21,7 +20,7 @@ func DefaultAutoSolve( client tlsclient.HttpClient, profile browserprofile.Profile, ) (string, error) { - log.Printf("[STREAM %d] [Captcha] Solving captcha...", streamID) + captcha.Log.Infof("[STREAM %d] [Captcha] Solving captcha...", streamID) if captchaErr.SessionToken == "" { return "", fmt.Errorf("no session_token in redirect_uri for auto-solve") @@ -32,7 +31,7 @@ func DefaultAutoSolve( var savedProfile *browserprofile.Saved if sp, err := browserprofile.Load(); err == nil { - log.Printf("[STREAM %d] [Captcha] Using saved real browser profile", streamID) + captcha.Log.Infof("[STREAM %d] [Captcha] Using saved real browser profile", streamID) savedProfile = sp profile = sp.Profile } @@ -41,6 +40,6 @@ func DefaultAutoSolve( if err != nil { return "", err } - log.Printf("[STREAM %d] [Captcha] solver succeeded", streamID) + captcha.Log.Infof("[STREAM %d] [Captcha] solver succeeded", streamID) return successToken, nil } diff --git a/internal/client/vkauth/client.go b/internal/client/vkauth/client.go index 30cae4f..706f78e 100644 --- a/internal/client/vkauth/client.go +++ b/internal/client/vkauth/client.go @@ -156,12 +156,12 @@ func (c *Client) HandleAuthError(streamID int) bool { count := cache.errorCount.Add(1) cache.lastErrorTime.Store(now) - c.log.Infof("[STREAM %d] Auth error (cache=%d, count=%d/%d)", streamID, cacheID, count, MaxCacheErrors) + c.log.Warnf("[STREAM %d] [VK Auth] Auth error (cache=%d, count=%d/%d)", streamID, cacheID, count, MaxCacheErrors) if count >= MaxCacheErrors { - c.log.Infof("[VK Auth] Multiple auth errors detected (%d), invalidating cache %d for stream %d...", count, cacheID, streamID) + c.log.Warnf("[VK Auth] Multiple auth errors (%d), invalidating cache %d for stream %d", count, cacheID, streamID) cache.Invalidate() - c.log.Infof("[STREAM %d] [VK Auth] Credentials cache invalidated", streamID) + c.log.Warnf("[STREAM %d] [VK Auth] Credentials cache invalidated", streamID) return true } return false @@ -197,7 +197,7 @@ func (c *Client) fetchSerialized(ctx context.Context, link string, streamID int) elapsed := time.Since(c.lastFetchTime) if !c.lastFetchTime.IsZero() && elapsed < minInterval { wait := minInterval - elapsed - c.log.Infof("[STREAM %d] [VK Auth] Throttling: waiting %v to prevent rate limit...", streamID, wait.Truncate(time.Millisecond)) + c.log.Debugf("[STREAM %d] [VK Auth] Throttling: waiting %v to prevent rate limit", streamID, wait.Truncate(time.Millisecond)) select { case <-ctx.Done(): return "", "", nil, ctx.Err() @@ -225,14 +225,14 @@ func (c *Client) fetch(ctx context.Context, link string, streamID int) (string, return user, pass, addrs, nil } lastErr = err - c.log.Infof("[STREAM %d] [VK Auth] Failed with client_id=%s: %v", streamID, creds.ClientID, err) + c.log.Warnf("[STREAM %d] [VK Auth] Failed with client_id=%s: %v", streamID, creds.ClientID, err) if errors.Is(err, ErrCaptchaWaitRequired) || errors.Is(err, ErrFatalCaptchaNoStreams) { return "", "", nil, err } es := err.Error() if strings.Contains(es, "error_code:29") || strings.Contains(es, "error_code: 29") || strings.Contains(es, "Rate limit") { - c.log.Infof("[STREAM %d] [VK Auth] Rate limit detected, trying next credentials...", streamID) + c.log.Warnf("[STREAM %d] [VK Auth] Rate limit detected, trying next credentials", streamID) } } return "", "", nil, fmt.Errorf("all VK credentials failed: %w", lastErr) diff --git a/internal/client/vkauth/token.go b/internal/client/vkauth/token.go index 6255c49..011421b 100644 --- a/internal/client/vkauth/token.go +++ b/internal/client/vkauth/token.go @@ -75,7 +75,7 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c } defer func() { if closeErr := httpResp.Body.Close(); closeErr != nil { - c.log.Infof("close response body: %s", closeErr) + c.log.Warnf("[VK Auth] close response body: %s", closeErr) } }() @@ -109,7 +109,7 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c // Token 1 -> getCallPreview (warmup, non-fatal). data = fmt.Sprintf("vk_join_link=https://vk.com/call/join/%s&fields=photo_200&access_token=%s", link, token1) if _, prevErr := doRequest(data, "https://api.vk.ru/method/calls.getCallPreview?v=5.275&client_id="+creds.ClientID); prevErr != nil { - c.log.Infof("[STREAM %d] [VK Auth] Warning: getCallPreview failed: %v", streamID, prevErr) + c.log.Warnf("[STREAM %d] [VK Auth] getCallPreview failed: %v", streamID, prevErr) } vkDelayRandom(200, 400) @@ -130,10 +130,10 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c if captchaErr != nil && captchaErr.IsCaptcha() { solveMode, hasSolveMode := CaptchaSolveModeForAttempt(attempt, c.manualOnly) if !hasSolveMode { - c.log.Infof("[STREAM %d] [Captcha] No more solve modes available (attempt %d)", streamID, attempt+1) + c.log.Warnf("[STREAM %d] [Captcha] No more solve modes available (attempt %d)", streamID, attempt+1) c.engageLockout(60 * time.Second) if c.streamsFn() == 0 { - c.log.Infof("[STREAM %d] [FATAL] 0 connected streams and captcha solve modes exhausted.", streamID) + c.log.Errorf("[STREAM %d] [Captcha] FATAL: 0 connected streams and solve modes exhausted", streamID) return "", "", nil, ErrFatalCaptchaNoStreams } return "", "", nil, ErrCaptchaWaitRequired @@ -152,7 +152,7 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c if captchaErr.SessionToken != "" && captchaErr.RedirectURI != "" { successToken, solveErr = solveFn(ctx, captchaErr, streamID, client, profile) if solveErr != nil { - c.log.Infof("[STREAM %d] [Captcha] Auto captcha failed: %v", streamID, solveErr) + c.log.Warnf("[STREAM %d] [Captcha] Auto captcha failed: %v", streamID, solveErr) } } else { solveErr = fmt.Errorf("missing fields for auto solve") @@ -162,7 +162,7 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c solveErr = fmt.Errorf("manual captcha solver not configured") break } - c.log.Infof("[STREAM %d] [Captcha] Triggering manual captcha fallback...", streamID) + c.log.Infof("[STREAM %d] [Captcha] Triggering manual captcha fallback", streamID) // Manual solver gets its own 3-min budget so a tight parent // deadline doesn't cut user solve time. We still propagate // parent cancellation (app shutdown) so the in-flight solver @@ -187,12 +187,12 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c solveErr = res.err if successToken != "" || captchaKey != "" { if solveErr != nil { - c.log.Infof("[STREAM %d] [Captcha] Token received (ignoring cleanup error: %v)", streamID, solveErr) + c.log.Debugf("[STREAM %d] [Captcha] Token received (ignoring cleanup error: %v)", streamID, solveErr) solveErr = nil } - c.log.Infof("[STREAM %d] [Captcha] Successfully got token from browser", streamID) + c.log.Infof("[STREAM %d] [Captcha] Got token from browser", streamID) } else if solveErr != nil { - c.log.Infof("[STREAM %d] [Captcha] manual solver returned error: %v", streamID, solveErr) + c.log.Warnf("[STREAM %d] [Captcha] Manual solver error: %v", streamID, solveErr) } case <-manualCtx.Done(): if errors.Is(manualCtx.Err(), context.DeadlineExceeded) { @@ -205,15 +205,15 @@ func (c *Client) getTokenChain(ctx context.Context, link string, streamID int, c } if solveErr != nil { - c.log.Infof("[STREAM %d] [Captcha] %s failed (attempt %d): %v", streamID, CaptchaSolveModeLabel(solveMode), attempt+1, solveErr) + c.log.Warnf("[STREAM %d] [Captcha] %s failed (attempt %d): %v", streamID, CaptchaSolveModeLabel(solveMode), attempt+1, solveErr) nextSolveMode, hasNextSolveMode := CaptchaSolveModeForAttempt(attempt+1, c.manualOnly) if hasNextSolveMode { - c.log.Infof("[STREAM %d] [Captcha] Falling back to %s...", streamID, CaptchaSolveModeLabel(nextSolveMode)) + c.log.Infof("[STREAM %d] [Captcha] Falling back to %s", streamID, CaptchaSolveModeLabel(nextSolveMode)) continue } c.engageLockout(60 * time.Second) if c.streamsFn() == 0 { - c.log.Infof("[STREAM %d] [FATAL] 0 connected streams and manual captcha failed/timed out.", streamID) + c.log.Errorf("[STREAM %d] [Captcha] FATAL: 0 connected streams and manual captcha failed/timed out", streamID) return "", "", nil, ErrFatalCaptchaNoStreams } return "", "", nil, ErrCaptchaWaitRequired diff --git a/internal/proxy/udprelay/udprelay.go b/internal/proxy/udprelay/udprelay.go index 5682084..9c0a0be 100644 --- a/internal/proxy/udprelay/udprelay.go +++ b/internal/proxy/udprelay/udprelay.go @@ -255,7 +255,7 @@ func TURNLoop(ctx context.Context, deps *Deps, params *Params, peer *net.UDPAddr } if errors.Is(err, vkauth.ErrCaptchaWaitRequired) { if !errors.Is(err, vkauth.ErrLockoutActive) { - deps.log().Errorf("[STREAM %d] Backing off for 60 seconds to avoid IP ban...", streamID) + deps.log().Warnf("[STREAM %d] Backing off for 60 seconds to avoid IP ban", streamID) select { case <-ctx.Done(): return @@ -330,7 +330,7 @@ func oneDTLS(ctx context.Context, deps *Deps, peer *net.UDPAddr, listenConn net. wg := sync.WaitGroup{} context.AfterFunc(dtlsctx, func() { if err := dtlsConn.SetDeadline(time.Now()); err != nil { - deps.log().Errorf("[STREAM %d] Warning: SetDeadline failed: %v", streamID, err) + deps.log().Warnf("[STREAM %d] SetDeadline failed: %v", streamID, err) } })