Hey all
I just took over running some oracle vm servers and noticed odd behavior. Could anyone take a glance at this log and see if it doesn't seem right?
The server seemed to go down and come back up within minutes but there are large gaps in the log. It is just a single server. Or course all the VMs were stopped during this 'event'
thanks for any insights!
Gap comments in bold
[2015-01-05 13:30:49 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices tap2.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vif.
[2015-01-05 13:30:49 3449] DEBUG (DevController:144) Waiting for 0.
[2015-01-05 13:30:49 3449] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vif/63/0/hotplug-status.
[2015-01-05 13:30:49 3449] DEBUG (DevController:642) hotplugStatusCallback 1.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vkbd.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices ioports.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices tap.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vif2.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices console.
[2015-01-05 13:30:49 3449] DEBUG (DevController:144) Waiting for 0.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vscsi.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vbd.
[2015-01-05 13:30:49 3449] DEBUG (DevController:144) Waiting for 51712.
[2015-01-05 13:30:49 3449] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/63/51712/hotplug-status.
[2015-01-05 13:30:49 3449] DEBUG (DevController:642) hotplugStatusCallback 1.
[2015-01-05 13:30:49 3449] DEBUG (DevController:144) Waiting for 51728.
[2015-01-05 13:30:49 3449] DEBUG (DevController:628) hotplugStatusCallback /local/domain/0/backend/vbd/63/51728/hotplug-status.
[2015-01-05 13:30:49 3449] DEBUG (DevController:642) hotplugStatusCallback 1.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices irq.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vfb.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices pci.
[2015-01-05 13:30:49 3449] DEBUG (DevController:139) Waiting for devices vusb.
[2015-01-05 13:30:49 3449] INFO (XendDomain:1226) Domain 0004fb0000060000c7f7f74b0aa342fd (63) unpaused.
first gap, no logs for two days until three mysterious poweroff attemps?
[2015-01-07 11:58:48 3449] DEBUG (XendDomainInfo:539) XendDomainInfo.shutdown(poweroff)
[2015-01-07 11:58:48 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 11:58:48 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 11:58:59 3449] INFO (XendDomainInfo:2101) Domain has shutdown: name=0004fb000006000019f18b86e5c5266b id=27 reason=poweroff.
[2015-01-07 11:58:59 3449] DEBUG (XendDomainInfo:3106) XendDomainInfo.destroy: domid=27
[2015-01-07 11:59:05 3449] DEBUG (XendDomainInfo:2424) Destroying device model
[2015-01-07 11:59:06 3449] INFO (image:617) 0004fb000006000019f18b86e5c5266b device model terminated
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:2431) Releasing devices
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:2437) Removing vif/0
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:539) XendDomainInfo.shutdown(poweroff)
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:2437) Removing console/0
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:2437) Removing vbd/51712
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:2437) Removing vfb/0
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 11:59:06 3449] DEBUG (XendDomainInfo:4488) Release running lock: status=0, output=
[2015-01-07 11:59:15 3449] INFO (XendDomainInfo:2101) Domain has shutdown: name=0004fb0000060000004afa9f49c064e4 id=26 reason=poweroff.
[2015-01-07 11:59:15 3449] DEBUG (XendDomainInfo:3106) XendDomainInfo.destroy: domid=26
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:2424) Destroying device model
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:539) XendDomainInfo.shutdown(poweroff)
[2015-01-07 11:59:21 3449] INFO (image:617) 0004fb0000060000004afa9f49c064e4 device model terminated
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:2431) Releasing devices
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:2437) Removing vif/0
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:2437) Removing console/0
[2015-01-07 11:59:21 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2015-01-07 11:59:22 3449] DEBUG (XendDomainInfo:2437) Removing vbd/51712
[2015-01-07 11:59:22 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712
[2015-01-07 11:59:22 3449] DEBUG (XendDomainInfo:2437) Removing vfb/0
[2015-01-07 11:59:22 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0
[2015-01-07 11:59:22 3449] DEBUG (XendDomainInfo:4488) Release running lock: status=0, output=
[2015-01-07 11:59:33 3449] INFO (XendDomainInfo:2101) Domain has shutdown: name=0004fb00000600002b46a8744908570a id=11 reason=poweroff.
[2015-01-07 11:59:33 3449] DEBUG (XendDomainInfo:3106) XendDomainInfo.destroy: domid=11
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:2424) Destroying device model
[2015-01-07 11:59:38 3449] INFO (image:617) 0004fb00000600002b46a8744908570a device model terminated
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:2431) Releasing devices
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:2437) Removing vif/0
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vif, device = vif/0
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:2437) Removing console/0
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = console, device = console/0
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:2437) Removing vbd/51712
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vbd, device = vbd/51712
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:2437) Removing vfb/0
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:1291) XendDomainInfo.destroyDevice: deviceClass = vfb, device = vfb/0
[2015-01-07 11:59:38 3449] DEBUG (XendDomainInfo:4488) Release running lock: status=0, output=
second gap, 3 poweroff commands then 2 hour gap before it starts up. Yet the server was never off for 2 hours, it was went down and up in 4mins
[2015-01-07 13:59:58 19304] INFO (SrvDaemon:332) Xend Daemon started
[2015-01-07 13:59:58 19304] INFO (SrvDaemon:336) Xend changeset: .
[2015-01-07 13:59:58 19304] DEBUG (tcp:96) Listening on :8002
[2015-01-07 13:59:58 19304] DEBUG (tcp:194) Listening on :8003
[2015-01-07 14:00:00 19304] DEBUG (XendCPUPool:747) recreate_active_pools
[2015-01-07 14:00:00 19304] DEBUG (XendDomainInfo:154) XendDomainInfo.recreate({'max_vcpu_id': 19, 'cpu_time': 89557727718L, 'ssidref': 0, '
hvm': 0, 'shutdown_reason': 255, 'dying': 0, 'online_vcpus': 20, 'domid': 0, 'paused': 0, 'crashed': 0, 'running': 1, 'maxmem_kb': 11796480L
, 'shutdown': 0, 'mem_kb': 11796480L, 'blocked': 0, 'handle': [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], 'cpupool': 0, 'name': 'Domai
n-0'})
[2015-01-07 14:00:00 19304] INFO (XendDomainInfo:172) Recreating domain 0, UUID 00000000-0000-0000-0000-000000000000. at /local/domain/0
[2015-01-07 14:00:00 19304] DEBUG (XendDomainInfo:3470) Storing VM details: {'on_xend_stop': 'ignore', 'pool_name': 'Pool-0', 'shadow_memory
': '0', 'uuid': '00000000-0000-0000-0000-000000000000', 'on_reboot': 'restart', 'image': "(linux (kernel '') (expose_host_uuid 0) (superpage
s 0) (nomigrate 0) (tsc_mode 0))", 'on_poweroff': 'destroy', 'bootloader_args': '', 'on_xend_start': 'ignore', 'on_crash': 'restart', 'xend/
restart_count': '0', 'vcpus': '20', 'vcpu_avail': '1048575', 'bootloader': '', 'name': 'Domain-0'}
[2015-01-07 14:00:00 19304] DEBUG (XendDomainInfo:1817) Storing domain details: {'cpu/3/availability': 'online', 'cpu/6/availability': 'onli
ne', 'vm': '/vm/00000000-0000-0000-0000-000000000000', 'control/platform-feature-multiprocessor-suspend': '1', 'cpu/17/availability': 'onlin
e', 'cpu/14/availability': 'online', 'cpu/13/availability': 'online', 'cpu/2/availability': 'online', 'cpu/11/availability': 'online', 'memo
ry/target': '11796480', 'cpu/7/availability': 'online', 'cpu/1/availability': 'online', 'cpu/4/availability': 'online', 'cpu/15/availability
': 'online', 'description': '', 'console/limit': '1048576', 'cpu/8/availability': 'online', 'cpu/9/availability': 'online', 'cpu/5/availabil
ity': 'online', 'cpu/0/availability': 'online', 'cpu/18/availability': 'online', 'console/type': 'xenconsoled', 'cpu/12/availability': 'onli
ne', 'cpu/19/availability': 'online', 'name': 'Domain-0', 'domid': '0', 'control/platform-feature-xs_reset_watches': '1', 'cpu/16/availabili
ty': 'online', 'cpu/10/availability': 'online'}
[2015-01-07 14:00:00 19304] DEBUG (XendDomain:476) Adding Domain: 0
[2015-01-07 14:00:00 19304] DEBUG (XendDomain:410) number of vcpus to use is 0
[2015-01-07 14:00:00 19304] DEBUG (XendDomainInfo:1904) XendDomainInfo.handleShutdownWatch
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: VBD.set_device not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: VBD.set_type not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: session.get_all_records not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: event.get_record not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: event.get_all not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: VIF.set_device not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: VIF.set_MAC not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: VIF.set_MTU not found
[2015-01-07 14:00:00 19304] WARNING (XendAPI:696) API call: debug.get_all not found
[2015-01-07 14:00:00 19304] INFO (XMLRPCServer:161) Opening Unix domain socket XML-RPC server on /var/run/xend/xmlrpc.sock.
[2015-01-07 14:00:00 19304] INFO (XMLRPCServer:161) Opening Unix domain socket XML-RPC server on /var/run/xend/xen-api.sock; authentication
has been disabled for this server.
server now up and here bringing up the first VM
[2015-01-07 14:05:39 19304] DEBUG (XendDomainInfo:106) XendDomainInfo.create(['vm', ['name', '0004fb00000600007e625c3f9f93bb9e'], ['memory',
4096], ['on_poweroff', 'destroy'], ['on_reboot', 'restart'], ['on_crash', 'restart'], ['on_xend_start', 'ignore'], ['on_xend_stop', 'ignore
'], ['vcpu_avail', '1'], ['vcpus', 1], ['uuid', '0004fb00-0006-0000-7e62-5c3f9f93bb9e'], ['cpu_cap', 0], ['cpu_weight', 27500], ['oos', 1],
['image', ['hvm', ['videoram', 4], ['serial', 'pty'], ['acpi', 1], ['apic', 1], ['boot', 'c'], ['cpuid', []], ['cpuid_check', []], ['fda', '
'], ['fdb', ''], ['guest_os_type', 'windows'], ['hap', 1], ['hpet', 0], ['isa', 0], ['keymap', 'en-us'], ['localtime', 0], ['nestedhvm', 0],
['nographic', 0], ['oos', 1], ['pae', 1], ['pci', []], ['pci_msitranslate', 1], ['pci_power_mgmt', 0], ['rtc_timeoffset', 0], ['soundhw', '
'], ['stdvga', 0], ['timer_mode', 1], ['usb', 0], ['usbdevice', ''], ['vcpus', 1], ['vnc', 1], ['vnclisten', '127.0.0.1'], ['vncunused', 1],
['viridian', 0], ['vpt_align', 1], ['xauthority', '/root/.Xauthority'], ['xen_platform_pci', 1], ['memory_sharing', 0], ['tsc_mode', 0], ['
nomigrate', 0]]], ['s3_integrity', 1], ['device', ['vbd', ['uname', 'file:/OVS/Repositories/0004fb0000030000851e3ae680577395/VirtualDisks/00
04fb0000120000010aa7b368a59ca2.img'], ['dev', 'xvda'], ['mode', 'w']]], ['device', ['vbd', ['uname', ''], ['dev', 'xvdb:cdrom'], ['mode', 'r
']]], ['device', ['vif', ['bridge', '10f1ef9e38'], ['mac', '00:21:f6:00:00:4f']]]])
[2015-01-07 14:05:40 19304] DEBUG (XendDomainInfo:4476) Acquire running lock: status=0, output=
[2015-01-07 14:05:40 19304] DEBUG (XendDomainInfo:2521) XendDomainInfo.constructDomain
[2015-01-07 14:05:40 19304] DEBUG (balloon:187) Balloon: 518225660 KiB free; need 16384; done.
[2015-01-07 14:05:40 19304] DEBUG (XendDomain:476) Adding Domain: 1
[2015-01-07 14:05:40 19304] DEBUG (XendDomainInfo:2864) XendDomainInfo.initDomain: 1 27500
[2015-01-07 14:05:40 19304] DEBUG (image:339) No VNC passwd configured for vfb access
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: boot, val: c
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: fda, val: None
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: fdb, val: None
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: soundhw, val: None
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: localtime, val: 0
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: serial, val: ['pty']
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: std-vga, val: 0
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: isa, val: 0
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: acpi, val: 1
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: usb, val: 0
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: usbdevice, val: None
[2015-01-07 14:05:40 19304] DEBUG (image:893) args: gfx_passthru, val: None
[2015-01-07 14:05:40 19304] INFO (image:824) Need to create platform device.[domid:1]
[2015-01-07 14:05:40 19304] DEBUG (XendDomainInfo:2891) _initDomain:shadow_memory=0x0, memory_static_max=0x100000000, memory_static_min=0x0.
[2015-01-07 14:05:40 19304] INFO (image:182) buildDomain os=hvm dom=1 vcpus=1
[2015-01-07 14:05:40 19304] DEBUG (image:952) domid = 1
[2015-01-07 14:05:40 19304] DEBUG (image:953) image = /usr/lib/xen/boot/hvmloader
[2015-01-07 14:05:40 19304] DEBUG (image:954) store_evtchn = 3
[2015-01-07 14:05:40 19304] DEBUG (image:955) memsize = 4096
[2015-01-07 14:05:40 19304] DEBUG (image:956) target = 4096
[2015-01-07 14:05:40 19304] DEBUG (image:957) vcpus = 1
[2015-01-07 14:05:40 19304] DEBUG (image:958) vcpu_avail = 1
[2015-01-07 14:05:40 19304] DEBUG (image:959) acpi = 1
[2015-01-07 14:05:40 19304] DEBUG (image:960) apic = 1