def attach_handler(self, sender):
"""Add the handler to a list of handlers that are attached when get_logger() is called.."""
smtpconf = self.site.config.get('LOGGING_HANDLERS').get('smtp')
if smtpconf:
smtpconf['format_string'] = '''\
Subject: {record.level_name}: {record.channel}
{record.message}
'''
self.site.loghandlers.append(logbook.MailHandler(
smtpconf.pop('from_addr'),
smtpconf.pop('recipients'),
**smtpconf
))
def _create_log_handler(config, add_hostname=False):
logbook.set_datetime_format("local")
handlers = [logbook.NullHandler()]
format_str = " ".join([
"[{record.time:%Y-%m-%d %H:%M}]",
"{record.extra[source]}:" if add_hostname else "", "{record.message}"
])
log_dir = get_log_dir(config)
if log_dir:
if not os.path.exists(log_dir):
utils.safe_makedir(log_dir)
# Wait to propagate, Otherwise see logging errors on distributed filesystems.
time.sleep(5)
handlers.append(
logbook.FileHandler(os.path.join(log_dir, "%s.log" % LOG_NAME),
format_string=format_str,
level="INFO",
filter=_not_cl))
handlers.append(
logbook.FileHandler(os.path.join(log_dir,
"%s-debug.log" % LOG_NAME),
format_string=format_str,
level="DEBUG",
bubble=True,
filter=_not_cl))
handlers.append(
logbook.FileHandler(os.path.join(log_dir,
"%s-commands.log" % LOG_NAME),
format_string=format_str,
level="DEBUG",
filter=_is_cl))
email = config.get("email",
config.get("resources", {}).get("log", {}).get("email"))
if email:
email_str = u'''Subject: [bcbio-nextgen] {record.extra[run]} \n\n {record.message}'''
handlers.append(
logbook.MailHandler(email, [email],
format_string=email_str,
level='INFO',
bubble=True))
handlers.append(
logbook.StreamHandler(sys.stderr,
format_string=format_str,
bubble=True,
filter=_not_cl))
return CloseableNestedSetup(handlers)
def create_log_handler(config, log_name):
log_dir = config.get("log_dir", None)
email = config.get("email", None)
if log_dir:
utils.safe_makedir(log_dir)
handler = logbook.FileHandler(os.path.join(log_dir, "%s.log" % log_name))
else:
handler = logbook.StreamHandler(sys.stdout)
if email:
handler = logbook.MailHandler(email, [email],
format_string=u'''Subject: [BCBB pipeline] {record.extra[run]} \n\n {record.message}''',
level='INFO', bubble = True)
return handler
def main(user_email,
url_api_collections,
log_handler=None,
mail_handler=None,
dir_profile='profiles',
profile_path=None,
config_file='akara.ini',
rq_queue=None,
**kwargs):
'''Runs a UCLDC ingest process for the given collection'''
emails = [user_email]
if EMAIL_SYS_ADMIN:
emails.extend([u for u in EMAIL_SYS_ADMIN.split(',')])
if not mail_handler:
mail_handler = logbook.MailHandler(EMAIL_RETURN_ADDRESS,
emails,
level='ERROR',
bubble=True)
mail_handler.push_application()
config = config_harvest(config_file=config_file)
if not log_handler:
log_handler = logbook.StderrHandler(level='DEBUG')
log_handler.push_application()
for url_api_collection in [x for x in url_api_collections.split(';')]:
try:
collection = Collection(url_api_collection)
except Exception, e:
msg = 'Exception in Collection {}, init {}'.format(
url_api_collection, str(e))
logbook.error(msg)
raise e
queue_image_harvest(config['redis_host'],
config['redis_port'],
config['redis_password'],
config['redis_connect_timeout'],
rq_queue=rq_queue,
collection_key=collection.id,
object_auth=collection.auth,
**kwargs)
from lib.scale import BeeHiveScale
from lib.dht import DHTSensorController
import settings
secrets = json.load(
open(os.path.join(os.path.dirname(__file__), "secrets.json"), "r"))
mail_log_settings = secrets["logging"]
logger = logbook.NestedSetup([
logbook.NullHandler(),
logbook.SyslogHandler(level=logbook.INFO),
logbook.MailHandler(from_addr=mail_log_settings["sender"],
recipients=mail_log_settings["recipients"],
level=logbook.ERROR,
credentials=(mail_log_settings["username"],
mail_log_settings["password"]),
server_addr=(mail_log_settings["server"],
mail_log_settings["port"]),
secure=mail_log_settings["secure"],
bubble=True)
])
def acquire_weights(scale_obj,
sleep_time=settings.WEIGHT_MEASURE_WAIT_TIME,
measure_count=settings.WEIGHT_MEASURE_COUNT):
"""
to ensure accuracy of the weight do a number of
measures with sleep time in between
:param scale_obj: BeeHiveScale object
def main(user_email,
url_api_collection,
log_handler=None,
mail_handler=None,
dir_profile='profiles',
profile_path=None,
config_file=None,
redis_host=None,
redis_port=None,
redis_pswd=None,
redis_timeout=600,
rq_queue=None,
run_image_harvest=False,
**kwargs):
'''Runs a UCLDC ingest process for the given collection'''
cleanup_work_dir() # remove files from /tmp
emails = [user_email]
if EMAIL_SYS_ADMIN:
emails.extend([u for u in EMAIL_SYS_ADMIN.split(',')])
if not mail_handler:
mail_handler = logbook.MailHandler(EMAIL_RETURN_ADDRESS,
emails,
level='ERROR',
bubble=True)
mail_handler.push_application()
if not config_file:
config_file = os.environ.get('DPLA_CONFIG_FILE', 'akara.ini')
if not (redis_host and redis_port and redis_pswd):
config = config_harvest(config_file=config_file)
try:
collection = Collection(url_api_collection)
except Exception as e:
msg = 'Exception in Collection {}, init {}'.format(
url_api_collection, str(e))
logbook.error(msg)
raise e
if not log_handler:
log_handler = logbook.StderrHandler(level='DEBUG')
log_handler.push_application()
logger = logbook.Logger('run_ingest')
ingest_doc_id, num_recs, dir_save, harvester = fetcher.main(
emails,
url_api_collection,
log_handler=log_handler,
mail_handler=mail_handler,
**kwargs)
if 'prod' in os.environ['DATA_BRANCH'].lower():
if not collection.ready_for_publication:
raise Exception(''.join(
('Collection {} is not ready for publication.',
' Run on stage and QA first, then set',
' ready_for_publication')).format(collection.id))
logger.info("INGEST DOC ID:{0}".format(ingest_doc_id))
logger.info('HARVESTED {0} RECORDS'.format(num_recs))
logger.info('IN DIR:{0}'.format(dir_save))
resp = enrich_records.main([None, ingest_doc_id])
if not resp == 0:
logger.error("Error enriching records {0}".format(resp))
raise Exception('Failed during enrichment process: {0}'.format(resp))
logger.info('Enriched records')
resp = save_records.main([None, ingest_doc_id])
if not resp >= 0:
logger.error("Error saving records {0}".format(str(resp)))
raise Exception("Error saving records {0}".format(str(resp)))
num_saved = resp
logger.info("SAVED RECS : {}".format(num_saved))
resp = remove_deleted_records.main([None, ingest_doc_id])
if not resp == 0:
logger.error("Error deleting records {0}".format(resp))
raise Exception("Error deleting records {0}".format(resp))
resp = check_ingestion_counts.main([None, ingest_doc_id])
if not resp == 0:
logger.error("Error checking counts {0}".format(resp))
raise Exception("Error checking counts {0}".format(resp))
resp = dashboard_cleanup.main([None, ingest_doc_id])
if not resp == 0:
logger.error("Error cleaning up dashboard {0}".format(resp))
raise Exception("Error cleaning up dashboard {0}".format(resp))
subject = format_results_subject(collection.id,
'Harvest to CouchDB {env} ')
publish_to_harvesting(
subject, 'Finished metadata harvest for CID: {}\n'
'Fetched: {}\nSaved: {}'.format(collection.id, num_recs, num_saved))
log_handler.pop_application()
mail_handler.pop_application()
def create_log_handler(config, batch_records=False):
log_dir = config.get("log_dir", None)
email = config.get("email", None)
rabbitmq = config.get("rabbitmq_logging", None)
redis = config.get("redis_handler", None)
handlers = []
if log_dir:
utils.safe_makedir(log_dir)
handlers.append(
logbook.FileHandler(os.path.join(log_dir, "%s.log" % LOG_NAME)))
else:
handlers.append(logbook.StreamHandler(sys.stdout))
if email:
smtp_host = config.get("smtp_host", None)
smtp_port = config.get("smtp_port", 25)
if smtp_host is not None:
smtp_host = [smtp_host, smtp_port]
email = email.split(",")
handlers.append(
logbook.MailHandler(
email[0],
email,
server_addr=smtp_host,
format_string=
u'''Subject: [BCBB pipeline] {record.extra[run]} \n\n {record.message}''',
level='INFO',
bubble=True))
if rabbitmq:
from logbook.queues import RabbitMQHandler
handlers.append(
RabbitMQHandler(rabbitmq["url"],
queue=rabbitmq["log_queue"],
bubble=True))
if redis:
try:
redis_host = config.get('redis_handler').get('host')
redis_port = int(config.get('redis_handler').get('port'))
redis_key = config.get('redis_handler').get('key')
redis_password = config.get('redis_handler').get('password')
redis_handler = RedisHandler(host=redis_host,
port=redis_port,
key=redis_key,
password=redis_password)
handlers.append(redis_handler)
except:
logger2.warn("Failed loading Redis handler, please check your \
configuration and the connectivity to your Redis Database")
if config.get("debug", False):
for handler in handlers:
handler.level = logbook.DEBUG
logger2.level = logbook.DEBUG
else:
for handler in handlers:
handler.level = logbook.INFO
return logbook.NestedSetup(handlers)
def test_mail_handler_arguments():
with patch('smtplib.SMTP', autospec=True) as mock_smtp:
# Test the mail handler with supported arguments before changes to
# secure, credentials, and starttls
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr=('server.example.com',
465),
credentials=('username',
'password'),
secure=('keyfile', 'certfile'))
mail_handler.get_connection()
assert mock_smtp.call_args == call('server.example.com', 465)
assert mock_smtp.method_calls[1] == call().starttls(
keyfile='keyfile', certfile='certfile')
assert mock_smtp.method_calls[3] == call().login(
'username', 'password')
# Test secure=()
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr=('server.example.com',
465),
credentials=('username',
'password'),
secure=())
mail_handler.get_connection()
assert mock_smtp.call_args == call('server.example.com', 465)
assert mock_smtp.method_calls[5] == call().starttls(certfile=None,
keyfile=None)
assert mock_smtp.method_calls[7] == call().login(
'username', 'password')
# Test implicit port with string server_addr, dictionary credentials,
# dictionary secure.
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr='server.example.com',
credentials={
'user': '******',
'password': '******'
},
secure={
'certfile': 'certfile2',
'keyfile': 'keyfile2'
})
mail_handler.get_connection()
assert mock_smtp.call_args == call('server.example.com', 465)
assert mock_smtp.method_calls[9] == call().starttls(
certfile='certfile2', keyfile='keyfile2')
assert mock_smtp.method_calls[11] == call().login(user='******',
password='******')
# Test secure=True
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr=('server.example.com',
465),
credentials=('username',
'password'),
secure=True)
mail_handler.get_connection()
assert mock_smtp.call_args == call('server.example.com', 465)
assert mock_smtp.method_calls[13] == call().starttls(certfile=None,
keyfile=None)
assert mock_smtp.method_calls[15] == call().login(
'username', 'password')
assert len(mock_smtp.method_calls) == 16
# Test secure=False
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr=('server.example.com',
465),
credentials=('username',
'password'),
secure=False)
mail_handler.get_connection()
# starttls not called because we check len of method_calls before and
# after this test.
assert mock_smtp.call_args == call('server.example.com', 465)
assert mock_smtp.method_calls[16] == call().login(
'username', 'password')
assert len(mock_smtp.method_calls) == 17
with patch('smtplib.SMTP_SSL', autospec=True) as mock_smtp_ssl:
# Test starttls=False
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr='server.example.com',
credentials={
'user': '******',
'password': '******'
},
secure={
'certfile': 'certfile',
'keyfile': 'keyfile'
},
starttls=False)
mail_handler.get_connection()
assert mock_smtp_ssl.call_args == call('server.example.com',
465,
keyfile='keyfile',
certfile='certfile')
assert mock_smtp_ssl.method_calls[0] == call().login(
user='******', password='******')
# Test starttls=False with secure=True
mail_handler = logbook.MailHandler(from_addr='*****@*****.**',
recipients='*****@*****.**',
server_addr='server.example.com',
credentials={
'user': '******',
'password': '******'
},
secure=True,
starttls=False)
mail_handler.get_connection()
assert mock_smtp_ssl.call_args == call('server.example.com',
465,
keyfile=None,
certfile=None)
assert mock_smtp_ssl.method_calls[1] == call().login(
user='******', password='******')
def main(input_path, transferred_db, run_folder, uppnexid, samplesheet, logfile, email_notification, config_file, force, dryrun):
config = {}
if config_file is not None:
config = load_config(config_file)
if logfile is None:
logfile = config.get("logfile",os.path.normpath(os.path.expanduser(DEFAULT_LOGFILE)))
email_handler = None
# Don't write dry runs to log
if dryrun:
handler = logbook.StreamHandler(sys.stdout)
else:
if not os.path.exists(logfile):
safe_makedir(os.path.dirname(logfile))
open(logfile,"w").close()
handler = logbook.FileHandler(logfile)
if email_notification is None:
email_notification = config.get("email_recipient",DEFAULT_RECIPIENT)
recipients = email_notification.split(",")
if len(recipients) > 0:
email_handler = logbook.MailHandler("*****@*****.**", recipients,
server_addr=[config.get("smtp_host",DEFAULT_SMTP_HOST),config.get("smtp_port",DEFAULT_SMTP_PORT)],
format_string=u'''Subject: [MiSeq delivery] {record.extra[run]}\n\n {record.message}''')
with handler.applicationbound():
if dryrun:
logger2.info("This is just a dry-run. Nothing will be delivered and no directories will be created/changed")
# If no run folder was specified, try with the folders in the input_path
if run_folder is None:
pat = "*_M*_AMS*"
folders = [os.path.relpath(os.path.normpath(file),input_path) for file in glob.glob(os.path.join(input_path,pat))]
else:
run_folder = os.path.basename(os.path.normpath(run_folder))
assert os.path.exists(os.path.join(input_path,run_folder)), "The specified run folder %s does not seem to exist in the %s folder" % (run_folder, input_path)
folders = [run_folder]
logger2.info("Will process %s folders: %s" % (len(folders),folders))
# Parse the supplied db of transferred flowcells, or a db in the default location if present
if transferred_db is None:
transferred_db = os.path.normpath(config.get("transfer_db",os.path.expanduser(DEFAULT_DB)))
assert os.path.exists(transferred_db), "Could not locate transferred_db (expected %s)" % transferred_db
logger2.info("Transferred db is %s" % transferred_db)
# Process each run folder
for folder in folders:
try:
# Skip this folder if it has already been processed
logger2.info("Processing %s" % folder)
if _is_processed(folder,transferred_db) and not force:
logger2.info("%s has already been processed, skipping" % folder)
continue
# Locate the samplesheet and pasre the uppnex id if necessary
if uppnexid is None:
local_samplesheet = samplesheet
if local_samplesheet is None: local_samplesheet = os.path.join(input_path,folder,config.get("samplesheet_name",DEFAULT_SS_NAME))
assert os.path.exists(local_samplesheet), "Could not find expected sample sheet %s" % local_samplesheet
local_uppnexid = _fetch_uppnexid(local_samplesheet, config.get("uppnexid_field",DEFAULT_UPPNEXID_FIELD))
assert local_uppnexid is not None and len(local_uppnexid) > 0, "Could not parse Uppnex ID for project from samplesheet %s" % local_samplesheet
else:
local_uppnexid = uppnexid
logger2.info("Will deliver to inbox of project %s" % local_uppnexid)
# Locate the fastq-files to be delivered
pat = os.path.join(input_path,folder,config.get("fastq_path",DEFAULT_FQ_LOCATION),"*.fastq.gz")
fq_files = glob.glob(pat)
# Also search directly in the folder
pat = os.path.join(input_path,folder,"*.fastq.gz")
fq_files.extend(glob.glob(pat))
assert len(fq_files) > 0, "Could not locate fastq files for folder %s using pattern %s" % (folder,pat)
logger2.info("Found %s fastq files to deliver: %s" % (len(fq_files),fq_files))
if dryrun:
logger2.info("Remember that this is a dry-run. Nothing will be delivered and no directories will be created/changed")
# Create the destination directory if required
dest_dir = os.path.normpath(os.path.join(config.get("project_root",DEFAULT_PROJECT_ROOT),local_uppnexid,"INBOX",folder,"fastq"))
_update_processed(folder,transferred_db,dryrun)
assert _create_destination(dest_dir, dryrun), "Could not create destination %s" % dest_dir
assert _deliver_files(fq_files,dest_dir, dryrun), "Could not transfer files to destination %s" % dest_dir
assert _verify_files(fq_files,dest_dir,dryrun), "Integrity of files in destination directory %s could not be verified. Please investigate" % dest_dir
assert _set_permissions(dest_dir, dryrun), "Could not change permissions on destination %s" % dest_dir
if email_handler is not None:
with email_handler.applicationbound():
with logbook.Processor(lambda record: record.extra.__setitem__('run', folder)):
logger2.info("The MiSeq sequence data for run %s was successfully delivered to the inbox of Uppnex project %s (%s)" % (folder,local_uppnexid,dest_dir))
except AssertionError as e:
logger2.error("Could not deliver data from folder %s. Reason: %s. Please fix problems and retry." % (folder,e))
logger2.info("Rolling back changes to %s" % transferred_db)
_update_processed(folder,transferred_db,dryrun,True)
def main(user_email,
url_api_collection,
log_handler=None,
mail_handler=None,
dir_profile='profiles',
profile_path=None,
config_file=None,
**kwargs):
'''Executes a harvest with given parameters.
Returns the ingest_doc_id, directory harvest saved to and number of
records.
'''
if not config_file:
config_file = os.environ.get('DPLA_CONFIG_FILE', 'akara.ini')
num_recs = -1
my_mail_handler = None
if not mail_handler:
my_mail_handler = logbook.MailHandler(EMAIL_RETURN_ADDRESS,
user_email,
level='ERROR',
bubble=True)
my_mail_handler.push_application()
mail_handler = my_mail_handler
try:
collection = Collection(url_api_collection)
except Exception as e:
msg = 'Exception in Collection {}, init {}'.format(
url_api_collection, str(e))
logbook.error(msg)
raise e
if not (collection['harvest_type'] in HARVEST_TYPES):
msg = 'Collection {} wrong type {} for harvesting. Harvest type {} \
is not in {}'.format(url_api_collection,
collection['harvest_type'],
collection['harvest_type'],
HARVEST_TYPES.keys())
logbook.error(msg)
raise ValueError(msg)
mail_handler.subject = "Error during harvest of " + collection.url
my_log_handler = None
if not log_handler: # can't init until have collection
my_log_handler = FileHandler(get_log_file_path(collection.slug))
my_log_handler.push_application()
logger = logbook.Logger('HarvestMain')
msg = 'Init harvester next. Collection:{}'.format(collection.url)
logger.info(msg)
# email directly
mimetext = create_mimetext_msg(
EMAIL_RETURN_ADDRESS, user_email, ' '.join(
('Starting harvest for ', collection.slug)), msg)
try: # TODO: request more emails from AWS
mail_handler.deliver(mimetext, '*****@*****.**')
except:
pass
logger.info('Create DPLA profile document')
if not profile_path:
profile_path = os.path.abspath(
os.path.join(dir_profile, collection.id + '.pjs'))
with codecs.open(profile_path, 'w', 'utf8') as pfoo:
pfoo.write(collection.dpla_profile)
logger.info('DPLA profile document : ' + profile_path)
harvester = None
try:
harvester = HarvestController(user_email,
collection,
profile_path=profile_path,
config_file=config_file,
**kwargs)
except Exception as e:
import traceback
msg = 'Exception in harvester init: type: {} TRACE:\n{}'.format(
type(e), traceback.format_exc())
logger.error(msg)
raise e
logger.info('Create ingest doc in couch')
ingest_doc_id = harvester.create_ingest_doc()
logger.info('Ingest DOC ID: ' + ingest_doc_id)
logger.info('Start harvesting next')
num_recs = harvester.harvest()
msg = ''.join(('Finished harvest of ', collection.slug, '. ',
str(num_recs), ' records harvested.'))
logger.info(msg)
logger.debug('-- get a new harvester --')
harvester = HarvestController(user_email,
collection,
profile_path=profile_path,
config_file=config_file,
**kwargs)
harvester.ingest_doc_id = ingest_doc_id
harvester.couch = dplaingestion.couch.Couch(
config_file=harvester.config_file,
dpla_db_name=harvester.couch_db_name,
dashboard_db_name=harvester.couch_dashboard_name)
harvester.ingestion_doc = harvester.couch.dashboard_db[ingest_doc_id]
try:
harvester.update_ingest_doc('complete', items=num_recs, num_coll=1)
logger.debug('updated ingest doc!')
except Exception as e:
import traceback
error_msg = ''.join(("Error while harvesting: type-> ", str(type(e)),
" TRACE:\n" + str(traceback.format_exc())))
logger.error(error_msg)
harvester.update_ingest_doc('error',
error_msg=error_msg,
items=num_recs)
raise e
if my_log_handler:
my_log_handler.pop_application()
if my_mail_handler:
my_mail_handler.pop_application()
return ingest_doc_id, num_recs, harvester.dir_save, harvester
