def _process_fileset_task(list_of_file_dict, lockfile, lock_id):
'''
Hands the list to a recursive celery task function.
The recursion continues until the list is empty. The calling
function exits immediately.
'''
logid = {'logid': "%s" % (lockfile)}
logger.debug("Function: %s()" % sys._getframe().f_code.co_name, extra=logid)
# Create a lock file here to block any other actions on this report (see TS-8411)
locallock = TaskLock(lock_id, timeout=60) # short timeout in case lock release code doesn't get called
if not(locallock.lock()):
logger.warn("lock file exists: %s(%s)" % (lock_id, locallock.get()), extra=logid)
# Release the task lock
try:
applock = TaskLock(lockfile)
applock.unlock()
except:
logger.error(traceback.format_exc(), extra=logid)
return
logger.info("lock file created: %s(%s)" % (lock_id, locallock.get()), extra=logid)
# lockfile variable stored in list_of_file_dict
for entry in list_of_file_dict:
entry['lockfile'] = lockfile
try:
pfilename = set_action_param_var(list_of_file_dict)
# Call the recursive celery task function to process the list
_process_task.delay(pfilename)
except:
logger.error("We got an error here, _process_fileset_task", extra=logid)
raise
finally:
if locallock:
locallock.unlock()
return
def manage_manual_action():
logid = {'logid': "%s" % ('manual_action')}
logger.debug("manage_manual_action", extra=logid)
def getfirstmanualaction():
manual_selects = DMFileStat.objects.filter(action_state__in=['SA', 'SE', 'SD']).order_by('created')
for item in manual_selects:
try:
dmactions.action_validation(item, item.dmfileset.auto_action)
return item
except(DMExceptions.FilesInUse, DMExceptions.FilesMarkedKeep):
logger.debug("%s Failed action_validation. Try next fileset" %
item.result.resultsName, extra=logid)
except DMExceptions.BaseInputLinked:
# want to allow Basecalling Input delete if all results are expired
related_objs = DMFileStat.objects.filter(
result__experiment=item.result.experiment, dmfileset__type=dmactions_types.BASE)
if related_objs.count() == related_objs.filter(created__lt=threshdate).count():
item.allow_delete = True
return item
else:
logger.debug("%s Failed action_validation. Try next fileset" %
item.result.resultsName, extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
raise DMExceptions.NoDMFileStat("NONE FOUND")
try:
# Create lock file to prevent more than one celery task for manual action (export or archive)
lock_id = 'manual_action_lock_id'
logid = {'logid': "%s" % (lock_id)}
applock = TaskLock(lock_id)
if not applock.lock():
logger.info("Currently processing: %s(%s)" % (lock_id, applock.get()), extra=logid)
return
logger.debug("lock file created: %s(%s)" % (lock_id, applock.get()), extra=logid)
except Exception as e:
logger.error(traceback.format_exc(), extra=logid)
try:
#
# Check for manually selected Archive and Export actions - action_state == 'SA' or 'SE' or 'SD'
# Manual Delete actions do not get processed here. Only suspended Delete actions get processed here.
# These jobs should execute even when auto action is disabled.
# Note: manual actions will not be executed in the order they are selected, but by age.
#
actiondmfilestat = getfirstmanualaction()
user = actiondmfilestat.user_comment.get('user', 'dm_agent')
user_comment = actiondmfilestat.user_comment.get('user_comment', 'Manual Action')
logger.info("Picked: %s" % (actiondmfilestat.result.resultsName), extra=logid)
dmfileset = actiondmfilestat.dmfileset
applock.update(actiondmfilestat.result.resultsName)
if actiondmfilestat.action_state == 'SA':
logger.info("Manual Archive Action: %s from %s" %
(dmfileset.type, actiondmfilestat.result.resultsName), extra=logid)
archive_action(user, user_comment, actiondmfilestat, lock_id, msg_banner=True)
elif actiondmfilestat.action_state == 'SE':
logger.info("Manual Export Action: %s from %s" %
(dmfileset.type, actiondmfilestat.result.resultsName), extra=logid)
export_action(user, user_comment, actiondmfilestat, lock_id, msg_banner=True)
elif actiondmfilestat.action_state == 'SD':
logger.info("Delete Action: %s from %s" %
(dmfileset.type, actiondmfilestat.result.resultsName), extra=logid)
delete_action(user, "Continuing delete action after being suspended",
actiondmfilestat, lock_id, msg_banner=True)
else:
logger.warn("Dev Error: we don't handle this '%s' here" %
actiondmfilestat.action_state, extra=logid)
except DMExceptions.NoDMFileStat:
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed on exit %s" % (os.getpid(), lock_id), extra=logid)
# NOTE: all these exceptions are also handled in manage_data() below. beaucoup de duplication de code
except (DMExceptions.FilePermission,
DMExceptions.InsufficientDiskSpace,
DMExceptions.MediaNotSet,
DMExceptions.MediaNotAvailable,
DMExceptions.FilesInUse) as e:
applock.unlock()
message = Message.objects.filter(tags__contains=e.tag)
if not message:
Message.error(e.message, tags=e.tag)
# TODO: TS-6525: This logentry will repeat for an Archive action every 30 seconds until the cause of the exception is fixed.
# at least, while the message banner is raised, suppress additional Log Entries.
dmactions.add_eventlog(actiondmfilestat, "%s - %s" %
(dmfileset.type, e.message), username='******')
# State needs to be Error since we do not know previous state (ie, do NOT
# set to Local, it might get deleted automatically)
actiondmfilestat.setactionstate('E')
except DMExceptions.SrcDirDoesNotExist as e:
applock.unlock()
msg = "Src Dir not found: %s. Setting action_state to Deleted" % e.message
EventLog.objects.add_entry(actiondmfilestat.result, msg, username='******')
actiondmfilestat.setactionstate('DD')
logger.info(msg, extra=logid)
except Exception as e:
applock.unlock()
msg = "action error on %s " % actiondmfilestat.result.resultsName
msg += " Error: %s" % str(e)
logger.error("%s - %s" % (dmfileset.type, msg), extra=logid)
logger.error(traceback.format_exc(), extra=logid)
dmactions.add_eventlog(actiondmfilestat, "%s - %s" % (dmfileset.type, msg), username='******')
# State needs to be Error since we do not know previous state (ie, do NOT
# set to Local, it might get deleted automatically)
actiondmfilestat.setactionstate('E')
return
def manage_data(deviceid, dmfileset, pathlist, auto_acknowledge_enabled, auto_action_enabled):
logid = {'logid': "%s" % ('manage_data')}
logger.debug("manage_data: %s %s" % (dmfileset['auto_action'], dmfileset['type']), extra=logid)
def getfirstnotpreserved(dmfilestats, action, threshdate):
'''QuerySet of DMFileStat objects. Returns first instance of an object
with preserve_data set to False and passes the action_validation test'''
logger.debug("Function: %s()" % sys._getframe().f_code.co_name, extra=logid)
logger.debug("Looking at %d dmfilestat objects" % dmfilestats.count(), extra=logid)
for archiveme in dmfilestats:
if not archiveme.getpreserved():
try:
dmactions.action_validation(archiveme, action)
return archiveme
except(DMExceptions.FilesInUse, DMExceptions.FilesMarkedKeep):
logger.debug("%s Failed action_validation. Try next fileset" %
archiveme.result.resultsName, extra=logid)
except DMExceptions.BaseInputLinked:
# want to allow Basecalling Input delete if all results are expired
related_objs = DMFileStat.objects.filter(
result__experiment=archiveme.result.experiment, dmfileset__type=dmactions_types.BASE)
if related_objs.count() == related_objs.filter(created__lt=threshdate).count():
archiveme.allow_delete = True
return archiveme
else:
logger.debug("%s Failed action_validation. Try next fileset" %
archiveme.result.resultsName, extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
else:
logger.debug("Skipped a preserved fileset: %s" % archiveme.result.resultsName, extra=logid)
logger.info("%d filestat objects are preserved." % dmfilestats.count(), extra=logid)
raise DMExceptions.NoDMFileStat("NONE FOUND")
try:
# logger.debug("manage_data lock for %s (%d)" % (dmfileset['type'], os.getpid()), extra = logid)
# Create lock file to prevent more than one celery task for each process_type and partition
lock_id = "%s_%s" % (hex(deviceid), slugify(dmfileset['type']))
logid = {'logid': "%s" % (lock_id)}
applock = TaskLock(lock_id)
if not applock.lock():
logger.info("Currently processing: %s(%s)" % (lock_id, applock.get()), extra=logid)
return
logger.debug("lock file created: %s(%s)" % (lock_id, applock.get()), extra=logid)
except Exception as e:
logger.error(traceback.format_exc(), extra=logid)
try:
#---------------------------------------------------------------------------
# Database object filtering
#---------------------------------------------------------------------------
actiondmfilestat = None
user_comment = "Auto Action"
# Order by incrementing pk. This puts them in chronological order.
# Select DMFileStat objects of category DMFileSet.type (1/4th of all objects)
dmfilestats = DMFileStat.objects.filter(dmfileset__type=dmfileset['type']).order_by('created')
tot_obj = dmfilestats.count()
# Select objects not yet processed
dmfilestats = dmfilestats.filter(action_state__in=['L', 'S', 'N', 'A'])
tot_act = dmfilestats.count()
# Select objects that are old enough
threshdate = datetime.now(pytz.UTC) - timedelta(days=dmfileset['auto_trigger_age'])
dmfilestats = dmfilestats.filter(created__lt=threshdate)
tot_exp = dmfilestats.count()
# Select objects stored on the deviceid
query = Q()
for path in pathlist:
if dmfileset['type'] == dmactions_types.SIG:
query |= Q(result__experiment__expDir__startswith=path)
# These categories have files in both directory paths.
elif dmfileset['type'] in [dmactions_types.INTR, dmactions_types.BASE]:
query |= Q(result__experiment__expDir__startswith=path)
query |= Q(result__reportstorage__dirPath__startswith=path)
else:
query |= Q(result__reportstorage__dirPath__startswith=path)
dmfilestats = dmfilestats.filter(query)
tot_onpath = dmfilestats.count()
# Exclude objects marked 'Keep' upfront to optimize db access
if dmfileset['type'] == dmactions_types.SIG:
dmfilestats = dmfilestats.exclude(result__experiment__storage_options="KI")
else:
dmfilestats = dmfilestats.exclude(preserve_data=True)
tot_notpreserved = dmfilestats.count()
# Compress to single log entry
logger.info("Total: %d Active: %d Expired: %d On Path: %d Not Preserved: %d" %
(tot_obj, tot_act, tot_exp, tot_onpath, tot_notpreserved), extra=logid)
#---------------------------------------------------------------------------
# Archive
#---------------------------------------------------------------------------
if dmfileset['auto_action'] == 'ARC':
'''
Rules:
1) archive a fileset as soon as age threshold reached, regardless of disk threshold
2) select oldest fileset
3) select unprocessed fileset
4) Archiving does not require 'S' -> 'N' -> 'A' progression before action
5) Do not include filesets marked 'E' in auto-action - can get stuck on that fileset forever
'''
logger.info("Exceed %d days. Eligible to archive: %d" %
(dmfileset['auto_trigger_age'], dmfilestats.count()), extra=logid)
actiondmfilestat = None
# Bail out if disabled
if auto_action_enabled != True:
logger.info("Data management auto-action is disabled.", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" % (os.getpid(), lock_id), extra=logid)
return
# Select first object stored on the deviceid
try:
actiondmfilestat = getfirstnotpreserved(dmfilestats, dmactions.ARCHIVE, threshdate)
logger.info("Picked: %s" % (actiondmfilestat.result.resultsName), extra=logid)
except DMExceptions.NoDMFileStat:
logger.debug("No filesets to archive on this device", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" % (os.getpid(), lock_id), extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" % (os.getpid(), lock_id), extra=logid)
else:
applock.update(actiondmfilestat.result.resultsName)
archive_action('dm_agent', user_comment, actiondmfilestat, lock_id)
#---------------------------------------------------------------------------
# Delete
#---------------------------------------------------------------------------
elif dmfileset['auto_action'] == 'DEL':
'''
Rules: If auto-acknowledge is True:
promote to Acknowledged and delete when age and disk threshold reached.
If auto-acknowledge is False:
If fileset type is SIG:
'S' -> 'N' -> 'A' progression
Else:
promote to 'A'
delete an 'A' fileset
'''
logger.info("Exceed %d days. Eligible to delete: %d" %
(dmfileset['auto_trigger_age'], dmfilestats.count()), extra=logid)
if auto_acknowledge_enabled:
if dmfileset['type'] == dmactions_types.SIG:
logger.debug("Sig Proc Input Files auto acknowledge enabled", extra=logid)
'''
Do not require 'S' -> 'N' -> 'A' progression before action; mark 'A' and process
'''
a_list = dmfilestats.filter(action_state='A')
if a_list.count() > 0:
# there are filesets acknowledged and ready to be deleted. Covers situation where user has
# already acknowledged but recently enabled auto-acknowledge as well.
# deleteme = a_list[0]
try:
actiondmfilestat = getfirstnotpreserved(a_list, dmactions.DELETE, threshdate)
logger.info("Picked: %s" % (actiondmfilestat.result.resultsName), extra=logid)
except DMExceptions.NoDMFileStat:
logger.info("No filesets to delete on this device", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
if actiondmfilestat == None:
# Select oldest fileset regardless if its 'L','S','N','A'. This covers situation where user
# recently enabled auto-acknowledge
try:
actiondmfilestat = getfirstnotpreserved(dmfilestats, dmactions.DELETE, threshdate)
logger.info("Picked: %s" % (actiondmfilestat.result.resultsName), extra=logid)
except DMExceptions.NoDMFileStat:
logger.info("No filesets to delete on this device", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
else:
if dmfileset['type'] == dmactions_types.SIG:
logger.debug("Sig Proc Input Files auto acknowledge disabled", extra=logid)
'''
Need to select # of filesets and mark 'S'
Need to find 'S' filesets and notify (set to 'N')
Set queue length to 5
sum(S,N,A) == queue length
'''
# Get email recipient
try:
recipient = User.objects.get(username='******').email
except:
recipient = None
# Need to select Experiments to process with appropriate dmfilestats action states.
exps = Experiment.objects.exclude(
storage_options='KI').exclude(expDir='').order_by('date')
l_list = exps.filter(
results_set__dmfilestat__in=dmfilestats.filter(action_state='L')).distinct()
s_list = exps.filter(
results_set__dmfilestat__in=dmfilestats.filter(action_state='S')).distinct()
n_list = exps.filter(
results_set__dmfilestat__in=dmfilestats.filter(action_state='N')).distinct()
a_list = exps.filter(
results_set__dmfilestat__in=dmfilestats.filter(action_state='A')).distinct()
logger.info("Experiments (Keep=False) L:%d S:%d N:%d A:%d" %
(l_list.count(), s_list.count(), n_list.count(), a_list.count()), extra=logid)
queue_length = 5
to_select = queue_length - (a_list.count() + n_list.count() + s_list.count())
if to_select > 0:
# Mark to_select number of oldest Experiments, from 'L', to 'S'
promoted = dmfilestats.filter(
result__experiment__id__in=list(l_list[:to_select].values_list('id', flat=True)))
if auto_action_enabled:
promoted.update(action_state='S')
for dmfilestat in promoted:
EventLog.objects.add_entry(
dmfilestat.result, "Signal Processing Input Selected for Deletion", username='******')
# Get updated list of Selected items
selected = dmfilestats.filter(action_state='S')
# Send Selected items to be notified
if selected.count() > 0 and auto_action_enabled:
logger.debug("notify recipient %s" % (recipient), extra=logid)
if notify([dmfilestat.result.resultsName for dmfilestat in selected], recipient):
selected.update(action_state='N')
for dmfilestat in selected:
EventLog.objects.add_entry(
dmfilestat.result, "Notification for Deletion Sent", username='******')
try:
actiondmfilestat = getfirstnotpreserved(
dmfilestats.filter(action_state='A'), dmactions.DELETE, threshdate)
logger.info("Picked: %s" % (actiondmfilestat.result.resultsName), extra=logid)
except DMExceptions.NoDMFileStat:
logger.info("No filesets to delete on this device", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
else:
try:
actiondmfilestat = getfirstnotpreserved(dmfilestats, dmactions.DELETE, threshdate)
logger.info("Picked: %s" % (actiondmfilestat.result.resultsName), extra=logid)
except DMExceptions.NoDMFileStat:
logger.info("No filesets to delete on this device", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
except:
logger.error(traceback.format_exc(), extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" %
(os.getpid(), lock_id), extra=logid)
# Bail out if disabled
if auto_action_enabled != True:
logger.info("Data management auto-action is disabled.", extra=logid)
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed %s" % (os.getpid(), lock_id), extra=logid)
return
if actiondmfilestat is not None:
applock.update(actiondmfilestat.result.resultsName)
delete_action('dm_agent', user_comment, actiondmfilestat, lock_id,
confirmed=getattr(actiondmfilestat, 'allow_delete', False))
else:
logger.error("Unknown or unhandled action: %s" % dmfileset['auto_action'], extra=logid)
applock.unlock()
except (DMExceptions.FilePermission,
DMExceptions.InsufficientDiskSpace,
DMExceptions.MediaNotSet,
DMExceptions.MediaNotAvailable,
DMExceptions.FilesInUse) as e:
applock.unlock()
message = Message.objects.filter(tags__contains=e.tag)
if not message:
Message.error(e.message, tags=e.tag)
# TODO: TS-6525: This logentry will repeat for an Archive action every 30 seconds until the cause of the exception is fixed.
# at least, while the message banner is raised, suppress additional Log Entries.
EventLog.objects.add_entry(actiondmfilestat.result, "%s - %s" %
(dmfileset['type'], e.message), username='******')
except DMExceptions.SrcDirDoesNotExist as e:
applock.unlock()
msg = "Src Dir not found: %s. Setting action_state to Deleted" % e.message
EventLog.objects.add_entry(actiondmfilestat.result, msg, username='******')
actiondmfilestat.setactionstate('DD')
logger.info(msg, extra=logid)
except Exception as inst:
applock.unlock()
msg = ''
if actiondmfilestat:
msg = "Auto-action error on %s " % actiondmfilestat.result.resultsName
msg += " Error: %s" % str(inst)
logger.error("%s - %s" % (dmfileset['type'], msg), extra=logid)
logger.error(traceback.format_exc(), extra=logid)
if actiondmfilestat:
EventLog.objects.add_entry(actiondmfilestat.result, "%s - %s" %
(dmfileset['type'], msg), username='******')
return
def _process_task(pfilename):
'''
Recursive celery task.
To trigger an orphaned task:
python -c "from iondb.bin import djangoinit; from iondb.rundb.data import dmactions; dmactions._process_task.(<filename>)"
where <filename> is full path to the data file found in /var/spool/ion
'''
logid = {'logid': "%s" % ('dmactions')}
from datetime import datetime
from datetime import timedelta
logger.debug("Function: %s()" % sys._getframe().f_code.co_name, extra=logid)
logger.debug("Task ID: %s" % _process_task.request.id, extra=logid)
# catch all unhandled exceptions and clean up
try:
try:
list_of_file_dict = get_action_param_var(pfilename)
except Exception as e:
logger.error("Error accessing file: %s. Cannot continue the DM action!" %
(pfilename), extra=logid)
# parse the filename to extract the dmfilestat pk and retrieve dmfilestat object.
dmfilestat_pk = os.path.basename(pfilename).split("_")[1]
dmfilestat = DMFileStat.objects.get(id=dmfilestat_pk)
raise e
dmfilestat = DMFileStat.objects.get(id=list_of_file_dict[0]['pk'])
terminate = True # flag to indicate recursion termination
total_processed = 0
fstatus = "Success"
start_time = datetime.now()
max_time_delta = timedelta(seconds=10)
# list_of_file_dict contains zero, one, or two dictionary variables to iterate over.
for d_cnt, mydict in enumerate(list_of_file_dict):
logid = {'logid': "%s" % (mydict.get('lockfile', '_process_task'))}
# The dictionary contains an element named 'to_process' which is a list variable to iterate over
logger.debug("%d, start_dir: %s" % (d_cnt, mydict['start_dir']), extra=logid)
logger.info("%6d %s %s" %
(len(mydict['to_process']), dmfilestat.dmfileset.type, dmfilestat.result.resultsName), extra=logid)
while (datetime.now() - start_time) < max_time_delta:
# If there are no files left to process, (all to_process lists are empty), the recursion ends
if len(mydict['to_process']) > 0:
terminate = False
try:
# process one file and remove entry from the list
path = mydict['to_process'].pop(0)
j = mydict['processed_cnt'] + 1
this_file_size = 0
if not os.path.islink(path):
this_file_size = os.lstat(path)[6]
if _process(path, mydict['action'], mydict['archivepath'], mydict['start_dir'], mydict['to_keep']):
mydict['processed_cnt'] = j
mydict['total_size'] += this_file_size
logger.debug("%04d/%04d %s %10d %s" % (
j, mydict['total_cnt'], mydict['action'], mydict['total_size'], path), extra=logid)
except (OSError, IOError) as e:
# IOError: [Errno 28] No space left on device:
if e.errno == errno.ENOSPC:
raise
elif e.errno == errno.ENOENT or e.errno == errno.ESTALE:
logger.warn("%04d No longer exists %s" % (j, path), extra=logid)
continue
else:
raise
except (DMExceptions.RsyncError, DMExceptions.MediaNotAvailable):
raise
except:
errmsg = "%04d/%04d %s %10d %s" % (
j, mydict['total_cnt'], mydict['action'], mydict['total_size'], path)
logger.error(errmsg, extra=logid)
logger.error(traceback.format_exc(), extra=logid)
if not mydict['action'] in [EXPORT, TEST] and dmfilestat.dmfileset.del_empty_dir:
thisdir = os.path.dirname(path)
try:
if len(os.listdir(thisdir)) == 0:
if not "plugin_out" in thisdir:
try:
os.rmdir(thisdir)
logger.debug("Removed empty directory: %s" % thisdir, extra=logid)
except Exception as e:
logger.warn("rmdir [%d] %s: %s" % (
e.errno, e.strerror, thisdir), extra=logid)
except OSError as e:
if e.errno == errno.ENOENT:
logger.warn("del_empty_dir Does not exist %s" % (path), extra=logid)
continue
else:
raise e
else:
break
# only expect to execute this line when no files to process
total_processed += mydict['total_size']
except Exception as e:
fstatus = "Error"
terminate = True
dmfilestat.setactionstate('E')
logger.error("DM Action failure on %s for %s report." %
(dmfilestat.dmfileset.type, dmfilestat.result.resultsName), extra=logid)
logger.error("This %s action will need to be manually completed." % (mydict['action']), extra=logid)
logger.error("The following is the exception error:\n" + traceback.format_exc(), extra=logid)
EventLog.objects.add_entry(
dmfilestat.result, "%s - %s. Action not completed. User intervention required." % (fstatus, e), username='******')
# Release the task lock
try:
applock = TaskLock(mydict['lockfile'])
applock.unlock()
except:
logger.error(traceback.format_exc(), extra=logid)
# Do the user notification
try:
# pop up a message banner
if mydict['msg_banner']:
dmfileset = dmfilestat.dmfileset
project_msg = {}
msg_dict = {}
msg_dict[dmfileset.type] = fstatus
project_msg[dmfilestat.result_id] = msg_dict
project_msg_banner('', project_msg, mydict['action'])
except:
logger.error(traceback.format_exc(), extra=logid)
# ====================================================================
# Exit function here on error
# ====================================================================
return
# Remove the data file here, no earlier. In case the task is clobbered, celery
# will relaunch the task, access the data file and continue the action.
try:
os.unlink(pfilename)
except:
pass
if not terminate:
# ====================================================================
# Launch next task
# ====================================================================
try:
mydict.get('action', 'unk')
pfilename = set_action_param_var(list_of_file_dict)
_process_task.delay(pfilename)
except:
logger.error(traceback.format_exc(), extra=logid)
else:
# ====================================================================
# No more files to process. Clean up and exit.
# ====================================================================
try:
dmfilestat.diskspace = float(total_processed) / (1024 * 1024)
dmfilestat.save()
logger.info("%0.1f MB %s processed" %
(dmfilestat.diskspace, dmfilestat.dmfileset.type), extra=logid)
if mydict['action'] in [ARCHIVE, DELETE]:
_brokenlinks_delete([dmfilestat.result.get_report_dir(), dmfilestat.result.experiment.expDir])
_emptydir_delete([dmfilestat.result.get_report_dir(), dmfilestat.result.experiment.expDir])
except:
logger.error(traceback.format_exc(), extra=logid)
# Do the user notification
try:
_action_complete_update(mydict['user'], mydict['user_comment'], dmfilestat, mydict['action'])
# pop up a message banner
if mydict['msg_banner']:
dmfileset = dmfilestat.dmfileset
project_msg = {}
msg_dict = {}
msg_dict[dmfileset.type] = fstatus
project_msg[dmfilestat.result_id] = msg_dict
project_msg_banner(mydict['user'], project_msg, mydict['action'])
except:
logger.error(traceback.format_exc(), extra=logid)
# Release the task lock
try:
applock = TaskLock(mydict['lockfile'])
applock.unlock()
except:
logger.error(traceback.format_exc(), extra=logid)
return
def manage_manual_action():
logger.debug("manage_manual_action")
try:
#Create lock file to prevent more than one celery task for manual action (export or archive)
lock_id = 'manual_action_lock_id'
applock = TaskLock(lock_id)
if not (applock.lock()):
logger.debug("failed to acquire lock file: %d" % os.getpid())
logger.info("manage_manual_action task still executing")
return
logger.debug("Worker PID %d lock_id created %s" %
(os.getpid(), lock_id))
except Exception as e:
logger.exception(e)
try:
#
# Check for manually selected Archive and Export actions - action_state == 'SA' or 'SE' or 'SD'
# Manual Delete actions do not get processed here. Only suspended Delete actions get processed here.
# These jobs should execute even when auto action is disabled.
# Note: manual actions will not be executed in the order they are selected, but by age.
#
manualSelects = DMFileStat.objects.filter(
action_state__in=['SA', 'SE', 'SD']).order_by('created')
if manualSelects.exists():
actiondmfilestat = manualSelects[0]
user = actiondmfilestat.user_comment.get('user', 'dm_agent')
user_comment = actiondmfilestat.user_comment.get(
'user_comment', 'Manual Action')
dmfileset = actiondmfilestat.dmfileset
if actiondmfilestat.action_state == 'SA':
logger.info(
"Manual Archive Action: %s from %s" %
(dmfileset.type, actiondmfilestat.result.resultsName))
archive_action(user,
user_comment,
actiondmfilestat,
lock_id,
msg_banner=True)
elif actiondmfilestat.action_state == 'SE':
logger.info(
"Manual Export Action: %s from %s" %
(dmfileset.type, actiondmfilestat.result.resultsName))
export_action(user,
user_comment,
actiondmfilestat,
lock_id,
msg_banner=True)
elif actiondmfilestat.action_state == 'SD':
logger.info(
"Delete Action: %s from %s" %
(dmfileset.type, actiondmfilestat.result.resultsName))
delete_action(user,
"Continuing delete action after being suspended",
actiondmfilestat,
lock_id,
msg_banner=True)
else:
logger.warn("Dev Error: we don't handle this '%s' here" %
actiondmfilestat.action_state)
else:
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed on exit %s" %
(os.getpid(), lock_id))
#NOTE: all these exceptions are also handled in manage_data() below. beaucoup de duplication de code
except (DMExceptions.FilePermission, DMExceptions.InsufficientDiskSpace,
DMExceptions.MediaNotSet, DMExceptions.MediaNotAvailable,
DMExceptions.FilesInUse) as e:
applock.unlock()
message = Message.objects.filter(tags__contains=e.tag)
if not message:
Message.error(e.message, tags=e.tag)
#TODO: TS-6525: This logentry will repeat for an Archive action every 30 seconds until the cause of the exception is fixed.
#at least, while the message banner is raised, suppress additional Log Entries.
dmactions.add_eventlog(actiondmfilestat,
"%s - %s" % (dmfileset.type, e.message),
username='******')
# Revert this dmfilestat object action-state to Local
actiondmfilestat.setactionstate('L')
except DMExceptions.SrcDirDoesNotExist as e:
applock.unlock()
msg = "Src Dir not found: %s. Setting action_state to Deleted" % e.message
EventLog.objects.add_entry(actiondmfilestat.result,
msg,
username='******')
actiondmfilestat.setactionstate('DD')
logger.info(msg)
except Exception as e:
applock.unlock()
msg = "action error on %s " % actiondmfilestat.result.resultsName
msg += " Error: %s" % str(e)
logger.exception("%s - %s" % (dmfileset.type, msg))
dmactions.add_eventlog(actiondmfilestat,
"%s - %s" % (dmfileset.type, msg),
username='******')
# Revert this dmfilestat object action-state to Local
actiondmfilestat.setactionstate('L')
return
def _process_fileset_task(dmfilestat, action, user, user_comment, lockfile, msg_banner):
'''
This function generates a list of files to process, then hands the list to a recursive
celery task function. The recursion continues until the list is empty. The calling
function exits immediately.
'''
logid = {'logid':"%s" % (lockfile)}
logger.debug("Function: %s()" % sys._getframe().f_code.co_name, extra = logid)
if dmfilestat.isdeleted():
errmsg = "The %s for %s are deleted" % (dmfilestat.dmfileset.type, dmfilestat.result.resultsName)
logger.warn(errmsg, extra = logid)
raise Exception(errmsg)
elif dmfilestat.isarchived():
if not os.path.exists(dmfilestat.archivepath):
errmsg = "Cannot access backup location %s" % dmfilestat.archivepath
logger.warn(errmsg, extra = logid)
raise Exception(errmsg)
else:
# search archived directory
search_dirs = [dmfilestat.archivepath]
else:
# search both results directory and raw data directory
search_dirs = [dmfilestat.result.get_report_dir(), dmfilestat.result.experiment.expDir]
# Create a lock file here to block any other actions on this report (see TS-8411)
lock_id = "%s_%s" % (dmfilestat.result.resultsName, dm_utils.slugify(dmfilestat.dmfileset.type))
locallock = TaskLock(lock_id, timeout=60) # short timeout in case lock release code doesn't get called
if not(locallock.lock()):
logger.warn("lock file exists: %s(%s)" % (lock_id, locallock.get()), extra = logid)
# Release the task lock
try:
applock = TaskLock(lockfile)
applock.unlock()
except:
logger.error(traceback.format_exc(), extra = logid)
return
logger.info("lock file created: %s(%s)" % (lock_id, locallock.get()), extra = logid)
if action == ARCHIVE:
dmfilestat.setactionstate('AG')
elif action == DELETE:
dmfilestat.setactionstate('DG')
elif action == EXPORT:
dmfilestat.setactionstate('EG')
# List of all files associated with the report
cached_file_list = dm_utils.get_walk_filelist(search_dirs, list_dir=dmfilestat.result.get_report_dir())
#Determine if this file type is eligible to use a keep list
kpatterns = _get_keeper_list(dmfilestat, action)
#Create a list of files eligible to process
list_of_file_dict = []
is_thumbnail = dmfilestat.result.isThumbnail
add_linked_sigproc = False if (action == DELETE or dmfilestat.dmfileset.type == dmactions_types.INTR) else True
for start_dir in search_dirs:
logger.debug("Searching: %s" % start_dir, extra = logid)
to_process = []
to_keep = []
if os.path.isdir(start_dir):
to_process, to_keep = dm_utils._file_selector(start_dir,
dmfilestat.dmfileset.include,
dmfilestat.dmfileset.exclude,
kpatterns,
is_thumbnail,
add_linked_sigproc,
cached=cached_file_list)
logger.info("%d files to process at %s" % (len(list(set(to_process) - set(to_keep))), start_dir), extra = logid)
list_of_file_dict.append(
{
'pk':dmfilestat.id,
'action':action,
'archivepath':dmfilestat.archivepath,
'start_dir':start_dir,
'to_process':to_process,
'to_keep':to_keep,
'total_cnt':len(list(set(to_process) - set(to_keep))),
'processed_cnt':0,
'total_size':0,
'user':user,
'user_comment':user_comment,
'lockfile':lockfile,
'msg_banner':msg_banner,
}
)
try:
pfilename = set_action_param_var(list_of_file_dict)
# Call the recursive celery task function to process the list
_process_task.delay(pfilename)
except:
logger.error("We got an error here, _process_fileset_task", extra = logid)
raise
finally:
if locallock:
locallock.unlock()
return
def _process_task(pfilename):
'''
Recursive celery task
'''
from datetime import datetime
from datetime import timedelta
logger.debug("Function: %s()" % sys._getframe().f_code.co_name)
logger.debug("Task ID: %s" % _process_task.request.id)
#catch all unhandled exceptions and clean up
try:
list_of_file_dict = get_action_param_file(pfilename)
os.unlink(pfilename)
dmfilestat = DMFileStat.objects.get(id=list_of_file_dict[0]['pk'])
terminate = True # flag to indicate recursion termination
total_processed = 0
start_time = datetime.now()
max_time_delta = timedelta(seconds=10)
# list_of_file_dict contains zero, one, or two dictionary variables to iterate over.
for q,dict in enumerate(list_of_file_dict):
# The dictionary contains an element named 'to_process' which is a list variable to iterate over
logger.debug("%d, start_dir: %s" % (q,dict['start_dir']))
while (datetime.now() - start_time) < max_time_delta:
# If there are no files left to process, (all to_process lists are empty), the recursion ends
if len(dict['to_process']) > 0:
terminate = False
try:
# process one file and remove entry from the list
path = dict['to_process'].pop(0)
j = dict['processed_cnt'] + 1
this_file_size = 0
if not os.path.islink(path):
this_file_size = os.lstat(path)[6]
if _process(path, dict['action'], dict['archivepath'], dict['start_dir'], dict['to_keep']):
dict['processed_cnt'] = j
dict['total_size'] += this_file_size
logger.info("%04d/%04d %s %10d %s" % (j, dict['total_cnt'], dict['action'], dict['total_size'], path))
except (OSError,IOError) as e:
#IOError: [Errno 28] No space left on device:
if e.errno == errno.ENOSPC:
raise
elif e.errno == errno.ENOENT:
logger.warn("%04d No longer exists %s" % (j,path))
continue
except:
errmsg = "%04d/%04d %s %10d %s" % (j, dict['total_cnt'], dict['action'], dict['total_size'], path)
logger.error(errmsg)
logger.error(traceback.format_exc())
if not dict['action'] in [EXPORT,TEST] and dmfilestat.dmfileset.del_empty_dir:
dir = os.path.dirname(path)
try:
if len(os.listdir(dir)) == 0:
if not "plugin_out" in dir:
try:
os.rmdir(dir)
logger.debug("Removed empty directory: %s" % dir)
except Exception as e:
logger.warn("rmdir [%d] %s: %s" % (e.errno,e.strerror,dir))
except OSError as e:
if e.errno == errno.ENOENT:
logger.warn("del_empty_dir Does not exist %s" % (path))
continue
else:
raise e
else:
break
# only expect to execute this line when no files to process
total_processed += dict['total_size']
except:
dmfilestat.setactionstate('E')
logger.error("DM Action failure on %s for %s report." % (dmfilestat.dmfileset.type,dmfilestat.result.resultsName))
logger.error("This %s action will need to be manually completed." % (dict['action']))
logger.error("The following is the exception error:\n"+traceback.format_exc())
EventLog.objects.add_entry(dmfilestat.result,"%s - %s" % (dmfilestat.dmfileset.type, msg),username='******')
if dict['lockfile']:
applock = TaskLock(dict['lockfile'])
applock.unlock()
return
#logger.debug("Sleep for 1")
#import time
#time.sleep(1)
if terminate:
try:
# No more files to process. Do the clean up.
dmfilestat.diskspace = float(total_processed)/(1024*1024)
dmfilestat.save()
logger.info("%0.1f MB %s processed" % (dmfilestat.diskspace, dmfilestat.dmfileset.type))
if dict['action'] in [ARCHIVE, DELETE]:
_emptydir_delete(dmfilestat)
_action_complete_update(dict['user'], dict['user_comment'], dmfilestat, dict['action'])
# pop up a message banner
if dict['msg_banner']:
dmfileset = dmfilestat.dmfileset
project_msg = {}
msg_dict = {}
msg_dict[dmfileset.type] = "Success"
project_msg[dmfilestat.result_id] = msg_dict
project_msg_banner('', project_msg, dict['action'])
if dict['lockfile']:
applock = TaskLock(dict['lockfile'])
applock.unlock()
except:
logger.exception(traceback.format_exc())
else:
# Launch next task
try:
pfilename = set_action_param_file(list_of_file_dict)
celery_result = _process_task.delay(pfilename)
except:
logger.error(traceback.format_exc())
return
def _process_task(pfilename):
'''
Recursive celery task
'''
from datetime import datetime
from datetime import timedelta
logger.debug("Function: %s()" % sys._getframe().f_code.co_name)
logger.debug("Task ID: %s" % _process_task.request.id)
#catch all unhandled exceptions and clean up
try:
list_of_file_dict = get_action_param_file(pfilename)
os.unlink(pfilename)
dmfilestat = DMFileStat.objects.get(id=list_of_file_dict[0]['pk'])
terminate = True # flag to indicate recursion termination
total_processed = 0
start_time = datetime.now()
max_time_delta = timedelta(seconds=10)
# list_of_file_dict contains zero, one, or two dictionary variables to iterate over.
for q, dict in enumerate(list_of_file_dict):
# The dictionary contains an element named 'to_process' which is a list variable to iterate over
logger.debug("%d, start_dir: %s" % (q, dict['start_dir']))
while (datetime.now() - start_time) < max_time_delta:
# If there are no files left to process, (all to_process lists are empty), the recursion ends
if len(dict['to_process']) > 0:
terminate = False
try:
# process one file and remove entry from the list
path = dict['to_process'].pop(0)
j = dict['processed_cnt'] + 1
this_file_size = 0
if not os.path.islink(path):
this_file_size = os.lstat(path)[6]
if _process(path, dict['action'], dict['archivepath'],
dict['start_dir'], dict['to_keep']):
dict['processed_cnt'] = j
dict['total_size'] += this_file_size
logger.info("%04d/%04d %s %10d %s" %
(j, dict['total_cnt'], dict['action'],
dict['total_size'], path))
except (OSError, IOError) as e:
#IOError: [Errno 28] No space left on device:
if e.errno == errno.ENOSPC:
raise
elif e.errno == errno.ENOENT:
logger.warn("%04d No longer exists %s" % (j, path))
continue
except:
errmsg = "%04d/%04d %s %10d %s" % (
j, dict['total_cnt'], dict['action'],
dict['total_size'], path)
logger.error(errmsg)
logger.error(traceback.format_exc())
if not dict['action'] in [
EXPORT, TEST
] and dmfilestat.dmfileset.del_empty_dir:
dir = os.path.dirname(path)
try:
if len(os.listdir(dir)) == 0:
if not "plugin_out" in dir:
try:
os.rmdir(dir)
logger.debug(
"Removed empty directory: %s" %
dir)
except Exception as e:
logger.warn("rmdir [%d] %s: %s" %
(e.errno, e.strerror, dir))
except OSError as e:
if e.errno == errno.ENOENT:
logger.warn("del_empty_dir Does not exist %s" %
(path))
continue
else:
raise e
else:
break
# only expect to execute this line when no files to process
total_processed += dict['total_size']
except:
dmfilestat.setactionstate('E')
logger.error(
"DM Action failure on %s for %s report." %
(dmfilestat.dmfileset.type, dmfilestat.result.resultsName))
logger.error("This %s action will need to be manually completed." %
(dict['action']))
logger.error("The following is the exception error:\n" +
traceback.format_exc())
EventLog.objects.add_entry(dmfilestat.result,
"%s - %s" %
(dmfilestat.dmfileset.type, msg),
username='******')
if dict['lockfile']:
applock = TaskLock(dict['lockfile'])
applock.unlock()
return
#logger.debug("Sleep for 1")
#import time
#time.sleep(1)
if terminate:
try:
# No more files to process. Do the clean up.
dmfilestat.diskspace = float(total_processed) / (1024 * 1024)
dmfilestat.save()
logger.info("%0.1f MB %s processed" %
(dmfilestat.diskspace, dmfilestat.dmfileset.type))
if dict['action'] in [ARCHIVE, DELETE]:
_emptydir_delete(dmfilestat)
_action_complete_update(dict['user'], dict['user_comment'],
dmfilestat, dict['action'])
# pop up a message banner
if dict['msg_banner']:
dmfileset = dmfilestat.dmfileset
project_msg = {}
msg_dict = {}
msg_dict[dmfileset.type] = "Success"
project_msg[dmfilestat.result_id] = msg_dict
project_msg_banner('', project_msg, dict['action'])
if dict['lockfile']:
applock = TaskLock(dict['lockfile'])
applock.unlock()
except:
logger.exception(traceback.format_exc())
else:
# Launch next task
try:
pfilename = set_action_param_file(list_of_file_dict)
celery_result = _process_task.delay(pfilename)
except:
logger.error(traceback.format_exc())
return
def manage_manual_action():
logger.debug("manage_manual_action", extra = {'logid':"%s" % ('manual_action')})
try:
#Create lock file to prevent more than one celery task for manual action (export or archive)
lock_id = 'manual_action_lock_id'
d = {'logid':"%s" % (lock_id)}
applock = TaskLock(lock_id)
if not(applock.lock()):
logger.debug("lock file exists: %s(%s)" % (lock_id, applock.get()), extra = d)
return
logger.debug("lock file created: %s(%s)" % (lock_id, applock.get()), extra = d)
except Exception as e:
logger.error(traceback.format_exc(), extra = d)
try:
#
# Check for manually selected Archive and Export actions - action_state == 'SA' or 'SE' or 'SD'
# Manual Delete actions do not get processed here. Only suspended Delete actions get processed here.
# These jobs should execute even when auto action is disabled.
# Note: manual actions will not be executed in the order they are selected, but by age.
#
manualSelects = DMFileStat.objects.filter(action_state__in=['SA','SE','SD']).order_by('created')
if manualSelects.exists():
actiondmfilestat = manualSelects[0]
user = actiondmfilestat.user_comment.get('user', 'dm_agent')
user_comment = actiondmfilestat.user_comment.get('user_comment', 'Manual Action')
dmfileset = actiondmfilestat.dmfileset
applock.update(actiondmfilestat.result.resultsName)
if actiondmfilestat.action_state == 'SA':
logger.info("Manual Archive Action: %s from %s" % (dmfileset.type,actiondmfilestat.result.resultsName), extra = d)
archive_action(user, user_comment, actiondmfilestat, lock_id, msg_banner = True)
elif actiondmfilestat.action_state == 'SE':
logger.info("Manual Export Action: %s from %s" % (dmfileset.type,actiondmfilestat.result.resultsName), extra = d)
export_action(user, user_comment, actiondmfilestat, lock_id, msg_banner = True)
elif actiondmfilestat.action_state == 'SD':
logger.info("Delete Action: %s from %s" % (dmfileset.type,actiondmfilestat.result.resultsName), extra = d)
delete_action(user, "Continuing delete action after being suspended", actiondmfilestat, lock_id, msg_banner = True)
else:
logger.warn("Dev Error: we don't handle this '%s' here" % actiondmfilestat.action_state, extra = d)
else:
applock.unlock()
logger.debug("Worker PID %d lock_id destroyed on exit %s" % (os.getpid(),lock_id), extra = d)
#NOTE: all these exceptions are also handled in manage_data() below. beaucoup de duplication de code
except (DMExceptions.FilePermission,
DMExceptions.InsufficientDiskSpace,
DMExceptions.MediaNotSet,
DMExceptions.MediaNotAvailable,
DMExceptions.FilesInUse) as e:
applock.unlock()
message = Message.objects.filter(tags__contains=e.tag)
if not message:
Message.error(e.message,tags=e.tag)
#TODO: TS-6525: This logentry will repeat for an Archive action every 30 seconds until the cause of the exception is fixed.
#at least, while the message banner is raised, suppress additional Log Entries.
dmactions.add_eventlog(actiondmfilestat, "%s - %s" % (dmfileset.type, e.message), username='******')
# Revert this dmfilestat object action-state to Local
actiondmfilestat.setactionstate('L')
except DMExceptions.SrcDirDoesNotExist as e:
applock.unlock()
msg = "Src Dir not found: %s. Setting action_state to Deleted" % e.message
EventLog.objects.add_entry(actiondmfilestat.result,msg,username='******')
actiondmfilestat.setactionstate('DD')
logger.info(msg, extra = d)
except Exception as e:
applock.unlock()
msg = "action error on %s " % actiondmfilestat.result.resultsName
msg += " Error: %s" % str(e)
logger.error("%s - %s" % (dmfileset.type, msg), extra = d)
logger.error(traceback.format_exc(), extra = d)
dmactions.add_eventlog(actiondmfilestat,"%s - %s" % (dmfileset.type, msg),username='******')
# Revert this dmfilestat object action-state to Local
actiondmfilestat.setactionstate('L')
return
def _process_task(pfilename):
'''
Recursive celery task.
To trigger an orphaned task:
python -c "from iondb.bin import djangoinit; from iondb.rundb.data import dmactions; dmactions._process_task.(<filename>)"
where <filename> is full path to the data file found in /var/spool/ion
'''
logid = {'logid':"%s" % ('dmactions')}
from datetime import datetime
from datetime import timedelta
logger.debug("Function: %s()" % sys._getframe().f_code.co_name, extra = logid)
logger.debug("Task ID: %s" % _process_task.request.id, extra = logid)
#catch all unhandled exceptions and clean up
try:
try:
list_of_file_dict = get_action_param_var(pfilename)
except Exception as e:
logger.error("Error accessing file: %s. Cannot continue the DM action!" % (pfilename), extra = logid)
# parse the filename to extract the dmfilestat pk and retrieve dmfilestat object.
dmfilestat_pk = os.path.basename(pfilename).split("_")[1]
dmfilestat = DMFileStat.objects.get(id=dmfilestat_pk)
raise e
dmfilestat = DMFileStat.objects.get(id=list_of_file_dict[0]['pk'])
terminate = True # flag to indicate recursion termination
total_processed = 0
fstatus = "Success"
start_time = datetime.now()
max_time_delta = timedelta(seconds=10)
# list_of_file_dict contains zero, one, or two dictionary variables to iterate over.
for d_cnt, dict in enumerate(list_of_file_dict):
logid = {'logid':"%s" % (dict.get('lockfile','_process_task'))}
# The dictionary contains an element named 'to_process' which is a list variable to iterate over
logger.debug("%d, start_dir: %s" % (d_cnt, dict['start_dir']), extra = logid)
logger.info("%6d %s %s" %(len(dict['to_process']), dmfilestat.dmfileset.type, dmfilestat.result.resultsName), extra = logid)
while (datetime.now() - start_time) < max_time_delta:
# If there are no files left to process, (all to_process lists are empty), the recursion ends
if len(dict['to_process']) > 0:
terminate = False
try:
# process one file and remove entry from the list
path = dict['to_process'].pop(0)
j = dict['processed_cnt'] + 1
this_file_size = 0
if not os.path.islink(path):
this_file_size = os.lstat(path)[6]
if _process(path, dict['action'], dict['archivepath'], dict['start_dir'], dict['to_keep']):
dict['processed_cnt'] = j
dict['total_size'] += this_file_size
logger.debug("%04d/%04d %s %10d %s" % (j, dict['total_cnt'], dict['action'], dict['total_size'], path), extra = logid)
except (OSError, IOError) as e:
#IOError: [Errno 28] No space left on device:
if e.errno == errno.ENOSPC:
raise
elif e.errno == errno.ENOENT or e.errno == errno.ESTALE:
logger.warn("%04d No longer exists %s" % (j, path), extra = logid)
continue
else:
raise
except (DMExceptions.RsyncError, DMExceptions.MediaNotAvailable):
raise
except:
errmsg = "%04d/%04d %s %10d %s" % (j, dict['total_cnt'], dict['action'], dict['total_size'], path)
logger.error(errmsg, extra = logid)
logger.error(traceback.format_exc(), extra = logid)
if not dict['action'] in [EXPORT, TEST] and dmfilestat.dmfileset.del_empty_dir:
dir = os.path.dirname(path)
try:
if len(os.listdir(dir)) == 0:
if not "plugin_out" in dir:
try:
os.rmdir(dir)
logger.debug("Removed empty directory: %s" % dir, extra = logid)
except Exception as e:
logger.warn("rmdir [%d] %s: %s" % (e.errno, e.strerror, dir), extra = logid)
except OSError as e:
if e.errno == errno.ENOENT:
logger.warn("del_empty_dir Does not exist %s" % (path), extra = logid)
continue
else:
raise e
else:
break
# only expect to execute this line when no files to process
total_processed += dict['total_size']
except Exception as e:
fstatus = "Error"
terminate = True
dmfilestat.setactionstate('E')
logger.error("DM Action failure on %s for %s report." % (dmfilestat.dmfileset.type, dmfilestat.result.resultsName), extra = logid)
logger.error("This %s action will need to be manually completed." % (dict['action']), extra = logid)
logger.error("The following is the exception error:\n"+traceback.format_exc(), extra = logid)
EventLog.objects.add_entry(dmfilestat.result,"%s - %s. Action not completed. User intervention required." % (fstatus, e), username='******')
# Release the task lock
try:
applock = TaskLock(dict['lockfile'])
applock.unlock()
except:
logger.error(traceback.format_exc(), extra = logid)
# Do the user notification
try:
# pop up a message banner
if dict['msg_banner']:
dmfileset = dmfilestat.dmfileset
project_msg = {}
msg_dict = {}
msg_dict[dmfileset.type] = fstatus
project_msg[dmfilestat.result_id] = msg_dict
project_msg_banner('', project_msg, dict['action'])
except:
logger.error(traceback.format_exc(), extra = logid)
# ====================================================================
# Exit function here on error
# ====================================================================
return
# Remove the data file here, no earlier. In case the task is clobbered, celery
# will relaunch the task, access the data file and continue the action.
try:
os.unlink(pfilename)
except:
pass
if not terminate:
# ====================================================================
# Launch next task
# ====================================================================
try:
dict.get('action','unk')
pfilename = set_action_param_var(list_of_file_dict)
_process_task.delay(pfilename)
except:
logger.error(traceback.format_exc(), extra = logid)
else:
# ====================================================================
# No more files to process. Clean up and exit.
# ====================================================================
try:
dmfilestat.diskspace = float(total_processed)/(1024*1024)
dmfilestat.save()
logger.info("%0.1f MB %s processed" % (dmfilestat.diskspace, dmfilestat.dmfileset.type), extra = logid)
if dict['action'] in [ARCHIVE, DELETE]:
_brokenlinks_delete([dmfilestat.result.get_report_dir(), dmfilestat.result.experiment.expDir])
_emptydir_delete([dmfilestat.result.get_report_dir(), dmfilestat.result.experiment.expDir])
except:
logger.error(traceback.format_exc(), extra = logid)
# Do the user notification
try:
_action_complete_update(dict['user'], dict['user_comment'], dmfilestat, dict['action'])
# pop up a message banner
if dict['msg_banner']:
dmfileset = dmfilestat.dmfileset
project_msg = {}
msg_dict = {}
msg_dict[dmfileset.type] = fstatus
project_msg[dmfilestat.result_id] = msg_dict
project_msg_banner(dict['user'], project_msg, dict['action'])
except:
logger.error(traceback.format_exc(), extra = logid)
# Release the task lock
try:
applock = TaskLock(dict['lockfile'])
applock.unlock()
except:
logger.error(traceback.format_exc(), extra = logid)
return
def _process_fileset_task(dmfilestat, action, user, user_comment, lockfile, msg_banner):
'''
This function generates a list of files to process, then hands the list to a recursive
celery task function. The recursion continues until the list is empty. The calling
function exits immediately.
'''
logid = {'logid':"%s" % (lockfile)}
logger.debug("Function: %s()" % sys._getframe().f_code.co_name, extra = logid)
if dmfilestat.isdeleted():
errmsg = "The %s for %s are deleted" % (dmfilestat.dmfileset.type, dmfilestat.result.resultsName)
logger.warn(errmsg, extra = logid)
raise Exception(errmsg)
elif dmfilestat.isarchived():
if not os.path.exists(dmfilestat.archivepath):
errmsg = "Cannot access backup location %s" % dmfilestat.archivepath
logger.warn(errmsg, extra = logid)
raise Exception(errmsg)
else:
# search archived directory
search_dirs = [dmfilestat.archivepath]
else:
# search both results directory and raw data directory
search_dirs = [dmfilestat.result.get_report_dir(), dmfilestat.result.experiment.expDir]
# Create a lock file here to block any other actions on this report (see TS-8411)
lock_id = "%s_%s" % (dmfilestat.result.resultsName, dm_utils.slugify(dmfilestat.dmfileset.type))
locallock = TaskLock(lock_id, timeout=60) # short timeout in case lock release code doesn't get called
if not(locallock.lock()):
logger.warn("lock file exists: %s(%s)" % (lock_id, locallock.get()), extra = logid)
# Release the task lock
try:
applock = TaskLock(lockfile)
applock.unlock()
except:
logger.error(traceback.format_exc(), extra = logid)
return
logger.info("lock file created: %s(%s)" % (lock_id, locallock.get()), extra = logid)
if action == ARCHIVE:
dmfilestat.setactionstate('AG')
elif action == DELETE:
dmfilestat.setactionstate('DG')
elif action == EXPORT:
dmfilestat.setactionstate('EG')
# List of all files associated with the report
cached_file_list = dm_utils.get_walk_filelist(search_dirs, list_dir=dmfilestat.result.get_report_dir())
#Determine if this file type is eligible to use a keep list
kpatterns = _get_keeper_list(dmfilestat, action)
#Create a list of files eligible to process
list_of_file_dict = []
is_thumbnail = dmfilestat.result.isThumbnail
add_linked_sigproc = False if (action == DELETE or dmfilestat.dmfileset.type == dmactions_types.INTR) else True
for start_dir in search_dirs:
logger.debug("Searching: %s" % start_dir, extra = logid)
to_process = []
to_keep = []
if os.path.isdir(start_dir):
to_process, to_keep = dm_utils._file_selector(start_dir,
dmfilestat.dmfileset.include,
dmfilestat.dmfileset.exclude,
kpatterns,
is_thumbnail,
add_linked_sigproc,
cached=cached_file_list)
logger.info("%d files to process at %s" % (len(list(set(to_process) - set(to_keep))), start_dir), extra = logid)
list_of_file_dict.append(
{
'pk':dmfilestat.id,
'action':action,
'archivepath':dmfilestat.archivepath,
'start_dir':start_dir,
'to_process':to_process,
'to_keep':to_keep,
'total_cnt':len(list(set(to_process) - set(to_keep))),
'processed_cnt':0,
'total_size':0,
'user':user,
'user_comment':user_comment,
'lockfile':lockfile,
'msg_banner':msg_banner,
}
)
try:
pfilename = set_action_param_var(list_of_file_dict)
# Call the recursive celery task function to process the list
_process_task.delay(pfilename)
except:
logger.error("We got an error here, _process_fileset_task", extra = logid)
raise
finally:
if locallock:
locallock.unlock()
return