Problems with autoloader js & websocket related with proxy protected sites. Apache2 - Bokeh server HTTPS

Hi my name is Adrián.

I was post a topic some few weeks ago waiting for the SSL connection on Bokeh server. Finally, the release of the version 1.4.0 was be usefully to show my Flask python application in a web page with SSL security. But at present I have a problem related with.

The problem is related with people that try to enter to the web and Bokeh don’t load (autoload.js can’t complete the request, image attached).

*I changed css and js to version 1.4.0(not solution).

These people was navigate to my web from “Free Anonymous Surfing or Browse with Privacy Protection”. On the one hand, I thought that Bokeh server/Apache didn’t know what address they have because they hide this information (using Proxy?). For this reason, I think that the request remaining waiting and it can’t send anything. On the other hand, I think it could be related with the Websocket creation of Bokeh. I suspect about this two possible facts but I am not sure about it. Next, I post the server info and command to run Bokeh server:

apache = 2.4.29-1ubuntu4.11
bokeh = 1.4.0
Flask = 1.0.2
python = 3.7

[FLASK APP]

command = “bokeh serve app1.py app2.py --ssl-certfile=fullchain.pem --ssl-keyfile=privkey.pem --allow-websocket-origin=host --port=5006 --address host --use-xheaders &”

@app.route("/graphic")
def graphic():
script_1 = server_document(host + “/app1”)
return render_template(
“graphic.html”, app1=script_1, template=“Flask”
)

I post this to try found someone knows what could be happening. Also, I would like congrats Bokeh team for the new design of the page and this new version 1.4.0 that is great too.

Thank you.
Regards,
Adrián.

As a continue of the explanation I write above. I have used one of these “adress protective” browsers in order to reproduce the error and it return this:

The 404 for the source map is annoying but harmless, and can be safely ignored. We will be removing the source map URL comments in the published bundles on the next release and these will cease.

As for the other, I can’t really speculate with the information on hand. Useful things to do:

  • set `–log-level=debug on running the Bokeh server
  • report back Bokeh server console logs after a failed connection
1 Like

Hi @Bryan.
First of all thank you for your reply and sorry for answer really late. I was so busy this week with work. On one hand, the problem with “…navigate to my web from “Free Anonymous Surfing or Browse with Privacy Protection”…” was solved using the browser Tor (you can configure it for no blocking javascript). The reason of this problem was that some of these “browse with privacy protection” blocks the javascript execution, especially Bokeh. That fact does that Bokeh does not be loaded.

On the other hand, some people using browsers like Chrome, Firefox,… did not see Bokeh. It’s similar like the problem I explained above, but in this case, I suspect that some firewall configuration blocks the request of this “autoload.js” (image below, same case that I expose above).

image

I will try to post the debug log in order to help you to understand whats going on.

Thank your time.

Best regards,
Adrián.

@Adrian I look forward to seeing what you find and helping if I am able. Though I do feel obliged to state clearly that Bokeh is fundamentally a JavaScript tool. So if there are users who have disabled JS execution, or are in an environment where it is blocked, then standard Bokeh content is not going to function for them, and there is nothing that can be done about that.

The only other alternative might be to generate PNG exports, but of course you will lose Bokeh’s interactive capabilities.

1 Like

@Bryan thank you for offer me your help. I set the level-log into the mode debug and write some lines these days:

1 warning

2019-11-28 16:09:08,281 Configuring for SSL termination
2019-11-28 16:09:08,284 Host wildcard ‘*’ will allow connections originating from multiple (or possibly all) hostnames or IPs. Use non-wildcard values to restrict access explicitly
2019-11-28 16:09:08,286 User authentication hooks NOT provided (default user enabled)
2019-11-28 16:09:08,295 Bokeh app running at: http://alf06.uab.es:506/dimerbow_crystal
2019-11-28 16:09:08,295 Bokeh app running at: http://alf06.uab.es:506/dimerbow_simulation
2019-11-28 16:09:08,295 Starting Bokeh server with process id: 31555

2 warning

2019-11-28 20:10:40,719 ServerConnection created
2019-11-28 20:12:43,388 WebSocket connection closed: code=None, reason=None
2019-11-29 02:05:22,857 Uncaught exception, closing connection.
Traceback (most recent call last):
File “/usr/local/lib/python3.6/dist-packages/tornado/iostream.py”, line 709, in _handle_events
self._handle_read()
File “/usr/local/lib/python3.6/dist-packages/tornado/iostream.py”, line 1581, in _handle_read
self._do_ssl_handshake()
File “/usr/local/lib/python3.6/dist-packages/tornado/iostream.py”, line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File “/usr/lib/python3.6/ssl.py”, line 1077, in do_handshake
self._sslobj.do_handshake()
File “/usr/lib/python3.6/ssl.py”, line 689, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
2019-11-29 02:05:22,860 Exception in callback None()
handle:
Traceback (most recent call last):
File “/usr/lib/python3.6/asyncio/events.py”, line 145, in _run
self._callback(*self._args)
File “/usr/local/lib/python3.6/dist-packages/tornado/platform/asyncio.py”, line 122, in _handle_events
handler_func(fileobj, events)
File “/usr/local/lib/python3.6/dist-packages/tornado/stack_context.py”, line 300, in null_wrapper
return fn(*args, **kwargs)
File “/usr/local/lib/python3.6/dist-packages/tornado/iostream.py”, line 709, in _handle_events
self._handle_read()
File “/usr/local/lib/python3.6/dist-packages/tornado/iostream.py”, line 1581, in _handle_read
self._do_ssl_handshake()
File “/usr/local/lib/python3.6/dist-packages/tornado/iostream.py”, line 1501, in _do_ssl_handshake
self.socket.do_handshake()
File “/usr/lib/python3.6/ssl.py”, line 1077, in do_handshake
self._sslobj.do_handshake()
File “/usr/lib/python3.6/ssl.py”, line 689, in do_handshake
self._sslobj.do_handshake()
OSError: [Errno 0] Error
2019-11-29 02:05:23,927 WebSocket connection opened
2019-11-29 02:05:23,928 ServerConnection created

3 warning

2019-12-03 08:55:02,142 SSL Error on 10 (‘79.154.249.204’, 57301): [SSL: INAPPROPRIATE_FALLBACK] inappropriate fallback (_ssl.c:852)

4 warning

2019-12-04 15:32:11,169 Starting Bokeh server version 1.4.0 (running on Tornado 5.1.1)
2019-12-04 15:32:11,170 Configuring for SSL termination
2019-12-04 15:32:11,173 Host wildcard ‘’ will allow connections originating from multiple (or possibly all) hostnames or IPs. Use non-wildcard values to restrict access explicitly
2019-12-04 15:32:11,175 User authentication hooks NOT provided (default user enabled)
2019-12-04 15:32:11,175 These host origins can connect to the websocket: [’
’]
2019-12-04 15:32:11,177 Patterns are:
2019-12-04 15:32:11,180 [(’/dimerbow_crystal/?’,
2019-12-04 15:32:11,180 <class ‘bokeh.server.views.doc_handler.DocHandler’>,
2019-12-04 15:32:11,180 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b97f54630>,
2019-12-04 15:32:11,180 ‘bokeh_websocket_path’: ‘/dimerbow_crystal/ws’}),
2019-12-04 15:32:11,180 (’/dimerbow_crystal/ws’,
2019-12-04 15:32:11,180 <class ‘bokeh.server.views.ws.WSHandler’>,
2019-12-04 15:32:11,181 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b97f54630>,
2019-12-04 15:32:11,181 ‘bokeh_websocket_path’: ‘/dimerbow_crystal/ws’}),
2019-12-04 15:32:11,181 (’/dimerbow_crystal/metadata’,
2019-12-04 15:32:11,181 <class ‘bokeh.server.views.metadata_handler.MetadataHandler’>,
2019-12-04 15:32:11,181 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b97f54630>,
2019-12-04 15:32:11,181 ‘bokeh_websocket_path’: ‘/dimerbow_crystal/ws’}),
2019-12-04 15:32:11,181 (’/dimerbow_crystal/autoload.js’,
2019-12-04 15:32:11,181 <class ‘bokeh.server.views.autoload_js_handler.AutoloadJsHandler’>,
2019-12-04 15:32:11,182 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b97f54630>,
2019-12-04 15:32:11,182 ‘bokeh_websocket_path’: ‘/dimerbow_crystal/ws’}),
2019-12-04 15:32:11,182 (’/dimerbow_simulation/?’,
2019-12-04 15:32:11,182 <class ‘bokeh.server.views.doc_handler.DocHandler’>,
2019-12-04 15:32:11,182 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b945abe80>,
2019-12-04 15:32:11,182 ‘bokeh_websocket_path’: ‘/dimerbow_simulation/ws’}),
2019-12-04 15:32:11,182 (’/dimerbow_simulation/ws’,
2019-12-04 15:32:11,182 <class ‘bokeh.server.views.ws.WSHandler’>,
2019-12-04 15:32:11,183 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b945abe80>,
2019-12-04 15:32:11,183 ‘bokeh_websocket_path’: ‘/dimerbow_simulation/ws’}),
2019-12-04 15:32:11,183 (’/dimerbow_simulation/metadata’,
2019-12-04 15:32:11,183 <class ‘bokeh.server.views.metadata_handler.MetadataHandler’>,
2019-12-04 15:32:11,183 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b945abe80>,
2019-12-04 15:32:11,183 ‘bokeh_websocket_path’: ‘/dimerbow_simulation/ws’}),
2019-12-04 15:32:11,183 (’/dimerbow_simulation/autoload.js’,
2019-12-04 15:32:11,183 <class ‘bokeh.server.views.autoload_js_handler.AutoloadJsHandler’>,
2019-12-04 15:32:11,183 {‘application_context’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b945abe80>,
2019-12-04 15:32:11,184 ‘bokeh_websocket_path’: ‘/dimerbow_simulation/ws’}),
2019-12-04 15:32:11,184 (’/?’,
2019-12-04 15:32:11,184 <class ‘bokeh.server.views.root_handler.RootHandler’>,
2019-12-04 15:32:11,184 {‘applications’: {’/dimerbow_crystal’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b97f54630>,
2019-12-04 15:32:11,184 ‘/dimerbow_simulation’: <bokeh.server.contexts.ApplicationContext object at 0x7f4b945abe80>},
2019-12-04 15:32:11,184 ‘index’: None,
2019-12-04 15:32:11,184 ‘prefix’: ‘’,
2019-12-04 15:32:11,184 ‘use_redirect’: True}),
2019-12-04 15:32:11,184 (’/static/(.*)’,
2019-12-04 15:32:11,184 <class ‘bokeh.server.views.static_handler.StaticHandler’>)]

5 warning

2019-12-04 15:32:13,804 WebSocket connection opened
2019-12-04 15:32:13,804 Receiver created for Protocol(‘1.0’)
2019-12-04 15:32:13,805 ProtocolHandler created for Protocol(‘1.0’)
2019-12-04 15:32:13,806 ServerConnection created
2019-12-04 15:32:13,922 Sending pull-doc-reply from session ‘Ta663aQB7l0FbOL684CeImEMs4kDBncCMtSIq8wobfYI’
2019-12-04 15:32:26,198 [pid 19635] 1 clients connected
2019-12-04 15:32:26,198 [pid 19635] /dimerbow_crystal has 1 sessions with 0 unused
2019-12-04 15:32:26,198 [pid 19635] /dimerbow_simulation has 1 sessions with 1 unused
2019-12-04 15:32:41,201 [pid 19635] 1 clients connected
2019-12-04 15:32:41,202 [pid 19635] /dimerbow_crystal has 1 sessions with 0 unused
2019-12-04 15:32:41,202 [pid 19635] /dimerbow_simulation has 1 sessions with 1 unused
2019-12-04 15:32:45,192 Scheduling 1 sessions to discard
2019-12-04 15:32:45,193 Discarding session ‘TyFAPwjDL6mIlsfdreXFRfkQtQv4T3ZOsv2s6CxkwVci’ last in use 31399.55800819397 milliseconds ago
2019-12-04 15:32:45,193 Deleting 1 modules for <bokeh.document.document.Document object at 0x7f4b5e1fbcc0>

6 warning

2019-12-08 17:16:06,250 Starting Bokeh server version 1.4.0 (running on Tornado 5.1.1)
2019-12-08 17:16:06,251 Configuring for SSL termination
2019-12-08 17:16:06,254 Cannot start Bokeh server, port 506 is already in use

I don’t know if some of these warnings are related with the problem of the loading of “autoload.js” but I suppose that is related with the 4th warning. Sorry for the long text and I expect that this would help you to give me an answer and solve the problem.

Thank you for your time,
Adrián.

@Adrian Most of those are not warnings at all?

The only issue I see in logs is in 2 and 3 where Tornado is reporting exceptions during SSL handshake. I am not sure what might cause that besides bad or incorrect SSL certs being provided.

Number 6 states exactly that you already have a Bokeh server running on the default port, so it can’t start up. That’s an OS-level restriction and nothing to do with Bokeh. To run more than one at Bokeh server at once you would need to explicitly supply different ports to listen on.

All rest seem to indicate normal operation. In particular Number 5 actually shows websocket connections being made and session/documents being created for them. What happened in the browser in this instance?

To be clear, only logs that are important are ones that correspond to when things don’t work in the browser. The most useful thing is a single set: browser JS log, bokeh server log, and Apache log, all corresponding to a single “failed” access attempt. It’s unclear where the problem might be, so the entire cross section for a single failure is what is needed, to try and narrow that down.

1 Like

@Bryan I am sorry not to be clear and thank you for your attention. I did not known what could be the reason. I tried to ask people with the problem to view Bokeh and they report me the next:

JS LOG


(They tried to disable AdBlock if it interference but did not work)


Detailed:

Bokeh Serve log

2019-12-11 15:02:05,941 [pid 25930] 0 clients connected
2019-12-11 15:02:05,941 [pid 25930] /dimerbow_crystal has 0 sessions with 0 unused
2019-12-11 15:02:05,941 [pid 25930] /dimerbow_simulation has 0 sessions with 0 unused

(The connection never it is performed between the user with the problem and Bokeh)

Apache log (Nothing saying an error)

[Wed Dec 11 15:19:52.704929 2019] [core:debug] [pid 27431:tid 140267181041408] protocol.c(2257): [client 129.129.195.114:55120] AH03155: select protocol from , choices=h2,http/1.1 for server alf06.uab.es
[Wed Dec 11 15:19:52.758392 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758438 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.758508 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758524 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.758578 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758616 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.758669 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758684 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.758734 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758747 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.758797 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758812 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.758862 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of Require all granted: granted
[Wed Dec 11 15:19:52.758876 2019] [authz_core:debug] [pid 27431:tid 140267181041408] mod_authz_core.c(809): [client 129.129.195.114:55120] AH01626: authorization result of : granted
[Wed Dec 11 15:19:52.761965 2019] [deflate:debug] [pid 27431:tid 140267181041408] mod_deflate.c(854): [client 129.129.195.114:55120] AH01384: Zlib: Compressed 3729 to 1256 : URL /dimerbow/
[Wed Dec 11 15:19:53.197316 2019] [core:debug] [pid 27426:tid 140267315259136] protocol.c(2257): [client 129.129.195.114:55122] AH03155: select protocol from , choices=h2,http/1.1 for server alf06.uab.es
[Wed Dec 11 15:19:53.198939 2019] [core:debug] [pid 27431:tid 140267038430976] protocol.c(2257): [client 129.129.195.114:55124] AH03155: select protocol from , choices=h2,http/1.1 for server alf06.uab.es
[Wed Dec 11 15:19:53.201655 2019] [core:debug] [pid 27431:tid 140267407079168] protocol.c(2257): [client 129.129.195.114:55126] AH03155: select protocol from , choices=h2,http/1.1 for server alf06.uab.es
[Wed Dec 11 15:19:53.206473 2019] [core:debug] [pid 27426:tid 140267407079168] protocol.c(2257): [client 129.129.195.114:55128] AH03155: select protocol from , choices=h2,http/1.1 for server alf06.uab.es
[Wed Dec 11 15:19:53.249379 2019] [authz_core:debug] [pid 27426:tid 140267315259136] mod_authz_core.c(809): [client 129.129.195.114:55122] AH01626: authorization result of Require all granted: granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.249430 2019] [authz_core:debug] [pid 27426:tid 140267315259136] mod_authz_core.c(809): [client 129.129.195.114:55122] AH01626: authorization result of : granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.249838 2019] [authz_core:debug] [pid 27431:tid 140267038430976] mod_authz_core.c(809): [client 129.129.195.114:55124] AH01626: authorization result of Require all granted: granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.249875 2019] [authz_core:debug] [pid 27431:tid 140267038430976] mod_authz_core.c(809): [client 129.129.195.114:55124] AH01626: authorization result of : granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.252276 2019] [authz_core:debug] [pid 27431:tid 140267407079168] mod_authz_core.c(809): [client 129.129.195.114:55126] AH01626: authorization result of Require all granted: granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.252347 2019] [authz_core:debug] [pid 27431:tid 140267407079168] mod_authz_core.c(809): [client 129.129.195.114:55126] AH01626: authorization result of : granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.252426 2019] [deflate:debug] [pid 27426:tid 140267315259136] mod_deflate.c(854): [client 129.129.195.114:55122] AH01384: Zlib: Compressed 1666 to 551 : URL /dimerbow/graphic_crystal, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.256071 2019] [deflate:debug] [pid 27431:tid 140267038430976] mod_deflate.c(854): [client 129.129.195.114:55124] AH01384: Zlib: Compressed 7456 to 2101 : URL /dimerbow/structure_crystal, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.256415 2019] [deflate:debug] [pid 27431:tid 140267407079168] mod_deflate.c(854): [client 129.129.195.114:55126] AH01384: Zlib: Compressed 1676 to 550 : URL /dimerbow/graphic_simulation, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.258213 2019] [authz_core:debug] [pid 27426:tid 140267407079168] mod_authz_core.c(809): [client 129.129.195.114:55128] AH01626: authorization result of Require all granted: granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.258258 2019] [authz_core:debug] [pid 27426:tid 140267407079168] mod_authz_core.c(809): [client 129.129.195.114:55128] AH01626: authorization result of : granted, referer: https://alf06.uab.es/dimerbow/
[Wed Dec 11 15:19:53.261362 2019] [deflate:debug] [pid 27426:tid 140267407079168] mod_deflate.c(854): [client 129.129.195.114:55128] AH01384: Zlib: Compressed 11601 to 2635 : URL /dimerbow/structure_simulation, referer: https://alf06.uab.es/dimerbow/

Among all this report I think that people that can’t see Bokeh Server (error on autoload.js) also the browser don’t show the websocket connection. Reason why I suspect that they have some firewall preferences to block that. I don’t know your opinion about it. If is true we can’t do nothing about it.

Thank you @Bryan for your time and attention. Always are you kind with the users and you are try to give a solution.

Best regards,
Adrian.

In the first screenshot, the failed autoload.js loads are attempting to load from port 506, have you made some change to the port configuration? Default port for Bokeh server without any modification is always 5006.

1 Like

I change the port from 5006 to 506 for this problem. I read that some institutions have preferences to blocks ports higher than ~1024 for security reasons. I asked to the user with the problem to ask the system admin of the institution if they have any configuration that could blocks autoload.js. If I have news I will tell you.

Thank you for all @Bryan.

Regards,
Adrián.

@Adrian It is usually ports lower than 1024 that are protected by the OS from user-space apps running on them. That is specifically why we chose a port higher than 1024 as the default. I suggest you try on the standard default port (or at least a port higher than 1024).

1 Like

@Adrian I should clarify more: Any org can choose to block whatever ports or range of ports they want as a matter of policy. It could be that in this instance, all ports except some pre-approved whitelist are blocked. There’s nothing we could do about that, though. The only solution would be to get the admins to open a port for Bokeh apps to use.

1 Like

Yes, as I told you above and you say now, it could be the reason and not a problem with my app and Bokeh. I asked them about this type of whitelist or restriction with ports.

Thank you @Bryan and sorry to stole some of your time.

Have a nice day,
Adrián.