Checking the elapsed time for a database query for munin monitoring,I have created a script, the time measurement part being:
start=$(sed 's/^0*//'<<< `date +%N`) /usr/bin/mysql -u 3da_d9 -p****** --host="127.0.0.1" --port=4002 -e "SELECT f.*, AVG(l.value) AS vote_value, COUNT(l.value) AS vote_count, 0 AS active_feature, c.name from 3dallusions_joomla_d9.jom3_downloads_files AS f INNER JOIN 3dallusions_joomla_d9.jom3_downloads_containers AS c ON f.containerid = c.id LEFT JOIN 3dallusions_joomla_d9.jom3_downloads_log AS l ON l.type = 3 AND l.fileid = f.id AND l.value != 0" > /dev/null end=$(sed 's/^0*//'<<< `date +%N`) if [ "$end" -lt "$start" ]; then end=$(($end+1000000000)) fi elapsed=$(($end - $start)) elapsed=$(($elapsed/1000000)) echo $elapsed
I've checked the logic of the time measurement by replacing the SQL call with a simple sleep. That gives a consistent result every time.
The database and client are MariaDB 10.1 from the Debian Stretch repository.
The thing that is puzzling me is that the first time I run the script, the answer is around 10 milliseconds. Subsequent runs give about 50 milliseconds. After not running the script for a while, a result of around 10 is obtained again.
Why would a query be five times quicker the first time than when repeated? One might expect caching to cause the opposite effect. What is happening?