R: R: R: BUG #6342: libpq blocks forever in "poll" function

From: "Andrea Grassi" <andreagrassi(at)sogeasoft(dot)com>
To: "'Alvaro Herrera'" <alvherre(at)commandprompt(dot)com>
Cc: "'Craig Ringer'" <ringerc(at)ringerc(dot)id(dot)au>, "'Tom Lane'" <tgl(at)sss(dot)pgh(dot)pa(dot)us>, "'Pg Bugs'" <pgsql-bugs(at)postgresql(dot)org>
Subject: R: R: R: BUG #6342: libpq blocks forever in "poll" function
Date: 2011-12-20 16:15:43
Message-ID: 001601ccbf32$a070f890$e152e9b0$@com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

This is the output of "bt full" command in gdb of my test program.
In this case the libpqs was not compiled in debug-mode.

(gdb) bt full
#0 0xffffe410 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf76539cb in poll () from /lib/libc.so.6
No symbol table info available.
#2 0xf770d39a in pqSocketCheck () from /home/pg/pgsql/lib-32/libpq.so.5
No symbol table info available.
#3 0xf770d49d in pqWaitTimed () from /home/pg/pgsql/lib-32/libpq.so.5
No symbol table info available.
#4 0xf770d513 in pqWait () from /home/pg/pgsql/lib-32/libpq.so.5
No symbol table info available.
#5 0xf770c6d6 in PQgetResult () from /home/pg/pgsql/lib-32/libpq.so.5
No symbol table info available.
#6 0xf770c89c in PQexecFinish () from /home/pg/pgsql/lib-32/libpq.so.5
No symbol table info available.
#7 0x08048c3f in read_rigpia ()
No symbol table info available.
#8 0x08048ae9 in main ()

Here below I add the complete stack of my business application (blocked also it) if it can be useful.
In this case, the libpq was compiled in debug-mode and we can see the value parameter of function and the lines numbers of code.
Consider that the stack until PQexecFinish is the same as my test program.

(gdb) bt full
#0 0xffffe410 in __kernel_vsyscall ()
No symbol table info available.
#1 0xf6cdb9cb in poll () from /lib/libc.so.6
No symbol table info available.
#2 0xf766a39a in pqSocketPoll (conn=0x90e0838, forRead=1, forWrite=0, end_time=-1) at fe-misc.c:1082
No locals.
#3 pqSocketCheck (conn=0x90e0838, forRead=1, forWrite=0, end_time=-1)
at fe-misc.c:1024
result = -1
#4 0xf766a49d in pqWaitTimed (forRead=1, forWrite=0, conn=0x90e0838,
finish_time=-1) at fe-misc.c:956
result = <value optimized out>
#5 0xf766a513 in pqWait (forRead=1, forWrite=0, conn=0x90e0838)
at fe-misc.c:939
No locals.
#6 0xf76696d6 in PQgetResult (conn=0x90e0838) at fe-exec.c:1554
flushResult = 1
res = 0x0
#7 0xf766989c in PQexecFinish (conn=0x90e0838) at fe-exec.c:1807
result = 0x23
lastResult = 0x0
#8 0xf767c3ec in pos_fetch (cur_dta=0x9485c80) at possup.c:930
cmd = "FETCH 100 IN cur038_00063", '\000' <repeats 23 times>, "Þh\031\b\230\021&\bl_R\t(\tÜÿm\216\027\bø¸\016\t", '\000' <repeats 12 times>, "ø¸\016\t\000\000\000\000\020\000\000\000\230\021&\bl_R\tи\016\tX\tÜÿ/\221\027\bl_R\tи\016\t\001\000\000"
res = 0x0
bind = 0x0
buf = 0x0
colinfo = 0x0
colnum = 136712600
len = 156393324
type = 1
row = -2356856
null = 135921165
#9 0xf767b147 in dm_possup (request=35) at possup.c:216
retcode = 135268645
l = 156393324
eliminata = 0
#10 0x081076f3 in dm_call_fnc ()
No symbol table info available.
#11 0x080fda3d in dm_do_a_fetch ()
No symbol table info available.
#12 0x080fd913 in dm_fetch ()
No symbol table info available.
#13 0x08102974 in dm_execute ()
No symbol table info available.
#14 0x080f96de in execute_cursor ()
No symbol table info available.
#15 0x080f8556 in dm_do_dbms ()
No symbol table info available.
#16 0x080ff22f in dm_call ()
No symbol table info available.
#17 0x080f7edd in dm_dbms ()
No symbol table info available.
#18 0xf76a655e in dm_dbms_drv (
command=0xffdc0fa0 "with cursor cur038_00063 execute ")
at r_sqlutifunc.c:1090
No locals.
#19 0xf76ba4f6 in fetchCursorDb (curName=0xffdc1050 "cur038_00063")
at sqlPanth.c:895
buffer = "with cursor cur038_00063 execute ", '\000' <repeats 35 times>, "à*Öö\000\000\000\000\000\000\000\000ô/ÖöÇ¥l÷X¢Üÿ\030\020Üÿ¾\220ÆöP\020Üÿ\r¶l÷(\020Üÿ(\020Üÿ\004N<\bØ\020Üÿ+ k÷"
app = 0x0
retcode = 0
command = 0xf76cb6e4 "execute"
using_app = '\000' <repeats 1023 times>
#20 0xf76ba03d in fetchCursor (f0_file=38, curName=0xf76cbb40 "")
at sqlPanth.c:759
cursor = "cur038_00063", '\000' <repeats 115 times>
app = 0x0
retcode = 0
#21 0xf76bc020 in sqlRead (f0_file=38, w_dat=0xffdcc23c "", mode=7)
at sqlRead.c:109
msg = "\000\000\000\000\000\000\000\000\\^Íö\000\000\000\000\035\000\000\000\000\000\000\b\000\000\000\000^\002Ýÿ\000\000\000\000ph\021\th\221Üÿ\022íj÷\224.o÷à*Ööÿÿÿÿ«·\005\b"
s_where = " \"cdart\" = '50110725' ", '\000' <repeats 32740 times>
tslock = 0
tpOrd = 68
id_rec = 0
Failed = 0
failed_lock = 0
old_w_dat = 0x0
init_col = 0
ret = 0
#22 0xf7699159 in ISREAD (f0_file=38, w_dat=0xffdcc23c "", mode=7)
at r_dbswsql7.c:75
ret = -2321976
environ_save = '\000' <repeats 31 times>
#23 0x0807f6a4 in cal_prodat ()
No symbol table info available.
#24 0x08057650 in read_mrp () at /home/uwrk/pgsai/WRKUNX/g_mrprun.c:465
i = 0
idx = 0
dub = 4.8873862481069038e-313
dub1 = -1.209991882770505e+266
RFPO = {id = -153734240, cdart = "\027\000\000\000¨ÈÜÿéïÄöàÈÜÿ\000",
descr = "\000\000\n\000\000\000\000\000\000\000HÉÜÿ$\\\a\bàÈÜÿ\004:9\b\031\000\000", bkini = 0, bkfin = 0, stato = 85 'U',
cdpeg = '\000' <repeats 17 times>,
grpeg = "\000\000\000\000\000\000\000\000\000\065\000\000\000\000\000\000\000\000\000", tscon = 0 '\000', fillc = "\000\000\000", qtfan = 0,
qtpro = 0, bkpeg = 0, lnuti = 0, anpia = "\000",
nupia = "\000\000\000\000\000", nurig = "\000\000\000\000\000",
nupid = "\000\000\000\000",
fill = '\000' <repeats 45 times>, "\bÊÜÿÏ£\005\bU\000\000\000°\000\071\brÉÜÿph\021\t\034Ý2\b\000\000\000\000¸ÉÜÿ\215×,÷\220ÉPEZZI", '\000' <repeats 16 times>}
#25 0x08056f93 in cal_net () at /home/uwrk/pgsai/WRKUNX/g_mrprun.c:340
lotlt = 0
qta_app = 2.1220281700514382e-314
qta_incr = 8.2383361536408976e-315
n_volte = 121
it = 136
tsmax = 0
#26 0x08056f3c in mrp_run () at /home/uwrk/pgsai/WRKUNX/g_mrprun.c:317
counter = 23036
#27 0x08056cf9 in conf_dat () at /home/uwrk/pgsai/WRKUNX/g_mrprun.c:250
No locals.
#28 0x08056d56 in r_keybot (bm=36) at /home/uwrk/pgsai/WRKUNX/g_mrprun.c:265
No locals.
#29 0x08056ccb in s_entry (nsc=0x9116870 "g_mrprun.jam", con=128)
at /home/uwrk/pgsai/WRKUNX/g_mrprun.c:240
result = 137551132
stat_master = {st_dev = 651884900619439004, __pad1 = 62940,
st_ino = 1, st_mode = 4141232116, st_nlink = 24, st_uid = 1,
st_gid = 4292660168, st_rdev = 583229779520846990, __pad2 = 0,
st_size = -2307184, st_blksize = 136712600, st_blocks = 152135792,
st_atim = {tv_sec = 151778824, tv_nsec = -2307160}, st_mtim = {
tv_sec = 134928144, tv_nsec = 136512150}, st_ctim = {
tv_sec = 135726702, tv_nsec = 137550944}, __unused4 = 136712600,
__unused5 = 152135792}
stat_artico = {st_dev = 0, __pad1 = 4272, st_ino = 152140972,
st_mode = 1, st_nlink = 151778780, st_uid = 136712600,
st_gid = 4141232116, st_rdev = 128984812658, __pad2 = 12,
st_size = 0, st_blksize = -153735180, st_blocks = -2307224,
st_atim = {tv_sec = -154863084, tv_nsec = 151778768}, st_mtim = {
tv_sec = -2307184, tv_nsec = 12}, st_ctim = {tv_sec = 136250915,
tv_nsec = 40}, __unused4 = 1, __unused5 = 151778768}
stat_disbas = {st_dev = 135667194, __pad1 = 51960,
st_ino = 4292659912, st_mode = 136712600, st_nlink = 0, st_uid = 3,
st_gid = 4292659928, st_rdev = 5514874160500, __pad2 = 48,
st_size = -153730728, st_blksize = 136152200, st_blocks = 136712600,
st_atim = {tv_sec = 152153576, tv_nsec = -2307304}, st_mtim = {
tv_sec = 136147953, tv_nsec = 151914368}, st_ctim = {
tv_sec = 151916720, tv_nsec = 152151728}, __unused4 = 4140104046,
__unused5 = 0}
#30 0x08170570 in sm_call_fnc ()
No symbol table info available.
#31 0x081a7ddf in sm_fmfunc ()
No symbol table info available.
#32 0x081a7a20 in sm_frmtail ()
No symbol table info available.
#33 0x081a7772 in sm_frmfile ()
No symbol table info available.
#34 0x081a19ca in sm_r_window ()
No symbol table info available.
#35 0x081a18c8 in sm_r_there ()
No symbol table info available.
#36 0x08190cd4 in sm_jform ()
No symbol table info available.
#37 0x08190135 in sm_jexec_top ()
No symbol table info available.
#38 0x08190015 in sm_jtop ()
No symbol table info available.
#39 0x0807d11b in start_up ()
No symbol table info available.
#40 0x08056a71 in common_main (argc=2, argv=0xffdcd444)
at /home/pgsai/include/p_mainfi.h:11
No locals.
#41 0x08056998 in main (argc=2, argv=0xffdcd444)
at /home/pgsai/include/p_mainnm.h:17
No locals.

I am available for further requests.

Regards, Andrea

-----Messaggio originale-----
Da: Alvaro Herrera [mailto:alvherre(at)commandprompt(dot)com]
Inviato: martedì 20 dicembre 2011 16.43
A: Andrea Grassi
Cc: 'Craig Ringer'; Tom Lane; Pg Bugs
Oggetto: Re: R: R: [BUGS] BUG #6342: libpq blocks forever in "poll" function

Excerpts from Andrea Grassi's message of mar dic 20 06:01:55 -0300 2011:
> Sorry if I insist, but now I have the case at hand (my test program is now blocked), so I can check and verify all what you want.
> I would like to know if it can be a libpq bug or if you think the fault is due to a system bug or to a machine issue and in this case I would be grateful if you could give me a hint on what could be.

Please attach GDB to the stuck process (gdb -p `pidof testprogram`) and
grab a backtrace (bt full).

--
Álvaro Herrera <alvherre(at)commandprompt(dot)com>
The PostgreSQL Company - Command Prompt, Inc.
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

In response to

Browse pgsql-bugs by date

  From Date Subject
Next Message Andrea Grassi 2011-12-20 16:28:46 R: R: R: BUG #6342: libpq blocks forever in "poll" function
Previous Message Alvaro Herrera 2011-12-20 15:43:00 Re: R: R: BUG #6342: libpq blocks forever in "poll" function