ZServer not threading

[gogobd]

We're running ZServer 4.0.1 (that comes with Plone 5.2RC5) under Python 2.7. and I realized that I can't open urls with my browser whenever I'm in a breakpoint. Our zope.conf has "zserver-threads 6" but I'm getting the impression that ZServer doesn't thread. pstree shows one instance of the server, not more. We're using macOS High Sierra.

[gogobd]

This behavior has been consistent for two weeks now.

[d-maurer]

Georg Gogo. BERNHARD wrote at 2019-7-16 01:23 -0700:

This behavior has been consistent for two weeks now.

I can confirm the bug. I will investigate.

[d-maurer]

This turned out to be a ZServer(not a Zope) bug.

Fixed by zopefoundation/ZServer#17

[gogobd]

THANK YOU!

[gogobd]

Unfortunately the problem's still there, I updated to master, confirmed the fix is active but the behavior of the server is still the same: no requests are being handled while I'm in a breakpoint, no threads are visible in pstree.

[d-maurer]

Georg Gogo. BERNHARD wrote at 2019-7-19 02:48 -0700:

Unfortunately the problem's still there, I updated to master, confirmed the fix is active but the behavior of the server is still the same: no requests are being handled while I'm in a breakpoint, no threads are visible in pstree.

Try to add a `zserver-threads` definition to your configuration file. In my `zope.conf`, I have `zserver-threads 4` and when I visit `http://localhost:9080/Control_Panel/Database/main/manage_main`, I see that 4 ZODB connections have been opened (which means that 4 threads have been active). I also have verified multithreading with a sleeping `ExternalMethod`. After the fix, other requests were handled while the `ExternalMethod` was sleeping.

[gogobd]

My zope.conf shows 'zserver-threads 6', my Control_Panel/Database/main/manage_main i see only one <Connection at .........> listed uner "Total number of objects in each cache". I'm starting with "./bin/instance" if that makes any difference.

[d-maurer]

Georg Gogo. BERNHARD wrote at 2019-7-19 04:44 -0700:

My zope.conf shows 'zserver-threads 6', my Control_Panel/Database/main/manage_main i see only one <Connection at .........> listed uner "Total number of objects in each cache.

I switched to the current "master" and checked again: here, "ZServer" works as it should (i.e. all 4 worker threads have been used). Something seems to be wrong at your side locally. I cannot tell what this is (maybe, you unexpectedly still use the old "ZServer"; maybe, you use an unexpected configuration file). I can tell you however how I have analysed the problem: I have put a (code) breakpoint in `ZServer.PubCore.ZRendevous.ZRendevous.__init__` (that is the place where the worker thread pool is created) and found that a pool of size 1 was created. I looked at the call chain to find out where this wrong (pool size) value came from. Maybe, you follow those steps and check whether a wrong pool size is (still) your problem.

[gogobd]

Thank you so much for your help, it's very appreciated!

So, I tried out the suggested breakpoint and: in ZRendevous.init i can see the RIGHT number of threads being passed in, and I can see that the while loop actually calls "thread.start_new_thread" 6 times in my case!

However when I create two Python Scripts, one that returns "Hi" and another that goes into an infinite while loop I can reproduce that the server is blocking. This is happening both with "instance fg" and "instance start".

I was now investigating a little further and things got a bit weird. in ZServerPublisher's init 5 out of 6 threads can not do "from ZPublisher.Publish import publish_module" - only the first one doesn't fail with an ImportError. That's the reason why I only have one thread. The funny thing is when I add a conditional breakpoint on that ImportError and execute the failing import statement in the debugger it works and I get no error. So there must be some sort of runtime concurrency / sequence problem which led me to a funny fix:

        import time
        import random
        time.sleep(random.random())
        from ZPublisher.Publish import publish_module

solves my problem and I can see all 6 configured threads in "/Control_Panel/Database/main". It's still completely misterious for me why this happens at all.

[d-maurer]

Georg Gogo. BERNHARD wrote at 2019-7-22 02:08 -0700:

... I was now investigating a little further and things got a bit weird. in ZServerPublisher's __init__ 5 out of 6 threads can not do "from ZPublisher.Publish import publish_module" - only the first one doesn't fail with an ImportError.

Can you catch the `ImportError` and log the complete error information (with `logger.exception(...)`). There are known issues with concurrent Python imports (in different threads), even though I do not yet know that they can result in an `ImportError` (I know about deadlocks in some situations). As a workaround, you could try to import `publish_module` before the worker threads are created. This way, you get less concurrent imports and reduce the risk of import interferences.

[gogobd]

My colleague iHam just suggested to use

from ZServer.ZPublisher.Publish import publish_module

instead of

from ZPublisher.Publish import publish_module

and: That seems to resolve all problems, including the deprication warning!

[icemac]

@gogobd So your problem is solved? Can this issue be closed then or should we keep it open until the connected issues are resolved and released?

[dataflake]

This is long fixed.