Обсуждение: lock problem
I'm seeing connection hang issue these days. many concurrent connections are hanging on db. They basically do the same thing:update different rows in same table. The sql itself should run very fast as it's updating just one row based on anunique key. I though it might be lock problem. The I list the locks ordered by query start time(see list below). I'mconfused why the oldest connection are still waiting for the lock? anything else can hold that lock?<br /> <font color="#ff0000"> | 1580056836 | ShareLock | f | update article set tm_update=$ |2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020</font><br /><br /> select <br /> pg_class.relname,pg_locks.transactionid,pg_locks.mode, pg_locks.granted, <br /> substr(pg_stat_activity.current_query,1,30),pg_stat_activity.query_start, <br /> age(now(),pg_stat_activity.query_start)as "age", pg_stat_activity.procpid <br /> from pg_stat_activity,pg_locks left <br/> outer join pg_class on (pg_locks.relation = pg_class.oid) <br /> where pg_locks.pid=pg_stat_activity.procpidorder by query_start limit 50;<br /> relname | transactionid | mode | granted | substr | query_start | age | procpid<br /> ----------------------------+---------------+------------------+---------+--------------------------------+-------------------------------+-----------------+---------<br /> article_title_hash_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> | 1580056836 | ShareLock | f | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> | 1579897513 | ExclusiveLock | t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> article_fid_author_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article_stage_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> article_fid_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article_cid_time_style_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> | | ExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article_tm_spider_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> article_tm_update_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article_guid_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> article_url_hash | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article_rfid_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> article_url_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:28:56.643105+08 | 00:24:51.599424 | 21020<br /> article_pkey | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:28:56.643105+08 | 00:24:51.599424 | 21020<br/> article | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> article_cid_time_style_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_fid_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> article_rfid_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_pkey | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> | 1579921995 | ExclusiveLock | t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_url_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> article_title_hash_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_guid_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> article_tm_update_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> | 1580056836 | ShareLock | f | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> article_fid_author_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_tm_spider_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> article_stage_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_url_hash | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:01.947787+08 | 00:23:46.294742 | 706<br /> | | ExclusiveLock | t | update article set tm_update=$ | 2011-12-21 13:30:01.947787+08 | 00:23:46.294742 | 706<br/> article_title_hash_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> | 1580056836 | ShareLock | f | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_stage_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> article_fid_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_pkey | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> article_url_hash | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_cid_time_style_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> article | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_fid_author_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> article_tm_update_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_rfid_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> article_url_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> | | ExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> article_guid_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_tm_spider_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:11.735228+08 | 00:23:36.507301 | 22892<br /> | 1579925267 | ExclusiveLock | t | update article set tm_update=$ | 2011-12-21 13:30:11.735228+08 | 00:23:36.507301 | 22892<br/> article_title_hash_idx | | RowExclusiveLock | t | update article set tm_update=$ | 2011-12-2113:30:26.843451+08 | 00:23:21.399078 | 32700<br /> article_fid_author_idx | | RowExclusiveLock| t | update article set tm_update=$ | 2011-12-21 13:30:26.843451+08 | 00:23:21.399078 | 32700<br/> (50 rows)
Rural Hunter wrote: > I'm seeing connection hang issue these days. many concurrent > connections are hanging on db. They basically do the same thing: > update different rows in same table. The sql itself should run very > fast as it's updating just one row based on an unique key. > update article set tm_update=$ I don't see a WHERE clause, so it looks like you're updating the whole table each time. Once a row is updated by one of the transactions, others will block on attempts to update the same row until the first transaction commits. -Kevin
Hi!
==============================I don't see a WHERE clause, so it looks like you're updating the
whole table each time.
it's got a substr(pg_stat_activity.current_query,1,30) in it, so we shall hardly see anything about the WHERE clause, but we'd really need to have more info about it.
Bèrto
--
If Pac-Man had affected us as kids, we'd all be running around in a darkened room munching pills and listening to repetitive music.
yes, it's truncated. the full sql is like this: "update article set tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where title_hash=$5" the title_hash is unique. I dig another case more and found something interesting. it's actually waiting for a lock of type transactionid. I ran the query below 3 times very quickly and each time it showed a different lock holder. db=# select pl1.*,pl2.pid,pa.query_start,pa.waiting,pa.current_query from pg_locks pl1 left join pg_locks pl2 on pl1.transactionid=pl2.transactionid and pl2.granted left join pg_stat_activity pa on pl2.pid=pa.procpid where pl1.pid=6053 and not pl1.granted; locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | pid | query_start | waiting | current_query ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+-----------+---------+------+--------- ----------------------+---------+--------------------------------------------------------------------------------------------- transactionid | | | | | | 1586721800 | | | | 238/39230 | 6053 | ShareLock | f | 3026 | 2011-12- 21 22:24:20.027493+08 | t | update article set tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where title_hash=$5 (1 row) db=# select pl1.*,pl2.pid,pa.query_start,pa.waiting,pa.current_query from pg_locks pl1 left join pg_locks pl2 on pl1.transactionid=pl2.transactionid and pl2.granted left join pg_stat_activity pa on pl2.pid=pa.procpid where pl1.pid=6053 and not pl1.granted; locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | pid | query_start | waiting | current_query ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+-----------+---------+------+--------- ----------------------+---------+--------------------------------------------------------------------------------------------- transactionid | | | | | | 1586739901 | | | | 238/39230 | 6053 | ShareLock | f | 3254 | 2011-12- 21 22:25:15.133554+08 | t | update article set tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where title_hash=$5 (1 row) db=# select pl1.*,pl2.pid,pa.query_start,pa.waiting,pa.current_query from pg_locks pl1 left join pg_locks pl2 on pl1.transactionid=pl2.transactionid and pl2.granted left join pg_stat_activity pa on pl2.pid=pa.procpid where pl1.pid=6053 and not pl1.granted; locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | pid | query_start | waiting | current_query ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+-----------+---------+------+--------- ----------------------+---------+--------------------------------------------------------------------------------------------- transactionid | | | | | | 1586626482 | | | | 238/39230 | 6053 | ShareLock | f | 1518 | 2011-12- 21 22:19:28.880025+08 | t | update article set tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where title_hash=$5 (1 row) I found the description of transactionid type here: http://archives.postgresql.org/pgsql-novice/2010-05/msg00066.php Currently, the only case where anything will try to take a sharelock on transaction id is when it is blocking on a row-level lock as a result of trying to modify or delete or SELECT FOR UPDATE/FOR SHARE a row that the other transaction already modified or deleted or selected FOR UPDATE/SHARE. I'm pretty sure those queries are updating different rows each. why they are waiting for row lock for each other? Another question is: query A waiting for B, then waiting for C, then waiting for D. I checked the query start time, A is much earlier than B/C/D. Why A still couldn't get the lock while looks B/C/D seems have gotten the lock even ABCD are all similar transaction? 于2011年12月21日 21:51:14,Bèrto ëd Sèra写到: > Hi! > > I don't see a WHERE clause, so it looks like you're updating the > whole table each time. > > > it's got a substr(pg_stat_activity.current_query,1,30) in it, so we > shall hardly see anything about the WHERE clause, but we'd really need > to have more info about it. > > Bèrto > -- > ============================== > If Pac-Man had affected us as kids, we'd all be running around in a > darkened room munching pills and listening to repetitive music.
Rural Hunter <ruralhunter@gmail.com> writes: > yes, it's truncated. the full sql is like this: > "update article set > tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where > title_hash=$5" > the title_hash is unique. > > I dig another case more and found something interesting. it's actually > waiting for a lock of type transactionid. I ran the query below 3 Normal. That's the kind of lock you are waiting for when some other transaction has touched the same rows for update that you are attempting. > times very quickly and each time it showed a different lock holder. > db=# select pl1.*,pl2.pid,pa.query_start,pa.waiting,pa.current_query > from pg_locks pl1 left join pg_locks pl2 on > pl1.transactionid=pl2.transactionid and pl2.granted > left join pg_stat_activity pa on pl2.pid=pa.procpid where pl1.pid=6053 > and not pl1.granted; > locktype | database | relation | page | tuple | virtualxid | > transactionid | classid | objid | objsubid | virtualtransaction | pid > | mode | granted | pid | > query_start | waiting | > current_query > ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+-----------+---------+------+--------- > ----------------------+---------+--------------------------------------------------------------------------------------------- > transactionid | | | | | | > 1586721800 | | | | 238/39230 | 6053 | > ShareLock | f | 3026 | 2011-12- > 21 22:24:20.027493+08 | t | update article set > tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where > title_hash=$5 > (1 row) > db=# select pl1.*,pl2.pid,pa.query_start,pa.waiting,pa.current_query > from pg_locks pl1 left join pg_locks pl2 on > pl1.transactionid=pl2.transactionid and pl2.granted > left join pg_stat_activity pa on pl2.pid=pa.procpid where pl1.pid=6053 > and not pl1.granted; > locktype | database | relation | page | tuple | virtualxid | > transactionid | classid | objid | objsubid | virtualtransaction | pid > | mode | granted | pid | > query_start | waiting | > current_query > ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+-----------+---------+------+--------- > ----------------------+---------+--------------------------------------------------------------------------------------------- > transactionid | | | | | | > 1586739901 | | | | 238/39230 | 6053 | > ShareLock | f | 3254 | 2011-12- > 21 22:25:15.133554+08 | t | update article set > tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where > title_hash=$5 > (1 row) > > db=# select pl1.*,pl2.pid,pa.query_start,pa.waiting,pa.current_query > from pg_locks pl1 left join pg_locks pl2 on > pl1.transactionid=pl2.transactionid and pl2.granted > left join pg_stat_activity pa on pl2.pid=pa.procpid where pl1.pid=6053 > and not pl1.granted; > locktype | database | relation | page | tuple | virtualxid | > transactionid | classid | objid | objsubid | virtualtransaction | pid > | mode | granted | pid | > query_start | waiting | > current_query > ---------------+----------+----------+------+-------+------------+---------------+---------+-------+----------+--------------------+------+-----------+---------+------+--------- > ----------------------+---------+--------------------------------------------------------------------------------------------- > transactionid | | | | | | > 1586626482 | | | | 238/39230 | 6053 | > ShareLock | f | 1518 | 2011-12- > 21 22:19:28.880025+08 | t | update article set > tm_update=$1,rply_cnt=$2,read_cnt=$3,tm_last_rply=$4 where > title_hash=$5 > (1 row) > > I found the description of transactionid type here: > http://archives.postgresql.org/pgsql-novice/2010-05/msg00066.php > Currently, the only case where anything will try to take a sharelock on > transaction id is when it is blocking on a row-level lock as a result of > trying to modify or delete or SELECT FOR UPDATE/FOR SHARE a row that the > other transaction already modified or deleted or selected FOR > UPDATE/SHARE. > > I'm pretty sure those queries are updating different rows each. why > they are waiting for row lock for each other? > Another question is: query A waiting for B, then waiting for C, then > waiting for D. I checked the query start time, A is much earlier than > B/C/D. Why A still couldn't get the lock while looks B/C/D seems have > gotten the lock even ABCD are all similar transaction? > > > äº2011å¹´12æ21æ¥ 21:51:14,Bèrto ëd Sèraåå°: >> Hi! >> >> I don't see a WHERE clause, so it looks like you're updating the >> whole table each time. >> >> >> it's got a substr(pg_stat_activity.current_query,1,30) in it, so we >> shall hardly see anything about the WHERE clause, but we'd really >> need to have more info about it. >> >> Bèrto >> -- >> ============================== >> If Pac-Man had affected us as kids, we'd all be running around in a >> darkened room munching pills and listening to repetitive music. > > > > -- > Sent via pgsql-admin mailing list (pgsql-admin@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-admin > -- Jerry Sievers Postgres DBA/Development Consulting e: postgres.consulting@comcast.net p: 305.321.1144
Hi,
Record level locks are stored on the records themselves, so you won't see them explicitly mentioned in views like pg_locks:
"Although tuples are a lockable type of object, information about row-level locks is stored on disk, not in memory, and therefore row-level locks normally do not appear in this view. If a transaction is waiting for a row-level lock, it will usually appear in the view as waiting for the permanent transaction ID of the current holder of that row lock."
> I dig another case more and found something interesting. it's actuallyNormal. That's the kind of lock you are waiting for when some other
> waiting for a lock of type transactionid. I ran the query below 3
transaction has touched the same rows for update that you are
attempting.
"Although tuples are a lockable type of object, information about row-level locks is stored on disk, not in memory, and therefore row-level locks normally do not appear in this view. If a transaction is waiting for a row-level lock, it will usually appear in the view as waiting for the permanent transaction ID of the current holder of that row lock."
Bèrto
-- ==============================
If Pac-Man had affected us as kids, we'd all be running around in a darkened room munching pills and listening to repetitive music.
well, thanks. I checked the application and found there was a bug causing many queries were updating the same row. However, those updates are just single statement, no multi-statement transaction involved. So I still have this question: same statement A,B,C,D update same row. The start order is A->B->C-D. From what I've gotten, B/C/D got the lock before A. Why did that happen? 于2011年12月21日 23:40:35,Bèrto ëd Sèra写到: > Hi, > > > I dig another case more and found something interesting. it's > actually > > waiting for a lock of type transactionid. I ran the query below 3 > > Normal. That's the kind of lock you are waiting for when some other > transaction has touched the same rows for update that you are > attempting. > > > Record level locks are stored on the records themselves, so you won't > see them explicitly mentioned in views like pg_locks: > "Although tuples are a lockable type of object, information about > row-level locks is stored on disk, not in memory, and therefore > row-level locks normally do not appear in this view. If a transaction > is waiting for a row-level lock, it will usually appear in the view as > waiting for the permanent transaction ID of the current holder of that > row lock." > See http://www.postgresql.org/docs/9.1/static/explicit-locking.html > > Bèrto > -- > ============================== > If Pac-Man had affected us as kids, we'd all be running around in a > darkened room munching pills and listening to repetitive music.
Rural Hunter <ruralhunter@gmail.com> wrote: > I still have this question: > same statement A,B,C,D update same row. The start order is > A->B->C-D. From what I've gotten, B/C/D got the lock before A. > Why did that happen? Did you do anything to prevent it from happening? If not, the OS scheduler is going to give time to one process or another in a fairly unpredictable way. -Kevin
hmm....no I didn't do anything. is the lock priority decided by OS not the DB? I'm confused here. B/C/D started several mins later than A here while the update statement takes no more than 1 second. of coz there are hundreds of connections trying to acquire the lock during that time. 于2011年12月22日 0:09:17,Kevin Grittner写到: > Rural Hunter<ruralhunter@gmail.com> wrote: > >> I still have this question: >> same statement A,B,C,D update same row. The start order is >> A->B->C-D. From what I've gotten, B/C/D got the lock before A. >> Why did that happen? > > Did you do anything to prevent it from happening? If not, the OS > scheduler is going to give time to one process or another in a > fairly unpredictable way. > > -Kevin >
Rural Hunter wrote: > Kevin Grittner wrote: >> Rural Hunter wrote: >> >>> I still have this question: >>> same statement A,B,C,D update same row. The start order is >>> A->B->C-D. From what I've gotten, B/C/D got the lock before A. >>> Why did that happen? >> >> Did you do anything to prevent it from happening? If not, the OS >> scheduler is going to give time to one process or another in a >> fairly unpredictable way. > > hmm....no I didn't do anything. is the lock priority decided by OS > not the DB? What the heck is "lock priority"? I'm not familiar with that term. > I'm confused here. B/C/D started several mins later than A here > while the update statement takes no more than 1 second. of coz > there are hundreds of connections trying to acquire the lock during > that time. Well, that sounds like your problem right there. If you have hundreds of connections, among a great many other problems, competition for locks can leave any one connection shut out for quite a long time. If you have hundreds of connections, you will have this and other problems indefinitely. Right now, look into setting up pgpool or some other connection pooler to accept your hundreds of connections, and funnel them into a number of connections somewhere around double the number of cores on your server. Use transaction- based pooling, so that when you have more transactions than the server can efficiently handle, the extras will queue. This will improve both your overall throughput and your latency (response time). Many people naively think that even when the server is saturated, throwing another transaction at it right away will get a response for it sooner. That is dead wrong. -Kevin