SQLite Forum

sqlite CLI: .timer - should be whole transaction?
Login

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