[dev] [Tickets #11777] Re: ActiveSync error after latest changes in git

Fri Dec 21 19:15:12 UTC 2012

Quoting Joerg Pulz <Joerg.Pulz at frm2.tum.de>:

> 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.

This should be fixed now with the latest release of Horde_Util (See  
Bug: 11899).
-- 
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/50cb1ddb/attachment.bin>