From 5296336f4a9bdb38d29dce107d19a67639fb18fe Mon Sep 17 00:00:00 2001 From: Alexander Kukushkin Date: Fri, 18 May 2018 11:18:27 +0200 Subject: [PATCH] BUGFIX: postmaster start can fail if pid from postmaster.pid is alive (#681) Upon start postmaster process performs various safety checks if there is a postmaster.pid file in the data directory. Although Patroni already detected that the running process corresponding to the postmaster.pid is not a postmaster, the new postmaster might fail to start, because it thinks that postmaster.pid is already locked. Important!!! Unlink of postmaster.pid isn't an option in this case, because it has a lot of nasty race conditions. Luckily there is a workaround to this problem, we can pass the pid from postmaster.pid in the `PG_GRANDPARENT_PID` environment variable and postmaster will ignore it. More likely to hit such problem if you run Patroni and postgres in the docker container. --- patroni/postgresql.py | 15 +------- patroni/postmaster.py | 82 +++++++++++++++++++++++++++++----------- tests/test_postgresql.py | 10 ----- tests/test_postmaster.py | 50 ++++++++++++++++-------- 4 files changed, 95 insertions(+), 62 deletions(-) diff --git a/patroni/postgresql.py b/patroni/postgresql.py index b52b7068..f31e4828 100644 --- a/patroni/postgresql.py +++ b/patroni/postgresql.py @@ -141,7 +141,6 @@ class Postgresql(object): self._postgresql_base_conf = os.path.join(self._config_dir, self._postgresql_base_conf_name) self._pg_hba_conf = os.path.join(self._config_dir, 'pg_hba.conf') self._recovery_conf = os.path.join(self._data_dir, 'recovery.conf') - self._postmaster_pid = os.path.join(self._data_dir, 'postmaster.pid') self._trigger_file = config.get('recovery_conf', {}).get('trigger_file') or 'promote' self._trigger_file = os.path.abspath(os.path.join(self._data_dir, self._trigger_file)) @@ -732,21 +731,9 @@ class Postgresql(object): return self._postmaster_proc self._postmaster_proc = None - self._postmaster_proc = PostmasterProcess.from_pidfile(self._read_pid_file()) + self._postmaster_proc = PostmasterProcess.from_pidfile(self._data_dir) return self._postmaster_proc - def _read_pid_file(self): - """Reads and parses postmaster.pid from the data directory - - :returns dictionary of values if successful, empty dictionary otherwise - """ - pid_line_names = ['pid', 'data_dir', 'start_time', 'port', 'socket_dir', 'listen_addr', 'shmem_key'] - try: - with open(self._postmaster_pid) as f: - return {name: line.rstrip("\n") for name, line in zip(pid_line_names, f)} - except IOError: - return {} - @property def cb_called(self): return self.__cb_called diff --git a/patroni/postmaster.py b/patroni/postmaster.py index aaec2d44..aa5f3050 100644 --- a/patroni/postmaster.py +++ b/patroni/postmaster.py @@ -17,6 +17,7 @@ STOP_SIGNALS = { class PostmasterProcess(psutil.Process): + def __init__(self, pid): self.is_single_user = False if pid < 0: @@ -24,32 +25,55 @@ class PostmasterProcess(psutil.Process): self.is_single_user = True super(PostmasterProcess, self).__init__(pid) - @classmethod - def from_pidfile(cls, pidfile): - try: - pid = int(pidfile.get('pid', 0)) - if not pid: - return None - except ValueError: - return None + @staticmethod + def _read_postmaster_pidfile(data_dir): + """Reads and parses postmaster.pid from the data directory + :returns dictionary of values if successful, empty dictionary otherwise + """ + pid_line_names = ['pid', 'data_dir', 'start_time', 'port', 'socket_dir', 'listen_addr', 'shmem_key'] try: - proc = cls(pid) - except psutil.NoSuchProcess: - return None + with open(os.path.join(data_dir, 'postmaster.pid')) as f: + return {name: line.rstrip('\n') for name, line in zip(pid_line_names, f)} + except IOError: + return {} + def _is_postmaster_process(self): try: - start_time = int(pidfile.get('start_time', 0)) - if start_time and abs(proc.create_time() - start_time) > 3: - return None + start_time = int(self._postmaster_pid.get('start_time', 0)) + if start_time and abs(self.create_time() - start_time) > 3: + logger.info('Too much difference between %s and %s', self.create_time(), start_time) + return False except ValueError: - logger.warning("Garbage start time value in pid file: %r", pidfile.get('start_time')) + logger.warning('Garbage start time value in pid file: %r', self._postmaster_pid.get('start_time')) # Extra safety check. The process can't be ourselves, our parent or our direct child. - if proc.pid == os.getpid() or proc.pid == os.getppid() or proc.parent() == os.getpid(): - return None + if self.pid == os.getpid() or self.pid == os.getppid() or self.ppid() == os.getpid(): + logger.info('Patroni (pid=%s, ppid=%s), "fake postmaster" (pid=%s, ppid=%s)', + os.getpid(), os.getppid(), self.pid, self.ppid()) + return False - return proc + return True + + @classmethod + def _from_pidfile(cls, data_dir): + postmaster_pid = PostmasterProcess._read_postmaster_pidfile(data_dir) + try: + pid = int(postmaster_pid.get('pid', 0)) + if pid: + proc = cls(pid) + proc._postmaster_pid = postmaster_pid + return proc + except ValueError: + pass + + @staticmethod + def from_pidfile(data_dir): + try: + proc = PostmasterProcess._from_pidfile(data_dir) + return proc if proc and proc._is_postmaster_process() else None + except psutil.NoSuchProcess: + return None @classmethod def from_pid(cls, pid): @@ -100,8 +124,8 @@ class PostmasterProcess(psutil.Process): except psutil.Error: logger.exception('wait_for_user_backends_to_close') - @classmethod - def start(cls, pgcommand, data_dir, conf, options): + @staticmethod + def start(pgcommand, data_dir, conf, options): # Unfortunately `pg_ctl start` does not return postmaster pid to us. Without this information # it is hard to know the current state of postgres startup, so we had to reimplement pg_ctl start # in python. It will start postgres, wait for port to be open and wait until postgres will start @@ -113,10 +137,24 @@ class PostmasterProcess(psutil.Process): # of init process to take care about postmaster. # In order to make everything portable we can't use fork&exec approach here, so we will call # ourselves and pass list of arguments which must be used to start postgres. + env = {p: os.environ[p] for p in ('PATH', 'LC_ALL', 'LANG') if p in os.environ} + try: + proc = PostmasterProcess._from_pidfile(data_dir) + if proc and not proc._is_postmaster_process(): + # Upon start postmaster process performs various safety checks if there is a postmaster.pid + # file in the data directory. Although Patroni already detected that the running process + # corresponding to the postmaster.pid is not a postmaster, the new postmaster might fail + # to start, because it thinks that postmaster.pid is already locked. + # Important!!! Unlink of postmaster.pid isn't an option, because it has a lot of nasty race conditions. + # Luckily there is a workaround to this problem, we can pass the pid from postmaster.pid + # in the `PG_GRANDPARENT_PID` environment variable and postmaster will ignore it. + env['PG_GRANDPARENT_PID'] = str(proc.pid) + except psutil.NoSuchProcess: + pass + proc = call_self(['pg_ctl_start', pgcommand, '-D', data_dir, '--config-file={}'.format(conf)] + options, close_fds=True, - preexec_fn=os.setsid, stdout=subprocess.PIPE, - env={p: os.environ[p] for p in ('PATH', 'LC_ALL', 'LANG') if p in os.environ}) + preexec_fn=os.setsid, stdout=subprocess.PIPE, env=env) pid = int(proc.stdout.readline().strip()) proc.wait() logger.info('postmaster pid=%s', pid) diff --git a/tests/test_postgresql.py b/tests/test_postgresql.py index e6d5a079..b6f4d2d5 100644 --- a/tests/test_postgresql.py +++ b/tests/test_postgresql.py @@ -808,16 +808,6 @@ class TestPostgresql(unittest.TestCase): self.p._state = 'starting' self.assertIsNone(self.p.wait_for_startup()) - def test_read_pid_file(self): - pidfile = os.path.join(self.data_dir, 'postmaster.pid') - if os.path.exists(pidfile): - os.remove(pidfile) - self.assertEquals(self.p._read_pid_file(), {}) - with open(pidfile, 'w') as fd: - fd.write("123\n/foo/bar\n123456789\n5432") - self.assertEquals(self.p._read_pid_file(), {"pid": "123", "data_dir": "/foo/bar", - "start_time": "123456789", "port": "5432"}) - def test_pick_sync_standby(self): cluster = Cluster(True, None, self.leader, 0, [self.me, self.other, self.leadermem], None, SyncState(0, self.me.name, self.leadermem.name), None) diff --git a/tests/test_postmaster.py b/tests/test_postmaster.py index 342f17af..c0aaaa78 100644 --- a/tests/test_postmaster.py +++ b/tests/test_postmaster.py @@ -1,8 +1,9 @@ +import psutil import unittest -from mock import Mock, patch +from mock import Mock, patch, mock_open from patroni.postmaster import PostmasterProcess -import psutil +from six.moves import builtins class TestPostmasterProcess(unittest.TestCase): @@ -13,26 +14,34 @@ class TestPostmasterProcess(unittest.TestCase): @patch('psutil.Process.create_time') @patch('psutil.Process.__init__') - def test_from_pidfile(self, mock_init, mock_create_time): + @patch('patroni.postmaster.PostmasterProcess._read_postmaster_pidfile') + def test_from_pidfile(self, mock_read, mock_init, mock_create_time): mock_init.side_effect = psutil.NoSuchProcess(123) - self.assertEquals(PostmasterProcess.from_pidfile({}), None) - self.assertEquals(PostmasterProcess.from_pidfile({"pid": "foo"}), None) - self.assertEquals(PostmasterProcess.from_pidfile({"pid": "123"}), None) + mock_read.return_value = {} + self.assertIsNone(PostmasterProcess.from_pidfile('')) + mock_read.return_value = {"pid": "foo"} + self.assertIsNone(PostmasterProcess.from_pidfile('')) + mock_read.return_value = {"pid": "123"} + self.assertIsNone(PostmasterProcess.from_pidfile('')) mock_init.side_effect = None with patch.object(psutil.Process, 'pid', 123), \ - patch.object(psutil.Process, 'parent', return_value=124), \ + patch.object(psutil.Process, 'ppid', return_value=124), \ patch('os.getpid', return_value=125) as mock_ospid, \ patch('os.getppid', return_value=126): - self.assertNotEquals(PostmasterProcess.from_pidfile({"pid": "123"}), None) + self.assertIsNotNone(PostmasterProcess.from_pidfile('')) mock_create_time.return_value = 100000 - self.assertEquals(PostmasterProcess.from_pidfile({"pid": "123", "start_time": "200000"}), None) - self.assertNotEquals(PostmasterProcess.from_pidfile({"pid": "123", "start_time": "foobar"}), None) + mock_read.return_value = {"pid": "123", "start_time": "200000"} + self.assertIsNone(PostmasterProcess.from_pidfile('')) + + mock_read.return_value = {"pid": "123", "start_time": "foobar"} + self.assertIsNotNone(PostmasterProcess.from_pidfile('')) mock_ospid.return_value = 123 - self.assertEquals(PostmasterProcess.from_pidfile({"pid": "123", "start_time": "100000"}), None) + mock_read.return_value = {"pid": "123", "start_time": "100000"} + self.assertIsNone(PostmasterProcess.from_pidfile('')) @patch('psutil.Process.__init__') def test_from_pid(self, mock_init): @@ -75,11 +84,20 @@ class TestPostmasterProcess(unittest.TestCase): @patch('subprocess.Popen') @patch.object(PostmasterProcess, 'from_pid') - def test_start(self, mock_frompid, mock_popen): + @patch.object(PostmasterProcess, '_from_pidfile') + def test_start(self, mock_frompidfile, mock_frompid, mock_popen): + mock_frompidfile.return_value._is_postmaster_process.return_value = False mock_frompid.return_value = "proc 123" mock_popen.return_value.stdout.readline.return_value = '123' - self.assertEquals( - PostmasterProcess.start('/bin/true', '/tmp/', '/tmp/test.conf', ['--foo=bar', '--bar=baz']), - "proc 123" - ) + self.assertEquals(PostmasterProcess.start('true', '/tmp', '/tmp/test.conf', []), "proc 123") mock_frompid.assert_called_with(123) + + mock_frompidfile.side_effect = psutil.NoSuchProcess(123) + self.assertEquals(PostmasterProcess.start('true', '/tmp', '/tmp/test.conf', []), "proc 123") + + @patch('psutil.Process.__init__', Mock(side_effect=psutil.NoSuchProcess(123))) + def test_read_postmaster_pidfile(self): + with patch.object(builtins, 'open', Mock(side_effect=IOError)): + self.assertIsNone(PostmasterProcess.from_pidfile('')) + with patch.object(builtins, 'open', mock_open(read_data='123\n')): + self.assertIsNone(PostmasterProcess.from_pidfile(''))