Loading...

XML

Word

Printable

JSON

Type: Task
Resolution: Fixed
Priority: Normal
Fix Version/s: 1.0.2
Affects Version/s: None
Component/s: WBS 3.x VA
Labels:
None

When I try to ingest a test SIP, it is creating the high level directory in SDA but failing to upload the files that are part of the zip. Tomcat output is shown below:

-------------------
"http-bio-8080"]
Feb 14, 2014 4:58:17 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Feb 14, 2014 4:58:17 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 21755 ms
⭠ master± ⮀ ~/Documents/git_seadva/SEAD-VA-extensions/utils/initDB ⮀
» sudo tail -100 /usr/local/apache-tomcat-7.0.42/logs/catalina.out
16:58:46.347 [pool-22-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
16:58:46.347 [pool-22-thread-2] DEBUG org.hibernate.jdbc.ConnectionManager - opening JDBC connection
16:58:46.347 [pool-22-thread-1] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: true
16:58:46.347 [pool-22-thread-2] DEBUG o.h.transaction.JDBCTransaction - current autocommit status: true
16:58:46.347 [pool-22-thread-1] DEBUG o.h.transaction.JDBCTransaction - disabling autocommit
16:58:46.347 [pool-22-thread-2] DEBUG o.h.transaction.JDBCTransaction - disabling autocommit
16:58:46.348 [pool-22-thread-1] DEBUG o.s.o.h.HibernateTransactionManager - Exposing Hibernate transaction as JDBC transaction [jdbc:h2:file:/tmp/identifiers/id, UserName=, H2 JDBC Driver]
16:58:46.348 [pool-22-thread-2] DEBUG o.s.o.h.HibernateTransactionManager - Exposing Hibernate transaction as JDBC transaction [jdbc:h2:file:/tmp/identifiers/id, UserName=, H2 JDBC Driver]
16:58:46.348 [pool-22-thread-1] DEBUG o.h.e.def.AbstractSaveEventListener - executing identity-insert immediately
16:58:46.348 [pool-22-thread-2] DEBUG o.h.e.def.AbstractSaveEventListener - executing identity-insert immediately
16:58:46.348 [pool-22-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
16:58:46.348 [pool-22-thread-2] DEBUG org.hibernate.jdbc.AbstractBatcher - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
16:58:46.348 [pool-22-thread-1] DEBUG org.hibernate.SQL - insert into TypeInfo (id, type) values (null, ?)
16:58:46.348 [pool-22-thread-2] DEBUG org.hibernate.SQL - insert into TypeInfo (id, type) values (null, ?)
16:58:46.348 [pool-22-thread-1] DEBUG o.h.id.IdentifierGeneratorFactory - Natively generated identity: 4069
16:58:46.348 [pool-22-thread-1] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 2)
16:58:46.349 [pool-22-thread-1] DEBUG o.s.o.h.HibernateTransactionManager - Initiating transaction commit
16:58:46.349 [pool-22-thread-1] DEBUG o.s.o.h.HibernateTransactionManager - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@57eb150a]
16:58:46.349 [pool-22-thread-1] DEBUG o.h.transaction.JDBCTransaction - commit
16:58:46.349 [pool-22-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
16:58:46.349 [pool-22-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
16:58:46.349 [pool-22-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
16:58:46.349 [pool-22-thread-1] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
16:58:46.349 [pool-22-thread-1] DEBUG org.hibernate.pretty.Printer - listing entities:
16:58:46.349 [pool-22-thread-1] DEBUG org.hibernate.pretty.Printer - org.dataconservancy.dcs.id.impl.hibernate.TypeInfo

{id=4069, type=sip}

16:58:46.349 [pool-22-thread-1] DEBUG o.h.transaction.JDBCTransaction - re-enabling autocommit
16:58:46.349 [pool-22-thread-1] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
16:58:46.349 [pool-22-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
16:58:46.349 [pool-22-thread-2] DEBUG o.h.id.IdentifierGeneratorFactory - Natively generated identity: 4070
16:58:46.349 [pool-22-thread-2] DEBUG org.hibernate.jdbc.AbstractBatcher - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
16:58:46.349 [pool-22-thread-1] DEBUG o.s.o.h.HibernateTransactionManager - Closing Hibernate Session [org.hibernate.impl.SessionImpl@57eb150a] after transaction
16:58:46.349 [pool-22-thread-1] DEBUG o.s.o.hibernate3.SessionFactoryUtils - Closing Hibernate Session
16:58:46.349 [pool-22-thread-2] DEBUG o.s.o.h.HibernateTransactionManager - Initiating transaction commit
16:58:46.350 [pool-22-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
16:58:46.350 [pool-22-thread-2] DEBUG o.s.o.h.HibernateTransactionManager - Committing Hibernate transaction on Session [org.hibernate.impl.SessionImpl@5d23c733]
16:58:46.350 [pool-22-thread-2] DEBUG o.h.transaction.JDBCTransaction - commit
16:58:46.350 [pool-22-thread-1] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
16:58:46.350 [pool-22-thread-2] DEBUG o.h.e.d.AbstractFlushingEventListener - processing flush-time cascades
16:58:46.350 [pool-22-thread-2] DEBUG o.h.e.d.AbstractFlushingEventListener - dirty checking collections
16:58:46.350 [pool-22-thread-2] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
16:58:46.350 [pool-22-thread-2] DEBUG o.h.e.d.AbstractFlushingEventListener - Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
16:58:46.350 [pool-22-thread-2] DEBUG org.hibernate.pretty.Printer - listing entities:
16:58:46.350 [pool-22-thread-2] DEBUG org.hibernate.pretty.Printer - org.dataconservancy.dcs.id.impl.hibernate.TypeInfo

{id=4070, type=sip}

16:58:46.350 [pool-22-thread-2] DEBUG o.h.transaction.JDBCTransaction - re-enabling autocommit
16:58:46.350 [pool-22-thread-2] DEBUG o.h.transaction.JDBCTransaction - committed JDBC Connection
16:58:46.350 [pool-22-thread-2] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
16:58:46.350 [pool-22-thread-2] DEBUG o.s.o.h.HibernateTransactionManager - Closing Hibernate Session [org.hibernate.impl.SessionImpl@5d23c733] after transaction
16:58:46.350 [pool-22-thread-2] DEBUG o.s.o.hibernate3.SessionFactoryUtils - Closing Hibernate Session
16:58:46.351 [pool-22-thread-2] DEBUG org.hibernate.jdbc.ConnectionManager - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
16:58:46.351 [pool-22-thread-2] DEBUG org.hibernate.jdbc.ConnectionManager - transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
16:58:46.354 [pool-22-thread-2] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 4063: Service org.dataconservancy.dcs.ingest.services.ExternalContentStager execution: 63 ms
16:58:46.354 [pool-22-thread-2] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 4063: Executing service StagedContentResolver
16:58:46.357 [pool-22-thread-1] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 3057: Service org.dataconservancy.dcs.ingest.services.ExternalContentStager execution: 57 ms
16:58:46.357 [pool-22-thread-1] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 3057: Executing service StagedContentResolver
16:58:46.357 [pool-22-thread-2] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 4063: Service org.dataconservancy.dcs.ingest.services.StagedContentResolver execution: 3 ms
16:58:46.357 [pool-22-thread-2] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 4063: Executing service SeadArchiver
16:58:46.359 [pool-22-thread-1] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 3057: Service org.dataconservancy.dcs.ingest.services.StagedContentResolver execution: 2 ms
16:58:46.360 [pool-22-thread-1] DEBUG o.d.d.i.s.runners.ExecutorBootstrap - Ingest 3057: Executing service SeadArchiver
com.jcraft.jsch.JSchException: connection is closed by foreign host
at com.jcraft.jsch.Session.connect(Session.java:248)
at com.jcraft.jsch.Session.connect(Session.java:162)
at org.seadva.archive.impl.cloud.Sftp.<init>(Sftp.java:46)
at org.seadva.archive.impl.cloud.SdaArchiveStore.putResearchPackage(SdaArchiveStore.java:172)
at org.dataconservancy.dcs.ingest.services.SeadArchiver.execute(SeadArchiver.java:96)
at org.dataconservancy.dcs.ingest.services.TimedServiceWrapper.execute(TimedServiceWrapper.java:36)
at org.dataconservancy.dcs.ingest.services.runners.ExecutorBootstrap$IngestRunner.run(ExecutorBootstrap.java:117)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
com.jcraft.jsch.JSchException: connection is closed by foreign host
at com.jcraft.jsch.Session.connect(Session.java:248)
at com.jcraft.jsch.Session.connect(Session.java:162)
at org.seadva.archive.impl.cloud.Sftp.<init>(Sftp.java:46)
at org.seadva.archive.impl.cloud.SdaArchiveStore.putResearchPackage(SdaArchiveStore.java:172)
at org.dataconservancy.dcs.ingest.services.SeadArchiver.execute(SeadArchiver.java:96)
at org.dataconservancy.dcs.ingest.services.TimedServiceWrapper.execute(TimedServiceWrapper.java:36)
at org.dataconservancy.dcs.ingest.services.runners.ExecutorBootstrap$IngestRunner.run(ExecutorBootstrap.java:117)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
--------------sead ---------{DcsEvent{eventType='deposit', eventDate='2014-02-14T21:58:45.873Z', eventDetail='4063', eventOutcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4065'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='deposit', date='2014-02-14T21:58:45.873Z', detail='4063', outcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4065'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3063'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='ingest.start', eventDate='2014-02-14T21:58:45.873Z', eventDetail='Ingest 4063 started', eventOutcome='4063', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/3063'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4065'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='ingest.start', date='2014-02-14T21:58:45.873Z', detail='Ingest 4063 started', outcome='4063', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/3063'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4065'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3064'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='identifier.assignment', eventDate='2014-02-14T21:58:45.877Z', eventDetail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4064' to DeliverableUnit 'xyz'', eventOutcome='xyz to http://localhost:8080/sead-wf/entity/4064', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='identifier.assignment', date='2014-02-14T21:58:45.877Z', detail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4064' to DeliverableUnit 'xyz'', outcome='xyz to http://localhost:8080/sead-wf/entity/4064', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3065'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='identifier.assignment', eventDate='2014-02-14T21:58:45.879Z', eventDetail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4065' to Manifestation 'man'', eventOutcome='man to http://localhost:8080/sead-wf/entity/4065', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4065'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='identifier.assignment', date='2014-02-14T21:58:45.879Z', detail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4065' to Manifestation 'man'', outcome='man to http://localhost:8080/sead-wf/entity/4065', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4065'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3066'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='identifier.assignment', eventDate='2014-02-14T21:58:45.883Z', eventDetail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4068' to File 'fileid'', eventOutcome='fileid to http://localhost:8080/sead-wf/entity/4068', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='identifier.assignment', date='2014-02-14T21:58:45.883Z', detail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4068' to File 'fileid'', outcome='fileid to http://localhost:8080/sead-wf/entity/4068', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3067'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='matchmaking', eventDate='2014-02-14T21:58:46.290Z', eventDetail='Matched Repository IU SDA for the given dataset collection.', eventOutcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='matchmaking', date='2014-02-14T21:58:46.290Z', detail='Matched Repository IU SDA for the given dataset collection.', outcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4064'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3068'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='fixity.digest', eventDate='2014-02-14T21:58:46.331Z', eventDetail='Calculated SHA-1 upon content retrieval', eventOutcome='SHA-1 a1d604ca3de5c1123e136e875e1be96589b171dc', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='fixity.digest', date='2014-02-14T21:58:46.331Z', detail='Calculated SHA-1 upon content retrieval', outcome='SHA-1 a1d604ca3de5c1123e136e875e1be96589b171dc', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3070'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='fixity.digest', eventDate='2014-02-14T21:58:46.334Z', eventDetail='Calculated MD5 upon content retrieval', eventOutcome='MD5 76ede8aecc00dc3af3151fef4478184c', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='fixity.digest', date='2014-02-14T21:58:46.334Z', detail='Calculated MD5 upon content retrieval', outcome='MD5 76ede8aecc00dc3af3151fef4478184c', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3072'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='file.resolution', eventDate='2014-02-14T21:58:46.356Z', eventDetail='Resolved staged content, and changed src from urn:dataconservancy.org:file/4070 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', eventOutcome='urn:dataconservancy.org:file/4070 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='file.resolution', date='2014-02-14T21:58:46.356Z', detail='Resolved staged content, and changed src from urn:dataconservancy.org:file/4070 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', outcome='urn:dataconservancy.org:file/4070 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3074'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='file.download', eventDate='2014-02-14T21:58:46.353Z', eventDetail='Retrieved file content from http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml, changed src to urn:dataconservancy.org:file/4070', eventOutcome='http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml to urn:dataconservancy.org:file/4070', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='file.download', date='2014-02-14T21:58:46.353Z', detail='Retrieved file content from http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml, changed src to urn:dataconservancy.org:file/4070', outcome='http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml to urn:dataconservancy.org:file/4070', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4068'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3073'alternateIds=}

}}16:58:46.467 [pool-22-thread-2] INFO o.d.d.i.s.runners.ExecutorBootstrap - failed ingest: 4063
java.lang.NullPointerException: null
at org.seadva.archive.impl.cloud.SdaArchiveStore.putResearchPackage(SdaArchiveStore.java:226) ~[sead-archive-impl-sda-1.1.0-SNAPSHOT.jar:na]
at org.dataconservancy.dcs.ingest.services.SeadArchiver.execute(SeadArchiver.java:96) ~[sead-ingest-services-1.1.0-SNAPSHOT.jar:na]
at org.dataconservancy.dcs.ingest.services.TimedServiceWrapper.execute(TimedServiceWrapper.java:36) ~[dcs-ingest-services-1.1.1-SNAPSHOT.jar:na]
at org.dataconservancy.dcs.ingest.services.runners.ExecutorBootstrap$IngestRunner.run(ExecutorBootstrap.java:117) ~[dcs-ingest-services-1.1.1-SNAPSHOT.jar:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_45]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_45]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_45]
16:58:46.467 [pool-22-thread-2] INFO o.d.d.i.s.runners.ExecutorBootstrap - Total ingest (4063) execution: 594 ms
--------------sead ---------{DcsEvent{eventType='deposit', eventDate='2014-02-14T21:58:45.613Z', eventDetail='3057', eventOutcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4059'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='deposit', date='2014-02-14T21:58:45.613Z', detail='3057', outcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4059'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3058'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='ingest.start', eventDate='2014-02-14T21:58:45.640Z', eventDetail='Ingest 3057 started', eventOutcome='3057', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4059'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/3058'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='ingest.start', date='2014-02-14T21:58:45.640Z', detail='Ingest 3057 started', outcome='3057', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4059'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/3058'}

, org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3059'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='identifier.assignment', eventDate='2014-02-14T21:58:45.651Z', eventDetail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4058' to DeliverableUnit 'xyz'', eventOutcome='xyz to http://localhost:8080/sead-wf/entity/4058', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='identifier.assignment', date='2014-02-14T21:58:45.651Z', detail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4058' to DeliverableUnit 'xyz'', outcome='xyz to http://localhost:8080/sead-wf/entity/4058', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3060'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='identifier.assignment', eventDate='2014-02-14T21:58:45.653Z', eventDetail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4059' to Manifestation 'man'', eventOutcome='man to http://localhost:8080/sead-wf/entity/4059', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4059'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='identifier.assignment', date='2014-02-14T21:58:45.653Z', detail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4059' to Manifestation 'man'', outcome='man to http://localhost:8080/sead-wf/entity/4059', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4059'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3061'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='identifier.assignment', eventDate='2014-02-14T21:58:45.657Z', eventDetail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4062' to File 'fileid'', eventOutcome='fileid to http://localhost:8080/sead-wf/entity/4062', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='identifier.assignment', date='2014-02-14T21:58:45.657Z', detail='Assigned identifier 'http://localhost:8080/sead-wf/entity/4062' to File 'fileid'', outcome='fileid to http://localhost:8080/sead-wf/entity/4062', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3062'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='matchmaking', eventDate='2014-02-14T21:58:46.299Z', eventDetail='Matched Repository IU SDA for the given dataset collection.', eventOutcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='matchmaking', date='2014-02-14T21:58:46.299Z', detail='Matched Repository IU SDA for the given dataset collection.', outcome='null', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4058'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3069'alternateIds=}

{ref='http://localhost:8080/sead-wf/entity/4062'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3070'alternateIds=}

{ref='http://localhost:8080/sead-wf/entity/4062'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='fixity.digest', date='2014-02-14T21:58:46.334Z', detail='Calculated MD5 upon content retrieval', outcome='MD5 76ede8aecc00dc3af3151fef4478184c', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3071'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='file.resolution', eventDate='2014-02-14T21:58:46.359Z', eventDetail='Resolved staged content, and changed src from urn:dataconservancy.org:file/4069 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', eventOutcome='urn:dataconservancy.org:file/4069 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='file.resolution', date='2014-02-14T21:58:46.359Z', detail='Resolved staged content, and changed src from urn:dataconservancy.org:file/4069 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', outcome='urn:dataconservancy.org:file/4069 to file:///tmp/files/a1/d6/a1d604ca3de5c1123e136e875e1be96589b171dc', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3076'alternateIds=}

}}--------------sead ---------{DcsEvent{eventType='file.download', eventDate='2014-02-14T21:58:46.357Z', eventDetail='Retrieved file content from http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml, changed src to urn:dataconservancy.org:file/4069', eventOutcome='http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml to urn:dataconservancy.org:file/4069', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

], logDetail=SeadLogDetail{ipAddress='null', userAgent='null', subject='null', nodeIdentifier=null}}{DcsEvent{type='file.download', date='2014-02-14T21:58:46.357Z', detail='Retrieved file content from http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml, changed src to urn:dataconservancy.org:file/4069', outcome='http://ashbha.ads.iu.edu/leadinabox/cape.metadata.xml to urn:dataconservancy.org:file/4069', targets=[org.dataconservancy.model.dcs.DcsEntityReference

{ref='http://localhost:8080/sead-wf/entity/4062'}

]}DcsEntity

{id='http://localhost:8080/sead-wf/entity/3075'alternateIds=}

}}16:58:46.478 [pool-22-thread-1] INFO o.d.d.i.s.runners.ExecutorBootstrap - failed ingest: 3057
java.lang.NullPointerException: null
at org.seadva.archive.impl.cloud.SdaArchiveStore.putResearchPackage(SdaArchiveStore.java:226) ~[sead-archive-impl-sda-1.1.0-SNAPSHOT.jar:na]
at org.dataconservancy.dcs.ingest.services.SeadArchiver.execute(SeadArchiver.java:96) ~[sead-ingest-services-1.1.0-SNAPSHOT.jar:na]
at org.dataconservancy.dcs.ingest.services.TimedServiceWrapper.execute(TimedServiceWrapper.java:36) ~[dcs-ingest-services-1.1.1-SNAPSHOT.jar:na]
at org.dataconservancy.dcs.ingest.services.runners.ExecutorBootstrap$IngestRunner.run(ExecutorBootstrap.java:117) ~[dcs-ingest-services-1.1.1-SNAPSHOT.jar:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_45]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_45]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_45]
16:58:46.479 [pool-22-thread-1] INFO o.d.d.i.s.runners.ExecutorBootstrap - Total ingest (3057) execution: 839 ms

Assignee:: Kavitha Chandrasekar

Reporter:: Aravindh Varadharaju

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Created:: 14/Feb/14 4:03 PM

Updated:: 30/Mar/16 10:10 AM

Resolved:: 09/Mar/14 1:52 PM

Details

Description

Gliffy Diagrams

Attachments

Activity

People

Dates

Tasks