The finally section

Syntax

finally [<request-type>] {
    [ statements ]
}

Description

The finally { … } section allows you to configure any logging or cleanup which is necessary before the request returns from the virtual server. For example, if you wish to log all requests and responses that enter a virtual server, you could place a single call to linelog in the finally section.

The finally { … } section is executed as the last thing before a request returns from a virtual server. The finally section is always executed, whether the request was accepted, rejected or it timed out.

The <request-type> qualifier can be any valid request type for current namespace of the virtual server. If no there is no finally <request-type> { … } section, then the unqualified finally { … } section is run.

Example of using unqalified finally

# Is processed first
recv Access-Request {
    ...
}

# Is processed second
send Access-Accept {
    ...
}

# Is processed last
finally {
    linelog.log("Sending %{reply.Packet-Type} to %{NAS-IP-Address}")
}

Example of using qualified finally

# Is processed first
recv Access-Request {
    ...
}

# Is processed second
send Access-Accept {
    ...
}

# Is processed last, for all replies to Access-Request packets,
# including "Do-Not-Respond"
finally Access-Request {
    linelog.log("Sending %{reply.Packet-Type} in response to Access-Request to %{NAS-IP-Address}")
}

# Is process last for all other packet types, including
# Accounting-Request.
finally {
    ...
}

Return Codes

Each recv … and send … section finishes with a return code. These return codes are available at the start of the finally section.

Similarly, the finally section also ends with a return code, which is in some cases visible to a parent virtual server.

At the start of "finally"

Return codes can be checked within the finally section by using return code expressions. These checks allow the finally section to perform different actions based on the result of the protocol state machine.

Example of calling different modules based on the previous rcode

# Is processed first
recv Access-Request {
	...
}

# Is processed second
send Access-Accept {
	ok
}
# returns `ok`

# Is processed last
finally {
    if (ok || updated) {
        linelog.log("Request succeeded")
    } else {
	linelog.log("Request failed")
    }
}

At the end of "finally".

Once a finally section is finished, it will result in a return code. In most cases, this return code is discarded, and has no effect on any subsequent packet processing.

That is, the return code of a finally section will not modify the response packet type from the virtual server. If finally returns reject, then nothing will happen, and the server will not send an Access-Reject response to an Access-Accept request. This behavior is because finally section is run after the protocol state machine has completed.

However, the return code of a finally is available to a parent virtual server, when one virtual server uses call to run another virtual server.

Timeouts

The finally section is executed even if the request times out. Requests terminated by a timeout will return the timeout return code. This condition can be checked with if (timeout) at the start of the finally section.

Request which are being processed in a finally section will not stop until the finally section is done. The max_request_time configuration applies only to normal processing of requests, and not to finally sections. This behavior is necessary in order for the finally section to catch a max_request_time timeout.

We recommend doing as little as possible in a finally section. Logging a short message to disk will be safe. Logging complex messages to an SQL database or to a REST API will likely be problematic. This issue is not because FreeRADIUS has any problem running the sql module in a finally section, it doesn’t. The finally section is just another processing section, and runs exactly the same as a recv or send section.

The problem with running the sql module in the finally section is that there can be cascading chains of failure when something goes wrong. For example, if the server is configured to use log Accounting-Request packets to SQL for both normal accounting processing, and in the finally section, what happens when the SQL databsase is slow, or has an issue?

When the SQL database is slow, the Accounting-Request packet will fail to log anything to SQL and time out. When all processing for the Accounting-Request is done, the finally section will run, which will also try to log information to the same slow SQL database. The result will be doubled slow writes to SQL, or requests that never complete.

In order to ensure that the server remains responsive, the finally section should contain as little as possible. Any potentially long running module calls or dynamic expansions in a finally section should be wrapped in a timeout block:

Example of using timeout in finally

...
finally {
    timeout 0.1s {
        ...
    }
}

This configuration will ensure that the finally section is limited in how much time it spends processing a packet.

Subrequests

Where subrequest calls are used, the finally section in the parent will not be run until the subrequest has finished. However, a timeout in the parent will cause the child subrequest to be forcibly stopped, but the childs finally section will still run.

Timeouts in finally sections of subrequests should therfore be set extremely short, in order to ensure that the parent request isn’t cancelled due to an excessively long running subrequest.