Disable logging as default for libraries.
We are in progress of having a zmg handler for the messages that we log through threads and processes. That handler is used in a log window to display those messages and also displayed on the terminal (if any) and logged to @bitmask.log@. The problem is that other libraries (leap_pycommon, soledad, keymanager) use the @logging@ module and log stuff to the terminal or any handler we define, and those logs are (most likely) lost.
For instance, there are messages like:
No handlers could be found for logger "leap.common.check"
We should rely on return code/messages to the app that uses those libs instead. We (most likely) won't get those logs in users' reports since they'll use the bitmask.log file or the log window.
As an example here's a run for a cdev.bitmask.net user's login.
(venv:bitmask) (git:feature/new-zmq-logger ✔) ➜ python src/leap/bitmask/app.py -d --danger [2015-06-10 20:29:08] DEBUG - L#72 : leap.bitmask.util.requirement_checker:check_requirements - Checking requirements... [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - requests>=1.1.0 ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - srp>=1.0.2 ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - pyopenssl ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - coloredlogs ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - psutil ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - ipaddr ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - twisted ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - python-daemon==1.6.1 # this should not be needed for Windows. ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - keyring ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - zope.proxy ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - pyzmq ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - txzmq ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - leap.soledad.client>=0.6.0 ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - leap.keymanager>=0.3.8 ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - leap.mail>=0.3.9 ... OK [2015-06-10 20:29:08] DEBUG - L#100 : leap.bitmask.util.requirement_checker:check_requirements - oauth ... OK [2015-06-10 20:29:08] DEBUG - L#102 : leap.bitmask.util.requirement_checker:check_requirements - Done [2015-06-10 20:29:08] INFO - L#174 : __main__:start_app - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ [2015-06-10 20:29:08] INFO - L#175 : __main__:start_app - Bitmask version 0.8.1-48-g965bc73 [2015-06-10 20:29:08] INFO - L#176 : __main__:start_app - leap.mail version 0.3.10-90-gd5d9c37 [2015-06-10 20:29:08] INFO - L#177 : __main__:start_app - ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ [2015-06-10 20:29:08] INFO - L#179 : __main__:start_app - Starting app [2015-06-10 20:29:08] DEBUG - L#67 : leap.bitmask.backend.backend_proxy:_init_zmq - Setting up ZMQ connection to server... [2015-06-10 20:29:08] DEBUG - L#174 : leap.bitmask.backend.backend_proxy:check_online - Checking whether backend is online... [2015-06-10 20:29:08] WARNING - L#180 : leap.bitmask.backend.backend_proxy:check_online - Backend is offline! [2015-06-10 20:29:08] DEBUG - L#182 : __main__:start_app - Backend online: False [2015-06-10 20:29:08] DEBUG - L#53 : leap.bitmask.backend.signaler:__init__ - Connecting to signaling server... [2015-06-10 20:29:08] DEBUG - L#172 : leap.bitmask.backend.backend:run - Starting Twisted reactor. [2015-06-10 20:29:08] DEBUG - L#67 : leap.bitmask.backend.backend_proxy:_init_zmq - Setting up ZMQ connection to server... [2015-06-10 20:29:08] DEBUG - L#188 : leap.bitmask.backend.backend_proxy:start - Starting backend proxy... [2015-06-10 20:29:08] DEBUG - L#174 : leap.bitmask.backend.backend_proxy:check_online - Checking whether backend is online... [2015-06-10 20:29:08] DEBUG - L#96 : leap.bitmask.backend.backend_proxy:run - Starting ZMQ loop. [2015-06-10 20:29:08] DEBUG - L#75 : leap.bitmask.backend.signaler_qt:_run - Running SignalerQt loop [2015-06-10 20:29:08] DEBUG - L#70 : leap.bitmask.platform_init.initializers:init_platform - Running initializer for Linux [2015-06-10 20:29:09] DEBUG - L#58 : leap.bitmask.gui.statemachines:onEntry - State Encrypted Internet::off entered. Emitting signal ... [2015-06-10 20:29:09] DEBUG - L#58 : leap.bitmask.gui.statemachines:onEntry - State Mail::off entered. Emitting signal ... [2015-06-10 20:29:09] DEBUG - L#58 : leap.bitmask.gui.statemachines:onEntry - State IMAP::off entered. Emitting signal ... [2015-06-10 20:29:09] DEBUG - L#58 : leap.bitmask.gui.statemachines:onEntry - State IMAP::off entered. Emitting signal ... No handlers could be found for logger "leap.common.check" [2015-06-10 20:29:09] ERROR - L#664 : leap.bitmask.backend.components:_can_start - Cannot load provider and eip config, cannot autostart Bus::open: Can not get ibus-daemon's address. IBusInputContext::createInputContext: no connection to ibus-daemon [2015-06-10 20:29:13] DEBUG - L#120 : leap.bitmask.provider.providerbootstrapper:_check_name_resolution - Checking name resolution for u'cdev.bitmask.net' [2015-06-10 20:29:13] DEBUG - L#134 : leap.bitmask.provider.providerbootstrapper:_check_https - Checking https for u'cdev.bitmask.net' /home/ivan/.virtualenvs/bitmask/local/lib/python2.7/site-packages/requests/packages/urllib3/connectionpool.py:734: InsecureRequestWarning: Unverified HTTPS request is being made. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.org/en/latest/security.html InsecureRequestWarning) [2015-06-10 20:29:14] DEBUG - L#167 : leap.bitmask.provider.providerbootstrapper:_download_provider_info - Downloading provider info for u'cdev.bitmask.net' [2015-06-10 20:29:14] DEBUG - L#210 : leap.bitmask.provider.providerbootstrapper:_download_provider_info - Requesting for provider.json... uri: https://api.cdev.bitmask.net:4430/provider.json, verify: /home/ivan/.config/leap/providers/cdev.bitmask.net/keys/ca/cacert.pem, headers: {'if-modified-since': 'Thu Oct 9 19:06:24 2014 GMT'} [2015-06-10 20:29:15] DEBUG - L#214 : leap.bitmask.provider.providerbootstrapper:_download_provider_info - Request status code: 200 [2015-06-10 20:29:15] DEBUG - L#244 : leap.bitmask.provider.providerbootstrapper:_download_provider_info - Provider definition has been modified [2015-06-10 20:29:15] DEBUG - L#314 : leap.bitmask.provider.providerbootstrapper:_download_ca_cert - Downloading ca cert for u'cdev.bitmask.net' at u'https://cdev.bitmask.net/ca.crt' [2015-06-10 20:29:15] DEBUG - L#346 : leap.bitmask.provider.providerbootstrapper:_check_ca_fingerprint - Checking ca fingerprint for u'cdev.bitmask.net' and cert '/home/ivan/.config/leap/providers/cdev.bitmask.net/keys/ca/cacert.pem' [2015-06-10 20:29:15] DEBUG - L#378 : leap.bitmask.provider.providerbootstrapper:_check_api_certificate - Checking api certificate for https://api.cdev.bitmask.net:4430 and cert /home/ivan/.config/leap/providers/cdev.bitmask.net/keys/ca/cacert.pem [2015-06-10 20:29:15] DEBUG - L#209 : leap.bitmask.crypto.srpauth:_authentication_preprocessing - Authentication preprocessing... [2015-06-10 20:29:15] DEBUG - L#238 : leap.bitmask.crypto.srpauth:_start_authentication - Starting authentication process... [2015-06-10 20:29:17] DEBUG - L#311 : leap.bitmask.crypto.srpauth:_process_challenge - Processing challenge... [2015-06-10 20:29:17] DEBUG - L#413 : leap.bitmask.crypto.srpauth:_verify_session - Verifying session... [2015-06-10 20:29:17] DEBUG - L#425 : leap.bitmask.crypto.srpauth:_verify_session - Session verified. [2015-06-10 20:29:17] DEBUG - L#436 : leap.bitmask.crypto.srpauth:_verify_session - SUCCESS LOGIN [2015-06-10 20:29:17] DEBUG - L#637 : leap.bitmask.crypto.srpauth:_authenticate_ok - Successful login! [2015-06-10 20:29:21] DEBUG - L#1327 : leap.bitmask.gui.mainwindow:_on_soledad_ready - Done bootstrapping Soledad bitmask-root: done [2015-06-10 20:29:21] DEBUG - L#58 : leap.bitmask.gui.statemachines:onEntry - State Mail::connecting entered. Emitting signal ... [2015-06-10 20:29:21] DEBUG - L#58 : leap.bitmask.gui.statemachines:onEntry - State Mail::on entered. Emitting signal ... ERROR:leap.common.check:Bug: ERROR:leap.common.check: File "/usr/lib/python2.7/threading.py", line 783, in __bootstrap ERROR:leap.common.check: self.__bootstrap_inner() ERROR:leap.common.check: File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner ERROR:leap.common.check: self.run() ERROR:leap.common.check: File "/usr/lib/python2.7/threading.py", line 763, in run ERROR:leap.common.check: self.__target(*self.__args, **self.__kwargs) ERROR:leap.common.check: File "/home/ivan/.virtualenvs/bitmask/local/lib/python2.7/site-packages/Twisted-14.0.2-py2.7-linux-x86_64.egg/twisted/python/threadpool.py", line 196, in _worker ERROR:leap.common.check: result = context.call(ctx, function, *args, **kwargs) ERROR:leap.common.check: File "/home/ivan/.virtualenvs/bitmask/local/lib/python2.7/site-packages/Twisted-14.0.2-py2.7-linux-x86_64.egg/twisted/python/context.py", line 118, in callWithContext ERROR:leap.common.check: return self.currentContext().callWithContext(ctx, func, *args, **kw) ERROR:leap.common.check: File "/home/ivan/.virtualenvs/bitmask/local/lib/python2.7/site-packages/Twisted-14.0.2-py2.7-linux-x86_64.egg/twisted/python/context.py", line 81, in callWithContext ERROR:leap.common.check: return func(*args,**kw) ERROR:leap.common.check: File "/home/ivan/LEAP/bitmask_client/src/leap/bitmask/backend/backend.py", line 229, in ERROR:leap.common.check: method = lambda: func(**kwargs) ERROR:leap.common.check: File "/home/ivan/LEAP/bitmask_client/src/leap/bitmask/backend/leapbackend.py", line 298, in eip_can_start ERROR:leap.common.check: self._eip.can_start(domain) ERROR:leap.common.check: File "/home/ivan/LEAP/bitmask_client/src/leap/bitmask/backend/components.py", line 693, in can_start ERROR:leap.common.check: if self._can_start(domain): ERROR:leap.common.check: File "/home/ivan/LEAP/bitmask_client/src/leap/bitmask/backend/components.py", line 653, in _can_start ERROR:leap.common.check: eip_loaded = eip_config.load(eipconfig.get_eipconfig_path(domain)) ERROR:leap.common.check: File "/home/ivan/LEAP/leap_pycommon/src/leap/common/config/baseconfig.py", line 174, in load ERROR:leap.common.check: self._config_checker.load(fromfile=config_path, mtime=mtime) ERROR:leap.common.check: File "/home/ivan/LEAP/leap_pycommon/src/leap/common/config/pluggableconfig.py", line 439, in load ERROR:leap.common.check: content = self.deserialize(fromfile=fromfile) ERROR:leap.common.check: File "/home/ivan/LEAP/leap_pycommon/src/leap/common/config/pluggableconfig.py", line 383, in deserialize ERROR:leap.common.check: leap_assert(os.path.exists(fromfile)) ERROR:leap.common.config.baseconfig:Something went wrong while loading the config from /home/ivan/.config/leap/providers/cdev.bitmask.net/eip-service.json [2015-06-10 20:33:54] ERROR - L#664 : leap.bitmask.backend.components:_can_start - Cannot load provider and eip config, cannot autostart
(from redmine: created on 2015-06-10, relates #7185 (closed))