Debug info for 2 page requests via Firefox: 1. SUCCESSFUL REQUEST (sent by forcing a reload using Shift+F5) 2007-12-10 16:13:46,566 INFO ProcessorService - /xforms-renderer - Received request 2007-12-10 16:13:46,690 INFO ProcessorService - /xforms-renderer - Timing: 124 - Cache hits for cache.main: 27, fault: 13, adds: 12, expirations: 0, success rate: 67% 2007-12-10 16:13:48,607 INFO ProcessorService - /xforms-renderer - Received request 2007-12-10 16:13:48,685 DEBUG XFormsServer - XForms - creating new ContainingDocument (static state object provided). 2007-12-10 16:13:48,685 DEBUG XFormsServer - XForms - dispatching event: xforms-model-construct - mdl - at line 124 of XFormsEventFactory.java 2007-12-10 16:13:48,763 INFO ProcessorService - /xforms-renderer - Received request 2007-12-10 16:13:48,779 INFO ProcessorService - /xforms-renderer - Received request 2007-12-10 16:13:48,794 INFO ProcessorService - /xforms-renderer - Timing: 31 - Cache hits for cache.main: 25, fault: 4, adds: 3, expirations: 0, success rate: 86% 2007-12-10 16:13:48,794 INFO ProcessorService - /xforms-renderer - Timing: 15 - Cache hits for cache.main: 28, fault: 0, adds: 0, expirations: 0, success rate: 100% 2007-12-10 16:13:48,810 DEBUG XFormsServer - XForms - instance loading time for instance 'inst_submission_data' (including handling returned body): 0 2007-12-10 16:13:48,810 DEBUG XFormsServer - XForms - instance loading time for instance 'inst_form_state' (including handling returned body): 0 2007-12-10 16:13:48,810 DEBUG XFormsServer - XForms - instance loading time for instance 'inst_init_data' (including handling returned body): 0 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - building controls state start. 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - building controls state end: 0 ms. 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: xforms-model-construct-done - mdl - at line 139 of XFormsEventFactory.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: xforms-ready - mdl - at line 144 of XFormsEventFactory.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: xforms-refresh - mdl - at line 1816 of XFormsModel.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - performing refresh for model: mdl 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: xforms-valid - xforms-element-72 - at line 27 of XFormsValidEvent.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: xforms-valid - xforms-element-81 - at line 27 of XFormsValidEvent.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: xforms-invalid - xforms-element-90 - at line 27 of XFormsInvalidEvent.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: action 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: dispatch 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: version_num_invalid - mdl - at line 272 of XFormsEventFactory.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: action 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: setvalue 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: dispatch 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - dispatching event: check_input_validity - mdl - at line 272 of XFormsEventFactory.java 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: action 2007-12-10 16:13:48,826 DEBUG XFormsServer - XForms - executing action: setvalue 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: xforms-valid - xforms-element-98 - at line 27 of XFormsValidEvent.java 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: xforms-valid - xforms-element-114·1 - at line 27 of XFormsValidEvent.java 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: xforms-valid - xforms-element-123 - at line 27 of XFormsValidEvent.java 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: xforms-invalid - xforms-element-139·1 - at line 27 of XFormsInvalidEvent.java 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: action 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: dispatch 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: allowable_capitalised_element_invalid - mdl - at line 272 of XFormsEventFactory.java 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: action 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: setvalue 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: dispatch 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: check_input_validity - mdl - at line 272 of XFormsEventFactory.java 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: action 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - executing action: setvalue 2007-12-10 16:13:48,841 DEBUG XFormsServer - XForms - dispatching event: xxforms-ready - mdl - at line 104 of XFormsEventFactory.java 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms - adding document cache dependency for schema: /EASchemaWeb/forms/submission_schema.xsd 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms - annotated document and static state not obtained from cache. 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms - did not find cached static state UUID. 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms - cannot cache dynamic state UUID for resulting document. 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms - evaluating controls start. 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms - evaluating controls end: 0 ms. 2007-12-10 16:13:48,857 DEBUG XFormsServer - XForms resources - creating xhtml:head with combined resources. 2007-12-10 16:13:48,903 INFO ProcessorService - /xforms-renderer - Timing: 296 - Cache hits for cache.main: 50, fault: 16, adds: 6, expirations: 0, success rate: 75% 2007-12-10 16:13:49,730 INFO ProcessorService - /xforms-server/xforms-min.css - Received request 2007-12-10 16:13:49,917 DEBUG XFormsServer - XForms resources - caching not requested, serving directly /xforms-server/xforms-min.css. 2007-12-10 16:13:49,917 INFO ProcessorService - /xforms-server/xforms-min.css - Timing: 187 - Cache hits for cache.main: 7, fault: 5, adds: 5, expirations: 0, success rate: 58% 2007-12-10 16:13:50,041 INFO ProcessorService - /xforms-server/xforms-min.js - Received request 2007-12-10 16:13:50,150 DEBUG XFormsServer - XForms resources - caching not requested, serving directly /xforms-server/xforms-min.js. 2007-12-10 16:13:50,244 INFO ProcessorService - /xforms-server/xforms-min.js - Timing: 203 - Cache hits for cache.main: 7, fault: 0, adds: 0, expirations: 0, success rate: 100% 2007-12-10 16:13:50,431 INFO ProcessorService - /images/xforms/section-opened.png - Received request 2007-12-10 16:13:50,431 INFO ProcessorService - /images/xforms/section-closed.png - Received request 2007-12-10 16:13:50,431 INFO ProcessorService - /images/xforms/section-opened.png - Timing: 0 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2007-12-10 16:13:50,431 INFO ProcessorService - /images/xforms/remove.gif - Received request 2007-12-10 16:13:50,447 INFO ProcessorService - /images/xforms/remove.gif - Timing: 16 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2007-12-10 16:13:50,447 INFO ProcessorService - /ops/images/xforms/help.gif - Received request 2007-12-10 16:13:50,462 INFO ProcessorService - /ops/images/xforms/help.gif - Timing: 15 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2007-12-10 16:13:50,462 INFO ProcessorService - /images/xforms/section-closed.png - Timing: 31 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2007-12-10 16:13:50,478 INFO ProcessorService - /ops/images/xforms/error.gif - Received request 2007-12-10 16:13:50,478 INFO ProcessorService - /ops/images/xforms/calendar.gif - Received request 2007-12-10 16:13:50,493 INFO ProcessorService - /ops/images/xforms/error.gif - Timing: 15 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2007-12-10 16:13:50,509 INFO ProcessorService - /ops/images/xforms/calendar.gif - Timing: 31 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2007-12-10 16:13:50,587 INFO ProcessorService - /ops/images/yui/container/close12_1.gif - Received request 2007-12-10 16:13:50,602 INFO ProcessorService - /ops/images/yui/container/close12_1.gif - Timing: 15 - Cache hits for cache.main: 12, fault: 5, adds: 5, expirations: 0, success rate: 70% 2. UNSUCCESSFUL REQUEST (sent by refreshing the page) 2007-12-10 16:17:16,556 INFO ProcessorService - /xforms-renderer - Received request 2007-12-10 16:17:16,571 INFO ProcessorService - /xforms-renderer - Timing: 15 - Cache hits for cache.main: 28, fault: 0, adds: 0, expirations: 0, success rate: 100%