6.0.0-alpha14
6/25/25

[#12765] Permission Denied ERR with ActiveSync
Summary Permission Denied ERR with ActiveSync
Queue Synchronization
Queue Version Git master
Type Bug
State Resolved
Priority 1. Low
Owners mrubinsk (at) horde (dot) org
Requester lst_hoe02 (at) kwsoft (dot) de
Created 10/15/2013 (4271 days ago)
Due
Updated 11/22/2013 (4233 days ago)
Assigned
Resolved 10/16/2013 (4270 days ago)
Github Issue Link
Github Pull Request
Milestone
Patch No

History
11/22/2013 06:30:14 PM registrations (at) baruchgreen (dot) net Comment #10 Reply to this comment
If resetting your syncronization preferences for kronolith does not 
solve this for you then you are going to have to track this down. I 
can't reproduce it.
Strange.  I'd never changed the sync preferences (is and always has 
been my default calendar).  But simply pressing "save" on the 
preferences page w/o making any changes does appear to have solved the 
issue.

Not sure what was going on.  But thanks!
11/22/2013 06:09:07 PM Michael Rubinsky Comment #9 Reply to this comment
If resetting your syncronization preferences for kronolith does not 
solve this for you then you are going to have to track this down. I 
can't reproduce it.
11/22/2013 05:35:07 PM registrations (at) baruchgreen (dot) net Comment #8 Reply to this comment
I'm still getting the same set of errors reported from the outset of 
this bug (see below).  I've got Horde_Core 2.11.1 and Horde_ActiveSync 
2.9.1 installed.

Any suggestions?

2013-11-22T12:33:30-05:00 INFO: [30874] Initializing state for 
collection: @Tasks@, synckey: {528d3a2c-3878-4188-9e70-6825c0a80037}3
2013-11-22T12:33:30-05:00 INFO: [30874] Loading state for synckey 
{528d3a2c-3878-4188-9e70-6825c0a80037}3
2013-11-22T12:33:30-05:00 INFO: [30874] Initializing message diff 
engine for @Tasks@ (@Tasks@)
2013-11-22T12:33:30-05:00 INFO: [30874] Using SYNCSTAMP 48357 for @Tasks@.
2013-11-22T12:33:30-05:00 INFO: [30874] 
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 48357, 48357, 
0, 1)
2013-11-22T12:33:30-05:00 INFO: [30874] Fetching changes for tasks 
using MODSEQ.
2013-11-22T12:33:30-05:00 INFO: [30874] Found 0 message changes in @Tasks@.
2013-11-22T12:33:30-05:00 INFO: [30874] Initializing state for 
collection: @Contacts@, synckey: {528d3a2a-64f4-435f-bd9a-6825c0a8003
7}19
2013-11-22T12:33:30-05:00 INFO: [30874] Loading state for synckey 
{528d3a2a-64f4-435f-bd9a-6825c0a80037}19
2013-11-22T12:33:30-05:00 INFO: [30874] Initializing message diff 
engine for @Contacts@ (@Contacts@)
2013-11-22T12:33:30-05:00 INFO: [30874] Using SYNCSTAMP 48360 for @Contacts@.
2013-11-22T12:33:30-05:00 INFO: [30874] 
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 48360, 
48360, 0, 1)
2013-11-22T12:33:30-05:00 INFO: [30874] Fetching changes for contacts 
using MODSEQ.
2013-11-22T12:33:30-05:00 INFO: [30874] Found 0 message changes in @Contacts@.
2013-11-22T12:33:30-05:00 INFO: [30874] Initializing state for 
collection: @Calendar@, synckey: {528d3a2c-82c0-489f-8417-6824c0a8003
7}6
2013-11-22T12:33:30-05:00 INFO: [30874] Loading state for synckey 
{528d3a2c-82c0-489f-8417-6824c0a80037}6
2013-11-22T12:33:30-05:00 INFO: [30874] Initializing message diff 
engine for @Calendar@ (@Calendar@)
2013-11-22T12:33:30-05:00 INFO: [30874] Using SYNCSTAMP 48376 for @Calendar@.
2013-11-22T12:33:30-05:00 INFO: [30874] 
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 48364, 
48376, 1383932010, 1)
2013-11-22T12:33:30-05:00 INFO: [30874] Fetching changes for calendar 
using MODSEQ.
2013-11-22T12:33:30-05:00 INFO: [30874] Polling for SOFTDELETE items 
in calendar collection
2013-11-22T12:33:30-05:00 ERR: Permission Denied
10/22/2013 02:18:04 PM nimm (at) technikum-wien (dot) at Comment #7 Reply to this comment
(Username masked) not found [pid 22168 on line 199 of
"/usr/share/php/Horde/Share/Base.php"]
This sounds like your default calendar or sync calendar preference 
needs to be updated.
Thanks for the hint, I had a wrong prefs_init hook modifying the sync 
calendar preference, now it works!


10/22/2013 01:28:41 PM Michael Rubinsky Comment #6 Reply to this comment
Horde_Core 2.10.1
The upgrade to Horde_Core 2.10.1 didn't fix this for me:

Horde log says:
2013-10-22T09:05:31+02:00 ERR: HORDE [kronolith] Share name XXXXX 
(Username masked) not found [pid 22168 on line 199 of 
"/usr/share/php/Horde/Share/Base.php"]
This sounds like your default calendar or sync calendar preference 
needs to be updated.

10/22/2013 07:13:27 AM nimm (at) technikum-wien (dot) at Comment #5 Reply to this comment
Horde_Core 2.10.1
The upgrade to Horde_Core 2.10.1 didn't fix this for me:

Horde log says:
2013-10-22T09:05:31+02:00 ERR: HORDE [kronolith] Share name XXXXX 
(Username masked) not found [pid 22168 on line 199 of 
"/usr/share/php/Horde/Share/Base.php"]
2013-10-22T09:05:31+02:00 ERR: HORDE [horde] Returning HTTP 500 while 
handling Ping command. [pid 22168 on line 156 of 
"/var/www/horde/rpc.php"]
2013-10-22T09:05:31+02:00 ERR: HORDE [horde] Error in communicating 
with ActiveSync server: Permission Denied [pid 22168 on line 162 of 
"/usr/share/php/Horde/Rpc/ActiveSync.php"]
2013-10-22T09:05:31+02:00 ERR: HORDE [horde] #0 [internal function]: 
Kronolith_Api->listEvents(0, 1381215931, Array, false, false, false, 
true, false)
#1 /usr/share/php/Horde/Registry.php(1116): call_user_func_array(Array, Array)
#2 /usr/share/php/Horde/Registry.php(1073): 
Horde_Registry->callByPackage('kronolith', 'listEvents', Array)
#3 /usr/share/php/Horde/Registry/Caller.php(41): 
Horde_Registry->call('calendar/listEv...', Array)
#4 /usr/share/php/Horde/Core/ActiveSync/Connector.php(831): 
Horde_Registry_Caller->__call('listEvents', Array)
#5 /usr/share/php/Horde/Core/ActiveSync/Connector.php(831): 
Horde_Registry_Caller->listEvents(0, 1381215931, Array, false, false, 
false, true, false)
#6 /usr/share/php/Horde/Core/ActiveSync/Driver.php(596): 
Horde_Core_ActiveSync_Connector->softDelete('calendar', 0, 1381215931)
#7 /usr/share/php/Horde/ActiveSync/State/Sql.php(923): 
Horde_Core_ActiveSync_Driver->getServerChanges(Object(Horde_ActiveSync_Folder_Collection), 253112, 253166, 1381215931, true, 
true)
#8 /usr/share/php/Horde/ActiveSync/Collections.php(1146): 
Horde_ActiveSync_State_Sql->getChanges(Array)
#9 /usr/share/php/Horde/ActiveSync/Collections.php(1182): 
Horde_ActiveSync_Collections->getCollectionChanges(true)
#10 /usr/share/php/Horde/ActiveSync/Collections.php(1019): 
Horde_ActiveSync_Collections->getCollectionChangeCount(true)
#11 /usr/share/php/Horde/ActiveSync/Request/Ping.php(208): 
Horde_ActiveSync_Collections->pollForChanges('470', 5, Array)
#12 /usr/share/php/Horde/ActiveSync/Request/Base.php(249): 
Horde_ActiveSync_Request_Ping->_handle()
#13 /usr/share/php/Horde/ActiveSync.php(848): 
Horde_ActiveSync_Request_Base->handle()
#14 /usr/share/php/Horde/Rpc/ActiveSync.php(143): 
Horde_ActiveSync->handleRequest('Ping', 'androidc2033156...')
#15 /var/www/horde/rpc.php(156): Horde_Rpc_ActiveSync->getResponse(NULL)
#16 {main} [pid 22168 on line 162 of 
"/usr/share/php/Horde/Rpc/ActiveSync.php"]
2013-10-22T09:05:31+02:00 ERR: HORDE [horde] Buffer contents:  [pid 
22168 on line 162 of "/usr/share/php/Horde/Rpc/ActiveSync.php"]


10/16/2013 02:04:51 PM Michael Rubinsky Comment #4
State ⇒ Resolved
Assigned to Michael Rubinsky		 Reply to this comment
Horde_Core 2.10.1
10/16/2013 02:04:03 PM Git Commit Comment #3 Reply to this comment
Changes have been made in Git (master):

commit e8c2e2dc91b521a1f6be5a82d21f838eda7dcaec
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date:   Wed Oct 16 09:59:37 2013 -0400

     Need to get a list of syncronized calendars to softdelete.

     Slight hack to get around the data not being available via Kronolith 4's
     public API. Fixes Bug: 12765.

  .../Core/lib/Horde/Core/ActiveSync/Connector.php   |   33 ++++++++++++++++---
  1 files changed, 27 insertions(+), 6 deletions(-)

http://git.horde.org/horde-git/-/commit/e8c2e2dc91b521a1f6be5a82d21f838eda7dcaec
10/16/2013 11:05:45 AM simon (at) simonandkate (dot) net Comment #2 Reply to this comment
Same issue on a Motorola XT910.

Horde log:

2013-10-16T20:48:49+10:00 ERR: HORDE [horde] Returning HTTP 500 while 
handling Ping command. [pid 19290 on line 156 of 
"/var/www/horde/rpc.php"]
2013-10-16T20:48:49+10:00 ERR: HORDE [horde] Error in communicating 
with ActiveSync server: Permission Denied [pid 19290 on line 162 of 
"/usr/share/pear/Horde/Rpc/ActiveSync.php"]
2013-10-16T20:48:49+10:00 ERR: HORDE [horde] #0 [internal function]: 
Kronolith_Api->listEvents(1380627270, 1380710929, NULL, false, false, 
false, true, false)
#1 /usr/share/pear/Horde/Registry.php(1116): 
call_user_func_array(Array, Array)
#2 /usr/share/pear/Horde/Registry.php(1073): 
Horde_Registry->callByPackage('kronolith', 'listEvents', Array)
#3 /usr/share/pear/Horde/Registry/Caller.php(41): 
Horde_Registry->call('calendar/listEv...', Array)
#4 /usr/share/pear/Horde/Core/ActiveSync/Connector.php(811): 
Horde_Registry_Caller->__call('listEvents', Array)
#5 /usr/share/pear/Horde/Core/ActiveSync/Connector.php(811): 
Horde_Registry_Caller->listEvents(1380627270, 1380710929, NULL, false, 
false, false, true, false)
#6 /usr/share/pear/Horde/Core/ActiveSync/Driver.php(596): 
Horde_Core_ActiveSync_Connector->softDelete('calendar', 1380627270, 
1380710929)
#7 /usr/share/pear/Horde/ActiveSync/State/Sql.php(923): 
Horde_Core_ActiveSync_Driver->getServerChanges(Object(Horde_ActiveSync_Folder_Collection), 3471, 3482, 1380710929, true, 
true)
#8 /usr/share/pear/Horde/ActiveSync/Collections.php(1146): 
Horde_ActiveSync_State_Sql->getChanges(Array)
#9 /usr/share/pear/Horde/ActiveSync/Collections.php(1182): 
Horde_ActiveSync_Collections->getCollectionChanges(true)
#10 /usr/share/pear/Horde/ActiveSync/Collections.php(1019): 
Horde_ActiveSync_Collections->getCollectionChangeCount(true)
#11 /usr/share/pear/Horde/ActiveSync/Request/Ping.php(208): 
Horde_ActiveSync_Collections->pollForChanges('470', 30, Array)
#12 /usr/share/pear/Horde/ActiveSync/Request/Base.php(249): 
Horde_ActiveSync_Request_Ping->_handle()
#13 /usr/share/pear/Horde/ActiveSync.php(848): 
Horde_ActiveSync_Request_Base->handle()
#14 /usr/share/pear/Horde/Rpc/ActiveSync.php(143): 
Horde_ActiveSync->handleRequest('Ping', 'androidc1004933...')
#15 /var/www/horde/rpc.php(156): Horde_Rpc_ActiveSync->getResponse(NULL)
#16 {main} [pid 19290 on line 162 of 
"/usr/share/pear/Horde/Rpc/ActiveSync.php"]

Device log for that interaction:

2013-10-16T20:48:49+10:00 INFO: [19290] SyncCache collections refreshed.
2013-10-16T20:48:49+10:00 INFO: [19290] Refreshing a6a55856 from the cache.
2013-10-16T20:48:49+10:00 INFO: [19290] Refreshing @Tasks@ from the cache.
2013-10-16T20:48:49+10:00 INFO: [19290] Refreshing @Contacts@ from the cache.
2013-10-16T20:48:49+10:00 INFO: [19290] Refreshing @Calendar@ from the cache.
2013-10-16T20:48:49+10:00 INFO: [19290] Refreshing 37de1ec2 from the cache.
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing state for 
collection: INBOX, synckey: {525d2842-1a10-4ecc-a018-329fc0a801e6}10
2013-10-16T20:48:49+10:00 INFO: [19290] Loading state for synckey 
{525d2842-1a10-4ecc-a018-329fc0a801e6}10
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing message diff 
engine for a6a55856 (INBOX)
2013-10-16T20:48:49+10:00 INFO: [19290] Using SYNCSTAMP 1381920529 for 
a6a55856.
2013-10-16T20:48:49+10:00 INFO: [19290] 
Horde_Core_ActiveSync_Driver::getServerChanges(INBOX, 1381916410, 
1381920529, 1379501329, 1)
2013-10-16T20:48:49+10:00 INFO: [19290] MODSEQ: 0
2013-10-16T20:48:49+10:00 INFO: [19290] Found 0 message changes in a6a55856.
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing state for 
collection: @Tasks@, synckey: {525d2843-0a44-4028-bea2-33a9c0a801e6}2
2013-10-16T20:48:49+10:00 INFO: [19290] Loading state for synckey 
{525d2843-0a44-4028-bea2-33a9c0a801e6}2
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing message diff 
engine for @Tasks@ (@Tasks@)
2013-10-16T20:48:49+10:00 INFO: [19290] Using SYNCSTAMP 3223 for @Tasks@.
2013-10-16T20:48:49+10:00 INFO: [19290] 
Horde_Core_ActiveSync_Driver::getServerChanges(@Tasks@, 3223, 3223, 0, 
1)
2013-10-16T20:48:49+10:00 INFO: [19290] Fetching changes for tasks 
using MODSEQ.
2013-10-16T20:48:49+10:00 INFO: [19290] Found 0 message changes in @Tasks@.
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing state for 
collection: @Contacts@, synckey: {525d2844-243c-4d6f-bef1-338fc0a801e6}2
2013-10-16T20:48:49+10:00 INFO: [19290] Loading state for synckey 
{525d2844-243c-4d6f-bef1-338fc0a801e6}2
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing message diff 
engine for @Contacts@ (@Contacts@)
2013-10-16T20:48:49+10:00 INFO: [19290] Using SYNCSTAMP 3458 for @Contacts@.
2013-10-16T20:48:49+10:00 INFO: [19290] 
Horde_Core_ActiveSync_Driver::getServerChanges(@Contacts@, 3458, 3458, 
0, 1)
2013-10-16T20:48:49+10:00 INFO: [19290] Fetching changes for contacts 
using MODSEQ.
2013-10-16T20:48:49+10:00 INFO: [19290] Found 0 message changes in @Contacts@.
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing state for 
collection: @Calendar@, synckey: {525d2844-8174-4346-9741-32a1c0a801e6}2
2013-10-16T20:48:49+10:00 INFO: [19290] Loading state for synckey 
{525d2844-8174-4346-9741-32a1c0a801e6}2
2013-10-16T20:48:49+10:00 INFO: [19290] Initializing message diff 
engine for @Calendar@ (@Calendar@)
2013-10-16T20:48:49+10:00 INFO: [19290] Using SYNCSTAMP 3482 for @Calendar@.
2013-10-16T20:48:49+10:00 INFO: [19290] 
Horde_Core_ActiveSync_Driver::getServerChanges(@Calendar@, 3471, 3482, 
1380710929, 1)
2013-10-16T20:48:49+10:00 INFO: [19290] Fetching changes for calendar 
using MODSEQ.
2013-10-16T20:48:49+10:00 INFO: [19290] Polling for SOFTDELETE items 
in calendar collection
2013-10-16T20:48:49+10:00 ERR: Permission Denied

Going into his Kronolith prefs his only calendar appeared in the 
Default Calendar pref already, but I saved it to see if that changes 
it.  He has no other calendars.
10/15/2013 01:55:10 PM lst_hoe02 (at) kwsoft (dot) de Comment #1
Priority ⇒ 1. Low
State ⇒ Unconfirmed
Patch ⇒ No
Milestone ⇒
Queue ⇒ Synchronization
Summary ⇒ Permission Denied ERR with ActiveSync
Type ⇒ Bug		 Reply to this comment
With the latest ActiveSync (Horde_ActiveSync 2.8.3) supporting 
SOFTDELETE the following error pops up:

INFO: [26058] Fetching changes for calendar using MODSEQ.
INFO: [26058] Polling for SOFTDELETE items in calendar collection
ERR: Permission Denied

According to mrubinsk@horde.org:
Two issues going on here. One is that you don't have a configured 
default calendar. Second is that we don't add the list of calendars 
configured to sync other than the default user calendar.

New Ticket
My Tickets
Search
Query Builder
Reports

Saved Queries

Open Bugs
Bugs waiting for Feedback
Open Bugs in Releases
Open Enhancements
Enhancements waiting for Feedback
Bugs with Patches
Enhancements with Patches
Release Showstoppers
Stalled Tickets
New Tickets
Horde 5 Showstoppers