Requests take a really long time from certain ISP
We have an Apache server with PHP running on a virtual machine. Document roots are inside the users' home folders (/home/users/{first letter}/{username}/), and /home/users/ is mounted over NFS.
It appears that there's something strange going on. When some users request a file (in this example I used Hondenbol.png) it takes ages (at first the user thought it didn't load at all) while for others (for me, in this case) it loads pretty much instantly.
This is part of the Apache log file for that vHost. The only strange thing I notice is the number after the HTTP status code, which as far as I can tell is this (from the Apache documentation);
2326 (%b)
The last part indicates the size of the object returned to the client, not including the response headers. If no content was returned to the client, this value will be "-". To log "0" for no content, use %B instead.
Should there be such a big difference for the same file? Or has that got to do with browser caching?
root@web:/var/log/apache2/vhost# cat VHOST_USERNAME_USERNAME.sinners.be.log | grep -i bol
IP_USER - - [09/Sep/2014:17:18:34 +0200] "GET /SUBFOLDER/application/img/Hondenbol200.png HTTP/1.1" 404 544 "http://USERNAME.sinners.be/SUBFOLDER/index.php" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.44 Safari/537.36"
IP_USER - - [09/Sep/2014:17:20:29 +0200] "GET /SUBFOLDER/application/img/Hondenbol200.png HTTP/1.1" 404 544 "http://USERNAME.sinners.be/SUBFOLDER/index.php" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.44 Safari/537.36"
IP_USER - - [09/Sep/2014:17:43:45 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222132 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.44 Safari/537.36"
IP_USER - - [10/Sep/2014:17:13:05 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.103 Safari/537.36"
IP_ME - - [20/Sep/2014:13:50:38 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222130 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:13:53:23 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:13:53:41 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_USER - - [20/Sep/2014:13:53:39 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.66 Safari/537.36"
IP_USER - - [20/Sep/2014:13:53:38 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.66 Safari/537.36"
RANDOM_IP - - [20/Sep/2014:13:55:17 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.0" 200 222094 "-" "-"
IP_ME - - [20/Sep/2014:13:56:14 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 183 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_ME - - [20/Sep/2014:13:56:15 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_ME - - [20/Sep/2014:13:56:15 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_ME - - [20/Sep/2014:13:56:15 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_USER - - [20/Sep/2014:13:53:39 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.66 Safari/537.36"
IP_ME - - [20/Sep/2014:13:59:58 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:14:01:04 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:14:01:38 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222131 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_USER - - [20/Sep/2014:14:02:39 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222130 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.66 Safari/537.36"
IP_USER - - [20/Sep/2014:14:03:17 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 183 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/38.0.2125.66 Safari/537.36"
File:
-rwxr-xr-x 1 USERNAME user 221841 Sep 10 01:22 Hondenbol.png
root@web:~# uname -a
Linux web 3.14-2-amd64 #1 SMP Debian 3.14.15-2 (2014-08-09) x86_64 GNU/Linux
root@web:~# apache2 -v
Server version: Apache/2.4.10 (Debian)
Server built: Jul 23 2014 13:15:48
root@web:~# php -v
PHP 5.6.0-1 (cli) (built: Aug 28 2014 13:03:02)
Copyright (c) 1997-2014 The PHP Group
Zend Engine v2.6.0, Copyright (c) 1998-2014 Zend Technologies
with Zend OPcache v7.0.4-dev, Copyright (c) 1999-2014, by Zend Technologies
We use mpm-itk.
Update 1
Thanks, @kasperd. I added %D to the log file and found a fellow staff member with the same issue. I asked him to (fully) load the website in question a few times.
To clarify; The page itself loads fine. It's just the images on the page that are troublesome for some people, but they're always the same images.
Log for fellow staff member's visits:
IP_OTHER_GUY - - [20/Sep/2014:21:18:38 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 206 339 2602 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:18:38 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 206 341 11028 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:18:38 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 984 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:18:38 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 206 252546 33461847 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:18:38 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 206 184858 61415214 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:33:29 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1078 30539 "http://l.facebook.com/lsr.php?u=http%3A%2F%2FUSERNAME.sinners.be%2FSUBFOLDER%2F&ext=1411241671&hash=" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:33:29 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 864 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:33:39 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1078 30241 "http://l.facebook.com/lsr.php?u=http%3A%2F%2FUSERNAME.sinners.be%2FSUBFOLDER%2F&ext=1411241671&hash=" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:33:39 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 2659 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:33:39 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 506 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:34:04 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1078 50469 "http://l.facebook.com/lsr.php?u=http%3A%2F%2FUSERNAME.sinners.be%2FSUBFOLDER%2F&ext=1411241671&hash=" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:34:04 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 1663 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:34:04 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 562 8751 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:34:04 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 200 310256 48043620 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:34:04 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 200 222130 61975581 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:35:07 +0200] "GET /favicon.ico HTTP/1.1" 404 506 2452 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:36:08 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1078 33676 "http://l.facebook.com/lsr.php?u=http%3A%2F%2FUSERNAME.sinners.be%2FSUBFOLDER%2F&ext=1411241671&hash=" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:36:08 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 3005 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:36:08 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 562 8426 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
IP_OTHER_GUY - - [20/Sep/2014:21:36:08 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 200 310256 60066766 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/37.0.2062.120 Safari/537.36"
Log for my visits:
IP_ME - - [20/Sep/2014:21:32:59 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1078 55236 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:32:59 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 1154 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:32:59 +0200] "GET /favicon.ico HTTP/1.1" 404 506 216 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:32:59 +0200] "GET /favicon.ico HTTP/1.1" 404 506 183 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:16 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1078 51083 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:16 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 2006 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:16 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 774 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:16 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 717 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:16 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 304 183 9232 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:16 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1077 9386 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 657 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 304 182 488 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 183 8270 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 392 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1077 9150 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 1028 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 777 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 304 182 487 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:17 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 340 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1077 8646 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 746 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 287 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 304 182 699 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 311 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1077 7981 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 349 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 304 182 238 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 2150 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:18 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 291 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:19 +0200] "GET /SUBFOLDER/ HTTP/1.1" 200 1077 22099 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:19 +0200] "GET /SUBFOLDER/application/css/style.css HTTP/1.1" 200 1304 822 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:19 +0200] "GET /SUBFOLDER/application/img/Hondenbol.png HTTP/1.1" 304 182 345 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:19 +0200] "GET /SUBFOLDER/application/img/banner.jpg HTTP/1.1" 304 182 217 "http://USERNAME.sinners.be/SUBFOLDER/" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
IP_ME - - [20/Sep/2014:21:37:19 +0200] "GET /SUBFOLDER/application/css/afbeeldingen/template/pattern.png HTTP/1.1" 404 561 265 "http://USERNAME.sinners.be/SUBFOLDER/application/css/style.css" "Mozilla/5.0 (X11; Linux x86_64; rv:32.0) Gecko/20100101 Firefox/32.0"
As you can see, the loading/processing times for my visits are much lower.
All the people who have problems with this seem to have Telenet as their internet service provider. People who have Belgacom (which is the only other choice here) don't seem to have this problem. This could be a coincidence, though. It's just something I noticed; I'm not sure whether this can be related.
Update 2
For reference, a test page; http://robinj1995.sinners.be/test/index_en.php
The first fieldset (block) is the most relevant one here.
Update 3
We tried with a non-Apache web server (GitLab's Unicorn) and experienced the same kind of issues. It seems the problem is related to a network/firewall issue, and not a problem with our Apache configuration.
Our firewall and/or stepping stone is a server running Debian stable with iptables.
Solution 1:
Status code 304 means the cached copy is still up to date, and no data was sent to the client. You'll see that the byte count is small for all the requests with status code 304 and about the size of the file for all the requests with status code 200.
But transferring 200KB of static data should only take a fraction of a second, if you have a decent connection speed. So this might not be the bottleneck you are looking for.
For debugging Apache performance problems, I find it useful to include %D in the LogFormat. That will tell you how many microseconds it took to process the request.
Solution 2:
There are several variables here (different browsers, source IP addresses), but these are all external to your web server. If you've seen a pattern based on the users' ISPs, then try to come up with some quantified metrics around it. For instance, you can track network time to load an image from the browser.
For instance, in Chrome (developer tools, click the "network tab"), you can load an image via URL and track the request size, HTTP method, HTTP status, and total network latency. Note that you can toggle the "disable cache" checkbox to view caching impact - most of your IP_ME requests were 304 (cached) vs. IP_OTHER, which were 200 (uncached).
Try testing with your own Hondenbol.jpg URL (cached/not cached). Then also try to load a neutral image from an unrelated server (I tested with an arbitrary one, http://telefonica.cl/images/new-home/banners/banner-tripack-moviecity.jpg, located somewhere in Chile).
With this testing you should be able to confirm if a) it's just caching, or b) that the latency is external to your web server and related to the users' ISPs.
Solution 3:
If you look at the logfile for the client who is having problems, you'll see repeated HTTP 206 response codes.
You will see a 206 response when you client is requesting a partial download of a resource, which could arise for various reason eg it has downloaded some of that resource before, it recognises that it is a large binary file, or its attempting some sort of bandwidth control.
Where you see a HTTP 304 response, that means that the client has requested the resource only if the cache on that resource hasn't expired. If the cache hasn't expired, the server doesn't send any data; it just tells the client that its OK to load the file from the client cache, as it hasn't changed on the server.
As such, these response will always render the content quickly, as the resource is being loaded locally.
If the pattern in the shared logs is typical, then the issue is caused by the browser making repeated requests for partial content, and only getting the full content after repeated attempts.
That could be to do with proxying, browser configuration or just network latency. If you could provide a live link to one of the image files, more debug would be possible.