Resource not loading - 404 Error

Hi Alex,

As suggested above, We did the changes in the Orbeon Forms war.
Now application is working fine in our local setup.

But when we deployed same ear to DEV environment region, we received below exception.
It's look like some cache related issue.

2017-06-05 10:01:46,040 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.generator.URLGenerator, config, class org.orbeon.oxf.processor.xinclude.XIncludeProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.xinclude.XIncludeProcessor, inputName: config, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [InputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, 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/xml/schemas/url-generator-config.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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] ]]]], SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [oxf:/config/not-found.xhtml|null|null|001|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.oxf.processor.URIProcessorOutputImpl$URIReferences@62fd7543
2017-06-05 10:01:46,051 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$1 getConfigURIReferences: Config found: org.orbeon.oxf.processor.generator.URLGenerator$ConfigURIReferences@1957f535
2017-06-05 10:01:46,057 - INFO  org.orbeon.oxf.pipeline.InitUtils$ runProcessor: /resources/auto_resources.xml - Timing: 122
2017-06-05 10:01:46,060 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "14", "session": "pX1_d0ry7Qyh5qt7KpGGOLq", "source": "service", "message": "end: handle", "time": "125 ms"}
2017-06-05 10:01:46,062 - DEBUG org.orbeon.oxf.util.IndentedLogger log: opening URL connection {method: "GET", URL: "http://tcwas-dev.travcan.ca/FormsServer/resources/auto_resources.xml", Orbeon-Token: "92bcc4b2af38458610037548a03cabbc5d26f295"}
2017-06-05 10:01:46,064 - DEBUG org.orbeon.oxf.util.IndentedLogger log: response {status code: "404"}

As you suggested, we did below changes

 In the <xforms:instance>,

replacing:
    src="/resources/auto_resources.xml"
with:
    src="oxf:/auto_resources.xml"

and replaced "auto_resources.xml" to Orbeon.war\WEB-INF\resources

But  the deployed application in DEV environment region still try to call from "/resources/auto_resources.xml"
We are not getting such issue in local. Application is working fine.

To me, it's look like orbeon cache related issue but not sure on it.
Could you please help me how to resolve such issue?

Hi Hasim,

The cache is in memory only, so you can try to restart the server, and if you still have the problem, you'll know it's not a cache issue.

To me, it looks like the old `src="/resources/auto_resources.xml"` is still being fed to the Orbeon Forms web app. But without being to debug things, I have no way to tell for sure.

Alex

Hi Alex,

Above issue is resolved after restart JVM in DEV Environment. Thank you for suggestion.

Now, I am talking about another issue which we are facing in S2 DEV. We are getting below popup error when trying to change any field value in the page.

You may want to try one of the following:

Close this dialog and continue to use this page.
Reload this page. Note that you will lose any unsaved changes.
If the above does not work, try reloading the page yourself. Note that you will lose any unsaved changes:

With Firefox: hold down the shift key and click the Reload button in your browser toolbar.
With Safari and Chrome: click the Reload button in your browser toolbar.
With Internet Explorer: hold down the control key and click the Reload button in your browser toolbar.
Return home.



But in my local, I able to change those value
 

Here, I want to mention that an AJAX call is made to the server each time a field is modified.
 

Could you please help me to resolve such issue? Thanks for your help.

Hi Hasim,

When does this dialog show up? Is it right away as you load the form? Or when you interact with the form? If you open the Chrome Dev Tools console, are you seeing any error?

Alex

Hi Alex,

We are not getting the error when page is loaded.
we are getting it when we interact with the forms. we want to update some text field in the loaded page.

In Chrome dev Tools console we are getting below error




Here, connection.js trying to fetch https://tc-gateway-dev.can.ca/FormsServer/orbeon/xforms-server which throws 404 error.

I wonder why I am not getting such issue in my local. In local its works fine.
The issue is coming in DEV region.

Hi Hasim,

Could you attach the orbeon.log you get when doing this? I suspect that it will show some errors related to the 403 and 500 you're getting here.

Alex

Hi Alex,

We don't have any error in orbeon.log.

but received below exception in DEV server log

[6/20/17 3:04:16:724 EDT] 0000006f webapp        E com.ibm.ws.webcontainer.webapp.WebApp logServletError SRVE0293E: [Servlet Error]-[com.ibm.ws.webcontainer.extension.DefaultExtensionProcessor]: javax.servlet.ServletException: Session has expired. Unable to process incoming request.
        at org.orbeon.oxf.servlet.OrbeonXFormsFilter.doFilter(OrbeonXFormsFilter.java:76)

above exception is coming from below code snippet in OrbeonXFormsFilter.java



Here session doesn't exists for any request to /xforms-server in DEV server.

I believe this is Server related issue but not sure how to fix the issue in DEV.
Please suggest me.

Hasim

Hi Alex,
Please find orbeon.log below

2017-06-20 03:10:45,212 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-dev.xml
2017-06-20 03:10:45,215 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-internal.xml
2017-06-20 03:10:45,216 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-base.xml
2017-06-20 03:10:45,218 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-xforms.xml
2017-06-20 03:10:45,219 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-form-runner.xml
2017-06-20 03:10:45,221 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-form-builder.xml
2017-06-20 03:10:45,222 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-local.xml
2017-06-20 03:10:45,223 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/properties-local-dev.xml
2017-06-20 03:10:45,224 - DEBUG org.orbeon.oxf.processor.ProcessorImpl findInputLastModified: Last modified: 1483152242000
2017-06-20 03:10:45,224 - DEBUG org.orbeon.oxf.properties.Properties update: Not reloading properties because they have not changed.
2017-06-20 03:10:45,225 - WARN  org.orbeon.oxf.fr.FormRunnerAuth$ getCredentialsAsHeadersUseSession: not setting auth headers because username is missing
2017-06-20 03:10:45,225 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "481", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "service", "message": "start: handle", "path": "/xforms-server", "method": "POST"}
2017-06-20 03:10:45,225 - INFO  org.orbeon.oxf.pipeline.InitUtils$$anonfun$runProcessor$1 apply: /xforms-server - Received request
2017-06-20 03:10:45,226 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/pipeline.rng
2017-06-20 03:10:45,227 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/prologue-servlet.xpl
2017-06-20 03:10:45,228 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.PipelineProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.PipelineProcessor, 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/xml/schemas/pipeline.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ], CompoundOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [oxf:/config/prologue-servlet.xpl|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]]]'. FOUND object: org.orbeon.oxf.processor.pipeline.PipelineConfig@1a87a637
2017-06-20 03:10:45,228 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,229 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor, $data, class org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor, inputName: $data, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, outputName: data, key: [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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]]]'. FOUND object: org.orbeon.saxon.tinytree.TinyDocumentImpl@10124000
2017-06-20 03:10:45,230 - DEBUG org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor start: Choose: taking when branch with test: p:get-request-path() = '/xforms-server' or starts-with(p:get-request-path(), '/xforms-server/') at line 25, column 40 of oxf:/config/prologue-servlet.xpl
2017-06-20 03:10:45,230 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/pipeline.rng
2017-06-20 03:10:45,230 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server.xpl
2017-06-20 03:10:45,232 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.PipelineProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.PipelineProcessor, 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/xml/schemas/pipeline.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ], 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.xpl|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]]]'. FOUND object: org.orbeon.oxf.processor.pipeline.PipelineConfig@59f207c8
2017-06-20 03:10:45,232 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,232 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor, $data, class org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor, inputName: $data, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, outputName: data, key: [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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]]]'. FOUND object: org.orbeon.saxon.tinytree.TinyDocumentImpl@1b724000
2017-06-20 03:10:45,233 - DEBUG org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor start: Choose: taking when branch with test: p:get-request-method() = 'POST' and not(starts-with(p:get-request-header('content-type'), 'multipart/form-data')) at line 19, column 40 of oxf:/ops/xforms/xforms-server.xpl
2017-06-20 03:10:45,234 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/processor/serializer/http-serializer-config.rng
2017-06-20 03:10:45,236 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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|000|true|false|false|false|null|null|true|null|[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@223858ee
2017-06-20 03:10:45,236 - DEBUG org.orbeon.oxf.processor.ProcessorImpl findInputLastModified: Last modified: 0
2017-06-20 03:10:45,237 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/processor/converter/standard-text-converter-config.rng
2017-06-20 03:10:45,239 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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|000|true|false|false|false|null|null|true|null|[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@34d6cb8b
2017-06-20 03:10:45,240 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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.orbeon.dom.tree.ConcreteDocument@fa9f4b02 [Document]
2017-06-20 03:10:45,240 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server-response.rng
2017-06-20 03:10:45,242 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.msv.verifier.jarv.SchemaImpl@df6bd802
2017-06-20 03:10:45,243 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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.orbeon.dom.tree.ConcreteDocument@fa9f4b02 [Document]
2017-06-20 03:10:45,243 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server-request.rng
2017-06-20 03:10:45,245 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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-request.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.msv.verifier.jarv.SchemaImpl@fb7b424e
2017-06-20 03:10:45,245 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/request-config.rng
2017-06-20 03:10:45,246 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.generator.RequestGenerator]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.generator.RequestGenerator, 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/xml/schemas/request-config.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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.dom.tree.ConcreteDocument@b741f4db [Document]
2017-06-20 03:10:45,248 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.generator.URLGenerator]: READING.
2017-06-20 03:10:45,248 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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.orbeon.dom.tree.ConcreteDocument@fa9f4b02 [Document]
2017-06-20 03:10:45,249 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/url-generator-config.rng
2017-06-20 03:10:45,250 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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:/org/orbeon/oxf/xml/schemas/url-generator-config.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.msv.verifier.jarv.SchemaImpl@5e0fcf1f
2017-06-20 03:10:45,251 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,251 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, 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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]'. FOUND object: org.orbeon.dom.tree.ConcreteDocument@d44e53c6 [Document]
2017-06-20 03:10:45,252 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,252 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, 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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]'. FOUND object: org.orbeon.dom.tree.ConcreteDocument@aac159e4 [Document]
2017-06-20 03:10:45,253 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.generator.DOMGenerator, config, class org.orbeon.oxf.processor.transformer.XPathProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.transformer.XPathProcessor, inputName: config, DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: xpath config] ]]'. FOUND object: org.orbeon.oxf.processor.transformer.XPathProcessor$Config@1ee3c772
2017-06-20 03:10:45,253 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.generator.RequestGenerator, data, class org.orbeon.oxf.processor.transformer.XPathProcessor]: READING.
2017-06-20 03:10:45,262 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: http://www.orbeon.org/oxf/xml/url validation completed in 11
2017-06-20 03:10:45,272 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: oxf:/ops/xforms/xforms-server-request.rng validation completed in 27
2017-06-20 03:10:45,272 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "481", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "xforms", "message": "ajax with update events", "uuid": "159e95b56510212455afe986bcc5b20ff7a11466"}
2017-06-20 03:10:45,273 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "481", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "xforms", "message": "before document lock", "uuid": "159e95b56510212455afe986bcc5b20ff7a11466"}
2017-06-20 03:10:45,274 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "481", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "xforms", "message": "Unknown form document requested."}
2017-06-20 03:10:45,274 - INFO  org.orbeon.oxf.xforms.processor.XFormsServer$1 readImpl: Unknown form document requested.
2017-06-20 03:10:45,275 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: oxf:/ops/xforms/xforms-server-response.rng validation completed in 32
2017-06-20 03:10:45,275 - INFO  org.orbeon.oxf.pipeline.InitUtils$ runProcessor: /xforms-server - Timing: 50
2017-06-20 03:10:45,276 - DEBUG org.orbeon.oxf.util.NetUtils deleteFileItem: deleting temporary request-scoped file upon session destruction: /tmp/upload_d7b98b7_15ca680ccd2__7ff6_00000487.tmp
2017-06-20 03:10:45,276 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "481", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "service", "message": "end: handle", "time": "51 ms"}
2017-06-20 03:10:45,474 - WARN  org.orbeon.oxf.fr.FormRunnerAuth$ getCredentialsAsHeadersUseSession: not setting auth headers because username is missing
2017-06-20 03:10:45,475 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "482", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "service", "message": "start: handle", "path": "/xforms-server", "method": "POST"}
2017-06-20 03:10:45,475 - INFO  org.orbeon.oxf.pipeline.InitUtils$$anonfun$runProcessor$1 apply: /xforms-server - Received request
2017-06-20 03:10:45,476 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/pipeline.rng
2017-06-20 03:10:45,476 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /config/prologue-servlet.xpl
2017-06-20 03:10:45,476 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.PipelineProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.PipelineProcessor, 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/xml/schemas/pipeline.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ], CompoundOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.URLGenerator, outputName: data, key: [oxf:/config/prologue-servlet.xpl|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]]]'. FOUND object: org.orbeon.oxf.processor.pipeline.PipelineConfig@1a87a637
2017-06-20 03:10:45,477 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,477 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor, $data, class org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor, inputName: $data, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, outputName: data, key: [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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]]]'. FOUND object: org.orbeon.saxon.tinytree.TinyDocumentImpl@10124000
2017-06-20 03:10:45,478 - DEBUG org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor start: Choose: taking when branch with test: p:get-request-path() = '/xforms-server' or starts-with(p:get-request-path(), '/xforms-server/') at line 25, column 40 of oxf:/config/prologue-servlet.xpl
2017-06-20 03:10:45,478 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/pipeline.rng
2017-06-20 03:10:45,479 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server.xpl
2017-06-20 03:10:45,479 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.PipelineProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.PipelineProcessor, 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/xml/schemas/pipeline.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]], DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: no decorate cfg] ], 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.xpl|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]]]'. FOUND object: org.orbeon.oxf.processor.pipeline.PipelineConfig@59f207c8
2017-06-20 03:10:45,479 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,480 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor, $data, class org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor, inputName: $data, CompoundOutputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, outputName: data, key: [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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]]]'. FOUND object: org.orbeon.saxon.tinytree.TinyDocumentImpl@1b724000
2017-06-20 03:10:45,481 - DEBUG org.orbeon.oxf.processor.pipeline.choose.ConcreteChooseProcessor start: Choose: taking when branch with test: p:get-request-method() = 'POST' and not(starts-with(p:get-request-header('content-type'), 'multipart/form-data')) at line 19, column 40 of oxf:/ops/xforms/xforms-server.xpl
2017-06-20 03:10:45,481 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/processor/serializer/http-serializer-config.rng
2017-06-20 03:10:45,481 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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|000|true|false|false|false|null|null|true|null|[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@223858ee
2017-06-20 03:10:45,482 - DEBUG org.orbeon.oxf.processor.ProcessorImpl findInputLastModified: Last modified: 0
2017-06-20 03:10:45,482 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/processor/converter/standard-text-converter-config.rng
2017-06-20 03:10:45,483 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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|000|true|false|false|false|null|null|true|null|[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@34d6cb8b
2017-06-20 03:10:45,484 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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.orbeon.dom.tree.ConcreteDocument@fa9f4b02 [Document]
2017-06-20 03:10:45,484 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server-response.rng
2017-06-20 03:10:45,484 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.msv.verifier.jarv.SchemaImpl@df6bd802
2017-06-20 03:10:45,485 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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.orbeon.dom.tree.ConcreteDocument@fa9f4b02 [Document]
2017-06-20 03:10:45,486 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /ops/xforms/xforms-server-request.rng
2017-06-20 03:10:45,486 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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-request.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.msv.verifier.jarv.SchemaImpl@fb7b424e
2017-06-20 03:10:45,487 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/request-config.rng
2017-06-20 03:10:45,487 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.generator.RequestGenerator]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.generator.RequestGenerator, 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/xml/schemas/request-config.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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.dom.tree.ConcreteDocument@b741f4db [Document]
2017-06-20 03:10:45,489 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.generator.URLGenerator]: READING.
2017-06-20 03:10:45,489 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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.orbeon.dom.tree.ConcreteDocument@fa9f4b02 [Document]
2017-06-20 03:10:45,490 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/url-generator-config.rng
2017-06-20 03:10:45,490 - DEBUG org.orbeon.oxf.processor.ProcessorImpl 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:/org/orbeon/oxf/xml/schemas/url-generator-config.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[false|true|false|false|false|false]]]]]]'. FOUND object: org.orbeon.msv.verifier.jarv.SchemaImpl@5e0fcf1f
2017-06-20 03:10:45,491 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,491 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, 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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]'. FOUND object: org.orbeon.dom.tree.ConcreteDocument@d44e53c6 [Document]
2017-06-20 03:10:45,492 - DEBUG org.orbeon.oxf.processor.generator.URLGenerator$OXFResourceHandler getValidity: OXF Protocol: Using ResourceManager for key /org/orbeon/oxf/xml/schemas/aggregator.rng
2017-06-20 03:10:45,492 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.validation.MSVValidationProcessor, config, class org.orbeon.oxf.processor.pipeline.AggregatorProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.pipeline.AggregatorProcessor, 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/xml/schemas/aggregator.rng|application/xml|null|000|true|false|false|false|null|null|true|null|[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: aggregate config] ]]]]'. FOUND object: org.orbeon.dom.tree.ConcreteDocument@aac159e4 [Document]
2017-06-20 03:10:45,493 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.generator.DOMGenerator, config, class org.orbeon.oxf.processor.transformer.XPathProcessor]: source cacheable and found for key 'InputCacheKey [class: org.orbeon.oxf.processor.transformer.XPathProcessor, inputName: config, DocKey [ SimpleOutputCacheKey [class: org.orbeon.oxf.processor.generator.DOMGenerator, outputName: data, key: xpath config] ]]'. FOUND object: org.orbeon.oxf.processor.transformer.XPathProcessor$Config@1ee3c772
2017-06-20 03:10:45,493 - DEBUG org.orbeon.oxf.processor.ProcessorImpl readCacheInputAsObject: Cache [data, class org.orbeon.oxf.processor.generator.RequestGenerator, data, class org.orbeon.oxf.processor.transformer.XPathProcessor]: READING.
2017-06-20 03:10:45,504 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: http://www.orbeon.org/oxf/xml/url validation completed in 13
2017-06-20 03:10:45,513 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: oxf:/ops/xforms/xforms-server-request.rng validation completed in 27
2017-06-20 03:10:45,514 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "482", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "xforms", "message": "ajax with update events", "uuid": "159e95b56510212455afe986bcc5b20ff7a11466"}
2017-06-20 03:10:45,514 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "482", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "xforms", "message": "before document lock", "uuid": "159e95b56510212455afe986bcc5b20ff7a11466"}
2017-06-20 03:10:45,515 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "482", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "xforms", "message": "Unknown form document requested."}
2017-06-20 03:10:45,515 - INFO  org.orbeon.oxf.xforms.processor.XFormsServer$1 readImpl: Unknown form document requested.
2017-06-20 03:10:45,516 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: oxf:/ops/xforms/xforms-server-response.rng validation completed in 31
2017-06-20 03:10:45,517 - INFO  org.orbeon.oxf.pipeline.InitUtils$ runProcessor: /xforms-server - Timing: 42
2017-06-20 03:10:45,517 - DEBUG org.orbeon.oxf.util.NetUtils deleteFileItem: deleting temporary request-scoped file upon session destruction: /tmp/upload_d7b98b7_15ca680ccd2__7ff6_00000489.tmp
2017-06-20 03:10:45,517 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "482", "session": "YIx1WD3lajLmsc1Zkcn-kg6", "source": "service", "message": "end: handle", "time": "42 ms"}

Hi Hasim,

Got it, and to ask the obvious question: is it possible that the session for the user expired? For instance, if in your `web.xml` the session timeout is set to 1 hour (the default with Orbeon Forms out-of-the-box), if a user opens a form, then closes her laptop, jumps on a train home, and 2 hours later when she arrives opens her laptop to resume work on the form, she will get a session expired, and this is to be expected.

Alex

Hi Alex,

We don't have any idle time in between load the form and interact with the form.

One point I want to mention here - we are using "http" in local and "https" in DEV.

Is that should be the causes for the issue?
Is there any way, so that Orbeon can access with the HTTPS protocol?
Should we debug Orbeon locally or any server to analyze the issue?

Please suggest. Thanks.

Hasim

Just to clarify the ask. We have HTTPS enabled in our environments. But Orbeon calls itself during transaction. Could that be an issue? We were told that there is a way to configure Orbeon the use HTTP for these internal calls. Could you please suggest how we can do it? Maybe that is the reason for the Security-related error? Is there a way to debug our issue better and get a more detailed error? Thank you, Olena

Ho Olena,

It has been awhile (since about 4.7) that requests made by Orbeon Forms to Orbeon Forms are done "internally"; i.e. they are not going through HTTP or HTTPS. So this shouldn't be a problem. Or are you maybe referring to requests to eXist, if you are using eXist? Or maybe services you've implemented yourself within Orbeon Forms?

Alex

Hi Alex,

As you suggested earlier, we've replaced csio-codes and resource XML within Orbeon Forms.
Could that be an issue?

Looks like Orbeon is sending back a message “Unknown form document requested”.  We can see it in the sources as well as the network traffic.  Can you tell us what this means?
 

Hi Olena,

Often, this happens because of an earlier error in the log. Because of this, the "document" corresponding to the current page was removed from memory on the server, and can't be found anymore. Locally on your machine, could you try to stop Tomcat, remove the `orbeon.log`, reproduce the problem, and attach the `orbeon.log` to your response?

Alex

Hi Alex,
I included the following Orbeon logs, which came directly from the server.  The logs are edited so they would only contain the information you requested.  The file Orbeon1.log contains the logs for the initial render of the UI.  The file Orbeon2.log contains the error that results after an AJAX call from the UI, which is triggered by a field edit.   I also posted the screenshots taken from Chrome Developer Tools. It shows the HTTP Post to the server, as well as the error in the response.  We believe you are correct, the server object has been cleared, thus the second call to the server cannot retrieve any objects.  The question is why.  Hopefully the information attached will help the analysis.

orbeon.zip
Screenshots-Chrome.zip

Hi Olena,

I am not seeing (surprisingly?) any error in the `orbeon.log`. A few questions for you:

1. Do you have any error with any Ajax requests before that 403, for the current page? Based on the screenshot, I don't think this is the case, but would like to confirm.
2. Is this always happening with this page? Are you always getting a 403 on the first Ajax request after loading the page?
3. Is the request returning a 403 getting to Orbeon Forms, or is the 403 returned by something before Orbeon Forms?
4. Are you using the embedding API, or embedding the form yourself in the form? I am asking as I'm surprised not to see a `JSESSIONID` cookie in the Ajax request as shown in the screenshot.

Alex

Alex, please see responses form our Alex (architect) inline:
1. Do you have any error with any Ajax requests before that 403, for the current page? Based on the screenshot, I don't think this is the case, but would like to confirm.

[Alex] No error before the AJAX post, which is initiated in the following line within connection.js
o.conn.send(postData || '');

2. Is this always happening with this page? Are you always getting a 403 on the first Ajax request after loading the page?

[Alex] Correct.  It makes no difference which field is modified on the form, or which event is triggered, the AJAX call to the server always fails with HTTP 403.
<error><title>Unknown form document requested.</title></error>

3. Is the request returning a 403 getting to Orbeon Forms, or is the 403 returned by something before Orbeon Forms?

[Alex] This is coming from Orbeon forms as we can correlate it to the following lines in the orbeon2.log file
2017-06-23 09:03:04,069 - INFO  org.orbeon.oxf.logging.LifecycleLogger$ event: event: {"request": "852", "session": "GlSQP0mbTuau1fOUDX8mZs5", "source": "xforms", "message": "Unknown form document requested."}
2017-06-23 09:03:04,069 - INFO  org.orbeon.oxf.xforms.processor.XFormsServer$1 readImpl: Unknown form document requested.
2017-06-23 09:03:04,070 - DEBUG org.orbeon.oxf.processor.validation.MSVValidationProcessor$1 readImpl: oxf:/ops/xforms/xforms-server-response.rng validation completed in 26

4. Are you using the embedding API, or embedding the form yourself in the form? I am asking as I'm surprised not to see a `JSESSIONID` cookie in the Ajax request as shown in the screenshot.

[Alex] Not sure what you mean by embedding API.  The JSESSION cookie is there but called S2_BMSFormsSESSIONID instead, which is visible in the screenshot.  Perhaps there is a configuration that concatenates the JVM Name (S2_BMSForms) with SESSIONID.  In any case, we have found a developer running this code on a local laptop has a Cookie named JSESSIONID, and there is no HTTP 403 (forbidden) error.  However, playing with an HTML edit tool (Fiddler2), we were able to replicate the same scenario (403) by simply modifying the payload.  Specifically we modified one character in the “xxf:uid” element.  This is how we deduced the server object must have been destroyed on the server (where the code generated an HTTP 403) OR the session was destroyed.  

<!DOCTYPE xxf:event-request [<!ENTITY nbsp "&#160;">]>
<xxf:event-request xmlns:xxf="http://orbeon.org/oxf/xml/xforms">
    <xxf:uuid>a314106c3d75323768f0d4d8e155079626f74419</xxf:uuid>
    <xxf:sequence>1</xxf:sequence>
    <xxf:action>
        <xxf:event name="xforms-focus" source-control-id="xf-699"></xxf:event>
    </xxf:action>
</xxf:event-request>

PLease also see this screenshot of a heartbeat, which generates a success (HTTP 200)

Couple more screenshots below. The only difference between the success (top) and failure (bottom) is the payload.  That tells us the server has lost the object.