...
| Code Block |
|---|
00000001 10/13/2020 1416:4709:5603.5551143958 [initRegistrywait_for_add_device] WDRBD_INFO<6>[0xFFFFE001458BC880[LOG:10] registrybsr_path[\Registry\Machine\System\CurrentControlSet\Services\drbd] bypass_level=0, read_filter=0, use_volume_lock=1, netlink_tcp_port=5678, daemon_tcp_port=5679, ver=1.5info<6> [0xFFFFE000CBDC1880] Wait for device to be connected for log file generation.(C:\Program Files\bsr) 00000002 10/13/2020 1416:4709:5603.5551144175 [drbd_init] WDRBD_INFO<6>..\drbd\drbd_main.c: initialized. Version: 9.0.6 (api:2/proto:86-113) 00000003 10/13/2020 14:47:56.555 [drbd_init] WDRBD_INFO<6>..\drbd\drbd_main.c: 00000004 10/13/2020 14:47:56.555 [drbd_init] WDRBD_INFO<6>..\drbd\drbd_main.c: registered as block device major 147 00000005 10/13/2020 14:47:56.555 [DriverEntry] WDRBD_INFO<6>[0xFFFFE001458BC880] MVF Driver loaded. |
cli command
| Code Block |
|---|
00000087 10/13/2020 14:50:50.598 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00146877040] drbd netlink cmd(DRBD_ADM_DOWN:27) begin ->
00000116 10/13/2020 14:50:50.598 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00146877040] drbd netlink cmd(DRBD_ADM_DOWN:27) done (cmd_pending:0) <-
00000117 10/13/2020 14:51:34.520 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00146877040] drbd netlink cmd(DRBD_ADM_NEW_RESOURCE:7) begin ->
00000119 10/13/2020 14:51:34.520 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00146877040] drbd netlink cmd(DRBD_ADM_NEW_RESOURCE:7) done (cmd_pending:0) <-
00000120 10/13/2020 14:51:34.535 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014688B880] drbd netlink cmd(DRBD_ADM_NEW_MINOR:5) begin ->
00000122 10/13/2020 14:51:34.535 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014688B880] drbd netlink cmd(DRBD_ADM_NEW_MINOR:5) done (cmd_pending:0) <- <- |
state change
| Code Block |
|---|
00000048 10/13/2020 14:48:17.644 [print_state_change] WDRBD_INFO<6>drbd r0/0 minor 2, ds(Attaching), dvflag(0x0): change_disk_state, disk( Attaching -> UpToDate ) 00000057 10/13/2020 14:48:17.660 [print_state_change] WDRBD_INFO<6>drbd r0 pnode-id:1, cs(Unconnected), prole(Unknown), cflag(0x0), scf(0x2a): conn_connect, conn( Unconnected -> Connecting ) 00000248 10/13/2020 14:53:50.473 [print_state_change] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0xa1c): change_role, role( Secondary -> Primary ) 00000254 10/13/2020 14:53:50.473 [print_state_change] WDRBD_INFO<6>drbdinitRegistry] [DRIVER:63] bsr_info<6> [0xFFFFE000CBABD880] registry_path[\Registry\Machine\System\CurrentControlSet\Services\bsr] 00000003 10/13/2020 16:09:03.1144212 [initRegistry] [DRIVER:64] bsr_info<6> [0xFFFFE000CBABD880] bypass_level=0, read_filter=0, use_volume_lock=1, netlink_tcp_port=5678, daemon_tcp_port=5679, ver=1.5 00000004 10/13/2020 16:09:03.1144826 [bsr_init] [DRIVER:77] bsr_info<6> [0xFFFFE000CBABD880] initialized. Version: 1.6-A4 (api:2/proto:86-114) 00000005 10/13/2020 16:09:03.1144850 [bsr_init] [DRIVER:78] bsr_info<6> [0xFFFFE000CBABD880] 1.6(2020.9.01_A4) GIT-hash: f52eea3 build by DEV3-KBLD+Administrator@dev3-kbld, Tue Sep 1 15:19:41 2020 00000006 10/13/2020 16:09:03.1144868 [bsr_init] [DRIVER:79] bsr_info<6> [0xFFFFE000CBABD880] registered as block device major 147 |
cli command
| Code Block |
|---|
00000018 10/13/2020 16:09:29.0058164 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAA5040] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) begin ->
00000020 10/13/2020 16:09:29.0612210 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAA5040] bsr netlink cmd(BSR_ADM_NEW_RESOURCE:7) done (cmd_pending:0) <-
00000021 10/13/2020 16:09:29.0902772 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAC4880] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) begin ->
00000023 10/13/2020 16:09:29.0906385 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAC4880] bsr netlink cmd(BSR_ADM_NEW_MINOR:5) done (cmd_pending:0) <-
00000024 10/13/2020 16:09:29.1011907 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAA5040] bsr netlink cmd(BSR_ADM_NEW_PEER:44) begin ->
00000027 10/13/2020 16:09:29.1014684 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAA5040] bsr netlink cmd(BSR_ADM_NEW_PEER:44) done (cmd_pending:0) <-
00000028 10/13/2020 16:09:29.1124180 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CC6EF880] bsr netlink cmd(BSR_ADM_NEW_PATH:45) begin ->
00000029 10/13/2020 16:09:29.1140515 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CC6EF880] bsr netlink cmd(BSR_ADM_NEW_PATH:45) done (cmd_pending:0) <-
|
state change
| Code Block |
|---|
00000053 10/13/2020 16:09:29.3583295 [print_state_change] [STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Attaching), dvflag(0x0): change_disk_state, disk( Attaching -> UpToDate )
00000091 10/13/2020 16:09:48.2615732 [print_state_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): receive_state, pdsk( DUnknown -> UpToDate ) repl( Off -> Established )
00000099 10/13/2020 16:10:14.3457504 [print_state_change] [STATE:18] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0xa1c): change_role, role( Secondary -> Primary )
00000583 10/13/2020 16:14:01.5270141 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xe), scf(0xa0a): connect_work, conn( Connecting -> Connected ) peer( Unknown -> Secondary ) |
resource up
| 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.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]) 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) <- 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 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) 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) 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 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 ) 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 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) <- 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 ) 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(ConsistentDUnknown), prpl(WFBitMapSOff), pdvflag(0x1006000x100000): receive_state, pdsk( Consistent -> Outdated ) 00000259 node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) 00000778 10/13/2020 1416:5316:5015.4737781429 [print_state_changereceive_sizes] [PROTOCOL:39] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(OutdatedDUnknown), prpl(WFBitMapSOff), pdvflag(0x1006000x100000): drbd_start_resync, pdsk( Outdated -> Inconsistent ) repl( WFBitMapS -> SyncSource ) |
resource up
| Code Block |
|---|
00000016 Proceed with device size setting 00000779 10/13/2020 1416:4816:17.566 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE001467C7880] drbd netlink cmd(DRBD_ADM_NEW_RESOURCE:7) begin -> 0000001715.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 1416:4816:1715.5667782109 [drbdget_max_thread_startagreeable_size] [GENL:17] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, rpdsk(SecondaryDUnknown), fprpl(0x0Off), scfpdvflag(0x00x100000): Starting worker thread (from not_drbd_thread [0x0000000000000000]) 00000018 10/13/2020 14:48:17.566 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE001467C7880] drbd netlink cmd(DRBD_ADM_NEW_RESOURCE:7) done (cmd_pending:0) <- 00000019node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) |
resource down
| Code Block |
|---|
00000617 10/13/2020 1416:4816:1711.5662136805 [NetlinkWorkThread] [NETLINK:18] WDRBDbsr_INFO<6>info<6> [0xFFFFE00145F920400xFFFFE000CCAC4880] drbdbsr netlink cmd(DRBDBSR_ADM_NEW_MINORDOWN:527) begin -> 0000002000000618 10/13/2020 1416:4816:1711.5662137344 [drbd_create_deviceFsctlLockVolume] WDRBD_INFO<6>[0xFFFFE00145F92040] device:FFFFE0014796F5F0 q->max_hw_sectors: 10967040 sectors, device->this_bdev->d_size: 5615124480 bytes 00000021[VOLUME:65] bsr_info<6> [0xFFFFE000CCAC4880] try lock volume(\Device\HarddiskVolume2) 00000680 10/13/2020 1416:4816:1711.5662534883 [NetlinkWorkThreadFsctlLockVolume] WDRBD_INFO<6>[0xFFFFE00145F92040[VOLUME:23] drbd netlink cmd(DRBD_ADM_NEW_MINOR:5) done (cmd_pending:0) <- 00000022 bsr_info<6> [0xFFFFE000CCAC4880] volume(\Device\HarddiskVolume2) locked. handle(0xFFFFFFFF80000DC8) 00000683 10/13/2020 1416:4816:1711.5822535024 [NetlinkWorkThreadFsctlFlushDismountVolume] WDRBD_INFO<6>[0xFFFFE0014691B880[VOLUME:62] drbd netlink cmd(DRBD_ADM_NEW_PEER:44) begin -> 00000023bsr_info<6> [0xFFFFE000CCAC4880] try flush volume(\Device\HarddiskVolume2) 00000684 10/13/2020 1416:4816:17.582 [drbd_create_peer_device_default_config] WDRBD_INFO<6>drbd 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 0000002411.2535729 [FsctlFlushDismountVolume] [VOLUME:63] bsr_info<6> [0xFFFFE000CCAC4880] volume(\Device\HarddiskVolume2) flushed 00000685 10/13/2020 16:16:11.2535766 [FsctlFlushDismountVolume] [VOLUME:64] bsr_info<6> [0xFFFFE000CCAC4880] 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 10/13/2020 1416:4816:1711.5822560178 [drbdprint_thread_startstate_change] [STATE:18] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, csr(StandAlonePrimary), prole(Unknown), cflag(0x0f(0x11), scf(0x00x83c): Starting sender thread (from not_drbd_thread [0x0000000000000000]) 00000025change_role, role( Primary -> Secondary ) 00000688 10/13/2020 1416:4816:1711.5822568256 [NetlinkWorkThread__receive_uuids] WDRBD_INFO<6>[0xFFFFE0014691B880] drbd netlink cmd(DRBD_ADM_NEW_PEER:44) done (cmd_pending:0) <- 00000026 10/13/2020 14:48:17.582 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00145F92040] drbd netlink cmd(DRBD_ADM_NEW_PATH:45) begin -> 00000027 [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 1416:4816:1711.5822568317 [NetlinkWorkThreadbsr_uuid_compare] WDRBD_INFO<6>[0xFFFFE00145F92040] drbd netlink cmd(DRBD_ADM_NEW_PATH:45) done (cmd_pending:0) <- 00000028[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 10/13/2020 1416:48:17.597 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014691B880] drbd netlink cmd(DRBD_ADM_CHG_PEER_DEVICE_OPTS:43) begin -> 0000002916:11.2569857 [FsctlUnlockVolume] [VOLUME:61] bsr_info<6> [0xFFFFE000CCAC4880] unlock volume(\Device\HarddiskVolume2) 00000691 10/13/2020 1416:4816:17.597 [drbd_adm_peer_device_opts] WDRBD_INFO<6>drbd r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x0): new, resync_rate : 614400k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k 00000030 10/13/2020 14:48:17.597 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014691B880] drbd netlink cmd(DRBD_ADM_CHG_PEER_DEVICE_OPTS:43) done (cmd_pending:0) <- 0000003111.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 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 1416:4816:1711.6442577355 [NetlinkWorkThreadchange_cluster_wide_state] WDRBD_INFO<6>[0xFFFFE00145F92040] drbd netlink cmd(DRBD_ADM_ATTACH:12) begin -> 00000032 10/13/2020 14:48:17.644 [state_change_lock] WDRBD_WARN<4>[0xFFFFE00145F92040] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040 resource->worker.task:FFFFE00147372D20 00000033[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 1416:4816:1711.6442580212 [printchange_cluster_wide_state_change] WDRBD_INFO<6>drbd r0/0 minor 2, ds(Diskless), dvflag(0x0): change_disk_state, disk( Diskless -> Attaching ) 00000034 10/13/2020 14:48:17.644 [FsctlLockVolume] WDRBD_INFO<6>[0xFFFFE00145F92040] no lock. volume(\Device\HarddiskVolume2) already dismounted 00000035] [TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x11), scf(0x28): [TWOPC:1834520240] target_node_id(1) get_cluster_wide_reply (3) 00000696 10/13/2020 1416:4816:1711.6442580251 [FsctlFlushDismountVolumechange_cluster_wide_state] WDRBD_INFO<6>[0xFFFFE00145F92040] no dismount. volume(\Device\HarddiskVolume2) already dismounted 00000036[TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x11), scf(0x28): State change 1834520240: primary_nodes=0, weak_nodes=0 00000697 10/13/2020 1416:4816:1711.6442580275 [FsctlUnlockVolumechange_cluster_wide_state] WDRBD_INFO<6>[0xFFFFE00145F92040] volume(\Device\HarddiskVolume2) not locked 00000037[TWOPC:38] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x210e), scf(0x28): Cluster is now split 00000698 10/13/2020 1416:4816:1711.6442580300 [drbdchange_cluster_adm_attachwide_state] [TWOPC:39] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, r(Secondary), dsf(Attaching0x11), dvflagscf(0x00x28): MaximumCommitting numbercluster-wide ofstate peerchange devices1834520240 = 1 00000038(0ms) (0->1) 00000699 10/13/2020 1416:4816:17.644 [drbd_bump_write_ordering] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x1): Method to ensure write ordering: drain 00000039 11.2584388 [Receive] [SOCKET:66] bsr_info<6> [0xFFFFE000CDB66880] receiver => Recv multiWait error. err(STATUS_CONNECTION_RESET) wsk(0xFFFFE000CE2A8198) size(16) 00000700 10/13/2020 1416:4816:1711.6442584579 [get_max_agreeable_size] WDRBD_INFO<6>drbd r0/0 minor 2, ds(Attaching), dvflag(0x0): my node_id: 0 00000040bsr_recv] [SOCKET:14] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x210e), scf(0x28): socket reset due to peer. 00000701 10/13/2020 1416:4816:1711.6442584757 [getprint_max_agreeable_sizestate_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdskcs(DUnknownConnected), prplprole(OffSecondary), pdvflagcflag(0x00x210e): node_id: 1 idx: 0 bm-uuid: 0x0 flags: 0x20010 max_size: 0 (DUnknown) 00000041, scf(0x21): bsr_recv, conn( Connected -> BrokenPipe ) peer( Secondary -> Unknown ) 00000702 10/13/2020 1416:4816:1711.6442584805 [getprint_max_agreeable_sizestate_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(UpToDate), dsprpl(AttachingEstablished), dvflagpdvflag(0x00x100600): my node_id: 0 00000042 bsr_recv, pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 00000703 10/13/2020 1416:4816:1711.6442585071 [getbsr_maxrecv_agreeable_sizeall_warn] [PROTOCOL:64] WDRBDbsr_INFO<6>drbdwarn<4> bsr r0/0 minor 2 pnode-id:1, cs(BrokenPipe), pdskprole(DUnknownUnknown), prplcflag(Off0x211e), pdvflagscf(0x0): node_id: 1 idx: 0 bm-uuid: 0x0 flags: 0x20010 max_size: 0 (DUnknown) 00000043short read (expected size 16) 00000704 10/13/2020 1416:4816:1711.6442585247 [drbdprint_bm_resizestate_change] [STATE:19] WDRBDbsr_INFO<6>drbd r0/0 minor 2, ds(Attaching), dvflag(0x0): drbd_bm_resize called with capacity == 10967040 00000044info<6> bsr r0 pnode-id:1, cs(BrokenPipe), prole(Unknown), cflag(0x211e), scf(0x208): conn_try_disconnect, conn( BrokenPipe -> Disconnecting ) 00000705 10/13/2020 1416:4816:1711.6442586495 [drbdbsr_bm_resizeack_receiver] [CONNECTION:16] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Attaching pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e), dvflagscf(0x0): resync bitmap: bits=1370880 words=42840 pages=42 00000045ack_receiver terminated 00000706 10/13/2020 1416:4816:1711.6442586532 [drbdbsr_determine_dev_sizethread_setup] [THREAD:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Attaching pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e), dvflagscf(0x0): sizeTerminating =ack_recv 5355thread MB (5483520 KB) 00000046 00000707 10/13/2020 1416:4816:1711.6442587692 [bmw_rw_rangeresync_timer] [RESYNC/OV:105] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), dsprpl(AttachingOff), dvflagpdvflag(0x0): recounting of set bits took additional 0ms 00000047 completed because it is not in the VerifyS or SyncTarget replication state. 00000708 10/13/2020 1416:4816:1711.6442591157 [stateconn_change_lockdisconnect] WDRBD_WARN<4>[0xFFFFE00145F92040[CONNECTION:9] workerbsr_info<6> shouldbsr not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040 resource->worker.task:FFFFE00147372D20 00000048r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e), scf(0x0): Connection closed 00000709 10/13/2020 1416:4816:1711.6442591688 [print_state_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Attaching pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x211e), dvflagscf(0x00x23): changeconn_disk_statedisconnect, diskconn( AttachingDisconnecting -> UpToDateStandAlone ) 0000004900000710 10/13/2020 1416:4816:1711.6442591981 [finishbsr_state_changethread_setup] [THREAD:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Attaching pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x211e), dvflagscf(0x0): attachedTerminating toreceiver current UUID: 233537F4119A9BFE 00000050thread 00000711 10/13/2020 1416:4816:1711.6442592468 [NetlinkWorkThreadbsr_thread_setup] WDRBD_INFO<6>[0xFFFFE00145F92040] drbd netlink cmd(DRBD_ADM_ATTACH:12) done (cmd_pending:0) <- 00000051[THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x211e), scf(0x0): Terminating sender thread 00000712 10/13/2020 1416:4816:1711.6602593036 [NetlinkWorkThreadbsr_destroy_connection] WDRBD_INFO<6>[0xFFFFE001464EF880] drbd netlink cmd(DRBD_ADM_CONNECT:10) begin -> 00000052[CONNECTION:1] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x311e), scf(0x0): bsr_destroy_connection 00000713 10/13/2020 1416:4816:1711.6602593241 [state_change_lockchange_lock] [STATE:40] WDRBDbsr_WARN<4>info<6> [0xFFFFE001464EF8800xFFFFE000CCAC4880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040FFFFF801707C9BD0 resource->worker.task:FFFFE00147372D20FFFFE000CDB38300 0000005300000714 10/13/2020 1416:4816:1711.6602593339 [print_state_change] [STATE:20] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x0), scf(0x2a): drbd_adm_connect, conn( StandAlone -> Unconnected ) 00000054 /0 minor 2, ds(UpToDate), dvflag(0x2): change_disk_state, disk( UpToDate -> Detaching ) 00000715 10/13/2020 16:16:11.2593378 [finish_state_change] [UUID:19] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x10002): detaching to current UUID: 83F530CA41FA9868 00000716 10/13/2020 1416:4816:1711.6602593863 [NetlinkWorkThreadprint_state_change] WDRBD_INFO<6>[0xFFFFE001464EF880] drbd netlink cmd(DRBD_ADM_CONNECT:10) done (cmd_pending:0) <- |
resource down
| Code Block |
|---|
00000087 10/13/2020 14:50:50.598 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00146877040] drbd netlink cmd(DRBD_ADM_DOWN:27) begin -> 00000088[STATE:20] bsr_info<6> bsr r0/0 minor 2, ds(Detaching), dvflag(0x1002): change_disk_state, disk( Detaching -> Diskless ) 00000717 10/13/2020 1416:5016:50.598 [FsctlLockVolume] WDRBD_INFO<6>[0xFFFFE00146877040] no lock. volume(\Device\HarddiskVolume2) already dismounted 0000008911.2593963 [adm_detach] [GENL:42] bsr_info<6> [0xFFFFE000CCAC4880] wait event interruptible timeout. time out(3000) disk state(Diskless) 00000718 10/13/2020 1416:5016:5011.5982599158 [FsctlFlushDismountVolumebsr_bm_resize] WDRBD_INFO<6>[0xFFFFE00146877040] no dismount. volume(\Device\HarddiskVolume2) already dismounted 00000090[BITMAP:23] bsr_info<6> bsr r0/0 minor 2, ds(Diskless), dvflag(0x2): bitmap resize called with capacity(0) 00000719 10/13/2020 1416:5016:5011.5982601141 [FsctlUnlockVolumebsr_thread_setup] WDRBD_INFO<6>[0xFFFFE00146877040] volume(\Device\HarddiskVolume2) not locked 00000091[THREAD:10] bsr_info<6> bsr r0, r(Secondary), f(0x11), scf(0x0): Terminating worker thread 00000720 10/13/2020 1416:5016:5011.5982601562 [state_change_lockmvolWorkThread] WDRBD_WARN<4>[0xFFFFE00146877040[THREAD:20] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040 resource->worker.task:FFFFE00147372D20 00000092bsr_info<6> [0xFFFFE000CDC92880] Terminating mvolWorkThread 00000721 10/13/2020 1416:5016:50.598 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x28): Preparing cluster-wide state change 789940694 (0->1 496/16) 0000009311.2603818 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAC4880] bsr netlink cmd(BSR_ADM_DOWN:27) done (cmd_pending:0) <- |
resource connect
| Code Block |
|---|
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 1416:5018:5020.5989762023 [state_change_cluster_wide_statelock] [STATE:40] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x28): [TWOPC:789940694] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000094bsr_info<6> [0xFFFFE000CCAFB880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000793 10/13/2020 1416:5018:5020.5989762218 [change_cluster_wide_state] [TWOPC:34] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC:789940694] target_node_id(1) get_cluster_wide_reply (3) 00000095Preparing cluster-wide state change 2366568536 (0->1 496/16) 00000794 10/13/2020 1416:5018:5020.5989762252 [change_cluster_wide_state] [TWOPC:35] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0, r(Secondary), f(0x0), scf(0x28): State change 789940694: primary_nodes=0, weak_nodes=0 00000096 10/13/2020 14:50:50.598 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0 pnode-id:1, cs(Connected), prole(Secondary), cflag(0x10e), scf(0x28): Cluster is now split 00000097[TWOPC:2366568536] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000795 10/13/2020 1416:5018:5020.5989766356 [change_cluster_wide_state] WDRBD_INFO<6>drbd[TWOPC:36] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x28): [TWOPC: Committing cluster-wide state change 789940694 (0ms) (0->1) 000000982366568536] target_node_id(1) get_cluster_wide_reply (3) 00000796 10/13/2020 1416:5018:5020.5989766412 [printchange_cluster_wide_state_change] [TWOPC:37] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Connected), prole(r(Secondary), cflagf(0x10e0x0), scf(0x2080x28): conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown ) 00000099State change 2366568536: primary_nodes=0, weak_nodes=0 00000797 10/13/2020 1416:5018:5020.5989766463 [printchange_cluster_wide_state_change] [TWOPC:38] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdskcs(UpToDate), prpl(Established), pdvflag(0x100600): conn_try_disconnect, pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 00000100Connected), prole(Secondary), cflag(0x10e), scf(0x28): Cluster is now split 00000798 10/13/2020 1416:5018:5020.5989766497 [drbd_recvchange_cluster_wide_state] [TWOPC:39] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Connected), proler(Secondary), cflagf(0x10e0x0), scf(0x2080x28): sock_recvmsg returned -15 00000101 Committing cluster-wide state change 2366568536 (0ms) (0->1) 00000799 10/13/2020 1416:5018:5020.5989767770 [drbd_ack_receiver] WDRBD_INFO<6>drbdprint_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(DisconnectingConnected), prole(UnknownSecondary), cflag(0x10e), scf(0x00x208): ack_receiver terminated 00000102conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown ) 00000800 10/13/2020 1416:5018:5020.5989767831 [drbdprint_thread_setupstate_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, cspdsk(DisconnectingUpToDate), proleprpl(UnknownEstablished), cflagpdvflag(0x10e)0x100600): conn_try_disconnect, scf(0x0): Terminating ack_recv thread 00000103pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 00000801 10/13/2020 1416:5018:5020.5989768211 [w_resync_timerbsr_recv] [SOCKET:15] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, cs(Connected), pdskprole(DUnknownSecondary), prplcflag(Off0x10e), pdvflagscf(0x00x208): completedsocket becausedata it is not in the VERIFY_S or SYNC_TARGET replication state. 00000104 receive error(-15) 00000802 10/13/2020 1416:5018:5020.5989768974 [conn_disconnectbsr_ack_receiver] [CONNECTION:16] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x0): Connectionack_receiver closedterminated 0000010500000803 10/13/2020 1416:5018:5020.5989769028 [printbsr_state_changethread_setup] [THREAD:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x230x0): conn_disconnect, conn( Disconnecting -> StandAlone ) 00000106 Terminating ack_recv thread 00000804 10/13/2020 1416:5018:5020.5989771990 [drbdw_thread_setupresync_timer] [RESYNC/OV:105] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, cspdsk(StandAloneDUnknown), proleprpl(UnknownOff), cflag(0x10e), scfpdvflag(0x0): Terminating receiver thread 00000107 completed because it is not in the VerifyS or SyncTarget replication state. 00000805 10/13/2020 1416:5018:5020.5989774397 [drbd_thread_setupconn_disconnect] [CONNECTION:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(StandAloneDisconnecting), prole(Unknown), cflag(0x10e), scf(0x0): TerminatingConnection senderclosed thread 0000010800000806 10/13/2020 1416:5018:5020.5989774928 [drbdprint_destroy_connectionstate_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(StandAloneDisconnecting), prole(Unknown), cflag(0x110e0x10e), scf(0x00x23): drbd_destroy_connection 00000109conn_disconnect, conn( Disconnecting -> StandAlone ) 00000807 10/13/2020 1416:5018:5020.5989775335 [statebsr_changethread_locksetup] WDRBD_WARN<4>[0xFFFFE00146877040] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040 resource->worker.task:FFFFE00147372D20 00000110[THREAD:9] bsr_info<6> bsr r0 pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), scf(0x0): Terminating receiver thread 00000808 10/13/2020 1416:5018:50.598 [print_state_change] WDRBD_INFO<6>drbd r0/0 minor 2, ds(UpToDate), dvflag(0x0): change_disk_state, disk( UpToDate -> Detaching ) 00000111 20.9777552 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_DISCONNECT:11) done (cmd_pending:0) <- 00000809 10/13/2020 1416:5018:50.598 [print_state_change] WDRBD_INFO<6>drbd r0/0 minor 2, ds(Detaching), dvflag(0x1000): change_disk_state, disk( Detaching -> Diskless ) 0000011222.9478253 [NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(BSR_ADM_CONNECT:10) begin -> 00000810 10/13/2020 1416:5018:5022.5989478355 [adm_detachstate_change_lock] [STATE:40] WDRBDbsr_INFO<6>info<6> [0xFFFFE00146877040] wait_event_interruptible_timeout timeo:3000 device->disk_state[NOW]:0 000001130xFFFFE000CCAAC040] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000811 10/13/2020 1416:5018:5022.5989478519 [drbdprint_bm_resizestate_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Diskless pnode-id:1, cs(StandAlone), prole(Unknown), cflag(0x10e), dvflagscf(0x00x2a): drbdbsr_bmadm_resizeconnect, calledconn( withStandAlone capacity-> ==Unconnected 0) 0000011400000812 10/13/2020 1416:5018:5022.5989478904 [drbdbsr_thread_setupstart] [THREAD:11] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Unconnected), rprole(SecondaryUnknown), fcflag(0x00x10e), scf(0x0): TerminatingStarting workerreceiver thread 00000115 10/13/2020 14:50:50.598 [mvolWorkThread] WDRBD_INFO<6>[0xFFFFE00147830040] Terminating mvolWorkThread 00000116(from worker [2108]) 00000813 10/13/2020 1416:5018:5022.5989480150 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE00146877040] drbd[NETLINK:20] bsr_info<6> [0xFFFFE000CCAAC040] bsr netlink cmd(DRBDBSR_ADM_DOWNCONNECT:2710) done (cmd_pending:0) <- |
resource connect
| Code Block |
|---|
00000206 10/13/2020 14:51:49.379 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014688B040] drbd netlink cmd(DRBD_ADM_CONNECT:10) begin -> 00000207) <- 00000814 10/13/2020 1416:5118:4922.3799480265 [state_change_lock] WDRBD_WARN<4>[0xFFFFE0014688B040[STATE:40] bsr_info<6> [0xFFFFE000CE728040] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040FFFFE000CE0F9170 resource->worker.task:FFFFE001476959A0 00000208:FFFFE000CDE0B820 00000815 10/13/2020 16:18:22.9480416 [print_state_change] [STATE:19] bsr_info<6> bsr r0 pnode-id:1, cs(Unconnected), prole(Unknown), cflag(0xe), scf(0x2a): conn_connect, conn( Unconnected -> Connecting ) 00000816 10/13/2020 1416:5118:4925.3799566941 [printbsr_state_changedo_features] [PROTOCOL:55] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(StandAloneConnecting), prole(Unknown), cflag(0x10c0xe), scf(0x2a0x0): drbd_adm_connect, conn( StandAlone -> Unconnected ) 00000209 Handshake to peer 1 successful: Agreed network protocol version 114 00000817 10/13/2020 1416:5118:4925.3799567017 [drbdbsr_thread_startdo_features] [PROTOCOL:56] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(UnconnectedConnecting), prole(Unknown), cflag(0x10c0xe), scf(0x0): Starting receiver thread (from worker [0xFFFFE00147E45040]) 00000210 Feature flags enabled on protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME. 00000818 10/13/2020 1416:5118:4925.3799568141 [stateconn_change_lockconnect] WDRBD_WARN<4>[0xFFFFE00146923880] worker should not initiate state changes with CS_SERIALIZE current:FFFFE00147638310 resource->worker.task:FFFFE001476959A0 00000211[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 1416:5118:4925.3799568180 [printbsr_state_changethread_start] [THREAD:11] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(UnconnectedConnecting), prole(Unknown), cflag(0xc0xe), scf(0x2a0x0): Starting conn_connect, conn( Unconnected -> Connecting ) 00000212ack_recv thread (from receiver [1676]) 00000820 10/13/2020 1416:5118:49.379 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014688B040] drbd netlink cmd(DRBD_ADM_CONNECT:10) done (cmd_pending:0) <- 0000021326.0424367 [state_change_lock] [STATE:40] bsr_info<6> [0xFFFFE000CDA1A040] worker should not initiate state changes with CS_SERIALIZE current:FFFFE000CDAA58C0 resource->worker.task:FFFFE000CDE0B820 00000821 10/13/2020 1416:5118:5226.5200424586 [drbdchange_cluster_do_featureswide_state] [TWOPC:34] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, csr(ConnectingSecondary), prole(Unknown), cflag(0xcf(0x0), scf(0x00x82a): HandshakePreparing tocluster-wide peerstate 1change successful: Agreed network protocol version 113 000002142387348015 (0->1 499/146) 00000822 10/13/2020 1416:5118:5226.5200424733 [drbdchange_cluster_do_featureswide_state] [TWOPC:35] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, csr(ConnectingSecondary), prolef(Unknown0x0), cflagscf(0xc), scf(0x0): Feature flags enabled on protocol level: 0x7 TRIM THIN_RESYNC WRITE_SAME. 000002150x82a): [TWOPC:2387348015] target_node_id(1) conn(Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) flags (2058) 00000823 10/13/2020 1416:5118:5226.5200430489 [conn_connectchange_cluster_wide_state] [TWOPC:36] WDRBDbsr_WARN<4>drbdinfo<6> bsr r0 pnode-id:1, csr(ConnectingSecondary), prolef(Unknown0x0), cflagscf(0xc), scf(0x0): send-buffering disabled nc->sndbuf_size:0 000002160x82a): [TWOPC:2387348015] target_node_id(1) get_cluster_wide_reply (3) 00000824 10/13/2020 1416:5118:52.520 [drbd_thread_start] WDRBD_INFO<6>drbd r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xc26.0430560 [change_cluster_wide_state] [TWOPC:37] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x00x82a): StartingState ack_recv thread (from receiver [0xFFFFE00146923880]) 00000217change 2387348015: primary_nodes=0, weak_nodes=0 00000825 10/13/2020 1416:5118:5226.5350430611 [statechange_cluster_changewide_lockstate] WDRBD_WARN<4>[0xFFFFE00147972040] worker should not initiate state changes with CS_SERIALIZE current:FFFFE00146F98630 resource->worker.task:FFFFE001476959A0 00000218[TWOPC:39] bsr_info<6> bsr r0, r(Secondary), f(0x0), scf(0x82a): Committing cluster-wide state change 2387348015 (0ms) (0->1) 00000826 10/13/2020 1416:5118:5226.5350432317 [changeprint_cluster_wide_statestate_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Connecting), rprole(SecondaryUnknown), fcflag(0x00xe), scf(0x82a0xa0a): Preparing cluster-wide state change 1043930053 (0->1 499/146) 00000219connect_work, conn( Connecting -> Connected ) peer( Unknown -> Secondary ) 00000827 10/13/2020 1416:5118:5226.5350434960 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:1043930053] target_node_id(1) conn(Connected) repl(-) disk(-) pdsk(-) role(Secondary) peer(-) flags (2058) 00000220receive_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 00000828 10/13/2020 1416:5118:5226.5350435080 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x82a): [TWOPC:1043930053] target_node_id(1) get_cluster_wide_reply (3) 00000221receive_sizes] [PROTOCOL:32] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): current_mydisk_size: 10860101632 bytes 00000829 10/13/2020 1416:5118:5226.5350435114 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x82a): State change 1043930053: primary_nodes=0, weak_nodes=0 00000222receive_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 00000830 10/13/2020 1416:5118:5226.5350435168 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x82a): Committing cluster-wide state change 1043930053 (0ms) (0->1) 00000223receive_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 00000831 10/13/2020 1416:5118:5226.5350435209 [printget_max_state_changeagreeable_size] [GENL:16] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Connecting), prole(Unknown), cflag(0xc), scf(0xa0a): connect_work, conn( Connecting -> Connected ) peer( Unknown -> Secondary ) 00000224 /0 minor 2, ds(UpToDate), dvflag(0x0): local node_id: 0 00000832 10/13/2020 1416:5118:5226.5350435236 [receive_SyncParamget_max_agreeable_size] [GENL:17] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): node id(1) bitmap index(0) bitmap uuid(0x0): sync, resync_rate : 614400k, c_plan_ahead : 20k, c_delay_target : 10k, c_fill_target : 100s, c_max_rate : 102400k, c_min_rate : 250k 00000225) flags(0x10) max size(21211136) disk state(DUnknown) 00000833 10/13/2020 16:18:26.0435292 [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 00000834 10/13/2020 1416:5118:5226.5350436443 [receive_sizesget_max_agreeable_size] [GENL:16] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x0): local currentnode_mydisk_sizeid: 56151244800 bytes 0000022600000835 10/13/2020 1416:5118:5226.5350436474 [receive_sizesget_max_agreeable_size] [GENL:17] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x00x100000): peer_current_size: 5615124480 bytes peer_user_size: 0 bytes peer_disk_size: 10807672832 bytes peer_max_size: 10807672832 bytes 00000227node id(1) bitmap index(0) bitmap uuid(0x0) flags(0x10) max size(21211136) disk state(DUnknown) |
resource disconnect
| Code Block |
|---|
00000791 10/13/2020 1416:5118:5220.5359761914 [receive_sizes] WDRBD_INFO<6>drbd r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): md_effective_size: 10967040 my_user_size: 0 my_max_size: 10967040 00000228NetlinkWorkThread] [NETLINK:18] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_DISCONNECT:11) begin -> 00000792 10/13/2020 1416:5118:5220.5359762023 [warnstate_if_differ_considerablychange_lock] [STATE:40] WDRBDbsr_WARN<4>drbd r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x100000): Considerable difference in lower level device sizes: 10807672832 bytes vs. 5615124480 bytes 00000229info<6> [0xFFFFE000CCAFB880] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801707C9BD0 resource->worker.task:FFFFE000CDE0B820 00000793 10/13/2020 1416:5118:5220.5359762218 [getchange_maxcluster_agreeable_sizewide_state] [TWOPC:34] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, r(Secondary), dsf(UpToDate0x0), dvflagscf(0x00x28): my node_id: 0 00000230 Preparing cluster-wide state change 2366568536 (0->1 496/16) 00000794 10/13/2020 1416:5118:5220.5359762252 [getchange_maxcluster_agreeable_sizewide_state] [TWOPC:35] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdskr(DUnknownSecondary), prplf(Off0x0), pdvflagscf(0x1000000x28): [TWOPC:2366568536] target_node_id: (1 idx: 0 bm-uuid: 0x0 flags: 0x20010 max_size: 21108736 (DUnknown) 00000231) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000795 10/13/2020 1416:5118:5220.5359766356 [receive_sizeschange_cluster_wide_state] [TWOPC:36] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown, r(Secondary), f(0x0), prpl(Off), pdvflag(0x100000): calling drbd_determine_dev_size() 00000232scf(0x28): [TWOPC:2366568536] target_node_id(1) get_cluster_wide_reply (3) 00000796 10/13/2020 1416:5118:5220.5359766412 [getchange_maxcluster_agreeable_sizewide_state] [TWOPC:37] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, r(Secondary), dsf(UpToDate0x0), dvflagscf(0x00x28): my node_id: 0 00000233 State change 2366568536: primary_nodes=0, weak_nodes=0 00000797 10/13/2020 1416:5118:5220.5359766463 [getchange_maxcluster_agreeable_sizewide_state] [TWOPC:38] WDRBD_INFO<6>drbd r0/0 minor 2bsr_info<6> bsr r0 pnode-id:1, pdskcs(DUnknownConnected), prplprole(OffSecondary), pdvflagcflag(0x1000000x10e): node_id, scf(0x28): 1Cluster idx:is 0 bm-uuid: 0x0 flags: 0x20010 max_size: 21108736 (DUnknown) |
resource disconnect
| Code Block |
|---|
00000188now split 00000798 10/13/2020 1416:5118:4420.7549766497 [NetlinkWorkThread] WDRBD_INFO<6>[0xFFFFE0014688B040] drbd netlink cmd(DRBD_ADM_DISCONNECT:11) begin -> 00000189 10/13/2020 14:51:44.754 [state_change_lock] WDRBD_WARN<4>[0xFFFFE0014688B040] worker should not initiate state changes with CS_SERIALIZE current:FFFFF801B127A040 resource->worker.task:FFFFE001476959A0 00000190change_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) 00000799 10/13/2020 1416:5118:4420.7549767770 [changeprint_cluster_wide_statestate_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(Connected), rprole(Secondary), f(0x0), scf(0x28): Preparing cluster-wide state change 1012019641 (0->1 496/16) 00000191cflag(0x10e), scf(0x208): conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown ) 00000800 10/13/2020 1416:5118:4420.7549767831 [changeprint_cluster_wide_statestate_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, rpdsk(SecondaryUpToDate), fprpl(0x0Established), scfpdvflag(0x280x100600): [TWOPC:1012019641] target_node_id(1) conn(Disconnecting) repl(-) disk(-) pdsk(-) role(-) peer(-) flags (8) 00000192conn_try_disconnect, pdsk( UpToDate -> DUnknown ) repl( Established -> Off ) 00000801 10/13/2020 1416:5118:4420.7549768211 [change_cluster_wide_state] WDRBD_INFO<6>drbd r0, rbsr_recv] [SOCKET:15] bsr_info<6> bsr r0 pnode-id:1, cs(Connected), prole(Secondary), fcflag(0x00x10e), scf(0x280x208): [TWOPC:1012019641] target_node_id(1) get_cluster_wide_reply (3) 00000193 socket data receive error(-15) 00000802 10/13/2020 1416:5118:4420.7549768974 [changebsr_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0ack_receiver] [CONNECTION:16] bsr_info<6> bsr r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10e), scf(0x280x0): State change 1012019641: primary_nodes=0, weak_nodes=0 00000194ack_receiver terminated 00000803 10/13/2020 1416:5118:4420.7549769028 [changebsr_cluster_wide_statethread_setup] [THREAD:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(ConnectedDisconnecting), prole(SecondaryUnknown), cflag(0x10c0x10e), scf(0x280x0): ClusterTerminating isack_recv nowthread split00000804 00000195 10/13/2020 1416:5118:4420.7549771990 [changew_cluster_wide_state] WDRBD_INFO<6>drbd r0, r(Secondary), f(0x0), scf(0x28): Committing cluster-wide state change 1012019641 (0ms) (0->1) 00000196resync_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 1416:5118:4420.7549774397 [print_state_changeconn_disconnect] [CONNECTION:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(ConnectedDisconnecting), prole(SecondaryUnknown), cflag(0x10c0x10e), scf(0x2080x0): conn_try_disconnect, conn( Connected -> Disconnecting ) peer( Secondary -> Unknown ) 00000197Connection closed 00000806 10/13/2020 1416:5118:4420.7549774928 [print_state_change] [STATE:19] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, cs(Disconnecting), pdskprole(UpToDateUnknown), prplcflag(Established0x10e), pdvflagscf(0x1006000x23): conn_try_disconnect, pdskconn( UpToDateDisconnecting -> DUnknownStandAlone ) repl( Established -> Off ) 0000019800000807 10/13/2020 1416:5118:4420.7549775335 [drbd_recvbsr_thread_setup] [THREAD:9] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0 pnode-id:1, cs(ConnectedStandAlone), prole(SecondaryUnknown), cflag(0x10c0x10e), scf(0x2080x0): sock_recvmsgTerminating returnedreceiver -15thread 0000019900000808 10/13/2020 1416:5118:44.754 [drbd_ack_receiver] WDRBD_INFO<6>drbd r0 pnode-id:1, cs(Disconnecting), prole(Unknown), cflag(0x10c), scf(0x0): ack_receiver terminated 0000020020.9777552 [NetlinkWorkThread] [NETLINK:20] bsr_info<6> [0xFFFFE000CCAFB880] bsr netlink cmd(BSR_ADM_DISCONNECT:11) done (cmd_pending:0) <- |
syncsource
resync start
Code Block 00000593 10/13/2020 16:14:
...
01.
...
5273798 [
...
__
...
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: 7B326D963D9936CE 00000594 10/13/2020 16:14:
...
01.
...
5273852 [
...
bsr_
...
uuid_compare] [RESYNC/OV:202]
...
bsr_
...
info<6> bsr r0/0 minor 2
...
,
...
ds(
...
UpToDate),
...
dvflag(
...
0x2)
...
: Peer UUID and local bitmap UUID are the same. rule(70), res(2) 00000595 10/13/2020 16:14:
...
01.
...
5275442 [
...
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 10/13/2020 16:14:
...
01.
...
5275481 [
...
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 83F530CA41FA9869:7B326D963D9936CF:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:8711 flags:120 00000597 10/13/2020 16:14:
...
01.
...
5275527 [
...
bsr_uuid_
...
dump_peer] [RESYNC/OV:66]
...
bsr_
...
info<6> bsr r0/0 minor 2 pnode-id:1,
...
pdsk(
...
DUnknown),
...
prpl(
...
Off),
...
pdvflag(0x100000):
...
syncsource
resync start
Code Block 00000305peer 7B326D963D9936CE:0000000000000000:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:0 flags:0 00000598 10/13/2020 16:14:54:5101.5055275568 [bsr__receive_uuidsuuid_compare] [RESYNC/OV:202] WDRBDbsr_WARN<4>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdskds(DUnknownUpToDate), prpldvflag(Off), pdvflag(0x100000): receive new current but not update UUID: 233537F4119A9BFE 000003060x2): Peer UUID and local bitmap UUID are the same. rule(70), res(2) 00000599 10/13/2020 16:14:54:5101.5055275593 [logbsr_handshake] [RESYNC/OV:75] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x1002000x100000): drbd_sync_handshake: 00000307uuid_compare(2) by rule 70 00000600 10/13/2020 16:14:54:5101.5055275634 [drbd_uuid_dump_self] WDRBD_INFO<6>drbdreceive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x1002000x100000): receive self BA6151025D30A885:233537F4119A9BFF:238A851C11C54292:1DD3312D0EE9989A bits:17 flags:120 00000308new repl state "WFBitMapS" 00000601 10/13/2020 16:14:54:5101.5055275781 [drbdprint_uuid_dump_peerstate_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknown), prpl(Off), pdvflag(0x1002000x100000): peer 233537F4119A9BFE:0000000000000000:B43F1BF5DA1F8DFE:B66081A55B3040D6 bits:0 flags:0 00000309 receive_state, pdsk( DUnknown -> Outdated ) repl( Off -> WFBitMapS ) 00000602 10/13/2020 16:14:54:5101.5055277419 [drbd_handshake] WDRBD_INFO<6>drbdbsr_queue_bitmap_io] [RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, ds(UpToDate), pdskdvflag(DUnknown), prpl(Off0x2): send_bitmap (WFBitMapS), pdvflagworker.task(0x100200FFFFE000CDB38300):, uuid_comparecurrent(FFFFE000CDB38300)=2 by rule 70 00000310 00000603 10/13/2020 16:14:54:5101.5055297955 [receive_state] [STATE:8] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknownOutdated), prpl(OffWFBitMapS), pdvflag(0x1002000x100600): receive new repl state "WFBitMapS" 0000031100000604 10/13/2020 16:14:54:51.505 [print_state_change] WDRBD_INFO<6>drbd01.5299369 [INFO_bm_xfer_stats] [BITMAP:50] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(DUnknownOutdated), prpl(OffWFBitMapS), pdvflag(0x1002000x100600): receive_state, pdsk( DUnknown -> Outdated ) repl( Off -> WFBitMapS ) 00000312send bitmap stats [Bytes(packets)]: plain 0(0), RLE 56(1), total 56; compression: 100.0% 00000605 10/13/2020 16:14:54:5101.5055321829 [drbdINFO_queuebm_bitmap_ioxfer_stats] [BITMAP:50] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), dsprpl(UpToDateWFBitMapS), dvflag(0x0): send_bitmap (WFBitMapS), worker.task(FFFFE001476959A0), current(FFFFE001476959A0) .. 00000322 pdvflag(0x100600): receive bitmap stats [Bytes(packets)]: plain 0(0), RLE 56(1), total 56; compression: 100.0% 00000606 10/13/2020 16:14:54:5101.5055321885 [receive_state_bitmap_finished] [BITMAP:52] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): send that receivebitmap newexchange replhas statebeen "WFBitMapS"completed 0000032300000607 10/13/2020 16:14:54:5101.5055323570 [INFOprint_bm_xfer_statsstate_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Outdated), prpl(WFBitMapS), pdvflag(0x100600): send bitmap stats [Bytes(packets)]: plain 0(0), RLE 45(1), total 45; compression: 100.0% 00000324bsr_start_resync, pdsk( Outdated -> Inconsistent ) repl( WFBitMapS -> SyncSource ) 00000608 10/13/2020 16:14:54:5101.5055324087 [INFObsr_bm_xfer_stats] WDRBD_INFO<6>drbdstart_resync] [RESYNC/OV:144] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdsk(OutdatedInconsistent), prpl(WFBitMapSSyncSource), pdvflag(0x100600): receiveBegan bitmapresync stats [Bytes(packets)]: plain 0(0), RLE 45(1), total 45; compression: 100.0% 00000325as SyncSource (will sync 34844 KB [8711 bits set]). 00000609 10/13/2020 16:14:54:5101.5055332003 [receive_bitmap_finished_state] [STATE:8] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(OutdatedInconsistent), prpl(WFBitMapSSyncSource), pdvflag(0x100600): sendreceive thatnew bitmaprepl exchangestate has been completed 00000326"SyncSource" 00000610 10/13/2020 16:14:54:5110.5057932817 [print__state_changereceive_uuids] [UUID:16] WDRBDbsr_INFO<6>drbdwarn<4> bsr r0/0 minor 2 pnode-id:1, pdsk(OutdatedInconsistent), prpl(WFBitMapSSyncSource), pdvflag(0x100600): drbd_start_resync, pdsk( Outdated -> Inconsistent ) repl( WFBitMapS -> SyncSource ) 00000327receive new current but not update UUID: 83F530CA41FA9868 00000611 10/13/2020 16:14:54:5110.5057932881 [drbdbsr_start_resync] WDRBD_INFO<6>drbduuid_compare] [RESYNC/OV:197] bsr_info<6> bsr r0/0 minor 2 pnode-id:1, pdskds(InconsistentUpToDate), prpldvflag(SyncSource), pdvflag(0x100600)0x2): BeganLocal resyncand aspeer SyncSourcecurrent (willUUIDs syncare 68the KB [17 bits set]).same. rule(40), res(0)
resync finished
Code Block 0000032900000612 10/13/2020 16:14:54:5110.5367932922 [bsr__receiveprint_uuids] [UUID:1] WDRBDbsr_WARN<4>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): receive new current but not update UUID: BA6151025D30A884 00000330bsr_uuid_detect_finished_resyncs, updated UUIDs 83F530CA41FA9869:0000000000000000:7B326D963D9936CE:3DF87D1E1EFC3E92 00000613 10/13/2020 16:14:54:5110.5367939134 [drbdbsr_print_uuidsresync_finished] [RESYNC/OV:116] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(Inconsistent), prpl(SyncSource), pdvflag(0x100600): drbd_uuid_detect_finished_resyncs, updated UUIDs BA6151025D30A885:0000000000000000:233537F4119A9BFE:238A851C11C54292 00000331 Resync done (total 9 sec; paused 0 sec; 3868 K/sec), hit bit (in sync 0; marked rl 0) 00000614 10/13/2020 16:14:54:5110.5367939295 [drbdprint_uuid_detect_finished_resyncs] WDRBD_INFO<6>drbdstate_change] [STATE:21] bsr_info<6> bsr r0/0 minor 2 2 pnode-id:1, pdsk(Inconsistent), dsprpl(UpToDateSyncSource), dvflagpdvflag(0x40x100600): Clearing bitmap UUID for node 2 00000332 bsr_resync_finished, pdsk( Inconsistent -> UpToDate ) repl( SyncSource -> Established ) 00000615 10/13/2020 16:14:54:5110.5367940275 [drbdbsr_queue_resync_finishedbitmap_io] [RESYNC/OV:33] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdskds(InconsistentUpToDate), prpldvflag(SyncSource0x2), pdvflag(0x100600): Resync done (total 1 sec; paused 0 sec; 68 K/sec), hit bit (in sync 0; marked rl 0) 00000333: write from resync_finished, worker.task(FFFFE000CDB38300), current(FFFFE000CDB38300) 00000616 10/13/2020 16:14:54:5110.5367941994 [printreceive_state_change] [STATE:8] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:1, pdsk(InconsistentUpToDate), prpl(SyncSourceEstablished), pdvflag(0x100600): drbd_resync_finished, pdsk( Inconsistent -> UpToDate ) repl( SyncSource -> Established ) 00000334 receive new repl state "Established"
synctarget
resync start
Code Block 00000084 10/13/2020 16:14:54:5101.5363783975 [drbd_queue_bitmap_ioreceive_uuids] [UUID:16] WDRBDbsr_INFO<6>drbdwarn<4> bsr r0/0 minor 2 pnode-id:0 minor 2, pdsk(DUnknown), dsprpl(UpToDateOff), dvflagpdvflag(0x00x100200): write from resync_finished, worker.task(FFFFE001476959A0), current(FFFFE001476959A0) 00000335receive new current but not update UUID: 83F530CA41FA9869 00000085 10/13/2020 16:14:54:5101.5363784433 [receive_statelog_handshake] [RESYNC/OV:73] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:10, pdsk(UpToDateDUnknown), prpl(EstablishedOff), pdvflag(0x1006000x100200): receive new repl state "Established"
synctarget
resync start
Code Block 00000080bsr_sync_handshake: 00000086 10/13/2020 16:14:54:51.300 [__receive_uuids] WDRBD_WARN<4>drbd01.3784484 [bsr_uuid_dump_self] [RESYNC/OV:65] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): receive new current but not update UUID: BA6151025D30A885 00000081self 7B326D963D9936CE:0000000000000000:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:0 flags:0 00000087 10/13/2020 16:14:54:5101.3003784535 [log_handshake] WDRBD_INFO<6>drbdbsr_uuid_dump_peer] [RESYNC/OV:66] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): drbd_sync_handshake: 00000082 peer 83F530CA41FA9869:7B326D963D9936CF:3DF87D1E1EFC3E92:3550951C1AA84A92 bits:8711 flags:120 00000088 10/13/2020 16:14:54:5101.3003784589 [drbdbsr_uuid_dump_selfcompare] [RESYNC/OV:198] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdskds(DUnknownOutdated), prpldvflag(Off), pdvflag(0x100200): self 233537F4119A9BFE:0000000000000000:B43F1BF5DA1F8DFE:B66081A55B3040D6 bits:0 flags:0 000000830x0): The local current UUID is the same as the peer bitmap UUID. rule(50), res(-2) 00000089 10/13/2020 16:14:54:5101.3003784626 [drbd_uuid_dump_peer] WDRBD_INFO<6>drbdbsr_handshake] [RESYNC/OV:75] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): peer BA6151025D30A885:233537F4119A9BFF:238A851C11C54292:1DD3312D0EE9989A bits:17 flags:1120 00000084uuid_compare(-2) by rule 50 00000090 10/13/2020 16:14:54:5101.3003784682 [drbd_handshakereceive_state] [STATE:8] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): uuid_compare()=-2 by rule 50 00000085 receive new repl state "WFBitMapT" 00000091 10/13/2020 16:14:54:5101.3003784857 [receiveprint_state_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknown), prpl(Off), pdvflag(0x100200): receive new repl state "WFBitMapT" 00000086_state, pdsk( DUnknown -> UpToDate ) repl( Off -> WFBitMapT ) 00000092 10/13/2020 16:14:54:5101.3003785440 [printw_after_state_change] [STATE:28] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(DUnknownUpToDate), prpl(OffWFBitMapT), pdvflag(0x1002000x100600): receive_state, pdsk( DUnknown -> UpToDate ) repl( Off -> WFBitMapT ) 00000087not sending state because of old repl_state(Off) 00000093 10/13/2020 16:14:54:5101.3003787983 [w_afterreceive_state_change] [STATE:8] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): notreceive new sendingrepl state because of old repl_state(Off) 00000088 "WFBitMapT" 00000094 10/13/2020 16:14:54:5101.3163788417 [receivew_after_state_change] [STATE:28] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): receive new repl state "WFBitMapT" 00000089 not sending state because of old repl_state(WFBitMapT) 00000095 10/13/2020 16:14:54:5101.3163807180 [wINFO_afterbm_state_changexfer_stats] [BITMAP:50] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): receive notbitmap sending state because of old repl_state(WFBitMapT) 00000090stats [Bytes(packets)]: plain 0(0), RLE 56(1), total 56; compression: 100.0% 00000096 10/13/2020 16:14:54:5101.3163830286 [INFO_bm_xfer_stats] WDRBD_INFO<6>drbd[BITMAP:50] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): receivesend bitmap stats [Bytes(packets)]: plain 0(0), RLE 4556(1), total 4556; compression: 100.0% 0000009100000097 10/13/2020 16:14:54:5101.3163831040 [receive_bm_exchange_state] WDRBD_INFO<6>drbd[BITMAP:44] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): bitmap exchange complete 0000009200000098 10/13/2020 16:14:54:5101.3163833661 [INFO_bm_xfer_stats] WDRBD_INFO<6>drbdreceive_state] [STATE:8] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): sendreceive bitmapnew stats [Bytes(packets)]: plain 0(0), RLE 45(1), total 45; compression: 100.0% 00000093 repl state "WFBitMapT" 00000099 10/13/2020 16:14:54:5101.3163834175 [print_state_change] [STATE:20] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Outdated), dvflag(0x0): drbdbsr_start_resync, disk( Outdated -> Inconsistent ) 0000009400000100 10/13/2020 16:14:54:5101.3163834212 [print_state_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(WFBitMapT), pdvflag(0x100600): drbdbsr_start_resync, repl( WFBitMapT -> SyncTarget ) 0000009500000101 10/13/2020 16:14:54:5101.3163834682 [drbdbsr_start_resync] WDRBD_INFO<6>drbd[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 6834844 KB [178711 bits set]). 0000009600000102 10/13/2020 16:14:54:5101.3163841175 [__receive_stateuuids] [UUID:16] WDRBDbsr_INFO<6>drbdwarn<4> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): receive new repl state "SyncTarget" 00000097 current but not update UUID: 83F530CA41FA9869 00000103 10/13/2020 16:14:54:5110.3316370316 [make_resync_request] WDRBD_INFO<6>drbd[RESYNC/OV:109] bsr_info<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): DRBDBSR_END_OF_BITMAP(2580266625786753), device->bm_resync_fo : 13708802651392, bm_set : 8132
resync finished
Code Block 0000009800000104 10/13/2020 16:14:54:5110.3316436530 [drbdbsr_resync_finished_finished] [RESYNC/OV:116] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): Resync done (total 19 sec; paused 0 sec; 683868 K/sec), hit bit (in sync 0; marked rl 0) 0000009900000105 10/13/2020 16:14:54:5110.3316436613 [drbdbsr_print_uuids] [UUID:1] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): drbdbsr_resync_finished, updated UUIDs BA6151025D30A88483F530CA41FA9868:0000000000000000:233537F4119A9BFE7B326D963D9936CE:B43F1BF5DA1F8DFE3DF87D1E1EFC3E92 0000010000000106 10/13/2020 16:14:54:5110.3316436766 [print_state_change] [STATE:20] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2, ds(Inconsistent), dvflag(0x20004): drbdbsr_resync_finished, disk( Inconsistent -> UpToDate ) 0000010100000107 10/13/2020 16:14:54:5110.3316436796 [print_state_change] [STATE:21] WDRBDbsr_INFO<6>drbdinfo<6> bsr r0/0 minor 2 pnode-id:0, pdsk(UpToDate), prpl(SyncTarget), pdvflag(0x100600): drbdbsr_resync_finished, repl( SyncTarget -> Established ) 0000010200000108 10/13/2020 16:14:54:5110.3316441781 [drbdbsr_queue_bitmap_io] WDRBD_INFO<6>drbd[RESYNC/OV:33] bsr_info<6> bsr r0/0 minor 2, ds(UpToDate), dvflag(0x20000): write from resync_finished, worker.task(FFFFE0007414EEC0FFFFE0016F4E7770), current(FFFFE0007414EEC0FFFFE0016F4E7770)