[prev in list] [next in list] [prev in thread] [next in thread]
List: kde-core-devel
Subject: Re: OCS Providers File - High Numbers of Requests
From: Ben Cooksley <bcooksley () kde ! org>
Date: 2021-09-24 18:26:19
Message-ID: CA+XidOGxai4ujxCTXLfnQrsAxdRYARdnVydBypK+Pq+mpVNP6Q () mail ! gmail ! com
[Download RAW message or body]
On Sat, Sep 25, 2021 at 12:34 AM Aleix Pol <aleixpol@kde.org> wrote:
> On Fri, Sep 24, 2021 at 1:32 AM Nicol=C3=A1s Alvarez
> <nicolas.alvarez@gmail.com> wrote:
> >
> > El jue, 23 de sep. de 2021 a la(s) 19:31, Aleix Pol (aleixpol@kde.org)
> escribi=C3=B3:
> > >
> > > On Thu, Sep 23, 2021 at 10:12 PM Nicol=C3=A1s Alvarez
> > > <nicolas.alvarez@gmail.com> wrote:
> > > >
> > > > El jue, 23 de sep. de 2021 a la(s) 08:55, Aleix Pol (
> aleixpol@kde.org) escribi=C3=B3:
> > > > >
> > > > > On Thu, Sep 23, 2021 at 11:52 AM Ben Cooksley <bcooksley@kde.org>
> wrote:
> > > > > >
> > > > > > Hi all,
> > > > > >
> > > > > > It has recently come to our attention that the number of querie=
s
> being handled for the endpoint
> https://autoconfig.kde.org/ocs/providers.xml on a day to day basis has
> gotten to the point where it is causing issues with server responsiveness
> to other traffic. This is perhaps best summarised by the following:
> > > > > >
> > > > > > root@nicoda /var/log/apache2 # ls -lah ...
> > > > > > -rw-r----- 1 root adm 458M Sep 23 06:25 autoconfig.kde.org.log.=
1
> > > > > > -rw-r----- 1 root adm 381M Sep 23 06:25
> networkcheck.kde.org.log.1
> > > > > > -rw-r----- 1 root adm 143M Sep 23 06:25 www.kde.org.log.1
> > > > > >
> > > > > > root@nicoda /var/log/apache2 # cat autoconfig.kde.org.log.1 |
> wc -l
> > > > > > 4,222,343
> > > > > >
> > > > > > Based on those numbers we're looking at 48-49 requests per
> second (on average - peaks are much higher by many magnitudes), which see=
ms
> extremely excessive given that this file is only supposed to be retrieved
> by KDE software when GHNS functionality is triggered. That is supported b=
y
> the substantial size difference it has over networkcheck.kde.org - which
> is used by plasma-nm and NetworkManager (on Neon) to check for whether th=
ey
> have a working internet connection - which i'd expect to be the site
> receiving the most traffic.
> > > > > >
> > > > > > As such, I therefore suspect we have bug(s) in software that
> makes use of GHNS functionality.
> > > > > >
> > > > > > It would therefore be appreciated if we could please review the
> software in question to determine whether it is operating correctly. Give=
n
> that it usually runs in the background on user systems, i'd especially
> appreciate it if a detailed review could be conducted on Discover and oth=
er
> software that conducts package management operations or assists in managi=
ng
> updates.
> > > > > >
> > > > > > Unfortunately all these applications submit a fairly useless
> user agent (Mozilla/5.0) so it is impossible for Sysadmin to ascertain an=
y
> further information. If we could get information on the software that is
> originating the request added to the user agent to assist in investigatin=
g
> these issues in the future that would be extremely helpful.
> > > > > >
> > > > > > Thanks,
> > > > > > Ben
> > > > >
> > > > > That's correct. Discover fetches them at startup. It's necessary
> to be
> > > > > able to check if there are updates on KNS-provided resources.
> > > > >
> > > > > Incidentally, I was looking into this yesterday incidentally. We
> > > > > could see if caching is broken somehow. A request will still be
> needed
> > > > > though to check if the cache is out of date.
> > > >
> > > > Caching seems to be working, since the vast majority of the request=
s
> > > > are returning 304 Not Modified.
> > > >
> > > > However in *many* cases I see a single IP making multiple requests =
in
> > > > the same second, and doing it again the next minute. Here's one IP
> > > > address picked randomly:
> > > >
> > > > [22/Sep/2021:06:25:41 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:25:41 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:25:41 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:25:41 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:27:57 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:27:58 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:27:58 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:59 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:59 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:59 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:28:59 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:30:11 +0000] "GET /ocs/providers.xml HTTP/1.1" 200
> > > > [22/Sep/2021:06:30:11 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:30:11 +0000] "GET /ocs/providers.xml HTTP/1.1" 200
> > > > [22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > > [22/Sep/2021:06:31:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304
> > > >
> > > > This continues for hours. And it's not an isolated case; again, the
> IP
> > > > I searched for was a random one from the log.
> > > >
> > > > There are 120 IP addresses that *each* made more than 10,000 reques=
ts
> > > > in a 24h period.
> > > >
> > > > I tried a few GHNS things on my own system and I couldn't reproduce
> it...
> > > >
> > > > --
> > > > Nicol=C3=A1s
> > >
> > > Is there a possibilty that we can get an UserAgent of something like
> > > that to see who's asking?
> >
> > Yes please :P
> >
> > (all requests to this file currently have "Mozilla/5.0" as the
> > User-Agent, I very much welcome modifying the code so that it sends
> > something useful instead)
> >
> > --
> > Nicol=C3=A1s
>
> This is for KNS:
> https://invent.kde.org/frameworks/knewstuff/-/merge_requests/142
>
> Attica already sets the UserAgent.
>
Thanks for getting all of these changes through.
Hopefully in the coming months we'll start to see the impact of these
changes.
In the meantime, we've switched autoconfig.kde.org to our CDN provider,
which should enable our systems to continue to handle the current load
we're experiencing.
> Aleix
>
Cheers,
Ben
[Attachment #3 (text/html)]
<div dir="ltr"><div class="gmail_quote"><div dir="ltr" class="gmail_attr">On Sat, Sep \
25, 2021 at 12:34 AM Aleix Pol <<a \
href="mailto:aleixpol@kde.org">aleixpol@kde.org</a>> wrote:<br></div><blockquote \
class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid \
rgb(204,204,204);padding-left:1ex">On Fri, Sep 24, 2021 at 1:32 AM Nicolás \
Alvarez<br> <<a href="mailto:nicolas.alvarez@gmail.com" \
target="_blank">nicolas.alvarez@gmail.com</a>> wrote:<br> ><br>
> El jue, 23 de sep. de 2021 a la(s) 19:31, Aleix Pol (<a \
href="mailto:aleixpol@kde.org" target="_blank">aleixpol@kde.org</a>) escribió:<br> \
> ><br> > > On Thu, Sep 23, 2021 at 10:12 PM Nicolás Alvarez<br>
> > <<a href="mailto:nicolas.alvarez@gmail.com" \
target="_blank">nicolas.alvarez@gmail.com</a>> wrote:<br> > > ><br>
> > > El jue, 23 de sep. de 2021 a la(s) 08:55, Aleix Pol (<a \
href="mailto:aleixpol@kde.org" target="_blank">aleixpol@kde.org</a>) escribió:<br> \
> > > ><br> > > > > On Thu, Sep 23, 2021 at 11:52 AM Ben \
Cooksley <<a href="mailto:bcooksley@kde.org" \
target="_blank">bcooksley@kde.org</a>> wrote:<br> > > > > ><br>
> > > > > Hi all,<br>
> > > > ><br>
> > > > > It has recently come to our attention that the number of \
queries being handled for the endpoint <a \
href="https://autoconfig.kde.org/ocs/providers.xml" rel="noreferrer" \
target="_blank">https://autoconfig.kde.org/ocs/providers.xml</a> on a day to day \
basis has gotten to the point where it is causing issues with server responsiveness \
to other traffic. This is perhaps best summarised by the following:<br> > > \
> > ><br> > > > > > root@nicoda /var/log/apache2 # ls -lah \
...<br> > > > > > -rw-r----- 1 root adm 458M Sep 23 06:25 \
autoconfig.kde.org.log.1<br> > > > > > -rw-r----- 1 root adm 381M Sep \
23 06:25 networkcheck.kde.org.log.1<br> > > > > > -rw-r----- 1 root \
adm 143M Sep 23 06:25 www.kde.org.log.1<br> > > > > ><br>
> > > > > root@nicoda /var/log/apache2 # cat autoconfig.kde.org.log.1 \
| wc -l<br> > > > > > 4,222,343<br>
> > > > ><br>
> > > > > Based on those numbers we're looking at 48-49 requests \
per second (on average - peaks are much higher by many magnitudes), which seems \
extremely excessive given that this file is only supposed to be retrieved by KDE \
software when GHNS functionality is triggered. That is supported by the substantial \
size difference it has over <a href="http://networkcheck.kde.org" rel="noreferrer" \
target="_blank">networkcheck.kde.org</a> - which is used by plasma-nm and \
NetworkManager (on Neon) to check for whether they have a working internet connection \
- which i'd expect to be the site receiving the most traffic.<br> > > > \
> ><br> > > > > > As such, I therefore suspect we have bug(s) in \
software that makes use of GHNS functionality.<br> > > > > ><br>
> > > > > It would therefore be appreciated if we could please review \
the software in question to determine whether it is operating correctly. Given that \
it usually runs in the background on user systems, i'd especially appreciate it \
if a detailed review could be conducted on Discover and other software that conducts \
package management operations or assists in managing updates.<br> > > > > \
><br> > > > > > Unfortunately all these applications submit a \
fairly useless user agent (Mozilla/5.0) so it is impossible for Sysadmin to ascertain \
any further information. If we could get information on the software that is \
originating the request added to the user agent to assist in investigating these \
issues in the future that would be extremely helpful.<br> > > > > \
><br> > > > > > Thanks,<br>
> > > > > Ben<br>
> > > ><br>
> > > > That's correct. Discover fetches them at startup. It's \
necessary to be<br> > > > > able to check if there are updates on \
KNS-provided resources.<br> > > > ><br>
> > > > Incidentally, I was looking into this yesterday incidentally. \
We<br> > > > > could see if caching is broken somehow. A request will \
still be needed<br> > > > > though to check if the cache is out of \
date.<br> > > ><br>
> > > Caching seems to be working, since the vast majority of the \
requests<br> > > > are returning 304 Not Modified.<br>
> > ><br>
> > > However in *many* cases I see a single IP making multiple requests \
in<br> > > > the same second, and doing it again the next minute. Here's \
one IP<br> > > > address picked randomly:<br>
> > ><br>
> > > [22/Sep/2021:06:25:41 +0000] "GET /ocs/providers.xml \
HTTP/1.1" 304<br> > > > [22/Sep/2021:06:25:41 +0000] "GET \
/ocs/providers.xml HTTP/1.1" 304<br> > > > [22/Sep/2021:06:25:41 +0000] \
"GET /ocs/providers.xml HTTP/1.1" 304<br> > > > \
[22/Sep/2021:06:25:41 +0000] "GET /ocs/providers.xml HTTP/1.1" 304<br> > \
> > [22/Sep/2021:06:27:57 +0000] "GET /ocs/providers.xml HTTP/1.1" \
304<br> > > > [22/Sep/2021:06:27:58 +0000] "GET /ocs/providers.xml \
HTTP/1.1" 304<br> > > > [22/Sep/2021:06:27:58 +0000] "GET \
/ocs/providers.xml HTTP/1.1" 304<br> > > > [22/Sep/2021:06:28:32 +0000] \
"GET /ocs/providers.xml HTTP/1.1" 304<br> > > > \
[22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml HTTP/1.1" 304<br> > \
> > [22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml HTTP/1.1" \
304<br> > > > [22/Sep/2021:06:28:32 +0000] "GET /ocs/providers.xml \
HTTP/1.1" 304<br> > > > [22/Sep/2021:06:28:59 +0000] "GET \
/ocs/providers.xml HTTP/1.1" 304<br> > > > [22/Sep/2021:06:28:59 +0000] \
"GET /ocs/providers.xml HTTP/1.1" 304<br> > > > \
[22/Sep/2021:06:28:59 +0000] "GET /ocs/providers.xml HTTP/1.1" 304<br> > \
> > [22/Sep/2021:06:28:59 +0000] "GET /ocs/providers.xml HTTP/1.1" \
304<br> > > > [22/Sep/2021:06:30:11 +0000] "GET /ocs/providers.xml \
HTTP/1.1" 200<br> > > > [22/Sep/2021:06:30:11 +0000] "GET \
/ocs/providers.xml HTTP/1.1" 304<br> > > > [22/Sep/2021:06:30:11 +0000] \
"GET /ocs/providers.xml HTTP/1.1" 200<br> > > > \
[22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304<br> > \
> > [22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml HTTP/1.1" \
304<br> > > > [22/Sep/2021:06:30:38 +0000] "GET /ocs/providers.xml \
HTTP/1.1" 304<br> > > > [22/Sep/2021:06:30:38 +0000] "GET \
/ocs/providers.xml HTTP/1.1" 304<br> > > > [22/Sep/2021:06:31:19 +0000] \
"GET /ocs/providers.xml HTTP/1.1" 304<br> > > > \
[22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml HTTP/1.1" 304<br> > \
> > [22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml HTTP/1.1" \
304<br> > > > [22/Sep/2021:06:31:19 +0000] "GET /ocs/providers.xml \
HTTP/1.1" 304<br> > > > [22/Sep/2021:06:31:38 +0000] "GET \
/ocs/providers.xml HTTP/1.1" 304<br> > > > [22/Sep/2021:06:31:38 +0000] \
"GET /ocs/providers.xml HTTP/1.1" 304<br> > > > \
[22/Sep/2021:06:31:38 +0000] "GET /ocs/providers.xml HTTP/1.1" 304<br> > \
> > [22/Sep/2021:06:31:38 +0000] "GET /ocs/providers.xml HTTP/1.1" \
304<br> > > ><br>
> > > This continues for hours. And it's not an isolated case; again, \
the IP<br> > > > I searched for was a random one from the log.<br>
> > ><br>
> > > There are 120 IP addresses that *each* made more than 10,000 \
requests<br> > > > in a 24h period.<br>
> > ><br>
> > > I tried a few GHNS things on my own system and I couldn't \
reproduce it...<br> > > ><br>
> > > --<br>
> > > Nicolás<br>
> ><br>
> > Is there a possibilty that we can get an UserAgent of something like<br>
> > that to see who's asking?<br>
><br>
> Yes please :P<br>
><br>
> (all requests to this file currently have "Mozilla/5.0" as the<br>
> User-Agent, I very much welcome modifying the code so that it sends<br>
> something useful instead)<br>
><br>
> --<br>
> Nicolás<br>
<br>
This is for KNS:<br>
<a href="https://invent.kde.org/frameworks/knewstuff/-/merge_requests/142" \
rel="noreferrer" target="_blank">https://invent.kde.org/frameworks/knewstuff/-/merge_requests/142</a><br>
<br>
Attica already sets the UserAgent.<br></blockquote><div><br></div><div>Thanks for \
getting all of these changes through.</div><div>Hopefully in the coming months \
we'll start to see the impact of these changes.</div><div><br></div><div>In the \
meantime, we've switched <a \
href="http://autoconfig.kde.org">autoconfig.kde.org</a> to our CDN provider, which \
should enable our systems to continue to handle the current load we're \
experiencing.<br></div><div> <br></div><blockquote class="gmail_quote" \
style="margin:0px 0px 0px 0.8ex;border-left:1px solid \
rgb(204,204,204);padding-left:1ex"> <br>
Aleix<br></blockquote><div><br></div><div>Cheers,</div><div>Ben<br></div></div></div>
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic