Voicemail Pro slow to send emails

[unspecialeffect]

I'll preface my question by stating I am not an Avaya Expert at all. I'm trying to fix problems that our Avaya Partner cannot.

I had an Avaya partner recently upgrade our phone system from IP406 to IP500 and Voicemail Pro 9.0. We did not change any other aspect of our network or systems. The Avaya IP Office and Voicemail Pro system both run off of a single virtual machine running windows server 2008 SP2.

We record all outgoing phone calls from our sales staff, the recorded calls are then forwarded to the sales person's email so that they can go over the phone call. The call limit is set (in voicemail pro) to 600 seconds (10 minutes) The SMTP server is Exchange 2010, on the same subnet and has a send/receive limit of 25MB. No authentication is required from the subnet. This all worked fine prior to our upgrade. Sales people received emails within seconds of the call, no matter the size of the attached message.

Now messages can take up to an hour, no matter how long the message is. I have turned on SMTP logging on Voicemail pro and I see the following strange behavior:

1. WAV files are populated in the user mailbox even after being received via Email (WAVs should be forwarded, not copied to email)
2. Status.txt files show a reference to all WAV files in the folder with either a +N or +F (not sure what this is, but I'm thinking it is +N = new and +F = Forwarded?
3. Voicemail pro Logs folder shows 2 log files growing (slowly) at the same time. Files continue to grow until they reach 18,496KB. Looking into the log file, the end shows :

CSMTPConnection::SendBodyPart: Failed in call to send body parts body 10054 [0x2746] (An existing connection was forcibly closed by the remote host.) calling send from CMailSocket::Send
04/12/2014 13:26:06.969 - ######## START OF CHUNK ######
04/12/2014 13:26:07.020 - > QUIT
04/12/2014 13:26:07.071 - ######## END OF CHUNK ######
04/12/2014 13:26:07.122 - CSMTPConnection:isconnect: Failed in call to send QUIT command 10054 [0x2746] (An existing connection was forcibly closed by the remote host.) calling send from CMailSocket::Send
04/12/2014 13:26:07.173 - <
04/12/2014 13:26:07.224 - CSMTPConnection:isconnect: An unexpected QUIT response was received
​

4. Using resource monitor, I only see about 2 - 3MB/s between the voicemail pro server and the email server. Over a Gb card. I've tested throughput using iperf and get 60MB/s + between the two servers.

Any ideas where I should check next for a solution to this?

 

[holdmusic34]

Set up a gmail account and enable imap in gmail settings. Set the gmail sender account in VMPRo client as per below.

Save and make live. RESTART the SERVER (this will force the dns to get the right smtp.gmail address).

See if it makes a difference. use the debug trace. It might not be the Avaya. it looks like in the debug trace the remote host is closing the connection.

Dulce et decorum pro Avaya mori

 

[unspecialeffect]

Hi HoldMusic,

Thanks for the help. I've now turned off the auto record feature for our sales staff since there is obviously a bottleneck somewhere. The way I'm testing now... I've recorded a 2.5 minute "test message" which is a song so that I'm comparing apples to apples. Messages are both 4.5 MB in size ... there is no other traffic on the server during the tests.

After hanging up the phone, the SMTP log starts, it takes 2+ minutes to write the 4.5MB file. The network connection between either the gmail smtp server or the internal smtp server never goes over 1.5 Mb/s. See below for the SMTP log files from each. See anything odd other than the time it takes to send?


First test with GMAIL acting as the SMTP server - I'll include just the helpful stuff

05/12/2014 09:42:36.828 - Attempting to connect to host smtp.gmail.com on port 25, local bound address is (null)
05/12/2014 09:42:36.980 - Successfully connected to host smtp.gmail.com on port 25
05/12/2014 09:42:37.097 - < 220 mx.google.com ESMTP y3sm29451104pbt.44 - gsmtp
05/12/2014 09:42:37.148 - ######## START OF CHUNK ######
05/12/2014 09:42:37.199 - > EHLO IPOFFICE
05/12/2014 09:42:37.250 - ######## END OF CHUNK ######
05/12/2014 09:42:37.301 - < 250-mx.google.com at your service, [exchange server IP address removed]
05/12/2014 09:42:37.301 - 250-SIZE 35882577
05/12/2014 09:42:37.301 - 250-8BITMIME
05/12/2014 09:42:37.301 - 250-STARTTLS
05/12/2014 09:42:37.301 - 250-ENHANCEDSTATUSCODES
05/12/2014 09:42:37.301 - 250-PIPELINING
05/12/2014 09:42:37.301 - 250-CHUNKING
05/12/2014 09:42:37.301 - 250 SMTPUTF8
05/12/2014 09:42:37.358 - ######## START OF CHUNK ######
05/12/2014 09:42:37.409 - > STARTTLS
05/12/2014 09:42:37.460 - ######## END OF CHUNK ######
05/12/2014 09:42:37.511 - < 220 2.0.0 Ready to start TLS
05/12/2014 09:42:37.655 - ######## START OF CHUNK ######
05/12/2014 09:42:37.706 - > EHLO IPOFFICE
05/12/2014 09:42:37.757 - ######## END OF CHUNK ######
05/12/2014 09:42:37.808 - < 250-mx.google.com at your service, [Server IP removed]
05/12/2014 09:42:37.808 - 250-SIZE 35882577
05/12/2014 09:42:37.808 - 250-8BITMIME
05/12/2014 09:42:37.808 - 250-AUTH LOGIN PLAIN XOAUTH XOAUTH2 PLAIN-CLIENTTOKEN OAUTHBEARER
05/12/2014 09:42:37.808 - 250-ENHANCEDSTATUSCODES
05/12/2014 09:42:37.808 - 250-PIPELINING
05/12/2014 09:42:37.808 - 250-CHUNKING
05/12/2014 09:42:37.808 - 250 SMTPUTF8
05/12/2014 09:42:37.859 - ######## START OF CHUNK ######
05/12/2014 09:42:37.909 - > AUTH LOGIN
05/12/2014 09:42:37.960 - ######## END OF CHUNK ######
05/12/2014 09:42:38.011 - < 334 VXNlcm5hbWU6
05/12/2014 09:42:38.112 - ######## START OF CHUNK ######
05/12/2014 09:42:38.163 - > aWFuY29zbGV5QGdtYWlsLmNvbQ==
05/12/2014 09:42:38.214 - ######## END OF CHUNK ######
05/12/2014 09:42:38.265 - < 334 UGFzc3dvcmQ6
05/12/2014 09:42:38.365 - ######## START OF CHUNK ######
05/12/2014 09:42:38.466 - > QWdlbnQkMHJhbmdl
05/12/2014 09:42:38.517 - ######## END OF CHUNK ######
05/12/2014 09:42:38.828 - < 235 2.7.0 Accepted
05/12/2014 09:42:38.879 - ######## START OF CHUNK ######
05/12/2014 09:42:38.930 - > MAIL FROM:<personal email address removed>
05/12/2014 09:42:38.981 - ######## END OF CHUNK ######
05/12/2014 09:42:39.089 - < 250 2.1.0 OK y3sm29451104pbt.44 - gsmtp
05/12/2014 09:42:39.140 - ######## START OF CHUNK ######
05/12/2014 09:42:39.190 - > RCPT TO:<email address removed>
05/12/2014 09:42:39.241 - ######## END OF CHUNK ######
05/12/2014 09:42:39.292 - < 250 2.1.5 OK y3sm29451104pbt.44 - gsmtp
05/12/2014 09:42:39.343 - ######## START OF CHUNK ######
05/12/2014 09:42:39.394 - > DATA
05/12/2014 09:42:39.445 - ######## END OF CHUNK ######
05/12/2014 09:42:39.720 - < 354 Go ahead y3sm29451104pbt.44 - gsmtp
05/12/2014 09:42:39.771 - ######## START OF CHUNK ######
05/12/2014 09:42:39.822 - > From: WIRELESS CALLER <email address removed>
05/12/2014 09:42:39.822 - To: <email address removed>
05/12/2014 09:42:39.822 - Subject: Voicemail Message (WIRELESS CALLER > name removed) From:cell phone # removed
05/12/2014 09:42:39.822 - Date: Fri, 05 Dec 2014 09:42:39 -0800
05/12/2014 09:42:39.822 - X-Mailer: Voicemail Pro Server
05/12/2014 09:42:39.822 - MIME-Version: 1.0
05/12/2014 09:42:39.822 - Content-Type: multipart/mixed;
05/12/2014 09:42:39.822 - boundary="{ce7b983e-af4b-44f1-80f8-1fbc326695f0}"
05/12/2014 09:42:39.822 - Content-Transfer-Encoding: quoted-printable
05/12/2014 09:42:39.822 - X-Priority: 3
05/12/2014 09:42:39.822 - X-MSMail-Priority: Normal
05/12/2014 09:42:39.822 - Priority: Normal
05/12/2014 09:42:39.822 - Importance: Normal
05/12/2014 09:42:39.822 - Sensitivity: Normal
05/12/2014 09:42:39.822 - Content-Class: voice
05/12/2014 09:42:39.822 - X-CallingTelephoneNumber: cell phone number removed
05/12/2014 09:42:39.822 - X-VoiceMessageDuration: 143
05/12/2014 09:42:39.822 - X-VoiceMessageSenderName: WIRELESS CALLER
05/12/2014 09:42:39.822 - X-VoiceMessageOffset: 0
05/12/2014 09:42:39.822 - X-VoiceMessageReceivedTime: 3595254003
05/12/2014 09:42:39.822 - X-AttachmentOrder: ;MSG00075.WAV
05/12/2014 09:42:39.822 - X-MS-Has-Attach: yes
05/12/2014 09:42:39.822 -
05/12/2014 09:42:39.928 - ######## END OF CHUNK ######
05/12/2014 09:42:39.979 - ######## START OF CHUNK ######
05/12/2014 09:42:40.030 - > This is a multi-part message in MIME format.
05/12/2014 09:42:40.081 - ######## END OF CHUNK ######
05/12/2014 09:42:40.132 - ######## START OF CHUNK ######
05/12/2014 09:42:40.183 - >
05/12/2014 09:42:40.183 - --{ce7b983e-af4b-44f1-80f8-1fbc326695f0}
05/12/2014 09:42:40.183 - Content-Type: text/plain;
05/12/2014 09:42:40.183 - charset=iso-8859-1
05/12/2014 09:42:40.183 - Content-Transfer-Encoding: quoted-printable
05/12/2014 09:42:40.183 -
05/12/2014 09:42:40.283 - ######## END OF CHUNK ######
05/12/2014 09:42:40.334 - ######## START OF CHUNK ######
05/12/2014 09:42:40.385 - > IP Office Voicemail redirected message
05/12/2014 09:42:40.486 - ######## END OF CHUNK ######
05/12/2014 09:42:40.537 - ######## START OF CHUNK ######
05/12/2014 09:42:40.588 - >
05/12/2014 09:42:40.588 -
05/12/2014 09:42:40.588 - --{ce7b983e-af4b-44f1-80f8-1fbc326695f0}
05/12/2014 09:42:40.588 - Content-Type: audio/wav;
05/12/2014 09:42:40.588 - name="MSG00075.WAV"
05/12/2014 09:42:40.588 - Content-Transfer-Encoding: base64
05/12/2014 09:42:40.588 - Content-Disposition: attachment;
05/12/2014 09:42:40.588 - filename="MSG00075.WAV"
05/12/2014 09:42:40.588 -
05/12/2014 09:42:40.689 - ######## END OF CHUNK ######
05/12/2014 09:43:09.287 - ######## START OF CHUNK ######
05/12/2014 09:43:09.398 - > UklGRpj/IgBXQVZFZm10IBAAAAABAAEAQB8AAIA+AAACABAAQUxDSBIMAABBdmF5YQAAAAAAAAAA

05/12/2014 09:45:00.788 - ######## END OF CHUNK ######
05/12/2014 09:45:00.896 - ######## START OF CHUNK ######
05/12/2014 09:45:00.947 - >
05/12/2014 09:45:00.947 - --{ce7b983e-af4b-44f1-80f8-1fbc326695f0}--
05/12/2014 09:45:00.998 - ######## END OF CHUNK ######
05/12/2014 09:45:01.049 - ######## START OF CHUNK ######
05/12/2014 09:45:01.100 - >
05/12/2014 09:45:01.100 - .
05/12/2014 09:45:01.201 - ######## END OF CHUNK ######
05/12/2014 09:45:04.103 - < 250 2.0.0 OK 1417801521 y3sm29451104pbt.44 - gsmtp
05/12/2014 09:45:04.204 - ######## START OF CHUNK ######
05/12/2014 09:45:04.255 - > QUIT
05/12/2014 09:45:04.356 - ######## END OF CHUNK ######
05/12/2014 09:45:04.407 - < 221 2.0.0 closing connection y3sm29451104pbt.44 - gsmtp
​

Next is the same message with internal SMTP

05/12/2014 09:56:59.039 - Attempting to connect to host [removed internal mail server name] on port 25, local bound address is (null)
05/12/2014 09:56:59.147 - Successfully connected to host [removed internal mail server name] on port 25
05/12/2014 09:56:59.247 - < 220 [removed mail server] Microsoft ESMTP MAIL Service ready at Fri, 5 Dec 2014 09:56:58 -0800
05/12/2014 09:56:59.298 - ######## START OF CHUNK ######
05/12/2014 09:56:59.349 - > EHLO IPOFFICE
05/12/2014 09:56:59.450 - ######## END OF CHUNK ######
05/12/2014 09:56:59.562 - < 250-[removed server name] Hello [removed server ip address]
05/12/2014 09:56:59.562 - 250-SIZE 26214400
05/12/2014 09:56:59.562 - 250-PIPELINING
05/12/2014 09:56:59.562 - 250-DSN
05/12/2014 09:56:59.562 - 250-ENHANCEDSTATUSCODES
05/12/2014 09:56:59.562 - 250-AUTH
05/12/2014 09:56:59.562 - 250-8BITMIME
05/12/2014 09:56:59.562 - 250-BINARYMIME
05/12/2014 09:56:59.562 - 250 CHUNKING
05/12/2014 09:56:59.667 - ######## START OF CHUNK ######
05/12/2014 09:56:59.767 - > MAIL FROM:<ipoffice@[removed].com>
05/12/2014 09:56:59.868 - ######## END OF CHUNK ######
05/12/2014 09:56:59.969 - < 250 2.1.0 Sender OK
05/12/2014 09:57:00.070 - ######## START OF CHUNK ######
05/12/2014 09:57:00.170 - > RCPT TO:<removed email address>
05/12/2014 09:57:00.271 - ######## END OF CHUNK ######
05/12/2014 09:57:00.372 - < 250 2.1.5 Recipient OK
05/12/2014 09:57:00.472 - ######## START OF CHUNK ######
05/12/2014 09:57:00.573 - > DATA
05/12/2014 09:57:00.674 - ######## END OF CHUNK ######
05/12/2014 09:57:00.775 - < 354 Start mail input; end with <CRLF>.<CRLF>
05/12/2014 09:57:00.876 - ######## START OF CHUNK ######
05/12/2014 09:57:00.977 - > From: WIRELESS CALLER <ipoffice@[removed].com>
05/12/2014 09:57:00.977 - To: <removed email address>
05/12/2014 09:57:00.977 - Subject: Voicemail Message (WIRELESS CALLER > [removed name) From:[removed cell phone number]
05/12/2014 09:57:00.977 - Date: Fri, 05 Dec 2014 09:57:00 -0800
05/12/2014 09:57:00.977 - X-Mailer: Voicemail Pro Server
05/12/2014 09:57:00.977 - MIME-Version: 1.0
05/12/2014 09:57:00.977 - Content-Type: multipart/mixed;
05/12/2014 09:57:00.977 - boundary="{d82adeea-590c-44a5-84f1-4dee244db5db}"
05/12/2014 09:57:00.977 - Content-Transfer-Encoding: quoted-printable
05/12/2014 09:57:00.977 - X-Priority: 3
05/12/2014 09:57:00.977 - X-MSMail-Priority: Normal
05/12/2014 09:57:00.977 - Priority: Normal
05/12/2014 09:57:00.977 - Importance: Normal
05/12/2014 09:57:00.977 - Sensitivity: Normal
05/12/2014 09:57:00.977 - Content-Class: voice
05/12/2014 09:57:00.977 - X-CallingTelephoneNumber: removed cell phone number
05/12/2014 09:57:00.977 - X-VoiceMessageDuration: 192
05/12/2014 09:57:00.977 - X-VoiceMessageSenderName: WIRELESS CALLER
05/12/2014 09:57:00.977 - X-VoiceMessageOffset: 0
05/12/2014 09:57:00.977 - X-VoiceMessageReceivedTime: 3595254801
05/12/2014 09:57:00.977 - X-AttachmentOrder: ;MSG00076.WAV
05/12/2014 09:57:00.977 - X-MS-Has-Attach: yes
05/12/2014 09:57:00.977 -
05/12/2014 09:57:01.078 - ######## END OF CHUNK ######
05/12/2014 09:57:01.178 - ######## START OF CHUNK ######
05/12/2014 09:57:01.279 - > This is a multi-part message in MIME format.
05/12/2014 09:57:01.380 - ######## END OF CHUNK ######
05/12/2014 09:57:01.481 - ######## START OF CHUNK ######
05/12/2014 09:57:01.581 - >
05/12/2014 09:57:01.581 - --{d82adeea-590c-44a5-84f1-4dee244db5db}
05/12/2014 09:57:01.581 - Content-Type: text/plain;
05/12/2014 09:57:01.581 - charset=iso-8859-1
05/12/2014 09:57:01.581 - Content-Transfer-Encoding: quoted-printable
05/12/2014 09:57:01.581 -
05/12/2014 09:57:01.682 - ######## END OF CHUNK ######
05/12/2014 09:57:01.783 - ######## START OF CHUNK ######
05/12/2014 09:57:01.883 - > IP Office Voicemail redirected message
05/12/2014 09:57:01.984 - ######## END OF CHUNK ######
05/12/2014 09:57:02.134 - ######## START OF CHUNK ######
05/12/2014 09:57:02.235 - >
05/12/2014 09:57:02.235 -
05/12/2014 09:57:02.235 - --{d82adeea-590c-44a5-84f1-4dee244db5db}
05/12/2014 09:57:02.235 - Content-Type: audio/wav;
05/12/2014 09:57:02.235 - name="MSG00076.WAV"
05/12/2014 09:57:02.235 - Content-Transfer-Encoding: base64
05/12/2014 09:57:02.235 - Content-Disposition: attachment;
05/12/2014 09:57:02.235 - filename="MSG00076.WAV"
05/12/2014 09:57:02.235 -
05/12/2014 09:57:02.342 - ######## END OF CHUNK ######
05/12/2014 09:57:32.501 - ######## START OF CHUNK ######


05/12/2014 09:59:59.251 - ######## END OF CHUNK ######
05/12/2014 09:59:59.356 - ######## START OF CHUNK ######
05/12/2014 09:59:59.407 - >
05/12/2014 09:59:59.407 - --{d82adeea-590c-44a5-84f1-4dee244db5db}--
05/12/2014 09:59:59.458 - ######## END OF CHUNK ######
05/12/2014 09:59:59.509 - ######## START OF CHUNK ######
05/12/2014 09:59:59.560 - >
05/12/2014 09:59:59.560 - .
05/12/2014 09:59:59.611 - ######## END OF CHUNK ######
05/12/2014 10:00:00.008 - < 250 2.6.0 <b4dc274c-0094-466d-bb76-1b38f6716a9b@[removed exchange server name]> [InternalId=1999849] Queued mail for delivery
05/12/2014 10:00:00.109 - ######## START OF CHUNK ######
05/12/2014 10:00:00.160 - > QUIT
05/12/2014 10:00:00.211 - ######## END OF CHUNK ######
05/12/2014 10:00:00.262 - < 221 2.0.0 Service closing transmission channel
​

 

[holdmusic34]

What level of trace are you running in debug view?
I tried to replicate your trace with a level 9 trace but I see similar information to below. I never see references to chunks.

At least you know you're getting the same results with gmaill and private smtp.
Is MWI nearly instant notification still?
What else is on the VMPro server?

Here is a SMTP attempt failure with a level 5 trace in debug view ( I need to restart the VMPro server):

09/12 12:25:18.937 vmprov5s (66,5) 1794,14f0: CMAPIImpl::SendUMEmail[5698]: At entry, counter=[0]
09/12 12:25:18.937 vmprov5s (66,2) 1794,14f0: CMAPIImpl::SendUMEmail[5931]: Error pIMsgStore is NULL.
09/12 12:25:18.937 vmprov5s (66,5) 1794,14f0: CMAPIImpl::SendUMEmail[5934]: At Exit, counter=[0]
09/12 12:25:18.937 vmprov5s (19,2) 1794,14f0: Error (hr=0x80004003) from SendUMEmail
09/12 12:25:18.937 vmprov5s (14,2) 1794,14f0: Error 0x80004003 sending email to billblogs@mysmtpserver.com.au
09/12 12:25:18.938 vmprov5s (00,?) 1794,14f0: SMTP file size - 69
09/12 12:25:18.988 vmprov5s (14,2) 1794,14f0: CSMTPConnection:isconnect: Already disconnected from SMTP server, doing nothing
09/12 12:25:18.988 vmprov5s (14,2) 1794,14f0: emailerThrd - SendRequest failed for 790\MSG00008, error Unspecified error (80004005)
09/12 12:25:32.827 DbgOut (01,5) 1228,5432: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
09/12 12:25:32.828 DbgOut (01,5) 1228,5256: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
09/12 12:25:32.828 DbgOut (01,5) 1228,5880: DllMain(hinstDLL=0x10000000, fdwReason=DLL_THREAD_ATTACH)
09/12 12:25:42.084 vmprov5s (29,5) 1794, 700: > VMProWorkerThread::RemoveLongestIdleThreads(age=3600000)
09/12 12:25:42.084 vmprov5s (29,5) 1794, 700: < VMProWorkerThread::RemoveLongestIdleThreads()
09/12 12:25:42.084 vmprov5s (19,1) 1794, 700: VMIsMAPIAvailable returning [0]
09/12 12:25:42.084 vmprov5s (19,5) 1794, 700: CMAPIImpl::CheckMAPIConnection() - return is -1, m_iMAPIStatus = [-2]
09/12 12:25:42.085 DbgOut (01,5) 6036,5436: DllMain(hinstDLL=0x00AD0000, fdwReason=DLL_THREAD_ATTACH)
09/12 12:25:42.085 vmprov5s (09,5) 1794, 700: Created worker thread (02F6E380) (TID: 153c (5436))
09/12 12:25:42.295 vmprov5s (09,5) 1794,153c: Terminated worker thread (02F6E380) (TID: 153c (5436)), used by "CMAPIImpl:isconnectThreadRoutine" since 09/12/2014 12:25:42
09/12 12:25:42.295 DbgOut (01,5) 6036,5436: DllMain(hinstDLL=0x00AD0000, fdwReason=DLL_THREAD_DETACH

Dulce et decorum pro Avaya mori

 

[unspecialeffect]

The information I posted is from the SMTP log under C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\logs. It's taken me a while, (as I said, I'm not familiar with Avaya) to figure out all the different places this crazy program is logging things. From the monitor, to SMTP logs, and now I see there is this DbgOUT.txt file as well. I do not know what level of debugging is set to.

Here is the log :

17/12 12:32:22.754 DbgOut (00,5) 2704,3528: Process file is 'C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\vmprov5svc.exe' and DLL file is 'C:\Windows\system32\DbgOut.Dll'
17/12 12:32:22.755 vmprov5s (0b,5) a90, dc8: VMRegistry - registry opened with full access
17/12 12:32:22.755 vmprov5s (0b,5) a90, dc8: VMRegistry - user variables registry opened with full access
17/12 12:32:22.755 vmprov5s (0b,5) a90, dc8: VMRegistry - VPIM registry opened with full access
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Greetings"
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Accounts"
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\Modules"
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\Custom"
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\Custom\NumericPrompts"
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\Modules\CPAPrompts"
17/12 12:32:22.778 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Campaigns"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Names"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\logs"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\VRL"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\IMAP4"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\WebMail"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\tempfiles"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\ConferenceData"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM/Back Up"
17/12 12:32:22.779 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\HTML"
17/12 12:32:22.780 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\EVMLGreetings"
17/12 12:32:22.780 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\EVMLAccounts"
17/12 12:32:22.780 vmprov5s (0b,5) a90, dc8: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\EVMLNames"
17/12 12:32:22.892 DbgOut (01,5) 2704,2244: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:22.892 vmprov5s (09,5) a90, 8c4: Created thread "main(CheckGlobalLock)"
17/12 12:32:22.892 DbgOut (01,5) 2704,3584: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:22.896 DbgOut (01,5) 2704,2856: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:22.910 DbgOut (01,5) 2704,2184: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Supported compression formats:
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [0] = G723[RATE=4000]:4.0 kbps, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [1] = G723[RATE=4800]:4.8 kbps, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [2] = G723[RATE=5300]:5.3 kbps, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [3] = G723[RATE=6400]:6.4 kbps, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [4] = G726[RATE=6400]:6.4 kbps, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [5] = G728[RATE=6400]:6.4 kbps, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [6] = TXC[RATE=128000]:SND PCM, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [7] = TXC[RATE=128000]:WAV PCM, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [8] = TXC[RATE=13000]:WAV GSM, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [9] = TXC[RATE=14000]:ARIA, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [10] = TXC[RATE=16000]:Audix CELP16, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [11] = TXC[RATE=16000]:Audix SBC16, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [12] = TXC[RATE=24000]:Audix SBC24, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [13] = TXC[RATE=24000]:SER, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [14] = TXC[RATE=256000]:Float, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [15] = TXC[RATE=32000]:Audix ADPCM32, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [16] = TXC[RATE=32000]:VPIM, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [17] = TXC[RATE=64000]:Audix PCM64, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [18] = TXC[RATE=64000]:SND aLAW, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [19] = TXC[RATE=64000]:SND uLAW, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [20] = TXC[RATE=64000]:WAV aLAW, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [21] = TXC[RATE=64000]:WAV uLAW, 8 kHz, mono
17/12 12:32:23.048 vmprov5s (12,5) a90, 8c4: Format [22] = TXC[RATE=64000]:uLAW, 8 kHz, mono
17/12 12:32:23.052 vmprov5s (09,5) a90, 8c4: Created worker thread (019570E8) (TID: c34 (3124))
17/12 12:32:23.052 DbgOut (01,5) 2704,3124: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:23.054 vmprov5s (09,5) a90, 8c4: Initialising Voicemail Server - server is coming up.

IP Office Voicemail Pro [Hardware mode 00] - Version 9.0 (300.212)

*** Hardware ***
Processor: Intel(R) Xeon(R) CPU E5520 @ 2.27GHz
Number Of Processors: 4
Physical Memory: 4192792 KB (Available: 2659364 KB)
Commit Charge Limit: 8639088 KB

*** Operating System ***
Windows Server 2008,Standard Server (full installation),Service Pack 2 (Version 6.0 Build 6002)

17/12 12:32:23.059 vmprov5s (0b,5) a90, 8c4: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Back up\Scheduled\Daily"
17/12 12:32:23.059 vmprov5s (0b,5) a90, 8c4: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Back up\Scheduled\Weekly"
17/12 12:32:23.059 vmprov5s (0b,5) a90, 8c4: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Back up\Scheduled\Monthly"
17/12 12:32:23.060 vmprov5s (0b,5) a90, 8c4: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro"
17/12 12:32:23.060 vmprov5s (0b,5) a90, 8c4: VMRegistry - Validating directory "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Back up\Scheduled\Immediate"
17/12 12:32:23.100 vmprov5s (1d,5) a90, 8c4: Database not connected.
17/12 12:32:23.100 vmprov5s (09,3) a90, 8c4: Failed to connect to database
17/12 12:32:23.102 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA570) (TID: 8f4 (2292))
17/12 12:32:23.102 DbgOut (01,5) 2704,2292: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:23.103 DbgOut (01,5) 2704,2228: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:23.105 vmprov5s (66,2) a90, 8b4: CMAPIImpl::MAPIMessagePump[7136]: Error 0x80004005 [MAPI_E_CALL_FAILED] from MAPIInitialize Possible causes are:
* No version of Extended MAPI is installed (Either Outlook or MAPICDO must be installed).
* The 64 bit version of Outlook 2010 is installed.
* Windows Mail or Outlook Express (which do not implement Extended MAPI) is registered as the Default Mail Client.
17/12 12:32:23.105 DbgOut (01,5) 2704,2228: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:32:24.481 vmprov5s (01,4) a90, 8f4: Creating new instance of VMUser for 172.20.2.52:4098, backup address=0.0.0.0
17/12 12:32:24.539 vmprov5s (09,5) a90, 8f4: Created worker thread (02AAA660) (TID: fc0 (4032))
17/12 12:32:24.539 vmprov5s (26,5) a90, 8f4: Unable to process message using a background worker thread (none available)
17/12 12:32:24.539 vmprov5s (26,5) a90, 8f4: SVMAIL supported
17/12 12:32:24.539 DbgOut (01,5) 2704,4032: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:24.539 vmprov5s (09,5) a90, 8f4: Licence Summary for <AmericanElec (MASTER:172.20.2.52 - SLAVE:0.0.0.0 [INACTIVE]) [9.0.3.0 build 941]>
Voicemail Pro is licenced for 4 ports
Integrated messaging is NOT licenced
3rd Party License is NOT licenced
VPIM is NOT licenced
Voice recording library is NOT licenced
3rd Party Database is NOT licenced
VB Scripting is NOT licenced
Outlook Calendar based greetings is NOT licenced
ScanSoft TTS Support is NOT licenced
Generic TTS Support is NOT licenced
Loquendo TTS Support is NOT licenced
Not in SOG Mode
UMS (web) is NOT licenced
UMS (IMAP4) is NOT licenced
17/12 12:32:24.540 vmprov5s (09,5) a90, 8f4: Created worker thread (02AAA750) (TID: d4c (3404))
17/12 12:32:24.540 vmprov5s (09,3) a90, 8f4: Loading Config Data
17/12 12:32:24.540 DbgOut (01,5) 2704,3404: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:24.540 vmprov5s (00,5) a90, 8f4: > VMailBox:eleteMailboxList(02E3F788)
17/12 12:32:24.540 vmprov5s (09,5) a90, 8f4: 0 mailboxes were open (but not active) when flushed (PBX=02798468)
17/12 12:32:24.540 vmprov5s (00,5) a90, 8f4: < VMailBox:eleteMailboxList()
17/12 12:32:24.560 vmprov5s (0b,2) a90, 8f4: VMRegistry - Decrypting VoicemailPassword failed.
17/12 12:32:24.560 vmprov5s (09,5) a90, 8f4: Created worker thread (02AAA930) (TID: e9c (3740))
17/12 12:32:24.560 DbgOut (01,5) 2704,3740: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:24.560 vmprov5s (09,3) a90, 8f4: Took 79ms to process request " VMMESSAGE_POLLBULKINFO Session=00000000, Seq=1, length=73" from 172.20.2.52:4098
17/12 12:32:24.571 vmprov5s (09,5) a90, e9c: UDPSocket bind assigns port=0 [UDP]
17/12 12:32:27.305 vmprov5s (00,5) a90, e9c: > VMailBox:eleteMailboxList(0336FA9C)
17/12 12:32:27.305 vmprov5s (09,5) a90, e9c: 0 mailboxes were open (but not active) when flushed (PBX=02798468)
17/12 12:32:27.305 vmprov5s (00,5) a90, e9c: < VMailBox:eleteMailboxList()
17/12 12:32:27.308 vmprov5s (00,5) a90, e9c: > VMailBox:eleteMailboxList(018CF918)
17/12 12:32:27.308 vmprov5s (09,5) a90, e9c: 0 mailboxes were open (but not active) when flushed (PBX=02798468)
17/12 12:32:27.308 vmprov5s (00,5) a90, e9c: < VMailBox:eleteMailboxList()
17/12 12:32:27.308 vmprov5s (09,5) a90, e9c: Created worker thread (02AAAB10) (TID: f0c (3852))
17/12 12:32:27.308 DbgOut (01,5) 2704,3852: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:27.319 vmprov5s (09,5) a90, f0c: Changing ITZ Support to [False]
17/12 12:32:27.319 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 1>, extn = <101>
17/12 12:32:27.321 vmprov5s (09,4) a90, f0c: BulkInfo <AmericanElec (MASTER:172.20.2.52 - SLAVE:0.0.0.0 [INACTIVE]) [9.0.3.0 build 941]> - Mailbox <Modem 1>: New: 0, Old: 0, Saved: 0
17/12 12:32:27.321 vmprov5s (09,4) a90, f0c: BulkInfo Response 1 AmericanElec (MASTER:172.20.2.52 - SLAVE:0.0.0.0 [INACTIVE]) [9.0.3.0 build 941]
17/12 12:32:27.322 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 2>, extn = <102>
17/12 12:32:27.326 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 3>, extn = <103>
17/12 12:32:27.329 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 4>, extn = <104>
17/12 12:32:27.332 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 5>, extn = <105>
17/12 12:32:27.334 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 6>, extn = <106>
17/12 12:32:27.337 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 7>, extn = <107>
17/12 12:32:27.339 vmprov5s (06,5) a90, f0c: VMailBox::AddNewMailbox - pbx = <02798468>, mailbox = <Modem 8>, extn = <108>
[removed 30 mailbox names to protect the innocent]

7/12 12:32:27.472 vmprov5s (09,5) a90, f0c: Created worker thread (02AAA5E8) (TID: f48 (3912))
17/12 12:32:27.472 DbgOut (01,5) 2704,3912: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:27.473 vmprov5s (1c,5) a90, f0c: > NiceCopyFile(source <C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Alarms_temp>, dest <Alarms>)
17/12 12:32:27.474 vmprov5s (1c,5) a90, f0c: < NiceCopyFile(source <C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Alarms_temp>, dest <Alarms>) - Succeeded.
17/12 12:32:27.475 vmprov5s (09,5) a90, f0c: Finished processing configuration data (took 158ms)
17/12 12:32:27.475 vmprov5s (09,5) a90, f0c: Terminated worker thread (02AAAB10) (TID: f0c (3852)), used by "ProcessTFTPCompleteThread" since 17/12/2014 12:32:27
17/12 12:32:27.475 DbgOut (01,5) 2704,3852: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:32:27.980 vmprov5s (19,5) a90, f48: No connection to Mail Server using MAPI exists, could not request email notifications for mailbox "Ian C".
17/12 12:32:28.104 vmprov5s (19,1) a90, 8c4: Connection count=[1]
17/12 12:32:28.204 DbgOut (01,5) 2704,3576: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:28.204 vmprov5s (66,2) a90, df8: CMAPIImpl::MAPIMessagePump[7136]: Error 0x80004005 [MAPI_E_CALL_FAILED] from MAPIInitialize Possible causes are:
* No version of Extended MAPI is installed (Either Outlook or MAPICDO must be installed).
* The 64 bit version of Outlook 2010 is installed.
* Windows Mail or Outlook Express (which do not implement Extended MAPI) is registered as the Default Mail Client.
17/12 12:32:28.204 DbgOut (01,5) 2704,3576: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:32:31.425 vmprov5s (09,5) a90, f48: Terminated worker thread (02AAA5E8) (TID: f48 (3912)), used by "GetMailboxDataThread" since 17/12/2014 12:32:31
17/12 12:32:31.425 DbgOut (01,5) 2704,3912: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:32:33.304 vmprov5s (19,1) a90, 8c4: Creating secondary connection
17/12 12:32:33.304 vmprov5s (19,1) a90, 8c4: Connection count=[2]
17/12 12:32:33.304 vmprov5s (19,5) a90, 8c4: MAPIServiceAddress is either empty or default to ipaddress. So retruning back CMAPIImpl::Reconnect 824
17/12 12:32:33.304 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA5E8) (TID: 4c0 (1216))
17/12 12:32:33.304 DbgOut (01,5) 2704,1216: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.304 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA8B8) (TID: e0c (3596))
17/12 12:32:33.305 DbgOut (01,5) 2704,3596: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.305 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA6D8) (TID: d90 (3472))
17/12 12:32:33.305 DbgOut (01,5) 2704,3472: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.305 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA9A8) (TID: c38 (3128))
17/12 12:32:33.305 DbgOut (01,5) 2704,3128: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.306 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAAA98) (TID: df0 (3568))
17/12 12:32:33.306 DbgOut (01,5) 2704,3568: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.306 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA318) (TID: f28 (3880))
17/12 12:32:33.306 DbgOut (01,5) 2704,3880: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.306 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA228) (TID: 908 (2312))
17/12 12:32:33.306 DbgOut (01,5) 2704,2312: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.307 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA138) (TID: e68 (3688))
17/12 12:32:33.307 DbgOut (01,5) 2704,3688: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.308 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAA048) (TID: 5d0 (1488))
17/12 12:32:33.308 DbgOut (01,5) 2704,1488: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.308 vmprov5s (09,5) a90, 8c4: Created worker thread (02AA9F58) (TID: da8 (3496))
17/12 12:32:33.308 DbgOut (01,5) 2704,3496: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.308 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAAC78) (TID: 170 (368))
17/12 12:32:33.308 DbgOut (01,5) 2704, 368: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.309 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAAD68) (TID: 5cc (1484))
17/12 12:32:33.309 DbgOut (01,5) 2704,1484: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.309 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAAE58) (TID: 894 (2196))
17/12 12:32:33.309 DbgOut (01,5) 2704,2196: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.309 vmprov5s (09,5) a90, 8c4: Created worker thread (02AAAC00) (TID: d0c (3340))
17/12 12:32:33.310 DbgOut (01,5) 2704,3340: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.310 vmprov5s (09,5) a90, 8c4: Created worker thread (01957340) (TID: d88 (3464))
17/12 12:32:33.310 DbgOut (01,5) 2704,3464: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.310 vmprov5s (09,5) a90, 8c4: Created worker thread (01957250) (TID: f34 (3892))
17/12 12:32:33.310 DbgOut (01,5) 2704,3892: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.311 vmprov5s (09,5) a90, 8c4: Created worker thread (01957160) (TID: e90 (3728))
17/12 12:32:33.311 DbgOut (01,5) 2704,3728: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.311 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3B9D0) (TID: bc4 (3012))
17/12 12:32:33.311 DbgOut (01,5) 2704,3012: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.313 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BA48) (TID: f94 (3988))
17/12 12:32:33.313 DbgOut (01,5) 2704,3988: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.313 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BB38) (TID: 83c (2108))
17/12 12:32:33.313 DbgOut (01,5) 2704,2108: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:33.317 vmprov5s (1e,5) a90, 8c4: IMAP4 - IMAP4 Server starting
17/12 12:32:34.504 DbgOut (01,5) 2704,2252: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.504 vmprov5s (1e,5) a90, 8cc: IMAP4 - Listener thread starting
17/12 12:32:34.504 DbgOut (01,5) 2704, 260: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.504 vmprov5s (1e,5) a90, 104: IMAP4 - Listener thread starting
17/12 12:32:34.504 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BC28) (TID: 95c (2396))
17/12 12:32:34.504 DbgOut (01,5) 2704,2396: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.504 vmprov5s (09,5) a90, 8c4: UDPSocket bind assigns port=0 [UDP]
17/12 12:32:34.505 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BD18) (TID: efc (3836))
17/12 12:32:34.505 DbgOut (01,5) 2704,3836: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.505 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BE08) (TID: c8c (3212))
17/12 12:32:34.505 DbgOut (01,5) 2704,3212: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.506 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BEF8) (TID: 928 (2344))
17/12 12:32:34.506 DbgOut (01,5) 2704,2344: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.506 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3BFE8) (TID: e24 (3620))
17/12 12:32:34.506 DbgOut (01,5) 2704,3620: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.506 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C0D8) (TID: e3c (3644))
17/12 12:32:34.507 DbgOut (01,5) 2704,3644: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.507 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C1C8) (TID: bf8 (3064))
17/12 12:32:34.507 DbgOut (01,5) 2704,3064: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.507 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C2B8) (TID: c4c (3148))
17/12 12:32:34.507 DbgOut (01,5) 2704,3148: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.507 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C3A8) (TID: fec (4076))
17/12 12:32:34.508 DbgOut (01,5) 2704,4076: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.508 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C498) (TID: 8f0 (2288))
17/12 12:32:34.508 DbgOut (01,5) 2704,2288: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.508 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C588) (TID: 87c (2172))
17/12 12:32:34.508 DbgOut (01,5) 2704,2172: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.509 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C678) (TID: f6c (3948))
17/12 12:32:34.509 DbgOut (01,5) 2704,3948: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.509 vmprov5s (09,5) a90, 8c4: Created worker thread (02B3C768) (TID: db4 (3508))
17/12 12:32:34.509 DbgOut (01,5) 2704,3508: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.509 vmprov5s (09,5) a90, 8c4: Created worker thread (02B452F8) (TID: 904 (2308))
17/12 12:32:34.509 DbgOut (01,5) 2704,2308: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.510 vmprov5s (09,5) a90, 8c4: Created worker thread (02B453E8) (TID: 72c (1836))
17/12 12:32:34.510 DbgOut (01,5) 2704,1836: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.510 vmprov5s (09,5) a90, 8c4: Created worker thread (02B454D8) (TID: 6b4 (1716))
17/12 12:32:34.510 DbgOut (01,5) 2704,1716: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.510 vmprov5s (14,2) a90, 8c4: EMailer::EMailer - Host=mail.aeri.com, Domain=mail.aeri.com, Port=25, Authentication:0 (None)
17/12 12:32:34.511 vmprov5s (09,5) a90, 8c4: Created worker thread (02B455C8) (TID: c9c (3228))
17/12 12:32:34.511 DbgOut (01,5) 2704,3228: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.511 vmprov5s (09,5) a90, 8c4: Created worker thread (02B456B8) (TID: c3c (3132))
17/12 12:32:34.511 DbgOut (01,5) 2704,3132: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.511 vmprov5s (09,5) a90, 8c4: Created worker thread (02B457A8) (TID: aac (2732))
17/12 12:32:34.511 DbgOut (01,5) 2704,2732: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.512 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45898) (TID: 650 (1616))
17/12 12:32:34.512 DbgOut (01,5) 2704,1616: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.512 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45988) (TID: c90 (3216))
17/12 12:32:34.512 DbgOut (01,5) 2704,3216: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.512 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45A78) (TID: ae0 (2784))
17/12 12:32:34.512 DbgOut (01,5) 2704,2784: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.513 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45B68) (TID: e08 (3592))
17/12 12:32:34.513 DbgOut (01,5) 2704,3592: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.513 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45C58) (TID: b30 (2864))
17/12 12:32:34.513 DbgOut (01,5) 2704,2864: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.513 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45D48) (TID: ec (236))
17/12 12:32:34.513 DbgOut (01,5) 2704, 236: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.514 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45E38) (TID: 814 (2068))
17/12 12:32:34.514 DbgOut (01,5) 2704,2068: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.514 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45EB0) (TID: d18 (3352))
17/12 12:32:34.514 DbgOut (01,5) 2704,3352: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.515 vmprov5s (09,5) a90, 8c4: Created worker thread (02B45FA0) (TID: c20 (3104))
17/12 12:32:34.515 DbgOut (01,5) 2704,3104: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.524 vmprov5s (09,5) a90, 8c4: Created worker thread (02B53898) (TID: db8 (3512))
17/12 12:32:34.524 DbgOut (01,5) 2704,3512: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.524 vmprov5s (09,5) a90, 8c4: Created worker thread (02B53910) (TID: b1c (2844))
17/12 12:32:34.524 DbgOut (01,5) 2704,2844: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.525 vmprov5s (09,5) a90, 8c4: Allowing PBXes whose IP address match the mask of 255.255.255.255
17/12 12:32:34.525 vmprov5s (09,5) a90, 8c4: Voicemail Server initialisation complete - server is now running.
17/12 12:32:34.525 vmprov5s (09,5) a90, 8c4: Created worker thread (02B53A00) (TID: 2dc (732))
17/12 12:32:34.525 DbgOut (01,5) 2704, 732: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.525 vmprov5s (09,5) a90, 8c4: Created worker thread (02B53AF0) (TID: d08 (3336))
17/12 12:32:34.525 DbgOut (01,5) 2704,3336: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:34.535 vmprov5s (09,5) a90, d08: MAPIMailboxScanRoutine started
17/12 12:32:54.477 vmprov5s (09,5) a90, 170: Created worker thread (02AAA840) (TID: bfc (3068))
17/12 12:32:54.477 DbgOut (01,5) 2704,3068: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:32:54.484 vmprov5s (09,5) a90, 8f4: PBX <AmericanElec (MASTER:172.20.2.52 - SLAVE:0.0.0.0 [INACTIVE]) [9.0.3.0 build 941]> is licensed for CPA.
17/12 12:32:54.507 vmprov5s (09,5) a90, bfc: Terminated worker thread (02AAA840) (TID: bfc (3068)), used by "UpdateMessageStatsThread" since 17/12/2014 12:32:54
17/12 12:32:54.507 DbgOut (01,5) 2704,3068: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc:
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: IP Office Voicemail Pro [Hardware mode 03] - Version 9.0 (300.212) [CPU Usage 0.0] [CPU Min:0.0, Avg:0.1, Max:0.5] has been running for 0 days, 0 hours and 1 minutes.
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Call information: Received 0, Made 0, 0 missed voice packets (0 calls completed, 0 calls/hour) (Call duration(secs) - Min:0, Max:0, Avg:0).
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Threads (57 threads), worker threads (57 inuse, 0 free), voicemail tasks (6 tasks)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Voicemail Sessions (Connections 0 - 0) (Links:11825 from 12000) (CMMsg:0 left from 0) (VM:0 NODES:0 SN:0 SCO:0 SBL:0 FILES:0)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Predictive Call objects CIPOSessionManager[0], CIVRSession[0], CRecordingSession[0], CIVRConfig[0], CCPAPlayerData[0], CPromptPlayer[0]
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Allocated buffers (3 buffers, 0 sequenced) (Buffer pool(0:1000 1:250 2:2500 3:1497)) cached prompts (0 ALAW, 0 ULAW)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Mailboxes (71 mailboxes, 56 messages, 0 file objects)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: TCP Connections (0 clients)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Outstanding Emails (0 Emails, 0 VPNM and 0 SMTP)
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: SYNC Status: [0 outstanding tasks, 0 cached objects, 0 allocated objects]
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: PBX Configuration:-
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Voicemail Pro mode, locale: enu, IPO hardware mode: 03 [USA]
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: EVML:-
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Maximum recording capacity: Unlimited, Maximum Recording Time: 120 seconds
17/12 12:33:34.122 vmprov5s (09,5) a90, 2dc: Maximum Sessions: 4, Minimum PIN length: 0 digits
17/12 12:33:34.123 vmprov5s (09,5) a90, 2dc: SMTP:-
17/12 12:33:34.123 vmprov5s (09,5) a90, 2dc: Host address 172.20.2.13, port 25, Login method "none", email from "", login user ""
17/12 12:33:34.123 vmprov5s (09,5) a90, 2dc: Memory statistics:-
17/12 12:33:34.123 vmprov5s (09,5) a90, 2dc: Physical Memory: 37% in use, 4192792 KB (Available: 2636280 KB)
17/12 12:33:34.123 vmprov5s (09,5) a90, 2dc: Commit Charge Limit: 8639088 KB, (Available to commit: 7219884 KB)
17/12 12:33:34.123 vmprov5s (09,5) a90, 2dc: Virtual memory: 2097024 KB, (Available: 1938752 KB, Extended available: 0 KB)
17/12 12:33:34.133 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:33:38.833 vmprov5s (09,5) a90, 8f4: new VMAIL Client [02B5BE50] [Connections 0 - 1] [INBAND DTMF=YES]
17/12 12:33:38.833 vmprov5s (09,5) a90, 8f4: Created worker thread (019573B8) (TID: c14 (3092))
17/12 12:33:38.834 DbgOut (01,5) 2704,3092: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:33:38.846 vmprov5s (06,5) a90, c14: VMClient::RxOpen - Created dialog 02B5D1A8
17/12 12:33:38.846 vmprov5s (06,5) a90, c14: VMClient::RxOpen 02B5BDE8 Ian C (1), session=000001d0, dialog=02B5D1A8, Fallback number is ""
17/12 12:33:40.158 vmprov5s (23,5) a90, c14: SoundsManager::ConvertWAV(02B53338, "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Greetings\Ian C_1.wav" [uLaw], 02B5D1A8) - Took 71 ms to process, return is 70200
17/12 12:33:40.158 vmprov5s (23,5) a90, c14: Succeeded in loading sound bite "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Greetings\Ian C_1.wav" [uLaw]
17/12 12:33:49.116 vmprov5s (24,5) a90, c14: Successfully determined fragments for announcement 1146 using language enu, fragments are "1440"
17/12 12:33:49.158 vmprov5s (23,5) a90, c14: SoundsManager::ConvertWAV(02B53318, "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\1440.WAV" [uLaw], 02B5D1A8) - Took 21 ms to process, return is 1280
17/12 12:33:49.158 vmprov5s (23,5) a90, c14: Succeeded in loading sound bite "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Wavs\enu\1440.WAV" [uLaw]
17/12 12:33:52.906 DbgOut (01,5) 2704,2184: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:34:05.863 vmprov5s (09,5) a90, c14: Session: 000001d0 - Created worker thread (02AAA4F8) (TID: c84 (3204))
17/12 12:34:05.863 DbgOut (01,5) 2704,3204: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:34:05.883 vmprov5s (09,5) a90, c14: Session: 000001d0 - ~IClient [Call duration: 27 secs, 0 missed packets] [Connections 0 - 0] [Buffer pool(0:1000 1:250 2:2500 3:1497) allocated:3, seq:0] [Links:11824 from 12000] [CMMsg:1 left from 1] [VM:1 NODES:0 SN:0 SCO:0 SBL:0 TASKS:7 FILES:1 Msgs:56]
17/12 12:34:05.883 vmprov5s (09,5) a90, c14: Terminated worker thread (019573B8) (TID: c14 (3092)), used by "VMTask[VMClient(02B5BE04)]" since 17/12/2014 12:34:05
17/12 12:34:05.883 DbgOut (01,5) 2704,3092: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:34:06.325 vmprov5s (23,5) a90, c84: Normalized wave file "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Greetings\MSG74725.wav" - Took 450 ms to normalize, maximum energy was 12.123449 and used factor 1.138051 to normalize
17/12 12:34:06.327 vmprov5s (23,5) a90, c84: Normalized wave file "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Greetings\MSG74725.wav" - rewritten at 0.180000 FS
17/12 12:34:06.350 vmprov5s (13,5) a90, c84: Renaming message file "Ian C/C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Accounts\Ian C\MSG00085.wav" to "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Accounts\Ian C\ad3a76a744e64d7f8d9b4ae3e5126291.wav"
17/12 12:34:06.362 vmprov5s (09,2) a90, c84: RemoveRecordingThread(02B3FF00) called for dialog 02B5D1A8 (Background saving message "C:\Program Files (x86)\Avaya\IP Office\Voicemail Pro\VM\Greetings\MSG74725.wav" to 425 [entry 1 of 1]) that has no client.
17/12 12:34:06.362 vmprov5s (09,5) a90, c84: Terminated worker thread (02AAA4F8) (TID: c84 (3204)), used by "IntuityRecordNode::SaveRecordingForMailboxList" since 17/12/2014 12:34:06
17/12 12:34:06.362 DbgOut (01,5) 2704,3204: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:34:09.532 vmprov5s (66,5) a90, e24: CMAPIImpl::SendUMEmail[5698]: At entry, counter=[0]
17/12 12:34:09.532 vmprov5s (66,2) a90, e24: CMAPIImpl::SendUMEmail[5931]: Error pIMsgStore is NULL.
17/12 12:34:09.532 vmprov5s (66,5) a90, e24: CMAPIImpl::SendUMEmail[5934]: At Exit, counter=[0]
17/12 12:34:09.532 vmprov5s (19,2) a90, e24: Error (hr=0x80004003) from SendUMEmail
17/12 12:34:09.532 vmprov5s (14,2) a90, e24: Error 0x80004003 sending email to ian@aeri.com
17/12 12:34:09.532 vmprov5s (00,?) a90, e24: SMTP file size - 241
17/12 12:34:09.634 vmprov5s (09,5) a90, e24: CMailSocket::Create: Receive buffer size is 0x10000 bytes (64K)
17/12 12:34:09.634 vmprov5s (09,5) a90, e24: CMailSocket::Create: Send buffer size is 0x2000 bytes (8K)
17/12 12:34:09.638 DbgOut (01,5) 2704,3672: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc:
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: IP Office Voicemail Pro [Hardware mode 03] - Version 9.0 (300.212) [CPU Usage 0.4] [CPU Min:0.0, Avg:0.2, Max:1.0] has been running for 0 days, 0 hours and 2 minutes.
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Call information: Received 1, Made 0, 0 missed voice packets (1 calls completed, 30 calls/hour) (Call duration(secs) - Min:0, Max:27, Avg:27).
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Threads (57 threads), worker threads (57 inuse, 0 free), voicemail tasks (6 tasks)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Voicemail Sessions (Connections 0 - 0) (Links:11824 from 12000) (CMMsg:1 left from 1) (VM:0 NODES:0 SN:0 SCO:0 SBL:0 FILES:0)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Predictive Call objects CIPOSessionManager[0], CIVRSession[0], CRecordingSession[0], CIVRConfig[0], CCPAPlayerData[0], CPromptPlayer[0]
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Allocated buffers (3 buffers, 0 sequenced) (Buffer pool(0:1000 1:250 2:2500 3:1497)) cached prompts (0 ALAW, 0 ULAW)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Mailboxes (71 mailboxes, 57 messages, 0 file objects)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: TCP Connections (0 clients)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Outstanding Emails (0 Emails, 0 VPNM and 0 SMTP)
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: SYNC Status: [0 outstanding tasks, 0 cached objects, 0 allocated objects]
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: PBX Configuration:-
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Voicemail Pro mode, locale: enu, IPO hardware mode: 03 [USA]
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: EVML:-
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Maximum recording capacity: Unlimited, Maximum Recording Time: 120 seconds
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Maximum Sessions: 4, Minimum PIN length: 0 digits
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: SMTP:-
17/12 12:34:34.174 vmprov5s (09,5) a90, 2dc: Host address 172.20.2.13, port 25, Login method "none", email from "", login user ""
17/12 12:34:34.184 vmprov5s (09,5) a90, 2dc: Memory statistics:-
17/12 12:34:34.184 vmprov5s (09,5) a90, 2dc: Physical Memory: 36% in use, 4192792 KB (Available: 2646456 KB)
17/12 12:34:34.184 vmprov5s (09,5) a90, 2dc: Commit Charge Limit: 8639088 KB, (Available to commit: 7231776 KB)
17/12 12:34:34.184 vmprov5s (09,5) a90, 2dc: Virtual memory: 2097024 KB, (Available: 1928504 KB, Extended available: 0 KB)
17/12 12:34:34.184 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:35:22.899 DbgOut (01,5) 2704,3388: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_ATTACH)
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc:
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc: IP Office Voicemail Pro [Hardware mode 03] - Version 9.0 (300.212) [CPU Usage 0.0] [CPU Min:0.0, Avg:0.1, Max:1.0] has been running for 0 days, 0 hours and 3 minutes.
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc: Call information: Received 1, Made 0, 0 missed voice packets (1 calls completed, 20 calls/hour) (Call duration(secs) - Min:0, Max:27, Avg:27).
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc: Threads (57 threads), worker threads (57 inuse, 0 free), voicemail tasks (6 tasks)
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc: Voicemail Sessions (Connections 0 - 0) (Links:11824 from 12000) (CMMsg:1 left from 1) (VM:0 NODES:0 SN:0 SCO:0 SBL:0 FILES:0)
17/12 12:35:34.247 vmprov5s (09,5) a90, 2dc: Predictive Call objects CIPOSessionManager[0], CIVRSession[0], CRecordingSession[0], CIVRConfig[0], CCPAPlayerData[0], CPromptPlayer[0]
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Allocated buffers (3 buffers, 0 sequenced) (Buffer pool(0:1000 1:250 2:2500 3:1497)) cached prompts (0 ALAW, 0 ULAW)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Mailboxes (71 mailboxes, 57 messages, 0 file objects)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: TCP Connections (0 clients)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Outstanding Emails (0 Emails, 0 VPNM and 0 SMTP)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: SYNC Status: [0 outstanding tasks, 0 cached objects, 0 allocated objects]
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: PBX Configuration:-
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Voicemail Pro mode, locale: enu, IPO hardware mode: 03 [USA]
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: EVML:-
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Maximum recording capacity: Unlimited, Maximum Recording Time: 120 seconds
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Maximum Sessions: 4, Minimum PIN length: 0 digits
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: SMTP:-
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Host address 172.20.2.13, port 25, Login method "none", email from "", login user ""
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Memory statistics:-
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Physical Memory: 36% in use, 4192792 KB (Available: 2641868 KB)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Commit Charge Limit: 8639088 KB, (Available to commit: 7225608 KB)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: Virtual memory: 2097024 KB, (Available: 1927224 KB, Extended available: 0 KB)
17/12 12:35:34.257 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:36:34.019 vmprov5s (09,5) a90, 2dc:
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: IP Office Voicemail Pro [Hardware mode 03] - Version 9.0 (300.212) [CPU Usage 0.0] [CPU Min:0.0, Avg:0.1, Max:1.0] has been running for 0 days, 0 hours and 4 minutes.
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Call information: Received 1, Made 0, 0 missed voice packets (1 calls completed, 15 calls/hour) (Call duration(secs) - Min:0, Max:27, Avg:27).
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Threads (57 threads), worker threads (57 inuse, 0 free), voicemail tasks (6 tasks)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Voicemail Sessions (Connections 0 - 0) (Links:11824 from 12000) (CMMsg:1 left from 1) (VM:0 NODES:0 SN:0 SCO:0 SBL:0 FILES:0)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Predictive Call objects CIPOSessionManager[0], CIVRSession[0], CRecordingSession[0], CIVRConfig[0], CCPAPlayerData[0], CPromptPlayer[0]
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Allocated buffers (3 buffers, 0 sequenced) (Buffer pool(0:1000 1:250 2:2500 3:1497)) cached prompts (0 ALAW, 0 ULAW)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Mailboxes (71 mailboxes, 57 messages, 0 file objects)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: TCP Connections (0 clients)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Outstanding Emails (0 Emails, 0 VPNM and 0 SMTP)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: SYNC Status: [0 outstanding tasks, 0 cached objects, 0 allocated objects]
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: PBX Configuration:-
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Voicemail Pro mode, locale: enu, IPO hardware mode: 03 [USA]
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: EVML:-
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Maximum recording capacity: Unlimited, Maximum Recording Time: 120 seconds
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Maximum Sessions: 4, Minimum PIN length: 0 digits
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: SMTP:-
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Host address 172.20.2.13, port 25, Login method "none", email from "", login user ""
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Memory statistics:-
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Physical Memory: 37% in use, 4192792 KB (Available: 2638860 KB)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Commit Charge Limit: 8639088 KB, (Available to commit: 7222312 KB)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: Virtual memory: 2097024 KB, (Available: 1927224 KB, Extended available: 0 KB)
17/12 12:36:34.029 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:36:52.894 DbgOut (01,5) 2704,3388: DllMain(hinstDLL=0x00300000, fdwReason=DLL_THREAD_DETACH)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc:
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: IP Office Voicemail Pro [Hardware mode 03] - Version 9.0 (300.212) [CPU Usage 0.0] [CPU Min:0.0, Avg:0.1, Max:1.0] has been running for 0 days, 0 hours and 5 minutes.
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Call information: Received 1, Made 0, 0 missed voice packets (1 calls completed, 12 calls/hour) (Call duration(secs) - Min:0, Max:27, Avg:27).
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Threads (57 threads), worker threads (57 inuse, 0 free), voicemail tasks (6 tasks)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Voicemail Sessions (Connections 0 - 0) (Links:11824 from 12000) (CMMsg:1 left from 1) (VM:0 NODES:0 SN:0 SCO:0 SBL:0 FILES:0)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Predictive Call objects CIPOSessionManager[0], CIVRSession[0], CRecordingSession[0], CIVRConfig[0], CCPAPlayerData[0], CPromptPlayer[0]
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Allocated buffers (3 buffers, 0 sequenced) (Buffer pool(0:1000 1:250 2:2500 3:1497)) cached prompts (0 ALAW, 0 ULAW)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Mailboxes (71 mailboxes, 57 messages, 0 file objects)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: TCP Connections (0 clients)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Outstanding Emails (0 Emails, 0 VPNM and 0 SMTP)
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: SYNC Status: [0 outstanding tasks, 0 cached objects, 0 allocated objects]
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: PBX Configuration:-
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Voicemail Pro mode, locale: enu, IPO hardware mode: 03 [USA]
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: EVML:-
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Maximum recording capacity: Unlimited, Maximum Recording Time: 120 seconds
17/12 12:37:34.111 vmprov5s (09,5) a90, 2dc: Maximum Sessions: 4, Minimum PIN length: 0 digits
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: SMTP:-
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: Host address 172.20.2.13, port 25, Login method "none", email from "", login user ""
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: Memory statistics:-
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: Physical Memory: 36% in use, 4192792 KB (Available: 2658380 KB)
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: Commit Charge Limit: 8639088 KB, (Available to commit: 7246632 KB)
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: Virtual memory: 2097024 KB, (Available: 1928504 KB, Extended available: 0 KB)
17/12 12:37:34.112 vmprov5s (09,5) a90, 2dc: ======================================================================
17/12 12:37:54.114 vmprov5s (29,5) a90, 2dc: > VMProWorkerThread::RemoveLongestIdleThreads(age=3600000)
17/12 12:37:54.114 vmprov5s (29,5) a90, 2dc: < VMProWorkerThread::RemoveLongestIdleThreads()
17/12 12:37:54.114 vmprov5s (19,1) a90, 2dc: VMIsMAPIAvailable returning [0]
17/12 12:37:54.114 vmprov5s (19,5) a90, 2dc: CMAPIImpl::CheckMAPIConnection() - return is 0, m_iMAPIStatus = [0]
17/12 12:37:54.114 vmprov5s (19,5) a90, 2dc: MAPIServiceAddress is either empty or default to ipaddress. So retruning back CMAPIImpl::Reconnect 824
​

I'm not sure what is or isn't an error? Anyone see a problem here?

 

[CarGoSki]

3. Voicemail pro Logs folder shows 2 log files growing (slowly) at the same time. Files continue to grow until they reach 18,496KB. Looking into the log file, the end shows :

If you view that file more carefully you may find that it contains all of the attempts to send to the same mail with a smtp failure listed.
If so you may have to go extract the wav file to unjamit. Yes that is a new word.