Debugging NSE scripts

Debugging NSE has one twist: a script that fails, a script that finds nothing and a script that never ran can all look identical: a scan with no output for that port. Your first job is always to work out which one you’re dealing with.

The debugging toolbox

Start with -d. Increase the level only when you need more.

nmap -d -p 8000 --script ./my-script.nse 127.0.0.1
nmap -d --script-trace -p 8000 --script ./my-script.nse 127.0.0.1

What a crash looks like

Without -d, an unhandled error is deliberately terse:

PORT     STATE SERVICE
7080/tcp open  empowerid
|_buggy-server: ERROR: Script execution failed (use -d to debug)

With -d you get the real message and a stack trace:

NSE: buggy-server against 127.0.0.1:7080 threw an error!
./buggy-server.nse:13: attempt to concatenate a nil value (field 'server')
stack traceback:
        ./buggy-server.nse:13: in function <./buggy-server.nse:11>
        (...tail calls...)

Read it from the top: file, line number, then what went wrong. The line number points you straight at the bug.

Your own log lines

stdnse.debug1 through debug5 print only when the user runs with -d at that level or higher, so you can leave them in production scripts.

stdnse.debug1("connecting to %s:%d", host.ip, port.number)
stdnse.debug2("banner=%q", banner)                 -- %q shows hidden characters like \r\n
stdnse.debug3("headers=%s", nsedebug.tostr(resp.header))

Use %q when logging network data. It quotes the string and shows \r, \n and control bytes that would otherwise be invisible.

Lab: fix the broken script

local http = require "http"
local shortport = require "shortport"

description = "Prints the Server header"
author = "You"
license = "Same as Nmap--See https://nmap.org/book/man-legal.html"
categories = {"safe"}

portrule = shortport.port_or_service(80, "http")

action = function(host, port)
  local response = http.get(host, port, "/")
  return "Server: " .. response.header.server
end

Python’s built-in web server always sends a Server header, so for this lab use a bare server that doesn’t. Save it as bare_server.py and leave it running:

import socketserver

class Handler(socketserver.BaseRequestHandler):
    def handle(self):
        self.request.recv(4096)
        self.request.sendall(b"HTTP/1.1 200 OK\r\nContent-Length: 2\r\nConnection: close\r\n\r\nok")

socketserver.ThreadingTCPServer.allow_reuse_address = True
with socketserver.ThreadingTCPServer(("127.0.0.1", 7080), Handler) as server:
    server.serve_forever()

Keep the python3 -m http.server 8000 server from earlier running too.

Symptom 1: silence. Run nmap -p 8000 --script ./buggy-server.nse 127.0.0.1. The port is listed, but there’s no script output at all. Is that “ran and found nothing”, “crashed” or “never ran”?

Run it again with -d and look at the NSE lines. You’ll see the script loaded, and no error. Now compare the port number and its detected service name against the script’s rule.

Symptom 2: a crash. Fix the rule (switch it to shortport.http), then run against the bare server: nmap -p 7080 --script ./buggy-server.nse 127.0.0.1. What does the output say? Rerun with -d. What extra information do you get, and which line of your script does it point at?

Symptom 3: watching the traffic. Use --script-trace to watch the request and response on port 7080:

nmap --script-trace -p 7080 --script ./buggy-server.nse 127.0.0.1

You’ll see lines like the following. Look at the response and find the header the code assumed would be there.

NSE: TCP 127.0.0.1:20897 > 127.0.0.1:7080 | CONNECT
NSE: TCP 127.0.0.1:20897 > 127.0.0.1:7080 | 00000000: 47 45 54 20 2f 20 48 54 54 50 2f 31 2e 31 0d 0a GET / HTTP/1.1
NSE: TCP 127.0.0.1:20897 < 127.0.0.1:7080 | 00000000: 48 54 54 50 2f 31 2e 31 20 32 30 30 20 4f 4b 0d HTTP/1.1 200 OK

portrule = shortport.http

action = function(host, port)
  local response = http.get(host, port, "/")
  if not (response and response.status) then
    return nil                                    -- request failed: nothing to report
  end
  local server = response.header["server"]
  if not server then return nil end               -- no header: nothing to report
  return "Server: " .. server
end

A repeatable checklist

When a script does nothing or the wrong thing, work down this list. Each step rules something out.

1. Did it load? Run with -d. A syntax error appears at startup (NSE: failed to initialize the script engine) with the file and line.
2. Did the rule match? Temporarily make it return true (or print with stdnse.debug1 at the start of the rule). If the script now runs, the rule was wrong. Check port number, protocol, state and the service name (-sV changes it).
3. Did action start? Add stdnse.debug1("action start") as its first line. Look for it under -d.
4. Did the network call succeed? Use --script-trace, or log the status, err a library call returns.
5. Is the data what you expect? Log it with %q, or with nsedebug.tostr for tables.
6. Does it return what you think it returns? Run with -oX - and check the XML. An early return nil looks like “nothing found”.

Common Lua and NSE mistakes

Testing logic outside Nmap

Pure-Lua helper functions (version parsers, pattern extractors) can be tested with a standalone lua interpreter, which starts instantly and has no network in the way:

-- test_helpers.lua
local function parse_version(s) ... end   -- paste the function under test
assert(parse_version("1.4.2")[2] == 4)
assert(parse_version("nope") == nil)
print("ok")

The habit of keeping logic in small local functions, separate from the network code, makes scripts far easier to test and debug.

Checkpoint