22 Jan 2020 11:41:05,748 INFO : Copying experiment "Targeted Mass Spectrometry of a Clinically Relevant PSA Variant from Post-DRE Urines for Quantitation and Genotype Determination" from folder /Eastern Virginia Med School - Proteomics/Otto et al -- Proteomics Clinical Applications to /Panorama Public/2020/Eastern Virginia Med School - Otto et al  Proteomics Clinical Applications
22 Jan 2020 11:41:05,748 INFO : =======================================
22 Jan 2020 11:41:06,053 INFO : Starting to run task 'org.labkey.panoramapublic.pipeline.ExperimentExportTask' at location 'webserver-high-priority'
22 Jan 2020 11:41:06,053 INFO : 
22 Jan 2020 11:41:06,053 INFO : Exporting experiment.
22 Jan 2020 12:04:11,468 INFO : 
22 Jan 2020 12:04:11,468 INFO : Experiment export completed successfully.
22 Jan 2020 12:04:11,468 INFO : Successfully completed task 'org.labkey.panoramapublic.pipeline.ExperimentExportTask'
22 Jan 2020 12:04:11,591 INFO : Starting to run task 'org.labkey.panoramapublic.pipeline.ExperimentImportTask' at location 'webserver-high-priority'
22 Jan 2020 12:04:11,592 INFO : 
22 Jan 2020 12:04:11,592 INFO : Importing experiment.
22 Jan 2020 12:04:11,861 INFO : Loading folder properties (folder type, settings and active modules)
22 Jan 2020 12:04:12,060 INFO : Done importing folder properties (folder type, settings and active modules)
22 Jan 2020 12:04:12,069 INFO : Loading etl definitions
22 Jan 2020 12:04:12,087 INFO : Loading wikis
22 Jan 2020 12:04:12,095 INFO : 0 wikis imported
22 Jan 2020 12:04:12,096 INFO : Done importing wikis
22 Jan 2020 12:21:36,014 INFO : Loading xar
22 Jan 2020 12:21:39,607 DEBUG: Finished loading Protocol with LSID 'urn:lsid:uw.edu:Protocol.Folder-6379:TargetedMS.ImportSkyZip'
22 Jan 2020 12:21:39,615 DEBUG: Finished loading Protocol with LSID 'urn:lsid:uw.edu:Protocol.Folder-6379:TargetedMS.ImportSkyZip.Core'
22 Jan 2020 12:21:39,622 DEBUG: Finished loading Protocol with LSID 'urn:lsid:uw.edu:Protocol.Folder-6379:TargetedMS.ImportSkyZip.Output'
22 Jan 2020 12:21:39,622 DEBUG: Protocol import complete
22 Jan 2020 12:21:39,660 DEBUG: Finished loading Experiment with LSID 'urn:lsid:uw.edu:Experiment.Folder-6379:Targeted+Mass+Spectrometry+of+a+Clinically+Relevant+PSA+Variant+from+Post-DRE+Urines+for+Quantitation+and+Genotype+Determination'
22 Jan 2020 12:21:39,660 DEBUG: Experiment/Run group import complete
22 Jan 2020 12:21:39,733 DEBUG: Protocol action set import complete
22 Jan 2020 12:21:39,842 DEBUG: Finished loading ProtocolApplication with LSID 'urn:lsid:uw.edu:Protocol.Folder-6379:TargetedMS.ImportSkyZip'
22 Jan 2020 12:21:39,990 DEBUG: Finished loading Data with LSID 'urn:lsid:uw.edu:UploadedFile.Folder-6379:c204fb60-1aa7-1038-baec-3013bb9b17af'
22 Jan 2020 12:21:40,003 DEBUG: Finished loading Data with LSID 'urn:lsid:uw.edu:skyd.Folder-6379:c204fcb8-1aa7-1038-baec-3013bb9b17af'
22 Jan 2020 12:21:40,003 DEBUG: Finished loading ProtocolApplication with LSID 'urn:lsid:uw.edu:Protocol.Folder-6379:TargetedMS.ImportSkyZip.Core'
22 Jan 2020 12:21:40,013 DEBUG: Finished loading ProtocolApplication with LSID 'urn:lsid:uw.edu:Protocol.Folder-6379:TargetedMS.ImportSkyZip.Output'
22 Jan 2020 12:21:40,014 DEBUG: Finished loading ExperimentRun with LSID 'urn:lsid:uw.edu:Run.Folder-6379:c204fcdb-1aa7-1038-baec-3013bb9b17af'
22 Jan 2020 12:21:40,017 DEBUG: Trying to load data file file:///data/labkey/files/Panorama%20Public/2020/Eastern%20Virginia%20Med%20School%20-%20Otto%20et%20al%20%20Proteomics%20Clinical%20Applications/@files/export/xar/experiments_and_runs.xar.exploded/Run79427/PSA_Mut_53Samps.sky_BACKUPCOPY.zip into the system
22 Jan 2020 12:21:40,022 INFO : Starting import from PSA_Mut_53Samps.sky_BACKUPCOPY.zip
22 Jan 2020 12:21:40,032 INFO : Starting to import Skyline document from PSA_Mut_53Samps.sky_BACKUPCOPY.zip
22 Jan 2020 12:21:40,095 INFO : Expanding PSA_Mut_53Samps.skyd
22 Jan 2020 12:21:41,194 INFO : Expanding PSA_Mut_53Samps.sky.view
22 Jan 2020 12:21:41,195 INFO : Expanding PSA_Mut_53Samps.sky
22 Jan 2020 12:21:41,212 INFO : Expanding PSA_Mut_53Samps.skyl
22 Jan 2020 12:21:41,220 WARN : The version of this Skyline document is 19.1. This is newer than the highest supported version 4.1
22 Jan 2020 12:21:41,260 INFO : 4% Done
22 Jan 2020 12:21:42,534 INFO : Inserting Mut I179T
22 Jan 2020 12:21:42,682 INFO : 32% Done
22 Jan 2020 12:21:46,461 DEBUG: Total peptides inserted: 1
22 Jan 2020 12:21:46,462 INFO : Inserting WT
22 Jan 2020 12:21:46,535 INFO : 60% Done
22 Jan 2020 12:21:49,608 DEBUG: Total peptides inserted: 1
22 Jan 2020 12:21:49,609 INFO : Inserting Ctrl
22 Jan 2020 12:21:49,665 INFO : 80% Done
22 Jan 2020 12:21:51,945 INFO : 98% Done
22 Jan 2020 12:21:53,294 DEBUG: Total peptides inserted: 2
22 Jan 2020 12:21:53,295 INFO : Done parsing Skyline document.
22 Jan 2020 12:21:57,391 INFO : Completed import of Skyline document from PSA_Mut_53Samps.sky_BACKUPCOPY.zip
22 Jan 2020 12:21:57,393 INFO : 100% Done
22 Jan 2020 12:21:57,408 DEBUG: Finished trying to load data file file:///data/labkey/files/Panorama%20Public/2020/Eastern%20Virginia%20Med%20School%20-%20Otto%20et%20al%20%20Proteomics%20Clinical%20Applications/@files/export/xar/experiments_and_runs.xar.exploded/Run79427/PSA_Mut_53Samps.sky_BACKUPCOPY.zip into the system
22 Jan 2020 12:21:57,408 DEBUG: Trying to load data file file:///data/labkey/files/Panorama%20Public/2020/Eastern%20Virginia%20Med%20School%20-%20Otto%20et%20al%20%20Proteomics%20Clinical%20Applications/@files/export/xar/experiments_and_runs.xar.exploded/Run79427/PSA_Mut_53Samps.sky_BACKUPCOPY/PSA_Mut_53Samps.skyd into the system
22 Jan 2020 12:21:57,409 DEBUG: Finished trying to load data file file:///data/labkey/files/Panorama%20Public/2020/Eastern%20Virginia%20Med%20School%20-%20Otto%20et%20al%20%20Proteomics%20Clinical%20Applications/@files/export/xar/experiments_and_runs.xar.exploded/Run79427/PSA_Mut_53Samps.sky_BACKUPCOPY/PSA_Mut_53Samps.skyd into the system
22 Jan 2020 12:21:57,429 INFO : Done importing xar
22 Jan 2020 12:21:57,435 INFO : Loading pages and webpart properties
22 Jan 2020 12:21:57,681 INFO : Done importing pages and webpart properties
22 Jan 2020 12:21:57,682 INFO : 
22 Jan 2020 12:21:57,682 INFO : Experiment import completed successfully.
22 Jan 2020 12:21:57,682 INFO : Successfully completed task 'org.labkey.panoramapublic.pipeline.ExperimentImportTask'
22 Jan 2020 12:21:57,752 INFO : Starting to run task 'org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask' at location 'webserver-high-priority'
22 Jan 2020 12:21:57,752 INFO : 
22 Jan 2020 12:21:57,752 INFO : Finishing up experiment copy.
22 Jan 2020 12:21:57,755 INFO : Creating a new TargetedMS experiment entry in panoramapublic.ExperimentAnnotations.
22 Jan 2020 12:21:57,854 INFO : Updating access URL to point to the new copy of the data.
22 Jan 2020 12:21:57,882 INFO : Setting the 'copied' timestamp on the JournalExperiment table.
22 Jan 2020 12:21:57,884 INFO : Removing copy permissions given to journal.
22 Jan 2020 12:21:57,929 INFO : Adding read permissions to all users that are folder admins in the source container.
22 Jan 2020 12:21:57,966 INFO : Setting the TargetedMS folder type to 'Experimental Data'
22 Jan 2020 12:21:57,997 INFO : Updating the 'Raw Data' tab configuration
22 Jan 2020 12:21:58,008 INFO : Updating dataFileUrls for run PSA_Mut_53Samps.sky_BACKUPCOPY.zip; targetedms run ID 81460
22 Jan 2020 12:21:58,009 ERROR: Data path does not exist: /data/labkey/files/Panorama Public/2020/Eastern Virginia Med School - Otto et al  Proteomics Clinical Applications/@files/PSA_Mut_53Samps.sky_BACKUPCOPY/PSA_Mut_53Samps.sky_BACKUPCOPY.zip
22 Jan 2020 12:21:58,530 INFO : Failed to complete task 'org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask'
22 Jan 2020 12:21:58,532 ERROR: Unable to update all data file paths.
org.labkey.api.pipeline.PipelineJobException: Unable to update all data file paths.
	at org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask.run(CopyExperimentFinalTask.java:94)
	at org.labkey.api.pipeline.PipelineJob.runActiveTask(PipelineJob.java:795)
	at org.labkey.api.pipeline.PipelineJob.run(PipelineJob.java:1026)
	at org.labkey.pipeline.mule.PipelineJobRunner.run(PipelineJobRunner.java:40)
	at jdk.internal.reflect.GeneratedMethodAccessor1487.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:567)
	at org.mule.impl.model.resolvers.DynamicEntryPoint.invokeMethod(DynamicEntryPoint.java:312)
	at org.mule.impl.model.resolvers.DynamicEntryPoint.invoke(DynamicEntryPoint.java:259)
	at org.mule.impl.DefaultLifecycleAdapter.intercept(DefaultLifecycleAdapter.java:193)
	at org.mule.impl.InterceptorsInvoker.execute(InterceptorsInvoker.java:47)
	at org.mule.impl.model.DefaultMuleProxy.run(DefaultMuleProxy.java:470)
	at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
	at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$CallerRunsPolicy.rejectedExecution(ThreadPoolExecutor.java:1486)
	at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:391)
	at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:865)
	at org.mule.impl.work.ScheduleWorkExecutor.doExecute(ScheduleWorkExecutor.java:39)
	at org.mule.impl.work.MuleWorkManager.executeWork(MuleWorkManager.java:277)
	at org.mule.impl.work.MuleWorkManager.scheduleWork(MuleWorkManager.java:244)
	at org.mule.impl.model.seda.SedaComponent.run(SedaComponent.java:483)
	at org.mule.impl.work.WorkerContext.run(WorkerContext.java:310)
	at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
	at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
	at java.base/java.lang.Thread.run(Thread.java:835)
Caused by: org.labkey.api.pipeline.PipelineJobException: Unable to update all data file paths.
	at org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask.finishUp(CopyExperimentFinalTask.java:218)
	at org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask.run(CopyExperimentFinalTask.java:90)
	... 23 more
22 Jan 2020 14:54:41,939 INFO : Retrying job.
22 Jan 2020 14:54:41,945 DEBUG: Database indicates active task ID is org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask
22 Jan 2020 14:54:41,945 DEBUG: Retry details: Old Job ID: 901aba3d-1f7b-1038-aabe-3013bb9bf748
22 Jan 2020 14:54:41,988 INFO : Starting to run task 'org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask' at location 'webserver-high-priority'
22 Jan 2020 14:54:41,988 INFO : 
22 Jan 2020 14:54:41,988 INFO : Finishing up experiment copy.
22 Jan 2020 14:54:41,991 INFO : Creating a new TargetedMS experiment entry in panoramapublic.ExperimentAnnotations.
22 Jan 2020 14:54:42,013 INFO : Updating access URL to point to the new copy of the data.
22 Jan 2020 14:54:42,022 INFO : Setting the 'copied' timestamp on the JournalExperiment table.
22 Jan 2020 14:54:42,025 INFO : Removing copy permissions given to journal.
22 Jan 2020 14:54:42,110 INFO : Adding read permissions to all users that are folder admins in the source container.
22 Jan 2020 14:54:42,131 INFO : Setting the TargetedMS folder type to 'Experimental Data'
22 Jan 2020 14:54:42,162 INFO : Updating the 'Raw Data' tab configuration
22 Jan 2020 14:54:59,249 INFO : Successfully completed task 'org.labkey.panoramapublic.pipeline.CopyExperimentFinalTask'