Rate limiting? - Githubissues

linusgke commented 1 year ago

I just recently encountered a problem, where after some reloads via F5 all requests to /api/auth/login result in a HTTP403: This happens absolutely randomly! The credentials don't change – sometimes logging-in works, but after some requests it fails again… I'm a bit clueless of what to do with that kind of issue!

Is there any information on rate-limits blocking requests after a threshold is reached? That's the only thing I could imagine…

Hardware/Software:

UniFi Network 7.4.156
running on UniFi OS 3.1.9
on a UCK G2 Plus

Debug information below:

-----------LOGIN-------------
Array
(
    [url] => https://192.168.49.1/api/auth/login
    [content_type] => application/json; charset=utf-8
    [http_code] => 403
    [header_size] => 576
    [request_size] => 195
    [filetime] => -1
    [ssl_verify_result] => 18
    [redirect_count] => 0
    [total_time] => 0.316588
    [namelookup_time] => 2.0E-5
    [connect_time] => 2.0E-5
    [pretransfer_time] => 4.7E-5
    [size_upload] => 44
    [size_download] => 82
    [speed_download] => 259
    [speed_upload] => 138
    [download_content_length] => 82
    [upload_content_length] => 44
    [starttransfer_time] => 4.7E-5
    [redirect_time] => 0
    [redirect_url] => 
    [primary_ip] => 192.168.49.1
    [certinfo] => Array
        (
        )

    [primary_port] => 443
    [local_ip] => 192.168.52.91
    [local_port] => 47192
    [http_version] => 3
    [protocol] => 2
    [ssl_verifyresult] => 0
    [scheme] => HTTPS
    [appconnect_time_us] => 21
    [connect_time_us] => 20
    [namelookup_time_us] => 20
    [pretransfer_time_us] => 47
    [redirect_time_us] => 0
    [starttransfer_time_us] => 47
    [total_time_us] => 316588
)

----------RESPONSE-----------
{"code":"AUTHENTICATION_FAILED","message":"Authentication failed","level":"debug"}
-----------------------------

malle-pietje commented 1 year ago

From my experience the Network Application on CloudKeys is bit underpowered, so I am not that surprised this is happening. That being said, I myself have not yet seen this happen on UDM's or correctly sized software-based controllers.

My recommendation is to review the server.log and mongod.log files on the CloudKey's filesystem to see if there any clues to be found there.

Another recommendation is to use the cookies whenever possible; the login can take up to 30-40% of the total request time. Obviously depending on the endpoints.

Have a look at the implementation of cookies in the API Browser tool for some hints. https://github.com/Art-of-WiFi/UniFi-API-browser

I'd be curious to hear whether the API Browser tool also experiences these errors or not...

linusgke commented 1 year ago

Thanks for your detailed and quick reply!

The CloudKey is very slow at times, and we'll maybe switch to a self-hosted and more performant system. But for now, we'll have to stick with what we have...

I implemented cookies, which greatly improved overall performance. Sadly, it didn't resolve the AUTHENTICATION_FAILED issue... It's probably a bit less frequent now, but still interferes with a good user experience.

server.log (using tail -f | grep api) does not contain any errors, whatsoever.

A sample:

root@Waldorf-Augsburg:/usr/lib/unifi/logs# tail -f server.log | grep api
[2023-06-21 12:03:22,968] <webapi-666> DEBUG api    - /api/ucore/status finished (26 handling, 0 rendering)
[2023-06-21 12:03:32,840] <webapi-669> DEBUG api    - /api/s/default/stat/voucher finished (4 handling, 1 rendering)
[2023-06-21 12:03:37,676] <webapi-666> DEBUG api    - /api/s/default/rest/account finished (94 handling, 2 rendering)
[2023-06-21 12:03:37,798] <webapi-669> DEBUG api    - /api/s/default/stat/alluser finished (64 handling, 34 rendering)
[2023-06-21 12:03:37,873] <webapi-666> DEBUG api    - /api/s/default/stat/sta/ finished (23 handling, 20 rendering)
[2023-06-21 12:03:37,970] <webapi-669> DEBUG api    - /api/ucore/status finished (22 handling, 0 rendering)
[2023-06-21 12:03:52,970] <webapi-666> DEBUG api    - /api/ucore/status finished (22 handling, 0 rendering)
[2023-06-21 12:03:53,420] <webapi-669> DEBUG api    - /api/s/default/stat/voucher finished (6 handling, 1 rendering)
[2023-06-21 12:03:56,525] <webapi-666> DEBUG api    - /api/s/default/rest/account finished (4 handling, 1 rendering)
[2023-06-21 12:03:56,648] <webapi-669> DEBUG api    - /api/s/default/stat/alluser finished (63 handling, 31 rendering)
[2023-06-21 12:03:56,727] <webapi-666> DEBUG api    - /api/s/default/stat/sta/ finished (24 handling, 22 rendering)

Same with mongod.log - just shows normal operation and the queries executed on the db. No errors present in any log when the client gets declined.

I think I'm going to spin up an instance of UniFi-API-browser and check if the problems also occur there. My codebase is the following: https://github.com/FreieWaldorfschuleAugsburg/wifi

malle-pietje commented 1 year ago

Hmm, strange that nothing appears in the logs... Yes, please do share the results when testing with the API browser.

christianschneider89 commented 1 year ago

I have the same problem here. Seems a rate limit. Before UniFi OS 3.1.9 I had no problems. What version do you have? I have a Cloud Key G2.

linusgke commented 1 year ago

I have the same problem here. Seems a rate limit. Before UniFi OS 3.1.9 I had no problems. What version do you have? I have a Cloud Key G2.

Yeah, same setup! Seems like the last update broke something? Strangely enough, I couldn't reproduce the problem with UniFi-API-browser - and I was literally flooding the API. Every request went through smoothly without any issues. It seems like the implementation there does something different.

I'll further investigate ...

linusgke commented 1 year ago

Ok, my bad... I accidentally invoked $_SESSION['unificookie'] = $unifi_connection->get_cookie(); before calling $client->login() which resulted in cookies not actually working. The performance increase I felt was probably caused by the system restart I did prior to that.

Now my application is as responsive as it was before updating to UniFi OS 3.1.9 and UniFi Network 7.4.156 and the errors are gone - yay!! It looks like calling login() repetitively isn't only a performance bottleneck, but can now also cause authentication denial.

Would it be possible to better document the implementation of the cookie function? It's awesome, but I didn't know about it.

Thank you @malle-pietje for supporting! ❤️

malle-pietje commented 1 year ago

@elektr0nisch Thanks for the feedback, I'll look into documenting the cookie feature a bit better. @christianschneider89 Can you confirm whether adding the cookie logic eliminates the issues for you as well?

We may need to conclude that Ubiquiti have implemented some form of rate-limiting in the latest UniFi OS update... Could be something like fail2ban (GlennR has implemented this for software-based installs with his scripts) but haven't looked into this myself. Maybe either you can check?

christianschneider89 commented 1 year ago

@malle-pietje Yes, I can confirm it. By adding the cookie logic the issue is eliminated:

$loginresults = $unifi_connection->login(); $_SESSION['unificookie'] = $unifi_connection->get_cookie();

I'm using the CLI of PHP, so I needed to save and load the value manually into/from a file, but it works now.

malle-pietje commented 1 year ago

@christianschneider89 thanks for confirming! Makes sense; when using the cli you don’t have the global session variable available.

christianschneider89 commented 1 year ago

I think there is also a rate limit when using cookies:

I have this code:

<?php
define("controlleruser",        'admin');
define("controllerpassword",    '***********');
define("controllerurl",         'https://192.168.0.2');
define("site_id",               'default');
define("controllerversion",     '7.4.156');

session_start();

while(true)
{
    echo date('H:i:s').": ";

    require_once __DIR__ . "/vendor/autoload.php";

    $cookie_file = '/var/tmp/unificookie.dat';

    error_reporting(E_ALL);

    $_SESSION['unificookie'] = file_get_contents($cookie_file);
    $unifi_connection = new UniFi_API\Client(controlleruser, controllerpassword, controllerurl, site_id, controllerversion, false);
    $set_debug_mode   = $unifi_connection->set_debug(false);
    $loginresult     = $unifi_connection->login();
    $_SESSION['unificookie'] = $unifi_connection->get_cookie();
    file_put_contents($cookie_file, $_SESSION['unificookie']);

    if($loginresult)
    {
            $devices = Array();
            $devices = $unifi_connection->list_devices();
            if($devices !== false)
            {
                    echo count($devices)." devices found\n";
            }
            else
            {
                    echo "No devices or error\n";
            }
    }
    else
    {
            echo "Login error\n";
    }

    sleep(5);

}
?>

When executing this code (query API every 5 seconds), I get this output:

12:56:28: 4 devices found
12:56:33: 4 devices found
12:56:39: 4 devices found
12:56:44: 4 devices found
12:56:50: 4 devices found
12:56:55: No devices or error
12:57:01: No devices or error
12:57:06: No devices or error
12:57:12: No devices or error
12:57:17: No devices or error
12:57:23: No devices or error
12:57:28: 4 devices found
12:57:34: 4 devices found
12:57:40: 4 devices found
12:57:45: 4 devices found
12:57:51: 4 devices found
12:57:56: No devices or error
12:58:02: No devices or error
12:58:07: No devices or error
12:58:13: No devices or error
12:58:18: No devices or error
12:58:24: No devices or error
12:58:29: 4 devices found
12:58:35: 4 devices found
12:58:40: 4 devices found
12:58:46: 4 devices found
12:58:51: 4 devices found
12:58:57: No devices or error
12:59:02: No devices or error

So I think there is a rate limit like 5 requests per minute or is it my fault?

Here are the debug logs when the request failed:

And why is $loginresult true?

Thanks!

malle-pietje commented 1 year ago

Interesting; I can't replicate that when testing using the API browser. I can easily issue 20 requests per minutes or more without error. Could this be an issue with the PHP session global variable?

malle-pietje commented 1 year ago

Do you any hints in this log file on the UniFi OS console? /var/log/auth.log

christianschneider89 commented 1 year ago

Do you any hints in this log file on the UniFi OS console? /var/log/auth.log

Nothing special here. Only my ssh logins are logged.

malle-pietje commented 1 year ago

Do you any hints in this log file on the UniFi OS console? /var/log/auth.log

Nothing special here. Only my ssh logins are logged.

OK, that would be something I'd like to see as an admin... failed login attempts.

christianschneider89 commented 1 year ago

Interesting; I can't replicate that when testing using the API browser. I can easily issue 20 requests per minutes or more without error. Could this be an issue with the PHP session global variable?

No I don't think so, I just checked it.

I created a new user in the console for using in the script. Now I don't have a rate limit yet: 220 request within 15 seconds was no problem...

But, I detected, that when the TOKEN is invalid, I never get a new token:

When the token is valid, I get this output:

Cookie from file:
TOKEN=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VySWQiOiI3ODdhYzM2OS1mNDJhLTRlNGUtYjA2Ny1hZTJmNDkyNmM1ZWIiLCJjc3JmVG9rZW4iOiIzNWY4ZGIwZS1iYzVlLTRiZTQtOWU5OS02MTQxYTMxMmE3NWUiLCJpYXQiOjE2ODc1MjE1MzQsImV4cCI6MTY4NzUyNTEzNCwianRpIjoiZjNhOGU1OWMtNTZmYy00OTY5LWE2NDItZTQ1ZmJlNDc1NjYwIn0.AvuLHwj8CluOHGvQKEgFfO3bJPS4SwEaT2CUyJCCetM

Cookie from unifi:
TOKEN=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VySWQiOiI3ODdhYzM2OS1mNDJhLTRlNGUtYjA2Ny1hZTJmNDkyNmM1ZWIiLCJjc3JmVG9rZW4iOiIzNWY4ZGIwZS1iYzVlLTRiZTQtOWU5OS02MTQxYTMxMmE3NWUiLCJpYXQiOjE2ODc1MjE1MzQsImV4cCI6MTY4NzUyNTEzNCwianRpIjoiZjNhOGU1OWMtNTZmYy00OTY5LWE2NDItZTQ1ZmJlNDc1NjYwIn0.AvuLHwj8CluOHGvQKEgFfO3bJPS4SwEaT2CUyJCCetM

Cookie from session var and written to file:
TOKEN=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJ1c2VySWQiOiI3ODdhYzM2OS1mNDJhLTRlNGUtYjA2Ny1hZTJmNDkyNmM1ZWIiLCJjc3JmVG9rZW4iOiIzNWY4ZGIwZS1iYzVlLTRiZTQtOWU5OS02MTQxYTMxMmE3NWUiLCJpYXQiOjE2ODc1MjE1MzQsImV4cCI6MTY4NzUyNTEzNCwianRpIjoiZjNhOGU1OWMtNTZmYy00OTY5LWE2NDItZTQ1ZmJlNDc1NjYwIn0.AvuLHwj8CluOHGvQKEgFfO3bJPS4SwEaT2CUyJCCetM

When the token is invalid:

Cookie from file:
TOKEN=INVALIDTOKEN

Cookie from unifi:
TOKEN=INVALIDTOKEN

Cookie from session var and written to file:
TOKEN=INVALIDTOKEN

Here the debug output when a invalid token is sent:

malle-pietje commented 1 year ago

Hmm, interesting. I don't have time at the moment to troubleshoot this but if you have suggestions on how to improve the client class behaviour, please share them.

dmham187 commented 10 months ago

Had the same problem and found another script that was run periodically, but without using cookies. I just forgot about it. Found it with tcpdump and netstat. Now everything works fine again.

christianschneider89 commented 10 months ago

Which script do you use? I have still the problem with the rate limit.

thib3113 commented 10 months ago

I also encounter the problem using the unifi api . it seems to appear on login/logout . So, the solution can be to store the token, reuse it, and renew it only when expired ?

dmham187 commented 10 months ago

I also encounter the problem using the unifi api . it seems to appear on login/logout . So, the solution can be to store the token, reuse it, and renew it only when expired ?

Yes, for me that helped. But every access to the api has to use that token. I have 2 scripts that get run every few seconds. If one of these two scripts doesn't use the token, both won't work due to the rate limit.

thib3113 commented 10 months ago

Yes, for me that helped. But every access to the api has to use that token. I have 2 scripts that get run every few seconds. If one of these two scripts doesn't use the token, both won't work due to the rate limit.

it doesn't work if you store two separate tokens ? it will only failed if you regenerate them in the same time ? if your scripts never stop you can "manage" to separate the token generations ?

dmham187 commented 10 months ago

I don't know. I have only one account for API usage, so I use the same token for both scripts.

thib3113 commented 10 months ago

I don't know. I have only one account for API usage, so I use the same token for both scripts.

you can get multiples tokens for the same account ( tested on unifios )

tflatebo commented 6 months ago

FYI, the rate limit on the Unifi side can be adjusted: https://community.ui.com/questions/Unifi-API-Rate-Limited/ba82a718-9418-46b0-8f2f-235bfc647f9b#answer/0761c014-a393-432c-a792-48defcef3f5e

wisouder commented 5 months ago

I'd like to add onto what tflatebo noted: https://github.com/Art-of-WiFi/UniFi-API-client/issues/194#issuecomment-1858909340

In summary, all the same issues reported here as well as the link provided. As commented by travis.vitek in that thread "It is controlled by the success.login.limit.count option in /usr/lib/ulp-go/config.props."

This was super annoying to find as there didn't appear to be any change notes regarding this implementation (unless I missed it). Further the suggested change does not indicate whether changing those values will actually stay after an upgrade (so you may need to remind yourself that you have to go and change the value and reboot again after upgrades) which isn't optimal.

Please also note that there appear to be more than one threshold... my existing scripts using this library only logged in once and would pull data every 5 seconds... this persisted until this last update.

To share how I resolved, I created a function in my monitor scripts for the login and logout procedure, I then look for the seconds in the minute and if we are >= 29 seconds, I log out and log back in to the unifi and begin pulling every 5 seconds again. This means that we essentially log out and log back in every minute but still pull every 5 seconds... this seems to keep me below all the thresholds implemented and still pull the frequent updates.

malle-pietje commented 4 months ago

Leaving this issue here for informational purposes.

Art-of-WiFi / UniFi-API-client

Rate limiting? #194