ZCB Authentication Problem

[md_detroit]

Using the latest version of ZCB and BES 4.1, we seem to be having something simple as an authentication problem between BES and ZCS.

We have established a Global Administrator account for the BES in Zimbra. It seems to have full admin capabilities on the admin web interface (i.e., logging in with this account we can create other accounts, as well as view other account's email, etc). However, when we use the BES command line tool on the BES server to test the activation of any other user account (other than that of the BES admin account in Zimbra) it fails the test of trying to create the IMAP folder for that user account. It will create the test IMAP folder and delete it for itself just fine, so we know it is resolving the Zimbra mail server and able to access it's own account on it.

Is there something we need to do in the COS (we're using the default) in order for the BES admin account to be able to access the normal user email accounts in Zimbra so it can read the mail sent by RIM and do its process to sync the Blackberry? Or perhaps something we need to implement server-side on the Zimbra server to allow the BES admin account to manipulate other users accounts?

The process should work like this:

1. User goes to authorize Blackberry by configuring email and BES password we set for it.
2. RIM sends email to user account.
3. BES Admin account constantly monitors user's Zimbra email account for the RIM email w/ attachment, finds it, does its routine to start the sync and delete the email.

We're stuck on #3. Like I said, it will access the BES Admin Zimbra account just fine, but cannot manipulate anyone else's email, as it should be able to with the Global Administrator access.

Any suggestions?

Thanx!

[md_detroit]

Just to give you an idea of what I mean. This is the test of the server where it is successful (using the BES Admin account we created on the zimbra server):

C:\Program Files\Research In Motion\BlackBerry Enterprise Server\Utility>iemstes
t.exe
BlackBerry Enterprise Server Utility - IEMSTest.exe (IExchangeManageStore), Vers
ion 1.0
Copyright (c) Research In Motion, Ltd. 1999. All rights reserved.
Opening Default Message Store Zimbra - Blackberry Administrator.
Opening message store for Blackberry Administrator using besadmin@pilot.testemail.org
 /o=pilot.testemail.org/ou=First Administrative Group/cn=Configuration/cn=Serv
ers/cn=pilot.testemail.org/cn=Microsoft Private MDB.
Blackberry Administrator's Mailbox opened successfully.
Root Folder opened successfully.
Folder created successfully.
Test folder deleted successfully.
Test completed successfully for Blackberry Administrator.

and this is what happens when we try the test with a user's account:

C:\Program Files\Research In Motion\BlackBerry Enterprise Server\Utility>iemstes
t.exe
BlackBerry Enterprise Server Utility - IEMSTest.exe (IExchangeManageStore), Vers
ion 1.0
Copyright (c) Research In Motion, Ltd. 1999. All rights reserved.
Opening Default Message Store Zimbra - Blackberry Administrator.
Opening message store for Mark D using markd@pilot.testemail.org 
/o=pilot.testemail.org/ou=First Administrative
Group/cn=Configuration/cn=Servers/cn=pilot.testemail.org
/cn=Microsoft Private MDB.
CreateStoreEntryID failed (80004005).

So, it can access it's own account, but cannot access anyone else's account, though it has Global Administrator access on the Zimbra server.

Is there something we missed on the Zimbra server side?

[md_detroit]

From the Zimbra logs, it is sitting at this when trying to sync another account other than itself:

2009-10-08 12:53:09,287 INFO  [btpool0-84] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest

when it's successful (when attempting on it's own account), the log says this:

2009-10-08 12:54:39,732 INFO  [btpool0-84] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest
2009-10-08 12:54:47,346 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - CheckLicenseRequest
2009-10-08 12:54:47,356 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - GetInfoRequest
2009-10-08 12:54:47,372 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - GetAccountInfoRequest
2009-10-08 12:54:47,379 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminCreateWaitSetRequest
2009-10-08 12:54:47,393 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest
2009-10-08 12:54:47,420 INFO  [btpool0-84] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - SyncGalRequest
2009-10-08 12:54:48,244 INFO  [btpool0-84] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest
2009-10-08 12:54:48,461 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - SyncRequest
2009-10-08 12:54:48,574 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest
2009-10-08 12:54:51,468 INFO  [btpool0-84] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - SyncRequest
2009-10-08 12:54:58,545 INFO  [btpool0-66] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminDestroyWaitSetRequest
2009-10-08 12:54:58,549 INFO  [btpool0-84] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest

[eugener]

Please try the following:

- enable zcb logging
- execute IEMSTest.exe for offending user
- find corresponding zcb log file that has 'IEMSTest.exe' component in the name
- look for CreateStoreEntryId
- post portion of the log covering execution of the function mentioned in the previous step

[md_detroit]

ahh.. errors about not being able to get eid of the user, and then some 500 internal server errors:

08-10-2009 16:06:07.257 [5804]: In Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. Msg Store DN /o=pilot.testemail.org/ou=First Administrative Group/cn=Configuration/cn=Servers/cn=pilot.testemail.org/cn=Microsoft Private MDB, Mailbox DN markd@pilot.testemail.org, Flags 0x9
08-10-2009 16:06:07.257 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. trying to get the sync lock...
08-10-2009 16:06:07.257 [5804]: Zimbra::Util::GlobalSyncLock::GetSyncLock. got the sync lock, we can sync
08-10-2009 16:06:07.257 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. got the sync lock...
08-10-2009 16:06:07.257 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. Waiting for GAL sync to complete
08-10-2009 16:06:07.257 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. Dispatching message 0xc11a. HWND 0x80226
08-10-2009 16:06:07.257 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. Dispatching message 0xc11a. HWND 0x80226
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. Dispatching message 0xc11a. HWND 0x80226
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. Dispatching message 0xc11a. HWND 0x80226
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. GAL sync is complete
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. trying to get eid for user: fisher@dwsd.org
08-10-2009 16:06:07.272 [5804]: In Zimbra::Store::StoreContextManager::GetMailboxEidForUser
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::StoreContextManager::GetMailboxEidForUser. could not find the entry id in the map, looking in the profile for: markd@pilot.testemail.org
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Rpc::UserSession::GetSupportObject - m_pMapiSup = 0x00f22c28
08-10-2009 16:06:07.272 [5804]: Zimbra::Mapi::GetProfileParamProps. trying to get PR_SERVICE_UID, PR_ZIMBRA_USER_ID from the profile section (1)
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps - # of properties retrieved from profile: 19
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #0 property tag: 0x6640001f
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #1 property tag: 0x66430003
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #2 property tag: 0x6641001f
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #3 property tag: 0x66420102
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #4 property tag: 0x6644000b
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #5 property tag: 0x66550003
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #5 property value:      0x1
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #6 property tag: 0x6656000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #7 property tag: 0x6657000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #8 property tag: 0x6645001f
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #9 property tag: 0x6646001f
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #10 property tag: 0x66470102
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #11 property tag: 0x6648000b
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #12 property tag: 0x6649000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #13 property tag: 0x6650000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #14 property tag: 0x6652000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #15 property tag: 0x6651000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #16 property tag: 0x3d0c000a
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #17 property tag: 0x3d12001f
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Mapi::GetProfileParamProps #18 property tag: 0x66580003
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::StoreContextManager::GetMailboxEidForUserFromProfile. services table has 0 entries
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::StoreContextManager::GetMailboxEidForUserFromProfile. no entries in the service table after the restriction
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::StoreContextManager::GetMailboxEidForUser. +++++++++++++++++++++++++++++++++++++
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::StoreContextManager::GetMailboxEidForUser. could not find the mailbox EID for markd@pilot.testemail.org...even in the profile!!!
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::StoreContextManager::GetMailboxEidForUser. +++++++++++++++++++++++++++++++++++++
08-10-2009 16:06:07.272 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. couldn't find the EID for the user [markd@pilot.testemail.org] in an existing store...
08-10-2009 16:06:07.272 [5804]: DEBUG: Zimbra::Rpc::UserSession::GetSupportObject - m_pMapiSup = 0x00f22c28
08-10-2009 16:06:07.616 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. found the user in the GAL.
08-10-2009 16:06:07.616 [5804]: TRACING => Zimbra::Rpc::UserSession::GetInstance
08-10-2009 16:06:07.616 [5804]: DEBUG: Zimbra::Rpc::UserSession::GetInstance - get a user session (0x2437808)
08-10-2009 16:06:07.616 [5804]: Zimbra::Store::CZimbraExchangeManageStore::CreateStoreEntryID. getting the user's zimbra ID from the session.
08-10-2009 16:06:07.616 [5804]: *9* Enter Zimbra::Rpc::Connection::SendRequest ...
08-10-2009 16:06:07.616 [5804]: DEBUG: Zimbra::Rpc::Connection::Connect - thread 5804
08-10-2009 16:06:07.616 [5804]: *9* <<<<-------- HTTP stream Start (Request) ----------------------------------------------->>>>
08-10-2009 16:06:07.678 [5804]: *9* HTTP Headers:
08-10-2009 16:06:07.678 [5804]: POST /service/admin/soap/ HTTP/1.1
Content-Type: application/soap+xml; charset=utf-8
User-Agent: Zimbra-ZCB/5.0.2711.18 (5.2.3790 Service Pack 2; en-US)
Host: pilot.testemail.org:7071
Content-Length: 631
Connection: Keep-Alive
Cache-Control: no-cache
Pragma: no-cache
08-10-2009 16:06:07.678 [5804]: *9* HTTP body:
<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"><userAgent name="ZimbraConnectorForBES" version="5.0.2711.18"/><nonotify/><noqualify/><authToken>0_0d379862ffa6a883255625b08b3f956e83d2ad95_69643d33363a66343661366435352d626132652d343538392d393766352d3432356563333539666266613b6578703d31333a313235353037353933313331393b61646d696e3d313a313b747970653d363a7a696d6272613b</authToken><nosession/></context></soap:Header><soap:Body><GetAccountInfoRequest xmlns="urn:zimbraAccount"><account by="name">markd@pilot.testemail.org</account></GetAccountInfoRequest></soap:Body></soap:Envelope>
08-10-2009 16:06:07.678 [5804]: *9* <<<<-------- HTTP stream End (Request) ----------------------------------------------->>>>
08-10-2009 16:06:07.678 [5804]: *9* <<<<-------- HTTP stream Start (Response) ----------------------------------------------->>>>
08-10-2009 16:06:07.678 [5804]: *9* DEBUG: in Zimbra::Rpc::Connection::ReadResponseFully - content-length in http response header: 518
08-10-2009 16:06:07.678 [5804]: *9* HTTP Headers:
08-10-2009 16:06:07.678 [5804]: HTTP/1.1 500 Internal Server Error

The 500 internal server errors continue in the log.

Not sure what might be causing those. Like I said, what's really strange is when attempting to do the IEMSTest on the Besadmin account itself, it works just fine. Just doesn't work when trying to do another user.

[eugener]

The offending line is:

"HTTP/1.1 500 Internal Server Error" that was returned in response to GetAccountInfoRequest. I would look in zimbra server log(mailbox.log) to get more info on the error. Please post portion of server log covering 08-10-2009 16:06:07.678

[md_detroit]

again, in the mailbox log, this is what we get (as posted above)

2009-10-08 16:06:27,642 INFO  [btpool0-12] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest
2009-10-08 16:06:28,651 INFO  [btpool0-10] [name=besadmin@pilot.testemail.org;mid=54;ip=172.16.216.169;ua=ZimbraConnectorForBES/5.0.2711.18;] soap - AdminWaitSetRequest

nothing else. it's just sitting at adminwaitsetrequest.

[eugener]

Please open up support case and include the reference to this post. Support team will need to investigate what happened on the server during execution of GetAccountInfoRequest.

[peters]

Could you please tell me how this is solved

[phoenix]

Please update your forum profile with the output of the following command (do not post the output in this thread):

zmcontrol -v

Originally Posted by peters

Could you please tell me how this is solved

Who said it was fixed? You should follow the instructions in the post above yours and open a support case and reference this thread. It needs to be investigated by support staff.