Revision 34c9ee7b daemons/import-export
b/daemons/import-export | ||
---|---|---|
30 | 30 |
import logging |
31 | 31 |
import optparse |
32 | 32 |
import os |
33 |
import re |
|
34 | 33 |
import select |
35 | 34 |
import signal |
36 |
import socket |
|
37 | 35 |
import subprocess |
38 | 36 |
import sys |
39 | 37 |
import time |
... | ... | |
47 | 45 |
from ganeti import impexpd |
48 | 46 |
|
49 | 47 |
|
50 |
#: Used to recognize point at which socat(1) starts to listen on its socket. |
|
51 |
#: The local address is required for the remote peer to connect (in particular |
|
52 |
#: the port number). |
|
53 |
LISTENING_RE = re.compile(r"^listening on\s+" |
|
54 |
r"AF=(?P<family>\d+)\s+" |
|
55 |
r"(?P<address>.+):(?P<port>\d+)$", re.I) |
|
56 |
|
|
57 |
#: Used to recognize point at which socat(1) is sending data over the wire |
|
58 |
TRANSFER_LOOP_RE = re.compile(r"^starting data transfer loop with FDs\s+.*$", |
|
59 |
re.I) |
|
60 |
|
|
61 |
SOCAT_LOG_DEBUG = "D" |
|
62 |
SOCAT_LOG_INFO = "I" |
|
63 |
SOCAT_LOG_NOTICE = "N" |
|
64 |
SOCAT_LOG_WARNING = "W" |
|
65 |
SOCAT_LOG_ERROR = "E" |
|
66 |
SOCAT_LOG_FATAL = "F" |
|
67 |
|
|
68 |
SOCAT_LOG_IGNORE = frozenset([ |
|
69 |
SOCAT_LOG_DEBUG, |
|
70 |
SOCAT_LOG_INFO, |
|
71 |
SOCAT_LOG_NOTICE, |
|
72 |
]) |
|
73 |
|
|
74 | 48 |
#: How many lines to keep in the status file |
75 | 49 |
MAX_RECENT_OUTPUT_LINES = 20 |
76 | 50 |
|
... | ... | |
88 | 62 |
options = None |
89 | 63 |
|
90 | 64 |
|
91 |
class Error(Exception): |
|
92 |
"""Generic exception""" |
|
93 |
|
|
94 |
|
|
95 | 65 |
def SetupLogging(): |
96 | 66 |
"""Configures the logging module. |
97 | 67 |
|
... | ... | |
120 | 90 |
return child_logger |
121 | 91 |
|
122 | 92 |
|
123 |
def _VerifyListening(family, address, port): |
|
124 |
"""Verify address given as listening address by socat. |
|
125 |
|
|
126 |
""" |
|
127 |
# TODO: Implement IPv6 support |
|
128 |
if family != socket.AF_INET: |
|
129 |
raise Error("Address family %r not supported" % family) |
|
130 |
|
|
131 |
try: |
|
132 |
packed_address = socket.inet_pton(family, address) |
|
133 |
except socket.error: |
|
134 |
raise Error("Invalid address %r for family %s" % (address, family)) |
|
135 |
|
|
136 |
return (socket.inet_ntop(family, packed_address), port) |
|
137 |
|
|
138 |
|
|
139 | 93 |
class StatusFile: |
140 | 94 |
"""Status file manager. |
141 | 95 |
|
... | ... | |
223 | 177 |
mode=0400) |
224 | 178 |
|
225 | 179 |
|
226 |
def _ProcessSocatOutput(status_file, level, msg): |
|
227 |
"""Interprets socat log output. |
|
228 |
|
|
229 |
""" |
|
230 |
if level == SOCAT_LOG_NOTICE: |
|
231 |
if status_file.GetListenPort() is None: |
|
232 |
# TODO: Maybe implement timeout to not listen forever |
|
233 |
m = LISTENING_RE.match(msg) |
|
234 |
if m: |
|
235 |
(_, port) = _VerifyListening(int(m.group("family")), m.group("address"), |
|
236 |
int(m.group("port"))) |
|
237 |
|
|
238 |
status_file.SetListenPort(port) |
|
239 |
return True |
|
240 |
|
|
241 |
if not status_file.GetConnected(): |
|
242 |
m = TRANSFER_LOOP_RE.match(msg) |
|
243 |
if m: |
|
244 |
status_file.SetConnected() |
|
245 |
return True |
|
246 |
|
|
247 |
return False |
|
248 |
|
|
249 |
|
|
250 |
def ProcessOutput(line, status_file, logger, socat): |
|
251 |
"""Takes care of child process output. |
|
252 |
|
|
253 |
@param status_file: Status file manager |
|
254 |
@param logger: Child output logger |
|
255 |
@type socat: bool |
|
256 |
@param socat: Whether it's a socat output line |
|
257 |
@type line: string |
|
258 |
@param line: Child output line |
|
259 |
|
|
260 |
""" |
|
261 |
force_update = False |
|
262 |
forward_line = line |
|
263 |
|
|
264 |
if socat: |
|
265 |
level = None |
|
266 |
parts = line.split(None, 4) |
|
267 |
|
|
268 |
if len(parts) == 5: |
|
269 |
(_, _, _, level, msg) = parts |
|
270 |
|
|
271 |
force_update = _ProcessSocatOutput(status_file, level, msg) |
|
272 |
|
|
273 |
if options.debug or (level and level not in SOCAT_LOG_IGNORE): |
|
274 |
forward_line = "socat: %s %s" % (level, msg) |
|
275 |
else: |
|
276 |
forward_line = None |
|
277 |
else: |
|
278 |
forward_line = "socat: %s" % line |
|
279 |
|
|
280 |
if forward_line: |
|
281 |
logger.info(forward_line) |
|
282 |
status_file.AddRecentOutput(forward_line) |
|
283 |
|
|
284 |
status_file.Update(force_update) |
|
285 |
|
|
286 |
|
|
287 | 180 |
def ProcessChildIO(child, socat_stderr_read_fd, status_file, child_logger, |
288 | 181 |
signal_notify, signal_handler, mode): |
289 | 182 |
"""Handles the child processes' output. |
... | ... | |
297 | 190 |
# readable again. |
298 | 191 |
socat_stderr_read = os.fdopen(socat_stderr_read_fd, "r", 0) |
299 | 192 |
|
300 |
script_stderr_lines = utils.LineSplitter(ProcessOutput, status_file,
|
|
301 |
child_logger, False)
|
|
193 |
child_io_proc = impexpd.ChildIOProcessor(options.debug, status_file,
|
|
194 |
child_logger) |
|
302 | 195 |
try: |
303 |
socat_stderr_lines = utils.LineSplitter(ProcessOutput, status_file, |
|
304 |
child_logger, True) |
|
305 |
try: |
|
306 |
fdmap = { |
|
307 |
child.stderr.fileno(): (child.stderr, script_stderr_lines), |
|
308 |
socat_stderr_read.fileno(): (socat_stderr_read, socat_stderr_lines), |
|
309 |
signal_notify.fileno(): (signal_notify, None), |
|
310 |
} |
|
311 |
|
|
312 |
poller = select.poll() |
|
313 |
for fd in fdmap: |
|
314 |
utils.SetNonblockFlag(fd, True) |
|
315 |
poller.register(fd, select.POLLIN) |
|
316 |
|
|
317 |
if options.connect_timeout and mode == constants.IEM_IMPORT: |
|
318 |
listen_timeout = locking.RunningTimeout(options.connect_timeout, True) |
|
319 |
else: |
|
320 |
listen_timeout = None |
|
321 |
|
|
322 |
exit_timeout = None |
|
323 |
|
|
324 |
while True: |
|
325 |
# Break out of loop if only signal notify FD is left |
|
326 |
if len(fdmap) == 1 and signal_notify.fileno() in fdmap: |
|
196 |
fdmap = { |
|
197 |
child.stderr.fileno(): |
|
198 |
(child.stderr, child_io_proc.GetLineSplitter(impexpd.PROG_OTHER)), |
|
199 |
socat_stderr_read.fileno(): |
|
200 |
(socat_stderr_read, child_io_proc.GetLineSplitter(impexpd.PROG_SOCAT)), |
|
201 |
signal_notify.fileno(): (signal_notify, None), |
|
202 |
} |
|
203 |
|
|
204 |
poller = select.poll() |
|
205 |
for fd in fdmap: |
|
206 |
utils.SetNonblockFlag(fd, True) |
|
207 |
poller.register(fd, select.POLLIN) |
|
208 |
|
|
209 |
if options.connect_timeout and mode == constants.IEM_IMPORT: |
|
210 |
listen_timeout = locking.RunningTimeout(options.connect_timeout, True) |
|
211 |
else: |
|
212 |
listen_timeout = None |
|
213 |
|
|
214 |
exit_timeout = None |
|
215 |
|
|
216 |
while True: |
|
217 |
# Break out of loop if only signal notify FD is left |
|
218 |
if len(fdmap) == 1 and signal_notify.fileno() in fdmap: |
|
219 |
break |
|
220 |
|
|
221 |
timeout = None |
|
222 |
|
|
223 |
if listen_timeout and not exit_timeout: |
|
224 |
if status_file.GetConnected(): |
|
225 |
listen_timeout = None |
|
226 |
elif listen_timeout.Remaining() < 0: |
|
227 |
logging.info("Child process didn't establish connection in time") |
|
228 |
child.Kill(signal.SIGTERM) |
|
229 |
exit_timeout = \ |
|
230 |
locking.RunningTimeout(CHILD_LINGER_TIMEOUT, True) |
|
231 |
# Next block will calculate timeout |
|
232 |
else: |
|
233 |
# Not yet connected, check again in a second |
|
234 |
timeout = 1000 |
|
235 |
|
|
236 |
if exit_timeout: |
|
237 |
timeout = exit_timeout.Remaining() * 1000 |
|
238 |
if timeout < 0: |
|
239 |
logging.info("Child process didn't exit in time") |
|
327 | 240 |
break |
328 | 241 |
|
329 |
timeout = None |
|
330 |
|
|
331 |
if listen_timeout and not exit_timeout: |
|
332 |
if status_file.GetConnected(): |
|
333 |
listen_timeout = None |
|
334 |
elif listen_timeout.Remaining() < 0: |
|
335 |
logging.info("Child process didn't establish connection in time") |
|
336 |
child.Kill(signal.SIGTERM) |
|
337 |
exit_timeout = \ |
|
338 |
locking.RunningTimeout(CHILD_LINGER_TIMEOUT, True) |
|
339 |
# Next block will calculate timeout |
|
242 |
for fd, event in utils.RetryOnSignal(poller.poll, timeout): |
|
243 |
if event & (select.POLLIN | event & select.POLLPRI): |
|
244 |
(from_, to) = fdmap[fd] |
|
245 |
|
|
246 |
# Read up to 1 KB of data |
|
247 |
data = from_.read(1024) |
|
248 |
if data: |
|
249 |
if to: |
|
250 |
to.write(data) |
|
251 |
elif fd == signal_notify.fileno(): |
|
252 |
# Signal handling |
|
253 |
if signal_handler.called: |
|
254 |
signal_handler.Clear() |
|
255 |
if exit_timeout: |
|
256 |
logging.info("Child process still has about %0.2f seconds" |
|
257 |
" to exit", exit_timeout.Remaining()) |
|
258 |
else: |
|
259 |
logging.info("Giving child process %0.2f seconds to exit", |
|
260 |
CHILD_LINGER_TIMEOUT) |
|
261 |
exit_timeout = \ |
|
262 |
locking.RunningTimeout(CHILD_LINGER_TIMEOUT, True) |
|
340 | 263 |
else: |
341 |
# Not yet connected, check again in a second |
|
342 |
timeout = 1000 |
|
343 |
|
|
344 |
if exit_timeout: |
|
345 |
timeout = exit_timeout.Remaining() * 1000 |
|
346 |
if timeout < 0: |
|
347 |
logging.info("Child process didn't exit in time") |
|
348 |
break |
|
349 |
|
|
350 |
for fd, event in utils.RetryOnSignal(poller.poll, timeout): |
|
351 |
if event & (select.POLLIN | event & select.POLLPRI): |
|
352 |
(from_, to) = fdmap[fd] |
|
353 |
|
|
354 |
# Read up to 1 KB of data |
|
355 |
data = from_.read(1024) |
|
356 |
if data: |
|
357 |
if to: |
|
358 |
to.write(data) |
|
359 |
elif fd == signal_notify.fileno(): |
|
360 |
# Signal handling |
|
361 |
if signal_handler.called: |
|
362 |
signal_handler.Clear() |
|
363 |
if exit_timeout: |
|
364 |
logging.info("Child process still has about %0.2f seconds" |
|
365 |
" to exit", exit_timeout.Remaining()) |
|
366 |
else: |
|
367 |
logging.info("Giving child process %0.2f seconds to exit", |
|
368 |
CHILD_LINGER_TIMEOUT) |
|
369 |
exit_timeout = \ |
|
370 |
locking.RunningTimeout(CHILD_LINGER_TIMEOUT, True) |
|
371 |
else: |
|
372 |
poller.unregister(fd) |
|
373 |
del fdmap[fd] |
|
374 |
|
|
375 |
elif event & (select.POLLNVAL | select.POLLHUP | |
|
376 |
select.POLLERR): |
|
377 | 264 |
poller.unregister(fd) |
378 | 265 |
del fdmap[fd] |
379 | 266 |
|
380 |
script_stderr_lines.flush() |
|
381 |
socat_stderr_lines.flush() |
|
267 |
elif event & (select.POLLNVAL | select.POLLHUP | |
|
268 |
select.POLLERR): |
|
269 |
poller.unregister(fd) |
|
270 |
del fdmap[fd] |
|
271 |
|
|
272 |
child_io_proc.FlushAll() |
|
382 | 273 |
|
383 |
# If there was a timeout calculator, we were waiting for the child to |
|
384 |
# finish, e.g. due to a signal |
|
385 |
return not bool(exit_timeout) |
|
386 |
finally: |
|
387 |
socat_stderr_lines.close() |
|
274 |
# If there was a timeout calculator, we were waiting for the child to |
|
275 |
# finish, e.g. due to a signal |
|
276 |
return not bool(exit_timeout) |
|
388 | 277 |
finally: |
389 |
script_stderr_lines.close()
|
|
278 |
child_io_proc.CloseAll()
|
|
390 | 279 |
|
391 | 280 |
|
392 | 281 |
def ParseOptions(): |
Also available in: Unified diff