Add GAE Shutdown Handler #2976

waprin · 2017-01-31T02:06:00Z

Very rough draft (no tests/docs, it's messy) etc, to get feedback on overall direction from @karan and whoever will review for this repo.

This is a feature for App Engine Flex customers to get more post-mortem logs on VM shutdown. In theory it could be generalized but it's been spec-ed out to be very GAE specific so currently code just checks for that.

Due to lack of MonitoredResource support (see #2673) this currently uses the client.logging_api directly. This could be changed if the ability to specific monitoredresource gets added to the higher level API.

karan

I'm hoping someone who owns the repo also reviews this for style/testing.

logging/google/cloud/logging/_shutdown.py

+
+
+def _get_gae_instance():
+    return _fetch_metadata('instance/attributes/gae_backend_instance')


logging/google/cloud/logging/_shutdown.py

+
+
+def _get_gae_backend():
+    return _fetch_metadata('instance/attributes/gae_backend_name')


logging/google/cloud/logging/_shutdown.py

+
+
+def _get_gae_version():
+    return _fetch_metadata('instance/attributes/gae_backend_version')


logging/google/cloud/logging/_shutdown.py

+
+    entries = [entry]
+
+    client.logging_api.write_entries(


lukesneeringer

So, if I understand this correctly, the idea is that you can call client.enable_shutdown_logging(), and if you are on AppEngine, logs get sent on SIGTERM?

If that is correct, then the overall direction seems fine to me. I have a couple nitpicks with particulars of your implementation (see comments) but no major issues with what you are trying to do.

logging/google/cloud/logging/client.py

+        :param log_level: (Optional) When true, on SIGTERM the application
+                          will log the stacktrace of all running threads.
+        """
+        if thread_dump:


logging/google/cloud/logging/_shutdown.py

+    :param client: Stackdriver logging client.
+    """
+    if not _is_on_appengine():
+        raise Exception('Shutdown reporting is only supported on App Engine '


waprin · 2017-02-24T20:05:11Z

@dhermes @karan ready for review. I didn't put anything in the usage docs yet, felt a little too niche.

lukesneeringer · 2017-02-25T02:33:45Z

It looks fine to me, but hoping @dhermes will take a pass also before we merge it.

waprin · 2017-02-28T21:25:36Z

Addresses #2819

lukesneeringer · 2017-02-28T22:08:54Z

Officially assigning @dhermes for review; I forgot to the first time.

waprin · 2017-03-01T22:10:09Z

@dhermes ping

logging/google/cloud/logging/_environment_vars.py

@@ -0,0 +1,26 @@
+# Copyright 2017 Google Inc.


logging/google/cloud/logging/_shutdown.py

+
+
+# Maximum size in bytes to send to Stackdriver Logging in one entry
+MAX_PAYLOAD_SIZE = 1024 * 100


logging/google/cloud/logging/_shutdown.py

+
+def _get_gae_instance():
+    """Returns the App Engine Flexible instance."""
+    return os.getenv('GAE_INSTANCE')


logging/google/cloud/logging/_shutdown.py

+
+def _get_gae_service():
+    """Returns the App Engine Flexible service."""
+    return os.getenv('GAE_SERVICE')


logging/google/cloud/logging/_shutdown.py

+
+def _get_gae_version():
+    """Returns the App Engine Flexible version."""
+    return os.getenv('GAE_VERSION')


logging/google/cloud/logging/_shutdown.py

+
+
+def _report_stacktraces(
+        client, signal_, frame):  # pylint: disable=unused-argument


logging/google/cloud/logging/_shutdown.py

+    :param frame: The current stack frame.
+    """
+    traces = ''
+    for thread_id, stack in sys._current_frames().items():


logging/google/cloud/logging/_shutdown.py

+        'appengine.googleapis.com/module_id': gae_service,
+    }
+
+    split_payloads = _split_entry(text_payload.encode('utf-8'))


logging/google/cloud/logging/_shutdown.py

+    :type frame: frame object
+    :param frame: The current stack frame.
+    """
+    traces = ''


logging/google/cloud/logging/_shutdown.py

+        raise RuntimeError('Shutdown reporting is only supported on App '
+                           'Engine flexible environment.')
+    signal.signal(
+        signal.SIGTERM, functools.partial(_report_stacktraces, client))


waprin · 2017-03-02T21:31:12Z

wow good to know difference between += and append there. Others comments were just me forgetting to run lint all done.

waprin · 2017-03-02T21:54:37Z

Agreed I can add a test for that but have to head to GDG at the moment.

waprin · 2017-03-03T18:06:11Z

@dhermes sorry for delay got pulled into that conference rest of yesterday.

So it turns out that my tests weren't that bad because the function behavior was still correct, since the last line of the function joins the entire list into one big string at the end, it's irrelevant whether the strings get broken up in the interim. Obviously sloppy to mix += and append like that but just noting end result was the same.

Since I took a look at the test anyway I did try to make it check a bit more with a regex rather than just looking for a function name.

waprin · 2017-03-06T22:52:04Z

@dhermes ping

logging/google/cloud/logging/_environment_vars.py

+"""Environment variable set in App Engine when env:flex is set."""
+
+
+_CONTAINER_ENGINE_ENV = 'KUBERNETES_SERVICE'


logging/google/cloud/logging/_shutdown.py

+
+
+def _report_stacktraces(
+        client, signal_, frame):  # pylint: disable=unused-argument


logging/google/cloud/logging/_shutdown.py

+        raise RuntimeError('Shutdown reporting is only supported on App '
+                           'Engine flexible environment.')
+    signal.signal(
+        signal.SIGTERM, functools.partial(_report_stacktraces, client))


logging/unit_tests/test__shutdown.py

+import mock
+
+
+class Test_setup_shutdown_stracktrace_reporting(unittest.TestCase):


logging/unit_tests/test__shutdown.py

+            setup_stacktrace_crash_report)
+        return setup_stacktrace_crash_report(request)
+
+    def test_setup_shutdown_stacktrace_reporting_no_gae(self):


logging/unit_tests/test__shutdown.py

+
+        expected_payload = 'myversion\nThread traces\n{}'.format(
+            trace).encode('utf-8')
+        self.assertEqual(called[0][0], [{'text_payload': expected_payload}])


logging/unit_tests/test__shutdown.py

+        self.assertEqual(called[0][0], [{'text_payload': expected_payload}])
+
+
+class Test_report_stacktraces(unittest.TestCase):


logging/unit_tests/test__shutdown.py

+        patch = mock.patch(
+            'google.cloud.logging._shutdown._write_stacktrace_log')
+        with patch as write_log_mock:
+            self._call_fut(mock.Mock(), mock.Mock(), mock.Mock())


logging/unit_tests/test__shutdown.py

+        )
+        return _report_stacktraces(client, signal, frame)
+
+    def test_report_stacktraces(self):


logging/unit_tests/test_client.py

@@ -632,6 +632,20 @@ def test_setup_logging(self):

        setup_logging.assert_called()

+    def test_enable_shutdown_logging(self):


waprin · 2017-03-07T21:20:32Z

@dhermes comments addressed and rebased

re: it belonging in the library, I could see it going either way, hopefully in future we can figure those things out in issue tracker ( #2819 ) before PR.

lukesneeringer · 2017-03-08T15:25:29Z

I'm on the fence on how to feel about a "very specific use case" as it pertains to this library. Would be interested in what @jonparrott and @lukesneeringer think.

~~My feeling on monitoring is basically "defer to @waprin when it comes to what he thinks he needs".~~

After talking with @dhermes, I actually do have a few concerns here. My understanding (correct me if I am wrong on this) is that this only works in GAE, and throws an error elsewhere? That seems to violate principle of least surprise for the majority of users, who will be using this outside GAE.

At minimum, can we set this up in a way to hold non-GAE users harmless?

logging/google/cloud/logging/_shutdown.py

+from google.cloud.logging._environment_vars import GAE_VERSION
+from google.cloud import _helpers
+
+import six


logging/google/cloud/logging/client.py

+
+        :type thread_dump: bool
+        :param thread_dump: (Optional) When true, on SIGTERM the application
+                          will log the stacktrace of all running threads.


logging/google/cloud/logging/client.py

+        .. note::  This method is only supported on App Engine Flexible.
+
+        This method installs a SIGTERM handler that will report various
+        application metrics to Stackdriver Logging.


logging/google/cloud/logging/_shutdown.py

+                  handler.
+    """
+    traces = []
+    for thread_id, stack in sys._current_frames().items():


waprin · 2017-03-20T19:05:11Z

Based on offline convo going to close this PR and relocate it to https://github.com/googlecloudplatform/stackdriver-python (OOO this week but starting that migration when I return).

googlebot added the cla: yes This human has signed the Contributor License Agreement. label Jan 31, 2017

karan suggested changes Jan 31, 2017

View reviewed changes

lukesneeringer reviewed Feb 14, 2017

View reviewed changes

waprin force-pushed the shutdown_logs branch 2 times, most recently from 576cfd4 to 4985c5b Compare February 23, 2017 23:26

waprin changed the title ~~[ROUGH DRAFT] Add GAE Shutdown Handler~~ Add GAE Shutdown Handler Feb 24, 2017

lukesneeringer requested a review from dhermes February 28, 2017 22:08

dhermes reviewed Mar 1, 2017

View reviewed changes

dhermes reviewed Mar 7, 2017

View reviewed changes

Bill Prin added 12 commits March 7, 2017 13:03

[ROUGH DRAFT] Add GAE Shutdown Handler

a4a1194

add metadata header

ca8a52d

reviews and tests

e8f760f

Style issues

3a8376c

Fix tests

5327583

Make environ private

a98bc91

dhermes review

16d41ac

fix tests

a289db4

dhermes review

39fe642

fix append

0a1fc9d

dhermes review

c7dcbfa

dhermes review

4a902cb

waprin force-pushed the shutdown_logs branch from 68f7f3e to 4a902cb Compare March 7, 2017 21:03

dhermes reviewed Mar 8, 2017

View reviewed changes

logging/google/cloud/logging/_shutdown.py

from google.cloud.logging._environment_vars import GAE_VERSION

from google.cloud import _helpers

import six

This comment was marked as spam.

Sign in to view

dhermes reviewed Mar 8, 2017

View reviewed changes

tseaver added the api: logging Issues related to the Cloud Logging API. label Mar 15, 2017

waprin closed this Mar 20, 2017



		def _get_gae_instance():
		return _fetch_metadata('instance/attributes/gae_backend_instance')



		def _get_gae_backend():
		return _fetch_metadata('instance/attributes/gae_backend_name')



		def _get_gae_version():
		return _fetch_metadata('instance/attributes/gae_backend_version')



		# Maximum size in bytes to send to Stackdriver Logging in one entry
		MAX_PAYLOAD_SIZE = 1024 * 100



		def _report_stacktraces(
		client, signal_, frame): # pylint: disable=unused-argument

		"""Environment variable set in App Engine when env:flex is set."""


		_CONTAINER_ENGINE_ENV = 'KUBERNETES_SERVICE'

		import mock


		class Test_setup_shutdown_stracktrace_reporting(unittest.TestCase):

		self.assertEqual(called[0][0], [{'text_payload': expected_payload}])


		class Test_report_stacktraces(unittest.TestCase):

		@@ -632,6 +632,20 @@ def test_setup_logging(self):

		setup_logging.assert_called()

		def test_enable_shutdown_logging(self):

Add GAE Shutdown Handler #2976

Add GAE Shutdown Handler #2976

Conversation

waprin commented Jan 31, 2017

karan left a comment

Choose a reason for hiding this comment

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

lukesneeringer left a comment

Choose a reason for hiding this comment

This comment was marked as spam.

This comment was marked as spam.

waprin commented Feb 24, 2017

lukesneeringer commented Feb 25, 2017

waprin commented Feb 28, 2017

lukesneeringer commented Feb 28, 2017

waprin commented Mar 1, 2017

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

waprin commented Mar 2, 2017

waprin commented Mar 2, 2017

waprin commented Mar 3, 2017

waprin commented Mar 6, 2017

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

waprin commented Mar 7, 2017

lukesneeringer commented Mar 8, 2017 • edited Loading

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

waprin commented Mar 20, 2017

lukesneeringer commented Mar 8, 2017 •

edited

Loading