26 Mar 2019 06:18:13,661 INFO : Copying experiment "Homeostatic and Interferon-induced gene expression represent different states of promoter-associated transcription factor ISGF3" from folder /MFPL - MS Facility/Decker Lab - STAT1, STAT2, IRF9 BioIDs to /Panorama Public/2019/Decker Lab - STAT1, STAT2, IRF9 BioIDs
26 Mar 2019 06:18:13,662 INFO : =======================================
26 Mar 2019 06:18:13,967 INFO : Starting to run task 'org.labkey.targetedms.pipeline.ExperimentExportTask' at location 'webserver'
26 Mar 2019 06:18:13,968 INFO : 
26 Mar 2019 06:18:13,969 INFO : Exporting experiment.
26 Mar 2019 06:23:19,179 INFO : 
26 Mar 2019 06:23:19,187 INFO : Experiment export completed successfully.
26 Mar 2019 06:23:19,187 INFO : Successfully completed task 'org.labkey.targetedms.pipeline.ExperimentExportTask'
26 Mar 2019 06:23:19,281 INFO : Starting to run task 'org.labkey.targetedms.pipeline.ExperimentImportTask' at location 'webserver'
26 Mar 2019 06:23:19,281 INFO : 
26 Mar 2019 06:23:19,282 INFO : Importing experiment.
26 Mar 2019 06:23:19,476 INFO : Loading folder properties (folder type, settings and active modules)
26 Mar 2019 06:23:19,830 INFO : Done importing folder properties (folder type, settings and active modules)
26 Mar 2019 06:23:19,848 INFO : Loading container specific module properties
26 Mar 2019 06:23:19,910 INFO : Done importing container specific module properties
26 Mar 2019 06:23:19,997 INFO : Loading xar
26 Mar 2019 06:23:24,160 DEBUG: Finished loading Protocol with LSID 'urn:lsid:uw.edu:Protocol.Folder-5156:TargetedMS.ImportSkyZip'
26 Mar 2019 06:23:24,172 DEBUG: Finished loading Protocol with LSID 'urn:lsid:uw.edu:Protocol.Folder-5156:TargetedMS.ImportSkyZip.Core'
26 Mar 2019 06:23:24,183 DEBUG: Finished loading Protocol with LSID 'urn:lsid:uw.edu:Protocol.Folder-5156:TargetedMS.ImportSkyZip.Output'
26 Mar 2019 06:23:24,184 DEBUG: Protocol import complete
26 Mar 2019 06:23:24,247 DEBUG: Finished loading Experiment with LSID 'urn:lsid:uw.edu:Experiment.Folder-5156:Homeostatic+and+Interferon-induced+gene+expression+represent+different+states+of+promoter-associated+transcription+factor+ISGF3'
26 Mar 2019 06:23:24,247 DEBUG: Experiment/Run group import complete
26 Mar 2019 06:23:24,424 DEBUG: Protocol action set import complete
26 Mar 2019 06:23:24,600 DEBUG: Finished loading ProtocolApplication with LSID 'urn:lsid:uw.edu:Protocol.Folder-5156:TargetedMS.ImportSkyZip'
26 Mar 2019 06:23:24,966 DEBUG: Finished loading Data with LSID 'urn:lsid:uw.edu:skyd.Folder-5156:7e887b2d-2b8e-1037-a6dd-3013bb9b5a14'
26 Mar 2019 06:23:25,004 DEBUG: Finished loading Data with LSID 'urn:lsid:uw.edu:UploadedFile.Folder-5156:7e887b13-2b8e-1037-a6dd-3013bb9b5a14'
26 Mar 2019 06:23:25,004 DEBUG: Finished loading ProtocolApplication with LSID 'urn:lsid:uw.edu:Protocol.Folder-5156:TargetedMS.ImportSkyZip.Core'
26 Mar 2019 06:23:25,038 DEBUG: Finished loading ProtocolApplication with LSID 'urn:lsid:uw.edu:Protocol.Folder-5156:TargetedMS.ImportSkyZip.Output'
26 Mar 2019 06:23:25,040 DEBUG: Finished loading ExperimentRun with LSID 'urn:lsid:uw.edu:Run.Folder-5156:7e887c00-2b8e-1037-a6dd-3013bb9b5a14'
26 Mar 2019 06:23:25,046 DEBUG: Trying to load data file file:///data/labkey/files/Panorama%20Public/2019/Decker%20Lab%20-%20STAT1,%20STAT2,%20IRF9%20BioIDs/@files/export/xar/experiments_and_runs.xar.exploded/Run59454/PRM_final_quantification_non-normalized.skyd into the system
26 Mar 2019 06:23:25,049 DEBUG: Finished trying to load data file file:///data/labkey/files/Panorama%20Public/2019/Decker%20Lab%20-%20STAT1,%20STAT2,%20IRF9%20BioIDs/@files/export/xar/experiments_and_runs.xar.exploded/Run59454/PRM_final_quantification_non-normalized.skyd into the system
26 Mar 2019 06:23:25,049 DEBUG: Trying to load data file file:///data/labkey/files/Panorama%20Public/2019/Decker%20Lab%20-%20STAT1,%20STAT2,%20IRF9%20BioIDs/@files/export/xar/experiments_and_runs.xar.exploded/Run59454/PRM_final_quantification_non-normalized_2019-03-18_10-30-44.sky.zip into the system
26 Mar 2019 06:23:25,071 INFO : Starting import from PRM_final_quantification_non-normalized_2019-03-18_10-30-44.sky.zip
26 Mar 2019 06:23:25,102 INFO : Starting to import Skyline document from PRM_final_quantification_non-normalized_2019-03-18_10-30-44.sky.zip
26 Mar 2019 06:23:25,104 INFO : Expanding iRT-C18.irtdb
26 Mar 2019 06:23:25,105 INFO : Expanding PRM_PD_Amanda_Percolator.blib
26 Mar 2019 06:23:25,120 INFO : Expanding PRM_PD_Amanda_Percolator.redundant.blib
26 Mar 2019 06:23:26,263 INFO : Expanding PRM_final_quantification_non-normalized.skyd
26 Mar 2019 06:23:27,828 INFO : Expanding PRM_final_quantification_non-normalized.sky.view
26 Mar 2019 06:23:27,828 INFO : Expanding PRM_final_quantification_non-normalized.sky
26 Mar 2019 06:23:27,845 WARN : The version of this Skyline document is 4.21. This is newer than the highest supported version 4.1
26 Mar 2019 06:23:29,762 INFO : Inserting STAT1
26 Mar 2019 06:23:31,862 INFO : Total peptides inserted: 5
26 Mar 2019 06:23:31,966 INFO : Inserting STAT2
26 Mar 2019 06:23:33,975 INFO : Total peptides inserted: 5
26 Mar 2019 06:23:34,067 INFO : Inserting STAT3
26 Mar 2019 06:23:36,893 INFO : Total peptides inserted: 5
26 Mar 2019 06:23:36,964 INFO : Inserting IRF9
26 Mar 2019 06:23:39,122 INFO : Total peptides inserted: 5
26 Mar 2019 06:23:39,123 INFO : Inserting PRTC Standard
26 Mar 2019 06:23:49,892 INFO : Total peptides inserted: 15
26 Mar 2019 06:24:16,725 INFO : Completed import of Skyline document from PRM_final_quantification_non-normalized_2019-03-18_10-30-44.sky.zip
26 Mar 2019 06:24:16,732 DEBUG: Finished trying to load data file file:///data/labkey/files/Panorama%20Public/2019/Decker%20Lab%20-%20STAT1,%20STAT2,%20IRF9%20BioIDs/@files/export/xar/experiments_and_runs.xar.exploded/Run59454/PRM_final_quantification_non-normalized_2019-03-18_10-30-44.sky.zip into the system
26 Mar 2019 06:24:16,971 INFO : Done importing xar
26 Mar 2019 06:24:16,978 INFO : Loading wikis
26 Mar 2019 06:24:17,020 INFO : 0 wikis imported
26 Mar 2019 06:24:17,020 INFO : Done importing wikis
26 Mar 2019 06:29:19,032 INFO : Loading pages and webpart properties
26 Mar 2019 06:29:19,186 INFO : Done importing pages and webpart properties
26 Mar 2019 06:29:19,187 INFO : 
26 Mar 2019 06:29:19,187 INFO : Experiment import completed successfully.
26 Mar 2019 06:29:19,188 INFO : Successfully completed task 'org.labkey.targetedms.pipeline.ExperimentImportTask'
26 Mar 2019 06:29:19,277 INFO : Starting to run task 'org.labkey.targetedms.pipeline.CopyExperimentFinalTask' at location 'webserver'
26 Mar 2019 06:29:19,278 INFO : 
26 Mar 2019 06:29:19,278 INFO : Finishing up experiment copy.
26 Mar 2019 06:29:19,284 INFO : Creating a new TargetedMS experiment entry in targetedms.ExperimentAnnotations.
26 Mar 2019 06:29:19,347 INFO : Updating access URL to point to the new copy of the data.
26 Mar 2019 06:29:19,496 ERROR: Data path does not exist: /data/labkey/files/Panorama Public/2019/Decker Lab - STAT1, STAT2, IRF9 BioIDs/@files/Run59454/PRM_final_quantification_non-normalized.skyd
26 Mar 2019 06:29:23,092 INFO : Failed to complete task 'org.labkey.targetedms.pipeline.CopyExperimentFinalTask'
26 Mar 2019 06:29:23,117 ERROR: Unable to update all data file paths.
org.labkey.api.pipeline.PipelineJobException: Unable to update all data file paths.
	at org.labkey.targetedms.pipeline.CopyExperimentFinalTask.run(CopyExperimentFinalTask.java:94)
	at org.labkey.api.pipeline.PipelineJob.runActiveTask(PipelineJob.java:805)
	at org.labkey.api.pipeline.PipelineJob.run(PipelineJob.java:1036)
	at org.labkey.pipeline.mule.PipelineJobRunner.run(PipelineJobRunner.java:34)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	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.lang.Thread.run(Thread.java:748)
Caused by: org.labkey.api.pipeline.PipelineJobException: Unable to update all data file paths.
	at org.labkey.targetedms.pipeline.CopyExperimentFinalTask.finishUp(CopyExperimentFinalTask.java:208)
	at org.labkey.targetedms.pipeline.CopyExperimentFinalTask.run(CopyExperimentFinalTask.java:90)
	... 24 more
26 Mar 2019 08:06:04,528 INFO : Retrying job.
26 Mar 2019 08:06:04,528 DEBUG: Database indicates active task ID is org.labkey.targetedms.pipeline.CopyExperimentFinalTask
26 Mar 2019 08:06:04,529 DEBUG: Retry details: Old Job ID: 8f9ec5d0-31f6-1037-a72b-3013bb9b836c
26 Mar 2019 08:06:04,557 INFO : Starting to run task 'org.labkey.targetedms.pipeline.CopyExperimentFinalTask' at location 'webserver'
26 Mar 2019 08:06:04,558 INFO : 
26 Mar 2019 08:06:04,558 INFO : Finishing up experiment copy.
26 Mar 2019 08:06:04,560 INFO : Creating a new TargetedMS experiment entry in targetedms.ExperimentAnnotations.
26 Mar 2019 08:06:04,611 INFO : Updating access URL to point to the new copy of the data.
26 Mar 2019 08:06:07,648 INFO : Successfully completed task 'org.labkey.targetedms.pipeline.CopyExperimentFinalTask'