Help
CodeShare
Have some code. Share some code.
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
Technical Forum Quicklinks: No Replies | Active-Not Solved | Recent Solutions
Custom Alert Banner

F5 AppWorld 2024 session proposal deadline extended to Friday, December 8th!

iRule Event Order

Yann_Desmarest
Cirrus
Cirrus

on ‎05-Jun-2016 07:31 - edited on ‎05-Jun-2023 22:52 by Fog

Problem this snippet solves:

It's sometimes hard which event is triggered and in which order. This code provide visibility on the event order and time between each event in millisecond.

Possible (but not limited to) use cases :

  • Troubleshooting connection
  • Identify event triggered for specific requests
  • learn the order of irule events

How to use this snippet:

Installation

irule

You need to install the irule on the top of the list in your Virtual Server.

Special considerations

Irule Generator

the displayed irule has been generated with a proprietary tool developed in golang.

Zip file Content

The downloadable zip file contains :

  • a shell script that generate the irule code for the list of event specified in event_list.tcl file
  • a file that contain a list of all irule event (excluded : CLIENT_ACCEPTED, CLIENT_CLOSED, RULE_INIT)
  • an irule containing all possible events (generated by the script). Just for demo, can not be used in real life.

Compatibility

Supported in v12.1.0

  • ACCESS_PER_REQUEST_AGENT_EVENT
  • BOTDEFENSE_ACTION
  • BOTDEFENSE_REQUEST
  • WS_CLIENT_DATA
  • WS_CLIENT_FRAME
  • WS_CLIENT_FRAME_DONE
  • WS_REQUEST
  • WS_RESPONSE
  • WS_SERVER_DATA
  • WS_SERVER_FRAME
  • WS_SERVER_FRAME_DONE

Irule Events

The displayed irule currently support events from CLIENT_*, HTTP_*, LB_* and SSL_*. This irule should fit for most of the standard ltm use cases on http and https.

Outputs

syslog output :

virtual=/Common/vs_test_irule_order_event, id=d5f693399, time=0, event_order=0, event_type=CLIENT_ACCEPTED
virtual=/Common/vs_test_irule_order_event, id=d5f693399, time=0, event_order=1, event_type=CLIENTSSL_CLIENTHELLO
virtual=/Common/vs_test_irule_order_event, id=d5f693399, time=6, event_order=2, event_type=CLIENTSSL_HANDSHAKE
virtual=/Common/vs_test_irule_order_event, id=d5f693399, time=6, event_order=3, event_type=HTTP_REQUEST
virtual=/Common/vs_test_irule_order_event, id=d5f693399, time=6, event_order=4, event_type=LB_FAILED
virtual=/Common/vs_test_irule_order_event, id=d5f693399, time=6, event_order=5, event_type=CLIENT_CLOSED
`

JSON output : 

{
   "d5f693399": [
      {
         "virtual": "/Common/vs_test_irule_order_event",
         "id": "d5f693399",
         "time": "0",
         "event_order": "0",
         "event_type": "CLIENT_ACCEPTED"
      },
      {
         "virtual": "/Common/vs_test_irule_order_event",
         "id": "d5f693399",
         "time": "0",
         "event_order": "1",
         "event_type": "CLIENTSSL_CLIENTHELLO"
      },
      {
         "virtual": "/Common/vs_test_irule_order_event",
         "id": "d5f693399",
         "time": "6",
         "event_order": "2",
         "event_type": "CLIENTSSL_HANDSHAKE"
      },
      {
         "virtual": "/Common/vs_test_irule_order_event",
         "id": "d5f693399",
         "time": "6",
         "event_order": "3",
         "event_type": "HTTP_REQUEST"
      },
      {
         "virtual": "/Common/vs_test_irule_order_event",
         "id": "d5f693399",
         "time": "6",
         "event_order": "4",
         "event_type": "LB_FAILED"
      },
      {
         "virtual": "/Common/vs_test_irule_order_event",
         "id": "d5f693399",
         "time": "6",
         "event_order": "5",
         "event_type": "CLIENT_CLOSED"
      }
   ]
}

Features

Version 1.0

  • List Event order
  • Generate a sessionid to track the Client connection until it close
  • Display time elapsed since client has been accepted
  • Logging in JSON format (to use with third party libraries like d3.js)

Backlog

  • add logging using csv format
  • use HSL instead of local logging
  • add extra comments for specific events like CLIENT_CERT and LB_FAILED
  • add more events (security related events)
  • release a script to generate an irule that use events related to the other irules present in a Virtual Server

External links

Github : https://github.com/e-XpertSolutions/f5

iRule Sample

when RULE_INIT {
    set static::client_ip "192.168.10.1"
    set static::json 1
}

when CLIENT_ACCEPTED {
    set counter 0
    set event_type "CLIENT_ACCEPTED"
    set sessionid "[IP::client_addr][TCP::client_port][IP::local_addr][TCP::local_port][expr { int(100000000 * rand()) }]" 
    binary scan [md5 $sessionid] H* md5_string trash
    set md5_string [string range $md5_string 12 20]
    set start_time [clock clicks -milliseconds]
    log local0. "virtual=[virtual], id=$md5_string, time=0, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        set json_log "\{ \"$md5_string\": \[\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"0\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENT_CLOSED {
    set counter [expr { $counter+1 }]
    set event_type "CLIENT_CLOSED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\}\]\}"
        log local0. "$json_log"
    }
}

when HTTP_REQUEST {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_REQUEST"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_REQUEST_RELEASE {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_REQUEST_RELEASE"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_RESPONSE {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_RESPONSE"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_RESPONSE_RELEASE {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_RESPONSE_RELEASE"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_RESPONSE_CONTINUE {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_RESPONSE_CONTINUE"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_REQUEST_SEND {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_REQUEST_SEND"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_REQUEST_DATA {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_REQUEST_DATA"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENT_DATA {
    set counter [expr { $counter+1 }]
    set event_type "CLIENT_DATA"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_PROXY_REQUEST {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_PROXY_REQUEST"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when HTTP_DISABLED {
    set counter [expr { $counter+1 }]
    set event_type "HTTP_DISABLED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVER_CLOSED {
    set counter [expr { $counter+1 }]
    set event_type "SERVER_CLOSED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVER_DATA {
    set counter [expr { $counter+1 }]
    set event_type "SERVER_DATA"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVERSSL_DATA {
    set counter [expr { $counter+1 }]
    set event_type "SERVERSSL_DATA"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVER_CONNECTED {
    set counter [expr { $counter+1 }]
    set event_type "SERVER_CONNECTED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENTSSL_DATA {
    set counter [expr { $counter+1 }]
    set event_type "CLIENTSSL_DATA"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENTSSL_CLIENTCERT {
    set counter [expr { $counter+1 }]
    set event_type "CLIENTSSL_CLIENTCERT"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENTSSL_CLIENTHELLO {
    set counter [expr { $counter+1 }]
    set event_type "CLIENTSSL_CLIENTHELLO"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENTSSL_HANDSHAKE {
    set counter [expr { $counter+1 }]
    set event_type "CLIENTSSL_HANDSHAKE"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when CLIENTSSL_SERVERHELLO_SEND {
    set counter [expr { $counter+1 }]
    set event_type "CLIENTSSL_SERVERHELLO_SEND"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVERSSL_CLIENTHELLO_SEND {
    set counter [expr { $counter+1 }]
    set event_type "SERVERSSL_CLIENTHELLO_SEND"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVERSSL_HANDSHAKE {
    set counter [expr { $counter+1 }]
    set event_type "SERVERSSL_HANDSHAKE"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when SERVERSSL_SERVERHELLO {
    set counter [expr { $counter+1 }]
    set event_type "SERVERSSL_SERVERHELLO"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

when LB_QUEUED {
    set counter [expr { $counter+1 }]
    set event_type "LB_QUEUED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
} 

when LB_FAILED {
    set counter [expr { $counter+1 }]
    set event_type "LB_FAILED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
} 

when LB_SELECTED {
    set counter [expr { $counter+1 }]
    set event_type "LB_SELECTED"
    set curtime [expr { [clock clicks -milliseconds] - $start_time }]
    log local0. "virtual=[virtual], id=$md5_string, time=$curtime, event_order=$counter, event_type=$event_type"
    if { $static::json } {
        append json_log "\{\"virtual\":\"[virtual]\", \"id\":\"$md5_string\", \"time\":\"$curtime\", \"event_order\":\"$counter\", \"event_type\":\"$event_type\"\},"
    }
}

Code :

68686

Tested this on version:

11.5
0 Kudos
Comments
AngelRosales_27
Nimbostratus
Nimbostratus
‎20-Jun-2016 15:32
Hello, I´m new in iRule, i undesrtand programing in general, but this lenguage is very very diferent, because involves networks, can you tell me in where page i can learned?. sorry to my english. thank you
0 Kudos
Yann_Desmarest
Cirrus
Cirrus
‎20-Jun-2016 23:45

Hi,

you can have a look at following url:

https://devcentral.f5.com/s/question/0D51T00006i7X94/irule-event-order-http

0 Kudos
keithhubb
F5 Employee
F5 Employee
‎05-Sep-2019 10:39

Yann, can you make that zipfile available on your github page, or re-upload here?

0 Kudos
Version history
Last update:
‎05-Jun-2023 22:52
Updated by:
Fog
Copyright © 2023 Khoros, LLC