PIP Package 依存関係エラーの調査例を詳しく解説しました

依存関係、わかりませんよね？？

オープンソースがオープンソースに無限に依存している昨今、依存関係に悩まされることは日常茶飯事です。駆け出しの方は調査方法すらわからないと思うので、この記事を書いてみました。１年以上前に書いたので内容は古いですが、調査方法は今も変わりません。これはpythonですが、他の言語でもだいたい同じだと思います。誰かの参考になることを願ってここに記します。

なお、この問題は たった１行 の修正で直りました。しかしその１行にたどり着くまで、こんな行程があったんだよという参考にもしてほしいです。

調査フロー

一口に調査といっても、その過程には様々な内容が含まれています。簡単に言えば、今知りたいのは「直す方法」です。しかしその過程にはこのような要素が含まれます。

1. 原因の仮設を立てる
2. 被疑者(エラーを起こす張本人）を建てる
3. 犯人の証拠を掴む
4. 修正方法の決定

この記事には、 "3.犯人の証拠を掴む" ところに失敗し、"2の被疑者" が間違っていたという内容が含まれています。闇雲に修正を当ててみても直らないことも多々あります。私がいかに犯人の証拠を掴んだか、これから説明していきます。

依存関係のエラーはこんな感じに見えます

python API + vue frontend の docker build がコケました。初めて触ったプロジェクトなので何もわかりません。前回のビルドは数ヶ月前。その間何もコードは変わってないのにコケるなんて、私はいつもツイてない。

error logの最後がこれ。

info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
error Command failed with exit code 1.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.
The command '/bin/sh -c PYTHON_ENV=testing uvicorn myapp:app --reload --port 19999 & sleep 10; yarn generate-api-client' returned a non-zero code: 1

実はこの部分では何もわかりません。さあ、調査開始です。

調査開始〜原因を推定する

まずは何とも error 内容を読むことからすべては始まります。
少し log をさかのぼって、エラーになった場所を探すと、これ。ここから重要な情報を探していきます。

Step 13/21 : RUN PYTHON_ENV=testing uvicorn myapp:app --reload --port 19999 & sleep 10; yarn generate-api-client
 ---> Running in 2e206e895240
INFO:     Will watch for changes in these directories: ['/app']
INFO:     Uvicorn running on http://127.0.0.1:19999 (Press CTRL+C to quit)
INFO:     Started reloader process [6] using statreload
Process SpawnProcess-1:
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/local/lib/python3.9/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.9/site-packages/uvicorn/subprocess.py", line 76, in subprocess_started
    target(sockets=sockets)
  File "/usr/local/lib/python3.9/site-packages/uvicorn/server.py", line 68, in run
    return asyncio.run(self.serve(sockets=sockets))
  File "/usr/local/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/local/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.9/site-packages/uvicorn/server.py", line 76, in serve
    config.load()
  File "/usr/local/lib/python3.9/site-packages/uvicorn/config.py", line 448, in load
    self.loaded_app = import_from_string(self.app)
  File "/usr/local/lib/python3.9/site-packages/uvicorn/importer.py", line 24, in import_from_string
    raise exc from None
  File "/usr/local/lib/python3.9/site-packages/uvicorn/importer.py", line 21, in import_from_string
    module = importlib.import_module(module_str)
  File "/usr/local/lib/python3.9/importlib/__init__.py", line 127, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 1030, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1007, in _find_and_load
  File "<frozen importlib._bootstrap>", line 986, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 680, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 790, in exec_module
  File "<frozen importlib._bootstrap>", line 228, in _call_with_frames_removed
  File "./myapp/__init__.py", line 3, in <module>
    from .routes import init_routes
  File "./myapp/routes.py", line 5, in <module>
    from .controllers import auth_controller
  File "./myapp/controllers/auth_controller.py", line 4, in <module>
    from ..auth import AuthenticatedUser, oauth
  File "./myapp/auth.py", line 2, in <module>
    from authlib.integrations.starlette_client import OAuth
  File "/usr/local/lib/python3.9/site-packages/authlib/integrations/starlette_client/__init__.py", line 4, in <module>
    from .integration import StartletteIntegration, StarletteRemoteApp
  File "/usr/local/lib/python3.9/site-packages/authlib/integrations/starlette_client/integration.py", line 2, in <module>
    from ..httpx_client import AsyncOAuth1Client, AsyncOAuth2Client
  File "/usr/local/lib/python3.9/site-packages/authlib/integrations/httpx_client/__init__.py", line 10, in <module>
    from .oauth2_client import (
  File "/usr/local/lib/python3.9/site-packages/authlib/integrations/httpx_client/oauth2_client.py", line 3, in <module>
    from httpx import AsyncClient, Auth, Client, Request, Response, USE_CLIENT_DEFAULT
ImportError: cannot import name 'USE_CLIENT_DEFAULT' from 'httpx' (/usr/local/lib/python3.9/site-packages/httpx/__init__.py)

注目するのはこの行

    from httpx import AsyncClient, Auth, Client, Request, Response, USE_CLIENT_DEFAULT

from httpx で httpx というモジュールを使おうとしています。これは wgetやcurlのように webコンテンツを取得するための python向け パッケージで最近流行り始めてます。
エラーでは その中の USE_CLIENT_DEFAULT がないといわれています。最後のbuildは 2021 / 7月で、そのときは成功しています。

こういうときはだいたい version 問題なので、versionを確認します。 そう思う理由は、ソースコードを変えていないからです。Docker imageも変わっていない = OS や python 周りのバージョンも変わっていない。変わっているのはきっと pip install しているパッケージ群でしょう。ちゃんとしたプロジェクトなら package のversionも固定するべきですが、このプロジェクトでは常に最新バージョンを使うようになっていました。それは主に requirements.txt というファイルに書かれるパッケージ情報にバージョン名がついているかどうかでわかります(pythonのお作法だと思ってください)。パッケージ名しか書かれていなかったら、常に最新バージョンをインストールします。これはこれで時代遅れにならず、バージョンアップの負荷を小分けにできるので、個人的にも好きな戦術です（もちろんprojectの重要度によっては取らない戦術です）

さて。from httpx と書かれているので、 docker buildで出た log の中から httpx のversionを見ます。「version x をinstallしてください」という宣言(requirements.txt)を見てもいいのですが、実は違うファイルで指定しているかもしれないので、実際にインストールされたバージョンを見るのが最も安全です。

Collecting Authlib
  Downloading Authlib-0.15.5-py2.py3-none-any.whl (203 kB)
Collecting httpx==0.18.1                       <---------------------------
  Downloading httpx-0.18.1-py3-none-any.whl (75 kB)
Collecting aiofiles
  Downloading aiofiles-0.7.0-py3-none-any.whl (13 kB)

httpx==0.18.1 ですね。ここにきっと原因が潜んでいるのでしょう。

OSS のソースを調査します

いったん 被疑者を httpx にして調査しましょう。エラーが出た原因はそこにあると思われます。

とりあえず、最新の httpx がどうなってるか見てみます。 Google で "github httpx USE_CLIENT_DEFAULT" とかでぐぐります。

一番上にファイルが出てきました。

master branchなので、最新でしょう。

Git Blame を活用して 重要な変更があった commit を探します

blame button を押して、USE_CLIENT_DEFAULT の歴史を見ます。

USE_CLIENT_DEFAULT で検索すると、多数の行が見つかります。特にこの最初のブロックは大きく変更されていて怪しいです。コミット名をクリックすると、該当の変更がされたコミットを見ることができます。

これでcommitを見つけました。中を見ると、もともと USE_CLIENT_DEFAULT は存在しなかった → 追加された、ことがわかります。

https://github.com/encode/httpx/commit/69409bb8b9e85caf2dd63f9b76f0aa920feaf4f1

commit から PR を探します

ここからがけっこう重要です。 今知りたいのは、この commit が、 私が困っている httpx のversion と本当に紐づくのかどうか です。 そのために、まず PR を探します。ちゃんと管理されているプロジェクトならきっとあるはず。

さっきの commit には元の PR を示す commit message が残されています。master branch への merge commitだったんですね。

merge commitには元の PR が示されていることが多いです。ここでは #1634 というlinkが見えます。これがきっと PR でしょう。

その PR を見てみます。
https://github.com/encode/httpx/pull/1634/files

PRを見ると、その commit/PR が #1384 の issueを解決するためだったことがわかりますが、 この先は私のアプリを直す情報ではないので、追いません 。これ以上は必要ない、これ以上追ってもしょうがない、というポイントをわかるようになるのも、調査のキモです。これも技術と経験ですね。

commit/PR からその software の version を類推する

この変更が、どの version の httpx でreleaseされたかは PR の下にある 0.18.2 でわかりました。
https://github.com/encode/httpx/pull/1634

正直なところ、 commit番号と OSS のバージョン番号を付き当てるのは最も難しい作業 だと思っています。今回のようにしっかり分かる形で管理されているプロジェクトはかなりラッキーです。このプロジェクトでは git tag (https://github.com/encode/httpx/tags ) でバージョンを管理していて、この Notes の中で該当する PR をメンションすることで紐付けを可視化してくれています。（しかし確認したところ軽微な PR はリストアップされていませんでした）

この紐付けが明らかではない場合は、日時から推測したり、パッケージの中身を見てこのコミットが当たっているかどうかを調べる必要もあると思います。 commitとsoftware versionを紐付けるいい方法があればぜひ教えてほしいです！

version conflict の考察 〜 犯人を追う

さあ、httpxのversion変更により何かに影響があったことはわかりました。しかし、まだ犯人はわかっていません。さらに踏み込んでいきます。改めて log を見返します。

私の docker build が入れたのはこれ

Collecting httpx==0.18.1                       <----------------

USE_CLIENT_DEFAULTが入ったhttpxは

0.18.2

さて。

これはつまり、私のアプリは httpx==0.18.1 を使えと指示してるのに、 0.18.2 を使おうとしている誰かがいるということを示しています。
なんでそんなことが起こるんでしょう？？

もう一回 error の traceback 部分をよく見てみます。

  File "/usr/local/lib/python3.9/site-packages/authlib/integrations/httpx_client/oauth2_client.py", line 3, in <module>
    from httpx import AsyncClient, Auth, Client, Request, Response, USE_CLIENT_DEFAULT

from httpx ですよね。そう。これは、httpxじゃない誰かが、httpxを使おうとしているのです。犯人は httpx じゃない！！

新しい httpx を使おうとしているのは私のアプリでしょうか？ 他の依存パッケージでしょうか？

さらに上の行を見てみます。tracebackでは、「なんのファイルが」そのコードを持っているか教えてくれます。

  File "/usr/local/lib/python3.9/site-packages/authlib/integrations/httpx_client/oauth2_client.py", line 3, in <module>

File の後の path の中に site-packages/authlib とあります。
python/pip では site-packages の直下に python package名が来るルールになってます（たぶん）

authlib、犯人はお前だ！！！

犯人の証拠を探す

早速 authlib のソースをgithubで探します。ビバOSS.

該当の行を見つけました。

USE_CLIENT_DEFAULT は追加されたはずなので、いつ追加されたかを探します。Blameボタンを押します。

該当業にめっちゃそれっぽいコミットがあるので、開きます。

+ で始まる緑色の行は新しく追加された行を示します。今までなかった USE_CLIENT_DEFAULT が追加されています。

これだ！！！（確信）

この書き方だと、version依存性どうなってるんだろう？という疑問が湧くので、authlibの依存性がどうなってるか、requirements.txtを見てみます。

requests
httpx
starlette

version指定されてません。はい、終了。これが示すところは、 Authlib はもう httpx >= 0.18.2 にしか対応していない = 0.18.1 は非対応になっているということです。

犯人の証拠は掴めました。これでいったん調査は終わりです。

自分のアプリを修正する方法を考える

さて、手元のappの requirements.txt を見てみると、これがありました。

httpx==0.18.1

これ以外はほぼversion指定されていないのにこれだけ指定されています。明らかに過去に何かあった感あります。これは、社内slackで検索したらさくっとやりとりが出てきました。会話中で出てきたissueはこれでした。

やっぱり Authlib や！！！

つまり、このような順番で依存関係が壊れたとわかりました。

1. httpx側の破壊的変更が最初にあった。
2. authlibがその httpx に対応していなかった。

authlibは新しい httpx に対応して いない ので、この状況でアプリを動かすには httpx を古くする しかなかったことでしょう。

しかし、その後 authlib が新しい httpx に対応したことで、私の build はこわれました。
というわけで、現状のアプリをまとめるとこうなります。

• httpx : Authlibがコケるから、古くしている
• authlib : httpxが新しければ動く。古いと動かない

やっとすっきりしたわ〜〜〜〜。ある日突然壊れるアプリって、こういう経緯があって壊れるんですね。

たった１行でアプリを修正します。

この現状を解消する選択肢は２つです。

• 両方古くする
• 両方新しくする

やっと解決方法まで導けました！
0.18.1 に固定したコミットをした同僚に相談し、新しくすることで決定。

というわけで、たった一行を直しただけで、buildは成功するようになりました。

- httpx==0.18.1
+ httpx

結果だけ見ると、かんたんです。でもこの一連の考察、検索ができるようになるにはそれなりに時間がかかると思います。

Open Source なんだから、元を直そう！

同じ問題で困る人がいるのは悲しいので、なんとかしたいですよね。
無駄な時間を使う人を減らすためにPRをしたのがこれです。

〜〜〜 これがmergeされてから記事を書こうと思って 1 年が経過 〜〜〜

この記事の draft を見つけて、PRを見たら merge されてました。完全に忘れてた。
まあそんなこんなで、世界は平和になりました。

（締めの定型文）

いかがだったでしょうか？
今回は Open sourceの依存関係の調査方法を記事にしてみました。
面白かったという方は、いいねしてくださいね！

ちなみに転職先は随時募集してますのでぜひお声がけください :)