Discussion:
Valgrind, evmap_io_add Invalid write of size 4
(too old to reply)
Robin
2014-06-15 13:09:59 UTC
Permalink
Raw Message
Hey,

I was just debugging some crashes and memory leaks with valgrind and
this came up:
[warn] Epoll MOD(4) on fd 61 failed. Old events were 6; read change was
2 (del); write change was 0 (none): Bad file descriptor
==10706== Invalid write of size 4
==10706== at 0x5348FE6: evmap_io_add (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x5337BAA: event_add (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x5343A57: _bufferevent_add_event (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x53441DC: be_socket_enable (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x5343475: bufferevent_enable (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x806974F: net::Socket::Setup(int, sockaddr_in)
(Socket.cpp:77)
net::Listener<net::socket::Client>::Accept(int, sockaddr_in*)
(Listener.hpp:85)
net::Listener<net::socket::Client>::SOnAccept(evconnlistener*, int,
sockaddr*, int, void*) (Listener.hpp:112)
==10706== by 0x53462E1: listener_read_cb (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x78BBD23D: ???
==10706== Address 0x61d44e80 is 176 bytes inside a block of size
4,056 free'd
[...] Non libevent related stuff, some free'd memory which has nothing
to do with libevent
void Accept(evutil_socket_t fd, sockaddr_in * addr) {
sys_log(0, "New connection on %s:%d from %s",
m_bind_ip.c_str(), m_bind_port, inet_ntoa(addr->sin_addr));
SocketType* s = new SocketType();
s->SetID(m_socket_id++);
if (!s->Setup(fd, *addr)) {
sys_err("Failed to set up socket %d", m_socket_id);
delete s;
return;
}
if (!OnAccept(s)) {
delete s;
return;
}
m_sockets.insert(std::pair<unsigned int,
SocketType*>(s->GetID(), s));
}
static void SOnAccept(evconnlistener *, evutil_socket_t fd,
struct sockaddr * addr, int socklen, void * arg) {
if (!arg) {
sys_err("Recieved nullpointer as arg");
return;
}
Listener<SocketType>* l = (Listener<SocketType>*) arg;
l->Accept(fd, (sockaddr_in*) addr);
}
The callback is registered like this:
m_listener =
evconnlistener_new_bind(NetworkManager::instance().GetEventBase(),
Listener::SOnAccept, this, LEV_OPT_REUSEABLE | LEV_OPT_CLOSE_ON_FREE,
1024, (sockaddr*) & sa, sizeof (sa));
bool Socket::Setup(evutil_socket_t fd, sockaddr_in addr) {
if (m_event) {
sys_err("Socket already set up");
return false;
}
m_addr = addr;
m_event =
bufferevent_socket_new(NetworkManager::instance().GetEventBase(), fd,
_SOCKET_DEFAULT_FLAGS);
bufferevent_setcb(m_event, Socket::SOnRead, Socket::SOnWrite,
Socket::SOnEvent, this);
bufferevent_enable(m_event, EV_READ | EV_WRITE);
OnConnect();
return true;
}
Is this just a false positive or am I doing something wrong?
This doesn't happen every time there's a new connection, in fact, it
only seems to happen once

I am running on Debian Wheezy & libevent 2.0.19
[warn] Epoll MOD(4) on fd 68 failed. Old events were 6; read change
was 2 (del); write change was 0 (none): Bad file descriptor
Usually after it hit a breakpoint or it couldn't keep up (running this
in a single thread+valgrind, stuff gets sloow)
Am I right to assume I can just ignore it as it only seems to happen
when running valgrind?


- imer
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Azat Khuzhin
2014-06-15 13:46:04 UTC
Permalink
Raw Message
Hey,
I was just debugging some crashes and memory leaks with valgrind and this
[warn] Epoll MOD(4) on fd 61 failed. Old events were 6; read change was 2
(del); write change was 0 (none): Bad file descriptor
Hi,

I don't see any reason why epoll_ctl() can fail under valgrind only, so
seems that this is *not* false-positive.
You could try to use $(valgrind --db-attach=yes) to investigate this.
==10706== Invalid write of size 4
==10706== at 0x5348FE6: evmap_io_add (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x5337BAA: event_add (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x5343A57: _bufferevent_add_event (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x53441DC: be_socket_enable (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x5343475: bufferevent_enable (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x806974F: net::Socket::Setup(int, sockaddr_in)
(Socket.cpp:77)
==10706== by 0x8068A96: net::Listener<net::socket::Client>::Accept(int,
sockaddr_in*) (Listener.hpp:85)
net::Listener<net::socket::Client>::SOnAccept(evconnlistener*, int,
sockaddr*, int, void*) (Listener.hpp:112)
==10706== by 0x53462E1: listener_read_cb (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==10706== by 0x78BBD23D: ???
==10706== Address 0x61d44e80 is 176 bytes inside a block of size 4,056
free'd
[...] Non libevent related stuff, some free'd memory which has nothing to
do with libevent
void Accept(evutil_socket_t fd, sockaddr_in * addr) {
sys_log(0, "New connection on %s:%d from %s",
m_bind_ip.c_str(), m_bind_port, inet_ntoa(addr->sin_addr));
SocketType* s = new SocketType();
s->SetID(m_socket_id++);
if (!s->Setup(fd, *addr)) {
sys_err("Failed to set up socket %d", m_socket_id);
delete s;
return;
}
if (!OnAccept(s)) {
delete s;
return;
}
m_sockets.insert(std::pair<unsigned int,
SocketType*>(s->GetID(), s));
}
static void SOnAccept(evconnlistener *, evutil_socket_t fd, struct
sockaddr * addr, int socklen, void * arg) {
if (!arg) {
sys_err("Recieved nullpointer as arg");
return;
}
Listener<SocketType>* l = (Listener<SocketType>*) arg;
l->Accept(fd, (sockaddr_in*) addr);
}
m_listener =
evconnlistener_new_bind(NetworkManager::instance().GetEventBase(),
Listener::SOnAccept, this, LEV_OPT_REUSEABLE | LEV_OPT_CLOSE_ON_FREE, 1024,
(sockaddr*) & sa, sizeof (sa));
Do you have one event-base per thread?
bool Socket::Setup(evutil_socket_t fd, sockaddr_in addr) {
if (m_event) {
sys_err("Socket already set up");
return false;
}
m_addr = addr;
m_event =
bufferevent_socket_new(NetworkManager::instance().GetEventBase(), fd,
_SOCKET_DEFAULT_FLAGS);
bufferevent_setcb(m_event, Socket::SOnRead, Socket::SOnWrite,
Socket::SOnEvent, this);
bufferevent_enable(m_event, EV_READ | EV_WRITE);
OnConnect();
return true;
}
Is this just a false positive or am I doing something wrong?
This doesn't happen every time there's a new connection, in fact, it only
seems to happen once
I am running on Debian Wheezy & libevent 2.0.19
Could you try with the latest libevent version?
(But I don't see any patches that can fix it in history)
[warn] Epoll MOD(4) on fd 68 failed. Old events were 6; read change was 2
(del); write change was 0 (none): Bad file descriptor
Usually after it hit a breakpoint or it couldn't keep up (running this in a
single thread+valgrind, stuff gets sloow)
Am I right to assume I can just ignore it as it only seems to happen when
running valgrind?
- imer
***********************************************************************
unsubscribe libevent-users in the body.
--
Respectfully
Azat Khuzhin
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Robin
2014-06-15 14:28:39 UTC
Permalink
Raw Message
Post by Azat Khuzhin
Hey,
I was just debugging some crashes and memory leaks with valgrind and this
[warn] Epoll MOD(4) on fd 61 failed. Old events were 6; read change was 2
(del); write change was 0 (none): Bad file descriptor
Hi,
I don't see any reason why epoll_ctl() can fail under valgrind only, so
seems that this is *not* false-positive.
You could try to use $(valgrind --db-attach=yes) to investigate this.
Whoops, the [warn] Epoll message wasnt mean to be there, was talking
about the Invalid write.
Post by Azat Khuzhin
Do you have one event-base per thread?
I only have one event-base and the application is single threaded
Post by Azat Khuzhin
Is this just a false positive or am I doing something wrong?
This doesn't happen every time there's a new connection, in fact, it only
seems to happen once
I am running on Debian Wheezy & libevent 2.0.19
Could you try with the latest libevent version?
(But I don't see any patches that can fix it in history)
I've just tried it with 2.0.21 (or were you talking about 2.1.x?) and
it's still happening.
Post by Azat Khuzhin
==14175== Invalid write of size 4
==14175== at 0x5348E76: evmap_io_add (evmap.c:328)
==14175== by 0x5337ACA: event_add (event.c:2073)
==14175== by 0x5343927: _bufferevent_add_event (bufferevent.c:858)
==14175== by 0x53440AC: be_socket_enable (bufferevent_sock.c:554)
==14175== by 0x5343345: bufferevent_enable (bufferevent.c:422)
==14175== by 0x806974F: net::Socket::Setup(int, sockaddr_in)
(Socket.cpp:77)
net::Listener<net::socket::Client>::Accept(int, sockaddr_in*)
(Listener.hpp:85)
net::Listener<net::socket::Client>::SOnAccept(evconnlistener*, int,
sockaddr*, int, void*) (Listener.hpp:112)
==14175== by 0x5346161: listener_read_cb (listener.c:417)
==14175== by 0xF11D8657: ???
Although it might be my code doing some bad stuff, writing to memory it
shouldnt - still gotta figure that out.
It's still odd it only happens once though.
Post by Azat Khuzhin
[warn] Epoll MOD(4) on fd 68 failed. Old events were 6; read change was 2
(del); write change was 0 (none): Bad file descriptor
Usually after it hit a breakpoint or it couldn't keep up (running this in a
single thread+valgrind, stuff gets sloow)
Am I right to assume I can just ignore it as it only seems to happen when
running valgrind?
- imer
***********************************************************************
unsubscribe libevent-users in the body.
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Azat Khuzhin
2014-06-15 15:23:01 UTC
Permalink
Raw Message
Post by Azat Khuzhin
Hey,
I was just debugging some crashes and memory leaks with valgrind and this
[warn] Epoll MOD(4) on fd 61 failed. Old events were 6; read change was 2
(del); write change was 0 (none): Bad file descriptor
Hi,
I don't see any reason why epoll_ctl() can fail under valgrind only, so
seems that this is *not* false-positive.
You could try to use $(valgrind --db-attach=yes) to investigate this.
Whoops, the [warn] Epoll message wasnt mean to be there, was talking about
the Invalid write.
Post by Azat Khuzhin
Do you have one event-base per thread?
I only have one event-base and the application is single threaded
Post by Azat Khuzhin
Is this just a false positive or am I doing something wrong?
This doesn't happen every time there's a new connection, in fact, it only
seems to happen once
I am running on Debian Wheezy & libevent 2.0.19
Could you try with the latest libevent version?
(But I don't see any patches that can fix it in history)
I've just tried it with 2.0.21 (or were you talking about 2.1.x?) and it's
still happening.
Yeah, I'm talking about 2.1.x (even better, clone git repository and
compile it by yourself.)
Post by Azat Khuzhin
==14175== Invalid write of size 4
==14175== at 0x5348E76: evmap_io_add (evmap.c:328)
==14175== by 0x5337ACA: event_add (event.c:2073)
==14175== by 0x5343927: _bufferevent_add_event (bufferevent.c:858)
==14175== by 0x53440AC: be_socket_enable (bufferevent_sock.c:554)
==14175== by 0x5343345: bufferevent_enable (bufferevent.c:422)
==14175== by 0x806974F: net::Socket::Setup(int, sockaddr_in)
(Socket.cpp:77)
==14175== by 0x8068A96: net::Listener<net::socket::Client>::Accept(int,
sockaddr_in*) (Listener.hpp:85)
net::Listener<net::socket::Client>::SOnAccept(evconnlistener*, int,
sockaddr*, int, void*) (Listener.hpp:112)
==14175== by 0x5346161: listener_read_cb (listener.c:417)
==14175== by 0xF11D8657: ???
Although it might be my code doing some bad stuff, writing to memory it
shouldnt - still gotta figure that out.
AFAIR I don't have such warnings under valgrind, and I'v just do simple
check on some of servers that use event listeners and bufferevent's and
there is no warnings related to libevent
(But I use upstream libevent, and there are some patches ahead, but
those are for signal layer, so it mustn't impact)
It's still odd it only happens once though.
Post by Azat Khuzhin
[warn] Epoll MOD(4) on fd 68 failed. Old events were 6; read change was 2
(del); write change was 0 (none): Bad file descriptor
Usually after it hit a breakpoint or it couldn't keep up (running this in a
single thread+valgrind, stuff gets sloow)
Am I right to assume I can just ignore it as it only seems to happen when
running valgrind?
- imer
***********************************************************************
unsubscribe libevent-users in the body.
***********************************************************************
unsubscribe libevent-users in the body.
--
Respectfully
Azat Khuzhin
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Nick Mathewson
2014-06-16 12:42:38 UTC
Permalink
Raw Message
On Sun, Jun 15, 2014 at 10:28 AM, Robin <***@imer.cc> wrote:
[...]
I've just tried it with 2.0.21 (or were you talking about 2.1.x?) and it's
still happening.
Post by Azat Khuzhin
==14175== Invalid write of size 4
==14175== at 0x5348E76: evmap_io_add (evmap.c:328)
If I'm matching the line number to the version properly, line 328 is:
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Nick Mathewson
2014-06-16 12:50:15 UTC
Permalink
Raw Message
[...]
I've just tried it with 2.0.21 (or were you talking about 2.1.x?) and it's
still happening.
Post by Azat Khuzhin
==14175== Invalid write of size 4
I assume you're compiling for a 32-bit architecture here. If not, my
analysis below is wrong.
Post by Azat Khuzhin
==14175== at 0x5348E76: evmap_io_add (evmap.c:328)
Whoa, sorry, premature send. :(

If I'm matching the line number to the version properly, line 328 is:
TAILQ_INSERT_TAIL(&ctx->events, ev, ev_io_next);

Is that what you have? (In other words, if you match the failing line
number to the code you compiled, is that the line you're seeing?)

The TAILQ_INSERT_TAIL macro is defined as:

#define TAILQ_INSERT_TAIL(head, elm, field) do { \
(elm)->field.tqe_next = NULL; \
(elm)->field.tqe_prev = (head)->tqh_last; \
*(head)->tqh_last = (elm); \
(head)->tqh_last = &(elm)->field.tqe_next; \
} while (0)

So the only pointers accessed there are fields in ev->ev_io_next,
fields in ctx->events, and (indirectly) whatever the tqh_last pointer
points to.

I think it's unlikely that "ev->ev_io_next" or "ctx->events" would be
freed or invalid, since they're part of the ev and ctx structures
respectively, and those structures are used elsewhere in
evmap_io_add().

What seems more likely to me is that the ctx->events.tqh_last point
has become corrupt, and no longer points to a valid event pointer.
The most common way for this to happen would be if one of the events
for this fd has been freed without first removing it from the
event_base with event_del(). It might also happen, I think, if you
use event_assign() or event_set() to change an event's configuration
without first removing it from the event_base with event_del().

hope this helps,
--
Nick
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Catalin Patulea
2014-06-16 23:33:36 UTC
Permalink
Raw Message
I saw similar things a long while back, stacks looking like this:

==18923== Invalid write of size 8
==18923== at 0x452C2C: evmap_io_add (evmap.c:328)
==18923== by 0x446715: event_add_internal (event.c:2033)
==18923== by 0x446AF3: event_add (event.c:1926)
==18923== by 0x44E91C: _bufferevent_add_event (bufferevent.c:860)
==18923== by 0x44FE66: be_socket_enable (bufferevent_sock.c:552)
==18923== by 0x44EF47: bufferevent_enable (bufferevent.c:422)
==18923== by 0x45B7BC: evhttp_connection_connect (http.c:2215)
==18923== by 0x45B945: evhttp_make_request (http.c:2270)
[...]

==18923== Invalid write of size 8
==18923== at 0x4524D0: evmap_io_del (evmap.c:384)
==18923== by 0x4471C3: event_del (event.c:2211)
==18923== by 0x44F85D: be_socket_disable (bufferevent_sock.c:569)
==18923== by 0x44E286: bufferevent_suspend_write (bufferevent.c:96)
==18923== by 0x450198: bufferevent_socket_connect_hostname
(bufferevent_sock.c:487)
==18923== by 0x45B7E0: evhttp_connection_connect (http.c:2217)
==18923== by 0x45B945: evhttp_make_request (http.c:2270)
[...]

There's definitely some state sync issues between what evhttp thinks
about a socket, and what evmap/epoll think.

At the time, this patch reduced our crash rate significantly (7x):
http://archives.seul.org/libevent/users/Dec-2012/msg00034.html

(thread continued here:
http://archives.seul.org/libevent/users/Feb-2013/msg00020.html)

Nick, you proposed a different variant of the patch in this post:
http://archives.seul.org/libevent/users/Feb-2013/msg00028.html

But I never had a chance to try it.

Sorry I can't offer more concrete information.
Post by Nick Mathewson
[...]
I've just tried it with 2.0.21 (or were you talking about 2.1.x?) and it's
still happening.
Post by Azat Khuzhin
==14175== Invalid write of size 4
I assume you're compiling for a 32-bit architecture here. If not, my
analysis below is wrong.
Post by Azat Khuzhin
==14175== at 0x5348E76: evmap_io_add (evmap.c:328)
Whoa, sorry, premature send. :(
TAILQ_INSERT_TAIL(&ctx->events, ev, ev_io_next);
Is that what you have? (In other words, if you match the failing line
number to the code you compiled, is that the line you're seeing?)
#define TAILQ_INSERT_TAIL(head, elm, field) do { \
(elm)->field.tqe_next = NULL; \
(elm)->field.tqe_prev = (head)->tqh_last; \
*(head)->tqh_last = (elm); \
(head)->tqh_last = &(elm)->field.tqe_next; \
} while (0)
So the only pointers accessed there are fields in ev->ev_io_next,
fields in ctx->events, and (indirectly) whatever the tqh_last pointer
points to.
I think it's unlikely that "ev->ev_io_next" or "ctx->events" would be
freed or invalid, since they're part of the ev and ctx structures
respectively, and those structures are used elsewhere in
evmap_io_add().
What seems more likely to me is that the ctx->events.tqh_last point
has become corrupt, and no longer points to a valid event pointer.
The most common way for this to happen would be if one of the events
for this fd has been freed without first removing it from the
event_base with event_del(). It might also happen, I think, if you
use event_assign() or event_set() to change an event's configuration
without first removing it from the event_base with event_del().
hope this helps,
--
Nick
***********************************************************************
unsubscribe libevent-users in the body.
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Robin
2014-06-18 22:27:31 UTC
Permalink
Raw Message
Sorry for the late reponse.
I tried the latest code from github and it didnt give me the invalid
write. Although I'd prefer to use the easy to install libraries from
debian itself instead of having to compile them myself.
Maybe I'm just doing something wrong and it isnt a libevent glitch?
Post by Nick Mathewson
The most common way for this to happen would be if one of the events
for this fd has been freed without first removing it from the
event_base with event_del().
I'm calling bufferevent_free() in the destructor of my socket class -
that's all I need to do or did I miss anything?
Post by Nick Mathewson
It might also happen, I think, if you
use event_assign() or event_set() to change an event's configuration
without first removing it from the event_base with event_del().
Not using any of those, so I should be good there.

This one makes a bit more sense, thats libevent memory I assume?
Post by Nick Mathewson
==3728== Invalid write of size 4
==3728== at 0x5348FE6: evmap_io_add (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==3728== by 0x5337BAA: event_add (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==3728== by 0x5343A57: _bufferevent_add_event (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==3728== by 0x53441DC: be_socket_enable (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==3728== by 0x5343475: bufferevent_enable (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==3728== by 0x806978F: net::Socket::Setup(int, sockaddr_in)
(Socket.cpp:77)
net::Listener<net::socket::Client>::Accept(int, sockaddr_in*)
(Listener.hpp:85)
net::Listener<net::socket::Client>::SOnAccept(evconnlistener*, int,
sockaddr*, int, void*) (Listener.hpp:112)
==3728== by 0x53462E1: listener_read_cb (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
==3728== by 0x892CFED8: ???
==3728== Address 0x4ec8e170 is 112 bytes inside a block of size 268
free'd
==3728== at 0x51DF50C: free (vg_replace_malloc.c:427)
==3728== by 0x53396C3: event_mm_free_ (in
/usr/lib/i386-linux-gnu/libevent-2.0.so.5.1.7)
net::socket::Generic<net::socket::Client>::~Generic() (Generic.hpp:45)
==3728== by 0x81E45A3: net::socket::Client::~Client() (Client.cpp:47)
==3728== by 0x81E4646: net::socket::Client::~Client() (Client.cpp:52)
net::Listener<net::socket::Client>::RemoveClosed() (Listener.hpp:68)
==3728== by 0x8068454: net::NetworkManager::Tick()
(NetworkManager.cpp:89)
==3728== by 0x81A4277: idle() (main.cpp:552)
==3728== by 0x81A355D: main (main.cpp:299)
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.
Robin
2014-06-18 22:34:44 UTC
Permalink
Raw Message
So, I just had an idea
How would one go about forcefully closing a bufferevent correctly?
bool Socket::Close() {
if (!m_event) {
sys_err("Tried to close socket while m_event is a nullptr");
return false;
}
evutil_socket_t fd = bufferevent_getfd(m_event);
if (fd < 0) {
sys_err("Tried to close socket while m_event is not
connected (fd < 0)");
return false;
}
if (evutil_closesocket(fd) < 0) {
int err = evutil_socket_geterror(fd);
sys_err("Closing the socket %d failed. %s errorcode (%d)",
fd, evutil_socket_error_to_string(err), err);
return false;
}
// Simulate EOf event so we can handle disconnect properly
OnEvent(BEV_EVENT_EOF);
return true;
}
This might be the reason the stuff is corrupted (dont know why I didnt
think of this earlier, sorry!)
***********************************************************************
To unsubscribe, send an e-mail to ***@freehaven.net with
unsubscribe libevent-users in the body.

Loading...