Strange things happening while attempting universal persistence using JSESSIONID

Hi,

I'm setting up a Java web application behind a pair of F5 BIG-IP LTMs

running operating system version 9.3.1. The application is hosted on

a cluster of machines running Resin servlet container.

The backend nodes are not using any kind of shared session store,

so we need to direct each session to the same backend node that

served the initial request. Resin is configured to use JSESSIONID cookie

to store the session identifier. So based on documentation and

examples found here on DevCentral, I created a universal persistence

profile, and assigned that to the virtual server as the only

persistency profile. The iRule powering the profile is included below

(it also supports setting the session id in the request URI,

but cookies are preferred).

when RULE_INIT {
  set ::debug 1
}
when CLIENT_ACCEPTED {
  if { $::debug } {
    set client [IP::client_addr]:[TCP::client_port]
  }
}
when HTTP_RESPONSE {
  if { [HTTP::cookie exists "JSESSIONID"] } {
    set jsessionid [HTTP::cookie "JSESSIONID"]
    persist add uie $jsessionid 3600
    if { $::debug } {
      log local0. "NEW PERSIST ENTRY client>$client< JSESSIONID>$jsessionid<"
    }
  }
}
when HTTP_REQUEST {
  set jsessionid ""
  set cookie_id ""
  set uri [HTTP::uri]
  set uri_id [findstr $uri "jsessionid=" 11 "?"]
  if { [HTTP::cookie exists "JSESSIONID"] } {
    set cookie_id [HTTP::cookie "JSESSIONID"]
  }
  if { $cookie_id ne "" } {
    set jsessionid $cookie_id
  } elseif { $uri_id ne "" } {
    set jsessionid $uri_id
  }
  if { $jsessionid ne "" } {
    persist uie $jsessionid 3600
  }
  if { $::debug } {
    set table ""
    if { $jsessionid ne "" } {
      set table [persist lookup uie $jsessionid]
    }
    if { $table eq "" } {
      log local0. "client>$client< uri>$uri< cookie_id>$cookie_id< uri_id>$uri_id< JSESSIONID>$jsessionid< table>null<"
    } else {
      log local0. "client>$client< uri>$uri< cookie_id>$cookie_id< uri_id>$uri_id< JSESSIONID>$jsessionid< table>[lindex $table 0] [lindex $table 1] [lindex $table 2]<"
    }
  }
}
when LB_SELECTED {
  if { $::debug } {
    set server [LB::server addr]:[LB::server port]
    log local0. "client>$client< server>$server<"
  }
}
when LB_FAILED {
  if { $::debug } {
    if { $jsessionid ne "" } {
      if { $table ne "" } {
        log local0. "client>$client< JSESSIONID>$jsessionid< table>[lindex $table 0] [lindex $table 1] [lindex $table 2]<"
      } else {
        log local0. "client>$client< JSESSIONID>$jsessionid< table>null<"
      }
    } else {
      log local0. "client>$client< JSESSIONID>null< table>null<"
    }
  }
  if { $jsessionid ne "" } { persist delete uie $jsessionid }
  if { $table ne "" } { LB::reselect pool [lindex $table 0] }
}

However, when this setup is in place, we noticed that requests of

a session were not actually always directed to the same node,

even though the logic seemed to work as sane values were printed in

the syslog by iRule debugging statements. I give an example using

the debug statements in the iRule and HTTP data captured using tcpdump

on the BIG-IP LTM when the web application was accessed with a browser.

Setup:

Client IP: 194.137.112.98

BE Nodes: 192.168.135.16:6889 and 192.168.135.17:6889

Here we have the first request from the client

(irrelevant HTTP headers omitted)

GET /littleredcap-demo/app/?lang=fi HTTP/1.1

As you can see, we have no session cookie.

The request was served by 192.168.135.17 with response

HTTP/1.1 200 OK
Set-Cookie: JSESSIONID=abccmG4bh7OVaeO7KjCLr; path=/

We now have the cookie. Corresponding debug log entries from the iRule:

Apr 17 14:30:24 tmm tmm[875]: Rule persist_jsessionid : client>194.137.112.98:8283< uri>/littleredcap-demo/app/?lang=fi< cookie_id>< uri_id>< JSESSIONID>< table>null<
Apr 17 14:30:24 tmm tmm[875]: Rule persist_jsessionid : client>194.137.112.98:8283< server>192.168.135.17:6998<
Apr 17 14:30:25 tmm tmm[875]: Rule persist_jsessionid : NEW PERSIST ENTRY client>194.137.112.98:8283< JSESSIONID>abccmG4bh7OVaeO7KjCLr<

So the iRule logs that new universal persistence entry has been created

for this session id, and we're using 192.168.135.17:6998 as

the backend node for the session.

But then, with next request hitting the virtual server, things are

getting weird. The request that the browser sends in order to get some

CSS resource needed to render the front page looks like this.

GET /littleredcap-demo/css/app-layout.css HTTP/1.1
Cookie: JSESSIONID=abccmG4bh7OVaeO7KjCLr

We have the session id, as iRule log entry confirms

Apr 17 14:30:25 tmm tmm[875]: Rule persist_jsessionid : client>194.137.112.98:8276< uri>/littleredcap-demo/css/app-layout.css< cookie_id>abccmG4bh7OVaeO7KjCLr< uri_id>< JSESSIONID>abccmG4bh7OVaeO7KjCLr< table>test_pool 192.168.135.17 6998<

This log entry finds the original backend node associated for

the session, 192.168.135.17. But the tcpdump capture and access log

on the backend 192.168.135.16 revealed that the actual request was

redirected to the node 192.168.135.16 instead! So persistency for

this esablished session was not honoured, and the default

scheduling algorithm that chooses the node from the pool was

applied instead.

Any idea why this happened? Can someone point out the flaw in

the iRule? Thanks.