Bug 289285 – gorg is very slow for frontpage: maybe not using cached XML files

• Product: Websites
• Status: RESOLVED FIXED

[Description Robin Johnson 2009-10-16 09:45:28 UTC]

I was trying to trace why the frontpage loads so slowly compared to non-frontpage, and I suspect that Gorg might not be using the cached files at all. Additionally, the frontpage takes a LOT of XML light

Incidently, the time also matches the time that it takes xsltproc to run locally on the webserver (with no caching). I know that the frontpage causes 1.3MiB of XML to be examined (mainly in glsa-index*xml), so I'm wondering if Gorg's caching isn't working. I can tell that it DOES write the cache files to disk, and inotify says it's accessing them again to read, but it doesn't seem to send the data back out from the cache I think. If the cache file doesn't exist, and I run a query twice, the second time is NOT faster.

Presently you can target a host with:
http://www-{ani,auklet,wren,loon}.gentoo.org/

I tested within the cluster pairs, so we can rule out network latency issues.
(on loon)
# ab2 -n 100 -c 1 -t 10 http://www-wren.gentoo.org/main/en/about.xml
...
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    1   3.3      0      11
Processing:   336  469 133.3    448     793
Waiting:      334  467 132.4    446     791
Total:        336  471 134.1    448     804
...

# ab2 -n 100 -c 1 -t 10 http://www-wren.gentoo.org/
...
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0   11  16.3     23      23
Processing:  3234 3676 625.8   4119    4119
Waiting:     3229 3674 629.3   4119    4119
Total:       3257 3688 609.5   4119    4119
...

(on ani)
# ab2 -n 100 -c 1 -t 10 http://www-auklet.gentoo.org/
...
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    2   2.3      4       4
Processing:  4643 6347 2409.6   8051    8051
Waiting:     4638 6340 2407.8   8043    8043
Total:       4647 6349 2407.3   8051    8051
...

# ab2 -n 100 -c 1 -t 10 http://www-auklet.gentoo.org/main/en/about.xml
...
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       0
Processing:   396  986 442.7    976    1712
Waiting:      364  982 446.9    974    1711
Total:        396  987 442.7    976    1713
...

[Comment 1 Xavier Neys (RETIRED) 2009-10-16 16:41:27 UTC]

$ ssh www-auklet.gentoo.org
 Any or all uses of this system and all files on this system may be
 intercepted, monitored, recorded, copied, audited, inspected, and
 disclosed to authorized site personnel, as well as authorized officials
 of federal law enforcement agencies, both domestic and foreign. By 
 using this system, the user consents to such interception, monitoring,
 recording, copying, auditing, inspection, and disclosure at the
 discretion of authorized site personnel. Use of this system constitutes
 consent to security monitoring and testing. All activity is logged with
 your host name and IP address. Unauthorized or improper use of this
 system may result in civil and criminal penalties. By continuing to use
 this system you indicate your awareness of and consent to these terms
 and conditions of use. -- Gentoo Linux Infrastructure Admins
 
                             LOG OFF IMMEDIATELY, 
        If you do not agree to the conditions stated in this warning.
Permission denied (publickey).

[Comment 2 Robin Johnson 2009-10-16 19:21:49 UTC]

You don't have accounts on any of the web nodes. Looks like it was removed in early 2008. I'm re-adding them now. Please be aware that most of /etc is under cfengine control on the new machines. If you need to change something long-term, please tell me it, so that I can change it in the master copy.

[Comment 3 Xavier Neys (RETIRED) 2009-10-16 21:04:00 UTC]

Looks like all caching is disabled because of the missing debug.xml file
The front page is slower because it has more to do.
Create an empty debug.xml containing just <debug/> in the doc root for a quick test or temp fix.
I do not want it on our web node or in CVS as it's not meant to be used on www.g.o


BTW, /etc/xml/catalog needs to be edited. The one on wren & loon is OK.
without this, files that source external resources (http://www.gentoo.org/dtd/... is common) will not be cached.

[Comment 4 Robin Johnson 2009-10-16 21:35:16 UTC]

Yup, adding the debug.xml file on disk cuts the time way down as the caching kicks in:
auklet, with debug.xml existing, rendering /:
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.6      0       6
Processing:    49  114  76.2     94     675
Waiting:       44  110  76.7     89     674
Total:         49  114  76.2     94     675

and /main/en/about.xml:
Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.6      0       8
Processing:    21   34  14.4     34      98
Waiting:       20   32  14.2     33      96
Total:         21   34  14.4     34      98

So why does gorg need debug.xml to exist for the caching to work? Can we please get gorg fixed?

> BTW, /etc/xml/catalog needs to be edited. The one on wren & loon is OK.
I've added the XML catalog to cfengine.

[Comment 5 Xavier Neys (RETIRED) 2009-10-16 21:53:15 UTC]

(In reply to comment #4)
> So why does gorg need debug.xml to exist for the caching to work?

Gorg doesn't really.
It's just that a missing file triggers a cache miss and it shouldn't.

> Can we please get gorg fixed?

Yes, we can! See bug #289391

[Comment 6 Xavier Neys (RETIRED) 2009-10-17 20:00:52 UTC]

I've done my part. Updating gorg on server is all it takes. No extra action is required.

[Comment 7 Robin Johnson 2009-10-18 07:00:17 UTC]

Gorg deployed via cfengine.
loon and wren removed from rotation for now.

[Comment 8 Robin Johnson 2009-10-18 07:00:28 UTC]

oops, closing.