From 0a88645eb58d8544fde8ad3cbaa598a245745040 Mon Sep 17 00:00:00 2001 From: Dimitri Fontaine Date: Sat, 21 Oct 2017 21:04:55 +0200 Subject: [PATCH] Fix time measurements of the write activity. When using --verbose or more detailed log messages, the summary prints timings for both read and write operations separately. The write summary timing took into account only the PostgreSQL batch activity, discarding the formatting of the data done by pgloader. As this formatting is quite heavy at the moment, the results are pretty misleading without that information. --- src/pgsql/copy-from-queue.lisp | 13 +++++++------ 1 file changed, 7 insertions(+), 6 deletions(-) diff --git a/src/pgsql/copy-from-queue.lisp b/src/pgsql/copy-from-queue.lisp index d01b0a1..36ac472 100644 --- a/src/pgsql/copy-from-queue.lisp +++ b/src/pgsql/copy-from-queue.lisp @@ -164,21 +164,22 @@ ;; if current-batch is full, send data to PostgreSQL ;; and prepare a new batch (when (batch-full-p current-batch) - (let ((batch-seconds - (send-current-batch unqualified-table-name))) - (incf seconds batch-seconds)) + (incf seconds (send-current-batch unqualified-table-name)) (setf current-batch (make-batch)) ;; give a little help to our friend, now is a good time ;; to garbage collect #+sbcl (sb-ext:gc :full t)) - (format-row-in-batch copy row current-batch - preprocessor pre-formatted))) + ;; also add up the time it takes to format the rows + (let ((start-time (get-internal-real-time))) + (format-row-in-batch copy row current-batch + preprocessor pre-formatted) + (incf seconds (elapsed-time-since start-time))))) ;; the last batch might not be empty (unless (= 0 (batch-count current-batch)) - (send-current-batch unqualified-table-name)))))) + (incf seconds (send-current-batch unqualified-table-name))))))) ;; each writer thread sends its own stop timestamp and the monitor keeps ;; only the latest entry