Project

General

Profile

Actions

Bug #4417

closed

whttp connector and max-num-sessions not working

Added by mat Sch over 8 years ago. Updated over 8 years ago.

Status:
Closed
Priority:
High
Assignee:
Roel Standaert
Target version:
Start date:
08/25/2015
Due date:
% Done:

0%

Estimated time:

Description

I have a wt application that works correctly as a shared-process. I'm attempting to get it to work as a dedicated-process per session. I've uncommented the dedicated-process config section and commented out the shared-process section. My application starts fine but a connection attempt results in,

[info] "wthttp: started server: http://0.0.0.0:45601"

[info] \"wthttp/proxy: Child process xxxxx died before a session could be assigned

However, If I run the application under gdb it works great and I see,

[info] "wthttp: started server: http://0.0.0.0:45601"

[info] "Wt: session created (#sessions = 1)"

I don't see the constructor of my WApplication class getting to the first printout so I assume this is outside of my application.

I'm using qt 3.3.4

Thanks for the assistance.


Files

bug_4417.patch (469 Bytes) bug_4417.patch Roel Standaert, 09/01/2015 02:21 PM
bug_4417_2.patch (3.17 KB) bug_4417_2.patch Roel Standaert, 09/07/2015 11:19 AM
Actions #1

Updated by Wim Dumon over 8 years ago

  • Assignee set to Roel Standaert
Actions #2

Updated by Benoit Daccache over 8 years ago

  • Target version set to 3.3.5
Actions #3

Updated by Roel Standaert over 8 years ago

I haven't noticed that issue with any of our applications and examples, so I'm not sure what's going wrong here.

What does your main method look like? Is there anything non-standard happening there, or is it just like this:

Wt::WApplication *createApplication(const Wt::WEnvironment& env)
{
    return new HelloApplication(env);
}

int main(int argc, char **argv)
{
    return Wt::WRun(argc, argv, &createApplication);
}

Another thing that might cause the crash is the initialization of the WApplication before you enter the body of the constructor.

Actions #4

Updated by mat Sch over 8 years ago

main creates a Wt::Wserver that adds two entry points. Looks almost exactly like the example in the WServer docs except one entry oint is a WidgetSet. main calls, WRun as follows.

int WRun(int argc, char *argv[], ApplicationCreator createApplication)

{

WServer server(argv[0]);

server.setServerConfiguration(argc, argv, WTHTTP_CONFIGURATION);

server.addEntryPoint(Wt::WidgetSet, createWidget1, "/widget1");

server.addEntryPoint(Wt::Application, createWidget2,"/page1");

if (server.start()) {

int sig = WServer::waitForShutdown(argv[0]);

std::cerr << "Shutdown (signal = " << sig << ")" << std::endl;

server.stop();

}

}

After changing some of my code, I'm getting a different behavior under gdb. It looks like immediately after the server is started it's terminating with a SIGTERM.

Shutdown (signal = 15)

[2015-Aug-26 17:15:02.613197] 28511 - [info] "WebController: shutdown: stopping sessions."

[2015-Aug-26 17:15:02.613265] 28511 - [info] "WServer/wthttp: Shutdown: stopping web server."

[2015-Aug-26 17:15:02.613453] 15650 - [error] "wthttp/proxy: error reading status line: End of file"

192.46.110.86 - - [2015-Aug-26 17:15:02.613593] "GET /widget1?div=mydiv HTTP/1.1" 503 105

[2015-Aug-26 17:15:02.644195] 15650 - [info] "wthttp/proxy: Child process 28511 died before a session could be assigned"

not running under gdb a connection just logs, - [info] "wthttp/proxy: Child process 12823 died before a session could be assigned"

One thing I'm confused about is it looks like main is called again for each connection. At least that's what I'm seeing under gdb. How is that possible? If that is the case is there anyway to do a one time initialization for the webserver?

I'm confused about your comment about initializing the WApplication before entering the body of the constructor. It looks like all of your examples show WApplication being initialized in an initializer list in the constructor. That's what I'm doing as well.

thanks

Actions #5

Updated by mat Sch over 8 years ago

above I say that I changed some code and the behavior changed, but i've isolated it to different behavior depending on if the browser is connecting over the internet or connecting over a LAN. So, the behavior I'm seeing is,

*Over a LAN and under GDB it works.

*Over the internet and GDB I get the WServer returning signal 15 and the "wthttp/proxy: error reading status line: End of file"

*outside of GDB I aways get an immediate "wthttp/proxy: Child process 28511 died before a session could be assigned" before even getting to the main function of my application.

Thanks.

Actions #6

Updated by Roel Standaert over 8 years ago

Is it only your own application that is not working? What happens when you run an example application, like hello.wt (examples/hello), or hellowidgetset.wt (examples/feature/widgetset)?

W.r.t. your question about the main method being called again: that is indeed the case. For every session, a new process is spawned with the same arguments as were provided to the parent process, with one extra argument. The child process shares no resources with the parent process and only communicates with the parent through a local TCP socket opened at a random port. The extra argument corresponds to a TCP port the parent listens on that the child should use to notify the parent of this random port, after which the parent closes its listening socket.

Actions #7

Updated by mat Sch over 8 years ago

The hello.wt app exhibits the same behavior. I'm using the stock wt_config.xml file just with the section uncommented and the section commented out. So to summarize,

*works perfect over a lan..

*503 error over internet with, "wthttp/proxy: Child process 7656 died before a session could be assigned"

*503 error with gdb over internet but with more output.

[2015-Aug-28 14:10:27.517908] 26223 - [info] "config: reading Wt config file: /etc/wt.conf (location = '/apps/bin/hello.wt')"

[2015-Aug-28 14:10:27.518741] 26223 - [info] "WServer/wthttp: initializing built-in wthttpd"

[2015-Aug-28 14:10:27.519101] 26223 - [info] "wthttp: started server: http://0.0.0.0:42618"

[2015-Aug-28 14:10:32.522487] 26223 - [info] "WServer/wthttp: shutdown (signal = 15)"

[2015-Aug-28 14:10:32.522549] 26223 - [info] "WebController: shutdown: stopping sessions."

[2015-Aug-28 14:10:32.522577] 26223 - [info] "WServer/wthttp: Shutdown: stopping web server."

[2015-Aug-28 14:10:32.522763] 25504 - [error] "wthttp/proxy: error reading status line: End of file"

192.46.110.110 - - [2015-Aug-28 14:10:32.523014] "GET / HTTP/1.1" 503 105

[2015-Aug-28 14:10:32.524110] 25504 - [info] "wthttp/proxy: Child process 26223 died before a session could be assigned"

Previously I said it worked under gdb but I think that was wrong. It works only when contacted over a lan.

Thanks,

Actions #8

Updated by Roel Standaert over 8 years ago

It seems that the child process is killed with SIGTERM after 5 seconds. I think the child process is taking so long to create a new session, that the session expiration code kicks in, detects that there are no sessions, and tells the child to shutdown. I fixed that, and it will be on GitHub some time later. I've attached the patch here, too.

It's quite strange that the child process takes so long to create a session, though. Is this a slow system or under heavy load? Maybe it's stuck in a loop. That would be another bug then.

Actions #9

Updated by mat Sch over 8 years ago

-with all browsers it works perfectly over a LAN for 80+ connected client with lots of activity. It's been working well for 7 days

-over the internet with chrome it does not work. 100% failure rate. Have tried multiple machines and environments. hello.wt returns a 503 as well as my app.

-over the internet with firefox it does work.

Am I the only person that this doesn't work for? I'm using debian.

Here's the debug for a failed connection to hello.wt over the internet(vpn) using chrome, Note I redirected stdout and stderror to the same file so there's a bit of interleaving.

[2015-Sep-01 16:34:32.921047] 2924 - [info] "WServer/wthttp: initializing built-in wthttpd"

[2015-Sep-01 16:34:32.921651] 2924 - [info] "wthttp: started server: http://0.0.0.0:81"

[2015-Sep-01 16:34:39.251191] 2924 - [error] "wthttp/async: new connection (#1)"

[2015-Sep-01 16:34:39.251325] 2924 - [debug] "wthttp/async: 11: start()"

[2015-Sep-01 16:34:39.251443] 2924 - [debug] "wthttp/async: 11: startAsyncReadRequest"

[2015-Sep-01 16:34:39.251484] 2924 - [debug] "wthttp/async: 11 setting read timeout (ws: --1)"x

[2015-Sep-01 16:34:39.466794] 2924 - [debug] "wthttp/async: 11: handleReadRequest(): Success"

[2015-Sep-01 16:34:39.466921] 2924 - [debug] "wthttp/async: 11 cancel read timeout"

[2015-Sep-01 16:34:39.467003] 2924 - [debug] "wthttp/async: 11incoming request: 55154 (avail= 1350): GET / HTTP/1.1

Host: 192.168.22.125:81

Connection: keep-alive

Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,/;q=0.8

Upgrade-Insecure-Requests: 1

User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 Safari/537.36

Accept-Encoding: gzip, deflate, sdch

Accept-Language: en-US,en;q=0.8,ar;q=0.6,ru;q=0.4

Cookie: prefsJSON=7B%22selectedDriveRow%22%3A4%2C%22curExpandedRow%22%3A%22%22%2C%22channelHeaderArray%22%3A%5B%7B%22dbName%22%3A%22status%22%2C%22displayName%22%3A%22activity%22%2C%22columnType%22%3A%22activity%22%2C%22isAdvanced%22%3Atrue%7D%2C%7B%22dbName%22%3A%22boardChannelId%22%2C%22displayName%22%3A

[2015-Sep-01 16:34:39.467207] 2924 - [debug] "wthttp/async: 11: startAsyncReadRequest\"

[2015-Sep-01 16:34:39.467245] 2924 - [debug] "wthttp/async: 11 setting read timeout (ws: --1)"

[2015-Sep-01 16:34:39.485155] 2924 - [debug] "wthttp/async: 11: handleReadRequest(): Success"

[2015-Sep-01 16:34:39.485228] 2924 - [debug] "wthttp/async: 11 cancel read timeout"

[2015-Sep-01 16:34:39.485289] 2924 - [debug] \"wthttp/async: 11incoming request: 55154 (avail= 555): dvanced%22%3Atrue%7D%2C%7B%22dbName%22%3A%22serial%22%2C%22displayName%22%3A%22Serial%22%2C%22columnType%22%3Anull%2C%22isAdvanced%22%3Atrue%7D%5D%2C%22showByChannels%22%3Afalse%7D; udsso=0; e_soap_sess

\"

[2015-Sep-01 16:34:39.485402] 2924 - [debug] "wthttp/async: 11request: 200"

[2015-Sep-01 16:34:39.485801] 2924 - [debug] "wthttp/proxy: Listening to child process on port 53792"

[2015-Sep-01 16:34:39.486095] 2924 - [error] "wthttp/proxy: fork()"

[2015-Sep-01 16:34:39.486144] 2924 - [error] "wthttp/proxy: parent process"

[2015-Sep-01 16:34:39.486243] 3127 - [error] "wthttp/proxy: fork()"

[2015-Sep-01 16:34:39.486501] 3127 - [error] "wthttp/proxy: child process"

[2015-Sep-01 16:34:39.500482] 3127 - [info] "config: reading Wt config file: //etc/wt.conf (location = '/bin/hello.wt')"

[2015-Sep-01 16:34:39.501680] 3127 - [info] "WServer/wthttp: initializing built-in wthttpd"

[2015-Sep-01 16:34:39.502289] 3127 - [info] "wthttp: started server: http://0.0.0.0:57625"

[2015-Sep-01 16:34:39.502920] 2924 - [debug] "wthttp/proxy: Child is listening on port 57625"

[2015-Sep-01 16:34:39.503162] 3127 - [error] "wthttp/async: new connection (#1)"

[2015-Sep-01 16:34:39.503241] 3127 - [debug] "wthttp/async: 14: start()"

[2015-Sep-01 16:34:39.503338] 3127 - [debug] "wthttp/async: 14: startAsyncReadRequest"

[2015-Sep-01 16:34:39.503377] 3127 - [debug] "wthttp/async: 14 setting read timeout (ws: --1)"

[2015-Sep-01 16:34:39.503578] 3127 - [debug] "wthttp/async: 14: handleReadRequest(): Success"

[2015-Sep-01 16:34:39.503620] 3127 - [debug] "wthttp/async: 14 cancel read timeout"

[2015-Sep-01 16:34:39.503676] 3127 - [debug] "wthttp/async: 14incoming request: 58018 (avail= 16): GET / HTTP/1.1

[2015-Sep-01 16:34:39.503748] 3127 - [debug] "wthttp/async: 14: startAsyncReadRequest\"

[2015-Sep-01 16:34:39.503785] 3127 - [debug] "wthttp/async: 14 setting read timeout (ws: --1)"

[2015-Sep-01 16:34:44.504514] 3127 - [info] "WServer/wthttp: shutdown (signal = 15)"

[2015-Sep-01 16:34:44.504639] 3127 - [info] "WebController: shutdown: stopping sessions."

[2015-Sep-01 16:34:44.504691] 3127 - [info] "WServer/wthttp: Shutdown: stopping web server."

[2015-Sep-01 16:34:44.504849] 3127 - [error] "wthttp/async: removed connection (#0)"

[2015-Sep-01 16:34:44.504974] 3127 - [debug] "wthttp/async: 14: stop()"

[2015-Sep-01 16:34:44.505016] 3127 - [debug] "wthttp/async: last request: GET / (ws:--1)"

[2015-Sep-01 16:34:44.505089] 3127 - [debug] "wthttp/async: 14: closing socket"

[2015-Sep-01 16:34:44.505163] 3127 - [debug] "wthttp/async: --1: handleReadRequest(): End of file"

[2015-Sep-01 16:34:44.505201] 3127 - [debug] "wthttp/async: --1 cancel read timeout"

[2015-Sep-01 16:34:44.505173] 2924 - [error] "wthttp/proxy: error reading status line: End of file"

[2015-Sep-01 16:34:44.505243] 3127 - [debug] "wthttp/async: --1: error: End of file"

[2015-Sep-01 16:34:44.505282] 3127 - [debug] "wthttp/async: --1 cancel read timeout"

[2015-Sep-01 16:34:44.505293] 2924 - [debug] "wthttp: 0x93fda98: Reply: send(): scheduling write response."[2015-Sep-01 16:34:44.505317] 3127 - [debug] "wthttp/async: --1 cancel write timeout"

[2015-Sep-01 16:34:44.505355] 3127 - [debug] "wthttp/async: --1: close()"

[2015-Sep-01 16:34:44.505394] 3127 - [debug] "wthttp/async: ~Connection"

[2015-Sep-01 16:34:44.505615] 2924 - [debug] "wthttp/async: 11 sending: 223(buffers: 2)"

[2015-Sep-01 16:34:44.505676] 2924 - [debug] "wthttp/async: 11: startAsyncWriteResponse"

[2015-Sep-01 16:34:44.505713] 2924 - [debug] "wthttp/async: 11 setting write timeout (ws: --1)"

[2015-Sep-01 16:34:44.505962] 3127 - [debug] "wthttp/async: ~Connection"

[2015-Sep-01 16:34:44.505979] 2924 - [debug] "wthttp/async: 11: handleWriteResponse(): 223 ; Success"

[2015-Sep-01 16:34:44.506029] 2924 - [debug] "wthttp/async: 11 cancel write timeout"

[2015-Sep-01 16:34:44.506075] 2924 - [debug] "wthttp/async: 11: handleWriteResponse() 0 1"

[2015-Sep-01 16:34:44.506209] 2924 - [error] "wthttp/async: removed connection (#0)"

[2015-Sep-01 16:34:44.506317] 2924 - [debug] "wthttp/async: 11: stop()"

[2015-Sep-01 16:34:44.506369] 2924 - [debug] "wthttp/async: last request: GET / (ws:--1)"

[2015-Sep-01 16:34:44.506421] 2924 - [debug] "wthttp/async: 11: closing socket"

[2015-Sep-01 16:34:44.506504] 2924 - [debug] "wthttp: ~Reply"

[2015-Sep-01 16:34:44.506551] 2924 - [debug] "wthttp: ~Reply"

[2015-Sep-01 16:34:44.506597] 2924 - [debug] "wthttp/async: ~Connection"

[2015-Sep-01 16:34:44.507424] 2924 - [info] "wthttp/proxy: Child process 3127 died before a session could be assigned"

[2015-Sep-01 16:34:48.009398] 2924 - [info] "WServer/wthttp: shutdown (signal = 2)"

[2015-Sep-01 16:34:48.009554] 2924 - [info] "WebController: shutdown: stopping sessions."

[2015-Sep-01 16:34:48.009654] 2924 - [info] "WServer/wthttp: Shutdown: stopping web server."

[2015-Sep-01 16:34:48.010140] 2924 - [debug] "wthttp/async: ~Connection"

Here is example output of it working using firefox. Same PC connecting to the same server

192.46.110.110 - - [2015-Sep-01 16:45:31.531126] "POST /?wtd=YqbluEZYYzQVr9z8 HTTP/1.1" 200 50

"wthttp/async: 11 cancel read timeout"

[2015-Sep-01 16:45:31.053619] 29145 - [debug] \"wthttp/async: 11incoming request: 55199 (avail= 301): GET / HTTP/1.1

Host: 192.168.22.125:81

User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:37.0) Gecko/20100101 Firefox/37.0

Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8

Accept-Language: en-US,en;q=0.5

Accept-Encoding: gzip, deflate

Connection: keep-alive

\"

[2015-Sep-01 16:45:31.053733] 29145 - [debug] "wthttp/async: 11request: 200"

[2015-Sep-01 16:45:31.054077] 29145 - [debug] "wthttp/proxy: Listening to child process on port 59842"

[2015-Sep-01 16:45:31.054379] 29145 - [error] "wthttp/proxy: fork()"

[2015-Sep-01 16:45:31.054430] 29145 - [error] "wthttp/proxy: parent process"

[2015-Sep-01 16:45:31.054522] 29628 - [error] "wthttp/proxy: fork()"

[2015-Sep-01 16:45:31.054805] 29628 - [error] "wthttp/proxy: child process"

[2015-Sep-01 16:45:31.068797] 29628 - [info] "config: reading Wt config file: //etc/wt.conf (location = '//bin/hello.wt')"

[2015-Sep-01 16:45:31.069989] 29628 - [info] "WServer/wthttp: initializing built-in wthttpd"

[2015-Sep-01 16:45:31.070602] 29628 - [info] "wthttp: started server: http://0.0.0.0:57768"

[2015-Sep-01 16:45:31.071265] 29145 - [debug] "wthttp/proxy: Child is listening on port 57768"

[2015-Sep-01 16:45:31.071519] 29628 - [error] "wthttp/async: new connection (#1)"

[2015-Sep-01 16:45:31.071577] 29628 - [debug] "wthttp/async: 14: start()"

[2015-Sep-01 16:45:31.071666] 29628 - [debug] "wthttp/async: 14: startAsyncReadRequest"

[2015-Sep-01 16:45:31.071705] 29628 - [debug] "wthttp/async: 14 setting read timeout (ws: --1)"

[2015-Sep-01 16:45:31.071926] 29628 - [debug] "wthttp/async: 14: handleReadRequest(): Success"

[2015-Sep-01 16:45:31.071993] 29628 - [debug] "wthttp/async: 14 cancel read timeout"

[2015-Sep-01 16:45:31.072058] 29628 - [debug] \"wthttp/async: 14incoming request: 54906 (avail= 329): GET / HTTP/1.1

Host: 192.168.22.125:81

User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:37.0) Gecko/20100101 Firefox/37.0

Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8

Accept-Language: en-US,en;q=0.5

Accept-Encoding: gzip, deflate

Connection: close

X-Forwarded-For: 192.46.110.110

\"

[2015-Sep-01 16:45:31.072154] 29628 - [debug] "wthttp/async: 14request: 200"

[2015-Sep-01 16:45:31.072402] 29628 - [debug] "CgiParser: queryString (len=0): "

[2015-Sep-01 16:45:31.072653] 29628 - [info] "Wt: session created (#sessions = 1)"

[2015-Sep-01 16:45:31.073105] 29628 [/ YqbluEZYYzQVr9z8] [info] "WEnvironment: UserAgent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:37.0) Gecko/20100101 Firefox/37.0"

[2015-Sep-01 16:45:31.074591] 29628 [/ YqbluEZYYzQVr9z8] [debug] "wthttp: WtReply::send(): 0"

[2015-Sep-01 16:45:31.074660] 29628 [/ YqbluEZYYzQVr9z8] [debug] "wthttp: 0x9d72a40: Reply: send(): scheduling write response."

[2015-Sep-01 16:45:31.074755] 29628 [/ YqbluEZYYzQVr9z8] [debug] "Wt: Setting to expire in 10s"

[2015-Sep-01 16:45:31.074889] 29628 - [debug] "wthttp: avail now: 6917"

[2015-Sep-01 16:45:31.075409] 29628 - [debug] "wthttp/async: 14 sending: 2872(buffers: 2)"

[2015-Sep-01 16:45:31.075452] 29628 - [debug] "wthttp/async: 14: startAsyncWriteResponse"

[2015-Sep-01 16:45:31.075488] 29628 - [debug] "wthttp/async: 14 setting write timeout (ws: --1)"

[2015-Sep-01 16:45:31.075788] 29628 - [debug] "wthttp/async: 14: handleWriteResponse(): 2872 ; Success"

[2015-Sep-01 16:45:31.075836] 29628 - [debug] "wthttp/async: 14 cancel write timeout"

[2015-Sep-01 16:45:31.075879] 29628 - [debug] "wthttp: writeDone() success:1, sent: 6917"

[2015-Sep-01 16:45:31.075922] 29628 - [debug] "wthttp/async: 14: handleWriteResponse() 0 1"

[2015-Sep-01 16:45:31.075937] 29145 - [debug] "wthttp: 0x9e6aa88: Reply: send(): scheduling write response."

[2015-Sep-01 16:45:31.075974] 29628 - [info] "WebRequest: took 3.643ms"

[2015-Sep-01 16:45:31.076054] 29628 - [error] "wthttp/async: removed connection (#0)"

[2015-Sep-01 16:45:31.076159] 29628 - [debug] "wthttp/async: 14: stop()"

[2015-Sep-01 16:45:31.076166] 29145 - [debug] "wthttp/async: 11 sending: 496(buffers: 3)"

[2015-Sep-01 16:45:31.076204] 29628 - [debug] "wthttp/async: last request: GET / (ws:--1)"

[2015-Sep-01 16:45:31.076227] 29145 - [debug] "wthttp/async: 11: startAsyncWriteResponse"

[2015-Sep-01 16:45:31.076266] 29145 - [debug] "wthttp/async: 11 setting write ti

eout (ws: --1)"

[2015-Sep-01 16:45:31.076364] 29628 - [debug] "wthttp: ~Reply"

[2015-Sep-01 16:45:31.076422] 29628 - [debug] "wthttp/async: ~Connection"

[2015-Sep-01 16:45:31.076522] 29145 - [debug] "wthttp/async: 11: handleWriteResponse(): 496 ; Success"

[2015-Sep-01 16:45:31.076567] 29145 - [debug] "wthttp/async: 11 cancel write timeout"

[2015-Sep-01 16:45:31.076665] 29145 - [debug] "wthttp/async: 11: handleWriteResponse() 0 0"

[2015-Sep-01 16:45:31.076766] 29145 - [debug] "wthttp: 0x9e6aa88: Reply: send(): scheduling write response."

[2015-Sep-01 16:45:31.076844] 29145 - [debug] "wthttp/async: 11 sending: 519(buffers: 3)"

[2015-Sep-01 16:45:31.076890] 29145 - [debug] "wthttp/async: 11: startAsyncWriteResponse"

[2015-Sep-01 16:45:31.076926] 29145 - [debug] "wthttp/async: 11 setting write timeout (ws: --1)"

[2015-Sep-01 16:45:31.077034] 29145 - [debug] "wthttp/async: 11: handleWriteResponse(): 519 ; Success"

[2015-Sep-01 16:45:31.077075] 29145 - [debug] "wthttp/async: 11 cancel write timeout"

[2015-Sep-01 16:45:31.077138] 29145 - [debug] "wthttp/async: 11: handleWriteResponse() 0 0"

[2015-Sep-01 16:45:31.077201] 29145 - [debug] "wthttp: 0x9e6aa88: Reply: send(): scheduling write response."

[2015-Sep-01 16:45:31.077274] 29145 - [debug] "wthttp/async: 11 sending: 519(buffers: 3)"

[2015-Sep-01 16:45:31.077318] 29145 - [debug] "wthttp/async: 11: startAsyncWriteResponse"

[2015-Sep-01 16:45:31.077354] 29145 - [debug] "wthttp/async: 11 setting write timeout (ws: --1)"

[2015-Sep-01 16:45:31.077456] 29145 - [debug] "wthttp/async: 11: handleWriteResponse(): 519 ; Success"

To make things more complicated my application works fine over the LAN, but does not work in chrome or firefox. Looks like the child process dies immediately. Here it is failing from firefox over the internet.

[2015-Sep-01 19:17:07.180714] 3966 - [error] "wthttp/async: new connection (#1)"

[2015-Sep-01 19:17:07.180802] 3966 - [debug] "wthttp/async: 11: start()"

[2015-Sep-01 19:17:07.180871] 3966 - [debug] "wthttp/async: 11: startAsyncReadRequest"

[2015-Sep-01 19:17:07.180901] 3966 - [debug] "wthttp/async: 11 setting read timeout (ws: --1)"

[2015-Sep-01 19:17:07.181621] 3966 - [debug] "wthttp/async: 11: handleReadRequest(): Success"

[2015-Sep-01 19:17:07.181694] 3966 - [debug] "wthttp/async: 11 cancel read timeout"

[2015-Sep-01 19:17:07.181752] 3966 - [debug] \"wthttp/async: 11incoming request: 59149 (avail= 753): GET /ljaudioWidget?div=ljaudio HTTP/1.1

Host: 192.168.22.125:81

User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:37.0) Gecko/20100101 Firefox/37.0

Accept: /

Accept-Language: en-US,en;q=0.5

Accept-Encoding: gzip, deflate

Referer: http://192.168.22.125/client/mediaworks/?console=1

Cookie: udsso=0; e_soap_session=L4LUcVNA9tNDcI8m; e_soap_user=Admin; prefsJSON=%7B%22curExpandedRow%22%3A%22%22%7D; e_soap_session_192.168.22.17=yBmktFxfkcZQ5fNn; e_soap_user_192.168.22.17=admin; e_soap_session_192.46.153.128=xnqkAZhgXp6TGKkb; e_soap_user_192.46.153.128=admin; e_soap_session_192.168.22.40=HwEwVQdYUcn7JMMs; e_soap_user_192.168.22.40=admin

Connection: keep-alive

\"

[2015-Sep-01 19:17:07.181855] 3966 - [debug] "wthttp/async: 11request: 200"

[2015-Sep-01 19:17:07.182403] 3966 - [debug] "wthttp/proxy: Listening to child process on port 54211"

[2015-Sep-01 19:17:07.183063] 3966 - [error] "wthttp/proxy: fork()"

[2015-Sep-01 19:17:07.183107] 3966 - [error] "wthttp/proxy: parent process"

[2015-Sep-01 19:17:07.183199] 7046 - [error] "wthttp/proxy: fork()"

[2015-Sep-01 19:17:07.183394] 7046 - [error] "wthttp/proxy: child process"

[2015-Sep-01 19:17:07.186718] 3966 - [info] "wthttp/proxy: Child process 7046 died before a session could be assigned"

And again, This all worked fine if I didn't use a dedicated process per session. I switched because my system couldn't handle the amount of threads for a single process.

I can provide access to the machine if that would be helpful.

Thanks,

-mat

Actions #10

Updated by Roel Standaert over 8 years ago

Looks like the problem occurs if the request is split up into multiple buffers, causing incomplete headers to be sent to the child process. I fixed that issue, and the fix should be up on GitHub the next time Koen pushes the changes. I've also attached the patch here.

Actions #11

Updated by Koen Deforche over 8 years ago

  • Status changed from Resolved to Closed
Actions

Also available in: Atom PDF