On Thu, Jan 17, 2019 at 11:11:08PM +0100, Gustaf Neumann wrote: > I've now replaced the UTF-8 string literals by > hexadecimal-escape-sequences on bitbucket [1]. > [1] > https://bitbucket.org/naviserver/naviserver/commits/5c915e2412de64d0ee9e5c85a9fd46c59bc64ea4
I tried it, no difference, still the same 8 ns_striphtml test failures as before. After that, I also rebuilt with "-finput-charset=UTF-8" added to CFLAGS_EXTRA in include/Makefile.global; that also made no difference. However, next I built Tcl 8.6.9 from source myself, and to my surprise, THAT fixed the ns_striphtml test failures! For some reason NaviServer now skipped the 4 nsf tests, but hopefully that doesn't matter, since they passed before. ## Newer from-source Tcl: $ /usr/local/pkg/tcl-8.6.9-20190118/bin/tclsh8.6 % info patchlevel 8.6.9 ## Older Ubuntu Tcl, ns_striphtml tests fail: $ /usr/bin/tclsh8.6 % info patchlevel 8.6.5 -- Andrew Piskorski <a...@piskorski.com>
make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsthread' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsthread' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsd' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsd' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nssock' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nssock' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nscgi' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nscgi' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nscp' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nscp' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nslog' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nslog' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsperm' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsperm' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsdb' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsdb' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsdbtest' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsdbtest' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsssl' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsssl' make[1]: Entering directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsproxy' make[1]: Nothing to be done for 'all'. make[1]: Leaving directory '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/nsproxy' LD_LIBRARY_PATH="/usr/local/src/web/ns-head-pub/naviserver/nsd:/usr/local/src/web/ns-head-pub/naviserver/nsthread:/usr/local/src/web/ns-head-pub/naviserver/nsdb:/usr/local/src/web/ns-head-pub/naviserver/nsproxy:$LD_LIBRARY_PATH" DYLD_LIBRARY_PATH="/usr/local/src/web/ns-head-pub/naviserver/nsd:/usr/local/src/web/ns-head-pub/naviserver/nsthread:/usr/local/src/web/ns-head-pub/naviserver/nsdb:/usr/local/src/web/ns-head-pub/naviserver/nsproxy:$DYLD_LIBRARY_PATH" ./nsd/nsd -u root -c -d -t /usr/local/src/web/ns-head-pub/naviserver/tests/test.nscfg /usr/local/src/web/ns-head-pub/naviserver/tests/all.tcl [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: try ::1 8000 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: configure LOOPBACK ::1 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: configure LISTENURL http://[::1]:8000 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: enable progress statistics for uploads >= 1 bytes [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: NaviServer/4.99.17 (fd186ea6d7d2+ default tip) starting [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: security info: uid=1010, euid=1010, gid=501, egid=501 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: Tcl version: 8.6.9 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: max files: soft limit 1048576, hard limit 1048576 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Warning: nsmain: rl_cur (1048576) > FD_SETSIZE (1024), select() calls should not be used [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: vhost[testvhost]: www.example.com:80 -> /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/testserver/vhosts/e/x/a/example.com/pages [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: pool default: queueLength 97 low water 9 high water 77 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsd/init.tcl[testvhost]: booting virtual server: Tcl system encoding: "utf-8" [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: Using ns_cache implemented as a Tcl proc [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: limits: confLimit1: maxrun=99 maxwait=100 maxupload=10240000 timeout=60 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: limits: confLimit2: maxrun=100 maxwait=100 maxupload=10240000 timeout=60 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: tcl[testvhost]: enabletclpages for {GET HEAD POST} requests [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: limits: confLimit1: maxrun=99 maxwait=100 maxupload=10240000 timeout=60 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: limits: confLimit2: maxrun=100 maxwait=100 maxupload=10240000 timeout=60 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Warning: ns_md, ns_hmac, ns_hotp and ns_totp are not available [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: update interpreter to epoch 1, trace deallocate, time 0.005670 secs [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: pool default: queueLength 96 low water 9 high water 76 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsd/init.tcl[testvhost2]: booting virtual server: Tcl system encoding: "utf-8" [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: Using ns_cache implemented as a Tcl proc [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: tcl[testvhost2]: enabletclpages for {GET HEAD POST} requests [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Warning: ns_md, ns_hmac, ns_hotp and ns_totp are not available [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: update interpreter to epoch 1, trace deallocate, time 0.005075 secs [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: pool default: queueLength 90 low water 9 high water 72 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: pool emergency: queueLength 99 low water 9 high water 79 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsd/init.tcl[test]: booting virtual server: Tcl system encoding: "utf-8" [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: modload: loading module nslog from file /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/../nslog/nslog.so [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nslog: opened '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/testserver/access.log' [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: modload: loading module nsdb from file /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/../nsdb/nsdb.so [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: modload: loading module ns/db/driver/nsdbtest from file /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/../nsdbtest/nsdbtest.so [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: modload: loading module nsproxy from file /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/../nsproxy/nsproxy.so [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: Using ns_cache implemented as a Tcl proc [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: limits[test]: confLimit1 -> GET /confLimit1 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: adp[test]: mapped {GET HEAD POST} *.adp [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: adp[test]: mapped {GET HEAD POST} *_adp [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: tcl[test]: mapped {GET HEAD POST} *.tcl [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: limits[test]: confLimit1 -> GET /confLimit1 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Warning: ns_md, ns_hmac, ns_hotp and ns_totp are not available [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: update interpreter to epoch 1, trace deallocate, time 0.004296 secs [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: update interpreter to epoch 1, trace none, time 0.004092 secs [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: modload: loading module nssock from file /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/../nssock/nssock.so [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nssock:0: enable 3 spooler thread(s) for uploads >= 1025 bytes [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nssock:0: enable 3 writer thread(s) for downloads >= 1026 bytes, bufsize=512 bytes, HTML streaming 0 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nssock: adding virtual host entry for host <test:8000> location: http://test:8000 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nssock: adding virtual host entry for host <testvhost:8000> location: http://testvhost:8000 [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nssock: adding virtual host entry for host <testvhost2:8000> location: http://testvhost2:8000 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: starting [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: nssock:0: listening on [::1]:8000 [18/Jan/2019:16:19:25][39532.7fbf4bfff700][-spooler2-] Notice: spooler2: accepting connections [18/Jan/2019:16:19:25][39532.7fbf4b7fe700][-spooler1-] Notice: spooler1: accepting connections [18/Jan/2019:16:19:25][39532.7fbf4affd700][-spooler0-] Notice: spooler0: accepting connections [18/Jan/2019:16:19:25][39532.7fbf4a7fc700][-writer2-] Notice: writer2: accepting connections [18/Jan/2019:16:19:25][39532.7fbf49ffb700][-writer1-] Notice: writer1: accepting connections [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: driver: accepting connections [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: NaviServer/4.99.17 (fd186ea6d7d2+ default tip) running [18/Jan/2019:16:19:25][39532.7fbf701ec700][-main-] Notice: nsmain: security info: uid=1010, euid=1010, gid=501, egid=501 [18/Jan/2019:16:19:25][39532.7fbf497fa700][-writer0-] Notice: writer0: accepting connections [18/Jan/2019:16:19:25][39532.7fbf67fff700][-sched-] Notice: sched: starting [18/Jan/2019:16:19:25][39532.7fbf651e8700][-conn:testvhost2:0:0-] Notice: update interpreter to epoch 1, trace none, time 0.006092 secs [18/Jan/2019:16:19:25][39532.7fbf651e8700][-conn:testvhost2:0:0-] Notice: thread initialized (0.012108 secs) [18/Jan/2019:16:19:25][39532.7fbf661ea700][-conn:test:1:0-] Notice: update interpreter to epoch 1, trace none, time 0.006254 secs [18/Jan/2019:16:19:25][39532.7fbf669eb700][-conn:test:0:0-] Notice: update interpreter to epoch 1, trace none, time 0.006335 secs [18/Jan/2019:16:19:25][39532.7fbf661ea700][-conn:test:1:0-] Notice: thread initialized (0.012418 secs) [18/Jan/2019:16:19:25][39532.7fbf671ec700][-conn:test:emergency:0:0-] Notice: update interpreter to epoch 1, trace none, time 0.006223 secs [18/Jan/2019:16:19:25][39532.7fbf6d598700][-command-] Notice: update interpreter to epoch 1, trace none, time 0.006002 secs [18/Jan/2019:16:19:25][39532.7fbf669eb700][-conn:test:0:0-] Notice: thread initialized (0.012527 secs) [18/Jan/2019:16:19:25][39532.7fbf659e9700][-conn:testvhost:0:0-] Notice: update interpreter to epoch 1, trace none, time 0.006249 secs [18/Jan/2019:16:19:25][39532.7fbf671ec700][-conn:test:emergency:0:0-] Notice: thread initialized (0.012426 secs) [18/Jan/2019:16:19:25][39532.7fbf659e9700][-conn:testvhost:0:0-] Notice: thread initialized (0.012469 secs) Tests running in interp: /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/nsd/nsd Tests located in: /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests Tests running in: /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests Temporary files stored in /net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests Test files sourced into current interpreter Running tests that match: * Skipping test files that match: l.*.test Only running test files that match: *.test Tests began at Fri Jan 18 16:19:25 EST 2019 adp.test [18/Jan/2019:16:19:25][39532.7fbf6d598700][-command-] Warning: ns_adp_eval {<% ns_adp_append adp-4.1 %>} is deprecated. Use 'ns_adp_parse' instead! [18/Jan/2019:16:19:25][39532.7fbf6d598700][-command-] Warning: ns_adp_eval {<% ns_adp_puts adp-4.2 %>} is deprecated. Use 'ns_adp_parse' instead! [18/Jan/2019:16:19:25][39532.7fbf6d598700][-command-] Warning: ns_adp_eval {<% ns_adp_puts -nonewline adp-4.3 %>} is deprecated. Use 'ns_adp_parse' instead! compat.test [18/Jan/2019:16:19:25][39532.7fbf6d598700][-command-] Warning: ns_cp f1 f2 is deprecated. Use 'file copy' instead! cookies.test encoding.test errordoc.test http.test [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <bogus HTTP/1.0> -> ERROR [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'bogus HTTP/1.0' offsets: read 17 write 102 content 0 avail 85 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: bogus HTTP/1.0\x00\x0aAccept: */*\x0d\x0aUser-Agent: NaviServer-Tcl/4.99\x0d\x0aConnection: close\x0d\x0aHost: [::1]:8000\x0d\x0a\x0d\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: pre-HTTP/1.0 request <GET /noexist> [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <GET a> -> ERROR [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'GET a' offsets: read 7 write 7 content 0 avail 0 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: GET a\x00\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <GET a b> -> ERROR [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'GET a b' offsets: read 9 write 9 content 0 avail 0 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: GET a b\x00\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <GET a b c> -> ERROR [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'GET a b c' offsets: read 11 write 11 content 0 avail 0 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: GET a b c\x00\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <a b> -> ERROR [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'a b' offsets: read 5 write 5 content 0 avail 0 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: a b\x00\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <a b c> -> ERROR [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'a b c' offsets: read 7 write 7 content 0 avail 0 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: a b c\x00\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: pre-HTTP/1.0 request <GET /10bytes> [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: request line is too long (1072 bytes) [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: request header line is too long (1054 bytes) [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: request header line is too long (1054 bytes) [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: SockParse: request too large, length=1000002, maxinput=1000001 [18/Jan/2019:16:19:25][39532.7fbf4bfff700][-spooler2-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf4bfff700][-spooler2-] Notice: progress end url '/put' [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 414 (Too Many Request Headers) from peer ::1 request 'GET /limits HTTP/1.1' offsets: read 124 write 1024 content 0 avail 900 [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: GET /limits HTTP/1.1\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x00\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0ax: y\x0d\x0a [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf4b7fe700][-spooler1-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf4affd700][-spooler0-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf4bfff700][-spooler2-] Notice: progress start url '/put' [18/Jan/2019:16:19:25][39532.7fbf4bfff700][-spooler2-] Notice: progress end url '/put' [18/Jan/2019:16:19:25][39532.7fbf4b7fe700][-spooler1-] Notice: progress start url '/put' [18/Jan/2019:16:19:26][39532.7fbf4b7fe700][-spooler1-] Notice: progress end url '/put' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Warning: SockParse: request too large, length=1000002, maxinput=1000001 [18/Jan/2019:16:19:26][39532.7fbf4affd700][-spooler0-] Notice: progress start url '/put' [18/Jan/2019:16:19:26][39532.7fbf4affd700][-spooler0-] Notice: progress end url '/put' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Warning: SockParse: request too large, length=1000002, maxinput=1000001 [18/Jan/2019:16:19:26][39532.7fbf4bfff700][-spooler2-] Notice: progress start url '/put' [18/Jan/2019:16:19:26][39532.7fbf4bfff700][-spooler2-] Notice: progress end url '/put' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/put' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/post' [18/Jan/2019:16:19:26][39532.7fbf669eb700][-conn:test:0:83-] Notice: encoding system utf-8 conn charset utf-8 [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/post' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/post' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/post' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:26][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/form' [18/Jan/2019:16:19:27][39532.7fbf4b7fe700][-spooler1-] Notice: progress start url '/post' [18/Jan/2019:16:19:27][39532.7fbf4b7fe700][-spooler1-] Notice: progress end url '/post' [18/Jan/2019:16:19:28][39532.7fbf4affd700][-spooler0-] Notice: progress start url '/post' [18/Jan/2019:16:19:28][39532.7fbf4affd700][-spooler0-] Notice: progress end url '/post' [18/Jan/2019:16:19:28][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/put' [18/Jan/2019:16:19:30][39532.7fbf6d598700][-command-] Notice: OK [18/Jan/2019:16:19:30][39532.7fbf48ff9700][task:tclhttp] Notice: update interpreter to epoch 1, trace none, time 0.008201 secs http_byteranges.test http_chunked.test http_keep.test [18/Jan/2019:16:19:45][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/keep' [18/Jan/2019:16:19:45][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/keep' http_persistent.test [18/Jan/2019:16:19:45][39532.7fbf649e7700][-driver:nssock:0-] Warning: Ns_ParseRequest <TOOMUCH> -> ERROR [18/Jan/2019:16:19:45][39532.7fbf649e7700][-driver:nssock:0-] Warning: invalid request: 400 (Bad Request) from peer ::1 request 'TOOMUCH' offsets: read 9 write 9 content 0 avail 0 [18/Jan/2019:16:19:45][39532.7fbf649e7700][-driver:nssock:0-] Warning: REQ BUFFER: TOOMUCH\x00\x0a [18/Jan/2019:16:19:45][39532.7fbf649e7700][-driver:nssock:0-] Notice: progress start url '/1' init.test [18/Jan/2019:16:19:45][39532.7fbf277fe700][-ns_job_0-] Notice: Starting thread: -ns_job_0- [18/Jan/2019:16:19:45][39532.7fbf277fe700][-ns_job_0-] Notice: update interpreter to epoch 1, trace none, time 0.008251 secs keylist.test ns_accesslog.test ns_addrbyhost.test ns_adp_compress.test ns_base64.test ns_cache.test [18/Jan/2019:16:19:58][39532.7fbf26ffd700][-tcl-nsthread:0-] Notice: update interpreter to epoch 1, trace none, time 0.008236 secs [18/Jan/2019:16:20:01][39532.7fbf26ffd700][-tcl-nsthread:1-] Notice: update interpreter to epoch 1, trace none, time 0.007918 secs [18/Jan/2019:16:20:06][39532.7fbf26ffd700][-tcl-nsthread:2-] Notice: update interpreter to epoch 1, trace none, time 0.008213 secs [18/Jan/2019:16:20:13][39532.7fbf6d598700][-command-] Warning: cache trans_c1: adding entry 0x7fbf18021f20 with key 'k4' multiple times to pending table [18/Jan/2019:16:20:13][39532.7fbf6d598700][-command-] Notice: CacheTransactionFinish: rolled back 2 elements in (0.000013 secs) [18/Jan/2019:16:20:13][39532.7fbf6d598700][-command-] Warning: cache trans_c1: adding entry 0x7fbf18021f20 with key 'k4' multiple times to pending table [18/Jan/2019:16:20:13][39532.7fbf6d598700][-command-] Notice: CacheTransactionFinish: committed 2 elements in (0.000007 secs) ns_cond.test [18/Jan/2019:16:20:13][39532.7fbf6d598700][-command-] Notice: tst_cond_master: New thread '' started for running tst_cond_worker. [18/Jan/2019:16:20:13][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: update interpreter to epoch 1, trace none, time 0.008257 secs [18/Jan/2019:16:20:13][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: 2 work items: 0 1 [18/Jan/2019:16:20:14][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: Event 'ns:condition:tcl:0' - got it. [18/Jan/2019:16:20:14][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: 1 work items: 2 [18/Jan/2019:16:20:15][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: Event 'ns:condition:tcl:0' - got it. [18/Jan/2019:16:20:15][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: 1 work items: 3 [18/Jan/2019:16:20:16][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: Event 'ns:condition:tcl:0' - got it. [18/Jan/2019:16:20:16][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: 1 work items: 4 [18/Jan/2019:16:20:17][39532.7fbf6d598700][-command-] Notice: tst_cond_master: 5 work items done: 0 1 2 3 4 [18/Jan/2019:16:20:17][39532.7fbf6d598700][-command-] Notice: tst_cond_master: 0 work items NOT done: [18/Jan/2019:16:20:17][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: Event 'ns:condition:tcl:0' - got it. [18/Jan/2019:16:20:17][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: 0 work items: [18/Jan/2019:16:20:17][39532.7fbf26ffd700][-tcl-nsthread:3-] Notice: tst_cond_worker: No more work for me today. ns_config.test ns_conn.test ns_conn_host.test ns_crypt.test ns_crypto.test ns_driver.test ns_env.test ns_file.test ns_gifsize.test ns_hashpath.test ns_hostbyaddr.test [18/Jan/2019:16:20:17][39532.7fbf6d598700][-command-] Notice: dns: getnameinfo failed for addr <0.0.0.0>: Name or service not known ns_hrefs.test ns_httptime.test ns_image.test ns_info.test ns_jpegsize.test ns_limits.test ns_listencallback.test [18/Jan/2019:16:20:19][39532.7fbf26ffd700][-socks-] Notice: socks: starting [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Notice: open sockent on ::1 7227 [18/Jan/2019:16:20:19][39532.7fbf26ffd700][-socks-] Notice: ... query IP + PROTO: SockAddr family AF_INET6, ip ::1, port 7227 [18/Jan/2019:16:20:19][39532.7fbf26ffd700][-socks-] Notice: update interpreter to epoch 1, trace none, time 0.008069 secs ns_log.test [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-3.4: (ns_log + severity "fatal" never writes) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Fatal: test [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-5.2: (count buffered log entries) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-5.7: (get) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-5.8: (flush) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Notice: test [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-5.9: (flush) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Notice: test [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-6.1: (configuration) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-6.2: (configuration) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-6.3: (enable/disable) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-6.4: (list severities) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-6.5: (bounds check) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-6.6: (bounds check) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Dev: >->-> ns_log-7.0: (two callbacks test) [18/Jan/2019:16:20:19][39532.7fbf6d598700][-command-] Notice: Log callback test 7.0 ns_md5.test ns_mime.test ns_nsv.test ns_pagepath.test ns_parseargs.test [18/Jan/2019:16:20:19][39532.7fbf267fc700][-tcl-nsthread:4-] Notice: update interpreter to epoch 1, trace none, time 0.007826 secs ns_parseurl.test ns_proxy.test [18/Jan/2019:16:20:19][39565.7f74e1736700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:19][39532.7fbf267fc700][-nsproxy:reap-] Notice: starting [18/Jan/2019:16:20:19][39567.7fe23f31f700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:19][39568.7f8b67425700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:19][39569.7f852ea88700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:19][39570.7fb768172700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:19][39532.7fbf25ffb700][-tcl-nsthread:5-] Notice: update interpreter to epoch 1, trace none, time 0.005692 secs [18/Jan/2019:16:20:19][39532.7fbf25ffb700][-tcl-nsthread:6-] Notice: update interpreter to epoch 1, trace none, time 0.005093 secs [18/Jan/2019:16:20:19][39573.7f5942f8a700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:19][39574.7fe369a21700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:20][39532.7fbf6d598700][-command-] Notice: releasing busy proxy testpool-8 [18/Jan/2019:16:20:21][39575.7f5ba4641700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:22][39532.7fbf6d598700][-command-] Notice: releasing busy proxy testpool-8 [18/Jan/2019:16:20:24][39576.7ffbf6c8c700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:25][39532.7fbf6d598700][-command-] Notice: releasing busy proxy testpool-8 [18/Jan/2019:16:20:26][39577.7f6bc5c2e700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:27][39532.7fbf6d598700][-command-] Notice: releasing busy proxy testpool-8 [18/Jan/2019:16:20:28][39578.7f6fbe8d5700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39579.7f5eaeca4700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39580.7f34d7317700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39581.7efd484d8700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39582.7f54fda07700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39583.7f11ed96a700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39584.7f0e55ea5700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39585.7f20dcebb700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:28][39586.7ffab54f1700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:30][39532.7fbf267fc700][-nsproxy:reap-] Warning: [testpool]: pid 39578 won't die, send signal 15 [18/Jan/2019:16:20:30][39532.7fbf6d598700][-command-] Notice: proxy maxrun reached pool testpool slave 39587 [18/Jan/2019:16:20:30][39532.7fbf267fc700][-nsproxy:reap-] Notice: nsproxy process 39578 killed with signal 15 (Terminated) [18/Jan/2019:16:20:30][39587.7f37512d0700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:30][39588.7f9c9b1eb700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:30][39532.7fbf6d598700][-command-] Notice: proxy maxrun reached pool testpool slave 39588 [18/Jan/2019:16:20:30][39589.7f094567a700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized [18/Jan/2019:16:20:30][39532.7fbf6d598700][-command-] Notice: proxy maxrun reached pool testpool slave 39589 [18/Jan/2019:16:20:30][39591.7f2089fa1700][-main-] Notice: OpenSSL 1.0.2g 1 Mar 2016 initialized ns_reflow_text.test ns_register_filter.test ns_register_proc.test ns_schedule.test [18/Jan/2019:16:20:40][39532.7fbf67fff700][-sched-] Notice: update interpreter to epoch 1, trace none, time 0.008477 secs [18/Jan/2019:16:20:51][39532.7fbf25ffb700][-sched:idle0-] Notice: starting [18/Jan/2019:16:20:51][39532.7fbf25ffb700][-sched:6-] Notice: update interpreter to epoch 1, trace none, time 0.007395 secs ns_server.test [18/Jan/2019:16:20:59][39532.7fbf6d598700][-command-] Notice: pool[test]: mapped GET /foo -> emergency [18/Jan/2019:16:20:59][39532.7fbf6d598700][-command-] Notice: pool[test]: unmapped GET /foo [18/Jan/2019:16:20:59][39532.7fbf6d598700][-command-] Notice: pool[test]: mapped GET /foo -> emergency [18/Jan/2019:16:20:59][39532.7fbf6d598700][-command-] Notice: pool[test]: unmapped GET /foo [18/Jan/2019:16:20:59][39532.7fbf6d598700][-command-] Notice: pool[test]: mapped GET /foo/*.png -> emergency [18/Jan/2019:16:20:59][39532.7fbf6d598700][-command-] Warning: pool[test]: could not unmap GET /foo ns_serverpath.test ns_set.test ns_sha1.test ns_sls.test ns_striphtml.test ns_thread.test [18/Jan/2019:16:20:59][39532.7fbf24ff9700][-tcl-nsthread:8-] Notice: update interpreter to epoch 1, trace none, time 0.008593 secs [18/Jan/2019:16:20:59][39532.7fbf257fa700][-tcl-nsthread:7-] Notice: update interpreter to epoch 1, trace none, time 0.008629 secs [18/Jan/2019:16:20:59][39532.7fbf24ff9700][-tcl-nsthread:9-] Notice: update interpreter to epoch 1, trace none, time 0.004083 secs [18/Jan/2019:16:20:59][39532.7fbf24ff9700][-tcl-nsthread:10-] Notice: update interpreter to epoch 1, trace none, time 0.016233 secs [18/Jan/2019:16:20:59][39532.7fbf0effd700][-tcl-nsthread:11-] Notice: update interpreter to epoch 1, trace none, time 0.016115 secs [18/Jan/2019:16:20:59][39532.7fbf0cff9700][-tcl-nsthread:12-] Notice: update interpreter to epoch 1, trace none, time 0.011590 secs [18/Jan/2019:16:20:59][39532.7fbf0ffff700][-tcl-nsthread:15-] Notice: update interpreter to epoch 1, trace none, time 0.005773 secs [18/Jan/2019:16:20:59][39532.7fbf0e7fc700][-tcl-nsthread:13-] Notice: update interpreter to epoch 1, trace none, time 0.006835 secs [18/Jan/2019:16:20:59][39532.7fbf257fa700][-tcl-nsthread:14-] Notice: update interpreter to epoch 1, trace none, time 0.005565 secs [18/Jan/2019:16:20:59][39532.7fbf017fa700][-tcl-nsthread:24-] Notice: update interpreter to epoch 1, trace none, time 0.005878 secs [18/Jan/2019:16:20:59][39532.7fbf0f7fe700][-tcl-nsthread:16-] Notice: update interpreter to epoch 1, trace none, time 0.007132 secs [18/Jan/2019:16:20:59][39532.7fbf0dffb700][-tcl-nsthread:17-] Notice: update interpreter to epoch 1, trace none, time 0.006250 secs [18/Jan/2019:16:20:59][39532.7fbf03fff700][-tcl-nsthread:20-] Notice: update interpreter to epoch 1, trace none, time 0.006375 secs [18/Jan/2019:16:20:59][39532.7fbf02ffd700][-tcl-nsthread:21-] Notice: update interpreter to epoch 1, trace none, time 0.006101 secs [18/Jan/2019:16:20:59][39532.7fbf037fe700][-tcl-nsthread:19-] Notice: update interpreter to epoch 1, trace none, time 0.007233 secs [18/Jan/2019:16:20:59][39532.7fbeeffff700][-tcl-nsthread:32-] Notice: update interpreter to epoch 1, trace none, time 0.007383 secs ns_thread_crash.test [18/Jan/2019:16:20:59][39532.7fbf0d7fa700][-tcl-nsthread:18-] Notice: update interpreter to epoch 1, trace none, time 0.012272 secs [18/Jan/2019:16:20:59][39532.7fbef77fe700][-tcl-nsthread:27-] Notice: update interpreter to epoch 1, trace none, time 0.012821 secs [18/Jan/2019:16:20:59][39532.7fbf01ffb700][-tcl-nsthread:23-] Notice: update interpreter to epoch 1, trace none, time 0.016003 secs [18/Jan/2019:16:20:59][39532.7fbef5ffb700][-tcl-nsthread:30-] Notice: update interpreter to epoch 1, trace none, time 0.020877 secs [18/Jan/2019:16:20:59][39532.7fbef6ffd700][-tcl-nsthread:28-] Notice: update interpreter to epoch 1, trace none, time 0.023169 secs [18/Jan/2019:16:20:59][39532.7fbef4ff9700][-tcl-nsthread:33-] Notice: update interpreter to epoch 1, trace none, time 0.024151 secs [18/Jan/2019:16:20:59][39532.7fbf00ff9700][-tcl-nsthread:25-] Notice: update interpreter to epoch 1, trace none, time 0.025090 secs [18/Jan/2019:16:20:59][39532.7fbee77fe700][-tcl-nsthread:41-] Notice: update interpreter to epoch 1, trace none, time 0.026476 secs [18/Jan/2019:16:20:59][39532.7fbeedffb700][-tcl-nsthread:37-] Notice: update interpreter to epoch 1, trace none, time 0.023156 secs [18/Jan/2019:16:20:59][39532.7fbe47fff700][-tcl-nsthread:53-] Notice: update interpreter to epoch 1, trace none, time 0.026740 secs [18/Jan/2019:16:20:59][39532.7fbeed7fa700][-tcl-nsthread:38-] Notice: update interpreter to epoch 1, trace none, time 0.026814 secs [18/Jan/2019:16:20:59][39532.7fbe6effd700][-tcl-nsthread:49-] Notice: update interpreter to epoch 1, trace none, time 0.017782 secs [18/Jan/2019:16:20:59][39532.7fbeee7fc700][-tcl-nsthread:36-] Notice: update interpreter to epoch 1, trace none, time 0.023086 secs [18/Jan/2019:16:20:59][39532.7fbe4cff9700][-tcl-nsthread:61-] Notice: update interpreter to epoch 1, trace none, time 0.020051 secs [18/Jan/2019:16:20:59][39532.7fbe6e7fc700][-tcl-nsthread:50-] Notice: update interpreter to epoch 1, trace none, time 0.022990 secs [18/Jan/2019:16:20:59][39532.7fbd6d7fa700][-tcl-nsthread:108-] Notice: update interpreter to epoch 1, trace none, time 0.019330 secs [18/Jan/2019:16:20:59][39532.7fbe4ffff700][-tcl-nsthread:55-] Notice: update interpreter to epoch 1, trace none, time 0.023066 secs [18/Jan/2019:16:20:59][39532.7fbe6f7fe700][-tcl-nsthread:47-] Notice: update interpreter to epoch 1, trace none, time 0.023293 secs [18/Jan/2019:16:20:59][39532.7fbee5ffb700][-tcl-nsthread:44-] Notice: update interpreter to epoch 1, trace none, time 0.023232 secs [18/Jan/2019:16:20:59][39532.7fbeecff9700][-tcl-nsthread:39-] Notice: update interpreter to epoch 1, trace none, time 0.023742 secs [18/Jan/2019:16:20:59][39532.7fbe4effd700][-tcl-nsthread:57-] Notice: update interpreter to epoch 1, trace none, time 0.013756 secs [18/Jan/2019:16:20:59][39532.7fbe457fa700][-tcl-nsthread:66-] Notice: update interpreter to epoch 1, trace none, time 0.024043 secs [18/Jan/2019:16:20:59][39532.7fbf027fc700][-tcl-nsthread:22-] Notice: update interpreter to epoch 1, trace none, time 0.028326 secs [18/Jan/2019:16:20:59][39532.7fbef57fa700][-tcl-nsthread:31-] Notice: update interpreter to epoch 1, trace none, time 0.028176 secs [18/Jan/2019:16:20:59][39532.7fbee6ffd700][-tcl-nsthread:42-] Notice: update interpreter to epoch 1, trace none, time 0.024272 secs [18/Jan/2019:16:20:59][39532.7fbe6ffff700][-tcl-nsthread:48-] Notice: update interpreter to epoch 1, trace none, time 0.024576 secs [18/Jan/2019:16:20:59][39532.7fbe46ffd700][-tcl-nsthread:63-] Notice: update interpreter to epoch 1, trace none, time 0.020564 secs [18/Jan/2019:16:20:59][39532.7fbee67fc700][-tcl-nsthread:43-] Notice: update interpreter to epoch 1, trace none, time 0.024651 secs [18/Jan/2019:16:20:59][39532.7fbe4f7fe700][-tcl-nsthread:56-] Notice: update interpreter to epoch 1, trace none, time 0.021585 secs [18/Jan/2019:16:20:59][39532.7fbef7fff700][-tcl-nsthread:26-] Notice: update interpreter to epoch 1, trace none, time 0.021995 secs [18/Jan/2019:16:20:59][39532.7fbe467fc700][-tcl-nsthread:64-] Notice: update interpreter to epoch 1, trace none, time 0.025093 secs [18/Jan/2019:16:20:59][39532.7fbdf4ff9700][-tcl-nsthread:81-] Notice: update interpreter to epoch 1, trace none, time 0.025186 secs [18/Jan/2019:16:20:59][39532.7fbe6d7fa700][-tcl-nsthread:52-] Notice: update interpreter to epoch 1, trace none, time 0.021191 secs [18/Jan/2019:16:20:59][39532.7fbd91ffb700][-tcl-nsthread:100-] Notice: update interpreter to epoch 1, trace none, time 0.029523 secs [18/Jan/2019:16:20:59][39532.7fbe4e7fc700][-tcl-nsthread:58-] Notice: update interpreter to epoch 1, trace none, time 0.025863 secs [18/Jan/2019:16:20:59][39532.7fbe0dffb700][-tcl-nsthread:72-] Notice: update interpreter to epoch 1, trace none, time 0.026068 secs [18/Jan/2019:16:20:59][39532.7fbef67fc700][-tcl-nsthread:29-] Notice: update interpreter to epoch 1, trace none, time 0.024233 secs [18/Jan/2019:16:20:59][39532.7fbe0e7fc700][-tcl-nsthread:71-] Notice: update interpreter to epoch 1, trace none, time 0.022776 secs [18/Jan/2019:16:20:59][39532.7fbee4ff9700][-tcl-nsthread:46-] Notice: update interpreter to epoch 1, trace none, time 0.027088 secs [18/Jan/2019:16:20:59][39532.7fbe0ffff700][-tcl-nsthread:68-] Notice: update interpreter to epoch 1, trace none, time 0.020726 secs [18/Jan/2019:16:20:59][39532.7fbe0f7fe700][-tcl-nsthread:69-] Notice: update interpreter to epoch 1, trace none, time 0.031283 secs [18/Jan/2019:16:20:59][39532.7fbe45ffb700][-tcl-nsthread:65-] Notice: update interpreter to epoch 1, trace none, time 0.021707 secs [18/Jan/2019:16:20:59][39532.7fbe477fe700][-tcl-nsthread:62-] Notice: update interpreter to epoch 1, trace none, time 0.024253 secs [18/Jan/2019:16:20:59][39532.7fbe44ff9700][-tcl-nsthread:67-] Notice: update interpreter to epoch 1, trace none, time 0.027991 secs [18/Jan/2019:16:20:59][39532.7fbeef7fe700][-tcl-nsthread:34-] Notice: update interpreter to epoch 1, trace none, time 0.023104 secs [18/Jan/2019:16:20:59][39532.7fbeeeffd700][-tcl-nsthread:35-] Notice: update interpreter to epoch 1, trace none, time 0.032771 secs [18/Jan/2019:16:20:59][39532.7fbe6dffb700][-tcl-nsthread:51-] Notice: update interpreter to epoch 1, trace none, time 0.026374 secs [18/Jan/2019:16:20:59][39532.7fbe6cff9700][-tcl-nsthread:54-] Notice: update interpreter to epoch 1, trace none, time 0.029016 secs [18/Jan/2019:16:20:59][39532.7fbd93fff700][-tcl-nsthread:96-] Notice: update interpreter to epoch 1, trace none, time 0.025189 secs [18/Jan/2019:16:20:59][39532.7fbe4dffb700][-tcl-nsthread:59-] Notice: update interpreter to epoch 1, trace none, time 0.030203 secs [18/Jan/2019:16:20:59][39532.7fbe4d7fa700][-tcl-nsthread:60-] Notice: update interpreter to epoch 1, trace none, time 0.005143 secs [18/Jan/2019:16:20:59][39532.7fbd90ff9700][-tcl-nsthread:102-] Notice: update interpreter to epoch 1, trace none, time 0.005176 secs [18/Jan/2019:16:20:59][39532.7fbda9ffb700][-tcl-nsthread:93-] Notice: update interpreter to epoch 1, trace none, time 0.005295 secs [18/Jan/2019:16:20:59][39532.7fbdf6ffd700][-tcl-nsthread:77-] Notice: update interpreter to epoch 1, trace none, time 0.009818 secs [18/Jan/2019:16:20:59][39532.7fbe0d7fa700][-tcl-nsthread:73-] Notice: update interpreter to epoch 1, trace none, time 0.010373 secs [18/Jan/2019:16:20:59][39532.7fbdf67fc700][-tcl-nsthread:78-] Notice: update interpreter to epoch 1, trace none, time 0.010609 secs [18/Jan/2019:16:20:59][39532.7fbd917fa700][-tcl-nsthread:101-] Notice: update interpreter to epoch 1, trace none, time 0.010352 secs [18/Jan/2019:16:20:59][39532.7fbd6effd700][-tcl-nsthread:105-] Notice: update interpreter to epoch 1, trace none, time 0.010353 secs [18/Jan/2019:16:20:59][39532.7fbd6dffb700][-tcl-nsthread:107-] Notice: update interpreter to epoch 1, trace none, time 0.010644 secs [18/Jan/2019:16:20:59][39532.7fbd6e7fc700][-tcl-nsthread:106-] Notice: update interpreter to epoch 1, trace none, time 0.010292 secs [18/Jan/2019:16:20:59][39532.7fbd937fe700][-tcl-nsthread:97-] Notice: update interpreter to epoch 1, trace none, time 0.010944 secs [18/Jan/2019:16:20:59][39532.7fbdcbfff700][-tcl-nsthread:82-] Notice: update interpreter to epoch 1, trace none, time 0.009592 secs [18/Jan/2019:16:20:59][39532.7fbdf77fe700][-tcl-nsthread:76-] Notice: update interpreter to epoch 1, trace none, time 0.010428 secs [18/Jan/2019:16:20:59][39532.7fbee57fa700][-tcl-nsthread:45-] Notice: update interpreter to epoch 1, trace none, time 0.010869 secs [18/Jan/2019:16:20:59][39532.7fbdc9ffb700][-tcl-nsthread:86-] Notice: update interpreter to epoch 1, trace none, time 0.010357 secs [18/Jan/2019:16:20:59][39532.7fbd6cff9700][-tcl-nsthread:109-] Notice: update interpreter to epoch 1, trace none, time 0.011711 secs [18/Jan/2019:16:20:59][39532.7fbe0cff9700][-tcl-nsthread:74-] Notice: update interpreter to epoch 1, trace none, time 0.011761 secs [18/Jan/2019:16:20:59][39532.7fbdf5ffb700][-tcl-nsthread:79-] Notice: update interpreter to epoch 1, trace none, time 0.011253 secs [18/Jan/2019:16:20:59][39532.7fbdcaffd700][-tcl-nsthread:84-] Notice: update interpreter to epoch 1, trace none, time 0.010542 secs [18/Jan/2019:16:20:59][39532.7fbee7fff700][-tcl-nsthread:40-] Notice: update interpreter to epoch 1, trace none, time 0.010682 secs [18/Jan/2019:16:20:59][39532.7fbdaa7fc700][-tcl-nsthread:92-] Notice: update interpreter to epoch 1, trace none, time 0.010799 secs [18/Jan/2019:16:20:59][39532.7fbdca7fc700][-tcl-nsthread:85-] Notice: update interpreter to epoch 1, trace none, time 0.010868 secs [18/Jan/2019:16:20:59][39532.7fbda97fa700][-tcl-nsthread:94-] Notice: update interpreter to epoch 1, trace none, time 0.010882 secs [18/Jan/2019:16:20:59][39532.7fbdf7fff700][-tcl-nsthread:75-] Notice: update interpreter to epoch 1, trace none, time 0.011002 secs [18/Jan/2019:16:20:59][39532.7fbdf57fa700][-tcl-nsthread:80-] Notice: update interpreter to epoch 1, trace none, time 0.012649 secs [18/Jan/2019:16:20:59][39532.7fbda8ff9700][-tcl-nsthread:95-] Notice: update interpreter to epoch 1, trace none, time 0.011124 secs [18/Jan/2019:16:20:59][39532.7fbdc8ff9700][-tcl-nsthread:88-] Notice: update interpreter to epoch 1, trace none, time 0.011215 secs [18/Jan/2019:16:20:59][39532.7fbdabfff700][-tcl-nsthread:89-] Notice: update interpreter to epoch 1, trace none, time 0.011203 secs [18/Jan/2019:16:20:59][39532.7fbd92ffd700][-tcl-nsthread:98-] Notice: update interpreter to epoch 1, trace none, time 0.011213 secs [18/Jan/2019:16:20:59][39532.7fbd927fc700][-tcl-nsthread:99-] Notice: update interpreter to epoch 1, trace none, time 0.011242 secs [18/Jan/2019:16:20:59][39532.7fbe0effd700][-tcl-nsthread:70-] Notice: update interpreter to epoch 1, trace none, time 0.011226 secs [18/Jan/2019:16:20:59][39532.7fbdab7fe700][-tcl-nsthread:91-] Notice: update interpreter to epoch 1, trace none, time 0.011247 secs [18/Jan/2019:16:20:59][39532.7fbdcb7fe700][-tcl-nsthread:83-] Notice: update interpreter to epoch 1, trace none, time 0.011358 secs [18/Jan/2019:16:20:59][39532.7fbd6f7fe700][-tcl-nsthread:104-] Notice: update interpreter to epoch 1, trace none, time 0.006546 secs [18/Jan/2019:16:20:59][39532.7fbdaaffd700][-tcl-nsthread:90-] Notice: update interpreter to epoch 1, trace none, time 0.011693 secs [18/Jan/2019:16:20:59][39532.7fbdc97fa700][-tcl-nsthread:87-] Notice: update interpreter to epoch 1, trace none, time 0.012642 secs [18/Jan/2019:16:20:59][39532.7fbd6ffff700][-tcl-nsthread:103-] Notice: update interpreter to epoch 1, trace none, time 0.013500 secs [18/Jan/2019:16:20:59][39532.7fbd6f7fe700][-tcl-nsthread:110-] Notice: update interpreter to epoch 1, trace none, time 0.003890 secs ns_urlencode.test ns_urlspace.test ns_uuencode.test ns_writer.test nsdb.test progress.test tclconnio.test [18/Jan/2019:16:20:59][39532.7fbf669eb700][-conn:test:0:294-] Notice: 'ns_connsendfp file33 5 ' is deprecated. Use 'ns_writefp fileid ?nbytes?' instead. tclresp.test [18/Jan/2019:16:21:04][39532.7fbf277fe700][-ns_job_0-] Notice: update interpreter to epoch 2, trace deallocate, time 0.004061 secs [18/Jan/2019:16:21:04][39532.7fbf669eb700][-conn:test:0:323-] Notice: update interpreter to epoch 2, trace allocate, time 0.004045 secs [18/Jan/2019:16:21:04][39532.7fbdab7fe700][-ns_job_1-] Notice: Starting thread: -ns_job_1- [18/Jan/2019:16:21:04][39532.7fbf277fe700][-ns_job_0-] Notice: update interpreter to epoch 3, trace deallocate, time 0.003152 secs [18/Jan/2019:16:21:04][39532.7fbf277fe700][-ns_job_0-] Notice: update interpreter to epoch 4, trace deallocate, time 0.003147 secs [18/Jan/2019:16:21:04][39532.7fbd6f7fe700][-ns_job_2-] Notice: Starting thread: -ns_job_2- [18/Jan/2019:16:21:04][39532.7fbd6ffff700][-ns_job_3-] Notice: Starting thread: -ns_job_3- [18/Jan/2019:16:21:04][39532.7fbf277fe700][-ns_job_0-] Notice: update interpreter to epoch 5, trace deallocate, time 0.003196 secs [18/Jan/2019:16:21:04][39532.7fbf277fe700][-ns_job_0-] Notice: update interpreter to epoch 6, trace deallocate, time 0.003148 secs [18/Jan/2019:16:21:04][39532.7fbf669eb700][-conn:test:0:328-] Notice: update interpreter to epoch 6, trace allocate, time 0.003179 secs [18/Jan/2019:16:21:04][39532.7fbdab7fe700][-ns_job_1-] Notice: update interpreter to epoch 6, trace none, time 0.004532 secs [18/Jan/2019:16:21:04][39532.7fbdab7fe700][-ns_job_1-] Notice: update interpreter to epoch 7, trace deallocate, time 0.004001 secs [18/Jan/2019:16:21:09][39532.7fbf669eb700][-conn:test:0:345-] Notice: update interpreter to epoch 7, trace allocate, time 0.003748 secs timeout.test url2file.test Tests ended at Fri Jan 18 16:21:09 EST 2019 all.tcl: Total 1319 Passed 1311 Skipped 8 Failed 0 Sourced 66 Test Files. Number of tests skipped for each constraint: 2 knownBug 1 notDarwin 4 nsf 1 stress [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: nsmain: NaviServer/4.99.17 (fd186ea6d7d2+ default tip) stopping [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: [driver:nssock:0]: stopping [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: server [test]: stopping [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: server [testvhost]: stopping [18/Jan/2019:16:21:09][39532.7fbf649e7700][-driver:nssock:0-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: server [testvhost2]: stopping [18/Jan/2019:16:21:09][39532.7fbf669eb700][-conn:test:0:352-] Notice: exiting: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf659e9700][-conn:testvhost:0:9-] Notice: exiting: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf651e8700][-conn:testvhost2:0:8-] Notice: exiting: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf661ea700][-conn:test:1:197-] Notice: exiting: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf671ec700][-conn:test:emergency:0:0-] Notice: exiting: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: server [test]: connection threads stopped [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: server [testvhost]: connection threads stopped [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: server [testvhost2]: connection threads stopped [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: driver: stopping writer and spooler threads [18/Jan/2019:16:21:09][39532.7fbf4a7fc700][-writer2-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf49ffb700][-writer1-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf497fa700][-writer0-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf4bfff700][-spooler2-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf4b7fe700][-spooler1-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf4affd700][-spooler0-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: sched: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf67fff700][-sched-] Notice: sched: shutdown started [18/Jan/2019:16:21:09][39532.7fbf67fff700][-sched-] Notice: sched: waiting for 1/1 event threads... [18/Jan/2019:16:21:09][39532.7fbf48ff9700][task:tclhttp] Notice: shutdown pending [18/Jan/2019:16:21:09][39532.7fbf48ff9700][task:tclhttp] Notice: shutdown complete [18/Jan/2019:16:21:09][39532.7fbd6f7fe700][-ns_job_2-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf25ffb700][-sched:idle0-] Notice: exiting, 0 threads, 0 idle [18/Jan/2019:16:21:09][39532.7fbf26ffd700][-socks-] Notice: socks: shutdown pending [18/Jan/2019:16:21:09][39532.7fbd6ffff700][-ns_job_3-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf67fff700][-sched-] Notice: sched: shutdown complete [18/Jan/2019:16:21:09][39532.7fbf26ffd700][-socks-] Notice: socks: shutdown complete [18/Jan/2019:16:21:09][39532.7fbf277fe700][-ns_job_0-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbdab7fe700][-ns_job_1-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: [driver:nssock:0]: stopped [18/Jan/2019:16:21:09][39532.7fbf4affd700][-shutdown-] Notice: update interpreter to epoch 7, trace none, time 0.003793 secs [18/Jan/2019:16:21:09][39532.7fbf4affd700][-shutdown-] Notice: nslog: closed '/net/pinky/home/local-16.04/src/web/ns-head-pub/naviserver/tests/testserver/access.log' [18/Jan/2019:16:21:09][39532.7fbf4affd700][-shutdown-] Notice: update interpreter to epoch 1, trace none, time 0.003658 secs [18/Jan/2019:16:21:09][39532.7fbf4affd700][-shutdown-] Notice: update interpreter to epoch 1, trace none, time 0.003541 secs [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: nsproxy: shutdown started [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: nsproxy: shutdown complete [18/Jan/2019:16:21:09][39532.7fbf267fc700][-nsproxy:reap-] Notice: exiting [18/Jan/2019:16:21:09][39532.7fbf701ec700][-main-] Notice: nsmain: NaviServer/4.99.17 (fd186ea6d7d2+ default tip) exiting
_______________________________________________ naviserver-devel mailing list naviserver-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/naviserver-devel