googlearchive / simian

Simian is an enterprise-class Mac OS X software deployment solution. Google App Engine hosted server, with a client powered by the Munki open-source project.
Apache License 2.0
332 stars 51 forks source link

Loading Apple Updates > Catalogue Admin stalls and returns an error #36

Open Rumbles opened 8 years ago

Rumbles commented 8 years ago

I installed Simian last week to test it, today I was writing up documentation on how I set it up and the Apple Updates page wouldn't load. In the browser I get:

Traceback (most recent call last):
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 267, in Handle
    result = handler(dict(self._environ), self._StartResponse)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1529, in __call__
    rv = self.router.dispatch(request, response)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1278, in default_dispatcher
    return route.handler_adapter(request, response)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1102, in __call__
    return handler.dispatch()
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 570, in dispatch
    return method(*args, **kwargs)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/admin/applesus.py", line 186, in get
    self._DisplayMain()
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/admin/applesus.py", line 204, in _DisplayMain
    p.testing_promote_date = applesus.GetAutoPromoteDate(common.TESTING, p)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/common/applesus.py", line 306, in GetAutoPromoteDate
    if not settings.APPLE_AUTO_PROMOTE_ENABLED:
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/settings.py", line 382, in __getattr__
    return self._Get(str(k).lower())
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/settings.py", line 805, in _Get
    item, unused_mtime = self._module.models.Settings.GetItem(k)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/models/settings.py", line 274, in GetItem
    value, mtime = cls.GetSerializedItem(name)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/models/base.py", line 734, in GetSerializedItem
    entity = cls.MemcacheWrappedGet(key)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/models/base.py", line 141, in MemcacheWrappedGet
    cached = memcache.get(memcache_key)
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/memcache/__init__.py", line 560, in get
    results = rpc.get_result()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 613, in get_result
    return self.__get_result_hook(self)
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/memcache/__init__.py", line 616, in __get_hook
    rpc.check_success()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 584, in check_success
    self.__stubmap.GetPostCallHooks().Call(self.__service, self.__method,
DeadlineExceededError: The overall deadline for responding to the HTTP request was exceeded.

Looking at this in the AppEngine console, I get the following:

Traceback (most recent call last):
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 267, in Handle
    result = handler(dict(self._environ), self._StartResponse)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1529, in __call__
    rv = self.router.dispatch(request, response)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1278, in default_dispatcher
    return route.handler_adapter(request, response)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1102, in __call__
    return handler.dispatch()
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 570, in dispatch
    return method(*args, **kwargs)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/admin/applesus.py", line 186, in get
    self._DisplayMain()
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/admin/applesus.py", line 204, in _DisplayMain
    p.testing_promote_date = applesus.GetAutoPromoteDate(common.TESTING, p)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/common/applesus.py", line 306, in GetAutoPromoteDate
    if not settings.APPLE_AUTO_PROMOTE_ENABLED:
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/settings.py", line 382, in __getattr__
    return self._Get(str(k).lower())
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/settings.py", line 805, in _Get
    item, unused_mtime = self._module.models.Settings.GetItem(k)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/models/settings.py", line 274, in GetItem
    value, mtime = cls.GetSerializedItem(name)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/models/base.py", line 734, in GetSerializedItem
    entity = cls.MemcacheWrappedGet(key)
  File "/base/data/home/apps/e~thefloow-simian/f8bfa254267e.393014033104675667/simian/mac/models/base.py", line 141, in MemcacheWrappedGet
    cached = memcache.get(memcache_key)
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/memcache/__init__.py", line 560, in get
    results = rpc.get_result()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 613, in get_result
    return self.__get_result_hook(self)
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/memcache/__init__.py", line 616, in __get_hook
    rpc.check_success()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 577, in check_success
    self.wait()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 556, in wait
    assert self.__rpc.state == apiproxy_rpc.RPC.FINISHING, repr(self.state)
DeadlineExceededError: The overall deadline for responding to the HTTP request was exceeded.

On one of the errors I've managed to generate in AppEngine I got the following (none of the others I have seen reported this):

This request caused a new process to be started for your application, and thus caused your application code to be loaded for the first time. This request may thus take longer and use more CPU than a typical request for your application.

I've waited over an hour for this code to finish running, but it still loads the same/similar error.

When I first ran in to this issue, I did try running make release again just in case something was wrong with my deployment, but I get the same issue. I checked I was on the latest branch at the time.

Rumbles commented 8 years ago

I checked this page a few times since I raised this bug - each time the page failed to load, today I checked and the page loaded after a long delay, it would be good if there was some more information as to why the page didn't load when the backend times out

aryanet commented 8 years ago

I am having the same problem and I experience what Rumbles is saying. I also get the following stack trace during preflight --debug run:

DEBUG:root:MunkiDownloadError getting Apple SUS catalog: HTTP result 404: not found Traceback (most recent call last): File "/usr/local/munki/simian/lib/python2.7/site-packages/simian-2.4-py2.7.egg/simian/mac/client/flight_common.py", line 538, in GetAppleSUSCatalog '%s/applesus/' % url, APPLE_SUS_CATALOG) File "/usr/local/munki/munkilib/updatecheck.py", line 3519, in getResourceIfChangedAtomically verify=verify) File "/usr/local/munki/munkilib/fetch.py", line 300, in getResourceIfChangedAtomically message=message, resume=resume, follow_redirects=follow_redirects) File "/usr/local/munki/munkilib/fetch.py", line 413, in getHTTPfileIfChangedAtomically raise GurlDownloadError(err) GurlDownloadError: HTTP result 404: not found

maximermilov commented 8 years ago

I am having the same problem and I experience what Rumbles is saying.

Long delays and occasional timeouts are due to F1 instance class by default. You can change it in app.yaml. Recommended instance class is F4, but it will cost more.

I also get the following stack trace during preflight --debug run:

Seems, Client is misconfigured. Did you follow https://github.com/google/simian/wiki/Configuration ?

Thanks, Maxim

On Tue, Sep 13, 2016 at 8:48 PM, Arya Goudarzi notifications@github.com wrote:

I am having the same problem and I experience what Rumbles is saying. I also get the following stack trace during preflight --debug run:

DEBUG:root:MunkiDownloadError getting Apple SUS catalog: HTTP result 404: not found Traceback (most recent call last): File "/usr/local/munki/simian/lib/python2.7/site-packages/ simian-2.4-py2.7.egg/simian/mac/client/flight_common.py", line 538, in GetAppleSUSCatalog '%s/applesus/' % url, APPLE_SUS_CATALOG) File "/usr/local/munki/munkilib/updatecheck.py", line 3519, in getResourceIfChangedAtomically verify=verify) File "/usr/local/munki/munkilib/fetch.py", line 300, in getResourceIfChangedAtomically message=message, resume=resume, follow_redirects=follow_redirects) File "/usr/local/munki/munkilib/fetch.py", line 413, in getHTTPfileIfChangedAtomically raise GurlDownloadError(err) GurlDownloadError: HTTP result 404: not found

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/google/simian/issues/36#issuecomment-246872607, or mute the thread https://github.com/notifications/unsubscribe-auth/AOn0htUuge0G75_HLaXkQhtyViSe4X0xks5qp0R4gaJpZM4IleJP .

eelco commented 6 years ago

I’ve made a new setup and are also experiencing this problem. Possibly because the backlog of the catalog has to be processed all at once (there are a lot of Voice Updates in there)? I quickly hit the free limit of datastore read operations, but even with everything paid it’s still hanging. It seems to go through memcache, but nothing gets cached (only 5 items are in there, my current hit ratio is 0,02%)

Traceback (most recent call last):
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 267, in Handle
    result = handler(dict(self._environ), self._StartResponse)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1529, in __call__
    rv = self.router.dispatch(request, response)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1278, in default_dispatcher
    return route.handler_adapter(request, response)
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 1102, in __call__
    return handler.dispatch()
  File "/base/data/home/runtimes/python27/python27_lib/versions/third_party/webapp2-2.5.2/webapp2.py", line 570, in dispatch
    return method(*args, **kwargs)
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/mac/admin/applesus.py", line 180, in get
    self._DisplayMain()
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/mac/admin/applesus.py", line 198, in _DisplayMain
    p.testing_promote_date = applesus.GetAutoPromoteDate(common.TESTING, p)
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/mac/common/applesus.py", line 322, in GetAutoPromoteDate
    if not settings.APPLE_AUTO_PROMOTE_ENABLED:
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/settings.py", line 372, in __getattr__
    return self._Get(str(k).lower())
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/settings.py", line 800, in _Get
    item, unused_mtime = self._module.models.Settings.GetItem(k)
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/mac/models/settings.py", line 282, in GetItem
    value, mtime = cls.GetSerializedItem(name)
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/mac/models/base.py", line 685, in GetSerializedItem
    entity = cls.MemcacheWrappedGet(key)
  File "/base/data/home/apps/e~motif-simian/46fec3c1946e.405618737280548051/simian/mac/models/base.py", line 106, in MemcacheWrappedGet
    cached = memcache.get(memcache_key)
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/memcache/__init__.py", line 563, in get
    results = rpc.get_result()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 613, in get_result
    return self.__get_result_hook(self)
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/memcache/__init__.py", line 623, in __get_hook
    rpc.check_success()
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 585, in check_success
    self.request, self.response,
  File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/api/apiproxy_stub_map.py", line 471, in request
    return self.__rpc.request
DeadlineExceededError: The overall deadline for responding to the HTTP request was exceeded.
eelco commented 6 years ago

Pretty sure it’s this (6 year old) code: https://github.com/google/simian/blob/46fec3c1946efe77df67385c7f4eeb3fc25660ea/src/simian/mac/admin/applesus.py#L192-L199

You’ll only run into this on new installs, otherwise all the products would already have moved to “stable” and the (expensive) check is skipped.

This also means that new installs are completely broken for AppleSUS until more than a week has passed and all packages have been promoted?

eelco commented 6 years ago

If anybody else runs into this: I’ve now worked around this issue by temporarily making _ReadyToAutoPromote in src/simian/mac/cron/applesus.py always return True, deploying that, manually triggering the auto promote cron job and then deploying back the original version.