以前「大きなサイズのファイルをGitで上手く管理する方法について考える」で、Git LFSに似た仕組み storebin を考え実装した。Gitは大きなファイルを扱うのが苦手なので、ファイルの実体はクラウドのストレージ(Cloudflare R2)に置き、Gitには「どこに置いたか」を書いた小さなポインタファイルだけを登録する、という仕組みだ。それをしばらく使用していたのだが、アップロード時に何かしらのメッセージが出力されることがあった。出ていたのは次のようなエラーだ。
2026/10/08 12:30:45 CRITICAL: Source doesn't exist or is a directory and destination is a file > rclone copyto --verbose DUMMYFILE.tar.xz.gpg DUMMYBUCKET:e2/a6/e2a694ad2292534dbdc3d9055a971ae87529e4c55f46a794c88f4b68a5333aaa 2026/10/08 12:30:45 INFO : S3 bucket e2 path a6: Bucket "e2" created with ACL "" 2026/10/08 12:30:48 ERROR : DUMMYFILE.tar.xz.gpg: Failed to copy: multi-thread copy: failed to write chunk: failed to upload chunk 1 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. 2026/10/08 12:30:48 ERROR : Attempt 1/3 failed with 1 errors and: multi-thread copy: failed to write chunk: failed to upload chunk 1 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. 2026/10/08 12:30:50 ERROR : DUMMYFILE.tar.xz.gpg: Failed to copy: multi-thread copy: failed to write chunk: failed to upload chunk 1 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. 2026/10/08 12:30:50 ERROR : Attempt 2/3 failed with 1 errors and: multi-thread copy: failed to write chunk: failed to upload chunk 1 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. 2026/10/08 12:30:52 ERROR : DUMMYFILE.tar.xz.gpg: Failed to copy: multi-thread copy: failed to write chunk: failed to upload chunk 3 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. 2026/10/08 12:30:52 ERROR : Attempt 3/3 failed with 1 errors and: multi-thread copy: failed to write chunk: failed to upload chunk 3 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. 2026/10/08 12:30:52 INFO : Transferred: 992 KiB / 992 KiB, 100%, 141.713 KiB/s, ETA 0s Errors: 1 (retrying may help) Elapsed time: 7.1s 2026/10/08 12:30:52 NOTICE: Failed to copyto: multi-thread copy: failed to write chunk: failed to upload chunk 3 with 5242880 bytes: operation error S3: UploadPart, https response error StatusCode: 404, RequestID: , HostID: , api error NoSuchUpload: The specified multipart upload does not exist. error: target_file=DUMMYFILE.tar.xz.gpg key=e2/a6/e2a694ad2292534dbdc3d9055a971ae87529e4c55f46a794c88f4b68a5333aaa: rclone copyto --verbose DUMMYFILE.tar.xz.gpg DUMMYBUCKET:e2/a6/e2a694ad2292534dbdc3d9055a971ae87529e4c55f46a794c88f4b68a5333aaa
コマンドの内部ではrcloneを使用している。rcloneは、様々なクラウドストレージに対してファイルのコピーや削除を行える汎用のコマンドラインツールで、 storebin はその薄いラッパに過ぎない。その際、rcloneのアップロードのログも出力するようにしていたため、それと同じようなログが出ているだけかと思い、あまり気に止めていなかった。しかし、この態度がマズかった。どうやらこのログが出力されている時は、ファイルのアップロードに失敗しているようだ。ヤバい、ヤバすぎる。こんな致命的な欠陥がある状態で、そのまま使い続けていた。もしかすると、その問題を踏んだファイルはもう復元不可能かもしれない。
この手のツールは自作するべきじゃないなと思いつつ、それでもアイディアは悪くないと感じていたし、捨てるには忍びなかったので修正することにした。
storebin は、現在version2まで進んでいるが、今回の修正では破壊的な修正になるだろう。コマンド自体も storebin3 という名前に変更し、 storebin と併用できるようにする。
バケットを作り過ぎているという仮説
ログを見て、問題はバケットを作り過ぎてしまうということを疑いはじめた。少し用語を整理しておくと、R2のようなオブジェクトストレージでは、まず「バケット」という大きな入れ物を作り、その中に「キー」という名前を付けてファイル(オブジェクト)を置く。キーは e2/a6/ファイル名 のようにスラッシュ区切りで書けるので、見た目はフォルダ階層のようになるが、実際にはただの長い名前である。 storebin では、まず保存するファイルのハッシュ値(ファイルの中身から計算される64文字の固定長の値で、中身が1ビットでも違えば全く別の値になる)を計算し、そのハッシュ値の先頭4文字を2文字ずつ / で区切ってキーに含めている。この先頭の2文字はバケット名と解釈されてしまい、また当然ここはハッシュ値の一部でもあるので、バケット数が極端に増えてしまっているように見えた。実際にログには以下のような出力があった。
> rclone copyto --verbose DUMMYFILE.tar.xz.gpg DUMMYBUCKET:e2/a6/e2a694ad2292534dbdc3d9055a971ae87529e4c55f46a794c88f4b68a5333aaa 2026/10/08 12:30:45 INFO : S3 bucket e2 path a6: Bucket "e2" created with ACL ""
バケット名をハッシュ値の一部にしなければ直るものなのだろうか、そして、そうだとするとバケット名をどこから取ってくればよいかということだろう。保存するファイルから取得したり生成したりはできないため、設定ファイルである storebin.conf から取得することになるだろう。
[storebin]
rclone_config_label = 設定名
コードの中では次のように値を取得している。
conf = parse_config(config_file)
rclone_config_label = conf["storebin"]["rclone_config_label"]
parse_config() 内部では、 configparser を使い解析し configparser.ConfigParser オブジェクトを返している。 rclone_config_label の値自体は2箇所で使用している。1つめはここだ。
remote_location = f"{rclone_config_label}:{object_storage_key}"2つめはここで使用している。
cmd = f"rclone deletefile --verbose {rclone_config_label}:{object_storage_key}"
ここの : の記号の後ろの部分をobject_storage_keyをそのまま埋めるのではなく、プレフィックスを指定可能にしておくという感じが良さそうに思える。またバケット名も指定できるようした方が良さそうではある。設定ファイルが、どのバージョンを想定しているのかを判断できるようにもする必要がある。
従って次の属性を指定できるように設定ファイルを拡張する必要がある。
| 属性名 | 意味 |
|---|---|
| config_version | 設定ファイルのバージョン |
| object_storage_bucket_name | オブジェクトストレージのバケット名 |
| object_storage_key_prefix | オブジェクトストレージのキーに付ける接頭辞 |
この方針で拡張するのはどうだろうか。パッと見だと悪くはなさそうだ。この方針で実装を進めることにした。
修正しても同じエラーが出る
新しいコマンドを storebin3 という名前とすることや、設定のグループ名を storebin3 にするなど、細かな修正と共に put コマンドの修正をある程度進めた段階で、実際に動くかを試してみることにした。
$ ./storebin3 put DUMMY.tar.xz.gpg
ERROR : DUMMY.tar.xz.gpg: Failed to copy: multi-thread copy: failed to write chunk:
failed to upload chunk 4 with 5242880 bytes: ... api error NoSuchUpload
error: failed to put
oid : e2a694ad…fc4
size : 707455600
exit_code : 1
バケット名を直したのに同じエラーが発生する。どうやら、修正版でも動かないらしい。何かを間違えているようだ。仮説は疑わしくなった。
ただ、ひとつ良いこともあった。この時点で put は失敗を検知して終了コード1で止まるように直してあったので、エラーが出たこと自体を見逃さずに済んだ。終了コードというのは、コマンドが終わるときに呼び出し元へ返す小さな整数で、慣例として0が成功、それ以外が失敗を意味する。シェルスクリプトやMakefileは、この値だけを見て次に進むかどうかを決めるので、ここが正しくないと失敗が誰にも伝わらない。以前の storebin であれば、このエラーも無視して通過していただろう。ここから先は storebin3 を一旦離れて、rcloneを手で叩いて切り分けていくことにした。
並列処理を疑う
次に並列処理を疑うことにした。これまで使用してきた storebin でも常にエラーしてた訳ではなく、サイズの大きなファイルはエラーするようだった。rcloneはアップロードするファイルのサイズがある程度大きい場合、マルチパートアップロードという方式を使う。これはS3系のストレージが持つ仕組みで、まず「今からこのキーに分割アップロードを始める」と宣言してupload IDという受付番号をもらい、ファイルを5 MiBなどの塊(パート)に分けてその番号を添えて送り、最後に「全部送った」と締める、という流れになる。途中で止まると、送り終えたパートだけが残骸として残る。実際、マルチパートでのアップロードの残骸が、R2の管理画面上には取り残されていた。エラーメッセージの先頭には multi-thread copy とあり、ファイルサイズの674 MiBは --multi-thread-cutoff の既定値である256 MiBを超えていた。並列に投げている UploadPart が、まだupload IDを認識していないノードに当たっているのではないか、というのがこの時の読みだった。
そこで並列数を1にして直列でアップロードするようにオプションを指定し、rcloneを直接叩いてみることにした。
$ rclone copyto --multi-thread-streams 1 DUMMY.tar.xz.gpg 設定名:バケット名/storebin/e2/a6/e2a694ad….gpg ERROR : Failed to copy: failed to upload chunk 1 with 5242880 bytes: ... NoSuchUpload
multi-thread copy: の接頭辞が消え、チャンク1で落ちた。最初のパートで upload ID が無効となっており、並列処理やタイミングでの問題ではない。仮説がもう1つ消えて、マルチパートの開始そのものが成立していないという方向に絞られてきた。
設定の確認と修正
もはや何が何だか分からなくなっていたが、rcloneの設定を確認するため、以下のコマンドを実行した。
rclone config show 設定名
このコマンドはrcloneの設定ファイルを読み込み、その値を表示する。 endpoint というのは、rcloneがリクエストを送る先のURLのことで、どのサービスのどのアカウントに話しかけるかを決める。この出力では endpoint が次のように設定されていた。
endpoint = https://アカウントID.r2.cloudflarestorage.com/バケット名
endpoint の設定は本来バケット名は含むべきではないらしい。Cloudflare R2の管理画面の endpoint には、バケット名もキーとして含まれているのだが、それをそのままコピーしていたのがマズかったらしい。
そこで endpoint にはバケット名をパスとして指定しないように修正した。
rclone config update 設定名 endpoint https://アカウントID.r2.cloudflarestorage.comまたバケットのチェックもしないように設定した。
rclone config update 設定名 no_check_bucket truercloneは書き込みの前にバケットの存在確認を行い、無ければ作ろうとする。しかし使っているトークン(R2にアクセスするための鍵のようなもので、どのバケットに何をしてよいかの権限が付いている)にはバケットを作る権限を与えていないので、そもそも確認させない方が安全だ。
バケットの中を見る
ついでにrcloneでバケット一覧も確認できるか確認したが、それはトークンにその権限を与えていないため表示されなかった。
$ rclone lsd 設定名: ERROR : : error listing: operation error S3: ListBuckets, ... 403 ... AccessDenied
バケットの個数を外から数える手段は無いので、代わりにバケットの中身を見ることにした。
$ rclone lsf 設定名:バケット名/ --dirs-only 6c/ b5/ バケット名/
ハッシュの先頭2文字が、バケットではなくキーの一部になっている。それと、バケット名と同じ名前のディレクトリまである。
rclone lsf 設定名:バケット名/ -R --files-only 6c/ac/6cac55702fc908f1224683b801e7eef30e9205d3bcbd78d15ee7de4162f92422 6c ← 0バイト b5/42/b542cdf0da1a357038c8c3cd89e2b03248337c2acf78a79a1a5868cbcc82b1cd b5 ← 0バイト e2 ← 0バイト。配下にデータが無い バケット名/storebin/3c/8a/3c8ab2e8….png バケット名/storebin/42/aa/42aa988e….png バケット名/storebin/52/e0/52e00480….txt バケット名/storebin/b9/1d/b91d1640….storebin バケット名 ← 0バイト
末尾に / の付かない 6c や b5 といった、ディレクトリと同名の0バイトのオブジェクトが並んでいる。先に書いたとおりオブジェクトストレージにはフォルダという概念が無く、 6c/ はキーの先頭が 6c/ で始まるものをまとめて表示しているだけだ。だから 6c/ という表示と 6c という中身が空のオブジェクトは、別々に存在できる。どうにも痕跡のようなものに見える。そして e2 だけは配下が空だった。記事冒頭でアップロードしようとしたファイルは、やはり保存されていなかったということだ。
現在のバケットのサイズも確認してみた。
rclone size 設定名:バケット名/ Total objects: 10 Total size: 137.906 MiB (144604670 Byte)
何が起きていたのかはこの時点でも薄っすらとしか分かっていなかったが、ともかく辻褄が合っていないのは明らかだった。整理は後に回して、まず動くようにしてしまおう。
掃除して再試行
失敗したマルチパートアップロードの残骸が溜まっているはずなので、まずそれを掃除する。
rclone cleanup 設定名:バケット名
設定を修正した状態で再度 put を実行し、ファイルが保存されることを確認する。 echo $? は直前のコマンドの終了コードを表示するもので、ここで0が出れば成功したということになる。
$ ./storebin3 put DUMMY.tar.xz.gpg echo $?
0
できた。
サイズも確認しておこう。
$ rclone size 設定名:バケット名/ Total objects: 11 Total size: 812.588 MiB (852060270 Byte) 852060270 - 144604670 = 707455600
ファイルサイズとぴったり一致した。良さそうだ。
往復の確認をする。アップロードしたものを一度手元から消し、ストレージから取り直して、元のファイルと1バイトも違わないことを cmp で比べる。
rclone lsl 設定名:バケット名/storebin/e2/a6/e2a694ad….gpg 707455600 2026-10-08 07:14:06.648431258 e2a694ad….gpg
$ mv DUMMY.tar.xz.gpg DUMMY.tar.xz.gpg.orig ./storebin3 get DUMMY.tar.xz.gpg.storebin cmp DUMMY.tar.xz.gpg DUMMY.tar.xz.gpg.orig && echo "一致" 一致
ファイルの中身も一致した。
何が起きていたのか
動くようになったところで、改めて何が起きていたのかを整理しておく。
rcloneは endpoint の後ろに <バケット名>/<キー> を連結してリクエストを組み立てる。ところが endpoint に既にバケット名がパスとして含まれていたので、R2側には旧 storebin の場合 /バケット名/e2/a6/<oid> という形で届いていた。R2はURLのパスの最初の区切りをバケット名として読むので、rcloneが想定している構造とR2が解釈する構造が1段ずれていたことになる。住所でいえば、rcloneは「e2市 a6町 <oid>番地」のつもりで書いているのに、宛先の先頭に勝手に「バケット名県」が付いていて、R2側は「バケット名県の、e2市a6町<oid>番地」として受け取っていた、という状態だ。rcloneが e2 というバケットだと思っていたものは、R2から見ればバケット名のバケットの中にある e2/a6/<oid> というキーだった。先ほどの一覧で 6c/ や b5/ がキーとして並んでいたのは、このためだ。 storebin3 で書いた分にバケット名と同じ名前のディレクトリが付いていたのも同じ理屈で、設定から取ったバケット名がもう一段キーの先頭に積まれていた。
単一のPUTであれば、このずれがあっても成立する。パスが何であれ、そこにオブジェクトが置かれるだけだからだ。しかしマルチパートアップロードは CreateMultipartUpload と UploadPart で、バケット・キー・upload IDの3つ組が一致していなければならない。ここでずれが致命的になり、 NoSuchUpload として現れていたのだろう。だから一定サイズを超えるファイルだけが失敗し、小さいファイルは1年近く普通に通り続けていた。
Bucket "e2" created というログも嘘だった。rcloneはバケットを作ったつもりだったが、R2側では e2 という名前の0バイトのオブジェクトがPUTされていただけだ。バケットの中に残っていた 6c b5 e2 といった0バイトのオブジェクトは、その「バケットを作ったつもり」の化石だった。つまりバケットは1つも増えていなかった。当初の「バケットを作り過ぎている」という見立ては、完全に外れていたことになる。
失われたファイルについても、この一覧から確定できた。 6c と b5 には配下にデータがあり、 e2 にだけ無い。復元不可能かもしれないと恐れていたが、失われたのは記事冒頭のあの1件だけだった。
ただし、キー設計の欠陥そのものは実在していた。ハッシュの先頭2文字をバケット名の位置に置くという構造は、 endpoint が正しく設定されていれば本当にバケットを量産する。設定ミスが設計の欠陥を隠し、設計の欠陥が設定ミスの症状をバケットの問題に見せていた、という二重のねじれだった。バケット名とプレフィックスを設定ファイルから取るようにした修正は、原因の取り違えから始まったものだったが、結果としては必要な修正だった。
正しいrcloneの設定
rcloneでCloudflare R2を使うには、次のように設定する。
[my-rclone-name]
type = s3
provider = Cloudflare
endpoint = https://<account-id>.r2.cloudflarestorage.com
no_check_bucket = true
当初、 この endpoint には https://<account-id>.r2.cloudflarestorage.com/my-bucket-name というような値を指定していたが、これが間違いだった。 endpoint にパスを含めるべきではない。
本当の問題は失敗を検知していなかったこと
ここまで右往左往してきた。実装の目処も立ったし、動きも概ね良い。今回ここまで問題が発覚しなかったことの理由の一つは、戻り値をちゃんと見ていなかったからだろう。実際 storebin (version 1とversion 2)は、rcloneの戻り値を適切に見ておらず、スクリプトの返却値として戻すだけだったし、一部に無視していた所もあった。
適切にコマンドの戻り値をチェックし、期待した挙動の場合には静かに、期待した挙動になっていない場合には盛大にエラーを出力するようにしていれば、1年近く気づかないなんてことにはならなかっただろう。
この観点での反省点を、少しまとめておこう。
os.systemの戻り値を終了コードだと誤解していた
旧バージョンでは、 rcloneを os.system() で呼び出した戻り値を、そのまま sys.exit() に渡していた。 os.system() はPythonからシェルのコマンドを1行実行する関数で、 sys.exit() はPythonのスクリプト自身の終了コードを決めて終了する関数だ。つまり「rcloneの結果をそのまま自分の結果として返す」つもりだった。しかし、 os.system() が返すのは終了コードそのものではなく、OSが子プロセスの終わり方を1つの整数に詰め込んだ waitpid のステータスという値で、終了コード1のときは256が返される。
rc = 0= の比較は偶然正しく動くが、 sys.exit(rc) は壊れる。 sys.exit(256) は下位8ビットが取られて0になるので、失敗が成功として伝播していた。
os.waitstatus_to_exitcode() を通すだけで、この問題は解消できる。この関数は終了コードとシグナル情報が1つの整数に編み込まれたものを解く役目を持つ。
まあ、 os.system() ではなく subprocess.run() を使えという話もあるのだが、それは使い勝手とデバッグのし易さの観点で、そのままとした。
失敗しても終了コードが0だった
put は失敗時に print するだけで sys.exit() しておらず、呼び出し側からは成功に見えていた。記事冒頭の長大なエラー出力も、シェルや Makefile からは成功として扱われていたはずだ。 delete にいたっては、戻り値を見ておらず、削除に失敗してもポインタファイルを .deleted にリネームしていた。もう、むちゃくちゃだった。ちゃんと実装しようという一言に尽きる。
rcloneが成功を申告して何もしないことがある
S3では存在しないキーを指定しても、エラーではなく「空のプレフィックスの一覧」として扱われる。そのため rclone copyto は存在しないオブジェクトを指定されても、空のディレクトリをコピーしたと解釈して終了コード0を返す。実際、オブジェクトが消えた後のポインタファイルで get を実行したところ、何のエラーも出ずに成功し、しかしファイルは1つも作られていなかった。
戻り値を見るようにしただけでは、これは防げない。rcloneは嘘をついているわけではなく、頼まれたことは成立したと言っているだけだ。対処としては、事前に「あるか?」を問い合わせるのではなく、事後に「できたか?」を検査するしかない。 get の後にファイルの存在を確認するようにした。
同じ理由で、 put にあった存在チェックは削除した。 rclone copyto は同一内容であれば転送をスキップしてくれるので、Python側で再実装していた判定は冗長で、しかもネットワークエラーを「存在しない」と誤判定する原因になっていた。
ハッシュの照合はstorebin3しかできない
rcloneは転送後に、ストレージ側が持っているETagという値と手元のファイルのハッシュを比べて、内容が壊れていないか確認しようとする。ところがR2ではマルチパートでアップロードしたオブジェクトのETagがMD5ではないので、 rclone はハッシュを検証できず、サイズしか見られない。 oid については内容のsha256そのものなので、ダウンロード後に照合すれば「サイズは合っているが内容が壊れている」という状態を検出できる。今回の実装で get の事後検査は3段(終了コード、ファイルの存在、sha256 の照合)となり、処理が強化された。これは良かった点だろう。
rstripでファイル名が壊れていた
本当にお粗末な話だが、Pythonの rstrip() は「この文字列を末尾から取り除く」関数ではない。引数を「取り除く文字の一覧」として受け取り、末尾からその一覧に含まれる文字を、含まれない文字に当たるまで1文字ずつ削り続ける。だから pointer_file.rstrip(".storebin") は、 .storebin という文字列ではなく文字集合 {. s t o r e b i n} を末尾から剥がす処理になる。つまり、 notes.storebin というファイル名は空文字列になり、 report.storebin は rep になる。いろいろと終わっている。
扱っていたファイルが .tar.xz.gpg のように集合外の文字で終わっていたため、たまたま正しく動いていて露見しなかっただけであり、 report.storebin を get すると rep という名前で復元され、 rclone も storebin3 も成功を返す。
失敗せずに間違った結果を出す、一番たちの悪い壊れ方だ。今回の修正で removesuffix() に置き換えたため、この問題も解消された。
しかし、今の今まで rstrip() の挙動に対して間違った認識を持っていたのだが、これまでの人生は大丈夫だったのだろうか。本当に怪しすぎる。もっとちゃんと勉強しなければならない。
ポインタファイルの解析が緩かった
ポインタファイルから oid を読み取るのに正規表現を使っているのだが、 [0-9a-f]+ というパターンは「16進数の文字が1文字以上」という意味で、長さを検証しない。oidが途中で切れている場合、途中で切れた oid がそのまま通り、結果として404として現れる。ポインタが壊れているのか、オブジェクトが消えたのかが区別できていなかった。
re.search は最初のマッチを黙って採用するので、Gitのマージコンフリクト(2人が同じファイルを別々に変更したときにGitが両方の内容を並べて残す状態)のマーカーが残ったポインタファイルで、片方の内容を黙って選んでしまうということも考えられる。
今回の修正では、=[0-9a-f]{64}= に固定し、 findall でマッチが1件だけであることも検証した。ハッシュ関数が64文字を出すことと、64文字が書かれていることの確認は別の話であり、ポインタファイルは外部入力なので境界で検証するようにした。
設計を整理する
それでは storebin3 の設計の考え方を整理しておく。
値と同一性を分ける
オブジェクトストレージには mv が無い。ファイルの名前を変えたり場所を移したりするには、新しいキーにコピーしてから古いキーを消すしかなく、数GBのファイルだとそれだけで一仕事になる。だから名前空間を Git 側に外出しして、ポインタファイルの移動で mv を代行している。ポインタファイルは数百バイトのテキストなので、 git mv で好きに動かせる。
オブジェクトストレージ = 値(不変、内容のハッシュで名指す)、ポインタファイル = 同一性(名前と場所、履歴は Git が持つ)という位置付けにしている。中身が同じファイルは必ず同じキーになるので、同じファイルを2回保存しても実体は1つしか置かれない。これをコンテンツアドレス方式と呼ぶ。
この分離があるので、元のファイル名をキーに入れられない。入れると put した瞬間に名前が凍結され、ポインタ側の名前と乖離していく。これを避けた形となっている。
拡張子は値の属性、ファイル名は同一性の属性
拡張子は内容の型なので値の側にある。内容が不変なら型も不変なので、キーに含めてよい。
キーの形は <prefix>/<oid[:2]>/<oid[2:4]>/<oid><拡張子> とする。=<oid>.png= を選んだのは、R2 のダッシュボードの一覧でそのまま型が見えるからである。 <oid>/data.png 形式だとオブジェクトごとにフォルダになり、一覧では型が一切見えなくなる。
storetmp が document.png だったのは、公開 URL でダウンロードしたときのファイル名を綺麗にするためだ。 storebin は配信しないので、その要求が存在しない。
拡張子はアドレスの一部になるので凍結される。変えたい場合は次の手順で合成できる。
getmvputdelete
そのためrename用の専用コマンドは作らないことにした。
拡張子は [A-Za-z0-9]+ にマッチするものだけ採用し、それ以外は拡張子なしとして扱う。非 ASCII を弾くのでキーが常に ASCII に収まり、macOS と Linux で日本語の表現方法が異なる(見た目は同じ「が」でも、内部的には別のバイト列として保存される)ために同じ内容が別キーになってしまう問題も消える。
コマンドの世代を名前で分ける
コマンドの挙動の破壊的変更は、変更ではなく同じ名前を付けられた別物である。だからコマンド名を storebin3 とし、設定ファイルのセクションを [storebin3] にした。セクション名が世代を表すので、当初考えていた config_version は冗長になり廃止した。情報源が2つあると整合しない状態が表現可能になる。
旧 storebin が新しい設定ファイルを読むと KeyError で落ちるため、世代混在での混乱を防げるようにしている。
ポインタファイル側には storebin_version を追加した。これは旧世代のポインタには存在しないので、 storebin3 が必ず弾くことができる。
互換が無いなら全ての操作を失敗させる方が単純で安全であり、当初書いていた「 storebin と併用できるようにする」という方針は撤回した。
静かに動き、壊れたら騒ぐ
旧 storebin では、 rclone のコマンドに–verboseを付け、その出力をそのまま出すようにしていた。しかし、その結果として出力が多くなり、正常終了と異常終了の違いに気付くことができなかった。
やはり、正しい時には静かに動き、壊れたら盛大に騒ぐという昔ながらの方針に従うほうが良いということなのだろう。 storebin3 については、そのような出力になるように実装した。
まず、成功時は完全に無音にした。 --verbose を外し、実行コマンドの表示もやめた。失敗時は標準エラー出力に、 oid ・キー・リモート位置・実行したコマンド・終了コードを全部出すようにした。透明性が価値を持つのは失敗したときだけ。成功時に見せても何もすることがない。
デバッグ用の出力として STOREBIN_VERBOSE を立てたときだけ、実行の流れが見える。デバッグ用の出力を有効にする場合には、コマンドをそのまま見せるので、コピペして再実行できる。 os.system を残した理由がここで効いてくる。
参照カウントが無いという性質
storebin3 は、コンテンツアドレス方式で参照カウント(そのデータを何箇所から使っているかを数えておく仕組み)を持たないので、 delete は値そのものを破壊する。同じ oid と拡張子を持つ別のポインタがあれば、それが壊れる。実際に同一のオブジェクトを指す3つのポインタファイルが手元に存在していた。
ポインタファイルの cp が仮想的なコピーになるという設計の利点と、 delete が危険であるという性質は、同じコインの裏表だ。同一オブジェクトの共有自体は異常ではなく、重複排除が効いているだけなので、後に説明する verify コマンドでは報告はするが異常として数えないようにした。 delete を打つ時は気を付けなければならない。
その他の実装方針
os.system を残した。1行で済み、 rclone の出力が端末に直結し、実行した文字列をそのまま見せられる。戻り値の解読と shlex.quote を使う必要があるというのが代償だろう。せめて、1箇所に閉じ込めるようにした。
シェルは空白で単語を区切り、 $ や & のような記号を特別扱いするので、ファイル名をそのままコマンドに埋め込むと my photo.png が2つの引数に割れたりする。これを防ぐのが shlex.quote で、文字列を引用符で包んで「これは1つの単語で、中の記号は解釈しないで」とシェルに伝える。ただし何でも包めばよいわけではなく、データはquoteし、構文はquoteしない。ファイル名は shlex.quote で包み、 rclone のフラグは quote せずシェルに単語として分割させる。
キーの組み立てとポインタファイルの解析を、それぞれスクリプト内の1箇所に集約した。 storetmp には put と delete でキーの形が違うというバグが実在していた。組み立てが複製されていることが原因で、同じ構造のバグを storebin3 でも一度踏んだ。
ポインタファイルは frozen な dataclass にしたが、メソッドは持たせず自由関数として扱う。レコードと自由関数という形、ちょっとだけclojure風味の実装にした。
hashlib.file_digest() に替えて、巨大ファイルをメモリに載せないようにした。大きなファイルを扱う道具なのに全体を read() していた。まあこれは、普通にバグだったな。
検出する手段
これまで get ・ put ・ delete を用意していたが、ポインタファイルや環境自体の検証のための手段を整えた。
verify
既にある壊れた状態を見つけるためのサブコマンドを追加した。ポインタファイルを複数渡して一括検査する。検査項目は、書式と世代、リモートにオブジェクトが存在するか、サイズが一致するか、同じオブジェクトを指すポインタが複数ないかを確認する。
問題のあるものだけ1行ずつ出力し、正常なものには何も言わない。1件でもあれば終了コード1。見つかったものだけを表示して、見つからなければ無言で終わる grep と同じ振る舞いとなる。もしかしたらEmacsの compilation-mode と相性がいいかもしれない。=get= との本質的な違いは、1件の失敗で中断せず最後まで検査することだ。
存在確認は終了コードだけでは判定できないので、 rclone lsf --format s の出力を読む必要がある。ここだけ subprocess を使うことにした。これは後々修正するかもしれないが、現時点ではここまでの実装にした。
実際に、宙に浮いたポインタファイルが8個ある状態で試したら、7件が missing として検出され、オブジェクトが実在する1件だけが無言になった。問題なさそうだ。
selftest
storebin3 の実装の出発点は設定ミスによるバグ誘発だったため、設定をあらかじめ確認するコマンドとして selftest を実装した。これは設定の内容を検証するのではなく、経路が機能することを検証する。
設定の正しさを検査しようとすると、rclone の実装に依存し、既知の間違いの一覧を持つことになって際限がない。小さいファイルの往復では今回のバグを検出できない。エンドポイントがずれていても put と get が同じ計算で同じキーを使うので、往復は一致してしまう。だから multipart を必ず通す必要がある。16 MiB のランダムデータに --s3-upload-cutoff 5Mi --s3-chunk-size 5Mi --multi-thread-cutoff 5Mi を与えると4パートになり、数秒で今回と同じ経路を踏める。
自分自身を別のプロセスとして呼び出し(つまり storebin3 の中から storebin3 put ... というコマンドを実行する)、 put → verify → get → delete を順に実行する。各サブコマンドのロジックを複製しない。内容がランダムなので oid は毎回一意になり、既存のオブジェクトに影響しない。失敗したときは調査の材料を消さないために後始末をしないようにした。 rclone に追加フラグを渡す仕掛け( STOREBIN_RCLONE_FLAGS )は、環境固有の回避策が必要になったときの逃げ道にもなる。
3つの機能がそれぞれ別の時点を守る
失敗検知は常時働いて壊れた状態を作らないようにし、 selftest は設定を変えた直後に環境が機能していることを確認し、 verify は既にある壊れた状態を見つける。3つの機能が、それぞれ別の時点を守る形になった。
まとめ
さて、ここまで長々と書いてきたが、今回の話を整理しておこう。
出発点は「ファイルのアップロードに失敗していたのに、1年近く気づかなかった」ということだった。最初は、ハッシュ値の先頭2文字がバケット名として解釈されてバケットを作り過ぎているのが原因だと考えた。しかしその修正を進めて実際に動かしてみると、同じエラーが出た。rcloneを手で叩いて切り分けていった結果、本当の原因はrcloneの設定の endpoint にバケット名が含まれていたことだと分かった。これによってrcloneの考える構造とR2の解釈が1段ずれ、小さいファイルは通るのにマルチパートアップロードだけが失敗する、という状態になっていた。バケットは1つも増えておらず、「作った」というログは嘘だった。失われたファイルも、恐れていたほどではなく1件だけだった。
ただし、当初の見立てが外れていたからといって、やった修正が無駄だったわけではない。ハッシュ値をバケット名の位置に置くキーの設計は確かに欠陥で、設定が正しければ本当にバケットを量産していた。設定ミスがその欠陥を隠し、欠陥の症状が設定ミスをバケットの問題に見せていた。2つの問題が互いを隠し合っていたということだ。
そして、この2つのどちらよりも重かったのが、失敗を検知していなかったことだ。 os.system() の戻り値を終了コードと誤解し、失敗しても sys.exit() せず、rcloneの出力をそのまま流していたために、正常と異常の区別がつかなくなっていた。設定ミスも設計の欠陥も、失敗を検知できていれば大きなファイルを初めてアップロードした時点で分かっていたはずのものだ。1年近くを無駄にしたのは、この1点に尽きる。
storebin3 では、この順に手を入れた。戻り値を正しく読み、全ての経路で失敗したら終了コードを返す。rcloneが成功を申告しても信用せず、ファイルが本当にできたか、中身のハッシュが一致するかを事後に検査する。成功したときは何も言わず、失敗したときは原因を追うのに必要な情報を全部出す。その上で、壊れた状態を後から見つける verify と、設定を変えたときに経路が機能することを確かめる selftest を足した。 selftest は小さいファイルでは今回のバグを検出できないので、マルチパートを強制的に通すようにしてある。
この手のツールは自作すべきではない、と最初に書いた。今回の経験で、その理由が少しはっきりした。壊れていたのは、ポインタファイルとオブジェクトストレージを組み合わせるという発想そのものではなく、それが本当に動いていることを確かめる手続きが無かったことだ。動いているように見えることと、動いていることは別である。自作するなら、その2つを区別する手段まで含めて作らなければならない。それが今回の教訓だ。
スクリプトを貼っておく。
storebin3
#! /usr/bin/env python3
import configparser
import hashlib
import os
import re
import shlex
import shutil
import subprocess
import sys
from collections.abc import Mapping
from dataclasses import dataclass
__author__ = "TakesxiSximada"
__version__ = "3"
POINTER_FILE_FORMAT_VERSION = "3"
pointer_file_format = """# LFS POINTER
version https://git-lfs.github.com/spec/v1
oid {pointer.hash_type}:{pointer.oid}
size {pointer.size}
# storebin3 customize
# NOTE: extension is a part of the object storage key. DO NOT EDIT.
storebin_version {pointer_file_format_version}
"""
@dataclass(frozen=True)
class StorebinPointer:
hash_type: str
oid: str
size: int
extension: str = ""
class StorebinPointerParseError(Exception):
pass
def build_pointer_file_content(pointer: StorebinPointer) -> str:
content = pointer_file_format.format(
pointer=pointer,
pointer_file_format_version=POINTER_FILE_FORMAT_VERSION,
)
if pointer.extension:
content += f"extension {pointer.extension}\n"
return content
def parse_pointer_file_content(data: str) -> StorebinPointer:
versions = re.findall(r"^storebin_version (\d+)$", data, re.M)
if versions != [POINTER_FILE_FORMAT_VERSION]:
raise StorebinPointerParseError("incompatible pointer file")
oids = re.findall(r"^oid ([a-z0-9]+):([0-9a-f]{64})$", data, re.M)
if len(oids) != 1 or oids[0][0] != "sha256":
raise StorebinPointerParseError("bad oid")
sizes = re.findall(r"^size (\d+)$", data, re.M)
if len(sizes) != 1:
raise StorebinPointerParseError("bad size")
extension_lines = re.findall(r"^extension .*$", data, re.M)
extensions = re.findall(r"^extension (\.[A-Za-z0-9]+)$", data, re.M)
if len(extension_lines) != len(extensions) or len(extensions) > 1:
raise StorebinPointerParseError("bad extension")
return StorebinPointer(
hash_type=oids[0][0],
oid=oids[0][1],
size=int(sizes[0]),
extension=extensions[0] if extensions else "",
)
def traverse_config_file(path):
cur_dir = os.path.abspath(path)
for i in range(100):
conf_path = os.path.join(cur_dir, "storebin.conf")
if os.path.exists(conf_path):
return conf_path
cur_dir = os.path.dirname(cur_dir)
def parse_config(path) -> configparser.ConfigParser:
conf = configparser.ConfigParser()
conf.read(path)
return conf
def validate_config(conf: configparser.ConfigParser) -> configparser.ConfigParser:
# 必須キーの存在確認。無ければKeyErrorを送出
conf["storebin3"]["rclone_config_label"]
conf["storebin3"]["object_storage_bucket_name"]
conf["storebin3"]["object_storage_key_prefix"]
return conf
def build_object_storage_key(conf: configparser.ConfigParser, oid: str, extension: str) -> str:
prefix = conf["storebin3"]["object_storage_key_prefix"]
return f"{prefix}/{oid[:2]}/{oid[2:4]}/{oid}{extension}"
def build_remote_location(conf: configparser.ConfigParser, object_storage_key: str) -> str:
label = conf["storebin3"]["rclone_config_label"]
bucket = conf["storebin3"]["object_storage_bucket_name"]
return f"{label}:{bucket}/{object_storage_key}"
def os_system(line) -> int:
if os.environ.get("STOREBIN_VERBOSE"):
print("> ", line, file=sys.stderr)
return os.waitstatus_to_exitcode(os.system(line))
def get_rclone_flags(environ: Mapping[str, str]) -> str:
return environ.get("STOREBIN_RCLONE_FLAGS", "")
def print_error(message: str, **fields) -> None:
print(f"error: {message}", file=sys.stderr)
width = max((len(key) for key in fields), default=0)
for key, value in fields.items():
print(f" {key.ljust(width)} : {value}", file=sys.stderr)
def rclone_object_size(remote_location: str) -> int | None:
"""リモートのオブジェクトのサイズを返す。存在しなければ None。"""
argv = [
"rclone",
"lsf",
*shlex.split(get_rclone_flags(os.environ)),
"--format",
"s",
remote_location,
]
if os.environ.get("STOREBIN_VERBOSE"):
print(">", " ".join(argv), file=sys.stderr)
proc = subprocess.run(argv, capture_output=True, text=True)
if proc.returncode in (3, 4): # directory not found / file not found
return None
if proc.returncode != 0:
print_error(
"rclone lsf failed",
remote_location=remote_location,
exit_code=proc.returncode,
stderr=proc.stderr.strip(),
)
sys.exit(1)
sizes = proc.stdout.split()
if not sizes: # 空の出力 = 存在しない
return None
if len(sizes) != 1: # 単一オブジェクトを指定したのに複数返る = 想定外
print_error("unexpected lsf output", remote_location=remote_location,
output=proc.stdout.strip())
sys.exit(1)
return int(sizes[0])
sub_command = sys.argv[1]
if "put" == sub_command:
target_file = sys.argv[2]
pointer_file = f"{target_file}.storebin"
if os.path.exists(pointer_file):
print("already exists: ", pointer_file, file=sys.stderr)
sys.exit(1)
with open(target_file, "rb") as fp:
hash_value_obj = hashlib.file_digest(fp, "sha256")
oid = hash_value_obj.hexdigest()
file_size = os.path.getsize(target_file)
# 拡張子はそのまま使う
extension = os.path.splitext(target_file)[1]
if not re.fullmatch(r"\.[A-Za-z0-9]+", extension):
extension = "" # ただし半角英数じゃない拡張子は無視
config_file = traverse_config_file(target_file)
if not config_file:
print("no config file: storebin.conf", file=sys.stderr)
sys.exit(1)
conf = validate_config(parse_config(config_file))
object_storage_key = build_object_storage_key(conf, oid, extension)
remote_location = build_remote_location(conf, object_storage_key)
pointer = StorebinPointer(
hash_type="sha256",
oid=oid,
size=file_size,
extension=extension,
)
pointer_file_content = build_pointer_file_content(pointer)
cmd = f"rclone copyto {get_rclone_flags(os.environ)} {shlex.quote(target_file)} {shlex.quote(remote_location)}"
rc = os_system(cmd)
if rc != 0:
print_error(
"failed to put",
target_file=target_file,
pointer_file=pointer_file,
oid=oid,
size=file_size,
extension=extension or "(none)",
object_storage_key=object_storage_key,
remote_location=remote_location,
command=cmd,
exit_code=rc,
)
sys.exit(rc)
with open(pointer_file, "w+") as fp:
fp.write(pointer_file_content)
elif "get" == sub_command:
pointer_file = sys.argv[2]
target_file = pointer_file.removesuffix(".storebin")
if os.path.exists(target_file):
print("already exists: ", target_file, file=sys.stderr)
sys.exit(1)
config_file = traverse_config_file(target_file)
if not config_file:
print("no config file: storebin.conf", file=sys.stderr)
sys.exit(1)
conf = validate_config(parse_config(config_file))
try:
with open(pointer_file) as fp:
pointer = parse_pointer_file_content(fp.read())
except StorebinPointerParseError as err:
print_error("failed to parse pointer file", pointer_file=pointer_file, reason=err)
sys.exit(1)
object_storage_key = build_object_storage_key(conf, pointer.oid, pointer.extension)
remote_location = build_remote_location(conf, object_storage_key)
cmd = f"rclone copyto {get_rclone_flags(os.environ)} --immutable {shlex.quote(remote_location)} {shlex.quote(target_file)}"
rc = os_system(cmd)
if rc != 0:
print_error(
"failed to get",
pointer_file=pointer_file,
target_file=target_file,
oid=pointer.oid,
size=pointer.size,
extension=pointer.extension or "(none)",
object_storage_key=object_storage_key,
remote_location=remote_location,
command=cmd,
exit_code=rc,
)
sys.exit(rc)
if not os.path.isfile(target_file):
print_error(
"file not transferred",
pointer_file=pointer_file,
target_file=target_file,
oid=pointer.oid,
object_storage_key=object_storage_key,
remote_location=remote_location,
command=cmd,
exit_code=rc,
)
sys.exit(1)
with open(target_file, "rb") as fp: # ファイルちゃんとダウンロードされて作られたか検証する
actual_oid = hashlib.file_digest(fp, "sha256").hexdigest()
if actual_oid != pointer.oid:
print_error(
"checksum mismatch",
pointer_file=pointer_file,
target_file=target_file,
expected=pointer.oid,
actual=actual_oid,
)
sys.exit(1)
elif "delete" == sub_command:
pointer_file = sys.argv[2]
target_file = pointer_file.removesuffix(".storebin")
config_file = traverse_config_file(target_file)
if not config_file:
print("no config file: storebin.conf", file=sys.stderr)
sys.exit(1)
conf = validate_config(parse_config(config_file))
try:
with open(pointer_file) as fp:
pointer = parse_pointer_file_content(fp.read())
except StorebinPointerParseError as err:
print_error("failed to parse pointer file", pointer_file=pointer_file, reason=err)
sys.exit(1)
object_storage_key = build_object_storage_key(conf, pointer.oid, pointer.extension)
remote_location = build_remote_location(conf, object_storage_key)
cmd = f"rclone deletefile {get_rclone_flags(os.environ)} {shlex.quote(remote_location)}"
rc = os_system(cmd)
if rc != 0:
print_error(
"failed to delete",
pointer_file=pointer_file,
oid=pointer.oid,
size=pointer.size,
extension=pointer.extension or "(none)",
object_storage_key=object_storage_key,
remote_location=remote_location,
command=cmd,
exit_code=rc,
)
sys.exit(rc)
shutil.move(pointer_file, pointer_file + ".deleted")
elif "verify" == sub_command:
pointer_files = sys.argv[2:]
if not pointer_files:
print("no pointer file", file=sys.stderr)
sys.exit(1)
problem_count = 0
seen = {}
for pointer_file in pointer_files:
if not pointer_file.endswith(".storebin"):
print(f"not a pointer file: {pointer_file}")
problem_count += 1
continue
config_file = traverse_config_file(pointer_file)
if not config_file:
print(f"no config file: {pointer_file}", file=sys.stderr)
problem_count += 1
continue
try:
conf = validate_config(parse_config(config_file))
except Exception:
print(f"bad config file: {config_file}", file=sys.stderr)
problem_count += 1
continue
try:
with open(pointer_file) as fp:
pointer = parse_pointer_file_content(fp.read())
except StorebinPointerParseError as err:
print(f"parse error: {pointer_file}: {err}")
problem_count += 1
continue
object_storage_key = build_object_storage_key(
conf, pointer.oid, pointer.extension)
remote_location = build_remote_location(conf, object_storage_key)
seen.setdefault(remote_location, []).append(pointer_file)
actual_size = rclone_object_size(remote_location)
if actual_size is None:
print(f"missing: {pointer_file}: {object_storage_key}")
problem_count += 1
continue
if actual_size != pointer.size:
print(f"size mismatch: {pointer_file}: expected={pointer.size} actual={actual_size}")
problem_count += 1
for remote_location, files in seen.items():
if len(files) > 1:
print(f"shared object: {', '.join(files)}")
problem_count += 1
if problem_count:
sys.exit(1)
elif "selftest" == sub_command:
test_file = f"storebin3-selftest-{os.getpid()}.bin"
pointer_file = f"{test_file}.storebin"
deleted_pointer_file = f"{pointer_file}.deleted"
# 内容が毎回異なるので oid が一意になり、既存のオブジェクトに影響しない
with open(test_file, "wb") as fp:
for _ in range(16):
fp.write(os.urandom(1024 * 1024))
# multipart を必ず通す(5MiB チャンク × 4パート)
os.environ["STOREBIN_RCLONE_FLAGS"] = (
"--s3-upload-cutoff 5Mi --s3-chunk-size 5Mi --multi-thread-cutoff 5Mi")
self_file = shlex.quote(sys.argv[0])
steps = [
("put", f"{self_file} put {shlex.quote(test_file)}"),
("verify", f"{self_file} verify {shlex.quote(pointer_file)}"),
("remove local file", f"rm -f {shlex.quote(test_file)}"),
("get", f"{self_file} get {shlex.quote(pointer_file)}"),
("delete", f"{self_file} delete {shlex.quote(pointer_file)}"),
]
for step, cmd in steps:
rc = os_system(cmd)
if rc != 0:
print_error(
"selftest failed",
step=step,
test_file=test_file,
pointer_file=pointer_file,
command=cmd,
exit_code=rc,
note="not cleaned up for investigation",
)
sys.exit(1)
os.remove(test_file)
os.remove(deleted_pointer_file)
else:
print("not support subcommand")
sys.exit(1)