Announcement

Collapse
No announcement yet.
X
  • Filter
  • Time
Clear All
new posts

    Transport error when my jsp is followed by exportClientData

    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:

    Code:
          isc.RPCManager.send(message,
                              {
                                 target: nitroamosOutput,
                                 methodName: "processOutput"
                              },
                              {
                                 actionURL: "nitroamos.jsp",
                                 timeout: 0
                              });
    Where nitroamos.jsp looks like:
    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);
    %>
    However, if I immediately run this code on completely unrelated data (but in the same tab):
    Code:
          click: function () {
             grid.exportClientData({ exportAs: "ooxml",
                                     exportDisplay: "download",
                                     exportFilename: table.filename
                                   });
          }
    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:

    Code:
    Transport error - HTTP code: 0 for URL: nitroamos.jsp
    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:
    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>[&#x000D;    &quot;/analysis/energy.py&quot;, &#x000D;    [&#x000D;        &quot;-input.inputStructure&quot;, &#x000D;        62&#x000D;    ], &#x000D;    [&#x000D;        &quot;--subset&quot;, &#x000D;        &quot;/&quot;&#x000D;    ], &#x000D;    [&#x000D;        &quot;--crosetta&quot;, &#x000D;        &quot;&quot;&#x000D;    ]&#x000D;]</data><form>{&#x000D;    &quot;subset&quot;:&quot;/&quot;, &#x000D;    &quot;optimization_energyModel&quot;:&quot;EnergyModelType.Standard&quot;, &#x000D;    &quot;optimization_partition&quot;:&quot;sidechain&quot;, &#x000D;    &quot;shortcut_crosetta&quot;:&quot;crosetta&quot;, &#x000D;    &quot;shortcut_wtBias&quot;:&quot;&quot;, &#x000D;    &quot;useCallback&quot;:false, &#x000D;    &quot;optimization_siteDistanceMax&quot;:15, &#x000D;    &quot;shortcut_solvation&quot;:false, &#x000D;    &quot;input_inputStructure&quot;:{&#x000D;        &quot;source&quot;:&quot;structureDS&quot;, &#x000D;        &quot;ID&quot;:62, &#x000D;        &quot;filename&quot;:&quot;2pii_process.pdb&quot;&#x000D;    }, &#x000D;    &quot;input_detectSymmetry&quot;:false, &#x000D;    &quot;job_dryrun&quot;:false, &#x000D;    &quot;shortcut_solubility&quot;:false&#x000D;}</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
    Last edited by nitroamos; 30 May 2014, 09:23. Reason: add version info

    #2
    HTTP 0 is a bogus status code for the browser to report to SmartClient. Also, the first request uses an XMLHttpRequest and the second a different approach - as far as SmartClient is concerned, these are completely unconnected. So this strongly suggests some kind of browser bug..

    What browser(s) do this?

    Can you reproduce it using any other client machine?

    What about a machine on a different network?

    Comment


      #3
      Browsers tested on my intranet:
      Chrome 35.0.1916.114
      Safari 6.1.4 (8537.76.4)
      Firefox 29.0.1

      I confirmed it occurs on an Amazon EC2 server using two different clients (OSX 10.8 and OSX 10.9).

      I can reproduce this error on every configuration I've tested.

      Comment


        #4
        All 3 browsers return HTTP code 0?? We've never seen that with any browser but Windows IE.

        Does this reproduce for you on a Windows machine? It's important to try a true Windows machine, and not a Parallels VM or similar.

        Comment


          #5
          Yes, all instances for this error appear the same (i.e. HTTP code 0).

          We have a Windows Server 2008 desktop. Chrome does produce the error there, but Internet Explorer 9 and 11 do not produce the error (nor any hint of trouble in the SmartClient logs).

          Comment


            #6
            OK, well this really really makes no sense as we previously noted (you're saying a request that involves using a hidden iframe for a download somehow interferes with a previous xmlHttpRequest..), and we have no further speculation as to a cause.

            At this point, we need to be able to run it and see the problem. If you think you've really isolated the cause to a slow RPCRequest and a large export, you should be able to put that together as a standalone example easily. We would recommend just using Thread.sleep() as a means of making the first request take a long time.

            Comment


              #7
              Ok, here's a simplified test. All you need to do to replicate is click the button, and the warning appears instantly.

              This particular test was done on Chrome 35, OSX 10.8.5, Apache Tomcat 7.0.50.

              Let me know if I'm missing anything...
              Attached Files

              Comment


                #8
                Just to reassure you - we are reproducing the problem on our end and are looking into it. We'll let you know when we get to the bottom of it.

                Regards
                Isomorphic Software

                Comment


                  #9
                  Well we've identified the problem. The best way to work around this for now is to set "downloadToNewWindow" to true on your export request.
                  We're looking into the best way to handle this more gracefully by default.

                  Regards
                  Isomorphic Software

                  Comment


                    #10
                    Thanks for looking into this! No, I didn't think you'd forgotten.

                    I'm happy to wait for the correct solution, but it doesn't seem like your suggestion works in my case. Did you mean like this (diff on test.js):

                    Code:
                    *** 53,58 ****
                               grid.exportClientData({ exportAs: "ooxml",
                                                       exportDisplay: "download",
                    !                                  exportFilename: table.filename,
                    !                                  downloadToNewWindow:true
                                                     });
                               console.log("### done");
                    --- 53,57 ----
                               grid.exportClientData({ exportAs: "ooxml",
                                                       exportDisplay: "download",
                    !                                  exportFilename: table.filename
                                                     });
                               console.log("### done");

                    Comment


                      #11
                      We've made a change now to address this issue (9.1p and 10.0d branches). Please try the next nightly build (June 7 or above), with your original test case and let us know if you continue to have problems with it.

                      Regards
                      Isomorphic Software

                      Comment


                        #12
                        Your fix works for the problem as I described it. Thanks for your timely responses and fix!!!

                        However, I've discovered a variant of the same problem. The same test files as before are sufficient. To reproduce the problem, click the button, and simply send the browser window to another URL (e.g. clicking a bookmark on my browser window's toolbar) before the jsp completes. The window successfully moves to the new URL, but the same warning message briefly flashes on the window as a parting farewell.

                        I should note the warning may not appear if the window switches too quickly. The warning appears more consistently when running the test on a remove server than on localhost.

                        Of course if the user is going to a new URL, the warning has no impact on their workflow. However, if the user sees it, they might get worried.

                        Comment


                          #13
                          Hello Isomorphic --

                          Have you been able to reproduce the additional issue I described?

                          Comment

                          Working...
                          X