くんすとの備忘録

IT系技術メモ

移転しました。

15秒後に自動的にリダイレクトします。

AnsibleのDocker Connection Pluginを使って空ファイルをコピーするとジョブがたまにハングする問題

ためした環境

  • 実行元
    • macOS High Sierra 10.13.6
    • Ansible 2.4.3.0
    • Python 2.7.10
  • 対象サーバー
    • Docker for Mac上のコンテナ
      • Centos 6.10
      • AmazonLinux

再現手順

1. 空ファイルを作成

$ touch empty

2. site.yml を以下の内容で作成

- hosts: all
  connection: docker
  tasks:
    - name: copy empty file
      copy:
        src: empty
        dest: /empty

    - name: remove empty file
      file:
        state: absent
        path: /empty

3. 検証スクリプトを以下の内容で作成

test.sh

#!/bin/bash
set -eu

NAME=$(docker ps -l --format '{{.Names}}')

cat <<++EOS>hosts
[all]
$NAME
++EOS

for ((i=0; i<100; i++)); do
    ansible-playbook -i hosts site.yml
done

4 対象サーバーのdockerコンテナを起動

$ docker run -it --rm centos:6.10 bash

5. 4.とは別のターミナルで検証スクリプトを起動

$ ./test.sh

_人人人人人人人人人_
> そのうち止まる <
 ̄YYYYYYYY

止まったときの状態

コンテナのプロセス

# ps aux
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.1  11500  2652 pts/0    Ss   15:31   0:00 bash
root      2268  0.0  0.0   8396   556 ?        Ss   15:33   0:00 dd of=/root/.ansible/tmp/ansible-tmp-1536593616.23-267547494832017/source bs=65536
root      2279  0.0  0.0  13380  1872 pts/0    R+   15:34   0:00 ps aux

こんな感じで、dd コマンドで停止しているように見えます。

ansible-playbookの詳細ログ

-vvvオプションを付けて再実行してみます。

$ ansible-playbook -vvv -i hosts site.yml

ログを全部貼ると長いので、停止した箇所付近だけ貼り付けます。

TASK [copy empty file] **************************************************************************************************************************************************
task path: /Users/kunst/work2/ansible-test/site.yml:4
<goofy_goldstine> ESTABLISH DOCKER CONNECTION FOR USER: root
<goofy_goldstine> EXEC ['/usr/local/bin/docker', 'exec', '-i', u'goofy_goldstine', u'/bin/sh', '-c', u"/bin/sh -c 'echo ~ && sleep 0'"]
<goofy_goldstine> EXEC ['/usr/local/bin/docker', 'exec', '-i', u'goofy_goldstine', u'/bin/sh', '-c', u'/bin/sh -c \'( umask 77 && mkdir -p "` echo /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844 `" && echo ansible-tmp-1536593766.1-91378099171844="` echo /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844 `" ) && sleep 0\'']
Using module file /Users/kunst/Library/Python/2.7/lib/python/site-packages/ansible/modules/files/stat.py
<goofy_goldstine> PUT /var/folders/ys/535_fggj5fb3k98v2xz06b0h0000gn/T/tmpEojaf5 TO /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844/stat.py
<goofy_goldstine> EXEC ['/usr/local/bin/docker', 'exec', '-i', u'goofy_goldstine', u'/bin/sh', '-c', u"/bin/sh -c 'chmod u+x /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844/ /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844/stat.py && sleep 0'"]
<goofy_goldstine> EXEC ['/usr/local/bin/docker', 'exec', '-i', u'goofy_goldstine', u'/bin/sh', '-c', u"/bin/sh -c '/usr/bin/python /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844/stat.py && sleep 0'"]
<goofy_goldstine> PUT /Users/kunst/work2/ansible-test/empty TO /root/.ansible/tmp/ansible-tmp-1536593766.1-91378099171844/source

原因調査

最初は copy モジュールが怪しいなぁと思って site-packages/ansible/modules/files/copy.py あたりをデバッグしていたのですが、どうやらその前に止まっている模様……

もしやと思い、Docker Connection Pluginのソースを見てみると、そのもの dd コマンドを投げている箇所がありました。 github.com

そのままissueを検索してみると、bugでissueが立っているのを発見。 github.com

あー、これですね。ログの出方も同じ。

応急処置

  • 空ファイルをコピーせず、 touch コマンドなどで作成する
  • 空ファイルじゃなければいいので、適当に半角スペースや改行などを入れて1バイトにする