Sven created ZEPPELIN-2071: ------------------------------ Summary: Very slow parsing of large %html output Key: ZEPPELIN-2071 URL: https://issues.apache.org/jira/browse/ZEPPELIN-2071 Project: Zeppelin Issue Type: Bug Components: front-end, Interpreters Affects Versions: 0.7.0 Environment: Ubuntu 16.04, 12 GB RAM Reporter: Sven
*The problem*: open a notebook and run the following cell, which creates a string of length 100k and outputs it via %html in order to execute some javascript on it (similar for other interpreters, e.g., %spark, %spark-python) ---- %python print("%html ready") s = "X" * 100000 print("<script>js='" + s + "'; alert(js.length)</script>") ---- The execution of this cell takes more than 1 minute! Since running the same html directly in a browser takes only milliseconds, I believe that a bug causes this huge performance drop (for example erroneous event polling from some queue or so, see below...). *Why this is a major issue*: In contrast to Jupyter, Zeppelin allows for an almost seamless integration of spark, python, scala, etc. into the front-end's JavaScript context. This allows to easily visualize results rendered by JavaScript librarys such as Plotly, D3, Vis, Cytoscape, crossfilter, etc., by outputting the corresponding JavaScript incl. the stringified data via print("%html <script>" + content + "</script>"). Indeed, this works very well in practice with all these libraries. However, it is a total dealbreaker if we cannot pass more than just some hundreds of bytes. *Logfile*: Please see some relevant DEBUG log output attached (from logs/zeppelin-user-host.log). Just a guess because of the repeated IDLE messages: probably the long output string is polled in small portions, and some event handler falls into some idle-delay in between these portions? {quote} (...) thousands of more lines before... INFO [2017-02-07 09:56:01,928] ({pool-2-thread-2} Paragraph.java[jobRun]:344) - run paragraph 20170206-210437_343934373 using null org.apache.zeppelin.interpreter.LazyOpenInterpreter@79f86c19 DEBUG [2017-02-07 09:56:01,928] ({pool-2-thread-2} Paragraph.java[jobRun]:380) - RUN : print("%html start...") # start html output s = "X"*100000 # create some string of length 100k print("ready for transfer..."); # notify that done. print("<div class='hidden'>" + s + "'</div>") # copy the string to javascript and compute its length - takes more than a minute! print("done") DEBUG [2017-02-07 09:56:01,928] ({pool-2-thread-2} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:01,928] ({pool-2-thread-2} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:01,928] ({pool-2-thread-2} RemoteInterpreter.java[interpret]:297) - st: print("%html start...") # start html output s = "X"*100000 # create some string of length 100k print("ready for transfer..."); # notify that done. print("<div class='hidden'>" + s + "'</div>") # copy the string to javascript and compute its length - takes more than a minute! print("done") DEBUG [2017-02-07 09:56:01,930] ({Thread-39} NotebookServer.java[broadcast]:472) - SEND >> PARAGRAPH DEBUG [2017-02-07 09:56:01,931] ({Thread-39} WebSocketRemoteEndpoint.java[sendString]:385) - sendString with HeapByteBuffer@2c27cd44[p=0,l=978,c=978,r=978]={<<<{"op":"PARAGRAPH"...us","roles":""}>>>} DEBUG [2017-02-07 09:56:01,935] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-4: Close connection DEBUG [2017-02-07 09:56:01,935] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:357) - Connection manager shut down DEBUG [2017-02-07 09:56:01,935] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:351) - Connection manager is shutting down DEBUG [2017-02-07 09:56:01,935] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-5: Close connection DEBUG [2017-02-07 09:56:01,939] ({Thread-39} ExtensionStack.java[outgoingFrame]:288) - Queuing TEXT[len=978,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:01,939] ({Thread-39} ExtensionStack.java[process]:388) - Processing TEXT[len=978,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:01,939] ({Thread-39} AbstractWebSocketConnection.java[outgoingFrame]:564) - outgoingFrame(TEXT[len=978,fin=true,rsv=...,masked=false], org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING]) DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[enqueue]:378) - Flusher[queueSize=1,aggregateSize=0,failure=null] queued FrameEntry[TEXT[len=978,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 1 entries: [FrameEntry[TEXT[len=978,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[batch]:67) - Flusher[queueSize=0,aggregateSize=0,failure=null] acquired aggregate buffer java.nio.DirectByteBuffer[pos=0 lim=0 cap=32768] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[batch]:86) - Flusher[queueSize=0,aggregateSize=0,failure=null] aggregated 1 frames: [FrameEntry[TEXT[len=0,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=0,failure=null] auto flushing DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[flush]:118) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing aggregate java.nio.DirectByteBuffer[pos=0 lim=982 cap=32768] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} WriteFlusher.java[write]:295) - write: WriteFlusher@296a7050{IDLE} [DirectByteBuffer@5f97bfd0[p=0,l=982,c=32768,r=982]={<<<\x81~\x03\xD2{"op":"PARAGR...us","roles":""}>>>"sql","class":"or...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] DEBUG [2017-02-07 09:56:01,940] ({Thread-39} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{WRITING}:IDLE-->WRITING DEBUG [2017-02-07 09:56:01,941] ({Thread-39} ChannelEndPoint.java[flush]:188) - flushed 982 SelectChannelEndPoint@646c7187{/0:0:0:0:0:0:0:1:35664<->8080,Open,in,out,R,W,14/300000,WebSocketServerConnection}{io=1,kio=1,kro=1} DEBUG [2017-02-07 09:56:01,941] ({Thread-39} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{IDLE}:WRITING-->IDLE DEBUG [2017-02-07 09:56:01,941] ({Thread-39} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=982,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:01,941] ({Thread-39} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=982,failure=null] auto flushing DEBUG [2017-02-07 09:56:01,941] ({Thread-39} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=982,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:01,941] ({Thread-39} ExtensionStack.java[process]:384) - Entering IDLE DEBUG [2017-02-07 09:56:01,941] ({Thread-39} RemoteInterpreterEventPoller.java[run]:251) - Event from remote process OUTPUT_UPDATE_ALL DEBUG [2017-02-07 09:56:01,949] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-5: Close connection DEBUG [2017-02-07 09:56:01,950] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:357) - Connection manager shut down DEBUG [2017-02-07 09:56:01,950] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:351) - Connection manager is shutting down DEBUG [2017-02-07 09:56:01,950] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-6: Close connection DEBUG [2017-02-07 09:56:01,951] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-6: Close connection DEBUG [2017-02-07 09:56:01,951] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:357) - Connection manager shut down DEBUG [2017-02-07 09:56:01,951] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:351) - Connection manager is shutting down DEBUG [2017-02-07 09:56:01,951] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-7: Close connection DEBUG [2017-02-07 09:56:01,951] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-7: Close connection DEBUG [2017-02-07 09:56:01,951] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:357) - Connection manager shut down DEBUG [2017-02-07 09:56:01,951] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:351) - Connection manager is shutting down DEBUG [2017-02-07 09:56:01,952] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-8: Close connection DEBUG [2017-02-07 09:56:01,953] ({Finalizer} LoggingManagedHttpClientConnection.java[close]:79) - http-outgoing-8: Close connection DEBUG [2017-02-07 09:56:01,953] ({Finalizer} PoolingHttpClientConnectionManager.java[shutdown]:357) - Connection manager shut down DEBUG [2017-02-07 09:56:02,047] ({Thread-44} NotebookServer.java[broadcast]:472) - SEND >> PARAGRAPH DEBUG [2017-02-07 09:56:02,048] ({Thread-44} WebSocketRemoteEndpoint.java[sendString]:385) - sendString with HeapByteBuffer@6402a789[p=0,l=978,c=978,r=978]={<<<{"op":"PARAGRAPH"...us","roles":""}>>>} DEBUG [2017-02-07 09:56:02,048] ({Thread-44} ExtensionStack.java[outgoingFrame]:288) - Queuing TEXT[len=978,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:02,048] ({Thread-44} ExtensionStack.java[process]:388) - Processing TEXT[len=978,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:02,048] ({Thread-44} AbstractWebSocketConnection.java[outgoingFrame]:564) - outgoingFrame(TEXT[len=978,fin=true,rsv=...,masked=false], org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING]) DEBUG [2017-02-07 09:56:02,048] ({Thread-44} FrameFlusher.java[enqueue]:378) - Flusher[queueSize=1,aggregateSize=0,failure=null] queued FrameEntry[TEXT[len=978,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null] DEBUG [2017-02-07 09:56:02,048] ({Thread-44} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 1 entries: [FrameEntry[TEXT[len=978,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:02,048] ({Thread-44} FrameFlusher.java[batch]:67) - Flusher[queueSize=0,aggregateSize=0,failure=null] acquired aggregate buffer java.nio.DirectByteBuffer[pos=0 lim=0 cap=32768] DEBUG [2017-02-07 09:56:02,048] ({Thread-44} FrameFlusher.java[batch]:86) - Flusher[queueSize=0,aggregateSize=0,failure=null] aggregated 1 frames: [FrameEntry[TEXT[len=0,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:02,048] ({Thread-44} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:02,049] ({Thread-44} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=0,failure=null] auto flushing DEBUG [2017-02-07 09:56:02,049] ({Thread-44} FrameFlusher.java[flush]:118) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing aggregate java.nio.DirectByteBuffer[pos=0 lim=982 cap=32768] DEBUG [2017-02-07 09:56:02,049] ({Thread-44} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:02,049] ({Thread-44} WriteFlusher.java[write]:295) - write: WriteFlusher@296a7050{IDLE} [DirectByteBuffer@5f97bfd0[p=0,l=982,c=32768,r=982]={<<<\x81~\x03\xD2{"op":"PARAGR...us","roles":""}>>>"sql","class":"or...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] DEBUG [2017-02-07 09:56:02,049] ({Thread-44} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{WRITING}:IDLE-->WRITING DEBUG [2017-02-07 09:56:02,049] ({Thread-44} ChannelEndPoint.java[flush]:188) - flushed 982 SelectChannelEndPoint@646c7187{/0:0:0:0:0:0:0:1:35664<->8080,Open,in,out,R,W,108/300000,WebSocketServerConnection}{io=1,kio=1,kro=1} DEBUG [2017-02-07 09:56:02,049] ({Thread-44} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{IDLE}:WRITING-->IDLE DEBUG [2017-02-07 09:56:02,049] ({Thread-44} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=982,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:02,050] ({Thread-44} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=982,failure=null] auto flushing DEBUG [2017-02-07 09:56:02,050] ({Thread-44} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=982,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:02,050] ({Thread-44} ExtensionStack.java[process]:384) - Entering IDLE DEBUG [2017-02-07 09:56:02,453] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,453] ({Thread-45} InterpreterFactory.java[getInterpreterSessionKey]:1239) - Interpreter session key: shared_session, for note: 2C7TKVQEW, user: admin, InterpreterSetting Name: python3 DEBUG [2017-02-07 09:56:02,453] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,453] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,481] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,481] ({Thread-45} InterpreterFactory.java[getInterpreterSessionKey]:1239) - Interpreter session key: shared_session, for note: 2C7TKVQEW, user: admin, InterpreterSetting Name: python3 DEBUG [2017-02-07 09:56:02,481] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,482] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,486] ({Thread-45} NotebookServer.java[broadcast]:472) - SEND >> PROGRESS DEBUG [2017-02-07 09:56:02,486] ({Thread-45} WebSocketRemoteEndpoint.java[sendString]:385) - sendString with HeapByteBuffer@ed7f6db[p=0,l=128,c=128,r=128]={<<<{"op":"PROGRESS",...us","roles":""}>>>} DEBUG [2017-02-07 09:56:02,486] ({Thread-45} ExtensionStack.java[outgoingFrame]:288) - Queuing TEXT[len=128,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:02,486] ({Thread-45} ExtensionStack.java[process]:388) - Processing TEXT[len=128,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:02,486] ({Thread-45} AbstractWebSocketConnection.java[outgoingFrame]:564) - outgoingFrame(TEXT[len=128,fin=true,rsv=...,masked=false], org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING]) DEBUG [2017-02-07 09:56:02,486] ({Thread-45} FrameFlusher.java[enqueue]:378) - Flusher[queueSize=1,aggregateSize=0,failure=null] queued FrameEntry[TEXT[len=128,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null] DEBUG [2017-02-07 09:56:02,486] ({Thread-45} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 1 entries: [FrameEntry[TEXT[len=128,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:02,486] ({Thread-45} FrameFlusher.java[batch]:67) - Flusher[queueSize=0,aggregateSize=0,failure=null] acquired aggregate buffer java.nio.DirectByteBuffer[pos=0 lim=0 cap=32768] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[batch]:86) - Flusher[queueSize=0,aggregateSize=0,failure=null] aggregated 1 frames: [FrameEntry[TEXT[len=0,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=0,failure=null] auto flushing DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[flush]:118) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing aggregate java.nio.DirectByteBuffer[pos=0 lim=132 cap=32768] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} WriteFlusher.java[write]:295) - write: WriteFlusher@296a7050{IDLE} [DirectByteBuffer@5f97bfd0[p=0,l=132,c=32768,r=132]={<<<\x81~\x00\x80{"op":"PROGRE...us","roles":""}>>>e string of lengt...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{WRITING}:IDLE-->WRITING DEBUG [2017-02-07 09:56:02,487] ({Thread-45} ChannelEndPoint.java[flush]:188) - flushed 132 SelectChannelEndPoint@646c7187{/0:0:0:0:0:0:0:1:35664<->8080,Open,in,out,R,W,438/300000,WebSocketServerConnection}{io=1,kio=1,kro=1} DEBUG [2017-02-07 09:56:02,487] ({Thread-45} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{IDLE}:WRITING-->IDLE DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=132,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=132,failure=null] auto flushing DEBUG [2017-02-07 09:56:02,487] ({Thread-45} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=132,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:02,488] ({Thread-45} ExtensionStack.java[process]:384) - Entering IDLE DEBUG [2017-02-07 09:56:02,988] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,988] ({Thread-45} InterpreterFactory.java[getInterpreterSessionKey]:1239) - Interpreter session key: shared_session, for note: 2C7TKVQEW, user: admin, InterpreterSetting Name: python3 DEBUG [2017-02-07 09:56:02,989] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,989] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,994] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,994] ({Thread-45} InterpreterFactory.java[getInterpreterSessionKey]:1239) - Interpreter session key: shared_session, for note: 2C7TKVQEW, user: admin, InterpreterSetting Name: python3 DEBUG [2017-02-07 09:56:02,994] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,994] ({Thread-45} InterpreterSetting.java[getInterpreterProcessKey]:143) - getInterpreterProcessKey: shared_process for InterpreterSetting Id: 2C7KPWF4Y, Name: python3 DEBUG [2017-02-07 09:56:02,998] ({Thread-45} NotebookServer.java[broadcast]:472) - SEND >> PROGRESS DEBUG [2017-02-07 09:56:02,998] ({Thread-45} WebSocketRemoteEndpoint.java[sendString]:385) - sendString with HeapByteBuffer@bd7ddbf[p=0,l=128,c=128,r=128]={<<<{"op":"PROGRESS",...us","roles":""}>>>} DEBUG [2017-02-07 09:56:02,998] ({Thread-45} ExtensionStack.java[outgoingFrame]:288) - Queuing TEXT[len=128,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:02,998] ({Thread-45} ExtensionStack.java[process]:388) - Processing TEXT[len=128,fin=true,rsv=...,masked=false] DEBUG [2017-02-07 09:56:02,998] ({Thread-45} AbstractWebSocketConnection.java[outgoingFrame]:564) - outgoingFrame(TEXT[len=128,fin=true,rsv=...,masked=false], org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING]) DEBUG [2017-02-07 09:56:02,998] ({Thread-45} FrameFlusher.java[enqueue]:378) - Flusher[queueSize=1,aggregateSize=0,failure=null] queued FrameEntry[TEXT[len=128,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null] DEBUG [2017-02-07 09:56:02,998] ({Thread-45} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 1 entries: [FrameEntry[TEXT[len=128,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:02,998] ({Thread-45} FrameFlusher.java[batch]:67) - Flusher[queueSize=0,aggregateSize=0,failure=null] acquired aggregate buffer java.nio.DirectByteBuffer[pos=0 lim=0 cap=32768] DEBUG [2017-02-07 09:56:02,998] ({Thread-45} FrameFlusher.java[batch]:86) - Flusher[queueSize=0,aggregateSize=0,failure=null] aggregated 1 frames: [FrameEntry[TEXT[len=0,fin=true,rsv=...,masked=false],org.eclipse.jetty.websocket.common.extensions.ExtensionStack$Flusher@7d2522f0[PROCESSING],AUTO,null]] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=0,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=0,failure=null] auto flushing DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[flush]:118) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing aggregate java.nio.DirectByteBuffer[pos=0 lim=132 cap=32768] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=0,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} WriteFlusher.java[write]:295) - write: WriteFlusher@296a7050{IDLE} [DirectByteBuffer@5f97bfd0[p=0,l=132,c=32768,r=132]={<<<\x81~\x00\x80{"op":"PROGRE...us","roles":""}>>>e string of lengt...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{WRITING}:IDLE-->WRITING DEBUG [2017-02-07 09:56:02,999] ({Thread-45} ChannelEndPoint.java[flush]:188) - flushed 132 SelectChannelEndPoint@646c7187{/0:0:0:0:0:0:0:1:35664<->8080,Open,in,out,R,W,512/300000,WebSocketServerConnection}{io=1,kio=1,kro=1} DEBUG [2017-02-07 09:56:02,999] ({Thread-45} WriteFlusher.java[updateState]:118) - update WriteFlusher@296a7050{IDLE}:WRITING-->IDLE DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[process]:197) - Flusher[queueSize=0,aggregateSize=132,failure=null] processing 0 entries: [] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[process]:210) - Flusher[queueSize=0,aggregateSize=132,failure=null] auto flushing DEBUG [2017-02-07 09:56:02,999] ({Thread-45} FrameFlusher.java[flush]:141) - Flusher[queueSize=0,aggregateSize=132,failure=null] flushing 0 frames: [] DEBUG [2017-02-07 09:56:02,999] ({Thread-45} ExtensionStack.java[process]:384) - Entering IDLE (...) thousands of more lines... {quote} -- This message was sent by Atlassian JIRA (v6.3.15#6346)