10.1 Rule Tracing

If you have more than one entry in your `users' file it is not always obvious which of the entries were used for authentication. The authentication data flow becomes even harder to understand if there are some complex rules in the `hints' and `huntgroups' files.

The rule tracing mode is intended to help you find out the exact order of the rules that each request matched during processing. The mode is toggled by trace-rules statement in auth or acct block of your `config' file. When rule tracing mode is on for a given type of requests, radiusd will display the data flow diagram for each processed request of this type. The diagram is output on info logging category, it represents the list of rules in reverse chronological order. Each rule is represented by its location in the form filename:line. To make the output more compact, if several rules appear in the same configuration file, their locations are listed as a comma-separated list of numbers after the file name. Furthermore, if the configuration files have the same path prefix, then only the first file name appears with the full prefix.

Here is an example of trace rule diagram:

Oct 31 11:37:17 [28322]: Auth.info: (Access-Request foo 170 bar): rule trace: /etc/raddb/users:157,22,3; huntgroups:72; hints:34

This diagram means, that the authentication request from server `foo' for user `bar' with ID 170 matched the following rules

File name	Line number
`/etc/raddb/hints'	34
`/etc/raddb/huntgroups'	72
`/etc/raddb/users'	3
`/etc/raddb/users'	22
`/etc/raddb/users'	157

As a practical example, let's suppose you have the following setup. There are three classes of users:

1. Users from group "root" are authenticated using system password database and get rlogin access to the server 192.168.10.1
2. Users from group "staff" are also authenticated using system password database, but they are granted only telnet access to the server 192.168.10.2
3. Finally, the rest of users is authenticated against SQL database and get usual PPP access.

In addition, users from the first two classes are accounted using custom Scheme procedure staff-acct.

The configuration files for this setup are showed below:

Contents of `hints':

DEFAULT Group = "root" Scheme-Acct-Procedure = "staff-acct", Hint = "admin" DEFAULT Group = "staff" Scheme-Acct-Procedure = "staff-acct", Hint = "staff"

Contents of file `users':

DEFAULT Auth-Type = SQL, Simultaneous-Use = 1 Service-Type = Framed-User, Framed-Protocol = PPP DEFAULT Hint = "admin", Auth-Type = System Service-Type = Login-User, Login-IP-Host = 192.168.0.1, Login-Service = Rlogin DEFAULT Hint = "staff", Auth-Type = System, Simultaneous-Use = 1 Service-Type = Login-User, Login-IP-Host = 192.168.0.2, Login-Service = Telnet

Now, let's suppose that user `svp' is in the group `staff' and is trying to log in. However, he fails to do so and in radiusd logs you see:

Nov 06 21:25:24: Auth.notice: (Access-Request local 61 svp): Login incorrect [svp]

Why? To answer this question, you add to auth block of your `config' the statement

trace-rules yes;

and ask user `svp' to retry his attempt. Now you see in your logs:

Nov 06 21:31:24: Auth.notice: (Access-Request local 13 svp): Login incorrect [svp] Nov 06 21:31:24: Auth.info: (Access-Request local 13 svp): rule trace: /etc/raddb/users:1, hints: 5

This means that the request for `svp' has first matched rule on the line 1 of file `hints', then the rule on line 1 of file `users'. Now you see the error: the entries in `users' appear in wrong order! After fixing it your `users' looks like:

DEFAULT Hint = "admin", Auth-Type = System Service-Type = Login-User, Login-IP-Host = 192.168.0.1, Login-Service = Rlogin DEFAULT Hint = "staff", Auth-Type = System, Simultaneous-Use = 1 Service-Type = Login-User, Login-IP-Host = 192.168.0.2, Login-Service = Telnet DEFAULT Auth-Type = SQL, Simultaneous-Use = 1 Service-Type = Framed-User, Framed-Protocol = PPP

Now, you ask `svp' to log in again, and see:

Nov 06 21:35:14: Auth.notice: (Access-Request local 42 svp): Login OK [svp] Nov 06 21:35:14: Auth.info: (Access-Request local 42 svp): rule trace: /etc/raddb/users:7, hints: 5

Let's also suppose that user `plog' is not listed in groups "root" and "staff", so he is supposed to authenticate using SQL. When he logs in, you see in your logs:

Nov 06 21:39:05: Auth.notice: (Access-Request local 122 plog): Login OK [svp] Nov 06 21:39:05: Auth.info: (Access-Request local 122 plog): rule trace: /etc/raddb/users:14