Notice (2018-05-24): bugzilla.xamarin.com is now in
Please join us on
Visual Studio Developer Community and in the
Mono organizations on
GitHub to continue tracking issues. Bugzilla will remain
available for reference in read-only mode. We will continue to work
on open Bugzilla bugs, copy them to the new locations
as needed for follow-up, and add the new items under Related
Our sincere thanks to everyone who has contributed on this bug
tracker over the years. Thanks also for your understanding as we
make these adjustments and improvements for the future.
Please create a new report on
Developer Community with
your current version information, steps to reproduce, and relevant error
messages or log files if you are hitting an issue that looks similar to
this resolved bug and you do not yet see a matching new report.
Time profiling not working for latest versions of profiler, from 0.34 to 0.38.
The column "Running Time" is mostly 0. Even after using "heavy" method, that takes most of time, several times it still displayed - Running Time 0.
Visual Studion 15, Update 3,
Xamarin Profiler 0.38
Can you please share the resulting MLPD (File->Save as after you've profiled the app)?
After some research I noticed that the information of profiler is not always updated. After using some (not always same) action it might to take 20-30 seconds untill show and update this action in Profiler.
In this file I used search action - RecordListViewModel:search, but it's not even displayed in profiler.
I see you are using '1000' as the sample cycle frequency, which was the old default we had, so can you change it (in the app's preferences) to 100 and see if it gets any better?
This is the mprof-report output on that MLPD, and indeed seems we're getting too few samples, which probably is because of the '1000' value in sample cycle frequency.
Mono log profiler data
Profiler version: 1.0
Data version: 13
Operating system: linux
Mean timer overhead: 550 nanoseconds
Program startup: Tue Oct 18 11:54:15 2016
Program ID: 22220
Server listening on: 49230
Compiled methods: 7730
Generated code size: 1905286
JIT helpers: 16677
JIT helpers code size: 1917279
GC resizes: 0
Max heap size: 0
Object moves: 251396
Gen0 collections: 7, max time: 25481us, total time: 87178us, average: 12454us
GC handles weak: created: 633, destroyed: 358, max: 579
GC handles weaktrack: created: 1944, destroyed: 454, max: 1490
GC handles normal: created: 2, destroyed: 0, max: 2
Statistical samples summary
Sample type: cycles
Unmanaged hits: 2548 (98.8%)
Managed hits: 32 ( 1.2%)
Unresolved hits: 223 ( 8.6%)
Hits % Method name
1927 74.69 syscall
107 4.15 clock_gettime
93 3.60 gettimeofday
25 0.97 read
9 0.35 mono_metadata_type_hash
9 0.35 pthread_mutex_lock
7 0.27 fstatat
6 0.23 pthread_mutex_unlock
6 0.23 strcmp
5 0.19 Java.Interop.JniEnvironment/Object:AllocObject (Java.Interop.JniObjectReference)
5 0.19 mono_metadata_decode_row_col
5 0.19 memcpy
5 0.19 _ZN3art11ScopedCheck18CheckVirtualMethodEP8_jobjectP10_jmethodID
4 0.16 System.Security.Cryptography.RijndaelManagedTransform:Dec (int*,int*,int*,int*,int*,int*)
4 0.16 memset
4 0.16 strlen
4 0.16 _ZN3art6mirror5Class25FindDeclaredVirtualMethodERKNS_11StringPieceES4_
4 0.16 artQuickToInterpreterBridge
4 0.16 mono_metadata_get_inflated_signature
4 0.16 madvise
3 0.12 System.Threading.Timer/Scheduler:SchedulerThread ()
3 0.12 __epoll_pwait
3 0.12 pthread_mutex_trylock
3 0.12 mono_class_enum_basetype
3 0.12 mono_metadata_decode_row
3 0.12 mono_error_init
3 0.12 pthread_mutex_unlock
3 0.12 sched_yield
3 0.12 pread64
3 0.12 munmap
3 0.12 pthread_mutex_lock
3 0.12 __ioctl
So please try again after changing it to 100.
I don't have any "sample cycle frequency" in Profiler options. What I have is:
Tools -> Options -> Sampling:
1. Samples per Second: 10
2. Max Frames: 8
3. Call Depth: 100
I think what you mean is Samples per Second. I set it to 10000 and this is what I got:
In profiler search toolbar I entered "search" string and noticed that some of actions are 0 running time. Also some actions still missing and appears in profiler only after using them several times.
Yes, the label is wrong, sorry. We have it fixed internally and will be released publicly soon, but what that value is referring to is the interval between samples, so if you set it to 10,000 you'll get many less samples, as between samples it would wait 10,000 microseconds.
With 10,000, you get even less samples than before:
Statistical samples summary
Sample type: cycles
Unmanaged hits: 12014 (98.9%)
Managed hits: 132 ( 1.1%)
Unresolved hits: 557 ( 4.6%)
Hits % Method name
10128 83.39 syscall
537 4.42 clock_gettime
254 2.09 gettimeofday
112 0.92 read
20 0.16 madvise
13 0.11 Mono.Globalization.Unicode.SimpleCollator:GetContraction (string,int,int,Mono.Globalization.Unicode.Contraction)
13 0.11 fstatat
So whatever the label says, please set it to 100 and try again.
It seems like changing this parametr makes no difference.
Search action still not visible here:
After waiting about 20 seconds and doing nothing in application I got this:
In both runs, you're still using 1000 for 'sample cycle frequency':
ardones:profiler rodrigo$ mprof-report ~/Public/sampling100.mlpd | grep Arguments
ardones:profiler rodrigo$ mprof-report ~/Public/sampling100_2.mlpd | grep Arguments
so please make sure you change it in the preferences dialog before starting to profile.
What I see in Profiler options:
Samples per Second: 100
can you check in regedit.exe, what the value of SamplesPerSecond key in HKEY_CURRENT_USER\SOFTWARE\Xamarin\Profiler is after having changed the setting?
Ok, this is a bug we have, already fixed internally, but not on the build you have, so:
* change the setting to 100 in the options dialog
* exit the profiler
* start profiling again as before
The bug is that the options dialog was not saving the changes.
It seems that this parameter has no affect, still have same issue after changing it to 100.
Is there something new for this bug?
Currently I can't use the profiler but I very need to.
@Rodrigo, I have checked this issue with Profiler v1.0.0-12 and getting same issue after setting 'sample cycle frequency' to 100.
Profiler Log: https://gist.github.com/Asimk360/3db62bc0df5f5333ce5d8d4286c03337
@Prashant you are not getting '0 ms', there is one node in the call tree that has 5k ms
Dima, is it working better with the 1.0.x profiler versions?
In fact it is not. Still has '0 ms' issue.
1. Profiler stacks in Time Profile mode from time to time and I have to start profiling from scratch.
2. On image time of Time Profiler total time and total time of profiler are different.
Sorry, I put wrong mlpd.
'0 ms' issue is still reproduced.
Some of records has '0 ms' and some of them has > 0 values.
Ok, this is showing at least some data, so it looks a lot like the runtime profiler is not dumping its samples buffer or not giving us enough samples.
I'll mark it as duplicated of bug #51485
*** This bug has been marked as a duplicate of bug 51485 ***