From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Dan Nicolaescu Newsgroups: gmane.emacs.devel Subject: Re: slow output in *compilation* buffer Date: Mon, 24 Aug 2009 13:24:57 -0700 (PDT) Message-ID: <200908242024.n7OKOvWQ001940@godzilla.ics.uci.edu> References: <200908220823.n7M8NAk5028199@godzilla.ics.uci.edu> <200908241852.n7OIqVDl001279@godzilla.ics.uci.edu> NNTP-Posting-Host: lo.gmane.org Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii X-Trace: ger.gmane.org 1251145619 21768 80.91.229.12 (24 Aug 2009 20:26:59 GMT) X-Complaints-To: usenet@ger.gmane.org NNTP-Posting-Date: Mon, 24 Aug 2009 20:26:59 +0000 (UTC) Cc: emacs-devel@gnu.org To: Stefan Monnier Original-X-From: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Mon Aug 24 22:26:51 2009 Return-path: Envelope-to: ged-emacs-devel@m.gmane.org Original-Received: from lists.gnu.org ([199.232.76.165]) by lo.gmane.org with esmtp (Exim 4.50) id 1Mfg7s-00060w-01 for ged-emacs-devel@m.gmane.org; Mon, 24 Aug 2009 22:26:48 +0200 Original-Received: from localhost ([127.0.0.1]:42864 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.43) id 1Mfg7q-0003w0-Vk for ged-emacs-devel@m.gmane.org; Mon, 24 Aug 2009 16:26:47 -0400 Original-Received: from mailman by lists.gnu.org with tmda-scanned (Exim 4.43) id 1Mfg7l-0003sq-AF for emacs-devel@gnu.org; Mon, 24 Aug 2009 16:26:41 -0400 Original-Received: from exim by lists.gnu.org with spam-scanned (Exim 4.43) id 1Mfg7g-0003lY-M3 for emacs-devel@gnu.org; Mon, 24 Aug 2009 16:26:40 -0400 Original-Received: from [199.232.76.173] (port=52963 helo=monty-python.gnu.org) by lists.gnu.org with esmtp (Exim 4.43) id 1Mfg7g-0003lQ-GC for emacs-devel@gnu.org; Mon, 24 Aug 2009 16:26:36 -0400 Original-Received: from barrelv2.ics.uci.edu ([128.195.1.114]:45009) by monty-python.gnu.org with esmtps (TLS-1.0:DHE_RSA_3DES_EDE_CBC_SHA1:24) (Exim 4.60) (envelope-from ) id 1Mfg7f-000709-TV for emacs-devel@gnu.org; Mon, 24 Aug 2009 16:26:36 -0400 Original-Received: from godzilla.ics.uci.edu (godzilla.ics.uci.edu [128.195.10.101]) by barrelv2.ics.uci.edu (8.13.8+Sun/8.13.8) with ESMTP id n7OKOwws004149; Mon, 24 Aug 2009 13:24:58 -0700 (PDT) Original-Received: (from dann@localhost) by godzilla.ics.uci.edu (8.13.8+Sun/8.13.6/Submit) id n7OKOvWQ001940; Mon, 24 Aug 2009 13:24:57 -0700 (PDT) In-Reply-To: <200908241852.n7OIqVDl001279@godzilla.ics.uci.edu> (Dan Nicolaescu's message of "Mon, 24 Aug 2009 11:52:31 -0700 (PDT)") Original-Lines: 112 X-ICS-MailScanner-Information: Please contact the ISP for more information X-ICS-MailScanner-ID: n7OKOwws004149 X-ICS-MailScanner: Found to be clean X-ICS-MailScanner-SpamCheck: not spam, SpamAssassin (score=-1.44, required 5, autolearn=disabled, ALL_TRUSTED -1.44) X-ICS-MailScanner-From: dann@godzilla.ics.uci.edu X-detected-operating-system: by monty-python.gnu.org: Solaris 10 (beta) X-BeenThere: emacs-devel@gnu.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: "Emacs development discussions." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Original-Sender: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Errors-To: emacs-devel-bounces+ged-emacs-devel=m.gmane.org@gnu.org Xref: news.gmane.org gmane.emacs.devel:114566 Archived-At: Dan Nicolaescu writes: > Stefan Monnier writes: > > > > % cumulative self self total > > > time seconds seconds calls s/call s/call name > > > 31.19 2.72 2.72 52618323 0.00 0.00 lookup_char_property > > > 20.30 4.49 1.77 51726150 0.00 0.00 previous_interval > > > 12.16 5.55 1.06 208889310 0.00 0.00 Fcdr > > > 5.85 6.06 0.51 52444384 0.00 0.00 Fassq > > > 5.39 6.53 0.47 4573 0.00 0.00 Fprevious_single_property_change > > > 2.64 6.76 0.23 8860105 0.00 0.00 mark_object > > > 2.52 6.98 0.22 10621 0.00 0.00 Fsetcar > > > 2.29 7.18 0.20 52618300 0.00 0.00 textget > > > 1.83 7.34 0.16 59828 0.00 0.00 re_search_2 > > > 1.72 7.49 0.15 305181 0.00 0.00 re_match_2_internal > > > 1.03 7.58 0.09 82087 0.00 0.00 Fbyte_code > > > 0.80 7.65 0.07 9094 0.00 0.00 adjust_for_invis_intang > > > 0.80 7.72 0.07 581767 0.00 0.00 find_interval > > > 0.69 7.78 0.06 295253 0.00 0.00 next_interval > > > 0.69 7.84 0.06 21 0.00 0.02 Fgarbage_collect > > > 0.57 7.89 0.05 23886 0.00 0.00 mark_vectorlike > > > > compile.el does its work via font-lock, so I do expect most/all of the > > time to be spent there. > > Another data point, take the process output out of the equation: > grep -nH -e emacs *.el */*.el > /tmp/t.grep > > emacs -Q /tmp/t.grep > M-x compilation-mode RET > M-x font-lock-fontify-buffer RET [this might not be necessary] > > > % cumulative self self total > time seconds seconds calls s/call s/call name > 35.13 5.54 5.54 102003560 0.00 0.00 lookup_char_property > 22.45 9.08 3.54 101705026 0.00 0.00 previous_interval > 13.57 11.22 2.14 408455379 0.00 0.00 Fcdr > 6.59 12.26 1.04 9018 0.00 0.00 Fprevious_single_property_change > 5.83 13.18 0.92 101946549 0.00 0.00 Fassq > 2.98 13.65 0.47 18460 0.00 0.00 Fsetcar > 1.71 13.92 0.27 9370435 0.00 0.00 mark_object > 1.59 14.17 0.25 102003522 0.00 0.00 textget > 1.46 14.40 0.23 54635 0.00 0.00 re_search_2 > 1.14 14.58 0.18 134737 0.00 0.00 Fbyte_code > 0.95 14.73 0.15 adjust_for_invis_intang > 0.95 14.88 0.15 525629 0.00 0.00 re_match_2_internal > 0.82 15.01 0.13 262725 0.00 0.00 next_interval > 0.63 15.11 0.10 2698 0.00 0.00 Frassq > 0.44 15.18 0.07 22 0.00 0.02 Fgarbage_collect > 0.32 15.23 0.05 541671 0.00 0.00 Ffuncall > 0.32 15.28 0.05 22906 0.00 0.00 mark_vectorlike > 0.19 15.31 0.03 584428 0.00 0.00 balance_an_interval > 0.13 15.33 0.02 2333591 0.00 0.00 multibyte_char_to_unibyte_safe > 0.13 15.35 0.02 315105 0.00 0.00 find_interval > 0.13 15.37 0.02 133764 0.00 0.00 funcall_lambda > 0.13 15.39 0.02 91236 0.00 0.00 add_properties > 0.13 15.41 0.02 18261 0.00 0.00 set_point_both > 0.13 15.43 0.02 9448 0.00 0.00 balance_intervals_internal > 0.13 15.45 0.02 5316 0.00 0.00 set_buffer_internal_1 > 0.13 15.47 0.02 92 0.00 0.00 mark_glyph_matrix > 0.13 15.49 0.02 Fmemory_limit > 0.06 15.50 0.01 1006998 0.00 0.00 specbind > 0.06 15.51 0.01 718455 0.00 0.00 Fcons > 0.06 15.52 0.01 621053 0.00 0.00 Faref And another data point and some explanation. Using -Q -nw instead of just -Q: % cumulative self self total time seconds seconds calls s/call s/call name 34.58 5.19 5.19 101981134 0.00 0.00 lookup_char_property 21.19 8.37 3.18 101705010 0.00 0.00 previous_interval 13.06 10.33 1.96 408395117 0.00 0.00 Fcdr 6.73 11.34 1.01 9018 0.00 0.00 Fprevious_single_property_change 6.73 12.35 1.01 101923589 0.00 0.00 Fassq 3.06 12.81 0.46 18459 0.00 0.00 Fsetcar 1.93 13.10 0.29 514797 0.00 0.00 re_match_2_internal 1.73 13.36 0.26 5072134 0.00 0.00 mark_object 1.60 13.60 0.24 31816 0.00 0.00 re_search_2 1.27 13.79 0.19 133095 0.00 0.00 Fbyte_code 1.20 13.97 0.18 256789 0.00 0.00 next_interval 1.07 14.13 0.16 2555 0.00 0.00 Frassq 1.07 14.29 0.16 adjust_for_invis_intang 1.00 14.44 0.15 101981134 0.00 0.00 textget 0.40 14.50 0.06 300850 0.00 0.00 find_interval 0.40 14.56 0.06 19 0.00 0.02 Fgarbage_collect 0.27 14.60 0.04 132114 0.00 0.00 funcall_lambda so roughly 40% less mark_object calls. Why? Although I use LANG=C, when using the X11 version (with this font: -b&h-lucidatypewriter-medium-r-normal-sans-12-120-75-75-m-70-iso8859-1) these charsets are read during startup: emacs/etc/charsets/MULE-tibetan.map emacs/etc/charsets/MULE-ethiopic.map emacs/etc/charsets/MULE-ipa.map emacs/etc/charsets/symbol.map emacs/etc/charsets/JISX0208.map emacs/etc/charsets/GB2312.map emacs/etc/charsets/BIG5.map emacs/etc/charsets/CNS-1.map emacs/etc/charsets/KSC5601.map and it seems that creates a lot of lisp objects. Is it necessary to read all these charsets? Creating that many lisp objects has second order effects on GC speed, and cache performance.