Inbound Email Issues

[erikimorton]

I've been having a lot of difficulty getting the inbound email process to work in the scheduler. I have no problem polling my email account with POP and the cron is set up correctly. As i was debugging I discovered that SugarCRM will not execute a scheduler if that scheduler is already in process, which makes sense. However I kept on having my Inbound Email scheduler stuck "in process". Through some debugging I found the following error:

*** glibc detected *** double free or corruption (out):

I really have no idea what that could possibly mean. The net result is that the emails are downloaded but the error causes the scheduler to remain "in progress", which prevents it from running again.

Any thoughts would be much appreciated.

Regards,
Erik

Red Hat Enterprise 4
Apache 2.2
PHP 5.2
SugarCRM 4.5.0

[erikimorton]

I found a reference in the RedHat EL4 release notes about this error: http://www.redhat.com/docs/manuals/e...-notes/ws-x86/

The version of glibc provided with Red Hat Enterprise Linux 4 performs additional internal sanity checks to prevent and detect data corruption as early as possible. By default, should corruption be detected, a message similar to the following will be displayed on standard error (or logged via syslog if stderr is not open):

I set the MALLOC_CHECK_=1 with the following results:

[initiate@destro SugarOS-Full-4.5.0h]$ cd /var/www/apps/SugarOS-Full-4.5.0h; php -f cron.php
malloc: using debugging hooks
malloc: using debugging hooks
*** glibc detected *** free(): invalid pointer: 0x00906838 ***
Segmentation fault
[initiate@destro Sug

I don't know how to find out where the seg fault is coming from. My first thought was that it could be coming from the library that is used to pull down the email. This is the library that I installed to get PHP to compile with --with-imap and --with-imap-ssl: ftp://ftp.cac.washington.edu/imap/imap.tar.Z

Any thoughts? Thanks in advance.

Erik

[ddbtek]

Hi,

This is the issue-- and it has popped up all over the world in a lot of different environments. Basically the glibc library is being called and asked to release a chunk of memory that's already been freed.

Enterprise versions of Linux (RHEL, CENTOS, etc.) have more robust versions of glibc. These versions see that they have been asked to release a chunk of memory that has already been freed and they report it and cause the application to abort, to protect the system. In the old days the system would have possibly corrupted memory and after a few hundreds or thousand iterations the system would tank, unstable.

In this specific case it appears to be an issue with using TLS (SSL) for encrypted IMAP access. It's very near the end of closing TLS.

Here is a link that more closely describes the problem: http://www.zmailer.org/mhalist/2006/msg00071.html

You can set an environment variable to tell glibc to ignore the error and allow the application to continue. I don't know if that allows glibc to actually do the free() call in which case the system might eventually become unstable and I wouldn't recommend it.

I think this can be fixed if the developers at Sugar review the way they are working with TLS from within PHP. I hope the above link helps.

Thanks,
David

[ddbtek]

here's some more info-- Is there a way to submit a ticket on this here--

Here's where the problem happens-- we have 3 INBOX for it to scan. It logs in, scans the first, gets authenticated TLS/SSL and the does a IMAP Logout. Right after than it does a boatload of stuff internally, getting to:

lstat64...
lstat64...
lstat64...
fstat64(7, {st_mode=S_IFREG|0644, st_size=18674, ...}) = 0
mmap2(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb76cf000
read(7, "<?php\r\n/* vim: set expandtab tab"..., 8192) = 8192
read(7, "B6, 0xEBADFE6E, 0xEAC31F66,\r\n   "..., 8192) = 8192
read(7, "88D40, 0xCCD2017F, 0x6BB4E3BB,\r\n"..., 8192) = 2290
read(7, "", 8192)                       = 0
mmap2(NULL, 528384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb764e000
close(7)                                = 0
alarm(0)                                = 0
alarm(0)                                = 0
alarm(0)                                = 0
time(NULL)                              = 1179902787

...

then we see:

socket(PF_FILE, SOCK_STREAM, 0)         = 7
fcntl64(7, F_GETFL)                     = 0x2 (flags O_RDWR)
fcntl64(7, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(7)                                = 0
socket(PF_FILE, SOCK_STREAM, 0)         = 7
fcntl64(7, F_GETFL)                     = 0x2 (flags O_RDWR)
fcntl64(7, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(7)                                = 0
open("/etc/host.conf", O_RDONLY)        = 7
fstat64(7, {st_mode=S_IFREG|0644, st_size=17, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb764d000
read(7, "order hosts,bind\n", 4096)     = 17
read(7, "", 4096)                       = 0
close(7)                                = 0
munmap(0xb764d000, 4096)                = 0
futex(0x680f00, FUTEX_WAKE, 2147483647) = 0
open("/etc/hosts", O_RDONLY)            = 7
fcntl64(7, F_GETFD)                     = 0
fcntl64(7, F_SETFD, FD_CLOEXEC)         = 0
fstat64(7, {st_mode=S_IFREG|0444, st_size=205, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb764d000
read(7, "# Do not remove the following li"..., 4096) = 205
close(7)                                = 0
munmap(0xb764d000, 4096)                = 0
open("/etc/protocols", O_RDONLY)        = 7

...

open("/usr/share/ssl/cert.pem", O_RDONLY) = 8
fstat64(8, {st_mode=S_IFREG|0644, st_size=249373, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb764d000

then it does a bunch of reads of the key...

then a "getpeername()" call..

then it opens /etc/hosts...

then we get right down to the crash:

alarm(0)                                = 0
alarm(0)                                = 0
time(NULL)                              = 1179902787
alarm(0)                                = 0
alarm(0)                                = 0
write(7, "\25\3\1\0 \f\315\313\253\315\352\201\316\374+\364\27\34"..., 37) = 37
open("/dev/tty", O_RDWR|O_NONBLOCK|O_NOCTTY) = 8
writev(8, [{"*** glibc detected *** ", 23}, {"free(): invalid pointer", 23}, {": 0x", 4}, {"0067f878", 8}, {" ***\n", 5}], 5*** glibc detected *** free(): invalid pointer: 0x0067f878 ***
) = 63
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
+++ killed by SIGSEGV +++

[ddbtek]

The problem may be resolved by researching one or more of these files, executing code in one of these files seems to be where it's at...

./crm/include/Pear/HTML_Safe/Safe.php
./crm/include/Pear/XML_HTMLSax3/HTMLSax3/States.php
./crm/include/Pear/XML_HTMLSax3/HTMLSax3/Decorators.php
./crm/include/Pear/XML_HTMLSax3/HTMLSax3.php
./crm/include/Pear/Crypt_Blowfish/Blowfish/DefaultKey.php
./crm/include/Pear/Crypt_Blowfish/Blowfish.php

David