HELP - guest suddenly aborts multiple times per day

[rkleemann]

Hi,

I have a linux Ubuntu 8.0.4 host which is currently running 8 guests. 7 of them are linux guests and 1 is win2k3.

I'm running VB 2.0.6.

I've been running the linux guests for many months now, and they run perfectly. No problems, no aborts.

I just installed the win2k3 guest a couple of days ago. I don't see any apparent problem. Everything looks ok on both the guest and the host.

However, the guest will suddenly abort a few times each day. I don't see any evidence of errors. There's nothing telling in the windows event logs.

Again, there are 7 other guests, all linux, which never abort.

How can I debug this? Does VB log any sort of errors or give any sort of reason for aborting?

Can I run the guest in such a way as to get some sort of logging to catch these aborts?

Help...

[Perryg]

• Is this the same guest that will not work using bridged mode?
• Any way please post the guest settings (all of them) so we can see if there is an issue.
• When you say abort I assume it forces a hard shutdown on itself or something similar. Have you seen it when it shuts down?
• The VBox logs are stored in the machine folder and under the folder of the machine name. I don't have my Linux system up at the moment but you should be able to find it. That log should give you an idea of what is happening.

[rkleemann]

• Is this the same guest that will not work using bridged mode?
• Any way please post the guest settings (all of them) so we can see if there is an issue.
• When you say abort I assume it forces a hard shutdown on itself or something similar. Have you seen it when it shuts down?
• The VBox logs are stored in the machine folder and under the folder of the machine name. I don't have my Linux system up at the moment but you should be able to find it. That log should give you an idea of what is happening.

Hi,

Yes, it's the same one that was not working initially with bridged mode. I got it fixed by changing the hostifdev, for some reason the one I was using was having problems.

Aborted simply means that showvminfo shows that the box got aborted. I have never actually "caught it in the act", because I have a cronjob that looks at the vm state and if it has been not running for 5 minutes it automatically restarts the vm. But I am notified when this is detected and also the current state, and that's how I know that the vm is aborted (the state is always "aborted")

As far as logs, I have the directory /Virtualbox2/Machines/win2003/Logs. I have this for all my guests. However ALL of them are empty. None of my guest vms have any logs, for some strange reason.

Here's the settings from the xml file.

Code: Select all

<?xml version="1.0" encoding="UTF-8"?>
<!-- Sun xVM VirtualBox Machine Configuration -->
<VirtualBox xmlns="http://www.innotek.de/VirtualBox-settings" version="1.3-linux">
  <Machine uuid="{bd234016-9b68-4e20-be69-ae7219d4aee1}" name="win2003" nameSync="false" OSType="win2k3" lastStateCha
nge="2009-05-28T04:31:30Z" snapshotFolder="/var/Virtualbox/snapshots/win2003/" aborted="true">
    <ExtraData/>
    <Hardware>
      <CPU>
        <HardwareVirtEx enabled="true"/>
        <HardwareVirtExNestedPaging enabled="false"/>
        <PAE enabled="true"/>
      </CPU>
      <Memory RAMSize="3000"/>
      <Boot>
        <Order position="1" device="Floppy"/>
        <Order position="2" device="DVD"/>
        <Order position="3" device="HardDisk"/>
      </Boot>
      <Display VRAMSize="32" MonitorCount="1"/>
      <RemoteDisplay enabled="true" port="5008" authType="Null"/>
      <BIOS>
        <ACPI enabled="true"/>
        <IOAPIC enabled="true"/>
        <Logo fadeIn="true" fadeOut="true" displayTime="0"/>
        <BootMenu mode="MessageAndMenu"/>
        <TimeOffset value="0"/>
        <PXEDebug enabled="false"/>
        <IDEController type="PIIX4"/>
      </BIOS>
      <DVDDrive passthrough="false"/>
      <FloppyDrive enabled="true"/>
      <USBController enabled="false" enabledEhci="false"/>
      <SATAController enabled="false" PortCount="30" IDE0MasterEmulationPort="0" IDE0SlaveEmulationPort="1" IDE1Maste
rEmulationPort="2" IDE1SlaveEmulationPort="3"/>
      <Network>
        <Adapter slot="0" enabled="true" MACAddress="0800279DA832" cable="true" speed="0" type="82540EM">
          <HostInterface name="vbox0"/>
        </Adapter>
        <Adapter slot="1" enabled="false" MACAddress="080027948F38" cable="true" speed="0" type="82540EM">
          <HostInterface name="vbox8"/>
        </Adapter>
        <Adapter slot="2" enabled="false" MACAddress="080027A9B42E" cable="true" speed="0" type="Am79C973"/>
        <Adapter slot="3" enabled="false" MACAddress="080027E7F9D9" cable="true" speed="0" type="Am79C973"/>
      </Network>
      <UART>
      <LPT>
        <Port slot="0" enabled="false" IOBase="0x378" IRQ="4"/>
        <Port slot="1" enabled="false" IOBase="0x378" IRQ="4"/>
      </LPT>
      <AudioAdapter controller="AC97" driver="Pulse" enabled="true"/>
      <SharedFolders/>
      <Clipboard mode="Bidirectional"/>
      <Guest memoryBalloonSize="0" statisticsUpdateInterval="0"/>
      <GuestProperties>
        <GuestProperty name="/VirtualBox/GuestInfo/OS/Product" value="Windows 2003" timestamp="1243479610426750000" f
lags=""/>
        <GuestProperty name="/VirtualBox/GuestInfo/OS/Release" value="5.2.3790" timestamp="1243479610469262000" flags
=""/>
        <GuestProperty name="/VirtualBox/GuestInfo/OS/ServicePack" value="2" timestamp="1243479610567879000" flags=""
/>
        <GuestProperty name="/VirtualBox/GuestAdd/InstallDir" value="C:/Program Files/Sun/xVM VirtualBox Guest Additi
ons" timestamp="1243479610569524000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Revision" value="39755" timestamp="1243479610570236000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Version" value="2.0.6" timestamp="1243479610570511000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxControl.exe" value="2.0.6r39755" timestamp="12434796
10572626000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxHook.dll" value="2.0.6r39755" timestamp="12434796105
73914000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxDisp.dll" value="2.0.6r39755" timestamp="12434796105
75520000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxMRXNP.dll" value="2.0.6r39755" timestamp="1243479610
577243000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxService.exe" value="2.0.6r39755" timestamp="12434796
10577471000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxTray.exe" value="2.0.6r39755" timestamp="12434796105
79114000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxGuest.sys" value="2.0.6r39755" timestamp="1243479610
580474000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxMouse.sys" value="2.0.6r39755" timestamp="1243479610
581821000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxSF.sys" value="2.0.6r39755" timestamp="1243479610583
436000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestAdd/Components/VBoxVideo.sys" value="2.0.6r39755" timestamp="1243479610
585012000" flags=""/>
        <GuestProperty name="/VirtualBox/GuestInfo/OS/LoggedInUsers" value="0" timestamp="1243479769385839000" flags=
""/>
        <GuestProperty name="/VirtualBox/GuestInfo/OS/NoLoggedInUsers" value="true" timestamp="1243479769385979000" f
lags=""/>
        <GuestProperty name="/VirtualBox/GuestInfo/Net/Count" value="0" timestamp="1243479769819511000" flags=""/>
      </GuestProperties>
    </Hardware>
    <HardDiskAttachments>
      <HardDiskAttachment hardDisk="{5754604a-b9f6-44de-9784-2ce20f57d513}" bus="IDE" channel="0" device="0"/>
    </HardDiskAttachments>
  </Machine>
</VirtualBox>

[Perryg]

I put your log in a code block to make it easier to read.

The main problems I have with Windows as guest that concern hangs and other strange behaviors is screen savers and power managers. They seem to tick off VBox for some reason. I would look for anything that would cause the guest to loose its linkup to the system.

Out of curiosity what command are you using to start the VM?

[rkleemann]

I put your log in a code block to make it easier to read.

The main problems I have with Windows as guest that concern hangs and other strange behaviors is screen savers and power managers. They seem to tick off VBox for some reason. I would look for anything that would cause the guest to loose its linkup to the system.

Out of curiosity what command are you using to start the VM?

Thanks for the tip. So you think I should turn off the default session locking?

I run all my guests headless, I simply use:
VBoxHeadless -s win2003&

Any idea why there would be no logs (none of the vms have logs, even though there's a Logs directory)

[Perryg]

I think you try and see if it helps. If so then at least you know where to look for answers. As for the start command I wanted to make sure that you were not using the VBoxManage command to start the VM. See below from the book:

To start a virtual machine with VBoxHeadless, you have two options:

You can use VBoxManage startvm <vmname> --type vrdp. The extra --type option causes the VirtualBox core to use VBoxHeadless as the front-end to the internal virtualization engine.

The recommended way, however, is to use VBoxHeadless directly, as follows:

VBoxHeadless --startvm <uuid|name>
This is the recommended way, because when starting the headless interface through VBoxManage, you will not be able to view or log messages that VBoxHeadless may have output on the console. Especially in case of startup errors, such output might be desirable for problem diagnosis.

So if it not producing a log file you should approach the bugtracker with this. I really want my logs and I bet you do too.

[rkleemann]

So maybe the lack of logs is a bug...

My concern is that I'm using 2.0.6 and don't want to change versions. I'm running 8 production vms and don't want to risk changing versions.

So if I go into bugtracker, I don't know if a fix would be done for 2.0.6 or if I would be required to upgrade.

[rkleemann]

So I did find the logs! A simple locate showed me they were in a different directory...

Here is the tail end of the previous session:

Code: Select all

00:00:09.820 VRDP: New connection:
00:00:09.980 VRDP: Flags 0x0000001b
00:00:09.980 VRDP: Channel: [rdpdr] [1004]. Not supported.
00:00:09.980 VRDP: Channel: [rdpsnd] [1005]. Accepted.
00:00:09.980 VRDP: Channel: [drdynvc] [1006]. Not supported.
00:00:09.980 VRDP: Channel: [cliprdr] [1007]. Accepted.
00:00:10.312 Guest Log: BIOS: int13_harddisk: function 15, unmapped device for ELDL=81
00:00:10.582 VRDP: Client seems to be MSFT.
00:00:10.582 VRDP: Logon: RICARDO-LAPTOP (192.168.0.101) build 6001. User: [] Domain: [] Screen: 0
00:00:10.583 VRDPAUTH: User: []. Domain: []. Authentication type: [Null]
00:00:10.583 VRDPAUTH: Access granted.
00:00:10.583 VBVA: VRDP acceleration has been requested.
00:00:10.899 VMMDev::SetVideoModeHint: got a video mode hint (1280x1024x0) at 0
00:01:14.883 PIT: mode=2 count=0xffff (65535) - 18.20 Hz (ch=0)
00:01:15.149 Changing the VM state from 'RUNNING' to 'RESETTING'.
00:01:15.224 CPUMSetGuestCpuIdFeature: Enabled APIC
00:01:15.224 PIT: mode=3 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:01:15.238 PIIX3 ATA: Ctl#0: finished processing RESET
00:01:15.339 PIIX3 ATA: Ctl#1: finished processing RESET
00:01:15.439 Audio: set_record_source ars=0 als=0 (not implemented)
00:01:15.439 TM: Aborting catch-up attempt on reset with a 281131678 ns lag on reset; new total: 281131678 ns
00:01:15.454 Changing the VM state from 'RESETTING' to 'RUNNING'.
00:01:15.458 Guest Log: BIOS: VirtualBox 2.0.6
00:01:15.458 PIT: mode=2 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:01:15.473 PIIX3 ATA: Ctl#0: RESET, DevSel=0 AIOIf=0 CmdIf0=0x30 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:01:15.473 PIIX3 ATA: Ctl#0: finished processing RESET
00:01:15.473 Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
00:01:15.473 PIIX3 ATA: Ctl#1: RESET, DevSel=0 AIOIf=0 CmdIf0=0xa0 (-1 usec ago) CmdIf1=0x00 (-1 usec ago)
00:01:15.473 PIIX3 ATA: Ctl#1: finished processing RESET
00:01:15.473 PIT: mode=2 count=0x48d3 (18643) - 64.00 Hz (ch=0)
00:01:15.474 Display::handleDisplayResize(): uScreenId = 0, pvVRAM=00007f5735508000 w=640 h=480 bpp=32 cbLine=0xA00
00:01:15.631 VMMDev::SetVideoModeHint: got a video mode hint (1280x1024x0) at 0
00:01:17.951 PIT: mode=2 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:01:17.952 Guest Log: BIOS: Boot from Floppy 0 failed
00:01:17.954 Guest Log: BIOS: CDROM boot failure code : 0003
00:01:17.954 Guest Log: BIOS: Boot from CD-ROM failed
00:01:17.955 Guest Log: BIOS: Booting from Hard Disk...
00:01:17.967 Display::handleDisplayResize(): uScreenId = 0, pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0
00:01:18.575 Guest Log: BIOS: int13_harddisk: function 15, unmapped device for ELDL=81
00:01:18.920 VMMDev::SetVideoModeHint: got a video mode hint (1280x1024x0) at 0
00:01:35.165 PIT: mode=2 count=0xffff (65535) - 18.20 Hz (ch=0)
00:01:35.300 Display::handleDisplayResize(): uScreenId = 0, pvVRAM=00007f5735508000 w=640 h=480 bpp=0 cbLine=0x140
00:01:43.893 VBVA: Enabled.
00:01:44.004 Guest requests mouse pointer integration
00:01:47.605 Guest Log: VBoxService: Started.
00:01:47.762 Guest Log: vboxVMInfoThread: GuestProp ClientID = 2
00:01:59.065 Audio: set_record_source ars=0 als=0 (not implemented)
00:01:59.065 Audio: set_record_source ars=0 als=0 (not implemented)
00:01:59.732 Guest Log: VBoxTray: Started.
00:01:59.793 Guest Additions capability report: (0x5) seamless: yes, hostWindowMapping: no, graphics: yes
00:03:26.635 Guest Log: VBOXNP: DLL loaded.
00:05:26.606 TM: Giving up catch-up attempt at a 60001342955 ns lag; new total: 60282474633 ns
00:06:37.384 VRDP: Connection closed:
00:06:37.384 VRDP: Logoff: RICARDO-LAPTOP (192.168.0.101) build 6001. User: [] Domain: [] Reason 0x0001.
00:06:37.384 VBVA: VRDP acceleration has been disabled.
00:08:39.989 TM: Giving up catch-up attempt at a 60000999935 ns lag; new total: 120283474568 ns
00:11:44.539 TM: Giving up catch-up attempt at a 60000206053 ns lag; new total: 180283680621 ns
00:14:48.469 TM: Giving up catch-up attempt at a 60000292609 ns lag; new total: 240283973230 ns
00:18:04.469 TM: Giving up catch-up attempt at a 60000148575 ns lag; new total: 300284121805 ns
00:21:14.926 TM: Giving up catch-up attempt at a 60001094594 ns lag; new total: 360285216399 ns
00:24:09.787 TM: Giving up catch-up attempt at a 60000457584 ns lag; new total: 420285673983 ns
00:27:08.984 TM: Giving up catch-up attempt at a 60022403308 ns lag; new total: 480308077291 ns
00:30:03.819 TM: Giving up catch-up attempt at a 60000751228 ns lag; new total: 540308828519 ns
00:32:56.656 TM: Giving up catch-up attempt at a 60002248534 ns lag; new total: 600311077053 ns
00:36:00.206 TM: Giving up catch-up attempt at a 60000051591 ns lag; new total: 660311128644 ns
00:38:58.396 TM: Giving up catch-up attempt at a 60001393094 ns lag; new total: 720312521738 ns
00:41:54.186 TM: Giving up catch-up attempt at a 60000661068 ns lag; new total: 780313182806 ns
00:44:49.466 TM: Giving up catch-up attempt at a 60000972196 ns lag; new total: 840314155002 ns
00:47:33.503 TM: Giving up catch-up attempt at a 60000783422 ns lag; new total: 900314938424 ns
00:50:22.506 TM: Giving up catch-up attempt at a 60001484917 ns lag; new total: 960316423341 ns
00:53:02.349 TM: Giving up catch-up attempt at a 60000053372 ns lag; new total: 1020316476713 ns
00:55:55.119 TM: Giving up catch-up attempt at a 60001179656 ns lag; new total: 1080317656369 ns
00:59:02.139 TM: Giving up catch-up attempt at a 60001294597 ns lag; new total: 1140318950966 ns
01:01:47.880 TM: Giving up catch-up attempt at a 60000221085 ns lag; new total: 1200319172051 ns
01:04:45.149 TM: Giving up catch-up attempt at a 60000381619 ns lag; new total: 1260319553670 ns
01:08:22.281 TM: Giving up catch-up attempt at a 60000186740 ns lag; new total: 1320319740410 ns
01:11:18.679 TM: Giving up catch-up attempt at a 60001409317 ns lag; new total: 1380321149727 ns
01:14:16.405 TM: Giving up catch-up attempt at a 60001748527 ns lag; new total: 1440322898254 ns
01:17:34.483 TM: Giving up catch-up attempt at a 60002586177 ns lag; new total: 1500325484431 ns
01:20:47.796 TM: Giving up catch-up attempt at a 60000423165 ns lag; new total: 1560325907596 ns
01:23:46.372 TM: Giving up catch-up attempt at a 60006624634 ns lag; new total: 1620332532230 ns
01:26:28.945 TM: Giving up catch-up attempt at a 60000672770 ns lag; new total: 1680333205000 ns

So what's this "catch-up attempt"?

[Perryg]

Actually this concerns me more that the catchup.

Code: Select all

00:01:14.883 PIT: mode=2 count=0xffff (65535) - 18.20 Hz (ch=0)
00:01:15.149 Changing the VM state from 'RUNNING' to 'RESETTING'.
00:01:15.224 CPUMSetGuestCpuIdFeature: Enabled APIC

Could your cronjob be seeing the machine as not working and then sending it a reset when it is actually working? What happens if you leave the cronjob out of the loop?

[rkleemann]

Actually this concerns me more that the catchup.

Code: Select all

00:01:14.883 PIT: mode=2 count=0xffff (65535) - 18.20 Hz (ch=0)
00:01:15.149 Changing the VM state from 'RUNNING' to 'RESETTING'.
00:01:15.224 CPUMSetGuestCpuIdFeature: Enabled APIC

Could your cronjob be seeing the machine as not working and then sending it a reset when it is actually working? What happens if you leave the cronjob out of the loop?

The cronjob looks at the VM state. If it is not running for 5 minutes, it does a poweroff and then a start.

I guess I have to wait for the next time this happens, maybe I'm looking at a log for a real reset, and not one of the aborted ones

[Perryg]

Let us know.

[fixedwheel]

My concern is that I'm using 2.0.6 and don't want to change versions.

JFTR there is a a newer 2.0.8 bugfix release, you dont need to change version
http://download.virtualbox.org/virtualbox/2.0.8/