Adding user to proxy fails

[yuvipanda]

Bug description

On first login, a user's route fails to be added to the proxy (with the TOML proxy).

May 15 12:56:58 sms.localdomain python3[13384]: [I 2020-05-15 12:56:58.525 JupyterHub proxy:262] Adding user username to proxy /user/username/ => http://127.0.0.1:60417
May 15 12:56:58 sms.localdomain python3[13384]: /opt/hub/lib/python3.7/site-packages/jupyterhub_traefik_proxy/traefik_utils.py:42: RuntimeWarning: Escape character '_' cannot be a safe character. Set allow_collisions=True if you want to allow ambiguous escaped strings.
May 15 12:56:58 sms.localdomain python3[13384]: return server_type + "_" + escapism.escape(routespec, safe=safe)
May 15 12:56:58 sms.localdomain python3[13384]: [E 2020-05-15 12:56:58.529 JupyterHub base:876] Failed to add username to proxy!
May 15 12:56:58 sms.localdomain python3[13384]: Traceback (most recent call last):
May 15 12:56:58 sms.localdomain python3[13384]: File "/opt/hub/lib/python3.7/site-packages/jupyterhub/handlers/base.py", line 869, in finish_user_spawn
May 15 12:56:58 sms.localdomain python3[13384]: await self.proxy.add_user(user, server_name)
May 15 12:56:58 sms.localdomain python3[13384]: File "/opt/hub/lib/python3.7/site-packages/jupyterhub/proxy.py", line 274, in add_user
May 15 12:56:58 sms.localdomain python3[13384]: {'user': user.name, 'server_name': server_name},
May 15 12:56:58 sms.localdomain python3[13384]: File "/opt/hub/lib/python3.7/site-packages/jupyterhub_traefik_proxy/toml.py", line 191, in add_route
May 15 12:56:58 sms.localdomain python3[13384]: self.toml_dynamic_config_file, self.routes_cache
May 15 12:56:58 sms.localdomain python3[13384]: File "/opt/hub/lib/python3.7/site-packages/jupyterhub_traefik_proxy/traefik_utils.py", line 153, in persist_routes
May 15 12:56:58 sms.localdomain python3[13384]: toml.dump(routes_dict, config_fd)
May 15 12:56:58 sms.localdomain python3[13384]: File "/opt/hub/lib/python3.7/site-packages/toml/encoder.py", line 29, in dump
May 15 12:56:58 sms.localdomain python3[13384]: d = dumps(o, encoder=encoder)
May 15 12:56:58 sms.localdomain python3[13384]: File "/opt/hub/lib/python3.7/site-packages/toml/encoder.py", line 67, in dumps
May 15 12:56:58 sms.localdomain python3[13384]: raise ValueError("Circular reference detected")
May 15 12:56:58 sms.localdomain python3[13384]: ValueError: Circular reference detected
May 15 12:56:58 sms.localdomain python3[13384]: [E 2020-05-15 12:56:58.531 JupyterHub base:878] Stopping username to avoid inconsistent state

Expected behaviour

The user's route is added successfully.

Actual behaviour

User spawn fails, succeeds when I try again.

[yuvipanda]

Will try to provide reproducible case soon.

[yuvipanda]

I dug in to the content it's trying to dump with TOML, and ended up with

{
	"frontends": {
		"frontend__2F": {
			"backend": "backend__2F",
			"passHostHeader": true,
			"routes": {
				"test": {
					"rule": "PathPrefix:/",
					"data": "{\"hub\": true}"
				}
			}
		},
		"frontend__2Fuser_2Fyuvipanda": {
			"backend": "backend__2Fuser_2Fyuvipanda",
			"passHostHeader": true,
			"routes": {
				"test": {
					"rule": "PathPrefix:/user/yuvipanda",
					"data": "{\"user\": \"yuvipanda\", \"server_name\": \"\"}"
				}
			}
		},
		"frontend__2Fuser_2Fusername": {
			"backend": "backend__2Fuser_2Fusername",
			"passHostHeader": true,
			"routes": {
				"test": {
					"rule": "PathPrefix:/user/username",
					"data": "{\"user\": \"username\", \"server_name\": \"\"}"
				}
			}
		}
	},
	"backends": {
		"backend__2F": {
			"servers": {
				"server1": {
					"url": "http://127.0.0.1:8081",
					"weight": 1
				}
			}
		},
		"backend__2Fuser_2Fyuvipanda": {
			"servers": {
				"server1": {
					"url": "http://127.0.0.1:41224",
					"weight": 1
				}
			}
		},
		"backend__2Fuser_2Fusername": {
			"servers": {
				"server1": {
					"url": "http://127.0.0.1:38844",
					"weight": 1
				}
			}
		}
	}
}

Not sure if that's circular

[yuvipanda]

I could reproduce this with this Python file + code: https://gist.github.com/yuvipanda/7d59e9d00833739a6ddacfed6bb0338c

I can't figure out what is circular here

[GeorgianaElena]

@yuvipanda, I managed to reproduce this too with your test after I upgraded the toml package.
It has something to do with the release from 2 days ago: https://github.com/uiri/toml/releases.

I'll investigate if this release exposed an existing bug in traefik-proxy or there is some sort of breaking change.

[GeorgianaElena]

I managed to reproduce this with a smaller json: https://gist.github.com/GeorgianaElena/6d0c5b0357a1b43cfb25651c23ba9983.

Note that if the backend name is "backend__2Fuser_2Fyuvi" instead of "backend__2Fuser_2Fyuvipanda", it works. This make me think that the memory is somehow messed up when looking for circular references.

The commit that seems relevant is this one: uiri/toml@7dd67a6. Note the use of id that I think is to blame.

There is a similar issue opened in toml github repo: uiri/toml#295.

@yuvipanda, do you think we should pin the version of toml in traefik-proxy to the previous one (that worked) until this is fixed?

[dhirschfeld]

do you think we should pin the version of toml in traefik-proxy to the previous one (that worked) until this is fixed?

I think that would be very useful for other users to not stumble into this problem however they would only get the benefit if there was a corresponding release... which adds admin overhead.

[yuvipanda]

@GeorgianaElena wow, great debugging! Thank you for being so quick on this :)

Yes, I think we should pin version and make a release. We can unpin after upstream fixes it.

Thanks!