Hi Nick,
Task schedule delays (best effort) are expected but this is not the case.
Take a look at the log excerpt below which shows a task with 6 reties.
Retries are perfectly timed on flat 20sec back off schedule. In other words
I have never seen task reties follow what I put in my queue.yaml. Instead
they *always* do 20 sec backoff.
Another fact that might help is this has not changed at all with SDK 1.4.0
release. This picture was exactly the same before the release.
My queue.yaml
queue:
- name: default
rate: 20/s
bucket_size: 100
retry_parameters:
task_age_limit: 120s
min_backoff_seconds: 1
max_backoff_seconds: 7
1.
1. 12-14 11:56PM 14.864 /_ah/queue/deferred 500 71ms 63cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E457E2BF5.5CB32920&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:56:14 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=71 cpu_ms=63 api_cpu_ms=17 cpm_usd=0.001856 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:56PM 14.867 X-Appengine-Taskretrycount:6,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:56PM 14.868 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. I 12-14 11:56PM 14.921
Hand=aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw,
state=playing, table=Medes (aglhY2UtcG9rZXJyDQsSBVRhYmxlGPODOAw)
5. I 12-14 11:56PM 14.921 pre-action-dealer (force-fold)
2.
1. 12-14 11:56PM 14.864 /_ah/queue/deferred 500 71ms 63cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E457E2BF5.5CB32920&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:56:14 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=71 cpu_ms=63 api_cpu_ms=17 cpm_usd=0.001856 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:56PM 14.867
X-Appengine-Taskretrycount:6, X-Appengine-Queuename:default,
X-Appengine-Taskname:9640193529655285671, X-Appengine-Current-Namespace:
3. I 12-14 11:56PM 14.868
running task: {'player': 'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM',
'action': 'force-fold', 'who': 'dealer', 'type': 'action', 'hand-snapshot':
u'flop-50-chj8szUM', 'hand':
'aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw'}
4. I 12-14 11:56PM 14.921
Hand=aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw, state=playing,
table=Medes (aglhY2UtcG9rZXJyDQsSBVRhYmxlGPODOAw)
5. I 12-14 11:56PM 14.921
pre-action-dealer (force-fold)
6. I 12-14 11:56PM 14.921
pre-action: (force-fold) pot=50 round=flop board=[u'Td', u'Ac', u'Ad']
current_bet=0 next_to_act=0
players:
aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM: bet=0 total=10 acted=False
in-game=True
aglhY2UtcG9rZXJyDgsSBlBsYXllchispDUM: bet=0 total=10 acted=False
in-game=True
7. I 12-14 11:56PM 14.928
notify-multi: ['hjygzgM-33', 'hixwjgM-33', 'hiZyjgM-33', 'hiLhTUM-33',
'hispDUM-33', 'hj8szUM-33', 'bserver-33']
8. I 12-14 11:56PM 14.928
{'pot': 50L, 'who': 'dealer', 'hand':
'aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw', 'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'type':
'action', 'stack': 1685L, 'hand-snapshot': u'flop-50-chj8szUM'}
9. D 12-14 11:56PM 14.928
hand action: {'pot': 50L, 'who': 'dealer', 'hand':
datastore_types.Key.from_path(u'Table', 918003L, u'Hand', 330015L,
_app=u'ace-poker'), 'player': datastore_types.Key.from_path(u'Player', 875004L,
_app=u'ace-poker'), 'action': 'force-fold', 'type': 'action', 'stack': 1685L,
'hand-snapshot': 'flop-50-chj8szUM'}
10. I 12-14 11:56PM 14.928
hand = aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw, betting
finished, round = flop
11. I 12-14 11:56PM 14.929
showdown among 4 players
12. E 12-14 11:56PM 14.931
datastore_types.Key.from_path(u'Player', 926001L, _app=u'ace-poker')
Traceback (most recent call last):
File
"/base/python_runtime/python_lib/versions/1/google/appengine/ext/webapp/__init__.py",
line 517, in __call__
handler.post(*groups)
File
"/base/python_runtime/python_lib/versions/1/google/appengine/ext/deferred/deferred.py",
line 258, in post
run(self.request.body)
File
"/base/python_runtime/python_lib/versions/1/google/appengine/ext/deferred/deferred.py",
line 124, in run
return func(*args, **kwds)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
681, in dispatch_task
execute_request(req)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
707, in execute_request
rsp = HandEngine().execute(msg)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
301, in execute
rsp = self.dealer_action_transactional( act)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
336, in dealer_action_transactional
return db.run_in_transaction(_txn)
File
"/base/python_runtime/python_lib/versions/1/google/appengine/api/datastore.py",
line 1981, in RunInTransaction
DEFAULT_TRANSACTION_RETRIES, function, *args, **kwargs)
File
"/base/python_runtime/python_lib/versions/1/google/appengine/api/datastore.py",
line 2067, in RunInTransactionCustomRetries
ok, result = _DoOneTry(new_connection, function, args, kwargs)
File
"/base/python_runtime/python_lib/versions/1/google/appengine/api/datastore.py",
line 2088, in _DoOneTry
result = function(*args, **kwargs)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
332, in _txn
rsp = self.action_dealer(action['action'], action)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
423, in action_dealer
act_rsp = self.action(req['player'], req)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
460, in action
self.showdown()
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
594, in showdown
self._showdown(pot.players, pot.pot)
File
"/base/data/home/apps/ace-poker/1-04-alpha.346925832780397423/engine.py", line
607, in _showdown
winning_hand = card.PokerHand(ha.pd[winner].cards + ha.board)
KeyError: datastore_types.Key.from_path(u'Player', 926001L,
_app=u'ace-poker')
3.
1. 12-14 11:55PM 54.860 /_ah/queue/deferred 500 49ms 40cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E444C9953.A6E13C57&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:55:54 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=49 cpu_ms=40 api_cpu_ms=17 cpm_usd=0.001208 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:55PM 54.863 X-Appengine-Taskretrycount:5,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:55PM 54.863 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. I 12-14 11:55PM 54.894
Hand=aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw,
state=playing, table=Medes (aglhY2UtcG9rZXJyDQsSBVRhYmxlGPODOAw)
5. I 12-14 11:55PM 54.894 pre-action-dealer (force-fold)
4.
1. 12-14 11:55PM 34.847 /_ah/queue/deferred 500 50ms 86cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E431B3F4F.89F091A0&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:55:34 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=51 cpu_ms=87 api_cpu_ms=17 cpm_usd=0.002504 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:55PM 34.850 X-Appengine-Taskretrycount:4,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:55PM 34.850 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. I 12-14 11:55PM 34.882
Hand=aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw,
state=playing, table=Medes (aglhY2UtcG9rZXJyDQsSBVRhYmxlGPODOAw)
5. E 12-14 11:55PM 34.893 datastore_types.Key.from_path(u'Player',
926001L, _app=u'ace-poker') Traceback (most recent call last): File
"/base/python_runtime/python_lib/versio
5.
1. 12-14 11:55PM 14.841 /_ah/queue/deferred 500 50ms 63cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E41E9F74F.038495A2&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:55:14 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=50 cpu_ms=63 api_cpu_ms=17 cpm_usd=0.001856 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:55PM 14.844 X-Appengine-Taskretrycount:3,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:55PM 14.844 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. E 12-14 11:55PM 14.886 datastore_types.Key.from_path(u'Player',
926001L, _app=u'ace-poker') Traceback (most recent call last): File
"/base/python_runtime/python_lib/versio
6.
1. 12-14 11:54PM 54.975 /_ah/queue/deferred 500 52ms 86cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E40BADD01.24C0582E&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:54:55 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=52 cpu_ms=87 api_cpu_ms=17 cpm_usd=0.002504 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:54PM 54.978 X-Appengine-Taskretrycount:2,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:54PM 54.978 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. I 12-14 11:54PM 55.010
Hand=aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw,
state=playing, table=Medes (aglhY2UtcG9rZXJyDQsSBVRhYmxlGPODOAw)
5. E 12-14 11:54PM 55.021 datastore_types.Key.from_path(u'Player',
926001L, _app=u'ace-poker') Traceback (most recent call last): File
"/base/python_runtime/python_lib/versio
7.
1. 12-14 11:54PM 34.825 /_ah/queue/deferred 500 50ms 40cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E3F87616D.4C5A5557&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:54:34 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=51 cpu_ms=40 api_cpu_ms=17 cpm_usd=0.001208 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:54PM 34.828 X-Appengine-Taskretrycount:1,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:54PM 34.828 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. E 12-14 11:54PM 34.870 datastore_types.Key.from_path(u'Player',
926001L, _app=u'ace-poker') Traceback (most recent call last): File
"/base/python_runtime/python_lib/versio
8.
1. 12-14 11:54PM 14.821 /_ah/queue/deferred 500 59ms 86cpu_ms
16api_cpu_ms 0kb AppEngine-Google; (+http://code.google.com/appengine)
See
details<https://appengine.google.com/logs/log_detail?app_id=ace-poker&version_id=1-04-alpha.346925832780397423&request_id=0004976E3E564859.5897B878&layout=plain>
0.1.0.2 - - [14/Dec/2010:23:54:14 -0800] "POST /_ah/queue/deferred
HTTP/1.1" 500 124 "http://ace-poker.appspot.com/_ah/queue/deferred";
"AppEngine-Google; (+http://code.google.com/appengine)" "ace-poker.appspot.com"
ms=60 cpu_ms=87 api_cpu_ms=17 cpm_usd=0.002504 queue_name=default
task_name=9640193529655285671
2. I 12-14 11:54PM 14.824 X-Appengine-Taskretrycount:0,
X-Appengine-Queuename:default, X-Appengine-Taskname:9640193529655285671,
X-Appengine-Current-Namespace:
3. I 12-14 11:54PM 14.824 running task: {'player':
'aglhY2UtcG9rZXJyDgsSBlBsYXllchj8szUM', 'action': 'force-fold', 'who':
'dealer', 'type': 'action', 'hand-snapshot': u'flop-50
4. I 12-14 11:54PM 14.861
Hand=aglhY2UtcG9rZXJyGQsSBVRhYmxlGPODOAwLEgRIYW5kGJ-SFAw,
state=playing, table=Medes (aglhY2UtcG9rZXJyDQsSBVRhYmxlGPODOAw)
5. E 12-14 11:54PM 14.875 datastore_types.Key.from_path(u'Player',
926001L, _app=u'ace-poker') Traceback (most recent call last): File
"/base/python_runtime/python_lib/versio
9.
1.
--
You received this message because you are subscribed to the Google Groups
"Google App Engine" group.
To post to this group, send email to [email protected].
To unsubscribe from this group, send email to
[email protected].
For more options, visit this group at
http://groups.google.com/group/google-appengine?hl=en.
