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

cuckoohello · 2014-06-18T02:15:09Z

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! *

The text was updated successfully, but these errors were encountered:

egorse · 2014-12-17T09:34:26Z

+1

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

mranney · 2015-01-07T23:15:22Z

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 · 2015-01-08T00:24:19Z

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 · 2015-01-08T04:50:42Z

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 · 2015-01-08T05:18:44Z

Kernel: 3.16.0-4-amd64
Distribution: Debian Jessie
NodeJS: 0.10.29~dfsg-1.1

mranney · 2015-01-08T05:44:57Z

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 · 2015-01-08T06:44:16Z

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 · 2015-01-08T06:52:08Z

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

Thanks

mranney · 2015-01-12T19:38:08Z

@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:

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.

egorse · 2015-01-12T20:03:14Z

I would guess that is actually not your issue - this seems to be
the-tcpdump-group/libpcap#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
#103 (comment).

skepticfx · 2015-01-12T22:44:55Z

@egorse 👍 Nice catch there!

mranney · 2015-01-13T00:39:42Z

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 · 2015-01-13T06:42:05Z

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 · 2015-01-13T07:59:47Z

+1

Adding

 pcap_set_immediate_mode(session->pcap_handle, 1);

did help this issue to get fixed.

mranney · 2015-01-13T08:37:04Z

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.

mranney closed this as completed Jan 7, 2015

mranney reopened this Jan 8, 2015

mranney closed this as completed Jan 8, 2015

mranney reopened this Jan 8, 2015

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

cuckoohello commented Jun 18, 2014

egorse commented Dec 17, 2014

mranney commented Jan 7, 2015

cuckoohello commented Jan 8, 2015

mranney commented Jan 8, 2015

cuckoohello commented Jan 8, 2015

mranney commented Jan 8, 2015

egorse commented Jan 8, 2015

cuckoohello commented Jan 8, 2015

mranney commented Jan 12, 2015

egorse commented Jan 12, 2015

skepticfx commented Jan 12, 2015

mranney commented Jan 13, 2015

egorse commented Jan 13, 2015

cuckoohello commented Jan 13, 2015

mranney commented Jan 13, 2015

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

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

Comments

cuckoohello commented Jun 18, 2014

Test Source Code

DNS Lookup

Pcap Output

egorse commented Dec 17, 2014

mranney commented Jan 7, 2015

cuckoohello commented Jan 8, 2015

mranney commented Jan 8, 2015

cuckoohello commented Jan 8, 2015

mranney commented Jan 8, 2015

egorse commented Jan 8, 2015

cuckoohello commented Jan 8, 2015

mranney commented Jan 12, 2015

egorse commented Jan 12, 2015

skepticfx commented Jan 12, 2015

mranney commented Jan 13, 2015

egorse commented Jan 13, 2015

cuckoohello commented Jan 13, 2015

mranney commented Jan 13, 2015