Entirely rework logging

This commit is contained in:
2025-10-30 15:18:59 +01:00
parent 661ac0b372
commit ec8568c4a8
3 changed files with 107 additions and 116 deletions

16
go.mod
View File

@@ -2,4 +2,18 @@ module binarysusser
go 1.24.1 go 1.24.1
require github.com/bmatcuk/doublestar/v4 v4.8.1 require (
git.site.quack-lab.dev/dave/cylogger v1.5.0
git.site.quack-lab.dev/dave/cyutils v1.5.0
github.com/bmatcuk/doublestar/v4 v4.8.1
)
require (
github.com/google/go-cmp v0.5.9 // indirect
github.com/hexops/valast v1.5.0 // indirect
golang.org/x/mod v0.7.0 // indirect
golang.org/x/sys v0.3.0 // indirect
golang.org/x/time v0.12.0 // indirect
golang.org/x/tools v0.4.0 // indirect
mvdan.cc/gofumpt v0.4.0 // indirect
)

32
go.sum
View File

@@ -1,2 +1,34 @@
git.site.quack-lab.dev/dave/cylogger v1.5.0 h1:9H/eEMD1dqJ9hEudwbszxrzE9lN0P0iCeYOzYRPMWOA=
git.site.quack-lab.dev/dave/cylogger v1.5.0/go.mod h1:wctgZplMvroA4X6p8f4B/LaCKtiBcT1Pp+L14kcS8jk=
git.site.quack-lab.dev/dave/cyutils v1.5.0 h1:U5pojDNoXV4Kj/dlPaGm2COaT4aX6zu88gBF+nTYeJw=
git.site.quack-lab.dev/dave/cyutils v1.5.0/go.mod h1:fBjALu2Cp2u2bDr+E4zbGVMBeIgFzROg+4TCcTNAiQU=
github.com/bmatcuk/doublestar/v4 v4.8.1 h1:54Bopc5c2cAvhLRAzqOGCYHYyhcDHsFF4wWIR5wKP38= github.com/bmatcuk/doublestar/v4 v4.8.1 h1:54Bopc5c2cAvhLRAzqOGCYHYyhcDHsFF4wWIR5wKP38=
github.com/bmatcuk/doublestar/v4 v4.8.1/go.mod h1:xBQ8jztBU6kakFMg+8WGxn0c6z1fTSPVIjEY1Wr7jzc= github.com/bmatcuk/doublestar/v4 v4.8.1/go.mod h1:xBQ8jztBU6kakFMg+8WGxn0c6z1fTSPVIjEY1Wr7jzc=
github.com/frankban/quicktest v1.14.3 h1:FJKSZTDHjyhriyC81FLQ0LY93eSai0ZyR/ZIkd3ZUKE=
github.com/frankban/quicktest v1.14.3/go.mod h1:mgiwOwqx65TmIk1wJ6Q7wvnVMocbUorkibMOrVTHZps=
github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
github.com/google/go-cmp v0.5.9/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
github.com/hexops/autogold v0.8.1 h1:wvyd/bAJ+Dy+DcE09BoLk6r4Fa5R5W+O+GUzmR985WM=
github.com/hexops/autogold v0.8.1/go.mod h1:97HLDXyG23akzAoRYJh/2OBs3kd80eHyKPvZw0S5ZBY=
github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM=
github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg=
github.com/hexops/valast v1.5.0 h1:FBTuvVi0wjTngtXJRZXMbkN/Dn6DgsUsBwch2DUJU8Y=
github.com/hexops/valast v1.5.0/go.mod h1:Jcy1pNH7LNraVaAZDLyv21hHg2WBv9Nf9FL6fGxU7o4=
github.com/kr/pretty v0.3.0 h1:WgNl7dwNpEZ6jJ9k1snq4pZsg7DOEN8hP9Xw0Tsjwk0=
github.com/kr/pretty v0.3.0/go.mod h1:640gp4NfQd8pI5XOwp5fnNeVWj67G7CFk/SaSQn7NBk=
github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
github.com/rogpeppe/go-internal v1.9.0 h1:73kH8U+JUqXU8lRuOHeVHaa/SZPifC7BkcraZVejAe8=
github.com/rogpeppe/go-internal v1.9.0/go.mod h1:WtVeX8xhTBvf0smdhujwtBcq4Qrzq/fJaraNFVN+nFs=
golang.org/x/mod v0.7.0 h1:LapD9S96VoQRhi/GrNTqeBJFrUjs5UHCAtTlgwA5oZA=
golang.org/x/mod v0.7.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs=
golang.org/x/sync v0.1.0 h1:wsuoTGHzEhffawBOhz5CYhcrV4IdKZbEyZjBMuTp12o=
golang.org/x/sync v0.1.0/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
golang.org/x/sys v0.3.0 h1:w8ZOecv6NaNa/zC8944JTU3vz4u6Lagfk4RPQxv92NQ=
golang.org/x/sys v0.3.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/time v0.12.0 h1:ScB/8o8olJvc+CQPWrK3fPZNfh7qgwCrY0zJmoEQLSE=
golang.org/x/time v0.12.0/go.mod h1:CDIdPxbZBQxdj6cxyCIdrNogrJKMJ7pr37NYpMcMDSg=
golang.org/x/tools v0.4.0 h1:7mTAgkunk3fr4GAloyyCasadO6h9zSsQZbwvcaIciV4=
golang.org/x/tools v0.4.0/go.mod h1:UE5sM2OK9E/d67R0ANs2xJizIymRP5gJU295PvKXxjQ=
mvdan.cc/gofumpt v0.4.0 h1:JVf4NN1mIpHogBj7ABpgOyZc65/UUOkKQFkoURsz4MM=
mvdan.cc/gofumpt v0.4.0/go.mod h1:PljLOHDeZqgS8opHRKLzp2It2VBuSdteAgqUfzMTxlQ=

175
main.go
View File

@@ -11,23 +11,10 @@ import (
"sync" "sync"
"github.com/bmatcuk/doublestar/v4" "github.com/bmatcuk/doublestar/v4"
logger "git.site.quack-lab.dev/dave/cylogger"
utils "git.site.quack-lab.dev/dave/cyutils"
) )
var Error *log.Logger
var Warning *log.Logger
func init() {
log.SetFlags(log.Lmicroseconds | log.Lshortfile)
log.SetOutput(os.Stdout)
Error = log.New(os.Stderr,
fmt.Sprintf("%sERROR:%s ", "\033[0;101m", "\033[0m"),
log.Lmicroseconds|log.Lshortfile)
Warning = log.New(os.Stdout,
fmt.Sprintf("%sWarning:%s ", "\033[0;93m", "\033[0m"),
log.Lmicroseconds|log.Lshortfile)
}
type ExtData struct { type ExtData struct {
ext string ext string
binaryCount int binaryCount int
@@ -37,70 +24,58 @@ type ExtData struct {
var debug bool var debug bool
func main() { func main() {
raw := flag.Bool("r", false, "More application friendly output") track := flag.Bool("t", false, "Git add and commit the results")
debugF := flag.Bool("d", false, "Debug mode")
flag.Parse() flag.Parse()
debug = *debugF logger.InitFlag()
logger.Info("Starting binarysusser")
dir := flag.Arg(0) dir := flag.Arg(0)
if dir == "" { if dir == "" {
dir = "." dir = "."
} }
logger.Info("Scanning directory: %s", dir)
dir = NormalizePath(dir) dir = NormalizePath(dir)
if debug { logger.Info("Normalized directory: %s", dir)
log.Printf("Scanning directory: %s", dir)
}
files, err := doublestar.Glob(os.DirFS(dir), "**/*") files, err := doublestar.Glob(os.DirFS(dir), "**/*")
if err != nil { if err != nil {
log.Fatalf("Error globbing directory: %v", err) logger.Error("Error globbing directory: %v", err)
os.Exit(1)
} }
logger.Info("Found %d files", len(files))
extensionTypeCount := sync.Map{} extensionTypeCount := sync.Map{}
wg := sync.WaitGroup{} utils.WithWorkers(20, files, func(worker, i int, file string) {
for _, file := range files { filelog := logger.Default.WithPrefix(fmt.Sprintf("file=%s", file))
wg.Add(1) filelog.Debug("Processing file")
go func(file string) { isBinary, err := IsBinaryFile(file)
defer wg.Done() if err != nil {
if debug { filelog.Error("Error analyzing file: %v", err)
log.Printf("[%s] Processing file", file) // Log the file being processed return
} }
ext := filepath.Ext(file)
isBinary, err := IsBinaryFile(file) extData, _ := extensionTypeCount.LoadOrStore(ext, &ExtData{ext: ext, binaryCount: 0, textCount: 0})
if err != nil { if isBinary {
if debug { extData.(*ExtData).binaryCount++
log.Printf("[%s] Error analyzing file: %v", file, err) filelog.Debug("Binary file detected: (%s)", ext)
} } else {
return extData.(*ExtData).textCount++
} filelog.Debug("Text file detected: (%s)", ext)
}
ext := filepath.Ext(file) })
extData, _ := extensionTypeCount.LoadOrStore(ext, &ExtData{ext: ext, binaryCount: 0, textCount: 0}) logger.Info("Processing complete")
if isBinary {
extData.(*ExtData).binaryCount++
if debug {
log.Printf("[%s] Binary file detected: (%s)", file, ext)
}
} else {
extData.(*ExtData).textCount++
if debug {
log.Printf("[%s] Text file detected: (%s)", file, ext)
}
}
}(file)
}
wg.Wait()
extensionTypeCount.Range(func(key, value any) bool { extensionTypeCount.Range(func(key, value any) bool {
extData := value.(*ExtData) extData := value.(*ExtData)
extlog := logger.Default.WithPrefix(fmt.Sprintf("ext=%s", extData.ext))
if extData.ext == "" { if extData.ext == "" {
extlog.Debug("Skipping empty extension")
return true return true
} }
if extData.binaryCount > extData.textCount*2 { if extData.binaryCount > extData.textCount*2 {
if *raw { extlog.Info("Extension: %q, Binary Count: %d, Text Count: %d", extData.ext, extData.binaryCount, extData.textCount)
fmt.Println(extData.ext)
} else {
log.Printf("Extension: %q, Binary Count: %d, Text Count: %d", extData.ext, extData.binaryCount, extData.textCount)
}
} }
return true return true
}) })
@@ -109,16 +84,13 @@ func main() {
// IsBinaryFile detects if a file is binary by analyzing a sample of its content // IsBinaryFile detects if a file is binary by analyzing a sample of its content
// It uses multiple heuristics for more reliable detection // It uses multiple heuristics for more reliable detection
func IsBinaryFile(filename string) (bool, error) { func IsBinaryFile(filename string) (bool, error) {
if debug { filelog := logger.Default.WithPrefix(fmt.Sprintf("file=%s", filename))
log.Printf("[%s] Starting binary detection for file", filename) filelog.Debug("Starting binary detection for file")
}
// Open the file // Open the file
file, err := os.Open(filename) file, err := os.Open(filename)
if err != nil { if err != nil {
if debug { filelog.Error("Failed to open file: %v", err)
log.Printf("[%s] Failed to open file: %v", filename, err)
}
return false, err return false, err
} }
defer file.Close() defer file.Close()
@@ -126,12 +98,10 @@ func IsBinaryFile(filename string) (bool, error) {
// Get file info for size // Get file info for size
fileInfo, err := file.Stat() fileInfo, err := file.Stat()
if err != nil { if err != nil {
if debug { filelog.Error("Failed to get file stats: %v", err)
log.Printf("[%s] Failed to get file stats: %v", filename, err) return false, err
}
} else if debug {
log.Printf("[%s] File size: %d bytes", filename, fileInfo.Size())
} }
filelog.Debug("File size: %d bytes", fileInfo.Size())
// Create a buffer to read a sample (first 8KB is usually enough) // Create a buffer to read a sample (first 8KB is usually enough)
// Adjust the buffer size as needed // Adjust the buffer size as needed
@@ -139,22 +109,16 @@ func IsBinaryFile(filename string) (bool, error) {
buffer := make([]byte, sampleSize) buffer := make([]byte, sampleSize)
// Read a sample from the file // Read a sample from the file
if debug { filelog.Debug("Reading %d byte sample from file", sampleSize)
log.Printf("[%s] Reading %d byte sample from file", filename, sampleSize)
}
bytesRead, err := file.Read(buffer) bytesRead, err := file.Read(buffer)
if err != nil && err.Error() != "EOF" { if err != nil && err.Error() != "EOF" {
if debug { filelog.Error("Error reading from file: %v", err)
log.Printf("[%s] Error reading from file: %v", filename, err)
}
return false, err return false, err
} }
// Adjust buffer to actual bytes read // Adjust buffer to actual bytes read
buffer = buffer[:bytesRead] buffer = buffer[:bytesRead]
if debug { filelog.Debug("Actually read %d bytes from file", bytesRead)
log.Printf("[%s] Actually read %d bytes from file", filename, bytesRead)
}
// Null byte check - common in binary files, rare in text files // Null byte check - common in binary files, rare in text files
nullCount := 0 nullCount := 0
@@ -168,16 +132,12 @@ func IsBinaryFile(filename string) (bool, error) {
// Count of characters analyzed // Count of characters analyzed
totalBytes := bytesRead totalBytes := bytesRead
if debug { filelog.Debug("Analyzing bytes for binary detection...")
log.Printf("[%s] Analyzing bytes for binary detection...", filename)
}
// Check each byte in the sample // Check each byte in the sample
for _, b := range buffer { for _, b := range buffer {
// Update character frequency (debug only) // Update character frequency (debug only)
if debug { charFreq[b]++
charFreq[b]++
}
// Count null bytes // Count null bytes
if b == 0 { if b == 0 {
@@ -219,17 +179,12 @@ func IsBinaryFile(filename string) (bool, error) {
extendedAsciiPercentage = 100.0 * float64(extendedAsciiCount) / float64(totalBytes) extendedAsciiPercentage = 100.0 * float64(extendedAsciiCount) / float64(totalBytes)
} }
if debug { filelog.Trace("File size analyzed: %d bytes", totalBytes)
log.Printf("[%s] File", filename) filelog.Trace("Null bytes: %d (%.2f%%)", nullCount, nullPercentage)
log.Printf("[%s] Size analyzed: %d bytes", filename, totalBytes) filelog.Trace("Non-printable: %d (%.2f%%)", nonPrintableCount, nonPrintablePercentage)
log.Printf("[%s] Null bytes: %d (%.2f%%)", filename, nullCount, nullPercentage) filelog.Trace("Control chars: %d (%.2f%%)", controlCharCount, controlCharPercentage)
log.Printf("[%s] Non-printable: %d (%.2f%%)", filename, nonPrintableCount, nonPrintablePercentage) filelog.Trace("Extended ASCII: %d (%.2f%%)", extendedAsciiCount, extendedAsciiPercentage)
log.Printf("[%s] Control chars: %d (%.2f%%)", filename, controlCharCount, controlCharPercentage) filelog.Trace("Thresholds: nulls > %.2f%%, non-printable > %.2f%%", 100.0*nullThreshold/float64(totalBytes), 100.0*nonPrintableThreshold/float64(totalBytes))
log.Printf("[%s] Extended ASCII: %d (%.2f%%)", filename, extendedAsciiCount, extendedAsciiPercentage)
log.Printf("[%s] Thresholds: nulls > %.2f%%, non-printable > %.2f%%",
filename,
100.0*nullThreshold/float64(totalBytes),
100.0*nonPrintableThreshold/float64(totalBytes))
// Print top 10 most frequent non-printable characters if any were found // Print top 10 most frequent non-printable characters if any were found
if nonPrintableCount > 0 { if nonPrintableCount > 0 {
@@ -266,25 +221,20 @@ func IsBinaryFile(filename string) (bool, error) {
} }
} }
} }
}
isBinary := float64(nullCount) > nullThreshold || float64(nonPrintableCount) > nonPrintableThreshold isBinary := float64(nullCount) > nullThreshold || float64(nonPrintableCount) > nonPrintableThreshold
if debug {
if isBinary { if isBinary {
log.Printf("[%s] RESULT: %s is detected as BINARY file", filename, filename) filelog.Debug("File is detected as BINARY file")
if float64(nullCount) > nullThreshold { if float64(nullCount) > nullThreshold {
log.Printf("[%s] - Detected as binary due to null bytes: %.2f%% > threshold %.2f%%", filelog.Trace("Detected as binary due to null bytes: %.2f%% > threshold %.2f%%", nullPercentage, 100.0*nullThreshold/float64(totalBytes))
filename, nullPercentage, 100.0*nullThreshold/float64(totalBytes))
} }
if float64(nonPrintableCount) > nonPrintableThreshold { if float64(nonPrintableCount) > nonPrintableThreshold {
log.Printf("[%s] - Detected as binary due to non-printable chars: %.2f%% > threshold %.2f%%", filelog.Trace("Detected as binary due to non-printable chars: %.2f%% > threshold %.2f%%", nonPrintablePercentage, 100.0*nonPrintableThreshold/float64(totalBytes))
filename, nonPrintablePercentage, 100.0*nonPrintableThreshold/float64(totalBytes))
} }
} else { } else {
log.Printf("[%s] RESULT: %s is detected as TEXT file", filename, filename) filelog.Debug("File is detected as TEXT file")
} }
}
return isBinary, nil return isBinary, nil
} }
@@ -301,21 +251,16 @@ func isWhitespace(b byte) bool {
// IsStringBinary is kept for backwards compatibility // IsStringBinary is kept for backwards compatibility
func IsStringBinary(s string) bool { func IsStringBinary(s string) bool {
if debug { filelog := logger.Default.WithPrefix(fmt.Sprintf("file=%s", s))
log.Printf("Checking if string is binary: %q", s) filelog.Debug("Checking if string is binary: %q", s)
}
for _, c := range s { for _, c := range s {
// 65279 is GOD DAMNED BOM dogshit // 65279 is GOD DAMNED BOM dogshit
if (c < ' ' || c > '~') && c != 65279 { if (c < ' ' || c > '~') && c != 65279 {
if debug { filelog.Trace("Found non-printable character: '%c' with ASCII value %d", c, c)
log.Printf("Found non-printable character: '%c' with ASCII value %d", c, c)
}
return true return true
} }
} }
if debug { filelog.Debug("String is not binary.")
log.Println("String is not binary.")
}
return false return false
} }