sqlite CLI: .timer - should be whole transaction?
(1) By midijohnny on 2021-11-26 19:13:54 [link] [source]
I am loading ~80k rows of data using SQL via the 'sqlite3' CLI '.read' command:
sqlite> .version
SQLite 3.36.0 [...]
sqlite> .timer on
sqlite> .read load.sql
The SQL itself wrapped in a TRANSACTION like this:
BEGIN TRANSACTION;
-- many INSERT statements --
END TRANSACTION;
I notice the output from the .timer is for every statement, rather than the whole batch:
Run Time: real 0.000 user 0.000000 sys 0.000000
Run Time: real 0.912 user 0.015625 sys 0.125000
Run Time: real 0.000 user 0.000000 sys 0.000000
Run Time: real 0.794 user 0.000000 sys 0.484375
Run Time: real 0.000 user 0.000000 sys 0.000000
Run Time: real 0.968 user 0.000000 sys 0.484375
Run Time: real 0.000 user 0.000000 sys 0.000000
Run Time: real 0.855 user 0.000000 sys 0.203125
Run Time: real 0.000 user 0.000000 sys 0.000000
[...]
Is this the correct behaviour/useful? In my case; I happen to more interested in the total time/summary for the whole batch, rather than a list of individual timings. I also assume that this output in fact slows down the overall import? Wouldn't it be more appropriate to just treat the whole block as a batch and show an average timing here?
(2) By Keith Medcalf (kmedcalf) on 2021-11-26 20:37:49 in reply to 1 [link] [source]
Is this the correct behaviour/useful?
Yes, this is the correct behaviour. Usefulness is in the eye of the beholder.
I happen to more interested in the total time/summary for the whole batch, rather than a list of individual timings.
As you have discovered, .timer
does not do this. If you want to do this, then I would suggest that you do what you require. One such possibility is:
timethis sqlite3 dumdum.db < load.sql
I also assume that this output in fact slows down the overall import?
Of course it does. Significantly. I/O is slow and the fastest way to do I/O is to not do it.
Wouldn't it be more appropriate to just treat the whole block as a batch and show an average timing here?
You are entirely free to do that.
(3) By midijohnny on 2021-11-26 21:00:22 in reply to 2 [link] [source]
Thanks ! And in the meantime I came up with some additional SQL to achieve what I need here.
--mysql.sql
DROP TABLE IF EXISTS _timer;
CREATE TEMPORARY TABLE _timer AS SELECT strftime('%s','now') AS start, NULL as end;
BEGIN TRANSACTION;
-- many inserts here --
END TRANSACTION;
UPDATE _timer SET end=strftime('%s','now');
SELECT PRINTF("Elapsed Time: %d seconds", end-start) FROM _timer;
Example Output:
sqlite> .read mysql.sql
Elapsed Time: 87 seconds
(4) By Keith Medcalf (kmedcalf) on 2021-11-26 21:35:49 in reply to 3 [link] [source]
Excellent. If you need millisecond precision then use the julianday function, and multiply the difference by 86400 to get the difference in seconds.milliseconds.
(5) By Mark Lawrence (mark) on 2021-11-29 08:46:48 in reply to 3 [source]
You could also (ab)use the Shell's .parameter command to avoid polluting your table namespace:
.parameter init
.parameter set $start julianday()
BEGIN TRANSACTION;
-- many inserts here --
END TRANSACTION;
SELECT printf('Elapsed Time: %d seconds', 86400 * (julianday() - $start));
(6) By anonymous on 2021-12-01 19:53:42 in reply to 5 [link] [source]
Nice improvement - and I guess might also want to clear the param at the end, just to tidy up.
.param unset $start