[Bro-Dev] [JIRA] (BIT-1056) incorrect values in num_pkts and num_bytes_ip
Jakub Svoboda (JIRA)
jira at bro-tracker.atlassian.net
Wed Aug 14 22:32:21 PDT 2013
Jakub Svoboda created BIT-1056:
----------------------------------
Summary: incorrect values in num_pkts and num_bytes_ip
Key: BIT-1056
URL: https://bro-tracker.atlassian.net/browse/BIT-1056
Project: Bro Issue Tracker
Issue Type: Problem
Components: Bro
Affects Versions: 2.1, git/master
Environment: Two separate testing environments:
1. Intel i3, OpenSuse x64, public IP, Bro is on the computer monitoring its own traffic
2. Intel i3, Ubuntu 12.04 x64 in VirtualBox, host has public IP, virtual machine has private IP, Bro is on virtual machine monitoring its own traffic
Reporter: Jakub Svoboda
Problem: Bro does not see traffic correctly.
* conn.log contains invalid information, with values differing from a network monitoring probe. (The probe runs on a different computer, so there's no interference.)
* Our own scripts logging connections using the connection_state_remove event report the same bad values as conn.log.
* Specifically, all following values are off in the connection_state_remove event handler: c$orig$num_pkts c$resp$num_pkts c$conn$orig_pkts c$conn$resp_pkts c$orig$num_bytes_ip c$resp$num_bytes_ip c$conn$orig_ip_bytes c$conn$resp_ip_bytes. (Yes, we know some of the values are copied one from another in conn/main.bro.)
* Problem is the same on both tested machines.
* Problem is the same both when capturing an interface and when analyzing a pcap.
* Problem is the same on both Bro 2.1 and the current git version (as of 14.08.2013)
The problem is exactly the same on two different computers.
1. i3, OpenSuse, public IP
2. i3, Ubuntu 12.04 x64 in VirtualBox, host has public IP, virtual machine has private IP, Bro is on virtual machine monitoring its own traffic
Both computers use 64bit OS and Bro 2.1 compiled from source.
Notes: The chance of the network monitoring probe reporting bad values is very low as this probe is used by our department of computer science and several people checked it works correctly.
Also, the values reported by Bro are obviously wrong even without no comparison with the probe---e.g. an outgoing flow with 0 outgoing packets, 0 outgoing bytes and nonzero incoming packets/bytes.
Test 1:
Bro log files were read after bro shutdown so that there should be nothing missing.
Bro was installed on a computer with IP 147.251.13.65, monitoring its own traffic. A web browser was used to generate connections. One of the contacted addresses was 77.75.77.170.
Data from conn.log:
id.orig_h id.orig_p id.resp_h id.resp_p proto orig_bytes resp_bytes orig_pkts orig_ip_bytes resp_pkts resp_ip_bytes
147.251.13.65 44690 77.75.77.170 993 tcp 0 151 0 0 3 307
(this was the only line with 147.251.13.65 and 77.75.77.170)
Data from the network monitoring probe:
nfdump filter:
ip 147.251.13.65 and ip 77.75.77.170
Date first seen Duration Proto Src IP Addr:Port Dst IP Addr:Port Flags Tos Packets Bytes pps bps Bpp Flows
2013-08-14 09:54:30.355 0.054 TCP 77.75.77.170:993 -> 147.251.13.65:44690 .AP... 0 3 307 55 45481 102 1
2013-08-14 09:54:30.347 0.062 TCP 147.251.13.65:44690 -> 77.75.77.170:993 .AP... 0 5 348 80 44903 69 1
Summary: total flows: 2, total bytes: 655, total packets: 8, avg bps: 84516, avg pps: 129, avg bpp: 81
Time window: 2013-08-14 09:48:47 - 2013-08-14 10:00:00
Total flows processed: 881266, Blocks skipped: 0, Bytes read: 77680460
Sys: 0.153s flows/second: 5723435.6 Wall: 0.152s flows/second: 5795248.1
Test 2:
Bro log files were read after bro shutdown so that there should be nothing missing.
Bro was installed on a computer with IP 147.251.13.65, monitoring its own traffic. A web browser was used to generate connections. One of the contacted addresses was 195.113.232.73.
Debug output of our own Bro script watching connections using connection_state_remove event handler.
The script's code for the event handler is:
event connection_state_remove(c: connection) {
NOTICE([$note=profile_creation::Test3, $msg=cat("DBG: ", c$id$orig_h, "->", c$id$resp_h, " c$orig$num_pkts=", c$orig$num_pkts, " c$resp$num_pkts=", c$resp$num_pkts, " c$conn$orig_pkts=", c$conn$orig_pkts, " c$conn$resp_pkts=", c$conn$resp_pkts, " c$orig$num_bytes_ip=", c$orig$num_bytes_ip, " c$resp$num_bytes_ip=", c$resp$num_bytes_ip, " c$conn$orig_ip_bytes=", c$conn$orig_ip_bytes, " c$conn$resp_ip_bytes=", c$conn$resp_ip_bytes, " c$id$orig_p=", c$id$orig_p, " c$id$resp_p=", c$id$resp_p )]);
}
The cut out output:
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=0 c$conn$orig_pkts=0 c$conn$resp_pkts=0 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=0 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=0 c$id$orig_p=49631/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=0 c$conn$orig_pkts=0 c$conn$resp_pkts=0 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=0 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=0 c$id$orig_p=49721/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=0 c$conn$orig_pkts=0 c$conn$resp_pkts=0 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=0 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=0 c$id$orig_p=49723/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=0 c$conn$orig_pkts=0 c$conn$resp_pkts=0 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=0 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=0 c$id$orig_p=49724/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=0 c$conn$orig_pkts=0 c$conn$resp_pkts=0 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=0 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=0 c$id$orig_p=49725/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=17 c$conn$orig_pkts=0 c$conn$resp_pkts=17 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=21613 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=21613 c$id$orig_p=49725/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=5 c$conn$orig_pkts=0 c$conn$resp_pkts=5 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=5032 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=5032 c$id$orig_p=49721/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=5 c$conn$orig_pkts=0 c$conn$resp_pkts=5 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=5056 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=5056 c$id$orig_p=49723/tcp c$id$resp_p=80/tcp
DBG: 147.251.13.65->195.113.232.73 c$orig$num_pkts=0 c$resp$num_pkts=4 c$conn$orig_pkts=0 c$conn$resp_pkts=4 c$orig$num_bytes_ip=0 c$resp$num_bytes_ip=4110 c$conn$orig_ip_bytes=0 c$conn$resp_ip_bytes=4110 c$id$orig_p=49724/tcp c$id$resp_p=80/tcp
All relevant data from conn.log:
id.orig_h id.orig_p id.resp_h id.resp_p proto orig_bytes resp_bytes orig_pkts orig_ip_bytes resp_pkts resp_ip_bytes
147.251.13.65 49631 195.113.232.73 80 tcp - - 0 0 0 0
147.251.13.65 49721 195.113.232.73 80 tcp - - 0 0 0 0
147.251.13.65 49723 195.113.232.73 80 tcp - - 0 0 0 0
147.251.13.65 49724 195.113.232.73 80 tcp - - 0 0 0 0
147.251.13.65 49725 195.113.232.73 80 tcp - - 0 0 0 0
147.251.13.65 49725 195.113.232.73 80 tcp 0 20729 0 0 17 21613
147.251.13.65 49721 195.113.232.73 80 tcp 0 4772 0 0 5 5032
147.251.13.65 49723 195.113.232.73 80 tcp 0 4796 0 0 5 5056
147.251.13.65 49724 195.113.232.73 80 tcp 0 3902 0 0 4 4110
Data from the network monitoring probe:
** nfdump -M /data/nfsen/profiles-data/live/p3006:p3005:p3004:p3002:p3003:p3001:p3000 -T -r 2013/08/14/nfcapd.201308140955 -o extended -c 500
nfdump filter:
ip 147.251.13.65 and ip 195.113.232.73
Date first seen Duration Proto Src IP Addr:Port Dst IP Addr:Port Flags Tos Packets Bytes pps bps Bpp Flows
2013-08-14 09:54:33.929 28.188 TCP 195.113.232.73:80 -> 147.251.13.65:49725 .AP..F 0 15 19873 0 5640 1324 1
2013-08-14 09:54:17.976 44.141 TCP 195.113.232.73:80 -> 147.251.13.65:49631 .AP.SF 0 6 3709 0 672 618 1
2013-08-14 09:54:33.958 28.159 TCP 195.113.232.73:80 -> 147.251.13.65:49723 .AP..F 0 5 5056 0 1436 1011 1
2013-08-14 09:54:33.948 28.169 TCP 195.113.232.73:80 -> 147.251.13.65:49721 .AP..F 0 5 5032 0 1429 1006 1
2013-08-14 09:54:33.950 28.167 TCP 195.113.232.73:80 -> 147.251.13.65:49724 .AP..F 0 4 4110 0 1167 1027 1
2013-08-14 09:54:33.777 28.340 TCP 147.251.13.65:49725 -> 195.113.232.73:80 .AP..F 0 13 1732 0 488 133 1
2013-08-14 09:54:33.777 28.340 TCP 147.251.13.65:49724 -> 195.113.232.73:80 .AP..F 0 6 1356 0 382 226 1
2013-08-14 09:54:17.972 44.145 TCP 147.251.13.65:49631 -> 195.113.232.73:80 .AP.SF 0 8 746 0 135 93 1
2013-08-14 09:54:33.777 28.340 TCP 147.251.13.65:49723 -> 195.113.232.73:80 .AP..F 0 7 1408 0 397 201 1
2013-08-14 09:54:33.777 28.340 TCP 147.251.13.65:49721 -> 195.113.232.73:80 .AP..F 0 5 1304 0 368 260 1
Summary: total flows: 10, total bytes: 44326, total packets: 74, avg bps: 8032, avg pps: 1, avg bpp: 599
Time window: 2013-08-14 09:48:47 - 2013-08-14 10:00:00
Total flows processed: 881266, Blocks skipped: 0, Bytes read: 77680460
Sys: 0.153s flows/second: 5723435.6 Wall: 0.152s flows/second: 5782205.9
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://bro-tracker.atlassian.net/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the bro-dev
mailing list