[MERGE] merged trunk.

bzr revid: vmt@openerp.com-20120816104804-k5pwjk3j3um5mow7

1 files changed, 87 insertions, 96 deletions

diff --git a/openerp/modules/loading.py b/openerp/modules/loading.py
index 5d274f6614b..4399145bfc6 100644
--- a/openerp/modules/loading.py
+++ b/openerp/modules/loading.py
@@ -24,44 +24,28 @@
 
 """
 
-import base64
-import imp
 import itertools
 import logging
 import os
-import re
 import sys
 import threading
-import zipfile
-import zipimport
-
-from cStringIO import StringIO
-from os.path import join as opj
-from zipfile import PyZipFile, ZIP_DEFLATED
-
 
 import openerp
 import openerp.modules.db
 import openerp.modules.graph
 import openerp.modules.migration
-import openerp.netsvc as netsvc
 import openerp.osv as osv
 import openerp.pooler as pooler
 import openerp.release as release
 import openerp.tools as tools
-import openerp.tools.osutil as osutil
+import openerp.tools.assertion_report as assertion_report
 
-from openerp.tools.safe_eval import safe_eval as eval
+from openerp import SUPERUSER_ID
 from openerp.tools.translate import _
-from openerp.modules.module import \
-    get_modules, get_modules_with_version, \
-    load_information_from_description_file, \
-    get_module_resource, zip_directory, \
-    get_module_path, initialize_sys_path, \
-    register_module_classes, init_module_models
-
-logger = netsvc.Logger()
+from openerp.modules.module import initialize_sys_path, \
+    load_openerp_module, init_module_models
 
+_logger = logging.getLogger(__name__)
 
 def open_openerp_namespace():
     # See comment for open_openerp_namespace.
@@ -80,7 +64,6 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
        :param skip_modules: optional list of module names (packages) which have previously been loaded and can be skipped
        :return: list of modules that were installed or updated
     """
-    logger = logging.getLogger('init.load')
     def process_sql_file(cr, fp):
         queries = fp.read().split(';')
         for query in queries:
@@ -96,19 +79,20 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
 
     def load_test(module_name, idref, mode):
         cr.commit()
-        if not tools.config.options['test_disable']:
-            try:
-                threading.currentThread().testing = True
-                _load_data(cr, module_name, idref, mode, 'test')
-            except Exception, e:
-                logging.getLogger('init.test').exception(
-                    'Tests failed to execute in module %s', module_name)
-            finally:
-                threading.currentThread().testing = False
-                if tools.config.options['test_commit']:
-                    cr.commit()
-                else:
-                    cr.rollback()
+        try:
+            threading.currentThread().testing = True
+            _load_data(cr, module_name, idref, mode, 'test')
+            return True
+        except Exception:
+            _logger.error(
+                'module %s: an exception occurred in a test', module_name)
+            return False
+        finally:
+            threading.currentThread().testing = False
+            if tools.config.options['test_commit']:
+                cr.commit()
+            else:
+                cr.rollback()
 
     def _load_data(cr, module_name, idref, mode, kind):
         """
@@ -120,7 +104,7 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
 
         """
         for filename in package.data[kind]:
-            logger.info("module %s: loading %s", module_name, filename)
+            _logger.info("module %s: loading %s", module_name, filename)
             _, ext = os.path.splitext(filename)
             pathname = os.path.join(module_name, filename)
             fp = tools.file_open(pathname)
@@ -135,7 +119,7 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
                 elif ext == '.sql':
                     process_sql_file(cr, fp)
                 elif ext == '.yml':
-                    tools.convert_yaml_import(cr, module_name, fp, idref, mode, noupdate)
+                    tools.convert_yaml_import(cr, module_name, fp, idref, mode, noupdate, report)
                 else:
                     tools.convert_xml_import(cr, module_name, fp, idref, mode, noupdate, report)
             finally:
@@ -148,10 +132,10 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
     loaded_modules = []
     pool = pooler.get_pool(cr.dbname)
     migrations = openerp.modules.migration.MigrationManager(cr, graph)
-    logger.debug('loading %d packages...', len(graph))
+    _logger.debug('loading %d packages...', len(graph))
 
     # get db timestamp
-    cr.execute("select now()::timestamp")
+    cr.execute("select (now() at time zone 'UTC')::timestamp")
     dt_before_load = cr.fetchone()[0]
 
     # register, instantiate and initialize models for each modules
@@ -162,14 +146,15 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
         if skip_modules and module_name in skip_modules:
             continue
 
-        logger.info('module %s: loading objects', package.name)
+        _logger.info('module %s: loading objects', package.name)
         migrations.migrate_module(package, 'pre')
-        register_module_classes(package.name)
+        load_openerp_module(package.name)
+
         models = pool.load(cr, package)
         loaded_modules.append(package.name)
         if package.state in ('to install', 'to upgrade'):
             init_module_models(cr, package.name, models)
-
+        pool._init_modules.add(package.name)
         status['progress'] = float(index) / len(graph)
 
         # Can't put this line out of the loop: ir.module.module will be
@@ -177,7 +162,7 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
         modobj = pool.get('ir.module.module')
 
         if perform_checks:
-            modobj.check(cr, 1, [module_id])
+            modobj.check(cr, SUPERUSER_ID, [module_id])
 
         idref = {}
 
@@ -189,7 +174,7 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
         if package.state in ('to install', 'to upgrade'):
             if package.state=='to upgrade':
                 # upgrading the module information
-                modobj.write(cr, 1, [module_id], modobj.get_values_from_terp(package.data))
+                modobj.write(cr, SUPERUSER_ID, [module_id], modobj.get_values_from_terp(package.data))
             load_init_xml(module_name, idref, mode)
             load_update_xml(module_name, idref, mode)
             load_data(module_name, idref, mode)
@@ -203,7 +188,14 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
                 # on demo data. Other tests can be added into the regular
                 # 'data' section, but should probably not alter the data,
                 # as there is no rollback.
-                load_test(module_name, idref, mode)
+                if tools.config.options['test_enable']:
+                    report.record_result(load_test(module_name, idref, mode))
+
+                    # Run the `fast_suite` and `checks` tests given by the module.
+                    if module_name == 'base':
+                        # Also run the core tests after the database is created.
+                        report.record_result(openerp.modules.module.run_unit_tests('openerp'))
+                    report.record_result(openerp.modules.module.run_unit_tests(module_name))
 
             processed_modules.append(package.name)
 
@@ -211,17 +203,14 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules=
 
             ver = release.major_version + '.' + package.data['version']
             # Set new modules and dependencies
-            modobj.write(cr, 1, [module_id], {'state': 'installed', 'latest_version': ver})
+            modobj.write(cr, SUPERUSER_ID, [module_id], {'state': 'installed', 'latest_version': ver})
             # Update translations for all installed languages
-            modobj.update_translations(cr, 1, [module_id], None)
+            modobj.update_translations(cr, SUPERUSER_ID, [module_id], None)
 
             package.state = 'installed'
 
         cr.commit()
-
-    # mark new res_log records as read
-    cr.execute("update res_log set read=True where create_date >= %s", (dt_before_load,))
-
+    
     cr.commit()
 
     return loaded_modules, processed_modules
@@ -238,7 +227,7 @@ def _check_module_names(cr, module_names):
             # find out what module name(s) are incorrect:
             cr.execute("SELECT name FROM ir_module_module")
             incorrect_names = mod_names.difference([x['name'] for x in cr.dictfetchall()])
-            logging.getLogger('init').warning('invalid module names, ignored: %s', ", ".join(incorrect_names))
+            _logger.warning('invalid module names, ignored: %s', ", ".join(incorrect_names))
 
 def load_marked_modules(cr, graph, states, force, progressdict, report, loaded_modules):
     """Loads modules marked with ``states``, adding them to ``graph`` and
@@ -247,8 +236,8 @@ def load_marked_modules(cr, graph, states, force, progressdict, report, loaded_m
     while True:
         cr.execute("SELECT name from ir_module_module WHERE state IN %s" ,(tuple(states),))
         module_list = [name for (name,) in cr.fetchall() if name not in graph]
-        new_modules_in_graph = graph.add_modules(cr, module_list, force)
-        logger.notifyChannel('init', netsvc.LOG_DEBUG, 'Updating graph with %d more modules' % (len(module_list)))
+        graph.add_modules(cr, module_list, force)
+        _logger.debug('Updating graph with %d more modules', len(module_list))
         loaded, processed = load_module_graph(cr, graph, progressdict, report=report, skip_modules=loaded_modules)
         processed_modules.extend(processed)
         loaded_modules.extend(loaded)
@@ -271,14 +260,13 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
     cr = db.cursor()
     try:
         if not openerp.modules.db.is_initialized(cr):
-            logger.notifyChannel("init", netsvc.LOG_INFO, "init db")
+            _logger.info("init db")
             openerp.modules.db.initialize(cr)
             update_module = True
 
         # This is a brand new pool, just created in pooler.get_db_and_pool()
         pool = pooler.get_pool(cr.dbname)
 
-        report = tools.assertion_report()
         if 'base' in tools.config['update'] or 'all' in tools.config['update']:
             cr.execute("update ir_module_module set state=%s where name=%s and state=%s", ('to upgrade', 'base', 'installed'))
 
@@ -286,12 +274,13 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
         graph = openerp.modules.graph.Graph()
         graph.add_module(cr, 'base', force_demo)
         if not graph:
-            logger.notifyChannel('init', netsvc.LOG_CRITICAL, 'module base cannot be loaded! (hint: verify addons-path)')
+            _logger.critical('module base cannot be loaded! (hint: verify addons-path)')
             raise osv.osv.except_osv(_('Could not load base module'), _('module base cannot be loaded! (hint: verify addons-path)'))
 
         # processed_modules: for cleanup step after install
         # loaded_modules: to avoid double loading
         # After load_module_graph(), 'base' has been installed or updated and its state is 'installed'.
+        report = assertion_report.assertion_report()
         loaded_modules, processed_modules = load_module_graph(cr, graph, status, report=report)
 
         if tools.config['load_language']:
@@ -306,7 +295,7 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
             modobj = pool.get('ir.module.module')
             if ('base' in tools.config['init']) or ('base' in tools.config['update']) \
                 or ('all' in tools.config['init']) or ('all' in tools.config['update']):
-                logger.notifyChannel('init', netsvc.LOG_INFO, 'updating modules list')
+                _logger.info('updating modules list')
                 modobj.update_list(cr, 1)
 
             if 'all' in tools.config['init']:
@@ -316,15 +305,16 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
             _check_module_names(cr, itertools.chain(tools.config['init'].keys(), tools.config['update'].keys()))
 
             mods = [k for k in tools.config['init'] if tools.config['init'][k] and k not in ('base', 'all')]
-            ids = modobj.search(cr, 1, ['&', ('state', '=', 'uninstalled'), ('name', 'in', mods)])
+            ids = modobj.search(cr, SUPERUSER_ID, ['&', ('state', '=', 'uninstalled'), ('name', 'in', mods)])
             if ids:
-                modobj.button_install(cr, 1, ids) # goes from 'uninstalled' to 'to install'
+                modobj.button_install(cr, SUPERUSER_ID, ids) # goes from 'uninstalled' to 'to install'
 
             mods = [k for k in tools.config['update'] if tools.config['update'][k] and k not in ('base', 'all')]
-            ids = modobj.search(cr, 1, ['&', ('state', '=', 'installed'), ('name', 'in', mods)])
+            ids = modobj.search(cr, SUPERUSER_ID, ['&', ('state', '=', 'installed'), ('name', 'in', mods)])
             if ids:
-                modobj.button_upgrade(cr, 1, ids) # goes from 'installed' to 'to upgrade'
+                modobj.button_upgrade(cr, SUPERUSER_ID, ids) # goes from 'installed' to 'to upgrade'
 
+        # Remove that funky global one-shot thingy.
         for kind in ('init', 'demo', 'update'):
             tools.config[kind] = {}
 
@@ -333,7 +323,11 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
         #            partially installed modules (i.e. installed/to upgrade), to
         #            offer a consistent system to the second part: installing
         #            newly selected modules.
-        states_to_load = ['installed', 'to upgrade']
+        #            We include the modules 'to remove' in the first step, because
+        #            they are part of the "currently installed" modules. They will
+        #            be dropped in STEP 6 later, before restarting the loading
+        #            process.
+        states_to_load = ['installed', 'to upgrade', 'to remove']
         processed = load_marked_modules(cr, graph, states_to_load, force, status, report, loaded_modules)
         processed_modules.extend(processed)
         if update_module:
@@ -344,15 +338,15 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
         # load custom models
         cr.execute('select model from ir_model where state=%s', ('manual',))
         for model in cr.dictfetchall():
-            pool.get('ir.model').instanciate(cr, 1, model['model'], {})
+            pool.get('ir.model').instanciate(cr, SUPERUSER_ID, model['model'], {})
 
-        # STEP 4: Finish and cleanup
+        # STEP 4: Finish and cleanup installations
         if processed_modules:
             cr.execute("""select model,name from ir_model where id NOT IN (select distinct model_id from ir_model_access)""")
             for (model, name) in cr.fetchall():
                 model_obj = pool.get(model)
                 if model_obj and not model_obj.is_transient():
-                    logger.notifyChannel('init', netsvc.LOG_WARNING, 'Model %s (%s) has no access rules!' % (model, name))
+                    _logger.warning('Model %s (%s) has no access rules!', model, name)
 
             # Temporary warning while we remove access rights on osv_memory objects, as they have
             # been replaced by owner-only access rights
@@ -360,7 +354,7 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
             for (model, name) in cr.fetchall():
                 model_obj = pool.get(model)
                 if model_obj and model_obj.is_transient():
-                    logger.notifyChannel('init', netsvc.LOG_WARNING, 'The transient model %s (%s) should not have explicit access rules!' % (model, name))
+                    _logger.warning('The transient model %s (%s) should not have explicit access rules!', model, name)
 
             cr.execute("SELECT model from ir_model")
             for (model,) in cr.fetchall():
@@ -368,36 +362,18 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
                 if obj:
                     obj._check_removed_columns(cr, log=True)
                 else:
-                    logger.notifyChannel('init', netsvc.LOG_WARNING, "Model %s is declared but cannot be loaded! (Perhaps a module was partially removed or renamed)" % model)
+                    _logger.warning("Model %s is declared but cannot be loaded! (Perhaps a module was partially removed or renamed)", model)
 
             # Cleanup orphan records
-            pool.get('ir.model.data')._process_end(cr, 1, processed_modules)
-
-        if report.get_report():
-            logger.notifyChannel('init', netsvc.LOG_INFO, report)
+            pool.get('ir.model.data')._process_end(cr, SUPERUSER_ID, processed_modules)
 
         cr.commit()
-        if update_module:
-            # Remove records referenced from ir_model_data for modules to be
-            # removed (and removed the references from ir_model_data).
-            cr.execute("select id,name from ir_module_module where state=%s", ('to remove',))
-            for mod_id, mod_name in cr.fetchall():
-                cr.execute('select model,res_id from ir_model_data where noupdate=%s and module=%s order by id desc', (False, mod_name,))
-                for rmod, rid in cr.fetchall():
-                    uid = 1
-                    rmod_module= pool.get(rmod)
-                    if rmod_module:
-                        # TODO group by module so that we can delete multiple ids in a call
-                        rmod_module.unlink(cr, uid, [rid])
-                    else:
-                        logger.notifyChannel('init', netsvc.LOG_ERROR, 'Could not locate %s to remove res=%d' % (rmod,rid))
-                cr.execute('delete from ir_model_data where noupdate=%s and module=%s', (False, mod_name,))
-                cr.commit()
 
-            # Remove menu items that are not referenced by any of other
-            # (child) menu item, ir_values, or ir_model_data.
-            # This code could be a method of ir_ui_menu.
-            # TODO: remove menu without actions of children
+        # STEP 5: Cleanup menus 
+        # Remove menu items that are not referenced by any of other
+        # (child) menu item, ir_values, or ir_model_data.
+        # TODO: This code could be a method of ir_ui_menu. Remove menu without actions of children
+        if update_module:
             while True:
                 cr.execute('''delete from
                         ir_ui_menu
@@ -411,11 +387,26 @@ def load_modules(db, force_demo=False, status=None, update_module=False):
                 if not cr.rowcount:
                     break
                 else:
-                    logger.notifyChannel('init', netsvc.LOG_INFO, 'removed %d unused menus' % (cr.rowcount,))
+                    _logger.info('removed %d unused menus', cr.rowcount)
 
-            # Pretend that modules to be removed are actually uninstalled.
-            cr.execute("update ir_module_module set state=%s where state=%s", ('uninstalled', 'to remove',))
-            cr.commit()
+        # STEP 6: Uninstall modules to remove
+        if update_module:
+            # Remove records referenced from ir_model_data for modules to be
+            # removed (and removed the references from ir_model_data).
+            cr.execute("SELECT id FROM ir_module_module WHERE state=%s", ('to remove',))
+            mod_ids_to_remove = [x[0] for x in cr.fetchall()]
+            if mod_ids_to_remove:
+                pool.get('ir.module.module').module_uninstall(cr, SUPERUSER_ID, mod_ids_to_remove)
+                # Recursive reload, should only happen once, because there should be no
+                # modules to remove next time
+                cr.commit()
+                _logger.info('Reloading registry once more after uninstalling modules')
+                return pooler.restart_pool(cr.dbname, force_demo, status, update_module)
+
+        if report.failures:
+            _logger.error('At least one test failed when loading the modules.')
+        else:
+            _logger.info('Modules loaded.')
     finally:
         cr.close()