def initialize():
# Creating capped handler
self.handler_periodical = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=2.0,
buffer_early_flush_level=logging.CRITICAL)
self.log.removeHandler(self.handler)
self.log.addHandler(self.handler_periodical)
def setUp(self):
self.handler = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=None,
buffer_early_flush_level=logging.CRITICAL
)
self.log = logging.getLogger('testLogger')
self.log.setLevel(logging.DEBUG)
self.log.addHandler(self.handler)
self.old_stderr = sys.stdout
sys.stderr = StringIO()
def get_logger(self):
if self.logger == None:
format = '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
logging.basicConfig(format=format)
formatter = logging.Formatter(format)
self.logger = logging.getLogger()
filehandler = RotatingFileHandler("./logs/bigcgi.log",
maxBytes=50000,
backupCount=2)
filehandler.setFormatter(formatter)
self.logger.addHandler(filehandler)
try:
handler = BufferedMongoHandler(
host='localhost',
capped=True,
database_name="bigcgi-logs",
username=AppSettings.DATABASE_USERNAME,
password=AppSettings.DATABASE_PASSWORD,
authentication_db="bigcgi-main",
buffer_size=100,
buffer_periodical_flush_timing=10.0,
buffer_early_flush_level=logging.CRITICAL,
connectTimeoutMS=5000,
serverSelectionTimeoutMS=5000,
)
self.logger.addHandler(handler)
except pymongo.errors.ServerSelectionTimeoutError:
print("Failed to connecto to MongoDB logger.")
sys.exit(1)
self.logger.setLevel("INFO")
return self.logger
def setUp(self):
self.handler = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=None,
buffer_early_flush_level=logging.CRITICAL
)
self.log = logging.getLogger('testLogger')
self.log.setLevel(logging.DEBUG)
self.log.addHandler(self.handler)
self.old_stderr = sys.stdout
sys.stderr = StringIO()
def log_factory(db_name):
mongo_host = os.environ.get('MONGO_URI')
handler = BufferedMongoHandler(host=mongo_host,
database_name=db_name,
collection='crawler_logs',
buffer_early_flush_level=logging.ERROR)
logger = logging.getLogger()
log = logging.getLogger('cardataLogger')
log.setLevel(logging.DEBUG)
log.handlers = []
log.addHandler(handler)
return log, handler
def test_buffer_periodical_flush(self):
# Creating capped handler
self.handler_periodical = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=2.0,
buffer_early_flush_level=logging.CRITICAL)
self.log.removeHandler(self.handler)
self.log.addHandler(self.handler_periodical)
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database") # except if your computer is really slow
self.assertEqual(len(self.handler_periodical.buffer), 1, "Buffer size should be 1")
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler_periodical.buffer), 2, "Buffer size should be 2")
time.sleep(2.5) # wait a bit so the periodical timer thread has kicked off the buffer flush
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNotNone(document, "Should not have been written to database")
doc_amount = self.handler_periodical.collection.find({'message': 'test periodical buffer'}).count()
self.assertEqual(doc_amount, 2, "Should have found 2 documents written to database")
self.assertEqual(len(self.handler_periodical.buffer), 0, "Buffer should be empty")
self.assertTrue(self.handler_periodical.buffer_timer_thread.is_alive())
self.handler_periodical.destroy()
time.sleep(0.2) # waiting a tiny bit so that the child thread actually exits
self.assertFalse(self.handler_periodical.buffer_timer_thread.is_alive(),
"Child timer thread should be dead by now. Slow computer?")
# reset to previous
self.log.removeHandler(self.handler_periodical)
self.log.addHandler(self.handler)
def get_handler():
'''
Return a log4mongo logging handler.
Use docker networking if in a docker container.
Otherwise use a mongodb that exists on the localhost
'''
if os.path.exists('/.dockerenv'):
host = 'mongo'
else:
host = 'localhost'
# Buffered handler writes logs periodically, to prevent frequent write-locks
handler = BufferedMongoHandler(host=host, port=27017,
buffer_size=1000,
buffer_periodical_flush_timing=10.0,
buffer_early_flush_level=logging.CRITICAL)
return handler
def test_buffer_periodical_flush(self):
# Creating capped handler
self.handler_periodical = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=2.0,
buffer_early_flush_level=logging.CRITICAL)
self.log.removeHandler(self.handler)
self.log.addHandler(self.handler_periodical)
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database") # except if your computer is really slow
self.assertEqual(len(self.handler_periodical.buffer), 1, "Buffer size should be 1")
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler_periodical.buffer), 2, "Buffer size should be 2")
time.sleep(2.5) # wait a bit so the periodical timer thread has kicked off the buffer flush
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNotNone(document, "Should not have been written to database")
doc_amount = self.handler_periodical.collection.find({'message': 'test periodical buffer'}).count()
self.assertEqual(doc_amount, 2, "Should have found 2 documents written to database")
self.assertEqual(len(self.handler_periodical.buffer), 0, "Buffer should be empty")
self.assertTrue(self.handler_periodical.buffer_timer_thread.is_alive())
self.handler_periodical.destroy()
time.sleep(0.2) # waiting a tiny bit so that the child thread actually exits
self.assertFalse(self.handler_periodical.buffer_timer_thread.is_alive(),
"Child timer thread should be dead by now. Slow computer?")
# reset to previous
self.log.removeHandler(self.handler_periodical)
self.log.addHandler(self.handler)
def getMongoLogHandler(loggerName=None, **kwargs):
"""
:param loggerName: logger名，整个项目应该共用一个名称，
这个很重要，为了后期按项目筛选日志
:param kwargs: 数据库的信息
:return:
"""
fmt = MongoFormatter(loggerName=loggerName)
mlh = BufferedMongoHandler(
# host='222.178.152.79',
# port=4316,
# database_name='origin',
# collection='org_logs',
# username='******',
# password='******',
# authSource='admin',
formatter=fmt,
# capped=True,
buffer_size=100, # buffer size.
buffer_periodical_flush_timing=10.0, # periodical flush every 10 seconds
buffer_early_flush_level=logging.CRITICAL, # early flush level
**kwargs
)
# mlh = MongoHandler(
# host='222.178.152.79',
# port=4316,
# database_name='origin',
# collection='org_logs',
# username='******',
# password='******',
# authSource='admin',
# formatter=fmt
# )
return mlh
def initialize_access_logger(app):
class AccessRecordFormatter(logging.Formatter):
def format(self, record):
remote_address, method, path, status = record.args
document = {
"timestamp": datetime.datetime.utcnow(),
"remote_address": remote_address,
"method": method,
"path": path,
"status": status
}
return document
access_handler = BufferedMongoHandler(
host=app.config["MONGO_HOST"],
port=app.config["MONGO_PORT"],
database_name=app.config["MONGO_DB"],
collection="access_log",
username=app.config["MONGO_USER"],
password=app.config["MONGO_PASSWORD"],
authentication_db=app.config["MONGO_DB"],
formatter=AccessRecordFormatter(),
buffer_size=100,
buffer_periodical_flush_timing=10.0,
buffer_early_flush_level=logging.CRITICAL,
)
access_logger = logging.getLogger("flask.app.access")
access_logger.setLevel(logging.INFO)
access_logger.addHandler(access_handler)
@app.after_request
def after_request(response):
logger = logging.getLogger("flask.app.access")
logger.info("", request.remote_addr, request.method, request.path,
response.status)
return response
class TestBufferedMongoHandler(TestMongoHandler):
collection_name = 'buffered_logs_test'
def setUp(self):
self.handler = BufferedMongoHandler(
host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5,
buffer_periodical_flush_timing=None,
buffer_early_flush_level=logging.CRITICAL)
self.log = logging.getLogger('testLogger')
self.log.setLevel(logging.DEBUG)
self.log.addHandler(self.handler)
self.old_stderr = sys.stdout
sys.stderr = StringIO()
def force_flush(self):
self.handler.flush_to_mongo()
def test_contextual_info(self):
self.log.info('test message with contextual info',
extra={
'ip': '127.0.0.1',
'host': 'localhost'
})
self.force_flush()
document = self.handler.collection.find_one({
'message': 'test message with contextual info',
'level': 'INFO'
})
self.assertEqual(document['message'],
'test message with contextual info')
self.assertEqual(document['level'], 'INFO')
self.assertEqual(document['ip'], '127.0.0.1')
self.assertEqual(document['host'], 'localhost')
def test_contextual_info_adapter(self):
adapter = logging.LoggerAdapter(self.log, {
'ip': '127.0.0.1',
'host': 'localhost'
})
adapter.info('test message with contextual info')
self.force_flush()
document = self.handler.collection.find_one({
'message': 'test message with contextual info',
'level': 'INFO'
})
self.assertEqual(document['message'],
'test message with contextual info')
self.assertEqual(document['level'], 'INFO')
self.assertEqual(document['ip'], '127.0.0.1')
self.assertEqual(document['host'], 'localhost')
def test_emit(self):
self.log.warning('test message')
self.force_flush()
document = self.handler.collection.find_one({
'message': 'test message',
'level': 'WARNING'
})
self.assertEqual(document['message'], 'test message')
self.assertEqual(document['level'], 'WARNING')
def test_emit_exception(self):
try:
raise Exception('exc1')
except:
self.log.exception('test message')
self.force_flush()
document = self.handler.collection.find_one({
'message': 'test message',
'level': 'ERROR'
})
self.assertEqual(document['message'], 'test message')
self.assertEqual(document['level'], 'ERROR')
self.assertEqual(document['exception']['message'], 'exc1')
def test_emit_fail(self):
self.handler.collection = ''
self.log.warn('test warning')
self.force_flush()
val = sys.stderr.getvalue()
self.assertRegexpMatches(
val, r"AttributeError: 'str' object has no attribute '{}'".format(
write_many_method))
def test_buffer(self):
self.force_flush()
self.assertEqual(len(self.handler.buffer), 0,
"Ensure buffer should be empty")
self.log.warning('test_buffer message')
document = self.handler.collection.find_one(
{'message': 'test_buffer message'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler.buffer), 1,
"Buffer size should be 1")
self.log.info('test_buffer message')
self.log.debug('test_buffer message')
self.log.info('test_buffer message')
doc_amount = self.handler.collection.find({
'message':
'test_buffer message'
}).count()
self.assertEqual(doc_amount, 0,
"Nothing should have been written to database")
self.assertEqual(len(self.handler.buffer), 4,
"Buffer size should be 4")
self.log.warning('test_buffer message')
doc_amount = self.handler.collection.find({
'message':
'test_buffer message'
}).count()
self.assertEqual(
doc_amount, 5,
"Buffer size reached, buffer should have been written to database")
self.assertEqual(len(self.handler.buffer), 0,
"Ensure buffer should be empty")
self.log.warning('test_buffer message 2')
document = self.handler.collection.find_one(
{'message': 'test_buffer message 2'})
self.assertIsNone(document, 'Should not have been written to database')
self.assertEqual(len(self.handler.buffer), 1,
"Buffer size should be 1")
def test_buffer_early_flush(self):
self.force_flush()
self.assertEqual(len(self.handler.buffer), 0,
"Ensure buffer should be empty")
self.log.info('test_buffer_early_flush message')
document = self.handler.collection.find_one(
{'message': 'test_buffer_early_flush message'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler.buffer), 1,
"Buffer size should be 1")
self.log.critical('test_buffer_early_flush message')
doc_amount = self.handler.collection.find({
'message':
'test_buffer_early_flush message'
}).count()
self.assertEqual(doc_amount, 2,
"2 messages should have been written to database")
self.assertEqual(len(self.handler.buffer), 0,
"Buffer should now be empty")
doc_amount = self.handler.collection.find({
'message': 'test_buffer_early_flush message',
'level': 'INFO'
}).count()
self.assertEqual(
doc_amount, 1,
"One INFO message should have been written to database")
doc_amount = self.handler.collection.find({
'message': 'test_buffer_early_flush message',
'level': 'CRITICAL'
}).count()
self.assertEqual(
doc_amount, 1,
"One CRITICAL message should have been written to database")
def _buffer_periodical_flush(self, is_initialized_in_thread):
def initialize():
# Creating capped handler
self.handler_periodical = BufferedMongoHandler(
host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5,
buffer_periodical_flush_timing=2.0,
buffer_early_flush_level=logging.CRITICAL)
self.log.removeHandler(self.handler)
self.log.addHandler(self.handler_periodical)
if is_initialized_in_thread:
t = threading.Thread(target=initialize)
t.start()
t.join()
else:
initialize()
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one(
{'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database"
) # except if your computer is really slow
self.assertEqual(len(self.handler_periodical.buffer), 1,
"Buffer size should be 1")
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one(
{'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler_periodical.buffer), 2,
"Buffer size should be 2")
time.sleep(
2.5
) # wait a bit so the periodical timer thread has kicked off the buffer flush
document = self.handler_periodical.collection.find_one(
{'message': 'test periodical buffer'})
self.assertIsNotNone(document,
"Should not have been written to database")
doc_amount = self.handler_periodical.collection.find({
'message':
'test periodical buffer'
}).count()
self.assertEqual(doc_amount, 2,
"Should have found 2 documents written to database")
self.assertEqual(len(self.handler_periodical.buffer), 0,
"Buffer should be empty")
self.assertTrue(self.handler_periodical.buffer_timer_thread.is_alive())
self.handler_periodical.destroy()
time.sleep(
0.2) # waiting a tiny bit so that the child thread actually exits
self.assertFalse(
self.handler_periodical.buffer_timer_thread.is_alive(),
"Child timer thread should be dead by now. Slow computer?")
# reset to previous
self.log.removeHandler(self.handler_periodical)
self.log.addHandler(self.handler)
def test_buffer_periodical_flush(self):
self._buffer_periodical_flush(is_initialized_in_thread=False)
def test_buffer_periodical_flush_init_in_new_thread(self):
self._buffer_periodical_flush(is_initialized_in_thread=True)
class TestBufferedMongoHandler(TestMongoHandler):
collection_name = 'buffered_logs_test'
def setUp(self):
self.handler = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=None,
buffer_early_flush_level=logging.CRITICAL
)
self.log = logging.getLogger('testLogger')
self.log.setLevel(logging.DEBUG)
self.log.addHandler(self.handler)
self.old_stderr = sys.stdout
sys.stderr = StringIO()
def force_flush(self):
self.handler.flush_to_mongo()
def test_contextual_info(self):
self.log.info('test message with contextual info',
extra={'ip': '127.0.0.1', 'host': 'localhost'})
self.force_flush()
document = self.handler.collection.find_one(
{'message': 'test message with contextual info', 'level': 'INFO'})
self.assertEqual(document['message'],
'test message with contextual info')
self.assertEqual(document['level'], 'INFO')
self.assertEqual(document['ip'], '127.0.0.1')
self.assertEqual(document['host'], 'localhost')
def test_contextual_info_adapter(self):
adapter = logging.LoggerAdapter(self.log,
{'ip': '127.0.0.1',
'host': 'localhost'})
adapter.info('test message with contextual info')
self.force_flush()
document = self.handler.collection.find_one(
{'message': 'test message with contextual info', 'level': 'INFO'})
self.assertEqual(document['message'], 'test message with contextual info')
self.assertEqual(document['level'], 'INFO')
self.assertEqual(document['ip'], '127.0.0.1')
self.assertEqual(document['host'], 'localhost')
def test_emit(self):
self.log.warning('test message')
self.force_flush()
document = self.handler.collection.find_one(
{'message': 'test message', 'level': 'WARNING'})
self.assertEqual(document['message'], 'test message')
self.assertEqual(document['level'], 'WARNING')
def test_emit_exception(self):
try:
raise Exception('exc1')
except:
self.log.exception('test message')
self.force_flush()
document = self.handler.collection.find_one(
{'message': 'test message', 'level': 'ERROR'})
self.assertEqual(document['message'], 'test message')
self.assertEqual(document['level'], 'ERROR')
self.assertEqual(document['exception']['message'], 'exc1')
def test_emit_fail(self):
self.handler.collection = ''
self.log.warn('test warning')
self.force_flush()
val = sys.stderr.getvalue()
self.assertRegexpMatches(val, r"AttributeError: 'str' object has no attribute '{}'".format(write_many_method))
def test_buffer(self):
self.force_flush()
self.assertEqual(len(self.handler.buffer), 0, "Ensure buffer should be empty")
self.log.warning('test_buffer message')
document = self.handler.collection.find_one({'message': 'test_buffer message'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler.buffer), 1, "Buffer size should be 1")
self.log.info('test_buffer message')
self.log.debug('test_buffer message')
self.log.info('test_buffer message')
doc_amount = self.handler.collection.find({'message': 'test_buffer message'}).count()
self.assertEqual(doc_amount, 0, "Nothing should have been written to database")
self.assertEqual(len(self.handler.buffer), 4, "Buffer size should be 4")
self.log.warning('test_buffer message')
doc_amount = self.handler.collection.find({'message': 'test_buffer message'}).count()
self.assertEqual(doc_amount, 5, "Buffer size reached, buffer should have been written to database")
self.assertEqual(len(self.handler.buffer), 0, "Ensure buffer should be empty")
self.log.warning('test_buffer message 2')
document = self.handler.collection.find_one({'message': 'test_buffer message 2'})
self.assertIsNone(document, 'Should not have been written to database')
self.assertEqual(len(self.handler.buffer), 1, "Buffer size should be 1")
def test_buffer_early_flush(self):
self.force_flush()
self.assertEqual(len(self.handler.buffer), 0, "Ensure buffer should be empty")
self.log.info('test_buffer_early_flush message')
document = self.handler.collection.find_one({'message': 'test_buffer_early_flush message'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler.buffer), 1, "Buffer size should be 1")
self.log.critical('test_buffer_early_flush message')
doc_amount = self.handler.collection.find({'message': 'test_buffer_early_flush message'}).count()
self.assertEqual(doc_amount, 2, "2 messages should have been written to database")
self.assertEqual(len(self.handler.buffer), 0, "Buffer should now be empty")
doc_amount = self.handler.collection.find({'message': 'test_buffer_early_flush message',
'level': 'INFO'}).count()
self.assertEqual(doc_amount, 1, "One INFO message should have been written to database")
doc_amount = self.handler.collection.find({'message': 'test_buffer_early_flush message',
'level': 'CRITICAL'}).count()
self.assertEqual(doc_amount, 1, "One CRITICAL message should have been written to database")
def test_buffer_periodical_flush(self):
# Creating capped handler
self.handler_periodical = BufferedMongoHandler(host=self.host_name,
database_name=self.database_name,
collection=self.collection_name,
buffer_size=5, buffer_periodical_flush_timing=2.0,
buffer_early_flush_level=logging.CRITICAL)
self.log.removeHandler(self.handler)
self.log.addHandler(self.handler_periodical)
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database") # except if your computer is really slow
self.assertEqual(len(self.handler_periodical.buffer), 1, "Buffer size should be 1")
self.log.info('test periodical buffer')
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNone(document, "Should not have been written to database")
self.assertEqual(len(self.handler_periodical.buffer), 2, "Buffer size should be 2")
time.sleep(2.5) # wait a bit so the periodical timer thread has kicked off the buffer flush
document = self.handler_periodical.collection.find_one({'message': 'test periodical buffer'})
self.assertIsNotNone(document, "Should not have been written to database")
doc_amount = self.handler_periodical.collection.find({'message': 'test periodical buffer'}).count()
self.assertEqual(doc_amount, 2, "Should have found 2 documents written to database")
self.assertEqual(len(self.handler_periodical.buffer), 0, "Buffer should be empty")
self.assertTrue(self.handler_periodical.buffer_timer_thread.is_alive())
self.handler_periodical.destroy()
time.sleep(0.2) # waiting a tiny bit so that the child thread actually exits
self.assertFalse(self.handler_periodical.buffer_timer_thread.is_alive(),
"Child timer thread should be dead by now. Slow computer?")
# reset to previous
self.log.removeHandler(self.handler_periodical)
self.log.addHandler(self.handler)
from pymongo import MongoClient
from static import MONGODB, FILEINFO, EMAILINFO
from datetime import datetime
import logging
import logging.handlers
from log4mongo.handlers import BufferedMongoHandler
bmh = BufferedMongoHandler(host=MONGODB["host"], # All MongoHandler parameters are valid
port=MONGODB["port"],
username=MONGODB["user"],
password=MONGODB["passwd"],
capped=True,
buffer_size=100, # buffer size.
buffer_periodical_flush_timing=10.0, # periodical flush every 10 seconds
buffer_early_flush_level=logging.CRITICAL) # early flush
# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
# create formatter
formatter = logging.Formatter('%(asctime)-15s - %(levelname)s - %(collection_name)s : %(message)s')
# add formatter to ch
ch.setFormatter(formatter)
fh = logging.FileHandler(FILEINFO["loc"])
fh.setLevel(logging.DEBUG)
fh.setFormatter(formatter)
