${venv:env} does not actually set the Python interpreter to the virtualenv one

[Fuyukai]

Expected behavior

Setting the following:

pythonCommand = ["${venv:.venv}"]

Will cause esbonio to pick up the paths of the virtual environment automatically.

Actual behavior

Traceback (most recent call last):
  File "<frozen runpy>", line 198, in _run_module_as_main
  File "<frozen runpy>", line 88, in _run_code
  File "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio/sphinx_agent/__main__.py", line 3, in <module>
    from .server import main
  File "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio/sphinx_agent/server.py", line 18, in <module>
    from .patches import patch_sphinx
  File "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio/sphinx_agent/patches.py", line 14, in <module>
    from .util import send_message
  File "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio/sphinx_agent/util.py", line 12, in <module>
    from sphinx.locale import _TranslationProxy
ModuleNotFoundError: No module named 'sphinx'

If I modify util.py to print sys.path first (notice the incorrect numbers) there's nothing that has been added from the virtual environment at all:

['/home/lura/dev/libs/century-ring', '/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio', '/usr/lib/python313.zip', '/usr/lib/python3.13', '/usr/lib/python3.13/lib-dynload', '/usr/lib/python3.13/site-packages']

If I set the command to the absolute path, then it prints the correct path with the virtual environment paths:

['/home/lura/dev/libs/century-ring', '/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio', '/usr/lib/python313.zip', '/usr/lib/python3.13', '/usr/lib/python3.13/lib-dynload', '/home/lura/dev/libs/century-ring/.venv/lib/python3.13/site-packages', '/home/lura/dev/libs/century-ring/pysrc']

[Fuyukai]

Actually, printing sys.executable shows that it uses /usr/bin/python3.13 regardless if ${venv: is used.

[alcarney]

Actually, printing sys.executable shows that it uses /usr/bin/python3.13 regardless if ${venv: is used.

It sounds like maybe the configuration option is not being applied... a common theme around here at the moment! 😅

A few questions / things to check

• How are you setting pythonCommand? in VSCode's settings.json or a pyproject.toml file?
• Are being affected by It's impossible to configure the server for projects located in a folder with multiple "names" #813?

If you could share some of the debug logs (enabled by setting esbonio.logging.level = "debug") - especially those related to the configuration and creation of the sphinx process that would also be a great help

For example, this is what I see when using esbonio.sphinx.pythonCommand = ["${venv:.venv}"]

[esbonio.Configuration] ConfigurationContext(file_scope='file:///workspaces/develop/lib/esbonio/tests/workspaces/demo', workspace_scope='file:///workspaces/develop')
[esbonio.Configuration] esbonio.sphinx: {
  "buildCommand": [
    "sphinx-build",
    "-M",
    "dirhtml",
    ".",
    "./_build"
  ],
  "fallbackEnv": "/workspaces/develop/.vscode/extensions/esbonio/bundled/env",
  "enableDevTools": false,
  "pythonPath": [],
  "pythonCommand": [
    "${venv:.venv}"
  ],
  "configOverrides": {}
}
[esbonio.Configuration] SphinxConfig(enable_dev_tools=False, python_command=['${venv:.venv}'], build_command=['sphinx-build', '-M', 'dirhtml', '.', './_build'], config_overrides={}, env_passthrough=[], cwd='/workspaces/develop/lib/esbonio/tests/workspaces/demo', fallback_env='/workspaces/develop/.vscode/extensions/esbonio/bundled/env', python_path=[])
[esbonio.Configuration] Previous: None
[esbonio.Configuration] Current: SphinxConfig(enable_dev_tools=False, python_command=['${venv:.venv}'], build_command=['sphinx-build', '-M', 'dirhtml', '.', './_build'], config_overrides={}, env_passthrough=[], cwd='/workspaces/develop/lib/esbonio/tests/workspaces/demo', fallback_env='/workspaces/develop/.vscode/extensions/esbonio/bundled/env', python_path=[])
[esbonio.Configuration] ConfigChangeEvent(scope='file:///workspaces/develop/lib/esbonio/tests/workspaces/demo', value=SphinxConfig(enable_dev_tools=False, python_command=['${venv:.venv}'], build_command=['sphinx-build', '-M', 'dirhtml', '.', './_build'], config_overrides={}, env_passthrough=[], cwd='/workspaces/develop/lib/esbonio/tests/workspaces/demo', fallback_env='/workspaces/develop/.vscode/extensions/esbonio/bundled/env', python_path=[]), previous=None)
[esbonio] Scheduled task: <Task finished name='Task-11' coro=<SphinxManager._create_or_replace_client() done, defined at /workspaces/develop/.vscode/extensions/esbonio/bundled/libs/esbonio/server/features/sphinx_manager/manager.py:309> result=None>
[esbonio.SphinxManager] Cwd: /workspaces/develop/lib/esbonio/tests/workspaces/demo
[esbonio.SphinxManager] Build command: ['sphinx-build', '-M', 'dirhtml', '.', './_build']
[esbonio.SphinxManager] Client created for scope file:///workspaces/develop/lib/esbonio/tests/workspaces/demo
[esbonio.SphinxManager] SphinxClient[23a0f06c-646a-4dc4-9aeb-3b0449089201]: None -> ClientState.Starting
[esbonio.SphinxManager] Starting sphinx agent: /workspaces/develop/lib/esbonio/tests/workspaces/demo/.venv/bin/python -m sphinx_agent

Another useful section for this situation is where esbonio shows you all the configuration values it has loaded from various sources

Example

[esbonio.Configuration] Looking for pyproject.toml files in: '/workspaces/develop'
[esbonio.Configuration] Found '/workspaces/develop/code/pyproject.toml'
[esbonio.Configuration] Found '/workspaces/develop/docs/pyproject.toml'
[esbonio.Configuration] Found '/workspaces/develop/lib/esbonio-extensions/pyproject.toml'
[esbonio.Configuration] Found '/workspaces/develop/lib/esbonio/pyproject.toml'
[esbonio.Configuration] Found '/workspaces/develop/lib/esbonio/tests/workspaces/demo/pyproject.toml'
[esbonio.Configuration] Found '/workspaces/develop/lib/esbonio/tests/workspaces/demo/_build/dirhtml/_images/pyproject.toml'
[esbonio.Configuration] File 'file:///workspaces/develop/code' configuration: {
  "esbonio": {}
}
[esbonio.Configuration] File 'file:///workspaces/develop/docs' configuration: {
  "esbonio": {
    "sphinx": {
      "buildCommand": [
        "sphinx-build",
        "-M",
        "dirhtml",
        ".",
        "${defaultBuildDir}"
      ],
      "pythonCommand": [
        "hatch",
        "-e",
        "docs",
        "run",
        "python"
      ]
    }
  }
}
[esbonio.Configuration] File 'file:///workspaces/develop/lib/esbonio-extensions' configuration: {
  "esbonio": {}
}
[esbonio.Configuration] File 'file:///workspaces/develop/lib/esbonio' configuration: {
  "esbonio": {}
}
[esbonio.Configuration] File 'file:///workspaces/develop/lib/esbonio/tests/workspaces/demo' configuration: {
  "esbonio": {
    "sphinx": {
      "buildCommand": [
        "sphinx-build",
        "-M",
        "dirhtml",
        ".",
        "./_build"
      ],
      "pythonCommand": [
        "${venv:.venv}"
      ]
    }
  }
}
[esbonio.Configuration] File 'file:///workspaces/develop/lib/esbonio/tests/workspaces/demo/_build/dirhtml/_images' configuration: {
  "esbonio": {
    "sphinx": {
      "buildCommand": [
        "sphinx-build",
        "-M",
        "dirhtml",
        ".",
        "./_build"
      ]
    }
  }
}
[esbonio.Configuration] workspace/configuration: {
  "items": [
    {
      "section": "esbonio"
    },
    {
      "scopeUri": "file:///workspaces/develop",
      "section": "esbonio"
    }
  ]
}
[esbonio.SphinxManager] No client found, creating new subscription
[esbonio.ProjectManager] No applicable project for uri: file:///workspaces/develop/lib/esbonio/tests/workspaces/demo/index.rst
[esbonio.Configuration] Workspace 'None' configuration: {
  "server": {
    "enabled": true,
    "documentSelector": [],
    "startupModule": "esbonio.server",
    "excludedModules": [],
    "includedModules": [],
    "completion": {
      "preferredInsertBehavior": "replace"
    },
    "enableDevTools": false,
    "debug": false,
    "showDeprecationWarnings": true
  },
  "sphinx": {
    "configOverrides": {},
    "enableDevTools": false,
    "pythonPath": []
  },
  "preview": {
    "showLineMarkers": false
  },
  "logging": {
    "level": "debug",
    "stderr": true,
    "window": false,
    "config": {}
  },
  "trace": {
    "server": "off"
  }
}
[esbonio.Configuration] Workspace 'file:///workspaces/develop' configuration: {
  "server": {
    "enabled": true,
    "documentSelector": [],
    "startupModule": "esbonio.server",
    "excludedModules": [],
    "includedModules": [],
    "completion": {
      "preferredInsertBehavior": "replace"
    },
    "enableDevTools": false,
    "debug": false,
    "showDeprecationWarnings": true
  },
  "sphinx": {
    "configOverrides": {},
    "enableDevTools": false,
    "pythonPath": []
  },
  "preview": {
    "showLineMarkers": false
  },
  "logging": {
    "level": "debug",
    "stderr": true,
    "window": false,
    "config": {}
  },
  "trace": {
    "server": "off"
  }
}

[Fuyukai]

in VSCode's settings.json or a pyproject.toml file?

It's in pyproject.toml.

Are being affected by #813?

Nope, running on my local /home.

A full debug log from a clean Reload Window is here: https://gist.github.com/Fuyukai/cfe78713940f0b28b5b6e7d65e0178fa

There's some interesting lines near the bottom:

[esbonio.Configuration] Current: CompletionConfig(preferred_insert_behavior='replace')
[esbonio.Configuration] ConfigChangeEvent(scope='', value=CompletionConfig(preferred_insert_behavior='replace'), previous=None)
[esbonio.Configuration] ConfigurationContext(file_scope='file:///home/lura/dev/libs/century-ring', workspace_scope='file:///home/lura/dev/libs/century-ring')
[esbonio.Configuration] esbonio.sphinx: {
  "pythonCommand": [
    "${venv:.venv}"
  ],
  "enableDevTools": false,
  "fallbackEnv": "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/env",
  "pythonPath": []
}
[esbonio.Configuration] SphinxConfig(enable_dev_tools=False, python_command=['${venv:.venv}'], build_command=[], config_overrides={}, env_passthrough=[], cwd='/home/lura/dev/libs/century-ring', fallback_env='/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/env', python_path=[])
[esbonio.Configuration] Previous: SphinxConfig(enable_dev_tools=False, python_command=['${venv:.venv}'], build_command=[], config_overrides={}, env_passthrough=[], cwd='/home/lura/dev/libs/century-ring', fallback_env='/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/env', python_path=[])
[esbonio.Configuration] Current: SphinxConfig(enable_dev_tools=False, python_command=['${venv:.venv}'], build_command=[], config_overrides={}, env_passthrough=[], cwd='/home/lura/dev/libs/century-ring', fallback_env='/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/env', python_path=[])
[esbonio.Configuration] ConfigurationContext(file_scope='', workspace_scope='')
[esbonio.Configuration] esbonio.logging: {
  "config": {},
  "window": false,
  "level": "debug",
  "stderr": true
}
[esbonio.Configuration] LoggingConfig(level='debug', format='[%(name)s] %(message)s', filepath=None, stderr=True, window=False, config={}, show_deprecation_warnings=False)
[esbonio.Configuration] Previous: LoggingConfig(level='debug', format='[%(name)s] %(message)s', filepath=None, stderr=True, window=False, config={}, show_deprecation_warnings=False)
[esbonio.Configuration] Current: LoggingConfig(level='debug', format='[%(name)s] %(message)s', filepath=None, stderr=True, window=False, config={}, show_deprecation_warnings=False)
[esbonio.Configuration] ConfigurationContext(file_scope='', workspace_scope='')
[esbonio.Configuration] esbonio.sphinx: {
  "pythonPath": [],
  "enableDevTools": false,
  "fallbackEnv": "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/env"
}

It looks like the Sphinx config is losing the pythonCommand somewhere.

[alcarney]

Thanks for sharing the whole thing!

I've not digested it all yet, however I am very surprised to see this almost at the start of the log

[client] Starting Language Server
[client] sphinx/clientCreated: {
  "pythonCommand": [
    "/usr/bin/python3.13"
  ],
  "buildCommand": [
    "sphinx-build",
    "-M",
    "dirhtml",
    "/home/lura/dev/libs/century-ring/docs/source",
    "${defaultBuildDir}"
  ],
  "cwd": "/home/lura/dev/libs/century-ring",
  "pythonPath": [
    "/home/lura/.vscode/extensions/swyddfa.esbonio-0.96.1/bundled/libs/esbonio"
  ]
}

There is no way the client should be created that soon! No wonder it is ignoring your config, it is happening before the config system has even initialized itself! 🤔

Edit: That might have been an over-reaction, I forgot that the server captures all log messages during startup and re-plays them once it has configured it's logging setup. But you are right, the ${venv:.venv} is being lost somewhere

[alcarney]

I see what's happening - can't believe I didn't catch this when I was doing my testing 🤦

The server converts ${venv:.venv} -> /path/to/cwd/.venv/bin/python
Then it calls pathlib.Path.resolve() (to resolve relative references like ../../), however .resolve() also follows symlinks! and the /bin/python in a venv is a symlink back to the Python installation that created it.

So when it runs Sphinx, it's using the global interpreter rather than the venv, and I've been able to reproduce your issue

However, using an absolute path e.g. ${venv:/path/to/cwd/.venv}, works as expected for me. Can you confirm that you see the same issue with an absolute path, and if so share the logs? :)

[Fuyukai]

Running with the absolute path works fine; I mentioned it in the initial issue because it didn't cause the issue. Apologies if that wasn't clear.