Initial- and boundary-value problems in Maxima.
- Subject: Initial- and boundary-value problems in Maxima.
- From: Michel Talon
- Date: Wed, 21 Sep 2011 17:10:18 +0200
Raymond Toy wrote:
<...>
You asked to run sbcl statistical profiler only on colnew_expert. I have
done it the following way:
load(colnew);
:lisp(cl:require :sb-sprof "/usr/local/lib/sbcl/sb-sprof/sb-sprof.fasl")
load(prob2);
:lisp(sb-sprof:profile-call-counts "COLNEW")
:lisp(sb-sprof:with-profiling (:max-samples 10000 :report :flat :loop nil
)#$[iflag, fspace, ispace] : colnew_expert(ncomp, m, aleft, aright, zeta,
ipar, ltol, tol, fixpnt, ispace, fspace,0, fsub, dfsub, gsub, dgsub,
solutn)$)
The last one on one line.
Here is the result:
Number of samples: 403
Sample interval: 0.01 seconds
Total sampling time: 4.0299997 seconds
Number of cycles: 0
Sampled threads:
#<SB-THREAD:THREAD "initial thread" RUNNING {5B3F2EA9}>
Self Total Cumul
Nr Count % Count % Count % Calls Function
------------------------------------------------------------------------
1 36 8.9 36 8.9 36 8.9 - SB-EXT:WEAK-POINTER-
VALUE
2 28 6.9 75 18.6 64 15.9 - REMOVE-IF
3 18 4.5 18 4.5 82 20.3 - SB-C::COMPACT-INFO-
LOOKUP
4 16 4.0 16 4.0 98 24.3 - "foreign function
sigprocmask"
5 15 3.7 15 3.7 113 28.0 - SB-IMPL::GET3
6 14 3.5 75 18.6 127 31.5 - SIMPLIFYA
7 13 3.2 399 99.0 140 34.7 - MEVAL1
8 12 3.0 54 13.4 152 37.7 - (FLET SB-C::LOOKUP)
9 10 2.5 10 2.5 162 40.2 - SB-VM::ALLOC-SIGNED-
BIGNUM-IN-EAX
10 9 2.2 132 32.8 171 42.4 - MAKE-ARRAY
11 9 2.2 9 2.2 180 44.7 - SB-KERNEL:%MEMBER-EQ
12 9 2.2 9 2.2 189 46.9 - SB-C::VOLATILE-INFO-
LOOKUP
13 7 1.7 7 1.7 196 48.6 - SB-KERNEL:CSUBTYPEP
14 6 1.5 6 1.5 202 50.1 - LENGTH
15 6 1.5 6 1.5 208 51.6 - KEYWORDP
16 5 1.2 13 3.2 213 52.9 - SB-KERNEL:SPECIFIER-
TYPE
17 5 1.2 10 2.5 218 54.1 - EQUAL
18 5 1.2 8 2.0 223 55.3 - SB-KERNEL:VALUES-
SPECIFIER-TYPE
19 4 1.0 134 33.3 227 56.3 1584 COLNEW::VWBLOK
20 4 1.0 20 5.0 231 57.3 - SUBTYPEP
21 4 1.0 8 2.0 235 58.3 - ALIKE1
22 4 1.0 8 2.0 239 59.3 - SAFE-MGET
23 4 1.0 6 1.5 243 60.3 - REDUCE
24 4 1.0 6 1.5 247 61.3 - SB-C::CLASS-INFO-OR-
LOSE
25 4 1.0 5 1.2 251 62.3 - SB-C::FIND-TYPE-INFO
26 4 1.0 4 1.0 255 63.3 - (LABELS SB-
IMPL::EQUAL-AUX)
27 4 1.0 4 1.0 259 64.3 - SB-KERNEL::%%TYPEP
28 4 1.0 4 1.0 263 65.3 - (LAMBDA (SB-
IMPL::VALUE))
29 3 0.7 38 9.4 266 66.0 - MACRO-FUNCTION
30 3 0.7 12 3.0 269 66.7 - TIMESIN
31 3 0.7 8 2.0 272 67.5 - GETL
32 3 0.7 3 0.7 275 68.2 - DELETE
33 3 0.7 3 0.7 278 69.0 - SB-KERNEL:HAIRY-DATA-
VECTOR-REF/CHECK-BOUNDS
34 3 0.7 3 0.7 281 69.7 - BADFUNCHK
35 3 0.7 3 0.7 284 70.5 - GETCHARN
36 3 0.7 3 0.7 287 71.2 - MTIMESP
37 2 0.5 380 94.3 289 71.7 74 COLNEW::LSYSLV
38 2 0.5 45 11.2 291 72.2 - GETL-LM-FCN-PROP
39 2 0.5 31 7.7 293 72.7 - SB-KERNEL:FDEFINITION-
OBJECT
40 2 0.5 29 7.2 295 73.2 - MSET
41 2 0.5 29 7.2 297 73.7 - MBIND-DOIT
42 2 0.5 29 7.2 299 74.2 - SIMPTIMES
43 2 0.5 22 5.5 301 74.7 - SB-IMPL::%COMPLEX-
VECTOR-WIDETAG
44 2 0.5 19 4.7 303 75.2 - (LAMBDA (SB-C::NAME))
45 2 0.5 12 3.0 305 75.7 - MUNBIND
46 2 0.5 9 2.2 307 76.2 - SB-VM::GENERIC-+
47 2 0.5 4 1.0 309 76.7 - SB-KERNEL:TWO-ARG->
48 2 0.5 3 0.7 311 77.2 - SB-KERNEL:TWO-ARG-<
49 2 0.5 2 0.5 313 77.7 - NOTLOREQ
50 2 0.5 2 0.5 315 78.2 - $LISTP
51 2 0.5 2 0.5 317 78.7 - SB-KERNEL:TYPE-
SPECIFIER
52 2 0.5 2 0.5 319 79.2 - (LAMBDA (SB-C::NAME))
53 2 0.5 2 0.5 321 79.7 - SB-C::GET-INFO-VALUE
54 2 0.5 2 0.5 323 80.1 - LIST
55 2 0.5 2 0.5 325 80.6 - SB-KERNEL:VECTOR-
SUBSEQ*
56 2 0.5 2 0.5 327 81.1 - $SUBVARP
57 2 0.5 2 0.5 329 81.6 - MNUMP
58 2 0.5 2 0.5 331 82.1 - SB-BIGNUM:BIGNUM-
TRUNCATE
59 2 0.5 2 0.5 333 82.6 - (LAMBDA (&REST REST))
60 2 0.5 2 0.5 335 83.1 - F2CL-LIB::FIND-ARRAY-
DATA
61 1 0.2 399 99.0 336 83.4 - MEVAL
62 1 0.2 213 52.9 337 83.6 - MLAMBDA
63 1 0.2 152 37.7 338 83.9 - FSUB
64 1 0.2 116 28.8 339 84.1 - MEVALARGS
65 1 0.2 49 12.2 340 84.4 - MAXIMA-SUBSTITUTE
66 1 0.2 45 11.2 341 84.6 - SUBST1
67 1 0.2 34 8.4 342 84.9 - FUNCTIONP
68 1 0.2 30 7.4 343 85.1 - MBIND
69 1 0.2 22 5.5 344 85.4 - FBOUNDP
70 1 0.2 20 5.0 345 85.6 - SB-INT:ABOUT-TO-
MODIFY-SYMBOL-VALUE
71 1 0.2 16 4.0 346 85.9 - SB-INT:INFO
72 1 0.2 15 3.7 347 86.1 396 COLNEW::DGEFA
73 1 0.2 14 3.5 348 86.4 - F2CL-LIB::EXECUTE-
FORMAT
74 1 0.2 12 3.0 349 86.6 49 COLNEW::SBBLOK
75 1 0.2 10 2.5 350 86.8 - SB-KERNEL:%COERCE-
CALLABLE-TO-FUN
76 1 0.2 9 2.2 351 87.1 - PLS
77 1 0.2 5 1.2 352 87.3 - MAKUNBOUND
78 1 0.2 5 1.2 353 87.6 5872 COLNEW::APPROX
79 1 0.2 4 1.0 354 87.8 - SUBST0
80 1 0.2 4 1.0 355 88.1 - PLUSIN
81 1 0.2 4 1.0 356 88.3 - COMMON-LISP:MAKUNBOUND
82 1 0.2 3 0.7 357 88.6 - ALIKE
83 1 0.2 3 0.7 358 88.8 - SIMPARGS
84 1 0.2 3 0.7 359 89.1 - TIMESK
85 1 0.2 2 0.5 360 89.3 - TESTTNEG
86 1 0.2 2 0.5 361 89.6 - GREAT
87 1 0.2 2 0.5 362 89.8 - QUEUE+P
88 1 0.2 2 0.5 363 90.1 - MEVAL2
89 1 0.2 2 0.5 364 90.3 - EXPTB
90 1 0.2 2 0.5 365 90.6 52818 COLNEW::DAXPY
91 1 0.2 2 0.5 366 90.8 - FPCOFRAT1
92 1 0.2 2 0.5 367 91.1 - SB-KERNEL::NUMBER-
UNPARSE-TYPE-METHOD
93 1 0.2 1 0.2 368 91.3 - SB-C::VARIFY-LAMBDA-
ARG
94 1 0.2 1 0.2 369 91.6 - SB-KERNEL:MAKE-VALUES-
TYPE
95 1 0.2 1 0.2 370 91.8 - MATCHECK
96 1 0.2 1 0.2 371 92.1 - CPUT
97 1 0.2 1 0.2 372 92.3 - ARRAY-ELEMENT-TYPE
98 1 0.2 1 0.2 373 92.6 - (LABELS SB-
IMPL::SXHASH-RECURSE)
99 1 0.2 1 0.2 374 92.8 - SB-KERNEL:TWO-ARG-=
100 1 0.2 1 0.2 375 93.1 - SB-KERNEL:TWO-ARG-AND
101 1 0.2 1 0.2 376 93.3 - MAPPLY
102 1 0.2 1 0.2 377 93.5 - MPLUSP
103 1 0.2 1 0.2 378 93.8 - GETOPR0
104 1 0.2 1 0.2 379 94.0 - SB-IMPL::%OUTPUT-
REASONABLE-INTEGER-IN-BASE
105 1 0.2 1 0.2 380 94.3 - SB-INT:VALID-FUNCTION-
NAME-P
106 1 0.2 1 0.2 381 94.5 - SB-KERNEL:TWO-ARG-+
107 1 0.2 1 0.2 382 94.8 - EXPT
108 1 0.2 1 0.2 383 95.0 - SB-KERNEL:VECTOR-
SIGNED-BYTE-32-P
109 1 0.2 1 0.2 384 95.3 - MDEFLISTP
110 1 0.2 1 0.2 385 95.5 - SIMPQUOT
111 1 0.2 1 0.2 386 95.8 - ARRAY-TOTAL-SIZE
112 1 0.2 1 0.2 387 96.0 - SB-KERNEL:%ASSOC-EQ
113 1 0.2 1 0.2 388 96.3 - ONEP1
114 1 0.2 1 0.2 389 96.5 1291 COLNEW::RKBAS
115 1 0.2 1 0.2 390 96.8 - SB-KERNEL::INTEGER-/-
INTEGER
116 1 0.2 1 0.2 391 97.0 - SB-BIGNUM:BIGNUM-
LOGCOUNT
117 1 0.2 1 0.2 392 97.3 - SB-INT:LEGAL-FUN-NAME-
OR-TYPE-ERROR
118 1 0.2 1 0.2 393 97.5 - MXORLISTP
119 1 0.2 1 0.2 394 97.8 - SB-INT:EQUAL-BUT-NO-
CAR-RECURSION
120 1 0.2 1 0.2 395 98.0 - RISPLIT
121 1 0.2 1 0.2 396 98.3 - NTHCDR
122 1 0.2 1 0.2 397 98.5 - REALPART
123 1 0.2 1 0.2 398 98.8 - SB-C:RETURN-MULTIPLE
124 1 0.2 1 0.2 399 99.0 - ZEROP1
125 1 0.2 1 0.2 400 99.3 - (LAMBDA (SB-C::NAME))
126 1 0.2 1 0.2 401 99.5 - WRITE-STRING
127 1 0.2 1 0.2 402 99.8 - TRUNCATE
128 1 0.2 1 0.2 403 100.0 - SB-KERNEL:VECTOR-
DOUBLE-FLOAT-P
129 0 0.0 399 99.0 403 100.0 - SB-INT:SIMPLE-EVAL-IN-
LEXENV
I stopped at the function which has 0 direct sample in it.
The problem is always the same, sampling at 0.01s gives to few samples, and
there are very little samples in colnew code. Most samples are inside sbcl
or maxima code. It is interesting to look at the column Total. For example
if one looks at the line 63 one sees that fsub has just 1 sample directly
inside it, but has 152 samples in functions called from fsub (37.7%) that is
in functions from maxima which evaluate fsub. Similarly lsyslv in line 37
has 380 samples (94.3 %) of samples in functions called from it, which is
not surprising since almost everything in colnew is called from lsyslv.
Now look at dgesl, which we know uses a fair amount of time. It doesn't
even appear above, it is at line 154:
154 0 0.0 50 12.4 403 100.0 2782 COLNEW::DGESL
it has no sample directly in it and 50 samples in functions called from
dgesl. What are these functions? Maybe some boxing or unboxing or indexing
which appears inside the lisp translation of dgesl.
By the way, one can shorten the sampling time, by doing:
:lisp(sb-sprof:with-profiling (:max-samples 10000 :sample-interval 0.001
:report :flat :loop nil )#$[iflag, fspace, ispace] : colnew_expert(ncomp, m,
aleft, aright, zeta, ipar, ltol, tol, fixpnt, ispace, fspace,0, fsub, dfsub,
gsub, dgsub, solutn)$)
One gets the more statistically significant result, but which doesn't change
much the top scorers (note that daxpy in line 36 has 39 direct samples, but
57 samples from functions called within, what functions?)
Number of samples: 6566
Sample interval: 0.001 seconds
Total sampling time: 6.566 seconds
Number of cycles: 0
Sampled threads:
#<SB-THREAD:THREAD "initial thread" RUNNING {5B3F2EA9}>
Self Total Cumul
Nr Count % Count % Count % Calls Function
------------------------------------------------------------------------
1 413 6.3 413 6.3 413 6.3 - SB-EXT:WEAK-POINTER-
VALUE
2 328 5.0 889 13.5 741 11.3 - REMOVE-IF
3 319 4.9 319 4.9 1060 16.1 - "foreign function
sigprocmask"
4 290 4.4 290 4.4 1350 20.6 - SB-C::COMPACT-INFO-
LOOKUP
5 191 2.9 191 2.9 1541 23.5 - SB-VM::ALLOC-SIGNED-
BIGNUM-IN-EAX
6 177 2.7 1273 19.4 1718 26.2 - SIMPLIFYA
7 173 2.6 173 2.6 1891 28.8 - SB-IMPL::GET3
8 160 2.4 6507 99.1 2051 31.2 - MEVAL1
9 117 1.8 117 1.8 2168 33.0 - SB-KERNEL:%MEMBER-EQ
10 112 1.7 685 10.4 2280 34.7 - (FLET SB-C::LOOKUP)
11 109 1.7 109 1.7 2389 36.4 - SB-C::VOLATILE-INFO-
LOOKUP
12 105 1.6 107 1.6 2494 38.0 - (LABELS SB-
IMPL::EQUAL-AUX)
13 97 1.5 220 3.4 2591 39.5 - SB-KERNEL:VALUES-
SPECIFIER-TYPE
14 97 1.5 146 2.2 2688 40.9 - ALIKE1
15 95 1.4 95 1.4 2783 42.4 - (LAMBDA (SB-
IMPL::VALUE))
16 76 1.2 2082 31.7 2859 43.5 - MAKE-ARRAY
17 74 1.1 74 1.1 2933 44.7 - SB-IMPL::GET2
18 73 1.1 107 1.6 3006 45.8 5872 COLNEW::APPROX
19 65 1.0 277 4.2 3071 46.8 - SB-KERNEL:SPECIFIER-
TYPE
20 64 1.0 175 2.7 3135 47.7 - EQUAL
21 64 1.0 64 1.0 3199 48.7 - KEYWORDP
22 63 1.0 69 1.1 3262 49.7 - LENGTH
23 62 0.9 124 1.9 3324 50.6 - GETL
24 62 0.9 62 0.9 3386 51.6 - SB-C::GET-INFO-VALUE
25 60 0.9 60 0.9 3446 52.5 - SB-KERNEL:CSUBTYPEP
26 55 0.8 120 1.8 3501 53.3 - SB-VM::GENERIC-+
27 54 0.8 269 4.1 3555 54.1 - SUBTYPEP
28 53 0.8 53 0.8 3608 54.9 - BADFUNCHK
29 52 0.8 63 1.0 3660 55.7 - SB-C::FIND-TYPE-INFO
30 46 0.7 74 1.1 3706 56.4 - ARRAY-ELEMENT-TYPE
31 46 0.7 59 0.9 3752 57.1 - DELETE
32 43 0.7 148 2.3 3795 57.8 - PLS
33 43 0.7 43 0.7 3838 58.5 - (LABELS SB-
IMPL::SXHASH-RECURSE)
34 42 0.6 230 3.5 3880 59.1 - TIMESIN
35 41 0.6 6112 93.1 3921 59.7 74 COLNEW::LSYSLV
36 39 0.6 57 0.9 3960 60.3 52818 COLNEW::DAXPY
37 38 0.6 2206 33.6 3998 60.9 1584 COLNEW::VWBLOK
38 38 0.6 1685 25.7 4036 61.5 - MEVALARGS
39 37 0.6 799 12.2 4073 62.0 - SUBST1
40 37 0.6 37 0.6 4110 62.6 - MNUMP
41 36 0.5 92 1.4 4146 63.1 - ALIKE
42 36 0.5 55 0.8 4182 63.7 - ZEROP1
43 35 0.5 417 6.4 4217 64.2 - SIMPTIMES
44 35 0.5 35 0.5 4252 64.8 - SXHASH
45 34 0.5 356 5.4 4286 65.3 - MSET
46 33 0.5 216 3.3 4319 65.8 - SB-C::TYPE-INFO-OR-
LOSE
47 32 0.5 36 0.5 4351 66.3 - SB-KERNEL:%WITH-ARRAY-
DATA
48 32 0.5 32 0.5 4383 66.8 - SB-INT:EQUAL-BUT-NO-
CAR-RECURSION
49 31 0.5 243 3.7 4414 67.2 - SB-INT:INFO
50 31 0.5 83 1.3 4445 67.7 - SB-C::CLASS-INFO-OR-
LOSE
51 31 0.5 58 0.9 4476 68.2 - SB-IMPL::BACKQ-LIST
52 30 0.5 48 0.7 4506 68.6 - EQTEST
53 28 0.4 54 0.8 4534 69.1 - RISPLIT
54 28 0.4 28 0.4 4562 69.5 - AT-SUBSTP
55 27 0.4 473 7.2 4589 69.9 - SB-KERNEL:FDEFINITION-
OBJECT
56 27 0.4 27 0.4 4616 70.3 - $BFLOATP
57 26 0.4 27 0.4 4642 70.7 - SB-KERNEL:TWO-ARG-=
58 24 0.4 307 4.7 4666 71.1 - TMS
59 24 0.4 39 0.6 4690 71.4 - SB-INT:LEGAL-FUN-NAME-
OR-TYPE-ERROR
60 23 0.4 711 10.8 4713 71.8 2782 COLNEW::DGESL
61 23 0.4 326 5.0 4736 72.1 - MBIND-DOIT
62 23 0.4 216 3.3 4759 72.5 - SIMPLUS
63 23 0.4 37 0.6 4782 72.8 - SB-KERNEL:TWO-ARG-+
64 23 0.4 23 0.4 4805 73.2 - F2CL-LIB::FIND-ARRAY-
DATA
65 22 0.3 450 6.9 4827 73.5 - MACRO-FUNCTION
66 22 0.3 45 0.7 4849 73.9 - REDUCE
67 21 0.3 105 1.6 4870 74.2 - SIMPARGS
68 21 0.3 24 0.4 4891 74.5 - GETCHARN
69 20 0.3 166 2.5 4911 74.8 - SB-KERNEL:%COERCE-
CALLABLE-TO-FUN
70 20 0.3 78 1.2 4931 75.1 - MEVAL2
71 20 0.3 73 1.1 4951 75.4 - TIMESK
72 20 0.3 23 0.4 4971 75.7 - SB-BIGNUM:BIGNUM-
TRUNCATE
73 20 0.3 20 0.3 4991 76.0 - SB-KERNEL:VECTOR-
DOUBLE-FLOAT-P
74 19 0.3 573 8.7 5010 76.3 - GETL-LM-FCN-PROP
75 19 0.3 19 0.3 5029 76.6 - SPECREPP
76 19 0.3 19 0.3 5048 76.9 - SB-KERNEL:TYPE-
SPECIFIER
77 19 0.3 19 0.3 5067 77.2 - TRUNCATE
78 18 0.3 6507 99.1 5085 77.4 - MEVAL
79 18 0.3 209 3.2 5103 77.7 1594 COLNEW::GBLOCK
80 17 0.3 1306 19.9 5120 78.0 - (FLET SB-IMPL::PURGE)
81 17 0.3 250 3.8 5137 78.2 - (LAMBDA (SB-C::NAME))
82 17 0.3 139 2.1 5154 78.5 - COMMON-LISP:MAKUNBOUND
83 17 0.3 106 1.6 5171 78.8 - SIMPEXPT
84 17 0.3 73 1.1 5188 79.0 - SAFE-MGET
85 17 0.3 31 0.5 5205 79.3 - SB-KERNEL::%%TYPEP
86 16 0.2 3307 50.4 5221 79.5 - MLAMBDA
87 16 0.2 236 3.6 5237 79.8 - UPGRADED-ARRAY-
ELEMENT-TYPE
88 16 0.2 61 0.9 5253 80.0 - PLUSIN
89 16 0.2 26 0.4 5269 80.2 - SB-KERNEL::NUMBER-
UNPARSE-TYPE-METHOD
90 16 0.2 16 0.2 5285 80.5 - MTIMESP
91 15 0.2 1325 20.2 5300 80.7 - SB-IMPL::%SAVE-
DISPLACED-ARRAY-BACKPOINTER
92 15 0.2 30 0.5 5315 80.9 - EXPT
93 15 0.2 21 0.3 5330 81.2 396 COLNEW::FACTRB
Running
:lisp(disassemble 'colnew::daxpy)
i have looked where are these samples for functions called from daxpy.
Apparently in functions like
ALLOC-SIGNED-BIGNUM-IN-ECX
ALLOC-SIGNED-BIGNUM-IN-EDI
and similar. Is this boxing and unboxing?
Looking similarly in the disassembly of dgesl, i see call to daxpy (normal)
but also fair number of calls to
#<FDEFINITION object for MAKE-ARRAY>
so calls inside lisp, and ALLOCS like above in great number.
--
Michel Talon