2017-03-09 07:06:44.622+0000: starting up libvirt version: 2.0.0, package: 10.el7_3.5 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2017-02-10-03:02:29, x86-020.build.eng.bos.redhat.com), qemu version: 2.6.0 (qemu-kvm-rhev-2.6.0-28.el7_3.6), hostname: hyper03.spice.brq.redhat.com
LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=spice SPICE_DEBUG_LEVEL=9 /usr/libexec/qemu-kvm -name guest=toso-rhel7,debug-threads=on -S -object secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-23-toso-rhel7/master-key.aes -machine pc-i440fx-rhel7.3.0,accel=kvm,usb=off -cpu Nehalem -m size=2097152k,slots=16,maxmem=8388608k -realtime mlock=off -smp 1,maxcpus=16,sockets=16,cores=1,threads=1 -numa node,nodeid=0,cpus=0,mem=2048 -uuid d3f66688-ba48-40c1-881a-81ed660ad397 -smbios 'type=1,manufacturer=Red Hat,product=RHEV Hypervisor,version=7.3-7.el7,serial=36343035-3733-5A43-4A30-323830343546,uuid=d3f66688-ba48-40c1-881a-81ed660ad397' -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/domain-23-toso-rhel7/monitor.sock,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=2017-03-09T07:06:44,driftfix=slew -global kvm-pit.lost_tick_policy=discard -no-hpet -no-shutdown -boot strict=on -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x6 -device virtio-serial-pci,id=virtio-serial0,max_ports=16,bus=pci.0,addr=0x5 -drive if=none,id=drive-ide0-1-0,readonly=on -device ide-cd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0 -drive file=/rhev/data-center/00000001-0001-0001-0001-000000000311/325d0826-e9a1-470a-a5f5-3253e3e2f8c1/images/50918d2d-3af2-4bff-bac9-6312b1c1d065/bdf6803d-e152-4d46-99ac-8ed313cdcfbe,format=raw,if=none,id=drive-scsi0-0-0-0,serial=50918d2d-3af2-4bff-bac9-6312b1c1d065,cache=none,werror=stop,rerror=stop,aio=native -device scsi-hd,bus=scsi0.0,channel=0,scsi-id=0,lun=0,drive=drive-scsi0-0-0-0,id=scsi0-0-0-0,bootindex=2 -netdev tap,fd=33,id=hostnet0,vhost=on,vhostfd=36 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=00:1a:41:80:00:0e,bus=pci.0,addr=0x3,bootindex=1 -chardev socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/d3f66688-ba48-40c1-881a-81ed660ad397.com.redhat.rhevm.vdsm,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.rhevm.vdsm -chardev socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/d3f66688-ba48-40c1-881a-81ed660ad397.org.qemu.guest_agent.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,id=channel1,name=org.qemu.guest_agent.0 -chardev spicevmc,id=charchannel2,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=3,chardev=charchannel2,id=channel2,name=com.redhat.spice.0 -spice tls-port=5900,addr=10.34.73.132,x509-dir=/etc/pki/vdsm/libvirt-spice,tls-channel=default,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=smartcard,tls-channel=usbredir,seamless-migration=on -device qxl-vga,id=video0,ram_size=268435456,vram_size=134217728,vram64_size_mb=0,vgamem_mb=64,bus=pci.0,addr=0x2 -device intel-hda,id=sound0,bus=pci.0,addr=0x4 -device hda-duplex,id=sound0-codec0,bus=sound0.0,cad=0 -incoming defer -object rng-random,id=objrng0,filename=/dev/urandom -device virtio-rng-pci,rng=objrng0,id=rng0,bus=pci.0,addr=0x7 -msg timestamp=on
Domain id=23 is tainted: custom-argv
((null):32040): Spice-Debug **: reds.c:4647:spice_server_set_seamless_migration: seamless migration enabled=1
((null):32040): Spice-Info **: reds.c:4011:do_spice_init: starting 0.12.4
((null):32040): Spice-Info **: reds.c:3137:reds_init_socket: bound to 10.34.73.132:5900
((null):32040): Spice-Info **: reds.c:3337:reds_init_ssl: Loaded certificates from /etc/pki/vdsm/libvirt-spice/server-cert.pem
((null):32040): Spice-Info **: reds.c:3348:reds_init_ssl: Using private key from /etc/pki/vdsm/libvirt-spice/server-key.pem
((null):32040): Spice-Info **: reds.c:3357:reds_init_ssl: Loaded CA certificates from /etc/pki/vdsm/libvirt-spice/ca-cert.pem
((null):32040): Spice-Debug **: red_channel.c:1064:red_channel_create: channel type 1 id 0 thread_id 0x7f8e31990c80
((null):32040): Spice-Debug **: red_channel.c:1064:red_channel_create: channel type 3 id 0 thread_id 0x7f8e31990c80
((null):32040): Spice-Info **: reds.c:3943:spice_server_add_interface: SPICE_INTERFACE_MIGRATION
((null):32040): Spice-Info **: reds.c:3847:spice_server_add_interface: SPICE_INTERFACE_KEYBOARD
((null):32040): Spice-Info **: reds.c:3857:spice_server_add_interface: SPICE_INTERFACE_MOUSE
((null):32040): Spice-Debug **: red_dispatcher.c:813:red_dispatcher_on_vm_stop: 
2017-03-09T07:06:44.704390Z qemu-kvm: warning: CPU(s) not present in any NUMA nodes: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15
2017-03-09T07:06:44.704550Z qemu-kvm: warning: All CPU(s) up to maxcpus should be described in NUMA config
((null):32040): Spice-Info **: reds.c:3869:spice_server_add_interface: SPICE_INTERFACE_QXL
((null):32040): Spice-Debug **: red_dispatcher.c:1093:red_dispatcher_init: red_dispatcher->async_commands.next 0x7f8e3320ce28
((null):32040): SpiceWorker-Info **: red_worker.c:12224:red_worker_main: begin
((null):32040): SpiceWorker-Info **: red_worker.c:10734:display_channel_create: create display channel
((null):32040): Spice-Debug **: red_channel.c:1064:red_channel_create: channel type 2 id 0 thread_id 0x7f8d829ff700
((null):32040): SpiceWorker-Info **: red_worker.c:10989:cursor_channel_create: create cursor channel
((null):32040): Spice-Debug **: red_channel.c:1064:red_channel_create: channel type 4 id 0 thread_id 0x7f8d829ff700
((null):32040): Spice-Info **: reds.c:3897:spice_server_add_interface: SPICE_INTERFACE_PLAYBACK
((null):32040): Spice-Debug **: red_channel.c:1110:red_channel_create_dummy: channel type 5 id 0 thread_id 0x7f8e31990c80
((null):32040): Spice-Info **: reds.c:3906:spice_server_add_interface: SPICE_INTERFACE_RECORD
((null):32040): Spice-Debug **: red_channel.c:1110:red_channel_create_dummy: channel type 6 id 0 thread_id 0x7f8e31990c80
((null):32040): SpiceWorker-Debug **: red_worker.c:11233:dev_destroy_surfaces: 
((null):32040): SpiceWorker-Debug **: red_worker.c:11378:dev_create_primary_surface: 
((null):32040): Spice-Info **: reds.c:2710:reds_handle_auth_mechanism: Auth method: 1
((null):32040): Spice-Info **: reds.c:1707:reds_handle_main_link: 
((null):32040): Spice-Info **: reds.c:621:reds_disconnect: 
((null):32040): Spice-Info **: reds.c:1577:reds_info_new_channel: channel 1:0, connected successfully, over Secure link
main_channel_link: add main channel client
((null):32040): Spice-Info **: reds.c:1746:reds_handle_main_link: NEW Client 0x7f8e33203080 mcc 0x7f8e33ef7000 connect-id 768639639
((null):32040): Spice-Info **: reds.c:1604:reds_mig_target_client_add: 
((null):32040): Spice-Debug **: red_channel.c:825:red_channel_client_start_connectivity_monitoring: 
((null):32040): Spice-Debug **: red_channel.c:2088:red_channel_client_set_migration_seamless: channel type 1 id 0 rcc 0x7f8e33ef7000 wait data 1
((null):32040): Spice-Info **: reds.c:1839:reds_link_mig_target_channels: 0x7f8e33203080
((null):32040): Spice-Info **: reds.c:2710:reds_handle_auth_mechanism: Auth method: 1
((null):32040): Spice-Info **: reds.c:1577:reds_info_new_channel: channel 3:0, connected successfully, over Secure link
inputs_connect: inputs channel client create
((null):32040): Spice-Debug **: red_channel.c:2088:red_channel_client_set_migration_seamless: channel type 3 id 0 rcc 0x7f8e35df8000 wait data 1
((null):32040): Spice-Info **: reds.c:2710:reds_handle_auth_mechanism: Auth method: 1
((null):32040): Spice-Info **: reds.c:1577:reds_info_new_channel: channel 2:0, connected successfully, over Secure link
((null):32040): Spice-Debug **: red_dispatcher.c:104:red_dispatcher_set_display_peer: 
((null):32040): SpiceWorker-Info **: red_worker.c:11676:handle_dev_display_connect: connect
((null):32040): SpiceWorker-Info **: red_worker.c:10835:handle_new_display_channel: add display channel client
((null):32040): Spice-Debug **: red_channel.c:2088:red_channel_client_set_migration_seamless: channel type 2 id 0 rcc 0x7f8e34d80000 wait data 1
((null):32040): SpiceWorker-Info **: red_worker.c:10843:handle_new_display_channel: New display (client 0x7f8e33203080) dcc 0x7f8e34d80000 stream 0x7f8e33276dc0
((null):32040): SpiceWorker-Info **: red_worker.c:10870:handle_new_display_channel: jpeg disabled
((null):32040): SpiceWorker-Info **: red_worker.c:10871:handle_new_display_channel: zlib-over-glz disabled
((null):32040): Spice-Info **: reds.c:2710:reds_handle_auth_mechanism: Auth method: 1
((null):32040): Spice-Info **: reds.c:1577:reds_info_new_channel: channel 6:0, connected successfully, over Secure link
((null):32040): Spice-Debug **: snd_worker.c:216:snd_disconnect_channel: not connected
((null):32040): Spice-Debug **: red_channel.c:2088:red_channel_client_set_migration_seamless: channel type 6 id 0 rcc 0x7f8e35dfd000 wait data 0
((null):32040): Spice-Info **: reds.c:2710:reds_handle_auth_mechanism: Auth method: 1
((null):32040): Spice-Info **: reds.c:1577:reds_info_new_channel: channel 4:0, connected successfully, over Secure link
red_dispatcher_set_cursor_peer: 
((null):32040): SpiceWorker-Info **: red_worker.c:11778:handle_dev_cursor_connect: cursor connect
((null):32040): SpiceWorker-Info **: red_worker.c:11017:red_connect_cursor: add cursor channel client
((null):32040): Spice-Debug **: red_channel.c:2088:red_channel_client_set_migration_seamless: channel type 4 id 0 rcc 0x7f8e35e0a000 wait data 0
((null):32040): Spice-Info **: reds.c:2710:reds_handle_auth_mechanism: Auth method: 1
((null):32040): Spice-Info **: reds.c:1577:reds_info_new_channel: channel 5:0, connected successfully, over Secure link
((null):32040): Spice-Debug **: snd_worker.c:216:snd_disconnect_channel: not connected
((null):32040): Spice-Debug **: red_channel.c:2088:red_channel_client_set_migration_seamless: channel type 5 id 0 rcc 0x7f8e35e0f000 wait data 0
((null):32040): Spice-Info **: reds.c:3882:spice_server_add_interface: SPICE_INTERFACE_TABLET
((null):32040): SpiceWorker-Debug **: red_worker.c:11233:dev_destroy_surfaces: 
((null):32040): SpiceWorker-Debug **: red_worker.c:11378:dev_create_primary_surface: 
((null):32040): SpiceWorker-Debug **: red_worker.c:1259:monitors_config_decref: freeing monitors config
((null):32040): SpiceWorker-Debug **: red_worker.c:11437:dev_destroy_primary_surface: 
((null):32040): SpiceWorker-Debug **: red_worker.c:11378:dev_create_primary_surface: 
((null):32040): SpiceWorker-Debug **: red_worker.c:1259:monitors_config_decref: freeing monitors config
red_dispatcher_loadvm_commands: 
((null):32040): SpiceWorker-Info **: red_worker.c:11911:handle_dev_loadvm_commands: loadvm_commands
((null):32040): Spice-Debug **: red_dispatcher.c:352:async_command_alloc: 0x7f8e36a626a0
((null):32040): SpiceWorker-Debug **: red_worker.c:1259:monitors_config_decref: freeing monitors config
((null):32040): SpiceWorker-Debug **: red_worker.c:11301:worker_update_monitors_config: monitors config 1(4)
((null):32040): SpiceWorker-Debug **: red_worker.c:11307:worker_update_monitors_config: +0+0 1024x768
((null):32040): SpiceWorker-Debug **: red_worker.c:11945:worker_handle_dispatcher_async_done: 
((null):32040): Spice-Debug **: red_dispatcher.c:1016:red_dispatcher_async_complete: 0x7f8e36a626a0: cookie 140248737771216
((null):32040): Spice-Debug **: red_dispatcher.c:1018:red_dispatcher_async_complete: no more async commands
((null):32040): Spice-Debug **: red_channel.c:1400:red_channel_handle_migrate_data: channel type 2 id 0 rcc 0x7f8e34d80000 size 88
((null):32040): SpiceWorker-Debug **: red_worker.c:10225:display_channel_handle_migrate_data: 
((null):32040): SpiceWorker-Debug **: red_worker.c:10177:display_channel_client_restore_surfaces_lossless: 
2017-03-09T07:07:05.391312Z qemu-kvm: warning: TSC frequency mismatch between VM (2000070 kHz) and host (3092973 kHz), and TSC scaling unavailable
((null):32040): Spice-Info **: reds.c:3776:spice_server_char_device_add_interface: CHAR_DEVICE vdagent
((null):32040): Spice-Debug **: char_device.c:698:spice_char_device_state_create: sin 0x7f8e331e0b48 dev_state 0x7f8e33205980
((null):32040): Spice-Debug **: char_device.c:779:spice_char_device_client_add: dev_state 0x7f8e33205980 client 0x7f8e33203080
((null):32040): Spice-Debug **: reds.c:3697:attach_to_red_agent: waiting for migration data
((null):32040): Spice-Debug **: red_channel.c:1400:red_channel_handle_migrate_data: channel type 3 id 0 rcc 0x7f8e35df8000 size 10
((null):32040): Spice-Debug **: char_device.c:834:spice_char_device_start: dev_state 0x7f8e33205980
((null):32040): Spice-Debug **: red_dispatcher.c:824:red_dispatcher_on_vm_start: 
((null):32040): Spice-Debug **: red_channel.c:1400:red_channel_handle_migrate_data: channel type 1 id 0 rcc 0x7f8e33ef7000 size 65
((null):32040): Spice-Debug **: reds.c:1376:reds_handle_migrate_data: main-channel: got migrate data
((null):32040): Spice-Debug **: reds.c:1398:reds_handle_migrate_data: restoring state from mig_data
((null):32040): Spice-Debug **: reds.c:1359:reds_agent_state_restore: to agent filter: discard all 0, wait_msg 0, msg_filter_result 0
((null):32040): Spice-Debug **: reds.c:1363:reds_agent_state_restore: from agent filter: discard all 0, wait_msg 0, msg_filter_result 0
((null):32040): Spice-Debug **: reds.c:1887:reds_on_client_seamless_migrate_complete: 
((null):32040): Spice-Debug **: red_channel.c:1507:red_channel_client_handle_pong: update roundtrip 20209.79(ms)
((null):32040): SpiceWorker-Info **: red_worker.c:11876:handle_dev_set_mouse_mode: mouse mode 2
((null):32040): Spice-Debug **: red_channel.c:1507:red_channel_client_handle_pong: update roundtrip 1.25(ms)
red_channel_client_disconnect: rcc=0x7f8e35df8000 (channel=0x7f8e33304000 type=3 id=0)
red_channel_client_disconnect: rcc=0x7f8e34d80000 (channel=0x7f8e33338c00 type=2 id=0)
((null):32040): Spice-Info **: reds.c:4725:reds_stream_free: ((null):32040): Spice-Info **: reds.c:4725:reds_stream_free: close socket fd 32
close socket fd 31
((null):32040): SpiceWorker-Info **: red_worker.c:9471:display_channel_client_on_disconnect: 
((null):32040): SpiceWorker-Debug **: red_worker.c:9493:display_channel_client_on_disconnect: #draw=5, #red_draw=5, #glz_draw=0
red_channel_client_disconnect: rcc=0x7f8e35e0a000 (channel=0x7f8e362d4000 type=4 id=0)
((null):32040): Spice-Info **: reds.c:4725:reds_stream_free: close socket fd 34
((null):32040): Spice-Debug **: snd_worker.c:220:snd_disconnect_channel: SndChannel=0x7f8e3359a000 rcc=0x7f8e35dfd000 type=6
red_channel_client_disconnect_dummy: rcc=0x7f8e35dfd000 (channel=0x7f8e34de6100 type=6 id=0)
((null):32040): Spice-Info **: reds.c:4725:reds_stream_free: close socket fd 37
snd_channel_put: SndChannel=0x7f8e3359a000 freed
((null):32040): Spice-Debug **: snd_worker.c:220:snd_disconnect_channel: SndChannel=0x7f8e354b6000 rcc=0x7f8e35e0f000 type=5
((null):32040): Spice-Debug **: reds.c:3165:reds_send_mm_time: 
red_channel_client_disconnect_dummy: rcc=0x7f8e35e0f000 (channel=0x7f8e34de5fa0 type=5 id=0)
((null):32040): Spice-Info **: reds.c:4725:reds_stream_free: close socket fd 35
red_channel_client_disconnect: rcc=0x7f8e33ef7000 (channel=0x7f8e332fc000 type=1 id=0)
((null):32040): Spice-Info **: reds.c:4725:reds_stream_free: close socket fd 29
main_channel_client_on_disconnect: rcc=0x7f8e33ef7000
((null):32040): Spice-Debug **: main_dispatcher.c:160:main_dispatcher_client_disconnect: client 0x7f8e33203080
((null):32040): Spice-Debug **: main_dispatcher.c:121:main_dispatcher_handle_client_disconnect: client=0x7f8e33203080
((null):32040): Spice-Info **: reds.c:544:reds_client_disconnect: 
((null):32040): Spice-Debug **: char_device.c:811:spice_char_device_client_remove: dev_state 0x7f8e33205980 client 0x7f8e33203080
((null):32040): Spice-Debug **: char_device.c:132:spice_char_device_client_send_queue_free: send_queue_empty 1
((null):32040): Spice-Debug **: char_device.c:159:spice_char_device_client_free: write_queue_is_empty 1
red_client_destroy: destroy client 0x7f8e33203080 with #channels=6
((null):32040): Spice-Debug **: snd_worker.c:984:snd_disconnect_channel_client: channel-type=5
((null):32040): Spice-Debug **: red_channel.c:1228:red_channel_client_unref: destroy rcc=0x7f8e35e0f000
red_dispatcher_disconnect_cursor_peer: 
((null):32040): SpiceWorker-Info **: red_worker.c:11791:handle_dev_cursor_disconnect: disconnect cursor client
((null):32040): Spice-Debug **: red_channel.c:1228:red_channel_client_unref: destroy rcc=0x7f8e35e0a000
((null):32040): Spice-Debug **: snd_worker.c:984:snd_disconnect_channel_client: channel-type=6
((null):32040): Spice-Debug **: red_channel.c:1228:red_channel_client_unref: destroy rcc=0x7f8e35dfd000
red_dispatcher_disconnect_display_peer: 
((null):32040): SpiceWorker-Info **: red_worker.c:11690:handle_dev_display_disconnect: disconnect display client
((null):32040): Spice-Debug **: red_channel.c:1228:red_channel_client_unref: destroy rcc=0x7f8e34d80000
((null):32040): Spice-Debug **: red_channel.c:1228:red_channel_client_unref: destroy rcc=0x7f8e35df8000
((null):32040): Spice-Debug **: red_channel.c:1228:red_channel_client_unref: destroy rcc=0x7f8e33ef7000
((null):32040): Spice-Debug **: red_channel.c:2070:red_client_unref: release client=0x7f8e33203080
snd_channel_put: SndChannel=0x7f8e354b6000 freed
((null):32040): Spice-Info **: snd_worker.c:1107:spice_server_playback_put_samples: audio samples belong to a disconnected channel
2017-03-09T07:07:27.151875Z qemu-kvm: terminating on signal 15 from pid 1978
((null):32040): Spice-Info **: reds.c:3970:spice_server_remove_interface: remove SPICE_INTERFACE_PLAYBACK
((null):32040): Spice-Debug **: snd_worker.c:216:snd_disconnect_channel: not connected
((null):32040): Spice-Info **: reds.c:3973:spice_server_remove_interface: remove SPICE_INTERFACE_RECORD
((null):32040): Spice-Debug **: snd_worker.c:216:snd_disconnect_channel: not connected
((null):32040): Spice-Info **: reds.c:3818:spice_server_char_device_remove_interface: remove CHAR_DEVICE vdagent
2017-03-09 07:07:27.352+0000: shutting down