kisli
Socket-Exception causes memory-error and core-file (-> free(): corrupted unsorted chunks:)
Hello Vincent,
we have a strange problem with the vmime-library.
Sometimes the library throws an exception named "ECONNRESET: connection reset by peer".
The exception is thrown, after the connection to an IMAP-Server is established and DURING vmime tries to provide the folder-status. We catch the exception, but the memory seems to be corrupted and a short time later the whole application cores.
(It seems, that the state of the folder-object in general is somehow corrupt after the exception(?), cause calling the close()-method from the folder raises another exception "broken pipe", but the isOpen()-Method returned true before!)
I analyzed the problem and provided a minimal example, logically derived from our real-world application, which provokes the memory-crash (Without the "broken pipe"-issue, cause this is probably a subsequent fault).
We are using the vmime version with GIT-Hash: 265baf17aa671f78695aed137200d922ae14b633
Thanx for your super support!
Minimal compilable example (CentOS release 6.5 (Final), 2.6.32-431.el6.x86_64)
#define VMIME_STATIC
#include <vmime/vmime.hpp>
#include <iostream>
#include <fstream>
#include <exception>
struct MyCV : vmime::security::cert::defaultCertificateVerifier
{
void verify(__attribute__((unused))vmime::shared_ptr<vmime::security::cert::certificateChain> c,
__attribute__((unused))const vmime::string& h) {}
};
struct MyTH : vmime::net::timeoutHandler
{
virtual bool isTimeOut() {return (getTime() >= m_last + 20);}
virtual void resetTimeOut() {m_last = getTime(); }
virtual bool handleTimeOut() {std::cout << "TimeOut!" << getTime() << std::endl; return false;}
unsigned long getTime() {return vmime::platform::getHandler()->getUnixTime();}
unsigned long m_last;
};
struct MyTHF : vmime::net::timeoutHandlerFactory
{
vmime::shared_ptr<vmime::net::timeoutHandler> create() {return vmime::make_shared<MyTH>();}
};
struct MyT : vmime::net::tracer
{
MyT(const vmime::string& proto, const int cId) : m_p(proto), m_cId(cId) {}
void traceSend(const vmime::string& line)
{
if (!logger.is_open())
logger.open("example.log", std::ofstream::out | std::ofstream::app);
logger << "[" << m_p << ":" << m_cId << "] CLIENT: " << line << std::endl;
}
void traceReceive(const vmime::string& line)
{
if (!logger.is_open())
logger.open("example.log", std::ofstream::out | std::ofstream::app);
logger << "[" << m_p << ":" << m_cId << "] SERVER: " << line << std::endl;
}
const vmime::string m_p;
const int m_cId;
std::ofstream logger;
};
class MyTF : public vmime::net::tracerFactory
{
vmime::shared_ptr<vmime::net::tracer> create(vmime::shared_ptr<vmime::net::service> serv, const int cId)
{
return vmime::make_shared<MyT>(serv->getProtocolName(), cId);
}
};
int main()
{
std::ofstream logger;
logger.open("example.log", std::ofstream::out | std::ofstream::app);
while(true)
{
logger << "[DEBUG-LOG] Iteration start" << "..." << std::endl;
vmime::shared_ptr<vmime::net::session> sess = vmime::net::session::create();
sess->getProperties().setProperty("store.protocol","imap");
vmime::shared_ptr<vmime::net::store> store = sess->getStore();
store->setProperty("server.address","Exchange?????.de");
store->setProperty("server.port",143);
store->setProperty("connection.tls", true);
store->setProperty("connection.tls.required", true);
store->setProperty("options.need-authentication", true);
store->setProperty("auth.username", "?????");
store->setProperty("auth.password", "?????");
store->setProperty("options.chunking",false);
store->setCertificateVerifier(vmime::make_shared<MyCV>());
store->setTimeoutHandlerFactory(vmime::make_shared<MyTHF>());
store->setTracerFactory(vmime::make_shared<MyTF>());
store->connect();
vmime::shared_ptr<vmime::net::folder> folder;
folder = store->getDefaultFolder();
folder->open(vmime::net::folder::MODE_READ_WRITE);
logger << "[DEBUG-LOG] folder opend!" << std::endl;
try
{
if (folder.get() && folder->isOpen())
{
logger << "[DEBUG-LOG] Calling folder->getStatus() ..." << std::endl;
vmime::shared_ptr<vmime::net::folderStatus> fs = folder->getStatus(); //ECONNRESET-Exception is thrown here!!!!!
logger << "[DEBUG-LOG] Called folder->getStatus()" << std::endl;
if(fs.get())
std::cout << "[DEBUG-LOG] Mail-Count: " << fs->getUnseenCount() << std::endl;
}
}
catch (const vmime::exception& ex)
{
logger << "[DEBUG-LOG] Exception1 caught: ex.name:" << ex.name() << " WHAT: " << ex.what() << ">" << std::endl;
}
} // NO next iteration -> program cores!
return 0;
}
To fake the exception at the correct time, I built an interactive "std::cin" at the necessarry code-fragment, to throw the exception on the fly at the correct time.
posixSocket.cpp: sendRawNonBlocking modified to throw interactive the exception
#include <iostream>
#include <string>
#include <sstream>
size_t posixSocket::sendRawNonBlocking(const byte_t* buffer, const size_t count)
{
m_status &= ~STATUS_WOULDBLOCK;
std::string input = "";
std::cout << "Please enter 1 to simulate the ECONNRESET-Exception:";
std::getline(std::cin, input);
int myNumber = 0;
bool bForceException=false;
std::stringstream myStream(input);
myStream >> myNumber;
if (myNumber==1)
{
std::cout << "Exception will be prepared now ..." << std::endl;
bForceException=true;
}
#if VMIME_HAVE_MSG_NOSIGNAL
const ssize_t ret = ::send(m_desc, buffer, count, MSG_NOSIGNAL);
#else
const ssize_t ret = ::send(m_desc, buffer, count, 0);
#endif
if (ret <= 0 || bForceException)
{
if (bForceException || (ret < 0 && !IS_EAGAIN(errno)))
{
bForceException=false;
throwSocketError(errno); //ECONNRESET was thrown here
}
// Check if we are timed out
if (m_timeoutHandler &&
m_timeoutHandler->isTimeOut())
{
if (!m_timeoutHandler->handleTimeOut())
{
// Could not send data within timeout delay
throw exceptions::operation_timed_out();
}
else
{
// Reset timeout
m_timeoutHandler->resetTimeOut();
}
}
m_status |= STATUS_WOULDBLOCK;
// No data can be written at this time
return 0;
}
posixSocket.cpp: sendRaw modified to throw interactive the exception
#include <iostream>
#include <string>
#include <sstream>
void posixSocket::sendRaw(const byte_t* buffer, const size_t count)
{
m_status &= ~STATUS_WOULDBLOCK;
size_t size = count;
std::string input = "";
std::cout << "Please enter 1 to simulate the ECONNRESET-Exception:";
std::getline(std::cin, input);
int myNumber = 0;
bool bForceException=false;
std::stringstream myStream(input);
myStream >> myNumber;
if (myNumber==1)
{
std::cout << "Exception will be prepared now ..." << std::endl;
bForceException=true;
}
while (size > 0)
{
#if VMIME_HAVE_MSG_NOSIGNAL
const ssize_t ret = ::send(m_desc, buffer, size, MSG_NOSIGNAL);
#else
const ssize_t ret = ::send(m_desc, buffer, size, 0);
#endif
if (ret <= 0 || bForceException)
{
if (bForceException || (ret < 0 && !IS_EAGAIN(errno)))
{
bForceException=false;
throwSocketError(errno); //ECONNRESET was thrown here
}
waitForWrite(50 /* msecs */);
}
else
{
buffer += ret;
size -= ret;
}
}
HERE THE LOG FROM THE INERACTIVE SHELL (IMAPFolder.cpp also modified with logs)
Please enter 1 to simulate an ECONNRESET-Exception:1 You entered: 1 Exception will be prepared now ... (0x256eca0)[~IMAPFolder() 1] (0x256eca0)[~IMAPFolder() 2] (0x256eca0)[~IMAPFolder() 3] (0x256eca0)[~IMAPFolder() 4] (0x256eca0)[~IMAPFolder() 5] (0x256eca0)[close(const bool expunge) 1] (0x256eca0)[close(const bool expunge) 2] (0x256eca0)[close(const bool expunge) 3] (0x256eca0)[close(const bool expunge) 4] (0x256eca0)[close(const bool expunge) 5] (0x256eca0)[close(const bool expunge) 9] Please enter 1 to simulate an ECONNRESET-Exception: You entered: Please enter 1 to simulate an ECONNRESET-Exception: You entered: Please enter 1 to simulate an ECONNRESET-Exception: You entered: (0x256eca0)[~IMAPFolder() 9] (0x256eca0)[~IMAPFolder() 10] Please enter 1 to simulate an ECONNRESET-Exception: You entered: Please enter 1 to simulate an ECONNRESET-Exception: You entered: Please enter 1 to simulate an ECONNRESET-Exception: You entered: Please enter 1 to simulate an ECONNRESET-Exception: You entered: Please enter 1 to simulate an ECONNRESET-Exception: You entered: *** glibc detected *** ./example: free(): corrupted unsorted chunks: 0x0000000002581500 *** ======= Backtrace: ========= /lib64/libc.so.6[0x31d8676166] /lib64/libc.so.6[0x31d8678c93] /usr/lib64/libstdc++.so.6(_ZNSt19basic_ostringstreamIcSt11char_traitsIcESaIcEED1Ev+0xb3)[0x31dae99e03] ./example(ZN5vmime11propertySet8property8setValueIA5_cEEvRKT+0xc0)[0x470ca0] ./example(ZN5vmime11propertySet11setPropertyIA5_cEEvRKSsRKT+0x47)[0x470281] ./example(main+0xed)[0x46eb98] /lib64/libc.so.6(__libc_start_main+0xfd)[0x31d861ed1d] ./example[0x46e929] ======= Memory map: ======== 00400000-0097c000 r-xp 00000000 08:11 1725206 /home/prog/app/vmime_example/example 00b7c000-00ba7000 rw-p 0057c000 08:11 1725206 /home/prog/app/vmime_example/example
HERE THE LOG FROM THE MINIMAL EXAMPLE
[DEBUG-LOG] Iteration start... [imap:1] CLIENT: Connecting to Exchange?????.de, port 143 [imap:1] SERVER: * OK The Microsoft Exchange IMAP4 service is ready. [imap:1] CLIENT: a001 STARTTLS [imap:1] SERVER: a001 OK Begin TLS negotiation now. [imap:1] CLIENT: Beginning SSL/TLS handshake [imap:1] CLIENT: Getting peer certificates [imap:1] CLIENT: a002 CAPABILITY [imap:1] SERVER: * CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+ [imap:1] SERVER: a002 OK CAPABILITY completed. [imap:1] CLIENT: a003 AUTHENTICATE GSSAPI [imap:1] SERVER: + [imap:1] CLIENT: * [imap:1] SERVER: a003 NO The AUTH protocol exchange was canceled by the client. [imap:1] CLIENT: a004 AUTHENTICATE NTLM [imap:1] SERVER: + [imap:1] CLIENT: {...SASL exchange: 64 bytes of data...} [imap:1] CLIENT: {...SASL exchange: 216 bytes of data...} [imap:1] SERVER: a004 OK AUTHENTICATE completed. [imap:1] CLIENT: a005 LIST "" "" [imap:1] SERVER: * LIST (\Noselect \HasChildren) "/" "" [imap:1] SERVER: a005 OK LIST completed. [imap:2] CLIENT: Connecting to Exchange?????.de, port 143 [imap:2] SERVER: * OK The Microsoft Exchange IMAP4 service is ready. [imap:2] CLIENT: a001 STARTTLS [imap:2] SERVER: a001 OK Begin TLS negotiation now. [imap:2] CLIENT: Beginning SSL/TLS handshake [imap:2] CLIENT: Getting peer certificates [imap:2] CLIENT: a002 CAPABILITY [imap:2] SERVER: * CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+ [imap:2] SERVER: a002 OK CAPABILITY completed. [imap:2] CLIENT: a003 AUTHENTICATE GSSAPI [imap:2] SERVER: + [imap:2] CLIENT: * [imap:2] SERVER: a003 NO The AUTH protocol exchange was canceled by the client. [imap:2] CLIENT: a004 AUTHENTICATE NTLM [imap:2] SERVER: + [imap:2] CLIENT: {...SASL exchange: 64 bytes of data...} [imap:2] CLIENT: {...SASL exchange: 216 bytes of data...} [imap:2] SERVER: a004 OK AUTHENTICATE completed. [imap:2] CLIENT: a005 LIST "" "" [imap:2] SERVER: * LIST (\Noselect \HasChildren) "/" "" [imap:2] SERVER: a005 OK LIST completed. [imap:1] CLIENT: a006 CAPABILITY [imap:1] SERVER: * CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+ [imap:1] SERVER: a006 OK CAPABILITY completed. [imap:2] CLIENT: a006 SELECT INBOX [imap:2] SERVER: * 0 EXISTS [imap:2] SERVER: * 0 RECENT [imap:2] SERVER: * FLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent) [imap:2] SERVER: * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags [imap:2] SERVER: * OK [UIDVALIDITY 23669] UIDVALIDITY value [imap:2] SERVER: * OK [UIDNEXT 67] The next unique identifier value [imap:2] SERVER: a006 OK [READ-WRITE] SELECT completed. [DEBUG-LOG] folder opend! [DEBUG-LOG] Calling folder->getStatus() ... [DEBUG-LOG] Exception1 caught: ex.name:exception WHAT: Success> [imap:2] CLIENT: Disconnecting [imap:1] CLIENT: a007 LOGOUT [imap:1] CLIENT: Disconnecting [DEBUG-LOG] Iteration start...
GDB BT AT COREFILE
(gdb) bt full
#0 0x00000031d8632925 in raise () from /lib64/libc.so.6
No symbol table info available.
#1 0x00000031d8634105 in abort () from /lib64/libc.so.6
No symbol table info available.
#2 0x00000031d8670837 in __libc_message () from /lib64/libc.so.6
No symbol table info available.
#3 0x00000031d8676166 in malloc_printerr () from /lib64/libc.so.6
No symbol table info available.
#4 0x00000031d8678c93 in _int_free () from /lib64/libc.so.6
No symbol table info available.
#5 0x00000031dae99e03 in std::basic_ostringstream<char, std::char_traits
Hello!
Thank you for this very complete bug report. Unfortunately, I can't manage to reproduce the issue on my Linux box (Ubuntu 16.04.1 LTS) and current master.
I also ran the test program through Valgrind and found no problem. :/
Also, the IMAP server I connect to is obviously not the same as yours, but it's difficult to imagine how it could be related...
