[Mono-dev] Unexpected Delays in P/Invoke

[Miguel de Icaza]

Time the C calls, it is possible that close is flushing the data and is not
returning until that happebs
On Sat, Apr 23, 2016 at 9:33 AM Jason Curl <jcurlnews at arcor.de> wrote:

> I've tested the latest snapshot of Mono and the problem remains:
>
> Mono JIT compiler version 4.5.0 (Nightly 4.5.0.421/c5789eb Thu Mar 24
> 18:42:59 UTC 2016)
> Copyright (C) 2002-2014 Novell, Inc, Xamarin Inc and Contributors.
> www.mono-project.com
>      TLS:           __thread
>      SIGSEGV:       altstack
>      Notifications: epoll
>      Architecture:  amd64
>      Disabled:      none
>      Misc:          softdebug
>      LLVM:          supported, not enabled.
>      GC:            sgen
>
> nUnit-gui now works properly (4.2.3.4 would hang when trying to close)
> and using MONO debug variables (MONO_LOG_MASK="dll";
> MONO_LOG_LEVEL="debug", I can see that the method "serial_close" is
> called at the correct time, but I don't see any other activity while
> blocked.
>
> Mono: DllImport searching in: 'nserial' ('libnserial.so').
> Mono: Searching for 'serial_close'.
> Mono: Probing 'serial_close'.
> Mono: Found as 'serial_close'.
>
> PAUSE FOR 6 SECONDS
>
> Mono: DllImport searching in: 'nserial' ('libnserial.so').
> Mono: Searching for 'serial_read'.
> Mono: Probing 'serial_read'.
> Mono: Found as 'serial_read'.
> Mono: DllImport searching in: 'nserial' ('libnserial.so').
> Mono: Searching for 'serial_terminate'.
> Mono: Probing 'serial_terminate'.
> Mono: Found as 'serial_terminate'.
>
> Any help is appreciated.
>
> On 22.04.2016 23:37, Jason Curl wrote:
> > I've generally got my library working
> > (github.com/jcurl/serialportstream) on Linux with Mono 4.2.3.4 from
> > the Xamarin repositories on Ubuntu 16.04, with one small problem.
> >
> > One new test case (ClosedWhenBlocked) takes 6923ms for a simple
> > close() function using marshalling, where the function in C only needs
> > 22ms. It's called twice (there's two instances), the second is
> > effectively instantaneous. On my machine, the issue is 100%
> > reproducible. My C code and .NET is OK (as far as I can tell) and
> > appears to be some blocking behaviour in the Marshalling code of the
> > .NET framework. How can I debug further if it's me or .NET?
> >
> > Note, I can't compare on Windows as it's Linux specific code.
> >
> >
> > Closing serialSource
> > ...
> > --> serial_close(140601190288768)   => 0x7FE044008D80
> > ...
> > -->  serial_close(140601190288768) took 6916 ms
> > IO.Ports.SerialPortStream Verbose: 0 : -->
> > serial_close(140601190288768) took 6916 ms
> > ...
> > Closed serialSource after 6923 ms
> > ...
> > --> serial_close(140601190278688)  => 0x7FE044006620
> > -->  serial_close(140601190278688) took 0 ms
> > -->  serial_close(140601190278688) took 0 ms
> >
> >
> >
> > The code in question is
> >         [DllImport("nserial", EntryPoint="serial_close",
> > SetLastError=true)]
> >         private static extern int nserial_close(IntPtr handle);
> >         public int serial_close(IntPtr handle)
> >         {
> >             System.Diagnostics.Stopwatch sw = new
> > System.Diagnostics.Stopwatch();
> >             sw.Start();
> >             Console.WriteLine("--> serial_close({0})", handle);
> >             int result = nserial_close(handle);
> >             Console.WriteLine("-->  serial_close({0}) took {1} ms",
> > handle, sw.ElapsedMilliseconds);
> >             errno = Marshal.GetLastWin32Error();
> >             Console.WriteLine("-->  serial_close({0}) took {1} ms",
> > handle, sw.ElapsedMilliseconds);
> >             return result;
> >         }
> >
> > I added diagnostics to my C code to write performance data to disk and
> > it is:
> > c: serial_close(handle=0x7fe044008d80)
> > c: serial_close(handle=0x7fe044008d80) fd=4
> > c: serial_close(handle=0x7fe044008d80) flushbuffer elapsed=0,005000
> > c: serial_close(handle=0x7fe044008d80) close(prfd) elapsed=0,028000
> > c: serial_close(handle=0x7fe044008d80) close(pwfd) elapsed=0,046000
> > c: serial_close(handle=0x7fe044008d80) close(fd) elapsed=21,530000
> > c: serial_close(handle=0x7fe044006620)
> > c: serial_close(handle=0x7fe044006620) fd=14
> > c: serial_close(handle=0x7fe044006620) flushbuffer elapsed=0,004000
> > c: serial_close(handle=0x7fe044006620) close(prfd) elapsed=0,048000
> > c: serial_close(handle=0x7fe044006620) close(pwfd) elapsed=0,062000
> > c: serial_close(handle=0x7fe044006620) close(fd) elapsed=0,066000
> >
> > _______________________________________________
> > Mono-devel-list mailing list
> > Mono-devel-list at lists.ximian.com
> > http://lists.ximian.com/mailman/listinfo/mono-devel-list
> >
>
> _______________________________________________
> Mono-devel-list mailing list
> Mono-devel-list at lists.ximian.com
> http://lists.ximian.com/mailman/listinfo/mono-devel-list
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ximian.com/pipermail/mono-devel-list/attachments/20160423/e0a3e3a3/attachment.html>