Question on -pg profiling and function calls

Software RawTherapee
1

I tried building the current dev debug build of RT this morning with -pg added, simply to see what is going on - just for fun. I found something interesting though, which I cannot explain. FYI: I’m opening RT into a completely empty folder.
These are the first few lines of output I get when running gprof afterwards:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ns/call  ns/call  name    
 56.25      0.09     0.09                             _mcount_private
 18.75      0.12     0.03                             __fentry__
 12.50      0.14     0.02                             rtengine::(anonymous namespace)::catmull_rom_spline(int, double, double, double, double, double, double, double, double, std::vector<double, std::allocator<double> >&, std::vector<double, std::allocator<double> >&)
  6.25      0.15     0.01   697589    14.34    14.34  LUT<float>::operator[](int) const
  6.25      0.16     0.01                             exp
  0.00      0.16     0.00  3009904     0.00     0.00  std::vector<rtexif::Tag*, std::allocator<rtexif::Tag*> >::size() const
  0.00      0.16     0.00  2877878     0.00     0.00  rtexif::Tag::getID() const
  0.00      0.16     0.00  2640799     0.00     0.00  std::vector<rtexif::Tag*, std::allocator<rtexif::Tag*> >::operator[](unsigned long long) const
  0.00      0.16     0.00   835170     0.00     0.00  int const& rtengine::LIM<int>(int const&, int const&, int const&)
  0.00      0.16     0.00   764653     0.00     0.00  int const& rtengine::min<int>(int const&, int const&)
  0.00      0.16     0.00   715466     0.00     0.00  int const& rtengine::max<int>(int const&, int const&)

What’s going on with all those function calls when there are no images in the current folder? Calling a function related to exif 2877878 times? And even the number of calls to the LUT is oddly high.
Any clue? :thinking:

2

Maybe ping @floessie or @heckflosse

3

If no flat field or dark frame directory is set, the current path is parsed for raws. Maybe that’s the case with you? LUT<T>::operator[](int) const is called from rtengine::Color::init().

4

Getting rid of the flat-field and dark frame directories, got rid of the exif-calls. Still I don’t understand why so many: there were only a few hundred RAWs in those folder combined.

Anyway, things look better now. Still a lot of calls to min, LIM and max for starting into an empty directory… :roll_eyes:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 52.63      0.10     0.10                             _mcount_private
 10.53      0.12     0.02                             rtengine::(anonymous namespace)::catmull_rom_spline(int, double, double, double, double, double, double, double, double, std::vector<double, std::allocator<double> >&, std::vector<double, std::allocator<double> >&)
 10.53      0.14     0.02                             __fentry__
  5.26      0.15     0.01   784466     0.00     0.00  int const& rtengine::min<int>(int const&, int const&)
  5.26      0.16     0.01      184     0.05     0.05  sigc::limit_reference<FileBrowser, true>::limit_reference(FileBrowser&)
  5.26      0.17     0.01                             _GLOBAL__sub_I__ZN8rtengine5Color14linearGammaTRCE
  5.26      0.18     0.01                             Glib::Value<Pango::EllipsizeMode>::value_type()
  5.26      0.19     0.01                             __logl_internal
  0.00      0.19     0.00   841920     0.00     0.00  int const& rtengine::LIM<int>(int const&, int const&, int const&)
  0.00      0.19     0.00   726252     0.00     0.00  int const& rtengine::max<int>(int const&, int const&)
  0.00      0.19     0.00   705223     0.00     0.00  LUT<float>::operator[](int) const
  0.00      0.19     0.00   523930     0.00     0.00  double const& std::forward<double const&>(std::remove_reference<double const&>::type&)
  0.00      0.19     0.00   309082     0.00     0.00  operator new(unsigned long long, void*)
  0.00      0.19     0.00   261708     0.00     0.00  void __gnu_cxx::new_allocator<double>::construct<double, double const&>(double*, double const&)
  0.00      0.19     0.00   261708     0.00     0.00  void std::allocator_traits<std::allocator<double> >::construct<double, double const&>(std::allocator<double>&, double*, double const&)
  0.00      0.19     0.00   261708     0.00     0.00  std::vector<double, std::allocator<double> >::push_back(double const&)
5

Roel, GDB is your friend. :wink: