That *might* be a problem with DBD::Sybase and/or with the way Sybase
client libs use signals.

As Lincoln suggested, a couple of traces might be useful.

I'm running under mod_perl, DBI 1.45 and DBD::Sybase 1.04. I'm attaching a number of traces.


The first listing below is what happens under $sth->trace(15) when there is no timeout and all goes well:

DBIx::HA::st=HASH(0x832d4c0) trace level set to 0x0/15 (DBI @ 0x0/0) in DBI 1.45-nothread (pid 20783)
-> execute for DBD::Sybase::st (DBIx::HA::st=HASH(0xad19a14)~0x832d4c0)
syb_alloc_cmd() -> CS_COMMAND 80af758 for CS_CONNECTION 8f4f2e0
syb_st_execute() -> ct_command() OK
syb_st_execute() -> ct_send() OK
st_next_result() -> ct_results(4043) == 1
ct_res_info() returns 1 columns
ct_describe(0): type = 8, maxlen = 4
describe() -> col 0, type 8, realtype 8
describe() retcode = 1
st_next_result() -> lasterr = 0, lastsev = 0
<- execute= -1


---

Then the DESTROY of that statement handle happens properly:

    -> DESTROY for DBD::Sybase::st (DBIx::HA::st=HASH(0x832d4c0)~INNER)
    syb_st_finish() -> flushing
    dbih_setup_fbav for 1 fields => 0xad2279c
    syb_st_fetch() -> 0/4/8
    st_next_result() -> ct_results(4047) == 1
    st_next_result() -> ct_results(4046) == 1
ct_results(4046) final retcode = -205
    st_next_result() -> lasterr = 0, lastsev = 0
    syb_st_fetch() -> st_next_results() == 4046
    syb_st_fetch() -> resetting ACTIVE, moreResults, dyn_execed
    syb_st_finish() -> resetting ACTIVE, moreResults, dyn_execed
    syb_st_destroy: called on ae1e200...
    syb_st_destroy(): freeing imp_sth->statement
    ct_cmd_drop() -> CS_COMMAND 80af758
    syb_st_destroy(): cmd dropped: 1
    <- DESTROY= undef

---

Now below is what happens when a timeout is caught and the execution is stopped by the signal:

DBIx::HA::st=HASH(0x832d4c0) trace level set to 0x0/15 (DBI @ 0x0/0) in DBI 1.45-nothread (pid 20784)
-> execute for DBD::Sybase::st (DBIx::HA::st=HASH(0xad1a364)~0x832d4c0)
syb_alloc_cmd() -> CS_COMMAND 80af758 for CS_CONNECTION 8f4f2e0
syb_st_execute() -> ct_command() OK
syb_st_execute() -> ct_send() OK
< HERE THE EXECUTION TIMES OUT AND IS STOPPED BY THE SIGNAL >
-> finish for DBD::Sybase::st (DBIx::HA::st=HASH(0xad1a364)~0x832d4c0)
syb_st_finish() -> flushing
(in cleanup) dbih_setup_fbav: invalid number of fields: -1, NUM_OF_FIELDS attribute probably not set right at /xxx/xxx/xxx.pm line 207.
DBI handle 0xad1a364 cleared whilst still active at /xxx/xxx/xxx.pm line 207.
DBI handle 0xad1a364 has uncleared implementors data at /xxx/xxx/xxx.pm line 207
dbih_clearcom (sth 0xad1a364, com 0xad26198, imp DBD::Sybase::st):
FLAGS 0x180057: COMSET IMPSET Active Warn ChopBlanks PrintWarn
PARENT DBIx::HA::db=HASH(0x919e514)
KIDS 0 (0 Active)
IMP_DATA undef
LongReadLen 32768
NUM_OF_FIELDS -1
NUM_OF_PARAMS 0


---

Here's a verbose strace of the call that times out and zombifies the statement handle:


select(32, [31], [], [31], {0, 0}) = 0 (Timeout)
fcntl64(5, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl64(5, F_SETFL, O_RDWR) = 0
send(5, "\17\1\0\31\0\0\0\0!\f\0\0\0\0use logging", 25, 0) = 25
recv(5, "\4\1\0l\0\0\0\0\343\21\0\1\7logging\7logging\345D\0E"..., 3072, 0) = 108
send(5, "\17\1\0\17\0\0\0\0\246\4\0\1\31\1\0", 15, 0) = 15
recv(5, "\4\1\0\21\0\0\0\0\375\0\0\2\0\0\0\0\0", 3072, 0) = 17
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 189) = 189
rt_sigprocmask(SIG_BLOCK, ~[], [RTMIN], 8) = 0
rt_sigaction(SIGALRM, NULL, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], ~[KILL STOP], 8) = 0
rt_sigaction(SIGALRM, {0x406c4c70, [], SA_RESTORER, 0x4009d4f8}, {SIG_DFL}, 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP], NULL, 8) = 0
rt_sigaction(SIGALRM, {0x406c4c70, [ALRM], SA_RESTORER, 0x4009d4f8}, NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
alarm(8) = 0
send(5, "\17\1\0\26\0\0\0\0!\t\0\0\0\0select 1", 22, 0) = 22
recv(5, "\4\1\0000\0\0\0\0a\21\0\0\0\1\0\0\0\0\0\0\20\0\0\0\7\0"..., 3072, 0) = 48
alarm(0) = 8
rt_sigprocmask(SIG_BLOCK, ~[], [RTMIN], 8) = 0
rt_sigprocmask(SIG_BLOCK, [ALRM], ~[KILL STOP], 8) = 0
rt_sigaction(SIGALRM, {SIG_DFL}, {0x406c4c70, [ALRM], SA_RESTORER, 0x4009d4f8}, 8) = 0
rt_sigprocmask(SIG_SETMASK, ~[KILL STOP], NULL, 8) = 0
rt_sigaction(SIGALRM, {SIG_DFL}, NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [RTMIN], NULL, 8) = 0
alarm(0) = 0
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 69) = 69
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 77) = 77
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 302) = 302


<snip Carp stuff>

open("/usr/lib/perl5/5.8.4/Carp/Heavy.pm", O_RDONLY|O_LARGEFILE) = 6
ioctl(6, SNDCTL_TMR_TIMEBASE, 0xbffff350) = -1 ENOTTY (Inappropriate ioctl for device)
_llseek(6, 0, [0], SEEK_CUR) = 0
read(6, "# Carp::Heavy uses some variable"..., 4096) = 4096
brk(0) = 0xae35000
brk(0xae36000) = 0xae36000
brk(0) = 0xae36000
brk(0xae37000) = 0xae37000
brk(0) = 0xae37000
brk(0xae38000) = 0xae38000
brk(0) = 0xae38000
brk(0xae39000) = 0xae39000
brk(0) = 0xae39000
brk(0xae3a000) = 0xae3a000
brk(0) = 0xae3a000
brk(0xae3b000) = 0xae3b000
brk(0) = 0xae3b000
brk(0xae3c000) = 0xae3c000
read(6, "ler($i++);\n my $caller = call"..., 4096) = 1831
brk(0) = 0xae3c000
brk(0xae3d000) = 0xae3d000
brk(0) = 0xae3d000
brk(0xae3e000) = 0xae3e000
brk(0) = 0xae3e000
brk(0xae3f000) = 0xae3f000
brk(0) = 0xae3f000
brk(0xae40000) = 0xae40000
read(6, "", 4096) = 0
close(6) = 0
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 58) = 58
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 69) = 69
close(5) = 0
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 338) = 338
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 51) = 51
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 163) = 163
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 216) = 216
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 157) = 157
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 161) = 161
write(2, " dbih_clearcom (sth 0xace6e0c"..., 71) = 71
write(2, " FLAGS 0x180057: COMSET IM"..., 71) = 71
write(2, " PARENT DBIx::HA::db=HASH("..., 43) = 43
write(2, " KIDS 0 (0 Active)\n", 25) = 25
write(2, " IMP_DATA undef\n", 22) = 22
write(2, " LongReadLen 32768\n", 25) = 25
write(2, " NUM_OF_FIELDS -1\n", 24) = 24
write(2, " NUM_OF_PARAMS 0\n", 23) = 23
time([1101370634]) = 1101370634
write(2, "[Thu Nov 25 00:17:14 2004] null:"..., 404) = 404
rt_sigaction(SIGALRM, {0x406c4c70, [], SA_RESTORER, 0x4009d4f8}, {SIG_DFL}, 8) = 0




Reply via email to