Forum OpenACS Q&A: Re: naviserver signal 11 core backtrace (revproxy)

Collapse
15: Re: naviserver signal 11 core backtrace (revproxy) (response to 1)
Posted by Gustaf Neumann on 07/07/22 06:55 PM

Dear Marty,

I've tried hard to reproduce the behavior, but I failed to get a crash. The best I could get was to come to the situation, where ConnchanDriverSend partial write operationand ConnchanDriverSend would block, no timeout configured happened during GET requests, but then, I could not get a crash.

I have also tested with aborted server requests (where e.g. a user presses quickly reload before the load has finished), but still no crash. Have you collected new insights in this matter?

The updated test environment is https://github.com/gustafn/ns-revproxy-test.

All the best
-g

[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ConnchanDriverSend check partialResult 9144 nSent 9144 toSend 7240 partial ? 1
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Notice: conn321 ConnchanDriverSend partial write operation, sent 9144 (so far 9144) remaining 7240 bytes, full length 16384
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ### check result 9144 == -1 || 16384 == 9144 (partial 1 && ok 1) => try again 1
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ConnchanDriverSend try to send [0] 7240 bytes (total 7240)
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ConnchanDriverSend NsDriverSend returned result 0 errorState 1 --- resource temporarily unavailable
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ConnchanDriverSend would block, no timeout configured, origLength 16384 still to send 16384 already sent 9144
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): ... keep for later 7240 bytes of 16384 (buffered 7240) will be BYTES from 7406520 to 7413760
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ns_connchan write returns 0
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 ns_connchan callback returns 0
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn320 NsTclConnChanProc Tcl eval <::revproxy::spool> returned <2>
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): NsTclConnChanProc <::revproxy::spool conn320 conn321 http://127.0.0.1:18091//10MB.html {-timeout 10.0 -sendtimeout 0.0 -receivetimeout 0.5} 0 r> numeric result 2
[07/Jul/2022:18:31:12][301497.7fa599ffb640][-socks-] Debug(connchan): conn320 NsTclConnChanProc client requested to CANCEL (suspend) callback 0x7fa590276b40
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 NsTclConnChanProc why  (64)
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn320 ns_connchan exists returns 0
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn320 ns_connchan close connChanPtr 0x7fa590064b80
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn320 connchan: CancelCallback 0x7fa590276b40
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn320 ns_connchan close returns 0
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 NsTclConnChanProc Tcl eval <::revproxy::write_once> returned <0>
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): NsTclConnChanProc <::revproxy::write_once conn320 conn321 http://127.0.0.1:18091//10MB.html {-timeout 10.0 -sendtimeout 0.0 -receivetimeout 0.5} t> numeric result 0
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 NsTclConnChanProc free channel
[07/Jul/2022:18:31:22][301497.7fa599ffb640][-socks-] Debug(connchan): conn321 connchan: CancelCallback 0x7fa59018f110