##// END OF EJS Templates
config: update gunicorn config examples
super-admin -
r5272:ab333ff0 default
parent child Browse files
Show More
@@ -1,510 +1,518 b''
1 """
1 """
2 Gunicorn config extension and hooks. This config file adds some extra settings and memory management.
2 Gunicorn config extension and hooks. This config file adds some extra settings and memory management.
3 Gunicorn configuration should be managed by .ini files entries of RhodeCode or VCSServer
3 Gunicorn configuration should be managed by .ini files entries of RhodeCode or VCSServer
4 """
4 """
5
5
6 import gc
6 import gc
7 import os
7 import os
8 import sys
8 import sys
9 import math
9 import math
10 import time
10 import time
11 import threading
11 import threading
12 import traceback
12 import traceback
13 import random
13 import random
14 import socket
14 import socket
15 import dataclasses
15 import dataclasses
16 from gunicorn.glogging import Logger
16 from gunicorn.glogging import Logger
17
17
18
18
19 def get_workers():
19 def get_workers():
20 import multiprocessing
20 import multiprocessing
21 return multiprocessing.cpu_count() * 2 + 1
21 return multiprocessing.cpu_count() * 2 + 1
22
22
23
23
24 bind = "127.0.0.1:10020"
24 bind = "127.0.0.1:10020"
25
25
26
26
27 # Error logging output for gunicorn (-) is stdout
27 # Error logging output for gunicorn (-) is stdout
28 errorlog = '-'
28 errorlog = '-'
29
29
30 # Access logging output for gunicorn (-) is stdout
30 # Access logging output for gunicorn (-) is stdout
31 accesslog = '-'
31 accesslog = '-'
32
32
33
33
34 # SERVER MECHANICS
34 # SERVER MECHANICS
35 # None == system temp dir
35 # None == system temp dir
36 # worker_tmp_dir is recommended to be set to some tmpfs
36 # worker_tmp_dir is recommended to be set to some tmpfs
37 worker_tmp_dir = None
37 worker_tmp_dir = None
38 tmp_upload_dir = None
38 tmp_upload_dir = None
39
39
40 # use re-use port logic
40 # use re-use port logic
41 #reuse_port = True
41 #reuse_port = True
42
42
43 # Custom log format
43 # Custom log format
44 #access_log_format = (
44 #access_log_format = (
45 # '%(t)s %(p)s INFO [GNCRN] %(h)-15s rqt:%(L)s %(s)s %(b)-6s "%(m)s:%(U)s %(q)s" usr:%(u)s "%(f)s" "%(a)s"')
45 # '%(t)s %(p)s INFO [GNCRN] %(h)-15s rqt:%(L)s %(s)s %(b)-6s "%(m)s:%(U)s %(q)s" usr:%(u)s "%(f)s" "%(a)s"')
46
46
47 # loki format for easier parsing in grafana
47 # loki format for easier parsing in grafana
48 access_log_format = (
48 access_log_format = (
49 'time="%(t)s" pid=%(p)s level="INFO" type="[GNCRN]" ip="%(h)-15s" rqt="%(L)s" response_code="%(s)s" response_bytes="%(b)-6s" uri="%(m)s:%(U)s %(q)s" user=":%(u)s" user_agent="%(a)s"')
49 'time="%(t)s" pid=%(p)s level="INFO" type="[GNCRN]" ip="%(h)-15s" rqt="%(L)s" response_code="%(s)s" response_bytes="%(b)-6s" uri="%(m)s:%(U)s %(q)s" user=":%(u)s" user_agent="%(a)s"')
50
50
51
51
52 # Sets the number of process workers. More workers means more concurrent connections
52 # Sets the number of process workers. More workers means more concurrent connections
53 # RhodeCode can handle at the same time. Each additional worker also it increases
53 # RhodeCode can handle at the same time. Each additional worker also it increases
54 # memory usage as each has it's own set of caches.
54 # memory usage as each has its own set of caches.
55 # Recommended value is (2 * NUMBER_OF_CPUS + 1), eg 2CPU = 5 workers, but no more
55 # The Recommended value is (2 * NUMBER_OF_CPUS + 1), eg 2CPU = 5 workers, but no more
56 # than 8-10 unless for huge deployments .e.g 700-1000 users.
56 # than 8-10 unless for huge deployments .e.g 700-1000 users.
57 # `instance_id = *` must be set in the [app:main] section below (which is the default)
57 # `instance_id = *` must be set in the [app:main] section below (which is the default)
58 # when using more than 1 worker.
58 # when using more than 1 worker.
59 workers = 4
59 workers = 4
60
60
61 # self adjust workers based on CPU count, to use maximum of CPU and not overquota the resources
61 # self adjust workers based on CPU count, to use maximum of CPU and not overquota the resources
62 # workers = get_workers()
62 # workers = get_workers()
63
63
64 # Gunicorn access log level
64 # Gunicorn access log level
65 loglevel = 'info'
65 loglevel = 'info'
66
66
67 # Process name visible in a process list
67 # Process name visible in a process list
68 proc_name = 'rhodecode_enterprise'
68 proc_name = 'rhodecode_enterprise'
69
69
70 # Type of worker class, one of `sync`, `gevent`
70 # Type of worker class, one of `sync`, `gevent` or `gthread`
71 # currently `sync` is the only option allowed.
71 # currently `sync` is the only option allowed for vcsserver and for rhodecode all of 3 are allowed
72 # gevent:
73 # In this case, the maximum number of concurrent requests is (N workers * X worker_connections)
74 # e.g. workers =3 worker_connections=10 = 3*10, 30 concurrent requests can be handled
75 # gtrhead:
76 # In this case, the maximum number of concurrent requests is (N workers * X threads)
77 # e.g. workers = 3 threads=3 = 3*3, 9 concurrent requests can be handled
72 worker_class = 'gevent'
78 worker_class = 'gevent'
73
79
74 # The maximum number of simultaneous clients. Valid only for gevent
80 # The maximum number of simultaneous clients. Valid only for gevent
81 # In this case, the maximum number of concurrent requests is (N workers * X worker_connections)
82 # e.g workers =3 worker_connections=10 = 3*10, 30 concurrent requests can be handled
75 worker_connections = 10
83 worker_connections = 10
76
84
77 # Max number of requests that worker will handle before being gracefully restarted.
85 # Max number of requests that worker will handle before being gracefully restarted.
78 # Prevents memory leaks, jitter adds variability so not all workers are restarted at once.
86 # Prevents memory leaks, jitter adds variability so not all workers are restarted at once.
79 max_requests = 2000
87 max_requests = 2000
80 max_requests_jitter = int(max_requests * 0.2) # 20% of max_requests
88 max_requests_jitter = int(max_requests * 0.2) # 20% of max_requests
81
89
82 # The maximum number of pending connections.
90 # The maximum number of pending connections.
83 # Exceeding this number results in the client getting an error when attempting to connect.
91 # Exceeding this number results in the client getting an error when attempting to connect.
84 backlog = 64
92 backlog = 64
85
93
86 # The Amount of time a worker can spend with handling a request before it
94 # The Amount of time a worker can spend with handling a request before it
87 # gets killed and restarted. By default, set to 21600 (6hrs)
95 # gets killed and restarted. By default, set to 21600 (6hrs)
88 # Examples: 1800 (30min), 3600 (1hr), 7200 (2hr), 43200 (12h)
96 # Examples: 1800 (30min), 3600 (1hr), 7200 (2hr), 43200 (12h)
89 timeout = 21600
97 timeout = 21600
90
98
91 # The maximum size of HTTP request line in bytes.
99 # The maximum size of HTTP request line in bytes.
92 # 0 for unlimited
100 # 0 for unlimited
93 limit_request_line = 0
101 limit_request_line = 0
94
102
95 # Limit the number of HTTP headers fields in a request.
103 # Limit the number of HTTP headers fields in a request.
96 # By default this value is 100 and can't be larger than 32768.
104 # By default this value is 100 and can't be larger than 32768.
97 limit_request_fields = 32768
105 limit_request_fields = 32768
98
106
99 # Limit the allowed size of an HTTP request header field.
107 # Limit the allowed size of an HTTP request header field.
100 # Value is a positive number or 0.
108 # Value is a positive number or 0.
101 # Setting it to 0 will allow unlimited header field sizes.
109 # Setting it to 0 will allow unlimited header field sizes.
102 limit_request_field_size = 0
110 limit_request_field_size = 0
103
111
104 # Timeout for graceful workers restart.
112 # Timeout for graceful workers restart.
105 # After receiving a restart signal, workers have this much time to finish
113 # After receiving a restart signal, workers have this much time to finish
106 # serving requests. Workers still alive after the timeout (starting from the
114 # serving requests. Workers still alive after the timeout (starting from the
107 # receipt of the restart signal) are force killed.
115 # receipt of the restart signal) are force killed.
108 # Examples: 1800 (30min), 3600 (1hr), 7200 (2hr), 43200 (12h)
116 # Examples: 1800 (30min), 3600 (1hr), 7200 (2hr), 43200 (12h)
109 graceful_timeout = 21600
117 graceful_timeout = 21600
110
118
111 # The number of seconds to wait for requests on a Keep-Alive connection.
119 # The number of seconds to wait for requests on a Keep-Alive connection.
112 # Generally set in the 1-5 seconds range.
120 # Generally set in the 1-5 seconds range.
113 keepalive = 2
121 keepalive = 2
114
122
115 # Maximum memory usage that each worker can use before it will receive a
123 # Maximum memory usage that each worker can use before it will receive a
116 # graceful restart signal 0 = memory monitoring is disabled
124 # graceful restart signal 0 = memory monitoring is disabled
117 # Examples: 268435456 (256MB), 536870912 (512MB)
125 # Examples: 268435456 (256MB), 536870912 (512MB)
118 # 1073741824 (1GB), 2147483648 (2GB), 4294967296 (4GB)
126 # 1073741824 (1GB), 2147483648 (2GB), 4294967296 (4GB)
119 # Dynamic formula 1024 * 1024 * 256 == 256MBs
127 # Dynamic formula 1024 * 1024 * 256 == 256MBs
120 memory_max_usage = 0
128 memory_max_usage = 0
121
129
122 # How often in seconds to check for memory usage for each gunicorn worker
130 # How often in seconds to check for memory usage for each gunicorn worker
123 memory_usage_check_interval = 60
131 memory_usage_check_interval = 60
124
132
125 # Threshold value for which we don't recycle worker if GarbageCollection
133 # Threshold value for which we don't recycle worker if GarbageCollection
126 # frees up enough resources. Before each restart, we try to run GC on worker
134 # frees up enough resources. Before each restart, we try to run GC on worker
127 # in case we get enough free memory after that; restart will not happen.
135 # in case we get enough free memory after that; restart will not happen.
128 memory_usage_recovery_threshold = 0.8
136 memory_usage_recovery_threshold = 0.8
129
137
130
138
131 @dataclasses.dataclass
139 @dataclasses.dataclass
132 class MemoryCheckConfig:
140 class MemoryCheckConfig:
133 max_usage: int
141 max_usage: int
134 check_interval: int
142 check_interval: int
135 recovery_threshold: float
143 recovery_threshold: float
136
144
137
145
138 def _get_process_rss(pid=None):
146 def _get_process_rss(pid=None):
139 try:
147 try:
140 import psutil
148 import psutil
141 if pid:
149 if pid:
142 proc = psutil.Process(pid)
150 proc = psutil.Process(pid)
143 else:
151 else:
144 proc = psutil.Process()
152 proc = psutil.Process()
145 return proc.memory_info().rss
153 return proc.memory_info().rss
146 except Exception:
154 except Exception:
147 return None
155 return None
148
156
149
157
150 def _get_config(ini_path):
158 def _get_config(ini_path):
151 import configparser
159 import configparser
152
160
153 try:
161 try:
154 config = configparser.RawConfigParser()
162 config = configparser.RawConfigParser()
155 config.read(ini_path)
163 config.read(ini_path)
156 return config
164 return config
157 except Exception:
165 except Exception:
158 return None
166 return None
159
167
160
168
161 def get_memory_usage_params(config=None):
169 def get_memory_usage_params(config=None):
162 # memory spec defaults
170 # memory spec defaults
163 _memory_max_usage = memory_max_usage
171 _memory_max_usage = memory_max_usage
164 _memory_usage_check_interval = memory_usage_check_interval
172 _memory_usage_check_interval = memory_usage_check_interval
165 _memory_usage_recovery_threshold = memory_usage_recovery_threshold
173 _memory_usage_recovery_threshold = memory_usage_recovery_threshold
166
174
167 if config:
175 if config:
168 ini_path = os.path.abspath(config)
176 ini_path = os.path.abspath(config)
169 conf = _get_config(ini_path)
177 conf = _get_config(ini_path)
170
178
171 section = 'server:main'
179 section = 'server:main'
172 if conf and conf.has_section(section):
180 if conf and conf.has_section(section):
173
181
174 if conf.has_option(section, 'memory_max_usage'):
182 if conf.has_option(section, 'memory_max_usage'):
175 _memory_max_usage = conf.getint(section, 'memory_max_usage')
183 _memory_max_usage = conf.getint(section, 'memory_max_usage')
176
184
177 if conf.has_option(section, 'memory_usage_check_interval'):
185 if conf.has_option(section, 'memory_usage_check_interval'):
178 _memory_usage_check_interval = conf.getint(section, 'memory_usage_check_interval')
186 _memory_usage_check_interval = conf.getint(section, 'memory_usage_check_interval')
179
187
180 if conf.has_option(section, 'memory_usage_recovery_threshold'):
188 if conf.has_option(section, 'memory_usage_recovery_threshold'):
181 _memory_usage_recovery_threshold = conf.getfloat(section, 'memory_usage_recovery_threshold')
189 _memory_usage_recovery_threshold = conf.getfloat(section, 'memory_usage_recovery_threshold')
182
190
183 _memory_max_usage = int(os.environ.get('RC_GUNICORN_MEMORY_MAX_USAGE', '')
191 _memory_max_usage = int(os.environ.get('RC_GUNICORN_MEMORY_MAX_USAGE', '')
184 or _memory_max_usage)
192 or _memory_max_usage)
185 _memory_usage_check_interval = int(os.environ.get('RC_GUNICORN_MEMORY_USAGE_CHECK_INTERVAL', '')
193 _memory_usage_check_interval = int(os.environ.get('RC_GUNICORN_MEMORY_USAGE_CHECK_INTERVAL', '')
186 or _memory_usage_check_interval)
194 or _memory_usage_check_interval)
187 _memory_usage_recovery_threshold = float(os.environ.get('RC_GUNICORN_MEMORY_USAGE_RECOVERY_THRESHOLD', '')
195 _memory_usage_recovery_threshold = float(os.environ.get('RC_GUNICORN_MEMORY_USAGE_RECOVERY_THRESHOLD', '')
188 or _memory_usage_recovery_threshold)
196 or _memory_usage_recovery_threshold)
189
197
190 return MemoryCheckConfig(_memory_max_usage, _memory_usage_check_interval, _memory_usage_recovery_threshold)
198 return MemoryCheckConfig(_memory_max_usage, _memory_usage_check_interval, _memory_usage_recovery_threshold)
191
199
192
200
193 def _time_with_offset(check_interval):
201 def _time_with_offset(check_interval):
194 return time.time() - random.randint(0, check_interval/2.0)
202 return time.time() - random.randint(0, check_interval/2.0)
195
203
196
204
197 def pre_fork(server, worker):
205 def pre_fork(server, worker):
198 pass
206 pass
199
207
200
208
201 def post_fork(server, worker):
209 def post_fork(server, worker):
202
210
203 memory_conf = get_memory_usage_params()
211 memory_conf = get_memory_usage_params()
204 _memory_max_usage = memory_conf.max_usage
212 _memory_max_usage = memory_conf.max_usage
205 _memory_usage_check_interval = memory_conf.check_interval
213 _memory_usage_check_interval = memory_conf.check_interval
206 _memory_usage_recovery_threshold = memory_conf.recovery_threshold
214 _memory_usage_recovery_threshold = memory_conf.recovery_threshold
207
215
208 worker._memory_max_usage = int(os.environ.get('RC_GUNICORN_MEMORY_MAX_USAGE', '')
216 worker._memory_max_usage = int(os.environ.get('RC_GUNICORN_MEMORY_MAX_USAGE', '')
209 or _memory_max_usage)
217 or _memory_max_usage)
210 worker._memory_usage_check_interval = int(os.environ.get('RC_GUNICORN_MEMORY_USAGE_CHECK_INTERVAL', '')
218 worker._memory_usage_check_interval = int(os.environ.get('RC_GUNICORN_MEMORY_USAGE_CHECK_INTERVAL', '')
211 or _memory_usage_check_interval)
219 or _memory_usage_check_interval)
212 worker._memory_usage_recovery_threshold = float(os.environ.get('RC_GUNICORN_MEMORY_USAGE_RECOVERY_THRESHOLD', '')
220 worker._memory_usage_recovery_threshold = float(os.environ.get('RC_GUNICORN_MEMORY_USAGE_RECOVERY_THRESHOLD', '')
213 or _memory_usage_recovery_threshold)
221 or _memory_usage_recovery_threshold)
214
222
215 # register memory last check time, with some random offset so we don't recycle all
223 # register memory last check time, with some random offset so we don't recycle all
216 # at once
224 # at once
217 worker._last_memory_check_time = _time_with_offset(_memory_usage_check_interval)
225 worker._last_memory_check_time = _time_with_offset(_memory_usage_check_interval)
218
226
219 if _memory_max_usage:
227 if _memory_max_usage:
220 server.log.info("pid=[%-10s] WORKER spawned with max memory set at %s", worker.pid,
228 server.log.info("pid=[%-10s] WORKER spawned with max memory set at %s", worker.pid,
221 _format_data_size(_memory_max_usage))
229 _format_data_size(_memory_max_usage))
222 else:
230 else:
223 server.log.info("pid=[%-10s] WORKER spawned", worker.pid)
231 server.log.info("pid=[%-10s] WORKER spawned", worker.pid)
224
232
225
233
226 def pre_exec(server):
234 def pre_exec(server):
227 server.log.info("Forked child, re-executing.")
235 server.log.info("Forked child, re-executing.")
228
236
229
237
230 def on_starting(server):
238 def on_starting(server):
231 server_lbl = '{} {}'.format(server.proc_name, server.address)
239 server_lbl = '{} {}'.format(server.proc_name, server.address)
232 server.log.info("Server %s is starting.", server_lbl)
240 server.log.info("Server %s is starting.", server_lbl)
233 server.log.info('Config:')
241 server.log.info('Config:')
234 server.log.info(f"\n{server.cfg}")
242 server.log.info(f"\n{server.cfg}")
235 server.log.info(get_memory_usage_params())
243 server.log.info(get_memory_usage_params())
236
244
237
245
238 def when_ready(server):
246 def when_ready(server):
239 server.log.info("Server %s is ready. Spawning workers", server)
247 server.log.info("Server %s is ready. Spawning workers", server)
240
248
241
249
242 def on_reload(server):
250 def on_reload(server):
243 pass
251 pass
244
252
245
253
246 def _format_data_size(size, unit="B", precision=1, binary=True):
254 def _format_data_size(size, unit="B", precision=1, binary=True):
247 """Format a number using SI units (kilo, mega, etc.).
255 """Format a number using SI units (kilo, mega, etc.).
248
256
249 ``size``: The number as a float or int.
257 ``size``: The number as a float or int.
250
258
251 ``unit``: The unit name in plural form. Examples: "bytes", "B".
259 ``unit``: The unit name in plural form. Examples: "bytes", "B".
252
260
253 ``precision``: How many digits to the right of the decimal point. Default
261 ``precision``: How many digits to the right of the decimal point. Default
254 is 1. 0 suppresses the decimal point.
262 is 1. 0 suppresses the decimal point.
255
263
256 ``binary``: If false, use base-10 decimal prefixes (kilo = K = 1000).
264 ``binary``: If false, use base-10 decimal prefixes (kilo = K = 1000).
257 If true, use base-2 binary prefixes (kibi = Ki = 1024).
265 If true, use base-2 binary prefixes (kibi = Ki = 1024).
258
266
259 ``full_name``: If false (default), use the prefix abbreviation ("k" or
267 ``full_name``: If false (default), use the prefix abbreviation ("k" or
260 "Ki"). If true, use the full prefix ("kilo" or "kibi"). If false,
268 "Ki"). If true, use the full prefix ("kilo" or "kibi"). If false,
261 use abbreviation ("k" or "Ki").
269 use abbreviation ("k" or "Ki").
262
270
263 """
271 """
264
272
265 if not binary:
273 if not binary:
266 base = 1000
274 base = 1000
267 multiples = ('', 'k', 'M', 'G', 'T', 'P', 'E', 'Z', 'Y')
275 multiples = ('', 'k', 'M', 'G', 'T', 'P', 'E', 'Z', 'Y')
268 else:
276 else:
269 base = 1024
277 base = 1024
270 multiples = ('', 'Ki', 'Mi', 'Gi', 'Ti', 'Pi', 'Ei', 'Zi', 'Yi')
278 multiples = ('', 'Ki', 'Mi', 'Gi', 'Ti', 'Pi', 'Ei', 'Zi', 'Yi')
271
279
272 sign = ""
280 sign = ""
273 if size > 0:
281 if size > 0:
274 m = int(math.log(size, base))
282 m = int(math.log(size, base))
275 elif size < 0:
283 elif size < 0:
276 sign = "-"
284 sign = "-"
277 size = -size
285 size = -size
278 m = int(math.log(size, base))
286 m = int(math.log(size, base))
279 else:
287 else:
280 m = 0
288 m = 0
281 if m > 8:
289 if m > 8:
282 m = 8
290 m = 8
283
291
284 if m == 0:
292 if m == 0:
285 precision = '%.0f'
293 precision = '%.0f'
286 else:
294 else:
287 precision = '%%.%df' % precision
295 precision = '%%.%df' % precision
288
296
289 size = precision % (size / math.pow(base, m))
297 size = precision % (size / math.pow(base, m))
290
298
291 return '%s%s %s%s' % (sign, size.strip(), multiples[m], unit)
299 return '%s%s %s%s' % (sign, size.strip(), multiples[m], unit)
292
300
293
301
294 def _check_memory_usage(worker):
302 def _check_memory_usage(worker):
295 _memory_max_usage = worker._memory_max_usage
303 _memory_max_usage = worker._memory_max_usage
296 if not _memory_max_usage:
304 if not _memory_max_usage:
297 return
305 return
298
306
299 _memory_usage_check_interval = worker._memory_usage_check_interval
307 _memory_usage_check_interval = worker._memory_usage_check_interval
300 _memory_usage_recovery_threshold = memory_max_usage * worker._memory_usage_recovery_threshold
308 _memory_usage_recovery_threshold = memory_max_usage * worker._memory_usage_recovery_threshold
301
309
302 elapsed = time.time() - worker._last_memory_check_time
310 elapsed = time.time() - worker._last_memory_check_time
303 if elapsed > _memory_usage_check_interval:
311 if elapsed > _memory_usage_check_interval:
304 mem_usage = _get_process_rss()
312 mem_usage = _get_process_rss()
305 if mem_usage and mem_usage > _memory_max_usage:
313 if mem_usage and mem_usage > _memory_max_usage:
306 worker.log.info(
314 worker.log.info(
307 "memory usage %s > %s, forcing gc",
315 "memory usage %s > %s, forcing gc",
308 _format_data_size(mem_usage), _format_data_size(_memory_max_usage))
316 _format_data_size(mem_usage), _format_data_size(_memory_max_usage))
309 # Try to clean it up by forcing a full collection.
317 # Try to clean it up by forcing a full collection.
310 gc.collect()
318 gc.collect()
311 mem_usage = _get_process_rss()
319 mem_usage = _get_process_rss()
312 if mem_usage > _memory_usage_recovery_threshold:
320 if mem_usage > _memory_usage_recovery_threshold:
313 # Didn't clean up enough, we'll have to terminate.
321 # Didn't clean up enough, we'll have to terminate.
314 worker.log.warning(
322 worker.log.warning(
315 "memory usage %s > %s after gc, quitting",
323 "memory usage %s > %s after gc, quitting",
316 _format_data_size(mem_usage), _format_data_size(_memory_max_usage))
324 _format_data_size(mem_usage), _format_data_size(_memory_max_usage))
317 # This will cause worker to auto-restart itself
325 # This will cause worker to auto-restart itself
318 worker.alive = False
326 worker.alive = False
319 worker._last_memory_check_time = time.time()
327 worker._last_memory_check_time = time.time()
320
328
321
329
322 def worker_int(worker):
330 def worker_int(worker):
323 worker.log.info("pid=[%-10s] worker received INT or QUIT signal", worker.pid)
331 worker.log.info("pid=[%-10s] worker received INT or QUIT signal", worker.pid)
324
332
325 # get traceback info, when a worker crashes
333 # get traceback info, when a worker crashes
326 def get_thread_id(t_id):
334 def get_thread_id(t_id):
327 id2name = dict([(th.ident, th.name) for th in threading.enumerate()])
335 id2name = dict([(th.ident, th.name) for th in threading.enumerate()])
328 return id2name.get(t_id, "unknown_thread_id")
336 return id2name.get(t_id, "unknown_thread_id")
329
337
330 code = []
338 code = []
331 for thread_id, stack in sys._current_frames().items(): # noqa
339 for thread_id, stack in sys._current_frames().items(): # noqa
332 code.append(
340 code.append(
333 "\n# Thread: %s(%d)" % (get_thread_id(thread_id), thread_id))
341 "\n# Thread: %s(%d)" % (get_thread_id(thread_id), thread_id))
334 for fname, lineno, name, line in traceback.extract_stack(stack):
342 for fname, lineno, name, line in traceback.extract_stack(stack):
335 code.append('File: "%s", line %d, in %s' % (fname, lineno, name))
343 code.append('File: "%s", line %d, in %s' % (fname, lineno, name))
336 if line:
344 if line:
337 code.append(" %s" % (line.strip()))
345 code.append(" %s" % (line.strip()))
338 worker.log.debug("\n".join(code))
346 worker.log.debug("\n".join(code))
339
347
340
348
341 def worker_abort(worker):
349 def worker_abort(worker):
342 worker.log.info("pid=[%-10s] worker received SIGABRT signal", worker.pid)
350 worker.log.info("pid=[%-10s] worker received SIGABRT signal", worker.pid)
343
351
344
352
345 def worker_exit(server, worker):
353 def worker_exit(server, worker):
346 worker.log.info("pid=[%-10s] worker exit", worker.pid)
354 worker.log.info("pid=[%-10s] worker exit", worker.pid)
347
355
348
356
349 def child_exit(server, worker):
357 def child_exit(server, worker):
350 worker.log.info("pid=[%-10s] worker child exit", worker.pid)
358 worker.log.info("pid=[%-10s] worker child exit", worker.pid)
351
359
352
360
353 def pre_request(worker, req):
361 def pre_request(worker, req):
354 worker.start_time = time.time()
362 worker.start_time = time.time()
355 worker.log.debug(
363 worker.log.debug(
356 "GNCRN PRE WORKER [cnt:%s]: %s %s", worker.nr, req.method, req.path)
364 "GNCRN PRE WORKER [cnt:%s]: %s %s", worker.nr, req.method, req.path)
357
365
358
366
359 def post_request(worker, req, environ, resp):
367 def post_request(worker, req, environ, resp):
360 total_time = time.time() - worker.start_time
368 total_time = time.time() - worker.start_time
361 # Gunicorn sometimes has problems with reading the status_code
369 # Gunicorn sometimes has problems with reading the status_code
362 status_code = getattr(resp, 'status_code', '')
370 status_code = getattr(resp, 'status_code', '')
363 worker.log.debug(
371 worker.log.debug(
364 "GNCRN POST WORKER [cnt:%s]: %s %s resp: %s, Load Time: %.4fs",
372 "GNCRN POST WORKER [cnt:%s]: %s %s resp: %s, Load Time: %.4fs",
365 worker.nr, req.method, req.path, status_code, total_time)
373 worker.nr, req.method, req.path, status_code, total_time)
366 _check_memory_usage(worker)
374 _check_memory_usage(worker)
367
375
368
376
369 def _filter_proxy(ip):
377 def _filter_proxy(ip):
370 """
378 """
371 Passed in IP addresses in HEADERS can be in a special format of multiple
379 Passed in IP addresses in HEADERS can be in a special format of multiple
372 ips. Those comma separated IPs are passed from various proxies in the
380 ips. Those comma separated IPs are passed from various proxies in the
373 chain of request processing. The left-most being the original client.
381 chain of request processing. The left-most being the original client.
374 We only care about the first IP which came from the org. client.
382 We only care about the first IP which came from the org. client.
375
383
376 :param ip: ip string from headers
384 :param ip: ip string from headers
377 """
385 """
378 if ',' in ip:
386 if ',' in ip:
379 _ips = ip.split(',')
387 _ips = ip.split(',')
380 _first_ip = _ips[0].strip()
388 _first_ip = _ips[0].strip()
381 return _first_ip
389 return _first_ip
382 return ip
390 return ip
383
391
384
392
385 def _filter_port(ip):
393 def _filter_port(ip):
386 """
394 """
387 Removes a port from ip, there are 4 main cases to handle here.
395 Removes a port from ip, there are 4 main cases to handle here.
388 - ipv4 eg. 127.0.0.1
396 - ipv4 eg. 127.0.0.1
389 - ipv6 eg. ::1
397 - ipv6 eg. ::1
390 - ipv4+port eg. 127.0.0.1:8080
398 - ipv4+port eg. 127.0.0.1:8080
391 - ipv6+port eg. [::1]:8080
399 - ipv6+port eg. [::1]:8080
392
400
393 :param ip:
401 :param ip:
394 """
402 """
395 def is_ipv6(ip_addr):
403 def is_ipv6(ip_addr):
396 if hasattr(socket, 'inet_pton'):
404 if hasattr(socket, 'inet_pton'):
397 try:
405 try:
398 socket.inet_pton(socket.AF_INET6, ip_addr)
406 socket.inet_pton(socket.AF_INET6, ip_addr)
399 except socket.error:
407 except socket.error:
400 return False
408 return False
401 else:
409 else:
402 return False
410 return False
403 return True
411 return True
404
412
405 if ':' not in ip: # must be ipv4 pure ip
413 if ':' not in ip: # must be ipv4 pure ip
406 return ip
414 return ip
407
415
408 if '[' in ip and ']' in ip: # ipv6 with port
416 if '[' in ip and ']' in ip: # ipv6 with port
409 return ip.split(']')[0][1:].lower()
417 return ip.split(']')[0][1:].lower()
410
418
411 # must be ipv6 or ipv4 with port
419 # must be ipv6 or ipv4 with port
412 if is_ipv6(ip):
420 if is_ipv6(ip):
413 return ip
421 return ip
414 else:
422 else:
415 ip, _port = ip.split(':')[:2] # means ipv4+port
423 ip, _port = ip.split(':')[:2] # means ipv4+port
416 return ip
424 return ip
417
425
418
426
419 def get_ip_addr(environ):
427 def get_ip_addr(environ):
420 proxy_key = 'HTTP_X_REAL_IP'
428 proxy_key = 'HTTP_X_REAL_IP'
421 proxy_key2 = 'HTTP_X_FORWARDED_FOR'
429 proxy_key2 = 'HTTP_X_FORWARDED_FOR'
422 def_key = 'REMOTE_ADDR'
430 def_key = 'REMOTE_ADDR'
423
431
424 def _filters(x):
432 def _filters(x):
425 return _filter_port(_filter_proxy(x))
433 return _filter_port(_filter_proxy(x))
426
434
427 ip = environ.get(proxy_key)
435 ip = environ.get(proxy_key)
428 if ip:
436 if ip:
429 return _filters(ip)
437 return _filters(ip)
430
438
431 ip = environ.get(proxy_key2)
439 ip = environ.get(proxy_key2)
432 if ip:
440 if ip:
433 return _filters(ip)
441 return _filters(ip)
434
442
435 ip = environ.get(def_key, '0.0.0.0')
443 ip = environ.get(def_key, '0.0.0.0')
436 return _filters(ip)
444 return _filters(ip)
437
445
438
446
439 class RhodeCodeLogger(Logger):
447 class RhodeCodeLogger(Logger):
440 """
448 """
441 Custom Logger that allows some customization that gunicorn doesn't allow
449 Custom Logger that allows some customization that gunicorn doesn't allow
442 """
450 """
443
451
444 datefmt = r"%Y-%m-%d %H:%M:%S"
452 datefmt = r"%Y-%m-%d %H:%M:%S"
445
453
446 def __init__(self, cfg):
454 def __init__(self, cfg):
447 Logger.__init__(self, cfg)
455 Logger.__init__(self, cfg)
448
456
449 def now(self):
457 def now(self):
450 """ return date in RhodeCode Log format """
458 """ return date in RhodeCode Log format """
451 now = time.time()
459 now = time.time()
452 msecs = int((now - int(now)) * 1000)
460 msecs = int((now - int(now)) * 1000)
453 return time.strftime(self.datefmt, time.localtime(now)) + '.{0:03d}'.format(msecs)
461 return time.strftime(self.datefmt, time.localtime(now)) + '.{0:03d}'.format(msecs)
454
462
455 def atoms(self, resp, req, environ, request_time):
463 def atoms(self, resp, req, environ, request_time):
456 """ Gets atoms for log formatting.
464 """ Gets atoms for log formatting.
457 """
465 """
458 status = resp.status
466 status = resp.status
459 if isinstance(status, str):
467 if isinstance(status, str):
460 status = status.split(None, 1)[0]
468 status = status.split(None, 1)[0]
461 atoms = {
469 atoms = {
462 'h': get_ip_addr(environ),
470 'h': get_ip_addr(environ),
463 'l': '-',
471 'l': '-',
464 'u': self._get_user(environ) or '-',
472 'u': self._get_user(environ) or '-',
465 't': self.now(),
473 't': self.now(),
466 'r': "%s %s %s" % (environ['REQUEST_METHOD'],
474 'r': "%s %s %s" % (environ['REQUEST_METHOD'],
467 environ['RAW_URI'],
475 environ['RAW_URI'],
468 environ["SERVER_PROTOCOL"]),
476 environ["SERVER_PROTOCOL"]),
469 's': status,
477 's': status,
470 'm': environ.get('REQUEST_METHOD'),
478 'm': environ.get('REQUEST_METHOD'),
471 'U': environ.get('PATH_INFO'),
479 'U': environ.get('PATH_INFO'),
472 'q': environ.get('QUERY_STRING'),
480 'q': environ.get('QUERY_STRING'),
473 'H': environ.get('SERVER_PROTOCOL'),
481 'H': environ.get('SERVER_PROTOCOL'),
474 'b': getattr(resp, 'sent', None) is not None and str(resp.sent) or '-',
482 'b': getattr(resp, 'sent', None) is not None and str(resp.sent) or '-',
475 'B': getattr(resp, 'sent', None),
483 'B': getattr(resp, 'sent', None),
476 'f': environ.get('HTTP_REFERER', '-'),
484 'f': environ.get('HTTP_REFERER', '-'),
477 'a': environ.get('HTTP_USER_AGENT', '-'),
485 'a': environ.get('HTTP_USER_AGENT', '-'),
478 'T': request_time.seconds,
486 'T': request_time.seconds,
479 'D': (request_time.seconds * 1000000) + request_time.microseconds,
487 'D': (request_time.seconds * 1000000) + request_time.microseconds,
480 'M': (request_time.seconds * 1000) + int(request_time.microseconds/1000),
488 'M': (request_time.seconds * 1000) + int(request_time.microseconds/1000),
481 'L': "%d.%06d" % (request_time.seconds, request_time.microseconds),
489 'L': "%d.%06d" % (request_time.seconds, request_time.microseconds),
482 'p': "<%s>" % os.getpid()
490 'p': "<%s>" % os.getpid()
483 }
491 }
484
492
485 # add request headers
493 # add request headers
486 if hasattr(req, 'headers'):
494 if hasattr(req, 'headers'):
487 req_headers = req.headers
495 req_headers = req.headers
488 else:
496 else:
489 req_headers = req
497 req_headers = req
490
498
491 if hasattr(req_headers, "items"):
499 if hasattr(req_headers, "items"):
492 req_headers = req_headers.items()
500 req_headers = req_headers.items()
493
501
494 atoms.update({"{%s}i" % k.lower(): v for k, v in req_headers})
502 atoms.update({"{%s}i" % k.lower(): v for k, v in req_headers})
495
503
496 resp_headers = resp.headers
504 resp_headers = resp.headers
497 if hasattr(resp_headers, "items"):
505 if hasattr(resp_headers, "items"):
498 resp_headers = resp_headers.items()
506 resp_headers = resp_headers.items()
499
507
500 # add response headers
508 # add response headers
501 atoms.update({"{%s}o" % k.lower(): v for k, v in resp_headers})
509 atoms.update({"{%s}o" % k.lower(): v for k, v in resp_headers})
502
510
503 # add environ variables
511 # add environ variables
504 environ_variables = environ.items()
512 environ_variables = environ.items()
505 atoms.update({"{%s}e" % k.lower(): v for k, v in environ_variables})
513 atoms.update({"{%s}e" % k.lower(): v for k, v in environ_variables})
506
514
507 return atoms
515 return atoms
508
516
509
517
510 logger_class = RhodeCodeLogger
518 logger_class = RhodeCodeLogger
General Comments 0
You need to be logged in to leave comments. Login now