Attachment 827121 Details for Bug 1018849 – HA agent on host

HA agent on host

agent.log (text/x-log), 14.90 KB, created by Lukas Svaty on 2013-11-21 10:38:02 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Lukas Svaty

Created: 2013-11-21 10:38:02 UTC

Size: 14.90 KB

patch

obsolete

>MainThread::INFO::2013-11-21 11:10:00,990::agent::50::Broker::(run) ovirt-hosted-engine-ha agent 0.1.0-0.6.beta1 started
>MainThread::INFO::2013-11-21 11:10:01,024::hosted_engine::293::HostedEngine::(_initialize_broker) Initializing ha-broker connection
>MainThread::INFO::2013-11-21 11:10:01,025::brokerlink::67::BrokerLink::(connect) Failed to connect to broker: [Errno 2] No such file or directory
>MainThread::INFO::2013-11-21 11:10:01,025::brokerlink::68::BrokerLink::(connect) Retrying broker connection...
>MainThread::INFO::2013-11-21 11:10:02,027::brokerlink::126::BrokerLink::(start_monitor) Starting monitor ping, options {'addr': '10.34.63.254'}
>MainThread::INFO::2013-11-21 11:10:02,031::brokerlink::137::BrokerLink::(start_monitor) Success, id 16176080
>MainThread::INFO::2013-11-21 11:10:02,031::brokerlink::126::BrokerLink::(start_monitor) Starting monitor mgmt-bridge, options {'use_ssl': 'true', 'bridge_name': 'rhevm', 'address': '0'}
>MainThread::INFO::2013-11-21 11:10:02,042::brokerlink::137::BrokerLink::(start_monitor) Success, id 16176720
>MainThread::INFO::2013-11-21 11:10:02,043::brokerlink::126::BrokerLink::(start_monitor) Starting monitor mem-free, options {'use_ssl': 'true', 'address': '0'}
>MainThread::INFO::2013-11-21 11:10:02,046::brokerlink::137::BrokerLink::(start_monitor) Success, id 16176208
>MainThread::INFO::2013-11-21 11:10:02,047::brokerlink::126::BrokerLink::(start_monitor) Starting monitor cpu-load, options {'use_ssl': 'true', 'address': '0'}
>MainThread::INFO::2013-11-21 11:10:02,048::brokerlink::137::BrokerLink::(start_monitor) Success, id 140028013670096
>MainThread::INFO::2013-11-21 11:10:02,050::brokerlink::126::BrokerLink::(start_monitor) Starting monitor mem-load, options {'use_ssl': 'true', 'address': '0'}
>MainThread::INFO::2013-11-21 11:10:02,056::brokerlink::137::BrokerLink::(start_monitor) Success, id 140028013789712
>MainThread::INFO::2013-11-21 11:10:02,059::brokerlink::126::BrokerLink::(start_monitor) Starting monitor engine-health, options {'use_ssl': 'true', 'vm_uuid': 'f42a49e1-03f5-4931-8cca-322fb58258cf', 'address': '0'}
>MainThread::INFO::2013-11-21 11:10:02,064::brokerlink::137::BrokerLink::(start_monitor) Success, id 140028013670224
>MainThread::INFO::2013-11-21 11:10:02,065::hosted_engine::316::HostedEngine::(_initialize_broker) Broker initialized, all submonitors started
>MainThread::INFO::2013-11-21 11:10:02,627::hosted_engine::384::HostedEngine::(_initialize_sanlock) Ensuring lease for lockspace hosted-engine, host id 1 is acquired (file: /rhev/data-center/mnt/10.34.63.202:_mnt_export_nfs_lv3_lsvaty_nfs02/479c7746-fbe0-467e-a8d2-0d068da024cc/ha_agent/hosted-engine.lockspace)
>MainThread::INFO::2013-11-21 11:10:23,633::hosted_engine::416::HostedEngine::(_initialize_sanlock) Acquired lock on host id 1
>MainThread::INFO::2013-11-21 11:10:23,700::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: NONE
>MainThread::INFO::2013-11-21 11:10:23,776::hosted_engine::442::HostedEngine::(_initialize_domain_monitor) Started VDSM domain monitor for 479c7746-fbe0-467e-a8d2-0d068da024cc
>MainThread::INFO::2013-11-21 11:10:23,837::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:10:28,944::hosted_engine::741::HostedEngine::(_collect_all_host_stats) Waiting for first update from host slot-5.rhev.lab.eng.brq.redhat.com (id 1)
>MainThread::INFO::2013-11-21 11:10:28,944::hosted_engine::758::HostedEngine::(_collect_all_host_stats) Global metadata: {}
>MainThread::INFO::2013-11-21 11:10:28,944::hosted_engine::762::HostedEngine::(_collect_all_host_stats) Host slot-5.rhev.lab.eng.brq.redhat.com (id 1): {'last-update-host-ts': 1385028628, 'last-update-local-ts': 1385028628, 'hostname': 'slot-5.rhev.lab.eng.brq.redhat.com', 'alive': 'unknown', 'engine-status': 'vm-down', 'score': 2400, 'first-update': True}
>MainThread::INFO::2013-11-21 11:10:28,945::hosted_engine::789::HostedEngine::(_perform_engine_actions) Unknown host state for id 1, waiting for initialization
>MainThread::INFO::2013-11-21 11:10:39,452::brokerlink::108::BrokerLink::(notify) Trying: notify time=1385028639.45 type=state_transition detail=<initial_state>-ENTRY hostname='slot-5.rhev.lab.eng.brq.redhat.com'
>MainThread::INFO::2013-11-21 11:10:39,454::brokerlink::117::BrokerLink::(notify) Success, was notification of state_transition (<initial_state>-ENTRY) sent? ignored
>MainThread::INFO::2013-11-21 11:10:39,455::hosted_engine::864::HostedEngine::(_handle_entry) Determining initial state for host
>MainThread::INFO::2013-11-21 11:10:39,455::brokerlink::108::BrokerLink::(notify) Trying: notify time=1385028639.46 type=state_transition detail=ENTRY-OFF hostname='slot-5.rhev.lab.eng.brq.redhat.com'
>MainThread::INFO::2013-11-21 11:10:39,456::brokerlink::117::BrokerLink::(notify) Success, was notification of state_transition (ENTRY-OFF) sent? ignored
>MainThread::ERROR::2013-11-21 11:10:39,456::hosted_engine::912::HostedEngine::(_handle_off) Engine down and local host has best score (2400), attempting to start engine VM
>MainThread::INFO::2013-11-21 11:10:39,457::brokerlink::108::BrokerLink::(notify) Trying: notify time=1385028639.46 type=state_transition detail=OFF-START hostname='slot-5.rhev.lab.eng.brq.redhat.com'
>MainThread::INFO::2013-11-21 11:23:22,009::agent::50::Broker::(run) ovirt-hosted-engine-ha agent 0.1.0-0.6.beta1 started
>MainThread::INFO::2013-11-21 11:23:22,066::hosted_engine::293::HostedEngine::(_initialize_broker) Initializing ha-broker connection
>MainThread::INFO::2013-11-21 11:23:22,067::brokerlink::126::BrokerLink::(start_monitor) Starting monitor ping, options {'addr': '10.34.63.254'}
>MainThread::INFO::2013-11-21 11:23:22,069::brokerlink::137::BrokerLink::(start_monitor) Success, id 30086096
>MainThread::INFO::2013-11-21 11:23:22,070::brokerlink::126::BrokerLink::(start_monitor) Starting monitor mgmt-bridge, options {'use_ssl': 'true', 'bridge_name': 'rhevm', 'address': '0'}
>MainThread::INFO::2013-11-21 11:23:22,155::brokerlink::137::BrokerLink::(start_monitor) Success, id 30086864
>MainThread::INFO::2013-11-21 11:23:22,157::brokerlink::126::BrokerLink::(start_monitor) Starting monitor mem-free, options {'use_ssl': 'true', 'address': '0'}
>MainThread::INFO::2013-11-21 11:23:22,160::brokerlink::137::BrokerLink::(start_monitor) Success, id 30086800
>MainThread::INFO::2013-11-21 11:23:22,161::brokerlink::126::BrokerLink::(start_monitor) Starting monitor cpu-load, options {'use_ssl': 'true', 'address': '0'}
>MainThread::INFO::2013-11-21 11:23:22,163::brokerlink::137::BrokerLink::(start_monitor) Success, id 140216119820240
>MainThread::INFO::2013-11-21 11:23:22,165::brokerlink::126::BrokerLink::(start_monitor) Starting monitor mem-load, options {'use_ssl': 'true', 'address': '0'}
>MainThread::INFO::2013-11-21 11:23:22,170::brokerlink::137::BrokerLink::(start_monitor) Success, id 140216119935312
>MainThread::INFO::2013-11-21 11:23:22,175::brokerlink::126::BrokerLink::(start_monitor) Starting monitor engine-health, options {'use_ssl': 'true', 'vm_uuid': 'f42a49e1-03f5-4931-8cca-322fb58258cf', 'address': '0'}
>MainThread::INFO::2013-11-21 11:23:22,179::brokerlink::137::BrokerLink::(start_monitor) Success, id 30222480
>MainThread::INFO::2013-11-21 11:23:22,179::hosted_engine::316::HostedEngine::(_initialize_broker) Broker initialized, all submonitors started
>MainThread::INFO::2013-11-21 11:23:22,507::hosted_engine::360::HostedEngine::(_cond_start_service) Starting vdsmd
>MainThread::INFO::2013-11-21 11:23:31,716::hosted_engine::384::HostedEngine::(_initialize_sanlock) Ensuring lease for lockspace hosted-engine, host id 1 is acquired (file: /rhev/data-center/mnt/10.34.63.202:_mnt_export_nfs_lv3_lsvaty_nfs02/479c7746-fbe0-467e-a8d2-0d068da024cc/ha_agent/hosted-engine.lockspace)
>MainThread::INFO::2013-11-21 11:26:12,735::hosted_engine::416::HostedEngine::(_initialize_sanlock) Acquired lock on host id 1
>MainThread::INFO::2013-11-21 11:26:12,801::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: NONE
>MainThread::INFO::2013-11-21 11:26:12,878::hosted_engine::442::HostedEngine::(_initialize_domain_monitor) Started VDSM domain monitor for 479c7746-fbe0-467e-a8d2-0d068da024cc
>MainThread::INFO::2013-11-21 11:26:12,944::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:18,016::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:23,081::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:28,151::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:33,217::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:38,293::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:43,380::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:48,445::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:53,532::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:26:58,597::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:03,659::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:08,724::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:13,790::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:18,854::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:23,918::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:28,983::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:34,050::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:39,116::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:44,180::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:49,245::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:54,311::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:27:59,376::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:04,442::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:09,507::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:14,572::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:19,637::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:24,701::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:29,765::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:34,830::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:39,896::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:44,960::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:50,024::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:28:55,087::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:29:00,152::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:29:05,218::hosted_engine::489::HostedEngine::(_get_domain_monitor_status) VDSM domain monitor status: PENDING
>MainThread::INFO::2013-11-21 11:29:10,339::hosted_engine::741::HostedEngine::(_collect_all_host_stats) Waiting for first update from host slot-5.rhev.lab.eng.brq.redhat.com (id 1)
>MainThread::INFO::2013-11-21 11:29:10,340::hosted_engine::758::HostedEngine::(_collect_all_host_stats) Global metadata: {}
>MainThread::INFO::2013-11-21 11:29:10,340::hosted_engine::762::HostedEngine::(_collect_all_host_stats) Host slot-5.rhev.lab.eng.brq.redhat.com (id 1): {'last-update-host-ts': 1385029750, 'last-update-local-ts': 1385029750, 'hostname': 'slot-5.rhev.lab.eng.brq.redhat.com', 'alive': 'unknown', 'engine-status': 'vm-down', 'score': 2400, 'first-update': True}
>MainThread::INFO::2013-11-21 11:29:10,340::hosted_engine::789::HostedEngine::(_perform_engine_actions) Unknown host state for id 1, waiting for initialization
>MainThread::INFO::2013-11-21 11:29:20,918::brokerlink::108::BrokerLink::(notify) Trying: notify time=1385029760.92 type=state_transition detail=<initial_state>-ENTRY hostname='slot-5.rhev.lab.eng.brq.redhat.com'
>MainThread::INFO::2013-11-21 11:29:20,938::brokerlink::117::BrokerLink::(notify) Success, was notification of state_transition (<initial_state>-ENTRY) sent? ignored
>MainThread::INFO::2013-11-21 11:29:20,938::hosted_engine::864::HostedEngine::(_handle_entry) Determining initial state for host
>MainThread::INFO::2013-11-21 11:29:20,939::brokerlink::108::BrokerLink::(notify) Trying: notify time=1385029760.94 type=state_transition detail=ENTRY-OFF hostname='slot-5.rhev.lab.eng.brq.redhat.com'
>MainThread::INFO::2013-11-21 11:29:20,940::brokerlink::117::BrokerLink::(notify) Success, was notification of state_transition (ENTRY-OFF) sent? ignored
>MainThread::ERROR::2013-11-21 11:29:20,940::hosted_engine::912::HostedEngine::(_handle_off) Engine down and local host has best score (2400), attempting to start engine VM
>MainThread::INFO::2013-11-21 11:29:20,941::brokerlink::108::BrokerLink::(notify) Trying: notify time=1385029760.94 type=state_transition detail=OFF-START hostname='slot-5.rhev.lab.eng.brq.redhat.com'

Actions: View

Attachments on bug 1018849: 819803 | 819804 | 819815 | 819816 | 827121 | 827122