I've finally found a way to deterministically reproduce this error. I'm using "v9.1p_2014-05-23/Pro Deployment", but I believe it was the same error I had been seeing in v9.0 too.
I've got code which runs a .jsp on my server:
Where nitroamos.jsp looks like:
However, if I immediately run this code on completely unrelated data (but in the same tab):
The exportClientData is expected to take ~30 seconds to complete, but when it does (and it's completely successful) the following error pops up in the tab:
which destroys the RPC (my methodName never gets called). Both of these pieces work just fine if they're run separately or in the other order (the export and then the RPC).
Am I doing something wrong? Or is my Tomcat server configured incorrectly (I mostly use default settings everywhere)? I'm not using security/authentication for this test.
Here's what I'm seeing in the logs over the relevant interval. Yes, the SmartClient time stamps appears to be ~27 seconds ahead of the Catalina time stamps, but I'm confident these intervals align because of how I collected them.
In the SmartClient log:
In the Catalina log:
In the access log:
I've got code which runs a .jsp on my server:
Code:
isc.RPCManager.send(message, { target: nitroamosOutput, methodName: "processOutput" }, { actionURL: "nitroamos.jsp", timeout: 0 });
Code:
<%@ page import="java.util.*" %> <%@ page import="java.io.*" %> <%@ page import="org.apache.commons.exec.*" %> <%@ page import="org.apache.commons.io.*" %> <%@ page import="com.isomorphic.rpc.*" %> <%@ page import="com.isomorphic.datasource.*" %> <% RPCManager rpc; try { // instantiate the RPCManager that parses the encoded data sent by the client rpc = new RPCManager(request, response, out); } catch (ClientMustResubmitException cmre) { // Workaround IE bug - see the RPC API docs for a more detailed explanation return; } Map<String,Object> data = (Map<String,Object>)rpc.getData(); //expensive calculation which takes several minutes to complete rpc.send(msg); %>
Code:
click: function () { grid.exportClientData({ exportAs: "ooxml", exportDisplay: "download", exportFilename: table.filename }); }
Code:
Transport error - HTTP code: 0 for URL: nitroamos.jsp
Am I doing something wrong? Or is my Tomcat server configured incorrectly (I mostly use default settings everywhere)? I'm not using security/authentication for this test.
Here's what I'm seeing in the logs over the relevant interval. Yes, the SmartClient time stamps appears to be ~27 seconds ahead of the Catalina time stamps, but I'm confident these intervals align because of how I collected them.
In the SmartClient log:
Code:
09:21:32.203:MMV2:DEBUG:EventHandler:mousing over [Canvas ID:isc_CenteredTitleWindow_1_statusBar] 09:21:32.235:MMV5:DEBUG:EventHandler:mousing out of [Canvas ID:isc_CenteredTitleWindow_1_statusBar] mousing over [Layout ID:isc_CenteredTitleWindow_1_body] 09:21:32.252:MMV7:DEBUG:EventHandler:mousing out of [Layout ID:isc_CenteredTitleWindow_1_body] mousing over [HLayout ID:isc_HLayout_2] 09:21:32.368:MMV4:DEBUG:EventHandler:mousing out of [HLayout ID:isc_HLayout_2] mousing over [Button ID:isc_Button_32] 09:21:32.996:MDN1:INFO:EventHandler:Target Canvas for event 'mousedown': [Button ID:isc_Button_32] 09:21:32.997:MDN1:INFO:nativeFocus:isc_Button_32:about to call native focus() Button.setFocus(newState=>true, reason=>"focus on mousedown") @ ISC_Core.js:57454:75 Button.focus(reason=>"focus on mousedown") @ ISC_Core.js:57522:10 EventHandler.doHandleMouseDown(DOMevent=>[object MouseEvent], syntheticEvent=>undef) @ ISC_Core.js:30526:20 EventHandler.observation() @ ISC_Core.js:6763:68 [c]EventHandler.handleMouseDown(DOMevent=>[object MouseEvent], syntheticEvent=>undef) @ ISC_Core.js:30390:26 [c]EventHandler.dispatch(handler=>[c]EventHandler.handleMouseDown(), event=>[object MouseEvent]) @ ISC_Core.js:34932:34 HTMLDocument.eval(event=>[object MouseEvent]) @ [no file]:3:127 09:21:32.998:FCS2:DEBUG:nativeFocus:onfocus fired on: [Button ID:isc_Button_32] 09:21:33.001:MDN1:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[Button ID:isc_Button_32]' has handler: Canvas.prepareForDragging() 09:21:33.001:MDN1:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[HLayout ID:isc_HLayout_2]' has handler: Canvas.prepareForDragging() 09:21:33.002:MDN1:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[Layout ID:isc_CenteredTitleWindow_1_body]' has handler: Canvas.prepareForDragging() 09:21:33.002:MDN1:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[CenteredTitleWindow ID:isc_CenteredTitleWindow_1]' has handler: Canvas.prepareForDragging() 09:21:33.002:MDN1:DEBUG:EventHandler:Event 'prepareForDragging' bubbled to top 09:21:33.002:MDN1:DEBUG:dragDrop:No dragTarget, not dragging 09:21:33.003:MDN1:DEBUG:EventHandler:Event 'mouseDown' bubbled to top 09:21:33.166:MUP3:INFO:EventHandler:Target Canvas for event 'mouseup': [Button ID:isc_Button_32] 09:21:33.170:MUP3:DEBUG:EventHandler:Event 'mouseUp' bubbled to top 09:21:33.181:MUP3:INFO:RPCManager:sendQueue called with no current queue, ignoring 09:21:33.193:MUP3:DEBUG:Offline:get() with key: userProfile item is: "{\r "email":"amosa@nitroamos.com", \r ..."[84]: 0ms 09:21:33.195:MUP3:INFO:RPCManager:sendQueue[11]: 1 RPCRequest(s); transport: xmlHttpRequest; target: nitroamos.jsp?isc_rpc=1&isc_v=v9.1p_2014-05-23&isc_xhr=1 09:21:33.195:MUP3:WARN:Log:Unexpected failure to find stack entry logging timing data: description: 'Marshall and send request', type: start 09:21:33.199:MUP3:DEBUG:RPCManager:XMLHttpRequest POST to nitroamos.jsp?isc_rpc=1&isc_v=v9.1p_2014-05-23&isc_xhr=1 contentType: application/x-www-form-urlencoded; charset=UTF-8 with body -->isc_tnum=11&_transaction=<transaction xmlns:xsi="http://www.w3.org/2000/10/XMLSchema-instance" xsi:type="xsd:Object"><transactionNum xsi:type="xsd:long">11</transactionNum><operations xsi:type="xsd:List"><elem xsi:type="xsd:Object"><description>2pii_process.pdb</description><data>[
 "/analysis/energy.py", 
 [
 "-input.inputStructure", 
 62
 ], 
 [
 "--subset", 
 "/"
 ], 
 [
 "--crosetta", 
 ""
 ]
]</data><form>{
 "subset":"/", 
 "optimization_energyModel":"EnergyModelType.Standard", 
 "optimization_partition":"sidechain", 
 "shortcut_crosetta":"crosetta", 
 "shortcut_wtBias":"", 
 "useCallback":false, 
 "optimization_siteDistanceMax":15, 
 "shortcut_solvation":false, 
 "input_inputStructure":{
 "source":"structureDS", 
 "ID":62, 
 "filename":"2pii_process.pdb"
 }, 
 "input_detectSymmetry":false, 
 "job_dryrun":false, 
 "shortcut_solubility":false
}</form><files xsi:type="xsd:List"></files><parent xsi:type="xsd:long">45</parent><username>amos</username></elem></operations></transaction>&protocolVersion=1.0<-- 09:21:33.202:MUP3:WARN:Log:Unexpected failure to find stack entry logging timing data: description: 'Marshall and send request', type: end 09:21:33.202:MUP3:WARN:Log:Unexpected failure to find stack entry logging timing data: description: 'Client processing', type: end 09:21:33.202:MUP3:DEBUG:EventHandler:Event 'click' bubbled to top 09:21:33.203:MUP3[E]:DEBUG:EventHandler:firing threadExitActions: [ anonymous() ] 09:21:33.203:MUP3[E]:DEBUG:listPolicy:stretchResize for isc_VLayout_4 with totalSize: 353, desired sizes: , calculated sizes: 09:21:33.203:MUP3[E]:DEBUG:listPolicy:stretchResize for isc_VLayout_4 with totalSize: 353, desired sizes: , calculated sizes: 09:21:33.218:TMR6:DEBUG:drawing:clearRedrawQueue: [Canvas ID:isc_CenteredTitleWindow_1_statusBar] 09:21:33.222:TMR6:INFO:drawing:isc_CenteredTitleWindow_1_statusBar:_updateHTML(): redrawing 09:21:33.224:TMR6:DEBUG:drawing:isc_CenteredTitleWindow_1_statusBar:Redraw() - Total time to redraw in DOM:2 09:21:34.620:MMV5:DEBUG:EventHandler:mousing out of [Button ID:isc_Button_32] mousing over [HLayout ID:isc_HLayout_2] 09:21:34.669:MMV9:DEBUG:EventHandler:mousing out of [HLayout ID:isc_HLayout_2] mousing over [SectionStack ID:isc_SectionStack_1] 09:21:34.703:MMV2:DEBUG:EventHandler:mousing out of [SectionStack ID:isc_SectionStack_1] 09:21:34.720:MMV4:DEBUG:EventHandler:mousing over [SectionHeader ID:isc_SectionHeader_8] 09:21:34.819:MMV1:DEBUG:EventHandler:mousing out of [SectionHeader ID:isc_SectionHeader_8] mousing over [Button ID:isc_Button_13] 09:21:35.885:MDN4:INFO:EventHandler:Target Canvas for event 'mousedown': [Button ID:isc_Button_13] 09:21:35.887:MDN4:INFO:nativeFocus:isc_Button_13:about to call native focus() Button.setFocus(newState=>true, reason=>"focus on mousedown") @ ISC_Core.js:57454:75 Button.focus(reason=>"focus on mousedown") @ ISC_Core.js:57522:10 EventHandler.doHandleMouseDown(DOMevent=>[object MouseEvent], syntheticEvent=>undef) @ ISC_Core.js:30526:20 EventHandler.observation() @ ISC_Core.js:6763:68 [c]EventHandler.handleMouseDown(DOMevent=>[object MouseEvent], syntheticEvent=>undef) @ ISC_Core.js:30390:26 [c]EventHandler.dispatch(handler=>[c]EventHandler.handleMouseDown(), event=>[object MouseEvent]) @ ISC_Core.js:34932:34 HTMLDocument.eval(event=>[object MouseEvent]) @ [no file]:3:127 09:21:35.887:BLR5:DEBUG:nativeFocus:onblur fired on: [Button ID:isc_Button_32] 09:21:35.887:FCS6:DEBUG:nativeFocus:onfocus fired on: [Button ID:isc_Button_13] 09:21:35.895:MDN4:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[Button ID:isc_Button_13]' has handler: Canvas.prepareForDragging() 09:21:35.895:MDN4:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[VLayout ID:isc_VLayout_3]' has handler: Canvas.prepareForDragging() 09:21:35.895:MDN4:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[VLayout ID:isc_VLayout_1]' has handler: Canvas.prepareForDragging() 09:21:35.895:MDN4:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[SectionStack ID:isc_SectionStack_0]' has handler: Canvas.prepareForDragging() 09:21:35.896:MDN4:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[Layout ID:isc_CenteredTitleWindow_0_body]' has handler: Canvas.prepareForDragging() 09:21:35.896:MDN4:DEBUG:EventHandler:Bubbling event 'prepareForDragging', target '[CenteredTitleWindow ID:isc_CenteredTitleWindow_0]' has handler: Canvas.prepareForDragging() 09:21:35.896:MDN4:DEBUG:EventHandler:Event 'prepareForDragging' bubbled to top 09:21:35.896:MDN4:DEBUG:dragDrop:No dragTarget, not dragging 09:21:35.897:MDN4:DEBUG:EventHandler:Event 'mouseDown' bubbled to top 09:21:36.063:MUP7:INFO:EventHandler:Target Canvas for event 'mouseup': [Button ID:isc_Button_13] 09:21:36.068:MUP7:DEBUG:EventHandler:Event 'mouseUp' bubbled to top 09:21:36.076:MUP7:INFO:export:isc_ListGrid_1:starting export chunking process - 1401466896076 09:21:36.343:MUP7:INFO:export:isc_ListGrid_1:processed 50 rows - starting next chunk - 0.267 09:21:36.347:MUP7:DEBUG:EventHandler:Event 'click' bubbled to top 09:21:36.660:TMR9:INFO:export:isc_ListGrid_1:processed 100 rows - starting next chunk - 0.317 09:21:36.990:TMR0:INFO:export:isc_ListGrid_1:processed 150 rows - starting next chunk - 0.329 09:21:37.325:TMR1:INFO:export:isc_ListGrid_1:processed 200 rows - starting next chunk - 0.336 09:21:37.699:TMR2:INFO:export:isc_ListGrid_1:processed 250 rows - starting next chunk - 0.373 09:21:38.090:TMR3:INFO:export:isc_ListGrid_1:processed 300 rows - starting next chunk - 0.392 09:21:38.582:TMR4:INFO:export:isc_ListGrid_1:processed 350 rows - starting next chunk - 0.492 09:21:39.059:TMR5:INFO:export:isc_ListGrid_1:processed 400 rows - starting next chunk - 0.477 09:21:39.604:TMR6:INFO:export:isc_ListGrid_1:processed 450 rows - starting next chunk - 0.545 09:21:40.281:TMR7:INFO:export:isc_ListGrid_1:processed 500 rows - starting next chunk - 0.677 09:21:40.958:TMR8:INFO:export:isc_ListGrid_1:processed 550 rows - starting next chunk - 0.677 09:21:41.616:TMR1:INFO:export:isc_ListGrid_1:processed 600 rows - starting next chunk - 0.658 09:21:42.282:TMR2:INFO:export:isc_ListGrid_1:processed 650 rows - starting next chunk - 0.666 09:21:42.923:TMR3:INFO:export:isc_ListGrid_1:processed 700 rows - starting next chunk - 0.641 09:21:43.584:TMR4:INFO:export:isc_ListGrid_1:processed 750 rows - starting next chunk - 0.661 09:21:44.234:TMR5:INFO:export:isc_ListGrid_1:processed 800 rows - starting next chunk - 0.65 09:21:44.872:TMR6:INFO:export:isc_ListGrid_1:processed 850 rows - starting next chunk - 0.637 09:21:45.530:TMR7:INFO:export:isc_ListGrid_1:processed 900 rows - starting next chunk - 0.659 09:21:46.202:TMR8:INFO:export:isc_ListGrid_1:processed 950 rows - starting next chunk - 0.672 09:21:46.862:TMR9:INFO:export:isc_ListGrid_1:processed 1000 rows - starting next chunk - 0.66 09:21:47.505:TMR0:INFO:export:isc_ListGrid_1:processed 1050 rows - starting next chunk - 0.643 09:21:48.160:TMR1:INFO:export:isc_ListGrid_1:processed 1100 rows - starting next chunk - 0.655 09:21:48.801:TMR2:INFO:export:isc_ListGrid_1:processed 1150 rows - starting next chunk - 0.641 09:21:49.699:TMR3:INFO:export:isc_ListGrid_1:processed 1200 rows - starting next chunk - 0.898 09:21:50.592:TMR4:INFO:export:isc_ListGrid_1:processed 1250 rows - starting next chunk - 0.893 09:21:51.254:TMR5:INFO:export:isc_ListGrid_1:processed 1300 rows - starting next chunk - 0.662 09:21:51.279:BLR6:DEBUG:nativeFocus:onblur fired on: [Button ID:isc_Button_13] 09:21:51.917:TMR7:INFO:export:isc_ListGrid_1:processed 1350 rows - starting next chunk - 0.663 09:21:52.817:TMR8:INFO:export:isc_ListGrid_1:processed 1400 rows - starting next chunk - 0.9 09:21:53.698:TMR9:INFO:export:isc_ListGrid_1:processed 1450 rows - starting next chunk - 0.881 09:21:54.378:TMR0:INFO:export:isc_ListGrid_1:processed 1500 rows - starting next chunk - 0.68 09:21:55.048:TMR1:INFO:export:isc_ListGrid_1:processed 1550 rows - starting next chunk - 0.67 09:21:55.729:TMR2:INFO:export:isc_ListGrid_1:processed 1600 rows - starting next chunk - 0.681 09:21:56.560:TMR3:INFO:export:isc_ListGrid_1:processed 1650 rows - starting next chunk - 0.831 09:21:57.251:TMR4:INFO:export:isc_ListGrid_1:finished processing 1689 rows - about to export - 1401466917251 09:21:57.372:TMR4:INFO:RPCManager:sendQueue[12]: 1 RPCRequest(s); transport: hiddenFrame; target: http://tower.nitroamos.com:8080/nitroamos/isomorphic/IDACall?isc_rpc=1&isc_v=v9.1p_2014-05-23&isc_tnum=12 09:21:57.373:TMR4:WARN:Log:Unexpected failure to find stack entry logging timing data: description: 'Marshall and send request', type: start 09:22:37.752:TMR4:INFO:RPCManager:Sending data via frame isc_HiddenFrame_2 to server at URL: http://tower.nitroamos.com:8080/nitroamos/isomorphic/IDACall?isc_rpc=1&isc_v=v9.1p_2014-05-23&isc_tnum=12 09:22:37.813:TMR4:DEBUG:drawing:isc_HiddenFrame_2_commCanvas:inserting HTML at top level 09:22:43.370:TMR4:INFO:HiddenFrame:isc_HiddenFrame_2:Form submitted to server 09:22:43.370:TMR4:WARN:Log:Unexpected failure to find stack entry logging timing data: description: 'Marshall and send request', type: end 09:22:43.370:TMR4:WARN:Log:Unexpected failure to find stack entry logging timing data: description: 'Client processing', type: end 09:22:43.434:FCS5:DEBUG:nativeFocus:onfocus fired on: [Button ID:isc_Button_13] 09:22:43.452:BLR6:DEBUG:nativeFocus:onblur fired on: [Button ID:isc_Button_13] 09:22:43.601:XRP7:INFO:RPCManager:transaction 11 arrived after 70399ms 09:22:43.602:XRP7:DEBUG:RPCManager:RPC request to: nitroamos.jsp returned with http response code: 0. Response text: 09:22:43.602:XRP7:DEBUG:RPCManager:Result string for transaction 11: [ {response: Obj} ] 09:22:43.603:XRP7:WARN:RPCManager:xmlHttpRequest.getAllResponseHeaders() returned null 09:22:43.603:XRP7:INFO:RPCManager:rpcResponse(custom)[rpc]: result: object[status=unknown] 09:22:43.613:XRP7:INFO:destroys:isc_IButton_0:destroy() IButton._logDestroy(synchronous=>true, indirectDestroy=>undef) @ ISC_Core.js:46691:65 IButton.destroy(indirectDestroy=>undef, b=>undef, c=>undef, d=>undef, e=>undef) @ ISC_Core.js:46518:10 [a][c]IButton.invokeSuper(clazz=>null, methodName=>"destroy", a=>undef, b=>undef, c=>undef, d=>undef, e=>undef, f=>undef, g=>undef, h=>undef, i=>undef, j=>undef, lastArg=>undef) @ ISC_Core.js:5949:44 [a][c]IButton.Super(methodName=>"destroy", args=>[object Arguments], nativeArguments=>undef) @ ISC_Core.js:5767:21 IButton.destroy() @ ISC_Foundation.js:4221:17 Toolbar.setButtons(newButtons=>Array[1]) @ ISC_Foundation.js:12731:25 Dialog.setToolbarButtons(newButtons=>Array[1]) @ ISC_Containers.js:2381:22 Dialog.setButtons(newButtons=>Array[1]) @ ISC_Containers.js:2366:17 [a]Dialog.setProperties() @ ISC_Core.js:7331:29 [a]Dialog.showMessage(newMessage=>"Transport error - HTTP code: 0 for URL: ..."[49], properties=>Obj{title:Warning}) @ ISC_Containers.js:8024:14 09:22:43.627:XRP7:INFO:clickMask:showing click mask, action: [object Object], autoHide false , ID: isc_globalWarn, focusCanvas: null 09:22:43.638:XRP7:INFO:resize:isc_EH_screenSpan:resize of drawn component: new width/height: 1297,857, old width/height: 1,1, delta width/height: 1296,856 ScreenSpan.resizeBy(deltaX=>1296, deltaY=>856, animating=>undef, suppressHandleUpdate=>undef, reason=>undef) @ ISC_Core.js:53130:28 ScreenSpan.resizeTo(width=>1297, height=>857, animating=>undef, suppressHandleUpdate=>undef, reason=>undef) @ ISC_Core.js:53525:17 ScreenSpan.fitToScreen() @ ISC_Core.js:63265:14 ScreenSpan.show(a=>undef, b=>undef, c=>undef, d=>undef) @ ISC_Core.js:63223:14 [c]EventHandler.showScreenSpan(mask=>Obj{ID:isc_globalWarn}) @ ISC_Core.js:37154:10 [c]EventHandler.showClickMask(clickAction=>Obj, mode=>"hard", unmaskedTargets=>Array[13], maskID=>"isc_globalWarn") @ ISC_Core.js:36538:18 Dialog.showClickMask(clickAction=>Obj, mode=>false, unmaskedTargets=>Array[13]) @ ISC_Core.js:48961:27 Dialog.show(a=>undef, b=>undef, c=>undef, d=>undef) @ ISC_Containers.js:2975:18 [a]Dialog.showMessage(newMessage=>"Transport error - HTTP code: 0 for URL: ..."[49], properties=>Obj{title:Warning}) @ ISC_Containers.js:8055:14 <anonymous>(message=>"Transport error - HTTP code: 0 for URL: ..."[49], messageType=>"warn", callback=>undef, properties=>Obj{title:Warning}) @ ISC_Containers.js:8129:21 09:22:43.648:XRP7:DEBUG:Page:setEvent(resize): action => [ScreenSpan ID:isc_EH_screenSpan] 09:22:43.654:XRP7:DEBUG:drawing:isc_globalWarn:inserting HTML at top level 09:22:43.657:XRP7:INFO:drawing:isc_globalWarn_body:inserting HTML into parent: [Dialog ID:isc_globalWarn] 09:22:43.660:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_body with totalSize: 28, desired sizes: 1,42, calculated sizes: 1,42 09:22:43.664:XRP7:INFO:drawing:isc_globalWarn_messageStack:inserting HTML into parent: [Layout ID:isc_globalWarn_body] 09:22:43.666:XRP7:DEBUG:Label:isc_globalWarn_messageLabel:setRect: {left: null, top: null, width: "100%", height: null} 09:22:43.667:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_messageStack with totalSize: 294, desired sizes: 32,324, calculated sizes: 32,324 09:22:43.672:XRP7:INFO:drawing:isc_globalWarn_messageIcon:inserting HTML into parent: [HStack ID:isc_globalWarn_messageStack] 09:22:43.677:XRP7:INFO:drawing:isc_globalWarn_messageLabel:inserting HTML into parent: [HStack ID:isc_globalWarn_messageStack] 09:22:43.690:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_messageStack with totalSize: 294, desired sizes: 32,324, calculated sizes: 32,324 09:22:43.699:XRP7:INFO:drawing:isc_globalWarn_toolbar:inserting HTML into parent: [Layout ID:isc_globalWarn_body] 09:22:43.701:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_toolbar with totalSize: 0, desired sizes: 75, calculated sizes: 75 09:22:43.705:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_toolbar with totalSize: 0, desired sizes: 75, calculated sizes: 75 09:22:43.711:XRP7:INFO:drawing:isc_IButton_0:inserting HTML into parent: [Toolbar ID:isc_globalWarn_toolbar] 09:22:43.733:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_body with totalSize: 28, desired sizes: 47,42, calculated sizes: 47,42 09:22:43.746:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn with totalSize: 55, desired sizes: 20,111, calculated sizes: 20,111 09:22:43.751:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn with totalSize: 55, desired sizes: 20,111, calculated sizes: 20,111 09:22:43.755:XRP7:INFO:drawing:isc_globalWarn_header:inserting HTML into parent: [Dialog ID:isc_globalWarn] 09:22:43.757:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_header with totalSize: 414, desired sizes: *,15, calculated sizes: 399,15 09:22:43.761:XRP7:DEBUG:listPolicy:stretchResize for isc_globalWarn_header with totalSize: 414, desired sizes: *,15, calculated sizes: 399,15 09:22:43.766:XRP7:INFO:drawing:isc_globalWarn_headerLabelParent_label:inserting HTML into parent: [HLayout ID:isc_globalWarn_header] 09:22:43.769:XRP7:INFO:drawing:isc_globalWarn_headerLabelParent:inserting HTML into parent: [HLayout ID:isc_globalWarn_header] 09:22:43.769:XRP7:INFO:drawing:isc_globalWarn_headerLabelParent:drawChildren(): 1 children 09:22:43.769:XRP7:DEBUG:HStack:isc_HStack_3:setRect: {left: null, top: null, width: "100%", height: "100%"} 09:22:43.772:XRP7:INFO:drawing:isc_HStack_3:inserting HTML into parent: [StatefulCanvas ID:isc_globalWarn_headerLabelParent] 09:22:43.772:XRP7:DEBUG:listPolicy:stretchResize for isc_HStack_3 with totalSize: 399, desired sizes: 10, calculated sizes: 10 09:22:43.774:XRP7:INFO:drawing:isc_globalWarn_headerLabel:inserting HTML into parent: [HStack ID:isc_HStack_3] 09:22:43.781:XRP7:DEBUG:listPolicy:stretchResize for isc_HStack_3 with totalSize: 399, desired sizes: 48, calculated sizes: 48 09:22:43.783:XRP7:INFO:drawing:isc_globalWarn_headerLabelParent:drawPeers(): 1 peers 09:22:43.787:XRP7:INFO:drawing:isc_globalWarn_closeButton:inserting HTML into parent: [HLayout ID:isc_globalWarn_header] 09:22:43.796:XRP7:DEBUG:enforceScrollSize:isc_globalWarn_header:enforcing scroll size:1,1 09:22:43.802:XRP7:DEBUG:enforceScrollSize:isc_globalWarn_header:enforcing scroll size:1,1 09:22:43.824:XRP7:DEBUG:Page:setEvent(resize): action => [Dialog ID:isc_globalWarn] 09:22:43.827:XRP7:INFO:nativeFocus:isc_IButton_0:about to call native focus() IButton.setFocus(newState=>true, reason=>undef) @ ISC_Core.js:57454:75 IButton.focus(reason=>undef) @ ISC_Core.js:57522:10 [a]Dialog.showMessage(newMessage=>"Transport error - HTTP code: 0 for URL: ..."[49], properties=>Obj{title:Warning}) @ ISC_Containers.js:8067:25 <anonymous>(message=>"Transport error - HTTP code: 0 for URL: ..."[49], messageType=>"warn", callback=>undef, properties=>Obj{title:Warning}) @ ISC_Containers.js:8129:21 <anonymous>(message=>"Transport error - HTTP code: 0 for URL: ..."[49], callback=>undef, properties=>undef) @ ISC_Containers.js:8185:9 [c]RPCManager.reportError(errorMessage=>"Transport error - HTTP code: 0 for URL: ..."[49]) @ ISC_DataBinding.js:38382:13 [c]RPCManager.handleError(response=>Obj, request=>Obj) @ ISC_DataBinding.js:37766:22 [c]RPCManager._handleError(response=>Obj, request=>Obj) @ ISC_DataBinding.js:37746:21 [c]RPCManager.performOperationReply(request=>Obj, response=>Obj) @ ISC_DataBinding.js:37593:25 [c]RPCManager._performTransactionReply(transactionNum=>11) @ ISC_DataBinding.js:37486:18 09:22:43.828:XRP7:WARN:RPCManager:Transport error - HTTP code: 0 for URL: nitroamos.jspundefined - response: {operationId: "custom", clientContext: undef, internalClientContext: undef, context: Obj, transactionNum: 11, httpResponseCode: 0, httpResponseText: "", xmlHttpRequest: [object XMLHttpRequest], transport: "xmlHttpRequest", status: -90, clientOnly: undef, httpHeaders: null, isStructured: true, callbackArgs: null, results: Obj, data: "Transport error - HTTP code: 0 for URL: ..."[49], clientTiming: Obj{name:Client processing}, clientTimingStack: Array[2]} 09:22:56.053:FCS9:DEBUG:nativeFocus:onfocus fired on: [IButton ID:isc_IButton_0] 09:23:01.828:BLR0:DEBUG:nativeFocus:onblur fired on: [IButton ID:isc_IButton_0]
In the Catalina log:
Code:
=== 2014-05-30 09:21:06,400 [c-61] INFO RequestContext - URL: '/nitroamos/nitroamos.jsp', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/35.0.1916.114 Safari/537.36': Safari with Accept-Encoding header === 2014-05-30 09:21:06,402 [c-61] DEBUG XML - Parsed XML from (in memory stream): 1ms === 2014-05-30 09:21:06,402 [c-61] DEBUG RPCManager - Processing 1 requests. === 2014-05-30 09:21:06,402 [c-61] DEBUG RPCManager - Request #1 (RPCRequest) data: { ... } === 2014-05-30 09:21:47,536 [c-61] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8 === 2014-05-30 09:22:17,124 [c-52] DEBUG IDACall - Header Name:Value pair: host:tower.nitroamos.com:8080 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: connection:keep-alive === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: content-length:5288918 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: cache-control:max-age=0 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: origin:http://tower.nitroamos.com:8080 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/35.0.1916.114 Safari/537.36 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: dnt:1 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: referer:http://tower.nitroamos.com:8080/nitroamos/ === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip,deflate,sdch === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,en;q=0.8 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - Header Name:Value pair: cookie:JSESSIONID=B6C69C6FAC2ACBD7D5A324D8E6AA0C56; GLog=%7B%0D%20%20%20%20left%3A867%2C%20%0D%20%20%20%20top%3A60%2C%20%0D%20%20%20%20width%3A1163%2C%20%0D%20%20%20%20height%3A1240%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A3%2C%20%0D%20%20%20%20%20%20%20%20sizing%3A3%2C%20%0D%20%20%20%20%20%20%20%20scrolling%3A3%2C%20%0D%20%20%20%20%20%20%20%20ListGrid%3A3%2C%20%0D%20%20%20%20%20%20%20%20redraws%3A3%2C%20%0D%20%20%20%20%20%20%20%20draws%3A3%2C%20%0D%20%20%20%20%20%20%20%20layout%3A3%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A5%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - session exists: B6C69C6FAC2ACBD7D5A324D8E6AA0C56 === 2014-05-30 09:22:17,125 [c-52] DEBUG IDACall - remote user: null === 2014-05-30 09:22:17,126 [c-52] INFO RequestContext - URL: '/nitroamos/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/35.0.1916.114 Safari/537.36': Safari with Accept-Encoding header === 2014-05-30 09:22:17,307 [c-52] DEBUG XML - Parsed XML from (in memory stream): 78ms === 2014-05-30 09:22:17,665 [c-52] DEBUG RPCManager - Processing 1 requests. === 2014-05-30 09:22:17,777 [c-52] DEBUG RPCManager - Request #1 (RPCRequest) data: { appID:"isc_builtin", className:"builtin", methodName:"downloadClientExport", arguments:[ ....[truncated 3635462bytes - to change, set config param RPCManager.maxRequestDebugLength to desired max bytes (in server.properties) - zero disables/negative value allows arbitrary length messages]. === 2014-05-30 09:22:17,777 [c-52] INFO IDACall - Performing 1 operation(s) === 2014-05-30 09:22:17,778 [c-52] DEBUG RPCDMI - appConfig: isc.Application.create({ rpcBindings:[ { ID:"builtin", className:"com.isomorphic.rpc.BuiltinRPC", visibleMethods:[ { name:"downloadWSDL" }, { name:"downloadClientContent" }, { name:"downloadClientExport" }, { name:"xmlToJS" }, { name:"uploadProgressCheck" }, { name:"saveFile" }, { name:"appendToFile" }, { name:"loadFile" }, { name:"deleteFile" }, { name:"loadSharedXML" }, { name:"saveSharedXML" }, { name:"getAvailableScriptEngines" }, { name:"devConsoleEvalServerScript" }, { name:"evalJava" }, { name:"getLogNames" }, { name:"getLogEntries" }, { name:"clearLogEntries" }, { name:"getLogThresholds" }, { name:"setLogThreshold" }, { name:"setTemporaryLogThreshold" }, { name:"revertTemporaryLogThresholds" }, { name:"getPdfObject" }, { name:"exportImage" }, { name:"areServerTimingsTracked" }, { name:"trackServerTimings" } ] }, { ID:"builtin_tools", className:"com.isomorphic.tools.BuiltinRPC", visibleMethods:[ { name:"getDataSourceFromTable" }, { name:"getDataSourceJSONFromTable" }, { name:"getDataSourceFromHibernateMapping" }, { name:"getDataSourceJSONFromHibernateMapping" }, { name:"getTables" }, { name:"getFieldsFromTable" }, { name:"getBeanFields" }, { name:"getHibernateBeans" }, { name:"getDatabaseProductNameAndVersion" }, { name:"getDatabaseTableTypes" }, { name:"setAttributes" }, { name:"clearAttributes" }, { name:"getAttributes" }, { name:"getAttribute" }, { name:"getDataSourceConfigFromJavaClass" }, { args:"cName", language:"groovy", name:"getJavaSource", script:"\n if (!com.isomorphic.auth.DevModeAuthFilter.devModeAuthorized(request)) throw new Exception(\"Not Authorized\"); \n //import org.apache.bcel.Repository;\n\n try {\n return org.apache.bcel.Repository.lookupClass(cName).toString();\n } catch (Throwable e) {\n return \"Unable to reverse engineer class \"+cName+\": \"+e.getMessage();\n }\n " }, { name:"loadDataSource" }, { name:"dsFromXML" }, { name:"dsConfigFromXML" }, { name:"getDefinedDataSources" } ] }, { ID:"builtin_adminconsole", className:"com.isomorphic.tools.AdminConsole", visibleMethods:[ { name:"getDefinedDatabases" }, { name:"testDB" }, { name:"saveDBConfig" }, { name:"setDefaultDB" }, { name:"importDataSources" }, { name:"discoverJNDIDatabases" } ] } ] }) === 2014-05-30 09:22:17,860 [c-52] INFO BuiltinRPC - Export data passed to server: .... === 2014-05-30 09:22:17,880 [c-52] INFO BuiltinRPC - Generating and streaming ooxml file... === 2014-05-30 09:22:20,332 [c-52] DEBUG RPCDMI - rpc returned data
In the access log:
Code:
192.168.1.120 - - [30/May/2014:09:22:16 -0700] "POST /nitroamos/nitroamos.jsp?isc_rpc=1&isc_v=v9.1p_2014-05-23&isc_xhr=1 HTTP/1.1" 200 1403653 192.168.1.120 - - [30/May/2014:09:22:20 -0700] "POST /nitroamos/isomorphic/IDACall?isc_rpc=1&isc_v=v9.1p_2014-05-23&isc_tnum=12 HTTP/1.1" 200 137039
Comment