...
Code Block |
---|
// 명령 실행 시작 로그 [NETLINK:18] 00000791 10/13/2020 16:18:20.9761914 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_DISCONNECT:11) begin -> 00000792 10/13/2020 16:18:20.9762023 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAFB880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000793 10/13/2020 16:18:20.9762218 [change_cluster_wide_state] [TWOPC:34] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): Preparing cluster-wide state change 2366568536 (0->1 496/16) 00000794 10/13/2020 16:18:20.9762252 [change_cluster_wide_state] [TWOPC:35] 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 [change_cluster_wide_state] [TWOPC:36] 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/2020 16:18:20.9766412 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): State change 2366568536: primary_nodes=0, weak_nodes=0 00000797 10/13/2020 16:18:20.9766463 [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 00000798 10/13/2020 16:18:20.9766497 [change_cluster_wide_state] [TWOPC:39] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): Committing cluster-wide state change 2366568536 (0ms) (0->1) // 연결을 종료를 위한 상태 변경 로그 [STATE:19, 21] 00000799 10/13/2020 16:18:20.9767770 [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 ) 00000800 10/13/2020 16:18:20.9767831 [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 ) 00000801 10/13/2020 16:18:20.9768211 [bsr_recv] [SOCKET:15] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x208): socket data receive error(-15) 00000802 10/13/2020 16:18:20.9768974 [bsr_ack_receiver] [CONNECTION:16] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): ack_receiver terminated 00000803 10/13/2020 16:18:20.9769028 [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 00000804 10/13/2020 16:18:20.9771990 [w_resync_timer] [RESYNC/OV:105] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): completed because it is not in the VerifyS or SyncTarget replication state. 00000805 10/13/2020 16:18:20.9774397 [conn_disconnect] [CONNECTION:9] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Connection closed 00000806 10/13/2020 16:18:20.9774928 [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 ) 00000807 10/13/2020 16:18:20.9775335 [bsr_thread_setup] [THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), scf(0x0): Terminating receiver thread // 명령 실행 완료 로그 [NETLINK:20] 00000808 10/13/2020 16:18:20.9777552 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_DISCONNECT:11) done (cmd_pending:0) <- |
...
up 실행
bsradm up 명령 실행 시 up되는 과정의 로그를 출력합니다.
bsradm up 명령을 실행하면 내부적으로는
BSR_ADM_NEW_RESOURCE
,BSR_ADM_NEW_MINOR
,BSR_ADM_NEW_PEER
,BSR_ADM_NEW_PATH
,BSR_ADM_ATTACH
,BSR_ADM_CONNECT
명령이 실행됩니다.
Code Block |
---|
// up 명령 실행 시 가장 처음 실행되는 BSR_ADM_NEW_RESOURCE 명령 시작 로그 [NETLINK:18] 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.6266252 [bsr_thread_start] [THREAD:12] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x0): Starting worker thread (from not_bsr_thread [0]) // up 명령 실행 시 가장 처음 실행되는 BSR_ADM_NEW_RESOURCE 명령 완료 로그 [NETLINK:20] 00000724 10/13/2020 16:16:12.6268449 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) done (cmd_pending:0) <- 00000725 10/13/2020 16:16:12.6346292 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) begin -> 00000726 10/13/2020 16:16:12.6346651 [bsr_create_device] [VOLUME:10] bsr_info<6> [0xFFFFE000CCAAC040] device(FFFFE000CE6C8890) max sectors(21211136), size(10860101632 bytes) 00000727 10/13/2020 16:16:12.6348421 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) done (cmd_pending:0) <- 00000728 10/13/2020 16:16:12.6430701 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_NEW_PEER:44) begin -> 00000729 10/13/2020 16:16:12.6430889 [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, 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] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x0), scf(0x0): Starting 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.6521598 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_NEW_PATH:45) done (cmd_pending:0) <- // up 명령 실행으로 실행되는 BSR_ADM_NEW_RESOURCE 명령 시작 로그 [NETLINK:18] 00000734 10/13/2020 16:16:12.7033475 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAC4880] bsr netlink cmd(BSR_ADM_ATTACH:12) begin -> 00000735 10/13/2020 16:16:12.7037719 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAC4880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 // attach를 위한 상태 변경 로그 [STATE:20] 00000736 10/13/2020 16:16:12.7037883 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Diskless), dvflag(0x0): change_disk_state, disk( Diskless -> Attaching ) 00000737 10/13/2020 16:16:12.7038382 [FsctlLockVolume] [VOLUME:20] bsr_info<6> [0xFFFFE000CCAC4880] no lock. volume(\Device\HarddiskVolume2) already dismounted 00000738 10/13/2020 16:16:12.7038414 [FsctlFlushDismountVolume] [VOLUME:15] bsr_info<6> [0xFFFFE000CCAC4880] no dismount. volume(\Device\HarddiskVolume2) already dismounted 00000739 10/13/2020 16:16:12.7038441 [FsctlUnlockVolume] [VOLUME:24] bsr_info<6> [0xFFFFE000CCAC4880] volume(\Device\HarddiskVolume2) not locked 00000740 10/13/2020 16:16:12.7038460 [bsr_adm_attach] [GENL:36] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Maximum number of bitmap peer devices 1 00000741 10/13/2020 16:16:12.7047859 [bsr_bump_write_ordering] [VOLUME:66] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x1): Method to ensure write ordering: drain 00000742 10/13/2020 16:16:12.7047891 [get_max_agreeable_size] [GENL:16] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): local node_id: 0 00000743 10/13/2020 16:16:12.7047913 [get_max_agreeable_size] [GENL:17] 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/2020 16:16:12.7048103 [get_max_agreeable_size] [GENL:16] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): local node_id: 0 00000745 10/13/2020 16:16:12.7048123 [get_max_agreeable_size] [GENL:17] 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) // 비트맵 사이즈 로그 [BITMAP:23,25] 00000746 10/13/2020 16:16:12.7048159 [bsr_bm_resize] [BITMAP:23] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): bitmap resize called with capacity(21211136) 00000747 10/13/2020 16:16:12.7054015 [bsr_bm_resize] [BITMAP:25] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): resize bitmap, bits(2651392) words(82856) pages(81) // 복제 볼륨 디스크 사이즈 로그 [GENL:13] 00000748 10/13/2020 16:16:12.7054054 [bsr_determine_dev_size] [GENL:13] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): Update disk size 10 GB (10605568 KB) 00000749 10/13/2020 16:16:12.7092993 [bm_rw_range] [BITMAP:29] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): recounting of set bits took additional 1ms 00000750 10/13/2020 16:16:12.7093079 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAC4880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 // attach 완료 상태 변경 로그 [STATE:20] 00000751 10/13/2020 16:16:12.7093240 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): change_disk_state, disk( Attaching -> UpToDate ) // attach 시 반영되어 있는 current UUID 정보 [UUID:14] 00000752 10/13/2020 16:16:12.7093288 [finish_state_change] [UUID:14] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): attached to current UUID: 83F530CA41FA9868 // up 명령 실행으로 실행되는 BSR_ADM_NEW_RESOURCE 명령 완료 로그 [NETLINK:20] 00000753 10/13/2020 16:16:12.7097657 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAC4880] bsr netlink cmd(BSR_ADM_ATTACH:12) done (cmd_pending:0) <- // up 명령 실행 시 가장 마지막으로 실행되는 BSR_ADM_CONNECT 명령 시작 로그 [NETLINK:18] // BSR_ADM_CONNECT은 이전에 작성한 connect 명령 실행 참고 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/2020 16:16:12.7186894 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CCAAC040] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000756 10/13/2020 16:16:12.7187102 [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 ) // up 명령 실행 시 가장 마지막으로 실행되는 BSR_ADM_CONNECT 명령 완료 로그 [NETLINK:20] 00000757 10/13/2020 16:16:12.7189150 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_CONNECT:10) done (cmd_pending:0) <- 00000758 10/13/2020 16:16:12.7190322 [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 [2108]) 00000759 10/13/2020 16:16:12.7191149 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CDDA5880] worker should not initiate state changes with CS_SERIALIZE current:FFFFE000CE0F9170 resource->worker.task:FFFFE000CDE0B820 00000760 10/13/2020 16:16:12.7191349 [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 ) 00000761 10/13/2020 16:16:15.7224848 [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 00000762 10/13/2020 16:16:15.7224916 [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. 00000763 10/13/2020 16:16:15.7227332 [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 00000764 10/13/2020 16:16:15.7227437 [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 [2808]) 00000765 10/13/2020 16:16:15.7770404 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CDA1A040] worker should not initiate state changes with CS_SERIALIZE current:FFFFE000CDAA58C0 resource->worker.task:FFFFE000CDE0B820 00000766 10/13/2020 16:16:15.7770628 [change_cluster_wide_state] [TWOPC:34] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): Preparing cluster-wide state change 1853056548 (0->1 499/146) 00000767 10/13/2020 16:16:15.7770664 [change_cluster_wide_state] [TWOPC:35] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:1853056548] target_node_id(1) conn(Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) flags (2058) 00000768 10/13/2020 16:16:15.7776058 [change_cluster_wide_state] [TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:1853056548] target_node_id(1) get_cluster_wide_reply (3) 00000769 10/13/2020 16:16:15.7776109 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): State change 1853056548: primary_nodes=0, weak_nodes=0 00000770 10/13/2020 16:16:15.7776145 [change_cluster_wide_state] [TWOPC:39] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): Committing cluster-wide state change 1853056548 (1ms) (0->1) 00000771 10/13/2020 16:16:15.7778471 [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 ) 00000772 10/13/2020 16:16:15.7779527 [receive_SyncParam] [PROTOCOL:29] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): 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 00000773 10/13/2020 16:16:15.7781260 [receive_sizes] [PROTOCOL:32] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): current_mydisk_size: 10860101632 bytes 00000774 10/13/2020 16:16:15.7781292 [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 00000775 10/13/2020 16:16:15.7781334 [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 00000776 10/13/2020 16:16:15.7781365 [get_max_agreeable_size] [GENL:16] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): local node_id: 0 00000777 10/13/2020 16:16:15.7781387 [get_max_agreeable_size] [GENL:17] 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) 00000778 10/13/2020 16:16:15.7781429 [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 00000779 10/13/2020 16:16:15.7782072 [get_max_agreeable_size] [GENL:16] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): local node_id: 0 00000780 10/13/2020 16:16:15.7782109 [get_max_agreeable_size] [GENL:17] 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 명령 실행 시 down되는 과정의 로그를 출력합니다.
down 과정은 볼륨 lock, 볼륨 flush, 볼륨 dismount, 연결 종료, 디스크 제거 순서로 실행됩니다.
...