@samitouri / QOSAMI-WSL / commits / 6f47fa9b

diagnostics: improve logging of hcs helper utilities on debug builds (#13971)

* diagnostics: improve logging of hcs helper utilities on debug builds * implement pr feedback --------- Co-authored-by: Ben Hillis <benhill@ntdev.microsoft.com>

Ben Hillis committed Jan 6, 2026 at 10:07 UTC 6f47fa9b202fe41704e3c559b38b33a64aaa1387
3 files changed +95 -51
src/windows/common/hcs.cpp
+87 -45
@@ -78,6 +78,8 @@ wsl::windows::common::hcs::unique_hcs_operation wsl::windows::common::hcs::Creat
78
79 wsl::windows::common::hcs::unique_hcs_system wsl::windows::common::hcs::CreateComputeSystem(_In_ PCWSTR Id, _In_ PCWSTR Configuration)
80 {
81 + WSL_LOG_DEBUG("HcsCreateComputeSystem", TraceLoggingValue(Id, "id"), TraceLoggingValue(Configuration, "configuration"));
82 +
83 ExecutionContext context(Context::HCS);
84
85 const unique_hcs_operation operation = CreateOperation();
@@ -96,34 +98,41 @@ wsl::windows::common::hcs::unique_hcs_system wsl::windows::common::hcs::CreateCo
98 return system;
99 }
100
99 -std::vector<std::string> wsl::windows::common::hcs::GetProcessorFeatures()
101 +const std::vector<std::string>& wsl::windows::common::hcs::GetProcessorFeatures()
102 {
101 - ExecutionContext context(Context::HCS);
103 + static std::vector<std::string> g_processorFeatures;
104 + static std::once_flag flag;
105 + std::call_once(flag, []() {
106 + ExecutionContext context(Context::HCS);
107
103 - wil::unique_cotaskmem_string result;
104 - THROW_IF_FAILED(::HcsGetServiceProperties(c_processorCapabilitiesQuery, &result));
108 + wil::unique_cotaskmem_string result;
109 + THROW_IF_FAILED(::HcsGetServiceProperties(c_processorCapabilitiesQuery, &result));
110
106 - const auto properties = wsl::shared::FromJson<ServicePropertiesResponse<PropertyResponse<ProcessorCapabilitiesInfo>>>(result.get());
111 + const auto properties =
112 + wsl::shared::FromJson<ServicePropertiesResponse<PropertyResponse<ProcessorCapabilitiesInfo>>>(result.get());
113
108 - const auto& response = properties.PropertyResponses.at(c_processorCapabilities);
109 - if (response.Error)
110 - {
111 - THROW_HR_MSG(static_cast<HRESULT>(response.Error->Error), "%hs", response.Error->ErrorMessage.c_str());
112 - }
114 + const auto& response = properties.PropertyResponses.at(c_processorCapabilities);
115 + if (response.Error)
116 + {
117 + THROW_HR_MSG(static_cast<HRESULT>(response.Error->Error), "%hs", response.Error->ErrorMessage.c_str());
118 + }
119 +
120 + g_processorFeatures = response.Response.ProcessorFeatures;
121 + });
122
114 - return response.Response.ProcessorFeatures;
123 + return g_processorFeatures;
124 }
125
126 wsl::shared::hns::HNSEndpoint wsl::windows::common::hcs::GetEndpointProperties(HCN_ENDPOINT Endpoint)
127 {
128 + WSL_LOG_DEBUG("HcsGetEndpointProperties");
129 +
130 + ExecutionContext context(Context::HNS);
131 +
132 wil::unique_cotaskmem_string propertiesString;
133 wil::unique_cotaskmem_string error;
121 -
122 - {
123 - ExecutionContext context(Context::HNS);
124 - const auto result = HcnQueryEndpointProperties(Endpoint, nullptr, &propertiesString, &error);
125 - THROW_IF_FAILED_MSG(result, "HcnQueryEndpointProperties %ls", error.get());
126 - }
134 + const auto result = HcnQueryEndpointProperties(Endpoint, nullptr, &propertiesString, &error);
135 + THROW_IF_FAILED_MSG(result, "HcnQueryEndpointProperties %ls", error.get());
136
137 return wsl::shared::FromJson<wsl::shared::hns::HNSEndpoint>(propertiesString.get());
138 }
@@ -147,66 +156,84 @@ GUID wsl::windows::common::hcs::GetRuntimeId(_In_ HCS_SYSTEM ComputeSystem)
156
157 std::pair<uint32_t, uint32_t> wsl::windows::common::hcs::GetSchemaVersion()
158 {
150 - PropertyQuery query;
151 - query.PropertyTypes.emplace_back(PropertyType::Basic);
152 -
153 - ExecutionContext context(Context::HCS);
154 - wil::unique_cotaskmem_string result;
155 -
156 - THROW_IF_FAILED(::HcsGetServiceProperties(wsl::shared::ToJsonW(query).c_str(), &result));
157 -
158 - const auto properties = wsl::shared::FromJson<ServiceProperties<BasicInformation>>(result.get());
159 - THROW_HR_IF_MSG(E_UNEXPECTED, properties.Properties.empty(), "%ls", result.get());
160 -
161 - uint32_t majorVersion = 0;
162 - uint32_t minorVersion = 0;
163 - for (const auto& version : properties.Properties[0].SupportedSchemaVersions)
164 - {
165 - if (version.Major >= majorVersion)
159 + static std::pair<uint32_t, uint32_t> g_schemaVersion{};
160 + static std::once_flag flag;
161 + std::call_once(flag, []() {
162 + ExecutionContext context(Context::HCS);
163 +
164 + PropertyQuery query;
165 + query.PropertyTypes.emplace_back(PropertyType::Basic);
166 + wil::unique_cotaskmem_string result;
167 + THROW_IF_FAILED(::HcsGetServiceProperties(wsl::shared::ToJsonW(query).c_str(), &result));
168 +
169 + const auto properties = wsl::shared::FromJson<ServiceProperties<BasicInformation>>(result.get());
170 + THROW_HR_IF_MSG(E_UNEXPECTED, properties.Properties.empty(), "%ls", result.get());
171 +
172 + uint32_t majorVersion = 0;
173 + uint32_t minorVersion = 0;
174 + for (const auto& version : properties.Properties[0].SupportedSchemaVersions)
175 {
167 - if ((version.Major > majorVersion) || (version.Minor > minorVersion))
176 + if (version.Major >= majorVersion)
177 {
169 - majorVersion = version.Major;
170 - minorVersion = version.Minor;
178 + if ((version.Major > majorVersion) || (version.Minor > minorVersion))
179 + {
180 + majorVersion = version.Major;
181 + minorVersion = version.Minor;
182 + }
183 }
184 }
173 - }
185
175 - return {majorVersion, minorVersion};
186 + g_schemaVersion = {majorVersion, minorVersion};
187 + });
188 +
189 + return g_schemaVersion;
190 }
191
192 void wsl::windows::common::hcs::GrantVmAccess(_In_ PCWSTR VmId, _In_ PCWSTR FilePath)
193 {
194 + WSL_LOG_DEBUG("HcsGrantVmAccess", TraceLoggingValue(VmId, "vmId"), TraceLoggingValue(FilePath, "filePath"));
195 +
196 ExecutionContext context(Context::HCS);
197
182 - THROW_IF_FAILED_MSG(::HcsGrantVmAccess(VmId, FilePath), "Path (%ws)", FilePath);
198 + THROW_IF_FAILED_MSG(::HcsGrantVmAccess(VmId, FilePath), "HcsGrantVmAccess(%ls, %ls)", VmId, FilePath);
199 }
200
201 void wsl::windows::common::hcs::ModifyComputeSystem(_In_ HCS_SYSTEM ComputeSystem, _In_ PCWSTR Configuration, _In_opt_ HANDLE Identity)
202 {
203 + WSL_LOG_DEBUG("HcsModifyComputeSystem", TraceLoggingValue(Configuration, "configuration"));
204 +
205 ExecutionContext context(Context::HCS);
206
207 const unique_hcs_operation operation = CreateOperation();
208 THROW_IF_FAILED_MSG(
191 - ::HcsModifyComputeSystem(ComputeSystem, operation.get(), Configuration, Identity), "HcsModifyComputeSystem (%ws)", Configuration);
209 + ::HcsModifyComputeSystem(ComputeSystem, operation.get(), Configuration, Identity), "HcsModifyComputeSystem (%ls)", Configuration);
210
211 wil::unique_cotaskmem_string resultDocument;
212 const auto result = ::HcsWaitForOperationResult(operation.get(), INFINITE, &resultDocument);
195 - THROW_IF_FAILED_MSG(result, "HcsModifyComputeSystem failed (%ls - error string: %ls)", Configuration, resultDocument.get());
213 + if (FAILED(result))
214 + {
215 + // N.B. Logging is split into two calls because the configuration and error strings can be quite long.
216 + LOG_HR_MSG(result, "HcsModifyComputeSystem(%ls)", Configuration);
217 + THROW_HR_MSG(result, "HcsModifyComputeSystem failed (error string: %ls)", resultDocument.get());
218 + }
219 }
220
221 wsl::windows::common::hcs::unique_hcs_system wsl::windows::common::hcs::OpenComputeSystem(_In_ PCWSTR Id, _In_ DWORD RequestedAccess)
222 {
223 + WSL_LOG_DEBUG("HcsOpenComputeSystem", TraceLoggingValue(Id, "id"), TraceLoggingValue(RequestedAccess, "requestedAccess"));
224 +
225 ExecutionContext context(Context::HCS);
226
227 unique_hcs_system system;
203 - THROW_IF_FAILED(::HcsOpenComputeSystem(Id, RequestedAccess, &system));
228 + THROW_IF_FAILED_MSG(::HcsOpenComputeSystem(Id, RequestedAccess, &system), "HcsOpenComputeSystem(%ls)", Id);
229
230 return system;
231 }
232
233 void wsl::windows::common::hcs::RegisterCallback(_In_ HCS_SYSTEM ComputeSystem, _In_ HCS_EVENT_CALLBACK Callback, _In_ void* Context)
234 {
235 + WSL_LOG_DEBUG("HcsSetComputeSystemCallback");
236 +
237 ExecutionContext context(Context::HCS);
238
239 THROW_IF_FAILED(::HcsSetComputeSystemCallback(ComputeSystem, HcsEventOptionNone, Context, Callback));
@@ -222,13 +249,17 @@ void wsl::windows::common::hcs::RemoveScsiDisk(_In_ HCS_SYSTEM ComputeSystem, _I
249
250 void wsl::windows::common::hcs::RevokeVmAccess(_In_ PCWSTR VmId, _In_ PCWSTR FilePath)
251 {
225 - ExecutionContext context(Context::HCS);
252 + WSL_LOG_DEBUG("HcsRevokeVmAccess", TraceLoggingValue(VmId, "vmId"), TraceLoggingValue(FilePath, "filePath"));
253
227 - THROW_IF_FAILED(::HcsRevokeVmAccess(VmId, FilePath));
254 + ExecutionContext context(Context::HNS);
255 +
256 + THROW_IF_FAILED_MSG(::HcsRevokeVmAccess(VmId, FilePath), "HcsRevokeVmAccess(%ls, %ls)", VmId, FilePath);
257 }
258
259 void wsl::windows::common::hcs::StartComputeSystem(_In_ HCS_SYSTEM ComputeSystem, _In_ LPCWSTR Configuration)
260 {
261 + WSL_LOG_DEBUG("HcsStartComputeSystem", TraceLoggingValue(Configuration, "configuration"));
262 +
263 ExecutionContext context(Context::HCS);
264
265 const unique_hcs_operation operation = CreateOperation();
@@ -236,11 +267,18 @@ void wsl::windows::common::hcs::StartComputeSystem(_In_ HCS_SYSTEM ComputeSystem
267
268 wil::unique_cotaskmem_string resultDocument;
269 const auto result = ::HcsWaitForOperationResult(operation.get(), INFINITE, &resultDocument);
239 - THROW_IF_FAILED_MSG(result, "HcsStartComputeSystem failed (error string: %ls, configuration: %ls)", resultDocument.get(), Configuration);
270 + if (FAILED(result))
271 + {
272 + // N.B. Logging is split into two calls because the configuration and error strings can be quite long.
273 + LOG_HR_MSG(result, "HcsStartComputeSystem(%ls)", Configuration);
274 + THROW_HR_MSG(result, "HcsStartComputeSystem failed (error string: %ls)", resultDocument.get());
275 + }
276 }
277
278 void wsl::windows::common::hcs::TerminateComputeSystem(_In_ HCS_SYSTEM ComputeSystem)
279 {
280 + WSL_LOG_DEBUG("HcsTerminateComputeSystem");
281 +
282 ExecutionContext context(Context::HCS);
283
284 const unique_hcs_operation operation = CreateOperation();
@@ -254,6 +292,8 @@ void wsl::windows::common::hcs::TerminateComputeSystem(_In_ HCS_SYSTEM ComputeSy
292 wsl::windows::common::hcs::unique_hcn_service_callback wsl::windows::common::hcs::RegisterServiceCallback(
293 _In_ HCS_NOTIFICATION_CALLBACK Callback, _In_ PVOID Context)
294 {
295 + WSL_LOG_DEBUG("HcsRegisterServiceCallback");
296 +
297 ExecutionContext context(Context::HNS);
298
299 unique_hcn_service_callback callbackHandle;
@@ -265,6 +305,8 @@ wsl::windows::common::hcs::unique_hcn_service_callback wsl::windows::common::hcs
305 wsl::windows::common::hcs::unique_hcn_guest_network_service_callback wsl::windows::common::hcs::RegisterGuestNetworkServiceCallback(
306 _In_ const unique_hcn_guest_network_service& GuestNetworkService, _In_ HCS_NOTIFICATION_CALLBACK Callback, _In_ PVOID Context)
307 {
308 + WSL_LOG_DEBUG("HcsRegisterGuestNetworkServiceCallback");
309 +
310 ExecutionContext context(Context::HNS);
311
312 unique_hcn_guest_network_service_callback callbackHandle;
src/windows/common/hcs.hpp
+1 -1
@@ -55,7 +55,7 @@ unique_hcs_operation CreateOperation();
55
56 wsl::shared::hns::HNSEndpoint GetEndpointProperties(HCN_ENDPOINT endpoint);
57
58 -std::vector<std::string> GetProcessorFeatures();
58 +const std::vector<std::string>& GetProcessorFeatures();
59
60 GUID GetRuntimeId(_In_ HCS_SYSTEM ComputeSystem);
61
src/windows/service/exe/WslCoreVm.cpp
+7 -5
@@ -1516,16 +1516,18 @@ std::wstring WslCoreVm::GenerateConfigJson()
1516 {
1517 try
1518 {
1519 - std::vector<std::string> processorFeatures{};
1519 if (wsl::windows::common::helpers::IsWindows11OrAbove())
1520 {
1522 - processorFeatures = wsl::windows::common::hcs::GetProcessorFeatures();
1521 + const auto& processorFeatures = wsl::windows::common::hcs::GetProcessorFeatures();
1522 + auto feature = std::find(processorFeatures.begin(), processorFeatures.end(), "NestedVirt");
1523 + m_vmConfig.EnableNestedVirtualization = (feature != processorFeatures.end());
1524 + }
1525 + else
1526 + {
1527 + m_vmConfig.EnableNestedVirtualization = false;
1528 }
1529
1525 - auto feature = std::find(processorFeatures.begin(), processorFeatures.end(), "NestedVirt");
1526 - m_vmConfig.EnableNestedVirtualization = (feature != processorFeatures.end());
1530 vmSettings.ComputeTopology.Processor.ExposeVirtualizationExtensions = m_vmConfig.EnableNestedVirtualization;
1528 -
1531 if (!m_vmConfig.EnableNestedVirtualization)
1532 {
1533 EMIT_USER_WARNING(wsl::shared::Localization::MessageNestedVirtualizationNotSupported());