Re: Linux/PostgreSQL scalability issue - problem with 8 cores

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

Hi Tom,

> Strange.  The best idea that comes to mind is to add some debugging
> code to SendSharedInvalidMessage to log the content of each message
> that's sent out.  That would at least tell us *what* is going into
> the queue, even if not directly *why*.
we've patched postgresql and run one of our plpgsql complex procedures. There are many of sinval messages - log output is below. 

What does it mean?

Thanks,

Kuba

LOG:  sending inval msg 30 0 26 13 30036 4294936593
LOG:  sending inval msg 29 0 26 13 30036 337030170
LOG:  sending inval msg 30 0 25 46 30036 4294936593
LOG:  sending inval msg 29 0 25 46 30036 337030170
LOG:  sending inval msg 30 0 26 13 30036 4294936593
LOG:  sending inval msg 29 0 26 13 30036 337030170
LOG:  sending inval msg 30 0 25 45 30036 4294936595
LOG:  sending inval msg 29 0 25 45 30036 2019111801
LOG:  sending inval msg 30 0 26 11 30036 4294936595
LOG:  sending inval msg 29 0 26 11 30036 2019111801
LOG:  sending inval msg 30 0 25 44 30036 4294936597
LOG:  sending inval msg 29 0 25 44 30036 3703878920
LOG:  sending inval msg 30 0 26 10 30036 4294936597
LOG:  sending inval msg 29 0 26 10 30036 3703878920
LOG:  sending inval msg 30 0 26 9 30036 4294936616
LOG:  sending inval msg 29 0 26 9 30036 3527122063
LOG:  sending inval msg 30 0 25 43 30036 4294936616
LOG:  sending inval msg 29 0 25 43 30036 3527122063
LOG:  sending inval msg 30 0 26 9 30036 4294936616
LOG:  sending inval msg 29 0 26 9 30036 3527122063
LOG:  sending inval msg 30 0 25 41 30036 4294936618
LOG:  sending inval msg 29 0 25 41 30036 2126866956
LOG:  sending inval msg 30 0 26 7 30036 4294936618
LOG:  sending inval msg 29 0 26 7 30036 2126866956
LOG:  sending inval msg 30 0 25 40 30036 4294936620
LOG:  sending inval msg 29 0 25 40 30036 1941919314
LOG:  sending inval msg 30 0 26 5 30036 4294936620
LOG:  sending inval msg 29 0 26 5 30036 1941919314
LOG:  sending inval msg 30 0 26 4 30036 4294936633
LOG:  sending inval msg 29 0 26 4 30036 544523647
LOG:  sending inval msg 30 0 25 39 30036 4294936633
LOG:  sending inval msg 29 0 25 39 30036 544523647
LOG:  sending inval msg 30 0 26 4 30036 4294936633
LOG:  sending inval msg 29 0 26 4 30036 544523647
LOG:  sending inval msg 30 0 25 38 30036 4294936635
LOG:  sending inval msg 29 0 25 38 30036 2557582018
LOG:  sending inval msg 30 0 26 3 30036 4294936635
LOG:  sending inval msg 29 0 26 3 30036 2557582018
LOG:  sending inval msg 30 0 25 37 30036 4294936637
LOG:  sending inval msg 29 0 25 37 30036 2207280630
LOG:  sending inval msg 30 0 26 2 30036 4294936637
LOG:  sending inval msg 29 0 26 2 30036 2207280630
LOG:  sending inval msg 30 0 26 1 30036 4294936669
LOG:  sending inval msg 29 0 26 1 30036 1310188568
LOG:  sending inval msg 30 0 25 36 30036 4294936669
LOG:  sending inval msg 29 0 25 36 30036 1310188568
LOG:  sending inval msg 30 0 26 1 30036 4294936669
LOG:  sending inval msg 29 0 26 1 30036 1310188568
LOG:  sending inval msg 30 0 25 35 30036 4294936671
LOG:  sending inval msg 29 0 25 35 30036 2633053415
LOG:  sending inval msg 30 0 25 48 30036 4294936671
LOG:  sending inval msg 29 0 25 48 30036 2633053415
LOG:  sending inval msg 30 0 25 33 30036 4294936673
LOG:  sending inval msg 29 0 25 33 30036 2049964857
LOG:  sending inval msg 30 0 25 47 30036 4294936673
LOG:  sending inval msg 29 0 25 47 30036 2049964857
LOG:  sending inval msg -1 0 30036 0 30700 3218341912
LOG:  sending inval msg -2 2084 1663 0 30036 50335
LOG:  sending inval msg -2 0 1663 0 30036 50336
LOG:  sending inval msg -1 2075 30036 0 30702 30036
LOG:  sending inval msg -2 0 1663 0 30036 50324
LOG:  sending inval msg -1 0 30036 0 30702 30036
LOG:  sending inval msg -2 0 1663 0 30036 50336
LOG:  sending inval msg -2 0 1663 0 30036 50323
LOG:  sending inval msg -1 0 30036 0 30700 30036
LOG:  sending inval msg -2 0 1663 0 30036 50335
LOG:  sending inval msg -2 0 1663 0 30036 50322
LOG:  sending inval msg -1 0 30036 0 30698 30036
LOG:  sending inval msg -2 0 1663 0 30036 50334
LOG:  sending inval msg -1 0 30036 0 30677 3218341912
LOG:  sending inval msg -2 2084 1663 0 30036 50332
LOG:  sending inval msg -2 0 1663 0 30036 50333
LOG:  sending inval msg -1 2075 30036 0 30679 30036
LOG:  sending inval msg -2 0 1663 0 30036 50321
LOG:  sending inval msg -1 0 30036 0 30679 30036
LOG:  sending inval msg -2 0 1663 0 30036 50333
LOG:  sending inval msg -2 0 1663 0 30036 50320
LOG:  sending inval msg -1 0 30036 0 30677 30036
LOG:  sending inval msg -2 0 1663 0 30036 50332
LOG:  sending inval msg -2 0 1663 0 30036 50319
LOG:  sending inval msg -1 0 30036 0 30675 30036
LOG:  sending inval msg -2 0 1663 0 30036 50331
LOG:  sending inval msg -1 0 30036 0 30660 3218341912
LOG:  sending inval msg -2 2084 1663 0 30036 50329
LOG:  sending inval msg -2 0 1663 0 30036 50330
LOG:  sending inval msg -1 2075 30036 0 30662 30036
LOG:  sending inval msg -2 0 1663 0 30036 50318
LOG:  sending inval msg -1 0 30036 0 30662 30036
LOG:  sending inval msg -2 0 1663 0 30036 50330
LOG:  sending inval msg -2 0 1663 0 30036 50317
LOG:  sending inval msg -1 0 30036 0 30660 30036
LOG:  sending inval msg -2 0 1663 0 30036 50329
LOG:  sending inval msg -2 0 1663 0 30036 50316
LOG:  sending inval msg -1 0 30036 0 30658 30036
LOG:  sending inval msg -2 0 1663 0 30036 50328
LOG:  sending inval msg -1 0 30036 0 30624 3218341912
LOG:  sending inval msg -2 2084 1663 0 30036 50326
LOG:  sending inval msg -2 0 1663 0 30036 50327
LOG:  sending inval msg -1 2075 30036 0 30626 30036
LOG:  sending inval msg -2 0 1663 0 30036 50315
LOG:  sending inval msg -1 0 30036 0 30626 30036
LOG:  sending inval msg -2 0 1663 0 30036 50327
LOG:  sending inval msg -2 0 1663 0 30036 50314
LOG:  sending inval msg -1 0 30036 0 30624 30036
LOG:  sending inval msg -2 0 1663 0 30036 50326
LOG:  sending inval msg -2 0 1663 0 30036 50313
LOG:  sending inval msg -1 0 30036 0 30622 30036
LOG:  sending inval msg -2 0 1663 0 30036 50325


Tom Lane napsal(a):

Jakub Ouhrabka <kuba@xxxxxxxxxx> writes:
We'we tried hard to identify what's the cause of filling sinval-queue. We went through query logs as well as function bodies stored in the database. We were not able to find any DDL, temp table creations etc. 

Strange.  The best idea that comes to mind is to add some debugging
code to SendSharedInvalidMessage to log the content of each message
that's sent out.  That would at least tell us *what* is going into
the queue, even if not directly *why*.  Try something like (untested)

void
SendSharedInvalidMessage(SharedInvalidationMessage *msg)
{
	bool		insertOK;

+	elog(LOG, "sending inval msg %d %u %u %u %u %u",
+		msg->cc.id,
+		msg->cc.tuplePtr.ip_blkid.bi_hi,
+		msg->cc.tuplePtr.ip_blkid.bi_lo,
+		msg->cc.tuplePtr.ip_posid,
+		msg->cc.dbId,
+		msg->cc.hashValue);
+
	LWLockAcquire(SInvalLock, LW_EXCLUSIVE);
	insertOK = SIInsertDataEntry(shmInvalBuffer, msg);
	LWLockRelease(SInvalLock);

			regards, tom lane


---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
      choose an index scan if your joining column's datatypes do not
      match
[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux