naviserver-devel — Developer discussion

[naviserver-devel] [ns_getform] doesn't get form-data fields

[Iuri de A. S. <iu...@iu...>]

Hello there,

Reading [ns_getform] documentation, I noticed it supports multipart/form-data
https://naviserver.sourceforge.io/n/naviserver/files/ns_getform.html <https://naviserver.sourceforge.io/n/naviserver/files/ns_getform.html>

However, when I run the chunk bellow, it shows no form, neither fields and values at all, in the GET request.  

I’ve written [ns_getcontent …] right bellow the chunk, confirming that the body of the request has content within it, plus in the proper format (i.e. multipart/form-data). 

Furthermore, if I switch the request to application/x-www-form-urlencoded the chunk works just fine and form fields are properly assigned. Thus, I’m lost!

Could it be that Postman uses a different format for form-data? (Thus, it isn’t supported by ns_getform.)

Logs are bellow.

Best wishes.
I


  set myform [ns_getform]
    if {[string equal "" $myform]} {
        ns_log Notice "No Form was submited"
    } else {
        ns_log Notice "FORM"
        ns_set print $myform
        for {set i 0} {$i < [ns_set size $myform]} {incr i} {
            set varname [ns_set key $myform $i]
            set varvalue [ns_set value $myform $i]

            ns_log Notice " $varname - $varvalue"
        }
    }

    ns_log Notice "BODY \n  [ns_getcontent -as_file false]”





[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: HEADER 
 t0
[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: HEADERS 11
[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: Host iurix.com X-Real-IP 179.199.203.207 Connection close Content-Length 386 authorization {Bearer eyJhbGciOiAiSFMyNTYiLCAidHlwIjogIkpXVCJ9.eydzdWInOiAnNTk0MycsICdpYXQnOiAxNTkzODI2NjQ0fQ==.20f471933ae0a9c58d525f4ab0c1eef7adab03f17c3bbe18a00cf30a1ef06948} User-Agent PostmanRuntime/7.25.0 Accept */* Cache-Control no-cache Postman-Token 93e1f2b8-b680-470f-be60-52a25c93db0a Content-Type {multipart/form-data; boundary=--------------------------973675580213918217977892} Cookie ad_session_id=\"35550042%2c0%2c0%2c1593831987%20{947%201593833187%20876F0016C8883111AC63B5C6B6D964D76ED2D1DF}\"
[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: FORM
[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: BODY 
  ----------------------------973675580213918217977892
Content-Disposition: form-data; name="cTree"

featured
----------------------------973675580213918217977892
Content-Disposition: form-data; name="cTreeName"

t
----------------------------973675580213918217977892
Content-Disposition: form-data; name="cTreeIcon"

t
----------------------------973675580213918217977892--

[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: TREE 
[04/Jul/2020:00:07:19][8773.7efbf2d6e700][-conn:iurix:1:1031-] Notice: cTree 

Re: [naviserver-devel] using rwlocks for nsv variables

[Zoran V. <zv...@ar...>]

On Wed, 1 Jul 2020 11:49:01 +0200
Gustaf Neumann <ne...@wu...> wrote:

> There are already rwlocks in NaviServer since ages, used e.g. for epoch 
> management, ADP tags, permissions. The current version uses as well 
> rwlocks for nsv variables (most user visible part) and also for URLspace 
> and connchan handles. For URLspace, the write ratio is in the very low 
> per mille range (clear advantage for rwlocks), for connchan handles, it 
> is already better use rwlocks for channels with a single read operation, 
> and the benefit becomes larger with more channel interactions. This is 
> the current state - some parts still under evaluation. More details will 
> be in the summaries before the releases.

I do not believe it is the optimal decision to put rwlocks
(and thus favourize readers) at NSV, which is usage-pattern agnostic.
You do not really know who/how will use shared arrays and forcing the
reader/writer locks might be a drawback instead of a benefit in some cases.
For usage-patterns that are predictable (one knows roughly what kind of
access the data structures will encounter over time) one can then choose
what is the best. 
Ideally, one would be able to select locking type on per-array basis, 
but that might be too cumbersome to program. So a compile-switch, which
may not be the best, is the simplest option.
Next would be a config option that would for example take a glob expression
and assign locking type on nsv name-glob, putting desigated locking on all
arrays that match given glob.

> 
> Another interesting candidate is nscache, but the situation is more 
> complex: although - by construct - caches experience much more read than 
> write operations, the usage for rwlocks there would be rather complex, 
> since one has to know before the lock, whether an operation will be read 
> or write. But the lock guarding the main interface (nscache_eval) is 
> used for reading and writing, so it would require always a write lock. 
> So, due to my workload, i have no final opinion on the usefulness of 
> rwlocks in this context.

Yes, the nscache_eval is problematc. Otherwise I'd say that nscache per-design 
would be a good candidate for rwlocks, unlike NSVs. One uses the cache mainly
for things that are seldomly/expensively setup but often read.

> 
> For the people not having an eye on the source code changes: One 
> important enabler/driver for these changes is the switch from the 
> "manual" rwlock implementation we had before towards using the rwlock 
> implementation from pthreads (we still use the "manual" rwlock 
> implementation for NaviServer variants compiled without pthreads, such 
> as the usual windows compilations).
> 
> The newer implementations of pthreads in the Linux world benefit from 
> the work on futex variants (fast userspace mutex), which exist in new 
> Linux versions in many variants (wake-wait futex, priority inversion 
> futex, optimistic spinning futex formerly called throughout optimized 
> futex). As the results show, there is similar work going on e.g. on macOS.
> 

Bottom line: I think it is more opportune to leave NSV locks as-is
and add compile-option to use rwlocks if one's metric justify that.
Or, add a more complex (and more versatile) config option using 
nsv name-globs.

Personally... I am relaxed at this point since we do not use NSV's
directly and extensively (we have our own private object-based interface).
But for the sake of other (non-ACS users out there) I would trade
stability/predictability over (possible) performance benefits.

Re: [naviserver-devel] using rwlocks for nsv variables

[Gustaf N. <ne...@wu...>]

On 01.07.20 10:53, Zoran Vasiljevic wrote:
> I understand you added rwlocks elsewhere as well? 

There are already rwlocks in NaviServer since ages, used e.g. for epoch 
management, ADP tags, permissions. The current version uses as well 
rwlocks for nsv variables (most user visible part) and also for URLspace 
and connchan handles. For URLspace, the write ratio is in the very low 
per mille range (clear advantage for rwlocks), for connchan handles, it 
is already better use rwlocks for channels with a single read operation, 
and the benefit becomes larger with more channel interactions. This is 
the current state - some parts still under evaluation. More details will 
be in the summaries before the releases.

Another interesting candidate is nscache, but the situation is more 
complex: although - by construct - caches experience much more read than 
write operations, the usage for rwlocks there would be rather complex, 
since one has to know before the lock, whether an operation will be read 
or write. But the lock guarding the main interface (nscache_eval) is 
used for reading and writing, so it would require always a write lock. 
So, due to my workload, i have no final opinion on the usefulness of 
rwlocks in this context.

For the people not having an eye on the source code changes: One 
important enabler/driver for these changes is the switch from the 
"manual" rwlock implementation we had before towards using the rwlock 
implementation from pthreads (we still use the "manual" rwlock 
implementation for NaviServer variants compiled without pthreads, such 
as the usual windows compilations).

The newer implementations of pthreads in the Linux world benefit from 
the work on futex variants (fast userspace mutex), which exist in new 
Linux versions in many variants (wake-wait futex, priority inversion 
futex, optimistic spinning futex formerly called throughout optimized 
futex). As the results show, there is similar work going on e.g. on macOS.

all the best

-g

Re: [naviserver-devel] using rwlocks for nsv variables

[Zoran V. <zv...@ar...>]

On Wed, 1 Jul 2020 10:46:57 +0200
Gustaf Neumann <ne...@wu...> wrote:

> Right now, the flag is set in the sources (nsthread/rwlock.c).
> For the release, a more user-friendly configure flag 
> (--disable-nsvrwlock) would be appropriate.

I understand you added rwlocks elsewhere as well?

Re: [naviserver-devel] using rwlocks for nsv variables

[Gustaf N. <ne...@wu...>]

On 01.07.20 02:03, Maksym Zinchenko wrote:
> Hello,first of all thank you for great work.
> If I understood correctly on compile time we need to provide a 
> configuration option to compile NaviServer with mutex or rwlocks, so 
> option b sounds good and more than enough.

Right now, the flag is set in the sources (nsthread/rwlock.c).
For the release, a more user-friendly configure flag 
(--disable-nsvrwlock) would be appropriate.

> Default is rwlocks.
yes.

all the best

-g

Re: [naviserver-devel] using rwlocks for nsv variables

[Maksym Z. <siq...@gm...>]

Hello,first of all thank you for great work.
If I understood correctly on compile time we need to provide a
configuration option to compile NaviServer with mutex or rwlocks, so option
b sounds good and more than enough.
Default is rwlocks.
Correct me if I'm wrong.


On Tue, Jun 30, 2020 at 7:56 PM Zoran Vasiljevic <zv...@ar...> wrote:

> Excellent work as always!
> I'd go for the b. option.
>
> Am 30.06.2020 um 22:39 schrieb Gustaf Neumann <ne...@wu...>:
>
> 
>
> Dear all,
>
> some of you might have noticed the recent changes in the NaviServer
> repository concerning rwlocks. rwlocks support multiple concurrent readers
> and behave like mutex locks in the case of writers. rwlocks can improve
> concurrency especially in applications with many parallel threads and high
> loads, but these are only better in cases, where there are more readers
> than writers.
>
> The current version of NaviServer uses rwlocks e.g. for URLspace and for
> nsv variables. Here are some statistics of these locks collected on a
> real-world application (openacs.org):
>
> Name			Locks	Busy	Read	Write	Write %
> nsv:7:openacs.org	33.14M	4	33.13M	8.41K	0.03%
> nsv:6:openacs.org	16.85M	249	16.4M	453.88K	2.69%
> nsv:3:openacs.org	15.09M	3	15.04M	46.88K	0.31%
> nsv:2:openacs.org	10.26M	5	10.23M	38.17K	0.37%
> nsv:5:openacs.org	9.98M	0	9.98M	1.57K	0.02%
> ns:rw:urlspace:4	4.45M	0	4.45M	86	0.00%
>
>
> As one can see, the vast majority of operations are read operations, where
> typically less than one percent are write operations. One can see as well
> the very little number of busy operations, where a lock has to be blocked.
> The same site with the same traffic reaches about 2K busy locks for nsv:6
> (instead of 4) and about 3.5K busy locks for nsv:6 (instead of 249) on the
> same number of locks. The improvements on the busy locks are significantly
> higher on sites with more connection threads and more traffic.
>
> However, on some other applications, the write ratio might be different,
> and there might not be always only improvements, as the test below show.
>
> In our little test, we create 20 background threads busily reading and
> writing from nsv variables, while we are measuring of a foreground task
> hammering on the very same nsv variables (with different mixes of
> background tasks and writer percentages).
>
> The first chart shows results under macOS, relative to the same task using
> mutex locks instead of rwlocks:
>
> <dnkmmdiholbgceok.png>
>
> In the first three columns, we see the performance without background
> traffic (i.e. without concurrency). The performance is measured relative to
> the same application using mutex locks (lower numbers are better). We see
> that  without concurrency, the rwlocks lead to better results (runtime
> improvement about 25%). The next three columns show results with 20
> background tasks, just reading busily from the nsv variables. The version
> with rwlocks is faster by a factor of 10 in the best case (just foreground
> and background readers). But as one can see, the performance benefit
> reduces when more write operations are performed. The last three columns
> show the situation, when we have 50% read and write operations in the
> background.
>
> When we consider these values in combination with the statistics of
> openacs.org, we see that we are there essentially in the sweep spot where
> rwlocks shine (with practically no writers).
>
> The situation on Linux is different with less positive results (macOS
> seems to have a very good implementation of POSIX rwlocks). While in the
> best cases, the improvement on Linux is just a factor of 5 better than with
> mutex locks, in the worst cases, the performance is nearly 3 times worse.
>
> <clckkhjfmbfhgjol.png>
>
> One should also notice that these values were achieved with a conservative
> setting of rwlocks, which prevents writer starvation (the results would
> have been better without these).
>
> Since on sites like openacs.org (and even more on our high traffic sites
> of our e-learning environment), we are always in range of the first 5 bars,
> so using rwlocks is a big improvement. The improvement will be even higher
> for situations, where rwlocks are protecting areas where more computing
> intense operations are performed, or when more cores are available, etc.
>
> However, there might be NaviServer applications with nsvs out there, for
> which the change of using rwlocks for nsv variables might lead to a reduced
> performance. So we have in general the following options for the
> forthcoming release:
>
> a) hardwire nsvs to rwlocks
> b) make it a compile-time decision to choose between rwlocks and mutex
> locks for nsvs
> c) provide a configuration variable in the config file to choose between
> rwlocks and mutex locks for nsvs at startup
> d) provide a runtime API for creating nsv arrays with rwlock or mutex
>
> Currently, we have essentially (b) in the repository. (c) seems feasible
> with moderate implementation effort. (d) would be a larger project.
>
> What do you think? My approach would be to leave the code with (b) and
> consider (c) in the future, when necessary ... unless someone convinces me
> that more control is essential now.
>
> -g
>
> PS: Used hardware:
> Linux machine: Intel(R) Xeon(R) Silver 4114 CPU @ 2.20GHz, 10 cores +
> hyperthreading, Fedora release 32.
> macOS machine: 2,4 GHz Intel Core i9, 18.7.0 Darwin Kernel Version 18.7.0:
> Mon Apr 27 20:09:39 PDT 2020; root:xnu-4903.278.35~1/RELEASE_X86_64 x86_64
>
>
> _______________________________________________
> naviserver-devel mailing list
> nav...@li...
> https://lists.sourceforge.net/lists/listinfo/naviserver-devel
>
> _______________________________________________
> naviserver-devel mailing list
> nav...@li...
> https://lists.sourceforge.net/lists/listinfo/naviserver-devel
>

Re: [naviserver-devel] using rwlocks for nsv variables

[Zoran V. <zv...@ar...>]

Excellent work as always!
I'd go for the b. option. 

> Am 30.06.2020 um 22:39 schrieb Gustaf Neumann <ne...@wu...>:
> 
> 
> Dear all,
> 
> some of you might have noticed the recent changes in the NaviServer repository concerning rwlocks. rwlocks support multiple concurrent readers and behave like mutex locks in the case of writers. rwlocks can improve concurrency especially in applications with many parallel threads and high loads, but these are only better in cases, where there are more readers than writers.
> 
> The current version of NaviServer uses rwlocks e.g. for URLspace and for nsv variables. Here are some statistics of these locks collected on a real-world application (openacs.org):
> 
> Name			Locks	Busy	Read	Write	Write %
> nsv:7:openacs.org	33.14M	4	33.13M	8.41K	0.03%
> nsv:6:openacs.org	16.85M	249	16.4M	453.88K	2.69%
> nsv:3:openacs.org	15.09M	3	15.04M	46.88K	0.31%
> nsv:2:openacs.org	10.26M	5	10.23M	38.17K	0.37%
> nsv:5:openacs.org	9.98M	0	9.98M	1.57K	0.02%
> ns:rw:urlspace:4	4.45M	0	4.45M	86	0.00%
> 
> As one can see, the vast majority of operations are read operations, where typically less than one percent are write operations. One can see as well the very little number of busy operations, where a lock has to be blocked. The same site with the same traffic reaches about 2K busy locks for nsv:6 (instead of 4) and about 3.5K busy locks for nsv:6 (instead of 249) on the same number of locks. The improvements on the busy locks are significantly higher on sites with more connection threads and more traffic.
> 
> However, on some other applications, the write ratio might be different, and there might not be always only improvements, as the test below show.
> 
> In our little test, we create 20 background threads busily reading and writing from nsv variables, while we are measuring of a foreground task hammering on the very same nsv variables (with different mixes of background tasks and writer percentages).
> 
> The first chart shows results under macOS, relative to the same task using mutex locks instead of rwlocks:
> 
> <dnkmmdiholbgceok.png>
> 
> In the first three columns, we see the performance without background traffic (i.e. without concurrency). The performance is measured relative to the same application using mutex locks (lower numbers are better). We see that  without concurrency, the rwlocks lead to better results (runtime improvement about 25%). The next three columns show results with 20 background tasks, just reading busily from the nsv variables. The version with rwlocks is faster by a factor of 10 in the best case (just foreground and background readers). But as one can see, the performance benefit reduces when more write operations are performed. The last three columns show the situation, when we have 50% read and write operations in the background.
> 
> When we consider these values in combination with the statistics of openacs.org, we see that we are there essentially in the sweep spot where rwlocks shine (with practically no writers).
> 
> The situation on Linux is different with less positive results (macOS seems to have a very good implementation of POSIX rwlocks). While in the best cases, the improvement on Linux is just a factor of 5 better than with mutex locks, in the worst cases, the performance is nearly 3 times worse.
> 
> <clckkhjfmbfhgjol.png>
> 
> One should also notice that these values were achieved with a conservative setting of rwlocks, which prevents writer starvation (the results would have been better without these).
> 
> Since on sites like openacs.org (and even more on our high traffic sites of our e-learning environment), we are always in range of the first 5 bars, so using rwlocks is a big improvement. The improvement will be even higher for situations, where rwlocks are protecting areas where more computing intense operations are performed, or when more cores are available, etc.
> 
> However, there might be NaviServer applications with nsvs out there, for which the change of using rwlocks for nsv variables might lead to a reduced performance. So we have in general the following options for the forthcoming release:
> 
> a) hardwire nsvs to rwlocks
> b) make it a compile-time decision to choose between rwlocks and mutex locks for nsvs
> c) provide a configuration variable in the config file to choose between rwlocks and mutex locks for nsvs at startup
> d) provide a runtime API for creating nsv arrays with rwlock or mutex
> 
> Currently, we have essentially (b) in the repository. (c) seems feasible with moderate implementation effort. (d) would be a larger project.
> 
> What do you think? My approach would be to leave the code with (b) and consider (c) in the future, when necessary ... unless someone convinces me that more control is essential now.
> 
> -g
> 
> PS: Used hardware:
> Linux machine: Intel(R) Xeon(R) Silver 4114 CPU @ 2.20GHz, 10 cores + hyperthreading, Fedora release 32.
> macOS machine: 2,4 GHz Intel Core i9, 18.7.0 Darwin Kernel Version 18.7.0: Mon Apr 27 20:09:39 PDT 2020; root:xnu-4903.278.35~1/RELEASE_X86_64 x86_64
> 
> 
> 
> _______________________________________________
> naviserver-devel mailing list
> nav...@li...
> https://lists.sourceforge.net/lists/listinfo/naviserver-devel

[naviserver-devel] using rwlocks for nsv variables

[Gustaf N. <ne...@wu...>]

Dear all,

some of you might have noticed the recent changes in the NaviServer 
repository concerning rwlocks. rwlocks support multiple concurrent 
readers and behave like mutex locks in the case of writers. rwlocks can 
improve concurrency especially in applications with many parallel 
threads and high loads, but these are only better in cases, where there 
are more readers than writers.

The current version of NaviServer uses rwlocks e.g. for URLspace and for 
nsv variables. Here are some statistics of these locks collected on a 
real-world application (openacs.org):

Name			Locks	Busy	Read	Write	Write %
nsv:7:openacs.org	33.14M	4	33.13M	8.41K	0.03%
nsv:6:openacs.org	16.85M	249	16.4M	453.88K	2.69%
nsv:3:openacs.org	15.09M	3	15.04M	46.88K	0.31%
nsv:2:openacs.org	10.26M	5	10.23M	38.17K	0.37%
nsv:5:openacs.org	9.98M	0	9.98M	1.57K	0.02%
ns:rw:urlspace:4	4.45M	0	4.45M	86	0.00%

As one can see, the vast majority of operations are read operations, 
where typically less than one percent are write operations. One can see 
as well the very little number of busy operations, where a lock has to 
be blocked. The same site with the same traffic reaches about 2K busy 
locks for nsv:6 (instead of 4) and about 3.5K busy locks for nsv:6 
(instead of 249) on the same number of locks. The improvements on the 
busy locks are significantly higher on sites with more connection 
threads and more traffic.

However, on some other applications, the write ratio might be different, 
and there might not be always only improvements, as the test below show.

In our little test, we create 20 background threads busily reading and 
writing from nsv variables, while we are measuring of a foreground task 
hammering on the very same nsv variables (with different mixes of 
background tasks and writer percentages).

The first chart shows results under macOS, relative to the same task 
using mutex locks instead of rwlocks:

In the first three columns, we see the performance without background 
traffic (i.e. without concurrency). The performance is measured relative 
to the same application using mutex locks (lower numbers are better). We 
see that  without concurrency, the rwlocks lead to better results 
(runtime improvement about 25%). The next three columns show results 
with 20 background tasks, just reading busily from the nsv variables. 
The version with rwlocks is faster by a factor of 10 in the best case 
(just foreground and background readers). But as one can see, the 
performance benefit reduces when more write operations are performed. 
The last three columns show the situation, when we have 50% read and 
write operations in the background.

When we consider these values in combination with the statistics of 
openacs.org, we see that we are there essentially in the sweep spot 
where rwlocks shine (with practically no writers).

The situation on Linux is different with less positive results (macOS 
seems to have a very good implementation of POSIX rwlocks). While in the 
best cases, the improvement on Linux is just a factor of 5 better than 
with mutex locks, in the worst cases, the performance is nearly 3 times 
worse.

One should also notice that these values were achieved with a 
conservative setting of rwlocks, which prevents writer starvation (the 
results would have been better without these).

Since on sites like openacs.org (and even more on our high traffic sites 
of our e-learning environment), we are always in range of the first 5 
bars, so using rwlocks is a big improvement. The improvement will be 
even higher for situations, where rwlocks are protecting areas where 
more computing intense operations are performed, or when more cores are 
available, etc.

However, there might be NaviServer applications with nsvs out there, for 
which the change of using rwlocks for nsv variables might lead to a 
reduced performance. So we have in general the following options for the 
forthcoming release:

a) hardwire nsvs to rwlocks
b) make it a compile-time decision to choose between rwlocks and mutex 
locks for nsvs
c) provide a configuration variable in the config file to choose between 
rwlocks and mutex locks for nsvs at startup
d) provide a runtime API for creating nsv arrays with rwlock or mutex

Currently, we have essentially (b) in the repository. (c) seems feasible 
with moderate implementation effort. (d) would be a larger project.

What do you think? My approach would be to leave the code with (b) and 
consider (c) in the future, when necessary ... unless someone convinces 
me that more control is essential now.

-g

PS: Used hardware:
Linux machine: Intel(R) Xeon(R) Silver 4114 CPU @ 2.20GHz, 10 cores + 
hyperthreading, Fedora release 32.
macOS machine: 2,4 GHz Intel Core i9, 18.7.0 Darwin Kernel Version 
18.7.0: Mon Apr 27 20:09:39 PDT 2020; 
root:xnu-4903.278.35~1/RELEASE_X86_64 x86_64

Re: [naviserver-devel] Registering/Allowing request method HTTP PUT

[Gustaf N. <ne...@wu...>]

The "unfriendly" behavior of redirects (actually redirects for methods 
other then GET used e.g. for customized error pages) should be fixed by 
the following change in the NaviServer repository:

https://bitbucket.org/naviserver/naviserver/commits/0072469bedcd7a4640af9d9f215b1573504e385f

See as well the test cases

all the best

-gn

On 25.05.20 20:27, Iuri de Araujo Sampaio wrote:
>
> and regarding “unfriendly” behavior
>>
>> The last request leads to a "method not allowed" result, since a PUT 
>> on /shared
>> is indeed not allowed. This is the "unfriendly" behavior part. 
>> Clearly, in
>> the file-not-found case, the HTTP method should be changed to GET
>>
> I’ll handle it, using NGINX.
>
> Thanks!
>

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Sun, Jun 14, 2020 at 02:44:35PM +0200, Gustaf Neumann wrote:

> i fixed two more bugs for win64 (see [1]). The most complex
> case was handling thread results (threads returning string values).

Wow, great news Gustaf, thank you very much.

> @Andrew: are the still show-stoppers for you,
> which have to be fixed urgently?

No, everything for my application is working well now!  I've been
running your 2020-06-07 time_t Ns_Time fix for a week, that completely
fixed the problem with the scheduler thread getting stuck.  I just
recently upgraded to your 06-14 fixes as well.

The other Windows regression test failures don't seem to affect me,
but I'll still put some time into some them if/when I come up with any
better ideas for how to debug them.  And once Ibrahim Tannir gets his
nsproxy fixes ready, I can certainly try them.

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Gustaf N. <ne...@wu...>]

Dear all,

i fixed two more bugs for win64 (see [1]). The most complex
case was handling thread results (threads returning string values).
While pthread_exit() receives a pointer value (64 bit), the native
windows counter part _endthreadex() receives just a 32 bit value
(both, on win32 and win64). Since the received result is used
for setting the result-obj,  the value truncation caused many
bad things to happen. This could never have worked with
win64 before.

Now all the tests of ns_thread.test should work correctly.

@Andrew: are the still show-stoppers for you,
which have to be fixed urgently?

-gn

[1] 
https://bitbucket.org/naviserver/naviserver/commits/9c48894ae8e433aa4dfbe5473e9553f796ec24bd

On 08.06.20 17:46, Gustaf Neumann wrote:
>> No change to the other failing tests, nor to the ones that we're
>> currently skipping with the notWin32 constraint.
>> E.g., test ns_thread-2.6 still triggers this:
>>    Assertion failed: tid != NULL, file tclthread.c, line 238
> i am not surprised, since i have not changed anything around this.

Re: [naviserver-devel] scheduler thread getting stuck

[Gustaf N. <ne...@wu...>]

On 08.06.20 19:39, Andrew Piskorski wrote:
> On Windows there are still a few compiler warnings that look a little
> suspicious (below), but I don't see any good way to fix these.

it is not hard to silence these cases (at least one of these appeared 
multiple times on stackoverflow), but these are not related to the 
errors you have reported.

i hope, the next weekend, i can get a better PC for continuing on this.

-g

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Mon, Jun 08, 2020 at 05:46:54PM +0200, Gustaf Neumann wrote:
> >    Assertion failed: tid != NULL, file tclthread.c, line 238

> You might check whether "ns_thread handle"
> in a classical setup (e.g. in a ds/shell) thows the same exception.

Good idea.  I started up NaviServer with the same test.nscfg config
file, but using the installed binaries instead of the "nmake -f
Makefile.win32 _test" approach.  Then I typed "ns_thread handle" at
the control port prompt.

That threw the exact same exception as before.  Under WinDbg it also
looks the same, inside Ns_ThreadSelf() wPtr appears to be defined, but
threadPtr and wPtr->self are null.

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Windows there are still a few compiler warnings that look a little
suspicious (below), but I don't see any good way to fix these.


cl /W3 /nologo /c /EHsc /MDd /Od /Zi /RTC1 /I "..\include" /I "C:\P\OpenSSL-Win64\include"  /I "C:\P\Tcl-64-8.6\include" /D "_WINDOWS" /D "TCL_THREADS=1"  /D "FD_SETSIZE=128" /D "_MBCS"  /D _CRT_SECURE_NO_WARNINGS /D _CRT_SECURE_NO_DEPRECATE /D "_DEBUG" /c /Foexec.o exec.c
exec.c(154): warning C4312: 'type cast': conversion from 'pid_t' to 'HANDLE' of greater size
exec.c(371): warning C4311: 'type cast': pointer truncation from 'HANDLE' to 'pid_t'

cl /W3 /nologo /c /EHsc /MDd /Od /Zi /RTC1 /I "..\include" /I "C:\P\OpenSSL-Win64\include"  /I "C:\P\Tcl-64-8.6\include" /D "_WINDOWS" /D "TCL_THREADS=1"  /D "FD_SETSIZE=128" /D "_MBCS"  /D _CRT_SECURE_NO_WARNINGS /D _CRT_SECURE_NO_DEPRECATE /D "_DEBUG" /c /Fotls.o tls.c
tls.c(228): warning C4244: 'function': conversion from 'SOCKET' to 'int', possible loss of data
tls.c(376): warning C4244: 'function': conversion from 'SOCKET' to 'int', possible loss of data

cl /W3 /nologo /c /EHsc /MDd /Od /Zi /RTC1 /I "..\include" /I "C:\P\OpenSSL-Win64\include"  /I "C:\P\Tcl-64-8.6\include" /D "_WINDOWS" /D "TCL_THREADS=1"  /D "FD_SETSIZE=128" /D "_MBCS"  /D _CRT_SECURE_NO_WARNINGS /D _CRT_SECURE_NO_DEPRECATE /D "_DEBUG" /c /Fotclcrypto.o tclcrypto.c
tclcrypto.c(592): warning C4090: 'initializing': different 'const' qualifiers
tclcrypto.c(656): warning C4090: 'initializing': different 'const' qualifiers
tclcrypto.c(711): warning C4090: 'initializing': different 'const' qualifiers
tclcrypto.c(822): warning C4090: 'initializing': different 'const' qualifiers
tclcrypto.c(955): warning C4090: 'initializing': different 'const' qualifiers
tclcrypto.c(1011): warning C4090: 'initializing': different 'const' qualifiers
tclcrypto.c(1068): warning C4090: 'initializing': different 'const' qualifiers

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Gustaf N. <ne...@wu...>]

On 08.06.20 16:32, Andrew Piskorski wrote:
> On Mon, Jun 08, 2020 at 12:04:59PM +0200, Gustaf Neumann wrote:
>> So, i have modified the code to use "time_t" for the "sec" member,
>> ... and many of the warnings disappeared.
> That's a big improvement, thank you, Gustaf!  The 22 regression tests
> below used to fail, but now pass!
good news!
> No change to the other failing tests, nor to the ones that we're
> currently skipping with the notWin32 constraint.
> E.g., test ns_thread-2.6 still triggers this:
>    Assertion failed: tid != NULL, file tclthread.c, line 238
i am not surprised, since i have not changed anything around this.
The problem might have to to do with the different way of the
setup for tests. You might check whether "ns_thread handle"
in a classical setup (e.g. in a ds/shell) thows the same exception.

-gn

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Mon, Jun 08, 2020 at 12:04:59PM +0200, Gustaf Neumann wrote:

> So, i have modified the code to use "time_t" for the "sec" member,
> ... and many of the warnings disappeared.

That's a big improvement, thank you, Gustaf!  The 22 regression tests
below used to fail, but now pass!

No change to the other failing tests, nor to the ones that we're
currently skipping with the notWin32 constraint.
E.g., test ns_thread-2.6 still triggers this:
  Assertion failed: tid != NULL, file tclthread.c, line 238


## Gustaf's 2020-06-07 changes fixed these test failures:
==== ns_schedule-2.1 schedule proc: interval FAILED
==== ns_time-1.2ms ns_time incr timeunit float+ms int FAILED
==== ns_time-1.3ms ns_time incr timeunit int+ms int FAILED
==== ns_time-1.3?s ns_time incr timeunit int+ms int FAILED
==== ns_time-1.4-100ms ns_time incr timeunit 100ms int FAILED
==== ns_time-1.4-10ms ns_time incr timeunit 10ms int FAILED
==== ns_time-1.4-1ms ns_time incr timeunit 1ms int FAILED
==== ns_time-1.4-0.1ms ns_time incr timeunit 0.1ms int FAILED
==== ns_time-1.4-0.01ms ns_time incr timeunit 0.01ms int FAILED
==== ns_time-1.4-0.001ms ns_time incr timeunit 0.001ms int FAILED
==== ns_time-format-1.2 ns_time format positive microsecond FAILED
==== ns_time-format-2.1 ns_time format negative second FAILED
==== ns_time-format-2.2 ns_time format negative second with fraction FAILED
==== ns_time-format-2.4 ns_time format negative microsecond FAILED
==== ns_time-format-2.4-0.001ms ns_time format negative microsecond FAILED
==== ns_time-diff-1 ns_time diff simple FAILED
==== ns_time-diff-2 ns_time diff requires adjust FAILED
==== ns_time-diff-3 ns_time diff subtract nothing FAILED
==== ns_time-diff-4 ns_time diff add 1ms FAILED
==== ns_time-diff-5 ns_time diff turn positive to negative FAILED
==== ns_time-diff-6 ns_time diff make negative more negative FAILED
==== ns_time-diff-9 ns_time diff turn negative to positive FAILED

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Gustaf N. <ne...@wu...>]

On 04.06.20 17:26, Gustaf Neumann wrote:
> This sounds indeed related with the original problem.
> The test registers a repeating proc (interval 1s),
> but within in the time-range of 2.5s, it is executed
> only once.
>
> ...
>
> maybe i get on the weekend some access to a win environent.
i could use a windows machine over the weekend, but unfortunately,
this was very limited (windows 7, very small hd).

However, i was able to set everything up to be able to compile
NaviServer with msvc, but i was not able to run the regression tests
(path to long, etc.). When compiling with x64, there were many
warnings concerning the "sec" member in Ns_Time, which is
defined as long. Due to the memory model in windows 64
bit (LLP64) a long is there 32 bit, ... but an ns_time (e.g. the result
of time()) is 64 bit. This value is often supplied to the "sec" member.
So, i have modified the code to use "time_t" for the "sec" member,
... and many of the warnings disappeared.

Most other 64bit OS use LP64 (long is 64 bit), where assigning
time_t to long was not an issue.

This change will not solve all of the issues you are experiencing,
bit it might improve the situation for a few.

Background: The problem with LLP64 and using "long" for
sec is not new, many of the operations on Ns_Time were most
likely never working correctly under win64. But they started to
show up as a problem lately, since the newer code relies
more on this functions working correctly (among other things,
in the scheduler).

Hope that these changes helped a little.

all the best

-gn

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Thu, Jun 04, 2020 at 04:55:10PM -0400, Andrew Piskorski wrote:
> On Thu, Jun 04, 2020 at 05:26:04PM +0200, Gustaf Neumann wrote:

> > Probably "Ns_ThreadSelf(&tid);" does not work under windows (get the
> > id of the current thread). Ns_ThreadSelf() is defined in the OS specific
> > part (winthread.c). The exception is probably coming from
> > test thread-2.3, it looks to me as if the the thread (here the
> > thread running the tests) is not properly initiated under windows.

>   Assertion failed: tid != NULL, file tclthread.c, line 238

For debugging, I turned test ns_thread-2.6 back on, and added an
assertion inside Ns_ThreadSelf(), so that it was basically doing this:

void Ns_ThreadSelf(Ns_Thread *threadPtr) {
   WinThread *wPtr = TlsGetValue(tlskey);
   *threadPtr = (Ns_Thread) wPtr->self;
   assert(NULL != *threadPtr);
}

That got it to break into Microsoft's WinDbg debugger there, rather
than later in NsTclThreadObjCmd().  The global "tlskey" seems to be
initialized, and so does the "wPtr" WinThread pointer.  But the
"wPtr->self" looks like it's NULL, there is no Ns_Thread structure
stored there!

I see the wPtr WinThread allocation code in DllMain().  That seems to
be working fine.

The wPtr->self Ns_Thread stuff gets set up in NsCreateThread() and
ThreadMain(), but I don't really understand understand what that code
is doing.  Is that the place where something is going wrong?

Btw, The tlskey TLS index value looks like it's a 64-bit DWORD
(unsigned integer), not 32-bit.  So I think Nsthreads_LibInit() should
be checking for TLS_OUT_OF_INDEXES, not the 0xFFFFFFFF (decimal
4294967295, the maximum size of a 32-bit DWORD) it's been checking for
since ancient times.  That's probably a small bug, but it's not the
cause of the problems here.


WinDbug output:
--------------------------------------------------
0:001> .frame 7
07 00000000`0062f150 000007fe`ed490aae nsthread!Ns_ThreadSelf+0x89 [Z:\src\web\ns-fork-pub\naviserver\nsthread\winthread.c @ 848]
0:001> dt wPtr
Local var @ 0x62f170 Type WinThread*
0x00000000`004706d0 
   +0x000 nextPtr          : (null) 
   +0x008 wakeupPtr        : (null) 
   +0x010 self             : (null) 
   +0x018 event            : 0x00000000`0000015c Void
   +0x020 condwait         : 0n0
   +0x028 slots            : [100] (null) 
0:001> dt threadPtr
Local var @ 0x62f190 Type Ns_Thread_**
0x00000000`0062f208 
 -> (null) 

0:001> ? tlskey
Evaluate expression: 8791677299988 = 000007fe`f8cd6d14
0:001> .formats tlskey
Evaluate expression:
  Hex:     000007fe`f8cd6d14
  Decimal: 8791677299988
  Octal:   0000000177737063266424
  Binary:  00000000 00000000 00000111 11111110 11111000 11001101 01101101 00010100
  Chars:   ......m.
  Time:    Thu Jan 11 00:12:47.729 1601 (UTC - 4:00)
  Float:   low -3.33323e+034 high 2.86706e-042
  Double:  4.34367e-311
0:001> dt -v tlskey
Got address 000007fef8cd6d14 for symbol
nsthread!tlskey
7

0:001> kb
: Call Site
: ucrtbased!issue_debug_notification+0x45 [minkernel\crts\ucrt\src\appcrt\internal\report_runtime_error.cpp @ 28]
: ucrtbased!__acrt_report_runtime_error+0x13 [minkernel\crts\ucrt\src\appcrt\internal\report_runtime_error.cpp @ 154]
: ucrtbased!abort+0x1d [minkernel\crts\ucrt\src\appcrt\startup\abort.cpp @ 61]
: ucrtbased!common_assert_to_stderr_direct+0xe5 [minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 161]
: ucrtbased!common_assert_to_stderr<wchar_t>+0x27 [minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 179]
: ucrtbased!common_assert<wchar_t>+0x68 [minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 420]
: ucrtbased!_wassert+0x2f [minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 444]
: nsthread!Ns_ThreadSelf+0x89 [Z:\src\web\ns-fork-pub\naviserver\nsthread\winthread.c @ 848]
: libnsd!NsTclThreadObjCmd+0x42e [Z:\src\web\ns-fork-pub\naviserver\nsd\tclthread.c @ 238]
: tcl86t!TclNRRunCallbacks+0x63
: tcl86t!Tcl_EvalEx+0x9dd
: tcl86t!Tcl_FSEvalFileEx+0x223
: tcl86t!Tcl_MainEx+0x4be
: libnsd!CmdThread+0x6e [Z:\src\web\ns-fork-pub\naviserver\nsd\nsmain.c @ 1333]
: nsthread!NsThreadMain+0x77 [Z:\src\web\ns-fork-pub\naviserver\nsthread\thread.c @ 236]
: nsthread!ThreadMain+0x6c [Z:\src\web\ns-fork-pub\naviserver\nsthread\winthread.c @ 880]
: ucrtbased!thread_start<unsigned int (__cdecl*)(void *),1>+0x9c [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 97]
: kernel32!BaseThreadInitThunk+0xd
: ntdll!RtlUserThreadStart+0x1d
--------------------------------------------------

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Thu, Jun 04, 2020 at 04:55:10PM -0400, Andrew Piskorski wrote:

> Yes, with your new change, when running ns_thread.test on Windows I
> now always get this:
> 
>   Assertion failed: tid != NULL, file tclthread.c, line 238

A bunch of different tests seem to trigger that assertion failure.
However, it does seem to be the only thing in the tests that causes
crashes, which is good.  In my latest code here, I used the new
"notWin32" tcltest contstraint to turn off all the tests that tend to
trigger that assertion:

  https://bitbucket.org/apiskors/naviserver/commits/

That let's me run the rest of the regression tests to completion, with
the summary results below.

Is there someplace I should upload or attach the full test output?
It's about 5k lines and 3 megabytes.


Tests ended at Fri Jun 05 13:32:03 EDT 2020
all.tcl:        Total   1569    Passed  1376    Skipped 39      Failed  154
Sourced 70 Test Files.
Files with failing tests: encoding.test http.test http_byteranges.test http_chunked.test http_keep.test ns_adp_compress.test ns_base64.test ns_driver.test ns_hostbyaddr.test ns_httptime.test ns_info.test ns_log.test ns_proxy.test ns_schedule.test ns_time.test ns_urlencode.test tclconnio.test tclresp.test
Number of tests skipped for each constraint:
2       binaryMismatch
5       curl
2       knownBug
1       notDarwin
28      notWin32
1       stress

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Fri, May 15, 2020 at 10:37:15AM +0200, Gustaf Neumann wrote:
> On 15.05.20 09:21, Andrew Piskorski wrote:

> > Previously on Windows I was running NaviServer code from
> > c. 2019-07 and an ancient Microsoft compiler from 2010; the problem
> > did NOT happen then.

> Can you try with the released version 4.99.17 (2018-11-04)
> with your new Windows environment?

It can be tricky to find an old version of the NaviServer code that
builds correctly on Windows.  I did successfully build these two older
points in the code:

  commit c31d3a0c4ef60b79c542cacbdc66c9cb53428faa
  Author: Gustaf Neumann <ne...@wu...>
  Date:   2019-06-18 20:43:41 +0200 Tue
  fix prototype of Ns_SockListenCallback in in ns.h (many thanks to Maurizio Martignano)

  commit 83e8c50a38a6986f3c0468b69e8ef3abd68f926e
  Author: Gustaf Neumann <ne...@wu...>
  Date:   2020-01-17 21:03:31 +0100 Fri
  improve spelling

For each of those, first I did a "git checkout VERSION" to the commit
version number above.  Then I copied the latest makefiles and tests on
top of the old code like so:

  cp -p  $NEW_DIR/Makefile.win32 .
  cp -p  $NEW_DIR/include/Makefile.* include/
  cp -pr $NEW_DIR/win32-util .
  cp -pr $NEW_DIR/tests .

With that, those two older codebases both compiled on Windows.
However, when I then ran the latest regression tests, NaviServer
crashed with:

  Run-Time Check Failure #2 - Stack around the variable 'spoolLimit' was corrupted.
  (Press Retry to debug the application)

That terminated the tests early, of course.  It looks like about 93
tests passed and 42 failed before the testing NaviServer crashed.
Many of the failed tests did look like the same ones failing on the
latest head code.

The variable spoolLimit only appears in "nsd/tclhttp.c", so presumably
one of the later commits fixed a bug there.  But at that point I gave
up trying to test the older code.

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Thu, Jun 04, 2020 at 05:26:04PM +0200, Gustaf Neumann wrote:
> >    Assertion failed: (addr != ((void *)0)), file tclobj.c, line 325

> Probably "Ns_ThreadSelf(&tid);" does not work under windows (get the
> id of the current thread). Ns_ThreadSelf() is defined in the OS specific
> part (winthread.c). The exception is probably coming from
> test thread-2.3, it looks to me as if the the thread (here the
> thread running the tests) is not properly initiated under windows.
> 
> i have added one more assert, to make it easier to pinpoint the
> problem.

Yes, with your new change, when running ns_thread.test on Windows I
now always get this:

  Assertion failed: tid != NULL, file tclthread.c, line 238

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Gustaf N. <ne...@wu...>]

On 03.06.20 21:13, Andrew Piskorski wrote:
> ns_thread.test
>    [03/Jun/2020:14:25:28][4844.13bc][-tcl-nsthread:7-] Notice: update interpreter to epoch 1, trace none, time 0.219973 secs
>    Assertion failed: (addr != ((void *)0)), file tclobj.c, line 325
>    [03/Jun/2020:14:25:32][4844.1dd8][-tcl-nsthread:8-] Notice: update interpreter to epoch 1, trace none, time 3.902536 secs
>
> The stack trace looked like this:
>
>    ucrtbased.dll!000007feedad41cf()        Unknown
>    libnsd.dll!Ns_TclSetAddrObj(Tcl_Obj * objPtr, const char * type, void * addr) Line 325  C
>    libnsd.dll!NsTclThreadObjCmd(void * clientData, Tcl_Interp * interp, int objc, Tcl_Obj * const * objv) Line 239 C
>    [External Code]
>    libnsd.dll!CmdThread(void * arg) Line 1333      C
>    nsthread.dll!NsThreadMain(void * arg) Line 236  C
>    nsthread.dll!ThreadMain(void * arg) Line 874    C
>
> So that was inside Ns_TclSetAddrObj(), probably in the
> "NS_NONNULL_ASSERT(addr != NULL);" line.  It was called from
> NsTclThreadObjCmd(), in "case THandleIdx", line 238 in tclthread.c.
> That presumably came from a Tcl "ns_thread handle" call, and there's
> only one of those in the test suite, "test ns_thread-2.6" on line 70
> of "ns_thread.test".  But I don't understand why that would throw a
> null pointer exception!

Probably "Ns_ThreadSelf(&tid);" does not work under windows (get the
id of the current thread). Ns_ThreadSelf() is defined in the OS specific
part (winthread.c). The exception is probably coming from
test thread-2.3, it looks to me as if the the thread (here the
thread running the tests) is not properly initiated under windows.

i have added one more assert, to make it easier to pinpoint the
problem.

> ==== ns_listencallback-1.0 register FAILED
> ==== Contents of test case:

This is again one of these low-level socket commands.

> The ns_schedule-2.1 failure certainly sounds related to my original
> problem of the scheduler thread getting stuck, but there's enough else
> going on here that don't have any idea where the real source of the
> problem might be.

This sounds indeed related with the original problem.
The test registers a repeating proc (interval 1s),
but within in the time-range of 2.5s, it is executed
only once.

On 03.06.20 23:41, Andrew Piskorski wrote:
> Weirdly, that stacktrace seems like it must be missing some
> intermediate function calls, because nsproxy's Ns_ModuleInit()
> definitely never calls Ns_IncrTime() DIRECTLY.  So I'm not sure what's
> going on there either.
this is typical, when the code is compiled with an optimizer. Try to
deactivate the optimizer, this will improve the feedback.

maybe i get on the weekend some access to a win environent.

-gn

Re: [naviserver-devel] scheduler thread getting stuck

[Ibrahim T. <it...@ar...>]

On 03-Jun-20 23:41, Andrew Piskorski wrote:
> Is nsproxy supposed to work correctly on Windows?

I had to make extensive changes in the nsproxy code to make it 
work on Windows. The code is Unix-centric and makes some false 
assumptions w.r.t. to Windows handles v.s. unix file descriptors 
and therefore cannot run in Windows - at least not with native 
MSDN libraries.

I didn't push my changes back into the repository yet, since the 
changes need to possibly be readjusted and retested for Unix. I 
will ask Zoran to peer-review, adjust and push my changes, 
however this will not be before next week.

Cheers,
Ibrahim

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

Is nsproxy supposed to work correctly on Windows?

Its test framework wants to use test-nsproxy.sh to set LD_LIBRARY_PATH,
which of course can't work on Windows.  But as I work around that,
when I run just the ns_proxy.test tests, I get this error:

  Assertion failed: sec >= 0, file time.c, line 344

Which gives this stacktrace when run under the WinDbg debugger:

: nsthread!Ns_IncrTime+0x6c [naviserver\nsthread\time.c @ 344]
: nsproxy!Ns_ModuleInit+0x7a76
: nsthread!NsThreadMain+0x77 [naviserver\nsthread\thread.c @ 236]
: nsthread!ThreadMain+0x6c [naviserver\nsthread\winthread.c @ 874]
: ucrtbased!thread_start<unsigned int (__cdecl*)(void *),1>+0x9c [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 97]
: kernel32!BaseThreadInitThunk+0xd
: ntdll!RtlUserThreadStart+0x21

Weirdly, that stacktrace seems like it must be missing some
intermediate function calls, because nsproxy's Ns_ModuleInit()
definitely never calls Ns_IncrTime() DIRECTLY.  So I'm not sure what's
going on there either.

-- 
Andrew Piskorski <at...@pi...>

Re: [naviserver-devel] scheduler thread getting stuck

[Andrew P. <at...@pi...>]

On Mon, Jun 01, 2020 at 11:08:48AM -0400, Andrew Piskorski wrote:
> ## Last test that runs on Windows, it locks up forever:
> 
> http_persistent.test
> ns_sockioctl failed: no such file or directory
> while executing
> "ns_socknread $s"
> (procedure "client_readable" line 2)

For now I simply moved the entire http_persistent.test file out of the
way, so the server skips those tests.  With that, test server got
further, but eventually crashed with what looks like a null pointer
dereference, here:

  [03/Jun/2020:14:25:28][4844.2b10][-conn:test:default:1:229-] Notice: inside the filter 3.4
  ns_serverpath.test
  ns_set.test
  ns_sha1.test
  ns_sls.test
  ns_striphtml.test
  ns_thread.test

  [03/Jun/2020:14:25:28][4844.13bc][-tcl-nsthread:7-] Notice: update interpreter to epoch 1, trace none, time 0.219973 secs
  Assertion failed: (addr != ((void *)0)), file tclobj.c, line 325
  [03/Jun/2020:14:25:32][4844.1dd8][-tcl-nsthread:8-] Notice: update interpreter to epoch 1, trace none, time 3.902536 secs

The stack trace looked like this:

  ucrtbased.dll!000007feedad41cf()        Unknown
  libnsd.dll!Ns_TclSetAddrObj(Tcl_Obj * objPtr, const char * type, void * addr) Line 325  C
  libnsd.dll!NsTclThreadObjCmd(void * clientData, Tcl_Interp * interp, int objc, Tcl_Obj * const * objv) Line 239 C
  [External Code]
  libnsd.dll!CmdThread(void * arg) Line 1333      C
  nsthread.dll!NsThreadMain(void * arg) Line 236  C
  nsthread.dll!ThreadMain(void * arg) Line 874    C

So that was inside Ns_TclSetAddrObj(), probably in the
"NS_NONNULL_ASSERT(addr != NULL);" line.  It was called from
NsTclThreadObjCmd(), in "case THandleIdx", line 238 in tclthread.c.
That presumably came from a Tcl "ns_thread handle" call, and there's
only one of those in the test suite, "test ns_thread-2.6" on line 70
of "ns_thread.test".  But I don't understand why that would throw a
null pointer exception!

Prior to that crash, various other interesting test failures cropped
up, including both "ns_listencallback-1.0" and "ns_schedule-2.1" below.
The ns_schedule-2.1 failure certainly sounds related to my original
problem of the scheduler thread getting stuck, but there's enough else
going on here that don't have any idea where the real source of the
problem might be.


==== ns_listencallback-1.0 register FAILED
==== Contents of test case:

set localhost [expr {[ns_info ipv6] ? "::1" : "127.0.0.1"}]
ns_log notice "open sockent on $localhost 7227"
set fds [ns_sockopen $localhost 7227]
lassign $fds rfd wfd
set size 0

if {[gets $rfd line] == -1} {
ns_log error "got no data"
} else {
incr size [string length $line]
puts $wfd "How are you?"
flush $wfd
gets $rfd line
incr size [string length $line]
}
return [list size $size]

---- Result was:
size 0
---- Result should have been (exact matching):
size 46
==== ns_listencallback-1.0 FAILED


==== ns_schedule-2.1 schedule proc: interval FAILED
==== Contents of test case:

set id [ns_schedule_proc 1s {nsv_lappend . . ns_schedule-2.1}]
ns_sleep 2.5s
ns_unschedule_proc $id
nsv_get . .

---- Result was:
ns_schedule-2.1
---- Result should have been (glob matching):
ns_schedule-2.1 ns_schedule-2.1*
==== ns_schedule-2.1 FAILED

-- 
Andrew Piskorski <at...@pi...>