こんにちは、株式会社カミナシのエンジニア @imu です。
はじめに
突然ですがファイルアップロードに失敗することってありますよね？
カミナシレポートのプロダクトはオフライン機能を実装しており、オフラインで記録したデータをアップロードしたときに失敗するケースが、特定の条件下で起きるようになりました。そのため一部のお客様のデータが端末に残り続け、なんとかしてほしいとサポート依頼が発生しておりました。
私自身、半年ぶりにカミナシレポートのプロダクトに戻ってきたばかりで、リハビリのissueとなりました(笑)
今回は問題を解決するまでの仮説や、調査から解決までお話したいと思います！
※オフライン対応をなぜしているのかは以前書いたこちらを参照いただければと思います。 kaminashi-developer.hatenablog.jp
結論
何が問題だったか結論だけ知りたい方はこちらへ
開発環境
問題の確認
@dmi8a さんが予め調査をしており、以下の共有を受けました。
- AWS S3にファイルアップロードする際に
UploadWithContextメソッドを使っていて、ここでエラーを出力している。 - S3 UploadWithContextに関する調査は行い、Partサイズを変更してみたが結果は変わらず。
- ファイルアップロード出来ているケースもあり、ファイルサイズの問題である可能性がある。
- MultipartのファイルがS3にアップロードする前にファイルクローズされているのでは？という仮説。
なるほど…わからん。何はともあれ事象を確認していかないと、どこからアプローチをしていくかが分かりません。
まず、Datadogにアプリケーションログが出力されていたので、そちらのログを確認しました。
※一部抜粋 Caused by: failed to upload file:ReadRequestBody: unable to initialize upload caused by: seek /tmp/multipart-2439640442: file already closed
特定のメソッドでエラーを出力していることが分かり、@dmi8a さんが調査したところだなと再確認。
file already closed
とログが出ているので確かにファイルクローズが原因なのか？と思い調査を開始しました。
ローカル環境で再現するか試す
私自身のやり方になってしまいますが、まずはローカル環境で同じ事象が起きるのか？と確かめないと気が済まない質です。
手順としては以下を想定していました。
- ファイルサイズの問題であるため、アプリケーションで制限掛けているサイズのファイルを用意する
- ローカルからS3にアップロードして同じエラーが発生するかを確認する
- エラーが発生したら原因の切り分けをする
ローカルにデータを準備する
Mobileアプリケーションは現在 iOS のみ提供しているため、ローカルの動作検証はXcode Simulatorを利用しています。
ローカルDBはSQLiteを利用しているため、データベースファイルを用意しなくてはなりません。開発で利用しているオフラインデータを元に、DB Browser for SQLite などでファイルを開き、どのテーブルでも良いのでレコード数を増やせば目的のファイルサイズまで一気に増やすことが出来ます。
用意したデータは約70MBのファイルです。
Simulatorの場合、ローカルディレクトリにSQLiteのファイルがあるので用意したファイルと入れ替えれば問題なし！
SQLiteファイルがどこにあるかを調べる方法
cd Library/Developer/CoreSimulator/Devices find ./ -name fuga ※ディレクトリはあくまで一例 .//3B9CD40F-FFAC-4F30-9F5D-87D508468E15/data/Containers/Data/Application/F2F25F44-F105-422B-B9B5-880A2DCD6F3D/Documents/ExponentExperienceData/hoge1/hoge_directory/SQLite/fuga
あとはMobileからリクエストを投げて再現するかを確認すると…
「再現したよ！」
再現性があれば解決はできるのでまずは第一歩を踏み出しました。
仮説を立てながら原因の絞り込み
問題になっているリクエスト処理はこちらです。
※実際のコードを抜粋したもの type sqliteFileUpload struct { Name string `validate:"required" jaName:"ファイル名" enName:"file name"` // 最大100MB Size int64 `validate:"required,min=1,max=104857600" jaName:"ファイルサイズ" enName:"file size"` File io.Reader } func sample(c echo.Context) error { cc := c.(*middleware.Context) form, err := cc.MultipartForm() if err != nil { return err } files := form.File["files[]"] uploadFiles := make([]*sqliteFileUpload, 0) for _, file := range files { src, err := file.Open() defer src.Close() if err != nil { return err } uploadFiles = append(uploadFiles, &sqliteFileUpload{ Name: file.Filename, Size: file.Size, File: src, }) } // uploadFilesを元にS3へアップロード return c.JSON(http.StatusOK, nil) }
仮説1. 本当にファイルクローズが問題なのか
file already closed と出力されているため、defer src.Close() がS3アップロード前にされているのがダメなのかと思い、デバッグログを仕込んで処理フローを確認しました。
- Multipartファイルオープン
- Multipartファイルクローズ
- S3にアップロード
が、アップロードが成功するファイルとしないファイルでは処理フローに差分はありませんでした。
仮説2. ローカルからアップロードは可能なのか
次に試したことはMobileから送られるファイルに問題があるかどうかの切り分けです。
- MobileからApiサーバーに送られたMultipartファイルを
os.Openする - ソースファイルと同じディレクトにSQLiteファイルを置いて
os.Openする 2.で読み込んだファイルをMobileから送られたファイルとして、S3にアップロードしてみる（同じファイルなので、ここで失敗すればS3にアップロードが出来ないという問題に絞り込める）
func sample(c echo.Context) error { ... uploadFiles := make([]*sqliteFileUpload, 0) for _, file := range files { src, _ := file.Open() if err != nil { return err } // ソースファイルと同じディレクトにSQLiteファイルを読み取る localFile, err := os.Open("local SQLite file path") if err != nil { return err } defer src.Close() defer localFile.Close() uploadFiles = append(uploadFiles, &sqliteFileUpload{ Name: file.Filename, Size: file.Size, // Mobileから送られたファイルではなく、ローカルから読み取ったファイルを指定してみた // File: src, File: localFile, }) } // uploadFilesを元にS3へアップロード return c.JSON(http.StatusOK, nil) }
ダメなんだろうなと思っていましたが、このケースはアップロードが出来ました！
可能性として MultipartForm(),os.Openに絞り込むことが出来ました。
仮説3. Multipartファイルがアップロード出来るケースと出来ないケースの違いを探る
- アップロード出来るときの
os.Openログ（戻り値の型はmultipart.File）
※一部抜粋 ... 0x69, 0x63, 0x61, 0x74, 0x65, 0x64, 0x49, 0x73, 0x73, 0x75, 0x65, 0x73, 0x22, 0x3a, 0x5b, 0x5d, 0x7d}, i: 0, prevRune: -1, }, base: 0, off: 0, limit: 53248, }, }
- アップロード出来ないときの
os.Openログ（戻り値の型はmultipart.File）
&os.File{
file: &os.file{
pfd: poll.FD{
fdmu: poll.fdMutex{},
Sysfd: 99,
pd: poll.pollDesc{},
iovecs: (*[]syscall.Iovec)(nil),
csema: 0x0,
isBlocking: 0x1,
IsStream: true,
ZeroReadIsEOF: true,
isFile: true,
},
name: "/tmp/multipart-1070998851",
dirinfo: (*os.dirInfo)(nil),
nonblock: false,
stdoutOrErr: false,
appendMode: false,
},
}
何かしらに失敗していることは明らかで、他に検討も付かなかった私はos.Openがどういった処理になっているのかコードを追うことにしました。
github.com
時間溶ける〜。溶けるよー。沼にハマること約1時間…。
これは解決難しいな…と思っていた矢先！
突然の閃き！！！
仮説4. MultipartFormが怪しい説
echoのMultipartForm() 関数をジャンプしても定義してはこちらです。
閃く前にここまでは見ていましたが、先入観で「あ、こういう関数なんだ。良しなにやってくれている」と思い込んでいました。
ただ実際何やっているのかを知る必要があると思い、検索すると…
echo...やってくれたな…！
defaultMemory = 32MBってめっちゃ書いてあるやん…。
しかも ParseMultipartForm を見ると答えは書いてありました…お恥ずかしいかぎりです。 github.com
修正コード
const MaxSQLiteFileSize untyped int = 104857600 type sqliteFileUpload struct { Name string `validate:"required" jaName:"ファイル名" enName:"file name"` // 最大100MB Size int64 `validate:"required,min=1,max=104857600" jaName:"ファイルサイズ" enName:"file size"` File io.Reader } func sample(c echo.Context) error { // // defaultMemoryサイズをvalidateのサイズと同じにして読み込めるように修正 // err := c.Request().ParseMultipartForm(MaxSQLiteFileSize) if err != nil { return err } form := c.Request().MultipartForm files := form.File["files[]"] uploadFiles := make([]*sqliteFileUpload, 0) for _, file := range files { src, err := file.Open() defer src.Close() if err != nil { return err } uploadFiles = append(uploadFiles, &sqliteFileUpload{ Name: file.Filename, Size: file.Size, File: src, }) } // uploadFilesを元にS3へアップロード return c.JSON(http.StatusOK, nil) }
ついにアップロード出来るようになりましたとさ。めでたしめでたし。
所感
- @dmi8a さんが予め調査をしていたので解決が早かった
- 何気なく使っているメソッド（packageが用意している）も疑おう
- 行き詰まったら別のアプローチを考えよう
- 根本的にはMobileから直接S3にアップロードしても良さそう
- 解決するとスッキリするし、仮説を立てて解決するまでは面白い
おわりに
問題を起こさないことに越したことはないけど、こういった問題が起きたときに仮説を立てながら解決していく面白さを感じています。なんとなく使っていたメソッドを深堀り出来たり、どうしたら再発しないかなど再発防止に取り組む意欲も湧いてきますね。
カミナシレポートが急成長していくなか、開発当初は考慮出来ていないことが、現在発生しており大きな課題にもなっています。
0 -> 1の開発フェーズは終わり、1 -> 10, 100といった難しさに直面しているのだと思っていますが、私自身は難しい課題や調査するのは楽しめるタイプなのでもっとプロダクトを良くしていきたいと思います。
今回は良いリハビリになりました！
最後にカミナシめっちゃ気になるなーと思ったら、TwitterのDMや下記の採用情報サイトからご連絡お待ちしております！
ここまで読んでいただき、ありがとうございました！
