Spring Batch Admin M2 with Oracle/2.0 SB Schema

[sams]

I am trying to run the sample and configure it to run against Oracle 10.2. I basically took the sample, configured a properties file for Oracle (took out the init datasource setting!) and pointed it at my schema that was built with spring batch 2.0 ddl. That being said, things look ok until you click around some. Here are the three problems I am seeing.

If I go to executions, I see my executions (the first 20). Rows 1-20 of 4,205. If I click "Next" to see more executions:

http://localhost:9090/batch-admin/ba...20&pageSize=20

I see this exception

org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.dao.EmptyResultDataAccessException: Incorrect result size: expected 1, actual 0
	org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:659)
	org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:552)

root cause

org.springframework.dao.EmptyResultDataAccessException: Incorrect result size: expected 1, actual 0
	org.springframework.dao.support.DataAccessUtils.requiredSingleResult(DataAccessUtils.java:71)
	org.springframework.jdbc.core.JdbcTemplate.queryForObject(JdbcTemplate.java:472)
	org.springframework.jdbc.core.JdbcTemplate.queryForObject(JdbcTemplate.java:476)
	org.springframework.jdbc.core.JdbcTemplate.queryForLong(JdbcTemplate.java:480)
	org.springframework.jdbc.core.simple.SimpleJdbcTemplate.queryForLong(SimpleJdbcTemplate.java:127)
	org.springframework.batch.admin.service.JdbcSearchableJobExecutionDao.getJobExecutions(JdbcSearchableJobExecutionDao.java:190)
	org.springframework.batch.admin.service.SimpleJobService.listJobExecutions(SimpleJobService.java:209)
	org.springframework.batch.admin.web.JobExecutionController.list(JobExecutionController.java:144)

The second involves drilling into the Job Execution details.
First:
batch/jobs/executions/4542

then "Step Executions":
batch/jobs/executions/4542/steps

selecting "detail"
/batch/jobs/executions/4542/steps/17030/progress

I get this exception on "most" steps on any job I look at (somewhere around 95% failure)

org.springframework.web.util.NestedServletException: Request processing failed; nested exception is freemarker.core.InvalidReferenceException: Expression stepExecutionInfo.stepExecution.exitStatus.exitDescription is undefined on line 84, column 39 in manager/jobs/steps/execution.ftl.
	org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:659)
	org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:552)

root cause

freemarker.core.InvalidReferenceException: Expression stepExecutionInfo.stepExecution.exitStatus.exitDescription is undefined on line 84, column 39 in manager/jobs/steps/execution.ftl.
	freemarker.core.TemplateObject.assertNonNull(TemplateObject.java:124)
	freemarker.core.Expression.getStringValue(Expression.java:118)
	freemarker.core.Expression.getStringValue(Expression.java:93)
	freemarker.core.DollarVariable.accept(DollarVariable.java:76)
	freemarker.core.Environment.visit(Environment.java:209)
	freemarker.core.MixedContent.accept(MixedContent.java:92)
	freemarker.core.Environment.visit(Environment.java:209)
	freemarker.core.IfBlock.accept(IfBlock.java:82)
	freemarker.core.Environment.visit(Environment.java:209)

Lastly if I look at jobs I see the first page of jobs:
* Rows: 1-20 of 180 * Next * Page Size: 20

My next link:
http://localhost:9090/batch-admin/ba...20&pageSize=20

Clicking "Next" yields information about the job that showed up in the link vs. showing the next page:

Job Instances for Job (Name: 1249859282430)

If I hack the link and remove the job name that's embedded in it, I get the expected behavior:

(Hacked link)
http://localhost:9090/batch-admin/ba...20&pageSize=20

(Correctly shows page 2 of the jobs)

[Dave Syer]

Can you try just upgrading Spring Batch? There were some bugs in the query generators for pagination with Oracle that were fixed in 2.1.0. If it works with HSQL but not Oracle I suspect that it is fixed.

[sams]

I am running Spring Batch 2.1.0.M4 with Spring Batch Admin (the other app that's writing data to the 2.0 database schema is actually on Spring Batch 2.1.0.RELEASE). If I upgrade Spring Batch Admin to 2.1.0.RELEASE of Spring Batch, I get this exception (does _not_ occur on SB 2.1.0.M4):

12:42:44,798 ERROR main context.ContextLoader:208 - Context initialization faile
d
org.springframework.beans.factory.CannotLoadBeanClassException: Cannot find clas
s [org.springframework.batch.core.configuration.support.ClassPathXmlJobLoader] f
or bean with name 'jobLoader' defined in URL [jar:file:/C:/apache-tomcat-6.0.20/
webapps/mercybatch-admin/WEB-INF/lib/spring-batch-admin-manager-1.0.0.jar!/META-
INF/bootstrap/batch/execution-context.xml]; nested exception is java.lang.ClassN
otFoundException: org.springframework.batch.core.configuration.support.ClassPath
XmlJobLoader
        at org.springframework.beans.factory.support.AbstractBeanFactory.resolve
BeanClass(AbstractBeanFactory.java:1208)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBean
Factory.predictBeanType(AbstractAutowireCapableBeanFactory.java:568)
        at org.springframework.beans.factory.support.AbstractBeanFactory.isFacto
ryBean(AbstractBeanFactory.java:1277)
        at org.springframework.beans.factory.support.AbstractBeanFactory.isFacto
ryBean(AbstractBeanFactory.java:844)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.
preInstantiateSingletons(DefaultListableBeanFactory.java:539)
        at org.springframework.context.support.AbstractApplicationContext.finish
BeanFactoryInitialization(AbstractApplicationContext.java:842)
        at org.springframework.context.support.AbstractApplicationContext.refres
h(AbstractApplicationContext.java:416)
        at org.springframework.web.context.ContextLoader.createWebApplicationCon
text(ContextLoader.java:261)
        at org.springframework.web.context.ContextLoader.initWebApplicationConte
xt(ContextLoader.java:192)
        at org.springframework.web.context.ContextLoaderListener.contextInitiali
zed(ContextLoaderListener.java:47)

[Dave Syer]

OK, then you might be able to just drop in spring-batch-infrastructure-2.1.0.RELEASE.jar (since the bug fix you need is there, but the missing class is in spring-batch-core). Or you can go to the trunk of Spring Batch Admin, or wait for the M3 release.

[sams]

I tried two things and no help either way. First, I mixed Spring Batch 2.1.0.M4 (core and test) with the the 2.1.0.RELEASE version of spring batch infrastructure. I was able to find the missing class of course (from core M4), but still had the same problems with paging and execution details. Also, I checked out trunk of Spring Batch Admin, changed the props for Oracle and built the sample app. I still see all of the same problems noted in the original post.

Strangely paging does work in some places. For instance if I am looking at Job Instances via:
/batch/jobs/{the_job_name}

I am able to page that just fine.

[Dave Syer]

Can you enable TRACE logging in org.springframework.jdbc and find the queries that are failing?

[sams]

Query that fails when going to page 2 of Job Executions:

core.JdbcTemplate:434 - Executing SQL query [SELECT * FROM (SELECT E.JOB_EXECUTION_ID AS SORT_KEY FROM BATCH_JOB_EXECUTION E, BATCH_JOB_INSTANCE I WHERE E.JOB_INSTANCE_ID=I.JOB_INSTANCE_ID ORDER BY E.JOB_EXECUTION_ID DESC) WHERE ROWNUM = 20]

The failure on paging jobs page seems to be a rendering problem - the link gets made with the last job on the page embedded in it. Modifying this link and removing the job name from it gives the proper behavior (you can page it by manually modifying the query parameters).

[sams]

The last failure involves trying to get the step execution details. Here are all of logs for that:

core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION from BATCH_JOB_EXECUTION where JOB_EXECUTION_ID = ?]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [4605], value class [java.lang.Long], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT ji.JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, ji.VERSION from BATCH_JOB_INSTANCE ji, BATCH_JOB_EXECUTION je where JOB_EXECUTION_ID = ? and ji.JOB_INSTANCE_ID = je.JOB_INSTANCE_ID]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [4605], value class [java.lang.Long], SQL type unknown
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL from BATCH_JOB_PARAMS where JOB_INSTANCE_ID = ?]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [4464], value class [java.lang.Long], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT SHORT_CONTEXT, SERIALIZED_CONTEXT FROM BATCH_JOB_EXECUTION_CONTEXT WHERE JOB_EXECUTION_ID = ?]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [4605], value class [java.lang.Long], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [4605], value class [java.lang.Long], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? and STEP_EXECUTION_ID = ?]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [4605], value class [java.lang.Long], SQL type unknown
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 2, parameter value [17572], value class [java.lang.Long], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT SHORT_CONTEXT, SERIALIZED_CONTEXT FROM BATCH_STEP_EXECUTION_CONTEXT WHERE STEP_EXECUTION_ID = ?]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [17572], value class [java.lang.Long], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT COUNT(STEP_EXECUTION_ID) from BATCH_STEP_EXECUTION where STEP_NAME = ?]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [arvValidateInputJobParams], value class [java.lang.String], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT COUNT(STEP_EXECUTION_ID) from BATCH_STEP_EXECUTION where STEP_NAME = ?]
Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [arvValidateInputJobParams], value class [java.lang.String], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
core.JdbcTemplate:634 - Executing prepared SQL query
core.JdbcTemplate:569 - Executing prepared SQL statement [SELECT * FROM (SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION FROM BATCH_STEP_EXECUTION WHERE STEP_NAME = ? ORDER BY STEP_EXECUTION_ID DESC) WHERE ROWNUM <= 1000]
datasource.DataSourceUtils:112 - Fetching JDBC Connection from DataSource
core.StatementCreatorUtils:206 - Setting SQL statement parameter value: column index 1, parameter value [arvValidateInputJobParams], value class [java.lang.String], SQL type unknown
datasource.DataSourceUtils:312 - Returning JDBC Connection to DataSource
freemarker.runtime:96 - 
Expression stepExecutionInfo.stepExecution.exitStatus.exitDescription is undefined on line 84, column 39 in manager/jobs/steps/execution.ftl.
The problematic instruction:
----------
==> ${stepExecutionInfo.stepExecution.exitStatus.exitDescription} [on line 84, column 37 in manager/jobs/steps/execution.ftl]
 in include "${execution}" [on line 7, column 1 in manager/jobs/steps/progress.ftl]
 in include body [on line 40, column 16 in layouts/standard.ftl]
----------
Java backtrace for programmers:
----------
freemarker.core.InvalidReferenceException: Expression stepExecutionInfo.stepExecution.exitStatus.exitDescription is undefined on line 84, column 39 in manager/jobs/steps/execution.ftl.
	at freemarker.core.TemplateObject.assertNonNull(TemplateObject.java:124)
	at freemarker.core.Expression.getStringValue(Expression.java:118)
	at freemarker.core.Expression.getStringValue(Expression.java:93)
	at freemarker.core.DollarVariable.accept(DollarVariable.java:76)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.IfBlock.accept(IfBlock.java:82)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.Environment.include(Environment.java:1482)
	at freemarker.core.Include.accept(Include.java:169)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.Environment.include(Environment.java:1482)
	at freemarker.core.Include.accept(Include.java:169)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.MixedContent.accept(MixedContent.java:92)
	at freemarker.core.Environment.visit(Environment.java:209)
	at freemarker.core.Environment.process(Environment.java:189)
	at freemarker.template.Template.process(Template.java:237)
	at org.springframework.web.servlet.view.freemarker.FreeMarkerView.processTemplate(FreeMarkerView.java:366)
	at org.springframework.web.servlet.view.freemarker.FreeMarkerView.doRender(FreeMarkerView.java:283)
	at org.springframework.web.servlet.view.freemarker.FreeMarkerView.renderMergedTemplateModel(FreeMarkerView.java:233)
	at org.springframework.js.ajax.freemarker.AjaxFreeMarkerView.renderMergedTemplateModel(AjaxFreeMarkerView.java:109)
	at org.springframework.web.servlet.view.AbstractTemplateView.renderMergedOutputModel(AbstractTemplateView.java:167)
	at org.springframework.web.servlet.view.AbstractView.render(AbstractView.java:250)
	at org.springframework.web.servlet.DispatcherServlet.render(DispatcherServlet.java:1060)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:798)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:716)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:647)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:552)

[Dave Syer]

The SQL looks fine to me, but I don't have an Oracle instance to try it out on just now. Can you see why it doesn't work?

Presumably the rendering error goes away if you switch back to the default database?

[sams]

The Oracle paging should look something more like this (this would get page 2 of your results at 20/page - you can add a FIRST_ROWS hint as well if you want to get really fancy):

SELECT * FROM (SELECT ROWNUM as rn, e.* from (select E.JOB_EXECUTION_ID AS SORT_KEY FROM BATCH_JOB_EXECUTION E, BATCH_JOB_INSTANCE I WHERE E.JOB_INSTANCE_ID=I.JOB_INSTANCE_ID ORDER BY E.JOB_EXECUTION_ID DESC) e where rownum <= 40 ) where rn > 20;

Regarding the rendering on the Jobs list page, there's not enough jobs defined in the sample to create more than a page worth of data so I wasn't able to test that scenario. I'll see if I can experiment with the sample db to get similar effects.