Enable logging.conf & fluentd for keystone

This change introduce ability to use log_config_append parameter with
new FluentdHandler to send logs directly to Fluentd.

To save per binary log streams as it is in the default logging states generates
separate logging.conf files per service and use /etc/default/<service name>
to pass dedicated logging.conf to every service.

Change-Id: I420dd20c2ba7017a2ed336361da1a684d93a77ed
Related-Prod: PROD-16324
diff --git a/README.rst b/README.rst
index 89593bd..8b80ef4 100644
--- a/README.rst
+++ b/README.rst
@@ -676,6 +676,31 @@
           name: "admin"
           domain: "default"
 
+Enhanced logging with logging.conf
+----------------------------------
+
+By default logging.conf is disabled.
+
+That is possible to enable per-binary logging.conf with new variables:
+  * openstack_log_appender - set it to true to enable log_config_append for all OpenStack services;
+  * openstack_fluentd_handler_enabled - set to true to enable FluentHandler for all Openstack services.
+
+Only WatchedFileHandler and FluentHandler are available.
+
+Also it is possible to configure this with pillar:
+
+.. code-block:: yaml
+
+  keystone:
+    server:
+      logging:
+        log_appender: true
+        log_handlers:
+          watchedfile:
+            enabled: true
+          fluentd:
+            enabled: true
+
 Usage
 =====
 
diff --git a/keystone/files/logging.conf b/keystone/files/logging.conf
new file mode 100644
index 0000000..498fd05
--- /dev/null
+++ b/keystone/files/logging.conf
@@ -0,0 +1,58 @@
+{%- set log_handlers = [] -%}
+{%- for log_handler_name, log_handler_attrs in values.logging.log_handlers.items() %}
+  {%- if log_handler_attrs.get('enabled', False) %}
+    {%- do log_handlers.append(log_handler_name) -%}
+  {%- endif %}
+{%- endfor %}
+[loggers]
+keys = root, keystone, access
+
+[handlers]
+keys = {{ log_handlers | join(", ") }}
+
+[formatters]
+keys = context, default, fluentd
+
+[logger_root]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+
+[logger_keystone]
+level = INFO
+handlers = {{ log_handlers | join(", ") }}
+qualname = keystone
+
+[logger_access]
+level = INFO
+qualname = access
+handlers = {{ log_handlers | join(", ") }}
+
+[logger_sqlalchemy]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+qualname = sqlalchemy
+
+{%- if values.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+[handler_fluentd]
+class = fluent.handler.FluentHandler
+args = ('openstack.keystone', 'localhost', 24224)
+formatter = fluentd
+{%- endif %}
+
+{%- if values.logging.log_handlers.watchedfile.enabled %}
+[handler_watchedfile]
+class = handlers.WatchedFileHandler
+args = ('/var/log/keystone/keystone.log',)
+formatter = context
+{%- endif %}
+
+[formatter_context]
+class = oslo_log.formatters.ContextFormatter
+
+[formatter_default]
+format = %(message)s
+
+{%- if values.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+[formatter_fluentd]
+class = oslo_log.formatters.FluentFormatter
+{%- endif %}
diff --git a/keystone/files/mitaka/keystone.conf.Debian b/keystone/files/mitaka/keystone.conf.Debian
index 4e61f49..03e3711 100644
--- a/keystone/files/mitaka/keystone.conf.Debian
+++ b/keystone/files/mitaka/keystone.conf.Debian
@@ -136,7 +136,10 @@
 # configuration file and other logging configuration options are ignored (for
 # example, logging_context_format_string). (string value)
 # Deprecated group/name - [DEFAULT]/log_config
-#log_config_append = <None>
+#log_config_append=<None>
+{%- if server.logging.log_appender %}
+log_config_append=/etc/keystone/logging.conf
+{%- endif %}
 
 # Defines the format string for %%(asctime)s in log records. Default:
 # %(default)s . This option is ignored if log_config_append is set. (string
diff --git a/keystone/files/newton/keystone.conf.Debian b/keystone/files/newton/keystone.conf.Debian
index 2b96be9..72a8c4c 100644
--- a/keystone/files/newton/keystone.conf.Debian
+++ b/keystone/files/newton/keystone.conf.Debian
@@ -171,7 +171,10 @@
 # example, logging_context_format_string). (string value)
 # Note: This option can be changed without restarting.
 # Deprecated group/name - [DEFAULT]/log_config
-#log_config_append = <None>
+#log_config_append=<None>
+{%- if server.logging.log_appender %}
+log_config_append=/etc/keystone/logging.conf
+{%- endif %}
 
 # Defines the format string for %%(asctime)s in log records. Default:
 # %(default)s . This option is ignored if log_config_append is set. (string
diff --git a/keystone/files/ocata/keystone.conf.Debian b/keystone/files/ocata/keystone.conf.Debian
index 2fdf03f..577cea3 100644
--- a/keystone/files/ocata/keystone.conf.Debian
+++ b/keystone/files/ocata/keystone.conf.Debian
@@ -160,7 +160,10 @@
 # example, logging_context_format_string). (string value)
 # Note: This option can be changed without restarting.
 # Deprecated group/name - [DEFAULT]/log_config
-#log_config_append = <None>
+#log_config_append=<None>
+{%- if server.logging.log_appender %}
+log_config_append=/etc/keystone/logging.conf
+{%- endif %}
 
 # Defines the format string for %%(asctime)s in log records. Default:
 # %(default)s . This option is ignored if log_config_append is set. (string
diff --git a/keystone/files/ocata/keystone.conf.RedHat b/keystone/files/ocata/keystone.conf.RedHat
index b3c159e..573ce19 100644
--- a/keystone/files/ocata/keystone.conf.RedHat
+++ b/keystone/files/ocata/keystone.conf.RedHat
@@ -160,7 +160,10 @@
 # example, logging_context_format_string). (string value)
 # Note: This option can be changed without restarting.
 # Deprecated group/name - [DEFAULT]/log_config
-#log_config_append = <None>
+#log_config_append=<None>
+{%- if server.logging.log_appender %}
+log_config_append = /etc/keystone/logging.conf
+{%- endif %}
 
 # Defines the format string for %%(asctime)s in log records. Default:
 # %(default)s . This option is ignored if log_config_append is set. (string
diff --git a/keystone/files/pike/keystone.conf.Debian b/keystone/files/pike/keystone.conf.Debian
index 48a0f0a..f1c7a7e 100644
--- a/keystone/files/pike/keystone.conf.Debian
+++ b/keystone/files/pike/keystone.conf.Debian
@@ -161,6 +161,9 @@
 # Note: This option can be changed without restarting.
 # Deprecated group/name - [DEFAULT]/log_config
 #log_config_append = <None>
+{%- if server.logging.log_appender %}
+log_config_append=/etc/keystone/logging.conf
+{%- endif %}
 
 # Defines the format string for %%(asctime)s in log records. Default:
 # %(default)s . This option is ignored if log_config_append is set. (string
diff --git a/keystone/files/pike/keystone.conf.RedHat b/keystone/files/pike/keystone.conf.RedHat
index 07392f1..60afa9c 100644
--- a/keystone/files/pike/keystone.conf.RedHat
+++ b/keystone/files/pike/keystone.conf.RedHat
@@ -161,6 +161,9 @@
 # Note: This option can be changed without restarting.
 # Deprecated group/name - [DEFAULT]/log_config
 #log_config_append = <None>
+{%- if server.logging.log_appender %}
+log_config_append=/etc/keystone/logging.conf
+{%- endif %}
 
 # Defines the format string for %%(asctime)s in log records. Default:
 # %(default)s . This option is ignored if log_config_append is set. (string
diff --git a/keystone/map.jinja b/keystone/map.jinja
index 31d0ada..e5fc380 100644
--- a/keystone/map.jinja
+++ b/keystone/map.jinja
@@ -21,7 +21,15 @@
         },
         'notification': False,
         'roles': ['admin', 'Member'],
-        'cacert': '/etc/ssl/certs/ca-certificates.crt'
+        'cacert': '/etc/ssl/certs/ca-certificates.crt',
+        'logging': {
+          'log_appender': false,
+          'log_handlers': {
+            'watchedfile': {
+              'enabled': true
+            }
+          },
+        },
     },
     'RedHat': {
         'pkgs': ['openstack-keystone', 'openstack-utils', 'python-keystone', 'python-keystoneclient', 'python-pycadf'],
@@ -37,7 +45,15 @@
         },
         'notification': False,
         'roles': ['admin', 'Member'],
-        'cacert': '/etc/pki/tls/certs/ca-bundle.crt'
+        'cacert': '/etc/pki/tls/certs/ca-bundle.crt',
+        'logging': {
+          'log_appender': false,
+          'log_handlers': {
+            'watchedfile': {
+              'enabled': true
+            }
+          },
+        },
     },
 }, merge=pillar.keystone.get('server', {}), base='BaseDefaults') %}
 
diff --git a/keystone/meta/fluentd.yml b/keystone/meta/fluentd.yml
new file mode 100644
index 0000000..9699826
--- /dev/null
+++ b/keystone/meta/fluentd.yml
@@ -0,0 +1,162 @@
+{%- if pillar.get('fluentd', {}).get('agent', {}).get('enabled', False) %}
+{%- from "keystone/map.jinja" import server with context %}
+{%- set positiondb = pillar.fluentd.agent.dir.positiondb %}
+agent:
+  config:
+    label:
+      forward_input:
+        input:
+          generic_forward_input:
+            type: forward
+            bind: 0.0.0.0
+            port: 24224
+        match:
+          route_openstack_keystone:
+            tag: openstack.keystone
+            type: relabel
+            label: openstack_keystone
+{%- if server.service_name in ['apache2', 'httpd'] %}
+      openstack_keystone_wsgi:
+        input:
+          keystone_api_wsgi_in_tail:
+            type: tail
+            path: /var/log/apache2/keystone.access.log
+            tag: openstack.keystone
+            pos_file: {{ positiondb }}/keystone.wsgi.pos
+            parser:
+              type: regexp
+              time_key: Timestamp
+              time_format: '%d/%b/%Y:%H:%M:%S %z'
+              keep_time_key: false
+              # Apache format: https://regex101.com/r/WeCT7s/5
+              format: '/(?<hostname>[\w\.\-]+)\:(?<port>\d+)\s(?<http_client_ip_address>[\d\.]+)\s\-\s\-\s\[(?<Timestamp>.*)\]\s(?<Payload>\"(?<http_method>[A-Z]+)\s(?<http_url>\S+)\s(?<http_version>[.\/\dHTFSP]+)\"\s(?<http_status>\d{3})\s(?<http_response_time>\d+)\s(?<http_response_size>\d+)\s\"(?<http_referer>.*)\"\s\"(?<user_agent>.*)\")/'
+        filter:
+          add_keystone_wsgi_record_fields:
+            tag: openstack.keystone
+            type: record_transformer
+            enable_ruby: true
+            record:
+              - name: Severity
+                value: 6
+              - name: severity_label
+                value: INFO
+              - name: programname
+                value: keystone-wsgi
+              - name: http_response_time
+                value: ${ record['http_response_time'].to_i/100000.to_f }
+        match:
+          send_to_default:
+            tag: openstack.keystone
+            type: copy
+            store:
+              - type: relabel
+                label: default_output
+              - type: rewrite_tag_filter
+                rule:
+                  - name: severity_label
+                    regexp: '.'
+                    result: metric.keystone_log_messages
+              - type: rewrite_tag_filter
+                rule:
+                  - name: http_status
+                    regexp: '.'
+                    result: metric.keystone_openstack_http_response
+          push_to_metric:
+            tag: 'metric.**'
+            type: relabel
+            label: default_metric
+{%- endif %}
+      openstack_keystone:
+        filter:
+          set_log_record_fields:
+            tag: openstack.keystone
+            type: record_transformer
+            enable_ruby: true
+            record:
+              - name: Severity
+                value: ${ {'TRACE'=>7,'DEBUG'=>7,'INFO'=>6,'AUDIT'=>6,'WARNING'=>4,'ERROR'=>3,'CRITICAL'=>2}[record['level']].to_i }
+              - name: severity_label
+                value: ${ record['level'] }
+              - name: programname
+                value: keystone
+              - name: Payload
+                value: ${ record['message'] }
+              - name: python_module
+                value: ${ record['name'] }
+          parse_http_stats:
+            tag: openstack.keystone
+            type: parser
+            key_name: Payload
+            reserve_data: true
+            emit_invalid_record_to_error: false
+            parser:
+              type: regexp
+              # Parse openstack http stats: https://regex101.com/r/Tf0XUK/1/
+              format: '\"(?<http_method>GET|POST|OPTIONS|DELETE|PUT|HEAD|TRACE|CONNECT|PATCH)\s(?<http_url>\S+)\s(?<http_version>[.\/\dHTFSP]+)\"\sstatus:\s(?<http_status>\d{3})\slen:\s(?<http_response_size>\d+)\stime:\s(?<http_response_time>\d+\.\d+)'
+              types: http_response_time:float
+        match:
+          unify_tag:
+            tag: openstack.keystone.*
+            type: rewrite_tag_filter
+            rule:
+              - name: level
+                regexp: '.*'
+                result: openstack.keystone
+          send_to_default:
+            tag: openstack.keystone
+            type: copy
+            store:
+              - type: relabel
+                label: default_output
+              - type: rewrite_tag_filter
+                rule:
+                  - name: severity_label
+                    regexp: '.'
+                    result: metric.keystone_log_messages
+              - type: rewrite_tag_filter
+                rule:
+                  - name: http_status
+                    regexp: '.'
+                    result: metric.keystone_openstack_http_response
+          push_to_metric:
+            tag: 'metric.**'
+            type: relabel
+            label: default_metric
+      default_metric:
+        filter:
+          keystone_logs_per_severity:
+            tag: metric.keystone_log_messages
+            require:
+              - add_general_fields
+            type: prometheus
+            metric:
+              - name: log_messages
+                type: counter
+                desc: Total number of log lines by severity
+            label:
+              - name: service
+                value: keystone
+              - name: level
+                value: ${severity_label}
+              - name: host
+                value: ${Hostname}
+          keystone_openstack_http_response_times:
+            tag: metric.keystone_openstack_http_response
+            require:
+              - add_general_fields
+            type: prometheus
+            metric:
+              - name: openstack_http_response_times
+                type: summary
+                desc: Total number of requests per method and status
+                key: http_response_time
+            label:
+              - name: http_method
+                value: ${http_method}
+              - name: http_status
+                value: ${http_status}
+              - name: service
+                value: keystone
+              - name: host
+                value: ${Hostname}
+{% endif %}
\ No newline at end of file
diff --git a/keystone/server.sls b/keystone/server.sls
index ad74eae..99337f9 100644
--- a/keystone/server.sls
+++ b/keystone/server.sls
@@ -109,17 +109,41 @@
   - watch_in:
     - service: {{ keystone_service }}
 
-/etc/keystone/policy.json:
-  file.managed:
-  - user: keystone
-  - group: keystone
-  - require:
-    - pkg: keystone_packages
-  - watch_in:
-    - service: {{ keystone_service }}
+{%- if server.logging.log_appender %}
+
+{%- if server.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+keystone_fluentd_logger_package:
+  pkg.installed:
+    - name: python-fluent-logger
+{%- endif %}
 
 /etc/keystone/logging.conf:
   file.managed:
+    - user: keystone
+    - group: keystone
+    - source: salt://keystone/files/logging.conf
+    - template: jinja
+    - defaults:
+        values: {{ server }}
+    - require:
+      - pkg: keystone_packages
+{%- if server.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+      - pkg: keystone_fluentd_logger_package
+{%- endif %}
+    - watch_in:
+      - service: {{ keystone_service }}
+
+/var/log/keystone/keystone.log:
+  file.managed:
+    - user: keystone
+    - group: keystone
+    - watch_in:
+      - service: {{ keystone_service }}
+
+{%- endif %}
+
+/etc/keystone/policy.json:
+  file.managed:
   - user: keystone
   - group: keystone
   - require:
diff --git a/metadata/service/server/cluster.yml b/metadata/service/server/cluster.yml
index 147bd34..fd80ebd 100644
--- a/metadata/service/server/cluster.yml
+++ b/metadata/service/server/cluster.yml
@@ -3,6 +3,9 @@
 classes:
 - service.keystone.support
 parameters:
+  _param:
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   keystone:
     server:
       enabled: true
@@ -32,6 +35,13 @@
         location: /etc/keystone/fernet-keys/
       credential:
         location: /etc/keystone/credential-keys/
+      logging:
+        log_appender: ${_param:openstack_log_appender}
+        log_handlers:
+          watchedfile:
+            enabled: true
+          fluentd:
+            enabled: ${_param:openstack_fluentd_handler_enabled}
       message_queue:
         engine: rabbitmq
         host: ${_param:cluster_vip_address}
diff --git a/metadata/service/server/single.yml b/metadata/service/server/single.yml
index d131fd7..39cf725 100644
--- a/metadata/service/server/single.yml
+++ b/metadata/service/server/single.yml
@@ -3,6 +3,9 @@
 classes:
 - service.keystone.support
 parameters:
+  _param:
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   keystone:
     server:
       enabled: true
@@ -32,6 +35,13 @@
         location: /etc/keystone/fernet-keys/
       credential:
         location: /etc/keystone/credential-keys/
+      logging:
+        log_appender: ${_param:openstack_log_appender}
+        log_handlers:
+          watchedfile:
+            enabled: true
+          fluentd:
+            enabled: ${_param:openstack_fluentd_handler_enabled}
       message_queue:
         engine: rabbitmq
         host: ${_param:single_address}
diff --git a/metadata/service/support.yml b/metadata/service/support.yml
index 413387b..f056fb2 100644
--- a/metadata/service/support.yml
+++ b/metadata/service/support.yml
@@ -3,6 +3,8 @@
     _support:
       collectd:
         enabled: true
+      fluentd:
+        enabled: true
       heka:
         enabled: true
       sensu: