Note that there are some explanatory texts on larger screens.

plurals
  1. POHanging on last Backend (or Module) memcache writes until /_ah/stop
    primarykey
    data
    text
    <p>I have a batch processing Backend (B4) on python27 runtime with threading enabled. It does a bunch of unpickle/pickle and Numpy/array stuff. </p> <p>Recently I noticed that I was getting much higher backend charges, which would hit quota almost every time. I migrated to Modules (also B4), thinking that might solve it since I saw the "backends are being removed" notice. However, I still see the same issue. </p> <p>What seem to happen is that the code hangs on the last (always the last) memcache write until my quota has been drained. The moment the /_ah/stop call is made (because of quota) the backend wakes up again and resumes its processing, then exits because of the shutdown request.</p> <p>Here are all the relevant logs:</p> <pre> 2013-08-05 15:23:33.962 /BatchRankings 500 19413478ms 0kb instance=0 AppEngine-Google; (+http://code.google.com/appengine) I 2013-08-05 10:00:04.118 mem usage at start of meleerumble: 24.55078125MB ... lots more logs ... I 2013-08-05 10:01:03.550 split bots into 18 sections I 2013-08-05 15:23:03.086 wrote 564 bots to memcache E 2013-08-05 15:23:33.962 Process terminated because the backend took too long to shutdown. </pre> <p>Look at the timestamp between splitting and writing to memcache. Over 5 hours, when this should be taking a few seconds (and does with all of the other times this code is looped over).</p> <p>In addition, in my logs just below the actual request handler, I see this:</p> <pre>2013-08-05 15:23:02.938 /_ah/stop 200 5ms 0kb instance=0</pre> <p>So, from what I can tell, it looks like the backend hangs inside of the memcache writing, and the /_ah/stop wakes it up when I hit my quota.</p> <p>Here is the relevant code between those two logging points:</p> <pre><code> client = memcache.Client() if len(botsdict) > 0: splitlist = dict_split(botsdict,32) logging.info("split bots into " + str(len(splitlist)) + " sections") for d in splitlist: rpcList.append(client.set_multi_async(d)) logging.info("wrote " + str(len(botsdict)) + " bots to memcache") </code></pre> <p>I don't see how 18 set_multi_async calls can take 5h23m. Can the logs be trusted here? Could it be that the actual code is finished but somehow the exit never registered and the logging was the problem? I'm having to disable my backend processing because of this, since it just eats as much quota as I throw at it.</p> <p>Any help regarding what on earth is happening here would be much appreciated.</p>
    singulars
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    plurals
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
 

Querying!

 
Guidance

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload