[IMP] runbot: number of log lines per build

When a build is running, a cron, an evil query or something else can
start to fill and bloat the runbot ir_logging table.

With this commit, a log_counter field is added on the build, starting at
100. The SQL trigger decrement this counter after a line is inserted.

When the counter drops to 0, a the last log line contains a message
stating that the limit has been reached. Further log lines are dropped
for this build step.

The counter is reset to a default of 100 before each step.
This value is configurable through an optional ir.config_parameter
runbot_maxlogs.

The runbot itself is still able to add logs lines through the build _log
method.

Thanks @Xavier-Do for the smart idea.

runbot/models/build.py

@@ -108,6 +108,7 @@ class runbot_build(models.Model):
     build_url = fields.Char('Build url', compute='_compute_build_url', store=False)
     build_error_ids = fields.Many2many('runbot.build.error', 'runbot_build_error_ids_runbot_build_rel', string='Errors')
     keep_running = fields.Boolean('Keep running', help='Keep running')
+    log_counter = fields.Integer('Log Lines counter', default=100)
 
     @api.depends('config_id')
     def _compute_log_list(self):  # storing this field because it will be access trhoug repo viewn and keep track of the list at create

runbot/models/build_config.py

@@ -179,6 +179,7 @@ class ConfigStep(models.Model):
         return self._run_step(build, log_path)
 
     def _run_step(self, build, log_path):
+        build.log_counter = self.env['ir.config_parameter'].sudo().get_param('runbot.runbot_maxlogs', 100)
         if self.job_type == 'run_odoo':
             return self._run_odoo_run(build, log_path)
         if self.job_type == 'install_odoo':

runbot/models/event.py

@@ -29,6 +29,28 @@ BEGIN
   IF (NEW.build_id IS NULL AND NEW.dbname IS NOT NULL AND NEW.dbname != current_database()) THEN
     NEW.build_id := split_part(NEW.dbname, '-', 1)::integer;
   END IF;
+  IF (NEW.build_id IS NOT NULL) AND (NEW.type = 'server') THEN
+    DECLARE
+        counter INTEGER;
+    BEGIN
+        UPDATE runbot_build b
+            SET log_counter = log_counter - 1
+        WHERE b.id = NEW.build_id;
+        SELECT log_counter
+        INTO counter
+        FROM runbot_build
+        WHERE runbot_build.id = NEW.build_id;
+        IF (counter = 0) THEN
+            NEW.message = 'Log limit reached (full logs are still available in the log file)';
+            NEW.level = 'SEPARATOR';
+            NEW.func = '';
+            NEW.type = 'runbot';
+            RETURN NEW;
+        ELSIF (counter < 0) THEN
+                RETURN NULL;
+        END IF;
+    END;
+  END IF;
   IF (NEW.build_id IS NOT NULL AND UPPER(NEW.level) NOT IN ('INFO', 'SEPARATOR')) THEN
     BEGIN
         UPDATE runbot_build b

runbot/tests/__init__.py

@@ -6,4 +6,5 @@ from . import test_frontend
 from . import test_schedule
 from . import test_cron
 from . import test_build_config_step
+from . import test_event
 

runbot/tests/test_event.py

@@ -0,0 +1,71 @@
+# -*- coding: utf-8 -*-
+from unittest.mock import patch
+from odoo.tests import common
+
+
+class TestIrLogging(common.TransactionCase):
+
+    def setUp(self):
+        super(TestIrLogging, self).setUp()
+        self.Repo = self.env['runbot.repo']
+        self.repo = self.Repo.create({'name': 'bla@example.com:foo/bar', 'server_files': 'server.py', 'addons_paths': 'addons,core/addons'})
+        self.Branch = self.env['runbot.branch']
+        self.branch = self.Branch.create({
+            'repo_id': self.repo.id,
+            'name': 'refs/heads/master'
+        })
+        self.Build = self.env['runbot.build']
+        self.IrLogging = self.env['ir.logging']
+
+    def simulate_log(self, build, func, message, level='INFO'):
+        """ simulate ir_logging from an external build """
+        dest = '%s-fake-dest' % build.id
+        val = ('server', dest, 'test', level, message, 'test', '0', func)
+        self.cr.execute("""
+                INSERT INTO ir_logging(create_date, type, dbname, name, level, message, path, line, func)
+                VALUES (NOW() at time zone 'UTC', %s, %s, %s, %s, %s, %s, %s, %s)
+            """, val)
+
+    @patch('odoo.addons.runbot.models.build.runbot_build._get_params')
+    @patch('odoo.addons.runbot.models.build.fqdn')
+    def test_ir_logging(self, mock_fqdn, mock_get_params):
+        build = self.Build.create({
+            'branch_id': self.branch.id,
+            'name': 'd0d0caca0000ffffffffffffffffffffffffffff',
+            'port': '1234',
+        })
+
+        build.log_counter = 10
+
+        #  Test that an ir_logging is created and a the trigger set the build_id
+        self.simulate_log(build, 'test function', 'test message')
+        log_line = self.IrLogging.search([('func', '=', 'test function'), ('message', '=', 'test message'), ('level', '=', 'INFO')])
+        self.assertEqual(len(log_line), 1, "A build log event should have been created")
+        self.assertEqual(log_line.build_id, build)
+
+        #  Test that a warn log line sets the build in warn
+        self.simulate_log(build, 'test function', 'test message', level='WARNING')
+        build.invalidate_cache()
+        self.assertEqual(build.triggered_result, 'warn', 'A warning log should sets the build in warn')
+
+        #  Test that a error log line sets the build in ko
+        self.simulate_log(build, 'test function', 'test message', level='ERROR')
+        build.invalidate_cache()
+        self.assertEqual(build.triggered_result, 'ko', 'An error log should sets the build in ko')
+        self.assertEqual(7, build.log_counter, 'server lines should decrement the build log_counter')
+
+        build.log_counter = 10
+
+        # Test the log limit
+        for i in range(11):
+            self.simulate_log(build, 'limit function', 'limit message')
+        log_lines = self.IrLogging.search([('build_id', '=', build.id), ('type', '=', 'server'), ('func', '=', 'limit function'), ('message', '=', 'limit message'), ('level', '=', 'INFO')])
+        self.assertGreater(len(log_lines), 7, 'Trigger should have created logs with appropriate build id')
+        self.assertLess(len(log_lines), 10, 'Trigger should prevent insert more lines of logs than log_counter')
+        last_log_line = self.IrLogging.search([('build_id', '=', build.id)], order='id DESC', limit=1)
+        self.assertIn('Log limit reached', last_log_line.message, 'Trigger should modify last log message')
+
+        # Test that the _log method is still able to add logs
+        build._log('runbot function', 'runbot message')
+        log_lines = self.IrLogging.search([('type', '=', 'runbot'), ('name', '=', 'odoo.runbot'), ('func', '=', 'runbot function'), ('message', '=', 'runbot message'), ('level', '=', 'INFO')])
+        self.assertEqual(len(log_lines), 1, '_log should be able to add logs from the runbot')