[MRG] merge trunk.

bzr revid: florent.xicluna@gmail.com-20120208141358-emgwspa0s58gtsez

gunicorn.conf.py

@@ -22,11 +22,15 @@ workers = 4
 # Some application-wide initialization is needed.
 on_starting = openerp.wsgi.on_starting
 when_ready = openerp.wsgi.when_ready
+pre_request = openerp.wsgi.pre_request
+post_request = openerp.wsgi.post_request
 
 # openerp request-response cycle can be quite long for
 # big reports for example
 timeout = 240
 
+max_requests = 2000
+
 # Equivalent of --load command-line option
 openerp.conf.server_wide_modules = ['web']
 
@@ -52,5 +56,4 @@ conf['addons_path'] = '/home/openerp/addons/trunk,/home/openerp/web/trunk/addons
 # If --static-http-enable is used, path for the static web directory
 #conf['static_http_document_root'] = '/var/www'
 
-
 # vim:expandtab:smartindent:tabstop=4:softtabstop=4:shiftwidth=4:

openerp-server

@@ -42,6 +42,9 @@ import openerp
 __author__ = openerp.release.author
 __version__ = openerp.release.version
 
+# Also use the `openerp` logger for the main script.
+_logger = logging.getLogger('openerp')
+
 def check_root_user():
     """ Exit if the process's user is 'root' (on POSIX system)."""
     if os.name == 'posix':
@@ -66,13 +69,12 @@ def report_configuration():
     This function assumes the configuration has been initialized.
     """
     config = openerp.tools.config
-    logger = logging.getLogger('server')
+    _logger.info("OpenERP version %s", __version__)
-    logger.info("OpenERP version %s", __version__)
     for name, value in [('addons paths', config['addons_path']),
                         ('database hostname', config['db_host'] or 'localhost'),
                         ('database port', config['db_port'] or '5432'),
                         ('database user', config['db_user'])]:
-        logger.info("%s: %s", name, value)
+        _logger.info("%s: %s", name, value)
 
 def setup_pid_file():
     """ Create a file with the process id written in it.
@@ -94,32 +96,30 @@ def preload_registry(dbname):
         # jobs will start to be processed later, when openerp.cron.start_master_thread() is called by openerp.service.start_services()
         registry.schedule_cron_jobs()
     except Exception:
-        logging.exception('Failed to initialize database `%s`.', dbname)
+        _logger.exception('Failed to initialize database `%s`.', dbname)
 
 def run_test_file(dbname, test_file):
     """ Preload a registry, possibly run a test file, and start the cron."""
     try:
         db, registry = openerp.pooler.get_db_and_pool(dbname, update_module=config['init'] or config['update'], pooljobs=False)
         cr = db.cursor()
-        logger = logging.getLogger('server')
+        _logger.info('loading test file %s', test_file)
-        logger.info('loading test file %s', test_file)
         openerp.tools.convert_yaml_import(cr, 'base', file(test_file), {}, 'test', True)
         cr.rollback()
         cr.close()
     except Exception:
-        logging.exception('Failed to initialize database `%s` and run test file `%s`.', dbname, test_file)
+        _logger.exception('Failed to initialize database `%s` and run test file `%s`.', dbname, test_file)
 
 
 def export_translation():
     config = openerp.tools.config
     dbname = config['db_name']
-    logger = logging.getLogger('server')
 
     if config["language"]:
         msg = "language %s" % (config["language"],)
     else:
         msg = "new language"
-    logger.info('writing translation file for %s to %s', msg,
+    _logger.info('writing translation file for %s to %s', msg,
         config["translate_out"])
 
     fileformat = os.path.splitext(config["translate_out"])[-1][1:].lower()
@@ -130,7 +130,7 @@ def export_translation():
     cr.close()
     buf.close()
 
-    logger.info('translation file written successfully')
+    _logger.info('translation file written successfully')
 
 def import_translation():
     config = openerp.tools.config
@@ -173,7 +173,7 @@ def dumpstacks(sig, frame):
             code.append('File: "%s", line %d, in %s' % (filename, lineno, name))
             if line:
                 code.append("  %s" % (line.strip()))
-    logging.getLogger('dumpstacks').info("\n".join(code))
+    _logger.info("\n".join(code))
 
 def setup_signal_handlers():
     """ Register the signal handler defined above. """
@@ -240,7 +240,7 @@ if __name__ == "__main__":
 
     for m in openerp.conf.server_wide_modules:
         try:
-            __import__(m)
+            __import__('openerp.addons.' + m)
             # Call any post_load hook.
             info = openerp.modules.module.load_information_from_description_file(m)
             if info['post_load']:
@@ -251,7 +251,7 @@ if __name__ == "__main__":
                 msg = """
 The `web` module is provided by the addons found in the `openerp-web` project.
 Maybe you forgot to add those addons in your addons_path configuration."""
-            logging.exception('Failed to load server-wide module `%s`.%s', m, msg)
+            _logger.exception('Failed to load server-wide module `%s`.%s', m, msg)
 
     if config['db_name']:
         for dbname in config['db_name'].split(','):
@@ -261,8 +261,7 @@ Maybe you forgot to add those addons in your addons_path configuration."""
         sys.exit(0)
 
     setup_pid_file()
-    logger = logging.getLogger('server')
+    _logger.info('OpenERP server is running, waiting for connections...')
-    logger.info('OpenERP server is running, waiting for connections...')
     quit_on_signals()
 
 # vim:expandtab:smartindent:tabstop=4:softtabstop=4:shiftwidth=4:

openerp/addons/base/__openerp__.py

@@ -97,7 +97,7 @@
         # 'test/test_ir_cron.yml', # <-- These tests perform a roolback.
     ],
     'installable': True,
-    'active': True,
+    'auto_install': True,
     'certificate': '0076807797149',
     "css": [ 'static/src/css/modules.css' ],
 }

openerp/addons/base/base.sql

@@ -302,6 +302,7 @@ CREATE TABLE ir_module_module (
     web boolean DEFAULT FALSE,
     license character varying(32),
     sequence integer DEFAULT 100,
+    auto_install boolean default False,
     primary key(id)
 );
 ALTER TABLE ir_module_module add constraint name_uniq unique (name);

openerp/addons/base/base_data.xml

@@ -674,6 +674,7 @@
         <record id="nl" model="res.country">
             <field name="name">Netherlands</field>
             <field name="code">nl</field>
+            <field name="address_format" eval="'%(street)s\n%(street2)s\n%(zip)s %(city)s\n%(country_name)s'" />            
         </record>
         <record id="no" model="res.country">
             <field name="name">Norway</field>

openerp/addons/base/base_update.xml

@@ -89,7 +89,7 @@
                         <field name="view" readonly="0"/>
                         <field name="context_lang" readonly="0"/>
                         <field name="context_tz" readonly="0"/>
-                        <field name="menu_tips" readonly="0"/>
+                        <field name="menu_tips" readonly="0" groups="base.group_no_one"/>
                     </group>
                     <group name="default_filters" colspan="2" col="2">
                         <separator string="Default Filters" colspan="2"/>
@@ -208,7 +208,7 @@
             <field name="view_type">form</field>
             <field name="view_mode">tree,form</field>
             <field name="context" eval="{'default_partner_id':ref('base.main_partner'), 'company_hide':False, 'default_company_id':ref('base.main_company'), 'search_default_my_bank':1}"/>
-            <field name="help">Configure your company's bank account and select those that must appear on the report footer. You can reorder bank accounts from the list view. If you use the accounting application of OpenERP, journals and accounts will be created automatically based on these data.</field>
+            <field name="help">Configure your company's bank accounts and select those that must appear on the report footer. You can reorder bank accounts from the list view. If you use the accounting application of OpenERP, journals and accounts will be created automatically based on these data.</field>
         </record>
 
 
@@ -273,6 +273,9 @@
                             <field name="currency_id" colspan="2"/>
                             <newline/>
                         </page>
+                        <page string="Bank Accounts" groups="base.group_extended">
+                          <field name="bank_ids" nolabel="1"/>
+                        </page>
                     </notebook>
                 </form>
             </field>

openerp/addons/base/i18n/es_AR.po

@@ -2199,7 +2199,7 @@ msgstr "Tajikistán"
 
 #. module: base
 #: help:ir.actions.report.xml,header:0
-msgid "Add or not the coporate RML header"
+msgid "Add or not the corporate RML header"
 msgstr "Añadir o no la cabecera corporativa en el informe RML"
 
 #. module: base

openerp/addons/base/i18n/lt_LT.po

@@ -2110,7 +2110,7 @@ msgstr ""
 
 #. module: base
 #: help:ir.actions.report.xml,header:0
-msgid "Add or not the coporate RML header"
+msgid "Add or not the corporate RML header"
 msgstr ""
 
 #. module: base

openerp/addons/base/i18n/nl_NL.po

@@ -2205,7 +2205,7 @@ msgstr "Tajikistan"
 
 #. module: base
 #: help:ir.actions.report.xml,header:0
-msgid "Add or not the coporate RML header"
+msgid "Add or not the corporate RML header"
 msgstr "Wel of niet RML-bedrijfskoptekst toevoegen"
 
 #. module: base

openerp/addons/base/i18n/uk_UA.po

@@ -2127,7 +2127,7 @@ msgstr ""
 
 #. module: base
 #: help:ir.actions.report.xml,header:0
-msgid "Add or not the coporate RML header"
+msgid "Add or not the corporate RML header"
 msgstr "Додати чи ні корпоративний заголовок RML"
 
 #. module: base

openerp/addons/base/ir/ir_actions.py

@@ -36,6 +36,8 @@ from tools.safe_eval import safe_eval as eval
 from tools.translate import _
 from socket import gethostname
 
+_logger = logging.getLogger(__name__)
+
 class actions(osv.osv):
     _name = 'ir.actions.actions'
     _table = 'ir_actions'
@@ -120,7 +122,7 @@ class report_xml(osv.osv):
         'attachment_use': fields.boolean('Reload from Attachment', help='If you check this, then the second time the user prints with same attachment name, it returns the previous report.'),
         'auto': fields.boolean('Custom python parser'),
 
-        'header': fields.boolean('Add RML header', help="Add or not the coporate RML header"),
+        'header': fields.boolean('Add RML header', help="Add or not the corporate RML header"),
 
         'report_xsl': fields.char('XSL path', size=256),
         'report_xml': fields.char('XML path', size=256, help=''),
@@ -550,7 +552,6 @@ class actions_server(osv.osv):
     }
 
     def get_email(self, cr, uid, action, context):
-        logger = logging.getLogger('Workflow')
         obj_pool = self.pool.get(action.model_id.model)
         id = context.get('active_id')
         obj = obj_pool.browse(cr, uid, id)
@@ -566,12 +567,11 @@ class actions_server(osv.osv):
             try:
                 obj = getattr(obj, field)
             except Exception:
-                logger.exception('Failed to parse: %s', field)
+                _logger.exception('Failed to parse: %s', field)
 
         return obj
 
     def get_mobile(self, cr, uid, action, context):
-        logger = logging.getLogger('Workflow')
         obj_pool = self.pool.get(action.model_id.model)
         id = context.get('active_id')
         obj = obj_pool.browse(cr, uid, id)
@@ -587,7 +587,7 @@ class actions_server(osv.osv):
             try:
                 obj = getattr(obj, field)
             except Exception:
-                logger.exception('Failed to parse: %s', field)
+                _logger.exception('Failed to parse: %s', field)
 
         return obj
 
@@ -624,7 +624,6 @@ class actions_server(osv.osv):
 
     # FIXME: refactor all the eval() calls in run()!
     def run(self, cr, uid, ids, context=None):
-        logger = logging.getLogger(self._name)
         if context is None:
             context = {}
         user = self.pool.get('res.users').browse(cr, uid, uid)
@@ -668,11 +667,11 @@ class actions_server(osv.osv):
                     pass
 
                 if not address:
-                    logger.info('No partner email address specified, not sending any email.')
+                    _logger.info('No partner email address specified, not sending any email.')
                     continue
 
                 if not email_from:
-                    logger.debug('--email-from command line option is not specified, using a fallback value instead.')
+                    _logger.debug('--email-from command line option is not specified, using a fallback value instead.')
                     if user.user_email:
                         email_from = user.user_email
                     else:
@@ -685,9 +684,9 @@ class actions_server(osv.osv):
                 msg = ir_mail_server.build_email(email_from, [address], subject, body)
                 res_email = ir_mail_server.send_email(cr, uid, msg)
                 if res_email:
-                    logger.info('Email successfully sent to: %s', address)
+                    _logger.info('Email successfully sent to: %s', address)
                 else:
-                    logger.warning('Failed to send email to: %s', address)
+                    _logger.warning('Failed to send email to: %s', address)
 
             if action.state == 'trigger':
                 wf_service = netsvc.LocalService("workflow")
@@ -701,7 +700,7 @@ class actions_server(osv.osv):
                 #TODO: set the user and password from the system
                 # for the sms gateway user / password
                 # USE smsclient module from extra-addons
-                logger.warning('SMS Facility has not been implemented yet. Use smsclient module!')
+                _logger.warning('SMS Facility has not been implemented yet. Use smsclient module!')
 
             if action.state == 'other':
                 res = []

openerp/addons/base/ir/ir_cron.py

@@ -37,6 +37,8 @@ from tools import DEFAULT_SERVER_DATETIME_FORMAT
 from tools.safe_eval import safe_eval as eval
 from tools.translate import _
 
+_logger = logging.getLogger(__name__)
+
 def str2tuple(s):
     return eval('tuple(%s)' % (s or ''))
 
@@ -87,8 +89,6 @@ class ir_cron(osv.osv):
         'doall' : lambda *a: 1
     }
 
-    _logger = logging.getLogger('cron')
-
     def _check_args(self, cr, uid, ids, context=None):
         try:
             for this in self.browse(cr, uid, ids, context):
@@ -114,7 +114,7 @@ class ir_cron(osv.osv):
 
         """
         cr.rollback()
-        self._logger.exception("Call of self.pool.get('%s').%s(cr, uid, *%r) failed in Job %s" % (model_name, method_name, args, job_id))
+        _logger.exception("Call of self.pool.get('%s').%s(cr, uid, *%r) failed in Job %s" % (model_name, method_name, args, job_id))
 
     def _callback(self, cr, uid, model_name, method_name, args, job_id):
         """ Run the method associated to a given job
@@ -131,15 +131,14 @@ class ir_cron(osv.osv):
         if model and hasattr(model, method_name):
             method = getattr(model, method_name)
             try:
-                netsvc.log('cron', (cr.dbname,uid,'*',model_name,method_name)+tuple(args), channel=logging.DEBUG,
+                log_depth = (None if _logger.isEnabledFor(logging.DEBUG) else 1)
-                            depth=(None if self._logger.isEnabledFor(logging.DEBUG_RPC_ANSWER) else 1), fn='object.execute')
+                netsvc.log(_logger, logging.DEBUG, 'cron.object.execute', (cr.dbname,uid,'*',model_name,method_name)+tuple(args), depth=log_depth)
-                logger = logging.getLogger('execution time')
+                if _logger.isEnabledFor(logging.DEBUG):
-                if logger.isEnabledFor(logging.DEBUG):
                     start_time = time.time()
                 method(cr, uid, *args)
-                if logger.isEnabledFor(logging.DEBUG):
+                if _logger.isEnabledFor(logging.DEBUG):
                     end_time = time.time()
-                    logger.log(logging.DEBUG, '%.3fs (%s, %s)' % (end_time - start_time, model_name, method_name))
+                    _logger.debug('%.3fs (%s, %s)' % (end_time - start_time, model_name, method_name))
             except Exception, e:
                 self._handle_callback_exception(cr, uid, model_name, method_name, args, job_id, e)
 
@@ -224,7 +223,7 @@ class ir_cron(osv.osv):
                 except psycopg2.OperationalError, e:
                     if e.pgcode == '55P03':
                         # Class 55: Object not in prerequisite state; 55P03: lock_not_available
-                        self._logger.debug('Another process/thread is already busy executing job `%s`, skipping it.', job['name'])
+                        _logger.debug('Another process/thread is already busy executing job `%s`, skipping it.', job['name'])
                         continue
                     else:
                         # Unexpected OperationalError
@@ -240,7 +239,7 @@ class ir_cron(osv.osv):
                 task_thread.setDaemon(False)
                 openerp.cron.take_thread_slot()
                 task_thread.start()
-                self._logger.debug('Cron execution thread for job `%s` spawned', job['name'])
+                _logger.debug('Cron execution thread for job `%s` spawned', job['name'])
 
             # Find next earliest job ignoring currently processed jobs (by this and other cron threads)
             find_next_time_query = """SELECT min(nextcall) AS min_next_call
@@ -261,7 +260,7 @@ class ir_cron(osv.osv):
             openerp.cron.schedule_wakeup(next_call, db_name)
 
         except Exception, ex:
-            self._logger.warning('Exception in cron:', exc_info=True)
+            _logger.warning('Exception in cron:', exc_info=True)
 
         finally:
             cr.commit()

openerp/addons/base/ir/ir_filters.py

@@ -62,7 +62,7 @@ class ir_filters(osv.osv):
 
     _columns = {
         'name': fields.char('Filter Name', size=64, translate=True, required=True),
-        'user_id':fields.many2one('res.users', 'User', help="The user this filter is available to. Keep empty to make it available to all users."),
+        'user_id':fields.many2one('res.users', 'User', help="The user this filter is available to. When left empty the filter is usable by the system only."),
         'domain': fields.text('Domain Value', required=True),
         'context': fields.text('Context Value', required=True),
         'model_id': fields.selection(_list_all_models, 'Object', size=64, required=True),

openerp/addons/base/ir/ir_mail_server.py

@@ -40,7 +40,7 @@ import openerp.tools as tools
 # it is moved to loglevels until we refactor tools.
 from openerp.loglevels import ustr
 
-_logger = logging.getLogger('ir.mail_server')
+_logger = logging.getLogger(__name__)
 
 class MailDeliveryException(osv.except_osv):
     """Specific exception subclass for mail delivery errors"""

openerp/addons/base/ir/ir_model.py

@@ -32,6 +32,8 @@ from tools import config
 from tools.translate import _
 import pooler
 
+_logger = logging.getLogger(__name__)
+
 def _get_fields_type(self, cr, uid, context=None):
     return sorted([(k,k) for k,v in fields.__dict__.iteritems()
                       if type(v) == types.TypeType
@@ -232,7 +234,7 @@ class ir_model_fields(osv.osv):
         try:
             selection_list = eval(selection)
         except Exception:
-            logging.getLogger('ir.model').warning('Invalid selection list definition for fields.selection', exc_info=True)
+            _logger.warning('Invalid selection list definition for fields.selection', exc_info=True)
             raise except_orm(_('Error'),
                     _("The Selection Options expression is not a valid Pythonic expression." \
                       "Please provide an expression in the [('key','Label'), ...] format."))
@@ -308,10 +310,10 @@ class ir_model_fields(osv.osv):
         if 'serialization_field_id' in vals or 'name' in vals:
             for field in self.browse(cr, user, ids, context=context):
                 if 'serialization_field_id' in vals and field.serialization_field_id.id != vals['serialization_field_id']:
-                    raise except_orm(_('Error!'),  _('Changing the storing system for the field "%s" is not allowed.'%field.name))
+                    raise except_orm(_('Error!'),  _('Changing the storing system for field "%s" is not allowed.')%field.name)
                 if field.serialization_field_id and (field.name != vals['name']):
-                    raise except_orm(_('Error!'),  _('Renaming the sparse field "%s" is not allowed'%field.name))           
+                    raise except_orm(_('Error!'),  _('Renaming sparse field "%s" is not allowed')%field.name)
-                
+
         column_rename = None # if set, *one* column can be renamed here
         obj = None
         models_patch = {}    # structs of (obj, [(field, prop, change_to),..])
@@ -588,7 +590,6 @@ class ir_model_data(osv.osv):
              update them seamlessly.
     """
     _name = 'ir.model.data'
-    __logger = logging.getLogger('addons.base.'+_name)
     _order = 'module,model,name'
     _columns = {
         'name': fields.char('External Identifier', required=True, size=128, select=1,
@@ -821,13 +822,13 @@ class ir_model_data(osv.osv):
         if not config.get('import_partial'):
             for (model, res_id) in to_unlink:
                 if self.pool.get(model):
-                    self.__logger.info('Deleting %s@%s', res_id, model)
+                    _logger.info('Deleting %s@%s', res_id, model)
                     try:
                         self.pool.get(model).unlink(cr, uid, [res_id])
                         cr.commit()
                     except Exception:
                         cr.rollback()
-                        self.__logger.warn(
+                        _logger.warning(
                             'Could not delete obsolete record with id: %d of model %s\n'
                             'There should be some relation that points to this resource\n'
                             'You should manually fix this and restart with --update=module',

openerp/addons/base/ir/ir_sequence.py

@@ -24,7 +24,7 @@ import time
 
 import openerp
 
-_logger = logging.getLogger('ir_sequence')
+_logger = logging.getLogger(__name__)
 
 class ir_sequence_type(openerp.osv.osv.osv):
     _name = 'ir.sequence.type'

openerp/addons/base/ir/ir_translation.py

@@ -23,6 +23,8 @@ from osv import fields, osv
 import tools
 import logging
 
+_logger = logging.getLogger(__name__)
+
 TRANSLATION_TYPE = [
     ('field', 'Field'),
     ('model', 'Object'),
@@ -87,13 +89,12 @@ class ir_translation_import_cursor(object):
     def finish(self):
         """ Transfer the data from the temp table to ir.translation
         """
-        logger = logging.getLogger('orm')
 
         cr = self._cr
         if self._debug:
             cr.execute("SELECT count(*) FROM %s" % self._table_name)
             c = cr.fetchone()[0]
-            logger.debug("ir.translation.cursor: We have %d entries to process", c)
+            _logger.debug("ir.translation.cursor: We have %d entries to process", c)
 
         # Step 1: resolve ir.model.data references to res_ids
         cr.execute("""UPDATE %s AS ti
@@ -109,7 +110,7 @@ class ir_translation_import_cursor(object):
             cr.execute("SELECT imd_module, imd_model, imd_name FROM %s " \
                 "WHERE res_id IS NULL AND imd_module IS NOT NULL" % self._table_name)
             for row in cr.fetchall():
-                logger.debug("ir.translation.cursor: missing res_id for %s. %s/%s ", *row)
+                _logger.debug("ir.translation.cursor: missing res_id for %s. %s/%s ", *row)
 
         cr.execute("DELETE FROM %s WHERE res_id IS NULL AND imd_module IS NOT NULL" % \
             self._table_name)
@@ -143,7 +144,7 @@ class ir_translation_import_cursor(object):
             cr.execute('SELECT COUNT(*) FROM ONLY %s AS irt, %s AS ti WHERE %s' % \
                 (self._parent_table, self._table_name, find_expr))
             c = cr.fetchone()[0]
-            logger.debug("ir.translation.cursor:  %d entries now in ir.translation, %d common entries with tmp", c1, c)
+            _logger.debug("ir.translation.cursor:  %d entries now in ir.translation, %d common entries with tmp", c1, c)
 
         # Step 4: cleanup
         cr.execute("DROP TABLE %s" % self._table_name)

openerp/addons/base/ir/ir_ui_menu.py

@@ -22,6 +22,7 @@
 
 import base64
 import re
+import threading
 
 import tools
 import openerp.modules
@@ -40,65 +41,68 @@ class ir_ui_menu(osv.osv):
     _name = 'ir.ui.menu'
 
     def __init__(self, *args, **kwargs):
-        self._cache = {}
+        self.cache_lock = threading.RLock()
+        self.clear_cache()
         r = super(ir_ui_menu, self).__init__(*args, **kwargs)
         self.pool.get('ir.model.access').register_cache_clearing_method(self._name, 'clear_cache')
         return r
 
     def clear_cache(self):
-        # radical but this doesn't frequently happen
+        with self.cache_lock:
-        self._cache = {}
+            # radical but this doesn't frequently happen
+            self._cache = {}
 
     def _filter_visible_menus(self, cr, uid, ids, context=None):
         """Filters the give menu ids to only keep the menu items that should be
            visible in the menu hierarchy of the current user.
            Uses a cache for speeding up the computation.
         """
-        modelaccess = self.pool.get('ir.model.access')
+        with self.cache_lock:
-        user_groups = set(self.pool.get('res.users').read(cr, 1, uid, ['groups_id'])['groups_id'])
+            modelaccess = self.pool.get('ir.model.access')
-        result = []
+            user_groups = set(self.pool.get('res.users').read(cr, 1, uid, ['groups_id'])['groups_id'])
-        for menu in self.browse(cr, uid, ids, context=context):
+            result = []
-            # this key works because user access rights are all based on user's groups (cfr ir_model_access.check)
+            for menu in self.browse(cr, uid, ids, context=context):
-            key = (cr.dbname, menu.id, tuple(user_groups))
+                # this key works because user access rights are all based on user's groups (cfr ir_model_access.check)
-            if key in self._cache:
+                key = (cr.dbname, menu.id, tuple(user_groups))
-                if self._cache[key]:
+                if key in self._cache:
-                    result.append(menu.id)
+                    if self._cache[key]:
-                #elif not menu.groups_id and not menu.action:
+                        result.append(menu.id)
-                #    result.append(menu.id)
+                    #elif not menu.groups_id and not menu.action:
-                continue
+                    #    result.append(menu.id)
-
-            self._cache[key] = False
-            if menu.groups_id:
-                restrict_to_groups = [g.id for g in menu.groups_id]
-                if not user_groups.intersection(restrict_to_groups):
-                    continue
-                #result.append(menu.id)
-                #self._cache[key] = True
-                #continue
-
-            if menu.action:
-                # we check if the user has access to the action of the menu
-                data = menu.action
-                if data:
-                    model_field = { 'ir.actions.act_window':    'res_model',
-                                    'ir.actions.report.xml':    'model',
-                                    'ir.actions.wizard':        'model',
-                                    'ir.actions.server':        'model_id',
-                                  }
-
-                    field = model_field.get(menu.action._name)
-                    if field and data[field]:
-                        if not modelaccess.check(cr, uid, data[field], 'read', False):
-                            continue
-            else:
-                # if there is no action, it's a 'folder' menu
-                if not menu.child_id:
-                    # not displayed if there is no children
                     continue
 
-            result.append(menu.id)
+                self._cache[key] = False
-            self._cache[key] = True
+                if menu.groups_id:
-        return result
+                    restrict_to_groups = [g.id for g in menu.groups_id]
+                    if not user_groups.intersection(restrict_to_groups):
+                        continue
+                    #result.append(menu.id)
+                    #self._cache[key] = True
+                    #continue
+
+                if menu.action:
+                    # we check if the user has access to the action of the menu
+                    data = menu.action
+                    if data:
+                        model_field = { 'ir.actions.act_window':    'res_model',
+                                        'ir.actions.report.xml':    'model',
+                                        'ir.actions.wizard':        'model',
+                                        'ir.actions.server':        'model_id',
+                                      }
+
+                        field = model_field.get(menu.action._name)
+                        if field and data[field]:
+                            if not modelaccess.check(cr, uid, data[field], 'read', False):
+                                continue
+                else:
+                    # if there is no action, it's a 'folder' menu
+                    if not menu.child_id:
+                        # not displayed if there is no children
+                        continue
+
+                result.append(menu.id)
+                self._cache[key] = True
+            return result
 
     def search(self, cr, uid, args, offset=0, limit=None, order=None, context=None, count=False):
         if context is None:

openerp/addons/base/ir/ir_ui_view.py

@@ -27,6 +27,8 @@ import tools
 import os
 import logging
 
+_logger = logging.getLogger(__name__)
+
 class view_custom(osv.osv):
     _name = 'ir.ui.view.custom'
     _order = 'create_date desc'  # search(limit=1) should return the last customization
@@ -72,7 +74,6 @@ class view(osv.osv):
     _order = "priority,name"
 
     def _check_xml(self, cr, uid, ids, context=None):
-        logger = logging.getLogger('init')
         for view in self.browse(cr, uid, ids, context):
             eview = etree.fromstring(view.arch.encode('utf8'))
             frng = tools.file_open(os.path.join('base','rng','view.rng'))
@@ -81,7 +82,7 @@ class view(osv.osv):
                 relaxng = etree.RelaxNG(relaxng_doc)
                 if not relaxng.validate(eview):
                     for error in relaxng.error_log:
-                        logger.error(tools.ustr(error))
+                        _logger.error(tools.ustr(error))
                     return False
             finally:
                 frng.close()

openerp/addons/base/ir/workflow/print_instance.py

@@ -19,12 +19,15 @@
 #
 ##############################################################################
 
+import logging
 import time, os
 
 import netsvc
 import report,pooler,tools
 from operator import itemgetter
 
+_logger = logging.getLogger(__name__)
+
 def graph_get(cr, graph, wkf_ids, nested, workitem, processed_subflows):
     import pydot
     cr.execute('select * from wkf_activity where wkf_id in ('+','.join(['%s']*len(wkf_ids))+')', wkf_ids)
@@ -126,13 +129,12 @@ def graph_instance_get(cr, graph, inst_id, nested=False):
 
 class report_graph_instance(object):
     def __init__(self, cr, uid, ids, data):
-        logger = netsvc.Logger()
         try:
             import pydot
         except Exception,e:
-            logger.notifyChannel('workflow', netsvc.LOG_WARNING,
+            _logger.warning(
-                    'Import Error for pydot, you will not be able to render workflows\n'
+                'Import Error for pydot, you will not be able to render workflows.\n'
-                    'Consider Installing PyDot or dependencies: http://dkbza.org/pydot.html')
+                'Consider Installing PyDot or dependencies: http://dkbza.org/pydot.html.')
             raise e
         self.done = False
 
@@ -168,9 +170,7 @@ showpage'''
                         graph_instance_get(cr, graph, inst_id, data.get('nested', False))
                     ps_string = graph.create(prog='dot', format='ps')
         except Exception, e:
-            import traceback, sys
+            _logger.exception('Exception in call:')
-            tb_s = reduce(lambda x, y: x+y, traceback.format_exception(sys.exc_type, sys.exc_value, sys.exc_traceback))
-            logger.notifyChannel('workflow', netsvc.LOG_ERROR, 'Exception in call: ' + tb_s)
             # string is in PS, like the success message would have been
             ps_string = '''%PS-Adobe-3.0
 /inch {72 mul} def

openerp/addons/base/module/module.py

@@ -40,6 +40,8 @@ from tools.translate import _
 
 from osv import fields, osv, orm
 
+_logger = logging.getLogger(__name__)
+
 ACTION_DICT = {
     'view_type': 'form',
     'view_mode': 'form',
@@ -88,7 +90,6 @@ class module_category(osv.osv):
 class module(osv.osv):
     _name = "ir.module.module"
     _description = "Module"
-    __logger = logging.getLogger('base.' + _name)
 
     @classmethod
     def get_module_info(cls, name):
@@ -97,8 +98,8 @@ class module(osv.osv):
             info = addons.load_information_from_description_file(name)
             info['version'] = release.major_version + '.' + info['version']
         except Exception:
-            cls.__logger.debug('Error when trying to fetch informations for '
+            _logger.debug('Error when trying to fetch informations for '
-                                'module %s', name, exc_info=True)
+                          'module %s', name, exc_info=True)
         return info
 
     def _get_latest_version(self, cr, uid, ids, field_name=None, arg=None, context=None):
@@ -156,14 +157,14 @@ class module(osv.osv):
                 for um in menu_obj.browse(cr, uid, imd_models.get('ir.ui.menu', []), context=context):
                     res_mod_dic['menus_by_module'].append(um.complete_name)
             except KeyError, e:
-                self.__logger.warning(
+                _logger.warning(
-                            'Data not found for items of %s', module_rec.name)
+                      'Data not found for items of %s', module_rec.name)
             except AttributeError, e:
-                self.__logger.warning(
+                _logger.warning(
-                            'Data not found for items of %s %s', module_rec.name, str(e))
+                      'Data not found for items of %s %s', module_rec.name, str(e))
             except Exception, e:
-                self.__logger.warning('Unknown error while fetching data of %s',
+                _logger.warning('Unknown error while fetching data of %s',
-                            module_rec.name, exc_info=True)
+                      module_rec.name, exc_info=True)
         for key, value in res.iteritems():
             for k, v in res[key].iteritems():
                 res[key][k] = "\n".join(sorted(v))
@@ -192,6 +193,10 @@ class module(osv.osv):
         'sequence': fields.integer('Sequence'),
         'dependencies_id': fields.one2many('ir.module.module.dependency',
             'module_id', 'Dependencies', readonly=True),
+        'auto_install': fields.boolean('Automatic Installation',
+            help='An auto-installable module is automatically installed by the '
+            'system when all its dependencies are satisfied. '
+            'If the module has no dependency, it is always installed.'),
         'state': fields.selection([
             ('uninstallable','Not Installable'),
             ('uninstalled','Not Installed'),
@@ -318,20 +323,27 @@ class module(osv.osv):
         return demo
 
     def button_install(self, cr, uid, ids, context=None):
-        model_obj = self.pool.get('ir.model.data')
+
+        # Mark the given modules to be installed.
         self.state_update(cr, uid, ids, 'to install', ['uninstalled'], context)
 
-        categ = model_obj.get_object(cr, uid, 'base', 'module_category_hidden_links', context=context)
+        # Mark (recursively) the newly satisfied modules to also be installed:
-        todo = []
+
-        for mod in categ.module_ids:
+        # Select all auto-installable (but not yet installed) modules.
-            if mod.state=='uninstalled':
+        domain = [('state', '=', 'uninstalled'), ('auto_install', '=', True),]
-                ok = True
+        uninstalled_ids = self.search(cr, uid, domain, context=context)
-                for dep in mod.dependencies_id:
+        uninstalled_modules = self.browse(cr, uid, uninstalled_ids, context=context)
-                    ok = ok and (dep.state in ('to install','installed'))
+
-                if ok:
+        # Keep those with all their dependencies satisfied.
-                    todo.append(mod.id)
+        def all_depencies_satisfied(m):
-        if todo:
+            return all(x.state in ('to install', 'installed', 'to upgrade') for x in m.dependencies_id)
-            self.button_install(cr, uid, todo, context=context)
+        to_install_modules = filter(all_depencies_satisfied, uninstalled_modules)
+        to_install_ids = map(lambda m: m.id, to_install_modules)
+
+        # Mark them to be installed.
+        if to_install_ids:
+            self.button_install(cr, uid, to_install_ids, context=context)
+
         return dict(ACTION_DICT, name=_('Install'))
 
     def button_immediate_install(self, cr, uid, ids, context=None):
@@ -439,6 +451,7 @@ class module(osv.osv):
             'complexity': terp.get('complexity', ''),
             'sequence': terp.get('sequence', 100),
             'application': terp.get('application', False),
+            'auto_install': terp.get('auto_install', False),
         }
 
     # update the list of available packages
@@ -502,8 +515,8 @@ class module(osv.osv):
                 with open(fname, 'wb') as fp:
                     fp.write(zip_content)
             except Exception:
-                self.__logger.exception('Error when trying to create module '
+                _logger.exception('Error when trying to create module '
-                                        'file %s', fname)
+                                  'file %s', fname)
                 raise orm.except_orm(_('Error'), _('Can not create the module file:\n %s') % (fname,))
             terp = self.get_module_info(mod.name)
             self.write(cr, uid, mod.id, self.get_values_from_terp(terp))
@@ -556,7 +569,6 @@ class module(osv.osv):
     def update_translations(self, cr, uid, ids, filter_lang=None, context=None):
         if context is None:
             context = {}
-        logger = logging.getLogger('i18n')
         if not filter_lang:
             pool = pooler.get_pool(cr.dbname)
             lang_obj = pool.get('res.lang')
@@ -580,7 +592,7 @@ class module(osv.osv):
                     iso_lang2 = iso_lang.split('_')[0]
                     f2 = addons.get_module_resource(mod.name, 'i18n', iso_lang2 + '.po')
                     if f2:
-                        logger.info('module %s: loading base translation file %s for language %s', mod.name, iso_lang2, lang)
+                        _logger.info('module %s: loading base translation file %s for language %s', mod.name, iso_lang2, lang)
                         tools.trans_load(cr, f2, lang, verbose=False, context=context)
                         context2['overwrite'] = True
                 # Implementation notice: we must first search for the full name of
@@ -590,23 +602,22 @@ class module(osv.osv):
                     iso_lang = iso_lang.split('_')[0]
                     f = addons.get_module_resource(mod.name, 'i18n', iso_lang + '.po')
                 if f:
-                    logger.info('module %s: loading translation file (%s) for language %s', mod.name, iso_lang, lang)
+                    _logger.info('module %s: loading translation file (%s) for language %s', mod.name, iso_lang, lang)
                     tools.trans_load(cr, f, lang, verbose=False, context=context2)
                 elif iso_lang != 'en':
-                    logger.warning('module %s: no translation for language %s', mod.name, iso_lang)
+                    _logger.warning('module %s: no translation for language %s', mod.name, iso_lang)
 
     def check(self, cr, uid, ids, context=None):
-        logger = logging.getLogger('init')
         for mod in self.browse(cr, uid, ids, context=context):
             if not mod.description:
-                logger.warn('module %s: description is empty !', mod.name)
+                _logger.warning('module %s: description is empty !', mod.name)
 
             if not mod.certificate or not mod.certificate.isdigit():
-                logger.info('module %s: no quality certificate', mod.name)
+                _logger.info('module %s: no quality certificate', mod.name)
             else:
                 val = long(mod.certificate[2:]) % 97 == 29
                 if not val:
-                    logger.critical('module %s: invalid quality certificate: %s', mod.name, mod.certificate)
+                    _logger.critical('module %s: invalid quality certificate: %s', mod.name, mod.certificate)
                     raise osv.except_osv(_('Error'), _('Module %s: Invalid Quality Certificate') % (mod.name,))
 
     def root_menus(self, cr, uid, ids, context=None):

openerp/addons/base/module/module_data.xml

@@ -7,13 +7,6 @@
             <field name="visible" eval="0" />
         </record>
 
-        <record model="ir.module.category" id="module_category_hidden_links">
-            <field name="parent_id" ref="module_category_hidden" />
-            <field name="name">Links</field>
-            <field name="sequence">0</field>
-            <field name="visible" eval="0" />
-        </record>
-
         <record model="ir.module.category" id="module_category_localization">
             <field name="name">Localization</field>
             <field name="visible" eval="0" />

openerp/addons/base/publisher_warranty/publisher_warranty.py

@@ -317,13 +317,25 @@ def get_sys_logs(cr, uid):
 
     dbuuid = pool.get('ir.config_parameter').get_param(cr, uid, 'database.uuid')
     db_create_date = pool.get('ir.config_parameter').get_param(cr, uid, 'database.create_date')
+    limit_date = datetime.datetime.now()
+    limit_date = limit_date - datetime.timedelta(15)
+    limit_date_str = limit_date.strftime(misc.DEFAULT_SERVER_DATETIME_FORMAT)
     nbr_users = pool.get("res.users").search(cr, uid, [], count=True)
+    nbr_active_users = pool.get("res.users").search(cr, uid, [("date", ">=", limit_date_str)], count=True)
+    nbr_share_users = False
+    nbr_active_share_users = False
+    if "share" in pool.get("res.users")._all_columns:
+        nbr_share_users = pool.get("res.users").search(cr, uid, [("share", "=", True)], count=True)
+        nbr_active_share_users = pool.get("res.users").search(cr, uid, [("share", "=", True), ("date", ">=", limit_date_str)], count=True)
     contractosv = pool.get('publisher_warranty.contract')
     contracts = contractosv.browse(cr, uid, contractosv.search(cr, uid, []))
     user = pool.get("res.users").browse(cr, uid, uid)
     msg = {
         "dbuuid": dbuuid,
         "nbr_users": nbr_users,
+        "nbr_active_users": nbr_active_users,
+        "nbr_share_users": nbr_share_users,
+        "nbr_active_share_users": nbr_active_share_users,
         "dbname": cr.dbname,
         "db_create_date": db_create_date,
         "version": release.version,

openerp/addons/base/res/res_bank.py

@@ -20,6 +20,7 @@
 ##############################################################################
 
 from osv import fields, osv
+from tools.translate import _
 
 class Bank(osv.osv):
     _description='Bank'
@@ -117,14 +118,13 @@ class res_partner_bank(osv.osv):
                 value = address.get(field, value)
         return value
 
-    _rec_name = 'acc_number'
     _columns = {
         'name': fields.char('Bank Account', size=64), # to be removed in v6.2 ?
         'acc_number': fields.char('Account Number', size=64, required=True),
         'bank': fields.many2one('res.bank', 'Bank'),
         'bank_bic': fields.char('Bank Identifier Code', size=16),
         'bank_name': fields.char('Bank Name', size=32),
-        'owner_name': fields.char('Account Owner Name', size=64),
+        'owner_name': fields.char('Account Owner Name', size=128),
         'street': fields.char('Street', size=128),
         'zip': fields.char('Zip', change_default=True, size=24),
         'city': fields.char('City', size=128),
@@ -141,6 +141,7 @@ class res_partner_bank(osv.osv):
         'sequence': fields.integer('Sequence'),
         'footer': fields.boolean("Display on Reports", help="Display this bank account on the footer of printed documents like invoices and sales orders.")
     }
+
     _defaults = {
         'owner_name': lambda obj, cursor, user, context: obj._default_value(
             cursor, user, 'name', context=context),
@@ -183,9 +184,12 @@ class res_partner_bank(osv.osv):
                 if type_ids:
                     t = bank_type_obj.browse(cr, uid, type_ids[0], context=context)
                     try:
+                        # avoid the default format_layout to result in "False: ..."
+                        if not val._data[val.id]['bank_name']:
+                            val._data[val.id]['bank_name'] = _('BANK')
                         result = t.format_layout % val._data[val.id]
                     except:
-                        result += ' [Formating Error]'
+                        result += ' [Formatting Error]'
                         raise
             res.append((val.id, result))
         return res

openerp/addons/base/res/res_config.py

@@ -27,6 +27,7 @@ import netsvc
 from tools import ustr
 import pooler
 
+_logger = logging.getLogger(__name__)
 
 class res_config_configurable(osv.osv_memory):
     ''' Base classes for new-style configuration items
@@ -37,11 +38,10 @@ class res_config_configurable(osv.osv_memory):
     '''
     _name = 'res.config'
     _inherit = 'ir.wizard.screen'
-    __logger = logging.getLogger(_name)
 
     def _next_action(self, cr, uid, context=None):
         Todos = self.pool['ir.actions.todo']
-        self.__logger.info('getting next %s', Todos)
+        _logger.info('getting next %s', Todos)
 
         active_todos = Todos.browse(cr, uid,
             Todos.search(cr, uid, ['&', ('type', '=', 'automatic'), ('state','=','open')]),
@@ -63,9 +63,9 @@ class res_config_configurable(osv.osv_memory):
         return None
 
     def _next(self, cr, uid, context=None):
-        self.__logger.info('getting next operation')
+        _logger.info('getting next operation')
         next = self._next_action(cr, uid, context=context)
-        self.__logger.info('next action is %s', next)
+        _logger.info('next action is %s', next)
         if next:
             res = next.action_launch(context=context)
             res['nodestroy'] = False
@@ -244,7 +244,6 @@ class res_config_installer(osv.osv_memory):
     """
     _name = 'res.config.installer'
     _inherit = 'res.config'
-    __logger = logging.getLogger(_name)
 
     _install_if = {}
 
@@ -352,7 +351,7 @@ class res_config_installer(osv.osv_memory):
         modules = self.pool.get('ir.module.module')
         to_install = list(self.modules_to_install(
             cr, uid, ids, context=context))
-        self.__logger.info('Selecting addons %s to install', to_install)
+        _logger.info('Selecting addons %s to install', to_install)
         modules.state_update(
             cr, uid,
             modules.search(cr, uid, [('name','in',to_install)]),
@@ -374,7 +373,6 @@ class ir_actions_configuration_wizard(osv.osv_memory):
     '''
     _name='ir.actions.configuration.wizard'
     _inherit = 'res.config'
-    __logger = logging.getLogger(_name)
 
     def _next_action_note(self, cr, uid, ids, context=None):
         next = self._next_action(cr, uid)
@@ -394,7 +392,7 @@ class ir_actions_configuration_wizard(osv.osv_memory):
         }
 
     def execute(self, cr, uid, ids, context=None):
-        self.__logger.warn(DEPRECATION_MESSAGE)
+        _logger.warning(DEPRECATION_MESSAGE)
 
 ir_actions_configuration_wizard()
 

openerp/addons/base/res/res_lang.py

@@ -29,6 +29,8 @@ import tools
 from tools.safe_eval import safe_eval as eval
 from tools.translate import _
 
+_logger = logging.getLogger(__name__)
+
 class lang(osv.osv):
     _name = "res.lang"
     _description = "Languages"
@@ -64,7 +66,6 @@ class lang(osv.osv):
     def load_lang(self, cr, uid, lang, lang_name=None):
         # create the language with locale information
         fail = True
-        logger = logging.getLogger('i18n')
         iso_lang = tools.get_iso_codes(lang)
         for ln in tools.get_locales(lang):
             try:
@@ -76,7 +77,7 @@ class lang(osv.osv):
         if fail:
             lc = locale.getdefaultlocale()[0]
             msg = 'Unable to get information for locale %s. Information from the default locale (%s) have been used.'
-            logger.warning(msg, lang, lc)
+            _logger.warning(msg, lang, lc)
 
         if not lang_name:
             lang_name = tools.get_languages().get(lang, lang)

openerp/addons/base/res/res_users.py

@@ -35,6 +35,8 @@ from tools.translate import _
 import openerp
 import openerp.exceptions
 
+_logger = logging.getLogger(__name__)
+
 class groups(osv.osv):
     _name = "res.groups"
     _description = "Access Groups"
@@ -254,8 +256,9 @@ class users(osv.osv):
         'context_lang': fields.selection(_lang_get, 'Language', required=True,
             help="The default language used in the graphical user interface, when translations are available. To add a new language, you can use the 'Load an Official Translation' wizard available from the 'Administration' menu."),
         'context_tz': fields.selection(_tz_get,  'Timezone', size=64,
-            help="The user's timezone, used to perform timezone conversions "
+            help="The user's timezone, used to output proper date and time values inside printed reports. "
-                 "between the server and the client."),
+                 "It is important to set a value for this field. You should use the same timezone "
+                 "that is otherwise used to pick and render date and time values: your computer's timezone."),
         'view': fields.function(_get_interface_type, type='selection', fnct_inv=_set_interface_type,
                                 selection=[('simple','Simplified'),('extended','Extended')],
                                 string='Interface', help="OpenERP offers a simplified and an extended user interface. If you use OpenERP for the first time we strongly advise you to select the simplified interface, which has less features but is easier to use. You can switch to the other interface from the User/Preferences menu at any time."),
@@ -461,7 +464,7 @@ class users(osv.osv):
                                                                    user_agent_env['base_location'])
                     cr.commit()
                 except Exception:
-                    logging.getLogger('res.users').exception("Failed to update web.base.url configuration parameter")
+                    _logger.exception("Failed to update web.base.url configuration parameter")
                 finally:
                     cr.close()
         return uid

openerp/addons/base/res/wizard/partner_wizard_massmail.py

@@ -23,7 +23,7 @@ from osv import fields, osv
 import re
 import logging
 
-_logger = logging.getLogger('mass.mailing')
+_logger = logging.getLogger(__name__)
 
 class partner_massmail_wizard(osv.osv_memory):
     """ Mass Mailing """

openerp/addons/base/rng/view.rng

@@ -413,7 +413,18 @@
         <rng:element name="notebook">
             <rng:ref name="overload"/>
             <rng:optional><rng:attribute name="colspan"/></rng:optional>
-            <rng:optional><rng:attribute name="tabpos"/></rng:optional>
+            <rng:optional>
+              <rng:attribute name="tabpos">
+                <!-- position of the notebook's tabs bar, support is
+                     optional and implementation-dependent -->
+                <rng:choice>
+                  <rng:value>up</rng:value>
+                  <rng:value>down</rng:value>
+                  <rng:value>left</rng:value>
+                  <rng:value>right</rng:value>
+                </rng:choice>
+              </rng:attribute>
+            </rng:optional>
             <rng:oneOrMore>
                 <rng:ref name="page"/>
             </rng:oneOrMore>

openerp/cron.py

@@ -47,6 +47,8 @@ import time
 import openerp
 import tools
 
+_logger = logging.getLogger(__name__)
+
 # Heapq of database wake-ups. Note that 'database wake-up' meaning is in
 # the context of the cron management. This is not originally about loading
 # a database, although having the database name in the queue will
@@ -84,8 +86,6 @@ _thread_slots = None
 # A (non re-entrant) lock to protect the above _thread_slots variable.
 _thread_slots_lock = threading.Lock()
 
-_logger = logging.getLogger('cron')
-
 # Sleep duration limits - must not loop too quickly, but can't sleep too long
 # either, because a new job might be inserted in ir_cron with a much sooner
 # execution date than current known ones. We won't see it until we wake!

openerp/loglevels.py

@@ -21,12 +21,8 @@
 
 import sys
 import logging
-import warnings
 
 LOG_NOTSET = 'notset'
-LOG_DEBUG_SQL = 'debug_sql'
-LOG_DEBUG_RPC_ANSWER = 'debug_rpc_answer'
-LOG_DEBUG_RPC = 'debug_rpc'
 LOG_DEBUG = 'debug'
 LOG_TEST = 'test'
 LOG_INFO = 'info'
@@ -34,32 +30,27 @@ LOG_WARNING = 'warn'
 LOG_ERROR = 'error'
 LOG_CRITICAL = 'critical'
 
-logging.DEBUG_RPC_ANSWER = logging.DEBUG - 4
-logging.addLevelName(logging.DEBUG_RPC_ANSWER, 'DEBUG_RPC_ANSWER')
-logging.DEBUG_RPC = logging.DEBUG - 2
-logging.addLevelName(logging.DEBUG_RPC, 'DEBUG_RPC')
-logging.DEBUG_SQL = logging.DEBUG_RPC - 3
-logging.addLevelName(logging.DEBUG_SQL, 'DEBUG_SQL')
-
 logging.TEST = logging.INFO - 5
 logging.addLevelName(logging.TEST, 'TEST')
 
+_logger = logging.getLogger(__name__)
+
 class Logger(object):
     def __init__(self):
-        warnings.warn("The netsvc.Logger API shouldn't be used anymore, please "
+        _logger.warning(
-                      "use the standard `logging.getLogger` API instead",
+            "The netsvc.Logger API shouldn't be used anymore, please "
-                      PendingDeprecationWarning, stacklevel=2)
+            "use the standard `logging.getLogger` API instead.")
         super(Logger, self).__init__()
 
     def notifyChannel(self, name, level, msg):
-        warnings.warn("notifyChannel API shouldn't be used anymore, please use "
+        _logger.warning(
-                      "the standard `logging` module instead",
+            "notifyChannel API shouldn't be used anymore, please use "
-                      PendingDeprecationWarning, stacklevel=2)
+            "the standard `logging` module instead.")
         from service.web_services import common
 
-        log = logging.getLogger(ustr(name))
+        log = logging.getLogger(__name__ + '.deprecated.' + ustr(name))
 
-        if level in [LOG_DEBUG_RPC, LOG_TEST] and not hasattr(log, level):
+        if level in [LOG_TEST] and not hasattr(log, level):
             fct = lambda msg, *args, **kwargs: log.log(getattr(logging, level.upper()), msg, *args, **kwargs)
             setattr(log, level, fct)
 

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:
@@ -66,7 +68,7 @@ def initialize(cr):
         category_id = create_categories(cr, categories)
 
         if info['installable']:
-            if info['active']:
+            if info['auto_install'] and not info['depends']:
                 state = 'to install'
             else:
                 state = 'uninstalled'
@@ -75,11 +77,12 @@ def initialize(cr):
 
         cr.execute('INSERT INTO ir_module_module \
                 (author, website, name, shortdesc, description, \
-                    category_id, state, certificate, web, license, complexity, application, icon, sequence) \
+                    category_id, auto_install, state, certificate, web, license, complexity, application, icon, sequence) \
-                VALUES (%s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s) RETURNING id', (
+                VALUES (%s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s) RETURNING id', (
             info['author'],
             info['website'], i, info['name'],
-            info['description'], category_id, state, info['certificate'],
+            info['description'], category_id,
+            info['auto_install'], state, info['certificate'],
             info['web'],
             info['license'],
             info['complexity'], info['application'], info['icon'],

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
 
 

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()
 

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:

openerp/modules/module.py

@@ -48,13 +48,15 @@ import logging
 import openerp.modules.db
 import openerp.modules.graph
 
+_logger = logging.getLogger(__name__)
+
 _ad = os.path.join(os.path.dirname(os.path.dirname(__file__)), 'addons') # default addons path (base)
 ad_paths = []
 
 # Modules already loaded
 loaded = []
 
-logger = netsvc.Logger()
+_logger = logging.getLogger(__name__)
 
 class AddonsImportHook(object):
     """
@@ -98,8 +100,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>.`.""" % (module_name, path))
@@ -135,9 +136,12 @@ To import it, use `import openerp.addons.<module>.`.""" % (module_name, path))
 
         # Note: we don't support circular import.
         f, path, descr = imp.find_module(module_part, ad_paths)
-        mod = imp.load_module(module_name, f, path, descr)
+        mod = imp.load_module('openerp.addons.' + module_part, f, path, descr)
         if not is_shadowing:
             sys.modules[module_part] = mod
+            for k in sys.modules.keys():
+                if k.startswith('openerp.addons.' + module_part):
+                    sys.modules[k[len('openerp.addons.'):]] = sys.modules[k]
         sys.modules['openerp.addons.' + module_part] = mod
         return mod
 
@@ -174,7 +178,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
 
 
@@ -317,9 +321,9 @@ def load_information_from_description_file(module):
         if os.path.isfile(terp_file) or zipfile.is_zipfile(mod_path+'.zip'):
             # default values for descriptor
             info = {
-                'active': False,
                 'application': False,
                 'author': '',
+                'auto_install': False,
                 'category': 'Uncategorized',
                 'certificate': None,
                 'complexity': 'normal',
@@ -327,6 +331,7 @@ def load_information_from_description_file(module):
                 'description': '',
                 'icon': get_module_icon(module),
                 'installable': True,
+                'auto_install': False,
                 'license': 'AGPL-3',
                 'name': False,
                 'post_load': None,
@@ -339,14 +344,21 @@ def load_information_from_description_file(module):
                 'depends data demo test init_xml update_xml demo_xml'.split(),
                 iter(list, None)))
 
-            with tools.file_open(terp_file) as terp_f:
+            f = tools.file_open(terp_file)
-                info.update(eval(terp_f.read()))
+            try:
+                info.update(eval(f.read()))
+            finally:
+                f.close()
+
+            if 'active' in info:
+                # 'active' has been renamed 'auto_install'
+                info['auto_install'] = info['active']
 
             return info
 
     #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 +372,7 @@ def init_module_models(cr, module_name, obj_list):
     TODO better explanation of _auto_init and init.
 
     """
-    logger.notifyChannel('init', netsvc.LOG_INFO,
+    _logger.info('module %s: creating or updating database tables', module_name)
-        '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 +400,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.critical(msg)
-        logger.notifyChannel('init', netsvc.LOG_CRITICAL, e)
+        _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()

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()
 

openerp/netsvc.py

@@ -38,6 +38,8 @@ from loglevels import *
 import tools
 import openerp
 
+_logger = logging.getLogger(__name__)
+
 def close_socket(sock):
     """ Closes a socket instance cleanly
 
@@ -100,12 +102,11 @@ class ExportService(object):
     """
 
     _services = {}
-    _logger = logging.getLogger('web-services')
     
     def __init__(self, name):
         ExportService._services[name] = self
         self.__name = name
-        self._logger.debug("Registered an exported service: %s" % name)
+        _logger.debug("Registered an exported service: %s" % name)
 
     @classmethod
     def getService(cls,name):
@@ -124,9 +125,6 @@ COLOR_SEQ = "\033[1;%dm"
 BOLD_SEQ = "\033[1m"
 COLOR_PATTERN = "%s%s%%s%s" % (COLOR_SEQ, COLOR_SEQ, RESET_SEQ)
 LEVEL_COLOR_MAPPING = {
-    logging.DEBUG_SQL: (WHITE, MAGENTA),
-    logging.DEBUG_RPC: (BLUE, WHITE),
-    logging.DEBUG_RPC_ANSWER: (BLUE, WHITE),
     logging.DEBUG: (BLUE, DEFAULT),
     logging.INFO: (GREEN, DEFAULT),
     logging.TEST: (WHITE, BLUE),
@@ -137,6 +135,7 @@ LEVEL_COLOR_MAPPING = {
 
 class DBFormatter(logging.Formatter):
     def format(self, record):
+        record.pid = os.getpid()
         record.dbname = getattr(threading.currentThread(), 'dbname', '?')
         return logging.Formatter.format(self, record)
 
@@ -146,12 +145,13 @@ class ColoredFormatter(DBFormatter):
         record.levelname = COLOR_PATTERN % (30 + fg_color, 40 + bg_color, record.levelname)
         return DBFormatter.format(self, record)
 
+
 def init_logger():
     from tools.translate import resetlocale
     resetlocale()
 
     # create a format for log messages and dates
-    format = '[%(asctime)s][%(dbname)s] %(levelname)s:%(name)s:%(message)s'
+    format = '%(asctime)s %(pid)s %(levelname)s %(dbname)s %(name)s: %(message)s'
 
     if tools.config['syslog']:
         # SysLog Handler
@@ -188,11 +188,49 @@ def init_logger():
         formatter = DBFormatter(format)
     handler.setFormatter(formatter)
 
-    # add the handler to the root logger
+    # Configure handlers
-    logger = logging.getLogger()
+    default_config = [
-    logger.handlers = []
+        'openerp.netsvc.rpc.request:INFO',
-    logger.addHandler(handler)
+        'openerp.netsvc.rpc.response:INFO',
-    logger.setLevel(int(tools.config['log_level'] or '0'))
+        'openerp.addons.web.common.http:INFO',
+        'openerp.addons.web.common.openerplib:INFO',
+        'openerp.sql_db:INFO',
+        ':INFO',
+    ]
+
+    if tools.config['log_level'] == 'info':
+        pseudo_config = []
+    elif tools.config['log_level'] == 'debug_rpc':
+        pseudo_config = ['openerp:DEBUG','openerp.netsvc.rpc.request:DEBUG']
+    elif tools.config['log_level'] == 'debug_rpc_answer':
+        pseudo_config = ['openerp:DEBUG','openerp.netsvc.rpc.request:DEBUG', 'openerp.netsvc.rpc.response:DEBUG']
+    elif tools.config['log_level'] == 'debug':
+        pseudo_config = ['openerp:DEBUG']
+    elif tools.config['log_level'] == 'test':
+        pseudo_config = ['openerp:TEST']
+    elif tools.config['log_level'] == 'warn':
+        pseudo_config = ['openerp:WARNING']
+    elif tools.config['log_level'] == 'error':
+        pseudo_config = ['openerp:ERROR']
+    elif tools.config['log_level'] == 'critical':
+        pseudo_config = ['openerp:CRITICAL']
+    elif tools.config['log_level'] == 'debug_sql':
+        pseudo_config = ['openerp.sql_db:DEBUG']
+
+    logconfig = tools.config['log_handler']
+
+    for logconfig_item in default_config + pseudo_config + logconfig:
+        loggername, level = logconfig_item.split(':')
+        level = getattr(logging, level, logging.INFO)
+        logger = logging.getLogger(loggername)
+        logger.handlers = []
+        logger.setLevel(level)
+        logger.addHandler(handler)
+        if loggername != '':
+            logger.propagate = False
+
+    for logconfig_item in default_config + pseudo_config + logconfig:
+        _logger.debug('logger level set: "%s"', logconfig_item)
 
 # A alternative logging scheme for automated runs of the
 # server intended to test it.
@@ -202,8 +240,8 @@ def init_alternative_logger():
             if record.levelno > 20:
                 print record.levelno, record.pathname, record.msg
     handler = H()
-    logger = logging.getLogger()
+    # Add the handler to the 'openerp' logger.
-    logger.handlers = []
+    logger = logging.getLogger('openerp')
     logger.addHandler(handler)
     logger.setLevel(logging.ERROR)
 
@@ -225,9 +263,6 @@ class Server:
     # all I/O blocking operations
     _busywait_timeout = 0.5
 
-
-    __logger = logging.getLogger('server')
-
     def __init__(self):
         Server.__servers.append(self)
         if Server.__is_started:
@@ -242,7 +277,7 @@ class Server:
             t.start()
 
     def start(self):
-        self.__logger.debug("called stub Server.start")
+        _logger.debug("called stub Server.start")
 
     def _late_start(self):
         self.start()
@@ -251,7 +286,7 @@ class Server:
                 Server.__starter_threads.remove(thr)
 
     def stop(self):
-        self.__logger.debug("called stub Server.stop")
+        _logger.debug("called stub Server.stop")
 
     def stats(self):
         """ This function should return statistics about the server """
@@ -261,7 +296,7 @@ class Server:
     def startAll(cls):
         if cls.__is_started:
             return
-        cls.__logger.info("Starting %d services" % len(cls.__servers))
+        _logger.info("Starting %d services" % len(cls.__servers))
         for srv in cls.__servers:
             srv.start()
         cls.__is_started = True
@@ -270,7 +305,7 @@ class Server:
     def quitAll(cls):
         if not cls.__is_started:
             return
-        cls.__logger.info("Stopping %d services" % len(cls.__servers))
+        _logger.info("Stopping %d services" % len(cls.__servers))
         for thr in cls.__starter_threads:
             if not thr.finished.is_set():
                 thr.cancel()
@@ -292,19 +327,17 @@ class Server:
 def replace_request_password(args):
     # password is always 3rd argument in a request, we replace it in RPC logs
     # so it's easier to forward logs for diagnostics/debugging purposes...
-    args = list(args)
     if len(args) > 2:
+        args = list(args)
         args[2] = '*'
-    return args
+    return tuple(args)
 
-def log(title, msg, channel=logging.DEBUG_RPC, depth=None, fn=""):
+def log(logger, level, prefix, msg, depth=None):
-    logger = logging.getLogger(title)
+    indent=''
-    if logger.isEnabledFor(channel):
+    indent_after=' '*len(prefix)
-        indent=''
+    for line in (prefix+pformat(msg, depth=depth)).split('\n'):
-        indent_after=' '*len(fn)
+        logger.log(level, indent+line)
-        for line in (fn+pformat(msg, depth=depth)).split('\n'):
+        indent=indent_after
-            logger.log(channel, indent+line)
-            indent=indent_after
 
 def dispatch_rpc(service_name, method, params):
     """ Handle a RPC call.
@@ -312,22 +345,25 @@ def dispatch_rpc(service_name, method, params):
     This is pure Python code, the actual marshalling (from/to XML-RPC or
     NET-RPC) is done in a upper layer.
     """
-    def _log(title, msg, channel=logging.DEBUG_RPC, depth=None, fn=""):
-        log(title, msg, channel=channel, depth=depth, fn=fn)
     try:
-        logger = logging.getLogger('result')
+        rpc_request = logging.getLogger(__name__ + '.rpc.request')
-        start_time = end_time = 0
+        rpc_response = logging.getLogger(__name__ + '.rpc.response')
-        if logger.isEnabledFor(logging.DEBUG_RPC_ANSWER):
+        rpc_request_flag = rpc_request.isEnabledFor(logging.DEBUG)
-            _log('service', tuple(replace_request_password(params)), depth=None, fn='%s.%s'%(service_name,method))
+        rpc_response_flag = rpc_response.isEnabledFor(logging.DEBUG)
-        if logger.isEnabledFor(logging.DEBUG_RPC):
+        if rpc_request_flag or rpc_response_flag:
             start_time = time.time()
+            if rpc_request and rpc_response_flag:
+                log(rpc_request,logging.DEBUG,'%s.%s'%(service_name,method), replace_request_password(params))
+
         result = ExportService.getService(service_name).dispatch(method, params)
-        if logger.isEnabledFor(logging.DEBUG_RPC):
+
+        if rpc_request_flag or rpc_response_flag:
             end_time = time.time()
-        if not logger.isEnabledFor(logging.DEBUG_RPC_ANSWER):
+            if rpc_response_flag:
-            _log('service (%.3fs)' % (end_time - start_time), tuple(replace_request_password(params)), depth=1, fn='%s.%s'%(service_name,method))
+                log(rpc_response,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), result)
-        _log('execution time', '%.3fs' % (end_time - start_time), channel=logging.DEBUG_RPC_ANSWER)
+            else:
-        _log('result', result, channel=logging.DEBUG_RPC_ANSWER)
+                log(rpc_request,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), replace_request_password(params), depth=1)
+
         return result
     except openerp.exceptions.AccessError:
         raise
@@ -336,11 +372,11 @@ def dispatch_rpc(service_name, method, params):
     except openerp.exceptions.Warning:
         raise
     except openerp.exceptions.DeferredException, e:
-        _log('exception', tools.exception_to_unicode(e))
+        _logger.error(tools.exception_to_unicode(e))
         post_mortem(e.traceback)
         raise
     except Exception, e:
-        _log('exception', tools.exception_to_unicode(e))
+        _logger.error(tools.exception_to_unicode(e))
         post_mortem(sys.exc_info())
         raise
 

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

openerp/osv/fields.py

@@ -34,8 +34,8 @@
 
 import base64
 import datetime as DT
+import logging
 import re
-import warnings
 import xmlrpclib
 from psycopg2 import Binary
 
@@ -45,6 +45,8 @@ from openerp.tools.translate import _
 from openerp.tools import float_round, float_repr
 import simplejson
 
+_logger = logging.getLogger(__name__)
+
 def _symbol_set(symb):
     if symb == None or symb == False:
         return None
@@ -136,8 +138,10 @@ class boolean(_column):
     def __init__(self, string='unknown', required=False, **args):
         super(boolean, self).__init__(string=string, required=required, **args)
         if required:
-            warnings.warn("Making a boolean field `required` has no effect, as NULL values are "
+            _logger.warning(
-                          "automatically turned into False", PendingDeprecationWarning, stacklevel=2)
+                "required=True is deprecated: making a boolean field"
+                " `required` has no effect, as NULL values are "
+                "automatically turned into False.")
 
 class integer(_column):
     _type = 'integer'
@@ -149,8 +153,10 @@ class integer(_column):
     def __init__(self, string='unknown', required=False, **args):
         super(integer, self).__init__(string=string, required=required, **args)
         if required:
-            warnings.warn("Making an integer field `required` has no effect, as NULL values are "
+            _logger.warning(
-                          "automatically turned into 0", PendingDeprecationWarning, stacklevel=2)
+                "required=True is deprecated: making an integer field"
+                " `required` has no effect, as NULL values are "
+                "automatically turned into 0.")
 
 class integer_big(_column):
     """Experimental 64 bit integer column type, currently unused.
@@ -173,8 +179,10 @@ class integer_big(_column):
     def __init__(self, string='unknown', required=False, **args):
         super(integer_big, self).__init__(string=string, required=required, **args)
         if required:
-            warnings.warn("Making an integer_big field `required` has no effect, as NULL values are "
+            _logger.warning(
-                          "automatically turned into 0", PendingDeprecationWarning, stacklevel=2)
+                "required=True is deprecated: making an integer_big field"
+                " `required` has no effect, as NULL values are "
+                "automatically turned into 0.")
 
 class reference(_column):
     _type = 'reference'
@@ -235,8 +243,10 @@ class float(_column):
         # synopsis: digits_compute(cr) ->  (precision, scale)
         self.digits_compute = digits_compute
         if required:
-            warnings.warn("Making a float field `required` has no effect, as NULL values are "
+            _logger.warning(
-                          "automatically turned into 0.0", PendingDeprecationWarning, stacklevel=2)
+                "required=True is deprecated: making a float field"
+                " `required` has no effect, as NULL values are "
+                "automatically turned into 0.0.")
 
     def digits_change(self, cr):
         if self.digits_compute:
@@ -352,7 +362,7 @@ class one2one(_column):
     _deprecated = True
 
     def __init__(self, obj, string='unknown', **args):
-        warnings.warn("The one2one field doesn't work anymore", DeprecationWarning)
+        _logger.warning("The one2one field is deprecated and doesn't work anymore.")
         _column.__init__(self, string=string, **args)
         self._obj = obj
 
@@ -617,8 +627,9 @@ class many2many(_column):
         for id in ids:
             res[id] = []
         if offset:
-            warnings.warn("Specifying offset at a many2many.get() may produce unpredictable results.",
+            _logger.warning(
-                      DeprecationWarning, stacklevel=2)
+                "Specifying offset at a many2many.get() is deprecated and may"
+                " produce unpredictable results.")
         obj = model.pool.get(self._obj)
         rel, id1, id2 = self._sql_names(model)