You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@pegasus.apache.org by GitBox <gi...@apache.org> on 2022/07/19 03:12:59 UTC

[GitHub] [incubator-pegasus] empiredan opened a new issue, #1067: Unit test broken down with unhandled error for load_from_private_log_test.ignore_useless while failed to write mutation log file header

empiredan opened a new issue, #1067:
URL: https://github.com/apache/incubator-pegasus/issues/1067

   While unit test `load_from_private_log_test.ignore_useless` was being executed, it failed to write mutation log file header then broken down with an unhandled error as follows (https://github.com/apache/incubator-pegasus/runs/7387575656?check_suite_focus=true) :
   ```
   [----------] 9 tests from load_from_private_log_test
   [ RUN      ] load_from_private_log_test.find_log_file_to_start
   E2022-07-18 11:42:36.540 (1658144556540112657 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   E2022-07-18 11:42:36.540 (1658144556540365771 9611) replica.default0.0000257e00010001: [1.1@] unable to start duplication since no log file is available
   [       OK ] load_from_private_log_test.find_log_file_to_start (7 ms)
   [ RUN      ] load_from_private_log_test.start_duplication_10000_4MB
   E2022-07-18 11:42:36.547 (1658144556547914109 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   W2022-07-18 11:42:36.586 (1658144556586599550 9615) replica.replica0.010100000000004f: [1.1@] duplication status hasn't been sync completed, try next for delay 1s, last_commit_decree=10010, confirmed_decree=-1
   [       OK ] load_from_private_log_test.start_duplication_10000_4MB (1059 ms)
   [ RUN      ] load_from_private_log_test.start_duplication_50000_4MB
   E2022-07-18 11:42:37.607 (1658144557607002977 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   W2022-07-18 11:42:37.756 (1658144557756301528 9615) replica.replica0.0101000000000078: [1.1@] duplication status hasn't been sync completed, try next for delay 1s, last_commit_decree=50010, confirmed_decree=-1
   E2022-07-18 11:42:38.831 (1658144558831113007 9615) replica.replica0.0104000000000015: [1.1@] ERR_FILE_OPERATION_FAILED: open_read
   [       OK ] load_from_private_log_test.start_duplication_50000_4MB (1312 ms)
   [ RUN      ] load_from_private_log_test.start_duplication_10000_1MB
   E2022-07-18 11:42:38.918 (1658144558918401664 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   W2022-07-18 11:42:38.951 (1658144558951939108 9615) replica.replica0.0101000000000099: [1.1@] duplication status hasn't been sync completed, try next for delay 1s, last_commit_decree=10010, confirmed_decree=-1
   [       OK ] load_from_private_log_test.start_duplication_10000_1MB (1055 ms)
   [ RUN      ] load_from_private_log_test.start_duplication_50000_1MB
   E2022-07-18 11:42:39.974 (1658144559974081135 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   W2022-07-18 11:42:40.119 (1658144560119475359 9615) replica.replica0.01010000000000ef: [1.1@] duplication status hasn't been sync completed, try next for delay 1s, last_commit_decree=50010, confirmed_decree=-1
   E2022-07-18 11:42:41.121 (1658144561121544023 9615) replica.replica0.010400000000006a: [1.1@] ERR_FILE_OPERATION_FAILED: open_read
   [       OK ] load_from_private_log_test.start_duplication_50000_1MB (2256 ms)
   [ RUN      ] load_from_private_log_test.start_duplication_100000_4MB
   E2022-07-18 11:42:42.230 (1658144562230087457 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   W2022-07-18 11:42:42.505 (1658144562505037289 9615) replica.replica0.0101000000000143: [1.1@] duplication status hasn't been sync completed, try next for delay 1s, last_commit_decree=100010, confirmed_decree=-1
   [       OK ] load_from_private_log_test.start_duplication_100000_4MB (1478 ms)
   [ RUN      ] load_from_private_log_test.handle_real_private_log
   E2022-07-18 11:42:43.707 (1658144563707902946 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   E2022-07-18 11:42:43.711 (1658144563711313344 9611) replica.default0.0000257e00010001: [1.4@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   E2022-07-18 11:42:43.712 (1658144563712498012 9611) replica.default0.0000257e00010001: [1.4@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   E2022-07-18 11:42:43.713 (1658144563713367463 9611) replica.default0.0000257e00010001: [1.5@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   [       OK ] load_from_private_log_test.handle_real_private_log (6 ms)
   [ RUN      ] load_from_private_log_test.restart_duplication
   E2022-07-18 11:42:43.714 (1658144563714207711 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   [       OK ] load_from_private_log_test.restart_duplication (2 ms)
   [ RUN      ] load_from_private_log_test.ignore_useless
   E2022-07-18 11:42:43.715 (1658144563715980514 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   E2022-07-18 11:42:43.719 (1658144563719703030 9612) replica.default1.010100000000017f: write failed with errno=Bad file descriptor, return ERR_FILE_OPERATION_FAILED.
   E2022-07-18 11:42:43.719 (1658144563719734132 9612) replica.default1.010100000000017e: write mutation log file header failed, file = ./test-log/log.1.0, err = ERR_FILE_OPERATION_FAILED
   F2022-07-18 11:42:43.719 (1658144563719739932 9612) replica.default1.010100000000017e: assertion expression: false
   F2022-07-18 11:42:43.719 (1658144563719745333 9612) replica.default1.010100000000017e: unhandled error
   Aborted (core dumped)
   I2022-07-18 11:42:43.711 (1658144563711978682 9612) replica.default1.010400010000000a: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0104000100000009
   I2022-07-18 11:42:43.711 (1658144563711983482 9612) replica.default1.010100010000006a: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010400010000000b
   I2022-07-18 11:42:43.712 (1658144563712013784 9612) replica.default1.010400010000000e: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010400010000000d
   I2022-07-18 11:42:43.712 (1658144563712023085 9612) replica.default1.010100010000006b: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010400010000000f
   D2022-07-18 11:42:43.712 (1658144563712032385 9616) replica.replica1.010400010000000c: no next log file (log.2) is found
   D2022-07-18 11:42:43.712 (1658144563712465010 9611) replica.default0.0000257e00010001: [1.4@] closing duplication {"dupid":1,"status":"DS_PAUSE","remote":"remote_address","confirmed":0,"app":"temp"}
   E2022-07-18 11:42:43.712 (1658144563712493112 9611) replica.default0.0000257e00010001: [1.4@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   I2022-07-18 11:42:43.712 (1658144563712540415 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   I2022-07-18 11:42:43.712 (1658144563712544915 9611) replica.default0.0000257e00010001: performance counter replica*eon.replica*private.log.size(MB)@1.4 is removed, remaining reference (1)
   D2022-07-18 11:42:43.712 (1658144563712547915 9611) replica.default0.0000257e00010001: 1.4@: replica closed, time_used = 0ms
   I2022-07-18 11:42:43.712 (1658144563712550215 9611) replica.default0.0000257e00010001: 1.4@: replica destroyed
   I2022-07-18 11:42:43.712 (1658144563712642621 9612) replica.default1.010100010000006c: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000150
   D2022-07-18 11:42:43.712 (1658144563712650821 9611) replica.default0.0000257e00010001: open private log ./test-log/log.1.0 succeed, start_offset = 0, end_offset = 426, size = 426, previous_max_decree = 0
   D2022-07-18 11:42:43.712 (1658144563712657521 9611) replica.default0.0000257e00010001: start to replay mutation log ./test-log/log.1.0, offset = [0, 426), size = 426
   I2022-07-18 11:42:43.712 (1658144563712685423 9612) replica.default1.0101000000000152: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000151
   I2022-07-18 11:42:43.712 (1658144563712697624 9612) replica.default1.010100010000006d: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000153
   I2022-07-18 11:42:43.712 (1658144563712716125 9612) replica.default1.0101000000000155: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000154
   I2022-07-18 11:42:43.712 (1658144563712724925 9612) replica.default1.010100010000006e: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000156
   D2022-07-18 11:42:43.712 (1658144563712731126 9611) replica.default0.0000257e00010001: finish to replay mutation log (./test-log/log.1.0) [err: ERR_HANDLE_EOF: failed to read log block]
   D2022-07-18 11:42:43.712 (1658144563712741826 9611) replica.default0.0000257e00010001: [1.4@] initialize replica_duplicator[DS_PAUSE] [dupid:1, meta_confirmed_decree:0]
   D2022-07-18 11:42:43.712 (1658144563712779029 9611) replica.default0.0000257e00010001: add fail_point [name: open_read, task: Return(), frequency: 25%, max_count: 1]
   D2022-07-18 11:42:43.712 (1658144563712796630 9611) replica.default0.0000257e00010001: add fail_point [name: mutation_log_read_log_block, task: Return(), frequency: 25%, max_count: 1]
   D2022-07-18 11:42:43.712 (1658144563712811030 9611) replica.default0.0000257e00010001: add fail_point [name: duplication_sync_complete, task: Void(), frequency: 100%, max_count: -1]
   I2022-07-18 11:42:43.712 (1658144563712870434 9612) replica.default1.010100010000006f: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0104000100000012
   D2022-07-18 11:42:43.712 (1658144563712875934 9616) replica.replica1.0101000000000157: [1.4@] start loading from log file ./test-log/log.1.0
   I2022-07-18 11:42:43.712 (1658144563712952939 9612) replica.default1.0104000100000017: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0104000100000016
   I2022-07-18 11:42:43.712 (1658144563712957739 9612) replica.default1.0101000100000070: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0104000100000018
   I2022-07-18 11:42:43.712 (1658144563712979140 9612) replica.default1.010400010000001b: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010400010000001a
   I2022-07-18 11:42:43.712 (1658144563712988241 9612) replica.default1.0101000100000071: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010400010000001c
   D2022-07-18 11:42:43.712 (1658144563712994041 9616) replica.replica1.0104000100000019: no next log file (log.2) is found
   D2022-07-18 11:42:43.713 (1658144563713336261 9611) replica.default0.0000257e00010001: [1.4@] closing duplication {"dupid":1,"status":"DS_PAUSE","remote":"remote_address","confirmed":0,"app":"temp"}
   E2022-07-18 11:42:43.713 (1658144563713362462 9611) replica.default0.0000257e00010001: [1.5@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   I2022-07-18 11:42:43.713 (1658144563713413365 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   I2022-07-18 11:42:43.713 (1658144563713418166 9611) replica.default0.0000257e00010001: performance counter �چ}�U is removed, remaining reference (0)
   D2022-07-18 11:42:43.713 (1658144563713420966 9611) replica.default0.0000257e00010001: 1.4@: replica closed, time_used = 0ms
   I2022-07-18 11:42:43.713 (1658144563713423166 9611) replica.default0.0000257e00010001: 1.4@: replica destroyed
   I2022-07-18 11:42:43.713 (1658144563713507771 9612) replica.default1.0101000100000072: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000015a
   D2022-07-18 11:42:43.713 (1658144563713517071 9611) replica.default0.0000257e00010001: open private log ./test-log/log.1.0 succeed, start_offset = 0, end_offset = 405, size = 405, previous_max_decree = 0
   D2022-07-18 11:42:43.713 (1658144563713523272 9611) replica.default0.0000257e00010001: start to replay mutation log ./test-log/log.1.0, offset = [0, 405), size = 405
   I2022-07-18 11:42:43.713 (1658144563713554473 9612) replica.default1.010100000000015c: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000015b
   I2022-07-18 11:42:43.713 (1658144563713565974 9612) replica.default1.0101000100000073: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000015d
   I2022-07-18 11:42:43.713 (1658144563713581775 9612) replica.default1.010100000000015f: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000015e
   I2022-07-18 11:42:43.713 (1658144563713590476 9612) replica.default1.0101000100000074: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000160
   D2022-07-18 11:42:43.713 (1658144563713596476 9611) replica.default0.0000257e00010001: finish to replay mutation log (./test-log/log.1.0) [err: ERR_HANDLE_EOF: failed to read log block]
   D2022-07-18 11:42:43.713 (1658144563713606877 9611) replica.default0.0000257e00010001: [1.5@] initialize replica_duplicator[DS_PAUSE] [dupid:1, meta_confirmed_decree:0]
   D2022-07-18 11:42:43.713 (1658144563713648279 9611) replica.default0.0000257e00010001: add fail_point [name: open_read, task: Return(), frequency: 25%, max_count: 1]
   D2022-07-18 11:42:43.713 (1658144563713665780 9611) replica.default0.0000257e00010001: add fail_point [name: mutation_log_read_log_block, task: Return(), frequency: 25%, max_count: 1]
   D2022-07-18 11:42:43.713 (1658144563713679981 9611) replica.default0.0000257e00010001: add fail_point [name: duplication_sync_complete, task: Void(), frequency: 100%, max_count: -1]
   I2022-07-18 11:42:43.713 (1658144563713740984 9612) replica.default1.0101000100000075: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 01040000000000f7
   D2022-07-18 11:42:43.713 (1658144563713746285 9615) replica.replica0.0101000000000161: [1.5@] start loading from log file ./test-log/log.1.0
   I2022-07-18 11:42:43.713 (1658144563713845090 9612) replica.default1.01040000000000fc: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 01040000000000fb
   I2022-07-18 11:42:43.713 (1658144563713850891 9612) replica.default1.0101000100000076: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 01040000000000fd
   I2022-07-18 11:42:43.713 (1658144563713873792 9612) replica.default1.0104000000000100: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 01040000000000ff
   I2022-07-18 11:42:43.713 (1658144563713882793 9612) replica.default1.0101000100000077: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0104000000000101
   D2022-07-18 11:42:43.713 (1658144563713889093 9615) replica.replica0.01040000000000fe: no next log file (log.2) is found
   D2022-07-18 11:42:43.713 (1658144563713918795 9611) replica.default0.0000257e00010001: [1.5@] closing duplication {"dupid":1,"status":"DS_PAUSE","remote":"remote_address","confirmed":0,"app":"temp"}
   I2022-07-18 11:42:43.713 (1658144563713936196 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   I2022-07-18 11:42:43.713 (1658144563713940896 9611) replica.default0.0000257e00010001: performance counter �چ}�U is removed, remaining reference (0)
   D2022-07-18 11:42:43.713 (1658144563713943596 9611) replica.default0.0000257e00010001: 1.5@: replica closed, time_used = 0ms
   I2022-07-18 11:42:43.713 (1658144563713945796 9611) replica.default0.0000257e00010001: 1.5@: replica destroyed
   D2022-07-18 11:42:43.713 (1658144563713950996 9611) replica.default0.0000257e00010001: close block service manager.
   E2022-07-18 11:42:43.714 (1658144563714189910 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   D2022-07-18 11:42:43.715 (1658144563715030559 9611) replica.default0.0000257e00010001: [1.1@] initialize replica_duplicator[DS_PAUSE] [dupid:1, meta_confirmed_decree:-1]
   D2022-07-18 11:42:43.715 (1658144563715095163 9611) replica.default0.0000257e00010001: create new log file ./test-log/log.1.0 succeed, time_used = 20201 ns
   I2022-07-18 11:42:43.715 (1658144563715236171 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   I2022-07-18 11:42:43.715 (1658144563715308975 9612) replica.default1.0101000100000078: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000168
   D2022-07-18 11:42:43.715 (1658144563715330876 9611) replica.default0.0000257e00010001: open private log ./test-log/log.1.0 succeed, start_offset = 0, end_offset = 1192, size = 1192, previous_max_decree = 0
   D2022-07-18 11:42:43.715 (1658144563715336677 9611) replica.default0.0000257e00010001: start to replay mutation log ./test-log/log.1.0, offset = [0, 1192), size = 1192
   I2022-07-18 11:42:43.715 (1658144563715361578 9612) replica.default1.010100000000016a: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000169
   I2022-07-18 11:42:43.715 (1658144563715372179 9612) replica.default1.0101000100000079: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000016b
   I2022-07-18 11:42:43.715 (1658144563715398780 9612) replica.default1.010100000000016d: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000016c
   I2022-07-18 11:42:43.715 (1658144563715407581 9612) replica.default1.010100010000007a: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000016e
   D2022-07-18 11:42:43.715 (1658144563715415881 9611) replica.default0.0000257e00010001: finish to replay mutation log (./test-log/log.1.0) [err: ERR_HANDLE_EOF: failed to read log block]
   D2022-07-18 11:42:43.715 (1658144563715446583 9611) replica.default0.0000257e00010001: create new log file ./test-log/log.2.1192 succeed, time_used = 22301 ns
   I2022-07-18 11:42:43.715 (1658144563715548889 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   I2022-07-18 11:42:43.715 (1658144563715658095 9612) replica.default1.010100010000007b: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000177
   D2022-07-18 11:42:43.715 (1658144563715670496 9611) replica.default0.0000257e00010001: open private log ./test-log/log.2.1192 succeed, start_offset = 1192, end_offset = 2400, size = 1208, previous_max_decree = 10
   D2022-07-18 11:42:43.715 (1658144563715675596 9611) replica.default0.0000257e00010001: start to replay mutation log ./test-log/log.2.1192, offset = [1192, 2400), size = 1208
   I2022-07-18 11:42:43.715 (1658144563715699098 9612) replica.default1.0101000000000179: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 0101000000000178
   I2022-07-18 11:42:43.715 (1658144563715704698 9612) replica.default1.010100010000007c: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000017a
   I2022-07-18 11:42:43.715 (1658144563715741300 9612) replica.default1.010100000000017c: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000017b
   I2022-07-18 11:42:43.715 (1658144563715749901 9612) replica.default1.010100010000007d: disk operation failure with code LPC_AIO_IMMEDIATE_CALLBACK, err = ERR_HANDLE_EOF, aio_task_id = 010100000000017d
   D2022-07-18 11:42:43.715 (1658144563715760101 9611) replica.default0.0000257e00010001: finish to replay mutation log (./test-log/log.2.1192) [err: ERR_HANDLE_EOF: failed to read log block]
   D2022-07-18 11:42:43.715 (1658144563715768702 9611) replica.default0.0000257e00010001: [1.1@] start loading from log file ./test-log/log.2.1192
   I2022-07-18 11:42:43.715 (1658144563715771402 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   D2022-07-18 11:42:43.715 (1658144563715793603 9611) replica.default0.0000257e00010001: [1.1@] closing duplication {"dupid":1,"status":"DS_PAUSE","remote":"remote_address","confirmed":-1,"app":"temp"}
   I2022-07-18 11:42:43.715 (1658144563715797904 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   I2022-07-18 11:42:43.715 (1658144563715801904 9611) replica.default0.0000257e00010001: performance counter pe�}�U is removed, remaining reference (0)
   D2022-07-18 11:42:43.715 (1658144563715804904 9611) replica.default0.0000257e00010001: 1.1@: replica closed, time_used = 0ms
   I2022-07-18 11:42:43.715 (1658144563715807204 9611) replica.default0.0000257e00010001: 1.1@: replica destroyed
   D2022-07-18 11:42:43.715 (1658144563715812704 9611) replica.default0.0000257e00010001: close block service manager.
   E2022-07-18 11:42:43.715 (1658144563715973014 9611) replica.default0.0000257e00010001: [1.1@] get disk tag of ./test-log failed: ERR_OBJECT_NOT_FOUND, init it to empty 
   D2022-07-18 11:42:43.716 (1658144563716446741 9611) replica.default0.0000257e00010001: [1.1@] initialize replica_duplicator[DS_PAUSE] [dupid:1, meta_confirmed_decree:-1]
   D2022-07-18 11:42:43.716 (1658144563716862265 9611) replica.default0.0000257e00010001: create new log file ./test-log/log.1.0 succeed, time_used = 25101 ns
   I2022-07-18 11:42:43.718 (1658144563718476459 9611) replica.default0.0000257e00010001: close mutation log ./test-log
   E2022-07-18 11:42:43.719 (1658144563719684229 9612) replica.default1.010100000000017f: write failed with errno=Bad file descriptor, return ERR_FILE_OPERATION_FAILED.
   I2022-07-18 11:42:43.719 (1658144563719706130 9612) replica.default1.010100000000017f: disk operation failure with code LPC_WRITE_REPLICATION_LOG_COMMON, err = ERR_FILE_OPERATION_FAILED, aio_task_id = 010100000000017e
   E2022-07-18 11:42:43.719 (1658144563719729232 9612) replica.default1.010100000000017e: write mutation log file header failed, file = ./test-log/log.1.0, err = ERR_FILE_OPERATION_FAILED
   F2022-07-18 11:42:43.719 (1658144563719736132 9612) replica.default1.010100000000017e: assertion expression: false
   F2022-07-18 11:42:43.719 (1658144563719741632 9612) replica.default1.010100000000017e: unhandled error
   ERROR: run dsn_replica_dup_test failed, return_code = 1
   Error: Process completed with exit code 1.
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@pegasus.apache.org.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@pegasus.apache.org
For additional commands, e-mail: dev-help@pegasus.apache.org