DragonFly users List (threaded) for 2012-03
[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index][Thread Index]
Re: What's _slaballoc?

From:	Venkatesh Srinivas <me@xxxxxxxxxxx>
Date:	Tue, 6 Mar 2012 10:55:26 -0500
On Mon, Mar 5, 2012 at 11:26 PM, Pierre Abbat <phma@phma.optus.nu> wrote:
> I'm profiling a program so that I can optimize it and hopefully get it to run in real time. Here's
> the profile of the program running under Linux:
>
> Flat profile:
>
> Each sample counts as 0.01 seconds.
> Â % Â  cumulative Â  self Â  Â  Â  Â  Â  Â  Â self Â  Â  total
> Â time Â  seconds Â  seconds Â  Â calls Â  s/call Â  s/call Â name
> Â 65.94 Â  Â  Â 7.59 Â  Â  7.59 Â  613648 Â  Â  0.00 Â  Â  0.00 Â tonegenerator::fwaves(int)
> Â 11.29 Â  Â  Â 8.89 Â  Â  1.30 Â  613648 Â  Â  0.00 Â  Â  0.00
> __gnu_cxx::__enable_if<std::__is_scalar<float>::__value, float*>::__type std::__fill_n_a<float*,
> unsigned int, float>(float*, unsigned int, float const&)
> Â 5.39 Â  Â  Â 9.51 Â  Â  0.62 168385808 Â  Â  0.00 Â  Â  0.00 Â std::vector<float, std::allocator<float>
>>::operator[](unsigned int)
> Â 2.78 Â  Â  Â 9.83 Â  Â  0.32 Â  991456 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double const,
> errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> >
>>::_M_lower_bound(std::_Rb_tree_node<std::pair<double const, errec> > const*,
> std::_Rb_tree_node<std::pair<double const, errec> > const*, double const&) const
> Â 2.17 Â  Â  10.08 Â  Â  0.25 15606822 Â  Â  0.00 Â  Â  0.00 Â std::less<double>::operator()(double const&,
> double const&) const
> Â 1.26 Â  Â  10.22 Â  Â  0.14 Â  613648 Â  Â  0.00 Â  Â  0.00 Â mastertimer::skip()
> Â 1.04 Â  Â  10.35 Â  Â  0.12 14558791 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double
> const, errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> >
>>::_S_key(std::_Rb_tree_node<std::pair<double const, errec> > const*)
> Â 0.87 Â  Â  10.45 Â  Â  0.10 Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  main
> Â 0.52 Â  Â  10.51 Â  Â  0.06 Â  613648 Â  Â  0.00 Â  Â  0.00 Â tonegenerator::unfwave()
> Â 0.48 Â  Â  10.56 Â  Â  0.06 Â 8000250 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree_iterator<std::pair<double
> const, errec> >::operator->() const
> Â 0.43 Â  Â  10.61 Â  Â  0.05 Â  999513 Â  Â  0.00 Â  Â  0.00 Â std::map<double, errec, std::less<double>,
> std::allocator<std::pair<double const, errec> > >::end()
> Â 0.43 Â  Â  10.66 Â  Â  0.05 Â  991456 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double const,
> errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> > >::find(double const&) const
> Â 0.43 Â  Â  10.71 Â  Â  0.05 Â  205449 Â  Â  0.00 Â  Â  0.00 Â downspike()
> Â 0.35 Â  Â  10.75 Â  Â  0.04 Â 1227298 Â  Â  0.00 Â  Â  0.00 Â std::vector<float, std::allocator<float>
>>::~vector()
> Â 0.35 Â  Â  10.79 Â  Â  0.04 Â  613648 Â  Â  0.00 Â  Â  0.00 Â std::vector<float, std::allocator<float>
>>::vector(std::vector<float, std::allocator<float> > const&)
> Â 0.30 Â  Â  10.82 Â  Â  0.04 Â 1840944 Â  Â  0.00 Â  Â  0.00 Â parity(unsigned int)
> Â 0.26 Â  Â  10.86 Â  Â  0.03 14558791 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double
> const, errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> >
>>::_S_value(std::_Rb_tree_node<std::pair<double const, errec> > const*)
> Â 0.26 Â  Â  10.88 Â  Â  0.03 Â 2011200 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double const,
> errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> > >::end() const
> Â 0.26 Â  Â  10.91 Â  Â  0.03 Â 1970656 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree_iterator<std::pair<double
> const, errec> >::operator!=(std::_Rb_tree_iterator<std::pair<double const, errec> > const&)
> const
> Â 0.26 Â  Â  10.95 Â  Â  0.03 Â 1524715 Â  Â  0.00 Â  Â  0.00 Â float* std::__copy_move<false, true,
> std::random_access_iterator_tag>::__copy_m<float>(float const*, float const*, float*)
> Â 0.26 Â  Â  10.97 Â  Â  0.03 Â  613648 Â  Â  0.00 Â  Â  0.00 Â std::vector<float, std::allocator<float>
>>::operator=(std::vector<float, std::allocator<float> > const&)
> Â 0.26 Â  Â  11.01 Â  Â  0.03 Â  Â 22128 Â  Â  0.00 Â  Â  0.00 Â compdiv(double)
> Â 0.22 Â  Â  11.03 Â  Â  0.03 Â 7046596 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double const,
> errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> > >::_S_left(std::_Rb_tree_node_base const*)
> Â 0.22 Â  Â  11.05 Â  Â  0.03 Â 5504021 Â  Â  0.00 Â  Â  0.00 Â std::vector<float, std::allocator<float>
>>::size() const
> Â 0.17 Â  Â  11.07 Â  Â  0.02 Â 8056834 Â  Â  0.00 Â  Â  0.00 Â std::pair<double const, errec>*
> std::__addressof<std::pair<double const, errec> >(std::pair<double const, errec>&)
> Â 0.17 Â  Â  11.10 Â  Â  0.02 Â 1859754 Â  Â  0.00 Â  Â  0.00 Â __gnu_cxx::__normal_iterator<float const*,
> std::vector<float, std::allocator<float> > >::base() const
> Â 0.17 Â  Â  11.12 Â  Â  0.02 Â 1859754 Â  Â  0.00 Â  Â  0.00
> std::_Niter_base<__gnu_cxx::__normal_iterator<float const*, std::vector<float,
> std::allocator<float> > > >::iterator_type
> std::__niter_base<__gnu_cxx::__normal_iterator<float const*, std::vector<float,
> std::allocator<float> > > >(__gnu_cxx::__normal_iterator<float const*, std::vector<float,
> std::allocator<float> > >)
> Â 0.17 Â  Â  11.13 Â  Â  0.02 Â 1048032 Â  Â  0.00 Â  Â  0.00 Â std::vector<double, std::allocator<double>
>>::operator[](unsigned int)
> Â 0.17 Â  Â  11.15 Â  Â  0.02 Â  613648 Â  Â  0.00 Â  Â  0.00 Â std::_Vector_base<float, std::allocator<float>
>>::_M_get_Tp_allocator() const
> Â 0.17 Â  Â  11.18 Â  Â  0.02 Â  Â  Â  Â 1 Â  Â  0.02 Â  Â 10.22 Â cscale()
>
> Here's the profile under DragonFly:
>
> Flat profile:
>
> Each sample counts as 0.0078125 seconds.
> Â % Â  cumulative Â  self Â  Â  Â  Â  Â  Â  Â self Â  Â  total
> Â time Â  seconds Â  seconds Â  Â calls Â  s/call Â  s/call Â name
> Â 45.55 Â  Â 122.17 Â  122.17 Â 1255310 Â  Â  0.00 Â  Â  0.00 Â _slaballoc
> Â 25.03 Â  Â 189.30 Â  Â 67.13 Â  613648 Â  Â  0.00 Â  Â  0.00 Â tonegenerator::fwaves(int)
> Â 22.74 Â  Â 250.29 Â  Â 60.99 Â  Â  Â 415 Â  Â  0.15 Â  Â  0.15 Â write
> Â 4.19 Â  Â 261.53 Â  Â 11.23 Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  Â  .mcount
> Â 1.11 Â  Â 264.50 Â  Â  2.98 Â 2752043 Â  Â  0.00 Â  Â  0.00 Â memmove
> Â 0.37 Â  Â 265.50 Â  Â  1.00 Â  613648 Â  Â  0.00 Â  Â  0.00
> __gnu_cxx::__enable_if<std::__is_scalar<float>::__value, float*>::__type std::__fill_n_a<float*,
> unsigned int, float>(float*, unsigned int, float const&)
> Â 0.22 Â  Â 266.09 Â  Â  0.59 168385808 Â  Â  0.00 Â  Â  0.00 Â std::vector<float, std::allocator<float>
>>::operator[](unsigned int)
> Â 0.10 Â  Â 266.36 Â  Â  0.27 Â  946349 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double const,
> errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> >
>>::_M_lower_bound(std::_Rb_tree_node<std::pair<double const, errec> > const*,
> std::_Rb_tree_node<std::pair<double const, errec> > const*, double const&) const
> Â 0.06 Â  Â 266.53 Â  Â  0.17 14880846 Â  Â  0.00 Â  Â  0.00 Â std::less<double>::operator()(double
> const&, double const&) const
> Â 0.05 Â  Â 266.67 Â  Â  0.14 Â 1175511 Â  Â  0.00 Â  Â  0.00 Â exp
> Â 0.05 Â  Â 266.79 Â  Â  0.12 Â  613648 Â  Â  0.00 Â  Â  0.00 Â mastertimer::skip()
> Â 0.04 Â  Â 266.89 Â  Â  0.10 Â  Â  Â  Â 1 Â  Â  0.10 Â  256.25 Â main
> Â 0.03 Â  Â 266.99 Â  Â  0.09 Â 1227296 Â  Â  0.00 Â  Â  0.00 Â hypot
> Â 0.02 Â  Â 267.05 Â  Â  0.06 Â 1840944 Â  Â  0.00 Â  Â  0.00 Â parity(unsigned int)
> Â 0.02 Â  Â 267.11 Â  Â  0.06 Â  613648 Â  Â  0.00 Â  Â  0.00 Â tonegenerator::unfwave()
> Â 0.02 Â  Â 267.17 Â  Â  0.06 Â  277009 Â  Â  0.00 Â  Â  0.00
> __gnu_cxx::__enable_if<std::__is_integer<int>::__value, double>::__type std::log<int>(int)
> Â 0.02 Â  Â 267.23 Â  Â  0.05 Â 1524715 Â  Â  0.00 Â  Â  0.00 Â float* std::__copy_move<false, true,
> std::random_access_iterator_tag>::__copy_m<float>(float const*, float const*, float*)
> Â 0.02 Â  Â 267.28 Â  Â  0.05 13879461 Â  Â  0.00 Â  Â  0.00 Â std::_Rb_tree<double, std::pair<double
> const, errec>, std::_Select1st<std::pair<double const, errec> >, std::less<double>,
> std::allocator<std::pair<double const, errec> >
>>::_S_key(std::_Rb_tree_node<std::pair<double const, errec> > const*)
> Â 0.02 Â  Â 267.32 Â  Â  0.05 Â  554079 Â  Â  0.00 Â  Â  0.00 Â log
> Â 0.02 Â  Â 267.37 Â  Â  0.05 Â  205449 Â  Â  0.00 Â  Â  0.00 Â downspike()
> Â 0.02 Â  Â 267.42 Â  Â  0.05 Â  Â  Â  Â 1 Â  Â  0.05 Â  241.22 Â cscale()
>
> I replaced downhann(), which was taking even more time than fwaves(int), with downspike(),
> thus making the program much faster. The next function to optimize is fwaves(int), which I'm
> working on. But in DFly, _slaballoc takes more time than fwaves(int). What is it, and how can I
> optimize it?
>
> Pierre

It is the allocation path in our libc slab allocator, specifically nmalloc.

I'd be fascinated to see the allocation pattern this application
produces that cause that much time to be spent in the allocator.
nmalloc is a segregated-storage allocator, patterns should have a lot
of difficulty causing worst-case behavior.

-- vs;
http://ops101.org/4k/
[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index][Thread Index]