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 1976119 Details for
Bug 2221772
Automatic failover - Pacemaker 2.0 , on-fail=demote with sql server 3node replicas, stat-failure-is-fatal not being adhered to
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.
Pacemaker logs
pacemaker2.log (text/plain), 239.38 KB, created by
Aravind Mahadevan
on 2023-07-17 05:29:29 UTC
(
hide
)
Description:
Pacemaker logs
Filename:
MIME Type:
Creator:
Aravind Mahadevan
Created:
2023-07-17 05:29:29 UTC
Size:
239.38 KB
patch
obsolete
>Jul 14 17:06:56 ag(ag_cluster)[16029]: INFO: ag_cluster notify : 0 >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: mssql_validate >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: Resource agent invoked with: notify >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: mssql_notify pre-start >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: notify: 2023/07/14 17:06:56 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: notify: 2023/07/14 17:06:56 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: notify: 2023/07/14 17:06:56 Replica is RESOLVING (0) >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: notify: 2023/07/14 17:06:56 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: notify: 2023/07/14 17:06:56 Sequence number is 301B:F (52892522250255) >Jul 14 17:06:56 ag(ag_cluster)[16129]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:07:01 ag(ag_cluster)[16129]: INFO: ag_cluster notify : 0 >Jul 14 17:07:07 ag(ag_cluster)[16229]: INFO: mssql_validate >Jul 14 17:07:07 ag(ag_cluster)[16229]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:07 ag(ag_cluster)[16229]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:07 ag(ag_cluster)[16229]: INFO: Resource agent invoked with: notify >Jul 14 17:07:07 ag(ag_cluster)[16229]: INFO: mssql_notify post-start >Jul 14 17:07:07 ag(ag_cluster)[16229]: INFO: ag_cluster notify : 0 >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: mssql_validate >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: Resource agent invoked with: notify >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: mssql_notify pre-promote >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: notify: 2023/07/14 17:07:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: notify: 2023/07/14 17:07:12 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:07:12 ag(ag_cluster)[16276]: INFO: notify: 2023/07/14 17:07:12 Connected to the instance at localhost:1433 >Jul 14 17:07:17 ag(ag_cluster)[16276]: INFO: notify: 2023/07/14 17:07:17 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:07:17 ag(ag_cluster)[16276]: INFO: notify: 2023/07/14 17:07:17 Sequence number is 301B:F (52892522250255) >Jul 14 17:07:17 ag(ag_cluster)[16276]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:07:23 ag(ag_cluster)[16276]: INFO: ag_cluster notify : 0 >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: mssql_validate >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: Resource agent invoked with: notify >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: mssql_notify pre-promote >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: notify: 2023/07/14 17:07:23 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: notify: 2023/07/14 17:07:23 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:07:23 ag(ag_cluster)[16382]: INFO: notify: 2023/07/14 17:07:23 Connected to the instance at localhost:1433 >Jul 14 17:07:28 ag(ag_cluster)[16382]: INFO: notify: 2023/07/14 17:07:28 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:07:28 ag(ag_cluster)[16382]: INFO: notify: 2023/07/14 17:07:28 Sequence number is 301B:F (52892522250255) >Jul 14 17:07:28 ag(ag_cluster)[16382]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:07:33 ag(ag_cluster)[16382]: INFO: ag_cluster notify : 0 >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: mssql_validate >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: Resource agent invoked with: notify >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: mssql_notify post-promote >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: notify: 2023/07/14 17:07:44 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-promote]; connection-timeout [30]; health-threshold [3]; action [post-promote] >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: notify: 2023/07/14 17:07:44 [DEBUG] AG Helper PostPromote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: notify: 2023/07/14 17:07:44 Replica is RESOLVING (0) >Jul 14 17:07:44 ag(ag_cluster)[16504]: INFO: ag_cluster notify : 0 >Jul 14 17:07:55 ag(ag_cluster)[16580]: INFO: mssql_validate >Jul 14 17:07:55 ag(ag_cluster)[16580]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:55 ag(ag_cluster)[16580]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:55 ag(ag_cluster)[16580]: INFO: Resource agent invoked with: notify >Jul 14 17:07:55 ag(ag_cluster)[16580]: INFO: mssql_notify pre-demote >Jul 14 17:07:55 ag(ag_cluster)[16580]: INFO: ag_cluster notify : 0 >Jul 14 17:07:55 ag(ag_cluster)[16625]: INFO: mssql_validate >Jul 14 17:07:55 ag(ag_cluster)[16625]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:55 ag(ag_cluster)[16625]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:55 ag(ag_cluster)[16625]: INFO: Resource agent invoked with: notify >Jul 14 17:07:55 ag(ag_cluster)[16625]: INFO: mssql_notify post-demote >Jul 14 17:07:55 ag(ag_cluster)[16625]: INFO: ag_cluster notify : 0 >Jul 14 17:07:55 ag(ag_cluster)[16670]: INFO: mssql_validate >Jul 14 17:07:55 ag(ag_cluster)[16670]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:55 ag(ag_cluster)[16670]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:55 ag(ag_cluster)[16670]: INFO: Resource agent invoked with: notify >Jul 14 17:07:55 ag(ag_cluster)[16670]: INFO: mssql_notify pre-stop >Jul 14 17:07:55 ag(ag_cluster)[16670]: INFO: ag_cluster notify : 0 >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: mssql_validate >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: Resource agent invoked with: notify >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: mssql_notify post-stop >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: notify: 2023/07/14 17:07:55 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: notify: 2023/07/14 17:07:55 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: notify: 2023/07/14 17:07:55 Replica is RESOLVING (0) >Jul 14 17:07:55 ag(ag_cluster)[16715]: INFO: ag_cluster notify : 0 >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: mssql_validate >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: Resource agent invoked with: notify >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: mssql_notify pre-start >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: notify: 2023/07/14 17:07:55 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: notify: 2023/07/14 17:07:55 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: notify: 2023/07/14 17:07:55 Replica is RESOLVING (0) >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: notify: 2023/07/14 17:07:55 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: notify: 2023/07/14 17:07:55 Sequence number is 301B:F (52892522250255) >Jul 14 17:07:55 ag(ag_cluster)[16789]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:08:00 ag(ag_cluster)[16789]: INFO: ag_cluster notify : 0 >Jul 14 17:08:00 ag(ag_cluster)[16888]: INFO: mssql_validate >Jul 14 17:08:00 ag(ag_cluster)[16888]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:00 ag(ag_cluster)[16888]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:00 ag(ag_cluster)[16888]: INFO: Resource agent invoked with: notify >Jul 14 17:08:00 ag(ag_cluster)[16888]: INFO: mssql_notify pre-stop >Jul 14 17:08:00 ag(ag_cluster)[16888]: INFO: ag_cluster notify : 0 >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: mssql_validate >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: Resource agent invoked with: notify >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: mssql_notify post-stop >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: notify: 2023/07/14 17:08:01 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: notify: 2023/07/14 17:08:01 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: notify: 2023/07/14 17:08:01 Replica is RESOLVING (0) >Jul 14 17:08:01 ag(ag_cluster)[16933]: INFO: ag_cluster notify : 0 >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: mssql_validate >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: Resource agent invoked with: notify >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: mssql_notify pre-start >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: notify: 2023/07/14 17:08:01 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: notify: 2023/07/14 17:08:01 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: notify: 2023/07/14 17:08:01 Replica is RESOLVING (0) >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: notify: 2023/07/14 17:08:01 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: notify: 2023/07/14 17:08:01 Sequence number is 301B:F (52892522250255) >Jul 14 17:08:01 ag(ag_cluster)[17008]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:08:06 ag(ag_cluster)[17008]: INFO: ag_cluster notify : 0 >Jul 14 17:08:11 ag(ag_cluster)[17108]: INFO: mssql_validate >Jul 14 17:08:11 ag(ag_cluster)[17108]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:11 ag(ag_cluster)[17108]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:11 ag(ag_cluster)[17108]: INFO: Resource agent invoked with: notify >Jul 14 17:08:11 ag(ag_cluster)[17108]: INFO: mssql_notify post-start >Jul 14 17:08:11 ag(ag_cluster)[17108]: INFO: ag_cluster notify : 0 >Jul 14 17:08:12 ag(ag_cluster)[17154]: INFO: mssql_validate >Jul 14 17:08:12 ag(ag_cluster)[17154]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:12 ag(ag_cluster)[17154]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:12 ag(ag_cluster)[17154]: INFO: Resource agent invoked with: notify >Jul 14 17:08:12 ag(ag_cluster)[17154]: INFO: mssql_notify pre-stop >Jul 14 17:08:12 ag(ag_cluster)[17154]: INFO: ag_cluster notify : 0 >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: mssql_validate >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: Resource agent invoked with: notify >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: mssql_notify post-stop >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: notify: 2023/07/14 17:08:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: notify: 2023/07/14 17:08:12 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: notify: 2023/07/14 17:08:12 Replica is RESOLVING (0) >Jul 14 17:08:12 ag(ag_cluster)[17199]: INFO: ag_cluster notify : 0 >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: mssql_validate >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: Resource agent invoked with: notify >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: mssql_notify pre-promote >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: notify: 2023/07/14 17:08:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: notify: 2023/07/14 17:08:12 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:08:12 ag(ag_cluster)[17273]: INFO: notify: 2023/07/14 17:08:12 Connected to the instance at localhost:1433 >Jul 14 17:08:17 ag(ag_cluster)[17273]: INFO: notify: 2023/07/14 17:08:17 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:08:17 ag(ag_cluster)[17273]: INFO: notify: 2023/07/14 17:08:17 Sequence number is 301B:F (52892522250255) >Jul 14 17:08:17 ag(ag_cluster)[17273]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:08:22 ag(ag_cluster)[17273]: INFO: ag_cluster notify : 0 >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: mssql_validate >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: Resource agent invoked with: notify >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: mssql_notify pre-promote >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: notify: 2023/07/14 17:08:22 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: notify: 2023/07/14 17:08:22 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:08:22 ag(ag_cluster)[17380]: INFO: notify: 2023/07/14 17:08:22 Connected to the instance at localhost:1433 >Jul 14 17:08:27 ag(ag_cluster)[17380]: INFO: notify: 2023/07/14 17:08:27 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:08:27 ag(ag_cluster)[17380]: INFO: notify: 2023/07/14 17:08:27 Sequence number is 301B:F (52892522250255) >Jul 14 17:08:27 ag(ag_cluster)[17380]: INFO: notify: SEQUENCE_NUMBER: 52892522250255 >Jul 14 17:08:32 ag(ag_cluster)[17380]: INFO: ag_cluster notify : 0 >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: mssql_validate >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: Resource agent invoked with: promote >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: mssql_promote >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:33 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-promote]; connection-timeout [30]; health-threshold [3]; action [promote] >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:33 ag-helper invoked with skip-precheck [false]; sequence-numbers [...]; new-master [server2]; required-synchronized-secondaries-to-commit [-1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:33 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:08:33 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:33 Connected to the instance at localhost:1433 >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Replica is RESOLVING (0) >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Line does not match expected syntax. Ignoring. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Sequence number line [name="ag_cluster-sequence-number" host="server2" value="52892522250255"] >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 2 sequence numbers were found >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Max sequence number is 301B:F (52892522250255) >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Sequence number of server2 is 301B:F (52892522250255) >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 AG has 3 SYNCHRONOUS_COMMIT or CONFIGURATION_ONLY replicas. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 [DEBUG] Promote info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Promoting replica to PRIMARY role... >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Replica is PRIMARY (1) >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Replica is now PRIMARY >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Monitor Caller is: promote. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Replica is PRIMARY (1) >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Instance name is server2. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Current master is server2. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 DB_FAILOVER is ON. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: 2023/07/14 17:08:38 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: promote: PROMOTION_SCORE: 20 >Jul 14 17:08:38 ag(ag_cluster)[17485]: INFO: ag_cluster promote : 0 >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: mssql_validate >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: Resource agent invoked with: notify >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: mssql_notify post-promote >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: notify: 2023/07/14 17:08:38 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-promote]; connection-timeout [30]; health-threshold [3]; action [post-promote] >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: notify: 2023/07/14 17:08:38 [DEBUG] AG Helper PostPromote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: notify: 2023/07/14 17:08:38 Replica is PRIMARY (1) >Jul 14 17:08:38 ag(ag_cluster)[17771]: INFO: ag_cluster notify : 0 >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: mssql_validate >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: Resource agent invoked with: monitor >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: mssql_monitor >Jul 14 17:08:38 IPaddr2(virtualip)[17860]: INFO: Adding inet address 192.168.0.200/24 with broadcast address 192.168.0.255 to device eth0 >Jul 14 17:08:38 IPaddr2(virtualip)[17860]: INFO: Bringing device eth0 up >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:38 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] >Jul 14 17:08:38 IPaddr2(virtualip)[17860]: INFO: /usr/libexec/heartbeat/send_arp -i 200 -r 5 -p /run/resource-agents/send_arp-192.168.0.200 eth0 192.168.0.200 auto not_used not_used >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:38 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:38 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:08:38 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:38 Connected to the instance at localhost:1433 >Jul 14 17:08:42 IPaddr2(virtualip)[17860]: INFO: ARPING 192.168.0.200 from 192.168.0.200 eth0 >Sent 5 probes (5 broadcast(s)) >Received 0 response(s) >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 Monitor Caller is: monitor. >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 Replica is PRIMARY (1) >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 Instance name is server2. >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 Current master is server2. >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 DB_FAILOVER is ON. >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: 2023/07/14 17:08:43 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: lease_expiry after monitor update: >Jul 14 17:08:43 ag(ag_cluster)[17848]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:08:44 ag(ag_cluster)[17848]: INFO: ag_cluster monitor : 8 >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: mssql_validate >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: Resource agent invoked with: monitor >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: mssql_monitor >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:08: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] >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:08:55 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:08:55 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:08:55 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:08:55 Connected to the instance at localhost:1433 >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 Monitor Caller is: monitor. >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 Replica is PRIMARY (1) >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 Instance name is server2. >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 Current master is server2. >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 DB_FAILOVER is ON. >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: 2023/07/14 17:09:00 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: lease_expiry after monitor update: >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:09:00 ag(ag_cluster)[18215]: INFO: ag_cluster monitor : 8 >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: mssql_validate >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: Resource agent invoked with: notify >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: mssql_notify pre-start >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 Replica is PRIMARY (1) >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: 2023/07/14 17:09:07 Sequence number is 301C:2 (52896817217538) >Jul 14 17:09:07 ag(ag_cluster)[18521]: INFO: notify: SEQUENCE_NUMBER: 52896817217538 >Jul 14 17:09:12 ag(ag_cluster)[18521]: INFO: ag_cluster notify : 0 >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: mssql_validate >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: Resource agent invoked with: monitor >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: mssql_monitor >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09: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] >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:12 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:12 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:09:12 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:12 Connected to the instance at localhost:1433 >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 Monitor Caller is: monitor. >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 Replica is PRIMARY (1) >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 Instance name is server2. >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 Current master is server2. >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 DB_FAILOVER is ON. >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: 2023/07/14 17:09:17 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: lease_expiry after monitor update: >Jul 14 17:09:17 ag(ag_cluster)[18792]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:09:18 ag(ag_cluster)[18792]: INFO: ag_cluster monitor : 8 >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: mssql_validate >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: Resource agent invoked with: notify >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: mssql_notify pre-start >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 Replica is PRIMARY (1) >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: 2023/07/14 17:09:18 Sequence number is 301C:2 (52896817217538) >Jul 14 17:09:18 ag(ag_cluster)[19040]: INFO: notify: SEQUENCE_NUMBER: 52896817217538 >Jul 14 17:09:23 ag(ag_cluster)[19040]: INFO: ag_cluster notify : 0 >Jul 14 17:09:23 ag(ag_cluster)[19195]: INFO: mssql_validate >Jul 14 17:09:23 ag(ag_cluster)[19195]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:09:23 ag(ag_cluster)[19195]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:23 ag(ag_cluster)[19195]: INFO: Resource agent invoked with: notify >Jul 14 17:09:23 ag(ag_cluster)[19195]: INFO: mssql_notify post-start >Jul 14 17:09:23 ag(ag_cluster)[19195]: INFO: ag_cluster notify : 0 >Jul 14 17:09:28 ag(ag_cluster)[19244]: INFO: mssql_validate >Jul 14 17:09:28 ag(ag_cluster)[19244]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:09:28 ag(ag_cluster)[19244]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:28 ag(ag_cluster)[19244]: INFO: Resource agent invoked with: notify >Jul 14 17:09:28 ag(ag_cluster)[19244]: INFO: mssql_notify pre-stop >Jul 14 17:09:28 ag(ag_cluster)[19244]: INFO: ag_cluster notify : 0 >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: mssql_validate >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: Resource agent invoked with: monitor >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: mssql_monitor >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:29 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] >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:29 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:29 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:09:29 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:29 Connected to the instance at localhost:1433 >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 Monitor Caller is: monitor. >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 Replica is PRIMARY (1) >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 Instance name is server2. >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 Current master is server2. >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 DB_FAILOVER is ON. >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: 2023/07/14 17:09:34 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: lease_expiry after monitor update: >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:09:34 ag(ag_cluster)[19289]: INFO: ag_cluster monitor : 8 >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: mssql_validate >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: Resource agent invoked with: notify >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: mssql_notify post-stop >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: notify: 2023/07/14 17:09:34 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: notify: 2023/07/14 17:09:34 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: notify: 2023/07/14 17:09:34 Replica is PRIMARY (1) >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: notify: 2023/07/14 17:09:34 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: notify: 2023/07/14 17:09:34 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:34 ag(ag_cluster)[19518]: INFO: ag_cluster notify : 0 >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: mssql_validate >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: Resource agent invoked with: monitor >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: mssql_monitor >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:45 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] >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:45 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:45 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:09:45 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:45 Connected to the instance at localhost:1433 >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Monitor Caller is: monitor. >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Replica is PRIMARY (1) >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Instance name is server2. >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Current master is server2. >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 There is a configuration commit in progress since 2023-07-14 17:08:38.37 -0400 EDT. Not renewing lease. >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Offlining replica... >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Replica is RESOLVING (0) >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 DB_FAILOVER is ON. >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: 2023/07/14 17:09:50 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:09:50 ag(ag_cluster)[19726]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:09:51 ag(ag_cluster)[19726]: INFO: lease_expiry after monitor update: >Jul 14 17:09:51 ag(ag_cluster)[19726]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:09:51 ag(ag_cluster)[19726]: INFO: ag_cluster monitor : 8 >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: mssql_validate >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: Resource agent invoked with: monitor >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: mssql_monitor >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:02 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] >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:02 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:02 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:10:02 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:02 Connected to the instance at localhost:1433 >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 Monitor Caller is: monitor. >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 Replica is RESOLVING (0) >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 Instance name is server2. >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 Current master is server2. >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 test - Role is %!s(ag.Role=0). >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 test - Instance name is server2. >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: monitor: 2023/07/14 17:10:07 test - Current master is server2. >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: lease_expiry after monitor update: >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:10:07 ag(ag_cluster)[20006]: INFO: ag_cluster monitor : 1 >Jul 14 17:10:07 ag(ag_cluster)[20180]: INFO: mssql_validate >Jul 14 17:10:07 ag(ag_cluster)[20180]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:07 ag(ag_cluster)[20180]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:07 ag(ag_cluster)[20180]: INFO: Resource agent invoked with: notify >Jul 14 17:10:07 ag(ag_cluster)[20180]: INFO: mssql_notify pre-demote >Jul 14 17:10:07 IPaddr2(virtualip)[20179]: INFO: IP status = ok, IP_CIP= >Jul 14 17:10:07 ag(ag_cluster)[20180]: INFO: ag_cluster notify : 0 >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: mssql_validate >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: Resource agent invoked with: demote >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: mssql_demote >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: demote: 2023/07/14 17:10:07 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-demote]; connection-timeout [30]; health-threshold [3]; action [demote] >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: demote: 2023/07/14 17:10:07 [DEBUG] AG Helper Demote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: demote: 2023/07/14 17:10:07 Replica is RESOLVING (0) >Jul 14 17:10:07 ag(ag_cluster)[20278]: INFO: ag_cluster demote : 0 >Jul 14 17:10:08 ag(ag_cluster)[20371]: INFO: mssql_validate >Jul 14 17:10:08 ag(ag_cluster)[20371]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:08 ag(ag_cluster)[20371]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:08 ag(ag_cluster)[20371]: INFO: Resource agent invoked with: notify >Jul 14 17:10:08 ag(ag_cluster)[20371]: INFO: mssql_notify post-demote >Jul 14 17:10:08 ag(ag_cluster)[20371]: INFO: ag_cluster notify : 0 >Jul 14 17:10:08 ag(ag_cluster)[20416]: INFO: mssql_validate >Jul 14 17:10:08 ag(ag_cluster)[20416]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:08 ag(ag_cluster)[20416]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:08 ag(ag_cluster)[20416]: INFO: Resource agent invoked with: notify >Jul 14 17:10:08 ag(ag_cluster)[20416]: INFO: mssql_notify pre-stop >Jul 14 17:10:08 ag(ag_cluster)[20416]: INFO: ag_cluster notify : 0 >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: mssql_validate >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: Resource agent invoked with: stop >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: mssql_stop >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: stop: 2023/07/14 17:10:08 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-stop]; connection-timeout [30]; health-threshold [3]; action [stop] >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: stop: 2023/07/14 17:10:08 [DEBUG] AG Helper Stop Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: stop: 2023/07/14 17:10:08 Replica is RESOLVING (0) >Jul 14 17:10:08 ag(ag_cluster)[20461]: INFO: ag_cluster stop : 0 >Jul 14 17:10:40 ag(ag_cluster)[20688]: INFO: mssql_validate >Jul 14 17:10:40 ag(ag_cluster)[20688]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:40 ag(ag_cluster)[20688]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:40 ag(ag_cluster)[20688]: INFO: Resource agent invoked with: start >Jul 14 17:10:40 ag(ag_cluster)[20688]: INFO: mssql_start >Jul 14 17:10:41 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:41 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-start]; connection-timeout [30]; health-threshold [3]; action [start] >Jul 14 17:10:41 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:41 ag-helper invoked with sequence-numbers [...]; required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:10:41 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:41 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:10:41 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:41 Connected to the instance at localhost:1433 >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 [DEBUG] AG Helper Start Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Replica is RESOLVING (0) >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Sequence number is 301C:2 (52896817217538) >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Line does not match expected syntax. Ignoring. >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Sequence number line [name="ag_cluster-sequence-number" host="server2" value=""] >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Line does not match expected syntax. Ignoring. >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 1 sequence numbers were found >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Max sequence number is 17F:F (1644972474383) >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Monitor Caller is: start. >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Replica is RESOLVING (0) >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Instance name is server2. >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: 2023/07/14 17:10:46 Current master is . >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: start: PROMOTION_SCORE: 10 >Jul 14 17:10:46 ag(ag_cluster)[20688]: INFO: ag_cluster start : 0 >Jul 14 17:10:46 ag(ag_cluster)[20887]: INFO: mssql_validate >Jul 14 17:10:46 ag(ag_cluster)[20887]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:46 ag(ag_cluster)[20887]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:46 ag(ag_cluster)[20887]: INFO: Resource agent invoked with: notify >Jul 14 17:10:46 ag(ag_cluster)[20887]: INFO: mssql_notify post-start >Jul 14 17:10:46 ag(ag_cluster)[20887]: INFO: ag_cluster notify : 0 >Jul 14 17:10:46 ag(ag_cluster)[20933]: INFO: mssql_validate >Jul 14 17:10:46 ag(ag_cluster)[20933]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:46 ag(ag_cluster)[20933]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:46 ag(ag_cluster)[20933]: INFO: Resource agent invoked with: notify >Jul 14 17:10:46 ag(ag_cluster)[20933]: INFO: mssql_notify pre-stop >Jul 14 17:10:46 ag(ag_cluster)[20933]: INFO: ag_cluster notify : 0 >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: mssql_validate >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: Resource agent invoked with: notify >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: mssql_notify post-stop >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: notify: 2023/07/14 17: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-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: notify: 2023/07/14 17:10:46 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: notify: 2023/07/14 17:10:46 Replica is RESOLVING (0) >Jul 14 17:10:46 ag(ag_cluster)[20978]: INFO: ag_cluster notify : 0 >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: mssql_validate >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: Resource agent invoked with: notify >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: mssql_notify pre-promote >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: notify: 2023/07/14 17: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-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: notify: 2023/07/14 17:10:46 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:10:46 ag(ag_cluster)[21054]: INFO: notify: 2023/07/14 17:10:46 Connected to the instance at localhost:1433 >Jul 14 17:10:51 ag(ag_cluster)[21054]: INFO: notify: 2023/07/14 17:10:51 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:10:51 ag(ag_cluster)[21054]: INFO: notify: 2023/07/14 17:10:51 Sequence number is 301C:2 (52896817217538) >Jul 14 17:10:51 ag(ag_cluster)[21054]: INFO: notify: SEQUENCE_NUMBER: 52896817217538 >Jul 14 17:10:57 ag(ag_cluster)[21054]: INFO: ag_cluster notify : 0 >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: mssql_validate >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: Resource agent invoked with: notify >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: mssql_notify pre-promote >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: notify: 2023/07/14 17:10:57 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: notify: 2023/07/14 17:10:57 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:10:57 ag(ag_cluster)[21156]: INFO: notify: 2023/07/14 17:10:57 Connected to the instance at localhost:1433 >Jul 14 17:11:02 ag(ag_cluster)[21156]: INFO: notify: 2023/07/14 17:11:02 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:11:02 ag(ag_cluster)[21156]: INFO: notify: 2023/07/14 17:11:02 Sequence number is 301C:2 (52896817217538) >Jul 14 17:11:02 ag(ag_cluster)[21156]: INFO: notify: SEQUENCE_NUMBER: 52896817217538 >Jul 14 17:11:07 ag(ag_cluster)[21156]: INFO: ag_cluster notify : 0 >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: mssql_validate >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: Resource agent invoked with: promote >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: mssql_promote >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:07 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-promote]; connection-timeout [30]; health-threshold [3]; action [promote] >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:07 ag-helper invoked with skip-precheck [false]; sequence-numbers [...]; new-master [server2]; required-synchronized-secondaries-to-commit [-1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:07 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:11:07 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:07 Connected to the instance at localhost:1433 >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Replica is RESOLVING (0) >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Line does not match expected syntax. Ignoring. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Sequence number line [name="ag_cluster-sequence-number" host="server2" value="52896817217538"] >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 2 sequence numbers were found >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Max sequence number is 301C:2 (52896817217538) >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Sequence number of server2 is 301C:2 (52896817217538) >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 AG has 3 SYNCHRONOUS_COMMIT or CONFIGURATION_ONLY replicas. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 [DEBUG] Promote info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Promoting replica to PRIMARY role... >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Replica is PRIMARY (1) >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Replica is now PRIMARY >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Monitor Caller is: promote. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Replica is PRIMARY (1) >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Instance name is server2. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Current master is server2. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 DB_FAILOVER is ON. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: 2023/07/14 17:11:12 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: promote: PROMOTION_SCORE: 20 >Jul 14 17:11:12 ag(ag_cluster)[21260]: INFO: ag_cluster promote : 0 >Jul 14 17:11:12 ag(ag_cluster)[21533]: INFO: mssql_validate >Jul 14 17:11:12 ag(ag_cluster)[21533]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:11:12 ag(ag_cluster)[21533]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:12 ag(ag_cluster)[21533]: INFO: Resource agent invoked with: notify >Jul 14 17:11:12 ag(ag_cluster)[21533]: INFO: mssql_notify post-promote >Jul 14 17:11:12 ag(ag_cluster)[21533]: INFO: notify: 2023/07/14 17:11:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-promote]; connection-timeout [30]; health-threshold [3]; action [post-promote] >Jul 14 17:11:13 ag(ag_cluster)[21533]: INFO: notify: 2023/07/14 17:11:13 [DEBUG] AG Helper PostPromote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:11:13 ag(ag_cluster)[21533]: INFO: notify: 2023/07/14 17:11:13 Replica is PRIMARY (1) >Jul 14 17:11:13 ag(ag_cluster)[21533]: INFO: ag_cluster notify : 0 >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: mssql_validate >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: Resource agent invoked with: monitor >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: mssql_monitor >Jul 14 17:11:13 IPaddr2(virtualip)[21622]: INFO: Adding inet address 192.168.0.200/24 with broadcast address 192.168.0.255 to device eth0 >Jul 14 17:11:13 IPaddr2(virtualip)[21622]: INFO: Bringing device eth0 up >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:13 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] >Jul 14 17:11:13 IPaddr2(virtualip)[21622]: INFO: /usr/libexec/heartbeat/send_arp -i 200 -r 5 -p /run/resource-agents/send_arp-192.168.0.200 eth0 192.168.0.200 auto not_used not_used >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:13 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:13 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:11:13 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:13 Connected to the instance at localhost:1433 >Jul 14 17:11:17 IPaddr2(virtualip)[21622]: INFO: ARPING 192.168.0.200 from 192.168.0.200 eth0 >Sent 5 probes (5 broadcast(s)) >Received 0 response(s) >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 Monitor Caller is: monitor. >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 Replica is PRIMARY (1) >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 Instance name is server2. >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 Current master is server2. >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 DB_FAILOVER is ON. >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: 2023/07/14 17:11:18 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: lease_expiry after monitor update: >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:11:18 ag(ag_cluster)[21609]: INFO: ag_cluster monitor : 8 >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: mssql_validate >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: Resource agent invoked with: monitor >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: mssql_monitor >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:29 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] >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:29 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:29 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:11:29 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:29 Connected to the instance at localhost:1433 >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 Monitor Caller is: monitor. >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 Replica is PRIMARY (1) >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 Instance name is server2. >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 Current master is server2. >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 DB_FAILOVER is ON. >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: 2023/07/14 17:11:34 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: lease_expiry after monitor update: >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:11:34 ag(ag_cluster)[21939]: INFO: ag_cluster monitor : 8 >Jul 14 17:11:42 ag(ag_cluster)[22179]: INFO: mssql_validate >Jul 14 17:11:42 ag(ag_cluster)[22179]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:11:42 ag(ag_cluster)[22179]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:42 ag(ag_cluster)[22179]: INFO: Resource agent invoked with: notify >Jul 14 17:11:42 ag(ag_cluster)[22179]: INFO: mssql_notify pre-start >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:42 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:42 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:43 Replica is PRIMARY (1) >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:43 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:43 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:43 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: 2023/07/14 17:11:43 Sequence number is 301D:2 (52901112184834) >Jul 14 17:11:43 ag(ag_cluster)[22179]: INFO: notify: SEQUENCE_NUMBER: 52901112184834 >Jul 14 17:11:48 ag(ag_cluster)[22179]: INFO: ag_cluster notify : 0 >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: mssql_validate >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: Resource agent invoked with: monitor >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: mssql_monitor >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:48 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] >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:48 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:48 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:11:48 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:48 Connected to the instance at localhost:1433 >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 Monitor Caller is: monitor. >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 Replica is PRIMARY (1) >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 Instance name is server2. >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 Current master is server2. >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 DB_FAILOVER is ON. >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: 2023/07/14 17:11:53 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: lease_expiry after monitor update: >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:11:53 ag(ag_cluster)[22332]: INFO: ag_cluster monitor : 8 >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: mssql_validate >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: Resource agent invoked with: notify >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: mssql_notify pre-start >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 Replica is PRIMARY (1) >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: 2023/07/14 17:11:53 Sequence number is 301D:2 (52901112184834) >Jul 14 17:11:53 ag(ag_cluster)[22516]: INFO: notify: SEQUENCE_NUMBER: 52901112184834 >Jul 14 17:11:58 ag(ag_cluster)[22516]: INFO: ag_cluster notify : 0 >Jul 14 17:11:58 ag(ag_cluster)[22670]: INFO: mssql_validate >Jul 14 17:11:58 ag(ag_cluster)[22670]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:11:58 ag(ag_cluster)[22670]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:11:58 ag(ag_cluster)[22670]: INFO: Resource agent invoked with: notify >Jul 14 17:11:58 ag(ag_cluster)[22670]: INFO: mssql_notify post-start >Jul 14 17:11:58 ag(ag_cluster)[22670]: INFO: ag_cluster notify : 0 >Jul 14 17:12:04 ag(ag_cluster)[22758]: INFO: mssql_validate >Jul 14 17:12:04 ag(ag_cluster)[22758]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:04 ag(ag_cluster)[22758]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:04 ag(ag_cluster)[22758]: INFO: Resource agent invoked with: notify >Jul 14 17:12:04 ag(ag_cluster)[22758]: INFO: mssql_notify pre-stop >Jul 14 17:12:04 ag(ag_cluster)[22758]: INFO: ag_cluster notify : 0 >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: mssql_validate >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: Resource agent invoked with: notify >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: mssql_notify post-stop >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: notify: 2023/07/14 17:12:04 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: notify: 2023/07/14 17:12:04 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: notify: 2023/07/14 17:12:04 Replica is PRIMARY (1) >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: notify: 2023/07/14 17:12:04 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: notify: 2023/07/14 17:12:04 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:12:04 ag(ag_cluster)[22803]: INFO: ag_cluster notify : 0 >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: mssql_validate >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: Resource agent invoked with: monitor >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: mssql_monitor >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:04 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] >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:04 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:04 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:12:04 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:04 Connected to the instance at localhost:1433 >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 Monitor Caller is: monitor. >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 Replica is PRIMARY (1) >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 Instance name is server2. >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 Current master is server2. >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 DB_FAILOVER is ON. >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: 2023/07/14 17:12:09 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:12:09 ag(ag_cluster)[22890]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:12:10 ag(ag_cluster)[22890]: INFO: lease_expiry after monitor update: >Jul 14 17:12:10 ag(ag_cluster)[22890]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:12:10 ag(ag_cluster)[22890]: INFO: ag_cluster monitor : 8 >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: mssql_validate >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: Resource agent invoked with: monitor >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: mssql_monitor >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12: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] >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:21 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:21 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:12:21 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:21 Connected to the instance at localhost:1433 >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 Monitor Caller is: monitor. >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 Replica is PRIMARY (1) >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 Instance name is server2. >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 Current master is server2. >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 There is a configuration commit in progress since 2023-07-14 17:11:13.017 -0400 EDT. Not renewing lease. >Jul 14 17:12:26 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:26 Offlining replica... >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:27 Replica is RESOLVING (0) >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:27 DB_FAILOVER is ON. >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:27 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: monitor: 2023/07/14 17:12:27 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: lease_expiry after monitor update: >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:12:27 ag(ag_cluster)[23120]: INFO: ag_cluster monitor : 8 >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: mssql_validate >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: Resource agent invoked with: monitor >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: mssql_monitor >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:38 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] >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:38 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:38 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:12:38 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:38 Connected to the instance at localhost:1433 >Jul 14 17:12:43 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 Monitor Caller is: monitor. >Jul 14 17:12:43 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:12:43 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 Replica is RESOLVING (0) >Jul 14 17:12:43 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 Instance name is server2. >Jul 14 17:12:43 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 Current master is server2. >Jul 14 17:12:44 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 test - Role is %!s(ag.Role=0). >Jul 14 17:12:44 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 test - Instance name is server2. >Jul 14 17:12:44 ag(ag_cluster)[23412]: INFO: monitor: 2023/07/14 17:12:43 test - Current master is server2. >Jul 14 17:12:44 ag(ag_cluster)[23412]: INFO: lease_expiry after monitor update: >Jul 14 17:12:44 ag(ag_cluster)[23412]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:12:44 ag(ag_cluster)[23412]: INFO: ag_cluster monitor : 1 >Jul 14 17:12:44 ag(ag_cluster)[23581]: INFO: mssql_validate >Jul 14 17:12:44 ag(ag_cluster)[23581]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:44 ag(ag_cluster)[23581]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:44 ag(ag_cluster)[23581]: INFO: Resource agent invoked with: notify >Jul 14 17:12:44 IPaddr2(virtualip)[23580]: INFO: IP status = ok, IP_CIP= >Jul 14 17:12:44 ag(ag_cluster)[23581]: INFO: mssql_notify pre-demote >Jul 14 17:12:44 ag(ag_cluster)[23581]: INFO: ag_cluster notify : 0 >Jul 14 17:12:45 ag(ag_cluster)[23679]: INFO: mssql_validate >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: Resource agent invoked with: demote >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: mssql_demote >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: demote: 2023/07/14 17:12:46 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-demote]; connection-timeout [30]; health-threshold [3]; action [demote] >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: demote: 2023/07/14 17:12:46 [DEBUG] AG Helper Demote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: demote: 2023/07/14 17:12:46 Replica is RESOLVING (0) >Jul 14 17:12:46 ag(ag_cluster)[23679]: INFO: ag_cluster demote : 0 >Jul 14 17:12:46 ag(ag_cluster)[23771]: INFO: mssql_validate >Jul 14 17:12:46 ag(ag_cluster)[23771]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:46 ag(ag_cluster)[23771]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:46 ag(ag_cluster)[23771]: INFO: Resource agent invoked with: notify >Jul 14 17:12:46 ag(ag_cluster)[23771]: INFO: mssql_notify post-demote >Jul 14 17:12:46 ag(ag_cluster)[23771]: INFO: ag_cluster notify : 0 >Jul 14 17:12:51 ag(ag_cluster)[23816]: INFO: mssql_validate >Jul 14 17:12:51 ag(ag_cluster)[23816]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:51 ag(ag_cluster)[23816]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:12:51 ag(ag_cluster)[23816]: INFO: Resource agent invoked with: notify >Jul 14 17:12:51 ag(ag_cluster)[23816]: INFO: mssql_notify pre-stop >Jul 14 17:12:51 ag(ag_cluster)[23816]: INFO: ag_cluster notify : 0 >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: mssql_validate >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: Resource agent invoked with: stop >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: mssql_stop >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: stop: 2023/07/14 17:12:51 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-stop]; connection-timeout [30]; health-threshold [3]; action [stop] >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: stop: 2023/07/14 17:12:51 [DEBUG] AG Helper Stop Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: stop: 2023/07/14 17:12:51 Replica is RESOLVING (0) >Jul 14 17:12:51 ag(ag_cluster)[23861]: INFO: ag_cluster stop : 0 >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: mssql_validate >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: Resource agent invoked with: start >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: mssql_start >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:02 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-start]; connection-timeout [30]; health-threshold [3]; action [start] >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:02 ag-helper invoked with sequence-numbers [...]; required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:02 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:13:02 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:02 Connected to the instance at localhost:1433 >Jul 14 17:13:07 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 [DEBUG] AG Helper Start Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Replica is RESOLVING (0) >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Sequence number is 301D:2 (52901112184834) >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Line does not match expected syntax. Ignoring. >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Sequence number line [name="ag_cluster-sequence-number" host="server2" value=""] >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Line does not match expected syntax. Ignoring. >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 1 sequence numbers were found >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Max sequence number is 17F:F (1644972474383) >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Monitor Caller is: start. >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Replica is RESOLVING (0) >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Instance name is server2. >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: 2023/07/14 17:13:07 Current master is . >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: start: PROMOTION_SCORE: 10 >Jul 14 17:13:08 ag(ag_cluster)[23943]: INFO: ag_cluster start : 0 >Jul 14 17:13:08 ag(ag_cluster)[24141]: INFO: mssql_validate >Jul 14 17:13:08 ag(ag_cluster)[24141]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:08 ag(ag_cluster)[24141]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:08 ag(ag_cluster)[24141]: INFO: Resource agent invoked with: notify >Jul 14 17:13:08 ag(ag_cluster)[24141]: INFO: mssql_notify post-start >Jul 14 17:13:08 ag(ag_cluster)[24141]: INFO: ag_cluster notify : 0 >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: mssql_validate >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: Resource agent invoked with: notify >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: mssql_notify pre-start >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: notify: 2023/07/14 17:13:08 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: notify: 2023/07/14 17:13:08 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: notify: 2023/07/14 17:13:08 Replica is RESOLVING (0) >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: notify: 2023/07/14 17:13:08 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: notify: 2023/07/14 17:13:08 Sequence number is 301D:2 (52901112184834) >Jul 14 17:13:08 ag(ag_cluster)[24187]: INFO: notify: SEQUENCE_NUMBER: 52901112184834 >Jul 14 17:13:13 ag(ag_cluster)[24187]: INFO: ag_cluster notify : 0 >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: mssql_validate >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: Resource agent invoked with: notify >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: mssql_notify pre-start >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: notify: 2023/07/14 17:13:13 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: notify: 2023/07/14 17:13:13 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: notify: 2023/07/14 17:13:13 Replica is RESOLVING (0) >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: notify: 2023/07/14 17:13:13 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: notify: 2023/07/14 17:13:13 Sequence number is 301D:2 (52901112184834) >Jul 14 17:13:13 ag(ag_cluster)[24289]: INFO: notify: SEQUENCE_NUMBER: 52901112184834 >Jul 14 17:13:18 ag(ag_cluster)[24289]: INFO: ag_cluster notify : 0 >Jul 14 17:13:19 ag(ag_cluster)[24390]: INFO: mssql_validate >Jul 14 17:13:19 ag(ag_cluster)[24390]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:19 ag(ag_cluster)[24390]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:19 ag(ag_cluster)[24390]: INFO: Resource agent invoked with: notify >Jul 14 17:13:19 ag(ag_cluster)[24390]: INFO: mssql_notify post-start >Jul 14 17:13:19 ag(ag_cluster)[24390]: INFO: ag_cluster notify : 0 >Jul 14 17:13:19 ag(ag_cluster)[24436]: INFO: mssql_validate >Jul 14 17:13:19 ag(ag_cluster)[24436]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:19 ag(ag_cluster)[24436]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:19 ag(ag_cluster)[24436]: INFO: Resource agent invoked with: notify >Jul 14 17:13:19 ag(ag_cluster)[24436]: INFO: mssql_notify pre-stop >Jul 14 17:13:19 ag(ag_cluster)[24436]: INFO: ag_cluster notify : 0 >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: mssql_validate >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: Resource agent invoked with: notify >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: mssql_notify post-stop >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: notify: 2023/07/14 17:13:19 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: notify: 2023/07/14 17:13:19 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: notify: 2023/07/14 17:13:19 Replica is RESOLVING (0) >Jul 14 17:13:19 ag(ag_cluster)[24481]: INFO: ag_cluster notify : 0 >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: mssql_validate >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: Resource agent invoked with: notify >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: mssql_notify pre-promote >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: notify: 2023/07/14 17:13:19 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: notify: 2023/07/14 17:13:19 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:13:19 ag(ag_cluster)[24555]: INFO: notify: 2023/07/14 17:13:19 Connected to the instance at localhost:1433 >Jul 14 17:13:24 ag(ag_cluster)[24555]: INFO: notify: 2023/07/14 17:13:24 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:13:24 ag(ag_cluster)[24555]: INFO: notify: 2023/07/14 17:13:24 Sequence number is 301D:2 (52901112184834) >Jul 14 17:13:24 ag(ag_cluster)[24555]: INFO: notify: SEQUENCE_NUMBER: 52901112184834 >Jul 14 17:13:29 ag(ag_cluster)[24555]: INFO: ag_cluster notify : 0 >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: mssql_validate >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: Resource agent invoked with: notify >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: mssql_notify pre-promote >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: notify: 2023/07/14 17:13:30 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: notify: 2023/07/14 17:13:30 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:13:30 ag(ag_cluster)[24662]: INFO: notify: 2023/07/14 17:13:30 Connected to the instance at localhost:1433 >Jul 14 17:13:35 ag(ag_cluster)[24662]: INFO: notify: 2023/07/14 17:13:35 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:13:35 ag(ag_cluster)[24662]: INFO: notify: 2023/07/14 17:13:35 Sequence number is 301D:2 (52901112184834) >Jul 14 17:13:35 ag(ag_cluster)[24662]: INFO: notify: SEQUENCE_NUMBER: 52901112184834 >Jul 14 17:13:40 ag(ag_cluster)[24662]: INFO: ag_cluster notify : 0 >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: mssql_validate >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: Resource agent invoked with: promote >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: mssql_promote >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:40 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-promote]; connection-timeout [30]; health-threshold [3]; action [promote] >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:40 ag-helper invoked with skip-precheck [false]; sequence-numbers [...]; new-master [server2]; required-synchronized-secondaries-to-commit [-1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:40 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:13:40 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:40 Connected to the instance at localhost:1433 >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Replica is RESOLVING (0) >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Line does not match expected syntax. Ignoring. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Sequence number line [name="ag_cluster-sequence-number" host="server2" value="52901112184834"] >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 2 sequence numbers were found >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Max sequence number is 301D:2 (52901112184834) >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Sequence number of server2 is 301D:2 (52901112184834) >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 AG has 3 SYNCHRONOUS_COMMIT or CONFIGURATION_ONLY replicas. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 [DEBUG] Promote info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Promoting replica to PRIMARY role... >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Replica is PRIMARY (1) >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Replica is now PRIMARY >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Monitor Caller is: promote. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Replica is PRIMARY (1) >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Instance name is server2. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Current master is server2. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 DB_FAILOVER is ON. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: 2023/07/14 17:13:45 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: promote: PROMOTION_SCORE: 20 >Jul 14 17:13:45 ag(ag_cluster)[24779]: INFO: ag_cluster promote : 0 >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: mssql_validate >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: Resource agent invoked with: notify >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: mssql_notify post-promote >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: notify: 2023/07/14 17:13:45 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-promote]; connection-timeout [30]; health-threshold [3]; action [post-promote] >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: notify: 2023/07/14 17:13:45 [DEBUG] AG Helper PostPromote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: notify: 2023/07/14 17:13:45 Replica is PRIMARY (1) >Jul 14 17:13:45 ag(ag_cluster)[25053]: INFO: ag_cluster notify : 0 >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: mssql_validate >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: Resource agent invoked with: monitor >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: mssql_monitor >Jul 14 17:13:46 IPaddr2(virtualip)[25141]: INFO: Adding inet address 192.168.0.200/24 with broadcast address 192.168.0.255 to device eth0 >Jul 14 17:13:46 IPaddr2(virtualip)[25141]: INFO: Bringing device eth0 up >Jul 14 17:13:46 IPaddr2(virtualip)[25141]: INFO: /usr/libexec/heartbeat/send_arp -i 200 -r 5 -p /run/resource-agents/send_arp-192.168.0.200 eth0 192.168.0.200 auto not_used not_used >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13: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] >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:46 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:46 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:13:46 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:46 Connected to the instance at localhost:1433 >Jul 14 17:13:50 IPaddr2(virtualip)[25141]: INFO: ARPING 192.168.0.200 from 192.168.0.200 eth0 >Sent 5 probes (5 broadcast(s)) >Received 0 response(s) >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 Monitor Caller is: monitor. >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 Replica is PRIMARY (1) >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 Instance name is server2. >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 Current master is server2. >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 DB_FAILOVER is ON. >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: 2023/07/14 17:13:51 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: lease_expiry after monitor update: >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:13:51 ag(ag_cluster)[25129]: INFO: ag_cluster monitor : 8 >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: mssql_validate >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: Resource agent invoked with: monitor >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: mssql_monitor >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:02 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] >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:02 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:02 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:14:02 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:02 Connected to the instance at localhost:1433 >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 Monitor Caller is: monitor. >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 Replica is PRIMARY (1) >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 Instance name is server2. >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 Current master is server2. >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 DB_FAILOVER is ON. >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: 2023/07/14 17:14:07 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: lease_expiry after monitor update: >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:14:07 ag(ag_cluster)[25439]: INFO: ag_cluster monitor : 8 >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: mssql_validate >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: Resource agent invoked with: monitor >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: mssql_monitor >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14: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] >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:19 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:19 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:14:19 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:19 Connected to the instance at localhost:1433 >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 Monitor Caller is: monitor. >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 Replica is PRIMARY (1) >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 Instance name is server2. >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 Current master is server2. >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 DB_FAILOVER is ON. >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: 2023/07/14 17:14:24 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: lease_expiry after monitor update: >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:14:24 ag(ag_cluster)[25715]: INFO: ag_cluster monitor : 8 >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: mssql_validate >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: Resource agent invoked with: notify >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: mssql_notify pre-start >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 Replica is PRIMARY (1) >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: 2023/07/14 17:14:24 Sequence number is 301E:1 (52905407152129) >Jul 14 17:14:24 ag(ag_cluster)[25902]: INFO: notify: SEQUENCE_NUMBER: 52905407152129 >Jul 14 17:14:29 ag(ag_cluster)[25902]: INFO: ag_cluster notify : 0 >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: mssql_validate >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: Resource agent invoked with: notify >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: mssql_notify pre-start >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 Replica is PRIMARY (1) >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: 2023/07/14 17:14:31 Sequence number is 301E:1 (52905407152129) >Jul 14 17:14:31 ag(ag_cluster)[26055]: INFO: notify: SEQUENCE_NUMBER: 52905407152129 >Jul 14 17:14:36 ag(ag_cluster)[26055]: INFO: ag_cluster notify : 0 >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: mssql_validate >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: Resource agent invoked with: monitor >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: mssql_monitor >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:36 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] >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:36 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:36 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:14:36 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:36 Connected to the instance at localhost:1433 >Jul 14 17:14:41 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 Monitor Caller is: monitor. >Jul 14 17:14:41 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:14:41 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 Replica is PRIMARY (1) >Jul 14 17:14:41 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 Instance name is server2. >Jul 14 17:14:41 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 Current master is server2. >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 DB_FAILOVER is ON. >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: monitor: 2023/07/14 17:14:41 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: lease_expiry after monitor update: >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:14:42 ag(ag_cluster)[26167]: INFO: ag_cluster monitor : 8 >Jul 14 17:14:42 ag(ag_cluster)[26409]: INFO: mssql_validate >Jul 14 17:14:42 ag(ag_cluster)[26409]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:14:42 ag(ag_cluster)[26409]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:42 ag(ag_cluster)[26409]: INFO: Resource agent invoked with: notify >Jul 14 17:14:42 ag(ag_cluster)[26409]: INFO: mssql_notify post-start >Jul 14 17:14:42 ag(ag_cluster)[26409]: INFO: ag_cluster notify : 0 >Jul 14 17:14:47 ag(ag_cluster)[26498]: INFO: mssql_validate >Jul 14 17:14:47 ag(ag_cluster)[26498]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:14:47 ag(ag_cluster)[26498]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:47 ag(ag_cluster)[26498]: INFO: Resource agent invoked with: notify >Jul 14 17:14:47 ag(ag_cluster)[26498]: INFO: mssql_notify pre-stop >Jul 14 17:14:47 ag(ag_cluster)[26498]: INFO: ag_cluster notify : 0 >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: mssql_validate >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: Resource agent invoked with: monitor >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: mssql_monitor >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14: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] >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:53 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:53 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:14:53 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:53 Connected to the instance at localhost:1433 >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Monitor Caller is: monitor. >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Replica is PRIMARY (1) >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Instance name is server2. >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Current master is server2. >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 There is a configuration commit in progress since 2023-07-14 17:13:45.683 -0400 EDT. Not renewing lease. >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Offlining replica... >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Replica is RESOLVING (0) >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 DB_FAILOVER is ON. >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: 2023/07/14 17:14:58 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: lease_expiry after monitor update: >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:14:58 ag(ag_cluster)[26543]: INFO: ag_cluster monitor : 8 >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: mssql_validate >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: Resource agent invoked with: notify >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: mssql_notify post-stop >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: notify: 2023/07/14 17:14:58 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: notify: 2023/07/14 17:14:58 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: notify: 2023/07/14 17:14:58 Replica is RESOLVING (0) >Jul 14 17:14:58 ag(ag_cluster)[26776]: INFO: ag_cluster notify : 0 >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: mssql_validate >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: Resource agent invoked with: monitor >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: mssql_monitor >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:09 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] >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:09 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:09 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:15:09 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:09 Connected to the instance at localhost:1433 >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 Monitor Caller is: monitor. >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 Replica is RESOLVING (0) >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 Instance name is server2. >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 Current master is server2. >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 test - Role is %!s(ag.Role=0). >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 test - Instance name is server2. >Jul 14 17:15:14 ag(ag_cluster)[26893]: INFO: monitor: 2023/07/14 17:15:14 test - Current master is server2. >Jul 14 17:15:15 ag(ag_cluster)[26893]: INFO: lease_expiry after monitor update: >Jul 14 17:15:15 ag(ag_cluster)[26893]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:15:15 ag(ag_cluster)[26893]: INFO: ag_cluster monitor : 1 >Jul 14 17:15:15 ag(ag_cluster)[27062]: INFO: mssql_validate >Jul 14 17:15:15 ag(ag_cluster)[27062]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:15 ag(ag_cluster)[27062]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:15 ag(ag_cluster)[27062]: INFO: Resource agent invoked with: notify >Jul 14 17:15:15 ag(ag_cluster)[27062]: INFO: mssql_notify pre-demote >Jul 14 17:15:15 ag(ag_cluster)[27062]: INFO: ag_cluster notify : 0 >Jul 14 17:15:15 IPaddr2(virtualip)[27061]: INFO: IP status = ok, IP_CIP= >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: mssql_validate >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: Resource agent invoked with: demote >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: mssql_demote >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: demote: 2023/07/14 17:15:15 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-demote]; connection-timeout [30]; health-threshold [3]; action [demote] >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: demote: 2023/07/14 17:15:15 [DEBUG] AG Helper Demote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: demote: 2023/07/14 17:15:15 Replica is RESOLVING (0) >Jul 14 17:15:15 ag(ag_cluster)[27160]: INFO: ag_cluster demote : 0 >Jul 14 17:15:15 ag(ag_cluster)[27253]: INFO: mssql_validate >Jul 14 17:15:15 ag(ag_cluster)[27253]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:15 ag(ag_cluster)[27253]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:15 ag(ag_cluster)[27253]: INFO: Resource agent invoked with: notify >Jul 14 17:15:15 ag(ag_cluster)[27253]: INFO: mssql_notify post-demote >Jul 14 17:15:15 ag(ag_cluster)[27253]: INFO: ag_cluster notify : 0 >Jul 14 17:15:15 ag(ag_cluster)[27298]: INFO: mssql_validate >Jul 14 17:15:15 ag(ag_cluster)[27298]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:15 ag(ag_cluster)[27298]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:15 ag(ag_cluster)[27298]: INFO: Resource agent invoked with: notify >Jul 14 17:15:15 ag(ag_cluster)[27298]: INFO: mssql_notify pre-stop >Jul 14 17:15:15 ag(ag_cluster)[27298]: INFO: ag_cluster notify : 0 >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: mssql_validate >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: Resource agent invoked with: stop >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: mssql_stop >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: stop: 2023/07/14 17:15:15 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-stop]; connection-timeout [30]; health-threshold [3]; action [stop] >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: stop: 2023/07/14 17:15:15 [DEBUG] AG Helper Stop Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: stop: 2023/07/14 17:15:15 Replica is RESOLVING (0) >Jul 14 17:15:15 ag(ag_cluster)[27343]: INFO: ag_cluster stop : 0 >Jul 14 17:15:42 ag(ag_cluster)[27444]: INFO: mssql_validate >Jul 14 17:15:42 ag(ag_cluster)[27444]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:42 ag(ag_cluster)[27444]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:42 ag(ag_cluster)[27444]: INFO: Resource agent invoked with: start >Jul 14 17:15:43 ag(ag_cluster)[27444]: INFO: mssql_start >Jul 14 17:15:43 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:43 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-start]; connection-timeout [30]; health-threshold [3]; action [start] >Jul 14 17:15:43 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:43 ag-helper invoked with sequence-numbers [...]; required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:15:43 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:43 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:15:43 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:43 Connected to the instance at localhost:1433 >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 [DEBUG] AG Helper Start Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Replica is RESOLVING (0) >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Sequence number is 301E:1 (52905407152129) >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Line does not match expected syntax. Ignoring. >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Sequence number line [name="ag_cluster-sequence-number" host="server2" value=""] >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Line does not match expected syntax. Ignoring. >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 1 sequence numbers were found >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Max sequence number is 17F:F (1644972474383) >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Monitor Caller is: start. >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Replica is RESOLVING (0) >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Instance name is server2. >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: 2023/07/14 17:15:48 Current master is . >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: start: PROMOTION_SCORE: 10 >Jul 14 17:15:48 ag(ag_cluster)[27444]: INFO: ag_cluster start : 0 >Jul 14 17:15:48 ag(ag_cluster)[27644]: INFO: mssql_validate >Jul 14 17:15:48 ag(ag_cluster)[27644]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:48 ag(ag_cluster)[27644]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:48 ag(ag_cluster)[27644]: INFO: Resource agent invoked with: notify >Jul 14 17:15:48 ag(ag_cluster)[27644]: INFO: mssql_notify post-start >Jul 14 17:15:48 ag(ag_cluster)[27644]: INFO: ag_cluster notify : 0 >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: mssql_validate >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: Resource agent invoked with: notify >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: mssql_notify pre-start >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: notify: 2023/07/14 17:15:48 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: notify: 2023/07/14 17:15:48 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: notify: 2023/07/14 17:15:48 Replica is RESOLVING (0) >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: notify: 2023/07/14 17:15:48 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: notify: 2023/07/14 17:15:48 Sequence number is 301E:1 (52905407152129) >Jul 14 17:15:48 ag(ag_cluster)[27690]: INFO: notify: SEQUENCE_NUMBER: 52905407152129 >Jul 14 17:15:53 ag(ag_cluster)[27690]: INFO: ag_cluster notify : 0 >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: mssql_validate >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: Resource agent invoked with: notify >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: mssql_notify pre-start >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: notify: 2023/07/14 17:15:53 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: notify: 2023/07/14 17:15:53 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:15:53 ag(ag_cluster)[27790]: INFO: notify: 2023/07/14 17:15:53 Replica is RESOLVING (0) >Jul 14 17:15:54 ag(ag_cluster)[27790]: INFO: notify: 2023/07/14 17:15:53 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:15:54 ag(ag_cluster)[27790]: INFO: notify: 2023/07/14 17:15:53 Sequence number is 301E:1 (52905407152129) >Jul 14 17:15:54 ag(ag_cluster)[27790]: INFO: notify: SEQUENCE_NUMBER: 52905407152129 >Jul 14 17:15:59 ag(ag_cluster)[27790]: INFO: ag_cluster notify : 0 >Jul 14 17:15:59 ag(ag_cluster)[27891]: INFO: mssql_validate >Jul 14 17:15:59 ag(ag_cluster)[27891]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:59 ag(ag_cluster)[27891]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:59 ag(ag_cluster)[27891]: INFO: Resource agent invoked with: notify >Jul 14 17:15:59 ag(ag_cluster)[27891]: INFO: mssql_notify post-start >Jul 14 17:15:59 ag(ag_cluster)[27891]: INFO: ag_cluster notify : 0 >Jul 14 17:15:59 ag(ag_cluster)[27937]: INFO: mssql_validate >Jul 14 17:15:59 ag(ag_cluster)[27937]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:59 ag(ag_cluster)[27937]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:59 ag(ag_cluster)[27937]: INFO: Resource agent invoked with: notify >Jul 14 17:15:59 ag(ag_cluster)[27937]: INFO: mssql_notify pre-stop >Jul 14 17:15:59 ag(ag_cluster)[27937]: INFO: ag_cluster notify : 0 >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: mssql_validate >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: Resource agent invoked with: notify >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: mssql_notify post-stop >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: notify: 2023/07/14 17:15:59 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: notify: 2023/07/14 17:15:59 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: notify: 2023/07/14 17:15:59 Replica is RESOLVING (0) >Jul 14 17:15:59 ag(ag_cluster)[27982]: INFO: ag_cluster notify : 0 >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: mssql_validate >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: Resource agent invoked with: notify >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: mssql_notify pre-promote >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: notify: 2023/07/14 17:15:59 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: notify: 2023/07/14 17:15:59 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:15:59 ag(ag_cluster)[28058]: INFO: notify: 2023/07/14 17:15:59 Connected to the instance at localhost:1433 >Jul 14 17:16:04 ag(ag_cluster)[28058]: INFO: notify: 2023/07/14 17:16:04 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:16:04 ag(ag_cluster)[28058]: INFO: notify: 2023/07/14 17:16:04 Sequence number is 301E:1 (52905407152129) >Jul 14 17:16:04 ag(ag_cluster)[28058]: INFO: notify: SEQUENCE_NUMBER: 52905407152129 >Jul 14 17:16:09 ag(ag_cluster)[28058]: INFO: ag_cluster notify : 0 >Jul 14 17:16:09 ag(ag_cluster)[28161]: INFO: mssql_validate >Jul 14 17:16:09 ag(ag_cluster)[28161]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:16:10 ag(ag_cluster)[28161]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:16:10 ag(ag_cluster)[28161]: INFO: Resource agent invoked with: notify >Jul 14 17:16:10 ag(ag_cluster)[28161]: INFO: mssql_notify pre-promote >Jul 14 17:16:10 ag(ag_cluster)[28161]: INFO: notify: 2023/07/14 17:16:10 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:16:10 ag(ag_cluster)[28161]: INFO: notify: 2023/07/14 17:16:10 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:16:10 ag(ag_cluster)[28161]: INFO: notify: 2023/07/14 17:16:10 Connected to the instance at localhost:1433 >Jul 14 17:16:15 ag(ag_cluster)[28161]: INFO: notify: 2023/07/14 17:16:15 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:16:15 ag(ag_cluster)[28161]: INFO: notify: 2023/07/14 17:16:15 Sequence number is 301E:1 (52905407152129) >Jul 14 17:16:15 ag(ag_cluster)[28161]: INFO: notify: SEQUENCE_NUMBER: 52905407152129 >Jul 14 17:16:20 ag(ag_cluster)[28161]: INFO: ag_cluster notify : 0 >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: mssql_validate >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: Resource agent invoked with: promote >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: mssql_promote >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:20 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-promote]; connection-timeout [30]; health-threshold [3]; action [promote] >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:20 ag-helper invoked with skip-precheck [false]; sequence-numbers [...]; new-master [server2]; required-synchronized-secondaries-to-commit [-1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:20 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:16:20 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:20 Connected to the instance at localhost:1433 >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Replica is RESOLVING (0) >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Line does not match expected syntax. Ignoring. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Sequence number line [name="ag_cluster-sequence-number" host="server2" value="52905407152129"] >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 2 sequence numbers were found >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Max sequence number is 301E:1 (52905407152129) >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Sequence number of server2 is 301E:1 (52905407152129) >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 AG has 3 SYNCHRONOUS_COMMIT or CONFIGURATION_ONLY replicas. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 [DEBUG] Promote info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Promoting replica to PRIMARY role... >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Replica is PRIMARY (1) >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Replica is now PRIMARY >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Monitor Caller is: promote. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Replica is PRIMARY (1) >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Instance name is server2. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Current master is server2. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 DB_FAILOVER is ON. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: 2023/07/14 17:16:25 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: promote: PROMOTION_SCORE: 20 >Jul 14 17:16:25 ag(ag_cluster)[28267]: INFO: ag_cluster promote : 0 >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: mssql_validate >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: Resource agent invoked with: notify >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: mssql_notify post-promote >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: notify: 2023/07/14 17:16:25 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-promote]; connection-timeout [30]; health-threshold [3]; action [post-promote] >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: notify: 2023/07/14 17:16:25 [DEBUG] AG Helper PostPromote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: notify: 2023/07/14 17:16:25 Replica is PRIMARY (1) >Jul 14 17:16:25 ag(ag_cluster)[28543]: INFO: ag_cluster notify : 0 >Jul 14 17:16:25 ag(ag_cluster)[28619]: INFO: mssql_validate >Jul 14 17:16:25 ag(ag_cluster)[28619]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:16:25 ag(ag_cluster)[28619]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:16:25 ag(ag_cluster)[28619]: INFO: Resource agent invoked with: monitor >Jul 14 17:16:25 ag(ag_cluster)[28619]: INFO: mssql_monitor >Jul 14 17:16:26 IPaddr2(virtualip)[28633]: INFO: Adding inet address 192.168.0.200/24 with broadcast address 192.168.0.255 to device eth0 >Jul 14 17:16:26 IPaddr2(virtualip)[28633]: INFO: Bringing device eth0 up >Jul 14 17:16:26 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16: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] >Jul 14 17:16:26 IPaddr2(virtualip)[28633]: INFO: /usr/libexec/heartbeat/send_arp -i 200 -r 5 -p /run/resource-agents/send_arp-192.168.0.200 eth0 192.168.0.200 auto not_used not_used >Jul 14 17:16:26 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:26 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:16:26 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:26 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:16:26 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:26 Connected to the instance at localhost:1433 >Jul 14 17:16:30 IPaddr2(virtualip)[28633]: INFO: ARPING 192.168.0.200 from 192.168.0.200 eth0 >Sent 5 probes (5 broadcast(s)) >Received 0 response(s) >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 Monitor Caller is: monitor. >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 Replica is PRIMARY (1) >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 Instance name is server2. >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 Current master is server2. >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 DB_FAILOVER is ON. >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: 2023/07/14 17:16:31 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: lease_expiry after monitor update: >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:16:31 ag(ag_cluster)[28619]: INFO: ag_cluster monitor : 8 >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: mssql_validate >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: Resource agent invoked with: monitor >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: mssql_monitor >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16: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] >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:42 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:42 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:16:42 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:42 Connected to the instance at localhost:1433 >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 Monitor Caller is: monitor. >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 Replica is PRIMARY (1) >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 Instance name is server2. >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 Current master is server2. >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 DB_FAILOVER is ON. >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: 2023/07/14 17:16:47 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: lease_expiry after monitor update: >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:16:47 ag(ag_cluster)[28945]: INFO: ag_cluster monitor : 8 >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: mssql_validate >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: Resource agent invoked with: monitor >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: mssql_monitor >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:16: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] >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:16:58 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:16:58 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:16:58 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:16:58 Connected to the instance at localhost:1433 >Jul 14 17:17:03 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 Monitor Caller is: monitor. >Jul 14 17:17:03 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:17:03 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 Replica is PRIMARY (1) >Jul 14 17:17:03 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 Instance name is server2. >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 Current master is server2. >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 DB_FAILOVER is ON. >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: 2023/07/14 17:17:03 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: lease_expiry after monitor update: >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:17:04 ag(ag_cluster)[29218]: INFO: ag_cluster monitor : 8 >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: mssql_validate >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: Resource agent invoked with: notify >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: mssql_notify pre-start >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 Replica is PRIMARY (1) >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: 2023/07/14 17:17:04 Sequence number is 301F:1 (52909702119425) >Jul 14 17:17:04 ag(ag_cluster)[29401]: INFO: notify: SEQUENCE_NUMBER: 52909702119425 >Jul 14 17:17:09 ag(ag_cluster)[29401]: INFO: ag_cluster notify : 0 >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: mssql_validate >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: Resource agent invoked with: notify >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: mssql_notify pre-start >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 Replica is PRIMARY (1) >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: 2023/07/14 17:17:11 Sequence number is 301F:1 (52909702119425) >Jul 14 17:17:11 ag(ag_cluster)[29554]: INFO: notify: SEQUENCE_NUMBER: 52909702119425 >Jul 14 17:17:16 ag(ag_cluster)[29554]: INFO: ag_cluster notify : 0 >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: mssql_validate >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: Resource agent invoked with: monitor >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: mssql_monitor >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:16 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] >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:16 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:16 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:17:16 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:16 Connected to the instance at localhost:1433 >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 Monitor Caller is: monitor. >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 Replica is PRIMARY (1) >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 Instance name is server2. >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 Current master is server2. >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 DB_FAILOVER is ON. >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:17:21 ag(ag_cluster)[29666]: INFO: monitor: 2023/07/14 17:17:21 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:17:22 ag(ag_cluster)[29666]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:17:22 ag(ag_cluster)[29666]: INFO: lease_expiry after monitor update: >Jul 14 17:17:22 ag(ag_cluster)[29666]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:17:22 ag(ag_cluster)[29666]: INFO: ag_cluster monitor : 8 >Jul 14 17:17:22 ag(ag_cluster)[29893]: INFO: mssql_validate >Jul 14 17:17:22 ag(ag_cluster)[29893]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:22 ag(ag_cluster)[29893]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:22 ag(ag_cluster)[29893]: INFO: Resource agent invoked with: notify >Jul 14 17:17:22 ag(ag_cluster)[29893]: INFO: mssql_notify post-start >Jul 14 17:17:22 ag(ag_cluster)[29893]: INFO: ag_cluster notify : 0 >Jul 14 17:17:27 ag(ag_cluster)[29983]: INFO: mssql_validate >Jul 14 17:17:27 ag(ag_cluster)[29983]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:27 ag(ag_cluster)[29983]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:27 ag(ag_cluster)[29983]: INFO: Resource agent invoked with: notify >Jul 14 17:17:27 ag(ag_cluster)[29983]: INFO: mssql_notify pre-stop >Jul 14 17:17:27 ag(ag_cluster)[29983]: INFO: ag_cluster notify : 0 >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: mssql_validate >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: Resource agent invoked with: monitor >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: mssql_monitor >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17: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] >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:33 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:33 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:17:33 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:33 Connected to the instance at localhost:1433 >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Monitor Caller is: monitor. >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Replica is PRIMARY (1) >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Instance name is server2. >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Current master is server2. >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 There is a configuration commit in progress since 2023-07-14 17:16:25.633 -0400 EDT. Not renewing lease. >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Offlining replica... >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Replica is RESOLVING (0) >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 DB_FAILOVER is ON. >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: 2023/07/14 17:17:38 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: lease_expiry after monitor update: >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:17:38 ag(ag_cluster)[30029]: INFO: ag_cluster monitor : 8 >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: mssql_validate >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: Resource agent invoked with: notify >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: mssql_notify post-stop >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: notify: 2023/07/14 17:17:38 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: notify: 2023/07/14 17:17:38 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: notify: 2023/07/14 17:17:38 Replica is RESOLVING (0) >Jul 14 17:17:38 ag(ag_cluster)[30275]: INFO: ag_cluster notify : 0 >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: mssql_validate >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: Resource agent invoked with: monitor >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: mssql_monitor >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17: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] >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:49 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:49 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:17:49 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:49 Connected to the instance at localhost:1433 >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 Monitor Caller is: monitor. >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 Replica is RESOLVING (0) >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 Instance name is server2. >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 Current master is server2. >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 test - Role is %!s(ag.Role=0). >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 test - Instance name is server2. >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: monitor: 2023/07/14 17:17:54 test - Current master is server2. >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: lease_expiry after monitor update: >Jul 14 17:17:54 ag(ag_cluster)[30394]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:17:55 ag(ag_cluster)[30394]: INFO: ag_cluster monitor : 1 >Jul 14 17:17:55 ag(ag_cluster)[30561]: INFO: mssql_validate >Jul 14 17:17:55 ag(ag_cluster)[30561]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:55 ag(ag_cluster)[30561]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:55 ag(ag_cluster)[30561]: INFO: Resource agent invoked with: notify >Jul 14 17:17:55 ag(ag_cluster)[30561]: INFO: mssql_notify pre-demote >Jul 14 17:17:55 IPaddr2(virtualip)[30560]: INFO: IP status = ok, IP_CIP= >Jul 14 17:17:55 ag(ag_cluster)[30561]: INFO: ag_cluster notify : 0 >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: mssql_validate >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: Resource agent invoked with: demote >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: mssql_demote >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: demote: 2023/07/14 17:17:55 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-demote]; connection-timeout [30]; health-threshold [3]; action [demote] >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: demote: 2023/07/14 17:17:55 [DEBUG] AG Helper Demote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: demote: 2023/07/14 17:17:55 Replica is RESOLVING (0) >Jul 14 17:17:55 ag(ag_cluster)[30659]: INFO: ag_cluster demote : 0 >Jul 14 17:17:55 ag(ag_cluster)[30752]: INFO: mssql_validate >Jul 14 17:17:55 ag(ag_cluster)[30752]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:55 ag(ag_cluster)[30752]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:55 ag(ag_cluster)[30752]: INFO: Resource agent invoked with: notify >Jul 14 17:17:55 ag(ag_cluster)[30752]: INFO: mssql_notify post-demote >Jul 14 17:17:55 ag(ag_cluster)[30752]: INFO: ag_cluster notify : 0 >Jul 14 17:17:55 ag(ag_cluster)[30797]: INFO: mssql_validate >Jul 14 17:17:55 ag(ag_cluster)[30797]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:55 ag(ag_cluster)[30797]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:17:55 ag(ag_cluster)[30797]: INFO: Resource agent invoked with: notify >Jul 14 17:17:55 ag(ag_cluster)[30797]: INFO: mssql_notify pre-stop >Jul 14 17:17:55 ag(ag_cluster)[30797]: INFO: ag_cluster notify : 0 >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: mssql_validate >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: Resource agent invoked with: stop >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: mssql_stop >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: stop: 2023/07/14 17:17:55 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-stop]; connection-timeout [30]; health-threshold [3]; action [stop] >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: stop: 2023/07/14 17:17:55 [DEBUG] AG Helper Stop Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: stop: 2023/07/14 17:17:55 Replica is RESOLVING (0) >Jul 14 17:17:55 ag(ag_cluster)[30842]: INFO: ag_cluster stop : 0 >Jul 14 17:18:22 ag(ag_cluster)[30927]: INFO: mssql_validate >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: Resource agent invoked with: start >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: mssql_start >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:23 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-start]; connection-timeout [30]; health-threshold [3]; action [start] >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:23 ag-helper invoked with sequence-numbers [...]; required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:23 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:18:23 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:23 Connected to the instance at localhost:1433 >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 [DEBUG] AG Helper Start Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Replica is RESOLVING (0) >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Sequence number is 301F:1 (52909702119425) >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Line does not match expected syntax. Ignoring. >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Sequence number line [name="ag_cluster-sequence-number" host="server2" value=""] >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Line does not match expected syntax. Ignoring. >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 1 sequence numbers were found >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Max sequence number is 17F:F (1644972474383) >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Monitor Caller is: start. >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Replica is RESOLVING (0) >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Instance name is server2. >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: 2023/07/14 17:18:28 Current master is . >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: start: PROMOTION_SCORE: 10 >Jul 14 17:18:28 ag(ag_cluster)[30927]: INFO: ag_cluster start : 0 >Jul 14 17:18:28 ag(ag_cluster)[31126]: INFO: mssql_validate >Jul 14 17:18:28 ag(ag_cluster)[31126]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:28 ag(ag_cluster)[31126]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:28 ag(ag_cluster)[31126]: INFO: Resource agent invoked with: notify >Jul 14 17:18:28 ag(ag_cluster)[31126]: INFO: mssql_notify post-start >Jul 14 17:18:28 ag(ag_cluster)[31126]: INFO: ag_cluster notify : 0 >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: mssql_validate >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: Resource agent invoked with: notify >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: mssql_notify pre-start >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: notify: 2023/07/14 17:18:28 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: notify: 2023/07/14 17:18:28 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: notify: 2023/07/14 17:18:28 Replica is RESOLVING (0) >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: notify: 2023/07/14 17:18:28 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: notify: 2023/07/14 17:18:28 Sequence number is 301F:1 (52909702119425) >Jul 14 17:18:28 ag(ag_cluster)[31172]: INFO: notify: SEQUENCE_NUMBER: 52909702119425 >Jul 14 17:18:33 ag(ag_cluster)[31172]: INFO: ag_cluster notify : 0 >Jul 14 17:18:33 ag(ag_cluster)[31272]: INFO: mssql_validate >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: Resource agent invoked with: notify >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: mssql_notify pre-start >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: notify: 2023/07/14 17:18:34 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: notify: 2023/07/14 17:18:34 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: notify: 2023/07/14 17:18:34 Replica is RESOLVING (0) >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: notify: 2023/07/14 17:18:34 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: notify: 2023/07/14 17:18:34 Sequence number is 301F:1 (52909702119425) >Jul 14 17:18:34 ag(ag_cluster)[31272]: INFO: notify: SEQUENCE_NUMBER: 52909702119425 >Jul 14 17:18:39 ag(ag_cluster)[31272]: INFO: ag_cluster notify : 0 >Jul 14 17:18:39 ag(ag_cluster)[31385]: INFO: mssql_validate >Jul 14 17:18:39 ag(ag_cluster)[31385]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:39 ag(ag_cluster)[31385]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:39 ag(ag_cluster)[31385]: INFO: Resource agent invoked with: notify >Jul 14 17:18:39 ag(ag_cluster)[31385]: INFO: mssql_notify post-start >Jul 14 17:18:39 ag(ag_cluster)[31385]: INFO: ag_cluster notify : 0 >Jul 14 17:18:39 ag(ag_cluster)[31431]: INFO: mssql_validate >Jul 14 17:18:39 ag(ag_cluster)[31431]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:39 ag(ag_cluster)[31431]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:39 ag(ag_cluster)[31431]: INFO: Resource agent invoked with: notify >Jul 14 17:18:39 ag(ag_cluster)[31431]: INFO: mssql_notify pre-stop >Jul 14 17:18:39 ag(ag_cluster)[31431]: INFO: ag_cluster notify : 0 >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: mssql_validate >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: Resource agent invoked with: notify >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: mssql_notify post-stop >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: notify: 2023/07/14 17:18:39 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: notify: 2023/07/14 17:18:39 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: notify: 2023/07/14 17:18:39 Replica is RESOLVING (0) >Jul 14 17:18:39 ag(ag_cluster)[31476]: INFO: ag_cluster notify : 0 >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: mssql_validate >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: Resource agent invoked with: notify >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: mssql_notify pre-promote >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: notify: 2023/07/14 17:18:39 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: notify: 2023/07/14 17:18:39 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:18:39 ag(ag_cluster)[31552]: INFO: notify: 2023/07/14 17:18:39 Connected to the instance at localhost:1433 >Jul 14 17:18:44 ag(ag_cluster)[31552]: INFO: notify: 2023/07/14 17:18:44 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:18:45 ag(ag_cluster)[31552]: INFO: notify: 2023/07/14 17:18:44 Sequence number is 301F:1 (52909702119425) >Jul 14 17:18:45 ag(ag_cluster)[31552]: INFO: notify: SEQUENCE_NUMBER: 52909702119425 >Jul 14 17:18:50 ag(ag_cluster)[31552]: INFO: ag_cluster notify : 0 >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: mssql_validate >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: Resource agent invoked with: notify >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: mssql_notify pre-promote >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: notify: 2023/07/14 17:18:50 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: notify: 2023/07/14 17:18:50 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:18:50 ag(ag_cluster)[31657]: INFO: notify: 2023/07/14 17:18:50 Connected to the instance at localhost:1433 >Jul 14 17:18:55 ag(ag_cluster)[31657]: INFO: notify: 2023/07/14 17:18:55 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:18:55 ag(ag_cluster)[31657]: INFO: notify: 2023/07/14 17:18:55 Sequence number is 301F:1 (52909702119425) >Jul 14 17:18:55 ag(ag_cluster)[31657]: INFO: notify: SEQUENCE_NUMBER: 52909702119425 >Jul 14 17:19:00 ag(ag_cluster)[31657]: INFO: ag_cluster notify : 0 >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: mssql_validate >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: Resource agent invoked with: promote >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: mssql_promote >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:00 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-promote]; connection-timeout [30]; health-threshold [3]; action [promote] >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:00 ag-helper invoked with skip-precheck [false]; sequence-numbers [...]; new-master [server2]; required-synchronized-secondaries-to-commit [-1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:00 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:19:00 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:00 Connected to the instance at localhost:1433 >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Replica is RESOLVING (0) >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Line does not match expected syntax. Ignoring. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Sequence number line [name="ag_cluster-sequence-number" host="server2" value="52909702119425"] >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 2 sequence numbers were found >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Max sequence number is 301F:1 (52909702119425) >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Sequence number of server2 is 301F:1 (52909702119425) >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 AG has 3 SYNCHRONOUS_COMMIT or CONFIGURATION_ONLY replicas. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 [DEBUG] Promote info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Promoting replica to PRIMARY role... >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Replica is PRIMARY (1) >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Replica is now PRIMARY >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Monitor Caller is: promote. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Replica is PRIMARY (1) >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Instance name is server2. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Current master is server2. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 62 seconds >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 DB_FAILOVER is ON. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: 2023/07/14 17:19:05 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:05 ag(ag_cluster)[31760]: INFO: promote: PROMOTION_SCORE: 20 >Jul 14 17:19:06 ag(ag_cluster)[31760]: INFO: ag_cluster promote : 0 >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: mssql_validate >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: Resource agent invoked with: notify >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: mssql_notify post-promote >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: notify: 2023/07/14 17:19:06 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-promote]; connection-timeout [30]; health-threshold [3]; action [post-promote] >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: notify: 2023/07/14 17:19:06 [DEBUG] AG Helper PostPromote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: notify: 2023/07/14 17:19:06 Replica is PRIMARY (1) >Jul 14 17:19:06 ag(ag_cluster)[32032]: INFO: ag_cluster notify : 0 >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: mssql_validate >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: Resource agent invoked with: monitor >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: mssql_monitor >Jul 14 17:19:06 IPaddr2(virtualip)[32124]: INFO: Adding inet address 192.168.0.200/24 with broadcast address 192.168.0.255 to device eth0 >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:06 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] >Jul 14 17:19:06 IPaddr2(virtualip)[32124]: INFO: Bringing device eth0 up >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:06 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:06 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:19:06 IPaddr2(virtualip)[32124]: INFO: /usr/libexec/heartbeat/send_arp -i 200 -r 5 -p /run/resource-agents/send_arp-192.168.0.200 eth0 192.168.0.200 auto not_used not_used >Jul 14 17:19:06 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:06 Connected to the instance at localhost:1433 >Jul 14 17:19:10 IPaddr2(virtualip)[32124]: INFO: ARPING 192.168.0.200 from 192.168.0.200 eth0 >Sent 5 probes (5 broadcast(s)) >Received 0 response(s) >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 Monitor Caller is: monitor. >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 Replica is PRIMARY (1) >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 Instance name is server2. >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 Current master is server2. >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 DB_FAILOVER is ON. >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: 2023/07/14 17:19:11 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: lease_expiry after monitor update: >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:19:11 ag(ag_cluster)[32108]: INFO: ag_cluster monitor : 8 >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: mssql_validate >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: Resource agent invoked with: monitor >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: mssql_monitor >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:22 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] >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:22 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:22 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:19:22 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:22 Connected to the instance at localhost:1433 >Jul 14 17:19:27 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 Monitor Caller is: monitor. >Jul 14 17:19:27 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:19:27 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 Replica is PRIMARY (1) >Jul 14 17:19:27 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 Instance name is server2. >Jul 14 17:19:27 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 Current master is server2. >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 DB_FAILOVER is ON. >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: monitor: 2023/07/14 17:19:27 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: lease_expiry after monitor update: >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:19:28 ag(ag_cluster)[32421]: INFO: ag_cluster monitor : 8 >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: mssql_validate >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: Resource agent invoked with: monitor >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: mssql_monitor >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19: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] >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:39 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:39 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:19:39 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:39 Connected to the instance at localhost:1433 >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 Monitor Caller is: monitor. >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 Replica is PRIMARY (1) >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 Instance name is server2. >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 Current master is server2. >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 DB_FAILOVER is ON. >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: 2023/07/14 17:19:44 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: lease_expiry after monitor update: >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:19:44 ag(ag_cluster)[32707]: INFO: ag_cluster monitor : 8 >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: mssql_validate >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: Resource agent invoked with: notify >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: mssql_notify pre-start >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 Replica is PRIMARY (1) >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:19:44 ag(ag_cluster)[32893]: INFO: notify: 2023/07/14 17:19:44 Sequence number is 3020:1 (52913997086721) >Jul 14 17:19:45 ag(ag_cluster)[32893]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:19:50 ag(ag_cluster)[32893]: INFO: ag_cluster notify : 0 >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: mssql_validate >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: Resource agent invoked with: notify >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: mssql_notify pre-start >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 Replica is PRIMARY (1) >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: 2023/07/14 17:19:50 Sequence number is 3020:1 (52913997086721) >Jul 14 17:19:50 ag(ag_cluster)[33046]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:19:55 ag(ag_cluster)[33046]: INFO: ag_cluster notify : 0 >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: mssql_validate >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: Resource agent invoked with: monitor >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: mssql_monitor >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:19: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] >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:19:55 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:19:55 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:19:55 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:19:55 Connected to the instance at localhost:1433 >Jul 14 17:20:00 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 Monitor Caller is: monitor. >Jul 14 17:20:00 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 Replica is PRIMARY (1) >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 Instance name is server2. >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 Current master is server2. >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 [DEBUG] Lease is in the process of being renewed for AVAILABILITY GROUP ag1 for 73 seconds >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 WARNING (Ignore this if External Lease is not used) : The AG does not allow updating external write lease. Not updating the external write lease. Recreate the AG with the WRITE_LEASE_VALIDITY option in the CREATE AVAILABILITY GROUP DDL. >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 DB_FAILOVER is ON. >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: 2023/07/14 17:20:00 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: lease_expiry after monitor update: >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:20:01 ag(ag_cluster)[33157]: INFO: ag_cluster monitor : 8 >Jul 14 17:20:02 ag(ag_cluster)[33384]: INFO: mssql_validate >Jul 14 17:20:02 ag(ag_cluster)[33384]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:02 ag(ag_cluster)[33384]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:02 ag(ag_cluster)[33384]: INFO: Resource agent invoked with: notify >Jul 14 17:20:02 ag(ag_cluster)[33384]: INFO: mssql_notify post-start >Jul 14 17:20:02 ag(ag_cluster)[33384]: INFO: ag_cluster notify : 0 >Jul 14 17:20:02 ag(ag_cluster)[33430]: INFO: mssql_validate >Jul 14 17:20:02 ag(ag_cluster)[33430]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:02 ag(ag_cluster)[33430]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:02 ag(ag_cluster)[33430]: INFO: Resource agent invoked with: notify >Jul 14 17:20:02 ag(ag_cluster)[33430]: INFO: mssql_notify pre-stop >Jul 14 17:20:02 ag(ag_cluster)[33430]: INFO: ag_cluster notify : 0 >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: mssql_validate >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: Resource agent invoked with: notify >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: mssql_notify post-stop >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: notify: 2023/07/14 17:20:02 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: notify: 2023/07/14 17:20:02 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: notify: 2023/07/14 17:20:02 Replica is PRIMARY (1) >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: notify: 2023/07/14 17:20:02 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: notify: 2023/07/14 17:20:02 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:20:02 ag(ag_cluster)[33475]: INFO: ag_cluster notify : 0 >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: mssql_validate >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: Resource agent invoked with: monitor >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: mssql_monitor >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20: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] >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:12 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:12 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:20:12 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:12 Connected to the instance at localhost:1433 >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Monitor Caller is: monitor. >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Replica is PRIMARY (1) >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Instance name is server2. >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Current master is server2. >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 There is a configuration commit in progress since 2023-07-14 17:19:05.923 -0400 EDT. Not renewing lease. >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Offlining replica... >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Replica is RESOLVING (0) >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 DB_FAILOVER is ON. >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 AG has 3 SYNCHRONOUS_COMMIT replicas. >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: 2023/07/14 17:20:17 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1... >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: monitor: PROMOTION_SCORE: 20 >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: lease_expiry after monitor update: >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:20:17 ag(ag_cluster)[33605]: INFO: ag_cluster monitor : 8 >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: mssql_validate >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: OCF_RESKEY_CRM_meta_interval value: 11000 >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: Resource agent invoked with: monitor >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: mssql_monitor >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20: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] >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:28 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server2]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60] >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:28 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:20:28 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:28 Connected to the instance at localhost:1433 >Jul 14 17:20:33 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 Monitor Caller is: monitor. >Jul 14 17:20:33 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:20:33 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 Replica is RESOLVING (0) >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 Instance name is server2. >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 Current master is server2. >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 test - Role is %!s(ag.Role=0). >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 test - Instance name is server2. >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: monitor: 2023/07/14 17:20:33 test - Current master is server2. >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: lease_expiry after monitor update: >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: lease information from all replicas after monitor update: name="ag_cluster-lease-expiry" host="server1" value="" >name="ag_cluster-lease-expiry" host="server3" value="" >name="ag_cluster-lease-expiry" host="server2" value="" >Jul 14 17:20:34 ag(ag_cluster)[33884]: INFO: ag_cluster monitor : 1 >Jul 14 17:20:34 ag(ag_cluster)[34054]: INFO: mssql_validate >Jul 14 17:20:34 ag(ag_cluster)[34054]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:34 ag(ag_cluster)[34054]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:34 IPaddr2(virtualip)[34053]: INFO: IP status = ok, IP_CIP= >Jul 14 17:20:34 ag(ag_cluster)[34054]: INFO: Resource agent invoked with: notify >Jul 14 17:20:34 ag(ag_cluster)[34054]: INFO: mssql_notify pre-demote >Jul 14 17:20:34 ag(ag_cluster)[34054]: INFO: ag_cluster notify : 0 >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: mssql_validate >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: Resource agent invoked with: demote >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: mssql_demote >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: demote: 2023/07/14 17:20:34 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-demote]; connection-timeout [30]; health-threshold [3]; action [demote] >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: demote: 2023/07/14 17:20:34 [DEBUG] AG Helper Demote Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: demote: 2023/07/14 17:20:34 Replica is RESOLVING (0) >Jul 14 17:20:34 ag(ag_cluster)[34152]: INFO: ag_cluster demote : 0 >Jul 14 17:20:34 ag(ag_cluster)[34245]: INFO: mssql_validate >Jul 14 17:20:34 ag(ag_cluster)[34245]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:34 ag(ag_cluster)[34245]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:34 ag(ag_cluster)[34245]: INFO: Resource agent invoked with: notify >Jul 14 17:20:34 ag(ag_cluster)[34245]: INFO: mssql_notify post-demote >Jul 14 17:20:34 ag(ag_cluster)[34245]: INFO: ag_cluster notify : 0 >Jul 14 17:20:34 ag(ag_cluster)[34290]: INFO: mssql_validate >Jul 14 17:20:34 ag(ag_cluster)[34290]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:34 ag(ag_cluster)[34290]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:34 ag(ag_cluster)[34290]: INFO: Resource agent invoked with: notify >Jul 14 17:20:34 ag(ag_cluster)[34290]: INFO: mssql_notify pre-stop >Jul 14 17:20:34 ag(ag_cluster)[34290]: INFO: ag_cluster notify : 0 >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: mssql_validate >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: OCF_RESKEY_CRM_meta_timeout value: 10000 >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: Resource agent invoked with: stop >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: mssql_stop >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: stop: 2023/07/14 17:20:34 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-stop]; connection-timeout [30]; health-threshold [3]; action [stop] >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: stop: 2023/07/14 17:20:34 [DEBUG] AG Helper Stop Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: stop: 2023/07/14 17:20:34 Replica is RESOLVING (0) >Jul 14 17:20:34 ag(ag_cluster)[34335]: INFO: ag_cluster stop : 0 >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: mssql_validate >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: Resource agent invoked with: start >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: mssql_start >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:20:56 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-start]; connection-timeout [30]; health-threshold [3]; action [start] >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:20:56 ag-helper invoked with sequence-numbers [...]; required-synchronized-secondaries-to-commit [-1]; current-master []; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:20:56 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:20:56 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:20:56 Connected to the instance at localhost:1433 >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 [DEBUG] AG Helper Start Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Replica is RESOLVING (0) >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Sequence number is 3020:1 (52913997086721) >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Verifying replica's sequence number vs all sequence numbers... >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""] >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Line does not match expected syntax. Ignoring. >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"] >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Sequence number line [name="ag_cluster-sequence-number" host="server2" value=""] >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Line does not match expected syntax. Ignoring. >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 1 sequence numbers were found >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Max sequence number is 17F:F (1644972474383) >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Monitor Caller is: start. >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server2 >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Replica is RESOLVING (0) >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Instance name is server2. >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: 2023/07/14 17:21:01 Current master is . >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: start: PROMOTION_SCORE: 10 >Jul 14 17:21:01 ag(ag_cluster)[34436]: INFO: ag_cluster start : 0 >Jul 14 17:21:01 ag(ag_cluster)[34634]: INFO: mssql_validate >Jul 14 17:21:01 ag(ag_cluster)[34634]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:01 ag(ag_cluster)[34634]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:01 ag(ag_cluster)[34634]: INFO: Resource agent invoked with: notify >Jul 14 17:21:01 ag(ag_cluster)[34634]: INFO: mssql_notify post-start >Jul 14 17:21:01 ag(ag_cluster)[34634]: INFO: ag_cluster notify : 0 >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: mssql_validate >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: Resource agent invoked with: notify >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: mssql_notify pre-promote >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: notify: 2023/07/14 17:21:02 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: notify: 2023/07/14 17:21:02 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:21:02 ag(ag_cluster)[34680]: INFO: notify: 2023/07/14 17:21:02 Connected to the instance at localhost:1433 >Jul 14 17:21:07 ag(ag_cluster)[34680]: INFO: notify: 2023/07/14 17:21:07 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:21:07 ag(ag_cluster)[34680]: INFO: notify: 2023/07/14 17:21:07 Sequence number is 3020:1 (52913997086721) >Jul 14 17:21:07 ag(ag_cluster)[34680]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:21:12 ag(ag_cluster)[34680]: INFO: ag_cluster notify : 0 >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: mssql_validate >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: Resource agent invoked with: notify >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: mssql_notify pre-start >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: notify: 2023/07/14 17:21:12 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: notify: 2023/07/14 17:21:12 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: notify: 2023/07/14 17:21:12 Replica is RESOLVING (0) >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: notify: 2023/07/14 17:21:12 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: notify: 2023/07/14 17:21:12 Sequence number is 3020:1 (52913997086721) >Jul 14 17:21:12 ag(ag_cluster)[34785]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:21:17 ag(ag_cluster)[34785]: INFO: ag_cluster notify : 0 >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: mssql_validate >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: Resource agent invoked with: notify >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: mssql_notify pre-start >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: notify: 2023/07/14 17:21:17 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-start]; connection-timeout [30]; health-threshold [3]; action [pre-start] >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: notify: 2023/07/14 17:21:17 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: notify: 2023/07/14 17:21:17 Replica is RESOLVING (0) >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: notify: 2023/07/14 17:21:17 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: notify: 2023/07/14 17:21:17 Sequence number is 3020:1 (52913997086721) >Jul 14 17:21:17 ag(ag_cluster)[34884]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:21:22 ag(ag_cluster)[34884]: INFO: ag_cluster notify : 0 >Jul 14 17:21:22 ag(ag_cluster)[34985]: INFO: mssql_validate >Jul 14 17:21:22 ag(ag_cluster)[34985]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:22 ag(ag_cluster)[34985]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:22 ag(ag_cluster)[34985]: INFO: Resource agent invoked with: notify >Jul 14 17:21:22 ag(ag_cluster)[34985]: INFO: mssql_notify post-start >Jul 14 17:21:22 ag(ag_cluster)[34985]: INFO: ag_cluster notify : 0 >Jul 14 17:21:23 ag(ag_cluster)[35031]: INFO: mssql_validate >Jul 14 17:21:23 ag(ag_cluster)[35031]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:23 ag(ag_cluster)[35031]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:23 ag(ag_cluster)[35031]: INFO: Resource agent invoked with: notify >Jul 14 17:21:23 ag(ag_cluster)[35031]: INFO: mssql_notify pre-stop >Jul 14 17:21:23 ag(ag_cluster)[35031]: INFO: ag_cluster notify : 0 >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: mssql_validate >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: Resource agent invoked with: notify >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: mssql_notify post-stop >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: notify: 2023/07/14 17:21:23 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-post-stop]; connection-timeout [30]; health-threshold [3]; action [post-stop] >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: notify: 2023/07/14 17:21:23 ag-helper invoked with required-synchronized-secondaries-to-commit [-1] >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: notify: 2023/07/14 17:21:23 Replica is RESOLVING (0) >Jul 14 17:21:23 ag(ag_cluster)[35076]: INFO: ag_cluster notify : 0 >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: mssql_validate >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: Resource agent invoked with: notify >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: mssql_notify pre-promote >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: notify: 2023/07/14 17:21:23 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: notify: 2023/07/14 17:21:23 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:21:23 ag(ag_cluster)[35151]: INFO: notify: 2023/07/14 17:21:23 Connected to the instance at localhost:1433 >Jul 14 17:21:28 ag(ag_cluster)[35151]: INFO: notify: 2023/07/14 17:21:28 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:21:28 ag(ag_cluster)[35151]: INFO: notify: 2023/07/14 17:21:28 Sequence number is 3020:1 (52913997086721) >Jul 14 17:21:28 ag(ag_cluster)[35151]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:21:33 ag(ag_cluster)[35151]: INFO: ag_cluster notify : 0 >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: mssql_validate >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: Resource agent invoked with: notify >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: mssql_notify pre-promote >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: notify: 2023/07/14 17:21:33 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-pre-promote]; connection-timeout [30]; health-threshold [3]; action [pre-promote] >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: notify: 2023/07/14 17:21:33 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:21:33 ag(ag_cluster)[35256]: INFO: notify: 2023/07/14 17:21:33 Connected to the instance at localhost:1433 >Jul 14 17:21:38 ag(ag_cluster)[35256]: INFO: notify: 2023/07/14 17:21:38 Replica is SYNCHRONOUS_COMMIT (1). >Jul 14 17:21:38 ag(ag_cluster)[35256]: INFO: notify: 2023/07/14 17:21:38 Sequence number is 3020:1 (52913997086721) >Jul 14 17:21:38 ag(ag_cluster)[35256]: INFO: notify: SEQUENCE_NUMBER: 52913997086721 >Jul 14 17:21:43 ag(ag_cluster)[35256]: INFO: ag_cluster notify : 0 >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: mssql_validate >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: OCF_RESKEY_CRM_meta_interval value: 0 >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: OCF_RESKEY_CRM_meta_timeout value: 60000 >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: Resource agent invoked with: promote >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: mssql_promote >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: promote: 2023/07/14 17:21:43 ag-helper invoked with hostname [localhost]; port [1433]; ag-name [ag1]; credentials-file [/var/opt/mssql/secrets/passwd]; application-name [monitor-ag_cluster-promote]; connection-timeout [30]; health-threshold [3]; action [promote] >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: promote: 2023/07/14 17:21:43 ag-helper invoked with skip-precheck [false]; sequence-numbers [...]; new-master [server2]; required-synchronized-secondaries-to-commit [-1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [62] >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: promote: 2023/07/14 17:21:43 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433 >Jul 14 17:21:43 ag(ag_cluster)[35374]: INFO: promote: 2023/07/14 17:21:43 Connected to the instance at localhost:1433
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 2221772
:
1976118
| 1976119 |
1976120
|
1976684
|
1976685
|
1976686