[Bro] HTTP not being seen
James Lay
jlay at slave-tothe-box.net
Fri Sep 13 16:51:26 PDT 2013
WELLL this is gonna hurt my head. So…here's my setup:
DSL modem (dummy mode) < -- > eth1/ppp0(Linuxbox)eth0 < -- > switch with everything else
ext IP int IP
For giggles I decided to see if there was any difference with requests originating from the linuxbox, compared to originating behind it. I tsharked at ppp0, here's what I have
Curl from a Mac
2013-09-13 17:30:53.720063 x.x.x.x -> 23.63.227.171 TCP 80 51579 > 80 [SYN] Seq=0 Win=65535 Len=0 MSS=1452 WS=16 TSval=962401899 TSecr=0 SACK_PERM=1
2013-09-13 17:30:53.781038 23.63.227.171 -> x.x.x.x TCP 76 80 > 51579 [SYN, ACK] Seq=0 Ack=1 Win=14480 Len=0 MSS=1460 SACK_PERM=1 TSval=923336834 TSecr=962401899 WS=2
2013-09-13 17:30:53.781706 x.x.x.x -> 23.63.227.171 TCP 68 51579 > 80 [ACK] Seq=1 Ack=1 Win=131760 Len=0 TSval=962401960 TSecr=923336834
2013-09-13 17:30:53.781917 x.x.x.x -> 23.63.227.171 HTTP 214 GET / HTTP/1.1
2013-09-13 17:30:53.844280 23.63.227.171 -> x.x.x.x TCP 68 80 > 51579 [ACK] Seq=1 Ack=147 Win=15552 Len=0 TSval=923336896 TSecr=962401960
2013-09-13 17:30:54.058292 23.63.227.171 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:54.059011 23.63.227.171 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:54.059543 x.x.x.x -> 23.63.227.171 TCP 68 51579 > 80 [ACK] Seq=147 Ack=2881 Win=129632 Len=0 TSval=962402235 TSecr=923337110
2013-09-13 17:30:54.059571 23.63.227.171 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:54.060385 23.63.227.171 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:54.060387 23.63.227.171 -> x.x.x.x HTTP 97 HTTP/1.1 200 OK (text/html)
2013-09-13 17:30:54.060889 x.x.x.x -> 23.63.227.171 TCP 68 51579 > 80 [ACK] Seq=147 Ack=5761 Win=129632 Len=0 TSval=962402236 TSecr=923337110
2013-09-13 17:30:54.060923 x.x.x.x -> 23.63.227.171 TCP 68 51579 > 80 [ACK] Seq=147 Ack=5790 Win=131040 Len=0 TSval=962402236 TSecr=923337110
2013-09-13 17:30:54.136000 x.x.x.x -> 23.63.227.171 TCP 68 51579 > 80 [FIN, ACK] Seq=147 Ack=5790 Win=131072 Len=0 TSval=962402311 TSecr=923337110
2013-09-13 17:30:54.196402 23.614 2013-09-13 17:30:54.196402 23.614 2013-09-13 17:30:54.196402 23.614 2013-09-13 17:30:54.19=923337249 TSecr=962402311
2013-09-13 17:30:54.197075 x.x.x.x -> 23.63.227.171 TCP 68 51579 > 80 [ACK] Seq=148 Ack=5791 Win=131072 Len=0 TSval=962402371 TSecr=923337249
Wget from the linuxbox
2013-09-13 17:30:56.769223 x.x.x.x -> 207.108.220.146 TCP 76 46641 > 80 [SYN] Seq=0 Win=14520 Len=0 MSS=1452 SACK_PERM=1 TSval=150537829 TSecr=0 WS=16
2013-09-13 17:30:56.800179 207.108.220.146 -> x.x.x.x TCP 76 80 > 46641 [SYN, ACK] Seq=0 Ack=1 Win=14480 Len=0 MSS=1460 SACK_PERM=1 TSval=811267839 TSecr=150537829 WS=2
2013-09-13 17:30:56.800271 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [ACK] Seq=1 Ack=1 Win=14528 Len=0 TSval=150537837 TSecr=811267839
2013-09-13 17:30:56.800559 x.x.x.x -> 207.108.220.146 HTTP 183 GET / HTTP/1.1
2013-09-13 17:30:56.833172 207.108.220.146 -> x.x.x.x TCP 68 80 > 46641 [ACK] Seq=1 Ack=116 Win=14480 Len=0 TSval=811267872 TSecr=150537837
2013-09-13 17:30:56.898798 207.108.220.146 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:56.898890 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [ACK] Seq=116 Ack=1441 Win=17408 Len=0 TSval=150537862 TSecr=811267937
2013-09-13 17:30:56.899540 207.108.220.146 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:56.899597 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [ACK] Seq=116 Ack=2881 Win=20288 Len=0 TSval=150537862 TSecr=811267937
2013-09-13 17:30:56.900295 207.108.220.146 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:56.900355 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [ACK] Seq=116 Ack=4321 Win=23168 Len=0 TSval=150537862 TSecr=811267937
2013-09-13 17:30:56.901041 207.108.220.146 -> x.x.x.x TCP 1508 [TCP segment of a reassembled PDU]
2013-09-13 17:30:56.901097 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [ACK] Seq=116 Ack=5761 Win=26048 Len=0 TSval=150537862 TSecr=811267937
2013-09-13 17:30:56.901043 207.108.220.146 -> x.x.x.x HTTP 97 HTTP/1.1 200 OK (text/html)
2013-09-13 17:30:56.901141 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [ACK] Seq=116 Ack=5790 Win=26048 Len=0 TSval=150537862 TSecr=811267937
2013-09-13 17:30:56.901950 x.x.x.x -> 207.108.220.146 TCP 68 46641 > 80 [FIN, ACK] Seq=116 Ack=5790 Win=26048 Len=0 TSval=150537863 TSecr=811267937
2013-09-13 17:30:56.933443 207.108.220.146 -> x.x.x.x TCP 68 80 > 46641 [FIN, ACK] Seq=5790 Ack=117 Win=14480 Len=0 TSva2013-09-13 17:30:56.933443 207.108.220.146 -> 71.39.117.84 TCP 68 80 > 46641 [FIN, ACK] Seq=5790 Ac > 80 [ACK] Seq=117 Ack=5791 Win=26048 Len=0 TSval=150537871 TSecr=811267973
Mac
2013-09-13T17:30:53-0600 BnQTbzFqpae x.x.x.x 51579 23.63.227.171 80 tcp http 0.476339 146 5789 SF - 0 ShADadFf 8 574 8 6213 (empty)
2013-09-13T17:30:53-0600 BnQTbzFqpae x.x.x.x 51579 23.63.227.171 80 1 GET www.spamcop.net / - curl/7.24.0 (x86_64-apple-darwin12.0) libcurl/7.24.0 OpenSSL/0.9.8y zlib/1.2.5 0 5455 200 OK - - - (empty) - - - text/html - -
Linuxbox
2013-09-13T17:30:56-0600 aDSEGHvanZ1 x.x.x.x 46641 207.108.220.146 80 tcp - - - - OTH - 0 C 0 0 0 0 (empty)
2013-09-13T17:30:56-0600 aDSEGHvanZ1 x.x.x.x 46641 207.108.220.146 80 active_connection_reuse - F bro
When coming from the linuxbox, I get active_connection_reuse and no http logged. When routing(natting) internal traffic, it logs http and no active_connection_reuse. A puzzle to be sure.
James
On Sep 13, 2013, at 3:41 PM, "Schoenefeld, Keith P." <Keith_Schoenefeld at baylor.edu> wrote:
> I'd point out that the conn.log file lines included in his email indicate that the received and sent bytes are 0, and the connection state is borked -- I believe this would prevent it from being detected as http traffic, and therefore not create an http.log file.
>
> -- KS
>
> -----Original Message-----
> From: bro-bounces at bro.org [mailto:bro-bounces at bro.org] On Behalf Of James Lay
> Sent: Friday, September 13, 2013 4:37 PM
> To: Keith Butler
> Cc: <bro at bro.org>
> Subject: Re: [Bro] HTTP not being seen
>
> Hi Keith,
>
> Just ran that http.pcap...looked great in my http.log:
>
> #fields ts uid id.orig_h id.orig_p id.resp_h id.resp_p trans_depth method host uri referrer user_agent request_body_len response_body_len status_code status_msg info_code info_msg filename tags username password proxied mime_type md5 extraction_file
> #types time string addr port addr port count string string string string string count count count string count string string table[enum] string string table[string] string string file
> 1320279566.452687 JIDwiHjbv85 192.168.2.76 52026 132.235.215.119 80 1 GET www.reddit.com / - Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:7.0.1) Gecko/20100101 Firefox/7.0.1 0 109978 200 OK - - - (empty) - - - text/html - -
> 1320279566.831619 VKdyryoPlil 192.168.2.76 52030 72.21.211.173 80 1 GET e.thumbs.redditmedia.com /E-pbDbmiBclPkDaX.jpg http://www.reddit.com/ Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:7.0.1) Gecko/20100101 Firefox/7.0.1 0 2300 200 OK - - - (empty) - - - image/jpeg - -
>
> Thank you.
>
> James
>
> On Sep 13, 2013, at 15:27, Keith Butler <kebutler at gmail.com> wrote:
>
>> In line with Doug's suggestion, can you try a known good source of traffic? For example a packet trace from Bro Workshop:
>> The first exercise on the following page has an http.pcap file:
>> http://www.bro.org/bro-workshop-2011/exercises/logs/index.html
>>
>> Here is the direct link:
>> http://www.bro.org/bro-workshop-2011/exercises/logs/http.pcap
>>
>> Try running:
>> $ /path/to/your/bro -r http.pcap
>>
>> and see what happens?
>>
>> -kb
>>
>>
>> On Sep 13, 2013, at 3:50 PM, James Lay <jlay at slave-tothe-box.net> wrote:
>>
>>> On 2013-09-13 13:31, Liam Randall wrote:
>>>> Lets enable your capture loss and see what happens:
>>>>
>>>> Add the following to your local.bro; on security onion it will be
>>>> located at /opt/bro/share/bro/site/
>>>>
>>>> # count the ACKs, tell me the # and % I am missing @load
>>>> misc/capture-loss.bro
>>>>
>>>> # By default capture-loss reports every 15 minutes, lets turn it up
>>>> redef CaptureLoss::watch_interval = 1 min;
>>>>
>>>> Give it a couple of minutes and see what the log says under:
>>>>
>>>> /nsm/bro/logs/capture_loss.log
>>>>
>>>> You will see per worker statistics written every minute.
>>>>
>>>> Let us know.
>>>>
>>>> Thanks,
>>>>
>>>> Liam Randall
>>>
>>>
>>> Thanks Liam...here's what I got:
>>> #fields ts ts_delta peer gaps acks percent_lost
>>> #types time interval string count count string
>>> 2013-09-13T13:34:59-0600 60.000084 bro 0 16
>>> 0.000%
>>> 2013-09-13T13:35:59-0600 60.000044 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:36:59-0600 60.000048 bro 0 14
>>> 0.000%
>>> 2013-09-13T13:37:59-0600 60.000048 bro 1 1
>>> 100.000%
>>> 2013-09-13T13:38:59-0600 60.000038 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:39:59-0600 60.000050 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:40:59-0600 60.000093 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:41:59-0600 60.000023 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:42:59-0600 60.000022 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:43:59-0600 60.000023 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:44:59-0600 60.000089 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:45:59-0600 60.000073 bro 0 0
>>> 0.000%
>>> 2013-09-13T13:46:59-0600 60.000011 bro 0 0
>>> 0.000%
>>>
>>> Bro entries:
>>> 2013-09-13T13:45:33-0600 dPCMEyJBiU7 x.x.x.x 47285
>>> 50.18.192.250 80 tcp - - - - OTH
>>> - 0 C 0 0 0 0 (empty)
>>> 2013-09-13T13:45:33-0600 PFUbImVSSZ2 x.x.x.x 35306
>>> 205.171.2.25 53 udp 63725 www.duckduckgo.com 1
>>> C_INTERNET 1 A 0 NOERROR F F T
>>> T 0 duckduckgo.com,50.18.192.250,50.18.192.251
>>> 900.000000,25.000000,25.000000
>>> 2013-09-13T13:45:34-0600 8ZduhgTSjm6 x.x.x.x 37025
>>> 205.171.2.25 53 udp 35309 duckduckgo.com 1
>>> C_INTERNET 1 A 0 NOERROR F F T
>>> T 0 50.18.192.251,50.18.192.250 24.000000,24.000000
>>> 2013-09-13T13:45:34-0600 dPCMEyJBiU7 x.x.x.x 47285
>>> 50.18.192.250 80 active_connection_reuse - F bro
>>>
>>>
>>> Wget info:
>>> [13:45:20 gateway:~$] wget www.duckduckgo.com
>>> --2013-09-13 13:45:33-- http://www.duckduckgo.com/ Resolving
>>> www.duckduckgo.com (www.duckduckgo.com)... 50.18.192.250,
>>> 50.18.192.251
>>> Connecting to www.duckduckgo.com
>>> (www.duckduckgo.com)|50.18.192.250|:80... connected.
>>> HTTP request sent, awaiting response... 301 Moved Permanently
>>> Location: https://duckduckgo.com/ [following]
>>> --2013-09-13 13:45:34-- https://duckduckgo.com/ Resolving
>>> duckduckgo.com (duckduckgo.com)... 50.18.192.251,
>>> 50.18.192.250
>>> Connecting to duckduckgo.com (duckduckgo.com)|50.18.192.251|:443...
>>> connected.
>>> HTTP request sent, awaiting response... 200 OK
>>> Length: 8646 (8.4K) [text/html]
>>> Saving to: `index.html'
>>>
>>> 100%[=========================>] 8,646 --.-K/s in 0s
>>>
>>> 2013-09-13 13:45:34 (86.8 MB/s) - `index.html' saved [8646/8646]
>>>
>>>
>>> Tshark info:
>>> 2013-09-13 13:45:33.991079 x.x.x.x -> 50.18.192.250 TCP 76 47285 > 80
>>> [SYN] Seq=0 Win=14520 Len=0 MSS=1452 SACK_PERM=1 TSval=147157135
>>> TSecr=0
>>> WS=16
>>> 2013-09-13 13:45:34.035256 50.18.192.250 -> x.x.x.x TCP 76 80 > 47285
>>> [SYN, ACK] Seq=0 Ack=1 Win=7240 Len=0 MSS=1460 SACK_PERM=1
>>> TSval=23107600 TSecr=147157135 WS=1
>>> 2013-09-13 13:45:34.035375 x.x.x.x -> 50.18.192.250 TCP 68 47285 > 80
>>> [ACK] Seq=1 Ack=1 Win=14528 Len=0 TSval=147157146 TSecr=23107600
>>> 2013-09-13 13:45:34.035595 x.x.x.x -> 50.18.192.250 HTTP 186 GET /
>>> HTTP/1.1
>>> 2013-09-13 13:45:34.082121 50.18.192.250 -> x.x.x.x TCP 68 80 > 47285
>>> [ACK] Seq=1 Ack=119 Win=7122 Len=0 TSval=23107612 TSecr=147157146
>>> 2013-09-13 13:45:34.082132 50.18.192.250 -> x.x.x.x HTTP 503 HTTP/1.1
>>> 301 Moved Permanently (text/html)
>>> 2013-09-13 13:45:34.082241 x.x.x.x -> 50.18.192.250 TCP 68 47285 > 80
>>> [ACK] Seq=119 Ack=436 Win=15600 Len=0 TSval=147157158 TSecr=23107612
>>> 2013-09-13 13:45:34.446981 x.x.x.x -> 50.18.192.250 TCP 68 47285 > 80
>>> [FIN, ACK] Seq=119 Ack=436 Win=15600 Len=0 TSval=147157249
>>> TSecr=23107612
>>> 2013-09-13 13:45:34.492112 50.18.192.250 -> x.x.x.x TCP 68 80 > 47285
>>> [FIN, ACK] Seq=436 Ack=120 Win=7121 Len=0 TSval=23107714
>>> TSecr=147157249
>>> 2013-09-13 13:45:34.492164 x.x.x.x -> 50.18.192.250 TCP 68 47285 > 80
>>> [ACK] Seq=120 Ack=437 Win=15600 Len=0 TSval=147157260 TSecr=23107714
>>>
>>> Not sure what to think...it's very strange. Thanks again.
>>>
>>> James
>>>
>>> _______________________________________________
>>> Bro mailing list
>>> bro at bro-ids.org
>>> http://mailman.ICSI.Berkeley.EDU/mailman/listinfo/bro
>
>
> _______________________________________________
> Bro mailing list
> bro at bro-ids.org
> http://mailman.ICSI.Berkeley.EDU/mailman/listinfo/bro
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 496 bytes
Desc: Message signed with OpenPGP using GPGMail
Url : http://mailman.ICSI.Berkeley.EDU/pipermail/bro/attachments/20130913/c3eaf445/attachment.bin
More information about the Bro
mailing list