Attachment 1976118 Details for Bug 2221772 – Pacemaker logs

Pacemaker logs

pacemaker1.log (text/plain), 40.56 KB, created by Aravind Mahadevan on 2023-07-17 05:21:55 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Aravind Mahadevan

Created: 2023-07-17 05:21:55 UTC

Size: 40.56 KB

patch

obsolete

>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: mssql_validate
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: OCF_RESKEY_CRM_meta_interval value: 11000
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: Resource agent invoked with: monitor
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: mssql_monitor
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06: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:06:13  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:13 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60]
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:13 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433
>Jul 14 17:06:13  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:13 Connected to the instance at localhost:1433
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Monitor Caller is: monitor.
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server1
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Replica is PRIMARY (1)
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Instance name is server1.
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Current master is server1.
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 There is a configuration commit in progress since 2023-07-14 17:05:18.34 -0400 EDT. Not renewing lease.
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Offlining replica...
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Replica is RESOLVING (0)
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 DB_FAILOVER is ON.
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 AG has 3 SYNCHRONOUS_COMMIT replicas.
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: 2023/07/14 17:06:18 Setting REQUIRED_SYNCHRONIZED_SECONDARIES_TO_COMMIT to 1...
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: monitor: PROMOTION_SCORE: 20
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    INFO: lease_expiry after monitor update: 
>Jul 14 17:06:18  ag(ag_cluster)[932924]:    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:06:18  ag(ag_cluster)[932924]:    INFO: ag_cluster monitor : 8
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: mssql_validate
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: OCF_RESKEY_CRM_meta_interval value: 11000
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: Resource agent invoked with: monitor
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: mssql_monitor
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06: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:06:29  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:29 ag-helper invoked with required-synchronized-secondaries-to-commit [-1]; current-master [server1]; disable-primary-on-quorum-timeout-after [60]; primary-write-lease-duration [73]; monitor-interval-timeout [60]
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:29 From RetryExecuteWithTimeout - Attempt 1 to connect to the instance at localhost:1433
>Jul 14 17:06:29  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:29 Connected to the instance at localhost:1433
>Jul 14 17:06:34  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 Monitor Caller is: monitor.
>Jul 14 17:06:34  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server1
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 Replica is RESOLVING (0)
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 Instance name is server1.
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 Current master is server1.
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 test - Role is %!s(ag.Role=0).
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 test - Instance name is server1.
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: monitor: 2023/07/14 17:06:34 test - Current master is server1.
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    INFO: lease_expiry after monitor update: 
>Jul 14 17:06:35  ag(ag_cluster)[933211]:    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:06:35  ag(ag_cluster)[933211]:    INFO: ag_cluster monitor : 1
>Jul 14 17:06:35  ag(ag_cluster)[933387]:    INFO: mssql_validate
>Jul 14 17:06:35  ag(ag_cluster)[933387]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:06:35  ag(ag_cluster)[933387]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:06:35  ag(ag_cluster)[933387]:    INFO: Resource agent invoked with: notify
>Jul 14 17:06:35  IPaddr2(virtualip)[933386]:    INFO: IP status = ok, IP_CIP=
>Jul 14 17:06:35  ag(ag_cluster)[933387]:    INFO: mssql_notify pre-demote
>Jul 14 17:06:35  ag(ag_cluster)[933387]:    INFO: ag_cluster notify : 0
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: mssql_validate
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: Resource agent invoked with: demote
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: mssql_demote
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: demote: 2023/07/14 17:06:39 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:06:39  ag(ag_cluster)[933486]:    INFO: demote: 2023/07/14 17:06:39 [DEBUG] AG Helper Demote Role info: AVAILABILITY GROUP ag1 on instance server1
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: demote: 2023/07/14 17:06:39 Replica is RESOLVING (0)
>Jul 14 17:06:39  ag(ag_cluster)[933486]:    INFO: ag_cluster demote : 0
>Jul 14 17:06:39  ag(ag_cluster)[933579]:    INFO: mssql_validate
>Jul 14 17:06:39  ag(ag_cluster)[933579]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:06:39  ag(ag_cluster)[933579]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:06:39  ag(ag_cluster)[933579]:    INFO: Resource agent invoked with: notify
>Jul 14 17:06:39  ag(ag_cluster)[933579]:    INFO: mssql_notify post-demote
>Jul 14 17:06:39  ag(ag_cluster)[933579]:    INFO: ag_cluster notify : 0
>Jul 14 17:06:44  ag(ag_cluster)[933624]:    INFO: mssql_validate
>Jul 14 17:06:44  ag(ag_cluster)[933624]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:06:44  ag(ag_cluster)[933624]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:06:44  ag(ag_cluster)[933624]:    INFO: Resource agent invoked with: notify
>Jul 14 17:06:44  ag(ag_cluster)[933624]:    INFO: mssql_notify pre-stop
>Jul 14 17:06:44  ag(ag_cluster)[933624]:    INFO: ag_cluster notify : 0
>Jul 14 17:06:51  ag(ag_cluster)[933672]:    INFO: mssql_validate
>Jul 14 17:06:51  ag(ag_cluster)[933672]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:06:51  ag(ag_cluster)[933672]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:06:51  ag(ag_cluster)[933672]:    INFO: Resource agent invoked with: notify
>Jul 14 17:06:51  ag(ag_cluster)[933672]:    INFO: mssql_notify pre-stop
>Jul 14 17:06:51  ag(ag_cluster)[933672]:    INFO: ag_cluster notify : 0
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: mssql_validate
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: Resource agent invoked with: stop
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: mssql_stop
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: stop: 2023/07/14 17:06: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:06:51  ag(ag_cluster)[933717]:    INFO: stop: 2023/07/14 17:06:51 [DEBUG] AG Helper Stop Role info: AVAILABILITY GROUP ag1 on instance server1
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: stop: 2023/07/14 17:06:51 Replica is RESOLVING (0)
>Jul 14 17:06:51  ag(ag_cluster)[933717]:    INFO: ag_cluster stop : 0
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: mssql_validate
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: Resource agent invoked with: start
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: mssql_start
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07: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:07:02  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07: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:07:02  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:02 From RetryExecute - Attempt 1 to connect to the instance at localhost:1433
>Jul 14 17:07:02  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:02 Connected to the instance at localhost:1433
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 [DEBUG] AG Helper Start Role info: AVAILABILITY GROUP ag1 on instance server1
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Replica is RESOLVING (0)
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Sequence number is 301F:1 (52909702119425)
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Verifying replica's sequence number vs all sequence numbers...
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Sequence number line [name="ag_cluster-sequence-number" host="server1" value=""]
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Line does not match expected syntax. Ignoring.
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Sequence number line [name="ag_cluster-sequence-number" host="server3" value="1644972474383"]
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Sequence number line [name="ag_cluster-sequence-number" host="server2" value="52892522250255"]
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 2 sequence numbers were found
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Max sequence number is 301B:F (52892522250255)
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Monitor Caller is: start.
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 [DEBUG] AG Helper Monitor Role info: AVAILABILITY GROUP ag1 on instance server1
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Replica is RESOLVING (0)
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Instance name is server1.
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: 2023/07/14 17:07:07 Current master is .
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: start: PROMOTION_SCORE: 10
>Jul 14 17:07:07  ag(ag_cluster)[933798]:    INFO: ag_cluster start : 0
>Jul 14 17:07:07  ag(ag_cluster)[933991]:    INFO: mssql_validate
>Jul 14 17:07:07  ag(ag_cluster)[933991]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:07  ag(ag_cluster)[933991]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:07  ag(ag_cluster)[933991]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:07  ag(ag_cluster)[933991]:    INFO: mssql_notify post-start
>Jul 14 17:07:07  ag(ag_cluster)[933991]:    INFO: ag_cluster notify : 0
>Jul 14 17:07:12  ag(ag_cluster)[934037]:    INFO: mssql_validate
>Jul 14 17:07:12  ag(ag_cluster)[934037]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:12  ag(ag_cluster)[934037]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:12  ag(ag_cluster)[934037]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:12  ag(ag_cluster)[934037]:    INFO: mssql_notify pre-promote
>Jul 14 17:07:12  ag(ag_cluster)[934037]:    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)[934037]:    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)[934037]:    INFO: notify: 2023/07/14 17:07:12 Connected to the instance at localhost:1433
>Jul 14 17:07:17  ag(ag_cluster)[934037]:    INFO: notify: 2023/07/14 17:07:17 Replica is SYNCHRONOUS_COMMIT (1).
>Jul 14 17:07:17  ag(ag_cluster)[934037]:    INFO: notify: 2023/07/14 17:07:17 Sequence number is 301F:1 (52909702119425)
>Jul 14 17:07:18  ag(ag_cluster)[934037]:    INFO: notify: SEQUENCE_NUMBER: 52909702119425
>Jul 14 17:07:23  ag(ag_cluster)[934037]:    INFO: ag_cluster notify : 0
>Jul 14 17:07:23  ag(ag_cluster)[934147]:    INFO: mssql_validate
>Jul 14 17:07:23  ag(ag_cluster)[934147]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:23  ag(ag_cluster)[934147]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:23  ag(ag_cluster)[934147]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:23  ag(ag_cluster)[934147]:    INFO: mssql_notify pre-promote
>Jul 14 17:07:23  ag(ag_cluster)[934147]:    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)[934147]:    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)[934147]:    INFO: notify: 2023/07/14 17:07:23 Connected to the instance at localhost:1433
>Jul 14 17:07:25  ag(ag_cluster)[934147]:    INFO: notify: 2023/07/14 17:07:25 OpenDBWithHealthCheck failed during pre-promote: Unable to open tcp connection with host 'localhost:1433': dial tcp [::1]:1433: getsockopt: connection refused
>Jul 14 17:07:25  ag(ag_cluster)[934147]:    INFO: notify: ERROR: 2023/07/14 17:07:25 Unexpected error: Unable to open tcp connection with host 'localhost:1433': dial tcp [::1]:1433: getsockopt: connection refused
>Jul 14 17:07:25  ag(ag_cluster)[934147]:    ERROR: 2023/07/14 17:07:25 Unexpected error: Unable to open tcp connection with host 'localhost:1433': dial tcp [::1]:1433: getsockopt: connection refused
>Jul 14 17:07:25  ag(ag_cluster)[934147]:    INFO: ag_cluster notify : 1
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    INFO: mssql_validate
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    INFO: Resource agent invoked with: promote
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    INFO: mssql_promote
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    ERROR: SQL Server isn't running.
>Jul 14 17:07:44  ag(ag_cluster)[934267]:    INFO: ag_cluster promote : 7
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: mssql_validate
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: mssql_notify post-promote
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    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)[934320]:    INFO: notify: 2023/07/14 17:07:44 OpenDB failed during post-promote: Unresponsive or down Unable to open tcp connection with host 'localhost:1433': dial tcp [::1]:1433: getsockopt: connection refused
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: notify: ERROR: 2023/07/14 17:07:44 Could not connect to instance: Unresponsive or down Unable to open tcp connection with host 'localhost:1433': dial tcp [::1]:1433: getsockopt: connection refused
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    ERROR: 2023/07/14 17:07:44 Could not connect to instance: Unresponsive or down Unable to open tcp connection with host 'localhost:1433': dial tcp [::1]:1433: getsockopt: connection refused
>Jul 14 17:07:44  ag(ag_cluster)[934320]:    INFO: ag_cluster notify : 1
>Jul 14 17:07:55  ag(ag_cluster)[934402]:    INFO: mssql_validate
>Jul 14 17:07:55  ag(ag_cluster)[934402]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:55  ag(ag_cluster)[934402]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:55  ag(ag_cluster)[934402]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:55  ag(ag_cluster)[934402]:    INFO: mssql_notify pre-demote
>Jul 14 17:07:55  ag(ag_cluster)[934402]:    INFO: ag_cluster notify : 0
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    INFO: mssql_validate
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    INFO: Resource agent invoked with: demote
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    INFO: mssql_demote
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    ERROR: SQL Server isn't running.
>Jul 14 17:07:55  ag(ag_cluster)[934447]:    INFO: ag_cluster demote : 0
>Jul 14 17:07:55  ag(ag_cluster)[934500]:    INFO: mssql_validate
>Jul 14 17:07:55  ag(ag_cluster)[934500]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:55  ag(ag_cluster)[934500]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:55  ag(ag_cluster)[934500]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:55  ag(ag_cluster)[934500]:    INFO: mssql_notify post-demote
>Jul 14 17:07:55  ag(ag_cluster)[934500]:    INFO: ag_cluster notify : 0
>Jul 14 17:07:55  ag(ag_cluster)[934545]:    INFO: mssql_validate
>Jul 14 17:07:55  ag(ag_cluster)[934545]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:55  ag(ag_cluster)[934545]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:07:55  ag(ag_cluster)[934545]:    INFO: Resource agent invoked with: notify
>Jul 14 17:07:55  ag(ag_cluster)[934545]:    INFO: mssql_notify pre-stop
>Jul 14 17:07:55  ag(ag_cluster)[934545]:    INFO: ag_cluster notify : 0
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    INFO: mssql_validate
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    INFO: Resource agent invoked with: stop
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    INFO: mssql_stop
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    ERROR: SQL Server isn't running.
>Jul 14 17:07:55  ag(ag_cluster)[934590]:    INFO: ag_cluster stop : 0
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    INFO: mssql_validate
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    INFO: Resource agent invoked with: start
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    INFO: mssql_start
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    ERROR: SQL Server isn't running.
>Jul 14 17:08:06  ag(ag_cluster)[934651]:    INFO: ag_cluster start : 1
>Jul 14 17:08:11  ag(ag_cluster)[934705]:    INFO: mssql_validate
>Jul 14 17:08:11  ag(ag_cluster)[934705]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:08:11  ag(ag_cluster)[934705]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:08:11  ag(ag_cluster)[934705]:    INFO: Resource agent invoked with: notify
>Jul 14 17:08:11  ag(ag_cluster)[934705]:    INFO: mssql_notify post-start
>Jul 14 17:08:11  ag(ag_cluster)[934705]:    INFO: ag_cluster notify : 0
>Jul 14 17:08:12  ag(ag_cluster)[934751]:    INFO: mssql_validate
>Jul 14 17:08:12  ag(ag_cluster)[934751]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:08:12  ag(ag_cluster)[934751]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:08:12  ag(ag_cluster)[934751]:    INFO: Resource agent invoked with: notify
>Jul 14 17:08:12  ag(ag_cluster)[934751]:    INFO: mssql_notify pre-stop
>Jul 14 17:08:12  ag(ag_cluster)[934751]:    INFO: ag_cluster notify : 0
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    INFO: mssql_validate
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    INFO: Resource agent invoked with: stop
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    INFO: mssql_stop
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    ERROR: SQL Server isn't running.
>Jul 14 17:08:12  ag(ag_cluster)[934796]:    INFO: ag_cluster stop : 0
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    INFO: mssql_validate
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    INFO: Resource agent invoked with: start
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    INFO: mssql_start
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    ERROR: SQL Server isn't running.
>Jul 14 17:09:23  ag(ag_cluster)[934904]:    INFO: ag_cluster start : 1
>Jul 14 17:09:23  ag(ag_cluster)[934958]:    INFO: mssql_validate
>Jul 14 17:09:23  ag(ag_cluster)[934958]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:09:23  ag(ag_cluster)[934958]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:09:23  ag(ag_cluster)[934958]:    INFO: Resource agent invoked with: notify
>Jul 14 17:09:23  ag(ag_cluster)[934958]:    INFO: mssql_notify post-start
>Jul 14 17:09:23  ag(ag_cluster)[934958]:    INFO: ag_cluster notify : 0
>Jul 14 17:09:28  ag(ag_cluster)[935004]:    INFO: mssql_validate
>Jul 14 17:09:28  ag(ag_cluster)[935004]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:09:28  ag(ag_cluster)[935004]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:09:28  ag(ag_cluster)[935004]:    INFO: Resource agent invoked with: notify
>Jul 14 17:09:28  ag(ag_cluster)[935004]:    INFO: mssql_notify pre-stop
>Jul 14 17:09:28  ag(ag_cluster)[935004]:    INFO: ag_cluster notify : 0
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    INFO: mssql_validate
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    INFO: Resource agent invoked with: stop
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    INFO: mssql_stop
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    ERROR: SQL Server isn't running.
>Jul 14 17:09:29  ag(ag_cluster)[935049]:    INFO: ag_cluster stop : 0
>Jul 14 17:10:40  ag(ag_cluster)[935128]:    INFO: mssql_validate
>Jul 14 17:10:40  ag(ag_cluster)[935128]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:10:40  ag(ag_cluster)[935128]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:10:40  ag(ag_cluster)[935128]:    INFO: Resource agent invoked with: start
>Jul 14 17:10:40  ag(ag_cluster)[935128]:    INFO: mssql_start
>Jul 14 17:10:41  ag(ag_cluster)[935128]:    ERROR: SQL Server isn't running.
>Jul 14 17:10:41  ag(ag_cluster)[935128]:    INFO: ag_cluster start : 1
>Jul 14 17:10:46  ag(ag_cluster)[935183]:    INFO: mssql_validate
>Jul 14 17:10:46  ag(ag_cluster)[935183]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:10:46  ag(ag_cluster)[935183]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:10:46  ag(ag_cluster)[935183]:    INFO: Resource agent invoked with: notify
>Jul 14 17:10:46  ag(ag_cluster)[935183]:    INFO: mssql_notify post-start
>Jul 14 17:10:46  ag(ag_cluster)[935183]:    INFO: ag_cluster notify : 0
>Jul 14 17:10:46  ag(ag_cluster)[935229]:    INFO: mssql_validate
>Jul 14 17:10:46  ag(ag_cluster)[935229]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:10:46  ag(ag_cluster)[935229]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:10:46  ag(ag_cluster)[935229]:    INFO: Resource agent invoked with: notify
>Jul 14 17:10:46  ag(ag_cluster)[935229]:    INFO: mssql_notify pre-stop
>Jul 14 17:10:46  ag(ag_cluster)[935229]:    INFO: ag_cluster notify : 0
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    INFO: mssql_validate
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    INFO: Resource agent invoked with: stop
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    INFO: mssql_stop
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    ERROR: SQL Server isn't running.
>Jul 14 17:10:46  ag(ag_cluster)[935274]:    INFO: ag_cluster stop : 0
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    INFO: mssql_validate
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    INFO: Resource agent invoked with: start
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    INFO: mssql_start
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    ERROR: SQL Server isn't running.
>Jul 14 17:11:58  ag(ag_cluster)[935405]:    INFO: ag_cluster start : 1
>Jul 14 17:11:58  ag(ag_cluster)[935459]:    INFO: mssql_validate
>Jul 14 17:11:58  ag(ag_cluster)[935459]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:11:58  ag(ag_cluster)[935459]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:11:58  ag(ag_cluster)[935459]:    INFO: Resource agent invoked with: notify
>Jul 14 17:11:58  ag(ag_cluster)[935459]:    INFO: mssql_notify post-start
>Jul 14 17:11:58  ag(ag_cluster)[935459]:    INFO: ag_cluster notify : 0
>Jul 14 17:12:04  ag(ag_cluster)[935505]:    INFO: mssql_validate
>Jul 14 17:12:04  ag(ag_cluster)[935505]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:12:04  ag(ag_cluster)[935505]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:12:04  ag(ag_cluster)[935505]:    INFO: Resource agent invoked with: notify
>Jul 14 17:12:04  ag(ag_cluster)[935505]:    INFO: mssql_notify pre-stop
>Jul 14 17:12:04  ag(ag_cluster)[935505]:    INFO: ag_cluster notify : 0
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    INFO: mssql_validate
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    INFO: Resource agent invoked with: stop
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    INFO: mssql_stop
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    ERROR: SQL Server isn't running.
>Jul 14 17:12:04  ag(ag_cluster)[935550]:    INFO: ag_cluster stop : 0
>Jul 14 17:13:18  ag(ag_cluster)[935627]:    INFO: mssql_validate
>Jul 14 17:13:19  ag(ag_cluster)[935627]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:13:19  ag(ag_cluster)[935627]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:13:19  ag(ag_cluster)[935627]:    INFO: Resource agent invoked with: start
>Jul 14 17:13:19  ag(ag_cluster)[935627]:    INFO: mssql_start
>Jul 14 17:13:19  ag(ag_cluster)[935627]:    ERROR: SQL Server isn't running.
>Jul 14 17:13:19  ag(ag_cluster)[935627]:    INFO: ag_cluster start : 1
>Jul 14 17:13:19  ag(ag_cluster)[935681]:    INFO: mssql_validate
>Jul 14 17:13:19  ag(ag_cluster)[935681]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:13:19  ag(ag_cluster)[935681]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:13:19  ag(ag_cluster)[935681]:    INFO: Resource agent invoked with: notify
>Jul 14 17:13:19  ag(ag_cluster)[935681]:    INFO: mssql_notify post-start
>Jul 14 17:13:19  ag(ag_cluster)[935681]:    INFO: ag_cluster notify : 0
>Jul 14 17:13:19  ag(ag_cluster)[935727]:    INFO: mssql_validate
>Jul 14 17:13:19  ag(ag_cluster)[935727]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:13:19  ag(ag_cluster)[935727]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:13:19  ag(ag_cluster)[935727]:    INFO: Resource agent invoked with: notify
>Jul 14 17:13:19  ag(ag_cluster)[935727]:    INFO: mssql_notify pre-stop
>Jul 14 17:13:19  ag(ag_cluster)[935727]:    INFO: ag_cluster notify : 0
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    INFO: mssql_validate
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    INFO: Resource agent invoked with: stop
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    INFO: mssql_stop
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    ERROR: SQL Server isn't running.
>Jul 14 17:13:19  ag(ag_cluster)[935772]:    INFO: ag_cluster stop : 0
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    INFO: mssql_validate
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    INFO: Resource agent invoked with: start
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    INFO: mssql_start
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    ERROR: SQL Server isn't running.
>Jul 14 17:14:42  ag(ag_cluster)[935852]:    INFO: ag_cluster start : 1
>Jul 14 17:14:42  ag(ag_cluster)[935906]:    INFO: mssql_validate
>Jul 14 17:14:42  ag(ag_cluster)[935906]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:14:42  ag(ag_cluster)[935906]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:14:42  ag(ag_cluster)[935906]:    INFO: Resource agent invoked with: notify
>Jul 14 17:14:42  ag(ag_cluster)[935906]:    INFO: mssql_notify post-start
>Jul 14 17:14:42  ag(ag_cluster)[935906]:    INFO: ag_cluster notify : 0
>Jul 14 17:14:47  ag(ag_cluster)[935952]:    INFO: mssql_validate
>Jul 14 17:14:47  ag(ag_cluster)[935952]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:14:47  ag(ag_cluster)[935952]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:14:47  ag(ag_cluster)[935952]:    INFO: Resource agent invoked with: notify
>Jul 14 17:14:47  ag(ag_cluster)[935952]:    INFO: mssql_notify pre-stop
>Jul 14 17:14:47  ag(ag_cluster)[935952]:    INFO: ag_cluster notify : 0
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    INFO: mssql_validate
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    INFO: Resource agent invoked with: stop
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    INFO: mssql_stop
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    ERROR: SQL Server isn't running.
>Jul 14 17:14:53  ag(ag_cluster)[935997]:    INFO: ag_cluster stop : 0
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    INFO: mssql_validate
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    INFO: Resource agent invoked with: start
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    INFO: mssql_start
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    ERROR: SQL Server isn't running.
>Jul 14 17:15:59  ag(ag_cluster)[936068]:    INFO: ag_cluster start : 1
>Jul 14 17:15:59  ag(ag_cluster)[936122]:    INFO: mssql_validate
>Jul 14 17:15:59  ag(ag_cluster)[936122]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:15:59  ag(ag_cluster)[936122]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:15:59  ag(ag_cluster)[936122]:    INFO: Resource agent invoked with: notify
>Jul 14 17:15:59  ag(ag_cluster)[936122]:    INFO: mssql_notify post-start
>Jul 14 17:15:59  ag(ag_cluster)[936122]:    INFO: ag_cluster notify : 0
>Jul 14 17:15:59  ag(ag_cluster)[936168]:    INFO: mssql_validate
>Jul 14 17:15:59  ag(ag_cluster)[936168]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:15:59  ag(ag_cluster)[936168]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:15:59  ag(ag_cluster)[936168]:    INFO: Resource agent invoked with: notify
>Jul 14 17:15:59  ag(ag_cluster)[936168]:    INFO: mssql_notify pre-stop
>Jul 14 17:15:59  ag(ag_cluster)[936168]:    INFO: ag_cluster notify : 0
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    INFO: mssql_validate
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    INFO: Resource agent invoked with: stop
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    INFO: mssql_stop
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    ERROR: SQL Server isn't running.
>Jul 14 17:15:59  ag(ag_cluster)[936213]:    INFO: ag_cluster stop : 0
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    INFO: mssql_validate
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    INFO: Resource agent invoked with: start
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    INFO: mssql_start
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    ERROR: SQL Server isn't running.
>Jul 14 17:17:22  ag(ag_cluster)[936352]:    INFO: ag_cluster start : 1
>Jul 14 17:17:22  ag(ag_cluster)[936406]:    INFO: mssql_validate
>Jul 14 17:17:22  ag(ag_cluster)[936406]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:17:22  ag(ag_cluster)[936406]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:17:22  ag(ag_cluster)[936406]:    INFO: Resource agent invoked with: notify
>Jul 14 17:17:22  ag(ag_cluster)[936406]:    INFO: mssql_notify post-start
>Jul 14 17:17:22  ag(ag_cluster)[936406]:    INFO: ag_cluster notify : 0
>Jul 14 17:17:27  ag(ag_cluster)[936452]:    INFO: mssql_validate
>Jul 14 17:17:27  ag(ag_cluster)[936452]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:17:27  ag(ag_cluster)[936452]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:17:27  ag(ag_cluster)[936452]:    INFO: Resource agent invoked with: notify
>Jul 14 17:17:27  ag(ag_cluster)[936452]:    INFO: mssql_notify pre-stop
>Jul 14 17:17:27  ag(ag_cluster)[936452]:    INFO: ag_cluster notify : 0
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    INFO: mssql_validate
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    INFO: Resource agent invoked with: stop
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    INFO: mssql_stop
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    ERROR: SQL Server isn't running.
>Jul 14 17:17:33  ag(ag_cluster)[936497]:    INFO: ag_cluster stop : 0
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    INFO: mssql_validate
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    INFO: Resource agent invoked with: start
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    INFO: mssql_start
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    ERROR: SQL Server isn't running.
>Jul 14 17:18:39  ag(ag_cluster)[936576]:    INFO: ag_cluster start : 1
>Jul 14 17:18:39  ag(ag_cluster)[936630]:    INFO: mssql_validate
>Jul 14 17:18:39  ag(ag_cluster)[936630]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:18:39  ag(ag_cluster)[936630]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:18:39  ag(ag_cluster)[936630]:    INFO: Resource agent invoked with: notify
>Jul 14 17:18:39  ag(ag_cluster)[936630]:    INFO: mssql_notify post-start
>Jul 14 17:18:39  ag(ag_cluster)[936630]:    INFO: ag_cluster notify : 0
>Jul 14 17:18:39  ag(ag_cluster)[936676]:    INFO: mssql_validate
>Jul 14 17:18:39  ag(ag_cluster)[936676]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:18:39  ag(ag_cluster)[936676]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:18:39  ag(ag_cluster)[936676]:    INFO: Resource agent invoked with: notify
>Jul 14 17:18:39  ag(ag_cluster)[936676]:    INFO: mssql_notify pre-stop
>Jul 14 17:18:39  ag(ag_cluster)[936676]:    INFO: ag_cluster notify : 0
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    INFO: mssql_validate
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    INFO: Resource agent invoked with: stop
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    INFO: mssql_stop
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    ERROR: SQL Server isn't running.
>Jul 14 17:18:39  ag(ag_cluster)[936721]:    INFO: ag_cluster stop : 0
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    INFO: mssql_validate
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    INFO: Resource agent invoked with: start
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    INFO: mssql_start
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    ERROR: SQL Server isn't running.
>Jul 14 17:20:01  ag(ag_cluster)[936822]:    INFO: ag_cluster start : 1
>Jul 14 17:20:02  ag(ag_cluster)[936876]:    INFO: mssql_validate
>Jul 14 17:20:02  ag(ag_cluster)[936876]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:20:02  ag(ag_cluster)[936876]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:20:02  ag(ag_cluster)[936876]:    INFO: Resource agent invoked with: notify
>Jul 14 17:20:02  ag(ag_cluster)[936876]:    INFO: mssql_notify post-start
>Jul 14 17:20:02  ag(ag_cluster)[936876]:    INFO: ag_cluster notify : 0
>Jul 14 17:20:02  ag(ag_cluster)[936922]:    INFO: mssql_validate
>Jul 14 17:20:02  ag(ag_cluster)[936922]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:20:02  ag(ag_cluster)[936922]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 60000
>Jul 14 17:20:02  ag(ag_cluster)[936922]:    INFO: Resource agent invoked with: notify
>Jul 14 17:20:02  ag(ag_cluster)[936922]:    INFO: mssql_notify pre-stop
>Jul 14 17:20:02  ag(ag_cluster)[936922]:    INFO: ag_cluster notify : 0
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    INFO: mssql_validate
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    INFO: OCF_RESKEY_CRM_meta_interval value: 0
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    INFO: OCF_RESKEY_CRM_meta_timeout value: 10000
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    INFO: Resource agent invoked with: stop
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    INFO: mssql_stop
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    ERROR: SQL Server isn't running.
>Jul 14 17:20:02  ag(ag_cluster)[936967]:    INFO: ag_cluster stop : 0

Actions: View

Attachments on bug 2221772: 1976118 | 1976119 | 1976120 | 1976684 | 1976685 | 1976686