Summary | Activesync: error 500 while handling FolderUpdate |
Queue | Horde Framework Packages |
Queue Version | Git master |
Type | Bug |
State | Resolved |
Priority | 1. Low |
Owners | mrubinsk (at) horde (dot) org |
Requester | software-horde (at) interfasys (dot) ch |
Created | 07/08/2014 (4028 days ago) |
Due | |
Updated | 07/11/2014 (4025 days ago) |
Assigned | 07/10/2014 (4026 days ago) |
Resolved | 07/11/2014 (4025 days ago) |
Github Issue Link | |
Github Pull Request | |
Milestone | |
Patch | No |
State ⇒ Resolved
Fixed for Horde_Core 2.12.5
commit 2c28ef420442261badd33b8613a213bfbdff2522
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Thu Jul 10 22:33:34 2014 -0400
Bug: 13334Fix broken CHANGEFOLDER functionality for NOTES collections..../Core/lib/Horde/Core/ActiveSync/Connector.php | 1 +
1 files changed, 1 insertions(+), 0 deletions(-)
http://github.com/horde/horde/commit/2c28ef420442261badd33b8613a213bfbdff2522
2014-07-10T20:48:43+02:00 ERR: HORDE Returning HTTP 500 while handling
FolderUpdate command. [pid 52217 on line 159 of "/horde/rpc.php"]
2014-07-10T20:48:43+02:00 ERR: HORDE Error in communicating with
ActiveSync server: Share name _siqWNjWBqAIyNNy2m8i not found [pid
52217 on line 162 of "/php/Horde/Rpc/ActiveSync.php"]
2014-07-10T20:48:43+02:00 ERR: HORDE #0
/php/Horde/Share/Base.php(199):
Horde_Share_Sql->_getShare('_siqWNjWBqAIy...')
#1[internal function]: Horde_Share_Base->getShare('_siqWNjWBqAIy...')#2/php/Horde/Core/Share/Driver.php(63): call_user_func_array(Array, Array)#3/horde/nag/lib/Api.php(131):Horde_Core_Share_Driver->__call('getShare', Array)
#4/horde/nag/lib/Api.php(131):Horde_Core_Share_Driver->getShare('_siqWNjWBqAIy...')
#5[internal function]: Nag_Api->getTasklist('_siqWNjWBqAIy...')#6/php/Horde/Registry.php(1136): call_user_func_array(Array, Array)#7/php/Horde/Registry.php(1093): Horde_Registry->callByPackage('nag','getTasklist', Array)
#8/php/Horde/Registry/Caller.php(41):Horde_Registry->call('tasks/getTaskli...', Array)
#9/php/Horde/Core/ActiveSync/Connector.php(1219):Horde_Registry_Caller->__call('getTasklist', Array)
#10/php/Horde/Core/ActiveSync/Connector.php(1219):Horde_Registry_Caller->getTasklist('_siqWNjWBqAIy...')
#11/php/Horde/Core/ActiveSync/Driver.php(718):Horde_Core_ActiveSync_Connector->changeFolder('Notes',
'_siqWNjWBqAIy...', 'Notes (o@of)')
#12/php/Horde/ActiveSync/Connector/Importer.php(347):Horde_Core_ActiveSync_Driver->changeFolder('Notes:_IqHpMZrX...',
'Notes (o@of)', '0', 'N65f21b18', false)
#13 /php/Horde/ActiveSync/Request/FolderCreate.php(149):
Horde_ActiveSync_Connector_Importer->importFolderChange('N65f21b18',
'Notes (o@of)', '0', false)
#14/php/Horde/ActiveSync/Request/Base.php(253):Horde_ActiveSync_Request_FolderCreate->_handle()
#15/php/Horde/ActiveSync.php(880): Horde_ActiveSync_Request_Base->handle()#16/php/Horde/Rpc/ActiveSync.php(143):Horde_ActiveSync->handleRequest('FolderUpdate', 'BB1234ABCD')
#17/horde/rpc.php(159): Horde_Rpc_ActiveSync->getResponse(NULL)#18{main} [pid 52217 on line 162 of "/php/Horde/Rpc/ActiveSync.php"]ActiveSync is looking for a Mnemo share using the Nag driver
The share only exists in mnemo_sharesng, not in nag_sharesng
State ⇒ Assigned
Assigned to Michael Rubinsky
Also, what client is this?
for multiple tasks and notes folder synchronisation.
The error I'm presently seeing is about a note share which is not
found. We're using sharesng, but it shouldn't make a difference, since
everything went fine in the initial sync.
The name of the share (share_name) starts with an underscore and is
followed by an alphanumeric sequence, sorry for calling it _randomised.
_siqWNjWBqAIyNNy2m8i
Also, what client is this?
2014-07-10T19:48:45+02:00 ERR: Share name _randomised not found
The log is similar to what I posted earlier in the log.
I did not make any modifications to the notes in the phone or in
Horde, except for changing the colour of the folder in the phone.
I did move a task from one folder to another, but there is no
complaint about that.
I can see the share in the DB, it has the correct share_owner. That
Notebook was created on an earlier version of Horde and it starts with
an underscore (not sure if it's relevant)
State ⇒ Duplicate
Bug: 13338{53944bcf-adf4-4bd1-b3ca-24b2904cae96}3
2014-07-09T03:40:22+02:00 INFO: [5683] Loading FOLDERSYNC state
containing 12 folders
2014-07-09T03:40:22+02:00 ERR: Share name _randomised not found
no longer available. It was either deleted or renamed, or this user no
longer has permissions to it.
Re-saving the synchronization preferences for this app should rectify
the situation.
between accounts on the device and Horde sync sources.
This is from the sync log:
2014-07-09T03:40:22+02:00 INFO: [5683]
Horde_Core_ActiveSync_Driver::authenticate() attempt for user@domain.tld
2014-07-09T03:40:22+02:00 INFO: [5683] FOLDERUPDATE request received
for user user@domain.tld
2014-07-09T03:40:22+02:00 INFO: [5683] Device entry exists for
BB1234ABCD, updating userAgent and version.
2014-07-09T03:40:22+02:00 INFO: [5683] Request being handled for
device: BB1234ABCD, Supporting protocol version: 14.1, Using
Horde_ActiveSync v2.16.9
2014-07-09T03:40:22+02:00 INFO: [5683] GET VARIABLES: Array
(
[Cmd] => FolderUpdate
[DeviceType] => BlackBerry
[User] => user@domain.tld
[DeviceId] => BB1234ABCD
)
2014-07-09T03:40:22+02:00 INFO: [BB1234ABCD] Handling
FOLDER[CREATE|DELETE|CHANGE] command.
2014-07-09T03:40:22+02:00 DEBUG: [5683] I <FolderHierarchy:FolderUpdate>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I <FolderHierarchy:SyncKey>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I
{53944bcf-adf4-4bd1-b3ca-24b2904cae96}3
2014-07-09T03:40:22+02:00 DEBUG: [5683] I </FolderHierarchy:SyncKey>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I <FolderHierarchy:ServerEntryId>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I Ncf4f9a88
2014-07-09T03:40:22+02:00 DEBUG: [5683] I </FolderHierarchy:ServerEntryId>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I <FolderHierarchy:ParentId>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I 0
2014-07-09T03:40:22+02:00 DEBUG: [5683] I </FolderHierarchy:ParentId>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I <FolderHierarchy:DisplayName>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I Notepad of user@domain.tld
2014-07-09T03:40:22+02:00 DEBUG: [5683] I </FolderHierarchy:DisplayName>
2014-07-09T03:40:22+02:00 DEBUG: [5683] I </FolderHierarchy:FolderUpdate>
2014-07-09T03:40:22+02:00 INFO: [5683] Loading state for synckey
{53944bcf-adf4-4bd1-b3ca-24b2904cae96}3
2014-07-09T03:40:22+02:00 INFO: [5683] Loading FOLDERSYNC state
containing 12 folders.
2014-07-09T03:40:22+02:00 INFO: [5683]
Horde_ActiveSync_Connector_Importer::importFolderChange(Ncf4f9a88,
Notepad of user@domain.tld, 0, )
2014-07-09T03:40:22+02:00 INFO: [5683]
Horde_Core_ActiveSync_Driver::changeFolder(Notes:_randomised, Notepad
of user@domain.tld, 0, Ncf4f9a88, )
2014-07-09T03:40:22+02:00 INFO: [5683] Polling
Horde_Core_ActiveSync_Driver::_getMailFolders()
2014-07-09T03:40:22+02:00 ERR: Share name _randomised not found
Priority ⇒ 1. Low
State ⇒ Unconfirmed
Patch ⇒ No
Milestone ⇒
Summary ⇒ Activesync: error 500 while handling FolderUpdate
Type ⇒ Bug
Queue ⇒ Horde Framework Packages
The logs show this:
T01:35:00+02:00 ERR: HORDE Returning HTTP 500 while handling
FolderUpdate command. [pid 89163 on line 159 of
"/var/www/html/webmail/rpc.php"]
T01:35:00+02:00 ERR: HORDE Error in communicating with ActiveSync
server: Protocol Error [pid 89163 on line 162 of
"/php/lib/php/Horde/Rpc/ActiveSync.php"]
T01:35:00+02:00 ERR: HORDE #0
/php/lib/php/Horde/ActiveSync/Request/Base.php(253):
Horde_ActiveSync_Request_FolderCreate->_handle()
#1/php/lib/php/Horde/ActiveSync.php(880):Horde_ActiveSync_Request_Base->handle()
#2/php/lib/php/Horde/Rpc/ActiveSync.php(143):Horde_ActiveSync->handleRequest('FolderUpdate', 'BBABCD1234')
#3/var/www/html/webmail/rpc.php(159): Horde_Rpc_ActiveSync->getResponse(NULL)#4{main} [pid 89163 on line 162 of "/php/lib/php/Horde/Rpc/ActiveSync.php"]T01:35:00+02:00 ERR: HORDE Buffer contents: [pid 89163 on line 162 of
"/php/lib/php/Horde/Rpc/ActiveSync.php"]