Velocidex / velociraptor

Digging Deeper....
https://docs.velociraptor.app/
Other
2.8k stars 469 forks source link

[Bug] MergeSortGrouper errors #3553

Closed nullifysecurity closed 1 month ago

nullifysecurity commented 1 month ago

Hi there,

Just reporting an unusual bug that I encountered which causes Velociraptor to throw hundreds (to thousands) of errors and become unresponsive when a particular query is run from a hunt notebook. Initially I noticed this issue occurred on 0.72.3 but downgraded to 0.72.1 and noticed the same thing happening.

Jun 12 00:20:57 REDACTED velociraptor[695]: Copying scope of 1001 children - this is probably a bug!!!
Jun 12 00:20:57 REDACTED velociraptor[695]: goroutine 5125366 [running]:
Jun 12 00:20:57 REDACTED velociraptor[695]: runtime/debug.Stack()
Jun 12 00:20:57 REDACTED velociraptor[695]:         /opt/hostedtoolcache/go/1.22.3/x64/src/runtime/debug/stack.go:24 +0x5e
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/vfilter/scope.(*Scope).Copy(0xc007f3dbc0)
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/go/pkg/mod/www.velocidex.com/golang/vfilter@v0.0.0-20240507155450-520bec263d49/scope/scope.go:377 +0x237
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/vfilter.(*_SelectExpression).Transform(0xc000605660, {0x27b0868, 0xc002cd2460}, {0x27d2b50, 0xc007f3dbc0}, {0x22f8360, 0xc005e8cb40})
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/go/pkg/mod/www.velocidex.com/golang/vfilter@v0.0.0-20240507155450-520bec263d49/vfilter.go:942 +0x35e
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/vfilter.(*GroupbyActor).GetNextRow(0xc0020d98a0, {0x27b0868, 0xc002cd2460}, {0x27d2b50, 0xc000908480})
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/go/pkg/mod/www.velocidex.com/golang/vfilter@v0.0.0-20240507155450-520bec263d49/vfilter_group.go:35 +0x13f
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/velociraptor/vql/grouper.(*MergeSortGrouper).Group.func1()
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/work/velociraptor/velociraptor/vql/grouper/mergegrouper.go:202 +0x102
Jun 12 00:20:57 REDACTED velociraptor[695]: created by www.velocidex.com/golang/velociraptor/vql/grouper.(*MergeSortGrouper).Group in goroutine 5125363
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/work/velociraptor/velociraptor/vql/grouper/mergegrouper.go:196 +0x125
Jun 12 00:20:57 REDACTED velociraptor[695]: Copying scope of 1002 children - this is probably a bug!!!
Jun 12 00:20:57 REDACTED velociraptor[695]: goroutine 5125366 [running]:
Jun 12 00:20:57 REDACTED velociraptor[695]: runtime/debug.Stack()
Jun 12 00:20:57 REDACTED velociraptor[695]:         /opt/hostedtoolcache/go/1.22.3/x64/src/runtime/debug/stack.go:24 +0x5e
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/vfilter/scope.(*Scope).Copy(0xc007f3dbc0)
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/go/pkg/mod/www.velocidex.com/golang/vfilter@v0.0.0-20240507155450-520bec263d49/scope/scope.go:377 +0x237
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/vfilter.(*_SelectExpression).Transform(0xc000605660, {0x27b0868, 0xc002cd2460}, {0x27d2b50, 0xc007f3dbc0}, {0x22f8360, 0xc005e8ccc0})
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/go/pkg/mod/www.velocidex.com/golang/vfilter@v0.0.0-20240507155450-520bec263d49/vfilter.go:942 +0x35e
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/vfilter.(*GroupbyActor).GetNextRow(0xc0020d98a0, {0x27b0868, 0xc002cd2460}, {0x27d2b50, 0xc000908480})
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/go/pkg/mod/www.velocidex.com/golang/vfilter@v0.0.0-20240507155450-520bec263d49/vfilter_group.go:35 +0x13f
Jun 12 00:20:57 REDACTED velociraptor[695]: www.velocidex.com/golang/velociraptor/vql/grouper.(*MergeSortGrouper).Group.func1()
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/work/velociraptor/velociraptor/vql/grouper/mergegrouper.go:202 +0x102
Jun 12 00:20:57 REDACTED velociraptor[695]: created by www.velocidex.com/golang/velociraptor/vql/grouper.(*MergeSortGrouper).Group in goroutine 5125363
Jun 12 00:20:57 REDACTED velociraptor[695]:         /home/runner/work/velociraptor/velociraptor/vql/grouper/mergegrouper.go:196 +0x125

The error occurs in the server's journal logging after running the following query in the hunt notebook for a Windows.System.Pslist collection (approx. 250 clients):

SELECT Exe,CommandLine, Fqdn FROM source(artifact="Windows.System.Pslist")
WHERE Exe =~ "apache|tomcat|nginx|w3wp"
GROUP BY Exe

I was able to replicate the issue by starting another Windows.System.Pslist hunt and creating a notebook cell with the same query. I'm unsure if it is happening with other queries as well, there are thousands of these errors in the journal.

Let me know if you need any additional information from the server.

scudette commented 1 month ago

Thanks for reporting this issue - I think this issue was fixed by this https://github.com/Velocidex/vfilter/commit/307fc598a311a0b47fc708a665ce4fdc7c69870a

which should be merged with the latest head build - could you please test with that?

nullifysecurity commented 1 month ago

Thanks for your quick response, @scudette!

I've just tested with the latest CI build (1135) and confirmed that the issue is no longer present, thank you!

name: velociraptor
version: 0.72.3
commit: 66960c3
build_time: "2024-06-12T02:06:51Z"
ci_build_url: https://github.com/Velocidex/velociraptor/actions/runs/9475544984
compiler: go1.22.3