search

calvez / xcoaitoolkit

Automatically exported from code.google.com/p/xcoaitoolkit
0 stars 0 forks source link

Harvest timesout #82

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago 
the MST harvest timed out (180 seconds) 3 consecutive times on this request:
http://128.151.244.135:8080/OAIToolkit/oai-request.do?verb=ListRecords&resumptio
nToken=18%7C6576000

This means that the MST harvest did not complete.  Perhaps your upcoming change 
will fix this?  If you need to info from the log or the server - let me know.

relevant section from log

2011-05-04 13:17:12,652 [http-8080-3] (Facade.java:762) ERROR - [PRG] 
java.lang.NullPointerException
java.lang.NullPointerException
        at info.extensiblecatalog.OAIToolkit.oai.dataproviders.LuceneFacadeDataProvider.doc2SetToRecordDTO(LuceneFacadeDataProvider.java:385)
        at info.extensiblecatalog.OAIToolkit.oai.dataproviders.LuceneFacadeDataProvider.getSetsOfRecord(LuceneFacadeDataProvider.java:200)
        at info.extensiblecatalog.OAIToolkit.api.Facade.transformRecord(Facade.java:839)
        at info.extensiblecatalog.OAIToolkit.api.Facade.handleRecordLists(Facade.java:714)
        at info.extensiblecatalog.OAIToolkit.api.Facade.doCachedSearch(Facade.java:383)
        at info.extensiblecatalog.OAIToolkit.api.Facade.doListRecords(Facade.java:353)
        at info.extensiblecatalog.OAIToolkit.struts.action.OaiRequestAction.execute(OaiRequestAction.java:80)
        at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:419)
        at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:224)
        at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1194)
        at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:414)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
        at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
        at java.lang.Thread.run(Thread.java:619)
2011-05-04 13:17:12,653 [http-8080-3] (Facade.java:408) INFO  - [PRG] first 
phase: 23299, 0
2011-05-04 13:17:12,653 [http-8080-3] (OaiRequestAction.java:86) INFO  - [PRG] 
findForward
2011-05-04 13:17:30,553 [http-8080-3] (OaiRequestAction.java:56) INFO  - [PRG] 
verb = ListRecords
2011-05-04 13:17:30,553 [http-8080-3] (Facade.java:183) INFO  - [PRG] Lucene
2011-05-04 13:17:30,554 [http-8080-3] (Facade.java:558) INFO  - [PRG] registry 
consistency took: 0
2011-05-04 13:17:30,555 [http-8080-3] (Facade.java:375) INFO  - [PRG] Select 
strategy for 18_6571000: cacheId null: false, hasCache: false, registered: false
2011-05-04 13:17:30,555 [http-8080-3] (Facade.java:382) INFO  - [PRG] 
strategy->direct request
2011-05-04 13:17:30,555 [http-8080-3] (Facade.java:621) INFO  - [PRG] 
handleRecordLists: null, null, null, null, 18|6571000, ListRecords
2011-05-04 13:17:30,556 [http-8080-3] (PrototypeMgr.java:357) DEBUG - [PRG] 
selection SQL: com.mysql.jdbc.JDBC4PreparedStatement@1604a9e: SELECT * FROM 
resumption_tokens WHERE id = 18
2011-05-04 13:17:30,556 [http-8080-3] (PrototypeMgr.java:363) DEBUG - [PRG] 
number of rows: 1
2011-05-04 13:17:30,557 [http-8080-3] (LuceneFacadeDataProvider.java:271) INFO  
- [PRG] tokens.size: 1
2011-05-04 13:17:30,557 [http-8080-3] (Facade.java:656) INFO  - [PRG] 
recordLimit: 5000
2011-05-04 13:17:30,557 [http-8080-3] (Facade.java:665) INFO  - [PRG] 
maxLength: 100000000
2011-05-04 13:17:30,558 [http-8080-3] (PrototypeMgr.java:357) DEBUG - [PRG] 
selection SQL: com.mysql.jdbc.JDBC4PreparedStatement@c2cfe1: SELECT * FROM 
resumption_tokens WHERE id = 18
2011-05-04 13:17:30,559 [http-8080-3] (PrototypeMgr.java:363) DEBUG - [PRG] 
number of rows: 1
2011-05-04 13:17:30,560 [http-8080-3] (LuceneFacadeDataProvider.java:271) INFO  
- [PRG] tokens.size: 1
2011-05-04 13:17:50,061 [http-8080-3] (Facade.java:670) INFO  - [PRG] 
totalRecordNr: 6628684
2011-05-04 13:17:50,171 [http-8080-3] (Facade.java:696) INFO  - [PRG] while 
transformRecord
2011-05-04 13:17:57,095 [http-8080-3] (Facade.java:718) INFO  - [PRG] /while 
transformRecord. insertedRecords: 5000, readTime: 1675/1.0 (inside this: 
getIdTime: 7/1.0, getDocTime: 1395/1.0, doc2RecordTime: 246/1.0), 
transformTime: 5224/2.0 (inside this: xslTransformTime: 0/0.0, domBuildTime: 
1294/1.0)
2011-05-04 13:17:57,794 [http-8080-3] (Facade.java:408) INFO  - [PRG] first 
phase: 27240, 0
2011-05-04 13:17:57,795 [http-8080-3] (Facade.java:415) INFO  - [PRG] actual 
next resumption token: 18|6576000, second phase: 0
2011-05-04 13:17:57,795 [http-8080-3] (OaiRequestAction.java:84) INFO  - [PRG] 
Thread started
2011-05-04 13:17:57,796 [http-8080-3] (OaiRequestAction.java:86) INFO  - [PRG] 
findForward
2011-05-04 13:17:57,796 [Thread-54] (RecordCacher.java:41) INFO  - [PRG] 
18_6576000 cache registred? false
2011-05-04 13:17:57,796 [Thread-54] (RecordCacher.java:45) INFO  - [PRG] 
18_6576000 registered: true
2011-05-04 13:17:57,796 [Thread-54] (Facade.java:621) INFO  - [PRG] 
handleRecordLists: null, null, null, null, 18|6576000, ListRecords
2011-05-04 13:17:57,797 [Thread-54] (Facade.java:656) INFO  - [PRG] 
recordLimit: 5000
2011-05-04 13:17:57,797 [Thread-54] (Facade.java:665) INFO  - [PRG] maxLength: 
100000000
2011-05-04 13:17:57,798 [Thread-54] (PrototypeMgr.java:357) DEBUG - [PRG] 
selection SQL: com.mysql.jdbc.JDBC4PreparedStatement@780024: SELECT * FROM 
resumption_tokens WHERE id = 18
2011-05-04 13:17:57,799 [Thread-54] (PrototypeMgr.java:363) DEBUG - [PRG] 
number of rows: 1
2011-05-04 13:17:57,800 [Thread-54] (LuceneFacadeDataProvider.java:271) INFO  - 
[PRG] tokens.size: 1
2011-05-04 13:18:16,660 [Thread-54] (Facade.java:670) INFO  - [PRG] 
totalRecordNr: 6628684
2011-05-04 13:18:16,781 [Thread-54] (Facade.java:696) INFO  - [PRG] while 
transformRecord
2011-05-04 13:18:19,939 [Thread-54] (Facade.java:762) ERROR - [PRG] 
java.lang.NullPointerException
java.lang.NullPointerException
Exception in thread "Thread-54" java.lang.NullPointerException
        at java.io.Writer.write(Writer.java:140)
        at info.extensiblecatalog.OAIToolkit.utils.TextUtil.writeFile(TextUtil.java:226)
        at info.extensiblecatalog.OAIToolkit.api.Facade.setCache(Facade.java:468)
        at info.extensiblecatalog.OAIToolkit.api.Facade.createCache(Facade.java:436)
        at info.extensiblecatalog.OAIToolkit.oai.RecordCacher.run(RecordCacher.java:47)
        at java.lang.Thread.run(Thread.java:619)
2011-05-04 13:36:18,829 [http-8080-3] (OaiRequestAction.java:56) INFO  - [PRG] 
verb = ListRecords

Original issue reported on code.google.com by bander...@library.rochester.edu on 4 May 2011 at 5:54

GoogleCodeExporter commented 9 years ago 
same issue happened again last night at the same spot
(the exact offset number is slightly different because the first time I changed 
the oai-toolkit's records-per-request config after the first request had 
already been issued)

Perhaps there is some character in a record in this chunk that is causing the 
issue?

http://128.151.244.135:8080/OAIToolkit/oai-request.do?verb=ListRecords&resumptio
nToken=32%7C6575000

Original comment by bander...@library.rochester.edu on 5 May 2011 at 1:03

GoogleCodeExporter commented 9 years ago 
Version 1.0.0 handles resumptionTokens considerably different (and much more 
cleanly).  I am pretty certain upgrading to the latest version will solve this 
issue.

Original comment by cede...@uillinois.edu on 10 May 2011 at 9:15

GoogleCodeExporter commented 9 years ago 
Closing this.  If anyone reports a continuing problem, please open a new issue 
in Jira.

Original comment by rc...@library.rochester.edu on 26 Jun 2012 at 1:41