Thread: plperl db crash
I had a db lock up on one of our machines.
To reproduce it, I did a fresh install on a testing machine.
On the other machine where it occured the first time the db just hung,
but it didn't crash. I tried to /etc/init.d/postgresql stop
But it didn't stop.
Then I did pg_ctl -m immediate stop
The log said something like 'redo is not required', so i gues everything
should be fine.
However, like already said, I did a fresh install on a testing machine
and there it crashes:
------------------------------------------------------------------------
debian/unstable
postgresql 7.3.4
/usr/lib/postgresql/bin/createlang plperl plasma
psql plasma
CREATE FUNCTION perlsub(text, text, text) RETURNS text AS '
my ($data, $pat, $repl) = $_;
$data =~ s/$pat/$repl/;
return $data
' LANGUAGE 'plperl';
-- Taken from here:
-- http://archives.postgresql.org/pgsql-general/2001-02/msg00798.php
plasma=# SELECT perlsub('abc','b','123');
server closed the connection unexpectedly
This probably means the server terminated abnormally
before or while processing the request.
The connection to the server was lost. Attempting reset: Failed.
!#
---------------------------------------------------------------
Oct 2 19:15:00 billy postgres[23521]: [7] LOG: connection received:
host=[local]
Oct 2 19:15:00 billy postgres[23521]: [8] LOG: connection authorized:
user=plasma database=plasma
Oct 2 19:15:02 billy postgres[23329]: [7] LOG: server process (pid
23521) was terminated by signal 11
Oct 2 19:15:02 billy postgres[23329]: [8] LOG: terminating any other
active server processes
Oct 2 19:15:02 billy postgres[23329]: [9] LOG: all server processes
terminated; reinitializing shared memory and semaphores
Oct 2 19:15:02 billy postgres[23523]: [10] LOG: database system was
interrupted at 2003-10-02 19:13:01 CEST
Oct 2 19:15:02 billy postgres[23523]: [11] LOG: checkpoint record is
at 0/83238C
Oct 2 19:15:02 billy postgres[23523]: [12] LOG: redo record is at
0/83238C; undo record is at 0/0; shutdown TRUE
Oct 2 19:15:02 billy postgres[23523]: [13] LOG: next transaction id:
513; next oid: 25168
Oct 2 19:15:02 billy postgres[23523]: [14] LOG: database system was
not properly shut down; automatic recovery in progress
Oct 2 19:15:02 billy postgres[23523]: [15] LOG: ReadRecord: record
with zero length at 0/8323CC
Oct 2 19:15:02 billy postgres[23523]: [16] LOG: redo is not required
Oct 2 19:15:02 billy postgres[23524]: [10] LOG: connection received:
host=[local]
Oct 2 19:15:02 billy postgres[23524]: [11] FATAL: The database system
is starting up
Oct 2 19:15:04 billy postgres[23523]: [17] LOG: database system is ready
---------------------------------------------------------------
--
e-Trolley Sayegh & John, Nabil Sayegh
Tel.: 0700 etrolley /// 0700 38765539
Fax.: +49 69 8299381-8
PGP : http://www.e-trolley.de
Nabil, > However, like already said, I did a fresh install on a testing machine > and there it crashes: > > ------------------------------------------------------------------------ > debian/unstable <=== this is most likely your culprit > postgresql 7.3.4 I've been using pl/perl in production for up to 3 years on some projects. My first thought would be that it's a problem with Perl on Debian/unstable, not a problem with PostgreSQL. I'd suggest that you do a gdb trace and post it to pgsql-bugs to get feedback on where the issue lies. -- Josh Berkus Aglio Database Solutions San Francisco
On Thu, 2003-10-02 at 18:30, Nabil Sayegh wrote: > I had a db lock up on one of our machines. > To reproduce it, I did a fresh install on a testing machine. > > On the other machine where it occured the first time the db just hung, > but it didn't crash. I tried to /etc/init.d/postgresql stop > But it didn't stop. > > Then I did pg_ctl -m immediate stop > The log said something like 'redo is not required', so i gues everything > should be fine. > > However, like already said, I did a fresh install on a testing machine > and there it crashes: > > ------------------------------------------------------------------------ > debian/unstable > postgresql 7.3.4 Is this the Debian package or your own build? If it's the package, what is the package's full release number? -- Oliver Elphick Oliver.Elphick@lfix.co.uk Isle of Wight, UK http://www.lfix.co.uk/oliver GPG: 1024D/3E1D0C1C: CA12 09E0 E8D5 8870 5839 932A 614D 4C34 3E1D 0C1C ======================================== "Set your affection on things above, not on things on the earth." Colossians 3:2
> Is this the Debian package or your own build? If it's the package, what > is the package's full release number? It is 7.3.4-5 (not self built) Is there a way to dump a list of all my installed packages ? cu
On Fri, 2003-10-03 at 02:23, Nabil Sayegh wrote:
> > Is this the Debian package or your own build? If it's the package, what
> > is the package's full release number?
>
> It is 7.3.4-5 (not self built)
> Is there a way to dump a list of all my installed packages ?
One way is:
dpkg --get-selections | grep -Ev 'deinstall|purge$' | awk '{print $1}'
Strictly, this tells you the requested rather than the actual state of
your packages.
--
Oliver Elphick Oliver.Elphick@lfix.co.uk
Isle of Wight, UK http://www.lfix.co.uk/oliver
GPG: 1024D/3E1D0C1C: CA12 09E0 E8D5 8870 5839 932A 614D 4C34 3E1D 0C1C
========================================
"I beseech you therefore, brethren, by the mercies of
God, that ye present your bodies a living sacrifice,
holy, acceptable unto God, which is your reasonable
service. And be not conformed to this world; but be ye
transformed by the renewing of your mind, that ye may
prove what is that good, and acceptable, and perfect,
will of God." Romans 12:1,2
On Thu, 2003-10-02 at 18:30, Nabil Sayegh wrote:
> I had a db lock up on one of our machines.
> To reproduce it, I did a fresh install on a testing machine.
...
> ------------------------------------------------------------------------
> debian/unstable
> postgresql 7.3.4
>
> /usr/lib/postgresql/bin/createlang plperl plasma
> psql plasma
>
> CREATE FUNCTION perlsub(text, text, text) RETURNS text AS '
> my ($data, $pat, $repl) = $_;
^^^
That should be @_ (but that wouldn't cause the crash).
> $data =~ s/$pat/$repl/;
> return $data
> ' LANGUAGE 'plperl';
>
> -- Taken from here:
> -- http://archives.postgresql.org/pgsql-general/2001-02/msg00798.php
>
> plasma=# SELECT perlsub('abc','b','123');
> server closed the connection unexpectedly
I'm just uploading 7.3.4-6 to unstable.
I've tested this function with that release and your problem does not
occur on my system, but I'm not aware of having done anything to affect
it.
--
Oliver Elphick Oliver.Elphick@lfix.co.uk
Isle of Wight, UK http://www.lfix.co.uk/oliver
GPG: 1024D/3E1D0C1C: CA12 09E0 E8D5 8870 5839 932A 614D 4C34 3E1D 0C1C
========================================
"I beseech you therefore, brethren, by the mercies of
God, that ye present your bodies a living sacrifice,
holy, acceptable unto God, which is your reasonable
service. And be not conformed to this world; but be ye
transformed by the renewing of your mind, that ye may
prove what is that good, and acceptable, and perfect,
will of God." Romans 12:1,2
Josh Berkus wrote: > I'd suggest that you do a gdb trace and post it to pgsql-bugs to get feedback > on where the issue lies. gdb doesn't notice the 'crash'. It seems to be handled by the postmaster itself. I think I will contact Oliver Elphick then. thx -- e-Trolley Sayegh & John, Nabil Sayegh Tel.: 0700 etrolley /// 0700 38765539 Fax.: +49 69 8299381-8 PGP : http://www.e-trolley.de
Nabil Sayegh wrote: > I had a db lock up on one of our machines. > To reproduce it, I did a fresh install on a testing machine. > > On the other machine where it occured the first time the db just hung, > but it didn't crash. I tried to /etc/init.d/postgresql stop > But it didn't stop. Another fact I had forgotten: The 'original' problem occured when I wanted to DROP FUNCTION perlsub; The 'original' system was 7.3.4-5, too. It didn't crash when executing the function but locked up the db when i wanted to remove the function. Sorry for not mentioning it before :| However the testing system crashes when executing the function. I will upgrade ASA it is in my apt sources. cu -- e-Trolley Sayegh & John, Nabil Sayegh Tel.: 0700 etrolley /// 0700 38765539 Fax.: +49 69 8299381-8 PGP : http://www.e-trolley.de
Oliver Elphick wrote:
> I'm just uploading 7.3.4-6 to unstable.
>
> I've tested this function with that release and your problem does not
> occur on my system, but I'm not aware of having done anything to affect
> it.
>
Here's the strace output:
---------------------------------------8<---------------------------------
) = 1 (in [4], left {288, 80000})
--- SIGCHLD (Child exited) @ 0 (0) ---
rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS],
NULL, 8) = 0
waitpid(-1, [WIFSIGNALED(s) && WTERMSIG(s) == SIGSEGV && WCOREDUMP(s)],
WNOHANG) = 6147
time(NULL) = 1065208172
socket(PF_UNIX, SOCK_DGRAM, 0) = 8
fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
connect(8, {sa_family=AF_UNIX, path="/dev/log"}, 16) = 0
time([1065208172]) = 1065208172
getpid() = 6136
rt_sigaction(SIGPIPE, {0x40334540, [], SA_RESTORER, 0x40289578},
{SIG_IGN}, 8) = 0
send(8, "<134>Oct 3 21:09:32 postgres[61"..., 100, 0) = 100
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
time(NULL) = 1065208172
time([1065208172]) = 1065208172
getpid() = 6136
rt_sigaction(SIGPIPE, {0x40334540, [], SA_RESTORER, 0x40289578},
{SIG_IGN}, 8) = 0
send(8, "<134>Oct 3 21:09:32 postgres[61"..., 92, 0) = 92
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
send(5, "\2\0\0\0\30\0\0\0\0\0\0\0\3\30\0\0\0\0\0\0\0\0\0\0", 24, 0) = 24
waitpid(-1, 0xbffff39c, WNOHANG) = 0
time(NULL) = 1065208172
time([1065208172]) = 1065208172
getpid() = 6136
rt_sigaction(SIGPIPE, {0x40334540, [], SA_RESTORER, 0x40289578},
{SIG_IGN}, 8) = 0
send(8, "<134>Oct 3 21:09:32 postgres[61"..., 123, 0) = 123
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
semctl(983040, 0, IPC_RMID, 0xbffff2dc) = 0
semctl(1015809, 0, IPC_RMID, 0xbffff2dc) = 0
semctl(1048578, 0, IPC_RMID, 0xbffff2dc) = 0
semctl(1081347, 0, IPC_RMID, 0xbffff2dc) = 0
semctl(1114116, 0, IPC_RMID, 0xbffff2dc) = 0
shmdt(0x4040a000) = 0
shmctl(3768320, IPC_RMID, 0) = 0
shmget(5432001, 9732096, IPC_CREAT|IPC_EXCL|0600) = 3801111
shmat(3801111, 0, 0) = 0x4040a000
open("/var/lib/postgres/data/postmaster.pid", O_RDWR|O_LARGEFILE) = 9
read(9, "6136\n/var/lib/postgres/data\n 54"..., 8092) = 48
_llseek(9, 0, [0], SEEK_SET) = 0
write(9, "6136\n/var/lib/postgres/data\n 54"..., 48) = 48
close(9) = 0
getpid() = 6136
open("/var/lib/postgres/data/global/pg_control", O_RDWR|O_LARGEFILE) = 9
read(9, "\23\240^\34?\350\375<H\0\0\0M\372\356\v\4\0\0\0`\311}?"...,
360) = 360
close(9) = 0
semget(5432001, 17, IPC_CREAT|IPC_EXCL|0600) = 1146880
semctl(1146880, 16, SETVAL, 0xbffff23c) = 0
semop(1146880, 0xbffff2a4, 1) = 0
semctl(1146880, 0, SETVAL, 0xbffff26c) = 0
semctl(1146880, 1, SETVAL, 0xbffff26c) = 0
semctl(1146880, 2, SETVAL, 0xbffff26c) = 0
semctl(1146880, 3, SETVAL, 0xbffff26c) = 0
semctl(1146880, 4, SETVAL, 0xbffff26c) = 0
semctl(1146880, 5, SETVAL, 0xbffff26c) = 0
semctl(1146880, 6, SETVAL, 0xbffff26c) = 0
semctl(1146880, 7, SETVAL, 0xbffff26c) = 0
semctl(1146880, 8, SETVAL, 0xbffff26c) = 0
semctl(1146880, 9, SETVAL, 0xbffff26c) = 0
semctl(1146880, 10, SETVAL, 0xbffff26c) = 0
semctl(1146880, 11, SETVAL, 0xbffff26c) = 0
semctl(1146880, 12, SETVAL, 0xbffff26c) = 0
semctl(1146880, 13, SETVAL, 0xbffff26c) = 0
semctl(1146880, 14, SETVAL, 0xbffff26c) = 0
semctl(1146880, 15, SETVAL, 0xbffff26c) = 0
semget(5432002, 17, IPC_CREAT|IPC_EXCL|0600) = 1179649
semctl(1179649, 16, SETVAL, 0xbffff23c) = 0
semop(1179649, 0xbffff2a4, 1) = 0
semctl(1179649, 0, SETVAL, 0xbffff26c) = 0
semctl(1179649, 1, SETVAL, 0xbffff26c) = 0
semctl(1179649, 2, SETVAL, 0xbffff26c) = 0
semctl(1179649, 3, SETVAL, 0xbffff26c) = 0
semctl(1179649, 4, SETVAL, 0xbffff26c) = 0
semctl(1179649, 5, SETVAL, 0xbffff26c) = 0
semctl(1179649, 6, SETVAL, 0xbffff26c) = 0
semctl(1179649, 7, SETVAL, 0xbffff26c) = 0
semctl(1179649, 8, SETVAL, 0xbffff26c) = 0
semctl(1179649, 9, SETVAL, 0xbffff26c) = 0
semctl(1179649, 10, SETVAL, 0xbffff26c) = 0
semctl(1179649, 11, SETVAL, 0xbffff26c) = 0
semctl(1179649, 12, SETVAL, 0xbffff26c) = 0
semctl(1179649, 13, SETVAL, 0xbffff26c) = 0
semctl(1179649, 14, SETVAL, 0xbffff26c) = 0
semctl(1179649, 15, SETVAL, 0xbffff26c) = 0
semget(5432003, 17, IPC_CREAT|IPC_EXCL|0600) = 1212418
semctl(1212418, 16, SETVAL, 0xbffff23c) = 0
semop(1212418, 0xbffff2a4, 1) = 0
semctl(1212418, 0, SETVAL, 0xbffff26c) = 0
semctl(1212418, 1, SETVAL, 0xbffff26c) = 0
semctl(1212418, 2, SETVAL, 0xbffff26c) = 0
semctl(1212418, 3, SETVAL, 0xbffff26c) = 0
semctl(1212418, 4, SETVAL, 0xbffff26c) = 0
semctl(1212418, 5, SETVAL, 0xbffff26c) = 0
semctl(1212418, 6, SETVAL, 0xbffff26c) = 0
semctl(1212418, 7, SETVAL, 0xbffff26c) = 0
semctl(1212418, 8, SETVAL, 0xbffff26c) = 0
semctl(1212418, 9, SETVAL, 0xbffff26c) = 0
semctl(1212418, 10, SETVAL, 0xbffff26c) = 0
semctl(1212418, 11, SETVAL, 0xbffff26c) = 0
semctl(1212418, 12, SETVAL, 0xbffff26c) = 0
semctl(1212418, 13, SETVAL, 0xbffff26c) = 0
semctl(1212418, 14, SETVAL, 0xbffff26c) = 0
semctl(1212418, 15, SETVAL, 0xbffff26c) = 0
semget(5432004, 17, IPC_CREAT|IPC_EXCL|0600) = 1245187
semctl(1245187, 16, SETVAL, 0xbffff23c) = 0
semop(1245187, 0xbffff2a4, 1) = 0
semctl(1245187, 0, SETVAL, 0xbffff26c) = 0
semctl(1245187, 1, SETVAL, 0xbffff26c) = 0
semctl(1245187, 2, SETVAL, 0xbffff26c) = 0
semctl(1245187, 3, SETVAL, 0xbffff26c) = 0
semctl(1245187, 4, SETVAL, 0xbffff26c) = 0
semctl(1245187, 5, SETVAL, 0xbffff26c) = 0
semctl(1245187, 6, SETVAL, 0xbffff26c) = 0
semctl(1245187, 7, SETVAL, 0xbffff26c) = 0
semctl(1245187, 8, SETVAL, 0xbffff26c) = 0
semctl(1245187, 9, SETVAL, 0xbffff26c) = 0
semctl(1245187, 10, SETVAL, 0xbffff26c) = 0
semctl(1245187, 11, SETVAL, 0xbffff26c) = 0
semctl(1245187, 12, SETVAL, 0xbffff26c) = 0
semctl(1245187, 13, SETVAL, 0xbffff26c) = 0
semctl(1245187, 14, SETVAL, 0xbffff26c) = 0
semctl(1245187, 15, SETVAL, 0xbffff26c) = 0
semget(5432005, 17, IPC_CREAT|IPC_EXCL|0600) = 1277956
semctl(1277956, 16, SETVAL, 0xbffff23c) = 0
semop(1277956, 0xbffff2a4, 1) = 0
semctl(1277956, 0, SETVAL, 0xbffff26c) = 0
brk(0) = 0x827d000
brk(0x829e000) = 0x829e000
fork() = 6148
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
sigreturn() = ? (mask now [])
rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS],
NULL, 8) = 0
accept(4, {sa_family=AF_UNIX, path=@}, [2]) = 9
getsockname(9, {sa_family=AF_UNIX,
path="/var/run/postgresql/.s.PGSQL.5432"}, [36]) = 0
fork() = 6149
close(9) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD (Child exited) @ 0 (0) ---
rt_sigprocmask(SIG_SETMASK, ~[ILL TRAP ABRT BUS FPE SEGV CONT SYS],
NULL, 8) = 0
waitpid(-1, [WIFEXITED(s) && WEXITSTATUS(s) == 0], WNOHANG) = 6149
send(5, "\2\0\0\0\30\0\0\0\0\0\0\0\5\30\0\0\0\0\0\0\0\0\0\0", 24, 0) = 24
waitpid(-1, 0xbffff39c, WNOHANG) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
sigreturn() = ? (mask now [])
select(5, [3 4], [], NULL, {60, 0} <unfinished ...>
---------------------------------8<-------------------------------------
--
e-Trolley Sayegh & John, Nabil Sayegh
Tel.: 0700 etrolley /// 0700 38765539
Fax.: +49 69 8299381-8
PGP : http://www.e-trolley.de
Oliver Elphick wrote: > Wait for the new release and try it. Then let me know if it still isn't > working. fixed with libpgperl 7.3.4-6 it works. TFYH -- e-Trolley Sayegh & John, Nabil Sayegh Tel.: 0700 etrolley /// 0700 38765539 Fax.: +49 69 8299381-8 PGP : http://www.e-trolley.de