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:
- How do I debug that any further?
- 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
/usr/lib/postfix/localis 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:-O2, re-compile, and see if it works.