ERP5: fix neo log rotation

neo logs to sqlite databases, not to "append only" files, so we need extra
care when rotation and cannot use the new "copytruncate" approach.

needs nexedi/erp5!1786

See merge request nexedi/slapos!1395

software/erp5/test/test/__init__.py

@@ -179,6 +179,10 @@ class ERP5InstanceTestCase(SlapOSInstanceTestCase, metaclass=ERP5InstanceTestMet
   """
   __test_matrix__ = matrix((zeo, neo))  # switch between NEO and ZEO mode
 
+  @classmethod
+  def isNEO(cls):
+    return '_neo' in cls.__name__
+
   @classmethod
   def getRootPartitionConnectionParameterDict(cls):
     """Return the output parameters from the root partition"""

software/erp5/test/test/test_erp5.py

@@ -34,6 +34,7 @@ import json
 import os
 import shutil
 import socket
+import sqlite3
 import ssl
 import subprocess
 import sys
@@ -48,7 +49,7 @@ import xmlrpc.client
 import urllib3
 from slapos.testing.utils import CrontabMixin
 
-from . import ERP5InstanceTestCase, setUpModule, matrix, default
+from . import ERP5InstanceTestCase, setUpModule, matrix, default, neo
 
 setUpModule # pyflakes
 
@@ -789,6 +790,39 @@ class ZopeTestMixin(ZopeSkinsMixin, CrontabMixin):
     self.assertTrue(os.path.exists(rotated_log_file + '.xz'))
     self.assertFalse(os.path.exists(rotated_log_file))
 
+  def test_neo_root_log_rotation(self):
+    zope_neo_root_log_path = os.path.join(
+      self.getComputerPartitionPath('zope-default'),
+      'var',
+      'log',
+      'zope-0-neo-root.log',
+    )
+    if not self.isNEO():
+      self.assertFalse(os.path.exists(zope_neo_root_log_path))
+      return
+
+    def check_sqlite_log(path):
+      with contextlib.closing(sqlite3.connect(path)) as con:
+        con.execute('select * from log')
+
+    check_sqlite_log(zope_neo_root_log_path)
+    self._executeCrontabAtDate('logrotate', '2050-01-01')
+
+    rotated_log_file = os.path.join(
+      self.getComputerPartitionPath('zope-default'),
+      'srv',
+      'backup',
+      'logrotate',
+      'zope-0-neo-root.log-20500101',
+    )
+    check_sqlite_log(rotated_log_file)
+
+    self._executeCrontabAtDate('logrotate', '2050-01-02')
+    self.assertTrue(os.path.exists(rotated_log_file + '.xz'))
+    self.assertFalse(os.path.exists(rotated_log_file))
+    requests.get(self._getAuthenticatedZopeUrl('/'), verify=False).raise_for_status()
+    check_sqlite_log(zope_neo_root_log_path)
+
   def test_basic_authentication_user_in_access_log(self):
     param_dict = self.getRootPartitionConnectionParameterDict()
     requests.get(self.zope_base_url,
@@ -866,7 +900,7 @@ class ZopeTestMixin(ZopeSkinsMixin, CrontabMixin):
         'zope-2-Z2.log',
         'zope-2-event.log',
         'zope-2-neo-root.log',
-      ] if '_neo' in self.__class__.__name__ else [
+      ] if self.isNEO() else [
         'zope-0-Z2.log',
         'zope-0-event.log',
         'zope-1-Z2.log',
@@ -1004,3 +1038,66 @@ class TestCloudoooDefaultParameter(ZopeSkinsMixin, ERP5InstanceTestCase):
             'portal_preferences/getPreferredDocumentConversionServerRetry'),
           verify=False).text,
       "2")
+
+
+class TestNEO(ZopeSkinsMixin, CrontabMixin, ERP5InstanceTestCase):
+  """Tests specific to neo storage
+  """
+  __partition_reference__ = 'n'
+  __test_matrix__ = matrix((neo,))
+
+  def _getCrontabCommand(self, crontab_name):
+    # type: (str) -> str
+    """Read a crontab and return the command that is executed.
+
+    overloaded to use crontab from neo partition
+    """
+    with open(
+        os.path.join(
+            self.getComputerPartitionPath('neo-0'),
+            'etc',
+            'cron.d',
+            crontab_name,
+        )) as f:
+      crontab_spec, = f.readlines()
+    self.assertNotEqual(crontab_spec[0], '@', crontab_spec)
+    return crontab_spec.split(None, 5)[-1]
+
+  def test_log_rotation(self):
+    # first run to create state files
+    self._executeCrontabAtDate('logrotate', '2000-01-01')
+
+    def check_sqlite_log(path):
+      with self.subTest(path), contextlib.closing(sqlite3.connect(path)) as con:
+        con.execute('select * from log')
+
+    logfiles = ('neoadmin.log', 'neomaster.log', 'neostorage-0.log')
+    for f in logfiles:
+      check_sqlite_log(
+        os.path.join(
+          self.getComputerPartitionPath('neo-0'),
+          'var',
+          'log',
+          f))
+
+    self._executeCrontabAtDate('logrotate', '2050-01-01')
+
+    for f in logfiles:
+      check_sqlite_log(
+        os.path.join(
+          self.getComputerPartitionPath('neo-0'),
+          'srv',
+          'backup',
+          'logrotate',
+          f'{f}-20500101'))
+
+    self._executeCrontabAtDate('logrotate', '2050-01-02')
+    requests.get(self._getAuthenticatedZopeUrl('/'), verify=False).raise_for_status()
+
+    for f in logfiles:
+      check_sqlite_log(
+        os.path.join(
+          self.getComputerPartitionPath('neo-0'),
+          'var',
+          'log',
+          f))

stack/erp5/buildout.hash.cfg

@@ -86,7 +86,7 @@ md5sum = 0ac4b74436f554cd677f19275d18d880
 
 [template-zope]
 filename = instance-zope.cfg.in
-md5sum = 558ffbc6d51bb0ce9fc25d1062edcd2a
+md5sum = e6c94c2a48788683bf0d63d135a44932
 
 [template-balancer]
 filename = instance-balancer.cfg.in

stack/erp5/instance-zope.cfg.in

@@ -308,14 +308,14 @@ port = {{ port }}
 event-log = ${directory:log}/{{ name }}-event.log
 z2-log = ${directory:log}/{{ name }}-Z2.log
 node-id = {{ dumps(node_id_base ~ (node_id_index_format % index)) }}
-{% set log_list = [] -%}
+{% set neo_log_list = [] -%}
 {% set import_set = set() -%}
 {% for db_name, zodb in six.iteritems(zodb_dict) -%}
 {%   do zodb.setdefault('pool-size', thread_amount) -%}
 {%   if zodb['type'] == 'neo' -%}
 {%     do import_set.add('neo.client') -%}
 {%     set log = name ~ '-neo-' ~ db_name ~ '.log' -%}
-{%     do log_list.append('${directory:log}/' + log) -%}
+{%     do neo_log_list.append('${directory:log}/' + log) -%}
 {%     do zodb['storage-dict'].update(logfile='~/var/log/'+log) -%}
 {%   endif -%}
 {% endfor -%}
@@ -350,6 +350,7 @@ wrapped-command-line =
     '${:configuration-file}'
     --threads={{ thread_amount }}
     --large-file-threshold={{ slapparameter_dict['large-file-threshold'] }}
+    --pidfile={{ '${' ~ conf_parameter_name ~ ':pid-file}' }}
 {%- set private_dev_shm = slapparameter_dict['private-dev-shm'] %}
 {%- if private_dev_shm %}
 private-tmpfs = {{ private_dev_shm }} /dev/shm
@@ -408,8 +409,18 @@ config-maximum-delay = {{ slapparameter_dict["zope-longrequest-logger-maximum-de
 [{{ section('logrotate-entry-' ~ name) }}]
 < = logrotate-entry-base
 name = {{ name }}
-log = {{ '${' ~ conf_parameter_name ~ ':event-log}' }} {{ '${' ~ conf_parameter_name ~ ':z2-log}' }} {{ '${' ~ conf_parameter_name ~ ':longrequest-logger-file}' }} {{ ' '.join(log_list) }}
+log = {{ '${' ~ conf_parameter_name ~ ':event-log}' }} {{ '${' ~ conf_parameter_name ~ ':z2-log}' }} {{ '${' ~ conf_parameter_name ~ ':longrequest-logger-file}' }}
 copytruncate = true
+
+{% if neo_log_list -%}
+[{{ section('logrotate-entry-neo-' ~ name) }}]
+< = logrotate-entry-base
+name = neo-{{ name }}
+log = {{ ' '.join(neo_log_list) }}
+# we don't use copytruncate on neo logs, they are not regular text files but sqlite databases
+copytruncate =
+post = test ! -s {{ '${' ~ conf_parameter_name ~ ':pid-file}' }} || {{ bin_directory }}/slapos-kill --pidfile {{ '${' ~ conf_parameter_name ~ ':pid-file}' }} -s USR2
+{% endif %}
 {% endmacro -%}
 
 {% for i in instance_index_list -%}

stack/logrotate/buildout.hash.cfg

@@ -22,4 +22,4 @@ md5sum = 02c1009f8e0dc371cfc1290afef72ec7
 
 [template-logrotate-base]
 filename = instance-logrotate-base.cfg.in
-md5sum = 4e2baa1edd1d27831dda984769102a7c
+md5sum = 303fad78d62d6e29c0c547a9f64fa822

stack/logrotate/instance-logrotate-base.cfg.in

@@ -47,6 +47,8 @@ context =
 # - "post" with commands to execute after rotation
 # - "pre" with commands to execute before rotation
 # - "backup" with directory where to store logs
+# - "copytruncate" to use logrotate's copytruncate option, setting to ""
+#    (the default) disable copytruncate, setting to anything else enable copytruncate
 recipe = slapos.recipe.template:jinja2
 url = {{ logrotate_entry_template }}
 output = ${logrotate-conf-parameter:logrotate-entries}/${:name}
@@ -60,7 +62,7 @@ context =
   key rotate_num :rotate-num
   key nocompress :nocompress
   key delaycompress :delaycompress
-copytruncate = false
+copytruncate =
 post =
 pre =
 frequency = daily