UC560 - Voicemail Notification (Email) Not Working

[dhyland]

Email notifications had been working but no longer work.  In CCA -> Telephony - > Users/Extensions -> Voicemail: I have enable voicemail notification checked and enable email notification checked.  I have email address, SMTP server, SMTP port and authentication.  I'm not sure exactly where to begin troubleshooting as nothing should have changed...

Thanks in advance!

[dhyland]

I can telnet to the mail server on port 25 without issues so the mail server is up and reachable.

[johschaf]

Hello,

Can you ping the voicemail system from the mail server? The default voicemail IP is 10.1.10.1. If you can, you will need to get command line access to the UC, setup the following debugs, and recreate the issue:

1. Get command line access to the UC and access enable mode

2. Clear out any old CUE session: ser int 0/0 sess cl

3. Session into CUE: ser int 0/0 sess

4. Put your credentials in to access CUE

5. Enter the following debugs:

no trace all

clear trace

trace voicemail msgnotif all

trace configapi smtp debug

trace entitymanager NotifDevice all

trace smtp all

show trace buffer tail

6. Recreate the issue

7. Copy the debug output here

8. Hit ctrl+c to end the debug

9. Clear the trace:

no trace all

clear trace

Thanks,

-john

[dhyland]

Thanks for your reply, John.  The debug info is as follows (with identifying information removed):

11708 08/26 16:31:14.858 VMSS mnot 0 MessageNotification: Enter insertIntoMsgNotifQueue(): msg recipient: TClemnotif target: TClem

11708 08/26 16:31:14.871 capi smtp 0 SmtpServer: getSysdb(): Attribute: address

2288 08/26 16:31:14.872 capi smtp 0 SmtpSysdbNode: get(): address

11708 08/26 16:31:14.872 VMSS mnot 0 MessageNotification: query: INSERT INTO outcall_email_job VALUES ('TClem', 12, 1377574858, 965, 0, 'TClem');

11708 08/26 16:31:15.001 VMSS mnot 0 MessageNotification: Notifying sender threads

11708 08/26 16:31:15.001 VMSS mnot 0 MessageNotification: Exit insertIntoMsgNotifQueue(): notifyEmailThread=true, notifyPhoneThread=false

2846 08/26 16:31:15.009 VMSS mnot 0 EmailSender: Processing job: 1

2846 08/26 16:31:15.012 VMSS mnot 0 EmailSender: Got a job: [owner_id=TClem, contact=tclem@mailservernamehere.com, extra_text=null, nextSendTime=1377552674858, device_type=32, device_id=12, retryCount=0, targetId=TClem, attach_vm=true, isUrgent=false, isPrivate=false, isSecure=false, ndrreason=0, uid=965, messagetype=1, preferenceA, sender=6182443000, callerName=null

2846 08/26 16:31:15.018 VMSS mnot 0 EmailSender: sendEmailNotification: checkSendPreConditions passed

2846 08/26 16:31:15.018 capi smtp 0 SmtpServer: getSysdb(): Attribute: address

2305 08/26 16:31:15.018 capi smtp 0 SmtpSysdbNode: get(): address

2846 08/26 16:31:15.019 capi smtp 0 SmtpServer: getSysdb(): Attribute: port

2287 08/26 16:31:15.019 capi smtp 0 SmtpSysdbNode: get(): port

2846 08/26 16:31:15.019 capi smtp 0 SmtpServer: getSysdb(): Attribute: userid

2306 08/26 16:31:15.019 capi smtp 0 SmtpSysdbNode: get(): userid

2846 08/26 16:31:15.019 capi smtp 0 SmtpServer: getSysdb(): Attribute: password

2288 08/26 16:31:15.020 capi smtp 0 SmtpSysdbNode: get(): password

2846 08/26 16:31:15.020 capi smtp 0 SmtpServer: getSysdb(): Attribute: authRequired

2305 08/26 16:31:15.020 capi smtp 0 SmtpSysdbNode: get(): authRequired

2846 08/26 16:31:15.020 capi smtp 0 SmtpServer: getSysdb(): Attribute: securityMode

2287 08/26 16:31:15.020 capi smtp 0 SmtpSysdbNode: get(): securityMode

2846 08/26 16:31:15.020 VMSS mnot 0 EmailSender: Begin processing email job, UID=965

2846 08/26 16:31:15.021 capi smtp 0 SmtpServer: getSysdb(): Attribute: securityMode

2306 08/26 16:31:15.021 capi smtp 0 SmtpSysdbNode: get(): securityMode

2846 08/26 16:31:15.021 capi smtp 0 SmtpServer: getSysdb(): Attribute: securityMode

2288 08/26 16:31:15.021 capi smtp 0 SmtpSysdbNode: get(): securityMode

2846 08/26 16:31:15.035 VMSS mnot 0 EmailSender: Attachment body part added, UID=965

2846 08/26 16:31:15.121 VMSS mnot 0 DEBUG: getProvider() returning javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Sun Microsystems, Inc]

DEBUG SMTP: useEhlo true, useAuth true

DEBUG SMTP: trying to connect to host "mail.mailservernamehere.com", port 25, isSSL false

Send failed, UID=965

2846 08/26 16:31:15.122 VMSS mnot 0 EmailSender: Error sending email, UID= 965 :javax.mail.MessagingException: Could not connect to SMTP host: mail.mailservernamehere.com, port: 25;

  nested exception is:

        javax.net.ssl.SSLException: Unrecognized SSL message, plaintext connection?

2846 08/26 16:31:15.122 VMSS mnot 0 EmailSender: Send email rc=2

2846 08/26 16:31:15.122 VMSS mnot 0 EmailSender: Deleting email job: Device ID=12, UID=965

2846 08/26 16:31:15.147 VMSS mnot 0 EmailSender: calculateWaitTime(): current time: 1377552675146, job time: 0

2846 08/26 16:31:15.147 VMSS mnot 0 EmailSender: Wait time=0

[johschaf]

Hello,

Save the configuratio, reload CUE, and test again. The UC is trying to do SSL, but it should not being doing that.

Thanks,

-john

[dhyland]

Thanks, John.  I rebooted the UC last night and have tried another voicemail.  Below is the debug info:

11708 08/27 13:10:36.070 VMSS mnot 0 MessageNotification: Enter insertIntoMsgNotifQueue(): msg recipient: TClemnotif target: TClem

11708 08/27 13:10:36.094 capi smtp 0 SmtpServer: getSysdb(): Attribute: address

2306 08/27 13:10:36.094 capi smtp 0 SmtpSysdbNode: get(): address

11708 08/27 13:10:36.094 VMSS mnot 0 MessageNotification: query: INSERT INTO outcall_email_job VALUES ('TClem', 12, 1376203601, 967, 0, 'TClem');

11708 08/27 13:10:36.121 VMSS mnot 0 MessageNotification: Notifying sender threads

11708 08/27 13:10:36.121 VMSS mnot 0 MessageNotification: Exit insertIntoMsgNotifQueue(): notifyEmailThread=true, notifyPhoneThread=false

2846 08/27 13:10:36.137 VMSS mnot 0 EmailSender: Processing job: 1

2846 08/27 13:10:36.141 VMSS mnot 0 EmailSender: Got a job: [owner_id=TClem, contact=tclem@domainnamehere.com, extra_text=null, nextSendTime=137762736071, device_type=32, device_id=12, retryCount=0, targetId=TClem, attach_vm=true, isUrgent=false, isPrivate=false, isSecure=false, ndrreason=0, uid=967, messagetype=1, preferenceA, sender=5555553138, callerName=null

2846 08/27 13:10:36.149 VMSS mnot 0 EmailSender: sendEmailNotification: checkSendPreConditions passed

2846 08/27 13:10:36.149 capi smtp 0 SmtpServer: getSysdb(): Attribute: address

2287 08/27 13:10:36.149 capi smtp 0 SmtpSysdbNode: get(): address

2846 08/27 13:10:36.149 capi smtp 0 SmtpServer: getSysdb(): Attribute: port

2288 08/27 13:10:36.150 capi smtp 0 SmtpSysdbNode: get(): port

2846 08/27 13:10:36.150 capi smtp 0 SmtpServer: getSysdb(): Attribute: userid

2305 08/27 13:10:36.150 capi smtp 0 SmtpSysdbNode: get(): userid

2846 08/27 13:10:36.150 capi smtp 0 SmtpServer: getSysdb(): Attribute: password

2306 08/27 13:10:36.150 capi smtp 0 SmtpSysdbNode: get(): password

2846 08/27 13:10:36.151 capi smtp 0 SmtpServer: getSysdb(): Attribute: authRequired

2287 08/27 13:10:36.151 capi smtp 0 SmtpSysdbNode: get(): authRequired

2846 08/27 13:10:36.151 capi smtp 0 SmtpServer: getSysdb(): Attribute: securityMode

2288 08/27 13:10:36.151 capi smtp 0 SmtpSysdbNode: get(): securityMode

2846 08/27 13:10:36.151 VMSS mnot 0 EmailSender: Begin processing email job, UID =967

2846 08/27 13:10:36.151 capi smtp 0 SmtpServer: getSysdb(): Attribute: securityMode

2305 08/27 13:10:36.151 capi smtp 0 SmtpSysdbNode: get(): securityMode

2846 08/27 13:10:36.152 capi smtp 0 SmtpServer: getSysdb(): Attribute: securityMode

2306 08/27 13:10:36.152 capi smtp 0 SmtpSysdbNode: get(): securityMode

2846 08/27 13:10:36.162 VMSS mnot 0 EmailSender: Attachment body part added, UID=967

2846 08/27 13:10:36.246 VMSS mnot 0 DEBUG: getProvider() returning javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Sun Microsystems, Inc]

DEBUG SMTP: useEhlo true, useAuth true

DEBUG SMTP: trying to connect to host "mail.domainnamehere.com", port 25, isSSL false

Send failed, UID=967

2846 08/27 13:10:36.249 VMSS mnot 0 EmailSender: Error sending email, UID= 967 :javax.mail.MessagingException: Could not connect to SMTP host: mail.domainnamehere.com, port: 25;

  nested exception is:

        javax.net.ssl.SSLException: Unrecognized SSL message, plaintext connection?

2846 08/27 13:10:36.249 VMSS mnot 0 EmailSender: Send email rc=2

2846 08/27 13:10:36.249 VMSS mnot 0 EmailSender: Deleting email job: Device ID=12, UID=967

2846 08/27 13:10:36.274 VMSS mnot 0 EmailSender: calculateWaitTime(): current time: 1377627036273, job time: 0

2846 08/27 13:10:36.274 VMSS mnot 0 EmailSender: Wait time=0

[johschaf · Accepted solution]

Hello,

I've seen this before, and the fix was to reload CUE.

Reload CUE from the CLI by doing the following:

ser int 0/0 reload

Thanks,

-john

[dhyland]

This, ultimately, fixed the problem.  After reloading CUE the next debugs showed a blacklisting issue on the firewall in front of the mail server which was a quick fix.

Thank you greatly, John!  You've helped with a very annoying issue.  Guess it goes back to "have you tried turning it off and on again".