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