Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

netcdf error #34

Closed
forjin-vpac-innovations opened this issue Nov 11, 2014 · 23 comments
Closed

netcdf error #34

forjin-vpac-innovations opened this issue Nov 11, 2014 · 23 comments

Comments

@forjin-vpac-innovations

Hi all,

I am trying to import LGA and SA3 data to landblade, but during the processing there are some errors invoked.

Here is the message coming out from lb-importer.

root@b460899fd02b:/var/src/src/importer/src# ./lcmimporter.py --temp-dir ~/tempgdal -d /data -tr 100 --log info -rsa http://scweb:8080/spatialcubeservice/
INFO:lcmimporter:About to begin import process
INFO:lcmimporter:Created dataset boundaries with ID: 2c9180b3499cb7ed01499cbf059f0001
INFO:lcmimporter:found LGA shape file input
INFO:lcmimporter:reading features from LGA shape file
0...10...20...30...40...50...60...70...80...90...100 - done.
INFO:lcmimporter:Importing lga dataset into RSA
INFO:lcmimporter:Successful: importing LGA to RSA
INFO:lcmimporter:Building WMTS tiles for lga dataset in RSA
ERROR:lcmimporter:Failed: generating WMTS tiles in RSA
INFO:lcmimporter:found SA shape file input
INFO:lcmimporter:reading features from SA shape file
0...10...20...30...40...50...60...70...80...90...100 - done.
INFO:lcmimporter:Importing SA 3 dataset into RSA
INFO:lcmimporter:Successful: importing SA3 to RSA
INFO:lcmimporter:Building WMTS tiles for SA 3 dataset in RSA
ERROR:lcmimporter:Failed: generating WMTS tiles in RSA
ERROR:lcmimporter:Could not generate stats for boundaries
ERROR:lcmimporter:Could not generate stats for boundaries
root@b460899fd02b:/var/src/src/importer/src# exit

But the actual error is coming out from SpatialCubeService.

ERROR o.v.n.s.ActivityLogger - Invalid arguments detected during afterCreateDataset intercepting method.
WARN  o.v.n.s.u.BandUtil - Re-creating blank tile for band Band(LGA) in dataset Dataset(boundaries/100m)
ERROR o.v.n.t.Application - Exception during execution of task pipeline:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:151) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - TaskException:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:151) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - Task exited abnormally: Unable to extract statistics from gdalinfo output
ERROR o.v.n.s.ActivityLogger - Invalid arguments detected during afterCreateDataset intercepting method.
WARN  o.v.n.s.u.BandUtil - Re-creating blank tile for band Band(SA3) in dataset Dataset(boundaries/100m)
ERROR o.v.n.t.Application - Exception during execution of task pipeline:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:151) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - TaskException:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:151) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - Task exited abnormally: Unable to extract statistics from gdalinfo output
ERROR o.v.w.c.DatasetController - Failed to close output file
java.lang.NullPointerException: null
    at ucar.nc2.jni.netcdf.Nc4Iosp.flush(Nc4Iosp.java:2307) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.flush(NetcdfFileWriter.java:843) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.close(NetcdfFileWriter.java:852) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at org.vpac.web.controller.DatasetController.createCategories(DatasetController.java:212) ~[DatasetController.class:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
    at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
    at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) [servlet-api-2.5.jar:na]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:723) [servlet-api-2.5.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote-6.0.39.jar:6.0.39]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.w.c.DatasetController - Failed to close output file
java.lang.NullPointerException: null
    at ucar.nc2.jni.netcdf.Nc4Iosp.flush(Nc4Iosp.java:2307) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.flush(NetcdfFileWriter.java:843) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.close(NetcdfFileWriter.java:852) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at org.vpac.web.controller.DatasetController.createCategories(DatasetController.java:212) ~[DatasetController.class:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
    at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
    at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) [servlet-api-2.5.jar:na]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:723) [servlet-api-2.5.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote-6.0.39.jar:6.0.39]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
@z0u
Copy link

z0u commented Nov 11, 2014

If you turn on info level logging, you should see the command that is being run. Then you can run that from the command line and see why it's failing.

@forjin-vpac-innovations
Copy link
Author

Could you please let me know which file need to be changed?

@forjin-vpac-innovations
Copy link
Author

I found it and turn it on as info

It shows like this.

SEVERE: The web application [/spatialcubeservice] created a ThreadLocal with key of type [scala.util.DynamicVariable$$anon$1] (value [scala.util.DynamicVariable$$anon$1@6094f5d8]) and a value of type [org.apache.tomcat.util.log.SystemLogHandler] (value [org.apache.tomcat.util.log.SystemLogHandler@53986971]) but failed to remove it when the web application was stopped. This is very likely to create a memory leak.
Exception in thread "Timer-6" org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'transactionManager' defined in class path resource [spring/database/Hibernate.xml]: Cannot resolve reference to bean 'sessionFactory' while setting bean property 'sessionFactory'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sessionFactory' defined in class path resource [spring/database/Hibernate.xml]: Invocation of init method failed; nested exception is java.lang.NullPointerException
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:328)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:106)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1360)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1118)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:517)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.determineTransactionManager(TransactionAspectSupport.java:248)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:100)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
    at com.sun.proxy.$Proxy18.update(Unknown Source)
    at org.vpac.ndg.lock.ProcessUpdateTimer$1.run(ProcessUpdateTimer.java:104)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sessionFactory' defined in class path resource [spring/database/Hibernate.xml]: Invocation of init method failed; nested exception is java.lang.NullPointerException
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1455)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:519)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
    at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:322)
    ... 17 more
Caused by: java.lang.NullPointerException
    at com.mchange.v2.log.FallbackMLog$FallbackMLogger.isLoggable(FallbackMLog.java:328)
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getPoolManager(AbstractPoolBackedDataSource.java:509)
    at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
    at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.getConnection(LocalDataSourceConnectionProvider.java:81)
    at org.hibernate.cfg.SettingsFactory.buildSettings(SettingsFactory.java:114)
    at org.hibernate.cfg.Configuration.buildSettingsInternal(Configuration.java:2163)
    at org.hibernate.cfg.Configuration.buildSettings(Configuration.java:2159)
    at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1383)
    at org.hibernate.cfg.AnnotationConfiguration.buildSessionFactory(AnnotationConfiguration.java:954)
    at org.springframework.orm.hibernate3.LocalSessionFactoryBean.newSessionFactory(LocalSessionFactoryBean.java:860)
    at org.springframework.orm.hibernate3.LocalSessionFactoryBean.buildSessionFactory(LocalSessionFactoryBean.java:779)
    at org.springframework.orm.hibernate3.AbstractSessionFactoryBean.afterPropertiesSet(AbstractSessionFactoryBean.java:188)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1514)
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1452)
    ... 24 more
Nov 11, 2014 3:31:51 AM org.apache.coyote.http11.Http11Protocol destroy
INFO: Stopping Coyote HTTP/1.1 on http-8080
Exception in thread "C3P0PooledConnectionPoolManager[identityToken->1bqq1ir9517hez221akzm1v|4806c06c]-AdminTaskTimer" java.lang.NullPointerException
    at com.mchange.v2.log.FallbackMLog$FallbackMLogger.isLoggable(FallbackMLog.java:328)
    at com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector.run(ThreadPoolAsynchronousRunner.java:717)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)

@forjin-vpac-innovations
Copy link
Author

I think this error is real one.

INFO  o.v.n.t.Application - Temporary directory: /var/tmp/ndg/tmpDir4051426845089640959
INFO  o.v.n.t.Importer - Initialising import 2c9180b3499d402401499d4185d80007
INFO  o.v.n.t.Importer - Dataset: Dataset(boundaries/100m)
INFO  o.v.n.t.Importer - Timeslice: TS(2014-01-01 00:00:00.0)
INFO  o.v.n.t.TaskPipeline - Start of task initialisation.
ERROR o.v.n.s.ActivityLogger - Invalid arguments detected during afterCreateDataset intercepting method.
INFO  o.v.n.l.ProcessUpdateTimer - Heartbeat: 2014-11-11 05:09:18.637625
INFO  o.v.n.t.Application - Task starting: 2c9180b3499d402401499d4186240008
INFO  o.v.n.t.TaskPipeline - START OF TASK EXECUTION
INFO  o.v.n.t.TaskPipeline - -->Start of task initialisation.
INFO  o.v.n.t.TaskPipeline - -->START OF TASK EXECUTION
Exception in thread "Timer-0" java.lang.IllegalMonitorStateException: Time slice 2c9180b3499cb7ed01499cbf065d0003 still not locked even after acquiring lock.
    at org.vpac.ndg.lock.ProcessCleanupTimer$1.run(ProcessCleanupTimer.java:89)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
WARN  o.v.n.CommandUtil - ERROR 2: Out of memory allocating 100000000 byte destination buffer.
ERROR o.v.n.t.Application - Exception during execution of task pipeline:
org.vpac.ndg.exceptions.TaskException: TASK [Make Tile LGA_tile_x6_y6.nc] failed.
DETAILS: org.vpac.ndg.rasterservices.ProcessException: Command exited with error code 1
    at org.vpac.ndg.task.Transformer.execute(Transformer.java:207) ~[Transformer.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.TileTransformer.execute(TileTransformer.java:132) ~[TileTransformer.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
INFO  o.v.n.l.ProcessUpdateTimer - Deleting own process.
ERROR o.v.n.l.TimeSliceDbReadWriteLock - Error when stopping ProcessUpdateTimer: {}
java.lang.NullPointerException: null
    at org.vpac.ndg.storage.util.TimeSliceUtil.cleanOne(TimeSliceUtil.java:294) ~[TimeSliceUtil.class:na]
    at org.vpac.ndg.storage.util.TimeSliceUtil.clean(TimeSliceUtil.java:284) ~[TimeSliceUtil.class:na]
    at org.vpac.ndg.storage.util.TimeSliceUtil$$FastClassByCGLIB$$7283ae13.invoke(<generated>) ~[cglib-2.2.jar:na]
    at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191) ~[cglib-2.2.jar:na]
    at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.vpac.ndg.storage.util.TimeSliceUtil$$EnhancerByCGLIB$$25448e31.clean(<generated>) ~[cglib-2.2.jar:na]
    at org.vpac.ndg.lock.ProcessUpdateTimer.shutdown(ProcessUpdateTimer.java:129) ~[ProcessUpdateTimer.class:na]
    at org.vpac.ndg.lock.ProcessUpdateTimer.release(ProcessUpdateTimer.java:81) ~[ProcessUpdateTimer.class:na]
    at org.vpac.ndg.lock.TimeSliceDbReadWriteLock$WriteLock.releaseProcesses(TimeSliceDbReadWriteLock.java:300) [TimeSliceDbReadWriteLock$WriteLock.class:na]
    at org.vpac.ndg.lock.TimeSliceDbReadWriteLock$WriteLock.unlock(TimeSliceDbReadWriteLock.java:286) [TimeSliceDbReadWriteLock$WriteLock.class:na]
    at org.vpac.ndg.task.Importer.postExecute(Importer.java:359) [Importer.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:141) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
INFO  o.v.n.t.Application - Task failed: 2c9180b3499d402401499d4186240008
ERROR o.v.n.t.Application - TaskException:
org.vpac.ndg.exceptions.TaskException: TASK [Make Tile LGA_tile_x6_y6.nc] failed.
DETAILS: org.vpac.ndg.rasterservices.ProcessException: Command exited with error code 1
    at org.vpac.ndg.task.Transformer.execute(Transformer.java:207) ~[Transformer.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.TileTransformer.execute(TileTransformer.java:132) ~[TileTransformer.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
INFO  o.v.n.t.TaskPipeline - ROLLBACK
INFO  o.v.n.t.TaskPipeline - -->ROLLBACK
INFO  o.v.n.t.TaskPipeline - -->ROLLBACK
INFO  o.v.n.t.TaskPipeline - START OF TASK FINALISE
INFO  o.v.n.t.TaskPipeline - -->START OF TASK FINALISE
INFO  o.v.n.t.TaskPipeline - -->END OF TASK
INFO  o.v.n.t.TaskPipeline - -->START OF TASK FINALISE
INFO  o.v.n.t.TaskPipeline - -->END OF TASK
INFO  o.v.n.t.TaskPipeline - END OF TASK
ERROR o.v.n.t.Application - Task exited abnormally: TASK [Make Tile LGA_tile_x6_y6.nc] failed.
DETAILS: org.vpac.ndg.rasterservices.ProcessException: Command exited with error code 1

@forjin-vpac-innovations
Copy link
Author

I hope this one is really one.

INFO: Server startup in 15560 ms
ERROR o.v.n.s.ActivityLogger - Invalid arguments detected during afterCreateDataset intercepting method.
Exception in thread "Timer-0" java.lang.IllegalMonitorStateException: Time slice 2c9180b3499cb7ed01499cbf065d0003 still not locked even after acquiring lock.
    at org.vpac.ndg.lock.ProcessCleanupTimer$1.run(ProcessCleanupTimer.java:89)
    at java.util.TimerThread.mainLoop(Timer.java:555)
    at java.util.TimerThread.run(Timer.java:505)
ERROR o.v.n.l.TimeSliceDbReadWriteLock - Error when stopping ProcessUpdateTimer: {}
java.lang.NullPointerException: null
    at org.vpac.ndg.storage.util.TimeSliceUtil.cleanOne(TimeSliceUtil.java:294) ~[TimeSliceUtil.class:na]
    at org.vpac.ndg.storage.util.TimeSliceUtil.clean(TimeSliceUtil.java:284) ~[TimeSliceUtil.class:na]
    at org.vpac.ndg.storage.util.TimeSliceUtil$$FastClassByCGLIB$$7283ae13.invoke(<generated>) ~[cglib-2.2.jar:na]
    at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191) ~[cglib-2.2.jar:na]
    at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.vpac.ndg.storage.util.TimeSliceUtil$$EnhancerByCGLIB$$478707e4.clean(<generated>) ~[cglib-2.2.jar:na]
    at org.vpac.ndg.lock.ProcessUpdateTimer.shutdown(ProcessUpdateTimer.java:129) ~[ProcessUpdateTimer.class:na]
    at org.vpac.ndg.lock.ProcessUpdateTimer.release(ProcessUpdateTimer.java:81) ~[ProcessUpdateTimer.class:na]
    at org.vpac.ndg.lock.TimeSliceDbReadWriteLock$WriteLock.releaseProcesses(TimeSliceDbReadWriteLock.java:300) [TimeSliceDbReadWriteLock$WriteLock.class:na]
    at org.vpac.ndg.lock.TimeSliceDbReadWriteLock$WriteLock.unlock(TimeSliceDbReadWriteLock.java:286) [TimeSliceDbReadWriteLock$WriteLock.class:na]
    at org.vpac.ndg.task.Importer.postExecute(Importer.java:359) [Importer.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:141) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - Exception during execution of task pipeline:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:151) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - TaskException:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:151) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.v.n.t.Application - Task exited abnormally: Unable to extract statistics from gdalinfo output

@forjin-vpac-innovations
Copy link
Author

This is gdalinfo for one of the files in the timeslice.

root@0727d3007d2d:/var/lib/ndg/storagepool/boundaries_m100/2014-01-01T00-00-00.000# gdalinfo ./LGA_tile_x6_y5.nc
Driver: netCDF/Network Common Data Format
Files: ./LGA_tile_x6_y5.nc
Size is 5000, 5000
Coordinate System is:
PROJCS["GDA94 / Australian Albers",
    GEOGCS["GDA94",
        DATUM["Geocentric_Datum_of_Australia_1994",
            SPHEROID["GRS 1980",6378137,298.257222101,
                AUTHORITY["EPSG","7019"]],
            TOWGS84[0,0,0,0,0,0,0],
            AUTHORITY["EPSG","6283"]],
        PRIMEM["Greenwich",0,
            AUTHORITY["EPSG","8901"]],
        UNIT["degree",0.0174532925199433,
            AUTHORITY["EPSG","9122"]],
        AUTHORITY["EPSG","4283"]],
    PROJECTION["Albers_Conic_Equal_Area"],
    PARAMETER["standard_parallel_1",-18],
    PARAMETER["standard_parallel_2",-36],
    PARAMETER["latitude_of_center",0],
    PARAMETER["longitude_of_center",132],
    PARAMETER["false_easting",0],
    PARAMETER["false_northing",0],
    UNIT["metre",1,
        AUTHORITY["EPSG","9001"]],
    AXIS["Easting",EAST],
    AXIS["Northing",NORTH],
    AUTHORITY["EPSG","3577"]]
Origin = (310000.000000000000000,-3500000.000000000000000)
Pixel Size = (100.000000000000000,-100.000000000000000)
Metadata:
  albers_conical_equal_area#false_easting=0
  albers_conical_equal_area#false_northing=0
  albers_conical_equal_area#GeoTransform=310000 100 0 -3500000 0 -100 
  albers_conical_equal_area#grid_mapping_name=albers_conical_equal_area
  albers_conical_equal_area#inverse_flattening=298.257222101
  albers_conical_equal_area#latitude_of_projection_origin=0
  albers_conical_equal_area#longitude_of_central_meridian=132
  albers_conical_equal_area#longitude_of_prime_meridian=0
  albers_conical_equal_area#semi_major_axis=6378137
  albers_conical_equal_area#spatial_ref=PROJCS["GDA94 / Australian Albers",GEOGCS["GDA94",DATUM["Geocentric_Datum_of_Australia_1994",SPHEROID["GRS 1980",6378137,298.257222101,AUTHORITY["EPSG","7019"]],TOWGS84[0,0,0,0,0,0,0],AUTHORITY["EPSG","6283"]],PRIMEM["Greenwich",0,AUTHORITY["EPSG","8901"]],UNIT["degree",0.0174532925199433,AUTHORITY["EPSG","9122"]],AUTHORITY["EPSG","4283"]],PROJECTION["Albers_Conic_Equal_Area"],PARAMETER["standard_parallel_1",-18],PARAMETER["standard_parallel_2",-36],PARAMETER["latitude_of_center",0],PARAMETER["longitude_of_center",132],PARAMETER["false_easting",0],PARAMETER["false_northing",0],UNIT["metre",1,AUTHORITY["EPSG","9001"]],AXIS["Easting",EAST],AXIS["Northing",NORTH],AUTHORITY["EPSG","3577"]]
  albers_conical_equal_area#standard_parallel={-18,-36}
  Band1#_FillValue=0
  Band1#grid_mapping=albers_conical_equal_area
  Band1#long_name=GDAL Band Number 1
  NC_GLOBAL#Conventions=CF-1.5
  NC_GLOBAL#GDAL=GDAL 1.10.1, released 2013/08/26
  NC_GLOBAL#history=Tue Nov 11 05:29:37 2014: GDAL Create( /var/tmp/ndg/tmpDir6424378802362491040/LGA_tile_x6_y5.nc, ... )
  x#long_name=x coordinate of projection
  x#standard_name=projection_x_coordinate
  x#units=m
  y#long_name=y coordinate of projection
  y#standard_name=projection_y_coordinate
  y#units=m
Corner Coordinates:
Upper Left  (  310000.000,-3500000.000) (135d18'46.17"E, 32d 4'38.30"S)
Lower Left  (  310000.000,-4000000.000) (135d27'26.62"E, 36d33'51.93"S)
Upper Right (  810000.000,-3500000.000) (140d38'41.33"E, 31d52' 5.51"S)
Lower Right (  810000.000,-4000000.000) (141d 1'15.66"E, 36d20'38.76"S)
Center      (  560000.000,-3750000.000) (138d 6'32.46"E, 34d13'55.40"S)
Band 1 Block=5000x1 Type=Int32, ColorInterp=Undefined
  NoData Value=0
  Metadata:
    _FillValue=0
    grid_mapping=albers_conical_equal_area
    long_name=GDAL Band Number 1
    NETCDF_VARNAME=Band1

@forjin-vpac-innovations
Copy link
Author

--stats

oot@0727d3007d2d:/var/lib/ndg/storagepool/boundaries_m100/2014-01-01T00-00-00.000# gdalinfo -stats ./LGA_tile_x6_y5.nc 
Driver: netCDF/Network Common Data Format
Files: ./LGA_tile_x6_y5.nc
Size is 5000, 5000
Coordinate System is:
PROJCS["GDA94 / Australian Albers",
    GEOGCS["GDA94",
        DATUM["Geocentric_Datum_of_Australia_1994",
            SPHEROID["GRS 1980",6378137,298.257222101,
                AUTHORITY["EPSG","7019"]],
            TOWGS84[0,0,0,0,0,0,0],
            AUTHORITY["EPSG","6283"]],
        PRIMEM["Greenwich",0,
            AUTHORITY["EPSG","8901"]],
        UNIT["degree",0.0174532925199433,
            AUTHORITY["EPSG","9122"]],
        AUTHORITY["EPSG","4283"]],
    PROJECTION["Albers_Conic_Equal_Area"],
    PARAMETER["standard_parallel_1",-18],
    PARAMETER["standard_parallel_2",-36],
    PARAMETER["latitude_of_center",0],
    PARAMETER["longitude_of_center",132],
    PARAMETER["false_easting",0],
    PARAMETER["false_northing",0],
    UNIT["metre",1,
        AUTHORITY["EPSG","9001"]],
    AXIS["Easting",EAST],
    AXIS["Northing",NORTH],
    AUTHORITY["EPSG","3577"]]
Origin = (310000.000000000000000,-3500000.000000000000000)
Pixel Size = (100.000000000000000,-100.000000000000000)
Metadata:
  albers_conical_equal_area#false_easting=0
  albers_conical_equal_area#false_northing=0
  albers_conical_equal_area#GeoTransform=310000 100 0 -3500000 0 -100 
  albers_conical_equal_area#grid_mapping_name=albers_conical_equal_area
  albers_conical_equal_area#inverse_flattening=298.257222101
  albers_conical_equal_area#latitude_of_projection_origin=0
  albers_conical_equal_area#longitude_of_central_meridian=132
  albers_conical_equal_area#longitude_of_prime_meridian=0
  albers_conical_equal_area#semi_major_axis=6378137
  albers_conical_equal_area#spatial_ref=PROJCS["GDA94 / Australian Albers",GEOGCS["GDA94",DATUM["Geocentric_Datum_of_Australia_1994",SPHEROID["GRS 1980",6378137,298.257222101,AUTHORITY["EPSG","7019"]],TOWGS84[0,0,0,0,0,0,0],AUTHORITY["EPSG","6283"]],PRIMEM["Greenwich",0,AUTHORITY["EPSG","8901"]],UNIT["degree",0.0174532925199433,AUTHORITY["EPSG","9122"]],AUTHORITY["EPSG","4283"]],PROJECTION["Albers_Conic_Equal_Area"],PARAMETER["standard_parallel_1",-18],PARAMETER["standard_parallel_2",-36],PARAMETER["latitude_of_center",0],PARAMETER["longitude_of_center",132],PARAMETER["false_easting",0],PARAMETER["false_northing",0],UNIT["metre",1,AUTHORITY["EPSG","9001"]],AXIS["Easting",EAST],AXIS["Northing",NORTH],AUTHORITY["EPSG","3577"]]
  albers_conical_equal_area#standard_parallel={-18,-36}
  Band1#_FillValue=0
  Band1#grid_mapping=albers_conical_equal_area
  Band1#long_name=GDAL Band Number 1
  NC_GLOBAL#Conventions=CF-1.5
  NC_GLOBAL#GDAL=GDAL 1.10.1, released 2013/08/26
  NC_GLOBAL#history=Tue Nov 11 05:29:37 2014: GDAL Create( /var/tmp/ndg/tmpDir6424378802362491040/LGA_tile_x6_y5.nc, ... )
  x#long_name=x coordinate of projection
  x#standard_name=projection_x_coordinate
  x#units=m
  y#long_name=y coordinate of projection
  y#standard_name=projection_y_coordinate
  y#units=m
Corner Coordinates:
Upper Left  (  310000.000,-3500000.000) (135d18'46.17"E, 32d 4'38.30"S)
Lower Left  (  310000.000,-4000000.000) (135d27'26.62"E, 36d33'51.93"S)
Upper Right (  810000.000,-3500000.000) (140d38'41.33"E, 31d52' 5.51"S)
Lower Right (  810000.000,-4000000.000) (141d 1'15.66"E, 36d20'38.76"S)
Center      (  560000.000,-3750000.000) (138d 6'32.46"E, 34d13'55.40"S)
Band 1 Block=5000x1 Type=Int32, ColorInterp=Undefined
  Minimum=345.000, Maximum=371.000, Mean=370.706, StdDev=2.751
  NoData Value=0
  Metadata:
    _FillValue=0
    grid_mapping=albers_conical_equal_area
    long_name=GDAL Band Number 1
    NETCDF_VARNAME=Band1
    STATISTICS_MAXIMUM=371
    STATISTICS_MEAN=370.70557491289
    STATISTICS_MINIMUM=345
    STATISTICS_STDDEV=2.751066362869

@forjin-vpac-innovations
Copy link
Author

--noct

root@0727d3007d2d:/var/lib/ndg/storagepool/boundaries_m100/2014-01-01T00-00-00.000# gdalinfo -noct ./LGA_tile_x6_y5.nc 
Driver: netCDF/Network Common Data Format
Files: ./LGA_tile_x6_y5.nc
       ./LGA_tile_x6_y5.nc.aux.xml
Size is 5000, 5000
Coordinate System is:
PROJCS["GDA94 / Australian Albers",
    GEOGCS["GDA94",
        DATUM["Geocentric_Datum_of_Australia_1994",
            SPHEROID["GRS 1980",6378137,298.257222101,
                AUTHORITY["EPSG","7019"]],
            TOWGS84[0,0,0,0,0,0,0],
            AUTHORITY["EPSG","6283"]],
        PRIMEM["Greenwich",0,
            AUTHORITY["EPSG","8901"]],
        UNIT["degree",0.0174532925199433,
            AUTHORITY["EPSG","9122"]],
        AUTHORITY["EPSG","4283"]],
    PROJECTION["Albers_Conic_Equal_Area"],
    PARAMETER["standard_parallel_1",-18],
    PARAMETER["standard_parallel_2",-36],
    PARAMETER["latitude_of_center",0],
    PARAMETER["longitude_of_center",132],
    PARAMETER["false_easting",0],
    PARAMETER["false_northing",0],
    UNIT["metre",1,
        AUTHORITY["EPSG","9001"]],
    AXIS["Easting",EAST],
    AXIS["Northing",NORTH],
    AUTHORITY["EPSG","3577"]]
Origin = (310000.000000000000000,-3500000.000000000000000)
Pixel Size = (100.000000000000000,-100.000000000000000)
Metadata:
  albers_conical_equal_area#false_easting=0
  albers_conical_equal_area#false_northing=0
  albers_conical_equal_area#GeoTransform=310000 100 0 -3500000 0 -100 
  albers_conical_equal_area#grid_mapping_name=albers_conical_equal_area
  albers_conical_equal_area#inverse_flattening=298.257222101
  albers_conical_equal_area#latitude_of_projection_origin=0
  albers_conical_equal_area#longitude_of_central_meridian=132
  albers_conical_equal_area#longitude_of_prime_meridian=0
  albers_conical_equal_area#semi_major_axis=6378137
  albers_conical_equal_area#spatial_ref=PROJCS["GDA94 / Australian Albers",GEOGCS["GDA94",DATUM["Geocentric_Datum_of_Australia_1994",SPHEROID["GRS 1980",6378137,298.257222101,AUTHORITY["EPSG","7019"]],TOWGS84[0,0,0,0,0,0,0],AUTHORITY["EPSG","6283"]],PRIMEM["Greenwich",0,AUTHORITY["EPSG","8901"]],UNIT["degree",0.0174532925199433,AUTHORITY["EPSG","9122"]],AUTHORITY["EPSG","4283"]],PROJECTION["Albers_Conic_Equal_Area"],PARAMETER["standard_parallel_1",-18],PARAMETER["standard_parallel_2",-36],PARAMETER["latitude_of_center",0],PARAMETER["longitude_of_center",132],PARAMETER["false_easting",0],PARAMETER["false_northing",0],UNIT["metre",1,AUTHORITY["EPSG","9001"]],AXIS["Easting",EAST],AXIS["Northing",NORTH],AUTHORITY["EPSG","3577"]]
  albers_conical_equal_area#standard_parallel={-18,-36}
  Band1#_FillValue=0
  Band1#grid_mapping=albers_conical_equal_area
  Band1#long_name=GDAL Band Number 1
  NC_GLOBAL#Conventions=CF-1.5
  NC_GLOBAL#GDAL=GDAL 1.10.1, released 2013/08/26
  NC_GLOBAL#history=Tue Nov 11 05:29:37 2014: GDAL Create( /var/tmp/ndg/tmpDir6424378802362491040/LGA_tile_x6_y5.nc, ... )
  x#long_name=x coordinate of projection
  x#standard_name=projection_x_coordinate
  x#units=m
  y#long_name=y coordinate of projection
  y#standard_name=projection_y_coordinate
  y#units=m
Corner Coordinates:
Upper Left  (  310000.000,-3500000.000) (135d18'46.17"E, 32d 4'38.30"S)
Lower Left  (  310000.000,-4000000.000) (135d27'26.62"E, 36d33'51.93"S)
Upper Right (  810000.000,-3500000.000) (140d38'41.33"E, 31d52' 5.51"S)
Lower Right (  810000.000,-4000000.000) (141d 1'15.66"E, 36d20'38.76"S)
Center      (  560000.000,-3750000.000) (138d 6'32.46"E, 34d13'55.40"S)
Band 1 Block=5000x1 Type=Int32, ColorInterp=Undefined
  Min=345.000 Max=371.000 
  Minimum=345.000, Maximum=371.000, Mean=370.706, StdDev=2.751
  NoData Value=0
  Metadata:
    _FillValue=0
    grid_mapping=albers_conical_equal_area
    long_name=GDAL Band Number 1
    NETCDF_VARNAME=Band1
    STATISTICS_MAXIMUM=371
    STATISTICS_MEAN=370.70557491289
    STATISTICS_MINIMUM=345
    STATISTICS_STDDEV=2.751066362869

@forjin-vpac-innovations
Copy link
Author

-stats -noct

root@0727d3007d2d:/var/lib/ndg/storagepool/boundaries_m100/2014-01-01T00-00-00.000# gdalinfo -noct -stats ./LGA_tile_x6_y5.nc
Driver: netCDF/Network Common Data Format
Files: ./LGA_tile_x6_y5.nc
       ./LGA_tile_x6_y5.nc.aux.xml
Size is 5000, 5000
Coordinate System is:
PROJCS["GDA94 / Australian Albers",
    GEOGCS["GDA94",
        DATUM["Geocentric_Datum_of_Australia_1994",
            SPHEROID["GRS 1980",6378137,298.257222101,
                AUTHORITY["EPSG","7019"]],
            TOWGS84[0,0,0,0,0,0,0],
            AUTHORITY["EPSG","6283"]],
        PRIMEM["Greenwich",0,
            AUTHORITY["EPSG","8901"]],
        UNIT["degree",0.0174532925199433,
            AUTHORITY["EPSG","9122"]],
        AUTHORITY["EPSG","4283"]],
    PROJECTION["Albers_Conic_Equal_Area"],
    PARAMETER["standard_parallel_1",-18],
    PARAMETER["standard_parallel_2",-36],
    PARAMETER["latitude_of_center",0],
    PARAMETER["longitude_of_center",132],
    PARAMETER["false_easting",0],
    PARAMETER["false_northing",0],
    UNIT["metre",1,
        AUTHORITY["EPSG","9001"]],
    AXIS["Easting",EAST],
    AXIS["Northing",NORTH],
    AUTHORITY["EPSG","3577"]]
Origin = (310000.000000000000000,-3500000.000000000000000)
Pixel Size = (100.000000000000000,-100.000000000000000)
Metadata:
  albers_conical_equal_area#false_easting=0
  albers_conical_equal_area#false_northing=0
  albers_conical_equal_area#GeoTransform=310000 100 0 -3500000 0 -100 
  albers_conical_equal_area#grid_mapping_name=albers_conical_equal_area
  albers_conical_equal_area#inverse_flattening=298.257222101
  albers_conical_equal_area#latitude_of_projection_origin=0
  albers_conical_equal_area#longitude_of_central_meridian=132
  albers_conical_equal_area#longitude_of_prime_meridian=0
  albers_conical_equal_area#semi_major_axis=6378137
  albers_conical_equal_area#spatial_ref=PROJCS["GDA94 / Australian Albers",GEOGCS["GDA94",DATUM["Geocentric_Datum_of_Australia_1994",SPHEROID["GRS 1980",6378137,298.257222101,AUTHORITY["EPSG","7019"]],TOWGS84[0,0,0,0,0,0,0],AUTHORITY["EPSG","6283"]],PRIMEM["Greenwich",0,AUTHORITY["EPSG","8901"]],UNIT["degree",0.0174532925199433,AUTHORITY["EPSG","9122"]],AUTHORITY["EPSG","4283"]],PROJECTION["Albers_Conic_Equal_Area"],PARAMETER["standard_parallel_1",-18],PARAMETER["standard_parallel_2",-36],PARAMETER["latitude_of_center",0],PARAMETER["longitude_of_center",132],PARAMETER["false_easting",0],PARAMETER["false_northing",0],UNIT["metre",1,AUTHORITY["EPSG","9001"]],AXIS["Easting",EAST],AXIS["Northing",NORTH],AUTHORITY["EPSG","3577"]]
  albers_conical_equal_area#standard_parallel={-18,-36}
  Band1#_FillValue=0
  Band1#grid_mapping=albers_conical_equal_area
  Band1#long_name=GDAL Band Number 1
  NC_GLOBAL#Conventions=CF-1.5
  NC_GLOBAL#GDAL=GDAL 1.10.1, released 2013/08/26
  NC_GLOBAL#history=Tue Nov 11 05:29:37 2014: GDAL Create( /var/tmp/ndg/tmpDir6424378802362491040/LGA_tile_x6_y5.nc, ... )
  x#long_name=x coordinate of projection
  x#standard_name=projection_x_coordinate
  x#units=m
  y#long_name=y coordinate of projection
  y#standard_name=projection_y_coordinate
  y#units=m
Corner Coordinates:
Upper Left  (  310000.000,-3500000.000) (135d18'46.17"E, 32d 4'38.30"S)
Lower Left  (  310000.000,-4000000.000) (135d27'26.62"E, 36d33'51.93"S)
Upper Right (  810000.000,-3500000.000) (140d38'41.33"E, 31d52' 5.51"S)
Lower Right (  810000.000,-4000000.000) (141d 1'15.66"E, 36d20'38.76"S)
Center      (  560000.000,-3750000.000) (138d 6'32.46"E, 34d13'55.40"S)
Band 1 Block=5000x1 Type=Int32, ColorInterp=Undefined
  Min=345.000 Max=371.000 
  Minimum=345.000, Maximum=371.000, Mean=370.706, StdDev=2.751
  NoData Value=0
  Metadata:
    _FillValue=0
    grid_mapping=albers_conical_equal_area
    long_name=GDAL Band Number 1
    NETCDF_VARNAME=Band1
    STATISTICS_MAXIMUM=371
    STATISTICS_MEAN=370.70557491289
    STATISTICS_MINIMUM=345
    STATISTICS_STDDEV=2.751066362869

@z0u
Copy link

z0u commented Nov 11, 2014

This line:

  Minimum=345.000, Maximum=371.000, Mean=370.706, StdDev=2.751

Should be more like:

    STATISTICS_MAXIMUM=378
    STATISTICS_MEAN=342.13977994224
    STATISTICS_MINIMUM=301
    STATISTICS_STDDEV=21.535813406664

What version of GDAL is it? Mine is:

$ gdalinfo --version
GDAL 1.10.1, released 2013/08/26

@forjin-vpac-innovations
Copy link
Author

This is the gdal version of docker container.

GDAL 1.10.1, released 2013/08/26

@z0u
Copy link

z0u commented Nov 11, 2014

I see. And you're right, those lines are in the output you posted.

The output must be different when it runs in the task pipeline. Here is a patch you can use to print the actual last 10 lines if there's an error.

diff --git a/src/storagemanager/src/org/vpac/ndg/task/FileStatistics.java b/src/storagemanager/src/org/vpac/ndg/task/FileStatistics.java
index aee4ba5..882d231 100644
--- a/src/storagemanager/src/org/vpac/ndg/task/FileStatistics.java
+++ b/src/storagemanager/src/org/vpac/ndg/task/FileStatistics.java
@@ -148,7 +148,18 @@ public class FileStatistics extends Task {
         }

         if (foundCount < 4) {
-            throw new TaskException("Unable to extract statistics from gdalinfo output");
+            StringBuilder sb = new StringBuilder();
+            int start = lines.length - 11;
+            if (start < 0)
+                start = 0;
+            for (int i = start; i < lines.length; i++) {
+                if (i > start)
+                    sb.append("\n");
+                sb.append(lines[i]);
+            }
+            throw new TaskException(String.format(
+                    "Unable to extract statistics from gdalinfo output."
+                    + "Last 10 lines were\n %s", sb.toString()));
         }

@forjin-vpac-innovations
Copy link
Author

After inserting logging this error came out.

ERROR o.v.n.s.ActivityLogger - Invalid arguments detected during afterCreateDataset intercepting method.
WARN  o.v.n.s.u.BandUtil - Re-creating blank tile for band Band(LGA) in dataset Dataset(boundaries/100m)
ERROR o.v.n.t.Application - Exception during execution of task pipeline:
org.vpac.ndg.exceptions.TaskException: Unable to extract statistics from gdalinfo output.Last 10 lines were
 Origin = (1786000.000000000000000,2900000.000000000000000)
Pixel Size = (66.146000000000001,-66.146000000000001)
Corner Coordinates:
Upper Left  ( 1786000.000, 2900000.000) (144d23'38.18"E, 34d 7'12.04"N)
Lower Left  ( 1786000.000, 1997239.392) (145d 1'50.95"E, 22d27'52.45"N)
Upper Right ( 2999977.538, 2900000.000) (152d42' 2.87"E, 36d22'19.50"N)
Lower Right ( 2999977.538, 1997239.392) (153d45' 6.07"E, 24d28'27.62"N)
Center      ( 2392988.769, 2448619.696) (148d58'40.17"E, 28d58'41.54"N)
Band 1 Block=128x128 Type=Int32, ColorInterp=Undefined
  Min=0.000 Max=0.000 
  NoData Value=0
    at org.vpac.ndg.task.FileStatistics.execute(FileStatistics.java:160) ~[FileStatistics.class:na]
    at org.vpac.ndg.task.TaskPipeline.run(TaskPipeline.java:133) ~[TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:134) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
ERROR o.h.u.JDBCExceptionReporter - Batch entry 0 update JobProgress set NUMSTEPS='8', CURRENTSTEP='2', STEPPROGRESS='25.0', DESCRIPTION='Create VRT of single band/timeslice', APPLICATION='Builing WMTS tiles', SOURCE='unknown', NAME='building wmts tiles', STATE='EXECUTION_ERROR', TASKTYPE='WmtsTileBuilding', ERRORMESSAGE='Unable to extract statistics from gdalinfo output.Last 10 lines were
 Origin = (1786000.000000000000000,2900000.000000000000000)
Pixel Size = (66.146000000000001,-66.146000000000001)
Corner Coordinates:
Upper Left  ( 1786000.000, 2900000.000) (144d23''38.18"E, 34d 7''12.04"N)
Lower Left  ( 1786000.000, 1997239.392) (145d 1''50.95"E, 22d27''52.45"N)
Upper Right ( 2999977.538, 2900000.000) (152d42'' 2.87"E, 36d22''19.50"N)
Lower Right ( 2999977.538, 1997239.392) (153d45'' 6.07"E, 24d28''27.62"N)
Center      ( 2392988.769, 2448619.696) (148d58''40.17"E, 28d58''41.54"N)
Band 1 Block=128x128 Type=Int32, ColorInterp=Undefined
  Min=0.000 Max=0.000 
  NoData Value=0' where ID='2c9180cc499eacda01499eada8a9000d' was aborted.  Call getNextException to see the cause.
ERROR o.h.u.JDBCExceptionReporter - ERROR: value too long for type character varying(255)
ERROR o.h.e.d.AbstractFlushingEventListener - Could not synchronize database state with session
org.hibernate.exception.DataException: Could not execute JDBC batch update
    at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:102) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:262) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:179) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) [hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1206) [hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:375) [hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137) [hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:656) [spring-orm-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) [spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) [spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:393) [spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120) [spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) [spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) [spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at com.sun.proxy.$Proxy23.save(Unknown Source) [na:na]
    at org.vpac.ndg.task.TaskPipeline.taskpipelineErrorState(TaskPipeline.java:299) [TaskPipeline.class:na]
    at org.vpac.ndg.task.Application.executeTaskPipeline(Application.java:150) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:119) [Application.class:na]
    at org.vpac.ndg.task.Application.call(Application.java:40) [Application.class:na]
    at org.vpac.ndg.task.Application$1.run(Application.java:104) [Application$1.class:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
Caused by: java.sql.BatchUpdateException: Batch entry 0 update JobProgress set NUMSTEPS='8', CURRENTSTEP='2', STEPPROGRESS='25.0', DESCRIPTION='Create VRT of single band/timeslice', APPLICATION='Builing WMTS tiles', SOURCE='unknown', NAME='building wmts tiles', STATE='EXECUTION_ERROR', TASKTYPE='WmtsTileBuilding', ERRORMESSAGE='Unable to extract statistics from gdalinfo output.Last 10 lines were
 Origin = (1786000.000000000000000,2900000.000000000000000)
Pixel Size = (66.146000000000001,-66.146000000000001)
Corner Coordinates:
Upper Left  ( 1786000.000, 2900000.000) (144d23''38.18"E, 34d 7''12.04"N)
Lower Left  ( 1786000.000, 1997239.392) (145d 1''50.95"E, 22d27''52.45"N)
Upper Right ( 2999977.538, 2900000.000) (152d42'' 2.87"E, 36d22''19.50"N)
Lower Right ( 2999977.538, 1997239.392) (153d45'' 6.07"E, 24d28''27.62"N)
Center      ( 2392988.769, 2448619.696) (148d58''40.17"E, 28d58''41.54"N)
Band 1 Block=128x128 Type=Int32, ColorInterp=Undefined
  Min=0.000 Max=0.000 
  NoData Value=0' where ID='2c9180cc499eacda01499eada8a9000d' was aborted.  Call getNextException to see the cause.
    at org.postgresql.jdbc2.AbstractJdbc2Statement$BatchResultHandler.handleError(AbstractJdbc2Statement.java:2586) ~[postgresql-8.4-702.jdbc4.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl$1.handleError(QueryExecutorImpl.java:459) ~[postgresql-8.4-702.jdbc4.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1811) ~[postgresql-8.4-702.jdbc4.jar:na]
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:407) ~[postgresql-8.4-702.jdbc4.jar:na]
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeBatch(AbstractJdbc2Statement.java:2725) ~[postgresql-8.4-702.jdbc4.jar:na]
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1135) ~[c3p0-0.9.2.jar:0.9.2]
    at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) ~[hibernate-core-3.5.6-Final.jar:3.5.6-Final]
    ... 21 common frames omitted
ERROR o.v.n.t.Application - Task exited abnormally: Could not execute JDBC batch update; SQL [update JobProgress set NUMSTEPS=?, CURRENTSTEP=?, STEPPROGRESS=?, DESCRIPTION=?, APPLICATION=?, SOURCE=?, NAME=?, STATE=?, TASKTYPE=?, ERRORMESSAGE=? where ID=?]; nested exception is org.hibernate.exception.DataException: Could not execute JDBC batch update

@z0u
Copy link

z0u commented Nov 11, 2014

Ok! So min and max are zero, so there can be no standard deviation - I guess this prevents the STATISTICS_* lines from being printed.

The coordinates are possibly weird, too. If I run this:

gdalinfo -noct -stats /var/lib/ndg/storagepool/boundaries_m100/2014-01-01T00-00-00.000/LGA_tile_x1_y1.nc

Then I get:

Origin = (2500000.000000000000000,2400000.000000000000000)
Pixel Size = (100.000000000000000,-100.000000000000000)

etc. So, perhaps the VRT file is not being created properly. See if you can find the temporary directory it's working in, and have a look at the *_scaled.vrt file.

@z0u
Copy link

z0u commented Nov 11, 2014

In an earlier comment you said something about LGA_tile_x6_y5.nc. Those tile numbers seem strange. In my storage pool I have only:

LGA_tile_x0_y0.nc
LGA_tile_x0_y1.nc
LGA_tile_x1_y0.nc
LGA_tile_x1_y1.nc

So maybe rsa.xml is configured with the wrong projection or resolution?

@forjin-vpac-innovations
Copy link
Author

So the temp directory means setting in the rsa.xml, right?
There is no file like .srt.

And for the projection and resolution, do you mean this?

<!-- spatial reference system (SRS) EPSG code to be used -->
    <targetSrsEpsgId>3577</targetSrsEpsgId>

    <!-- Origin in specified SRS -->
    <gridOriginPointInTargetSrs>
        <x class="double">-2690000.0</x>
        <y class="double">-1000000.0</y>
    </gridOriginPointInTargetSrs>

@z0u
Copy link

z0u commented Nov 12, 2014

Part of the reason this is so hard to debug is that the temporary directory gets deleted after the task has finished (even if it errors).

That projection information is not right for this project. It should be:

    <targetSrsEpsgId>3111</targetSrsEpsgId>
    <gridOriginPointInTargetSrs>
        <x class="double">2000000</x>
        <y class="double">2900000</y>
    </gridOriginPointInTargetSrs>

    <upPositive>true</upPositive>
    <filelockingOn>false</filelockingOn>

@forjin-vpac-innovations
Copy link
Author

I wrote logs on near the error spots.

It says

java.lang.NullPointerException: null
    at ucar.nc2.jni.netcdf.Nc4Iosp.flush(Nc4Iosp.java:2307) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.flush(NetcdfFileWriter.java:843) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.close(NetcdfFileWriter.java:852) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at org.vpac.web.controller.DatasetController.createCategories(DatasetController.java:228) ~[DatasetController.class:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
    at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
    at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) [servlet-api-2.5.jar:na]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:723) [servlet-api-2.5.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote-6.0.39.jar:6.0.39]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
INFO  o.v.w.c.DatasetController - datasetId:2c9180cb49a6de400149a6e508130015
INFO  o.v.w.c.DatasetController - Step0-0
INFO  o.v.w.c.DatasetController - Step0-1
INFO  o.v.w.c.DatasetController - Step0-2
INFO  o.v.w.c.DatasetController - Step0-3
INFO  o.v.w.c.DatasetController - p:/var/src/.
INFO  o.v.n.q.Query - Configuring query based on memento
INFO  o.v.n.q.Query - Initialising inputs
INFO  o.v.n.q.Query - Requesting bands [#boundaries/LGA, #ds/SA3, #boundaries/SA3]
INFO  o.v.n.q.Query - Initialising grid
INFO  o.v.n.q.c.CoordinateUtils - Resizing requested bounding box from 2D to 2D.
INFO  o.v.n.q.Query - Opening inputs
INFO  o.v.n.q.Query - Constructing filters
INFO  o.v.n.q.FilterAdapter - Bound Sampler(SA3) to LGA.input
INFO  o.v.n.q.FilterAdapter - Bound Sampler(LGA) to LGA.categories
INFO  o.v.n.q.FilterAdapter - Bound FilteredPixel(LGA.output(!0)) to SA3.input
INFO  o.v.n.q.FilterAdapter - Bound Sampler(SA3) to SA3.categories
INFO  o.v.n.q.Query - Creating output file
INFO  o.v.n.q.DatasetOutput - Created variable time with shape [1]
INFO  o.v.n.q.DatasetOutput - Created variable y with shape [5651]
INFO  o.v.n.q.DatasetOutput - Created variable x with shape [8129]
INFO  o.v.n.q.DatasetOutput - Created variable nothing with shape [1, 5651, 8129]
INFO  o.v.w.c.DatasetController - Test1
ERROR o.v.w.c.DatasetController - Failed to close output file
java.lang.NullPointerException: null
    at ucar.nc2.jni.netcdf.Nc4Iosp.flush(Nc4Iosp.java:2307) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.flush(NetcdfFileWriter.java:843) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at ucar.nc2.NetcdfFileWriter.close(NetcdfFileWriter.java:852) ~[netcdf-4.3.16.jar:4.3.16-SNAPSHOT]
    at org.vpac.web.controller.DatasetController.createCategories(DatasetController.java:228) ~[DatasetController.class:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
    at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
    at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126) [spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) [servlet-api-2.5.jar:na]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:723) [servlet-api-2.5.jar:na]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina-6.0.39.jar:6.0.39]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) [catalina-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606) [tomcat-coyote-6.0.39.jar:6.0.39]
    at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote-6.0.39.jar:6.0.39]
    at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]

@forjin-vpac-innovations
Copy link
Author

Alex, after patch your code, I faced build error like this

init:
    [mkdir] Created dir: /var/src/spatialcubeservice/dist
    [mkdir] Created dir: /var/src/spatialcubeservice/doc

compile:
    [mkdir] Created dir: /var/src/spatialcubeservice/build
     [echo] Java home = /usr/lib/jvm/java-7-openjdk-amd64/jre
    [javac] /var/src/spatialcubeservice/build.xml:164: warning: 'includeantruntime' was not set, defaulting to build.sysclasspath=last; set to false for repeatable builds
    [javac] Compiling 356 source files to /var/src/spatialcubeservice/build
    [javac] /var/src/spatialcubeservice/src/main/java/org/vpac/web/controller/DataController.java:411: error: no suitable method found for execute()
    [javac]         converter.execute();
    [javac]                  ^
    [javac]     method ImageTranslator.execute(Collection<String>) is not applicable
    [javac]       (actual and formal argument lists differ in length)
    [javac]     method Translator.execute(Collection<String>) is not applicable
    [javac]       (actual and formal argument lists differ in length)
    [javac] /var/src/spatialcubeservice/src/main/java/org/vpac/web/controller/DataController.java:937: error: no suitable method found for execute()
    [javac]             converter.execute();
    [javac]                      ^
    [javac]     method ImageTranslator.execute(Collection<String>) is not applicable
    [javac]       (actual and formal argument lists differ in length)
    [javac]     method Translator.execute(Collection<String>) is not applicable
    [javac]       (actual and formal argument lists differ in length)
    [javac] Note: /var/src/storagemanager/src/org/vpac/ndg/GenericEnumUserType.java uses or overrides a deprecated API.
    [javac] Note: Recompile with -Xlint:deprecation for details.
    [javac] Note: /var/src/storagemanager/src/org/vpac/ndg/storage/dao/StatisticsDaoImpl.java uses unchecked or unsafe operations.
    [javac] Note: Recompile with -Xlint:unchecked for details.
    [javac] 2 errors

BUILD FAILED
/var/src/build.xml:82: The following error occurred while executing this line:
/var/src/spatialcubeservice/build.xml:164: Compile failed; see the compiler error output for details.

Total time: 12 seconds

@forjin-vpac-innovations
Copy link
Author

One more step to go.

Here is the error message. Could you please have a look of it?

[ERROR] [11/18/2014 10:39:55.836] [Workers-akka.actor.default-dispatcher-24] [akka://Workers/user/worker/exec] Failed to close output file WARNING arguments left: 1
[ERROR] [11/18/2014 10:39:55.838] [Workers-akka.actor.default-dispatcher-24] [akka://Workers/user/worker/exec] Task 69731977-86e4-4986-849c-fe26d8104d47 exited abnormally
java.lang.NullPointerException
    at org.vpac.ndg.datamodel.RsaAggregationFactory.create(RsaAggregationFactory.java:232)
    at org.vpac.ndg.datamodel.RsaAggregationFactory.create(RsaAggregationFactory.java:113)
    at org.vpac.ndg.datamodel.RsaDatasetProvider.open(RsaDatasetProvider.java:190)
    at org.vpac.ndg.datamodel.RsaDatasetProvider.open(RsaDatasetProvider.java:151)
    at org.vpac.ndg.query.io.ProviderRegistry.open(ProviderRegistry.java:119)
    at org.vpac.ndg.query.DatasetInput.open(DatasetInput.java:128)
    at org.vpac.ndg.query.Query.openInputs(Query.java:265)
    at org.vpac.ndg.query.Query.setMemento(Query.java:169)
    at org.vpac.worker.WorkExecutor.executeQuery(WorkExecutor.java:184)
    at org.vpac.worker.WorkExecutor.onReceive(WorkExecutor.java:95)
    at akka.actor.UntypedActor$$anonfun$receive$1.applyOrElse(UntypedActor.scala:167)
    at akka.actor.Actor$class.aroundReceive(Actor.scala:465)
    at akka.actor.UntypedActor.aroundReceive(UntypedActor.scala:97)
    at akka.actor.ActorCell.receiveMessage(ActorCell.scala:516)
    at akka.actor.ActorCell.invoke(ActorCell.scala:487)
    at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:238)
    at akka.dispatch.Mailbox.run(Mailbox.scala:220)
    at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:393)
    at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
    at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)
    at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
    at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)

Error:null
Error:null

@z0u
Copy link

z0u commented Nov 19, 2014

This might happen if the source dataset has no tiles in the requested spatial extents. Please check that:

  • The workers have the same rsa.xml as scs
  • They all share the same storage pool directory

@z0u
Copy link

z0u commented Dec 11, 2014

Hi Jin, is this issue fixed?

Alex

@forjin-vpac-innovations
Copy link
Author

Yes, it's fixed.

@z0u z0u closed this as completed Dec 11, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants