VirtualBox

Opened 11 years ago

Closed 10 years ago

#11481 closed defect (duplicate)

Weird behaviour

Reported by: Grimeton Owned by:
Component: VMM Version: VirtualBox 4.2.6
Keywords: Cc:
Guest type: all Host type: all

Description

Hello,

I know the topic isn't very clear, but that's what this whole thing is:

Sometimes processes in the guest are producing segfaults or exit without any reasons and fail. I can see this on Linux and on OS X hosts. Windows XP (guest) is sometimes affected, Windows 7 (guest) doesn't make it past the Windows Update installs without having the update service killed multiple times. It sometimes even produces a blue screen when you activate the guest (Windows license activation).

The main reason I didn't report the problem earlier was that I am unable to reproduce it. A few days ago someone else reported similar behaviour of his VMs on a Windows 7 Host, which could be solved by the same procedure I'm going to write about later, so I decided to file a bug report.

What happens is that the processes inside the guests fail. If you power the guest down and start it again (no reboot, new instance of Virtualbox), you still get the same error inside the guest. The only way around it, ist to power down the "broken" guest, start another VM, so that it allocates memory on the host, and then start the guest again (while the other VM is still running). After doing this, the guest starts to work properly again, as it now uses a different part of the host's memory (afaik).

In Windows 7 the update service fails, or .NET assemblies stop working from one second to another. On Linux guest you get all kinds of segfaults in all processes. Interesting is that you don't get a kernel core dump, all processes reside in user land. It's also independent of the memory the guest can use. I see it from machines with less than 256mb of Memory and up to 8GB and more of Memory.

The memory on my machines has been checked and everything is fine.

I'm sorry that I don't have any further information. If you have questions feel free to contact me.

Attachements: IRC log of #vbox

KR,

Oliver

Attachments (5)

irlog.txt (3.9 KB ) - added by Grimeton 11 years ago.
IRC Log of #vbox
VBox.log (53.1 KB ) - added by Grimeton 11 years ago.
Log file of linux machine
VBox.2.log (50.1 KB ) - added by Grimeton 11 years ago.
VBox.log of the Windows 7 VM in trouble
memtest86.jpg (104.6 KB ) - added by Grimeton 11 years ago.
Results of memtest
VBox.3.log (51.9 KB ) - added by Grimeton 11 years ago.
VBox.Log for the latest entry

Download all attachments as: .zip

Change History (31)

by Grimeton, 11 years ago

Attachment: irlog.txt added

IRC Log of #vbox

comment:1 by Grimeton, 11 years ago

I can see this on Windows 7 Ultimate x64 now too

comment:2 by Grimeton, 11 years ago

Another user reported similar issues. He also gets randomly corrupted files when storing stuff to a shared folder.

comment:3 by Grimeton, 11 years ago

After this is visible in dmesg, the Windows 7 machine becomes really slow:

[70768.756306] device vmbr2 entered promiscuous mode
[70780.497805] EMT-1: page allocation failure: order:9, mode:0x344d2
[70780.497809] Pid: 10244, comm: EMT-1 Tainted: G           O 3.6.0-030600-generic #201209302035
[70780.497809] Call Trace:
[70780.497815]  [<ffffffff81132496>] warn_alloc_failed+0xf6/0x150
[70780.497818]  [<ffffffff8168802a>] ? __alloc_pages_direct_compact+0x1a7/0x1b9
[70780.497820]  [<ffffffff811362be>] __alloc_pages_nodemask+0x76e/0x9b0
[70780.497836]  [<ffffffff8116edb6>] alloc_pages_current+0xb6/0x120
[70780.497844]  [<ffffffffa05fcab0>] rtR0MemObjLinuxAllocPages+0xc0/0x260 [vboxdrv]
[70780.497848]  [<ffffffffa05fcc8a>] rtR0MemObjLinuxAllocPhysSub2+0x3a/0xe0 [vboxdrv]
[70780.497852]  [<ffffffff81044c39>] ? default_spin_lock_flags+0x9/0x10
[70780.497856]  [<ffffffffa05fcdfa>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[70780.497861]  [<ffffffffa05fd1c9>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[70780.497865]  [<ffffffffa05fb074>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xb0 [vboxdrv]
[70780.497874]  [<ffffffffa05f3b2e>] ? supdrvIOCtl+0x152e/0x2a90 [vboxdrv]
[70780.497879]  [<ffffffffa05fc5dd>] ? rtR0MemAllocEx+0x17d/0x250 [vboxdrv]
[70780.497883]  [<ffffffffa05ee448>] ? VBoxDrvLinuxIOCtl_4_2_6+0x118/0x1f0 [vboxdrv]
[70780.497886]  [<ffffffff8119857a>] ? do_vfs_ioctl+0x8a/0x340
[70780.497888]  [<ffffffff811988c1>] ? sys_ioctl+0x91/0xa0
[70780.497890]  [<ffffffff816a6a69>] ? system_call_fastpath+0x16/0x1b
[70780.497891] Mem-Info:
[70780.497891] Node 0 DMA per-cpu:
[70780.497893] CPU    0: hi:    0, btch:   1 usd:   0
[70780.497894] CPU    1: hi:    0, btch:   1 usd:   0
[70780.497895] CPU    2: hi:    0, btch:   1 usd:   0
[70780.497896] CPU    3: hi:    0, btch:   1 usd:   0
[70780.497896] CPU    4: hi:    0, btch:   1 usd:   0
[70780.497897] CPU    5: hi:    0, btch:   1 usd:   0
[70780.497898] CPU    6: hi:    0, btch:   1 usd:   0
[70780.497899] CPU    7: hi:    0, btch:   1 usd:   0
[70780.497899] Node 0 DMA32 per-cpu:
[70780.497900] CPU    0: hi:  186, btch:  31 usd:   0
[70780.497901] CPU    1: hi:  186, btch:  31 usd:   0
[70780.497902] CPU    2: hi:  186, btch:  31 usd:   0
[70780.497903] CPU    3: hi:  186, btch:  31 usd:   0
[70780.497904] CPU    4: hi:  186, btch:  31 usd:   0
[70780.497904] CPU    5: hi:  186, btch:  31 usd:   0
[70780.497905] CPU    6: hi:  186, btch:  31 usd:   0
[70780.497906] CPU    7: hi:  186, btch:  31 usd:   0
[70780.497907] Node 0 Normal per-cpu:
[70780.497908] CPU    0: hi:  186, btch:  31 usd:   0
[70780.497908] CPU    1: hi:  186, btch:  31 usd:   0
[70780.497909] CPU    2: hi:  186, btch:  31 usd:   0
[70780.497910] CPU    3: hi:  186, btch:  31 usd:   0
[70780.497911] CPU    4: hi:  186, btch:  31 usd:   0
[70780.497911] CPU    5: hi:  186, btch:  31 usd:   0
[70780.497912] CPU    6: hi:  186, btch:  31 usd:   0
[70780.497913] CPU    7: hi:  186, btch:  31 usd:   0
[70780.497915] active_anon:39471 inactive_anon:2682 isolated_anon:0
[70780.497915]  active_file:3589592 inactive_file:3130528 isolated_file:0
[70780.497915]  unevictable:0 dirty:16 writeback:0 unstable:0
[70780.497915]  free:81431 slab_reclaimable:194364 slab_unreclaimable:16551
[70780.497915]  mapped:68909 shmem:2098 pagetables:3332 bounce:0
[70780.497916] Node 0 DMA free:15900kB min:32kB low:40kB high:48kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15644kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[70780.497919] lowmem_reserve[]: 0 2905 32135 32135
[70780.497921] Node 0 DMA32 free:136500kB min:6108kB low:7632kB high:9160kB active_anon:2180kB inactive_anon:904kB active_file:1126344kB inactive_file:1126460kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2975592kB mlocked:0kB dirty:0kB writeback:0kB mapped:10592kB shmem:0kB slab_reclaimable:68700kB slab_unreclaimable:200kB kernel_stack:8kB pagetables:44kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[70780.497924] lowmem_reserve[]: 0 0 29230 29230
[70780.497925] Node 0 Normal free:173324kB min:61440kB low:76800kB high:92160kB active_anon:155704kB inactive_anon:9824kB active_file:13232024kB inactive_file:11395652kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:29931552kB mlocked:0kB dirty:64kB writeback:0kB mapped:265044kB shmem:8392kB slab_reclaimable:708756kB slab_unreclaimable:66004kB kernel_stack:2800kB pagetables:13284kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[70780.497928] lowmem_reserve[]: 0 0 0 0
[70780.497930] Node 0 DMA: 1*4kB 1*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15900kB
[70780.497934] Node 0 DMA32: 988*4kB 952*8kB 722*16kB 395*32kB 295*64kB 267*128kB 69*256kB 33*512kB 11*1024kB 1*2048kB 0*4096kB = 136688kB
[70780.497938] Node 0 Normal: 1492*4kB 1402*8kB 886*16kB 283*32kB 154*64kB 165*128kB 170*256kB 100*512kB 5*1024kB 1*2048kB 0*4096kB = 173280kB
[70780.497942] 6722294 total pagecache pages
[70780.497943] 0 pages in swap cache
[70780.497944] Swap cache stats: add 0, delete 0, find 0/0
[70780.497945] Free swap  = 33553332kB
[70780.497945] Total swap = 33553332kB
[70780.545808] 8388080 pages RAM
[70780.545810] 1301006 pages reserved
[70780.545811] 6669509 pages shared
[70780.545811] 352615 pages non-shared

The machine has 32Gig of memory and not even a quarter of it is used:

             total       used       free     shared    buffers     cached
Mem:           31G        26G       4.5G         0B        12K        21G
-/+ buffers/cache:       5.2G        26G
Swap:          31G         0B        31G

Yes, there is a huge filesystem cache, but that's always the case.

comment:4 by Grimeton, 11 years ago

In Windows I can see errors like these:

Possible Memory Leak. Application (C:\Windows\System32\svchost.exe -k LocalServiceNetworkRestricted) (PID: 836) has passed a non-NULL pointer to RPC for an [out] parameter marked [allocate(all_nodes)]. [allocate(all_nodes)] parameters are always reallocated; if the original pointer contained the address of valid memory, that memory will be leaked. The call originated on the interface with UUID ({3f31c91e-2545-4b7b-9311-9529e8bffef6}), Method number (20). User Action: Contact your application vendor for an updated version of the application.

Faulting application name: TrustedInstaller.exe, version: 6.1.7601.17514, time stamp: 0x4ce7989b Faulting module name: wcp.dll, version: 6.1.7601.17514, time stamp: 0x4ce7c9f2 Exception code: 0xc0000005 Fault offset: 0x0000000000222aa4 Faulting process id: 0x938 Faulting application start time: 0x01ce0b0786cc84f0 Faulting application path: C:\Windows\servicing\TrustedInstaller.exe Faulting module path: C:\Windows\winsxs\amd64_microsoft-windows-servicingstack_31bf3856ad364e35_6.1.7601.17514_none_678566b7ddea04a5\wcp.dll Report Id: faeb0406-76fa-11e2-968f-08002753d7d5

Event filter with query "SELECT * FROM InstanceModificationEvent WITHIN 60 WHERE TargetInstance ISA "Win32_Processor" AND TargetInstance.LoadPercentage > 99" could not be reactivated in namespace "./root/CIMV2" because of error 0x80041003. Events cannot be delivered through this filter until the problem is corrected.

===

It gets worse up to memory corruption errors from Windows.

As always: the moment you try to reproduce it, it's not showing...

Version 0, edited 11 years ago by Grimeton (next)

comment:5 by Grimeton, 11 years ago

[410338.801517] Pid: 3284, comm: EMT-0 Tainted: G           O 3.6.0-030600-generic #201209302035
[410338.801518] Call Trace:
[410338.801523]  [<ffffffff81132496>] warn_alloc_failed+0xf6/0x150
[410338.801527]  [<ffffffff8168802a>] ? __alloc_pages_direct_compact+0x1a7/0x1b9
[410338.801528]  [<ffffffff811362be>] __alloc_pages_nodemask+0x76e/0x9b0
[410338.801532]  [<ffffffff8116edb6>] alloc_pages_current+0xb6/0x120
[410338.801540]  [<ffffffffa05fcab0>] rtR0MemObjLinuxAllocPages+0xc0/0x260 [vboxdrv]
[410338.801545]  [<ffffffffa05fcc8a>] rtR0MemObjLinuxAllocPhysSub2+0x3a/0xe0 [vboxdrv]
[410338.801548]  [<ffffffff81044c39>] ? default_spin_lock_flags+0x9/0x10
[410338.801552]  [<ffffffffa05fcdfa>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[410338.801556]  [<ffffffffa05fd1c9>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[410338.801561]  [<ffffffffa05fb074>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xb0 [vboxdrv]
[410338.801580]  [<ffffffffa05f3b2e>] ? supdrvIOCtl+0x152e/0x2a90 [vboxdrv]
[410338.801584]  [<ffffffffa05fc5dd>] ? rtR0MemAllocEx+0x17d/0x250 [vboxdrv]
[410338.801589]  [<ffffffffa05ee448>] ? VBoxDrvLinuxIOCtl_4_2_6+0x118/0x1f0 [vboxdrv]
[410338.801592]  [<ffffffff8119857a>] ? do_vfs_ioctl+0x8a/0x340
[410338.801594]  [<ffffffff810b4d77>] ? sys_futex+0x147/0x1a0
[410338.801596]  [<ffffffff811988c1>] ? sys_ioctl+0x91/0xa0
[410338.801598]  [<ffffffff816a6a69>] ? system_call_fastpath+0x16/0x1b
[410338.801599] Mem-Info:
[410338.801599] Node 0 DMA per-cpu:
[410338.801601] CPU    0: hi:    0, btch:   1 usd:   0
[410338.801602] CPU    1: hi:    0, btch:   1 usd:   0
[410338.801603] CPU    2: hi:    0, btch:   1 usd:   0
[410338.801603] CPU    3: hi:    0, btch:   1 usd:   0
[410338.801604] CPU    4: hi:    0, btch:   1 usd:   0
[410338.801605] CPU    5: hi:    0, btch:   1 usd:   0
[410338.801606] CPU    6: hi:    0, btch:   1 usd:   0
[410338.801606] CPU    7: hi:    0, btch:   1 usd:   0
[410338.801607] Node 0 DMA32 per-cpu:
[410338.801608] CPU    0: hi:  186, btch:  31 usd:   0
[410338.801609] CPU    1: hi:  186, btch:  31 usd:   0
[410338.801610] CPU    2: hi:  186, btch:  31 usd:   0
[410338.801611] CPU    3: hi:  186, btch:  31 usd:   0
[410338.801612] CPU    4: hi:  186, btch:  31 usd:   0
[410338.801612] CPU    5: hi:  186, btch:  31 usd:   0
[410338.801613] CPU    6: hi:  186, btch:  31 usd:   0
[410338.801614] CPU    7: hi:  186, btch:  31 usd:   0
[410338.801614] Node 0 Normal per-cpu:
[410338.801615] CPU    0: hi:  186, btch:  31 usd:   0
[410338.801616] CPU    1: hi:  186, btch:  31 usd:   0
[410338.801617] CPU    2: hi:  186, btch:  31 usd:   0
[410338.801618] CPU    3: hi:  186, btch:  31 usd:   0
[410338.801618] CPU    4: hi:  186, btch:  31 usd:   0
[410338.801619] CPU    5: hi:  186, btch:  31 usd:   0
[410338.801620] CPU    6: hi:  186, btch:  31 usd:   0
[410338.801621] CPU    7: hi:  186, btch:  31 usd:   0
[410338.801623] active_anon:43199 inactive_anon:3426 isolated_anon:0
[410338.801623]  active_file:3453681 inactive_file:3453752 isolated_file:0
[410338.801623]  unevictable:0 dirty:933 writeback:0 unstable:0
[410338.801623]  free:82515 slab_reclaimable:156210 slab_unreclaimable:15934
[410338.801623]  mapped:67726 shmem:2099 pagetables:3114 bounce:0

And again. Now I can see a damaged Filesystem.

Last edited 11 years ago by Grimeton (previous) (diff)

comment:6 by Grimeton, 11 years ago

RROR: build v8 from SVN failed: code=2
DEBUG: <built-in>:0:0: internal compiler error: Segmentation fault
Please submit a full bug report,
with preprocessed source if appropriate.
See <file:///usr/share/doc/gcc-4.7/README.Bugs> for instructions.
The bug is not reproducible, so it is likely a hardware or OS problem.
make[1]: *** [/usr/src/v8/pyv8/build/v8/out/x64.release/obj.target/preparser_lib/src/once.o] Error 1
make: *** [x64.release] Error 2

restarting the build and it works.

comment:7 by Frank Mehnert, 11 years ago

Please attach a VBox.log file of your VM to this ticket. This is mainly to get the VM configuration.

comment:8 by Grimeton, 11 years ago

malloc: ../bash/arrayfunc.c:164: assertion botched
free: start and end chunk sizes differ
last command: ls
Aborting...

The thing is: It happens accross multiple VMs on different hosts.

I'll attach the logfile of the machine that is now in memory trouble. I see weird filesystem messages, tmux just segfaulted and took everything with it and the bash isn't even able todo any command completion.

by Grimeton, 11 years ago

Attachment: VBox.log added

Log file of linux machine

comment:9 by Frank Mehnert, 11 years ago

Some unrelated information: Your extpack is still at 4.2.0, better update it to 4.2.6 -- but this should be really unrelated to your problem.

Recently we fixed a problem which looks a bit like your weird guest behavior but it could be only triggered with bigger guest RAM configurations. So I doubt that this is really the same problem but could you test this build anyway? Thank you!

comment:10 by Grimeton, 11 years ago

I installed the suggested build and after starting a Windows 7 VM, this appeared in dmesg:

[1101762.826765] EMT-0: page allocation failure: order:9, mode:0x344d2
[1101762.826769] Pid: 12021, comm: EMT-0 Tainted: G           O 3.6.0-030600-generic #201209302035
[1101762.826770] Call Trace:
[1101762.826776]  [<ffffffff81132496>] warn_alloc_failed+0xf6/0x150
[1101762.826778]  [<ffffffff81134cf6>] ? drain_local_pages+0x16/0x20
[1101762.826780]  [<ffffffff810b64b0>] ? on_each_cpu_mask+0x50/0x70
[1101762.826782]  [<ffffffff811362be>] __alloc_pages_nodemask+0x76e/0x9b0
[1101762.826785]  [<ffffffff8116edb6>] alloc_pages_current+0xb6/0x120
[1101762.826795]  [<ffffffffa0703ab0>] rtR0MemObjLinuxAllocPages+0xc0/0x260 [vboxdrv]
[1101762.826799]  [<ffffffffa0703c8a>] rtR0MemObjLinuxAllocPhysSub2+0x3a/0xe0 [vboxdrv]
[1101762.826802]  [<ffffffff81044c39>] ? default_spin_lock_flags+0x9/0x10
[1101762.826807]  [<ffffffffa0703dfa>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[1101762.826811]  [<ffffffffa07041c9>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[1101762.826816]  [<ffffffffa0702074>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xb0 [vboxdrv]
[1101762.826840]  [<ffffffffa06fab2e>] ? supdrvIOCtl+0x152e/0x2a90 [vboxdrv]
[1101762.826845]  [<ffffffffa07035dd>] ? rtR0MemAllocEx+0x17d/0x250 [vboxdrv]
[1101762.826850]  [<ffffffffa06f5448>] ? VBoxDrvLinuxIOCtl_4_2_7+0x118/0x1f0 [vboxdrv]
[1101762.826852]  [<ffffffff810135fa>] ? __switch_to+0x17a/0x410
[1101762.826855]  [<ffffffff81092ff0>] ? set_next_entity+0xa0/0xc0
[1101762.826859]  [<ffffffff8119857a>] ? do_vfs_ioctl+0x8a/0x340
[1101762.826861]  [<ffffffff8169cc8b>] ? __schedule+0x3bb/0x6f0
[1101762.826862]  [<ffffffff810b4d77>] ? sys_futex+0x147/0x1a0
[1101762.826864]  [<ffffffff811988c1>] ? sys_ioctl+0x91/0xa0
[1101762.826867]  [<ffffffff816a6a69>] ? system_call_fastpath+0x16/0x1b
[1101762.826868] Mem-Info:
[1101762.826868] Node 0 DMA per-cpu:
[1101762.826870] CPU    0: hi:    0, btch:   1 usd:   0
[1101762.826871] CPU    1: hi:    0, btch:   1 usd:   0
[1101762.826871] CPU    2: hi:    0, btch:   1 usd:   0
[1101762.826872] CPU    3: hi:    0, btch:   1 usd:   0
[1101762.826873] CPU    4: hi:    0, btch:   1 usd:   0
[1101762.826874] CPU    5: hi:    0, btch:   1 usd:   0
[1101762.826874] CPU    6: hi:    0, btch:   1 usd:   0
[1101762.826875] CPU    7: hi:    0, btch:   1 usd:   0
[1101762.826876] Node 0 DMA32 per-cpu:
[1101762.826877] CPU    0: hi:  186, btch:  31 usd:  35
[1101762.826878] CPU    1: hi:  186, btch:  31 usd:   0
[1101762.826879] CPU    2: hi:  186, btch:  31 usd:   0
[1101762.826879] CPU    3: hi:  186, btch:  31 usd:   0
[1101762.826880] CPU    4: hi:  186, btch:  31 usd:   0
[1101762.826881] CPU    5: hi:  186, btch:  31 usd:   0
[1101762.826882] CPU    6: hi:  186, btch:  31 usd:   0
[1101762.826883] CPU    7: hi:  186, btch:  31 usd:   0
[1101762.826883] Node 0 Normal per-cpu:
[1101762.826884] CPU    0: hi:  186, btch:  31 usd: 155
[1101762.826885] CPU    1: hi:  186, btch:  31 usd:   0
[1101762.826886] CPU    2: hi:  186, btch:  31 usd:   0
[1101762.826887] CPU    3: hi:  186, btch:  31 usd:   0
[1101762.826887] CPU    4: hi:  186, btch:  31 usd:   0
[1101762.826888] CPU    5: hi:  186, btch:  31 usd:   0
[1101762.826889] CPU    6: hi:  186, btch:  31 usd:   0
[1101762.826890] CPU    7: hi:  186, btch:  31 usd:   0
[1101762.826892] active_anon:40425 inactive_anon:3182 isolated_anon:0
[1101762.826892]  active_file:3595355 inactive_file:3945491 isolated_file:0
[1101762.826892]  unevictable:0 dirty:26 writeback:0 unstable:0
[1101762.826892]  free:74030 slab_reclaimable:155576 slab_unreclaimable:12336
[1101762.826892]  mapped:179302 shmem:2102 pagetables:1965 bounce:0
[1101762.826893] Node 0 DMA free:15900kB min:32kB low:40kB high:48kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15644kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[1101762.826896] lowmem_reserve[]: 0 2905 32135 32135
[1101762.826898] Node 0 DMA32 free:137856kB min:6108kB low:7632kB high:9160kB active_anon:0kB inactive_anon:124kB active_file:1182992kB inactive_file:1185268kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2975592kB mlocked:0kB dirty:0kB writeback:0kB mapped:13228kB shmem:0kB slab_reclaimable:91656kB slab_unreclaimable:3224kB kernel_stack:8kB pagetables:36kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scan
ned:0 all_unreclaimable? no
[1101762.826901] lowmem_reserve[]: 0 0 29230 29230
[1101762.826903] Node 0 Normal free:142364kB min:61440kB low:76800kB high:92160kB active_anon:161700kB inactive_anon:12604kB active_file:13198428kB inactive_file:14596696kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:29931552kB mlocked:0kB dirty:104kB writeback:0kB mapped:703980kB shmem:8408kB slab_reclaimable:530648kB slab_unreclaimable:46120kB kernel_stack:2672kB pagetables:7824kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1101762.826906] lowmem_reserve[]: 0 0 0 0
[1101762.826907] Node 0 DMA: 1*4kB 1*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15900kB
[1101762.826912] Node 0 DMA32: 1878*4kB 375*8kB 71*16kB 195*32kB 199*64kB 154*128kB 81*256kB 65*512kB 31*1024kB 1*2048kB 0*4096kB = 138144kB
[1101762.826916] Node 0 Normal: 14337*4kB 6694*8kB 1032*16kB 84*32kB 47*64kB 1*128kB 1*256kB 0*512kB 9*1024kB 0*2048kB 0*4096kB = 142708kB
[1101762.826921] 7542964 total pagecache pages
[1101762.826921] 0 pages in swap cache
[1101762.826922] Swap cache stats: add 0, delete 0, find 0/0
[1101762.826923] Free swap  = 33553332kB
[1101762.826924] Total swap = 33553332kB
[1101762.885835] 8388080 pages RAM
[1101762.885837] 526247 pages reserved
[1101762.885837] 3906604 pages shared
[1101762.885838] 3898660 pages non-shared

And the Windows 7 VM is becoming extremely slow again.

The Linux VM seems to work, but I wouldn't rely on that so far.

by Grimeton, 11 years ago

Attachment: VBox.2.log added

VBox.log of the Windows 7 VM in trouble

comment:11 by Grimeton, 11 years ago

I don't know if this is important or not:

I installed a new Windows 7 Ultimate VM in english to be able to provide english screenshots and error messages. The installation went just fine, all updates installed, everything else ok.

Then I created the "7basede" VM which is in trouble now.

The errors I've seen before are all inside the german edition of 7 Ultimate.

Kinda weird, but can also just be a pure coincidence.

comment:12 by Grimeton, 11 years ago

After the Installation of Windows 7 copied all files from the DVD to the harddrive and rebooted, it produced a blue screen during stage 2 of the installation and did a reset. After that one can read "The installation failed somewhere in the installation process, please reboot and run the installation again" on the monitor.

Rebooting from the harddrive doesn't help, so the only way is to redo the complete installation.

Powering the VM down and starting it again to run the install produced the following while it was copying the files over:

[1103154.012120] EMT-1: page allocation failure: order:9, mode:0x344d2
[1103154.012123] Pid: 12467, comm: EMT-1 Tainted: G           O 3.6.0-030600-generic #201209302035
[1103154.012124] Call Trace:
[1103154.012129]  [<ffffffff81132496>] warn_alloc_failed+0xf6/0x150
[1103154.012132]  [<ffffffff810b6497>] ? on_each_cpu_mask+0x37/0x70
[1103154.012134]  [<ffffffff811362be>] __alloc_pages_nodemask+0x76e/0x9b0
[1103154.012151]  [<ffffffff8116edb6>] alloc_pages_current+0xb6/0x120
[1103154.012158]  [<ffffffffa0703ab0>] rtR0MemObjLinuxAllocPages+0xc0/0x260 [vboxdrv]
[1103154.012163]  [<ffffffffa0703c8a>] rtR0MemObjLinuxAllocPhysSub2+0x3a/0xe0 [vboxdrv]
[1103154.012166]  [<ffffffff81044c39>] ? default_spin_lock_flags+0x9/0x10
[1103154.012170]  [<ffffffffa0703dfa>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[1103154.012175]  [<ffffffffa07041c9>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[1103154.012180]  [<ffffffffa0702074>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xb0 [vboxdrv]
[1103154.012189]  [<ffffffffa06fab2e>] ? supdrvIOCtl+0x152e/0x2a90 [vboxdrv]
[1103154.012193]  [<ffffffffa07035dd>] ? rtR0MemAllocEx+0x17d/0x250 [vboxdrv]
[1103154.012198]  [<ffffffffa06f5448>] ? VBoxDrvLinuxIOCtl_4_2_7+0x118/0x1f0 [vboxdrv]
[1103154.012201]  [<ffffffff8119857a>] ? do_vfs_ioctl+0x8a/0x340
[1103154.012203]  [<ffffffff811988c1>] ? sys_ioctl+0x91/0xa0
[1103154.012205]  [<ffffffff816a6a69>] ? system_call_fastpath+0x16/0x1b
[1103154.012206] Mem-Info:
[1103154.012207] Node 0 DMA per-cpu:
[1103154.012208] CPU    0: hi:    0, btch:   1 usd:   0
[1103154.012209] CPU    1: hi:    0, btch:   1 usd:   0
[1103154.012210] CPU    2: hi:    0, btch:   1 usd:   0
[1103154.012211] CPU    3: hi:    0, btch:   1 usd:   0
[1103154.012212] CPU    4: hi:    0, btch:   1 usd:   0
[1103154.012212] CPU    5: hi:    0, btch:   1 usd:   0
[1103154.012213] CPU    6: hi:    0, btch:   1 usd:   0
[1103154.012214] CPU    7: hi:    0, btch:   1 usd:   0
[1103154.012214] Node 0 DMA32 per-cpu:
[1103154.012216] CPU    0: hi:  186, btch:  31 usd:   0
[1103154.012217] CPU    1: hi:  186, btch:  31 usd:   0
[1103154.012217] CPU    2: hi:  186, btch:  31 usd:   0
[1103154.012218] CPU    3: hi:  186, btch:  31 usd:   0
[1103154.012219] CPU    4: hi:  186, btch:  31 usd:   0
[1103154.012220] CPU    5: hi:  186, btch:  31 usd:   0
[1103154.012221] CPU    6: hi:  186, btch:  31 usd:   0
[1103154.012221] CPU    7: hi:  186, btch:  31 usd:   0
[1103154.012222] Node 0 Normal per-cpu:
[1103154.012223] CPU    0: hi:  186, btch:  31 usd:   0
[1103154.012224] CPU    1: hi:  186, btch:  31 usd:   0
[1103154.012225] CPU    2: hi:  186, btch:  31 usd:   0
[1103154.012225] CPU    3: hi:  186, btch:  31 usd:   0
[1103154.012226] CPU    4: hi:  186, btch:  31 usd:   0
[1103154.012227] CPU    5: hi:  186, btch:  31 usd:   0
[1103154.012228] CPU    6: hi:  186, btch:  31 usd:   0
[1103154.012229] CPU    7: hi:  186, btch:  31 usd:   0
[1103154.012231] active_anon:40897 inactive_anon:3208 isolated_anon:0
[1103154.012231]  active_file:3539856 inactive_file:3569391 isolated_file:6
[1103154.012231]  unevictable:0 dirty:14 writeback:0 unstable:0
[1103154.012231]  free:180017 slab_reclaimable:132954 slab_unreclaimable:15217
[1103154.012231]  mapped:179977 shmem:2102 pagetables:2631 bounce:0
[1103154.012232] Node 0 DMA free:15900kB min:32kB low:40kB high:48kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15644kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[1103154.012235] lowmem_reserve[]: 0 2905 32135 32135
[1103154.012237] Node 0 DMA32 free:279200kB min:6108kB low:7632kB high:9160kB active_anon:0kB inactive_anon:228kB active_file:1107612kB inactive_file:1114864kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2975592kB mlocked:0kB dirty:4kB writeback:0kB mapped:13260kB shmem:0kB slab_reclaimable:86476kB slab_unreclaimable:3384kB kernel_stack:8kB pagetables:36kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1103154.012240] lowmem_reserve[]: 0 0 29230 29230
[1103154.012242] Node 0 Normal free:424968kB min:61440kB low:76800kB high:92160kB active_anon:163588kB inactive_anon:12604kB active_file:13051812kB inactive_file:13162700kB unevictable:0kB isolated(anon):0kB isolated(file):24kB present:29931552kB mlocked:0kB dirty:52kB writeback:0kB mapped:706648kB shmem:8408kB slab_reclaimable:445340kB slab_unreclaimable:57484kB kernel_stack:2664kB pagetables:10488kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1103154.012245] lowmem_reserve[]: 0 0 0 0
[1103154.012247] Node 0 DMA: 1*4kB 1*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15900kB
[1103154.012251] Node 0 DMA32: 2700*4kB 1240*8kB 4143*16kB 1630*32kB 432*64kB 184*128kB 97*256kB 67*512kB 29*1024kB 0*2048kB 0*4096kB = 279200kB
[1103154.012256] Node 0 Normal: 18205*4kB 9386*8kB 1800*16kB 281*32kB 177*64kB 156*128kB 141*256kB 121*512kB 107*1024kB 0*2048kB 0*4096kB = 424612kB
[1103154.012260] 7111410 total pagecache pages
[1103154.012261] 0 pages in swap cache
[1103154.012262] Swap cache stats: add 0, delete 0, find 0/0
[1103154.012262] Free swap  = 33553332kB
[1103154.012263] Total swap = 33553332kB
[1103154.066367] 8388080 pages RAM
[1103154.066369] 870823 pages reserved
[1103154.066377] 2921110 pages shared
[1103154.066378] 4433002 pages non-shared

Looks pretty much the same to me.

As I can now reproduce it for the moment, I'll try to run the same VM but with the english installation media.

comment:13 by Grimeton, 11 years ago

[1104376.457011] EMT-0: page allocation failure: order:9, mode:0x344d2
[1104376.457015] Pid: 19172, comm: EMT-0 Tainted: G           O 3.6.0-030600-generic #201209302035
[1104376.457016] Call Trace:
[1104376.457021]  [<ffffffff81132496>] warn_alloc_failed+0xf6/0x150
[1104376.457024]  [<ffffffff810b6497>] ? on_each_cpu_mask+0x37/0x70
[1104376.457025]  [<ffffffff811362be>] __alloc_pages_nodemask+0x76e/0x9b0
[1104376.457029]  [<ffffffff8116edb6>] alloc_pages_current+0xb6/0x120
[1104376.457037]  [<ffffffffa0703ab0>] rtR0MemObjLinuxAllocPages+0xc0/0x260 [vboxdrv]
[1104376.457041]  [<ffffffffa0703c8a>] rtR0MemObjLinuxAllocPhysSub2+0x3a/0xe0 [vboxdrv]
[1104376.457057]  [<ffffffff81044c39>] ? default_spin_lock_flags+0x9/0x10
[1104376.457062]  [<ffffffffa0703dfa>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[1104376.457066]  [<ffffffffa07041c9>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[1104376.457071]  [<ffffffffa0702074>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xb0 [vboxdrv]
[1104376.457080]  [<ffffffffa06fab2e>] ? supdrvIOCtl+0x152e/0x2a90 [vboxdrv]
[1104376.457085]  [<ffffffffa07035dd>] ? rtR0MemAllocEx+0x17d/0x250 [vboxdrv]
[1104376.457089]  [<ffffffffa06f5448>] ? VBoxDrvLinuxIOCtl_4_2_7+0x118/0x1f0 [vboxdrv]
[1104376.457092]  [<ffffffff810135fa>] ? __switch_to+0x17a/0x410
[1104376.457094]  [<ffffffff81092ff0>] ? set_next_entity+0xa0/0xc0
[1104376.457096]  [<ffffffff8119857a>] ? do_vfs_ioctl+0x8a/0x340
[1104376.457098]  [<ffffffff8169cc8b>] ? __schedule+0x3bb/0x6f0
[1104376.457100]  [<ffffffff811988c1>] ? sys_ioctl+0x91/0xa0
[1104376.457102]  [<ffffffff816a6a69>] ? system_call_fastpath+0x16/0x1b
[1104376.457103] Mem-Info:
[1104376.457104] Node 0 DMA per-cpu:
[1104376.457105] CPU    0: hi:    0, btch:   1 usd:   0
[1104376.457106] CPU    1: hi:    0, btch:   1 usd:   0
[1104376.457107] CPU    2: hi:    0, btch:   1 usd:   0
[1104376.457108] CPU    3: hi:    0, btch:   1 usd:   0
[1104376.457109] CPU    4: hi:    0, btch:   1 usd:   0
[1104376.457109] CPU    5: hi:    0, btch:   1 usd:   0
[1104376.457110] CPU    6: hi:    0, btch:   1 usd:   0
[1104376.457111] CPU    7: hi:    0, btch:   1 usd:   0
[1104376.457111] Node 0 DMA32 per-cpu:
[1104376.457113] CPU    0: hi:  186, btch:  31 usd:   0
[1104376.457114] CPU    1: hi:  186, btch:  31 usd:   0
[1104376.457114] CPU    2: hi:  186, btch:  31 usd:   0
[1104376.457115] CPU    3: hi:  186, btch:  31 usd:   0
[1104376.457116] CPU    4: hi:  186, btch:  31 usd:   0
[1104376.457117] CPU    5: hi:  186, btch:  31 usd:   0
[1104376.457117] CPU    6: hi:  186, btch:  31 usd:   0
[1104376.457118] CPU    7: hi:  186, btch:  31 usd:   0
[1104376.457119] Node 0 Normal per-cpu:
[1104376.457120] CPU    0: hi:  186, btch:  31 usd:   0
[1104376.457121] CPU    1: hi:  186, btch:  31 usd:   0
[1104376.457122] CPU    2: hi:  186, btch:  31 usd:   0
[1104376.457122] CPU    3: hi:  186, btch:  31 usd:   0
[1104376.457123] CPU    4: hi:  186, btch:  31 usd:   0
[1104376.457124] CPU    5: hi:  186, btch:  31 usd:   0
[1104376.457125] CPU    6: hi:  186, btch:  31 usd:   0
[1104376.457125] CPU    7: hi:  186, btch:  31 usd:   0
[1104376.457128] active_anon:39598 inactive_anon:4074 isolated_anon:0
[1104376.457128]  active_file:3540323 inactive_file:3600279 isolated_file:57
[1104376.457128]  unevictable:0 dirty:17 writeback:0 unstable:0
[1104376.457128]  free:148834 slab_reclaimable:130938 slab_unreclaimable:15704
[1104376.457128]  mapped:179951 shmem:2102 pagetables:2628 bounce:0
[1104376.457129] Node 0 DMA free:15900kB min:32kB low:40kB high:48kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15644kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[1104376.457132] lowmem_reserve[]: 0 2905 32135 32135
[1104376.457134] Node 0 DMA32 free:157448kB min:6108kB low:7632kB high:9160kB active_anon:360kB inactive_anon:240kB active_file:1111572kB inactive_file:1118696kB unevictable:0kB isolated(anon):0kB isolated(file):228kB present:2975592kB mlocked:0kB dirty:0kB writeback:0kB mapped:13472kB shmem:0kB slab_reclaimable:88660kB slab_unreclaimable:5832kB kernel_stack:40kB pagetables:36kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1104376.457137] lowmem_reserve[]: 0 0 29230 29230
[1104376.457139] Node 0 Normal free:421988kB min:61440kB low:76800kB high:92160kB active_anon:158032kB inactive_anon:16056kB active_file:13049720kB inactive_file:13282420kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:29931552kB mlocked:0kB dirty:68kB writeback:0kB mapped:706332kB shmem:8408kB slab_reclaimable:435092kB slab_unreclaimable:56984kB kernel_stack:2632kB pagetables:10476kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1104376.457142] lowmem_reserve[]: 0 0 0 0
[1104376.457143] Node 0 DMA: 1*4kB 1*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15900kB
[1104376.457148] Node 0 DMA32: 2330*4kB 890*8kB 367*16kB 432*32kB 318*64kB 201*128kB 106*256kB 72*512kB 11*1024kB 0*2048kB 0*4096kB = 157480kB
[1104376.457152] Node 0 Normal: 18057*4kB 9338*8kB 1637*16kB 98*32kB 5*64kB 1*128kB 132*256kB 169*512kB 122*1024kB 0*2048kB 0*4096kB = 421956kB
[1104376.457157] 7142790 total pagecache pages
[1104376.457158] 0 pages in swap cache
[1104376.457158] Swap cache stats: add 0, delete 0, find 0/0
[1104376.457159] Free swap  = 33553332kB
[1104376.457160] Total swap = 33553332kB
[1104376.510269] 8388080 pages RAM
[1104376.510270] 872359 pages reserved
[1104376.510279] 2768973 pages shared
[1104376.510279] 4614525 pages non-shared

English install media, same VM

comment:14 by Grimeton, 11 years ago

Running Memtest86 inside the vm doesn't give any errors. See attachment.

by Grimeton, 11 years ago

Attachment: memtest86.jpg added

Results of memtest

comment:15 by Grimeton, 11 years ago

I've ran another Windows 7 Ultimate x64 installation:

After the system has booted for the first time, I installed the guest additions and on the reboot I got a blue screen. I've got the memory dump file, so FWIW: if it would help you, I can upload it somewhere and you can analyze it. (It's about 256mb in size).

I also figured out that the only difference of the VM is that the german version does NOT include SP1.

Last edited 11 years ago by Grimeton (previous) (diff)

comment:16 by Grimeton, 11 years ago

The Windows 7 Ultimate installation is still downloading Updates at 0%.

Network connectivity is given. In the logs it shows an error message that an installer application has died. And IMHO that's the reason why the update service hangs. Happens on a regular basis.

comment:17 by Frank Mehnert, 11 years ago

Any reason why you enabled large pages for that VM? That feature is disabled by default because it makes Linux systems very slow if a large page is not available. That could explain the page allocation problems.

comment:18 by Grimeton, 11 years ago

I created a reference machine on OS X and used those settings. Maybe that's why it's set.

I'll disable it and report back.

comment:19 by Grimeton, 11 years ago

Didn't really help, had multiple of the already known errors in dmesg and the machine crashed.

One could connect to it via remote desktop, but all you see is a part of the screen and a "red bar" at the top of the screen. Reminded me a bit of "guru meditation" from the old A500 Amiga.

Should I post the errors in dmesg anyway?

Large pages are off on all VMs and the machine has been rebooted.

Last edited 11 years ago by Grimeton (previous) (diff)

comment:20 by Grimeton, 11 years ago

Still the same on the linux machine.

Tmux died a few times in the last 12 hours.

comment:21 by Frank Mehnert, 11 years ago

Please again attach a VBox.log file of such a VM session together with a file containing the dmesg errors.

by Grimeton, 11 years ago

Attachment: VBox.3.log added

VBox.Log for the latest entry

comment:22 by Grimeton, 11 years ago

Just sitting here and tmux crashed in front of my eyes.

No segfault message, nothing in the guest's dmesg or somewhere else. Not even a coredump. And on the host I see this:

1259073.137922] EMT-0: page allocation failure: order:9, mode:0x344d2
[1259073.137933] Pid: 9914, comm: EMT-0 Tainted: G           O 3.6.0-030600-generic #201209302035
[1259073.137934] Call Trace:
[1259073.137939]  [<ffffffff81132496>] warn_alloc_failed+0xf6/0x150
[1259073.137943]  [<ffffffff8168802a>] ? __alloc_pages_direct_compact+0x1a7/0x1b9
[1259073.137945]  [<ffffffff811362be>] __alloc_pages_nodemask+0x76e/0x9b0
[1259073.137948]  [<ffffffff8116edb6>] alloc_pages_current+0xb6/0x120
[1259073.137956]  [<ffffffffa0703ab0>] rtR0MemObjLinuxAllocPages+0xc0/0x260 [vboxdrv]
[1259073.137961]  [<ffffffffa0703c8a>] rtR0MemObjLinuxAllocPhysSub2+0x3a/0xe0 [vboxdrv]
[1259073.137977]  [<ffffffff81044c39>] ? default_spin_lock_flags+0x9/0x10
[1259073.137981]  [<ffffffffa0703dfa>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[1259073.137985]  [<ffffffffa07041c9>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[1259073.137990]  [<ffffffffa0702074>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xb0 [vboxdrv]
[1259073.137999]  [<ffffffffa06fab2e>] ? supdrvIOCtl+0x152e/0x2a90 [vboxdrv]
[1259073.138003]  [<ffffffffa07035dd>] ? rtR0MemAllocEx+0x17d/0x250 [vboxdrv]
[1259073.138008]  [<ffffffffa06f5448>] ? VBoxDrvLinuxIOCtl_4_2_7+0x118/0x1f0 [vboxdrv]
[1259073.138010]  [<ffffffff8119857a>] ? do_vfs_ioctl+0x8a/0x340
[1259073.138012]  [<ffffffff81185dd0>] ? vfs_write+0x110/0x180[1259073.138014]  [<ffffffff811988c1>] ? sys_ioctl+0x91/0xa0[1259073.138016]  [<ffffffff816a6a69>] ? system_call_fastpath+0x16/0x1b[1259073.138017] Mem-Info:[1259073.138018] Node 0 DMA per-cpu:
[1259073.138019] CPU    0: hi:    0, btch:   1 usd:   0[1259073.138020] CPU    1: hi:    0, btch:   1 usd:   0
[1259073.138021] CPU    2: hi:    0, btch:   1 usd:   0[1259073.138022] CPU    3: hi:    0, btch:   1 usd:   0[1259073.138022] CPU    4: hi:    0, btch:   1 usd:   0[1259073.138023] CPU    5: hi:    0, btch:   1 usd:   0[1259073.138024] CPU    6: hi:    0, btch:   1 usd:   0[1259073.138025] CPU    7: hi:    0, btch:   1 usd:   0[1259073.138025] Node 0 DMA32 per-cpu:[1259073.138027] CPU    0: hi:  186, btch:  31 usd:   0
[1259073.138028] CPU    1: hi:  186, btch:  31 usd:   0
[1259073.138028] CPU    2: hi:  186, btch:  31 usd:   0
[1259073.138029] CPU    3: hi:  186, btch:  31 usd:   0
[1259073.138030] CPU    4: hi:  186, btch:  31 usd:   0[1259073.138031] CPU    5: hi:  186, btch:  31 usd:   0[1259073.138032] CPU    6: hi:  186, btch:  31 usd:   0[1259073.138033] CPU    7: hi:  186, btch:  31 usd:   0[1259073.138033] Node 0 Normal per-cpu:[1259073.138034] CPU    0: hi:  186, btch:  31 usd:  18[1259073.138035] CPU    1: hi:  186, btch:  31 usd:   0[1259073.138036] CPU    2: hi:  186, btch:  31 usd:   0[1259073.138037] CPU    3: hi:  186, btch:  31 usd:   0[1259073.138037] CPU    4: hi:  186, btch:  31 usd:   0[1259073.138038] CPU    5: hi:  186, btch:  31 usd:   0[1259073.138039] CPU    6: hi:  186, btch:  31 usd:   0[1259073.138040] CPU    7: hi:  186, btch:  31 usd:   0
[1259073.138042] active_anon:47158 inactive_anon:10271 isolated_anon:0
[1259073.138042]  active_file:2574679 inactive_file:4066625 isolated_file:4
[1259073.138042]  unevictable:0 dirty:276 writeback:0 unstable:0
[1259073.138042]  free:73100 slab_reclaimable:129410 slab_unreclaimable:21701
[1259073.138042]  mapped:1244931 shmem:2103 pagetables:4039 bounce:0[1259073.138043] Node 0 DMA free:15900kB min:32kB low:40kB high:48kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15644kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[1259073.138046] lowmem_reserve[]: 0 2905 32135 32135
[1259073.138048] Node 0 DMA32 free:137960kB min:6108kB low:7632kB high:9160kB active_anon:3300kB inactive_anon:3592kB active_file:1240616kB inactive_file:1077432kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2975592kB mlocked:0kB dirty:712kB writeback:0kB mapped:362220kB shmem:0kB slab_reclaimable:86316kB slab_unreclaimable:17316kB kernel_stack:288kB pagetables:1120kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1259073.138051] lowmem_reserve[]: 0 0 29230 29230
[1259073.138053] Node 0 Normal free:138540kB min:61440kB low:76800kB high:92160kB active_anon:185332kB inactive_anon:37492kB active_file:9058100kB inactive_file:15189068kB unevictable:0kB isolated(anon):0kB isolated(file):16kB present:29931552kB mlocked:0kB dirty:392kB writeback:0kB mapped:4617504kB shmem:8412kB slab_reclaimable:431324kB slab_unreclaimable:69488kB kernel_stack:2688kB pagetables:15036kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[1259073.138056] lowmem_reserve[]: 0 0 0 0
[1259073.138057] Node 0 DMA: 1*4kB 1*8kB 1*16kB 0*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15900kB
[1259073.138062] Node 0 DMA32: 10257*4kB 1994*8kB 90*16kB 236*32kB 125*64kB 77*128kB 56*256kB 34*512kB 20*1024kB 1*2048kB 0*4096kB = 138100kB
[1259073.138066] Node 0 Normal: 9396*4kB 3474*8kB 1210*16kB 403*32kB 181*64kB 93*128kB 33*256kB 11*512kB 3*1024kB 0*2048kB 0*4096kB = 138272kB
[1259073.138070] 6643626 total pagecache pages
[1259073.138071] 0 pages in swap cache
[1259073.138072] Swap cache stats: add 0, delete 0, find 0/0
[1259073.138073] Free swap  = 33553332kB
[1259073.138073] Total swap = 33553332kB
[1259073.198155] 8388080 pages RAM
[1259073.198156] 1425838 pages reserved
[1259073.198157] 2077411 pages shared
[1259073.198158] 4821202 pages non-shared

The log of the machine is attached.

KR,

G.

comment:23 by Grimeton, 11 years ago

Something new:

[469911.540457] google[10938]: segfault at 0 ip 0000000000484cd8 sp 00007fff5a035420 error 6 in python2.7[400000+21f000]
[469911.773594] apport[10939] general protection ip:4d6d27 sp:7fff80205340 error:0 in python3.2mu[400000+245000]
[469911.773623] Process 10939(apport) has RLIMIT_CORE set to 1
[469911.773626] Aborting core
[470094.401988] google[10964]: segfault at 1222408 ip 00000000004b7fe7 sp 00007fffc0868e30 error 4 in python2.7[400000+21f000]
[537632.798056] google[12375] general protection ip:4c79b0 sp:7fffbba10328 error:0 in python2.7[400000+21f000]


Same Machine as before

comment:24 by Grimeton, 11 years ago

Something new:

I upgraded the Ubuntu Kernel to a more "vanilla" version "Linux ozone 3.8.2-030802-generic #201303031906 SMP Mon Mar 4 00:07:09 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux" after seeing weird behavior in other places like not freeing NDP caches and resetting connections. VirtualBox is still 4.2.8 and the extension pack is still 4.2.0 (yeah, I'll upgrade).

So far it works for me (TM). And it also seems that the Windows errors just made their way from the faulty installation on the Linux machine over to the Macs and Windows after I copied them over. So what I think is that the faulty install was the cause for all those problems.

I will keep an eye on it as I had similar issues before, but so far I'd say it is "fixed".

Thanks again for the support!

KR,

Grimeton

comment:25 by ThetaPhi, 11 years ago

Hi, the same (in terms of stack trace in kernel log of host) is still happening with 4.2.16 on an Ubuntu 12.04 LTS host machine running Windows 7 (or a Hackintosh OSX) in a VirtualBox. Although I see no problems in the VM itsself, the problem seems to happen once in a while. I have seen no slowdown, but the errors make me nervous, especially because the problem may cause bigger issues on the host machine later (so I try to reboot it when this happens), which is not nice.

The Ubuntu kernel is 3.2.0-51-generic (64 bits).

With the newer Ubuntu 12.04 kernel (Linux 3.8) this happens all the time, the dmesg log is full of this stack trace (so I reverted to the 3.2.0 kernel).

Here is the stack trace:

[39812.779959] EMT-1: page allocation failure: order:9, mode:0x344d2
[39812.779964] Pid: 18435, comm: EMT-1 Tainted: G           O 3.2.0-51-generic #77-Ubuntu
[39812.779967] Call Trace:
[39812.779977]  [<ffffffff8111e9a6>] warn_alloc_failed+0xf6/0x150
[39812.779985]  [<ffffffff8164b232>] ? __alloc_pages_direct_compact+0x166/0x178
[39812.779989]  [<ffffffff81122737>] __alloc_pages_nodemask+0x6d7/0x8f0
[39812.779995]  [<ffffffff81159af6>] alloc_pages_current+0xb6/0x120
[39812.780013]  [<ffffffffa01e7024>] rtR0MemObjLinuxAllocPages+0x144/0x250 [vboxdrv]
[39812.780023]  [<ffffffffa01e7168>] rtR0MemObjLinuxAllocPhysSub2+0x38/0xd0 [vboxdrv]
[39812.780029]  [<ffffffff8103ec59>] ? default_spin_lock_flags+0x9/0x10
[39812.780039]  [<ffffffffa01e72ca>] rtR0MemObjLinuxAllocPhysSub+0xca/0xd0 [vboxdrv]
[39812.780051]  [<ffffffffa01e7699>] rtR0MemObjNativeAllocPhys+0x19/0x20 [vboxdrv]
[39812.780061]  [<ffffffffa01e53b4>] VBoxHost_RTR0MemObjAllocPhysExTag+0x64/0xc0 [vboxdrv]
[39812.780072]  [<ffffffffa01ddd24>] ? supdrvIOCtl+0x1594/0x2a40 [vboxdrv]
[39812.780082]  [<ffffffffa01e6999>] ? rtR0MemAllocEx+0x179/0x230 [vboxdrv]
[39812.780091]  [<ffffffffa01d8477>] ? VBoxDrvLinuxIOCtl_4_2_16+0x137/0x200 [vboxdrv]
[39812.780096]  [<ffffffff81013878>] ? __switch_to+0x288/0x360
[39812.780101]  [<ffffffff8105725d>] ? set_next_entity+0xad/0xd0
[39812.780107]  [<ffffffff8118c4ea>] ? do_vfs_ioctl+0x8a/0x340
[39812.780112]  [<ffffffff8165e14c>] ? __schedule+0x3cc/0x6f0
[39812.780115]  [<ffffffff8118c831>] ? sys_ioctl+0x91/0xa0
[39812.780120]  [<ffffffff81668d02>] ? system_call_fastpath+0x16/0x1b
[39812.780122] Mem-Info:
[39812.780124] Node 0 DMA per-cpu:
[39812.780127] CPU    0: hi:    0, btch:   1 usd:   0
[39812.780129] CPU    1: hi:    0, btch:   1 usd:   0
[39812.780131] CPU    2: hi:    0, btch:   1 usd:   0
[39812.780134] CPU    3: hi:    0, btch:   1 usd:   0
[39812.780136] CPU    4: hi:    0, btch:   1 usd:   0
[39812.780138] CPU    5: hi:    0, btch:   1 usd:   0
[39812.780140] CPU    6: hi:    0, btch:   1 usd:   0
[39812.780142] CPU    7: hi:    0, btch:   1 usd:   0
[39812.780143] Node 0 DMA32 per-cpu:
[39812.780146] CPU    0: hi:  186, btch:  31 usd:   0
[39812.780148] CPU    1: hi:  186, btch:  31 usd: 181
[39812.780150] CPU    2: hi:  186, btch:  31 usd:   0
[39812.780152] CPU    3: hi:  186, btch:  31 usd:   0
[39812.780154] CPU    4: hi:  186, btch:  31 usd:   0
[39812.780157] CPU    5: hi:  186, btch:  31 usd:   0
[39812.780159] CPU    6: hi:  186, btch:  31 usd:   0
[39812.780162] CPU    7: hi:  186, btch:  31 usd:   0
[39812.780164] Node 0 Normal per-cpu:
[39812.780167] CPU    0: hi:  186, btch:  31 usd:   0
[39812.780168] CPU    1: hi:  186, btch:  31 usd: 127
[39812.780170] CPU    2: hi:  186, btch:  31 usd:   0
[39812.780172] CPU    3: hi:  186, btch:  31 usd:   0
[39812.780175] CPU    4: hi:  186, btch:  31 usd:   0
[39812.780177] CPU    5: hi:  186, btch:  31 usd:   0
[39812.780179] CPU    6: hi:  186, btch:  31 usd:   0
[39812.780181] CPU    7: hi:  186, btch:  31 usd:   0
[39812.780186] active_anon:717048 inactive_anon:143869 isolated_anon:0
[39812.780187]  active_file:205864 inactive_file:262068 isolated_file:0
[39812.780188]  unevictable:0 dirty:39 writeback:0 unstable:0
[39812.780189]  free:132306 slab_reclaimable:46452 slab_unreclaimable:12381
[39812.780191]  mapped:48134 shmem:303 pagetables:6924 bounce:0
[39812.780193] Node 0 DMA free:15904kB min:128kB low:160kB high:192kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_fil
e:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15648kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB
 slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned
:0 all_unreclaimable? yes
[39812.780204] lowmem_reserve[]: 0 1959 8007 8007
[39812.780208] Node 0 DMA32 free:428544kB min:16508kB low:20632kB high:24760kB active_anon:473028kB inactive_anon:233052kB active_fi
le:186348kB inactive_file:573356kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2006976kB mlocked:0kB dirty:12kB wr
iteback:0kB mapped:43512kB shmem:4kB slab_reclaimable:60440kB slab_unreclaimable:6696kB kernel_stack:112kB pagetables:4652kB unstabl
e:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
[39812.780219] lowmem_reserve[]: 0 0 6048 6048
[39812.780224] Node 0 Normal free:84776kB min:50944kB low:63680kB high:76416kB active_anon:2395164kB inactive_anon:342424kB active_f
ile:637108kB inactive_file:474916kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:6193152kB mlocked:0kB dirty:144kB
writeback:0kB mapped:149024kB shmem:1208kB slab_reclaimable:125368kB slab_unreclaimable:42828kB kernel_stack:3560kB pagetables:23044
kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:160 all_unreclaimable? no
[39812.780236] lowmem_reserve[]: 0 0 0 0
[39812.780239] Node 0 DMA: 0*4kB 0*8kB 0*16kB 1*32kB 2*64kB 1*128kB 1*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15904kB
[39812.780249] Node 0 DMA32: 9137*4kB 4603*8kB 1169*16kB 791*32kB 1372*64kB 828*128kB 268*256kB 65*512kB 16*1024kB 0*2048kB 0*4096kB
 = 429452kB
[39812.780259] Node 0 Normal: 6186*4kB 2346*8kB 706*16kB 137*32kB 31*64kB 20*128kB 38*256kB 8*512kB 5*1024kB 1*2048kB 0*4096kB = 847
28kB
[39812.780269] 492895 total pagecache pages
[39812.780271] 24516 pages in swap cache
[39812.780273] Swap cache stats: add 545903, delete 521387, find 287244/335754
[39812.780275] Free swap  = 10059984kB
[39812.780276] Total swap = 10388596kB
[39812.808262] 2097136 pages RAM
[39812.808264] 539222 pages reserved
[39812.808266] 339574 pages shared
[39812.808267] 1121579 pages non-shared

What else is needed to make a fix for that? Especially as the problem occurs all the time with newer Linux kernels (3.8).

comment:26 by Frank Mehnert, 10 years ago

Resolution: duplicate
Status: newclosed

Duplicate of #11171. See the explanation and a fix there.

Note: See TracTickets for help on using tickets.

© 2023 Oracle
ContactPrivacy policyTerms of Use