search

tkf / emacs-ipython-notebook

IPython notebook client in Emacs
tkf.github.com/emacs-ipython-notebook/
GNU General Public License v3.0
548 stars 51 forks source link

Unsupported websocket protocol #85

Closed alphaho closed 11 years ago

alphaho commented 11 years ago

I tried to open a notebook and got the error message:

ein: [error] Unsupported websocket protocol

and when I ran the ein:dev-start-debug, and opened the notebook again, I get this backtrace message: (it seems I can't paste all of the message to here)

Debugger entered--Lisp error: (websocket-unsupport signal(websocket-unsupported-protocol nil)
websocket-open("/kernels//shell" :on-open #[... ein:websocket("/kernels//shell")
ein:kernel-start-channels([cl-struct-ein:$kernel ein:kernel--kernel-started([cl-struct-ein:$kerne apply(ein:kernel--kernel-started [cl-struct-ein: ein:funcall-packed((ein:kernel--kernel-started . apply(ein:funcall-packed (ein:kernel--kernel-sta ein:safe-funcall-packed((ein:kernel--kernel-star apply(ein:safe-funcall-packed (... :status nil : ein:query-ajax-callback(nil :type "POST" :parser apply(ein:query-ajax-callback (nil :type "POST" url-http-activate-callback()
url-http-content-length-after-change-function(21 url-http-wait-for-headers-change-function(1 228 url-http-generic-filter(#<process 127.0.0.1<2>>

tkf commented 11 years ago

Could you run M-x ein:dev-bug-report-template and paste version information here?

See also: https://github.com/tkf/emacs-ipython-notebook/blob/master/CONTRIBUTING.md

tkf commented 11 years ago

And don't worry about backtrace. Emacs backtrace may contain binary so it can't be paste to github sometime.

alphaho commented 11 years ago

Here's the report:

Steps to reproduce the problem

  1. ein:notebooklist-open
  2. load-library ein-dev
  3. open a notebook
  4. Debugger popup

Expected output

open the notebook without problem

Your EIN configuration (in .emacs.d/init.el or somewhere else)

no configuration

Your IPython configuration

  1. How do you start IPython? (e.g., ipython notebook --port 9999):

ipython notebook --pylab=inline

  1. What is your IPython notebook port number or URL?:

8888

Additional information (if any)

System info:

("EIN system info" :emacs-version "GNU Emacs 24.2.1 (x86_64-unknown-linux-gnu, GTK+ Version 2.24.10)\n of 2012-10-13 on alpha-Dell-XPS-730X" :emacs-bzr-version nil :window-system x :emacs-variant nil :os
 (:uname "Linux alpha-Dell-XPS-730X 3.2.0-26-generic #41-Ubuntu SMP Thu Jun 14 17:49:24 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux\n" :lsb-release "No LSB modules are available.\nDistributor ID: LinuxDeepin\nDescription:   LinuxDeepin 12.06\nRelease: 12.06\nCodename:    precise\n")
 :image-types
 (png gif tiff jpeg xpm postscript xbm pbm)
 :image-types-available
 (png gif tiff jpeg xpm postscript xbm pbm)
 :ein
 (:version "0.2.0alpha0" :source-dir "/home/alpha/my_emacs.d/elpa/ein-20121127.254/")
 :lib
 ((:name "websocket" :path "~/my_emacs.d/elpa/websocket-20121013.1846/websocket.elc" :featurep t :version-var websocket-version :version "1.0")
  (:name "auto-complete" :path "~/my_emacs.d/elpa/auto-complete-20121022.2254/auto-complete.elc" :featurep t :version-var nil :version nil)
  (:name "mumamo" :path nil :featurep nil :version-var nil :version nil)
  (:name "auto-complete" :path "~/my_emacs.d/elpa/auto-complete-20121022.2254/auto-complete.elc" :featurep t :version-var nil :version nil)
  (:name "popup" :path "~/my_emacs.d/elpa/popup-20121020.1203/popup.elc" :featurep t :version-var nil :version nil)
  (:name "fuzzy" :path "~/my_emacs.d/elpa/fuzzy-0.1/fuzzy.elc" :featurep nil :version-var nil :version nil)
  (:name "pos-tip" :path nil :featurep nil :version-var nil :version nil)
  (:name "python" :path "~/my_emacs.d/elpa/python-20121014.1458/python.elc" :featurep t :version-var nil :version nil)
  (:name "python-mode" :path "~/my_emacs.d/elpa/python-mode-6.0.10/python-mode.elc" :featurep t :version-var nil :version nil)
  (:name "markdown-mode" :path "~/my_emacs.d/elpa/markdown-mode-20121007.2146/markdown-mode.elc" :featurep nil :version-var nil :version nil)
  (:name "smartrep" :path "~/my_emacs.d/elpa/smartrep-20120905.2101/smartrep.elc" :featurep nil :version-var nil :version nil)
  (:name "anything" :path "~/my_emacs.d/elpa/anything-1.287/anything.elc" :featurep t :version-var anything-version :version "1.287")
  (:name "helm" :path nil :featurep nil :version-var nil :version nil)))
tkf commented 11 years ago

Thanks. But it's still unclear what causes this problem. Could you save the backtrace in a file and upload it to somewhere (e.g., gist)?

Also, can you get debug log? Here is how to: http://tkf.github.com/emacs-ipython-notebook/#logging

Please do the easier one first and leave a comment. One can be enough (and also two can be not enough, though...).

alphaho commented 11 years ago

Seems I can't get the debug log. when I run

ein:dev-pop-to-debug-shell

I get or:

ein:$websocket-ws accessing a non-ein:$websocket

and

ein:dev-pop-to-debug-iopub

get:

or: ein:$notebook-kernel accessing a non-ein:$notebook

after I run

(ein:log-set-level 'debug)

and trigger the error I can't find the _ein:log-all buffer

What should I do?

alphaho commented 11 years ago

finally get to the ein:log-all buffer (through the command: ein:log-pop-to-all-buffer)

[debug] EIN:QUERY-AJAX @#<buffer *slime-repl sbcl*>
[debug] Start querying: http://127.0.0.1:8888/notebooks?_=1354546300 @#<buffer *slime-repl sbcl*>
[debug] Start timer: timeout=1000 ms @#<buffer *slime-repl sbcl*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 75
Etag: "94b1b34f7621543741b696a4ceaf9f1d29e11f17"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Sun, 04 Dec 2011 14:51:40 GMT; Path=/

[{"name":"test_date","notebook_id":"761da4a8-8a97-4ac8-9532-c195069a49ba"}] @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = (...) @#<buffer *Messages*>
[debug] canceled = nil @#<buffer *Messages*>
[debug] Executing success/error callback. @#<buffer *Messages*>
[info] Opened notebook list at 8888 @#<buffer *ein:notebooklist 8888*>
[debug] Executing status-code callback. @#<buffer *ein:notebooklist 8888*>
[info] Opening notebook 761da4a8-8a97-4ac8-9532-c195069a49ba... @#<buffer *ein:notebooklist 8888*>
[debug] Opening notebook at http://127.0.0.1:8888/notebooks/761da4a8-8a97-4ac8-9532-c195069a49ba @#<buffer *ein:notebooklist 8888*>
[debug] EIN:QUERY-AJAX @#<buffer *ein:notebooklist 8888*>
[debug] Start querying: http://127.0.0.1:8888/notebooks/761da4a8-8a97-4ac8-9532-c195069a49ba @#<buffer *ein:notebooklist 8888*>
[debug] Start timer: timeout=60000 ms @#<buffer *ein:notebooklist 8888*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 17550
Content-Disposition: attachment; filename="test_date.ipynb"
Server: TornadoServer/2.1
Last-Modified: Fri, 09 Nov 2012 14:50:40 GMT
Etag: "347020b416c19f0220ebb0a9dc3ba60a29db5e2a"
Content-Type: application/json
Set-Cookie: username=; expires=Sun, 04 Dec 2011 14:51:44 GMT; Path=/

{
 "metadata": {
  "name": "test_date"
 }, 
 "name": "test_date", 
 "nbformat": 2, 
 "worksheets": [
  {
   "cells": [
    {
     "cell_type": "code", 
     "collapsed": true, 
     "input": "import dateutil\nimport datetime", 
     "language": "python", 
     "outputs": [], 
     "prompt_number": 29
    }, 
    {
     "cell_type": "code", 
     "collapsed": false, 
     "input": "x = drange(datetime.datetime(2012,5,20,3,12,1),datetime.datetime(2012,5,21,8,30,8),datetime.timedelta(hours=1))\nx.size", 
     "language": "python", 
     "outputs": [
      {
       "output_type": "pyout", 
       "prompt_number": 48, 
       "text": "30"
      }
      @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = (:worksheets ... :nbformat 2 :name test_date :metadata ...) @#<buffer *scratch*>
[debug] canceled = nil @#<buffer *scratch*>
[debug] Executing success/error callback. @#<buffer *scratch*>
[debug] URL-RETRIEVE nodtebook-id = "761da4a8-8a97-4ac8-9532-c195069a49ba", status = nil @#<buffer *scratch*>
[debug] EIN:QUERY-AJAX @#<buffer *scratch*>
[debug] Start querying: http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba @#<buffer *scratch*>
[debug] Start timer: timeout=1000 ms @#<buffer *scratch*>
[info] Worksheet test_date is ready @#<buffer *ein: 8888/test_date*>
[info] Notebook test_date is ready @#<buffer *scratch*>
[debug] Executing status-code callback. @#<buffer *scratch*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 2
Etag: "97d170e1550eee4afc0af065b78cda302a97674c"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Sun, 04 Dec 2011 14:51:44 GMT; Path=/

[] @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = nil @#<buffer *slime-repl sbcl*>
[debug] canceled = nil @#<buffer *slime-repl sbcl*>
[debug] Executing success/error callback. @#<buffer *slime-repl sbcl*>
[info] Kernel started: nil @#<buffer *slime-repl sbcl*>
[info] Starting WS: "/kernels/" @#<buffer *slime-repl sbcl*>
tkf commented 11 years ago

Thanks for the log. I guess I find the problem.

This part is really fishy. It could be another url-retrieve bug...:

[debug] Start querying: http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba @#<buffer *scratch*>
[...]
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 2
Etag: "97d170e1550eee4afc0af065b78cda302a97674c"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Sun, 04 Dec 2011 14:51:44 GMT; Path=/

[] @#<buffer  *http 127.0.0.1:8888*>

It should return something like the following, instead of an empty array []:

{"kernel_id":"5ddcf582-8729-43a3-a47b-de85257a1309","ws_url":"ws://127.0.0.1:8888"}

Can you run the following in your Emacs to check if url-retrieve in your Emacs works as advertised? It will popup a buffer, so please paste the contents here.

(let ((url-request-method "POST"))
  (url-retrieve
   "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba"
   (lambda (&rest _) (pop-to-buffer (current-buffer)))))

The easiest way to evaluate the code is to hit M-:, paste the code, and then hit return.

You will need to change 761da4a8-8a97-4ac8-9532-c195069a49ba part if you restarted your ipython. This is the url when you open the notebook in browser.

tkf commented 11 years ago

Also, can you re-post your comment for backtrace? I can see it from my top page but not here.

alphaho commented 11 years ago

seems the url-retrieve works

HTTP/1.1 200 OK
Content-Length: 83
Content-Type: text/html; charset=UTF-8
Location: /00c90344-937e-4c3e-9d6d-dcb206b04260
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Sun, 04 Dec 2011 15:30:55 GMT; Path=/

{"kernel_id":"00c90344-937e-4c3e-9d6d-dcb206b04260","ws_url":"ws://127.0.0.1:8888"}
alphaho commented 11 years ago

the backtrace is here: https://gist.github.com/4195368

alphaho commented 11 years ago

the backtrace is here: https://gist.github.com/4195368

alphaho commented 11 years ago

it's weird that I paste the backtrace once and it comes with 2 to 3 comments here. so I deleted those before. Sorry for that.

tkf commented 11 years ago

two is better than none. thanks.

OK, then there is something wrong in EIN. Can you try this? This time, content will go into *Messages* buffer.

(ein:query-ajax
 "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba"
 :type "POST"
 :parser 'buffer-string
 :success (cons (lambda (_ &rest args) (message (plist-get args :data))) nil))
alphaho commented 11 years ago

More info is found

When I open the ipython with my firefox, I get

Websocket connection to ws://127.0.0.1:8888/kernels/d2d43f2f-8ca7-4993-9f9d-90222592152e could not be established.
You will NOT be able to run code.
Your browser may not be compatible with the websocket version in the server, or if the url does not look right, there could be an error in the server's configuration.

but it works well with my chrome

alphaho commented 11 years ago

That code fails with:

Debugger entered--Lisp error: (void-function ein:query-ajax)
  (ein:query-ajax "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba" :type "POST" :parser (quote buffer-string) :success (cons (lambda (_ &rest args) (message (plist-get args :data))) nil))
  eval-region(193 404 t (lambda (ignore) (goto-char 404) (quote (ein:query-ajax "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba" :type "POST" :parser (quote buffer-string) :success (cons (lambda (_ &rest args) (message (plist-get args :data))) nil)))))  ; Reading at buffer position 404
  apply(eval-region (193 404 t (lambda (ignore) (goto-char 404) (quote (ein:query-ajax "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba" :type "POST" :parser (quote buffer-string) :success (cons (lambda (_ &rest args) (message (plist-get args :data))) nil))))))
  eval-defun-2()
  eval-defun(nil)
  call-interactively(eval-defun nil nil)
alphaho commented 11 years ago

Sorry..... forgot my emacs & ipython have been restarted..... Here's what it comes:

HTTP/1.1 200 OK
Content-Length: 83
Content-Type: text/html; charset=UTF-8
Location: /296281bd-128f-4827-851d-5f2fd80a905f
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Sun, 04 Dec 2011 15:56:03 GMT; Path=/

{"kernel_id":"296281bd-128f-4827-851d-5f2fd80a905f","ws_url":"ws://127.0.0.1:8888"}
tkf commented 11 years ago

Re: firefox, probably that's because your Tornado is old or firefox is old.

alphaho commented 11 years ago

Tornado is 2.1 and firefox is 16.0 maybe it's tornado

alphaho commented 11 years ago

will that has impact on the ein?

alphaho commented 11 years ago

will that has impact on the ein?

tkf commented 11 years ago

Nothing. I was just guessing the reason why you get that message in firefox.

tkf commented 11 years ago

It is really strange. Your log and backtrace said that the POST request (ein:query-ajax ...) failed (I guess it was executed as a GET request). But actually it works when it is manually invoked. Sorry, I am not sure where to go now. At this point, I need to use debugger to see what is wrong. If you want to debug EIN, I can help you.

Note to me: This request is done in ein:kernel-start. It is for getting "ws_url" and "kernel_id". As EIN failed to fetch "ws_url", there is no "ws://127.0.0.1:8888" in the websocket url. That's why websocket.el says "Unsupported websocket protocol" (url does not start with ws or wss).

tkf commented 11 years ago

Can I ask you a favor? I changed some code to make error message more meaningful. So, can you take a log and backtrace as you did before with the latest code? As it looks like you install EIN from MELPA, probably you need to wait a little bit. Check the update here: https://twitter.com/melpa_emacs

Also, when you take backtrace, please run M-x ein:dev-depatch-backtrace after M-x ein:dev-start-debug. This way, backtrace will be more verbose.

I guess the change I did won't fix anything for you. This is just for catching error earlier so that log and error message will be clearer.

alphaho commented 11 years ago

ok. let me try. sorry to be late

alphaho commented 11 years ago

Here's the new backtrace: https://gist.github.com/4204360

alphaho commented 11 years ago

Here's the new backtrace: https://gist.github.com/4204360

alphaho commented 11 years ago

And the _ein:log-all

[debug] EIN:QUERY-AJAX @#<buffer *slime-repl sbcl*>
[debug] Start querying: http://127.0.0.1:8888/notebooks?_=1354630377 @#<buffer *slime-repl sbcl*>
[debug] Start timer: timeout=1000 ms @#<buffer *slime-repl sbcl*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 75
Etag: "506c89c3933d22689454b2cac93d39d098d5e916"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:12:58 GMT; Path=/

[{"name":"test_date","notebook_id":"64d18847-7ea9-445e-a8a5-96aacfd1ec60"}] @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = (...) @#<buffer *scratch*>
[debug] canceled = nil @#<buffer *scratch*>
[debug] Executing success/error callback. @#<buffer *scratch*>
[info] Opened notebook list at 8888 @#<buffer *ein:notebooklist 8888*>
[debug] Executing status-code callback. @#<buffer *ein:notebooklist 8888*>
[info] Opening notebook 64d18847-7ea9-445e-a8a5-96aacfd1ec60... @#<buffer *ein:notebooklist 8888*>
[debug] Opening notebook at http://127.0.0.1:8888/notebooks/64d18847-7ea9-445e-a8a5-96aacfd1ec60 @#<buffer *ein:notebooklist 8888*>
[debug] EIN:QUERY-AJAX @#<buffer *ein:notebooklist 8888*>
[debug] Start querying: http://127.0.0.1:8888/notebooks/64d18847-7ea9-445e-a8a5-96aacfd1ec60 @#<buffer *ein:notebooklist 8888*>
[debug] Start timer: timeout=60000 ms @#<buffer *ein:notebooklist 8888*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 17550
Content-Disposition: attachment; filename="test_date.ipynb"
Server: TornadoServer/2.1
Last-Modified: Fri, 09 Nov 2012 14:50:40 GMT
Etag: "347020b416c19f0220ebb0a9dc3ba60a29db5e2a"
Content-Type: application/json
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:12:59 GMT; Path=/

{
 "metadata": {
  "name": "test_date"
 }, 
 "name": "test_date", 
 "nbformat": 2, 
 "worksheets": [
  {
   "cells": [
    {
     "cell_type": "code", 
     "collapsed": true, 
     "input": "import dateutil\nimport datetime", 
     "language": "python", 
     "outputs": [], 
     "prompt_number": 29
    }, 
    {
     "cell_type": "code", 
     "collapsed": false, 
     "input": "x = drange(datetime.datetime(2012,5,20,3,12,1),datetime.datetime(2012,5,21,8,30,8),datetime.timedelta(hours=1))\nx.size", 
     "language": "python", 
     "outputs": [
      {
       "output_type": "pyout", 
       "prompt_number": 48, 
       "text": "30"
      }
      @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = (:worksheets ... :nbformat 2 :name test_date :metadata ...) @#<buffer *GNU Emacs*>
[debug] canceled = nil @#<buffer *GNU Emacs*>
[debug] Executing success/error callback. @#<buffer *GNU Emacs*>
[debug] URL-RETRIEVE nodtebook-id = "64d18847-7ea9-445e-a8a5-96aacfd1ec60", status = nil @#<buffer *GNU Emacs*>
[debug] EIN:QUERY-AJAX @#<buffer *GNU Emacs*>
[debug] Start querying: http://127.0.0.1:8888/kernels?notebook=64d18847-7ea9-445e-a8a5-96aacfd1ec60 @#<buffer *GNU Emacs*>
[debug] Start timer: timeout=1000 ms @#<buffer *GNU Emacs*>
[info] Worksheet test_date is ready @#<buffer *ein: 8888/test_date*>
[info] Notebook test_date is ready @#<buffer *GNU Emacs*>
[debug] Executing status-code callback. @#<buffer *GNU Emacs*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 2
Etag: "97d170e1550eee4afc0af065b78cda302a97674c"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:13:00 GMT; Path=/

[] @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = nil @#<buffer *slime-repl sbcl*>
[debug] canceled = nil @#<buffer *slime-repl sbcl*>
[debug] Executing success/error callback. @#<buffer *slime-repl sbcl*>
alphaho commented 11 years ago

And the _ein:log-all

[debug] EIN:QUERY-AJAX @#<buffer *slime-repl sbcl*>
[debug] Start querying: http://127.0.0.1:8888/notebooks?_=1354630377 @#<buffer *slime-repl sbcl*>
[debug] Start timer: timeout=1000 ms @#<buffer *slime-repl sbcl*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 75
Etag: "506c89c3933d22689454b2cac93d39d098d5e916"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:12:58 GMT; Path=/

[{"name":"test_date","notebook_id":"64d18847-7ea9-445e-a8a5-96aacfd1ec60"}] @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = (...) @#<buffer *scratch*>
[debug] canceled = nil @#<buffer *scratch*>
[debug] Executing success/error callback. @#<buffer *scratch*>
[info] Opened notebook list at 8888 @#<buffer *ein:notebooklist 8888*>
[debug] Executing status-code callback. @#<buffer *ein:notebooklist 8888*>
[info] Opening notebook 64d18847-7ea9-445e-a8a5-96aacfd1ec60... @#<buffer *ein:notebooklist 8888*>
[debug] Opening notebook at http://127.0.0.1:8888/notebooks/64d18847-7ea9-445e-a8a5-96aacfd1ec60 @#<buffer *ein:notebooklist 8888*>
[debug] EIN:QUERY-AJAX @#<buffer *ein:notebooklist 8888*>
[debug] Start querying: http://127.0.0.1:8888/notebooks/64d18847-7ea9-445e-a8a5-96aacfd1ec60 @#<buffer *ein:notebooklist 8888*>
[debug] Start timer: timeout=60000 ms @#<buffer *ein:notebooklist 8888*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 17550
Content-Disposition: attachment; filename="test_date.ipynb"
Server: TornadoServer/2.1
Last-Modified: Fri, 09 Nov 2012 14:50:40 GMT
Etag: "347020b416c19f0220ebb0a9dc3ba60a29db5e2a"
Content-Type: application/json
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:12:59 GMT; Path=/

{
 "metadata": {
  "name": "test_date"
 }, 
 "name": "test_date", 
 "nbformat": 2, 
 "worksheets": [
  {
   "cells": [
    {
     "cell_type": "code", 
     "collapsed": true, 
     "input": "import dateutil\nimport datetime", 
     "language": "python", 
     "outputs": [], 
     "prompt_number": 29
    }, 
    {
     "cell_type": "code", 
     "collapsed": false, 
     "input": "x = drange(datetime.datetime(2012,5,20,3,12,1),datetime.datetime(2012,5,21,8,30,8),datetime.timedelta(hours=1))\nx.size", 
     "language": "python", 
     "outputs": [
      {
       "output_type": "pyout", 
       "prompt_number": 48, 
       "text": "30"
      }
      @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = (:worksheets ... :nbformat 2 :name test_date :metadata ...) @#<buffer *GNU Emacs*>
[debug] canceled = nil @#<buffer *GNU Emacs*>
[debug] Executing success/error callback. @#<buffer *GNU Emacs*>
[debug] URL-RETRIEVE nodtebook-id = "64d18847-7ea9-445e-a8a5-96aacfd1ec60", status = nil @#<buffer *GNU Emacs*>
[debug] EIN:QUERY-AJAX @#<buffer *GNU Emacs*>
[debug] Start querying: http://127.0.0.1:8888/kernels?notebook=64d18847-7ea9-445e-a8a5-96aacfd1ec60 @#<buffer *GNU Emacs*>
[debug] Start timer: timeout=1000 ms @#<buffer *GNU Emacs*>
[info] Worksheet test_date is ready @#<buffer *ein: 8888/test_date*>
[info] Notebook test_date is ready @#<buffer *GNU Emacs*>
[debug] Executing status-code callback. @#<buffer *GNU Emacs*>
[debug] EIN:QUERY-AJAX-CALLBACK @#<buffer  *http 127.0.0.1:8888*>
[debug] status = nil @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>
[debug] url-http-response-status = 200 @#<buffer  *http 127.0.0.1:8888*>
[debug] (buffer-string) =
HTTP/1.1 200 OK
Content-Length: 2
Etag: "97d170e1550eee4afc0af065b78cda302a97674c"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:13:00 GMT; Path=/

[] @#<buffer  *http 127.0.0.1:8888*>
[debug] EIN:QUERY-AJAX-CANCEL-TIMER @#<buffer  *http 127.0.0.1:8888*>
[debug] data = nil @#<buffer *slime-repl sbcl*>
[debug] canceled = nil @#<buffer *slime-repl sbcl*>
[debug] Executing success/error callback. @#<buffer *slime-repl sbcl*>
tkf commented 11 years ago

From this line after the last request, I suspect there is something wrong in url.el:

[debug] url-http-method = GET @#<buffer  *http 127.0.0.1:8888*>

Probably recursive call of url-retrieve doing something wrong? Can you try this?

(url-retrieve
 "http://127.0.0.1:8888"
 (lambda (&rest _)
   (kill-buffer (current-buffer))
   (let ((url-request-method "POST"))
     (url-retrieve
      "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba"
      (lambda (&rest _) (pop-to-buffer (current-buffer)))))))

Please replace the notebook-id appropriately.

alphaho commented 11 years ago

Here's the result:

HTTP/1.1 200 OK
Content-Length: 2
Etag: "97d170e1550eee4afc0af065b78cda302a97674c"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:43:57 GMT; Path=/

[]
tkf commented 11 years ago

Great! The bug is in url.el. (No, it's not great....)

Here is the workaround I have in mind. Can you run this again?

(url-retrieve
 "http://127.0.0.1:8888"
 (lambda (&rest _)
   (kill-buffer (current-buffer))
   (run-with-idle-timer
    0 nil
    (lambda ()
      (let ((url-request-method "POST"))
        (url-retrieve
         "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba"
         (lambda (&rest _) (pop-to-buffer (current-buffer)))))))))
alphaho commented 11 years ago

Sounds we have come to a good place :-)

The result is the same:

HTTP/1.1 200 OK
Content-Length: 2
Etag: "97d170e1550eee4afc0af065b78cda302a97674c"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 14:53:29 GMT; Path=/

[]
tkf commented 11 years ago

Hmm... I hoped it works (i.e., returns a dict with ws_url etc.). Can you try it with increased delay, like this?:

(url-retrieve
 "http://127.0.0.1:8888"
 (lambda (&rest _)
   (kill-buffer (current-buffer))
   (run-with-idle-timer
    0.1 nil  ;; increased delay
    (lambda ()
      (let ((url-request-method "POST"))
        (url-retrieve
         "http://127.0.0.1:8888/kernels?notebook=761da4a8-8a97-4ac8-9532-c195069a49ba"
         (lambda (&rest _) (pop-to-buffer (current-buffer)))))))))
alphaho commented 11 years ago

This is weird:

I changed it to 0.1 and give this out:

HTTP/1.1 200 OK
Content-Length: 83
Content-Type: text/html; charset=UTF-8
Location: /c8c9468a-47bf-487c-ad57-56949c93fb29
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 15:19:40 GMT; Path=/

{"kernel_id":"c8c9468a-47bf-487c-ad57-56949c93fb29","ws_url":"ws://127.0.0.1:8888"}

and when I changed it back to 0, it also works!

HTTP/1.1 200 OK
Content-Length: 40
Etag: "11c2a6316229013b2c01abfc183a9a813c7d58cc"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 15:20:52 GMT; Path=/

["c8c9468a-47bf-487c-ad57-56949c93fb29"]
alphaho commented 11 years ago

This is weird:

I changed it to 0.1 and give this out:

HTTP/1.1 200 OK
Content-Length: 83
Content-Type: text/html; charset=UTF-8
Location: /c8c9468a-47bf-487c-ad57-56949c93fb29
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 15:19:40 GMT; Path=/

{"kernel_id":"c8c9468a-47bf-487c-ad57-56949c93fb29","ws_url":"ws://127.0.0.1:8888"}

and when I changed it back to 0, it also works!

HTTP/1.1 200 OK
Content-Length: 40
Etag: "11c2a6316229013b2c01abfc183a9a813c7d58cc"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 15:20:52 GMT; Path=/

["c8c9468a-47bf-487c-ad57-56949c93fb29"]
tkf commented 11 years ago

No your second example is different from the first. Second one returns array, not dict.

You will see M-: url-http-method RET returning "POST" in the buffer (named something like *http://127.0.0.1:8888*) of the first example, but "GET" in the last one. It should always be "POST", but url-retrieve somehow doesn't work this way...

Can you check it with shorter delay, something like 0.01?

alphaho commented 11 years ago

so the array is not we want?

alphaho commented 11 years ago

Why we get the array or dict?

Here's with 0.01:

HTTP/1.1 200 OK
Content-Length: 79
Etag: "bb0a7757f6c5fcfd4d48c0fbdf943709de3cfe10"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 15:27:37 GMT; Path=/

["c8c9468a-47bf-487c-ad57-56949c93fb29","88e324e0-c9db-41fc-82fa-63fb8d7b32d7"]
alphaho commented 11 years ago

Why we get the array or dict?

Here's with 0.01:

HTTP/1.1 200 OK
Content-Length: 79
Etag: "bb0a7757f6c5fcfd4d48c0fbdf943709de3cfe10"
Content-Type: text/html; charset=UTF-8
Server: TornadoServer/2.1
Set-Cookie: username=; expires=Mon, 05 Dec 2011 15:27:37 GMT; Path=/

["c8c9468a-47bf-487c-ad57-56949c93fb29","88e324e0-c9db-41fc-82fa-63fb8d7b32d7"]
alphaho commented 11 years ago

so it returns something with the array is the same as with an empty one?

alphaho commented 11 years ago

when it's 0.033 - 0.034 it will return a dict

alphaho commented 11 years ago

when it's 0.033 - 0.034 it will return a dict

tkf commented 11 years ago

Thanks for the detailed check!

Just a quick fix. Evaluate this and open a notebook. I hope it works.

(defun ein:kernel-start (kernel notebook-id)
  "Start kernel of the notebook whose id is NOTEBOOK-ID."
  (run-with-idle-timer
   0.1 nil
   (lambda (kernel notebook-id)
     (unless (ein:$kernel-running kernel)
       (ein:query-singleton-ajax
        (list 'kernel-start (ein:$kernel-kernel-id kernel))
        (concat (ein:url (ein:$kernel-url-or-port kernel)
                         (ein:$kernel-base-url kernel))
                "?" (format "notebook=%s" notebook-id))
        :type "POST"
        :parser #'ein:json-read
        :success (cons #'ein:kernel--kernel-started kernel))))
   kernel notebook-id))
alphaho commented 11 years ago

0.033 is the turing point, as it will return a dict or array randomly

alphaho commented 11 years ago

0.033 is the turing point, as it will return a dict or array randomly

alphaho commented 11 years ago

it works now. :-)

alphaho commented 11 years ago

it works now. :-)

alphaho commented 11 years ago

but 0.1 doesn't work. It works when I change it to 1. Still testing....

alphaho commented 11 years ago

but 0.1 doesn't work. It works when I change it to 1. Still testing....

alphaho commented 11 years ago

tested with servral values, fails under 0.465, works starts with 0.47 havn't tested between 0.465 and 0.47 with both exclusive