Console.Write prints a new line on iOS

[rolfbjarne]

Example:

Console.Write ("A");
Console.Write ("B");
Console.WriteLine ("C");

Output with .NET 5:

2020-05-14 12:50:56.386845+0200 MySingleView[89908:5086139] A
2020-05-14 12:50:56.386961+0200 MySingleView[89908:5086139] B
2020-05-14 12:50:56.387585+0200 MySingleView[89908:5086139] C

Output with current Xamarin.iOS:

2020-05-14 12:53:03.497594+0200 testapp[93230:5096504] ABC

The problem seems to be that mono's implementation stores text until a newline is written:

https://github.com/mono/mono/blob/f24a85069b3541ef45c8bbbd800ec7d88ad22e07/mcs/class/corlib/System/Console.iOS.cs#L81-L83

while dotnet's implementation writes out the text every time:

runtime/src/libraries/System.Console/src/System/ConsolePal.iOS.cs

Lines 16 to 24 in 622341e

	public override unsafe void Write(byte[] buffer, int offset, int count)
	{
	ValidateWrite(buffer, offset, count);
	fixed (byte* ptr = buffer)
	{
	Interop.Sys.Log(ptr + offset, count);
	}
	}

and NSLog will append a newline if the text doesn't have one.

[ghost]

Tagging subscribers to this area: @eiriktsarpalis
Notify danmosemsft if you want to be subscribed.

[stephentoub]

cc: @EgorBo

[EgorBo]

I forgot to file an issue for that because wanted to unblock Console for both Android (it has the same issue obviously) and iOS to print at least something for tests/development purposes.

[adamsitnik]

I've added 5.0.0 milestone as there is a PR (#37078) that should solve this issue.

[rolfbjarne]

This also means that WriteLines might be split up.

Example output:

❌ EXCEPTION: System.Inva
lidOperationException: XmlSerializeErrorDetails, 0, 0
 ---> System.ExecutionEngineException: Attempting to JIT compile method 'void Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializerContract:.ctor ()' while running in aot-only mode. See https://do
cs.microsoft.com/xamarin/ios/internals/limitations for more information.

   at System.Reflection.RuntimeConstructorInfo.InternalInvoke(Object , Object[] , Boolean ) in System.Private.CoreLib.dll:token 0x600269a+0x5
   Exception_EndOfInnerExceptionStack
  
 at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader , String , XmlDeserializationEvents ) in System.Private.Xml.dll:token 0x6001b05+0x10d
   at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader , String ) in System.Private.Xml.dll:t
oken 0x6001b04+0x0
   at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader ) in System.Private.Xml.dll:token 0x6001b02+0x0
   at MySimpleApp.Program.XmlSerializationTest.Response.Deserialize(String xml) in /Users/rolf/work/maccore/main/xamarin-m
acios/tests/dotnet/MySimpleApp/AppDelegate.cs:line 67
   at MySimpleApp.Program.XmlSerializationTest.Bug1820_GenericList() in /Users/rolf/work/maccore/main/xamarin-macios/tests/dotnet/MySimpleApp/AppDelegate.cs:line 184
   at MySimpleApp.Program.Main(Strin
g[] args) in /Users/rolf/work/maccore/main/xamarin-macios/tests/dotnet/MySimpleApp/AppDelegate.cs:line 22

The correct output is:

❌ EXCEPTION: System.InvalidOperationException: XmlSerializeErrorDetails, 0, 0
 ---> System.ExecutionEngineException: Attempting to JIT compile method 'void Microsoft.Xml.Serialization.GeneratedAssembly.XmlSerializerContract:.ctor ()' while running in aot-only mode. See https://docs.microsoft.com/xamarin/ios/internals/limitations for more information.

   at System.Reflection.RuntimeConstructorInfo.InternalInvoke(Object , Object[] , Boolean ) in System.Private.CoreLib.dll:token 0x600269a+0x5
   Exception_EndOfInnerExceptionStack
   at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader , String , XmlDeserializationEvents ) in System.Private.Xml.dll:token 0x6001b05+0x10d
   at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader , String ) in System.Private.Xml.dll:token 0x6001b04+0x0
   at System.Xml.Serialization.XmlSerializer.Deserialize(XmlReader ) in System.Private.Xml.dll:token 0x6001b02+0x0
   at MySimpleApp.Program.XmlSerializationTest.Response.Deserialize(String xml) in /Users/rolf/work/maccore/main/xamarin-macios/tests/dotnet/MySimpleApp/AppDelegate.cs:line 67
   at MySimpleApp.Program.XmlSerializationTest.Bug1820_GenericList() in /Users/rolf/work/maccore/main/xamarin-macios/tests/dotnet/MySimpleApp/AppDelegate.cs:line 184
   at MySimpleApp.Program.Main(String[] args) in /Users/rolf/work/maccore/main/xamarin-macios/tests/dotnet/MySimpleApp/AppDelegate.cs:line 22

This is because the call to WriteLine might be composed of multiple calls to Write:

(lldb) p/x $x0
(unsigned long) $11 = 0x000000016b28a310
(lldb) p (char16_t *) 0x000000016b28a310
(char16_t *) $12 = 0x000000016b28a310 u"❌ EXCEPTION: System.Inva"
(lldb) bt
* thread #1, name = 'tid_303', queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
  * frame #0: 0x0000000106df3cb4 MySimpleApp`SystemNative_Log(buffer="L' ", length=48) at pal_log.m:9:22 [opt]
    frame #1: 0x0000000104c2c9cc MySimpleApp`wrapper_managed_to_native_Interop_Sys_Log_byte__int(param0=6092792592, param1=48) at <unknown>:1
    frame #2: 0x0000000104c29b18 MySimpleApp`System_NSLogStream_Write_System_ReadOnlySpan_1_byte(this=<unavailable>, param0=1797825296) at <unknown>:1
    frame #3: 0x00000001066a0fc0 MySimpleApp`System_IO_StreamWriter_Flush_bool_bool at <unknown>:1
    frame #4: 0x00000001066a23a8 MySimpleApp`System_IO_StreamWriter_WriteSpan_System_ReadOnlySpan_1_char_bool at <unknown>:1
    frame #5: 0x00000001066a2af0 MySimpleApp`System_IO_StreamWriter_WriteFormatHelper_string_System_ParamsArray_bool at <unknown>:1
    frame #6: 0x00000001066a2d18 MySimpleApp`System_IO_StreamWriter_WriteLine_string_object at <unknown>:1
    frame #7: 0x00000001066acaf4 MySimpleApp`System_IO_TextWriter_SyncTextWriter_WriteLine_string_object at <unknown>:1
    frame #8: 0x0000000106aa2938 MySimpleApp`wrapper_synchronized_System_IO_TextWriter_SyncTextWriter_WriteLine_string_object at <unknown>:1
    frame #9: 0x0000000104c29888 MySimpleApp`System_Console_WriteLine_string_object(param0=0x000000010c90c130, param1=0x000000010976ad68) at <unknown>:1
    frame #10: 0x0000000104b781f8 MySimpleApp`MySimpleApp_Program_Main_string__(args=0x0000000109702be0) at AppDelegate.cs:25
    frame #11: 0x0000000106a82940 MySimpleApp`wrapper_runtime_invoke_object_runtime_invoke_dynamic_intptr_intptr_intptr_intptr at <unknown>:1
    frame #12: 0x00000001070ac1b0 MySimpleApp`mono_jit_runtime_invoke(method=<unavailable>, obj=<unavailable>, params=<unavailable>, exc=<unavailable>, error=0x000000016b28b130) at mini-runtime.c:3409:3 [opt]
    frame #13: 0x0000000106fe4154 MySimpleApp`mono_runtime_invoke_checked [inlined] do_runtime_invoke(method=0x000000011fd247a8, obj=0x0000000000000000, params=0x000000016b28b0d0, exc=0x0000000000000000, error=0x000000016b28b130) at object.c:2388:11 [opt]
    frame #14: 0x0000000106fe4118 MySimpleApp`mono_runtime_invoke_checked(method=0x000000011fd247a8, obj=0x0000000000000000, params=0x000000016b28b0d0, error=0x000000016b28b130) at object.c:2556:9 [opt]
    frame #15: 0x0000000106feaba8 MySimpleApp`mono_runtime_exec_main_checked [inlined] do_exec_main_checked(method=0x000000011fd247a8, args=<unavailable>, error=0x000000016b28b130) at object.c:0 [opt]
    frame #16: 0x0000000106feab6c MySimpleApp`mono_runtime_exec_main_checked(method=0x000000011fd247a8, args=<unavailable>, error=0x000000016b28b130) at object.c:4498:9 [opt]
    frame #17: 0x0000000106feac54 MySimpleApp`mono_runtime_run_main_checked(method=<unavailable>, argc=<unavailable>, argv=<unavailable>, error=<unavailable>) at object.c:4062:9 [opt] [artificial]
    frame #18: 0x00000001070b1c3c MySimpleApp`mono_jit_exec at driver.c:1384:13 [opt]
    frame #19: 0x00000001070b1c2c MySimpleApp`mono_jit_exec(domain=<unavailable>, assembly=<unavailable>, argc=1, argv=0x000000016b28b1b0) at driver.c:1329:7 [opt]
    frame #20: 0x0000000106da3034 MySimpleApp`xamarin_main(argc=1, argv=0x000000016b28bb40, launch_mode=XamarinLaunchModeApp) at monotouch-main.m:485:8
    frame #21: 0x000000010712a13c MySimpleApp`main(argc=1, argv=0x000000016b28bb40) at main.arm64.mm:136:11
    frame #22: 0x0000000183395fc0 libdyld.dylib`start + 4

This is quite annoying when reading logs.

@steveisok any idea when this could be fixed?

[steveisok]

@rolfbjarne this will be addressed before RC.

[am11]

Is using NSLog important on iOS or can we use fprintf(stderr, ... instead (which will simplify implementation and make it efficient)?
https://stackoverflow.com/questions/9006801/difference-between-nslog-and-printf-statement-for-objectivec#answer-9006877

[rolfbjarne]

Yes, using NSLog is important, because iOS will close stderr/stdout, and the output is lost. NSLog however will still work, and app users can get that output and show it to app developers if required to debug a particularly complicated issue.