Need help debugging slowness
|
coppit
Joined: 2002-09-15
Posts: 33 |
Posted: Sun, 2005-06-26 17:32
|
|
Hi everyone, I'm trying to figure out why my gallery is so darn slow. It takes 40 seconds to load the main page after clearing my browser cache, and sometimes the thumbnails fail to load, in which case Firefox shows just the image name. A reload with cached thumbnails also takes 40 seconds or so. Some of my relatives report that loading movie pages hangs entirely. (Even for very short movies.) I hacked main.php to print out some log messages, and it appears that cached thumbnails are being used correctly. Can anyone help out? Thanks, ---- |
|
Posts: 32509
what are the system specs?
once generated, G2 loads thumbnails etc. from the filesystem.
i've seen that the master php memory limit is set to 8mb and set to 128mb locally in in /. is it also 128mb in /gallery2/ ?
Posts: 33
Here's info from top:
last pid: 95541; load averages: 2.36, 2.45, 2.54 up 2+16:24:54 14:07:44
88 processes: 3 running, 85 sleeping
CPU states: 69.0% user, 0.0% nice, 12.0% system, 0.4% interrupt, 18.6% idle
Mem: 340M Active, 31M Inact, 101M Wired, 20M Cache, 60M Buf, 2200K Free
Swap: 1024M Total, 134M Used, 890M Free, 13% Inuse
Is this too much load for gallery to perform well? Here's the CPU info:
$ dmesg | grep CPU
CPU: AMD Athlon(tm) Processor (959.45-MHz 686-class CPU)
cpu0: <ACPI CPU (3 Cx states)> on acpi0
acpi_throttle0: <ACPI CPU Throttling> on cpu0
I thought that the memory limit was inherited by subdirectories. In any case, I also put the directive in gallery2/.htaccess. It didn't make a difference, AFAICT.
Posts: 32509
.htaccess instructions are inherited, correct.
1 GHz cpu, 1GB RAM should be fine.
a load over 1 is too much anyway. what else is running on this server?
Posts: 33
There are several websites, some with CGI-intensive aspects. In any case, the load averages are back down now:
last pid: 99935; load averages: 0.41, 0.31, 0.53 up 2+17:21:56 15:04:46
86 processes: 1 running, 85 sleeping
CPU states: 0.4% user, 0.0% nice, 2.7% system, 0.0% interrupt, 96.9% idle
Mem: 264M Active, 52M Inact, 108M Wired, 25M Cache, 60M Buf, 45M Free
Swap: 1024M Total, 118M Used, 906M Free, 11% Inuse
And gallery2 is still slow. It looks to me like the web browser is re-fetching the thumbnails. Here are the accesses for the main page:
[26/Jun/2005:15:07:03 -0400] "GET /gallery2/main.php HTTP/1.1" 200 5578[26/Jun/2005:15:07:08 -0400] "GET /gallery2/main.php?g2_view=imageframe.CSS&g2_frames=none%7Csolid HTTP/1.1" 304 26[26/Jun/2005:15:07:08 -0400] "GET /gallery2/templates/layout.css HTTP/1.1" 304 -[26/Jun/2005:15:07:08 -0400] "GET /gallery2/layouts/matrix/layout.css HTTP/1.1" 304 -[26/Jun/2005:15:07:09 -0400] "GET /gallery2/themes/matrix/theme.css HTTP/1.1" 304 -[26/Jun/2005:15:07:09 -0400] "GET /gallery2/images/galleryLogo_sm.gif HTTP/1.1" 304 -[26/Jun/2005:15:07:09 -0400] "GET /gallery2/d/332-2/capitol_building.jpg HTTP/1.1" 200 6656
[26/Jun/2005:15:07:09 -0400] "GET /gallery2/d/1177-2/oregon_117.jpg HTTP/1.1" 200 5849 [26/Jun/2005:15:07:09 -0400] "GET /gallery2/d/1828-2/william_and_mary-september_2002.jpe HTTP/1.1" 200 5921 [26/Jun/2005:15:07:09 -0400] "GET /gallery2/d/2677-4/day_6.jpe HTTP/1.1" 200 6358
[26/Jun/2005:15:07:24 -0400] "GET /gallery2/d/23-9/baby.jpe HTTP/1.1" 304 26
[26/Jun/2005:15:07:24 -0400] "GET /gallery2/d/256-2/family.jpe HTTP/1.1" 304 26
[26/Jun/2005:15:07:24 -0400] "GET /gallery2/d/530-3/friends.jpe HTTP/1.1" 304 26
[26/Jun/2005:15:07:24 -0400] "GET /gallery2/d/756-3/trips.jpe HTTP/1.1" 304 26
[26/Jun/2005:15:07:24 -0400] "GET /gallery2/d/1431-3/places.jpe HTTP/1.1" 200 4108
[26/Jun/2005:15:07:24 -0400] "GET /gallery2/d/1981-2/miscellaneous.jpe HTTP/1.1" 304 26
[26/Jun/2005:15:07:26 -0400] "GET /gallery2/images/xhtml10.png HTTP/1.1" 304 -
[26/Jun/2005:15:07:26 -0400] "GET /gallery2/images/gallery.gif HTTP/1.1" 304 -
[26/Jun/2005:15:07:27 -0400] "GET /gallery2/d/72-2/holidays.jpe HTTP/1.1" 304 26[26/Jun/2005:15:07:41 -0400] "GET /gallery2/d/756-3/trips.jpe HTTP/1.1" 304 26
[26/Jun/2005:15:07:41 -0400] "GET /gallery2/images/xhtml10.png HTTP/1.1" 304 -
[26/Jun/2005:15:07:42 -0400] "GET /gallery2/images/gallery.gif HTTP/1.1" 304 -
[26/Jun/2005:15:07:44 -0400] "GET /gallery2/d/1981-2/miscellaneous.jpe HTTP/1.1" 304 26[26/Jun/2005:15:07:44 -0400] "GET /gallery2/d/1431-3/places.jpe HTTP/1.1" 200 4108[26/Jun/2005:15:07:59 -0400] "GET /favicon.ico HTTP/1.1" 404 1142
You can see that they're taking a while...
Thanks...
Posts: 32509
the http codes 304 = not modified show that it doesn't load the whole G2 logic for each thumbnail.
some of the images are not cached (200 and not 304). i guess these are the images from the imageblock, random etc.
it's very slow, true. but i don't know why.
the actual request takes about 2 seconds. that's not great, but ok.
the rest is a problem.
Posts: 33
It looks like some of the thumbnails are not being always cached. Here are two consecutive reloads. In the second one, capitol, day_6, william_and_mary, and Image5 are from the image blocks. But RR and BL aren't being cached (indeed they don't get loaded at all), and neither is trips.jpe. For some reason trips.jpe is loaded multiple times.
Is this a server problem?
[17:18:09] /gallery2/d/530-3/friends.jpe HTTP/1.1" 200 4859
[17:18:30] /gallery2/v/ HTTP/1.1" 200 5754
[17:18:32] /gallery2/main.php?g2_view=imageframe.CSS&g2_frames=none%7Cpolaroids%7Csolid HTTP/1.1" 304 26
[17:18:33] /gallery2/templates/layout.css HTTP/1.1" 304 -
[17:18:33] /gallery2/layouts/matrix/layout.css HTTP/1.1" 304 -
[17:18:33] /gallery2/themes/matrix/theme.css HTTP/1.1" 304 -
[17:18:33] /gallery2/images/galleryLogo_sm.gif HTTP/1.1" 304 -
[17:18:33] /gallery2/d/771-2/dorothy.jpg HTTP/1.1" 200 4843
[17:18:33] /gallery2/d/332-2/capitol_building.jpg HTTP/1.1" 200 6656
[17:18:33] /gallery2/d/2677-4/day_6.jpe HTTP/1.1" 200 6358
[17:18:33] /gallery2/d/1828-2/william_and_mary-september_2002.jpe HTTP/1.1" 200 5921
[17:18:48] /gallery2/modules/imageframe/frames/polaroids/TL.gif HTTP/1.1" 304 -
[17:18:48] /gallery2/modules/imageframe/frames/polaroids/TR.gif HTTP/1.1" 304 -
[17:18:48] /gallery2/modules/imageframe/frames/polaroids/LL.gif HTTP/1.1" 304 -
[17:18:48] /gallery2/d/23-9/baby.jpe HTTP/1.1" 304 26
[17:18:48] /gallery2/modules/imageframe/frames/polaroids/RR.gif HTTP/1.1" 200 44
[17:18:48] /gallery2/modules/imageframe/frames/polaroids/BL.gif HTTP/1.1" 200 102
[17:18:49] /gallery2/d/256-2/family.jpe HTTP/1.1" 200 4109
[17:18:49] /gallery2/d/530-3/friends.jpe HTTP/1.1" 200 4859
[17:18:49] /gallery2/d/756-3/trips.jpe HTTP/1.1" 304 26
[17:18:49] /gallery2/d/1431-3/places.jpe HTTP/1.1" 200 4108
[17:18:49] /gallery2/d/1981-2/miscellaneous.jpe HTTP/1.1" 304 26
[17:18:49] /gallery2/images/xhtml10.png HTTP/1.1" 200 321
[17:18:49] /gallery2/images/gallery.gif HTTP/1.1" 200 1180
[17:18:50] /gallery2/modules/imageframe/frames/polaroids/BB.gif HTTP/1.1" 304 -
[17:18:50] -
[17:18:50] /gallery2/d/72-2/holidays.jpe HTTP/1.1" 304 26
[17:18:50] /gallery2/modules/imageframe/frames/polaroids/BB.gif HTTP/1.1" 304 -
[17:18:50] /gallery2/modules/imageframe/frames/polaroids/BR.gif HTTP/1.1" 304 -
[17:18:51] /gallery2/d/72-2/holidays.jpe HTTP/1.1" 304 26
[17:18:51] /gallery2/modules/imageframe/frames/polaroids/TT.gif HTTP/1.1" 304 -
[17:19:05] /gallery2/images/xhtml10.png HTTP/1.1" 200 321
[17:19:05] /gallery2/d/1981-2/miscellaneous.jpe HTTP/1.1" 304 26
[17:19:05] /gallery2/images/gallery.gif HTTP/1.1" 200 1180
===========================================================================
[17:24:10] /gallery2/v/ HTTP/1.1" 200 5730
[17:24:11] /gallery2/main.php?g2_view=imageframe.CSS&g2_frames=none%7Cpolaroids%7Csolid HTTP/1.1" 304 26
[17:24:12] /gallery2/templates/layout.css HTTP/1.1" 304 -
[17:24:13] /gallery2/layouts/matrix/layout.css HTTP/1.1" 304 -
[17:24:13] /gallery2/themes/matrix/theme.css HTTP/1.1" 304 -
[17:24:13] /gallery2/images/galleryLogo_sm.gif HTTP/1.1" 304 -
[17:24:13] /gallery2/d/670-2/Image5.jpg HTTP/1.1" 200 5399
[17:24:13] /gallery2/d/332-2/capitol_building.jpg HTTP/1.1" 200 6656
[17:24:13] /gallery2/d/2677-4/day_6.jpe HTTP/1.1" 200 6358
[17:24:14] /gallery2/d/1828-2/william_and_mary-september_2002.jpe HTTP/1.1" 200 5921
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/TL.gif HTTP/1.1" 304 -
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/TT.gif HTTP/1.1" 304 -
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/TR.gif HTTP/1.1" 304 -
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/LL.gif HTTP/1.1" 304 -
[17:24:14] /gallery2/d/23-9/baby.jpe HTTP/1.1" 304 26
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/RR.gif HTTP/1.1" 200 44
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/BL.gif HTTP/1.1" 200 102
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/BB.gif HTTP/1.1" 304 -
[17:24:14] /gallery2/modules/imageframe/frames/polaroids/BR.gif HTTP/1.1" 304 -
[17:24:14] /gallery2/d/72-2/holidays.jpe HTTP/1.1" 304 26
[17:24:14] /gallery2/d/256-2/family.jpe HTTP/1.1" 304 26
[17:24:14] /gallery2/d/530-3/friends.jpe HTTP/1.1" 304 26
[17:24:14] /gallery2/d/756-3/trips.jpe HTTP/1.1" 200 3505
[17:24:14] /gallery2/d/1431-3/places.jpe HTTP/1.1" 200 4108
[17:24:29] /gallery2/d/1981-2/miscellaneous.jpe HTTP/1.1" 304 26
[17:24:29] /gallery2/images/xhtml10.png HTTP/1.1" 304 -
[17:24:29] /gallery2/images/gallery.gif HTTP/1.1" 304 -
[17:24:29] /gallery2/modules/imageframe/frames/polaroids/BB.gif HTTP/1.1" 304 -
[17:24:29] /gallery2/modules/imageframe/frames/polaroids/BR.gif HTTP/1.1" 304 -
[17:24:29] /gallery2/d/72-2/holidays.jpe HTTP/1.1" 304 26
[17:24:29] /gallery2/d/256-2/family.jpe HTTP/1.1" 304 26
[17:24:29] /gallery2/d/530-3/friends.jpe HTTP/1.1" 304 26
[17:24:31] /gallery2/d/756-3/trips.jpe HTTP/1.1" 200 3505
[17:24:46] /gallery2/d/530-3/friends.jpe HTTP/1.1" 304 26
[17:24:46] /gallery2/d/756-3/trips.jpe HTTP/1.1" 200 3505
[17:24:46] /favicon.ico HTTP/1.1" 404 1143
Posts: 33
Here's some more info...
In Safari and Firefox on Mac OSX, the following link takes a long time to complete:
http://www.coppit.org/gallery2/main.php?g2_view=core.DownloadItem&g2_itemId=1981&g2_serialNumber=2
But MS Internet Explorer for the Mac reloads very quickly. Similarly, this page:
http://www.coppit.org/gallery2/test.php
loads very quickly in IE, but slowly in Safari and Firefox.
I wonder if Gallery isn't closing the connections properly?
Posts: 33
I solved part of the problem. According to the user comments at
http://us4.php.net/manual/en/function.fread.php
you should call flush() when reading from a file and printing the results.
After adding flush() after the print statement in the fastDownload method of Gallery.class, individual thumbnails now load fast:
http://www.coppit.org/gallery2/main.php?g2_view=core.DownloadItem&g2_itemId=1981&g2_serialNumber=2
Reload a couple times in firefox to see the difference. (BTW, I had to nuke my derivatives directory contents in order to flush the old cached version of GalleryFastDownload.
Unfortunately, the main page still loads slowly. I'm auditing all the uses of fread to see if I can find other similar problems.
P.S. I'll post a patch.
Posts: 32509
note: refresh on firefox has a different meaning than refresh in internet explorer.
in IE, refresh doesn't force a redownload of images. so it still sends the if modified since header. only if you use ctrl+F5 (whatever that is on mac), it forces redownloads of images.
in FF, a refresh always forces redownloads of images.
at least that is what we observed when testing other stuff.
so, you shouldn't hit refresh, but browse around, or hit enter in the address bar.
@flush():
weird that it works for everyone else. but your site is indeed a lot faster now. some also say that ob_flush() for large (> php memory limit) is required because flush() only is flushing the apache and not the php memory.
please experiment a little and submit a patch.
thanks, good work!
Posts: 32509
this is better:
http://ch2.php.net/ob_implicit_flush
just call ob_implicit_flush(true);
in modules/core/
DownloadItem.inc _sendFile before the while loop
and in classes/Gallery.class fastDownload also before the while loop, after the if statement.
Posts: 32509
maybe ob_implicit_flush(true); isn't a good choice though, there are some php bugs associated with it.
@ob_flush();
flush();
may work, but would need some testing.
let us know what's the best fix for your site.
Posts: 33
ob_implicit_flush doesn't seem to work for me. Using this test page:
http://www.coppit.org/gallery2/test1.php
I tried removing the explicit flush() and adding ob_implicit_flush(), but it remained slow. I also tried adding the ob_flush() per some of the comments on that webpage, but it was still slow. Only a flush() seems to make it load fast.
Two other notes: (1) I think shift-reload in Firefox is a hard reload that re-fetches the images. I think in the test page, the last two images are being refetched even for a soft reload. Dunno why... (2) This problem only seems to occur for Safari and Firefox on Mac OS X. I thought it also happened for Firefox on Windows, but that turned out to be Google web accelerator actually slowing down my gallery. :/
Posts: 8601
correct that shift-reload in FF forces reload of images.. plain reload sends If-modified-since.. until very recently G2 was only checking for If-Modified-Since (case sensitive) and was resending images anyway.
Posts: 33
I solved the final speed problem. I noticed that my last image on my test1.php page would spin forever on a soft reload, then timeout and show the broken image symbol. I added another flush for the not modified case in main.php:
header('HTTP/1.x 304 Not Modified');
flush();
return;
and that cleared it up. For whatever reason, these flushes seem to help firefox on OSX close the connection.
Now my gallery loads at a respectable speed.
Posts: 33
Okay, I removed the flushes from DownloadItem.inc and Gallery.class, instead putting flushes in main.php for each of the three cases. This solved the timeouts leading to broken images on soft reloads, and slowness on hard reloads.
Here is the complete patch file:
diff -c -r1.119 main.php *** main.php 14 Jun 2005 23:36:32 -0000 1.119 --- main.php 27 Jun 2005 20:15:40 -0000 *************** *** 44,49 **** --- 44,50 ---- $headers = GetAllHeaders(); if (isset($headers['If-Modified-Since']) || isset($headers['If-modified-since'])) { header('HTTP/1.x 304 Not Modified'); + flush(); return; } } *************** *** 61,66 **** --- 62,68 ---- if (file_exists($path)) { include($path); if (GalleryFastDownload()) { + flush(); return; } } *************** *** 76,81 **** --- 78,84 ---- /* Process the request */ GalleryMain(); + flush(); } else { require_once(dirname(__FILE__) . '/init.inc'); }Posts: 32509
why do you want to add a flush after the header() call?
Posts: 33
If I don't, a soft reload causes the last image of my test page to spin for 30 seconds. After 30 seconds, the browser times out and the image has a a "broken image" icon. With the flush, there is no spinning for 30 seconds--everything is very fast.
I don't know why this makes a difference, but it does. I think it may be some nasty interaction of my server and Firefox on Mac OS X. Other galleries don't exhibit this problem (although I don't know if they are running the latest CVS like I am). If any developer has access to Mac OS X, I'd be happy to comment out the flushes so that you can see the difference. IM me (coppit) so I can demonstrate it for you.
Posts: 32509
and are you sure this last image falls into the category of the header('HTTP/1.x 304 Not Modified'); in main.php?
Posts: 33
Yes. I was watching the access log as I reloaded for 304's. In Firefox, the image would appear, but the browser would keep spinning. After the timeout, the broken image icon would be overlaid on top of the image.
Posts: 32509
mindless, bharat, ok then.
i'd say we add @ob_flush(); flush(); (see comments in php.net/flush, php bugs) in the two render / fastdownload functions and in main.php after the header(304); statement.
ob_flush(); is needed (see comments in php.net/flush) but i'm not sure why, since we haven't enabled output buffering. but output buffering can also be enabled in php.ini, and there are php output compression handlers etc.
so @ob_flush(); flush(); should be safe, given that a ob_flush() call creates a warning if there's no output buffer to flush.
Posts: 1
I had a very similar performance issue with G2 being slow. Some thumbnails would take a very long time to load (15-30 seconds.) It never seemed to be the same thumbnails. There were no errors in apache's error_log and enabling profiling and debugging in G2 provided no clues. This happened using Firefox 1.04 and IE6.0 on different computers. Adding @ob_flush(); flush(); to main.php seemed to help a little, but didn't solve the problem.
Turns out gzip compression was causing the issue. My PHP installation was configured by H-Sphere which by default sets output_handler = ob_gzhandler. Once I commented out this line and restarted apache, thumbnails loaded perfectly. As suggested on another thread, the Firefox extension LiveHTTPHeaders was invaluable in troubleshooting the problem. LiveHTTPHeaders allowed me to watch the http headers in real time while the page was being downloaded.
Gallery version = 2.0-beta-3+ core 0.9.31
PHP version = 4.3.11 apache
Webserver = Apache
Database = mysql 4.0.23-standard-log
Toolkits = ArchiveUpload, Exif, Gd, ImageMagick, Thumbnail, NetPBM
Operating system = Linux cp.inthrive.com 2.4.21-32.0.1.ELsmp #1 SMP Wed May 25 14:26:33 EDT 2005 i686
Browser = Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.7.8) Gecko/20050511 Firefox/1.0.4
I hope this information helps someone else.
Posts: 16
I had a similar problem, but neither flush() nor the output_handler (this is in php.ini, right?) helped. Any other ideas? The gallery is on a fast server, it's definitely load issue. http://www.snehal.ca/gallery/
Posts: 16
OK I got one thing working:
I found that the g2data/derivative directory was owend by "nobody". I chowned it to this user's account, and the thumbs now load super fast. However, the resized images (when you click on a thumbnail) still load extremely slow. Are these also stored in "derivative" directory? Or is the problem elsewhere?
Thanks.
Posts: 16
Still looking into it... another thing I noticed was that if I chown the derivatives directory recursively, the resized imaged appear broken. However, if I only chown the derivative directory, but not the subdirectories, then it works fine, except that the resized images still load slow. Looks like a problem with permissions to create directories and files for caching?
Posts: 3236
The webserver *HAS* to have read/write permissions on the /g2data/ dir. So in your case, it would appear that apache runs as "nobody". So if you chown to a certain user, you will then want to do a "chmod -R 777 ./g2data/" so that everything is properly writable. You might also want to change the default permission mask in G2, but that is probably optional.
Before you judge resize image load times, I would visit the maintainance section of the site admin and run the "build all derivitives" tool. This will cause all thumbs and resizes to be built. NOW go back and compare load times.
Signature: Like Gallery? Appreciate my help? Think I'm an asshole? Make your point by donating to the Gallery project! Or maybe just visit my website.
Posts: 16
Yes, the g2data directory has 777 permissions recursively. I have also used the "Build all thumbnails/resizes" tool, but that didn't help either.
Try to browse that gallery. Click on a thumbnail and then click next> a few times. It seems like the resizes are built, but they are not being loaded. Sometimes one you click on any link, they immediately appear. Weird.
Any ideas?
Thanks.
Posts: 16
any ideas for help?
Posts: 16504
I was able to browse all 6 pictures publicly available on your site without problems. Your slowness could be the server, the connection, the database, etc.
____________________________________________
Like Gallery? Like the support? Donate now!!! See G2 live here
Posts: 16
Nivekiam,
thanks for looking into this. I don't think this is a server load or connection problem. I have root access on to that server, the load is close to 0 and my connection is 5MB cable. It definitely seems like something to do with caching the images.
Don't the thumbs/resizes load extremely slow on your end? It takes about 30 seconds on my end to load them. Same thing from my work of from home. I also have gallery 1.5 on the same server and it's super fast. It's definitely something with the Gallery 2.
I appreciate any ideas as for where should I look...
Thanks.
Posts: 16
I just realized that it loads much faster in Firefox. The thumbs/resizes are on the server, they're just not being displayed immediately in IE... Still no clue how to fix this.