1. Print the waiting lock for "LWLockAcquire"
p *lockIn below sample, this process is waiting for lock "148" and the lock holder is PID 16108.
Core was generated by `postgres: port 5432, gpadmin template1 172.28.8.251(28066) con121275 172.28.8.2'. #0 0x00000036748cb696 in poll () from /lib64/libc.so.6 (gdb) bt #0 0x00000036748cb696 in poll () from /lib64/libc.so.6 #1 0x0000000000aff734 in ic_rx_thread_func (arg=<value optimized out>) at ic_udp.c:3695 #2 0x000000367540673d in start_thread () from /lib64/libpthread.so.0 #3 0x00000036748d44bd in clone () from /lib64/libc.so.6 (gdb) info thre 2 Thread 17194 0x00000036748d5887 in semop () from /lib64/libc.so.6 * 1 Thread 17195 0x00000036748cb696 in poll () from /lib64/libc.so.6 (gdb) thre 2 [Switching to thread 2 (Thread 17194)]#0 0x00000036748d5887 in semop () from /lib64/libc.so.6 (gdb) bt #0 0x00000036748d5887 in semop () from /lib64/libc.so.6 #1 0x0000000000854368 in PGSemaphoreLock (sema=0x2b67b685d910, interruptOK=0 '\000') at pg_sema.c:437 #2 0x00000000008f33f0 in LWLockAcquire (lockid=148, mode=<value optimized out>) at lwlock.c:561 #3 0x0000000000c0a621 in getTmLock (distribXid=<value optimized out>, localXid=<value optimized out>) at cdbtm.c:1706 #4 createDtx (distribXid=<value optimized out>, localXid=<value optimized out>) at cdbtm.c:2495 #5 0x00000000004fa1ff in StartTransaction () at xact.c:2995 #6 0x00000000004fa795 in StartTransactionCommand () at xact.c:4305 #7 0x0000000000904a0d in start_xact_command (query_string=<value optimized out>, seqServerHost=<value optimized out>, seqServerPort=<value optimized out>) at postgres.c:3048 #8 exec_simple_query (query_string=<value optimized out>, seqServerHost=<value optimized out>, seqServerPort=<value optimized out>) at postgres.c:1503 #9 0x0000000000905d97 in PostgresMain (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:4612 #10 0x000000000086dd61 in BackendRun (port=0x1263fc40) at postmaster.c:6779 #11 BackendStartup (port=0x1263fc40) at postmaster.c:6380 #12 0x0000000000874410 in ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:2334 #13 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1546 #14 0x0000000000779eea in main (argc=18, argv=0x125ff030) at main.c:212 (gdb) f 2 #2 0x00000000008f33f0 in LWLockAcquire (lockid=148, mode=<value optimized out>) at lwlock.c:561 561 lwlock.c: No such file or directory. in lwlock.c (gdb) p *lock $1 = {mutex = 0 '\000', releaseOK = 1 '\001', exclusive = 1 '\001', shared = 0, exclusivePid = 16108, head = 0x2b67b6867b80, tail = 0x2b67b67ff1a0}Note:LWlock is lightweight lock in Greenplum and is different than the locks in pg_locks view.
2. Print the locks hold by the process
p held_lwlocks p held_lwlocks_exclusiveIn below sample, this process is holding lock 148.
(gdb) p held_lwlocks
$2 = {148, NullLock <repeats 99 times>}
3. Deadlock checking
p LWLockArray[some_lock]In below sample, FileRep recovery process is waiting for ProcArrayLock.
#0 0x000000374c6d5887 in semop () from /lib64/libc.so.6
#1 0x0000000000853af8 in PGSemaphoreLock (sema=0x2b5ec70f3fe0, interruptOK=0 '\000') at pg_sema.c:437
#2 0x00000000008ee270 in LWLockAcquire (lockid=ProcArrayLock, mode=<value optimized out>) at lwlock.c:561
#3 0x00000000008ce687 in ProcArrayRemove (proc=0x2b5ec70f3fd0, forPrepare=0 '\000', isCommit=1 '\001') at procarray.c:170
#4 0x00000000008caadd in shmem_exit (code=0) at ipc.c:205
#5 proc_exit_prepare (code=0) at ipc.c:165
#6 proc_exit (code=0) at ipc.c:93
#7 0x0000000000b42117 in FileRepSubProcess_Main () at cdbfilerepservice.c:862
#8 0x0000000000b38d3a in FileRep_StartChildProcess (type=FileRepProcessTypePrimaryRecovery) at cdbfilerep.c:2538
#9 0x0000000000b3ff61 in FileRep_Main () at cdbfilerep.c:3415
#10 0x0000000000593449 in AuxiliaryProcessMain (argc=7, argv=0x7fff5741bec0) at bootstrap.c:486
#11 0x0000000000868544 in StartChildProcess (type=<value optimized out>) at postmaster.c:7741
#12 0x000000000086872c in StartFilerepProcesses () at postmaster.c:1648
#13 0x000000000087a11d in stepDoFilerepStartup (isInShutdown=<value optimized out>) at primary_mirror_mode.c:1729
#14 applyStepForTransitionToPrimarySegmentMode (isInShutdown=<value optimized out>) at primary_mirror_mode.c:2013
#15 doRequestedPrimaryMirrorModeTransitions (isInShutdown=<value optimized out>) at primary_mirror_mode.c:1616
#16 0x00000000008743ca in ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:2355
#17 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1546
#18 0x00000000007796ba in main (argc=15, argv=0x1585f030) at main.c:212
In below sample, this user process is waiting for WALWriteLock, and is holding WALInsertLock.(gdb) bt #0 0x000000374c6d5887 in semop () from /lib64/libc.so.6 #1 0x0000000000853af8 in PGSemaphoreLock (sema=0x2b5ec7251e90, interruptOK=0 '\000') at pg_sema.c:437 #2 0x00000000008ee270 in LWLockAcquire (lockid=WALWriteLock, mode=<value optimized out>) at lwlock.c:561 #3 0x000000000050a80c in AdvanceXLInsertBuffer (rmid=<value optimized out>, info=<value optimized out>, rdata=0x7fff5741b5c0, headerXid=<value optimized out>) at xlog.c:1751 #4 XLogInsert_Internal (rmid=<value optimized out>, info=<value optimized out>, rdata=0x7fff5741b5c0, headerXid=<value optimized out>) at xlog.c:1276 #5 0x000000000050bd64 in XLogInsert (rmid=83 'S', info=128 '\200', rdata=0x7fff5741b820) at xlog.c:757 #6 0x00000000004ce79a in heap_log_tuple_insert (relation=0x159d9960, tup=0x16249720) at heapam.c:2087 #7 heap_insert (relation=0x159d9960, tup=0x16249720) at heapam.c:2205 #8 simple_heap_insert (relation=0x159d9960, tup=0x16249720) at heapam.c:2254 #9 0x00000000005d0ae6 in add_attribute_encoding_entry (rel=<value optimized out>, attr_encodings=<value optimized out>) at pg_attribute_encoding.c:51 #10 AddRelationAttributeEncodings (rel=<value optimized out>, attr_encodings=<value optimized out>) at pg_attribute_encoding.c:359 #11 0x000000000068896f in ATExecAddColumn (tab=<value optimized out>, rel=0x15945690, colDef=0x1593a7e0) at tablecmds.c:6841 #12 0x00000000006a9b6f in ATExecCmd (wqueue=<value optimized out>, tab=0x15982e30, rel=0x15945690, cmd=0xffffffffffffffff) at tablecmds.c:5196 #13 0x00000000006aa9ce in ATRewriteCatalogs (rel=<value optimized out>, cmds=<value optimized out>, recurse=<value optimized out>, oidInfoCount=<value optimized out>, oidInfo=<value optimized out>, poidmap=<value optimized out>) at tablecmds.c:5054 #14 ATController (rel=<value optimized out>, cmds=<value optimized out>, recurse=<value optimized out>, oidInfoCount=<value optimized out>, oidInfo=<value optimized out>, poidmap=<value optimized out>) at tablecmds.c:3868 #15 0x00000000006abd1a in AlterTable (stmt=0x1593a6a8) at tablecmds.c:3795 #16 0x000000000090d184 in ProcessUtility (parsetree=0x1593a6a8, queryString=0x7fff5741b480 "\001", params=0x1, isTopLevel=1 '\001', dest=0x1593aa78, completionTag=0x7fff5741c0e0 "") at utility.c:1101 #17 0x000000000090a8b0 in PortalRunUtility (portal=0x1598ff00, count=<value optimized out>, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>, completionTag=<value optimized out>) at pquery.c:1524 #18 PortalRunMulti (portal=0x1598ff00, count=<value optimized out>, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>, completionTag=<value optimized out>) at pquery.c:1634 #19 PortalRun (portal=0x1598ff00, count=<value optimized out>, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>, completionTag=<value optimized out>) at pquery.c:1151 #20 0x0000000000902339 in exec_mpp_query (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:1290 #21 PostgresMain (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:4873 #22 0x000000000086d371 in BackendRun (port=0x158c0c50) at postmaster.c:6779 #23 BackendStartup (port=0x158c0c50) at postmaster.c:6380 #24 0x0000000000873a20 in ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:2334 #25 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1546 #26 0x00000000007796ba in main (argc=15, argv=0x1585f030) at main.c:212 (gdb) p held_lwlocks $1 = {MirroredLock, 1746, WALInsertLock, NullLock <repeats 97 times>} (gdb) p LWLockArray[WALInsertLock] $2 = {lock = {mutex = 0 '\000', releaseOK = 1 '\001', exclusive = 1 '\001', shared = 0, exclusivePid = 2376, head = 0x2b5ec7255900, tail = 0x2b5ec7255900}, pad = "\000\001\001\000\000\000\000\000H\t\000\000\000\000\000\000\000Y%\307^+\000\000\000Y%\307^+\000"}In below sample, this process is waiting for WALInsertLock, and is holding ProcArrayLock.
(gdb) bt #0 0x000000374c6d5887 in semop () from /lib64/libc.so.6 #1 0x0000000000853af8 in PGSemaphoreLock (sema=0x2b5ec7255910, interruptOK=0 '\000') at pg_sema.c:437 #2 0x00000000008ee270 in LWLockAcquire (lockid=WALInsertLock, mode=<value optimized out>) at lwlock.c:561 #3 0x000000000050a316 in XLogInsert_Internal (rmid=<value optimized out>, info=<value optimized out>, rdata=<value optimized out>, headerXid=<value optimized out>) at xlog.c:1025 #4 0x000000000050bd64 in XLogInsert (rmid=83 'S', info=176 '\260', rdata=0x7fff5741bd50) at xlog.c:757 #5 0x00000000004ef801 in DistributedLog_WriteZeroPageXlogRec (newestXact=141090816) at distributedlog.c:799 #6 DistributedLog_ZeroPage (newestXact=141090816) at distributedlog.c:464 #7 DistributedLog_Extend (newestXact=141090816) at distributedlog.c:679 #8 0x00000000004f1475 in GetNewTransactionId (isSubXact=0 '\000', setProcXid=0 '\000') at varsup.c:119 #9 0x0000000000b8cfa9 in LocalDistribXact_Start (newDistribTimeStamp=<value optimized out>, newDistribXid=1892192, newLocalXid=0x10b2544) at cdblocaldistribxact.c:433 #10 LocalDistribXact_StartOnSegment (newDistribTimeStamp=<value optimized out>, newDistribXid=1892192, newLocalXid=0x10b2544) at cdblocaldistribxact.c:498 #11 0x00000000004fa228 in StartTransaction () at xact.c:2913 #12 0x00000000004fa315 in StartTransactionCommand () at xact.c:4145 #13 0x0000000000c028c4 in doQEDistributedExplicitBegin (dtxContextInfo=0x1094fc0) at cdbtm.c:3512 #14 setupQEDtxContext (dtxContextInfo=0x1094fc0) at cdbtm.c:3776 #15 0x0000000000901b9a in PostgresMain (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:4840 #16 0x000000000086d371 in BackendRun (port=0x158c0c50) at postmaster.c:6779 #17 BackendStartup (port=0x158c0c50) at postmaster.c:6380 #18 0x0000000000873a20 in ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:2334 #19 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1546 #20 0x00000000007796ba in main (argc=15, argv=0x1585f030) at main.c:212 (gdb) p held_lwlocks $1 = {MirroredLock, ProcArrayLock, XidGenLock, DistributedLogControlLock, NullLock <repeats 96 times>} (gdb) p LWLockArray[ProcArrayLock] $2 = {lock = {mutex = 0 '\000', releaseOK = 1 '\001', exclusive = 1 '\001', shared = 0, exclusivePid = 24290, head = 0x2b5ec7253880, tail = 0x2b5ec7193c80}, pad = "\000\001\001\000\000\000\000\000\342^\000\000\000\000\000\000\200\070%\307^+\000\000\200<\031\307^+\000"}
4. Show alive File replication sub processes of "primary" process of primary segment.
p FileRepSubProcListIn below sample, gdb is run on "primary" process – 32390.
[gpadmin@sdw15 ~]$ ps -ef|grep 48722 gpadmin 31303 28480 0 06:19 pts/0 00:00:00 grep 48722 gpadmin 32356 1 0 Apr05 ? 00:05:00 /usr/local/xxx_db/greenplum-db-4.2.2.1/bin/postgres -D /data/xxx/primary/gpseg9 -p 48722 -b 20 -z 18 --silent-mode=true -i -M quiescent -C 9 gpadmin 32376 32356 0 Apr05 ? 00:00:17 postgres: port 48722, logger process gpadmin 32390 32356 0 Apr05 ? 00:02:44 postgres: port 48722, primary process gpadmin 32402 32390 0 Apr05 ? 00:00:44 postgres: port 48722, primary receiver ack process gpadmin 32406 32390 0 Apr05 ? 00:04:12 postgres: port 48722, primary sender process gpadmin 32416 32390 0 Apr05 ? 00:00:36 postgres: port 48722, primary consumer ack process gpadmin 32418 32390 0 Apr05 ? 00:00:00 postgres: port 48722, primary recovery process gpadmin 32420 32390 0 Apr05 ? 00:00:00 postgres: port 48722, primary verification process gpadmin 32444 32356 0 Apr05 ? 00:00:00 postgres: port 48722, stats collector process gpadmin 32445 32356 0 Apr05 ? 00:00:03 postgres: port 48722, writer process gpadmin 32446 32356 0 Apr05 ? 00:00:21 postgres: port 48722, checkpoint process gpadmin 32447 32356 0 Apr05 ? 00:00:02 postgres: port 48722, sweeper process gpadmin 32448 32356 0 Apr05 ? 00:00:01 postgres: port 48722, stats sender process [gpadmin@sdw15 ~]$ gdb /usr/local/xxx_db/greenplum-db-4.2.2.1/bin/postgres 32390 (gdb) p FileRepSubProcList $1 = {{pid = 0, fileRepProcessType = FileRepProcessTypeNotInitialized}, {pid = 0, fileRepProcessType = FileRepProcessTypeMain}, { pid = 32406, fileRepProcessType = FileRepProcessTypePrimarySender}, {pid = 0, fileRepProcessType = FileRepProcessTypeMirrorReceiver}, { pid = 0, fileRepProcessType = FileRepProcessTypeMirrorConsumer}, {pid = 0, fileRepProcessType = FileRepProcessTypeMirrorSenderAck}, { pid = 32402, fileRepProcessType = FileRepProcessTypePrimaryReceiverAck}, {pid = 32416, fileRepProcessType = FileRepProcessTypePrimaryConsumerAck}, {pid = 32418, fileRepProcessType = FileRepProcessTypePrimaryRecovery}, { pid = 0, fileRepProcessType = FileRepProcessTypeMirrorConsumerWriter}, {pid = 0, fileRepProcessType = FileRepProcessTypeMirrorConsumerAppendOnly1}, {pid = 0, fileRepProcessType = FileRepProcessTypeResyncManager}, { pid = 0, fileRepProcessType = FileRepProcessTypeResyncWorker1}, {pid = 0, fileRepProcessType = FileRepProcessTypeResyncWorker2}, { pid = 0, fileRepProcessType = FileRepProcessTypeResyncWorker3}, {pid = 0, fileRepProcessType = FileRepProcessTypeResyncWorker4}, { pid = 32420, fileRepProcessType = FileRepProcessTypePrimaryVerification}, {pid = 0, fileRepProcessType = FileRepProcessTypeMirrorVerification}}
5. Print current SQL
p debug_query_string
eg:
(gdb) p debug_query_string $1 = 0xcb592a0 "delete from test ;"
6. Print current session and segment
p gp_session_id p Gp_segmenteg:
(gdb) p gp_session_id $6 = 37 (gdb) p Gp_segment $7 = -1
7. Print local params
info locals
eg:
(gdb) f 4
#4 0x00000000008e2f48 in LockAcquire (locktag=0x7fff3ce436a0, lockmode=<value optimized out>, sessionLock=<value optimized out>,
dontWait=<value optimized out>) at lock.c:1022
1022 lock.c: No such file or directory.
in lock.c
(gdb) info locals
lockmethodid = <value optimized out>
lockMethodTable = 0xdb02a0
localtag = {lock = {locktag_field1 = 17137, locktag_field2 = 17028, locktag_field3 = 0, locktag_field4 = 0, locktag_type = 0 '\000',
locktag_lockmethodid = 1 '\001'}, mode = 7}
locallock = 0xcb07250
lock = 0x2b541ba2da48
proclock = 0x2b541c08b770
proclocktag = {myLock = 0x2b541ba2da48, myProc = 0x2b541e91f200}
found = 0 '\000'
owner = 0xca83608
hashcode = 2660616842
proclock_hashcode = 2005592714
partitionLock = 227
status = -4
__func__ = "LockAcquire"
8. pg_cancel_backend reset postmaster issue(Fixed in latest version.)
(gdb) p PostmasterMain
$1 = {int (int, char **)} 0x879490 <PostmasterMain>
(gdb) disas GetCurrentCommandId
Dump of assembler code for function GetCurrentCommandId:
0x00000000004f3290 <GetCurrentCommandId+0>: push %rbp
0x00000000004f3291 <GetCurrentCommandId+1>: mov 0xbe903d(%rip),%eax # 0x10dc2d4 <currentCommandId>
0x00000000004f3297 <GetCurrentCommandId+7>: mov %rsp,%rbp
0x00000000004f329a <GetCurrentCommandId+10>: leaveq
0x00000000004f329b <GetCurrentCommandId+11>: retq
End of assembler dump.
(gdb) p errordata[0]
$2 = {
elevel = 20,
output_to_server = 1 '\001',
output_to_client = 1 '\001',
show_funcname = 0 '\000',
omit_location = 1 '\001',
fatal_return = 0 '\000',
hide_stmt = 0 '\000',
send_alert = 0 '\000',
filename = 0xdba330 "postgres.c",
lineno = 3473,
funcname = 0xdb6300 "ProcessInterrupts",
domain = 0xd8b9d0 "postgres-8.2",
sqlerrcode = 67371461,
message = 0x1c33d4c0 "canceling statement due to user request",
detail = 0x0,
detail_log = 0x0,
hint = 0x0,
context = 0x0,
cursorpos = 0,
internalpos = 0,
internalquery = 0x0,
saved_errno = 32,
stacktracearray = {0xa71f35, 0x907e5c, 0xb19605, 0xb00b66, 0x726649, 0x6f1bf5, 0x6ee8d4, 0x6f00d0, 0x915529, 0x909dc5, 0x90b6e7, 0x8746d1, 0x87ad00, 0x77ff3a, 0x2b1585f3c9c4, 0x47c449, 0x0 <repeats 14 times>},
stacktracesize = 16
}
(gdb) info threads
3 Thread 26077 0x00002b1585feb116 in poll () from /lib64/libc.so.6
2 Thread 26261 0x00002b1585fed1d2 in select () from /lib64/libc.so.6
* 1 Thread 0x2b158833fbe0 (LWP 26076) 0x00002b1585f4f182 in __longjmp () from /lib64/libc.so.6
(gdb) p gp_crash_handler_async
$3 = 0 '\000'
(gdb) thread 2
[Switching to thread 2 (Thread 26261)]#0 0x00002b1585fed1d2 in select () from /lib64/libc.so.6
(gdb) p gp_crash_handler_async
$4 = 0 '\000'
(gdb) p error_context_stack
$5 = (ErrorContextCallback *) 0x0
(gdb) p *CurrentMemoryContext
$6 = {
type = T_AllocSetContext,
methods = {
alloc = 0xaaae60 <AllocSetAlloc>,
free_p = 0xaab3d0 <AllocSetFree>,
realloc = 0xaabee0 <AllocSetRealloc>,
init = 0xaaad20 <AllocSetInit>,
reset = 0xaab2b0 <AllocSetReset>,
delete_context = 0xaab1c0 <AllocSetDelete>,
get_chunk_space = 0xaaad30 <AllocSetGetChunkSpace>,
is_empty = 0xaaad40 <AllocSetIsEmpty>,
stats = 0xaab4c0 <AllocSetStats>
},
parent = 0x1c33a6f0,
firstchild = 0x0,
nextchild = 0x0,
name = 0x1c33ace8 "ErrorContext",
allBytesAlloc = 8192,
allBytesFreed = 0,
maxBytesHeld = 8192,
localMinHeld = 0
}
9. Find lock holder information using the core of lock waiter
Assume you have the cores of a waiting session and it is waiting for "LockAcquire".How to find the lock holder information using the core? Answer is :
p *((PROCLOCK*) (ShmemBase+((unsigned long) lock->procLocks.next) - ((long) &((PROCLOCK*)0)->lockLink)))->tag.myProcFor example:
(gdb) bt
#0 0x0000003aae6d5887 in semop () from /lib64/libc.so.6
#1 0x000000000085ad98 in PGSemaphoreLock (sema=0x2b589d58d890, interruptOK=1 '\001') at pg_sema.c:437
#2 0x00000000008e812e in ProcSleep (locallock=<value optimized out>, lockMethodTable=<value optimized out>) at proc.c:1004
#3 0x00000000008e15e2 in WaitOnLock (locallock=<value optimized out>, owner=<value optimized out>) at lock.c:1378
#4 0x00000000008e2f48 in LockAcquire (locktag=0x7fff883480f0, lockmode=<value optimized out>, sessionLock=<value optimized out>, dontWait=<value optimized out>) at lock.c:1022
#5 0x00000000008dfdcb in LockRelationOid (relid=59290, lockmode=8) at lmgr.c:84
#6 0x00000000004c62f6 in try_relation_open (relationId=59290, lockmode=8, noWait=1 '\001') at heapam.c:908
#7 0x00000000006d2663 in open_relation_and_check_permission (vacstmt=0x16fff88, relids=<value optimized out>) at vacuum.c:4029
#8 vacuumStatement (vacstmt=0x16fff88, relids=<value optimized out>) at vacuum.c:460
#9 0x00000000006d3496 in vacuum (vacstmt=0x16fff88, relids=<value optimized out>) at vacuum.c:285
#10 0x00000000009179be in ProcessUtility (parsetree=0x16fff88, queryString=<value optimized out>, params=0x1, isTopLevel=1 '\001', dest=0x1700308, completionTag=0x7fff88348680 "")
at utility.c:1377
#11 0x0000000000915390 in PortalRunUtility (portal=0x17036f0, count=<value optimized out>, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>,
completionTag=<value optimized out>) at pquery.c:1525
#12 PortalRunMulti (portal=0x17036f0, count=<value optimized out>, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>,
completionTag=<value optimized out>) at pquery.c:1635
#13 PortalRun (portal=0x17036f0, count=<value optimized out>, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>,
completionTag=<value optimized out>) at pquery.c:1152
#14 0x0000000000909e95 in exec_simple_query (query_string=<value optimized out>, seqServerHost=<value optimized out>, seqServerPort=<value optimized out>) at postgres.c:1721
#15 0x000000000090b7a7 in PostgresMain (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:4612
#16 0x00000000008747a1 in BackendRun (port=0x162e580) at postmaster.c:6785
#17 BackendStartup (port=0x162e580) at postmaster.c:6386
#18 0x000000000087add0 in ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:2340
#19 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1546
#20 0x000000000078000a in main (argc=18, argv=0x1606030) at main.c:212
Lock information of current waiting session: pid=8637,mppSessionId=30.(gdb) f 4
#4 0x00000000008e2f48 in LockAcquire (locktag=0x7fff883480f0, lockmode=<value optimized out>, sessionLock=<value optimized out>, dontWait=<value optimized out>) at lock.c:1022
1022 lock.c: No such file or directory.
in lock.c
(gdb) p *proclock->tag.myProc
$1 = {links = {prev = 140902152, next = 140902152}, sem = {semId = 354844776, semNum = 5}, waitStatus = 2, xid = 4933, localDistribXactRef = {eyecatcher = "LDX", index = 203},
xmin = 4929, pid = 8367, databaseId = 17128, roleId = 10, mppSessionId = 30, mppLocalProcessSerial = 30, mppIsWriter = 1 '\001', postmasterResetRequired = 1 '\001',
inVacuum = 0 '\000', lwWaiting = 0 '\000', lwExclusive = 0 '\000', lwWaitLink = 0x0, waitLock = 0x2b589a69bee0, waitProcLock = 0x2b589acf9ad0, waitLockMode = 8, heldLocks = 0,
myProcLocks = {{prev = 147577592, next = 147577592}, {prev = 190126328, next = 190126328}, {prev = 190126344, next = 190126344}, {prev = 190126360, next = 190126360}, {
prev = 190126376, next = 190126376}, {prev = 190126392, next = 190126392}, {prev = 190126408, next = 190126408}, {prev = 190126424, next = 190126424}, {prev = 147577208,
next = 147577208}, {prev = 190126456, next = 190126456}, {prev = 190126472, next = 190126472}, {prev = 190126488, next = 190126488}, {prev = 190126504, next = 190126504}, {
prev = 190126520, next = 190126520}, {prev = 190126536, next = 190126536}, {prev = 190126552, next = 190126552}}, subxids = {overflowed = 0 '\000', nxids = 0, xids = {
0 <repeats 64 times>}}, waitPortalId = 4294967295, combocid_map_count = 15, combocid_map_name = "sess18_w24896_combocid_map", '\000' <repeats 997 times>, queryCommandId = 2}
Lock information of locker session: pid=8741,mppSessionId = 28(gdb) p *((PROCLOCK*) (ShmemBase+((unsigned long) lock->procLocks.next) - ((long) &((PROCLOCK*)0)->lockLink)))->tag.myProc $2 = {links = {prev = 18446744073709551615, next = 18446744073709551615}, sem = {semId = 354844776, semNum = 4}, waitStatus = 0, xid = 4929, localDistribXactRef = {eyecatcher = "LDX", index = 200}, xmin = 4929, pid = 8741, databaseId = 17128, roleId = 10, mppSessionId = 28, mppLocalProcessSerial = 28, mppIsWriter = 1 '\001', postmasterResetRequired = 1 '\001', inVacuum = 0 '\000', lwWaiting = 0 '\000', lwExclusive = 0 '\000', lwWaitLink = 0x0, waitLock = 0x0, waitProcLock = 0x0, waitLockMode = 8, heldLocks = 0, myProcLocks = {{ prev = 147577688, next = 147577688}, {prev = 190124664, next = 190124664}, {prev = 190124680, next = 190124680}, {prev = 190124696, next = 190124696}, {prev = 190124712, next = 190124712}, {prev = 190124728, next = 190124728}, {prev = 147577400, next = 147577400}, {prev = 190124760, next = 190124760}, {prev = 190124776, next = 190124776}, { prev = 190124792, next = 190124792}, {prev = 190124808, next = 190124808}, {prev = 190124824, next = 190124824}, {prev = 190124840, next = 190124840}, {prev = 190124856, next = 190124856}, {prev = 190124872, next = 190124872}, {prev = 190124888, next = 190124888}}, subxids = {overflowed = 0 '\000', nxids = 0, xids = {0 <repeats 64 times>}}, waitPortalId = 4294967295, combocid_map_count = 15, combocid_map_name = "sess28_w8741_combocid_map", '\000' <repeats 998 times>, queryCommandId = 194}
10. GPText queries hung in GPText 1.2.0.0 due to timeout. (Fixed in latest version)
Check the hung process of problematic session on one segment, it is waiting for "get_data" and err_buf shows "transfer closed with outstanding read data remaining".(gdb) bt #0 0x0000003c488cd722 in select () from /lib64/libc.so.6 #1 0x00002aaaab03da29 in get_data (state=0xcadad50) at solr_curl.c:630 #2 0x00002aaaab03c13d in get_next_result (fcinfo=0xc7e6e50) at solr_search.c:155 #3 solr_search (fcinfo=0xc7e6e50) at solr_search.c:982 #4 0x00000000007301b1 in TableFunctionNext (node=0xc7e3bc0) at nodeTableFunction.c:149 #5 0x00000000006f1b7e in ExecProcNode (node=0xc7e3bc0) at execProcnode.c:609 #6 0x0000000000726aa6 in execMotionSender (node=0x2aaaaae115c8) at nodeMotion.c:348 #7 ExecMotion (node=0x2aaaaae115c8) at nodeMotion.c:315 #8 0x00000000006f1cd5 in ExecProcNode (node=0x2aaaaae115c8) at execProcnode.c:657 #9 0x00000000006ee9b4 in ExecutePlan (estate=0xc408d50, planstate=<value optimized out>, operation=<value optimized out>, numberTuples=<value optimized out>, direction=<value optimized out>, dest=<value optimized out>) at execMain.c:2361 #10 0x00000000006f015e in ExecutorRun (queryDesc=<value optimized out>, direction=<value optimized out>, count=<value optimized out>) at execMain.c:862 #11 0x00000000009170b9 in PortalRunSelect (portal=<value optimized out>, count=0, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>, completionTag=<value optimized out>) at pquery.c:1283 #12 PortalRun (portal=<value optimized out>, count=0, isTopLevel=<value optimized out>, dest=<value optimized out>, altdest=<value optimized out>, completionTag=<value optimized out>) at pquery.c:1105 #13 0x000000000090f839 in exec_mpp_query (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:1291 #14 PostgresMain (argc=<value optimized out>, argv=<value optimized out>, username=<value optimized out>) at postgres.c:4826 #15 0x0000000000875ac1 in BackendRun (port=0xc2e85e0) at postmaster.c:6801 #16 BackendStartup (port=0xc2e85e0) at postmaster.c:6402 #17 0x000000000087bc00 in ServerLoop (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:2340 #18 PostmasterMain (argc=<value optimized out>, argv=<value optimized out>) at postmaster.c:1546 #19 0x0000000000780ada in main (argc=15, argv=0xc2b8030) at main.c:212 (gdb) p *state $6 = {curl = 0xcaf9100, curlm = 0xcb01db0, still_running = 0, timeout = 600, curl_ret = 0, curlm_ret = 0, http_rc = 200, err_buf = 0xcadade0 "transfer closed with outstanding read data remaining", headers = 0xcaf6640, context = 0xcac9940, buf = { data = 0x2aaaab251040 "\"__pk\",score\n7918990,1.0\n7919038,1.0\n7924704,1.0\n7925415,1.0\n7919604,1.0\n7923455,1.0\n7919183,1.0\n7923343,1.0\n7922114,1.0\n7919279,1.0\n7920769,1.0\n7924395,1.0\n7920576,1.0\n7923102,1.0\n7923375,1.0\n7921046"..., send_data_end = 0x2aaaab251040 "\"__pk\",score\n7918990,1.0\n7919038,1.0\n7924704,1.0\n7925415,1.0\n7919604,1.0\n7923455,1.0\n7919183,1.0\n7923343,1.0\n7922114,1.0\n7919279,1.0\n7920769,1.0\n7924395,1.0\n7920576,1.0\n7923102,1.0\n7923375,1.0\n7921046"..., bottom = 0x2aaaab28d035 "8660266,1.0", top = 0x2aaaab28d040 "", size = 4194304}, post_data = 0xcadaef0 "q=%2A%3A%2A&rows=1000000&fl=__pk%2Cscore&wt=csv&csv.header=true&start=0", post_data_size = 71}
Note: All above stuff are deep dive into core dumps of Greenplum processes using gdb.
Thanks - some really good information here. :)
ReplyDeleteCED0ADF156
ReplyDeletemobil ödeme takipçi
lindyn oversized swivel accent chair
8C962E6B91
ReplyDeleteTakipçi Satın Al
Ücretsiz Oyun Oyna
Aşk Kitapları
EC6B689D
ReplyDeleteGümüşhane
Yalova
Artvin
Sinop
Düzce
Kayseri
Edirne
Çankırı
Kütahya
52633DDC
ReplyDeleteBucak
Oğuzeli
Gemlik
Narlıdere
Seferihisar
Pamukova
Hendek
Eşme
Salihli
C541E881
ReplyDeleteAğva
Kozan
İslahiye
Kızıltepe
Kuşadası
Ömerli
Erdemli
Karşıyaka
Akseki
720CC95F
ReplyDeleteDemetevler
Sorgun
Karaburun
Cizre
Çerkezköy
Susurluk
Ödemiş
Alpu
Arsuz