post BES-server rebuild... errors (?)

[gnyce]

Just re-built our BES server (was using a beta ZCB), so all up to date on BES 4.1, with Outlook 2007 (w/out SP2), and GA release of ZCB. Everything has seemed ok, testing with just one BB at this point. Server stopped syncing to that account last night... here is what I'm seeign in the MAGT log - but after server restart, he is getting info, so not sure what I should be looking for/at. I have logs from _before_ the BES restart this morning, if needed. Any of this significant?

[40267] (06/30 07:53:31.484):{0xDA0} {secure@me.net} Starting calendar rescan
[40136] (06/30 07:53:31.500):{0xDA0} CalICSAgent::GetDirectoryName synch directory retrieved from registry: C:\Program Files\Research In Motion\BlackBerry Enterprise Server\Agents\ICSSync\ for secure@me.net
[10007] (06/30 07:53:31.500):{0xDA0} CalICSSynchronizer::Initialize - OpenProperty failed: (0x80004002)
[20041] (06/30 07:53:31.500):{0xDA0} CalICSAgent::Start Could not Initialize Synchronizer for secure@me.net: (0x80004002)
[30020] (06/30 07:53:31.500):{0xDA0} {secure@me.net} MAPIMailbox:oICS ICS Start failed
[20280] (06/30 07:53:31.500):{0xDA0} {secure@me.net} DoICS() failed: ERR_FAIL

____________

Restart of BES services....
____________

[40700] (06/30 08:43:49.812):{0xE58} {secure@me.net} Receiving packet from device, size=125, TransactionId=387161159, Tag=158, content type=CICAL, cmd=0x3
[40000] (06/30 08:43:49.812):{0xE58} {secure@me.net}-HandleAppointmentToSynchronize-Entering-Tag=158
[40000] (06/30 08:43:49.812):{0xE58} {secure@me.net}-HandleAppointmentToSynchronize-Received Slow Sync SessionID=0x4a4a0839 Cal item with Tag=158 from device, Outstanding Cal items=2
[30193] (06/30 08:43:49.812):{0xE58} {secure@me.net} Receiving calendar update from device, RefId=-1931988351, Tag=158, TransactionId=387161159
[40000] (06/30 08:43:49.812):{0xE58} Starting new CDO helper 0bdfb150
[40574] (06/30 08:43:49.937):{0xAB4} CDO helper 0bdfb150 started, PID 2648
[40000] (06/30 08:43:50.203):{0xB20} [BIPP] Received status DELIVERED, Tag=308
[40000] (06/30 08:43:50.515):{0xB20} [BIPP] Received status DELIVERED, Tag=309
[30001] (06/30 08:43:52.453):{0xAB4} CDOCalendar::Initialize - Code = 800406f9, WCode = 04f9, Code meaning = IDispatch error #1273,
[30002] (06/30 08:43:52.453):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]
[30180] (06/30 08:43:52.453):{0xAB4} {secure@me.net} CDOCalendar::Initialize - Error in call m_spCalendarFolder = m_spCDOSession->GetDefaultFolder
[40000] (06/30 08:43:52.453):{0xAB4} CDO initializing failure in CDO helper 0bdfb150 (1)
[30001] (06/30 08:43:55.875):{0xAB4} CDOCalendar::Initialize - Code = 800406f9, WCode = 04f9, Code meaning = IDispatch error #1273,
[30002] (06/30 08:43:55.875):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]
[30180] (06/30 08:43:55.875):{0xAB4} {secure@me.net} CDOCalendar::Initialize - Error in call m_spCalendarFolder = m_spCDOSession->GetDefaultFolder
[40000] (06/30 08:43:55.875):{0xAB4} CDO initializing failure in CDO helper 0bdfb150 (2)
[30001] (06/30 08:43:59.000):{0xAB4} CDOCalendar::Initialize - Code = 800406f9, WCode = 04f9, Code meaning = IDispatch error #1273,
[30002] (06/30 08:43:59.000):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]
[30180] (06/30 08:43:59.000):{0xAB4} {secure@me.net} CDOCalendar::Initialize - Error in call m_spCalendarFolder = m_spCDOSession->GetDefaultFolder
[40000] (06/30 08:43:59.000):{0xAB4} CDO initializing failure in CDO helper 0bdfb150 (3)
[30001] (06/30 08:44:02.015):{0xAB4} CDOCalendar::Initialize - Code = 800406f9, WCode = 04f9, Code meaning = IDispatch error #1273,
[30002] (06/30 08:44:02.015):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]
[30180] (06/30 08:44:02.015):{0xAB4} {secure@me.net} CDOCalendar::Initialize - Error in call m_spCalendarFolder = m_spCDOSession->GetDefaultFolder
[40000] (06/30 08:44:02.015):{0xAB4} CDO initializing failure in CDO helper 0bdfb150 (4)
[40000] (06/30 08:44:03.046):{0xB20} [BIPP] Received datagram, Tag=159
[30001] (06/30 08:44:05.031):{0xAB4} CDOCalendar::Initialize - Code = 800406f9, WCode = 04f9, Code meaning = IDispatch error #1273,
[30002] (06/30 08:44:05.031):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]
[30180] (06/30 08:44:05.031):{0xAB4} {secure@me.net} CDOCalendar::Initialize - Error in call m_spCalendarFolder = m_spCDOSession->GetDefaultFolder
[40000] (06/30 08:44:05.031):{0xAB4} CDO initializing failure in CDO helper 0bdfb150 (5)
[40580] (06/30 08:44:06.031):{0xAB4} CDO helper 0bdfb150 closing after CDO initialize failure
[40000] (06/30 08:44:06.234):{0xAB4} CalHelper failed 0bdfb150, ErrorCode = -11, Thread activity was Checking CDO object list
[40577] (06/30 08:44:06.937):{0xAB4} CDO helper 0bdfb150 stopped
[40000] (06/30 08:44:10.312):{0xB20} [BIPP] Received datagram, Tag=160
[40000] (06/30 08:44:16.031):{0xE58} {secure@me.net} Retrying (2) CDO helper 0bdfb150 call in RunCalHelper
[40000] (06/30 08:44:16.031):{0xE58} CDO helper 0bdfb150 is not in memory
[40000] (06/30 08:44:16.031):{0xE58} Starting new CDO helper 0bdfb150
[40574] (06/30 08:44:16.156):{0xAB4} CDO helper 0bdfb150 started, PID 2272
[30001] (06/30 08:44:18.671):{0xAB4} CDOCalendar::Initialize - Code = 800406f9, WCode = 04f9, Code meaning = IDispatch error #1273,
[30002] (06/30 08:44:18.671):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]


continues on for numerous lines... and a bunch of these as well.....

[40000] (06/30 08:43:44.437):{0xE58} {secure@me.net}-GetTZIndexByTZName-Unrecognized time zone string (GMT-05.00) Eastern Time (US & Canada)
[30000] (06/30 08:43:44.437):{0xE58} {secure@me.net}-GetRIMCalendar(EntryID)- GetTZIndexByTZName() failed Entry tag =1327
[40406] (06/30 08:43:44.453):{0xE58} {secure@me.net} CDOCalendar::ExpandPrivateDL - pContactsFolder->FindRow (0x8004010f) failed
[40406] (06/30 08:43:44.453):{0xE58} {secure@me.net} CDOCalendar::ExpandPrivateDL - pContactsFolder->FindRow (0x8004010f) failed
[40406] (06/30 08:43:44.453):{0xE58} {secure@me.net} CDOCalendar::ExpandPrivateDL - pContactsFolder->FindRow (0x8004010f) failed
[40406] (06/30 08:43:44.453):{0xE58} {secure@me.net} CDOCalendar::ExpandPrivateDL - pContactsFolder->FindRow (0x8004010f) failed
[40406] (06/30 08:43:44.453):{0xE58} {secure@me.net} CDOCalendar::ExpandPrivateDL - pContactsFolder->FindRow (0x8004010f) failed
[40406] (06/30 08:43:44.453):{0xE58} {secure@me.net} CDOCalendar::ExpandPrivateDL - pContactsFolder->FindRow (0x8004010f) failed

[eugener]

One of the errors listed above may affect capability of device to push calendar related changes over to zimbra server. The following message

[30002] (06/30 08:44:02.015):{0xAB4} Server = mail.server.com, Mailbox = secure@me.net Description = The information store could not be opened. [MAPI 1.0 - [MAPI_E_LOGON_FAILED(80040111)]]

indicates that CalHelper had troubles logging into the temporary profile. Please try to to repair connector in attempt to resolve this:

- stop BB controller, stop BB manager
- make sure that processes 'Calhelper.exe', 'Outlook.exe' are not running
- go to add/remove programs, step on zcb line and hit <Change> and then choose to 'Repair..'
- start BB controller

[gnyce]

OK, did that. Also found there is a slight different between the CDO 1.2.1 and the Exchange MAPI CDO 1.2.1. Anyway, bottom line is, the server stops syncing within a 24-hour period. I've been working around it by stopping/starting BES services, but can't survive that way.

Looking at the MAGT logs, it appears that it is scanning for new messages to sync, but seems to think all is well/the same. After restarting BES services, a whole host of messages get pushed out. So clearly something is not right.

I can open a support ticket, or work with it here, but I'll need to do something before I put more people on this (right now just serving up on BB device).

______________

MAGT entry when server not syncing items:

[40702] (07/09 08:12:33.529):{0x754} {secure@me.net} Starting message rescan
[40703] (07/09 08:12:33.529):{0x754} {secure@me.net} Message rescan completed

After restart of BES services:

[40423] (07/09 08:34:26.670):{0x1630} {secure@me.net} Queuing new mail through notification (external). EntryId=1195
[40724] (07/09 08:34:26.670):{0x12EC} {secure@me.net} Get record key for this MAPI object, EntryId=1195
[40435] (07/09 08:34:26.685):{0x12EC} {secure@me.net} Queuing new mail through notification. EntryId=1195. Msgs Pending 0
[20499] (07/09 08:34:26.857):{0x1630} {secure@me.net} MsgMemStateDb::GetRefIdByEntryId(uc*,l) - EntryId is 0
[30085] (07/09 08:34:26.857):{0x12EC} {secure@me.net} New mail has arrived, EntryId=1195
[20501] (07/09 08:34:26.873):{0x12EC} {secure@me.net} MsgMemStateDb::AddMessageState - EntryId is invalid
[20499] (07/09 08:34:26.888):{0x1630} {secure@me.net} MsgMemStateDb::GetRefIdByEntryId(uc*,l) - EntryId is 0
[40287] (07/09 08:34:26.935):{0x12EC} {secure@me.net} Queuing message, RefId=-860940461, EntryId=1195, Posted=07/08 21:55:13, Delivered=07/08 22:11:12
[30066] (07/09 08:34:26.935):{0x12EC} Total Msgs Pending 1

[gnyce]

So I upgraded to the 5.0.18 ZCB version, as well as applied Outlook 2007 sp2 updates. So far I have not had to stop/restart the BB services to correct anything, I'm going on 44 hours with it working properly. Granted, this is only with 2 blackberry devices connected, but we're head-and-shoulders above how it was the previous week... I'm encouraged.

[gnyce]

Up to 6 days.... restarted once after adding a new user, but not certain if that was required, but one user _did_ get a server failure during that time, so just to be safe. This is much improved from my previous experience (post-rebuild but pre-5.0.18 ZCB)