Skip to content

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

Merged
rolfbjarne merged 1 commit intodotnet:mainfrom
rolfbjarne:do-not-log-in-property-accessors
Nov 22, 2024
Merged

Don't log from property accessors in the ILLink task.#109948
rolfbjarne merged 1 commit intodotnet:mainfrom
rolfbjarne:do-not-log-in-property-accessors

Conversation

@rolfbjarne
Copy link
Copy Markdown
Member

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.

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.
@rolfbjarne rolfbjarne requested a review from sbomer as a code owner November 19, 2024 08:39
@ghost ghost added the area-Tools-ILLink .NET linker development as well as trimming analyzers label Nov 19, 2024
@dotnet-policy-service dotnet-policy-service Bot added the linkable-framework Issues associated with delivering a linker friendly framework label Nov 19, 2024
@dotnet-policy-service
Copy link
Copy Markdown
Contributor

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

@rolfbjarne
Copy link
Copy Markdown
Member Author

This was introduced in #109376 (CC @am11)

Copy link
Copy Markdown
Member

@am11 am11 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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

cc @ViktorHofer

@ViktorHofer
Copy link
Copy Markdown
Member

Interesting. Didn't know that either.

@rolfbjarne
Copy link
Copy Markdown
Member Author

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.

Copy link
Copy Markdown
Member

@sbomer sbomer left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Interesting, thanks for the fix!

@rolfbjarne
Copy link
Copy Markdown
Member Author

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

@sbomer
Copy link
Copy Markdown
Member

sbomer commented Nov 20, 2024

Agreed, they don't look related.

@sbomer
Copy link
Copy Markdown
Member

sbomer commented Nov 20, 2024

/ba-g "chrome-DebuggerTests deadlettered"

@rolfbjarne rolfbjarne merged commit 4389f9c into dotnet:main Nov 22, 2024
@rolfbjarne rolfbjarne deleted the do-not-log-in-property-accessors branch November 22, 2024 07:30
mikelle-rogers pushed a commit to mikelle-rogers/runtime that referenced this pull request Dec 10, 2024
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: ~/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 [...]xamarin-macios/msbuild/Messaging/Xamarin.Messaging.Build/TaskRunner.cs:line 42
   at Xamarin.Messaging.Build.ExecuteTaskMessageHandler.<>c__DisplayClass5_0.<ExecuteAsync>b__0() in [...]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 [...]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.
@github-actions github-actions Bot locked and limited conversation to collaborators Dec 22, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.

Labels

area-Tools-ILLink .NET linker development as well as trimming analyzers linkable-framework Issues associated with delivering a linker friendly framework

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants