Fossil SCM

Added basic timing info to json ops, but "should probably" move the timer start to the app/server init.

stephan 2011-09-27 13:22 UTC json
Commit b9ef0fe59b1262b072621046fdeaf116f275f4a0
Parent 0ddf92042d474d9…
1 file changed +136
~ src/json.c
M src/json.c
+136
--- src/json.c
+++ src/json.c
@@ -62,10 +62,131 @@
6262
 #define BITSET_UNSET(B,BIT) ((BITSET_BYTEFOR(B,BIT) &= ~(0x01 << (BIT%8))),0x00)
6363
 #define BITSET_GET(B,BIT) ((BITSET_BYTEFOR(B,BIT) & (0x01 << (BIT%8))) ? 0x01 : 0x00)
6464
 #define BITSET_TOGGLE(B,BIT) (BITSET_GET(B,BIT) ? (BITSET_UNSET(B,BIT)) : (BITSET_SET(B,BIT)))
6565
6666
67
+/* Timer code taken from sqlite3's shell.c, modified slightly.
68
+ FIXME: move the timer into the fossil core API so that we can
69
+ start the timer early on in the app init phase. Right now we're
70
+ just timing the json ops themselves.
71
+*/
72
+#if !defined(_WIN32) && !defined(WIN32) && !defined(__OS2__) && !defined(__RTP__) && !defined(_WRS_KERNEL)
73
+#include <sys/time.h>
74
+#include <sys/resource.h>
75
+
76
+/* Saved resource information for the beginning of an operation */
77
+static struct rusage sBegin;
78
+
79
+/*
80
+** Begin timing an operation
81
+*/
82
+static void beginTimer(void){
83
+ getrusage(RUSAGE_SELF, &sBegin);
84
+}
85
+
86
+/* Return the difference of two time_structs in milliseconds */
87
+static double timeDiff(struct timeval *pStart, struct timeval *pEnd){
88
+ return ((pEnd->tv_usec - pStart->tv_usec)*0.001 +
89
+ (double)((pEnd->tv_sec - pStart->tv_sec)*1000.0));
90
+}
91
+
92
+/*
93
+** Print the timing results.
94
+*/
95
+static double endTimer(void){
96
+ struct rusage sEnd;
97
+ getrusage(RUSAGE_SELF, &sEnd);
98
+ return timeDiff(&sBegin.ru_utime, &sEnd.ru_utime)
99
+ + timeDiff(&sBegin.ru_stime, &sEnd.ru_stime);
100
+#if 0
101
+ printf("CPU Time: user %f sys %f\n",
102
+ timeDiff(&sBegin.ru_utime, &sEnd.ru_utime),
103
+ timeDiff(&sBegin.ru_stime, &sEnd.ru_stime));
104
+#endif
105
+}
106
+
107
+#define BEGIN_TIMER beginTimer()
108
+#define END_TIMER endTimer()
109
+#define HAS_TIMER 1
110
+
111
+#elif (defined(_WIN32) || defined(WIN32))
112
+
113
+#include <windows.h>
114
+
115
+/* Saved resource information for the beginning of an operation */
116
+static HANDLE hProcess;
117
+static FILETIME ftKernelBegin;
118
+static FILETIME ftUserBegin;
119
+typedef BOOL (WINAPI *GETPROCTIMES)(HANDLE, LPFILETIME, LPFILETIME, LPFILETIME, LPFILETIME);
120
+static GETPROCTIMES getProcessTimesAddr = NULL;
121
+
122
+/*
123
+** Check to see if we have timer support. Return 1 if necessary
124
+** support found (or found previously).
125
+*/
126
+static int hasTimer(void){
127
+ if( getProcessTimesAddr ){
128
+ return 1;
129
+ } else {
130
+ /* GetProcessTimes() isn't supported in WIN95 and some other Windows versions.
131
+ ** See if the version we are running on has it, and if it does, save off
132
+ ** a pointer to it and the current process handle.
133
+ */
134
+ hProcess = GetCurrentProcess();
135
+ if( hProcess ){
136
+ HINSTANCE hinstLib = LoadLibrary(TEXT("Kernel32.dll"));
137
+ if( NULL != hinstLib ){
138
+ getProcessTimesAddr = (GETPROCTIMES) GetProcAddress(hinstLib, "GetProcessTimes");
139
+ if( NULL != getProcessTimesAddr ){
140
+ return 1;
141
+ }
142
+ FreeLibrary(hinstLib);
143
+ }
144
+ }
145
+ }
146
+ return 0;
147
+}
148
+
149
+/*
150
+** Begin timing an operation
151
+*/
152
+static void beginTimer(void){
153
+ if( getProcessTimesAddr ){
154
+ FILETIME ftCreation, ftExit;
155
+ getProcessTimesAddr(hProcess, &ftCreation, &ftExit, &ftKernelBegin, &ftUserBegin);
156
+ }
157
+}
158
+
159
+/* Return the difference of two FILETIME structs in milliseconds */
160
+static double timeDiff(FILETIME *pStart, FILETIME *pEnd){
161
+ sqlite_int64 i64Start = *((sqlite_int64 *) pStart);
162
+ sqlite_int64 i64End = *((sqlite_int64 *) pEnd);
163
+ return (double) ((i64End - i64Start) / 10000.0);
164
+}
165
+
166
+/*
167
+** Print the timing results.
168
+*/
169
+static double endTimer(void){
170
+ if(getProcessTimesAddr){
171
+ FILETIME ftCreation, ftExit, ftKernelEnd, ftUserEnd;
172
+ getProcessTimesAddr(hProcess, &ftCreation, &ftExit, &ftKernelEnd, &ftUserEnd);
173
+ return timeDiff(&ftUserBegin, &ftUserEnd) +
174
+ timeDiff(&ftKernelBegin, &ftKernelEnd);
175
+ }
176
+}
177
+
178
+#define BEGIN_TIMER beginTimer()
179
+#define END_TIMER endTimer()
180
+#define HAS_TIMER hasTimer()
181
+
182
+#else
183
+#define BEGIN_TIMER
184
+#define END_TIMER 0.0
185
+#define HAS_TIMER 0
186
+#endif
187
+
67188
 /*
68189
 ** Placeholder /json/XXX page impl for NYI (Not Yet Implemented)
69190
 ** (but planned) pages/commands.
70191
 */
71192
 static cson_value * json_page_nyi(){
@@ -1055,10 +1176,23 @@
10551176
 cson_object_set( o, "cmd.offset", tmp );
10561177
 cson_object_set( o, "isCGI", cson_value_new_bool( g.isHTTP ) );
10571178
 }
10581179
 }
10591180
1181
+ if(HAS_TIMER){
1182
+ /* This is, philosophically speaking, not quite the right place
1183
+ for ending the timer, but this is the one function which all of
1184
+ the JSON exit paths use (and they call it after processing,
1185
+ just before they end).
1186
+ */
1187
+ double span;
1188
+ span = END_TIMER;
1189
+ /* i'm actually seeing sub-ms runtimes in some tests, but a time of
1190
+ 0 is "just wrong", so we'll bump that up to 1ms.
1191
+ */
1192
+ cson_object_set(o,"procTimeMs", cson_value_new_integer((cson_int_t)((span>0.0)?span:1)));
1193
+ }
10601194
 if(g.json.warnings.v){
10611195
 tmp = g.json.warnings.v;
10621196
 SET("warnings");
10631197
 }
10641198
@@ -1668,10 +1802,11 @@
16681802
 void json_page_top(void){
16691803
 int rc = FSL_JSON_E_UNKNOWN_COMMAND;
16701804
 char const * cmd;
16711805
 cson_value * payload = NULL;
16721806
 JsonPageDef const * pageDef = NULL;
1807
+ BEGIN_TIMER;
16731808
 json_mode_bootstrap();
16741809
 cmd = json_command_arg(1);
16751810
 /*cgi_printf("{\"cmd\":\"%s\"}\n",cmd); return;*/
16761811
 pageDef = json_handler_for_name(cmd,&JsonPageDefs[0]);
16771812
 if( ! pageDef ){
@@ -1721,10 +1856,11 @@
17211856
 void json_cmd_top(void){
17221857
 char const * cmd = NULL;
17231858
 int rc = FSL_JSON_E_UNKNOWN_COMMAND;
17241859
 cson_value * payload = NULL;
17251860
 JsonPageDef const * pageDef;
1861
+ BEGIN_TIMER;
17261862
 memset( &g.perm, 0xff, sizeof(g.perm) )
17271863
 /* In CLI mode fossil does not use permissions
17281864
 and they all default to false. We enable them
17291865
 here because (A) fossil doesn't use them in local
17301866
 mode but (B) having them set gives us one less
17311867
--- src/json.c
+++ src/json.c
@@ -62,10 +62,131 @@
62 #define BITSET_UNSET(B,BIT) ((BITSET_BYTEFOR(B,BIT) &= ~(0x01 << (BIT%8))),0x00)
63 #define BITSET_GET(B,BIT) ((BITSET_BYTEFOR(B,BIT) & (0x01 << (BIT%8))) ? 0x01 : 0x00)
64 #define BITSET_TOGGLE(B,BIT) (BITSET_GET(B,BIT) ? (BITSET_UNSET(B,BIT)) : (BITSET_SET(B,BIT)))
65
66
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
67 /*
68 ** Placeholder /json/XXX page impl for NYI (Not Yet Implemented)
69 ** (but planned) pages/commands.
70 */
71 static cson_value * json_page_nyi(){
@@ -1055,10 +1176,23 @@
1055 cson_object_set( o, "cmd.offset", tmp );
1056 cson_object_set( o, "isCGI", cson_value_new_bool( g.isHTTP ) );
1057 }
1058 }
1059
 
 
 
 
 
 
 
 
 
 
 
 
 
1060 if(g.json.warnings.v){
1061 tmp = g.json.warnings.v;
1062 SET("warnings");
1063 }
1064
@@ -1668,10 +1802,11 @@
1668 void json_page_top(void){
1669 int rc = FSL_JSON_E_UNKNOWN_COMMAND;
1670 char const * cmd;
1671 cson_value * payload = NULL;
1672 JsonPageDef const * pageDef = NULL;
 
1673 json_mode_bootstrap();
1674 cmd = json_command_arg(1);
1675 /*cgi_printf("{\"cmd\":\"%s\"}\n",cmd); return;*/
1676 pageDef = json_handler_for_name(cmd,&JsonPageDefs[0]);
1677 if( ! pageDef ){
@@ -1721,10 +1856,11 @@
1721 void json_cmd_top(void){
1722 char const * cmd = NULL;
1723 int rc = FSL_JSON_E_UNKNOWN_COMMAND;
1724 cson_value * payload = NULL;
1725 JsonPageDef const * pageDef;
 
1726 memset( &g.perm, 0xff, sizeof(g.perm) )
1727 /* In CLI mode fossil does not use permissions
1728 and they all default to false. We enable them
1729 here because (A) fossil doesn't use them in local
1730 mode but (B) having them set gives us one less
1731
--- src/json.c
+++ src/json.c
@@ -62,10 +62,131 @@
62 #define BITSET_UNSET(B,BIT) ((BITSET_BYTEFOR(B,BIT) &= ~(0x01 << (BIT%8))),0x00)
63 #define BITSET_GET(B,BIT) ((BITSET_BYTEFOR(B,BIT) & (0x01 << (BIT%8))) ? 0x01 : 0x00)
64 #define BITSET_TOGGLE(B,BIT) (BITSET_GET(B,BIT) ? (BITSET_UNSET(B,BIT)) : (BITSET_SET(B,BIT)))
65
66
67 /* Timer code taken from sqlite3's shell.c, modified slightly.
68 FIXME: move the timer into the fossil core API so that we can
69 start the timer early on in the app init phase. Right now we're
70 just timing the json ops themselves.
71 */
72 #if !defined(_WIN32) && !defined(WIN32) && !defined(__OS2__) && !defined(__RTP__) && !defined(_WRS_KERNEL)
73 #include <sys/time.h>
74 #include <sys/resource.h>
75
76 /* Saved resource information for the beginning of an operation */
77 static struct rusage sBegin;
78
79 /*
80 ** Begin timing an operation
81 */
82 static void beginTimer(void){
83 getrusage(RUSAGE_SELF, &sBegin);
84 }
85
86 /* Return the difference of two time_structs in milliseconds */
87 static double timeDiff(struct timeval *pStart, struct timeval *pEnd){
88 return ((pEnd->tv_usec - pStart->tv_usec)*0.001 +
89 (double)((pEnd->tv_sec - pStart->tv_sec)*1000.0));
90 }
91
92 /*
93 ** Print the timing results.
94 */
95 static double endTimer(void){
96 struct rusage sEnd;
97 getrusage(RUSAGE_SELF, &sEnd);
98 return timeDiff(&sBegin.ru_utime, &sEnd.ru_utime)
99 + timeDiff(&sBegin.ru_stime, &sEnd.ru_stime);
100 #if 0
101 printf("CPU Time: user %f sys %f\n",
102 timeDiff(&sBegin.ru_utime, &sEnd.ru_utime),
103 timeDiff(&sBegin.ru_stime, &sEnd.ru_stime));
104 #endif
105 }
106
107 #define BEGIN_TIMER beginTimer()
108 #define END_TIMER endTimer()
109 #define HAS_TIMER 1
110
111 #elif (defined(_WIN32) || defined(WIN32))
112
113 #include <windows.h>
114
115 /* Saved resource information for the beginning of an operation */
116 static HANDLE hProcess;
117 static FILETIME ftKernelBegin;
118 static FILETIME ftUserBegin;
119 typedef BOOL (WINAPI *GETPROCTIMES)(HANDLE, LPFILETIME, LPFILETIME, LPFILETIME, LPFILETIME);
120 static GETPROCTIMES getProcessTimesAddr = NULL;
121
122 /*
123 ** Check to see if we have timer support. Return 1 if necessary
124 ** support found (or found previously).
125 */
126 static int hasTimer(void){
127 if( getProcessTimesAddr ){
128 return 1;
129 } else {
130 /* GetProcessTimes() isn't supported in WIN95 and some other Windows versions.
131 ** See if the version we are running on has it, and if it does, save off
132 ** a pointer to it and the current process handle.
133 */
134 hProcess = GetCurrentProcess();
135 if( hProcess ){
136 HINSTANCE hinstLib = LoadLibrary(TEXT("Kernel32.dll"));
137 if( NULL != hinstLib ){
138 getProcessTimesAddr = (GETPROCTIMES) GetProcAddress(hinstLib, "GetProcessTimes");
139 if( NULL != getProcessTimesAddr ){
140 return 1;
141 }
142 FreeLibrary(hinstLib);
143 }
144 }
145 }
146 return 0;
147 }
148
149 /*
150 ** Begin timing an operation
151 */
152 static void beginTimer(void){
153 if( getProcessTimesAddr ){
154 FILETIME ftCreation, ftExit;
155 getProcessTimesAddr(hProcess, &ftCreation, &ftExit, &ftKernelBegin, &ftUserBegin);
156 }
157 }
158
159 /* Return the difference of two FILETIME structs in milliseconds */
160 static double timeDiff(FILETIME *pStart, FILETIME *pEnd){
161 sqlite_int64 i64Start = *((sqlite_int64 *) pStart);
162 sqlite_int64 i64End = *((sqlite_int64 *) pEnd);
163 return (double) ((i64End - i64Start) / 10000.0);
164 }
165
166 /*
167 ** Print the timing results.
168 */
169 static double endTimer(void){
170 if(getProcessTimesAddr){
171 FILETIME ftCreation, ftExit, ftKernelEnd, ftUserEnd;
172 getProcessTimesAddr(hProcess, &ftCreation, &ftExit, &ftKernelEnd, &ftUserEnd);
173 return timeDiff(&ftUserBegin, &ftUserEnd) +
174 timeDiff(&ftKernelBegin, &ftKernelEnd);
175 }
176 }
177
178 #define BEGIN_TIMER beginTimer()
179 #define END_TIMER endTimer()
180 #define HAS_TIMER hasTimer()
181
182 #else
183 #define BEGIN_TIMER
184 #define END_TIMER 0.0
185 #define HAS_TIMER 0
186 #endif
187
188 /*
189 ** Placeholder /json/XXX page impl for NYI (Not Yet Implemented)
190 ** (but planned) pages/commands.
191 */
192 static cson_value * json_page_nyi(){
@@ -1055,10 +1176,23 @@
1176 cson_object_set( o, "cmd.offset", tmp );
1177 cson_object_set( o, "isCGI", cson_value_new_bool( g.isHTTP ) );
1178 }
1179 }
1180
1181 if(HAS_TIMER){
1182 /* This is, philosophically speaking, not quite the right place
1183 for ending the timer, but this is the one function which all of
1184 the JSON exit paths use (and they call it after processing,
1185 just before they end).
1186 */
1187 double span;
1188 span = END_TIMER;
1189 /* i'm actually seeing sub-ms runtimes in some tests, but a time of
1190 0 is "just wrong", so we'll bump that up to 1ms.
1191 */
1192 cson_object_set(o,"procTimeMs", cson_value_new_integer((cson_int_t)((span>0.0)?span:1)));
1193 }
1194 if(g.json.warnings.v){
1195 tmp = g.json.warnings.v;
1196 SET("warnings");
1197 }
1198
@@ -1668,10 +1802,11 @@
1802 void json_page_top(void){
1803 int rc = FSL_JSON_E_UNKNOWN_COMMAND;
1804 char const * cmd;
1805 cson_value * payload = NULL;
1806 JsonPageDef const * pageDef = NULL;
1807 BEGIN_TIMER;
1808 json_mode_bootstrap();
1809 cmd = json_command_arg(1);
1810 /*cgi_printf("{\"cmd\":\"%s\"}\n",cmd); return;*/
1811 pageDef = json_handler_for_name(cmd,&JsonPageDefs[0]);
1812 if( ! pageDef ){
@@ -1721,10 +1856,11 @@
1856 void json_cmd_top(void){
1857 char const * cmd = NULL;
1858 int rc = FSL_JSON_E_UNKNOWN_COMMAND;
1859 cson_value * payload = NULL;
1860 JsonPageDef const * pageDef;
1861 BEGIN_TIMER;
1862 memset( &g.perm, 0xff, sizeof(g.perm) )
1863 /* In CLI mode fossil does not use permissions
1864 and they all default to false. We enable them
1865 here because (A) fossil doesn't use them in local
1866 mode but (B) having them set gives us one less
1867

Keyboard Shortcuts

Open search /
Next entry (timeline) j
Previous entry (timeline) k
Open focused entry Enter
Show this help ?
Toggle theme Top nav button