Orbeon-Loging-Form does not Redirecting to DefaultSavedRequest

[hank]

We have an orbeon-based application set up with SpringSecurity running.

The login is handled as described in Multi-level Authentication with SSO and LoginPage

Now we want to change the login-page from regular HTML-Form to Orbeon-XHTML.

This is working as expected. The Login-Form comes up.

After giving the credentials and sending them back to the server by using a submission like:

         <xf:submission
            method="urlencoded-post"
            id="securitySubmit"
            includenamespaceprefixes=""
            replace="none"
            resource="/j_security_check"
            ref="instance('j_security_check')"/>

The server gets it, the correct filter (UsernameLogin) in the chains handles the request (reading from the contentstream of the request), and after the user got authenticated, the server sends the redirect to the browser (org.springframework.security.web.DefaultRedirectS trategy) , but the browser refuses to accept it.

So how can I get an idea what's going on?

Is this more a spring security issue or more an orbeon issue?

Thanks

cheers

Heinrich

[Rob Winch]

I would look in the logs to determine what is happening. It sounds like the response might already be committed and thus it is not sending the redirect. If that doesn't help turn up the Spring Security logging and look through that too.

[hank]

Reading the logs over and over:

This is what I see:

After entering the credentials and hitting the button:

[...]

 [00:53:39 DEBUG AbstractAuthenticationProcessingFilter.java.successfulAuthentication] Authentication success. Updating SecurityContextHolder to contain: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@441d0230: Principal: 123; Password: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: ROLE_USER
 [00:53:39 TRACE AbstractApplicationContext.java.publishEvent] Publishing event in Root WebApplicationContext: org.springframework.security.authentication.event.InteractiveAuthenticationSuccessEvent[source=org.springframework.security.authentication.UsernamePasswordAuthenticationToken@441d0230: Principal: 123; Password: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: ROLE_USER]
 [00:53:39 DEBUG SavedRequestAwareAuthenticationSuccessHandler.java.onAuthenticationSuccess] Redirecting to DefaultSavedRequest Url: http://host:9090/myApp/home/
 [00:53:39 DEBUG DefaultRedirectStrategy.java.sendRedirect] Redirecting to 'http://host:9090/myApp/home/'
 [00:53:39 DEBUG HttpSessionSecurityContextRepository.java.saveContext] SecurityContext stored to HttpSession: 'org.springframework.security.core.context.SecurityContextImpl@441d0230: Authentication: org.springframework.security.authentication.UsernamePasswordAuthenticationToken@441d0230: Principal: 123; Password: [PROTECTED]; Authenticated: true; Details: null; Granted Authorities: ROLE_USER'
 [00:53:39 DEBUG SecurityContextPersistenceFilter.java.doFilter] SecurityContextHolder now cleared, as request processing completed
 [00:53:39 DEBUG Wire.java.wire] << "HTTP/1.1 302 Moved Temporarily[EOL]"
 [00:53:39 DEBUG Wire.java.wire] << "Server: Apache-Coyote/1.1[EOL]"
 [00:53:39 DEBUG Wire.java.wire] << "Location: http://host:9090/myApp/home/[EOL]"
 [00:53:39 DEBUG Wire.java.wire] << "Content-Length: 0[EOL]"
 [00:53:39 DEBUG Wire.java.wire] << "Date: Fri, 18 Mar 2011 23:53:39 GMT[EOL]"
 [00:53:39 DEBUG Wire.java.wire] << "[EOL]"
 [00:53:39 DEBUG DefaultClientConnection.java.receiveResponseHeader] Receiving response: HTTP/1.1 302 Moved Temporarily
 [00:53:39 DEBUG DefaultClientConnection.java.receiveResponseHeader] << HTTP/1.1 302 Moved Temporarily
 [00:53:39 DEBUG DefaultClientConnection.java.receiveResponseHeader] << Server: Apache-Coyote/1.1
 [00:53:39 DEBUG DefaultClientConnection.java.receiveResponseHeader] << Location: http://host:9090/myApp/home/
 [00:53:39 DEBUG DefaultClientConnection.java.receiveResponseHeader] << Content-Length: 0
 [00:53:39 DEBUG DefaultClientConnection.java.receiveResponseHeader] << Date: Fri, 18 Mar 2011 23:53:39 GMT
 [00:53:39 DEBUG ThreadSafeClientConnManager.java.releaseConnection] Released connection is reusable.
 [00:53:39 DEBUG ConnPoolByRoute.java.freeEntry] Releasing connection [HttpRoute[{}->http://host:9090]][null]
 [00:53:39 DEBUG ConnPoolByRoute.java.freeEntry] Pooling connection [HttpRoute[{}->http://host:9090]][null]; keep alive for -1 MILLISECONDS
 [00:53:39 DEBUG IdleConnectionHandler.java.add] Adding connection at: 1300492419975
 [00:53:39 DEBUG ConnPoolByRoute.java.notifyWaitingThread] Notifying no-one, there are no waiting threads
 [00:53:39 DEBUG IndentedLogger.java.log]               end connecting {time (ms): "273", submitted asynchronously: "false"}
 [00:53:39 DEBUG IndentedLogger.java.log]               start handling result
 [00:53:39 DEBUG IndentedLogger.java.log]               end handling result {time (ms): "1"}
 [00:53:39 DEBUG IndentedLogger.java.log]             end submission {time (ms): "286"}
 [00:53:39 DEBUG IndentedLogger.java.log]           dispatchEvent - end default action handler {time (ms): "297"}
 [00:53:39 DEBUG IndentedLogger.java.log]         dispatchEvent - end dispatching {time (ms): "298", name: "xforms-submit", id: "securitySubmit"}
 [00:53:39 DEBUG IndentedLogger.java.log]       dispatchEvent - end default action handler {time (ms): "300"}
 [00:53:39 DEBUG IndentedLogger.java.log]     dispatchEvent - end dispatching {time (ms): "302", name: "DOMActivate", id: "xf-12"}
 [00:53:39 DEBUG IndentedLogger.java.log]   executeExternalEvent - end handling external event {time (ms): "303"}
 [00:53:39 DEBUG IndentedLogger.java.log] end handling external events and/or uploaded files {time (ms): "314"}
 [00:53:39 DEBUG IndentedLogger.java.log] response - start handling regular Ajax response
 [00:53:39 DEBUG IndentedLogger.java.log] response - end handling regular Ajax response {time (ms): "1"}
 [00:53:39 DEBUG ConcreteChooseProcessor.java.start] Choose: taking otherwise branch at line 61, column 47 of oxf:/ops/xforms/xforms-server.xpl
 [00:53:39 DEBUG URLGenerator.java.getValidity] OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/processor/serializer/http-serializer-config.rng
 [00:53:39 DEBUG ProcessorImpl.java.readCacheInputAsObject] Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.serializer.HttpSerializer]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.serializer.HttpSerializer, inputName: config, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.validation.MSVValidationProcessor, outputName: data, key: [CompoundOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [oxf:/org/orbeon/oxf/processor/serializer/http-serializer-config.rng|application/xml|null|false|false|false|false|false|[false|true|false|false|false|false]]]]], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: inline input] ]]]]'. FOUND object: org.orbeon.oxf.processor.serializer.HttpSerializerBase$Config@6eb1c2fe
 [00:53:39 DEBUG ProcessorImpl.java.findInputLastModified] Last modified: 0
 [00:53:39 DEBUG URLGenerator.java.getValidity] OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/processor/converter/standard-text-converter-config.rng
 [00:53:39 DEBUG ProcessorImpl.java.readCacheInputAsObject] Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.converter.XMLConverter]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.converter.XMLConverter, inputName: config, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.validation.MSVValidationProcessor, outputName: data, key: [CompoundOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [oxf:/org/orbeon/oxf/processor/converter/standard-text-converter-config.rng|application/xml|null|false|false|false|false|false|[false|true|false|false|false|false]]]]], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: inline input] ]]]]'. FOUND object: org.orbeon.oxf.processor.converter.ConverterBase$Config@56c5711e
 [00:53:39 DEBUG ProcessorImpl.java.readCacheInputAsObject] Cache [data, class org.orbeon.oxf.processor.generator.DOMGenerator, config, class org.orbeon.oxf.processor.validation.MSVValidationProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.validation.MSVValidationProcessor, inputName: config, DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ]]'. FOUND object: org.dom4j.tree.DefaultDocument@40ccc48b [Document: name null]
 [00:53:39 DEBUG URLGenerator.java.getValidity] OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server-response.rng
 [00:53:39 DEBUG ProcessorImpl.java.readCacheInputAsObject] Cache [data, class org.orbeon.oxf.processor.generator.URLGenerator, schema, class org.orbeon.oxf.processor.validation.MSVValidationProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.validation.MSVValidationProcessor, inputName: schema, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [oxf:/ops/xforms/xforms-server-response.rng|application/xml|null|false|false|false|false|false|[false|true|false|false|false|false]]]]]]'. FOUND object: com.sun.msv.verifier.jarv.SchemaImpl@6d9c83b2
 [00:53:39 DEBUG TeeProcessor.java.freeSAXStoreIfNeeded] Freed SAXStore for output id: response; approximate size: 676 bytes
 [00:53:39 DEBUG MSVValidationProcessor.java.readImpl] oxf:/ops/xforms/xforms-server-response.rng validation completed in 1
 [00:53:40 DEBUG NetUtils.java.deleteFileItem] Deleting temporary request-scoped file: /work/user/apache-tomcat-6.0.32/temp/upload_45259758_12ecb62e318__7ffd_00000007.tmp
 [00:53:40 INFO InitUtils.java.runProcessor] /xforms-server - Timing: 364 - Cache hits for cache.main: 24, fault: 1, adds: 0, expirations: 0, success rate: 96%

Request done, still having the login-screen on the browser

What does this mean?
Is orbeon-servlet still using this request or is the browser not getting the redirect?

[Rob Winch]

From the logs you posted I am not sure what is happening. Can you only enable Spring Security logging and gather the logs for requesting the protected resource and attempting to login?