]> granicus.if.org Git - vim/commitdiff
updated for version 7.3.1129 v7.3.1129
authorBram Moolenaar <Bram@vim.org>
Thu, 6 Jun 2013 12:01:46 +0000 (14:01 +0200)
committerBram Moolenaar <Bram@vim.org>
Thu, 6 Jun 2013 12:01:46 +0000 (14:01 +0200)
Problem:    Can't see what pattern in syntax highlighting is slow.
Solution:   Add the ":syntime" command.

runtime/doc/syntax.txt
src/ex_cmds.h
src/ex_cmds2.c
src/ex_docmd.c
src/proto/ex_cmds2.pro
src/proto/syntax.pro
src/structs.h
src/syntax.c
src/version.c

index d0f271b0858b33f7fb356551fda4f817b9d37d1e..7f296d142afa3a1191847df5c2540bbd859cc0ba 100644 (file)
@@ -37,6 +37,7 @@ In the User Manual:
 15. Highlighting tags          |tag-highlight|
 16. Window-local syntax                |:ownsyntax|
 17. Color xterms               |xterm-color|
+18. When syntax is slow                |:syntime|
 
 {Vi does not have any of these commands}
 
@@ -5086,4 +5087,60 @@ Also make sure TTpro's Setup / Window / Full Color is enabled, and make sure
 that Setup / Font / Enable Bold is NOT enabled.
 (info provided by John Love-Jensen <eljay@Adobe.COM>)
 
+
+==============================================================================
+18. When syntax is slow                                                *:syntime*
+
+This is aimed at authors of a syntax file.
+
+If your syntax causes redrawing to be slow, here are a few hints on making it
+faster.  To see slowness switch on some features that usually interfere, such
+as 'relativenumber' and |folding|.
+
+To find out what patterns are consuming most time, get an overview with this
+sequence: >
+       :syntime on
+       [ redraw the text at least once with CTRL-L ]
+       :syntime report
+
+This will display a list of syntax patterns that were used, sorted by the time
+it took to match them against the text.
+
+:syntime on            Start measuring syntax times.  This will add some
+                       overhead to compute the time spent on syntax pattern
+                       matching.
+
+:syntime off           Stop measuring syntax times.
+
+:syntime clear         Set all the counters to zero, restart measuring.
+
+:syntime report                Show the syntax items used since ":syntime on" in the
+                       current window.  Use a wider display to see more of
+                       the output.
+
+                       The list is sorted by total time. The columns are:
+                       TOTAL           Total time in seconds spent on
+                                       matching this pattern.
+                       COUNT           Number of times the pattern was used.
+                       MATCH           Number of times the pattern actually
+                                       matched
+                       SLOWEST         The longest time for one try.
+                       AVERAGE         The average time for one try.
+                       NAME            Name of the syntax item.  Note that
+                                       this is not unique.
+                       PATTERN         The pattern being used.
+
+Pattern matching gets slow when it has to try many alternatives.  Try to
+include as much literal text as possible to reduce the number of ways a
+pattern does NOT match.
+
+When using the "\@<=" and "\@<!" items, add a maximum size to avoid trying at
+all positions in the current and previous line.  For example, if the item is
+literal text specify the size of that text (in bytes):
+
+"<\@<=span"    Matches "span" in "<span".  This tries matching with "<" in
+               many places.
+"<\@1<=span"   Matches the same, but only tries one byte before "span".
+
+
  vim:tw=78:sw=4:ts=8:ft=help:norl:
index 75e1724e5f276d0d701b2d13d10bd960f24c3fd6..19740884b4666deaeb4357df9c9aec8dd874159e 100644 (file)
@@ -925,6 +925,8 @@ EX(CMD_swapname,    "swapname",     ex_swapname,
                        TRLBAR|CMDWIN),
 EX(CMD_syntax,         "syntax",       ex_syntax,
                        EXTRA|NOTRLCOM|CMDWIN),
+EX(CMD_syntime,                "syntime",      ex_syntime,
+                       WORD1|TRLBAR|CMDWIN),
 EX(CMD_syncbind,       "syncbind",     ex_syncbind,
                        TRLBAR),
 EX(CMD_t,              "t",            ex_copymove,
index 9afcc283adf49f73d816ddb9119e6413447ef6b3..40ad9a67f909f8c58a71fc5a195f3bf96e7bea30 100644 (file)
@@ -958,6 +958,36 @@ profile_zero(tm)
 
 # endif  /* FEAT_PROFILE || FEAT_RELTIME */
 
+#if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_FLOAT)
+# if defined(HAVE_MATH_H)
+#  include <math.h>
+# endif
+
+/*
+ * Divide the time "tm" by "count" and store in "tm2".
+ */
+    void
+profile_divide(tm, count, tm2)
+    proftime_T  *tm;
+    proftime_T  *tm2;
+    int                count;
+{
+    if (count == 0)
+       profile_zero(tm2);
+    else
+    {
+# ifdef WIN3264
+       tm2->QuadPart = tm->QuadPart / count;
+# else
+       double usec = (tm->tv_sec * 1000000.0 + tm->tv_usec) / count;
+
+       tm2->tv_sec = floor(usec / 1000000.0);
+       tm2->tv_usec = round(usec - (tm2->tv_sec * 1000000.0));
+# endif
+    }
+}
+#endif
+
 # if defined(FEAT_PROFILE) || defined(PROTO)
 /*
  * Functions for profiling.
@@ -1050,7 +1080,7 @@ profile_equal(tm1, tm2)
  */
     int
 profile_cmp(tm1, tm2)
-    proftime_T *tm1, *tm2;
+    const proftime_T *tm1, *tm2;
 {
 # ifdef WIN3264
     return (int)(tm2->QuadPart - tm1->QuadPart);
index 686ce3c9f8369d85a23b0b7d8d289416d9abcfed..9b8bf892708faa25f06efa692cc8ee7ed6f6f689 100644 (file)
@@ -242,6 +242,9 @@ static void ex_popup __ARGS((exarg_T *eap));
 # define ex_syntax             ex_ni
 # define ex_ownsyntax          ex_ni
 #endif
+#if !defined(FEAT_SYN_HL) || !defined(FEAT_RELTIME)
+# define ex_syntime            ex_ni
+#endif
 #ifndef FEAT_SPELL
 # define ex_spell              ex_ni
 # define ex_mkspell            ex_ni
index e4406d161ab351eec516da1dc4b16a8fa904f86e..d30ba41efab952dfc89f02cb0d7e68f581010bfb 100644 (file)
@@ -17,12 +17,13 @@ char *profile_msg __ARGS((proftime_T *tm));
 void profile_setlimit __ARGS((long msec, proftime_T *tm));
 int profile_passed_limit __ARGS((proftime_T *tm));
 void profile_zero __ARGS((proftime_T *tm));
+void profile_divide __ARGS((proftime_T *tm, int count, proftime_T *tm2));
 void profile_add __ARGS((proftime_T *tm, proftime_T *tm2));
 void profile_self __ARGS((proftime_T *self, proftime_T *total, proftime_T *children));
 void profile_get_wait __ARGS((proftime_T *tm));
 void profile_sub_wait __ARGS((proftime_T *tm, proftime_T *tma));
 int profile_equal __ARGS((proftime_T *tm1, proftime_T *tm2));
-int profile_cmp __ARGS((proftime_T *tm1, proftime_T *tm2));
+int profile_cmp __ARGS((const proftime_T *tm1, const proftime_T *tm2));
 void ex_profile __ARGS((exarg_T *eap));
 char_u *get_profile_name __ARGS((expand_T *xp, int idx));
 void set_context_in_profile_cmd __ARGS((expand_T *xp, char_u *arg));
index 7ae13e98eeb9d8ee61f05249e7090e8539261651..2f57051ca971c7ec94bfc009ede8ecd5bd218e01 100644 (file)
@@ -19,6 +19,7 @@ int get_syntax_info __ARGS((int *seqnrp));
 int syn_get_sub_char __ARGS((void));
 int syn_get_stack_item __ARGS((int i));
 int syn_get_foldlevel __ARGS((win_T *wp, long lnum));
+void ex_syntime __ARGS((exarg_T *eap));
 void init_highlight __ARGS((int both, int reset));
 int load_colors __ARGS((char_u *name));
 void do_highlight __ARGS((char_u *line, int forceit, int init));
index d7bb88e5a55475b328a6de4691a7570ba36fb7eb..20b12baf02930c1400a4dd08f63ec1341c87da8a 100644 (file)
@@ -1206,6 +1206,18 @@ struct dictvar_S
 typedef struct qf_info_S qf_info_T;
 #endif
 
+#ifdef FEAT_RELTIME
+/*
+ * Used for :syntime: timing of executing a syntax pattern.
+ */
+typedef struct {
+    proftime_T total;          /* total time used */
+    proftime_T slowest;        /* time of slowest call */
+    long       count;          /* nr of times used */
+    long       match;          /* nr of times matched */
+} syn_time_T;
+#endif
+
 /*
  * These are items normally related to a buffer.  But when using ":ownsyntax"
  * a window may have its own instance.
@@ -1230,6 +1242,9 @@ typedef struct {
     long       b_syn_sync_linebreaks;  /* offset for multi-line pattern */
     char_u     *b_syn_linecont_pat;    /* line continuation pattern */
     regprog_T  *b_syn_linecont_prog;   /* line continuation program */
+#ifdef FEAT_RELTIME
+    syn_time_T  b_syn_linecont_time;
+#endif
     int                b_syn_linecont_ic;      /* ignore-case flag for above */
     int                b_syn_topgrp;           /* for ":syntax include" */
 # ifdef FEAT_CONCEAL
index ed689601d034213415b47ccafe8a0bfb98a66517..6616e788d1462464d6d879a2e0004590ae253fb5 100644 (file)
@@ -153,6 +153,9 @@ typedef struct syn_pattern
     short       sp_syn_match_id;       /* highlight group ID of pattern */
     char_u     *sp_pattern;            /* regexp to match, pattern */
     regprog_T  *sp_prog;               /* regexp to match, program */
+#ifdef FEAT_RELTIME
+    syn_time_T  sp_time;
+#endif
     int                 sp_ic;                 /* ignore-case flag for sp_prog */
     short       sp_off_flags;          /* see below */
     int                 sp_offsets[SPO_COUNT]; /* offsets */
@@ -269,6 +272,8 @@ static keyentry_T dumkey;
  */
 static int keepend_level = -1;
 
+static char msg_no_items[] = N_("No Syntax items defined for this buffer");
+
 /*
  * For the current state we need to remember more than just the idx.
  * When si_m_endpos.lnum is 0, the items other than si_idx are unknown.
@@ -395,6 +400,21 @@ static short *copy_id_list __ARGS((short *list));
 static int in_id_list __ARGS((stateitem_T *item, short *cont_list, struct sp_syn *ssp, int contained));
 static int push_current_state __ARGS((int idx));
 static void pop_current_state __ARGS((void));
+#ifdef FEAT_RELTIME
+static void syn_clear_time __ARGS((syn_time_T *tt));
+static void syntime_clear __ARGS((void));
+#ifdef __BORLANDC__
+static int _RTLENTRYF syn_compare_syntime __ARGS((const void *v1, const void *v2));
+#else
+static int syn_compare_syntime __ARGS((const void *v1, const void *v2));
+#endif
+static void syntime_report __ARGS((void));
+static int syn_time_on = FALSE;
+# define IF_SYN_TIME(p) (p)
+#else
+# define IF_SYN_TIME(p) NULL
+typedef int syn_time_T;
+#endif
 
 static void syn_stack_apply_changes_block __ARGS((synblock_T *block, buf_T *buf));
 static void find_endpos __ARGS((int idx, lpos_T *startpos, lpos_T *m_endpos, lpos_T *hl_endpos, long *flagsp, lpos_T *end_endpos, int *end_idx, reg_extmatch_T *start_ext));
@@ -406,7 +426,7 @@ static void limit_pos_zero __ARGS((lpos_T *pos, lpos_T *limit));
 static void syn_add_end_off __ARGS((lpos_T *result, regmmatch_T *regmatch, synpat_T *spp, int idx, int extra));
 static void syn_add_start_off __ARGS((lpos_T *result, regmmatch_T *regmatch, synpat_T *spp, int idx, int extra));
 static char_u *syn_getcurline __ARGS((void));
-static int syn_regexec __ARGS((regmmatch_T *rmp, linenr_T lnum, colnr_T col));
+static int syn_regexec __ARGS((regmmatch_T *rmp, linenr_T lnum, colnr_T col, syn_time_T *st));
 static int check_keyword_id __ARGS((char_u *line, int startcol, int *endcol, long *flags, short **next_list, stateitem_T *cur_si, int *ccharp));
 static void syn_cmd_case __ARGS((exarg_T *eap, int syncing));
 static void syn_cmd_spell __ARGS((exarg_T *eap, int syncing));
@@ -977,7 +997,8 @@ syn_match_linecont(lnum)
     {
        regmatch.rmm_ic = syn_block->b_syn_linecont_ic;
        regmatch.regprog = syn_block->b_syn_linecont_prog;
-       return syn_regexec(&regmatch, lnum, (colnr_T)0);
+       return syn_regexec(&regmatch, lnum, (colnr_T)0,
+                               IF_SYN_TIME(&syn_block->b_syn_linecont_time));
     }
     return FALSE;
 }
@@ -2068,8 +2089,10 @@ syn_current_attr(syncing, displaying, can_spell, keep_state)
 
                            regmatch.rmm_ic = spp->sp_ic;
                            regmatch.regprog = spp->sp_prog;
-                           if (!syn_regexec(&regmatch, current_lnum,
-                                                            (colnr_T)lc_col))
+                           if (!syn_regexec(&regmatch,
+                                            current_lnum,
+                                            (colnr_T)lc_col,
+                                            IF_SYN_TIME(&spp->sp_time)))
                            {
                                /* no match in this line, try another one */
                                spp->sp_startcol = MAXCOL;
@@ -2950,7 +2973,8 @@ find_endpos(idx, startpos, m_endpos, hl_endpos, flagsp, end_endpos,
 
            regmatch.rmm_ic = spp->sp_ic;
            regmatch.regprog = spp->sp_prog;
-           if (syn_regexec(&regmatch, startpos->lnum, lc_col))
+           if (syn_regexec(&regmatch, startpos->lnum, lc_col,
+                                                 IF_SYN_TIME(&spp->sp_time)))
            {
                if (best_idx == -1 || regmatch.startpos[0].col
                                              < best_regmatch.startpos[0].col)
@@ -2981,7 +3005,8 @@ find_endpos(idx, startpos, m_endpos, hl_endpos, flagsp, end_endpos,
                lc_col = 0;
            regmatch.rmm_ic = spp_skip->sp_ic;
            regmatch.regprog = spp_skip->sp_prog;
-           if (syn_regexec(&regmatch, startpos->lnum, lc_col)
+           if (syn_regexec(&regmatch, startpos->lnum, lc_col,
+                                             IF_SYN_TIME(&spp_skip->sp_time))
                    && regmatch.startpos[0].col
                                             <= best_regmatch.startpos[0].col)
            {
@@ -3229,13 +3254,37 @@ syn_getcurline()
  * Returns TRUE when there is a match.
  */
     static int
-syn_regexec(rmp, lnum, col)
+syn_regexec(rmp, lnum, col, st)
     regmmatch_T        *rmp;
     linenr_T   lnum;
     colnr_T    col;
+    syn_time_T  *st;
 {
+    int r;
+#ifdef FEAT_RELTIME
+    proftime_T pt;
+
+    if (syn_time_on)
+       profile_start(&pt);
+#endif
+
     rmp->rmm_maxcol = syn_buf->b_p_smc;
-    if (vim_regexec_multi(rmp, syn_win, syn_buf, lnum, col, NULL) > 0)
+    r = vim_regexec_multi(rmp, syn_win, syn_buf, lnum, col, NULL);
+
+#ifdef FEAT_RELTIME
+    if (syn_time_on)
+    {
+       profile_end(&pt);
+       profile_add(&st->total, &pt);
+       if (profile_cmp(&pt, &st->slowest) < 0)
+           st->slowest = pt;
+       ++st->count;
+       if (r > 0)
+           ++st->match;
+    }
+#endif
+
+    if (r > 0)
     {
        rmp->startpos[0].lnum += lnum;
        rmp->endpos[0].lnum += lnum;
@@ -3769,7 +3818,7 @@ syn_cmd_list(eap, syncing)
 
     if (!syntax_present(curwin))
     {
-       MSG(_("No Syntax items defined for this buffer"));
+       MSG(_(msg_no_items));
        return;
     }
 
@@ -5609,6 +5658,9 @@ get_syn_pattern(arg, ci)
     if (ci->sp_prog == NULL)
        return NULL;
     ci->sp_ic = curwin->w_s->b_syn_ic;
+#ifdef FEAT_RELTIME
+    syn_clear_time(&ci->sp_time);
+#endif
 
     /*
      * Check for a match, highlight or region offset.
@@ -5783,8 +5835,11 @@ syn_cmd_sync(eap, syncing)
                cpo_save = p_cpo;
                p_cpo = (char_u *)"";
                curwin->w_s->b_syn_linecont_prog =
-                           vim_regcomp(curwin->w_s->b_syn_linecont_pat, RE_MAGIC);
+                      vim_regcomp(curwin->w_s->b_syn_linecont_pat, RE_MAGIC);
                p_cpo = cpo_save;
+#ifdef FEAT_RELTIME
+               syn_clear_time(&curwin->w_s->b_syn_linecont_time);
+#endif
 
                if (curwin->w_s->b_syn_linecont_prog == NULL)
                {
@@ -6471,6 +6526,179 @@ syn_get_foldlevel(wp, lnum)
 }
 #endif
 
+#ifdef FEAT_RELTIME
+/*
+ * ":syntime".
+ */
+    void
+ex_syntime(eap)
+    exarg_T    *eap;
+{
+    if (STRCMP(eap->arg, "on") == 0)
+       syn_time_on = TRUE;
+    else if (STRCMP(eap->arg, "off") == 0)
+       syn_time_on = FALSE;
+    else if (STRCMP(eap->arg, "clear") == 0)
+       syntime_clear();
+    else if (STRCMP(eap->arg, "report") == 0)
+       syntime_report();
+    else
+       EMSG2(_(e_invarg2), eap->arg);
+}
+
+    static void
+syn_clear_time(st)
+    syn_time_T *st;
+{
+    profile_zero(&st->total);
+    profile_zero(&st->slowest);
+    st->count = 0;
+    st->match = 0;
+}
+
+/*
+ * Clear the syntax timing for the current buffer.
+ */
+    static void
+syntime_clear()
+{
+    int                idx;
+    synpat_T   *spp;
+
+    if (!syntax_present(curwin))
+    {
+       MSG(_(msg_no_items));
+       return;
+    }
+    for (idx = 0; idx < curwin->w_s->b_syn_patterns.ga_len; ++idx)
+    {
+       spp = &(SYN_ITEMS(curwin->w_s)[idx]);
+       syn_clear_time(&spp->sp_time);
+    }
+}
+
+typedef struct
+{
+    proftime_T total;
+    int                count;
+    int                match;
+    proftime_T slowest;
+    proftime_T average;
+    int                id;
+    char_u     *pattern;
+} time_entry_T;
+
+    static int
+#ifdef __BORLANDC__
+_RTLENTRYF
+#endif
+syn_compare_syntime(v1, v2)
+    const void *v1;
+    const void *v2;
+{
+    const time_entry_T *s1 = v1;
+    const time_entry_T *s2 = v2;
+
+    return profile_cmp(&s1->total, &s2->total);
+}
+
+/*
+ * Clear the syntax timing for the current buffer.
+ */
+    static void
+syntime_report()
+{
+    int                idx;
+    synpat_T   *spp;
+    proftime_T tm;
+    int                len;
+    proftime_T total_total;
+    int                total_count = 0;
+    garray_T    ga;
+    time_entry_T *p;
+
+    if (!syntax_present(curwin))
+    {
+       MSG(_(msg_no_items));
+       return;
+    }
+
+    ga_init2(&ga, sizeof(time_entry_T), 50);
+    profile_zero(&total_total);
+    for (idx = 0; idx < curwin->w_s->b_syn_patterns.ga_len; ++idx)
+    {
+       spp = &(SYN_ITEMS(curwin->w_s)[idx]);
+       if (spp->sp_time.count > 0)
+       {
+           ga_grow(&ga, 1);
+           p = ((time_entry_T *)ga.ga_data) + ga.ga_len;
+           p->total = spp->sp_time.total;
+           profile_add(&total_total, &spp->sp_time.total);
+           p->count = spp->sp_time.count;
+           p->match = spp->sp_time.match;
+           total_count += spp->sp_time.count;
+           p->slowest = spp->sp_time.slowest;
+# ifdef FEAT_FLOAT
+           profile_divide(&spp->sp_time.total, spp->sp_time.count, &tm);
+           p->average = tm;
+# endif
+           p->id = spp->sp_syn.id;
+           p->pattern = spp->sp_pattern;
+           ++ga.ga_len;
+       }
+    }
+
+    /* sort on total time */
+    qsort(ga.ga_data, (size_t)ga.ga_len, sizeof(time_entry_T), syn_compare_syntime);
+
+    MSG_PUTS_TITLE(_("  TOTAL      COUNT  MATCH   SLOWEST     AVERAGE   NAME               PATTERN"));
+    MSG_PUTS("\n");
+    for (idx = 0; idx < ga.ga_len && !got_int; ++idx)
+    {
+       spp = &(SYN_ITEMS(curwin->w_s)[idx]);
+       p = ((time_entry_T *)ga.ga_data) + idx;
+
+       MSG_PUTS(profile_msg(&p->total));
+       MSG_PUTS(" "); /* make sure there is always a separating space */
+       msg_advance(13);
+       msg_outnum(p->count);
+       MSG_PUTS(" ");
+       msg_advance(20);
+       msg_outnum(p->match);
+       MSG_PUTS(" ");
+       msg_advance(26);
+       MSG_PUTS(profile_msg(&p->slowest));
+       MSG_PUTS(" ");
+       msg_advance(38);
+# ifdef FEAT_FLOAT
+       MSG_PUTS(profile_msg(&p->average));
+       MSG_PUTS(" ");
+# endif
+       msg_advance(50);
+       msg_outtrans(HL_TABLE()[p->id - 1].sg_name);
+       MSG_PUTS(" ");
+
+       msg_advance(69);
+       if (Columns < 80)
+           len = 20; /* will wrap anyway */
+       else
+           len = Columns - 70;
+       if (len > (int)STRLEN(p->pattern))
+           len = (int)STRLEN(p->pattern);
+       msg_outtrans_len(p->pattern, len);
+       MSG_PUTS("\n");
+    }
+    if (!got_int)
+    {
+       MSG_PUTS("\n");
+       MSG_PUTS(profile_msg(&total_total));
+       msg_advance(13);
+       msg_outnum(total_count);
+       MSG_PUTS("\n");
+    }
+}
+#endif
+
 #endif /* FEAT_SYN_HL */
 
 /**************************************
index e8febd52a5584a72c42d34def33c420d6aed3087..a16cfa1c9ca97a3687302a945088c46c166f193a 100644 (file)
@@ -728,6 +728,8 @@ static char *(features[]) =
 
 static int included_patches[] =
 {   /* Add new patch number below this line */
+/**/
+    1129,
 /**/
     1128,
 /**/