Importlab should not execute the code it analyzes

[0xjac]

When running pytype on a project which has kivy as a dependency, pytype somehow uses the kivy logger. This result in duplicate logging lines (and by default, logging of debug information).

I am not exactly sure why not ho this happens but I am guessing that pytype somehow, maybe through importlab here, imports the kivy module and this somehow hijack the python logging module used by pytype.

Minimum reproducible example

1. Create a new directory:

   mkdir kivy-issue && cd kivy-issue

2. Install pytype:

   pipenv install --categories "dev-packages" pytype

3. Install kivy:

   pipenv install "kivy[base]"

4. Create an empty main.py file

   touch main.py

5. Run pytype (which behaves as expected):

   pipenv run pytype main.py
   Computing dependencies
   Analyzing 1 sources with 0 local dependencies
   ninja: Entering directory `.pytype'
   [1/1] check main
   Leaving directory '.pytype'
   Success: no errors found

6. Add kivy import to main.py:

   echo "from kivy.app import App" >> main.py

7. Run pytype again:

   pipenv run pytype main.py
   Computing dependencies
   INFO Kivy: v2.2.0
   INFO Logger: Record log in /home/jac/.kivy/logs/kivy_23-05-30_38.txt
   [INFO   ] [Logger      ] Record log in /home/jac/.kivy/logs/kivy_23-05-30_38.txt
   [INFO   ] [Kivy        ] v2.2.0
   INFO Kivy: Installed at "/home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/lib/python3.10/site-packages/kivy/__init__.py"
   [INFO   ] [Kivy        ] Installed at "/home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/lib/python3.10/site-packages/kivy/__init__.py"
   INFO Python: v3.10.10 (main, Mar  5 2023, 22:26:53) [GCC 12.2.1 20230201]
   [INFO   ] [Python      ] v3.10.10 (main, Mar  5 2023, 22:26:53) [GCC 12.2.1 20230201]
   INFO Python: Interpreter at "/home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python"
   [INFO   ] [Python      ] Interpreter at "/home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python"
   INFO Logger: Purge log fired. Processing...
   [INFO   ] [Logger      ] Purge log fired. Processing...
   INFO Logger: Purge finished!
   [INFO   ] [Logger      ] Purge finished!
   INFO Factory: 190 symbols loaded
   [INFO   ] [Factory     ] 190 symbols loaded
   DEBUG Cache: register <kv.resourcefind> with limit=None, timeout=60
   [DEBUG  ] [Cache       ] register <kv.resourcefind> with limit=None, timeout=60
   DEBUG Cache: register <kv.lang> with limit=None, timeout=None
   [DEBUG  ] [Cache       ] register <kv.lang> with limit=None, timeout=None
   DEBUG Cache: register <kv.image> with limit=None, timeout=60
   [DEBUG  ] [Cache       ] register <kv.image> with limit=None, timeout=60
   DEBUG Cache: register <kv.atlas> with limit=None, timeout=None
   [DEBUG  ] [Cache       ] register <kv.atlas> with limit=None, timeout=None
   INFO Image: Providers: img_tex, img_dds, img_sdl2, img_pil (img_ffpyplayer ignored)
   [INFO   ] [Image       ] Providers: img_tex, img_dds, img_sdl2, img_pil (img_ffpyplayer ignored)
   DEBUG Cache: register <kv.texture> with limit=1000, timeout=60
   [DEBUG  ] [Cache       ] register <kv.texture> with limit=1000, timeout=60
   DEBUG Cache: register <kv.shader> with limit=1000, timeout=3600
   [DEBUG  ] [Cache       ] register <kv.shader> with limit=1000, timeout=3600
   DEBUG Cache: register <kv.graphics.texture> with limit=None, timeout=None
   [DEBUG  ] [Cache       ] register <kv.graphics.texture> with limit=None, timeout=None
   INFO Source tree:
   source: /home/jac/code/gh/kivy-issue/main.py
   deps:
     /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/lib/python3.10/site-packages/kivy/app.py
   source: /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/lib/python3.10/site-packages/kivy/app.py
   [INFO   ] [Source tree ]
   source: /home/jac/code/gh/kivy-issue/main.py
   deps:
     /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/lib/python3.10/site-packages/kivy/app.py
   source: /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/lib/python3.10/site-packages   /kivy/app.py
   INFO ------------- Starting pytype run. -------------
   [INFO   ] ------------- Starting pytype run. -------------
   INFO infer command: /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python -m pytype.single --imports_info $imports --module-name $module --platform linux -V 3.10 -o $out --no-report-errors --nofail --quick $in
   [INFO   ] [infer command  ] /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python -m pytype.single --imports_info $imports --module-name $module --platform linux -V 3.10 -o $out --no-report-errors --nofail --quick $in
   INFO check command: /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python -m pytype.single --imports_info $imports --module-name $module --platform linux -V 3.10 -o $out --analyze-annotated --nofail --quick $in
   [INFO   ] [check command  ] /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python -m pytype.single --imports_info $imports --module-name $module --platform linux -V 3.10 -o $out --analyze-annotated --nofail --quick $in
   INFO generate default: System module kivy.app
   [INFO   ] [generate default          ] System module kivy.app
   INFO check main
     imports: /home/jac/code/gh/kivy-issue/.pytype/imports/main.imports
     deps: ()
     output: /home/jac/code/gh/kivy-issue/.pytype/pyi/main.pyi
   [INFO   ] [check main
     imports] /home/jac/code/gh/kivy-issue/.pytype/imports/main.imports
     deps: ()
     output: /home/jac/code/gh/kivy-issue/.pytype/pyi/main.pyi
   Analyzing 1 sources with 0 local dependencies
   ninja: Entering directory `.pytype'
   [1/1] /home/jac/.local/share/virtualenvs/kivy-issue-Wk8HOo_3/bin/python -m pytype.single --imports_info /home/jac/code/gh/kivy-issue/.pytype/imports/main.imports --module-name main --platform linux -V 3.10 -o /home/jac/code/gh/kivy-issue/.pytype/pyi/main.pyi --analyze-annotated --nofail --quick /home/jac/code/gh/kivy-issue/main.py
   Leaving directory '.pytype'
   Success: no errors found

[0xjac]

After some investigations, it seems importing kivy imports kivy.logger which in turns runs the following code.

As a temporary fix calling pytype with something like KIVY_LOG_MODE=off disables the Kivy logger.

However this does not work with Kivy before version 2.2.0 which does not have that option. And this issue can apply to other dependencies with module that have initialization code. I would say the fact that pytype runs the module initialization code is unexpected and ideally should be avoided for security reasons. Or at least there should be some warning about it in the docs.

[martindemello]

the culprit seems to be this feature of importlib.find_spec:

If name is for a submodule (contains a dot), the parent module is automatically imported.

called from here. we might need to spawn a subprocess to find and resolve dependencies.

[0xjac]

That sounds like a good idea but I would be weary of importing and executing arbitrary code regardless for security reasons.

[h-joo]

Hi, thank you for your report. Google is shifting its effort to a different approach for type checking apart from pytype, and we're not planning to put in any effort in the near future in pytype, so we'll close this issue. Please see the announcement here.