[Bro] Bro behind a TLS reverse proxy

Brandon Sterne brandon.sterne at gmail.com
Mon Apr 9 21:21:35 PDT 2018


I can confirm this also happens on a C7 OpenStack VM:
[brandon.sterne at sterne-server ~]$ tshark -t ud -r pcaps/lo-port-80.pcap
  1 2018-04-10 03:35:40    127.0.0.1 -> 127.0.0.1    TCP 74 51546 > http
[SYN] Seq=0 Win=43690 Len=0 MSS=65495 SACK_PERM=1 TSval=595251 TSecr=0
WS=128
  2 2018-04-10 03:35:40    127.0.0.1 -> 127.0.0.1    TCP 54 http > 51546
[RST, ACK] Seq=1 Ack=1 Win=0 Len=0
  3 2018-04-10 03:35:52    127.0.0.1 -> 127.0.0.1    TCP 74 51548 > http
[SYN] Seq=0 Win=43690 Len=0 MSS=65495 SACK_PERM=1 TSval=607469 TSecr=0
WS=128
  4 1970-01-31 04:44:20    127.0.0.1 -> 127.0.0.1    TCP 74 http > 51548
[SYN, ACK] Seq=0 Ack=1 Win=43690 Len=0 MSS=65495 SACK_PERM=1 TSval=607469
TSecr=607469 WS=128
  5 2018-04-10 03:35:52    127.0.0.1 -> 127.0.0.1    TCP 66 51548 > http
[ACK] Seq=1 Ack=1 Win=43776 Len=0 TSval=607469 TSecr=607469
  6 2018-04-10 03:35:52    127.0.0.1 -> 127.0.0.1    HTTP 139 GET /
HTTP/1.1
  <snip>

I can't locate a C7 bare metal server right at the moment but will try to
test that tomorrow. If someone happens to have a C7 bare metal box and
would be willing to test, here is the sequence of commands to run:
[shell1]$ sudo tcpdump -s 0 -i lo -w lo-port-80.pcap "port 80"
[shell2]$ curl localhost
[shell1]$ ^C
[shell1]$ tshark -t ud -r lo-port-80.pcap


On Mon, Apr 9, 2018 at 4:25 PM, Brandon Sterne <brandon.sterne at gmail.com>
wrote:

> This is very interesting. It is totally reproducible with CentOS 7 VMs,
> but I confirmed the testcase works as expected with an Ubuntu Server VM. On
> a freshly provisioned C7 VM, I see "That 70s Packet" when I capture from
> the loopback interface, but not when I capture from the external interface:
>
> ```[vagrant at localhost pcaps]$ tshark -t ud -r lo-port80.pcap
>   1 2018-04-09 23:16:28          ::1 -> ::1          TCP 94 58156 > http
> [SYN] Seq=0 Win=43690 Len=0 MSS=65476 SACK_PERM=1 TSval=8358348 TSecr=0
> WS=64
>   2 2018-04-09 23:16:28          ::1 -> ::1          TCP 74 http > 58156
> [RST, ACK] Seq=1 Ack=1 Win=0 Len=0
>   3 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 74 43060 > http
> [SYN] Seq=0 Win=43690 Len=0 MSS=65495 SACK_PERM=1 TSval=8358349 TSecr=0
> WS=64
>   4 1971-02-20 11:53:55    127.0.0.1 -> 127.0.0.1    TCP 74 http > 43060
> [SYN, ACK] Seq=0 Ack=1 Win=43690 Len=0 MSS=65495 SACK_PERM=1 TSval=8358349
> TSecr=8358349 WS=64
>   5 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=1 Ack=1 Win=43712 Len=0 TSval=8358349 TSecr=8358349
>   6 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    HTTP 139 GET /
> HTTP/1.1
>   7 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 http > 43060
> [ACK] Seq=1 Ack=74 Win=43712 Len=0 TSval=8358349 TSecr=8358349
>   8 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 83 [TCP segment
> of a reassembled PDU]
>   9 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=18 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  10 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 103 [TCP segment
> of a reassembled PDU]
>  11 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=55 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  12 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 103 [TCP segment
> of a reassembled PDU]
>  13 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=92 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  14 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 106 [TCP segment
> of a reassembled PDU]
>  15 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=132 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  16 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 87 [TCP segment
> of a reassembled PDU]
>  17 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=153 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  18 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 68 [TCP segment
> of a reassembled PDU]
>  19 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=155 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  20 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    HTTP 512 HTTP/1.0 200
> OK  (text/html)
>  21 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [ACK] Seq=74 Ack=601 Win=44800 Len=0 TSval=8358351 TSecr=8358351
>  22 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 http > 43060
> [FIN, ACK] Seq=601 Ack=74 Win=43712 Len=0 TSval=8358351 TSecr=8358351
>  23 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 43060 > http
> [FIN, ACK] Seq=74 Ack=602 Win=44800 Len=0 TSval=8358351 TSecr=8358351
>  24 2018-04-09 23:16:28    127.0.0.1 -> 127.0.0.1    TCP 66 http > 43060
> [ACK] Seq=602 Ack=75 Win=43712 Len=0 TSval=8358351 TSecr=8358351
> [vagrant at localhost pcaps]$ tshark -t ud -r eth1-port80.pcap
>   1 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 78 53640 > http
> [SYN, ECN, CWR] Seq=0 Win=65535 Len=0 MSS=1460 WS=32 TSval=240784579
> TSecr=0 SACK_PERM=1
>   2 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 74 http > 53640
> [SYN, ACK, ECN] Seq=0 Ack=1 Win=28960 Len=0 MSS=1460 SACK_PERM=1
> TSval=556841 TSecr=240784579 WS=64
>   3 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=1 Ack=1 Win=131744 Len=0 TSval=240784579 TSecr=556841
>   4 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 HTTP 415 GET /
> HTTP/1.1
>   5 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 66 http > 53640
> [ACK] Seq=1 Ack=350 Win=30080 Len=0 TSval=556842 TSecr=240784579
>   6 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 83 [TCP segment
> of a reassembled PDU]
>   7 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=350 Ack=18 Win=131744 Len=0 TSval=240784581 TSecr=556843
>   8 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 103 [TCP segment
> of a reassembled PDU]
>   9 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=350 Ack=55 Win=131712 Len=0 TSval=240784581 TSecr=556844
>  10 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 103 [TCP segment
> of a reassembled PDU]
>  11 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=350 Ack=92 Win=131648 Len=0 TSval=240784581 TSecr=556844
>  12 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 106 [TCP segment
> of a reassembled PDU]
>  13 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=350 Ack=132 Win=131616 Len=0 TSval=240784581 TSecr=556844
>  14 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 87 [TCP segment
> of a reassembled PDU]
>  15 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 HTTP 466 HTTP/1.0
> 200 OK  (text/html)
>  16 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=350 Ack=153 Win=131616 Len=0 TSval=240784581 TSecr=556844
>  17 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [ACK] Seq=350 Ack=554 Win=131200 Len=0 TSval=240784581 TSecr=556844
>  18 2018-04-09 21:06:26 192.168.43.1 -> 192.168.43.10 TCP 66 53640 > http
> [FIN, ACK] Seq=350 Ack=554 Win=131200 Len=0 TSval=240784581 TSecr=556844
>  19 2018-04-09 21:06:26 192.168.43.10 -> 192.168.43.1 TCP 66 http > 53640
> [ACK] Seq=554 Ack=351 Win=30080 Len=0 TSval=556844 TSecr=240784581
> ```
>
> It's a good question, Michał. Whose bug is this? I'm happy to go chase it
> down with the right audience if we can answer this question. Thanks for
> taking the time to look.
>
> Cheers,
> Brandon
>
>
> On Mon, Apr 9, 2018 at 3:34 PM, Michał Purzyński <
> michalpurzynski1 at gmail.com> wrote:
>
>> To help with the investigation, I also observed a similar behavior on
>> some CentOS 7.x hosts, when capturing traffic into a pcap on a live system
>> would result in some packets being saved with the 70's timestamp.
>>
>> The question remain - is that a kernel bug, a network card bug, a driver
>> bug?
>>
>> On Mon, Apr 9, 2018 at 1:33 PM, Seth Hall <seth at corelight.com> wrote:
>>
>>> I don't know how it happened, but the timestamp for the SYN/ACK packet
>>> in your pcap is March 22, 1970. Bro uses the timestamps from packets to
>>> track it's notion of time moving forward and with Bro's internal clock
>>> being shoved around by nearly 50 years twice in the span of three packets
>>> will throw it off pretty badly (lots of timeouts take place). ;)
>>>
>>> Any clue why the timestamp on that packet would be like that? It's just
>>> the one packet in your pcap that is messed up too.
>>>
>>> .Seth
>>>
>>> On 9 Apr 2018, at 11:56, Brandon Sterne wrote:
>>>
>>> Hi Justin,
>>>
>>> Thank you for the reply. I don't think it is the MTU that is preventing
>>> the sensor from decoding the traffic correctly. I ran the same test case
>>> with snaplen=65535 and still received only the connection_established
>>> event:
>>>
>>> [vagrant at localhost security-gateway]$ sudo bro -C -i lo snaplen=65535
>>> rules/bro/detect-http-request.bro
>>> <params>, line 1: listening on lo, capture length 65535 bytes
>>>
>>> Connection: , [id=[orig_h=127.0.0.1, orig_p=34902/tcp, resp_h=127.0.0.1,
>>> resp_p=80/tcp], orig=[size=0, state=4, num_pkts=1, num_bytes_ip=60,
>>> flow_label=0], resp=[size=0, state=4, num_pkts=0, num_bytes_ip=0,
>>> flow_label=0], start_time=1523289116.669146, duration=-1516793840.109909,
>>> service={
>>>
>>> }, history=Sh, uid=Ch6Tqk39qjgHi6li88, tunnel=<uninitialized>,
>>> dpd=<uninitialized>, conn=<uninitialized>, extract_orig=F, extract_resp=F,
>>> thresholds=<uninitialized>, dhcp=<uninitialized>, dnp3=<uninitialized>,
>>> dns=<uninitialized>, dns_state=<uninitialized>, ftp=<uninitialized>,
>>> ftp_data_reuse=F, ssl=<uninitialized>, http=<uninitialized>,
>>> http_state=<uninitialized>, irc=<uninitialized>, krb=<uninitialized>,
>>> modbus=<uninitialized>, mysql=<uninitialized>, radius=<uninitialized>,
>>> rdp=<uninitialized>, sip=<uninitialized>, sip_state=<uninitialized>,
>>> snmp=<uninitialized>, smtp=<uninitialized>, smtp_state=<uninitialized>,
>>> socks=<uninitialized>, ssh=<uninitialized>, syslog=<uninitialized>]
>>>
>>> I'm attaching the script I'm using and the pcap for the same request,
>>> taken with:
>>> sudo tcpdump -i lo -s 0 -w port8080.pcap
>>>
>>> Thanks,
>>> Brandon
>>>
>>>
>>> On Wed, Apr 4, 2018 at 3:01 PM, Azoff, Justin S <jazoff at illinois.edu>
>>> wrote:
>>>
>>>>
>>>> > On Apr 2, 2018, at 12:04 AM, Brandon Sterne <brandon.sterne at gmail.com>
>>>> wrote:
>>>> >
>>>> > Hello,
>>>> >
>>>> > I am attempting to get Bro working sitting behind a reverse proxy
>>>> (nginx), which is receiving connections, terminating TLS, and forwarding
>>>> cleartext HTTP to a local app server (Tomcat). I have a really simple test
>>>> case that demonstrates the problem I'm running into, which is that Bro HTTP
>>>> events are only detected when requests are sent plaintext (without TLS).
>>>> Here is the test case I'm using:
>>>>
>>>> The output you have included is not enough to tell what is wrong.
>>>> Minimally, full conn.log entries are required to figure out what bro is
>>>> seeing.  Even better would be a full pcap of the traffic that bro is not
>>>> properly decoding.
>>>>
>>>> To just guess, i'd say your problem is that the MTU on lo is 65536 and
>>>> bro is not configured by default to handle that.  Throwing a
>>>>
>>>> redef Pcap::snaplen = 65536
>>>>
>>>> in your script may get things working.
>>>>
>>>>
>>>>>>>> Justin Azoff
>>>>
>>>>
>>> _______________________________________________
>>> Bro mailing list
>>> bro at bro-ids.org
>>> http://mailman.ICSI.Berkeley.EDU/mailman/listinfo/bro
>>>
>>> --
>>> Seth Hall * Corelight, Inc * www.corelight.com
>>>
>>> _______________________________________________
>>> Bro mailing list
>>> bro at bro-ids.org
>>> http://mailman.ICSI.Berkeley.EDU/mailman/listinfo/bro
>>>
>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mailman.ICSI.Berkeley.EDU/pipermail/bro/attachments/20180409/678f5f81/attachment-0001.html 


More information about the Bro mailing list