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

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 with an API, t…

Artificial Intelligence in Digital Operations

Artificial Intelligence in Digital Operations
Not a week goes by where I don't see a vendor claiming that they have applied Artificial Intelligence (AI) to running digital businesses (there was a new one this week, but I began writing this beforehand). The list of vendors continues to increase, and when digging into the technology, the marketing is often overstepping the use of the AI term. Let's take a step back and understand what AI is from a computer science perspective.
The traditional problems (or goals) of AI research include reasoning, knowledge, planning, learning, natural language processing, perception as per Wikipedia. The other interesting trend is the application of the AI effect. This term explains that as we apply models and data to problems, and create algorithms to solve these problems, we move the problem outside of the scope of AI. Thus, abusing term AI to describe much of what we do in technology. Most of the technology itself is not complex when it comes t…