Miscellaneous » zfs-replicate
Clone URL:  
Pushed to one repository · View In Graph Contained in tip

Add syslog support and integrate with console output

Changeset c9e9640173e6

Parent b5fca214862b

by Profile picture of User 912Tim Stewart <tim@fogcreek.com>

Changes to one file · Browse files at c9e9640173e6 Showing diff from parent b5fca214862b Diff from another changeset...

Change 1 of 14 Show Entire File zsync Stacked
 
4
5
6
 
7
8
9
 
175
176
177
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
178
179
180
 
198
199
200
201
202
203
204
205
206
207
 
 
 
 
 
208
209
210
 
276
277
278
279
280
281
282
283
284
 
 
 
 
285
286
287
 
325
326
327
328
 
329
330
331
 
332
333
334
 
337
338
339
340
341
 
 
342
343
344
 
358
359
360
361
362
 
 
363
364
365
 
366
367
368
 
383
384
385
386
387
388
389
390
 
 
 
 
391
392
393
 
395
396
397
398
399
400
 
 
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
 
 
 
 
 
 
 
 
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
440
441
442
443
444
 
445
446
447
448
449
 
 
450
451
452
453
454
 
455
456
457
458
459
460
461
462
 
 
463
464
465
 
480
481
482
483
484
485
486
 
 
487
488
 
 
489
490
491
492
493
494
 
549
550
551
 
 
 
 
552
553
554
 
556
557
558
559
 
560
561
562
 
564
565
566
567
568
 
569
570
571
 
573
574
575
576
 
577
578
579
580
581
 
582
583
584
 
4
5
6
7
8
9
10
 
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
 
214
215
216
 
 
 
 
 
 
 
217
218
219
220
221
222
223
224
 
290
291
292
 
 
 
 
 
 
293
294
295
296
297
298
299
 
337
338
339
 
340
341
342
 
343
344
345
346
 
349
350
351
 
 
352
353
354
355
356
 
370
371
372
 
 
373
374
375
376
 
377
378
379
380
 
395
396
397
 
 
 
 
 
398
399
400
401
402
403
404
 
406
407
408
 
 
 
409
410
411
412
413
414
415
 
 
 
 
 
 
 
 
 
 
416
417
418
419
420
421
422
423
424
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
 
 
450
 
451
452
453
 
 
 
454
455
456
457
 
 
 
458
459
460
461
462
 
 
 
 
463
464
465
466
467
 
482
483
484
 
 
 
 
485
486
487
488
489
490
491
492
 
493
494
495
 
550
551
552
553
554
555
556
557
558
559
 
561
562
563
 
564
565
566
567
 
569
570
571
 
 
572
573
574
575
 
577
578
579
 
580
581
582
583
584
 
585
586
587
588
@@ -4,6 +4,7 @@
   import os  import sys +import syslog  import shlex  import subprocess  import signal @@ -175,6 +176,21 @@
  os.unlink(lockfile)     +def log(msg, log=True, stdout=False, stderr=False): + for line in msg.split('\n'): + if stdout: + print(line) + sys.stdout.flush() + if stderr: + print('ERROR: %s' % line, file=sys.stderr) + sys.stderr.flush() + if log: + if stderr: + syslog.syslog('ERROR: %s' % line) + else: + syslog.syslog('INFO: %s' % line) + +  def split_dest(dest):   m = re.match('^([^:]+):([^:]+)$', dest)   if not m: @@ -198,13 +214,11 @@
  send_list = shlex.split(send_cmd)   recv_list = shlex.split(recv_cmd)   - if verbose: - if dryrun: - print('[DRY RUN] Not running command: %s | %s' % - (send_cmd, recv_cmd)) - else: - print('Running command: %s | %s' % (send_cmd, recv_cmd)) - sys.stdout.flush() + if dryrun: + log('[DRY RUN] Not running command: %s | %s' % + (send_cmd, recv_cmd), stdout=True) + else: + log('Running command: %s | %s' % (send_cmd, recv_cmd), stdout=verbose)     if not dryrun:   send_p = subprocess.Popen(send_list, @@ -276,12 +290,10 @@
  cmd = 'ssh %s zfs destroy %s' % (dst_host, dset.name)   cmd_list = shlex.split(cmd)   - if verbose: - if dryrun: - print('[DRY RUN] Not running command: %s' % (cmd)) - else: - print('Running command: %s' % (cmd)) - sys.stdout.flush() + if dryrun: + log('[DRY RUN] Not running command: %s' % (cmd), stdout=True) + else: + log('Running command: %s' % (cmd), stdout=verbose)     if not dryrun:   p = subprocess.Popen(cmd_list, @@ -325,10 +337,10 @@
  try:   fs_dset = Dataset(fs)   except NoSuchDatasetError: - print('ERROR: No such dataset: %s' % (fs), file=sys.stderr) + log('No such local dataset: %s' % (fs), stderr=True)   sys.exit(1)   if len(fs_dset.snapshots) == 0: - print('ERROR: No snapshots for dataset: %s' % (fs), file=sys.stderr) + log('No snapshots for local dataset: %s' % (fs), stderr=True)   sys.exit(1)     local_snaps = fs_dset.snapshots @@ -337,8 +349,8 @@
  try:   end_snap = Dataset('%s@%s' % (fs, options.end))   except NoSuchDatasetError: - print('ERROR: No such dataset: %s@%s' % (fs, options.end), - file=sys.stderr) + log('No such remote dataset: %s@%s' % (fs, options.end), + stderr=True)   sys.exit(1)   local_text = '(specified): '   else: @@ -358,11 +370,11 @@
  raise NoSuchDatasetError   Dataset(remfs[:rslash], 'ssh %s' % (remhost))   except NoSuchDatasetError: - print('ERROR: Remote dataset or parent does not exist: %s' - % (remfs), file=sys.stderr) + log('Remote dataset or parent does not exist: %s' % (remfs), + stderr=True)   sys.exit(1)   except NonZeroExitStatus, e: - print('ERROR: Error running ZFS command: %s' % (e), file=sys.stderr) + log('Error running ZFS command: %s' % (e), stderr=True)   sys.exit(1)     # Find the newest remote snapshot that also exists in the local @@ -383,11 +395,10 @@
  rem_snaps_todel.append(rsnap)     if not begin_snap: - print(textwrap.fill(textwrap.dedent('''\ - ERROR: No common snapshots between local and remote - datasets. You will need to perform a full replication. - Please destroy the remote dataset to begin.'''), 78), - file=sys.stderr) + log(textwrap.fill(textwrap.dedent('''\ + No common snapshots between local and remote datasets. + You will need to perform a full replication. Please + destroy the remote dataset to begin.'''), 70), stderr=True)   sys.exit(1)   rem_text = begin_snap.name   repl_text = 'Incremental update since last replication' @@ -395,71 +406,62 @@
  # Are snapshots the same on both sides?   if begin_snap and \   end_snap.name.split('@')[1] == begin_snap.name.split('@')[1]: - if options.verbose and not options.cron: - print('Remote snapshot is up-to-date, no work to do') - sys.stdout.flush() + log('Remote snapshot %s is up-to-date, no work to do' % + end_snap.name, stdout=(not options.cron))   sys.exit(0)     try:   with zfs_recv_lockfile(remhost, remfs):   # Print out validated parameters - if options.verbose: - print(textwrap.dedent('''\ - Replication parameters validated - - Local snapshot %s %s - Remote dataset, host: %s on %s - Replication type: %s - Remote starting dataset: %s - ''' % (local_text, end_snap.name, remfs, remhost, - repl_text, rem_text))) + log(textwrap.dedent('''\ + === Replication parameters validated === + Local snapshot %s %s + Remote dataset, host: %s on %s + Replication type: %s + Remote starting dataset: %s\ + ''' % (local_text, end_snap.name, remfs, remhost, + repl_text, rem_text)), stdout=options.verbose)   - # Snapshot analysis - if begin_snap: - print(textwrap.dedent("""\ - Snapshots exist on source and dest, showing analysis... - === Snapshot Analysis === - `-->' indicates starting snapshot on src and dest - `DEL' indicates remote snapshots to be destroyed - Local snapshot candidates (newest first):""")) - for snap in local_snaps: - if snap.name.split('@')[1] == begin_snap.name.split('@')[1]: - print('--> %s' % (snap)) - else: - print(' %s' % (snap)) - print() - print('Remote snapshot candidates (newest first)') - for snap in rem_snaps: - if snap.name.split('@')[1] == begin_snap.name.split('@')[1]: - print('--> %s' % (snap)) - elif snap in rem_snaps_todel: - print('DEL %s' % (snap)) - else: - print(' %s' % (snap)) - print() + # Snapshot analysis + if begin_snap: + log(textwrap.dedent("""\ + === Incremental Snapshot Analysis === + `-->' indicates starting snapshot on src and dest + `DEL' indicates remote snapshots to be destroyed + Local snapshot candidates (newest first):"""), + stdout=options.verbose) + for snap in local_snaps: + if snap.name.split('@')[1] == begin_snap.name.split('@')[1]: + log('--> %s' % (snap), stdout=options.verbose) + break + else: + log(' %s' % (snap), stdout=options.verbose) + log('Remote snapshot candidates (newest first)', + stdout=options.verbose) + for snap in rem_snaps: + if snap.name.split('@')[1] == begin_snap.name.split('@')[1]: + log('--> %s' % (snap), stdout=options.verbose) + break + elif snap in rem_snaps_todel: + log('DEL %s' % (snap), stdout=options.verbose) + else: + log(' %s' % (snap), stdout=options.verbose)   - sys.stdout.flush() -   if options.dryrun: - print(textwrap.dedent('''\ + log(textwrap.dedent('''\   ==============================================   DRY RUN - Replication commands will not be run - ============================================== - ''')) - sys.stdout.flush() + ==============================================\ + '''), stdout=options.verbose)     if rem_snaps_todel: - if options.verbose: - print('Removing remote snapshots...') - sys.stdout.flush() + log('Removing remote snapshots...', stdout=options.verbose)   rm_remote_dsets(rem_snaps_todel, remhost, options.verbose,   options.dryrun)     start_time = datetime.now() - if options.verbose: - print('=== Starting replication at %s' - % start_time.strftime('%c')) - sys.stdout.flush() + log('=== Starting replication at %s' + % start_time.strftime('%c'), stdout=options.verbose)     if not begin_snap:   # Perform a staging replication if necessary. This is @@ -480,15 +482,14 @@
  options.verbose, options.dryrun)     end_time = datetime.now() - if options.verbose: - print('=== Replication complete at %s' - % end_time.strftime('%c')) - sys.stdout.flush() + log('=== Replication complete at %s' + % end_time.strftime('%c'), stdout=options.verbose)     except LockfileExists: + log("Lock file exists, receive already in progress", + stderr=(not options.cron))   if options.cron:   sys.exit(0) - print("Lock file exists, receive already in progress", file=sys.stderr)   sys.exit(1)     @@ -549,6 +550,10 @@
  except InvalidDestinationError:   parser.error("Invalid dest specification")   + # Options look good, set up logging + syslog.openlog("zsync", syslog.LOG_PID, syslog.LOG_LOCAL0) + + # Begin replication   done = False   while not done:   try: @@ -556,7 +561,7 @@
  done = True   except SendNoSuchDataset, e:   sys.stderr.write('\n') - print(textwrap.fill(textwrap.dedent("""\ + log(textwrap.fill(textwrap.dedent("""\   WARNING: Source snapshot (%s) disappeared during   replication run. `zfs send -R ...' creates a list of   snapshots to send when the command is started and will @@ -564,8 +569,7 @@
  often with hourly snapshots dropping off then end of the   scheduled snapshot rotation. Replication will be   restarted--you can probably ignore this warning. - """ % (e)), 78), file=sys.stderr) - sys.stderr.write('\n') + """ % (e)), 70), stdout=options.verbose)      def sig_handler(sig, frame): @@ -573,12 +577,12 @@
  # since it will come back to us   signal.signal(sig, signal.SIG_IGN)   os.killpg(os.getpgid(0), sig) - print(textwrap.fill(textwrap.dedent('''\ + log(textwrap.fill(textwrap.dedent('''\   Replication aborted. Snapshots that have already transferred will   remain on the destination host; only the in-progress snapshot will   have to be transferred again. You should be able to restart later   where you left off. - '''), 78), file=sys.stderr) + '''), 70), stderr=True)   sys.exit(1)