...
bsr 드라이버 버전과 bsr 드라이버에서 사용하는 port 정보등을 출력합니다.
시스템 로그가 없는 상황에서는 커널 로드 로그 출력 시간을 통해 시스템 시작 시간을 짐작하기도 합니다.
| Code Block |
|---|
00000001 10/1326/2020 16:0924:03.1143958 [wait_for_add_device] [LOG:10] bsr_info<6> [0xFFFFE000CBDC1880] Wait for device to be connected for log file generation.(C:\Program Files\bsr) 00000002 10/13/2020 16:09:03.1144175 42.7079617 [initRegistry] [DRIVER:63] bsr_info<6> [0xFFFFE000CBABD8800xFFFFE0012A6BD880] registry_path[\Registry\Machine\System\CurrentControlSet\Services\bsr] 0000000300000002 10/1326/2020 16:0924:0342.11442127079678 [initRegistry] [DRIVER:64] bsr_info<6> [0xFFFFE000CBABD8800xFFFFE0012A6BD880] bypass_level=0, read_filter=0, use_volume_lock=1, netlink_tcp_port=5678, daemon_tcp_port=5679, ver=1.5 0000000400000003 10/1326/2020 16:0924:0342.11448267080324 [bsr_initwait_for_add_device] [DRIVERLOG:7710] bsr_info<6> [0xFFFFE000CBABD8800xFFFFE0012A9DC300] Wait initialized.for Version: 1.6.1-A1 (api:device to be connected for log file generation.(C:\Program Files\bsr) 00000004 10/26/2020 16:24:42.7080346 [bsr_init] [DRIVER:77] bsr_info<6> [0xFFFFE0012A6BD880] BSR driver loaded and initialized successfully. Version: 1.6.1 (api:2/proto:86-114) 00000005 10/1326/2020 16:0924:0342.11448507080380 [bsr_init] [DRIVER:78] bsr_info<6> [0xFFFFE000CBABD8800xFFFFE0012A6BD880] 1.6.1(2020.10.13_A1) GIT-hash: f52eea3 build by DEV3-KBLD+Administrator@dev3-kbld, Tue Oct 13 15:19:41 2020 00000006 10/1326/2020 16:0924:0342.11448687080400 [bsr_init] [DRIVER:79] bsr_info<6> [0xFFFFE000CBABD8800xFFFFE0012A6BD880] registered as block device major 147 |
상태 변경
...
00000007 10/26/2020 16:24:42.7080424 [DriverEntry] [DRIVER:4] bsr_info<6> [0xFFFFE0012A6BD880] BSR MVF Driver loaded. |
상태 변경
다음은 bsr 커널은 disk, peer disk, replication, connection, role 상태 변경 시 출력 로그와 설명입니다.
...
다음은 bsradm.exe, bsrsetup.exe, bsrmeta.exe, bsrcon.exe 으로 명령 실행 시 출력 로그와 설명입니다..
명령 실행 시 “bsr netlink cmd(~) begin”“
"실행 명령" command has been received. Execute the command.”, 명령 실행 후 “bsr netlink cmd(~) done” “"실행 명령" command execution terminated. (pending command:0)” 로그를 출력하며 실행되는 명령은 cmd()안에 “실행 명령”으로 표시됩니다.예를들어 명령 실행 시 “cmd(~) begin” 은 있으나 매칭되는 “cmd(~) done” “
"실행 명령" command has been received. Execute the command.” 은 있으나 매칭되는 “"실행 명령" command execution terminated. (pending command:0)” 이 없다면 명령이 완료되지 않은 상황임을 알 수 있습니다.
명령에따라 실행 완료까지 대기 또는 대기하지 않을 수 있습니다.
명령 실행으로 출력되는 로그는 “...” 으로 작성했습니다.
| Code Block |
|---|
00000018 10/1326/2020 16:0925:2903.00581642195574 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAA50400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) command beginhas ->been .received. 00000020 10/13Execute the command. ... 00000020 10/26/2020 16:0925:2903.06122102197637 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAA50400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) done command execution terminated. (cmd_pending command:0) <- .. 00000021 10/1326/2020 16:0925:2903.09027722278267 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012A786040] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) begin -> command has been received. Execute the command. ... 00000023 10/1326/2020 16:0925:2903.09063852280254 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012A786040] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) done command execution terminated. (cmd_pending command:0) <- .. 00000024 10/1326/2020 16:0925:2903.10119072352395 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAA50400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_PEER:44) begincommand ->has been received. Execute the command. ... 00000027 10/1326/2020 16:0925:2903.10146842354514 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAA50400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_PEER:44) done command execution terminated. (cmd_pending command:0) <- .. 00000028 10/1326/2020 16:0925:2903.11241802442056 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CC6EF8800xFFFFE0012A786040] bsr netlink cmd(BSR_ADM_NEW_PATH:45) begin -> command has been received. Execute the command. ... 00000029 10/1326/2020 16:0925:2903.11405152444816 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CC6EF8800xFFFFE0012A786040] bsr netlink cmd(BSR_ADM_NEW_PATH:45) done command execution terminated. (cmd_pending command:0) <- |
connect 실행
다음은 bsradm, bsrsetup 으로 connect 명령 실행 시 출력 로그와 설명입니다.
| Info |
|---|
시스템 또는 네트워크 상황등으로 재연결 시 connect 명령 실행과 동일한 과정의 로그가 출력됩니다. |
| Code Block |
|---|
00000809 10/1300000030 10/26/2020 16:25:03.2884146 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B2FC880] BSR_ADM_ATTACH:12 command has been received. Execute the command. ... 00000055 10/26/2020 16:1825:2203.94782533033626 [NetlinkWorkThread] [NETLINK:1820] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B2FC880] bsr netlink cmd(BSR_ADM_CONNECT:10) begin -> 00000810ATTACH:12 command execution terminated. (pending command:0) 00000056 10/1326/2020 16:1825:2203.94783553136502 [state_change_lockNetlinkWorkThread] [STATENETLINK:4018] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B2F9880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000811 10/13BSR_ADM_CONNECT:10 command has been received. Execute the command. ... 00000059 10/26/2020 16:1825:2203.94785193139110 [print_state_changeNetlinkWorkThread] [STATENETLINK:1920] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), scf(0x2a): bsr_adm_connect, conn( StandAlone -> Unconnected ) 00000812 10/13[0xFFFFE0012B2F9880] BSR_ADM_CONNECT:10 command execution terminated. (pending command:0) |
connect 실행
다음은 bsradm, bsrsetup 으로 connect 명령 실행 시 출력 로그와 설명입니다.
| Info |
|---|
시스템 또는 네트워크 상황등으로 재연결 시 connect 명령 실행과 동일한 과정의 로그가 출력됩니다. |
| Code Block |
|---|
00000056 10/26/2020 16:1825:2203.94789043136502 [bsr_thread_startNetlinkWorkThread] [THREADNETLINK:1118] bsr_info<6> bsr r0 pnode-id:1, cs(Unconnected), prole(Unknown), cflag(0x10e), scf(0x0): Starting receiver thread (from worker [2108]) 00000813 10/13[0xFFFFE0012B2F9880] BSR_ADM_CONNECT:10 command has been received. Execute the command. 00000057 10/26/2020 16:1825:2203.94801503136604 [NetlinkWorkThreadstate_change_lock] [NETLINKSTATE:2040] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B2F9880] bsrWorker netlink cmd(BSR_ADM_CONNECT:10) done (cmd_pending:0) <- 00000814 10/13/2020 16:18:22.9480265 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CE728040] worker should not initiate state should not initiate state changes with CS_SERIALIZE current:FFFFE000CE0F9170FFFFF800A6319BD0 resource->worker.task:FFFFE000CDE0B820FFFFE0012C513C60 0000081500000058 10/1326/2020 16:1825:2203.94804163136765 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(UnconnectedStandAlone), prole(Unknown), cflag(0xe0x0), scf(0x2a): connbsr_adm_connect, conn( UnconnectedStandAlone -> Connecting ) |
00000816 .. [PROTOCOL:55]로그는 연결 후 로컬이 허용하는 protocol version을 출력하며 protocol version은 하위호환을 지원합니다.
| Code Block |
|---|
00000816Unconnected ) 00000059 10/1326/2020 16:1825:2503.95669413139110 [bsr_do_featuresNetlinkWorkThread] [PROTOCOLNETLINK:5520] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xe), scf(0x0): Handshake to peer 1 successful: Agreed network protocol version 114 00000817 10/13[0xFFFFE0012B2F9880] BSR_ADM_CONNECT:10 command execution terminated. (pending command:0) 00000060 10/26/2020 16:1825:2503.95670173139464 [bsr_dothread_featuresstart] [PROTOCOLTHREAD:5611] bsr_info<6> bsr r0 pnode-id:1, cs(ConnectingUnconnected), prole(Unknown), cflag(0xe0x0), scf(0x0): Starting Featurereceiver flagsthread enabled(from on protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME. |
00000818 .. [SEND BUFFER:27]로그는 로컬 send-buffer 사용 유무와 사용 시 send-buffer 할당 크기를 출력하며 만약 메모리가 부족하면 send-buffer가 할당되지 않아 사용되지 않습니다.
| Code Block |
|---|
00000818 10/13/2020 16:18:25.9568141 [conn_connect] [SEND BUFFER:27] bsr_warn<4> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xe), scf(0x0): send-buffering disabled nc->sndbuf_size:0 00000819 10/13/2020 16:18:25.9568180 [bsr_thread_start] [THREAD:11worker [2928]) 00000061 10/26/2020 16:25:03.3140159 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012C706040] Worker should not initiate state changes with CS_SERIALIZE current:FFFFE0012C707160 resource->worker.task:FFFFE0012C513C60 00000062 10/26/2020 16:25:03.3140398 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(ConnectingUnconnected), prole(Unknown), cflag(0xe0x0), scf(0x00x2a): Starting ack_recv thread (from receiver [1676]) 00000820 10/13conn_connect, conn( Unconnected -> Connecting ) |
00000063 .. [PROTOCOL:55]로그는 연결 후 로컬이 허용하는 protocol version을 출력하며 protocol version은 하위호환을 지원합니다.
| Code Block |
|---|
00000063 10/26/2020 16:1825:2606.04243673224961 [statebsr_changedo_lockfeatures] [STATEPROTOCOL:4055] bsr_info<6> [0xFFFFE000CDA1A040] worker should not initiate state changes with CS_SERIALIZE current:FFFFE000CDAA58C0 resource->worker.task:FFFFE000CDE0B820 00000821 10/13/2020 16:18:26.0424586 [change_cluster_wide_state] [TWOPC:34bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0x0), scf(0x0): Handshake to peer 1 successful: Agreed network protocol version 114 00000064 10/26/2020 16:25:06.3225110 [bsr_do_features] [PROTOCOL:56] bsr_info<6> bsr r0 pnode-id:1, r(Secondarycs(Connecting), prole(Unknown), fcflag(0x0), scf(0x82a0x0): Feature Preparing cluster-wide state change 2387348015 (0->1 499/146) 00000822 10/13flags enabled on protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME. |
00000065 .. [SEND BUFFER:27]로그는 로컬 send-buffer 사용 유무와 사용 시 send-buffer 할당 크기를 출력하며 만약 메모리가 부족하면 send-buffer가 할당되지 않아 사용되지 않습니다.
| Code Block |
|---|
00000065 10/26/2020 16:1825:2606.04247333231473 [change_cluster_wide_stateconn_connect] [TWOPCSEND BUFFER:3527] bsr_info<6>warn<4> bsr r0 pnode-id:1, r(Secondarycs(Connecting), prole(Unknown), fcflag(0x0), scf(0x82a0x0): [TWOPC:2387348015] target_node_id(1) conn(Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) flags (2058) 00000823 10/13send-buffering disabled nc->sndbuf_size:0 00000066 10/26/2020 16:1825:2606.04304893231590 [changebsr_clusterthread_wide_statestart] [TWOPCTHREAD:3611] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), rprole(SecondaryUnknown), fcflag(0x0), scf(0x82a0x0): [TWOPC:2387348015] target_node_id(1) get_cluster_wide_reply (3) 00000824 10/13 Starting ack_recv thread (from receiver [1700]) 00000067 10/26/2020 16:1825:2606.04305603374818 [state_change_cluster_wide_statelock] [TWOPCSTATE:3740] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): State change 2387348015: primary_nodes=0, weak_nodes=0 00000825 10/13[0xFFFFE0012CBD2040] Worker should not initiate state changes with CS_SERIALIZE current:FFFFE0012C7CCC20 resource->worker.task:FFFFE0012C513C60 00000068 10/26/2020 16:1825:2606.04306113375354 [change_cluster_wide_state] [TWOPC:3934] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): CommittingPreparing cluster-wide state change 2387348015177619259 (0ms) (0->1 499/146) 0000082600000069 10/1326/2020 16:1825:2606.04323173375466 [printchange_cluster_wide_state_change] [STATETWOPC:1935] bsr_info<6> bsr r0 pnode-id:1, csr(ConnectingSecondary), prolef(Unknown0x0), cflagscf(0xe0x82a), scf(0xa0a): connect_work,: [TWOPC:177619259] target_node_id(1) conn( Connecting -> Connected Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) Unknown -> Secondary ) |
00000827 .. [PROTOCOL:29]로그는 피어 노드에게 수신 받은 peer device의 설정 정보가 출력됩니다.
| Code Block |
|---|
00000827flags (2058) 00000070 10/1326/2020 16:1825:2606.04349603384621 [receive_SyncParamchange_cluster_wide_state] [PROTOCOLTWOPC:2936] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown, r(Secondary), prplf(Off0x0), pdvflagscf(0x00x82a): sync, resync_rate : 250k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k, ov_req_num : 10b, ov_req_interval : 100ms |
00000828 .. [PROTOCOL:32]로그는 로컬 노드의 현재 설정되어있는 복제 디스크 크기가 출력됩니다.
| Code Block |
|---|
00000828 10/13/2020 16:18:26.0435080 [receive_sizes] [PROTOCOL:32[TWOPC:177619259] target_node_id(1) get_cluster_wide_reply (3) 00000071 10/26/2020 16:25:06.3384814 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): State change 177619259: primary_nodes=0, weak_nodes=0 00000072 10/26/2020 16:25:06.3384904 [change_cluster_wide_state] [TWOPC:39] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): current_mydisk_size: 10860101632 bytes |
00000829 .. [PROTOCOL:33]로그는 피어 노드의 현재 설정되어있는 복제 디스크 크기와 최대 설정 할 수 있는 복제 디스크 크기가 출력됩니다.
| Code Block |
|---|
00000829 10/13/2020 16:18:26.0435114 [receive_sizes] [PROTOCOL:33, r(Secondary), f(0x0), scf(0x82a): Committing cluster-wide state change 177619259 (1ms) (0->1) 00000073 10/26/2020 16:25:06.3389819 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xc), scf(0xa0a): connect_work, conn( Connecting -> Connected ) peer( Unknown -> Secondary ) |
00000074 .. [PROTOCOL:29]로그는 피어 노드에게 수신 받은 peer device의 설정 정보가 출력됩니다.
| Code Block |
|---|
00000074 10/26/2020 16:25:06.3391141 [receive_SyncParam] [PROTOCOL:29] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): recv peer_current_size: 10860101632 bytes peer_user_size: 0 bytes peer_disk_size: 10860101632 bytes peer_max_size: 10860101632 bytes |
...
device option, resync_rate : 250k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k, ov_req_num : 10b, ov_req_interval : 100ms |
00000075 .. [PROTOCOL:3432]로그는 최근 노드간 연결 후 협의로 로컬 노드의 현재 설정되어있는 복제 디스크 크기가 출력됩니다.
| Code Block |
|---|
0000083000000075 10/1326/2020 16:1825:2606.04351683396005 [receive_sizes] [PROTOCOL:3432] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdskds(DUnknownUpToDate), prpldvflag(Off), pdvflag(0x100000)0x0): mdcurrent_effectivemydisk_size: 21211136 my_user_size: 0 my_max_size: 21211136 00000831 10/13/2020 16:18:26.0435209 [get_max_agreeable_size] [GENL:16] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): local node_id: 0 00000832 10/13/2020 16:18:26.0435236 [get_max_agreeable_size] [GENL:1710860101632 bytes |
00000076 .. [PROTOCOL:33]로그는 피어 노드의 현재 설정되어있는 복제 디스크 크기와 최대 설정 할 수 있는 복제 디스크 크기가 출력됩니다.
| Code Block |
|---|
00000076 10/26/2020 16:25:06.3396102 [receive_sizes] [PROTOCOL:33] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x1000000x0): node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) 00000833 10/13peer_current_size: 10860101632 bytes peer_user_size: 0 bytes peer_disk_size: 10860101632 bytes peer_max_size: 10860101632 bytes |
00000077 .. [PROTOCOL:34]로그는 최근 노드간 연결 후 협의로 설정되어있는 복제 디스크 크기가 출력됩니다.
| Code Block |
|---|
00000077 10/26/2020 16:1825:2606.04352923396215 [receive_sizes] [PROTOCOL:3934] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): Proceed with device size setting 00000834 10/13md_effective_size: 21211136 my_user_size: 0 my_max_size: 21211136 00000078 10/26/2020 16:1825:2606.04364433396295 [get_max_agreeable_size] [GENLVOLUME:1698] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Skip local node_id: 0 00000835 10/13/2020 16:18:26.0436474the replication volume size comparison because it is a local node id(0) 00000079 10/26/2020 16:25:06.3396358 [get_max_agreeable_size] [GENLVOLUME:1799] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) |
disconnect 실행
다음은 bsradm, bsrsetup 으로 disconnect 명령 실행 시 출력 로그와 설명입니다.
| Info |
|---|
시스템 또는 네트워크 상황등으로 연결 종료 시 동일한 과정의 로그가 출력되나 연결 상태가 standalone으로 설정되지 않습니다. |
| Code Block |
|---|
00000791 00000080 10/1326/2020 16:1825:2006.97619143396463 [NetlinkWorkThreadreceive_sizes] [NETLINKPROTOCOL:1839] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_DISCONNECT:11) begin -> 00000792 10/13/r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): Proceed with device size setting 00000081 10/26/2020 16:1825:2006.97620233397114 [stateget_max_changeagreeable_locksize] [STATEVOLUME:4098] bsr_info<6> [0xFFFFE000CCAFB880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000793 10/13 bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Skip the replication volume size comparison because it is a local node id(0) 00000082 10/26/2020 16:1825:2006.97622183397234 [changeget_clustermax_wideagreeable_statesize] [TWOPCVOLUME:3499] bsr_info<6> bsr r0, r(Secondary/0 minor 2 pnode-id:1, pdsk(DUnknown), fprpl(0x0Off), scfpdvflag(0x280x100000): Preparing cluster-wide state change 2366568536 (0->1 496/16) 00000794 10/13node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) |
disconnect 실행
다음은 bsradm, bsrsetup 으로 disconnect 명령 실행 시 출력 로그와 설명입니다.
| Info |
|---|
시스템 또는 네트워크 상황등으로 연결 종료 시 동일한 과정의 로그가 출력되나 연결 상태가 standalone으로 설정되지 않습니다. |
| Code Block |
|---|
00000093 10/26/2020 16:1837:2052.97622522808432 [change_cluster_wide_stateNetlinkWorkThread] [TWOPCNETLINK:3518] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC:2366568536] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000795 10/13/2020 16:18:20.9766356[0xFFFFE0012B69D880] BSR_ADM_DISCONNECT:11 command has been received. Execute the command. 00000094 10/26/2020 16:37:52.2808549 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012B69D880] Worker should not initiate state changes with CS_SERIALIZE current:FFFFF800A6319BD0 resource->worker.task:FFFFE0012C513C60 00000095 10/26/2020 16:37:52.2808836 [change_cluster_wide_state] [TWOPC:3634] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC:2366568536] target_node_id(1) get_cluster_wide_reply (3) 00000796 10/13 Preparing cluster-wide state change 3319182627 (0->1 496/16) 00000096 10/26/2020 16:1837:2052.97664122808878 [change_cluster_wide_state] [TWOPC:3735] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC: State change 2366568536: primary_nodes=0, weak_nodes=0 00000797 10/133319182627] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000097 10/26/2020 16:1837:2052.97664632812432 [change_cluster_wide_state] [TWOPC:3836] bsr_info<6> bsr r0 pnode-id:1, csr(ConnectedSecondary), prolef(Secondary0x0), cflagscf(0x10e), scf(0x28): Cluster is now split 00000798 10/130x28): [TWOPC:3319182627] target_node_id(1) get_cluster_wide_reply (3) 00000098 10/26/2020 16:1837:2052.97664972812481 [change_cluster_wide_state] [TWOPC:3937] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): Committing cluster-wide state State change 2366568536 (0ms) (0->1) |
00000799 .. [STATE:19]로그는 disconnect 명령으로 연결 종료 시 연결 상태가 standalone으로 상태 변경 시 출력됩니다.
| Code Block |
|---|
00000799 10/133319182627: primary_nodes=0, weak_nodes=0 00000099 10/26/2020 16:1837:2052.97677702812511 [printchange_cluster_wide_state_change] [STATETWOPC:1938] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x2080x28): conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown ) 00000800 10/13Cluster is now split 00000100 10/26/2020 16:1837:2052.97678312812540 [printchange_cluster_wide_state_change] [STATETWOPC:2139] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdskr(UpToDateSecondary), prplf(Established0x0), pdvflagscf(0x1006000x28): conn_try_disconnect, pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 00000801 10/13Committing cluster-wide state change 3319182627 (1ms) (0->1) |
00000101 .. [STATE:19]로그는 disconnect 명령으로 연결 종료 시 연결 상태가 standalone으로 상태 변경 시 출력됩니다.
| Code Block |
|---|
00000101 10/26/2020 16:1837:2052.97682112813798 [bsrprint_recvstate_change] [SOCKETSTATE:1519] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x208): socket data receive error(-15) 00000802 10/13 conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown ) 00000102 10/26/2020 16:1837:2052.97689742813842 [bsrprint_ackstate_receiverchange] [CONNECTIONSTATE:1621] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, cspdsk(DisconnectingUpToDate), proleprpl(UnknownEstablished), cflagpdvflag(0x10e)0x100600): conn_try_disconnect, scf(0x0): ack_receiver terminated 00000803 10/13pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 00000103 10/26/2020 16:1837:2052.97690282814295 [bsr_thread_setuprecv] [THREADSOCKET:915] bsr_info<6> bsr r0 pnode-id:1, cs(DisconnectingConnected), prole(UnknownSecondary), cflag(0x10e), scf(0x00x208): Terminating ack_recv thread 00000804Data stream socket receive error(-15) 00000104 10/1326/2020 16:1837:2052.97719902814897 [wbsr_resyncack_timerreceiver] [RESYNC/OVCONNECTION:10516] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknowncs(Disconnecting), prole(Unknown), prplcflag(Off0x10e), pdvflagscf(0x0): completedack_receiver because it is not in the VerifyS or SyncTarget replication state. 00000805terminated 00000105 10/1326/2020 16:1837:2052.97743972814968 [connbsr_thread_disconnectsetup] [CONNECTIONTHREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Terminating Connectionack_recv closedthread 0000080600000106 10/1326/2020 16:1837:2052.97749282817384 [printw_stateresync_changetimer] [STATERESYNC/OV:19105] bsr_info<6> bsr r0 pnode/0 minor 2 pnode-id:1, cspdsk(DisconnectingDUnknown), proleprpl(UnknownOff), cflagpdvflag(0x10e), scf(0x23): conn_disconnect, conn( Disconnecting -> StandAlone ) 00000807 10/130x0): The resync is complete because it is not in VerifyS or SyncTarget replication state. 00000107 10/26/2020 16:1837:2052.97753352820403 [bsrconn_thread_setupdisconnect] [THREADCONNECTION:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAloneDisconnecting), prole(Unknown), cflag(0x10e), scf(0x0): TerminatingConnection receiverclosed thread 0000080800000108 10/1326/2020 16:1837:2052.97775522820944 [NetlinkWorkThreadprint_state_change] [NETLINKSTATE:2019] bsr_info<6> [0xFFFFE000CCAFB880]bsr bsr netlink cmd(BSR_ADM_DISCONNECT:11) done (cmd_pending:0) <- |
up 실행
다음은 bsradm up 명령 실행 시 출력 로그와 설명입니다.
| Info |
|---|
bsradm up 명령 실행 시 new-resource, new-minor, new-peer, new-path, attach, connect 명령이 순차적으로 실행됩니다. |
| Code Block |
|---|
00000722 10/13/2020 16:16:12.6266106 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) begin -> 00000723 10/13/2020 16:16:12.6266252r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x23): conn_disconnect, conn( Disconnecting -> StandAlone ) 00000109 10/26/2020 16:37:52.2821351 [bsr_thread_startsetup] [THREAD:129] bsr_info<6> bsr r0 pnode-id:1, rcs(SecondaryStandAlone), f(0x0prole(Unknown), cflag(0x10e), scf(0x0): StartingTerminating workerreceiver thread (from not_bsr_thread [0]) 00000724 00000110 10/1326/2020 16:1637:1252.62684492823823 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) done (cmd_pending:0) <- 00000725 10/13DISCONNECT:11 command execution terminated. (pending command:0) |
up 실행
다음은 bsradm up 명령 실행 시 출력 로그와 설명입니다.
| Info |
|---|
bsradm up 명령 실행 시 new-resource, new-minor, new-peer, new-path, attach, connect 명령이 순차적으로 실행됩니다. |
| Code Block |
|---|
00000018 10/26/2020 16:1625:1203.63462922195574 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_MINORRESOURCE:5) begin -> 000007267 command has been received. Execute the command. 00000019 10/1326/2020 16:1625:1203.63466512195696 [bsr_createthread_devicestart] [VOLUMETHREAD:1012] bsr_info<6> [0xFFFFE000CCAAC040] device(FFFFE000CE6C8890) max sectors(21211136), size(10860101632 bytes) 00000727 10/13 bsr r0, r(Secondary), f(0x0), scf(0x0): Starting worker thread (from not_bsr_thread [0]) 00000020 10/26/2020 16:1625:1203.63484212197637 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) done (cmd_pendingRESOURCE:7 command execution terminated. (pending command:0) <- 0000072800000021 10/1326/2020 16:1625:1203.64307012278267 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012A786040] bsr netlink cmd(BSR_ADM_NEW_PEER:44) begin -> 00000729MINOR:5 command has been received. Execute the command. 00000022 10/1326/2020 16:1625:1203.64308892278667 [bsr_create_peer_device_default_config] [GENLVOLUME:4510] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): default, resync_rate : 250k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k, ov_req_num : 10b, ov_req_interval : 100ms 00000730 10/13/2020 16:16:12.6431084 [bsr_thread_start] [THREAD:11[0xFFFFE0012A786040] The capacity of the create device(FFFFE0012CAD1AB0) is max sectors(21211136), size(10860101632 bytes) 00000023 10/26/2020 16:25:03.2280254 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012A786040] BSR_ADM_NEW_MINOR:5 command execution terminated. (pending command:0) 00000024 10/26/2020 16:25:03.2352395 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_NEW_PEER:44 command has been received. Execute the command. 00000025 10/26/2020 16:25:03.2352568 [bsr_create_peer_device_default_config] [GENL:45] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, cspdsk(StandAloneDUnknown), proleprpl(UnknownOff), cflagpdvflag(0x0), scf(0x0): Startingdefault sender thread (from not_bsr_thread [0]) 00000731 10/13/2020 16:16:12.6433056 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_NEW_PEER:44) done (cmd_pending:0) <- 00000732 10/13/2020 16:16:12.6519482 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_NEW_PATH:45) begin -> 00000733 10/13/2020 16:16:12.6521598peer device option. resync_rate : 250k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k, ov_req_num : 10b, ov_req_interval : 100ms 00000026 10/26/2020 16:25:03.2352753 [bsr_thread_start] [THREAD:11] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x0), scf(0x0): Starting sender thread (from not_bsr_thread [0]) 00000027 10/26/2020 16:25:03.2354514 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAFB8800xFFFFE0012B69D880] bsr netlink cmd(BSR_ADM_NEW_PATH:45) done (cmd_pendingPEER:44 command execution terminated. (pending command:0) <- 0000073400000028 10/1326/2020 16:1625:1203.70334752442056 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012A786040] bsr netlink cmd(BSR_ADM_ATTACH:12) begin -> 00000735 10/13NEW_PATH:45 command has been received. Execute the command. 00000029 10/26/2020 16:1625:1203.70377192444816 [state_change_lockNetlinkWorkThread] [STATENETLINK:4020] bsr_info<6> [0xFFFFE000CCAC4880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000736 10/130xFFFFE0012A786040] BSR_ADM_NEW_PATH:45 command execution terminated. (pending command:0) 00000030 10/26/2020 16:25:03.2884146 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B2FC880] BSR_ADM_ATTACH:12 command has been received. Execute the command. 00000031 10/26/2020 16:1625:1203.70378832889320 [print_state_change_lock] [STATE:2040] bsr_info<6> [0xFFFFE0012B2FC880] Worker should not initiate state changes with CS_SERIALIZE current:FFFFF800A6319BD0 resource->worker.task:FFFFE0012C513C60 00000032 10/26/2020 16:25:03.2889474 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Diskless), dvflag(0x0): change_disk_state, disk( Diskless -> Attaching ) 0000073700000033 10/1326/2020 16:1625:1203.70383822890049 [FsctlLockVolume] [VOLUME:2065] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2FC880] notry lock. volume(\Device\HarddiskVolume2) already00000034 dismounted 00000738 10/1326/2020 16:1625:1203.70384142959696 [FsctlFlushDismountVolumeFsctlLockVolume] [VOLUME:1523] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2FC880] no dismount. volume(\Device\HarddiskVolume2) already dismounted 00000739locked. handle(0xFFFFFFFF80000AFC) 00000035 10/1326/2020 16:1625:1203.70384412959798 [FsctlUnlockVolumeFsctlFlushDismountVolume] [VOLUME:2462] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2FC880] try volumeflush volume(\Device\HarddiskVolume2) not00000036 locked 00000740 10/1326/2020 16:1625:1203.70384602959854 [bsr_adm_attachFsctlFlushDismountVolume] [GENLVOLUME:3617] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Maximum number of bitmap peer devices 1 00000741 10/13[0xFFFFE0012B2FC880] Failed to flush volume. status(0xc000026e) 00000037 10/26/2020 16:1625:1203.70478592959874 [bsr_bump_write_orderingFsctlFlushDismountVolume] [VOLUME:6663] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x1): Method to ensure write ordering: drain 00000742 10/13[0xFFFFE0012B2FC880] volume(\Device\HarddiskVolume2) flushed 00000038 10/26/2020 16:1625:1203.70478912959893 [get_max_agreeable_sizeFsctlFlushDismountVolume] [GENLVOLUME:1664] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): local node_id: 0 00000743 10/13[0xFFFFE0012B2FC880] try dismount volume(\Device\HarddiskVolume2) 00000039 10/26/2020 16:25:03.2965893 [FsctlFlushDismountVolume] [VOLUME:19] bsr_info<6> [0xFFFFE0012B2FC880] volume(\Device\HarddiskVolume2) dismounted 00000040 10/26/2020 16:1625:1203.70479132965979 [get_max_agreeable_sizeFsctlUnlockVolume] [GENLVOLUME:1761] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(0) disk state(DUnknown) 00000744 10/13[0xFFFFE0012B2FC880] unlock volume(\Device\HarddiskVolume2) 00000041 10/26/2020 16:25:03.2969597 [FsctlUnlockVolume] [VOLUME:26] bsr_info<6> [0xFFFFE0012B2FC880] volume(\Device\HarddiskVolume2) unlocked 00000042 10/26/2020 16:1625:1203.70481032969738 [getbsr_maxadm_agreeable_sizeattach] [GENL:1636] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): local node_id: 0 00000745The maximum number of bitmap peer devices is 1. 00000043 10/1326/2020 16:1625:1203.70481232979413 [getbsr_maxbump_agreeablewrite_sizeordering] [GENLVOLUME:1766] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown, r(Secondary), prplf(Off0x0), pdvflagscf(0x00x1): node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(0) disk state(DUnknown) 00000746 10/13Method to ensure write ordering: drain 00000044 10/26/2020 16:1625:1203.70481592979447 [bsrget_max_bmagreeable_resizesize] [BITMAPVOLUME:2398] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): bitmap resize called with capacity(21211136) 00000747 10/13 Skip the replication volume size comparison because it is a local node id(0) 00000045 10/26/2020 16:1625:1203.70540152979474 [bsrget_max_bmagreeable_resizesize] [BITMAPVOLUME:2599] bsr_info<6> bsr r0/0 minor 2, ds(Attaching pnode-id:1, pdsk(DUnknown), prpl(Off), dvflagpdvflag(0x0): resize bitmap, bits(2651392) words(82856) pages(81) |
00000748 .. [GENL:13]로그는 attach 대상 복제 디스크의 크기가 출력됩니다.
| Code Block |
|---|
00000748 10/13node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(0) disk state(DUnknown) 00000046 10/26/2020 16:1625:1203.70540542979681 [bsrget_determinemax_devagreeable_size] [GENLVOLUME:1398] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Skip the Updatereplication diskvolume size 10 GB (10605568 KB) 00000749comparison because it is a local node id(0) 00000047 10/1326/2020 16:1625:1203.70929932979705 [bmget_rwmax_rangeagreeable_size] [BITMAPVOLUME:2999] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), dsprpl(AttachingOff), dvflagpdvflag(0x0): recounting of set bits took additional 1ms 00000750 10/13 node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(0) disk state(DUnknown) 00000048 10/26/2020 16:1625:1203.70930792979742 [statebsr_changebm_lockresize] [STATEBITMAP:4023] bsr_info<6> [0xFFFFE000CCAC4880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000751 10/13bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Start resizing the bitmap size to disk capacity. capacity sector(21211136) 00000049 10/26/2020 16:1625:1203.70932402985588 [printbsr_statebm_changeresize] [STATEBITMAP:2025] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): change_disk_state, disk( Attaching -> UpToDate ) |
...
The bitmap size has been resized to disk capacity. bits(2651392) words(82856) pages(81) |
00000050 .. [VOLUME:96]로그는 attach 대상 복제 디스크의 설정되어있는 current UUID가 크기가 출력됩니다.
| Code Block |
|---|
0000075200000050 10/1326/2020 16:1625:1203.70932882985622 [finishbsr_determine_statedev_changesize] [UUIDVOLUME:1496] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): attached to current UUID: 83F530CA41FA9868 00000753 10/13 Update the disk size in the meta. 10 GB (10605568 KB) 00000051 10/26/2020 16:1625:1203.70976573028170 [NetlinkWorkThreadbm_rw_range] [NETLINKBITMAP:2029] bsr_info<6> [0xFFFFE000CCAC4880] bsr netlink cmd(BSR_ADM_ATTACH:12) done (cmd_pending:0) <- |
connect 명령이 실행됩니다.
| Code Block |
|---|
00000754 10/13/2020 16:16:12.7186777 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_CONNECT:10) begin -> 00000755 10/13 bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Recounting of set bits took additional 0ms 00000052 10/26/2020 16:1625:1203.71868943028240 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAAC0400xFFFFE0012B2FC880] workerWorker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0FFFFF800A6319BD0 resource->worker.task:FFFFE000CDE0B820FFFFE0012C513C60 0000075600000053 10/1326/2020 16:1625:1203.71871023028465 [print_state_change] [STATE:1920] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown/0 minor 2, ds(Attaching), cflagdvflag(0x0), scf(0x2a): bsrchange_admdisk_connectstate, conndisk( StandAloneAttaching -> UnconnectedUpToDate ) 00000757 |
00000054 .. [UUID:14]로그는 attach 대상 복제 디스크의 설정되어있는 current UUID가 출력됩니다.
| Code Block |
|---|
00000054 10/1326/2020 16:1625:1203.71891503028511 [NetlinkWorkThreadfinish_state_change] [NETLINKUUID:2014] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_CONNECT:10) done (cmd_pending:0) <- 00000758 10/13 bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): attached to current UUID: A95D18E8D4AE8C78 00000055 10/26/2020 16:1625:1203.7190322 [3033626 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B2FC880] BSR_ADM_ATTACH:12 command execution terminated. (pending command:0) |
connect 명령이 실행됩니다.
| Code Block |
|---|
00000059 10/26/2020 16:25:03.3139110 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B2F9880] BSR_ADM_CONNECT:10 command execution terminated. (pending command:0) 00000060 10/26/2020 16:25:03.3139464 [bsr_thread_start] [THREAD:11] bsr_info<6> bsr r0 pnode-id:1, cs(Unconnected), prole(Unknown), cflag(0x0), scf(0x0): Starting receiver thread (from worker [21082928]) 0000075900000061 10/1326/2020 16:1625:1203.71911493140159 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CDDA58800xFFFFE0012C706040] workerWorker should not initiate state changes with CS_SERIALIZE current:FFFFE000CE0F9170FFFFE0012C707160 resource->worker.task:FFFFE000CDE0B820FFFFE0012C513C60 0000076000000062 10/1326/2020 16:1625:1203.71913493140398 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Unconnected), prole(Unknown), cflag(0x0), scf(0x2a): conn_connect, conn( Unconnected -> Connecting ) 0000076100000063 10/1326/2020 16:1625:1506.72248483224961 [bsr_do_features] [PROTOCOL:55] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0x0), scf(0x0): Handshake to peer 1 successful: Agreed network protocol version 114 0000076200000064 10/1326/2020 16:1625:1506.72249163225110 [bsr_do_features] [PROTOCOL:56] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0x0), scf(0x0): Feature flags enabled on protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME. 0000076300000065 10/1326/2020 16:1625:1506.72273323231473 [conn_connect] [SEND BUFFER:27] bsr_warn<4> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0x0), scf(0x0): send-buffering disabled nc->sndbuf_size:0 0000076400000066 10/1326/2020 16:1625:1506.72274373231590 [bsr_thread_start] [THREAD:11] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0x0), scf(0x0): Starting ack_recv thread (from receiver [28081700]) 0000076500000067 10/1326/2020 16:1625:1506.77704043374818 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CDA1A0400xFFFFE0012CBD2040] workerWorker should not initiate state changes with CS_SERIALIZE current:FFFFE000CDAA58C0FFFFE0012C7CCC20 resource->worker.task:FFFFE000CDE0B820FFFFE0012C513C60 0000076600000068 10/1326/2020 16:1625:1506.77706283375354 [change_cluster_wide_state] [TWOPC:34] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): Preparing cluster-wide state change 1853056548177619259 (0->1 499/146) 0000076700000069 10/1326/2020 16:1625:1506.77706643375466 [change_cluster_wide_state] [TWOPC:35] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:1853056548177619259] target_node_id(1) conn(Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) flags (2058) 0000076800000070 10/1326/2020 16:1625:1506.77760583384621 [change_cluster_wide_state] [TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:1853056548177619259] target_node_id(1) get_cluster_wide_reply (3) 0000076900000071 10/1326/2020 16:1625:1506.77761093384814 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): State change 1853056548177619259: primary_nodes=0, weak_nodes=0 0000077000000072 10/1326/2020 16:1625:1506.77761453384904 [change_cluster_wide_state] [TWOPC:39] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): Committing cluster-wide state change 1853056548177619259 (1ms) (0->1) 0000077100000073 10/1326/2020 16:1625:1506.77784713389819 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xc), scf(0xa0a): connect_work, conn( Connecting -> Connected ) peer( Unknown -> Secondary ) 0000077200000074 10/1326/2020 16:1625:1506.77795273391141 [receive_SyncParam] [PROTOCOL:29] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): syncrecv peer device option, resync_rate : 250k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k, ov_req_num : 10b, ov_req_interval : 100ms 0000077300000075 10/1326/2020 16:1625:1506.77812603396005 [receive_sizes] [PROTOCOL:32] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): current_mydisk_size: 10860101632 bytes 0000077400000076 10/1326/2020 16:1625:1506.77812923396102 [receive_sizes] [PROTOCOL:33] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): peer_current_size: 10860101632 bytes peer_user_size: 0 bytes peer_disk_size: 10860101632 bytes peer_max_size: 10860101632 bytes 0000077500000077 10/1326/2020 16:1625:1506.77813343396215 [receive_sizes] [PROTOCOL:34] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): md_effective_size: 21211136 my_user_size: 0 my_max_size: 21211136 0000077600000078 10/1326/2020 16:1625:1506.77813653396295 [get_max_agreeable_size] [GENLVOLUME:1698] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Skip the replication volume size comparison because it is a local node_ id: (0) 0000077700000079 10/1326/2020 16:1625:1506.77813873396358 [get_max_agreeable_size] [GENLVOLUME:1799] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) 0000077800000080 10/1326/2020 16:1625:1506.77814293396463 [receive_sizes] [PROTOCOL:39] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): Proceed with device size setting 0000077900000081 10/1326/2020 16:1625:1506.77820723397114 [get_max_agreeable_size] [GENLVOLUME:1698] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Skip the replication volume size comparison because it is a local node_ id: (0) 0000078000000082 10/1326/2020 16:1625:1506.77821093397234 [get_max_agreeable_size] [GENLVOLUME:1799] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) |
...
| Info |
|---|
bsradm down 명령은 볼륨 lock, 볼륨 flush, 볼륨 dismount, 연결 종료, 볼륨 잠금 순서로 실행됩니다. |
| Code Block |
|---|
0000061700000398 10/1326/2020 16:1649:1110.21368052436929 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] bsr netlink cmd(BSR_ADM_DOWN:27) begin -> |
...
command has been received. Execute the command. |
00000399 .. [VOLUME:65],00000680 .. [VOLUME:23]로그들은 복제 볼륨 베타적 락 획득 시 출력됩니다.
| Code Block |
|---|
0000061800000399 10/1326/2020 16:1649:1110.21373442437390 [FsctlLockVolume] [VOLUME:65] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] try lock volume(\Device\HarddiskVolume2) 0000068000000472 10/1326/2020 16:1649:1110.25348832864430 [FsctlLockVolume] [VOLUME:23] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] volume(\Device\HarddiskVolume2) locked. handle(0xFFFFFFFF80000DC80xFFFFFFFF80000C20) |
00000683 00000473 .. [VOLUME:62],00000684 00000474 .. [VOLUME:63]로그들은 복제 볼륨 flush 시 출력됩니다.
| Code Block |
|---|
0000068300000473 10/1326/2020 16:1649:1110.25350242864535 [FsctlFlushDismountVolume] [VOLUME:62] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] try flush volume(\Device\HarddiskVolume2) 0000068400000474 10/1326/2020 16:1649:1110.25357292864915 [FsctlFlushDismountVolume] [VOLUME:63] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] volume(\Device\HarddiskVolume2) flushed |
00000685 00000475 .. [VOLUME:64],00000686 00000476 .. [VOLUME:19]로그들은 복제 볼륨 dismount 실행 시 출력됩니다.
| Code Block |
|---|
0000068500000475 10/1326/2020 16:1649:1110.25357662864954 [FsctlFlushDismountVolume] [VOLUME:64] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] try dismount volume(\Device\HarddiskVolume2) 00000686 10/13/2020 16:16:11.2559822 [FsctlFlushDismountVolume] [VOLUME:19] bsr_info<6> [0xFFFFE000CCAC4880] volume(\Device\HarddiskVolume2) dismounted |
00000687 .. [STATE:18]로그는 down 시 role이 primary 일때 secondary 로 role을 변경 할때 출력됩니다.
| Code Block |
|---|
00000687 10/13/2020 16:16:11.2560178 [print_state_change] [STATE:18] bsr_info<6> bsr r0, r(Primary), f(0x11), scf(0x83c): change_role, role( Primary -> Secondary ) 00000688 10/13/2020 16:16:11.2568256 [__receive_uuids] [UUID:16] bsr_warn<4> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): receive new current but not update UUID: 83F530CA41FA9868 00000689 10/13/2020 16:16:11.2568317 [bsr_uuid_compare] [RESYNC/OV:197] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x2): Local and peer current UUIDs are the same. rule(40), res(0) |
00000690 .. [VOLUME:61],00000691 .. [VOLUME:26]로그들은 복제 볼륨 베타적 락 반환 시 출력됩니다.
| Code Block |
|---|
00000690 10/13/2020 16:16:11.2569857 [FsctlUnlockVolume] [VOLUME:61] bsr_info<6> [0xFFFFE000CCAC4880] unlock volume(\Device\HarddiskVolume2)
00000691 10/13/2020 16:16:11.2576899 [FsctlUnlockVolume] [VOLUME:26] bsr_info<6> [0xFFFFE000CCAC4880] volume(\Device\HarddiskVolume2) unlocked
00000692 10/13/2020 16:16:11.2577179 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAC4880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDB38300 |
disconnect 명령과 동일한 동작을 실행합니다.
| Code Block |
|---|
00000693 10/13/2020 16:16:11.2577328 [change_cluster_wide_state] [TWOPC:34] bsr_info<6> bsr r0, r(Secondary), f(0x11), scf(0x28): Preparing cluster-wide state change 1834520240 (0->1 496/16) 00000694 10/13/2020 16:16:11.2577355 [change_cluster_wide_state] [TWOPC:35] bsr_info<6> bsr r0, r(Secondary), f(0x11), scf(0x28): [TWOPC:1834520240] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000695 10/13/2020 16:16:11.2580212 00000479 10/26/2020 16:49:10.2871632 [FsctlFlushDismountVolume] [VOLUME:19] bsr_info<6> [0xFFFFE0012B2F9880] volume(\Device\HarddiskVolume2) dismounted |
00000480 .. [STATE:18]로그는 down 시 role이 primary 일때 secondary 로 role을 변경 할때 출력됩니다.
| Code Block |
|---|
00000480 10/26/2020 16:49:10.2871910 [print_state_change] [STATE:18] bsr_info<6> bsr r0, r(Primary), f(0x1), scf(0x83c): change_role, role( Primary -> Secondary )
00000481 10/26/2020 16:49:10.2879558 [__receive_uuids] [UUID:16] bsr_warn<4> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): receive new current but not update UUID: CE5CC8B0672E645C
00000482 10/26/2020 16:49:10.2879607 [bsr_uuid_compare] [RESYNC/OV:197] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x2): Local and peer current UUIDs are the same. rule(40), res(0) |
00000483 .. [VOLUME:61],00000691 .. [VOLUME:26]로그들은 복제 볼륨 베타적 락 반환 시 출력됩니다.
| Code Block |
|---|
00000483 10/26/2020 16:49:10.2881069 [FsctlUnlockVolume] [VOLUME:61] bsr_info<6> [0xFFFFE0012B2F9880] unlock volume(\Device\HarddiskVolume2)
00000484 10/26/2020 16:49:10.2889783 [FsctlUnlockVolume] [VOLUME:26] bsr_info<6> [0xFFFFE0012B2F9880] volume(\Device\HarddiskVolume2) unlocked
00000485 10/26/2020 16:49:10.2890044 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012B2F9880] Worker should not initiate state changes with CS_SERIALIZE current:FFFFF800A6319BD0 resource->worker.task:FFFFE0012C7D29A0 |
disconnect 명령과 동일한 동작을 실행합니다.
| Code Block |
|---|
00000486 10/26/2020 16:49:10.2890183 [change_cluster_wide_state] [TWOPC:3634] bsr_info<6> bsr r0, r(Secondary), f(0x110x1), scf(0x28): [TWOPC:1834520240] target_node_id(1) get_cluster_wide_reply (3) 00000696 10/13Preparing cluster-wide state change 1805107054 (0->1 496/16) 00000487 10/26/2020 16:1649:1110.25802512890209 [change_cluster_wide_state] [TWOPC:3735] bsr_info<6> bsr r0, r(Secondary), f(0x110x1), scf(0x28): [TWOPC: State change 1834520240: primary_nodes=0, weak_nodes=0 00000697 10/131805107054] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000488 10/26/2020 16:1649:1110.25802752893052 [change_cluster_wide_state] [TWOPC:3836] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(r(Secondary), cflagf(0x210e0x1), scf(0x28): Cluster is now split 00000698[TWOPC:1805107054] target_node_id(1) get_cluster_wide_reply (3) 00000489 10/1326/2020 16:1649:1110.25803002893089 [change_cluster_wide_state] [TWOPC:3937] bsr_info<6> bsr r0, r(Secondary), f(0x110x1), scf(0x28): Committing cluster-wide stateState change 1834520240 (0ms) (0->1) 000006991805107054: primary_nodes=0, weak_nodes=0 00000490 10/1326/2020 16:1649:1110.25843882893113 [Receivechange_cluster_wide_state] [SOCKETTWOPC:6638] bsr_info<6> [0xFFFFE000CDB66880] receiver => Recv multiWait error. err(STATUS_CONNECTION_RESET) wsk(0xFFFFE000CE2A8198) size(16) 00000700 10/13bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x28): Cluster is now split 00000491 10/26/2020 16:1649:1110.25845792893140 [bsr_recvchange_cluster_wide_state] [SOCKETTWOPC:1439] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(r(Secondary), cflagf(0x210e0x1), scf(0x28): socket reset due to peer. 00000701 10/13 Committing cluster-wide state change 1805107054 (1ms) (0->1) 00000492 10/26/2020 16:1649:1110.25847572895017 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x210e0x10e), scf(0x210x208): bsrconn_try_recvdisconnect, conn( Connected -> BrokenPipeDisconnecting ) peer( Secondary -> Unknown ) 0000070200000493 10/1326/2020 16:1649:1110.25848052895061 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): bsrconn_try_recvdisconnect, pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 0000070300000494 10/1326/2020 16:1649:1110.25850712895371 [bsr_recv_all_warn] [PROTOCOLSOCKET:6415] bsr_warn<4>info<6> bsr r0 pnode-id:1, cs(BrokenPipeConnected), prole(UnknownSecondary), cflag(0x211e0x10e), scf(0x00x208): shortData readstream (expectedsocket size 16) 00000704 10/13/2020 16:16:11.2585247 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(BrokenPipe), prole(Unknown), cflag(0x211e), scf(0x208): conn_try_disconnect, conn( BrokenPipe -> Disconnecting ) 00000705 10/13receive error(-15) 00000495 10/26/2020 16:1649:1110.25864952895990 [bsr_ack_receiver] [CONNECTION:16] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e0x10e), scf(0x0): ack_receiver terminated 0000070600000496 10/1326/2020 16:1649:1110.25865322896039 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e0x10e), scf(0x0): Terminating ack_recv thread 0000070700000497 10/1326/2020 16:1649:1110.25876922897546 [w_resync_timer] [RESYNC/OV:105] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): completed The resync is complete because it is not in the VerifyS or SyncTarget replication state. 0000070800000498 10/1326/2020 16:1649:1110.25911572900523 [conn_disconnect] [CONNECTION:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e0x10e), scf(0x0): Connection closed 0000070900000499 10/1326/2020 16:1649:1110.25916882900922 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e0x10e), scf(0x23): conn_disconnect, conn( Disconnecting -> StandAlone ) 0000071000000500 10/1326/2020 16:1649:1110.25919812901181 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x211e0x10e), scf(0x0): Terminating receiver thread 0000071100000501 10/1326/2020 16:1649:1110.25924682901744 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x211e0x10e), scf(0x0): Terminating sender thread 0000071200000502 10/1326/2020 16:1649:1110.25930362902522 [bsr_destroy_connection] [CONNECTION:1] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x311e0x110e), scf(0x0): The bsr_destroy_connection 00000713object is removed. 00000503 10/1326/2020 16:1649:1110.25932412902683 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] workerWorker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0FFFFF800A6319BD0 resource->worker.task:FFFFE000CDB38300FFFFE0012C7D29A0 |
00000714 00000504 .. [STATE:20]로그는 detaching 상태 변경이 출력됩니다.
| Code Block |
|---|
0000071400000504 10/1326/2020 16:1649:1110.25933392902780 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x2): change_disk_state, disk( UpToDate -> Detaching ) |
00000715 .. [UUID?:19]로그는 detaching 시 대상 복제 볼륨에 설정되어있는 current UUID 가 출력됩니다.
| Code Block |
|---|
0000071500000505 10/1326/2020 16:1649:1110.25933782902819 [finish_state_change] [UUID:19] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x10002): detaching to current UUID: 83F530CA41FA9868CE5CC8B0672E645C 0000071600000506 10/1326/2020 16:1649:1110.25938632903353 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Detaching), dvflag(0x1002): change_disk_state, disk( Detaching -> Diskless ) 0000071700000507 10/1326/2020 16:16:11.2593963 [adm_detach] [GENL:42] bsr_info<6> [0xFFFFE000CCAC4880] wait event interruptible timeout. time out(3000) disk state(Diskless) 00000718 10/13/2020 16:16:11.259915849:10.2909946 [bsr_bm_resize] [BITMAP:23] bsr_info<6> bsr r0/0 minor 2, ds(Diskless), dvflag(0x2): Start resizing the bitmap resizesize to calleddisk withcapacity. capacity sector(0) 0000071900000508 10/1326/2020 16:1649:1110.26011412912038 [bsr_thread_setup] [THREAD:10] bsr_info<6> bsr r0, r(Secondary), f(0x110x1), scf(0x0): Terminating worker thread 0000072000000509 10/1326/2020 16:1649:1110.26015622912489 [mvolWorkThread] [THREAD:20] bsr_info<6> [0xFFFFE000CDC928800xFFFFE0012CBCF880] Terminating mvolWorkThread 0000072100000510 10/1326/2020 16:1649:1110.26038182914483 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAC48800xFFFFE0012B2F9880] bsr netlink cmd(BSR_ADM_DOWN:27) done command execution terminated. (cmd_pending command:0) <- |
동기화
syncsource
다음은 syncsource에서 동기화 시작 출력 로그와 설명입니다.
| Code Block |
|---|
0000059300000322 10/1326/2020 16:1448:0153.52737981027626 [__receive_uuids] [UUID:16] bsr_warn<4> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): receive new current but not update UUID: 7B326D963D9936CEA95D18E8D4AE8C78 0000059400000323 10/1326/2020 16:1448:0153.52738521027665 [bsr_uuid_compare] [RESYNC/OV:202] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20x0): Peer UUID and local bitmap UUID are the same. rule(70), res(2) |
00000595 00000324 .. [RESYNC/OV:73]로그는 연결이 완료되면 로컬 노드와 피어 노드의 UUID 정보 교환을 시작하기 전에 출력됩니다.
| Code Block |
|---|
0000059500000324 10/1326/2020 16:1448:0153.52754421029289 [log_handshake] [RESYNC/OV:73] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): bsr_sync_handshake: |
00000596 00000325 .. [RESYNC/OV:65]로그는 로컬 노드에 설정되어있는 UUID 정보가 출력됩니다.
| Code Block |
|---|
0000059600000325 10/1326/2020 16:1448:0153.52754811029330 [bsr_uuid_dump_self] [RESYNC/OV:65] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): self 83F530CA41FA9869CE5CC8B0672E645D:7B326D963D9936CFA95D18E8D4AE8C78:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:87110 flags:12020 |
00000597 00000326 .. [RESYNC/OV:66]로그는 피어 노드에 설정되어있는 UUID 정보가 출력됩니다.
| Code Block |
|---|
0000059700000326 10/1326/2020 16:1448:0153.52755271029384 [bsr_uuid_dump_peer] [RESYNC/OV:66] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): peer 7B326D963D9936CEA95D18E8D4AE8C78:0000000000000000:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:0 flags:0100 |
00000598 00000327 .. [RESYNC/OV:202],00000599 .. [RESYNC/OV:75]로그는 로컬 노드와 피어 노드의 UUID 비교 후 결과가 출력됩니다.
| Code Block |
|---|
0000059800000327 10/1326/2020 16:1448:0153.52755681029433 [bsr_uuid_compare] [RESYNC/OV:202] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20x0): Peer UUID and local bitmap UUID are the same. rule(70), res(2) 0000059900000328 10/1326/2020 16:1448:0153.52755931029467 [bsr_handshake] [RESYNC/OV:75] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): uuid_compare(2) by rule 70 0000060000000329 10/1326/2020 16:1448:0153.52756341029713 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): receiveReceive new repl state "WFBitMapS" 0000060100000330 10/1326/2020 16:1448:0153.52757811029830 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): receive_state, pdsk( DUnknown -> OutdatedConsistent ) repl( Off -> WFBitMapS ) 0000060200000331 10/1326/2020 16:1448:0153.52774191030835 [bsr_queue_bitmap_io] [RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20x0): send_bitmap (WFBitMapS), worker.task(FFFFE000CDB38300FFFFE0012C7D29A0), current(FFFFE000CDB38300FFFFE0012C7D29A0) 0000060300000332 10/1326/2020 16:1448:0153.52979551048104 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(OutdatedConsistent), prpl(WFBitMapS), pdvflag(0x100600): receiveReceive new repl state "WFBitMapS" |
...
00000333 10/26/2020 16:48:53.1048248 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Consistent), prpl(WFBitMapS), pdvflag(0x100600): receive_state, pdsk( Consistent -> Outdated ) |
00000334 .. [BITMAP:50]로그는 로컬 노드의 비트맵을 피어 노드에 전송 완료 시 출력됩니다.
| Code Block |
|---|
0000060400000334 10/1326/2020 16:1448:0153.52993691049603 [INFO_bm_xfer_stats] [BITMAP:50] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): send bitmap stats [Bytes(packets)]: plain 0(0), RLE 5623(1), total 5623; compression: 100.0% |
00000605 00000335 .. [BITMAP:50]로그는 피어 노드의 비트맵을 로컬 노드가 수신 완료 시 출력됩니다.
| Code Block |
|---|
0000060500000335 10/1326/2020 16:1448:0153.53218291065768 [INFO_bm_xfer_stats] [BITMAP:50] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): receive bitmap stats [Bytes(packets)]: plain 0(0), RLE 5623(1), total 5623; compression: 100.0% |
00000606 00000336 .. [BITMAP:52]로그는 비트맵 교환이 완료되면 출력됩니다.
| Code Block |
|---|
0000060600000336 10/1326/2020 16:1448:0153.53218851065812 [receive_bitmap_finished] [BITMAP:52] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): sendSend that bitmap exchange has been completed 0000060700000337 10/1326/2020 16:1448:0153.53235701066753 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): bsr_start_resync, pdsk( Outdated -> Inconsistent ) repl( WFBitMapS -> SyncSource ) |
00000608 00000338 .. [RESYNC/OV:144]로그는 동기화 시작과 동기화 데이터 크기가 출력됩니다.
| Code Block |
|---|
0000060800000338 10/1326/2020 16:1448:0153.53240871067116 [bsr_start_resync] [RESYNC/OV:144] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): Began resync as SyncSource (will sync 348440 KB [87110 bits set]). 0000060900000339 10/1326/2020 16:1448:0153.53320031087501 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): receiveReceive new repl state "SyncSource" 0000061000000340 10/1326/2020 16:1448:1053.79328171170857 [__receive_uuids] [UUID:16] bsr_warn<4> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): receive new current but not update UUID: 83F530CA41FA9868CE5CC8B0672E645C 0000061100000341 10/1326/2020 16:1448:1053.79328811170913 [bsr_uuid_compare] [RESYNC/OV:197] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20x0): Local and peer current UUIDs are the same. rule(40), res(0) |
다음은 syncsource에서 동기화 완료 로그 출력과 설명입니다.
00000612 00000342 .. [UUID:1]로그는 동기화 완료로 갱신되는 UUID 정보가 출력됩니다.
| Code Block |
|---|
0000061200000342 10/1326/2020 16:1448:1053.79329221170949 [bsr_print_uuids] [UUID:1] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): bsr_uuid_detect_finished_resyncs, updated UUIDs 83F530CA41FA9869CE5CC8B0672E645D:0000000000000000:7B326D963D9936CEA95D18E8D4AE8C78:3DF87D1E1EFC3E92 |
00000613 .. [RESYNC/OV:116]로그는 동기화 진행 시간 및 초당 동기화 속도가 출력됩니다.
| Code Block |
|---|
0000061300000343 10/1326/2020 16:1448:1053.79391341180660 [bsr_resync_finished] [RESYNC/OV:116] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): Resync done (total 91 sec; paused 0 sec; 38680 K/sec), hit bit (in sync 0; marked rl 0) 0000061400000344 10/1326/2020 16:1448:1053.79392951180792 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): bsr_resync_finished, pdsk( Inconsistent -> UpToDate ) repl( SyncSource -> Established ) 0000061500000345 10/1326/2020 16:1448:1053.79402751181716 [bsr_queue_bitmap_io] [RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20x0): write from resync_finished, worker.task(FFFFE000CDB38300FFFFE0012C7D29A0), current(FFFFE000CDB38300FFFFE0012C7D29A0) 0000061600000346 10/1326/2020 16:1448:1053.79419941182718 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): receiveReceive new repl state "Established" |
...
비트맵 교환 과정은 syncsource와 동일합니다.
| Code Block |
|---|
| Code Block |
00000210 10/26/2020 16:48:52.7780270 [bsr_uuid_compare] [RESYNC/OV:198] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20000): The local current UUID is the same as the peer bitmap UUID. rule(50), res(-2) 00000211 10/26/2020 16:1448:0152.37839757780426 [print_state_receive_uuidschange] [UUIDSTATE:1620] bsr_warn<4>info<6> bsr r0/0 minor 2 pnode-id:0, pdskds(DUnknownUpToDate), prpldvflag(Off), pdvflag(0x100200)0x20000): __receive_uuids, newdisk( currentUpToDate but-> notOutdated update UUID: 83F530CA41FA9869 00000085) 00000212 10/1326/2020 16:1448:0152.37844337789223 [log_handshake] [RESYNC/OV:73] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): bsr_sync_handshake: 0000008600000213 10/1326/2020 16:1448:0152.37844847789252 [bsr_uuid_dump_self] [RESYNC/OV:65] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): self 7B326D963D9936CEA95D18E8D4AE8C78:0000000000000000:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:0 flags:0100 0000008700000214 10/1326/2020 16:1448:0152.37845357789291 [bsr_uuid_dump_peer] [RESYNC/OV:66] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): peer 83F530CA41FA9869CE5CC8B0672E645D:7B326D963D9936CFA95D18E8D4AE8C78:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:87110 flags:12020 0000008800000215 10/1326/2020 16:1448:0152.37845897789328 [bsr_uuid_compare] [RESYNC/OV:198] bsr_info<6> bsr r0/0 minor 2, ds(Outdated), dvflag(0x00x20000): The local current UUID is the same as the peer bitmap UUID. rule(50), res(-2) 0000008900000216 10/1326/2020 16:1448:0152.37846267789352 [bsr_handshake] [RESYNC/OV:75] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): uuid_compare(-2) by rule 50 0000009000000217 10/1326/2020 16:1448:0152.37846827789384 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): receiveReceive new repl state "WFBitMapT" 0000009100000218 10/1326/2020 16:1448:0152.37848577789491 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): receive_state, pdsk( DUnknown -> UpToDate ) repl( Off -> WFBitMapT ) 0000009200000219 10/1326/2020 16:1448:0152.37854407790130 [w_after_state_change] [STATE:28] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): notNot sending state because of old replication repl_state(Off) 0000009300000220 10/1326/2020 16:1448:0152.37879837791844 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): receiveReceive new repl state "WFBitMapT" 0000009400000221 10/1326/2020 16:1448:0152.37884177797620 [w_after_state_change] [STATE:28] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): notNot sending state because of old replication repl_state(WFBitMapT) 0000009500000222 10/1326/2020 16:1448:0152.38071807798480 [INFO_bm_xfer_stats] [BITMAP:50] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): receive bitmap stats [Bytes(packets)]: plain 0(0), RLE 5623(1), total 5623; compression: 100.0% 0000009600000223 10/1326/2020 16:1448:0152.38302867815593 [INFO_bm_xfer_stats] [BITMAP:50] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): send bitmap stats [Bytes(packets)]: plain 0(0), RLE 5623(1), total 5623; compression: 100.0% 0000009700000224 10/1326/2020 16:1448:0152.38310407815876 [receive_bm_exchange_state] [BITMAP:44] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): bitmap exchange complete 0000009800000225 10/1326/2020 16:1448:0152.38336617817559 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): receiveReceive new repl state "WFBitMapT" 0000009900000226 10/1326/2020 16:1448:0152.38341757832750 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Outdated), dvflag(0x0): bsr_start_resync, disk( Outdated -> Inconsistent ) 0000010000000227 10/1326/2020 16:1448:0152.38342127832782 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): bsr_start_resync, repl( WFBitMapT -> SyncTarget ) 0000010100000228 10/1326/2020 16:1448:0152.38346827833043 [bsr_start_resync] [RESYNC/OV:144] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): Began resync as SyncTarget (will sync 348440 KB [87110 bits set]). 0000010200000229 10/1326/2020 16:1448:0152.38411757838039 [__receive_uuids] [UUID:16] bsr_warn<4> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): receive new current but not update UUID: 83F530CA41FA9869CE5CC8B0672E645D |
00000103 00000230 .. [RESYNC/OV:109107]로그는 synctarget에서 동기화 데이터 요청을 syncsource에 모두 전송 했을때 출력됩니다.
| Code Block |
|---|
0000010300000230 10/1326/2020 16:1448:1052.63703167915051 [make_resync_request] [RESYNC/OV:109107] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): BSR_END_OF_BITMAP(25786753), device->bm_resync_fo : 2651392, bm_set : 132Finished the resync. resync target area does not exist. |
다음은 synctarget에서 동기화 완료 출력 로그와 설명입니다.
| Code Block |
|---|
0000010400000231 10/1326/2020 16:1448:1052.64365307918471 [bsr_resync_finished] [RESYNC/OV:116] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): Resync done (total 91 sec; paused 0 sec; 38680 K/sec), hit bit (in sync 0; marked rl 0) 0000010500000232 10/1326/2020 16:1448:1052.64366137918549 [bsr_print_uuids] [UUID:1] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): bsr_resync_finished, updated UUIDs 83F530CA41FA9868CE5CC8B0672E645C:0000000000000000:7B326D963D9936CEA95D18E8D4AE8C78:3DF87D1E1EFC3E92 0000010600000233 10/1326/2020 16:1448:1052.64367667918808 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Inconsistent), dvflag(0x20004): bsr_resync_finished, disk( Inconsistent -> UpToDate ) 0000010700000234 10/1326/2020 16:1448:1052.64367967918840 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): bsr_resync_finished, repl( SyncTarget -> Established ) 0000010800000235 10/1326/2020 16:1448:1052.64417817927024 [bsr_queue_bitmap_io] [RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20000): write from resync_finished, worker.task(FFFFE0016F4E7770FFFFE000E4CD8CF0), current(FFFFE0016F4E7770FFFFE000E4CD8CF0) |