config: resolve real paths from symlinks, add paths debug logging

Tweak test expectations to include the new debug logging.

Go through the paths in alphabetical order to get deterministic logging output,
so the test expectations always match.

Change-Id: I11a905b2467cda691d9ccea30ae436bac96476c9

selftest/resource_test.ok

@@ -9,6 +9,12 @@ The requested resource requirements are not solvable [[0, 2], [2], [0, 2]]
 ok, caused exception: RuntimeError('Refusing to drop a list of resources from itself. This is probably a bug where a list of Resources() should have been copied but is passed as-is. use Resources.clear() instead.',)
 - test removing a Resources list from one with the same list in it
 - test resources config and state dir:
+cnf -: DBG: Found config file paths.conf as [PATH]/selftest/conf/paths.conf in ./conf which is [PATH]/selftest/conf
+cnf -: DBG: [PATH]/selftest/conf/paths.conf: relative path ./test_work/state_dir is [PATH]/selftest/conf/test_work/state_dir
+cnf -: DBG: [PATH]/selftest/conf/paths.conf: relative path ./suite_test is [PATH]/selftest/conf/suite_test
+cnf -: DBG: Found path state_dir as [PATH]/selftest/conf/test_work/state_dir
+cnf -: DBG: Found config file resources.conf as [PATH]/selftest/conf/resources.conf in ./conf which is [PATH]/selftest/conf
+cnf -: DBG: Found path state_dir as [PATH]/selftest/conf/test_work/state_dir
 *** all resources:
 {'arfcn': [{'_hash': 'e620569450f8259b3f0212ec19c285dd07df063c',
             'arfcn': '512',

selftest/resource_test.ok.ign

@@ -0,0 +1 @@
+/[^ ]*/selftest/	[PATH]/selftest/

selftest/suite_test.ok

@@ -1,9 +1,15 @@
 - non-existing suite dir
---- -: ERR: RuntimeError: Suite not found: 'does_not_exist' in ./suite_test/.
+cnf -: DBG: Found config file paths.conf as [PATH]/selftest/suite_test/paths.conf in ./suite_test which is [PATH]/selftest/suite_test
+cnf -: DBG: [PATH]/selftest/suite_test/paths.conf: relative path ./test_work/state_dir is [PATH]/selftest/suite_test/test_work/state_dir
+cnf -: DBG: [PATH]/selftest/suite_test/paths.conf: relative path . is [PATH]/selftest/suite_test
+cnf -: DBG: Found path suites_dir as [PATH]/selftest/suite_test
+--- -: ERR: RuntimeError: Suite not found: 'does_not_exist' in [PATH]/selftest/suite_test
 - no suite.conf
+cnf -: DBG: Found path suites_dir as [PATH]/selftest/suite_test
 cnf empty_dir: DBG: reading suite.conf  [empty_dir↪empty_dir]
---- ./suite_test/./empty_dir/suite.conf: ERR: FileNotFoundError: [Errno 2] No such file or directory: './suite_test/./empty_dir/suite.conf'  [empty_dir↪./suite_test/./empty_dir/suite.conf]
+--- [PATH]/selftest/suite_test/empty_dir/suite.conf: ERR: FileNotFoundError: [Errno 2] No such file or directory: '[PATH]/selftest/suite_test/empty_dir/suite.conf'  [empty_dir↪[PATH]/selftest/suite_test/empty_dir/suite.conf]
 - valid suite dir
+cnf -: DBG: Found path suites_dir as [PATH]/selftest/suite_test
 cnf test_suite: DBG: reading suite.conf  [test_suite↪test_suite]
 defaults:
   timeout: 60s
@@ -16,6 +22,8 @@ resources:
   - times: '1'
 
 - run hello world test
+cnf -: DBG: Found config file resources.conf as [PATH]/selftest/suite_test/resources.conf in ./suite_test which is [PATH]/selftest/suite_test
+cnf -: DBG: Found path state_dir as [PATH]/selftest/suite_test/test_work/state_dir
 tst test_suite: Suite run start
 tst test_suite: reserving resources...
 tst test_suite: DBG: {combining='resources'}  [test_suite↪test_suite]

selftest/suite_test.ok.ign

@@ -0,0 +1 @@
+/[^ ]*/selftest/	[PATH]/selftest/

src/osmo_gsm_tester/config.py

@@ -88,9 +88,11 @@ def _get_config_file(basename, fail_if_missing=True):
         locations = DEFAULT_CONFIG_LOCATIONS
 
     for l in locations:
-        p = os.path.join(l, basename)
+        real_l = os.path.realpath(l)
+        p = os.path.realpath(os.path.join(real_l, basename))
         if os.path.isfile(p):
-            return (p, l)
+            log.dbg(None, log.C_CNF, 'Found config file', basename, 'as', p, 'in', l, 'which is', real_l)
+            return (p, real_l)
     if not fail_if_missing:
         return None, None
     raise RuntimeError('configuration file not found: %r in %r' % (basename,
@@ -115,20 +117,26 @@ def get_configured_path(label, allow_unset=False):
     env_name = ENV_PREFIX + label.upper()
     env_path = os.getenv(env_name)
     if env_path:
-        return env_path
+        real_env_path = os.path.realpath(env_path)
+        log.dbg(None, log.C_CNF, 'Found path', label, 'as', env_path, 'in', '$' + env_name, 'which is', real_env_path)
+        return real_env_path
 
     if PATHS is None:
         paths_file, found_in = _get_config_file(PATHS_CONF)
         PATHS = read(paths_file, PATHS_SCHEMA)
-        for key, path in PATHS.items():
+        # sorted for deterministic regression test results
+        for key, path in sorted(PATHS.items()):
             if not path.startswith(os.pathsep):
-                PATHS[key] = os.path.join(found_in, path)
+                PATHS[key] = os.path.realpath(os.path.join(found_in, path))
+                log.dbg(None, log.C_CNF, paths_file + ': relative path', path, 'is', PATHS[key])
     p = PATHS.get(label)
     if p is None and not allow_unset:
         raise RuntimeError('missing configuration in %s: %r' % (PATHS_CONF, label))
 
+    log.dbg(None, log.C_CNF, 'Found path', label, 'as', p)
     if p.startswith(PATHS_TEMPDIR_STR):
         p = os.path.join(get_tempdir(), p[len(PATHS_TEMPDIR_STR):])
+        log.dbg(None, log.C_CNF, 'Path', label, 'contained', PATHS_TEMPDIR_STR, 'and becomes', p)
     return p
 
 def get_state_dir():