Issue with Datamart export

Dear all,

I face an issue with Datamart export.Sent this message to user list earlier.

Server:
Build revision:
9149
Build date:
2013-03-27 13:41
User agent:
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:20.0) Gecko/20100101 Firefox/20.0
External configuration directory:
Not set
Environment variable:
DHIS2_HOME
Database type:
MySQL
Java Opts:
-Xms256m -Xmx1512m -XX:PermSize=128m -XX:MaxPermSize=512m -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Java version:
1.6.0_24
Java vendor:
Sun Microsystems Inc.
OS name:
Linux
OS architecture:
amd64
OS version:
3.2.0-29-generic
Server date:
2013-04-25 23:59
Server memory:
Mem Total in JVM: 846 Free in JVM: 403 Max Limit: 1344
CPU cores:
4Tomcat log:

  • INFO 2013-04-25 07:54:05,856 Using periods: [[Monthly: Sat Dec 01 00:00:00 IST 2012 - Mon Dec 31 00:00:00 IST 2012], [Quarterly: Mon Oct 01 00:00:00 IST 2012 - Mon Dec 31 00:00:00 IST 2012]] (DataMartTask.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:06,159 Data mart export process started, number of CPU cores: 4, Mem Total in JVM: 622 Free in JVM: 389 Max Limit: 1344: 0:00:00.000 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:06,162 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:06 IST 2013, message: Data mart export process started] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,206 Recreated temporary tables: 0:00:01.047 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,206 Data elements: 1228, indicators: 294, periods: 2, org units: 1296: 0:00:01.047 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,426 Retrieved meta-data objects, using periods: [[Quarterly: 2012-10-01 - 2012-12-31], [Monthly: 2012-12-01 - 2012-12-31]]: 0:00:01.267 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,426 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:07 IST 2013, message: Filtering meta-data] (InMemoryNotifier.java [taskScheduler-5])

  • WARN 2013-04-25 07:54:07,565 Indicator is invalid: [Number of Dental Surgeons per 10,000 population] (DefaultExpressionService.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,716 Filtered objects: 0:00:01.557 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,717 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:07 IST 2013, message: Loading indicators] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,727 Exploded indicator expressions: 0:00:01.568 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:07,727 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:07 IST 2013, message: Loading data elements] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:12,094 Retrieved operands: 1493: 0:00:05.935 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:12,095 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:12 IST 2013, message: Loading periods] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:12,101 Number of periods: 2: 0:00:05.942 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:12,102 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:12 IST 2013, message: Filtering data elements without data] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:14,234 Number of operands with data: 487, Mem Total in JVM: 622 Free in JVM: 285 Max Limit: 1344: 0:00:08.075 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:14,234 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:14 IST 2013, message: Populating crosstabulation table] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:25,438 Crosstab table columns: 489, rows: 0 (DefaultCrossTabService.java [SimpleAsyncTaskExecutor-98])

  • INFO 2013-04-25 07:54:26,761 Crosstab table columns: 489, rows: 0 (DefaultCrossTabService.java [SimpleAsyncTaskExecutor-97])

  • INFO 2013-04-25 07:54:27,003 Crosstab table columns: 489, rows: 1 (DefaultCrossTabService.java [SimpleAsyncTaskExecutor-100])

  • INFO 2013-04-25 07:54:27,027 Crosstab table columns: 489, rows: 1 (DefaultCrossTabService.java [SimpleAsyncTaskExecutor-99])

  • INFO 2013-04-25 07:54:27,027 Populated crosstab table, Mem Total in JVM: 624 Free in JVM: 385 Max Limit: 1344: 0:00:20.868 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:27,030 Created aggregated data cache, number of indicator operands: 232, operands with data: 487: 0:00:20.871 (Clock.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:27,039 [Level: INFO, category: DATAMART, time: Thu Apr 25 07:54:27 IST 2013, message: Exporting data for data element data] (InMemoryNotifier.java [taskScheduler-5])

  • INFO 2013-04-25 07:54:28,213 Data element export task done (DefaultDataElementDataMart.java [SimpleAsyncTaskExecutor-102])

  • ERROR 2013-04-25 07:54:28,663 Unexpected error occurred in scheduled task. (TaskUtils.java [taskScheduler-5])

java.lang.RuntimeException: Exception during execution
at org.hisp.dhis.system.util.ConcurrentUtils.waitForCompletion(ConcurrentUtils.java:54)
at org.hisp.dhis.datamart.engine.DefaultDataMartEngine.export(DefaultDataMartEngine.java:348)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:616)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)

at org.amplecode.quick.StatementInterceptor.intercept(StatementInterceptor.java:71)
at sun.reflect.GeneratedMethodAccessor570.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:616)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)

at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy105.export(Unknown Source)

at org.hisp.dhis.system.scheduling.DataMartTask.run(DataMartTask.java:163)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:53)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:165)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)

at java.lang.Thread.run(Thread.java:679)

Caused by: java.util.concurrent.ExecutionException: java.lang.RuntimeException: Failed to flush BatchHandler
at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:252)

at java.util.concurrent.FutureTask.get(FutureTask.java:111)
at org.hisp.dhis.system.util.ConcurrentUtils.waitForCompletion(ConcurrentUtils.java:50)
... 33 more

Caused by: java.lang.RuntimeException: Failed to flush BatchHandler

at org.amplecode.quick.batchhandler.AbstractBatchHandler.flush(AbstractBatchHandler.java:311)
at org.hisp.dhis.datamart.dataelement.DefaultDataElementDataMart.exportDataValues(DefaultDataElementDataMart.java:217)

at sun.reflect.GeneratedMethodAccessor521.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)

at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)

at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.interceptor.AsyncExecutionInterceptor$1.call(AsyncExecutionInterceptor.java:80)

at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
... 1 more

Caused by: com.mysql.jdbc.MysqlDataTruncation: Data truncation: Out of range value for column ‘value’ at row 96

at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4094)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4028)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2490)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2651)

at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2677)
at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1748)
at com.mysql.jdbc.StatementImpl.executeUpdate(StatementImpl.java:1665)

at org.amplecode.quick.batchhandler.AbstractBatchHandler.flush(AbstractBatchHandler.java:295)
... 11 more

**Cleared cash.
Archived data values and tried to run the datamart to locate the data vulues causing the problem. But it still gives the same result.

Datamart 2.txt (18.2 KB)

···

**

**Once all the existing data archived, Datamart behaves normally. **

**How to solve this problem (How to visualize already available data) ?
**

(Tomcat Log with fresh test data attached)

Sorry for the earlier post…

with regards,

Subodha.