def test_parse_intermediate_file(self):
"""Test of create_condition_type function"""
# Create condition type
result = parse_file(os.path.join(self.this_dir, "intermediate_update_run.log"))
awaited_start_time = datetime.strptime('02/01/16 19:25:32', "%m/%d/%y %H:%M:%S")
awaited_update_time = datetime.strptime('02/01/16 19:56:50', "%m/%d/%y %H:%M:%S")
self.assertIsInstance(result, CodaRunLogParseResult)
self.assertEqual(result.run_number, 10058)
self.assertEqual(result.has_run_start, True) # File has <run-start> xml section
self.assertEqual(result.has_run_end, False) # File has <run-end> xml section
self.assertEqual(result.run_type, 'hd_bcal.tsg') # the Run type. E.g. 'hd_all.tsg_cosmic'
self.assertEqual(result.session, 'hdops') # Session E.g. 'hdops'
self.assertEqual(result.start_time, awaited_start_time) # Start time
self.assertIsNone(result.end_time) # Time of the run end
self.assertEqual(result.update_time, awaited_update_time) # Time when the coda log file is written
self.assertEqual(result.event_count, 293798) # The number of events in the run
self.assertTrue(result.components) # a list of names of <components> section
self.assertIn('ROCBCAL10', result.components)
self.assertTrue(result.component_stats) # dictionary with contents
self.assertIn('ROCBCAL10', result.component_stats.keys())
self.assertTrue(result.rtvs) # dictionary with contents of <rtvs> section
self.assertIn('%(CODA_ROLMC)', result.rtvs.keys())
# config file with full path.
self.assertEqual(result.run_config_file, '/home/hdops/CDAQ/daq_dev_v0.31/daq/config/hd_bcal/bcal_phys_led.conf')
self.assertEqual(result.run_config, 'bcal_phys_led.conf') # config file name
def test_parse_intermediate_file(self):
"""Test of create_condition_type function"""
# Create condition type
result = parse_file(os.path.join(self.this_dir, "intermediate_update_run.log"))
awaited_start_time = datetime.strptime('02/01/16 19:25:32', "%m/%d/%y %H:%M:%S")
awaited_update_time = datetime.strptime('02/01/16 19:56:50', "%m/%d/%y %H:%M:%S")
self.assertIsInstance(result, CodaRunLogParseResult)
self.assertEqual(result.run_number, 10058)
self.assertEqual(result.has_run_start, True) # File has <run-start> xml section
self.assertEqual(result.has_run_end, False) # File has <run-end> xml section
self.assertEqual(result.run_type, 'hd_bcal.tsg') # the Run type. E.g. 'hd_all.tsg_cosmic'
self.assertEqual(result.session, 'hdops') # Session E.g. 'hdops'
self.assertEqual(result.start_time, awaited_start_time) # Start time
self.assertIsNone(result.end_time) # Time of the run end
self.assertEqual(result.update_time, awaited_update_time) # Time when the coda log file is written
self.assertEqual(result.event_count, 293798) # The number of events in the run
self.assertTrue(result.components) # a list of names of <components> section
self.assertIn('ROCBCAL10', result.components)
self.assertTrue(result.component_stats) # dictionary with contents
self.assertIn('ROCBCAL10', result.component_stats.keys())
self.assertTrue(result.rtvs) # dictionary with contents of <rtvs> section
self.assertIn('%(CODA_ROLMC)', result.rtvs.keys())
# config file with full path.
self.assertEqual(result.run_config_file, '/home/hdops/CDAQ/daq_dev_v0.31/daq/config/hd_bcal/bcal_phys_led.conf')
self.assertEqual(result.run_config, 'bcal_phys_led.conf') # config file name
def test_parse_file_with_end_run(self):
# Create condition type
result = parse_file(os.path.join(self.this_dir, "large_run.log"))
awaited_end_time = datetime.strptime('02/15/16 15:17:50', "%m/%d/%y %H:%M:%S")
self.assertIsInstance(result, CodaRunLogParseResult)
self.assertEqual(result.event_count, 10729318)
self.assertEqual(result.has_run_end, True)
self.assertEqual(result.end_time, awaited_end_time)
self.assertIn('monitoring test', result.user_comment)
def test_parse_file_with_end_run(self):
# Create condition type
result = parse_file(os.path.join(self.this_dir, "large_run.log"))
awaited_end_time = datetime.strptime('02/15/16 15:17:50', "%m/%d/%y %H:%M:%S")
self.assertIsInstance(result, CodaRunLogParseResult)
self.assertEqual(result.event_count, 10729318)
self.assertEqual(result.has_run_end, True)
self.assertEqual(result.end_time, awaited_end_time)
self.assertIn('monitoring test', result.user_comment)
def parse_files():
# We will use this to identify this process in logs. Is done for investigation of double messages
script_start_datetime = datetime.now()
script_start_time = time.time()
script_name = os.urandom(8).encode('hex')
script_pid = os.getpid()
script_ppid = os.getppid()
script_uid = os.getuid()
script_start_clock = time.clock()
description = "The script updates RCDB gathering different sources given in --update flag:" \
" coda - information from coda file (file is required anyway to get run)" \
" config - run configuration file in HallD format" \
" roc - roc configuration files (taken from run configuration file)"\
" this option is run only if config is given"\
" epics - epics variables" \
"So now update of everything looks like: --update=coda,config,roc,epics" \
parser = argparse.ArgumentParser(description=description,
usage=get_usage())
parser.add_argument("coda_xml_log_file", help="Path to CODA run log file")
parser.add_argument("-v",
"--verbose",
help="increase output verbosity",
action="store_true")
parser.add_argument(
"--reason",
help="Reason of the update. 'start', 'update', 'end' or ''",
default="")
parser.add_argument("--update",
help="Comma separated, modules to update",
default="")
parser.add_argument(
"-c",
"--connection",
help="The connection string (like mysql://rcdb@localhost/rcdb)")
parser.add_argument("--udl",
help="UDL link to send messages to UDL logging")
parser.add_argument("--ipl",
help="Use inter-process lock, that allows ",
action="store_true")
parser.add_argument("--run-config-file",
help="Set custom path to run config file",
default="")
args = parser.parse_args()
# Figure out the parameters
log.setLevel(logging.DEBUG if args.verbose else logging.INFO)
# coda xml file name
coda_xml_log_file = args.coda_xml_log_file
log.debug(F("coda_xml_log_file = '{}'", coda_xml_log_file))
# Connection string
if args.connection:
con_string = args.connection
elif "RCDB_CONNECTION" in os.environ:
con_string = os.environ["RCDB_CONNECTION"]
else:
print(
"ERROR! RCDB_CONNECTION is not set and is not given as a script parameter (-c)"
)
parser.print_help()
sys.exit(2)
log.debug(F("con_string = '{}'", con_string))
# What to update
update_parts = []
if args.update:
update_parts = args.update.split(',')
log.debug(F("update_parts = {}", update_parts))
# Update reason
update_reason = args.reason
log.debug(F("update_reason = '{}'", update_reason))
# Use interprocess lock?
use_interprocess_lock = args.ipl
script_info = "'{script_start_datetime}', reason: '{reason}', parts: '{parts}, " \
"'pid: '{pid}', ppid: '{ppid}', uid: '{uid}', " \
.format(
script_start_datetime=script_start_datetime,
reason=update_reason,
parts=args.update,
pid=script_pid,
ppid=script_ppid,
uid=script_uid)
# Open DB connection
db = ConfigurationProvider(con_string)
# Ensure only one such process is running, to avoid duplicated records. See issues #25 #20 #19 on GitHub
if use_interprocess_lock:
lock_success = try_set_interprocess_lock()
wait_count = 0
while not lock_success:
# We failed to obtain the lock. Some other instance of this script is running now.
if update_reason == UpdateReasons.UPDATE:
log.info(
"The other instance is running. Since update_reason = update we just exit"
)
exit(0)
time.sleep(1)
wait_count += 1
log.debug(
F("{script_name}: Waiting lock for {waited}s",
script_name=script_name,
waited=wait_count))
if wait_count > 10:
log.error(
F(
"The other instance is running. Since this update reason is '{}', "
"this instance waited > 10s for the other one to end. But it still holds the lock",
update_reason))
# this is major problem. We'll try send it to DB before exit
db.add_log_record(
"",
"'{}': Exit!. The other instance is running. This instance waited > 10s! {}"
.format(script_name, script_info), 0)
exit(1)
lock_success = try_set_interprocess_lock()
# >oO DB logging
db.add_log_record("", "'{}': Start. {}".format(script_name, script_info),
0)
# Create update context
update_context = rcdb.UpdateContext(db, update_reason)
# CODA
# Parse coda xml and save to DB
log.debug(F("Parsing coda_xml_log_file='{}'", coda_xml_log_file))
coda_parse_result = coda_parser.parse_file(coda_xml_log_file)
run_number = coda_parse_result.run_number
run_config_file = coda_parse_result.run_config_file
log.debug(
F("Parsed coda_xml_log_file='{}'. run='{}', run_config_file='{}'",
coda_xml_log_file, run_number, run_config_file))
# >oO DEBUG log message
now_clock = time.clock()
db.add_log_record(
"",
"'{}':Parsed coda_xml_log_file='{}'. run='{}', run_config_file='{}', clocks='{}', time: '{}'"
.format(script_name, coda_xml_log_file, run_number,
run_config_file, run_number, now_clock - script_start_clock,
datetime.now()), run_number)
# Conditions from coda file save to DB
if "coda" in update_parts:
log.debug(F("Adding coda conditions to DB", ))
update_coda_conditions(update_context, coda_parse_result)
else:
log.debug(
F(
"Skipping to add coda conditions to DB. Use --update=...,coda to update it",
))
update_context.run = db.get_run(run_number)
if update_context.run is None:
log.warning(
F("No DB record for run '{}' is found! Further updates look impossible"
))
update_context.run = run_number
# Save coda file to DB
log.debug(F("Adding coda_xml_log_file to DB", ))
db.add_configuration_file(run_number,
coda_xml_log_file,
overwrite=True,
importance=ConfigurationFile.IMPORTANCE_HIGH)
# CONFIGURATION FILES
# Add run configuration file to DB... if it is run-start update
if args.run_config_file:
log.debug(
F(
"Flag --run-config-file is provided. Using this as a path to run_config_file: '{}'",
args.run_config_file))
run_config_file = args.run_config_file
if update_reason in [UpdateReasons.START, UpdateReasons.UNKNOWN
] and "config" in update_parts and run_config_file:
if os.path.isfile(run_config_file) and os.access(
run_config_file, os.R_OK):
# mmm just save for now
log.debug(F("Adding run_config_file to DB", ))
db.add_configuration_file(
run_number,
run_config_file,
importance=ConfigurationFile.IMPORTANCE_HIGH)
log.debug("Parsing run_config_file")
run_config_parse_result = parse_run_config_file(run_config_file)
log.debug("Parsed run_config_file. Updating conditions")
update_run_config_conditions(update_context,
run_config_parse_result)
log.debug("Updated run_config_file conditions")
if "roc" in update_parts:
log.debug("Adding ROC config files...")
add_roc_configuration_files(update_context,
run_config_parse_result)
log.debug("Done ROC config files!")
else:
log.warn("Config file '{}' is missing or is not readable".format(
run_config_file))
if "roc" in update_parts:
log.warn(
"Can't parse roc configs because there is no main config")
# Parse run configuration file and save to DB
# EPICS
# Get EPICS variables
epics_start_clock = time.clock()
if 'epics' in update_parts and run_number:
log.debug(F("Performing update_epics.py", ))
# noinspection PyBroadException
try:
import update_epics
conditions = update_epics.update_rcdb_conds(
db, run_number, update_reason)
epics_end_clock = time.clock()
# >oO DEBUG log message
if "beam_current" in conditions:
db.add_log_record(
"",
"'{}': Update epics. beam_current:'{}', epics_clocks:'{}' clocks:'{}', time: '{}'"
.format(script_name, conditions["beam_current"],
epics_end_clock - epics_start_clock,
epics_end_clock - script_start_clock,
datetime.now()), run_number)
except Exception as ex:
log.warn(
"update_epics.py failure. Impossible to run the script. Internal exception is:\n"
+ str(ex))
epics_end_clock = time.clock()
# >oO DEBUG log message
db.add_log_record(
"",
"'{}': ERROR update epics. Error type: '{}' message: '{}' trace: '{}' "
"||epics_clocks:'{}' clocks:'{}' time: '{}'".format(
script_name, type(ex), ex.message, traceback.format_exc(),
epics_end_clock - epics_start_clock,
epics_end_clock - script_start_clock, datetime.now()),
run_number)
log.debug("End of update")
# >oO DEBUG log message
now_clock = time.clock()
db.add_log_record(
"",
"'{}': End of update. Script proc clocks='{}', wall time: '{}', datetime: '{}'"
.format(script_name, now_clock - script_start_clock,
time.time() - script_start_time, datetime.now()), run_number)
def test_evio_files(self):
result = parse_file(os.path.join(self.this_dir, "10340_run.log"))
self.assertEqual(result.evio_files_count, 2)
self.assertEqual(result.evio_last_file, "hd_rawdata_010340_001.evio")
def test_evio_files(self):
result = parse_file(os.path.join(self.this_dir, "10340_run.log"))
self.assertEqual(result.evio_files_count, 2)
self.assertEqual(result.evio_last_file, "hd_rawdata_010340_001.evio")
def parse_files():
# We will use this to identify this process in logs. Is done for investigation of double messages
script_start_datetime = datetime.now()
script_start_time = time.time()
script_name = os.urandom(8).encode('hex')
script_pid = os.getpid()
script_ppid = os.getppid()
script_uid = os.getuid()
script_start_clock = time.clock()
# check we have arguments
if len(sys.argv) < 2:
print("ERROR! Please provide a path to xml data file")
print_usage()
sys.exit(1)
parser = argparse.ArgumentParser()
parser.add_argument("coda_xml_log_file", help="Path to CODA run log file")
parser.add_argument("-v", "--verbose", help="increase output verbosity", action="store_true")
parser.add_argument("--reason", help="Reason of the update. 'start', 'update', 'end' or ''", default="")
parser.add_argument("--update", help="Comma separated, modules to update", default="")
parser.add_argument("-c", "--connection", help="The connection string (like mysql://rcdb@localhost/rcdb)")
parser.add_argument("--udl", help="UDL link to send messages to UDL logging")
parser.add_argument("--ipl", help="Use inter-process lock, that allows ", action="store_true")
parser.add_argument("--run-config-file", help="Set custom path to run config file", default="")
args = parser.parse_args()
# Figure out the parameters
log.setLevel(logging.DEBUG if args.verbose else logging.INFO)
# coda xml file name
coda_xml_log_file = args.coda_xml_log_file
log.debug(F("coda_xml_log_file = '{}'", coda_xml_log_file))
# Connection string
if args.connection:
con_string = args.connection
elif "RCDB_CONNECTION" in os.environ:
con_string = os.environ["RCDB_CONNECTION"]
else:
print ("ERROR! RCDB_CONNECTION is not set and is not given as a script parameter (-c)")
print_usage()
sys.exit(2)
log.debug(F("con_string = '{}'", con_string))
# What to update
update_parts = []
if args.update:
update_parts = args.update.split(',')
log.debug(F("update_parts = {}", update_parts))
# Update reason
update_reason = args.reason
log.debug(F("update_reason = '{}'", update_reason))
# Use interprocess lock?
use_interprocess_lock = args.ipl
script_info = "'{script_start_datetime}', reason: '{reason}', parts: '{parts}, " \
"'pid: '{pid}', ppid: '{ppid}', uid: '{uid}', " \
.format(
script_start_datetime=script_start_datetime,
reason=update_reason,
parts=args.update,
pid=script_pid,
ppid=script_ppid,
uid=script_uid)
# Open DB connection
db = ConfigurationProvider(con_string)
# Ensure only one such process is running, to avoid duplicated records. See issues #25 #20 #19 on GitHub
if use_interprocess_lock:
lock_success = try_set_interprocess_lock()
wait_count = 0
while not lock_success:
# We failed to obtain the lock. Some other instance of this script is running now.
if update_reason == UpdateReasons.UPDATE:
log.info("The other instance is running. Since update_reason = update we just exit")
exit(0)
time.sleep(1)
wait_count += 1
log.debug(F("{script_name}: Waiting lock for {waited}s", script_name=script_name, waited=wait_count))
if wait_count > 10:
log.error(F("The other instance is running. Since this update reason is '{}', "
"this instance waited > 10s for the other one to end. But it still holds the lock",
update_reason))
# this is major problem. We'll try send it to DB before exit
db.add_log_record("",
"'{}': Exit!. The other instance is running. This instance waited > 10s! {}"
.format(
script_name,
script_info), 0)
exit(1)
lock_success = try_set_interprocess_lock()
# >oO DB logging
db.add_log_record("", "'{}': Start. {}".format(script_name, script_info), 0)
# Create update context
update_context = rcdb.UpdateContext(db, update_reason)
# Parse coda xml and save to DB
log.debug(F("Parsing coda_xml_log_file='{}'", coda_xml_log_file))
coda_parse_result = coda_parser.parse_file(coda_xml_log_file)
run_number = coda_parse_result.run_number
run_config_file = coda_parse_result.run_config_file
log.debug(F("Parsed coda_xml_log_file='{}'. run='{}', run_config_file='{}'",
coda_xml_log_file, run_number, run_config_file))
# >oO DEBUG log message
now_clock = time.clock()
db.add_log_record("", "'{}':Parsed coda_xml_log_file='{}'. run='{}', run_config_file='{}', clocks='{}', time: '{}'"
.format(script_name, coda_xml_log_file, run_number, run_config_file, run_number,
now_clock - script_start_clock, datetime.now()), run_number)
# Conditions from coda file save to DB
if "coda" in update_parts:
log.debug(F("Adding coda conditions to DB", ))
update_coda_conditions(update_context, coda_parse_result)
else:
log.debug(F("Skipping to add coda conditions to DB. Use --update=...,coda to update it", ))
update_context.run = db.get_run(run_number)
if update_context.run is None:
log.warning(F("No DB record for run '{}' is found! Further updates look impossible"))
update_context.run = run_number
# Save coda file to DB
log.debug(F("Adding coda_xml_log_file to DB", ))
db.add_configuration_file(run_number, coda_xml_log_file, overwrite=True)
# Add run configuration file to DB... if it is run-start update
if args.run_config_file:
log.debug(F("Flag --run-config-file is provided. Using this as a path to run_config_file: '{}'",
args.run_config_file))
run_config_file = args.run_config_file
if update_reason in [UpdateReasons.START, UpdateReasons.UNKNOWN] and "config" in update_parts and run_config_file:
if os.path.isfile(run_config_file) and os.access(run_config_file, os.R_OK):
# mmm just save for now
log.debug(F("Adding run_config_file to DB", ))
db.add_configuration_file(run_number, run_config_file)
log.debug("Parsing run_config_file")
run_config_parse_result = parse_run_config_file(run_config_file)
log.debug("Parsed run_config_file. Updating conditions")
update_run_config_conditions(update_context, run_config_parse_result)
log.debug("Updated run_config_file conditions")
else:
log.warn("Config file '{}' is missing or is not readable".format(run_config_file))
# Parse run configuration file and save to DB
# Get EPICS variables
epics_start_clock = time.clock()
if 'epics' in update_parts and run_number:
log.debug(F("Performing update_epics.py", ))
# noinspection PyBroadException
try:
import update_epics
conditions = update_epics.update_rcdb_conds(db, run_number)
epics_end_clock = time.clock()
# >oO DEBUG log message
db.add_log_record("",
"'{}': Update epics. beam_current:'{}', epics_clocks:'{}' clocks:'{}', time: '{}'"
.format(script_name, conditions["beam_current"], epics_end_clock - epics_start_clock,
epics_end_clock - script_start_clock, datetime.now()), run_number)
except Exception as ex:
log.warn("update_epics.py failure. Impossible to run the script. Internal exception is:\n" + str(ex))
epics_end_clock = time.clock()
# >oO DEBUG log message
db.add_log_record("",
"'{}': ERROR update epics. Error type: '{}' message: '{}' trace: '{}' "
"||epics_clocks:'{}' clocks:'{}' time: '{}'"
.format(script_name, type(ex), ex.message, traceback.format_exc(),
epics_end_clock - epics_start_clock, epics_end_clock - script_start_clock,
datetime.now()), run_number)
log.debug("End of update")
# >oO DEBUG log message
now_clock = time.clock()
db.add_log_record("",
"'{}': End of update. Script proc clocks='{}', wall time: '{}', datetime: '{}'"
.format(script_name,
now_clock - script_start_clock,
time.time() - script_start_time,
datetime.now()), run_number)
