Versions Compared

Old Version 53

changes.mady.by.user SungEun Kim

Saved on

compared with

New Version Current

changes.mady.by.user SungEun Kim

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

개별 동작에 따라 발생하는 일련의 로그 패턴들에 대해 분석하고 설명합니다.

동작

Info

예로 든 로그 메시지들은 windwos bsr 1.6.1 버전을 버전의 로그를 기준으로 합니다.

드라이버 기동

다음은 windows 에서 bsr 커널 드라이버가 기동할 때의 로그 입니다.

...

Code Block
00000018 10/26/2020 16:25:03.2195574 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_NEW_RESOURCE:7 command has been received. Execute the command.
...//명령 수행
00000020 10/26/2020 16:25:03.2197637 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_NEW_RESOURCE:7 command execution terminated. (pending command:0)

00000021 10/26/2020 16:25:03.2278267 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012A786040] BSR_ADM_NEW_MINOR:5 command has been received. Execute the command.
...//명령 수행
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.
...//명령 수행
00000027 10/26/2020 16:25:03.2354514 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_NEW_PEER:44 command execution terminated. (pending command:0)

00000028 10/26/2020 16:25:03.2442056 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012A786040] BSR_ADM_NEW_PATH:45 command has been received. Execute the command.
...//명령 수행
00000029 10/26/2020 16:25:03.2444816 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012A786040] 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.
...//명령 수행
00000055 10/26/2020 16:25:03.3033626 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B2FC880] BSR_ADM_ATTACH:12 command execution terminated. (pending command:0)

00000056 10/26/2020 16:25:03.3136502 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B2F9880] BSR_ADM_CONNECT:10 command has been received. Execute the command.
...//명령 수행
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)

connect

...

  • connect 명령을 수행했을 때의 시작 로그입니다.

Code Block
00000056 10/26/2020 16:25:03.3136502 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B2F9880] BSR_ADM_CONNECT:10 command has been received. Execute the command.
00000057 10/26/2020 16:25:03.3136604 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012B2F9880] Worker should not initiate state changes with CS_SERIALIZE current:FFFFF800A6319BD0 resource->worker.task:FFFFE0012C513C60
00000058 10/26/2020 16:25:03.3136765 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x0), scf(0x2a): bsr_adm_connect, conn( StandAlone -> Unconnected )
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 [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(Unconnected), prole(Unknown), cflag(0x0), scf(0x2a): conn_connect, conn( Unconnected -> Connecting )

...

Code Block
00000077 10/26/2020 16:25:06.3396215 [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
00000078 10/26/2020 16:25:06.3396295 [get_max_agreeable_size] [VOLUME:98] 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)
00000079 10/26/2020 16:25:06.3396358 [get_max_agreeable_size] [VOLUME:99] 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)
00000080 10/26/2020 16:25:06.3396463 [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
00000081 10/26/2020 16:25:06.3397114 [get_max_agreeable_size] [VOLUME:98] 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)
00000082 10/26/2020 16:25:06.3397234 [get_max_agreeable_size] [VOLUME:99] 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

...

  • disconnect 명령의 시작 로그 입니다.

Code Block
00000093 10/26/2020 16:37:52.2808432 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [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:34] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): Preparing cluster-wide state change 3319182627 (0->1 496/16)
00000096 10/26/2020 16:37:52.2808878 [change_cluster_wide_state] [TWOPC:35] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC:3319182627] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 
00000097 10/26/2020 16:37:52.2812432 [change_cluster_wide_state] [TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC:3319182627] target_node_id(1) get_cluster_wide_reply (3) 
00000098 10/26/2020 16:37:52.2812481 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): State change 3319182627: primary_nodes=0, weak_nodes=0
00000099 10/26/2020 16:37:52.2812511 [change_cluster_wide_state] [TWOPC:38] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x28): Cluster is now split
00000100 10/26/2020 16:37:52.2812540 [change_cluster_wide_state] [TWOPC:39] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): Committing cluster-wide state change 3319182627 (1ms) (0->1)

...

Code Block
00000101 10/26/2020 16:37:52.2813798 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x208): conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown )
00000102 10/26/2020 16:37:52.2813842 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): conn_try_disconnect, pdsk( UpToDate -> DUnknown ) repl( Established -> Off )
00000103 10/26/2020 16:37:52.2814295 [bsr_recv] [SOCKET:15] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x208): Data stream socket receive error(-15)
00000104 10/26/2020 16:37:52.2814897 [bsr_ack_receiver] [CONNECTION:16] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): ack_receiver terminated
00000105 10/26/2020 16:37:52.2814968 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Terminating ack_recv thread
00000106 10/26/2020 16:37:52.2817384 [w_resync_timer] [RESYNC/OV:105] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): The resync is complete because it is not in VerifyS or SyncTarget replication state.
00000107 10/26/2020 16:37:52.2820403 [conn_disconnect] [CONNECTION:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Connection closed
00000108 10/26/2020 16:37:52.2820944 [print_state_change] [STATE:19] bsr_info<6> bsr r0 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_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), scf(0x0): Terminating receiver thread
00000110 10/26/2020 16:37:52.2823823 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_DISCONNECT: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:25:03.2195574 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_NEW_RESOURCE:7 command has been received. Execute the command.
00000019 10/26/2020 16:25:03.2195696 [bsr_thread_start] [THREAD:12] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x0): Starting worker thread (from not_bsr_thread [0])
00000020 10/26/2020 16:25:03.2197637 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B69D880] BSR_ADM_NEW_RESOURCE:7 command execution terminated. (pending command:0)
00000021 10/26/2020 16:25:03.2278267 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012A786040] BSR_ADM_NEW_MINOR:5 command has been received. Execute the command.
00000022 10/26/2020 16:25:03.2278667 [bsr_create_device] [VOLUME:10] bsr_info<6> [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, pdsk(DUnknown), prpl(Off), pdvflag(0x0): default 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
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> [0xFFFFE0012B69D880] BSR_ADM_NEW_PEER:44 command execution terminated. (pending command:0)
00000028 10/26/2020 16:25:03.2442056 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012A786040] BSR_ADM_NEW_PATH:45 command has been received. Execute the command.
00000029 10/26/2020 16:25:03.2444816 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012A786040] 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:25:03.2889320 [state_change_lock] [STATE:40] 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 )
00000033 10/26/2020 16:25:03.2890049 [FsctlLockVolume] [VOLUME:65] bsr_info<6> [0xFFFFE0012B2FC880] try lock volume(\Device\HarddiskVolume2)
00000034 10/26/2020 16:25:03.2959696 [FsctlLockVolume] [VOLUME:23] bsr_info<6> [0xFFFFE0012B2FC880] volume(\Device\HarddiskVolume2) locked. handle(0xFFFFFFFF80000AFC)
00000035 10/26/2020 16:25:03.2959798 [FsctlFlushDismountVolume] [VOLUME:62] bsr_info<6> [0xFFFFE0012B2FC880] try flush volume(\Device\HarddiskVolume2)
00000036 10/26/2020 16:25:03.2959854 [FsctlFlushDismountVolume] [VOLUME:17] bsr_info<6> [0xFFFFE0012B2FC880] Failed to flush volume. status(0xc000026e)
00000037 10/26/2020 16:25:03.2959874 [FsctlFlushDismountVolume] [VOLUME:63] bsr_info<6> [0xFFFFE0012B2FC880] volume(\Device\HarddiskVolume2) flushed
00000038 10/26/2020 16:25:03.2959893 [FsctlFlushDismountVolume] [VOLUME:64] bsr_info<6> [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:25:03.2965979 [FsctlUnlockVolume] [VOLUME:61] bsr_info<6> [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:25:03.2969738 [bsr_adm_attach] [GENL:36] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): The maximum number of bitmap peer devices is 1.
00000043 10/26/2020 16:25:03.2979413 [bsr_bump_write_ordering] [VOLUME:66] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x1): Method to ensure write ordering: drain
00000044 10/26/2020 16:25:03.2979447 [get_max_agreeable_size] [VOLUME:98] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Skip the replication volume size comparison because it is a local node id(0)
00000045 10/26/2020 16:25:03.2979474 [get_max_agreeable_size] [VOLUME:99] 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)
00000046 10/26/2020 16:25:03.2979681 [get_max_agreeable_size] [VOLUME:98] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Skip the replication volume size comparison because it is a local node id(0)
00000047 10/26/2020 16:25:03.2979705 [get_max_agreeable_size] [VOLUME:99] 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)
00000048 10/26/2020 16:25:03.2979742 [bsr_bm_resize] [BITMAP:23] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Start resizing the bitmap size to disk capacity. capacity sector(21211136)
00000049 10/26/2020 16:25:03.2985588 [bsr_bm_resize] [BITMAP:25] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): The bitmap size has been resized to disk capacity. bits(2651392) words(82856) pages(81)

  • 00000050 .. [VOLUME:96] attach 대상 복제 디스크의 볼륨의 크기가 출력됩니다.

Code Block
00000050 10/26/2020 16:25:03.2985622 [bsr_determine_dev_size] [VOLUME:96] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Update the disk size in the meta. 10 GB (10605568 KB)
00000051 10/26/2020 16:25:03.3028170 [bm_rw_range] [BITMAP:29] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Recounting of set bits took additional 0ms
00000052 10/26/2020 16:25:03.3028240 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012B2FC880] Worker should not initiate state changes with CS_SERIALIZE current:FFFFF800A6319BD0 resource->worker.task:FFFFE0012C513C60
00000053 10/26/2020 16:25:03.3028465 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): change_disk_state, disk( Attaching -> UpToDate )

  • 00000054 .. [UUID:14] attach 대상 복제 디스크의 볼륨의 current UUID가 출력됩니다.

Code Block
00000054 10/26/2020 16:25:03.3028511 [finish_state_change] [UUID:14] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): attached to current UUID: A95D18E8D4AE8C78
00000055 10/26/2020 16:25:03.3033626 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B2FC880] BSR_ADM_ATTACH:12 command execution terminated. (pending command:0)

...

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 [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(Unconnected), prole(Unknown), cflag(0x0), scf(0x2a): conn_connect, conn( Unconnected -> Connecting )
00000063 10/26/2020 16:25:06.3224961 [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
00000064 10/26/2020 16:25:06.3225110 [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.
00000065 10/26/2020 16:25:06.3231473 [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
00000066 10/26/2020 16:25:06.3231590 [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 [1700])
00000067 10/26/2020 16:25:06.3374818 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012CBD2040] Worker should not initiate state changes with CS_SERIALIZE current:FFFFE0012C7CCC20 resource->worker.task:FFFFE0012C513C60
00000068 10/26/2020 16:25:06.3375354 [change_cluster_wide_state] [TWOPC:34] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): Preparing cluster-wide state change 177619259 (0->1 499/146)
00000069 10/26/2020 16:25:06.3375466 [change_cluster_wide_state] [TWOPC:35] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:177619259] target_node_id(1) conn(Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) flags (2058) 
00000070 10/26/2020 16:25:06.3384621 [change_cluster_wide_state] [TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): [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, 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 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 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 10/26/2020 16:25:06.3396005 [receive_sizes] [PROTOCOL:32] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): current_mydisk_size: 10860101632 bytes
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(0x0): peer_current_size: 10860101632 bytes peer_user_size: 0 bytes peer_disk_size: 10860101632 bytes peer_max_size: 10860101632 bytes
00000077 10/26/2020 16:25:06.3396215 [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
00000078 10/26/2020 16:25:06.3396295 [get_max_agreeable_size] [VOLUME:98] 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)
00000079 10/26/2020 16:25:06.3396358 [get_max_agreeable_size] [VOLUME:99] 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)
00000080 10/26/2020 16:25:06.3396463 [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
00000081 10/26/2020 16:25:06.3397114 [get_max_agreeable_size] [VOLUME:98] 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)
00000082 10/26/2020 16:25:06.3397234 [get_max_agreeable_size] [VOLUME:99] 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)

down

다음은 bsradm down 명령 실행 시 로그와 설명입니다명령에서 순차적으로 수행하는 개별 동작 로그에 대해 설명합니다.

Info

bsradm down 명령은 볼륨 lock, 볼륨 flush, 볼륨 down 은 리소스를 볼륨에 대한 베타적 락 획득, Flush, dismount, 연결 종료해제, 볼륨 잠금 잠금의 순서로 실행됩니다수행합니다.

Code Block
00000398 10/26/2020 16:49:10.2436929 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE0012B2F9880] BSR_ADM_DOWN:27 command has been received. Execute the command.

  • 00000399 .. [VOLUME:65], 00000680 .. [VOLUME:23] 로그들은 복제 볼륨 베타적 락 획득 시 출력됩니다볼륨에 대한 베타적 락 획득을 시도합니다. 베타적 락이 다른 프로세스에 의해 이미 획득된 상태이면 이 시도는 실패할 수 있습니다. 이 시도가 실패되더라도 무시하고 다음 단계로 넘어갑니다.

Code Block
00000399 10/26/2020 16:49:10.2437390 [FsctlLockVolume] [VOLUME:65] bsr_info<6> [0xFFFFE0012B2F9880] try lock volume(\Device\HarddiskVolume2)
00000472 10/26/2020 16:49:10.2864430 [FsctlLockVolume] [VOLUME:23] bsr_info<6> [0xFFFFE0012B2F9880] volume(\Device\HarddiskVolume2) locked. handle(0xFFFFFFFF80000C20)

  • 00000473 .. [VOLUME:62], 00000474 .. [VOLUME:63] 로그들은 복제 볼륨 flush 시 출력됩니다볼륨에 대한 캐쉬 flush 를 수행합니다.

Code Block
00000473 10/26/2020 16:49:10.2864535 [FsctlFlushDismountVolume] [VOLUME:62] bsr_info<6> [0xFFFFE0012B2F9880] try flush volume(\Device\HarddiskVolume2)
00000474 10/26/2020 16:49:10.2864915 [FsctlFlushDismountVolume] [VOLUME:63] bsr_info<6> [0xFFFFE0012B2F9880] volume(\Device\HarddiskVolume2) flushed

  • 00000475 .. [VOLUME:64], 00000476 .. [VOLUME:19] 로그들은 복제 볼륨 dismount 실행 시 출력됩니다를 수행합니다.

Code Block
00000475 10/26/2020 16:49:10.2864954 [FsctlFlushDismountVolume] [VOLUME:64] bsr_info<6> [0xFFFFE0012B2F9880] try dismount volume(\Device\HarddiskVolume2)
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:34] bsr_info<6> bsr r0, r(Secondary), f(0x1), scf(0x28): Preparing cluster-wide state change 1805107054 (0->1 496/16)
00000487 10/26/2020 16:49:10.2890209 [change_cluster_wide_state] [TWOPC:35] bsr_info<6> bsr r0, r(Secondary), f(0x1), scf(0x28): [TWOPC:1805107054] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 
00000488 10/26/2020 16:49:10.2893052 [change_cluster_wide_state] [TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x1), scf(0x28): [TWOPC:1805107054] target_node_id(1) get_cluster_wide_reply (3) 
00000489 10/26/2020 16:49:10.2893089 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x1), scf(0x28): State change 1805107054: primary_nodes=0, weak_nodes=0
00000490 10/26/2020 16:49:10.2893113 [change_cluster_wide_state] [TWOPC:38] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x28): Cluster is now split
00000491 10/26/2020 16:49:10.2893140 [change_cluster_wide_state] [TWOPC:39] bsr_info<6> bsr r0, r(Secondary), f(0x1), scf(0x28): Committing cluster-wide state change 1805107054 (1ms) (0->1)
00000492 10/26/2020 16:49:10.2895017 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x208): conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown )
00000493 10/26/2020 16:49:10.2895061 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): conn_try_disconnect, pdsk( UpToDate -> DUnknown ) repl( Established -> Off )
00000494 10/26/2020 16:49:10.2895371 [bsr_recv] [SOCKET:15] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x208): Data stream socket receive error(-15)
00000495 10/26/2020 16:49:10.2895990 [bsr_ack_receiver] [CONNECTION:16] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): ack_receiver terminated
00000496 10/26/2020 16:49:10.2896039 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Terminating ack_recv thread
00000497 10/26/2020 16:49:10.2897546 [w_resync_timer] [RESYNC/OV:105] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): The resync is complete because it is not in VerifyS or SyncTarget replication state.
00000498 10/26/2020 16:49:10.2900523 [conn_disconnect] [CONNECTION:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Connection closed
00000499 10/26/2020 16:49:10.2900922 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x23): conn_disconnect, conn( Disconnecting -> StandAlone )
00000500 10/26/2020 16:49:10.2901181 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), scf(0x0): Terminating receiver thread
00000501 10/26/2020 16:49:10.2901744 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), scf(0x0): Terminating sender thread
00000502 10/26/2020 16:49:10.2902522 [bsr_destroy_connection] [CONNECTION:1] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x110e), scf(0x0): The connection object is removed.
00000503 10/26/2020 16:49:10.2902683 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE0012B2F9880] Worker should not initiate state changes with CS_SERIALIZE current:FFFFF800A6319BD0 resource->worker.task:FFFFE0012C7D29A0

  • 00000504 .. [STATE:20] 로그는 detaching 상태 변경이 출력됩니다.

Code Block
00000504 10/26/2020 16:49:10.2902780 [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
00000505 10/26/2020 16:49:10.2902819 [finish_state_change] [UUID:19] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x10002): detaching to current UUID: CE5CC8B0672E645C
00000506 10/26/2020 16:49:10.2903353 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Detaching), dvflag(0x1002): change_disk_state, disk( Detaching -> Diskless )
00000507 10/26/2020 16:49:10.2909946 [bsr_bm_resize] [BITMAP:23] bsr_info<6> bsr r0/0 minor 2, ds(Diskless), dvflag(0x2): Start resizing the bitmap size to disk capacity. capacity sector(0)
00000508 10/26/2020 16:49:10.2912038 [bsr_thread_setup] [THREAD:10] bsr_info<6> bsr r0, r(Secondary), f(0x1), scf(0x0): Terminating worker thread
00000509 10/26/2020 16:49:10.2912489 [mvolWorkThread] [THREAD:20] bsr_info<6> [0xFFFFE0012CBCF880] Terminating mvolWorkThread
00000510 10/26/2020 16:49:10.2914483 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE0012B2F9880] BSR_ADM_DOWN:27 command execution terminated. (pending command:0)

동기화

syncsource

다음은 syncsource에서 syncsource 의 동기화 시작 로그와 설명입니다로그입니다.

Code Block
00000322 10/26/2020 16:48:53.1027626 [__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: A95D18E8D4AE8C78
00000323 10/26/2020 16:48:53.1027665 [bsr_uuid_compare] [RESYNC/OV:202] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Peer UUID and local bitmap UUID are the same. rule(70), res(2)

  • 00000324 .. [RESYNC/OV:73] 로그는 연결이 완료되면 로컬 노드와 피어 노드의 UUID 정보 교환을 시작하기 전에 출력됩니다동기화 핸드쉐이크를 시작합니다.

Code Block
00000324 10/26/2020 16:48:53.1029289 [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:

  • 00000325 .. [RESYNC/OV:65] 로그는 로컬 노드에 설정되어있는 UUID 정보가 로컬의 UUID가 출력됩니다.

Code Block
00000325 10/26/2020 16:48:53.1029330 [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 CE5CC8B0672E645D:A95D18E8D4AE8C78:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:0 flags:20

  • 00000326 .. [RESYNC/OV:66] 로그는 피어 노드에 설정되어있는 UUID 정보가 피어의 UUID가 출력됩니다.

Code Block
00000326 10/26/2020 16:48:53.1029384 [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 A95D18E8D4AE8C78:0000000000000000:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:0 flags:100

  • 00000327 .. [RESYNC/OV:202], 00000599 .. [RESYNC/OV:75] 로그는 로컬 노드와 피어 노드의 UUID 비교 후 로컬과 피어의 uuid compare 결과가 출력됩니다.

Code Block
00000327 10/26/2020 16:48:53.1029433 [bsr_uuid_compare] [RESYNC/OV:202] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Peer UUID and local bitmap UUID are the same. rule(70), res(2)
00000328 10/26/2020 16:48:53.1029467 [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
00000329 10/26/2020 16:48:53.1029713 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): Receive new repl state "WFBitMapS"
00000330 10/26/2020 16:48:53.1029830 [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 -> Consistent ) repl( Off -> WFBitMapS )
00000331 10/26/2020 16:48:53.1030835 [bsr_queue_bitmap_io] [RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): send_bitmap (WFBitMapS), worker.task(FFFFE0012C7D29A0), current(FFFFE0012C7D29A0)
00000332 10/26/2020 16:48:53.1048104 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Consistent), prpl(WFBitMapS), pdvflag(0x100600): Receive 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
00000334 10/26/2020 16:48:53.1049603 [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 23(1), total 23; compression: 100.0%

  • 00000335 .. [BITMAP:50] 로그는 피어 노드의 비트맵을 로컬 노드가 비트맵이 로컬에서 수신 완료 시 출력됩니다되었습니다.

Code Block
00000335 10/26/2020 16:48:53.1065768 [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 23(1), total 23; compression: 100.0%

  • 00000336 .. [BITMAP:52] 로그는 비트맵 교환이 완료되면 출력됩니다완료되었습니다.

Code Block
00000336 10/26/2020 16:48:53.1065812 [receive_bitmap_finished] [BITMAP:52] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): Send that bitmap exchange has been completed
00000337 10/26/2020 16:48:53.1066753 [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 )

  • 00000338 .. [RESYNC/OV:144] 로그는 동기화가 시작되고 동기화 시작과 동기화 해야할 데이터 크기가 출력됩니다.

Code Block
00000338 10/26/2020 16:48:53.1067116 [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 0 KB [0 bits set]).
00000339 10/26/2020 16:48:53.1087501 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): Receive new repl state "SyncSource"
00000340 10/26/2020 16:48:53.1170857 [__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: CE5CC8B0672E645C
00000341 10/26/2020 16:48:53.1170913 [bsr_uuid_compare] [RESYNC/OV:197] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): Local and peer current UUIDs are the same. rule(40), res(0)

다음은 syncsource에서 동기화 완료 로그 출력과 설명입니다.

  • 00000342 .. [UUID:1] 로그는 동기화 완료로 갱신되는 동기화 완료 후 새로 지정되는 UUID 정보가 출력됩니다.

Code Block
00000342 10/26/2020 16:48:53.1170949 [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 CE5CC8B0672E645D:0000000000000000:A95D18E8D4AE8C78:3DF87D1E1EFC3E92

  • 00000613 .. [RESYNC/OV:116] 로그는 동기화 완료 후 동기화 진행 시간 및 초당 동기화 속도가 출력됩니다.

Code Block
00000343 10/26/2020 16:48:53.1180660 [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 1 sec; paused 0 sec; 0 K/sec), hit bit (in sync 0; marked rl 0)
00000344 10/26/2020 16:48:53.1180792 [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 )
00000345 10/26/2020 16:48:53.1181716 [bsr_queue_bitmap_io] [RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): write from resync_finished, worker.task(FFFFE0012C7D29A0), current(FFFFE0012C7D29A0)
00000346 10/26/2020 16:48:53.1182718 [receive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), prpl(Established), pdvflag(0x100600): Receive new repl state "Established"

synctarget

다음은 synctarget에서 동기화 시작 로그와 설명입니다로그입니다.

Info

syncsource와 중복되는 로그는 설명하지 않습니다.

...

  • 00000230 .. [RESYNC/OV:107] 로그는 synctarget에서 동기화 데이터 요청을 syncsource에 모두 전송 했을때 출력됩니다.

Code Block
00000230 10/26/2020 16:48:52.7915051 [make_resync_request] [RESYNC/OV:107] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): Finished the resync. resync target area does not exist.

  • 다음은

...

  • synctarget의 동기화 완료

...

  • 로그입니다.

Code Block
00000231 10/26/2020 16:48:52.7918471 [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 1 sec; paused 0 sec; 0 K/sec), hit bit (in sync 0; marked rl 0)
00000232 10/26/2020 16:48:52.7918549 [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 CE5CC8B0672E645C:0000000000000000:A95D18E8D4AE8C78:3DF87D1E1EFC3E92
00000233 10/26/2020 16:48:52.7918808 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Inconsistent), dvflag(0x20004): bsr_resync_finished, disk( Inconsistent -> UpToDate )
00000234 10/26/2020 16:48:52.7918840 [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 )
00000235 10/26/2020 16:48:52.7927024 [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(FFFFE000E4CD8CF0), current(FFFFE000E4CD8CF0)

...