Thread: Mail for Exchange (MfE). Blame me here, pls
View Single Post
bmouring is offline bmouring
2010-01-25 , 21:17
Posts: 36 | Thanked: 20 times | Joined on Nov 2009 @ Austin, TX
#1009
vitaly,

Excellent work on this, I see that the "server exists at a URL that contains more than just FQDN" issue I was seeing has been fixed in the 1.1 release, and I can certainly get further along, but I now see a new issue.

When I setup the account according to my workplace's EAS instructions, I get to the point where it's going to attempt the first synchronization when it reports that "Mandatory Exchange server policy failed. Access refused". What's got me going is that other (to my knowledge) non-provisionable devices work fine when syncing to the server. Following are some pertinent logs from my device and the server (sanitized for personal info)

From server:
Code:
---SNIP---
[01/19 15:46:57.462] INFO    Worker-069 MY_USER_NAME[MY_IMEI] WorkManager$WorkerRunnable.run#502 Device sent a policy key of null which is zero or does not match the server stored policy key of null, so a 449 HTTP return code will be sent
[01/19 15:46:57.462] MY_IP SERVER_IP "MY_USER_NAME" action=syncAS dm 449 0 "N900/1.1" MY_IMEI 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
---SNIP---
From phone:
Code:
---SNIP---
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: FolderSync started
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl: getFolderSyncKey enter
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl: getFolderSyncKey end
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: FolderSync restart with SyncKey=0
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl: clearStorage enter
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl: setFolderSyncKey enter, aSyncKey=0
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl: setFolderSyncKey end, res=0
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl: clearStorage end
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: Sending FolderSync request...
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: CurlConnectionManager: sendReceive: enter
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON: ICListener IAPs count = 1
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON: ICListener proxyHost: usessl = 1, proxy_host = (null)
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: HTTP REQUEST:  POST https://URL_OF_EAS_SERVER/Microsoft-Server-ActiveSync?Cmd=FolderSync&DeviceId=MY_IMEI&DeviceType=SmartPhone
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-CONN: startSession start, aWait=30 seconds
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-CONN: CURL-CONN-CALLBACK: Action=2
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-CONN: CURL-CONN-CALLBACK: Action=1
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-PING: Ping is disabled.. Ignore Ping action
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-CONN: CURL-CONN-CALLBACK: Action=4
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-CONN: startSession end, ret=0
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-PERF: Transfered 613 bytes in 0 seconds. Transfer rate is 0 Kb/sec
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: CurlConnectionManager: sendReceive attempt 1: CancelErr=0
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: HTTP REQUEST headers:
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: User-Agent: N900/1.1
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Host: URL_OF_EAS_SERVER
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Connection: Keep-Alive
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Authorization: <skipped>
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: MS-ASProtocolVersion: 2.5
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Content-Type: application/vnd.ms-sync.wbxml
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Content-Length: 13
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: HTTP STATUS: 449
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: HTTP RESPONSE headers:
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Cache-Control: no-cache
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Connection: close
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Content-Length: 180
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Content-Type: text/html
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Date: Fri, 22 Jan 2010 21:44:25 GMT
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Expires: Fri, 22 Jan 2010 21:44:25 GMT
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Pragma: no-cache
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Server: Lotus-Domino
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: Set-Cookie: LtpaToken=AAECAzRCN...
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: FolderSync response received (449)
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: FolderSync ends with status 449
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: Action execution ends with status 449
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: FolderSync failed with status 449. Abort retrieving estimations
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AS-LIB: Action execution ends with status 449
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ActionFullSync: ItemEstimate failed with status 449. Abort.
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ActionFullSync::doExecute end
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ActionWarpper - action completed with result 449
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: SyncScheduler::onSyncCompleted aStatus=449, mForcedSchedule=-1
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: StoreProxyImpl::freeSpaceAvailable avail=310392, blocks=516052, aSize=0, bs
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: UiNotifier::showInfoBanner aId=8
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: UiNotifier::showInfoBanner aText=Mandatory Exchange server policy failed. Access refused.
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: QString StoreProxyImpl::getUpdatedItems()
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: currentUploaded=''
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: ASDAEMON-SYNC: Sync mail complete: Camel ActiveSync provider is notified
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AsStatusManager::handleSyncCompleted(1, 449)
Jan 22 15:44:23 Nokia-N900-51-1 activesync[1591]: AsStatusManager::handleSyncFailed(1, 1, 8)
---SNIP---
Note the HTTP 449 return code, which seems to be linked to provisioning, but as I said above, I am almost certain that non-provisionable devices work with the server.

Anyone seen something similar? vitaly, thoughts? Additional troubleshooting steps?

EDIT incomplete thought completed
Last edited by bmouring; 2010-01-25 at 21:34.