"500 Command unrecognized" loop with -sV -sC -p2121 -dd

[jfrancos]

Initially was using -O -sV -sC on a number of hosts, then narrowed it down to the above command as minimal to reproduce a seemingly frozen nmap run.

Running
sudo nmap [ip] -sV -sC -p2121 -dd
eventually results in this looping over and over, many times per second:

NSOCK INFO [30.0650s] nsock_trace_handler_callback(): Callback: READ SUCCESS for EID 5122 [[ip]:2121] (27 bytes): 500 Command unrecognized...
NSOCK INFO [30.0650s] nsock_write(): Write request for 6 bytes to IOD #4 EID 5131 [[ip]:2121]
NSOCK INFO [30.0650s] nsock_trace_handler_callback(): Callback: WRITE SUCCESS for EID 5131 [[ip]:2121]
NSOCK INFO [30.0650s] nsock_read(): Read request from IOD #4 [[ip]:2121] (timeout: 7000ms) EID 5138
NSOCK INFO [30.0670s] nsock_trace_handler_callback(): Callback: READ SUCCESS for EID 5138 [[ip]:2121] (27 bytes): 500 Command unrecognized...
NSOCK INFO [30.0670s] nsock_write(): Write request for 6 bytes to IOD #4 EID 5147 [[ip]:2121]
NSOCK INFO [30.0670s] nsock_trace_handler_callback(): Callback: WRITE SUCCESS for EID 5147 [[ip]:2121]
NSOCK INFO [30.0670s] nsock_read(): Read request from IOD #4 [[ip]:2121] (timeout: 7000ms) EID 5154
NSOCK INFO [30.0690s] nsock_trace_handler_callback(): Callback: READ SUCCESS for EID 5154 [[ip]:2121] (27 bytes): 500 Command unrecognized...
NSOCK INFO [30.0690s] nsock_write(): Write request for 6 bytes to IOD #4 EID 5163 [[ip]:2121]
NSOCK INFO [30.0690s] nsock_trace_handler_callback(): Callback: WRITE SUCCESS for EID 5163 [[ip]:2121]
NSOCK INFO [30.0690s] nsock_read(): Read request from IOD #4 [[ip]:2121] (timeout: 7000ms) EID 5170

Happy to submit the IP privately, if that'll help.

[jfrancos]

Forgot to mention: Nmap 7.70

[nnposter]

Most likely there is a specific script that is stuck. Can you try to identify it by hitting a space while it is looping (and everything else has already stopped)?

You should get output similar to the following:

Stats: 0:00:05 elapsed; 0 hosts completed (1 up), 1 undergoing Script Scan
NSE: Active NSE Script Threads: 1 (1 waiting)
NSE Timing: About 0.00% done
NSE: Script some-buggy-script: 0 threads running, 1 threads waiting

[jfrancos]

Stats: 0:00:40 elapsed; 0 hosts completed (1 up), 1 undergoing Script Scan
NSE: Active NSE Script Threads: 1 (0 waiting)
NSE Timing: About 99.31% done; ETC: 14:07 (0:00:00 remaining)
NSE: Running: ftp-syst M:563354ccc998 against [ip]:2121
	stack traceback:
		[C]: in method 'receive'
		/snap/nmap/68/bin/../share/nmap/nselib/stdnse.lua:289: in function </snap/nmap/68/bin/../share/nmap/nselib/stdnse.lua:285>
		(...tail calls...)
		/snap/nmap/68/bin/../share/nmap/nselib/ftp.lua:81: in function 'ftp.read_reply'
		/snap/nmap/68/bin/../share/nmap/scripts/ftp-syst.nse:89: in function </snap/nmap/68/bin/../share/nmap/scripts/ftp-syst.nse:71>
		(...tail calls...)

[nnposter]

This is very helpful. Stay tuned.

[nnposter]

Could you please apply the following patch to scripts/ftp-syst.nse and test again?

--- a/scripts/ftp-syst.nse
+++ b/scripts/ftp-syst.nse
@@ -81,7 +81,7 @@
 
   -- SYST
   local auth_done = false
-  local syst
+  local syst = nil
   repeat
     if not socket:send("SYST\r\n") then
       return nil
@@ -110,6 +110,9 @@
       if status then
         auth_done = true
       end
+    else
+      stdnse.debug1("SYST error: %d %s", code, message)
+      break
     end
   until not auth_done
 

[jfrancos]

Yes that is much better! Would you like to know anything other than, nmap finishes normally and gives reasonable-looking results?

[nnposter]

If you ran the scan with at least one -d then at some point it should have produced the message from the patch:

SYST error: 500 Command unrecognized

but there is no need to go out of your way to look for it. The stack trace you have provided isolated the issue pretty well. I am confident that this patch is what we should go with. Unless you still see some misbehavior then I am going to commit it.

[jfrancos]

Yup:
NSE: [ftp-syst M:7cb82464 [ip]:2121] SYST error: 500 Command unrecognized.

Thanks for working on this!

[nnposter]

The fix has been committed as r37583. Thank you for reporting the issue and providing the necessary run-time trace.