From 8021a0e13726a1c541fa11c166f01090da6adbf1 Mon Sep 17 00:00:00 2001
From: deadc0de6 <info@deadc0de.ch>
Date: Thu, 29 Apr 2021 14:51:44 +0200
Subject: [PATCH] refactor debug logging

---
 dotdrop/cfg_aggregator.py |  32 ++++-------
 dotdrop/cfg_yaml.py       |   2 +-
 dotdrop/comparator.py     |  67 ++++++++++------------
 dotdrop/dotdrop.py        | 113 ++++++++++++++------------------------
 dotdrop/importer.py       |  27 ++++-----
 dotdrop/installer.py      | 108 ++++++++++++++----------------------
 dotdrop/logger.py         |   8 ++-
 dotdrop/options.py        |  15 +++--
 dotdrop/templategen.py    |  26 +++------
 dotdrop/updater.py        |  83 +++++++++++-----------------
 dotdrop/utils.py          |  22 ++++----
 11 files changed, 198 insertions(+), 305 deletions(-)

diff --git a/dotdrop/cfg_aggregator.py b/dotdrop/cfg_aggregator.py
index 1614416..017a256 100644
--- a/dotdrop/cfg_aggregator.py
+++ b/dotdrop/cfg_aggregator.py
@@ -41,7 +41,7 @@ class CfgAggregator:
         self.profile_key = profile_key
         self.debug = debug
         self.dry = dry
-        self.log = Logger()
+        self.log = Logger(debug=self.debug)
         self._load()
 
     ########################################################
@@ -74,7 +74,7 @@ class CfgAggregator:
 
         key = dotfile.key
         ret = self.cfgyaml.add_dotfile_to_profile(key, self.profile_key)
-        if ret and self.debug:
+        if ret:
             msg = 'new dotfile {} to profile {}'
             self.log.dbg(msg.format(key, self.profile_key))
 
@@ -196,8 +196,7 @@ class CfgAggregator:
         """create a new dotfile"""
         # get a new dotfile with a unique key
         key = self._get_new_dotfile_key(dst)
-        if self.debug:
-            self.log.dbg('new dotfile key: {}'.format(key))
+        self.log.dbg('new dotfile key: {}'.format(key))
         # add the dotfile
         if not self.cfgyaml.add_dotfile(key, src, dst, link, chmod=chmod):
             return None
@@ -260,9 +259,9 @@ class CfgAggregator:
         # patch actions in settings default_actions
         self._patch_keys_to_objs([self.settings],
                                  "default_actions", self._get_action_w_args)
-        if self.debug:
-            msg = 'default actions: {}'.format(self.settings.default_actions)
-            self.log.dbg(msg)
+
+        msg = 'default actions: {}'.format(self.settings.default_actions)
+        self.log.dbg(msg)
 
         # patch trans_w/trans_r in dotfiles
         self._patch_keys_to_objs(self.dotfiles,
@@ -281,8 +280,7 @@ class CfgAggregator:
         """
         if not containers:
             return
-        if self.debug:
-            self.log.dbg('patching {} ...'.format(keys))
+        self.log.dbg('patching {} ...'.format(keys))
         for container in containers:
             objects = []
             okeys = getattr(container, keys)
@@ -300,9 +298,6 @@ class CfgAggregator:
                 objects.append(obj)
             if not islist:
                 objects = objects[0]
-            # if self.debug:
-            #     er = 'patching {}.{} with {}'
-            #     self.log.dbg(er.format(c, keys, objects))
             setattr(container, keys, objects)
 
     ########################################################
@@ -368,8 +363,7 @@ class CfgAggregator:
         if self.dry:
             return
         self.save()
-        if self.debug:
-            self.log.dbg('reloading config')
+        self.log.dbg('reloading config')
         olddebug = self.debug
         self.debug = False
         self._load()
@@ -411,9 +405,8 @@ class CfgAggregator:
         if len(fields) > 1:
             # we have args
             key, *args = fields
-            if self.debug:
-                msg = 'action with parm: {} and {}'
-                self.log.dbg(msg.format(key, args))
+            msg = 'action with parm: {} and {}'
+            self.log.dbg(msg.format(key, args))
             action = self._get_action(key).copy(args)
         else:
             action = self._get_action(key)
@@ -426,9 +419,8 @@ class CfgAggregator:
             if len(fields) > 1:
                 # we have args
                 key, *args = fields
-                if self.debug:
-                    msg = 'trans with parm: {} and {}'
-                    self.log.dbg(msg.format(key, args))
+                msg = 'trans with parm: {} and {}'
+                self.log.dbg(msg.format(key, args))
                 trans = getter(key).copy(args)
             else:
                 trans = getter(key)
diff --git a/dotdrop/cfg_yaml.py b/dotdrop/cfg_yaml.py
index ffa7acb..e09e4c9 100644
--- a/dotdrop/cfg_yaml.py
+++ b/dotdrop/cfg_yaml.py
@@ -106,7 +106,7 @@ class CfgYaml:
         self._path = os.path.abspath(path)
         self._profile = profile
         self._debug = debug
-        self._log = Logger()
+        self._log = Logger(debug=self._debug)
         # config needs to be written
         self._dirty = False
         # indicates the config has been updated
diff --git a/dotdrop/comparator.py b/dotdrop/comparator.py
index 05b0590..b4d937d 100644
--- a/dotdrop/comparator.py
+++ b/dotdrop/comparator.py
@@ -24,7 +24,7 @@ class Comparator:
         """
         self.diff_cmd = diff_cmd
         self.debug = debug
-        self.log = Logger()
+        self.log = Logger(debug=self.debug)
         self.ignore_missing_in_dotdrop = ignore_missing_in_dotdrop
 
     def compare(self, local_path, deployed_path, ignore=[]):
@@ -32,12 +32,11 @@ class Comparator:
         deployed_path (destination file)"""
         local_path = os.path.expanduser(local_path)
         deployed_path = os.path.expanduser(deployed_path)
-        if self.debug:
-            self.log.dbg('comparing {} and {}'.format(
-                local_path,
-                deployed_path,
-            ))
-            self.log.dbg('ignore pattern(s): {}'.format(ignore))
+        self.log.dbg('comparing {} and {}'.format(
+            local_path,
+            deployed_path,
+        ))
+        self.log.dbg('ignore pattern(s): {}'.format(ignore))
 
         # test type of file
         if os.path.isdir(local_path) and not os.path.isdir(deployed_path):
@@ -53,17 +52,13 @@ class Comparator:
 
         # test content
         if not os.path.isdir(local_path):
-            if self.debug:
-                self.log.dbg('{} is a file'.format(local_path))
-            if self.debug:
-                self.log.dbg('is file')
+            self.log.dbg('{} is a file'.format(local_path))
             ret = self._comp_file(local_path, deployed_path, ignore)
             if not ret:
                 ret = self._comp_mode(local_path, deployed_path)
             return ret
 
-        if self.debug:
-            self.log.dbg('{} is a directory'.format(local_path))
+        self.log.dbg('{} is a directory'.format(local_path))
 
         ret = self._comp_dir(local_path, deployed_path, ignore)
         if not ret:
@@ -76,55 +71,49 @@ class Comparator:
         deployed_mode = get_file_perm(deployed_path)
         if local_mode == deployed_mode:
             return ''
-        if self.debug:
-            msg = 'mode differ {} ({:o}) and {} ({:o})'
-            self.log.dbg(msg.format(local_path, local_mode, deployed_path,
-                                    deployed_mode))
+        msg = 'mode differ {} ({:o}) and {} ({:o})'
+        self.log.dbg(msg.format(local_path, local_mode, deployed_path,
+                                deployed_mode))
         ret = 'modes differ for {} ({:o}) vs {:o}\n'
         return ret.format(deployed_path, deployed_mode, local_mode)
 
     def _comp_file(self, local_path, deployed_path, ignore):
         """compare a file"""
-        if self.debug:
-            self.log.dbg('compare file {} with {}'.format(
-                local_path,
-                deployed_path,
-            ))
+        self.log.dbg('compare file {} with {}'.format(
+            local_path,
+            deployed_path,
+        ))
         if (self.ignore_missing_in_dotdrop and not
                 os.path.exists(local_path)) \
                 or must_ignore([local_path, deployed_path], ignore,
                                debug=self.debug):
-            if self.debug:
-                self.log.dbg('ignoring diff {} and {}'.format(
-                    local_path,
-                    deployed_path,
-                ))
+            self.log.dbg('ignoring diff {} and {}'.format(
+                local_path,
+                deployed_path,
+            ))
             return ''
         return self._diff(local_path, deployed_path)
 
     def _comp_dir(self, local_path, deployed_path, ignore):
         """compare a directory"""
-        if self.debug:
-            self.log.dbg('compare directory {} with {}'.format(
-                local_path,
-                deployed_path,
-            ))
+        self.log.dbg('compare directory {} with {}'.format(
+            local_path,
+            deployed_path,
+        ))
         if not os.path.exists(deployed_path):
             return ''
         if (self.ignore_missing_in_dotdrop and not
                 os.path.exists(local_path)) \
                 or must_ignore([local_path, deployed_path], ignore,
                                debug=self.debug):
-            if self.debug:
-                self.log.dbg('ignoring diff {} and {}'.format(
-                    local_path,
-                    deployed_path,
-                ))
+            self.log.dbg('ignoring diff {} and {}'.format(
+                local_path,
+                deployed_path,
+            ))
             return ''
         if not os.path.isdir(deployed_path):
             return '\"{}\" is a file\n'.format(deployed_path)
-        if self.debug:
-            self.log.dbg('compare {} and {}'.format(local_path, deployed_path))
+        self.log.dbg('compare {} and {}'.format(local_path, deployed_path))
         ret = []
         comp = filecmp.dircmp(local_path, deployed_path)
 
diff --git a/dotdrop/dotdrop.py b/dotdrop/dotdrop.py
index 4334796..04e59da 100644
--- a/dotdrop/dotdrop.py
+++ b/dotdrop/dotdrop.py
@@ -48,8 +48,7 @@ def action_executor(o, actions, defactions, templater, post=False):
                 LOG.dry('would execute def-{}-action: {}'.format(s,
                                                                  action))
                 continue
-            if o.debug:
-                LOG.dbg('executing def-{}-action: {}'.format(s, action))
+            LOG.dbg('executing def-{}-action: {}'.format(s, action))
             ret = action.execute(templater=templater, debug=o.debug)
             if not ret:
                 err = 'def-{}-action \"{}\" failed'.format(s, action.key)
@@ -61,8 +60,7 @@ def action_executor(o, actions, defactions, templater, post=False):
             if o.dry:
                 LOG.dry('would execute {}-action: {}'.format(s, action))
                 continue
-            if o.debug:
-                LOG.dbg('executing {}-action: {}'.format(s, action))
+            LOG.dbg('executing {}-action: {}'.format(s, action))
             ret = action.execute(templater=templater, debug=o.debug)
             if not ret:
                 err = '{}-action \"{}\" failed'.format(s, action.key)
@@ -108,8 +106,7 @@ def _dotfile_compare(o, dotfile, tmp):
     t.add_tmp_vars(newvars=newvars)
 
     # dotfiles does not exist / not installed
-    if o.debug:
-        LOG.dbg('comparing {}'.format(dotfile))
+    LOG.dbg('comparing {}'.format(dotfile))
 
     src = dotfile.src
     if not os.path.lexists(os.path.expanduser(dotfile.dst)):
@@ -120,8 +117,7 @@ def _dotfile_compare(o, dotfile, tmp):
     # apply transformation
     tmpsrc = None
     if dotfile.trans_r:
-        if o.debug:
-            LOG.dbg('applying transformation before comparing')
+        LOG.dbg('applying transformation before comparing')
         tmpsrc = apply_trans(o.dotpath, dotfile, t, debug=o.debug)
         if not tmpsrc:
             # could not apply trans
@@ -132,10 +128,9 @@ def _dotfile_compare(o, dotfile, tmp):
     asrc = os.path.join(o.dotpath, os.path.expanduser(src))
     adst = os.path.expanduser(dotfile.dst)
     if os.path.samefile(asrc, adst):
-        if o.debug:
-            line = '=> compare {}: diffing with \"{}\"'
-            LOG.dbg(line.format(dotfile.key, dotfile.dst))
-            LOG.dbg('points to itself')
+        line = '=> compare {}: diffing with \"{}\"'
+        LOG.dbg(line.format(dotfile.key, dotfile.dst))
+        LOG.dbg('points to itself')
         return True
 
     ignores = list(set(o.compare_ignore + dotfile.cmpignore))
@@ -179,10 +174,9 @@ def _dotfile_compare(o, dotfile, tmp):
             LOG.emph(diff)
         return False
     # no difference
-    if o.debug:
-        line = '=> compare {}: diffing with \"{}\"'
-        LOG.dbg(line.format(dotfile.key, dotfile.dst))
-        LOG.dbg('same file')
+    line = '=> compare {}: diffing with \"{}\"'
+    LOG.dbg(line.format(dotfile.key, dotfile.dst))
+    LOG.dbg('same file')
     return True
 
 
@@ -208,9 +202,8 @@ def _dotfile_install(o, dotfile, tmpdir=None):
     pre_actions_exec = action_executor(o, preactions, defactions,
                                        t, post=False)
 
-    if o.debug:
-        LOG.dbg('installing dotfile: \"{}\"'.format(dotfile.key))
-        LOG.dbg(dotfile.prt())
+    LOG.dbg('installing dotfile: \"{}\"'.format(dotfile.key))
+    LOG.dbg(dotfile.prt())
 
     ignores = list(set(o.install_ignore + dotfile.instignore))
     ignores = patch_ignores(ignores, dotfile.dst, debug=o.debug)
@@ -278,12 +271,10 @@ def _dotfile_install(o, dotfile, tmpdir=None):
         # dotfile was NOT installed
         if o.install_force_action:
             # pre-actions
-            if o.debug:
-                LOG.dbg('force pre action execution ...')
+            LOG.dbg('force pre action execution ...')
             pre_actions_exec()
             # post-actions
-            if o.debug:
-                LOG.dbg('force post action execution ...')
+            LOG.dbg('force post action execution ...')
             defactions = o.install_default_actions_post
             postactions = dotfile.get_post_actions()
             post_actions_exec = action_executor(o, postactions, defactions,
@@ -320,8 +311,7 @@ def cmd_install(o):
     installed = []
 
     # execute profile pre-action
-    if o.debug:
-        LOG.dbg('run {} profile pre actions'.format(len(pro_pre_actions)))
+    LOG.dbg('run {} profile pre actions'.format(len(pro_pre_actions)))
     t = _get_templater(o)
     ret, err = action_executor(o, pro_pre_actions, [], t, post=False)()
     if not ret:
@@ -330,8 +320,7 @@ def cmd_install(o):
     # install each dotfile
     if o.workers > 1:
         # in parallel
-        if o.debug:
-            LOG.dbg('run with {} workers'.format(o.workers))
+        LOG.dbg('run with {} workers'.format(o.workers))
         ex = futures.ThreadPoolExecutor(max_workers=o.workers)
 
         wait_for = []
@@ -359,15 +348,13 @@ def cmd_install(o):
 
     # execute profile post-action
     if len(installed) > 0 or o.install_force_action:
-        if o.debug:
-            msg = 'run {} profile post actions'
-            LOG.dbg(msg.format(len(pro_post_actions)))
+        msg = 'run {} profile post actions'
+        LOG.dbg(msg.format(len(pro_post_actions)))
         ret, err = action_executor(o, pro_post_actions, [], t, post=False)()
         if not ret:
             return False
 
-    if o.debug:
-        LOG.dbg('install done: installed \"{}\"'.format(','.join(installed)))
+    LOG.dbg('install done: installed \"{}\"'.format(','.join(installed)))
 
     if o.install_temporary:
         LOG.log('\ninstalled to tmp \"{}\".'.format(tmpdir))
@@ -396,8 +383,7 @@ def cmd_compare(o, tmp):
     cnt = 0
     if o.workers > 1:
         # in parallel
-        if o.debug:
-            LOG.dbg('run with {} workers'.format(o.workers))
+        LOG.dbg('run with {} workers'.format(o.workers))
         ex = futures.ThreadPoolExecutor(max_workers=o.workers)
         wait_for = []
         for dotfile in selected:
@@ -440,12 +426,10 @@ def cmd_update(o):
     if not paths:
         # update the entire profile
         if iskey:
-            if o.debug:
-                LOG.dbg('update by keys: {}'.format(paths))
+            LOG.dbg('update by keys: {}'.format(paths))
             paths = [d.key for d in o.dotfiles]
         else:
-            if o.debug:
-                LOG.dbg('update by paths: {}'.format(paths))
+            LOG.dbg('update by paths: {}'.format(paths))
             paths = [d.dst for d in o.dotfiles]
         msg = 'Update all dotfiles for profile \"{}\"'.format(o.profile)
         if o.safe and not LOG.ask(msg):
@@ -456,14 +440,12 @@ def cmd_update(o):
         LOG.log('\nno dotfile to update')
         return True
 
-    if o.debug:
-        LOG.dbg('dotfile to update: {}'.format(paths))
+    LOG.dbg('dotfile to update: {}'.format(paths))
 
     # update each dotfile
     if o.workers > 1:
         # in parallel
-        if o.debug:
-            LOG.dbg('run with {} workers'.format(o.workers))
+        LOG.dbg('run with {} workers'.format(o.workers))
         ex = futures.ThreadPoolExecutor(max_workers=o.workers)
         wait_for = []
         for path in paths:
@@ -581,8 +563,7 @@ def cmd_remove(o):
     if not paths:
         LOG.log('no dotfile to remove')
         return False
-    if o.debug:
-        LOG.dbg('dotfile(s) to remove: {}'.format(','.join(paths)))
+    LOG.dbg('dotfile(s) to remove: {}'.format(','.join(paths)))
 
     removed = []
     for key in paths:
@@ -608,8 +589,7 @@ def cmd_remove(o):
                 LOG.warn(msg.format(k))
                 continue
 
-            if o.debug:
-                LOG.dbg('removing {}'.format(key))
+            LOG.dbg('removing {}'.format(key))
 
             # make sure is part of the profile
             if dotfile.key not in [d.key for d in o.dotfiles]:
@@ -624,8 +604,7 @@ def cmd_remove(o):
             msg = 'Remove \"{}\" from all these profiles: {}'.format(k, pkeys)
             if o.safe and not LOG.ask(msg):
                 return False
-            if o.debug:
-                LOG.dbg('remove dotfile: {}'.format(dotfile))
+            LOG.dbg('remove dotfile: {}'.format(dotfile))
 
             for profile in profiles:
                 if not o.conf.del_dotfile_from_profile(dotfile, profile):
@@ -736,8 +715,7 @@ def apply_trans(dotpath, dotfile, templater, debug=False):
     src = dotfile.src
     new_src = '{}.{}'.format(src, TRANS_SUFFIX)
     trans = dotfile.trans_r
-    if debug:
-        LOG.dbg('executing transformation: {}'.format(trans))
+    LOG.dbg('executing transformation: {}'.format(trans))
     s = os.path.join(dotpath, src)
     temp = os.path.join(dotpath, new_src)
     if not trans.transform(s, temp, templater=templater, debug=debug):
@@ -774,6 +752,7 @@ def main():
         return False
 
     if o.debug:
+        LOG.debug = o.debug
         LOG.dbg('\n\n')
     options_time = time.time() - t0
 
@@ -785,29 +764,25 @@ def main():
         if o.cmd_profiles:
             # list existing profiles
             command = 'profiles'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             cmd_list_profiles(o)
 
         elif o.cmd_files:
             # list files for selected profile
             command = 'files'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             cmd_files(o)
 
         elif o.cmd_install:
             # install the dotfiles stored in dotdrop
             command = 'install'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             ret = cmd_install(o)
 
         elif o.cmd_compare:
             # compare local dotfiles with dotfiles stored in dotdrop
             command = 'compare'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             tmp = get_tmpdir()
             ret = cmd_compare(o, tmp)
             # clean tmp directory
@@ -816,29 +791,25 @@ def main():
         elif o.cmd_import:
             # import dotfile(s)
             command = 'import'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             ret = cmd_importer(o)
 
         elif o.cmd_update:
             # update a dotfile
             command = 'update'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             ret = cmd_update(o)
 
         elif o.cmd_detail:
             # detail files
             command = 'detail'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             cmd_detail(o)
 
         elif o.cmd_remove:
             # remove dotfile
             command = 'remove'
-            if o.debug:
-                LOG.dbg('running cmd: {}'.format(command))
+            LOG.dbg('running cmd: {}'.format(command))
             cmd_remove(o)
 
     except KeyboardInterrupt:
@@ -846,16 +817,14 @@ def main():
         ret = False
     cmd_time = time.time() - t0
 
-    if o.debug:
-        LOG.dbg('done executing command \"{}\"'.format(command))
-        LOG.dbg('options loaded in {}'.format(options_time))
-        LOG.dbg('command executed in {}'.format(cmd_time))
+    LOG.dbg('done executing command \"{}\"'.format(command))
+    LOG.dbg('options loaded in {}'.format(options_time))
+    LOG.dbg('command executed in {}'.format(cmd_time))
 
     if ret and o.conf.save():
         LOG.log('config file updated')
 
-    if o.debug:
-        LOG.dbg('return {}'.format(ret))
+    LOG.dbg('return {}'.format(ret))
     return ret
 
 
diff --git a/dotdrop/importer.py b/dotdrop/importer.py
index e1cd0c8..7b2edfa 100644
--- a/dotdrop/importer.py
+++ b/dotdrop/importer.py
@@ -46,7 +46,7 @@ class Importer:
         self.ignore = ignore
 
         self.umask = get_umask()
-        self.log = Logger()
+        self.log = Logger(debug=self.debug)
 
     def import_path(self, path, import_as=None,
                     import_link=LinkTypes.NOLINK, import_mode=False):
@@ -57,8 +57,7 @@ class Importer:
             0: ignored
             -1: error
         """
-        if self.debug:
-            self.log.dbg('import {}'.format(path))
+        self.log.dbg('import {}'.format(path))
         if not os.path.exists(path):
             self.log.err('\"{}\" does not exist, ignored!'.format(path))
             return -1
@@ -100,8 +99,7 @@ class Importer:
             src = src.rstrip(os.sep)
             src = os.path.abspath(src)
             src = strip_home(src)
-            if self.debug:
-                self.log.dbg('import src for {} as {}'.format(dst, src))
+            self.log.dbg('import src for {} as {}'.format(dst, src))
         # with or without dot prefix
         strip = '.' + os.sep
         if self.keepdot:
@@ -121,8 +119,7 @@ class Importer:
         if self._already_exists(src, dst):
             return -1
 
-        if self.debug:
-            self.log.dbg('import dotfile: src:{} dst:{}'.format(src, dst))
+        self.log.dbg('import dotfile: src:{} dst:{}'.format(src, dst))
 
         if not self._prepare_hierarchy(src, dst):
             return -1
@@ -140,12 +137,10 @@ class Importer:
         # handle file mode
         chmod = None
         dflperm = get_default_file_perms(dst, self.umask)
-        if self.debug:
-            self.log.dbg('import mode: {}'.format(import_mode))
+        self.log.dbg('import mode: {}'.format(import_mode))
         if import_mode or perm != dflperm:
-            if self.debug:
-                msg = 'adopt mode {:o} (umask {:o})'
-                self.log.dbg(msg.format(perm, dflperm))
+            msg = 'adopt mode {:o} (umask {:o})'
+            self.log.dbg(msg.format(perm, dflperm))
             chmod = perm
 
         # add file to config file
@@ -168,7 +163,7 @@ class Importer:
         if os.path.exists(srcf):
             if self.safe:
                 cmp = Comparator(debug=self.debug,
-                               diff_cmd=self.diff_cmd)
+                                 diff_cmd=self.diff_cmd)
                 diff = cmp.compare(srcf, dst)
                 if diff != '':
                     # files are different, dunno what to do
@@ -178,8 +173,7 @@ class Importer:
                     msg = 'Dotfile \"{}\" already exists, overwrite?'
                     if not self.log.ask(msg.format(srcf)):
                         return False
-                    if self.debug:
-                        self.log.dbg('will overwrite existing file')
+                    self.log.dbg('will overwrite existing file')
 
         # create directory hierarchy
         if self.dry:
@@ -241,8 +235,7 @@ class Importer:
 
     def _ignore(self, path):
         if must_ignore([path], self.ignore, debug=self.debug):
-            if self.debug:
-                self.log.dbg('ignoring import of {}'.format(path))
+            self.log.dbg('ignoring import of {}'.format(path))
             self.log.warn('{} ignored'.format(path))
             return True
         return False
diff --git a/dotdrop/installer.py b/dotdrop/installer.py
index 8b0c1a4..70c5a12 100644
--- a/dotdrop/installer.py
+++ b/dotdrop/installer.py
@@ -57,7 +57,7 @@ class Installer:
         # when using install_to_tmp for comparing
         self.comparing = False
 
-        self.log = Logger()
+        self.log = Logger(debug=self.debug)
 
     ########################################################
     # public methods
@@ -88,13 +88,11 @@ class Installer:
         """
         if not src or not dst:
             # fake dotfile
-            if self.debug:
-                self.log.dbg('fake dotfile installed')
+            self.log.dbg('fake dotfile installed')
             self._exec_pre_actions(actionexec)
             return True, None
-        if self.debug:
-            msg = 'installing \"{}\" to \"{}\" (link: {})'
-            self.log.dbg(msg.format(src, dst, str(linktype)))
+        msg = 'installing \"{}\" to \"{}\" (link: {})'
+        self.log.dbg(msg.format(src, dst, str(linktype)))
         src, dst, cont, err = self._check_paths(src, dst, chmod)
         if not cont:
             return self._log_install(cont, err)
@@ -116,9 +114,8 @@ class Installer:
             return self._log_install(r, err)
 
         isdir = os.path.isdir(src)
-        if self.debug:
-            self.log.dbg('install {} to {}'.format(src, dst))
-            self.log.dbg('\"{}\" is a directory: {}'.format(src, isdir))
+        self.log.dbg('install {} to {}'.format(src, dst))
+        self.log.dbg('\"{}\" is a directory: {}'.format(src, isdir))
 
         if linktype == LinkTypes.NOLINK:
             # normal file
@@ -142,9 +139,8 @@ class Installer:
         elif linktype == LinkTypes.LINK_CHILDREN:
             # symlink direct children
             if not isdir:
-                if self.debug:
-                    msg = 'symlink children of {} to {}'
-                    self.log.dbg(msg.format(src, dst))
+                msg = 'symlink children of {} to {}'
+                self.log.dbg(msg.format(src, dst))
                 err = 'source dotfile is not a directory: {}'.format(src)
                 r = False
             else:
@@ -153,8 +149,7 @@ class Installer:
                                              is_template=is_template,
                                              ignore=ignore)
 
-        if self.debug:
-            self.log.dbg('before chmod: {} err:{}'.format(r, err))
+        self.log.dbg('before chmod: {} err:{}'.format(r, err))
 
         if self.dry:
             return self._log_install(r, err)
@@ -202,8 +197,7 @@ class Installer:
         return
         - success, error-if-any, dotfile-installed-path
         """
-        if self.debug:
-            self.log.dbg('tmp install {} (defined dst: {})'.format(src, dst))
+        self.log.dbg('tmp install {} (defined dst: {})'.format(src, dst))
         src, dst, cont, err = self._check_paths(src, dst, chmod)
         if not cont:
             return self._log_install(cont, err)
@@ -228,9 +222,8 @@ class Installer:
                                 LinkTypes.NOLINK,
                                 is_template=is_template,
                                 chmod=chmod, ignore=ignore)
-        if self.debug:
-            if ret:
-                self.log.dbg('tmp installed in {}'.format(tmpdst))
+        if ret:
+            self.log.dbg('tmp installed in {}'.format(tmpdst))
 
         # restore flags
         self.dry = drysaved
@@ -257,9 +250,8 @@ class Installer:
         - False, 'aborted'    : user aborted
         """
         if is_template:
-            if self.debug:
-                self.log.dbg('is a template')
-                self.log.dbg('install to {}'.format(self.workdir))
+            self.log.dbg('is a template')
+            self.log.dbg('install to {}'.format(self.workdir))
             tmp = self._pivot_path(dst, self.workdir, striphome=True)
             r, err = self.install(templater, src, tmp,
                                   LinkTypes.NOLINK,
@@ -314,20 +306,17 @@ class Installer:
             subdst = dsts[i]
 
             if utils.must_ignore([subsrc, subdst], ignore, debug=self.debug):
-                if self.debug:
-                    self.log.dbg(
-                        'ignoring install of {} to {}'.format(src, dst),
-                    )
+                self.log.dbg(
+                    'ignoring install of {} to {}'.format(src, dst),
+                )
                 continue
 
-            if self.debug:
-                self.log.dbg('symlink child {} to {}'.format(subsrc, subdst))
+            self.log.dbg('symlink child {} to {}'.format(subsrc, subdst))
 
             if is_template:
-                if self.debug:
-                    self.log.dbg('child is a template')
-                    self.log.dbg('install to {} and symlink'
-                                 .format(self.workdir))
+                self.log.dbg('child is a template')
+                self.log.dbg('install to {} and symlink'
+                             .format(self.workdir))
                 tmp = self._pivot_path(subdst, self.workdir, striphome=True)
                 r, e = self.install(templater, subsrc, tmp,
                                     LinkTypes.NOLINK,
@@ -367,8 +356,7 @@ class Installer:
         if os.path.lexists(dst):
             if os.path.realpath(dst) == os.path.realpath(src):
                 msg = 'ignoring "{}", link already exists'.format(dst)
-                if self.debug:
-                    self.log.dbg(msg)
+                self.log.dbg(msg)
                 return False, None
             if self.dry:
                 self.log.dry('would remove {} and link to {}'.format(dst, src))
@@ -422,12 +410,11 @@ class Installer:
         - False, None       : ignored
         - False, 'aborted'    : user aborted
         """
-        if self.debug:
-            self.log.dbg('deploy file: {}'.format(src))
-            self.log.dbg('ignore empty: {}'.format(noempty))
-            self.log.dbg('ignore pattern: {}'.format(ignore))
-            self.log.dbg('is_template: {}'.format(is_template))
-            self.log.dbg('no empty: {}'.format(noempty))
+        self.log.dbg('deploy file: {}'.format(src))
+        self.log.dbg('ignore empty: {}'.format(noempty))
+        self.log.dbg('ignore pattern: {}'.format(ignore))
+        self.log.dbg('is_template: {}'.format(is_template))
+        self.log.dbg('no empty: {}'.format(noempty))
 
         # check no loop
         if utils.samefile(src, dst):
@@ -435,8 +422,7 @@ class Installer:
             return False, err
 
         if utils.must_ignore([src, dst], ignore, debug=self.debug):
-            if self.debug:
-                self.log.dbg('ignoring install of {} to {}'.format(src, dst))
+            self.log.dbg('ignoring install of {} to {}'.format(src, dst))
             return False, None
 
         if utils.samefile(src, dst):
@@ -461,8 +447,7 @@ class Installer:
                 templater.restore_vars(saved)
             # test is empty
             if noempty and utils.content_empty(content):
-                if self.debug:
-                    self.log.dbg('ignoring empty template: {}'.format(src))
+                self.log.dbg('ignoring empty template: {}'.format(src))
                 return False, None
             if content is None:
                 err = 'empty template {}'.format(src)
@@ -490,8 +475,7 @@ class Installer:
         - False, None       : ignored
         - False, 'aborted'    : user aborted
         """
-        if self.debug:
-            self.log.dbg('deploy dir {}'.format(src))
+        self.log.dbg('deploy dir {}'.format(src))
         # default to nothing installed and no error
         ret = False, None
 
@@ -503,8 +487,7 @@ class Installer:
         # handle all files in dir
         for entry in os.listdir(src):
             f = os.path.join(src, entry)
-            if self.debug:
-                self.log.dbg('deploy sub from {}: {}'.format(dst, entry))
+            self.log.dbg('deploy sub from {}: {}'.format(dst, entry))
             if not os.path.isdir(f):
                 # is file
                 res, err = self._copy_file(templater, f,
@@ -566,12 +549,10 @@ class Installer:
 
             if self.diff:
                 if not self._is_different(src, dst, content=content):
-                    if self.debug:
-                        self.log.dbg('{} is the same'.format(dst))
+                    self.log.dbg('{} is the same'.format(dst))
                     return False, None
             if self.safe:
-                if self.debug:
-                    self.log.dbg('change detected for {}'.format(dst))
+                self.log.dbg('change detected for {}'.format(dst))
                 if self.showdiff:
                     # get diff
                     self._show_diff_before_write(src, dst,
@@ -588,8 +569,7 @@ class Installer:
         r, e = self._exec_pre_actions(actionexec)
         if not r:
             return False, e
-        if self.debug:
-            self.log.dbg('install file to \"{}\"'.format(dst))
+        self.log.dbg('install file to \"{}\"'.format(dst))
         # re-check in case action created the file
         if self.safe and not overwrite and os.path.lexists(dst):
             if not self.log.ask('Overwrite \"{}\"'.format(dst)):
@@ -637,8 +617,7 @@ class Installer:
             src = tmp
         r = utils.fastdiff(src, dst)
         if r:
-            if self.debug:
-                self.log.dbg('content differ')
+            self.log.dbg('content differ')
         return r
 
     def _show_diff_before_write(self, src, dst, content=None):
@@ -668,16 +647,14 @@ class Installer:
     def _create_dirs(self, directory):
         """mkdir -p <directory>"""
         if not self.create and not os.path.exists(directory):
-            if self.debug:
-                self.log.dbg('no mkdir as \"create\" set to false in config')
+            self.log.dbg('no mkdir as \"create\" set to false in config')
             return False
         if os.path.exists(directory):
             return True
         if self.dry:
             self.log.dry('would mkdir -p {}'.format(directory))
             return True
-        if self.debug:
-            self.log.dbg('mkdir -p {}'.format(directory))
+        self.log.dbg('mkdir -p {}'.format(directory))
         if not self.comparing:
             self.log.sub('create directory {}'.format(directory))
 
@@ -694,15 +671,13 @@ class Installer:
 
     def _pivot_path(self, path, newdir, striphome=False):
         """change path to be under newdir"""
-        if self.debug:
-            self.log.dbg('pivot new dir: \"{}\"'.format(newdir))
-            self.log.dbg('strip home: {}'.format(striphome))
+        self.log.dbg('pivot new dir: \"{}\"'.format(newdir))
+        self.log.dbg('strip home: {}'.format(striphome))
         if striphome:
             path = utils.strip_home(path)
         sub = path.lstrip(os.sep)
         new = os.path.join(newdir, sub)
-        if self.debug:
-            self.log.dbg('pivot \"{}\" to \"{}\"'.format(path, new))
+        self.log.dbg('pivot \"{}\" to \"{}\"'.format(path, new))
         return new
 
     def _exec_pre_actions(self, actionexec):
@@ -736,8 +711,7 @@ class Installer:
         # check both path are valid
         if not dst or not src:
             err = 'empty dst or src for {}'.format(src)
-            if self.debug:
-                self.log.dbg(err)
+            self.log.dbg(err)
             return None, None, False, err
 
         # normalize src and dst
diff --git a/dotdrop/logger.py b/dotdrop/logger.py
index 8f23622..581cccf 100644
--- a/dotdrop/logger.py
+++ b/dotdrop/logger.py
@@ -21,8 +21,8 @@ class Logger:
     EMPH = '\033[33m'
     BOLD = '\033[1m'
 
-    def __init__(self):
-        pass
+    def __init__(self, debug=False):
+        self.debug = debug
 
     def log(self, string, end='\n', pre='', bold=False):
         cs = self._color(self.BLUE)
@@ -57,7 +57,9 @@ class Logger:
         ce = self._color(self.RESET)
         sys.stderr.write('{}[WARN] {} {}{}'.format(cs, string, end, ce))
 
-    def dbg(self, string):
+    def dbg(self, string, force=False):
+        if not force and not self.debug:
+            return
         frame = inspect.stack()[1]
         mod = inspect.getmodule(frame[0]).__name__
         func = inspect.stack()[1][3]
diff --git a/dotdrop/options.py b/dotdrop/options.py
index 6a21233..5689cd9 100644
--- a/dotdrop/options.py
+++ b/dotdrop/options.py
@@ -121,8 +121,8 @@ class Options(AttrMonitor):
             self.args = docopt(USAGE, version=VERSION)
         if args:
             self.args = args.copy()
-        self.log = Logger()
         self.debug = self.args['--verbose'] or ENV_DEBUG in os.environ
+        self.log = Logger(debug=self.debug)
         self.dry = self.args['--dry']
         if ENV_NODEBUG in os.environ:
             # force disabling debugs
@@ -131,13 +131,12 @@ class Options(AttrMonitor):
         self.confpath = self._get_config_path()
         if not self.confpath:
             raise YamlException('no config file found')
-        if self.debug:
-            self.log.dbg('#################################################')
-            self.log.dbg('#################### DOTDROP ####################')
-            self.log.dbg('#################################################')
-            self.log.dbg('version: {}'.format(VERSION))
-            self.log.dbg('command: {}'.format(' '.join(sys.argv)))
-            self.log.dbg('config file: {}'.format(self.confpath))
+        self.log.dbg('#################################################')
+        self.log.dbg('#################### DOTDROP ####################')
+        self.log.dbg('#################################################')
+        self.log.dbg('version: {}'.format(VERSION))
+        self.log.dbg('command: {}'.format(' '.join(sys.argv)))
+        self.log.dbg('config file: {}'.format(self.confpath))
 
         self._read_config()
         self._apply_args()
diff --git a/dotdrop/templategen.py b/dotdrop/templategen.py
index 58cb2d8..23dd33d 100644
--- a/dotdrop/templategen.py
+++ b/dotdrop/templategen.py
@@ -42,7 +42,7 @@ class Templategen:
         """
         self.base = base.rstrip(os.sep)
         self.debug = debug
-        self.log = Logger()
+        self.log = Logger(debug=self.debug)
         self.variables = {}
         loader1 = FileSystemLoader(self.base)
         loader2 = FunctionLoader(self._template_loader)
@@ -66,18 +66,15 @@ class Templategen:
         # adding header method
         self.env.globals['header'] = self._header
         # adding helper methods
-        if self.debug:
-            self.log.dbg('load global functions:')
+        self.log.dbg('load global functions:')
         self._load_funcs_to_dic(jhelpers, self.env.globals)
         if func_file:
             for f in func_file:
-                if self.debug:
-                    self.log.dbg('load custom functions from {}'.format(f))
+                self.log.dbg('load custom functions from {}'.format(f))
                 self._load_path_to_dic(f, self.env.globals)
         if filter_file:
             for f in filter_file:
-                if self.debug:
-                    self.log.dbg('load custom filters from {}'.format(f))
+                self.log.dbg('load custom filters from {}'.format(f))
                 self._load_path_to_dic(f, self.env.filters)
         if self.debug:
             self._debug_dict('template additional variables', variables)
@@ -139,8 +136,7 @@ class Templategen:
             return
         funcs = utils.get_module_functions(mod)
         for name, func in funcs:
-            if self.debug:
-                self.log.dbg('load function \"{}\"'.format(name))
+            self.log.dbg('load function \"{}\"'.format(name))
             dic[name] = func
 
     def _header(self, prepend=''):
@@ -152,20 +148,16 @@ class Templategen:
         try:
             import magic
             filetype = magic.from_file(src, mime=True)
-            if self.debug:
-                self.log.dbg('using \"magic\" for filetype identification')
+            self.log.dbg('using \"magic\" for filetype identification')
         except ImportError:
             # fallback
             _, filetype = utils.run(['file', '-b', '--mime-type', src],
                                     debug=self.debug)
-            if self.debug:
-                self.log.dbg('using \"file\" for filetype identification')
+            self.log.dbg('using \"file\" for filetype identification')
             filetype = filetype.strip()
         istext = self._is_text(filetype)
-        if self.debug:
-            self.log.dbg('filetype \"{}\": {}'.format(src, filetype))
-        if self.debug:
-            self.log.dbg('is text \"{}\": {}'.format(src, istext))
+        self.log.dbg('filetype \"{}\": {}'.format(src, filetype))
+        self.log.dbg('is text \"{}\": {}'.format(src, istext))
         if not istext:
             return self._handle_bin_file(src)
         return self._handle_text_file(src)
diff --git a/dotdrop/updater.py b/dotdrop/updater.py
index 3c8ff34..c8dc273 100644
--- a/dotdrop/updater.py
+++ b/dotdrop/updater.py
@@ -52,7 +52,7 @@ class Updater:
                                      debug=self.debug)
         # save template vars
         self.tvars = self.templater.add_tmp_vars()
-        self.log = Logger()
+        self.log = Logger(debug=self.debug)
 
     def update_path(self, path):
         """update the dotfile installed on path"""
@@ -69,9 +69,8 @@ class Updater:
                 self.log.err(msg.format(dotfile.key))
                 return False
 
-            if self.debug:
-                msg = 'updating {} from path \"{}\"'
-                self.log.dbg(msg.format(dotfile, path))
+            msg = 'updating {} from path \"{}\"'
+            self.log.dbg(msg.format(dotfile, path))
             if not self._update(path, dotfile):
                 return False
         return True
@@ -81,8 +80,7 @@ class Updater:
         dotfile = self.conf.get_dotfile(key)
         if not dotfile:
             return False
-        if self.debug:
-            self.log.dbg('updating {} from key \"{}\"'.format(dotfile, key))
+        self.log.dbg('updating {} from key \"{}\"'.format(dotfile, key))
         path = self.conf.path_to_dotfile_dst(dotfile.dst)
         return self._update(path, dotfile)
 
@@ -92,8 +90,7 @@ class Updater:
         new_path = None
         ignores = list(set(self.ignore + dotfile.upignore))
         self.ignores = patch_ignores(ignores, dotfile.dst, debug=self.debug)
-        if self.debug:
-            self.log.dbg('ignore pattern(s): {}'.format(self.ignores))
+        self.log.dbg('ignore pattern(s): {}'.format(self.ignores))
 
         deployed_path = os.path.expanduser(path)
         local_path = os.path.join(self.dotpath, dotfile.src)
@@ -132,9 +129,8 @@ class Updater:
 
         if deployed_mode != local_mode:
             # mirror rights
-            if self.debug:
-                m = 'adopt mode {:o} for {}'
-                self.log.dbg(m.format(deployed_mode, dotfile.key))
+            m = 'adopt mode {:o} for {}'
+            self.log.dbg(m.format(deployed_mode, dotfile.key))
             r = self.conf.update_dotfile(dotfile.key, deployed_mode)
             if r:
                 ret = True
@@ -149,8 +145,7 @@ class Updater:
         trans = dotfile.get_trans_w()
         if not trans:
             return path
-        if self.debug:
-            self.log.dbg('executing write transformation {}'.format(trans))
+        self.log.dbg('executing write transformation {}'.format(trans))
         tmp = get_unique_tmp_name()
         self.templater.restore_vars(self.tvars)
         newvars = dotfile.get_dotfile_variables()
@@ -166,8 +161,7 @@ class Updater:
 
     def _is_template(self, path):
         if not Templategen.is_template(path, ignore=self.ignores):
-            if self.debug:
-                self.log.dbg('{} is NO template'.format(path))
+            self.log.dbg('{} is NO template'.format(path))
             return False
         self.log.warn('{} uses template, update manually'.format(path))
         return True
@@ -201,9 +195,8 @@ class Updater:
         dstr = get_file_perm(dst)
         if srcr == dstr:
             return
-        if self.debug:
-            msg = 'copy rights from {} ({:o}) to {} ({:o})'
-            self.log.dbg(msg.format(src, srcr, dst, dstr))
+        msg = 'copy rights from {} ({:o}) to {} ({:o})'
+        self.log.dbg(msg.format(src, srcr, dst, dstr))
         try:
             mirror_file_rights(src, dst)
         except OSError as e:
@@ -214,15 +207,13 @@ class Updater:
         if self._ignore([deployed_path, local_path]):
             self.log.sub('\"{}\" ignored'.format(local_path))
             return True
-        if self.debug:
-            self.log.dbg('update for file {} and {}'.format(
-                deployed_path,
-                local_path,
-            ))
+        self.log.dbg('update for file {} and {}'.format(
+            deployed_path,
+            local_path,
+        ))
         if self._is_template(local_path):
             # dotfile is a template
-            if self.debug:
-                self.log.dbg('{} is a template'.format(local_path))
+            self.log.dbg('{} is a template'.format(local_path))
             if self.showpatch:
                 try:
                     self._show_patch(deployed_path, local_path)
@@ -237,11 +228,10 @@ class Updater:
                 filecmp.cmp(deployed_path, local_path, shallow=False) and \
                 self._same_rights(deployed_path, local_path):
             # no difference
-            if self.debug:
-                self.log.dbg('identical files: {} and {}'.format(
-                    deployed_path,
-                    local_path,
-                ))
+            self.log.dbg('identical files: {} and {}'.format(
+                deployed_path,
+                local_path,
+            ))
             return True
         if not self._overwrite(deployed_path, local_path):
             return False
@@ -252,8 +242,7 @@ class Updater:
                     local_path,
                 ))
             else:
-                if self.debug:
-                    self.log.dbg('cp {} {}'.format(deployed_path, local_path))
+                self.log.dbg('cp {} {}'.format(deployed_path, local_path))
                 shutil.copyfile(deployed_path, local_path)
                 self._mirror_rights(deployed_path, local_path)
                 self.log.sub('\"{}\" updated'.format(local_path))
@@ -267,11 +256,10 @@ class Updater:
 
     def _handle_dir(self, deployed_path, local_path, dotfile):
         """sync path (local dir) and local_path (dotdrop dir path)"""
-        if self.debug:
-            self.log.dbg('handle update for dir {} to {}'.format(
-                deployed_path,
-                local_path,
-            ))
+        self.log.dbg('handle update for dir {} to {}'.format(
+            deployed_path,
+            local_path,
+        ))
         # paths must be absolute (no tildes)
         deployed_path = os.path.expanduser(deployed_path)
         local_path = os.path.expanduser(local_path)
@@ -289,8 +277,7 @@ class Updater:
     def _merge_dirs(self, diff, dotfile):
         """Synchronize directories recursively."""
         left, right = diff.left, diff.right
-        if self.debug:
-            self.log.dbg('sync dir {} to {}'.format(left, right))
+        self.log.dbg('sync dir {} to {}'.format(left, right))
         if self._ignore([left, right]):
             return True
 
@@ -312,8 +299,7 @@ class Updater:
             if self.dry:
                 self.log.dry('would cp -r {} {}'.format(exist, new))
                 continue
-            if self.debug:
-                self.log.dbg('cp -r {} {}'.format(exist, new))
+            self.log.dbg('cp -r {} {}'.format(exist, new))
 
             # Newly created directory should be copied as is (for efficiency).
             def ig(src, names):
@@ -349,8 +335,7 @@ class Updater:
             if self.dry:
                 self.log.dry('would rm -r {}'.format(old))
                 continue
-            if self.debug:
-                self.log.dbg('rm -r {}'.format(old))
+            self.log.dbg('rm -r {}'.format(old))
             if not self._confirm_rm_r(old):
                 continue
             removepath(old, logger=self.log)
@@ -370,8 +355,7 @@ class Updater:
             if self.dry:
                 self.log.dry('would cp {} {}'.format(fleft, fright))
                 continue
-            if self.debug:
-                self.log.dbg('cp {} {}'.format(fleft, fright))
+            self.log.dbg('cp {} {}'.format(fleft, fright))
             self._handle_file(fleft, fright, dotfile, compare=False)
 
         # copy files that don't exist in dotdrop
@@ -387,8 +371,7 @@ class Updater:
             if self.dry:
                 self.log.dry('would cp {} {}'.format(exist, new))
                 continue
-            if self.debug:
-                self.log.dbg('cp {} {}'.format(exist, new))
+            self.log.dbg('cp {} {}'.format(exist, new))
             try:
                 shutil.copyfile(exist, new)
             except OSError as e:
@@ -412,8 +395,7 @@ class Updater:
             if self.dry:
                 self.log.dry('would rm {}'.format(new))
                 continue
-            if self.debug:
-                self.log.dbg('rm {}'.format(new))
+            self.log.dbg('rm {}'.format(new))
             removepath(new, logger=self.log)
             self.log.sub('\"{}\" removed'.format(new))
 
@@ -447,7 +429,6 @@ class Updater:
 
     def _ignore(self, paths):
         if must_ignore(paths, self.ignores, debug=self.debug):
-            if self.debug:
-                self.log.dbg('ignoring update for {}'.format(paths))
+            self.log.dbg('ignoring update for {}'.format(paths))
             return True
         return False
diff --git a/dotdrop/utils.py b/dotdrop/utils.py
index 9189cda..435e474 100644
--- a/dotdrop/utils.py
+++ b/dotdrop/utils.py
@@ -37,7 +37,7 @@ NOREMOVE = [os.path.normpath(p) for p in DONOTDELETE]
 def run(cmd, debug=False):
     """run a command (expects a list)"""
     if debug:
-        LOG.dbg('exec: {}'.format(' '.join(cmd)))
+        LOG.dbg('exec: {}'.format(' '.join(cmd)), force=True)
     p = subprocess.Popen(cmd, shell=False,
                          stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
     out, _ = p.communicate()
@@ -61,10 +61,10 @@ def shell(cmd, debug=False):
     returns True|False, output
     """
     if debug:
-        LOG.dbg('shell exec: \"{}\"'.format(cmd))
+        LOG.dbg('shell exec: \"{}\"'.format(cmd), force=True)
     ret, out = subprocess.getstatusoutput(cmd)
     if debug:
-        LOG.dbg('shell result ({}): {}'.format(ret, out))
+        LOG.dbg('shell result ({}): {}'.format(ret, out), force=True)
     return ret == 0, out
 
 
@@ -203,7 +203,8 @@ def must_ignore(paths, ignores, debug=False):
     if not ignores:
         return False
     if debug:
-        LOG.dbg('must ignore? \"{}\" against {}'.format(paths, ignores))
+        LOG.dbg('must ignore? \"{}\" against {}'.format(paths, ignores),
+                force=True)
     ignored_negative, ignored = categorize(
         lambda ign: ign.startswith('!'), ignores)
     for p in paths:
@@ -212,7 +213,7 @@ def must_ignore(paths, ignores, debug=False):
         for i in ignored:
             if fnmatch.fnmatch(p, i):
                 if debug:
-                    LOG.dbg('ignore \"{}\" match: {}'.format(i, p))
+                    LOG.dbg('ignore \"{}\" match: {}'.format(i, p), force=True)
                 ignore_matches.append(p)
         # Then remove any matches that actually shouldn't be ignored
         for ni in ignored_negative:
@@ -220,7 +221,8 @@ def must_ignore(paths, ignores, debug=False):
             ni = ni[1:]
             if fnmatch.fnmatch(p, ni):
                 if debug:
-                    LOG.dbg('negative ignore \"{}\" match: {}'.format(ni, p))
+                    LOG.dbg('negative ignore \"{}\" match: {}'.format(ni, p),
+                            force=True)
                 try:
                     ignore_matches.remove(p)
                 except ValueError:
@@ -232,7 +234,7 @@ def must_ignore(paths, ignores, debug=False):
         if ignore_matches:
             return True
     if debug:
-        LOG.dbg('NOT ignoring {}'.format(paths))
+        LOG.dbg('NOT ignoring {}'.format(paths), force=True)
     return False
 
 
@@ -249,7 +251,7 @@ def patch_ignores(ignores, prefix, debug=False):
     """allow relative ignore pattern"""
     new = []
     if debug:
-        LOG.dbg('ignores before patching: {}'.format(ignores))
+        LOG.dbg('ignores before patching: {}'.format(ignores), force=True)
     for ignore in ignores:
         negative = ignore.startswith('!')
         if negative:
@@ -277,7 +279,7 @@ def patch_ignores(ignores, prefix, debug=False):
         else:
             new.append(path)
     if debug:
-        LOG.dbg('ignores after patching: {}'.format(new))
+        LOG.dbg('ignores after patching: {}'.format(new), force=True)
     return new
 
 
@@ -375,7 +377,7 @@ def get_file_perm(path):
 
 def chmod(path, mode, debug=False):
     if debug:
-        LOG.dbg('chmod {} {}'.format(oct(mode), path))
+        LOG.dbg('chmod {} {}'.format(oct(mode), path), force=True)
     os.chmod(path, mode)
     return get_file_perm(path) == mode