From f22f2fc77057a14d3a47472d981944445ebaeb09 Mon Sep 17 00:00:00 2001 From: Vo Minh Thu Date: Tue, 24 Jan 2012 13:42:52 +0100 Subject: [PATCH] [IMP] openerp.{modules,osv}: _logger with fully qualified module name. bzr revid: vmt@openerp.com-20120124124252-91g3ysf33zsq4nhd --- openerp/modules/db.py | 4 +- openerp/modules/graph.py | 9 +-- openerp/modules/loading.py | 37 +++++---- openerp/modules/migration.py | 9 +-- openerp/modules/module.py | 18 ++--- openerp/modules/registry.py | 8 +- openerp/osv/expression.py | 2 +- openerp/osv/orm.py | 144 +++++++++++++++++------------------ openerp/osv/osv.py | 9 ++- 9 files changed, 114 insertions(+), 126 deletions(-) diff --git a/openerp/modules/db.py b/openerp/modules/db.py index a670a29deed..181b6dfd1bb 100644 --- a/openerp/modules/db.py +++ b/openerp/modules/db.py @@ -23,6 +23,8 @@ import openerp.modules import logging +_logger = logging.getLogger(__name__) + def is_initialized(cr): """ Check if a database has been initialized for the ORM. @@ -43,7 +45,7 @@ def initialize(cr): f = openerp.modules.get_module_resource('base', 'base.sql') if not f: m = "File not found: 'base.sql' (provided by module 'base')." - logging.getLogger('init').critical(m) + _logger.critical(m) raise IOError(m) base_sql_file = openerp.tools.misc.file_open(f) try: diff --git a/openerp/modules/graph.py b/openerp/modules/graph.py index 1ee9d515313..56b17e3239a 100644 --- a/openerp/modules/graph.py +++ b/openerp/modules/graph.py @@ -48,8 +48,7 @@ from cStringIO import StringIO import logging -logger = netsvc.Logger() - +_logger = logging.getLogger(__name__) class Graph(dict): """ Modules dependency graph. @@ -104,7 +103,7 @@ class Graph(dict): if info and info['installable']: packages.append((module, info)) # TODO directly a dict, like in get_modules_with_version else: - logger.notifyChannel('init', netsvc.LOG_WARNING, 'module %s: not installable, skipped' % (module)) + _logger.warning('module %s: not installable, skipped', module) dependencies = dict([(p, info['depends']) for p, info in packages]) current, later = set([p for p, info in packages]), set() @@ -134,11 +133,11 @@ class Graph(dict): for package in later: unmet_deps = filter(lambda p: p not in self, dependencies[package]) - logger.notifyChannel('init', netsvc.LOG_ERROR, 'module %s: Unmet dependencies: %s' % (package, ', '.join(unmet_deps))) + _logger.error('module %s: Unmet dependencies: %s', package, ', '.join(unmet_deps)) result = len(self) - len_graph if result != len(module_list): - logger.notifyChannel('init', netsvc.LOG_WARNING, 'Not all modules have loaded.') + _logger.warning('Some modules were not loaded.') return result diff --git a/openerp/modules/loading.py b/openerp/modules/loading.py index 1ea0bdb7105..5092eaf4b2d 100644 --- a/openerp/modules/loading.py +++ b/openerp/modules/loading.py @@ -60,8 +60,7 @@ from openerp.modules.module import \ get_module_path, initialize_sys_path, \ register_module_classes, init_module_models -logger = netsvc.Logger() - +_logger = logging.getLogger(__name__) def open_openerp_namespace(): # See comment for open_openerp_namespace. @@ -80,7 +79,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: @@ -101,7 +99,7 @@ def load_module_graph(cr, graph, status=None, perform_checks=True, skip_modules= threading.currentThread().testing = True _load_data(cr, module_name, idref, mode, 'test') except Exception, e: - logging.getLogger('init.test').exception( + _logger.exception( 'Tests failed to execute in module %s', module_name) finally: threading.currentThread().testing = False @@ -120,7 +118,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) @@ -148,7 +146,7 @@ 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") @@ -162,7 +160,7 @@ 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) models = pool.load(cr, package) @@ -240,7 +238,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 @@ -250,7 +248,7 @@ def load_marked_modules(cr, graph, states, force, progressdict, report, loaded_m 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))) + _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) @@ -273,7 +271,7 @@ 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) tools.config["init"]["all"] = 1 tools.config['update']['all'] = 1 @@ -291,7 +289,7 @@ def load_modules(db, force_demo=False, status=None, update_module=False): graph = openerp.modules.graph.Graph() graph.add_module(cr, 'base', force) 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 @@ -306,7 +304,7 @@ def load_modules(db, force_demo=False, status=None, update_module=False): if update_module: modobj = pool.get('ir.module.module') if ('base' in tools.config['init']) or ('base' in tools.config['update']): - logger.notifyChannel('init', netsvc.LOG_INFO, 'updating modules list') + _logger.info('updating modules list') modobj.update_list(cr, 1) _check_module_names(cr, itertools.chain(tools.config['init'].keys(), tools.config['update'].keys())) @@ -350,7 +348,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 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 @@ -358,7 +356,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(): @@ -366,14 +364,11 @@ 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) - for kind in ('init', 'demo', 'update'): tools.config[kind] = {} @@ -391,7 +386,7 @@ def load_modules(db, force_demo=False, status=None, update_module=False): # 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)) + _logger.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() @@ -412,11 +407,13 @@ 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() + + _logger.info('Modules loaded.') finally: cr.close() diff --git a/openerp/modules/migration.py b/openerp/modules/migration.py index d26f5927141..e0faa77c3a4 100644 --- a/openerp/modules/migration.py +++ b/openerp/modules/migration.py @@ -51,8 +51,7 @@ import logging import openerp.modules.db import openerp.modules.graph -logger = netsvc.Logger() - +_logger = logging.getLogger(__name__) class MigrationManager(object): """ @@ -183,13 +182,13 @@ class MigrationManager(object): fp2.seek(0) try: mod = imp.load_source(name, pyfile, fp2) - logger.notifyChannel('migration', netsvc.LOG_INFO, 'module %(addon)s: Running migration %(version)s %(name)s' % mergedict({'name': mod.__name__}, strfmt)) + _logger.info('module %(addon)s: Running migration %(version)s %(name)s' % mergedict({'name': mod.__name__}, strfmt)) mod.migrate(self.cr, pkg.installed_version) except ImportError: - logger.notifyChannel('migration', netsvc.LOG_ERROR, 'module %(addon)s: Unable to load %(stage)s-migration file %(file)s' % mergedict({'file': pyfile}, strfmt)) + _logger.error('module %(addon)s: Unable to load %(stage)s-migration file %(file)s' % mergedict({'file': pyfile}, strfmt)) raise except AttributeError: - logger.notifyChannel('migration', netsvc.LOG_ERROR, 'module %(addon)s: Each %(stage)s-migration file must have a "migrate(cr, installed_version)" function' % strfmt) + _logger.error('module %(addon)s: Each %(stage)s-migration file must have a "migrate(cr, installed_version)" function' % strfmt) except: raise finally: diff --git a/openerp/modules/module.py b/openerp/modules/module.py index c75ab814254..124634efa7d 100644 --- a/openerp/modules/module.py +++ b/openerp/modules/module.py @@ -54,7 +54,7 @@ ad_paths = [] # Modules already loaded loaded = [] -logger = netsvc.Logger() +_logger = logging.getLogger(__name__) class AddonsImportHook(object): """ @@ -98,8 +98,7 @@ class AddonsImportHook(object): try: # Check if the bare module name clashes with another module. f, path, descr = imp.find_module(module_parts[0]) - logger = logging.getLogger('init') - logger.warning(""" + _logger.warning(""" Ambiguous import: the OpenERP module `%s` is shadowed by another module (available at %s). To import it, use `import openerp.addons..`.""" % (module_name, path)) @@ -174,7 +173,7 @@ def get_module_path(module, downloaded=False, display_warning=True): if downloaded: return opj(_ad, module) if display_warning: - logger.notifyChannel('init', netsvc.LOG_WARNING, 'module %s: module not found' % (module,)) + _logger.warning('module %s: module not found', module) return False @@ -346,7 +345,7 @@ def load_information_from_description_file(module): #TODO: refactor the logger in this file to follow the logging guidelines # for 6.0 - logging.getLogger('modules').debug('module %s: no descriptor file' + _logger.debug('module %s: no descriptor file' ' found: __openerp__.py or __terp__.py (deprecated)', module) return {} @@ -360,8 +359,7 @@ def init_module_models(cr, module_name, obj_list): TODO better explanation of _auto_init and init. """ - logger.notifyChannel('init', netsvc.LOG_INFO, - 'module %s: creating or updating database tables' % module_name) + _logger.info('module %s: creating or updating database tables', module_name) todo = [] for obj in obj_list: result = obj._auto_init(cr, {'module': module_name}) @@ -389,13 +387,13 @@ def register_module_classes(m): def log(e): mt = isinstance(e, zipimport.ZipImportError) and 'zip ' or '' msg = "Couldn't load %smodule %s" % (mt, m) - logger.notifyChannel('init', netsvc.LOG_CRITICAL, msg) - logger.notifyChannel('init', netsvc.LOG_CRITICAL, e) + _logger.critical(msg) + _logger.critical(e) global loaded if m in loaded: return - logger.notifyChannel('init', netsvc.LOG_INFO, 'module %s: registering objects' % m) + _logger.info('module %s: registering objects', m) mod_path = get_module_path(m) initialize_sys_path() diff --git a/openerp/modules/registry.py b/openerp/modules/registry.py index 20500f981c3..82928c3911b 100644 --- a/openerp/modules/registry.py +++ b/openerp/modules/registry.py @@ -22,9 +22,8 @@ """ Models registries. """ -import threading - import logging +import threading import openerp.sql_db import openerp.osv.orm @@ -33,6 +32,8 @@ import openerp.tools import openerp.modules.db import openerp.tools.config +_logger = logging.getLogger(__name__) + class Registry(object): """ Model registry for a particular database. @@ -53,8 +54,7 @@ class Registry(object): cr = self.db.cursor() has_unaccent = openerp.modules.db.has_unaccent(cr) if openerp.tools.config['unaccent'] and not has_unaccent: - logger = logging.getLogger('unaccent') - logger.warning("The option --unaccent was given but no unaccent() function was found in database.") + _logger.warning("The option --unaccent was given but no unaccent() function was found in database.") self.has_unaccent = openerp.tools.config['unaccent'] and has_unaccent cr.close() diff --git a/openerp/osv/expression.py b/openerp/osv/expression.py index 9da51ce744c..db700882555 100644 --- a/openerp/osv/expression.py +++ b/openerp/osv/expression.py @@ -159,7 +159,7 @@ FALSE_LEAF = (0, '=', 1) TRUE_DOMAIN = [TRUE_LEAF] FALSE_DOMAIN = [FALSE_LEAF] -_logger = logging.getLogger('expression') +_logger = logging.getLogger(__name__) def normalize(domain): """Returns a normalized version of ``domain_expr``, where all implicit '&' operators diff --git a/openerp/osv/orm.py b/openerp/osv/orm.py index 1c12fab27c9..6a84c87f81e 100644 --- a/openerp/osv/orm.py +++ b/openerp/osv/orm.py @@ -65,6 +65,9 @@ from openerp.tools.translate import _ from openerp import SUPERUSER_ID from query import Query +_logger = logging.getLogger(__name__) +_schema = logging.getLogger(__name__ + '(schema)') + # List of etree._Element subclasses that we choose to ignore when parsing XML. from openerp.tools import SKIPPED_ELEMENT_TYPES @@ -216,8 +219,7 @@ def check_object_name(name): def raise_on_invalid_object_name(name): if not check_object_name(name): msg = "The _name attribute %s is not valid." % name - logger = netsvc.Logger() - logger.notifyChannel('orm', netsvc.LOG_ERROR, msg) + _logger.error(msg) raise except_orm('ValueError', msg) POSTGRES_CONFDELTYPES = { @@ -306,7 +308,6 @@ class browse_record(object): user_rec = uobj.browse(cr, uid, 104) name = user_rec.name """ - logger = netsvc.Logger() def __init__(self, cr, uid, id, table, cache, context=None, list_class=None, fields_process=None): """ @@ -327,8 +328,6 @@ class browse_record(object): self._table = table # deprecated, use _model! self._model = table self._table_name = self._table._name - self.__logger = logging.getLogger( - 'osv.browse_record.' + self._table_name) self._context = context self._fields_process = fields_process @@ -369,7 +368,7 @@ class browse_record(object): return attr else: error_msg = "Field '%s' does not exist in object '%s'" % (name, self) - self.logger.notifyChannel("browse_record", netsvc.LOG_WARNING, error_msg) + _logger.warning(error_msg) raise KeyError(error_msg) # if the field is a classic one or a many2one, we'll fetch all classic and many2one fields @@ -405,7 +404,7 @@ class browse_record(object): if not field_values: # Where did those ids come from? Perhaps old entries in ir_model_dat? - self.__logger.warn("No field_values found for ids %s in %s", ids, self) + _logger.warning("No field_values found for ids %s in %s", ids, self) raise KeyError('Field %s not found in %s'%(name, self)) # create browse records for 'remote' objects for result_line in field_values: @@ -464,10 +463,8 @@ class browse_record(object): if not name in self._data[self._id]: # How did this happen? Could be a missing model due to custom fields used too soon, see above. - self.logger.notifyChannel("browse_record", netsvc.LOG_ERROR, - "Fields to fetch: %s, Field values: %s"%(field_names, field_values)) - self.logger.notifyChannel("browse_record", netsvc.LOG_ERROR, - "Cached: %s, Table: %s"%(self._data[self._id], self._table)) + _logger.error("Fields to fetch: %s, Field values: %s", field_names, field_values) + _logger.error("Cached: %s, Table: %s", self._data[self._id], self._table) raise KeyError(_('Unknown attribute %s in %s ') % (name, self)) return self._data[self._id][name] @@ -584,7 +581,7 @@ def get_pg_type(f, type_override=None): else: pg_type = get_pg_type(f, getattr(fields, f._type)) else: - logging.getLogger('orm').warn('%s type not supported!', field_type) + _logger.warning('%s type not supported!', field_type) pg_type = None return pg_type @@ -702,8 +699,6 @@ class BaseModel(object): _log_create = False _sql_constraints = [] _protected = ['read', 'write', 'create', 'default_get', 'perm_read', 'unlink', 'fields_get', 'fields_view_get', 'search', 'name_get', 'distinct_field_get', 'name_search', 'copy', 'import_data', 'search_count', 'exists'] - __logger = logging.getLogger('orm') - __schema = logging.getLogger('orm.schema') CONCURRENCY_CHECK_FIELD = '__last_update' @@ -957,8 +952,7 @@ class BaseModel(object): name = type(self).__name__.split('.')[0] msg = "The class %s has to have a _name attribute" % name - logger = netsvc.Logger() - logger.notifyChannel('orm', netsvc.LOG_ERROR, msg) + _logger.error(msg) raise except_orm('ValueError', msg) if not self._description: @@ -1384,7 +1378,7 @@ class BaseModel(object): res = key break if line[i] and not res: - logging.getLogger('orm.import').warn( + _logger.warning( _("key '%s' not found in selection field '%s'"), tools.ustr(line[i]), tools.ustr(field_name)) warning.append(_("Key/value '%s' not found in selection field '%s'") % ( @@ -2625,8 +2619,7 @@ class BaseModel(object): def _parent_store_compute(self, cr): if not self._parent_store: return - logger = netsvc.Logger() - logger.notifyChannel('data', netsvc.LOG_INFO, 'Computing parent left and right for table %s...' % (self._table, )) + _logger.info('Computing parent left and right for table %s...', self._table) def browse_rec(root, pos=0): # TODO: set order where = self._parent_name+'='+str(root) @@ -2650,8 +2643,7 @@ class BaseModel(object): return True def _update_store(self, cr, f, k): - logger = netsvc.Logger() - logger.notifyChannel('data', netsvc.LOG_INFO, "storing computed values of fields.function '%s'" % (k,)) + _logger.info("storing computed values of fields.function '%s'", k) ss = self._columns[k]._symbol_set update_query = 'UPDATE "%s" SET "%s"=%s WHERE id=%%s' % (self._table, k, ss[0]) cr.execute('select id from '+self._table) @@ -2707,12 +2699,12 @@ class BaseModel(object): for column in cr.dictfetchall(): if log: - self.__logger.debug("column %s is in the table %s but not in the corresponding object %s", - column['attname'], self._table, self._name) + _logger.debug("column %s is in the table %s but not in the corresponding object %s", + column['attname'], self._table, self._name) if column['attnotnull']: cr.execute('ALTER TABLE "%s" ALTER COLUMN "%s" DROP NOT NULL' % (self._table, column['attname'])) - self.__schema.debug("Table '%s': column '%s': dropped NOT NULL constraint", - self._table, column['attname']) + _schema.debug("Table '%s': column '%s': dropped NOT NULL constraint", + self._table, column['attname']) # checked version: for direct m2o starting from `self` def _m2o_add_foreign_key_checked(self, source_field, dest_model, ondelete): @@ -2724,14 +2716,14 @@ class BaseModel(object): # So unless stated otherwise we default them to ondelete=cascade. ondelete = ondelete or 'cascade' self._foreign_keys.append((self._table, source_field, dest_model._table, ondelete or 'set null')) - self.__schema.debug("Table '%s': added foreign key '%s' with definition=REFERENCES \"%s\" ON DELETE %s", - self._table, source_field, dest_model._table, ondelete) + _schema.debug("Table '%s': added foreign key '%s' with definition=REFERENCES \"%s\" ON DELETE %s", + self._table, source_field, dest_model._table, ondelete) # unchecked version: for custom cases, such as m2m relationships def _m2o_add_foreign_key_unchecked(self, source_table, source_field, dest_model, ondelete): self._foreign_keys.append((source_table, source_field, dest_model._table, ondelete or 'set null')) - self.__schema.debug("Table '%s': added foreign key '%s' with definition=REFERENCES \"%s\" ON DELETE %s", - source_table, source_field, dest_model._table, ondelete) + _schema.debug("Table '%s': added foreign key '%s' with definition=REFERENCES \"%s\" ON DELETE %s", + source_table, source_field, dest_model._table, ondelete) def _auto_init(self, cr, context=None): """ @@ -2805,8 +2797,8 @@ class BaseModel(object): cr.execute('ALTER TABLE "%s" RENAME "%s" TO "%s"' % (self._table, f.oldname, k)) res['attname'] = k column_data[k] = res - self.__schema.debug("Table '%s': renamed column '%s' to '%s'", - self._table, f.oldname, k) + _schema.debug("Table '%s': renamed column '%s' to '%s'", + self._table, f.oldname, k) # The field already exists in database. Possibly # change its type, rename it, drop it or change its @@ -2817,12 +2809,12 @@ class BaseModel(object): f_pg_notnull = res['attnotnull'] if isinstance(f, fields.function) and not f.store and\ not getattr(f, 'nodrop', False): - self.__logger.info('column %s (%s) in table %s removed: converted to a function !\n', - k, f.string, self._table) + _logger.info('column %s (%s) in table %s removed: converted to a function !\n', + k, f.string, self._table) cr.execute('ALTER TABLE "%s" DROP COLUMN "%s" CASCADE' % (self._table, k)) cr.commit() - self.__schema.debug("Table '%s': dropped column '%s' with cascade", - self._table, k) + _schema.debug("Table '%s': dropped column '%s' with cascade", + self._table, k) f_obj_type = None else: f_obj_type = get_pg_type(f) and get_pg_type(f)[0] @@ -2844,7 +2836,7 @@ class BaseModel(object): cr.execute('UPDATE "%s" SET "%s"=temp_change_size::%s' % (self._table, k, pg_varchar(f.size))) cr.execute('ALTER TABLE "%s" DROP COLUMN temp_change_size CASCADE' % (self._table,)) cr.commit() - self.__schema.debug("Table '%s': column '%s' (type varchar) changed size from %s to %s", + _schema.debug("Table '%s': column '%s' (type varchar) changed size from %s to %s", self._table, k, f_pg_size, f.size) for c in casts: if (f_pg_type==c[0]) and (f._type==c[1]): @@ -2855,7 +2847,7 @@ class BaseModel(object): cr.execute(('UPDATE "%s" SET "%s"=temp_change_size'+c[3]) % (self._table, k)) cr.execute('ALTER TABLE "%s" DROP COLUMN temp_change_size CASCADE' % (self._table,)) cr.commit() - self.__schema.debug("Table '%s': column '%s' changed type from %s to %s", + _schema.debug("Table '%s': column '%s' changed type from %s to %s", self._table, k, c[0], c[1]) break @@ -2876,7 +2868,7 @@ class BaseModel(object): cr.execute('ALTER TABLE "%s" RENAME COLUMN "%s" TO "%s"' % (self._table, k, newname)) cr.execute('ALTER TABLE "%s" ADD COLUMN "%s" %s' % (self._table, k, get_pg_type(f)[1])) cr.execute("COMMENT ON COLUMN %s.\"%s\" IS %%s" % (self._table, k), (f.string,)) - self.__schema.debug("Table '%s': column '%s' has changed type (DB=%s, def=%s), data moved to column %s !", + _schema.debug("Table '%s': column '%s' has changed type (DB=%s, def=%s), data moved to column %s !", self._table, k, f_pg_type, f._type, newname) # if the field is required and hasn't got a NOT NULL constraint @@ -2897,19 +2889,19 @@ class BaseModel(object): try: cr.execute('ALTER TABLE "%s" ALTER COLUMN "%s" SET NOT NULL' % (self._table, k), log_exceptions=False) cr.commit() - self.__schema.debug("Table '%s': column '%s': added NOT NULL constraint", - self._table, k) + _schema.debug("Table '%s': column '%s': added NOT NULL constraint", + self._table, k) except Exception: msg = "Table '%s': unable to set a NOT NULL constraint on column '%s' !\n"\ "If you want to have it, you should update the records and execute manually:\n"\ "ALTER TABLE %s ALTER COLUMN %s SET NOT NULL" - self.__schema.warn(msg, self._table, k, self._table, k) + _schema.warning(msg, self._table, k, self._table, k) cr.commit() elif not f.required and f_pg_notnull == 1: cr.execute('ALTER TABLE "%s" ALTER COLUMN "%s" DROP NOT NULL' % (self._table, k)) cr.commit() - self.__schema.debug("Table '%s': column '%s': dropped NOT NULL constraint", - self._table, k) + _schema.debug("Table '%s': column '%s': dropped NOT NULL constraint", + self._table, k) # Verify index indexname = '%s_%s_index' % (self._table, k) cr.execute("SELECT indexname FROM pg_indexes WHERE indexname = %s and tablename = %s", (indexname, self._table)) @@ -2923,12 +2915,12 @@ class BaseModel(object): "This is probably useless (does not work for fulltext search) and prevents INSERTs of long texts"\ " because there is a length limit for indexable btree values!\n"\ "Use a search view instead if you simply want to make the field searchable." - self.__schema.warn(msg, self._table, k, f._type) + _schema.warning(msg, self._table, k, f._type) if res2 and not f.select: cr.execute('DROP INDEX "%s_%s_index"' % (self._table, k)) cr.commit() msg = "Table '%s': dropping index for column '%s' of type '%s' as it is not required anymore" - self.__schema.debug(msg, self._table, k, f._type) + _schema.debug(msg, self._table, k, f._type) if isinstance(f, fields.many2one): dest_model = self.pool.get(f._obj) @@ -2955,7 +2947,7 @@ class BaseModel(object): cr.execute('ALTER TABLE "' + self._table + '" DROP CONSTRAINT "' + res2[0]['conname'] + '"') self._m2o_add_foreign_key_checked(k, dest_model, f.ondelete) cr.commit() - self.__schema.debug("Table '%s': column '%s': XXX", + _schema.debug("Table '%s': column '%s': XXX", self._table, k) # The field doesn't exist in database. Create it if necessary. @@ -2964,7 +2956,7 @@ class BaseModel(object): # add the missing field cr.execute('ALTER TABLE "%s" ADD COLUMN "%s" %s' % (self._table, k, get_pg_type(f)[1])) cr.execute("COMMENT ON COLUMN %s.\"%s\" IS %%s" % (self._table, k), (f.string,)) - self.__schema.debug("Table '%s': added column '%s' with definition=%s", + _schema.debug("Table '%s': added column '%s' with definition=%s", self._table, k, get_pg_type(f)[1]) # initialize it @@ -3002,14 +2994,14 @@ class BaseModel(object): try: cr.commit() cr.execute('ALTER TABLE "%s" ALTER COLUMN "%s" SET NOT NULL' % (self._table, k), log_exceptions=False) - self.__schema.debug("Table '%s': column '%s': added a NOT NULL constraint", + _schema.debug("Table '%s': column '%s': added a NOT NULL constraint", self._table, k) except Exception: msg = "WARNING: unable to set column %s of table %s not null !\n"\ "Try to re-run: openerp-server --update=module\n"\ "If it doesn't work, update records and execute manually:\n"\ "ALTER TABLE %s ALTER COLUMN %s SET NOT NULL" - self.__logger.warn(msg, k, self._table, self._table, k) + _logger.warning(msg, k, self._table, self._table, k) cr.commit() else: @@ -3046,7 +3038,7 @@ class BaseModel(object): def _create_table(self, cr): cr.execute('CREATE TABLE "%s" (id SERIAL NOT NULL, PRIMARY KEY(id)) WITHOUT OIDS' % (self._table,)) cr.execute(("COMMENT ON TABLE \"%s\" IS %%s" % self._table), (self._description,)) - self.__schema.debug("Table '%s': created", self._table) + _schema.debug("Table '%s': created", self._table) def _parent_columns_exist(self, cr): @@ -3061,24 +3053,24 @@ class BaseModel(object): cr.execute('ALTER TABLE "%s" ADD COLUMN "parent_left" INTEGER' % (self._table,)) cr.execute('ALTER TABLE "%s" ADD COLUMN "parent_right" INTEGER' % (self._table,)) if 'parent_left' not in self._columns: - self.__logger.error('create a column parent_left on object %s: fields.integer(\'Left Parent\', select=1)', - self._table) - self.__schema.debug("Table '%s': added column '%s' with definition=%s", - self._table, 'parent_left', 'INTEGER') + _logger.error('create a column parent_left on object %s: fields.integer(\'Left Parent\', select=1)', + self._table) + _schema.debug("Table '%s': added column '%s' with definition=%s", + self._table, 'parent_left', 'INTEGER') elif not self._columns['parent_left'].select: - self.__logger.error('parent_left column on object %s must be indexed! Add select=1 to the field definition)', - self._table) + _logger.error('parent_left column on object %s must be indexed! Add select=1 to the field definition)', + self._table) if 'parent_right' not in self._columns: - self.__logger.error('create a column parent_right on object %s: fields.integer(\'Right Parent\', select=1)', - self._table) - self.__schema.debug("Table '%s': added column '%s' with definition=%s", - self._table, 'parent_right', 'INTEGER') + _logger.error('create a column parent_right on object %s: fields.integer(\'Right Parent\', select=1)', + self._table) + _schema.debug("Table '%s': added column '%s' with definition=%s", + self._table, 'parent_right', 'INTEGER') elif not self._columns['parent_right'].select: - self.__logger.error('parent_right column on object %s must be indexed! Add select=1 to the field definition)', - self._table) + _logger.error('parent_right column on object %s must be indexed! Add select=1 to the field definition)', + self._table) if self._columns[self._parent_name].ondelete != 'cascade': - self.__logger.error("The column %s on object %s must be set as ondelete='cascade'", - self._parent_name, self._name) + _logger.error("The column %s on object %s must be set as ondelete='cascade'", + self._parent_name, self._name) cr.commit() @@ -3093,8 +3085,8 @@ class BaseModel(object): if not cr.rowcount: cr.execute('ALTER TABLE "%s" ADD COLUMN "%s" %s' % (self._table, field, field_def)) cr.commit() - self.__schema.debug("Table '%s': added column '%s' with definition=%s", - self._table, field, field_def) + _schema.debug("Table '%s': added column '%s' with definition=%s", + self._table, field, field_def) def _select_column_data(self, cr): @@ -3142,7 +3134,7 @@ class BaseModel(object): cr.execute('CREATE INDEX "%s_%s_index" ON "%s" ("%s")' % (m2m_tbl, col2, m2m_tbl, col2)) cr.execute("COMMENT ON TABLE \"%s\" IS 'RELATION BETWEEN %s AND %s'" % (m2m_tbl, self._table, ref)) cr.commit() - self.__schema.debug("Create table '%s': m2m relation between '%s' and '%s'", m2m_tbl, self._table, ref) + _schema.debug("Create table '%s': m2m relation between '%s' and '%s'", m2m_tbl, self._table, ref) def _add_sql_constraints(self, cr): @@ -3195,9 +3187,9 @@ class BaseModel(object): try: cr.execute(sql_action['query']) cr.commit() - self.__schema.debug(sql_action['msg_ok']) + _schema.debug(sql_action['msg_ok']) except: - self.__schema.warn(sql_action['msg_err']) + _schema.warning(sql_action['msg_err']) cr.rollback() @@ -3254,11 +3246,11 @@ class BaseModel(object): def _inherits_check(self): for table, field_name in self._inherits.items(): if field_name not in self._columns: - logging.getLogger('init').info('Missing many2one field definition for _inherits reference "%s" in "%s", using default one.' % (field_name, self._name)) + _logger.info('Missing many2one field definition for _inherits reference "%s" in "%s", using default one.', field_name, self._name) self._columns[field_name] = fields.many2one(table, string="Automatically created field to link to parent %s" % table, required=True, ondelete="cascade") elif not self._columns[field_name].required or self._columns[field_name].ondelete.lower() != "cascade": - logging.getLogger('init').warning('Field definition for _inherits reference "%s" in "%s" must be marked as "required" with ondelete="cascade", forcing it.' % (field_name, self._name)) + _logger.warning('Field definition for _inherits reference "%s" in "%s" must be marked as "required" with ondelete="cascade", forcing it.', field_name, self._name) self._columns[field_name].required = True self._columns[field_name].ondelete = "cascade" @@ -3937,7 +3929,7 @@ class BaseModel(object): self.pool.get(table).write(cr, user, nids, v, context) if unknown_fields: - self.__logger.warn( + _logger.warning( 'No such field(s) in model %s: %s.', self._name, ', '.join(unknown_fields)) self._validate(cr, user, ids, context) @@ -4073,7 +4065,7 @@ class BaseModel(object): del vals[v] unknown_fields.append(v) if unknown_fields: - self.__logger.warn( + _logger.warning( 'No such field(s) in model %s: %s.', self._name, ', '.join(unknown_fields)) @@ -4455,9 +4447,9 @@ class BaseModel(object): assert order_field_column._type == 'many2one', 'Invalid field passed to _generate_m2o_order_by()' if not order_field_column._classic_write and not getattr(order_field_column, 'store', False): - logging.getLogger('orm.search').debug("Many2one function/related fields must be stored " \ - "to be used as ordering fields! Ignoring sorting for %s.%s", - self._name, order_field) + _logger.debug("Many2one function/related fields must be stored " \ + "to be used as ordering fields! Ignoring sorting for %s.%s", + self._name, order_field) return # figure out the applicable order_by for the m2o diff --git a/openerp/osv/osv.py b/openerp/osv/osv.py index 44597bf6507..877e804314c 100644 --- a/openerp/osv/osv.py +++ b/openerp/osv/osv.py @@ -34,6 +34,8 @@ from openerp.tools.translate import translate from openerp.osv.orm import MetaModel, Model, TransientModel, AbstractModel import openerp.exceptions +_logger = logging.getLogger(__name__) + # Deprecated. class except_osv(Exception): def __init__(self, name, value): @@ -45,7 +47,6 @@ service = None class object_proxy(object): def __init__(self): - self.logger = logging.getLogger('web-services') global service service = self @@ -130,7 +131,7 @@ class object_proxy(object): tr(osv_pool._sql_error[key], 'sql_constraint') or inst[0]) if inst.pgcode in (errorcodes.NOT_NULL_VIOLATION, errorcodes.FOREIGN_KEY_VIOLATION, errorcodes.RESTRICT_VIOLATION): msg = _('The operation cannot be completed, probably due to the following:\n- deletion: you may be trying to delete a record while other records still reference it\n- creation/update: a mandatory field is not correctly set') - self.logger.debug("IntegrityError", exc_info=True) + _logger.debug("IntegrityError", exc_info=True) try: errortxt = inst.pgerror.replace('«','"').replace('»','"') if '"public".' in errortxt: @@ -151,7 +152,7 @@ class object_proxy(object): else: netsvc.abort_response(1, _('Integrity Error'), 'warning', inst[0]) except Exception: - self.logger.exception("Uncaught exception") + _logger.exception("Uncaught exception") raise return wrapper @@ -174,7 +175,7 @@ class object_proxy(object): raise except_osv('Access Denied', 'Private methods (such as %s) cannot be called remotely.' % (method,)) res = self.execute_cr(cr, uid, obj, method, *args, **kw) if res is None: - self.logger.warning('The method %s of the object %s can not return `None` !', method, obj) + _logger.warning('The method %s of the object %s can not return `None` !', method, obj) cr.commit() except Exception: cr.rollback()