Forum Discussion

atuls_7180's avatar
atuls_7180
Icon for Nimbostratus rankNimbostratus
Jan 12, 2012

Interpreting time-taken IIS log field in load balanced configuration

We are using BIG-IP LTM to load balance between application servers which are running IIS 7.0. Our system is configured to offload SSL to BIG-IP LTM. Our application servers handle compression. I have a question around how to interpret the time-taken IIS header

 

 

http://support.microsoft.com/kb/944884 describes this time as "Beginning in IIS 6.0, the time-taken field typically includes network time. Before HTTP.sys logs the value in the time-taken field, HTTP.sys usually waits for the client to acknowledge the last response packet send operation or HTTP.sys waits for the client to reset the underlying TCP connection. Therefore, when a large response or large responses are sent to a client over a slow network connection, the value of the time-taken field may be more than expected. "

 

 

Now, BIGIP is configured to buffer the response from IIS to the client -- we've configured our TCP profile per the WAN profile in BIG-IP LTM. We aren't using the LTM's connection pooling feature, so my expectation is that LTM will close the TCP connection to IIS after every response (is this correct?)

 

 

When does BIG-IP ACK the final packet sent by IIS to it? Does it wait for the client to ACK its last packet? Does the time-taken header include network time in all cases in our configuration? Please don't hesitate to point out how stupid this question, or suggest an alternate forum for this question! :)

 

 

 

config
design
  • nitass's avatar
    nitass
    Icon for Employee rankEmployee
    Jan 12, 2012
    i understand client sends FIN and then bigip sends it to server (pool member). 

    [root@ve1023:Active] config  b virtual bar list
bvirtual bar {
   snat automap
   pool foo
   destination 172.28.19.79:80
   ip protocol 6
   profiles {
      http {}
      tcp {}
   }
}
[root@ve1023:Active] config  b pool foo list
pool foo {
   members 200.200.200.101:80 {}
}
[root@ve1023:Active] config  b self 200.200.200.10 list
self 200.200.200.10 {
   netmask 255.255.255.0
   vlan internal
   allow default
}

[root@ve1023:Active] config  tcpdump -nni 0.0 port 80
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on 0.0, link-type EN10MB (Ethernet), capture size 108 bytes
20:43:47.571707 IP 172.28.19.253.49977 > 172.28.19.79.80: S 3323959709:3323959709(0) win 5840 
20:43:47.571760 IP 172.28.19.79.80 > 172.28.19.253.49977: S 1166530685:1166530685(0) ack 3323959710 win 4380 
20:43:47.575553 IP 172.28.19.253.49977 > 172.28.19.79.80: . ack 1 win 46 
20:43:47.575610 IP 172.28.19.253.49977 > 172.28.19.79.80: P 1:155(154) ack 1 win 46 
20:43:47.576607 IP 200.200.200.10.49977 > 200.200.200.101.80: S 1870686982:1870686982(0) win 4380 
20:43:47.577501 IP 200.200.200.101.80 > 200.200.200.10.49977: S 2801000415:2801000415(0) ack 1870686983 win 5792 
20:43:47.577513 IP 200.200.200.10.49977 > 200.200.200.101.80: . ack 1 win 4380 
20:43:47.577530 IP 200.200.200.10.49977 > 200.200.200.101.80: P 1:155(154) ack 1 win 4380 
20:43:47.578452 IP 200.200.200.101.80 > 200.200.200.10.49977: . ack 155 win 54 
20:43:47.580643 IP 200.200.200.101.80 > 200.200.200.10.49977: P 1:372(371) ack 155 win 54 
20:43:47.580670 IP 172.28.19.79.80 > 172.28.19.253.49977: P 1:372(371) ack 155 win 4534 
20:43:47.583720 IP 172.28.19.253.49977 > 172.28.19.79.80: . ack 372 win 54 
20:43:47.583732 IP 172.28.19.253.49977 > 172.28.19.79.80: F 155:155(0) ack 372 win 54 
20:43:47.583743 IP 172.28.19.79.80 > 172.28.19.253.49977: . ack 156 win 4534 
20:43:47.583749 IP 200.200.200.10.49977 > 200.200.200.101.80: F 155:155(0) ack 372 win 4751 
20:43:47.584686 IP 200.200.200.101.80 > 200.200.200.10.49977: F 372:372(0) ack 156 win 54 
20:43:47.584700 IP 200.200.200.10.49977 > 200.200.200.101.80: . ack 373 win 4751 
20:43:47.584704 IP 172.28.19.79.80 > 172.28.19.253.49977: F 372:372(0) ack 156 win 4534 
20:43:47.586583 IP 172.28.19.253.49977 > 172.28.19.79.80: . ack 373 win 54
  • atuls_7180's avatar
    atuls_7180
    Icon for Nimbostratus rankNimbostratus
    Jan 12, 2012
    Thanks sounds like LTM will mirror the connection state from the client over to IIS (pool member)-- is this true as a general design principle for the LTM?

     

     

    If so, the time-taken header will always include the final ACK (in the case of a keep alive), or FIN(in the case of a close) from the client.

     

     

  • nitass's avatar
    nitass
    Icon for Employee rankEmployee
    Jan 12, 2012
    When does BIG-IP ACK the final packet sent by IIS to it? Does it wait for the client to ACK its last packet? for ACK, bigip does ACK after receving the last data from IIS.

    172.28.19.253 is client

    172.28.19.79 is virtual server

    200.200.200.10 is bigip selfip

    200.200.200.103 is pool member (IIS)

    (a) is ACK from bigip to IIS and (b) is ACK from client to virtual server. 

    [root@ve1023:Active] config  tcpdump -nnr /var/tmp/test1.pcap |less
23:06:22.584631 IP 172.28.19.253.54264 > 172.28.19.79.80: S 396640664:396640664(0) win 5840  in slot1/tmm0 lis=
23:06:22.584687 IP 172.28.19.79.80 > 172.28.19.253.54264: S 3228099800:3228099800(0) ack 396640665 win 4380  out slot1/tmm0 lis=bar
23:06:22.587460 IP 172.28.19.253.54264 > 172.28.19.79.80: . ack 1 win 46  in slot1/tmm0 lis=bar
23:06:22.587501 IP 172.28.19.253.54264 > 172.28.19.79.80: P 1:164(163) ack 1 win 46  in slot1/tmm0 lis=bar
23:06:22.588445 IP 200.200.200.10.54264 > 200.200.200.103.80: S 3684513503:3684513503(0) win 4380  out slot1/tmm0 lis=bar
23:06:22.591665 IP 200.200.200.103.80 > 200.200.200.10.54264: S 2947746950:2947746950(0) ack 3684513504 win 64240  in slot1/tmm0 lis=bar
23:06:22.591676 IP 200.200.200.10.54264 > 200.200.200.103.80: . ack 1 win 4380  out slot1/tmm0 lis=bar
23:06:22.591692 IP 200.200.200.10.54264 > 200.200.200.103.80: P 1:164(163) ack 1 win 4380  out slot1/tmm0 lis=bar
...
23:06:22.648476 IP 200.200.200.103.80 > 200.200.200.10.54264: P 168951:169771(820) ack 164 win 64077  in slot1/tmm0 lis=bar
(a) 23:06:22.648481 IP 200.200.200.10.54264 > 200.200.200.103.80: . ack 169771 win 11676  out slot1/tmm0 lis=bar
...
23:06:22.681558 IP 172.28.19.79.80 > 172.28.19.253.54264: P 168575:169771(1196) ack 164 win 4543  out slot1/tmm0 lis=bar
(b) 23:06:22.691678 IP 172.28.19.253.54264 > 172.28.19.79.80: . ack 169771 win 374  in slot1/tmm0 lis=bar
23:06:22.717556 IP 172.28.19.253.54264 > 172.28.19.79.80: F 164:164(0) ack 169771 win 453  in slot1/tmm0 lis=bar
23:06:22.717574 IP 172.28.19.79.80 > 172.28.19.253.54264: . ack 165 win 4543  out slot1/tmm0 lis=bar
23:06:22.717580 IP 200.200.200.10.54264 > 200.200.200.103.80: F 164:164(0) ack 169771 win 11676  out slot1/tmm0 lis=bar
23:06:22.718441 IP 200.200.200.103.80 > 200.200.200.10.54264: . ack 165 win 64077  in slot1/tmm0 lis=bar
23:06:22.718448 IP 200.200.200.103.80 > 200.200.200.10.54264: F 169771:169771(0) ack 165 win 64077  in slot1/tmm0 lis=bar
23:06:22.718456 IP 200.200.200.10.54264 > 200.200.200.103.80: . ack 169772 win 11676  out slot1/tmm0 lis=bar
23:06:22.718459 IP 172.28.19.79.80 > 172.28.19.253.54264: F 169771:169771(0) ack 165 win 4543  out slot1/tmm0 lis=bar
23:06:22.719640 IP 172.28.19.253.54264 > 172.28.19.79.80: . ack 169772 win 453  in slot1/tmm0 lis=bar