From b4f90c6ecac8b2b7123298c8f5c93378f47a8d74 Mon Sep 17 00:00:00 2001 From: Pete Vander Giessen Date: Thu, 26 Sep 2019 20:56:52 +0000 Subject: [PATCH] Make logging better Move logging output for most services to systemd. Add a hook in snap.openstack to tell OpenStack services to wait until we set database.ready in the snap config before starting. This prevents spamming systemd with error messages before we run microstack.init (See matching PR against snap.openstack, coming soon.) Incidentally fix issue w/ the way that shell.py was running CalledProcessError and parsing output. Order patches part after uca-sources, to work around an issue we discovered with apt update while those two parts are running in parallel. (python-apt segfaults, and no fun is had by anyone.) Remaining gaps in our logging: systemd still displays some errors during init, which might be fixable with further ordering of snapctl start invocations. We're also relying on MySQL and RabbitMQ log output to know when those services are started, so we haven't moved their output to systemd just yet. Dropped in a fix to work w/ updated version of snap.openstack. Change-Id: I130ed730c14ab35b8b677b9c9f573fa6fe1e8f13 --- snap-overlay/snap-openstack.yaml | 31 ++------------- snap-overlay/templates/glance-snap.conf.j2 | 2 + snap-overlay/templates/horizon-nginx.conf.j2 | 4 +- snap-overlay/templates/horizon-snap.conf.j2 | 2 + snap-overlay/templates/keystone-nginx.conf.j2 | 4 +- snap-overlay/templates/keystone-snap.conf.j2 | 2 + snap-overlay/templates/neutron-snap.conf.j2 | 2 + snap-overlay/templates/nginx.conf.j2 | 4 +- snap-overlay/templates/nova-snap.conf.j2 | 5 +-- snap-overlay/templates/virtlogd.conf.j2 | 1 + snapcraft.yaml | 3 ++ tools/init/init/questions.py | 39 +++++++++++++++++++ tools/init/init/shell.py | 8 ++-- 13 files changed, 66 insertions(+), 41 deletions(-) diff --git a/snap-overlay/snap-openstack.yaml b/snap-overlay/snap-openstack.yaml index 51e23d8..654d03e 100644 --- a/snap-overlay/snap-openstack.yaml +++ b/snap-overlay/snap-openstack.yaml @@ -57,10 +57,10 @@ setup: "{snap_common}/instances": 0755 "{snap_common}/etc/microstack.rc": 0644 snap-config-keys: - - ospassword - - extgateway - - extcidr - - dns + ospassword: 'ospassword' + extgateway: 'extgateway' + extcidr: 'extcidr' + dns: 'dns' entry_points: keystone-manage: binary: "{snap}/bin/keystone-manage" @@ -74,14 +74,12 @@ entry_points: type: uwsgi uwsgi-dir: "{snap_common}/etc/keystone/uwsgi/snap" uwsgi-dir-override: "{snap_common}/etc/keystone/uwsgi" - uwsgi-log: "{snap_common}/log/keystone-uwsgi.log" config-files: - "{snap}/etc/keystone/keystone.conf" config-files-override: - "{snap_common}/etc/keystone/keystone.conf" config-dirs: - "{snap_common}/etc/keystone/keystone.conf.d" - log-file: "{snap_common}/log/keystone.log" templates: keystone-api.ini.j2: "{snap_common}/etc/keystone/uwsgi/snap/keystone-api.ini" nginx: @@ -96,19 +94,16 @@ entry_points: - "{snap_common}/etc/nova/nova.conf" config-dirs: - "{snap_common}/etc/nova/nova.conf.d" - log-file: "{snap_common}/log/nova-api-os-compute.log" nova-uwsgi: type: uwsgi uwsgi-dir: "{snap_common}/etc/nova/uwsgi/snap" uwsgi-dir-override: "{snap_common}/etc/nova/uwsgi" - uwsgi-log: "{snap_common}/log/nova-uwsgi.log" config-files: - "{snap}/etc/nova/nova.conf" config-files-override: - "{snap_common}/etc/nova/nova.conf" config-dirs: - "{snap_common}/etc/nova/nova.conf.d" - log-file: "{snap_common}/log/nova-placement-api.log" templates: nova-placement-api.ini.j2: "{snap_common}/etc/nova/uwsgi/snap/nova-placement-api.ini" @@ -120,7 +115,6 @@ entry_points: - "{snap_common}/etc/nova/nova.conf" config-dirs: - "{snap_common}/etc/nova/nova.conf.d" - log-file: "{snap_common}/log/nova-conductor.log" nova-scheduler: binary: "{snap}/bin/nova-scheduler" config-files: @@ -129,7 +123,6 @@ entry_points: - "{snap_common}/etc/nova/nova.conf" config-dirs: - "{snap_common}/etc/nova/nova.conf.d" - log-file: "{snap_common}/log/nova-scheduler.log" nova-compute: binary: "{snap}/bin/nova-compute" config-files: @@ -138,7 +131,6 @@ entry_points: - "{snap_common}/etc/nova/nova.conf" config-dirs: - "{snap_common}/etc/nova/nova.conf.d" - log-file: "{snap_common}/log/nova-compute.log" nova-api-metadata: binary: "{snap}/bin/nova-api-metadata" config-files: @@ -147,7 +139,6 @@ entry_points: - "{snap_common}/etc/nova/nova.conf" config-dirs: - "{snap_common}/etc/nova/nova.conf.d" - log-file: "{snap_common}/log/nova-api-metadata.log" nova-manage: binary: "{snap}/bin/nova-manage" config-files: @@ -176,7 +167,6 @@ entry_points: - "{snap_common}/etc/neutron/plugins/ml2/ml2_conf.ini" config-dirs: - "{snap_common}/etc/neutron/neutron.conf.d" - log-file: "{snap_common}/log/neutron-server.log" neutron-openvswitch-agent: binary: "{snap}/bin/neutron-openvswitch-agent" config-files: @@ -187,7 +177,6 @@ entry_points: - "{snap_common}/etc/neutron/plugins/ml2/openvswitch_agent.ini" config-dirs: - "{snap_common}/etc/neutron/neutron.conf.d" - log-file: "{snap_common}/log/neutron-openvswitch-agent.log" neutron-ovs-cleanup: binary: "{snap}/bin/neutron-ovs-cleanup" config-files: @@ -214,7 +203,6 @@ entry_points: - "{snap_common}/etc/neutron/l3_agent.ini" config-dirs: - "{snap_common}/etc/neutron/neutron.conf.d" - log-file: "{snap_common}/log/neutron-l3-agent.log" neutron-dhcp-agent: binary: "{snap}/bin/neutron-dhcp-agent" config-files: @@ -225,7 +213,6 @@ entry_points: - "{snap_common}/etc/neutron/dhcp_agent.ini" config-dirs: - "{snap_common}/etc/neutron/neutron.conf.d" - log-file: "{snap_common}/log/neutron-dhcp-agent.log" neutron-metadata-agent: binary: "{snap}/bin/neutron-metadata-agent" config-files: @@ -236,7 +223,6 @@ entry_points: - "{snap_common}/etc/neutron/metadata_agent.ini" config-dirs: - "{snap_common}/etc/neutron/neutron.conf.d" - log-file: "{snap_common}/log/neutron-metadata-agent.log" glance-manage: binary: "{snap}/bin/glance-manage" config-files: @@ -253,7 +239,6 @@ entry_points: - "{snap_common}/etc/glance/glance-registry.conf" config-dirs: - "{snap_common}/etc/glance/glance.conf.d" - log-file: "{snap_common}/log/glance-registry.log" glance-api: binary: "{snap}/bin/glance-api" config-files: @@ -262,7 +247,6 @@ entry_points: - "{snap_common}/etc/glance/glance-api.conf" config-dirs: - "{snap_common}/etc/glance/glance.conf.d" - log-file: "{snap_common}/log/glance-api.log" cinder-backup: binary: "{snap}/bin/cinder-backup" config-files: @@ -271,7 +255,6 @@ entry_points: - "{snap_common}/etc/cinder/cinder.conf" config-dirs: - "{snap_common}/etc/cinder/cinder.conf.d" - log-file: "{snap_common}/log/cinder-backup.log" cinder-manage: binary: "{snap}/bin/cinder-manage" config-files: @@ -288,7 +271,6 @@ entry_points: - "{snap_common}/etc/cinder/cinder.conf" config-dirs: - "{snap_common}/etc/cinder/cinder.conf.d" - log-file: "{snap_common}/log/cinder-scheduler.log" cinder-volume: binary: "{snap}/bin/cinder-volume" config-files: @@ -297,28 +279,23 @@ entry_points: - "{snap_common}/etc/cinder/cinder.conf" config-dirs: - "{snap_common}/etc/cinder/cinder.conf.d" - log-file: "{snap_common}/log/cinder-volume.log" cinder-uwsgi: type: uwsgi uwsgi-dir: "{snap_common}/etc/cinder/uwsgi/snap" uwsgi-dir-override: "{snap_common}/etc/cinder/uwsgi" - uwsgi-log: "{snap_common}/log/cinder-uwsgi.log" config-files: - "{snap}/etc/cinder/cinder.conf" config-files-override: - "{snap_common}/etc/cinder/cinder.conf" config-dirs: - "{snap_common}/etc/cinder/cinder.conf.d" - log-file: "{snap_common}/log/cinder-api.log" templates: cinder-api.ini.j2: "{snap_common}/etc/cinder/uwsgi/snap/cinder-api.ini" horizon-uwsgi: type: uwsgi uwsgi-dir: "{snap_common}/etc/horizon/uwsgi/snap" uwsgi-dir-override: "{snap_common}/etc/horizon/uwsgi" - uwsgi-log: "{snap_common}/log/horizon-uwsgi.log" config-dirs: - "{snap_common}/etc/horizon/horizon.conf.d" - log-file: "{snap_common}/log/horizon-api.log" templates: horizon.ini.j2: "{snap_common}/etc/horizon/uwsgi/snap/horizon.ini" diff --git a/snap-overlay/templates/glance-snap.conf.j2 b/snap-overlay/templates/glance-snap.conf.j2 index ea3df65..8a5e94d 100644 --- a/snap-overlay/templates/glance-snap.conf.j2 +++ b/snap-overlay/templates/glance-snap.conf.j2 @@ -1,6 +1,8 @@ [DEFAULT] # Set state path to writable directory state_path = {{ snap_common }}/lib +# Log to systemd journal +use_journal = True [oslo_concurrency] # Oslo Concurrency lock path diff --git a/snap-overlay/templates/horizon-nginx.conf.j2 b/snap-overlay/templates/horizon-nginx.conf.j2 index 2bcca62..c06b400 100644 --- a/snap-overlay/templates/horizon-nginx.conf.j2 +++ b/snap-overlay/templates/horizon-nginx.conf.j2 @@ -3,8 +3,8 @@ # also update "api-name" for the socket. server { listen 80; - access_log {{ snap_common }}/log/nginx-access.log; - error_log {{ snap_common }}/log/nginx-error.log; + error_log syslog:server=unix:/dev/log; + access_log syslog:server=unix:/dev/log; location / { include {{ snap }}/usr/conf/uwsgi_params; uwsgi_param SCRIPT_NAME ''; diff --git a/snap-overlay/templates/horizon-snap.conf.j2 b/snap-overlay/templates/horizon-snap.conf.j2 index f683970..196f315 100644 --- a/snap-overlay/templates/horizon-snap.conf.j2 +++ b/snap-overlay/templates/horizon-snap.conf.j2 @@ -1,6 +1,8 @@ [DEFAULT] # Set state path to writable directory state_path = {{ snap_common }}/lib +# Log to systemd journal +use_journal = True [oslo_concurrency] # Oslo Concurrency lock path diff --git a/snap-overlay/templates/keystone-nginx.conf.j2 b/snap-overlay/templates/keystone-nginx.conf.j2 index 6172998..413e923 100644 --- a/snap-overlay/templates/keystone-nginx.conf.j2 +++ b/snap-overlay/templates/keystone-nginx.conf.j2 @@ -1,7 +1,7 @@ server { listen 5000; - access_log {{ snap_common }}/log/nginx-access.log; - error_log {{ snap_common }}/log/nginx-error.log; + error_log syslog:server=unix:/dev/log; + access_log syslog:server=unix:/dev/log; location / { include {{ snap }}/usr/conf/uwsgi_params; uwsgi_param SCRIPT_NAME ''; diff --git a/snap-overlay/templates/keystone-snap.conf.j2 b/snap-overlay/templates/keystone-snap.conf.j2 index fca2577..0ef6927 100644 --- a/snap-overlay/templates/keystone-snap.conf.j2 +++ b/snap-overlay/templates/keystone-snap.conf.j2 @@ -1,6 +1,8 @@ [DEFAULT] # Set state path to writable directory state_path = {{ snap_common }}/lib +# Log to systemd journal +use_journal = True [oslo_concurrency] # Oslo Concurrency lock path diff --git a/snap-overlay/templates/neutron-snap.conf.j2 b/snap-overlay/templates/neutron-snap.conf.j2 index f683970..196f315 100644 --- a/snap-overlay/templates/neutron-snap.conf.j2 +++ b/snap-overlay/templates/neutron-snap.conf.j2 @@ -1,6 +1,8 @@ [DEFAULT] # Set state path to writable directory state_path = {{ snap_common }}/lib +# Log to systemd journal +use_journal = True [oslo_concurrency] # Oslo Concurrency lock path diff --git a/snap-overlay/templates/nginx.conf.j2 b/snap-overlay/templates/nginx.conf.j2 index e982ff3..3cb59b1 100644 --- a/snap-overlay/templates/nginx.conf.j2 +++ b/snap-overlay/templates/nginx.conf.j2 @@ -24,8 +24,8 @@ http { # Logging Settings ## - access_log {{ snap_common }}/log/nginx-access.log; - error_log {{ snap_common }}/log/nginx-error.log; + error_log syslog:server=unix:/dev/log; + access_log syslog:server=unix:/dev/log; ## # Gzip Settings diff --git a/snap-overlay/templates/nova-snap.conf.j2 b/snap-overlay/templates/nova-snap.conf.j2 index 330511f..196f315 100644 --- a/snap-overlay/templates/nova-snap.conf.j2 +++ b/snap-overlay/templates/nova-snap.conf.j2 @@ -1,9 +1,8 @@ [DEFAULT] # Set state path to writable directory state_path = {{ snap_common }}/lib - -# Set logging directory -log-dir = {{ snap_common }}/log +# Log to systemd journal +use_journal = True [oslo_concurrency] # Oslo Concurrency lock path diff --git a/snap-overlay/templates/virtlogd.conf.j2 b/snap-overlay/templates/virtlogd.conf.j2 index 877481e..71c8b43 100644 --- a/snap-overlay/templates/virtlogd.conf.j2 +++ b/snap-overlay/templates/virtlogd.conf.j2 @@ -57,6 +57,7 @@ #log_outputs="3:syslog:virtlogd" # #log_outputs="1:file:{{ snap_common }}/log/libvirtd.log" +log_outputs="2:syslog:virtlogd" # The maximum number of concurrent client connections to allow # over all sockets combined. diff --git a/snapcraft.yaml b/snapcraft.yaml index 5b4d58b..e02bc79 100644 --- a/snapcraft.yaml +++ b/snapcraft.yaml @@ -359,6 +359,7 @@ parts: - coreutils - haproxy - python3-dev + - python3-systemd override-prime: | snapcraftctl prime # Patch Openstack Dashboard (horizon) settings files. @@ -474,6 +475,8 @@ parts: # Snap patches patches: + after: + - uca-sources source: patches/ plugin: dump organize: diff --git a/tools/init/init/questions.py b/tools/init/init/questions.py index ec2bf70..81bb8f7 100644 --- a/tools/init/init/questions.py +++ b/tools/init/init/questions.py @@ -180,6 +180,13 @@ class DatabaseSetup(Question): log.info('Mysql server started! Creating databases ...') self._create_dbs() + check('snapctl', 'set', 'database.ready=true') + + # Start keystone-uwsgi. We use snapctl, because systemd + # doesn't yet know about the service. + check('snapctl', 'start', 'microstack.nginx') + check('snapctl', 'start', 'microstack.keystone-uwsgi') + log.info('Configuring Keystone Fernet Keys ...') check('snap-openstack', 'launch', 'keystone-manage', 'fernet_setup', '--keystone-user', 'root', @@ -261,6 +268,20 @@ class NovaSetup(Question): "GRANT ALL PRIVILEGES ON nova_cell0.* TO 'nova'@'{extgateway}' \ IDENTIFIED BY \'nova';".format(**_env)) + # Use snapctl to start nova services. We need to call them + # out manually, because systemd doesn't know about them yet. + # TODO: parse the output of `snapctl services` to get this + # list automagically. + for service in [ + 'microstack.nova-api', + 'microstack.nova-api-metadata', + 'microstack.nova-compute', + 'microstack.nova-conductor', + 'microstack.nova-scheduler', + 'microstack.nova-uwsgi', + ]: + check('snapctl', 'start', service) + check('snap-openstack', 'launch', 'nova-manage', 'api_db', 'sync') if 'cell0' not in check_output('snap-openstack', 'launch', @@ -307,6 +328,15 @@ class NeutronSetup(Question): 'microstack', 'network', endpoint, 'http://{extgateway}:9696'.format(**_env)) + for service in [ + 'microstack.neutron-api', + 'microstack.neutron-dhcp-agent', + 'microstack.neutron-l3-agent', + 'microstack.neutron-metadata-agent', + 'microstack.neutron-openvswitch-agent', + ]: + check('snapctl', 'start', service) + check('snap-openstack', 'launch', 'neutron-db-manage', 'upgrade', 'head') @@ -385,6 +415,12 @@ class GlanceSetup(Question): 'microstack', 'image', endpoint, 'http://{extgateway}:9292'.format(**_env)) + for service in [ + 'microstack.glance-api', + 'microstack.registry', # TODO rename this to glance-registery + ]: + check('snapctl', 'start', service) + check('snap-openstack', 'launch', 'glance-manage', 'db_sync') restart('glance*') @@ -406,5 +442,8 @@ class PostSetup(Question): # TODO: fix issue. restart('*virt*') + # Start horizon + check('snapctl', 'start', 'microstack.horizon-uwsgi') + check('snapctl', 'set', 'initialized=true') log.info('Complete. Marked microstack as initialized!') diff --git a/tools/init/init/shell.py b/tools/init/init/shell.py index 8a9bba8..9a77e97 100644 --- a/tools/init/init/shell.py +++ b/tools/init/init/shell.py @@ -45,9 +45,10 @@ def _popen(*args: List[str], env: Dict = _env): """ proc = subprocess.Popen(args, env=env, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, bufsize=1, - universal_newlines=True) + universal_newlines=True, encoding='utf-8') for line in iter(proc.stdout.readline, ''): log.debug(line) + proc.wait() return proc @@ -61,10 +62,7 @@ def check(*args: List[str], env: Dict = _env) -> int: """ proc = _popen(*args, env=env) if proc.returncode: - raise subprocess.CalledProcessError( - "Command '{}' returned non-zero exit status {}".format( - " ".join(args), - proc.returncode)) + raise subprocess.CalledProcessError(proc.returncode, " ".join(args)) return proc.returncode