mirrors/pgloader
1
0
Fork 0
mirror of https://github.com/dimitri/pgloader.git synced 2026-02-03 21:41:47 +01:00
Code Issues Projects Releases Wiki Activity

Simplify how to compute total load time, see #283.

Browse Source 
In some cases pgloader total time computing is quite off: in the archive
case because it fails to take into account per-file before and after
sections, and in the general case when there's parallel work done.

This patch helps by storing the start time explicitely and using it at
the moment when the summary is displayed: no guessing any more. This is
only used in the archive case for now because I want some feedback.

On my machine with the usual test cases I have, the difference with and
without this patch is line-noise, something more serious has to be done:
let's push testing to the user by committing this early version of the
work.
This commit is contained in:
Dimitri Fontaine 2015-08-29 23:08:22 +02:00
parent d71d39c59f
commit 72fdf112ff
3 changed files with 15 additions and 10 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
src/parsers/command-archive.lisp
View File

@ -42,7 +42,8 @@
(when (and (or before finally) (null pg-db-conn))
(error "When using a BEFORE LOAD DO or a FINALLY block, you must provide an archive level target database connection."))
`(lambda ()
(let* ((state-before (pgloader.utils:make-pgstate))
(let* ((start-irt (get-internal-real-time))
(state-before (pgloader.utils:make-pgstate))
(*state* (pgloader.utils:make-pgstate))
,@(pgsql-connection-bindings pg-db-conn nil)
(state-finally ,(when finally `(pgloader.utils:make-pgstate)))
@ -67,5 +68,6 @@
;; reporting
(report-full-summary "Total import time" *state*
:start-time start-irt
:before state-before
:finally state-finally)))))))

17
src/utils/report.lisp
View File

@ -159,7 +159,7 @@
(t :human-readable))))
(defun report-full-summary (legend state
&key before finally parallel)
&key before finally parallel start-time)
"Report the full story when given three different sections of reporting."
(let* ((stype (or (parse-summary-type *summary-pathname*)
@ -208,12 +208,15 @@
;; if the parallel tasks took longer than the rest cumulated, the total
;; waiting time actually was parallel - before
(when (and parallel
(< (pgloader.utils::pgstate-secs state)
(pgloader.utils::pgstate-secs parallel)))
(setf (pgloader.utils::pgstate-secs state)
(- (pgloader.utils::pgstate-secs parallel)
(if before (pgloader.utils::pgstate-secs before) 0))))
(if start-time
(setf (pgloader.utils::pgstate-secs state)
(pgloader.utils::elapsed-time-since start-time))
(when (and parallel
(< (pgloader.utils::pgstate-secs state)
(pgloader.utils::pgstate-secs parallel)))
(setf (pgloader.utils::pgstate-secs state)
(- (pgloader.utils::pgstate-secs parallel)
(if before (pgloader.utils::pgstate-secs before) 0)))))
;; and report the Grand Total
(report-pgstate-stats state legend)))

4
src/utils/utils.lisp
View File

@ -8,8 +8,8 @@
;;;
(defun elapsed-time-since (start)
"Return how many seconds ticked between START and now"
(/ (- (get-internal-real-time) start)
internal-time-units-per-second))
(let ((now (get-internal-real-time)))
(coerce (/ (- now start) internal-time-units-per-second) 'double-float)))
(defmacro timing (&body forms)
"return both how much real time was spend in body and its result"