Autosave failed; log full of "Forbidden" warnings; no indication in console

[rickyegeland]

I have just lost 2 days of code development work in a large-ish Jupyter notebook running on my laptop due to an unnoticed failure to autosave. I do not know how to reproduce this issue, but I will describe what happened and provide log output in the hopes this can lead to some resolution for this kind of issue. I am using jupyter notebook 5.5.0 on Mac OS 10.13.6 with python 3.6.8.

I typically close the laptop (put to sleep) and resume work in my Jupyter notebooks without a problem. But today I woke my laptop and noticed that the notebook was not executing new cells. I attempted to reconnect to the Kernel > Reconnect menu item. This failed, and the console indicated it would continue trying. I tried this a few times. Next (and this was the fatal step toward losing my coding work, I believe), I did ctl-r (refresh) in my browser to try to reinitiate a connection to the kernel. I was asked to enter a token. I found the token in my terminal log and entered it. When the notebook loaded, it was a version 2 days old. I verified in the terminal that notebook file was last modified 2 days ago. My work was lost.

Attached is the notebook log around the timeframe of the problem. To summarize, the output went like this, starting from a point where I woke the laptop and began working normally in the notebook:

[W 13:10:14.815 NotebookApp] WebSocket ping timeout after 29338692 ms.
[I 13:10:15.314 NotebookApp] Starting buffering for 381e32c8-ff88-41f2-98cc-51dc1833fa35:358789f7fe7d489bacf3ae181023606a
[I 11:22:36.359 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 11:30:09.660 NotebookApp] Adapting to protocol v5.1 for kernel 381e32c8-ff88-41f2-98cc-51dc1833fa35
[I 11:30:09.671 NotebookApp] Restoring connection for 381e32c8-ff88-41f2-98cc-51dc1833fa35:358789f7fe7d489bacf3ae181023606a
[I 11:30:36.013 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 11:32:36.026 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 11:34:35.986 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 11:36:37.483 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 11:46:26.468 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 11:48:26.470 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:06:41.313 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:08:41.307 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:10:41.301 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:12:41.309 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:14:41.296 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:16:41.288 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:18:41.292 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:26:41.284 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:28:41.282 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:30:41.287 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:32:41.247 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:34:41.427 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:55:05.278 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:57:05.273 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[I 12:59:05.271 NotebookApp] Saving file at /TESS DR1 Activity.ipynb
[W 14:43:38.888 NotebookApp] Forbidden
[W 14:43:38.890 NotebookApp] 403 GET /api/sessions?_=1548701411725 (::1) 17.76ms referer=http://localhost:8889/tree
[W 14:43:38.897 NotebookApp] Forbidden
[W 14:43:38.898 NotebookApp] 403 GET /api/terminals?_=1548701411726 (::1) 4.98ms referer=http://localhost:8889/tree
[W 14:45:21.778 NotebookApp] Forbidden
[W 14:45:21.778 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516511904 (::1) 1.85ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
...
... (above repeats for two days, spanning a few sleep/wake cycles)
...
[W 22:11:35.329 NotebookApp] Forbidden
[W 22:11:35.330 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 20.20ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 06:12:39.827 NotebookApp] WebSocket ping timeout after 7219418 ms.
[I 06:12:36.436 NotebookApp] Starting buffering for 381e32c8-ff88-41f2-98cc-51dc1833fa35:358789f7fe7d489bacf3ae181023606a
[W 06:12:36.518 NotebookApp] Forbidden
[W 06:12:36.537 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512123 (::1) 16.87ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 06:12:36.669 NotebookApp] Forbidden
[W 06:12:36.669 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 28.03ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:17:12.218 NotebookApp] Forbidden
[W 11:17:12.220 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512124 (::1) 11.51ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:17:12.309 NotebookApp] Forbidden
[W 11:17:12.310 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 24.20ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:19:12.023 NotebookApp] Forbidden
[W 11:19:12.026 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512125 (::1) 9.22ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:19:12.096 NotebookApp] Forbidden
[W 11:19:12.098 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 24.78ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:20:41.291 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:20:41.342 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 114.02ms referer=None
[W 11:20:43.434 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:20:43.437 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 5.64ms referer=None
[W 11:20:47.454 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:20:47.456 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 4.43ms referer=None
[W 11:20:55.495 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:20:55.497 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 2.73ms referer=None
[W 11:21:11.521 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:21:11.522 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 3.16ms referer=None
[W 11:21:11.885 NotebookApp] Forbidden
[W 11:21:11.885 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512126 (::1) 1.87ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:21:11.925 NotebookApp] Forbidden
[W 11:21:11.926 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 16.48ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:21:43.569 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:21:43.571 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 9.30ms referer=None
[W 11:22:47.626 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:22:47.629 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 4.49ms referer=None
[W 11:23:11.907 NotebookApp] Forbidden
[W 11:23:11.907 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512127 (::1) 0.72ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:23:11.935 NotebookApp] Forbidden
[W 11:23:11.935 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 4.49ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:25:11.870 NotebookApp] Forbidden
[W 11:25:11.871 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512128 (::1) 1.22ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:25:11.902 NotebookApp] Forbidden
[W 11:25:11.902 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 5.99ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:27:42.366 NotebookApp] Forbidden
[W 11:27:42.366 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512129 (::1) 1.35ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:27:42.399 NotebookApp] Forbidden
[W 11:27:42.399 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 4.55ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:30:50.773 NotebookApp] Forbidden
[W 11:30:50.773 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512130 (::1) 0.77ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:30:50.804 NotebookApp] Forbidden
[W 11:30:50.805 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 7.15ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:32:50.385 NotebookApp] Forbidden
[W 11:32:50.385 NotebookApp] 403 GET /api/contents/TESS%20DR1%20Activity.ipynb?content=0&_=1550516512131 (::1) 0.90ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:32:50.419 NotebookApp] Forbidden
[W 11:32:50.419 NotebookApp] 403 PUT /api/contents/TESS%20DR1%20Activity.ipynb (::1) 5.09ms referer=http://localhost:8889/notebooks/TESS%20DR1%20Activity.ipynb
[W 11:32:57.611 NotebookApp] Couldn't authenticate WebSocket connection
[W 11:32:57.616 NotebookApp] 403 GET /api/kernels/381e32c8-ff88-41f2-98cc-51dc1833fa35/channels?session_id=358789f7fe7d489bacf3ae181023606a (::1) 9.96ms referer=None
[I 11:33:39.962 NotebookApp] 302 GET /notebooks/TESS%20DR1%20Activity.ipynb (::1) 5.18ms
[W 11:33:40.392 NotebookApp] 404 GET /apple-touch-icon-precomposed.png (::1) 2.63ms referer=None
[W 11:33:40.397 NotebookApp] 404 GET /apple-touch-icon.png (::1) 2.11ms referer=None
[W 11:34:11.085 NotebookApp] 401 POST /login?next=%2Fnotebooks%2FTESS%2520DR1%2520Activity.ipynb (::1) 6.14ms referer=http://localhost:8889/login?next=%2Fnotebooks%2FTESS%2520DR1%2520Activity.ipynb
[I 11:34:35.233 NotebookApp] 302 POST /login?next=%2Fnotebooks%2FTESS%2520DR1%2520Activity.ipynb (::1) 6.18ms
[I 11:34:40.256 NotebookApp] Adapting to protocol v5.1 for kernel 381e32c8-ff88-41f2-98cc-51dc1833fa35

I believe the various Couldn't authenticate WebSocket connection are my attempts to reconnect the kernel, and [I 11:33:39.962 NotebookApp] 302 GET notebooks/TESS%20DR1%20Activity.ipynb (::1) 5.18ms is my ctl-r refresh of the webpage that ultimately lost my code.

I did not notice any warning is the notebook status area about the failure to autosave. If the underlying issue causing this autosave failure cannot be identified, it would be good to improve the monitoring of the autosave procedure to give a serious and visible warning to the user when autosave is not functioning.

A question: what can cause the (not very helpful) log warning "Forbidden"? Is it a response for the above http PUT, or something else?

[rickyegeland]

Just to answer part of my final question above: it looks like in the first instance "Forbidden" precedes "403 PUT", so the former is not a response to the latter.

[minrk]

Cookies being revoked or expiring could cause this.

If you open a new tab and login to the notebook server, you should be able to set a new cookie, which will then be used by subsequent saves in the first tab.

[rickyegeland]

Cookies being revoked or expiring could cause this.

OK, is there an issue for that behavior already?

(Note: I accidentally closed this issue a minute ago, then reopened)

[nofreewill42]

Cookies being revoked or expiring could cause this.

If you open a new tab and login to the notebook server, you should be able to set a new cookie, which will then be used by subsequent saves in the first tab.

1. Right click on Jupyter tab and then
2. Duplicate Tab
3. Close old tab
   Solved the problem for me in Firefox.

Variables remained intact, however keep in mind that if you are in the middle of a training and you do this, that training will not continue in the new tab and when you "continue" training in the new tab, optimizer's momentum will be restarted and that could ruin the smoothness of training.

[Flavasava1989]

How to fix this issue in google chrome

[planicka]

We still occasionally come across this problem even on github with the latest version.
Also according to our observation, it seems that the user's session expires and the cookie expires. There is a failure and the notebook is not stored correctly. All this happens only in the background and the user is not informed about the situation in any way.