解决接口出现 504 gateway time-out 的问题

今天测试之前写的一个 python 批处理脚本的时候，发现批处理中的某个请求总是提示网络错误。查看错误信息，发现是 504 gateway time-out。

robot.action.Panorama.UploadPanoramaJsonRobot.run输出数据:
{'manage': <task.TaskManager.TaskManager object at 0x000001E7BC7B22D0>, 'data': <entity.RobotDataEntity.RobotDataEntity object at 0x000001E7A61546D0>}

RequestUtil: post https://test.api.sollado.com/api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source {"source_list": ["pbDMXmwq9"]}
RequestUtil: url - https://test.api.sollado.com/api/v1/materials
RequestUtil: status_code - 504
RequestUtil:text - <html>
<head><title>504 Gateway Time-out</title></head>
<body>
<center><h1>504 Gateway Time-out</h1></center>
<hr><center>nginx/1.18.0 (Ubuntu)</center>
</body>
</html>

发生异常 网络错误
Traceback (most recent call last):
  File "\\wsl.localhost\Ubuntu-22.04\home\bboyyue\code\python\request\RequestUtil.py", line 68, in post
    return self.response(response)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "\\wsl.localhost\Ubuntu-22.04\home\bboyyue\code\python\request\RequestUtil.py", line 128, in response
    raise Exception('网络错误')
Exception: 网络错误
robot.action.ClearOutdatedOutputFileRobot.run输出数据:
{'manage': <task.TaskManager.TaskManager object at 0x000001E7BC7B22D0>, 'data': <entity.RobotDataEntity.RobotDataEntity object at 0x000001E7A61546D0>}
RequestUtil: post https://test.api.sollado.com/api/v1/materials/PYljQ9jaM/files {"fileList": ["vYDpbNjR7"], "purpose": "PanoramaXml", "source_id": "pbDMXmwq9"}
RequestUtil: url - https://test.api.sollado.com/api/v1/materials
RequestUtil: status_code - 200

出现这个问题，显然是 php 脚本运行超时了。按照经验，通常是慢查询导致的。然后就查看 SQL 日志，没有发现特别耗时的查询。(原谅我，这里确实有点长，但是这里只有一个 /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source 请求，不是我故意复制了很长。他是批处理操作，涉及到了三个数据表，然后三个数据表，有的是使用了排序扩展，有的使用了树操作扩展，然后观察者执行的时候就会产生多条语句)

[2023-08-06 22:11:54] local.DEBUG: [sollado_test] [5.48ms] select * from `users` where `id` = '1' limit 1 | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:54] local.DEBUG: [sollado_test] [2.07ms] select * from `material_files` where `material_id` = '14' and `source_id` in ('196') | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:54] local.DEBUG: [sollado_test] [1.36ms] select * from `filesystem` where `filesystem`.`id` in (344, 345, 346) | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:54] local.DEBUG: [sollado_test] [1.48ms] select * from `media` where `media`.`model_type` = 'Sollado\\Filesystem\\FilesystemModel' and `media`.`model_id` = '344' and `media`.`model_id` is not null | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:54] local.DEBUG: [sollado_test] [10.48ms] delete from `media` where `id` = '335' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [11.21ms] delete from `filesystem` where `id` = '344' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [1.47ms] delete from `filesystem` where `filesystem`.`_lft` between '22' and '22' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [9.37ms] update `filesystem` set `_lft` = case when `_lft` >= 23 then `_lft`-2 else `_lft` end, `_rgt` = case when `_rgt` >= 23 then `_rgt`-2 else `_rgt` end where (`_lft` >= '23' or `_rgt` >= '23') | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [12.79ms] delete from `material_files` where `id` = '233' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [1.37ms] select `id` from `material_files` where (`purpose` = 'PanoramaXml' and `material_id` = '14') order by `order` asc | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [1.2ms] select * from `media` where `media`.`model_type` = 'Sollado\\Filesystem\\FilesystemModel' and `media`.`model_id` = '345' and `media`.`model_id` is not null | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [11.58ms] delete from `media` where `id` = '336' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [4.29ms] select * from `users` where `id` = '1' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [3.81ms] select * from `filesystem` where `filesystem`.`id` = '347' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.72ms] select * from `materials` where `materials`.`id` = '14' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.14ms] select max(`order`) as aggregate from `material_files` where (`purpose` = 'PanoramaXml' and `material_id` = '14') | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [8.62ms] insert into `material_files` (`material_id`, `type`, `purpose`, `source_id`, `disk`, `file`, `order`, `updated_at`, `created_at`) values ('14', '1', 'PanoramaXml', '196', 'Sollado\\Filesystem\\FilesystemModel', '347', '1', '2023-08-06 22:12:55', '2023-08-06 22:12:55') | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [8.89ms] update `material_files` set `material_id` = '14', `type` = '1', `purpose` = 'PanoramaXml', `source_id` = '196', `disk` = 'Sollado\\Filesystem\\FilesystemModel', `file` = '347', `order` = '1', `created_at` = '2023-08-06 22:12:55', `id` = '236', `hash_id` = 'vGnB7EjBO', `material_files`.`updated_at` = '2023-08-06 22:12:55' where `id` = '236' | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.28ms] select * from `material_files` where `material_files`.`material_id` = '14' and `material_files`.`material_id` is not null | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [6.53ms] select * from `users` where `id` = '1' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.37ms] select * from `filesystem` where `filesystem`.`id` = '348' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [2.28ms] select * from `materials` where `materials`.`id` = '14' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [3.26ms] select max(`order`) as aggregate from `material_files` where (`purpose` = 'PanoramaTile' and `material_id` = '14') | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [10.13ms] insert into `material_files` (`material_id`, `type`, `purpose`, `source_id`, `disk`, `file`, `order`, `updated_at`, `created_at`) values ('14', '1', 'PanoramaTile', '196', 'Sollado\\Filesystem\\FilesystemModel', '348', '2', '2023-08-06 22:12:55', '2023-08-06 22:12:55') | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [10.66ms] update `material_files` set `material_id` = '14', `type` = '1', `purpose` = 'PanoramaTile', `source_id` = '196', `disk` = 'Sollado\\Filesystem\\FilesystemModel', `file` = '348', `order` = '2', `created_at` = '2023-08-06 22:12:55', `id` = '237', `hash_id` = 'zGwkm2n6X', `material_files`.`updated_at` = '2023-08-06 22:12:55' where `id` = '237' | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.36ms] select * from `material_files` where `material_files`.`material_id` = '14' and `material_files`.`material_id` is not null | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [5.8ms] select * from `users` where `id` = '1' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.09ms] select * from `filesystem` where `filesystem`.`id` = '349' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [860μs] select * from `materials` where `materials`.`id` = '14' limit 1 | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [2.46ms] select max(`order`) as aggregate from `material_files` where (`purpose` = 'PanoramaJson' and `material_id` = '14') | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [13.96ms] insert into `material_files` (`material_id`, `type`, `purpose`, `source_id`, `disk`, `file`, `order`, `updated_at`, `created_at`) values ('14', '1', 'PanoramaJson', '196', 'Sollado\\Filesystem\\FilesystemModel', '349', '2', '2023-08-06 22:12:55', '2023-08-06 22:12:55') | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [11.61ms] update `material_files` set `material_id` = '14', `type` = '1', `purpose` = 'PanoramaJson', `source_id` = '196', `disk` = 'Sollado\\Filesystem\\FilesystemModel', `file` = '349', `order` = '2', `created_at` = '2023-08-06 22:12:55', `id` = '238', `hash_id` = 'JrnPx5nx5', `material_files`.`updated_at` = '2023-08-06 22:12:55' where `id` = '238' | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:55] local.DEBUG: [sollado_test] [1.47ms] select * from `material_files` where `material_files`.`material_id` = '14' and `material_files`.`material_id` is not null | POST: /api/v1/materials/PYljQ9jaM/files
[2023-08-06 22:12:56] local.DEBUG: [sollado_test] [6.49ms] select * from `users` where `id` = '1' limit 1 | PUT: /api/v1/tasks/zGwkMmn6X
[2023-08-06 22:12:57] local.DEBUG: [sollado_test] [6.33ms] select * from `users` where `id` = '1' limit 1 | GET: /api/v1/tasks
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [1.89ms] select `_lft`, `_rgt` from `filesystem` where `id` = '345' limit 1 | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [7.99ms] delete from `filesystem` where `id` = '345' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [4.97ms] delete from `filesystem` where `filesystem`.`_lft` between '22' and '22' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [12.76ms] update `filesystem` set `_lft` = case when `_lft` >= 23 then `_lft`-2 else `_lft` end, `_rgt` = case when `_rgt` >= 23 then `_rgt`-2 else `_rgt` end where (`_lft` >= '23' or `_rgt` >= '23') | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [7.99ms] delete from `material_files` where `id` = '234' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [1.33ms] select `id` from `material_files` where (`purpose` = 'PanoramaTile' and `material_id` = '14') order by `order` asc | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [11.4ms] update `material_files` set `order` = '1', `material_files`.`updated_at` = '2023-08-06 22:13:17' where `id` = '237' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [1.53ms] select * from `media` where `media`.`model_type` = 'Sollado\\Filesystem\\FilesystemModel' and `media`.`model_id` = '346' and `media`.`model_id` is not null | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:17] local.DEBUG: [sollado_test] [10.29ms] delete from `media` where `id` = '337' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [1.43ms] select `_lft`, `_rgt` from `filesystem` where `id` = '346' limit 1 | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [10.44ms] delete from `filesystem` where `id` = '346' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [1.62ms] delete from `filesystem` where `filesystem`.`_lft` between '22' and '22' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [12.46ms] update `filesystem` set `_lft` = case when `_lft` >= 23 then `_lft`-2 else `_lft` end, `_rgt` = case when `_rgt` >= 23 then `_rgt`-2 else `_rgt` end where (`_lft` >= '23' or `_rgt` >= '23') | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [9.06ms] delete from `material_files` where `id` = '235' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [1.95ms] select `id` from `material_files` where (`purpose` = 'PanoramaJson' and `material_id` = '14') order by `order` asc | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source
[2023-08-06 22:13:21] local.DEBUG: [sollado_test] [9.56ms] update `material_files` set `order` = '1', `material_files`.`updated_at` = '2023-08-06 22:13:21' where `id` = '238' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source

然后查看代码，也没有发现奇怪的东西。只好在各个位置 Logg::debug 记录执行时间

public function deleteOutdatedFileBySource($id, Request $request)
{
    $startTime = time();
    Log::debug('MaterialController: deleteOutdatedFileBySource 开始处理 '.$startTime);
    $id = Hashids::decode($id)[0];
    $sourceList = [];
    if(is_iterable($request->source_list)) {
        foreach ($request->source_list as $val) {
            try {
                $sourceList[] = Hashids::decode($val)[0];
            }catch (\Exception $e){
                return RespondUtil::errorRespond(403, 'source_list 列表项 '.$val.' 无法 decode');
            }
        }
    }else{
        return RespondUtil::errorRespond(403, 'source_list 不可迭代');
    }
    $decodeTime = time();
    $decodeDcrTime = $decodeTime - $startTime;
    Log::debug('MaterialController: deleteOutdatedFileBySource decode 用时'.$decodeDcrTime);
    $materialFileModelList = MaterialFileModel::where('material_id', $id)->whereIn('source_id', $sourceList)->with('filesystem')->get();
    Log::debug('MaterialController: deleteOutdatedFileBySource 查询到 $materialFileModelList 用时'. strval(time() - $decodeTime));
    if(is_iterable($materialFileModelList)) {
        $iterableTime = time();
        $materialFileModelList->each(function (MaterialFileModel $materialFileModel, $key) use($iterableTime) {
            if($materialFileModel->filesystem instanceof Model){
                $materialFileModel->filesystem->delete();
            }
            $materialFileModel->delete();
            Log::debug('MaterialController: deleteOutdatedFileBySource 第'.strval($key).'处理完成, 总用时'.strval(time()-$iterableTime).'秒');
        });
    }
    $endTime = time();
    $dcrTime = $endTime - $startTime;
    Log::debug('MaterialController: deleteOutdatedFileBySource 貌似没有发生异常'.$endTime);
    Log::debug('MaterialController: deleteOutdatedFileBySource 一共用时'.$dcrTime);
    return RespondUtil::successRespond('删除成功');
}

查看日志发现第二个循环特别慢，用了 69 秒。

[2023-08-07 01:10:17] local.DEBUG: MaterialController: deleteOutdatedFileBySource 开始处理 1691341817
[2023-08-07 01:10:17] local.DEBUG: MaterialController: deleteOutdatedFileBySource decode 用时0
[2023-08-07 01:10:17] local.DEBUG: MaterialController: deleteOutdatedFileBySource 查询到 $materialFileModelList 用时0
[2023-08-07 01:10:17] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第0个 materialFile 开始, 总用时0秒
[2023-08-07 01:10:21] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第0个 filesystem 处理完成, 总用时4秒
[2023-08-07 01:10:21] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第0个 materialFile 处理完成, 总用时4秒
[2023-08-07 01:10:21] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第1个 materialFile 开始, 总用时4秒
[2023-08-07 01:11:30] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第1个 filesystem 处理完成, 总用时73秒
[2023-08-07 01:11:30] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第1个 materialFile 处理完成, 总用时73秒
[2023-08-07 01:11:30] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第2个 materialFile 开始, 总用时73秒
[2023-08-07 01:11:34] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第2个 filesystem 处理完成, 总用时77秒
[2023-08-07 01:11:34] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第2个 materialFile 处理完成, 总用时77秒
[2023-08-07 01:11:34] local.DEBUG: MaterialController: deleteOutdatedFileBySource 貌似没有发生异常1691341894
[2023-08-07 01:11:34] local.DEBUG: MaterialController: deleteOutdatedFileBySource 一共用时77

SQL 和代码都看不出来问题。又有点困，一遍遍的查看日志，最后终于发现了问题。问题就是出在第二个文件，Sql 日志是下面这一行。这一行的时间是 22:11:58 这一行之后的请求就来到了 22:12:55。

[2023-08-06 22:11:58] local.DEBUG: [sollado_test] [11.58ms] delete from `media` where `id` = '336' | POST: /api/v1/materials/PYljQ9jaM/delete_outdated_file_by_source

delete 语句肯定是用不了那么久的，日志记录也是 11.58ms。然后想到，之所以不 Model::whereIn('id',[1,2,3])->delete(); 就是为了避免批量操作不能触发观察者事件。这里 media 的 delete 会触发文件资源的删除事件，然后正好之前出现过 spatie/laravel-medialibrary 使用 iidestiny/laravel-filesystem-oss 不能删除文件夹的问题，当时用 ossutil64 封装了一个文件夹删除方法。后来 iidestiny/laravel-filesystem-oss 更新之后好像又好了，就没有用封装的方法。现在看来可能又是文件夹删除出了问题。

spatie/laravel-medialibrary 提供了 Overriding default filesystem behavior （覆盖默认文件系统行为）的方法 spatie.be/docs/laravel-medialibrar... 。我们只是要重写文件和文件夹删除方法，而且 Spatie\MediaLibrary\MediaCollections\Filesystem 的 removeAllFiles 和 removeFile 是 public 的。所以直接创建一个 Spatie\MediaLibrary\MediaCollections\Filesystem 的子类，然后重写 removeAllFiles 和 removeFile 方法。直接用 ossutil64 行删除操作。

<?php

namespace App\Http\Services;

use Sollado\Filesystem\Util\SyncUtil;
use Illuminate\Support\Facades\Log;
use Spatie\MediaLibrary\MediaCollections\Filesystem;
use Spatie\MediaLibrary\MediaCollections\Models\Media;

class SolladoFilesystem extends Filesystem
{
    public function removeAllFiles(Media $media): void
    {

        $mediaDirectory = $this->getMediaDirectory($media);
        if($media->disk == 'oss'){
            $this->removeOssAllFiles($mediaDirectory);
            return;
        }
        ...
    }

    public function removeFile(Media $media, string $path): void
    {

        if($media == 'oss'){
            $this->removeOssFile($path);
            return;
        }
        ...
    }

    private function removeOssAllFiles(string $mediaDirectory): void
    {
        SyncUtil::RemoveToOss($mediaDirectory);
        Log::debug('OssFilesystem: 删除文件夹'.$mediaDirectory);
    }

    private function removeOssFile(string $path): void
    {
        SyncUtil::RemoveToOss($path);
        Log::debug('OssFilesystem: 删除文件'.$path);
    }

}

<?php

namespace Sollado\Filesystem\Util;

use Illuminate\Support\Facades\Log;
use Illuminate\Support\Facades\Storage;

class SyncUtil
{
    public static function removeToOss($filepath, $bucket = 'sollado-test', $host = 'oss:/')
    {
        $targetPath = $host.'/'.$bucket.'/'.$filepath;
        $OssPath = storage_path('sollado/filesystem/ossutil64');
        $script = $OssPath.'  rm --recursive --force -c '.Storage::disk('local')->path('.ossutilconfig').' '.$targetPath;
        Log::info($script);
        exec($script, $output, $return_var);
        self::printOutPut($output);
    }
    ...
}

问题解决

[2023-08-07 00:35:55] local.DEBUG: MaterialController: deleteOutdatedFileBySource 开始处理 1691339755
[2023-08-07 00:35:55] local.DEBUG: MaterialController: deleteOutdatedFileBySource decode 用时0
[2023-08-07 00:35:55] local.DEBUG: MaterialController: deleteOutdatedFileBySource 查询到 $materialFileModelList 用时0
[2023-08-07 00:35:55] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第0个 materialFile 开始, 总用时0秒
[2023-08-07 00:35:56] local.INFO: /home/sollado/server/storage/sollado/filesystem/ossutil64  rm --recursive --force -c /home/sollado/server/storage/app/.ossutilconfig oss://sollado-test/371/
[2023-08-07 00:35:56] local.INFO: ^MTotal 3 objects. Removed 3 objects. Progress: 100%^M                                                   ^MSucceed: Total 3 objects. Removed 3 objects.
[2023-08-07 00:35:56] local.INFO:
[2023-08-07 00:35:56] local.INFO: 0.133722(s) elapsed
[2023-08-07 00:35:56] local.DEBUG: OssFilesystem: 删除文件夹371/
[2023-08-07 00:35:56] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第0个 filesystem 处理完成, 总用时1秒
[2023-08-07 00:35:56] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第0个 materialFile 处理完成, 总用时1秒
[2023-08-07 00:35:56] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第1个 materialFile 开始, 总用时1秒
[2023-08-07 00:35:56] local.INFO: /home/sollado/server/storage/sollado/filesystem/ossutil64  rm --recursive --force -c /home/sollado/server/storage/app/.ossutilconfig oss://sollado-test/372/
[2023-08-07 00:35:57] local.INFO: ^MTotal 419 objects. Removed 419 objects. Progress: 100%^M                                                       ^MSucceed: Total 419 objects. Removed 419 objects.
[2023-08-07 00:35:57] local.INFO:
[2023-08-07 00:35:57] local.INFO: 0.361367(s) elapsed
[2023-08-07 00:35:57] local.DEBUG: OssFilesystem: 删除文件夹372/
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第1个 filesystem 处理完成, 总用时2秒
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第1个 materialFile 处理完成, 总用时2秒
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第2个 materialFile 开始, 总用时2秒
[2023-08-07 00:35:57] local.INFO: /home/sollado/server/storage/sollado/filesystem/ossutil64  rm --recursive --force -c /home/sollado/server/storage/app/.ossutilconfig oss://sollado-test/373/
[2023-08-07 00:35:57] local.INFO: ^MTotal 3 objects. Removed 3 objects. Progress: 100%^M                                                   ^MSucceed: Total 3 objects. Removed 3 objects.
[2023-08-07 00:35:57] local.INFO:
[2023-08-07 00:35:57] local.INFO: 0.130585(s) elapsed
[2023-08-07 00:35:57] local.DEBUG: OssFilesystem: 删除文件夹373/
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第2个 filesystem 处理完成, 总用时2秒
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 第2个 materialFile 处理完成, 总用时2秒
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 貌似没有发生异常1691339757
[2023-08-07 00:35:57] local.DEBUG: MaterialController: deleteOutdatedFileBySource 一共用时2