Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Mitigate speed regressions in symmetric function related code due to #12313 #13991

Closed
nbruin opened this issue Jan 23, 2013 · 65 comments
Closed

Comments

@nbruin
Copy link
Contributor

nbruin commented Jan 23, 2013

As was found in #12313, there is some code, especially k_dual.py introduced in #13762, that seems to be extremely reliant for its performance on parents being immortal. Actually as it turned out it's not immortality, it was relying on non-unique parents comparing as equal, where parents should be unique and hence should be comparable by identity:

sage: from sage.combinat.sf.k_dual import DualkSchurFunctions
sage: Sym = SymmetricFunctions(QQ['t'].fraction_field())
sage: dks4 = DualkSchurFunctions(Sym.kBoundedQuotient(4))
sage: X=dks4[0]+ 2*dks4[1] + 3*dks4[2]
sage: X*X #takes surprisingly long with #12313 applied
sage: (X*X)*X #takes surprisingly long with #12313 applied

Profiling gives some indication what is happening:

sage: import cProfile,pstats
sage: cmd = "X*X"
sage: s=pstats.Stats(cProfile.Profile().runctx(cmd,globals(),{}))
sage: S=s.sort_stats('cumulative')
sage: S.print_callers() # get call graph info

it seems certain parents are created again and again (indeed they are, but the problem here turns out to be that they are created newly rather than the existing parent being reused) and the coercion discoveries need to be redone every time.

Probably, the most straightforward solution is to equip the classes with appropriate caches so that they themselves are now ensuring the lifetime of parents they use rather than rely on sage to keep them around.

Depends on #13605
Depends on #14225
Depends on #14228

CC: @tscrim

Component: combinatorics

Reviewer: Simon King

Issue created by migration from https://trac.sagemath.org/ticket/13991

@nbruin
Copy link
Contributor Author

nbruin commented Jan 23, 2013

comment:1

For information, the results of sage -tp devel/sage/sage/combinat/sf:

sage -t  devel/sage-0/sage/combinat/sf/all.py
	 [0.0 s]	 [0.0 s]
sage -t  devel/sage-0/sage/combinat/sf/classical.py
	 [1.6 s]	 [1.3 s]
sage -t  devel/sage-0/sage/combinat/sf/kschur.py
	 [1.9 s]	 [1.9 s]
sage -t  devel/sage-0/sage/combinat/sf/dual.py
	 [1.9 s]	 [1.7 s]
sage -t  devel/sage-0/sage/combinat/sf/elementary.py
	 [1.2 s]	 [1.4 s]
sage -t  devel/sage-0/sage/combinat/sf/kfpoly.py
	 [1.3 s]	 [1.3 s]
sage -t  devel/sage-0/sage/combinat/sf/schur.py
	 [1.3 s]	 [1.3 s]
sage -t  devel/sage-0/sage/combinat/sf/sfa.py
	 [4.5 s]	 [12.2 s]
sage -t  devel/sage-0/sage/combinat/sf/llt.py
	 [1.8 s]	 [2.2 s]
sage -t  devel/sage-0/sage/combinat/sf/homogeneous.py
	 [1.2 s]	 [1.2 s]
sage -t  devel/sage-0/sage/combinat/sf/multiplicative.py
	 [1.2 s]	 [1.1 s]
sage -t  devel/sage-0/sage/combinat/sf/jack.py
	 [4.9 s]	 [6.3 s]
sage -t  devel/sage-0/sage/combinat/sf/ns_macdonald.py
	 [1.8 s]	 [1.8 s]
sage -t  devel/sage-0/sage/combinat/sf/monomial.py
	 [1.3 s]	 [1.3 s]
sage -t  devel/sage-0/sage/combinat/sf/sf.py
	 [3.6 s]	 [7.8 s]
sage -t  devel/sage-0/sage/combinat/sf/powersum.py
	 [1.2 s]	 [1.7 s]
sage -t  devel/sage-0/sage/combinat/sf/orthotriang.py
	 [1.9 s]	 [1.9 s]
sage -t  devel/sage-0/sage/combinat/sf/hall_littlewood.py
	 [2.9 s]	 [3.1 s]
sage -t  devel/sage-0/sage/combinat/sf/__init__.py
	 [0.0 s]	 [0.0 s]
sage -t  devel/sage-0/sage/combinat/sf/macdonald.py
	 [6.7 s]	 [13.9 s]
sage -t  devel/sage-0/sage/combinat/sf/new_kschur.py
	 [5.5 s]	 [9.2 s]
sage -t  devel/sage-0/sage/combinat/sf/k_dual.py
	 [9.6 s]	 [51.7 s]

First time is reference, second one with #12313. Variations have not been compensated for, but the really big differences are probably due to a genuine issue. As you can see, the slowdown in k_dual.py is dramatic. Perhaps the other slowdowns give an indication for experts where the biggest problem lies?

@simon-king-jena
Copy link
Member

comment:2

If I am not mistaken, symmetric function algebras are our key example of algebras with multiple realisations. Hence, here one has frequent coercions back and forth between different realisations of the same abstract algebra. However, if I am not mistaken, the different realisations of an algebra are stored by strong references as attributes of the algebra.

@jdemeyer

This comment has been minimized.

@simon-king-jena
Copy link
Member

comment:4

With #12313, I get

sage: from sage.combinat.sf.k_dual import DualkSchurFunctions
sage: Sym = SymmetricFunctions(QQ['t'].fraction_field())
sage: dks4 = DualkSchurFunctions(Sym.kBoundedQuotient(4))
sage: X=dks4[0]+ 2*dks4[1] + 3*dks4[2]
sage: X*X
dks4[] + 4*dks4[1] + 4*dks4[1, 1] + 10*dks4[2] + 12*dks4[2, 1] + 9*dks4[2, 2] + 12*dks4[3] + 9*dks4[3, 1] + 9*dks4[4]
sage: import cProfile,pstats
sage: cmd = "X*X"
sage: s=pstats.Stats(cProfile.Profile().runctx(cmd,globals(),{}))
sage: Sc=s.sort_stats('calls')
sage: Sc.print_stats()
         921582 function calls (903323 primitive calls) in 10.401 seconds

   Ordered by: call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   112808    1.279    0.000    2.634    0.000 {repr}
    98409    0.121    0.000    0.121    0.000 {id}
    96993    0.372    0.000    0.491    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/structure/unique_representation.py:531(__hash__)
    56876    0.309    0.000    0.309    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:4003(__repr__)
    56809    0.113    0.000    0.113    0.000 {cmp}
    56404    0.451    0.000    3.198    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1051(__cmp__)
    54058    0.159    0.000    0.159    0.000 {isinstance}
    42834    0.099    0.000    0.099    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/rational_field.py:217(__hash__)
    42480    0.234    0.000    0.234    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:716(__hash__)
    42127    0.436    0.000    0.668    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:1369(_repr_)
    42127    0.232    0.000    0.232    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:725(_repr_)
28124/11520    1.748    0.000    5.921    0.001 {method 'has_coerce_map_from' of 'sage.structure.parent.Parent' objects}
    15235    0.040    0.000    0.040    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/structure/unique_representation.py:473(__eq__)
    14501    0.019    0.000    0.019    0.000 {method 'base_ring' of 'sage.structure.category_object.CategoryObject' objects}
    14278    0.035    0.000    0.035    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/rational_field.py:220(_repr_)
    14160    0.091    0.000    0.723    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/rational_field.py:261(_coerce_map_from_)
    14043    0.346    0.000    0.571    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:380(_repr_)
    14042    0.713    0.000    2.083    0.000 {method 'coerce_map_from' of 'sage.structure.parent.Parent' objects}
    14042    0.060    0.000    0.108    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:189(is_PolynomialRing)
    14042    0.400    0.000    2.630    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:468(_coerce_map_from_)
    14042    0.021    0.000    0.021    0.000 {sage.rings.polynomial.multi_polynomial_ring_generic.is_MPolynomialRing}
    13924    0.685    0.000    5.909    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:194(_coerce_map_from_)
     3344    0.009    0.000    0.009    0.000 {built-in method __new__ of type object at 0x7faac21514a0}
     3344    0.019    0.000    0.027    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/weakref.py:223(__new__)
     3344    0.024    0.000    0.024    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/weakref.py:228(__init__)
     2245    0.007    0.000    0.007    0.000 {getattr}
     2116    0.013    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:430(ring)
     1768    0.003    0.000    0.003    0.000 {len}
     1493    0.007    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:840(__hash__)
     1356    0.009    0.000    0.009    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:942(__init__)
     1356    0.028    0.000    0.053    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:883(_element_constructor_)
 1281/809    0.058    0.000    0.087    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/misc/lazy_attribute.py:506(__get__)
     1257    0.016    0.000    0.049    0.000 {hasattr}
     1146    0.003    0.000    0.003    0.000 {setattr}
      993    0.005    0.000    0.009    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:285(__cmp__)
  842/136    0.004    0.000    9.752    0.072 {sum}
      827    0.029    0.000    0.066    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3510(Partitions)
      765    0.003    0.000    0.004    0.000 {method 'get' of 'dict' objects}
      618    0.001    0.000    0.001    0.000 {method 'parent' of 'sage.structure.element.Element' objects}
      613    0.003    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:872(__getitem__)
      613    0.001    0.000    0.001    0.000 {method '__getitem__' of 'list' objects}
      590    0.009    0.000    0.074    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:2716(parent)
      590    0.002    0.000    0.002    0.000 {method 'category' of 'sage.structure.parent.Parent' objects}
      590    0.003    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3978(__init__)
      548    0.004    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/re.py:226(_compile)
      548    0.006    0.000    0.006    0.000 {method 'sub' of '_sre.SRE_Pattern' objects}
      548    0.004    0.000    0.014    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/re.py:144(sub)
      517    0.007    0.000    0.011    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:667(__init__)
      482    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:886(__iter__)
      472    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/homset.py:589(domain)
      472    0.082    0.000    0.154    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/homset.py:353(__init__)
      472    0.002    0.000    0.046    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/sets_cat.py:255(_element_constructor_)
      472    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/homset.py:592(codomain)
      472    0.059    0.000    0.248    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/homset.py:80(Hom)
      437    0.006    0.000    0.032    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1139(_element_constructor_)
      413    0.005    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:34(__init__)
      413    0.007    0.000    0.015    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2142(_from_dict)

I do find it strange that 472 homsets are created, but apparently this does not contribute much to the computation time - at least not directly. I am afraid the problem is not clear to me from these statistics. But perhaps a comparison with the pre-#12313 state gives a clue?

@simon-king-jena
Copy link
Member

comment:5

Note that the list of calls from my previous post is much longer. I just gave the calls that occur most frequently. And here is the same without #12313:

         47502 function calls (46319 primitive calls) in 0.562 seconds

   Ordered by: call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    11460    0.026    0.000    0.026    0.000 {isinstance}
     2116    0.013    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:430(ring)
     1768    0.002    0.000    0.002    0.000 {len}
     1534    0.008    0.000    0.008    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:4003(__repr__)
     1493    0.007    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:840(__hash__)
     1356    0.009    0.000    0.009    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:942(__init__)
     1356    0.027    0.000    0.051    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:883(_element_constructor_)
     1180    0.007    0.000    0.017    0.000 {repr}
      993    0.005    0.000    0.008    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:285(__cmp__)
      877    0.002    0.000    0.002    0.000 {cmp}
  842/136    0.003    0.000    0.469    0.003 {sum}
      827    0.025    0.000    0.058    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3510(Partitions)
      765    0.003    0.000    0.004    0.000 {method 'get' of 'dict' objects}
      667    0.004    0.000    0.004    0.000 {hasattr}
      618    0.001    0.000    0.001    0.000 {method 'parent' of 'sage.structure.element.Element' objects}
      613    0.003    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:872(__getitem__)
      613    0.001    0.000    0.001    0.000 {method '__getitem__' of 'list' objects}
      590    0.008    0.000    0.065    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:2716(parent)
      590    0.005    0.000    0.023    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1051(__cmp__)
      590    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3978(__init__)
      548    0.005    0.000    0.005    0.000 {method 'sub' of '_sre.SRE_Pattern' objects}
      548    0.004    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/re.py:226(_compile)
      548    0.004    0.000    0.014    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/re.py:144(sub)
      482    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:886(__iter__)
      438    0.001    0.000    0.001    0.000 {setattr}
      413    0.004    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:34(__init__)
      413    0.007    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2142(_from_dict)
      405    0.035    0.000    0.041    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:271(<lambda>)
      405    0.001    0.000    0.001    0.000 {method 'denominator' of 'sage.rings.rational.Rational' objects}
      405    0.001    0.000    0.001    0.000 {method 'numerator' of 'sage.rings.rational.Rational' objects}
      399    0.006    0.000    0.009    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:667(__init__)
      341    0.000    0.000    0.000    0.000 {method 'base_ring' of 'sage.structure.category_object.CategoryObject' objects}
      334    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:860(__len__)
      319    0.004    0.000    0.023    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1139(_element_constructor_)
  319/219    0.003    0.000    0.031    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1093(__call__)
      302    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3836(__contains__)
      299    0.001    0.000    0.001    0.000 {method 'iteritems' of 'dict' objects}
      275    0.001    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:1034(<lambda>)
      275    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:991(ceiling)
      274    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/rational_field.py:682(is_atomic_repr)
      256    0.000    0.000    0.000    0.000 {method 'one_element' of 'sage.rings.ring.Ring' objects}
      253    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2196(<genexpr>)
      251    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3812(__init__)
      244    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:720(__eq__)
      239    0.001    0.000    0.001    0.000 {getattr}
      231    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:972(floor)
      229    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:1120(get_part)
      219    0.005    0.000    0.010    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/misc/lazy_attribute.py:506(__get__)
      219    0.001    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1118(element_class)
      219    0.004    0.000    0.032    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3920(__contains__)
      209    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/structure/unique_representation.py:473(__eq__)
      196    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:321(_add_)
      189    0.001    0.000    0.001    0.000 {min}
      180    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:956(__cmp__)
      169    0.000    0.000    0.000    0.000 {id}
      169    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/structure/unique_representation.py:531(__hash__)
      148    0.000    0.000    0.000    0.000 {method 'base_ring' of 'sage.structure.element.Element' objects}
      146    0.002    0.000    0.005    0.000 {max}
      144    0.001    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:355(<lambda>)
      137    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:1043(ngens)
      137    0.099    0.001    0.163    0.001 {method 'subs' of 'sage.structure.element.Element' objects}
      137    0.003    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:532(gen)
      137    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:519(ngens)
      137    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:918(gen)
      124    0.002    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/weakref.py:55(__getitem__)
    123/4    0.042    0.000    0.512    0.128 {sage.combinat.dict_addition.dict_linear_combination}
      122    0.003    0.000    0.003    0.000 {sage.structure.sage_object.have_same_parent}
      122    0.000    0.000    0.000    0.000 {range}
      119    0.003    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:380(_repr_)
      119    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:1369(_repr_)
      119    0.007    0.000    0.058    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:456(_element_constructor_)
      119    0.001    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/poor_man_map.py:116(__call__)
      119    0.002    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2007(_monomial)
      119    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:725(_repr_)
      119    0.013    0.000    0.033    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:290(_element_constructor_)
      118    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:700(__str__)
   114/34    0.001    0.000    0.496    0.015 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1390(<genexpr>)
   114/34    0.001    0.000    0.496    0.015 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1982(<genexpr>)
      103    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:348(<lambda>)
       81    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:820(gen)
       81    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:1232(_neg_)
       79    0.009    0.000    0.011    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:411(_coefficient_fast)
       73    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:140(is_FractionField)
       70    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:502(__cmp__)
       69    0.002    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:349(_add_)
       69    0.002    0.000    0.028    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:737(_acted_upon_)
       69    0.001    0.000    0.008    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/commutative_additive_semigroups.py:143(__add__)
       69    0.001    0.000    0.001    0.000 {sage.combinat.dict_addition.dict_addition}
       68    0.003    0.000    0.010    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:377(_mul_)
       66    0.001    0.000    0.070    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:1054(__iter__)
       60    0.005    0.000    0.077    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:527(_element_constructor_)
       59    0.002    0.000    0.012    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:448(coefficient)
       52    0.000    0.000    0.000    0.000 {method 'domain' of 'sage.categories.map.Map' objects}
       52    0.004    0.000    0.363    0.007 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1277(<genexpr>)
       52    0.000    0.000    0.000    0.000 {method 'codomain' of 'sage.categories.map.Map' objects}
       51    0.021    0.000    0.194    0.004 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sfa.py:988(_from_cache)
       51    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:97(monomial_coefficients)
       50    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1576(_on_basis)
       48    0.001    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1984(term)
       48    0.003    0.000    0.066    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:318(next)
       48    0.012    0.000    0.046    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:192(rightmost_pivot)
       48    0.004    0.000    0.014    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:38(first)
       46    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:52(__iter__)
     44/4    0.001    0.000    0.512    0.128 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1958(linear_combination)
     44/4    0.001    0.000    0.512    0.128 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1368(__call__)
       43    0.000    0.000    0.000    0.000 {method 'insert' of 'list' objects}
       41    0.001    0.000    0.169    0.004 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:574(_s_to_self)
       40    0.000    0.000    0.000    0.000 {sage.structure.element.get_coercion_model}
       40    0.003    0.000    0.052    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/new_kschur.py:299(_element_constructor_)
       40    0.004    0.000    0.012    0.000 {method 'bin_op' of 'sage.structure.coerce.CoercionModel_cache_maps' objects}
       38    0.000    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/algebras_with_basis.py:216(from_base_ring_from_one_basis)
       32    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:249(Partition)
       31    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sf.py:885(hall_littlewood)
       31    0.000    0.000    0.000    0.000 {method 'sort' of 'list' objects}
       31    0.004    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:562(support)
       31    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:141(ambient)
       29    0.001    0.000    0.011    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/commutative_additive_semigroups.py:168(__radd__)
       28    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:514(<genexpr>)
       22    0.001    0.000    0.023    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1110(<genexpr>)
       20    0.000    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:652(trailing_item)
       20    0.000    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/misc/misc.py:2149(__call__)
       20    0.000    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:624(trailing_support)
       20    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/misc/sage_itertools.py:33(min_cmp)
       19    0.002    0.000    0.019    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1296(_element_constructor_)
       18    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:882(__init__)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:329(Qp)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:778(size)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/new_kschur.py:176(kschur)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:1014(build_args)
       18    0.000    0.000    0.000    0.000 {method 'keys' of 'dict' objects}
       18    0.002    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:488(is_zero)
       18    0.000    0.000    0.000    0.000 {all}
       18    0.000    0.000    0.000    0.000 {sorted}
       18    0.000    0.000    0.000    0.000 {method 'values' of 'dict' objects}
       18    0.000    0.000    0.000    0.000 {method 'join' of 'str' objects}
       18    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sf.py:1110(kBoundedSubspace)
     14/1    0.000    0.000    0.563    0.563 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/algebras.py:190(__mul__)
       14    0.001    0.000    0.066    0.005 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1234(<genexpr>)
       13    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:141(P)
       12    0.001    0.000    0.045    0.004 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1076(retract)
       12    0.001    0.000    0.378    0.032 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1236(_khlp_to_dks_on_basis)
       11    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3895(__init__)
       10    0.000    0.000    0.026    0.003 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:601(_self_to_s)
       10    0.000    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:392(_sub_)
       10    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/new_kschur.py:749(<lambda>)
       10    0.000    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/commutative_additive_groups.py:49(__sub__)
        9    0.001    0.000    0.003    0.000 {sage.libs.symmetrica.symmetrica.mult_schur_schur_symmetrica}
        9    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sf.py:762(schur)
        9    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sfa.py:212(SymmetricFunctionAlgebra)
        8    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:206(kHallLittlewoodP)
        8    0.000    0.000    0.000    0.000 {sage.structure.element.parent}
        8    0.001    0.000    0.019    0.002 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1690(preimage)
        8    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1279(__contains__)
        6    0.001    0.000    0.073    0.012 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1204(_dks_to_khlp_on_basis)
      4/2    0.000    0.000    0.077    0.038 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/sets_cat.py:824(lift)
        4    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:739(__lt__)
      3/1    0.000    0.000    0.563    0.563 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/magmas.py:337(_mul_parent)
      2/1    0.000    0.000    0.050    0.050 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/algebras_with_basis.py:308(_product_from_combinatorial_algebra_multiply)
        2    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1112(lift)
        2    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:157(a_realization)
        2    0.000    0.000    0.077    0.038 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:679(lift)
        1    0.004    0.004    0.008    0.008 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/schur.py:70(_multiply)
        1    0.000    0.000    0.563    0.563 <string>:1(<module>)
        1    0.000    0.000    0.563    0.563 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:708(product)
        1    0.000    0.000    0.050    0.050 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:677(_multiply)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

That's a huge difference.

@simon-king-jena
Copy link
Member

comment:6

One very astonishing difference is that without #12313, Hom (or anything else from sage.categories.homset) is not called at all!!! Note that the list without #12313 is complete.

I expected that it would be called once, and then cached. But why is no homset created, even though coercion maps should certainly be involved?

@nbruin
Copy link
Contributor Author

nbruin commented Jan 23, 2013

comment:7

Replying to @simon-king-jena:

I expected that it would be called once, and then cached. But why is no homset created, even though coercion maps should certainly be involved?

Probably the homsets are associated with the coercion maps.
Without #12313 coercion maps are blessed with eternal life (or at least as long as the life of the object they are mapping to), thus saving the domains as well. When those domains are re-used, it finds the coercion map that was stored and it doesn't need to create a new homset.

Note that k_dual gives a dual basis, so these are finitely generated quotients rather than finitely generated subspaces. I can imagine how for a computer algebra system that means you end up with a more complicated construction; one where you can more easily lose track of a parent. If you end up recreating that think, you have to rediscover (and construct!) the coercion; with its homset. In particular, to do arithmetic, you always end up lifting and projecting down again. Something that probably shouldn't be done via the coercion framework, since you already know which homomorphism to apply, but clearly is done.

Also note that k_dual is one of the recent recent additions there and has a different author list than the other files. It says explicitly that it's based on similar code elsewhere. The authors might not have carried through all the original design decision (and forgotten the caching of some associated stucture somewhere)

@nbruin
Copy link
Contributor Author

nbruin commented Jan 23, 2013

comment:8

In fact, you might try running the code in the python debugger and set a breakpoint on Hom (I've never done that, but I assume it's possible). The stackframes you're finding there might give you some indication for what the code is trying to construct (and aparently has lost compared to the reference case).

@simon-king-jena
Copy link
Member

comment:9

Replying to @nbruin:

In fact, you might try running the code in the python debugger and set a breakpoint on Hom (I've never done that, but I assume it's possible). The stackframes you're finding there might give you some indication for what the code is trying to construct (and aparently has lost compared to the reference case).

Why so complicated? A print statement would do as well. That's of course the next thing I'll try, as soon as I'm done helping my son with his homework.

@nbruin
Copy link
Contributor Author

nbruin commented Jan 23, 2013

comment:10

Cool! this sort of works:

sage: from sage.combinat.sf.k_dual import DualkSchurFunctions
sage: Sym = SymmetricFunctions(QQ['t'].fraction_field())
sage: dks4 = DualkSchurFunctions(Sym.kBoundedQuotient(4))
sage: X=dks4[0]+ 2*dks4[1] + 3*dks4[2]
sage: X*X; #takes surprisingly long with #12313 applied
sage: import pdb
sage: def test():
....:     pdb.set_trace()
....:     print X*X
....: 
sage: test()
(Pdb) b Hom
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the Hall-Littlewood Qp basis, None)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the Hall-Littlewood Qp basis, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the Hall-Littlewood Qp basis, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Fraction Field of Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Fraction Field of Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, 4-Bounded Quotient of Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the 4-bounded Hall-Littlewood P basis, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, 4-Bounded Quotient of Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the 4-bounded Hall-Littlewood P basis, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Fraction Field of Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Fraction Field of Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Univariate Polynomial Ring in t over Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(213)Hom()
-> try:
(Pdb) p (X,Y,category)
(Partitions of the integer 0, Rational Field, None)
(Pdb) c
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)
(Pdb) p (X,Y,category)
(Partitions of the integer 1, Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the Hall-Littlewood Qp basis, None)
(Pdb) bt
  /usr/local/sage/5.6rc0/local/bin/sage-ipython(62)<module>()
-> ipy_sage.mainloop(sys_exit=1, banner='')
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/IPython/Shell.py(76)mainloop()
-> self.IP.mainloop(banner)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/IPython/iplib.py(1762)mainloop()
-> self.interact(banner)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/IPython/iplib.py(2001)interact()
-> more = self.push(line)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/IPython/iplib.py(2305)push()
-> more = self.runsource('\n'.join(self.buffer), self.filename)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/IPython/iplib.py(2231)runsource()
-> if self.runcode(code) == 0:
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/IPython/iplib.py(2260)runcode()
-> exec code_obj in self.user_global_ns, self.user_ns
  <ipython console>(1)<module>()
  <ipython console>(3)test()
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/algebras.py(202)__mul__()
-> return self._mul_(right)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/magmas.py(361)_mul_parent()
-> return self.parent().product(self, other)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py(791)product()
-> return self( x.lift() * y.lift() )
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/sets_cat.py(839)lift()
-> return self.parent().lift(self)
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py(706)lift()
-> return kmhlp(self(la)).lift()
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py(1390)__call__()
-> return self.codomain().linear_combination( (self._on_basis(*(before+(index,)+after)), coeff ) for (index, coeff) in args[self._position] )
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py(1982)linear_combination()
-> return self._from_dict( dict_linear_combination( ( ( element._monomial_coefficients, coeff ) for element, coeff in iter_of_elements_coeff ), factor_on_left=factor_on_left ), remove_zeros=False )
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py(1982)<genexpr>()
-> return self._from_dict( dict_linear_combination( ( ( element._monomial_coefficients, coeff ) for element, coeff in iter_of_elements_coeff ), factor_on_left=factor_on_left ), remove_zeros=False )
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py(1390)<genexpr>()
-> return self.codomain().linear_combination( (self._on_basis(*(before+(index,)+after)), coeff ) for (index, coeff) in args[self._position] )
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py(1234)_dks_to_khlp_on_basis()
-> return sum( ks(Qp(x)).coefficient(la) * kHLP(x) for x in Partitions(Partition(la).size(), max_part = self.k))
  /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py(1234)<genexpr>()
-> return sum( ks(Qp(x)).coefficient(la) * kHLP(x) for x in Partitions(Partition(la).size(), max_part = self.k))
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/categories/homset.py(212)Hom()
-> key = (X,Y,category)

So it seems to me the first problem arises in this statement:

ks(Qp(x)).coefficient(la) * kHLP(x)

With

(Pdb) up
> /usr/local/sage/5.6rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py(1234)<genexpr>()
-> return sum( ks(Qp(x)).coefficient(la) * kHLP(x) for x in Partitions(Partition(la).size(), max_part = self.k))
(Pdb) p x
[1]
(Pdb) p kHLP
4-Bounded Quotient of Symmetric Functions over Fraction Field of Univariate Polynomial Ring in t over Rational Field in the 4-bounded Hall-Littlewood P basis

I guess it's the kHLP(x) part where it has to figure out how to make a kHLP element out of x. We have

(Pdb) p x.parent()
Partitions of the integer 1

which is obviously a parent that needs to be created again and again!

So my guess is that Partitions(...) here should be replaced by something that is a lot more economical about how to represent what it returns (in particular, they should have a parent Partitions of Integers), in which case THAT parent can be strongly cached, since it's the index test for the basis of kHLP.

Better yet, the call should just be replaced by give the basis vector of kHLPindexed by the partitionx`.

The lessons here are interesting for people intending to drive Sage's category and coercion system to its limits:

  • making your parent too specific does not come for free: it means many have to be created, few remain in use, so most of them have to get recreated time and again.
  • don't rely on the coercion/conversion framework if you already know what you need.
  • creating parents should be considered "expensive". They should not be created in inner loops. The idea is that parents are heavy-weight so that their elements can be lightweight. That means that sometimes you have to let your code change perspective even if mathematically this should not be necessary (see also why, e.g. fractional ideals in number fields aren't parents, but how you can turn them into, for instance, a ZZ-module, which is a parent).

@nbruin
Copy link
Contributor Author

nbruin commented Jan 23, 2013

comment:11

Replying to @simon-king-jena:

Why so complicated? A print statement would do as well. That's of course the next thing I'll try, as soon as I'm done helping my son with his homework.

Because it's not complicated as you can see! plus, you get to examine the call stack. And by setting the breakpoint only after initialization you avoid all the irrelevant data (I assume a lot of homspaces are created)

@simon-king-jena
Copy link
Member

comment:12

Replying to @nbruin:

Replying to @simon-king-jena:

Why so complicated? A print statement would do as well. That's of course the next thing I'll try, as soon as I'm done helping my son with his homework.

Because it's not complicated as you can see!

OK, I thought that for setting a break point one needs to change the source code.

@simon-king-jena
Copy link
Member

comment:13

I don't think that Partitions(n) has ever been cached. Partitions is a function which apparently does not use a cache, and the object returned by Partitions(1) is not an instance of UniqueRepresentation.

Actually, Partitions(1) is not a unique parent - and I think this actually is the problem. Namely, we have

sage: P = Partitions(1)
sage: P is Partitions(1)
False
sage: P == Partitions(1)
True

In the old way of caching homsets, domain and codomain were tested for equality. But now, they are tested for identity. Hence, we now have

sage: H = Hom(Partitions(0),SymmetricFunctionAlgebra(QQ))
sage: H is Hom(Partitions(0),SymmetricFunctionAlgebra(QQ))
False

which used to return True, because Hom was caching by equality.

Hence, rather than having less caching, I actually suggest to have more caching in this case: Partitions_n should inherit from UniqueRepresentation, or, if this is impossible, Partitions should be equipped with a cache.

This cache should either be a weak cache, or it should be semi-weak (e.g., cache the output of Partitions(n) permanently for n<256, but weakly for greater values).

@simon-king-jena
Copy link
Member

comment:14

OK, I indeed get

sage: H = Hom(Partitions(0),SymmetricFunctionAlgebra(QQ))
sage: H is Hom(Partitions(0),SymmetricFunctionAlgebra(QQ))
True

when making Partitions_n inherit from UniqueRepresentation. And the statistic for X*X in the example of the ticket description becomes

         41950 function calls (40767 primitive calls) in 0.536 seconds

   Ordered by: call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    11460    0.025    0.000    0.025    0.000 {isinstance}
     2116    0.013    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:430(ring)
     1768    0.002    0.000    0.002    0.000 {len}
     1493    0.007    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:840(__hash__)
     1356    0.009    0.000    0.009    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:942(__init__)
     1356    0.026    0.000    0.049    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:883(_element_constructor_)
      993    0.005    0.000    0.008    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:285(__cmp__)
      976    0.006    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/weakref.py:55(__getitem__)
  842/136    0.003    0.000    0.442    0.003 {sum}
      827    0.026    0.000    0.060    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3511(Partitions)
      765    0.002    0.000    0.004    0.000 {method 'get' of 'dict' objects}
      618    0.001    0.000    0.001    0.000 {method 'parent' of 'sage.structure.element.Element' objects}
      613    0.003    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:872(__getitem__)
      613    0.001    0.000    0.001    0.000 {method '__getitem__' of 'list' objects}
      590    0.008    0.000    0.066    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:2717(parent)
      548    0.004    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/re.py:226(_compile)
      548    0.005    0.000    0.005    0.000 {method 'sub' of '_sre.SRE_Pattern' objects}
      548    0.004    0.000    0.014    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python/re.py:144(sub)
      482    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:886(__iter__)
      448    0.001    0.000    0.001    0.000 {hasattr}
      413    0.004    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:34(__init__)
      413    0.006    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2142(_from_dict)
      405    0.040    0.000    0.046    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:271(<lambda>)
      405    0.001    0.000    0.001    0.000 {method 'denominator' of 'sage.rings.rational.Rational' objects}
      405    0.001    0.000    0.001    0.000 {method 'numerator' of 'sage.rings.rational.Rational' objects}
      399    0.005    0.000    0.009    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:667(__init__)
      341    0.000    0.000    0.000    0.000 {method 'base_ring' of 'sage.structure.category_object.CategoryObject' objects}
      334    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:860(__len__)
      327    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/structure/unique_representation.py:473(__eq__)
      319    0.002    0.000    0.010    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1139(_element_constructor_)
  319/219    0.003    0.000    0.018    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:1093(__call__)
      302    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3837(__contains__)
      299    0.001    0.000    0.001    0.000 {method 'iteritems' of 'dict' objects}
      287    0.000    0.000    0.000    0.000 {cmp}
      275    0.001    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:1034(<lambda>)
      275    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:991(ceiling)
      274    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/rational_field.py:682(is_atomic_repr)
      256    0.000    0.000    0.000    0.000 {method 'one_element' of 'sage.rings.ring.Ring' objects}
      253    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2196(<genexpr>)
      244    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:720(__eq__)
      231    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:972(floor)
      229    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:1121(get_part)
      219    0.004    0.000    0.019    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:3921(__contains__)
      196    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:321(_add_)
      189    0.001    0.000    0.001    0.000 {min}
      180    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:956(__cmp__)
      148    0.000    0.000    0.000    0.000 {method 'base_ring' of 'sage.structure.element.Element' objects}
      146    0.002    0.000    0.005    0.000 {max}
      144    0.001    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:355(<lambda>)
      137    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:1043(ngens)
      137    0.100    0.001    0.170    0.001 {method 'subs' of 'sage.structure.element.Element' objects}
      137    0.003    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:532(gen)
      137    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:519(ngens)
      137    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:918(gen)
    123/4    0.045    0.000    0.483    0.121 {sage.combinat.dict_addition.dict_linear_combination}
      122    0.003    0.000    0.004    0.000 {sage.structure.sage_object.have_same_parent}
      122    0.000    0.000    0.000    0.000 {range}
      119    0.007    0.000    0.049    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:456(_element_constructor_)
      119    0.001    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/poor_man_map.py:116(__call__)
      119    0.002    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:2007(_monomial)
      119    0.012    0.000    0.029    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:290(_element_constructor_)
      118    0.002    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:700(__str__)
      115    0.000    0.000    0.000    0.000 {id}
      115    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/structure/unique_representation.py:531(__hash__)
   114/34    0.001    0.000    0.466    0.014 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1390(<genexpr>)
   114/34    0.001    0.000    0.466    0.014 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1982(<genexpr>)
      103    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:348(<lambda>)
       81    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:820(gen)
       81    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:1232(_neg_)
       79    0.011    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:411(_coefficient_fast)
       73    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:140(is_FractionField)
       70    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:502(__cmp__)
       69    0.002    0.000    0.005    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:349(_add_)
       69    0.002    0.000    0.030    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:737(_acted_upon_)
       69    0.001    0.000    0.008    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/commutative_additive_semigroups.py:143(__add__)
       69    0.001    0.000    0.001    0.000 {sage.combinat.dict_addition.dict_addition}
       68    0.003    0.000    0.010    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/infinity.py:377(_mul_)
       66    0.001    0.000    0.068    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:1054(__iter__)
       60    0.004    0.000    0.059    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:527(_element_constructor_)
       59    0.001    0.000    0.013    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:448(coefficient)
       52    0.004    0.000    0.340    0.007 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1277(<genexpr>)
       52    0.000    0.000    0.000    0.000 {method 'codomain' of 'sage.categories.map.Map' objects}
       52    0.000    0.000    0.000    0.000 {method 'domain' of 'sage.categories.map.Map' objects}
       51    0.022    0.000    0.202    0.004 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sfa.py:988(_from_cache)
       51    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:97(monomial_coefficients)
       50    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1576(_on_basis)
       48    0.001    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1984(term)
       48    0.003    0.000    0.064    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:318(next)
       48    0.011    0.000    0.045    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:192(rightmost_pivot)
       48    0.004    0.000    0.014    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:38(first)
       46    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:52(__iter__)
     44/4    0.001    0.000    0.483    0.121 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1958(linear_combination)
     44/4    0.001    0.000    0.483    0.121 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1368(__call__)
       43    0.000    0.000    0.000    0.000 {method 'insert' of 'list' objects}
       41    0.001    0.000    0.175    0.004 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:574(_s_to_self)
       40    0.000    0.000    0.000    0.000 {sage.structure.element.get_coercion_model}
       40    0.003    0.000    0.039    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/new_kschur.py:299(_element_constructor_)
       40    0.004    0.000    0.013    0.000 {method 'bin_op' of 'sage.structure.coerce.CoercionModel_cache_maps' objects}
       38    0.000    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/algebras_with_basis.py:216(from_base_ring_from_one_basis)
       32    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:250(Partition)
       31    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sf.py:885(hall_littlewood)
       31    0.000    0.000    0.000    0.000 {method 'sort' of 'list' objects}
       31    0.005    0.000    0.006    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:562(support)
       31    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:141(ambient)
       29    0.001    0.000    0.011    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/commutative_additive_semigroups.py:168(__radd__)
       28    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:514(<genexpr>)
       22    0.001    0.000    0.019    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1110(<genexpr>)
       20    0.000    0.000    0.007    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:652(trailing_item)
       20    0.000    0.000    0.008    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/misc/misc.py:2149(__call__)
       20    0.000    0.000    0.004    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:624(trailing_support)
       20    0.000    0.000    0.000    0.000 {getattr}
       20    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/misc/sage_itertools.py:33(min_cmp)
       19    0.001    0.000    0.015    0.001 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1296(_element_constructor_)
       18    0.001    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:882(__init__)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:329(Qp)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/new_kschur.py:176(kschur)
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/integer_list.py:1014(build_args)
       18    0.000    0.000    0.000    0.000 {method 'keys' of 'dict' objects}
       18    0.003    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:488(is_zero)
       18    0.000    0.000    0.000    0.000 {sorted}
       18    0.000    0.000    0.000    0.000 {all}
       18    0.000    0.000    0.000    0.000 {method 'values' of 'dict' objects}
       18    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/partition.py:779(size)
       18    0.000    0.000    0.000    0.000 {method 'join' of 'str' objects}
       18    0.001    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sf.py:1110(kBoundedSubspace)
     14/1    0.000    0.000    0.537    0.537 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/algebras.py:190(__mul__)
       14    0.001    0.000    0.065    0.005 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1234(<genexpr>)
       13    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:141(P)
       12    0.001    0.000    0.038    0.003 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1076(retract)
       12    0.001    0.000    0.355    0.030 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1236(_khlp_to_dks_on_basis)
       10    0.000    0.000    0.028    0.003 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:601(_self_to_s)
       10    0.000    0.000    0.002    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:392(_sub_)
       10    0.000    0.000    0.003    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/commutative_additive_groups.py:49(__sub__)
       10    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/new_kschur.py:749(<lambda>)
        9    0.001    0.000    0.003    0.000 {sage.libs.symmetrica.symmetrica.mult_schur_schur_symmetrica}
        9    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sf.py:762(schur)
        9    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/sfa.py:212(SymmetricFunctionAlgebra)
        8    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:206(kHallLittlewoodP)
        8    0.000    0.000    0.000    0.000 {sage.structure.element.parent}
        8    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/free_module.py:1279(__contains__)
        8    0.001    0.000    0.020    0.003 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/modules_with_basis.py:1691(preimage)
        6    0.001    0.000    0.072    0.012 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1204(_dks_to_khlp_on_basis)
      4/2    0.000    0.000    0.077    0.038 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/sets_cat.py:824(lift)
        4    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/combinat.py:739(__lt__)
      3/1    0.000    0.000    0.537    0.537 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/magmas.py:337(_mul_parent)
      2/1    0.000    0.000    0.052    0.052 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/categories/algebras_with_basis.py:308(_product_from_combinatorial_algebra_multiply)
        2    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:1112(lift)
        2    0.000    0.000    0.001    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:157(a_realization)
        2    0.000    0.000    0.077    0.038 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:679(lift)
        1    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/fraction_field.py:380(_repr_)
        1    0.004    0.004    0.008    0.008 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/schur.py:70(_multiply)
        1    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:1369(_repr_)
        1    0.000    0.000    0.537    0.537 <string>:1(<module>)
        1    0.000    0.000    0.537    0.537 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/k_dual.py:708(product)
        1    0.000    0.000    0.000    0.000 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/rings/polynomial/polynomial_ring.py:725(_repr_)
        1    0.000    0.000    0.052    0.052 /home/simon/SAGE/debug/sage-5.6.rc0/local/lib/python2.7/site-packages/sage/combinat/sf/hall_littlewood.py:677(_multiply)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

Hence, it seems to me that more caching (but weak caching, with UniqueRepresentation) will fix the problem.

@simon-king-jena
Copy link
Member

comment:15

A strange problem is the fact that __cmp__ is inherited from CombinatorialClass, even if I let Partitions_n inherit from UniqueRepresentation. I have to check why this is the case - if it inherits from UniqueRepresentation, then it should inherit both __hash__ and __cmp__ from it, and not only __hash__.

@simon-king-jena
Copy link
Member

comment:16

The following is very bad:

sage: class C(UniqueRepresentation, CombinatorialClass): pass
....: 
sage: C.__cmp__.__module__
'sage.combinat.combinat'
sage: C.__hash__.__module__
'sage.structure.unique_representation'

I'll ask sage-devel about it.

@simon-king-jena
Copy link
Member

comment:17

The following (in which I use UniqueRepresentation on Partitions_n) could also benefit from making UniqueRepresentation provide a cmp method as well:

sage: P = Partitions(1)
sage: Q = Partitions(4)
sage: %timeit P==Q  # this is how they do compare
625 loops, best of 3: 2.33 µs per loop
sage: %timeit P is Q # this is how UniqueRepresentation *should* compare
625 loops, best of 3: 248 ns per loop

@simon-king-jena
Copy link
Member

comment:18

Aha! It could actually be the overhead of calling UniqueRepresentation.__eq__, which is just a Python method. I see remarks like "Should be cythoned" in the code. Perhaps this should really be done, but on a different ticket.

@simon-king-jena
Copy link
Member

Experimental patch

@simon-king-jena
Copy link
Member

comment:19

Attachment: trac13991-UniqueRepresentation_for_partitions.patch.gz

I have attached an unfinished patch (if UniqueRepresentation is used, then I guess some doctests should be changed from using == to using is, and perhaps other tests will break).

Can you test whether this patch would completely resolve the regression we are dealing with here?

@simon-king-jena
Copy link
Member

comment:20

Aha. Cythoning UniqueRepresentation makes a lot of sense. Simply renaming sage/structure/unique_representation.py into sage/structure/unique_representation.pyx and updating module_list.py already yields (with the experimental patch:

sage: P = Partitions(1)
sage: Q = Partitions(4)
sage: %timeit P==Q
625 loops, best of 3: 986 ns per loop

I guess making UniqueRepresentation inherit its methods from a cdef class will improve it further.

@simon-king-jena
Copy link
Member

comment:21

Great! When implementing comparison of UniqueRepresentation via the __richcmp__ method of a cdef class, one gets:

sage: P = Partitions(1)
sage: Q = Partitions(4)
sage: %timeit P==Q
625 loops, best of 3: 696 ns per loop
sage: %timeit P is Q
625 loops, best of 3: 318 ns per loop

Still, I am not totally happy that it takes longer than 400 ns, but certainly 696 ns is a lot better than 2.33 µs. I will try to make cythoned unique representations work, but that will be on a different ticket.

@nthiery
Copy link
Contributor

nthiery commented Jan 24, 2013

comment:22

Hi Simon!

Replying to @simon-king-jena:

A strange problem is the fact that __cmp__ is inherited from CombinatorialClass, even if I let Partitions_n inherit from UniqueRepresentation. I have to check why this is the case - if it inherits from UniqueRepresentation, then it should inherit both __hash__ and __cmp__ from it, and not only __hash__.

Thanks for investigating performance of UniqueRepresentation. Do not waste time on making CombinatorialClass and UniqueRepresentation play perfectly smoothly. CombinatorialClass is meant to dissapear anyway.

Cheers,
Nicolas

@nthiery
Copy link
Contributor

nthiery commented Jan 24, 2013

comment:23

Other than that, a definite +1 on having Partitions_n have UniqueRepresentation and on cythoning UniqueRepresentation.

@simon-king-jena
Copy link
Member

Dependencies: #13605

@simon-king-jena
Copy link
Member

comment:45

Replying to @nbruin:

EDIT: Hm, this change didn't make a difference for me whatsoever. However, running

sage: %time TestSuite(F).run()

as second time gives me much better performance and in %prun the second time around, weyl_group.py:937(action) hardly shows up, so a certain amount of caching is probably happening already. Note that WeylGroup is a factory function that does some possibly rather expensive preprocessing of its arguments. I guess if Simon would make his _Weyl_group_A a weakly_cached_function (i'm sure someone experimented with its implementation somewhere) we might be OK.

No, since this factory function is uncached. The cache lives in UniqueRepresentation (from which the different flavours of Weyl groups inherit), and they have a weak cache. Using another weak cache won't help, I guess.

In fact, I think that if we're finding that WeylGroup is too expensive to create in typical usage scenarios (is this one?) we might want to consider if it's possible to make their creation cheaper,

OK. This makes sense.

That said, optimizations such as these should only be performed if we find they are needed. I wouldn't think that making a silly testsuite, which may not reflect typical time-critical use of this code at all, run faster as a reasonable optimization goal by itself.

OK, but who has typical use cases?

Something else.

I noticed that k_dual.py uses Partition, Partitions and Partitions_all_bounded quite a lot---without storing their results in most cases. Since their own cache is now weak, I wouldn't be surprised if here is the reason for the slow down.

Since these partitions are repeatedly used in different methods, I think they should be cached more strongly.

I see the following options:

  • Use a strong cache for Partition(s) in general.
  • Use a strong cache for Partition(s) only for those instances that were created inside of the sage.combinat.sf.k_dual module. This would be possible by applying the cached_function decorator to Partition(s): Partition = cached_function(Partition) should be enough.
  • Store a strong reference to the partitions that really were used in the parent that was really using them. Hence, proceed as I suggested it for Weyl groups.

What do you think?

@simon-king-jena
Copy link
Member

Changed dependencies from #13605 to #13605, #14225

@simon-king-jena
Copy link
Member

comment:46

I think it makes sense to change this ticket into a "task", and to create separate tickets for several independent aspects/ideas that make sense individually. See #14225 for one of these aspects.

@nbruin
Copy link
Contributor Author

nbruin commented Mar 4, 2013

comment:47

Replying to @simon-king-jena:

What do you think?

I think that if it is indeed the case that Partitions get deleted and recreated often and if that is resulting in unacceptable slowdowns, then someone who understands the usage scenarios should look at k_dual and ensure that the right partitions are kept around for long enough by installing a strong reference somewhere. I think making functions cached_function willy nilly is a bad approach because it gives you poor control over the lifetime. Indeed, making per-instance cached wrappers would sort-of work, because now the wrapper and hence the cache will die when the instance dies, but I dislike that approach because it hides what's going on.

Expecting that Partitions(n) will (eventually) be cheap is in my opinion a bad programming paradigm. I don't think we're making parents UniqueRepresentation as a speed optimization of creation. I think we're doing that because it's required for efficient and well-defined coercion.

Thus, whenever code has Partitions(n) in its inner loop, the consequences are for that code.

If you're absolutely intent on making TestSuite(F).run() perform better, I think it's much more productive to understand why running the testsuite a second time gives much better performance. There must be plenty of caching happening already.

The most important value of this exercise I think is as a case-study into the pitfalls of getting good performance relating to complicated parent structures. I'd hope you'll eventually find some general guidelines people should follow if they want their code to perform reasonably well.

@nthiery
Copy link
Contributor

nthiery commented Mar 5, 2013

comment:48

Hi guys!

Replying to @nbruin:

The most important value of this exercise I think is as a case-study into the pitfalls of getting good performance relating to complicated parent structures. I'd hope you'll eventually find some general guidelines people should follow if they want their code to perform reasonably well.

Sorry for jumping a bit late in the discussion.

Thanks for investigating this. I just wanted to say to not worry too
much about k-Schur functions, except as an interesting case
study. Except for a few people, this is not an intensively used
feature. And those few people doing some intensive calculations should
be in charge of optimizing the code.

Also, from the top of my head, the k in k-Schur is basically the same
as that for the Weyl group (+-1). So there won't be many groups
created and it indeed would make a lot of sense to keep a reference to
that Weyl group in the appropriate parent.

Cheers,
Nicolas

@simon-king-jena
Copy link
Member

comment:49

Replying to @nthiery:

Thanks for investigating this. I just wanted to say to not worry too
much about k-Schur functions, except as an interesting case
study.

I think the slow-down is dramatic enough, and we should do something against it.

Also, from the top of my head, the k in k-Schur is basically the same
as that for the Weyl group (+-1). So there won't be many groups
created and it indeed would make a lot of sense to keep a reference to
that Weyl group in the appropriate parent.

What about the partitions? My guess is that they can't be too many either (namely, they used to be strongly cached, but the k_schur tests did not run out of memory).

@simon-king-jena
Copy link
Member

comment:50

Concerning "modularity": At #14225, I do both the __classcall_private__ thing (which probably has very little influence on the running time) and the caching of Weyl groups. Shall I separate the two?

@simon-king-jena
Copy link
Member

comment:51

Replying to @simon-king-jena:

Concerning "modularity": At #14225, I do both the __classcall_private__ thing (which probably has very little influence on the running time) and the caching of Weyl groups. Shall I separate the two?

Sorry that I didn't wait for a reply. I updated #14225, so that it only deals with __classcall_private__, and will subsequently deal with the caches of partition.py (concerning Weyl groups and permutation groups) and k_dual (this concerns partitions) on a new ticket.

@simon-king-jena
Copy link
Member

comment:52

In fact, sage.combinat.sf.k_dual uses Partitions in a rather restricted way: There is precisely one instance of Partitions_all_bounded used, and Partitions is also used in a restricted way, namely always with max_part = self.k.

I think it really makes sense to cache this, because the cache will be limited (and will live in the objects that really use the cached data).

With this, I obtain:

sage: from sage.combinat.sf.k_dual import AffineSchurFunctions
sage: F = AffineSchurFunctions(SymmetricFunctions(QQ['t']).kBoundedQuotient(Integer(4),t=Integer(1)))
sage: %time TestSuite(F).run()
CPU times: user 5.93 s, sys: 0.06 s, total: 5.99 s
Wall time: 6.10 s

on the same machine as with the timings mentioned above. Hence, I think there is hope to solve the problem in a convenient way.

Since this ticket is now a "task", I will post my patch on a new ticket.

@tscrim
Copy link
Collaborator

tscrim commented Mar 5, 2013

comment:53

Hey Simon,

I have a patch which does the caching. Here's the message I was going to post (right) before the server crash:

With some further digging, there is exactly one meaningful call to Core.to_grassmannian() which is a k-core method which converts back to a k-bounded partition and then calls Partition.from_kbounded_to_grassmannian() which calls Partition.from_kbounded_to_reduced_word(). I've made a change which caches the Weyl group to the basis object and then made it directly call from_kbounded_to_reduce_word() (which also avoids going to a k-core and back). This doesn't significantly decreases the test suite time for me.

Here are my top function calls.

Before changes:

         2399942 function calls (2360396 primitive calls) in 31.765 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   350412    1.685    0.000    1.685    0.000 {isinstance}
     7830    1.391    0.000    4.542    0.001 weyl_group.py:937(action)
    42983    1.269    0.000    2.375    0.000 free_module.py:2142(_from_dict)
    24207    1.185    0.000    2.246    0.000 partition.py:651(__init__)
 12128/85    1.094    0.000   31.100    0.366 {sage.combinat.dict_addition.dict_linear_combination}
   155841    1.052    0.000    1.052    0.000 combinat.py:866(__hash__)
22548/19595    0.678    0.000    3.589    0.000 partition.py:4043(_element_constructor_)
127648/127051    0.581    0.000    0.658    0.000 {len}
     7880    0.517    0.000    0.982    0.000 free_module.py:660(_vector_)
    15325    0.493    0.000    2.820    0.000 partition.py:597(__classcall_private__)
     2949    0.491    0.000    1.211    0.000 polynomial_ring.py:298(_element_constructor_)
    50979    0.474    0.000    0.613    0.000 weakref.py:55(__getitem__)
    42983    0.445    0.000    0.445    0.000 free_module.py:34(__init__)
    24635    0.435    0.000    1.075    0.000 integer_list.py:1013(__cmp__)
    49602    0.420    0.000    0.532    0.000 {repr}
     1848    0.415    0.000    2.560    0.001 {sage.libs.symmetrica.symmetrica.t_SCHUR_HOMSYM_symmetrica}
    22657    0.379    0.000    1.191    0.000 partition.py:3929(__classcall_private__)
     7766    0.362    0.000    0.715    0.000 free_module.py:562(support)

After:

         2296313 function calls (2256847 primitive calls) in 30.238 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   330017    1.550    0.000    1.550    0.000 {isinstance}
     7848    1.381    0.000    4.508    0.001 weyl_group.py:937(action)
    43052    1.276    0.000    2.410    0.000 free_module.py:2142(_from_dict)
 12175/85    1.103    0.000   29.582    0.348 {sage.combinat.dict_addition.dict_linear_combination}
    21796    1.081    0.000    2.074    0.000 partition.py:651(__init__)
   155841    1.023    0.000    1.023    0.000 combinat.py:866(__hash__)
20133/17182    0.613    0.000    3.299    0.000 partition.py:4043(_element_constructor_)
111781/110905    0.501    0.000    0.580    0.000 {len}
     7873    0.500    0.000    0.754    0.000 free_module.py:660(_vector_)
     2949    0.498    0.000    1.202    0.000 polynomial_ring.py:298(_element_constructor_)
    43052    0.466    0.000    0.466    0.000 free_module.py:34(__init__)
    47386    0.448    0.000    0.585    0.000 weakref.py:55(__getitem__)
    24635    0.425    0.000    1.065    0.000 integer_list.py:1013(__cmp__)
    49654    0.420    0.000    0.531    0.000 {repr}
     1848    0.403    0.000    2.521    0.001 {sage.libs.symmetrica.symmetrica.t_SCHUR_HOMSYM_symmetrica}
    11256    0.382    0.000    2.309    0.000 partition.py:597(__classcall_private__)
     7766    0.356    0.000    0.709    0.000 free_module.py:562(support)
     1324    0.353    0.000    6.382    0.005 modules_with_basis.py:1690(preimage)

Doing some digging through all the data, the longest tests seems to be:

        1    0.000    0.000   16.398   16.398 monoids.py:150(_test_prod)
        1    0.000    0.000   10.306   10.306 semigroups.py:90(_test_associativity)

Which basically comes from doing x = F.an_element() and x*x*x. Here are my timings:
Before:

         589843 function calls (579632 primitive calls) in 8.102 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    86470    0.439    0.000    0.439    0.000 {isinstance}
     1888    0.338    0.000    1.115    0.001 weyl_group.py:937(action)
     7839    0.235    0.000    0.451    0.000 free_module.py:2142(_from_dict)
     4510    0.220    0.000    0.426    0.000 partition.py:651(__init__)
   2146/9    0.187    0.000    7.944    0.883 {sage.combinat.dict_addition.dict_linear_combination}
    25751    0.171    0.000    0.171    0.000 combinat.py:866(__hash__)
31144/30547    0.141    0.000    0.185    0.000 {len}
4271/3838    0.128    0.000    0.680    0.000 partition.py:4043(_element_constructor_)
     1938    0.126    0.000    0.421    0.000 free_module.py:660(_vector_)
    13883    0.125    0.000    0.166    0.000 weakref.py:55(__getitem__)
     3101    0.105    0.000    0.624    0.000 partition.py:597(__classcall_private__)
 1246/671    0.103    0.000    0.343    0.001 {method 'has_coerce_map_from' of 'sage.structure.parent.Parent' objects}
    12195    0.101    0.000    0.150    0.000 unique_representation.py:531(__hash__)
        3    0.086    0.029    0.086    0.029 {posix.waitpid}
     9170    0.085    0.000    0.120    0.000 {repr}
     7839    0.084    0.000    0.084    0.000 free_module.py:34(__init__)
     5173    0.083    0.000    0.241    0.000 partition.py:3929(__classcall_private__)
     1888    0.082    0.000    1.604    0.001 weyl_group.py:970(has_descent)

With changes:

         555235 function calls (545766 primitive calls) in 7.224 seconds

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    82808    0.390    0.000    0.390    0.000 {isinstance}
     1870    0.329    0.000    1.078    0.001 weyl_group.py:937(action)
     7616    0.235    0.000    0.435    0.000 free_module.py:2142(_from_dict)
     4254    0.212    0.000    0.401    0.000 partition.py:651(__init__)
   1997/9    0.186    0.000    7.050    0.783 {sage.combinat.dict_addition.dict_linear_combination}
    25751    0.167    0.000    0.167    0.000 combinat.py:866(__hash__)
28064/27772    0.123    0.000    0.147    0.000 {len}
    13289    0.122    0.000    0.165    0.000 weakref.py:55(__getitem__)
     1895    0.122    0.000    0.185    0.000 free_module.py:660(_vector_)
4015/3580    0.112    0.000    0.625    0.000 partition.py:4043(_element_constructor_)
    12002    0.112    0.000    0.158    0.000 unique_representation.py:531(__hash__)
     2658    0.100    0.000    0.564    0.000 partition.py:597(__classcall_private__)
 1240/665    0.099    0.000    0.341    0.001 {method 'has_coerce_map_from' of 'sage.structure.parent.Parent' objects}
     8986    0.086    0.000    0.116    0.000 {repr}
     1870    0.081    0.000    1.566    0.001 weyl_group.py:970(has_descent)
     7616    0.080    0.000    0.080    0.000 free_module.py:34(__init__)
     1870    0.078    0.000    0.111    0.000 free_module.py:634(coefficients)
     1935    0.077    0.000    0.136    0.000 infinity.py:889(_element_constructor_)

I can post my patch in the new ticket you create (I gather that it the appropriate thing to do for tasks). Sorry for the message bomb.

Best,

Travis

@simon-king-jena
Copy link
Member

comment:54

Replying to @tscrim:

With some further digging, there is exactly one meaningful call to Core.to_grassmannian() which is a k-core method which converts back to a k-bounded partition and then calls Partition.from_kbounded_to_grassmannian() which calls Partition.from_kbounded_to_reduced_word(). I've made a change which caches the Weyl group to the basis object and then made it directly call from_kbounded_to_reduce_word() (which also avoids going to a k-core and back). This doesn't significantly decreases the test suite time for me.

OK. Let's see how we will merge the two patches. At least part of it should be orthogonal (you talk here about Weyl group caching, but my to-be-posted patch is about caching of partitions).

@simon-king-jena
Copy link
Member

Changed dependencies from #13605, #14225 to #13605, #14225, #14288

@simon-king-jena
Copy link
Member

comment:56

I have created #14228 for the caching.

@simon-king-jena
Copy link
Member

comment:57

Sorry for the typo in the ticket number.

@simon-king-jena
Copy link
Member

Changed dependencies from #13605, #14225, #14288 to #13605, #14225, #14228

@simon-king-jena
Copy link
Member

Reviewer: Simon King

@simon-king-jena
Copy link
Member

comment:58

With sage-5.8.beta0 plus

trac11490-coercion_tutorial.patch
14182_whitespace.patch
trac_13618-rings_doc_real-ts.patch
trac_13618-rings_doc_complex-ts.patch
trac_13618-rings_doc_others-ts.patch
trac_14040_housekeeping.patch
trac_14040_repr_option.patch
trac_14040_doctest.patch
trac_14040_review.patch
trac14054_fast_methods-5.8.patch

I obtain

sage: from sage.combinat.sf.k_dual import AffineSchurFunctions
sage: F = AffineSchurFunctions(SymmetricFunctions(QQ['t']).kBoundedQuotient(Integer(4),t=Integer(1)))
sage: %time TestSuite(F).run()
CPU times: user 5.90 s, sys: 0.12 s, total: 6.02 s
Wall time: 7.39 s
sage: %time TestSuite(F).run()
CPU times: user 3.49 s, sys: 0.03 s, total: 3.53 s
Wall time: 3.53 s

and

sage -t sage/combinat/sf
...
All tests passed!
Total time for all tests: 100.5 seconds

and second time

All tests passed!
Total time for all tests: 101.8 seconds

Adding

trac_12313-mono_dict-combined-random-sk.patch
trac_13387-combined.patch
trac_13387-guard_gc.patch
trac_14159_weak_value_triple_dict.patch
trac_14159_use_cdef_get.patch
trac12951_cached_extension.patch
trac_14214-cython_homset.patch
trac_14214-backup_cache.patch
trac_14063-remove_cc_compositions-ts.patch
trac_13688-finite_sets_cardinality_override-ts.patch
trac_14138.patch
trac_14138-doctests.patch
trac_13605-partition_options-ts.patch
trac_14011-Sphinx_roles-fh.patch
trac_14054-fix-rigged-list.2.patch
trac_11410-zero_one_sequence_partitions-pod.v2.patch
trac_11410-zero_one_sequence_partitions-review-ts.patch
trac_14225-partition_classcall_private.patch

I obtain

sage: from sage.combinat.sf.k_dual import AffineSchurFunctions
sage: F = AffineSchurFunctions(SymmetricFunctions(QQ['t']).kBoundedQuotient(Integer(4),t=Integer(1)))
sage: %time TestSuite(F).run()
CPU times: user 10.30 s, sys: 0.26 s, total: 10.56 s
Wall time: 10.72 s
sage: %time TestSuite(F).run()
CPU times: user 9.58 s, sys: 0.09 s, total: 9.68 s
Wall time: 9.69 s

and

sage -t sage/combinat/sf
...
All tests passed!
Total time for all tests: 107.6 seconds

and second time

All tests passed!
Total time for all tests: 107.5 seconds

Adding

trac_14228-sym_speedup-ts.patch
trac_14228-reviewer.patch

I obtain

sage: from sage.combinat.sf.k_dual import AffineSchurFunctions
sage: F = AffineSchurFunctions(SymmetricFunctions(QQ['t']).kBoundedQuotient(Integer(4),t=Integer(1)))
sage: %time TestSuite(F).run()
CPU times: user 5.50 s, sys: 0.09 s, total: 5.59 s
Wall time: 5.60 s
sage: %time TestSuite(F).run()
CPU times: user 3.13 s, sys: 0.00 s, total: 3.13 s
Wall time: 3.13 s

and

sage -t sage/combinat/sf
...
All tests passed!
Total time for all tests: 102.2 seconds

and second time

All tests passed!
Total time for all tests: 102.2 seconds

Hence, it seems to me that #14228 did indeed fix the problem.

@jdemeyer
Copy link

jdemeyer commented Mar 6, 2013

comment:60

positive_review to what?

@simon-king-jena
Copy link
Member

comment:61

Replying to @jdemeyer:

positive_review to what?

To the fact that the issue (for which I originally thought we might need more independent tickets) is fixed by the dependencies of this "task" ticket.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants