[core] Replace subprocess.Popen with safer get_subprocess_output #1892

JohnLZeller · 2015-09-03T21:46:10Z

Issue came up when investigating hostdown issues.
https://datadog.zendesk.com/agent/tickets/30510

It seems as though, periodically, a subprocess call hangs and ultimately causes the watchdog to reset the agent. During this period of time, there is then a host down event, followed by a host recovered event posted to the customers events page. We noticed that it seems as though the hanging happens in various checks (not the same for every host down event). Offending checks have included the customers own custom iostat check, as well as our own postfix check, and even resources/processes.py.

The theory is that this is caused by a hanging call to subprocess.Popen. There is a known issue where the use of a subprocess.PIPE for stdout (or even stderr) could cause the process to hang once the subprocess.PIPE fills up. The solution to this is to use get_subprocess_output() in our own utils/subprocess_output.py, which uses a file for stdout and stderr, removing such a low memory capacity issue.

To avoid further chasing this problem around the agent, this PR attempts to replace the use of subprocess.Popen anywhere it shows up in the agent with get_subprocess_output(). There are a few instances where further work will be needed to refactor the code in a clean way, and for those instances, I have added a FIXME note.

JohnLZeller · 2015-09-03T21:46:45Z

I have tested these on personal_chef, and fixed any issues that came up.

remh · 2015-09-03T21:50:45Z

checks.d/postfix.py

@@ -55,8 +57,13 @@ def _get_queue_count(self, directory, queues, tags):
                # can dd-agent user run sudo?
                test_sudo = os.system('setsid sudo -l < /dev/null')
                if test_sudo == 0:
-                    count = os.popen('sudo find %s -type f | wc -l' % queue_path)
-                    count = count.readlines()[0].strip()
+                    find = get_subprocess_output(['sudo', 'find', queue_path, '-type', 'f'], self.log)


the second command is

wc -l

so you can change this whole block with:

count = len(get_subprocess_output(['sudo', 'find', queue_path, '-type', 'f'], self.log).splitlines())

aha, clever :) I missed it! shakes fist at the sky

JohnLZeller · 2015-09-03T21:53:43Z

Reference material: http://thraxil.org/users/anders/posts/2008/03/13/Subprocess-Hanging-PIPE-is-your-enemy/

remh · 2015-09-03T22:03:02Z

config.py

-        systemStats['cpuCores'] = int(wc.communicate()[0])
+        grep = get_subprocess_output(['grep', 'model name', '/proc/cpuinfo'], log)
+        # Must use tempfiles to redirect stdout to second command
+        tempgrep = tempfile.TemporaryFile()


same thing here

JohnLZeller · 2015-09-03T22:31:56Z

@remh incorporated all your changes :)

Sorry I sorta jumped the 🔫 on squashing the commits.
Here are the changes:
postfix.py Line 59
config.py Line 585
subprocess_output.py Line 21

All changes have been tested! 👍

JohnLZeller · 2015-09-03T23:02:39Z

checks.d/mysql.py

@@ -385,8 +385,7 @@ def _get_server_pid(self, db):
        if pid is None:
            try:
                if sys.platform.startswith("linux"):
-                    ps = subprocess.Popen(['ps', '-C', 'mysqld', '-o', 'pid'],
-                                          stdout=subprocess.PIPE, close_fds=True).communicate()[0]
+                    ps = get_subprocess_output(['ps', '-C', 'mysqld', '-o', 'pid'], self.log)


Use splitlines()

remh · 2015-09-28T10:03:18Z

@JohnLZeller can you fix the conflicts please ?

remh · 2015-09-28T10:07:51Z

checks.d/varnish.py

    def _get_version_info(self, varnishstat_path):
        # Get the varnish version from varnishstat
+        # FIXME: Use get_subprocess_output() instead of subprocess.Popen


Can you do it while you're at it ?

JohnLZeller · 2015-09-28T23:17:44Z

Fixed a couple of the FIXME's. Needs a little more love, and some testing.

remh · 2015-09-30T11:33:22Z

Thanks @JohnLZeller can you fix the conflicts please ?

JohnLZeller · 2015-09-30T23:22:26Z

Okay, fixed the other places where there were existing FIXME comments for subprocess, as well as merged master to catch this branch up, and resolved conflicts.

Had to make some changes to the way the get_subprocess_output() function works, in order to allow it to work for all the cases we needed it. I did not however end up using it for jmxfetch.py because it would have made get_subprocess_output() too messy. Instead I implemented a safer way of calling subprocess for jmxfetch.py.

I need to do some testing and refactoring on broken tests in the 'morrow. Getting closer.

JohnLZeller · 2015-10-13T15:59:38Z

Could use some feedback.

@olivielpeau would you mind reviewing half? And @yannmh could you review the other half?

olivielpeau · 2015-10-14T16:50:27Z

checks.d/disk.py

-        df_out = utils.subprocess_output.get_subprocess_output(
-            self.DF_COMMAND + ['-k'], self.log
-        )
+        df_out, err, rtcode = get_subprocess_output(self.DF_COMMAND + ['-k'], self.log)


Just a general comment when using functions that return multiple values: you can discard the values that you don't use with _. It's just a convention but makes it clear that you're not using the value afterwards. For instance here you can use:

df_out, _, _ = get_subprocess_output(self.DF_COMMAND + ['-k'], self.log)

olivielpeau · 2015-10-14T18:21:21Z

Great job, looks way cleaner now!

Looks good to me apart from my comments 👍

JohnLZeller · 2015-10-21T06:06:13Z

Thanks @olivielpeau :)

Made the changes you mentioned, thanks for the good feedback!

remh · 2015-10-21T20:51:08Z

@JohnLZeller can you squash your commits please ?

JohnLZeller · 2015-10-21T20:57:06Z

@remh will do

JohnLZeller · 2015-10-27T17:44:41Z

@remh okay, I have squashed and rebased to matched up with the current state of master

[core] Replace subprocess.Popen with safer get_subprocess_output

miketheman · 2015-11-04T02:35:20Z

I'm very interested in trying out some of these methods in a new check, where might I find a recent build that includes this code?

miketheman · 2015-11-04T02:38:46Z

Reason I ask is that http://apt.datadoghq.com/dists/nightly/ has datadog-agent_5.5.0.git.6.ff669c3-1_amd64.deb - which is back on Sept 17.

remh · 2015-11-04T02:49:12Z

http://apt.datad0g.com/dists/nightly/
On Nov 3, 2015 9:38 PM, "Mike Fiedler" [email protected] wrote:

Reason i ask is that http://apt.datadoghq.com/dists/nightly/ has
datadog-agent_5.5.0.git.6.ff669c3-1_amd64.deb - which is back on Sept 17
ff669c3.

—
Reply to this email directly or view it on GitHub
#1892 (comment).

miketheman · 2015-11-04T13:44:15Z

Thanks @remh. I must have missed that when looking.

JohnLZeller force-pushed the zeller/subprocess branch from 7d404eb to f14168b Compare September 3, 2015 21:48

remh reviewed Sep 3, 2015
View reviewed changes

JohnLZeller force-pushed the zeller/subprocess branch from a743675 to e46fa87 Compare September 3, 2015 22:29

JohnLZeller reviewed Sep 3, 2015
View reviewed changes

remh mentioned this pull request Sep 14, 2015

hung subprocess causes the agent to hang as well #443

Closed

remh reviewed Sep 28, 2015
View reviewed changes

remh added this to the 5.5.1 milestone Sep 30, 2015

olivielpeau reviewed Oct 14, 2015
View reviewed changes

remh modified the milestones: 5.5.2, 5.5.1 Oct 19, 2015

yannmh modified the milestones: 5.6.0, 5.5.2 Oct 23, 2015

[core] Replace subprocess.Popen with safer get_subprocess_output

3042a1d

JohnLZeller force-pushed the zeller/subprocess branch from a663b13 to 3042a1d Compare October 27, 2015 17:43

JohnLZeller changed the title ~~Replace subprocess.Popen with safer get_subprocess_output~~ [core] Replace subprocess.Popen with safer get_subprocess_output Oct 27, 2015

remh pushed a commit that referenced this pull request Nov 2, 2015

Merge pull request #1892 from DataDog/zeller/subprocess

bfc4cb4

[core] Replace subprocess.Popen with safer get_subprocess_output

remh merged commit bfc4cb4 into master Nov 2, 2015

olivielpeau deleted the zeller/subprocess branch November 4, 2015 18:09

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[core] Replace subprocess.Popen with safer get_subprocess_output #1892

[core] Replace subprocess.Popen with safer get_subprocess_output #1892

JohnLZeller commented Sep 3, 2015

JohnLZeller commented Sep 3, 2015

remh Sep 3, 2015

JohnLZeller Sep 3, 2015

JohnLZeller commented Sep 3, 2015

remh Sep 3, 2015

JohnLZeller commented Sep 3, 2015

JohnLZeller Sep 3, 2015

remh commented Sep 28, 2015

remh Sep 28, 2015

JohnLZeller commented Sep 28, 2015

remh commented Sep 30, 2015

JohnLZeller commented Sep 30, 2015

JohnLZeller commented Oct 13, 2015

olivielpeau Oct 14, 2015

olivielpeau commented Oct 14, 2015

JohnLZeller commented Oct 21, 2015

remh commented Oct 21, 2015

JohnLZeller commented Oct 21, 2015

JohnLZeller commented Oct 27, 2015

miketheman commented Nov 4, 2015

miketheman commented Nov 4, 2015

remh commented Nov 4, 2015

miketheman commented Nov 4, 2015

[core] Replace subprocess.Popen with safer get_subprocess_output #1892

[core] Replace subprocess.Popen with safer get_subprocess_output #1892

Conversation

JohnLZeller commented Sep 3, 2015

JohnLZeller commented Sep 3, 2015

remh Sep 3, 2015

Choose a reason for hiding this comment

JohnLZeller Sep 3, 2015

Choose a reason for hiding this comment

JohnLZeller commented Sep 3, 2015

remh Sep 3, 2015

Choose a reason for hiding this comment

JohnLZeller commented Sep 3, 2015

JohnLZeller Sep 3, 2015

Choose a reason for hiding this comment

remh commented Sep 28, 2015

remh Sep 28, 2015

Choose a reason for hiding this comment

JohnLZeller commented Sep 28, 2015

remh commented Sep 30, 2015

JohnLZeller commented Sep 30, 2015

JohnLZeller commented Oct 13, 2015

olivielpeau Oct 14, 2015

Choose a reason for hiding this comment

olivielpeau commented Oct 14, 2015

JohnLZeller commented Oct 21, 2015

remh commented Oct 21, 2015

JohnLZeller commented Oct 21, 2015

JohnLZeller commented Oct 27, 2015

miketheman commented Nov 4, 2015

miketheman commented Nov 4, 2015

remh commented Nov 4, 2015

miketheman commented Nov 4, 2015