Hi:
A trace giving a more refined picture of the problem and more details is
attached
to this note. It dumps what I consider to be the significant fields of
the uv_loop_t structure,
the Poll_Loop in my code, and the the dynamically allocated uv_poll_t
structure surrounding
the essential Libuv API routine calls. I think the format of the dump is
fairly intuitive
but please inform me if you disagree.
My comments about what is happening are identified by the string
"COMMENT:" and the
API calls are identified by the string "MPOLL". The trace is redacted to
eliminate
irrelevant events.
Please let me know if you see something amiss about the data structure
fields at
any point.
My server code is based on simple event oriented architecture and uses
the following 5 concurrent
tasks.
1) main(): Handles incoming connections and Linux signals. (Libuv based.)
2) IO_Task(): Handles incoming data from the network. (Libuv based.)
3) Protocol_Task(): Does most of the work. (Message based.)
4) DB_Task(): Does database insertions. (Message based.)
5) Timer_Task(): Handles timer management. (Mostly Libuv based.)
I can send you my server code and a test tool if it would be useful to you.
However, it may take a few days to put it in an easily useable form.
As previously mentioned uv_accept() executes in the main() task and the
rest of the polling related Libuv API routines execute in the IO_Task().
Finally, remember the problem is intermittent. Generally, it takes about
45 to 3 hours of constant concurrent connections for the crash to occur.
Best Regards,
Paul R.
On 05/01/2021 12:01 AM, Paul Romero wrote:
Hi:
I may have overlooked the following factor.
We know that Libuv is not reentrant and not really multi-task safe. I
suspect, but
don't know, that the internal Libuv data structures attached to the
uv_loop_t structure,
Poll_Loop in my case, are not protected by internal Libuv Mutexes.
1) uv_accept() and uv_fileno() exectute in the main() thread.
2) uv_poll_init(), uv_poll_start() and uv_poll_stop(), execute in the
IO_Task() thread.
That means uv_accept() and that the Libuv API routines in 2, above,
can execute concurrently.
Is it possible if such concurrency could damage the internal Libuv
data structures attached to the
uv_loop_t structure ? (Again Poll_Loop in my case.)
Best Regards,
Paul R.
NOTE: I did a few experments and noticed that calling uv_close() in a
Mutex often
prevents its callback routine from executing.
On 04/30/2021 04:59 PM, Paul Romero wrote:
Hi:
I think I've isolated the problem and it appears to be in uv_poll_stop().
In particlular if uv_accept() is called immediately after
uv_poll_stop(), and it reallocates the
same socket descriptor just freed by uv_poll_stop(), then
uv_poll_init() fails with the error
EEXIST or EBADF. This must have something to do with uv_loop_t handle
passed to uv_poll_init(),
called Poll_Loop in my code.
I had to instrument my code to keep track of Libuv API calls to see this.
The following explanatory items follows.
A - The sequence of calls that produces the problem.
B - Commented syslog() diagnostics.
C - The relevant code segments.
D - The gdb stack backtrace.
Best Regards,
Paul R.
A) The sequence of relevant calls is as follows and the problem only
occur with this exact
sequence of events.
****************************************************************************************
1) uv_poll_stop(): The uv_pool_t handle is bound to socket descriptor N.
This should free socket descriptor N.
2) uv_accept(): Bound to socket desciptor N as set by uv_fileno().
Socket descriptor N should be newly allocated.
3) uv_poll_init(): Returns EBADF with socket descriptor N and
Poll_Loop.watchers[N] is NULL.
Something is wrong !
B) The commented syslog() diagnostic sequence from the instrumented code.
**************************************************************************
* Stop Polling - Connection 1 Fd 21. This frees the FD.
Apr 30 15:46:08 mobius pexd[30963]: POLL_CALL[i 1 fd 21] - IO_TASK -
uv_poll_stop() - T_POLL_DISMANTLE_REQ
* Stop Polling - Connection 0 Fd 20. This frees the FD
Apr 30 15:46:08 mobius pexd[30963]: POLL_CALL[i 0 fd 20] - IO_TASK -
uv_poll_stop() - T_POLL_DISMANTLE_REQ
* New Connection - Connection 1 Fd 20. This is fine since
uv_poll_stop() was called for Fd 20 which
freed it and it is newly allcated with uv_accept() and obtained
with uv_fileno().
Apr 30 15:46:08 mobius pexd[30963]: POLL_CALL[i 1 fd 20] - IO_TASK -
uv_accept() + uv_fileno()
* However we crash because uv_poll_init() returned EBADF !
Apr 30 15:46:08 mobius pexd[30963]: POLL_CALL[i 1 fd 20] - IO_TASK -
uv_poll_init() - T_POLL_CONFIG_REQ
Apr 30 15:46:08 mobius pexd[30963]: IO_TASK: POLL_PROXY - Polling
Initialization Error -9, EBADF
C) The edited associated code segments are as follows.
********************************************************
1) Prelude to uv_poll_stop() in poll_proxy() in the IO_Task() thread.
(network_io.c)
------------------------------------------------------------------------------------
case T_POLL_DISMANTLE_REQ:
ppdata = (uv_handle_t **) &msg->buffer[0];
poll_handle = (uv_poll_t *) *ppdata;
syslog(LOG_INFO, "POLL_CALL[i %d fd %d] - IO_TASK - uv_poll_stop() -
T_POLL_DISMANTLE_REQ\n", cdesc->index, cdesc->fd);
if( (r = uv_poll_stop(poll_handle)) )
{
fatal_error(LOG_CRIT, "IO_TASK: POLL_PROXY - Poll
Stop Error %d, %s",
r, uv_err_name(r) );
}
//
// The callback routine notifies the Protocol_Task()
when everything is done.
//
poll_handle->data = (void *) cdesc;
uv_close((uv_handle_t *) poll_handle,
async_close_callback);
2) Connection acceptance in make_incoming_connection() in the main()
thread. (main.c)
---------------------------------------------------------------------------------------
conn_handle = (uv_tcp_t *) VALLOC(sizeof(uv_tcp_t));
uv_tcp_init(&Connect_Loop, conn_handle);
if((r = uv_accept(listen_handle, (uv_stream_t *) conn_handle)) == 0)
{
//
// A new connection occured.
//
uv_os_fd_t fd;
ENTER_MUTEX(&Protocol_D_Mutex);
nsock = N_Sockets++;
EXIT_MUTEX(&Protocol_D_Mutex);
//
// Fetch the socket descriptor from the connection handle.
//
uv_fileno((const uv_handle_t*) conn_handle, &fd);
//
// Allocate the connection descriptor.
//
cdesc = ALLOC_CONN_DESC(fd);
if( !cdesc )
{
syslog(LOG_DEBUG, "MAIN_TASK: CONNECTION REJECTION - No
Connection Descriptors, N = %d", nsock);
ENTER_MUTEX(&Protocol_D_Mutex);
N_Sockets--;
close(fd);
EXIT_MUTEX(&Protocol_D_Mutex);
uv_close((uv_handle_t *) conn_handle, forced_close_callback);
return;
}
syslog(LOG_INFO, "POLL_CALL[i %d fd %d] - IO_TASK - uv_accept() +
uv_fileno()\n", cdesc->index, cdesc->fd);
//
// Save the connection handle and start polling.
//
cdesc->conn_handle = (uv_tcp_t *) conn_handle;
syslog(LOG_INFO, "MAIN_TASK: NEW CONNECTION ESTABLISHED -
CONN %d FD %d", cdesc->index, cdesc->fd);
//
// Set up epoll() plumbing by sending a message to IO_Task();
//
bzero((void *) &poll_data, sizeof(ASYNC_DATA));
poll_data.type = T_POLL_CONFIG_REQ;
poll_data.async_handle = &IO_Task_Async_Handle;
poll_data.async_q = &IO_Task_Input_Q;
poll_data.object_handle = NULL;
//
// The T_POLL_CONFIG_RSP message will be sent to the
Protocol_Task() which
// is in S_IDLE state.
//
send_async_msg(cdesc, &poll_data);
}
3) Prelude to uv_poll_init() in poll_proxy() in the IO_Task() thread.
(network_io.c)
------------------------------------------------------------------------------------
case T_POLL_CONFIG_REQ:
//
// Main process request to start Libuv/epoll() operation.
//
poll_handle = (uv_poll_t *) VALLOC(sizeof(uv_poll_t));
syslog(LOG_INFO, "POLL_CALL[i %d fd %d] - IO_TASK - uv_poll_init() -
T_POLL_CONFIG_REQ\n", cdesc->index, cdesc->fd);
if( (r = uv_poll_init(&Poll_Loop, poll_handle,
cdesc->fd)) != 0)
{
fatal_error(LOG_CRIT, "IO_TASK: POLL_PROXY -
Polling Initialization Error %d, %s",
r, uv_err_name(r));
}
D) Stack backtrace.
(gdb) bt
#0 0x00007f62c47b0267 in __GI_raise (sig=sig@entry=6) at
../sysdeps/unix/sysv/linux/raise.c:55
#1 0x00007f62c47b1eca in __GI_abort () at abort.c:89
#2 0x000000000040d411 in fatal_error (log_prio=2,
fmt=0x424e28 "IO_TASK: POLL_PROXY - Polling Initialization Error
%d, %s") at misc.c:135
#3 0x0000000000405b6d in poll_proxy (handle=0x641f80
<IO_Task_Async_Handle>) at network_io.c:291
#4 0x00000000004114cb in uv__async_io (loop=0xc26800 <Poll_Loop>,
w=<optimized out>, events=<optimized out>)
at src/unix/async.c:163
#5 0x000000000041d255 in uv__io_poll (loop=loop@entry=0xc26800
<Poll_Loop>, timeout=<optimized out>)
at src/unix/linux-core.c:462
#6 0x0000000000411c48 in uv_run (loop=0xc26800 <Poll_Loop>,
mode=UV_RUN_DEFAULT) at src/unix/core.c:385
#7 0x0000000000405835 in IO_Task (arg=0x0) at network_io.c:100
#8 0x00007f62c4b4c6aa in start_thread (arg=0x7f62bbfff700) at
pthread_create.c:333
#9 0x00007f62c4881eed in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:109
At this point cdesc->fd is 20 and Poll_Loop.watchers[20] is NULL.
On 04/30/2021 11:48 AM, Paul Romero wrote:
Hi:
My guess is that there is a subtle, probably timing related, problem
in uv_poll_stop()
simply because I can't think of any other relevant Libuv routines
that are explicitly
called after uv_poll_start() succeeds. What do you think ? Of
course, there could
be a problem in the way connections are rejected. All that code is
in the make_incoming_connection()
callback routine in main.c
Best Regards,
Paul R.
On 04/29/2021 03:14 PM, Paul Romero wrote:
Hi:
I reattached the following files with some confusing debugging
stuff removed and
a dump using them follows.
* main.c
* network_io.c
* rx_fsm.c
* async.c
Again this is the relevant code segment.
case T_POLL_CONFIG_REQ:
//
// Main process request to start Libuv/epoll() operation.
//
poll_handle = (uv_poll_t *) VALLOC(sizeof(uv_poll_t));
if( (r = uv_poll_init(&Poll_Loop, poll_handle, cdesc->fd))
!= 0)
{
fatal_error(LOG_CRIT, "IO_TASK: POLL_PROXY - Polling
Initialization Error %d, %s",
r, uv_err_name(r));
}
This is the crash diagnostic.
IO_TASK: POLL_PROXY - Polling Initialization Error -17, EEXIST
Aborted (core dumped)
And the is the gdb backtrace and is typical of the problem.
Using host libthread_db library
"/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `./pexd'.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007ff1da90b267 in __GI_raise (sig=sig@entry=6) at
../sysdeps/unix/sysv/linux/raise.c:55
55 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 0x00007ff1da90b267 in __GI_raise (sig=sig@entry=6) at
../sysdeps/unix/sysv/linux/raise.c:55
#1 0x00007ff1da90ceca in __GI_abort () at abort.c:89
#2 0x000000000040d379 in fatal_error (log_prio=2,
fmt=0x424ce0 "IO_TASK: POLL_PROXY - Polling Initialization
Error %d, %s") at misc.c:135
#3 0x0000000000405b21 in poll_proxy (handle=0x641f80
<IO_Task_Async_Handle>) at network_io.c:287
#4 0x000000000041142b in uv__async_io (loop=0xc26800 <Poll_Loop>,
w=<optimized out>, events=<optimized out>)
at src/unix/async.c:163
#5 0x000000000041d1b5 in uv__io_poll (loop=loop@entry=0xc26800
<Poll_Loop>, timeout=<optimized out>)
at src/unix/linux-core.c:462
#6 0x0000000000411ba8 in uv_run (loop=0xc26800 <Poll_Loop>,
mode=UV_RUN_DEFAULT) at src/unix/core.c:385
#7 0x000000000040580f in IO_Task (arg=0x0) at network_io.c:100
#8 0x00007ff1daca76aa in start_thread (arg=0x7ff1d5a7c700) at
pthread_create.c:333
#9 0x00007ff1da9dceed in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:109
At this point cdesc->fd is 22 and Poll_Loop.watchers[22] =
0x17ef458, a valid address ?
On 04/29/2021 09:09 AM, Paul Romero wrote:
Hi:
The most common symptom of the problem is that uv_poll_init()
fails which means the problem must
be related to the uv_poll_t Poll_Loop. The relevant code segment
is as follows.
poll_handle = (uv_poll_t *) VALLOC(sizeof(uv_poll_t));
if( (r = uv_poll_init(&Poll_Loop, poll_handle, cdesc->fd)) != 0)
{
fatal_error(LOG_CRIT, "IO_TASK: POLL_PROXY - Polling
Initialization Error %d, %s",
r, uv_err_name(r));
}
The following files illustrate the problem and are attached to
this message. Please advise me
how to attach files to the list directly.
* trace_badf.txt: A stack trace when the error code is EBADF.
* trace_eexist.txt: A stack trace when the error code is EEXIST.
* network_io.c: The IO_Task() thread code. The problem occurs in
the poll_proxy() routine.
* main.c: The main() process/thread code where most
initialization occurs.
* transmit.c: The Transmit_Task() thread.
* rx_fsm.c: The heart of the protocol task code.
You are right that only the IO_Task() performs polling related
operations.
However, please note that the Transmit_Task() thread uses the
underlying TCP socket descriptor
to send data to the network with Linux send(). (See the TX_DATA()
routine.) Also,
USE_SSL and USE_SCRAM are not defined.
I will send more information if am able to produce the problem at
another point.
Also, I have seen the issue you mentioned before and suspect it
may be relevant.
Please let me know if you need anything else.
Best Regards,
Paul R.
Best Regards,
Paul R.
On 04/28/2021 08:52 PM, Jameson Nash wrote:
I'm assuming from your description that you've ensured all libuv
calls happen from exactly one thread (except uv_async_send). It
sounds like you're describing the issue that
https://github.com/libuv/libuv/commit/c9406ba0e3d67907c1973a71968b89a6bd83c63c
was intended to fix, which was included in v1.41.0
Note that the Poll_Loop.watchers[N] is not always required to be
NULL, so perhaps you've found a case where it is still
incorrectly expecting that? You might want to file an issue with
code to reproduce the problem, or at least an `rr` trace dump of
the code that hits problem (note that `rr` could potentially
upload all of your hard drive, so be careful what you are
submitting).
On Wed, Apr 28, 2021 at 11:13 PM pa...@rcom-software.com
<mailto:pa...@rcom-software.com> <pa...@rcom-software.com
<mailto:pa...@rcom-software.com>> wrote:
Hi Folks:
I am experiencing an intermittent problem with uv_poll_init()
after the successful establishment and release
of multiple concurrent TCP connections. I am not sure if this
problem is due to a bug, which may
be corrected in another Libuv release, or if I am doing
something wrong when releasing the poll handle.
Do you have insight about the cause ? The details I consider
most important follow.
The uv_poll_t callback function reads incoming TCP data as
follows.
iff(events & UV_READABLE)
{
CONN_DESC *cdesc = (CONN_DESC *) poll_handle->data;
n = recv(cdesc->fd, cdesc->rx_buf, RX_BUF_SIZE,
MSG_DONTWAIT);
NOTE: I am using Libuv version 1.41.0 running on Ubuntu Linux
version 15.04.
The problem is that uv_poll_init() fails, normally with the
EEXIST or EBADF error code, and
my investigation indicates the uv_loop_t
Poll_Loop.watchers[N] field is not NULL when it should be,
where N is TCP socket descriptor. It occurs immediately after
the uv_poll_t poll_handle is allocated.
(There is exactly one TCP socket descriptor per poll handle.)
The call to uv_poll_init() is as follows
and the socket descriptor is obtained with uv_fileno().
if( (r = uv_poll_init(&Poll_Loop, poll_handle,
cdesc->fd)) != 0)
{
fatal_error(LOG_CRIT, "IO_TASK: POLL_PROXY - Polling
Initialization Error %d, %s",
r, uv_err_name(r));
}
It occurs in the IO_Task() thread when there multiple TCP
socket descriptors are in use. The IO_task
releases the poll_handle with the following code sequence
when it is notified that polling should stop
via a Libuv async. message from the Protocol_Task() thread.
if( (r = uv_poll_stop(poll_handle)) )
{
fatal_error(LOG_CRIT, "IO_TASK: POLL_PROXY - Poll
Stop Error %d, %s",
r, uv_err_name(r) );
}
poll_handle->data = (void *) cdesc;
uv_close((uv_handle_t *) poll_handle, async_close_callback);
The actual release occurs in async_close_callback() as
follows and the Protocol_Task() releases the
TCP socket decriptor with a normal Linux close() after it
receives the T_DISMANTLE response message.
VFREE((UCHAR *) handle);
//
// Send a notification message to the Protocol_Task.
//
msg = MSG_ALLOC(0, FALSE);
msg->class = C_NOTIFY;
msg->type = T_DISMANTLE_RSP;
msg->info = 0;
SendProtoMsg(cdesc, msg);
I think the underlying cause is that if there is new TCP
connection that uses a the same TCP socket descriptor
as one released with uv_poll_stop() and uv_close(), the call
to uv_poll_init() occurs before the socket closure
has propogated into the uv_loop_t Poll_Handle.
Best Regards,
Paul Romero
--
You received this message because you are subscribed to the
Google Groups "libuv" group.
To unsubscribe from this group and stop receiving emails from
it, send an email to libuv+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/libuv/c3290a76-ab6b-42ad-8540-33021c6188b9n%40googlegroups.com.
--
You received this message because you are subscribed to a topic
in the Google Groups "libuv" group.
To unsubscribe from this topic, visit
https://groups.google.com/d/topic/libuv/_4ClQoaVPCg/unsubscribe.
To unsubscribe from this group and all its topics, send an email
to libuv+unsubscr...@googlegroups.com
<mailto:libuv+unsubscr...@googlegroups.com>.
To view this discussion on the web visit
https://groups.google.com/d/msgid/libuv/CADnnjUXSsF7QwRnVqFojAm1W_o35CHKyMCPM%2BVw0FM0FjqN1XQ%40mail.gmail.com.
--
Paul Romero
-----------
RCOM Communications Software
EMAIL:pa...@rcom-software.com
PHONE: (510)482-2769
--
Paul Romero
-----------
RCOM Communications Software
EMAIL:pa...@rcom-software.com
PHONE: (510)482-2769
--
Paul Romero
-----------
RCOM Communications Software
EMAIL:pa...@rcom-software.com
PHONE: (510)482-2769
--
You received this message because you are subscribed to a topic in
the Google Groups "libuv" group.
To unsubscribe from this topic, visit
https://groups.google.com/d/topic/libuv/_4ClQoaVPCg/unsubscribe.
To unsubscribe from this group and all its topics, send an email to
libuv+unsubscr...@googlegroups.com
<mailto:libuv+unsubscr...@googlegroups.com>.
To view this discussion on the web visit
https://groups.google.com/d/msgid/libuv/608C50E8.7070202%40rcom-software.com.
--
Paul Romero
-----------
RCOM Communications Software
EMAIL:pa...@rcom-software.com
PHONE: (510)482-2769
--
Paul Romero
-----------
RCOM Communications Software
EMAIL:pa...@rcom-software.com
PHONE: (510)482-2769
--
Paul Romero
-----------
RCOM Communications Software
EMAIL: pa...@rcom-software.com
PHONE: (510)482-2769
--
You received this message because you are subscribed to the Google Groups
"libuv" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to libuv+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/libuv/608E45B4.4050606%40rcom-software.com.
COMMENT:CONNECTION 11, TCP FD 31. In uv_close() callback.
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE 0x15984f0 -
CLOSE POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: NULL
COMMENT: Protocol_Task() receive T_DISMANTLE_RSP from IO_Task() and sends a
T_CONN_DISMANTLE_REQ
to the main() task, (All action on connection 11.)
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62345 - CONN[11] State
15 Class 2 Type 36
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[11] Release State
1 Class 2 Type 36
May 1 16:03:39 mobius pexd[15007]: MAIN_TASK(Proxy): CONN[11] Type 35
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62346 - CONN[11] State
15 Class 2 Type 36
May 1 16:03:39 mobius pexd[15007]: IO_TASK(Proxy): RX EVENT - CONN[10] Type 32
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 10 FD 30 HANDLE (nil) - PRE-INIT
POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: NULL
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 10 FD 30 HANDLE (nil) -
POST-INIT POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[11] Release State
2 Class 2 Type 36
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: CONN[11] - CONNECTION RELEASE
COMPLETE
May 1 16:03:39 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 8d
Q-Head: Prev 0xc27810 Next 0x159a810 Loop FD 0 POLL CB (nil)
May 1 16:03:39 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 30 events 0
pevents 0
May 1 16:03:39 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x1598660 Next 0x1598660 Watcher Q-Head: Prev 0x1598670 Next 0x1598670
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 10 FD 30 HANDLE (nil) - START
POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 25 *FD: USER 0x1598658 BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] 0x1598658, @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[11] State 15 Class
4 Type 56
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[11] - NETWORK SERVICE DOWN
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62347 - CONN[11] State
15 Class 2 Type 30
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[11] Release State
2 Class 2 Type 30
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 12d
Q-Head: Prev 0xc27810 Next 0x159a810 Loop FD 0 POLL CB 0x4058be
May 1 16:03:39 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 30 events 0
pevents 1
May 1 16:03:39 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x1598660 Next 0x1598660 Watcher Q-Head: Prev 0xc27858 Next 0xc27858
COMMENT: Some non-Libuv events.
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62348 - CONN[10] State
0 Class 2 Type 33
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62349 - CONN[1] State
13 Class 0 Type 8
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX SEG - State 2 Type 8 Segment
4
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: CONN[1] - DATASET COMPLETE
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[1] - Xfer Started, Final
Segment = 0
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62350 - CONN[6] State
13 Class 0 Type 8
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX SEG - State 1 Type 8 Segment
2
May 1 16:03:39 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[1] State 13 Class
4 Type 54
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[1] - Xfer Finished
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[1] - Xfer Succeeded
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62351 - CONN[1] State
13 Class 2 Type 30
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: TX EVENT 62352 - CONN[1] State
12 Class 0 Type 9
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62353 - CONN[1] State
12 Class 0 Type 2
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: CONN[1] - SESSION COMPLETE
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: TX EVENT 62354 - CONN[1] State
1 Class 0 Type 9
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62355 - CONN[5] State
13 Class 0 Type 8
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX SEG - State 2 Type 8 Segment
2
****************************** CYCLE 1 ***************************************
COMMENT: TCP Connection on connection 11. This begins a successful session on
connection 11 using TCP FD 31. However, the use of FD 31 is matter of
chance
rather than a direct factor in subsequent use of that FD.
May 1 16:03:39 mobius pexd[15007]: MAIN_TASK: NEW CONNECTION ESTABLISHED -
CONN 11 FD 31
COMMENT: CYCLE 1, CONNECTION 11, TCP FD 31. After uv_accept().
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE (nil) - ACCEPT:
Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 25 *FD: USER (nil) BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] 0x1598658, @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: NULL
COMMENT: IO_Task() receives a T_POLL_CONFIG_REQ message from the main() task.
May 1 16:03:39 mobius pexd[15007]: IO_TASK(Proxy): RX EVENT - CONN[11] Type 32
COMMENT: CYCLE 1, CONNECTION 11, TCP FD 31. Before uv_poll_init().
I believe the data structures have correct values at this point.
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE (nil) - PRE-INIT
POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 25 *FD: USER (nil) BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] 0x1598658, @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: NULL
COMMENT: CYCLE 1, CONNECTION 11, TCP FD 31. After uv_poll_init().
I believe the data structures have the right values as this point.
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE (nil) -
POST-INIT POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 25 *FD: USER (nil) BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] 0x1598658, @FD[31] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 8d
Q-Head: Prev 0xc27810 Next 0x1598610 Loop FD 0 POLL CB (nil)
May 1 16:03:39 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 31 events 0
pevents 0
May 1 16:03:39 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x159ab60 Next 0x159ab60 Watcher Q-Head: Prev 0x159ab70 Next 0x159ab70
COMMENT: CYCLE 1, CONNECTION 11, TCP FD 31. After uv_poll_start().
May 1 16:03:39 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE (nil) - START
POLLING: Backend FD 16
May 1 16:03:39 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 26 *FD: USER 0x159ab58 BACKEND (nil)
May 1 16:03:39 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:39 mobius pexd[15007]: @FD[20] 0x159b258, @FD[21] 0x159aa58,
@FD[22] 0x1599e58, @FD[23] 0x159a758,
May 1 16:03:39 mobius pexd[15007]: @FD[24] 0x159a458, @FD[25] 0x159a558,
@FD[26] 0x159a158, @FD[27] 0x1599958,
May 1 16:03:39 mobius pexd[15007]: @FD[28] 0x159a858, @FD[29] 0x1599058,
@FD[30] 0x1598658, @FD[31] 0x159ab58,
May 1 16:03:39 mobius pexd[15007]: @FD[32] 0x159a658, @FD[33] 0x1599a58,
@FD[34] 0x1598f58, @FD[35] 0x1599b58,
May 1 16:03:39 mobius pexd[15007]: @FD[36] 0x159a058, @FD[37] 0x1598858,
@FD[38] 0x1598c58, @FD[39] 0x1598a58,
May 1 16:03:39 mobius pexd[15007]: @FD[40] 0x1599258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x159b158,
May 1 16:03:39 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:39 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:39 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 12d
Q-Head: Prev 0xc27810 Next 0x1598610 Loop FD 0 POLL CB 0x4058be
May 1 16:03:39 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 31 events 0
pevents 1
May 1 16:03:39 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x159ab60 Next 0x159ab60 Watcher Q-Head: Prev 0xc27858 Next 0xc27858
COMMENT: Some non-Libuv events.
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62356 - CONN[11] State
0 Class 2 Type 33
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62357 - CONN[2] State
13 Class 0 Type 8
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX SEG - State 2 Type 8 Segment
4
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: CONN[2] - DATASET COMPLETE
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[2] - Xfer Started, Final
Segment = 0
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62358 - CONN[7] State
13 Class 0 Type 8
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX SEG - State 1 Type 8 Segment
2
May 1 16:03:39 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[2] State 13 Class
4 Type 54
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[2] - Xfer Finished
May 1 16:03:39 mobius pexd[15007]: DB_TASK: CONN[2] - Xfer Succeeded
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62359 - CONN[2] State
13 Class 2 Type 30
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: TX EVENT 62360 - CONN[2] State
12 Class 0 Type 9
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: RX EVENT 62361 - CONN[2] State
12 Class 0 Type 2
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: CONN[2] - SESSION COMPLETE
May 1 16:03:39 mobius pexd[15007]: PROTO_TASK: TX EVENT 62362 - CONN[2] State
1 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 6 FD 26 HANDLE (nil) - PRE-INIT
POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 23 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] (nil), @FD[27] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[28] (nil), @FD[29] 0x1599558, @FD[30]
0x1598658, @FD[31] 0x159ab58,
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: DB_TASK: CONN[5] - Session Started
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62911 - CONN[5] State
4 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62912 - CONN[5] State
6 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: NULL
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 6 FD 26 HANDLE (nil) - POST-INIT
POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 23 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] (nil), @FD[27] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[28] (nil), @FD[29] 0x1599558, @FD[30]
0x1598658, @FD[31] 0x159ab58,
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 8d
Q-Head: Prev 0xc27810 Next 0x159a510 Loop FD 0 POLL CB (nil)
May 1 16:03:50 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 26 events 0
pevents 0
May 1 16:03:50 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x159a860 Next 0x159a860 Watcher Q-Head: Prev 0x159a870 Next 0x159a870
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 6 FD 26 HANDLE (nil) - START
POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER 0x159a858 BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[28] (nil), @FD[29] 0x1599558, @FD[30]
0x1598658, @FD[31] 0x159ab58,
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 12d
Q-Head: Prev 0xc27810 Next 0x159a510 Loop FD 0 POLL CB 0x4058be
May 1 16:03:50 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 26 events 0
pevents 1
May 1 16:03:50 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x159a860 Next 0x159a860 Watcher Q-Head: Prev 0xc27858 Next 0xc27858
COMMENT: Some non-Libuv events.
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62913 - CONN[6] State
0 Class 2 Type 33
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62914 - CONN[5] State
6 Class 0 Type 5
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[5] State 6 Class 0
Type 5
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62915 - CONN[5] State
6 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62916 - CONN[5] State
8 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62917 - CONN[5] State
8 Class 0 Type 6
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[5] State 8 Class 0
Type 6
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62918 - CONN[5] State
8 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62919 - CONN[5] State
10 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62920 - CONN[5] State
10 Class 0 Type 7
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[5] State 10 Class
0 Type 7
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62921 - CONN[5] State
10 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62922 - CONN[5] State
12 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62923 - CONN[5] State
12 Class 0 Type 8
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX SEG - State 0 Type 8 Segment
1
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62924 - CONN[2] State
13 Class 0 Type 8
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX SEG - State 1 Type 8 Segment
2
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62925 - CONN[3] State
13 Class 0 Type 8
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX SEG - State 2 Type 8 Segment
2
May 1 16:03:50 mobius pexd[15007]: MAIN_TASK: NEW CONNECTION ESTABLISHED -
CONN 7 FD 27
COMMENT: Some non-Libuv events mostly on connection 8.
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62973 - CONN[8] State
1 Class 0 Type 1
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: CONN[8] - Release State 0
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62974 - CONN[8] State
4 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62975 - CONN[8] State
4 Class 0 Type 4
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[8] State 4 Class 0
Type 4
May 1 16:03:50 mobius pexd[15007]: DB_TASK: CONN[8] - Session Started
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62976 - CONN[8] State
4 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62977 - CONN[8] State
6 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62978 - CONN[8] State
6 Class 0 Type 5
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[8] State 6 Class 0
Type 5
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62979 - CONN[8] State
6 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62980 - CONN[8] State
8 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62981 - CONN[8] State
8 Class 0 Type 6
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[8] State 8 Class 0
Type 6
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62982 - CONN[8] State
8 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62983 - CONN[8] State
10 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62984 - CONN[8] State
10 Class 0 Type 7
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[8] State 10 Class
0 Type 7
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62985 - CONN[8] State
10 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: TX EVENT 62986 - CONN[8] State
12 Class 0 Type 9
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62987 - CONN[8] State
12 Class 0 Type 8
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX SEG - State 0 Type 8 Segment
1
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62988 - CONN[11] State
1 Class 1 Type 21
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: CONN[11] - Release State 0
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62989 - CONN[10] State
1 Class 1 Type 21
COMMENT: The IO_Task() receives a T_POLL_DISMATLE_REQ from the Protocol_Task().
May 1 16:03:50 mobius pexd[15007]: IO_TASK(Proxy): RX EVENT - CONN[11] Type 34
COMMENT: CYCLE 1, CONNECTION 11, TCP FD 31. After uv_poll_stop(). According to
the
documentation this should free FD 31 to the user.
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE 0x159aaf0 - STOP
POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 25 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] 0x159b058,
May 1 16:03:50 mobius pexd[15007]: @FD[28] 0x159a158, @FD[29] 0x1599558,
@FD[30] 0x1598658, @FD[31] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 8d
Q-Head: Prev 0x1598f10 Next 0x1598610 Loop FD 0 POLL CB 0x4058be
May 1 16:03:50 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 31 events 0
pevents 0
May 1 16:03:50 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x159ab60 Next 0x159ab60 Watcher Q-Head: Prev 0x159ab70 Next 0x159ab70
COMMENT: CYCLE 1, CONNECTION 11, TCP FD 31. In the uv_close() callback. This
should release
FD 31 to the user.
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 11 FD 31 HANDLE 0x159aaf0 -
CLOSE POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 25 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: CONN[10] - Release State 0
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] 0x159b058,
May 1 16:03:50 mobius pexd[15007]: @FD[28] 0x159a158, @FD[29] 0x1599558,
@FD[30] 0x1598658, @FD[31] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: NULL
COMMENT: The Protocol_Task() receieves a T_DISMAMTLE_RSP from the IO_Task() and
sends a
T_CONN_DISMALTE_REQ to the main() task. The main() task responds with
another
T_DISMATLE_RSP. Upon reception of that message the Protocol_Task()
release
the FD with the Linux close(). (All action on connection 11.)
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62990 - CONN[11] State
15 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[11] Release State
1 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: MAIN_TASK(Proxy): CONN[11] Type 35
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62991 - CONN[11] State
15 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[11] Release State
2 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: CONN[11] - CONNECTION RELEASE
COMPLETE
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[11] State 15 Class
4 Type 56
May 1 16:03:50 mobius pexd[15007]: DB_TASK: CONN[11] - NETWORK SERVICE DOWN
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62992 - CONN[11] State
15 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[11] Release State
2 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: IO_TASK(Proxy): RX EVENT - CONN[10] Type 34
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 10 FD 30 HANDLE 0x15985f0 - STOP
POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] 0x159b058,
May 1 16:03:50 mobius pexd[15007]: @FD[28] 0x159a158, @FD[29] 0x1599558,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: LOOP PTR 0xc27800 type 8 flags 8d
Q-Head: Prev 0x1598f10 Next 0x642fa0 Loop FD 0 POLL CB 0x4058be
May 1 16:03:50 mobius pexd[15007]: IO FIELDS: cb 0x415050 fd 30 events 0
pevents 0
May 1 16:03:50 mobius pexd[15007]: IO WATCHER Queues: Pending Q-Head: Prev
0x1598660 Next 0x1598660 Watcher Q-Head: Prev 0x1598670 Next 0x1598670
COMMENT: This is the last polling operation before the cycle in which the crash
occurs.
It may be significant because it is where I believe TCP FD 30 should
be released.
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 10 FD 30 HANDLE 0x15985f0 -
CLOSE POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] 0x159b058,
May 1 16:03:50 mobius pexd[15007]: @FD[28] 0x159a158, @FD[29] 0x1599558,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: NULL
COMMENT: This is the final sequence of non-Libuv events before the Crash.
The Protocol_Task() receives the T_DISMANTLE_RSP message from the
IO_Task()
and a T_CONN_DISMANTL_REQ to the main() task.
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62993 - CONN[10] State
15 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[10] Release State
1 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: MAIN_TASK(Proxy): CONN[10] Type 35
COMMENT: The Protocol_Task() receives a T_DISMANTLE_RSP from the main() task,
cleans up everthing and uses Linux close() for the final file
descriptor
release.
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62994 - CONN[10] State
15 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[10] Release State
2 Class 2 Type 36
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: CONN[10] - CONNECTION RELEASE
COMPLETE
May 1 16:03:50 mobius pexd[15007]: DB_TASK: RX EVENT - CONN[10] State 15 Class
4 Type 56
May 1 16:03:50 mobius pexd[15007]: DB_TASK: CONN[10] - NETWORK SERVICE DOWN
*********************************** CYCLE N
*******************************************
COMMENT: This is the cycle in which the Crash occurs. TCP connection on
connection 11.
May 1 16:03:50 mobius pexd[15007]: MAIN_TASK: NEW CONNECTION ESTABLISHED -
CONN 11 FD 30
COMMENT: CYCLE N, CONNECTION 11, TCP FD 30. After uv_accept(). Do the uv_loop_t
Poll_Loop,
and uv_poll_t data structure look right at this point ?
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 11 FD 30 HANDLE (nil) - ACCEPT:
Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] 0x159b058,
May 1 16:03:50 mobius pexd[15007]: @FD[28] 0x159a158, @FD[29] 0x1599558,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: NULL
COMMENT: The last message in this sequence is T_POLL_CONFIG_REQ sent to the
IO_Task() by the main() task
to request polling initiation.
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT 62995 - CONN[10] State
15 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: PROTO_TASK: RX EVENT CONN[10] Release State
2 Class 2 Type 30
May 1 16:03:50 mobius pexd[15007]: IO_TASK(Proxy): RX EVENT - CONN[11] Type 32
COMMENT: CYCLE N, CONNECTION 11, TCP FD 30. Just before uv_poll_init().
There is definitely something wrong with the data structures at this
point
and uv_poll_init() will return EEXIST.
May 1 16:03:50 mobius pexd[15007]: MPOLL: IDX 11 FD 30 HANDLE (nil) - PRE-INIT
POLLING: Backend FD 16
May 1 16:03:50 mobius pexd[15007]: LOOP 0xc27800: Watch 0x7f7218000910 NWatch
62 Nfds 24 *FD: USER (nil) BACKEND (nil)
May 1 16:03:50 mobius pexd[15007]: @FD[0] (nil), @FD[1] (nil), @FD[2] (nil),
@FD[3] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[4] (nil), @FD[5] (nil), @FD[6] (nil),
@FD[7] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[8] (nil), @FD[9] (nil), @FD[10] (nil),
@FD[11] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[12] (nil), @FD[13] (nil), @FD[14]
(nil), @FD[15] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[16] (nil), @FD[17] 0xc27a30, @FD[18]
(nil), @FD[19] 0xc279c8,
May 1 16:03:50 mobius pexd[15007]: @FD[20] 0x159a958, @FD[21] 0x1598358,
@FD[22] 0x1599e58, @FD[23] 0x159b258,
May 1 16:03:50 mobius pexd[15007]: @FD[24] 0x159aa58, @FD[25] 0x159a558,
@FD[26] 0x159a858, @FD[27] 0x159b058,
May 1 16:03:50 mobius pexd[15007]: @FD[28] 0x159a158, @FD[29] 0x1599558,
@FD[30] (nil), @FD[31] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[32] 0x1599a58, @FD[33] 0x1599058,
@FD[34] 0x1598f58, @FD[35] 0x1599858,
May 1 16:03:50 mobius pexd[15007]: @FD[36] 0x1599b58, @FD[37] 0x1598958,
@FD[38] 0x1598c58, @FD[39] 0x1598858,
May 1 16:03:50 mobius pexd[15007]: @FD[40] 0x1598258, @FD[41] 0x1599358,
@FD[42] 0x1599158, @FD[43] 0x1599258,
May 1 16:03:50 mobius pexd[15007]: @FD[44] (nil), @FD[45] (nil), @FD[46]
(nil), @FD[47] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[48] (nil), @FD[49] (nil), @FD[50]
(nil), @FD[51] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[52] (nil), @FD[53] (nil), @FD[54]
(nil), @FD[55] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[56] (nil), @FD[57] (nil), @FD[58]
(nil), @FD[59] (nil),
May 1 16:03:50 mobius pexd[15007]: @FD[60] (nil), @FD[61] (nil),
May 1 16:03:50 mobius pexd[15007]: HANDLE: NULL
May 1 16:03:50 mobius pexd[15007]: IO_TASK: POLL_PROXY - Polling
Initialization Error -9, EBADF
