Slow to compile keymaps on armel
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
console-setup (Ubuntu) |
Invalid
|
Low
|
Unassigned |
Bug Description
Hi,
It takes 25 s to run "ckbcomp -model pc105 us >/dev/null" on a TI EVM board running jaunty/armel; this board is 500 MHz. On a 800 MHz Freescale Babbage board running jaunty/armel but perhaps building a different keymap, it's in the 5 seconds, and on my amd64 desktop it's sub-second.
ckbcomp could benefit from benchmarks and optimizations. We tried to add "use integer;" at the top and it didn't help.
Notes from conversation with Colin below; anybody is welcome to pickup the research.
12:22 < lool> cjwatson: Will it affect first boot?
12:22 < cjwatson> no, it won't
12:23 < cjwatson> it's interesting that it's so slow though
12:23 < lool> cjwatson: Ok, so it's normal that it takes so long on
12:23 < lool> Right, I find that really slow
12:23 < cjwatson> ckbcomp only uses maybe 5MB of memory tops
12:23 < cjwatson> $ time ckbcomp -model pc105 us '' '' >/dev/null
12:23 < cjwatson> real 0m0.618s
12:24 < lool> time (ckbcomp -model pc105 us >/dev/null) => 0m26.826s
12:24 < cjwatson> lool: is it possible that 'use integer;' near the top of
12:24 < lool> I don't see any faults in /proc/cpu/alignment
12:25 < cjwatson> I don't think it needs FP math
12:25 < lool> That's likely, trying
12:25 < lool> 0m25.583s
12:25 < lool> no
12:26 < cjwatson> might be worth trying it with -v 10 and seeing what's taking
12:27 < cjwatson> oh, hmm, -v 10 actually not that informative
12:27 -!- ember [n=pmf@
12:28 < cjwatson> verbose perl debugging will probably slow the whole thing
12:28 < cjwatson> maybe just print debugging at appropriate points?
12:29 < lool> Ok
12:33 < cjwatson> I don't have any other obvious bright ideas :-(
12:36 < lool> cjwatson: time is spent on iterations of this loop foreach my
$key (sort {$a <=> $b} (keys %symbols_table)) {
12:44 < cjwatson> lool: would be useful to know how many elements
12:44 < cjwatson> the actual work done in the inner loop is trivial
12:45 < cjwatson> if the hash lookups are taking ages then we could arrange to
12:46 < lool> cjwatson: flatten() is the one taking most time
12:47 < cjwatson> lool: flatten() isn't in the loop you mentioned ...
12:48 < cjwatson> oh, you're talking about a different loop than I'm looking at
12:48 * cjwatson starts again
12:50 < cjwatson> lool: the Devel::DProf module might help here
12:51 < cjwatson> 'perl -d:DProf /usr/bin/ckbcomp -model pc105 us >/dev/null'
...
12:48 < cjwatson> oh, you're talking about a different loop than I'm looking at
12:48 * cjwatson starts again
12:50 < cjwatson> lool: the Devel::DProf module might help here
12:51 < cjwatson> 'perl -d:DProf /usr/bin/ckbcomp -model pc105 us >/dev/null'
12:52 < persia> pitti, When you get a chance, could you look at bug #309396?
Bye
dprofpp -u to_string to_kernelsym keycodes_ definitions pattern symbols_ definitions
Total Elapsed Time = 27.45491 Seconds
User Time = 24.52491 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c Name
51.7 12.70 12.701 106928 0.0001 0.0001 main::approximate
40.0 9.831 26.264 103 0.0954 0.2550 main::flatten
16.4 4.030 4.030 9 0.4477 0.4477 main::file_
9.94 2.437 2.437 26368 0.0001 0.0001 main::distance
1.83 0.448 1.021 1648 0.0003 0.0006 main::x_
1.63 0.400 0.400 2 0.2000 0.2000 utf8::SWASHNEW
1.12 0.274 0.274 1648 0.0002 0.0002 main::x_to_ascii
1.10 0.271 0.611 3 0.0904 0.2037 main::xkb_
0.95 0.233 0.282 132 0.0018 0.0021 main::xkb_key
0.78 0.192 0.192 1048 0.0002 0.0002 main::matches_
0.57 0.140 0.140 3 0.0466 0.0465 main::BEGIN
0.38 0.094 0.094 784 0.0001 0.0001 main::uni_to_legacy
0.22 0.055 0.055 105 0.0005 0.0005 main::print_vector
0.17 0.041 1.344 6 0.0069 0.2241 main::xkb_
0.16 0.040 0.040 445 0.0001 0.0001 main::xkb_method