/src/h2o/lib/core/logconf.c
Line | Count | Source |
1 | | /* |
2 | | * Copyright (c) 2014-2016 DeNA Co., Ltd., Kazuho Oku |
3 | | * |
4 | | * Permission is hereby granted, free of charge, to any person obtaining a copy |
5 | | * of this software and associated documentation files (the "Software"), to |
6 | | * deal in the Software without restriction, including without limitation the |
7 | | * rights to use, copy, modify, merge, publish, distribute, sublicense, and/or |
8 | | * sell copies of the Software, and to permit persons to whom the Software is |
9 | | * furnished to do so, subject to the following conditions: |
10 | | * |
11 | | * The above copyright notice and this permission notice shall be included in |
12 | | * all copies or substantial portions of the Software. |
13 | | * |
14 | | * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR |
15 | | * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, |
16 | | * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE |
17 | | * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER |
18 | | * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING |
19 | | * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS |
20 | | * IN THE SOFTWARE. |
21 | | */ |
22 | | #include <inttypes.h> |
23 | | #include <stdio.h> |
24 | | #include <stdlib.h> |
25 | | #include "h2o.h" |
26 | | |
27 | | enum { |
28 | | ELEMENT_TYPE_EMPTY, /* empty element (with suffix only) */ |
29 | | ELEMENT_TYPE_LOCAL_ADDR, /* %A */ |
30 | | ELEMENT_TYPE_BYTES_SENT, /* %b */ |
31 | | ELEMENT_TYPE_HEADER_BYTES_SENT, /* %{response-header-bytes}x */ |
32 | | ELEMENT_TYPE_REQUEST_BODY_BYTES, /* %{request-body-bytes}x */ |
33 | | ELEMENT_TYPE_PROTOCOL, /* %H */ |
34 | | ELEMENT_TYPE_REMOTE_ADDR, /* %h */ |
35 | | ELEMENT_TYPE_LOGNAME, /* %l */ |
36 | | ELEMENT_TYPE_METHOD, /* %m */ |
37 | | ELEMENT_TYPE_LOCAL_PORT, /* %p, %{local}p */ |
38 | | ELEMENT_TYPE_REMOTE_PORT, /* %{remote}p */ |
39 | | ELEMENT_TYPE_ENV_VAR, /* %{..}e */ |
40 | | ELEMENT_TYPE_QUERY, /* %q */ |
41 | | ELEMENT_TYPE_REQUEST_LINE, /* %r */ |
42 | | ELEMENT_TYPE_STATUS, /* %s */ |
43 | | ELEMENT_TYPE_TIMESTAMP, /* %t */ |
44 | | ELEMENT_TYPE_TIMESTAMP_STRFTIME, /* %{...}t */ |
45 | | ELEMENT_TYPE_TIMESTAMP_SEC_SINCE_EPOCH, /* %{sec}t */ |
46 | | ELEMENT_TYPE_TIMESTAMP_MSEC_SINCE_EPOCH, /* %{msec}t */ |
47 | | ELEMENT_TYPE_TIMESTAMP_USEC_SINCE_EPOCH, /* %{usec}t */ |
48 | | ELEMENT_TYPE_TIMESTAMP_MSEC_FRAC, /* %{msec_frac}t */ |
49 | | ELEMENT_TYPE_TIMESTAMP_USEC_FRAC, /* %{usec_frac}t */ |
50 | | ELEMENT_TYPE_URL_PATH, /* %U */ |
51 | | ELEMENT_TYPE_REMOTE_USER, /* %u */ |
52 | | ELEMENT_TYPE_AUTHORITY, /* %V */ |
53 | | ELEMENT_TYPE_HOSTCONF, /* %v */ |
54 | | ELEMENT_TYPE_IN_HEADER_TOKEN, /* %{data.header_token}i */ |
55 | | ELEMENT_TYPE_IN_HEADER_STRING, /* %{data.name}i */ |
56 | | ELEMENT_TYPE_IN_HEADER_UPGRADE, /* %{upgrade}i */ |
57 | | ELEMENT_TYPE_OUT_HEADER_TOKEN, /* %{data.header_token}o */ |
58 | | ELEMENT_TYPE_OUT_HEADER_STRING, /* %{data.name}o */ |
59 | | ELEMENT_TYPE_OUT_HEADER_TOKEN_CONCATENATED, /* %{data.header_token}o */ |
60 | | ELEMENT_TYPE_EXTENDED_VAR, /* %{data.name}x */ |
61 | | ELEMENT_TYPE_CONNECTION_ID, /* %{connection-id}x */ |
62 | | ELEMENT_TYPE_REQUEST_ID, /* %{request-id}x */ |
63 | | ELEMENT_TYPE_CONNECT_TIME, /* %{connect-time}x */ |
64 | | ELEMENT_TYPE_REQUEST_HEADER_TIME, /* %{request-header-time}x */ |
65 | | ELEMENT_TYPE_REQUEST_BODY_TIME, /* %{request-body-time}x */ |
66 | | ELEMENT_TYPE_REQUEST_TOTAL_TIME, /* %{request-total-time}x */ |
67 | | ELEMENT_TYPE_PROCESS_TIME, /* %{process-time}x */ |
68 | | ELEMENT_TYPE_RESPONSE_TIME, /* %{response-total-time}x */ |
69 | | ELEMENT_TYPE_TOTAL_TIME, /* %{total-time}x */ |
70 | | ELEMENT_TYPE_ERROR, /* %{error}x */ |
71 | | ELEMENT_TYPE_PROTOCOL_SPECIFIC, /* %{protocol-specific...}x */ |
72 | | ELEMENT_TYPE_PROXY_IDLE_TIME, /* %{proxy.idle-time}x */ |
73 | | ELEMENT_TYPE_PROXY_CONNECT_TIME, /* %{proxy.connect-time}x */ |
74 | | ELEMENT_TYPE_PROXY_REQUEST_TIME, /* %{proxy.request-time}x */ |
75 | | ELEMENT_TYPE_PROXY_PROCESS_TIME, /* %{proxy.process-time}x */ |
76 | | ELEMENT_TYPE_PROXY_RESPONSE_TIME, /* %{proxy.response-time}x */ |
77 | | ELEMENT_TYPE_PROXY_TOTAL_TIME, /* %{proxy.total-time}x */ |
78 | | ELEMENT_TYPE_PROXY_REQUEST_BYTES, /* %{proxy.request-bytes}x */ |
79 | | ELEMENT_TYPE_PROXY_REQUEST_BYTES_HEADER, /* %{proxy.request-bytes-header}x */ |
80 | | ELEMENT_TYPE_PROXY_REQUEST_BYTES_BODY, /* %{proxy.request-bytes-body}x */ |
81 | | ELEMENT_TYPE_PROXY_RESPONSE_BYTES, /* %{proxy.response-bytes}x */ |
82 | | ELEMENT_TYPE_PROXY_RESPONSE_BYTES_HEADER, /* %{proxy.response-bytes-header}x */ |
83 | | ELEMENT_TYPE_PROXY_RESPONSE_BYTES_BODY, /* %{proxy.response-bytes-body}x */ |
84 | | ELEMENT_TYPE_PROXY_SSL_PROTOCOL_VERSION, /* ${proxy.ssl.protocol-version}x */ |
85 | | ELEMENT_TYPE_PROXY_SSL_SESSION_REUSED, /* ${proxy.ssl.session-reused}x */ |
86 | | ELEMENT_TYPE_PROXY_SSL_CIPHER, /* ${proxy.ssl.cipher}x */ |
87 | | ELEMENT_TYPE_PROXY_SSL_CIPHER_BITS, /* ${proxy.ssl.cipher_bits}x */ |
88 | | ELEMENT_TYPE_SSL_SERVER_NAME, /* ${ssl.server-name}x */ |
89 | | NUM_ELEMENT_TYPES |
90 | | }; |
91 | | |
92 | | struct log_element_t { |
93 | | unsigned type; |
94 | | h2o_iovec_t suffix; |
95 | | union { |
96 | | const h2o_token_t *header_token; |
97 | | h2o_iovec_t name; |
98 | | size_t protocol_specific_callback_index; |
99 | | } data; |
100 | | unsigned magically_quoted_json : 1; /* whether to omit surrounding doublequotes when the output is null */ |
101 | | unsigned original_response : 1; |
102 | | }; |
103 | | |
104 | | struct st_h2o_logconf_t { |
105 | | H2O_VECTOR(struct log_element_t) elements; |
106 | | int escape; |
107 | | }; |
108 | | |
109 | | static h2o_iovec_t strdup_lowercased(const char *s, size_t len) |
110 | 0 | { |
111 | 0 | h2o_iovec_t v = h2o_strdup(NULL, s, len); |
112 | 0 | h2o_strtolower(v.base, v.len); |
113 | 0 | return v; |
114 | 0 | } |
115 | | |
116 | | static void determine_magicquote_nodes(h2o_logconf_t *logconf) |
117 | 0 | { |
118 | 0 | size_t element_index; |
119 | 0 | int quote_char = '\0'; /* the quote char being used if the state machine is within a string literal */ |
120 | 0 | int just_in = 0; /* if we just went into the string literal */ |
121 | |
|
122 | 0 | for (element_index = 0; element_index < logconf->elements.size; ++element_index) { |
123 | 0 | h2o_iovec_t suffix = logconf->elements.entries[element_index].suffix; |
124 | 0 | logconf->elements.entries[element_index].magically_quoted_json = just_in && suffix.len != 0 && suffix.base[0] == quote_char; |
125 | |
|
126 | 0 | just_in = 0; |
127 | |
|
128 | 0 | size_t i; |
129 | 0 | for (i = 0; i < suffix.len; ++i) { |
130 | 0 | just_in = 0; |
131 | 0 | if (quote_char != '\0') { |
132 | 0 | if (quote_char == suffix.base[i]) { |
133 | | /* out of quote? */ |
134 | 0 | size_t j, num_bs = 0; |
135 | 0 | for (j = i; j != 0; ++num_bs) |
136 | 0 | if (suffix.base[--j] != '\\') |
137 | 0 | break; |
138 | 0 | if (num_bs % 2 == 0) |
139 | 0 | quote_char = '\0'; |
140 | 0 | } |
141 | 0 | } else { |
142 | 0 | if (suffix.base[i] == '"' || suffix.base[i] == '\'') { |
143 | 0 | quote_char = suffix.base[i]; |
144 | 0 | just_in = 1; |
145 | 0 | } |
146 | 0 | } |
147 | 0 | } |
148 | 0 | } |
149 | 0 | } |
150 | | |
151 | | h2o_logconf_t *h2o_logconf_compile(const char *fmt, int escape, char *errbuf) |
152 | 0 | { |
153 | 0 | h2o_logconf_t *logconf = h2o_mem_alloc(sizeof(*logconf)); |
154 | 0 | const char *pt = fmt; |
155 | 0 | size_t fmt_len = strlen(fmt); |
156 | |
|
157 | 0 | *logconf = (h2o_logconf_t){{NULL}, escape}; |
158 | |
|
159 | 0 | #define LAST_ELEMENT() (logconf->elements.entries + logconf->elements.size - 1) |
160 | | /* suffix buffer is always guaranteed to be larger than the fmt + (sizeof('\n') - 1) (so that they would be no buffer overruns) */ |
161 | 0 | #define NEW_ELEMENT(ty) \ |
162 | 0 | do { \ |
163 | 0 | h2o_vector_reserve(NULL, &logconf->elements, logconf->elements.size + 1); \ |
164 | 0 | logconf->elements.size++; \ |
165 | 0 | *LAST_ELEMENT() = (struct log_element_t){0}; \ |
166 | 0 | LAST_ELEMENT()->type = ty; \ |
167 | 0 | LAST_ELEMENT()->suffix.base = h2o_mem_alloc(fmt_len + 1); \ |
168 | 0 | } while (0) |
169 | |
|
170 | 0 | while (*pt != '\0') { |
171 | 0 | if (memcmp(pt, "%%", 2) == 0) { |
172 | 0 | ++pt; /* emit % */ |
173 | 0 | } else if (*pt == '%') { |
174 | 0 | ++pt; |
175 | | /* handle < and > */ |
176 | 0 | int log_original = 0; |
177 | 0 | for (;; ++pt) { |
178 | 0 | if (*pt == '<') { |
179 | 0 | log_original = 1; |
180 | 0 | } else if (*pt == '>') { |
181 | 0 | log_original = 0; |
182 | 0 | } else { |
183 | 0 | break; |
184 | 0 | } |
185 | 0 | } |
186 | | /* handle {...}n */ |
187 | 0 | if (*pt == '{') { |
188 | 0 | const h2o_token_t *token; |
189 | 0 | const char *quote_end = strchr(++pt, '}'); |
190 | 0 | if (quote_end == NULL) { |
191 | 0 | sprintf(errbuf, "failed to compile log format: unterminated header name starting at: \"%.16s\"", pt); |
192 | 0 | goto Error; |
193 | 0 | } |
194 | 0 | const char modifier = quote_end[1]; |
195 | 0 | switch (modifier) { |
196 | 0 | case 'i': |
197 | 0 | case 'o': { |
198 | 0 | h2o_iovec_t name = strdup_lowercased(pt, quote_end - pt); |
199 | 0 | token = h2o_lookup_token(name.base, name.len); |
200 | 0 | if (token != NULL) { |
201 | 0 | free(name.base); |
202 | 0 | if (modifier == 'i' && token == H2O_TOKEN_UPGRADE) { |
203 | 0 | NEW_ELEMENT(ELEMENT_TYPE_IN_HEADER_UPGRADE); |
204 | 0 | } else if (modifier == 'o' && token == H2O_TOKEN_SET_COOKIE) { |
205 | 0 | NEW_ELEMENT(ELEMENT_TYPE_OUT_HEADER_TOKEN_CONCATENATED); |
206 | 0 | LAST_ELEMENT()->data.header_token = token; |
207 | 0 | } else { |
208 | 0 | NEW_ELEMENT(modifier == 'i' ? ELEMENT_TYPE_IN_HEADER_TOKEN : ELEMENT_TYPE_OUT_HEADER_TOKEN); |
209 | 0 | LAST_ELEMENT()->data.header_token = token; |
210 | 0 | } |
211 | 0 | } else { |
212 | 0 | NEW_ELEMENT(modifier == 'i' ? ELEMENT_TYPE_IN_HEADER_STRING : ELEMENT_TYPE_OUT_HEADER_STRING); |
213 | 0 | LAST_ELEMENT()->data.name = name; |
214 | 0 | } |
215 | 0 | LAST_ELEMENT()->original_response = log_original; |
216 | 0 | } break; |
217 | 0 | case 'p': |
218 | 0 | if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("local"))) { |
219 | 0 | NEW_ELEMENT(ELEMENT_TYPE_LOCAL_PORT); |
220 | 0 | } else if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("remote"))) { |
221 | 0 | NEW_ELEMENT(ELEMENT_TYPE_REMOTE_PORT); |
222 | 0 | } else { |
223 | 0 | sprintf(errbuf, "failed to compile log format: unknown specifier for %%{...}p"); |
224 | 0 | goto Error; |
225 | 0 | } |
226 | 0 | break; |
227 | 0 | case 'e': { |
228 | 0 | h2o_iovec_t name = h2o_strdup(NULL, pt, quote_end - pt); |
229 | 0 | NEW_ELEMENT(ELEMENT_TYPE_ENV_VAR); |
230 | 0 | LAST_ELEMENT()->data.name = name; |
231 | 0 | } break; |
232 | 0 | case 't': |
233 | 0 | if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("sec"))) { |
234 | 0 | NEW_ELEMENT(ELEMENT_TYPE_TIMESTAMP_SEC_SINCE_EPOCH); |
235 | 0 | } else if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("msec"))) { |
236 | 0 | NEW_ELEMENT(ELEMENT_TYPE_TIMESTAMP_MSEC_SINCE_EPOCH); |
237 | 0 | } else if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("usec"))) { |
238 | 0 | NEW_ELEMENT(ELEMENT_TYPE_TIMESTAMP_USEC_SINCE_EPOCH); |
239 | 0 | } else if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("msec_frac"))) { |
240 | 0 | NEW_ELEMENT(ELEMENT_TYPE_TIMESTAMP_MSEC_FRAC); |
241 | 0 | } else if (h2o_memis(pt, quote_end - pt, H2O_STRLIT("usec_frac"))) { |
242 | 0 | NEW_ELEMENT(ELEMENT_TYPE_TIMESTAMP_USEC_FRAC); |
243 | 0 | } else { |
244 | 0 | if (quote_end == pt) { |
245 | 0 | sprintf(errbuf, "failed to compile log format: empty format for %%{...}t"); |
246 | 0 | goto Error; |
247 | 0 | } |
248 | 0 | h2o_iovec_t name = h2o_strdup(NULL, pt, quote_end - pt); |
249 | 0 | NEW_ELEMENT(ELEMENT_TYPE_TIMESTAMP_STRFTIME); |
250 | 0 | LAST_ELEMENT()->data.name = name; |
251 | 0 | } |
252 | 0 | break; |
253 | 0 | case 'x': |
254 | 0 | #define MAP_EXT_TO_TYPE(name, id) \ |
255 | 0 | if (h2o_lcstris(pt, quote_end - pt, H2O_STRLIT(name))) { \ |
256 | 0 | NEW_ELEMENT(id); \ |
257 | 0 | goto MAP_EXT_Found; \ |
258 | 0 | } |
259 | 0 | #define MAP_EXT_TO_PROTO(name, cb) \ |
260 | 0 | if (h2o_lcstris(pt, quote_end - pt, H2O_STRLIT(name))) { \ |
261 | 0 | h2o_conn_callbacks_t dummy_; \ |
262 | 0 | NEW_ELEMENT(ELEMENT_TYPE_PROTOCOL_SPECIFIC); \ |
263 | 0 | LAST_ELEMENT()->data.protocol_specific_callback_index = &dummy_.log_.cb - dummy_.log_.callbacks; \ |
264 | 0 | goto MAP_EXT_Found; \ |
265 | 0 | } |
266 | 0 | MAP_EXT_TO_TYPE("connection-id", ELEMENT_TYPE_CONNECTION_ID); |
267 | 0 | MAP_EXT_TO_TYPE("connect-time", ELEMENT_TYPE_CONNECT_TIME); |
268 | 0 | MAP_EXT_TO_TYPE("request-id", ELEMENT_TYPE_REQUEST_ID); |
269 | 0 | MAP_EXT_TO_TYPE("request-total-time", ELEMENT_TYPE_REQUEST_TOTAL_TIME); |
270 | 0 | MAP_EXT_TO_TYPE("request-header-time", ELEMENT_TYPE_REQUEST_HEADER_TIME); |
271 | 0 | MAP_EXT_TO_TYPE("request-body-time", ELEMENT_TYPE_REQUEST_BODY_TIME); |
272 | 0 | MAP_EXT_TO_TYPE("process-time", ELEMENT_TYPE_PROCESS_TIME); |
273 | 0 | MAP_EXT_TO_TYPE("response-time", ELEMENT_TYPE_RESPONSE_TIME); |
274 | 0 | MAP_EXT_TO_TYPE("duration", ELEMENT_TYPE_TOTAL_TIME); |
275 | 0 | MAP_EXT_TO_TYPE("total-time", ELEMENT_TYPE_TOTAL_TIME); |
276 | 0 | MAP_EXT_TO_TYPE("error", ELEMENT_TYPE_ERROR); |
277 | 0 | MAP_EXT_TO_TYPE("response-header-bytes", ELEMENT_TYPE_HEADER_BYTES_SENT); |
278 | 0 | MAP_EXT_TO_TYPE("request-body-bytes", ELEMENT_TYPE_REQUEST_BODY_BYTES); |
279 | 0 | MAP_EXT_TO_TYPE("proxy.idle-time", ELEMENT_TYPE_PROXY_IDLE_TIME); |
280 | 0 | MAP_EXT_TO_TYPE("proxy.connect-time", ELEMENT_TYPE_PROXY_CONNECT_TIME); |
281 | 0 | MAP_EXT_TO_TYPE("proxy.request-time", ELEMENT_TYPE_PROXY_REQUEST_TIME); |
282 | 0 | MAP_EXT_TO_TYPE("proxy.process-time", ELEMENT_TYPE_PROXY_PROCESS_TIME); |
283 | 0 | MAP_EXT_TO_TYPE("proxy.response-time", ELEMENT_TYPE_PROXY_RESPONSE_TIME); |
284 | 0 | MAP_EXT_TO_TYPE("proxy.total-time", ELEMENT_TYPE_PROXY_TOTAL_TIME); |
285 | 0 | MAP_EXT_TO_TYPE("proxy.request-bytes", ELEMENT_TYPE_PROXY_REQUEST_BYTES); |
286 | 0 | MAP_EXT_TO_TYPE("proxy.request-bytes-header", ELEMENT_TYPE_PROXY_REQUEST_BYTES_HEADER); |
287 | 0 | MAP_EXT_TO_TYPE("proxy.request-bytes-body", ELEMENT_TYPE_PROXY_REQUEST_BYTES_BODY); |
288 | 0 | MAP_EXT_TO_TYPE("proxy.response-bytes", ELEMENT_TYPE_PROXY_RESPONSE_BYTES); |
289 | 0 | MAP_EXT_TO_TYPE("proxy.response-bytes-header", ELEMENT_TYPE_PROXY_RESPONSE_BYTES_HEADER); |
290 | 0 | MAP_EXT_TO_TYPE("proxy.response-bytes-body", ELEMENT_TYPE_PROXY_RESPONSE_BYTES_BODY); |
291 | 0 | MAP_EXT_TO_TYPE("proxy.ssl.protocol-version", ELEMENT_TYPE_PROXY_SSL_PROTOCOL_VERSION); |
292 | 0 | MAP_EXT_TO_TYPE("proxy.ssl.session-reused", ELEMENT_TYPE_PROXY_SSL_SESSION_REUSED); |
293 | 0 | MAP_EXT_TO_TYPE("proxy.ssl.cipher", ELEMENT_TYPE_PROXY_SSL_CIPHER); |
294 | 0 | MAP_EXT_TO_TYPE("proxy.ssl.cipher-bits", ELEMENT_TYPE_PROXY_SSL_CIPHER_BITS); |
295 | 0 | MAP_EXT_TO_PROTO("extensible-priorities", extensible_priorities); |
296 | 0 | MAP_EXT_TO_PROTO("request-header-bytes", request_header_bytes); |
297 | 0 | MAP_EXT_TO_PROTO("request-header-text-bytes", request_header_text_bytes); |
298 | 0 | MAP_EXT_TO_PROTO("request-header-count", request_header_count); |
299 | 0 | MAP_EXT_TO_PROTO("response-header-text-bytes", response_header_text_bytes); |
300 | 0 | MAP_EXT_TO_PROTO("response-header-count", response_header_count); |
301 | 0 | MAP_EXT_TO_PROTO("cc.name", transport.cc_name); |
302 | 0 | MAP_EXT_TO_PROTO("delivery-rate", transport.delivery_rate); |
303 | 0 | MAP_EXT_TO_PROTO("ssl.protocol-version", ssl.protocol_version); |
304 | 0 | MAP_EXT_TO_PROTO("ssl.session-reused", ssl.session_reused); |
305 | 0 | MAP_EXT_TO_PROTO("ssl.cipher", ssl.cipher); |
306 | 0 | MAP_EXT_TO_PROTO("ssl.cipher-bits", ssl.cipher_bits); |
307 | 0 | MAP_EXT_TO_PROTO("ssl.session-id", ssl.session_id); |
308 | 0 | MAP_EXT_TO_TYPE("ssl.server-name", ELEMENT_TYPE_SSL_SERVER_NAME); |
309 | 0 | MAP_EXT_TO_PROTO("ssl.negotiated-protocol", ssl.negotiated_protocol); |
310 | 0 | MAP_EXT_TO_PROTO("ssl.ech.config-id", ssl.ech_config_id); |
311 | 0 | MAP_EXT_TO_PROTO("ssl.ech.kem", ssl.ech_kem); |
312 | 0 | MAP_EXT_TO_PROTO("ssl.ech.cipher", ssl.ech_cipher); |
313 | 0 | MAP_EXT_TO_PROTO("ssl.ech.cipher-bits", ssl.ech_cipher_bits); |
314 | 0 | MAP_EXT_TO_PROTO("ssl.backend", ssl.backend); |
315 | 0 | MAP_EXT_TO_PROTO("http1.request-index", http1.request_index); |
316 | 0 | MAP_EXT_TO_PROTO("http2.stream-id", http2.stream_id); |
317 | 0 | MAP_EXT_TO_PROTO("http2.priority.received", http2.priority_received); |
318 | 0 | MAP_EXT_TO_PROTO("http2.priority.received.exclusive", http2.priority_received_exclusive); |
319 | 0 | MAP_EXT_TO_PROTO("http2.priority.received.parent", http2.priority_received_parent); |
320 | 0 | MAP_EXT_TO_PROTO("http2.priority.received.weight", http2.priority_received_weight); |
321 | 0 | MAP_EXT_TO_PROTO("http2.priority.actual", http2.priority_actual); |
322 | 0 | MAP_EXT_TO_PROTO("http2.priority.actual.parent", http2.priority_actual_parent); |
323 | 0 | MAP_EXT_TO_PROTO("http2.priority.actual.weight", http2.priority_actual_weight); |
324 | 0 | MAP_EXT_TO_PROTO("http3.stream-id", http3.stream_id); |
325 | 0 | MAP_EXT_TO_PROTO("http3.quic-stats", http3.quic_stats); |
326 | 0 | MAP_EXT_TO_PROTO("http3.quic-version", http3.quic_version); |
327 | 0 | MAP_EXT_TO_PROTO("http3.qpack-blocked", http3.qpack_blocked); |
328 | 0 | MAP_EXT_TO_PROTO("http3.request-stream-bytes", http3.request_stream_bytes); |
329 | 0 | MAP_EXT_TO_PROTO("http3.response-stream-bytes", http3.response_stream_bytes); |
330 | 0 | { /* not found */ |
331 | 0 | h2o_iovec_t name = strdup_lowercased(pt, quote_end - pt); |
332 | 0 | NEW_ELEMENT(ELEMENT_TYPE_EXTENDED_VAR); |
333 | 0 | LAST_ELEMENT()->data.name = name; |
334 | 0 | } |
335 | 0 | MAP_EXT_Found: |
336 | 0 | #undef MAP_EXT_TO_TYPE |
337 | 0 | #undef MAP_EXT_TO_PROTO |
338 | 0 | break; |
339 | 0 | default: |
340 | 0 | sprintf(errbuf, "failed to compile log format: header name is not followed by either `i`, `o`, `x`, `e`"); |
341 | 0 | goto Error; |
342 | 0 | } |
343 | 0 | pt = quote_end + 2; |
344 | 0 | continue; |
345 | 0 | } else { |
346 | 0 | unsigned type = NUM_ELEMENT_TYPES; |
347 | 0 | switch (*pt++) { |
348 | 0 | #define TYPE_MAP(ch, ty) \ |
349 | 0 | case ch: \ |
350 | 0 | type = ty; \ |
351 | 0 | break |
352 | 0 | TYPE_MAP('A', ELEMENT_TYPE_LOCAL_ADDR); |
353 | 0 | TYPE_MAP('b', ELEMENT_TYPE_BYTES_SENT); |
354 | 0 | TYPE_MAP('H', ELEMENT_TYPE_PROTOCOL); |
355 | 0 | TYPE_MAP('h', ELEMENT_TYPE_REMOTE_ADDR); |
356 | 0 | TYPE_MAP('l', ELEMENT_TYPE_LOGNAME); |
357 | 0 | TYPE_MAP('m', ELEMENT_TYPE_METHOD); |
358 | 0 | TYPE_MAP('p', ELEMENT_TYPE_LOCAL_PORT); |
359 | 0 | TYPE_MAP('e', ELEMENT_TYPE_ENV_VAR); |
360 | 0 | TYPE_MAP('q', ELEMENT_TYPE_QUERY); |
361 | 0 | TYPE_MAP('r', ELEMENT_TYPE_REQUEST_LINE); |
362 | 0 | TYPE_MAP('s', ELEMENT_TYPE_STATUS); |
363 | 0 | TYPE_MAP('t', ELEMENT_TYPE_TIMESTAMP); |
364 | 0 | TYPE_MAP('U', ELEMENT_TYPE_URL_PATH); |
365 | 0 | TYPE_MAP('u', ELEMENT_TYPE_REMOTE_USER); |
366 | 0 | TYPE_MAP('V', ELEMENT_TYPE_AUTHORITY); |
367 | 0 | TYPE_MAP('v', ELEMENT_TYPE_HOSTCONF); |
368 | 0 | #undef TYPE_MAP |
369 | 0 | default: |
370 | 0 | sprintf(errbuf, "failed to compile log format: unknown escape sequence: %%%c", pt[-1]); |
371 | 0 | goto Error; |
372 | 0 | } |
373 | 0 | NEW_ELEMENT(type); |
374 | 0 | LAST_ELEMENT()->original_response = log_original; |
375 | 0 | continue; |
376 | 0 | } |
377 | 0 | } |
378 | | /* emit current char */ |
379 | 0 | if (logconf->elements.size == 0) |
380 | 0 | NEW_ELEMENT(ELEMENT_TYPE_EMPTY); |
381 | 0 | LAST_ELEMENT()->suffix.base[LAST_ELEMENT()->suffix.len++] = *pt++; |
382 | 0 | } |
383 | | |
384 | | /* emit end-of-line */ |
385 | 0 | if (logconf->elements.size == 0) |
386 | 0 | NEW_ELEMENT(ELEMENT_TYPE_EMPTY); |
387 | 0 | LAST_ELEMENT()->suffix.base[LAST_ELEMENT()->suffix.len++] = '\n'; |
388 | |
|
389 | 0 | #undef NEW_ELEMENT |
390 | 0 | #undef LAST_ELEMENT |
391 | |
|
392 | 0 | if (escape == H2O_LOGCONF_ESCAPE_JSON) { |
393 | 0 | determine_magicquote_nodes(logconf); |
394 | 0 | } |
395 | |
|
396 | 0 | return logconf; |
397 | | |
398 | 0 | Error: |
399 | 0 | h2o_logconf_dispose(logconf); |
400 | 0 | return NULL; |
401 | 0 | } |
402 | | |
403 | | void h2o_logconf_dispose(h2o_logconf_t *logconf) |
404 | 0 | { |
405 | 0 | size_t i; |
406 | |
|
407 | 0 | for (i = 0; i != logconf->elements.size; ++i) { |
408 | 0 | free(logconf->elements.entries[i].suffix.base); |
409 | 0 | switch (logconf->elements.entries[i].type) { |
410 | 0 | case ELEMENT_TYPE_EXTENDED_VAR: |
411 | 0 | case ELEMENT_TYPE_ENV_VAR: |
412 | 0 | case ELEMENT_TYPE_IN_HEADER_STRING: |
413 | 0 | case ELEMENT_TYPE_OUT_HEADER_STRING: |
414 | 0 | case ELEMENT_TYPE_TIMESTAMP_STRFTIME: |
415 | 0 | free(logconf->elements.entries[i].data.name.base); |
416 | 0 | break; |
417 | 0 | default: |
418 | 0 | break; |
419 | 0 | } |
420 | 0 | } |
421 | 0 | free(logconf->elements.entries); |
422 | 0 | free(logconf); |
423 | 0 | } |
424 | | |
425 | | static inline char *append_safe_string(char *pos, const char *src, size_t len) |
426 | 0 | { |
427 | 0 | memcpy(pos, src, len); |
428 | 0 | return pos + len; |
429 | 0 | } |
430 | | |
431 | | static char *append_unsafe_string_apache(char *pos, const char *src, size_t len) |
432 | 0 | { |
433 | 0 | if (len == 0) |
434 | 0 | return pos; |
435 | | |
436 | 0 | for (const char *src_end = src + len; src != src_end; ++src) { |
437 | 0 | if (' ' <= *src && *src < 0x7d && *src != '"') { |
438 | 0 | *pos++ = *src; |
439 | 0 | } else { |
440 | 0 | *pos++ = '\\'; |
441 | 0 | *pos++ = 'x'; |
442 | 0 | *pos++ = ("0123456789abcdef")[(*src >> 4) & 0xf]; |
443 | 0 | *pos++ = ("0123456789abcdef")[*src & 0xf]; |
444 | 0 | } |
445 | 0 | } |
446 | |
|
447 | 0 | return pos; |
448 | 0 | } |
449 | | |
450 | | static char *append_unsafe_string_json(char *pos, const char *src, size_t len) |
451 | 0 | { |
452 | 0 | const char *src_end = src + len; |
453 | |
|
454 | 0 | for (; src != src_end; ++src) { |
455 | 0 | if (' ' <= *src && *src < 0x7e) { |
456 | 0 | if (*src == '"' || *src == '\\') |
457 | 0 | *pos++ = '\\'; |
458 | 0 | *pos++ = *src; |
459 | 0 | } else { |
460 | 0 | *pos++ = '\\'; |
461 | 0 | *pos++ = 'u'; |
462 | 0 | *pos++ = '0'; |
463 | 0 | *pos++ = '0'; |
464 | 0 | *pos++ = ("0123456789abcdef")[(*src >> 4) & 0xf]; |
465 | 0 | *pos++ = ("0123456789abcdef")[*src & 0xf]; |
466 | 0 | } |
467 | 0 | } |
468 | |
|
469 | 0 | return pos; |
470 | 0 | } |
471 | | |
472 | | static char *append_addr(char *pos, socklen_t (*cb)(h2o_conn_t *conn, struct sockaddr *sa), h2o_conn_t *conn, h2o_iovec_t nullexpr) |
473 | 0 | { |
474 | 0 | struct sockaddr_storage ss; |
475 | 0 | socklen_t sslen; |
476 | |
|
477 | 0 | if ((sslen = cb(conn, (void *)&ss)) == 0) |
478 | 0 | goto Fail; |
479 | 0 | size_t l = h2o_socket_getnumerichost((void *)&ss, sslen, pos); |
480 | 0 | if (l == SIZE_MAX) |
481 | 0 | goto Fail; |
482 | 0 | pos += l; |
483 | 0 | return pos; |
484 | | |
485 | 0 | Fail: |
486 | 0 | memcpy(pos, nullexpr.base, nullexpr.len); |
487 | 0 | pos += nullexpr.len; |
488 | 0 | return pos; |
489 | 0 | } |
490 | | |
491 | | static char *append_port(char *pos, socklen_t (*cb)(h2o_conn_t *conn, struct sockaddr *sa), h2o_conn_t *conn, h2o_iovec_t nullexpr) |
492 | 0 | { |
493 | 0 | struct sockaddr_storage ss; |
494 | 0 | socklen_t sslen; |
495 | |
|
496 | 0 | if ((sslen = cb(conn, (void *)&ss)) == 0) |
497 | 0 | goto Fail; |
498 | 0 | int32_t port = h2o_socket_getport((void *)&ss); |
499 | 0 | if (port == -1) |
500 | 0 | goto Fail; |
501 | 0 | pos += sprintf(pos, "%" PRIu16, (uint16_t)port); |
502 | 0 | return pos; |
503 | | |
504 | 0 | Fail: |
505 | 0 | memcpy(pos, nullexpr.base, nullexpr.len); |
506 | 0 | pos += nullexpr.len; |
507 | 0 | return pos; |
508 | 0 | } |
509 | | |
510 | | #define APPEND_SAFE_STRING_WITH_LEN(pos, s, len) \ |
511 | 0 | do { \ |
512 | 0 | if (s == NULL) \ |
513 | 0 | goto EmitNull; \ |
514 | 0 | RESERVE(len); \ |
515 | 0 | pos = append_safe_string(pos, s, len); \ |
516 | 0 | } while (0) |
517 | 0 | #define APPEND_SAFE_STRING(pos, s) APPEND_SAFE_STRING_WITH_LEN(pos, s, strlen(s)) |
518 | | #define APPEND_DURATION(pos, name) \ |
519 | 0 | do { \ |
520 | 0 | int64_t delta_usec; \ |
521 | 0 | if (!h2o_time_compute_##name(req, &delta_usec)) \ |
522 | 0 | goto EmitNull; \ |
523 | 0 | int32_t delta_sec = (int32_t)(delta_usec / (1000 * 1000)); \ |
524 | 0 | delta_usec -= ((int64_t)delta_sec * (1000 * 1000)); \ |
525 | 0 | RESERVE(sizeof(H2O_INT32_LONGEST_STR ".999999") - 1); \ |
526 | 0 | pos += sprintf(pos, "%" PRId32, delta_sec); \ |
527 | 0 | if (delta_usec != 0) { \ |
528 | 0 | int i; \ |
529 | 0 | *pos++ = '.'; \ |
530 | 0 | for (i = 5; i >= 0; --i) { \ |
531 | 0 | pos[i] = '0' + delta_usec % 10; \ |
532 | 0 | delta_usec /= 10; \ |
533 | 0 | } \ |
534 | 0 | pos += 6; \ |
535 | 0 | } \ |
536 | 0 | } while (0) |
537 | | |
538 | | static char *expand_line_buf(char *line, size_t *cur_size, size_t required, int should_realloc) |
539 | 0 | { |
540 | 0 | size_t new_size = *cur_size; |
541 | | |
542 | | /* determine the new size */ |
543 | 0 | do { |
544 | 0 | new_size *= 2; |
545 | 0 | } while (new_size < required); |
546 | | |
547 | | /* reallocate */ |
548 | 0 | if (!should_realloc) { |
549 | 0 | char *newpt = h2o_mem_alloc(new_size); |
550 | 0 | memcpy(newpt, line, *cur_size); |
551 | 0 | line = newpt; |
552 | 0 | } else { |
553 | 0 | line = h2o_mem_realloc(line, new_size); |
554 | 0 | } |
555 | 0 | *cur_size = new_size; |
556 | |
|
557 | 0 | return line; |
558 | 0 | } |
559 | | |
560 | | char *h2o_log_request(h2o_logconf_t *logconf, h2o_req_t *req, size_t *len, char *buf) |
561 | 0 | { |
562 | 0 | char *line = buf, *pos = line, *line_end = line + *len; |
563 | 0 | h2o_iovec_t nullexpr; |
564 | 0 | char *(*append_unsafe_string)(char *pos, const char *src, size_t len); |
565 | 0 | size_t element_index, unsafe_factor; |
566 | 0 | struct tm localt = {0}; |
567 | 0 | int should_realloc_on_expand = 0; |
568 | |
|
569 | 0 | switch (logconf->escape) { |
570 | 0 | case H2O_LOGCONF_ESCAPE_APACHE: |
571 | 0 | nullexpr = h2o_iovec_init(H2O_STRLIT("-")); |
572 | 0 | append_unsafe_string = append_unsafe_string_apache; |
573 | 0 | unsafe_factor = 4; |
574 | 0 | break; |
575 | 0 | case H2O_LOGCONF_ESCAPE_JSON: |
576 | 0 | nullexpr = h2o_iovec_init(H2O_STRLIT("null")); |
577 | 0 | append_unsafe_string = append_unsafe_string_json; |
578 | 0 | unsafe_factor = 6; |
579 | 0 | break; |
580 | 0 | default: |
581 | 0 | h2o_fatal("unexpected escape mode"); |
582 | 0 | break; |
583 | 0 | } |
584 | | |
585 | 0 | for (element_index = 0; element_index != logconf->elements.size; ++element_index) { |
586 | 0 | struct log_element_t *element = logconf->elements.entries + element_index; |
587 | | |
588 | | /* reserve capacity + suffix.len or the NUL character */ |
589 | 0 | #define RESERVE(capacity) \ |
590 | 0 | do { \ |
591 | 0 | size_t required = (capacity) + (element->suffix.len < 1 ? 1 : element->suffix.len); \ |
592 | 0 | if (required > line_end - pos) { \ |
593 | 0 | size_t off = pos - line; \ |
594 | 0 | size_t size = line_end - line; \ |
595 | 0 | line = expand_line_buf(line, &size, off + required, should_realloc_on_expand); \ |
596 | 0 | pos = line + off; \ |
597 | 0 | line_end = line + size; \ |
598 | 0 | should_realloc_on_expand = 1; \ |
599 | 0 | } \ |
600 | 0 | } while (0) |
601 | |
|
602 | 0 | switch (element->type) { |
603 | 0 | case ELEMENT_TYPE_EMPTY: |
604 | 0 | RESERVE(0); |
605 | 0 | break; |
606 | 0 | case ELEMENT_TYPE_LOCAL_ADDR: /* %A */ |
607 | 0 | RESERVE(NI_MAXHOST); |
608 | 0 | pos = append_addr(pos, req->conn->callbacks->get_sockname, req->conn, nullexpr); |
609 | 0 | break; |
610 | 0 | case ELEMENT_TYPE_BYTES_SENT: /* %b */ |
611 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
612 | 0 | pos += sprintf(pos, "%" PRIu64, req->bytes_sent); |
613 | 0 | break; |
614 | 0 | case ELEMENT_TYPE_HEADER_BYTES_SENT: /* %{response-header-bytes}x */ |
615 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
616 | 0 | pos += sprintf(pos, "%" PRIu64, req->header_bytes_sent); |
617 | 0 | break; |
618 | 0 | case ELEMENT_TYPE_REQUEST_BODY_BYTES: /* %{request-body-bytes}x */ |
619 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
620 | 0 | pos += sprintf(pos, "%zu", req->req_body_bytes_received); |
621 | 0 | break; |
622 | 0 | case ELEMENT_TYPE_PROTOCOL: /* %H */ |
623 | 0 | if (req->version == 0) |
624 | 0 | goto EmitNull; |
625 | 0 | RESERVE(sizeof("HTTP/1.1")); |
626 | 0 | pos += h2o_stringify_protocol_version(pos, req->version); |
627 | 0 | break; |
628 | 0 | case ELEMENT_TYPE_REMOTE_ADDR: /* %h */ |
629 | 0 | RESERVE(NI_MAXHOST); |
630 | 0 | pos = append_addr(pos, req->conn->callbacks->get_peername, req->conn, nullexpr); |
631 | 0 | break; |
632 | 0 | case ELEMENT_TYPE_METHOD: /* %m */ |
633 | 0 | if (req->input.method.len == 0) |
634 | 0 | goto EmitNull; |
635 | 0 | RESERVE(req->input.method.len * unsafe_factor); |
636 | 0 | pos = append_unsafe_string(pos, req->input.method.base, req->input.method.len); |
637 | 0 | break; |
638 | 0 | case ELEMENT_TYPE_LOCAL_PORT: /* %p */ |
639 | 0 | RESERVE(sizeof(H2O_UINT16_LONGEST_STR) - 1); |
640 | 0 | pos = append_port(pos, req->conn->callbacks->get_sockname, req->conn, nullexpr); |
641 | 0 | break; |
642 | 0 | case ELEMENT_TYPE_REMOTE_PORT: /* %{remote}p */ |
643 | 0 | RESERVE(sizeof(H2O_UINT16_LONGEST_STR) - 1); |
644 | 0 | pos = append_port(pos, req->conn->callbacks->get_peername, req->conn, nullexpr); |
645 | 0 | break; |
646 | 0 | case ELEMENT_TYPE_ENV_VAR: /* %{..}e */ { |
647 | 0 | h2o_iovec_t *env_var = h2o_req_getenv(req, element->data.name.base, element->data.name.len, 0); |
648 | 0 | if (env_var == NULL) |
649 | 0 | goto EmitNull; |
650 | 0 | RESERVE(env_var->len * unsafe_factor); |
651 | 0 | pos = append_safe_string(pos, env_var->base, env_var->len); |
652 | 0 | } break; |
653 | 0 | case ELEMENT_TYPE_QUERY: /* %q */ |
654 | 0 | if (req->input.query_at != SIZE_MAX) { |
655 | 0 | size_t len = req->input.path.len - req->input.query_at; |
656 | 0 | RESERVE(len * unsafe_factor); |
657 | 0 | pos = append_unsafe_string(pos, req->input.path.base + req->input.query_at, len); |
658 | 0 | } else { |
659 | 0 | RESERVE(0); |
660 | 0 | } |
661 | 0 | break; |
662 | 0 | case ELEMENT_TYPE_REQUEST_LINE: /* %r */ |
663 | 0 | if (req->version == 0) |
664 | 0 | goto EmitNull; |
665 | 0 | RESERVE((req->input.method.len + req->input.path.len) * unsafe_factor + sizeof(" HTTP/1.1")); |
666 | 0 | pos = append_unsafe_string(pos, req->input.method.base, req->input.method.len); |
667 | 0 | *pos++ = ' '; |
668 | 0 | pos = append_unsafe_string(pos, req->input.path.base, req->input.path.len); |
669 | 0 | *pos++ = ' '; |
670 | 0 | pos += h2o_stringify_protocol_version(pos, req->version); |
671 | 0 | break; |
672 | 0 | case ELEMENT_TYPE_STATUS: /* %s */ |
673 | 0 | if (req->res.status == 0) |
674 | 0 | goto EmitNull; |
675 | 0 | RESERVE(sizeof(H2O_INT32_LONGEST_STR) - 1); |
676 | 0 | pos += sprintf(pos, "%" PRId32, (int32_t)(element->original_response ? req->res.original.status : req->res.status)); |
677 | 0 | break; |
678 | 0 | case ELEMENT_TYPE_TIMESTAMP: /* %t */ |
679 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
680 | 0 | goto EmitNull; |
681 | 0 | RESERVE(H2O_TIMESTR_LOG_LEN + 2); |
682 | 0 | *pos++ = '['; |
683 | 0 | pos = append_safe_string(pos, req->processed_at.str->log, H2O_TIMESTR_LOG_LEN); |
684 | 0 | *pos++ = ']'; |
685 | 0 | break; |
686 | 0 | case ELEMENT_TYPE_TIMESTAMP_STRFTIME: /* %{...}t */ |
687 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
688 | 0 | goto EmitNull; |
689 | 0 | { |
690 | 0 | size_t bufsz, len; |
691 | 0 | if (localt.tm_year == 0) |
692 | 0 | localtime_r(&req->processed_at.at.tv_sec, &localt); |
693 | 0 | for (bufsz = 128;; bufsz *= 2) { |
694 | 0 | RESERVE(bufsz); |
695 | 0 | if ((len = strftime(pos, bufsz, element->data.name.base, &localt)) != 0) |
696 | 0 | break; |
697 | 0 | } |
698 | 0 | pos += len; |
699 | 0 | } |
700 | 0 | break; |
701 | 0 | case ELEMENT_TYPE_TIMESTAMP_SEC_SINCE_EPOCH: /* %{sec}t */ |
702 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
703 | 0 | goto EmitNull; |
704 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
705 | 0 | pos += sprintf(pos, "%" PRIu64, (uint64_t)req->processed_at.at.tv_sec); |
706 | 0 | break; |
707 | 0 | case ELEMENT_TYPE_TIMESTAMP_MSEC_SINCE_EPOCH: /* %{msec}t */ |
708 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
709 | 0 | goto EmitNull; |
710 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
711 | 0 | pos += sprintf(pos, "%" PRIu64, |
712 | 0 | (uint64_t)req->processed_at.at.tv_sec * 1000 + (uint64_t)req->processed_at.at.tv_usec / 1000); |
713 | 0 | break; |
714 | 0 | case ELEMENT_TYPE_TIMESTAMP_USEC_SINCE_EPOCH: /* %{usec}t */ |
715 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
716 | 0 | goto EmitNull; |
717 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
718 | 0 | pos += |
719 | 0 | sprintf(pos, "%" PRIu64, (uint64_t)req->processed_at.at.tv_sec * 1000000 + (uint64_t)req->processed_at.at.tv_usec); |
720 | 0 | break; |
721 | 0 | case ELEMENT_TYPE_TIMESTAMP_MSEC_FRAC: /* %{msec_frac}t */ |
722 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
723 | 0 | goto EmitNull; |
724 | 0 | RESERVE(3); |
725 | 0 | pos += sprintf(pos, "%03u", (unsigned)(req->processed_at.at.tv_usec / 1000)); |
726 | 0 | break; |
727 | 0 | case ELEMENT_TYPE_TIMESTAMP_USEC_FRAC: /* %{usec_frac}t */ |
728 | 0 | if (h2o_timeval_is_null(&req->processed_at.at)) |
729 | 0 | goto EmitNull; |
730 | 0 | RESERVE(6); |
731 | 0 | pos += sprintf(pos, "%06u", (unsigned)req->processed_at.at.tv_usec); |
732 | 0 | break; |
733 | 0 | case ELEMENT_TYPE_URL_PATH: /* %U */ { |
734 | 0 | if (req->input.path.len == 0) |
735 | 0 | goto EmitNull; |
736 | 0 | size_t path_len = req->input.query_at == SIZE_MAX ? req->input.path.len : req->input.query_at; |
737 | 0 | RESERVE(path_len * unsafe_factor); |
738 | 0 | pos = append_unsafe_string(pos, req->input.path.base, path_len); |
739 | 0 | } break; |
740 | 0 | case ELEMENT_TYPE_REMOTE_USER: /* %u */ { |
741 | 0 | h2o_iovec_t *remote_user = h2o_req_getenv(req, H2O_STRLIT("REMOTE_USER"), 0); |
742 | 0 | if (remote_user == NULL) |
743 | 0 | goto EmitNull; |
744 | 0 | RESERVE(remote_user->len * unsafe_factor); |
745 | 0 | pos = append_unsafe_string(pos, remote_user->base, remote_user->len); |
746 | 0 | } break; |
747 | 0 | case ELEMENT_TYPE_AUTHORITY: /* %V */ |
748 | 0 | RESERVE(req->input.authority.len * unsafe_factor); |
749 | 0 | pos = append_unsafe_string(pos, req->input.authority.base, req->input.authority.len); |
750 | 0 | break; |
751 | 0 | case ELEMENT_TYPE_HOSTCONF: /* %v */ |
752 | 0 | RESERVE(req->hostconf->authority.hostport.len * unsafe_factor); |
753 | 0 | pos = append_unsafe_string(pos, req->hostconf->authority.hostport.base, req->hostconf->authority.hostport.len); |
754 | 0 | break; |
755 | | |
756 | 0 | #define EMIT_HEADER(__headers, concat, findfunc, ...) \ |
757 | 0 | do { \ |
758 | 0 | h2o_headers_t *headers = (__headers); \ |
759 | 0 | ssize_t index = -1; \ |
760 | 0 | int found = 0; \ |
761 | 0 | while ((index = (findfunc)(headers, __VA_ARGS__, index)) != -1) { \ |
762 | 0 | if (found) { \ |
763 | 0 | RESERVE(2); \ |
764 | 0 | *pos++ = ','; \ |
765 | 0 | *pos++ = ' '; \ |
766 | 0 | } else { \ |
767 | 0 | found = 1; \ |
768 | 0 | } \ |
769 | 0 | const h2o_header_t *header = headers->entries + index; \ |
770 | 0 | RESERVE(header->value.len * unsafe_factor); \ |
771 | 0 | pos = append_unsafe_string(pos, header->value.base, header->value.len); \ |
772 | 0 | if (!concat) \ |
773 | 0 | break; \ |
774 | 0 | } \ |
775 | 0 | if (!found) \ |
776 | 0 | goto EmitNull; \ |
777 | 0 | } while (0) |
778 | | |
779 | 0 | case ELEMENT_TYPE_IN_HEADER_TOKEN: |
780 | 0 | EMIT_HEADER(&req->headers, 0, h2o_find_header, element->data.header_token); |
781 | 0 | break; |
782 | 0 | case ELEMENT_TYPE_IN_HEADER_STRING: |
783 | 0 | EMIT_HEADER(&req->headers, 0, h2o_find_header_by_str, element->data.name.base, element->data.name.len); |
784 | 0 | break; |
785 | 0 | case ELEMENT_TYPE_IN_HEADER_UPGRADE: |
786 | 0 | if (req->upgrade.base == NULL) |
787 | 0 | goto EmitNull; |
788 | 0 | RESERVE(req->upgrade.len * unsafe_factor); |
789 | 0 | pos = append_unsafe_string(pos, req->upgrade.base, req->upgrade.len); |
790 | 0 | break; |
791 | 0 | case ELEMENT_TYPE_OUT_HEADER_TOKEN: |
792 | 0 | EMIT_HEADER(element->original_response ? &req->res.original.headers : &req->res.headers, 0, h2o_find_header, |
793 | 0 | element->data.header_token); |
794 | 0 | break; |
795 | 0 | case ELEMENT_TYPE_OUT_HEADER_STRING: |
796 | 0 | EMIT_HEADER(element->original_response ? &req->res.original.headers : &req->res.headers, 0, h2o_find_header_by_str, |
797 | 0 | element->data.name.base, element->data.name.len); |
798 | 0 | break; |
799 | 0 | case ELEMENT_TYPE_OUT_HEADER_TOKEN_CONCATENATED: |
800 | 0 | EMIT_HEADER(element->original_response ? &req->res.original.headers : &req->res.headers, 1, h2o_find_header, |
801 | 0 | element->data.header_token); |
802 | 0 | break; |
803 | | |
804 | 0 | #undef EMIT_HEADER |
805 | | |
806 | 0 | case ELEMENT_TYPE_CONNECTION_ID: |
807 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
808 | 0 | pos += sprintf(pos, "%" PRIu64, req->conn->id); |
809 | 0 | break; |
810 | | |
811 | 0 | case ELEMENT_TYPE_CONNECT_TIME: |
812 | 0 | APPEND_DURATION(pos, connect_time); |
813 | 0 | break; |
814 | | |
815 | 0 | case ELEMENT_TYPE_REQUEST_ID: |
816 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
817 | 0 | pos += sprintf(pos, "%" PRIu64, req->conn->callbacks->get_req_id(req)); |
818 | 0 | break; |
819 | | |
820 | 0 | case ELEMENT_TYPE_REQUEST_HEADER_TIME: |
821 | 0 | APPEND_DURATION(pos, header_time); |
822 | 0 | break; |
823 | | |
824 | 0 | case ELEMENT_TYPE_REQUEST_BODY_TIME: |
825 | 0 | APPEND_DURATION(pos, body_time); |
826 | 0 | break; |
827 | | |
828 | 0 | case ELEMENT_TYPE_REQUEST_TOTAL_TIME: |
829 | 0 | APPEND_DURATION(pos, request_total_time); |
830 | 0 | break; |
831 | | |
832 | 0 | case ELEMENT_TYPE_PROCESS_TIME: |
833 | 0 | APPEND_DURATION(pos, process_time); |
834 | 0 | break; |
835 | | |
836 | 0 | case ELEMENT_TYPE_RESPONSE_TIME: |
837 | 0 | APPEND_DURATION(pos, response_time); |
838 | 0 | break; |
839 | | |
840 | 0 | case ELEMENT_TYPE_TOTAL_TIME: |
841 | 0 | APPEND_DURATION(pos, total_time); |
842 | 0 | break; |
843 | | |
844 | 0 | case ELEMENT_TYPE_ERROR: |
845 | 0 | RESERVE(req->error_logs != NULL ? req->error_logs->size * unsafe_factor : 0); |
846 | 0 | if (req->error_logs != NULL) |
847 | 0 | pos = append_unsafe_string(pos, req->error_logs->bytes, req->error_logs->size); |
848 | 0 | break; |
849 | | |
850 | 0 | case ELEMENT_TYPE_PROXY_IDLE_TIME: |
851 | 0 | APPEND_DURATION(pos, proxy_idle_time); |
852 | 0 | break; |
853 | | |
854 | 0 | case ELEMENT_TYPE_PROXY_CONNECT_TIME: |
855 | 0 | APPEND_DURATION(pos, proxy_connect_time); |
856 | 0 | break; |
857 | | |
858 | 0 | case ELEMENT_TYPE_PROXY_REQUEST_TIME: |
859 | 0 | APPEND_DURATION(pos, proxy_request_time); |
860 | 0 | break; |
861 | | |
862 | 0 | case ELEMENT_TYPE_PROXY_PROCESS_TIME: |
863 | 0 | APPEND_DURATION(pos, proxy_process_time); |
864 | 0 | break; |
865 | | |
866 | 0 | case ELEMENT_TYPE_PROXY_RESPONSE_TIME: |
867 | 0 | APPEND_DURATION(pos, proxy_response_time); |
868 | 0 | break; |
869 | | |
870 | 0 | case ELEMENT_TYPE_PROXY_TOTAL_TIME: |
871 | 0 | APPEND_DURATION(pos, proxy_total_time); |
872 | 0 | break; |
873 | | |
874 | 0 | case ELEMENT_TYPE_PROXY_REQUEST_BYTES: |
875 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
876 | 0 | pos += sprintf(pos, "%" PRIu64, req->proxy_stats.bytes_written.total); |
877 | 0 | break; |
878 | | |
879 | 0 | case ELEMENT_TYPE_PROXY_REQUEST_BYTES_HEADER: |
880 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
881 | 0 | pos += sprintf(pos, "%" PRIu64, req->proxy_stats.bytes_written.header); |
882 | 0 | break; |
883 | | |
884 | 0 | case ELEMENT_TYPE_PROXY_REQUEST_BYTES_BODY: |
885 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
886 | 0 | pos += sprintf(pos, "%" PRIu64, req->proxy_stats.bytes_written.body); |
887 | 0 | break; |
888 | | |
889 | 0 | case ELEMENT_TYPE_PROXY_RESPONSE_BYTES: |
890 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
891 | 0 | pos += sprintf(pos, "%" PRIu64, req->proxy_stats.bytes_read.total); |
892 | 0 | break; |
893 | | |
894 | 0 | case ELEMENT_TYPE_PROXY_RESPONSE_BYTES_HEADER: |
895 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
896 | 0 | pos += sprintf(pos, "%" PRIu64, req->proxy_stats.bytes_read.header); |
897 | 0 | break; |
898 | | |
899 | 0 | case ELEMENT_TYPE_PROXY_RESPONSE_BYTES_BODY: |
900 | 0 | RESERVE(sizeof(H2O_UINT64_LONGEST_STR) - 1); |
901 | 0 | pos += sprintf(pos, "%" PRIu64, req->proxy_stats.bytes_read.body); |
902 | 0 | break; |
903 | 0 | case ELEMENT_TYPE_PROXY_SSL_SESSION_REUSED: |
904 | 0 | if (req->proxy_stats.conn.ssl.session_reused == -1) /* not TLS */ |
905 | 0 | goto EmitNull; |
906 | 0 | RESERVE(1); |
907 | 0 | *pos++ = (req->proxy_stats.conn.ssl.session_reused) ? '1' : '0'; |
908 | 0 | break; |
909 | 0 | case ELEMENT_TYPE_PROXY_SSL_CIPHER_BITS: |
910 | 0 | if (req->proxy_stats.conn.ssl.cipher_bits == 0) |
911 | 0 | goto EmitNull; |
912 | 0 | RESERVE(sizeof(H2O_INT16_LONGEST_STR)); |
913 | 0 | pos += sprintf(pos, "%" PRIu16, (uint16_t)req->proxy_stats.conn.ssl.cipher_bits); |
914 | 0 | break; |
915 | 0 | case ELEMENT_TYPE_PROXY_SSL_PROTOCOL_VERSION: |
916 | 0 | APPEND_SAFE_STRING(pos, req->proxy_stats.conn.ssl.protocol_version); |
917 | 0 | break; |
918 | 0 | case ELEMENT_TYPE_PROXY_SSL_CIPHER: |
919 | 0 | APPEND_SAFE_STRING(pos, req->proxy_stats.conn.ssl.cipher); |
920 | 0 | break; |
921 | 0 | case ELEMENT_TYPE_SSL_SERVER_NAME: { |
922 | 0 | const char *name = |
923 | 0 | req->conn->callbacks->get_ssl_server_name != NULL ? req->conn->callbacks->get_ssl_server_name(req->conn) : NULL; |
924 | 0 | if (name == NULL) |
925 | 0 | goto EmitNull; |
926 | 0 | size_t name_len = strlen(name); |
927 | 0 | RESERVE(name_len * unsafe_factor); |
928 | 0 | pos = append_unsafe_string(pos, name, name_len); |
929 | 0 | } break; |
930 | 0 | case ELEMENT_TYPE_PROTOCOL_SPECIFIC: { |
931 | 0 | h2o_iovec_t (*cb)(h2o_req_t *) = req->conn->callbacks->log_.callbacks[element->data.protocol_specific_callback_index]; |
932 | 0 | if (cb == NULL) |
933 | 0 | goto EmitNull; |
934 | 0 | h2o_iovec_t s = cb(req); |
935 | 0 | APPEND_SAFE_STRING_WITH_LEN(pos, s.base, s.len); |
936 | 0 | } break; |
937 | | |
938 | 0 | case ELEMENT_TYPE_LOGNAME: /* %l */ |
939 | 0 | case ELEMENT_TYPE_EXTENDED_VAR: /* %{...}x */ |
940 | 0 | EmitNull: |
941 | 0 | RESERVE(nullexpr.len); |
942 | | /* special case that trims surrounding quotes */ |
943 | 0 | if (element->magically_quoted_json) { |
944 | 0 | --pos; |
945 | 0 | pos = append_safe_string(pos, nullexpr.base, nullexpr.len); |
946 | 0 | pos = append_safe_string(pos, element->suffix.base + 1, element->suffix.len - 1); |
947 | 0 | continue; |
948 | 0 | } |
949 | 0 | pos = append_safe_string(pos, nullexpr.base, nullexpr.len); |
950 | 0 | break; |
951 | | |
952 | 0 | default: |
953 | 0 | h2o_fatal("unknown log element of type:%u", element->type); |
954 | 0 | break; |
955 | 0 | } |
956 | | |
957 | 0 | #undef RESERVE |
958 | | |
959 | 0 | pos = append_safe_string(pos, element->suffix.base, element->suffix.len); |
960 | 0 | } |
961 | | |
962 | 0 | *len = pos - line; |
963 | 0 | return line; |
964 | 0 | } |