From 076f5f47f72e80f0b205d25782a224c6588f3631 Mon Sep 17 00:00:00 2001 From: sajadMRjl Date: Wed, 28 Jan 2026 03:17:15 +0330 Subject: [PATCH] fix: readable log messages --- cmd/main.go | 26 ++++----- internal/filter/{filter.go => network.go} | 49 +++++++++-------- internal/parser/parser.go | 59 ++++++++++---------- internal/tester/runner.go | 66 +++++++++++------------ 4 files changed, 99 insertions(+), 101 deletions(-) rename internal/filter/{filter.go => network.go} (52%) diff --git a/cmd/main.go b/cmd/main.go index 86049f4..f3d2d48 100644 --- a/cmd/main.go +++ b/cmd/main.go @@ -54,32 +54,32 @@ func main() { // Step A: Parse proxy, err := parser.ParseLink(raw) if err != nil { - slog.Debug("Parse failed", "err", err) + // Parser logs its own errors at DEBUG level return } - // Step B: Cheap Filter (TCP/TLS) + // Step B: Network Filter if !netFilter.Check(proxy) { - // Failed cheap checks, discard silently or debug + // Filter logs specific failure reason (TCP/TLS) at DEBUG level return } - // Step C: Expensive Test (Sing-box) - semaphore <- struct{}{} // Acquire lock + // Step C: Integration Test + semaphore <- struct{}{} err = boxRunner.Test(proxy) - <-semaphore // Release lock + <-semaphore if err != nil { - slog.Debug("Test failed", "proxy", proxy.Address, "err", err) + // Runner logs probe failures return } - // Success! - validCount++ - slog.Info("Valid Proxy Found", - "addr", proxy.Address, - "latency", proxy.Latency.Milliseconds(), - "type", proxy.Type, + // Success Log + slog.Info("proxy_verified", + "target", proxy.Address, + "protocol", proxy.Type, + "latency_ms", proxy.Latency.Milliseconds(), + "sni", proxy.SNI, ) }(link) diff --git a/internal/filter/filter.go b/internal/filter/network.go similarity index 52% rename from internal/filter/filter.go rename to internal/filter/network.go index 49a23c2..d29399b 100644 --- a/internal/filter/filter.go +++ b/internal/filter/network.go @@ -10,7 +10,6 @@ import ( "find-me-internet/internal/model" ) -// Pipeline manages the "Cheap Check" logic type Pipeline struct { Timeout time.Duration } @@ -19,31 +18,42 @@ func NewPipeline(timeout time.Duration) *Pipeline { return &Pipeline{Timeout: timeout} } -// Check runs a sequence of low-cost network tests. -// Returns false immediately if any stage fails. func (f *Pipeline) Check(p *model.Proxy) bool { - // 1. Sanity Check - if p.Address == "" || p.Port == 0 { - return false - } + target := net.JoinHostPort(p.Address, strconv.Itoa(p.Port)) + log := slog.With("target", target, "protocol", p.Type) - // 2. TCP Liveness (Is the port open?) + // 1. TCP Connectivity + start := time.Now() if !f.checkTCP(p) { - slog.Debug("TCP Connection failed", "addr", p.Address, "port", p.Port) + log.Debug("tcp_connect_failed", "duration", time.Since(start)) p.IsOnline = false return false } p.IsOnline = true - // 3. TLS Validity (Does it handshake?) - // Only required if SNI is present or port is standard HTTPS - if p.SNI != "" || p.Port == 443 { - if !f.checkTLS(p) { - slog.Debug("TLS Handshake failed", "addr", p.Address, "sni", p.SNI) + // 2. TLS Handshake + // Only proceed if protocol supports/requires TLS + shouldCheckTLS := p.SNI != "" || p.Port == 443 || p.Type == model.TypeVLESS || p.Type == model.TypeTrojan + + if shouldCheckTLS { + sni := p.SNI + if sni == "" { + sni = p.Address // Fallback for handshake + } + + startTLS := time.Now() + if !f.checkTLS(p, sni) { + log.Debug("tls_handshake_failed", + "sni", sni, + "duration", time.Since(startTLS), + ) p.IsTLSSecure = false return false } p.IsTLSSecure = true + log.Debug("network_checks_passed", "duration", time.Since(start)) + } else { + log.Debug("network_checks_passed", "note", "tls_skipped_no_sni") } return true @@ -59,20 +69,13 @@ func (f *Pipeline) checkTCP(p *model.Proxy) bool { return true } -func (f *Pipeline) checkTLS(p *model.Proxy) bool { +func (f *Pipeline) checkTLS(p *model.Proxy, sni string) bool { address := net.JoinHostPort(p.Address, strconv.Itoa(p.Port)) dialer := &net.Dialer{Timeout: f.Timeout} - // We skip verification because many proxies use self-signed certs or Reality. - // The goal is to check if the server *speaks* TLS, not if the cert is trusted by Root CAs. conf := &tls.Config{ InsecureSkipVerify: true, - ServerName: p.SNI, - } - - // Fallback SNI if none provided - if conf.ServerName == "" { - conf.ServerName = p.Address + ServerName: sni, } conn, err := tls.DialWithDialer(dialer, "tcp", address, conf) diff --git a/internal/parser/parser.go b/internal/parser/parser.go index b2950da..ecc204e 100644 --- a/internal/parser/parser.go +++ b/internal/parser/parser.go @@ -11,13 +11,10 @@ import ( "github.com/gvcgo/vpnparser/pkgs/outbound" ) -// tempConfig covers multiple locations where SNI might be hidden in the JSON type tempConfig struct { Transport struct { Type string `json:"type"` } `json:"transport"` - - // Standard TLS TLS struct { ServerName string `json:"server_name"` } `json:"tls"` @@ -29,10 +26,11 @@ func ParseLink(raw string) (*model.Proxy, error) { return nil, fmt.Errorf("empty link") } - // 1. Parse using library + // 1. Library Parse item := outbound.ParseRawUriToProxyItem(raw) if item == nil { - return nil, fmt.Errorf("invalid link") + slog.Debug("parser_rejected_link", "reason", "invalid_structure", "raw_prefix", raw[:min(20, len(raw))]) + return nil, fmt.Errorf("invalid link structure") } p := &model.Proxy{ @@ -41,11 +39,10 @@ func ParseLink(raw string) (*model.Proxy, error) { Port: item.Port, } - // 2. Clean up Protocol (Fixing the "vless://" bug) - // Some versions of the lib return "vless://" instead of "vless" + // 2. Protocol Normalization scheme := strings.ToLower(item.Scheme) scheme = strings.TrimSuffix(scheme, "://") - + switch scheme { case "vless": p.Type = model.TypeVLESS @@ -60,60 +57,62 @@ func ParseLink(raw string) (*model.Proxy, error) { p.Type = model.TypeShadowsocks default: p.Type = model.TypeUnknown - slog.Warn("Unknown protocol", "scheme", scheme, "raw", item.Scheme) + slog.Warn("unknown_protocol_detected", "scheme", scheme, "target", p.Address) } - // 3. Extract SNI (Fixing the "sni=" bug) - // We first try to get it from the standard fields + // 3. Deep Extraction (JSON) + extractionSource := "none" if item.Outbound != "" { var cfg tempConfig if err := json.Unmarshal([]byte(item.Outbound), &cfg); err == nil { p.Network = cfg.Transport.Type p.SNI = cfg.TLS.ServerName + if p.Network != "" || p.SNI != "" { + extractionSource = "json_config" + } } } - // 4. Fallback for SNI (Crucial for Reality/VLESS) - // If JSON extraction failed, try to parse the raw URL query parameters manually. - // This is often more reliable than the JSON dump for simple fields. + // 4. Fallback Extraction (Query Params) if p.SNI == "" { - // Quick and dirty manual check for "&sni=..." or "&peer=..." if val := extractQueryParam(raw, "sni"); val != "" { p.SNI = val - } else if val := extractQueryParam(raw, "peer"); val != "" { - p.SNI = val // "peer" is often used in Telegram proxies as SNI + extractionSource = "query_sni" } else if val := extractQueryParam(raw, "host"); val != "" { p.SNI = val + extractionSource = "query_host" + } else if val := extractQueryParam(raw, "peer"); val != "" { + p.SNI = val + extractionSource = "query_peer" } } - - // 5. Final Safety: Reality MUST have an SNI - // If we still don't have one, the TLS check will inevitably fail. - // We can warn here. - if p.Type == model.TypeVLESS && p.SNI == "" { - slog.Debug("Warning: VLESS proxy has no SNI", "addr", p.Address) - } + + slog.Debug("proxy_parsed", + "target", fmt.Sprintf("%s:%d", p.Address, p.Port), + "protocol", p.Type, + "sni", p.SNI, + "sni_source", extractionSource, + ) return p, nil } -// Helper to manually grab query params from the raw string -// because sometimes the parser library logic is opaque. func extractQueryParam(url, key string) string { - // Find "key=" keyStr := key + "=" start := strings.Index(url, keyStr) if start == -1 { return "" } - // Move to value start start += len(keyStr) - - // Find end of value (either '&' or '#') rest := url[start:] end := strings.IndexAny(rest, "&#") if end == -1 { return rest } return rest[:end] +} + +func min(a, b int) int { + if a < b { return a } + return b } \ No newline at end of file diff --git a/internal/tester/runner.go b/internal/tester/runner.go index c06402d..bed876b 100644 --- a/internal/tester/runner.go +++ b/internal/tester/runner.go @@ -22,60 +22,62 @@ type Runner struct { } func NewRunner(binPath, testURL string, timeout time.Duration) *Runner { - return &Runner{ - BinPath: binPath, - TestURL: testURL, - Timeout: timeout, - } + return &Runner{BinPath: binPath, TestURL: testURL, Timeout: timeout} } -// Test spins up a Sing-box instance and measures HTTP latency func (r *Runner) Test(p *model.Proxy) error { - // 1. Acquire Local Port + log := slog.With("target", p.Address, "sni", p.SNI) + + // 1. Port Allocation port, err := getFreePort() if err != nil { - return fmt.Errorf("failed to get port: %w", err) - } - - // 2. Generate Configuration - configData, err := GenerateConfig(p, port) - if err != nil { + log.Error("local_port_allocation_failed", "error", err) + return err + } + + // 2. Config Generation + configData, err := GenerateConfig(p, port) + if err != nil { + log.Error("config_generation_failed", "error", err) return err } - // 3. Write Config File - // Using a unique name prevents collisions in concurrent tests configName := filepath.Join(os.TempDir(), fmt.Sprintf("sb_%d_%s.json", port, p.Address)) if err := os.WriteFile(configName, configData, 0644); err != nil { return err } - defer os.Remove(configName) // Cleanup + defer os.Remove(configName) - // 4. Execute Sing-box + // 3. Process Execution ctx, cancel := context.WithTimeout(context.Background(), r.Timeout+2*time.Second) defer cancel() cmd := exec.CommandContext(ctx, r.BinPath, "run", "-c", configName) if err := cmd.Start(); err != nil { - return fmt.Errorf("startup failed: %w", err) + log.Error("singbox_process_start_failed", "error", err) + return err } - // Ensure cleanup happens even if panic occurs defer func() { if cmd.Process != nil { - _ = cmd.Process.Kill() + cmd.Process.Kill() } }() - // 5. Wait for Binding + // 4. Wait for Binding if !waitForPort(port, 2*time.Second) { - return fmt.Errorf("sing-box failed to bind port %d", port) + log.Debug("singbox_bind_timeout", "local_port", port) + return fmt.Errorf("process_bind_timeout") } - // 6. HTTP Latency Test + // 5. HTTP Probe + startProbe := time.Now() latency, err := r.measureLatency(port) if err != nil { - slog.Debug("Latency test failed", "err", err, "proxy", p.Address) + log.Debug("http_probe_failed", + "duration", time.Since(startProbe), + "error", err, + ) return err } @@ -85,11 +87,10 @@ func (r *Runner) Test(p *model.Proxy) error { func (r *Runner) measureLatency(port int) (time.Duration, error) { proxyUrl, _ := url.Parse(fmt.Sprintf("http://127.0.0.1:%d", port)) - client := &http.Client{ Transport: &http.Transport{ Proxy: http.ProxyURL(proxyUrl), - DisableKeepAlives: true, // Force new connection + DisableKeepAlives: true, }, Timeout: r.Timeout, } @@ -101,23 +102,18 @@ func (r *Runner) measureLatency(port int) (time.Duration, error) { } defer resp.Body.Close() - if resp.StatusCode != 200 && resp.StatusCode != 204 { - return 0, fmt.Errorf("invalid status code: %d", resp.StatusCode) + if resp.StatusCode < 200 || resp.StatusCode > 299 { + return 0, fmt.Errorf("unexpected_status_code_%d", resp.StatusCode) } return time.Since(start), nil } -// getFreePort asks the kernel for a random open port func getFreePort() (int, error) { addr, err := net.ResolveTCPAddr("tcp", "localhost:0") - if err != nil { - return 0, err - } + if err != nil { return 0, err } l, err := net.ListenTCP("tcp", addr) - if err != nil { - return 0, err - } + if err != nil { return 0, err } defer l.Close() return l.Addr().(*net.TCPAddr).Port, nil }