Summary | AS: Endless loop with Windows Phone 7.8 |
Queue | Synchronization |
Queue Version | Git master |
Type | Bug |
State | Resolved |
Priority | 1. Low |
Owners | mrubinsk (at) horde (dot) org |
Requester | thomas.jarosch (at) intra2net (dot) com |
Created | 01/21/2014 (4181 days ago) |
Due | |
Updated | 01/23/2014 (4179 days ago) |
Assigned | 01/21/2014 (4181 days ago) |
Resolved | 01/23/2014 (4179 days ago) |
Github Issue Link | |
Github Pull Request | |
Milestone | |
Patch | No |
The phone is a LG E900 with the recent Windows Phone 7.8 update.
So it's a bit ironic that a Windows phone does not conform to the
ActiveSync spec ;)
running 6.5 that both work correctly (do not request the RI collection
unless it is sent the RI folder in a FOLDERSYNC response).
Summary ⇒ AS: Endless loop with Windows Phone 7.8
The phone is a LG E900 with the recent Windows Phone 7.8 update.
So it's a bit ironic that a Windows phone does not conform to the
ActiveSync spec ;)
It seems to sync with the latest fixes (backported to FRAMEWORK_5).
I'll try to gather some logs once it's done with the initial sync.
Driver/Base.php:_getFolderUidForBackendId()
which contains a $type parameter.
I'm extending the Driver/Base.php:_getFolderUidForBackendId() function
to check $type for the correct type OR $id for 'RI'.
Then we support both "modes" if $type is not given.
I think the new code in "public function getFolderUidForBackendId($folderid)"
contains a typo: It accesses "$type" instead of "$id".
-> Buuuuuuuug
I think it should be:
// Always use RI for recipient cache.
if ($folderid == 'RI') {
return $folderid;
}
commit ae02bbf0279959f2a3d25f7c011e503970fda975
Author: Michael J Rubinsky <mrubinsk@horde.org>
Date: Wed Jan 22 02:02:52 2014 -0500
Add support in Horde_ActiveSync for Recipient Cache.
Needs backend support, but this prevents broken clients from
killing the sync completely (see
Bug #12930)..../lib/Horde/ActiveSync/Collections.php | 11 +++++++++++
.../lib/Horde/ActiveSync/Driver/Base.php | 4 ++++
.../lib/Horde/ActiveSync/Request/Sync.php | 9 ++++++++-
.../Core/lib/Horde/Core/ActiveSync/Driver.php | 13 +++++++++++++
4 files changed, 36 insertions(+), 1 deletions(-)
http://git.horde.org/horde-git/-/commit/ae02bbf0279959f2a3d25f7c011e503970fda975
time an AS client sends us an unexpected tag ;) Just log it, bail out
of the loop and continue.
bottom of the loop. Something should be parsed through each iteration.
wbxml stream might kill further option parsing. Though that should
never happen ;)
(the server really struggles when ten or more 100% CPU time tasks are
running :o)).
I'll check tomorrow morning if some other phone causes trouble, too.
Hopefully not :)
bottom of the loop. Something should be parsed through each iteration.
her phone. I have to ask for the specific model again. May be that
update "enabled" the RI collection.
functionality now since I'll have to implement at least part of it
anyway. If the device is erroneously asking for the RI collection, it
is probably also expecting a return value for it as well. Just
ignoring the MAXITEMS is likely to cause problems on the client side.
because the MAXITEMS node is not expected. You can see this in
Horde_ActiveSYnc_Request_Sync:: line 1142 where there is a TODO to
remind me to implement it when we implement the RI cache.
while() loop in that case.
May be we should add a sanity limit of 5.000+ "sync options" the next
time an AS client sends us an unexpected tag ;) Just log it, bail out
of the loop and continue.
The user mentioned something about a recent OTA Android update for her
phone. I have to ask for the specific model again. May be that update
"enabled" the RI collection.
@Arjen: I still run 2.8.5 because of QA. When I update to a new
version, I have to test all the devices I have floating around again.
Therefore I prefer to apply known fixes to 2.8.5 and will update every
few months or so to the current pear version. I also update the horde
apps and framework at the same time ;)
because the MAXITEMS node is not expected. You can see this in
Horde_ActiveSYnc_Request_Sync:: line 1142 where there is a TODO to
remind me to implement it when we implement the RI cache.
while() loop in that case.
the MAXITEMS node is not expected. You can see this in
Horde_ActiveSYnc_Request_Sync:: line 1142 where there is a TODO to
remind me to implement it when we implement the RI cache.
latest version? Pear has 2.11.0 available as of now, so I'd try
upgrading to the latest version first.
the client is issuing a SYNC request for a collection that it
shouldn't be.
latest version? Pear has 2.11.0 available as of now, so I'd try
upgrading to the latest version first.
stranded here at work by the pending snow storm :)
I still try to figure out how to trace this with gdb. There was an
infinite loop
in the Kolab code once and it would be nice to debug this easily if it
should ever pop up again.
Assigned to Michael Rubinsky
State ⇒ Assigned
Information Cache - it's something like a "popular recipient" cache to
speed lookups. It's on the TODO to integrate this with IMP's favorite
recipients functionality. The thing is, I'm pretty sure the device is
NOT supposed to request this unless the server indicates that it is in
use. Sounds like a bug in the client, though I have 2 Samsung test
devices that don't exhibit this behavior.
I should be able to take a look at this tonight, if I don't get
stranded here at work by the pending snow storm :)
State ⇒ Unconfirmed
New Attachment: endless_loop_log.txt
Patch ⇒ No
Milestone ⇒
Priority ⇒ 1. Low
Type ⇒ Bug
Summary ⇒ AS: Endless loop with Samsung phone
Queue ⇒ Synchronization
I've one box that somehow triggers an endless loop via ActiveSync
until the PHP timeout is reached.
The Samsung phone sends a request and the httpd process gets stuck in
a loop, eating up 100% CPU time. I've tried to attach "strace" to it
but it does not communicate anything with the linux kernel, so I guess
it's stuck in a loop.
The last bits I see in the ActiveSync log look like this:
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I <Folder>
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I <SyncKey>
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I {52cbc9bb-e888-4cd3-92ed-17f95c4fb70f}1
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I </SyncKey>
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I <FolderId>
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I RI
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I </FolderId>
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I <Options>
2014-01-21T11:59:45+01:00 ef6bd35e390f8ed625df47ceaee3ae1f DEBUG:
[18254] I <MaxItems>
The full sync log of the device is attached to this report.
Horde_ActiveSync version is 2.8.5. Any known, related issue?
I'm currently thinking about ways to debug this since I don't have any
hint what might be wrong.
My first uneducated guess is that something is wrong in the binary
WBXML data and we run into an endless loop while decoding it. Just a
*wild* theory though.
Installing xdebug will probably slow down the productive box to a crawl :(
May be "gdb" might do the trick to debug this:
http://derickrethans.nl/what-is-php-doing.html
Cheers,
Thomas