[horde] [imp] Attachments failing. Someone please advise.

Kevin Konowalec webadmin at ualberta.ca
Mon Nov 26 18:00:19 UTC 2007


Yeah I thought that too... but we do remove the temp files on a daily  
basis (why it doesn't clean up after itself and leaves thousands of  
impatt<random> and PHP<random> files I still don't know).  We also  
have like 600 gigs on that volume so 1500 files shouldn't be a  
problem.  But in testing we also unmounted the NFS volume (thinking  
that maybe somehow it's causing the problem) and cleared out the temp  
space completely and the problem still persisted.


> Are you sure those attachments aren't just hitting the PHP memory  
> limit?
>
> -Drew


Yup.  The test attachments we were using were very small text files or  
image files.  Nothing more than a few hundred K.  If they were too  
large (we have the limit set at 20MB) Imp complains that the  
attachment was too large and doesn't let the user do it, which is the  
behavior you'd expect.

Thanks for the replies!

K



On Nov 26, 2007, at 10:47 AM, robert sand wrote:

> Sounds like a filesystem getting full and when the server reboots  
> the filesystem is empty.  Check to see where your php temp directory  
> is and make sure that you have enough storage there and/or clean it  
> up on a scheduled basis.
>
> Kevin Konowalec wrote:
>> Okay here's our setup:
>> 20x horde machines:
>> 	OpenBSD 4.1 (i386)
>> 	Horde: 3.1.4
>> 	Imp: H3 (4.1.4)
>> 	Turba: H3 (2.1.4)
>> 	PHP Version: 4.4.1
>> 4x Session Machines:
>> 	OpenBSD 4.1 (AMD64)
>> 	memcached 1.1.12
>> Database:
>> 	OpenBSD 4.1 (i386)
>> 	MySQL 14.12 Distrib 5.0.33
>> Round Robin Clustering via PF and CARP
>> shared NFS volume for uploaded attachments.
>> So, as Babita mentioned before, we're getting a lot of attachment   
>> failures.  They just don't show up in the received message all,   
>> despite Imp saying everything worked fine when sending.  When you   
>> check the sent mail folder, sure enough there's no attachment (and  
>> it  hasn't been "stripped" - there's no notice in the retained  
>> sent  message).
>> Having traced through the code as best as I can I haven't been able  
>> to  isolate exactly where it's failing.  So I'm not sure if it's a  
>> bug or  if it's in a misconfiguration or setup problem.
>> We noticed that when we reboot the test machine, the problem went   
>> away.  We speculated that it might be some PEAR/PHP nonsense and  
>> it  was actually the act of restarting apache that was solving the  
>> problem  rather than the complete reboot.  We were wrong.  So,  
>> thinking that a  reboot would at least be a bandaid solution to get  
>> us through end-of- semester we set up the horde machines to reboot  
>> once a week on  saturday morning.  Unfortunately that turned out to  
>> be completely  ineffective and we arrived this morning with 28  
>> complaints about  attachments.  We suspect that some of them saw  
>> the notice we put up  about the issue and, having never looked in  
>> their sent mail folder  before, saw that the attachments were  
>> getting stripped but not  realizing that it's the default  
>> behavior.  But I'm sure some of them  are seeing the same problem  
>> as before, where the attachments aren't  stripped... they were  
>> never attached in the first place.  We're also  not sure why the  
>> reboot seemed to fix the problem, though we  collectively sent only  
>> about 60 or 80 messages while testing it the  last time so it may  
>> not have been enough... however when it was  failing regularly you  
>> could count on at least a 1 in 10 failure rate.
>> I have no idea what role the session handler has on attachments,  
>> but  since we reboot the 4 memcached servers every monday morning  
>> I'm  watching to see what happens (we haven't had any further  
>> complaints  today yet).
>> Anyway... if any of the Imp developers or Horde team have any idea   
>> where we can look further to see why this is happening and stop  
>> it,  I'd greatly appreciate it.  This is the worst possible time of  
>> year to  have this happen, since students are relying on being able  
>> to submit  homework, projects, and the like for final grading.  We  
>> need to get  this fixed so the students will have a robust and  
>> reliable service and  at this point I can't say that they do.
>> Kevin
>> On Nov 23, 2007, at 10:46 AM, Kevin Konowalec wrote:
>>> That's not QUITE the problem we're having but it's similar.  When   
>>> the attachments fail to attach in our scenario it looks like  
>>> there  wasn't even an attempt to add something.  No zero-length  
>>> files.  No  "attachment stripped" message.  No nothing.  I thought  
>>> NFS may have  been the problem so I unmounted it and just used the  
>>> local file  system to test on... same problem.  And the annoying  
>>> thing is that  it happens only about 10% of the time so it's MUCH  
>>> harder to diagnose.
>>>
>>> So I went into the code and added a bunch of debug statements to  
>>> see  how Imp progresses through and constructs the message.   
>>> Here's what  I get:
>>>
>>> Message without any attachments:
>>>
>>> Nov 20 13:07:10 src at twc1 HORDE[30381]: [imp] testuser attempting  
>>> to  send message.  Adding 0 attachments [on line 302 of "/var/www/ 
>>> horde/ imp/compose.php"]
>>> Nov 20 13:07:10 src at twc1 HORDE[30381]: [imp] Creating base MIME   
>>> message for sending for testuser. [on line 328 of "/var/www/horde/  
>>> imp/compose.php"]
>>> Nov 20 13:07:10 src at twc1 HORDE[30381]: [imp] In addPart for   
>>> testuser. [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 13:07:11 src at twc1 HORDE[30381]: [imp] testuser sent  
>>> message  to webadmin at ualberta.ca [on line 1141 of "/var/www/horde/ 
>>> imp/ compose.php"]
>>>
>>>
>>> Message with attachment:
>>>
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] testuser attempting  
>>> to  send message.  Adding 1 attachments [on line 302 of "/var/www/ 
>>> horde/ imp/compose.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] About to build mixed   
>>> MIME part of message for testuser. [on line 310 of "/var/www/ 
>>> horde/ imp/compose.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] In addPart for   
>>> testuser. [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] In  
>>> buildAllAttachments  for testuser. [on line 748 of "/var/www/horde/ 
>>> imp/lib/Compose.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] In  
>>> buildAllAttachments  for testuser - Filename for upload is  
>>> munkie.jpg. [on line 759 of "/ var/www/horde/imp/lib/Compose.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] In addPart for   
>>> testuser. [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] Creating base MIME   
>>> message for sending for testuser. [on line 328 of "/var/www/horde/  
>>> imp/compose.php"]
>>> Nov 20 13:09:05 src at twc1 HORDE[13673]: [imp] In addPart for   
>>> testuser. [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 13:09:06 src at twc1 HORDE[13673]: [imp] testuser sent  
>>> message  to webadmin at ualberta.ca [on line 1141 of "/var/www/horde/ 
>>> imp/ compose.php"]
>>>
>>>
>>> Message that had an attachment but never gets attached:
>>>
>>> Nov 20 12:44:07 src at twc1 HORDE[31693]: [imp] testuser attempting  
>>> to  send message. Adding 0 attachments [on line 302 of "/var/www/ 
>>> horde/ imp/compose.php"]
>>> Nov 20 12:44:07 src at twc1 HORDE[31693]: [imp] Creating base MIME   
>>> message for sending for testuser. [on line 327 of "/var/www/horde/  
>>> imp/compose.php"]
>>> Nov 20 12:44:07 src at twc1 HORDE[31693]: [imp] In addPart for   
>>> testuser. [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 12:44:08 src at twc1 HORDE[31693]: [imp] testuser sent  
>>> message  to webadmin at ualberta.ca [on line 1140 of "/var/www/horde/ 
>>> imp/ compose.php"]
>>> Nov 20 12:44:08 src at twc1 HORDE[31693]: PHP Warning:  
>>> array_values():  The argument should be an array in /var/www/horde/ 
>>> imp/lib/ Compose.php on line 658
>>>
>>>
>>> This case is almost identical to the message with no attachment  
>>> with  the exception of the warning.  Turned out line 658 is in a  
>>> function  called "deleteAttachment".  I looked a bit more at that,  
>>> thinking  that might be a clue... but adding more debug statements  
>>> gives me  this:
>>>
>>>
>>> (this is an example of another successful attach and send)
>>>
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] testuser attempting  
>>> to  send message.  Adding 1 attachments [on line 302 of "/var/www/ 
>>> horde/ imp/compose.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] About to build mixed   
>>> MIME part of message for testuser. [on line 310 of "/var/www/ 
>>> horde/ imp/compose.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] In addPart for  
>>> testuser.  [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] In  
>>> buildAllAttachments  for testuser. [on line 756 of "/var/www/horde/ 
>>> imp/lib/Compose.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] In  
>>> buildAllAttachments  for testuser - Filename for upload is  
>>> 2006198979200376518_rs.jpg.  [on line 767 of "/var/www/horde/imp/ 
>>> lib/Compose.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] In addPart for  
>>> testuser.  [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] Creating base MIME   
>>> message for sending for testuser. [on line 328 of "/var/www/horde/  
>>> imp/compose.php"]
>>> Nov 20 15:35:40 src at twc1 HORDE[3941]: [imp] In addPart for  
>>> testuser.  [on line 577 of "/var/www/horde/lib/Horde/MIME/Part.php"]
>>> Nov 20 15:35:41 src at twc1 HORDE[3941]: [imp] testuser sent message  
>>> to  webadmin <webadmin at ualberta.ca> [on line 1155 of "/var/www/ 
>>> horde/imp/ compose.php"]
>>> Nov 20 15:35:41 src at twc1 HORDE[3941]: [imp] testuser is in   
>>> deleteAllAttachments for some reason. [on line 673 of "/var/www/  
>>> horde/imp/lib/Compose.php"]
>>> Nov 20 15:35:41 src at twc1 HORDE[3941]: [imp] Now testuser is in   
>>> deleteAttachment. [on line 627 of "/var/www/horde/imp/lib/  
>>> Compose.php"]
>>>
>>> Given that the warning is after all of the above it suggests that   
>>> it's basically a cleanup routine (though the 3000+ messages in my   
>>> shared NFS volume suggests it's not cleaning up after itself   
>>> properly...).
>>>
>>>
>>> So I'm totally at a loss as to where the problem could be.  I'm   
>>> hoping someone on the IMP team can at the very least point out  
>>> where  I can go in and add more debug statements to try and narrow  
>>> this  down.  I'm getting worried since this is the busiest time of  
>>> the  year for Imp usage on our campus.  The last thing we need is  
>>> to be  blamed when students try to email their assignments or  
>>> whatever for  their final marks and it doesn't attach.  That's  
>>> 50,000+ potentially  pissed students.  So hopefully with the help  
>>> of the Imp team we can  identify the problem quickly.
>>>
>>>
>>>
>>>
>>>
>>> On Nov 23, 2007, at 4:44 AM, Graeme Wood wrote:
>>>
>>>> I've also got a problem with some attachments not being uploaded   
>>>> and then appearing as zero length when the messages are sent.   
>>>> It  doesn't make any difference whether it is a clustered service  
>>>> or  not, as we have both one service made up of multiple web  
>>>> front-ends  and one which is a single web front-end.  I also am  
>>>> using just the  file system to store uploaded files, but there is  
>>>> no NFS. The  behaviour looks like either a failure in PHP to  
>>>> create the  temporary filename or a race condition which means  
>>>> that the  filename isn't there when the compose.php looks for it.  
>>>> We get  errors logged in the apache logs to say that the  
>>>> temporary file  doesn't exist.
>>>>
>>>> I'm not sure when this problem first started occuring as we have   
>>>> only in the last few months started getting reports about this.
>>>>
>>>> I'm running Horde 3.1.3, IMP 4.1.3 and PHP 4.4.7.
>>>>
>>>> On Thu, 22 Nov 2007, Kevin Konowalec wrote:
>>>>
>>>>> Horde 3.1.5
>>>>> IMP 4.1.5
>>>>> PHP 4.4.1
>>>>> Clustered environment all sharing common NFS space for uploaded   
>>>>> files.
>>>>>
>>>>>
>>>>> I was wondering if it was possible to separate the VFS DB from the
>>>>> regular SQL backend?  We're trying to do some testing to see why
>>>>> attachments are randomly failing and want to be able to use the
>>>>> production database for preferences and address book but want  
>>>>> to  shift
>>>>> the VFS storage to a second non-production database box for test
>>>>> purposes.  Is that doable?  If so, how?
>>>>>
>>>>> We're trying to test if the problem we're having with attachments
>>>>> randomly not being sent (though having been successfully  
>>>>> uploaded to
>>>>> the server) is related to not using VFS at all (simply storing the
>>>>> uploaded files on a shared NFS volume).
>>>>>
>>>>>
>>>>>
>>>> -- 
>>>> Graeme Wood, Unix Section of the IT Infrastructure Division,
>>>> Information Services, The University of Edinburgh
>>>> Email: Graeme.Wood at ed.ac.uk Phone: +44 131 650 5003 Fax: +44 131   
>>>> 650 6552
>>>>
>>>> The University of Edinburgh is a charitable body,
>>>> registered in Scotland, with registration number SC005336.
>>>>
>
> -- 
> Robert Sand.
> mailto:rsand at d.umn.edu
> 1208 Kirby Drive
> 366 K Plz
> Duluth, MN 55812-3095
> 218-726-6122        fax 218-726-7674
>
> "Walk behind me I may not lead, Walk in front of me I may not follow,
> Walk beside me and we walk together"  UTE Tribal proverb.
>



More information about the horde mailing list