You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hawq.apache.org by "Ruilong Huo (JIRA)" <ji...@apache.org> on 2016/02/01 03:49:39 UTC
[jira] [Commented] (HAWQ-372) Single row insert and COPY hang in
high concurrent workloads
[ https://issues.apache.org/jira/browse/HAWQ-372?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15125649#comment-15125649 ]
Ruilong Huo commented on HAWQ-372:
----------------------------------
Root cause analysis shows that the hang of concurrent workload is in three folds:
1. Most of the queries lock relations at first and then allocate resource for it, while analyze (either manually or automatically triggered) allocate resource at first and then lock relation. This may lead to deadlock between relation lock and query resource with concurrent queries.
2. Some of the queries may do query resource allocation multiple times, i.e., SRI/COPY which triggers automatic statistics collection. They do not return query resource as soon as some of the sub tasks are done for the query.
For example, SRI allocate resource for insert itself, do insertion, return query resource for insertion, allocate resource for automatically triggered analyze, do analyze, return query resource for analyze; while COPY allocate resource for COPY itself, do COPY, allocate resource for automatically triggered analyze, do analyze, return query resource for analyze, return query resource for COPY. This may lead to a lot of query resource for COPY itself is occupied, and they still try to allocate more resource for analyze. Thus, it makes some of the COPY pending to allocate resource for analyze, which seems like "deadlock" on query resource.
3. SRI/COPY do query resource allocation multiple times, while TPC-H do resource allocation only once. Usually TPC-H queries take longer time to complete. Thus, SRI/COPY maybe run in halfway and do second resource allocation for some of the sub-tasks. If meanwhile all resource are busy, SRI/COPY need to wait for TPC-H queries to return resource and then proceed. As a consequence, SRI/COPY run very slow or even hang in user's standpoint.
For address the issue, we do following fix:
For 1, make sure all queries (especially insert queries, create/alter/drop database object queries) follows the pattern that lock relation at first, and then allocate query resource.
For 2, make sure queries follows the pattern that allocate query resource for sub-task1, return query resource for sub-task1, ..., allocate query resource for sub-taskN, return query resource for sub-taskN
For 3, from user practice, separate different workloads in different resource queues, i.e., SRI/COPY in one load queue, while TPC-H in query queue.
> Single row insert and COPY hang in high concurrent workloads
> ------------------------------------------------------------
>
> Key: HAWQ-372
> URL: https://issues.apache.org/jira/browse/HAWQ-372
> Project: Apache HAWQ
> Issue Type: Bug
> Components: Core, Resource Manager
> Affects Versions: 2.0.0-beta-incubating
> Reporter: Ruilong Huo
> Assignee: Ruilong Huo
> Fix For: 2.0.0
>
>
> When we run high concurrent workload including multiple TPC-H, single row insert (SRI), and COPY, etc in the same HAWQ cluster, some of the SRI/COPY queries are waiting for resource allocation, while some of the SRI/COPY queries are waiting for relation lock to do ANALYZE.
> 1. High concurrent workload with multiple queries
> {noformat}
> postgres=# select datname,procpid, waiting, query_start, backend_start, waiting_resource from pg_stat_activity order by query_start;
> datname | procpid | waiting | query_start | backend_start | waiting_resource
> --------------------------------------------------+---------+---------+-------------------------------+-------------------------------+------------------
> gpsqltest_sri_ao_nopart_gpadmin | 645847 | t | 2016-01-20 00:36:39.72587-08 | 2016-01-20 00:36:39.713525-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646068 | t | 2016-01-20 00:36:39.746475-08 | 2016-01-20 00:36:39.735691-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646058 | t | 2016-01-20 00:36:39.748647-08 | 2016-01-20 00:36:39.736049-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646097 | t | 2016-01-20 00:36:39.751519-08 | 2016-01-20 00:36:39.744425-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646123 | t | 2016-01-20 00:36:39.762738-08 | 2016-01-20 00:36:39.756794-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646117 | t | 2016-01-20 00:36:39.764139-08 | 2016-01-20 00:36:39.752169-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646121 | t | 2016-01-20 00:36:39.766019-08 | 2016-01-20 00:36:39.756368-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646139 | t | 2016-01-20 00:36:39.773637-08 | 2016-01-20 00:36:39.763225-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646149 | t | 2016-01-20 00:36:39.783354-08 | 2016-01-20 00:36:39.772647-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646161 | t | 2016-01-20 00:36:39.786147-08 | 2016-01-20 00:36:39.779566-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646147 | t | 2016-01-20 00:36:39.787254-08 | 2016-01-20 00:36:39.771044-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646155 | t | 2016-01-20 00:36:39.789962-08 | 2016-01-20 00:36:39.773602-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646158 | t | 2016-01-20 00:36:39.790145-08 | 2016-01-20 00:36:39.777509-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646164 | t | 2016-01-20 00:36:39.790372-08 | 2016-01-20 00:36:39.782358-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646159 | t | 2016-01-20 00:36:39.795443-08 | 2016-01-20 00:36:39.778534-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646186 | t | 2016-01-20 00:36:39.798061-08 | 2016-01-20 00:36:39.790879-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646197 | t | 2016-01-20 00:36:39.802579-08 | 2016-01-20 00:36:39.794637-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646195 | t | 2016-01-20 00:36:39.806501-08 | 2016-01-20 00:36:39.796559-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646208 | t | 2016-01-20 00:36:39.806681-08 | 2016-01-20 00:36:39.799977-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646206 | t | 2016-01-20 00:36:39.809573-08 | 2016-01-20 00:36:39.79784-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646216 | t | 2016-01-20 00:36:39.809781-08 | 2016-01-20 00:36:39.802869-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646221 | t | 2016-01-20 00:36:39.81348-08 | 2016-01-20 00:36:39.807488-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646227 | t | 2016-01-20 00:36:39.813908-08 | 2016-01-20 00:36:39.808067-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646179 | t | 2016-01-20 00:36:39.814094-08 | 2016-01-20 00:36:39.800237-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646217 | t | 2016-01-20 00:36:39.814927-08 | 2016-01-20 00:36:39.804021-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646230 | t | 2016-01-20 00:36:39.816974-08 | 2016-01-20 00:36:39.810218-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646207 | t | 2016-01-20 00:36:39.820487-08 | 2016-01-20 00:36:39.799436-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646243 | t | 2016-01-20 00:36:39.824315-08 | 2016-01-20 00:36:39.817795-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646237 | t | 2016-01-20 00:36:39.827021-08 | 2016-01-20 00:36:39.815167-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646247 | t | 2016-01-20 00:36:39.831095-08 | 2016-01-20 00:36:39.820776-08 | f
> gpsqltest_sri_parquet_nopart_gpadmin | 646251 | t | 2016-01-20 00:36:39.835178-08 | 2016-01-20 00:36:39.821356-08 | f
> gpsqltest_sri_ao_nopart_gpadmin | 646249 | t | 2016-01-20 00:36:39.83527-08 | 2016-01-20 00:36:39.821945-08 | f
> gpsqltest_copy_parquet_part_gpadmin | 659498 | f | 2016-01-20 00:57:18.965937-08 | 2016-01-20 00:57:18.959584-08 | t
> gpsqltest_copy_parquet_part_gpadmin | 659499 | f | 2016-01-20 00:57:18.966475-08 | 2016-01-20 00:57:18.960242-08 | t
> tpch_parquet_10gpn_nocomp_part_gpadmin | 659934 | f | 2016-01-20 00:58:24.355165-08 | 2016-01-20 00:58:24.348844-08 | t
> tpch_parquet_10gpn_nocomp_part_gpadmin | 659935 | f | 2016-01-20 00:58:24.355451-08 | 2016-01-20 00:58:24.351018-08 | t
> tpch_parquet_10gpn_nocomp_part_random_gpadmin | 660464 | f | 2016-01-20 00:59:19.935069-08 | 2016-01-20 00:59:19.929064-08 | t
> gpsqltest_sri_ao_nopart_gpadmin | 645992 | f | 2016-01-20 01:01:56.863003-08 | 2016-01-20 00:36:39.72483-08 | t
> tpch_row_10gpn_nocomp_nopart_random_gpadmin | 662244 | f | 2016-01-20 01:01:58.523853-08 | 2016-01-20 01:01:58.515819-08 | t
> tpch_row_10gpn_nocomp_nopart_gpadmin | 662274 | f | 2016-01-20 01:02:10.616272-08 | 2016-01-20 01:02:10.61147-08 | t
> tpch_row_10gpn_nocomp_nopart_gpadmin | 662318 | f | 2016-01-20 01:02:16.426603-08 | 2016-01-20 01:02:16.416207-08 | t
> tpch_row_10gpn_nocomp_nopart_random_gpadmin | 663081 | f | 2016-01-20 01:03:37.280561-08 | 2016-01-20 01:03:37.270288-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646136 | f | 2016-01-20 01:06:14.42784-08 | 2016-01-20 00:36:39.763601-08 | t
> gpsqltest_sri_parquet_nopart_gpadmin | 645931 | f | 2016-01-20 01:06:14.541232-08 | 2016-01-20 00:36:39.713027-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646218 | f | 2016-01-20 01:06:14.718623-08 | 2016-01-20 00:36:39.805105-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646233 | f | 2016-01-20 01:06:14.952607-08 | 2016-01-20 00:36:39.812631-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646152 | f | 2016-01-20 01:06:15.04709-08 | 2016-01-20 00:36:39.772864-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646209 | f | 2016-01-20 01:06:15.090046-08 | 2016-01-20 00:36:39.801651-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646183 | f | 2016-01-20 01:06:15.866187-08 | 2016-01-20 00:36:39.788024-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646190 | f | 2016-01-20 01:06:15.951528-08 | 2016-01-20 00:36:39.791589-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646103 | f | 2016-01-20 01:06:16.080029-08 | 2016-01-20 00:36:39.744797-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646224 | f | 2016-01-20 01:06:16.141851-08 | 2016-01-20 00:36:39.807155-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646229 | f | 2016-01-20 01:06:16.172984-08 | 2016-01-20 00:36:39.821985-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646144 | f | 2016-01-20 01:06:16.193766-08 | 2016-01-20 00:36:39.767736-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646239 | f | 2016-01-20 01:06:16.240409-08 | 2016-01-20 00:36:39.814674-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646213 | f | 2016-01-20 01:06:16.245975-08 | 2016-01-20 00:36:39.802-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646240 | f | 2016-01-20 01:06:16.268388-08 | 2016-01-20 00:36:39.815886-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646169 | f | 2016-01-20 01:06:16.309693-08 | 2016-01-20 00:36:39.785618-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646191 | f | 2016-01-20 01:06:16.313055-08 | 2016-01-20 00:36:39.801915-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646175 | f | 2016-01-20 01:06:16.326254-08 | 2016-01-20 00:36:39.785054-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646140 | f | 2016-01-20 01:06:16.400912-08 | 2016-01-20 00:36:39.764722-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646145 | f | 2016-01-20 01:06:16.411653-08 | 2016-01-20 00:36:39.768863-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646048 | f | 2016-01-20 01:06:16.412374-08 | 2016-01-20 00:36:39.735611-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646095 | f | 2016-01-20 01:06:16.413301-08 | 2016-01-20 00:36:39.742487-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646133 | f | 2016-01-20 01:06:16.415134-08 | 2016-01-20 00:36:39.760946-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646199 | f | 2016-01-20 01:06:16.417315-08 | 2016-01-20 00:36:39.79628-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646252 | f | 2016-01-20 01:06:16.491593-08 | 2016-01-20 00:36:39.821589-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646231 | f | 2016-01-20 01:06:16.493291-08 | 2016-01-20 00:36:39.812089-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646115 | f | 2016-01-20 01:06:16.547751-08 | 2016-01-20 00:36:39.751355-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646245 | f | 2016-01-20 01:06:16.550403-08 | 2016-01-20 00:36:39.81845-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646142 | f | 2016-01-20 01:06:16.56214-08 | 2016-01-20 00:36:39.766291-08 | t
> gpsqltest_sri_ao_part_gpadmin | 645856 | f | 2016-01-20 01:06:16.562447-08 | 2016-01-20 00:36:39.705096-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646181 | f | 2016-01-20 01:06:16.56347-08 | 2016-01-20 00:36:39.788253-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646189 | f | 2016-01-20 01:06:16.595994-08 | 2016-01-20 00:36:39.790906-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646124 | f | 2016-01-20 01:06:16.598924-08 | 2016-01-20 00:36:39.758522-08 | t
> gpsqltest_sri_parquet_part_gpadmin | 646113 | f | 2016-01-20 01:06:16.610159-08 | 2016-01-20 00:36:39.750937-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646046 | f | 2016-01-20 01:06:16.652708-08 | 2016-01-20 00:36:39.734305-08 | t
> gpsqltest_sri_ao_part_gpadmin | 645889 | f | 2016-01-20 01:06:16.686254-08 | 2016-01-20 00:36:39.715722-08 | t
> gpsqltest_sri_ao_part_gpadmin | 645985 | f | 2016-01-20 01:06:16.699527-08 | 2016-01-20 00:36:39.721616-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646171 | f | 2016-01-20 01:06:17.32465-08 | 2016-01-20 00:36:39.784074-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646128 | f | 2016-01-20 01:06:17.625449-08 | 2016-01-20 00:36:39.759317-08 | t
> gpsqltest_sri_ao_part_gpadmin | 645952 | f | 2016-01-20 01:06:18.845291-08 | 2016-01-20 00:36:39.716739-08 | t
> gpsqltest_sri_ao_part_gpadmin | 646202 | f | 2016-01-20 01:06:20.135747-08 | 2016-01-20 00:36:39.796941-08 | t
> tpch_row_10gpn_nocomp_nopart_gpadmin | 664429 | f | 2016-01-20 01:08:28.056702-08 | 2016-01-20 01:08:28.047146-08 | t
> tpch_parquet_200gpn_snappy_nopart_random_gpadmin | 664938 | f | 2016-01-20 01:12:01.652304-08 | 2016-01-20 01:12:01.635576-08 | t
> tpch_row_10gpn_nocomp_nopart_random_gpadmin | 665052 | f | 2016-01-20 01:12:54.339621-08 | 2016-01-20 01:12:54.323247-08 | t
> tpch_parquet_10gpn_nocomp_part_gpadmin | 665441 | f | 2016-01-20 01:15:26.105002-08 | 2016-01-20 01:15:26.088598-08 | t
> postgres | 128173 | f | 2016-01-20 21:19:08.270989-08 | 2016-01-20 21:18:43.454291-08 | f
> {noformat}
> 2. Some of the SRI/COPY queries are waiting for resource allocation
> {noformat}
> [gpadmin@gva-mst1 pg_log]$ sudo pstack 646240
> Thread 3 (Thread 0x7f9c84847700 (LWP 646250)):
> #0 0x00000033d66df343 in poll () from /lib64/libc.so.6
> #1 0x0000000000aa9217 in testmode_poll ()
> #2 0x0000000000ab3bab in rxThreadFunc ()
> #3 0x00000033d6a079d1 in start_thread () from /lib64/libpthread.so.0
> #4 0x00000033d66e8b6d in clone () from /lib64/libc.so.6
> Thread 2 (Thread 0x7f9c7ffff700 (LWP 646512)):
> #0 0x00000033d66e15e3 in select () from /lib64/libc.so.6
> #1 0x0000000000b83238 in pg_usleep ()
> #2 0x0000000000a48cbb in generateResourceRefreshHeartBeat ()
> #3 0x00000033d6a079d1 in start_thread () from /lib64/libpthread.so.0
> #4 0x00000033d66e8b6d in clone () from /lib64/libc.so.6
> Thread 1 (Thread 0x7f9cb6f788c0 (LWP 646240)):
> #0 0x00000033d66df343 in poll () from /lib64/libc.so.6
> #1 0x0000000000a42543 in processAllCommFileDescs ()
> #2 0x0000000000a4edfe in callSyncRPCRemote ()
> #3 0x0000000000a4ca08 in callSyncRPCToRM ()
> #4 0x0000000000a47070 in acquireResourceFromRM ()
> #5 0x00000000008f0a6c in AllocateResource ()
> #6 0x0000000000b74880 in calculate_planner_segment_num ()
> #7 0x000000000083a7ba in resource_negotiator ()
> #8 0x0000000000839fa0 in planner ()
> #9 0x00000000008e68ad in pg_plan_query ()
> #10 0x00000000008e69b8 in pg_plan_queries ()
> #11 0x00000000008e7fdf in exec_simple_query ()
> #12 0x00000000008ece9f in PostgresMain ()
> #13 0x000000000089333d in BackendRun ()
> #14 0x00000000008927c7 in BackendStartup ()
> #15 0x000000000088c886 in ServerLoop ()
> #16 0x000000000088b95c in PostmasterMain ()
> #17 0x00000000007a5c32 in main ()
> {noformat}
> 3. Some of the SRI/COPY queries are waiting for lock
> {noformat}
> [gpadmin@gva-mst1 pg_log]$ sudo pstack 646147
> Thread 3 (Thread 0x7f9c84847700 (LWP 646170)):
> #0 0x00000033d66df343 in poll () from /lib64/libc.so.6
> #1 0x0000000000aa9217 in testmode_poll ()
> #2 0x0000000000ab3bab in rxThreadFunc ()
> #3 0x00000033d6a079d1 in start_thread () from /lib64/libpthread.so.0
> #4 0x00000033d66e8b6d in clone () from /lib64/libc.so.6
> Thread 2 (Thread 0x7f9c7ffff700 (LWP 646268)):
> #0 0x00000033d66e15e3 in select () from /lib64/libc.so.6
> #1 0x0000000000b83238 in pg_usleep ()
> #2 0x0000000000a48cbb in generateResourceRefreshHeartBeat ()
> #3 0x00000033d6a079d1 in start_thread () from /lib64/libpthread.so.0
> #4 0x00000033d66e8b6d in clone () from /lib64/libc.so.6
> Thread 1 (Thread 0x7f9cb6f788c0 (LWP 646147)):
> #0 0x00000033d66eb197 in semop () from /lib64/libc.so.6
> #1 0x000000000087655a in PGSemaphoreLock ()
> #2 0x00000000008d9ff3 in ProcSleep ()
> #3 0x00000000008d5e4a in WaitOnLock ()
> #4 0x00000000008d5516 in LockAcquire ()
> #5 0x00000000008d2ae3 in LockRelationOid ()
> #6 0x00000000004ecc73 in try_relation_open ()
> #7 0x000000000066af73 in analyzeStmt ()
> #8 0x000000000066a7b4 in analyzeStatement ()
> #9 0x00000000006f5724 in vacuum ()
> #10 0x0000000000879325 in autostats_issue_analyze ()
> #11 0x00000000008798fd in auto_stats ()
> #12 0x00000000008f017a in ProcessQuery ()
> #13 0x00000000008f2e63 in PortalRunMulti ()
> #14 0x00000000008f22f0 in PortalRun ()
> #15 0x00000000008e824d in exec_simple_query ()
> #16 0x00000000008ece9f in PostgresMain ()
> #17 0x000000000089333d in BackendRun ()
> #18 0x00000000008927c7 in BackendStartup ()
> #19 0x000000000088c886 in ServerLoop ()
> #20 0x000000000088b95c in PostmasterMain ()
> #21 0x00000000007a5c32 in main ()
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)