search

archiver-appliance / epicsarchiverap

This is an implementation of an archiver for EPICS control systems that aims to archive millions of PVs.
Other
38 stars 38 forks source link

Exception when consuming and flushing data from N/A #78

Closed lotrus closed 5 years ago

lotrus commented 5 years ago

Hello, Our Archive Appliance is not able to read data that are on lts on one of our experiment. First, we have seen that retrieval servlet generates an exception when it is reading the files. Secondly, when we open one lts file, at one point (Januray 10), there are null values. So it seems in a way normal that we have an exception. We are able to read the sts and mts files. Archive Appliance is updating the lts file, but I didn't find error in the log. Is there a log file that I should specifically read?

The log of the first point are for example:

2019-03-28 08:26:34 58125790 [http-bio-17668-exec-7] INFO  org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Mime is qw
2019-03-28 08:26:34 58125790 [http-bio-17668-exec-7] INFO  org.epics.archiverappliance.retrieval.DataRetrievalServlet  - After parsing the function call syntax pvName is POS:PT-055 and postProcessorUserArg is lastSample_120
2019-03-28 08:26:34 58125794 [http-bio-17668-exec-7] INFO  org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Using org.epics.archiverappliance.retrieval.mimeresponses.QWResponse as the mime response sending application/json
2019-03-28 08:26:34 58125794 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Memory consumption estimate from postprocessor for pv POS:PT-055 is 925539(bytes) ~= 0,88(MB)
2019-03-28 08:26:34 58125936 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Done with the RetrievalResult's; moving onto the individual event stream from each source for POS:PT-055
2019-03-28 08:26:34 58125936 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source Last known event from LTS from 055:2018.pb
2019-03-28 08:26:34 58125936 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source Last known event from LTS from 055:2018.pb
2019-03-28 08:26:34 58125936 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Switching to new PV POS:PT-055 In some mime responses we insert special headers at the beginning of the response. Calling the hook for that
2019-03-28 08:26:34 58125936 [http-bio-17668-exec-7] ERROR org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Exception when consuming and flushing data from N/A-->java.util.concurrent.ExecutionException: java.lang.NullPointerException
java.util.concurrent.ExecutionException: java.lang.NullPointerException
    at java.util.concurrent.FutureTask.report(FutureTask.java:122)
    at java.util.concurrent.FutureTask.get(FutureTask.java:192)
    at org.epics.archiverappliance.retrieval.DataRetrievalServlet.doGetSinglePV(DataRetrievalServlet.java:447)
    at org.epics.archiverappliance.retrieval.DataRetrievalServlet.doGet(DataRetrievalServlet.java:142)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:624)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:218)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:962)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source /arch/mts/ArchiverStore/POS/PT/055:2019_03_25.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source /arch/mts/ArchiverStore/POS/PT/055:2019_03_25.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source /arch/mts/ArchiverStore/POS/PT/055:2019_03_26.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source /arch/mts/ArchiverStore/POS/PT/055:2019_03_26.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source /arch/mts/ArchiverStore/POS/PT/055:2019_03_27.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source /arch/mts/ArchiverStore/POS/PT/055:2019_03_27.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source /arch/mts/ArchiverStore/POS/PT/055:2019_03_28.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source /arch/mts/ArchiverStore/POS/PT/055:2019_03_28.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source /arch/sts/ArchiverStore/POS/PT/055:2019_03_28_06.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source /arch/sts/ArchiverStore/POS/PT/055:2019_03_28_06.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source /arch/sts/ArchiverStore/POS/PT/055:2019_03_28_07.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source /arch/sts/ArchiverStore/POS/PT/055:2019_03_28_07.pb
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Processing event stream for pv POS:PT-055 from source engine
2019-03-28 08:26:34 58125937 [http-bio-17668-exec-7] DEBUG org.epics.archiverappliance.retrieval.DataRetrievalServlet  - Merging typeinfo into remote desc for pv POS:PT-055 into source engine
2019-03-28 08:26:34 58125941 [http-bio-17668-exec-7] INFO  org.epics.archiverappliance.retrieval.DataRetrievalServlet  - For the complete request, found a total of 0 in 119(ms) skipping 0 events deduping involved 0 compares.

We are using Archiver Appliance Version 0.0.1_SNAPSHOT_09-October-2018T15-49-47 since Febrary 22th, before we were using 0.0.1_SNAPSHOT_20-September-2016T13-50-17.

Around January 22-25th, we have change the IOC of the variable POS:PT-055. The IOC before was running on CompactRIO machine, and now, the IOC is running on CentOS, so IP address has changed. Archive Appliance was not able to manage a different IP adress for the same PV. So I have pause the PV, delete the PV wihout deleting the data file. Then, I have re-declared the PV in Archive Appliance. Maybe that could be a reason of the problem?

It is possible to download POS:PT-055 PV files on website https://cernbox.cern.ch/index.php/s/nf5iwfVqkd42Otm.

slacmshankar commented 5 years ago

Thanks for uploading the files; was very useful.

055:2019.pb is corrupted. You can use the validate.sh script to check this. Using printtimes.sh; the last data I can get out of this file is 2019-01-10T09:32:15.375Z Jan/10/2019 01:32:15 -08:00 0.0010202959 0 0 2019-01-10T09:32:15.576Z Jan/10/2019 01:32:15 -08:00 0.0010458302 0 0 2019-01-10T09:32:15.775Z Jan/10/2019 01:32:15 -08:00 0.0021401776 0 0 2019-01-10T09:32:15.975Z Jan/10/2019 01:32:15 -08:00 0.0020707913 0 0

delete the PV wihout deleting the data file. Then, I have re-declared the PV in Archive Appliance

I suspect this is the root cause of the problem. 055\:2018.pb says that this PV is a DBR_SCALAR_FLOAT; while 055:2019_03_28.pb says that the PV is a DBR_SCALAR_DOUBLE. So I suspect that somehow, we added some DBR_SCALAR_DOUBLE at the end of a DBR_SCALAR_FLOAT pb file. If you had not deleted the PV; then we'd have checked for this and reported it. However; since you deleted the PV; all information of what it was before was lost.

Since the PV is now a DBR_SCALAR_DOUBLE, you'll need to convert all of your 2018 data as well. Hope that helps.

lotrus commented 5 years ago

Thanks a lot for taking the time to analyse the files, all that makes sense now.

lotrus commented 5 years ago

We have written a program in Java for changing data type DBR_SCALAR_FLOAT into DBR_SCALAR_DOUBLE. Thanks again for your help.