Re: [Xen-users] substantial shutdown delay for PV guests with PCI -passthrough

[Atom2 <ariel.atom2@web2web.at>]

Am 18.03.14 16:07, schrieb Ian Campbell:
> On Tue, 2014-03-18 at 14:01 +0100, Atom2 wrote:
> [...]
>> So I guess probably not too much of value ...
>
> Unfortunately not, but thanks anyway, it's good to check.
>
>>> While the domain is happily running can you provide the output of
>>> "xenstore-ls -fp" -- I'm curious what state pciback is in. It should be
>>> 4, if not then that would be the problem.
>> Full output of xenstore-ls -fp (from dom0) is attached as it is 627
>> lines long and I am not quiet sure what you are actually after): There's
>> nothing in it that reads pciback; there are however a few entries named
>> 	/local/domain/0/backend/pci
>> and for one of the subentries named 3/0/state (3 is the domain-id)
>> the value seems to be 4:
>> 	/local/domain/0/backend/pci/3/0/state = "4"   (n0,r3)
>
> Yes, this is the one which libxl appears to be looking for and it is set
> to "4" which is what libxl is looking for.
>
> Please can you try this again but take the dump while the destruction is
> going on, i.e. in among the 10s delays somewhere (I don't think where
> exactly will matter. I don't see it in the logs but I'm wondering if the
> pciback directory is getting torn down too soon.
>
O.K. - that's what I have done: I created a loop at the shell prompt in 
dom0 that executes 'xenstore-ls -fp' for a total of 16 times with a 
delay of one second between invocations and stores each output in a 
separate file with an extension that counts up from 0. I have started 
that "script" just before the "reboot: System halted" message appeared 
in the domU, so at least the first file must still contain the info 
prior to the 10s delay when the domU is still sort of up and running. 
The output below is the result of

grep -E '/local/domain/(0|8)/(backend|device)/pci/.*/state' xenstore.n

where the domain id this time was 8 and n is the counter of my loop. 
Please find the output below:

.0 and .1 file:
/local/domain/0/backend/pci/8/0/state = "4"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-0 = "3"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-1 = "3"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-2 = "3"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-3 = "3"   (n0,r8)
/local/domain/8/device/pci/0/state = "4"   (n8,r0)
.2 upto .15 file:
/local/domain/0/backend/pci/8/0/state = "6"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-0 = "3"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-1 = "3"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-2 = "3"   (n0,r8)
/local/domain/0/backend/pci/8/0/state-3 = "3"   (n0,r8)
/local/domain/8/device/pci/0/state = "6"   (n8,r0)

So it seems that pretty much at the start of the 10s delay the state 
changed from 4 to 6 and stays at that value even after the first 10s 
delay is over - whatever that means.


And for the sake of being complete:
Below is the output from starting the domain prior to the grub menu 
showing on screen. There is one device with which xl seems to have an 
issue (for which I still have to find and compile a driver anyway), but 
I think that's unrelated because if I drop that one device from being 
passed through, the delay of 10s per remaining device nevertheless remains.
===========================
Parsing config from 5:voip.9
libxl: error: libxl_pci.c:990:libxl__device_pci_reset: The kernel 
doesn't support reset from sysfs for PCI device 0000:09:02.0
Daemon running with PID 4759
Xen Minimal OS!
   start_info: 0xbab000(VA)
     nr_pages: 0x40000
   shared_inf: 0xdb4f9000(MA)
      pt_base: 0xbae000(VA)
nr_pt_frames: 0xb
     mfn_list: 0x9ab000(VA)
    mod_start: 0x9aa000(VA)
      mod_len: 4096
        flags: 0x0
     cmd_line:
   stack:      0x9690e0-0x9890e0
MM: Init
       _text: 0x0(VA)
      _etext: 0x7b4c5(VA)
    _erodata: 0x96000(VA)
      _edata: 0x9bd20(VA)
stack start: 0x9690e0(VA)
        _end: 0x9a96e0(VA)
   start_pfn: bbc
     max_pfn: 40000
Mapping memory range 0x1000000 - 0x40000000
setting 0x0-0x96000 readonly
skipped 0x1000
MM: Initialise page allocator for db4000(db4000)-40000000(40000000) MM: done
Demand map pfns at 40001000-2040001000.
Heap resides at 2040002000-4040002000.
Initialising timer interface
Initialising console ... done.
gnttab_table mapped at 0x40001000.
Initialising scheduler
Thread "Idle": pointer: 0x2040002050, stack: 0xfd0000
Thread "xenstore": pointer: 0x2040002800, stack: 0xfe0000
xenbus initialised on irq 1 mfn 0x7a512a
Thread "shutdown": pointer: 0x2040002fb0, stack: 0xff0000
Dummy main: start_info=0x9891e0
Thread "main": pointer: 0x2040003760, stack: 0x1000000
"main"
vbd 51713 is hd0
******************* BLKFRONT for device/vbd/51713 **********


Shutting down ()
Shutdown requested: 3
Thread "shutdown" exited.
backend at /local/domain/0/backend/vbd/8/51713
16777216 sectors of 512 bytes
**************************
vbd 51714 is hd1
******************* BLKFRONT for device/vbd/51714 **********


backend at /local/domain/0/backend/vbd/8/51714
2097152 sectors of 512 bytes
**************************
vbd 51715 is hd2
******************* BLKFRONT for device/vbd/51715 **********


backend at /local/domain/0/backend/vbd/8/51715
2097152 sectors of 512 bytes
**************************
===========================

Thanks Atom2