Fixes #144.

run.bat

@@ -7,4 +7,4 @@ if "%NOMYPY%" == "" (
 ) else (
 	python setup.py clean build test
 )
-coverage run --branch --debug=sys --source=sos sos/tests.py && coverage html && coverage annotate sos/tests.py
+coverage run --branch --debug=sys --source=sos sos/tests.py --verbose && coverage html && coverage annotate sos/tests.py

run.sh

@@ -7,4 +7,4 @@ then
 else
 	python setup.py clean build test
 fi
-coverage run --branch --debug=sys --source=sos sos/tests.py && coverage html && coverage annotate sos/tests.py
+coverage run --branch --debug=sys --source=sos sos/tests.py --verbose && coverage html && coverage annotate sos/tests.py

setup.py

@@ -15,7 +15,7 @@
   if "--mypy" in sys.argv:
     try: shutil.rmtree(".mypy_cache/")
     except: pass
-  assert 0 == os.system("coconut%s %s %s -l -t 3.4 sos%s" % (cmd, "-p" if not "--mypy" in sys.argv else "", "--force" if "--force" in sys.argv else "", " --mypy --ignore-missing-imports --warn-incomplete-stub --warn-redundant-casts --warn-unused-ignores" if "--mypy" in sys.argv else ""))  #  or useChanges
+  assert 0 == os.system("coconut%s %s %s -l -t 3.4 sos%s" % (cmd, "-p" if not "--mypy" in sys.argv else "", "--force" if "--force" in sys.argv else "", " --mypy --ignore-missing-imports --warn-incomplete-stub --warn-redundant-casts" if "--mypy" in sys.argv else ""))  #  or useChanges
   if "--mypy" in sys.argv:  sys.argv.remove('--mypy')
   if "--force" in sys.argv: sys.argv.remove('--force')
 

sos/sos.coco

@@ -154,7 +154,7 @@ class Metadata:
         full: always create full branch copy, don't use a parent reference
         _.branch: current branch
     '''
-    debug("Duplicating branch '%s' to '%s'..." % (_.branches[_.branch].name ?? ("b%d" % _.branch), (name ?? "b%d" % branch)))
+    if verbose: info("Duplicating branch '%s' to '%s'..." % (_.branches[_.branch].name ?? ("b%d" % _.branch), (name ?? "b%d" % branch)))
     now:int = int(time.time() * 1000)
     _.loadBranch(_.branch)  # load commits for current (originating) branch
     revision:int = max(_.commits)
@@ -184,7 +184,7 @@ class Metadata:
     simpleMode = not (_.track or _.picky)
     tracked:List[str] =  [t for t in _.branches[_.branch].tracked]   if _.track and len(_.branches) > 0 else []  # in case of initial branch creation
     untracked:List[str] = [t for t in _.branches[_.branch].untracked] if _.track and len(_.branches) > 0 else []
-    debug("Creating branch '%s'..." % name ?? "b%d" % branch)
+    if verbose: info("Creating branch '%s'..." % name ?? "b%d" % branch)
     _.paths:Dict[str, PathInfo] = {}
     if simpleMode:  # branches from file system state
       changed, msg = _.findChanges(branch, 0, progress = simpleMode)  # creates revision folder and versioned files
@@ -320,7 +320,7 @@ class Metadata:
         changed.deletions[pth] = _.paths[pth]
     changed = dataCopy(ChangeSet, changed, moves = detectMoves(changed))
     if progress: printo("\r" + " " * termWidth + "\r", nl = "")  # forces clean line of progress output
-    else: debug("Finished detecting changes")
+    elif verbose: info("Finished detecting changes")
     tt:float = time.time() - start_time; speed:float = (original / (KIBI * tt)) if tt > 0. else 0.
     msg:str = (("Compression advantage is %.1f%%" % (original * 100. / compressed - 100.)) if _.compress and write and compressed > 0 else "")
     msg = (msg + " | " if msg else "") + ("Transfer speed was %.2f %siB/s." % (speed if speed < 1500. else speed / KIBI, "k" if speed < 1500. else "M") if original > 0 and tt > 0. else "")
@@ -444,15 +444,15 @@ def offline(name:str? = None, initialMessage:str? = None, options:str[] = []):
   if '--picky'    in options or m.c.picky:    m.picky =    True   # Git-like
   elif '--track'  in options or m.c.track:    m.track =    True   # Svn-like
   if '--strict'   in options or m.c.strict:   m.strict =   True   # always hash contents
-  debug(MARKER + "Going offline...")
+  if verbose: info(MARKER + "Going offline...")
   m.createBranch(0, name ?? defaults["defaultbranch"], initialMessage ?? "Offline repository created on %s" % strftime())  # main branch's name may be None (e.g. for fossil)
   m.branch = 0
   m.saveBranches(also = {"version": version.__version__})  # stores version info only once. no change immediately after going offline, going back online won't issue a warning
   info(MARKER + "Offline repository prepared. Use 'sos online' to finish offline work")
 
 def online(options:str[] = []):
   ''' Finish working offline. '''
-  debug(MARKER + "Going back online...")
+  if verbose: info(MARKER + "Going back online...")
   force:bool = '--force' in options
   m:Metadata = Metadata()
   strict:bool = '--strict' in options or m.strict
@@ -484,7 +484,7 @@ def branch(name:str? = None, initialMessage:str? = None, options:str[] = []):
   maxi:int = max(m.commits) if m.commits else m.branches[m.branch].revision
   if name and m.getBranchByName(name) is not None: Exit("Branch '%s' already exists. Cannot proceed" % name)  # attempted to create a named branch
   branch = max(m.branches.keys()) + 1  # next branch's key - this isn't atomic but we assume single-user non-concurrent use here
-  debug(MARKER + "Branching to %sbranch b%02d%s%s..." % ("unnamed " if name is None else "", branch, " '%s'" % name if name is not None else "", " from last revision" if last else ""))
+  if verbose: info(MARKER + "Branching to %sbranch b%02d%s%s..." % ("unnamed " if name is None else "", branch, " '%s'" % name if name is not None else "", " from last revision" if last else ""))
   if last: m.duplicateBranch(branch, name, (initialMessage + " " if initialMessage else "") + "(Branched from r%02d/b%02d)" % (m.branch, maxi), not fast)  # branch from last revision
   else: m.createBranch(branch, name, initialMessage ?? "Branched from file tree after r%02d/b%02d" % (m.branch, maxi))  # branch from current file tree state
   if not stay: m.branch = branch
@@ -500,7 +500,7 @@ def changes(argument:str? = None, options:str[] = [], onlys:FrozenSet[str]? = No
   m.loadBranch(branch)  # knows commits
   revision = m.branches[branch].revision if not m.commits else (revision if revision >= 0 else max(m.commits) + 1 + revision)  # negative indexing
   if revision < 0 or (m.commits and revision > max(m.commits)): Exit("Unknown revision r%02d" % revision)
-  debug(MARKER + "Changes of file tree vs. revision '%s/r%02d'" % (m.branches[branch].name ?? "b%02d" % branch, revision))
+  if verbose: info(MARKER + "Changes of file tree vs. revision '%s/r%02d'" % (m.branches[branch].name ?? "b%02d" % branch, revision))
   m.computeSequentialPathSet(branch, revision)  # load all commits up to specified revision
   changed, msg = m.findChanges(
     checkContent = strict,
@@ -548,7 +548,7 @@ def diff(argument:str = "", options:str[] = [], onlys:FrozenSet[str]? = None, ex
   m.loadBranch(branch)  # knows commits
   revision = m.branches[branch].revision if not m.commits else (revision if revision >= 0 else max(m.commits) + 1 + revision)  # negative indexing
   if revision < 0 or (m.commits and revision > max(m.commits)): Exit("Unknown revision r%02d" % revision)
-  debug(MARKER + "Textual differences of file tree vs. revision '%s/r%02d'" % (m.branches[branch].name ?? "b%02d" % branch, revision))
+  if verbose: info(MARKER + "Textual differences of file tree vs. revision '%s/r%02d'" % (m.branches[branch].name ?? "b%02d" % branch, revision))
   m.computeSequentialPathSet(branch, revision)  # load all commits up to specified revision
   changed, msg = m.findChanges(
     checkContent = strict, inverse = True,
@@ -564,7 +564,7 @@ def commit(argument:str? = None, options:str[] = [], onlys:FrozenSet[str]? = Non
   trackingPatterns:FrozenSet[str] = m.getTrackingPatterns()  # SVN-like mode
   # No untracking patterns needed here
   if m.picky and not trackingPatterns: Exit("No file patterns staged for commit in picky mode")
-  debug(MARKER + "Committing changes to branch '%s'..." % m.branches[m.branch].name ?? "b%d" % m.branch)
+  if verbose: info(MARKER + "Committing changes to branch '%s'..." % m.branches[m.branch].name ?? "b%d" % m.branch)
   m, branch, revision, changed, strict, force, trackingPatterns, untrackingPatterns = exitOnChanges(None, options, check = False, commit = True, onlys = onlys, excps = excps)  # special flag creates new revision for detected changes, but aborts if no changes
   changed = dataCopy(ChangeSet, changed, moves = detectMoves(changed))
   m.paths = {k: v for k, v in changed.additions.items()}  # copy to avoid wrong file numbers report below
@@ -685,7 +685,7 @@ def switch(argument:str, options:List[str] = [], onlys:FrozenSet[str]? = None, e
       if a in todos.deletions and pinfo.size == todos.deletions[a].size and (pinfo.hash == todos.deletions[a].hash if m.strict else pinfo.mtime == todos.deletions[a].mtime): rms.append(a)
     for rm in rms: del changed.additions[rm]  # TODO could also silently accept remote DEL for local ADD
     if modified(changed) and not force: m.listChanges(changed); Exit("File tree contains changes. Use --force to proceed")
-    debug(MARKER + "Switching to branch %sb%02d/r%02d..." % ("'%s' " % m.branches[branch].name if m.branches[branch].name else "", branch, revision))
+    if verbose: info(MARKER + "Switching to branch %sb%02d/r%02d..." % ("'%s' " % m.branches[branch].name if m.branches[branch].name else "", branch, revision))
     if not modified(todos):
       info("No changes to current file tree")
     else:  # integration required
@@ -714,7 +714,7 @@ def update(argument:str, options:str[] = [], onlys:FrozenSet[str]? = None, excps
   m:Metadata = Metadata()  # TODO same is called inside stop on changes - could return both current and designated branch instead
   currentBranch:int? = m.branch
   m, branch, revision, changes, strict, force, trackingPatterns, untrackingPatterns = exitOnChanges(argument, options, check = False, onlys = onlys, excps = excps)  # don't check for current changes, only parse arguments
-  debug(MARKER + "Integrating changes from '%s/r%02d' into file tree..." % (m.branches[branch].name ?? "b%02d" % branch, revision))
+  if verbose: info(MARKER + "Integrating changes from '%s/r%02d' into file tree..." % (m.branches[branch].name ?? "b%02d" % branch, revision))
 
   # Determine file changes from other branch over current file tree
   m.computeSequentialPathSet(branch, revision)  # load all commits up to specified revision for branch to integrate
@@ -753,13 +753,13 @@ def update(argument:str, options:str[] = [], onlys:FrozenSet[str]? = None, excps
       elif op == "m":
         with open(encode(into), "rb") as fd: current:bytes = fd.read()  # TODO slurps current file
         file:bytes? = m.readOrCopyVersionedFile(branch, revision, pinfo.nameHash) if pinfo.size > 0 else b''  # parse lines
-        if current == file: debug("No difference to versioned file")
+        if current == file and verbose: info("No difference to versioned file")
         elif file is not None:  # if None, error message was already logged
           merged:bytes; nl:bytes
           merged, nl = merge(file = file, into = current, mergeOperation = mrgline, charMergeOperation = mrgchar, eol = eol)
           if merged != current:
             with open(encode(path), "wb") as fd: fd.write(merged)  # TODO write to temp file first, in case writing fails
-          else: debug("No change")  # TODO but update timestamp?
+          elif verbose: info("No change")  # TODO but update timestamp?
       else:  # mine or wrong input
         printo("MNE " + path)  # nothing to do! same as skip
   info(MARKER + "Integrated changes from '%s/r%02d' into file tree" % (m.branches[branch].name ?? "b%02d" % branch, revision))
@@ -773,7 +773,7 @@ def destroy(argument:str, options:str[] = []):
   if len(m.branches) == 1: Exit("Cannot remove the only remaining branch. Use 'sos online' to leave offline mode")
   branch, revision = m.parseRevisionString(argument)  # not from exitOnChanges, because we have to set argument to None there
   if branch is None or branch not in m.branches: Exit("Cannot delete unknown branch %r" % branch)
-  debug(MARKER + "Removing branch b%02d%s..." % (branch, " '%s'" % (m.branches[branch].name ?? "")))
+  if verbose: info(MARKER + "Removing branch b%02d%s..." % (branch, " '%s'" % (m.branches[branch].name ?? "")))
   binfo = m.removeBranch(branch)  # need to keep a reference to removed entry for output below
   info(MARKER + "Branch b%02d%s removed" % (branch, " '%s'" % (binfo.name ?? "")))
 
@@ -814,7 +814,7 @@ def ls(folder:str? = None, options:str[] = []):
   recursive:bool = '--recursive' in options or '-r' in options or '--all' in options
   patterns:bool = '--patterns' in options or '-p' in options
   DOT:str = (DOT_SYMBOL if m.c.useUnicodeFont else " ") * 3
-  debug(MARKER + "Repository is in %s mode" % ("tracking" if m.track else ("picky" if m.picky else "simple")))
+  if verbose: info(MARKER + "Repository is in %s mode" % ("tracking" if m.track else ("picky" if m.picky else "simple")))
   relPath:str = relativize(m.root, os.path.join(folder, "-"))[0]
   if relPath.startswith(os.pardir): Exit("Cannot list contents of folder outside offline repository")
   trackingPatterns:FrozenSet[str]? = m.getTrackingPatterns() if m.track or m.picky else f{}  # for current branch
@@ -882,7 +882,7 @@ def log(options:str[] = []):
 
 def dump(argument:str, options:str[] = []):
   ''' Exported entire repository as archive for easy transfer. '''
-  debug(MARKER + "Dumping repository to archive...")
+  if verbose: info(MARKER + "Dumping repository to archive...")
   m:Metadata = Metadata()  # to load the configuration
   progress:bool = '--progress' in options
   delta:bool = '--full' not in options
@@ -896,12 +896,12 @@ def dump(argument:str, options:str[] = []):
   entries:List[str] = []
   if os.path.exists(encode(argument)) and not skipBackup:
     try:
-      debug("Creating backup...")
+      if verbose: info("Creating backup...")
       shutil.copy2(encode(argument), encode(argument + BACKUP_SUFFIX))
       if delta:
         with zipfile.ZipFile(argument, "r") as _zip: entries = _zip.namelist()  # list of pure relative paths without leading dot, normal slashes
     except Exception as E: Exit("Error creating backup copy before dumping. Please resolve and retry. %r" % E)
-  debug("Dumping revisions...")
+  if verbose: info("Dumping revisions...")
   if delta: warnings.filterwarnings('ignore', 'Duplicate name.*', UserWarning, "zipfile", 0)  # don't show duplicate entries warnings
   with zipfile.ZipFile(argument, "a" if delta else "w", compression) as _zip:  # create
     _zip.debug = 0  # suppress debugging output
@@ -985,7 +985,7 @@ def move(relPath:str, pattern:str, newRelPath:str, newPattern:str, options:List[
   ''' Path differs: Move files, create folder if not existing. Pattern differs: Attempt to rename file, unless exists in target or not unique.
       for "mvnot" don't do any renaming (or do?)
   '''
-  debug(MARKER + "Renaming %r to %r" % (pattern, newPattern))
+  if verbose: info(MARKER + "Renaming %r to %r" % (pattern, newPattern))
   force:bool = '--force' in options
   soft:bool = '--soft' in options
   if not os.path.exists(encode(relPath.replace(SLASH, os.sep))) and not force: Exit("Source folder doesn't exist. Use --force to proceed anyway")
@@ -1068,7 +1068,7 @@ def main():
   global debug, info, warn, error  # to modify logger
   logging.basicConfig(level = level, stream = sys.stderr, format = ("%(asctime)-23s %(levelname)-8s %(name)s:%(lineno)d | %(message)s" if '--log' in sys.argv else "%(message)s"))
   _log = Logger(logging.getLogger(__name__)); debug, info, warn, error = _log.debug, _log.info, _log.warn, _log.error
-  for option in (o for o in ['--log', '--verbose', '-v', '--sos'] if o in sys.argv): sys.argv.remove(option)  # clean up program arguments
+  for option in (o for o in ['--log', '--debug', '--verbose', '-v', '--sos', '--vcs'] if o in sys.argv): sys.argv.remove(option)  # clean up program arguments
   if '--help' in sys.argv or len(sys.argv) < 2: usage(APPNAME, version.__version__)
   command:str? = sys.argv[1] if len(sys.argv) > 1 else None
   root, vcs, cmd = findSosVcsBase()  # root is None if no .sos folder exists up the folder tree (still working online); vcs is checkout/repo root folder; cmd is the VCS base command
@@ -1097,9 +1097,10 @@ def main():
 
 
 # Main part
-verbose = os.environ.get("DEBUG", "False").lower() == "true" or '--verbose' in sys.argv or '-v' in sys.argv  # imported from utility, and only modified here
-level = logging.DEBUG if verbose else logging.INFO
 force_sos:bool = '--sos' in sys.argv
 force_vcs:bool = '--vcs' in sys.argv
+verbose:bool = '--verbose' in sys.argv or '-v' in sys.argv  # imported from utility, and only modified here
+debug_:bool = os.environ.get("DEBUG", "False").lower() == "true" or '--debug' in sys.argv
+level:int = logging.DEBUG if '--debug' in sys.argv else logging.INFO
 _log = Logger(logging.getLogger(__name__)); debug, info, warn, error = _log.debug, _log.info, _log.warn, _log.error
 if __name__ == '__main__': main()

sos/tests.coco

@@ -103,7 +103,6 @@ class Tests(unittest.TestCase):
   ''' Entire test suite. '''
 
   def setUp(_):
-    logging.getLogger().setLevel(logging.DEBUG)  # allowing to capture debug output
     sos.Metadata.singleton = None
     for entry in os.listdir(testFolder):  # cannot remove testFolder on Windows when using TortoiseSVN as VCS
       resource = os.path.join(testFolder, entry)
@@ -1054,8 +1053,8 @@ class Tests(unittest.TestCase):
   # TODO test wrong branch/revision after fast branching, would raise exception for -1 otherwise
 
 if __name__ == '__main__':
-  logging.basicConfig(level = logging.DEBUG if '-v' in sys.argv or "true" in [os.getenv("DEBUG", "false").strip().lower(), os.getenv("CI", "false").strip().lower()] else logging.INFO,
-    stream = sys.stderr, format = "%(asctime)-23s %(levelname)-8s %(name)s:%(lineno)d | %(message)s" if '-v' in sys.argv or os.getenv("DEBUG", "false") == "true" else "%(message)s")
+  logging.basicConfig(level = logging.DEBUG,
+    stream = sys.stderr, format = "%(asctime)-23s %(levelname)-8s %(name)s:%(lineno)d | %(message)s" if '--log' in sys.argv else "%(message)s")
   c = configr.Configr("sos"); c.loadSettings()
   if len(c.keys()) > 0: sos.Exit("Cannot run test suite with existing local SOS user configuration (would affect results)")
   unittest.main(testRunner = debugTestRunner() if '-v' in sys.argv and not os.getenv("CI", "false").lower() == "true" else None)  # warnings = "ignore")