[google-appengine] Re: deadline errors for pages which normally load fast
I believe this problem was fixed about 10 hours ago. None of these errors
occurred overnight and I have had them day after day for a week or longer.
Also, pages which were loading in 18 secs to greater than 60 are back to
loading in 2 seconds when they are not cached.
Also, something significant changed with memcache at the same time.
I typically have about 98% hits but for the last week or so it was 67%
hits. I suspected a memcache issue but it was hard to prove. Now that the
hit ratio is back up for normal ranges I am convinced there has been a
memcache issue.
In any case, I am grateful these problems appear to have been fixed.
I wonder if it was version 1.8.7 ???
On Monday, November 4, 2013 4:19:41 PM UTC-8, James Gilliam wrote:
I am seeing deadline failures such as the one below -- 61 secs. Using
python 2.7, appid ogeekcom. Notice it doesn't say deadline error -- it
appears that somebody is broken in the GAE logging code but based on the 61
seconds I have come to believe it is a deadline failure.
Just loaded the same page in 208 ms.
Many times they are associated with a memcache set failure, but sometimes
other failures, e.g. blob url_serving error.
I use the 1 gig premium memcache even though I don't need nearly that much
cache and hate the cost at $90 a month.
I saw almost 40 of these errors overnight ... clustered around a couple of
times. When that happens, instances are created for each URL because the
request takes so long to finish ouch.
1. 2013-11-04 14:04:27.457 /viking-international-llc 500 61941ms 0kb
Mozilla/5.0
(compatible; Googlebot/2.1; +http://www.google.com/bot.html)
66.249.66.180 - - [04/Nov/2013:14:04:27 -0800] GET
/viking-international-llc HTTP/1.1 500 0 - Mozilla/5.0 (compatible;
Googlebot/2.1; +http://www.google.com/bot.html) www.goobafoo.com ms=61941
cpu_ms=3850 app_engine_release=1.8.6
instance=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
https://appengine.google.com/instances?app_id=s~ogeekcomversion_id=1383584138-1576.371403051099549606key=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f#00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
2. E2013-11-04 14:04:27.361
[data.cacheSave, except, memcache set failed, goobafoo,
goobafoo-goobafoo-landingview-landingid=viking-international-llc,
{p-landingid:1, p-offset:1, t-gallerys:1, t-landings:1}]
3. E2013-11-04 14:04:27.454
Traceback (most recent call last):
4. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/app_logging.py,
line 78, in emit
5. E2013-11-04 14:04:27.454
logservice.write(message)
6. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 348, in write
7. E2013-11-04 14:04:27.454
logs_buffer().write(message)
8. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 237, in write
9. E2013-11-04 14:04:27.454
return self._lock_and_call(self._write, line)
10. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 158, in _lock_and_call
11. E2013-11-04 14:04:27.454
return method(*args)
12. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 254, in _write
13. E2013-11-04 14:04:27.454
self._autoflush()
14. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 322, in _autoflush
15. E2013-11-04 14:04:27.454
self._flush()
16. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 308, in _flush
17. E2013-11-04 14:04:27.454
apiproxy_stub_map.MakeSyncCall('logservice', 'Flush', request,
response)
18. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 94, in MakeSyncCall
19. E2013-11-04 14:04:27.454
return stubmap.MakeSyncCall(service, call, request, response)
20. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 328, in MakeSyncCall
21. E2013-11-04 14:04:27.454
rpc.CheckSuccess()
22. E2013-11-04 14:04:27.454
File
[google-appengine] Re: deadline errors for pages which normally load fast
Spoke too soon ... just had another rash of these errors ... also GAE
flushed all the memcache again for my app ... second time today ... and
there is a PYTHON investigation reported as well.
On Monday, November 4, 2013 4:19:41 PM UTC-8, James Gilliam wrote:
I am seeing deadline failures such as the one below -- 61 secs. Using
python 2.7, appid ogeekcom. Notice it doesn't say deadline error -- it
appears that somebody is broken in the GAE logging code but based on the 61
seconds I have come to believe it is a deadline failure.
Just loaded the same page in 208 ms.
Many times they are associated with a memcache set failure, but sometimes
other failures, e.g. blob url_serving error.
I use the 1 gig premium memcache even though I don't need nearly that much
cache and hate the cost at $90 a month.
I saw almost 40 of these errors overnight ... clustered around a couple of
times. When that happens, instances are created for each URL because the
request takes so long to finish ouch.
1. 2013-11-04 14:04:27.457 /viking-international-llc 500 61941ms 0kb
Mozilla/5.0
(compatible; Googlebot/2.1; +http://www.google.com/bot.html)
66.249.66.180 - - [04/Nov/2013:14:04:27 -0800] GET
/viking-international-llc HTTP/1.1 500 0 - Mozilla/5.0 (compatible;
Googlebot/2.1; +http://www.google.com/bot.html) www.goobafoo.com ms=61941
cpu_ms=3850 app_engine_release=1.8.6
instance=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
https://appengine.google.com/instances?app_id=s~ogeekcomversion_id=1383584138-1576.371403051099549606key=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f#00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
2. E2013-11-04 14:04:27.361
[data.cacheSave, except, memcache set failed, goobafoo,
goobafoo-goobafoo-landingview-landingid=viking-international-llc,
{p-landingid:1, p-offset:1, t-gallerys:1, t-landings:1}]
3. E2013-11-04 14:04:27.454
Traceback (most recent call last):
4. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/app_logging.py,
line 78, in emit
5. E2013-11-04 14:04:27.454
logservice.write(message)
6. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 348, in write
7. E2013-11-04 14:04:27.454
logs_buffer().write(message)
8. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 237, in write
9. E2013-11-04 14:04:27.454
return self._lock_and_call(self._write, line)
10. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 158, in _lock_and_call
11. E2013-11-04 14:04:27.454
return method(*args)
12. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 254, in _write
13. E2013-11-04 14:04:27.454
self._autoflush()
14. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 322, in _autoflush
15. E2013-11-04 14:04:27.454
self._flush()
16. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 308, in _flush
17. E2013-11-04 14:04:27.454
apiproxy_stub_map.MakeSyncCall('logservice', 'Flush', request,
response)
18. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 94, in MakeSyncCall
19. E2013-11-04 14:04:27.454
return stubmap.MakeSyncCall(service, call, request, response)
20. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 328, in MakeSyncCall
21. E2013-11-04 14:04:27.454
rpc.CheckSuccess()
22. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_rpc.py,
line 133, in CheckSuccess
23. E2013-11-04 14:04:27.454
raise self.exception
24. E2013-11-04 14:04:27.454
CancelledError: The API call logservice.Flush() was explicitly cancelled.
25. E2013-11-04 14:04:27.454
Logged from file common.py, line 573
--
You received this message because you are subscribed to the Google Groups
Google App Engine group.
To unsubscribe from this group and stop
[google-appengine] Re: deadline errors for pages which normally load fast
more failures and another memcache flush at 4:28 PT ...
here's an idea GAE ... why don't you test your shit before pushing it out !
On Monday, November 4, 2013 4:19:41 PM UTC-8, James Gilliam wrote:
I am seeing deadline failures such as the one below -- 61 secs. Using
python 2.7, appid ogeekcom. Notice it doesn't say deadline error -- it
appears that somebody is broken in the GAE logging code but based on the 61
seconds I have come to believe it is a deadline failure.
Just loaded the same page in 208 ms.
Many times they are associated with a memcache set failure, but sometimes
other failures, e.g. blob url_serving error.
I use the 1 gig premium memcache even though I don't need nearly that much
cache and hate the cost at $90 a month.
I saw almost 40 of these errors overnight ... clustered around a couple of
times. When that happens, instances are created for each URL because the
request takes so long to finish ouch.
1. 2013-11-04 14:04:27.457 /viking-international-llc 500 61941ms 0kb
Mozilla/5.0
(compatible; Googlebot/2.1; +http://www.google.com/bot.html)
66.249.66.180 - - [04/Nov/2013:14:04:27 -0800] GET
/viking-international-llc HTTP/1.1 500 0 - Mozilla/5.0 (compatible;
Googlebot/2.1; +http://www.google.com/bot.html) www.goobafoo.com ms=61941
cpu_ms=3850 app_engine_release=1.8.6
instance=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
https://appengine.google.com/instances?app_id=s~ogeekcomversion_id=1383584138-1576.371403051099549606key=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f#00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
2. E2013-11-04 14:04:27.361
[data.cacheSave, except, memcache set failed, goobafoo,
goobafoo-goobafoo-landingview-landingid=viking-international-llc,
{p-landingid:1, p-offset:1, t-gallerys:1, t-landings:1}]
3. E2013-11-04 14:04:27.454
Traceback (most recent call last):
4. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/app_logging.py,
line 78, in emit
5. E2013-11-04 14:04:27.454
logservice.write(message)
6. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 348, in write
7. E2013-11-04 14:04:27.454
logs_buffer().write(message)
8. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 237, in write
9. E2013-11-04 14:04:27.454
return self._lock_and_call(self._write, line)
10. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 158, in _lock_and_call
11. E2013-11-04 14:04:27.454
return method(*args)
12. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 254, in _write
13. E2013-11-04 14:04:27.454
self._autoflush()
14. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 322, in _autoflush
15. E2013-11-04 14:04:27.454
self._flush()
16. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 308, in _flush
17. E2013-11-04 14:04:27.454
apiproxy_stub_map.MakeSyncCall('logservice', 'Flush', request,
response)
18. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 94, in MakeSyncCall
19. E2013-11-04 14:04:27.454
return stubmap.MakeSyncCall(service, call, request, response)
20. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 328, in MakeSyncCall
21. E2013-11-04 14:04:27.454
rpc.CheckSuccess()
22. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_rpc.py,
line 133, in CheckSuccess
23. E2013-11-04 14:04:27.454
raise self.exception
24. E2013-11-04 14:04:27.454
CancelledError: The API call logservice.Flush() was explicitly cancelled.
25. E2013-11-04 14:04:27.454
Logged from file common.py, line 573
--
You received this message because you are subscribed to the Google Groups
Google App Engine group.
To unsubscribe from this group and stop receiving emails from it, send an email
to
[google-appengine] Re: deadline errors for pages which normally load fast
GAE ... can you please stop flushing the cache during the middle of the day
... !
I am pay $90 a month for the premium memcache and you flushed it three
times today !
Come on !
On Monday, November 4, 2013 4:19:41 PM UTC-8, James Gilliam wrote:
I am seeing deadline failures such as the one below -- 61 secs. Using
python 2.7, appid ogeekcom. Notice it doesn't say deadline error -- it
appears that somebody is broken in the GAE logging code but based on the 61
seconds I have come to believe it is a deadline failure.
Just loaded the same page in 208 ms.
Many times they are associated with a memcache set failure, but sometimes
other failures, e.g. blob url_serving error.
I use the 1 gig premium memcache even though I don't need nearly that much
cache and hate the cost at $90 a month.
I saw almost 40 of these errors overnight ... clustered around a couple of
times. When that happens, instances are created for each URL because the
request takes so long to finish ouch.
1. 2013-11-04 14:04:27.457 /viking-international-llc 500 61941ms 0kb
Mozilla/5.0
(compatible; Googlebot/2.1; +http://www.google.com/bot.html)
66.249.66.180 - - [04/Nov/2013:14:04:27 -0800] GET
/viking-international-llc HTTP/1.1 500 0 - Mozilla/5.0 (compatible;
Googlebot/2.1; +http://www.google.com/bot.html) www.goobafoo.com ms=61941
cpu_ms=3850 app_engine_release=1.8.6
instance=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
https://appengine.google.com/instances?app_id=s~ogeekcomversion_id=1383584138-1576.371403051099549606key=00c61b117c74a9c539d5b4ef839de2da2a3a8a3f#00c61b117c74a9c539d5b4ef839de2da2a3a8a3f
2. E2013-11-04 14:04:27.361
[data.cacheSave, except, memcache set failed, goobafoo,
goobafoo-goobafoo-landingview-landingid=viking-international-llc,
{p-landingid:1, p-offset:1, t-gallerys:1, t-landings:1}]
3. E2013-11-04 14:04:27.454
Traceback (most recent call last):
4. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/app_logging.py,
line 78, in emit
5. E2013-11-04 14:04:27.454
logservice.write(message)
6. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 348, in write
7. E2013-11-04 14:04:27.454
logs_buffer().write(message)
8. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 237, in write
9. E2013-11-04 14:04:27.454
return self._lock_and_call(self._write, line)
10. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 158, in _lock_and_call
11. E2013-11-04 14:04:27.454
return method(*args)
12. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 254, in _write
13. E2013-11-04 14:04:27.454
self._autoflush()
14. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 322, in _autoflush
15. E2013-11-04 14:04:27.454
self._flush()
16. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/logservice/logservice.py,
line 308, in _flush
17. E2013-11-04 14:04:27.454
apiproxy_stub_map.MakeSyncCall('logservice', 'Flush', request,
response)
18. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 94, in MakeSyncCall
19. E2013-11-04 14:04:27.454
return stubmap.MakeSyncCall(service, call, request, response)
20. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py,
line 328, in MakeSyncCall
21. E2013-11-04 14:04:27.454
rpc.CheckSuccess()
22. E2013-11-04 14:04:27.454
File
/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_rpc.py,
line 133, in CheckSuccess
23. E2013-11-04 14:04:27.454
raise self.exception
24. E2013-11-04 14:04:27.454
CancelledError: The API call logservice.Flush() was explicitly cancelled.
25. E2013-11-04 14:04:27.454
Logged from file common.py, line 573
--
You received this message because you are subscribed to the Google Groups
Google App Engine group.
To unsubscribe from this group and stop receiving
[google-appengine] Re: deadline errors for pages which normally load fast
A few hours ago most of our python app went down all requests were timing out. (Our app has never been down before). I checked https://code.google.com/status/appengine/ and it said investigating for Memcache Python so they must have been having some issues. I'm not sure why there is a green tick there now. -- You received this message because you are subscribed to the Google Groups Google App Engine group. To unsubscribe from this group and stop receiving emails from it, send an email to google-appengine+unsubscr...@googlegroups.com. To post to this group, send email to google-appengine@googlegroups.com. Visit this group at http://groups.google.com/group/google-appengine. For more options, visit https://groups.google.com/groups/opt_out.
[google-appengine] Re: deadline errors for pages which normally load fast
Same here, up until yesterday our app was doing fine, and now it has high timeout rate. Regards. Janusz. -- You received this message because you are subscribed to the Google Groups Google App Engine group. To unsubscribe from this group and stop receiving emails from it, send an email to google-appengine+unsubscr...@googlegroups.com. To post to this group, send email to google-appengine@googlegroups.com. Visit this group at http://groups.google.com/group/google-appengine. For more options, visit https://groups.google.com/groups/opt_out.
