Solaris 10 Host reboot - after kernel panic...

[JensMR]

After patching our Solaris System 10 with the actual patch cluster (21.5.2012) and updating VirtualBox to version 4.1.16 our server crashes. In the system messages we always find the attached message ahead of the crash. The referenced CPU number varies and so do the addresses. But the rest is 'stable'.

Since January we used VirtualBox v4.1.8 without any crashes. And after having troubles with version 4.1.16 I reinstalled v4.1.8 but the crashes persist.

System is a SunFire X4600M2 with 8 sockets (Opteron 8356) and 256GB ECC memory. No hardware changes between the running and the crashing system.

The guest systems did not change (predominant is WinXP, but linux systems are also running -- sometimes). The logfiles of the users VMs do not show additional messages. It does not seem to be load-dependent - right now only a small number of users is working on the system (load < 20%).

Did somebody else experience this? Any ideas? Please let me know, if you need additional logfiles, stats or data.

[JensMR]

extract of message log

[JensMR]

extract of message log (VirtBox 4.1.8)

[JensMR]

extract of message log (VirtBox 4.1.16)

[Ramshankar Venkataraman]

Could you please upload VBox.log for the VM that ran when the kernel panicked?

[JensMR]

vbox.log files 04.06.2012 separated by =====

[JensMR]

vbox.log files 06.06.2012 separated by =====

[JensMR]

You will find two new files attached. Each one containing the vbox.log files of the open sessions at the relevant date and time. Within the attached files the logfiles are separated by ===========

Replying to ramshankar:

Could you please upload VBox.log for the VM that ran when the kernel panicked?

[JensMR]

New errors with the new patchset. Previously installing a patch (147441-??) fixed the problem - at least until I installed the recommended patchset from December. Now the problem is back - but this time it is only after having installed the patchset, no changes to VirtualBox.

The following lines are from the messages file and show what's been happening the first time the system crashed (last lines show the boot process) :

Dec 28 11:12:11 mri002 xscreensaver[3933]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 11:21:02 mri002 xscreensaver[9619]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 11:32:44 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0CleanupVM: hGVM=0x2 left 0x3 shared pages behind! Dec 28 12:02:05 mri002 xscreensaver[3933]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 12:11:04 mri002 dtlogin[13109]: [ID 699796 user.error] sunray_get_user:pam_sm_auth: pam_get_user returned 6 (PAM_CONV_ERR) Dec 28 12:45:15 mri002 xscreensaver[17142]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 12:50:24 mri002 xscreensaver[18903]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 12:51:32 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0CleanupVM: hGVM=0x2 left 0x3 shared pages behind! Dec 28 13:07:54 mri002 xscreensaver[17142]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 13:47:53 mri002 xscreensaver[25097]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 13:51:46 mri002 xscreensaver[3933]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 14:47:15 mri002 xscreensaver[3242]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 28 14:59:40 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0CleanupVM: hGVM=0x2 left 0x9 shared pages behind! Dec 28 15:50:42 mri002 genunix: [ID 540533 kern.notice] ^{MSunOS Release 5.10 Version Generic_147441-27 64-bit Dec 28 15:50:42 mri002 genunix: [ID 459285 kern.notice] Copyright (c) 1983, 2012, Oracle and/or its affiliates. All rights reserved.}

The second crash shows a Panic (again the last lines show the boot process):

Dec 31 10:08:00 mri002 dtlogin[9052]: [ID 699796 user.error] sunray_get_user:pam_sm_auth: pam_get_user returned 6 (PAM_CONV_ERR) Dec 31 10:08:03 mri002 last message repeated 1 time Dec 31 10:35:29 mri002 xscreensaver[23159]: [ID 508707 user.error] pam_sunray:get_auth_perm: ut_setproperties username returned -1 Dec 31 11:02:30 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0CleanupVM: hGVM=0x1 left 0x28 shared pages behind! Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffec2ee3f1010/0x6: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffec3c7ce7010/0xe: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee12dc93010/0xac: cFree=505 cPrivate=0 cShared=7 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffec33fddc010/0x12: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee125487010/0x6ba: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffec2d9937010/0x6b4: cFree=510 cPrivate=0 cShared=2 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee123455010/0x6c2: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee12141f010/0x6e8: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee11f3fd010/0x706: cFree=508 cPrivate=0 cShared=4 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee11f407010/0x710: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee11f3ff010/0x708: cFree=504 cPrivate=0 cShared=8 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee121425010/0x6ee: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee125489010/0x6bc: cFree=510 cPrivate=0 cShared=2 cMappings=0 Dec 31 11:02:31 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee12dc99010/0xae: cFree=503 cPrivate=0 cShared=9 cMappings=0 Dec 31 11:34:32 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0CleanupVM: hGVM=0x1 left 0x3 shared pages behind! Dec 31 11:34:33 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee121425010/0x6b4: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:34:33 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee123465010/0x744: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 11:34:33 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee123469010/0x740: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 12:33:00 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0CleanupVM: hGVM=0x1 left 0x11 shared pages behind! Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffec374f66010/0xa: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee125485010/0x6b2: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee12bc75010/0x7da: cFree=507 cPrivate=0 cShared=5 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffec2ef53e010/0x7cc: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee0ba155010/0xe: cFree=509 cPrivate=0 cShared=3 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee11f3fd010/0x7fc: cFree=509 cPrivate=0 cShared=3 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: ffffffffe341b010/0x800: cFree=510 cPrivate=0 cShared=2 cMappings=0 Dec 31 12:33:01 mri002 vboxdrv: [ID 702911 kern.notice] GMMR0Term: fffffee12dc93010/0x7f2: cFree=511 cPrivate=0 cShared=1 cMappings=0 Dec 31 14:22:16 mri002 genunix: [ID 702911 kern.notice] enmKind=24 iShw=59 Dec 31 14:22:16 mri002 unix: [ID 836849 kern.notice] Dec 31 14:22:16 mri002 ^{Mpanic[cpu12]/thread=fffffee15544dc00: Dec 31 14:22:16 mri002 genunix: [ID 403854 kern.notice] assertion failed: enmKind=24 iShw=59 Dec 31 14:22:16 mri002 , file: /home/vbox/tinderbox/4.1-sol-rel/src/VBox/VMM/VMMAll/PGMAllPool.cpp, line: 3332 Dec 31 14:22:17 mri002 unix: [ID 100000 kern.notice] Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daa820 fffffffffba42e43 () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daa830 vboxdrv:RTR0AssertPanicSystem+9a () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daa870 fffffffff856863d () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daa8d0 fffffffff8568c0e () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daa930 fffffffff8568d10 () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daa9e0 fffffffff853cdb8 () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daa9f0 fffffffff852e73e () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daab20 fffffffff857a949 () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daab70 fffffffff852e7f7 () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daaba0 fffffffff853e621 () Dec 31 14:22:17 mri002 genunix: [ID 802836 kern.notice] fffffe8003daabe0 fffffffff853ed6b () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daace0 vboxdrv:supdrvIOCtl+13e6 () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daadb0 vboxdrv:VBoxDrvSolarisIOCtl+3b9 () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daadc0 genunix:cdev_ioctl+1d () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daade0 specfs:spec_ioctl+50 () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daae20 genunix:fop_ioctl+2e () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daaf00 genunix:ioctl+ac () Dec 31 14:22:17 mri002 genunix: [ID 655072 kern.notice] fffffe8003daaf10 unix:brand_sys_syscall+21d () Dec 31 14:22:17 mri002 unix: [ID 100000 kern.notice] Dec 31 14:22:17 mri002 genunix: [ID 672855 kern.notice] syncing file systems... Dec 31 14:22:27 mri002 genunix: [ID 904073 kern.notice] done Dec 31 14:22:28 mri002 genunix: [ID 111219 kern.notice] dumping to /dev/zvol/dsk/rpool/dump, offset 65536, content: kernel Dec 31 14:24:42 mri002 genunix: [ID 100000 kern.notice] Dec 31 14:24:42 mri002 genunix: [ID 665016 kern.notice]} M 4% done: 1634425 pages dumped, Dec 31 14:24:42 mri002 genunix: [ID 495082 kern.notice] dump failed: error 28 Jan 1 15:05:59 mri002 genunix: [ID 540533 kern.notice] ^{MSunOS Release 5.10 Version Generic_147441-27 64-bit Jan 1 15:05:59 mri002 genunix: [ID 459285 kern.notice] Copyright (c) 1983, 2012, Oracle and/or its affiliates. All rights reserved.}

So it seems to be the same error message as in June...

[JensMR]

extract of messages after system crash

[JensMR]

extract of messages after system crash #2

[Frank Mehnert]

Can you be more specific about the patchset you installed? We need a scenario to reproduce the problem and the VBox version for which you saw the problem. A VBox.log of such a VM session would also be helpful.

[JensMR]

Replying to frank:

Can you be more specific about the patchset you installed? We need a scenario to reproduce the problem and the VBox version for which you saw the problem. A VBox.log of such a VM session would also be helpful.

The patchset is the recommended patchset for Oracle Solaris (x86-64):

Title on Oracle Support website: "Patch Recommended OS Patchset Solaris 10 x86: Recommended Patchset for Solaris 10 x86 (Solaris Operating System patches only)"

Last Updated	19-Dec-2012 13:00
Product	Solaris Operating System
Release	Solaris 10 Operating System
Platform	Oracle Solaris on x86-64 (64-bit)		

After installation we have "SunOS mri000 5.10 Generic_147441-27 i86pc i386 i86pc"

The installed VirtualBox worked fine from June until December 27th. After installing the Solaris patchset the whole system crashes - not only the VirtualBox-Processes.

pkginfo -l SUNWvbox gives me (comment for hotline and email removed):

   PKGINST:  SUNWvbox
      NAME:  Oracle VM VirtualBox
  CATEGORY:  application
      ARCH:  i386
   VERSION:  4.1.16,REV=2012.05.22.15.07.78094
   BASEDIR:  /
    VENDOR:  Oracle Corporation
      DESC:  A powerful PC virtualization solution
    PSTAMP:  vbox20120522150817_r78094
  INSTDATE:  Jun 08 2012 15:59
    STATUS:  completely installed
     FILES:      427 installed pathnames
                  10 linked files
                  22 directories
                  43 executables
                  12 setuid/setgid executables
              500411 blocks used (approx)

VBox.log files will be uploaded soon...

[JensMR]

Series of VBOX.log of different users...

[JensMR]

Series of VBOX.log of different users...

[JensMR]

The VBOX.log file has been added twice...

[Frank Mehnert]

Thanks for the logs. Btw, the files VBOX.logs and VBOX.2.logs have the same content.

[aeichner]

Please reopen if still relevant with a recent VirtualBox release.