Re: [Mono-dev] Running --profiler=log:coverage

[Antoine Cailliau]

Great.

Let me know if you need something or if I can help.

Antoine

On 3 March 2016 at 17:10, Iain Holmes  wrote:

> Hi,
>
> Yes, I’ll have a look into it now.
>
> iain
>
> > On 3 Mar 2016, at 2:44 pm, Alex Rønne Petersen  wrote:
> >
> > Hi,
> >
> > The "time went backwards" message is harmless and has been removed in
> > later Mono versions.
> >
> > Could you have a look at the crash, Iain? (cc)
> >
> > On Thu, Mar 3, 2016 at 2:00 PM, Antoine Cailliau
> >  wrote:
> >> Hello,
> >>
> >> I'm trying to measure the code coverage of a test suite. I noticed that
> >> recently (Apr'15) cov and monocov were removed for log:coverage
> profiler.
> >>
> >> When I'm running that profile on my tests using nunit-console. I got a
> >> segmentation fault, see below. When using mprof-report, I do not get the
> >> section related to code coverage.
> >>
> >> What I use to run the tests :
> >> $ MONO_OPTIONS="--profile=log:coverage,covfilter=+MinePumpSystem.Test"
> >> nunit-console MinePumpSystem.Test.dll
> >>
> >> Plus, it is displaying "time went backwards" a lot.
> >>
> >> Anyone with any tips on how I could get this to work is welcome :-)
> >>
> >> Regards,
> >>
> >> Antoine
> >>
> >> -- The trace :
> >>
> >> tacktrace:
> >>
> >>
> >> Native stacktrace:
> >>
> >>
> >> Debug info from gdb:
> >>
> >> (lldb) command source -s 0 '/tmp/mono-gdb-commands.2cpqir'
> >> Executing commands in '/tmp/mono-gdb-commands.2cpqir'.
> >> (lldb) process attach --pid 47647
> >> warning: (i386)
> >>
> /Library/Frameworks/Mono.framework/Versions/4.2.2/lib/mono/4.5/mscorlib.dll.dylib
> >> empty dSYM file detected, dSYM was created with an executable with no
> debug
> >> info.
> >> Process 47647 stopped
> >> * thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4
> +
> >> 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
> >>frame #0: 0x92bb6d06 libsystem_kernel.dylib`__wait4 + 10
> >> libsystem_kernel.dylib`__wait4:
> >> ->  0x92bb6d06 <+10>: jae0x92bb6d16; <+26>
> >>0x92bb6d08 <+12>: calll  0x92bb6d0d; <+17>
> >>0x92bb6d0d <+17>: popl   %edx
> >>0x92bb6d0e <+18>: movl   0x104be317(%edx), %edx
> >>
> >> Executable module set to
> >> "/Library/Frameworks/Mono.framework/Versions/4.2.2/bin/mono".
> >> Architecture set to: i386-apple-macosx.
> >> (lldb) thread list
> >> Process 47647 stopped
> >> * thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4
> +
> >> 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
> >>  thread #2: tid = 0x109c47a, 0x92bb6402
> >> libsystem_kernel.dylib`__psynch_cvwait + 10
> >>  thread #3: tid = 0x109c47b, 0x92baf886
> >> libsystem_kernel.dylib`semaphore_wait_trap + 10
> >>  thread #4: tid = 0x109c47c, 0x92bb6d76
> >> libsystem_kernel.dylib`__workq_kernreturn + 10
> >>  thread #5: tid = 0x109c47d, 0x92bb7812
> libsystem_kernel.dylib`kevent_qos +
> >> 10, queue = 'com.apple.libdispatch-manager'
> >>  thread #6: tid = 0x109c47e, 0x0027008d mono`mono_hazard_pointer_get +
> 13
> >> at hazard-pointer.c:176
> >>  thread #7: tid = 0x109c482, 0x92bb6d76
> >> libsystem_kernel.dylib`__workq_kernreturn + 10
> >>  thread #8: tid = 0x109c484, 0x92bb6d76
> >> libsystem_kernel.dylib`__workq_kernreturn + 10
> >> (lldb) thread backtrace all
> >> mono was compiled with optimization - stepping may behave oddly;
> variables
> >> may not be available.
> >> * thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4
> +
> >> 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
> >>  * frame #0: 0x92bb6d06 libsystem_kernel.dylib`__wait4 + 10
> >>frame #1: 0x969f07dc libsystem_c.dylib`waitpid$UNIX2003 + 48
> >>frame #2: 0x000d7f2d mono`mono_handle_native_sigsegv(signal=11,
> >> ctx=0x007abfe0, info=0x007abfa0) + 541 at mini-exceptions.c:2193 [opt]
> >>frame #3: 0x00124482
> >> mono`mono_arch_handle_altstack_exception(sigctx=,
> >> siginfo=, fault_addr=, stack_ovf=0) + 162 at
> >> exceptions-x86.c:1097 [opt]
> >>frame #4: 0x0002540e
> >> mono`mono_sigsegv_signal_handler(_dummy=,
> _info=,
> >> context=) + 446 at mini-runtime.c:2471 [opt]
> >>frame #5: 0x9aad301b libsystem_platform.dylib`_sigtramp + 43
> >>frame #6: 0x96973051 libsystem_c.dylib`strlen + 17
> >>frame #7: 0x00690b48
> >> libmono-profiler-log.0.dylib`build_assembly_buffer(key=0x79962860,
> >> value=0x79962860, userdata=) + 216 at proflog.c:3514 [opt]
> >>frame #8: 0x00277150
> >> mono`mono_conc_hashtable_foreach(hash_table=,
> >> func=, userdata=) + 80 at
> >> mono-conc-hashtable.c:365 [opt]
> >>frame #9: 0x0068520a libmono-profiler-log.0.dylib`log_shutdown
> [inlined]
> >> dump_coverage(prof=0x79960ba0) + 92 at proflog.c:3544 [opt]
> >>frame #10: 0x006851ae
> >> libmono-profiler-log.0.dylib`log_shutdown(prof=0x79960ba0) + 46 at
> >> proflog.c:3851 [opt]
> >>frame #11: 0x001b7262 mono`mono_profiler_shutdown + 50 at
> 

Re: [Mono-dev] Running --profiler=log:coverage

[Alex Rønne Petersen]

Hi,

The "time went backwards" message is harmless and has been removed in
later Mono versions.

Could you have a look at the crash, Iain? (cc)

On Thu, Mar 3, 2016 at 2:00 PM, Antoine Cailliau
 wrote:
> Hello,
>
> I'm trying to measure the code coverage of a test suite. I noticed that
> recently (Apr'15) cov and monocov were removed for log:coverage profiler.
>
> When I'm running that profile on my tests using nunit-console. I got a
> segmentation fault, see below. When using mprof-report, I do not get the
> section related to code coverage.
>
> What I use to run the tests :
> $ MONO_OPTIONS="--profile=log:coverage,covfilter=+MinePumpSystem.Test"
> nunit-console MinePumpSystem.Test.dll
>
> Plus, it is displaying "time went backwards" a lot.
>
> Anyone with any tips on how I could get this to work is welcome :-)
>
> Regards,
>
> Antoine
>
> -- The trace :
>
> tacktrace:
>
>
> Native stacktrace:
>
>
> Debug info from gdb:
>
> (lldb) command source -s 0 '/tmp/mono-gdb-commands.2cpqir'
> Executing commands in '/tmp/mono-gdb-commands.2cpqir'.
> (lldb) process attach --pid 47647
> warning: (i386)
> /Library/Frameworks/Mono.framework/Versions/4.2.2/lib/mono/4.5/mscorlib.dll.dylib
> empty dSYM file detected, dSYM was created with an executable with no debug
> info.
> Process 47647 stopped
> * thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4 +
> 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
> frame #0: 0x92bb6d06 libsystem_kernel.dylib`__wait4 + 10
> libsystem_kernel.dylib`__wait4:
> ->  0x92bb6d06 <+10>: jae0x92bb6d16; <+26>
> 0x92bb6d08 <+12>: calll  0x92bb6d0d; <+17>
> 0x92bb6d0d <+17>: popl   %edx
> 0x92bb6d0e <+18>: movl   0x104be317(%edx), %edx
>
> Executable module set to
> "/Library/Frameworks/Mono.framework/Versions/4.2.2/bin/mono".
> Architecture set to: i386-apple-macosx.
> (lldb) thread list
> Process 47647 stopped
> * thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4 +
> 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
>   thread #2: tid = 0x109c47a, 0x92bb6402
> libsystem_kernel.dylib`__psynch_cvwait + 10
>   thread #3: tid = 0x109c47b, 0x92baf886
> libsystem_kernel.dylib`semaphore_wait_trap + 10
>   thread #4: tid = 0x109c47c, 0x92bb6d76
> libsystem_kernel.dylib`__workq_kernreturn + 10
>   thread #5: tid = 0x109c47d, 0x92bb7812 libsystem_kernel.dylib`kevent_qos +
> 10, queue = 'com.apple.libdispatch-manager'
>   thread #6: tid = 0x109c47e, 0x0027008d mono`mono_hazard_pointer_get + 13
> at hazard-pointer.c:176
>   thread #7: tid = 0x109c482, 0x92bb6d76
> libsystem_kernel.dylib`__workq_kernreturn + 10
>   thread #8: tid = 0x109c484, 0x92bb6d76
> libsystem_kernel.dylib`__workq_kernreturn + 10
> (lldb) thread backtrace all
> mono was compiled with optimization - stepping may behave oddly; variables
> may not be available.
> * thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4 +
> 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
>   * frame #0: 0x92bb6d06 libsystem_kernel.dylib`__wait4 + 10
> frame #1: 0x969f07dc libsystem_c.dylib`waitpid$UNIX2003 + 48
> frame #2: 0x000d7f2d mono`mono_handle_native_sigsegv(signal=11,
> ctx=0x007abfe0, info=0x007abfa0) + 541 at mini-exceptions.c:2193 [opt]
> frame #3: 0x00124482
> mono`mono_arch_handle_altstack_exception(sigctx=,
> siginfo=, fault_addr=, stack_ovf=0) + 162 at
> exceptions-x86.c:1097 [opt]
> frame #4: 0x0002540e
> mono`mono_sigsegv_signal_handler(_dummy=, _info=,
> context=) + 446 at mini-runtime.c:2471 [opt]
> frame #5: 0x9aad301b libsystem_platform.dylib`_sigtramp + 43
> frame #6: 0x96973051 libsystem_c.dylib`strlen + 17
> frame #7: 0x00690b48
> libmono-profiler-log.0.dylib`build_assembly_buffer(key=0x79962860,
> value=0x79962860, userdata=) + 216 at proflog.c:3514 [opt]
> frame #8: 0x00277150
> mono`mono_conc_hashtable_foreach(hash_table=,
> func=, userdata=) + 80 at
> mono-conc-hashtable.c:365 [opt]
> frame #9: 0x0068520a libmono-profiler-log.0.dylib`log_shutdown [inlined]
> dump_coverage(prof=0x79960ba0) + 92 at proflog.c:3544 [opt]
> frame #10: 0x006851ae
> libmono-profiler-log.0.dylib`log_shutdown(prof=0x79960ba0) + 46 at
> proflog.c:3851 [opt]
> frame #11: 0x001b7262 mono`mono_profiler_shutdown + 50 at profiler.c:813
> [opt]
> frame #12: 0x0002861a mono`mini_cleanup(domain=0x79863ce0) + 778 at
> mini-runtime.c:3455 [opt]
> frame #13: 0x000a2f61 mono`mono_main(argc=,
> argv=) + 8001 at driver.c:2083 [opt]
> frame #14: 0x0001ab50 mono`main [inlined]
> mono_main_with_options(argc=, argv=) + 768 at
> main.c:94 [opt]
> frame #15: 0x0001a86d mono`main(argc=, argv=)
> + 29 at main.c:125 [opt]
> frame #16: 0x0001a845 mono`start + 53
>
>   thread #2: tid = 0x109c47a, 0x92bb6402
> libsystem_kernel.dylib`__psynch_cvwait + 10
> frame #0: 0x92bb6402 libsystem_kernel.dylib`__psynch_cvwait + 10
> frame 

[Mono-dev] Running --profiler=log:coverage

[Antoine Cailliau]

Hello,

I'm trying to measure the code coverage of a test suite. I noticed that
recently (Apr'15) cov and monocov were removed for log:coverage profiler.

When I'm running that profile on my tests using nunit-console. I got a
segmentation fault, see below. When using mprof-report, I do not get the
section related to code coverage.

What I use to run the tests :
$ MONO_OPTIONS="--profile=log:coverage,covfilter=+MinePumpSystem.Test"
nunit-console MinePumpSystem.Test.dll

Plus, it is displaying "time went backwards" a lot.

Anyone with any tips on how I could get this to work is welcome :-)

Regards,

Antoine

-- The trace :

tacktrace:


Native stacktrace:


Debug info from gdb:

(lldb) command source -s 0 '/tmp/mono-gdb-commands.2cpqir'
Executing commands in '/tmp/mono-gdb-commands.2cpqir'.
(lldb) process attach --pid 47647
warning: (i386)
/Library/Frameworks/Mono.framework/Versions/4.2.2/lib/mono/4.5/mscorlib.dll.dylib
empty dSYM file detected, dSYM was created with an executable with no debug
info.
Process 47647 stopped
* thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4 +
10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
frame #0: 0x92bb6d06 libsystem_kernel.dylib`__wait4 + 10
libsystem_kernel.dylib`__wait4:
->  0x92bb6d06 <+10>: jae0x92bb6d16; <+26>
0x92bb6d08 <+12>: calll  0x92bb6d0d; <+17>
0x92bb6d0d <+17>: popl   %edx
0x92bb6d0e <+18>: movl   0x104be317(%edx), %edx

Executable module set to
"/Library/Frameworks/Mono.framework/Versions/4.2.2/bin/mono".
Architecture set to: i386-apple-macosx.
(lldb) thread list
Process 47647 stopped
* thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4 +
10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  thread #2: tid = 0x109c47a, 0x92bb6402
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #3: tid = 0x109c47b, 0x92baf886
libsystem_kernel.dylib`semaphore_wait_trap + 10
  thread #4: tid = 0x109c47c, 0x92bb6d76
libsystem_kernel.dylib`__workq_kernreturn + 10
  thread #5: tid = 0x109c47d, 0x92bb7812 libsystem_kernel.dylib`kevent_qos
+ 10, queue = 'com.apple.libdispatch-manager'
  thread #6: tid = 0x109c47e, 0x0027008d mono`mono_hazard_pointer_get + 13
at hazard-pointer.c:176
  thread #7: tid = 0x109c482, 0x92bb6d76
libsystem_kernel.dylib`__workq_kernreturn + 10
  thread #8: tid = 0x109c484, 0x92bb6d76
libsystem_kernel.dylib`__workq_kernreturn + 10
(lldb) thread backtrace all
mono was compiled with optimization - stepping may behave oddly; variables
may not be available.
* thread #1: tid = 0x109c479, 0x92bb6d06 libsystem_kernel.dylib`__wait4 +
10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
  * frame #0: 0x92bb6d06 libsystem_kernel.dylib`__wait4 + 10
frame #1: 0x969f07dc libsystem_c.dylib`waitpid$UNIX2003 + 48
frame #2: 0x000d7f2d mono`mono_handle_native_sigsegv(signal=11,
ctx=0x007abfe0, info=0x007abfa0) + 541 at mini-exceptions.c:2193 [opt]
frame #3: 0x00124482
mono`mono_arch_handle_altstack_exception(sigctx=,
siginfo=, fault_addr=, stack_ovf=0) + 162 at
exceptions-x86.c:1097 [opt]
frame #4: 0x0002540e
mono`mono_sigsegv_signal_handler(_dummy=, _info=,
context=) + 446 at mini-runtime.c:2471 [opt]
frame #5: 0x9aad301b libsystem_platform.dylib`_sigtramp + 43
frame #6: 0x96973051 libsystem_c.dylib`strlen + 17
frame #7: 0x00690b48
libmono-profiler-log.0.dylib`build_assembly_buffer(key=0x79962860,
value=0x79962860, userdata=) + 216 at proflog.c:3514 [opt]
frame #8: 0x00277150
mono`mono_conc_hashtable_foreach(hash_table=,
func=, userdata=) + 80 at
mono-conc-hashtable.c:365 [opt]
frame #9: 0x0068520a libmono-profiler-log.0.dylib`log_shutdown
[inlined] dump_coverage(prof=0x79960ba0) + 92 at proflog.c:3544 [opt]
frame #10: 0x006851ae
libmono-profiler-log.0.dylib`log_shutdown(prof=0x79960ba0) + 46 at
proflog.c:3851 [opt]
frame #11: 0x001b7262 mono`mono_profiler_shutdown + 50 at
profiler.c:813 [opt]
frame #12: 0x0002861a mono`mini_cleanup(domain=0x79863ce0) + 778 at
mini-runtime.c:3455 [opt]
frame #13: 0x000a2f61 mono`mono_main(argc=,
argv=) + 8001 at driver.c:2083 [opt]
frame #14: 0x0001ab50 mono`main [inlined]
mono_main_with_options(argc=, argv=) + 768 at
main.c:94 [opt]
frame #15: 0x0001a86d mono`main(argc=, argv=)
+ 29 at main.c:125 [opt]
frame #16: 0x0001a845 mono`start + 53

  thread #2: tid = 0x109c47a, 0x92bb6402
libsystem_kernel.dylib`__psynch_cvwait + 10
frame #0: 0x92bb6402 libsystem_kernel.dylib`__psynch_cvwait + 10
frame #1: 0x95c80f6b libsystem_pthread.dylib`_pthread_cond_wait + 757
frame #2: 0x95c84cc0 libsystem_pthread.dylib`pthread_cond_wait$UNIX2003
+ 71
frame #3: 0x0024b7e2 mono`thread_func(thread_data=0x) + 466 at
sgen-thread-pool.c:118 [opt]
frame #4: 0x95c80a26 libsystem_pthread.dylib`_pthread_body + 138
frame #5: 0x95c8099c libsystem_pthread.dylib`_pthread_start + 155
frame #6: 0x95c7df96