From: <tr...@eg...> - 2012-03-07 16:06:23
|
Ticket modified by Andre Larbiere at 2012/03/07 17:07 Tracking SystemBugs CategoryeSync VersionTrunk StatusOpen ResolutionAccepted Completed100% Priority5 - medium Created byAndre Larbiere Created on2011/03/29 19:08 Assigned toPhilip Herbert Summary#2917 - Delete email via WEB gui, then delete same message on AS device --> sync stops I found a problem in the activesync interface that occurs when the mobile AS client wants to act on an email that was deleted via the WEB gui (or any other email client) and when that deletion has not yet been synced to the mobile AS client. The following procedure can be used to reproduce the problem: - set email preferences to move deleted messages to a Trash folder - make sure the AS client is in sync - now delete an email via the EGW web interface - immediately after that, delete the same message on the AS client (before the deletion gets synced) - The server error log will now show the following sequence of messages and the synchronization does no longer work. [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] egw-pear::NET::IMAP:getSummary->error after Fetch for message(s):22895 Trying to retrieve single messages. [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] egw-pear::NET::IMAP:getSummary->error after Fetch for message with id:22895 [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] , [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] An error happened: failed to copy Message(s) to Deleted Items: 22895 due to:'BAD, invalid message range specified' [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #0 /var/www/egroupware/felamimail/inc/class.felamimail_activesync.inc.php(1338): felamimail_bo->deleteMessages(Array, 'INBOX') [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #1 [internal function]: felamimail_activesync->DeleteMessage('101000000000', '22895') [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #2 /var/www/egroupware/activesync/backend/egw.php(696): call_user_func_array(Array, Array) [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #3 /var/www/egroupware/activesync/backend/egw.php(314): BackendEGW->run_on_plugin_by_id('DeleteMessage', '101000000000', '22895') [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #4 /var/www/egroupware/activesync/backend/diffbackend.php(332): BackendEGW->DeleteMessage('101000000000', '22895') [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #5 /var/www/egroupware/activesync/request.php(1080): ImportContentsChangesDiff->ImportMessageDeletion('22895') [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #6 /var/www/egroupware/activesync/request.php(4132): HandleSync(Object(BackendEGW), '12.1', 'DEVICEID') [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #7 /var/www/egroupware/activesync/index.php(309): HandleRequest(Object(BackendEGW), 'Sync', 'DEVICEID', '12.1', false) [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] #8 {main} [Tue Mar 29 18:32:45 2011] [error] [client 192.168.254.107] # Instance=default, User=ender, URL=https://mysite.mydomain:443/Microsoft-Server-ActiveSync?Cmd=Sync&User=ender&DeviceId=DEVICEID&DeviceType=DEVICETYPE This sequence of messages repeats with the sync failing until either the AS configuration on the device is deleted and reconfigured, or the message is recovered via a server admin tool (I'm using dbmail, where that is possible) If one always deletes messages either only via the mobile device or only via the WEB gui, then everything works nicely. I tracked this down to the error trapping that occurs in method deleteMessages($_messageUID, $_folder) in file felamimail/inc/class.felamimail_bo.inc.php. With my configuration (move_to_trash), this method first calls egw-pear::Net::IMAP->copyMessages() to copy a message to the Trash folder, then egw-pear::Net::IMAP->deleteMessages() to delete the original message. This does generally work fine, but when the mobile device tries to delete an already deleted message, the first copyMessages() call returns with an error and the function returns false to the caller (without ever attempting to call deleteMessages() - but that's not really a problem). The issue is that the AS Sync call fails, so that the mobile device retries this operation over and over again. As a quick (and dirty) test, I commented out the error checking /* if ( PEAR::isError($retValue) ) { ... } */ after both egw-pear calls, and the issue goes away. This is of course no real fix, as errors may still occur for other reasons... Unfortunately, my knowledge of the egw-pear API is still a bit to limited to come up with a proper fix. But I think the overall process should be changed to: - First check if the message that should be deleted is still there - If not, return true to tell the caller that the request was successful (we wanted to delete the message, didn't we...) - If it is still there, go through the current process, trapping and reporting all errors Instead, Comment by Andre Larbiere at 2012/03/07 17:07: I have extracted my local tentative fix to the double delete issue as a patch to the current trunk release 38297 and attached it to this tracker item. Basically it consists in ignoring specific PEAR errors when deleting messages. There is of course a risk that other errors might get ignored, but so far I didn't have any such issues. Comment by Andre Larbiere at 2012/03/07 16:52: Unfortunately, I must come back on my previous comment. I forgot to revert a local fix I made in class.felamimail_bo.inc.php That fix was about handling failed deletes as a success when the error was due to the message not being found. With the trunk version of that file, the problem continues to exist. I'll isolate my fix in a patch and submit it here for review (next comment). It will be up to you to decide whether it can be integrated in the trunk. Comment by Andre Larbiere at 2012/03/07 16:44: Retested with trunk revision 38297: I could still observe an error message from egw-pear complaining about an invalid message id, this just occurs once, and everything recovers smoothly afterwards (eSync continues syncing). So it appears that eSync does now gracefully handle message deletes when those message are already gone. I just had an error after that in the felamimail web interface. Not really sure how that could be related, but after going through the procedure to reproduce this problem, felamimail did no longer display the message list (just the email folder tree in the sidebox). The apache log file contained the following message: ------------ PHP Fatal error: Interface 'activesync_plugin_write' not found in /var/www/egroupware/felamimail/inc/class.felamimail_activesync.inc.php on line 20, referer: https://www.mysite.com/egroupware/index.php?menuaction=felamimail.uifelamimail.viewMainScreen&ajax=true ------------ Note that this error did not occur before I made the double delete. Somehow it seems that class.felamimail_activesync.inc.php is loaded also from the web interface, but the eSync backend code is not loaded, so the interface definitions are missing. I do not pretend having understood the entire execution flow, but I fixed the problem for me by inserting the following two lines of code at the start of class.felamimail_activesync.inc.php: ----------- diff ----------------- Index: class.felamimail_activesync.inc.php =================================================================== --- class.felamimail_activesync.inc.php (revision 38297) +++ class.felamimail_activesync.inc.php (working copy) @@ -12,6 +12,9 @@ * @version $Id$ */ +set_include_path(EGW_SERVER_ROOT.'/activesync' . PATH_SEPARATOR . get_include_path()); +require_once EGW_INCLUDE_ROOT.'/activesync/backend/egw.php'; + /** * FMail eSync plugin * Comment by Ralf Becker at 2012/03/07 15:16: Please test again with current Trunk. Ralf Comment by Andre Larbiere at 2011/06/08 18:09: I just retested this in the latest trunc (35243), and the problem still occurs. The problem is that the AS client insists on deleting an message that does not exist anymore on the server. The server reports back an error, and the client tries again. That repeats forever, until one either: - recovers the deleted message (that's relatively easy on DBMAIL - which I use) - deletes and recreates the sync configuration on the AS client Currently, I am avoiding the issue by only deleting via the AS client. Comment by camel camel at 2011/06/08 15:26: i had sometimes the same problem, but seems to be, that it iis fixed on latest trunk @Andre Larbiere: please can you verify this bug again ? Comment by camel camel at 2011/04/21 01:52: i also tested and did exactly as on your test case ...hmm but working for me ...strange ...maybe i must stop "push" and test it with manually sync .. will do further tests cu Comment by Andre Larbiere at 2011/03/30 08:25: Sorry Philip, I don't know where I got the Herbert from. Must be something in my eyes... ;-) Andre Comment by Andre Larbiere at 2011/03/30 08:17: Hello Herbert, I'm using an Android 2.2 (Froyo) phone (a Galaxy S I9000) with the native email client. I will send the debug.txt to your email address. I'll point out my the IP address of my phone, because it might be intermingled with logs from my wife's phone (a Nokia C7), or my son's phone (a windows mobile 6.5) -- you see that I am testing quite a representative sample of AS capable phones. And I am really impressed by how well this does already work. Watch out for my PM from andre (underscore) larbiere (at) 123mail (dot) org Thanks, Andre Comment by Philip Herbert at 2011/03/29 22:43: I have tried to reproduce this issue. Because it works for me, I need the debug.txt file. In egw files dir /var/lib/egroupware/default/files/activesync create a file debug.txt, make it writeable for the webserver and reproduce the issue. Please send this debug.txt file to philip <a> knauber , de . If you do not want to attach to the ticket. Please make shure, you have updated to latest trunk before. Thanks, Philip</a> Comment by Philip Herbert at 2011/03/29 20:46: Hello Andre, thanks for testing our Active Sync implementation and the details of the error. What type of client are you using ? Do you know how to create a debug file ? Could you send a debug.txt of this (with the loop condition) ? You can send this via pm, because it may contain private information. We should fix this, without changing the behaviour of egw-pear. --Philip Linked entries: https://community.egroupware.org/egroupware/index.php?menuaction=tracker.tracker_ui.edit&tr_id=2917&no_popup=1 |