Python logging.debug() Examples

def init_logger(self, args):
        level = logging.INFO
        if args.verbose:
            level = logging.VERBOSE
        if args.debug:
            level = logging.DEBUG
        logging.basicConfig(format='%(asctime)s [%(levelname)s] %(message)s',
                            level=level)

        Rthandler = RotatingFileHandler('arbitrage.log', maxBytes=100*1024*1024,backupCount=10)
        Rthandler.setLevel(level)
        formatter = logging.Formatter('%(asctime)-12s [%(levelname)s] %(message)s')  
        Rthandler.setFormatter(formatter)
        logging.getLogger('').addHandler(Rthandler)

        logging.getLogger("requests").setLevel(logging.WARNING)
        logging.getLogger("urllib3").setLevel(logging.WARNING) 

def check(self, first_check=False):
		from pyplanet import __version__ as current_version

		logging.debug('Checking for new versions...')

		async with aiohttp.ClientSession() as session:
			async with session.get(self.url) as resp:
				for release in await resp.json():
					if not release['draft'] and not release['prerelease']:
						self.latest = release['tag_name']
						break

				self.current = current_version
				logging.debug('Version check, your version: {}, online version: {}'.format(self.current, self.latest))

				if first_check and self.update_available:
					logging.info('New version of PyPlanet available, consider updating: {}'.format(self.latest))
					await self.instance.chat(
						'\uf1e6 $FD4$oPy$369Planet$z$s$fff \uf0e7 new version available: v{}. Consider updating!'.format(self.latest)
					) 

def grad_sparsity(self):
    global_state = self._global_state
    if self._iter == 0:
      global_state["sparsity_avg"] = 0.0
    non_zero_cnt = 0.0
    all_entry_cnt = 0.0
    for group in self._optimizer.param_groups:
      for p in group['params']:
        if p.grad is None:
          continue
        grad = p.grad.data
        grad_non_zero = grad.nonzero()
        if grad_non_zero.dim() > 0:
          non_zero_cnt += grad_non_zero.size()[0]
        all_entry_cnt += torch.numel(grad)
    beta = self._beta
    global_state["sparsity_avg"] = beta * global_state["sparsity_avg"] \
      + (1 - beta) * non_zero_cnt / float(all_entry_cnt)
    self._sparsity_avg = \
      global_state["sparsity_avg"] / self.zero_debias_factor()
    
    if self._verbose:
      logging.debug("sparsity %f, sparsity avg %f", non_zero_cnt / float(all_entry_cnt), self._sparsity_avg)

    return 

def grad_sparsity(self):
    global_state = self._global_state
    if self._iter == 0:
      global_state["sparsity_avg"] = 0.0
    non_zero_cnt = 0.0
    all_entry_cnt = 0.0
    for group in self._optimizer.param_groups:
      for p in group['params']:
        if p.grad is None:
          continue
        grad = p.grad.data
        grad_non_zero = grad.nonzero()
        if grad_non_zero.dim() > 0:
          non_zero_cnt += grad_non_zero.size()[0]
        all_entry_cnt += torch.numel(grad)
    beta = self._beta
    global_state["sparsity_avg"] = beta * global_state["sparsity_avg"] \
      + (1 - beta) * non_zero_cnt / float(all_entry_cnt)
    self._sparsity_avg = \
      global_state["sparsity_avg"] / self.zero_debias_factor()
    
    if DEBUG:
      logging.debug("sparsity %f, sparsity avg %f", non_zero_cnt / float(all_entry_cnt), self._sparsity_avg)

    return 

def scan_scrapers():
    """On demand scrapper scanning handler.

    For some reason the scheduler doesn't always work, this endpoint allows for
    instant scanning, assuming it's not already occurring. The function is aborted
    with a ``404`` message to hide the page if the user is not authenticated.

    Scanning can take a long time - 20 to 30 minutes - so it's recommended this
    endpoint be called asynchronously.

    Returns:
       JSON formatted output to identify that scanning has completed or is already
       ongoing.
    """
    log.debug("Entering scan_scrapers.")
    if fe.check_login_id(escape(session['logged_in'])):
        log.debug("User is logged in, attempting to begin scan.")
        if not fe.scrape_shows():
            log.debug("scrape_shows returned false, either the lockfile exists incorrectly or scraping is ongoing.")
            return jsonify({"scan":"failure", "reason":"A scan is ongoing"})
        log.debug("scrape_shows just returned. Returning success.")
        return jsonify({"scan":"success"})
    log.debug("User cannot be authenticated, send 404 to hide page.")
    abort(404) 

def update_locallist(listb, refresh_lock):
    global UPDATE_LOCALSERVERS
    cached = dict()
    durable_duration = 5
    while UPDATE_LOCALSERVERS:
        toremove = []
        for item in cached:
            if cached[item] > durable_duration:
                toremove.append(item)
            cached[item] += 1
        for item in toremove:
            del cached[item]
        info = zeroconf_info()
        for item in info:
            cached[item] = 0
        if not UPDATE_LOCALSERVERS: break
        logging.debug('Acquiring refresh lock for updating list of local servers.')
        refresh_lock.acquire()
        listb.update_items(cached.keys())
        refresh_lock.release()
        logging.debug('Releasing refresh lock after updating locla server list') 

def get_cubic_root(self):
    # We have the equation x^2 D^2 + (1-x)^4 * C / h_min^2
    # where x = sqrt(mu).
    # We substitute x, which is sqrt(mu), with x = y + 1.
    # It gives y^3 + py = q
    # where p = (D^2 h_min^2)/(2*C) and q = -p.
    # We use the Vieta's substution to compute the root.
    # There is only one real solution y (which is in [0, 1] ).
    # http://mathworld.wolfram.com/VietasSubstitution.html
    # eps in the numerator is to prevent momentum = 1 in case of zero gradient
    p = (self._dist_to_opt + eps)**2 * (self._h_min + eps)**2 / 2 / (self._grad_var + eps)
    w3 = (-math.sqrt(p**2 + 4.0 / 27.0 * p**3) - p) / 2.0
    w = math.copysign(1.0, w3) * math.pow(math.fabs(w3), 1.0/3.0)
    y = w - p / 3.0 / (w + eps)
    x = y + 1

    if DEBUG:
      logging.debug("p %f, den %f", p, self._grad_var + eps)
      logging.debug("w3 %f ", w3)
      logging.debug("y %f, den %f", y, w + eps)

    return x 

def run(self):
    global lock, background_activity_count
    try:
      logging.debug('[{0:d}] AsyncDNS - calling getaddrinfo for {1}:{2:d}'.format(self.client_id, self.hostname, self.port))
      addresses = socket.getaddrinfo(self.hostname, self.port)
      logging.info('[{0:d}] Resolving {1}:{2:d} Completed'.format(self.client_id, self.hostname, self.port))
    except:
      addresses = ()
      logging.info('[{0:d}] Resolving {1}:{2:d} Failed'.format(self.client_id, self.hostname, self.port))
    message = {'message': 'resolved', 'connection': self.client_id, 'addresses': addresses, 'localhost': self.is_localhost}
    self.result_pipe.SendMessage(message, False)
    lock.acquire()
    if background_activity_count > 0:
      background_activity_count -= 1
    lock.release()
    # open and close a local socket which will interrupt the long polling loop to process the message
    s = socket.socket()
    s.connect((server.ipaddr, server.port))
    s.close()


########################################################################################################################
#   TCP Client
######################################################################################################################## 

def close(self, *args, **kwargs):
        """
        Engine closed, copy file to DB
        """
        super(DatabaseWrapper, self).close(*args, **kwargs)

        signature_version = self.settings_dict.get("SIGNATURE_VERSION", "s3v4")
        s3 = boto3.resource('s3',
                config=botocore.client.Config(signature_version=signature_version))

        try:
            with open(self.settings_dict['NAME'], 'rb') as f:
                fb = f.read()
                bytesIO = BytesIO()
                bytesIO.write(fb)
                bytesIO.seek(0)

                s3_object = s3.Object(self.settings_dict['BUCKET'], self.settings_dict['REMOTE_NAME'])
                result = s3_object.put('rb', Body=bytesIO)

        except Exception as e:
            print(e)

        logging.debug("Saved to remote DB!") 

def function_definition(self, ast):
        logging.debug("Found function definition %s", ast.name)
        self.add_position_info(ast)
        # Convert the AST to a simple dict, so that the grako buffer
        # associated with the parseinfo can be released when it is no
        # longer needed. Otherwise, the buffer is kept in memory
        # until the reference to this AST is kept in memory. When
        # dealing with many files this can lead to an excessive
        # memory usage.
        ast = dict(ast)
        ast['type'] = 'function'
        # Strip the comment character from the beginning of the line
        docs = ast['documentation']
        if docs is not None:
            stripped = strip_leading_comments(docs)
            ast['documentation'] = stripped
        self.collected_elements.append(ast)
        return ast 

def name_definition(self, ast):
        logging.debug('Found name definition %s', ast.name)
        self.add_position_info(ast)
        # Convert the AST to a simple dict, so that the grako buffer
        # associated with the parseinfo can be released when it is no
        # longer needed. Otherwise, the buffer is kept in memory
        # until the reference to this AST is kept in memory. When
        # dealing with many files this can lead to an excessive
        # memory usage.
        ast = dict(ast)
        ast['type'] = 'name'
        # Strip the comment character from the beginning of the line
        docs = ast['documentation']
        if docs is not None:
            stripped = strip_leading_comments(docs)
            ast['documentation'] = stripped
        self.collected_elements.append(ast)
        return ast 

def stop(self):
        self._log.debug("%s.stop()", self.naming_service_name)
        if self.query_commandAlive() == True:
            for sig, timeout in self.STOP_SIGNALS:
                try:
                    os.kill(self._pid, sig)
                except OSError:
                    self._pid = None
                    return
                if timeout != None:
                    giveup_time = time.time() + timeout
                    while os.waitpid(self._pid, os.WNOHANG) == (0,0):
                        time.sleep(0.1)
                        if time.time() > giveup_time:
                            break
                else:
                    # Wait until there is a response
                    os.waitpid(self._pid, 0)
            self._pid = None 

def query(self, configProperties):
    self._log.debug("BasicUsesDevice.query(%s)", configProperties)
    if configProperties == []:
      rv = []
      for key in self.props.keys():
        val = self.props[key].value
        d = CF.DataType(id=key, value=val)
        rv.append(d)
    else:
      unknownProperties = []
      for prop in configProperties:
        try:
            prop.value = self.props[prop.id].value
        except KeyError:
            unknownProperties.append(prop)

      if len(unknownProperties) > 0:
        raise CF.UnknownProperties(unknownProperties)

      rv = configProperties
    self._log.debug("BasicUsesDevice.query() -> %s", rv)
    return rv 

def _allocateCapacity(self, propname, value):
        """Override this if you want if you don't want magic dispatch"""
        self._log.debug("_allocateCapacity(%s, %s)", propname, value)
        if self._allocationCallbacks.has_key(propname):
            return self._allocationCallbacks[propname]._allocate(value)
        
        modified_propname = ''
        for ch in propname:
            if ch.isalnum():
                modified_propname += ch
            else:
                modified_propname += '_'
        allocate = _getCallback(self, "allocate_%s" % modified_propname)
        if allocate:
            self._log.debug("using callback for _allocateCapacity()", )
            return allocate(value)
        else:
            self._log.debug("no callback for _allocateCapacity()", )
            return False 

def safe_shutdown(self, timeout):
        if self._shutting_down:
            return

        self._shutting_down = True
        logging.debug('Stopping http server.')
        self.stop()

        logging.debug('Will be shutdown within %s seconds ...', timeout)
        io_loop = tornado.ioloop.IOLoop.instance()

        deadline = time.time() + timeout

        def safe_stop_loop():
            now = time.time()
            if now < deadline and io_loop._callbacks:
                io_loop.add_timeout(now + 1, safe_stop_loop)
            else:
                io_loop.stop()
                logging.debug('Http server has been shutdown.')
        safe_stop_loop() 

def __init__(self, servo_group, event, belt_speed, frequency,
                 mqtt_client, master_shadow, args=(), kwargs={}):
        super(BeltControlThread, self).__init__(
            name="belt_control_thread", args=args, kwargs=kwargs
        )
        self.sg = servo_group
        self.rolling = False
        self.cmd_event = event
        self.belt_speed = belt_speed
        self.frequency = frequency
        self.reversed = False
        self.active_state = 'initialized'
        self.last_state = 'initialized'
        self.control_stages = collections.OrderedDict()
        self.control_stages['roll'] = self.roll
        self.mqttc = mqtt_client
        self.master_shadow = master_shadow

        self.master_shadow.shadowRegisterDeltaCallback(self.shadow_mgr)
        log.debug("[bct.__init__] shadowRegisterDeltaCallback()") 

def shadow_mgr(self, payload, status, token):
        if payload == "REQUEST TIME OUT":
            log.error(
                "[bct.shadow_mgr] shadow 'REQUEST TIME OUT' tk:{0}".format(
                    token))
            return

        shady_values = json.loads(payload)
        log.debug("[bct.shadow_mgr] shadow payload:{0}".format(
            json.dumps(shady_values, sort_keys=True)))

        if 'convey_cmd' in shady_values['state']:
            cmd = shady_values['state']['convey_cmd']
            if cmd in commands:
                self._activate_command(cmd)
            else:
                log.debug("[bct.shadow_mgr] unknown command:{0}".format(cmd))
        if 'convey_reverse' in shady_values['state']:
            reverse = shady_values['state']['convey_reverse']
            log.info("[bct.shadow_mgr] convey_reverse val:{0}".format(reverse))
            self._reverse_roll(reverse) 

def topic_update(client, userdata, message):
    log.debug('[topic_update] received topic:{0} ts:{1}'.format(
        message.topic, dt.datetime.utcnow()))
    topic_cache[message.topic] = message.payload

    msg = json.loads(message.payload)

    if 'data' in msg:
        global last_hz
        global current_hz
        global current_hz_time
        count_telemetry(msg['data'])
        elapsed = dt.datetime.utcnow() - current_hz_time
        if elapsed > second:  # if a second has passed rollover Hz
            with rollover_lock:
                last_hz = current_hz
                current_hz_time = dt.datetime.utcnow()
                current_hz = 0

    history(msg) 

def get_core_definition(self, config):
        """
        Get the Master Group Type's core definition

        :param config: gg_group_setup.GroupConfigFile used with the Group Type
        :return: the core definition used to provision the group
        """
        cfg = config
        definition = [{
            "ThingArn": cfg['core']['thing_arn'],
            "CertificateArn": cfg['core']['cert_arn'],
            "Id": "{0}_00".format(self.type_name),  # arbitrary unique Id string
            "SyncShadow": True
        }]
        logging.debug('[master.get_core_definition] definition:{0}'.format(
            definition)
        )
        return definition 

def get_core_definition(self, config):
        """
        Get the Arm Group Type's core definition

        :param config: gg_group_setup.GroupConfigFile used with the Group Type
        :return: the core definition used to provision the group
        """
        cfg = config
        definition = [{
            "ThingArn": cfg['core']['thing_arn'],
            "CertificateArn": cfg['core']['cert_arn'],
            "Id": "{0}_00".format(self.type_name),
            "SyncShadow": True
        }]
        logging.debug(
            '[arm.get_core_definition] definition:{0}'.format(
                definition)
        )
        return definition 

def startRPC(self, port, eventListenerPort):

    logging.basicConfig(filename='worldpay-within-wrapper.log', level=logging.DEBUG)
    reqOS = ["darwin", "win32", "windows", "linux"]
    reqArch = ["x64", "ia32"]
    cfg = launcher.Config(reqOS, reqArch)
    launcherLocal = launcher.launcher()
    # define log file name for rpc agent, so e.g
    # for "runConsumerOWP.py" it will be: "rpc-wpwithin-runConsumerOWP.log"
    logfilename = os.path.basename(sys.argv[0])
    logfilename = "rpc-wpwithin-" + logfilename.rsplit(".", 1)[0] + ".log"

    args = []
    if eventListenerPort > 0:
        logging.debug(str(os.getcwd()) + "" + "-port " + str(port) + " -logfile " + logfilename + " -loglevel debug,warn,error,fatal,info" + " -callbackport " + str(eventListenerPort))
        args = ['-port', str(port), '-logfile', logfilename, '-loglevel', 'debug,warn,error,fatal,info', '-callbackport', str(eventListenerPort)]
    else:
        logging.debug(str(os.getcwd()) + "" + "-port " + str(port) + " -logfile " + logfilename + " -loglevel debug,warn,error,fatal,info")
        args = ['-port', str(port), '-logfile', logfilename, '-loglevel', 'debug,warn,error,fatal,info']

    process = launcherLocal.launch(cfg, os.getcwd() + "", args)

    return process 

def _send_message(self, message, update_status=True):
        """
        Sends a message to the VMU931 device, with 5ms delay between each character. 
        
        :param message: Message to send to device
        :param update_status: Update sensor status after message send (defaults to True)
        """
        byte_message = message.encode('ascii')

        # bytes must be sent with 1ms+ interval to be recognised by device.
        for c in byte_message:
            bs = bytes([c])
            self.ser.write(bs)
            logging.debug("Sent {}".format(bs))
            time.sleep(0.01)
        time.sleep(0.05)

        if update_status:
            self.request_status()
            time.sleep(0.100) 

def get_org_id(org_name):
    """
    Return the Organisation ID for a given Org Name
    """
    # Check if our organization exists, and extract its ID
    org = get_json(SAT_API + "organizations/" + org_name)
    # If the requested organization is not found, exit
    if org.get('error', None):
        msg = "Organization '%s' does not exist." % org_name
        log_msg(msg, 'ERROR')
        sys.exit(1)
    else:
        # Our organization exists, so let's grab the ID and write some debug
        org_id = org['id']
        msg = "Organisation '" + org_name + "' found with ID " + str(org['id'])
        log_msg(msg, 'DEBUG')

    return org_id 

def log_msg(msg, level):
    """Write message to logfile"""

    # If we are NOT in debug mode, only write non-debug messages to the log
    if level == 'DEBUG':
        if DEBUG:
            logging.debug(msg)
            print BOLD + "DEBUG: " + msg + ENDC
    elif level == 'ERROR':
        logging.error(msg)
        tf.write('ERROR:' + msg + '\n')
        print ERROR + "ERROR: " + msg + ENDC
    elif level == 'WARNING':
        logging.warning(msg)
        tf.write('WARNING:' + msg + '\n')
        print WARNING + "WARNING: " + msg + ENDC
    # Otherwise if we ARE in debug, write everything to the log AND stdout
    else:
        logging.info(msg)
        tf.write(msg + '\n') 

def SendAndAccount(self, binary_data):
        # Keep this check!
        if self._logger.isEnabledFor(logging.DEBUG):
            logging.debug("!! Sending BIN data: {0}".format(binascii.hexlify(binary_data)))

        datalen = len(binary_data)

        if self._is_udp:
            self._swarm.SendData(self.ip_address, self.udp_port, binary_data)
        else:
            # Prevent crashes when TCP connection is already removed, but some sending is still pending
            if self._proto is not None:
                self._proto.send_data(binary_data)
                self._swarm._all_data_tx += datalen
            else:
                return  # No need to increase sent data counter...

        self._total_data_tx += datalen 

def HandleRequest(self, msg_request):
        """Handle incomming REQUEST message"""
        for x in range(msg_request.start_chunk, msg_request.end_chunk + 1):
            # Ignore requests for discarded chunks
            if x <= self._swarm._last_discarded_id:
                continue

            self.set_requested.add(x)
            # TODO: We might want a more intelligent ACK mechanism than this, but this works well for now
            self.set_sent.discard(x)

        if self._logger.isEnabledFor(logging.DEBUG):
            logging.debug("FROM > {0} > REQUEST: {1}".format(self._peer_num, msg_request))

        # Try to send some data
        if self._sending_handle == None:
           self._sending_handle = asyncio.get_event_loop().call_soon(self.SendRequestedChunks) 

def index():
    """Primary index function.

    This function handles searching and the main page. If ``q`` is passed in a query
    string, e.g. ``http://localhost?q=gabriel+dropout``, then a search will be performed.

    If request path is ``search``, e.g. ``http://localhost/search``, then the navigation
    menu will not be rendered.

    Should there be no shows returned from the backend, ``front_end.do_first_time_setup``
    will be called to scrape shows from the source.

    Returns:
        A rendered template, either ``first_time.html`` for the first run or ``default.html`` otherwise.
    """
    log.debug("Entering index, attempting to get shows.")
    watching, airing, specials, movies = fe.get_shows_for_display(request.args.get('q',None))
    standalone = True if request.path.strip('/') == 'search' else False
    logged_in = fe.check_login_id(escape(session['logged_in'])) if 'logged_in' in session else False
    if not watching and not airing and not specials and not movies:
        log.debug("No shows found in any category. Starting first time startup.")
        fe.do_first_time_setup()
        return render_template('first_time.html', logged_in=logged_in)
    return render_template('default.html', watching=watching, airing=airing, specials=specials, movies=movies, standalone=standalone, logged_in=logged_in) 

def login():
    """Login POST handler.

    Only runs when ``/login`` is hit with a POST method. There is no GET method
    equivilent, as it is handled by the navigation template. Sets the status
    code to ``401`` on login failure.

    Returns:
        JSON formatted output describing success or failure.
    """
    log.debug("Entering login, attempting to authenticate user.")
    username = request.form['signin_username']
    password = request.form['signin_password']
    log.debug("Username: {0}".format(username))
    if fe.check_auth(username, password):
        log.debug("User authenticated. Trying to set session.")
        session_id = fe.set_login_id()
        session['logged_in'] = session_id
        log.debug("Session ID: {0}, returning to user".format(session_id))
        return jsonify({ "login": "success" })
    log.debug("Username or password not recognized, sending 401.")
    response.status = 401
    return jsonify({ "login": "failed" }) 

def star():
    """Starring/Highlighting handler.

    Attempts to toggle a star/highlight on a particular show. The show ID must
    be passed in the ``id`` query string. If the user is unauthenticated, the
    function is aborted with a ``404`` message to hide the page.

    Returns:
        JSON formatted output describing success and the ID of the show starred.
    """
    log.debug("Entering star, trying to toggle star.")
    if fe.check_login_id(escape(session['logged_in'])):
        log.debug("Sending show ID {0} to function".format(request.args['id']))
        fe.star_show(request.args['id'])
        log.debug("Returning to user.")
        return jsonify({ "star": "success", "id": request.args['id'] })
    log.debug("User cannot be authenticated, send 404 to hide page.")
    abort(404) 

def drop_show():
    """Show removal handler.

    Attempts to remove a show from the backend system. The show ID must
    be passed in the ``id`` query string. If the user if unauthenticated, the
    function is aborted with a ``404`` message to hide the page.

    Returns:
        An HTTP redirect to the home page, to refresh.
    """
    log.debug("Entering drop_show, trying to remove show from list.")
    if fe.check_login_id(escape(session['logged_in'])):
       log.debug("Sending show ID {0} to function".format(request.args['id']))
       fe.remove_show(request.args['id'])
       log.debug("Refreshing user's page.")
       return redirect('/')
    log.debug("User cannot be authenticated, send 404 to hide page.")
    abort(404) 

def main(self):
        parser = argparse.ArgumentParser()
        parser.add_argument("-d", "--debug", help="debug verbose mode",
                            action="store_true")
        parser.add_argument("-v", "--verbose", help="info verbose mode",
                            action="store_true")
        parser.add_argument("-o", "--observers", type=str,
                            help="observers, example: -oLogger,Emailer")
        parser.add_argument("-m", "--markets", type=str,
                            help="markets, example: -mHaobtcCNY,Bitstamp")
        parser.add_argument("-s", "--status", help="status", action="store_true")
        parser.add_argument("command", nargs='*', default="watch",
                            help='verb: "watch|replay-history|get-balance|list-public-markets|get-broker-balance"')
        args = parser.parse_args()
        self.init_logger(args)
        self.exec_command(args) 

def start_process(cmd, supress_output=False):
    """Starts the build process by passing the command string to the
    command line

    Args:
        cmd (string): command for the build process.
        supress_output (bool): Indicates if logging is active for the build .
    """
    logging.debug(cmd)
    proc = subprocess.Popen(cmd, stdout=None, stderr=subprocess.PIPE)
    out, err = proc.communicate()
    rtn_code = proc.returncode

    if supress_output is False:
        if out:
            logging.info(out)
        if err:
            logging.error(err)

    if rtn_code == 0 or rtn_code is None:
        logging.info('Success: Process return code %s', str(rtn_code))
    else:
        logging.error('Error: Process return code %s', str(rtn_code))
        sys.exit(1) 

def set_voltage(self, value, persist=False):
        """Set the output voltage to specified value.  Value is a 12-bit number
        (0-4095) that is used to calculate the output voltage from:

          Vout =  (VDD*value)/4096

        I.e. the output voltage is the VDD reference scaled by value/4096.
        If persist is true it will save the voltage value in EEPROM so it
        continues after reset (default is false, no persistence).
        """
        # Clamp value to an unsigned 12-bit value.
        if value > 4095:
            value = 4095
        if value < 0:
            value = 0
        logging.debug('Setting value to {0:04}'.format(value))
        # Generate the register bytes and send them.
        # See datasheet figure 6-2:
        #   https://www.adafruit.com/datasheets/mcp4725.pdf 
        reg_data = [(value >> 4) & 0xFF, (value << 4) & 0xFF]
        if persist:
            self._device.writeList(WRITEDACEEPROM, reg_data)
        else:
            self._device.writeList(WRITEDAC, reg_data) 

def main():
    print("see log scrape.log")
    if os.path.isfile("scrape.log"):
        os.remove("scrape.log")
    log.basicConfig(filename="scrape.log",
            format='%(asctime)s %(levelname)s %(message)s',
            level=log.DEBUG)

    try:
        log.debug("main() full scrape will take 5-10 minutes")
        cards, tokens = loadJsonCards()

        saveCardsAsJson("data/cards.json", loadSets(allcards=cards))

        # a lot of token names are not unique
        # a static, handmade list of ids is more reliable
        if os.path.isfile('data/tokenlist.json'):
            with open('data/tokenlist.json', 'r', encoding='utf8') as f:
                saveCardsAsJson("data/tokens.json", loadTokens(tokens, json.load(f)))
    except Exception as e:
        log.exception("main() error %s", e) 

def get_console_log(session, arg_dict):
    try:
        raw_dom_id = arg_dict['dom_id']
    except KeyError:
        raise dom0_pluginlib.PluginError("Missing dom_id")
    try:
        dom_id = int(raw_dom_id)
    except ValueError:
        raise dom0_pluginlib.PluginError("Invalid dom_id")

    logfile = open(CONSOLE_LOG_FILE_PATTERN % dom_id, 'rb')
    try:
        try:
            log_content = _last_bytes(logfile)
        except IOError, e:  # noqa
            msg = "Error reading console: %s" % e
            logging.debug(msg)
            raise dom0_pluginlib.PluginError(msg)
    finally:
        logfile.close()

    return base64.b64encode(zlib.compress(log_content)) 

def _write_file(filename, data):
    # If the ISO was tampered with such that the destination is a symlink,
    # that could allow a malicious user to write to protected areas of the
    # dom0 filesystem. /HT to comstud for pointing this out.
    #
    # Short-term, checking that the destination is not a symlink should be
    # sufficient.
    #
    # Long-term, we probably want to perform all file manipulations within a
    # chroot jail to be extra safe.
    if os.path.islink(filename):
        raise RuntimeError('SECURITY: Cannot write to symlinked destination')

    logging.debug("Writing to file '%s'" % filename)
    f = open(filename, 'w')
    try:
        f.write(data)
    finally:
        f.close() 

def iptables_config(session, args):
    # command should be either save or restore
    logging.debug("iptables_config:enter")
    logging.debug("iptables_config: args=%s", args)
    cmd_args = pluginlib.exists(args, 'cmd_args')
    logging.debug("iptables_config: cmd_args=%s", cmd_args)
    process_input = pluginlib.optional(args, 'process_input')
    logging.debug("iptables_config: process_input=%s", process_input)
    cmd = json.loads(cmd_args)
    cmd = map(str, cmd)

    # either execute iptable-save or iptables-restore
    # command must be only one of these two
    # process_input must be used only with iptables-restore
    if len(cmd) > 0 and cmd[0] in ('iptables-save',
                                   'iptables-restore',
                                   'ip6tables-save',
                                   'ip6tables-restore'):
        result = _run_command(cmd, process_input)
        ret_str = json.dumps(dict(out=result, err=''))
        logging.debug("iptables_config:exit")
        return ret_str
    # else don't do anything and return an error
    else:
        raise pluginlib.PluginError("Invalid iptables command") 

def prep_blob(self, blob):
        """Cleanup input."""
        # remove empty lines
        if type(blob) == list:
            blob = [line for line in blob if line.strip() != '']
            if len(blob) == 1:
                blob = blob[0].replace('\\n', '\n').split('\n')
        # Split by line
        if type(blob) == str or type(blob) == six.text_type:
            lines = blob.split('\n')
        elif type(blob) == list:
            if len(blob) == 1:
                lines = blob[0].split('\n')
            else:
                lines = [line.rstrip() for line in blob]
        else:
            message = "Unknown input format"
            log.debug("%s - '%s", message, blob)
            raise ParseException(message)
        return lines 

def register(self, event, callback, selector=None):
        logging.debug('Registering: ' + str(event))

        if selector:
            key = str(id(callback))
        else:
            key = '_'

        self.handlers[event][key].append(callback)

        if event not in ('init', 'load', 'close'):
            capture = False
            if selector is None:
                selector = 'html'
                capture = True

            logging.debug('Dispatching: ' + str(event))
            self.dispatch({
                'name': 'subscribe',
                'event': event,
                'selector': selector,
                'capture': capture,
                'key': str(id(callback))
            }) 

def get_filter(opts=None):
    opts = opts or []
    if 'inc=*' in opts:
        # do not filter any files, include everything
        return None

    def _filter(dir, ls):
        incs = [opt.split('=').pop() for opt in opts if 'inc=' in opt]
        _filter = []
        for f in ls:
            _f = os.path.join(dir, f)

            if not os.path.isdir(_f) and not _f.endswith('.py') and incs:
                if True not in [fnmatch(_f, inc) for inc in incs]:
                    logging.debug('Not syncing %s, does not match include '
                                  'filters (%s)' % (_f, incs))
                    _filter.append(f)
                else:
                    logging.debug('Including file, which matches include '
                                  'filters (%s): %s' % (incs, _f))
            elif (os.path.isfile(_f) and not _f.endswith('.py')):
                logging.debug('Not syncing file: %s' % f)
                _filter.append(f)
            elif (os.path.isdir(_f) and not
                  os.path.isfile(os.path.join(_f, '__init__.py'))):
                logging.debug('Not syncing directory: %s' % f)
                _filter.append(f)
        return _filter
    return _filter 

def sync_directory(src, dest, opts=None):
    if os.path.exists(dest):
        logging.debug('Removing existing directory: %s' % dest)
        shutil.rmtree(dest)
    logging.info('Syncing directory: %s -> %s.' % (src, dest))

    shutil.copytree(src, dest, ignore=get_filter(opts))
    ensure_init(dest) 

def __init__(self):
        logging.debug("Storage engine : %s", engine)
        Base.metadata.create_all(engine)
        Session = sessionmaker(bind=engine)
        self.session = Session() 

def msg_recv(conn, sendfunc, closefunc):
    '''
    Function msg_recv reads null-delimited series of bytes from `conn`, which
    is a socket. Each series of bytes is then de-serialized into a json object,
    and `sendfunc` is called with that json object.
    `closefunc` is called if/when the socket `conn` is closed.
    '''
    buf = bytes()
    while True:
        try:
            data = conn.recv(8192)

            # No data means the connection is closed
            if not data:
                closefunc()
                return

            inbuf = buf + data
            if SEP in inbuf:
                parts = inbuf.split(SEP)
                # logging.debug("Length of parts: {}".format(len(parts)))
                tosend = [parts[0]]
                for p in parts[1:-1]:
                    tosend.append(p)
                buf = parts[-1]
                for msg in tosend:
                    m = gzip.decompress(msg)
                    m = m.decode('utf-8')
                    logging.debug("Msg: {}".format(m[:150]+'...' if len(m) > 150 else m))
                    obj = json.loads(m)
                    sendfunc(obj)
            else:
                buf += data
        except Exception as e:
            logging.exception(e) 

def send_input(self, inpt):
        # Just pass the input to the parent bout, but with info saying that
        # this input comes from this player
        logging.debug(inpt)
        self.bout.send_input({'player': self.name, 'input': inpt}) 

def __init__(self, host, port):
        self.host = host
        self.port = int(port)
        self.stateq = queue.Queue()
        self.clientsock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
        self.clientsock.connect((self.host, self.port))
        net.msg_recv(self.clientsock, self.stateq.put, lambda: None)
        conf = self.stateq.get()
        logging.debug("Conf: {}".format(conf))
        self.name = conf['name'] 

def send_input(self, inpt):
        logging.debug('PlayerClient "{}" sending: {}'.format(
            self.name, net.json_dump(inpt)))
        if isinstance(inpt, dict) and 'change-name' in inpt:
            self.name = inpt['change-name']
        net.send(self.clientsock, inpt)
        # self.clientsock.sendall(net.json_dump(inpt).encode('utf-8')+net.SEP) 

def consumer(e, q):
    while not e.is_set():
        message = q.get()
        time.sleep(0.1)
        logging.debug('consume {0}'.format(message)) 

def producer(e, q):
    for i in range(10):
        q.put(i)
        time.sleep(0.1)
        logging.debug('produce {0}'.format(i))
    if q.empty():
        e.set() 

def worker(event):
    event.wait(3)
    logging.debug("event is set") 

def set(event):
    time.sleep(2)
    event.set()
    logging.debug("event is set")