Login
Log in using an SSO provider:
Fedora Account System
Red Hat Associate
Red Hat Customer
Login using a Red Hat Bugzilla account
Forgot Password
Create an Account
Red Hat Bugzilla – Attachment 1981341 Details for
Bug 2224249
Manual and Automatic failover issues in RHEL 9
Home
New
Search
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh89 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
[?]
This site requires JavaScript to be enabled to function correctly, please enable it.
LatestLogs_post_call_with_MS&Rhel
pacemaker_rhel91.log (text/plain), 208.85 KB, created by
Aravind Mahadevan
on 2023-08-02 18:22:59 UTC
(
hide
)
Description:
LatestLogs_post_call_with_MS&Rhel
Filename:
MIME Type:
Creator:
Aravind Mahadevan
Created:
2023-08-02 18:22:59 UTC
Size:
208.85 KB
patch
obsolete
>Aug 01 10:59:21.130 rhel91 pacemakerd [3734567] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.131 rhel91 pacemakerd [3734567] (ipc_post_disconnect) info: Disconnected from launcher IPC API >Aug 01 10:59:21.134 rhel91 pacemakerd [3734567] (get_cluster_type) info: Detected an active 'corosync' cluster >Aug 01 10:59:21.134 rhel91 pacemakerd [3734567] (mcp_read_config) info: Reading configuration for corosync stack >Aug 01 10:59:21.135 rhel91 pacemakerd [3734567] (main) notice: Starting Pacemaker 2.1.5-9.el9_2 | build=a3f44794f94 features:agent-manpages cibsecrets corosync-ge-2 default-concurrent-fencing default-resource-stickiness default-sbd-sync generated-manpages monotonic nagios ncurses remote systemd >Aug 01 10:59:21.135 rhel91 pacemakerd [3734567] (qb_ipcs_us_publish) info: server name: pacemakerd >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (pcmk__ipc_is_authentic_process_active) info: Could not connect to cib_ro IPC: Connection refused >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (pcmk__ipc_is_authentic_process_active) info: Could not connect to stonith-ng IPC: Connection refused >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (pcmk__ipc_is_authentic_process_active) info: Could not connect to lrmd IPC: Connection refused >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (pcmk__ipc_is_authentic_process_active) info: Could not connect to attrd IPC: Connection refused >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (pcmk__ipc_is_authentic_process_active) info: Could not connect to pengine IPC: Connection refused >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (pcmk__ipc_is_authentic_process_active) info: Could not connect to crmd IPC: Connection refused >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (start_child) info: Using uid=189 and group=189 for process pacemaker-based >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (start_child) info: Forked child 3734568 for process pacemaker-based >Aug 01 10:59:21.143 rhel91 pacemakerd [3734567] (start_child) info: Forked child 3734569 for process pacemaker-fenced >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Forked child 3734570 for process pacemaker-execd >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Using uid=189 and group=189 for process pacemaker-attrd >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Forked child 3734571 for process pacemaker-attrd >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Using uid=189 and group=189 for process pacemaker-schedulerd >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Forked child 3734572 for process pacemaker-schedulerd >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Using uid=189 and group=189 for process pacemaker-controld >Aug 01 10:59:21.144 rhel91 pacemakerd [3734567] (start_child) info: Forked child 3734573 for process pacemaker-controld >Aug 01 10:59:21.145 rhel91 pacemakerd [3734567] (main) notice: Pacemaker daemon successfully started and accepting connections >Aug 01 10:59:21.148 rhel91 pacemaker-execd [3734570] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.148 rhel91 pacemaker-execd [3734570] (main) notice: Starting Pacemaker local executor >Aug 01 10:59:21.148 rhel91 pacemaker-execd [3734570] (qb_ipcs_us_publish) info: server name: lrmd >Aug 01 10:59:21.148 rhel91 pacemaker-execd [3734570] (main) notice: Pacemaker local executor successfully started and accepting connections >Aug 01 10:59:21.148 rhel91 pacemaker-execd [3734570] (main) notice: OCF resource agent search path is /usr/lib/ocf/resource.d >Aug 01 10:59:21.148 rhel91 pacemaker-fenced [3734569] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.148 rhel91 pacemaker-fenced [3734569] (main) notice: Starting Pacemaker fencer >Aug 01 10:59:21.148 rhel91 pacemaker-fenced [3734569] (get_cluster_type) info: Verifying cluster type: 'corosync' >Aug 01 10:59:21.148 rhel91 pacemaker-fenced [3734569] (get_cluster_type) info: Assuming an active 'corosync' cluster >Aug 01 10:59:21.148 rhel91 pacemaker-fenced [3734569] (crm_cluster_connect) notice: Connecting to corosync cluster infrastructure >Aug 01 10:59:21.149 rhel91 pacemaker-attrd [3734571] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.149 rhel91 pacemaker-attrd [3734571] (main) notice: Starting Pacemaker node attribute manager >Aug 01 10:59:21.149 rhel91 pacemaker-attrd [3734571] (ipc_post_disconnect) info: Disconnected from attribute manager IPC API >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.149 rhel91 pacemaker-attrd [3734571] (cib_native_signon_raw) info: Could not connect to CIB manager for attrd >Aug 01 10:59:21.149 rhel91 pacemaker-attrd [3734571] (cib_native_signon_raw) info: Connection to CIB manager for attrd failed: Transport endpoint is not connected >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (main) notice: Starting Pacemaker CIB manager >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (get_cluster_type) info: Verifying cluster type: 'corosync' >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (get_cluster_type) info: Assuming an active 'corosync' cluster >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (pcmk__daemon_can_write) notice: /var/lib/pacemaker/cib/cib.xml not found: No such file or directory >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (pcmk__daemon_can_write) notice: /var/lib/pacemaker/cib/cib.xml.sig not found: No such file or directory >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (retrieveCib) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.xml (digest: /var/lib/pacemaker/cib/cib.xml.sig) >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (cib_file_read_and_verify) warning: Could not verify cluster configuration file /var/lib/pacemaker/cib/cib.xml: No such file or directory (2) >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (readCibXmlFile) warning: Primary configuration corrupt or unusable, trying backups in /var/lib/pacemaker/cib >Aug 01 10:59:21.149 rhel91 pacemaker-based [3734568] (readCibXmlFile) warning: Continuing with an empty configuration. >Aug 01 10:59:21.149 rhel91 pacemaker-schedulerd[3734572] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.149 rhel91 pacemaker-schedulerd[3734572] (main) notice: Starting Pacemaker scheduler >Aug 01 10:59:21.149 rhel91 pacemaker-schedulerd[3734572] (qb_ipcs_us_publish) info: server name: pengine >Aug 01 10:59:21.149 rhel91 pacemaker-schedulerd[3734572] (main) notice: Pacemaker scheduler successfully started and accepting connections >Aug 01 10:59:21.150 rhel91 pacemaker-controld [3734573] (crm_log_init) info: Changed active directory to /var/lib/pacemaker/cores >Aug 01 10:59:21.150 rhel91 pacemaker-controld [3734573] (main) notice: Starting Pacemaker controller >Aug 01 10:59:21.150 rhel91 pacemaker-controld [3734573] (do_log) info: Input I_STARTUP received in state S_STARTING from crmd_init >Aug 01 10:59:21.150 rhel91 pacemaker-controld [3734573] (cib_native_signon_raw) info: Could not connect to CIB manager for crmd >Aug 01 10:59:21.150 rhel91 pacemaker-controld [3734573] (cib_native_signon_raw) info: Connection to CIB manager for crmd failed: Transport endpoint is not connected >Aug 01 10:59:21.152 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Created entry 412a68d7-4fb9-4186-8383-318c524da4dc/0x562d1b4b6ef0 for node rhel91/1 (1 total) >Aug 01 10:59:21.152 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Node 1 is now known as rhel91 >Aug 01 10:59:21.156 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Node 1 has uuid 1 >Aug 01 10:59:21.156 rhel91 pacemaker-fenced [3734569] (crm_update_peer_proc) info: cluster_connect_cpg: Node rhel91[1] - corosync-cpg is now online >Aug 01 10:59:21.156 rhel91 pacemaker-fenced [3734569] (update_peer_state_iter) notice: Node rhel91 state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:21.156 rhel91 pacemaker-fenced [3734569] (pcmk__corosync_connect) info: Connection to corosync established >Aug 01 10:59:21.158 rhel91 pacemaker-fenced [3734569] (cib_native_signon_raw) info: Could not connect to CIB manager for stonithd >Aug 01 10:59:21.158 rhel91 pacemaker-fenced [3734569] (cib_native_signon_raw) info: Connection to CIB manager for stonithd failed: Transport endpoint is not connected >Aug 01 10:59:21.160 rhel91 pacemaker-based [3734568] (crm_cluster_connect) notice: Connecting to corosync cluster infrastructure >Aug 01 10:59:21.164 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Created entry 5ab6d99d-52a9-4e29-b0d4-678817a1d976/0x55994de30eb0 for node rhel91/1 (1 total) >Aug 01 10:59:21.164 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Node 1 is now known as rhel91 >Aug 01 10:59:21.166 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Node 1 has uuid 1 >Aug 01 10:59:21.166 rhel91 pacemaker-based [3734568] (crm_update_peer_proc) info: cluster_connect_cpg: Node rhel91[1] - corosync-cpg is now online >Aug 01 10:59:21.166 rhel91 pacemaker-based [3734568] (update_peer_state_iter) notice: Node rhel91 state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:21.166 rhel91 pacemaker-based [3734568] (pcmk__corosync_connect) info: Connection to corosync established >Aug 01 10:59:21.167 rhel91 pacemaker-based [3734568] (qb_ipcs_us_publish) info: server name: cib_ro >Aug 01 10:59:21.167 rhel91 pacemaker-based [3734568] (qb_ipcs_us_publish) info: server name: cib_rw >Aug 01 10:59:21.167 rhel91 pacemaker-based [3734568] (qb_ipcs_us_publish) info: server name: cib_shm >Aug 01 10:59:21.167 rhel91 pacemaker-based [3734568] (main) notice: Pacemaker CIB manager successfully started and accepting connections >Aug 01 10:59:21.168 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 0: node 1 pid 3734568 joined via cpg_join >Aug 01 10:59:21.168 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 0: rhel91 (node 1 pid 3734568) is member >Aug 01 10:59:21.168 rhel91 pacemaker-based [3734568] (cib_file_read_and_verify) warning: Could not verify cluster configuration file /var/lib/pacemaker/cib/cib.xml: No such file or directory (2) >Aug 01 10:59:21.182 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-0.raw >Aug 01 10:59:21.196 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.0.0 of the CIB to disk (digest: d6b33ef8090fc572254da1fc49c0b24d) >Aug 01 10:59:21.211 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.Eq8q76 (digest: /var/lib/pacemaker/cib/cib.GgGgLe) >Aug 01 10:59:22.151 rhel91 pacemaker-attrd [3734571] (cib_native_signon_raw) info: Successfully connected to CIB manager for attrd >Aug 01 10:59:22.151 rhel91 pacemaker-attrd [3734571] (main) info: CIB connection active >Aug 01 10:59:22.151 rhel91 pacemaker-controld [3734573] (cib_native_signon_raw) info: Successfully connected to CIB manager for crmd >Aug 01 10:59:22.151 rhel91 pacemaker-attrd [3734571] (get_cluster_type) info: Verifying cluster type: 'corosync' >Aug 01 10:59:22.151 rhel91 pacemaker-attrd [3734571] (get_cluster_type) info: Assuming an active 'corosync' cluster >Aug 01 10:59:22.151 rhel91 pacemaker-attrd [3734571] (crm_cluster_connect) notice: Connecting to corosync cluster infrastructure >Aug 01 10:59:22.151 rhel91 pacemaker-controld [3734573] (get_cluster_type) info: Verifying cluster type: 'corosync' >Aug 01 10:59:22.151 rhel91 pacemaker-controld [3734573] (get_cluster_type) info: Assuming an active 'corosync' cluster >Aug 01 10:59:22.151 rhel91 pacemaker-controld [3734573] (crm_cluster_connect) notice: Connecting to corosync cluster infrastructure >Aug 01 10:59:22.157 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Created entry 7857d908-4ce9-4a0a-928a-4f6507bf084d/0x5644f0a50150 for node rhel91/1 (1 total) >Aug 01 10:59:22.157 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Node 1 is now known as rhel91 >Aug 01 10:59:22.158 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Created entry 381b9209-e0c4-44d3-a6c4-c481f32b5ff2/0x555b4b038130 for node rhel91/1 (1 total) >Aug 01 10:59:22.158 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Node 1 is now known as rhel91 >Aug 01 10:59:22.158 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Cluster node rhel91 is now in unknown state >Aug 01 10:59:22.159 rhel91 pacemaker-fenced [3734569] (cib_native_signon_raw) info: Successfully connected to CIB manager for stonithd >Aug 01 10:59:22.159 rhel91 pacemaker-fenced [3734569] (setup_cib) info: Watching for fencing topology changes >Aug 01 10:59:22.159 rhel91 pacemaker-fenced [3734569] (qb_ipcs_us_publish) info: server name: stonith-ng >Aug 01 10:59:22.159 rhel91 pacemaker-fenced [3734569] (main) notice: Pacemaker fencer successfully started and accepting connections >Aug 01 10:59:22.159 rhel91 pacemaker-fenced [3734569] (init_cib_cache_cb) info: Updating device list from CIB >Aug 01 10:59:22.159 rhel91 pacemaker-fenced [3734569] (cib_devices_update) info: Updating devices to version 0.0.0 >Aug 01 10:59:22.160 rhel91 pacemaker-fenced [3734569] (unpack_nodes) info: Creating a fake local node >Aug 01 10:59:22.160 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 0: node 1 pid 3734569 joined via cpg_join >Aug 01 10:59:22.160 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 0: rhel91 (node 1 pid 3734569) is member >Aug 01 10:59:22.161 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Node 1 has uuid 1 >Aug 01 10:59:22.161 rhel91 pacemaker-attrd [3734571] (crm_update_peer_proc) info: cluster_connect_cpg: Node rhel91[1] - corosync-cpg is now online >Aug 01 10:59:22.161 rhel91 pacemaker-attrd [3734571] (update_peer_state_iter) notice: Node rhel91 state is now member | nodeid=1 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:22.161 rhel91 pacemaker-attrd [3734571] (pcmk__corosync_connect) info: Connection to corosync established >Aug 01 10:59:22.162 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Node 1 has uuid 1 >Aug 01 10:59:22.162 rhel91 pacemaker-controld [3734573] (crm_update_peer_proc) info: cluster_connect_cpg: Node rhel91[1] - corosync-cpg is now online >Aug 01 10:59:22.164 rhel91 pacemaker-attrd [3734571] (main) info: Cluster connection active >Aug 01 10:59:22.164 rhel91 pacemaker-attrd [3734571] (attrd_erase_attrs) info: Clearing transient attributes from CIB | xpath=//node_state[@uname='rhel91']/transient_attributes >Aug 01 10:59:22.164 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_delete operation for section //node_state[@uname='rhel91']/transient_attributes to all (origin=local/attrd/2) >Aug 01 10:59:22.164 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Node rhel91 is now a peer | DC=<none> old=0000000 new=0x4000000 >Aug 01 10:59:22.164 rhel91 pacemaker-controld [3734573] (te_trigger_stonith_history_sync) info: Fence history will be synchronized cluster-wide within 5 seconds >Aug 01 10:59:22.164 rhel91 pacemaker-controld [3734573] (pcmk__corosync_connect) info: Connection to corosync established >Aug 01 10:59:22.168 rhel91 pacemaker-attrd [3734571] (qb_ipcs_us_publish) info: server name: attrd >Aug 01 10:59:22.168 rhel91 pacemaker-attrd [3734571] (main) notice: Pacemaker node attribute manager successfully started and accepting connections >Aug 01 10:59:22.169 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 0: node 1 pid 3734571 joined via cpg_join >Aug 01 10:59:22.169 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 0: rhel91 (node 1 pid 3734571) is member >Aug 01 10:59:22.169 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting #attrd-protocol[rhel91]: (unset) -> 5 | from rhel91 with no write delay >Aug 01 10:59:22.169 rhel91 pacemaker-attrd [3734571] (attrd_start_election_if_needed) info: Starting an election to determine the writer >Aug 01 10:59:22.170 rhel91 pacemaker-attrd [3734571] (election_check) info: election-attrd won by local node >Aug 01 10:59:22.170 rhel91 pacemaker-attrd [3734571] (attrd_declare_winner) notice: Recorded local node as attribute writer (was unset) >Aug 01 10:59:22.170 rhel91 pacemaker-attrd [3734571] (attrd_write_attribute) info: Processed 1 private change for #attrd-protocol, id=n/a, set=n/a >Aug 01 10:59:22.170 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_delete operation for section //node_state[@uname='rhel91']/transient_attributes: OK (rc=0, origin=rhel91/attrd/2, version=0.0.0) >Aug 01 10:59:22.171 rhel91 pacemaker-controld [3734573] (pcmk__corosync_quorum_connect) warning: No quorum >Aug 01 10:59:22.173 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Created entry dcec76b5-91bc-4423-8a88-cec0fba2fa4d/0x555b4b03bb50 for node rhel92/2 (2 total) >Aug 01 10:59:22.173 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Node 2 is now known as rhel92 >Aug 01 10:59:22.173 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Cluster node rhel92 is now in unknown state >Aug 01 10:59:22.173 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Node 2 has uuid 2 >Aug 01 10:59:22.174 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Created entry c15146ac-561b-4723-8169-bb590ffc6c7c/0x555b4b03bbd0 for node rhel93/3 (3 total) >Aug 01 10:59:22.174 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Node 3 is now known as rhel93 >Aug 01 10:59:22.174 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Cluster node rhel93 is now in unknown state >Aug 01 10:59:22.174 rhel91 pacemaker-controld [3734573] (crm_get_peer) info: Node 3 has uuid 3 >Aug 01 10:59:22.176 rhel91 pacemaker-controld [3734573] (do_ha_control) info: Connected to the cluster >Aug 01 10:59:22.176 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section nodes to all (origin=local/crmd/5) >Aug 01 10:59:22.176 rhel91 pacemaker-controld [3734573] (lrmd_ipc_connect) info: Connecting to executor >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.0.0 2 >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.1.0 (null) >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=1 >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/nodes: <node id="1" uname="rhel91"/> >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/nodes: <node id="2" uname="rhel92"/> >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/nodes: <node id="3" uname="rhel93"/> >Aug 01 10:59:22.177 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section nodes: OK (rc=0, origin=rhel91/crmd/5, version=0.1.0) >Aug 01 10:59:22.177 rhel91 pacemaker-controld [3734573] (try_local_executor_connect) info: Connection to the local executor established >Aug 01 10:59:22.177 rhel91 pacemaker-controld [3734573] (do_started) info: Delaying start, no membership data (0000000000100000) >Aug 01 10:59:22.177 rhel91 pacemaker-controld [3734573] (do_started) info: Delaying start, no membership data (0000000000100000) >Aug 01 10:59:22.177 rhel91 pacemaker-controld [3734573] (quorum_notification_cb) info: Quorum still lost | membership=14 members=1 >Aug 01 10:59:22.177 rhel91 pacemaker-controld [3734573] (update_peer_state_iter) notice: Node rhel91 state is now member | nodeid=1 previous=unknown source=quorum_notification_cb >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Cluster node rhel91 is now member (was in unknown state) >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (pcmk__reap_unseen_nodes) info: State of node rhel93[3] is still unknown >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (pcmk__reap_unseen_nodes) info: State of node rhel92[2] is still unknown >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (do_started) info: Delaying start, Config not read (0000000000000040) >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 0: node 1 pid 3734573 joined via cpg_join >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 0: rhel91 (node 1 pid 3734573) is member >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (do_started) info: Delaying start, Config not read (0000000000000040) >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (qb_ipcs_us_publish) info: server name: crmd >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (do_started) notice: Pacemaker controller successfully started and accepting connections >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (do_log) info: Input I_PENDING received in state S_STARTING from do_started >Aug 01 10:59:22.178 rhel91 pacemaker-controld [3734573] (do_state_transition) notice: State transition S_STARTING -> S_PENDING | input=I_PENDING cause=C_FSA_INTERNAL origin=do_started >Aug 01 10:59:22.193 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-1.raw >Aug 01 10:59:22.206 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.1.0 of the CIB to disk (digest: f802ced469a9f68c7ede183ddbe90023) >Aug 01 10:59:22.221 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.L4b6U8 (digest: /var/lib/pacemaker/cib/cib.rdrcxY) >Aug 01 10:59:23.181 rhel91 pacemaker-controld [3734573] (te_trigger_stonith_history_sync) info: Fence history will be synchronized cluster-wide within 30 seconds >Aug 01 10:59:23.181 rhel91 pacemaker-controld [3734573] (te_connect_stonith) notice: Fencer successfully connected >Aug 01 10:59:23.358 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 1: node 2 pid 1478936 joined via cluster join >Aug 01 10:59:23.358 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 1: node 3 pid 953381 joined via cluster join >Aug 01 10:59:23.358 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 1: rhel91 (node 1 pid 3734571) is member >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 1: node 2 pid 1478938 joined via cluster join >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 1: node 3 pid 953383 joined via cluster join >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 1: rhel91 (node 1 pid 3734573) is member >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 1: rhel92 (node 2 pid 1478938) is member >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel92[2] - corosync-cpg is now online >Aug 01 10:59:23.358 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 1: node 2 pid 1478934 joined via cluster join >Aug 01 10:59:23.358 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 1: node 3 pid 953379 joined via cluster join >Aug 01 10:59:23.358 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 1: rhel91 (node 1 pid 3734569) is member >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Node rhel92 is now a peer | DC=<none> old=0000000 new=0x4000000 >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (te_trigger_stonith_history_sync) info: Fence history will be synchronized cluster-wide within 5 seconds >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (pcmk_cpg_membership) info: Group crmd event 1: rhel93 (node 3 pid 953383) is member >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel93[3] - corosync-cpg is now online >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Node rhel93 is now a peer | DC=<none> old=0000000 new=0x4000000 >Aug 01 10:59:23.358 rhel91 pacemaker-controld [3734573] (te_trigger_stonith_history_sync) info: Fence history will be synchronized cluster-wide within 5 seconds >Aug 01 10:59:23.359 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 1: node 2 pid 1478933 joined via cluster join >Aug 01 10:59:23.359 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 1: node 3 pid 953378 joined via cluster join >Aug 01 10:59:23.359 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 1: rhel91 (node 1 pid 3734568) is member >Aug 01 10:59:23.364 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Created entry 029a14cd-9da4-4625-a901-d22ffd624de2/0x562d1b4cbb10 for node rhel92/2 (2 total) >Aug 01 10:59:23.364 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Node 2 is now known as rhel92 >Aug 01 10:59:23.364 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Node 2 has uuid 2 >Aug 01 10:59:23.364 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 1: rhel92 (node 2 pid 1478934) is member >Aug 01 10:59:23.364 rhel91 pacemaker-fenced [3734569] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel92[2] - corosync-cpg is now online >Aug 01 10:59:23.364 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Created entry 06f621be-509b-457b-a1b8-b227ce628161/0x5644f0a52660 for node rhel92/2 (2 total) >Aug 01 10:59:23.364 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Node 2 is now known as rhel92 >Aug 01 10:59:23.364 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Node 2 has uuid 2 >Aug 01 10:59:23.364 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 1: rhel92 (node 2 pid 1478936) is member >Aug 01 10:59:23.364 rhel91 pacemaker-attrd [3734571] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel92[2] - corosync-cpg is now online >Aug 01 10:59:23.364 rhel91 pacemaker-fenced [3734569] (update_peer_state_iter) notice: Node rhel92 state is now member | nodeid=2 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:23.364 rhel91 pacemaker-attrd [3734571] (update_peer_state_iter) notice: Node rhel92 state is now member | nodeid=2 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:23.367 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Created entry 8fb807e4-414b-4218-b2e6-1757afeef9a0/0x55994debd090 for node rhel92/2 (2 total) >Aug 01 10:59:23.367 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Node 2 is now known as rhel92 >Aug 01 10:59:23.367 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Node 2 has uuid 2 >Aug 01 10:59:23.367 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 1: rhel92 (node 2 pid 1478933) is member >Aug 01 10:59:23.367 rhel91 pacemaker-based [3734568] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel92[2] - corosync-cpg is now online >Aug 01 10:59:23.367 rhel91 pacemaker-based [3734568] (update_peer_state_iter) notice: Node rhel92 state is now member | nodeid=2 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:23.369 rhel91 pacemaker-controld [3734573] (quorum_notification_cb) notice: Quorum acquired | membership=26 members=3 >Aug 01 10:59:23.369 rhel91 pacemaker-controld [3734573] (update_peer_state_iter) notice: Node rhel92 state is now member | nodeid=2 previous=unknown source=quorum_notification_cb >Aug 01 10:59:23.369 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Cluster node rhel92 is now member (was in unknown state) >Aug 01 10:59:23.369 rhel91 pacemaker-controld [3734573] (update_peer_state_iter) notice: Node rhel93 state is now member | nodeid=3 previous=unknown source=quorum_notification_cb >Aug 01 10:59:23.369 rhel91 pacemaker-controld [3734573] (peer_update_callback) info: Cluster node rhel93 is now member (was in unknown state) >Aug 01 10:59:23.369 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Created entry 785642ef-6d5b-46b2-af11-fc27afc8f238/0x562d1b4bd7c0 for node rhel93/3 (3 total) >Aug 01 10:59:23.369 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Node 3 is now known as rhel93 >Aug 01 10:59:23.369 rhel91 pacemaker-fenced [3734569] (crm_get_peer) info: Node 3 has uuid 3 >Aug 01 10:59:23.369 rhel91 pacemaker-fenced [3734569] (pcmk_cpg_membership) info: Group stonith-ng event 1: rhel93 (node 3 pid 953379) is member >Aug 01 10:59:23.369 rhel91 pacemaker-fenced [3734569] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel93[3] - corosync-cpg is now online >Aug 01 10:59:23.369 rhel91 pacemaker-fenced [3734569] (update_peer_state_iter) notice: Node rhel93 state is now member | nodeid=3 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:23.369 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Created entry df07ba50-4de2-4d09-9b50-ac2e987cb1f5/0x5644f0a57300 for node rhel93/3 (3 total) >Aug 01 10:59:23.369 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Node 3 is now known as rhel93 >Aug 01 10:59:23.369 rhel91 pacemaker-attrd [3734571] (crm_get_peer) info: Node 3 has uuid 3 >Aug 01 10:59:23.369 rhel91 pacemaker-attrd [3734571] (pcmk_cpg_membership) info: Group attrd event 1: rhel93 (node 3 pid 953381) is member >Aug 01 10:59:23.369 rhel91 pacemaker-attrd [3734571] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel93[3] - corosync-cpg is now online >Aug 01 10:59:23.369 rhel91 pacemaker-attrd [3734571] (update_peer_state_iter) notice: Node rhel93 state is now member | nodeid=3 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:23.370 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Created entry 30779c08-99a0-46b7-9f6c-54f1ae94a419/0x55994debcf60 for node rhel93/3 (3 total) >Aug 01 10:59:23.370 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Node 3 is now known as rhel93 >Aug 01 10:59:23.370 rhel91 pacemaker-based [3734568] (crm_get_peer) info: Node 3 has uuid 3 >Aug 01 10:59:23.370 rhel91 pacemaker-based [3734568] (pcmk_cpg_membership) info: Group cib event 1: rhel93 (node 3 pid 953378) is member >Aug 01 10:59:23.370 rhel91 pacemaker-based [3734568] (crm_update_peer_proc) info: pcmk_cpg_membership: Node rhel93[3] - corosync-cpg is now online >Aug 01 10:59:23.370 rhel91 pacemaker-based [3734568] (update_peer_state_iter) notice: Node rhel93 state is now member | nodeid=3 previous=unknown source=crm_update_peer_proc >Aug 01 10:59:23.574 rhel91 pacemaker-attrd [3734571] (attrd_check_for_new_writer) notice: Detected another attribute writer (rhel93), starting new election >Aug 01 10:59:23.574 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel93 >Aug 01 10:59:23.574 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting #attrd-protocol[rhel93]: (unset) -> 5 | from rhel93 with no write delay >Aug 01 10:59:23.575 rhel91 pacemaker-attrd [3734571] (attrd_check_for_new_writer) notice: Recorded new attribute writer: rhel92 (was rhel91) >Aug 01 10:59:23.575 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel92 >Aug 01 10:59:23.575 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting #attrd-protocol[rhel92]: (unset) -> 5 | from rhel92 with no write delay >Aug 01 10:59:23.575 rhel91 pacemaker-attrd [3734571] (election_count_vote) info: election-attrd round 2 (owner node ID 2) pass: vote from rhel92 (Uptime) >Aug 01 10:59:23.575 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel92 >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (election_count_vote) info: election-attrd round 2 (owner node ID 3) lost: vote from rhel93 (Uptime) >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel93 >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel93 >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (election_count_vote) info: election-attrd round 3 (owner node ID 3) lost: vote from rhel93 (Uptime) >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel92 >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (election_count_vote) info: election-attrd round 4 (owner node ID 3) lost: vote from rhel93 (Uptime) >Aug 01 10:59:23.576 rhel91 pacemaker-attrd [3734571] (election_count_vote) info: election-attrd round 5 (owner node ID 3) lost: vote from rhel93 (Uptime) >Aug 01 10:59:23.578 rhel91 pacemaker-attrd [3734571] (attrd_peer_sync_response) info: Processing sync-response from rhel93 >Aug 01 10:59:43.153 rhel91 pacemaker-controld [3734573] (election_count_vote) info: election-DC round 1 (owner node ID 2) lost: vote from rhel92 (Uptime) >Aug 01 10:59:43.153 rhel91 pacemaker-controld [3734573] (do_log) info: Input I_PENDING received in state S_PENDING from do_election_count_vote >Aug 01 10:59:43.166 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section cib: OK (rc=0, origin=rhel92/crmd/9, version=0.1.0) >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.1.0 2 >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.2.0 (null) >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=2 >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/crm_config: <cluster_property_set id="cib-bootstrap-options"/> >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="cib-bootstrap-options-have-watchdog" name="have-watchdog" value="false"/> >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </cluster_property_set> >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section crm_config: OK (rc=0, origin=rhel92/crmd/11, version=0.2.0) >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.2.0 2 >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.3.0 (null) >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=3 >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/crm_config/cluster_property_set[@id='cib-bootstrap-options']: <nvpair id="cib-bootstrap-options-dc-version" name="dc-version" value="2.1.5-9.el9_2-a3f44794f94"/> >Aug 01 10:59:43.167 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section crm_config: OK (rc=0, origin=rhel92/crmd/13, version=0.3.0) >Aug 01 10:59:43.168 rhel91 pacemaker-controld [3734573] (stonith__watchdog_fencing_enabled_for_node_api) notice: Cluster does not have watchdog fencing device >Aug 01 10:59:43.169 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.3.0 2 >Aug 01 10:59:43.169 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.4.0 (null) >Aug 01 10:59:43.169 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=4 >Aug 01 10:59:43.169 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/crm_config/cluster_property_set[@id='cib-bootstrap-options']: <nvpair id="cib-bootstrap-options-cluster-infrastructure" name="cluster-infrastructure" value="corosync"/> >Aug 01 10:59:43.169 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section crm_config: OK (rc=0, origin=rhel92/crmd/15, version=0.4.0) >Aug 01 10:59:43.169 rhel91 pacemaker-controld [3734573] (stonith__watchdog_fencing_enabled_for_node_api) notice: Cluster does not have watchdog fencing device >Aug 01 10:59:43.170 rhel91 pacemaker-controld [3734573] (update_dc) info: Set DC to rhel92 (3.16.2) >Aug 01 10:59:43.170 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.4.0 2 >Aug 01 10:59:43.170 rhel91 pacemaker-controld [3734573] (pcmk__update_peer_expected) info: update_dc: Node rhel92[2] - expected state is now member (was (null)) >Aug 01 10:59:43.170 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.0 (null) >Aug 01 10:59:43.170 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=5 >Aug 01 10:59:43.170 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/crm_config/cluster_property_set[@id='cib-bootstrap-options']: <nvpair id="cib-bootstrap-options-cluster-name" name="cluster-name" value="cluster1"/> >Aug 01 10:59:43.170 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section crm_config: OK (rc=0, origin=rhel92/crmd/17, version=0.5.0) >Aug 01 10:59:43.170 rhel91 pacemaker-controld [3734573] (stonith__watchdog_fencing_enabled_for_node_api) notice: Cluster does not have watchdog fencing device >Aug 01 10:59:43.172 rhel91 pacemaker-controld [3734573] (connect_and_send_attrd_request) info: Connecting to cluster... 5 retries remaining >Aug 01 10:59:43.172 rhel91 pacemaker-based [3734568] (cib_process_replace) info: Digest matched on replace from rhel92: 168cc25e1ac95f5ce314e1cdd0adbf01 >Aug 01 10:59:43.172 rhel91 pacemaker-based [3734568] (cib_process_replace) info: Replaced 0.5.0 with 0.5.0 from rhel92 >Aug 01 10:59:43.172 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_replace operation for section 'all': OK (rc=0, origin=rhel92/crmd/22, version=0.5.0) >Aug 01 10:59:43.172 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section nodes: OK (rc=0, origin=rhel92/crmd/23, version=0.5.0) >Aug 01 10:59:43.172 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section nodes: OK (rc=0, origin=rhel92/crmd/24, version=0.5.0) >Aug 01 10:59:43.172 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section nodes: OK (rc=0, origin=rhel92/crmd/25, version=0.5.0) >Aug 01 10:59:43.172 rhel91 pacemaker-controld [3734573] (do_log) info: Input I_NOT_DC received in state S_PENDING from do_cl_join_finalize_respond >Aug 01 10:59:43.172 rhel91 pacemaker-controld [3734573] (do_state_transition) notice: State transition S_PENDING -> S_NOT_DC | input=I_NOT_DC cause=C_HA_MESSAGE origin=do_cl_join_finalize_respond >Aug 01 10:59:43.173 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting #feature-set[rhel92]: (unset) -> 3.16.2 | from rhel92 with no write delay >Aug 01 10:59:43.173 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting #feature-set[rhel93]: (unset) -> 3.16.2 | from rhel93 with no write delay >Aug 01 10:59:43.173 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting #feature-set[rhel91]: (unset) -> 3.16.2 | from rhel91 with no write delay >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_delete operation for section //node_state[@uname='rhel92']/lrm: OK (rc=0, origin=rhel92/crmd/26, version=0.5.0) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.0 2 >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.1 (null) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=1 >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status: <node_state id="2" uname="rhel92" in_ccm="true" crmd="online" crm-debug-origin="controld_query_executor_state"/> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm id="2"> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_resources/> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </node_state> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/27, version=0.5.1) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_delete operation for section //node_state[@uname='rhel93']/lrm: OK (rc=0, origin=rhel92/crmd/28, version=0.5.1) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.1 2 >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.2 (null) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=2 >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status: <node_state id="3" uname="rhel93" in_ccm="true" crmd="online" crm-debug-origin="controld_query_executor_state"/> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm id="3"> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_resources/> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </node_state> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/29, version=0.5.2) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.2 2 >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.3 (null) >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=3 >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']: <transient_attributes id="2"/> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <instance_attributes id="status-2"> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="status-2-.feature-set" name="#feature-set" value="3.16.2"/> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </instance_attributes> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </transient_attributes> >Aug 01 10:59:43.174 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/attrd/4, version=0.5.3) >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_delete operation for section //node_state[@uname='rhel91']/lrm: OK (rc=0, origin=rhel92/crmd/30, version=0.5.3) >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.3 2 >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.4 (null) >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=4 >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status: <node_state id="1" uname="rhel91" in_ccm="true" crmd="online" crm-debug-origin="controld_query_executor_state"/> >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm id="1"> >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_resources/> >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm> >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </node_state> >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/31, version=0.5.4) >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section nodes: OK (rc=0, origin=rhel92/crmd/35, version=0.5.4) >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.4 2 >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.5 (null) >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=5 >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_state_transition, @join=member, @expected=member >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='3']: @crm-debug-origin=do_state_transition, @join=member, @expected=member >Aug 01 10:59:43.175 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_state_transition, @join=member, @expected=member >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/36, version=0.5.5) >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.5 2 >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.6 (null) >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=6, @have-quorum=1, @dc-uuid=2 >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section cib: OK (rc=0, origin=rhel92/crmd/37, version=0.5.6) >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.6 2 >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.5.7 (null) >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=7 >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']: <transient_attributes id="3"/> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <instance_attributes id="status-3"> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="status-3-.feature-set" name="#feature-set" value="3.16.2"/> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </instance_attributes> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </transient_attributes> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']: <transient_attributes id="1"/> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <instance_attributes id="status-1"> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="status-1-.feature-set" name="#feature-set" value="3.16.2"/> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </instance_attributes> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </transient_attributes> >Aug 01 10:59:43.176 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/attrd/5, version=0.5.7) >Aug 01 10:59:43.185 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-2.raw >Aug 01 10:59:43.194 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.3.0 of the CIB to disk (digest: 49e532c4f89fe3b1e2ee59b64e757f7e) >Aug 01 10:59:43.201 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.Jj9OHv (digest: /var/lib/pacemaker/cib/cib.4zdeNy) >Aug 01 10:59:43.217 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-3.raw >Aug 01 10:59:43.226 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.5.0 of the CIB to disk (digest: 0933e218a09d4aea1d82c8e59ac79537) >Aug 01 10:59:43.235 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.QuoIb4 (digest: /var/lib/pacemaker/cib/cib.nTyqHQ) >Aug 01 10:59:48.177 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: 740c6722418b824887dd3d3b0cece4be for 0.5.7 (0x55994debed00 0) >Aug 01 10:59:48.368 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_apply_diff operation for section 'all' to all (origin=local/cibadmin/2) >Aug 01 10:59:48.369 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.5.7 2 >Aug 01 10:59:48.369 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.6.0 (null) >Aug 01 10:59:48.369 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=6, @num_updates=0 >Aug 01 10:59:48.369 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/crm_config/cluster_property_set[@id='cib-bootstrap-options']: <nvpair id="cib-bootstrap-options-stonith-enabled" name="stonith-enabled" value="false"/> >Aug 01 10:59:48.370 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_apply_diff operation for section 'all': OK (rc=0, origin=rhel91/cibadmin/2, version=0.6.0) >Aug 01 10:59:48.370 rhel91 pacemaker-controld [3734573] (stonith__watchdog_fencing_enabled_for_node_api) notice: Cluster does not have watchdog fencing device >Aug 01 10:59:48.384 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-4.raw >Aug 01 10:59:48.398 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.6.0 of the CIB to disk (digest: 1f5708c803f75d9fa69d1cbba8fd9f52) >Aug 01 10:59:48.412 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.LiEXtJ (digest: /var/lib/pacemaker/cib/cib.Hh2xBl) >Aug 01 10:59:52.184 rhel91 pacemaker-controld [3734573] (pcmk__procfs_pid_of) info: Found pacemaker-based active as process 3734568 >Aug 01 10:59:52.184 rhel91 pacemaker-controld [3734573] (throttle_send_command) info: New throttle mode: negligible load (was undetermined) >Aug 01 10:59:53.373 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: b3bb189ab68034c5fc0cd792d2f64a35 for 0.6.0 (0x55994dec1c60 0) >Aug 01 11:03:02.017 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_apply_diff operation for section 'all' to all (origin=local/cibadmin/2) >Aug 01 11:03:02.018 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.6.0 2 >Aug 01 11:03:02.018 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.7.0 dff1077c6fc2630bed8414810d829c08 >Aug 01 11:03:02.018 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=7 >Aug 01 11:03:02.018 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/crm_config/cluster_property_set[@id='cib-bootstrap-options']: <nvpair id="cib-bootstrap-options-start-failure-is-fat" name="start-failure-is-fatal" value="true"/> >Aug 01 11:03:02.018 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_apply_diff operation for section 'all': OK (rc=0, origin=rhel91/cibadmin/2, version=0.7.0) >Aug 01 11:03:02.020 rhel91 pacemaker-controld [3734573] (stonith__watchdog_fencing_enabled_for_node_api) notice: Cluster does not have watchdog fencing device >Aug 01 11:03:02.033 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-5.raw >Aug 01 11:03:02.048 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.7.0 of the CIB to disk (digest: d837455833b73c6cba601d02343263d5) >Aug 01 11:03:02.063 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.Ijy5ae (digest: /var/lib/pacemaker/cib/cib.jOmJTL) >Aug 01 11:03:07.021 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: dff1077c6fc2630bed8414810d829c08 for 0.7.0 (0x55994dec9ec0 0) >Aug 01 11:03:42.098 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_apply_diff operation for section 'all' to all (origin=local/cibadmin/2) >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.7.0 2 >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.0 (null) >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=8 >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/resources: <clone id="ag_cluster-clone"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <primitive id="ag_cluster" class="ocf" type="ag" provider="mssql"> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <instance_attributes id="ag_cluster-instance_attributes"> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="ag_cluster-instance_attributes-ag_name" name="ag_name" value="ag1"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </instance_attributes> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <meta_attributes id="ag_cluster-meta_attributes"> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="ag_cluster-meta_attributes-failure-timeout" name="failure-timeout" value="60s"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </meta_attributes> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <operations> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="demote" interval="0s" timeout="10" id="ag_cluster-demote-interval-0s"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="monitor" interval="10" timeout="60" id="ag_cluster-monitor-interval-10"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="monitor" interval="11" timeout="60" role="Promoted" id="ag_cluster-monitor-interval-11"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="monitor" interval="12" timeout="60" role="Unpromoted" id="ag_cluster-monitor-interval-12"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="notify" interval="0s" timeout="60" id="ag_cluster-notify-interval-0s"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="promote" interval="0s" timeout="60" id="ag_cluster-promote-interval-0s"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="start" interval="0s" timeout="60" id="ag_cluster-start-interval-0s"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="stop" interval="0s" timeout="10" id="ag_cluster-stop-interval-0s"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </operations> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </primitive> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <meta_attributes id="ag_cluster-clone-meta_attributes"> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="ag_cluster-clone-meta_attributes-notify" name="notify" value="true"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="ag_cluster-clone-meta_attributes-promotable" name="promotable" value="true"/> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </meta_attributes> >Aug 01 11:03:42.099 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </clone> >Aug 01 11:03:42.100 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_apply_diff operation for section 'all': OK (rc=0, origin=rhel91/cibadmin/2, version=0.8.0) >Aug 01 11:03:42.100 rhel91 pacemaker-fenced [3734569] (update_cib_stonith_devices_v2) info: Updating device list from CIB: create resources >Aug 01 11:03:42.100 rhel91 pacemaker-fenced [3734569] (cib_devices_update) info: Updating devices to version 0.8.0 >Aug 01 11:03:42.100 rhel91 pacemaker-fenced [3734569] (unpack_config) warning: Blind faith: not fencing unseen nodes >Aug 01 11:03:42.109 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-6.raw >Aug 01 11:03:42.123 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.8.0 of the CIB to disk (digest: 07233e891f5f4a0d830ecf5331438c6f) >Aug 01 11:03:42.124 rhel91 pacemaker-execd [3734570] (process_lrmd_get_rsc_info) info: Agent information for 'ag_cluster' not in cache >Aug 01 11:03:42.124 rhel91 pacemaker-execd [3734570] (process_lrmd_get_rsc_info) info: Agent information for 'ag_cluster:0' not in cache >Aug 01 11:03:42.124 rhel91 pacemaker-execd [3734570] (process_lrmd_rsc_register) info: Cached agent information for 'ag_cluster' >Aug 01 11:03:42.125 rhel91 pacemaker-controld [3734573] (do_lrm_invoke) info: Retrieving metadata for ag_cluster (ocf:mssql:ag) asynchronously >Aug 01 11:03:42.132 rhel91 pacemaker-controld [3734573] (do_lrm_rsc_op) notice: Requesting local execution of probe operation for ag_cluster on rhel91 | transition_key=1:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4 op_key=ag_cluster_monitor_0 >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.0 2 >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.1 (null) >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=1 >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='2']: @crm-debug-origin=do_update_resource >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources: <lrm_resource id="ag_cluster" type="ag" class="ocf" provider="mssql"/> >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_rsc_op id="ag_cluster_last_0" operation_key="ag_cluster_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="2:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;2:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel92" call-id="-1" rc-code="193" op-status="-1" interval="0" last-rc-change="1690913022" exec-time="0" queue-time="0" op-digest="9672526152b2afa3a0cf05537be3c379"/> >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm_resource> >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/49, version=0.8.1) >Aug 01 11:03:42.132 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/14) >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.1 2 >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.2 (null) >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=2 >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']: @crm-debug-origin=do_update_resource >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources: <lrm_resource id="ag_cluster" type="ag" class="ocf" provider="mssql"/> >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_rsc_op id="ag_cluster_last_0" operation_key="ag_cluster_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="1:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;1:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel91" call-id="-1" rc-code="193" op-status="-1" interval="0" last-rc-change="1690913022" exec-time="0" queue-time="0" op-digest="9672526152b2afa3a0cf05537be3c379"/> >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm_resource> >Aug 01 11:03:42.133 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/14, version=0.8.2) >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.2 2 >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.3 (null) >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=3 >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='3']: @crm-debug-origin=do_update_resource >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources: <lrm_resource id="ag_cluster" type="ag" class="ocf" provider="mssql"/> >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_rsc_op id="ag_cluster_last_0" operation_key="ag_cluster_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="3:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;3:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel93" call-id="-1" rc-code="193" op-status="-1" interval="0" last-rc-change="1690913022" exec-time="0" queue-time="0" op-digest="9672526152b2afa3a0cf05537be3c379"/> >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm_resource> >Aug 01 11:03:42.134 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/14, version=0.8.3) >Aug 01 11:03:42.135 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.Gpwx9T (digest: /var/lib/pacemaker/cib/cib.nnXKfU) >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: mssql_validate >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: Resource agent invoked with: monitor >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: mssql_monitor >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:42 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:42 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62]; monitor-interval-timeout [60] >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:42 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:03:42 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:42 Connected to the instance at localhost:1433 >Aug 01 11:03:47.136 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: e24fc365f122f4fd6e283a3dd3c79466 for 0.8.3 (0x55994ded9240 0) >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:47 Monitor Caller is: monitor. >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:47 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:47 Replica is PRIMARY (1) >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: 2023/08/01 11:03:47 Skipping monitor for primary... >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: nomaster - timenow: 20230801180347 >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: LEASE_EXPIRY: 20230801180449 >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:03:47.257 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel92]: (unset) -> | from rhel92 with no write delay >Aug 01 11:03:47.257 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel93]: (unset) -> | from rhel93 with no write delay >Aug 01 11:03:47.261 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: (unset) -> 20230801180449 | from rhel91 with no write delay >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: lease_expiry after monitor update: 20230801180449 >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180449" >Aug 01 11:03:47.280 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting master-ag_cluster[rhel92]: (unset) -> 10 | from rhel92 with no write delay >Aug 01 11:03:47.280 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting master-ag_cluster[rhel93]: (unset) -> 10 | from rhel93 with no write delay >Aug 01 11:03:47.281 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.3 2 >Aug 01 11:03:47.281 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.4 (null) >Aug 01 11:03:47.281 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=4 >Aug 01 11:03:47.281 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']/transient_attributes[@id='2']/instance_attributes[@id='status-2']: <nvpair id="status-2-master-ag_cluster" name="master-ag_cluster" value="10"/> >Aug 01 11:03:47.281 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/attrd/6, version=0.8.4) >Aug 01 11:03:47.282 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.4 2 >Aug 01 11:03:47.282 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.5 (null) >Aug 01 11:03:47.282 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=5 >Aug 01 11:03:47.282 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']/transient_attributes[@id='3']/instance_attributes[@id='status-3']: <nvpair id="status-3-master-ag_cluster" name="master-ag_cluster" value="10"/> >Aug 01 11:03:47.282 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/attrd/7, version=0.8.5) >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.5 2 >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.6 (null) >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=6 >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_last_0']: @transition-magic=0:0;2:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=6, @rc-code=0, @op-status=0, @exec-time=5152 >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_last_failure_0" operation_key="ag_cluster_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="2:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="0:0;2:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel92" call-id="6" rc-code="0" op-status="0" interval="0" last-rc-change="1690913022" exec-time="5152" queue-time="0" op-digest="9672526152b2afa3a0cf05537be3c379"/> >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/50, version=0.8.6) >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.6 2 >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.7 (null) >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=7 >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_last_0']: @transition-magic=0:0;3:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=6, @rc-code=0, @op-status=0, @exec-time=5149 >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_last_failure_0" operation_key="ag_cluster_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="3:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="0:0;3:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel93" call-id="6" rc-code="0" op-status="0" interval="0" last-rc-change="1690913022" exec-time="5149" queue-time="0" op-digest="9672526152b2afa3a0cf05537be3c379"/> >Aug 01 11:03:47.285 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/15, version=0.8.7) >Aug 01 11:03:47.285 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting master-ag_cluster[rhel91]: (unset) -> 20 | from rhel91 with no write delay >Aug 01 11:03:47.287 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.7 2 >Aug 01 11:03:47.287 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.8 (null) >Aug 01 11:03:47.287 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=8 >Aug 01 11:03:47.287 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']/transient_attributes[@id='1']/instance_attributes[@id='status-1']: <nvpair id="status-1-master-ag_cluster" name="master-ag_cluster" value="20"/> >Aug 01 11:03:47.287 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/attrd/8, version=0.8.8) >Aug 01 11:03:47 ag(ag_cluster)[3734822]: INFO: ag_cluster monitor : 8 >Aug 01 11:03:47.289 rhel91 pacemaker-execd [3734570] (log_op_output) info: ag_cluster_monitor_0[3734822] error output [ resource ag_cluster is NOT running ] >Aug 01 11:03:47.289 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: Result of probe operation for ag_cluster on rhel91: promoted | CIB update 15, graph action confirmed; call=6 key=ag_cluster_monitor_0 rc=8 >Aug 01 11:03:47.289 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: ag_cluster_monitor_0@rhel91 output [ resource ag_cluster is NOT running\n ] >Aug 01 11:03:47.289 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/15) >Aug 01 11:03:47.289 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.8 2 >Aug 01 11:03:47.289 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.9 (null) >Aug 01 11:03:47.289 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=9 >Aug 01 11:03:47.289 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_last_0']: @transition-magic=0:8;1:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=6, @rc-code=8, @op-status=0, @exec-time=5155 >Aug 01 11:03:47.289 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_last_failure_0" operation_key="ag_cluster_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="1:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="0:8;1:3:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel91" call-id="6" rc-code="8" op-status="0" interval="0" last-rc-change="1690913022" exec-time="5155" queue-time="0" op-digest="9672526152b2afa3a0cf05537be3c379"/> >Aug 01 11:03:47.290 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/15, version=0.8.9) >Aug 01 11:03:47.306 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.9 2 >Aug 01 11:03:47.306 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.10 (null) >Aug 01 11:03:47.306 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=10 >Aug 01 11:03:47.306 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_monitor_12000" operation_key="ag_cluster_monitor_12000" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="4:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;4:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel92" call-id="-1" rc-code="193" op-status="-1" interval="12000" last-rc-change="1690913027" exec-time="0" queue-time="0" op-digest="a5ccb527549b0da2ccce481bc9858999"/> >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/52, version=0.8.10) >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.10 2 >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.11 (null) >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=11 >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_monitor_10000" operation_key="ag_cluster_monitor_10000" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="3:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;3:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel92" call-id="-1" rc-code="193" op-status="-1" interval="10000" last-rc-change="1690913027" exec-time="0" queue-time="0" op-digest="a5ccb527549b0da2ccce481bc9858999"/> >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/53, version=0.8.11) >Aug 01 11:03:47.307 rhel91 pacemaker-controld [3734573] (do_lrm_rsc_op) notice: Requesting local execution of monitor operation for ag_cluster on rhel91 | transition_key=13:4:8:976395e4-0f30-4f7e-9b5f-1da0b320d7c4 op_key=ag_cluster_monitor_11000 >Aug 01 11:03:47.307 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/16) >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.11 2 >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.12 (null) >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=12 >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_monitor_12000" operation_key="ag_cluster_monitor_12000" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="8:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;8:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel93" call-id="-1" rc-code="193" op-status="-1" interval="12000" last-rc-change="1690913027" exec-time="0" queue-time="0" op-digest="a5ccb527549b0da2ccce481bc9858999"/> >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/16, version=0.8.12) >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.12 2 >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.13 (null) >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=13 >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_monitor_11000" operation_key="ag_cluster_monitor_11000" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="13:4:8:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;13:4:8:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel91" call-id="-1" rc-code="193" op-status="-1" interval="11000" last-rc-change="1690913027" exec-time="0" queue-time="0" op-digest="a5ccb527549b0da2ccce481bc9858999"/> >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/16, version=0.8.13) >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.13 2 >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.14 (null) >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=14 >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='ag_cluster']: <lrm_rsc_op id="ag_cluster_monitor_10000" operation_key="ag_cluster_monitor_10000" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="7:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;7:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel93" call-id="-1" rc-code="193" op-status="-1" interval="10000" last-rc-change="1690913027" exec-time="0" queue-time="0" op-digest="a5ccb527549b0da2ccce481bc9858999"/> >Aug 01 11:03:47.308 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/17, version=0.8.14) >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: mssql_validate >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: Resource agent invoked with: monitor >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: mssql_monitor >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:47 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:47 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:47 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:03:47 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:47 Connected to the instance at localhost:1433 >Aug 01 11:03:52.310 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: 74b4f3ce718b94ce96090af12715c31b for 0.8.14 (0x55994ded9240 0) >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:52 Monitor Caller is: monitor. >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:52 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:52 Replica is PRIMARY (1) >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: 2023/08/01 11:03:52 Skipping monitor for primary... >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: nomaster - timenow: 20230801180352 >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: LEASE_EXPIRY: 20230801180505 >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:03:52.418 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180449 -> 20230801180505 | from rhel91 with no write delay >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: lease_expiry after monitor update: 20230801180505 >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180505" >Aug 01 11:03:52.444 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.14 2 >Aug 01 11:03:52.444 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.15 (null) >Aug 01 11:03:52.444 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=15 >Aug 01 11:03:52.444 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_monitor_12000']: @transition-magic=0:0;4:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=7, @rc-code=0, @op-status=0, @exec-time=5137 >Aug 01 11:03:52.444 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/54, version=0.8.15) >Aug 01 11:03:52.445 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.15 2 >Aug 01 11:03:52.445 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.16 (null) >Aug 01 11:03:52.445 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=16 >Aug 01 11:03:52.445 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_monitor_12000']: @transition-magic=0:0;8:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=7, @rc-code=0, @op-status=0, @exec-time=5136 >Aug 01 11:03:52.445 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/18, version=0.8.16) >Aug 01 11:03:52 ag(ag_cluster)[3734940]: INFO: ag_cluster monitor : 8 >Aug 01 11:03:52.448 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: Result of monitor operation for ag_cluster on rhel91: promoted | CIB update 17, graph action unconfirmed; call=7 key=ag_cluster_monitor_11000 rc=8 >Aug 01 11:03:52.448 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: ag_cluster_monitor_11000@rhel91 output [ 3733400 3733397\n ] >Aug 01 11:03:52.448 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/17) >Aug 01 11:03:52.449 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.16 2 >Aug 01 11:03:52.449 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.17 (null) >Aug 01 11:03:52.449 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=17 >Aug 01 11:03:52.449 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_monitor_11000']: @transition-magic=0:8;13:4:8:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=7, @rc-code=8, @op-status=0, @last-rc-change=1690913032, @exec-time=5140 >Aug 01 11:03:52.449 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/17, version=0.8.17) >Aug 01 11:03:57.451 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: 4c1f78ca1222aa8abd6c94f4e21208ad for 0.8.17 (0x55994ded9240 0) >Aug 01 11:03:57.576 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.17 2 >Aug 01 11:03:57.576 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.18 (null) >Aug 01 11:03:57.576 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=18 >Aug 01 11:03:57.576 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_monitor_10000']: @transition-magic=0:0;7:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=8, @rc-code=0, @op-status=0, @last-rc-change=1690913032, @exec-time=5131, @queue-time=5135 >Aug 01 11:03:57.576 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/19, version=0.8.18) >Aug 01 11:03:57.578 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.18 2 >Aug 01 11:03:57.578 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.8.19 (null) >Aug 01 11:03:57.578 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=19 >Aug 01 11:03:57.578 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='ag_cluster']/lrm_rsc_op[@id='ag_cluster_monitor_10000']: @transition-magic=0:0;3:4:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=8, @rc-code=0, @op-status=0, @last-rc-change=1690913032, @exec-time=5133, @queue-time=5137 >Aug 01 11:03:57.578 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/55, version=0.8.19) >Aug 01 11:04:02.579 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: ddb7101e1285be69a9c9d05d45e85f76 for 0.8.19 (0x55994ded9240 0) >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: mssql_validate >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: Resource agent invoked with: monitor >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: mssql_monitor >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:03 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:03 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:03 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:04:03 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:03 Connected to the instance at localhost:1433 >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:08 Monitor Caller is: monitor. >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:08 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:08 Replica is PRIMARY (1) >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: 2023/08/01 11:04:08 Skipping monitor for primary... >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: nomaster - timenow: 20230801180408 >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: LEASE_EXPIRY: 20230801180521 >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:04:08.553 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180505 -> 20230801180521 | from rhel91 with no write delay >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: lease_expiry after monitor update: 20230801180521 >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180521" >Aug 01 11:04:08 ag(ag_cluster)[3735064]: INFO: ag_cluster monitor : 8 >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: mssql_validate >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: Resource agent invoked with: monitor >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: mssql_monitor >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:19 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:19 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:19 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:04:19 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:19 Connected to the instance at localhost:1433 >Aug 01 11:04:22.684 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_apply_diff operation for section 'all' to all (origin=local/cibadmin/2) >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.8.19 2 >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.0 0d7ff4fc7e37c18d7de70e1dc3b1dfcf >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=9, @num_updates=0 >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/resources: <primitive id="virtualip" class="ocf" type="IPaddr2" provider="heartbeat"/> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <instance_attributes id="virtualip-instance_attributes"> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <nvpair id="virtualip-instance_attributes-ip" name="ip" value="10.135.65.30"/> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </instance_attributes> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <operations> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="monitor" interval="10s" timeout="20s" id="virtualip-monitor-interval-10s"/> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="start" interval="0s" timeout="20s" id="virtualip-start-interval-0s"/> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <op name="stop" interval="0s" timeout="20s" id="virtualip-stop-interval-0s"/> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </operations> >Aug 01 11:04:22.685 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </primitive> >Aug 01 11:04:22.686 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_apply_diff operation for section 'all': OK (rc=0, origin=rhel91/cibadmin/2, version=0.9.0) >Aug 01 11:04:22.686 rhel91 pacemaker-fenced [3734569] (update_cib_stonith_devices_v2) info: Updating device list from CIB: create resources >Aug 01 11:04:22.686 rhel91 pacemaker-fenced [3734569] (cib_devices_update) info: Updating devices to version 0.9.0 >Aug 01 11:04:22.700 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-7.raw >Aug 01 11:04:22.715 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.9.0 of the CIB to disk (digest: d8d0e1f69d8b4087b6cae23b079d7518) >Aug 01 11:04:22.716 rhel91 pacemaker-execd [3734570] (process_lrmd_get_rsc_info) info: Agent information for 'virtualip' not in cache >Aug 01 11:04:22.717 rhel91 pacemaker-execd [3734570] (process_lrmd_rsc_register) info: Cached agent information for 'virtualip' >Aug 01 11:04:22.717 rhel91 pacemaker-controld [3734573] (do_lrm_invoke) info: Retrieving metadata for virtualip (ocf:heartbeat:IPaddr2) asynchronously >Aug 01 11:04:22.722 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.0 2 >Aug 01 11:04:22.722 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.1 (null) >Aug 01 11:04:22.722 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=1 >Aug 01 11:04:22.722 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources: <lrm_resource id="virtualip" type="IPaddr2" class="ocf" provider="heartbeat"/> >Aug 01 11:04:22.722 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_rsc_op id="virtualip_last_0" operation_key="virtualip_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="7:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;7:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel92" call-id="-1" rc-code="193" op-status="-1" interval="0" last-rc-change="1690913062" exec-time="0" queue-time="0" op-digest="1875668557da4ce1d39bcf81dfed63ca"/> >Aug 01 11:04:22.722 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm_resource> >Aug 01 11:04:22.723 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/57, version=0.9.1) >Aug 01 11:04:22.724 rhel91 pacemaker-controld [3734573] (do_lrm_rsc_op) notice: Requesting local execution of probe operation for virtualip on rhel91 | transition_key=6:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4 op_key=virtualip_monitor_0 >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.1 2 >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.2 (null) >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=2 >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources: <lrm_resource id="virtualip" type="IPaddr2" class="ocf" provider="heartbeat"/> >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_rsc_op id="virtualip_last_0" operation_key="virtualip_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="8:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;8:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel93" call-id="-1" rc-code="193" op-status="-1" interval="0" last-rc-change="1690913062" exec-time="0" queue-time="0" op-digest="1875668557da4ce1d39bcf81dfed63ca"/> >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm_resource> >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/20, version=0.9.2) >Aug 01 11:04:22.724 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/18) >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.2 2 >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.3 (null) >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=3 >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources: <lrm_resource id="virtualip" type="IPaddr2" class="ocf" provider="heartbeat"/> >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ <lrm_rsc_op id="virtualip_last_0" operation_key="virtualip_monitor_0" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="6:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;6:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel91" call-id="-1" rc-code="193" op-status="-1" interval="0" last-rc-change="1690913062" exec-time="0" queue-time="0" op-digest="1875668557da4ce1d39bcf81dfed63ca"/> >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ </lrm_resource> >Aug 01 11:04:22.725 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/18, version=0.9.3) >Aug 01 11:04:22.730 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.7IodrQ (digest: /var/lib/pacemaker/cib/cib.G0ZcPq) >Aug 01 11:04:22.745 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.3 2 >Aug 01 11:04:22.745 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.4 (null) >Aug 01 11:04:22.745 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=4 >Aug 01 11:04:22.745 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='2']/lrm[@id='2']/lrm_resources/lrm_resource[@id='virtualip']/lrm_rsc_op[@id='virtualip_last_0']: @transition-magic=0:7;7:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=12, @rc-code=7, @op-status=0, @exec-time=22 >Aug 01 11:04:22.745 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel92/crmd/58, version=0.9.4) >Aug 01 11:04:22.746 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: Result of probe operation for virtualip on rhel91: not running | CIB update 19, graph action confirmed; call=11 key=virtualip_monitor_0 rc=7 >Aug 01 11:04:22.746 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/19) >Aug 01 11:04:22.746 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.4 2 >Aug 01 11:04:22.746 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.5 (null) >Aug 01 11:04:22.746 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=5 >Aug 01 11:04:22.746 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='virtualip']/lrm_rsc_op[@id='virtualip_last_0']: @transition-magic=0:7;6:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=11, @rc-code=7, @op-status=0, @exec-time=21 >Aug 01 11:04:22.747 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/19, version=0.9.5) >Aug 01 11:04:22.750 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.5 2 >Aug 01 11:04:22.750 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.6 (null) >Aug 01 11:04:22.750 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=6 >Aug 01 11:04:22.750 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='virtualip']/lrm_rsc_op[@id='virtualip_last_0']: @transition-magic=0:7;8:5:7:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=12, @rc-code=7, @op-status=0, @exec-time=25 >Aug 01 11:04:22.750 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel93/crmd/21, version=0.9.6) >Aug 01 11:04:22.751 rhel91 pacemaker-controld [3734573] (do_lrm_invoke) info: Retrieving metadata for virtualip (ocf:heartbeat:IPaddr2) asynchronously >Aug 01 11:04:22.757 rhel91 pacemaker-controld [3734573] (do_lrm_rsc_op) notice: Requesting local execution of start operation for virtualip on rhel91 | transition_key=41:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4 op_key=virtualip_start_0 >Aug 01 11:04:22.757 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/20) >Aug 01 11:04:22.757 rhel91 pacemaker-execd [3734570] (log_execute) info: executing - rsc:virtualip action:start call_id:12 >Aug 01 11:04:22.757 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.6 2 >Aug 01 11:04:22.757 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.7 (null) >Aug 01 11:04:22.757 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=7 >Aug 01 11:04:22.757 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='virtualip']/lrm_rsc_op[@id='virtualip_last_0']: @operation_key=virtualip_start_0, @operation=start, @transition-key=41:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @transition-magic=-1:193;41:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=-1, @rc-code=193, @op-status=-1, @exec-time=0 >Aug 01 11:04:22.758 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/20, version=0.9.7) >Aug 01 11:04:22 IPaddr2(virtualip)[3735305]: INFO: Adding inet address 10.135.65.30/22 with broadcast address 10.135.67.255 to device eth0 >Aug 01 11:04:22 IPaddr2(virtualip)[3735305]: INFO: Bringing device eth0 up >Aug 01 11:04:22 IPaddr2(virtualip)[3735305]: INFO: /usr/libexec/heartbeat/send_arp -i 200 -r 5 -p /run/resource-agents/send_arp-10.135.65.30 eth0 10.135.65.30 auto not_used not_used >Aug 01 11:04:22.787 rhel91 pacemaker-execd [3734570] (log_finished) info: virtualip start (call 12, PID 3735305) exited with status 0 (execution time 30ms) >Aug 01 11:04:22.787 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: Result of start operation for virtualip on rhel91: ok | CIB update 21, graph action confirmed; call=12 key=virtualip_start_0 rc=0 >Aug 01 11:04:22.787 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/21) >Aug 01 11:04:22.789 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.7 2 >Aug 01 11:04:22.789 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.8 (null) >Aug 01 11:04:22.789 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=8 >Aug 01 11:04:22.789 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='virtualip']/lrm_rsc_op[@id='virtualip_last_0']: @transition-magic=0:0;41:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=12, @rc-code=0, @op-status=0, @exec-time=30 >Aug 01 11:04:22.789 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/21, version=0.9.8) >Aug 01 11:04:22.790 rhel91 pacemaker-controld [3734573] (do_lrm_rsc_op) notice: Requesting local execution of monitor operation for virtualip on rhel91 | transition_key=42:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4 op_key=virtualip_monitor_10000 >Aug 01 11:04:22.790 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/22) >Aug 01 11:04:22.791 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.8 2 >Aug 01 11:04:22.791 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.9 (null) >Aug 01 11:04:22.791 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=9 >Aug 01 11:04:22.791 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='virtualip']: <lrm_rsc_op id="virtualip_monitor_10000" operation_key="virtualip_monitor_10000" operation="monitor" crm-debug-origin="do_update_resource" crm_feature_set="3.16.2" transition-key="42:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" transition-magic="-1:193;42:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4" exit-reason="" on_node="rhel91" call-id="-1" rc-code="193" op-status="-1" interval="10000" last-rc-change="1690913062" exec-time="0" queue-time="0" op-digest="2c3f2afdd0017d809047a3ec083e680c"/> >Aug 01 11:04:22.791 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/22, version=0.9.9) >Aug 01 11:04:22.811 rhel91 pacemaker-controld [3734573] (log_executor_event) notice: Result of monitor operation for virtualip on rhel91: ok | CIB update 23, graph action unconfirmed; call=13 key=virtualip_monitor_10000 rc=0 >Aug 01 11:04:22.811 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/23) >Aug 01 11:04:22.812 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.9 2 >Aug 01 11:04:22.812 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.9.10 (null) >Aug 01 11:04:22.812 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @num_updates=10 >Aug 01 11:04:22.812 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib/status/node_state[@id='1']/lrm[@id='1']/lrm_resources/lrm_resource[@id='virtualip']/lrm_rsc_op[@id='virtualip_monitor_10000']: @transition-magic=0:0;42:5:0:976395e4-0f30-4f7e-9b5f-1da0b320d7c4, @call-id=13, @rc-code=0, @op-status=0, @exec-time=20 >Aug 01 11:04:22.812 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=rhel91/crmd/23, version=0.9.10) >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:24 Monitor Caller is: monitor. >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:24 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:24 Replica is PRIMARY (1) >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: 2023/08/01 11:04:24 Skipping monitor for primary... >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: nomaster - timenow: 20230801180424 >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: LEASE_EXPIRY: 20230801180537 >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:04:24.683 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180521 -> 20230801180537 | from rhel91 with no write delay >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: lease_expiry after monitor update: 20230801180537 >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180537" >Aug 01 11:04:24 ag(ag_cluster)[3735191]: INFO: ag_cluster monitor : 8 >Aug 01 11:04:26 IPaddr2(virtualip)[3735305]: INFO: ARPING 10.135.65.30 from 10.135.65.30 eth0 >Sent 5 probes (5 broadcast(s)) >Received 0 response(s) >Aug 01 11:04:27.813 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: ef6beac77210229610a132c51fc0e0cc for 0.9.10 (0x55994df01ea0 0) >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: mssql_validate >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: Resource agent invoked with: monitor >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: mssql_monitor >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:35 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:35 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:35 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:04:35 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:35 Connected to the instance at localhost:1433 >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:40 Monitor Caller is: monitor. >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:40 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:40 Replica is PRIMARY (1) >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: 2023/08/01 11:04:40 Skipping monitor for primary... >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: nomaster - timenow: 20230801180440 >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: LEASE_EXPIRY: 20230801180553 >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:04:40.809 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180537 -> 20230801180553 | from rhel91 with no write delay >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: lease_expiry after monitor update: 20230801180553 >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180553" >Aug 01 11:04:40 ag(ag_cluster)[3735538]: INFO: ag_cluster monitor : 8 >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: mssql_validate >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: Resource agent invoked with: monitor >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: mssql_monitor >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:51 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:51 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:51 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:04:51 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:51 Connected to the instance at localhost:1433 >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:56 Monitor Caller is: monitor. >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:56 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:56 Replica is PRIMARY (1) >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: 2023/08/01 11:04:56 Skipping monitor for primary... >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: nomaster - timenow: 20230801180456 >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: LEASE_EXPIRY: 20230801180609 >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:04:56.936 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180553 -> 20230801180609 | from rhel91 with no write delay >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: lease_expiry after monitor update: 20230801180609 >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180609" >Aug 01 11:04:56 ag(ag_cluster)[3735714]: INFO: ag_cluster monitor : 8 >Aug 01 11:05:00.220 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_replace operation for section configuration to all (origin=local/cibadmin/2) >Aug 01 11:05:00.221 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.9.10 2 >Aug 01 11:05:00.221 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.10.0 (null) >Aug 01 11:05:00.221 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=10, @num_updates=0 >Aug 01 11:05:00.221 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/constraints: <rsc_colocation rsc="virtualip" with-rsc="ag_cluster-clone" score="INFINITY" rsc-role="Started" with-rsc-role="Master" id="colocation-virtualip-ag_cluster-clone-INFINITY"/> >Aug 01 11:05:00.222 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_replace operation for section configuration: OK (rc=0, origin=rhel91/cibadmin/2, version=0.10.0) >Aug 01 11:05:00.222 rhel91 pacemaker-fenced [3734569] (update_cib_stonith_devices_v2) info: Updating device list from CIB: create constraints >Aug 01 11:05:00.222 rhel91 pacemaker-fenced [3734569] (cib_devices_update) info: Updating devices to version 0.10.0 >Aug 01 11:05:00.233 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-8.raw >Aug 01 11:05:00.245 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.10.0 of the CIB to disk (digest: b8bda43fbcea30c2cb48c799c34f743b) >Aug 01 11:05:00.254 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.rpVKsh (digest: /var/lib/pacemaker/cib/cib.AOU5W3) >Aug 01 11:05:05.224 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: fc5a67d41ccfdd65a9f2ae31b0b7bd5b for 0.10.0 (0x55994dec8d00 0) >Aug 01 11:05:07 ag(ag_cluster)[3735929]: INFO: mssql_validate >Aug 01 11:05:07 ag(ag_cluster)[3735929]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:05:07 ag(ag_cluster)[3735929]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:05:07 ag(ag_cluster)[3735929]: INFO: Resource agent invoked with: monitor >Aug 01 11:05:07 ag(ag_cluster)[3735929]: INFO: mssql_monitor >Aug 01 11:05:07 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:07 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:05:08 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:07 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:05:08 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:07 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:05:08 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:08 Connected to the instance at localhost:1433 >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:13 Monitor Caller is: monitor. >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:13 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:13 Replica is PRIMARY (1) >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: 2023/08/01 11:05:13 Skipping monitor for primary... >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: nomaster - timenow: 20230801180513 >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: LEASE_EXPIRY: 20230801180626 >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:05:13.087 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180609 -> 20230801180626 | from rhel91 with no write delay >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: lease_expiry after monitor update: 20230801180626 >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180626" >Aug 01 11:05:13 ag(ag_cluster)[3735929]: INFO: ag_cluster monitor : 8 >Aug 01 11:05:20.024 rhel91 pacemaker-based [3734568] (cib_process_request) info: Forwarding cib_replace operation for section configuration to all (origin=local/cibadmin/2) >Aug 01 11:05:20.026 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: --- 0.10.0 2 >Aug 01 11:05:20.026 rhel91 pacemaker-based [3734568] (cib_perform_op) info: Diff: +++ 0.11.0 (null) >Aug 01 11:05:20.026 rhel91 pacemaker-based [3734568] (cib_perform_op) info: + /cib: @epoch=11 >Aug 01 11:05:20.026 rhel91 pacemaker-based [3734568] (cib_perform_op) info: ++ /cib/configuration/constraints: <rsc_order first="ag_cluster-clone" then="virtualip" first-action="promote" then-action="start" id="order-ag_cluster-clone-virtualip-mandatory"/> >Aug 01 11:05:20.026 rhel91 pacemaker-based [3734568] (cib_process_request) info: Completed cib_replace operation for section configuration: OK (rc=0, origin=rhel91/cibadmin/2, version=0.11.0) >Aug 01 11:05:20.026 rhel91 pacemaker-fenced [3734569] (update_cib_stonith_devices_v2) info: Updating device list from CIB: create constraints >Aug 01 11:05:20.026 rhel91 pacemaker-fenced [3734569] (cib_devices_update) info: Updating devices to version 0.11.0 >Aug 01 11:05:20.040 rhel91 pacemaker-based [3734568] (cib_file_backup) info: Archived previous version as /var/lib/pacemaker/cib/cib-9.raw >Aug 01 11:05:20.055 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Wrote version 0.11.0 of the CIB to disk (digest: 657045a818acc107d95d4d6ff834ee3c) >Aug 01 11:05:20.069 rhel91 pacemaker-based [3734568] (cib_file_write_with_digest) info: Reading cluster configuration file /var/lib/pacemaker/cib/cib.yMNv3K (digest: /var/lib/pacemaker/cib/cib.Wfthpo) >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: mssql_validate >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: Resource agent invoked with: monitor >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: mssql_monitor >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:24 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:24 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:24 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:05:24 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:24 Connected to the instance at localhost:1433 >Aug 01 11:05:25.029 rhel91 pacemaker-based [3734568] (cib_process_ping) info: Reporting our current digest to rhel92: 4f446d4cd5b0ecfc3476963d20d96b60 for 0.11.0 (0x55994de2da30 0) >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:29 Monitor Caller is: monitor. >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:29 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:29 Replica is PRIMARY (1) >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: 2023/08/01 11:05:29 Skipping monitor for primary... >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: nomaster - timenow: 20230801180529 >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: LEASE_EXPIRY: 20230801180642 >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:05:29.215 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180626 -> 20230801180642 | from rhel91 with no write delay >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: lease_expiry after monitor update: 20230801180642 >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180642" >Aug 01 11:05:29 ag(ag_cluster)[3736137]: INFO: ag_cluster monitor : 8 >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: mssql_validate >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: Resource agent invoked with: monitor >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: mssql_monitor >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:40 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:40 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:40 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:05:40 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:40 Connected to the instance at localhost:1433 >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:45 Monitor Caller is: monitor. >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:45 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:45 Replica is PRIMARY (1) >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: 2023/08/01 11:05:45 Skipping monitor for primary... >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: nomaster - timenow: 20230801180545 >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: LEASE_EXPIRY: 20230801180658 >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:05:45.344 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180642 -> 20230801180658 | from rhel91 with no write delay >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: lease_expiry after monitor update: 20230801180658 >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180658" >Aug 01 11:05:45 ag(ag_cluster)[3736313]: INFO: ag_cluster monitor : 8 >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: mssql_validate >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: Resource agent invoked with: monitor >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: mssql_monitor >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:05:56 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:05:56 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:05:56 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:05:56 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:05:56 Connected to the instance at localhost:1433 >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:06:01 Monitor Caller is: monitor. >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:06:01 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:06:01 Replica is PRIMARY (1) >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: 2023/08/01 11:06:01 Skipping monitor for primary... >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: nomaster - timenow: 20230801180601 >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: LEASE_EXPIRY: 20230801180714 >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:06:01.471 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180658 -> 20230801180714 | from rhel91 with no write delay >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: lease_expiry after monitor update: 20230801180714 >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180714" >Aug 01 11:06:01 ag(ag_cluster)[3736531]: INFO: ag_cluster monitor : 8 >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: mssql_validate >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: Resource agent invoked with: monitor >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: mssql_monitor >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:12 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:12 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:06:12 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:12 Connected to the instance at localhost:1433 >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:17 Monitor Caller is: monitor. >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:17 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:17 Replica is PRIMARY (1) >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: 2023/08/01 11:06:17 Skipping monitor for primary... >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: nomaster - timenow: 20230801180617 >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: LEASE_EXPIRY: 20230801180730 >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:06:17.595 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180714 -> 20230801180730 | from rhel91 with no write delay >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: lease_expiry after monitor update: 20230801180730 >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180730" >Aug 01 11:06:17 ag(ag_cluster)[3736751]: INFO: ag_cluster monitor : 8 >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: mssql_validate >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: Resource agent invoked with: monitor >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: mssql_monitor >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:28 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:28 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:28 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:06:28 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:28 Connected to the instance at localhost:1433 >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:33 Monitor Caller is: monitor. >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:33 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:33 Replica is PRIMARY (1) >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: 2023/08/01 11:06:33 Skipping monitor for primary... >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: nomaster - timenow: 20230801180633 >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: LEASE_EXPIRY: 20230801180746 >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:06:33.739 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180730 -> 20230801180746 | from rhel91 with no write delay >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: lease_expiry after monitor update: 20230801180746 >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180746" >Aug 01 11:06:33 ag(ag_cluster)[3736951]: INFO: ag_cluster monitor : 8 >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: mssql_validate >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: Resource agent invoked with: monitor >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: mssql_monitor >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:44 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:44 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:44 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:06:44 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:44 Connected to the instance at localhost:1433 >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:49 Monitor Caller is: monitor. >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:49 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:49 Replica is PRIMARY (1) >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: 2023/08/01 11:06:49 Skipping monitor for primary... >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: nomaster - timenow: 20230801180649 >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: LEASE_EXPIRY: 20230801180802 >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:06:49.888 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180746 -> 20230801180802 | from rhel91 with no write delay >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: lease_expiry after monitor update: 20230801180802 >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180802" >Aug 01 11:06:49 ag(ag_cluster)[3737151]: INFO: ag_cluster monitor : 8 >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: mssql_validate >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: Resource agent invoked with: monitor >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: mssql_monitor >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:00 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:00 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:07:00 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:00 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:07:01 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:01 Connected to the instance at localhost:1433 >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:06 Monitor Caller is: monitor. >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:06 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:06 Replica is PRIMARY (1) >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: 2023/08/01 11:07:06 Skipping monitor for primary... >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: nomaster - timenow: 20230801180706 >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: LEASE_EXPIRY: 20230801180819 >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:07:06.047 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180802 -> 20230801180819 | from rhel91 with no write delay >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: lease_expiry after monitor update: 20230801180819 >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180819" >Aug 01 11:07:06 ag(ag_cluster)[3737310]: INFO: ag_cluster monitor : 8 >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: mssql_validate >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: Resource agent invoked with: monitor >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: mssql_monitor >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:17 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:17 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:17 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:07:17 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:17 Connected to the instance at localhost:1433 >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:22 Monitor Caller is: monitor. >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:22 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:22 Replica is PRIMARY (1) >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: 2023/08/01 11:07:22 Skipping monitor for primary... >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: nomaster - timenow: 20230801180722 >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: LEASE_EXPIRY: 20230801180835 >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:07:22.205 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180819 -> 20230801180835 | from rhel91 with no write delay >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: lease_expiry after monitor update: 20230801180835 >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180835" >Aug 01 11:07:22 ag(ag_cluster)[3737514]: INFO: ag_cluster monitor : 8 >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: mssql_validate >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: Resource agent invoked with: monitor >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: mssql_monitor >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:33 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:33 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:33 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:07:33 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:33 Connected to the instance at localhost:1433 >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:38 Monitor Caller is: monitor. >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:38 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:38 Replica is PRIMARY (1) >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: 2023/08/01 11:07:38 Skipping monitor for primary... >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: nomaster - timenow: 20230801180738 >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: LEASE_EXPIRY: 20230801180851 >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:07:38.353 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180835 -> 20230801180851 | from rhel91 with no write delay >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: lease_expiry after monitor update: 20230801180851 >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180851" >Aug 01 11:07:38 ag(ag_cluster)[3737713]: INFO: ag_cluster monitor : 8 >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: mssql_validate >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: Resource agent invoked with: monitor >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: mssql_monitor >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:49 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:49 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:49 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:07:49 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:49 Connected to the instance at localhost:1433 >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:54 Monitor Caller is: monitor. >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:54 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:54 Replica is PRIMARY (1) >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: 2023/08/01 11:07:54 Skipping monitor for primary... >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: nomaster - timenow: 20230801180754 >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: LEASE_EXPIRY: 20230801180907 >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:07:54.477 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180851 -> 20230801180907 | from rhel91 with no write delay >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: lease_expiry after monitor update: 20230801180907 >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180907" >Aug 01 11:07:54 ag(ag_cluster)[3737874]: INFO: ag_cluster monitor : 8 >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: mssql_validate >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: Resource agent invoked with: monitor >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: mssql_monitor >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:05 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:05 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:05 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:08:05 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:05 Connected to the instance at localhost:1433 >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:10 Monitor Caller is: monitor. >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:10 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:10 Replica is PRIMARY (1) >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: 2023/08/01 11:08:10 Skipping monitor for primary... >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: nomaster - timenow: 20230801180810 >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: LEASE_EXPIRY: 20230801180923 >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:08:10.625 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180907 -> 20230801180923 | from rhel91 with no write delay >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: lease_expiry after monitor update: 20230801180923 >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180923" >Aug 01 11:08:10 ag(ag_cluster)[3738077]: INFO: ag_cluster monitor : 8 >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: mssql_validate >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: Resource agent invoked with: monitor >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: mssql_monitor >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:21 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:21 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:21 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:08:21 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:21 Connected to the instance at localhost:1433 >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:26 Monitor Caller is: monitor. >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:26 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:26 Replica is PRIMARY (1) >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: 2023/08/01 11:08:26 Skipping monitor for primary... >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: nomaster - timenow: 20230801180826 >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: LEASE_EXPIRY: 20230801180939 >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:08:26.754 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180923 -> 20230801180939 | from rhel91 with no write delay >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: lease_expiry after monitor update: 20230801180939 >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180939" >Aug 01 11:08:26 ag(ag_cluster)[3738239]: INFO: ag_cluster monitor : 8 >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: mssql_validate >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: Resource agent invoked with: monitor >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: mssql_monitor >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:37 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:37 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:37 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:08:37 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:37 Connected to the instance at localhost:1433 >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:42 Monitor Caller is: monitor. >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:42 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:42 Replica is PRIMARY (1) >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: 2023/08/01 11:08:42 Skipping monitor for primary... >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: nomaster - timenow: 20230801180842 >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: LEASE_EXPIRY: 20230801180955 >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:08:42.903 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180939 -> 20230801180955 | from rhel91 with no write delay >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: lease_expiry after monitor update: 20230801180955 >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801180955" >Aug 01 11:08:42 ag(ag_cluster)[3738440]: INFO: ag_cluster monitor : 8 >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: mssql_validate >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: Resource agent invoked with: monitor >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: mssql_monitor >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:53 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:53 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:08:53 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:53 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:08:54 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:54 Connected to the instance at localhost:1433 >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:59 Monitor Caller is: monitor. >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:59 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:59 Replica is PRIMARY (1) >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: 2023/08/01 11:08:59 Skipping monitor for primary... >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: nomaster - timenow: 20230801180859 >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: LEASE_EXPIRY: 20230801181012 >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:08:59.053 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801180955 -> 20230801181012 | from rhel91 with no write delay >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: lease_expiry after monitor update: 20230801181012 >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181012" >Aug 01 11:08:59 ag(ag_cluster)[3738640]: INFO: ag_cluster monitor : 8 >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: mssql_validate >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: Resource agent invoked with: monitor >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: mssql_monitor >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:10 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:10 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:10 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:09:10 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:10 Connected to the instance at localhost:1433 >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:15 Monitor Caller is: monitor. >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:15 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:15 Replica is PRIMARY (1) >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: 2023/08/01 11:09:15 Skipping monitor for primary... >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: nomaster - timenow: 20230801180915 >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: LEASE_EXPIRY: 20230801181028 >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:09:15.182 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181012 -> 20230801181028 | from rhel91 with no write delay >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: lease_expiry after monitor update: 20230801181028 >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181028" >Aug 01 11:09:15 ag(ag_cluster)[3738803]: INFO: ag_cluster monitor : 8 >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: mssql_validate >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: Resource agent invoked with: monitor >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: mssql_monitor >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:26 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:26 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:26 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:09:26 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:26 Connected to the instance at localhost:1433 >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:31 Monitor Caller is: monitor. >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:31 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:31 Replica is PRIMARY (1) >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: 2023/08/01 11:09:31 Skipping monitor for primary... >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: nomaster - timenow: 20230801180931 >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: LEASE_EXPIRY: 20230801181044 >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:09:31.308 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181028 -> 20230801181044 | from rhel91 with no write delay >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: lease_expiry after monitor update: 20230801181044 >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181044" >Aug 01 11:09:31 ag(ag_cluster)[3739002]: INFO: ag_cluster monitor : 8 >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: mssql_validate >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: Resource agent invoked with: monitor >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: mssql_monitor >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:42 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:42 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:42 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:09:42 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:42 Connected to the instance at localhost:1433 >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:47 Monitor Caller is: monitor. >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:47 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:47 Replica is PRIMARY (1) >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: 2023/08/01 11:09:47 Skipping monitor for primary... >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: nomaster - timenow: 20230801180947 >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: LEASE_EXPIRY: 20230801181100 >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:09:47.432 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181044 -> 20230801181100 | from rhel91 with no write delay >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: lease_expiry after monitor update: 20230801181100 >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181100" >Aug 01 11:09:47 ag(ag_cluster)[3739160]: INFO: ag_cluster monitor : 8 >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: mssql_validate >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: Resource agent invoked with: monitor >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: mssql_monitor >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:09:58 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:09:58 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:09:58 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:09:58 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:09:58 Connected to the instance at localhost:1433 >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:10:03 Monitor Caller is: monitor. >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:10:03 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:10:03 Replica is PRIMARY (1) >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: 2023/08/01 11:10:03 Skipping monitor for primary... >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: nomaster - timenow: 20230801181003 >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: LEASE_EXPIRY: 20230801181116 >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:10:03.555 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181100 -> 20230801181116 | from rhel91 with no write delay >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: lease_expiry after monitor update: 20230801181116 >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181116" >Aug 01 11:10:03 ag(ag_cluster)[3739366]: INFO: ag_cluster monitor : 8 >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: mssql_validate >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: Resource agent invoked with: monitor >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: mssql_monitor >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:14 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:14 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:14 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:10:14 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:14 Connected to the instance at localhost:1433 >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:19 Monitor Caller is: monitor. >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:19 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:19 Replica is PRIMARY (1) >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: 2023/08/01 11:10:19 Skipping monitor for primary... >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: nomaster - timenow: 20230801181019 >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: LEASE_EXPIRY: 20230801181132 >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:10:19.690 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181116 -> 20230801181132 | from rhel91 with no write delay >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: lease_expiry after monitor update: 20230801181132 >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181132" >Aug 01 11:10:19 ag(ag_cluster)[3739570]: INFO: ag_cluster monitor : 8 >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: mssql_validate >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: Resource agent invoked with: monitor >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: mssql_monitor >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:30 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:30 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:30 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:10:30 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:30 Connected to the instance at localhost:1433 >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:35 Monitor Caller is: monitor. >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:35 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:35 Replica is PRIMARY (1) >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: 2023/08/01 11:10:35 Skipping monitor for primary... >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: nomaster - timenow: 20230801181035 >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: LEASE_EXPIRY: 20230801181148 >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:10:35.838 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181132 -> 20230801181148 | from rhel91 with no write delay >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: lease_expiry after monitor update: 20230801181148 >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181148" >Aug 01 11:10:35 ag(ag_cluster)[3739730]: INFO: ag_cluster monitor : 8 >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: mssql_validate >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: Resource agent invoked with: monitor >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: mssql_monitor >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:46 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:46 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:46 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:10:46 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:46 Connected to the instance at localhost:1433 >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:51 Monitor Caller is: monitor. >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:51 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:51 Replica is PRIMARY (1) >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: 2023/08/01 11:10:51 Skipping monitor for primary... >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: nomaster - timenow: 20230801181051 >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: LEASE_EXPIRY: 20230801181204 >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:10:51.987 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181148 -> 20230801181204 | from rhel91 with no write delay >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: lease_expiry after monitor update: 20230801181204 >Aug 01 11:10:51 ag(ag_cluster)[3739933]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181204" >Aug 01 11:10:52 ag(ag_cluster)[3739933]: INFO: ag_cluster monitor : 8 >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: mssql_validate >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: Resource agent invoked with: monitor >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: mssql_monitor >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:03 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:03 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:03 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:11:03 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:03 Connected to the instance at localhost:1433 >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:08 Monitor Caller is: monitor. >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:08 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:08 Replica is PRIMARY (1) >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: 2023/08/01 11:11:08 Skipping monitor for primary... >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: nomaster - timenow: 20230801181108 >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: LEASE_EXPIRY: 20230801181221 >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:11:08.111 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181204 -> 20230801181221 | from rhel91 with no write delay >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: lease_expiry after monitor update: 20230801181221 >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181221" >Aug 01 11:11:08 ag(ag_cluster)[3740093]: INFO: ag_cluster monitor : 8 >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: mssql_validate >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: Resource agent invoked with: monitor >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: mssql_monitor >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:19 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:19 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:19 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:11:19 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:19 Connected to the instance at localhost:1433 >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:24 Monitor Caller is: monitor. >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:24 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:24 Replica is PRIMARY (1) >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: 2023/08/01 11:11:24 Skipping monitor for primary... >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: nomaster - timenow: 20230801181124 >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: LEASE_EXPIRY: 20230801181237 >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:11:24.234 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181221 -> 20230801181237 | from rhel91 with no write delay >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: lease_expiry after monitor update: 20230801181237 >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181237" >Aug 01 11:11:24 ag(ag_cluster)[3740295]: INFO: ag_cluster monitor : 8 >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: mssql_validate >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: Resource agent invoked with: monitor >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: mssql_monitor >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:35 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:35 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:35 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:11:35 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:35 Connected to the instance at localhost:1433 >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:40 Monitor Caller is: monitor. >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:40 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:40 Replica is PRIMARY (1) >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: 2023/08/01 11:11:40 Skipping monitor for primary... >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: nomaster - timenow: 20230801181140 >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: LEASE_EXPIRY: 20230801181253 >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:11:40.367 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181237 -> 20230801181253 | from rhel91 with no write delay >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: lease_expiry after monitor update: 20230801181253 >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181253" >Aug 01 11:11:40 ag(ag_cluster)[3740498]: INFO: ag_cluster monitor : 8 >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: mssql_validate >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: Resource agent invoked with: monitor >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: mssql_monitor >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:51 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:51 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:51 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:11:51 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:51 Connected to the instance at localhost:1433 >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:56 Monitor Caller is: monitor. >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:56 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:56 Replica is PRIMARY (1) >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: 2023/08/01 11:11:56 Skipping monitor for primary... >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: nomaster - timenow: 20230801181156 >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: LEASE_EXPIRY: 20230801181309 >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:11:56.493 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181253 -> 20230801181309 | from rhel91 with no write delay >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: lease_expiry after monitor update: 20230801181309 >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181309" >Aug 01 11:11:56 ag(ag_cluster)[3740657]: INFO: ag_cluster monitor : 8 >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: mssql_validate >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: Resource agent invoked with: monitor >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: mssql_monitor >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:07 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:07 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:07 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:12:07 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:07 Connected to the instance at localhost:1433 >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:12 Monitor Caller is: monitor. >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:12 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:12 Replica is PRIMARY (1) >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: 2023/08/01 11:12:12 Skipping monitor for primary... >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: nomaster - timenow: 20230801181212 >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: LEASE_EXPIRY: 20230801181325 >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:12:12.617 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181309 -> 20230801181325 | from rhel91 with no write delay >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: lease_expiry after monitor update: 20230801181325 >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181325" >Aug 01 11:12:12 ag(ag_cluster)[3740861]: INFO: ag_cluster monitor : 8 >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: mssql_validate >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: Resource agent invoked with: monitor >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: mssql_monitor >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:23 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:23 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:23 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:12:23 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:23 Connected to the instance at localhost:1433 >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:28 Monitor Caller is: monitor. >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:28 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:28 Replica is PRIMARY (1) >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: 2023/08/01 11:12:28 Skipping monitor for primary... >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: nomaster - timenow: 20230801181228 >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: LEASE_EXPIRY: 20230801181341 >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:12:28.761 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181325 -> 20230801181341 | from rhel91 with no write delay >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: lease_expiry after monitor update: 20230801181341 >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181341" >Aug 01 11:12:28 ag(ag_cluster)[3741019]: INFO: ag_cluster monitor : 8 >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: mssql_validate >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: Resource agent invoked with: monitor >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: mssql_monitor >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:39 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:39 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:39 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:12:39 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:39 Connected to the instance at localhost:1433 >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:44 Monitor Caller is: monitor. >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:44 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:44 Replica is PRIMARY (1) >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: 2023/08/01 11:12:44 Skipping monitor for primary... >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: nomaster - timenow: 20230801181244 >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: LEASE_EXPIRY: 20230801181357 >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:12:44.905 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181341 -> 20230801181357 | from rhel91 with no write delay >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: lease_expiry after monitor update: 20230801181357 >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181357" >Aug 01 11:12:44 ag(ag_cluster)[3741218]: INFO: ag_cluster monitor : 8 >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: mssql_validate >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: Resource agent invoked with: monitor >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: mssql_monitor >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:12:55 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:12:55 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:12:55 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:12:55 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:12:56 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:12:56 Connected to the instance at localhost:1433 >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:13:01 Monitor Caller is: monitor. >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:13:01 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:13:01 Replica is PRIMARY (1) >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: 2023/08/01 11:13:01 Skipping monitor for primary... >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: nomaster - timenow: 20230801181301 >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: LEASE_EXPIRY: 20230801181414 >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:13:01.034 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181357 -> 20230801181414 | from rhel91 with no write delay >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: lease_expiry after monitor update: 20230801181414 >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181414" >Aug 01 11:13:01 ag(ag_cluster)[3741418]: INFO: ag_cluster monitor : 8 >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: mssql_validate >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: Resource agent invoked with: monitor >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: mssql_monitor >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:12 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:12 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:13:12 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:12 Connected to the instance at localhost:1433 >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:17 Monitor Caller is: monitor. >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:17 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:17 Replica is PRIMARY (1) >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: 2023/08/01 11:13:17 Skipping monitor for primary... >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: nomaster - timenow: 20230801181317 >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: LEASE_EXPIRY: 20230801181430 >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:13:17.160 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181414 -> 20230801181430 | from rhel91 with no write delay >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: lease_expiry after monitor update: 20230801181430 >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181430" >Aug 01 11:13:17 ag(ag_cluster)[3741619]: INFO: ag_cluster monitor : 8 >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: mssql_validate >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: Resource agent invoked with: monitor >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: mssql_monitor >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:28 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:28 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:28 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:13:28 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:28 Connected to the instance at localhost:1433 >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:33 Monitor Caller is: monitor. >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:33 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:33 Replica is PRIMARY (1) >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: 2023/08/01 11:13:33 Skipping monitor for primary... >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: nomaster - timenow: 20230801181333 >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: LEASE_EXPIRY: 20230801181446 >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:13:33.289 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181430 -> 20230801181446 | from rhel91 with no write delay >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: lease_expiry after monitor update: 20230801181446 >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181446" >Aug 01 11:13:33 ag(ag_cluster)[3741818]: INFO: ag_cluster monitor : 8 >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: mssql_validate >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: Resource agent invoked with: monitor >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: mssql_monitor >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:44 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-monitor]; connection-timeout [30]; health-threshold [3]; action [monitor] >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:44 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:44 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Aug 01 11:13:44 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:44 Connected to the instance at localhost:1433 >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:49 Monitor Caller is: monitor. >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:49 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance rhel91 >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:49 Replica is PRIMARY (1) >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: 2023/08/01 11:13:49 Skipping monitor for primary... >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: nomaster - timenow: 20230801181349 >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: LEASE_EXPIRY: 20230801181502 >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: monitor: PROMOTION_SCORE: 20 >Aug 01 11:13:49.416 rhel91 pacemaker-attrd [3734571] (update_attr_on_host) notice: Setting ag_cluster-lease-expiry[rhel91]: 20230801181446 -> 20230801181502 | from rhel91 with no write delay >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: lease_expiry after monitor update: 20230801181502 >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="rhel92" value="" >name="ag_cluster-lease-expiry" host="rhel93" value="" >name="ag_cluster-lease-expiry" host="rhel91" value="20230801181502" >Aug 01 11:13:49 ag(ag_cluster)[3742018]: INFO: ag_cluster monitor : 8
You cannot view the attachment while viewing its details because your browser does not support IFRAMEs.
View the attachment on a separate page
.
View Attachment As Raw
Actions:
View
Attachments on
bug 2224249
:
1976688
|
1976689
|
1980299
|
1980300
| 1981341 |
1981342
|
1981343