So to start off with, lets see what the different fields are in the above picture of a sample log from the console;
| Virtual Firewall System | This shows the VSX from which the log was captured from. Depending on your hardware/software platform you may or may not see this field. |
| Firewall interface | This is the interface where the traffic was seen and captured. |
| Inspection Point | This can be either (i), (I), (o) or (O) based on what you are grepping when you setup the fw monitor. Read more about inspection points here. |
| Packet Length | This is the size of the frame as seen “on the wire” |
| Source IP | The source |
| Destination IP | The destination |
| Header/Payload | The type of header on that packet. Can either be TCP/UDP or something else in similar lines. |
| Packet ID | This is a unique number assigned to a packet until it is changed/altered in its course. Quite important when it comes to reading the fw monitor logs on your the console. (I also want to say this is locally significant on the firewall, but not very sure about it.) |
| Source Port | The source port |
| Destination Port | The destination port |
| TCP Flags | One of the most important fields in my opinion. These are the TCP flags you have always know about. 6 bits are reserved for the TCP flags denoted by 6 dots (……) in the logs. Each dot is a TCP flag in this order FSRPA* = FIN-SYN-RST-PUSH-ACK-*** and I don’t know what the last one is, yet. So, you will usually see something like this for a SYN-ACK = .S..A. | RST = ..R.. | PUSH ACK = …PA. | Hope I made this simple enough for you to be able to interpret the TCP flags. |
| Sequence Number | This is the sequence number that is the usual thing for TCP because of which it gets its name for being a reliable protocol. |
| Acknowledge Sequence Number | This is again a part of its reliable behavior where the other end host responds to denote that it has received its previous packet. |
Now that we know which field means what, let’s see how all of this fit together; Below is a complete set of logs for a two-way communication between two hosts (from the time it originates and gets back a reply from the destination). I omitted the (I) and (o) to minimize the amount of logs here so we’re only inspecting (i) pre-inbound and (O) post-outbound. We’ll take our time to analyze the logs and see what each set of packet ID means.
Logs on the console: [vs_4][fw_0] wrp256:i[48]: 10.1.1.1 -> 20.2.2.2 (TCP) len=48 id=27361 TCP: 59255 -> 443 .S.... seq=6cc07657 ack=00000000 [vs_4][fw_0] bond31.69:O[48]: 10.1.1.1 -> 20.2.2.2 (TCP) len=48 id=27361 TCP: 59255 -> 443 .S.... seq=6cc07657 ack=00000000 [vs_4][fw_0] bond31.69:i[48]: 20.2.2.2 -> 10.1.1.1 (TCP) len=48 id=44853 TCP: 443 -> 59255 .S..A. seq=37a73c7d ack=6cc07658 [vs_4][fw_0] wrp256:O[48]: 20.2.2.2 -> 10.1.1.1 (TCP) len=48 id=44853 TCP: 443 -> 59255 .S..A. seq=37a73c7d ack=6cc07658 [vs_4][fw_0] wrp256:i[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27386 TCP: 59255 -> 443 ....A. seq=6cc07658 ack=37a73c7e [vs_4][fw_0] bond31.69:O[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27386 TCP: 59255 -> 443 ....A. seq=6cc07658 ack=37a73c7e [vs_4][fw_0] wrp256:i[158]: 10.1.1.1 -> 20.2.2.2 (TCP) len=158 id=27396 TCP: 59255 -> 443 ...PA. seq=6cc07658 ack=37a73c7e [vs_4][fw_0] bond31.69:O[158]: 10.1.1.1 -> 20.2.2.2 (TCP) len=158 id=27396 TCP: 59255 -> 443 ...PA. seq=6cc07658 ack=37a73c7e [vs_4][fw_0] bond31.69:i[87]: 20.2.2.2 -> 10.1.1.1 (TCP) len=87 id=45365 TCP: 443 -> 59255 ...PA. seq=37a73c7e ack=6cc076ce [vs_4][fw_0] bond31.69:i[633]: 20.2.2.2 -> 10.1.1.1 (TCP) len=633 id=45621 TCP: 443 -> 59255 ...PA. seq=37a73cad ack=6cc076ce [vs_4][fw_0] wrp256:O[87]: 20.2.2.2 -> 10.1.1.1 (TCP) len=87 id=45365 TCP: 443 -> 59255 ...PA. seq=37a73c7e ack=6cc076ce [vs_4][fw_0] wrp256:O[633]: 20.2.2.2 -> 10.1.1.1 (TCP) len=633 id=45621 TCP: 443 -> 59255 ...PA. seq=37a73cad ack=6cc076ce [vs_4][fw_0] wrp256:i[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27478 TCP: 59255 -> 443 ....A. seq=6cc07a18 ack=37a7436b [vs_4][fw_0] bond31.69:O[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27478 TCP: 59255 -> 443 ....A. seq=6cc07a18 ack=37a7436b [vs_4][fw_0] wrp256:i[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27479 TCP: 59255 -> 443 F...A. seq=6cc07a18 ack=37a7436b [vs_4][fw_0] bond31.69:O[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27479 TCP: 59255 -> 443 F...A. seq=6cc07a18 ack=37a7436b [vs_4][fw_0] bond31.69:i[40]: 20.2.2.2 -> 10.1.1.1 (TCP) len=40 id=11794 TCP: 443 -> 59255 ....A. seq=37a7436b ack=6cc07a19 [vs_4][fw_0] wrp256:O[40]: 20.2.2.2 -> 10.1.1.1 (TCP) len=40 id=11794 TCP: 443 -> 59255 ....A. seq=37a7436b ack=6cc07a19
Each packet ID is shown at different inspection points depending on how the fw monitor is set. In our example we are looking for only (i) pre-inbound and (O) post-outbound so we see two logs with the same packet ID. If we were looking for all 4 inspection points (iIoO) we would’ve seen 4 such logs with the same packet ID. Makes sense? Okay, let’s proceed…
Starting with the first packet ID 27361:
[vs_4][fw_0] wrp256:i[48]: 10.1.1.1 -> 20.2.2.2 (TCP) len=48 id=27361 TCP: 59255 -> 443 .S.... seq=6cc07657 ack=00000000 [vs_4][fw_0] bond31.69:O[48]: 10.1.1.1 -> 20.2.2.2 (TCP) len=48 id=27361 TCP: 59255 -> 443 .S.... seq=6cc07657 ack=00000000
The first log with packet ID 27361 was seen on the virtual firewall 4 on ingress interface wrp256 on the (i) pre-inbound inspection point. Requestor 10.1.1.1 has sent a SYN (.S….) to 20.2.2.2 to setup an HTTPS (443) connection. In the second log with the same packet ID we see the exact same information but the inspection point has changed here to (O) and the egress interface to bond31.69. This tells us the SYN packet was successfully passed through the firewall towards the destination IP. Keep an eye on the ‘seq’ and ‘ack’ numbers from now on.
Next packet ID 44853;
[vs_4][fw_0] bond31.69:i[48]: 20.2.2.2 -> 10.1.1.1 (TCP) len=48 id=44853T CP: 443 -> 59255 .S..A. seq=37a73c7d ack=6cc07658[ vs_4][fw_0] wrp256:O[48]: 20.2.2.2 -> 10.1.1.1 (TCP) len=48 id=44853 TCP: 443 -> 59255 .S..A. seq=37a73c7d ack=6cc07658
This is the SYN-ACK (.S..A.) that responder 20.2.2.2 is sending back to the requestor 10.1.1.1. Notice how the ingress/egress interfaces are swapped now, since this is the exact opposite traffic flow, obviously. Now carefully compare the seq and ack number with that of the first packet ID 27361. Packet 27361 did not have an ack number since it was the first packet that was being sent but it did have a seq number 6cc07657 to which 44853 replied back incrementing it by ‘1’ in its ack – 6cc07658. It has also sent a seq number of 37a73c7d in the SYN-ACK, so in the next packet that will be an ACK from the requestor, we should see the ack number of 37a73c7e.
Next packet ID 27386;
[vs_4][fw_0] wrp256:i[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27386 TCP: 59255 -> 443 ....A. seq=6cc07658 ack=37a73c7e [vs_4][fw_0] bond31.69:O[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27386 TCP: 59255 -> 443 ....A. seq=6cc07658 ack=37a73c7e
Look at the ack number 37a73c7e, it has incremented by 1 to the seq number of the previous packet. This keeps on going back and forth until this session is torn down. So if you don’t see proper seq and ack numbers in sync, it should tell you that you are missing some packets (that would result in seeing many re-transmissions and out-of-order logs in wireshark). So this is an ACK (….A.) response by the initiator (10.1.1.1) which now completes the TCP three-way handshake.
Next packet ID is 27396;
[vs_4][fw_0] wrp256:i[158]: 10.1.1.1 -> 20.2.2.2 (TCP) len=158 id=27396 TCP: 59255 -> 443 ...PA. seq=6cc07658 ack=37a73c7e [vs_4][fw_0] bond31.69:O[158]: 10.1.1.1 -> 20.2.2.2 (TCP) len=158 id=27396 TCP: 59255 -> 443 ...PA. seq=6cc07658 ack=37a73c7e
Immediately after the three-way handshake, the requester sends its HTTPS request to the responder that we see in the PUSH-ACK messages (…PA.). You will also notice the packet length has changed since it now contains a good amount of payload (len=158).
Next packet IDs are 45365 and 45621;
[vs_4][fw_0] bond31.69:i[87]: 20.2.2.2 -> 10.1.1.1 (TCP) len=87 id=45365 TCP: 443 -> 59255 ...PA. seq=37a73c7e ack=6cc076ce [vs_4][fw_0] bond31.69:i[633]: 20.2.2.2 -> 10.1.1.1 (TCP) len=633 id=45621 TCP: 443 -> 59255 ...PA. seq=37a73cad ack=6cc076ce [vs_4][fw_0] wrp256:O[87]: 20.2.2.2 -> 10.1.1.1 (TCP) len=87 id=45365 TCP: 443 -> 59255 ...PA. seq=37a73c7e ack=6cc076ce [vs_4][fw_0] wrp256:O[633]: 20.2.2.2 -> 10.1.1.1 (TCP) len=633 id=45621 TCP: 443 -> 59255 ...PA. seq=37a73cad ack=6cc076ce
The responder has replied back as we see the PUSH-ACKs going back to the requester and the packet length has a significant value.
Next packet ID is 27478;
[vs_4][fw_0] wrp256:i[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27478 TCP: 59255 -> 443 ....A. seq=6cc07a18 ack=37a7436b [vs_4][fw_0] bond31.69:O[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27478 TCP: 59255 -> 443 ....A. seq=6cc07a18 ack=37a7436b
The requester 10.1.1.1 has replied back with an ACK to the HTTPS response it received from the responder in the earlier packets that were seen.
Next packet ID is 27479;
[vs_4][fw_0] wrp256:i[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27479 TCP: 59255 -> 443 F...A. seq=6cc07a18 ack=37a7436b [vs_4][fw_0] bond31.69:O[40]: 10.1.1.1 -> 20.2.2.2 (TCP) len=40 id=27479 TCP: 59255 -> 443 F...A. seq=6cc07a18 ack=37a7436b
The requester then sends a FIN-ACK telling the responder I’m done with my requests and I’ll close this session from my end.
Next packet ID is 11794;
[vs_4][fw_0] bond31.69:i[40]: 20.2.2.2 -> 10.1.1.1 (TCP) len=40 id=11794 TCP: 443 -> 59255 ....A. seq=37a7436b ack=6cc07a19 [vs_4][fw_0] wrp256:O[40]: 20.2.2.2 -> 10.1.1.1 (TCP) len=40 id=11794 TCP: 443 -> 59255 ....A. seq=37a7436b ack=6cc07a19
The responder acknowledges the closing of the session too and the connection comes to an end. Pheww.
Throughout all this traffic going back and forth, you want to keep an eye on the TCP flags as that is where you will see the most problems. Also when you want to troubleshoot packet loss, seq/ack numbers are your best friend and you want to track them very diligently.
