Re: Match ICMP echo reply to request in scan_engine.cc

[Chris Johnson <cjohnson () zenoss com>]

Use this patch instead: http://git.io/nmap-cjohnson.diff (also attached)

I've updated the patch to prevent interference from concurrent pings.

For example, run the following commands, quickly enough so that the background processes run concurrently.

    sudo tc qdisc add dev eth0 root netem delay 1800ms
    sudo nmap nmap.org -sn -PE -n --privileged --max-retries 1 --min-rtt-timeout 1.5s --max-rtt-timeout 1.5s &
    sudo nmap nmap.org -sn -PE -n --privileged --max-retries 1 --min-rtt-timeout 1.5s --max-rtt-timeout 1.5s &
    sleep 4
    sudo tc qdisc del dev eth0 root

Both nmap command results should show latency around 1.8s (plus natural latency to nmap.org). Without the patch, one 
will have a much lower (bogus) latency.

  - chris

Zenoss, Inc. offers the Nmap Project (Insecure.Com LLC) the unlimited, non-exclusive right to reuse, modify, and 
relicense the code contained in this email.


----- Original Message -----
From: "Chris Johnson" <cjohnson () zenoss com>
To: dev () nmap org
Sent: Tuesday, July 23, 2013 8:31:45 AM
Subject: Match ICMP echo reply to request in scan_engine.cc

Zenoss, Inc. offers the Nmap Project (Insecure.Com LLC) the unlimited, non-exclusive right to reuse, modify, and 
relicense the code contained in this email.

Steps to reproduce and fix bug:

0. Create some artificial latency

    $ sudo tc qdisc add dev eth0 root netem delay 500ms

1. Make sure you did that correctly with a sanity check

    $ ping www.google.com
    
    PING www.google.com (74.125.227.48) 56(84) bytes of data.
    64 bytes from 74.125.227.48: icmp_seq=1 ttl=63 time=506 ms
    64 bytes from 74.125.227.48: icmp_seq=2 ttl=63 time=509 ms
    64 bytes from 74.125.227.48: icmp_seq=3 ttl=63 time=510 ms
    64 bytes from 74.125.227.48: icmp_seq=4 ttl=63 time=510 ms
    64 bytes from 74.125.227.48: icmp_seq=5 ttl=63 time=519 ms
    64 bytes from 74.125.227.48: icmp_seq=6 ttl=63 time=527 ms
    ^C
    --- www.google.com ping statistics ---
    6 packets transmitted, 6 received, 0% packet loss, time 6216ms
    rtt min/avg/max/mdev = 506.614/513.973/527.012/7.139 ms


2. Try that with nmap.

    $ sudo nmap 74.125.227.48 -sn -PE -n --privileged --send-ip --min-rtt-timeout 1000ms --max-rtt-timeout 1000ms 
--max-retries 1

    Starting Nmap 6.26SVN ( http://nmap.org ) at 2013-07-22 18:20 UTC
    Nmap scan report for 74.125.227.48
    Host is up (0.51s latency).
    Nmap done: 1 IP address (1 host up) scanned in 0.55 seconds


3. That looks fine, now try it with a shorter rtt-timeout, and max-retries 0 ...

    $ sudo nmap 74.125.227.48 -sn -PE -n --privileged --send-ip --min-rtt-timeout 400ms --max-rtt-timeout 400ms 
--max-retries 0

    Starting Nmap 6.26SVN ( http://nmap.org ) at 2013-07-22 18:21 UTC
    Warning: 74.125.227.48 giving up on port because retransmission cap hit (0).
    Note: Host seems down. If it is really up, but blocking our ping probes, try -Pn
    Nmap done: 1 IP address (0 hosts up) scanned in 0.46 seconds


4. That makes sense. But if we try with a shorter rtt-timeout and max retries > 0 ...

    $ sudo nmap 74.125.227.48 -sn -PE -n --privileged --send-ip --min-rtt-timeout 400ms --max-rtt-timeout 400ms 
--max-retries 1

    Starting Nmap 6.26SVN ( http://nmap.org ) at 2013-07-22 18:21 UTC
    Nmap scan report for 74.125.227.48
    Host is up (0.11s latency).
    Nmap done: 1 IP address (1 host up) scanned in 0.57 seconds


5. Wait, what? 0.11s latency? Let's try that again with a little more debug logging ...

    $ sudo nmap 74.125.227.48 -sn -PE -n --privileged --send-ip --min-rtt-timeout 400ms --max-rtt-timeout 400ms 
--max-retries 1 -ddd

    Starting Nmap 6.26SVN ( http://nmap.org ) at 2013-07-22 18:21 UTC
    Fetchfile found /usr/local/bin/../share/nmap/nmap.xsl
    The max # of sockets we are using is: 0
    --------------- Timing report ---------------
      hostgroups: min 1, max 100000
      rtt-timeouts: init 400, min 400, max 400
      max-scan-delay: TCP 1000, UDP 1000, SCTP 1000
      parallelism: min 0, max 0
      max-retries: 1, host-timeout: 0
      min-rate: 0, max-rate: 0
    ---------------------------------------------
    Fetchfile found /usr/local/bin/../share/nmap/nmap-payloads
    Initiating Ping Scan at 18:21
    Scanning 74.125.227.48 [1 port]
    Packet capture filter (device eth0): dst host 10.0.2.15 and (icmp or icmp6 or ((tcp or udp or sctp) and (src host 
74.125.227.48)))
    SENT (0.0244s) ICMP [10.0.2.15 > 74.125.227.48 Echo request (type=8/code=0) id=61757 seq=0] IP [ver=4 ihl=5 
tos=0x00 iplen=28 id=47178 foff=0 ttl=51 proto=1 csum=0x95da]
    **TIMING STATS** (0.0244s): IP, probes active/freshportsleft/retry_stack/outstanding/retranwait/onbench, 
cwnd/ssthresh/delay, timeout/srtt/rttvar/
       Groupstats (1/1 incomplete): 1/*/*/*/*/* 10.00/75/* 400000/-1/-1
    Current sending rates: 44.51 packets / s, 1246.33 bytes / s.
    Overall sending rates: 44.51 packets / s, 1246.33 bytes / s.
    SENT (0.4301s) ICMP [10.0.2.15 > 74.125.227.48 Echo request (type=8/code=0) id=44373 seq=0] IP [ver=4 ihl=5 
tos=0x00 iplen=28 id=21126 foff=0 ttl=45 proto=1 csum=0x019f]
    **TIMING STATS** (0.4302s): IP, probes active/freshportsleft/retry_stack/outstanding/retranwait/onbench, 
cwnd/ssthresh/delay, timeout/srtt/rttvar/
       Groupstats (1/1 incomplete): 1/*/*/*/*/* 10.00/75/* 400000/-1/-1
    Current sending rates: 4.67 packets / s, 130.76 bytes / s.
    Overall sending rates: 4.67 packets / s, 130.76 bytes / s.
    RCVD (0.5391s) ICMP [74.125.227.48 > 10.0.2.15 Echo reply (type=0/code=0) id=61757 seq=0] IP [ver=4 ihl=5 tos=0x00 
iplen=28 id=13833 foff=0 ttl=50 proto=1 csum=0x191c]
    Found 74.125.227.48 in incomplete hosts list.
    We got a ping packet back from 74.125.227.48: id = 15857 seq = 0 checksum = 49678
    ultrascan_host_probe_update called for machine 74.125.227.48 state UNKNOWN -> HOST_UP (trynum 1 time: 109170)
    Ultrascan DROPPED probe packet to 74.125.227.48 detected
    Changing ping technique for 74.125.227.48 to icmp type 8 code 0
    Moving 74.125.227.48 to completed hosts list with 0 outstanding probes.
    Changing global ping host to 74.125.227.48.
    Completed Ping Scan at 18:21, 0.54s elapsed (1 total hosts)
    Overall sending rates: 3.72 packets / s, 104.22 bytes / s.
    pcap stats: 1 packets received by filter, 0 dropped by kernel.
    Nmap scan report for 74.125.227.48
    Host is up, received echo-reply (0.11s latency).
    Final times for host: srtt: 109047 rttvar: 109047  to: 400000
    Read from /usr/local/bin/../share/nmap: nmap-payloads.
    Nmap done: 1 IP address (1 host up) scanned in 0.56 seconds
               Raw packets sent: 2 (56B) | Rcvd: 1 (28B)

6. Looks like we matched up the response from the first (timed-out) request against the second request. Bogus! Let's 
fix that.

    $ sudo tc qdisc del dev eth0 root
    $ svn co https://svn.nmap.org/nmap && cd nmap
    $ wget 'http://git.io/cjohnson.nmap.diff&apos; -q -O - | patch -p0
    $ ./configure && make && sudo make install
    $ cd /tmp

7. Okay, now turn the latency back on again and try one more time.

    $ sudo tc qdisc add dev eth0 root netem delay 500ms
    $ sudo nmap 74.125.227.48 -sn -PE -n --privileged --send-ip --min-rtt-timeout 400ms --max-rtt-timeout 400ms 
--max-retries 1 -ddd

    Starting Nmap 6.26SVN ( http://nmap.org ) at 2013-07-22 18:36 UTC
    Fetchfile found /usr/local/bin/../share/nmap/nmap.xsl
    The max # of sockets we are using is: 0
    --------------- Timing report ---------------
      hostgroups: min 1, max 100000
      rtt-timeouts: init 400, min 400, max 400
      max-scan-delay: TCP 1000, UDP 1000, SCTP 1000
      parallelism: min 0, max 0
      max-retries: 1, host-timeout: 0
      min-rate: 0, max-rate: 0
    ---------------------------------------------
    Fetchfile found /usr/local/bin/../share/nmap/nmap-payloads
    Initiating Ping Scan at 18:36
    Scanning 74.125.227.48 [1 port]
    Packet capture filter (device eth0): dst host 10.0.2.15 and (icmp or icmp6 or ((tcp or udp or sctp) and (src host 
74.125.227.48)))
    SENT (0.0197s) ICMP [10.0.2.15 > 74.125.227.48 Echo request (type=8/code=0) id=14074 seq=0] IP [ver=4 ihl=5 
tos=0x00 iplen=28 id=43985 foff=0 ttl=51 proto=1 csum=0xa253]
    **TIMING STATS** (0.0197s): IP, probes active/freshportsleft/retry_stack/outstanding/retranwait/onbench, 
cwnd/ssthresh/delay, timeout/srtt/rttvar/
       Groupstats (1/1 incomplete): 1/*/*/*/*/* 10.00/75/* 400000/-1/-1
    Current sending rates: 55.71 packets / s, 1559.80 bytes / s.
    Overall sending rates: 55.71 packets / s, 1559.80 bytes / s.
    SENT (0.4229s) ICMP [10.0.2.15 > 74.125.227.48 Echo request (type=8/code=0) id=64577 seq=0] IP [ver=4 ihl=5 
tos=0x00 iplen=28 id=65362 foff=0 ttl=53 proto=1 csum=0x4cd2]
    **TIMING STATS** (0.4230s): IP, probes active/freshportsleft/retry_stack/outstanding/retranwait/onbench, 
cwnd/ssthresh/delay, timeout/srtt/rttvar/
       Groupstats (1/1 incomplete): 1/*/*/*/*/* 10.00/75/* 400000/-1/-1
    Current sending rates: 4.75 packets / s, 132.94 bytes / s.
    Overall sending rates: 4.75 packets / s, 132.94 bytes / s.
    RCVD (0.5316s) ICMP [74.125.227.48 > 10.0.2.15 Echo reply (type=0/code=0) id=14074 seq=0] IP [ver=4 ihl=5 tos=0x00 
iplen=28 id=13837 foff=0 ttl=50 proto=1 csum=0x1918]
    Found 74.125.227.48 in incomplete hosts list.
    We got a ping packet back from 74.125.227.48: id = 64054 seq = 0 checksum = 1481
    ultrascan_host_probe_update called for machine 74.125.227.48 state UNKNOWN -> HOST_UP (trynum 0 time: 512042)
    Changing ping technique for 74.125.227.48 to icmp type 8 code 0
    Moving 74.125.227.48 to completed hosts list with 0 outstanding probes.
    Changing global ping host to 74.125.227.48.
    Completed Ping Scan at 18:36, 0.53s elapsed (1 total hosts)
    Overall sending rates: 3.77 packets / s, 105.66 bytes / s.
    pcap stats: 1 packets received by filter, 0 dropped by kernel.
    Nmap scan report for 74.125.227.48
    Host is up, received echo-reply (0.51s latency).
    Final times for host: srtt: 511892 rttvar: 511892  to: 400000
    Read from /usr/local/bin/../share/nmap: nmap-payloads.
    Nmap done: 1 IP address (1 host up) scanned in 0.56 seconds
               Raw packets sent: 2 (56B) | Rcvd: 1 (28B)

8. Yep, 0.53s ping time... that's what we expected! OK, let's get rid of that artificial latency again.

    $ sudo tc qdisc del dev eth0 root


Thanks,
Chris Johnson

Attachment: nmap-cjohnson.diff
Description:

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