google / log4jscanner

A log4j vulnerability filesystem scanner and Go package for analyzing JAR files.
Apache License 2.0
1.56k stars 121 forks source link

Improve Parse performance #40

Closed mknyszek closed 2 years ago

mknyszek commented 2 years ago

This set of changes makes one small fix to the YARA rule checker for a false positive, adds a parallel test, and then improves performance by (1) sharing a decoding buffer via a sync.Pool and (2) reducing file scans to a single pass.

mknyszek commented 2 years ago

Hm. I'm not sure why that test failed. I'm currently running the tests in a loop to try to reproduce but I haven't been able to so far.

mknyszek commented 2 years ago

OK... It passed this time. I don't like that it failed. I'm worried that there's something subtly wrong with my use of sync.Pool, so I'll stare at that a little more.

ericchiang commented 2 years ago

Mind running https://pkg.go.dev/golang.org/x/tools/cmd/stress on this PR?

ericchiang commented 2 years ago

Yeah, looks like this is flaky

ericchiang@erics-mbp jar % go test -o jar.test            
go: downloading rsc.io/binaryregexp v0.2.0
PASS
ok      github.com/google/log4jscanner/jar  6.163s
ericchiang@erics-mbp jar % ~/go/bin/stress ./jar.test 
5s: 0 runs so far, 0 failures
10s: 0 runs so far, 0 failures
15s: 1 runs so far, 0 failures
20s: 8 runs so far, 0 failures
25s: 8 runs so far, 0 failures
30s: 8 runs so far, 0 failures

/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/go-stress-20220105T185111-2770984403
--- FAIL: TestWalker (0.48s)
    walker_test.go:92: walking filesystem returned diff (-want, +got):   []string{
            ... // 7 identical elements
            "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalker16629"...,
            "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalker16629"...,
        -   "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalker166299706/001/vuln-class.jar",
          }
FAIL

ERROR: exit status 1

35s: 16 runs so far, 1 failures (6.25%)
40s: 16 runs so far, 1 failures (6.25%)
45s: 16 runs so far, 1 failures (6.25%)
50s: 24 runs so far, 1 failures (4.17%)
55s: 24 runs so far, 1 failures (4.17%)
1m0s: 24 runs so far, 1 failures (4.17%)

/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/go-stress-20220105T185111-3757285326
--- FAIL: TestWalkerRewrite (1.81s)
    walker_test.go:165: walking filesystem returned diff (-want, +got):   []string{
            ... // 7 identical elements
            "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalkerRewri"...,
            "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalkerRewri"...,
        -   "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalkerRewrite1428347608/001/vuln-class.jar",
          }
    walker_test.go:177: walking filesystem after rewrite returned diff (-want, +got):   []string{
        +   "/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/TestWalkerRewrite1428347608/001/vuln-class.jar",
          }
FAIL

ERROR: exit status 1

/var/folders/d1/wpvcpdrs2tlgn5xs3_xm88th0000gn/T/go-stress-20220105T185111-821714357
--- FAIL: TestParse (0.60s)
    --- FAIL: TestParse/log4j-core-2.1.jar (0.01s)
        jar_test.go:83: checkJAR() returned unexpected value, got bad=false, want bad=true
FAIL
mknyszek commented 2 years ago

d'oh. I think I see the problem (or at least, a problem). it's with the byteReader; the initial length of the buffer is incorrect. if the buffer is dirty and the file is small, lots of stuff can go wrong. I really wish you could just pass a buffer into bufio.Reader.

mknyszek commented 2 years ago

20m of continuous execution with stress and I can't reproduce (I can reproduce as fast as you did with stress).

The reason why running the tests in a loop didn't work for me before is because the buffer wasn't getting dirtied in just the right way from other tests, I guess.

mknyszek commented 2 years ago

stress ran for 35m without failing before I stopped it, around 1000 runs of the full suite, without failure. I can run longer if need be.

I added tests for byteReader to be extra safe, also (which I should've done anyway).