#appengine Task Queueの放置タスクをGTalkで調べるbot作りました

DevFestのセッションに向けてTask Queueでの並列処理デモを作成してます。それをいじってる過程で気づいた挙動がありました：

• タスクを数個だけ（1〜3個くらい？）追加しとくと、数10秒〜数分ほったらかしにされることがある（以下、放置タスク）

で、この挙動をさらに詳しく調べるため、「GTalkからpingを打つと、HELLOと返事を返すタスクをTQに追加する」というbotを作ってみました。

• GTalkクライアントから「parallel@stillhouse-apps2.appspotchat.com」を友達に追加する
• 「ping」というメッセージを送る
• pingタスクがキューに積まれ、「Ping task added.」と返事が返る
  • spin-upしたときは、この返事が返るまで数秒かかる
• キューが実行されると「HELLO! Elapsed: 150ms」と返事が返る
  • Elapsed部分にはping受信時からの経過時刻が入る
• そのほか
  • 「ping xxx」とメッセージを送ると、TaskOptions.countdownMillis(xxx)が設定される（xxxは整数値、省略時は設定しない）
  • ソースはこちら

というものです。どなたでもお試しいただけます（いたづらはいやづら）。ってもみんなで使ってキューがそこそこあったまる？と現象消えたりして。

このツールでいろいろ挙動を調べてみましたが、よくわからんですw 以下のような感じ。。

• 放置タスク現象が出るときと出ないときがある。出るときは連続して発生する
• spin upにかかる時間は固定（数秒）なのに対し、放置タスクのほったらかし時間はは15s〜数分とまばら
• あるとき、現象が出ている状況でcountdownMillisを設定してみたら、現象が消えた（ように見えた。気のせいかも）（@shin1ogawaさんアドバイスthx!）しかし今日試したらもはや効果ないようで、「ping 1000」とは書いても2分以上も放置されたり。
• キューにタスクを100個とか積むような使い方では出ない様子（並列処理デモが長時間かかってしまうようなことはこれまで皆無）。キュー内のタスク数にも依存するのかな？

MLでも同様の指摘があった

という感じです。MLで探してみたら、同様の報告がありました。このレポートを信じれば、1.3.1以降の現象かもしれません（強調は私）：

• Task queue not starting the action when expected

Hello,

We have been using task queues for a few months without problem. We
handle actions that must execute right away.

At the time of the release of 1.3.1, we noticed that sometimes, some
tasks will take 1 to 2 minutes to start, but in the task queue, the
ETA shows as a date in the past (like 0:01:12 ago), usually 1 second
or so after the creation time.

This is not a consistent issue. I might works perfectly (task being
kicked in within 1 second of creation) for several times and suddenly,
the next task takes 1.5 minutes to get started.

Our task queue is empty when we see this issue.
Our queue is setup with a max rate of 5/s and a bucket size of 1.

Any idea of what we can do to work around or solve this new issue?

Jerome 

で、Ikaiさんは冷たく、

Tasks aren't guaranteed to execute immediately. Task queues execute when
there is capacity:
http://code.google.com/appengine/docs/python/taskqueue/overview.html#...

It may or may not be related to 1.3.1. What % of your requests see this
delay?

と言い放ってますが、これじゃETA設定してもなんにも意味ないじゃん。。現象起きてないときはきちんとETA前後で実行されるので、バグな気がします。

Issueにしてみた

既存のIssueを探してみましたがなさそうだったので、新しいIssueを作成しました：

http://code.google.com/p/googleappengine/issues/detail?id=2924