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

Thu Dec 20 14:44:43 UTC 2012

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-----
>
I had a feeling it was regex related which was the reason for my last  
commit.  However it appears the problem is with the expression in  
Horde_String::validUtf8. This is most likely the same issue described  
in Bug: 11899.

mike

Sent from mobile

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