On Mar 6, 2013, at 11:57 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
I can't get 4.x releases to work on Ubuntu ( 12.10 in my case ) x86… and there are no packages for 4.x releases so far? relevant info is hard to find on the Net about how to set it all up. I managed to compile from SVN successfully but the logs fill with errors,
I'm a little more interested in these errors than the ones you're having with 3.2, since 4.x is a lot closer to what we're currently working on in trunk. Can you send them on? Not to say that I wouldn't like you to fix your current errors, but if we do find a bug and fix it, you'll still have to upgrade :).
and after so many unpaid hours I chose 3.2 because the packages exist.
I think that someone's working on 4.2 packages, and in fact I believe they're on this mailing list. -glyph P.S.: Please remember to "reply all" so others on the list will see the reply.
Ok so I have 4.2 installed and I have the same problem... fresh Ubuntu 12.10 64bit install... When I move, delete, or change anything in iCal I have to do every twice before it will stick... Any ideas? OK… LOGS… I'm using iCal 5.0.3 and 4.0.4 both the same issues In iCal I create a event at 3:00pm March 6 and it seems to be ok… 2013-03-06 14:47:07-0500 [-] [caldav-0] [HTTPChannel,17,24.201.74.72] [twext.web2.server#info] PUT /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:47:07-0500 [-] [caldav-0] [HTTPChannel,18,24.201.74.72] [twext.web2.server#info] PUT /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Updating group membership cache 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Group membership snapshot file exists: /var/lib/caldavd/memberships_cache 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Attempting to acquire group membership cache lock 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Acquired lock 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Retrieving list of all proxies 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] There are 0 proxies 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Retrieving group hierarchy from directory 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] 1 groups retrieved from the directory 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] 0 groups are proxies 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] There are 0 users delegated-to via groups 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Taking snapshot of group memberships to /var/lib/caldavd/memberships_cache 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Storing 0 group memberships in memcached 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Releasing lock 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Group memberships cache updated 2013-03-06 14:47:18-0500 [-] [groupcacher] 2013-03-06 14:47:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacherService#info] Scheduling next group membership update Then I move the event to 4:00 … and it jumps back to 3:00 2013-03-06 14:51:02-0500 [-] [caldav-0] [HTTPChannel,19,24.201.74.72] [twext.web2.server#info] PUT /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:51:02-0500 [-] [caldav-0] [HTTPChannel,19,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:51:02-0500 [-] [caldav-0] [HTTPChannel,20,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 Then I move the event to 4:00 again … and it stays at 4:00 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Updating group membership cache 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Group membership snapshot file exists: /var/lib/caldavd/memberships_cache 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Attempting to acquire group membership cache lock 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Acquired lock 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Retrieving list of all proxies 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] There are 0 proxies 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Retrieving group hierarchy from directory 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] 1 groups retrieved from the directory 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] 0 groups are proxies 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] There are 0 users delegated-to via groups 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Taking snapshot of group memberships to /var/lib/caldavd/memberships_cache 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [-] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Storing 0 group memberships in memcached 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Releasing lock 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacheUpdater#info] Group memberships cache updated 2013-03-06 14:52:18-0500 [-] [groupcacher] 2013-03-06 14:52:18-0500 [PooledMemCacheProtocol,client] [twistedcaldav.directory.directory.GroupMembershipCacherService#info] Scheduling next group membership update 2013-03-06 14:52:20-0500 [-] [caldav-0] [HTTPChannel,21,24.201.74.72] [twext.web2.server#info] PUT /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:52:20-0500 [-] [caldav-0] [HTTPChannel,22,24.201.74.72] [twext.web2.server#info] PUT /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 Then I delete the event at 4:00 but it come right back 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,24,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 Then I delete the event at 4:00 again and this time it is gone 2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,25,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,26,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 It seems to me the Following GET operations are reading back the old data? On 2013-03-06, at 4:31 PM, Glyph wrote:
On Mar 6, 2013, at 11:57 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
I can't get 4.x releases to work on Ubuntu ( 12.10 in my case ) x86… and there are no packages for 4.x releases so far? relevant info is hard to find on the Net about how to set it all up. I managed to compile from SVN successfully but the logs fill with errors,
I'm a little more interested in these errors than the ones you're having with 3.2, since 4.x is a lot closer to what we're currently working on in trunk. Can you send them on? Not to say that I wouldn't like you to fix your current errors, but if we do find a bug and fix it, you'll still have to upgrade :).
and after so many unpaid hours I chose 3.2 because the packages exist.
I think that someone's working on 4.2 packages, and in fact I believe they're on this mailing list.
-glyph
P.S.: Please remember to "reply all" so others on the list will see the reply.
On Mar 7, 2013, at 6:20 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
... Then I delete the event at 4:00 but it come right back
2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,24,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
Either the delete is failing or the GETs are failing; they can't both be succeeding, but we can't see why. Can you turn your log level up to Debug (in caldavd.plist) then restart the service and reproduce these steps, then reply including the relevant portions of error.log and access.log? Thx, -dre
Then I delete the event at 4:00 again and this time it is gone
2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,25,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,26,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
It seems to me the Following GET operations are reading back the old data?
On 2013-03-06, at 4:31 PM, Glyph wrote:
On Mar 6, 2013, at 11:57 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
I can't get 4.x releases to work on Ubuntu ( 12.10 in my case ) x86… and there are no packages for 4.x releases so far? relevant info is hard to find on the Net about how to set it all up. I managed to compile from SVN successfully but the logs fill with errors,
I'm a little more interested in these errors than the ones you're having with 3.2, since 4.x is a lot closer to what we're currently working on in trunk. Can you send them on? Not to say that I wouldn't like you to fix your current errors, but if we do find a bug and fix it, you'll still have to upgrade :).
and after so many unpaid hours I chose 3.2 because the packages exist.
I think that someone's working on 4.2 packages, and in fact I believe they're on this mailing list.
-glyph
P.S.: Please remember to "reply all" so others on the list will see the reply.
_______________________________________________ calendarserver-users mailing list calendarserver-users@lists.macosforge.org https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Hi thank you for your time... This is the same for creating, moving, delete Calendarsever 2.4 does not have the same problem only 3.2, 4.2 on this system Here is the delete operation failing... 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,23,::ffff:192.168.1.38] [twext.web2.server#info] DELETE /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twext.web2.server#info] GET /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '23068977201759756079232744263502251584903490272716206165' 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:41:32-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:41:32-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 Now the second try works... 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twext.web2.server#info] DELETE /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '23068977201759756079232744263502251584903490272716206165' 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x339fdd0> 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x339fdd0> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.Notifier#debug] Notifications are enabled: update default CalDAV|admin 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.NotifierFactory#debug] Sending to notification server: update CalDAV|admin 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.Notifier#debug] Notifications are enabled: update collection CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.NotifierFactory#debug] Sending to notification server: update CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.cache.MemcacheChangeNotifier#debug] Changing Cache Token for '/calendars/__uids__/admin/' 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x366ea28> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.cache.MemcacheChangeNotifier#debug] Changing Cache Token for '/calendars/__uids__/admin/calendar/' 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 1, #busy: 2, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [notifications] 2013-03-07 11:42:57-0500 [InternalNotificationProtocol,0,127.0.0.1] [twistedcaldav.notify.Coalescer#debug] Scheduling: CalDAV|admin 2013-03-07 11:42:57-0500 [-] [notifications] 2013-03-07 11:42:57-0500 [InternalNotificationProtocol,0,127.0.0.1] [twistedcaldav.notify.Coalescer#debug] Scheduling: CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x366ea28> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 2013-03-07 11:43:00-0500 [-] [notifications] 2013-03-07 11:43:00-0500 [-] [twistedcaldav.notify.Coalescer#debug] Time to send: CalDAV|admin 2013-03-07 11:43:00-0500 [-] [notifications] 2013-03-07 11:43:00-0500 [-] [twistedcaldav.notify.Coalescer#debug] Time to send: CalDAV|admin/calendar On 2013-03-07, at 10:34 AM, Andre LaBranche wrote:
On Mar 7, 2013, at 6:20 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
... Then I delete the event at 4:00 but it come right back
2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,24,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
Either the delete is failing or the GETs are failing; they can't both be succeeding, but we can't see why. Can you turn your log level up to Debug (in caldavd.plist) then restart the service and reproduce these steps, then reply including the relevant portions of error.log and access.log?
Thx, -dre
Then I delete the event at 4:00 again and this time it is gone
2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,25,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,26,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
It seems to me the Following GET operations are reading back the old data?
On 2013-03-06, at 4:31 PM, Glyph wrote:
On Mar 6, 2013, at 11:57 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
I can't get 4.x releases to work on Ubuntu ( 12.10 in my case ) x86… and there are no packages for 4.x releases so far? relevant info is hard to find on the Net about how to set it all up. I managed to compile from SVN successfully but the logs fill with errors,
I'm a little more interested in these errors than the ones you're having with 3.2, since 4.x is a lot closer to what we're currently working on in trunk. Can you send them on? Not to say that I wouldn't like you to fix your current errors, but if we do find a bug and fix it, you'll still have to upgrade :).
and after so many unpaid hours I chose 3.2 because the packages exist.
I think that someone's working on 4.2 packages, and in fact I believe they're on this mailing list.
-glyph
P.S.: Please remember to "reply all" so others on the list will see the reply.
_______________________________________________ calendarserver-users mailing list calendarserver-users@lists.macosforge.org https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Hi, Please also include the relevant portion of access.log. I'm very curious to see the http status code of the DELETE you're sending. -dre On Mar 7, 2013, at 8:45 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
Hi thank you for your time...
This is the same for creating, moving, delete Calendarsever 2.4 does not have the same problem only 3.2, 4.2 on this system
Here is the delete operation failing... 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,23,::ffff:192.168.1.38] [twext.web2.server#info] DELETE /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twext.web2.server#info] GET /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '23068977201759756079232744263502251584903490272716206165' 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:41:32-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:41:32-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0
Now the second try works...
2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twext.web2.server#info] DELETE /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '23068977201759756079232744263502251584903490272716206165' 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x339fdd0> 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x339fdd0> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.Notifier#debug] Notifications are enabled: update default CalDAV|admin 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.NotifierFactory#debug] Sending to notification server: update CalDAV|admin 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.Notifier#debug] Notifications are enabled: update collection CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.NotifierFactory#debug] Sending to notification server: update CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.cache.MemcacheChangeNotifier#debug] Changing Cache Token for '/calendars/__uids__/admin/' 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x366ea28> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.cache.MemcacheChangeNotifier#debug] Changing Cache Token for '/calendars/__uids__/admin/calendar/' 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 1, #busy: 2, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [notifications] 2013-03-07 11:42:57-0500 [InternalNotificationProtocol,0,127.0.0.1] [twistedcaldav.notify.Coalescer#debug] Scheduling: CalDAV|admin 2013-03-07 11:42:57-0500 [-] [notifications] 2013-03-07 11:42:57-0500 [InternalNotificationProtocol,0,127.0.0.1] [twistedcaldav.notify.Coalescer#debug] Scheduling: CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x366ea28> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 2013-03-07 11:43:00-0500 [-] [notifications] 2013-03-07 11:43:00-0500 [-] [twistedcaldav.notify.Coalescer#debug] Time to send: CalDAV|admin 2013-03-07 11:43:00-0500 [-] [notifications] 2013-03-07 11:43:00-0500 [-] [twistedcaldav.notify.Coalescer#debug] Time to send: CalDAV|admin/calendar
On 2013-03-07, at 10:34 AM, Andre LaBranche wrote:
On Mar 7, 2013, at 6:20 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
... Then I delete the event at 4:00 but it come right back
2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,24,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
Either the delete is failing or the GETs are failing; they can't both be succeeding, but we can't see why. Can you turn your log level up to Debug (in caldavd.plist) then restart the service and reproduce these steps, then reply including the relevant portions of error.log and access.log?
Thx, -dre
Then I delete the event at 4:00 again and this time it is gone
2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,25,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,26,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
It seems to me the Following GET operations are reading back the old data?
On 2013-03-06, at 4:31 PM, Glyph wrote:
On Mar 6, 2013, at 11:57 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
I can't get 4.x releases to work on Ubuntu ( 12.10 in my case ) x86… and there are no packages for 4.x releases so far? relevant info is hard to find on the Net about how to set it all up. I managed to compile from SVN successfully but the logs fill with errors,
I'm a little more interested in these errors than the ones you're having with 3.2, since 4.x is a lot closer to what we're currently working on in trunk. Can you send them on? Not to say that I wouldn't like you to fix your current errors, but if we do find a bug and fix it, you'll still have to upgrade :).
and after so many unpaid hours I chose 3.2 because the packages exist.
I think that someone's working on 4.2 packages, and in fact I believe they're on this mailing list.
-glyph
P.S.: Please remember to "reply all" so others on the list will see the reply.
_______________________________________________ calendarserver-users mailing list calendarserver-users@lists.macosforge.org https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Hi Failed Delete ::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.ics HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.ics HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4 Second try delete works... ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.ics HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1 The deletes that work are not followed by a GET... On 2013-03-07, at 11:55 AM, Andre LaBranche wrote:
Hi,
Please also include the relevant portion of access.log. I'm very curious to see the http status code of the DELETE you're sending.
-dre
On Mar 7, 2013, at 8:45 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
Hi thank you for your time...
This is the same for creating, moving, delete Calendarsever 2.4 does not have the same problem only 3.2, 4.2 on this system
Here is the delete operation failing... 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,23,::ffff:192.168.1.38] [twext.web2.server#info] DELETE /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twext.web2.server#info] GET /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '23068977201759756079232744263502251584903490272716206165' 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:41:32-0500 [-] [caldav-1] [HTTPChannel,24,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:41:32-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:41:32-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0
Now the second try works...
2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twext.web2.server#info] DELETE /calendars/__uids__/admin/calendar/4BB3FD49-05EC-46FE-A958-66C790F462B9.ics HTTP/1.1 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.directory.digest.DigestCredentialsMemcache#debug] Getting Cache Token for '23068977201759756079232744263502251584903490272716206165' 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x339fdd0> 2013-03-07 11:42:57-0500 [-] [caldav-1] [HTTPChannel,25,::ffff:192.168.1.38] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x339fdd0> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.Notifier#debug] Notifications are enabled: update default CalDAV|admin 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.NotifierFactory#debug] Sending to notification server: update CalDAV|admin 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.Notifier#debug] Notifications are enabled: update collection CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.notify.NotifierFactory#debug] Sending to notification server: update CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.cache.MemcacheChangeNotifier#debug] Changing Cache Token for '/calendars/__uids__/admin/' 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x366ea28> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.cache.MemcacheChangeNotifier#debug] Changing Cache Token for '/calendars/__uids__/admin/calendar/' 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Busied client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 1, #busy: 2, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [notifications] 2013-03-07 11:42:57-0500 [InternalNotificationProtocol,0,127.0.0.1] [twistedcaldav.notify.Coalescer#debug] Scheduling: CalDAV|admin 2013-03-07 11:42:57-0500 [-] [notifications] 2013-03-07 11:42:57-0500 [InternalNotificationProtocol,0,127.0.0.1] [twistedcaldav.notify.Coalescer#debug] Scheduling: CalDAV|admin/calendar 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x34df5a8> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 2, #busy: 1, #pending: 0, #queued: 0 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Freed client: <twistedcaldav.memcachepool.PooledMemCacheProtocol instance at 0x366ea28> 2013-03-07 11:42:57-0500 [-] [caldav-1] [PooledMemCacheProtocol,client] [twistedcaldav.memcachepool.MemCachePool#debug] Clients #free: 3, #busy: 0, #pending: 0, #queued: 0 2013-03-07 11:43:00-0500 [-] [notifications] 2013-03-07 11:43:00-0500 [-] [twistedcaldav.notify.Coalescer#debug] Time to send: CalDAV|admin 2013-03-07 11:43:00-0500 [-] [notifications] 2013-03-07 11:43:00-0500 [-] [twistedcaldav.notify.Coalescer#debug] Time to send: CalDAV|admin/calendar
On 2013-03-07, at 10:34 AM, Andre LaBranche wrote:
On Mar 7, 2013, at 6:20 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
... Then I delete the event at 4:00 but it come right back
2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,23,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:53:31-0500 [-] [caldav-0] [HTTPChannel,24,24.201.74.72] [twext.web2.server#info] GET /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
Either the delete is failing or the GETs are failing; they can't both be succeeding, but we can't see why. Can you turn your log level up to Debug (in caldavd.plist) then restart the service and reproduce these steps, then reply including the relevant portions of error.log and access.log?
Thx, -dre
Then I delete the event at 4:00 again and this time it is gone
2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,25,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1 2013-03-06 14:55:01-0500 [-] [caldav-0] [HTTPChannel,26,24.201.74.72] [twext.web2.server#info] DELETE /calendars/__uids__/1cc63f8f-744a-4941-88c8-8ab121d03be9/calendar/D49F6977-1BCA-4EB3-A602-510B2037DC81.ics HTTP/1.1
It seems to me the Following GET operations are reading back the old data?
On 2013-03-06, at 4:31 PM, Glyph wrote:
On Mar 6, 2013, at 11:57 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
I can't get 4.x releases to work on Ubuntu ( 12.10 in my case ) x86… and there are no packages for 4.x releases so far? relevant info is hard to find on the Net about how to set it all up. I managed to compile from SVN successfully but the logs fill with errors,
I'm a little more interested in these errors than the ones you're having with 3.2, since 4.x is a lot closer to what we're currently working on in trunk. Can you send them on? Not to say that I wouldn't like you to fix your current errors, but if we do find a bug and fix it, you'll still have to upgrade :).
and after so many unpaid hours I chose 3.2 because the packages exist.
I think that someone's working on 4.2 packages, and in fact I believe they're on this mailing list.
-glyph
P.S.: Please remember to "reply all" so others on the list will see the reply.
_______________________________________________ calendarserver-users mailing list calendarserver-users@lists.macosforge.org https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Hi Robert, --On March 7, 2013 at 12:04:56 PM -0500 Robert Bruce <rbruce@celsiusinc.com> wrote:
::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4
Second try delete works...
::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1
The deletes that work are not followed by a GET...
OK, so the client is doing a conditional DELETE request - i.e. it is asking the server to only do the DELETE if the resource on the server is unchanged from the one that the client originally cached. For some reason it is not, so a 412 error comes back, and the client reloads the resource using GET. The second DELETE then works fine. Is the account in your client one that has been present all the time since you did the upgrade? If so, try removing the account from the client, then re-add it and let it resync all the data. Once it has done that, hopefully it will have the change state correctly cached and you won't see the double DELETEs (except for when a real change has taken place on the server that the client has not sync'd). -- Cyrus Daboo
Hi I have been using multiple clients (different iCal version 4.0.4, 5.0.3) and different system and just created a new account to try to make sure... it's the same problem... It's not just for Deletes I have to do all operations twice... If I refresh iCal before each Move, Delete, etc... then it is ok, but not ideal solution. On 2013-03-07, at 12:09 PM, Cyrus Daboo wrote:
Hi Robert,
--On March 7, 2013 at 12:04:56 PM -0500 Robert Bruce <rbruce@celsiusinc.com> wrote:
::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4
Second try delete works...
::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1
The deletes that work are not followed by a GET...
OK, so the client is doing a conditional DELETE request - i.e. it is asking the server to only do the DELETE if the resource on the server is unchanged from the one that the client originally cached. For some reason it is not, so a 412 error comes back, and the client reloads the resource using GET. The second DELETE then works fine.
Is the account in your client one that has been present all the time since you did the upgrade? If so, try removing the account from the client, then re-add it and let it resync all the data. Once it has done that, hopefully it will have the change state correctly cached and you won't see the double DELETEs (except for when a real change has taken place on the server that the client has not sync'd).
-- Cyrus Daboo
Also calendar server 2.4 does not have this behaviour but does not have all the features I was hoping for. On 2013-03-07, at 12:18 PM, Robert Bruce wrote:
Hi I have been using multiple clients (different iCal version 4.0.4, 5.0.3) and different system and just created a new account to try to make sure... it's the same problem...
It's not just for Deletes I have to do all operations twice...
If I refresh iCal before each Move, Delete, etc... then it is ok, but not ideal solution.
On 2013-03-07, at 12:09 PM, Cyrus Daboo wrote:
Hi Robert,
--On March 7, 2013 at 12:04:56 PM -0500 Robert Bruce <rbruce@celsiusinc.com> wrote:
::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4
Second try delete works...
::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1
The deletes that work are not followed by a GET...
OK, so the client is doing a conditional DELETE request - i.e. it is asking the server to only do the DELETE if the resource on the server is unchanged from the one that the client originally cached. For some reason it is not, so a 412 error comes back, and the client reloads the resource using GET. The second DELETE then works fine.
Is the account in your client one that has been present all the time since you did the upgrade? If so, try removing the account from the client, then re-add it and let it resync all the data. Once it has done that, hopefully it will have the change state correctly cached and you won't see the double DELETEs (except for when a real change has taken place on the server that the client has not sync'd).
-- Cyrus Daboo
_______________________________________________ calendarserver-users mailing list calendarserver-users@lists.macosforge.org https://lists.macosforge.org/mailman/listinfo/calendarserver-users
Hi Robert, We'd like to help you get this figured out, but you're making it hard for us :) Please take the following to heart: 1) Please read each reply you receive on this thread in its entirety, and respond to all questions that are posed. For example, the second paragraph you quoted from Cyrus' reply hasn't been addressed (the one that begins: Is the account in your client one that has been present all the time since you did the upgrade?) 2) Please send all emails on this topic to the list and not to individual people; this helps everyone benefit from the shared knowledge, and lets us play tag team on dealing with this (and other) issues. Thanks and cheers, -dre On Mar 7, 2013, at 9:18 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
Hi I have been using multiple clients (different iCal version 4.0.4, 5.0.3) and different system and just created a new account to try to make sure... it's the same problem...
It's not just for Deletes I have to do all operations twice...
If I refresh iCal before each Move, Delete, etc... then it is ok, but not ideal solution.
On 2013-03-07, at 12:09 PM, Cyrus Daboo wrote:
Hi Robert,
--On March 7, 2013 at 12:04:56 PM -0500 Robert Bruce <rbruce@celsiusinc.com> wrote:
::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4
Second try delete works...
::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1
The deletes that work are not followed by a GET...
OK, so the client is doing a conditional DELETE request - i.e. it is asking the server to only do the DELETE if the resource on the server is unchanged from the one that the client originally cached. For some reason it is not, so a 412 error comes back, and the client reloads the resource using GET. The second DELETE then works fine.
Is the account in your client one that has been present all the time since you did the upgrade? If so, try removing the account from the client, then re-add it and let it resync all the data. Once it has done that, hopefully it will have the change state correctly cached and you won't see the double DELETEs (except for when a real change has taken place on the server that the client has not sync'd).
-- Cyrus Daboo
On Mar 7, 2013, at 1:17 PM, Andre LaBranche <dre@apple.com> wrote:
1) Please read each reply you receive on this thread in its entirety, and respond to all questions that are posed. For example, the second paragraph you quoted from Cyrus' reply hasn't been addressed (the one that begins: Is the account in your client one that has been present all the time since you did the upgrade?)
… and now I see that you did actually address this, so apologies. You said:
Hi I have been using multiple clients (different iCal version 4.0.4, 5.0.3) and different system and just created a new account to try to make sure... it's the same problem…
Ok, so that question is answered. Sorry about that! -dre
So is there any way to disable the caching? I really need a working Calendar server... Everything is working fine except having to do every operation twice to get it to stick... How can I debug this? Thank you, On 2013-03-07, at 12:09 PM, Cyrus Daboo wrote:
Hi Robert,
--On March 7, 2013 at 12:04:56 PM -0500 Robert Bruce <rbruce@celsiusinc.com> wrote:
::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4
Second try delete works...
::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1
The deletes that work are not followed by a GET...
OK, so the client is doing a conditional DELETE request - i.e. it is asking the server to only do the DELETE if the resource on the server is unchanged from the one that the client originally cached. For some reason it is not, so a 412 error comes back, and the client reloads the resource using GET. The second DELETE then works fine.
Is the account in your client one that has been present all the time since you did the upgrade? If so, try removing the account from the client, then re-add it and let it resync all the data. Once it has done that, hopefully it will have the change state correctly cached and you won't see the double DELETEs (except for when a real change has taken place on the server that the client has not sync'd).
-- Cyrus Daboo
On Mar 8, 2013, at 8:06 AM, Robert Bruce <rbruce@celsiusinc.com> wrote:
So is there any way to disable the caching? I really need a working Calendar server...
Everything is working fine except having to do every operation twice to get it to stick...
Something is pretty broken here; it's completely abnormal to have to do things twice to get them to stick.
How can I debug this?
We'll need a snapshot of client and server logs covering an example reproduction of the problem. One easy way to collect iCal logs (without making any persistent changes to logging configuration) is to launch iCal using Terminal with some additional arguments. 1) In a Terminal window, run the following, which launches iCal and sends all debug output to the terminal window (this is for Snow client. For Mountain Lion, see this document): /Applications/iCal.app/Contents/MacOS/iCal -LogHTTPActivity YES -iTIPLogDetailedActivity YES -CalDAVNotificationLog YES 2) Note the wall-clock time, then reproduce the problem (i.e. that you have to do things twice for them to stick). 3) Note the time again, then control-c the terminal window to kill iCal, and save the entire transcript as a text file. 4) Extract the relevant portions of the server's access.log and error.log, covering only the time during the problem reproduction please. Finally, please reply (privately, as the logs contain some possibly sensitive info like email addresses, etc) with the above logs and we'll have a look! Thx, -dre
Thank you,
On 2013-03-07, at 12:09 PM, Cyrus Daboo wrote:
Hi Robert,
--On March 7, 2013 at 12:04:56 PM -0500 Robert Bruce <rbruce@celsiusinc.com> wrote:
::ffff:192.168.1.38 - - [07/Mar/2013:12:03:02 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 412 157 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=12.7 ::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:02 -0400] "GET /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 200 705 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=22.4
Second try delete works...
::ffff:192.168.1.38 - admin [07/Mar/2013:12:03:51 -0400] "DELETE /calendars/__uids__/admin/calendar/AE195B52-8AD1-4F43-BB6B-2298EC72E889.i cs HTTP/1.1" 204 0 "-" "DAVKit/4.0.3 (732.2); CalendarStore/4.0.4 (997.7); iCal/4.0.4 (1395.7); Mac OS X/10.6.8 (10K549)" i=1 or=1 t=511.1
The deletes that work are not followed by a GET...
OK, so the client is doing a conditional DELETE request - i.e. it is asking the server to only do the DELETE if the resource on the server is unchanged from the one that the client originally cached. For some reason it is not, so a 412 error comes back, and the client reloads the resource using GET. The second DELETE then works fine.
Is the account in your client one that has been present all the time since you did the upgrade? If so, try removing the account from the client, then re-add it and let it resync all the data. Once it has done that, hopefully it will have the change state correctly cached and you won't see the double DELETEs (except for when a real change has taken place on the server that the client has not sync'd).
-- Cyrus Daboo
participants (4)
-
Andre LaBranche
-
Cyrus Daboo
-
Glyph
-
Robert Bruce