namhyung / uftrace

Function graph tracer for C/C++/Rust/Python
https://uftrace.github.io/slide/
GNU General Public License v2.0
3.01k stars 442 forks source link

Improving possibilities for efficient data analysis #1320

Open elfring opened 3 years ago

elfring commented 3 years ago

I tried the program „uftrace 0.10-53-gb001“ out together with the installation program „calamares 3.2.42.20210826-b9f22a75-dirty“ (for example). I let this software combination run with a trace record command for a few hours until I noticed that the installation program reached a processing step after which this data determination attempt could be terminated. My multi-core processor was only partly utilised during this test run. The following command pointed an interesting result out for the storage allocation from such a recording.

[Markus_Elfring@fedora calamares]$ du -h uftrace.data
1,2T    uftrace.data

Such a data amount triggers further challenges for efficient analysis in various ways, doesn't it? :thinking: How will corresponding data processing approaches evolve?

elfring commented 3 years ago

I hope that a command variant like the following will influence the data analysis also in desirable directions. :thinking:

[Markus_Elfring@fedora calamares]$ time sudo uftrace record --data=~/Test/calamares/getDevices-uftrace --disable --trigger='PartUtils::getDevices@trace_on' --nest-libcall --num-thread=4 ./calamares -d -c /usr/share/calamares
…

Will any more system fine-tuning evolve accordingly?

namhyung commented 3 years ago

Do you mean parallelizing the analysis commands (like uftrace replay, report, ...)?

elfring commented 3 years ago
elfring commented 3 years ago

Would you find any clarification interesting according to data processing aspects by the following command variant? :thinking:

[Markus_Elfring@fedora KPMcore]$ time sudo uftrace record --data=/home/Markus_Elfring/Test/KPMcore/device_scanner-uftrace --nest-libcall --num-thread=4 bin/testdevicescanner
unknown file system type  "dos"  on  "/dev/sda3"
unknown file system type  "dos"  on  "/dev/sdc2"

real    81m22,837s
user    0m4,846s
sys 0m3,122s

[Markus_Elfring@fedora device_scanner-uftrace]$ du -h
322M    .
[Markus_Elfring@fedora device_scanner-uftrace]$ time uftrace dump --data=. --flame-graph | flamegraph.pl > ~/Test/KPMcore/flame_graph-test1.svg

real    0m11,961s
user    0m11,589s
sys 0m0,295s

Summary: all — 10379210 samples

elfring commented 3 years ago

Would you find any analysis results according to a previous test run on 2021-08-31 similarly suspicious for desirable software improvements? :thinking:

Example:

[Markus_Elfring@fedora ~]$ uftrace --data=Test/KPMcore/device_scanner-uftrace report --filter=QStorageInfo::mountedVolumes
  Total time   Self time       Calls  Function
  ==========  ==========  ==========  ====================
    3.009  h   16.807 ms          27  QStorageInfo::mountedVolumes
    3.009  h    1.178 ms        2430  QStorageInfo::QStorageInfo
    3.009  h  340.387 ms        1296  QStorageInfo::setPath
    3.009  h    3.009  h        1382  linux:schedule
    3.009  h   21.944 ms        1296  statvfs64
  944.318 ms  190.814 ms       25488  QDirIterator::next
  621.877 ms  123.711 ms       25488  QFileInfo::symLinkTarget
…
elfring commented 3 years ago

Another background information for the desired clarification:

[Markus_Elfring@fedora mountedVolumes]$ time ./mountedVolumes
Number of mounted filesystems: 43

real    3m0,469s
user    0m0,036s
sys 0m0,048s