Re: Getting ACRN to work


Dubravko Moravski | Exor Embedded S.r.l. <dubravko.moravski@...>
 

Hi Zide,

The full log is below, with some additional /* comments */. I've noticed now that ACRN console prompt does appear, but it is unusable due to all the debug messages.

ACRN Hypervisor
calibrate_tsc, tsc_khz=1593600
[7621776us][cpu=0][(null)][sev=2][seq=1]:HV version 1.6-unstable-2020-02-11 17:29:55-4b983876-dirty DBG (daily tag:acrn-2020w04.1-140000p) build by clear, start time 7596708us
[7639207us][cpu=0][(null)][sev=2][seq=2]:API version 1.0
[7644984us][cpu=0][(null)][sev=2][seq=3]:Detect processor: Intel(R) Atom(TM) Processor E3940 @ 1.60GHz
[7655270us][cpu=0][(null)][sev=1][seq=4]:SECURITY WARNING!!!!!!
[7661731us][cpu=0][(null)][sev=1][seq=5]:Please apply the latest CPU uCode patch!
[7670865us][cpu=0][(null)][sev=5][seq=6]:hide pci uart dev: (0:18:0)
[7720135us][cpu=0][(null)][sev=5][seq=9]:profiling_setup: entering
[7720133us][cpu=1][(null)][sev=5][seq=7]:profiling_setup: entering
[7720136us][cpu=3][(null)][sev=5][seq=10]:profiling_setup: entering
[7720134us][cpu=2][(null)][sev=5][seq=8]:profiling_setup: entering
[7726787us][cpu=0][(null)][sev=5][seq=11]:profiling_setup: calling request_irq
[7733543us][cpu=1][(null)][sev=5][seq=12]:profiling_setup: exiting
[7740402us][cpu=3][(null)][sev=5][seq=13]:profiling_setup: exiting
[7747161us][cpu=2][(null)][sev=5][seq=14]:profiling_setup: exiting
[7755094us][cpu=0][(null)][sev=5][seq=15]:profiling_setup: exiting
[7783951us][cpu=0][(null)][sev=5][seq=16]:System S3/S5 is supported.
[7791335us][cpu=0][(null)][sev=5][seq=17]:Creating VCPU working on PCPU0
[7798597us][cpu=0][(null)][sev=5][seq=18]:Create VM0-VCPU0, Role: PRIMARY
[7806135us][cpu=0][(null)][sev=5][seq=19]:Creating VCPU working on PCPU1
[7813389us][cpu=0][(null)][sev=5][seq=20]:Create VM0-VCPU1, Role: SECONDARY
[7821031us][cpu=0][(null)][sev=5][seq=21]:Creating VCPU working on PCPU2
[7828376us][cpu=0][(null)][sev=5][seq=22]:Create VM0-VCPU2, Role: SECONDARY
[7836012us][cpu=0][(null)][sev=5][seq=23]:Creating VCPU working on PCPU3
[7843359us][cpu=0][(null)][sev=5][seq=24]:Create VM0-VCPU3, Role: SECONDARY
[7850998us][cpu=0][(null)][sev=4][seq=25]:Spurious vector: 0x50.
ACRN:\>[7858255us][cpu=0][(null)][sev=2][seq=26]:Start VM id: 0 name: ACRN SOS VM
[7865814us][cpu=0][vm0:vcpu0][sev=5][seq=27]:VM 0 Starting VCPU 0
[7872492us][cpu=0][vm0:vcpu0][sev=5][seq=28]:VM 0 VCPU 0 successfully launched
[7882501us][cpu=0][vm0:vcpu0][sev=4][seq=29]:Spurious vector: 0x50.
[7899292us][cpu=0][vm0:vcpu0][sev=4][seq=30]:Spurious vector: 0x50.
[7916327us][cpu=0][vm0:vcpu0][sev=4][seq=31]:Spurious vector: 0x50.
/* seq 32..99 are all identical entries like the surrounding ones */
[9075356us][cpu=0][vm0:vcpu0][sev=4][seq=100]:Spurious vector: 0x50.
[9092270us][cpu=0][vm0:vcpu0][sev=4][seq=101]:Spurious vector: 0x50.
[9109179us][cpu=0][vm0:vcpu0][sev=4][seq=102]:Spurious vector: 0x50.
[9126089us][cpu=0][vm0:vcpu0][sev=4][seq=103]:Spurious vector: 0x50.
[9163364us][cpu=0][vm0:vcpu0][sev=2][seq=104]:write_cfg 0:18.0 not found! off: 0x3c, val: 0x4
/* approximately here I've choosed an entry from the boot menu */

[9173239us][cpu=0][vm0:vcpu0][sev=3][seq=105]:vlapic: Start Secondary VCPU1 for VM[0]...
[9182086us][cpu=1][vm0:vcpu1][sev=5][seq=106]:VM 0 Starting VCPU 1
[9182310us][cpu=0][vm0:vcpu0][sev=3][seq=107]:vlapic: Start Secondary VCPU2 for VM[0]...
[9197761us][cpu=2][vm0:vcpu2][sev=5][seq=108]:VM 0 Starting VCPU 2
[9197985us][cpu=0][vm0:vcpu0][sev=3][seq=109]:vlapic: Start Secondary VCPU3 for VM[0]...
[9213427us][cpu=3][vm0:vcpu3][sev=5][seq=110]:VM 0 Starting VCPU 3
[9220288us][cpu=0][vm0:vcpu0][sev=3][seq=111]:vlapic: Start Secondary VCPU3 for VM[0]...
[9229124us][cpu=3][vm0:vcpu3][sev=5][seq=112]:VM 0 Starting VCPU 3
[9235992us][cpu=0][vm0:vcpu0][sev=3][seq=113]:vlapic: Start Secondary VCPU3 for VM[0]...
[9244836us][cpu=3][vm0:vcpu3][sev=5][seq=114]:VM 0 Starting VCPU 3
[9251701us][cpu=0][vm0:vcpu0][sev=3][seq=115]:vlapic: Start Secondary VCPU3 for VM[0]...
[9260536us][cpu=3][vm0:vcpu3][sev=5][seq=116]:VM 0 Starting VCPU 3
[9267402us][cpu=0][vm0:vcpu0][sev=3][seq=117]:vlapic: Start Secondary VCPU3 for VM[0]...
[9276237us][cpu=3][vm0:vcpu3][sev=5][seq=118]:VM 0 Starting VCPU 3
[9283102us][cpu=0][vm0:vcpu0][sev=3][seq=119]:vlapic: Start Secondary VCPU3 for VM[0]...
[9291941us][cpu=3][vm0:vcpu3][sev=5][seq=120]:VM 0 Starting VCPU 3
[9298810us][cpu=0][vm0:vcpu0][sev=3][seq=121]:vlapic: Start Secondary VCPU3 for VM[0]...
[9307648us][cpu=3][vm0:vcpu3][sev=5][seq=122]:VM 0 Starting VCPU 3
[9314511us][cpu=0][vm0:vcpu0][sev=3][seq=123]:vlapic: Start Secondary VCPU3 for VM[0]...
[9323355us][cpu=3][vm0:vcpu3][sev=5][seq=124]:VM 0 Starting VCPU 3
[9330216us][cpu=0][vm0:vcpu0][sev=3][seq=125]:vlapic: Start Secondary VCPU3 for VM[0]...
[9339041us][cpu=3][vm0:vcpu3][sev=5][seq=126]:VM 0 Starting VCPU 3
/* this continues indefinitely... */



Dubravko Moravski
SW engineering
Exor Embedded S.r.l.
p: +38 512455659  m: +38 5915402413
a: Slavonska avenija, 50, Zagreb, Croatia, 10000
w: exorint.com 

 Prima di stampare pensa ai costi ambientali. Please consider the environment before printing this email.

Privacy
From: acrn-users@... <acrn-users@...> on behalf of Chen, Zide via Lists.Projectacrn.Org <zide.chen=intel.com@...>
Sent: Tuesday, February 11, 2020 5:31 PM
To: acrn-users@... <acrn-users@...>
Subject: Re: [acrn-users] Getting ACRN to work
 
Hi Dubravko,

Is it possible to post the full log here?

Thanks,
Zide


On 2/11/20 6:19 AM, Dubravko Moravski | Exor Embedded S.r.l. wrote:
> Hi Zide,
>
> Your instructions were clear, unfortunately I'm still having issues.
>
> I have followed the instructions from https://projectacrn.github.io/latest/tutorials/kbl-nuc-sdc.html, and first upgraded
> Clear Linux to the same version as used there, just in case. Also I've rebuilt ACRN with CONFIG_CONSOLE_LOGLEVEL_DEFAULT
> now set to 5 (previously was 6).
>
> I've verified that I have all the required files on the EFI partition. I've added a new boot entry with:
>
>     sudo efibootmgr -c -l "\EFI\acrn\acrn.efi" -d /dev/mmcblk0 -p 1 -L "ACRN hypervisor" -u
>     "bootloader=\EFI\org.clearlinux\bootloaderx64.efi uart=bdf@0:18.0"
>
> Then I've set clr-boot-manager options according to instructions. This all went smoothly.
>
> After the reboot, ACRN loads. While it's waiting in the boot menu it continuously prints out a lot of these:
>
>     [21481383us][cpu=0][vm0:vcpu0][sev=4][seq=827]:Spurious vector: 0x50.
>     [21498377us][cpu=0][vm0:vcpu0][sev=4][seq=828]:Spurious vector: 0x50.
>     [21515373us][cpu=0][vm0:vcpu0][sev=4][seq=829]:Spurious vector: 0x50.
>     [21532360us][cpu=0][vm0:vcpu0][sev=4][seq=830]:Spurious vector: 0x50.
>     [21549353us][cpu=0][vm0:vcpu0][sev=4][seq=831]:Spurious vector: 0x50.
>
>
> When I choose the first option that I believe should start the Service OS, it then continuously prints out these:
>
>     [34072934us][cpu=3][vm0:vcpu3][sev=5][seq=1645]:VM 0 Starting CPU 3
>     [34079998us][cpu=0][vm0:vcpu0][sev=3][seq=1646]:vlapic: Start Secondary VCPU3 for VM[0]...
>     [34089037us][cpu=3][vm0:vcpu3][sev=5][seq=1647]:VM 0 Starting VCPU 3
>     [34096100us][cpu=0][vm0:vcpu0][sev=3][seq=1648]:vlapic: Start Secondary VCPU3 for VM[0]...
>     [34105131us][cpu=3][vm0:vcpu3][sev=5][seq=1649]:VM 0 Starting VCPU 3
>     [34112188us][cpu=0][vm0:vcpu0][sev=3][seq=1650]:vlapic: Start Secondary VCPU3 for VM[0]...
>
> ... and it never gets to SOS or ACRN console.
>
> As far as I know, there is nothing wrong with any of the CPU cores; all are enabled in BIOS; "top" in regular Clear Linux
> shows that all 4 cores are alive and occasionally doing something.
>
> Best regards,
>
>
>
> *Dubravko Moravski*
> /SW engineering/
> *Exor Embedded S.r.l.*
> p:     +38 512455659 <tel:+38 512455659>  m:+38 5915402413 <tel:+38 5915402413>
> a:     Slavonska avenija, 50, Zagreb, Croatia, 10000
> w:     exorint.com <https://exorint.com/>
>
>       
>
>
>   Prima di stampare pensa ai costi ambientali. Please consider the environment before printing this email.
>
> Privacy <https://www.exorint.com/it/privacy>
> --------------------------------------------------------------------------------------------------------------------------
> *From:* acrn-users@... <acrn-users@...> on behalf of Chen, Zide via
> Lists.Projectacrn.Org <zide.chen=intel.com@...>
> *Sent:* Monday, February 10, 2020 8:00 PM
> *To:* acrn-users@... <acrn-users@...>
> *Subject:* Re: [acrn-users] Getting ACRN to work
> Hi Dubravko,
>
> If you see endless vmexit messages, it's possibly that you have successfully loaded the guest kernel.
>
> You may remove the vmexit logs by configuring CONFIG_CONSOLE_LOGLEVEL_DEFAULT to any number < 6.
>
> Build it with "RELEASE=1" disables the hypervisor serial console so you won't be able to see anything. So it's discouraged
> to do that during bring-up.
>
> I'm expecting you can see the console prompt: "ACRN:\>", and you can try some basic commands like "help", "vm_list",
> "vcpu_list", etc. If you find any guest VM is running from "vm_list" command, you can switch to the guest console by
> "vm_console 0", and switch back to HV console by pressing "Ctrl + Space".
>
> https://projectacrn.github.io/latest/tutorials/debug.html?highlight=console
>
> If you don't see any VM running, you may following this tutorial (of cause you can try other scenario):
> https://projectacrn.github.io/latest/tutorials/kbl-nuc-sdc.html
>
> The key point is at the end you need to install a clear Linux bzImage and acrn.efi (sample:
> misc/efi-stub/clearlinux/acrn.conf) in the EFI partition, and the "Linux" line in acrn.efi points to the bzImage you
> installed.
>
>
> Best Regards,
> Zide
>
>
> On 2/10/20 10:39 AM, Dubravko Moravski | Exor Embedded S.r.l. wrote:
>> Hi Zide,
>>
>> You were right again, I don't know how it happened but my MAX_PCPU_NUM was set to 3, while there are 4 CPUs.
>>
>> MADT and DMAR tables seem to be correct.
>> I'm using acrn.efi, RELOC is enabled.
>>
>> Now the hypervisor seems to be almost working... The initialization seems to complete fine, then I'm getting a huge number
>> of printouts like these:
>>
>>     [836682306us][cpu=0][vm0:vcpu0][sev=6][seq=31854]:Exit Reason: 0x0000000000000001
>>     [836722306us][cpu=0][vm0:vcpu0][sev=6][seq=31855]:Exit Reason: 0x0000000000000001
>>     [836762306us][cpu=0][vm0:vcpu0][sev=6][seq=31856]:Exit Reason: 0x0000000000000001
>>     [836802306us][cpu=0][vm0:vcpu0][sev=6][seq=31857]:Exit Reason: 0x0000000000000001
>>
>> They continue indefinitely. As far as I can tell, there are no errors (unless these indicate some errors), but also
>> nothing else happens, just these printouts.
>>
>> RELEASE=1 build doesn't display the above printouts, but also nothing seems to happen.
>>
>> I think I might not have configured loading of the next stage (Linux loader) correctly, so it's possible that ACRN just
>> doesn't have anything to do. The tutorials aren't quite clear regarding doing that, for new custom boards. Though if
>> that's the problem, I would expect at least some warning message to be displayed. I'll check that first anyway.
>>
>> Thank you and best regards,
>> Dubravko
>>
>>
>>
>> *Dubravko Moravski*
>> /SW engineering/
>> *Exor Embedded S.r.l.*
>> p:     +38 512455659 <tel:+38 512455659>  m:+38 5915402413 <tel:+38 5915402413>
>> a:     Slavonska avenija, 50, Zagreb, Croatia, 10000
>> w:     exorint.com <https://exorint.com/>
>>
>>       
>>
>>
>>   Prima di stampare pensa ai costi ambientali. Please consider the environment before printing this email.
>>
>> Privacy <https://www.exorint.com/it/privacy>
>> --------------------------------------------------------------------------------------------------------------------------
>> *From:* acrn-users@... <acrn-users@...> on behalf of Chen, Zide via
>> Lists.Projectacrn.Org <zide.chen=intel.com@...>
>> *Sent:* Monday, February 10, 2020 5:50 PM
>> *To:* acrn-users@... <acrn-users@...>
>> *Subject:* Re: [acrn-users] Getting ACRN to work
>> Hi Dubravko,
>>
>> Did you boot ACRN from acrn.efi (UEFI) or acrn.bin (SBL), or acrn.32.out (Grub)? RELOC is enabled for acrn.efi, but not
>> others.
>>
>> For the init_percpu_lapic_init() issue, it's highly possibly that the user defined MAX_PCPU_NUM is less than the physical
>> CPU number from ACPI table.
>>
>> Other than that, probably you need to debug the parse_madt() and see if it can't find MADT table or corrupted MADT so that
>> it finds 0 pcpus.
>>
>> BTW, you can pull this PR to your code which may help your bring-up since it enables early panic() and other pr_err()
>> messages.
>> https://github.com/projectacrn/acrn-hypervisor/pull/4381
>>
>> Best Regards,
>> Zide
>>
>>
>>
>
>
>
>



Join acrn-users@lists.projectacrn.org to automatically receive all group messages.