Skip to main content

F5 Persistence and my 6 week battle with support

We've been having issues with persistence on our F5's since we launched our new product. We have tried many different ways of trying to get our clients to stick on a server. Of course the first step was using a standard cookie persistence which the F5 was injecting. All of our products which use SSL is being terminated on the F5, which makes cookie work fine even for SSL traffic. After we started seeing clients going to many servers, we figured it would be safe to use a JSESSIONID cookie which is a standard Java application server cookie that is always unique per session. We implemented the following Irule (slightly modified in order to get more logging):

http://devcentral.f5.com/Default.aspx?tabid=53&view=topic&postid=1171255 (registration is free)

when HTTP_REQUEST {

# Check if there is a JSESSIONID cookie

if {[HTTP::cookie "JSESSIONID"] ne ""}{

# Persist off of the cookie value with a timeout of 2 hours (7200 seconds)

persist uie [string tolower [HTTP::cookie "JSESSIONID"]] 7200

# Log that we're using the cookie value for persistence and the persistence key if it exists.

log local0. "[IP::client_addr]:[TCP::client_port]: Request to [HTTP::uri] on server [LB::server] with cookie: [HTTP::cookie value JSESSIONID]"

} else {

# Parse the jsessionid from the path

set jsess [findstr [string tolower [HTTP::path]] "jsessionid=" 11]

# Use the jsessionid from the path for persisting with a timeout of 2 hours (7200 seconds)

if { $jsess != "" } {

persist uie $jsess 7200

# Log that we're using the path jessionid for persistence and the persistence key if it exists.

log local0. "[IP::client_addr]:[TCP::client_port]: Request to [HTTP::uri] on server [LB::server] used persistence record from path: [persist lookup uie $jsess]"

}

}

}

when HTTP_RESPONSE {

# Check if there is a jsessionid cookie in the response

if {[HTTP::cookie "JSESSIONID"] ne ""} {

# Persist off of the cookie value with a timeout of 2 hours (7200 seconds)

persist add uie [string tolower [HTTP::cookie "JSESSIONID"]] 7200

            # Log Response

log local0. "[IP::client_addr]:[TCP::client_port]: Request to server [LB::server] with cookie: [HTTP::cookie value JSESSIONID]. Added persistence record from cookie: [persist lookup uie [string tolower [HTTP::cookie "JSESSIONID"]]]"

}

}

when LB_SELECTED {

log "From [IP::client_addr] to physical server [LB::server] the cookie JSESSIONID is [HTTP::cookie "JSESSIONID"] URI JESSIONID is [findstr [string tolower [HTTP::path]] "jsessionid=" 11] "

}


 

We've replicated and done 3 rounds of packet captures, and you can always see the issue in the logging from the irule above:

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63231: Request to /images/mfg/icons/search_cross.png on server -http-pool x.x.x.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63229: Request to /images/mfg/icons/icon_largemessages.png on server -http-pool BACKENDSUBNET.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63228: Request to /images/mfg/icons/icon_clock.png on server -http-pool BACKENDSUBNET.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63231: Request to /images/mfg/icons/icon_largequotes.png on server -http-pool BACKENDSUBNET.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63233: Request to /images/mfg/icons/icon_largendas.png on server -http-pool BACKENDSUBNET.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63230: Request to /images/mfg/icons/icon_largebluestar.png on server -http-pool BACKENDSUBNET.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63232: Request to /mfg/scripts/search/search.js on server -http-pool BACKENDSUBNET.19 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63235: Request to /favicon.ico on server -http-pool 0 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: 01220002:6: Rule JSESSION_iRule_withlogging <LB_SELECTED>: From CLIENTIP to physical server -http-pool BACKENDSUBNET.19 80 the cookie JSESSIONID is abcND0QYKjeOCczB8c_Ds URI JESSIONID is

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63236: Request to /servlet/mfg.Controller?time=1269130074065&pmId=1001&act=1154 on server -http-pool 0 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:14:25 tmm tmm[1629]: 01220002:6: Rule JSESSION_iRule_withlogging <LB_SELECTED>: From CLIENTIP to physical server -http-pool BACKENDSUBNET.19 80 the cookie JSESSIONID is abcND0QYKjeOCczB8c_Ds URI JESSIONID is

Mar 21 01:14:25 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63224: Request to /mfg/contactHome.jsp?time=1269130079475&pmId=1154 on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:31 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /servlet/mfg.Controller?time=1269130079686&pmId=1154&act=supplierDisplayAgent&aid=904564&dgrdv=1 on server -http-pool 0 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:31 tmm tmm[1629]: 01220002:6: Rule JSESSION_iRule_withlogging <LB_SELECTED>: From CLIENTIP to physical server -http-pool BACKENDSUBNET.20 80 the cookie JSESSIONID is abcND0QYKjeOCczB8c_Ds URI JESSIONID is

Mar 21 01:15:31 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /mfg/contactHome.jsp?time=1269130145070&pmId=1016 on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:43 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /images/mfg/modalbox/close.gif on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:44 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /servlet/mfg.Controller?time=1269130145287&pmId=1016&act=modal&mtId=800&mLoad=true&aid=904564 on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:44 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63250: Request to /images/bo/design/spinner.gif on server -http-pool 0 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:44 tmm tmm[1629]: 01220002:6: Rule JSESSION_iRule_withlogging <LB_SELECTED>: From CLIENTIP to physical server -http-pool BACKENDSUBNET.20 80 the cookie JSESSIONID is abcND0QYKjeOCczB8c_Ds URI JESSIONID is

Mar 21 01:15:44 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /images/mfg/icons/search_cross.png on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:44 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63250: Request to /images/mfg/icons/doubleDownArrow.png on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:45 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /images/mfg/combo/comboover.gif on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:45 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63250: Request to /images/mfg/combo/combopress.gif on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /servlet/mfg.ajaxProvider.GetDisciplineProvider;jsessionid=abcND0QYKjeOCczB8c_Ds?time=1269130158059&pmId=1016 on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63250: Request to /servlet/mfg.ajaxProvider.GetRfqBuyerLocationProvider?time=1269130158059&pmId=1016&sImg=false&sCwor=false on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /images/mfg/icons/dhtmlTree/iconUnCheckAll.gif on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /servlet/mfg.ajaxProvider.GetMaterialProvider?time=1269130158060&pmId=1016&sImg=false on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63250: Request to /images/mfg/combo/combonormal.gif on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /servlet/mfg.ajaxProvider.GetIndustryProvider?time=1269130158060&pmId=1016&ids= on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:46 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63250: Request to /servlet/mfg.ajaxProvider.GetLanguageProvider?time=1269130158060&pmId=1016&ids= on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds

Mar 21 01:15:47 tmm tmm[1629]: Rule JSESSION_iRule_withlogging <HTTP_REQUEST>: CLIENTIP:63247: Request to /images/mfg/icons/dhtmlTree/folderOpen.gif on server -http-pool BACKENDSUBNET.20 80 with cookie: abcND0QYKjeOCczB8c_Ds


 

The support team cannot figure out why this is, and it's been going on for very long. I will keep updating this as it goes on. The latest saga is that they are blaming it on the SNAT we are using.

http://devcentral.f5.com/Default.aspx?tabid=53&view=topic&postid=813179

http://devcentral.f5.com/Default.aspx?tabid=53&forumid=5&tpage=1&view=topic&postid=86374

F5 can be implemented as the inline gateway or outside of the gateway as a NAT device. We opted for the latter in order to avoid sending unnecessary traffic through the device. We may have to do some testing with it as the gateway and see if it fixes it. It clearly looks like a bug to me. We are running BIG-IP 9.4.5 Build 1049.10 Final, and we're planning on moving to V10 soon.

Comments

Adventures of a Technical MasterMind is a good blog for IT geeks.

Popular posts from this blog

Dynatrace Growth Misinformation

For my valued readers: I wanted to point out some issues I’ve recently seen in the public domain. As a Gartner analyst, I heard many claims about 200% growth, and all kind of data points which have little basis in fact. When those vendors are asked what actual numbers they are basing those growth claims on, often the questions are dodged. Dynatrace, recently used the Gartner name and brand in a press release. In Its First Year as an Independent Company, Gartner Ranks Dynatrace #1 in APM Market http://www.prweb.com/releases/2015/06/prweb12773790.htm I want to clarify the issues in their statements based on the actual Gartner facts published by Gartner in its Market Share data: Dynatrace says in their press release: “expand globally with more than three times the revenue of other new generation APM vendors” First, let’s look at how new the various technologies are: Dynatrace Data Center RUM (DCRUM) is based on the Adlex technology acquired in 2005, but was cr

Vsphere server issues and upgrade progress

So I found out that using the host update tool versus Vcenter update manager is much easier and more reliable when moving from ESXi 3.5 to 4.0. Before I was using the update manager and it wasn't working all that reliably. So far I haven't had any issues using the host update tool. I've done many upgrades now, and I only have 4 left, 3 of which I am doing this weekend. Whenever I speak to vmware they always think I'm using ESX, when I prefer and expect that people should move to the more appliance model of ESXi. With 4.0 they are pretty much on par, and I'm going to stick with ESXi. On one of my vsphere 4.0 servers (virtualcenter) its doing this annoying thing when I try to use the performance overview:   Perf Charts service experienced and internal error.   Message: Report application initialization is not completed successfully. Retry in 60 seconds.   In my stats.log I see this.   [28 Aug 09, 22:28:07] [ERROR] com.vmware.vim.stats.webui.startup.Stat

Misunderstanding "Open Tracing" for the Enterprise

When first hearing of the OpenTracing project in 2016 there was excitement, finally an open standard for tracing. First, what is a trace? A trace is following a transaction from different services to build an end to end picture. The latency of each transaction segment is captured to determine which is slow, or causing performance issues. The trace may also include metadata such as metrics and logs, more on that later. Great, so if this is open this will solve all interoperability issues we have, and allow me to use multiple APM and tracing tools at once? It will help avoid vendor or project lock-in, unlock cloud services which are opaque or invisible? Nope! Why not? Today there are so many different implementations of tracing providing end to end transaction monitoring, and the reason why is that each project or vendor has different capabilities and use cases for the traces. Most tool users don't need to know the implementation details, but when manually instrumenting wi