[GENERAL] Runtime analysis - Mailing list pgsql-general
From | Neto pr |
---|---|
Subject | [GENERAL] Runtime analysis |
Date | |
Msg-id | CA+TZvY+PayZ3fCScKYw8=c6bx6MFpi6VZ3SJLfMFU8p7myOzxQ@mail.gmail.com Whole thread Raw |
Responses |
Re: [GENERAL] Runtime analysis
|
List | pgsql-general |
Hello All,
I was measuring the execution time of 18 queries from the TPC-H benchmark.
I run 10 times each query using the EXPLAIN ANALYZE command and store the times in a table called control_tab.
To record the times, I have a java program that does the whole process as follows:
Step 1: Insert into Tab_control values (query_No, start_time) of query x
Step 2: Run the EXPLAIN ANALYZE command (inside Java)
Step 3: Update to save the final time of the query x and also the execution plan obtained.
After the 10th execution, I restart the DBMS and delete the cache this way:
/etc/init.d/pgsql stop
sync
echo 3> / proc / sys / vm / drop_caches
/etc/init.d/pgsql start
I expected that the first run would always take longer than the others because of not having cached data, but look what happened:
See at the end of the email, which had cases that the 1nd execution was 56% more faster than the 2nd execution.
If anyone has any suspicion or explanation, why in some cases the first execution can be faster than the others, please reply to this email.
Note: My server is dedicated to the DBMS and during the test it did not have concurrent query executions.
The programs that were running at the time of the executions believe that they did not influence, because during the tests were little used, they are: web browser, libreoffice calc, Java eclipse, DBeaver, Konsole.
The features of the server are: Postgresql 10, 4 GB Ram, Xeon 2.8GHz / 4-core, S.O Debian 8.
If someone wants to see the execution plans and other information the worksheet with results is at the following link:
https://sites.google.com/site/ eletrolareshop/repository/ Result_80gb-SSD-10_exec_v4.ods
query 52 = 2, 53 = 3 on Tpch benchmark... I was measuring the execution time of 18 queries from the TPC-H benchmark.
I run 10 times each query using the EXPLAIN ANALYZE command and store the times in a table called control_tab.
To record the times, I have a java program that does the whole process as follows:
Step 1: Insert into Tab_control values (query_No, start_time) of query x
Step 2: Run the EXPLAIN ANALYZE command (inside Java)
Step 3: Update to save the final time of the query x and also the execution plan obtained.
After the 10th execution, I restart the DBMS and delete the cache this way:
/etc/init.d/pgsql stop
sync
echo 3> / proc / sys / vm / drop_caches
/etc/init.d/pgsql start
I expected that the first run would always take longer than the others because of not having cached data, but look what happened:
- in 6 cases the first execution was more faster than all executions.
- in 2 cases only, the first exececution was more slower than all executions
See at the end of the email, which had cases that the 1nd execution was 56% more faster than the 2nd execution.
If anyone has any suspicion or explanation, why in some cases the first execution can be faster than the others, please reply to this email.
Note: My server is dedicated to the DBMS and during the test it did not have concurrent query executions.
The programs that were running at the time of the executions believe that they did not influence, because during the tests were little used, they are: web browser, libreoffice calc, Java eclipse, DBeaver, Konsole.
The features of the server are: Postgresql 10, 4 GB Ram, Xeon 2.8GHz / 4-core, S.O Debian 8.
If someone wants to see the execution plans and other information the worksheet with results is at the following link:
https://sites.google.com/site/
QUERY No | BEGIN TIME | END TIME | TIME SPENT | |||
52 | 2017-11-02 20:44:33 | 2017-11-02 20:48:11 | 00:03:38 | 1ª Execution was faster | 56.6 | % than the 2ª |
52 | 2017-11-02 20:48:11 | 2017-11-02 20:56:34 | 00:08:22 | |||
52 | 2017-11-02 20:56:34 | 2017-11-02 21:06:19 | 00:09:45 | |||
52 | 2017-11-02 21:06:19 | 2017-11-02 21:16:52 | 00:10:32 | |||
52 | 2017-11-02 21:16:52 | 2017-11-02 21:28:00 | 00:11:07 | |||
52 | 2017-11-02 21:28:00 | 2017-11-02 21:39:29 | 00:11:29 | |||
52 | 2017-11-02 21:39:29 | 2017-11-02 21:50:59 | 00:11:29 | |||
52 | 2017-11-02 21:50:59 | 2017-11-02 22:02:23 | 00:11:23 | |||
52 | 2017-11-02 22:02:23 | 2017-11-02 22:13:40 | 00:11:17 | |||
52 | 2017-11-02 22:13:40 | 2017-11-02 22:25:11 | 00:11:31 | |||
53 | 2017-11-02 22:25:20 | 2017-11-02 22:48:15 | 00:22:54 | |||
53 | 2017-11-02 22:48:15 | 2017-11-02 23:08:36 | 00:20:20 | |||
53 | 2017-11-02 23:08:36 | 2017-11-02 23:26:50 | 00:18:13 | |||
53 | 2017-11-02 23:26:50 | 2017-11-02 23:46:16 | 00:19:26 | |||
53 | 2017-11-02 23:46:16 | 2017-11-03 00:05:37 | 00:19:20 | |||
53 | 2017-11-03 00:05:37 | 2017-11-03 00:25:42 | 00:20:05 | |||
53 | 2017-11-03 00:25:42 | 2017-11-03 00:46:10 | 00:20:27 | |||
53 | 2017-11-03 00:46:10 | 2017-11-03 01:03:05 | 00:16:55 | |||
53 | 2017-11-03 01:03:05 | 2017-11-03 01:19:55 | 00:16:49 | |||
53 | 2017-11-03 01:19:55 | 2017-11-03 01:37:12 | 00:17:17 | |||
54 | 2017-11-03 01:37:20 | 2017-11-03 01:45:08 | 00:07:47 | |||
54 | 2017-11-03 01:45:08 | 2017-11-03 01:53:00 | 00:07:51 | |||
54 | 2017-11-03 01:53:00 | 2017-11-03 02:00:50 | 00:07:50 | |||
54 | 2017-11-03 02:00:50 | 2017-11-03 02:08:43 | 00:07:52 | |||
54 | 2017-11-03 02:08:43 | 2017-11-03 02:16:34 | 00:07:51 | |||
54 | 2017-11-03 02:16:34 | 2017-11-03 02:24:24 | 00:07:50 | |||
54 | 2017-11-03 02:24:24 | 2017-11-03 02:32:15 | 00:07:50 | |||
54 | 2017-11-03 02:32:15 | 2017-11-03 02:40:04 | 00:07:49 | |||
54 | 2017-11-03 02:40:04 | 2017-11-03 02:47:51 | 00:07:46 | |||
54 | 2017-11-03 02:47:51 | 2017-11-03 02:55:40 | 00:07:48 | |||
55 | 2017-11-03 02:55:47 | 2017-11-03 03:19:27 | 00:23:39 | |||
55 | 2017-11-03 03:19:27 | 2017-11-03 03:43:12 | 00:23:45 | |||
55 | 2017-11-03 03:43:12 | 2017-11-03 04:08:04 | 00:24:51 | |||
55 | 2017-11-03 04:08:04 | 2017-11-03 04:31:58 | 00:23:54 | |||
55 | 2017-11-03 04:31:58 | 2017-11-03 04:56:13 | 00:24:15 | |||
55 | 2017-11-03 04:56:14 | 2017-11-03 05:20:54 | 00:24:40 | |||
55 | 2017-11-03 05:20:54 | 2017-11-03 05:46:07 | 00:25:13 | |||
55 | 2017-11-03 05:46:07 | 2017-11-03 06:11:35 | 00:25:27 | |||
55 | 2017-11-03 06:11:35 | 2017-11-03 06:36:43 | 00:25:07 | |||
55 | 2017-11-03 06:36:43 | 2017-11-03 07:03:18 | 00:26:34 | |||
56 | 2017-11-03 07:03:26 | 2017-11-03 07:06:57 | 00:03:31 | 1ª Execution was faster | 4.1 | % than the2ª |
56 | 2017-11-03 07:06:57 | 2017-11-03 07:10:38 | 00:03:40 | |||
56 | 2017-11-03 07:10:38 | 2017-11-03 07:14:18 | 00:03:40 | |||
56 | 2017-11-03 07:14:18 | 2017-11-03 07:17:59 | 00:03:40 | |||
56 | 2017-11-03 07:17:59 | 2017-11-03 07:21:41 | 00:03:42 | |||
56 | 2017-11-03 07:21:41 | 2017-11-03 07:25:22 | 00:03:40 | |||
56 | 2017-11-03 07:25:22 | 2017-11-03 07:29:02 | 00:03:40 | |||
56 | 2017-11-03 07:29:02 | 2017-11-03 07:32:42 | 00:03:39 | |||
56 | 2017-11-03 07:32:42 | 2017-11-03 07:36:22 | 00:03:40 | |||
56 | 2017-11-03 07:36:22 | 2017-11-03 07:40:05 | 00:03:42 | |||
57 | 2017-11-03 07:40:12 | 2017-11-03 07:50:48 | 00:10:36 | |||
57 | 2017-11-03 07:50:49 | 2017-11-03 08:01:26 | 00:10:37 | |||
57 | 2017-11-03 08:01:26 | 2017-11-03 08:12:05 | 00:10:38 | |||
57 | 2017-11-03 08:12:05 | 2017-11-03 08:22:19 | 00:10:14 | |||
57 | 2017-11-03 08:22:19 | 2017-11-03 08:32:35 | 00:10:15 | |||
57 | 2017-11-03 08:32:35 | 2017-11-03 08:43:04 | 00:10:28 | |||
57 | 2017-11-03 08:43:04 | 2017-11-03 08:52:57 | 00:09:53 | |||
57 | 2017-11-03 08:52:57 | 2017-11-03 09:02:50 | 00:09:53 | |||
57 | 2017-11-03 09:02:50 | 2017-11-03 09:12:38 | 00:09:47 | |||
57 | 2017-11-03 09:12:38 | 2017-11-03 09:22:51 | 00:10:12 | |||
58 | 2017-11-03 09:22:58 | 2017-11-03 09:32:22 | 00:09:24 | |||
58 | 2017-11-03 09:32:22 | 2017-11-03 09:41:47 | 00:09:24 | |||
58 | 2017-11-03 09:41:47 | 2017-11-03 09:51:27 | 00:09:39 | |||
58 | 2017-11-03 09:51:27 | 2017-11-03 10:00:29 | 00:09:01 | |||
58 | 2017-11-03 10:00:29 | 2017-11-03 10:09:21 | 00:08:52 | |||
58 | 2017-11-03 10:09:22 | 2017-11-03 10:18:07 | 00:08:45 | |||
58 | 2017-11-03 10:18:08 | 2017-11-03 10:26:57 | 00:08:49 | |||
58 | 2017-11-03 10:26:57 | 2017-11-03 10:35:50 | 00:08:52 | |||
58 | 2017-11-03 10:35:50 | 2017-11-03 10:45:14 | 00:09:23 | |||
58 | 2017-11-03 10:45:14 | 2017-11-03 10:54:24 | 00:09:10 | |||
59 | 2017-11-03 10:54:33 | 2017-11-03 12:08:16 | 01:13:42 | |||
59 | 2017-11-03 12:08:16 | 2017-11-03 13:23:45 | 01:15:28 | |||
59 | 2017-11-03 13:23:45 | 2017-11-03 14:37:34 | 01:13:49 | |||
59 | 2017-11-03 14:37:34 | 2017-11-03 15:50:30 | 01:12:55 | |||
59 | 2017-11-03 15:50:30 | 2017-11-03 17:03:11 | 01:12:40 | |||
59 | 2017-11-03 17:03:11 | 2017-11-03 18:15:43 | 01:12:32 | |||
59 | 2017-11-03 18:15:43 | 2017-11-03 19:28:17 | 01:12:33 | |||
59 | 2017-11-03 19:28:17 | 2017-11-03 20:41:36 | 01:13:19 | |||
59 | 2017-11-03 20:41:36 | 2017-11-03 21:54:16 | 01:12:39 | |||
59 | 2017-11-03 21:54:16 | 2017-11-03 23:07:07 | 01:12:51 | |||
60 | 2017-11-03 23:07:16 | 2017-11-03 23:23:10 | 00:15:53 | 1ª Execution was faster | 0.2 | % than the2ª |
60 | 2017-11-03 23:23:10 | 2017-11-03 23:39:22 | 00:16:11 | |||
60 | 2017-11-03 23:39:22 | 2017-11-03 23:55:12 | 00:15:50 | |||
60 | 2017-11-03 23:55:12 | 2017-11-04 00:11:36 | 00:16:23 | |||
60 | 2017-11-04 00:11:36 | 2017-11-04 00:27:20 | 00:15:43 | |||
60 | 2017-11-04 00:27:20 | 2017-11-04 00:42:51 | 00:15:31 | |||
60 | 2017-11-04 00:42:51 | 2017-11-04 00:58:58 | 00:16:07 | |||
60 | 2017-11-04 00:58:59 | 2017-11-04 01:15:31 | 00:16:32 | |||
60 | 2017-11-04 01:15:31 | 2017-11-04 01:32:13 | 00:16:41 | |||
60 | 2017-11-04 01:32:13 | 2017-11-04 01:49:41 | 00:17:28 | |||
61 | 2017-11-04 01:49:49 | 2017-11-04 01:50:48 | 00:00:59 | |||
61 | 2017-11-04 01:50:48 | 2017-11-04 01:51:46 | 00:00:57 | |||
61 | 2017-11-04 01:51:46 | 2017-11-04 01:52:44 | 00:00:57 | |||
61 | 2017-11-04 01:52:44 | 2017-11-04 01:53:42 | 00:00:58 | |||
61 | 2017-11-04 01:53:42 | 2017-11-04 01:54:40 | 00:00:57 | |||
61 | 2017-11-04 01:54:40 | 2017-11-04 01:55:38 | 00:00:57 | |||
61 | 2017-11-04 01:55:38 | 2017-11-04 01:56:35 | 00:00:57 | |||
61 | 2017-11-04 01:56:35 | 2017-11-04 01:57:32 | 00:00:57 | |||
61 | 2017-11-04 01:57:32 | 2017-11-04 01:58:30 | 00:00:57 | |||
61 | 2017-11-04 01:58:30 | 2017-11-04 01:59:27 | 00:00:57 | |||
62 | 2017-11-04 01:59:34 | 2017-11-04 02:05:28 | 00:05:53 | |||
62 | 2017-11-04 02:05:28 | 2017-11-04 02:11:28 | 00:05:59 | |||
62 | 2017-11-04 02:11:28 | 2017-11-04 02:17:27 | 00:05:59 | |||
62 | 2017-11-04 02:17:27 | 2017-11-04 02:23:26 | 00:05:59 | |||
62 | 2017-11-04 02:23:26 | 2017-11-04 02:29:26 | 00:06:00 | |||
62 | 2017-11-04 02:29:26 | 2017-11-04 02:35:27 | 00:06:00 | |||
62 | 2017-11-04 02:35:27 | 2017-11-04 02:41:26 | 00:05:59 | |||
62 | 2017-11-04 02:41:26 | 2017-11-04 02:47:26 | 00:06:00 | |||
62 | 2017-11-04 02:47:26 | 2017-11-04 02:53:25 | 00:05:58 | |||
62 | 2017-11-04 02:53:25 | 2017-11-04 02:59:25 | 00:05:59 | |||
63 | 2017-11-04 02:59:32 | 2017-11-04 03:10:20 | 00:10:48 | 1ª Execution was faster | 14.1 | % than the2ª |
63 | 2017-11-04 03:10:20 | 2017-11-04 03:22:55 | 00:12:34 | |||
63 | 2017-11-04 03:22:55 | 2017-11-04 03:35:11 | 00:12:16 | |||
63 | 2017-11-04 03:35:11 | 2017-11-04 03:48:18 | 00:13:07 | |||
63 | 2017-11-04 03:48:18 | 2017-11-04 04:00:41 | 00:12:22 | |||
63 | 2017-11-04 04:00:41 | 2017-11-04 04:13:15 | 00:12:34 | |||
63 | 2017-11-04 04:13:15 | 2017-11-04 04:26:02 | 00:12:47 | |||
63 | 2017-11-04 04:26:02 | 2017-11-04 04:38:16 | 00:12:13 | |||
63 | 2017-11-04 04:38:16 | 2017-11-04 04:50:44 | 00:12:27 | |||
63 | 2017-11-04 04:50:44 | 2017-11-04 05:02:53 | 00:12:09 | |||
64 | 2017-11-04 05:03:01 | 2017-11-04 05:08:55 | 00:05:53 | 1ª Execution was faster | 1.7 | % than the2ª |
64 | 2017-11-04 05:08:55 | 2017-11-04 05:14:54 | 00:05:59 | |||
64 | 2017-11-04 05:14:54 | 2017-11-04 05:20:54 | 00:05:59 | |||
64 | 2017-11-04 05:20:54 | 2017-11-04 05:26:54 | 00:06:00 | |||
64 | 2017-11-04 05:26:54 | 2017-11-04 05:32:55 | 00:06:00 | |||
64 | 2017-11-04 05:32:55 | 2017-11-04 05:38:55 | 00:06:00 | |||
64 | 2017-11-04 05:38:55 | 2017-11-04 05:44:57 | 00:06:01 | |||
64 | 2017-11-04 05:44:57 | 2017-11-04 05:50:58 | 00:06:00 | |||
64 | 2017-11-04 05:50:58 | 2017-11-04 05:57:00 | 00:06:01 | |||
64 | 2017-11-04 05:57:00 | 2017-11-04 06:03:01 | 00:06:01 | |||
65 | 2017-11-04 06:03:09 | 2017-11-04 06:13:22 | 00:10:13 | |||
65 | 2017-11-04 06:13:22 | 2017-11-04 06:24:00 | 00:10:38 | |||
65 | 2017-11-04 06:24:00 | 2017-11-04 06:34:23 | 00:10:22 | |||
65 | 2017-11-04 06:34:23 | 2017-11-04 06:45:02 | 00:10:38 | |||
65 | 2017-11-04 06:45:02 | 2017-11-04 06:55:38 | 00:10:35 | |||
65 | 2017-11-04 06:55:38 | 2017-11-04 07:05:55 | 00:10:17 | |||
65 | 2017-11-04 07:05:56 | 2017-11-04 07:16:03 | 00:10:07 | |||
65 | 2017-11-04 07:16:03 | 2017-11-04 07:26:51 | 00:10:47 | |||
65 | 2017-11-04 07:26:51 | 2017-11-04 07:37:17 | 00:10:25 | |||
65 | 2017-11-04 07:37:17 | 2017-11-04 07:47:37 | 00:10:19 | |||
66 | 2017-11-04 07:47:44 | 2017-11-04 07:51:12 | 00:03:28 | |||
66 | 2017-11-04 07:51:12 | 2017-11-04 07:54:47 | 00:03:34 | |||
66 | 2017-11-04 07:54:47 | 2017-11-04 07:58:22 | 00:03:34 | |||
66 | 2017-11-04 07:58:22 | 2017-11-04 08:01:34 | 00:03:11 | |||
66 | 2017-11-04 08:01:34 | 2017-11-04 08:05:02 | 00:03:28 | |||
66 | 2017-11-04 08:05:02 | 2017-11-04 08:08:28 | 00:03:25 | |||
66 | 2017-11-04 08:08:28 | 2017-11-04 08:11:54 | 00:03:25 | |||
66 | 2017-11-04 08:11:54 | 2017-11-04 08:15:18 | 00:03:23 | |||
66 | 2017-11-04 08:15:18 | 2017-11-04 08:18:49 | 00:03:31 | |||
66 | 2017-11-04 08:18:49 | 2017-11-04 08:22:25 | 00:03:35 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
67 | 2017-11-04 08:22:32 | 2017-11-04 08:22:32 | 00:00:00 | |||
68 | 2017-11-04 08:22:39 | 2017-11-04 08:29:38 | 00:06:59 | 1ª Execution was faster | 7.3 | % than the2ª |
68 | 2017-11-04 08:29:38 | 2017-11-04 08:37:11 | 00:07:32 | |||
68 | 2017-11-04 08:37:11 | 2017-11-04 08:44:48 | 00:07:36 | |||
68 | 2017-11-04 08:44:48 | 2017-11-04 08:52:25 | 00:07:37 | |||
68 | 2017-11-04 08:52:25 | 2017-11-04 09:00:04 | 00:07:38 | |||
68 | 2017-11-04 09:00:04 | 2017-11-04 09:07:39 | 00:07:35 | |||
68 | 2017-11-04 09:07:39 | 2017-11-04 09:15:08 | 00:07:28 | |||
68 | 2017-11-04 09:15:08 | 2017-11-04 09:22:14 | 00:07:05 | |||
68 | 2017-11-04 09:22:14 | 2017-11-04 09:29:19 | 00:07:05 | |||
68 | 2017-11-04 09:29:19 | 2017-11-04 09:36:30 | 00:07:11 | |||
70 | 2017-11-04 09:36:38 | 2017-11-04 10:15:13 | 00:38:34 | |||
70 | 2017-11-04 10:15:13 | 2017-11-04 10:54:45 | 00:39:32 | |||
70 | 2017-11-04 10:54:45 | 2017-11-04 11:33:42 | 00:38:56 | |||
70 | 2017-11-04 11:33:42 | 2017-11-04 12:13:08 | 00:39:25 | |||
70 | 2017-11-04 12:13:08 | 2017-11-04 12:52:16 | 00:39:08 | |||
70 | 2017-11-04 12:52:16 | 2017-11-04 13:31:13 | 00:38:56 | |||
70 | 2017-11-04 13:31:13 | 2017-11-04 14:10:42 | 00:39:28 | |||
70 | 2017-11-04 14:10:42 | 2017-11-04 14:49:41 | 00:38:59 |
best regards
Neto
pgsql-general by date: