Streaming implementation to prevent OOMs for very long scans with progress

[echox]

I get reproducible crashes after scanning a large number of hosts, for example a /24 network.
I'm using -sSV -p- so the scan will take a while.
After ~ 1 hour the application simply exits with the following errors:

goroutine 91 [IO wait, 317 minutes]:
internal/poll.runtime_pollWait(0x7fa9fa9c8ea0, 0x72, 0xc00003ece8)
        /usr/lib/go-1.11/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc001942798, 0x72, 0xffffffffffffff01, 0x542a60, 0x5ed140)
        /usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc001942798, 0xc00013c401, 0x200, 0x200)
        /usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc001942780, 0xc00013c400, 0x200, 0x200, 0x0, 0x0, 0x0)
        /usr/lib/go-1.11/src/internal/poll/fd_unix.go:169 +0x179
os.(*File).read(0xc0001720b8, 0xc00013c400, 0x200, 0x200, 0xc00013c400, 0x0, 0x0)
        /usr/lib/go-1.11/src/os/file_unix.go:249 +0x4e
os.(*File).Read(0xc0001720b8, 0xc00013c400, 0x200, 0x200, 0xc00003ee58, 0x49b31c, 0xc00003ee60)
        /usr/lib/go-1.11/src/os/file.go:108 +0x69
bytes.(*Buffer).ReadFrom(0xc0001c63f0, 0x542900, 0xc0001720b8, 0x7fa9fa984020, 0xc0001c63f0, 0x1)
        /usr/lib/go-1.11/src/bytes/buffer.go:206 +0xbd
io.copyBuffer(0x542780, 0xc0001c63f0, 0x542900, 0xc0001720b8, 0x0, 0x0, 0x0, 0xc00d2a6660, 0x0, 0x0)
        /usr/lib/go-1.11/src/io/io.go:388 +0x303
io.Copy(0x542780, 0xc0001c63f0, 0x542900, 0xc0001720b8, 0x404a75, 0xc00d2a67e0, 0xc00003efb0)
        /usr/lib/go-1.11/src/io/io.go:364 +0x5a
os/exec.(*Cmd).writerDescriptor.func1(0xc00d2a67e0, 0xc00003efb0)
        /usr/lib/go-1.11/src/os/exec/exec.go:279 +0x4d
os/exec.(*Cmd).Start.func1(0xc003427a20, 0xc00220bc80)
        /usr/lib/go-1.11/src/os/exec/exec.go:400 +0x27
created by os/exec.(*Cmd).Start
        /usr/lib/go-1.11/src/os/exec/exec.go:399 +0x5af

goroutine 90 [IO wait]:
internal/poll.runtime_pollWait(0x7fa9fa9c8820, 0x72, 0xc0000a1ce8)
        /usr/lib/go-1.11/src/runtime/netpoll.go:173 +0x66
internal/poll.(*pollDesc).wait(0xc0019426d8, 0x72, 0xffffffffffffff01, 0x542a60, 0x5ed140)
        /usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:85 +0x9a
internal/poll.(*pollDesc).waitRead(0xc0019426d8, 0xc0fdd84b01, 0xd209, 0xd209)
        /usr/lib/go-1.11/src/internal/poll/fd_poll_runtime.go:90 +0x3d
internal/poll.(*FD).Read(0xc0019426c0, 0xc0fdd84bf7, 0xd209, 0xd209, 0x0, 0x0, 0x0)
        /usr/lib/go-1.11/src/internal/poll/fd_unix.go:169 +0x179
os.(*File).read(0xc0001720a0, 0xc0fdd84bf7, 0xd209, 0xd209, 0x6c, 0x0, 0x0)
        /usr/lib/go-1.11/src/os/file_unix.go:249 +0x4e
os.(*File).Read(0xc0001720a0, 0xc0fdd84bf7, 0xd209, 0xd209, 0x6c, 0x0, 0x0)
        /usr/lib/go-1.11/src/os/file.go:108 +0x69
bytes.(*Buffer).ReadFrom(0xc0001c6380, 0x542900, 0xc0001720a0, 0x7fa9fa984020, 0xc0001c6380, 0xc00d2dc901)
        /usr/lib/go-1.11/src/bytes/buffer.go:206 +0xbd
io.copyBuffer(0x542780, 0xc0001c6380, 0x542900, 0xc0001720a0, 0x0, 0x0, 0x0, 0xc00d2a6720, 0x0, 0x0)
        /usr/lib/go-1.11/src/io/io.go:388 +0x303
io.Copy(0x542780, 0xc0001c6380, 0x542900, 0xc0001720a0, 0x404a75, 0xc00d2a67e0, 0xc0004c3fb0)
        /usr/lib/go-1.11/src/io/io.go:364 +0x5a
os/exec.(*Cmd).writerDescriptor.func1(0xc00d2a67e0, 0xc0004c3fb0)
        /usr/lib/go-1.11/src/os/exec/exec.go:279 +0x4d
os/exec.(*Cmd).Start.func1(0xc003427a20, 0xc00220bc40)
        /usr/lib/go-1.11/src/os/exec/exec.go:400 +0x27
created by os/exec.(*Cmd).Start
        /usr/lib/go-1.11/src/os/exec/exec.go:399 +0x5af

goroutine 89 [chan receive]:
main.scan_host.func1(0xc00015a000, 0xc00220bc00, 0x1)
        main.go:139 +0x3f
created by main.scan_host
        main.go:138 +0x432
exit status 2

main.go:139 does contain the progress function.

The code (the progress if statement is not the most elegant but shouldn't be the cause of the error I guess :)):

        s, err := nmap.NewScanner(
                nmap.WithTargets(host),
                nmap.WithTimingTemplate(nmap.TimingAggressive),
                nmap.WithServiceInfo(),
                nmap.WithSYNScan(),
                nmap.WithPorts("-"),
                nmap.WithVerbosity(3),
                //nmap.WithFastMode(),
        )

        if err != nil {
                log.Fatalf("[worker_%v] unable to create nmap scanner: %v", id, err)
        }

        progress := make(chan float32, 1)
        ts := time.Now()
        go func() {
                for p := range progress {
                        if time.Now().After(ts.Add(60 * time.Second)) {
                                ts = time.Now()
                                log.Printf("[worker_%v] portscan progress: %v %%", id, p)
                        }
                }
        }()

        result, w, e := s.RunWithProgress(progress)

I'm not sure if this is a bug in the library, a frozen nmap process or anything else...
Doing a fast-mode scan with the same settings works fine (which is obviously faster ;-)).

I would appreciate any hints for debugging this further because I guess the pasted errors are not that helpful and I have no experience debugging these kind of errors in the go ecosystem.

[echox]

I recognized I can't reproduce the error if I remove the progress function, so it maybe related to the progress channel.

[Ullaakut]

Hi @echox thanks for opening this issue! :)

This sounds like a fun one to reproduce! 😄 The stack trace indeed does not really indicate the source of the error here, but simply says that the two goroutines were waiting while reading on channels when it crashed, AFAIK.

Was this really the only output when it crashed? The exit status 2 most likely comes from nmap itself erroring, but that should be caught by cameradar and handled appropriately, so this is for sure a pretty serious bug.

I'll try to reproduce it when I have some time, but I'm on holidays currently (even if I still work a little bit) so it might take me a while unfortunately.

I'd be very grateful to anyone willing to take a look.

[elivlo]

Hi,

since I coded that method back in December 2020 I feel responsible for this issue. ;)
Because I do not want to scan a public /24 network, I will try to reproduce this error by creating a script like we do it for testing. So I'm going to run a bash script as nmap-mockup that exits with status code 2.

@echox As a quick and dirty alternative you may do something like this by using the RunWithStreamer method and parsing the progress yourself. The output should be grepable with a regular expression.

[elivlo]

So I took your code @echox and opened the debugger in my IntelliJ IDE.
This is a snapshot from all running go routines:

As far as I can tell the error you'll get is coming from the function cmd.Start() in nmap.go line 188. I compared it with your error log and the first two blocks seem identical with the one in the picture.

I also ran a mass scan on my home-network, but I had to cancel it when I crashed my entire infastructure.:see_no_evil:

Could you please tell which Go version you use?

[echox]

Thanks for the help so far, no need to hurry and it might a somewhat slow progress anyway :)

@elivlo I've run into this on the following two versions:

• go1.11.6 linux/amd64
• go1.16.4 darwin/amd64

I've striped down my example code and started a scan against the /24 and /26 (I'm allowed to scan ;-)).
This should reproduce the error after a while.
If this works I will add RunWithStreamer() and log the output.

Thanks!