Esse é o log de inicialização da tela com form:
INFO: 09:00:29,859 DEBUG [VRaptor ] VRaptor received a new request
INFO: 09:00:29,859 DEBUG [DefaultRequestExecution] executing stack DefaultRequestExecution
INFO: 09:00:29,906 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ResourceLookupInterceptor
INFO: 09:00:29,906 DEBUG [DefaultResourceTranslator] trying to access /test/form
INFO: 09:00:29,906 DEBUG [DefaultResourceTranslator] found resource [DefaultResourceMethod: TestController.formTestController.form()]
INFO: 09:00:29,906 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor FlashInterceptor
INFO: 09:00:29,906 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor InterceptorListPriorToExecutionExtractor
INFO: 09:00:29,921 DEBUG [SessionImpl ] opened session at timestamp: 12928428299
INFO: 09:00:29,921 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor HibernateTransactionInterceptor
INFO: 09:00:30,031 DEBUG [JDBCTransaction ] begin
INFO: 09:00:30,031 DEBUG [ConnectionManager ] opening JDBC connection
INFO: 09:00:30,031 DEBUG [JDBCTransaction ] current autocommit status: true
INFO: 09:00:30,031 DEBUG [JDBCTransaction ] disabling autocommit
INFO: 09:00:30,031 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor InstantiateInterceptor
INFO: 09:00:30,046 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ExceptionHandlerInterceptor
INFO: 09:00:30,125 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ExecuteMethodInterceptor
INFO: 09:00:30,140 DEBUG [ExecuteMethodInterceptor] Invoking TestController.form()
INFO: 09:00:30,234 DEBUG [AbstractBatcher ] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
INFO: 09:00:30,234 DEBUG [SQL ] select station0_.cd_estac as cd1_0_, station0_.nm_estac as nm15_0_ from estacao station0_ order by station0_.nm_estac asc
INFO: Hibernate: select station0_.cd_estac as cd1_0_, station0_.nm_estac as nm15_0_ from estacao station0_ order by station0_.nm_estac asc
INFO: 09:00:30,343 DEBUG [AbstractBatcher ] about to open ResultSet (open ResultSets: 0, globally: 0)
INFO: 09:00:30,359 DEBUG [Loader ] result row: EntityKey[br.web.model.Station#2047]
...
INFO: 09:00:50,812 DEBUG [Loader ] result row: EntityKey[br.web.model.Station#1509]
INFO: 09:00:50,906 DEBUG [AbstractBatcher ] about to close ResultSet (open ResultSets: 1, globally: 1)
INFO: 09:00:50,906 DEBUG [AbstractBatcher ] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
INFO: 09:00:51,000 DEBUG [TwoPhaseLoad ] resolving associations for [br.web.model.Station#2047]
INFO: 09:00:51,000 DEBUG [TwoPhaseLoad ] done materializing entity [br.web.model.Station#2047]
...
INFO: 09:01:32,578 DEBUG [TwoPhaseLoad ] resolving associations for [br.web.model.Station#1509]
INFO: 09:01:32,578 DEBUG [TwoPhaseLoad ] done materializing entity [br.web.model.Station#1509]
INFO: 09:01:32,671 DEBUG [StatefulPersistenceContext] initializing non-lazy collections
INFO: 09:01:32,671 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ForwardToDefaultViewInterceptor
INFO: 09:01:32,781 DEBUG [ForwardToDefaultViewInterceptor] forwarding to the dafault page for this logic
INFO: 09:01:32,781 DEBUG [DefaultPageResult ] forwarding to /WEB-INF/jsp/test/form.jsp
INFO: 09:01:32,781 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/WEB-INF/jsp/test/form.jsp
INFO: 09:01:32,890 DEBUG [JDBCTransaction ] commit
INFO: 09:01:32,890 DEBUG [AbstractFlushingEventListener] processing flush-time cascades
INFO: 09:01:32,890 DEBUG [AbstractFlushingEventListener] dirty checking collections
INFO: 09:01:32,937 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/js/ajax.js
INFO: 09:01:32,984 DEBUG [Collections ] Collection found: [br.web.model.Station.testList#2047], was: [br.web.model.Station.testList#2047] (uninitialized)
INFO: 09:01:32,968 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/js/test.js
INFO: 09:01:32,984 DEBUG [Collections ] Collection found: [br.web.model.Station.testList#1011], was: [br.web.model.Station.testList#1011] (uninitialized)
INFO: 09:01:32,953 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/js/ajax-dynamic-content.js
INFO: 09:01:33,093 DEBUG [Collections ] Collection found: [br.web.model.Station.testList#566], was: [br.web.model.Station.testList#566] (uninitialized)
...
INFO: 09:01:49,187 DEBUG [Collections ] Collection found: [br.web.model.Station.testList#1509], was: [br.web.model.Station.testList#1509] (uninitialized)
INFO: 09:01:49,187 DEBUG [AbstractFlushingEventListener] Flushed: 0 insertions, 0 updates, 0 deletions to 691 objects
INFO: 09:01:49,187 DEBUG [AbstractFlushingEventListener] Flushed: 0 (re)creations, 0 updates, 0 removals to 691 collections
INFO: 09:01:49,281 DEBUG [Printer ] listing entities:
INFO: 09:01:49,281 DEBUG [Printer ] br.web.model.Station{testList=<uninitialized>, cdEstac=12345, nmEstac=Estac 1}
INFO: 09:01:50,500 DEBUG [Printer ] more......
INFO: 09:01:50,515 DEBUG [JDBCTransaction ] re-enabling autocommit
INFO: 09:01:50,546 DEBUG [JDBCTransaction ] committed JDBC Connection
INFO: 09:01:50,546 DEBUG [ConnectionManager ] aggressively releasing JDBC connection
INFO: 09:01:50,609 DEBUG [ConnectionManager ] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
INFO: 09:01:50,609 DEBUG [VRaptor ] VRaptor ended the request
INFO: 09:01:50,718 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/css/1.css
INFO: 09:01:50,750 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/images/body.jpg
INFO: 09:01:50,765 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/images/nav.jpg
INFO: 09:01:50,765 DEBUG [DefaultStaticContentHandler] Deferring request to container: /cq_web/images/innerwrapper.jpg
Esse é o log quando os dados do form são enviados:
INFO: 09:27:30,125 DEBUG [VRaptor ] VRaptor received a new request
INFO: 09:27:30,125 DEBUG [DefaultRequestExecution] executing stack DefaultRequestExecution
INFO: 09:27:30,156 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ResourceLookupInterceptor
INFO: 09:27:30,156 DEBUG [DefaultResourceTranslator] trying to access /test/add
INFO: 09:27:30,250 DEBUG [DefaultResourceTranslator] found resource [DefaultResourceMethod: TestController.addTestController.add(RangeTest)]
INFO: 09:27:30,250 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor FlashInterceptor
INFO: 09:27:30,265 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor InterceptorListPriorToExecutionExtractor
INFO: 09:27:30,265 DEBUG [SessionImpl ] opened session at timestamp: 12928444502
INFO: 09:27:30,265 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor HibernateTransactionInterceptor
INFO: 09:27:30,265 DEBUG [JDBCTransaction ] begin
INFO: 09:27:30,265 DEBUG [ConnectionManager ] opening JDBC connection
INFO: 09:27:30,265 DEBUG [JDBCTransaction ] current autocommit status: true
INFO: 09:27:30,265 DEBUG [JDBCTransaction ] disabling autocommit
INFO: 09:27:30,265 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor InstantiateInterceptor
INFO: 09:27:30,281 DEBUG [LazyInterceptorHandler] Invoking interceptor ParametersInstantiatorInterceptor
INFO: 09:27:30,281 DEBUG [OgnlParametersProvider] Applying rangeTest.variavel.cdVaria with [161]
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] cant find property for expression rangeTest.variavel.cdVaria ignoring
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] Applying rangeTest.mdMinim with [11]
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] cant find property for expression rangeTest.mdMinim ignoring
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] Applying rangeTest.mdMaxim with [15]
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] cant find property for expression rangeTest.mdMaxim ignoring
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] Applying type with [1]
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] cant find property for expression type ignoring
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] Applying rangeTest.estacao.cdEstac with [12345]
INFO: 09:27:30,390 DEBUG [OgnlParametersProvider] cant find property for expression rangeTest.estacao.cdEstac ignoring
INFO: 09:27:30,390 DEBUG [ParanamerNameProvider] Found parameter names with paranamer for TestController.add(RangeTest) as [test]
INFO: 09:27:30,406 DEBUG [ParametersInstantiatorInterceptor] Parameter values for [DefaultResourceMethod: TestController.addTestController.add(RangeTest)] are [null]
INFO: 09:27:30,406 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ExceptionHandlerInterceptor
INFO: 09:27:30,406 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ExecuteMethodInterceptor
INFO: 09:27:30,406 DEBUG [ExecuteMethodInterceptor] Invoking TestController.add(RangeTest)
INFO: java.lang.NullPointerException
at br.web.dao.impl.GenericDaoImpl.saveOrUpdate(GenericDaoImpl.java:189)
at br.web.service.impl.TestServiceImpl.saveOrUpdate(TestServiceImpl.java:100)
at br.web.controller.TestController.add(TestController.java:82)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at br.com.caelum.vraptor.interceptor.ExecuteMethodInterceptor.intercept(ExecuteMethodInterceptor.java:57)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.interceptor.ExceptionHandlerInterceptor.intercept(ExceptionHandlerInterceptor.java:69)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.core.LazyInterceptorHandler.execute(LazyInterceptorHandler.java:61)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.interceptor.ParametersInstantiatorInterceptor.intercept(ParametersInstantiatorInterceptor.java:90)
at br.com.caelum.vraptor.core.LazyInterceptorHandler.execute(LazyInterceptorHandler.java:59)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.interceptor.InstantiateInterceptor.intercept(InstantiateInterceptor.java:42)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.util.hibernate.HibernateTransactionInterceptor.intercept(HibernateTransactionInterceptor.java:45)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:56)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.interceptor.InterceptorListPriorToExecutionExtractor.intercept(InterceptorListPriorToExecutionExtractor.java:44)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.interceptor.FlashInterceptor.intercept(FlashInterceptor.java:81)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.interceptor.ResourceLookupInterceptor.intercept(ResourceLookupInterceptor.java:67)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:54)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.core.ToInstantiateInterceptorHandler.execute(ToInstantiateInterceptorHandler.java:56)
at br.com.caelum.vraptor.core.DefaultInterceptorStack.next(DefaultInterceptorStack.java:53)
at br.com.caelum.vraptor.core.DefaultRequestExecution.execute(DefaultRequestExecution.java:70)
at br.com.caelum.vraptor.VRaptor$1.insideRequest(VRaptor.java:92)
at br.com.caelum.vraptor.ioc.spring.SpringProvider.provideForRequest(SpringProvider.java:56)
at br.com.caelum.vraptor.VRaptor.doFilter(VRaptor.java:89)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:256)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:277)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:188)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:641)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97)
at com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:325)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:165)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
at java.lang.Thread.run(Thread.java:619)
INFO: 09:27:35,218 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ForwardToDefaultViewInterceptor
INFO: 09:27:35,218 DEBUG [ForwardToDefaultViewInterceptor] forwarding to the dafault page for this logic
INFO: 09:27:35,375 DEBUG [DefaultPageResult ] forwarding to /WEB-INF/jsp/test/add.jsp
INFO: 09:27:35,375 DEBUG [VRaptor ] VRaptor received a new request
WARNING: PWC4011: Unable to set request character encoding to UTF-8 from context /cq_web, because request parameters have already been read, or ServletRequest.getReader() has already been called
INFO: 09:27:35,375 DEBUG [DefaultRequestExecution] executing stack DefaultRequestExecution
INFO: 09:27:35,468 DEBUG [ToInstantiateInterceptorHandler] Invoking interceptor ResourceLookupInterceptor
INFO: 09:27:35,468 DEBUG [DefaultResourceTranslator] trying to access /WEB-INF/jsp/test/add.jsp
INFO: 09:27:35,468 DEBUG [VRaptor ] VRaptor ended the request
INFO: 09:27:35,468 DEBUG [JDBCTransaction ] commit
INFO: 09:27:35,468 DEBUG [JDBCTransaction ] re-enabling autocommit
INFO: 09:27:35,484 DEBUG [JDBCTransaction ] committed JDBC Connection
INFO: 09:27:35,484 DEBUG [ConnectionManager ] aggressively releasing JDBC connection
INFO: 09:27:35,484 DEBUG [ConnectionManager ] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
INFO: 09:27:35,578 DEBUG [VRaptor ] VRaptor ended the request