0

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=<[email protected]>, orig_to=<[email protected]>, 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 "[email protected]", address = 0x1392f608 "[email protected]", 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 "[email protected]", address = 0x1392f608 "[email protected]", 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 "[email protected]", address = 0x1392f608 "[email protected]", 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 "[email protected]", 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

1 Answer 1

1

/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.
5
  • 1
    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, 2010 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, 2010 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, 2010 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, 2010 at 17:50
  • What did your CFLAGS look like before, and what are they now?
    – Bill Weiss
    Jul 21, 2010 at 19:18

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .