[Spice-devel] spice vdagent in windows 7 32bit doesn't start on f16 after today update

Wed Jan 18 05:21:47 PST 2012

Thanks for the update. Few questions:
1. Looking at windows device manager, is there any error reported for 
the virtio-serial driver?
2. Is the error reproduced only on startup, or also when you start the 
vdservice ("RHEV Spice Agent") manually when the machine is up?
3. Is it reproduced for other linux/windows guests?

Gianluca Cecchi wrote:
> After today updates on my F16 host it seems I'm not able to start
> vdagent inside my 32bit windows 7.
> One relevant update was for kernel, from 3.1.7-1.fc16.x86_64 to  to
> 3.1.9-1.fc16.x86_64
> no updates for libvirt/qemu/spice
>
> agent is from windows-32-20111124
> on host:
> $ rpm -qa|egrep "virt|spice|qemu|bios"
> virt-viewer-0.4.1-3.fc16.x86_64
> libvirt-0.9.6-4.fc16.x86_64
> spice-gtk3-0.7.39-1.fc16.x86_64
> qemu-kvm-0.15.1-3.fc16.x86_64
> libvirt-client-0.9.6-4.fc16.x86_64
> spice-client-0.10.0-1.fc16.x86_64
> spice-server-0.10.0-1.fc16.x86_64
> virt-dmesg-0.3.0-1.fc16.x86_64
> python-virtinst-0.600.0-5.fc16.noarch
> spice-gtk-tools-0.7.39-1.fc16.x86_64
> redland-virtuoso-1.0.14-1.fc16.x86_64
> gpxe-roms-qemu-1.0.1-4.fc16.noarch
> spice-gtk-python-0.7.39-1.fc16.x86_64
> virtuoso-opensource-6.1.4-2.fc16.x86_64
> seabios-bin-0.6.2-3.fc16.noarch
> virt-manager-0.9.0-7.fc16.noarch
> libvirt-python-0.9.6-4.fc16.x86_64
> vgabios-0.6c-3.fc15.noarch
> virt-manager-common-0.9.0-7.fc16.noarch
> biosdevname-0.3.11-5.fc16.x86_64
> qemu-common-0.15.1-3.fc16.x86_64
> python-virtkey-0.50-9.fc15.x86_64
> spice-xpi-2.5-4.fc16.x86_64
> spice-glib-0.7.39-1.fc16.x86_64
> spice-gtk-0.7.39-1.fc16.x86_64
> virt-top-1.0.6-1.fc16.x86_64
> qemu-img-0.15.1-3.fc16.x86_64
> qemu-system-x86-0.15.1-3.fc16.x86_64
>
> also restarting the agent gets no success
> In c:\Windows\Temp I have this for vdservice.log
>
> 656::INFO::2012-01-18 01:45:32,929::VDService::read_pipe::vdagent
> disconnected (109)
> 656::INFO::2012-01-18 01:45:32,929::VDService::execute::Agent killed
> 656::INFO::2012-01-18 01:45:32,929::VDService::kill_agent::vdagent
> exit code 1073807364
> 644::INFO::2012-01-18 01:45:34,808::VDService::control_handler::Session 1 LOGOFF
> 644::INFO::2012-01-18 01:45:36,009::VDService::control_handler::Stop service
> 644::INFO::2012-01-18 01:45:36,009::VDService::stop::Service stopped
> 656::INFO::2012-01-18
> 01:45:36,009::VDService::handle_control_event::Control command 1
> 656::INFO::2012-01-18 09:23:15,805::VDService::main::***Service started***
> 656::INFO::2012-01-18 09:23:15,805::log_version::1.1.0.1009
> 656::INFO::2012-01-18 09:23:15,805::VDService::launch_agent::Wait for
> vdagent to connect
> 656::INFO::2012-01-18 09:23:15,821::VDService::launch_agent::Pipe
> connected by vdagent
> 656::INFO::2012-01-18 09:23:15,821::VirtioVDIPort::init::CreateFile()
> \ failed: 2
> 656::INFO::2012-01-18 09:23:15,821::PCIVDIPort::init::CreateFile() failed: 2
> 656::INFO::2012-01-18 09:23:15,821::VDService::execute::Failed to
> create VDIPort instance
> 2452::INFO::2012-01-18 09:29:23,756::VDService::main::***Service started***
> 2452::INFO::2012-01-18 09:29:23,756::log_version::1.1.0.1009
> 2452::INFO::2012-01-18 09:29:23,756::VDService::launch_agent::Wait for
> vdagent to connect
> 2452::INFO::2012-01-18 09:29:23,772::VDService::launch_agent::Pipe
> connected by vdagent
> 2452::INFO::2012-01-18 09:29:23,772::VirtioVDIPort::init::CreateFile()
> \ failed: 2
> 2452::INFO::2012-01-18 09:29:23,772::PCIVDIPort::init::CreateFile() failed: 2
> 2452::INFO::2012-01-18 09:29:23,772::VDService::execute::Failed to
> create VDIPort instance
> 3692::INFO::2012-01-18 11:53:12,200::VDService::main::***Service started***
> 3692::INFO::2012-01-18 11:53:12,200::log_version::1.1.0.1009
> 3692::INFO::2012-01-18 11:53:12,216::VDService::launch_agent::Wait for
> vdagent to connect
> 3692::INFO::2012-01-18 11:53:12,216::VDService::launch_agent::Pipe
> connected by vdagent
> 3692::INFO::2012-01-18 11:53:12,216::VirtioVDIPort::init::CreateFile()
> \ failed: 2
> 3692::INFO::2012-01-18 11:53:12,216::PCIVDIPort::init::CreateFile() failed: 2
> 3692::INFO::2012-01-18 11:53:12,216::VDService::execute::Failed to
> create VDIPort instance
>
> and this for vdagent.log
> 1288::INFO::2012-01-18 01:45:32,929::VDAgent::wnd_proc::Session ended
> 1288::INFO::2012-01-18
> 01:45:32,929::VDAgent::handle_control_event::Control command 0
> 668::INFO::2012-01-18 09:23:15,821::VDAgent::run::***Agent started in
> session 1***
> 668::INFO::2012-01-18 09:23:15,821::log_version::1.1.0.1009
> 668::INFO::2012-01-18
> 09:23:15,821::DesktopLayout::consistent_displays::#qxls 1 #others 0
> 668::INFO::2012-01-18 09:23:15,821::VDAgent::connect_pipe::Connected
> to service pipe
> 668::INFO::2012-01-18
> 09:23:15,821::VDAgent::send_announce_capabilities::Sending
> capabilities:
> 668::INFO::2012-01-18 09:23:15,821::VDAgent::send_announce_capabilities::37
> 668::INFO::2012-01-18
> 09:23:15,821::VDAgent::input_desktop_message_loop::Desktop: Winlogon
> 668::INFO::2012-01-18
> 09:23:15,821::VDAgent::read_completion::vdservice disconnected (109)
> 668::INFO::2012-01-18 09:23:15,821::VDAgent::run::Agent stopped
> 2872::INFO::2012-01-18 09:29:23,772::VDAgent::run::***Agent started in
> session 1***
> 2872::INFO::2012-01-18 09:29:23,772::log_version::1.1.0.1009
> 2872::INFO::2012-01-18
> 09:29:23,772::DesktopLayout::consistent_displays::#qxls 1 #others 0
> 2872::INFO::2012-01-18 09:29:23,772::VDAgent::connect_pipe::Connected
> to service pipe
> 2872::INFO::2012-01-18
> 09:29:23,772::VDAgent::send_announce_capabilities::Sending
> capabilities:
> 2872::INFO::2012-01-18 09:29:23,772::VDAgent::send_announce_capabilities::37
> 2872::INFO::2012-01-18
> 09:29:23,772::VDAgent::input_desktop_message_loop::Desktop: Default
> 2872::INFO::2012-01-18
> 09:29:23,772::VDAgent::input_desktop_message_loop::First display
> setting
> 2872::INFO::2012-01-18 09:29:23,772::DisplaySetting::load::loading
> display setting
> 2872::INFO::2012-01-18
> 09:29:23,772::DisplaySetting::reload_from_registry::explorer pid 904
> 2872::INFO::2012-01-18 09:29:23,772::DisplaySetting::reload_wallpaper::
> 2872::INFO::2012-01-18
> 09:29:23,772::DisplaySetting::reload_wallpaper::reload wallpaper:
> success
> 2872::INFO::2012-01-18 09:29:23,772::DisplaySetting::reload_font_smoothing::
> 2872::INFO::2012-01-18
> 09:29:23,772::DisplaySetting::reload_font_smoothing::font smoothing is
> disabled in registry. do nothing
> 2872::INFO::2012-01-18 09:29:23,772::DisplaySetting::reload_animation::
> 2872::INFO::2012-01-18 09:29:23,772::DisplaySetting::reload_win_animation::
> 2872::INFO::2012-01-18
> 09:29:23,772::DisplaySetting::reload_win_animation::reload window
> animation: success
> 2872::INFO::2012-01-18 09:29:23,772::DisplaySetting::reload_ui_effects::
> 2872::INFO::2012-01-18
> 09:29:23,772::DisplaySetting::reload_ui_effects::UserPreferencesMask =
> 80073294 12
> 2872::INFO::2012-01-18
> 09:29:23,819::VDAgent::read_completion::vdservice disconnected (109)
> 2872::INFO::2012-01-18 09:29:23,819::VDAgent::run::Agent stopped
> 2068::INFO::2012-01-18 11:53:12,216::VDAgent::run::***Agent started in
> session 1***
> 2068::INFO::2012-01-18 11:53:12,216::log_version::1.1.0.1009
> 2068::INFO::2012-01-18
> 11:53:12,216::DesktopLayout::consistent_displays::#qxls 1 #others 0
> 2068::INFO::2012-01-18 11:53:12,216::VDAgent::connect_pipe::Connected
> to service pipe
> 2068::INFO::2012-01-18
> 11:53:12,216::VDAgent::send_announce_capabilities::Sending
> capabilities:
> 2068::INFO::2012-01-18 11:53:12,216::VDAgent::send_announce_capabilities::37
> 2068::INFO::2012-01-18
> 11:53:12,216::VDAgent::input_desktop_message_loop::Desktop: Default
> 2068::INFO::2012-01-18
> 11:53:12,216::VDAgent::input_desktop_message_loop::First display
> setting
> 2068::INFO::2012-01-18 11:53:12,216::DisplaySetting::load::loading
> display setting
> 2068::INFO::2012-01-18
> 11:53:12,216::DisplaySetting::reload_from_registry::explorer pid 904
> 2068::INFO::2012-01-18 11:53:12,216::DisplaySetting::reload_wallpaper::
> 2068::INFO::2012-01-18
> 11:53:12,216::DisplaySetting::reload_wallpaper::reload wallpaper:
> success
> 2068::INFO::2012-01-18 11:53:12,216::DisplaySetting::reload_font_smoothing::
> 2068::INFO::2012-01-18
> 11:53:12,216::DisplaySetting::reload_font_smoothing::font smoothing is
> disabled in registry. do nothing
> 2068::INFO::2012-01-18 11:53:12,216::DisplaySetting::reload_animation::
> 2068::INFO::2012-01-18 11:53:12,216::DisplaySetting::reload_win_animation::
> 2068::INFO::2012-01-18
> 11:53:12,216::DisplaySetting::reload_win_animation::reload window
> animation: success
> 2068::INFO::2012-01-18 11:53:12,216::DisplaySetting::reload_ui_effects::
> 2068::INFO::2012-01-18
> 11:53:12,216::DisplaySetting::reload_ui_effects::UserPreferencesMask =
> 80073294 12
> 2068::INFO::2012-01-18
> 11:53:12,247::VDAgent::read_completion::vdservice disconnected (109)
> 2068::INFO::2012-01-18 11:53:12,247::VDAgent::run::Agent stopped
>
> Thanks in advance
> _______________________________________________
> Spice-devel mailing list
> Spice-devel at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/spice-devel
>   