Hi Michal,

I was able to reproduce it at my end. This problem was introduced in a recent refactor. The problem was that the code for configuring the VMM-side of cross vm connections (including those used by string_reverse) was not being linked into the VMM, so the required hypercall handlers were not registered.

I've fixed the problem, and the fix has been pushed to github.

Cheers,

Stephen

________________________________ From: Devel devel-bounces@sel4.systems on behalf of Michal Podhradsky mpodhradsky@galois.com Sent: Saturday, 20 May 2017 9:08 AM To: devel@sel4.systems Subject: [seL4] Fwd: k_vmm_manager: failed on sel4 hypervisor connection

Hello all,

I am running camkes-vm on x86 architecture, following the example on wiki https://wiki.sel4.systems/CAmkESVM#Cross_VM_Connectors with the exception that I want to invoke the stringReverse componenthttps://github.com/podhrmic/camkes-vm/tree/master/components/StringReverse.

I am running the optiplex9020_defconfig example with only one VM, and when I start booting the guest linux system, I see the following error:

[ 1.282326] dataport: loading out-of-tree module taints kernel. [ 1.290615] dataport: module license 'unspecified' taints kernel. [ 1.306854] Disabling lock debugging due to kernel taint [ 1.319664] dataport initialized with major number 247 vmm_vmcall_handler:55 | Failed to find handler for token:2 [ 1.325411] incorrect event context magic number (expected 42, got -677408512)insmod: can't insert '/lib/modules/4.8.16/kernel/drivers/vmm/consumes_event.ko': Operation not ermitted [ 1.337441] emits_event initialized with major number 245 [ 1.356391] k_vmm_manager: failed on sel4 hypervisor connection |-1|

Then when I log into linux and call `string_reversehttps://github.com/podhrmic/camkes-vm/tree/master/linux/pkg/string_reverse` program, I get the following error:

# string_reverse [ 8.360164] BUG: unable to handle kernel paging request at d881f2c0 [ 8.360164] IP: [<d00a69f0>] chrdev_open+0xab/0x100 [ 8.360164] *pde = 17867067 *pte = 00000000 [ 8.360164] Oops: 0000 [#1] [ 8.360164] Modules linked in: emits_event(PO) dataport(PO) [ 8.360164] CPU: 0 PID: 691 Comm: string_reverse Tainted: P O 4.8.16 #1 [ 8.360164] task: d79c9740 task.stack: d6ae0000 [ 8.360164] EIP: 0060:[<d00a69f0>] EFLAGS: 00010286 CPU: 0 [ 8.360164] EIP is at chrdev_open+0xab/0x100 [ 8.360164] EAX: d881f2c0 EBX: 00000000 ECX: d79b0d00 EDX: 00000000 [ 8.360164] ESI: d79b0d00 EDI: d6add808 EBP: d6ae1e10 ESP: d6ae1df8 [ 8.360164] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 [ 8.360164] CR0: 80050033 CR2: d881f2c0 CR3: 16ad9000 CR4: 00102690 [ 8.360164] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 8.360164] DR6: fffe0ff0 DR7: 00000400 [ 8.360164] Stack: [ 8.360164] d7ac9be0 d7ac9be0 00000001 d7ac9be0 d6add808 00000000 d6ae1e30 d00a2370 [ 8.360164] d6ae1e28 d7ac9be8 d00a6945 d7ac9be0 d69db010 d7462d80 d6ae1e4c d00a2cf8 [ 8.360164] d79c2b80 d79c2b80 00000000 d6ae1ebc d7462d80 d6ae1eb0 d00ae159 d6ae1e64 [ 8.360164] Call Trace: [ 8.360164] [<d00a2370>] do_dentry_open+0x197/0x216 [ 8.360164] [<d00a6945>] ? cdev_put+0x1a/0x1a [ 8.360164] [<d00a2cf8>] vfs_open+0x45/0x4e [ 8.360164] [<d00ae159>] path_openat+0x822/0x970 [ 8.360164] [<d007a468>] ? __alloc_pages_nodemask+0x11c/0x770 [ 8.360164] [<d00ae2d8>] do_filp_open+0x31/0x77 [ 8.360164] [<d00b6293>] ? __alloc_fd+0xbb/0xfe [ 8.360164] [<d00a2e56>] do_sys_open+0x54/0xc7 [ 8.360164] [<d00a2ee1>] SyS_open+0x18/0x1a [ 8.360164] [<d0000ee1>] do_fast_syscall_32+0x7a/0xb8 [ 8.360164] [<d047831f>] sysenter_past_esp+0x40/0x6a [ 8.360164] Code: 11 89 f0 e8 e1 fa ff ff 83 f8 01 19 db 31 d2 83 e3 fa 89 d0 e8 4d ff ff ff 85 db 75 59 8b 46 28 85 c0 75 0c [ 8.360164] EIP: [<d00a69f0>] chrdev_open+0xab/0x100 SS:ESP 0068:d6ae1df8 [ 8.360164] CR2: 00000000d881f2c0 [ 8.360164] ---[ end trace 46873a57a343e435 ]--- [ 8.376285] string_reverse (691) used greatest stack depth: 6496 bytes left Killed

which seems like the program is trying to access memory that it is not supposed to.

If I follow the example from wiki (here https://wiki.sel4.systems/CAmkESVM#Cross_VM_Connectors ) I get the same error, but triggered by `print_client` program.

Have you seen a problem like this before? How do I correctly load the kernel module?

Regards Michal

Hi Michal,

That's expected behaviour. The string_reverse program reverses each line of its standard input. After running string_reverse, try typing something and hitting enter.

The "dataport received mmap..." messages are the cross vm dataport linux kernel module reporting that something has mmaped a dataport.

Cheers,

Stephen

________________________________ From: Devel devel-bounces@sel4.systems on behalf of Michal Podhradsky mpodhradsky@galois.com Sent: Wednesday, 7 June 2017 9:04 AM To: devel@sel4.systems Subject: Re: [seL4] Fwd: k_vmm_manager: failed on sel4 hypervisor connection

Hi Stephen,

I tried the new code (repo init -u https://github.com/seL4/camkes-vm-manifest -m default.xml) with the same optiplex target and got these results:

[ 1.429435] dataport initialized with major number 247 [ 1.435347] consumes_event initialized with major number 246 [ 1.447805] emits_event initialized with major number 245 [ 1.454040] k_vmm_manager: failed on sel4 hypervisor connection |-1| insmod: can't insert '/lib/modules/4.8.16/kernel/drivers/vmm/vmm_manager.ko': Invalid argument

When I log in to shell and try the string_reverse command I now get following:

# string_reverse [ 9.228267] dataport received mmap for minor 1 [ 9.237493] dataport received mmap for minor 2

and no reply. Is that the expected behavior? Looks like there is still some issue with hypervisor connection.

Regards Michal

On Wed, May 24, 2017 at 6:37 PM, <Stephen.Sherratt@data61.csiro.aumailto:Stephen.Sherratt@data61.csiro.au> wrote:

Hi Michal,

I was able to reproduce it at my end. This problem was introduced in a recent refactor. The problem was that the code for configuring the VMM-side of cross vm connections (including those used by string_reverse) was not being linked into the VMM, so the required hypercall handlers were not registered.

I've fixed the problem, and the fix has been pushed to github.

Cheers,

Stephen

________________________________ From: Devel devel-bounces@sel4.systems on behalf of Michal Podhradsky <mpodhradsky@galois.commailto:mpodhradsky@galois.com> Sent: Saturday, 20 May 2017 9:08 AM To: devel@sel4.systems Subject: [seL4] Fwd: k_vmm_manager: failed on sel4 hypervisor connection

Hello all,

I am running camkes-vm on x86 architecture, following the example on wiki https://wiki.sel4.systems/CAmkESVM#Cross_VM_Connectors with the exception that I want to invoke the stringReverse componenthttps://github.com/podhrmic/camkes-vm/tree/master/components/StringReverse.

I am running the optiplex9020_defconfig example with only one VM, and when I start booting the guest linux system, I see the following error:

[ 1.282326] dataport: loading out-of-tree module taints kernel. [ 1.290615] dataport: module license 'unspecified' taints kernel. [ 1.306854] Disabling lock debugging due to kernel taint [ 1.319664] dataport initialized with major number 247 vmm_vmcall_handler:55 | Failed to find handler for token:2 [ 1.325411] incorrect event context magic number (expected 42, got -677408512)insmod: can't insert '/lib/modules/4.8.16/kernel/drivers/vmm/consumes_event.ko': Operation not ermitted [ 1.337441] emits_event initialized with major number 245 [ 1.356391] k_vmm_manager: failed on sel4 hypervisor connection |-1|

Then when I log into linux and call `string_reversehttps://github.com/podhrmic/camkes-vm/tree/master/linux/pkg/string_reverse` program, I get the following error:

# string_reverse [ 8.360164] BUG: unable to handle kernel paging request at d881f2c0 [ 8.360164] IP: [<d00a69f0>] chrdev_open+0xab/0x100 [ 8.360164] *pde = 17867067 *pte = 00000000 [ 8.360164] Oops: 0000 [#1] [ 8.360164] Modules linked in: emits_event(PO) dataport(PO) [ 8.360164] CPU: 0 PID: 691 Comm: string_reverse Tainted: P O 4.8.16 #1 [ 8.360164] task: d79c9740 task.stack: d6ae0000 [ 8.360164] EIP: 0060:[<d00a69f0>] EFLAGS: 00010286 CPU: 0 [ 8.360164] EIP is at chrdev_open+0xab/0x100 [ 8.360164] EAX: d881f2c0 EBX: 00000000 ECX: d79b0d00 EDX: 00000000 [ 8.360164] ESI: d79b0d00 EDI: d6add808 EBP: d6ae1e10 ESP: d6ae1df8 [ 8.360164] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 [ 8.360164] CR0: 80050033 CR2: d881f2c0 CR3: 16ad9000 CR4: 00102690 [ 8.360164] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 8.360164] DR6: fffe0ff0 DR7: 00000400 [ 8.360164] Stack: [ 8.360164] d7ac9be0 d7ac9be0 00000001 d7ac9be0 d6add808 00000000 d6ae1e30 d00a2370 [ 8.360164] d6ae1e28 d7ac9be8 d00a6945 d7ac9be0 d69db010 d7462d80 d6ae1e4c d00a2cf8 [ 8.360164] d79c2b80 d79c2b80 00000000 d6ae1ebc d7462d80 d6ae1eb0 d00ae159 d6ae1e64 [ 8.360164] Call Trace: [ 8.360164] [<d00a2370>] do_dentry_open+0x197/0x216 [ 8.360164] [<d00a6945>] ? cdev_put+0x1a/0x1a [ 8.360164] [<d00a2cf8>] vfs_open+0x45/0x4e [ 8.360164] [<d00ae159>] path_openat+0x822/0x970 [ 8.360164] [<d007a468>] ? __alloc_pages_nodemask+0x11c/0x770 [ 8.360164] [<d00ae2d8>] do_filp_open+0x31/0x77 [ 8.360164] [<d00b6293>] ? __alloc_fd+0xbb/0xfe [ 8.360164] [<d00a2e56>] do_sys_open+0x54/0xc7 [ 8.360164] [<d00a2ee1>] SyS_open+0x18/0x1a [ 8.360164] [<d0000ee1>] do_fast_syscall_32+0x7a/0xb8 [ 8.360164] [<d047831f>] sysenter_past_esp+0x40/0x6a [ 8.360164] Code: 11 89 f0 e8 e1 fa ff ff 83 f8 01 19 db 31 d2 83 e3 fa 89 d0 e8 4d ff ff ff 85 db 75 59 8b 46 28 85 c0 75 0c [ 8.360164] EIP: [<d00a69f0>] chrdev_open+0xab/0x100 SS:ESP 0068:d6ae1df8 [ 8.360164] CR2: 00000000d881f2c0 [ 8.360164] ---[ end trace 46873a57a343e435 ]--- [ 8.376285] string_reverse (691) used greatest stack depth: 6496 bytes left Killed

which seems like the program is trying to access memory that it is not supposed to.

If I follow the example from wiki (here https://wiki.sel4.systems/CAmkESVM#Cross_VM_Connectors ) I get the same error, but triggered by `print_client` program.

Have you seen a problem like this before? How do I correctly load the kernel module?

Regards Michal

_______________________________________________ Devel mailing list Devel@sel4.systems https://sel4.systems/lists/listinfo/devel

Hi Michal,

Good to hear it's working.

That error message comes from our vchan kernel module, which is unrelated to the cross vm connections. Without looking too deeply at it, it seems like the VMM-side of vchan isn't initialized, but we still try to load the module in linux.

Cheers,

Stephen

________________________________ From: Devel devel-bounces@sel4.systems on behalf of Michal Podhradsky mpodhradsky@galois.com Sent: Thursday, 8 June 2017 2:19 AM To: devel@sel4.systems Subject: Re: [seL4] Fwd: k_vmm_manager: failed on sel4 hypervisor connection

Hi Steven,

thanks for clarification - indeed I can reverse strings now.

I think I was confused by the kernel error message

[ 1.454040] k_vmm_manager: failed on sel4 hypervisor connection |-1| insmod: can't insert '/lib/modules/4.8.16/kernel/drivers/vmm/vmm_manager.ko': Invalid argument

but looks like that has no effect on functionality of string reverse. Is that message just a very verbose kernel?

Regards Michal

On Tue, Jun 6, 2017 at 8:46 PM, <Stephen.Sherratt@data61.csiro.aumailto:Stephen.Sherratt@data61.csiro.au> wrote:

Hi Michal,

That's expected behaviour. The string_reverse program reverses each line of its standard input. After running string_reverse, try typing something and hitting enter.

The "dataport received mmap..." messages are the cross vm dataport linux kernel module reporting that something has mmaped a dataport.

Cheers,

Stephen

________________________________ From: Devel devel-bounces@sel4.systems on behalf of Michal Podhradsky <mpodhradsky@galois.commailto:mpodhradsky@galois.com> Sent: Wednesday, 7 June 2017 9:04 AM To: devel@sel4.systems Subject: Re: [seL4] Fwd: k_vmm_manager: failed on sel4 hypervisor connection

Hi Stephen,

I tried the new code (repo init -u https://github.com/seL4/camkes-vm-manifest -m default.xml) with the same optiplex target and got these results:

[ 1.429435] dataport initialized with major number 247 [ 1.435347] consumes_event initialized with major number 246 [ 1.447805] emits_event initialized with major number 245 [ 1.454040] k_vmm_manager: failed on sel4 hypervisor connection |-1| insmod: can't insert '/lib/modules/4.8.16/kernel/drivers/vmm/vmm_manager.ko': Invalid argument

When I log in to shell and try the string_reverse command I now get following:

# string_reverse [ 9.228267] dataport received mmap for minor 1 [ 9.237493] dataport received mmap for minor 2

and no reply. Is that the expected behavior? Looks like there is still some issue with hypervisor connection.

Regards Michal

On Wed, May 24, 2017 at 6:37 PM, <Stephen.Sherratt@data61.csiro.aumailto:Stephen.Sherratt@data61.csiro.au> wrote:

Hi Michal,

I was able to reproduce it at my end. This problem was introduced in a recent refactor. The problem was that the code for configuring the VMM-side of cross vm connections (including those used by string_reverse) was not being linked into the VMM, so the required hypercall handlers were not registered.

I've fixed the problem, and the fix has been pushed to github.

Cheers,

Stephen

________________________________ From: Devel devel-bounces@sel4.systems on behalf of Michal Podhradsky <mpodhradsky@galois.commailto:mpodhradsky@galois.com> Sent: Saturday, 20 May 2017 9:08 AM To: devel@sel4.systems Subject: [seL4] Fwd: k_vmm_manager: failed on sel4 hypervisor connection

Hello all,

I am running camkes-vm on x86 architecture, following the example on wiki https://wiki.sel4.systems/CAmkESVM#Cross_VM_Connectors with the exception that I want to invoke the stringReverse componenthttps://github.com/podhrmic/camkes-vm/tree/master/components/StringReverse.

I am running the optiplex9020_defconfig example with only one VM, and when I start booting the guest linux system, I see the following error:

[ 1.282326] dataport: loading out-of-tree module taints kernel. [ 1.290615] dataport: module license 'unspecified' taints kernel. [ 1.306854] Disabling lock debugging due to kernel taint [ 1.319664] dataport initialized with major number 247 vmm_vmcall_handler:55 | Failed to find handler for token:2 [ 1.325411] incorrect event context magic number (expected 42, got -677408512)insmod: can't insert '/lib/modules/4.8.16/kernel/drivers/vmm/consumes_event.ko': Operation not ermitted [ 1.337441] emits_event initialized with major number 245 [ 1.356391] k_vmm_manager: failed on sel4 hypervisor connection |-1|

Then when I log into linux and call `string_reversehttps://github.com/podhrmic/camkes-vm/tree/master/linux/pkg/string_reverse` program, I get the following error:

# string_reverse [ 8.360164] BUG: unable to handle kernel paging request at d881f2c0 [ 8.360164] IP: [<d00a69f0>] chrdev_open+0xab/0x100 [ 8.360164] *pde = 17867067 *pte = 00000000 [ 8.360164] Oops: 0000 [#1] [ 8.360164] Modules linked in: emits_event(PO) dataport(PO) [ 8.360164] CPU: 0 PID: 691 Comm: string_reverse Tainted: P O 4.8.16 #1 [ 8.360164] task: d79c9740 task.stack: d6ae0000 [ 8.360164] EIP: 0060:[<d00a69f0>] EFLAGS: 00010286 CPU: 0 [ 8.360164] EIP is at chrdev_open+0xab/0x100 [ 8.360164] EAX: d881f2c0 EBX: 00000000 ECX: d79b0d00 EDX: 00000000 [ 8.360164] ESI: d79b0d00 EDI: d6add808 EBP: d6ae1e10 ESP: d6ae1df8 [ 8.360164] DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 0068 [ 8.360164] CR0: 80050033 CR2: d881f2c0 CR3: 16ad9000 CR4: 00102690 [ 8.360164] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 8.360164] DR6: fffe0ff0 DR7: 00000400 [ 8.360164] Stack: [ 8.360164] d7ac9be0 d7ac9be0 00000001 d7ac9be0 d6add808 00000000 d6ae1e30 d00a2370 [ 8.360164] d6ae1e28 d7ac9be8 d00a6945 d7ac9be0 d69db010 d7462d80 d6ae1e4c d00a2cf8 [ 8.360164] d79c2b80 d79c2b80 00000000 d6ae1ebc d7462d80 d6ae1eb0 d00ae159 d6ae1e64 [ 8.360164] Call Trace: [ 8.360164] [<d00a2370>] do_dentry_open+0x197/0x216 [ 8.360164] [<d00a6945>] ? cdev_put+0x1a/0x1a [ 8.360164] [<d00a2cf8>] vfs_open+0x45/0x4e [ 8.360164] [<d00ae159>] path_openat+0x822/0x970 [ 8.360164] [<d007a468>] ? __alloc_pages_nodemask+0x11c/0x770 [ 8.360164] [<d00ae2d8>] do_filp_open+0x31/0x77 [ 8.360164] [<d00b6293>] ? __alloc_fd+0xbb/0xfe [ 8.360164] [<d00a2e56>] do_sys_open+0x54/0xc7 [ 8.360164] [<d00a2ee1>] SyS_open+0x18/0x1a [ 8.360164] [<d0000ee1>] do_fast_syscall_32+0x7a/0xb8 [ 8.360164] [<d047831f>] sysenter_past_esp+0x40/0x6a [ 8.360164] Code: 11 89 f0 e8 e1 fa ff ff 83 f8 01 19 db 31 d2 83 e3 fa 89 d0 e8 4d ff ff ff 85 db 75 59 8b 46 28 85 c0 75 0c [ 8.360164] EIP: [<d00a69f0>] chrdev_open+0xab/0x100 SS:ESP 0068:d6ae1df8 [ 8.360164] CR2: 00000000d881f2c0 [ 8.360164] ---[ end trace 46873a57a343e435 ]--- [ 8.376285] string_reverse (691) used greatest stack depth: 6496 bytes left Killed

which seems like the program is trying to access memory that it is not supposed to.

If I follow the example from wiki (here https://wiki.sel4.systems/CAmkESVM#Cross_VM_Connectors ) I get the same error, but triggered by `print_client` program.

Have you seen a problem like this before? How do I correctly load the kernel module?

Regards Michal

_______________________________________________ Devel mailing list Devel@sel4.systems https://sel4.systems/lists/listinfo/devel

_______________________________________________ Devel mailing list Devel@sel4.systems https://sel4.systems/lists/listinfo/devel