Include decoded (from base64) negotiation for SASL.

[pprindeville]

Text is prefixed with (decoded) and appears before on sends and after
on receives.

[pprindeville]

Somewhat tangentially related to this: I needed to add tracing to understand some behavior I was seeing in git-send-email.perl (from the git repo). It fails when using DIGEST-MD5 authentication when talking to a Sendmail 8.15.2 server. I don't see this behavior with any other MUA's.

A log of the failure is here:

$ USER=philipp ./test.pl 
Net::SMTP>>> Net::SMTP(3.08)
Net::SMTP>>>   Net::Cmd(3.08)
Net::SMTP>>>     Exporter(5.72)
Net::SMTP>>>   IO::Socket::IP(0.37)
Net::SMTP>>>     IO::Socket(1.38)
Net::SMTP>>>       IO::Handle(1.35)
Net::SMTP=GLOB(0x1c60500)<<< 220 mail.redfish-solutions.com ESMTP Sendmail 8.15.2/8.15.2; Mon, 13 Jun 2016 11:29:06 -0600
Net::SMTP=GLOB(0x1c60500)>>> EHLO localhost.localdomain
Net::SMTP=GLOB(0x1c60500)<<< 250-mail.redfish-solutions.com Hello [192.168.1.76], pleased to meet you
Net::SMTP=GLOB(0x1c60500)<<< 250-ENHANCEDSTATUSCODES
Net::SMTP=GLOB(0x1c60500)<<< 250-PIPELINING
Net::SMTP=GLOB(0x1c60500)<<< 250-8BITMIME
Net::SMTP=GLOB(0x1c60500)<<< 250-SIZE
Net::SMTP=GLOB(0x1c60500)<<< 250-DSN
Net::SMTP=GLOB(0x1c60500)<<< 250-AUTH DIGEST-MD5 CRAM-MD5
Net::SMTP=GLOB(0x1c60500)<<< 250-STARTTLS
Net::SMTP=GLOB(0x1c60500)<<< 250-DELIVERBY
Net::SMTP=GLOB(0x1c60500)<<< 250 HELP
connected to mail.redfish-solutions.com
banner was 'mail.redfish-solutions.com ESMTP Sendmail 8.15.2/8.15.2; Mon, 13 Jun 2016 11:29:06 -0600'
want: DIGEST-MD5
got: DIGEST-MD5 CRAM-MD5
Net::SMTP=GLOB(0x1c60500)>>> AUTH DIGEST-MD5
Net::SMTP=GLOB(0x1c60500)<<< 334 bm9uY2U9IlRmOCsyY2pwNWx2cnE4RTZCcTZCTExJSXN4ZEtjMUUydlVvVnJmeVZWNFk9IixyZWFsbT0ibWFpbCIscW9wPSJhdXRoLGF1dGgtaW50LGF1dGgtY29uZiIsY2lwaGVyPSJyYzQtNDAscmM0LTU2LHJjNCxkZXMsM2RlcyIsbWF4YnVmPTgxOTIsY2hhcnNldD11dGYtOCxhbGdvcml0aG09bWQ1LXNlc3M=
Net::SMTP=GLOB(0x1c60500)<<< (decoded) nonce="Tf8+2cjp5lvrq8E6Bq6BLLIIsxdKc1E2vUoVrfyVV4Y=",realm="mail",qop="auth,auth-int,auth-conf",cipher="rc4-40,rc4-56,rc4,des,3des",maxbuf=8192,charset=utf-8,algorithm=md5-sess
Net::SMTP=GLOB(0x1c60500)>>> (decoded) authzid="philipp",charset=utf-8,cnonce="fa863102174839f0d56d2386a6b9e71e",digest-uri="smtp/192.168.1.3",nc=00000001,nonce="Tf8+2cjp5lvrq8E6Bq6BLLIIsxdKc1E2vUoVrfyVV4Y=",qop=auth-int,realm="mail",response=d14a2e8dbb152207874fe4d0315ce7fc,username="philipp"
Net::SMTP=GLOB(0x1c60500)>>> YXV0aHppZD0icGhpbGlwcCIsY2hhcnNldD11dGYtOCxjbm9uY2U9ImZhODYzMTAyMTc0ODM5ZjBkNTZkMjM4NmE2YjllNzFlIixkaWdlc3QtdXJpPSJzbXRwLzE5Mi4xNjguMS4zIixuYz0wMDAwMDAwMSxub25jZT0iVGY4KzJjanA1bHZycThFNkJxNkJMTElJc3hkS2MxRTJ2VW9WcmZ5VlY0WT0iLHFvcD1hdXRoLWludCxyZWFsbT0ibWFpbCIscmVzcG9uc2U9ZDE0YTJlOGRiYjE1MjIwNzg3NGZlNGQwMzE1Y2U3ZmMsdXNlcm5hbWU9InBoaWxpcHAi
Net::SMTP=GLOB(0x1c60500)<<< 334 cnNwYXV0aD1hZjI3NTNiMmMyMDYwYTNjNWU4MDdkOGZjYjIxOWUwMg==
Net::SMTP=GLOB(0x1c60500)<<< (decoded) rspauth=af2753b2c2060a3c5e807d8fcb219e02
Net::SMTP=GLOB(0x1c60500)>>> (decoded) 
Net::SMTP=GLOB(0x1c60500)>>> 
Net::SMTP=GLOB(0x1c60500)<<< 235 2.0.0 OK Authenticated
Net::SMTP=GLOB(0x1c60500)>>> MAIL FROM:<philipp>
Net::SMTP: Net::Cmd::getline(): unexpected EOF on command channel:  at ./test.pl line 51.
couldn't do MAIL FROM at ./test.pl line 51.
$ 

and the logs from the server side are:

Jun 13 11:29:06 mail mimedefang.pl[4201]: relay: [192.168.1.76] (192.168.1.76:59458 => 192.168.1.3:587)
Jun 13 11:29:06 mail mimedefang.pl[4201]: helo: [192.168.1.76] (192.168.1.76:59458) said "helo localhost.localdomain"
Jun 13 11:29:06 mail sendmail[5412]: AUTH=server, relay=[192.168.1.76], authid=philipp, mech=DIGEST-MD5, bits=1
Jun 13 11:29:06 mail sendmail[5412]: AUTH: sasl_decode error=-1
Jun 13 11:29:06 mail sendmail[5412]: u5DHT6MF005412: [192.168.1.76] did not issue MAIL/EXPN/VRFY/ETRN during connection to MSA

and attaching the script I used as well.

test.pl

I suspect this is a bug in Authen::SASL.