Take the 2-minute tour ×
Server Fault is a question and answer site for system and network administrators. It's 100% free, no registration required.

Since upgrading a Gentoo box from postfix 2.5.5 to 2.6.6, local mail delivery does no longer work. Virtual mailboxes still work.

Here's the log:

Jul 14 13:07:05 weser postfix/master[15825]: warning: process /usr/lib/postfix/local pid 20065 killed by signal 11
Jul 14 13:07:05 weser postfix/master[15825]: warning: /usr/lib/postfix/local: bad command startup -- throttling
Jul 14 13:07:05 weser postfix/qmgr[15829]: warning: private/local socket: malformed response
Jul 14 13:07:05 weser postfix/qmgr[15829]: warning: transport local failure -- see a previous warning/fatal/panic logfile record for the problem description
Jul 14 13:07:05 weser postfix/error[20067]: 5D2A3466D56C: to=<oliver@weser.XXX.YY>, orig_to=<oliver@ZZZ.ZZ>, relay=none, delay=6.9, delays=6.7/0.05/0/0.08, dsn=4.3.0, status=deferred (unknown mail transport error)

Where weser.XXX.YY is the local machine. I tried the -v switch on local and qmgr but it didn't help me very much.

I'm pretty clueless how to debug any further. Trying to trace the processes with debugger_command didn't generate any expected output files.

Questions:

  1. How do I debug that any further?
  2. Are there any caveats I should've known of before upgrading from 2.5 to 2.6?

Update: I managed to get a strace log, and it looks like the segfault immediatly occurs after reading the spool file from the active queue.

Update 2: I managed to get a coredump and created a backtrace:

#0  0x138f9469 in vstring_strcpy (vp=0x13929630, src=0x0) at vstring.c:409
#1  0x138e66d9 in dict_db_lookup (dict=0x139295b0, name=0x0) at dict_db.c:200
#2  0x138bd83e in deliver_alias (state=
      {level = 1, msg_attr = {level = 0, fp = 0x1392f630, queue_name = 0x1392f520 "active", queue_id = 0x1392f248 "0658546584CA", offset = 218, encoding = 0x1390b018 "", sender = 0x1390b018 "", dsn_envid = 0x1390b018 "", dsn_ret = 0, rcpt = {offset = 191, dsn_orcpt = 0x1390b018 "", dsn_notify = 0, orig_addr = 0x1392f5e0 "root@weser.XXX.YY", address = 0x1392f608 "root@weser.XXX.YY", u = {status = 0, queue = 0x0, addr_type = 0x0}}, domain = 0x0, local = 0x0, user = 0x0, extension = 0x0, unmatched = 0x0, owner = 0x0, delivered = 0x0, relay = 0x5d8f4a53 "local", msg_stats = {incoming_arrival = {tv_sec = 1279051621, tv_usec = 25651}, active_arrival = {tv_sec = 1279121939, tv_usec = 42594}, agent_handoff = {tv_sec = 1279121939, tv_usec = 124639}, conn_setup_done = {tv_sec = 0, tv_usec = 0}, deliver_done = {tv_sec = 0, tv_usec = 0}, reuse_count = 0}, exp_type = 0, exp_from = 0x0, request = 0x1392eb88, why = 0x1392f700}, dup_filter = 0x13931360, loop_info = 0x1392fa18, request = 0x1392eb88}, usr_attr={uid = 0, gid = 0, home = 0x0, logname = 0x0, shell = 0x0}, name=0x0, statusp=0x5d8f3d58)
    at alias.c:199
#3  0x138c3df9 in deliver_switch (state=
      {level = 1, msg_attr = {level = 0, fp = 0x1392f630, queue_name = 0x1392f520 "active", queue_id = 0x1392f248 "0658546584CA", offset = 218, encoding = 0x1390b018 "", sender = 0x1390b018 "", dsn_envid = 0x1390b018 "", dsn_ret = 0, rcpt = {offset = 191, dsn_orcpt = 0x1390b018 "", dsn_notify = 0, orig_addr = 0x1392f5e0 "root@weser.XXX.YY", address = 0x1392f608 "root@weser.XXX.YY", u = {status = 0, queue = 0x0, addr_type = 0x0}}, domain = 0x0, local = 0x0, user = 0x0, extension = 0x0, unmatched = 0x0, owner = 0x0, delivered = 0x0, relay = 0x5d8f4a53 "local", msg_stats = {incoming_arrival = {tv_sec = 1279051621, tv_usec = 25651}, active_arrival = {tv_sec = 1279121939, tv_usec = 42594}, agent_handoff = {tv_sec = 1279121939, tv_usec = 124639}, conn_setup_done = {tv_sec = 0, tv_usec = 0}, deliver_done = {tv_sec = 0, tv_usec = 0}, reuse_count = 0}, exp_type = 0, exp_from = 0x0, request = 0x1392eb88, why = 0x1392f700}, dup_filter = 0x13931360, loop_info = 0x1392fa18, request = 0x1392eb88}, usr_attr={uid = 0, gid = 0, home = 0x0, logname = 0x0, shell = 0x0}) at recipient.c:135
#4  0x138c4af8 in deliver_recipient (state=
      {level = 1, msg_attr = {level = 0, fp = 0x1392f630, queue_name = 0x1392f520 "active", queue_id = 0x1392f248 "0658546584CA", offset = 218, encoding = 0x1390b018 "", sender = 0x1390b018 "", dsn_envid = 0x1390b018 "", dsn_ret = 0, rcpt = {offset = 191, dsn_orcpt = 0x1390b018 "", dsn_notify = 0, orig_addr = 0x1392f5e0 "root@weser.XXX.YY", address = 0x1392f608 "root@weser.XXX.YY", u = {status = 0, queue = 0x0, addr_type = 0x0}}, domain = 0x1393145d "weser.XXX.YY", local = 0x13931458 "root", user = 0x13931480 "root", extension = 0x0, unmatched = 0x0, owner = 0x0, delivered = 0x1392f608 "root@weser.XXX.YY", relay = 0x5d8f4a53 "local", msg_stats = {incoming_arrival = {tv_sec = 1279051621, tv_usec = 25651}, active_arrival = {tv_sec = 1279121939, tv_usec = 42594}, agent_handoff = {tv_sec = 1279121939, tv_usec = 124639}, conn_setup_done = {tv_sec = 0, tv_usec = 0}, deliver_done = {tv_sec = 0, tv_usec = 0}, reuse_count = 0}, exp_type = 0, exp_from = 0x0, request = 0x1392eb88, why = 0x1392f700}, dup_filter = 0x13931360, loop_info = 0x1392fa18, request = 0x1392eb88}, usr_attr=
      {uid = 0, gid = 0, home = 0x0, logname = 0x0, shell = 0x0}) at recipient.c:319
#5  0x138c2246 in local_deliver (rqst=0x1392eb88, service=0x5d8f4a53 "local") at local.c:718
#6  0x138c23c5 in local_service (stream=0x1392daa8, service=0x5d8f4a53 "local", argv=0x5d8f4990) at local.c:756
#7  0x138c7c53 in single_server_wakeup (fd=14) at single_server.c:262
#8  0x138c7e1d in single_server_accept_local (unused_event=1, context=0x6 <Address 0x6 out of bounds>) at single_server.c:304
#9  0x138ed896 in event_loop (delay=-1) at events.c:1086
#10 0x138c8bd6 in single_server_main (argc=3, argv=0x5d8f4984, service=0x138c2351 <local_service>) at single_server.c:732
#11 0x138c2892 in main (argc=3, argv=0x5d8f4984) at local.c:917
share|improve this question

1 Answer 1

up vote 1 down vote accepted

/usr/lib/postfix/local is exiting with signal 11, a segmentation fault. This isn't a postfix problem, instead something with your local machine. In order of likelihood, I would check:

  1. Make sure your compilation options (such as CFLAGS) aren't insane. Scale back to something like -O2, re-compile, and see if it works.
  2. Likewise, any libraries that postfix uses. You can start with any that just postfix uses (since you'd see breakage in other programs using a broken library).
  3. Test your RAM with memtest86+. Leave it running overnight.
  4. Test other hardware.
share|improve this answer
    
CFLAGS are okay, hardware is okay... It's not a random segfault. Why should signal 11 not be a postfix problem? The backtrace I managed to get (after finding out I need to enable suid coredumps), clearly shows the problem within the dict lookup in postfix. –  hurikhan77 Jul 14 '10 at 15:47
    
Apparently the problem is even earlier in the backtrace: I tracked the null pointer back to local.c(718) which passes a usr_attr struct with only 0x0 pointers inside. –  hurikhan77 Jul 14 '10 at 16:09
    
Is Gentoo adding any patches to your postfix, or is it totally stock? I say it's not a postfix problem because (in general) it's well tested software, and 2.6.6 isn't bleeding edge enough to have a problem like "it segfaults when it reads a queue file". Did you run the upgrade script that comes with postfix? –  Bill Weiss Jul 15 '10 at 14:37
    
+1, mystery solved: It's a GCC issue. The passed parameters just before the function call were correct, then within the subroutine, the parameters were set wrong. Adding "-O2" to the CFLAGS (there was no "-Ox" parameter before) solved the problem. –  hurikhan77 Jul 21 '10 at 17:50
    
What did your CFLAGS look like before, and what are they now? –  Bill Weiss Jul 21 '10 at 19:18

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.