Re: Mirage, suspend resume and the ocaml GC

[Anil Madhavapeddy <anil@xxxxxxxxxx>]

Hi Jon, [+cc cl-mirage]

This could be an event channel not being initialised and causing it to spin in 
the event loop. 

You can try to recompile the monolithic mirage with MIR-TRACE=1 (see 
lib/myocamlbuild.ml) which will cause every function call to printf.  It'll be 
very verbose, but spins should be obvious as long as your console doesn't 
overflow.

Thomas: it occurs to me that we cannot actually do MIR-TRACE with the 
OPAM-based build, as we can't add a global pp flag for pa_trace to all 
libraries.  Any thoughts on how to do this in the future?

-anil

On 20 Jul 2012, at 16:57, Jonathan Ludlam wrote:

> Hi Anil,
> 
> I've been playing with getting suspend/resume working for mirage guests, and 
> it's in a state where it does suspend and resume, but there's some odd 
> behaviour on resume - specifically, the GC starts going bananas.
> 
> I'm using a modified regress/lwt/echoserver.ml guest, which is putting random 
> strings of 'a's on the console:
> 
> 
> -----------------------------------------------------------------------
> kernel.c: Mirage OS!
> kernel.c:   start_info: 0x10e3000(VA)
> kernel.c:     nr_pages: 0x4000
> kernel.c:   shared_inf: 0xdda73000(MA)
> kernel.c:      pt_base: 0x10e6000(VA)
> kernel.c: nr_pt_frames: 0xd
> kernel.c:     mfn_list: 0x10c3000(VA)
> kernel.c:    mod_start: 0x0(VA)
> kernel.c:      mod_len: 0
> kernel.c:        flags: 0x0
> kernel.c:     cmd_line: 
> x86_setup.c:   stack:      0xc2780-0x8c2780
> mm.c: MM: Init
> x86_mm.c:       _text: 0x0(VA)
> x86_mm.c:      _etext: 0x27bff(VA)
> x86_mm.c:    _erodata: 0x33000(VA)
> x86_mm.c:      _edata: 0x36620(VA)
> x86_mm.c: stack start: 0xc2780(VA)
> x86_mm.c:        _end: 0x10c3000(VA)
> x86_mm.c:   start_pfn: 10f6
> x86_mm.c:     max_pfn: 4000
> x86_mm.c: Mapping memory range 0x1400000 - 0x4000000
> x86_mm.c: setting 0x0-0x33000 readonly
> x86_mm.c: skipped 0x1000
> mm.c: MM: Initialise page allocator for 0x110c000 -> 0x4000000
> mm.c: MM: done
> x86_mm.c: Demand map pfns at 4001000-2004001000.
> Initial minor heap size: 1024k bytes
> Initial major heap size: 992k bytes
> Initial space overhead: 80%
> Initial max overhead: 500%
> Initial heap increment: 992k bytes
> Initial allocation policy: 0
> Growing page table to 1024 entries
> xs_watch ()
> Not initialising grant tablesDevices: [Xen.Blkif] provider start
> watch callback: [ control/shutdown = XXX ]
> 
> About to dir:
> Got this list: [platform-feature-multiprocessor-suspend]
> aaaaaaaaa
> aa
> aaaaaa
> aaa
> aaaaaaaaaaaa
> aaaaaaaaa
> aaaaaaaaaaaaaaaa
> aaaaaaaaaaaaaaaaa
> aaaaaaaaaaaaaaaaaa
> aaaaaaaaaa
> watch callback: [ control/shutdown = XXX ]
> 
> About to dir:
> Got this list: [platform-feature-multiprocessor-suspend,shutdown]
> Got control message: suspend
> -----------------------------------------------------------------------
> 
> All good so far, it has found the suspend key in xenstore and called 
> HYPERVISOR_suspend. On resuming however, you get this:
> 
> -----------------------------------------------------------------------
> 
> cancelled=0
> aaaaaaaaaaaaaaaaa
> <>Starting new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$aaaaaaaaaaa
> <>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting new major GC cycle
> ### O'Caml runtime: heap check ###
> !<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>!<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>$<>Starting
>  new major GC cycle
> ### O'Caml runtime: heap check ###
> 
> -----------------------------------------------------------------------
> 
> 
> I've done a little digging, but can't see quite where it's going wrong. It 
> looks a little like perhaps an allocation is failing and it's kicking the GC 
> to try and free up space, maybe?
> 
> The code is on github - I've made a temporary commit of the work so far in 
> jonludlam/mirage branch suspend-resume.
> 
> Any thoughts?
> 
> Jon
>