On 8/28/19 11:36 AM, francis picabia wrote:
The server was running Moodle. The slow load time was noticed when
loading a quiz containing
multiple images. All Apache log results showed a 6 seconds or a
multiple of 6 for how long
it took to retrieve each image.
Interestingly, if I did a wget, on the server, to the image link (which
was processed through a pluginfile.php URL)
even the HTML page returned of "please login first" took consistently 6
seconds. Never 2, 3, 4, 5 or 7, 8, 9...
So whatever was wrong, there was a 6 second penalty for this. We found
the problem
Caching software in the mix?
More below.
outside of the quizzes as well, so it wasn't a single part of the PHP
code. In addition, our development
server with a clone of data, database, apps, etc., was fast at doing any
of the tests.
Of course a database brought in with a dump will not include any of the
cruft
DB structures, so the dev server was free of the problem (and it had
fewer cores, memory, etc).
I was not suspecting PostgreSQL as the culprit, because all query times
in the log showed
roughly 1 ms response. I could tail -f the log file while loading a
quiz to watch the times
reported.
Last night the vacuum was run (on a database of about 40GB if dumped),
and since
then the quizzes and everything run as fast as would be expected. It
had run
for about 1.5 months without vacuum.
Apache, PHP and Postgres all on the same server. Memory and CPUs not
taxed, load kept level
while the problem quizzes were being tested.
Given this experience, I'd like something that reflected the true times
Postgres was spending
on any work it was doing.
The log_duration will show that.
If you want to verify open psql and set \timing on and run your statements.
The other possibility was it just didn't log the slower times, but I
have seen larger numbers
in the 10,000 ms range in the night when some backups and housekeeping
happens.
All log related settings:
checkpoint_segments = 12
logging_collector = on
log_destination = 'stderr'
log_directory = 'pg_log'
log_filename = 'postgresql-%a.log'
log_truncate_on_rotation = on
log_rotation_age = 1440
log_rotation_size = 0
log_min_messages = info
log_min_error_statement = debug1
log_duration = on
log_line_prefix = '<%t>'
I know it does sound strange, but this is what we battled with for 2.5
days until the light
came on that the vacuum had been set to off on the target system during
server migration.
--
Adrian Klaver
adrian.klaver@xxxxxxxxxxx
