Re: nmap hang due to bind failed

[Daniel Miller <bonsaiviking () gmail com>]

On Thu, Jan 15, 2015 at 1:11 AM, 泰森 <24123782 () qq com> wrote:

> On Wed, Jan 14, 2015 at 11:31 PM, 泰森 <24123782 () qq com> wrote:
>
> > Hi, all:
> >    First, I'm not sure if somebody has reported this issue.
> >    When I use nmap 6.47 to scan my hosts, sometimes nmap never quit.
> >    Here is my command: nmap -Pn -O -sT -sV --version-intensity 4
> > 10.18.209.151 -e eth1 -T 3 --max-retries 5 --min-rate 250 --min-parallelism
> > 100 -n -oX /tmp/logs/nmap_test.log --open
> > ‍
> >   Here are some parts of nmap output:
> >
> >   NSOCK ERROR [80.7190s] mksock_bind_addr(): Bind to 0.0.0.0:443 failed
> > (IOD #15): Address already in use (98)
> Ricky,
>
> Thanks for this detailed bug report. From the backtrace you gave, it looks
> like Nmap is waiting for a reply somewhere in an NSE script. Since you gave
> the -sV option and no other script options, the script is probably one with
> a "version" category. My guess is it's the rpc-grind.nse.
>
> If you run with the -d2 option, then pressing any key during an NSE phase
> will give a traceback of all the currently running scripts. Please run your
> scan with -d2 and then reply with the tracebacks you see.
>
> I think that the error message is not really the problem: several
> RPC-related scripts attempt to bind to a low-numbered port to bypass some
> security checks in NFS. More likely, there is a service that is
> unresponsive and a script that is using the default 30-second timeout,
> which can result in very long wait times for script completion.
>
> Dan
>
> ------------------------------
>
> Hi, Dan
> Thanks for your response. I run nmap with -d2 again, when repeat 10 times,
> the issue reproduced.
> please look at the tracebacks, I only put the end here.
>
> NSOCK INFO [98.6980s] nsock_trace_handler_callback(): Callback: READ
> SUCCESS for EID 26066 [10.18.209.151:32781] (28 bytes):
> ......;.....................
> NSOCK INFO [98.7490s] nsock_readbytes(): Read request for 4 bytes from IOD
> #8 [10.18.209.151:32781] EID 26074
> NSOCK INFO [98.7490s] nsock_readbytes(): Read request for 4 bytes from IOD
> #18 [10.18.209.151:32781] EID 26082
> NSOCK INFO [98.7490s] nsock_trace_handler_callback(): Callback: READ
> SUCCESS for EID 26074 [10.18.209.151:32781] (36 bytes): ...
> .v5.............................
> NSOCK INFO [98.7490s] nsock_trace_handler_callback(): Callback: READ
> SUCCESS for EID 26082 [10.18.209.151:32781] (28 bytes):
> ......q.....................
> NSOCK INFO [98.7490s] nsock_trace_handler_callback(): Callback: WRITE
> SUCCESS for EID 26091 [10.18.209.151:32781]
> NSE: Finished 'rpc-grind' worker (thread: 0x939f108) against
> 10.18.209.151:32781.
> NSE: Finished 'rpc-grind' worker (thread: 0x942f300) against
> 10.18.209.151:32781.
> NSOCK INFO [98.8000s] nsock_readbytes(): Read request for 4 bytes from IOD
> #23 [10.18.209.151:32781] EID 26098
> NSOCK INFO [98.8000s] nsi_delete(): nsi_delete (IOD #18)
> NSOCK INFO [98.8000s] nsi_delete(): nsi_delete (IOD #8)
> NSOCK INFO [98.8000s] nsock_trace_handler_callback(): Callback: READ
> SUCCESS for EID 26098 [10.18.209.151:32781] (28 bytes):
> ......;.....................
> NSE: Finished 'rpc-grind' worker (thread: 0x93a0790) against
> 10.18.209.151:32781.
> NSOCK INFO [98.8500s] nsi_delete(): nsi_delete (IOD #23)
> NSOCK INFO [101.2540s] nsock_trace_handler_callback(): Callback: READ
> TIMEOUT for EID 370 [10.18.209.151:9]
> NSE: rpc-grind: isRPC didn't receive response.
> NSE: Target port 9 is not a RPC port.
> NSE: Finished 'rpc-grind' (thread: 0x9406440) against 10.18.209.151:9.
> NSOCK INFO [101.2660s] nsi_delete(): nsi_delete (IOD #3)
> NSE Timing: About 96.08% done; ETC: 20:26 (0:00:01 remaining)
> NSE Timing: About 96.08% done; ETC: 20:26 (0:00:02 remaining)
> NSE Timing: About 96.08% done; ETC: 20:27 (0:00:04 remaining)
> NSE Timing: About 96.08% done; ETC: 20:27 (0:00:05 remaining)
> NSE Timing: About 96.08% done; ETC: 20:28 (0:00:06 remaining)
> NSE Timing: About 96.08% done; ETC: 20:28 (0:00:07 remaining)
> NSE Timing: About 96.08% done; ETC: 20:29 (0:00:09 remaining)
> NSE Timing: About 96.08% done; ETC: 20:29 (0:00:10 remaining)
> NSE Timing: About 96.08% done; ETC: 20:30 (0:00:11 remaining)
> NSE Timing: About 96.08% done; ETC: 20:30 (0:00:12 remaining)
> NSE Timing: About 96.08% done; ETC: 20:31 (0:00:14 remaining)
> NSE Timing: About 96.08% done; ETC: 20:31 (0:00:15 remaining)
> NSE Timing: About 96.08% done; ETC: 20:32 (0:00:16 remaining)
> NSE Timing: About 96.08% done; ETC: 20:32 (0:00:17 remaining)
> NSE Timing: About 96.08% done; ETC: 20:33 (0:00:18 remaining)
> NSE Timing: About 96.08% done; ETC: 20:33 (0:00:20 remaining)
> NSE Timing: About 96.08% done; ETC: 20:34 (0:00:21 remaining)
> NSE Timing: About 96.08% done; ETC: 20:34 (0:00:22 remaining)
> NSE Timing: About 96.08% done; ETC: 20:35 (0:00:23 remaining)
> NSE Timing: About 96.08% done; ETC: 20:35 (0:00:25 remaining)
> NSE Timing: About 96.08% done; ETC: 20:36 (0:00:26 remaining)
> NSE Timing: About 96.08% done; ETC: 20:36 (0:00:27 remaining)
> NSE Timing: About 96.08% done; ETC: 20:37 (0:00:28 remaining)
> NSE Timing: About 96.08% done; ETC: 20:37 (0:00:29 remaining)
> NSE Timing: About 96.08% done; ETC: 20:38 (0:00:31 remaining)
> NSE Timing: About 96.08% done; ETC: 20:39 (0:00:32 remaining)
> NSE Timing: About 96.08% done; ETC: 20:39 (0:00:33 remaining)
> NSE Timing: About 96.08% done; ETC: 20:40 (0:00:34 remaining)
> NSE Timing: About 96.08% done; ETC: 20:40 (0:00:36 remaining)
> NSE Timing: About 96.08% done; ETC: 20:41 (0:00:37 remaining)
> NSE Timing: About 96.08% done; ETC: 20:41 (0:00:38 remaining)
> NSE Timing: About 96.08% done; ETC: 20:42 (0:00:39 remaining)
> NSE Timing: About 96.08% done; ETC: 20:42 (0:00:40 remaining)
> NSE Timing: About 96.08% done; ETC: 20:43 (0:00:42 remaining)
> NSE Timing: About 96.08% done; ETC: 20:43 (0:00:43 remaining)
> NSE Timing: About 96.08% done; ETC: 20:44 (0:00:44 remaining)
> NSE Timing: About 96.08% done; ETC: 20:44 (0:00:46 remaining)
> NSE Timing: About 96.08% done; ETC: 20:45 (0:00:47 remaining)
> NSE Timing: About 96.08% done; ETC: 20:45 (0:00:48 remaining)
> NSE Timing: About 96.08% done; ETC: 20:46 (0:00:49 remaining)
> NSE Timing: About 96.08% done; ETC: 20:46 (0:00:50 remaining)
> NSE Timing: About 96.08% done; ETC: 20:47 (0:00:52 remaining)
> NSE Timing: About 96.08% done; ETC: 20:47 (0:00:53 remaining)
> NSE Timing: About 96.08% done; ETC: 20:48 (0:00:54 remaining)
> NSE Timing: About 96.08% done; ETC: 20:49 (0:00:55 remaining)
> NSE Timing: About 96.08% done; ETC: 20:49 (0:00:57 remaining)
> NSE Timing: About 96.08% done; ETC: 20:50 (0:00:58 remaining)
> NSE Timing: About 96.08% done; ETC: 20:50 (0:00:59 remaining)
> NSE Timing: About 96.08% done; ETC: 20:51 (0:01:00 remaining)
> NSE Timing: About 96.08% done; ETC: 20:51 (0:01:02 remaining)
> NSE Timing: About 96.08% done; ETC: 20:52 (0:01:03 remaining)
> NSE Timing: About 96.08% done; ETC: 20:52 (0:01:04 remaining)
> NSE Timing: About 96.08% done; ETC: 20:53 (0:01:05 remaining)
> NSE Timing: About 96.08% done; ETC: 20:53 (0:01:06 remaining)
Ricky,

Perhaps I was not clear. In order to get the backtraces of running scripts,
you must press any key during the execution. When Nmap is hanging at
96.08%, press the space bar at the console and you will see something like
this:

 NSE: Waiting: script-name M:22b8df0
        stack traceback:
                [C]: in function 'foo'
                script-name.nse:11: in function <script-name.nse:10>
                (...tail calls...)

I will work on better debugging output for future releases.

Dan

_______________________________________________
Sent through the dev mailing list
http://nmap.org/mailman/listinfo/dev
Archived at http://seclists.org/nmap-dev/