Sessions reused when behind IIS Proxy

trevoa · May 1, 2024, 7:24pm

I’m trying to use IIS with URL Rewrite as a reverse proxy to a Bokeh server listening on port 5006. The Bokeh server is being started from a panel serve command as I am using Holoviz Panel to create a webapp.

When I connect to the Bokeh server directly via port 5006 with two separate browser tabs, I get assigned two sessions which is what I desire and expect.

Logs when connecting via port 5006

2024-05-01 12:15:19,181 Subprotocol header received
2024-05-01 12:15:19,182 Supplied subprotocol headers: ['bokeh', 'eyJzZXNzaW9uX2lkIjogIjFpbVJaSjBqM094M0JNWUVQUHEzOE82SkgxRjFsV2xPckxqTGxYdTJHenRhIiwgInNlc3Npb25fZXhwaXJ5IjogMTcxNDU5MTIxNiwgIl9fYmtfX3psaWJfIjogImVOcDFVMnR2MmpBVV9TdFJQdTFCd002VFVGVVRwZENtRzNUbFdTcWt5WFp1RXBja1prbWdsTkhfUGlkcHQxRnA4TVc1NV9nLXpybi1wVVpBZk1oeXRhUDhVcTlGWHNpREdndEc0a2gtZEN5RWJMV2hxRDJScHNBS0x0SVNYd05zTkJMekhWUVlZUkZva2xGa0lpN2hoT3cxRXNJNUt0RUpNSzBYYVROU0lpdTFGMlVpNGR0a3BaN3R6bGNxMXMyVlpLM1VJV2VaeUVWUUtIMF9oUGZvU0JSYXQzbVJrZFJfaFZ4M3BaNmsxNGFDOGhqS0tsOU9DMnZmWTFJRUlrdnFEaFk4OWNWVFhsLWZiY0pNenE5NWFRNXNtNEUyaHA5YnlJdFNEeFZYakJ3eXJSdENXaWt6RkFjZXg2UmxOWkh5NFRXVE1wb3FHRFhSbVNJRHRubW03RzN6bzlMZGJHSllBUDNLaTVabE9FM0RWajU4dlo0T3Z6V1VtSzlCdVFLMkZoLVZTZzlveVVtYnFQd3JFeEtRakw5ZGtXTDh4Y3AydW96QnBtcWxnSDNSaW9va2JoQlppak5TdXRQYWw1SFAtX2ZSSkQ3N2VZNmFib01uMHBrVzJmSGc5ZmdFZFBNVzNhUmg0MVByVTBWdG55VEllWmlDcjhHZVJTUU5RVnBBallybXZFazlnSUpGMm9RWGxRV3BTT0VVR1FxX1JtVHRrQlR2MEZMbHlqcDhHci1FZWlOOXdiWko2Y0VmQ2JSLXlvVFAwN0NFd3dQZk5CUWZBdWswTkJTYU5aUkRYdmpfc0xfSnRyZHl5SklOcVRhYk5DQ3RKU2xKWHFDTlpNZmFrTWlpOVpybzJHWTJJcFE2S0FBVE1ZY1FSQmxqeU5hcDRXTEh0OXR0QTl4QTd0R0x6TUNFV0hPb245RldEcE9TQkxRXzcwaHJ5MS1aVnpfaURqcGkxTUVPTnRySWFCdnVVVGM2XzdseDFCSHF3UE1OWnZyOG1TYUQ0bUhpMlY3UE14NGU3dzdMYWRjYVh2Ynh3LU1NalM3SDY5dnBuVGxLeHRFd21UX2VUdnZtY2hxdFJ4TXY5M28zMi1VQ3g5NmpDTDMxWUV0MXk2SUxGN1BuaTR1SDY1dUlHZU40V2ZQVzVINzBSSzhHMXIxdVJYUXg0N2U4eS04VzFvNm1jVUdOLWNIckQ5WXNHUno4cTNuazhhZlFTLUl0dVI5dmxvdjk0VFhfUlIwZjdlaVYtMXpHYURyUDZUVTZQMW80UUlabEk5M3dzY044c0hGZ1dnWUF0bXdfSURLS0NESjF0LTJBeVJ4R0xWT2VrRzB4Z3hJYkljWktvMzdzOHl5b2hiUWMzVFdKaFktQmZNQy1iYUtBWXAwQi1BQkFtZTFhdWtNZHczWFk4YV9XbFZVa0M2dGRxc3g2ZWZrTmxUU0xqdyJ9']
2024-05-01 12:15:19,184 WebSocket connection opened
2024-05-01 12:15:19,185 Receiver created for Protocol()
2024-05-01 12:15:19,186 ProtocolHandler created for Protocol()
2024-05-01 12:15:19,186 ServerConnection created
2024-05-01 12:15:19,192 Sending pull-doc-reply from session '1imRZJ0j3Ox3BMYEPPq38O6JH1F1lWlOrLjLlXu2Gzta'
2024-05-01 12:15:19,223 Patching attribute 'dark_mode' of BrowserInfo(id='p1019', ...) with False
2024-05-01 12:15:19,225 Patching attribute 'device_pixel_ratio' of BrowserInfo(id='p1019', ...) with 1.25
2024-05-01 12:15:19,227 Patching attribute 'language' of BrowserInfo(id='p1019', ...) with 'en-US'
2024-05-01 12:15:19,228 Patching attribute 'webdriver' of BrowserInfo(id='p1019', ...) with False
2024-05-01 12:15:19,229 Patching attribute 'timezone' of BrowserInfo(id='p1019', ...) with 'America/Los_Angeles'     
2024-05-01 12:15:19,231 Patching attribute 'timezone_offset' of BrowserInfo(id='p1019', ...) with 420
2024-05-01 12:15:23,269 Running stats log job
2024-05-01 12:15:23,270 [pid 29848] 1 clients connected
2024-05-01 12:15:23,270 [pid 29848]   /app has 1 sessions with 0 unused
2024-05-01 12:15:25,024 Subprotocol header received
2024-05-01 12:15:25,024 Supplied subprotocol headers: ['bokeh', 'eyJzZXNzaW9uX2lkIjogIlB5UEl2M0I5cXJmS1dtcUl4cWtSbEc0cVBoM3d6VXZaSURyNE5qVUYzc0JqIiwgInNlc3Npb25fZXhwaXJ5IjogMTcxNDU5MTIyNCwgIl9fYmtfX3psaWJfIjogImVOcDFVOXR5MmpvVV9SV1BuOW9lREpKdC1VSW0weUVrSkU0TGFiaUdERE5uSkhuYlZ2Q0Yyb1lRU3Y3OXlIYlNIakpUZUpIM1d0cVh0YlotcVJGUUhfSkM3U3FfMUp1c0tPVkJqVE5PNDBoLWRBbENsdHBTMUg2V3BzQkxrYVVWdmdiWWFEUVdPNml3Q1hDdEgya3pXa0VydFJfbFdTSzJ5VW85MjUydlZLeWJLOGxhcVVQQjg2eklnbEs1OGtQNGlJNnlVdXUxTDNLYS1tLVE2NjdVa19UYU1HTWlocXJLVjNTS19JaHBHV1I1MG5Td0VLbWZQUmZOOWRrbXpPV0VtcGNXd0xjNWFHUDR1WVdpckNaV2NjMG9JTmQ2SWFUMTdNUHNJT0tZZGtnYktaX2VNaW1qcVlKUkc1MHBNbUNaWjhyZU1qOHJ2YzBtaGdXd2I2THNFTU51RzVieTZkdk5kUGk5cGNSaURjbzE4SFgyV2FuMWdJNmN0STJxdnpLaEFjM0YteFVweGgtc2FxZkhPV3pxVmtyWWw1Mm9UT0lXbGFVRXA1WC1uWDBWLVdmX01ackVael9QVWR0dGlZU0cwS0U3RWJ3ZG40RnQzcU9iTkd4OTZYeXBxYzVKZ2tLRUtmZ2E3SGxFMHhDa0JjeW9hZmE3MUFNb2VhUk5SRmxia0dZcG5DTER6RzhRV1R1azVRZTBVcm0yRHBfR0w2SFpPVF9qMjZUeTRMY0UybFhLTTEta1lRV0hCN0ZwS1Q0RTBtbG9LU3h2S1llaTlQX0hfaTdiM3NvaEt6YWsybXpTZ3JTUnBDSjVnVGFTSFd0REtvczJhd0pVWjFnblNPZllBY3Z3Q1hPd3l4ekx4SmJyTzlnSUVCaTZZd1J5ajE1bEJwNWxhd0hOUTluS1lWS2FnUGI3cFdpT19GVjU5U1B1b2lOR1hXeGp3MEdHWTdoSDNlai01Y1pSUjZnTEw3ZVk2X01YbGd6S3g0bG5lWDNQZUh5NlB5eW5QVEs4dk1LUFR6TTB1aHl2NzZiMzVpZ1pSOE5rX25RM3ZUS1gwMmc5bW5pRjE3X2RMaGM0OXA2eTBGc1B0a3duaEMxY3pGOHVMaDV2YmlOdWpPTmx3MXZUaDlFenV4NlFCNTFFYkRFVGQ2SW43aGRreDlLNFpNYjg0RjBOMWp3WkhQenJlZVNKNTlCTDRpMTlHRy1XaV8zaExmOUZFeF90MkxYN1VzVllPaV9ZRFRvX0Vod2dnMWhJTjN4c2N4OHNISmpFQU1ERThnTXFvNGdpVTNjZEcweHVjMFpNZVVJVzRRYWpGa0tjVjBiOXV5X3lvQkdTMkxwclVvS1BnWHpBdm1XaVFQckZBWHdBWU54eWlXNHoyM0J0ZnZ5amRXMFZ6Y042bDJxelhsX19BNnN6Z1k4In0']2024-05-01 12:15:25,043 WebSocket connection opened
2024-05-01 12:15:25,044 Receiver created for Protocol()
2024-05-01 12:15:25,044 ProtocolHandler created for Protocol()
2024-05-01 12:15:25,045 ServerConnection created
2024-05-01 12:15:25,065 Sending pull-doc-reply from session 'PyPIv3B9qrfKWmqIxqkRlG4qPh3wzUvZIDr4NjUF3sBj'
2024-05-01 12:15:25,106 Patching attribute 'dark_mode' of BrowserInfo(id='p1263', ...) with False
2024-05-01 12:15:25,108 Patching attribute 'device_pixel_ratio' of BrowserInfo(id='p1263', ...) with 1.25
2024-05-01 12:15:25,110 Patching attribute 'language' of BrowserInfo(id='p1263', ...) with 'en-US'
2024-05-01 12:15:25,112 Patching attribute 'webdriver' of BrowserInfo(id='p1263', ...) with False
2024-05-01 12:15:25,116 Patching attribute 'timezone' of BrowserInfo(id='p1263', ...) with 'America/Los_Angeles'     
2024-05-01 12:15:25,118 Patching attribute 'timezone_offset' of BrowserInfo(id='p1263', ...) with 420
2024-05-01 12:15:25,276 Running session cleanup job
2024-05-01 12:15:38,267 Running stats log job
2024-05-01 12:15:38,267 [pid 29848] 2 clients connected
2024-05-01 12:15:38,267 [pid 29848]   /app has 2 sessions with 0 unused

However, if I go through the reverse proxy and connect with two separate browser tabs then both tabs get assigned the same session even though the Bokeh server recognizes two separate clients.

Logs going through IIS Reverse Proxy

2024-05-01 12:20:09,686 Supplied subprotocol headers: ['bokeh', 'eyJzZXNzaW9uX2lkIjogIjdtcUpSWnVhaTdoQmhBSjN1V20xbWw4anNSVHV2bHFBVWFndXdLNnZlaGR0IiwgInNlc3Npb25fZXhwaXJ5IjogMTcxNDU5MTUwNywgIl9fYmtfX3psaWJfIjogImVOcDFVMnRUcTBnUV9Tc1VuLTY5bTBsbUdCNGhsclVWSDFIVXhOVWtSbDIzdG9hWkJzWUFrd3RFWTI3ODd6dUFycXRWQzEtR1B0Mm5lX29jZnBrSk1BRkZhUTZNWC1haHluUGdsVlM1X2pUUEFWWm9tTW9uTUR1R09lUWNWbFVkcjJCVDlaSXFTenRzdFVvbFozVkJiMU5IZnR0OGpXYnAzczk5M1BVN01tTXg5TmlUak42T3p4Q3UzcU9yUE83ODZQMW9VdnVmQ0VvWjV5QVFiSGpDOGhqMm52WkQycVI1SDBPaDQ1d3JJZk80bmk3ZXlsWEhFQkNscklLT0VSWWRZMXRXNGpfWkY1cG9yZHZXMlpDai1iUURlVHRrblhTcXl1YVd4UEs2V0w5azRHRHMxa2dRb1luS0FZMVp4Wk02NWNFazNMT3BUWHczZEQzUjl4am5IaFhNd3dDMnk1aUk5TW4zUFU0ZnpKcGd6RFpvcElwblZvaXlhWUhyNkx5RUFnMWp5SnUyWTdXVmFjcDZUaGNiM3hZeUYtcTVOQ1l6Zy1oWjlnd2RjTzA5WS1QYTM0MmgzaElzSUR5WFZjLWhYcGU2eHJmejA5bjRvbU9rY2duR0NmQ2wtbTRjSm9YS29FY3N1N2tPTnFZc1lvVjhMemtXOFFkV2p6TUZqZzRUTkdmdERadHl1YzRlVEwxNmZXSExmdEJaRC1aWThrS1ZLcXBxQnZpS1RsU0ZodDJEZ3VYaURmTDlkZ2ZfMHFPeENtWGFpUEQ3NThib0R5MWRwSXFzbmVCdENXMzVmQlVYMnE4b3lFdmc2d0xRTmZ4Y1ExbTEtM3luR1lGV0NFMWwxZERuV3JUUHlGaUpGdEYyakxWTlBxTzFJTTFZWF9pT29IV0dVSHlkMVhKcDlCWmRGaktXT1V2UnZFaHJWSnQ1MVNKdlVtdjM2bE1OX1RrWWtMOEdya05KdjgwWUZnVzZVREVLUkExVDdubVI1WG1JT2haR05pVUU5Um0ya09lNHJzMzdBZ3NhbXEtNmtDdTFsTkQtc21zOWJNNHlRS25pTEUyMGVWRmZQeldmdFNNRHZDTjRRRHhDLTVqMnFiLXo2T0JfS25ZV3hnTjRPU1BjdW5rSnMxRjFQdzNjNERDZzk0OVgyN3ZaMEJrZkhaUDd4em1lSEYwdkwyZFg5aVM3VHNiWnplUGw3TmktbXlYTHlUUW9nOE96OWQyQ3BNR2ppb1BsYUIxYWpoTXVmTUpmRGc3dVQ4OFNUcV9UdXpadnlXNG56LUhKeUxtMW5DUmN6T1dsSE1xcmhmTVU1bWtWMHB0dGNEeGE4bXkwRlNjM1NTQ2Y0eUJMMS16MmVuVzMyR3pmLUFfYS1PUXBQUEZmNmxpWTM1VGhLZDdmT1NUQzFIR3hSUVh4dUFDWFJMWkRBWWpqaW9qcEtHYll0dnktQnpiM2VPalktb1JkaDlPUXVSaHpYdXZ6OTZZc29uYVJqbWY1Tm5QSUx0TG1FNjZObzVCWUhFQUFRTWhkMzdHODBLUDZUOTk5N0xxUmloVng0NVZHck5mWGZ3RHM1S1N4In0']
2024-05-01 12:20:09,689 WebSocket connection opened
2024-05-01 12:20:09,691 Receiver created for Protocol()
2024-05-01 12:20:09,692 ProtocolHandler created for Protocol()
2024-05-01 12:20:09,692 ServerConnection created
2024-05-01 12:20:09,695 Sending pull-doc-reply from session '7mqJRZuai7hBhAJ3uWm1ml8jsRTuvlqAUaguwK6vehdt'
2024-05-01 12:20:09,745 Patching attribute 'href' of Location(id='p1002', ...) with 'http://localhost/app'
2024-05-01 12:20:09,747 Patching attribute 'hostname' of Location(id='p1002', ...) with 'localhost'
2024-05-01 12:20:09,748 Patching attribute 'port' of Location(id='p1002', ...) with ''
2024-05-01 12:20:09,757 Patching attribute 'dark_mode' of BrowserInfo(id='p1019', ...) with False
2024-05-01 12:20:09,759 Patching attribute 'device_pixel_ratio' of BrowserInfo(id='p1019', ...) with 1.25
2024-05-01 12:20:09,761 Patching attribute 'language' of BrowserInfo(id='p1019', ...) with 'en-US'
2024-05-01 12:20:09,762 Patching attribute 'webdriver' of BrowserInfo(id='p1019', ...) with False
2024-05-01 12:20:09,769 Patching attribute 'timezone' of BrowserInfo(id='p1019', ...) with 'America/Los_Angeles'     
2024-05-01 12:20:09,770 Patching attribute 'timezone_offset' of BrowserInfo(id='p1019', ...) with 420
2024-05-01 12:20:14,552 Running stats log job
2024-05-01 12:20:14,552 [pid 32000] 1 clients connected
2024-05-01 12:20:14,552 [pid 32000]   /app has 1 sessions with 0 unused
2024-05-01 12:20:16,550 Running session cleanup job
2024-05-01 12:20:17,276 Subprotocol header received
2024-05-01 12:20:17,277 Supplied subprotocol headers: ['bokeh', 'eyJzZXNzaW9uX2lkIjogIjdtcUpSWnVhaTdoQmhBSjN1V20xbWw4anNSVHV2bHFBVWFndXdLNnZlaGR0IiwgInNlc3Npb25fZXhwaXJ5IjogMTcxNDU5MTUwNywgIl9fYmtfX3psaWJfIjogImVOcDFVMnRUcTBnUV9Tc1VuLTY5bTBsbUdCNGhsclVWSDFIVXhOVWtSbDIzdG9hWkJzWUFrd3RFWTI3ODd6dUFycXRWQzEtR1B0Mm5lX29jZnBrSk1BRkZhUTZNWC1haHluUGdsVlM1X2pUUEFWWm9tTW9uTUR1R09lUWNWbFVkcjJCVDlaSXFTenRzdFVvbFozVkJiMU5IZnR0OGpXYnAzczk5M1BVN01tTXg5TmlUak42T3p4Q3UzcU9yUE83ODZQMW9VdnVmQ0VvWjV5QVFiSGpDOGhqMm52WkQycVI1SDBPaDQ1d3JJZk80bmk3ZXlsWEhFQkNscklLT0VSWWRZMXRXNGpfWkY1cG9yZHZXMlpDai1iUURlVHRrblhTcXl1YVd4UEs2V0w5azRHRHMxa2dRb1luS0FZMVp4Wk02NWNFazNMT3BUWHczZEQzUjl4am5IaFhNd3dDMnk1aUk5TW4zUFU0ZnpKcGd6RFpvcElwblZvaXlhWUhyNkx5RUFnMWp5SnUyWTdXVmFjcDZUaGNiM3hZeUYtcTVOQ1l6Zy1oWjlnd2RjTzA5WS1QYTM0MmgzaElzSUR5WFZjLWhYcGU2eHJmejA5bjRvbU9rY2duR0NmQ2wtbTRjSm9YS29FY3N1N2tPTnFZc1lvVjhMemtXOFFkV2p6TUZqZzRUTkdmdERadHl1YzRlVEwxNmZXSExmdEJaRC1aWThrS1ZLcXBxQnZpS1RsU0ZodDJEZ3VYaURmTDlkZ2ZfMHFPeENtWGFpUEQ3NThib0R5MWRwSXFzbmVCdENXMzVmQlVYMnE4b3lFdmc2d0xRTmZ4Y1ExbTEtM3luR1lGV0NFMWwxZERuV3JUUHlGaUpGdEYyakxWTlBxTzFJTTFZWF9pT29IV0dVSHlkMVhKcDlCWmRGaktXT1V2UnZFaHJWSnQ1MVNKdlVtdjM2bE1OX1RrWWtMOEdya05KdjgwWUZnVzZVREVLUkExVDdubVI1WG1JT2haR05pVUU5Um0ya09lNHJzMzdBZ3NhbXEtNmtDdTFsTkQtc21zOWJNNHlRS25pTEUyMGVWRmZQeldmdFNNRHZDTjRRRHhDLTVqMnFiLXo2T0JfS25ZV3hnTjRPU1BjdW5rSnMxRjFQdzNjNERDZzk0OVgyN3ZaMEJrZkhaUDd4em1lSEYwdkwyZFg5aVM3VHNiWnplUGw3TmktbXlYTHlUUW9nOE96OWQyQ3BNR2ppb1BsYUIxYWpoTXVmTUpmRGc3dVQ4OFNUcV9UdXpadnlXNG56LUhKeUxtMW5DUmN6T1dsSE1xcmhmTVU1bWtWMHB0dGNEeGE4bXkwRlNjM1NTQ2Y0eUJMMS16MmVuVzMyR3pmLUFfYS1PUXBQUEZmNmxpWTM1VGhLZDdmT1NUQzFIR3hSUVh4dUFDWFJMWkRBWWpqaW9qcEtHYll0dnktQnpiM2VPalktb1JkaDlPUXVSaHpYdXZ6OTZZc29uYVJqbWY1Tm5QSUx0TG1FNjZObzVCWUhFQUFRTWhkMzdHODBLUDZUOTk5N0xxUmloVng0NVZHck5mWGZ3RHM1S1N4In0']
2024-05-01 12:20:17,278 WebSocket connection opened
2024-05-01 12:20:17,278 Receiver created for Protocol()
2024-05-01 12:20:17,278 ProtocolHandler created for Protocol()
2024-05-01 12:20:17,278 ServerConnection created
2024-05-01 12:20:17,291 Sending pull-doc-reply from session '7mqJRZuai7hBhAJ3uWm1ml8jsRTuvlqAUaguwK6vehdt'
2024-05-01 12:20:29,550 Running stats log job
2024-05-01 12:20:29,550 [pid 32000] 2 clients connected
2024-05-01 12:20:29,550 [pid 32000]   /app has 1 sessions with 0 unused

Why does Bokeh assign the same session to two clients behind the IIS Reverse Proxy and how can I avoid it? I unfortunately cannot avoid the use of IIS as a reverse proxy so I have to work around this. Thank you for your help.

Bryan · May 1, 2024, 8:02pm

You can look at what Bokeh does for retrieving sessions here:

bokeh/src/bokeh/server/views/session_handler.py at branch-3.5 · bokeh/bokeh · GitHub

The only way I can see for an existing session to be returned is if an existing session_id gets extracted from either: the HTTP args, the request headers, or the token in the websocket subprotocol header. You could modify that module to add some additional logging to see which branch is actually occurring.

Is it possible the proxy is caching or modifying the request in some way?

I guess it’s also possible that Panel has additional code paths besides the ones above. I would not know anything about that that, Panel is a different project with separate maintainers. cc @Philipp_Rudiger

Bryan · May 1, 2024, 8:10pm

Actually looking more closely at the output, it does appear that in the top case, Bokeh is receiving two distinct websocket sub-protocol headers, whereas in the bottom case Bokeh is receiving the same sub-protocol header twice.

I would say that is the proximate cause of the problem, but I don’t know why that would be happening for sure. Best guess is the proxy is caching something it should not. That could be the inbound sub-protocol header itself, or (I suppose) it could be caching the outbound initial page response, which (might?) result in the same token being sent again.

trevoa · May 1, 2024, 8:29pm

This was it! IIS was caching something in the background. I speculate it may have been caching requests coming from the same IP.

This is the setting I had to change in IIS to prevent this behavior.