class NotifyingQueue(Event): def __init__(self): super(NotifyingQueue, self).__init__() self._queue = Queue() def put(self, item): """ Add new item to the queue. """ self._queue.put(item) self.set() def get(self, block=True, timeout=None): """ Removes and returns an item from the queue. """ value = self._queue.get(block, timeout) if self._queue.empty(): self.clear() return value def peek(self, block=True, timeout=None): return self._queue.peek(block, timeout) def __len__(self): return len(self._queue) def copy(self): """ Copies the current queue items. """ return [self.peek(i) for i in range(self._queue.qsize())]
class NotifyingQueue(Event): def __init__(self, maxsize=None, items=()): super().__init__() self._queue = Queue(maxsize, items) def put(self, item): """ Add new item to the queue. """ self._queue.put(item) self.set() def get(self, block=True, timeout=None): """ Removes and returns an item from the queue. """ value = self._queue.get(block, timeout) if self._queue.empty(): self.clear() return value def peek(self, block=True, timeout=None): return self._queue.peek(block, timeout) def __len__(self): return len(self._queue) def copy(self): """ Copies the current queue items. """ copy = self._queue.copy() result = list() while not copy.empty(): result.append(copy.get_nowait()) return result
class QueueStatReporter(StatReporter): def _start_queue(self): self.queue = Queue() @loop(setup='_start_queue') def _queue_proc(self): name, args, kwargs = self.queue.peek() self.logger.debug("Queue running {} with args '{}' kwargs '{}'" .format(name, args, kwargs)) try: func = getattr(self, name, None) if func is None: raise NotImplementedError( "Item {} has been enqueued that has no valid function!" .format(name)) func(*args, **kwargs) except self.queue_exceptions as e: self.logger.error("Unable to process queue item, retrying! " "{} Name: {}; Args: {}; Kwargs: {};" .format(e, name, args, kwargs)) sleep(1) return False # Don't do regular loop sleep except Exception: # Log any unexpected problem, but don't retry because we might # end up endlessly retrying with same failure self.logger.error("Unkown error, queue data discarded!" "Name: {}; Args: {}; Kwargs: {};" .format(name, args, kwargs), exc_info=True) # By default we want to remove the item from the queue self.queue.get() def log_one_minute(self, *args, **kwargs): self.queue.put(("_queue_log_one_minute", args, kwargs)) def add_block(self, *args, **kwargs): self.queue.put(("_queue_add_block", args, kwargs)) def _queue_add_block(self, address, height, total_subsidy, fees, hex_bits, hex_hash, currency, algo, merged=False, worker=None, **kwargs): raise NotImplementedError def _queue_log_one_minute(self, address, worker, algo, stamp, typ, amount): raise NotImplementedError
class NotifyingQueue(Event, Generic[T]): """This is not the same as a JoinableQueue. Here, instead of waiting for all the work to be processed, the wait is for work to be available. """ def __init__(self, maxsize: int = None, items: Iterable[T] = ()) -> None: super().__init__() self.queue = Queue(maxsize, items) if items: self.set() def put(self, item: T) -> None: """ Add new item to the queue. """ self.queue.put(item) self.set() def get(self, block: bool = True, timeout: float = None) -> T: """ Removes and returns an item from the queue. """ value = self.queue.get(block, timeout) if self.queue.empty(): self.clear() return value def peek(self, block: bool = True, timeout: float = None) -> T: return self.queue.peek(block, timeout) def __len__(self) -> int: return len(self.queue) def copy(self) -> List[T]: """ Copies the current queue items. """ copy = self.queue.copy() result = list() while not copy.empty(): result.append(copy.get_nowait()) return result def __repr__(self) -> str: return f"NotifyingQueue(id={id(self)}, num_items={len(self.queue)})"
def start_downloads(self, format_id, file_detail, user_info): """开始下载""" queue = Queue() # 队列, 用来传递 status ext = file_detail['file_ext'] title = file_detail['file_title'] dl_status = DownloadStatus() # 用于同步当前下载状态 dl_status.url = self.video_url dl_status.title = title gl = gevent.spawn(self.download_work, format_id, queue, dl_status) try: rst = queue.peek(timeout=15) # switch to gl if isinstance(rst, DownloadStatus): content_type = self.get_content_type(ext) file_name = '{}.{}'.format(title, ext) resp = Response(self.response_data_generator(queue), content_type=content_type) resp.headers["Content-Disposition"] = "attachment; filename={}".format(quote(file_name.encode('utf-8'))) resp.call_on_close(self.on_close(gl, dl_status, user_info)) # 免费额度在开始下载就扣除,不等下载完毕 if is_free_download(current_user): # current_user.is_anonymous or current_user.brick <= 0: info = current_user, user_info[1], user_info[-1] set_free_download_flag(info) size = get_file_size_of_format_id(self.video_url, format_id) if size > 0: minus_free_download_size(size) # 扣除免费额度 return resp elif isinstance(rst, Exception): print("request occur exception:{}".format(rst)) gl.kill() # close greenlet return _("request occur exception") # 请求发生异常 else: print("youtube-dl occur an unknown error") gl.kill() # close greenlet return _("unknown error") # 未知异常 except Empty: print("request timeout with url:{0}".format(self.video_url)) gl.kill() # close greenlet return _("request timeout") # 请求超时
class Balancer(object): def __init__(self, dispatcher): self.dispatcher = dispatcher self.task_list = [] self.task_queue = Queue() self.resource_graph = dispatcher.resource_graph self.threads = [] self.executors = [] self.logger = logging.getLogger('Balancer') self.dispatcher.require_collection('tasks', 'serial', type='log') self.create_initial_queues() self.start_executors() self.schedule_lock = RLock() self.distribution_lock = RLock() self.debugger = None self.debugged_tasks = None self.dispatcher.register_event_type('task.changed') # Lets try to get `EXECUTING|WAITING|CREATED` state tasks # from the previous dispatcher instance and set their # states to 'FAILED' since they are no longer running # in this instance of the dispatcher for stale_task in dispatcher.datastore.query( 'tasks', ('state', 'in', ['EXECUTING', 'WAITING', 'CREATED'])): self.logger.info( 'Stale task ID: {0}, name: {1} being set to FAILED'.format( stale_task['id'], stale_task['name'])) stale_task.update({ 'state': 'FAILED', 'error': { 'type': 'TaskException', 'message': 'dispatcher process died', 'code': errno.EINTR, 'stacktrace': '', 'extra': None } }) dispatcher.datastore.update('tasks', stale_task['id'], stale_task) def create_initial_queues(self): self.resource_graph.add_resource(Resource('system')) def start_executors(self): for i in range( 0, self.dispatcher.configstore.get('middleware.executors_count')): self.logger.info('Starting task executor #{0}...'.format(i)) self.executors.append(TaskExecutor(self, i)) def start(self): self.threads.append(gevent.spawn(self.distribution_thread)) self.logger.info("Started") def schema_to_list(self, schema): return { 'type': 'array', 'items': schema, 'minItems': sum([1 for x in schema if 'mandatory' in x and x['mandatory']]), 'maxItems': len(schema) } def verify_schema(self, clazz, args, strict=False): if not hasattr(clazz, 'params_schema'): return [] schema = self.schema_to_list(clazz.params_schema) val = validator.create_validator( schema, resolver=self.dispatcher.rpc.get_schema_resolver(schema)) if strict: val.fail_read_only = True else: val.remove_read_only = True return list(val.iter_errors(args)) def submit(self, name, args, sender, env=None): if name not in self.dispatcher.tasks: self.logger.warning("Cannot submit task: unknown task type %s", name) raise RpcException(errno.EINVAL, "Unknown task type {0}".format(name)) task = Task(self.dispatcher, name) task.user = sender.user.name task.session_id = sender.session_id task.created_at = datetime.utcnow() task.clazz = self.dispatcher.tasks[name] task.hooks = self.dispatcher.task_hooks.get(name, {}) task.args = copy.deepcopy(args) task.strict_verify = 'strict_validation' in sender.enabled_features if env: if not isinstance(env, dict): raise ValueError('env must be a dict') task.environment = copy.deepcopy(env) if self.debugger: for m in self.debugged_tasks: if fnmatch.fnmatch(name, m): task.debugger = self.debugger if 'RUN_AS_USER' in task.environment: task.user = task.environment['RUN_AS_USER'] task.environment['SENDER_ADDRESS'] = sender.client_address task.id = self.dispatcher.datastore.insert("tasks", task) task.set_state(TaskState.CREATED) self.task_queue.put(task) self.logger.info("Task %d submitted (type: %s, class: %s)", task.id, name, task.clazz) return task.id def submit_with_upload(self, task_name, args, sender, env=None): task_metadata = self.dispatcher.tasks[task_name]._get_metadata() schema = task_metadata['schema'] if schema is None: raise RpcException( errno.ENOENT, "Task {0} has no schema associated with it".format(task_name)) upload_token_list = [] for idx, arg in enumerate(schema): if arg.get('type') == 'fd': rfd, wfd = os.pipe() token = self.dispatcher.token_store.issue_token( FileToken(user=sender.user, lifetime=60, direction='upload', file=FileObjectPosix(wfd, 'wb', close=True), name=str(uuid.uuid4()), size=None)) upload_token_list.append(token) args[idx] = FileDescriptor(rfd) task_id = self.submit(task_name, args, sender, env) return task_id, upload_token_list def submit_with_download(self, task_name, args, sender, env=None): task_metadata = self.dispatcher.tasks[task_name]._get_metadata() schema = task_metadata['schema'] url_list = [] if schema is None: raise RpcException( errno.ENOENT, "Task {0} has no schema associated with it".format(task_name)) for idx, arg in enumerate(schema): if arg.get('type') == 'fd': rfd, wfd = os.pipe() url_list.append("/dispatcher/filedownload?token={0}".format( self.dispatcher.token_store.issue_token( FileToken(user=sender.user, lifetime=60, direction='download', file=FileObjectPosix(rfd, 'rb', close=True), name=args[idx])))) args[idx] = FileDescriptor(wfd) task_id = self.submit(task_name, args, sender, env) return task_id, url_list def verify_subtask(self, parent, name, args): clazz = self.dispatcher.tasks[name] instance = clazz(self.dispatcher, self.dispatcher.datastore) return instance.verify(*args) def run_subtask(self, parent, name, args, env=None): args = list(args) task = Task(self.dispatcher, name) task.created_at = datetime.utcnow() task.clazz = self.dispatcher.tasks[name] task.hooks = self.dispatcher.task_hooks.get(name, {}) task.args = args task.instance = task.clazz(self.dispatcher, self.dispatcher.datastore) task.instance.verify(*task.args) task.description = task.instance.describe(*task.args) task.id = self.dispatcher.datastore.insert("tasks", task) task.parent = parent task.environment = {} if parent: task.environment = copy.deepcopy(parent.environment) task.environment['parent'] = parent.id task.user = parent.user if env: if not isinstance(env, dict): raise ValueError('env must be a dict') task.environment.update(env) if self.debugger: for m in self.debugged_tasks: if fnmatch.fnmatch(name, m): task.debugger = self.debugger task.set_state(TaskState.CREATED) self.task_list.append(task) task.start() return task def join_subtasks(self, *tasks): for i in tasks: i.join() def abort(self, id, error=None): task = self.get_task(id) if not task: self.logger.warning("Cannot abort task: unknown task id %d", id) return success = False if task.started_at is None: success = True else: try: task.executor.abort() except: pass if success: task.ended.set() if error: task.set_state(TaskState.FAILED, TaskStatus(0), serialize_error(error)) self.logger.debug("Task ID: %d, name: %s aborted with error", task.id, task.name) else: task.set_state(TaskState.ABORTED, TaskStatus(0, "Aborted")) self.logger.debug("Task ID: %d, name: %s aborted by user", task.id, task.name) def task_exited(self, task): self.resource_graph.release(*task.resources) self.schedule_tasks(True) def schedule_tasks(self, exit=False): """ This function is called when: 1) any new task is submitted to any of the queues 2) any task exists """ with self.schedule_lock: started = 0 executing_tasks = [ t for t in self.task_list if t.state == TaskState.EXECUTING ] waiting_tasks = [ t for t in self.task_list if t.state == TaskState.WAITING ] for task in waiting_tasks: if not self.resource_graph.can_acquire(*task.resources): continue self.resource_graph.acquire(*task.resources) self.threads.append(task.start()) started += 1 if not started and not executing_tasks and ( exit or len(waiting_tasks) == 1): for task in waiting_tasks: # Check whether or not task waits on nonexistent resources. If it does, # abort it 'cause there's no chance anymore that missing resources will appear. if any( self.resource_graph.get_resource(res) is None for res in task.resources): self.logger.warning( 'Aborting task {0}: deadlock'.format(task.id)) self.abort( task.id, VerifyException(errno.EBUSY, 'Resource deadlock avoided')) def distribution_thread(self): while True: self.task_queue.peek() self.distribution_lock.acquire() task = self.task_queue.get() try: self.logger.debug("Picked up task %d: %s with args %s", task.id, task.name, task.args) errors = self.verify_schema(self.dispatcher.tasks[task.name], task.args, task.strict_verify) if len(errors) > 0: errors = list(validator.serialize_errors(errors)) self.logger.warning( "Cannot submit task {0}: schema verification failed with errors {1}" .format(task.name, errors)) raise ValidationException(extra=errors) task.instance = task.clazz(self.dispatcher, self.dispatcher.datastore) task.resources = task.instance.verify(*task.args) task.description = task.instance.describe(*task.args) if type(task.resources) is not list: raise ValueError( "verify() returned something else than resource list") except Exception as err: self.logger.warning("Cannot verify task %d: %s", task.id, err) task.set_state(TaskState.FAILED, TaskStatus(0), serialize_error(err)) task.ended.set() self.distribution_lock.release() if not isinstance(err, VerifyException): self.dispatcher.report_error( 'Task {0} verify() method raised invalid exception'. format(err), err) continue task.set_state(TaskState.WAITING) self.task_list.append(task) self.distribution_lock.release() self.schedule_tasks() if task.resources: self.logger.debug("Task %d assigned to resources %s", task.id, ','.join(task.resources)) def assign_executor(self, task): for i in self.executors: with i.cv: if i.state == WorkerState.IDLE: self.logger.info("Task %d assigned to executor #%d", task.id, i.index) task.executor = i i.state = WorkerState.ASSIGNED return # Out of executors! Need to spawn new one executor = TaskExecutor(self, len(self.executors)) self.executors.append(executor) with executor.cv: executor.cv.wait_for(lambda: executor.state == WorkerState.IDLE) executor.state = WorkerState.ASSIGNED task.executor = executor self.logger.info("Task %d assigned to executor #%d", task.id, executor.index) def dispose_executors(self): for i in self.executors: i.die() def get_active_tasks(self): return [ x for x in self.task_list if x.state in (TaskState.CREATED, TaskState.WAITING, TaskState.EXECUTING) ] def get_tasks(self, type=None): if type is None: return self.task_list return [x for x in self.task_list if x.state == type] def get_task(self, id): self.distribution_lock.acquire() t = first_or_default(lambda x: x.id == id, self.task_list) if not t: t = first_or_default(lambda x: x.id == id, self.task_queue.queue) self.distribution_lock.release() return t def get_executor_by_key(self, key): return first_or_default(lambda t: t.key == key, self.executors) def get_executor_by_sender(self, sender): return first_or_default(lambda t: t.conn == sender, self.executors)
class UploadFileToDocService(BaseWorker): """ Upload file with details """ def __init__(self, upload_to_doc_service_queue, upload_to_tender_queue, process_tracker, doc_service_client, services_not_available, sleep_change_value, delay=15): super(UploadFileToDocService, self).__init__(services_not_available) self.start_time = datetime.now() self.delay = delay self.process_tracker = process_tracker # init client self.doc_service_client = doc_service_client # init queues for workers self.upload_to_doc_service_queue = upload_to_doc_service_queue self.upload_to_tender_queue = upload_to_tender_queue self.sleep_change_value = sleep_change_value # retry queues for workers self.retry_upload_to_doc_service_queue = Queue(maxsize=500) def upload_worker(self): while not self.exit: self.services_not_available.wait() self.try_peek_and_upload(False) gevent.sleep(0) def retry_upload_worker(self): while not self.exit: self.services_not_available.wait() self.try_peek_and_upload(True) gevent.sleep(0) def try_peek_and_upload(self, is_retry): try: tender_data = self.peek_from_queue(is_retry) except LoopExit: gevent.sleep(0) else: self.try_upload_to_doc_service(tender_data, is_retry) def peek_from_queue(self, is_retry): return self.retry_upload_to_doc_service_queue.peek() if is_retry else self.upload_to_doc_service_queue.peek() def try_upload_to_doc_service(self, tender_data, is_retry): try: response = self.update_headers_and_upload(tender_data, is_retry) except Exception as e: self.remove_bad_data(tender_data, e, is_retry) else: self.move_to_tender_if_200(response, tender_data, is_retry) def update_headers_and_upload(self, tender_data, is_retry): if is_retry: return self.update_headers_and_upload_retry(tender_data) else: return self.doc_service_client.upload(file_name, create_file(tender_data.file_content), 'application/yaml', headers={'X-Client-Request-ID': tender_data.doc_id()}) def update_headers_and_upload_retry(self, tender_data): self.doc_service_client.headers.update({'X-Client-Request-ID': tender_data.doc_id()}) return self.client_upload_to_doc_service(tender_data) def remove_bad_data(self, tender_data, e, is_retry): logger.exception('Exception while uploading file to doc service {} doc_id: {}. Message: {}. {}'. format(tender_data, tender_data.doc_id(), e, "Removed tender data" if is_retry else ""), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_DOC_SERVICE}, tender_data.log_params())) if is_retry: self.retry_upload_to_doc_service_queue.get() self.process_tracker.update_items_and_tender(tender_data.tender_id, tender_data.item_id, tender_data.doc_id()) raise e else: self.retry_upload_to_doc_service_queue.put(tender_data) self.upload_to_doc_service_queue.get() def move_to_tender_if_200(self, response, tender_data, is_retry): if response.status_code == 200: self.move_to_tender_queue(tender_data, response, is_retry) else: self.move_data_to_retry_or_leave(response, tender_data, is_retry) def move_to_tender_queue(self, tender_data, response, is_retry): data = tender_data data.file_content = dict(response.json(), **{'meta': {'id': tender_data.doc_id()}}) self.upload_to_tender_queue.put(data) if not is_retry: self.upload_to_doc_service_queue.get() else: self.retry_upload_to_doc_service_queue.get() logger.info('Successfully uploaded file to doc service {} doc_id: {}'.format(tender_data, tender_data.doc_id()), extra=journal_context({"MESSAGE_ID": DATABRIDGE_SUCCESS_UPLOAD_TO_DOC_SERVICE}, tender_data.log_params())) def move_data_to_retry_or_leave(self, response, tender_data, is_retry): logger.info('Not successful response from document service while uploading {} doc_id: {}. Response {}'. format(tender_data, tender_data.doc_id(), response.status_code), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_DOC_SERVICE}, tender_data.log_params())) if not is_retry: self.retry_upload_to_doc_service_queue.put(tender_data) self.upload_to_doc_service_queue.get() @retry(stop_max_attempt_number=5, wait_exponential_multiplier=retry_mult) def client_upload_to_doc_service(self, tender_data): """Process upload request for retry queue objects.""" return self.doc_service_client.upload(file_name, create_file(tender_data.file_content), 'application/yaml', headers={'X-Client-Request-ID': tender_data.doc_id()}) def _start_jobs(self): return {'upload_worker': spawn(self.upload_worker), 'retry_upload_worker': spawn(self.retry_upload_worker)}
class UploadFileToTender(BaseWorker): def __init__(self, client, upload_to_tender_queue, process_tracker, services_not_available, sleep_change_value, delay=15): super(UploadFileToTender, self).__init__(services_not_available) self.start_time = datetime.now() self.delay = delay self.process_tracker = process_tracker # init clients self.client = client # init queues for workers self.upload_to_tender_queue = upload_to_tender_queue self.retry_upload_to_tender_queue = Queue(maxsize=500) # blockers self.sleep_change_value = sleep_change_value def upload_worker(self): while not self.exit: self.services_not_available.wait() self.try_peek_data_and_upload_to_tender(False) gevent.sleep(self.sleep_change_value.time_between_requests) def retry_upload_worker(self): while not self.exit: self.services_not_available.wait() self.try_peek_data_and_upload_to_tender(True) gevent.sleep(self.sleep_change_value.time_between_requests) def try_peek_data_and_upload_to_tender(self, is_retry): try: tender_data = self.peek_from_tender_queue(is_retry) except LoopExit: gevent.sleep(0) else: self.try_upload_to_tender(tender_data, is_retry) def peek_from_tender_queue(self, is_retry): return self.retry_upload_to_tender_queue.peek( ) if is_retry else self.upload_to_tender_queue.peek() def try_upload_to_tender(self, tender_data, is_retry): try: self.update_headers_and_upload_to_tender(tender_data, is_retry) except ResourceError as re: self.remove_data_or_increase_wait(re, tender_data, is_retry) except Exception as e: self.handle_error(e, tender_data, is_retry) else: self.successfully_uploaded_to_tender(tender_data, is_retry) def update_headers_and_upload_to_tender(self, tender_data, is_retry): if is_retry: self.do_upload_to_tender_with_retry(tender_data) else: self.do_upload_to_tender(tender_data) def do_upload_to_tender(self, tender_data): document_data = tender_data.file_content.get('data', {}) document_data["documentType"] = "registerExtract" self.client.headers.update( {'X-Client-Request-ID': tender_data.doc_id()}) self.client._create_tender_resource_item( munchify({'data': { 'id': tender_data.tender_id }}), {'data': document_data}, '{}/{}/documents'.format(tender_data.item_name, tender_data.item_id)) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=retry_mult) def do_upload_to_tender_with_retry(self, tender_data): """Process upload to tender request for retry queue objects.""" self.do_upload_to_tender(tender_data) def remove_data_or_increase_wait(self, re, tender_data, is_retry): if re.status_int == 403 or re.status_int == 422 or re.status_int is None: self.removing_data(re, tender_data, is_retry) elif re.status_int == 429: self.decrease_request_frequency(re, tender_data) else: self.handle_error(re, tender_data, is_retry) def removing_data(self, re, tender_data, is_retry): logger.warning( "Accept {} while uploading to {} doc_id: {}. Message {}".format( re.status_int, tender_data, tender_data.doc_id(), re.msg), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_ITEM_STATUS_CHANGED_WHILE_PROCESSING }, tender_data.log_params())) self.remove_data(tender_data, is_retry) def decrease_request_frequency(self, re, tender_data): logger.info( "Accept 429 while uploading to {} doc_id: {}. Message {}".format( tender_data, tender_data.doc_id(), re.msg), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_ITEM_STATUS_CHANGED_WHILE_PROCESSING }, tender_data.log_params())) self.sleep_change_value.increment() def handle_error(self, re, tender_data, is_retry): logger.info( 'Error while uploading file to {} doc_id: {}. Status: {}. Message: {}' .format(tender_data, tender_data.doc_id(), getattr(re, "status_int", None), re.message), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_TENDER}, tender_data.log_params())) self.sleep_change_value.decrement() if not is_retry: self.retry_upload_to_tender_queue.put(tender_data) self.upload_to_tender_queue.get() def successfully_uploaded_to_tender(self, tender_data, is_retry): logger.info('Successfully uploaded file to {} doc_id: {}'.format( tender_data, tender_data.doc_id()), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_SUCCESS_UPLOAD_TO_TENDER}, tender_data.log_params())) self.remove_data(tender_data, is_retry) def remove_data(self, tender_data, is_retry): self.process_tracker.update_items_and_tender(tender_data.tender_id, tender_data.item_id, tender_data.doc_id()) self.sleep_change_value.decrement() if is_retry: self.retry_upload_to_tender_queue.get() else: self.upload_to_tender_queue.get() def _start_jobs(self): return { 'upload_worker': spawn(self.upload_worker), 'retry_upload_worker': spawn(self.retry_upload_worker) }
class ChainService(WiredService): """ Manages the chain and requests to it. """ # required by BaseService name = 'chain' default_config = dict(eth=dict(network_id=0)) # required by WiredService wire_protocol = eth_protocol.ETHProtocol # create for each peer # initialized after configure: chain = None genesis = None synchronizer = None config = None block_queue_size = 1024 transaction_queue_size = 1024 def __init__(self, app): self.config = app.config self.db = app.services.db assert self.db is not None super(ChainService, self).__init__(app) log.info('initializing chain') coinbase = app.services.accounts.coinbase self.chain = Chain(self.db, new_head_cb=self._on_new_head, coinbase=coinbase) log.info('chain at', number=self.chain.head.number) self.synchronizer = Synchronizer(self, force_sync=None) self.block_queue = Queue(maxsize=self.block_queue_size) self.transaction_queue = Queue(maxsize=self.transaction_queue_size) self.add_blocks_lock = False self.add_transaction_lock = gevent.lock.Semaphore() self.broadcast_filter = DuplicatesFilter() def _on_new_head(self, block): pass def add_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) log.debug('add_transaction', locked=self.add_transaction_lock.locked()) self.add_transaction_lock.acquire() success = self.chain.add_transaction(tx) self.add_transaction_lock.release() if success: self.broadcast_transaction(tx, origin=origin) # asap def add_block(self, t_block, proto): "adds a block to the block_queue and spawns _add_block if not running" self.block_queue.put((t_block, proto)) # blocks if full if not self.add_blocks_lock: self.add_blocks_lock = True gevent.spawn(self._add_blocks) def knows_block(self, block_hash): "if block is in chain or in queue" if block_hash in self.chain: return True # check if queued or processed for i in range(len(self.block_queue.queue)): if block_hash == self.block_queue.queue[i][0].header.hash: return True return False def _add_blocks(self): log.debug('add_blocks', qsize=self.block_queue.qsize()) try: while not self.block_queue.empty(): t_block, proto = self.block_queue.peek() # peek: knows_block while processing if t_block.header.hash in self.chain: log.warn('known block', block=t_block) self.block_queue.get() continue if t_block.header.prevhash not in self.chain: log.warn('missing parent', block=t_block) self.block_queue.get() continue if not t_block.header.check_pow(): log.warn('invalid pow', block=t_block, FIXME='ban node') self.block_queue.get() continue try: # deserialize st = time.time() block = t_block.to_block(db=self.chain.db) elapsed = time.time() - st log.debug('deserialized', elapsed='%.2fs' % elapsed, gas_used=block.gas_used, gpsec=int(block.gas_used / elapsed)) except processblock.InvalidTransaction as e: log.warn('invalid transaction', block=t_block, error=e, FIXME='ban node') gevent.sleep(0.001) continue if self.chain.add_block(block): log.info('added', block=block) self.block_queue.get() gevent.sleep(0.001) finally: self.add_blocks_lock = False def broadcast_newblock(self, block, chain_difficulty=None, origin=None): if not chain_difficulty: assert block.hash in self.chain chain_difficulty = block.chain_difficulty() assert isinstance(block, (eth_protocol.TransientBlock, Block)) if self.broadcast_filter.known(block.header.hash): log.debug('already broadcasted block') else: log.debug('broadcasting newblock', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'newblock', args=(block, chain_difficulty), exclude_peers=[origin.peer] if origin else []) def broadcast_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) if self.broadcast_filter.known(tx.hash): log.debug('already broadcasted tx') else: log.debug('broadcasting tx', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'transactions', args=(tx,), exclude_peers=[origin.peer] if origin else []) # wire protocol receivers ########### def on_wire_protocol_start(self, proto): log.debug('on_wire_protocol_start', proto=proto) assert isinstance(proto, self.wire_protocol) # register callbacks proto.receive_status_callbacks.append(self.on_receive_status) proto.receive_transactions_callbacks.append(self.on_receive_transactions) proto.receive_getblockhashes_callbacks.append(self.on_receive_getblockhashes) proto.receive_blockhashes_callbacks.append(self.on_receive_blockhashes) proto.receive_getblocks_callbacks.append(self.on_receive_getblocks) proto.receive_blocks_callbacks.append(self.on_receive_blocks) proto.receive_newblock_callbacks.append(self.on_receive_newblock) # send status head = self.chain.head proto.send_status(chain_difficulty=head.chain_difficulty(), chain_head_hash=head.hash, genesis_hash=self.chain.genesis.hash) def on_wire_protocol_stop(self, proto): assert isinstance(proto, self.wire_protocol) log.debug('on_wire_protocol_stop', proto=proto) def on_receive_status(self, proto, eth_version, network_id, chain_difficulty, chain_head_hash, genesis_hash): log.debug('status received', proto=proto, eth_version=eth_version) assert eth_version == proto.version, (eth_version, proto.version) if network_id != self.config['eth'].get('network_id', proto.network_id): log.warn("invalid network id", remote_network_id=network_id, expected_network_id=self.config['eth'].get('network_id', proto.network_id)) raise eth_protocol.ETHProtocolError('wrong network_id') # check genesis if genesis_hash != self.chain.genesis.hash: log.warn("invalid genesis hash", remote_id=proto, genesis=genesis_hash.encode('hex')) raise eth_protocol.ETHProtocolError('wrong genesis block') # request chain self.synchronizer.receive_status(proto, chain_head_hash, chain_difficulty) # send transactions transactions = self.chain.get_transactions() if transactions: log.debug("sending transactions", remote_id=proto) proto.send_transactions(*transactions) # transactions def on_receive_transactions(self, proto, transactions): "receives rlp.decoded serialized" log.debug('remote_transactions_received', count=len(transactions), remote_id=proto) for tx in transactions: self.add_transaction(tx, origin=proto) # blockhashes ########### def on_receive_getblockhashes(self, proto, child_block_hash, count): log.debug("handle_get_blockhashes", count=count, block_hash=encode_hex(child_block_hash)) max_hashes = min(count, self.wire_protocol.max_getblockhashes_count) found = [] if child_block_hash not in self.chain: log.debug("unknown block") proto.send_blockhashes(*[]) return last = child_block_hash while len(found) < max_hashes: last = rlp.decode_lazy(self.chain.db.get(last))[0][0] if last: found.append(last) else: break log.debug("sending: found block_hashes", count=len(found)) proto.send_blockhashes(*found) def on_receive_blockhashes(self, proto, blockhashes): if blockhashes: log.debug("on_receive_blockhashes", count=len(blockhashes), remote_id=proto, first=encode_hex(blockhashes[0]), last=encode_hex(blockhashes[-1])) else: log.debug("recv 0 remote block hashes, signifying genesis block") self.synchronizer.receive_blockhashes(proto, blockhashes) # blocks ################ def on_receive_getblocks(self, proto, blockhashes): log.debug("on_receive_getblocks", count=len(blockhashes)) found = [] for bh in blockhashes[:self.wire_protocol.max_getblocks_count]: try: found.append(self.chain.db.get(bh)) except KeyError: log.debug("unknown block requested", block_hash=encode_hex(bh)) if found: log.debug("found", count=len(found)) proto.send_blocks(*found) def on_receive_blocks(self, proto, transient_blocks): blk_number = max(x.header.number for x in transient_blocks) if transient_blocks else 0 log.debug("recv blocks", count=len(transient_blocks), remote_id=proto, highest_number=blk_number) if transient_blocks: self.synchronizer.receive_blocks(proto, transient_blocks) def on_receive_newblock(self, proto, block, chain_difficulty): log.debug("recv newblock", block=block, remote_id=proto) self.synchronizer.receive_newblock(proto, block, chain_difficulty)
class ChainService(WiredService): """ Manages the chain and requests to it. """ # required by BaseService name = 'chain' default_config = dict(eth=dict(network_id=0)) # required by WiredService wire_protocol = eth_protocol.ETHProtocol # create for each peer # initialized after configure: chain = None genesis = None synchronizer = None config = None block_queue_size = 1024 transaction_queue_size = 1024 processed_gas = 0 processed_elapsed = 0 def __init__(self, app): self.config = app.config self.db = app.services.db assert self.db is not None super(ChainService, self).__init__(app) log.info('initializing chain') coinbase = app.services.accounts.coinbase self.chain = Chain(self.db, new_head_cb=self._on_new_head, coinbase=coinbase) log.info('chain at', number=self.chain.head.number) self.synchronizer = Synchronizer(self, force_sync=None) self.block_queue = Queue(maxsize=self.block_queue_size) self.transaction_queue = Queue(maxsize=self.transaction_queue_size) self.add_blocks_lock = False self.add_transaction_lock = gevent.lock.Semaphore() self.broadcast_filter = DuplicatesFilter() self.on_new_head_cbs = [] self.on_new_head_candidate_cbs = [] @property def is_syncing(self): return self.synchronizer.synctask is not None def _on_new_head(self, block): for cb in self.on_new_head_cbs: cb(block) self._on_new_head_candidate( ) # we implicitly have a new head_candidate def _on_new_head_candidate(self): for cb in self.on_new_head_candidate_cbs: cb(self.chain.head_candidate) def add_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) log.debug('add_transaction', locked=self.add_transaction_lock.locked()) self.add_transaction_lock.acquire() success = self.chain.add_transaction(tx) self.add_transaction_lock.release() if success: self._on_new_head_candidate() self.broadcast_transaction(tx, origin=origin) # asap def add_block(self, t_block, proto): "adds a block to the block_queue and spawns _add_block if not running" self.block_queue.put((t_block, proto)) # blocks if full if not self.add_blocks_lock: self.add_blocks_lock = True # need to lock here (ctx switch is later) gevent.spawn(self._add_blocks) def add_mined_block(self, block): log.debug('adding mined block', block=block) assert block.check_pow() if self.chain.add_block(block): log.info('added', block=block, ts=time.time()) assert block == self.chain.head self.broadcast_newblock(block, chain_difficulty=block.chain_difficulty()) def knows_block(self, block_hash): "if block is in chain or in queue" if block_hash in self.chain: return True # check if queued or processed for i in range(len(self.block_queue.queue)): if block_hash == self.block_queue.queue[i][0].header.hash: return True return False def _add_blocks(self): log.debug('add_blocks', qsize=self.block_queue.qsize(), add_tx_lock=self.add_transaction_lock.locked()) assert self.add_blocks_lock is True self.add_transaction_lock.acquire() try: while not self.block_queue.empty(): t_block, proto = self.block_queue.peek( ) # peek: knows_block while processing if t_block.header.hash in self.chain: log.warn('known block', block=t_block) self.block_queue.get() continue if t_block.header.prevhash not in self.chain: log.warn('missing parent', block=t_block) self.block_queue.get() continue # FIXME, this is also done in validation and in synchronizer for new_blocks if not t_block.header.check_pow(): log.warn('invalid pow', block=t_block, FIXME='ban node') self.block_queue.get() continue try: # deserialize st = time.time() block = t_block.to_block(db=self.chain.db) elapsed = time.time() - st log.debug('deserialized', elapsed='%.4fs' % elapsed, gas_used=block.gas_used, gpsec=self.gpsec(block.gas_used, elapsed)) except processblock.InvalidTransaction as e: log.warn('invalid transaction', block=t_block, error=e, FIXME='ban node') self.block_queue.get() continue except VerificationFailed as e: log.warn('verification failed', error=e, FIXME='ban node') self.block_queue.get() continue if self.chain.add_block(block): log.info('added', block=block, ts=time.time()) self.block_queue.get( ) # remove block from queue (we peeked only) gevent.sleep(0.001) finally: self.add_blocks_lock = False self.add_transaction_lock.release() def gpsec(self, gas_spent=0, elapsed=0): self.processed_gas += gas_spent self.processed_elapsed += elapsed return int(self.processed_gas / (0.001 + self.processed_elapsed)) def broadcast_newblock(self, block, chain_difficulty=None, origin=None): if not chain_difficulty: assert block.hash in self.chain chain_difficulty = block.chain_difficulty() assert isinstance(block, (eth_protocol.TransientBlock, Block)) if self.broadcast_filter.known(block.header.hash): log.debug('already broadcasted block') else: log.debug('broadcasting newblock', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'newblock', args=(block, chain_difficulty), exclude_peers=[origin.peer] if origin else []) def broadcast_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) if self.broadcast_filter.known(tx.hash): log.debug('already broadcasted tx') else: log.debug('broadcasting tx', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'transactions', args=(tx, ), exclude_peers=[origin.peer] if origin else []) # wire protocol receivers ########### def on_wire_protocol_start(self, proto): log.debug('on_wire_protocol_start', proto=proto) assert isinstance(proto, self.wire_protocol) # register callbacks proto.receive_status_callbacks.append(self.on_receive_status) proto.receive_transactions_callbacks.append( self.on_receive_transactions) proto.receive_getblockhashes_callbacks.append( self.on_receive_getblockhashes) proto.receive_blockhashes_callbacks.append(self.on_receive_blockhashes) proto.receive_getblocks_callbacks.append(self.on_receive_getblocks) proto.receive_blocks_callbacks.append(self.on_receive_blocks) proto.receive_newblock_callbacks.append(self.on_receive_newblock) # send status head = self.chain.head proto.send_status(chain_difficulty=head.chain_difficulty(), chain_head_hash=head.hash, genesis_hash=self.chain.genesis.hash) def on_wire_protocol_stop(self, proto): assert isinstance(proto, self.wire_protocol) log.debug('on_wire_protocol_stop', proto=proto) def on_receive_status(self, proto, eth_version, network_id, chain_difficulty, chain_head_hash, genesis_hash): log.debug('status received', proto=proto, eth_version=eth_version) assert eth_version == proto.version, (eth_version, proto.version) if network_id != self.config['eth'].get('network_id', proto.network_id): log.warn("invalid network id", remote_network_id=network_id, expected_network_id=self.config['eth'].get( 'network_id', proto.network_id)) raise eth_protocol.ETHProtocolError('wrong network_id') # check genesis if genesis_hash != self.chain.genesis.hash: log.warn("invalid genesis hash", remote_id=proto, genesis=genesis_hash.encode('hex')) raise eth_protocol.ETHProtocolError('wrong genesis block') # request chain self.synchronizer.receive_status(proto, chain_head_hash, chain_difficulty) # send transactions transactions = self.chain.get_transactions() if transactions: log.debug("sending transactions", remote_id=proto) proto.send_transactions(*transactions) # transactions def on_receive_transactions(self, proto, transactions): "receives rlp.decoded serialized" log.debug('remote_transactions_received', count=len(transactions), remote_id=proto) for tx in transactions: self.add_transaction(tx, origin=proto) # blockhashes ########### def on_receive_getblockhashes(self, proto, child_block_hash, count): log.debug("handle_get_blockhashes", count=count, block_hash=encode_hex(child_block_hash)) max_hashes = min(count, self.wire_protocol.max_getblockhashes_count) found = [] if child_block_hash not in self.chain: log.debug("unknown block") proto.send_blockhashes(*[]) return last = child_block_hash while len(found) < max_hashes: try: last = rlp.decode_lazy(self.chain.db.get(last))[0][0] except KeyError: # this can happen if we started a chain download, which did not complete # should not happen if the hash is part of the canonical chain log.warn('KeyError in getblockhashes', hash=last) break if last: found.append(last) else: break log.debug("sending: found block_hashes", count=len(found)) proto.send_blockhashes(*found) def on_receive_blockhashes(self, proto, blockhashes): if blockhashes: log.debug("on_receive_blockhashes", count=len(blockhashes), remote_id=proto, first=encode_hex(blockhashes[0]), last=encode_hex(blockhashes[-1])) else: log.debug("recv 0 remote block hashes, signifying genesis block") self.synchronizer.receive_blockhashes(proto, blockhashes) # blocks ################ def on_receive_getblocks(self, proto, blockhashes): log.debug("on_receive_getblocks", count=len(blockhashes)) found = [] for bh in blockhashes[:self.wire_protocol.max_getblocks_count]: try: found.append(self.chain.db.get(bh)) except KeyError: log.debug("unknown block requested", block_hash=encode_hex(bh)) if found: log.debug("found", count=len(found)) proto.send_blocks(*found) def on_receive_blocks(self, proto, transient_blocks): blk_number = max(x.header.number for x in transient_blocks) if transient_blocks else 0 log.debug("recv blocks", count=len(transient_blocks), remote_id=proto, highest_number=blk_number) if transient_blocks: self.synchronizer.receive_blocks(proto, transient_blocks) def on_receive_newblock(self, proto, block, chain_difficulty): log.debug("recv newblock", block=block, remote_id=proto) self.synchronizer.receive_newblock(proto, block, chain_difficulty)
class ResourceFeeder(object): idle = idle def __init__(self, host=DEFAULT_API_HOST, version=DEFAULT_API_VERSION, key=DEFAULT_API_KEY, resource='tenders', extra_params=DEFAULT_API_EXTRA_PARAMS, retrievers_params=DEFAULT_RETRIEVERS_PARAMS, adaptive=False): super(ResourceFeeder, self).__init__() self.host = host self.version = version self.key = key self.resource = resource self.adaptive = adaptive self.extra_params = extra_params self.retrievers_params = retrievers_params self.queue = Queue(maxsize=retrievers_params['queue_size']) self.forward_info = {} self.backward_info = {} def init_api_clients(self): self.backward_params = {'descending': True, 'feed': 'changes'} self.backward_params.update(self.extra_params) self.forward_params = {'feed': 'changes'} self.forward_params.update(self.extra_params) self.forward_client = TendersClientSync(self.key, resource=self.resource, host_url=self.host, api_version=self.version) self.forward_info['status'] = INITIALIZED self.backward_client = TendersClientSync(self.key, resource=self.resource, host_url=self.host, api_version=self.version) self.backward_info['status'] = INITIALIZED self.cookies = self.forward_client.session.cookies = self.backward_client.session.cookies def handle_response_data(self, data): for tender in data: # self.idle() self.queue.put(tender) def start_sync(self): # self.init_api_clients() response = self.backward_client.sync_tenders(self.backward_params) self.handle_response_data(response.data) self.backward_params['offset'] = response.next_page.offset self.forward_params['offset'] = response.prev_page.offset self.backward_worker = spawn(self.retriever_backward) self.forward_worker = spawn(self.retriever_forward) def restart_sync(self): """ Restart retrieving from Openprocurement API. """ logger.info('Restart workers') self.forward_worker.kill() self.backward_worker.kill() self.init_api_clients() self.start_sync() def get_resource_items(self): """ Prepare iterator for retrieving from Openprocurement API. :param: host (str): Url of Openprocurement API. Defaults is DEFAULT_API_HOST version (str): Verion of Openprocurement API. Defaults is DEFAULT_API_VERSION key(str): Access key of broker in Openprocurement API. Defaults is DEFAULT_API_KEY (Empty string) extra_params(dict): Extra params of query :returns: iterator of tender_object (Munch): object derived from the list of tenders """ self.init_api_clients() self.start_sync() check_down_worker = True while True: if check_down_worker and self.backward_worker.ready(): if self.backward_worker.value == 0: logger.info('Stop check backward worker') check_down_worker = False else: self.restart_sync() check_down_worker = True if self.forward_worker.ready(): self.restart_sync() check_down_worker = True while not self.queue.empty(): yield self.queue.get() try: self.queue.peek(block=True, timeout=0.1) except Empty: pass def feeder(self): """ Prepare iterator for retrieving from Openprocurement API. :param: host (str): Url of Openprocurement API. Defaults is DEFAULT_API_HOST version (str): Verion of Openprocurement API. Defaults is DEFAULT_API_VERSION key(str): Access key of broker in Openprocurement API. Defaults is DEFAULT_API_KEY (Empty string) extra_params(dict): Extra params of query :returns: iterator of tender_object (Munch): object derived from the list of tenders """ self.init_api_clients() self.start_sync() check_down_worker = True while 1: if check_down_worker and self.backward_worker.ready(): if self.backward_worker.value == 0: logger.info('Stop check backward worker') check_down_worker = False else: self.restart_sync() check_down_worker = True if self.forward_worker.ready(): self.restart_sync() check_down_worker = True sleep(2) def run_feeder(self): spawn(self.feeder) return self.queue def retriever_backward(self): logger.info('Backward: Start worker') logger.debug('Backward: Start process request.') self.backward_info['status'] = PROCESS_REQUEST response = get_response(self.backward_client, self.backward_params) self.backward_info['last_response'] = datetime.now() self.backward_info['resource_item_count'] = len(response.data) if self.cookies != self.backward_client.session.cookies: raise Exception('LB Server mismatch') while response.data: self.backward_info['status'] = PROCESS_DATA logger.debug('Backward: Start process data.') self.handle_response_data(response.data) self.backward_params['offset'] = response.next_page.offset self.log_retriever_state('Backward', self.backward_client, self.backward_params) self.backward_info['status'] = PROCESS_REQUEST logger.debug('Backward: Start process request.') response = get_response(self.backward_client, self.backward_params) self.backward_info['last_response'] = datetime.now() self.backward_info['resource_item_count'] = len(response.data) if self.cookies != self.backward_client.session.cookies: raise Exception('LB Server mismatch') logger.info('Backward: pause between requests {} sec.'.format( self.retrievers_params.get('down_requests_sleep', 5))) self.backward_info['status'] = SLEEP sleep(self.retrievers_params.get('down_requests_sleep', 5)) logger.info('Backward: finished') self.backward_info['status'] = FINISHED return 0 def retriever_forward(self): logger.info('Forward: Start worker') logger.debug('Forward: Start process request.') self.forward_info['status'] = PROCESS_REQUEST response = get_response(self.forward_client, self.forward_params) self.forward_info['last_response'] = datetime.now() self.forward_info['resource_item_count'] = len(response.data) if self.cookies != self.forward_client.session.cookies: raise Exception('LB Server mismatch') while 1: while response.data: self.forward_info['status'] = PROCESS_DATA logger.debug('Forward: Start process data.') self.handle_response_data(response.data) self.forward_params['offset'] = response.next_page.offset self.log_retriever_state('Forward', self.forward_client, self.forward_params) logger.debug('Forward: Start process request.') self.forward_info['status'] = PROCESS_REQUEST response = get_response(self.forward_client, self.forward_params) self.forward_info['last_response'] = datetime.now() self.forward_info['resource_item_count'] = len(response.data) if self.cookies != self.forward_client.session.cookies: raise Exception('LB Server mismatch') if len(response.data) != 0: logger.info( 'Forward: pause between requests {} sec.'.format( self.retrievers_params.get('up_requests_sleep', 1.0))) self.forward_info['status'] = SLEEP sleep(self.retrievers_params.get('up_requests_sleep', 1.0)) self.forward_info['status'] = SLEEP logger.info('Forward: pause after empty response {} sec.'.format( self.retrievers_params.get('up_wait_sleep', 30.0))) sleep(self.retrievers_params.get('up_wait_sleep', 30.0)) self.forward_params['offset'] = response.next_page.offset self.log_retriever_state('Forward', self.forward_client, self.forward_params) logger.debug('Forward: Start process request.') self.forward_info['status'] = PROCESS_REQUEST response = get_response(self.forward_client, self.forward_params) self.forward_info['last_response'] = datetime.now() self.forward_info['resource_item_count'] = len(response.data) if self.adaptive: if len(response.data) != 0: if (self.retrievers_params['up_wait_sleep'] > self.retrievers_params['up_wait_sleep_min']): self.retrievers_params['up_wait_sleep'] -= 1 else: if self.retrievers_params['up_wait_sleep'] < 30: self.retrievers_params['up_wait_sleep'] += 1 if self.cookies != self.forward_client.session.cookies: raise Exception('LB Server mismatch') return 1 def log_retriever_state(self, name, client, params): logger.debug('{}: offset {}'.format(name, params['offset'])) logger.debug('{}: AWSELB {}'.format( name, client.session.cookies.get('AWSELB', ' '))) logger.debug('{}: SERVER_ID {}'.format( name, client.session.cookies.get('SERVER_ID', ''))) logger.debug('{}: limit {}'.format(name, params.get('limit', '')))
class CeleryReporter(StatReporter): """ A legacy wrapper around old log reporting system to allow testing PowerPool 0.6 with SimpleCoin 0.7 """ one_sec_stats = ['queued'] gl_methods = ['_queue_proc', '_report_one_min', '_report_payout_share_aggrs'] defaults = StatReporter.defaults.copy() defaults.update(dict(celery_task_prefix='simplecoin.tasks', celery={'CELERY_DEFAULT_QUEUE': 'celery'}, share_batch_interval=60)) def __init__(self, config): self._configure(config) super(CeleryReporter, self).__init__() # setup our celery agent and monkey patch from celery import Celery self.celery = Celery() self.celery.conf.update(self.config['celery']) self.queue = Queue() self._aggr_shares = {} @property def status(self): dct = dict(queue_size=self.queue.qsize(), unrep_shares=len(self._aggr_shares)) return dct def log_one_minute(self, address, worker, algo, stamp, typ, amount): self._incr('queued') kwargs = {'user': address, 'worker': worker, 'minute': stamp, 'valid_shares': 0} if typ == StratumClient.VALID_SHARE: kwargs['valid_shares'] = amount if typ == StratumClient.DUP_SHARE: kwargs['dup_shares'] = amount if typ == StratumClient.LOW_DIFF_SHARE: kwargs['low_diff_shares'] = amount if typ == StratumClient.STALE_SHARE: kwargs['stale_shares'] = amount self.queue.put(("add_one_minute", [], kwargs)) def log_share(self, client, diff, typ, params, job=None, header_hash=None, header=None, **kwargs): super(CeleryReporter, self).log_share( client, diff, typ, params, job=job, header_hash=header_hash, header=header, **kwargs) # Aggregate valid shares to be reported in batches. SimpleCoin's Celery # worker can't really handle high load share logging with the way it's # built address = client.address if typ == StratumClient.VALID_SHARE: if address not in self._aggr_shares: self._aggr_shares[address] = diff else: self._aggr_shares[address] += diff def agent_send(self, *args, **kwargs): self._incr('queued') self.queue.put(("agent_receive", args, kwargs)) def add_block(self, address, height, total_subsidy, fees, hex_bits, hex_hash, currency, algo, merged=False, worker=None, **kwargs): self._incr('queued') # user, height, total_value, transaction_fees, bits, hash_hex, merged=None, worker=None kwargs = dict(user=address, height=height, total_value=total_subsidy, transaction_fees=fees, bits=hex_bits, hash_hex=hex_hash, merged=currency if merged else None, worker=worker) self.queue.put(("add_block", [], kwargs)) @loop() def _queue_proc(self): name, args, kwargs = self.queue.peek() try: if name != "agent_receive": self.logger.info("Calling celery task {} with args: {}, kwargs: {}" .format(name, args, kwargs)) self.celery.send_task( self.config['celery_task_prefix'] + '.' + name, args, kwargs) except Exception as e: self.logger.error("Unable to communicate with celery broker! {}" .format(e)) else: self.queue.get() @loop(interval='share_batch_interval', precise=True, fin='_report_payout_shares') def _report_payout_share_aggrs(self): self._report_payout_shares() def _report_payout_shares(self, exit_exc=None, caller=None): """ Goes through our internal aggregated share data and adds a celery task for each unque address. """ self.logger.info("Reporting shares for {:,} users" .format(len(self._aggr_shares))) for address, shares in self._aggr_shares.items(): self.queue.put(("add_share", [address, shares], {})) del self._aggr_shares[address]
class CompetitiveDialogueDataBridge(object): """ Competitive Dialogue Data Bridge """ copy_name_fields = ('title_ru', 'mode', 'procurementMethodDetails', 'title_en', 'description', 'description_en', 'description_ru', 'title', 'minimalStep', 'value', 'procuringEntity', 'submissionMethodDetails') rewrite_statuses = ['draft'] allowed_statuses = [ 'active.tendering', 'active.pre-qualification', 'active.pre-qualification.stand-still', 'active.auction', 'active.qualification', 'active.awarded', 'complete', 'cancelled', 'unsuccessful', STAGE2_STATUS ] def __init__(self, config): super(CompetitiveDialogueDataBridge, self).__init__() self.config = config self.tenders_sync_client = TendersClientSync( '', host_url=self.config_get('public_tenders_api_server') or self.config_get('tenders_api_server'), api_version=self.config_get('tenders_api_version'), ) self.client = TendersClientSync( self.config_get('api_token'), host_url=self.config_get('tenders_api_server'), api_version=self.config_get('tenders_api_version'), ) self.initial_sync_point = {} self.initialization_event = gevent.event.Event() self.competitive_dialogues_queue = Queue( maxsize=500) # Id tender which need to check self.handicap_competitive_dialogues_queue = Queue(maxsize=500) self.dialogs_stage2_put_queue = Queue( maxsize=500) # queue with new tender data self.dialogs_stage2_retry_put_queue = Queue(maxsize=500) self.dialog_stage2_id_queue = Queue(maxsize=500) self.dialog_retry_stage2_id_queue = Queue(maxsize=500) self.dialogs_stage2_patch_queue = Queue(maxsize=500) self.dialogs_stage2_retry_patch_queue = Queue(maxsize=500) self.dialog_set_complete_queue = Queue(maxsize=500) self.dialog_retry_set_complete_queue = Queue(maxsize=500) self.jobs_watcher_delay = self.config_get('jobs_watcher_delay') or 15 def config_get(self, name): return self.config.get('main').get(name) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def get_tender_credentials(self, tender_id): self.client.headers.update({'X-Client-Request-ID': generate_req_id()}) logger.info("Getting credentials for tender {}".format(tender_id), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_GET_CREDENTIALS}, {"TENDER_ID": tender_id})) data = self.client.extract_credentials(tender_id) logger.info("Got tender {} credentials".format(tender_id), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_GOT_CREDENTIALS}, {"TENDER_ID": tender_id})) return data @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def initialize_sync(self, params=None, direction=None): # TODO use gevent.Event to wake up forward sync instead of checking # initial sync point if direction == "backward": assert params['descending'] response = self.tenders_sync_client.sync_tenders( params, extra_headers={'X-Client-Request-ID': generate_req_id()}) # set values in reverse order due to 'descending' option self.initial_sync_point = { 'forward_offset': response.prev_page.offset, 'backward_offset': response.next_page.offset } self.initialization_event.set() logger.info("Initial sync point {}".format( self.initial_sync_point)) return response elif not self.initial_sync_point: raise ValueError else: assert 'descending' not in params gevent.wait([self.initialization_event]) self.initialization_event.clear() params['offset'] = self.initial_sync_point['forward_offset'] logger.info("Starting forward sync from offset {}".format( params['offset'])) return self.tenders_sync_client.sync_tenders( params, extra_headers={'X-Client-Request-ID': generate_req_id()}) def get_tenders(self, params, direction=""): response = self.initialize_sync(params=params, direction=direction) while not (params.get('descending') and not len(response.data) and params.get('offset') == response.next_page.offset): tenders_list = response.data params['offset'] = response.next_page.offset delay = 101 if tenders_list: delay = 15 logger.info("Client {} params: {}".format(direction, params)) for tender in tenders_list: # Check, if we already work with this tender if tender['id'] in dialog_work: logger.info('WORK with tender {}'.format(tender['id'])) continue if tender['procurementMethodType'] in [ CD_UA_TYPE, CD_EU_TYPE ] and tender['status'] == 'active.stage2.waiting': logger.info( '{0} sync: Found competitive dialogue (stage1), id={1} with status {2}' .format(direction.capitalize(), tender['id'], tender['status']), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_FOUND_NOLOT}, {"TENDER_ID": tender['id']})) yield tender else: logger.debug( '{0} sync: Skipping tender {1} in status {2} with procurementMethodType {3}' .format(direction.capitalize(), tender['id'], tender['status'], tender['procurementMethodType']), extra=journal_context( params={"TENDER_ID": tender['id']})) logger.info('Sleep {} sync...'.format(direction), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_SYNC_SLEEP})) gevent.sleep(delay) logger.info('Restore {} sync'.format(direction), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_SYNC_RESUME})) logger.debug('{} {}'.format(direction, params)) response = self.tenders_sync_client.sync_tenders( params, extra_headers={'X-Client-Request-ID': generate_req_id()}) def get_competitive_dialogue_data(self): while True: try: tender_to_sync = self.competitive_dialogues_queue.peek( ) # Get competitive dialogue which we want to sync tender = self.tenders_sync_client.get_tender( tender_to_sync['id'])['data'] # Try get data by tender id except Exception, e: # If we have something problems then put tender back to queue logger.exception(e) logger.info('Put tender {} back to tenders queue'.format( tender_to_sync['id']), extra=journal_context( params={"TENDER_ID": tender_to_sync['id']})) self.competitive_dialogues_queue.put(tender_to_sync) else: if 'stage2TenderID' in tender: try: tender_stage2 = self.tenders_sync_client.get_tender( tender['stage2TenderID'])['data'] except: logger.info( 'Tender stage 2 id={0} didn\'t exist, need create new' .format(tender['id']), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_TENDER_STAGE2_NOT_EXIST }, {"TENDER_ID": tender['id']})) else: if tender_stage2.get( 'status') in self.allowed_statuses: logger.info( 'For dialog {0} tender stage 2 already exists, need only patch' .format(tender['id']), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_ONLY_PATCH}, {"TENDER_ID": tender['id']})) patch_data = { "id": tender['id'], "status": "complete" } self.dialog_set_complete_queue.put(patch_data) continue elif tender_stage2.get( 'status') in self.rewrite_statuses: logger.info( 'Tender stage 2 id={0} has bad status need to create new ' .format(tender['id']), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_CREATE_NEW_STAGE2 }, {"TENDER_ID": tender['id']})) logger.info('Copy competitive dialogue data, id={} '.format( tender['id']), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_COPY_TENDER_ITEMS}, {"TENDER_ID": tender['id']})) new_tender = dict(title=tender['title'], procurementMethod='selective', status='draft', dialogueID=tender['id']) for field_name in self.copy_name_fields: # Copy fields from stage 1 competitive dialog if field_name in tender: new_tender[field_name] = tender[field_name] if tender['procurementMethodType'].endswith('EU'): new_tender['procurementMethodType'] = STAGE_2_EU_TYPE else: new_tender['procurementMethodType'] = STAGE_2_UA_TYPE new_tender['tenderID'] = '{}.2'.format( tender['tenderID']) # set tenderID as in stage1 + '.2' old_lots, items, short_listed_firms = dict(), list(), dict() for qualification in tender['qualifications']: if qualification[ 'status'] == 'active': # check if qualification has status active if qualification.get('lotID'): if qualification[ 'lotID'] not in old_lots: # check if lot id in local dict with new lots lot = prepare_lot( tender, qualification['lotID'], items) # update lot with new id if not lot: # Go next iter if not lot continue old_lots[qualification[ 'lotID']] = lot # set new lot in local dict bid = get_bid_by_id(tender['bids'], qualification['bidID']) for bid_tender in bid['tenderers']: if bid_tender['identifier'][ 'id'] not in short_listed_firms: short_listed_firms[ bid_tender['identifier']['id']] = { "name": bid_tender['name'], "identifier": bid_tender['identifier'], "lots": [{ "id": old_lots[qualification[ 'lotID']]['id'] }] } else: short_listed_firms[bid_tender[ 'identifier']['id']]['lots'].append({ "id": old_lots[qualification['lotID']] ['id'] }) else: new_tender['items'] = copy.deepcopy( tender['items']) # add all items, with new id bid = get_bid_by_id(tender['bids'], qualification['bidID']) for bid_tender in bid['tenderers']: if bid_tender['identifier'][ 'id'] not in short_listed_firms: short_listed_firms[ bid_tender['identifier']['id']] = { "name": bid_tender['name'], "identifier": bid_tender['identifier'], "lots": [] } if items: # If we have lots, then add only related items new_tender['items'] = items new_tender['lots'] = old_lots.values() if 'features' in tender: new_tender['features'] = [] for feature in tender.get('features'): if feature[ 'featureOf'] == 'tenderer': # If feature related to tender, than just copy new_tender['features'].append(feature) elif feature[ 'featureOf'] == 'item': # If feature related to item need check if it's actual if feature['relatedItem'] in ( item['id'] for item in new_tender['items']): new_tender['features'].append(feature) elif feature[ 'featureOf'] == 'lot': # If feature related to lot need check if it's actual if feature['relatedItem'] in old_lots.keys(): new_tender['features'].append(feature) new_tender['shortlistedFirms'] = short_listed_firms.values() self.competitive_dialogues_queue.get() self.handicap_competitive_dialogues_queue.put(new_tender)
class Balancer(object): def __init__(self, dispatcher): self.dispatcher = dispatcher self.task_list = [] self.task_queue = Queue() self.resource_graph = dispatcher.resource_graph self.threads = [] self.executors = [] self.logger = logging.getLogger("Balancer") self.dispatcher.require_collection("tasks", "serial", type="log") self.create_initial_queues() self.start_executors() self.schedule_lock = RLock() self.distribution_lock = RLock() self.debugger = None self.debugged_tasks = None self.dispatcher.register_event_type("task.changed") # Lets try to get `EXECUTING|WAITING|CREATED` state tasks # from the previous dispatcher instance and set their # states to 'FAILED' since they are no longer running # in this instance of the dispatcher for stale_task in dispatcher.datastore.query("tasks", ("state", "in", ["EXECUTING", "WAITING", "CREATED"])): self.logger.info( "Stale task ID: {0}, name: {1} being set to FAILED".format(stale_task["id"], stale_task["name"]) ) stale_task.update( { "state": "FAILED", "error": { "type": "TaskException", "message": "dispatcher process died", "code": errno.EINTR, "stacktrace": "", "extra": None, }, } ) dispatcher.datastore.update("tasks", stale_task["id"], stale_task) def create_initial_queues(self): self.resource_graph.add_resource(Resource("system")) def start_executors(self): for i in range(0, self.dispatcher.configstore.get("middleware.executors_count")): self.logger.info("Starting task executor #{0}...".format(i)) self.executors.append(TaskExecutor(self, i)) def start(self): self.threads.append(gevent.spawn(self.distribution_thread)) self.logger.info("Started") def schema_to_list(self, schema): return { "type": "array", "items": schema, "minItems": sum([1 for x in schema if "mandatory" in x and x["mandatory"]]), "maxItems": len(schema), } def verify_schema(self, clazz, args, strict=False): if not hasattr(clazz, "params_schema"): return [] schema = self.schema_to_list(clazz.params_schema) val = validator.create_validator(schema, resolver=self.dispatcher.rpc.get_schema_resolver(schema)) if strict: val.fail_read_only = True else: val.remove_read_only = True return list(val.iter_errors(args)) def submit(self, name, args, sender, env=None): if name not in self.dispatcher.tasks: self.logger.warning("Cannot submit task: unknown task type %s", name) raise RpcException(errno.EINVAL, "Unknown task type {0}".format(name)) task = Task(self.dispatcher, name) task.user = sender.user.name task.session_id = sender.session_id task.created_at = datetime.utcnow() task.clazz = self.dispatcher.tasks[name] task.hooks = self.dispatcher.task_hooks.get(name, {}) task.args = copy.deepcopy(args) task.strict_verify = "strict_validation" in sender.enabled_features if env: if not isinstance(env, dict): raise ValueError("env must be a dict") task.environment = copy.deepcopy(env) if self.debugger: for m in self.debugged_tasks: if fnmatch.fnmatch(name, m): task.debugger = self.debugger if "RUN_AS_USER" in task.environment: task.user = task.environment["RUN_AS_USER"] task.environment["SENDER_ADDRESS"] = sender.client_address task.id = self.dispatcher.datastore.insert("tasks", task) task.set_state(TaskState.CREATED) self.task_queue.put(task) self.logger.info("Task %d submitted (type: %s, class: %s)", task.id, name, task.clazz) return task.id def submit_with_upload(self, task_name, args, sender, env=None): task_metadata = self.dispatcher.tasks[task_name]._get_metadata() schema = task_metadata["schema"] if schema is None: raise RpcException(errno.ENOENT, "Task {0} has no schema associated with it".format(task_name)) upload_token_list = [] for idx, arg in enumerate(schema): if arg.get("type") == "fd": rfd, wfd = os.pipe() token = self.dispatcher.token_store.issue_token( FileToken( user=sender.user, lifetime=60, direction="upload", file=FileObjectPosix(wfd, "wb", close=True), name=str(uuid.uuid4()), size=None, ) ) upload_token_list.append(token) args[idx] = FileDescriptor(rfd) task_id = self.submit(task_name, args, sender, env) return task_id, upload_token_list def submit_with_download(self, task_name, args, sender, env=None): task_metadata = self.dispatcher.tasks[task_name]._get_metadata() schema = task_metadata["schema"] url_list = [] if schema is None: raise RpcException(errno.ENOENT, "Task {0} has no schema associated with it".format(task_name)) for idx, arg in enumerate(schema): if arg.get("type") == "fd": rfd, wfd = os.pipe() url_list.append( "/dispatcher/filedownload?token={0}".format( self.dispatcher.token_store.issue_token( FileToken( user=sender.user, lifetime=60, direction="download", file=FileObjectPosix(rfd, "rb", close=True), name=args[idx], ) ) ) ) args[idx] = FileDescriptor(wfd) task_id = self.submit(task_name, args, sender, env) return task_id, url_list def verify_subtask(self, parent, name, args): clazz = self.dispatcher.tasks[name] instance = clazz(self.dispatcher, self.dispatcher.datastore) return instance.verify(*args) def run_subtask(self, parent, name, args, env=None): args = list(args) task = Task(self.dispatcher, name) task.created_at = datetime.utcnow() task.clazz = self.dispatcher.tasks[name] task.hooks = self.dispatcher.task_hooks.get(name, {}) task.args = args task.instance = task.clazz(self.dispatcher, self.dispatcher.datastore) task.instance.verify(*task.args) task.description = task.instance.describe(*task.args) task.id = self.dispatcher.datastore.insert("tasks", task) task.parent = parent task.environment = {} if parent: task.environment = copy.deepcopy(parent.environment) task.environment["parent"] = parent.id task.user = parent.user if env: if not isinstance(env, dict): raise ValueError("env must be a dict") task.environment.update(env) if self.debugger: for m in self.debugged_tasks: if fnmatch.fnmatch(name, m): task.debugger = self.debugger task.set_state(TaskState.CREATED) self.task_list.append(task) task.start() return task def join_subtasks(self, *tasks): for i in tasks: i.join() def abort(self, id, error=None): task = self.get_task(id) if not task: self.logger.warning("Cannot abort task: unknown task id %d", id) return success = False if task.started_at is None: success = True else: try: task.executor.abort() except: pass if success: task.ended.set() if error: task.set_state(TaskState.FAILED, TaskStatus(0), serialize_error(error)) self.logger.debug("Task ID: %d, name: %s aborted with error", task.id, task.name) else: task.set_state(TaskState.ABORTED, TaskStatus(0, "Aborted")) self.logger.debug("Task ID: %d, name: %s aborted by user", task.id, task.name) def task_exited(self, task): self.resource_graph.release(*task.resources) self.schedule_tasks(True) def schedule_tasks(self, exit=False): """ This function is called when: 1) any new task is submitted to any of the queues 2) any task exists """ with self.schedule_lock: started = 0 executing_tasks = [t for t in self.task_list if t.state == TaskState.EXECUTING] waiting_tasks = [t for t in self.task_list if t.state == TaskState.WAITING] for task in waiting_tasks: if not self.resource_graph.can_acquire(*task.resources): continue self.resource_graph.acquire(*task.resources) self.threads.append(task.start()) started += 1 if not started and not executing_tasks and (exit or len(waiting_tasks) == 1): for task in waiting_tasks: # Check whether or not task waits on nonexistent resources. If it does, # abort it 'cause there's no chance anymore that missing resources will appear. if any(self.resource_graph.get_resource(res) is None for res in task.resources): self.logger.warning("Aborting task {0}: deadlock".format(task.id)) self.abort(task.id, VerifyException(errno.EBUSY, "Resource deadlock avoided")) def distribution_thread(self): while True: self.task_queue.peek() self.distribution_lock.acquire() task = self.task_queue.get() try: self.logger.debug("Picked up task %d: %s with args %s", task.id, task.name, task.args) errors = self.verify_schema(self.dispatcher.tasks[task.name], task.args, task.strict_verify) if len(errors) > 0: errors = list(validator.serialize_errors(errors)) self.logger.warning( "Cannot submit task {0}: schema verification failed with errors {1}".format(task.name, errors) ) raise ValidationException(extra=errors) task.instance = task.clazz(self.dispatcher, self.dispatcher.datastore) task.resources = task.instance.verify(*task.args) task.description = task.instance.describe(*task.args) if type(task.resources) is not list: raise ValueError("verify() returned something else than resource list") except Exception as err: self.logger.warning("Cannot verify task %d: %s", task.id, err) task.set_state(TaskState.FAILED, TaskStatus(0), serialize_error(err)) task.ended.set() self.distribution_lock.release() if not isinstance(err, VerifyException): self.dispatcher.report_error("Task {0} verify() method raised invalid exception".format(err), err) continue task.set_state(TaskState.WAITING) self.task_list.append(task) self.distribution_lock.release() self.schedule_tasks() if task.resources: self.logger.debug("Task %d assigned to resources %s", task.id, ",".join(task.resources)) def assign_executor(self, task): for i in self.executors: with i.cv: if i.state == WorkerState.IDLE: self.logger.info("Task %d assigned to executor #%d", task.id, i.index) task.executor = i i.state = WorkerState.ASSIGNED return # Out of executors! Need to spawn new one executor = TaskExecutor(self, len(self.executors)) self.executors.append(executor) with executor.cv: executor.cv.wait_for(lambda: executor.state == WorkerState.IDLE) executor.state = WorkerState.ASSIGNED task.executor = executor self.logger.info("Task %d assigned to executor #%d", task.id, executor.index) def dispose_executors(self): for i in self.executors: i.die() def get_active_tasks(self): return [x for x in self.task_list if x.state in (TaskState.CREATED, TaskState.WAITING, TaskState.EXECUTING)] def get_tasks(self, type=None): if type is None: return self.task_list return [x for x in self.task_list if x.state == type] def get_task(self, id): self.distribution_lock.acquire() t = first_or_default(lambda x: x.id == id, self.task_list) if not t: t = first_or_default(lambda x: x.id == id, self.task_queue.queue) self.distribution_lock.release() return t def get_executor_by_key(self, key): return first_or_default(lambda t: t.key == key, self.executors) def get_executor_by_sender(self, sender): return first_or_default(lambda t: t.conn == sender, self.executors)
class UploadFile(Greenlet): """ Upload file with details """ def __init__(self, client, upload_to_doc_service_queue, upload_to_tender_queue, process_tracker, doc_service_client, services_not_available, sleep_change_value, delay=15): super(UploadFile, self).__init__() self.exit = False self.start_time = datetime.now() self.delay = delay self.process_tracker = process_tracker # init clients self.client = client self.doc_service_client = doc_service_client # init queues for workers self.upload_to_doc_service_queue = upload_to_doc_service_queue self.upload_to_tender_queue = upload_to_tender_queue self.sleep_change_value = sleep_change_value # retry queues for workers self.retry_upload_to_doc_service_queue = Queue(maxsize=500) self.retry_upload_to_tender_queue = Queue(maxsize=500) # blockers self.services_not_available = services_not_available def removing_data(self, retry, re, tender_data, document_id, item_name_id): logger.warning( "Accept {} while uploading to {} doc_id: {}. Message {}".format( re.status_int, data_string(tender_data), document_id, re.msg), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_ITEM_STATUS_CHANGED_WHILE_PROCESSING }, { "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) self.process_tracker.update_items_and_tender(tender_data.tender_id, tender_data.item_id) self.sleep_change_value.decrement() if retry == '': self.upload_to_tender_queue.get() elif retry == 'retry': self.retry_upload_to_tender_queue.get() def decrease_request_frequency(self, re, tender_data, document_id, item_name_id): logger.info( "Accept 429 while uploading to tender {} {} {} doc_id: {}. Message {}" .format(tender_data.tender_id, tender_data.item_name, tender_data.item_id, document_id, re.msg), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_ITEM_STATUS_CHANGED_WHILE_PROCESSING }, { "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) self.sleep_change_value.increment() def resource_errors_else(self, retry, re, tender_data, document_id, item_name_id): logger.info( 'ResourceError while{} uploading file to {} doc_id: {}. ResourceErrorStatus_int: {}. Message: {}' .format('' if retry == '' else ' ' + retry, data_string(tender_data), document_id, re.status_int, re.message), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_TENDER.format( '' if retry == '' else '_' + retry) }, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) self.sleep_change_value.decrement() def exception_errors(self, retry, e, tender_data, document_id, item_name_id): logger.info( 'Exception while{} uploading file to {} doc_id: {}. Message: {}'. format('' if retry == '' else ' ' + retry, data_string(tender_data), document_id, e.message), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_TENDER.format( '' if retry == '' else '_' + retry) }, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) logger.exception("Message: {}".format(e.message)) self.sleep_change_value.decrement() def succesfully_uploaded_to_tender(self, retry, tender_data, document_id, item_name_id): logger.info( 'Successfully uploaded file to {} doc_id: {} in retry'.format( data_string(tender_data), document_id), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_SUCCESS_UPLOAD_TO_TENDER}, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) # delete current tender after successful upload file (to avoid reloading file) self.process_tracker.update_items_and_tender(tender_data.tender_id, tender_data.item_id) self.sleep_change_value.decrement() if retry == '': self.upload_to_tender_queue.get() elif retry == 'retry': self.retry_upload_to_tender_queue.get() def move_to_tender_queue(self, retry, tender_data, response, document_id, item_name_id): data = Data(tender_data.tender_id, tender_data.item_id, tender_data.code, tender_data.item_name, dict(response.json(), **{'meta': { 'id': document_id }})) self.upload_to_tender_queue.put(data) if retry == '': self.upload_to_doc_service_queue.get() elif retry == 'retry': self.retry_upload_to_doc_service_queue.get() logger.info( 'Successfully uploaded file to doc service {} doc_id: {}'.format( data_string(tender_data), document_id), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_SUCCESS_UPLOAD_TO_DOC_SERVICE}, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) def upload_to_doc_service(self): """Get data from upload_to_doc_service_queue; Create file of the Data.file_content data; If upload successful put Data object to upload_file_to_tender, otherwise put Data to retry_upload_file_queue.""" while not self.exit: self.services_not_available.wait() try: tender_data = self.upload_to_doc_service_queue.peek() document_id = tender_data.file_content.get('meta', {}).get('id') except LoopExit: gevent.sleep(0) continue item_name_id = tender_data.item_name[:-1].upper() + "_ID" try: response = self.doc_service_client.upload( file_name, create_file(tender_data.file_content), 'application/yaml', headers={'X-Client-Request-ID': document_id}) except Exception as e: logger.warning( 'Exception while uploading file to doc service {}. Message: {}. ' 'Put tender_data to retry queue '.format( data_string(tender_data), e.message), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_DOC_SERVICE }, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) logger.exception("Message: {}".format(e.message)) self.retry_upload_to_doc_service_queue.put(tender_data) self.upload_to_doc_service_queue.get() else: if response.status_code == 200: self.move_to_tender_queue('', tender_data, response, document_id, item_name_id) else: logger.info( 'Not successful response from document service while uploading {} doc_id: {}. Response {}' .format(data_string(tender_data), document_id, response.status_code), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_DOC_SERVICE }, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) self.retry_upload_to_doc_service_queue.put(tender_data) self.upload_to_doc_service_queue.get() gevent.sleep(0) def retry_upload_to_doc_service(self): """Get data from retry_upload_to_doc_service_queue; If upload were successful put Data obj to upload_to_tender_queue, otherwise put Data obj back to retry_upload_file_queue""" while not self.exit: self.services_not_available.wait() try: tender_data = self.retry_upload_to_doc_service_queue.peek() document_id = tender_data.file_content.get('meta', {}).get('id') except LoopExit: gevent.sleep(0) continue item_name_id = tender_data.item_name[:-1].upper() + "_ID" try: # create patch request to award/qualification with document to upload self.client.headers.update( {'X-Client-Request-ID': document_id}) response = self.client_upload_to_doc_service(tender_data) except Exception as e: logger.warning( 'Exception while uploading file to doc service {} doc_id: {}. Message: {}. ' 'Lost tender_data'.format(data_string(tender_data), document_id, e.message), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_DOC_SERVICE }, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) logger.exception("Message: {}".format(e.message)) self.retry_upload_to_doc_service_queue.get() self.process_tracker.update_items_and_tender( tender_data.tender_id, tender_data.item_id) raise e else: if response.status_code == 200: self.move_to_tender_queue('retry', tender_data, response, document_id, item_name_id) else: logger.info( 'Not successful response in retry from document service while uploading {} {} {} {}. Response {}' .format(tender_data.tender_id, tender_data.item_name, tender_data.item_id, document_id, response.status_code), extra=journal_context( { "MESSAGE_ID": DATABRIDGE_UNSUCCESS_UPLOAD_TO_DOC_SERVICE. format('_retry') }, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) gevent.sleep(0) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=retry_mult) def client_upload_to_doc_service(self, tender_data): """Process upload request for retry queue objects.""" return self.doc_service_client.upload( file_name, create_file(tender_data.file_content), 'application/yaml', headers={ 'X-Client-Request-ID': tender_data.file_content.get('meta', {}).get('id') }) def upload_to_tender(self): """Get data from upload_to_tender_queue; Upload get_Url and documentType; If upload to tender were unsuccessful put Data object to retry_upload_to_tender_queue, otherwise delete given award/qualification from processing_items.""" while not self.exit: self.services_not_available.wait() try: tender_data = self.upload_to_tender_queue.peek() except LoopExit: gevent.sleep(0) continue document_data = tender_data.file_content.get('data', {}) document_id = tender_data.file_content.get('meta', {}).get('id') document_data["documentType"] = "registerExtract" item_name_id = tender_data.item_name[:-1].upper() + "_ID" try: self.client.headers.update( {'X-Client-Request-ID': document_id}) self.client._create_tender_resource_item( munchify({'data': { 'id': tender_data.tender_id }}), {'data': document_data}, '{}/{}/documents'.format(tender_data.item_name, tender_data.item_id)) except ResourceError as re: if re.status_int == 403 or re.status_int == 422 or re.status_int is None: self.removing_data('', re, tender_data, document_id, item_name_id) elif re.status_int == 429: self.decrease_request_frequency(re, tender_data, document_id, item_name_id) else: self.resource_errors_else('', re, tender_data, document_id, item_name_id) self.retry_upload_to_tender_queue.put(tender_data) self.upload_to_tender_queue.get() except Exception as e: self.exception_errors('', e, tender_data, document_id, item_name_id) self.retry_upload_to_tender_queue.put(tender_data) self.upload_to_tender_queue.get() else: self.succesfully_uploaded_to_tender('', tender_data, document_id, item_name_id) gevent.sleep(self.sleep_change_value.time_between_requests) def retry_upload_to_tender(self): """Get data from retry_upload_to_tender_queue; If upload was unsuccessful put Data obj back to retry_upload_to_tender_queue""" while not self.exit: self.services_not_available.wait() try: tender_data = self.retry_upload_to_tender_queue.peek() except LoopExit: gevent.sleep(0) continue document_id = tender_data.file_content.get('meta', {}).get('id') self.client.headers.update({'X-Client-Request-ID': document_id}) item_name_id = tender_data.item_name[:-1].upper() + "_ID" try: self.client_upload_to_tender(tender_data) except ResourceError as re: if re.status_int == 403 or re.status_int == 422 or re.status_int is None: self.removing_data('retry', re, tender_data, document_id, item_name_id) elif re.status_int == 429: self.decrease_request_frequency(re, tender_data, document_id, item_name_id) else: self.resource_errors_else('retry', re, tender_data, document_id, item_name_id) except Exception as e: self.exception_errors('retry', e, tender_data, document_id, item_name_id) else: self.succesfully_uploaded_to_tender('retry', tender_data, document_id, item_name_id) gevent.sleep(self.sleep_change_value.time_between_requests) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=retry_mult) def client_upload_to_tender(self, tender_data): """Process upload to tender request for retry queue objects.""" document_data = tender_data.file_content.get('data', {}) document_data["documentType"] = "registerExtract" self.client.headers.update({ 'X-Client-Request-ID': tender_data.file_content.get('meta', {}).get('id') }) self.client._create_tender_resource_item( munchify({'data': { 'id': tender_data.tender_id }}), {'data': document_data}, '{}/{}/documents'.format(tender_data.item_name, tender_data.item_id)) def _run(self): logger.info('Start UploadFile worker', extra=journal_context( {"MESSAGE_ID": DATABRIDGE_START_UPLOAD}, {})) self.immortal_jobs = { 'upload_to_doc_service': spawn(self.upload_to_doc_service), 'upload_to_tender': spawn(self.upload_to_tender), 'retry_upload_to_doc_service': spawn(self.retry_upload_to_doc_service), 'retry_upload_to_tender': spawn(self.retry_upload_to_tender) } try: while not self.exit: gevent.sleep(self.delay) for name, job in self.immortal_jobs.items(): if job.dead: logger.warning( "{} worker dead try restart".format(name), extra=journal_context( { "MESSAGE_ID": 'DATABRIDGE_RESTART_{}'.format( name.lower()) }, {})) self.immortal_jobs[name] = gevent.spawn( getattr(self, name)) logger.info("{} worker is up".format(name)) except Exception as e: logger.error(e) gevent.killall(self.immortal_jobs.values(), timeout=5) def shutdown(self): self.exit = True logger.info('Worker UploadFile complete his job.')
class ChainService(WiredService): """ Manages the chain and requests to it. """ # required by BaseService name = 'chain' default_config = dict(eth=dict(network_id=0, genesis='', pruning=-1), block=ethereum_config.default_config) # required by WiredService wire_protocol = eth_protocol.ETHProtocol # create for each peer # initialized after configure: chain = None genesis = None synchronizer = None config = None block_queue_size = 1024 transaction_queue_size = 1024 processed_gas = 0 processed_elapsed = 0 def __init__(self, app): self.config = app.config sce = self.config['eth'] if int(sce['pruning']) >= 0: self.db = RefcountDB(app.services.db) if "I am not pruning" in self.db.db: raise Exception("This database was initialized as non-pruning." " Kinda hard to start pruning now.") self.db.ttl = int(sce['pruning']) self.db.db.put("I am pruning", "1") else: self.db = app.services.db if "I am pruning" in self.db: raise Exception("This database was initialized as pruning." " Kinda hard to stop pruning now.") self.db.put("I am not pruning", "1") if 'network_id' in self.db: db_network_id = self.db.get('network_id') if db_network_id != str(sce['network_id']): raise Exception( "This database was initialized with network_id {} " "and can not be used when connecting to network_id {}". format(db_network_id, sce['network_id'])) else: self.db.put('network_id', str(sce['network_id'])) self.db.commit() assert self.db is not None super(ChainService, self).__init__(app) log.info('initializing chain') coinbase = app.services.accounts.coinbase env = Env(self.db, sce['block']) self.chain = Chain(env, new_head_cb=self._on_new_head, coinbase=coinbase) log.info('chain at', number=self.chain.head.number) if 'genesis_hash' in sce: assert sce['genesis_hash'] == self.chain.genesis.hex_hash() self.synchronizer = Synchronizer(self, force_sync=None) self.block_queue = Queue(maxsize=self.block_queue_size) self.transaction_queue = Queue(maxsize=self.transaction_queue_size) self.add_blocks_lock = False self.add_transaction_lock = gevent.lock.Semaphore() self.broadcast_filter = DuplicatesFilter() self.on_new_head_cbs = [] self.on_new_head_candidate_cbs = [] self.newblock_processing_times = deque(maxlen=1000) @property def is_syncing(self): return self.synchronizer.synctask is not None @property def is_mining(self): if 'pow' in self.app.services: return self.app.services.pow.active return False def _on_new_head(self, block): # DEBUG('new head cbs', len(self.on_new_head_cbs)) for cb in self.on_new_head_cbs: cb(block) self._on_new_head_candidate( ) # we implicitly have a new head_candidate def _on_new_head_candidate(self): # DEBUG('new head candidate cbs', len(self.on_new_head_candidate_cbs)) for cb in self.on_new_head_candidate_cbs: cb(self.chain.head_candidate) def add_transaction(self, tx, origin=None): if self.is_syncing: return # we can not evaluate the tx based on outdated state log.debug('add_transaction', locked=self.add_transaction_lock.locked(), tx=tx) assert isinstance(tx, Transaction) assert origin is None or isinstance(origin, BaseProtocol) if tx.hash in self.broadcast_filter: log.debug('discarding known tx') # discard early return # validate transaction try: validate_transaction(self.chain.head_candidate, tx) log.debug('valid tx, broadcasting') self.broadcast_transaction(tx, origin=origin) # asap except InvalidTransaction as e: log.debug('invalid tx', error=e) return if origin is not None: # not locally added via jsonrpc if not self.is_mining or self.is_syncing: log.debug('discarding tx', syncing=self.is_syncing, mining=self.is_mining) return self.add_transaction_lock.acquire() success = self.chain.add_transaction(tx) self.add_transaction_lock.release() if success: self._on_new_head_candidate() def add_block(self, t_block, proto): "adds a block to the block_queue and spawns _add_block if not running" self.block_queue.put((t_block, proto)) # blocks if full if not self.add_blocks_lock: self.add_blocks_lock = True # need to lock here (ctx switch is later) gevent.spawn(self._add_blocks) def add_mined_block(self, block): log.debug('adding mined block', block=block) assert isinstance(block, Block) assert block.header.check_pow() if self.chain.add_block(block): log.debug('added', block=block, ts=time.time()) assert block == self.chain.head self.broadcast_newblock(block, chain_difficulty=block.chain_difficulty()) def knows_block(self, block_hash): "if block is in chain or in queue" if block_hash in self.chain: return True # check if queued or processed for i in range(len(self.block_queue.queue)): if block_hash == self.block_queue.queue[i][0].header.hash: return True return False def _add_blocks(self): log.debug('add_blocks', qsize=self.block_queue.qsize(), add_tx_lock=self.add_transaction_lock.locked()) assert self.add_blocks_lock is True self.add_transaction_lock.acquire() try: while not self.block_queue.empty(): t_block, proto = self.block_queue.peek( ) # peek: knows_block while processing if t_block.header.hash in self.chain: log.warn('known block', block=t_block) self.block_queue.get() continue if t_block.header.prevhash not in self.chain: log.warn('missing parent', block=t_block, head=self.chain.head) self.block_queue.get() continue # FIXME, this is also done in validation and in synchronizer for new_blocks if not t_block.header.check_pow(): log.warn('invalid pow', block=t_block, FIXME='ban node') sentry.warn_invalid(t_block, 'InvalidBlockNonce') self.block_queue.get() continue try: # deserialize st = time.time() block = t_block.to_block(env=self.chain.env) elapsed = time.time() - st log.debug('deserialized', elapsed='%.4fs' % elapsed, ts=time.time(), gas_used=block.gas_used, gpsec=self.gpsec(block.gas_used, elapsed)) except processblock.InvalidTransaction as e: log.warn('invalid transaction', block=t_block, error=e, FIXME='ban node') errtype = \ 'InvalidNonce' if isinstance(e, InvalidNonce) else \ 'NotEnoughCash' if isinstance(e, InsufficientBalance) else \ 'OutOfGasBase' if isinstance(e, InsufficientStartGas) else \ 'other_transaction_error' sentry.warn_invalid(t_block, errtype) self.block_queue.get() continue except VerificationFailed as e: log.warn('verification failed', error=e, FIXME='ban node') sentry.warn_invalid(t_block, 'other_block_error') self.block_queue.get() continue # Check canary score = 0 for address in canary_addresses: if block.get_storage_data(address, 1) > 0: score += 1 if score >= 2: log.warn('canary triggered') continue # All checks passed log.debug('adding', block=block, ts=time.time()) if self.chain.add_block( block, forward_pending_transactions=self.is_mining): now = time.time() log.info('added', block=block, txs=block.transaction_count, gas_used=block.gas_used) if t_block.newblock_timestamp: total = now - t_block.newblock_timestamp self.newblock_processing_times.append(total) avg = statistics.mean(self.newblock_processing_times) med = statistics.median(self.newblock_processing_times) max_ = max(self.newblock_processing_times) min_ = min(self.newblock_processing_times) log.info('processing time', last=total, avg=avg, max=max_, min=min_, median=med) else: log.warn('could not add', block=block) self.block_queue.get( ) # remove block from queue (we peeked only) gevent.sleep(0.001) finally: self.add_blocks_lock = False self.add_transaction_lock.release() def gpsec(self, gas_spent=0, elapsed=0): if gas_spent: self.processed_gas += gas_spent self.processed_elapsed += elapsed return int(self.processed_gas / (0.001 + self.processed_elapsed)) def broadcast_newblock(self, block, chain_difficulty=None, origin=None): if not chain_difficulty: assert block.hash in self.chain chain_difficulty = block.chain_difficulty() assert isinstance(block, (eth_protocol.TransientBlock, Block)) if self.broadcast_filter.update(block.header.hash): log.debug('broadcasting newblock', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'newblock', args=(block, chain_difficulty), exclude_peers=[origin.peer] if origin else []) else: log.debug('already broadcasted block') def broadcast_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) if self.broadcast_filter.update(tx.hash): log.debug('broadcasting tx', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'transactions', args=(tx, ), exclude_peers=[origin.peer] if origin else []) else: log.debug('already broadcasted tx') # wire protocol receivers ########### def on_wire_protocol_start(self, proto): log.debug('----------------------------------') log.debug('on_wire_protocol_start', proto=proto) assert isinstance(proto, self.wire_protocol) # register callbacks proto.receive_status_callbacks.append(self.on_receive_status) proto.receive_transactions_callbacks.append( self.on_receive_transactions) proto.receive_getblockhashes_callbacks.append( self.on_receive_getblockhashes) proto.receive_blockhashes_callbacks.append(self.on_receive_blockhashes) proto.receive_getblocks_callbacks.append(self.on_receive_getblocks) proto.receive_blocks_callbacks.append(self.on_receive_blocks) proto.receive_newblock_callbacks.append(self.on_receive_newblock) proto.receive_newblockhashes_callbacks.append(self.on_newblockhashes) # send status head = self.chain.head proto.send_status(chain_difficulty=head.chain_difficulty(), chain_head_hash=head.hash, genesis_hash=self.chain.genesis.hash) def on_wire_protocol_stop(self, proto): assert isinstance(proto, self.wire_protocol) log.debug('----------------------------------') log.debug('on_wire_protocol_stop', proto=proto) def on_receive_status(self, proto, eth_version, network_id, chain_difficulty, chain_head_hash, genesis_hash): log.debug('----------------------------------') log.debug('status received', proto=proto, eth_version=eth_version) assert eth_version == proto.version, (eth_version, proto.version) if network_id != self.config['eth'].get('network_id', proto.network_id): log.warn("invalid network id", remote_network_id=network_id, expected_network_id=self.config['eth'].get( 'network_id', proto.network_id)) raise eth_protocol.ETHProtocolError('wrong network_id') # check genesis if genesis_hash != self.chain.genesis.hash: log.warn("invalid genesis hash", remote_id=proto, genesis=genesis_hash.encode('hex')) raise eth_protocol.ETHProtocolError('wrong genesis block') # request chain self.synchronizer.receive_status(proto, chain_head_hash, chain_difficulty) # send transactions transactions = self.chain.get_transactions() if transactions: log.debug("sending transactions", remote_id=proto) proto.send_transactions(*transactions) # transactions def on_receive_transactions(self, proto, transactions): "receives rlp.decoded serialized" log.debug('----------------------------------') log.debug('remote_transactions_received', count=len(transactions), remote_id=proto) for tx in transactions: self.add_transaction(tx, origin=proto) # blockhashes ########### def on_newblockhashes(self, proto, newblockhashes): """ msg sent out if not the full block is propagated chances are high, that we get the newblock, though. """ log.debug('----------------------------------') log.debug("recv newnewblockhashes", num=len(newblockhashes), remote_id=proto) assert len(newblockhashes) <= 32 self.synchronizer.receive_newblockhashes(proto, newblockhashes) def on_receive_getblockhashes(self, proto, child_block_hash, count): log.debug('----------------------------------') log.debug("handle_get_blockhashes", count=count, block_hash=encode_hex(child_block_hash)) max_hashes = min(count, self.wire_protocol.max_getblockhashes_count) found = [] if child_block_hash not in self.chain: log.debug("unknown block") proto.send_blockhashes(*[]) return last = child_block_hash while len(found) < max_hashes: try: last = rlp.decode_lazy( self.chain.db.get(last))[0][0] # [head][prevhash] except KeyError: # this can happen if we started a chain download, which did not complete # should not happen if the hash is part of the canonical chain log.warn('KeyError in getblockhashes', hash=last) break if last: found.append(last) else: break log.debug("sending: found block_hashes", count=len(found)) proto.send_blockhashes(*found) def on_receive_blockhashes(self, proto, blockhashes): log.debug('----------------------------------') if blockhashes: log.debug("on_receive_blockhashes", count=len(blockhashes), remote_id=proto, first=encode_hex(blockhashes[0]), last=encode_hex(blockhashes[-1])) else: log.debug("recv 0 remote block hashes, signifying genesis block") self.synchronizer.receive_blockhashes(proto, blockhashes) # blocks ################ def on_receive_getblocks(self, proto, blockhashes): log.debug('----------------------------------') log.debug("on_receive_getblocks", count=len(blockhashes)) found = [] for bh in blockhashes[:self.wire_protocol.max_getblocks_count]: try: found.append(self.chain.db.get(bh)) except KeyError: log.debug("unknown block requested", block_hash=encode_hex(bh)) if found: log.debug("found", count=len(found)) proto.send_blocks(*found) def on_receive_blocks(self, proto, transient_blocks): log.debug('----------------------------------') blk_number = max(x.header.number for x in transient_blocks) if transient_blocks else 0 log.debug("recv blocks", count=len(transient_blocks), remote_id=proto, highest_number=blk_number) if transient_blocks: self.synchronizer.receive_blocks(proto, transient_blocks) def on_receive_newblock(self, proto, block, chain_difficulty): log.debug('----------------------------------') log.debug("recv newblock", block=block, remote_id=proto) self.synchronizer.receive_newblock(proto, block, chain_difficulty) def on_receive_getblockheaders(self, proto, blockhashes): log.debug('----------------------------------') log.debug("on_receive_getblockheaders", count=len(blockhashes)) found = [] for bh in blockhashes[:self.wire_protocol.max_getblocks_count]: try: found.append(rlp.encode(rlp.decode(self.chain.db.get(bh))[0])) except KeyError: log.debug("unknown block requested", block_hash=encode_hex(bh)) if found: log.debug("found", count=len(found)) proto.send_blockheaders(*found) def on_receive_blockheaders(self, proto, transient_blocks): log.debug('----------------------------------') pass # TODO: implement headers first syncing def on_receive_hashlookup(self, proto, hashes): found = [] for h in hashes: try: found.append( utils.encode_hex( self.chain.db.get('node:' + utils.decode_hex(h)))) except KeyError: found.append('') proto.send_hashlookupresponse(h) def on_receive_hashlookupresponse(self, proto, hashresponses): pass
from gevent.monkey import patch_all patch_all() from socket import socket from gevent.queue import Queue import gevent.socket import conf_server queue = Queue() queue.put('123') queue.put('456') print queue.peek() print queue.peek() import json print json.loads('123') # address = (conf_server.SERVER_IP, conf_server.SERVER_PORT) # s = socket() # s.connect(address) # # print s.recv(1024) # s.send('123') # print s.recv(1024) # # queue.put(s)
class CompetitiveDialogueDataBridge(object): """ Competitive Dialogue Data Bridge """ copy_name_fields = ( 'title', 'title_ru', 'title_en', 'description', 'description_en', 'description_ru', 'mode', 'procurementMethodDetails', 'submissionMethodDetails', 'minimalStep', 'value', 'procuringEntity', 'buyers', ) rewrite_statuses = ['draft'] allowed_statuses = ['active.tendering', 'active.pre-qualification', 'active.pre-qualification.stand-still', 'active.auction', 'active.qualification', 'active.awarded', 'complete', 'cancelled', 'unsuccessful', STAGE2_STATUS] def __init__(self, config): super(CompetitiveDialogueDataBridge, self).__init__() self.config = config self.tenders_sync_client = TendersClientSync( '', host_url=self.config_get('public_tenders_api_server') or self.config_get('tenders_api_server'), api_version=self.config_get('tenders_api_version'), ) self.client = TendersClientSync( self.config_get('api_token'), host_url=self.config_get('tenders_api_server'), api_version=self.config_get('tenders_api_version'), ) def_queue_size = 500 def_watcher_delay = 15 self.initial_sync_point = {} self.initialization_event = gevent.event.Event() self.competitive_dialogues_queue = Queue(maxsize=def_queue_size) # Id tender which need to check self.handicap_competitive_dialogues_queue = Queue(maxsize=def_queue_size) self.dialogs_stage2_put_queue = Queue(maxsize=def_queue_size) # queue with new tender data self.dialogs_stage2_retry_put_queue = Queue(maxsize=def_queue_size) self.dialog_stage2_id_queue = Queue(maxsize=def_queue_size) self.dialog_retry_stage2_id_queue = Queue(maxsize=def_queue_size) self.dialogs_stage2_patch_queue = Queue(maxsize=def_queue_size) self.dialogs_stage2_retry_patch_queue = Queue(maxsize=def_queue_size) self.dialog_set_complete_queue = Queue(maxsize=def_queue_size) self.dialog_retry_set_complete_queue = Queue(maxsize=def_queue_size) self.jobs_watcher_delay = self.config_get('jobs_watcher_delay') or def_watcher_delay def config_get(self, name): return self.config.get('main').get(name) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def get_tender_credentials(self, tender_id): self.client.headers.update({'X-Client-Request-ID': generate_req_id()}) logger.info("Getting credentials for tender {}".format(tender_id), extra=journal_context({"MESSAGE_ID": DATABRIDGE_GET_CREDENTIALS}, {"TENDER_ID": tender_id})) data = self.client.extract_credentials(tender_id) logger.info("Got tender {} credentials".format(tender_id), extra=journal_context({"MESSAGE_ID": DATABRIDGE_GOT_CREDENTIALS}, {"TENDER_ID": tender_id})) return data @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def initialize_sync(self, params=None, direction=None): # TODO use gevent.Event to wake up forward sync instead of checking # initial sync point if direction == "backward": assert params['descending'] response = self.tenders_sync_client.sync_tenders(params, extra_headers={'X-Client-Request-ID': generate_req_id()}) # set values in reverse order due to 'descending' option self.initial_sync_point = {'forward_offset': response.prev_page.offset, 'backward_offset': response.next_page.offset} self.initialization_event.set() logger.info("Initial sync point {}".format(self.initial_sync_point)) return response elif not self.initial_sync_point: raise ValueError else: assert 'descending' not in params gevent.wait([self.initialization_event]) self.initialization_event.clear() params['offset'] = self.initial_sync_point['forward_offset'] logger.info("Starting forward sync from offset {}".format(params['offset'])) return self.tenders_sync_client.sync_tenders(params, extra_headers={'X-Client-Request-ID': generate_req_id()}) def get_tenders(self, params, direction=""): response = self.initialize_sync(params=params, direction=direction) while not (params.get('descending') and not len(response.data) and params.get('offset') == response.next_page.offset): tenders_list = response.data params['offset'] = response.next_page.offset delay = 101 if tenders_list: delay = 15 logger.info("Client {} params: {}".format(direction, params)) for tender in tenders_list: # Check, if we already work with this tender if tender['id'] in dialog_work: logger.info('WORK with tender {}'.format(tender['id'])) continue if tender['procurementMethodType'] in [CD_UA_TYPE, CD_EU_TYPE] and tender['status'] == 'active.stage2.waiting': logger.info('{0} sync: Found competitive dialogue (stage1), id={1} with status {2}'.format(direction.capitalize(), tender['id'], tender['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_FOUND_NOLOT}, {"TENDER_ID": tender['id']})) yield tender else: logger.debug('{0} sync: Skipping tender {1} in status {2} with procurementMethodType {3}'.format(direction.capitalize(), tender['id'], tender['status'], tender['procurementMethodType']), extra=journal_context(params={"TENDER_ID": tender['id']})) logger.info('Sleep {} sync...'.format(direction), extra=journal_context({"MESSAGE_ID": DATABRIDGE_SYNC_SLEEP})) gevent.sleep(delay) logger.info('Restore {} sync'.format(direction), extra=journal_context({"MESSAGE_ID": DATABRIDGE_SYNC_RESUME})) logger.debug('{} {}'.format(direction, params)) response = self.tenders_sync_client.sync_tenders(params, extra_headers={'X-Client-Request-ID': generate_req_id()}) def get_competitive_dialogue_data(self): while True: try: tender_to_sync = self.competitive_dialogues_queue.peek() # Get competitive dialogue which we want to sync tender = self.tenders_sync_client.get_tender(tender_to_sync['id'])['data'] # Try get data by tender id except Exception as e: # If we have something problems then put tender back to queue logger.exception(e) logger.info('Putting tender {} back to tenders queue...'.format(tender_to_sync['id']), extra=journal_context(params={"TENDER_ID": tender_to_sync['id']})) self.competitive_dialogues_queue.get() # Remove erroneous item from the queue, to put it as the last item # What if another thread put one more item after get but before put? self.competitive_dialogues_queue.put(tender_to_sync) logger.info('Tender {} put back to tenders queue. Que size: {}'.format( tender_to_sync['id'], self.competitive_dialogues_queue.qsize())) else: if 'stage2TenderID' in tender: try: tender_stage2 = self.tenders_sync_client.get_tender(tender['stage2TenderID'])['data'] except: logger.info('Tender stage 2 id={0} didn\'t exist, need create new'.format(tender['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_TENDER_STAGE2_NOT_EXIST}, {"TENDER_ID": tender['id']})) else: if tender_stage2.get('status') in self.allowed_statuses: if tender.get('status') == 'complete': logger.warn('Dialog {0} already has complete status - silently removing from initial queue.'.format(tender['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_ONLY_PATCH}, {"TENDER_ID": tender['id']})) self.competitive_dialogues_queue.get() # Remove from the queue else: logger.info('For dialog {0} tender stage 2 already exists, need only patch'.format(tender['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_ONLY_PATCH}, {"TENDER_ID": tender['id']})) patch_data = {"id": tender['id'], "status": "complete"} self.competitive_dialogues_queue.get() # Remove from the queue self.dialog_set_complete_queue.put(patch_data) continue elif tender_stage2.get('status') in self.rewrite_statuses: logger.info('Tender stage 2 id={0} has bad status need to create new '.format(tender['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CREATE_NEW_STAGE2}, {"TENDER_ID": tender['id']})) logger.info('Copy competitive dialogue data, id={} '.format(tender['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_COPY_TENDER_ITEMS}, {"TENDER_ID": tender['id']})) new_tender = dict(procurementMethod='selective', status='draft', dialogueID=tender['id']) for field_name in self.copy_name_fields: # Copy fields from stage 1 competitive dialog if field_name in tender: new_tender[field_name] = tender[field_name] if tender['procurementMethodType'].endswith('EU'): new_tender['procurementMethodType'] = STAGE_2_EU_TYPE else: new_tender['procurementMethodType'] = STAGE_2_UA_TYPE new_tender['tenderID'] = '{}.2'.format(tender['tenderID']) # set tenderID as in stage1 + '.2' old_lots, items, short_listed_firms = dict(), list(), dict() for qualification in tender['qualifications']: if qualification['status'] == 'active': # check if qualification has status active if qualification.get('lotID'): if qualification['lotID'] not in old_lots: # check if lot id in local dict with new lots lot = prepare_lot(tender, qualification['lotID'], items) # update lot with new id if not lot: # Go next iter if not lot continue old_lots[qualification['lotID']] = lot # set new lot in local dict bid = get_bid_by_id(tender['bids'], qualification['bidID']) for bid_tender in bid['tenderers']: if bid_tender['identifier']['id'] not in short_listed_firms: short_listed_firms[bid_tender['identifier']['id']] = {"name": bid_tender['name'], "identifier": bid_tender['identifier'], "lots": [{"id": old_lots[qualification['lotID']]['id']}]} else: short_listed_firms[bid_tender['identifier']['id']]['lots'].append( {"id": old_lots[qualification['lotID']]['id']}) else: new_tender['items'] = copy.deepcopy(tender['items']) # add all items, with new id bid = get_bid_by_id(tender['bids'], qualification['bidID']) for bid_tender in bid['tenderers']: if bid_tender['identifier']['id'] not in short_listed_firms: short_listed_firms[bid_tender['identifier']['id']] = {"name": bid_tender['name'], "identifier": bid_tender['identifier'], "lots": []} if items: # If we have lots, then add only related items new_tender['items'] = items new_tender['lots'] = old_lots.values() if 'features' in tender: new_tender['features'] = [] for feature in tender.get('features'): if feature['featureOf'] == 'tenderer': # If feature related to tender, than just copy new_tender['features'].append(feature) elif feature['featureOf'] == 'item': # If feature related to item need check if it's actual if feature['relatedItem'] in (item['id'] for item in new_tender['items']): new_tender['features'].append(feature) elif feature['featureOf'] == 'lot': # If feature related to lot need check if it's actual if feature['relatedItem'] in old_lots.keys(): new_tender['features'].append(feature) new_tender['shortlistedFirms'] = short_listed_firms.values() self.competitive_dialogues_queue.get() self.handicap_competitive_dialogues_queue.put(new_tender) def prepare_new_tender_data(self): while True: new_tender = self.handicap_competitive_dialogues_queue.get() try: logger.info("Getting extra info for competitive dialogue, id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_GET_EXTRA_INFO}, {"TENDER_ID": new_tender['dialogueID']})) tender_data = self.get_tender_credentials(new_tender['dialogueID']) except Exception as e: logger.exception(e) logger.info("Can't get competitive dialogue credentials, id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_MISSING_CREDENTIALS}, {"TENDER_ID": new_tender['dialogueID']})) self.handicap_competitive_dialogues_queue.put(new_tender) else: logger.debug("Got extra info for competitive dialogue, id={}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_GOT_EXTRA_INFO}, {"TENDER_ID": new_tender['dialogueID']})) data = tender_data.data new_tender['owner'] = data['owner'] new_tender['dialogue_token'] = data['tender_token'] self.dialogs_stage2_put_queue.put(new_tender) gevent.sleep(0) def put_tender_stage2(self): """ Create tender for stage 2 """ while True: new_tender = self.dialogs_stage2_put_queue.get() logger.info("Creating tender stage2 from competitive dialogue id={}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CREATE_NEW_TENDER}, {"TENDER_ID": new_tender['dialogueID']})) data = {"data": new_tender} try: res = self.client.create_tender(data) except ResourceError as re: if re.status_int == 412: # Update Cookie, and retry self.client.headers['Cookie'] = re.response.headers['Set-Cookie'] elif re.status_int == 422: # WARNING and don't retry logger.warn("Catch 422 status, stop create tender stage2", extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) logger.warn("Error response {}".format(re.message), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) continue elif re.status_int == 404: # WARNING and don't retry logger.warn("Catch 404 status, stop create tender stage2", extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) continue logger.info("Unsuccessful put for tender stage2 of competitive dialogue id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) logger.info("Schedule retry for competitive dialogue id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_RETRY_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) self.dialogs_stage2_retry_put_queue.put(new_tender) except Exception as e: logger.info("Exception, schedule retry for competitive dialogue id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_RETRY_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) self.dialogs_stage2_retry_put_queue.put(new_tender) logger.exception(e) else: logger.info("Successfully created tender stage2 id={} from competitive dialogue id={}".format(res['data']['id'], res['data']['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_TENDER_CREATED}, {"DIALOGUE_ID": res['data']['dialogueID'], "TENDER_ID": res['data']['id']})) # Put data in queue for patch dialog dialog = {"id": res['data']['dialogueID'], "stage2TenderID": res['data']['id']} self.dialog_stage2_id_queue.put(dialog) gevent.sleep(0) def patch_dialog_add_stage2_id(self): """ Patch origin competitive dialogue - set tender id for stage 2 (field stage2TenderID) """ while True: dialog = self.dialog_stage2_id_queue.get() dialog_work.add(dialog['id']) logger.info("Patch competitive dialogue id={} with stage2 tender id".format(dialog['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CD_PATCH_STAGE2_ID}, {"TENDER_ID": dialog['id']})) patch_data = {"data": dialog} try: res_patch = self.client.patch_tender(patch_data) except Exception as e: logger.exception(e) logger.info("Unsuccessful patch competitive dialogue id={0} with stage2 tender id".format(dialog['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CD_UNSUCCESSFUL_PATCH_STAGE2_ID}, {"TENDER_ID": dialog['id']})) logger.info("Schedule retry for competitive dialogue id={0}".format(dialog['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CD_RETRY_PATCH_STAGE2_ID}, {"TENDER_ID": dialog['id']})) self.dialog_retry_stage2_id_queue.put(dialog) else: logger.info("Successful patch competitive dialogue id={0} with stage2 tender id".format(res_patch['data']['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CD_PATCHED_STAGE2_ID}, {"DIALOGUE_ID": res_patch['data']['id'], "TENDER_ID": res_patch['data']['stage2TenderID']})) data = {"id": dialog['stage2TenderID'], "status": STAGE2_STATUS, "dialogueID": dialog['id']} self.dialogs_stage2_patch_queue.put(data) gevent.sleep(0) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def _patch_dialog_add_stage2_id_with_retry(self, dialog): try: data = {"data": dialog} logger.info("Patch competitive dialogue id={0}".format(dialog['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_PATCH_DIALOG}, {"TENDER_ID": dialog['id']})) self.client.patch_tender(data) except Exception as e: logger.exception(e) raise def retry_patch_dialog_add_stage2_id(self): while True: try: dialog = self.dialog_retry_stage2_id_queue.get() self._patch_dialog_add_stage2_id_with_retry(dialog) except: logger.warn("Can't patch competitive dialogue id={0}".format(dialog['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CD_UNSUCCESSFUL_PATCH_STAGE2_ID}, {"TENDER_ID": dialog['id']})) self.competitive_dialogues_queue.put({"id": dialog['id']}) else: data = {"id": dialog['stage2TenderID'], "status": STAGE2_STATUS, "dialogueID": dialog['id']} self.dialogs_stage2_patch_queue.put(data) gevent.sleep(0) def patch_new_tender_status(self): while True: patch_data = self.dialogs_stage2_patch_queue.get() logger.info("Patch tender stage2 id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_PATCH_NEW_TENDER_STATUS}, {"TENDER_ID": patch_data["id"]})) try: res = self.client.patch_tender({"data": patch_data}) except Exception as e: logger.exception(e) logger.info("Unsuccessful path tender stage2 id={0} with status {1}".format(patch_data['id'], patch_data['status'])) logger.info("Schedule retry patch for tender stage2 {0}".format(patch_data['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_PATCH_NEW_TENDER_STATUS}, {"TENDER_ID": patch_data['id']})) self.dialogs_stage2_retry_patch_queue.put(patch_data) else: logger.info("Successful patch tender stage2 id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_SUCCESSFUL_PATCH_NEW_TENDER_STATUS})) patch_data = {"id": res['data']['dialogueID'], "status": "complete"} self.dialog_set_complete_queue.put(patch_data) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def _patch_new_tender_status_with_retry(self, new_tender): try: data = {"data": new_tender} logger.info("Patch new tender stage2 id={0} status".format(new_tender['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_PATCH_NEW_TENDER_STATUS}, {"TENDER_ID": new_tender['id']})) self.client.patch_tender(data) except Exception as e: logger.exception(e) raise def path_dialog_status(self): while True: patch_data = self.dialog_set_complete_queue.get() logger.info("Patch competitive dialogue id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_PATCH_DIALOG_STATUS}, {"TENDER_ID": patch_data["id"]})) try: self.client.patch_tender({"data": patch_data}) except Exception as e: logger.exception(e) logger.info("Unsuccessful path competitive dialogue id={0} with status {1}".format(patch_data['id'], patch_data['status'])) logger.info("Schedule retry patch for competitive dialogue id={0}".format(patch_data['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_PATCH_DIALOG_STATUS}, {"TENDER_ID": patch_data['id']})) self.dialog_retry_set_complete_queue.put(patch_data) else: logger.info("Successful patch competitive dialogue id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_SUCCESSFUL_PATCH_DIALOG_STATUS})) try: dialog_work.remove(patch_data['id']) except KeyError: pass def retry_patch_dialog_status(self): while True: patch_data = self.dialog_retry_set_complete_queue.get() try: self._patch_dialog_status_with_retry(patch_data) except: logger.warn("Can't patch competitive dialogue id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_PATCH_DIALOG_STATUS, "TENDER_ID": patch_data['id']})) self.competitive_dialogues_queue.put({"id": patch_data['id']}) gevent.sleep(0) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=1000) def _patch_dialog_status_with_retry(self, patch_data): try: data = {"data": patch_data} logger.info("Patch competitive dialogue id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_PATCH_DIALOG_STATUS}, {"TENDER_ID": patch_data['id']})) self.client.patch_tender(data) except Exception as e: logger.exception(e) raise def retry_patch_new_tender_status(self): while True: patch_data = self.dialogs_stage2_retry_patch_queue.get() try: self._patch_new_tender_status_with_retry(patch_data) except: logger.warn("Can't patch tender stage2 id={0} with status {1}".format(patch_data['id'], patch_data['status']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_PATCH_NEW_TENDER_STATUS, "TENDER_ID": patch_data['id']})) self.competitive_dialogues_queue.put({"id": patch_data['dialogueID']}) gevent.sleep(0) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=10000) def _put_with_retry(self, new_tender): data = {"data": new_tender} logger.info("Creating tender stage2 from competitive dialogue id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CREATE_NEW_TENDER}, {"TENDER_ID": new_tender['dialogueID']})) try: res = self.client.create_tender(data) except ResourceError as re: if re.status_int == 412: # Update Cookie, and retry self.client.headers['Cookie'] = re.response.headers['Set-Cookie'] elif re.status_int == 422: # WARNING and don't retry logger.warn("Catch 422 status, stop create tender stage2", extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) logger.warn("Error response {}".format(re.message), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) elif re.status_int == 404: # WARNING and don't retry logger.warn("Catch 404 status, stop create tender stage2", extra=journal_context( {"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) else: logger.info("Unsuccessful put for tender stage2 of competitive dialogue id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_UNSUCCESSFUL_CREATE}, {"TENDER_ID": new_tender['dialogueID']})) raise re except Exception as e: logger.exception(e) raise else: # Put data in queue for patch dialog dialog = {"id": res['data']['dialogueID'], "stage2TenderID": res['data']['id']} self.dialog_stage2_id_queue.put(dialog) def retry_put_tender_stage2(self): while True: try: new_tender = self.dialogs_stage2_retry_put_queue.get() self._put_with_retry(new_tender) except: del new_tender['dialogue_token'] # do not reveal tender credentials in logs logger.warn("Can't create tender stage2 from competitive dialogue id={0}".format(new_tender['dialogueID']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_CREATE_ERROR, "TENDER_ID": new_tender['dialogueID']})) self.competitive_dialogues_queue.put({"id": new_tender['dialogueID']}) else: dialog = {"id": new_tender['dialogueID'], "stage2TenderID": new_tender['id']} self.dialog_stage2_id_queue.put(dialog) gevent.sleep(0) def get_competitive_dialogue_forward(self): logger.info('Start forward data sync worker...') params = {'opt_fields': 'status,procurementMethodType', 'mode': '_all_'} try: for tender_data in self.get_tenders(params=params, direction="forward"): logger.info('Forward sync: Put competitive dialogue id={} to process...'.format(tender_data['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_TENDER_PROCESS}, {"TENDER_ID": tender_data['id']})) self.competitive_dialogues_queue.put(tender_data) except ResourceError as re: if re.status_int == 412: self.tenders_sync_client.headers['Cookie'] = re.response.headers['Set-Cookie'] logger.warn('Forward catch 412, update coockie and restart worker',extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) logger.warn('Forward worker died!', extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) logger.error("Error response {}".format(re.message)) raise re except Exception as e: # TODO reset queues and restart sync logger.warn('Forward worker died!', extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) logger.exception(e) raise e else: logger.warn('Forward data sync finished!') # Should never happen!!! def get_competitive_dialogue_backward(self): logger.info('Start backward data sync worker...') params = {'opt_fields': 'status,procurementMethodType', 'descending': 1, 'mode': '_all_'} try: for tender_data in self.get_tenders(params=params, direction="backward"): logger.info('Backward sync: Put competitive dialogue id={} to process...'.format(tender_data['id']), extra=journal_context({"MESSAGE_ID": DATABRIDGE_TENDER_PROCESS}, {"TENDER_ID": tender_data['id']})) self.competitive_dialogues_queue.put(tender_data) except ResourceError as re: if re.status_int == 412: self.tenders_sync_client.headers['Cookie'] = re.response.headers['Set-Cookie'] logger.warn('Backward catch 412, update coockie and restart worker', extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) logger.warn('Backward worker died!', extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) logger.error("Error response {}".format(re.message)) raise re except Exception as e: # TODO reset queues and restart sync logger.warn('Backward worker died!', extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) logger.exception(e) raise e else: logger.info('Backward data sync finished.') def catch_exception(self, exc, name): """Restarting job""" logger.warning('Worker died! Restarting {}.'.format(name), extra=journal_context({"MESSAGE_ID": DATABRIDGE_WORKER_DIED}, {})) if name == 'get_competitive_dialogue_data': tender = self.competitive_dialogues_queue.get() # delete invalid tender from queue logger.info('Remove invalid tender {}'.format(tender.id)) self.immortal_jobs[name] = gevent.spawn(getattr(self, name)) self.immortal_jobs[name].link_exception(partial(self.catch_exception, name=name)) def _start_competitive_sculptors(self): logger.info('Start Competitive Dialogue Data Bridge') self.immortal_jobs = { 'get_competitive_dialogue_data': gevent.spawn(self.get_competitive_dialogue_data), 'prepare_new_tender_data': gevent.spawn(self.prepare_new_tender_data), 'put_tender_stage2': gevent.spawn(self.put_tender_stage2), 'retry_put_tender_stage2': gevent.spawn(self.retry_put_tender_stage2), 'patch_dialog_add_stage2_id': gevent.spawn(self.patch_dialog_add_stage2_id), 'retry_patch_dialog_add_stage2_id': gevent.spawn(self.retry_patch_dialog_add_stage2_id), 'patch_new_tender_status': gevent.spawn(self.patch_new_tender_status), 'retry_patch_new_tender_status': gevent.spawn(self.retry_patch_new_tender_status), 'path_dialog_status': gevent.spawn(self.path_dialog_status), 'retry_patch_dialog_status': gevent.spawn(self.retry_patch_dialog_status) } for name, job in self.immortal_jobs.items(): job.link_exception(partial(self.catch_exception, name=name)) def _start_competitive_wokers(self): self.jobs = [ gevent.spawn(self.get_competitive_dialogue_backward), gevent.spawn(self.get_competitive_dialogue_forward), ] def _restart_synchronization_workers(self): logger.warn("Restarting synchronization", extra=journal_context({"MESSAGE_ID": DATABRIDGE_RESTART}, {})) for j in self.jobs: j.kill(timeout=5) self._start_competitive_wokers() def run(self): self._start_competitive_sculptors() self._start_competitive_wokers() backward_worker, forward_worker = self.jobs counter = 0 try: while True: gevent.sleep(self.jobs_watcher_delay) if counter == 20: logger.info( """Current state: First stages in processing {competitive_dialogues_queue}; Prepared data for second stage {handicap_competitive_dialogues_queue}; Prepared data with owner and token {dialogs_stage2_put_queue}; Retry prepared data with owner and token {dialogs_stage2_retry_put_queue}; Data with second stage ID {dialog_stage2_id_queue}; Retry data with second stage ID {dialog_retry_stage2_id_queue}; Data with new status and first stage ID {dialogs_stage2_patch_queue} Retry data with new status and first stage ID {dialogs_stage2_retry_patch_queue} Data with new status for first stage {dialog_set_complete_queue} Retry data with new status for first stage {dialog_retry_set_complete_queue}""".format( competitive_dialogues_queue=self.competitive_dialogues_queue.qsize(), handicap_competitive_dialogues_queue=self.handicap_competitive_dialogues_queue.qsize(), dialogs_stage2_put_queue=self.dialogs_stage2_put_queue.qsize(), dialogs_stage2_retry_put_queue=self.dialogs_stage2_retry_put_queue.qsize(), dialog_stage2_id_queue=self.dialog_stage2_id_queue.qsize(), dialog_retry_stage2_id_queue=self.dialog_retry_stage2_id_queue.qsize(), dialogs_stage2_patch_queue=self.dialogs_stage2_patch_queue.qsize(), dialogs_stage2_retry_patch_queue=self.dialogs_stage2_retry_patch_queue.qsize(), dialog_set_complete_queue=self.dialog_set_complete_queue.qsize(), dialog_retry_set_complete_queue=self.dialog_retry_set_complete_queue.qsize()), extra={ 'competitive_dialogues_queue': self.competitive_dialogues_queue.qsize(), 'handicap_competitive_dialogues_queue': self.handicap_competitive_dialogues_queue.qsize(), 'dialogs_stage2_put_queue': self.dialogs_stage2_put_queue.qsize(), 'dialogs_stage2_retry_put_queue': self.dialogs_stage2_retry_put_queue.qsize(), 'dialog_stage2_id_queue': self.dialog_stage2_id_queue.qsize(), 'dialog_retry_stage2_id_queue': self.dialog_retry_stage2_id_queue.qsize(), 'dialogs_stage2_patch_queue': self.dialogs_stage2_patch_queue.qsize(), 'dialogs_stage2_retry_patch_queue': self.dialogs_stage2_retry_patch_queue.qsize(), 'dialog_set_complete_queue': self.dialog_set_complete_queue.qsize(), 'dialog_retry_set_complete_queue': self.dialog_retry_set_complete_queue.qsize()}) counter = 0 counter += 1 if forward_worker.dead or (backward_worker.dead and not backward_worker.successful()): self._restart_synchronization_workers() backward_worker, forward_worker = self.jobs except KeyboardInterrupt: logger.info('Exiting...') gevent.killall(self.jobs, timeout=5) gevent.killall(self.immortal_jobs, timeout=5) except Exception as e: logger.exception(e) logger.warn("Restarting synchronization", extra=journal_context({"MESSAGE_ID": DATABRIDGE_RESTART}))
''' from gevent.monkey import patch_all patch_all() from socket import socket from gevent.queue import Queue import gevent.socket import conf_server queue = Queue() queue.put('123') queue.put('456') print queue.peek() print queue.peek() import json print json.loads('123') # address = (conf_server.SERVER_IP, conf_server.SERVER_PORT) # s = socket() # s.connect(address) # # print s.recv(1024) # s.send('123') # print s.recv(1024) #
class EdrHandler(BaseWorker): """ Edr API Data Bridge """ identification_scheme = u"UA-EDR" activityKind_scheme = u'КВЕД' def __init__(self, proxy_client, edrpou_codes_queue, upload_to_doc_service_queue, process_tracker, services_not_available, delay=15): super(EdrHandler, self).__init__(services_not_available) self.start_time = datetime.now() # init clients self.proxy_client = proxy_client # init queues for workers self.edrpou_codes_queue = edrpou_codes_queue self.upload_to_doc_service_queue = upload_to_doc_service_queue # retry queues for workers self.retry_edrpou_codes_queue = Queue(maxsize=500) self.retry_edr_ids_queue = Queue(maxsize=500) # blockers self.until_too_many_requests_event = event.Event() self.until_too_many_requests_event.set() self.delay = delay self.process_tracker = process_tracker def get_edr_data(self): """Get data from edrpou_codes_queue; make request to EDR Api, passing EDRPOU (IPN, passport); Received data put into upload_to_doc_service_queue""" while not self.exit: self.services_not_available.wait() self.try_peek_and_get_edr_data() gevent.sleep() def try_peek_and_get_edr_data(self): try: tender_data = self.edrpou_codes_queue.peek() except LoopExit: gevent.sleep() else: self.get_data_and_move_to_upload_or_retry(tender_data) def get_data_and_move_to_upload_or_retry(self, tender_data): logger.info('Get {} from edrpou_codes_queue'.format(tender_data), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_GET_TENDER_FROM_QUEUE}, tender_data.log_params())) self.until_too_many_requests_event.wait() response = self.proxy_client.verify( tender_data.param(), tender_data.code, headers={'X-Client-Request-ID': tender_data.doc_id()}) tender_data.add_unique_req_id(response) res_json = get_res_json(response) if is_no_document_in_edr(response, res_json): self.move_data_nonexistent_edr(response.json(), tender_data, False) elif response.status_code == 200: self.move_data_existing_edr(response, tender_data, False) else: self.handle_status_response(response, tender_data.tender_id) self.retry_edrpou_codes_queue.put(tender_data) logger.info( 'Put {} to retry_edrpou_codes_queue'.format(tender_data), extra=journal_context(params=tender_data.log_params())) self.edrpou_codes_queue.get() def move_data_nonexistent_edr(self, res_json, tender_data, is_retry): logger.info( 'Empty response for {} doc_id {}.'.format(tender_data, tender_data.doc_id()), extra=journal_context({"MESSAGE_ID": DATABRIDGE_EMPTY_RESPONSE}, tender_data.log_params())) file_content = res_json.get('errors')[0].get('description')[0] file_content['meta'].update(deepcopy(tender_data.file_content['meta'])) file_content['meta'].update({"version": version}) data = copy(tender_data) data.file_content = file_content self.process_tracker.set_item(tender_data.tender_id, tender_data.item_id, 1) self.process_tracker.add_unprocessed_item(tender_data) self.upload_to_doc_service_queue.put(data) if is_retry: self.retry_edrpou_codes_queue.get() def move_data_existing_edr(self, response, tender_data, is_retry): data_list = [] try: fill_data_list(response, tender_data, data_list, self.process_tracker) except (KeyError, IndexError) as e: logger.info('Error {}. {}'.format(tender_data, e)) self.retry_edrpou_codes_queue.put( self.retry_edrpou_codes_queue.get( ) if is_retry else tender_data) else: for data in data_list: self.upload_to_doc_service_queue.put(data) logger.info( 'Put tender {} doc_id {} to upload_to_doc_service_queue.'. format(data, data.doc_id())) if is_retry: self.retry_edrpou_codes_queue.get() self.process_tracker.set_item(tender_data.tender_id, tender_data.item_id, len(response.json()['data'])) def retry_get_edr_data(self): """Get data from retry_edrpou_codes_queue; Put data into upload_to_doc_service_queue if request is successful, otherwise put data back to retry_edrpou_codes_queue.""" while not self.exit: self.services_not_available.wait() self.try_get_retry_data_and_process() gevent.sleep() def try_get_retry_data_and_process(self): try: tender_data = self.retry_edrpou_codes_queue.peek() except LoopExit: gevent.sleep() else: self.retry_process_tender_data(tender_data) def retry_process_tender_data(self, tender_data): logger.info('Get {} from retry_edrpou_codes_queue'.format(tender_data), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_GET_TENDER_FROM_QUEUE}, tender_data.log_params())) self.retry_try_get_edr_data(tender_data) self.until_too_many_requests_event.wait() def retry_try_get_edr_data(self, tender_data): try: response = self.get_edr_data_request(tender_data.param(), tender_data.code, tender_data.doc_id()) tender_data.add_unique_req_id(response) except RetryException as re: self.handle_status_response(re.args[1], tender_data.tender_id) res_json = get_res_json(re.args[1]) if is_no_document_in_edr(re.args[1], res_json): self.move_data_nonexistent_edr(res_json, tender_data, True) else: logger.info( 'Put {} in back of retry_edrpou_codes_queue. Response {}'. format(tender_data, res_json), extra=journal_context(params=tender_data.log_params())) self.retry_edrpou_codes_queue.put( self.retry_edrpou_codes_queue.get()) gevent.sleep() except Exception as e: logger.info( 'Put {} in back of retry_edrpou_codes_queue. Error: {}'.format( tender_data, e.message), extra=journal_context(params=tender_data.log_params())) self.retry_edrpou_codes_queue.put( self.retry_edrpou_codes_queue.get()) gevent.sleep() else: if response.status_code == 429: seconds_to_wait = response.headers.get('Retry-After', self.delay) logger.info( 'retry_get_edr_id: Too many requests to EDR API. Msg: {}, wait {} seconds.' .format(response.text, seconds_to_wait), extra=journal_context(params=tender_data.log_params())) self.wait_until_too_many_requests(seconds_to_wait) elif response.status_code == 200: self.move_data_existing_edr(response, tender_data, True) @retry(stop_max_attempt_number=5, wait_exponential_multiplier=retry_mult) def get_edr_data_request(self, param, code, document_id): """Execute request to EDR Api for retry queue objects.""" self.until_too_many_requests_event.wait() response = self.proxy_client.verify( param, code, headers={'X-Client-Request-ID': document_id}) if response.status_code not in (200, 429): logger.info( 'Get unsuccessful response {} code={} document_id={}, header {}' .format(response.status_code, code, document_id, response.headers.get('X-Request-ID'))) raise RetryException('Unsuccessful retry request to EDR.', response) return response def handle_status_response(self, response, tender_id): """Process unsuccessful request""" if response.status_code == 429: seconds_to_wait = response.headers.get('Retry-After', self.delay) logger.info( 'Too many requests to EDR API. Msg: {}, wait {} seconds.'. format(response.text, seconds_to_wait), extra=journal_context(params={"TENDER_ID": tender_id})) self.wait_until_too_many_requests(seconds_to_wait) elif is_payment_required(response): logger.warning( 'Payment required for requesting info to EDR. Message: {err}'. format(err=response.text), extra=journal_context(params={"TENDER_ID": tender_id})) else: logger.warning( 'Error appeared while requesting to EDR. Description: {err}'. format(err=response.text), extra=journal_context(params={"TENDER_ID": tender_id})) def wait_until_too_many_requests(self, seconds_to_wait): if self.until_too_many_requests_event.ready(): logger.info('Bot is waiting...') self.until_too_many_requests_event.clear() self.until_too_many_requests_event.wait(float(seconds_to_wait)) logger.info('Bot stop waiting...') self.until_too_many_requests_event.set() def _start_jobs(self): return { 'get_edr_data': spawn(self.get_edr_data), 'retry_get_edr_data': spawn(self.retry_get_edr_data) }
class CeleryReporter(Greenlet): one_min_stats = [] one_sec_stats = ['queued'] def _set_config(self, **config): self.config = dict(celery_task_prefix='simplecoin.tasks', celery={'CELERY_DEFAULT_QUEUE': 'celery'}, report_pool_stats=True, share_batch_interval=60, tracker_expiry_time=180) self.config.update(config) # check that we have at least one configured coin server if not self.config['celery_task_prefix']: self.logger.error("You need to specify a celery prefix") exit() def __init__(self, server, **config): Greenlet.__init__(self) self.logger = server.register_logger('reporter') self._set_config(**config) # setup our celery agent and monkey patch self.celery = Celery() self.celery.conf.update(self.config['celery']) self.share_reporter = None self.server = server self.server.register_stat_counters(self.one_min_stats, self.one_sec_stats) self.queue = Queue() self.addresses = {} self.workers = {} @property def status(self): dct = dict(queue_size=self.queue.qsize(), addresses_count=len(self.addresses), workers_count=len(self.workers)) dct.update({key: self.server[key].summary() for key in self.one_min_stats + self.one_sec_stats}) return dct # Remote methods to send information to other servers ######################## def add_one_minute(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("add_one_minute", args, kwargs)) self.logger.info("Calling celery task {} with {}" .format("add_one_minute", args)) def add_share(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("add_share", args, kwargs)) self.logger.info("Calling celery task {} with {}" .format("add_shares", args)) def agent_send(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("agent_receive", args, kwargs)) def add_block(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("add_block", args, kwargs)) self.logger.info("Calling celery task {} with {}" .format("transmit_block", args)) def _run(self): self.share_reporter = spawn(self.report_loop) while True: self._queue_proc() def _queue_proc(self): name, args, kwargs = self.queue.peek() try: self.celery.send_task( self.config['celery_task_prefix'] + '.' + name, args, kwargs) except Exception as e: self.logger.error("Unable to communicate with celery broker! {}" .format(e)) else: self.queue.get() def report_loop(self): """ Repeatedly do our share reporting on an interval """ while True: sleep(self.config['share_batch_interval']) try: self._report_shares() except Exception: self.logger.error("Unhandled error in report shares", exc_info=True) def _report_shares(self, flush=False): """ Goes through our internal aggregated share data structures and reports them to our external storage. If asked to flush it will report all one minute shares, otherwise it will only report minutes that have passed. """ if flush: self.logger.info("Flushing all aggreated share data...") self.logger.info("Reporting shares for {:,} users" .format(len(self.addresses))) t = time.time() for address, tracker in self.addresses.items(): tracker.report() # if the last log time was more than expiry time ago... if (tracker.last_log + self.config['tracker_expiry_time']) < t: assert tracker.unreported == 0 del self.addresses[address] self.logger.info("Shares reported (queued) in {}" .format(time_format(time.time() - t))) self.logger.info("Reporting one minute shares for {:,} address/workers" .format(len(self.workers))) t = time.time() if flush: upper = t + 10 else: upper = (t // 60) * 60 for worker_addr, tracker in self.workers.items(): tracker.report(upper) # if the last log time was more than expiry time ago... if (tracker.last_log + self.config['tracker_expiry_time']) < t: assert sum(tracker.slices.itervalues()) == 0 del self.workers[worker_addr] self.logger.info("One minute shares reported (queued) in {}" .format(time_format(time.time() - t))) def log_share(self, address, worker, amount, typ): """ Logs a share for a user and user/worker into all three share aggregate sources. """ # log the share for the pool cache total as well if address != "pool" and self.config['report_pool_stats']: self.log_share("pool", '', amount, typ) # collecting for reporting to the website for display in graphs addr_worker = (address, worker) if addr_worker not in self.workers: self.workers[addr_worker] = WorkerTracker(self, address, worker) self.workers[(address, worker)].count_share(amount, typ) # reporting for payout share logging and vardiff rates if typ == StratumClient.VALID_SHARE and address != "pool": if address not in self.addresses: self.addresses[address] = AddressTracker(self, address) # for tracking vardiff speeds self.addresses[address].count_share(amount) def kill(self, *args, **kwargs): self.share_reporter.kill(*args, **kwargs) self._report_shares(flush=True) self.logger.info("Flushing the reporter task queue, {} items blocking " "exit".format(self.queue.qsize())) while not self.queue.empty(): self._queue_proc() self.logger.info("Shutting down CeleryReporter..") Greenlet.kill(self, *args, **kwargs)
class EdrHandler(Greenlet): """ Edr API Data Bridge """ identification_scheme = u"UA-EDR" activityKind_scheme = u'КВЕД' def __init__(self, proxyClient, edrpou_codes_queue, upload_to_doc_service_queue, process_tracker, services_not_available, delay=15): super(EdrHandler, self).__init__() self.exit = False self.start_time = datetime.now() # init clients self.proxyClient = proxyClient # init queues for workers self.edrpou_codes_queue = edrpou_codes_queue self.upload_to_doc_service_queue = upload_to_doc_service_queue # retry queues for workers self.retry_edrpou_codes_queue = Queue(maxsize=500) self.retry_edr_ids_queue = Queue(maxsize=500) # blockers self.until_too_many_requests_event = gevent.event.Event() self.services_not_available = services_not_available self.until_too_many_requests_event.set() self.delay = delay self.process_tracker = process_tracker def get_edr_data(self): """Get data from edrpou_codes_queue; make request to EDR Api, passing EDRPOU (IPN, passport); Received data put into upload_to_doc_service_queue""" while not self.exit: self.services_not_available.wait() try: tender_data = self.edrpou_codes_queue.peek() except LoopExit: gevent.sleep() continue item_name_id = tender_data.item_name[:-1].upper() + "_ID" logger.info('Get {} from edrpou_codes_queue'.format( data_string(tender_data)), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_GET_TENDER_FROM_QUEUE}, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id })) self.until_too_many_requests_event.wait() document_id = tender_data.file_content['meta']['id'] response = self.proxyClient.verify( validate_param(tender_data.code), tender_data.code, headers={'X-Client-Request-ID': document_id}) if response.headers.get('X-Request-ID'): tender_data.file_content['meta']['sourceRequests'].append( response.headers['X-Request-ID']) # add unique request id if response.status_code == 404 and response.json().get( 'errors')[0].get('description')[0].get('error').get( 'code') == u"notFound": logger.info('Empty response for {} doc_id {}.'.format( data_string(tender_data), document_id), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_EMPTY_RESPONSE}, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) file_content = response.json().get('errors')[0].get( 'description')[0] file_content['meta'].update(tender_data.file_content['meta'] ) # add meta.id to file_content file_content['meta'].update({"version": version }) # add filed meta.version data = Data(tender_data.tender_id, tender_data.item_id, tender_data.code, tender_data.item_name, file_content) self.process_tracker.set_item(tender_data.tender_id, tender_data.item_id, 1) self.upload_to_doc_service_queue.put(data) self.edrpou_codes_queue.get() continue if response.status_code == 200: meta_id = tender_data.file_content['meta']['id'] data_list = [] try: for i, obj in enumerate(response.json()['data']): document_id = check_add_suffix(response.json()['data'], meta_id, i + 1) file_content = { 'meta': { 'sourceDate': response.json()['meta']['detailsSourceDate'][i] }, 'data': obj } file_content['meta'].update( deepcopy(tender_data.file_content['meta'])) file_content['meta'].update( {"version": version}) # add filed meta.version file_content['meta']['id'] = document_id data = Data(tender_data.tender_id, tender_data.item_id, tender_data.code, tender_data.item_name, file_content) data_list.append(data) except (KeyError, IndexError) as e: logger.info('Error {}. {}'.format(data_string(tender_data), e)) self.retry_edrpou_codes_queue.put(tender_data) else: self.process_tracker.set_item(tender_data.tender_id, tender_data.item_id, len(response.json()['data'])) for data in data_list: self.upload_to_doc_service_queue.put(data) logger.info( 'Put tender {} doc_id {} to upload_to_doc_service_queue.' .format(data_string(data), data.file_content['meta']['id'])) else: self.handle_status_response(response, tender_data.tender_id) self.retry_edrpou_codes_queue.put( tender_data) # Put tender to retry logger.info('Put {} to retry_edrpou_codes_queue'.format( data_string(tender_data)), extra=journal_context( params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id })) self.edrpou_codes_queue.get() gevent.sleep() def retry_get_edr_data(self): """Get data from retry_edrpou_codes_queue; Put data into upload_to_doc_service_queue if request is successful, otherwise put data back to retry_edrpou_codes_queue.""" while not self.exit: self.services_not_available.wait() try: tender_data = self.retry_edrpou_codes_queue.peek() except LoopExit: gevent.sleep() continue item_name_id = tender_data.item_name[:-1].upper() + "_ID" logger.info('Get {} from retry_edrpou_codes_queue'.format( data_string(tender_data)), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_GET_TENDER_FROM_QUEUE}, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id })) self.until_too_many_requests_event.wait() document_id = tender_data.file_content['meta']['id'] try: response = self.get_edr_data_request( validate_param(tender_data.code), tender_data.code, document_id) if response.headers.get('X-Request-ID'): tender_data.file_content['meta']['sourceRequests'].append( response.headers['X-Request-ID']) except RetryException as re: try: self.handle_status_response(re.args[1], tender_data.tender_id) res_json = re.args[1].json() except JSONDecodeError: res_json = re.args[1].text if re.args[1].status_code == 404 and isinstance( res_json, dict) and res_json.get('errors')[0].get( 'description')[0].get('error').get( 'code') == u"notFound": logger.info('Empty response for {} doc_id: {}.'.format( data_string(tender_data), document_id), extra=journal_context( {"MESSAGE_ID": DATABRIDGE_EMPTY_RESPONSE}, params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id, "DOCUMENT_ID": document_id })) file_content = res_json.get('errors')[0].get( 'description')[0] file_content['meta'].update( tender_data.file_content['meta']) file_content['meta'].update({"version": version }) # add filed meta.version data = Data(tender_data.tender_id, tender_data.item_id, tender_data.code, tender_data.item_name, file_content) self.process_tracker.set_item(tender_data.tender_id, tender_data.item_id, 1) self.upload_to_doc_service_queue.put( data ) # Given EDRPOU code not found, file with error put into upload_to_doc_service_queue self.retry_edrpou_codes_queue.get() logger.info( 'Put {} in back of retry_edrpou_codes_queue. Response {}'. format(data_string(tender_data), res_json), extra=journal_context( params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id })) self.retry_edrpou_codes_queue.put( self.retry_edrpou_codes_queue.get()) gevent.sleep() except Exception as e: logger.info( 'Put {} in back of retry_edrpou_codes_queue. Error: {}'. format(data_string(tender_data), e.message), extra=journal_context( params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id })) self.retry_edrpou_codes_queue.put( self.retry_edrpou_codes_queue.get()) gevent.sleep() else: # Create new Data object. Write to Data.code list of edr ids from EDR. # List because EDR can return 0, 1 or 2 values to our request if response.status_code == 429: seconds_to_wait = response.headers.get( 'Retry-After', self.delay) logger.info( 'retry_get_edr_id: Too many requests to EDR API. Msg: {}, wait {} seconds.' .format(response.text, seconds_to_wait), extra=journal_context( params={ "TENDER_ID": tender_data.tender_id, item_name_id: tender_data.item_id })) self.wait_until_too_many_requests(seconds_to_wait) continue if response.status_code == 200: meta_id = tender_data.file_content['meta']['id'] data_list = [] try: for i, obj in enumerate(response.json()['data']): document_id = check_add_suffix( response.json()['data'], meta_id, i + 1) file_content = { 'meta': { 'sourceDate': response.json()['meta'] ['detailsSourceDate'][i] }, 'data': obj } file_content['meta'].update( deepcopy(tender_data.file_content['meta'])) file_content['meta'].update( {"version": version}) # add filed meta.version file_content['meta']['id'] = document_id data = Data(tender_data.tender_id, tender_data.item_id, tender_data.code, tender_data.item_name, file_content) data_list.append(data) except (KeyError, IndexError) as e: logger.info('Error {}. {}'.format( data_string(tender_data), e)) self.retry_edrpou_codes_queue.put( self.retry_edrpou_codes_queue.get()) else: for data in data_list: self.upload_to_doc_service_queue.put(data) logger.info( 'Put tender {} doc_id {} to upload_to_doc_service_queue from retry.' .format(data_string(data), data.file_content['meta']['id'])) self.retry_edrpou_codes_queue.get() self.process_tracker.set_item( tender_data.tender_id, tender_data.item_id, len(response.json()['data'])) gevent.sleep() @retry(stop_max_attempt_number=5, wait_exponential_multiplier=retry_mult) def get_edr_data_request(self, param, code, document_id): """Execute request to EDR Api for retry queue objects.""" self.until_too_many_requests_event.wait() response = self.proxyClient.verify( param, code, headers={'X-Client-Request-ID': document_id}) if response.status_code not in (200, 429): logger.info( 'Get unsuccessful response {} in get_edr_id_request code={} document_id={}, header {}' .format(response.status_code, code, document_id, response.headers.get('X-Request-ID'))) raise RetryException('Unsuccessful retry request to EDR.', response) return response def handle_status_response(self, response, tender_id): """Process unsuccessful request""" if response.status_code == 429: seconds_to_wait = response.headers.get('Retry-After', self.delay) logger.info( 'Too many requests to EDR API. Msg: {}, wait {} seconds.'. format(response.text, seconds_to_wait), extra=journal_context(params={"TENDER_ID": tender_id})) self.wait_until_too_many_requests(seconds_to_wait) elif response.status_code == 403 and response.headers.get( 'content-type', '') == 'application/json' and response.json( ).get('errors')[0].get('description') == [{ 'message': 'Payment required.', 'code': 5 }]: logger.warning( 'Payment required for requesting info to EDR. Error description: {err}' .format(err=response.text), extra=journal_context(params={"TENDER_ID": tender_id})) else: logger.warning( 'Error appeared while requesting to EDR. Description: {err}'. format(err=response.text), extra=journal_context(params={"TENDER_ID": tender_id})) def wait_until_too_many_requests(self, seconds_to_wait): if self.until_too_many_requests_event.ready(): logger.info('Bot is waiting...') self.until_too_many_requests_event.clear() self.until_too_many_requests_event.wait(float(seconds_to_wait)) self.until_too_many_requests_event.set() logger.info('Bot stop waiting...') def _run(self): logger.info('Start EDR Handler', extra=journal_context( {"MESSAGE_ID": DATABRIDGE_START_EDR_HANDLER}, {})) self.immortal_jobs = { 'get_edr_data': spawn(self.get_edr_data), 'retry_get_edr_data': spawn(self.retry_get_edr_data) } try: while not self.exit: gevent.sleep(self.delay) for name, job in self.immortal_jobs.items(): if job.dead: logger.warning( "EDR handler worker {} dead try restart".format( name), extra=journal_context( { "MESSAGE_ID": "DATABRIDGE_RESTART_{}".format( name.lower()) }, {})) self.immortal_jobs[name] = gevent.spawn( getattr(self, name)) logger.info("EDR handler worker {} is up".format(name)) except Exception as e: logger.error(e) gevent.killall(self.immortal_jobs.values(), timeout=5) def shutdown(self): self.exit = True logger.info('Worker EDR Handler complete his job.')
class Balancer(object): def __init__(self, dispatcher): self.dispatcher = dispatcher self.task_list = [] self.task_queue = Queue() self.resource_graph = dispatcher.resource_graph self.queues = {} self.threads = [] self.executors = [] self.logger = logging.getLogger('Balancer') self.dispatcher.require_collection('tasks', 'serial', type='log') self.create_initial_queues() self.start_executors() self.distribution_lock = RLock() self.debugger = None self.debugged_tasks = None self.dispatcher.register_event_type('task.changed') # Lets try to get `EXECUTING|WAITING|CREATED` state tasks # from the previous dispatcher instance and set their # states to 'FAILED' since they are no longer running # in this instance of the dispatcher for stale_task in dispatcher.datastore.query('tasks', ('state', 'in', ['EXECUTING', 'WAITING', 'CREATED'])): self.logger.info('Stale Task ID: {0} Name: {1} being set to FAILED'.format( stale_task['id'], stale_task['name'] )) stale_task.update({ 'state': 'FAILED', 'error': { 'message': 'dispatcher process died', 'code': errno.EINTR, } }) dispatcher.datastore.update('tasks', stale_task['id'], stale_task) def create_initial_queues(self): self.resource_graph.add_resource(Resource('system')) def start_executors(self): for i in range(0, self.dispatcher.configstore.get('middleware.executors_count')): self.logger.info('Starting task executor #{0}...'.format(i)) self.executors.append(TaskExecutor(self, i)) def start(self): self.threads.append(gevent.spawn(self.distribution_thread)) self.logger.info("Started") def schema_to_list(self, schema): return { 'type': 'array', 'items': schema, 'minItems': sum([1 for x in schema if 'mandatory' in x and x['mandatory']]), 'maxItems': len(schema) } def verify_schema(self, clazz, args): if not hasattr(clazz, 'params_schema'): return [] schema = self.schema_to_list(clazz.params_schema) val = validator.DefaultDraft4Validator(schema, resolver=self.dispatcher.rpc.get_schema_resolver(schema)) return list(val.iter_errors(args)) def submit(self, name, args, sender, env=None): if name not in self.dispatcher.tasks: self.logger.warning("Cannot submit task: unknown task type %s", name) raise RpcException(errno.EINVAL, "Unknown task type {0}".format(name)) task = Task(self.dispatcher, name) task.user = sender.user.name task.session_id = sender.session_id task.created_at = datetime.utcnow() task.clazz = self.dispatcher.tasks[name] task.args = copy.deepcopy(args) if env: if not isinstance(env, dict): raise ValueError('env must be a dict') task.environment = copy.deepcopy(env) if self.debugger: for m in self.debugged_tasks: if fnmatch.fnmatch(name, m): task.debugger = self.debugger task.id = self.dispatcher.datastore.insert("tasks", task) task.set_state(TaskState.CREATED) self.task_queue.put(task) self.logger.info("Task %d submitted (type: %s, class: %s)", task.id, name, task.clazz) return task.id def verify_subtask(self, parent, name, args): clazz = self.dispatcher.tasks[name] instance = clazz(self.dispatcher, self.dispatcher.datastore) return instance.verify(*args) def run_subtask(self, parent, name, args): args = list(args) task = Task(self.dispatcher, name) task.created_at = datetime.utcnow() task.clazz = self.dispatcher.tasks[name] task.args = args task.instance = task.clazz(self.dispatcher, self.dispatcher.datastore) task.instance.verify(*task.args) task.id = self.dispatcher.datastore.insert("tasks", task) task.parent = parent if self.debugger: for m in self.debugged_tasks: if fnmatch.fnmatch(name, m): task.debugger = self.debugger task.set_state(TaskState.CREATED) self.task_list.append(task) # If we actually have a non `None` parent task then, add # the current subtask to the parent task's subtasks list too if parent is not None: parent.subtask_ids.append(task.id) task.start() return task def join_subtasks(self, *tasks): for i in tasks: i.join() def abort(self, id): task = self.get_task(id) if not task: self.logger.warning("Cannot abort task: unknown task id %d", id) return success = False if task.started_at is None: success = True else: try: task.executor.abort() # Also try to abort any subtasks that might have been running for st in task.subtask_ids: self.abort(st) except: pass if success: task.ended.set() task.set_state(TaskState.ABORTED, TaskStatus(0, "Aborted")) self.logger.debug("Task ID: %d, Name: %s aborted by user", task.id, task.name) def task_exited(self, task): self.resource_graph.release(*task.resources) self.schedule_tasks() def schedule_tasks(self): """ This function is called when: 1) any new task is submitted to any of the queues 2) any task exists :return: """ for task in [t for t in self.task_list if t.state == TaskState.WAITING]: if not self.resource_graph.can_acquire(*task.resources): continue self.resource_graph.acquire(*task.resources) self.threads.append(task.start()) def distribution_thread(self): while True: self.task_queue.peek() self.distribution_lock.acquire() task = self.task_queue.get() try: self.logger.debug("Picked up task %d: %s with args %s", task.id, task.name, task.args) errors = self.verify_schema(self.dispatcher.tasks[task.name], task.args) if len(errors) > 0: errors = list(validator.serialize_errors(errors)) self.logger.warning("Cannot submit task {0}: schema verification failed with errors {1}".format( task.name, errors )) raise ValidationException(extra=errors) task.instance = task.clazz(self.dispatcher, self.dispatcher.datastore) task.resources = task.instance.verify(*task.args) if type(task.resources) is not list: raise ValueError("verify() returned something else than resource list") except Exception as err: self.logger.warning("Cannot verify task %d: %s", task.id, err) task.set_state(TaskState.FAILED, TaskStatus(0), serialize_error(err)) self.task_list.append(task) task.ended.set() self.distribution_lock.release() if not isinstance(Exception, VerifyException): self.dispatcher.report_error('Task {0} verify() method raised invalid exception', err) continue task.set_state(TaskState.WAITING) self.task_list.append(task) self.distribution_lock.release() self.schedule_tasks() self.logger.debug("Task %d assigned to resources %s", task.id, ','.join(task.resources)) def assign_executor(self, task): for i in self.executors: if i.state == WorkerState.IDLE: i.checked_in.wait() self.logger.info("Task %d assigned to executor #%d", task.id, i.index) task.executor = i i.state = WorkerState.EXECUTING return # Out of executors! Need to spawn new one executor = TaskExecutor(self, len(self.executors)) self.executors.append(executor) executor.checked_in.wait() executor.state = WorkerState.EXECUTING task.executor = executor self.logger.info("Task %d assigned to executor #%d", task.id, executor.index) def dispose_executors(self): for i in self.executors: i.die() def get_active_tasks(self): return [x for x in self.task_list if x.state in ( TaskState.CREATED, TaskState.WAITING, TaskState.EXECUTING)] def get_tasks(self, type=None): if type is None: return self.task_list return [x for x in self.task_list if x.state == type] def get_task(self, id): self.distribution_lock.acquire() t = first_or_default(lambda x: x.id == id, self.task_list) if not t: t = first_or_default(lambda x: x.id == id, self.task_queue.queue) self.distribution_lock.release() return t def get_executor_by_key(self, key): return first_or_default(lambda t: t.key == key, self.executors) def get_executor_by_sender(self, sender): return first_or_default(lambda t: t.conn == sender, self.executors)
class MeekSession(object): def __init__(self, sessionid, socksip, socksport, timeout, sessionmap): self.sessionid = sessionid self.socksip = socksip self.socksport = socksport self.timeout = timeout self.sessionmap = sessionmap self.sessionmap[self.sessionid] = self self.udpsock = None self.udp_associate = None self.socksconn = None self.allsocks = [] self.status = SESSION_WAIT_INIT self.initialized = False self.in_queue = Queue() self.in_notifier = Event() self.in_notifier.clear() self.out_queue = Queue() self.timer = SharedTimer(self.timeout) self.finish = Event() self.finish.clear() self.threads = [] def meeks_clean_thread(self): while not self.finish.is_set(): gevent.sleep(SERVER_TURNAROUND_MAX) [t.join() for t in self.threads] self.clean() def write_to_socks(self, data): if self.udpsock: self.udpsock.sendto(data, self.udp_associate) else: self.socksconn.sendall(data) def meeks_write_to_socks_thread(self): while not self.finish.is_set(): try: hasdata = self.in_notifier.wait(timeout=CLIENT_MAX_POLL_INTERVAL) self.in_notifier.clear() if not hasdata: self.timer.count(CLIENT_MAX_POLL_INTERVAL) if self.timer.timeout(): break self.timer.reset() while not self.in_queue.empty(): data = self.in_queue.get() log.debug("%s: RELAY-UP %d bytes" % (self.sessionid, len(data))) self.write_to_socks(data) except Exception as ex: log.error("[Exception][meeks_write_to_socks_thread] %s: %s" % (self.sessionid, str(ex))) break self.finish.set() def meeks_read_from_socks_thread(self): while not self.finish.is_set(): try: readable, _, _ = select.select(self.allsocks, [], [], CLIENT_MAX_POLL_INTERVAL) if not readable: self.timer.count(CLIENT_MAX_POLL_INTERVAL) if self.timer.timeout(): break else: self.timer.reset() if self.socksconn in readable: if self.udpsock: raise RelaySessionError("unexcepted read-event from tcp socket in UDP session") data = self.socksconn.recv(MAX_PAYLOAD_LENGTH) if not data: raise RelaySessionError("peer closed") self.out_queue.put(data) continue if self.udpsock and self.udpsock in readable: data, _ = self.udpsock.recvfrom(MAX_PAYLOAD_LENGTH) if data: self.out_queue.put(data) except Exception as ex: log.error("[Exception][meeks_read_from_socks_thread] %s:%s" % (self.sessionid, str(ex))) break self.finish.set() def initialize(self): self.socksconn = socket.create_connection((self.socksip, self.socksport), self.timeout) self.allsocks = [self.socksconn] self.socksconn.sendall(InitRequest().pack()) read_init_reply(self.socksconn) self.status = SESSION_WAIT_REQUEST self.initialized = True def cmd_connect(self, req): self.socksconn.sendall(req.pack()) reply = read_reply(self.socksconn) resp = reply.pack() headers = [ (HEADER_SESSION_ID, self.sessionid), (HEADER_MSGTYPE, MSGTYPE_DATA) ] self.threads.append(gevent.spawn(self.meeks_write_to_socks_thread)) self.threads.append(gevent.spawn(self.meeks_read_from_socks_thread)) # clean_thread will join the other two threads, then clean resources gevent.spawn(self.meeks_clean_thread) self.status = SESSION_TCP return resp, headers def cmd_udp_associate(self, req): self.udpsock = bind_local_udp(self.socksconn) self.allsocks.append(self.udpsock) addrtype, ip, port = sock_addr_info(self.udpsock) self.socksconn.sendall(Request(cmd=UDP_ASSOCIATE, addrtype=addrtype, dstaddr=ip, dstport=port).pack()) reply = read_reply(self.socksconn) resp = reply.pack() headers = [ (HEADER_SESSION_ID, self.sessionid), (HEADER_MSGTYPE, MSGTYPE_DATA) ] self.udp_associate = (reply.bndaddr, reply.bndport) self.threads.append(gevent.spawn(self.meeks_write_to_socks_thread)) self.threads.append(gevent.spawn(self.meeks_read_from_socks_thread)) # clean_thread will join the other two threads, then clean resources gevent.spawn(self.meeks_clean_thread) self.status = SESSION_UDP return resp, headers def cmd_bind(self, req): resp = "" headers = [ (HEADER_SESSION_ID, self.sessionid), (HEADER_ERROR, "Not Supported") ] return resp, headers def sync_socks_request(self, data, env): req = Request() req.unpack(data) return { CONNECT: self.cmd_connect, BIND: self.cmd_bind, UDP_ASSOCIATE : self.cmd_udp_associate }[req.cmd](req) def _fetch_resp(self): data = [] totalsize = 0 while True: while not self.out_queue.empty() and totalsize < MAX_PAYLOAD_LENGTH: pkt = self.out_queue.get() data.append(pkt) totalsize += len(pkt) if data: return data, totalsize else: try: self.out_queue.peek(block=True, timeout=SERVER_TURNAROUND_TIMEOUT) except Empty: break return data, totalsize def fetch_resp(self): data, _ = self._fetch_resp() resp = "".join(data) headers = [ (HEADER_SESSION_ID, self.sessionid), (HEADER_MSGTYPE, MSGTYPE_DATA), ] if self.status == SESSION_UDP and data: headers.append((HEADER_UDP_PKTS, ",".join([str(len(d)) for d in data]))) return resp, headers def process_tcp(self, data, env): if data: self.in_queue.put(data) self.in_notifier.set() return self.fetch_resp() def process_udp(self, data, env): if data: lengths = env[header_to_env(HEADER_UDP_PKTS)].split(",") pos = 0 for length in lengths: nxt = pos + int(length) self.in_queue.put(data[pos:nxt]) pos = nxt self.in_notifier.set() return self.fetch_resp() def process(self, data, env): if not self.initialized: self.initialize() return { SESSION_WAIT_REQUEST: self.sync_socks_request, SESSION_TCP: self.process_tcp, SESSION_UDP: self.process_udp, }[self.status](data, env) def alive(self): return not self.finish.is_set() def clean(self): self.finish.set() for sock in self.allsocks: sock.close() self.in_queue.queue.clear() self.out_queue.queue.clear() if self.sessionid in self.sessionmap: del self.sessionmap[self.sessionid] log.info("%s: quit, %d sessions left" % (self.sessionid, len(self.sessionmap.keys())))
class CeleryReporter(StatReporter): """ A legacy wrapper around old log reporting system to allow testing PowerPool 0.6 with SimpleCoin 0.7 """ one_sec_stats = ['queued'] gl_methods = [ '_queue_proc', '_report_one_min', '_report_payout_share_aggrs' ] defaults = StatReporter.defaults.copy() defaults.update( dict(celery_task_prefix='simplecoin.tasks', celery={'CELERY_DEFAULT_QUEUE': 'celery'}, share_batch_interval=60)) def __init__(self, config): self._configure(config) super(CeleryReporter, self).__init__() # setup our celery agent and monkey patch from celery import Celery self.celery = Celery() self.celery.conf.update(self.config['celery']) self.queue = Queue() self._aggr_shares = {} @property def status(self): dct = dict(queue_size=self.queue.qsize(), unrep_shares=len(self._aggr_shares)) return dct def log_one_minute(self, address, worker, algo, stamp, typ, amount): self._incr('queued') kwargs = { 'user': address, 'worker': worker, 'minute': stamp, 'valid_shares': 0 } if typ == StratumClient.VALID_SHARE: kwargs['valid_shares'] = amount if typ == StratumClient.DUP_SHARE: kwargs['dup_shares'] = amount if typ == StratumClient.LOW_DIFF_SHARE: kwargs['low_diff_shares'] = amount if typ == StratumClient.STALE_SHARE: kwargs['stale_shares'] = amount self.queue.put(("add_one_minute", [], kwargs)) def log_share(self, client, diff, typ, params, job=None, header_hash=None, header=None, **kwargs): super(CeleryReporter, self).log_share(client, diff, typ, params, job=job, header_hash=header_hash, header=header, **kwargs) # Aggregate valid shares to be reported in batches. SimpleCoin's Celery # worker can't really handle high load share logging with the way it's # built address = client.address if typ == StratumClient.VALID_SHARE: if address not in self._aggr_shares: self._aggr_shares[address] = diff else: self._aggr_shares[address] += diff def agent_send(self, *args, **kwargs): self._incr('queued') self.queue.put(("agent_receive", args, kwargs)) def add_block(self, address, height, total_subsidy, fees, hex_bits, hex_hash, currency, algo, merged=False, worker=None, **kwargs): self._incr('queued') # user, height, total_value, transaction_fees, bits, hash_hex, merged=None, worker=None kwargs = dict(user=address, height=height, total_value=total_subsidy, transaction_fees=fees, bits=hex_bits, hash_hex=hex_hash, merged=currency if merged else None, worker=worker) self.queue.put(("add_block", [], kwargs)) @loop() def _queue_proc(self): name, args, kwargs = self.queue.peek() try: if name != "agent_receive": self.logger.info( "Calling celery task {} with args: {}, kwargs: {}".format( name, args, kwargs)) self.celery.send_task( self.config['celery_task_prefix'] + '.' + name, args, kwargs) except Exception as e: self.logger.error( "Unable to communicate with celery broker! {}".format(e)) else: self.queue.get() @loop(interval='share_batch_interval', precise=True, fin='_report_payout_shares') def _report_payout_share_aggrs(self): self._report_payout_shares() def _report_payout_shares(self, exit_exc=None, caller=None): """ Goes through our internal aggregated share data and adds a celery task for each unque address. """ self.logger.info("Reporting shares for {:,} users".format( len(self._aggr_shares))) for address, shares in self._aggr_shares.items(): self.queue.put(("add_share", [address, shares], {})) del self._aggr_shares[address]
class WebSocket: def __init__(self, socket): self.socket = socket self.closed = False self.status = None self._receive_error = None self._queue = Queue() self.max_length = 10 * 1024 * 1024 gevent.spawn(self._listen) def set_max_message_length(self, length): self.max_length = length def _listen(self): try: while True: fin = False message = bytearray() is_first_message = True start_opcode = None while not fin: payload, opcode, fin = self._get_frame(max_length=self.max_length - len(message)) # Make sure continuation frames have correct information if not is_first_message and opcode != 0: self._error(STATUS_PROTOCOL_ERROR) if is_first_message: if opcode not in (OPCODE_TEXT, OPCODE_BINARY): self._error(STATUS_PROTOCOL_ERROR) # Save opcode start_opcode = opcode message += payload is_first_message = False message = bytes(message) if start_opcode == OPCODE_TEXT: # UTF-8 text try: message = message.decode() except UnicodeDecodeError: self._error(STATUS_DATA_ERROR) self._queue.put(message) except Exception as e: self.closed = True self._receive_error = e self._queue.put(None) # To make sure the error is read def receive(self): if not self._queue.empty(): return self.receive_nowait() if isinstance(self._receive_error, EOFError): return None if self._receive_error: raise self._receive_error self._queue.peek() return self.receive_nowait() def receive_nowait(self): ret = self._queue.get_nowait() if self._receive_error and not isinstance(self._receive_error, EOFError): raise self._receive_error return ret def send(self, data): if self.closed: raise EOFError() if isinstance(data, str): self._send_frame(OPCODE_TEXT, data.encode()) elif isinstance(data, bytes): self._send_frame(OPCODE_BINARY, data) else: raise TypeError("Expected str or bytes, got " + repr(type(data))) # Reads a frame from the socket. Pings, pongs and close packets are handled # automatically def _get_frame(self, max_length): while True: payload, opcode, fin = self._read_frame(max_length=max_length) if opcode == OPCODE_PING: self._send_frame(OPCODE_PONG, payload) elif opcode == OPCODE_PONG: pass elif opcode == OPCODE_CLOSE: if len(payload) >= 2: self.status = struct.unpack("!H", payload[:2])[0] was_closed = self.closed self.closed = True if not was_closed: # Send a close frame in response self.close(STATUS_OK) raise EOFError() else: return payload, opcode, fin # Low-level function, use _get_frame instead def _read_frame(self, max_length): header = self._recv_exactly(2) if not (header[1] & 0x80): self._error(STATUS_POLICY_VIOLATION) opcode = header[0] & 0xf fin = bool(header[0] & 0x80) payload_length = header[1] & 0x7f if payload_length == 126: payload_length = struct.unpack("!H", self._recv_exactly(2))[0] elif payload_length == 127: payload_length = struct.unpack("!Q", self._recv_exactly(8))[0] # Control frames are handled in a special way if opcode in (OPCODE_PING, OPCODE_PONG): max_length = 125 if payload_length > max_length: self._error(STATUS_TOO_LONG) mask = self._recv_exactly(4) payload = self._recv_exactly(payload_length) payload = self._unmask(payload, mask) return payload, opcode, fin def _recv_exactly(self, length): buf = bytearray() while len(buf) < length: block = self.socket.recv(min(4096, length - len(buf))) if block == b"": raise EOFError() buf += block return bytes(buf) def _unmask(self, payload, mask): def gen(c): return bytes([x ^ c for x in range(256)]) payload = bytearray(payload) payload[0::4] = payload[0::4].translate(gen(mask[0])) payload[1::4] = payload[1::4].translate(gen(mask[1])) payload[2::4] = payload[2::4].translate(gen(mask[2])) payload[3::4] = payload[3::4].translate(gen(mask[3])) return bytes(payload) def _send_frame(self, opcode, data): for i in range(0, len(data), SEND_PACKET_SIZE): part = data[i:i + SEND_PACKET_SIZE] fin = int(i == (len(data) - 1) // SEND_PACKET_SIZE * SEND_PACKET_SIZE) header = bytes( [ (opcode if i == 0 else 0) | (fin << 7), min(len(part), 126) ] ) if len(part) >= 126: header += struct.pack("!H", len(part)) self.socket.sendall(header + part) def _error(self, status): self.close(status) raise EOFError() def close(self, status=STATUS_OK): self.closed = True try: self._send_frame(OPCODE_CLOSE, struct.pack("!H", status)) except (BrokenPipeError, ConnectionResetError): pass self.socket.close()
class Notifier(object): def __init__(self, app=None): self._url = None self._channel = None self._interval = 1 self._started = False self._q = Queue() self._logger = None if app: self.init_app(app) def init_app(self, app): self._url = app.config['SLACK_INCOMING_WEBHOOK'] self._channel = app.config['SLACK_CHANNEL'] self._interval = 1/float(app.config['SLACK_RATE_LIMIT']) self._logger = app.logger spawn(self._loop) app.extensions['slack_notifier'] = self self._started = True self._logger.info( 'slack notifier started. min interval: %.1fs; default channel: %s', self._interval, self._channel) def notify(self, msg, channel=None, now=False): """ send a message to slack. The messages are buffered under the hood to avoid hitting Slack API rate limit. :param msg: message to send :param channel: channel to send the message """ if self._started: channel = channel if channel else self._channel if now: self._send(msg, channel) else: self._q.put((channel, msg)) def stop(self): self._started = False self.notify(id(self), None) # use id as token to stop def _send(self, message, channel): """ send to slack incoming webhook :param str message: message to send :param str channel: channel to send the message in :returns: True if send succeeds """ data = { 'text': message, 'parse': 'full', } if channel: data['channel'] = channel try: r = requests.post(self._url, data=json.dumps(data)) except (requests.ConnectionError, requests.Timeout) as e: self._logger.warning('Fail to send slack request: %s', e) return False else: if r.status_code == 200: return True else: self._logger.warning( 'Non-200 code returned from slack: %d - %s', r.status_code, r.content ) return False def _flush(self): """ flush current queuing messages """ togo = defaultdict(list) try: while True: channel, msg = self._q.get_nowait() togo[channel].append(msg) except Empty: pass flushed = [] for channel, messages in togo.iteritems(): msg = '\n'.join(messages) if not self._send(msg, channel): self._logger.error('fail to send message to slack %s - %s', channel, msg) else: flushed.append((channel, msg)) return flushed def _loop(self): """ send loop """ last_send = time.time() while True: top = self._q.peek(block=True) if top == id(self): # stop break interval = time.time() - last_send if interval >= self._interval: # flush queue flushed = self._flush() last_send = time.time() self._logger.debug( 'flush finished at %.3f: %s', last_send, flushed) else: sleep(interval) self.notify('Bye.') self._flush()
class ChainService(WiredService): """ Manages the chain and requests to it. """ # required by BaseService name = 'chain' default_config = dict(eth=dict(network_id=0, genesis_nonce=GENESIS_NONCE.encode('hex'))) # required by WiredService wire_protocol = eth_protocol.ETHProtocol # create for each peer # initialized after configure: chain = None genesis = None synchronizer = None config = None block_queue_size = 1024 transaction_queue_size = 1024 processed_gas = 0 processed_elapsed = 0 def __init__(self, app): self.config = app.config self.db = app.services.db assert self.db is not None super(ChainService, self).__init__(app) log.info('initializing chain') coinbase = app.services.accounts.coinbase _genesis = genesis(self.db, nonce=self.config['eth']['genesis_nonce'].decode('hex')) self.chain = Chain(self.db, genesis=_genesis, new_head_cb=self._on_new_head, coinbase=coinbase) log.info('chain at', number=self.chain.head.number) self.synchronizer = Synchronizer(self, force_sync=None) self.block_queue = Queue(maxsize=self.block_queue_size) self.transaction_queue = Queue(maxsize=self.transaction_queue_size) self.add_blocks_lock = False self.add_transaction_lock = gevent.lock.Semaphore() self.broadcast_filter = DuplicatesFilter() self.on_new_head_cbs = [] self.on_new_head_candidate_cbs = [] self.newblock_processing_times = deque(maxlen=1000) # gevent.spawn(update_watcher, self) @property def is_syncing(self): return self.synchronizer.synctask is not None @property def is_mining(self): if 'pow' in self.app.services: return self.app.services.pow.active return False def _on_new_head(self, block): for cb in self.on_new_head_cbs: cb(block) self._on_new_head_candidate() # we implicitly have a new head_candidate def _on_new_head_candidate(self): for cb in self.on_new_head_candidate_cbs: cb(self.chain.head_candidate) def add_transaction(self, tx, origin=None): log.debug('add_transaction', locked=self.add_transaction_lock.locked(), tx=tx) assert isinstance(tx, Transaction) assert origin is None or isinstance(origin, BaseProtocol) if tx.hash in self.broadcast_filter: log.debug('discarding known tx') # discard early return # validate transaction try: validate_transaction(self.chain.head_candidate, tx) log.debug('valid tx, broadcasting') self.broadcast_transaction(tx, origin=origin) # asap except InvalidTransaction as e: log.debug('invalid tx', error=e) return if origin is not None: # not locally added via jsonrpc if not self.is_mining or self.is_syncing: log.debug('discarding tx', syncing=self.is_syncing, mining=self.is_mining) return self.add_transaction_lock.acquire() success = self.chain.add_transaction(tx) self.add_transaction_lock.release() if success: self._on_new_head_candidate() def add_block(self, t_block, proto): "adds a block to the block_queue and spawns _add_block if not running" self.block_queue.put((t_block, proto)) # blocks if full if not self.add_blocks_lock: self.add_blocks_lock = True # need to lock here (ctx switch is later) gevent.spawn(self._add_blocks) def add_mined_block(self, block): log.debug('adding mined block', block=block) assert isinstance(block, Block) assert block.header.check_pow() if self.chain.add_block(block): log.debug('added', block=block, ts=time.time()) assert block == self.chain.head self.broadcast_newblock(block, chain_difficulty=block.chain_difficulty()) def knows_block(self, block_hash): "if block is in chain or in queue" if block_hash in self.chain: return True # check if queued or processed for i in range(len(self.block_queue.queue)): if block_hash == self.block_queue.queue[i][0].header.hash: return True return False def _add_blocks(self): log.debug('add_blocks', qsize=self.block_queue.qsize(), add_tx_lock=self.add_transaction_lock.locked()) assert self.add_blocks_lock is True self.add_transaction_lock.acquire() try: while not self.block_queue.empty(): t_block, proto = self.block_queue.peek() # peek: knows_block while processing if t_block.header.hash in self.chain: log.warn('known block', block=t_block) self.block_queue.get() continue if t_block.header.prevhash not in self.chain: log.warn('missing parent', block=t_block) self.block_queue.get() continue # FIXME, this is also done in validation and in synchronizer for new_blocks if not t_block.header.check_pow(): log.warn('invalid pow', block=t_block, FIXME='ban node') self.block_queue.get() continue try: # deserialize st = time.time() block = t_block.to_block(db=self.chain.db) elapsed = time.time() - st log.debug('deserialized', elapsed='%.4fs' % elapsed, ts=time.time(), gas_used=block.gas_used, gpsec=self.gpsec(block.gas_used, elapsed)) except processblock.InvalidTransaction as e: log.warn('invalid transaction', block=t_block, error=e, FIXME='ban node') self.block_queue.get() continue except VerificationFailed as e: log.warn('verification failed', error=e, FIXME='ban node') self.block_queue.get() continue log.debug('adding', block=block, ts=time.time()) if self.chain.add_block(block, forward_pending_transactions=self.is_mining): now = time.time() log.debug('added', block=block, ts=now, txs=len(block.get_transactions())) if t_block.newblock_timestamp: total = now - t_block.newblock_timestamp self.newblock_processing_times.append(total) avg = statistics.mean(self.newblock_processing_times) med = statistics.median(self.newblock_processing_times) max_ = max(self.newblock_processing_times) min_ = min(self.newblock_processing_times) log.debug('processing time', last=total, avg=avg, max=max_, min=min_, median=med) else: log.warn('could not add', block=block) self.block_queue.get() # remove block from queue (we peeked only) gevent.sleep(0.001) finally: self.add_blocks_lock = False self.add_transaction_lock.release() def gpsec(self, gas_spent=0, elapsed=0): if gas_spent: self.processed_gas += gas_spent self.processed_elapsed += elapsed return int(self.processed_gas / (0.001 + self.processed_elapsed)) def broadcast_newblock(self, block, chain_difficulty=None, origin=None): if not chain_difficulty: assert block.hash in self.chain chain_difficulty = block.chain_difficulty() assert isinstance(block, (eth_protocol.TransientBlock, Block)) if self.broadcast_filter.update(block.header.hash): log.debug('broadcasting newblock', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'newblock', args=(block, chain_difficulty), exclude_peers=[origin.peer] if origin else []) else: log.debug('already broadcasted block') def broadcast_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) if self.broadcast_filter.update(tx.hash): log.debug('broadcasting tx', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'transactions', args=(tx,), exclude_peers=[origin.peer] if origin else []) else: log.debug('already broadcasted tx') # wire protocol receivers ########### def on_wire_protocol_start(self, proto): log.debug('----------------------------------') log.debug('on_wire_protocol_start', proto=proto) assert isinstance(proto, self.wire_protocol) # register callbacks proto.receive_status_callbacks.append(self.on_receive_status) proto.receive_transactions_callbacks.append(self.on_receive_transactions) proto.receive_getblockhashes_callbacks.append(self.on_receive_getblockhashes) proto.receive_blockhashes_callbacks.append(self.on_receive_blockhashes) proto.receive_getblocks_callbacks.append(self.on_receive_getblocks) proto.receive_blocks_callbacks.append(self.on_receive_blocks) proto.receive_newblock_callbacks.append(self.on_receive_newblock) proto.receive_newblockhashes_callbacks.append(self.on_newblockhashes) # send status head = self.chain.head proto.send_status(chain_difficulty=head.chain_difficulty(), chain_head_hash=head.hash, genesis_hash=self.chain.genesis.hash) def on_wire_protocol_stop(self, proto): assert isinstance(proto, self.wire_protocol) log.debug('----------------------------------') log.debug('on_wire_protocol_stop', proto=proto) def on_receive_status(self, proto, eth_version, network_id, chain_difficulty, chain_head_hash, genesis_hash): log.debug('----------------------------------') log.debug('status received', proto=proto, eth_version=eth_version) assert eth_version == proto.version, (eth_version, proto.version) if network_id != self.config['eth'].get('network_id', proto.network_id): log.warn("invalid network id", remote_network_id=network_id, expected_network_id=self.config['eth'].get('network_id', proto.network_id)) raise eth_protocol.ETHProtocolError('wrong network_id') # check genesis if genesis_hash != self.chain.genesis.hash: log.warn("invalid genesis hash", remote_id=proto, genesis=genesis_hash.encode('hex')) raise eth_protocol.ETHProtocolError('wrong genesis block') # request chain self.synchronizer.receive_status(proto, chain_head_hash, chain_difficulty) # send transactions transactions = self.chain.get_transactions() if transactions: log.debug("sending transactions", remote_id=proto) proto.send_transactions(*transactions) # transactions def on_receive_transactions(self, proto, transactions): "receives rlp.decoded serialized" log.debug('----------------------------------') log.debug('remote_transactions_received', count=len(transactions), remote_id=proto) for tx in transactions: self.add_transaction(tx, origin=proto) # blockhashes ########### def on_newblockhashes(self, proto, newblockhashes): """ msg sent out if not the full block is propagated chances are high, that we get the newblock, though. """ log.debug('----------------------------------') log.debug("recv newnewblockhashes", num=len(newblockhashes), remote_id=proto) self.synchronizer.receive_newblockhashes(proto, newblockhashes) def on_receive_getblockhashes(self, proto, child_block_hash, count): log.debug('----------------------------------') log.debug("handle_get_blockhashes", count=count, block_hash=encode_hex(child_block_hash)) max_hashes = min(count, self.wire_protocol.max_getblockhashes_count) found = [] if child_block_hash not in self.chain: log.debug("unknown block") proto.send_blockhashes(*[]) return last = child_block_hash while len(found) < max_hashes: try: last = rlp.decode_lazy(self.chain.db.get(last))[0][0] # [head][prevhash] except KeyError: # this can happen if we started a chain download, which did not complete # should not happen if the hash is part of the canonical chain log.warn('KeyError in getblockhashes', hash=last) break if last: found.append(last) else: break log.debug("sending: found block_hashes", count=len(found)) proto.send_blockhashes(*found) def on_receive_blockhashes(self, proto, blockhashes): log.debug('----------------------------------') if blockhashes: log.debug("on_receive_blockhashes", count=len(blockhashes), remote_id=proto, first=encode_hex(blockhashes[0]), last=encode_hex(blockhashes[-1])) else: log.debug("recv 0 remote block hashes, signifying genesis block") self.synchronizer.receive_blockhashes(proto, blockhashes) # blocks ################ def on_receive_getblocks(self, proto, blockhashes): log.debug('----------------------------------') log.debug("on_receive_getblocks", count=len(blockhashes)) found = [] for bh in blockhashes[:self.wire_protocol.max_getblocks_count]: try: found.append(self.chain.db.get(bh)) except KeyError: log.debug("unknown block requested", block_hash=encode_hex(bh)) if found: log.debug("found", count=len(found)) proto.send_blocks(*found) def on_receive_blocks(self, proto, transient_blocks): log.debug('----------------------------------') blk_number = max(x.header.number for x in transient_blocks) if transient_blocks else 0 log.debug("recv blocks", count=len(transient_blocks), remote_id=proto, highest_number=blk_number) if transient_blocks: self.synchronizer.receive_blocks(proto, transient_blocks) def on_receive_newblock(self, proto, block, chain_difficulty): log.debug('----------------------------------') log.debug("recv newblock", block=block, remote_id=proto) self.synchronizer.receive_newblock(proto, block, chain_difficulty)
class CeleryReporter(Greenlet): one_min_stats = [] one_sec_stats = ['queued'] def _set_config(self, **config): self.config = dict(celery_task_prefix='simplecoin.tasks', celery={'CELERY_DEFAULT_QUEUE': 'celery'}, report_pool_stats=True, share_batch_interval=60, tracker_expiry_time=180) self.config.update(config) # check that we have at least one configured coin server if not self.config['celery_task_prefix']: self.logger.error("You need to specify a celery prefix") exit() def __init__(self, server, **config): Greenlet.__init__(self) self.logger = server.register_logger('reporter') self._set_config(**config) # setup our celery agent and monkey patch self.celery = Celery() self.celery.conf.update(self.config['celery']) self.share_reporter = None self.server = server self.server.register_stat_counters(self.one_min_stats, self.one_sec_stats) self.queue = Queue() self.addresses = {} self.workers = {} @property def status(self): dct = dict(queue_size=self.queue.qsize(), addresses_count=len(self.addresses), workers_count=len(self.workers)) dct.update({ key: self.server[key].summary() for key in self.one_min_stats + self.one_sec_stats }) return dct # Remote methods to send information to other servers ######################## def add_one_minute(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("add_one_minute", args, kwargs)) self.logger.info("Calling celery task {} with {}".format( "add_one_minute", args)) def add_share(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("add_share", args, kwargs)) self.logger.info("Calling celery task {} with {}".format( "add_shares", args)) def agent_send(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("agent_receive", args, kwargs)) def add_block(self, *args, **kwargs): self.server['queued'].incr() self.queue.put(("add_block", args, kwargs)) self.logger.info("Calling celery task {} with {}".format( "transmit_block", args)) def _run(self): self.share_reporter = spawn(self.report_loop) while True: self._queue_proc() def _queue_proc(self): name, args, kwargs = self.queue.peek() try: self.celery.send_task( self.config['celery_task_prefix'] + '.' + name, args, kwargs) except Exception as e: self.logger.error( "Unable to communicate with celery broker! {}".format(e)) else: self.queue.get() def report_loop(self): """ Repeatedly do our share reporting on an interval """ while True: sleep(self.config['share_batch_interval']) try: self._report_shares() except Exception: self.logger.error("Unhandled error in report shares", exc_info=True) def _report_shares(self, flush=False): """ Goes through our internal aggregated share data structures and reports them to our external storage. If asked to flush it will report all one minute shares, otherwise it will only report minutes that have passed. """ if flush: self.logger.info("Flushing all aggreated share data...") self.logger.info("Reporting shares for {:,} users".format( len(self.addresses))) t = time.time() for address, tracker in self.addresses.items(): tracker.report() # if the last log time was more than expiry time ago... if (tracker.last_log + self.config['tracker_expiry_time']) < t: assert tracker.unreported == 0 del self.addresses[address] self.logger.info("Shares reported (queued) in {}".format( time_format(time.time() - t))) self.logger.info( "Reporting one minute shares for {:,} address/workers".format( len(self.workers))) t = time.time() if flush: upper = t + 10 else: upper = (t // 60) * 60 for worker_addr, tracker in self.workers.items(): tracker.report(upper) # if the last log time was more than expiry time ago... if (tracker.last_log + self.config['tracker_expiry_time']) < t: assert sum(tracker.slices.itervalues()) == 0 del self.workers[worker_addr] self.logger.info("One minute shares reported (queued) in {}".format( time_format(time.time() - t))) def log_share(self, address, worker, amount, typ): """ Logs a share for a user and user/worker into all three share aggregate sources. """ # log the share for the pool cache total as well if address != "pool" and self.config['report_pool_stats']: self.log_share("pool", '', amount, typ) # collecting for reporting to the website for display in graphs addr_worker = (address, worker) if addr_worker not in self.workers: self.workers[addr_worker] = WorkerTracker(self, address, worker) self.workers[(address, worker)].count_share(amount, typ) # reporting for payout share logging and vardiff rates if typ == StratumClient.VALID_SHARE and address != "pool": if address not in self.addresses: self.addresses[address] = AddressTracker(self, address) # for tracking vardiff speeds self.addresses[address].count_share(amount) def kill(self, *args, **kwargs): self.share_reporter.kill(*args, **kwargs) self._report_shares(flush=True) self.logger.info("Flushing the reporter task queue, {} items blocking " "exit".format(self.queue.qsize())) while not self.queue.empty(): self._queue_proc() self.logger.info("Shutting down CeleryReporter..") Greenlet.kill(self, *args, **kwargs)
class Notifier(object): def __init__(self, app=None): self._url = None self._channel = None self._interval = 1 self._started = False self._q = Queue() self._logger = None if app: self.init_app(app) def init_app(self, app): self._url = app.config['SLACK_INCOMING_WEBHOOK'] self._channel = app.config['SLACK_CHANNEL'] self._interval = 1 / float(app.config['SLACK_RATE_LIMIT']) self._logger = app.logger spawn(self._loop) app.extensions['slack_notifier'] = self self._started = True self._logger.info( 'slack notifier started. min interval: %.1fs; default channel: %s', self._interval, self._channel) def notify(self, msg, channel=None, now=False): """ send a message to slack. The messages are buffered under the hood to avoid hitting Slack API rate limit. :param msg: message to send :param channel: channel to send the message """ if self._started: channel = channel if channel else self._channel if now: self._send(msg, channel) else: self._q.put((channel, msg)) def stop(self): self._started = False self.notify(id(self), None) # use id as token to stop def _send(self, message, channel): """ send to slack incoming webhook :param str message: message to send :param str channel: channel to send the message in :returns: True if send succeeds """ data = { 'text': message, 'parse': 'full', } if channel: data['channel'] = channel try: r = requests.post(self._url, data=json.dumps(data)) except (requests.ConnectionError, requests.Timeout) as e: self._logger.warning('Fail to send slack request: %s', e) return False else: if r.status_code == 200: return True else: self._logger.warning( 'Non-200 code returned from slack: %d - %s', r.status_code, r.content) return False def _flush(self): """ flush current queuing messages """ togo = defaultdict(list) try: while True: channel, msg = self._q.get_nowait() togo[channel].append(msg) except Empty: pass flushed = [] for channel, messages in togo.iteritems(): msg = '\n'.join(messages) if not self._send(msg, channel): self._logger.error('fail to send message to slack %s - %s', channel, msg) else: flushed.append((channel, msg)) return flushed def _loop(self): """ send loop """ last_send = time.time() while True: top = self._q.peek(block=True) if top == id(self): # stop break interval = time.time() - last_send if interval >= self._interval: # flush queue flushed = self._flush() last_send = time.time() self._logger.debug('flush finished at %.3f: %s', last_send, flushed) else: sleep(interval) self.notify('Bye.') self._flush()
class ChainService(WiredService): """ Manages the chain and requests to it. """ # required by BaseService name = 'chain' default_config = dict(eth=dict(network_id=0, genesis='', pruning=-1), block=ethereum_config.default_config) # required by WiredService wire_protocol = eth_protocol.ETHProtocol # create for each peer # initialized after configure: chain = None genesis = None synchronizer = None config = None block_queue_size = 1024 processed_gas = 0 processed_elapsed = 0 process_time_queue_period = 5 def __init__(self, app): self.config = app.config sce = self.config['eth'] if int(sce['pruning']) >= 0: self.db = RefcountDB(app.services.db) if "I am not pruning" in self.db.db: raise RuntimeError( "The database in '{}' was initialized as non-pruning. " "Can not enable pruning now.".format( self.config['data_dir'])) self.db.ttl = int(sce['pruning']) self.db.db.put("I am pruning", "1") else: self.db = app.services.db if "I am pruning" in self.db: raise RuntimeError( "The database in '{}' was initialized as pruning. " "Can not disable pruning now".format( self.config['data_dir'])) self.db.put("I am not pruning", "1") if 'network_id' in self.db: db_network_id = self.db.get(b'network_id') if db_network_id != to_string(sce['network_id']): raise RuntimeError( "The database in '{}' was initialized with network id {} and can not be used " "when connecting to network id {}. Please choose a different data directory." .format(self.config['data_dir'], db_network_id, sce['network_id'])) else: self.db.put(b'network_id', to_string(sce['network_id'])) self.db.commit() assert self.db is not None super(ChainService, self).__init__(app) log.info('initializing chain') coinbase = app.services.accounts.coinbase env = Env(self.db, sce['block']) genesis_data = sce.get('genesis_data', {}) if not genesis_data: genesis_data = mk_genesis_data(env) self.chain = Chain(env=env, genesis=genesis_data, coinbase=coinbase, new_head_cb=self._on_new_head) header = self.chain.state.prev_headers[0] log.info('chain at', number=header.number) if 'genesis_hash' in sce: assert sce['genesis_hash'] == self.chain.genesis.hex_hash, \ "Genesis hash mismatch.\n Expected: %s\n Got: %s" % ( sce['genesis_hash'], self.chain.genesis.hex_hash) self.dao_challenges = dict() self.synchronizer = Synchronizer(self, force_sync=None) self.block_queue = Queue(maxsize=self.block_queue_size) # When the transaction_queue is modified, we must set # self._head_candidate_needs_updating to True in order to force the # head candidate to be updated. self.transaction_queue = TransactionQueue() self._head_candidate_needs_updating = True # Initialize a new head candidate. _ = self.head_candidate self.min_gasprice = 20 * 10**9 # TODO: better be an option to validator service? self.add_blocks_lock = False self.add_transaction_lock = gevent.lock.Semaphore() self.broadcast_filter = DuplicatesFilter() self.on_new_head_cbs = [] self.newblock_processing_times = deque(maxlen=1000) gevent.spawn_later(self.process_time_queue_period, self.process_time_queue) @property def is_syncing(self): return self.synchronizer.synctask is not None @property def is_mining(self): if 'pow' in self.app.services: return self.app.services.pow.active if 'validator' in self.app.services: return self.app.services.validator.active return False def process_time_queue(self): try: self.chain.process_time_queue() except Exception as e: log.info(str(e)) finally: gevent.spawn_later(self.process_time_queue_period, self.process_time_queue) # TODO: Move to pyethereum def get_receipts(self, block): # Receipts are no longer stored in the database, so need to generate # them on the fly here. temp_state = self.chain.mk_poststate_of_blockhash( block.header.prevhash) initialize(temp_state, block) for tx in block.transactions: apply_transaction(temp_state, tx) return temp_state.receipts def _on_new_head(self, block): log.debug('new head cbs', num=len(self.on_new_head_cbs)) self.transaction_queue = self.transaction_queue.diff( block.transactions) self._head_candidate_needs_updating = True for cb in self.on_new_head_cbs: cb(block) @property def head_candidate(self): if self._head_candidate_needs_updating: self._head_candidate_needs_updating = False # Make a copy of self.transaction_queue because # make_head_candidate modifies it. txqueue = copy.deepcopy(self.transaction_queue) self._head_candidate, self._head_candidate_state = make_head_candidate( self.chain, txqueue, timestamp=int(time.time())) return self._head_candidate def add_transaction(self, tx, origin=None, force_broadcast=False, force=False): if self.is_syncing: if force_broadcast: assert origin is None # only allowed for local txs log.debug('force broadcasting unvalidated tx') self.broadcast_transaction(tx, origin=origin) return # we can not evaluate the tx based on outdated state log.debug('add_transaction', locked=(not self.add_transaction_lock.locked()), tx=tx) assert isinstance(tx, Transaction) assert origin is None or isinstance(origin, BaseProtocol) if tx.hash in self.broadcast_filter: log.debug('discarding known tx') # discard early return # validate transaction try: # Transaction validation for broadcasting. Transaction is validated # against the current head candidate. validate_transaction(self._head_candidate_state, tx) log.debug('valid tx, broadcasting') self.broadcast_transaction(tx, origin=origin) # asap except InvalidTransaction as e: log.debug('invalid tx', error=e) return if origin is not None: # not locally added via jsonrpc if not self.is_mining or self.is_syncing: log.debug('discarding tx', syncing=self.is_syncing, mining=self.is_mining) return if tx.gasprice >= self.min_gasprice: self.add_transaction_lock.acquire() self.transaction_queue.add_transaction(tx, force=force) self._head_candidate_needs_updating = True self.add_transaction_lock.release() else: log.info("too low gasprice, ignore", tx=encode_hex(tx.hash)[:8], gasprice=tx.gasprice) def check_header(self, header): return check_pow(self.chain.state, header) def add_block(self, t_block, proto): "adds a block to the block_queue and spawns _add_block if not running" self.block_queue.put((t_block, proto)) # blocks if full if not self.add_blocks_lock: self.add_blocks_lock = True # need to lock here (ctx switch is later) gevent.spawn(self._add_blocks) def add_mined_block(self, block): log.debug('adding mined block', block=block) assert isinstance(block, Block) if self.chain.add_block(block): log.debug('added', block=block, ts=time.time()) assert block == self.chain.head self.transaction_queue = self.transaction_queue.diff( block.transactions) self._head_candidate_needs_updating = True self.broadcast_newblock( block, chain_difficulty=self.chain.get_score(block)) return True log.debug('failed to add', block=block, ts=time.time()) return False def knows_block(self, block_hash): "if block is in chain or in queue" if self.chain.has_blockhash(block_hash): return True # check if queued or processed for i in range(len(self.block_queue.queue)): if block_hash == self.block_queue.queue[i][0].header.hash: return True return False def _add_blocks(self): log.debug('add_blocks', qsize=self.block_queue.qsize(), add_tx_lock=self.add_transaction_lock.locked()) assert self.add_blocks_lock is True self.add_transaction_lock.acquire() try: while not self.block_queue.empty(): # sleep at the beginning because continue keywords will skip bottom gevent.sleep(0.001) t_block, proto = self.block_queue.peek( ) # peek: knows_block while processing if self.chain.has_blockhash(t_block.header.hash): log.warn('known block', block=t_block) self.block_queue.get() continue if not self.chain.has_blockhash(t_block.header.prevhash): log.warn('missing parent', block=t_block, head=self.chain.head) self.block_queue.get() continue try: # deserialize st = time.time() block = t_block.to_block() elapsed = time.time() - st log.debug('deserialized', elapsed='%.4fs' % elapsed, ts=time.time(), gas_used=block.gas_used, gpsec=self.gpsec(block.gas_used, elapsed)) except InvalidTransaction as e: log.warn('invalid transaction', block=t_block, error=e, FIXME='ban node') errtype = \ 'InvalidNonce' if isinstance(e, InvalidNonce) else \ 'NotEnoughCash' if isinstance(e, InsufficientBalance) else \ 'OutOfGasBase' if isinstance(e, InsufficientStartGas) else \ 'other_transaction_error' sentry.warn_invalid(t_block, errtype) self.block_queue.get() continue except VerificationFailed as e: log.warn('verification failed', error=e, FIXME='ban node') sentry.warn_invalid(t_block, 'other_block_error') self.block_queue.get() continue # All checks passed log.debug('adding', block=block, ts=time.time()) if self.chain.add_block(block): now = time.time() log.info('added', block=block, txs=block.transaction_count, gas_used=block.gas_used) if t_block.newblock_timestamp: total = now - t_block.newblock_timestamp self.newblock_processing_times.append(total) avg = statistics.mean(self.newblock_processing_times) med = statistics.median(self.newblock_processing_times) max_ = max(self.newblock_processing_times) min_ = min(self.newblock_processing_times) log.info('processing time', last=total, avg=avg, max=max_, min=min_, median=med) if self.is_mining: self.transaction_queue = self.transaction_queue.diff( block.transactions) else: log.warn('could not add', block=block) self.block_queue.get( ) # remove block from queue (we peeked only) finally: self.add_blocks_lock = False self.add_transaction_lock.release() def gpsec(self, gas_spent=0, elapsed=0): if gas_spent: self.processed_gas += gas_spent self.processed_elapsed += elapsed return int( old_div(self.processed_gas, (0.001 + self.processed_elapsed))) def broadcast_newblock(self, block, chain_difficulty=None, origin=None): if not chain_difficulty: assert self.chain.has_blockhash(block.hash) chain_difficulty = self.chain.get_score(block) assert isinstance(block, (eth_protocol.TransientBlock, Block)) if self.broadcast_filter.update(block.header.hash): log.debug('broadcasting newblock', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'newblock', args=(block, chain_difficulty), exclude_peers=[origin.peer] if origin else []) else: log.debug('already broadcasted block') def broadcast_transaction(self, tx, origin=None): assert isinstance(tx, Transaction) if self.broadcast_filter.update(tx.hash): log.debug('broadcasting tx', origin=origin) bcast = self.app.services.peermanager.broadcast bcast(eth_protocol.ETHProtocol, 'transactions', args=(tx, ), exclude_peers=[origin.peer] if origin else []) else: log.debug('already broadcasted tx') def query_headers(self, hash_mode, max_hashes, skip, reverse, origin_hash=None, number=None): headers = [] unknown = False while not unknown and len(headers) < max_hashes: if hash_mode: if not origin_hash: break block = self.chain.get_block(origin_hash) if not block: break # If reached genesis, stop if block.number == 0: break origin = block.header else: # If reached genesis, stop if number is None or number == 0: break block = self.chain.get_block_by_number(number) if block is None: break origin = block.header headers.append(origin) if hash_mode: # hash traversal if reverse: for i in range(skip + 1): try: block = self.chain.get_block(origin_hash) if block: origin_hash = block.prevhash else: unknown = True break except KeyError: unknown = True break else: blockhash = self.chain.get_blockhash_by_number( origin.number + skip + 1) try: # block = self.chain.get_block(blockhash) if block and self.chain.get_blockhashes_from_hash( blockhash, skip + 1)[skip] == origin_hash: origin_hash = blockhash else: unknown = True except KeyError: unknown = True else: # number traversal if reverse: if number >= (skip + 1): number -= (skip + 1) else: unknown = True else: number += (skip + 1) return headers # wire protocol receivers ########### def on_wire_protocol_start(self, proto): log.debug('----------------------------------') log.debug('on_wire_protocol_start', proto=proto) assert isinstance(proto, self.wire_protocol) # register callbacks proto.receive_status_callbacks.append(self.on_receive_status) proto.receive_newblockhashes_callbacks.append(self.on_newblockhashes) proto.receive_transactions_callbacks.append( self.on_receive_transactions) proto.receive_getblockheaders_callbacks.append( self.on_receive_getblockheaders) proto.receive_blockheaders_callbacks.append( self.on_receive_blockheaders) proto.receive_getblockbodies_callbacks.append( self.on_receive_getblockbodies) proto.receive_blockbodies_callbacks.append(self.on_receive_blockbodies) proto.receive_newblock_callbacks.append(self.on_receive_newblock) # send status head = self.chain.head proto.send_status(chain_difficulty=self.chain.get_score(head), chain_head_hash=head.hash, genesis_hash=self.chain.genesis.hash) def on_wire_protocol_stop(self, proto): assert isinstance(proto, self.wire_protocol) log.debug('----------------------------------') log.debug('on_wire_protocol_stop', proto=proto) def on_receive_status(self, proto, eth_version, network_id, chain_difficulty, chain_head_hash, genesis_hash): log.debug('----------------------------------') log.debug('status received', proto=proto, eth_version=eth_version) if eth_version != proto.version: if ('eth', proto.version) in proto.peer.remote_capabilities: # if remote peer is capable of our version, keep the connection # even the peer tried a different version pass else: log.debug("no capable protocol to use, disconnect", proto=proto, eth_version=eth_version) proto.send_disconnect(proto.disconnect.reason.useless_peer) return if network_id != self.config['eth'].get('network_id', proto.network_id): log.debug("invalid network id", remote_network_id=network_id, expected_network_id=self.config['eth'].get( 'network_id', proto.network_id)) raise eth_protocol.ETHProtocolError('wrong network_id') # check genesis if genesis_hash != self.chain.genesis.hash: log.warn("invalid genesis hash", remote_id=proto, genesis=encode_hex(genesis_hash)) raise eth_protocol.ETHProtocolError('wrong genesis block') # initiate DAO challenge self.dao_challenges[proto] = (DAOChallenger(self, proto), chain_head_hash, chain_difficulty) def on_dao_challenge_answer(self, proto, result): if result: log.debug("DAO challenge passed") _, chain_head_hash, chain_difficulty = self.dao_challenges[proto] # request chain self.synchronizer.receive_status(proto, chain_head_hash, chain_difficulty) # send transactions transactions = self.transaction_queue.peek() if transactions: log.debug("sending transactions", remote_id=proto) proto.send_transactions(*transactions) else: log.debug("peer failed to answer DAO challenge, stop.", proto=proto) if proto.peer: proto.peer.stop() del self.dao_challenges[proto] # transactions def on_receive_transactions(self, proto, transactions): "receives rlp.decoded serialized" log.debug('----------------------------------') log.debug('remote_transactions_received', count=len(transactions), remote_id=proto) for tx in transactions: self.add_transaction(tx, origin=proto) # blockhashes ########### def on_newblockhashes(self, proto, newblockhashes): """ msg sent out if not the full block is propagated chances are high, that we get the newblock, though. """ log.debug('----------------------------------') log.debug("recv newblockhashes", num=len(newblockhashes), remote_id=proto) assert len(newblockhashes) <= 256 self.synchronizer.receive_newblockhashes(proto, newblockhashes) def on_receive_getblockheaders(self, proto, hash_or_number, block, amount, skip, reverse): hash_mode = 1 if hash_or_number[0] else 0 block_id = encode_hex( hash_or_number[0]) if hash_mode else hash_or_number[1] log.debug('----------------------------------') log.debug("handle_getblockheaders", amount=amount, block=block_id) headers = [] max_hashes = min(amount, self.wire_protocol.max_getblockheaders_count) if hash_mode: origin_hash = hash_or_number[0] else: if is_dao_challenge(self.config['eth']['block'], hash_or_number[1], amount, skip): log.debug("sending: answer DAO challenge") headers.append(build_dao_header(self.config['eth']['block'])) proto.send_blockheaders(*headers) return try: origin_hash = self.chain.get_blockhash_by_number( hash_or_number[1]) except KeyError: origin_hash = b'' if not origin_hash or not self.chain.has_blockhash(origin_hash): log.debug('unknown block: {}'.format(encode_hex(origin_hash))) proto.send_blockheaders(*[]) return headers = self.query_headers( hash_mode, max_hashes, skip, reverse, origin_hash=origin_hash, number=block_id, ) log.debug("sending: found blockheaders", count=len(headers)) proto.send_blockheaders(*headers) def on_receive_blockheaders(self, proto, blockheaders): log.debug('----------------------------------') if blockheaders: log.debug("on_receive_blockheaders", count=len(blockheaders), remote_id=proto, first=encode_hex(blockheaders[0].hash), last=encode_hex(blockheaders[-1].hash)) else: log.debug("recv 0 remote block headers, signifying genesis block") if proto in self.dao_challenges: self.dao_challenges[proto][0].receive_blockheaders( proto, blockheaders) else: self.synchronizer.receive_blockheaders(proto, blockheaders) # blocks ################ def on_receive_getblockbodies(self, proto, blockhashes): log.debug('----------------------------------') log.debug("on_receive_getblockbodies", count=len(blockhashes)) found = [] for bh in blockhashes[:self.wire_protocol.max_getblocks_count]: try: found.append(self.chain.get_block(bh)) except KeyError: log.debug("unknown block requested", block_hash=encode_hex(bh)) if found: log.debug("found", count=len(found)) proto.send_blockbodies(*found) def on_receive_blockbodies(self, proto, bodies): log.debug('----------------------------------') log.debug("recv block bodies", count=len(bodies), remote_id=proto) if bodies: self.synchronizer.receive_blockbodies(proto, bodies) def on_receive_newblock(self, proto, block, chain_difficulty): log.debug('----------------------------------') log.debug("recv newblock", block=block, remote_id=proto) self.synchronizer.receive_newblock(proto, block, chain_difficulty)