search

node-pcap / node_pcap

libpcap bindings for node
MIT License
930 stars 254 forks source link

The pcap session doesn't emit UDP packet event until it receives the next package! #103

Open cuckoohello opened 10 years ago

cuckoohello commented 10 years ago

Test Source Code

var pcap = require('pcap'), util = require('util'), EventEmitter = require('events').EventEmitter;

var pcap_session = pcap.createSession('eth0', 'port 53');
pcap_session.on('packet', function (raw_packet) {
    var date = new Date();
    console.log('Time: '+date.toString());
    var packet = pcap.decode.packet(raw_packet);
    if (packet.link.ip.protocol_name === 'UDP'){
        if (packet.link.ip.udp.dns){
            var dns = packet.link.ip.udp.dns;
            console.log('Question: '+util.inspect(dns.question)+'\n Answer: '+util.inspect(dns.answer));
        }
    }
});

DNS Lookup

cuckoo@vm0:~$ date && nslookup twitter.com
Wed Jun 18 10:08:20 CST 2014
Server:         202.112.0.23
Address:        202.112.0.23#53

Non-authoritative answer:
Name:   twitter.com
Address: 37.61.54.158

cuckoo@vm0:~$ date && nslookup facebook.com
Wed Jun 18 10:08:40 CST 2014
Server:         202.112.0.23
Address:        202.112.0.23#53

Non-authoritative answer:
Name:   facebook.com
Address: 37.61.54.158

Pcap Output

root@vm0:/home/cuckoo/Project/dns# nodejs dns.js
Time: Wed Jun 18 2014 10:08:40 GMT+0800 (CST)
Question: [ { qname: 'twitter.com', qtype: 'A', qclass: 'IN' } ]
 Answer: []
Time: Wed Jun 18 2014 10:08:40 GMT+0800 (CST)
Question: [ { qname: 'twitter.com', qtype: 'A', qclass: 'IN' } ]
 Answer: [ { name: 'twitter.com',
    rrtype: 'A',
    rrclass: 'IN',
    ttl: 270,
    rdlength: 4,
    data: { ipAddress: '37.61.54.158' } } ]

_The pcap session doesn't emit UDP packet event until it receives the next package! _

egorse commented 9 years ago

+1

The parallel tcpdump indicates the packet already received, but not yet by pcap based app

mranney commented 9 years ago

This example generates the expected output for me on both OSX and Linux, so I think this bug got fixed and some point.

This is probably both the same problem and solution as #110

cuckoohello commented 9 years ago

Still have this bug tested using Debian Jessie, Nodejs 0.10.29 and the pcap package from npm install and github repo.

Could you tell me which environment did you test, thanks.

Besides there is another error reported

/home/cp/tmp/node_modules/pcap/pcap.js:1009
            throw new Error("Malformed DNS RR. Offset is larger than the size
                  ^
Error: Malformed DNS RR. Offset is larger than the size of the packet (decodeRR). offset: 42, internal_offset: 35403, packet length: 504
    at Object.dns_util.decodeRR (/home/cp/tmp/node_modules/pcap/pcap.js:1009:19)
    at Object.dns_util.decodeRRs (/home/cp/tmp/node_modules/pcap/pcap.js:1046:40)
    at Object.decode.dns (/home/cp/tmp/node_modules/pcap/pcap.js:1104:32)
    at Object.decode.udp (/home/cp/tmp/node_modules/pcap/pcap.js:784:26)
    at Object.decode.ip (/home/cp/tmp/node_modules/pcap/pcap.js:523:26)
    at Object.decode.ethernet (/home/cp/tmp/node_modules/pcap/pcap.js:292:29)
    at Object.decode.packet (/home/cp/tmp/node_modules/pcap/pcap.js:211:30)
    at Pcap.<anonymous> (/home/cp/tmp/test.js:7:30)
    at Pcap.emit (events.js:95:17)
    at packet_ready (/home/cp/tmp/node_modules/pcap/pcap.js:42:12)
mranney commented 9 years ago

Hmm, I don't see this on my OSX or Linux machines. Can you give me more info on your environment? Linux distro + version and node version?

cuckoohello commented 9 years ago
mranney commented 9 years ago

Sorry for overlooking your version info in the previous message.

This is very strange. I have similar node and Linux versions, and I do not see this behavior. I wonder if there's something different about how those DNS names resolve for you. I tried to use the same recursive DNS server you used in your example, but it doesn't give me any results. Maybe this is some kind of GFW issue?

If you want to dig into this further, you could save a pcap from tcpdump, and then send over somehow. Maybe there's something about the DNS parser that's getting confused on certain kinds of responses that causes this. Since I can't see these responses myself, it's really hard to fix the bug.

egorse commented 9 years ago

That is not DNS related. I have same behaviour with ICMP and any others. You just have to run on interface with almost no traffic.

See pcap_header.tv_sec vs Date.

The app:

var pcap = require('pcap');

var pcap_session = pcap.createSession('eth0', 'icmp');
pcap_session.on('packet', function (raw_packet) {
    var date = new Date(),
        packet = pcap.decode.packet(raw_packet);
    console.log('Time: %s', date.getTime() / 1000, packet);
});

then:

#sudo node test.js &
#sudo tcpdump -i eth0 &
#ping 10.200.0.81 -i 10 -D

output:

PING 10.200.0.81 (10.200.0.81) 56(84) bytes of data.
[1420699200.447624] 64 bytes from 10.200.0.81: icmp_seq=1 ttl=64 time=0.374 ms
08:40:00.447139 IP TC14217 > 10.200.0.81: ICMP echo request, id 15537, seq 1, length 64
08:40:00.447459 IP 10.200.0.81 > TC14217: ICMP echo reply, id 15537, seq 1, length 64
08:40:05.457711 ARP, Request who-has TC14217 tell 10.200.0.81, length 42
08:40:05.457741 ARP, Reply TC14217 is-at 0c:4d:e9:af:88:58 (oui Unknown), length 28
[1420699210.446637] 64 bytes from 10.200.0.81: icmp_seq=2 ttl=64 time=0.342 ms
Time: 1420699210.447 { link_type: 'LINKTYPE_ETHERNET',
  link: 
   { dhost: '00:90:50:e1:69:06',
     shost: '0c:4d:e9:af:88:58',
     ethertype: 2048,
     vlan: { priority: 0, canonical_format: 0, id: 200 },
     ip: 
      { version: 4,
        header_length: 5,
        header_bytes: 20,
        diffserv: 0,
        total_length: 84,
        identification: 3222,
        flags: [Object],
        fragment_offset: 0,
        ttl: 64,
        protocol: 1,
        header_checksum: 6193,
        saddr: '10.200.0.2',
        daddr: '10.200.0.81',
        protocol_name: 'ICMP',
        icmp: [Object] } },
  pcap_header: 
   { tv_sec: 1420699200,
     tv_usec: 447139,
     caplen: 102,
     len: 102,
     link_type: 'LINKTYPE_ETHERNET',
     time_ms: 1420699200447.139 } }
Time: 1420699210.458 { link_type: 'LINKTYPE_ETHERNET',
  link: 
   { dhost: '0c:4d:e9:af:88:58',
     shost: '00:90:50:e1:69:06',
     ethertype: 2048,
     vlan: { priority: 0, canonical_format: 0, id: 200 },
     ip: 
      { version: 4,
        header_length: 5,
        header_bytes: 20,
        diffserv: 0,
        total_length: 84,
        identification: 43424,
        flags: [Object],
        fragment_offset: 0,
        ttl: 64,
        protocol: 1,
        header_checksum: 47910,
        saddr: '10.200.0.81',
        daddr: '10.200.0.2',
        protocol_name: 'ICMP',
        icmp: [Object] } },
  pcap_header: 
   { tv_sec: 1420699200,
     tv_usec: 447459,
     caplen: 102,
     len: 102,
     link_type: 'LINKTYPE_ETHERNET',
     time_ms: 1420699200447.459 } }
08:40:10.446129 IP TC14217 > 10.200.0.81: ICMP echo request, id 15537, seq 2, length 64
08:40:10.446426 IP 10.200.0.81 > TC14217: ICMP echo reply, id 15537, seq 2, length 64
cuckoohello commented 9 years ago

I have just created a testing environment in a docker container. And send you an account to your email mjr@ranney.com.

Thanks

mranney commented 9 years ago

@cuckoohello I didn't get any email from you yet, sorry. I'm on gmail, so maybe that's in our way.

@egorse I can't reproduce those results, but I want to figure out what's causing this. I know on some OSX systems, there was a similar issue what we worked around by setting BIOCIMMEDIATE on the pcap fd. Maybe there's something similar we need to set on some Linux systems?

If you (or anyone reading this) are willing to dig into this some more, it would be very helpful to add some print lines in a few places in the code:

Also, when running a test like this, please make sure to use the same filter and interface for tcpdump that you use for node_pcap. In your example above, it would be tcpdump -i eth0 icmp. I doubt that this will change the behavior, but you might as well eliminate that variable.

egorse commented 9 years ago

I would guess that is actually not your issue - this seems to be https://github.com/the-tcpdump-group/libpcap/issues/380. I tried to force dispatch by setInterval and it helped, but some packets were lost as the issue in libpcap defines. Actually, there are many complains about "turbo packets"

2015-01-12 21:38 GMT+02:00 Matt Ranney notifications@github.com:

@cuckoohello https://github.com/cuckoohello I didn't get any email from you yet, sorry. I'm on gmail, so maybe that's in our way.

@egorse https://github.com/egorse I can't reproduce those results, but I want to figure out what's causing this. I know on some OSX systems, there was a similar issue what we worked around by setting BIOCIMMEDIATE on the pcap fd. Maybe there's something similar we need to set on some Linux systems?

If you (or anyone reading this) are willing to dig into this some more, it would be very helpful to add some print lines in a few places in the code:

  • SocketWatcher callback: pcap_read_callback in pcap.js
  • PcapSession::Dispatch in pcap_session.cc
  • PcapSession::PacketReady in pcap_session.cc

Also, when running a test like this, please make sure to use the same filter and interface for tcpdump that you use for node_pcap. In your example above, it would be tcpdump -i eth0 icmp. I doubt that this will change the behavior, but you might as well eliminate that variable.

— Reply to this email directly or view it on GitHub https://github.com/mranney/node_pcap/issues/103#issuecomment-69631236.

skepticfx commented 9 years ago

@egorse :+1: Nice catch there!

mranney commented 9 years ago

This tpacket3 stuff does sound promising.

Can you try adding this line to pcap_session.cc, right before the call to pcap_activate():

pcap_set_immediate(session->pcap_handle, 1);

My systems do not have a new enough pcap that exposes this. If you can confirm that this fixes the issue, I'll figure out how to #define around it.

egorse commented 9 years ago

Adding

pcap_set_immediate_mode(session->pcap_handle, 1);

did help this issue to get fixed.

Should it be somehow managed by option passed to createSession?

cuckoohello commented 9 years ago

+1

Adding

 pcap_set_immediate_mode(session->pcap_handle, 1);

did help this issue to get fixed.

mranney commented 9 years ago

Wonderful, thanks for testing that out.

I'm working on a big refactor for a major performance win. As soon as that's done, I'll get the fix in for this. I think it should be set by default with a way to disable if you are doing higher volume traffic.