Some requests don't get proccessed

[sabof]

Here is the request - which does get into the process filter.

GET /original/js/views/about.js HTTP/1.1
Host: localhost:8001
Connection: keep-alive
Cache-Control: no-cache
Pragma: no-cache
Accept: */*
User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.56 Safari/537.36
Referer: http://localhost:8001/original/
Accept-Encoding: gzip,deflate,sdch
Accept-Language: en-US,en;q=0.8

Here are the lines mentioning 56085 - value of (process-contact) for the above. I couldn't paste the whole log, as some characters wouldn't get accepted. Previous experiments have shown that the requests don't get to the stage of user-defined functions. If this is not helpful, I'll try to find more info or post a more complete log, a bit later.

elnode-error: elnode--sentinel 'open from 127.0.0.1.' for process  *elnode-webserver-proc* <127.0.0.1:56085> with buffer nil
elnode-error: Elnode status: *elnode-webserver-proc* <127.0.0.1:56085> open from 127.0.0.1
elnode-error: filter: calling handler on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: starting HTTP response on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: Elnode-child-process init *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: filter: handler returned on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: Elnode-child-process-filter http state: open data length: 306 on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: elnode-http-send-string *elnode-webserver-proc* <127.0.0.1:56085> [[a.plain:link.{ color]]
elnode-error: Elnode-child-process-sentinel Status @ finished: open -> exit on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: elnode-http-send-string *elnode-webserver-proc* <127.0.0.1:56085> [[]]
elnode-error: elnode--http-end ending socket *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: filter: calling handler on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: Http already started on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: Elnode-child-process init *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: filter: handler returned on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: elnode--sentinel 'deleted.' for process  *elnode-webserver-proc* <127.0.0.1:56085> with buffer  *elnode-request-56085*
elnode-error: Elnode status: *elnode-webserver-proc* <127.0.0.1:56085> deleted
elnode-error: Elnode-child-process-filter http state: closed data length: 306 on *elnode-webserver-proc* <127.0.0.1:56085>
elnode-error: Elnode-child-process-sentinel Status @ finished: closed -> exit on *elnode-webserver-proc* <127.0.0.1:56085>

[nicferrier]

It looks like it IS getting into the user code to send the data:

elnode-error: elnode-http-send-string *elnode-webserver-proc*<127.0.0.1:56085> [[a.plain:link.{ color]]

have you tried using edebug or message debugging on this proc?

Of course if you fail while processing your response can get totally lost.

You could try wrapping your handler with a condition-case?

[sabof]

Presumably, ports are being reused to serve different resources - some of them being processed correctly. It's a non-deterministic, and rather rare bug - so edebug isn't ideal.

[sabof]

Actually the JS application isn't relevant. As what doesn't load, are simple script tags like:

<script src="js/utils.js"></script>

[sabof]

Those files where served through elnode-webserver-handler-maker, without anything adventurous. I guess a simplified case would be a long html file with lots of ~150 script/img tags pointing to different files. The client side assertion being that they all get a correct mime type, and not text/plain (which they do in case of a failure).

[sabof]

Here is a more characteristic bit. bt-handler-root is the entry point for my program. 55236 is being used twice. The first time about.js is requested and served. The second time main.js is requested and about.js is served again (apparently).

elnode-error: filter-START: /original/js/views/about.js
elnode--http-parse: nil
elnode-error: filter: calling handler on *elnode-webserver-proc* <127.0.0.1:55236>
bt-handler-root: /original/js/views/about.js 
elnode-error: starting HTTP response on *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: Elnode-child-process init *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: filter: handler returned on *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: filter-END: /original/js/views/about.js 
elnode-error: Elnode-child-process-filter http state: open data length: 201 on *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: Elnode-child-process-sentinel Status @ finished: open -> exit on *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: elnode--http-end ending socket *elnode-webserver-proc* <127.0.0.1:55236>
elnode--http-end: an error occurred processing the access log
elnode-error: Elnode-child-process-filter http state: open data length: 3015 on *elnode-webserver-proc* <127.0.0.1:55235>
elnode-error: Elnode-child-process-sentinel Status @ finished: open -> exit on *elnode-webserver-proc* <127.0.0.1:55235>
elnode-error: elnode--http-end ending socket *elnode-webserver-proc* <127.0.0.1:55235>
elnode--http-end: an error occurred processing the access log
elnode-error: filter-START: /original/js/main.js
elnode--http-parse: GET /original/js/views/about.js HTTP/1.1
elnode-error: filter: calling handler on *elnode-webserver-proc* <127.0.0.1:55236>
bt-handler-root: /original/js/views/about.js 
elnode-error: Http already started on *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: Elnode-child-process init *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: filter: handler returned on *elnode-webserver-proc* <127.0.0.1:55236>
elnode-error: filter-END: /original/js/main.js 

[nicferrier]

Ermmm... I've never seen this. I guess we could make a script test case of it?

(elnode-start (elnode-webserver-handler-maker "~/dir-with-some-files-in-it") :port 8000)

and then a script:

while [ 1 ]
do
   curl http://location:8000
   curl http://location:8000/scripts/some.js
done

and what are you saying the assertion is? that sometimes the curl for the js returns some other file?

[sabof]

I think so. The symptom is that if a page has many resources, not all of them will get loaded.

A possible way to reproduce it might be to generate many small images (1000?), include them in a single html page, and let elnode serve it.

[nicferrier]

Would lots of small js files work? I could make lots of small js files... I'd have to go find out how to make lots of small images. imagemagick I expect would work. scripting images is boring.

[sabof]

Might actually be better with .js files. It would be easier to verify that the content is correct.

[sabof]

If that's not your area of expertise, I can setup a RequireJS page, that would load them asynchronously. A bit later though, since my left hand indicates that I've been typing too much.

[nicferrier]

Oh I can do it. It's not my priority for the next hour but am happy to do it.

One other thing I'm working on btw is an emacs-lisp -> javascript compiler which would make this very easy. I'll just do this the dumb way though.

[sabof]

I think that this will become relevant when (and if) we get an embedded browser.

[nicferrier]

I looked at this a little bit over the last few months. I think it's related to the backlog. Elnode didn't set a specific backlog on the socket. Now it does. It should be better. I'll still try and come up with a decent way to test this though.