Monday, December 05, 2011

UC520 and UC540 load 8.2.0 and CUE voicemail message delivery log samples with GMail TLS / SSL failures

The trace commands used on CUE are:

no trace all
clear trace
trace voicemail msgnotif all
trace configapi smtp debug
trace entitymanager NotifDevice all
trace smtp all
show trace buffer tail

Below is a successful voicemail notification to ray.maslanka@gmail.com, using smtp-server.roadrunner.com on port 25.

The WAN port is directly connected to a RoadRunner cable modem with a public IP address.

The UC520 firewall is set to "Low" via the CCA GUI and no command line modifications have been made.

4414 12/05 08:39:51.938 VMSS mnot 0 MessageNotification: Enter insertIntoMsgNotifQueue(): msg recipient: UOnenotif target: UOne
4414 12/05 08:39:51.976 capi smtp 0 SmtpServer: getSysdb(): Attribute: address
2322 12/05 08:39:51.977 capi smtp 0 SmtpSysdbNode: get(): address
4414 12/05 08:39:51.978 VMSS mnot 0 MessageNotification: query: INSERT INTO outcall_email_job VALUES ('UOne', 108, 1323092391940, 15, 0, 'UOne');
4414 12/05 08:39:51.996 VMSS mnot 0 MessageNotification: Notifying sender threads
3021 12/05 08:39:52.005 VMSS mnot 0 EmailSender: Processing job: 1
4414 12/05 08:39:52.006 VMSS mnot 0 MessageNotification: Exit insertIntoMsgNotifQueue(): notifyEmailThread=true, notifyPhoneThread=false
3021 12/05 08:39:52.113 VMSS mnot 0 EmailSender: Got a job: [owner_id=UOne, contact=ray.maslanka@gmail.com, extra_text=null, nextSendTime=1323092391940, device_type=32, device_id=108, retryCount=0, targetId=UOne, attach_vm=true, isUrgent=false, isPrivate=false, ndrreason=0, uid=15, messagetype=1, preferenceA, sender=203, callerName=User Three
3021 12/05 08:39:52.118 VMSS mnot 0 EmailSender: sendEmailNotification: checkSendPreConditions passed
3021 12/05 08:39:52.118 capi smtp 0 SmtpServer: getSysdb(): Attribute: address
2297 12/05 08:39:52.119 capi smtp 0 SmtpSysdbNode: get(): address
3021 12/05 08:39:52.119 capi smtp 0 SmtpServer: getSysdb(): Attribute: port
2307 12/05 08:39:52.120 capi smtp 0 SmtpSysdbNode: get(): port
3021 12/05 08:39:52.121 capi smtp 0 SmtpServer: getSysdb(): Attribute: userid
2322 12/05 08:39:52.122 capi smtp 0 SmtpSysdbNode: get(): userid
3021 12/05 08:39:52.122 capi smtp 0 SmtpServer: getSysdb(): Attribute: password
2318 12/05 08:39:52.123 capi smtp 0 SmtpSysdbNode: get(): password
3021 12/05 08:39:52.123 capi smtp 0 SmtpServer: getSysdb(): Attribute: authRequired
2297 12/05 08:39:52.124 capi smtp 0 SmtpSysdbNode: get(): authRequired
3021 12/05 08:39:52.130 VMSS mnot 0 EmailSender: Begin processing email job, UID=15
3021 12/05 08:39:52.158 VMSS mnot 0 EmailSender: Attachment body part added, UID=15
3021 12/05 08:39:53.476 VMSS mnot 0 EmailSender: Sent successfully, UID=15
3021 12/05 08:39:53.476 VMSS mnot 0 EmailSender: Send email rc=1
3021 12/05 08:39:53.476 VMSS mnot 0 EmailSender: Deleting email job: Device ID=108, UID=15
3021 12/05 08:39:53.495 VMSS mnot 0 EmailSender: calculateWaitTime(): current time: 1323092393492, job time: 0
3021 12/05 08:39:53.495 VMSS mnot 0 EmailSender: Wait time=0

Below is a failed voicemail notification to ray.maslanka@gmail.com, using smtp.gmail.com on port 587.

The CUE is configured to require SMTP authentication, and again using ray.maslanka@gmail.com.

Note the errors related specifically to TLS, a logical result of using port 587.

4414 12/05 09:11:59.431 VMSS mnot 0 MessageNotification: Enter insertIntoMsgNotifQueue(): msg recipient: UOnenotif target: UOne
4414 12/05 09:11:59.469 capi smtp 0 SmtpServer: getSysdb(): Attribute: address
2297 12/05 09:11:59.470 capi smtp 0 SmtpSysdbNode: get(): address
4414 12/05 09:11:59.470 VMSS mnot 0 MessageNotification: query: INSERT INTO outcall_email_job VALUES ('UOne', 108, 1323094319432, 17, 0, 'UOne');
4414 12/05 09:11:59.493 VMSS mnot 0 MessageNotification: Notifying sender threads
3021 12/05 09:11:59.502 VMSS mnot 0 EmailSender: Processing job: 1
4414 12/05 09:11:59.512 VMSS mnot 0 MessageNotification: Exit insertIntoMsgNotifQueue(): notifyEmailThread=true, notifyPhoneThread=false
3021 12/05 09:11:59.602 VMSS mnot 0 EmailSender: Got a job: [owner_id=UOne, contact=ray.maslanka@gmail.com, extra_text=null, nextSendTime=1323094319432, device_type=32, device_id=108, retryCount=0, targetId=UOne, attach_vm=true, isUrgent=false, isPrivate=false, ndrreason=0, uid=17, messagetype=1, preferenceA, sender=203, callerName=User Three
3021 12/05 09:11:59.606 VMSS mnot 0 EmailSender: sendEmailNotification: checkSendPreConditions passed
3021 12/05 09:11:59.606 capi smtp 0 SmtpServer: getSysdb(): Attribute: address
2297 12/05 09:11:59.607 capi smtp 0 SmtpSysdbNode: get(): address
3021 12/05 09:11:59.607 capi smtp 0 SmtpServer: getSysdb(): Attribute: port
2307 12/05 09:11:59.608 capi smtp 0 SmtpSysdbNode: get(): port
3021 12/05 09:11:59.609 capi smtp 0 SmtpServer: getSysdb(): Attribute: userid
2322 12/05 09:11:59.610 capi smtp 0 SmtpSysdbNode: get(): userid
3021 12/05 09:11:59.610 capi smtp 0 SmtpServer: getSysdb(): Attribute: password
2318 12/05 09:11:59.611 capi smtp 0 SmtpSysdbNode: get(): password
3021 12/05 09:11:59.612 capi smtp 0 SmtpServer: getSysdb(): Attribute: authRequired
2297 12/05 09:11:59.613 capi smtp 0 SmtpSysdbNode: get(): authRequired
3021 12/05 09:11:59.622 VMSS mnot 0 EmailSender: Begin processing email job, UID=17
3021 12/05 09:11:59.654 VMSS mnot 0 EmailSender: Attachment body part added, UID=17
3021 12/05 09:12:00.339 VMSS mnot 0 EmailSender: Error sending email, UID= 17 :javax.mail.SendFailedException: Sending failed;
nested exception is:
class javax.mail.MessagingException: 530 5.7.0 Must issue a STARTTLS command first. v18sm77175183ibh.4
3021 12/05 09:12:00.339 VMSS mnot 0 EmailSender: Send email rc=2
3021 12/05 09:12:00.339 VMSS mnot 0 EmailSender: Deleting email job: Device ID=108, UID=17
3021 12/05 09:12:00.362 VMSS mnot 0 EmailSender: calculateWaitTime(): current time: 1323094320360, job time: 0
3021 12/05 09:12:00.362 VMSS mnot 0 EmailSender: Wait time=0

Below is a failed voicemail notification to ray.maslanka@gmail.com, using smtp.gmail.com on port 465.

The CUE is configured to require SMTP authentication, and again using ray.maslanka@gmail.com.

Note the errors related "Exception reading response", not a very descriptive error but related to the 465 / SSL authentication.

4414 12/05 09:18:08.994 VMSS mnot 0 MessageNotification: Enter insertIntoMsgNotifQueue(): msg recipient: UOnenotif target: UOne
4414 12/05 09:18:09.083 capi smtp 0 SmtpServer: getSysdb(): Attribute: address
2297 12/05 09:18:09.088 capi smtp 0 SmtpSysdbNode: get(): address
4414 12/05 09:18:09.088 VMSS mnot 0 MessageNotification: query: INSERT INTO outcall_email_job VALUES ('UOne', 108, 1323094689041, 18, 0, 'UOne');
4414 12/05 09:18:09.120 VMSS mnot 0 MessageNotification: Notifying sender threads
4414 12/05 09:18:09.120 VMSS mnot 0 MessageNotification: Exit insertIntoMsgNotifQueue(): notifyEmailThread=true, notifyPhoneThread=false
3021 12/05 09:18:09.194 VMSS mnot 0 EmailSender: Processing job: 1
3021 12/05 09:18:09.212 VMSS mnot 0 EmailSender: Got a job: [owner_id=UOne, contact=ray.maslanka@gmail.com, extra_text=null, nextSendTime=1323094689041, device_type=32, device_id=108, retryCount=0, targetId=UOne, attach_vm=true, isUrgent=false, isPrivate=false, ndrreason=0, uid=18, messagetype=1, preferenceA, sender=203, callerName=User Three
3021 12/05 09:18:09.217 VMSS mnot 0 EmailSender: sendEmailNotification: checkSendPreConditions passed
3021 12/05 09:18:09.217 capi smtp 0 SmtpServer: getSysdb(): Attribute: address
2322 12/05 09:18:09.218 capi smtp 0 SmtpSysdbNode: get(): address
3021 12/05 09:18:09.218 capi smtp 0 SmtpServer: getSysdb(): Attribute: port
2297 12/05 09:18:09.220 capi smtp 0 SmtpSysdbNode: get(): port
3021 12/05 09:18:09.220 capi smtp 0 SmtpServer: getSysdb(): Attribute: userid
2318 12/05 09:18:09.221 capi smtp 0 SmtpSysdbNode: get(): userid
3021 12/05 09:18:09.222 capi smtp 0 SmtpServer: getSysdb(): Attribute: password
2307 12/05 09:18:09.223 capi smtp 0 SmtpSysdbNode: get(): password
3021 12/05 09:18:09.223 capi smtp 0 SmtpServer: getSysdb(): Attribute: authRequired
2322 12/05 09:18:09.224 capi smtp 0 SmtpSysdbNode: get(): authRequired
3021 12/05 09:18:09.230 VMSS mnot 0 EmailSender: Begin processing email job, UID=18
3021 12/05 09:18:09.261 VMSS mnot 0 EmailSender: Attachment body part added, UID=18
3021 12/05 09:20:09.532 VMSS mnot 0 EmailSender: Error sending email, UID= 18 :javax.mail.SendFailedException: Sending failed;
nested exception is:
class javax.mail.MessagingException: Exception reading response;
nested exception is:
java.net.SocketTimeoutException: Read timed out
3021 12/05 09:20:09.532 VMSS mnot 0 EmailSender: Send email rc=2
3021 12/05 09:20:09.532 VMSS mnot 0 EmailSender: Deleting email job: Device ID=108, UID=18
3021 12/05 09:20:09.560 VMSS mnot 0 EmailSender: calculateWaitTime(): current time: 1323094809558, job time: 0
3021 12/05 09:20:09.560 VMSS mnot 0 EmailSender: Wait time=0

Below is the software version information related to the UC520 CUE.

Unfortunately the CUE release notes at http://www.cisco.com/en/US/docs/voice_ip_comm/unity_exp/rel8_6/rel_notes/rel_notes86.html#wp364157 indicate SMTP over TLS and SSL to GMail, etc is supported first in version 8.6.

show software versions


Cisco Unity Express version (8.0.6)


Technical Support: http://www.cisco.com/techsupport Copyright (c) 1986-2010 by Cisco Systems, Inc.


Components:
- TimeCardView version 8.0.6
- PhoneConnect version 7.0.0
- CUE Voicemail Language Support version 8.0.6
- Monitor Agent version 7.0.0
- Madrox Multi-app Support version 8.0.6

There are multiple conversations on the Internet re: using GMail's SMTP server(s) as voicemail message delivery servers, but none with detailed resolutions.

A request for feedback in the Cisco supportforums re: the software version and related errors can be found here, with no replies at the time of this writing: https://supportforums.cisco.com/message/3503487#3503487

My strategy at this time will be to assume voicemail message delivery from UC5XX with software load 8.2.0 is not possible via GMail's SMTP servers.