Merge pull request #1922 from schellap/fxr-move

Add logging and fix xunit runtimeconfig

src/corehost/cli/fxr/fx_muxer.cpp

@@ -16,8 +16,9 @@
 
 typedef web::json::value json_value;
 
-pal::string_t fx_muxer_t::resolve_fx_dir(const pal::string_t& muxer_dir, runtime_config_t* runtime, const pal::string_t& app_path)
+pal::string_t fx_muxer_t::resolve_fx_dir(const pal::string_t& muxer_dir, runtime_config_t* runtime)
 {
+    trace::verbose(_X("--- Resolving FX directory from muxer dir [%s]"), muxer_dir.c_str());
     const auto fx_name = runtime->get_fx_name();
     const auto fx_ver = runtime->get_fx_version();
     const auto roll_fwd = runtime->get_fx_roll_fwd();
@@ -25,6 +26,7 @@ pal::string_t fx_muxer_t::resolve_fx_dir(const pal::string_t& muxer_dir, runtime
     fx_ver_t specified(-1, -1, -1);
     if (!fx_ver_t::parse(fx_ver, &specified, false))
     {
+        trace::error(_X("The specified runtimeconfig.json version [%s] could not be parsed"), fx_ver.c_str());
         return pal::string_t();
     }
 
@@ -35,15 +37,20 @@ pal::string_t fx_muxer_t::resolve_fx_dir(const pal::string_t& muxer_dir, runtime
     // If not roll forward or if pre-release, just return.
     if (!roll_fwd || specified.is_prerelease())
     {
+        trace::verbose(_X("Did not roll forward because rollfwd=%d and [%s] is prerelease=%d"),
+                roll_fwd, fx_ver.c_str(), specified.is_prerelease());
         append_path(&fx_dir, fx_ver.c_str());
     }
     else
     {
+        trace::verbose(_X("Attempting production FX roll forward starting from [%s]"), fx_ver.c_str());
+
         std::vector<pal::string_t> list;
         pal::readdir(fx_dir, &list);
         fx_ver_t max_specified = specified;
         for (const auto& version : list)
         {
+            trace::verbose(_X("Inspecting version... [%s]"), version.c_str());
             fx_ver_t ver(-1, -1, -1);
             if (fx_ver_t::parse(version, &ver, true) &&
                 ver.get_major() == max_specified.get_major() &&
@@ -55,21 +62,26 @@ pal::string_t fx_muxer_t::resolve_fx_dir(const pal::string_t& muxer_dir, runtime
         pal::string_t max_specified_str = max_specified.as_str();
         append_path(&fx_dir, max_specified_str.c_str());
     }
-    trace::verbose(_X("Found fx in: %s"), fx_dir.c_str());
+
+    trace::verbose(_X("Chose FX version [%s]"), fx_dir.c_str());
     return pal::directory_exists(fx_dir) ? fx_dir : pal::string_t();
 }
 
 pal::string_t fx_muxer_t::resolve_cli_version(const pal::string_t& global_json)
 {
+    trace::verbose(_X("--- Resolving CLI version from global json [%s]"), global_json.c_str());
+
     pal::string_t retval;
     if (!pal::file_exists(global_json))
     {
+        trace::verbose(_X("[%s] does not exist"), global_json.c_str());
         return retval;
     }
 
     pal::ifstream_t file(global_json);
     if (!file.good())
     {
+        trace::verbose(_X("[%s] could not be opened"), global_json.c_str());
         return retval;
     }
 
@@ -80,6 +92,7 @@ pal::string_t fx_muxer_t::resolve_cli_version(const pal::string_t& global_json)
         const auto sdk_iter = json.find(_X("sdk"));
         if (sdk_iter == json.end() || sdk_iter->second.is_null())
         {
+            trace::verbose(_X("CLI '/sdk/version' field not present/null in [%s]"), global_json.c_str());
             return retval;
         }
 
@@ -87,19 +100,23 @@ pal::string_t fx_muxer_t::resolve_cli_version(const pal::string_t& global_json)
         const auto ver_iter = sdk_obj.find(_X("version"));
         if (ver_iter == sdk_obj.end() || ver_iter->second.is_null())
         {
+            trace::verbose(_X("CLI 'sdk/version' field not present/null in [%s]"), global_json.c_str());
             return retval;
         }
         retval = ver_iter->second.as_string();
     }
     catch (...)
     {
+        trace::verbose(_X("A JSON parsing exception occurred"));
     }
-    trace::verbose(_X("Found cli in: %s"), retval.c_str());
+    trace::verbose(_X("CLI version is [%s] in global json file [%s]"), retval.c_str(), global_json.c_str());
     return retval;
 }
 
 pal::string_t resolve_sdk_version(pal::string_t sdk_path)
 {
+    trace::verbose(_X("--- Resolving SDK version from SDK dir [%s]"), sdk_path.c_str());
+
     pal::string_t retval;
     std::vector<pal::string_t> versions;
 
@@ -108,6 +125,8 @@ pal::string_t resolve_sdk_version(pal::string_t sdk_path)
     fx_ver_t max_pre(-1, -1, -1);
     for (const auto& version : versions)
     {
+        trace::verbose(_X("Considering version... [%s]"), version.c_str());
+
         fx_ver_t ver(-1, -1, -1);
         if (fx_ver_t::parse(version, &ver, true))
         {
@@ -122,20 +141,26 @@ pal::string_t resolve_sdk_version(pal::string_t sdk_path)
     // No production, use the max pre-release.
     if (max_ver == fx_ver_t(-1, -1, -1))
     {
+        trace::verbose(_X("No production version found, so using latest prerelease"));
         max_ver = max_pre;
     }
 
     pal::string_t max_ver_str = max_ver.as_str();
     append_path(&sdk_path, max_ver_str.c_str());
+
+    trace::verbose(_X("Checking if resolved SDK dir [%s] exists"), sdk_path.c_str());
     if (pal::directory_exists(sdk_path))
     {
         retval = sdk_path;
     }
+
+    trace::verbose(_X("Resolved SDK dir is [%s]"), retval.c_str());
     return retval;
 }
 
 bool fx_muxer_t::resolve_sdk_dotnet_path(const pal::string_t& own_dir, pal::string_t* cli_sdk)
 {
+    trace::verbose(_X("--- Resolving dotnet from working dir"));
     pal::string_t cwd;
     pal::string_t global;
     if (pal::getcwd(&cwd))
@@ -144,18 +169,27 @@ bool fx_muxer_t::resolve_sdk_dotnet_path(const pal::string_t& own_dir, pal::stri
         {
             pal::string_t file = cur_dir;
             append_path(&file, _X("global.json"));
+
+            trace::verbose(_X("Probing path [%s] for global.json"), file.c_str());
             if (pal::file_exists(file))
             {
                 global = file;
+                trace::verbose(_X("Found global.json [%s]"), global.c_str());
                 break;
             }
             parent_dir = get_directory(cur_dir);
             if (parent_dir.empty() || parent_dir.size() == cur_dir.size())
             {
+                trace::verbose(_X("Terminating global.json search at [%s]"), parent_dir.c_str());
                 break;
             }
         }
     }
+    else
+    {
+        trace::verbose(_X("Failed to obtain current working dir"));
+    }
+
     pal::string_t retval;
     if (!global.empty())
     {
@@ -165,10 +199,16 @@ bool fx_muxer_t::resolve_sdk_dotnet_path(const pal::string_t& own_dir, pal::stri
             pal::string_t sdk_path = own_dir;
             append_path(&sdk_path, _X("sdk"));
             append_path(&sdk_path, cli_version.c_str());
+
             if (pal::directory_exists(sdk_path))
             {
+                trace::verbose(_X("CLI directory [%s] from global.json exists"), sdk_path.c_str());
                 retval = sdk_path;
             }
+            else
+            {
+                trace::verbose(_X("CLI directory [%s] from global.json doesn't exist"), sdk_path.c_str());
+            }
         }
     }
     if (retval.empty())
@@ -178,13 +218,15 @@ bool fx_muxer_t::resolve_sdk_dotnet_path(const pal::string_t& own_dir, pal::stri
         retval = resolve_sdk_version(sdk_path);
     }
     cli_sdk->assign(retval);
-    trace::verbose(_X("Found cli sdk in: %s"), cli_sdk->c_str());
+    trace::verbose(_X("Found CLI SDK in: %s"), cli_sdk->c_str());
     return !retval.empty();
 }
 
 /* static */
 int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
 {
+    trace::error(_X("--- Executing in muxer mode..."));
+
     pal::string_t own_path;
 
     // Get the full name of the application
@@ -198,6 +240,7 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
 
     if (argc <= 1)
     {
+        trace::error(_X("Usage: dotnet [--help | app.dll]"));
         return StatusCode::InvalidArgFailure;
     }
     if (ends_with(argv[1], _X(".dll"), false))
@@ -206,10 +249,12 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
 
         if (!pal::realpath(&app_path))
         {
+            trace::error(_X("Could not resolve app's full path [%s]"), app_path.c_str());
             return StatusCode::LibHostExecModeFailure;
         }
 
-        runtime_config_t config(get_runtime_config_json(app_path));
+        auto config_file = get_runtime_config_from_file(app_path);
+        runtime_config_t config(config_file);
         if (!config.is_valid())
         {
             trace::error(_X("Invalid runtimeconfig.json [%s]"), config.get_path().c_str());
@@ -217,12 +262,14 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
         }
         if (config.get_portable())
         {
-            pal::string_t fx_dir = resolve_fx_dir(own_dir, &config, app_path);
+            trace::verbose(_X("Executing as a portable app as per config file [%s]"), config_file.c_str());
+            pal::string_t fx_dir = resolve_fx_dir(own_dir, &config);
             corehost_init_t init(_X(""), _X(""), fx_dir, host_mode_t::muxer, &config);
             return policy_load_t::execute_app(fx_dir, &init, argc, argv);
         }
         else
         {
+            trace::verbose(_X("Executing as a standlone app as per config file [%s]"), config_file.c_str());
             corehost_init_t init(_X(""), _X(""), _X(""), host_mode_t::muxer, &config);
             return policy_load_t::execute_app(get_directory(app_path), &init, argc, argv);
         }
@@ -237,11 +284,13 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
             std::unordered_map<pal::string_t, pal::string_t> opts;
             if (!parse_known_args(argc - 2, &argv[2], known_opts, &opts, &num_args))
             {
+                trace::error(_X("Failed to parse known arguments."));
                 return InvalidArgFailure;
             }
             int cur_i = 2 + num_args;
             if (cur_i >= argc)
             {
+                trace::error(_X("Parsed known args, but need more arguments."));
                 return InvalidArgFailure;
             }
 
@@ -256,23 +305,31 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
             pal::string_t deps_file = opts.count(opts_deps_file) ? opts[opts_deps_file] : _X("");
             pal::string_t probe_path = opts.count(opts_probe_path) ? opts[opts_probe_path] : _X("");
 
-            pal::string_t app_path = argv[cur_i];
+            pal::string_t app_or_deps = deps_file.empty() ? argv[cur_i] : deps_file;
-            runtime_config_t config(get_runtime_config_json(app_path));
+            auto config_file = get_runtime_config_from_file(app_or_deps);
+            runtime_config_t config(config_file);
             if (!config.is_valid())
             {
                 trace::error(_X("Invalid runtimeconfig.json [%s]"), config.get_path().c_str());
                 return StatusCode::InvalidConfigFile;
             }
+            if (!deps_file.empty() && !pal::file_exists(deps_file))
+            {
+                trace::error(_X("Deps file [%s] specified but doesn't exist"), deps_file.c_str());
+                return StatusCode::InvalidArgFailure;
+            }
             if (config.get_portable())
             {
-                pal::string_t fx_dir = resolve_fx_dir(own_dir, &config, app_path);
+                trace::verbose(_X("Executing as a portable app as per config file [%s]"), config_file.c_str());
+                pal::string_t fx_dir = resolve_fx_dir(own_dir, &config);
                 corehost_init_t init(deps_file, probe_path, fx_dir, host_mode_t::muxer, &config);
                 return policy_load_t::execute_app(fx_dir, &init, new_argv.size(), new_argv.data());
             }
             else
             {
+                trace::verbose(_X("Executing as a standalone app as per config file [%s]"), config_file.c_str());
                 corehost_init_t init(deps_file, probe_path, _X(""), host_mode_t::muxer, &config);
-                pal::string_t impl_dir = get_directory(deps_file.empty() ? app_path : deps_file);
+                pal::string_t impl_dir = get_directory(app_or_deps);
                 return policy_load_t::execute_app(impl_dir, &init, new_argv.size(), new_argv.data());
             }
         }
@@ -281,9 +338,17 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
             pal::string_t sdk_dotnet;
             if (!resolve_sdk_dotnet_path(own_dir, &sdk_dotnet))
             {
+                trace::error(_X("Could not resolve SDK directory from [%s]"), own_dir.c_str());
                 return StatusCode::LibHostSdkFindFailure;
             }
             append_path(&sdk_dotnet, _X("dotnet.dll"));
+
+            if (!pal::file_exists(_X("dotnet.dll")))
+            {
+                trace::error(_X("Could not find dotnet.dll at [%s]"), sdk_dotnet.c_str());
+                return StatusCode::LibHostSdkFindFailure;
+            }
+
             // Transform dotnet [command] [args] -> dotnet [dotnet.dll] [command] [args]
 
             std::vector<const pal::char_t*> new_argv(argc + 1);
@@ -291,20 +356,21 @@ int fx_muxer_t::execute(const int argc, const pal::char_t* argv[])
             new_argv[0] = argv[0];
             new_argv[1] = sdk_dotnet.c_str();
 
-            trace::verbose(_X("Using SDK dll=[%s]"), sdk_dotnet.c_str());
+            trace::verbose(_X("Using dotnet SDK dll=[%s]"), sdk_dotnet.c_str());
 
-            assert(ends_with(sdk_dotnet, _X(".dll"), false));
+            auto config_file = get_runtime_config_from_file(sdk_dotnet);
-
+            runtime_config_t config(config_file);
-            runtime_config_t config(get_runtime_config_json(sdk_dotnet));
 
             if (config.get_portable())
             {
-                pal::string_t fx_dir = resolve_fx_dir(own_dir, &config, sdk_dotnet);
+                trace::verbose(_X("Executing dotnet.dll as a portable app as per config file [%s]"), config_file.c_str());
+                pal::string_t fx_dir = resolve_fx_dir(own_dir, &config);
                 corehost_init_t init(_X(""), _X(""), fx_dir, host_mode_t::muxer, &config);
                 return policy_load_t::execute_app(fx_dir, &init, new_argv.size(), new_argv.data());
             }
             else
             {
+                trace::verbose(_X("Executing dotnet.dll as a standalone app as per config file [%s]"), config_file.c_str());
                 corehost_init_t init(_X(""), _X(""), _X(""), host_mode_t::muxer, &config);
                 return policy_load_t::execute_app(get_directory(sdk_dotnet), &init, new_argv.size(), new_argv.data());
             }
@@ -316,4 +382,4 @@ SHARED_API int hostfxr_main(const int argc, const pal::char_t* argv[])
 {
     trace::setup();
     return fx_muxer_t().execute(argc, argv);
-}
+}

src/corehost/cli/fxr/fx_muxer.h

@@ -9,7 +9,7 @@ class fx_muxer_t
 public:
     static int execute(const int argc, const pal::char_t* argv[]);
 private:
-    static pal::string_t resolve_fx_dir(const pal::string_t& muxer_path, runtime_config_t* runtime, const pal::string_t& app_path);
+    static pal::string_t resolve_fx_dir(const pal::string_t& muxer_path, runtime_config_t* runtime);
     static pal::string_t resolve_cli_version(const pal::string_t& global);
     static bool resolve_sdk_dotnet_path(const pal::string_t& own_dir, pal::string_t* cli_sdk);
 };

src/corehost/cli/hostpolicy.cpp

@@ -215,7 +215,8 @@ SHARED_API int corehost_main(const int argc, const pal::char_t* argv[])
     }
     else
     {
-        runtime_config_t config(get_runtime_config_json(args.managed_application));
+        auto config_path = get_runtime_config_from_file(args.managed_application);
+        runtime_config_t config(config_path);
         if (!config.is_valid())
         {
             trace::error(_X("Invalid runtimeconfig.json [%s]"), config.get_path().c_str());

src/corehost/cli/libhost.cpp

@@ -6,11 +6,12 @@
 #include "trace.h"
 #include "libhost.h"
 
-pal::string_t get_runtime_config_json(const pal::string_t& app_path)
+pal::string_t get_runtime_config_from_file(const pal::string_t& file)
 {
-    auto name = get_filename_without_ext(app_path);
+    auto name = get_filename_without_ext(file);
+    name = name.substr(0, name.find(_X('.')));
     auto json_name = name + _X(".runtimeconfig.json");
-    auto json_path = get_directory(app_path);
+    auto json_path = get_directory(file);
 
     append_path(&json_path, json_name.c_str());
     if (pal::file_exists(json_path))

src/corehost/cli/libhost.h

@@ -64,7 +64,7 @@ public:
     }
 };
 
-pal::string_t get_runtime_config_json(const pal::string_t& app_path);
+pal::string_t get_runtime_config_from_file(const pal::string_t& file);
 host_mode_t detect_operating_mode(const int argc, const pal::char_t* argv[], pal::string_t* own_dir = nullptr);
 
 #endif // __LIBHOST_H__

src/corehost/common/utils.cpp

@@ -74,7 +74,7 @@ pal::string_t get_filename_without_ext(const pal::string_t& path)
     size_t name_pos = path.find_last_of(_X("/\\"));
     size_t dot_pos = path.rfind(_X('.'));
     size_t start_pos = (name_pos == pal::string_t::npos) ? 0 : (name_pos + 1);
-    size_t count = (dot_pos == pal::string_t::npos) ? pal::string_t::npos : (dot_pos - start_pos);
+    size_t count = (dot_pos == pal::string_t::npos || dot_pos < start_pos) ? pal::string_t::npos : (dot_pos - start_pos);
     return path.substr(start_pos, count);
 }