Merge lp:~stub/charms/precise/postgresql/syslog into lp:charms/postgresql

[Stuart Bishop]

Ship PostgreSQL log files via syslog.

I'm not too familiar with other charms using syslog, in particular if I should be sending on port 10514 or 514, so I'd like a review from someone who has done work in this area.

The goal of this work is to connect PostgreSQL to reporting programs, and I'll be creating a pgBadger charm shortly that will consume the logs. For this use case, I also need to advertise the log_line_prefix that PostgreSQL uses to consumers, so they can decode the logs. I also added the programname required to tell logs from different units apart (IP address isn't reliable).

[lp:~stub/charms/precise/postgresql/syslog]

175. By Stuart Bishop on 2014-02-13

Basic docs for syslog

[Charles Butler (lazypower)]

Stuart,

These modifications look fine to me. I've pulled them and deployed, setup a rather basic deployment test using rsyslog charm and the branch+prereq on HP-Cloud, AWS, and Local providers. All of which were properly forwarding the syslog. I haven't deployed the PGBadger service, however I see it as being ready in the queue, and I'll get to that next with additional commentary.

From what I've experienced in the past, forwarding over port 514 to your logging-nexus is perfectly acceptable. If you want to get into TLS wrapping your rsyslog forwarding, that's typically when you go to port 1999, so I'm a bit confused on the port 10514 dialogue above. Can you shed some light on why that was of a concern?

I'll be pushing this review to another charmer for an additional +1 review.

Thank you for the submission, keep up the excellent work!

review: Approve (deployment + audit)

[Stuart Bishop (stub)]

On 25 February 2014 02:27, Charles Butler <email address hidden> wrote:

> These modifications look fine to me. I've pulled them and deployed, setup a rather basic deployment test using rsyslog charm and the branch+prereq on HP-Cloud, AWS, and Local providers. All of which were properly forwarding the syslog. I haven't deployed the PGBadger service, however I see it as being ready in the queue, and I'll get to that next with additional commentary.
>
> >From what I've experienced in the past, forwarding over port 514 to your logging-nexus is perfectly acceptable. If you want to get into TLS wrapping your rsyslog forwarding, that's typically when you go to port 1999, so I'm a bit confused on the port 10514 dialogue above. Can you shed some light on why that was of a concern?

Its a concern as I'm cargo culting code from elsewhere, rather than
follow a specification. If there actually is a specification for the
syslog interface somewhere please let me know ;)

From what I can tell with the rsyslog and rsyslog-forarder charms, the
'open' port is 514 (TCP+UDP) but the 'closed' one used for syslog
forwarding is 10514 (TCP only). I also see nothing about TLS in those
charms, and nothing on port 1999.

--
Stuart Bishop <email address hidden>

[Charles Butler (lazypower)]

Ah, i reached out to my prior co-workers about the TLS security wrappers
and port 1999, that was a convention we coined. its not part of the spec.

Apparently getting transport security on our syslog forwarding constituted
partying like its 1999, hence the port chosen.

On Tue, Feb 25, 2014 at 12:42 AM, Stuart Bishop <<email address hidden>
> wrote:

> On 25 February 2014 02:27, Charles Butler <email address hidden>
> wrote:
>
> > These modifications look fine to me. I've pulled them and deployed,
> setup a rather basic deployment test using rsyslog charm and the
> branch+prereq on HP-Cloud, AWS, and Local providers. All of which were
> properly forwarding the syslog. I haven't deployed the PGBadger service,
> however I see it as being ready in the queue, and I'll get to that next
> with additional commentary.
> >
> > >From what I've experienced in the past, forwarding over port 514 to
> your logging-nexus is perfectly acceptable. If you want to get into TLS
> wrapping your rsyslog forwarding, that's typically when you go to port
> 1999, so I'm a bit confused on the port 10514 dialogue above. Can you shed
> some light on why that was of a concern?
>
> Its a concern as I'm cargo culting code from elsewhere, rather than
> follow a specification. If there actually is a specification for the
> syslog interface somewhere please let me know ;)
>
> >From what I can tell with the rsyslog and rsyslog-forarder charms, the
> 'open' port is 514 (TCP+UDP) but the 'closed' one used for syslog
> forwarding is 10514 (TCP only). I also see nothing about TLS in those
> charms, and nothing on port 1999.
>
>
> --
> Stuart Bishop <email address hidden>
>
>
> https://code.launchpad.net/~stub/charms/precise/postgresql/syslog/+merge/206176
> You are reviewing the proposed merge of
> lp:~stub/charms/precise/postgresql/syslog into lp:charms/postgresql.
>

[Marco Ceppi (marcoceppi)]

LGTM, +1

review: Approve

[lp:~stub/charms/precise/postgresql/syslog]

176. By Stuart Bishop on 2014-02-17

Merged bug-1278731-hot-standby-allowed-units into syslog.

177. By Stuart Bishop on 2014-03-04

Merged bug-1278731-hot-standby-allowed-units into syslog.

=== modified file 'README.md'
--- README.md	2014-02-05 12:29:09 +0000
+++ README.md	2014-02-13 13:49:35 +0000
@@ -130,6 +130,16 @@
 - `allowed-units`: space separated list of allowed clients (unit name).  You
   should check this to determine if you can connect to the database yet.
 
+## During syslog-relation-changed
+
+### the postgresql service provides:
+
+- `programname`: the syslog 'programname' identifying this unit's
+  PostgreSQL logs.
+- `log_line_prefix`: the 'log_line_prefix' setting for the PostgreSQL
+  service.
+
+
 ## For replicated database support
 
 A PostgreSQL service may contain multiple units (a single master, and
 
=== modified file 'config.yaml'
--- config.yaml	2014-01-23 11:41:03 +0000
+++ config.yaml	2014-02-13 13:49:35 +0000
@@ -90,7 +90,7 @@
     type: boolean
     description: Log disconnections
   log_line_prefix:
-    default: "%t "
+    default: "%t [%p]: [%l-1] db=%d,user=%u "
     type: string
     description: |
         special values:
 
=== modified file 'hooks/hooks.py'
--- hooks/hooks.py	2014-02-13 13:49:35 +0000
+++ hooks/hooks.py	2014-02-13 13:49:35 +0000
@@ -14,6 +14,7 @@
 import subprocess
 import sys
 from tempfile import NamedTemporaryFile
+from textwrap import dedent
 import time
 import yaml
 from yaml.constructor import ConstructorError
@@ -482,6 +483,9 @@
         config_file, pg_config,
         owner="postgres",  group="postgres", perms=0600)
 
+    # Create or update files included from postgresql.conf.
+    configure_log_destination(os.path.dirname(config_file))
+
     local_state['saved_config'] = config_data
     local_state.save()
 
@@ -999,6 +1003,11 @@
         postgresql_restart()
     postgresql_reload_or_restart()
 
+    # In case the log_line_prefix has changed, inform syslog consumers.
+    for relid in hookenv.relation_ids('syslog'):
+        hookenv.relation_set(
+            relid, log_line_prefix=hookenv.config('log_line_prefix'))
+
 
 @hooks.hook()
 def install(run_pre=True):
@@ -2194,6 +2203,69 @@
         host.service_reload('nagios-nrpe-server')
 
 
[e-mail]()
+def syslog_relation_changed():
+    configure_log_destination(_get_postgresql_config_dir())
+    postgresql_reload()
+
+    # We extend the syslog interface by exposing the log_line_prefix.
+    # This is required so consumers of the PostgreSQL logs can decode
+    # them. Consumers not smart enough to cope with arbitrary prefixes
+    # can at a minimum abort if they detect it is set to something they
+    # cannot support. Similarly, inform the consumer of the programname
+    # we are using so they can tell one units log messages from another.
+    hookenv.relation_set(
+        log_line_prefix=hookenv.config('log_line_prefix'),
+        programname=sanitize(hookenv.local_unit()))
+
+    template_path = "{0}/templates/rsyslog_forward.conf".format(
+        hookenv.charm_dir())
+    rsyslog_conf = Template(open(template_path).read()).render(
+        local_unit=sanitize(hookenv.local_unit()),
+        raw_local_unit=hookenv.local_unit(),
+        raw_remote_unit=hookenv.remote_unit(),
+        remote_addr=hookenv.relation_get('private-address'))
+    host.write_file(rsyslog_conf_path(hookenv.remote_unit()), rsyslog_conf)
+    run(['service', 'rsyslog', 'restart'])
+
+
[e-mail]()
+def syslog_relation_departed():
+    configure_log_destination(_get_postgresql_config_dir())
+    postgresql_reload()
+    os.unlink(rsyslog_conf_path(hookenv.remote_unit()))
+    run(['service', 'rsyslog', 'restart'])
+
+
+def configure_log_destination(config_dir):
+    """Set the log_destination PostgreSQL config flag appropriately"""
+    # We currently support either 'standard' logs (the files in
+    # /var/log/postgresql), or syslog + 'standard' logs. This should
+    # grow more complex in the future, as the local logs will be
+    # redundant if you are using syslog for log aggregation, and we
+    # probably want to add csvlog in the future. Note that csvlog
+    # requires switching from 'Debian' log redirection and rotation to
+    # the PostgreSQL builtin facilities.
+    logdest_conf_path = os.path.join(config_dir, 'juju_logdest.conf')
+    logdest_conf = open(logdest_conf_path, 'w')
+    if hookenv.relation_ids('syslog'):
+        # For syslog, we change the ident from the default of 'postgres'
+        # to the unit name to allow remote services to easily identify
+        # and filter which unit messages are from. We don't use IP
+        # address for this as it is not necessarily unique.
+        logdest_conf.write(dedent("""\
+                log_destination='stderr,syslog'
+                syslog_ident={0}
+                """).format(sanitize(hookenv.local_unit())))
+    else:
+        open(logdest_conf_path, 'w').write("log_destination='stderr'")
+
+
+def rsyslog_conf_path(remote_unit):
+    return '/etc/rsyslog.d/juju-{0}-{1}.conf'.format(
+        sanitize(hookenv.local_unit()), sanitize(remote_unit))
+
+
 def _get_postgresql_config_dir(config_data=None):
     """ Return the directory path of the postgresql configuration files. """
     if config_data is None:
@@ -2202,6 +2274,7 @@
     cluster_name = config_data['cluster_name']
     return os.path.join("/etc/postgresql", version, cluster_name)
 
+
 ###############################################################################
 # Global variables
 ###############################################################################
 
=== added symlink 'hooks/syslog-relation-changed'
=== target is u'hooks.py'
=== added symlink 'hooks/syslog-relation-departed'
=== target is u'hooks.py'
=== modified file 'metadata.yaml'
--- metadata.yaml	2013-10-08 22:44:28 +0000
+++ metadata.yaml	2014-02-13 13:49:35 +0000
@@ -26,6 +26,8 @@
 requires:
   persistent-storage:
     interface: directory-path
+  syslog:
+    interface: syslog
 peers:
   replication:
     interface: pgreplication
 
=== modified file 'templates/postgresql.conf.tmpl'
--- templates/postgresql.conf.tmpl	2014-01-30 16:44:33 +0000
+++ templates/postgresql.conf.tmpl	2014-02-13 13:49:35 +0000
@@ -88,6 +88,8 @@
 # ERROR REPORTING AND LOGGING
 #------------------------------------------------------------------------------
 
+include 'juju_logdest.conf'
+
 {% if log_min_duration_statement  != "" -%}
 log_min_duration_statement = {{log_min_duration_statement}}
 {% endif -%}
 
=== added file 'templates/rsyslog_forward.conf'
--- templates/rsyslog_forward.conf	1970-01-01 00:00:00 +0000
+++ templates/rsyslog_forward.conf	2014-02-13 13:49:35 +0000
@@ -0,0 +1,19 @@
+##
+## Managed by juju
+##
+
+# This file is installed into /etc/rsyslog.d to forward the unit's
+# PostgreSQL logs via syslog to another service.
+
+# This configuration is pretty dumb, and was cargo culted from the
+# rsyslog-forwarder charm. The client really needs to inform the
+# server what sort of service it requires (eg. reliability), but that
+# involves extending and documenting the juju common syslog interface.
+
+$ActionQueueType LinkedList      # use asynchronous processing
+$ActionQueueFileName @@service@@ # set file name, also enables disk mode
+$ActionResumeRetryCount -1       # infinite retries on insert failure
+$ActionQueueSaveOnShutdown on    # save in-memory data if rsyslog shuts down
+ 
+# Forward all PostgreSQL unit {{raw_local_unit}} logs to {{raw_remote_unit}}
+if $programname == '{{local_unit}}' then @@{{remote_addr}}:10514
 
=== modified file 'test.py'
--- test.py	2014-02-13 13:49:35 +0000
+++ test.py	2014-02-13 13:49:35 +0000
@@ -14,6 +14,7 @@
 import subprocess
 import time
 import unittest
+import uuid
 
 import fixtures
 import psycopg2
@@ -137,6 +138,10 @@
         result = self.sql('SELECT TRUE')
         self.assertEqual(result, [['t']])
 
+        # Confirm that the relation tears down without errors.
+        self.juju.do(['destroy-relation', 'postgresql:db', 'psql:db'])
+        self.juju.wait_until_ready()
+
     def test_streaming_replication(self):
         self.juju.deploy(
             TEST_CHARM, 'postgresql', num_units=2, config=self.pg_config)
@@ -163,6 +168,11 @@
         result = self.sql('SELECT TRUE', dbname='postgres')
         self.assertEqual(result, [['t']])
 
+        # Confirm that the relation tears down without errors.
+        self.juju.do([
+            'destroy-relation', 'postgresql:db-admin', 'psql:db-admin'])
+        self.juju.wait_until_ready()
+
     def is_master(self, postgres_unit, dbname=None):
         is_master = self.sql(
             'SELECT NOT pg_is_in_recovery()',
@@ -425,6 +435,36 @@
             ''')
         self.assertEqual(result, [['f', 'f', 'f']])
 
+    def test_syslog(self):
+        # Deploy 2 PostgreSQL units and 2 rsyslog units to ensure that
+        # log messages from every source reach every sink.
+        self.pg_config['log_min_duration_statement'] = 0  # Log all statements
+        self.juju.deploy(
+            TEST_CHARM, 'postgresql', num_units=2, config=self.pg_config)
+        self.juju.deploy(PSQL_CHARM, 'psql')
+        self.juju.do(['add-relation', 'postgresql:db', 'psql:db'])
+        self.juju.deploy('cs:rsyslog', 'rsyslog', num_units=2)
+        self.juju.do([
+            'add-relation', 'postgresql:syslog', 'rsyslog:aggregator'])
+        self.juju.wait_until_ready()
+
+        token = str(uuid.uuid1())
+
+        self.sql("SELECT 'master {}'".format(token), 'master')
+        self.sql("SELECT 'hot standby {}'".format(token), 'hot standby')
+        time.sleep(2)
+
+        for runit in ['rsyslog/0', 'rsyslog/1']:
+            cmd = ['juju', 'ssh', runit, 'tail -100 /var/log/syslog']
+            out = run(self, cmd)
+            self.failUnless('master {}'.format(token) in out)
+            self.failUnless('hot standby {}'.format(token) in out)
+
+        # Confirm that the relation tears down correctly.
+        self.juju.do([
+            'destroy-relation', 'postgresql:syslog', 'rsyslog:aggregator'])
+        self.juju.wait_until_ready()
+
 
 class PG91Tests(
         PostgreSQLCharmBaseTestCase,