[IMP] core: improve module loading logs

Performances from a general point of view can be difficult to track.
This commit proposes to improve logs in two ways:

The current logs only use the sql_counter, wich will only be updated
when a cursor is closed. In a test-enable install, this counter
is actually the queries of the tests wince the install cursor is
open untill the end. The first fix is to use bot sql_counter and
sql_log_count to have total queries untill now on closed cursor,
but also the current number of queries of the current cursor.

This means that the new log format will be
{nb} modules loaded in {time}, {loading_querie} (+{test_cr_queries}) queries
instead of
{nb} modules loaded in {time}, {tests_cr__queries}queries

Nothe that in the current version, {nb} is actually the total number of
loaded modules until now.

This commit also add an equivalent end log by module and change the
loglevel of module start on install (mainly usefull if an error occurs
before anything else is logged hidding the module causing this error.)

A cleaner runbot logger is also added, in order to be abble to call
_logger.runbot( instead of _logger.log(25. This will clarify the purpose
of such a log level.

closes odoo/odoo#47283

Signed-off-by: Christophe Monniez (moc) <moc@odoo.com>

2 files changed, 5 insertions, 5 deletions

diff --git a/addons/web/tests/test_click_everywhere.py b/addons/web/tests/test_click_everywhere.py
index 7f2d16d75d6..18c7431339e 100644
--- a/addons/web/tests/test_click_everywhere.py
+++ b/addons/web/tests/test_click_everywhere.py
@@ -13,7 +13,7 @@ class TestMenusAdmin(odoo.tests.HttpCase):
         menus = self.env['ir.ui.menu'].load_menus(False)
         for app in menus['children']:
                 with self.subTest(app=app['name']):
-                    _logger.log(25, 'Testing %s', app['name'])
+                    _logger.runbot('Testing %s', app['name'])
                     self.browser_js("/web", "odoo.__DEBUG__.services['web.clickEverywhere'](%d);" % app['id'], "odoo.isReady === true", login="admin", timeout=300)
                     self.terminate_browser()
 
@@ -25,7 +25,7 @@ class TestMenusDemo(odoo.tests.HttpCase):
         menus = self.env['ir.ui.menu'].load_menus(False)
         for app in menus['children']:
                 with self.subTest(app=app['name']):
-                    _logger.log(25, 'Testing %s', app['name'])
+                    _logger.runbot('Testing %s', app['name'])
                     self.browser_js("/web", "odoo.__DEBUG__.services['web.clickEverywhere'](%d);" % app['id'], "odoo.isReady === true", login="demo", timeout=300)
                     self.terminate_browser()
 
diff --git a/addons/web/tests/test_serving_base.py b/addons/web/tests/test_serving_base.py
index 09c52df3471..267388bda85 100644
--- a/addons/web/tests/test_serving_base.py
+++ b/addons/web/tests/test_serving_base.py
@@ -982,7 +982,7 @@ class TestStaticInheritancePerformance(TestStaticInheritanceCommon):
         contents = HomeStaticTemplateHelpers.get_qweb_templates(addons=self._get_module_names(), debug=True)
         after = datetime.now()
         delta2500 = after - before
-        _logger.log(25, 'Static Templates Inheritance: 2500 templates treated in %s seconds' % delta2500.total_seconds())
+        _logger.runbot('Static Templates Inheritance: 2500 templates treated in %s seconds' % delta2500.total_seconds())
 
         whole_tree = etree.fromstring(contents)
         self.assertEqual(len(whole_tree), nMod * nFilePerMod * nTemplatePerFile)
@@ -997,6 +997,6 @@ class TestStaticInheritancePerformance(TestStaticInheritanceCommon):
         delta25000 = after - before
 
         time_ratio = delta25000.total_seconds() / delta2500.total_seconds()
-        _logger.log(25, 'Static Templates Inheritance: 25000 templates treated in %s seconds' % delta25000.total_seconds())
-        _logger.log(25, 'Static Templates Inheritance: Computed linearity ratio: %s' % time_ratio)
+        _logger.runbot('Static Templates Inheritance: 25000 templates treated in %s seconds' % delta25000.total_seconds())
+        _logger.runbot('Static Templates Inheritance: Computed linearity ratio: %s' % time_ratio)
         self.assertLessEqual(time_ratio, 10)