# irule to log slow and/or tcp profile timed out requests to backend

**URL:** <https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428>\
**Category:** Technical Forums\
**Tags:** irules, ltm, application-delivery\
**Created:** [January 25, 2016, 3:27pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428 "2016-01-25T15:27:34Z")\
**Posts on this page:** 6\
**Page:** 1

<div class="post-metadata">

**Author:** ![ingard](https://avatars.discourse-cdn.com/v4/letter/i/4491bb/32.png) [@ingard](https://community.f5.com/u/ingard)\
**Post date:** [January 25, 2016, 3:27pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428/1 "2016-01-25T15:27:34Z")

</div>

Hi

I’m trying to identify which requests are causing our backends to stop responding/hang/fail. I was thinking some sort of timer and/or catch the tcp timeout rst maybe? I’ve been trying to figure out what event to attach this rule to and maybe it would be CLIENT\_CLOSED but I’m struggling to see how to go about this. I don’t want to log every request that ends with a client\_closed obviously, but only the ones where there is no response. Any ideas out there?

kind regards ingard

---

<div class="post-metadata">

**Author:** ![Kai\_Wilke](https://d1p9zq3aats0t8.cloudfront.net/user_avatar/community.f5.com/kai_wilke/32/24646_2.png) [@Kai\_Wilke](https://community.f5.com/u/Kai_Wilke)\
**Post date:** [January 25, 2016, 6:21pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428/2 "2016-01-25T18:21:07Z")

</div>

Hi Ingard,

unfortunately there is no way to access TCP flags (PSH, RST, etc.) using iRules.

But you may try this snipped as a starting point to identify slow server responses…

```tcl
when RULE_INIT {
    set static::timeout 10000 ; msec
}
when HTTP_REQUEST {
    set debug(request_url) "[HTTP::host][HTTP::uri]"
    set debug(id) [after $static::timeout {
            log local0.warn "$static::timeout msec timeout reached for \"$debug(request_url)\""
    }]
}
when HTTP_RESPONSE {
    after cancel $debug(id)
    unset -nocomplain debug
}
when CLIENT_CLOSED {
    if { [info exist debug(request_url)] } then {
        log local0.warn "Connection closed without HTTP response for \"$debug(request_url)\""
    }
}

```

Cheers, Kai

---

<div class="post-metadata">

**Author:** ![ingard](https://avatars.discourse-cdn.com/v4/letter/i/4491bb/32.png) [@ingard](https://community.f5.com/u/ingard)\
**Post date:** [February 1, 2016, 1:31pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428/3 "2016-02-01T13:31:13Z")

</div>

Hi Kai and thanks for this! We’re testing it right now. Do you know though, if there is any way to add which backend the request is sent to? I know we have variables like [LB::server addr]:[LB::server port], but they are not available in HTTP\_REQUEST. Would I be able to switch the logic in HTTP\_REQUEST to lets say LB\_SELECTED?

kind regards Ingard

---

<div class="post-metadata">

**Author:** ![Kai\_Wilke](https://d1p9zq3aats0t8.cloudfront.net/user_avatar/community.f5.com/kai_wilke/32/24646_2.png) [@Kai\_Wilke](https://community.f5.com/u/Kai_Wilke)\
**Post date:** [February 1, 2016, 2:11pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428/4 "2016-02-01T14:11:45Z")

</div>

Hi Ingard,

of course, you can also include other events and/or other variables to the log output.

Here is a quick sample using the **LB\_SELECTED** event to include the **[LB::server addr]** of the selected pool member…

```tcl
when RULE_INIT {
    set static::timeout 10000 ; msec
}
when LB_SELECTED {
    set debug(request_url) "[HTTP::host][HTTP::uri]"
    set debug(server_addr) "[LB::server addr]"
    set debug(id) [after $static::timeout {
            log local0.warn "$static::timeout msec timeout reached on Node \"$debug(server_addr)\" for \"$debug(request_url)\""
    }]
}
when HTTP_RESPONSE {
    after cancel $debug(id)
    unset -nocomplain debug
}
when CLIENT_CLOSED {
    if { [info exist debug(request_url)] } then {
        log local0.warn "Connection closed without HTTP response on Node \"$debug(server_addr)\" for \"$debug(request_url)\""
    }
}

```

Cheers, Kai

---

<div class="post-metadata">

**Author:** ![Kai\_Wilke](https://d1p9zq3aats0t8.cloudfront.net/user_avatar/community.f5.com/kai_wilke/32/24646_2.png) [@Kai\_Wilke](https://community.f5.com/u/Kai_Wilke)\
**Post date:** [February 2, 2016, 12:18pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428/5 "2016-02-02T12:18:41Z")

</div>

Hi Ingard,

I’ve added additional error handles to avoid any **can’t read “debug(xyz)”: no such variable** errors. In addition I’ve moved the **[after]** code to the **HTTP\_REQUEST\_SEND** event to not depend on the **LB\_SELECTED** getting triggered.

```tcl
when RULE_INIT {
    set static::timeout 10000 ; msec
}
when HTTP_REQUEST {
    set debug(request_url) "[HTTP::host][HTTP::uri]"
}
when HTTP_REQUEST_SEND {
    set debug(server_addr) "[LB::server addr]"
    set debug(id) [after $static::timeout {
        if { [info exist debug(server_addr)] and [info exist debug(request_url)] } then {
            log local0.warn "$static::timeout msec timeout reached on Node \"$debug(server_addr)\" for \"$debug(request_url)\""
        } elseif { [info exist debug(request_url)] } then {
            log local0.warn "$static::timeout msec timeout reached on Node \"UNKNOWN\" for \"$debug(request_url)\""
        }
    }]
}
when HTTP_RESPONSE {
    if { [info exist debug(id)] } then {
        after cancel $debug(id)
    }
    unset -nocomplain debug
}
when CLIENT_CLOSED {
    if { [info exist debug(server_addr)] and [info exist debug(request_url)] } then {
        log local0.warn "Connection closed without HTTP response on Node \"$debug(server_addr)\" for \"$debug(request_url)\""
    } elseif { [info exist debug(request_url)] } then {
        log local0.warn "Connection closed without HTTP response on Node \"UNKNOWN\" for \"$debug(request_url)\""
    }
}

```

Cheers, Kai

---

<div class="post-metadata">

**Author:** ![JRahm](https://d1p9zq3aats0t8.cloudfront.net/user_avatar/community.f5.com/jrahm/32/3327_2.png) [@JRahm](https://community.f5.com/u/JRahm)\
**Post date:** [December 20, 2022, 9:39pm UTC](https://community.f5.com/t/irule-to-log-slow-and-or-tcp-profile-timed-out-requests-to-backend/60428/6 "2022-12-20T21:39:10Z")

</div>

FYI&nbsp; @Kai_Wilke ,&nbsp;you can access the TCP flags in the FLOW\_INIT event with the [DATAGRAM::tcp flags](https://clouddocs.f5.com/api/irules/DATAGRAM__tcp.html) command.