Learn F5 Technologies, Get Answers & Share Community Solutions Join DevCentral

Filter by:
  • Solution
  • Technology
Answers

ACCESS::session behavior within ACCESS_* events

I have a question about ACCESS::session command which suspends execution of irule.

In k12962, there is this note:

Note: When you run the ACCESS::session command, iRule execution on the connection will be suspended until the operation completes only if the session database record is held by another TMM; this situation allows the current TMM to retrieve the data from the other TMM before processing the remainder of the iRule.

When evaluating ACCESS_SESSION_ALLOWED, does it suspend IRule processing as this is an APM event?

Same question for other APM events!

0
Rate this Question

Answers to this Question

placeholder+image
USER ACCEPTED ANSWER & F5 ACCEPTED ANSWER

Hi Stanislas,

you can easily detect connection parking/suspending situations by measuring the [clock clicks] needed to execute the individual ACCESS::session commands. If the connection gets suspended it will take way more than 50 clicks and if not it will take less clicks...

I've once reverse engineered the connection suspending behavior for [table] and [ACCESS::*] commands on a CMP-enabled plattform and came to the following conclusion.

General rules for TMM distribution:

  • The underlying TCP/UDP connection will use the CMP-hash settings (IP or IP+Port) to select the owning TMM instance.
  • The [table] command will use a hash of the KEY value to select the owning TMM instance.
  • The [table -subtable] command will use a hash of the subtable-label to select the owning TMM instance.
  • The [ACCESS::*] commands will use a hash of the SID to select the owning TMM instance.

General rule for connection suspending:

  • A connection suspending situation will ocour if the TMM instance where the [table] or [ACCESS::*] command is executed is not the owning TMM instance.

APM specific behavior:

  • The underlying TCP session of the HTTP request that initiates a new APM session will be CMP-hash distributed to a given TMM (lets say TMM0)
  • The ACCESS_SESSION_STARTED will be processed on the TMM core of the underlying TCP session (still TMM0)
  • During ACCESS_SESSION_STARTED a (slightly pseudo) random SID will be generated, where the hash of the just created SID always routes the responsibility for that APM session to the local TMM (still TMM0 in this case)
  • In a non-clientless mode, the client may open multiple keep-alive TCP session to fetch the login pages where each TCP session may be CMP-hash distributed to a different TMM (TMM0, TMM1, ect.)
  • From here it depends on the underlying TCP session the client has used to POST-back login page information.
  • If the underlying TCP session is handled by the TMM which has processed the ACCESS_SESSION_STARTED event no connection parking situations will happen while executing [ACCESS::*] commands.
  • If the underlying TCP session is handled by a different TMM a connection parking situations will happen everytime while executing [ACCESS::*] commands.

How to repro my observations:

Create a VPE with a pattern like that:

START -> iRule Action -> MSGBox -> iRule Action -> MSGBox -> iRule Action -> DENY

Use the following iRule to measure the time needed and to output the used TMM instance.

when CLIENT_ACCEPTED {
    ACCESS::restrict_irule_events disable
}
when HTTP_REQUEST {
    log local0.debug "Path: [HTTP::path]"
}
when ACCESS_SESSION_STARTED {
    set start [clock clicks]
    set test [ACCESS::session data get "blub"]
    set stop [clock clicks]
    log local0.debug "APM session initialized on TMM[TMM::cmp_unit]. ACCESS command took [expr { $stop - $start }] clicks"
}
when ACCESS_POLICY_AGENT_EVENT {
    set start [clock clicks]
    set test [ACCESS::session data get "blub"]
    set stop [clock clicks]
    log local0.debug "We are on TMM[TMM::cmp_unit] now. ACCESS command took [expr { $stop - $start }] clicks"
}
when ACCESS_POLICY_COMPLETED {
    set start [clock clicks]
    set test [ACCESS::session data get "blub"]
    set stop [clock clicks]
    log local0.debug "We are on TMM[TMM::cmp_unit] now. ACCESS command took [expr { $stop - $start }] clicks"
}

Log outputs on a test system with 2 TMM cores:

tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /
tmm[13406]: Rule /Common/Test <ACCESS_SESSION_STARTED>: APM session initialized on TMM0. ACCESS command took 15 clicks
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM0 now. ACCESS command took 15 clicks
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_message_box_form.eui
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm1[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM1 now. ACCESS command took 201 clicks
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_message_box_form.eui
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM0 now. ACCESS command took 16 clicks
tmm[13406]: Rule /Common/Test <ACCESS_POLICY_COMPLETED>: We are on TMM0 now. ACCESS command took 14 clicks
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /vdesk/hangup.php3

tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /
tmm1[13406]: Rule /Common/Test <ACCESS_SESSION_STARTED>: APM session initialized on TMM1. ACCESS command took 14 clicks
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm1[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM1 now. ACCESS command took 12 clicks
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_message_box_form.eui
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm1[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM1 now. ACCESS command took 16 clicks
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_message_box_form.eui
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM0 now. ACCESS command took 611 clicks
tmm[13406]: Rule /Common/Test <ACCESS_POLICY_COMPLETED>: We are on TMM0 now. ACCESS command took 564 clicks
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /vdesk/hangup.php3

tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /
tmm[13406]: Rule /Common/Test <ACCESS_SESSION_STARTED>: APM session initialized on TMM0. ACCESS command took 12 clicks
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM0 now. ACCESS command took 16 clicks
tmm[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_message_box_form.eui
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm1[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM1 now. ACCESS command took 205 clicks
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_message_box_form.eui
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /my.policy
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /renderer/agent_irule_event_form.eui
tmm1[13406]: Rule /Common/Test <ACCESS_POLICY_AGENT_EVENT>: We are on TMM1 now. ACCESS command took 193 clicks
tmm1[13406]: Rule /Common/Test <ACCESS_POLICY_COMPLETED>: We are on TMM1 now. ACCESS command took 105 clicks
tmm1[13406]: Rule /Common/Test <HTTP_REQUEST>: Path: /vdesk/hangup.php3

Note: Keep in mind that those informations are based on reverse engineerings. They may or may not be 100% acurate, but for now it seems they are at least 99% correct... ;-)

Cheers, Kai

1
Comments on this Answer
Comment made 2 days ago by Stanislas Piron 6170

Hi Kai,

Thanks for the detailed answer as always. I wondered if I will have any answer for that question.

I used the same code as you in my lab and I have 1000 clicks more when on a different TMM. these commands may really be used carefully. I also tried with set instead of get... same performance impact.

Do you know if it's possible to evaluate impact of variable assign vs ACCESS_POLICY_AGENT_EVENT like you did?

0
Comment made 2 days ago by Kai Wilke 6258

Hi Stanislas,

you're very much welcome!

I used the same code as you in my lab and I have 1000 clicks more when on a different TMM. these commands may really be used carefully. I also tried with set instead of get... same performance impact.

It doesn't matter if a connection parking adds 100, 200, 500 or 1000 clicks, since most of the added time is used to wait for the owning TMM to pickup the request and to retrive/set information and also used to wait for the calling TMM to pickup the result from the owning TMM. The more the TMM cores are under pressure the more wait time is needed (its a sort of Preemtive-Multitasking within each TMM core) to process the session lookups/inserts. But the added CPU overhead (without wait time) of a single parking situation should most likely be considered as a fixed amount.

Do you know if it's possible to evaluate impact of variable assign vs ACCESS_POLICY_AGENT_EVENT like you did?

You may use the same [clock clicks] technique within VPE to measure the time needed to assign a single variable.

VPE Action pattern:

START -> Var Assign -> iRule Action -> MSGBox -> Var Assign -> iRule Action -> MSGBox -> Var Assign -> iRule Action -> DENY

Var Assign Actions:

start = clock clicks
stop = clock clicks

And the use an iRule event to calculate and log the time taken:

when ACCESS_POLICY_AGENT_EVENT {
    set start [ACCESS::session data get "start"]
    set stop [ACCESS::session data get "stop"]
    log local0.debug "We are on TMM[TMM::cmp_unit] now. Assignment took [expr { $stop - $start }] clicks"
}

Note: I didn't tested this before. I may be that APMs caching mechanism will produce some very strange results. But give it a try and report back the results...

Cheers, Kai

0
Comment made 2 days ago by Stanislas Piron 6170

I did this test:

START -> iRule Event -> Var Assign -> MSGBox -> DENY

In variable assign I configured :

  • session.custom.start = clock clicks
  • session.custom.stop = clock clicks
  • session.custom.clicks = expr {[mcget {session.custom.stop}] - [mcget {session.custom.start}]}

The message box text is :

Variable assignment took %{session.custom.clicks} clicks

each time I evaluate the access policy

  • I had a value around 10 - 18 clicks
  • irule event on different TMM calculated around 1000 clicks

I guess that assigning variable session.custom.start count as an assignment operation

I also tried with following test:

START -> iRule Event -> Var Assign1 -> Var Assign2 -> MSGBox -> DENY

In Var Assign1

  • session.custom.start = clock clicks

In Var Assign2

  • session.custom.stop = clock clicks
  • session.custom.clicks = expr {[mcget {session.custom.stop}] - [mcget {session.custom.start}]}

each time I evaluate the access policy, I had a value less than around 20-25 clicks

0
Comment made 2 days ago by Kai Wilke 6258

Hi Stanislas,

both of your VPE patterns will most likely become executed on a single TMM core without any parkings. The reason for that is, that the client will most likely open just a single TCP connection (aka. the initial /landingpage request followed by a /my.policy redirect) and therefor stick to the TMM which has created the SID.

If the client performs a page impression on either the Login or a MSGBox pages, it will most likely open additional TCP connections to request multiple web object simultaniously (e.g. CSS, JS, grafics). After the client has opened and also keep-alived more than one TCP session you can't control which TCP session the client will use to further interact with the VPE policy. And if the client choses a TCP session that is handled by a different TMM then TMM parkings will ocour!

This is the reason I've chained multiple MSGBoxes/iRule Events in my example. The first iRule event is always handled on the TMM that has created the APM session without any parkings. But the later events are getting RR'ed...

Cheers, Kai

0
Comment made 2 days ago by Stanislas Piron 6170

The first iRule event is always handled on the TMM that has created the APM session without any parkings.

I disagree! In my tests, I had only

START -> iRule Event -> DENY

and irule event was handled by the other TMM.

I also tried this

START -> iRule Event -> Logon page -> Var Assign1 -> Var Assign2 -> MSGBox -> DENY

variable assign only took around 20-25 clicks (I tried 15 times)

And the last test:

START -> Logon page -> Var Assign1 -> iRule Event -> Var Assign2 -> MSGBox -> DENY

Result in iRule :

tmm[12133]: Rule /Common/apm_session_perfs <ACCESS_POLICY_AGENT_EVENT>: We are on TMM0 now. ACCESS command took 1064 clicks

Result in Message box :

the variable assign took 8448 clicks

Values I had were between 3000 and 9000 clicks (20 attempts)

So according to my tests, iRule Event is really bad, Variable assign is much better :-)

0
Comment made 2 days ago by Kai Wilke 6258

Please make sure to close the browser after each test to kill any keep-alive sessions. Other wise the initial redirect to /my.policy may already be send over a different keep-alive connection.

In addition on my box iRule assigment is more often much faster than variable assign? Strange...

Cheers,Kai

0
Comment made 1 day ago by Stanislas Piron 6170

Kai,

Do you agree with this scenario?

VPE

START -> Logon page -> Var Assign1 -> iRule Event -> Var Assign2 -> Var Assign3 -> Allow

Var Assign1

  • session.custom.start = clock clicks

Var Assign2

  • session.custom.stop = clock clicks
  • session.custom.clicks_event = expr {[mcget {session.custom.stop}] - [mcget {session.custom.start}]}
  • session.custom.start = clock clicks

Var Assign3

  • session.custom.stop = clock clicks
  • session.custom.clicks_variable_assign = expr {[mcget {session.custom.stop}] - [mcget {session.custom.start}]}

iRule assigned to the VS

when ACCESS_SESSION_STARTED {
    ACCESS::session data set "session.custom.landing_tmm" [TMM::cmp_unit]
}
when ACCESS_POLICY_AGENT_EVENT {
    set start [clock clicks]
    set test [ACCESS::session data get "session.server.landinguri"]
    set stop [clock clicks]
    ACCESS::session data set "session.custom.clicks_access_event" [expr {$stop - $start}]
    ACCESS::session data set "session.custom.event_tmm" [TMM::cmp_unit]
}

when ACCESS_ACL_ALLOWED {
    ACCESS::respond 200 content "
                <html>
                    <head><title>Authenticated</title></head>
                <body>
                    <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                    <p>Landing TMM  : <b>TMM[ACCESS::session data get "session.custom.landing_tmm"]</b></p>
                    <p>iRule Event TMM  : <b>TMM[ACCESS::session data get "session.custom.event_tmm"]</b></p>
                    <p>ACCESS::session in iRule Event took : <b>[ACCESS::session data get "session.custom.clicks_access_event"]</b> clicks</p>
                    <p>iRule Event took : <b>[ACCESS::session data get "session.custom.clicks_event"]</b> clicks (including 3 ACCESS::session commands)</p>
                    <p>Variable Assign took : <b>[ACCESS::session data get "session.custom.clicks_variable_assign"]</b> clicks</p>

                </body>
                </html>
    " noserver
}

tests with curl (to be sure tcp connection is closed between every requests)

$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM0</b></p>
                <p>iRule Event TMM  : <b>TMM1</b></p>
                <p>ACCESS::session in iRule Event took : <b>308</b> clicks</p>
                <p>iRule Event took : <b>3245</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>15</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>1078</b> clicks</p>
                <p>iRule Event took : <b>10582</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>11</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>1057</b> clicks</p>
                <p>iRule Event took : <b>11535</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>16</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>1098</b> clicks</p>
                <p>iRule Event took : <b>10511</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>17</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>1088</b> clicks</p>
                <p>iRule Event took : <b>8169</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>15</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>305</b> clicks</p>
                <p>iRule Event took : <b>6264</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>17</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>301</b> clicks</p>
                <p>iRule Event took : <b>3056</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>15</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>303</b> clicks</p>
                <p>iRule Event took : <b>3301</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>14</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>1060</b> clicks</p>
                <p>iRule Event took : <b>10369</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>16</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>1058</b> clicks</p>
                <p>iRule Event took : <b>11514</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>16</b> clicks</p>

            </body>
            </html>
$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM1</b></p>
                <p>iRule Event TMM  : <b>TMM0</b></p>
                <p>ACCESS::session in iRule Event took : <b>307</b> clicks</p>
                <p>iRule Event took : <b>3064</b> clicks (including 3 ACCESS::session commands)</p>
                <p>Variable Assign took : <b>16</b> clicks</p>

            </body>
            </html>
0
Comment made 1 day ago by Kai Wilke 6258

Hi Stanislas,

I really don't get the point of what you're trying to achive with this test and what you're trying to prove?

Note: Before comparing an Apple and Oranges you should make sure that the method to measure is the same. I didn't digged into this in detail, but I know from previous projects that iRules and VPEs [clock clicks] commands are very much different (64-bit vs. 32bit scale).

Cheers, Kai

0
Comment made 1 day ago by Stanislas Piron 6170

I'm trying to prove that irule event performances to set APM variables is worse than variable assign.

To be sure clock clicks can be compared between VPE and irule, I changed the display message:

<p>Variable Assign took : <b>[ACCESS::session data get "session.custom.clicks_variable_assign"]</b> clicks</p>
<p>VPE Clock click result : <b>[ACCESS::session data get "session.custom.stop"]</b></p>
<p>irule Clock click result: <b>[clock clicks]</b></p>
<p>Variable Assign took : <b>[expr {[ACCESS::session data get "session.custom.stop"] - [ACCESS::session data get "session.custom.start"]}]</b> clicks (calculated in irule)</p>

And I got similar values

<p>Variable Assign took : <b>16</b> clicks</p>
<p>VPE Clock click result : <b>1511342467891802</b></p>
<p>irule Clock click result: <b>1511342467989463</b></p>
<p>Variable Assign took : <b>16</b> clicks (calculated in irule)</p>

So it seems that VPE and irule clock clicks format are the same.

0
Comment made 1 day ago by Stanislas Piron 6170

I also changed the irule code to calculate where there is performance degradation:

when ACCESS_SESSION_STARTED {
    ACCESS::session data set "session.custom.landing_tmm" [TMM::cmp_unit]
}
when ACCESS_POLICY_AGENT_EVENT {
    ACCESS::session data set "session.custom.begin_irule_event" [clock clicks]
    ACCESS::session data set "session.custom.event_tmm" [TMM::cmp_unit]
    ACCESS::session data set "session.custom.end_irule_event" [clock clicks]
}

when ACCESS_ACL_ALLOWED {
    set irule_event_init_clicks [expr {[ACCESS::session data get "session.custom.begin_irule_event"] - [ACCESS::session data get "session.custom.before_irule_event"]}]
    set irule_event_end_clicks [expr {[ACCESS::session data get "session.custom.after_irule_event"] - [ACCESS::session data get "session.custom.end_irule_event"]}]
    set irule_event_total_clicks [expr {[ACCESS::session data get "session.custom.after_irule_event"] - [ACCESS::session data get "session.custom.before_irule_event"]}]
    set variable_assign_clicks [expr {[ACCESS::session data get "session.custom.after_variable_assign"] - [ACCESS::session data get "session.custom.before_variable_assign"]}]
    ACCESS::respond 200 content "
                <html>
                    <head><title>Authenticated</title></head>
                <body>
                    <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                    <p>Landing TMM  : <b>TMM[ACCESS::session data get "session.custom.landing_tmm"]</b></p>
                    <p>iRule Event TMM  : <b>TMM[ACCESS::session data get "session.custom.event_tmm"]</b></p>
                    <p>iRule Event init took : <b>$irule_event_init_clicks</b> clicks</p>
                    <p>iRule Event end took : <b>$irule_event_end_clicks</b> clicks</p>
                    <p>iRule Event total took : <b>$irule_event_total_clicks</b> clicks</p>
                    <p>Variable Assign took : <b>$variable_assign_clicks</b> clicks</p>
                </body>
                </html>" noserver
}

the problem is not only ACCESS::session only but the whole ACCESS_POLICY_AGENT_EVENT usage which consume too much clicks

<html>
    <head><title>Authenticated</title></head>
<body>
    <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
    <p>Landing TMM  : <b>TMM0</b></p>
    <p>iRule Event TMM  : <b>TMM1</b></p>
    <p>iRule Event init took : <b>2919</b> clicks</p>
    <p>iRule Event end took : <b>3439</b> clicks</p>
    <p>iRule Event total took : <b>8423</b> clicks</p>
    <p>Variable Assign took : <b>11</b> clicks</p>
</body>
0
Comment made 1 day ago by Kai Wilke 6258

Hi Stanislas,

well, I highly doubt that executing an iRule event out of VPE (this takes time and CPU overhead too) just for setting an variable could be any faster than just staying within VPE and setting the variable. But you may test this out to get some acurate numbers to prove this expectations...

To isolate the test further, I would recommend to make a test to figure out the added delay (not overhead!) of launching an iRule event...

START -> VAR (setting start) -> iRule event (empty iRule) -> VAR (setting stop) -> MSGBox (display result) -> Deny

Note: You may extent this test to see if the result are getting different if the TMM has changed during evaluation.

Then measure the creation of a single session variable (using VPE and TMM) and collect the results for the individual "Initial TMM <-> Processing TMM" combinations. I would love to see if if VPE would also causes parking situations as iRule events do...

Cheers, Kai

0
Comment made 1 day ago by Kai Wilke 6258

Note: Did a quick test on an old v12 strongbox lab unit. The [clock clicks] formats are indeed different on my box ( VPE: 1561357669 | iRule: 1511344718244157). So are you testing on a v13 unit?

Cheers, Kai

0
Comment made 1 day ago by Stanislas Piron 6170

I'm testing on a v13.1 VE.

0
Comment made 1 day ago by Kai Wilke 6258

Just saw you last comment. Well you already had the same idea to further isolate the test setup... ;-)

And again, consuming lots of clicks is not a problem if the comsumed time is caused by parkings. (Delay =/= CPU overhead)

Cheers, Kai

0
Comment made 1 day ago by Stanislas Piron 6170

to force to stay on the same TMM, I inserted the clientless-mode header in curl:

$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ -H "clientless-mode: 1" ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

    <html>
        <head><title>Authenticated</title></head>
    <body>
        <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
        <p>Landing TMM  : <b>TMM1</b></p>
        <p>iRule Event TMM  : <b>TMM1</b></p>
        <p>iRule Event init took : <b>2431</b> clicks</p>
        <p>iRule Event end took : <b>1139</b> clicks</p>
        <p>iRule Event total took : <b>3586</b> clicks</p>
        <p>Variable Assign took : <b>24</b> clicks</p>
    </body>

the irule event data set is quick, but the init / end irule call cause performance impact.

Here is the test without irule Event code

when ACCESS_SESSION_STARTED {
    ACCESS::session data set "session.custom.landing_tmm" [TMM::cmp_unit]
}


when ACCESS_ACL_ALLOWED {
    set irule_event_total_clicks [expr {[ACCESS::session data get "session.custom.after_irule_event"] - [ACCESS::session data get "session.custom.before_irule_event"]}]
    set variable_assign_clicks [expr {[ACCESS::session data get "session.custom.after_variable_assign"] - [ACCESS::session data get "session.custom.before_variable_assign"]}]
    ACCESS::respond 200 content "
                <html>
                    <head><title>Authenticated</title></head>
                <body>
                    <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                    <p>Landing TMM  : <b>TMM[ACCESS::session data get "session.custom.landing_tmm"]</b></p>
                    <p>iRule Event TMM  : <b>TMM[ACCESS::session data get "session.custom.event_tmm"]</b></p>
                    <p>iRule Event total took : <b>$irule_event_total_clicks</b> clicks</p>
                    <p>Variable Assign took : <b>$variable_assign_clicks</b> clicks</p>
                </body>
                </html>" noserver
} 

and the result is :

$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ -H "clientless-mode: 1" ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null


            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM0</b></p>
                <p>iRule Event TMM  : <b>TMM</b></p>
                <p>iRule Event total took : <b>9448</b> clicks</p>
                <p>Variable Assign took : <b>16</b> clicks</p>
            </body>
            </html>

$ rm session-cookies ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/ -H "clientless-mode: 1" ; curl -k -L -c session-cookies -b session-cookies https://192.168.2.6/vdesk/hangup.php3 -s > /dev/null

            <html>
                <head><title>Authenticated</title></head>
            <body>
                <p>You are authenticated successfuly : <b><a href='/vdesk/hangup.php3'>Disconnect here</a></b></p>
                <p>Landing TMM  : <b>TMM0</b></p>
                <p>iRule Event TMM  : <b>TMM</b></p>
                <p>iRule Event total took : <b>3579</b> clicks</p>
                <p>Variable Assign took : <b>16</b> clicks</p>
            </body>
            </html>
0
Comment made 1 day ago by Kai Wilke 6258

This alligns with my test results now. As long as the processing TMM is the same that initiates the APM session a single ACCESS::session variable assigment is somewhat quick!

Cheers, Kai

0
Comment made 1 day ago by Kai Wilke 6258

but the init / end irule call cause performance impact.

You can't judge on this rigth now. It adds undoubly a "delay" but you can't tell if this causes a "performance impact" until you've stress tested the individual setups.

Cheers, Kai

0
Comment made 1 day ago by Stanislas Piron 6170

I agree performance impact is not the right word. maybe latency.

I have a customer which too much ACCESS::session commands caused TCP reset because of timeout during suspended irule. (50K concurrent access session)

that's why I'm working on which function park connection.

I replaced variable assign clock clicks to clock clicks -milliseconds

Irule event suspends access policy evaluation during at least 5 milliseconds. (I am the only one user on the platform) when variable assign is done in less than 1 millisecond.

The goal of the last test since you gave me the right answer of the original question is to prove that irule event is not a good idea for several reasons:

  • irule event cause more latency than variable assign
  • irule event doesn't update session variable cache is the variable changed in ACCESS_POLICY_AGENT_EVENT already exists
  • multiple irule events in the same policy share the same code. you have to first check the event ID which may cause more latency if on different TMM.

To prevent this,

  • you showed me that ACCESS::session commands in ACCESS_SESSION_STARTED doesn't suspend irule execution because it is on the same TMM. provisioning several variables in this event doesn't have too much impact.
  • Variable assign is as quick as setting variables in ACCESS_SESSION_STARTED event.

Now, I have to evaluate if variable assign expressions with several commands are as performant as same commands in irule.

0
Comment made 1 day ago by Kai Wilke 6258

Hi Stanislas,

I have a customer which too much ACCESS::session commands caused TCP reset because of timeout during suspended irule. (50K concurrent access session)

that's why I'm working on which function park connection.

In my opinion you should consider and analyse those three things:

  1. Having many concurrent session may degrate performance, since you have to store, maintain and search through a lot of session data.
  2. Having many concurrent VPE evaluatation per second may dramatically degrate performance, since it involves certain heavy liftings (LDAP seaches/auth, GA-Checks, etc.)
  3. Having many request per second from authenticated users may dramatically degrate performance if a single request requires lots of APM session lookups and/or manipulations.

I don't think that 1.) has a that big impact on the overall performance, since I've already tested rather small 1600th units with a couple million of [table] entries and/or variables set at the same time without experiencing any noticable hard/soft caps. It seems its a nobrainer for TMOS till the entire RAM was exhausted.

When using 50k long living concurrent APM sessions, the overhead of 2.) will be most likely rather small compared to the overhead of 3.). But for short living APM session 2.) may have a bigger impact than 3.).

Depending on your APM session usage, you should spend your time for optimizing either 2.), 3.) or both of them.

The VPE policy and also certain per-request lookups may be offloaded by implementing certain short living caches (via $static::namespace variables or local TMM [table -subtable] information) so that consecutive authentications of the same username/password or session lookups require much less CPU cycles and/or don't cause frequent TMM parking situations.

But you have to understand the traffic pattern at first, to find the juice spots in your setup where optimizations would benefit you the most.

Well, alternatively you can skip all this stuff and simply buy a stronger plattform... ;-)

Cheers, Kai

0
Comment made 1 day ago by Stanislas Piron 6170

to support 50K Access sessions, only 102X0 or VIPRION appliance were available when customer bought the appliances (4 years ago).

we are working on 10250 appliance which support up to 60K access session and can be upgraded to 500K

The Sharepoint irule is evaluated for 95% of HTTP requests. when I had to write it, evaluating ACCESS::session once per request caused TCP reset. that's how I discovered the irule suspended issue and optimized the code.

In Agility 2017, I discovered that instead of inserting HTTP header within ACCESS_ACL_ALLOWED based on session variable, we can use Per-request policy to do the same. F5 team confirm then it's much more performant than I did previously.

I'm not searching how to solve an issue but want to extend my knowledge on how to optimize performances.

0
Comment made 22 hours ago by Kai Wilke 6258

Hi Stanislas,

The Sharepoint irule is evaluated for 95% of HTTP requests. when I had to write it, evaluating ACCESS::session once per request caused TCP reset. that's how I discovered the irule suspended issue and optimized the code.

The apmstatus, apmpersiststatus and basic auth sections can be improved by implementing certain short living caches to offload the ACCESS::session execution for subsequent request. In addition to that you can optimize the performance of the controll structure by copy and pasting the same code over and over again (Yeah, I know you realy hate redundant code blocks, but its performance wise absolutely the best choice.)

In Agility 2017, I discovered that instead of inserting HTTP header within ACCESS_ACL_ALLOWED based on session variable, we can use Per-request policy to do the same.

Gosh, you must be getting old in the mean time. I was the cool guy sitting next to you and we already discussed this topic from face to face. Remember? :-)

Cheers, Kai

0