Forum OpenACS Development: Re: NaviServer on Windows: [ns_info threads] returning unbalanced braces

Dear all,
the problem observed by Frank and proved by Brian and myself, is caused by a bad memory allocation handling in the file "sockfile.c", function "SendFd".
Here you can see the problem and the fix:
http://www.spazioit.com/images/naviserver/mem_alloc_error.jpg
When a file has line too long (longer than 16384 bytes) we have a buffer overflow. The limit is now 64 MB and should be more than adequate also for larke JS application compressed and obfuscated in one single line.
Linux systems that have a working "sendfile" function may not have had the need to call the "SendFd" function and this is a possible explanation why the issue did not show up in these systems.
I blieve I need to say:
1. it wasn't a compilation error/problem
2. instead of always complaining about Windows, most of the times Windows is nothing else than a different platforms exposing other problems, other issues present in our work.
A new version of the installer is on its way.
This time the build system is Visual Studio 2017

Kind regards,
Maurizio

Hi Maurizio,

Great to see you found the issue. I'm looking forward to include your quick fix in the ]po[ Windows installer ASAP.

However, you can't leave such a security hole in NaviServer permanently! I'm not a NaviServer expert (I never looked into the code...), but I know there are many ways in C to deliver file contents safely and with a smaller buffer...

Frank

Dear Frank,
as you properly noted it is a quick fix. I spent too much time compiling...
I hope that now the people knowing Naviserver much better than I do will convert my quick and dirty fix into something properly done.
Maurizio
The situation is quite strange. in my compiled binary, there is no buffer overflow, so the diagnosis is not correct at least for "my" compile. I've added a few more debugging help statements for maurizio to get more clearness ( NaviServer commit).

with these debugging statements activated i see on large downloads the following output

[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: SendFd offset 0 length 1528060
[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: ... pread toread 16384 offset 0 => read 16384
[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: ... pread toread 16384 offset 16384 => read 16384
[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: ... pread toread 16384 offset 32768 => read 16384
[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: ... pread toread 16384 offset 49152 => read 16384
...
[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: ... pread toread 16384 offset 1507328 => read 16384
[10/Mar/2017:11:56:55][336.73c][-conn:default:4-] Notice: ... pread toread 4348 offset 1523712 => read 4348 
so, maybe there is a difference between compiles with Visual Studio 11 and newer versions. But that was the last i can do on the windows front for the next 10-14 days.
Hi!

Just FYI, Maurizio just 5 min ago provided me with a workaround/fix for the nsd.exe "hang" issue. He'll later explain what he did.

Cheers,
Frank

There is no need for a rush from my side. i prefer a deeper analysis of the cause over a quick hack to fix the symptoms.
Dear Gustaf,
this is not a quick hack to fix the symptoms.
This is a properly working version of the SendFd function:

#define MAX_BUF_SIZE 16384
static ssize_t
SendFd(Ns_Sock *sock, int fd, off_t offset, size_t length,
const Ns_Time *timeoutPtr, unsigned int flags,
Ns_DriverSendProc *sendProc)
{
static char buf[MAX_BUF_SIZE+1];
struct iovec iov;
ssize_t nwrote = 0, toRead = (ssize_t)length, result;
bool decork;

decork = Ns_SockCork(sock, NS_TRUE);
while (toRead > 0) {
ssize_t sent, nread;

nread = pread(fd, buf, MIN((size_t)toRead, MAX_BUF_SIZE), offset);
if (nread <= 0) {
break;
}
toRead -= nread;
offset += (off_t)nread;

buf[nread] = '\0';

(void) Ns_SetVec(&iov, 0, buf, (size_t)nread);
sent = (*sendProc)(sock, &iov, 1, timeoutPtr, flags);
if (sent > 0) {
nwrote += sent;
}

if (sent != nread) {
break;
}
}

if (decork) {
(void) Ns_SockCork(sock, NS_FALSE);
}

if (nwrote > 0) {
result = nwrote;
} else {
result = -1;
}

return result;
}

The "hacks" I made are in bold.
1: I made the buffer static.
2: I added a +1 in the buffer size
3: I used MAX_BUF_SIZE, that is size(buf) -1 in the MIN function
4. As safety I put a buf[nread] = '\0'; statement.

Up to you.... to decide what we are talking about... if hacks in the solution or bugs in the original version of the function.

I do use hacks to verify if a portion of code is responsible or not for a problem, but then, if and when I have time, I try to convert these hacks into proper bug fixes.

You are very welcome to analyze, discover, why the original version of the function causes memory allocation problems (in the stack...) if the content is bigger than 16384 and understand what my hacks do.

For sure we are not facing a compilation issue/problem.

Thank you,
Maurizio

some comments about the newly suggested changes, which are different to the previous suggestions:
* by making the buffer static, the code becomes subject to random results in concurrent operations
* pread() reads binary data. there is no need for \0 termination

questions:
* why should making the buffer static help against a buffer overflow (as you stated above)?
* what is the result of the debugging lines (that i have added to bitbucket) in your installation?
* do you get the same problems with the config-file, that i have sent to you?
* if the config file and the test case is the same, what is your explanation that the original code works flawlessly with visual studio 11 (my installation) but not with visual studio 2017 (your installation)?

A possible explanation would be that the thread stack size is different (maybe different due to a different config file), but for that i require answers to the questions i have asked before.

If the code patterns above are really a problem, there are many places in the code that have to be altered.

btw, the OpenACS forum is not the right place for this discussion.

Dear Gustaf,
thank you for your questions.
The new version of the function I'm using is here below:
#define MAX_BUF_SIZE 16384
#define ACC_DELAY 5
static ssize_t
SendFd(Ns_Sock *sock, int fd, off_t offset, size_t length,
const Ns_Time *timeoutPtr, unsigned int flags,
Ns_DriverSendProc *sendProc)
{
char buf[MAX_BUF_SIZE + 1];
struct iovec iov;
ssize_t nwrote = 0, toRead = (ssize_t)length, result;
bool decork;

decork = Ns_SockCork(sock, NS_TRUE);
while (toRead > 0) {
ssize_t sent, nread;

nread = pread(fd, buf, MIN((size_t)toRead, MAX_BUF_SIZE), offset);
if (nread <= 0) {
break;
}
toRead -= nread;
offset += (off_t)nread;

buf[nread] = '\0';

(void) Ns_SetVec(&iov, 0, buf, (size_t)nread);
sent = (*sendProc)(sock, &iov, 1, timeoutPtr, flags);
Sleep(ACC_DELAY);
if (sent > 0) {
nwrote += sent;
}

if (sent != nread) {
break;
}
}

if (decork) {
(void) Ns_SockCork(sock, NS_FALSE);
}

if (nwrote > 0) {
result = nwrote;
} else {
result = -1;
}

return result;
}

Now the answers to your questions:
questions:
* why should making the buffer static help against a buffer overflow (as you stated above)?
because, if I do not use the buffer static, the code as it is stops working. I believe it is a timing issue. The send operation still takes place when the function is finished.
If I want to remove the static, I need to introduce a delay after the call to (*sendProc). I know this is a ugly fix, perhaps you can investigate this issue. But with this delay the code works and it is thread safe.

* what is the result of the debugging lines (that i have added to bitbucket) in your installation?
I did not check them.
* do you get the same problems with the config-file, that i have sent to you?
I did not try the binaries. I will try with the config-file and let you know.

Hello Gustaf,
I did try the original version of the code + your debugging hooks and I did try it with the nsd-config file you sent me.
And I observed the very same behaviour we saw at the beginning. When the content is larger than 16384 naviserver goes into a sort endless loop and it consumes lots of system resources.
The problem disappears if I make the (in)famous buffer static or if I put a delay after the send, like I did in here:

#define MAX_BUF_SIZE 16384
#ifdef _WIN32
#define AC_DELAY 5
#endif
static ssize_t
SendFd(Ns_Sock *sock, int fd, off_t offset, size_t length,
const Ns_Time *timeoutPtr, unsigned int flags,
Ns_DriverSendProc *sendProc)
{
char buf[MAX_BUF_SIZE+1];
struct iovec iov;
ssize_t nwrote = 0, toRead = (ssize_t)length, result;
bool decork;

// Ns_Log(Notice, "SendFd offset %ld length %lu", offset, length);

decork = Ns_SockCork(sock, NS_TRUE);
while (toRead > 0) {
ssize_t sent, nread;

nread = pread(fd, buf, MIN((size_t)toRead, MAX_BUF_SIZE), offset);

// Ns_Log(Notice, "... pread toread %lu offset %ld => read %ld", MIN((size_t)toRead, sizeof(buf)), offset, nread);
if (nread <= 0) {
break;
}
toRead -= nread;
offset += (off_t)nread;

(void) Ns_SetVec(&iov, 0, buf, (size_t)nread);
sent = (*sendProc)(sock, &iov, 1, timeoutPtr, flags);
#ifdef _WIN32
Sleep(AC_DELAY);
#endif
if (sent > 0) {
nwrote += sent;
}

if (sent != nread) {
break;
}
}

if (decork) {
(void) Ns_SockCork(sock, NS_FALSE);
}

if (nwrote > 0) {
result = nwrote;
} else {
result = -1;
}

return result;
}

I have the feeling that without that delay, some of the read/write on the buff is still occurring even when the function has finished, but then the actual content of that memory area at that moment is not what we had in the (in)famous buffer. By making the buffer static, the memory stays there... but the solution is not thread safe (obviously).
Putting the delay is an ugly fix, but it is thread safe and it does work.

No further digging.

Maurizio

from the transit: nobody is interested in "explanations" like "if I do not use the buffer static, the code as it is stops working" hinting on symptoms, but on constructive feedback, helping to find the cause of the differences (why can i not reproduce these symptoms with the small provided example configuration)? If it is e.g. a stack size problem, the the same cause can be responsible for other broken behavior (like the one of the begin of this thread).

M: "i did try ... and I observed the very same behavior..." What is the output from the debugging lines? I am interested in an output like in https://openacs.org/forums/message-view?message_id=5354342

There is no need for a rush from my side. On Monday, i'll be back in Vienna, and it will take me at least one week to recover from jet lag and work backlog, before i can make one more attempt with a newer version of visual studio.

Dear Gustaf...
let's be "constructive"...
1. the code:
#define MAX_BUF_SIZE 16384
#ifdef _WIN32
#define AC_DELAY 5
#endif
static ssize_t
SendFd(Ns_Sock *sock, int fd, off_t offset, size_t length,
const Ns_Time *timeoutPtr, unsigned int flags,
Ns_DriverSendProc *sendProc)
{
char buf[MAX_BUF_SIZE];
struct iovec iov;
ssize_t nwrote = 0, toRead = (ssize_t)length, result;
bool decork;

// Ns_Log(Notice, "SendFd offset %ld length %lu", offset, length);

decork = Ns_SockCork(sock, NS_TRUE);
while (toRead > 0) {
ssize_t sent, nread;

nread = pread(fd, buf, MIN((size_t)toRead, sizeof(buf)), offset);

Ns_Log(Notice, "... pread toread %lu offset %ld => read %ld", MIN((size_t)toRead, sizeof(buf)), offset, nread);
if (nread <= 0) {
break;
}
toRead -= nread;
offset += (off_t)nread;

(void) Ns_SetVec(&iov, 0, buf, (size_t)nread);
sent = (*sendProc)(sock, &iov, 1, timeoutPtr, flags);
#ifdef _WIN32
// Sleep(AC_DELAY);
#endif
if (sent > 0) {
nwrote += sent;
}

if (sent != nread) {
break;
}
}

if (decork) {
(void) Ns_SockCork(sock, NS_FALSE);
}

if (nwrote > 0) {
result = nwrote;
} else {
result = -1;
}

return result;
}
2. let's download a file of 6.68 MB...

3. without delay, the output is this:
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 0 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 16384 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 32768 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 49152 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 65536 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 81920 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 98304 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 114688 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 131072 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 147456 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 163840 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 180224 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 196608 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 212992 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 229376 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 245760 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 262144 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 278528 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 294912 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 311296 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 327680 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 344064 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 360448 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 376832 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 393216 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 409600 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 425984 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 442368 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 458752 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 475136 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 491520 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 507904 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 524288 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 540672 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 557056 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 573440 => read 16384
[19/Mar/2017:18:30:58][25880.6164][-conn:kedrios:4-] Notice: ... pread toread 16384 offset 589824 => read 16384
and the notices stop here.

But, if I put the delay we obtain:

[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 0 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 16384 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 32768 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 49152 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 65536 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 81920 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 98304 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 114688 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 131072 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 147456 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 163840 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 180224 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 196608 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 212992 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 229376 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 245760 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 262144 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 278528 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 294912 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 311296 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 327680 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 344064 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 360448 => read 16384
[19/Mar/2017:18:46:23][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 376832 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 393216 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 409600 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 425984 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 442368 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 458752 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 475136 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 491520 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 507904 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 524288 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 540672 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 557056 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 573440 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 589824 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 606208 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 622592 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 638976 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 655360 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 671744 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 688128 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 704512 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 720896 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 737280 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 753664 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 770048 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 786432 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 802816 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 819200 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 835584 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 851968 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 868352 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 884736 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 901120 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 917504 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 933888 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 950272 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 966656 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 983040 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 999424 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1015808 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1032192 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1048576 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1064960 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1081344 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1097728 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1114112 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1130496 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1146880 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1163264 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1179648 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1196032 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1212416 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1228800 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1245184 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1261568 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1277952 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1294336 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1310720 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1327104 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1343488 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1359872 => read 16384
[19/Mar/2017:18:46:24][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1376256 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1392640 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1409024 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1425408 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1441792 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1458176 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1474560 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1490944 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1507328 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1523712 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1540096 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1556480 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1572864 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1589248 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1605632 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1622016 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1638400 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1654784 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1671168 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1687552 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1703936 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1720320 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1736704 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1753088 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1769472 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1785856 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1802240 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1818624 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1835008 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1851392 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1867776 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1884160 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1900544 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1916928 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1933312 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1949696 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1966080 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1982464 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 1998848 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2015232 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2031616 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2048000 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2064384 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2080768 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2097152 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2113536 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2129920 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2146304 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2162688 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2179072 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2195456 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2211840 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2228224 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2244608 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2260992 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2277376 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2293760 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2310144 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2326528 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2342912 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2359296 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2375680 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2392064 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2408448 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2424832 => read 16384
[19/Mar/2017:18:46:25][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2441216 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2457600 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2473984 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2490368 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2506752 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2523136 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2539520 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2555904 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2572288 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2588672 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2605056 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2621440 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2637824 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2654208 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2670592 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2686976 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2703360 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2719744 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2736128 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2752512 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2768896 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2785280 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2801664 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2818048 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2834432 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2850816 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2867200 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2883584 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2899968 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2916352 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2932736 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2949120 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2965504 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2981888 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 2998272 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3014656 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3031040 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3047424 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3063808 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3080192 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3096576 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3112960 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3129344 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3145728 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3162112 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3178496 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3194880 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3211264 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3227648 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3244032 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3260416 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3276800 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3293184 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3309568 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3325952 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3342336 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3358720 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3375104 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3391488 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3407872 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3424256 => read 16384
[19/Mar/2017:18:46:26][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3440640 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3457024 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3473408 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3489792 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3506176 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3522560 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3538944 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3555328 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3571712 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3588096 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3604480 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3620864 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3637248 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3653632 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3670016 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3686400 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3702784 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3719168 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3735552 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3751936 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3768320 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3784704 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3801088 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3817472 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3833856 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3850240 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3866624 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3883008 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3899392 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3915776 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3932160 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3948544 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3964928 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3981312 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 3997696 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4014080 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4030464 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4046848 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4063232 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4079616 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4096000 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4112384 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4128768 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4145152 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4161536 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4177920 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4194304 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4210688 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4227072 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4243456 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4259840 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4276224 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4292608 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4308992 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4325376 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4341760 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4358144 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4374528 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4390912 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4407296 => read 16384
[19/Mar/2017:18:46:27][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4423680 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4440064 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4456448 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4472832 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4489216 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4505600 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4521984 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4538368 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4554752 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4571136 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4587520 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4603904 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4620288 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4636672 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4653056 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4669440 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4685824 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4702208 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4718592 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4734976 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4751360 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4767744 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4784128 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4800512 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4816896 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4833280 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4849664 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4866048 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4882432 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4898816 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4915200 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4931584 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4947968 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4964352 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4980736 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 4997120 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5013504 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5029888 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5046272 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5062656 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5079040 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5095424 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5111808 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5128192 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5144576 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5160960 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5177344 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5193728 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5210112 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5226496 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5242880 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5259264 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5275648 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5292032 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5308416 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5324800 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5341184 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5357568 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5373952 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5390336 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5406720 => read 16384
[19/Mar/2017:18:46:28][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5423104 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5439488 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5455872 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5472256 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5488640 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5505024 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5521408 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5537792 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5554176 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5570560 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5586944 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5603328 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5619712 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5636096 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5652480 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5668864 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5685248 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5701632 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5718016 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5734400 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5750784 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5767168 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5783552 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5799936 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5816320 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5832704 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5849088 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5865472 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5881856 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5898240 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5914624 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5931008 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5947392 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5963776 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5980160 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 5996544 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6012928 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6029312 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6045696 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6062080 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6078464 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6094848 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6111232 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6127616 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6144000 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6160384 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6176768 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6193152 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6209536 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6225920 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6242304 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6258688 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6275072 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6291456 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6307840 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6324224 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6340608 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6356992 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6373376 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6389760 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6406144 => read 16384
[19/Mar/2017:18:46:29][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6422528 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6438912 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6455296 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6471680 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6488064 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6504448 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6520832 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6537216 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6553600 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6569984 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6586368 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6602752 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6619136 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6635520 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6651904 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6668288 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6684672 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6701056 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6717440 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6733824 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6750208 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6766592 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6782976 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6799360 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6815744 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6832128 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6848512 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6864896 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6881280 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6897664 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6914048 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6930432 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6946816 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6963200 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 16384 offset 6979584 => read 16384
[19/Mar/2017:18:46:30][16928.60bc][-conn:kedrios:2-] Notice: ... pread toread 12072 offset 6995968 => read 12072
and everything works fine.
I'm sure you'll find this output very informative.

Thank you,
Maurizio

Dear Gustaf,
SendFd in sockfile calls
(*sendProc)(sock, &iov, 1, timeoutPtr, flags)...
Well this is a ptr function, eventually the function WSASend(in nssock.c/264) gets called.
But this is an asynchronous call.
This is why, I had to put a delay (an ugly fix I know) immediately after the call inside SendFd.
Whithout this delay, the WSASend can still work even after the SendFd is finished, that is when the buffer "buf" does not exists any longer in the stack. And this is why a static buffer prevents the problem from occurring (of course at the cost of the function non being thread safe).
A proper solution would be using WASSend completion routines. I believe this could be the reason why we see memory corruption problems:
http://www.serverframework.com/asynchronousevents/2015/01/wsarecv-wsasend-and-thread-safety.html

This is design, coding error and it has nothing to do with the compiler, the compiler options and so on....

Hope it helps,
Maurizio

Errata-Corrige
1. In teory, "WSASend", called within "SockSend", is called with the last two parameters set to NULL should be blocking... so no problem should occur.
2. when replacing "WSASend" with a normal "send", "SockSend" works without problems
3. "WSASend" by "SockSend also by AOLserver.
Probably the behaviour fo the "WSASend" has changed with the latest version of Windows and/or Visual C/C++.

I will update the code consequently.

Maurizio

Dear Maurizio at al,

I've installed Visual Studio 2017 on a VM, and could reproduce the first error of this forums thread. As expected, there was a change in Visual Studio: with version 2015, Microsoft changed with the introduction of the Universal CRT the behavior of _vsnprintf, which is not longer identical to _vsnprintf, but complies now with the C99 standard.

This change in Visual Studio affects potentially many places in the code and explains, why i could not reproduce the mentioned problem with Visual Studio 11. Maybe this is also related to the problem with large files (which i still can't reproduce).

it is not unlikely, that there are still more fixes necessary when compiling with Visual Studio 2015 or newer, but at least the problem with the "unbalanced brackets" should be fixed.

The changes are committed to bitbucket.

Dear Gustaf,
thank you very much for having replicated the issue.
I'm not sure I agree completely with your explanation.
If you're explanation was correct how come the following small modification (which I believe is the memory bug I was referring too) in the file dstring.c,
// #ifdef _WIN32
// while (result == -1 && errno == ERANGE) {
// newLength = dsPtr->spaceAvl * 2;
//#else
if ((size_t)result >= bufLength) {
newLength = dsPtr->spaceAvl + (result - (int)bufLength);
//#endif
makes:
1. the problem with the unbalanced braces disappear
2. the odd characters in the log disappear
3. the erratic behaviour disappear?

Thank you,
Maurizio

I saw your fix, in the same file, in the same area... we can call it as we want....
1. a compilation issue
2. a matter of compliance with standards...

but at the end of the day it is a memory allocation problem causing wrong/erratic behaviour.

This does not solve the long file problem, which at the moment I "fixed" not using a delay, but replacing WSASend with a plain send. I do not know why the second works and the first one doesn't.

Thank you,
Maurizio

maurizio, does this mean, you see with this change still the "unbalanced braces" issue? If so, make sure, that in your local changes, you do not alter the definitions of naviserver in respect to snprintf/vsnprintf (as it was in the case with the changes you sent to me around April 2016).

Background: the committed change (not sure, if the snippet you posted is the same) affects the dstring infrastructure, which is all over the code to append to a string. A buffer overflow on such a string can have many weird effects. Up to Visual Studio 2015, the functions vsnprintf() and _vsnprintf() behaved in the same, microsoft specific way, namely returning -1 in case, the provided buffer was too small, not guaranteeing null termination.

With the introduction of Visual Studio 2015, the behavior of vsnprintf() changed to become c99 compliant, but __vsnprintf() stayed the same. the c99 standard states, that in cases where the buffer is too small, the function should return the number of bytes that would have been written. That is a very different behavior for recognizing buffer grow requests and buffer size management. The same change of behavior also affects e.g. snprintf()/_snprintf(). So, when using these functions, a change from a Visual Studio before version 2015 to a newer version requires code changes. Convince yourself by compiling with an earlier version of Visual Studio!

So far, i see no obvious connection between the dstring function and the WSASend() problem. So far, i could not reproduce this issue. I tried yesterday multiple times with requests for a 6+ MB file, but everything worked fine. I find it hard to believe, that the specification

if both lpOverlapped and lpCompletionRoutine are NULL, the socket in this function will be treated as a non-overlapped socket. (https://msdn.microsoft.com/en-us/library/windows/desktop/ms742203.aspx)
is not valid in newer versions.

If someone has instructions, how to reproduce the issue reliably, i would appreciate it. i can't test maurizio's binaries in my setup, since i don't have 10GB free on the c: partition, and i failed to extend the partition in the vm under mac os x; so i need probably a different, completely new setup, for which i have no time now).

Dear Gustaf,
I've tried all combinations... here's the result:

the original code was:

DWORD n1;
if (WSASend(sock, (LPWSABUF)bufs, nbufs, &n1, flags,
NULL, NULL) != 0) {
n1 = -1;
}
n = n1;

and it DOES NOT WOK

I then used the readability improvement modification you posted this morning at 09:57:40
DWORD bytesReceived;
int rc;

rc = WSASend(sock, (LPWSABUF)bufs, nbufs, &bytesReceived, flags,
NULL, NULL);

if (rc == 0) {
n = bytesReceived;
} else {
n = -1;
}
and it DOES WORK

My original fix was to use a plain send
# if _MSC_VER < 1900
DWORD n1;
if (WSASend(sock, (LPWSABUF)bufs, nbufs, &n1, flags,
NULL, NULL) != 0) {
n1 = -1;
}
n = n1;
#else
n = send(sock, (LPWSABUF)bufs[0].iov_base, bufs[0].iov_len, flags);

#endif

and it DOES WORK

I will include your modification in my distribution, though I cannot see any difference between the first two implementations, but the code is here if anyone wants to check.

Thank you very much,
Maurizio

Do i read your mail correctly that now all know issues are gone? That would be great.

Concerning the change around WSAsend(): The difference is not easy to spot but due to a type conversion, since n1 (type DWORD) was originally assigned -1 in error conditions. Since DWORD is defined as unsigned 32bit quantity, bad things happen when its value is assigned to a type of a different size and signedness (here: ssize_t; probably not an issue in 32bit versions). Interestingly, this type issue is not flagged by sonarsrv: the current version of nssock.c in sonarsrv is still the "old" code and shows 0 issues [1]. I've cleaned this code yesterday to prepare for debugging return-codes from WSASend().

Concerning send(): When send() is used as shown in your snippet, the code will produce incorrect results when nbufs <> 1. The reason for using WSAsend() instead of send() is that the former supports the more efficient scatter/gather interface.

all the best
-gn

[1] http://sonarsrv.spazioit.com/code/index?id=my%3Anaviserver#/my%3Anaviserver%3Ansd%2Fsock.c

Dear Gustaf,
I believe all issues we have been facing are gone.
They were caused by two errors:
1. memory allocation problem (in dstring.c)
2. bad handling of the WSASend call.

I do not know if you saw it or not. But looking into possible causes for these problems I noticed that EINTR is not handled in a generic way as EWOULDBLOCK and EINPROGRESS. Perhaps it would make sense to normalize also EINTR.

Thank you,
Maurizio