diff --git a/hetzner/robot.py b/hetzner/robot.py index 4eeda08..7aa5804 100644 --- a/hetzner/robot.py +++ b/hetzner/robot.py @@ -2,6 +2,7 @@ import ssl import json import socket +import logging from base64 import b64encode from urllib import urlencode @@ -124,14 +125,16 @@ def login(self, user=None, passwd=None, force=False): " page".format(response.status)) data = {'user': self.user, 'password': self.passwd} - response = self.request('/login/check', data, xhr=False) + logging.debug("Logging in to Robot web frontend with user %s.", + self.user) + response = self.request('/login/check', data, xhr=False, log=False) if response.status != 302 or response.getheader('Location') is None: raise WebRobotError("Login to robot web interface failed.") self.logged_in = True - def request(self, path, data=None, xhr=True, method=None): + def request(self, path, data=None, xhr=True, method=None, log=True): """ Send a request to the web interface, using 'data' for urlencoded POST data. If 'data' is None (which it is by default), a GET request is sent @@ -139,6 +142,9 @@ def request(self, path, data=None, xhr=True, method=None): By default this method uses headers for XMLHttpRequests, so if the request should be an ordinary HTTP request, set 'xhr' to False. + + If 'log' is set to False, don't log anything containing data. This is + useful to prevent logging sensible information such as passwords. """ self.connect() @@ -158,15 +164,24 @@ def request(self, path, data=None, xhr=True, method=None): encoded = urlencode(data) headers['Content-Type'] = 'application/x-www-form-urlencoded' + if log: + logging.debug("Sending %s request to Robot web frontend " + "at %s with data %r.", + ("XHR " if xhr else "") + method, path, encoded) self.conn.request(method, path, encoded, headers) try: response = self.conn.getresponse() except ResponseNotReady: + logging.debug("Connection closed by Robot web frontend, retrying.") # Connection closed, so we need to reconnect. # FIXME: Try to avoid endless loops here! self.connect(force=True) - return self.request(path, data=data, xhr=xhr) + return self.request(path, data=data, xhr=xhr, log=log) + + if log: + logging.debug("Got response from web frontend with status %d.", + response.status) self.update_session(response) return response @@ -208,6 +223,8 @@ def request(self, method, path, data=None, allow_empty=False): if data is not None: headers['Content-Type'] = 'application/x-www-form-urlencoded' + logging.debug("Sending %s request to Robot at %s with data %r.", + method, path, data) response = self._request(method, path, data, headers) raw_data = response.read() if len(raw_data) == 0 and not allow_empty: @@ -221,6 +238,8 @@ def request(self, method, path, data=None, allow_empty=False): raise RobotError(msg.format(response.status, repr(raw_data))) else: data = None + logging.debug("Got response from Robot with status %d and data %r.", + response.status, data) if 200 <= response.status < 300: return data diff --git a/hetzner/server.py b/hetzner/server.py index 99c5ff8..dbc3d12 100644 --- a/hetzner/server.py +++ b/hetzner/server.py @@ -6,6 +6,7 @@ import string import subprocess import warnings +import logging from tempfile import mkdtemp from datetime import datetime @@ -380,6 +381,7 @@ def __init__(self, conn, result): self.subnets = SubnetManager(self.conn, self.ip) self.rdns = ReverseDNSManager(self.conn, self.ip) self._admin_account = None + self.logger = logging.getLogger("Server #{0}".format(self.number)) @property def admin(self): @@ -457,17 +459,25 @@ def observed_reboot(self, patience=300, tries=None, manual=False): tries = ['soft', 'hard'] for mode in tries: + self.logger.info("Tring to reboot using the %r method.", mode) self.reboot(mode) - now = time.time() + start_time = time.time() + self.logger.info("Waiting for machine to become available.") while True: - if time.time() > now + patience: + current_time = time.time() + if current_time > start_time + patience: + self.logger.info( + "Machine didn't come up after %d seconds.", + patience + ) break is_up = self.check_ssh() time.sleep(1) if is_up and is_down: + self.logger.info("Machine just became available.") return elif not is_down: is_down = not is_up diff --git a/hetznerctl b/hetznerctl index a8f3f72..df13a34 100755 --- a/hetznerctl +++ b/hetznerctl @@ -3,6 +3,9 @@ import sys import locale import warnings +import logging +logging.basicConfig(format='%(name)s: %(message)s', level=logging.INFO) + from os.path import expanduser from optparse import OptionParser, make_option from ConfigParser import RawConfigParser, Error