NetBSD Problem Report #49349

From fair@secondary.clock.org  Fri Oct 31 21:58:59 2014
Return-Path: <fair@secondary.clock.org>
Received: from mail.netbsd.org (mail.netbsd.org [149.20.53.66])
	(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
	(Client CN "mail.netbsd.org", Issuer "Postmaster NetBSD.org" (verified OK))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 6C880A66A9
	for <gnats-bugs@gnats.NetBSD.org>; Fri, 31 Oct 2014 21:58:59 +0000 (UTC)
Message-Id: <20141031201322.C8CC62F0DB@secondary.clock.org>
Date: Fri, 31 Oct 2014 20:13:22 +0000 (UTC)
From: fair@netbsd.org
Reply-To: fair@netbsd.org
To: gnats-bugs@gnats.NetBSD.org
Subject: OpenSSL unaligned access during DATA decryption in Postfix smtpd
X-Send-Pr-Version: 3.95

>Number:         49349
>Category:       lib
>Synopsis:       OpenSSL unaligned access during DATA decryption in Postfix smtpd
>Confidential:   no
>Severity:       critical
>Priority:       high
>Responsible:    lib-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Fri Oct 31 22:00:00 +0000 2014
>Last-Modified:  Sat Nov 01 00:25:00 +0000 2014
>Originator:     Erik E. Fair
>Release:        NetBSD 6.1_STABLE (daily build 201410291830Z of tag netbsd-6)
>Organization:
The NetBSD Project
>Environment:
System: NetBSD secondary.clock.org 6.1_STABLE NetBSD 6.1_STABLE (GENERIC.UP) sparc64
Architecture: sparc64
Machine: sparc64

total memory = 1024 MB
avail memory = 991 MB
mainbus0 (root): SUNW,UltraAX-i2 (Sun Fire V100): hostid XXXXXXXX
cpu0 at mainbus0: SUNW,UltraSPARC-IIe @ 500 MHz, UPA id 0
cpu0: 16K instruction (32 b/l), 16K data (32 b/l), 256K external (64 b/l)

Postfix 2.8.1.7

% openssl version
OpenSSL 1.0.1j 15 Oct 2014

% ldd /usr/libexec/postfix/smtpd 
/usr/libexec/postfix/smtpd:
        -lssl.10 => /usr/lib/libssl.so.10
        -lcrypto.8 => /usr/lib/libcrypto.so.8
        -lcrypt.1 => /lib/libcrypt.so.1
        -lc.12 => /usr/lib/libc.so.12
        -lsaslc.0 => /usr/lib/libsaslc.so.0
        -lgssapi.10 => /usr/lib/libgssapi.so.10
        -lkrb5.26 => /usr/lib/libkrb5.so.26
        -lhx509.5 => /usr/lib/libhx509.so.5
        -lasn1.9 => /usr/lib/libasn1.so.9
        -lcom_err.7 => /usr/lib/libcom_err.so.7
        -lroken.19 => /usr/lib/libroken.so.19
        -lutil.7 => /usr/lib/libutil.so.7
        -lwind.0 => /usr/lib/libwind.so.0
        -lheimbase.1 => /usr/lib/libheimbase.so.1
        -lheimntlm.4 => /usr/lib/libheimntlm.so.4
        -lsqlite3.1 => /usr/lib/libsqlite3.so.1
        -lldap.4 => /usr/lib/libldap.so.4
        -llber.3 => /usr/lib/liblber.so.3

>Description:
	God bless Microsoft. E-mail from their former Hotmail facility triggers
	an OpenSSL bug in the data decryption routines. Because the signal is
	SIGBUS, I suspect an unaligned data access, which UltraSPARC CPUs
	fault on, rather than accessing slowly. Turning off encryption makes
	the problem go away.

	Summary of log to follow: hotmail contacts smtpd, negotiates TLS, does
	EHLO, MAIL FROM:, RCPT TO:, and then DATA (all getting OK response),
	and then smtpd dies from SIGBUS (signal 10) during the transfer of the E-mail.
	Long, unrelated sections of Postfix debug output elided at each "[...]"

Oct 31 18:26:21 secondary postfix/smtpd[6984]: connect from bay004-omc4s13.hotmail.com[65.54.190.215]
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 220 secondary.clock.org ESMTP Postfix
Oct 31 18:26:21 secondary postfix/smtpd[6984]: < bay004-omc4s13.hotmail.com[65.54.190.215]: EHLO BAY004-OMC4S13.hotmail.com
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-secondary.clock.org
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-PIPELINING
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-SIZE 15000000
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-VRFY
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-ETRN
Oct 31 18:26:21 secondary postfix/smtpd[6984]: match_list_match: bay004-omc4s13.hotmail.com: no match
Oct 31 18:26:21 secondary postfix/smtpd[6984]: match_list_match: 65.54.190.215: no match
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-STARTTLS
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-ENHANCEDSTATUSCODES
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-8BITMIME
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250 DSN
Oct 31 18:26:21 secondary postfix/smtpd[6984]: < bay004-omc4s13.hotmail.com[65.54.190.215]: STARTTLS
Oct 31 18:26:21 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 220 2.0.0 Ready to start TLS
Oct 31 18:26:21 secondary postfix/smtpd[6984]: setting up TLS connection from bay004-omc4s13.hotmail.com[65.54.190.215]
[...]
Oct 31 18:26:22 secondary postfix/smtpd[6984]: Anonymous TLS connection established from bay004-omc4s13.hotmail.com[65.54.190.215]: TLSv1.2 with cipher ECDHE-RSA-AES256-SHA384 (256/256 bits)
Oct 31 18:26:22 secondary postfix/smtpd[6984]: < bay004-omc4s13.hotmail.com[65.54.190.215]: EHLO BAY004-OMC4S13.hotmail.com
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-secondary.clock.org
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-PIPELINING
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-SIZE 15000000
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-VRFY
Oct 31 18:26:22 secondary postfix/smtpd[6984]: match_list_match: bay004-omc4s13.hotmail.com: no match
Oct 31 18:26:22 secondary postfix/smtpd[6984]: match_list_match: 65.54.190.215: no match
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-ETRN
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-ENHANCEDSTATUSCODES
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250-8BITMIME
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250 DSN
Oct 31 18:26:22 secondary postfix/smtpd[6984]: < bay004-omc4s13.hotmail.com[65.54.190.215]: MAIL FROM:<account-security-noreply@account.microsoft.com> SIZE=3888
[...]
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250 2.1.0 Ok
Oct 31 18:26:22 secondary postfix/smtpd[6984]: < bay004-omc4s13.hotmail.com[65.54.190.215]: RCPT TO:<nunyabeeswax@use.net>
[...]
Oct 31 18:26:22 secondary postfix/smtpd[6984]: 9F78B2F0DA: client=bay004-omc4s13.hotmail.com[65.54.190.215]
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 250 2.1.5 Ok
Oct 31 18:26:22 secondary postfix/smtpd[6984]: < bay004-omc4s13.hotmail.com[65.54.190.215]: DATA
Oct 31 18:26:22 secondary postfix/smtpd[6984]: >>> START Data command RESTRICTIONS <<<
Oct 31 18:26:22 secondary postfix/smtpd[6984]: generic_checks: name=reject_unauth_pipelining
Oct 31 18:26:22 secondary postfix/smtpd[6984]: reject_unauth_pipelining: DATA
Oct 31 18:26:22 secondary postfix/smtpd[6984]: generic_checks: name=reject_unauth_pipelining status=0
Oct 31 18:26:22 secondary postfix/smtpd[6984]: generic_checks: name=permit
Oct 31 18:26:22 secondary postfix/smtpd[6984]: generic_checks: name=permit status=1
Oct 31 18:26:22 secondary postfix/smtpd[6984]: > bay004-omc4s13.hotmail.com[65.54.190.215]: 354 End data with <CR><LF>.<CR><LF>
Oct 31 18:26:22 secondary postfix/master[555]: warning: process /usr/libexec/postfix/smtpd pid 6984 killed by signal 10
Oct 31 18:26:22 secondary /netbsd: pid 6984 (smtpd), uid 12: exited on signal 10 (core not dumped, err = 1)

>How-To-Repeat:
	Trigger an E-mail from Microsoft/Skype account security to a user on
	a NetBSD/sparc64 host running Postfix with OpenSSL and opportunistic
	encryption enabled. To date, I am unaware of any other peer which
	triggers this problem - it seems to be something different that they're
	doing.

>Fix:
	I worked around the problem by turning off opportunistic
	SMTP session encryption globally - hotmail subsequently
	successfully transfered the E-mail without session encryption.
	This observed behavior supports my theory that the problem is in
	OpenSSL, rather than in Postfix.

	Turning off encryption is an unacceptable long-term work-around.
	This code bug must be found and squashed.

>Audit-Trail:
From: christos@zoulas.com (Christos Zoulas)
To: gnats-bugs@NetBSD.org, lib-bug-people@netbsd.org, 
	gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc: 
Subject: Re: lib/49349: OpenSSL unaligned access during DATA decryption in Postfix smtpd
Date: Fri, 31 Oct 2014 18:26:35 -0400

 On Oct 31, 10:00pm, fair@netbsd.org (fair@netbsd.org) wrote:
 -- Subject: lib/49349: OpenSSL unaligned access during DATA decryption in Pos

 Can you get a core file?

 christos

From: "Erik E. Fair" <fair@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc: lib-bug-people@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: lib/49349: OpenSSL unaligned access during DATA decryption in Postfix smtpd
Date: Fri, 31 Oct 2014 17:20:34 -0700

 Apparently not:

 # sysctl -w kern.coredump.setid.dump=1
 sysctl: kern.coredump.setid.dump: Operation not permitted

 Or is that a securelevel thing? (sigh) I'll stick that in /etc/sysctl.conf
 and reboot.

 I'll also ask the user to trigger another such E-mail from Microsoft; my
 work-around permitted the errant messages to be delivered, so there's nothing
 triggering the bug right this second.

 But the necessary code review should begin anon. Or perhaps it could be fed
 to a static analyzer? You already know which cipher to look at from the log
 messages I included in the intial PR.

 	Erik <fair@netbsd.org>

>Unformatted:

Home	PR Database Search