[dev] [Tickets #11777] Re: ActiveSync error after latest changes in git
Michael J Rubinsky
mrubinsk at horde.org
Fri Dec 21 19:31:53 UTC 2012
Quoting Joerg Pulz <Joerg.Pulz at frm2.tum.de>:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
>
> On Thu, 20 Dec 2012, Michael J Rubinsky wrote:
>
>> Quoting Joerg Pulz <Joerg.Pulz at frm2.tum.de>> -----BEGIN PGP SIGNED
>> MESSAGE-----
>>> Hash: SHA1
>>>
>>>
>>> On Tue, 18 Dec 2012, Michael J Rubinsky wrote:
>>>
>>>>
>>>> Quoting Joerg Pulz <Joerg.Pulz at frm2.tum.de>:
>>>>
>>>>> -----BEGIN PGP SIGNED MESSAGE-----
>>>>> Hash: SHA1
>>>>>
>>>>>
>>>>> On Tue, 18 Dec 2012, Michael J Rubinsky wrote:
>>>>>
>>>>>>
>>>>>> Quoting Joerg Pulz <Joerg.Pulz at frm2.tum.de>:
>>>>>>
>>>>>>> On Mon, 17 Dec 2012, Michael J Rubinsky wrote:
>>>>>>>
>>>>>>>>
>>>>>>>> Quoting Joerg Pulz <Joerg.Pulz at frm2.tum.de>:
>>>>>>>>
>>>>>>>>> Hi Michael,
>>>>>>>>>
>>>>>>>>> here are two mails, directly copied out of our cyrus-imapd
>>>>>>>>> mailstore, to
>>>>>>>>> keep the whole unmodified content.
>>>>>>>>> Both messages lead to php-fpm segfault with "Sending HTML
>>>>>>>>> Message." as last
>>>>>>>>> log entry.
>>>>>>>>>
>>>>>>>>> Hope this helps to find the problem.
>>>>>>>>
>>>>>>>> Can you try the latest changes I just pushed to Git?
>>>>>>>
>>>>>>> Hi Michael,
>>>>>>>
>>>>>>> just pulled the latest changes from git, stopped all services,
>>>>>>> purged all
>>>>>>> caches and removed the device from ActiveSync devices.
>>>>>>> Both messages i sent you yesterday where transferred correctly but it
>>>>>>> stops at another two mails with the following log entry:
>>>>>>>
>>>>>>> ####
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Synchronize>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Status>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O 1
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Status/>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: [89302] Initializing state
>>>>>>> for collection: INBOX, synckey:
>>>>>>> {50d02135-4528-455c-8534-5cc881bbb396}3
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: [89302] Loading state for
>>>>>>> synckey {50d02135-4528-455c-8534-5cc881bbb396}3
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: [89302] Found 5 changes
>>>>>>> remaining from previous SYNC.
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: [89302] Initializing message
>>>>>>> diff engine for INBOX
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: [89302] Returning previously
>>>>>>> found changes.
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: Old SYNCKEY:
>>>>>>> {50d02135-4528-455c-8534-5cc881bbb396}3, New SYNCKEY:
>>>>>>> {50d02135-4528-455c-8534-5cc881bbb396}4
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Folders>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Folder>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <SyncKey>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O
>>>>>>> {50d02135-4528-455c-8534-5cc881bbb396}4
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <SyncKey/>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <FolderId>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O INBOX
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <FolderId/>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Status>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O 1
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG: O <Status/>
>>>>>>> 2012-12-18T09:00:05+01:00 DEBUG:
>>>>>>> Horde_Core_ActiveSync_Driver::getMessage(INBOX, 392277)
>>>>>>> 2012-12-18T09:00:06+01:00 DEBUG:
>>>>>>> 2012-12-18T09:00:06+01:00 DEBUG: Sending HTML Message.
>>>>>>> ####
>>>>>>>
>>>>>>> I will send you a off-list mail with the mails in question.
>>>>>>> Just curious,
>>>>>>> there is no HTML at all in those messages.
>>>>>>
>>>>>> Can you send me a more complete log for this? I'm looking for
>>>>>> the request that triggered this response (the request would
>>>>>> start with: I <SYNC>. I'm looking for the options your device
>>>>>> is sending, including the truncation value.
>>>>>>
>>>>>> FWIW, it's not about if the email contains HTML or not, it's
>>>>>> about what the server is requesting. It requests bare HTML
>>>>>> email (not a MIME message).
>>>>>
>>>>> Michael,
>>>>>
>>>>> thanks for explaining. Found it out by myself, that Android gets
>>>>> HTML messages deliverd and iPhone gets MIME messages.
>>>>>
>>>>> Please find attached the log for a failing Android sync from
>>>>> login to segfault. As you will see, there are two messages
>>>>> delivered before the segfault occurs.
>>>>>
>>>>> Hope this helps.
>>>>
>>>> Can you try again with my latest changes in Git?
>>>
>>> Michael,
>>>
>>> here are some news on this topic as I finally found some time to
>>> investigate this further.
>>>
>>> First some details about my environment that i totally forgot to
>>> mention earlier:
>>>
>>> OS: FreeBSD 9.1-RC2 amd64
>>> Software: PHP-5.4.9 (FPM), nginx-1.2.6, memcached-1.4.15,
>>> postgresql-9.2.2, pcre-8.32
>>>
>>> The segfault occurs in the match() function of libpcre.
>>> After searching the web i found PHPbug #48153:
>>> https://bugs.php.net/bug.php?id=48153
>>> I checked the configure values for the php hash module and removed
>>> "--with-mhash". After rebuilding and installing the php hash
>>> module I was able to sync some eMails more but still ended in a
>>> segfault again.
>>> I attached gdb to the php-fpm process and found out that libpcre
>>> match() was called recursive over 5700 times until it hit the
>>> stacksize limit which leads to the segfault.
>>> I tried increasing the stacksize again and again, but i still
>>> ended in a segfault again.
>>> After reading pcre docs ( http://pcre.org/pcre.txt ) i've rebuilt
>>> libpcre and used the "--disable-stack-for-recursion" configure
>>> option.After reinstalling the rebuilt libpcre and restarting
>>> php-fpm, the segfaults are gone and i can sync all my eMails again.
>>>
>>> It looks like some of the horde/ActiveSync pcre actions lead to a
>>> massive recursive call to the libpcre match() function which then
>>> reaches the stacksize limit. There is some good reading in the
>>> pcrestack(3) manpage about how to reduce/limit stack usage. Maybe
>>> it's worth to check the used pcre match pattern again to see if
>>> they can be rewritten to produce less recursive calls to match()
>>> and thereby use lass stack.
>>>
>>> I think we've hit the same problem during turba adressbook import
>>> using CSV files, but i have to recheck that.
>>>
>>> So for now, ActiveSync seems to work quite well, but somehow some
>>> eMails are not transferred correctly. In Android the header and
>>> attachments are displayed and readable but the mail body is empty.
>>> The same holds true for iPhone devices. IMP and other mail clients
>>> are displaying these mails correctly.
>>>
>>> Kind regards
>>> Joerg
>>>
>>> - -- The beginning is the most important part of the work.
>>> -Plato
>>> -----BEGIN PGP SIGNATURE-----
>>> Version: GnuPG v2.0.19 (FreeBSD)
>>>
>>> iD8DBQFQ0yEwSPOsGF+KA+MRAlwsAKCCIHaqIKFj7kvZ5wF9Q5lwdXizzQCgyoLa
>>> HD/QWrTnYOBl9Lcj2CCNPh0=
>>> =YNnU
>>> -----END PGP SIGNATURE-----
>>>
>> ..also, it would be helpful to have a copy of an email whose body
>> appears empty.
>
> Michael,
>
> thanks for your fast response.
> Attached are 3 different mails which are displayed with empty body
> on my Android phone after ActiveSync transferred them.
I can't reproduce this. If this is still happening after updating to
latest code, please send me synclog when one of these messages is sent
to the device.
--
mike
The Horde Project (www.horde.org)
mrubinsk at horde.org
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6062 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.horde.org/archives/dev/attachments/20121221/23e7bbc2/attachment-0001.bin>
More information about the dev
mailing list