search

conjure-cp / conjure

Conjure: The Automated Constraint Modelling Tool
Other
94 stars 20 forks source link

Crossfigures spends an unusual amount of time in `Name.pretty` due to `Name.(==)` #640

Open CodingCellist opened 5 months ago

CodingCellist commented 5 months ago

This oddity was observed by Alessio. I recompiled conjure with profiling support and discovered that, for some reason, conjure spends the majority of its time in Conjure.Language.Name.(==) when compiling the crossfigures model. Name.(==) calls Name.pretty internally, which I would definitely expect to be slow (and seems to be an odd way of comparing name equality; but I'm likely missing some context).

Comparing with other models, knapsack and nqueens, they seem to spend a lot of time in Haskell's Pipes.Internal._bind (presumably due to file I/O or similar) and Conjure.Rules.rApply (which, from my completely unfamiliar view, makes more sense: conjure is spending most time in these models applying transformation rules).

This needs further investigation by someone more familiar with the internals than I am (I literally only knew how to build+profile the thing). I know a rewrite is planned, but this should (hopefully) still be interesting.

Sample profiling data, ordered in descending order by number of entries into the function:

Profiling data **CROSSFIGURES** ``` ,COST_CENTRE,MODULE,SRC,no.,entries,%time,%alloc,%time.1,%alloc.1 131115,pretty,Conjure.Language.Name,"src/Conjure/Language/Name.hs:(47,5)-(49,44)",371289,128578064956,8.3,1.2,57.4,53.1 131114,==,Conjure.Language.Name,"src/Conjure/Language/Name.hs:(24,5)-(25,47)",371288,65273912686,26.3,41.6,83.7,94.7 131931,==,Conjure.Language.Name,"src/Conjure/Language/Name.hs:(24,5)-(25,47)",372629,5095379520,0.1,0.1,0.3,0.2 24682,_bind.go,Pipes.Internal,"src/Pipes/Internal.hs:(111,5)-(115,29)",187963,4648414459,0.1,0.0,99.9,99.9 24681,_bind,Pipes.Internal,"src/Pipes/Internal.hs:(110,1)-(115,29)",187962,4585504019,0.1,0.1,100.0,100.0 122565,ghashWithSalt,Data.Hashable.Generic.Instances,src/Data/Hashable/Generic/Instances.hs:39:5-62,361232,2545869496,0.1,0.0,0.8,0.2 122569,hashSum,Data.Hashable.Generic.Instances,"src/Data/Hashable/Generic/Instances.hs:(103,5)-(107,46)",361234,2211598992,0.1,0.0,0.6,0.1 131937,==,Conjure.Language.Type,src/Conjure/Language/Type.hs:47:15-16,372633,1830807360,0.2,0.0,0.2,0.0 199884,pretty,Conjure.Language.Name,"src/Conjure/Language/Name.hs:(47,5)-(49,44)",353051,1681698120,0.1,0.0,0.8,0.7 122467,ghashWithSalt,Data.Hashable.Generic.Instances,src/Data/Hashable/Generic/Instances.hs:39:5-62,361480,1647331168,0.0,0.0,0.5,0.1 122470,hashSum,Data.Hashable.Generic.Instances,"src/Data/Hashable/Generic/Instances.hs:(103,5)-(107,46)",361483,1542418054,0.1,0.0,0.4,0.1 122566,ghashWithSalt,Data.Hashable.Generic.Instances,src/Data/Hashable/Generic/Instances.hs:43:5-36,361242,1532770348,0.1,0.0,0.1,0.0 131938,==,Conjure.Language.Type,src/Conjure/Language/Type.hs:90:15-16,372634,1296821880,0.0,0.0,0.0,0.0 24680,>>=,Pipes.Internal,src/Pipes/Internal.hs:103:5-18,187961,1175089659,0.0,0.0,100.0,100.0 122468,ghashWithSalt,Data.Hashable.Generic.Instances,src/Data/Hashable/Generic/Instances.hs:43:5-36,361489,1158426712,0.0,0.0,0.0,0.0 126668,>>,Pipes.Internal,src/Pipes/Internal.hs:101:10-47,358184,1140934568,0.1,0.0,0.1,0.0 130924,runExceptT,Conjure.Prelude,src/Conjure/Prelude.hs:450:33-42,369380,1033398480,0.0,0.0,0.0,0.0 130923,>>=,Conjure.Prelude,"src/Conjure/Prelude.hs:(461,5)-(465,39)",369245,1015014824,0.2,0.1,90.9,95.3 131118,runExceptT,Conjure.Prelude,src/Conjure/Prelude.hs:450:33-42,371148,990849272,0.0,0.0,0.0,0.0 122568,ghashWithSalt,Data.Hashable.Generic.Instances,src/Data/Hashable/Generic/Instances.hs:100:5-53,361233,988771388,0.0,0.0,0.7,0.2 ``` **NQUEENS** ``` ,COST_CENTRE,MODULE,SRC,no.,entries,%time,%alloc,%time.1,%alloc.1 6349,unArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:126:7-13,207093,20434503,0.0,0.0,0.0,0.0 22817,_bind.go,Pipes.Internal,"src/Pipes/Internal.hs:(111,5)-(115,29)",187963,16017989,1.3,0.1,93.9,94.5 22816,_bind,Pipes.Internal,"src/Pipes/Internal.hs:(110,1)-(115,29)",187962,15856886,1.0,2.2,94.9,96.7 6350,unMArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:158:7-14,207094,12734386,0.0,0.0,0.0,0.0 22815,>>=,Pipes.Internal,src/Pipes/Internal.hs:103:5-18,187961,5701200,0.3,1.0,95.3,97.8 67751,>>,Pipes.Internal,src/Pipes/Internal.hs:101:10-47,272934,5525381,1.6,0.5,1.6,0.5 67752,runExceptT,Conjure.Prelude,src/Conjure/Prelude.hs:450:33-42,272937,2650176,0.0,0.0,0.0,0.0 67755,rApply,Conjure.Rules.Definition,src/Conjure/Rules/Definition.hs:160:7-12,272938,2649857,2.5,1.2,56.8,52.7 123382,<*>,Pipes.Internal,"src/Pipes/Internal.hs:(88,5)-(93,39)",272932,2649857,0.2,0.4,2.1,1.8 123387,fmap.go,Pipes.Internal,"src/Pipes/Internal.hs:(80,9)-(84,40)",272969,2649857,0.8,1.2,0.8,1.2 123384,fmap,Pipes.Internal,"src/Pipes/Internal.hs:(79,5)-(84,40)",273258,2649857,0.2,0.4,1.6,1.5 123383,<*>.go,Pipes.Internal,"src/Pipes/Internal.hs:(89,9)-(93,39)",272933,2649857,0.3,0.0,1.9,1.5 123385,fmap.go,Pipes.Internal,"src/Pipes/Internal.hs:(80,9)-(84,40)",273259,2649857,1.4,1.1,1.4,1.1 123386,fmap,Pipes.Internal,"src/Pipes/Internal.hs:(79,5)-(84,40)",272968,2649857,0.2,0.4,1.0,1.6 67753,applicableRules.\,Conjure.UI.Model,"src/Conjure/UI/Model.hs:(1313,9)-(1323,17)",273260,2649857,4.8,10.8,4.9,10.8 6351,new_,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:208:1-28,207095,1923490,0.2,0.7,0.2,0.7 132063,unArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:126:7-13,265691,1112900,0.0,0.0,0.0,0.0 132059,follower.\,Data.Generics.Uniplate.Internal.Data,Data/Generics/Uniplate/Internal/Data.hs:158:25-49,265682,901107,0.1,0.0,0.9,0.1 132062,lookup#,Data.HashMap.Internal,Data/HashMap/Internal.hs:609:1-82,265685,901107,0.6,0.0,0.7,0.1 132065,hash,Data.Hashable.Class,src/Data/Hashable/Class.hs:758:5-56,265687,901107,0.0,0.0,0.1,0.1 ``` **KNAPSACK** ``` ,COST_CENTRE,MODULE,SRC,no.,entries,%time,%alloc,%time.1,%alloc.1 6716,unArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:126:7-13,208378,20434503,0.0,0.0,0.0,0.0 6717,unMArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:158:7-14,208379,12734386,0.0,0.0,0.0,0.0 23714,_bind.go,Pipes.Internal,"src/Pipes/Internal.hs:(111,5)-(115,29)",187963,7538016,1.5,0.1,89.3,92.4 23713,_bind,Pipes.Internal,"src/Pipes/Internal.hs:(110,1)-(115,29)",187962,7482061,1.1,2.1,90.4,94.5 23712,>>=,Pipes.Internal,src/Pipes/Internal.hs:103:5-18,187961,2756885,0.3,1.0,90.7,95.5 71535,>>,Pipes.Internal,src/Pipes/Internal.hs:101:10-47,278648,2568343,1.5,0.5,1.5,0.5 6718,new_,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:208:1-28,208380,1923490,0.4,1.3,0.4,1.3 71536,runExceptT,Conjure.Prelude,src/Conjure/Prelude.hs:450:33-42,278651,1230290,0.0,0.0,0.0,0.0 113191,fmap,Pipes.Internal,"src/Pipes/Internal.hs:(79,5)-(84,40)",278682,1230150,0.2,0.3,0.6,1.5 113192,fmap.go,Pipes.Internal,"src/Pipes/Internal.hs:(80,9)-(84,40)",278683,1230150,0.4,1.1,0.4,1.1 113187,<*>,Pipes.Internal,"src/Pipes/Internal.hs:(88,5)-(93,39)",278646,1230150,0.3,0.3,2.1,1.7 71539,rApply,Conjure.Rules.Definition,src/Conjure/Rules/Definition.hs:160:7-12,278652,1230150,2.2,1.1,50.2,48.5 113188,<*>.go,Pipes.Internal,"src/Pipes/Internal.hs:(89,9)-(93,39)",278647,1230150,0.3,0.0,1.9,1.4 113189,fmap,Pipes.Internal,"src/Pipes/Internal.hs:(79,5)-(84,40)",278972,1230150,0.1,0.3,1.6,1.4 113190,fmap.go,Pipes.Internal,"src/Pipes/Internal.hs:(80,9)-(84,40)",278973,1230150,1.4,1.0,1.4,1.0 71537,applicableRules.\,Conjure.UI.Model,"src/Conjure/UI/Model.hs:(1313,9)-(1323,17)",278974,1230150,4.7,10.2,4.9,10.2 122650,unArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:126:7-13,270274,658541,0.0,0.0,0.0,0.0 61862,unArray,Data.HashMap.Internal.Array,Data/HashMap/Internal/Array.hs:126:7-13,213168,559342,0.0,0.0,0.0,0.0 122651,hash,Data.HashMap.Internal,Data/HashMap/Internal.hs:180:1-28,270269,520961,0.1,0.0,0.2,0.1 122654,hashTypeRep.(...),Data.Hashable.Class,src/Data/Hashable/Class.hs:755:9-47,270273,520961,0.0,0.0,0.0,0.0 ```