Mercurial > vim

comparison src/ex_cmds2.c @ 17370:ba06a1c42274 v8.1.1684

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
patch 8.1.1684: profiling functionality is spread out commit https://github.com/vim/vim/commit/fa55cfc69d2b14761e2a8bd85bc1e0d82df770aa Author: Bram Moolenaar <Bram@vim.org> Date: Sat Jul 13 22:59:32 2019 +0200 patch 8.1.1684: profiling functionality is spread out Problem: Profiling functionality is spread out. Solution: Put profiling functionality in profiling.c. (Yegappan Lakshmanan, closes #4666)
author Bram Moolenaar <Bram@vim.org>
date Sat, 13 Jul 2019 23:00:06 +0200
parents 984eef966002
children 8f44c630c366
comparison
equal deleted inserted replaced
17369:4b97e0731720 17370:ba06a1c42274
14 #include "vim.h" 14 #include "vim.h"
15 #include "version.h" 15 #include "version.h"
16 16
17 static void cmd_source(char_u *fname, exarg_T *eap); 17 static void cmd_source(char_u *fname, exarg_T *eap);
18 18
19 #ifdef FEAT_EVAL
20 /* Growarray to store info about already sourced scripts.
21 * For Unix also store the dev/ino, so that we don't have to stat() each
22 * script when going through the list. */
23 typedef struct scriptitem_S
24 {
25 char_u *sn_name;
26 # ifdef UNIX
27 int sn_dev_valid;
28 dev_t sn_dev;
29 ino_t sn_ino;
30 # endif
31 # ifdef FEAT_PROFILE
32 int sn_prof_on; /* TRUE when script is/was profiled */
33 int sn_pr_force; /* forceit: profile functions in this script */
34 proftime_T sn_pr_child; /* time set when going into first child */
35 int sn_pr_nest; /* nesting for sn_pr_child */
36 /* profiling the script as a whole */
37 int sn_pr_count; /* nr of times sourced */
38 proftime_T sn_pr_total; /* time spent in script + children */
39 proftime_T sn_pr_self; /* time spent in script itself */
40 proftime_T sn_pr_start; /* time at script start */
41 proftime_T sn_pr_children; /* time in children after script start */
42 /* profiling the script per line */
43 garray_T sn_prl_ga; /* things stored for every line */
44 proftime_T sn_prl_start; /* start time for current line */
45 proftime_T sn_prl_children; /* time spent in children for this line */
46 proftime_T sn_prl_wait; /* wait start time for current line */
47 int sn_prl_idx; /* index of line being timed; -1 if none */
48 int sn_prl_execed; /* line being timed was executed */
49 # endif
50 } scriptitem_T;
51
52 static garray_T script_items = {0, 0, sizeof(scriptitem_T), 4, NULL};
53 #define SCRIPT_ITEM(id) (((scriptitem_T *)script_items.ga_data)[(id) - 1])
54
55 # ifdef FEAT_PROFILE
56 /* Struct used in sn_prl_ga for every line of a script. */
57 typedef struct sn_prl_S
58 {
59 int snp_count; /* nr of times line was executed */
60 proftime_T sn_prl_total; /* time spent in a line + children */
61 proftime_T sn_prl_self; /* time spent in a line itself */
62 } sn_prl_T;
63
64 # define PRL_ITEM(si, idx) (((sn_prl_T *)(si)->sn_prl_ga.ga_data)[(idx)])
65 # endif
66 #endif
67
68 #if defined(FEAT_EVAL) || defined(PROTO) 19 #if defined(FEAT_EVAL) || defined(PROTO)
69 # if defined(FEAT_PROFILE) || defined(FEAT_RELTIME) || defined(PROTO)
70 /*
71 * Store the current time in "tm".
72 */
73 void
74 profile_start(proftime_T *tm)
75 {
76 # ifdef MSWIN
77 QueryPerformanceCounter(tm);
78 # else
79 gettimeofday(tm, NULL);
80 # endif
81 }
82
83 /*
84 * Compute the elapsed time from "tm" till now and store in "tm".
85 */
86 void
87 profile_end(proftime_T *tm)
88 {
89 proftime_T now;
90
91 # ifdef MSWIN
92 QueryPerformanceCounter(&now);
93 tm->QuadPart = now.QuadPart - tm->QuadPart;
94 # else
95 gettimeofday(&now, NULL);
96 tm->tv_usec = now.tv_usec - tm->tv_usec;
97 tm->tv_sec = now.tv_sec - tm->tv_sec;
98 if (tm->tv_usec < 0)
99 {
100 tm->tv_usec += 1000000;
101 --tm->tv_sec;
102 }
103 # endif
104 }
105
106 /*
107 * Subtract the time "tm2" from "tm".
108 */
109 void
110 profile_sub(proftime_T *tm, proftime_T *tm2)
111 {
112 # ifdef MSWIN
113 tm->QuadPart -= tm2->QuadPart;
114 # else
115 tm->tv_usec -= tm2->tv_usec;
116 tm->tv_sec -= tm2->tv_sec;
117 if (tm->tv_usec < 0)
118 {
119 tm->tv_usec += 1000000;
120 --tm->tv_sec;
121 }
122 # endif
123 }
124
125 /*
126 * Return a string that represents the time in "tm".
127 * Uses a static buffer!
128 */
129 char *
130 profile_msg(proftime_T *tm)
131 {
132 static char buf[50];
133
134 # ifdef MSWIN
135 LARGE_INTEGER fr;
136
137 QueryPerformanceFrequency(&fr);
138 sprintf(buf, "%10.6lf", (double)tm->QuadPart / (double)fr.QuadPart);
139 # else
140 sprintf(buf, "%3ld.%06ld", (long)tm->tv_sec, (long)tm->tv_usec);
141 # endif
142 return buf;
143 }
144
145 # if defined(FEAT_FLOAT) || defined(PROTO)
146 /*
147 * Return a float that represents the time in "tm".
148 */
149 float_T
150 profile_float(proftime_T *tm)
151 {
152 # ifdef MSWIN
153 LARGE_INTEGER fr;
154
155 QueryPerformanceFrequency(&fr);
156 return (float_T)tm->QuadPart / (float_T)fr.QuadPart;
157 # else
158 return (float_T)tm->tv_sec + (float_T)tm->tv_usec / 1000000.0;
159 # endif
160 }
161 # endif
162
163 /*
164 * Put the time "msec" past now in "tm".
165 */
166 void
167 profile_setlimit(long msec, proftime_T *tm)
168 {
169 if (msec <= 0) /* no limit */
170 profile_zero(tm);
171 else
172 {
173 # ifdef MSWIN
174 LARGE_INTEGER fr;
175
176 QueryPerformanceCounter(tm);
177 QueryPerformanceFrequency(&fr);
178 tm->QuadPart += (LONGLONG)((double)msec / 1000.0 * (double)fr.QuadPart);
179 # else
180 long usec;
181
182 gettimeofday(tm, NULL);
183 usec = (long)tm->tv_usec + (long)msec * 1000;
184 tm->tv_usec = usec % 1000000L;
185 tm->tv_sec += usec / 1000000L;
186 # endif
187 }
188 }
189
190 /*
191 * Return TRUE if the current time is past "tm".
192 */
193 int
194 profile_passed_limit(proftime_T *tm)
195 {
196 proftime_T now;
197
198 # ifdef MSWIN
199 if (tm->QuadPart == 0) /* timer was not set */
200 return FALSE;
201 QueryPerformanceCounter(&now);
202 return (now.QuadPart > tm->QuadPart);
203 # else
204 if (tm->tv_sec == 0) /* timer was not set */
205 return FALSE;
206 gettimeofday(&now, NULL);
207 return (now.tv_sec > tm->tv_sec
208 || (now.tv_sec == tm->tv_sec && now.tv_usec > tm->tv_usec));
209 # endif
210 }
211
212 /*
213 * Set the time in "tm" to zero.
214 */
215 void
216 profile_zero(proftime_T *tm)
217 {
218 # ifdef MSWIN
219 tm->QuadPart = 0;
220 # else
221 tm->tv_usec = 0;
222 tm->tv_sec = 0;
223 # endif
224 }
225
226 # endif /* FEAT_PROFILE || FEAT_RELTIME */
227
228 # if defined(FEAT_TIMERS) || defined(PROTO) 20 # if defined(FEAT_TIMERS) || defined(PROTO)
229 static timer_T *first_timer = NULL; 21 static timer_T *first_timer = NULL;
230 static long last_timer_id = 0; 22 static long last_timer_id = 0;
231 23
232 /* 24 /*
601 } 393 }
602 } 394 }
603 # endif 395 # endif
604 # endif 396 # endif
605 397
606 #if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_FLOAT) && defined(FEAT_PROFILE)
607 # if defined(HAVE_MATH_H)
608 # include <math.h>
609 # endif
610
611 /*
612 * Divide the time "tm" by "count" and store in "tm2".
613 */
614 void
615 profile_divide(proftime_T *tm, int count, proftime_T *tm2)
616 {
617 if (count == 0)
618 profile_zero(tm2);
619 else
620 {
621 # ifdef MSWIN
622 tm2->QuadPart = tm->QuadPart / count;
623 # else
624 double usec = (tm->tv_sec * 1000000.0 + tm->tv_usec) / count;
625
626 tm2->tv_sec = floor(usec / 1000000.0);
627 tm2->tv_usec = vim_round(usec - (tm2->tv_sec * 1000000.0));
628 # endif
629 }
630 }
631 #endif
632
633 # if defined(FEAT_PROFILE) || defined(PROTO) 398 # if defined(FEAT_PROFILE) || defined(PROTO)
634 /* 399 /*
635 * Functions for profiling.
636 */
637 static void script_dump_profile(FILE *fd);
638 static proftime_T prof_wait_time;
639
640 /*
641 * Add the time "tm2" to "tm".
642 */
643 void
644 profile_add(proftime_T *tm, proftime_T *tm2)
645 {
646 # ifdef MSWIN
647 tm->QuadPart += tm2->QuadPart;
648 # else
649 tm->tv_usec += tm2->tv_usec;
650 tm->tv_sec += tm2->tv_sec;
651 if (tm->tv_usec >= 1000000)
652 {
653 tm->tv_usec -= 1000000;
654 ++tm->tv_sec;
655 }
656 # endif
657 }
658
659 /*
660 * Add the "self" time from the total time and the children's time.
661 */
662 void
663 profile_self(proftime_T *self, proftime_T *total, proftime_T *children)
664 {
665 /* Check that the result won't be negative. Can happen with recursive
666 * calls. */
667 #ifdef MSWIN
668 if (total->QuadPart <= children->QuadPart)
669 return;
670 #else
671 if (total->tv_sec < children->tv_sec
672 || (total->tv_sec == children->tv_sec
673 && total->tv_usec <= children->tv_usec))
674 return;
675 #endif
676 profile_add(self, total);
677 profile_sub(self, children);
678 }
679
680 /*
681 * Get the current waittime.
682 */
683 void
684 profile_get_wait(proftime_T *tm)
685 {
686 *tm = prof_wait_time;
687 }
688
689 /*
690 * Subtract the passed waittime since "tm" from "tma".
691 */
692 void
693 profile_sub_wait(proftime_T *tm, proftime_T *tma)
694 {
695 proftime_T tm3 = prof_wait_time;
696
697 profile_sub(&tm3, tm);
698 profile_sub(tma, &tm3);
699 }
700
701 /*
702 * Return TRUE if "tm1" and "tm2" are equal.
703 */
704 int
705 profile_equal(proftime_T *tm1, proftime_T *tm2)
706 {
707 # ifdef MSWIN
708 return (tm1->QuadPart == tm2->QuadPart);
709 # else
710 return (tm1->tv_usec == tm2->tv_usec && tm1->tv_sec == tm2->tv_sec);
711 # endif
712 }
713
714 /*
715 * Return <0, 0 or >0 if "tm1" < "tm2", "tm1" == "tm2" or "tm1" > "tm2"
716 */
717 int
718 profile_cmp(const proftime_T *tm1, const proftime_T *tm2)
719 {
720 # ifdef MSWIN
721 return (int)(tm2->QuadPart - tm1->QuadPart);
722 # else
723 if (tm1->tv_sec == tm2->tv_sec)
724 return tm2->tv_usec - tm1->tv_usec;
725 return tm2->tv_sec - tm1->tv_sec;
726 # endif
727 }
728
729 static char_u *profile_fname = NULL;
730 static proftime_T pause_time;
731
732 /*
733 * ":profile cmd args"
734 */
735 void
736 ex_profile(exarg_T *eap)
737 {
738 char_u *e;
739 int len;
740
741 e = skiptowhite(eap->arg);
742 len = (int)(e - eap->arg);
743 e = skipwhite(e);
744
745 if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL)
746 {
747 vim_free(profile_fname);
748 profile_fname = expand_env_save_opt(e, TRUE);
749 do_profiling = PROF_YES;
750 profile_zero(&prof_wait_time);
751 set_vim_var_nr(VV_PROFILING, 1L);
752 }
753 else if (do_profiling == PROF_NONE)
754 emsg(_("E750: First use \":profile start {fname}\""));
755 else if (STRCMP(eap->arg, "pause") == 0)
756 {
757 if (do_profiling == PROF_YES)
758 profile_start(&pause_time);
759 do_profiling = PROF_PAUSED;
760 }
761 else if (STRCMP(eap->arg, "continue") == 0)
762 {
763 if (do_profiling == PROF_PAUSED)
764 {
765 profile_end(&pause_time);
766 profile_add(&prof_wait_time, &pause_time);
767 }
768 do_profiling = PROF_YES;
769 }
770 else
771 {
772 /* The rest is similar to ":breakadd". */
773 ex_breakadd(eap);
774 }
775 }
776
777 /* Command line expansion for :profile. */
778 static enum
779 {
780 PEXP_SUBCMD, /* expand :profile sub-commands */
781 PEXP_FUNC /* expand :profile func {funcname} */
782 } pexpand_what;
783
784 static char *pexpand_cmds[] = {
785 "start",
786 #define PROFCMD_START 0
787 "pause",
788 #define PROFCMD_PAUSE 1
789 "continue",
790 #define PROFCMD_CONTINUE 2
791 "func",
792 #define PROFCMD_FUNC 3
793 "file",
794 #define PROFCMD_FILE 4
795 NULL
796 #define PROFCMD_LAST 5
797 };
798
799 /*
800 * Function given to ExpandGeneric() to obtain the profile command
801 * specific expansion.
802 */
803 char_u *
804 get_profile_name(expand_T *xp UNUSED, int idx)
805 {
806 switch (pexpand_what)
807 {
808 case PEXP_SUBCMD:
809 return (char_u *)pexpand_cmds[idx];
810 /* case PEXP_FUNC: TODO */
811 default:
812 return NULL;
813 }
814 }
815
816 /*
817 * Handle command line completion for :profile command.
818 */
819 void
820 set_context_in_profile_cmd(expand_T *xp, char_u *arg)
821 {
822 char_u *end_subcmd;
823
824 /* Default: expand subcommands. */
825 xp->xp_context = EXPAND_PROFILE;
826 pexpand_what = PEXP_SUBCMD;
827 xp->xp_pattern = arg;
828
829 end_subcmd = skiptowhite(arg);
830 if (*end_subcmd == NUL)
831 return;
832
833 if (end_subcmd - arg == 5 && STRNCMP(arg, "start", 5) == 0)
834 {
835 xp->xp_context = EXPAND_FILES;
836 xp->xp_pattern = skipwhite(end_subcmd);
837 return;
838 }
839
840 /* TODO: expand function names after "func" */
841 xp->xp_context = EXPAND_NOTHING;
842 }
843
844 /*
845 * Dump the profiling info.
846 */
847 void
848 profile_dump(void)
849 {
850 FILE *fd;
851
852 if (profile_fname != NULL)
853 {
854 fd = mch_fopen((char *)profile_fname, "w");
855 if (fd == NULL)
856 semsg(_(e_notopen), profile_fname);
857 else
858 {
859 script_dump_profile(fd);
860 func_dump_profile(fd);
861 fclose(fd);
862 }
863 }
864 }
865
866 /*
867 * Start profiling script "fp". 400 * Start profiling script "fp".
868 */ 401 */
869 static void 402 void
870 script_do_profile(scriptitem_T *si) 403 script_do_profile(scriptitem_T *si)
871 { 404 {
872 si->sn_pr_count = 0; 405 si->sn_pr_count = 0;
873 profile_zero(&si->sn_pr_total); 406 profile_zero(&si->sn_pr_total);
874 profile_zero(&si->sn_pr_self); 407 profile_zero(&si->sn_pr_self);
916 profile_add(&si->sn_prl_children, &si->sn_pr_child); 449 profile_add(&si->sn_prl_children, &si->sn_pr_child);
917 } 450 }
918 } 451 }
919 } 452 }
920 453
921 static proftime_T inchar_time;
922
923 /*
924 * Called when starting to wait for the user to type a character.
925 */
926 void
927 prof_inchar_enter(void)
928 {
929 profile_start(&inchar_time);
930 }
931
932 /*
933 * Called when finished waiting for the user to type a character.
934 */
935 void
936 prof_inchar_exit(void)
937 {
938 profile_end(&inchar_time);
939 profile_add(&prof_wait_time, &inchar_time);
940 }
941
942 /* 454 /*
943 * Dump the profiling results for all scripts in file "fd". 455 * Dump the profiling results for all scripts in file "fd".
944 */ 456 */
945 static void 457 void
946 script_dump_profile(FILE *fd) 458 script_dump_profile(FILE *fd)
947 { 459 {
948 int id; 460 int id;
949 scriptitem_T *si; 461 scriptitem_T *si;
950 int i; 462 int i;
1014 } 526 }
1015 fprintf(fd, "\n"); 527 fprintf(fd, "\n");
1016 } 528 }
1017 } 529 }
1018 } 530 }
1019
1020 /*
1021 * Return TRUE when a function defined in the current script should be
1022 * profiled.
1023 */
1024 int
1025 prof_def_func(void)
1026 {
1027 if (current_sctx.sc_sid > 0)
1028 return SCRIPT_ITEM(current_sctx.sc_sid).sn_pr_force;
1029 return FALSE;
1030 }
1031
1032 # endif 531 # endif
1033 #endif 532 #endif
1034 533
1035 /* 534 /*
1036 * If 'autowrite' option set, try to write the file. 535 * If 'autowrite' option set, try to write the file.