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

I do apologize for this flooding of posts. I did some further analysis. These are current results and I will stop here.

1. The fix I made is not always working, so I will put back the code to its original version

2. The problem shows up only in ]po[ because ]po[ is a rather complex application from the timing/threading point of view

3. Putting a delay of one sec at the end of Ns_ThreadList temporarily fixes the problem, but at soon as ]po[ triggers its background processing the functioning of Ns_ThreadList is compromised.

4. When I talk about ]po[ I refer (and I always referred) refer to the FULL ]po[ and not the mini subset of modules/packages recently made available. @ Frank: I am surprised and sorry that I still have to provide these clarifications.

5. @ Gustaf: This is not a problem of "my binary". This is a problem in the timing and threading of Naviserver in Windows, that shows up in ]po[ given the complexity of this application.

6. As I said this problem, at least on my Windows Installer, is not blocking and does not prevent ]po[ (the FULL ]po[) from working.

7. In an hybrid environment like MS64+MINGW64 or MS64-CYGWIN64 timing and threading issues are more likely to appear that in a homogenous environment (e.g. MS only, MINGW only, CYGWIN only). My installer provides a sort of MS64+MINGW64 environment, Frank 's installer exposes bits and pieces of mine plus GIGWIN(64?), so it is a MS64+MINGW64+CYGWIN64 platform.

Hope it clarifies the situation.

Here I stop.

Maurizio

Dear Gustaf,
one key point cold, "could", be the different TCL version.
In my installer I'm still using 8.5.18.
Soon there will be a new VS version. When that is available, I will make an update of all components.
On top of that we did not use the same compiler, the same switches.
On point (7) I probably was not clear. I will make an example, perhaps I am wrong:
on my distribution I kind of distinguish between core components and ancillary tools, e.g.
1. Naviserver, it's modules, Tcl, Xotcl, etc... all these things are considered core components, and they are built from sources using the same compiler, the same switches, the same everything....
2. ancillary binaries like Curl, Wget, Perl, and the like are not compiled together with the core components, they are kind of "external binaries".
if Naviserver calls a Tcl function and Tcl has been compiled exactly in the same way and with the same tools (and same switches, like --enable-threads, and so on...) there are for sure less problems than the ones we could have when a MS Naviserver calls a MS Tcl compiled with different switches or even worse a MINGW or a CIGWIN Tcl. What do you think?

Finally the call
::xo::system_stats::gettid
works well with OpenACS and doesn't with ]po[ and I believe this is because ]po[ is more demanding in terms of timing/threading. In other words, ]po[ exposes a problem we have in Naviserver timing/threading (only on Windows).

Did you run ]po[ on your Windows test platform?

Thank you,
Maurizio

Dear Frank and Gustaf,
just for your information.

I've integrated in my distribution TCL 8.5.19 (it was 8.5.18) and the issue is still there.

1. OpenACS works fine.

2. With ]po[ we still have the unbalanced braces.
as far as I can see it is a timing / threading issue, getting worse when the scheduled background procedures are executed.

3. This issue in my installer is not blocking and does not prevent ]po[ from functioning properly.

4. I will be glad to prove anything I said in here with a live Teamviewer (or whatever) session.

BTW: It's almost one year I have ]po[ 5.0 running on this platform (with this issue present).

Thank you,
Maurizio

Dear Frank,
my installer, my binary... or simply Naviserver's behaviour on Windows?

...and how about the unbalanced braces...

Does this issue shows up also in the binary generated by Gustaf (I mean when running ]project-open[, not OpenACS)?

If not we need to understand the differences, if yes... then we are facing some problems in Naviserver that show up only in particular cases, work loads...

Please, if you can, get the binary form Gustaf. Please do try those binaries a big file, load then ]project-open[ and then let's see if we are observing different or identical behaviours.

Thank you for your analysis,
Maurizio

Hi,

Here are some additional details from debugging:

When pointing a browser to http://localhost:8000, Crome loads the first files without any issues. Here is part of the "Network" debugging output:

jquery.min.js	200
mktree.js	200
diagram.js	200
showhide.js	200
mktree.css	200
sm-simple.css	200
jquery.smartmenus.min.js	200
style.saltnpepper.css?v=0	(never returns)
style.saltnpepper.js	200
rounded_corners.inc.js	(never returns)
logo.gif	(never returns)
core.js	(never returns)

After that, NSD is blocked and consumes 99% CPU.

So I tried to load files individually via WGET in order to check if there is something special. As a result, I can load each of the files above, but with style.saltnpepper.css the download stops after 37% or 16kB of data.
- wget http://127.0.0.1:8000/intranet/style/style.saltnpepper.css

I tried multiple times, and also rounded_corners.inc.js stops after 16kB data. After that, NSD CPU usage increases 25% each (1 thread, my Laptop has 4 cores...). The same happens with any other slightly longer file (>16kB).

In contrast, I've downloaded hundred times the mktree.js file (9kB) without any issue.

Summary:
It looks to me like NaviServer stops/breaks during delivery of slightly larger files. As Maurizio said, the unbalanced braces error doesn't seem to affect the behavior of the server.

Cheers,
Frank

Just a quick status: Maurizio and I are right now repeating the installation process with completely fresh machines, because things seem to work on his instalation.

Frank

@frank i will send you the binaries that i've compiled, but be patient, i am on seldom on that machine. the binaries are built with win7, 64bit, plain naviserver installation ( i.e. no ssl or db-drivers); including the test-files for calling "ns_into threads" while the ticker is running; i've no idea, how well these run on different windows versions, but it seems that windows will pick up the binaries from the ns/bin/ directory. Will send you the binaries via mail. When building the server, i was essentially following the instructions of Makefile.win32 in the NaviServer distribution, but used different paths.

just now, i've tested to load larger files with these binaries. the largest .html files on that machine were 1.4 and 1.5 MB large, but these load without problems:

127.0.0.1 - - [07/Mar/2017:13:05:09 +0100] "GET /dt.html HTTP/1.1" 200 1432756 "" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:47.0) Gecko/20100101 Firefox/47.0" 
127.0.0.1 - - [07/Mar/2017:13:07:32 +0100] "GET /im.html HTTP/1.1" 200 1528278 "" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:47.0) Gecko/20100101 Firefox/47.0" 

@frank & maurizio: Since you have compiled fresh binaries, have you checked the debugging hooks mentioned above to find the source for the broken thread-info from the "-ticker-" thread?

@frank: Do you see any messages in the error.log around the time, when processing of large files stops?

sorry for the slower replies, I've very little time resources currently, full next week i'll be in china.

Dear all, sorry for my late post but I did lots of tests and now I am even more confused than before... 😊 😊 😊 This is what I found: 1. I took a single Windows machine, I installed Naviserver from my installer. 2. naviserver is answering on localhost, port 8000. 3. Then I installed on the same machine Nginx. this is the config:

# user www-data;
worker_processes  1;

# error_log  /var/log/nginx/error.log;
# pid        /var/run/nginx.pid;

events {
    worker_connections  1024;
    multi_accept on;
}

http {
  server_names_hash_bucket_size 64;
  
  server {
    listen 80;
    server_name openacs.local.lan;
    client_max_body_size 12M;
    location / {
      proxy_pass http://localhost:8000;
      proxy_connect_timeout 5;
      proxy_send_timeout    5;
      proxy_read_timeout  43200;
      proxy_set_header  X-Forwarded-For $remote_addr;
    }
  }
  }

In the /etc/hosts (yes, there's such a file also on Windows) I put the follwing:
127.0.0.1       openacs.local.lan

The Openacs Config had the following lines:

# change to 80 and 443 for production use
set httpport                  8000
set httpsport                 8443 

# The hostname and address should be set to actual values.
# setting the address to 0.0.0.0 means aolserver listens on all interfaces
set hostname                  localhost
set address                   localhost

With all of this in place, trying to get a big file via Nginx, that is: https://openacs.local.lan/acs-admin/ext-all.js works without any problem on the contrary http://localhost:8000/acs-admin/ext-all.js stops and never returns

I'm very confused by this result.
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

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.

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.

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.

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

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

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 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

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).

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