Enable logging.conf & fluentd for cinder

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: I7b062f671aaaf0359a3ed072a8a0259023b4da8e
Related-Prod: PROD-16324
diff --git a/README.rst b/README.rst
index d3f0672..6c8590b 100644
--- a/README.rst
+++ b/README.rst
@@ -680,6 +680,40 @@
         barbican:
           enabled: true
 
+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
+
+  cinder:
+    controller:
+      logging:
+        log_appender: true
+        log_handlers:
+          watchedfile:
+            enabled: true
+          fluentd:
+            enabled: true
+
+    volume:
+      logging:
+        log_appender: true
+        log_handlers:
+          watchedfile:
+            enabled: true
+          fluentd:
+            enabled: true
+
 Documentation and Bugs
 ============================
 
diff --git a/cinder/controller.sls b/cinder/controller.sls
index b5620b9..2aacdc1 100644
--- a/cinder/controller.sls
+++ b/cinder/controller.sls
@@ -22,6 +22,97 @@
   - require:
     - pkg: cinder_controller_packages
 
+{%- if controller.backup.engine != None %}
+  {%- set cinder_log_services = controller.services + controller.backup.services %}
+{%- else %}
+  {%- set cinder_log_services = controller.services %}
+{%- endif %}
+
+{%- for service_name in cinder_log_services %}
+{{ service_name }}_default:
+  file.managed:
+    - name: /etc/default/{{ service_name }}
+    - source: salt://cinder/files/default
+    - template: jinja
+    - defaults:
+        service_name: {{ service_name }}
+        values: {{ controller }}
+    - require:
+      - pkg: cinder_controller_packages
+{%- if controller.backup.engine != None %}
+      - pkg: cinder_backup_packages
+{%- endif %}
+    - watch_in:
+      - service: cinder_controller_services
+{%- if controller.backup.engine != None %}
+      - pkg: cinder_backup_services
+{%- endif %}
+{%- endfor %}
+
+{% if controller.logging.log_appender %}
+
+{%- if controller.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+cinder_controller_fluentd_logger_package:
+  pkg.installed:
+    - name: python-fluent-logger
+{%- endif %}
+
+cinder_general_logging_conf:
+  file.managed:
+    - name: /etc/cinder/logging.conf
+    - source: salt://cinder/files/logging.conf
+    - template: jinja
+    - user: cinder
+    - group: cinder
+    - defaults:
+        service_name: cinder
+        values: {{ controller }}
+    - require:
+      - pkg: cinder_controller_packages
+{%- if controller.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+      - pkg: cinder_controller_fluentd_logger_package
+{%- endif %}
+    - watch_in:
+      - service: cinder_controller_services
+      - service: cinder_api_service
+
+/var/log/cinder/cinder.log:
+  file.managed:
+    - user: cinder
+    - group: cinder
+    - watch_in:
+      - service: cinder_controller_services
+      - service: cinder_api_service
+
+{% for service_name in cinder_log_services %}
+{{ service_name }}_logging_conf:
+  file.managed:
+    - name: /etc/cinder/logging/logging-{{ service_name }}.conf
+    - source: salt://cinder/files/logging.conf
+    - template: jinja
+    - makedirs: True
+    - user: cinder
+    - group: cinder
+    - defaults:
+        service_name: {{ service_name }}
+        values: {{ controller }}
+    - require:
+      - pkg: cinder_controller_packages
+{%- if controller.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+      - pkg: cinder_controller_fluentd_logger_package
+{%- endif %}
+{%- if controller.backup.engine != None %}
+      - pkg: cinder_backup_packages
+{%- endif %}
+    - watch_in:
+      - service: cinder_controller_services
+{%- if controller.backup.engine != None %}
+      - pkg: cinder_backup_services
+{%- endif %}
+{% endfor %}
+
+{% endif %}
+
 {%- for name, rule in controller.get('policy', {}).iteritems() %}
 
 {%- if rule != None %}
diff --git a/cinder/files/default b/cinder/files/default
new file mode 100644
index 0000000..99f34b9
--- /dev/null
+++ b/cinder/files/default
@@ -0,0 +1,4 @@
+# Generated by Salt.
+{% if values.logging.log_appender %}
+DAEMON_ARGS="--log-config-append=/etc/cinder/logging/logging-{{ service_name }}.conf"
+{% endif %}
diff --git a/cinder/files/logging.conf b/cinder/files/logging.conf
new file mode 100644
index 0000000..7130ebf
--- /dev/null
+++ b/cinder/files/logging.conf
@@ -0,0 +1,77 @@
+{%- 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, cinder
+
+[handlers]
+keys = {{ log_handlers | join(", ") }}
+
+[formatters]
+keys = context, default, fluentd
+
+[logger_root]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+
+[logger_cinder]
+level = INFO
+handlers = {{ log_handlers | join(", ") }}
+qualname = cinder
+propagate = 0
+
+[logger_amqplib]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+qualname = amqplib
+
+[logger_sqlalchemy]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+qualname = sqlalchemy
+# "level = INFO" logs SQL queries.
+# "level = DEBUG" logs SQL queries and results.
+# "level = WARNING" logs neither.  (Recommended for production systems.)
+
+[logger_boto]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+qualname = boto
+
+[logger_suds]
+level = INFO
+handlers = {{ log_handlers | join(", ") }}
+qualname = suds
+
+[logger_eventletwsgi]
+level = WARNING
+handlers = {{ log_handlers | join(", ") }}
+qualname = eventlet.wsgi.server
+
+{%- if values.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+[handler_fluentd]
+class = fluent.handler.FluentHandler
+args = ('openstack.{{ service_name | replace("-", ".") }}', 'localhost', 24224)
+formatter = fluentd
+{%- endif %}
+
+{%- if values.logging.log_handlers.watchedfile.enabled %}
+[handler_watchedfile]
+class = handlers.WatchedFileHandler
+args = ('/var/log/cinder/{{ service_name }}.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/cinder/files/mitaka/cinder.conf.controller.Debian b/cinder/files/mitaka/cinder.conf.controller.Debian
index 852e974..8a66c11 100644
--- a/cinder/files/mitaka/cinder.conf.controller.Debian
+++ b/cinder/files/mitaka/cinder.conf.controller.Debian
@@ -83,6 +83,10 @@
 volumes_dir = /var/lib/cinder/volumes
 log_dir=/var/log/cinder
 
+{%- if controller.logging.log_appender %}
+log_config_append=/etc/cinder/logging.conf
+{%- endif %}
+
 # Use syslog for logging. (boolean value)
 #use_syslog=false
 
diff --git a/cinder/files/newton/cinder.conf.controller.Debian b/cinder/files/newton/cinder.conf.controller.Debian
index 701f78f..6a0a6a2 100644
--- a/cinder/files/newton/cinder.conf.controller.Debian
+++ b/cinder/files/newton/cinder.conf.controller.Debian
@@ -82,6 +82,9 @@
 
 volumes_dir = /var/lib/cinder/volumes
 log_dir=/var/log/cinder
+{%- if controller.logging.log_appender %}
+log_config_append=/etc/cinder/logging.conf
+{%- endif %}
 
 # Use syslog for logging. (boolean value)
 #use_syslog=false
diff --git a/cinder/files/ocata/cinder.conf.controller.Debian b/cinder/files/ocata/cinder.conf.controller.Debian
index 8bc04ef..a36f403 100644
--- a/cinder/files/ocata/cinder.conf.controller.Debian
+++ b/cinder/files/ocata/cinder.conf.controller.Debian
@@ -86,6 +86,9 @@
 
 volumes_dir = /var/lib/cinder/volumes
 log_dir=/var/log/cinder
+{%- if controller.logging.log_appender %}
+log_config_append=/etc/cinder/logging.conf
+{%- endif %}
 
 # Use syslog for logging. (boolean value)
 #use_syslog=false
diff --git a/cinder/map.jinja b/cinder/map.jinja
index e04b232..35af31f 100644
--- a/cinder/map.jinja
+++ b/cinder/map.jinja
@@ -22,7 +22,15 @@
           'pkgs': ['cinder-backup'],
           'services': ['cinder-backup'],
           'engine': None
-        }
+        },
+        'logging': {
+          'log_appender': false,
+          'log_handlers': {
+            'watchedfile': {
+              'enabled': true
+            }
+          },
+        },
     },
     'RedHat': {
         'pkgs': ['openstack-cinder', 'python-cinder', 'lvm2', 'python-pycadf'],
@@ -39,8 +47,15 @@
           'pkgs': ['cinder-backup'],
           'services': ['cinder-backup'],
           'engine': None
-        }
-
+        },
+        'logging': {
+          'log_appender': false,
+          'log_handlers': {
+            'watchedfile': {
+              'enabled': true
+            }
+          },
+        },
     },
 }, merge=pillar.cinder.get('controller', {}), base='BaseDefaults') %}
 
@@ -60,8 +75,15 @@
           'pkgs': ['cinder-backup'],
           'services': ['cinder-backup'],
           'engine': None
-        }
-
+        },
+        'logging': {
+          'log_appender': false,
+          'log_handlers': {
+            'watchedfile': {
+              'enabled': true
+            }
+          },
+        },
     },
     'RedHat': {
         'pkgs': ['openstack-cinder', 'python-cinder', 'lvm2', 'sysfsutils', 'sg3_utils', 'device-mapper-multipath', 'device-mapper-multipath-libs', 'python-pycadf'],
@@ -77,7 +99,15 @@
           'pkgs': ['cinder-backup'],
           'services': ['cinder-backup'],
           'engine': None
-        }
+        },
+        'logging': {
+          'log_appender': false,
+          'log_handlers': {
+            'watchedfile': {
+              'enabled': true
+            }
+          },
+        },
     },
 }, merge=pillar.cinder.get('volume', {}), base='BaseDefaults') %}
 
diff --git a/cinder/meta/fluentd.yml b/cinder/meta/fluentd.yml
new file mode 100644
index 0000000..0951dd0
--- /dev/null
+++ b/cinder/meta/fluentd.yml
@@ -0,0 +1,171 @@
+{%- from "cinder/map.jinja" import controller with context %}
+{%- if pillar.get('fluentd', {}).get('agent', {}).get('enabled', False) %}
+{%- set positiondb = pillar.fluentd.agent.dir.positiondb %}
+{%- set apache_wsgi = controller.get('enabled', False) and controller.version == 'ocata' %}
+agent:
+  config:
+    label:
+      forward_input:
+        input:
+          generic_forward_input:
+            type: forward
+            bind: 0.0.0.0
+            port: 24224
+        match:
+          route_openstack_cinder:
+            tag: openstack.cinder.**
+            type: relabel
+            label: openstack_cinder
+{%- if apache_wsgi %}
+      openstack_cinder_wsgi:
+        input:
+          cinder_api_wsgi_in_tail:
+            type: tail
+            path: /var/log/apache2/cinder.log
+            tag: openstack.cinder
+            pos_file: {{ positiondb }}/cinder.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_cinder_wsgi_record_fields:
+            tag: openstack.cinder
+            type: record_transformer
+            enable_ruby: true
+            record:
+              - name: Severity
+                value: 6
+              - name: severity_label
+                value: INFO
+              - name: programname
+                value: cinder-wsgi
+              - name: http_response_time
+                value: ${ record['http_response_time'].to_i/100000.to_f }
+        match:
+          send_to_default:
+            tag: openstack.cinder
+            type: copy
+            store:
+              - type: relabel
+                label: default_output
+              - type: rewrite_tag_filter
+                rule:
+                  - name: severity_label
+                    regexp: '.'
+                    result: metric.cinder_log_messages
+              - type: rewrite_tag_filter
+                rule:
+                  - name: http_status
+                    regexp: '.'
+                    result: metric.cinder_openstack_http_response
+          push_to_metric:
+            tag: 'metric.**'
+            type: relabel
+            label: default_metric
+{%- endif %}
+      openstack_cinder:
+        filter:
+          set_programname:
+            tag: openstack.cinder.*
+            type: record_transformer
+            enable_ruby: true
+            record:
+              - name: programname
+                value: cinder-${ tag_parts[2] }
+        filter:
+          set_log_record_fields:
+            tag: openstack.cinder
+            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: Payload
+                value: ${ record['message'] }
+              - name: python_module
+                value: ${ record['name'] }
+              - name: programname
+                value: '${ record["programname"] ? record["programname"] : "cinder" }'
+          parse_http_stats:
+            tag: openstack.cinder
+            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.cinder.*
+            type: rewrite_tag_filter
+            rule:
+              - name: level
+                regexp: '.*'
+                result: openstack.cinder
+          send_to_default:
+            tag: openstack.cinder
+            type: copy
+            store:
+              - type: relabel
+                label: default_output
+              - type: rewrite_tag_filter
+                rule:
+                  - name: severity_label
+                    regexp: '.'
+                    result: metric.cinder_log_messages
+              - type: rewrite_tag_filter
+                rule:
+                  - name: http_status
+                    regexp: '.'
+                    result: metric.cinder_openstack_http_response
+          push_to_metric:
+            tag: 'metric.**'
+            type: relabel
+            label: default_metric
+      default_metric:
+        filter:
+          cinder_logs_per_severity:
+            tag: metric.cinder_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: cinder
+              - name: level
+                value: ${severity_label}
+              - name: host
+                value: ${Hostname}
+          cinder_openstack_http_response_times:
+            tag: metric.cinder_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: cinder
+              - name: host
+                value: ${Hostname}
+{% endif %}
\ No newline at end of file
diff --git a/cinder/volume.sls b/cinder/volume.sls
index 4df74c7..dd35bf4 100644
--- a/cinder/volume.sls
+++ b/cinder/volume.sls
@@ -65,6 +65,70 @@
     - pkg: cinder_volume_packages
 
 {%- if volume.backup.engine != None %}
+  {%- set cinder_log_services = volume.services + volume.backup.services %}
+{%- else %}
+  {%- set cinder_log_services = volume.services %}
+{%- endif %}
+
+{% for service_name in cinder_log_services %}
+{{ service_name }}_default:
+  file.managed:
+    - name: /etc/default/{{ service_name }}
+    - source: salt://cinder/files/default
+    - template: jinja
+    - defaults:
+        service_name: {{ service_name }}
+        values: {{ volume }}
+    - require:
+      - pkg: cinder_volume_packages
+{%- if volume.backup.engine != None %}
+      - pkg: cinder_backup_packages
+{%- endif %}
+    - watch_in:
+      - service: cinder_volume_services
+{%- if volume.backup.engine != None %}
+      - pkg: cinder_backup_services
+{%- endif %}
+{% endfor %}
+
+{% if volume.logging.log_appender %}
+
+{%- if volume.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+cinder_volume_fluentd_logger_package:
+  pkg.installed:
+    - name: python-fluent-logger
+{%- endif %}
+
+{% for service_name in cinder_log_services %}
+{{ service_name }}_logging_conf:
+  file.managed:
+    - name: /etc/cinder/logging/logging-{{ service_name }}.conf
+    - source: salt://cinder/files/logging.conf
+    - template: jinja
+    - makedirs: True
+    - user: cinder
+    - group: cinder
+    - defaults:
+        service_name: {{ service_name }}
+        values: {{ volume }}
+    - require:
+      - pkg: cinder_volume_packages
+{%- if volume.logging.log_handlers.get('fluentd', {}).get('enabled', False) %}
+      - pkg: cinder_volume_fluentd_logger_package
+{%- endif %}
+{%- if controller.backup.engine != None %}
+      - pkg: cinder_backup_packages
+{%- endif %}
+    - watch_in:
+      - service: cinder_volume_services
+{%- if controller.backup.engine != None %}
+      - pkg: cinder_backup_services
+{%- endif %}
+{% endfor %}
+
+{% endif %}
+
+{%- if volume.backup.engine != None %}
 
 cinder_backup_packages:
   pkg.installed:
diff --git a/metadata/service/control/cluster.yml b/metadata/service/control/cluster.yml
index ffd2aac..3bc81cf 100644
--- a/metadata/service/control/cluster.yml
+++ b/metadata/service/control/cluster.yml
@@ -5,6 +5,8 @@
 parameters:
   _param:
     keystone_cinder_endpoint_type: internalURL
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   cinder:
     controller:
       enabled: true
@@ -30,6 +32,13 @@
       glance:
         host: ${_param:cluster_vip_address}
         port: 9292
+      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/control/cluster_control.yml b/metadata/service/control/cluster_control.yml
index ffd2aac..3bc81cf 100644
--- a/metadata/service/control/cluster_control.yml
+++ b/metadata/service/control/cluster_control.yml
@@ -5,6 +5,8 @@
 parameters:
   _param:
     keystone_cinder_endpoint_type: internalURL
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   cinder:
     controller:
       enabled: true
@@ -30,6 +32,13 @@
       glance:
         host: ${_param:cluster_vip_address}
         port: 9292
+      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/control/single.yml b/metadata/service/control/single.yml
index 1bf8378..3ebd30d 100644
--- a/metadata/service/control/single.yml
+++ b/metadata/service/control/single.yml
@@ -5,6 +5,8 @@
 parameters:
   _param:
     keystone_cinder_endpoint_type: internalURL
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   cinder:
     controller:
       enabled: true
@@ -30,6 +32,13 @@
       glance:
         host: ${_param:single_address}
         port: 9292
+      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 9298460..f1a069b 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:
diff --git a/metadata/service/volume/local.yml b/metadata/service/volume/local.yml
index 592f010..074ed9d 100644
--- a/metadata/service/volume/local.yml
+++ b/metadata/service/volume/local.yml
@@ -5,6 +5,8 @@
 parameters:
   _param:
     keystone_cinder_endpoint_type: internalURL
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   cinder:
     volume:
       enabled: true
@@ -30,6 +32,13 @@
       glance:
         host: ${_param:single_address}
         port: 9292
+      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/volume/single.yml b/metadata/service/volume/single.yml
index 65a5640..689f0a6 100644
--- a/metadata/service/volume/single.yml
+++ b/metadata/service/volume/single.yml
@@ -5,6 +5,8 @@
 parameters:
   _param:
     keystone_cinder_endpoint_type: internalURL
+    openstack_log_appender: false
+    openstack_fluentd_handler_enabled: false
   cinder:
     volume:
       enabled: true
@@ -30,6 +32,13 @@
       glance:
         host: ${_param:cluster_vip_address}
         port: 9292
+      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}