26 Mar 2023 19:49:17,762 DEBUG: Resetting Job ID: da318cc6-ae77-103b-a3e9-fea6ddf59764
26 Mar 2023 19:49:17,779 INFO : Starting to run task 'org.labkey.targetedms.pipeline.TargetedMSImportTask' at location 'webserver-high-priority'
26 Mar 2023 19:49:17,780 INFO : Starting to import Skyline document from final_sprg2019_all_charges_template2_Paul_WSU_12Mar2019_2023-03-26_22-49-05.sky.zip
26 Mar 2023 19:49:17,780 INFO : Expanding sprg2019_std_only_onefile.blib
26 Mar 2023 19:49:17,783 INFO : Expanding final_sprg2019_all_charges_template2_Paul_WSU_12Mar2019.skyd
26 Mar 2023 19:49:17,995 INFO : Expanding final_sprg2019_all_charges_template2_Paul_WSU_12Mar2019.sky.view
26 Mar 2023 19:49:17,996 INFO : Expanding final_sprg2019_all_charges_template2_Paul_WSU_12Mar2019.sky
26 Mar 2023 19:49:18,002 INFO : Expanding final_sprg2019_all_charges_template2_Paul_WSU_12Mar2019.skyl
26 Mar 2023 19:49:18,017 INFO : 2% Done
26 Mar 2023 19:49:18,017 WARN : Input iRT database does not exist sprg2019_irt_calculator.irtdb
26 Mar 2023 19:49:18,288 DEBUG: Starting to load chromatogram headers
26 Mar 2023 19:49:18,290 DEBUG: Done loading chromatogram headers
26 Mar 2023 19:49:18,465 INFO : Inserting Library Peptides
26 Mar 2023 19:49:18,486 INFO : 3% Done
26 Mar 2023 19:49:18,513 INFO : 4% Done
26 Mar 2023 19:49:18,540 INFO : 5% Done
26 Mar 2023 19:49:18,577 INFO : 6% Done
26 Mar 2023 19:49:18,607 INFO : 7% Done
26 Mar 2023 19:49:18,635 INFO : 8% Done
26 Mar 2023 19:49:18,680 INFO : 9% Done
26 Mar 2023 19:49:18,700 INFO : 10% Done
26 Mar 2023 19:49:18,733 INFO : 11% Done
26 Mar 2023 19:49:18,758 INFO : 12% Done
26 Mar 2023 19:49:18,790 INFO : 13% Done
26 Mar 2023 19:49:18,820 INFO : 14% Done
26 Mar 2023 19:49:18,837 INFO : 15% Done
26 Mar 2023 19:49:18,867 INFO : 16% Done
26 Mar 2023 19:49:18,903 INFO : 17% Done
26 Mar 2023 19:49:18,928 INFO : 18% Done
26 Mar 2023 19:49:18,972 INFO : 19% Done
26 Mar 2023 19:49:18,987 INFO : 20% Done
26 Mar 2023 19:49:19,015 INFO : 21% Done
26 Mar 2023 19:49:19,031 INFO : 22% Done
26 Mar 2023 19:49:19,072 INFO : 23% Done
26 Mar 2023 19:49:19,089 INFO : 24% Done
26 Mar 2023 19:49:19,118 INFO : 25% Done
26 Mar 2023 19:49:19,179 INFO : 26% Done
26 Mar 2023 19:49:19,204 INFO : 27% Done
26 Mar 2023 19:49:19,232 INFO : 28% Done
26 Mar 2023 19:49:19,261 INFO : 29% Done
26 Mar 2023 19:49:19,292 INFO : 30% Done
26 Mar 2023 19:49:19,324 INFO : 31% Done
26 Mar 2023 19:49:19,351 INFO : 32% Done
26 Mar 2023 19:49:19,380 INFO : 34% Done
26 Mar 2023 19:49:19,438 INFO : 36% Done
26 Mar 2023 19:49:19,465 DEBUG: Inserted 50 peptides
26 Mar 2023 19:49:19,490 INFO : 38% Done
26 Mar 2023 19:49:19,531 INFO : 39% Done
26 Mar 2023 19:49:19,584 INFO : 41% Done
26 Mar 2023 19:49:19,629 INFO : 42% Done
26 Mar 2023 19:49:19,650 INFO : 43% Done
26 Mar 2023 19:49:19,679 INFO : 44% Done
26 Mar 2023 19:49:19,717 INFO : 45% Done
26 Mar 2023 19:49:19,743 INFO : 46% Done
26 Mar 2023 19:49:19,766 INFO : 47% Done
26 Mar 2023 19:49:19,777 INFO : 48% Done
26 Mar 2023 19:49:19,808 INFO : 49% Done
26 Mar 2023 19:49:19,862 INFO : 51% Done
26 Mar 2023 19:49:19,921 INFO : 53% Done
26 Mar 2023 19:49:19,949 INFO : 54% Done
26 Mar 2023 19:49:20,007 INFO : 56% Done
26 Mar 2023 19:49:20,050 INFO : 57% Done
26 Mar 2023 19:49:20,085 INFO : 58% Done
26 Mar 2023 19:49:20,102 INFO : 59% Done
26 Mar 2023 19:49:20,133 INFO : 60% Done
26 Mar 2023 19:49:20,164 INFO : 61% Done
26 Mar 2023 19:49:20,190 INFO : 62% Done
26 Mar 2023 19:49:20,232 INFO : 63% Done
26 Mar 2023 19:49:20,252 INFO : 64% Done
26 Mar 2023 19:49:20,299 INFO : 65% Done
26 Mar 2023 19:49:20,318 INFO : 66% Done
26 Mar 2023 19:49:20,365 INFO : 67% Done
26 Mar 2023 19:49:20,416 INFO : 68% Done
26 Mar 2023 19:49:20,461 INFO : 69% Done
26 Mar 2023 19:49:20,484 INFO : 70% Done
26 Mar 2023 19:49:20,524 INFO : 71% Done
26 Mar 2023 19:49:20,559 INFO : 72% Done
26 Mar 2023 19:49:20,603 INFO : 73% Done
26 Mar 2023 19:49:20,653 INFO : 74% Done
26 Mar 2023 19:49:20,699 INFO : 75% Done
26 Mar 2023 19:49:20,699 DEBUG: Inserted 100 peptides
26 Mar 2023 19:49:20,751 INFO : 77% Done
26 Mar 2023 19:49:20,792 INFO : 78% Done
26 Mar 2023 19:49:20,822 INFO : 79% Done
26 Mar 2023 19:49:20,854 INFO : 80% Done
26 Mar 2023 19:49:20,905 INFO : 81% Done
26 Mar 2023 19:49:20,941 INFO : 82% Done
26 Mar 2023 19:49:20,981 INFO : 84% Done
26 Mar 2023 19:49:21,017 INFO : 85% Done
26 Mar 2023 19:49:21,065 INFO : 87% Done
26 Mar 2023 19:49:21,134 INFO : 89% Done
26 Mar 2023 19:49:21,198 INFO : 90% Done
26 Mar 2023 19:49:21,215 INFO : 91% Done
26 Mar 2023 19:49:21,244 INFO : 92% Done
26 Mar 2023 19:49:21,290 INFO : 93% Done
26 Mar 2023 19:49:21,303 INFO : 94% Done
26 Mar 2023 19:49:21,344 INFO : 95% Done
26 Mar 2023 19:49:21,373 INFO : 96% Done
26 Mar 2023 19:49:21,399 INFO : 97% Done
26 Mar 2023 19:49:21,415 INFO : 98% Done
26 Mar 2023 19:49:21,457 DEBUG: Total peptides inserted: 130
26 Mar 2023 19:49:21,458 INFO : Done parsing Skyline document.
26 Mar 2023 19:49:21,680 ERROR: Import failed
org.labkey.targetedms.parser.skyaudit.AuditLogException: Error when parsing audit log file.
at org.labkey.targetedms.parser.skyaudit.SkylineAuditLogParser.<init>(SkylineAuditLogParser.java:108)
at org.labkey.targetedms.SkylineAuditLogManager.importAuditLogFile(SkylineAuditLogManager.java:106)
at org.labkey.targetedms.SkylineDocImporter.importSkylineDoc(SkylineDocImporter.java:470)
at org.labkey.targetedms.SkylineDocImporter.importRun(SkylineDocImporter.java:248)
at org.labkey.targetedms.pipeline.TargetedMSImportTask.run(TargetedMSImportTask.java:63)
at org.labkey.api.pipeline.PipelineJob.runActiveTask(PipelineJob.java:833)
at org.labkey.api.pipeline.PipelineJob.run(PipelineJob.java:1074)
at org.labkey.pipeline.mule.PipelineJobRunner.run(PipelineJobRunner.java:40)
at jdk.internal.reflect.GeneratedMethodAccessor1748.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
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:833)
Caused by: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 17; cvc-complex-type.4: Attribute 'format_version' must appear on element 'audit_log_root'.
at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source)
at org.apache.xerces.util.ErrorHandlerWrapper.error(Unknown Source)
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator$XSIErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.reportSchemaError(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.addDefaultAttributes(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.handleStartElement(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.startElement(Unknown Source)
at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
at org.apache.xerces.impl.XMLNSDocumentScannerImpl$NSContentDispatcher.scanRootElementHook(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
at org.apache.xerces.jaxp.validation.StreamValidatorHelper.validate(Unknown Source)
at org.apache.xerces.jaxp.validation.ValidatorImpl.validate(Unknown Source)
at java.xml/javax.xml.validation.Validator.validate(Validator.java:124)
at org.labkey.targetedms.parser.skyaudit.SkylineAuditLogParser.validateXml(SkylineAuditLogParser.java:122)
at org.labkey.targetedms.parser.skyaudit.SkylineAuditLogParser.<init>(SkylineAuditLogParser.java:104)
... 27 more
26 Mar 2023 19:49:21,704 INFO : Failed to complete task 'org.labkey.targetedms.pipeline.TargetedMSImportTask'
26 Mar 2023 19:49:21,705 ERROR: Error when parsing audit log file.
org.labkey.api.pipeline.PipelineJobException: Error when parsing audit log file.
at org.labkey.targetedms.SkylineDocImporter.importRun(SkylineDocImporter.java:275)
at org.labkey.targetedms.pipeline.TargetedMSImportTask.run(TargetedMSImportTask.java:63)
at org.labkey.api.pipeline.PipelineJob.runActiveTask(PipelineJob.java:833)
at org.labkey.api.pipeline.PipelineJob.run(PipelineJob.java:1074)
at org.labkey.pipeline.mule.PipelineJobRunner.run(PipelineJobRunner.java:40)
at jdk.internal.reflect.GeneratedMethodAccessor1748.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
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:833)
Caused by: org.labkey.targetedms.parser.skyaudit.AuditLogException: Error when parsing audit log file.
at org.labkey.targetedms.parser.skyaudit.SkylineAuditLogParser.<init>(SkylineAuditLogParser.java:108)
at org.labkey.targetedms.SkylineAuditLogManager.importAuditLogFile(SkylineAuditLogManager.java:106)
at org.labkey.targetedms.SkylineDocImporter.importSkylineDoc(SkylineDocImporter.java:470)
at org.labkey.targetedms.SkylineDocImporter.importRun(SkylineDocImporter.java:248)
... 24 more
Caused by: org.xml.sax.SAXParseException; lineNumber: 2; columnNumber: 17; cvc-complex-type.4: Attribute 'format_version' must appear on element 'audit_log_root'.
at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source)
at org.apache.xerces.util.ErrorHandlerWrapper.error(Unknown Source)
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator$XSIErrorReporter.reportError(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.reportSchemaError(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.addDefaultAttributes(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.handleStartElement(Unknown Source)
at org.apache.xerces.impl.xs.XMLSchemaValidator.startElement(Unknown Source)
at org.apache.xerces.impl.XMLNSDocumentScannerImpl.scanStartElement(Unknown Source)
at org.apache.xerces.impl.XMLNSDocumentScannerImpl$NSContentDispatcher.scanRootElementHook(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl$FragmentContentDispatcher.dispatch(Unknown Source)
at org.apache.xerces.impl.XMLDocumentFragmentScannerImpl.scanDocument(Unknown Source)
at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
at org.apache.xerces.jaxp.validation.StreamValidatorHelper.validate(Unknown Source)
at org.apache.xerces.jaxp.validation.ValidatorImpl.validate(Unknown Source)
at java.xml/javax.xml.validation.Validator.validate(Validator.java:124)
at org.labkey.targetedms.parser.skyaudit.SkylineAuditLogParser.validateXml(SkylineAuditLogParser.java:122)
at org.labkey.targetedms.parser.skyaudit.SkylineAuditLogParser.<init>(SkylineAuditLogParser.java:104)
... 27 more