【解決済】GoのS3 ListObjectsはPythonより遅いのか？問題

# はじめに

S3から大量Objectをダウンロードする場合、Objectサイズに関わらず中々速度が出ないですよね。
Pythonで書いている時も、**concurrent.futures**などで頑張ってたのですが、もしかしてGoroutineで出来るのでは？と思い、Golangデビューしてみました。

### やろうと思ったこと
- ListObjectV2を用いて、S3の特定Prefix配下のKeyをすべて取得
- 取得したKeyをGoroutineでいい感じにダウンロード

### 実際起こったこと
- ListObject部分を試しに書いてみたが、はっきり言って遅い。
- なんならPythonで書いた方が早い気が？

ん？API叩くだけなので同じ速度。だったらまだ納得は出来るが、**スクリプト言語よりGoの方が遅い**というのはちょっと気になる。
予定を急遽変更して、本件を少し検証してみました。


## ソースコード
### Go版
というわけで[こちら](https://github.com/aws/aws-sdk-go-v2/blob/master/example/service/s3/listObjects/listObjects.go)や[こちら](https://docs.aws.amazon.com/sdk-for-go/api/service/s3/#S3.ListObjectsV2)を参考に書いてみる。

``` main.go 
package main

import (
	"fmt"
	"github.com/aws/aws-sdk-go/aws"
	"github.com/aws/aws-sdk-go/aws/session"
	"github.com/aws/aws-sdk-go/service/s3"
	"os"
)

func main() {
	bucket := os.Getenv("BUCKET")
	prefix := os.Getenv("PREFIX")
	region := os.Getenv("REGION")

	sess := session.Must(session.NewSession())
	svc := s3.New(sess, &aws.Config{
		Region: &region,
	})
	params := &s3.ListObjectsV2Input{
		Bucket: &bucket,
		Prefix: &prefix,
	}
	fmt.Println("Start:")
	err := svc.ListObjectsV2Pages(params,
		func(p *s3.ListObjectsV2Output, last bool) (shouldContinue bool) {
			for _, obj := range p.Contents {
				fmt.Println(*obj.Key)
			}
			return true
		})
	fmt.Println("End:")
	if err != nil {
		fmt.Println(err.Error())
		return
	}
}
```
### Python版
こちらもサクッと書いてみる。
Goと条件を合わせる為、低レベルクライアントで。

``` main.py
#!/usr/bin/env python
# -*- coding: utf-8 -*-
import os
import boto3
bucket = os.environ["BUCKET"]
prefix = os.environ["PREFIX"]
region = os.environ["REGION"]

# r = boto3.resource('s3').Bucket(bucket).objects.filter(Prefix=prefix)
# [print(r.key) for r in r]
# 普段は上記の様に取得するが、Golangへ寄せるため下記のコードにて測定

s3_client = boto3.client('s3', region)

contents = []
next_token = ''
while True:
    if next_token == '':
        response = s3_client.list_objects_v2(Bucket=bucket, Prefix=prefix)
    else:
        response = s3_client.list_objects_v2(Bucket=bucket, Prefix=prefix, ContinuationToken=next_token)

    contents.extend(response['Contents'])
    if 'NextContinuationToken' in response:
        next_token = response['NextContinuationToken']
    else:
        break

[print(r["Key"]) for r in contents]
```

## 環境
### サーバ等
- 基本的にCloud9 on EC2(t2.micro)で実行。

### ビルド・デプロイ等
- 環境を汚したくない&面倒なので、全部Dockerで構築。

``` bash
$ docker-compose up -d --build
```
- ちなみに構築資材は下記を参照。

``` dockerfile:Dockerfile 
FROM golang:1.13.5-stretch as build
RUN go get \
  github.com/aws/aws-sdk-go/aws \
  github.com/aws/aws-sdk-go/aws/session \
  github.com/aws/aws-sdk-go/service/s3 
COPY . /work
WORKDIR /work
RUN CGO_ENABLED=0 GOOS=linux GOARCH=amd64 go build -o main main.go

FROM python:3.7.6-stretch as release
RUN pip install boto3
COPY --from=build /work/main /usr/local/bin/main
COPY --from=build /work/main.py /usr/local/bin/main.py
WORKDIR /usr/local/bin/
```

``` docker-compose.yml
version: '3'
services:
  app:
    build:
      context: .
    container_name: "app"
    tty: True
    environment:
      BUCKET: <Bucket>
      PREFIX: test/
      REGION: ap-northeast-1
```
### S3バケット
東京リージョンにバケットを一つ作って、以下のツールで1000件程度作成。

``` bash
#/bin/bash

Bucket=<Bucket>
Prefix="test"

# テストファイル作成
dd if=/dev/zero of=testobj bs=1 count=30
# マスタファイルのコピー
aws s3 cp testobj s3://${Bucket}/${Prefix}/testobj
# マスタファイルを複製
for i in $(seq 0 9); do
    for k in $(seq 0 99); do
        aws s3 cp s3://${Bucket}/${Prefix}/testobj s3://${Bucket}/${Prefix}/${i}/${k}/${i}_${k}.obj
    done
done
```

## 測定
### 測定結果(1000 Object)
- Go

``` bash
$ time docker-compose exec app ./main

～略～

real    0m21.888s
user    0m0.580s
sys     0m0.107s
```

- Python

``` bash
$ time docker-compose exec app ./main.py

～略～

real    0m2.671s
user    0m0.577s
sys     0m0.104s
```

GoがPythonより10倍遅い。なんでや！ 

### Object数を増やしてみる
- もうすこしobjectを増やしてみましょう。とりあえず10000件あたりで。

``` bash
#差分のみ
for i in $(seq 0 99); do
    for k in $(seq 0 99); do
```
- ちなみにアップロード完了までに3、4時間かかりました。ツールはちゃんと作っとけばよかったね…

### 再測定結果(10000 Object)
- Go

``` bash
$ time docker-compose exec app ./main

～略～

real    0m23.276s
user    0m0.617s
sys     0m0.128s
```

- Python

``` bash
$ time docker-compose exec app ./main.py

～略～
real    0m5.973s
user    0m0.576s
sys     0m0.114s
```

今回は4倍程度の差。
というよりObject数によらず18秒ほど差が出ている様子。うーむ。

## 終わりに
- ライブラリの設定起因か、言語仕様の理解不足な気もしているので、もう少し情報を漁ってみたい。
- そもそもの目的である**Goroutineでの並列ダウンロード処理**の効率が良ければ20秒程度は誤差な気もするので、残りも実装してみます。

### 気になるところ
- よく見るとuser, sysは同じ程度なのでS3でI/O周りが怪しい。
- goのコードを雑にprintデバッグしたところ("Start:", "End:")、list objectが処理時間の大半を占めている様子。もしやboto3とはS3設定のデフォルト値が異なるのだろうか。
- 同じコンテナで動かしてるので、T系インスタンスのCPUクレジット問題やNW帯域の差も関係ないと思うが……
   - 前者はm5.largeに代えても解決しなかったので関係なさげ。

## 続報(2020/01/18)
コメント欄でアドバイスいただいた通り、SDKをデバッグしてみたところ
IAMのCredentialを探すのに時間がかかっていたことが分かりました。
「-stretch」のOSのデフォルト値が悪さしていたのか。
その後何度か試しましたが、こちらの環境でも再現しなくなったのでいったん解決とします。モヤモヤしますが…

@nabekenさん ありがとうございました！