segfault on rollback

Hello -hackers,

I recently have seen the segfault with Postgres 8.1.4.

The situation in which the segfault occur is quite complicated (a lot of
commands in one transaction from JDBC), but Here I show the gdb core dump of
it. From looking in my application, it seems that the core dump occurs when
the application issue the ROLLBACK command in the end of large transaction.
(when I do Connection.rollback() from JDBC)

Also I must notice that the segfault only occur if
log_min_duration_statement is set to 0

if it is set to -1, the segfault do not occur.

Also I must say that I specially removed all the C functions calls from the
transaction, to be sure that I'm not corrupting the memory myself.

Program received signal SIGSEGV, Segmentation fault.
0xb7dbd6db in strlen () from /lib/tls/libc.so.6
(gdb) bt
#0 0xb7dbd6db in strlen () from /lib/tls/libc.so.6
#1 0xb7d91ef1 in vfprintf () from /lib/tls/libc.so.6
#2 0xb7db0700 in vsnprintf () from /lib/tls/libc.so.6
#3 0x08179c47 in appendStringInfoVA (str=0xbfd639f0,
fmt=0x83d43c0 "duration: %ld.%03ld ms statement: %sEXECUTE %s [PREPARE: %s]", args=0xbfd63a24 "Y") at stringinfo.c:125
#4 0x08290471 in errmsg (
fmt=0x834b0c0 "duration: %ld.%03ld ms statement: %sEXECUTE %s [PREPARE: %s]") at elog.c:647
#5 0x08202bd2 in exec_execute_message (portal_name=0x8421a6c "", max_rows=1)
at postgres.c:1825
#6 0x0820498a in PostgresMain (argc=4, argv=0x83d2754,
username=0x83d2658 "cas_user_tmp") at postgres.c:3268
#7 0x081d3528 in BackendRun (port=0x83eaed0) at postmaster.c:2856
#8 0x081d2b3f in BackendStartup (port=0x83eaed0) at postmaster.c:2500
#9 0x081d0bc9 in ServerLoop () at postmaster.c:1230
#10 0x081d0474 in PostmasterMain (argc=1, argv=0x83bb000) at postmaster.c:941
#11 0x081821d8 in main (argc=1, argv=0x83bb000) at main.c:265

(gdb) bt full
#0 0xb7dbd6db in strlen () from /lib/tls/libc.so.6
No symbol table info available.
#1 0xb7d91ef1 in vfprintf () from /lib/tls/libc.so.6
No symbol table info available.
#2 0xb7db0700 in vsnprintf () from /lib/tls/libc.so.6
No symbol table info available.
#3 0x08179c47 in appendStringInfoVA (str=0xbfd639f0,
fmt=0x83d43c0 "duration: %ld.%03ld ms statement: %sEXECUTE %s [PREPARE: %s]", args=0xbfd63a24 "Y") at stringinfo.c:125
avail = 255
nprinted = 256
#4 0x08290471 in errmsg (
fmt=0x834b0c0 "duration: %ld.%03ld ms statement: %sEXECUTE %s [PREPARE: %s]") at elog.c:647
args = 0xbfd63a24 "Y"
success = -65 '©'
fmtbuf = 0x83d43c0 "duration: %ld.%03ld ms statement: %sEXECUTE %s [PREPARE: %s]"
buf = {
data = 0x83d42b4 "duration: 89.073 ms statement: EXECUTE <unnamed> [PREPARE: ", '\177' <repeats 138 times>..., len = 0, maxlen = 256, cursor = 0}
edata = (ErrorData *) 0x83ab3a0
oldcontext = 0x83d1f00
---Type <return> to continue, or q <return> to quit---
#5 0x08202bd2 in exec_execute_message (portal_name=0x8421a6c "", max_rows=1)
at postgres.c:1825
usecs = 89073
dest = DestRemoteExecute
receiver = (DestReceiver *) 0x8421b78
portal = 0x842c114
completed = 1 '\001'
completionTag = "ROLLBACK\000:ж©Ф\033\030\bэ:ж©m\032B\b\004\000\000\000%\n \b╓\201?\b\000\001\000\000Х:ж©Ё\031\030\b\000\000\000\001э:ж©\004\000\000\000\224\035\030\b"
start_t = {tv_sec = 1155432847, tv_usec = 699143}
stop_t = {tv_sec = 1155432847, tv_usec = 788216}
save_log_duration = 0 '\0'
save_log_min_duration_statement = 0
save_log_statement_stats = 0 '\0'
execute_is_fetch = 0 '\0'
#6 0x0820498a in PostgresMain (argc=4, argv=0x83d2754,
username=0x83d2658 "cas_user_tmp") at postgres.c:3268
portal_name = 0x8421a6c ""
max_rows = 1
flag = -1
dbname = 0x83dd198 "cas"
userDoption = 0x0
---Type <return> to continue, or q <return> to quit---
secure = 0 '\0'
errs = 0
debug_flag = -1
guc_names = (List *) 0x0
guc_values = (List *) 0x0
ctx = PGC_USERSET
gucsource = PGC_S_CLIENT
am_superuser = 0 '\0'
tmp = 0x83d232c ""
firstchar = 69
stack_base = 0 '\0'
input_message = {data = 0x8421a6c "", len = 5, maxlen = 256,
cursor = 5}
local_sigjmp_buf = {{__jmpbuf = {138325712, 137883360, 1, -1076478888,
-1076479248, 136332736}, __mask_was_saved = 1, __saved_mask = {__val = {
1073347075, 4294967294, 0, 0, 0, 0, 0, 7004, 0, 8, 0, 0, 138225460,
138224272, 138223360, 3218488264, 4294967295, 138223360, 3085359680,
3084618868, 138225440, 138224272, 3084378772, 138326168, 3085312352,
200, 138249720, 138241528, 3085367328, 137883360, 1, 3218488344}}}}
send_rfq = 0 '\0'
#7 0x081d3528 in BackendRun (port=0x83eaed0) at postmaster.c:2856
status = 0
remote_host = "127.0.0.1\000ж╥\000ЮФ╥\004\aГ╥\004\aГ╥xAж©bЦщ╥\004\aГ╥\00---Type <return> to continue, or q <return> to quit---
0\000\000\000hAж©╠\201*\b<\032Г╥\000\000\000\000\004\aГ╥\002\024\000\000\000\024\000\000\000\000\000\000\000ЮФ╥╪\177=\bо]3\b\000ЮФ╥ ХФ╥\000шФ╥hAж©\b\212з╥ ХФ╥\005\000\000\000\000\000\000\000xEж©И╗ш╥\000ЮФ╥ЬAж©дБщ╥\210Aж©\000ЮФ╥\004\aГ╥\224Бв╥ЬAж©bЦщ╥\004\aГ╥\000\000\000\000\002\024\000\000\005\000\000\000<\032Г╥\000\000\000\000\004\aГ╥\003\024\000\000\000\024\000\000\000\000\000\000"...
remote_port = "32989\000ж©╥\220У╥ГEш╥FD\a\bЭDж©И╗ш╥\000ЮФ"
remote_ps_data = "127.0.0.1(32989)\000╚х\233pq©\233\034чФ╥p<ж©.фУ╥\000\000\000\000\000\000\000\000╦qЖ╥\000\000\000\000\000\000\000\000\003\000\000\000P<ж©ьoЖ╥\000\000\000\000\b©;\bL=ж©\"еУ╥\b©;\b\001\000\000\000дGж©ю!=\b╦\031ж╥Жiж╥╦qЖ╥╪tЖ╥\000\000\000\000дGж©\001\000\000\000\000ЮФ╥юlЖ╥ю!=\bл=ж©O\000Д╥ю!=\b\000\000\000\200\001\000\000\220\000\000\000\000 1\001\000Ю\236>\b\004\000\000\000\003\000\000\000 ЬФ╥\000ЮФ╥ ЬФ╥юlЖ╥═=ж©"...
av = (char **) 0x83d2754
maxac = 10
ac = 4
protobuf = "-v196608\000<ж©\000\024\000\000ЪЪЪЪ\000\000\000\000ПТ$\234\000\000\000"
i = 4
#8 0x081d2b3f in BackendStartup (port=0x83eaed0) at postmaster.c:2500
bn = (Backend *) 0x83dd0c8
pid = 0
#9 0x081d0bc9 in ServerLoop () at postmaster.c:1230
timeout = {tv_sec = 59, tv_usec = 948000}
---Type <return> to continue, or q <return> to quit---
selres = 1
i = 0
port = (Port *) 0x83eaed0
rmask = {fds_bits = {8, 0 <repeats 31 times>}}
readmask = {fds_bits = {24, 0 <repeats 31 times>}}
nSockets = 5
now = 1155432807
last_touch_time = 1155432686
earlier = {tv_sec = 1155432686, tv_usec = 49004}
later = {tv_sec = 1155432765, tv_usec = 301709}
#10 0x081d0474 in PostmasterMain (argc=1, argv=0x83bb000) at postmaster.c:941
opt = -1
status = 0
userDoption = 0x0
i = 64
#11 0x081821d8 in main (argc=1, argv=0x83bb000) at main.c:265
pw = (struct passwd *) 0xb7f66cc0
pw_name_persist = 0xb7e6e000 "\\}\021"

Any ideas ? Or I should try to narrower the problem ?... (it is not very easy
for my application)...

Initially I thought that the problem can be due to JDBC, but it doesn't
seem so... In any case, since JDBC for PG is pure java and is using libpq,
Posgres shouldn't crash.

Thanks,
Regards,
Sergey

*******************************************************************
Sergey E. Koposov
Max Planck Institute for Astronomy/Sternberg Astronomical Institute
Tel: +49-6221-528-349
Web: http://lnfm1.sai.msu.ru/~math
E-mail: math(at)sai(dot)msu(dot)ru