虚無ありき

うるせーーーしらねーーー

マルチユーザ用 JupyterHub の構築

やりたいこと

  • PAM 認証を使ってそれぞれのユーザがサーバ上で Jupyter を使えるようにする
  • ユーザの default dir をサーバの root dir にする
  • Bash と R の kernel を使えるようにする
  • PATH などの環境変数が引き継がれるようにする
  • ファイルの作成などがユーザの permission で行われるようにする

Environment

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 18.04.2 LTS
Release:    18.04
Codename:   bionic

Installation

Nodejs

$ node -v
v8.10.0
$ npm -v
  • node.js は既に入っていた。npm を isntall する
  • 依存関係の問題で、libssl などから入れていかなければならなかった
    • 単純に apt install -y npm で install 出来る場合もあると思われる
$ apt update
$ apt install -y libssl1.0-dev
$ apt install -y nodejs-dev
$ apt install -y node-gyp
$ apt install -y npm
$ npm -v
3.5.2
$ apt autoremove

JupyterHub

jupyter 関係は入っていなかった

$ pip3 list --format=legacy | grep jupyter
$ pip3 install jupyterhub
$ npm install -g configurable-http-proxy
$ pip3 install notebook
$ jupyterhub -h
$ configurable-http-proxy -h
  • 設定ファイルは、/etc/jupyterhub に置く
    • ssh portforward を使うため、ssl の設定は行わない
    • root 権限で jupyter server を起動する
$ mkdir -p /etc/jupyterhub
$ cd jupyterhub --generate-config
$ vim jupyterhub_config.py

c.Authenticator.whitelist = {"users"}
c.JupyterHub.admin_users = {"users"}
c.JupyterHub.allow_named_servers = True
c.Spawner.notebook_dir = "/"
c.Spawner.default_url = "/tree/home/{username}"
  • c.Spawner.notebook_dir
    • WebUI から見えるファイル構造のルート
    • WebUI でホームボタンおした時に飛ぶ先
    • URL では /tree に対応する
  • c.Spawner.default_url
    • WebUI からアクセスしたときに、最初に表示する URL

起動は、

$ cd /etc/jupyterhub
$ sudo -u root jupyterhub

接続する場合、Host マシンの .ssh/config に下記を追加

LocalForward 8000 localhost:8000

ブラウザから、localhost:8000 にアクセスする


起動時、下記のような error が発生する場合がある

[E 2019-06-21 09:25:03.286 JupyterHub utils:75] Unexpected error connecting to rhelixa-analysis-001:8000 [Errno 22] Invalid argument

これは、/etc/hosts を設定するで解決する

$ echo "127.0.0.1 $(hostname)" >> /etc/hosts

Kernel


$ pip3 install bash_kernel
$ python3 -m bash_kernel.install

$ R
> install.packages('IRkernel')
> IRkernel::installspec()
  • Kernel の確認は jupyter-kernelspec list を使う
    • 下記の場合、R kernel が実行出来ないため、適切な場所に配置する
$ jupyter-kernelspec list
Available kernels:
  ir         /root/.local/share/jupyter/kernels/ir
  bash       /usr/local/share/jupyter/kernels/bash
  python3    /usr/local/share/jupyter/kernels/python3

$ cp -r /root/.local/share/jupyter/kernels/ir /usr/local/share/jupyter/kernels/
$ jupyter-kernelspec uninstall ir
$ jupyter-kernelspec install /usr/local/share/jupyter/kernels/
$ jupyter-kernelspec list
Available kernels:
  bash       /usr/local/share/jupyter/kernels/bash
  ir         /usr/local/share/jupyter/kernels/ir
  python3    /usr/local/share/jupyter/kernels/python3

Service への登録

https://github.com/jupyterhub/jupyterhub/wiki/Run-jupyterhub-as-a-system-service

$ curl -fsSL https://gist.githubusercontent.com/lambdalisue/f01c5a65e81100356379/raw/ecf427429f07a6c2d6c5c42198cc58d4e332b425/jupyterhub > /etc/init.d/jupyterhub
$ sed -i -e "s#PATH=/sbin:/usr/sbin:/bin:/usr/bin:/usr/local/bin#PATH=$(echo $PATH)#g" /etc/init.d/jupyterhub
$ chmod +x /etc/init.d/jupyterhub
$ systemctl daemon-reload
$ update-rc.d jupyterhub defaults
$ systemctl start jupyterhub
$ systemctl status jupyterhub
● jupyterhub.service - LSB: Start jupyterhub
   Loaded: loaded (/etc/init.d/jupyterhub; generated)
   Active: active (running) since Fri 2019-06-21 09:41:16 UTC; 2s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 7479 ExecStart=/etc/init.d/jupyterhub start (code=exited, status=0/SUCCESS)
    Tasks: 9 (limit: 4915)
   CGroup: /system.slice/jupyterhub.service
           ├─7498 /usr/bin/python3 /usr/local/bin/jupyterhub --config=/etc/jupyterhub/jupyterhub_co
           └─7505 node /usr/local/bin/configurable-http-proxy --ip --port 8000 --api-ip 127.0.0.1 -
$ systemctl enable jupyterhub

Ubuntu 18.04: Slurm の導入

tl;dr

  • ジョブ管理ツール Slurm を Ubuntu 18.04 に導入する
  • PC クラスタ環境ではなく、1 ホスト 1 ノード環境に入れる

Environment

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 18.04.2 LTS
Release:    18.04
Codename:   bionic

Introduction

  • slurmctl
    • 管理デーモン
    • マスターノードにインストール
  • slurmd
    • 計算デーモン
    • 各計算ノードにインストール
  • 今回は、1 ホスト 1 ノード環境であるため両方入れる
  • MUNGE
    • 認証システム
    • 入れないと、後々の起動時にコケていた
  • apt で slurm を入れることも出来るが、今回は最新 version をソースから入れていく

Installation

[Slurm - Quick Start Admin] https://slurm.schedmd.com/quickstart_admin.html を参考にする

MUNGE の install

Install MUNGE for authentication. Make sure that all nodes in your cluster have the same munge.key. Make sure the MUNGE daemon, munged is started before you start the Slurm daemons.

めんどくさいから、apt で入れる

$ apt search munge
Sorting... Done
Full Text Search... Done
invada-studio-plugins-lv2/bionic 1.2.0+repack0-8 amd64
  Invada Studio Plugins - a set of LV2 audio plugins

libdata-munge-perl/bionic 0.097-1 all
  collection of various utility functions

libmoosex-mungehas-perl/bionic 0.007-3 all
  munge your "has" (works with Moo, Moose and Mouse)

libmunge-dev/bionic,now 0.5.13-1 amd64 [installed]
  authentication service for credential -- development package

libmunge-maven-plugin-java/bionic 1.0-2 all
  Maven plugin to pre-process Java code

libmunge2/bionic,now 0.5.13-1 amd64 [installed,automatic]
  authentication service for credential -- library package

libpod-elemental-perlmunger-perl/bionic 0.200006-1 all
  Perl module that rewrites Perl documentation

libstring-flogger-perl/bionic 1.101245-2 all
  module to munge strings for loggers

libterm-ttyrec-plus-perl/bionic 0.09-1 all
  module for reading a ttyrec

munge/bionic,now 0.5.13-1 amd64 [installed]
  authentication service to create and validate credentials

$ apt install -y munge libmunge-dev

Daemon が起動しているかと、MUNGE の key を確認しておく

$ systemctl list-unit-files --type=service | grep munge
munge.service                          enabled
$ systemctl start munge
$ systemctl status munge
● munge.service - MUNGE authentication service
   Loaded: loaded (/lib/systemd/system/munge.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2019-06-16 12:08:51 UTC; 2h 59min ago
     Docs: man:munged(8)
 Main PID: 9372 (munged)
    Tasks: 4 (limit: 4915)
   CGroup: /system.slice/munge.service
           └─9372 /usr/sbin/munged

$ find /etc | grep munge.key
/etc/munge/munge.key

Slurm の Install

Slurm - Download を参考にする

最新のソースは GitHub - slurm から取得する

$ cd /tmp
$ curl -fsSL https://github.com/SchedMD/slurm/archive/slurm-19-05-0-1.tar.gz | tar zx
$ cd slurm-slurm-19-05-0-1
$ ./configure
$ make -j 10
$ make install

Daemon と設定ファイルの確認する

$ systemctl list-unit-files --type=service | grep slurm
$ find /usr/local -type d | grep slurm
/usr/local/share/doc/slurm-19.05.0
/usr/local/share/doc/slurm-19.05.0/html
/usr/local/lib/slurm
/usr/local/lib/slurm/src
/usr/local/lib/slurm/src/sattach
/usr/local/lib/slurm/src/srun
/usr/local/include/slurm
$ find /etc -type d | grep slurm
$ find /var -type d | grep slurm

基本的に、service や 設定ファイル用の dir が存在しないため、作成しなければならない

$ cp ./etc/slurmd.service /etc/systemd/system/
$ cp ./etc/slurmctld.service /etc/systemd/system/

Type ldconfig -n <library_location> so that the Slurm libraries can be found by applications that intend to use Slurm APIs directly.

$ ldconfig -n /usr/local/lib/slurm

コンフィグファイルを作成する

下記の html を使って作成することが出来るが、最新 version を使う場合は Slurm - configurator を使うほうが楽

$ ls /usr/local/share/doc/slurm-19.05.0/html | grep configurator
configurator.easy.html
configurator.html
$ slurmd -V
slurm 19.05.0

作成したものを /usr/local/etc/slurm.conf に配置する

$ cat << EOS > /usr/local/etc/slurm.conf
SlurmctldHost=<my_host_name>
MpiDefault=none
ProctrackType=proctrack/pgid
ReturnToService=1
SlurmctldPidFile=/var/run/slurmctld.pid
SlurmctldPort=6817
SlurmdPidFile=/var/run/slurmd.pid
SlurmdPort=6818
SlurmdSpoolDir=/var/spool/slurmd
SlurmUser=root
StateSaveLocation=/var/spool
SwitchType=switch/none
TaskPlugin=task/none
InactiveLimit=0
KillWait=30
MinJobAge=300
SlurmctldTimeout=120
SlurmdTimeout=300
Waittime=0
FastSchedule=1
SchedulerType=sched/backfill
SelectType=select/cons_res
SelectTypeParameters=CR_CPU
AccountingStorageType=accounting_storage/none
AccountingStoreJobComment=YES
ClusterName=cluster
JobCompType=jobcomp/none
JobAcctGatherFrequency=30
JobAcctGatherType=jobacct_gather/none
SlurmctldDebug=info
SlurmdDebug=info
NodeName=<my_node_name> NodeAddr=<my_node_ip_address> RealMemory=96333 Sockets=2 CoresPerSocket=8 ThreadsPerCore=2 State=UNKNOWN
PartitionName=<my_pertition_name> Nodes=<my_node_name> Default=YES MaxTime=INFINITE State=UP
EOS
  • 基本的に default の設定を使う
  • 変更部分は、
    • SlurmUser: root
      • slurm などを使う場合は、user と group を作成して、適切に permission を設定する
    • SelectType: cons_res
    • SelectTypeParameters: CR_CPU
    • RealMemory, Sockets, CoresPerSocket, ThreadsPerCore は下記のコマンドで調べる
$ grep physical.id /proc/cpuinfo | sort -u | wc -l
$ grep cpu.cores /proc/cpuinfo | sort -u
$ grep processor /proc/cpuinfo | wc -l
$ free -m

The parent directories for Slurm's log files, process ID files, state save directories, etc. are not created by Slurm. They must be created and made writable by SlurmUser as needed prior to starting Slurm daemons.

自動生成されないファイル群を作成しておく

mkdir -p /var/spool/slurmd
touch /var/spool/node_state
touch /var/spool/job_state
touch /var/spool/resv_state
touch /var/spool/trigger_state
touch /var/run/slurmctld.pid
touch /var/run/slurmd.pid

起動する

$ systemctl enable slurmctld
$ systemctl start slurmctld
$ systemctl status slurmctld
● slurmctld.service - Slurm controller daemon
   Loaded: loaded (/etc/systemd/system/slurmctld.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2019-06-16 15:34:48 UTC; 5s ago
  Process: 9512 ExecStart=/usr/local/sbin/slurmctld $SLURMCTLD_OPTIONS (code=exited, status=0/SUCCESS)
 Main PID: 9520 (slurmctld)
    Tasks: 7
   CGroup: /system.slice/slurmctld.service
           └─9520 /usr/local/sbin/slurmctld

$ systemctl enable slurmd
$ systemctl start slurmd
$ systemctl status slurmd
● slurmd.service - Slurm node daemon
   Loaded: loaded (/etc/systemd/system/slurmd.service; enabled; vendor preset: enabled)
   Active: active (running) since Sun 2019-06-16 15:34:26 UTC; 1min 1s ago
  Process: 9455 ExecStart=/usr/local/sbin/slurmd $SLURMD_OPTIONS (code=exited, status=0/SUCCESS)
 Main PID: 9479 (slurmd)
    Tasks: 1
   CGroup: /system.slice/slurmd.service
           └─9479 /usr/local/sbin/slurmd

Test

$ sinfo
$ srun -l sleep 60 &
$ srun -l sleep 60 &
$ squeue

CWL(CommonWorkflowLanguage) の NetworkAccess について

tl;dr

  • cwltool が生成する docker container の中から、host の network にアクセスしたいケースがあった
    • ローカルファイルサーバのファイルを取ってくるケースなど
  • cwltool により docker run の command が生成されるため色々辛い
  • cwlVersion v1.1.0 から実装される NetworkAccess を使ってなんとかする

Environment

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 16.04.6 LTS
Release:    16.04
Codename:   xenial
$ docker --version
Docker version 18.09.5, build e8ff056
$ python3 -V
Python 3.5.2
$ cwltool --version
/usr/local/bin/cwltool 1.0.20190228155703

Docker Use Host Network

Docker Docs - Use host networking

  • コンテナにホストネットワークドライバーを接続する
    • Linux のみで動作し、Docker for Mac や Docker for Windows では動作しない
    • docker run 時に --net=host をつける
    • /etc/hosts なども host のものを使うことが出来る

試しにやってみる、まずローカルサーバを立てておく。

$ pwd
/home/ubuntu/cwltool-net-test
$ ls
memo.md  net-test.cwl
$ python3 -m http.server --bind localhost 8000 > /dev/null 2>&1 &
[1] 2409
$ curl  -fsSL localhost:8000/
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN" "http://www.w3.org/TR/html4/strict.dtd">
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
<title>Directory listing for /</title>
</head>
<body>
<h1>Directory listing for /</h1>
<hr>
<ul>
<li><a href="memo.md">memo.md</a></li>
<li><a href="net-test.cwl">net-test.cwl</a></li>
</ul>
<hr>
</body>
</html>

まずは、--net=host を付けない場合、

$ docker run --rm appropriate/curl curl -fsSL localhost:8000/
curl: (7) Failed to connect to localhost port 8000: Connection refused

次に、--net=host を付けた場合、

$ docker run --rm --net=host appropriate/curl curl -fsSL localhost:8000/
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN" "http://www.w3.org/TR/html4/strict.dtd">
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
<title>Directory listing for /</title>
</head>
<body>
<h1>Directory listing for /</h1>
<hr>
<ul>
<li><a href="memo.md">memo.md</a></li>
<li><a href="net-test.cwl">net-test.cwl</a></li>
</ul>
<hr>
</body>
</html>

host に立てた server から取得できた。

CWL NetworkAccess

5.15 NetworkAccess

Indicate whether a process requires outgoing IPv4/IPv6 network access. Choice of IPv4 or IPv6 is implementation and site specific, correct tools must support both.

If networkAccess is false or not specified, tools must not assume network access, except for localhost (the loopback device).

If networkAccess is true, the tool must be able to make outgoing connections to network resources. Resources may be on a private subnet or the public Internet. However, implementations and sites may apply their own security policies to restrict what is accessible by the tool.

Enabling network access does not imply a publically routable IP address or the ability to accept inbound connections.

とのこと。

また、CWL の標準処理系である cwltool の help によると、

$ cwltool --help | grep net
  --custom-net CUSTOM_NET
                        Passed to `docker run` as the '--net' parameter when

という Option が存在している。

つまり、cwl file に NetworkAccess を追加し、 --custome-net host Option を渡せば、host の network にアクセスできる。


まず、失敗するケースの cwl command line tool を書いた。

class: CommandLineTool
cwlVersion: v1.0
requirements:
  DockerRequirement:
    dockerPull: appropriate/curl:latest
baseCommand: curl
arguments:
  - "-fsSL"
  - "localhost:8000"
inputs: []
outputs: []

これを実行すると、

$ cwltool net-test.cwl
/usr/local/bin/cwltool 1.0.20190228155703
Resolved 'net-test.cwl' to 'file:///home/ubuntu/cwltool-net-test/net-test.cwl'
[job net-test.cwl] /tmp/c2q72jah$ docker \
    run \
    -i \
    --volume=/tmp/c2q72jah:/IGKaZw:rw \
    --volume=/tmp/4p2_8ny2:/tmp:rw \
    --workdir=/IGKaZw \
    --read-only=true \
    --user=1000:1000 \
    --rm \
    --env=TMPDIR=/tmp \
    --env=HOME=/IGKaZw \
    --cidfile=/tmp/fa6lf9vt/20190425050648-304775.cid \
    appropriate/curl:latest \
    curl \
    -fsSL \
    localhost:8000
curl: (7) Failed to connect to localhost port 8000: Connection refused
[job net-test.cwl] Max memory used: 0MiB
[job net-test.cwl] completed permanentFail
{}
Final process status is permanentFail

失敗している。


次に、NetworkAccess を追加する。この際、 cwlVersionv1.1.0-dev1 になる。

class: CommandLineTool
cwlVersion: v1.1.0-dev1
requirements:
  DockerRequirement:
    dockerPull: appropriate/curl:latest
  NetworkAccess:
    networkAccess: true
baseCommand: curl
arguments:
  - "-fsSL"
  - "localhost:8000"
inputs: []
outputs: []

これで、cwltool に --custom-net host Option を渡し実行してみる。

この際、cwlVersion: v1.1.0-dev1 を用いているため、--enable-dev Option も渡さなければならない。

$ cwltool --enable-dev --custom-net host net-test.cwl
/usr/local/bin/cwltool 1.0.20190228155703
Resolved 'net-test.cwl' to 'file:///home/ubuntu/cwltool-net-test/net-test.cwl'
[job net-test.cwl] /tmp/q1z2jsai$ docker \
    run \
    -i \
    --volume=/tmp/q1z2jsai:/qfcEJr:rw \
    --volume=/tmp/5h6avo69:/tmp:rw \
    --workdir=/qfcEJr \
    --read-only=true \
    --net=host \
    --user=1000:1000 \
    --rm \
    --env=TMPDIR=/tmp \
    --env=HOME=/qfcEJr \
    --cidfile=/tmp/d2vdphx0/20190425051126-429824.cid \
    appropriate/curl:latest \
    curl \
    -fsSL \
    localhost:8000
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN" "http://www.w3.org/TR/html4/strict.dtd">
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
<title>Directory listing for /</title>
</head>
<body>
<h1>Directory listing for /</h1>
<hr>
<ul>
<li><a href="memo.md">memo.md</a></li>
<li><a href="net-test.cwl">net-test.cwl</a></li>
</ul>
<hr>
</body>
</html>
[job net-test.cwl] Max memory used: 0MiB
[job net-test.cwl] completed success
{}
Final process status is success

出来た。

ちゃんと --net=host が追加されている。

Summary

  • cwltool に --net=host, --enable-dev Option を渡す
  • cwl file の cwlVersionv1.1.0-dev1 にして、NetworkAccess を追加する

CWL Conformance Test について

tl;dr

  • cwltool に対する pull request を作成したい
  • その前に conformance test を行わなければならない
  • 基本的には下記のページを参照する
  • メモ書きとして、手順を自分でも残しておく

環境準備


環境は下記の通り

$ cat /etc/os-release
NAME="Ubuntu"
VERSION="16.04.6 LTS (Xenial Xerus)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 16.04.6 LTS"
VERSION_ID="16.04"
HOME_URL="http://www.ubuntu.com/"
SUPPORT_URL="http://help.ubuntu.com/"
BUG_REPORT_URL="http://bugs.launchpad.net/ubuntu/"
VERSION_CODENAME=xenial
UBUNTU_CODENAME=xenial
$ python -V
Python 3.7.2
$ pip -V
pip 19.0.3 from /opt/pyenv/versions/3.7.2/lib/python3.7/site-packages/pip (python 3.7)
$ pip3 list
Package           Version
----------------- ------------------
certifi           2019.3.9
pip               19.0.3
pipenv            2018.11.26
setuptools        41.0.0
virtualenv        16.4.3
virtualenv-clone  0.5.3
wheel             0.33.1

諸々を clone, install する

$ git clone https://github.com/suecharo/cwltool.git
$ cd ..
$ git clone https://github.com/common-workflow-language/common-workflow-language.git
$ pip3 install cwltest
$ pip3 list
Package           Version
----------------- ------------------
CacheControl      0.12.5
certifi           2019.3.9
chardet           3.0.4
cwltest           1.0.20190228134645
idna              2.8
isodate           0.6.0
junit-xml         1.8
lockfile          0.12.2
mistune           0.8.4
msgpack           0.6.1
pip               19.0.3
pipenv            2018.11.26
pyparsing         2.4.0
rdflib            4.2.2
rdflib-jsonld     0.4.0
requests          2.21.0
ruamel.yaml       0.15.91
schema-salad      4.1.20190305210046
setuptools        41.0.0
six               1.12.0
typing-extensions 3.7.2
urllib3           1.24.1
virtualenv        16.4.3
virtualenv-clone  0.5.3
wheel             0.33.1

cwltool を install する際、git clone した dir 上の file をそのまま使いたいため setuptools の開発者モードを使う

$ cd cwltool
$ python3 setup.py develop
$ pip3 list | grep cwltool
cwltool           1.0.20190402060741 /home/suecharo/GitHub/cwltool
$ cwltool --version
/opt/pyenv/versions/3.7.2/bin/cwltool 1.0.20190402060741

ファイルの書き換えと Conformance Test の実行

  • 注意点として、
    • ./run_test.sh を実行したら runner 'cwl-runner' not found って言われる
      • cwl-runner の alias が設定されていないため
      • RUNNER=cwltool とかで実行する
    • 実行にかなり時間がかかる
      • -j option を使う
    • ファイルを書き換える前に一度 Conformance Test を実行しておく
      • そもそも Test が落ちている場合がある
$ cd common-workflow-language
$ ./run_test.sh --help
run_test.sh: Run common workflow tool description language conformance tests.

Syntax:
        run_test.sh [RUNNER=/path/to/cwl-runner] [DRAFT=cwl-draft-version]
                       [EXTRA=--optional-arguments-to-cwl-runner]

Options:
  -nT                   Run a specific test.
  -l                    List tests
  -jJ                   Specifies the number of tests to run simultaneously
                        (defaults to one).
  --only-tools          Only test CommandLineTools
  --junit-xml=FILENAME  Store results in JUnit XML format using the given
                        FILENAME
  --classname=CLASSNAME In the JUnit XML, tag the results with the given
                        CLASSNAME
  --timeout=TIMEOUT     cwltest timeout in seconds.
  --verbose             Print the cwltest invocation and pass --verbose to
                        cwltest
  --self                Test CWL and test .cwl files themselves. If this flag
                        is given, any other flags will be ignored.
  --badgedir=DIRNAME    Specifies the directory to store JSON files for badges.
  --tags TAGS           Tags to be tested

Note:
  EXTRA is useful for passing --enable-dev to the CWL reference runner:
  Example: RUNNER=cwltool EXTRA=--enable-dev
$ ./run_test.sh RUNNER=cwltool -j=32

...

All tests passed

All tool tests succeeded
  • ここから、cwltool/cwltool 内を書き換えていく
  • 修正後、再度 Confirmance Test を実行して、test が通るようにする
  • git push して、pull request を作成する

Flask の logging 設定

tl;dl

環境

これも一緒

$ cat /etc/os-release
NAME="Alpine Linux"
ID=alpine
VERSION_ID=3.8.2
PRETTY_NAME="Alpine Linux v3.8"
HOME_URL="http://alpinelinux.org"
BUG_REPORT_URL="http://bugs.alpinelinux.org"
$ python -V
Python 3.7.2
$ django-admin version
2.1.5

Flask の Logging の初期設定

下のコードで、Flask インスタンス作成時の Logger を調べると、

# coding: utf-8
import logging
from pprint import pprint

from flask import Flask

if __name__ == "__main__":
    app = Flask(__name__)
    pprint(logging.root.manager.loggerDict)
{'asyncio': <Logger asyncio (WARNING)>,
 'concurrent': <logging.PlaceHolder object at 0x7f71fe7bb550>,
 'concurrent.futures': <Logger concurrent.futures (WARNING)>}

であり、Flask で生成される Logger は存在しない。

ただ、上の Docs より、

from logging.config import dictConfig

dictConfig({
    'version': 1,
    'formatters': {'default': {
        'format': '[%(asctime)s] %(levelname)s in %(module)s: %(message)s',
    }},
    'handlers': {'wsgi': {
        'class': 'logging.StreamHandler',
        'stream': 'ext://flask.logging.wsgi_errors_stream',
        'formatter': 'default'
    }},
    'root': {
        'level': 'INFO',
        'handlers': ['wsgi']
    }
})

app = Flask(__name__)

であることから、Flask は root logger に色々吐いているようだ。

# coding: utf-8
import logging
from pprint import pprint

from flask import Flask

if __name__ == "__main__":
    app = Flask(__name__)
    pprint(vars(logging.getLogger()))
{'_cache': {},
 'disabled': False,
 'filters': [],
 'handlers': [],
 'level': 30,
 'name': 'root',
 'parent': None,
 'propagate': True}

ここでは、handler は登録されていないが、root logger は console に出力する。

$ python3
Python 3.7.2 (default, Jan 30 2019, 23:40:31)
[GCC 6.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import logging
>>> root = logging.getLogger()
>>> root.warning("FUGA")
FUGA

どうしたか

logging_config.py を作って以下を記述する。この際、root は handlers の中に入れず、別エントリを作る

# coding: utf-8
from .config import LOG_FILE_PATH
from copy import deepcopy


TEMPLATE = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "default": {
            "format": "[%(asctime)s] %(levelname)s %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S",
        },
        "long": {
            "format": "[%(asctime)s] %(levelname)s - %(filename)s#%(funcName)s:%(lineno)d: %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S",
        },
    },
    "handlers": {
        "console": {
            "level": "INFO",
            "class": "logging.StreamHandler",
            "formatter": "default",
            "stream": "ext://sys.stderr"
        },
        "file": {
            "level": "INFO",
            "class": "logging.FileHandler",
            "formatter": "default",
            "filename": LOG_FILE_PATH,
        },
    },
    "root": {
        "handlers": ["console", "file"],
        "level": "INFO",
    },
}

wsgi_info = deepcopy(TEMPLATE)
wsgi_info["root"]["handlers"] = ["file"]
wsgi_debug = deepcopy(TEMPLATE)
wsgi_debug["handlers"]["file"]["level"] = "DEBUG"
wsgi_debug["handlers"]["file"]["formatter"] = "long"
wsgi_debug["root"]["handlers"] = ["file"]
wsgi_debug["root"]["level"] = "DEBUG"

local_info = deepcopy(TEMPLATE)
local_debug = deepcopy(TEMPLATE)
local_debug["handlers"]["console"]["level"] = "DEBUG"
local_debug["handlers"]["console"]["formatter"] = "long"
local_debug["handlers"]["file"]["level"] = "DEBUG"
local_debug["handlers"]["file"]["formatter"] = "long"
local_debug["root"]["level"] = "DEBUG"

Flask インスタンスを作成後に、logger を更新する。

# coding: utf-8
import logging
from pprint import pprint
import os

from flask import Flask

if __name__ == "__main__":
    app = Flask(__name__)
    if os.environ.get("DEBUG") == "True":
        if os.environ.get("LOG_LEVEL") == "DEBUG":
            dictConfig(local_debug)
        else:
            dictConfig(local_info)
    else:
        if os.environ.get("LOG_LEVEL") == "DEBUG":
            dictConfig(wsgi_debug)
        else:
            dictConfig(wsgi_info)

更に、Flask は Debug mode の場合、ブラウザで debug するための html が response で帰ってくる。また、log には traceback の情報が残らない仕様になっている。そのため、Error Handler を編集する。

@app.errorhandler(400)
@app.errorhandler(401)
@app.errorhandler(404)
@app.errorhandler(500)
def error_handler(error):
    response = {
        "msg": error.description,
        "status_code": error.code,
    }
    response = jsonify(response)
    response.status_code = error.code
    return response

@app.errorhandler(Exception)
def error_handler_exception(exception):
    import traceback
    root_logger.error(exception.args[0])
    root_logger.debug(traceback.format_exc())
    response = {
        "msg": "The server encountered an internal error and was unable to complete your request.",
        "status_code": 500,
    }
    response = jsonify(response)
    response.status_code = 500
    return response

return app

上を使うことで、DEBUG レベルの log として、traceback が出力されるようになる。

Django の logging 設定

tl;dr

  • Django の logging の設定についてのメモ
  • Django の Default の設定 logging の設定は Admin に Email を送ったりしていたため、設定を弄った

何がしたいか

  • Application Server を WSGI にする場合と Local Server にする場合
  • LOG_LEVEL を development と production にする場合
  • 上のそれぞれ 2 パターン * 2 パターンを環境変数で切り替えられるようにしたかった
    • WSGI の場合は File のみに吐く
    • Local Server の場合は File と Console に吐く
    • development の場合は DEBUG レベルの Log と traceback を表示する
    • production の場合は INFO レベルの Log のみを表示する

環境

$ cat /etc/os-release
NAME="Alpine Linux"
ID=alpine
VERSION_ID=3.8.2
PRETTY_NAME="Alpine Linux v3.8"
HOME_URL="http://alpinelinux.org"
BUG_REPORT_URL="http://bugs.alpinelinux.org"
$ python -V
Python 3.7.2
$ django-admin version
2.1.5

Django の Logging の初期設定

初期設定は、Python の dictConfig 形式で表すと、

DEFAULT_LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },
    'formatters': {
        'django.server': {
            '()': 'django.utils.log.ServerFormatter',
            'format': '[{server_time}] {message}',
            'style': '{',
        }
    },
    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
        },
        'django.server': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'django.server',
        },
        'mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false'],
            'class': 'django.utils.log.AdminEmailHandler'
        }
    },
    'loggers': {
        'django': {
            'handlers': ['console', 'mail_admins'],
            'level': 'INFO',
        },
        'django.server': {
            'handlers': ['django.server'],
            'level': 'INFO',
            'propagate': False,
        },
    }
}

この設定は、Django - Docs - logging から引用すると、

  • DEBUG が True のとき:
  • DEBUG が False のとき:
  • DEBUG の値にかかわらず:
    • django.server ロガーは INFO レベル以上のメッセージをコンソールに送信します。
  • All loggers except django.server propagate logging to their parents, up to the root django logger. The console and mail_admins handlers are attached to the root logger to provide the behavior described above.

だそうだ。


もう少しちゃんと調べる。 まず、django.setup() した後に設定されている logger の list は、

# coding: utf-8
import logging
import os
from pprint import pprint

import django

if __name__ == "__main__":
    os.environ.setdefault("DJANGO_SETTINGS_MODULE", "config.settings")
    django.setup()
    pprint(logging.root.manager.loggerDict)

を使って、結果は、

$ python3 logging_test.py
{'django': <Logger django (INFO)>,
 'django.db': <logging.PlaceHolder object at 0x7f70c014deb8>,
 'django.db.backends': <Logger django.db.backends (INFO)>,
 'django.db.backends.schema': <Logger django.db.backends.schema (INFO)>,
 'django.request': <Logger django.request (INFO)>,
 'django.security': <logging.PlaceHolder object at 0x7f70bf5a46d8>,
 'django.security.csrf': <Logger django.security.csrf (INFO)>,
 'django.server': <Logger django.server (INFO)>,
 'django.template': <Logger django.template (INFO)>,
 'factory': <logging.PlaceHolder object at 0x7f70be564400>,
 'factory.generate': <Logger factory.generate (WARNING)>,
 'faker': <logging.PlaceHolder object at 0x7f70be508828>,
 'faker.factory': <Logger faker.factory (WARNING)>,
 'requests': <Logger requests (WARNING)>,
 'urllib3': <Logger urllib3 (WARNING)>,
 'urllib3.connection': <Logger urllib3.connection (WARNING)>,
 'urllib3.connectionpool': <Logger urllib3.connectionpool (WARNING)>,
 'urllib3.poolmanager': <Logger urllib3.poolmanager (WARNING)>,
 'urllib3.response': <Logger urllib3.response (WARNING)>,
 'urllib3.util': <logging.PlaceHolder object at 0x7f70be826e80>,
 'urllib3.util.retry': <Logger urllib3.util.retry (WARNING)>}

つまり、django 以外の library が logger を設定していたり、django.server 以外の logger が使われている。

Django で使われている Logger

Django - Docs - logging より、

  • django
    • django の Logger をまとめるための logger, logging 自体は行わない
  • django.request
    • request に関する logger。5xx 系は error, 4xx 系は warning として処理をする
    • [26/Feb/2019 08:48:34] "GET / HTTP/1.1" 200 4051 みたいな log を吐いている
  • django.server
    • runserver コマンドによって呼び出されたサーバーによって受信された request の処理に関する logger
    • 基本的には django.request と同じ
  • django.template
    • Template のレンダリングに関する logger
    • context 変数などが足りない場合 debug レベルの log を吐く
  • django.db.backends
    • データベースに関する logger
    • SQL 文などを debug で log している
  • django.security
    • セキュリティ関連に関する logger

とのことで、それぞれの logger の中身を調べると、

# coding: utf-8
import logging
import os

import django

if __name__ == "__main__":
    os.environ.setdefault("DJANGO_SETTINGS_MODULE", "config.settings")
    django.setup()
    print(vars(logging.getLogger("root")))
    for logger_name in logging.root.manager.loggerDict.keys():
        if "django" not in logger_name:
            continue
        print(vars(logging.getLogger(logger_name)))
$ python3 logging_test.py
{'filters': [], 'name': 'root', 'level': 0, 'parent': <RootLogger root (WARNING)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.template', 'level': 0, 'parent': <Logger django (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django', 'level': 20, 'parent': <RootLogger root (WARNING)>, 'propagate': True, 'handlers': [<StreamHandler <stderr> (INFO)>, <AdminEmailHandler (ERROR)>], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.db.backends', 'level': 0, 'parent': <Logger django (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.db', 'level': 0, 'parent': <Logger django (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.request', 'level': 0, 'parent': <Logger django (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.server', 'level': 20, 'parent': <Logger django (INFO)>, 'propagate': False, 'handlers': [<StreamHandler <stderr> (INFO)>], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.security.csrf', 'level': 0, 'parent': <Logger django (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.security', 'level': 0, 'parent': <Logger django (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}
{'filters': [], 'name': 'django.db.backends.schema', 'level': 0, 'parent': <Logger django.db.backends (INFO)>, 'propagate': True, 'handlers': [], 'disabled': False, '_cache': {}, 'manager': <logging.Manager object at 0x7f5c77908cf8>}

見辛いので、いらない項目を消して、整形すると、

{'handlers': [],
 'level': 0,
 'name': 'root',
 'parent': <RootLogger root (WARNING)>,
 'propagate': True}
{'handlers': [<StreamHandler <stderr> (INFO)>, <AdminEmailHandler (ERROR)>],
 'level': 20,
 'name': 'django',
 'parent': <RootLogger root (WARNING)>,
 'propagate': True}
{'handlers': [],
 'level': 0,
 'name': 'django.template',
 'parent': <Logger django (INFO)>,
 'propagate': True}
{'handlers': [],
 'level': 0,
 'name': 'django.db.backends',
 'parent': <Logger django.db (INFO)>,
 'propagate': True}
{'handlers': [],
 'level': 0,
 'name': 'django.db',
 'parent': <Logger django (INFO)>,
 'propagate': True}
{'handlers': [],
 'level': 0,
 'name': 'django.request',
 'parent': <Logger django (INFO)>,
 'propagate': True}
 {'handlers': [<StreamHandler <stderr> (INFO)>],
 'level': 20,
 'name': 'django.server',
 'parent': <Logger django (INFO)>,
 'propagate': False}
{'handlers': [],
 'level': 0,
 'name': 'django.security.csrf',
 'parent': <Logger django.security (INFO)>,
 'propagate': True}
{'handlers': [],
 'level': 0,
 'name': 'django.security',
 'parent': <Logger django (INFO)>,
 'propagate': True}
{'handlers': [],
 'level': 0,
 'name': 'django.db.backends.schema',
 'parent': <Logger django.db.backends (INFO)>,
 'propagate': True}

上の出力を整理すると、

{'handlers': [<StreamHandler <stderr> (INFO)>, <AdminEmailHandler (ERROR)>],
 'level': 20,
 'name': 'django',
 'parent': <RootLogger root (WARNING)>,
 'propagate': True}

に対して、その他大勢の logger が、

{'handlers': [],
 'level': 0,
 'name': 'django.template',
 'parent': <Logger django (INFO)>,
 'propagate': True}

のようにして、propagate している。そのため、DEBUG メッセージも含めて django logger に propagate しているけど django logger が INFO 未満を切り捨てている事になっている。

ちなみに、python の logging の level と数値の対応は下記の通りである。

Level Num
CRITICAL 50
ERROR 40
WARNING 30
INFO 20
DEBUG 10
NOTSET 0

また、

 {'handlers': [<StreamHandler <stderr> (INFO)>],
 'level': 20,
 'name': 'django.server',
 'parent': <Logger django (INFO)>,
 'propagate': False}

だけ、propagate せずに、そのまま stderr に吐いている。


ここで、django.requestdjango.server が同じログを吐く場合、./manage.py runserver をした場合、ログが重複するのではないかと考えたが、重複していない。これは、./manage.py runserver の場合は django.server にのみ、WSGI などを使った場合は django.request のみに行っているようだ。

どうしたか

とりあえず、setting.pyDEBUG = True にしても実際には INFO レベルの Log しか吐かれていないようだった。そのため、環境変数LOG_LEVEL = DEBUG にした場合、DEBUG レベルの Log を吐いてほしい。また、DUBUG=True の場合は、Local Server を使っているとして、console と file の両方に、DEBUG=False の場合は、WSGI を使っているとして file のみに Log を吐いてほしい。

# coding: utf-8
from .settings import LOG_FILE_PATH
from copy import deepcopy

TEMPLATE = {
    "version": 1,
    "disable_existing_loggers": False,
    "filters": {
        "require_debug_true": {
            "()": "django.utils.log.RequireDebugTrue",
        },
    },
    "formatters": {
        "default": {
            "format": "[%(asctime)s] %(levelname)s %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S",
        },
        "long": {
            "format": "[%(asctime)s] %(levelname)s - %(filename)s#%(funcName)s:%(lineno)d: %(message)s",
            "datefmt": "%Y-%m-%d %H:%M:%S",
        },
    },
    "handlers": {
        "console": {
            "level": "INFO",
            "filters": ["require_debug_true"],
            "class": "logging.StreamHandler",
            "formatter": "default",
            "stream": "ext://sys.stderr",
        },
        "file": {
            "level": "INFO",
            "class": "logging.FileHandler",
            "formatter": "default",
            "filename": LOG_FILE_PATH,
        },
    },
    "loggers": {
        "django": {
            "handlers": ["console", "file"],
            "level": "INFO",
        },
        "django.server": {
            "handlers": ["console", "file"],
            "level": "INFO",
            "propagate": False,
        },
    },
}

# DUBUG is False --- console is filtered and django.server not work
wsgi_info = deepcopy(TEMPLATE)

wsgi_debug = deepcopy(TEMPLATE)
wsgi_debug["handlers"]["file"]["level"] = "DEBUG"
wsgi_debug["handlers"]["file"]["formatter"] = "long"
wsgi_debug["loggers"]["django"]["level"] = "DEBUG"

# DUBUG is True --- console is not filtered and django.server works
local_info = deepcopy(TEMPLATE)

local_debug = deepcopy(TEMPLATE)
local_debug["handlers"]["file"]["level"] = "DEBUG"
local_debug["handlers"]["file"]["formatter"] = "long"
local_debug["handlers"]["console"]["level"] = "DEBUG"
local_debug["handlers"]["console"]["formatter"] = "long"
local_debug["loggers"]["django"]["level"] = "DEBUG"
local_debug["loggers"]["django.server"]["level"] = "DEBUG"

上のような file を作成し、setting.py にて

from .logging_conf import wsgi_info, wsgi_debug, local_info, local_debug

if DEBUG:
    if os.environ.get("LOG_LEVEL") == "DEBUG":
        LOGGING = local_debug
    else:
        LOGGING = local_info
else:
    if os.environ.get("LOG_LEVEL") == "DEBUG":
        LOGGING = wsgi_debug
    else:
        LOGGING = wsgi_info

とした。

注意点

from logging.config import dictConfig
dictConfig(wsgi_info)

のように setting.py の中で設定した場合、きちんと反映されないため LOGGING 変数を使う必要がある。


disable_existing_loggers キーが True もしくは何もセットしない場合 (default は True) 、下記の Logger も削除されてしまうため、注意が必要である。

'factory': <logging.PlaceHolder object at 0x7f70be564400>,
'factory.generate': <Logger factory.generate (WARNING)>,
'faker': <logging.PlaceHolder object at 0x7f70be508828>,
'faker.factory': <Logger faker.factory (WARNING)>,
'requests': <Logger requests (WARNING)>,
'urllib3': <Logger urllib3 (WARNING)>,
'urllib3.connection': <Logger urllib3.connection (WARNING)>,
'urllib3.connectionpool': <Logger urllib3.connectionpool (WARNING)>,
'urllib3.poolmanager': <Logger urllib3.poolmanager (WARNING)>,
'urllib3.response': <Logger urllib3.response (WARNING)>,
'urllib3.util': <logging.PlaceHolder object at 0x7f70be826e80>,
'urllib3.util.retry': <Logger urllib3.util.retry (WARNING)>}

setting.pyLOGGING_CONFIG = None にした場合、django.template などの設定も削除される。そのため、注意が必要である。

開発中の Django の Session が切れる問題

tl;dr

  • Django の開発する際、コードを変更したら自動的にサーバがリロードされる
  • 以前まで、リロードされても Session が保たれていたため、再度ログインが必要なかった
  • setting.pySECRET_KEY を自動生成にしたら、リロードされる度に再度ログインが必要になった

以前まで

setting.pySECRET_KEY にハードコーディングしたり、env file から読み込んだりしていた。

SECRET_KEY = "a)4r0@mbs6&yef62h2b4(h&b37f$ijn9t53t=hg5wk0_s"
import os

SECRET_KEY = os.environ.get("SECRET_KEY")

ただ、これだとデプロイの度に setting.py を書き換えたり、env file を書き換えるのが辛いと感じていた。

何をしてだめになったか

setting.pySECRET_KEY を自動生成にした。

import random
import string

def generate_secret_key(n):
    c = string.ascii_lowercase + string.ascii_uppercase + string.digits
    return "".join([random.choice(c) for i in range(n)])

SECRET_KEY = generate_secret_key(32)

この場合、自動的にサーバがリロードされる度に SECRET_KEY が生成されるようになる。

Django Docs - settings より、SECRET_KEY の役割としては以下の通りで、SECRET_KEY が変わると Session が切れる。

  • All sessions if you are using any other session backend than django.contrib.sessions.backends.cache, or are using the default get_session_auth_hash().
  • All messages if you are using CookieStorage or FallbackStorage.
  • All PasswordResetView tokens.
  • Any usage of cryptographic signing, unless a different key is provided.

どうすればいいか

デプロイの際に local_settings.py などに書き込むようにして、そこから読み込むようにすれば良い。local_settings.py を git 監視下から外す。

以下のようなスクリプトを作成し、entry_point.sh などで実行するようにする

from django.core.management.utils import get_random_secret_key

print('SECRET_KEY = "{}"'.format(get_random_secret_key()))
python generate_secretkey.py > local_settings.py

setting.py の中で import する

import settings_local

SECRET_KEY = settings_local.SECRET_KEY