[MERGE] many improvements regarding translations, logging, reports, http, speed

bzr revid: odo@openerp.com-20101125142219-8bkqfboyuslzpvyo

6 files changed, 203 insertions, 63 deletions

diff --git a/bin/tools/convert.py b/bin/tools/convert.py
index 756004f1e78..0f091ad4a56 100644
--- a/bin/tools/convert.py
+++ b/bin/tools/convert.py
@@ -277,7 +277,7 @@ form: module.record_id""" % (xml_id,)
                 assert modcnt == 1, """The ID "%s" refers to an uninstalled module""" % (xml_id,)
 
         if len(id) > 64:
-            self.logger.notifyChannel('init', netsvc.LOG_ERROR, 'id: %s is to long (max: 64)'% (id,))
+            self.logger.error('id: %s is to long (max: 64)', id)
 
     def _tag_delete(self, cr, rec, data_node=None):
         d_model = rec.get("model",'')
@@ -572,7 +572,7 @@ form: module.record_id""" % (xml_id,)
                     pid = res[0]
                 else:
                     # the menuitem does't exist but we are in branch (not a leaf)
-                    self.logger.notifyChannel("init", netsvc.LOG_WARNING, 'Warning no ID for submenu %s of menu %s !' % (menu_elem, str(m_l)))
+                    self.logger.warning('Warning no ID for submenu %s of menu %s !', menu_elem, str(m_l))
                     pid = self.pool.get('ir.ui.menu').create(cr, self.uid, {'parent_id' : pid, 'name' : menu_elem})
             values['parent_id'] = pid
         else:
@@ -705,7 +705,7 @@ form: module.record_id""" % (xml_id,)
                           ' expected count: %d\n'       \
                           ' obtained count: %d\n'       \
                           % (rec_string, count, len(ids))
-                    self.logger.notifyChannel('init', severity, msg)
+                    self.logger.log(severity, msg)
                     sevval = getattr(logging, severity.upper())
                     if sevval >= config['assert_exit_level']:
                         # TODO: define a dedicated exception
@@ -737,7 +737,7 @@ form: module.record_id""" % (xml_id,)
                           ' expected value: %r\n'       \
                           ' obtained value: %r\n'       \
                           % (rec_string, etree.tostring(test), expected_value, expression_value)
-                    self.logger.notifyChannel('init', severity, msg)
+                    self.logger.log(severity, msg)
                     sevval = getattr(logging, severity.upper())
                     if sevval >= config['assert_exit_level']:
                         # TODO: define a dedicated exception
@@ -852,11 +852,11 @@ form: module.record_id""" % (xml_id,)
 
     def parse(self, de):
         if not de.tag in ['terp', 'openerp']:
-            self.logger.notifyChannel("init", netsvc.LOG_ERROR, "Mismatch xml format" )
+            self.logger.error("Mismatch xml format")
             raise Exception( "Mismatch xml format: only terp or openerp as root tag" )
 
         if de.tag == 'terp':
-            self.logger.notifyChannel("init", netsvc.LOG_WARNING, "The tag <terp/> is deprecated, use <openerp/>")
+            self.logger.warning("The tag <terp/> is deprecated, use <openerp/>")
 
         for n in de.findall('./data'):
             for rec in n:
@@ -874,7 +874,7 @@ form: module.record_id""" % (xml_id,)
 
     def __init__(self, cr, module, idref, mode, report=None, noupdate=False):
 
-        self.logger = netsvc.Logger()
+        self.logger = logging.getLogger('init')
         self.mode = mode
         self.module = module
         self.cr = cr
@@ -907,13 +907,14 @@ def convert_csv_import(cr, module, fname, csvcontent, idref=None, mode='init',
         encoding: utf-8'''
     if not idref:
         idref={}
+    logger = logging.getLogger('init')
     model = ('.'.join(fname.split('.')[:-1]).split('-'))[0]
     #remove folder path from model
     head, model = os.path.split(model)
 
     pool = pooler.get_pool(cr.dbname)
 
-    input = cStringIO.StringIO(csvcontent)
+    input = cStringIO.StringIO(csvcontent) #FIXME
     reader = csv.reader(input, quotechar='"', delimiter=',')
     fields = reader.next()
     fname_partial = ""
@@ -931,9 +932,7 @@ def convert_csv_import(cr, module, fname, csvcontent, idref=None, mode='init',
                         reader.next()
 
     if not (mode == 'init' or 'id' in fields):
-        logger = netsvc.Logger()
-        logger.notifyChannel("init", netsvc.LOG_ERROR,
-            "Import specification does not contain 'id' and we are in init mode, Cannot continue.")
+        logger.error("Import specification does not contain 'id' and we are in init mode, Cannot continue.")
         return
 
     uid = 1
@@ -944,8 +943,7 @@ def convert_csv_import(cr, module, fname, csvcontent, idref=None, mode='init',
         try:
             datas.append(map(lambda x: misc.ustr(x), line))
         except:
-            logger = netsvc.Logger()
-            logger.notifyChannel("init", netsvc.LOG_ERROR, "Cannot import the line: %s" % line)
+            logger.error("Cannot import the line: %s", line)
     pool.get(model).import_data(cr, uid, fields, datas,mode, module, noupdate, filename=fname_partial)
     if config.get('import_partial'):
         data = pickle.load(file(config.get('import_partial')))
diff --git a/bin/tools/func.py b/bin/tools/func.py
index 8cedf6715fd..4150b3e688b 100644
--- a/bin/tools/func.py
+++ b/bin/tools/func.py
@@ -93,3 +93,24 @@ def synchronized(lock_attr='_lock'):
     return decorator
 
 
+
+from inspect import getsourcefile
+
+def frame_codeinfo(fframe, back=0):
+    """ Return a (filename, line) pair for a previous frame .
+        @return (filename, lineno) where lineno is either int or string==''
+    """
+    
+    try:
+        if not fframe:
+            return ("<unknown>", '')
+        for i in range(back):
+            fframe = fframe.f_back
+        try:
+            fname = getsourcefile(fframe)
+        except TypeError:
+            fname = '<builtin>'
+        lineno = fframe.f_lineno or ''
+        return (fname, lineno)
+    except Exception:
+        return ("<unknown>", '')
diff --git a/bin/tools/misc.py b/bin/tools/misc.py
index 90b4c135214..7a416052d21 100644
--- a/bin/tools/misc.py
+++ b/bin/tools/misc.py
@@ -25,6 +25,7 @@ Miscelleanous tools used by OpenERP.
 """
 
 import inspect
+import subprocess
 import logging
 import os
 import re
@@ -33,6 +34,7 @@ import socket
 import sys
 import threading
 import time
+import warnings
 import zipfile
 from datetime import datetime
 from email.MIMEText import MIMEText
@@ -141,27 +143,24 @@ def exec_pg_command(name, *args):
     if not prog:
         raise Exception('Couldn\'t find %s' % name)
     args2 = (os.path.basename(prog),) + args
-    return os.spawnv(os.P_WAIT, prog, args2)
+    
+    return subprocess.call(args2, executable=prog)
 
 def exec_pg_command_pipe(name, *args):
     prog = find_pg_tool(name)
     if not prog:
         raise Exception('Couldn\'t find %s' % name)
-    if os.name == "nt":
-        cmd = '"' + prog + '" ' + ' '.join(args)
-    else:
-        cmd = prog + ' ' + ' '.join(args)
-    return os.popen2(cmd, 'b')
+    pop = subprocess.Popen(args, executable=prog, shell=True, bufsize= -1,
+          stdin=subprocess.PIPE, stdout=subprocess.PIPE, close_fds=True)
+    return (pop.stdin, pop.stdout)
 
 def exec_command_pipe(name, *args):
     prog = find_in_path(name)
     if not prog:
         raise Exception('Couldn\'t find %s' % name)
-    if os.name == "nt":
-        cmd = '"'+prog+'" '+' '.join(args)
-    else:
-        cmd = prog+' '+' '.join(args)
-    return os.popen2(cmd, 'b')
+    pop = subprocess.Popen(args, executable=prog, shell=True, bufsize= -1,
+          stdin=subprocess.PIPE, stdout=subprocess.PIPE, close_fds=True)
+    return (pop.stdin, pop.stdout)
 
 #----------------------------------------------------------
 # File paths
@@ -1114,6 +1113,8 @@ def debug(what):
             --log-level=debug
 
     """
+    warnings.warn("The tools.debug() method is deprecated, please use logging.",
+                      DeprecationWarning, stacklevel=2)
     from inspect import stack
     from pprint import pformat
     st = stack()[1]
@@ -1122,10 +1123,10 @@ def debug(what):
     what = pformat(what)
     if param != what:
         what = "%s = %s" % (param, what)
-    netsvc.Logger().notifyChannel(st[3], netsvc.LOG_DEBUG, what)
+    logging.getLogger(st[3]).debug(what)
 
 
-icons = map(lambda x: (x,x), ['STOCK_ABOUT', 'STOCK_ADD', 'STOCK_APPLY', 'STOCK_BOLD',
+__icons_list = ['STOCK_ABOUT', 'STOCK_ADD', 'STOCK_APPLY', 'STOCK_BOLD',
 'STOCK_CANCEL', 'STOCK_CDROM', 'STOCK_CLEAR', 'STOCK_CLOSE', 'STOCK_COLOR_PICKER',
 'STOCK_CONNECT', 'STOCK_CONVERT', 'STOCK_COPY', 'STOCK_CUT', 'STOCK_DELETE',
 'STOCK_DIALOG_AUTHENTICATION', 'STOCK_DIALOG_ERROR', 'STOCK_DIALOG_INFO',
@@ -1161,7 +1162,11 @@ icons = map(lambda x: (x,x), ['STOCK_ABOUT', 'STOCK_ADD', 'STOCK_APPLY', 'STOCK_
 'terp-gdu-smart-failing','terp-go-week','terp-gtk-select-all','terp-locked','terp-mail-forward',
 'terp-mail-message-new','terp-mail-replied','terp-rating-rated','terp-stage','terp-stock_format-scientific',
 'terp-dolar_ok!','terp-idea','terp-stock_format-default','terp-mail-','terp-mail_delete'
-])
+]
+
+def icons(*a, **kw):
+    global __icons_list
+    return [(x, x) for x in __icons_list ]
 
 def extract_zip_file(zip_file, outdirectory):
     zf = zipfile.ZipFile(zip_file, 'r')
diff --git a/bin/tools/test_reports.py b/bin/tools/test_reports.py
new file mode 100644
index 00000000000..b6d0ec6b714
--- /dev/null
+++ b/bin/tools/test_reports.py
@@ -0,0 +1,91 @@
+# -*- coding: utf-8 -*-
+##############################################################################
+#
+#    OpenERP, Open Source Management Solution
+#    Copyright (C) 2010 OpenERP s.a. (<http://openerp.com>).
+#
+#    This program is free software: you can redistribute it and/or modify
+#    it under the terms of the GNU Affero General Public License as
+#    published by the Free Software Foundation, either version 3 of the
+#    License, or (at your option) any later version.
+#
+#    This program is distributed in the hope that it will be useful,
+#    but WITHOUT ANY WARRANTY; without even the implied warranty of
+#    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+#    GNU Affero General Public License for more details.
+#
+#    You should have received a copy of the GNU Affero General Public License
+#    along with this program.  If not, see <http://www.gnu.org/licenses/>.
+#
+##############################################################################
+
+""" Helper functions for reports testing.
+
+    Please /do not/ import this file by default, but only explicitly call it
+    through the code of yaml tests.
+"""
+
+import netsvc
+import tools
+import logging
+from subprocess import Popen, PIPE
+import os
+import tempfile
+
+def try_report(cr, uid, rname, ids, data=None, context=None):
+    """ Try to render a report <rname> with contents of ids
+    
+        This function should also check for common pitfalls of reports.
+    """
+    log = logging.getLogger('tools.test_reports')
+    if data is None:
+        data = {}
+    if context is None:
+        context = {}
+    if rname.startswith('report.'):
+        rname_s = rname[7:]
+    else:
+        rname_s = rname
+    log.debug("Trying %s.create(%r)", rname, ids)
+    res = netsvc.LocalService(rname).create(cr, uid, ids, data, context)
+    if not isinstance(res, tuple):
+        raise RuntimeError("Result of %s.create() should be a (data,format) tuple, now it is a %s" % \
+                                (rname, type(res)))
+    (res_data, res_format) = res
+   
+    if not res_data:
+        raise ValueError("Report %s produced an empty result!" % rname)
+    
+    if tools.config['test_report_directory']:
+        file(os.path.join(tools.config['test_report_directory'], rname+ '.'+res_format), 'wb+').write(res_data)
+
+    log.debug("Have a %s report for %s, will examine it", res_format, rname)
+    if res_format == 'pdf':
+        if res_data[:5] != '%PDF-':
+            raise ValueError("Report %s produced a non-pdf header, %r" % (rname, res_data[:10]))
+    
+        res_text = False
+        try:
+            fd, rfname = tempfile.mkstemp(suffix=res_format)
+            os.write(fd, res_data)
+            os.close(fd)
+
+            fp = Popen(['pdftotext', '-enc', 'UTF-8', '-nopgbrk', rfname, '-'], shell=False, stdout=PIPE).stdout
+            res_text = tools.ustr(fp.read())
+            os.unlink(rfname)
+        except Exception:
+            log.warning("Cannot extract report's text:", exc_info=True)
+        
+        if res_text is not False:
+            for line in res_text.split('\n'):
+                if ('[[' in line) or ('[ [' in line):
+                    log.error("Report %s may have bad expression near: \"%s\".", rname, line[80:])
+            # TODO more checks, what else can be a sign of a faulty report?
+    elif res_format == 'foobar':
+        # TODO
+        pass
+    else:
+        log.warning("Report %s produced a \"%s\" chunk, cannot examine it", rname, res_format)
+
+    return True
+#eof
diff --git a/bin/tools/translate.py b/bin/tools/translate.py
index 807de0d2cde..e1afc43b80f 100644
--- a/bin/tools/translate.py
+++ b/bin/tools/translate.py
@@ -27,6 +27,7 @@ import itertools
 import locale
 import os
 import re
+import logging
 import tarfile
 import tempfile
 from os.path import join
@@ -220,11 +221,11 @@ def unquote(str):
 # class to handle po files
 class TinyPoFile(object):
     def __init__(self, buffer):
-        self.logger = netsvc.Logger()
+        self.logger = logging.getLogger('i18n')
         self.buffer = buffer
 
     def warn(self, msg):
-        self.logger.notifyChannel("i18n", netsvc.LOG_WARNING, msg)
+        self.logger.warning(msg)
 
     def __iter__(self):
         self.buffer.seek(0)
@@ -316,7 +317,9 @@ class TinyPoFile(object):
         self.first = False
 
         if name is None:
-            self.warn('Missing "#:" formated comment for the following source:\n\t%s' % (source,))
+            if not fuzzy:
+                self.warn('Missing "#:" formated comment at line %d for the following source:\n\t%s', 
+                        self.cur_line(), source[:30])
             return self.next()
         return type, name, res_id, source, trad
 
@@ -483,7 +486,7 @@ def in_modules(object_name, modules):
     return module in modules
 
 def trans_generate(lang, modules, dbname=None):
-    logger = netsvc.Logger()
+    logger = logging.getLogger('i18n')
     if not dbname:
         dbname=tools.config['db_name']
         if not modules:
@@ -499,13 +502,21 @@ def trans_generate(lang, modules, dbname=None):
 
     query = 'SELECT name, model, res_id, module'    \
             '  FROM ir_model_data'
+            
+    query_models = """SELECT m.id, m.model, imd.module 
+            FROM ir_model AS m, ir_model_data AS imd 
+            WHERE m.id = imd.res_id AND imd.model = 'ir.model' """
+
     if 'all_installed' in modules:
         query += ' WHERE module IN ( SELECT name FROM ir_module_module WHERE state = \'installed\') '
+        query_models += " AND imd.module in ( SELECT name FROM ir_module_module WHERE state = 'installed') "
     query_param = None
     if 'all' not in modules:
         query += ' WHERE module IN %s'
+        query_models += ' AND imd.module in %s'
         query_param = (tuple(modules),)
     query += ' ORDER BY module, model, name'
+    query_models += ' ORDER BY module, model'
 
     cr.execute(query, query_param)
 
@@ -526,12 +537,12 @@ def trans_generate(lang, modules, dbname=None):
         xml_name = "%s.%s" % (module, encode(xml_name))
 
         if not pool.get(model):
-            logger.notifyChannel("db", netsvc.LOG_ERROR, "Unable to find object %r" % (model,))
+            logger.error("Unable to find object %r", model)
             continue
 
         exists = pool.get(model).exists(cr, uid, res_id)
         if not exists:
-            logger.notifyChannel("db", netsvc.LOG_WARNING, "Unable to find object %r with id %d" % (model, res_id))
+            logger.warning("Unable to find object %r with id %d", model, res_id)
             continue
         obj = pool.get(model).browse(cr, uid, res_id)
 
@@ -558,7 +569,7 @@ def trans_generate(lang, modules, dbname=None):
 
                         # export fields
                         if not result.has_key('fields'):
-                            logger.notifyChannel("db",netsvc.LOG_WARNING,"res has no fields: %r" % result)
+                            logger.warning("res has no fields: %r", result)
                             continue
                         for field_name, field_def in result['fields'].iteritems():
                             res_name = name + ',' + field_name
@@ -587,7 +598,7 @@ def trans_generate(lang, modules, dbname=None):
             try:
                 field_name = encode(obj.name)
             except AttributeError, exc:
-                logger.notifyChannel("db", netsvc.LOG_ERROR, "name error in %s: %s" % (xml_name,str(exc)))
+                logger.error("name error in %s: %s", xml_name, str(exc))
                 continue
             objmodel = pool.get(obj.model)
             if not objmodel or not field_name in objmodel._columns:
@@ -635,22 +646,9 @@ def trans_generate(lang, modules, dbname=None):
                     for t in parse_func(d.iter()):
                         push_translation(module, report_type, name, 0, t)
                 except (IOError, etree.XMLSyntaxError):
-                    logging.getLogger("i18n").exception("couldn't export translation for report %s %s %s", name, report_type, fname)
-
-        model_obj = pool.get(model)
-        def push_constraint_msg(module, term_type, model, msg):
-            # Check presence of __call__ directly instead of using
-            # callable() because it will be deprecated as of Python 3.0
-            if not hasattr(msg, '__call__'):
-                push_translation(module, term_type, model, 0, encode(msg))
-
-        for constraint in model_obj._constraints:
-            push_constraint_msg(module, 'constraint', model, constraint[1])
+                    logger.exception("couldn't export translation for report %s %s %s", name, report_type, fname)
 
-        for constraint in model_obj._sql_constraints:
-            push_constraint_msg(module, 'sql_constraint', model, constraint[2])
-
-        for field_name,field_def in model_obj._columns.items():
+        for field_name,field_def in obj._table._columns.items():
             if field_def.translate:
                 name = model + "," + field_name
                 try:
@@ -659,6 +657,32 @@ def trans_generate(lang, modules, dbname=None):
                     trad = ''
                 push_translation(module, 'model', name, xml_name, encode(trad))
 
+        # End of data for ir.model.data query results
+
+    cr.execute(query_models, query_param)
+
+    def push_constraint_msg(module, term_type, model, msg):
+        # Check presence of __call__ directly instead of using
+        # callable() because it will be deprecated as of Python 3.0
+        if not hasattr(msg, '__call__'):
+            push_translation(module, term_type, model, 0, encode(msg))
+
+    for (model_id, model, module) in cr.fetchall():
+        module = encode(module)
+        model = encode(model)
+
+        model_obj = pool.get(model)
+
+        if not model_obj:
+            logging.getLogger("i18n").error("Unable to find object %r", model)
+            continue
+
+        for constraint in getattr(model_obj, '_constraints', []):
+            push_constraint_msg(module, 'constraint', model, constraint[1])
+
+        for constraint in getattr(model_obj, '_sql_constraints', []):
+            push_constraint_msg(module, 'sql_constraint', model, constraint[2])
+
     # parse source code for _() calls
     def get_module_from_path(path, mod_paths=None):
         if not mod_paths:
@@ -750,23 +774,26 @@ def trans_generate(lang, modules, dbname=None):
     cr.close()
     return out
 
-def trans_load(db_name, filename, lang, strict=False, verbose=True, context={}):
-    logger = netsvc.Logger()
+def trans_load(db_name, filename, lang, strict=False, verbose=True, context=None):
+    logger = logging.getLogger('i18n')
     try:
         fileobj = open(filename,'r')
+        logger.info("loading %s", filename)
         fileformat = os.path.splitext(filename)[-1][1:].lower()
         r = trans_load_data(db_name, fileobj, fileformat, lang, strict=strict, verbose=verbose, context=context)
         fileobj.close()
         return r
     except IOError:
         if verbose:
-            logger.notifyChannel("i18n", netsvc.LOG_ERROR, "couldn't read translation file %s" % (filename,))
+            logger.error("couldn't read translation file %s", filename)
         return None
 
-def trans_load_data(db_name, fileobj, fileformat, lang, strict=False, lang_name=None, verbose=True, context={}):
-    logger = netsvc.Logger()
+def trans_load_data(db_name, fileobj, fileformat, lang, strict=False, lang_name=None, verbose=True, context=None):
+    logger = logging.getLogger('i18n')
     if verbose:
-        logger.notifyChannel("i18n", netsvc.LOG_INFO, 'loading translation file for language %s' % (lang))
+        logger.info('loading translation file for language %s', lang)
+    if context is None:
+        context = {}
     pool = pooler.get_pool(db_name)
     lang_obj = pool.get('res.lang')
     trans_obj = pool.get('ir.translation')
@@ -790,7 +817,7 @@ def trans_load_data(db_name, fileobj, fileformat, lang, strict=False, lang_name=
             if fail:
                 lc = locale.getdefaultlocale()[0]
                 msg = 'Unable to get information for locale %s. Information from the default locale (%s) have been used.'
-                logger.notifyChannel('i18n', netsvc.LOG_WARNING, msg % (lang, lc))
+                logger.warning(msg, lang, lc)
 
             if not lang_name:
                 lang_name = tools.get_languages().get(lang, lang)
@@ -829,6 +856,7 @@ def trans_load_data(db_name, fileobj, fileformat, lang, strict=False, lang_name=
             reader = TinyPoFile(fileobj)
             f = ['type', 'name', 'res_id', 'src', 'value']
         else:
+            logger.error('Bad file format: %s', fileformat)
             raise Exception(_('Bad file format'))
 
         # read the rest of the file
@@ -907,11 +935,10 @@ def trans_load_data(db_name, fileobj, fileformat, lang, strict=False, lang_name=
             cr.commit()
         cr.close()
         if verbose:
-            logger.notifyChannel("i18n", netsvc.LOG_INFO,
-                    "translation file loaded succesfully")
+            logger.info("translation file loaded succesfully")
     except IOError:
         filename = '[lang: %s][format: %s]' % (iso_lang or 'new', fileformat)
-        logger.notifyChannel("i18n", netsvc.LOG_ERROR, "couldn't read translation file %s" % (filename,))
+        logger.exception("couldn't read translation file %s", filename)
 
 def get_locales(lang=None):
     if lang is None:
diff --git a/bin/tools/yaml_import.py b/bin/tools/yaml_import.py
index 90fedbd0330..0098e4e2117 100644
--- a/bin/tools/yaml_import.py
+++ b/bin/tools/yaml_import.py
@@ -174,9 +174,7 @@ class YamlInterpreter(object):
             else:
                 module = self.module
                 checked_xml_id = xml_id
-            ir_id = self.pool.get('ir.model.data')._get_id(self.cr, self.uid, module, checked_xml_id)
-            obj = self.pool.get('ir.model.data').read(self.cr, self.uid, ir_id, ['res_id'])
-            id = int(obj['res_id'])
+            _, id = self.pool.get('ir.model.data').get_object_reference(self.cr, self.uid, module, checked_xml_id)
             self.id_map[xml_id] = id
         return id