dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.42k stars 4.76k forks source link

Don't log from property accessors in the ILLink task. #109948

Closed rolfbjarne closed 10 hours ago

rolfbjarne commented 3 days ago

When executing a remote iOS build from Windows on macOS, the ILLink task is instantiated on the remote macOS machine using a json deserializer.

This means that the properties will be read and written to before the task has been fully initialized, and this happens:

Newtonsoft.Json.JsonSerializationException: Error getting value from 'ILLinkPath' on 'Xamarin.MacDev.Tasks.ILLink'.
 ---> System.InvalidOperationException: Task attempted to log before it was initialized. Message was: ILLink.Tasks path: /Users/rolf/Library/Caches/Xamarin/XMA/Agents/Build/net/illink.dll
   at Microsoft.Build.Shared.ErrorUtilities.ThrowInvalidOperation(String resourceName, Object[] args)
   at Microsoft.Build.Utilities.TaskLoggingHelper.LogMessage(MessageImportance importance, String message, Object[] messageArgs)
   at ILLink.Tasks.ILLink.get_ILLinkPath()
   at Newtonsoft.Json.Serialization.ExpressionValueProvider.GetValue(Object target)
   --- End of inner exception stack trace ---
   at Newtonsoft.Json.Serialization.ExpressionValueProvider.GetValue(Object target)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.SetPropertyValue(JsonProperty property, JsonConverter propertyConverter, JsonContainerContract containerContract, JsonProperty containerProperty, JsonReader reader, Object target)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.PopulateObject(Object newObject, JsonReader reader, JsonObjectContract contract, JsonProperty member, String id)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateObject(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.CreateValueInternal(JsonReader reader, Type objectType, JsonContract contract, JsonProperty member, JsonContainerContract containerContract, JsonProperty containerMember, Object existingValue)
   at Newtonsoft.Json.Serialization.JsonSerializerInternalReader.Deserialize(JsonReader reader, Type objectType, Boolean checkAdditionalContent)
   at Newtonsoft.Json.JsonSerializer.DeserializeInternal(JsonReader reader, Type objectType)
   at Newtonsoft.Json.JsonSerializer.Deserialize(JsonReader reader, Type objectType)
   at Xamarin.Messaging.Build.Serialization.TaskSerializer.Deserialize(String content, Type taskType) in D:\a\_work\1\s\src\MSBuild\Xamarin.Messaging.Build.Common\Serialization\TaskSerializer.cs:line 25
   at Xamarin.Messaging.Build.TaskRunner.Execute(String taskName, String inputs) in /Users/rolf/work/maccore/net10.0/xamarin-macios/msbuild/Messaging/Xamarin.Messaging.Build/TaskRunner.cs:line 42
   at Xamarin.Messaging.Build.ExecuteTaskMessageHandler.<>c__DisplayClass5_0.<ExecuteAsync>b__0() in /Users/rolf/work/maccore/net10.0/xamarin-macios/msbuild/Messaging/Xamarin.Messaging.Build/Handlers/ExecuteTaskMessageHandler.cs:line 40
   at System.Threading.Tasks.Task`1.InnerInvoke()
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location ---
   at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state)
   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
--- End of stack trace from previous location ---
   at Xamarin.Messaging.Build.ExecuteTaskMessageHandler.ExecuteAsync(ExecuteTaskMessage message) in /Users/rolf/work/maccore/net10.0/xamarin-macios/msbuild/Messaging/Xamarin.Messaging.Build/Handlers/ExecuteTaskMessageHandler.cs:line 28
   at Xamarin.Messaging.Client.RequestHandler`2.HandleAsync(TMessage message) in D:\a\_work\1\s\src\Xamarin.Messaging.Client\Handlers\RequestHandler.cs:line 68
   at Xamarin.Messaging.Client.MessageHandlerManager.<>c__DisplayClass12_1`2.<<RegisterHandlerAsync>b__2>d.MoveNext() in D:\a\_work\1\s\src\Xamarin.Messaging.Client\MessageHandlerManager.cs:line 96
--- End of stack trace from previous location ---
   at Xamarin.Messaging.Client.MessagingClient.ReplyAsync[TRequest,TResponse](IRequest`1 request, MessagePriority priority, Func`1 replyFunctionAsync) in D:\a\_work\1\s\src\Xamarin.Messaging.Client\MessagingClient.cs:line 351: 11/18/2024 10:23:11Z

So move the logging statement to when it the property in question is used.

dotnet-policy-service[bot] commented 3 days ago

Tagging subscribers to this area: @agocke, @sbomer, @vitek-karas See info in area-owners.md if you want to be subscribed.

rolfbjarne commented 3 days ago

This was introduced in #109376 (CC @am11)

ViktorHofer commented 3 days ago

Interesting. Didn't know that either.

rolfbjarne commented 3 days ago

Looks good! TIL: didn't knew we can't use logger in task's property accessor. 👀

cc @ViktorHofer

It's usually not a problem, but for iOS projects we have a very special setup where when building on Windows we can execute tasks on macOS, and in this particular case our implementation for remoting tasks doesn't support logging in property accessors.

rolfbjarne commented 2 days ago

The failed checks don't look related to my changes from what I can tell?

sbomer commented 1 day ago

Agreed, they don't look related.

sbomer commented 1 day ago

/ba-g "chrome-DebuggerTests deadlettered"