diff --git a/ochopod/bindings/ec2/kubernetes.py b/ochopod/bindings/ec2/kubernetes.py index 48de1ec..60b68b4 100644 --- a/ochopod/bindings/ec2/kubernetes.py +++ b/ochopod/bindings/ec2/kubernetes.py @@ -82,7 +82,7 @@ def boot(self, lifecycle, model=Reactive, local=0): # - grab our environment variables # - isolate the ones prefixed with ochopod_ # - logger.debug('environment ->\n%s' % '\n'.join(['\t%s -> %s' % (k, v) for k, v in env.items()])) + logger.debug('environment ->\n%s', '\n'.join(['\t%s -> %s' % (k, v) for k, v in env.items()])) hints = {k[8:]: v for k, v in env.items() if k.startswith('ochopod_')} if local or hints['local'] == 'true': @@ -193,7 +193,7 @@ def _spin(): # the coordinator (especially the pod index which is derived from zookeeper) # latch = ThreadingFuture() - logger.info('starting %s.%s (kubernetes/ec2) @ %s' % (hints['namespace'], hints['cluster'], hints['node'])) + logger.info('starting %s.%s (kubernetes/ec2) @ %s', hints['namespace'], hints['cluster'], hints['node']) breadcrumbs = deepcopy(hints) env.update({'ochopod': json.dumps(hints)}) executor = lifecycle.start(env, latch, hints) @@ -264,12 +264,12 @@ def _control(task, timeout='60'): try: ts = time.time() - logger.debug('http in -> /control/%s' % task) + logger.debug('http in -> /control/%s', task) latch = ThreadingFuture() executor.tell({'request': task, 'latch': latch, 'data': request.data}) js, code = latch.get(timeout=int(timeout)) ms = time.time() - ts - logger.debug('http out -> HTTP %s (%d ms)' % (code, ms)) + logger.debug('http out -> HTTP %s (%d ms)', code, ms) return json.dumps(js), code except Timeout: @@ -341,6 +341,6 @@ def run(self): except Exception as failure: - logger.fatal('unexpected condition -> %s' % diagnostic(failure)) + logger.fatal('unexpected condition -> %s', diagnostic(failure)) - exit(1) \ No newline at end of file + exit(1) diff --git a/ochopod/bindings/ec2/marathon.py b/ochopod/bindings/ec2/marathon.py index c57eba6..a8a473a 100644 --- a/ochopod/bindings/ec2/marathon.py +++ b/ochopod/bindings/ec2/marathon.py @@ -85,7 +85,7 @@ def boot(self, lifecycle, model=Reactive, local=0): # - extract the mesos PORT_* bindings and construct a small remapping dict # ports = {} - logger.debug('environment ->\n%s' % '\n'.join(['\t%s -> %s' % (k, v) for k, v in env.items()])) + logger.debug('environment ->\n%s', '\n'.join(['\t%s -> %s' % (k, v) for k, v in env.items()])) for key, val in env.items(): if key.startswith('PORT_'): ports[key[5:]] = int(val) @@ -193,7 +193,7 @@ def _dcos_deployment(): # the coordinator (especially the pod index which is derived from zookeeper) # latch = ThreadingFuture() - logger.info('starting %s.%s (marathon/ec2) @ %s' % (hints['namespace'], hints['cluster'], hints['node'])) + logger.info('starting %s.%s (marathon/ec2) @ %s', hints['namespace'], hints['cluster'], hints['node']) breadcrumbs = deepcopy(hints) hints['metrics'] = {} env.update({'ochopod': json.dumps(hints)}) @@ -266,12 +266,12 @@ def _control(task, timeout='60'): try: ts = time.time() - logger.debug('http in -> /control/%s' % task) + logger.debug('http in -> /control/%s', task) latch = ThreadingFuture() executor.tell({'request': task, 'latch': latch, 'data': request.data}) js, code = latch.get(timeout=int(timeout)) ms = time.time() - ts - logger.debug('http out -> HTTP %s (%d ms)' % (code, ms)) + logger.debug('http out -> HTTP %s (%d ms)', code, ms) return json.dumps(js), code except Timeout: @@ -343,4 +343,4 @@ def run(self): except Exception as failure: - logger.fatal('unexpected condition -> %s' % diagnostic(failure)) \ No newline at end of file + logger.fatal('unexpected condition -> %s', diagnostic(failure)) diff --git a/ochopod/core/core.py b/ochopod/core/core.py index 3147595..7b5f24f 100644 --- a/ochopod/core/core.py +++ b/ochopod/core/core.py @@ -84,14 +84,14 @@ def reset(self, data): self.connected = 0 self.force_reset = 0 self.hints['state'] = 'follower' - logger.warning('%s : actor reset (%s)' % (self.path, data.cause)) + logger.warning('%s : actor reset (%s)', self.path, data.cause) if hasattr(data, 'zk'): # # - gracefully shut our client down # data.zk.stop() - logger.debug('%s : zk client stopped, releasing resources' % self.path) + logger.debug('%s : zk client stopped, releasing resources', self.path) data.zk.close() if self.terminate: @@ -105,7 +105,7 @@ def initial(self, data): # - setup a new kazoo client # cnx_string = ','.join(self.brokers) - logger.debug('%s : connecting @ %s' % (self.path, cnx_string)) + logger.debug('%s : connecting @ %s', self.path, cnx_string) data.zk = KazooClient(hosts=cnx_string, timeout=5.0, read_only=0, randomize_hosts=1) data.zk.add_listener(self.feedback) data.zk.start() @@ -155,10 +155,10 @@ def wait_for_cnx(self, data): # and /snapshot has not been phased out yet .. this is not an issue, simply pause a bit # to re-attempt later # - logger.debug('%s : pod %s is already there (probably a zk reconnect)' % (self.path, self.id)) + logger.debug('%s : pod %s is already there (probably a zk reconnect)', self.path, self.id) return 'wait_for_cnx', data, 5.0 * SAMPLING - logger.debug('%s : registered as %s (#%d)' % (self.path, self.id, self.seq)) + logger.debug('%s : registered as %s (#%d)', self.path, self.id, self.seq) data.connected_at = time.time() return 'spin', data, 0 @@ -179,9 +179,9 @@ def specialized(self, msg): # state = msg['state'] current = 'connected' if self.connected else 'disconnected' - logger.debug('%s : zk state change -> "%s" (%s)' % (self.path, str(state), current)) + logger.debug('%s : zk state change -> "%s" (%s)', self.path, str(state), current) if self.connected and state != KazooState.CONNECTED: - logger.warning('%s : lost connection (%s) / forcing a reset' % (self.path, str(state))) + logger.warning('%s : lost connection (%s) / forcing a reset', self.path, str(state)) self.force_reset = 1 self.connected = 0 @@ -278,7 +278,7 @@ def start_controller(self, data): # - start the controller actor # data.latch = ThreadingFuture() - logger.debug('%s : lock acquired @ %s, now leading' % (self.path, self.prefix)) + logger.debug('%s : lock acquired @ %s, now leading', self.path, self.prefix) data.controller = self.model.start(data.zk, self.id, self.hints, self.scope, self.tag, self.port, data.latch) return 'lock', data, 0 @@ -304,4 +304,4 @@ def lock(self, data): except Timeout: pass - return 'lock', data, 0 \ No newline at end of file + return 'lock', data, 0 diff --git a/ochopod/core/fsm.py b/ochopod/core/fsm.py index 707499b..0f5f40d 100644 --- a/ochopod/core/fsm.py +++ b/ochopod/core/fsm.py @@ -225,7 +225,7 @@ def reset(self, data): # - pass the exception that caused the reset back to the latch or re-package it as an Aborted # and seed its log using the failure diagnostic otherwise # - logger.debug('%s : reset (%s)' % (self.path, data.cause)) + logger.debug('%s : reset (%s)', self.path, data.cause) self.exitcode(data.cause if isinstance(data.cause, Aborted) else Aborted(data.diagnostic)) def initial(self, data): @@ -296,7 +296,7 @@ def on_receive(self, msg): return self.specialized(msg) except Exception as failure: - logger.debug('%s : exception trapped while handling specialized messages (%s)' % (self.path, str(failure))) + logger.debug('%s : exception trapped while handling specialized messages (%s)', self.path, str(failure)) pass else: @@ -364,7 +364,7 @@ def on_receive(self, msg): # if cmd['state'] == 'reset': - logger.debug('%s : exception trapped while resetting (%s)' % (self.path, str(failure))) + logger.debug('%s : exception trapped while resetting (%s)', self.path, str(failure)) _kill(self.actor_ref) self.dying = 1 @@ -374,7 +374,7 @@ def on_receive(self, msg): data.cause = failure data.previous = cmd['state'] data.diagnostic = diagnostic(failure) - logger.debug('%s : exception trapped -> (%s)' % (self.path, data.diagnostic)) + logger.debug('%s : exception trapped -> (%s)', self.path, data.diagnostic) self.actor_ref.tell({'fsm': {'state': 'reset', 'data': data}}) diff --git a/ochopod/models/piped.py b/ochopod/models/piped.py index 3bcb7e4..edaaf88 100644 --- a/ochopod/models/piped.py +++ b/ochopod/models/piped.py @@ -132,7 +132,7 @@ def reset(self, data): # - this happens when we need to first terminate the process # try: - logger.info('%s : tearing down process %s' % (self.path, data.sub.pid)) + logger.info('%s : tearing down process %s', self.path, data.sub.pid) self.hints['process'] = 'terminating' self.tear_down(data.sub) @@ -170,7 +170,7 @@ def wait_for_termination(self, data): # - if the soft switch is on bypass the SIGKILL completely # - this is a special case to handle peculiar scenarios # - logger.info('%s: bypassing the forced termination (leaking pid %s)...' % (self.path, data.sub.pid)) + logger.info('%s: bypassing the forced termination (leaking pid %s)...', self.path, data.sub.pid) else: @@ -178,7 +178,7 @@ def wait_for_termination(self, data): # - the process is stuck, force a SIGKILL # - silently trap any failure # - logger.info('%s : pid %s not terminating, killing it' % (self.path, data.sub.pid)) + logger.info('%s : pid %s not terminating, killing it', self.path, data.sub.pid) try: data.sub.kill() @@ -186,7 +186,7 @@ def wait_for_termination(self, data): pass else: - logger.debug('%s : pid %s terminated in %d seconds' % (self.path, data.sub.pid, int(elapsed))) + logger.debug('%s : pid %s terminated in %d seconds', self.path, data.sub.pid, int(elapsed)) data.sub = None self.hints['process'] = 'stopped' @@ -255,11 +255,11 @@ def spin(self, data): # data.checks -= 1 data.failed = 0 - logger.warning('%s : sanity check (%d/%d) failed -> %s' % - (self.path, self.checks - data.checks, self.checks, diagnostic(failure))) + logger.warning('%s : sanity check (%d/%d) failed -> %s', + self.path, self.checks - data.checks, self.checks, diagnostic(failure)) if not data.checks: - logger.warning('%s : turning pod off' % self.path) + logger.warning('%s : turning pod off', self.path) data.checks = self.checks self._request(['off']) @@ -272,7 +272,7 @@ def spin(self, data): # - a successful exit code (0) will automatically force a shutdown # - this is a convenient way for pods go down automatically once their task is done # - logger.error('%s : pid %s exited, shutting down' % (self.path, data.sub.pid)) + logger.error('%s : pid %s exited, shutting down', self.path, data.sub.pid) self._request(['kill']) else: @@ -283,7 +283,7 @@ def spin(self, data): # - restart it gracefully # data.failed += 1 - logger.error('%s : pid %s died (code %d), re-running' % (self.path, data.sub.pid, code)) + logger.error('%s : pid %s died (code %d), re-running', self.path, data.sub.pid, code) self._request(['off', 'on']) else: @@ -313,7 +313,7 @@ def on(self, data): # - this is the code-path used for instance up a leader request when strict is false # reply = {}, 200 - logger.debug('%s : skipping /control/on request' % self.path) + logger.debug('%s : skipping /control/on request', self.path) data.latch.set(reply) else: @@ -329,7 +329,7 @@ def on(self, data): # - if this is the 1st time the pod is running invoke the initialize() callback # - this is typically used to run once-only stuff such as attaching storage volumes, etc. # - logger.info('%s : initializing pod' % self.path) + logger.info('%s : initializing pod', self.path) self.initialize() self.initialized = 1 @@ -342,7 +342,7 @@ def on(self, data): # - make sure the optional overrides set by configure() are strings # cluster = _Cluster(data.js) - logger.info('%s : configuring pod %d/%d' % (self.path, 1 + cluster.index, cluster.size)) + logger.info('%s : configuring pod %d/%d' , self.path, 1 + cluster.index, cluster.size) data.command, overrides = self.configure(cluster) data.env = {key: str(value) for key, value in overrides.items()} self.last = data.js @@ -390,7 +390,7 @@ def _pipe(process): if line == '' and code is not None: break - logger.info('pid %s : %s' % (process.pid, line)) + logger.info('pid %s : %s', process.pid, line) out = Thread(target=_pipe, args=(data.sub,)) out.daemon = True @@ -409,10 +409,10 @@ def _pipe(process): data.pids += 1 self.hints['process'] = 'running' - logger.info('%s : popen() #%d -> started <%s> as pid %s' % (self.path, data.pids, data.command, data.sub.pid)) + logger.info('%s : popen() #%d -> started <%s> as pid %s', self.path, data.pids, data.command, data.sub.pid) if data.env: unrolled = '\n'.join(['\t%s -> %s' % (k, v) for k, v in data.env.items()]) - logger.debug('%s : extra environment for pid %s ->\n%s' % (self.path, data.sub.pid, unrolled)) + logger.debug('%s : extra environment for pid %s ->\n%s', self.path, data.sub.pid, unrolled) reply = {}, 200 data.latch.set(reply) @@ -424,7 +424,7 @@ def _pipe(process): # - the pod will shutdown automatically as well # reply = {}, 406 - logger.warning('%s : failed to configure -> %s, shutting down' % (self.path, diagnostic(failure))) + logger.warning('%s : failed to configure -> %s, shutting down', self.path, diagnostic(failure)) self._request(['kill']) data.latch.set(reply) @@ -449,7 +449,7 @@ def check(self, data): # - any failure trapped during the configuration -> HTTP 406 # reply = {}, 406 - logger.warning('%s : failed to run the pre-check -> %s' % (self.path, diagnostic(failure))) + logger.warning('%s : failed to run the pre-check -> %s', self.path, diagnostic(failure)) data.latch.set(reply) self.commands.popleft() @@ -482,7 +482,7 @@ def kill(self, data): # # - invoke the optional finalize() callback # - logger.info('%s : finalizing pod' % self.path) + logger.info('%s : finalizing pod', self.path) self.finalize() except Exception as failure: @@ -491,7 +491,7 @@ def kill(self, data): # - log something if for some reason finalize() failed as we can't really recover # - don't bother responding with a 406 # - logger.warning('%s : failed to finalize -> %s' % (self.path, diagnostic(failure))) + logger.warning('%s : failed to finalize -> %s', self.path, diagnostic(failure)) # # - in any case request a termination and tag the pod as 'dead' @@ -506,7 +506,7 @@ def kill(self, data): def signal(self, data): try: - logger.debug('%s : user signal received' % self.path) + logger.debug('%s : user signal received', self.path) js = self.signaled(data.js, process=data.sub) reply = js if js else {}, 200 @@ -516,7 +516,7 @@ def signal(self, data): # - abort on a 500 upon any failure # reply = {}, 500 - logger.warning('%s : failed to signal -> %s' % (self.path, diagnostic(failure))) + logger.warning('%s : failed to signal -> %s', self.path, diagnostic(failure)) data.latch.set(reply) self.commands.popleft() @@ -527,7 +527,7 @@ def ok(self, data): try: assert data.js, 'control/ok received out of context (leader bug ?)' - logger.debug('%s : cluster has been formed, invoking configured()' % self.path) + logger.debug('%s : cluster has been formed, invoking configured()', self.path) cluster = _Cluster(data.js) self.configured(cluster) reply = {}, 200 @@ -538,7 +538,7 @@ def ok(self, data): # - abort on a 500 upon any failure # reply = {}, 500 - logger.warning('%s : failed to signal -> %s' % (self.path, diagnostic(failure))) + logger.warning('%s : failed to signal -> %s', self.path, diagnostic(failure)) data.latch.set(reply) self.commands.popleft() diff --git a/ochopod/models/reactive.py b/ochopod/models/reactive.py index f0b35ed..b8e1eed 100644 --- a/ochopod/models/reactive.py +++ b/ochopod/models/reactive.py @@ -60,10 +60,10 @@ def run(self): # - any failure to reach the pod or timeout will be silently trapped (but the thread will # join() with an empty code) # - logger.debug('control -> %s' % self.url) + logger.debug('control -> %s', self.url) reply = requests.post(self.url, data=json.dumps(self.js), timeout=self.timeout) self.code = reply.status_code - logger.debug('control <- %s (HTTP %d)' % (self.url, self.code)) + logger.debug('control <- %s (HTTP %d)', self.url, self.code) except Timeout: @@ -71,7 +71,7 @@ def run(self): # - just log something # - the thread will simply return a None for return code # - logger.debug('control <- %s (timeout)' % self.url) + logger.debug('control <- %s (timeout)', self.url) def join(self, timeout=None): @@ -141,8 +141,8 @@ def initial(self, data): # - start spinning (the watcher updates will be processed in there) # self.watchers += [Remote.start(self.actor_ref, self.zk, self.scope, tag) for tag in self.depends_on] - logger.debug('%s : watching %d dependencies' % (self.path, len(self.depends_on))) - logger.info('%s : leading for cluster %s.%s' % (self.path, self.scope, self.tag)) + logger.debug('%s : watching %d dependencies', self.path, len(self.depends_on)) + logger.info('%s : leading for cluster %s.%s', self.path, self.scope, self.tag) return 'spin', data, 0 def spin(self, data): @@ -177,8 +177,8 @@ def spin(self, data): # - this will start the countdown to configuration (which can be aborted if we fall back # on the same hash again, typically after a transient zookeeper connection loss) # - logger.info('%s : hash changed, configuration in %2.1f seconds' % (self.path, self.damper)) - logger.debug('%s : hash -> %s' % (self.path, latest)) + logger.info('%s : hash changed, configuration in %2.1f seconds', self.path, self.damper) + logger.debug('%s : hash -> %s', self.path, latest) data.next = now + self.damper data.dirty = 1 @@ -201,7 +201,7 @@ def spin(self, data): data.last = js data.last['key'] = str(self.id) self.zk.set('%s/%s.%s/snapshot' % (ROOT, self.scope, self.tag), json.dumps(pods)) - logger.debug('%s : pod update with no hash impact (did we just reconnect to zk ?)' % self.path) + logger.debug('%s : pod update with no hash impact (did we just reconnect to zk ?)', self.path) if not data.dirty: @@ -235,11 +235,11 @@ def spin(self, data): # - something blew up in probe(), set the status accordingly # self.hints['status'] = '* probe() failed (check the code)' - logger.warning('%s : probe() failed -> %s' % (self.path, diagnostic(failure))) + logger.warning('%s : probe() failed -> %s', self.path, diagnostic(failure)) data.next_probe = now + self.probe_every if self.hints['status']: - logger.debug('%s : probe() -> "%s"' % (self.path, self.hints['status'])) + logger.debug('%s : probe() -> "%s"', self.path, self.hints['status']) else: @@ -256,7 +256,7 @@ def spin(self, data): # - print some cool countdown # else: - logger.debug('%s : configuration in %2.1f seconds' % (self.path, remaining)) + logger.debug('%s : configuration in %2.1f seconds', self.path, remaining) return 'spin', data, SAMPLING @@ -282,7 +282,7 @@ def config(self, data): # - this will allow us to send requests directly without worrying about remapping the control port # - pay attention to order the pod list to guarantee consistent sequencing # - logger.info('%s : configuring (%d pods, i/o port %d)' % (self.path, len(pods), self.port)) + logger.info('%s : configuring (%d pods, i/o port %d)', self.path, len(pods), self.port) ordered = sorted(pods.items()) local = str(self.port) urls = \ @@ -328,7 +328,7 @@ def _start_join(): thread.start() return thread.join() - logger.debug('%s : -> /control/%s (%d pods, sequential)' % (self.path, task, len(pods))) + logger.debug('%s : -> /control/%s (%d pods, sequential)', self.path, task, len(pods)) return [_start_join() for thread in threads] else: @@ -340,7 +340,7 @@ def _start_join(): for thread in threads: thread.start() - logger.debug('%s : -> /control/%s (%d pods)' % (self.path, task, len(pods))) + logger.debug('%s : -> /control/%s (%d pods)', self.path, task, len(pods)) return [thread.join() for thread in threads] # @@ -351,7 +351,7 @@ def _start_join(): replies = _control('check') dead = [key for key, code in replies if code == 410] if dead: - logger.warning('%s : dropping %d dead pods' % (self.path, len(dead))) + logger.warning('%s : dropping %d dead pods', self.path, len(dead)) for key in dead: del pods[key] del urls[key] @@ -371,8 +371,8 @@ def _start_join(): # - note we include an extra 'index' integer to the payload passed to the pod (this index # can be used to tag the pod in logs or perform specific setup procedures) # - logger.debug('%s : json payload ->\n%s' % (self.path, json.dumps(js, indent=4, separators=(',', ': ')))) - logger.info('%s : asking %d pods to configure' % (self.path, len(pods))) + logger.debug('%s : json payload ->\n%s', self.path, json.dumps(js, indent=4, separators=(',', ': '))) + logger.info('%s : asking %d pods to configure', self.path, len(pods)) replies = _control('on') assert all(code == 200 for _, code in replies), '1+ pods failing to configure or unreachable' @@ -390,8 +390,8 @@ def _start_join(): local = json.dumps(pods) self.zk.set('%s/%s.%s/snapshot' % (ROOT, self.scope, self.tag), local) self.zk.set('%s/%s.%s/hash' % (ROOT, self.scope, self.tag), latest) - logger.debug('%s : new hash -> %s' % (self.path, latest)) - logger.info('%s : configuration complete (%d pods alive)' % (self.path, len(pods))) + logger.debug('%s : new hash -> %s', self.path, latest) + logger.info('%s : configuration complete (%d pods alive)', self.path, len(pods)) # # - all cool, we can now unset our trigger @@ -409,7 +409,7 @@ def _start_join(): # - any assert aborts the procedure # - leave the trigger on and reset the timestamp to re-attempt # - logger.warn('%s : configuration failed -> %s' % (self.path, diagnostic(failure))) + logger.warn('%s : configuration failed -> %s', self.path, diagnostic(failure)) self.hints['state'] = 'leader (configuration pending)' data.next = time.time() + self.damper data.last = None @@ -437,7 +437,7 @@ def specialized(self, msg): # - one of our watcher actors failed to read from zk # - force a termination to re-attempt a connection to zk (and re-register the pod) # - logger.debug('%s : watcher failure, terminating' % self.path) + logger.debug('%s : watcher failure, terminating', self.path) self.terminate = 1 else: @@ -451,4 +451,4 @@ def _md5(self): # hashed = hashlib.md5() hashed.update(json.dumps(self.snapshots)) - return ':'.join(c.encode('hex') for c in hashed.digest()) \ No newline at end of file + return ':'.join(c.encode('hex') for c in hashed.digest()) diff --git a/ochopod/watchers/remote.py b/ochopod/watchers/remote.py index 1f11df2..da4f017 100644 --- a/ochopod/watchers/remote.py +++ b/ochopod/watchers/remote.py @@ -100,7 +100,7 @@ def spin(self, data): # if pods != data.latest: data.latest = pods - logger.debug('%s : change detected in dependency' % self.path) + logger.debug('%s : change detected in dependency', self.path) self.model.tell( { 'request': 'snapshot update',