testing ratelimiting

Hi,

I’m experimenting a bit with the ratelimit features in unbound (1.6.7),
I just configured example suggestions to see how it turns out.

server:
    ratelimit: 1000
    ip-ratelimit: 100

So for instance, I see this in the log:

Sep 3 08:43:09 rl-test unbound: [21732:0] notice: ratelimit exceeded 172.17.0.3 100
Sep 3 08:43:09 rl-test unbound: [21732:1] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:09 rl-test unbound: [21732:1] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:09 rl-test unbound: [21732:2] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:10 rl-test unbound: [21732:0] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:10 rl-test unbound: [21732:0] notice: ip_ratelimit allowed through for ip address 172.17.0.3

First line indicate that thread 0 reports that 172.17.0.3 exceeded the ip-ratelimit of 100 qps.
Second to sixth line indicate that thread 0-2 reports that the enforcement is released.

I'm thinking / wondering...
- Wouldn’t be good if first line could mention that it’s the ip-ratelimit that kicked in?
- Why the repeated/duplicate messages (logged the same second) about "allowed through” ? (bug?)

Thx,
/P

Hi Fredrik,

Hi,

I’m experimenting a bit with the ratelimit features in unbound (1.6.7),
I just configured example suggestions to see how it turns out.

server:
    ratelimit: 1000
    ip-ratelimit: 100

So for instance, I see this in the log:

Sep 3 08:43:09 rl-test unbound: [21732:0] notice: ratelimit exceeded 172.17.0.3 100
Sep 3 08:43:09 rl-test unbound: [21732:1] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:09 rl-test unbound: [21732:1] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:09 rl-test unbound: [21732:2] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:10 rl-test unbound: [21732:0] notice: ip_ratelimit allowed through for ip address 172.17.0.3
Sep 3 08:43:10 rl-test unbound: [21732:0] notice: ip_ratelimit allowed through for ip address 172.17.0.3

First line indicate that thread 0 reports that 172.17.0.3 exceeded the ip-ratelimit of 100 qps.
Second to sixth line indicate that thread 0-2 reports that the enforcement is released.

I'm thinking / wondering...
- Wouldn’t be good if first line could mention that it’s the ip-ratelimit that kicked in?

Yes, that would make the logging more consistent. I changed the log line
to "ip_ratelimit exceeded"

- Why the repeated/duplicate messages (logged the same second) about "allowed through” ? (bug?)

This is not the release of the limit but the queries that are allowed to
pass based on your ip-ratelimit-factor setting.

-- Ralph

Hi Ralph,

Yes, that would make the logging more consistent. I changed the log line
to "ip_ratelimit exceeded"

I have one other onservation. The option is called "ip-ratelimit" in the
config file (with a dash), but when logging, unbound logs it with
"ip_ratelimit", with an underscore.

This seems like a minor thing, but it's the kind of thing that people
could spend ages on. For example, a user might try to search for
"ip-ratelimit" in the log files, and see nothing, and realise much
later, with a lot of frustration, that the difference was that tiny.

Perhaps you want to consider logging as "ip-ratelimit" to match the
config option.

Regards,
Anand

Hi Ralph,