1

I constructed a strange situation in a CherryPy server, and I'd like some help understanding exactly what's happening, and why. Here is server.py:

import cherrypy
import os
import threading

class Root(object):
    def __init__(self):
        self.count = 0;
        self.lock = threading.Lock()

    @cherrypy.expose
    def app(self):
        with self.lock:
            self.count += 1
        return "Call #%d" % (self.count)

if __name__ == '__main__':
    cherrypy.quickstart(Root(), "/", {"/": { "tools.staticdir.on": True,
                                             "tools.staticdir.dir": os.getcwd() } })

This is a very simple application with some state protected by a mutex. Here is index.html:

<!doctype html>
<script src=http://code.jquery.com/jquery-1.8.2.js></script>
<script src=index.js></script>

(It's ok for the HTML to be this sparse - see this talk from Paul Irish) Here is index.js:

function request() {
    var cb = function (response) {
        console.log(response);
    };

    $.ajax({
        url: "/app",
        success: cb
    });
}

function go_slow(N, delay) {
    if (N > 0) {
        request();
        window.setTimeout(go_slow, delay, N - 1, delay);
    }
}

function go_fast(N) {
    var i;
    for (i = 0; i < N; i++) {
        request();
    }
}

window.onload = function () {
    //go_slow(100, 0);
    go_fast(100);
};

All of these files should go in the same directory. When I start the CherryPy server and then visit http://localhost:8080/index.html, the console shows the phrase "Call #1" 100 times, and the CherryPy log shows one GET request to "/app". In Firefox, I see several consecutive console messages, showing "#1" through "#100". The Firefox behavior is what I expected, because I made 100 explicit ajax requests, and the function associated to these requests is supposed to return a different result each time.

If instead of go_fast() I call go_slow() - a variant that uses "trampolining" (I think it's called) to force the ajax requests to be emitted from separate function calls at different times - then I get the "#1" through "#100" behavior on both Chrome and Firefox.

Finally, if I modify the app() method in the CherryPy server to accept an argument which it then ignores, like this (note the i argument that doesn't appear anywhere else):

@cherrypy.expose
def app(self, i):
    with self.lock:
        self.count += 1
    return "Call #%d" % (self.count)

and I arrange for the go_fast() function to make the ajax request to "/app/" + i" (where i is the loop index) instead of just "/app", by changing request() and go_fast() like this:

function request(i) {
    var cb = function (response) {
        console.log(response);
    };

    $.ajax({
        url: "/app/" + i,
        success: cb
    });
}

function go_fast(N) {
    var i;
    for (i = 0; i < N; i++) {
        request(i);
    }
}

then I again get the "#1" through "#100" behavior. If instead I modify the function to use, e.g., "/app/7" as the URL (i.e., replace "/app/" + i in the snippet above with "/app/7"), I get 100 repetitions of "Call #1" as in the initial example.

To me it looks a lot like something is "caching" the result of the one and only ajax request that was actually made in the initial case (where I only saw "Call #1" 100 times). The "Network" tab in Chrome's console just shows the one ajax request receiving a status code of "200 OK" and as far as I know, you have to explicitly enable server-side caching in CherryPy. There is also the curiosity that Firefox gives the expected behavior in this case.

In the other cases, for one reason or another, this "caching" mechanism is defeated. Trampolining might cause the browser to toss out the immediate context of the ajax request, preventing it from "remembering" that a request to the same URL was made previously, while contriving the URL to require a positional argument simply gives each request a unique URL, forcing an actual request to go out, rather than using any caching mechanism.

Can anyone explain concretely what's going on here? Is this simply a peculiarity about about how Chrome handles many ajax requests in a short time frame? Or is this situation a fatal problem with having stateful ajax resources?

Roni Choudhury
  • 486
  • 4
  • 15
  • The important part is probably *how* you modified `go_fast()` to make the Ajax request to `"/app" + i` :) Could you add that, please? – Ry- Sep 29 '13 at 23:10
  • Try adding `cache: false` to the AJAX options. – Barmar Sep 29 '13 at 23:20
  • @minitech, added the modifications. Let me know if you need more details! – Roni Choudhury Sep 30 '13 at 14:24
  • @Barmar, strangely enough, when I add `cache: false` to the options, I now get repeated messages in groups of one, two, or three (and sometimes even four). I.e., I might get "Call #27" followed by two "Call #28"s and then three "Call #29"s. (I also had to modify the `app()` method in the server to accept keyword dict arguments) – Roni Choudhury Sep 30 '13 at 14:26
  • Your `return "Call #%d" % (self.count)` isn’t inside the lock block… defeats the point of locking a bit. I think that’s your problem in the first case, but I’m not sure about the second. – Ry- Sep 30 '13 at 14:35
  • I have the lock there to make the increment to `self.count` atomic - does the return have to be part of that atomic operation? – Roni Choudhury Sep 30 '13 at 14:40

1 Answers1

0

I think that this is a race condition in combination with the cache: false option on the client side, remember that your object Root is shared inside a thread pool.

On time A you modify self.count and on time A another X requests (threads) are returning you newly modified parameter they were on time A - 1 on the with block and didn't return that new count on this particular request.

When the request that is modifying and getting out of the with statement another is already on the return so what determines the repetition or absence of the numbers returned is the processing throughput of cherrypy's thread pool.

cyraxjoe
  • 5,661
  • 3
  • 28
  • 42