Also turns out that -1 returned by sendfile and corresponding errno is set to indicate that there is simply not space in the network buffer and nginx now properly handles this back pressure scenario:
788 2017/09/01 15:56:07 [debug] 0#245: *9 writev: 256 of 256 789 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: @0 614770 790 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: 33324 of 614770 @0 *791 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: @33324 581446* * 792 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile() is not ready (11: Resource temporarily unavailable)* 793 2017/09/01 15:56:07 [debug] 0#245: *9 http write filter FFFF900003A352E8 794 2017/09/01 15:56:07 [debug] 0#245: *9 http copy filter: -2 "/services.js?" 795 2017/09/01 15:56:07 [debug] 0#245: *9 http finalize request: -2, "/services.js?" a:1, c:1 796 2017/09/01 15:56:07 [debug] 0#245: *9 event timer add: 22: 60000:1504281427482 797 2017/09/01 15:56:07 [debug] 0#245: *9 epoll add event: fd:22 op:3 ev:80002005 798 2017/09/01 15:56:07 [debug] 0#245: *9 http run request: "/services.js?" 799 2017/09/01 15:56:07 [debug] 0#245: *9 http writer handler: "/services.js?" 800 2017/09/01 15:56:07 [debug] 0#245: *9 http output filter "/services.js?" 801 2017/09/01 15:56:07 [debug] 0#245: *9 http copy filter: "/services.js?" 802 2017/09/01 15:56:07 [debug] 0#245: *9 http postpone filter "/services.js?" 0000000000000000 803 2017/09/01 15:56:07 [debug] 0#245: *9 write old buf t:0 f:1 0000000000000000, pos 0000000000000000, size: 0 file: 33324, size: 581446 804 2017/09/01 15:56:07 [debug] 0#245: *9 http write filter: l:1 f:0 s:581446 805 2017/09/01 15:56:07 [debug] 0#245: *9 http write filter limit 0 * 806 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: @33324 581446* * 807 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: 4380 of 581446 @33324* 808 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: @37704 577066 809 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: 16952 of 577066 @37704 810 2017/09/01 15:56:07 [debug] 0#245: *9 sendfile: @54656 560114 On Friday, September 1, 2017 at 12:08:41 PM UTC-4, Waldek Kozaczuk wrote: > > I changed > int sendfile(int out_fd, int in_fd, off_t *_offset, size_t count) > to > ssize_t sendfile(int out_fd, int in_fd, off_t *_offset, size_t count) > > and all works like a charm. > > On Friday, September 1, 2017 at 10:32:24 AM UTC-4, Waldek Kozaczuk wrote: >> >> In all headers and per Linux headers sendfile returns values of type >> ssize_t (which I think in OSv maps to long). The definition of sendfile in >> OSv (per >> https://github.com/cloudius-systems/osv/blob/master/fs/vfs/main.cc#L2011) >> returns int. This seems to be wrong! Shall it be changed to ssize_t? >> >> int sendfile(int out_fd, int in_fd, off_t *_offset, size_t count) >> >> Waldek >> >> On Thursday, August 31, 2017 at 6:41:12 PM UTC-4, Waldek Kozaczuk wrote: >>> >>> It seems like a number conversion issue. *4294967295 *is I think -1 but >>> when returned to nginx code it becomes *4294967295 *and if(n == -1) >>> does not happen ... Why >>> >>> Besides conversion sendfile probably fails. Per >>> https://github.com/cloudius-systems/osv/blob/master/fs/vfs/main.cc >>> there are 2 cases when -1 is returned: >>> 1) >>> https://github.com/cloudius-systems/osv/blob/master/fs/vfs/main.cc#L2053 >>> - from fstat (what is this comment about one extent?) >>> 2) >>> https://github.com/cloudius-systems/osv/blob/master/fs/vfs/main.cc#L2071 >>> - mmap failing >>> >>> Is my thinking correct? >>> >>> Waldek >>> >>> On Thursday, August 31, 2017 at 6:21:42 PM UTC-4, Waldek Kozaczuk wrote: >>>> >>>> I think the key question is why it is trying to "sendfile" *4294967295 >>>> *bytes of data if file is only *614770 *bytes big? >>>> >>>> If you look at the source code ( >>>> https://github.com/firebase/nginx/blob/master/src/os/unix/ngx_linux_sendfile_chain.c) >>>> >>>> and implementation of ngx_linux_sendfile it does this: >>>> >>>> ngx_log_debug2(NGX_LOG_DEBUG_EVENT, c->log, 0, >>>> "sendfile: @%O %uz", file->file_pos, size); >>>> n = sendfile(c->fd, file->file->fd, &offset, size); >>>> ... - error handling >>>> >>>> ngx_log_debug3(NGX_LOG_DEBUG_EVENT, c->log, 0, "sendfile: %z of %uz @%O >>>> ", >>>> n, size, file->file_pos) >>>> so why n (equal to what was returned by sendfile() was *4294967295?* >>>> >>>> It looks like sendfile() lied about bytes copied between descriptors. >>>> Why? >>>> >>>> Waldek >>>> >>>> On Thursday, August 31, 2017 at 9:14:06 AM UTC-4, Waldek Kozaczuk wrote: >>>>> >>>>> Recently I have been playing with nginx on OSv and seeing some errors >>>>> on client side (web browser or ab - Apache benchmark) tool. >>>>> >>>>> In general all works fine when I make single request to fetch >>>>> individual file. However when I use ab to fetch same file (around 600K >>>>> big) >>>>> concurrently 5 times some of the requests fail (2-4 of 5) with dropped >>>>> connections. It seems that ab is only getting subset of data for those >>>>> failed requests. >>>>> >>>>> In the browser when I try to reload entire HTML page that involves >>>>> fetching 10 or more resources simultaneously most GET requests succeed >>>>> but >>>>> some fail eventually with error like so :net::ERR_CONTENT_LENGTH_MISMATCH >>>>> which seems to indicate that data received was different from what was >>>>> advertised in Content-Length header received initially from nginx. >>>>> >>>>> I bumped up the nginx error log settings to debug and I have not seen >>>>> any errors. However in case of 5 concurrent requests scenario I only saw >>>>> it >>>>> handle only 4 requests. Is it because OSv drops connections prematurely? >>>>> Or >>>>> is it because I am testing it on qemu on OSx and there is some limitation >>>>> around virtual networking and timeouts. >>>>> >>>>> Here are my QEMU arguments: >>>>> /usr/local/bin/qemu-system-x86_64 -nographic -m 1024 -smp 4 -device >>>>> virtio-blk-pci,id=blk0,bootindex=0,drive=hd0 -drive >>>>> file=/my_app/disk.qcow2,if=none,id=hd0,aio=threads,cache=unsafe -device >>>>> virtio-rng-pci -chardev stdio,mux=on,id=stdio,signal=off -device >>>>> isa-serial,chardev=stdio -netdev user,id=un0,net= >>>>> 192.168.122.0/24,host=192.168.122.1,hostfwd=tcp::8000-:8000,hostfwd=tcp::8080-:80 >>>>> >>>>> -device virtio-net-pci,netdev=un0 -chardev >>>>> socket,id=charmonitor,path=/my_app/osv.monitor,server,nowait -mon >>>>> chardev=charmonitor,id=monitor,mode=control >>>>> >>>>> Please see attached ab outputs and nginx log outputs for both single >>>>> request and 5 concurrent requests. How can I better debug the problem? >>>>> User >>>>> traffic sniffer on host side or connect to OSv using debugger? If >>>>> debugger >>>>> then where in call stack put breakpoint? >>>>> >>>>> I appreciate help solving this problem. I am trying to port existing >>>>> static HTML5 app from Apache on Linux to nginx on OSv and would love to >>>>> see >>>>> it fully work. >>>>> >>>>> Regards, >>>>> Waldek >>>>> >>>> -- You received this message because you are subscribed to the Google Groups "OSv Development" group. To unsubscribe from this group and stop receiving emails from it, send an email to osv-dev+unsubscr...@googlegroups.com. For more options, visit https://groups.google.com/d/optout.
