FileUpload時にmove file errorで失敗する

NorihisaNakai commented 3 years ago

環境

ここかどうか悩んだのですが、以下の環境です。 docker-mirakurun-epgstationでの動作。

l3tnun/epgstation                        master-debian         a3552ad8a2d2   25 hours ago    775MB
mariadb                                  10.4                  b05589e7e943   5 days ago      398MB
<none>                                   <none>                6c5899511db2   10 days ago     1.1GB
<none>                                   <none>                c9945a478181   10 days ago     766MB
<none>                                   <none>                ab351e5ec2dd   10 days ago     1.29GB
l3tnun/epgstation                        <none>                ea025092deed   10 days ago     775MB
mariadb                                  <none>                37406e27ca2c   3 weeks ago     394MB
node                                     14.15.4-buster-slim   64f205b2c695   3 months ago    180MB
node                                     14.15.4-buster        e6ef78e097ed   3 months ago    911MB
chinachu/mirakurun                       latest                efddcfe01012   4 months ago    764MB

Architecture: x64 ファイルを保存しているドライブは8Tx2のRAID1をbcacheで組んでいます。

Issue

https://github.com/l3tnun/EPGStation/blob/master/src/model/operator/recorded/RecordedManageModel.ts#L296 ここでのawait FileUtil.rename(option.filePath, filePath);は実施されていて、ファイル自体は移動している。 (recorded/sample.tsの存在は確認) が、例外を出してcatchされた中で今度はerrを出力せずにmoveを試しているのでrename時のエラーがわからないのと、移動しているのにmoveしようとして今度はENOENTを出しているように見える。

[2021-05-19T22:35:49.424] [INFO] system - move file /app/data/upload/file-17984d495d916b2d -> /app/recorded/sample.ts
[2021-05-19T22:35:54.491] [INFO] system - delete recorded: 27
[2021-05-19T22:35:54.501] [INFO] system - successful delete recorded: 27
[2021-05-19T22:35:54.902] [ERROR] system - move file error
[2021-05-19T22:35:54.902] [ERROR] system - [Error: ENOENT: no such file or directory, unlink '/app/data/upload/file-17984d495d916b2d'] {
  errno: -2,
  code: 'ENOENT',
  syscall: 'unlink',
  path: '/app/data/upload/file-17984d495d916b2d'
}

週末の時間のあるときにdocker buildして試してみようかともいますが、まとまった時間を取るのに少し掛かりそうなので、取り急ぎご報告まで。

l3tnun commented 3 years ago

詳しく見てみます。

l3tnun commented 3 years ago

epgstation は web UI 側の Service と録画を管理する Operator に分かれているのですが、 file を upload する際に Service から Operator に IPC 通信で upload file の登録を依頼する際に、意図せずタイムアウトが発生しエラーとなっていたようです。

Operator にてファイルコピー中であっても、 Service からみると upload に失敗していたため、upload 失敗の後処理として番組情報の削除が行われました。このとき /app/data/upload/file-* が削除されるため、FileUtil.move() の最後の unlink でエラーがエラーとなりログ上に残ったようです。

IPC 通信時のタイムアウト時間を適切な長さに設定し、問題が発生しないように修正しました。修正完了したので閉じます。

ログを追っていくと以下のような感じです。

これが番組情報追加のログ

[2021-05-19T22:35:49.413] [INFO] system - add uploaded file: 27

ファイル upload 後のファイル移動開始のログ

[2021-05-19T22:35:49.424] [INFO] system - move file /app/data/upload/file-17984d495d916b2d -> /app/recorded/sample.ts

IPC でタイムアウトが発生し、番組情報が削除された際のログ (この時に /app/data/upload/ffile-17984d495d916b2d を削除)

[2021-05-19T22:35:54.491] [INFO] system - delete recorded: 27
[2021-05-19T22:35:54.501] [INFO] system - successful delete recorded: 27

/app/data/upload/ffile-17984d495d916b2d が無いため、ファイル移動(コピーと削除)の削除に失敗

[2021-05-19T22:35:54.902] [ERROR] system - move file error
[2021-05-19T22:35:54.902] [ERROR] system - [Error: ENOENT: no such file or directory, unlink '/app/data/upload/file-17984d495d916b2d'] {
  errno: -2,
  code: 'ENOENT',
  syscall: 'unlink',
  path: '/app/data/upload/file-17984d495d916b2d'
}

NorihisaNakai commented 3 years ago

ありがとうございました。こちらでも動作を確認いたしました。

l3tnun / EPGStation

FileUpload時にmove file errorで失敗する #480

環境

Issue