Forum OpenACS Q&A: How to correctly configure the reverse proxy.

I have been using the reverse proxy module to have NaviServer/OACS perform authentication and serve some of the URL space from a Node instance. My configuration has been working fairly well, but we have run into a problem with uploading some files. Most files upload fine, but with some we receive 504 Gateway Timeout responses. These responses seem to be size related. I am trying to figure out if this is an issue with the Naviserver reverse proxy configuration or limits set in the Node instance.

Focusing specifically on the ::revproxy::upstream call, I have configured and understand the -url_rewrite_callback arg (see here) and I can see that there are options for three timeouts: -timeout, -sendtimeout, -receivetimeout as well as other args.

What do each of these timeouts affect and where can I go to understand better the other arguments in this call?

Thanks,

-Tony

Which version of NaviServer are you using? There was a change in timeout semantics this year, making the behavior more useful.

How does backend behave? Does it send data incrementally or long time nothing and all data together?

For answering these questions, you can use in revproxy-procs the "verbose" flag, and "ns_logctl severity Debug(connchan) on" (e.g. in ds/shell) to get low-level debug information.

[1] https://bitbucket.org/naviserver/naviserver/commits/177e4e66a54810ed0bf4434ed0e60510584e3b90

First of all, i would recommend to upgrade to NaviServer 4.99.20, since there are many changes in the code, also affecting low-level I/O, connchan handling, etc. This will be much more robust also in connection with partial reads/writes and addresses changes in the behavior of newer versions of OpenSSL.

Anyhow, what i can read from your lines above is the following:

1. setting "-timeout 10"
2. start of request "29/Jan/2021:22:42:49"
3. timeout" 29/Jan/2021:22:42:59" while spooling from conn7 to conn6

Well, between (2) and (3) there are 10 seconds, the timeout value. Since it spools some data to conn6, i would assume that conn6 is the client (browser) and conn7 is the backend (node) . Since there is no reply from conn7 within this time span, the timeout occurs.

One question is, what happens on the node side? Maybe there are some entries in the log-file?

You can intensify the logging by turning on more log levels on the NaviServer side, especially on connchan. When you add for example the following line to the begin of the revproxy-procs, then you get more detailed information (be careful, if this is a busy site, you might get too much). One can certainly turn more detailed logging dynamically (maybe per revproxy PUT requests, but you have to add activation/deactivation yourself to the proc).

ns_logctl severity Debug(connchan) on

As in my last replies, i recommend to upgrade to NaviServer 4.99.20 (.18 is two years old, many things have changed around this area). However, i can answer to your specific questions

What timeout configuration is this warning referring to?

I am not sure, you want to hear this on this detail, but a short answer would raise more questions.... When turning on debugging, the system exposes more details that normally an application developer does not have to care about. ... but it provides as well debugging hints. When a socket say "would block, no timeout configured" this means, that on a read/write operation the OS-kernel reported that it refuses right now to read/write as the user-space program tried (here NaviServer) in non-blocking mode. For this concrete read/write operation, no timeout was provided (which is intended behavior for non-blocking socket operations in the socks thread. The same function is uses as well in other contexts). If the socket would be defined as blocking, it would block right now. Avoiding blocking operation is essential for the socks thread, since otherwise, all other concurrent operations in the same thread would halt as well.

The situation with "partial writes" is very similar: the user-space program want to write N bytes, but actually the kernel refuses to do this and writes only some X bytes (where X < N). The kernel can do so whenever it wants, this is allowed behavior from POSIX (see e.g. [1]). Different OSes do it so far rarely (macOS), other ones do this often (Linux, especially in newer versions).

To cope with these conditions, the user-level program has to retry the read/write (on our sockets receive/send) operations with the remaining data whenever the socket becomes readable or writable again. Handling of these operations in Tcl is unfortunately somewhat tricky, and is is also made more complex for TLS connections, where sometimes incomplete write operations mean that one has to wait for readability of the socket, since openssl does under the hood still some negotiations). On the Tcl-side we have two problem areas: where should the remaining data stored, how long, etc., what to do if in the meantime more data arrives, ... and what to do about binary/text data, especially when the byte-stream is separated inside a multi-byte character and the like. Earlier versions of revproxy solved this via nsv, switching different callbacks on the fly etc., while newer versions use newer socket functions in NaviServer that provide internal storage of the left-over bytes, such that the Tcl-side does not have to care about this.

So, under the hood, the code in 4.99.20 is very different compared to earlier versions, exactly to reduce the complexity sketched above. A similar situation is also around WebSockets. The good old WebSocket implementation of NaviServer worked perfectly fine over years for e.g. chat and similar other low-traffic, low volume operations, but when we started to use this for shared rooms with VR glasses (oculus) and WebVR/WebXR where one every movement substantial amount of data is sent, the old implementation run into many problems with partial reads/writes etc. This uses now the exactly same C-level operations.

So, sorry for being lengthy. Hope it explains reduced enthusiasm to dig into old code, since sooner or later you will want to upgrade.

[1] http://developerweb.net/viewtopic.php?id=4154

I now have a NaviServer 4.99.20 running and, unfortunately, I am seeing the same result; a 36.9 KB file uploads without a problem, but a 789 KB file does not.

Here is what I am now seeing in the logs for the failed upload. I have removed several of the repetitive lines.

[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: Inside validation call back pmd::val_call
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): ns_connchan open http://servern-pmd-pm-dashboard/pm-dashboard/api/program/25875/logo?user_id=2936 => conn304
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 63 bytes (total 1331)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 1331 errorState 0 --- operation now in progress
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend check partialResult 1331 nSent 1331 toSend 0 partial ? 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ### check result 1331 == -1 || 1331 == 1331 (partial 0 && ok 1) => try again 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend sent 1331 bytes state Operation now in progress
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): ns_connchan open http://servern-pmd-pm-dashboard/pm-dashboard/api/program/25875/logo?user_id=2936 returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: upstream: send max 16000 bytes from string to conn304 (length 808993)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): WS: send msgLen toSend 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 16000 bytes (total 16000)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 16000 errorState 0 --- operation now in progress
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend check partialResult 16000 nSent 16000 toSend 0 partial ? 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ### check result 16000 == -1 || 16000 == 16000 (partial 0 && ok 1) => try again 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan write returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: upstream: send max 16000 bytes from string to conn304 (length 808993)
... removed lines ...
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): WS: send msgLen toSend 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 16000 bytes (total 16000)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 16000 errorState 0 --- operation now in progress
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend check partialResult 16000 nSent 16000 toSend 0 partial ? 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ### check result 16000 == -1 || 16000 == 16000 (partial 0 && ok 1) => try again 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan write returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: upstream: send max 16000 bytes from string to conn304 (length 808993)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): WS: send msgLen toSend 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 16000 bytes (total 16000)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 12744 errorState 0 --- operation now in progress
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend check partialResult 12744 nSent 12744 toSend 3256 partial ? 1
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: conn304 ConnchanDriverSend partial write operation, sent 12744 (so far 12744) remaining 3256 bytes, full length 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ### check result 12744 == -1 || 16000 == 12744 (partial 1 && ok 1) => try again 1
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 3256 bytes (total 3256)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 0 errorState 0 --- resource temporarily unavailable
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend would block, no timeout configured, origLength 16000 still to send 16000 already sent 12744
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: ... partial write: to send 16000 sent 12744 remaining 3256
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan write returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: upstream: send max 16000 bytes from string to conn304 (length 808993)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): WS: send msgLen toSend 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 16000 bytes (total 16000)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 0 errorState 0 --- resource temporarily unavailable
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend would block, no timeout configured, origLength 16000 still to send 16000 already sent 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: ... partial write: to send 16000 sent 0 remaining 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan write returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: upstream: send max 16000 bytes from string to conn304 (length 808993)
... removed lines ...
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): WS: send msgLen toSend 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 16000 bytes (total 16000)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 0 errorState 0 --- resource temporarily unavailable
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend would block, no timeout configured, origLength 16000 still to send 16000 already sent 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: ... partial write: to send 16000 sent 0 remaining 16000
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan write returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: upstream: send max 16000 bytes from string to conn304 (length 808993)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): WS: send msgLen toSend 8993
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend try to send [0] 8993 bytes (total 8993)
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend NsDriverSend returned result 0 errorState 0 --- resource temporarily unavailable
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ConnchanDriverSend would block, no timeout configured, origLength 8993 still to send 8993 already sent 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: ... partial write: to send 8993 sent 0 remaining 8993
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan write returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn305 ConnChanDetachObjCmd sock 4
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn305 ns_connchan detach returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Notice: PROXY: backendChan conn304 frontendChan conn305 method POST version 1.0 http://servern-pmd-pm-dashboard/pm-dashboard/api/program/25875/logo?user_id=2936
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn305 ns_connchan callback returns 0
[03/May/2021:17:03:32][1.7fc60f646700][-conn:servern_pmd:default:0:216-] Debug(connchan): conn304 ns_connchan callback returns 0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn304 NsTclConnChanProc why  (64)
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Notice: PROXY: timeout occurred while waiting for backend reply conn304 to conn305
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): WS: send msgLen toSend 32
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ConnchanDriverSend try to send [0] 32 bytes (total 32)
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ConnchanDriverSend NsDriverSend returned result 32 errorState 1 --- Success
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ConnchanDriverSend check partialResult 32 nSent 32 toSend 0 partial ? 0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ### check result 32 == -1 || 32 == 32 (partial 0 && ok 1) => try again 0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ns_connchan write returns 0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Notice: PROXY: backendReply: ... auto closing conn304 http://servern-pmd-pm-dashboard/pm-dashboard/api/program/25875/logo?user_id=2936
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ns_connchan close connChanPtr 0x7fc609287ca0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 connchan: CancelCallback 0x7fc60a862700
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn305 ns_connchan close returns 0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn304 NsTclConnChanProc Tcl eval <::revproxy::backendReply> returned <0>
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): NsTclConnChanProc <::revproxy::backendReply -callback pmd::rep_call conn304 conn305 http://servern-pmd-pm-dashboard/pm-dashboard/api/program/25875/logo?user_id=2936 {-timeout 10 -sendtimeout 60 -receivetimeout 60} 0 t> numeric result 0
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn304 NsTclConnChanProc free channel
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): conn304 connchan: CancelCallback 0x7fc5e8fd6200
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): NsTclConnChanProc called on a probably deleted callback 0x7fc60a862700
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): connchan: callbackCallbackFree cbPtr 0x7fc60a862700 why 32
[03/May/2021:17:03:42][1.7fc5f4ff9700][-socks-] Debug(connchan): connchan: callbackCallbackFree cbPtr 0x7fc5e8fd6200 why 32

Here are the corresponding lines from the Node/Express logs, which do not appear deep enough to be of much use.

Mon, 03 May 2021 23:03:32 GMT express:router dispatching POST /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router query  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router expressInit  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router logger  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router logger  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router jsonParser  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router urlencodedParser  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router cookieParser  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router trim prefix (/pm-dashboard) from url /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router serveStatic /pm-dashboard : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router trim prefix (/pm-dashboard) from url /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router serveStatic /pm-dashboard : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router <anonymous>  : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router trim prefix (/pm-dashboard/api) from url /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router router /pm-dashboard/api : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router dispatching POST /program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router trim prefix (/program) from url /program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router router /program : /pm-dashboard/api/program/25875/logo?user_id=2936
Mon, 03 May 2021 23:03:32 GMT express:router dispatching POST /25875/logo?user_id=2936

The upload starts off just fine and then about half-way through a partial send happens and all further sends fail. Everything happens in the first second of the request and is not affected by the 10 second timeout I have tried to set in the least. It does now report that "resource temporarily unavailable" along with the "would block, no timeout configured".

Another part of this puzzle, that I did not mention before, is that I am running Naviserver and Node in separate Docker containers. As I mentioned above, if I change the upload code to bypass NaviServer as the reverse proxy and go directly to the Node server all of the files upload without a problem. So it does not seem to be a size limit problem for Node or Naviserver individually, but only in the transfer between them.

Does this give any more insight into this problem?

I really appreciate all the help,

-Tony

One other question on this, I only have modified the "string content" side because that is the path that is being followed. I assume something similar should be done on the "file content" path as well.

-Tony

The communication between CR is https and RT is http

Our host system is CentOS 7 running on a VM. We are running Docker on this system with each server in its own container (all on this host). They are all on the same network and reference each other via container names rather than ip addresses. As I understand it, this set-up should be very fast. I don't know where there would be any bandwidth problems on T or otherwise.

Just for reference, the first set-up we were working with:

R (NaviServer 4.99.18 on CentOS 7 container) <-> T (Node 12.22.1 on Debian - container node:12-slim)

The upgraded system is a little different. We are moving away from CentOS due to its end-of-life announcement:

R (NaviServer 4.99.20 on Ubuntu 20.04.1) <-> T (Node 12.22.1 on Debian - container node:12-slim)

Sorry, this took me a bit to get to. Thank you for your insight and help.

-Tony

The mentioned issue was not so easy to reproduce, but nevertheless, it is now resolved. I just write here a quick summary for everybody interested.

The test-setup from above worked as well for Tony, but with the same versions of software, there was still the problem on the real site, using docker images. So, the suspicion was with the docker setup. Tony provided me with a setup for a very similar installation based on docker, ... but this still worked for me without problems. In the next round i build a setup with VMs, t is quite easy to slow down the network interface), ... and i finally could reproduce and resolve the issue. The problem was indeed the slow backend, which causes partial write operations. The version of reverse proxy was using already the new C-level interface for handling these cases, ... but not on all places.

There was still a potential issue for reverse proxy operations with large input (typically POST or PUT requests). NaviServer should work with these conditions, so this was clearly an issue of the rev-proxy module that it was not prepared for this. The updated version in the public repository [1] fixes this issue by using the new C-level support for the partial writes also in these cases (in essence via "ns_connchan write -buffered") ... as we all know: if it can go wrong, it will go wrong.....

Many thanks for Tony the patience and for the good test cases!

-gn

[1] https://bitbucket.org/naviserver/revproxy/