Local java-network test failure

[SeanTAllen]

Happens for me with make run-hw (not make run-sw) with either debug or non-release build.

sean on dc-sean-dev in languages/java/network on  oe_port [!?]  make run-hw
sgx-lkl-java --hw-debug sgxlkl-java.img MainApp
[   SGX-LKL  ] SGX-LKL (OE) 0.2.0-dev (d3e0b9a) LKL 5.3.0 [DEBUG build (-O0)] [HARDWARE DEBUG]
[   SGX-LKL  ] nproc=8 ETHREADS=8 CMDLINE="mem=32M"
[   SGX-LKL  ] HW TLS support: conf->fsgsbase=1
[   SGX-LKL  ] Registering disk 0 (path='sgxlkl-java.img', mnt='/', [RW    ])
[   SGX-LKL  ] get_signed_libsgxlkl_path... result=/home/sean/code/lsds/test/build_musl/./libsgxlkl.so.signed
[   SGX-LKL  ] oe_create_enclave... result=0 (OE_OK)
[   SGX-LKL  ] sgxlkl_enclave_init(ethread_id=0)
[[  SGX-LKL ]] sgxlkl_enclave_init(): enter
[[  SGX-LKL ]] sgxlkl_enclave_show_attribute(): enclave base=0x7f9a80000000 size=1.043 GB
[[  SGX-LKL ]] sgxlkl_enclave_show_attribute(): enclave heap base=0x7f9a80b49000 size=1024.00 M end=0x7f9ac0b49000
[[  SGX-LKL ]] sgxlkl_enclave_init(): calling _dlstart_c()
[[  SGX-LKL ]] _register_enclave_signal_handlers(): Registering OE exception handler...
[[  SGX-LKL ]] lkl_start_init(): kernel command line: 'mem=32M console=hvc0'
[[  SGX-LKL ]] lkl_start_init(): lkl_start_kernel() called
[    0.000000] Linux version 5.3.0+ (sean@dc-sean-dev) (gcc version 7.5.0 (Ubuntu 7.5.0-3ubuntu1~18.04)) #1 Wed Jun 10 15:54:03 UTC 2020
[    0.000000] memblock address range: 0x7f9abe8c8000 - 0x7f9ac08c8000
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 8080
[    0.000000] Kernel command line: mem=32M console=hvc0 virtio_mmio.device=256@0x1000000:1 virtio_mmio.device=273@0x2000000:2
[    0.000000] Dentry cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.000000] Inode-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory available: 32176k/32768k RAM
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS: 4096
[    0.000000] lkl: irqs initialized
[    0.000000] clocksource: lkl: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] lkl: time and timers initialized (irq3)
[    0.000537] printk: console [hvc0] enabled
[    0.000537] pid_max: default: 4096 minimum: 301
[    0.001096] Mount-cache hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.001096] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.002211] devtmpfs: initialized
[    0.006822] random: get_random_bytes called from 0x00007f9a806649a4 with crng_init=0
[    0.006822] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.007326] futex hash table entries: 16 (order: -4, 384 bytes, linear)
[    0.007326] xor: automatically using best checksumming function   8regs
[    0.007326] NET: Registered protocol family 16
[    0.010059] clocksource: Switched to clocksource lkl
[    0.010615] NET: Registered protocol family 2
[    0.011188] tcp_listen_portaddr_hash hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.011188] TCP established hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.011188] TCP bind hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.011188] TCP: Hash tables configured (established 512 bind 512)
[    0.011748] UDP hash table entries: 128 (order: 0, 4096 bytes, linear)
[    0.011748] UDP-Lite hash table entries: 128 (order: 0, 4096 bytes, linear)
[    0.011748] NET: Registered protocol family 1
[    0.011748] virtio-mmio: Registering device virtio-mmio.0 at 0x1000000-0x10000ff, IRQ 1.
[    0.012297] virtio-mmio: Registering device virtio-mmio.1 at 0x2000000-0x2000110, IRQ 2.
[    0.012297] workingset: timestamp_bits=62 max_order=14 bucket_order=0
[    0.013964] NET: Registered protocol family 38
[    0.013964] io scheduler mq-deadline registered
[    0.013964] io scheduler kyber registered
[    0.097783] software IO TLB: mapped [mem 0x7f9b1c40b000-0x7f9b2040b000] (64MB)
[    0.101438] loop: module loaded
[    0.101998] device-mapper: ioctl: 4.40.0-ioctl (2019-01-18) initialised: [email protected]
[    0.103125] wireguard: WireGuard 0.0.20191219 loaded. See www.wireguard.com for information.
[    0.103125] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <[email protected]>. All Rights Reserved.
[    0.103684] NET: Registered protocol family 10
[    0.104244] Segment Routing with IPv6
[    0.104244] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.104805] This architecture does not have kernel memory protection.
[    0.105378] Run /init as init process
[[  SGX-LKL ]] lkl_start_init(): lkl_start_kernel() finished
[[  SGX-LKL ]] lkl_start_init(): creating LKL termination thread
[[  SGX-LKL ]] create_lkl_termination_thread(): enter
[[  SGX-LKL ]] lkl_start_init(): calling lkl_mount_virtial()
[[  SGX-LKL ]] lkl_termination_thread(): enter
[[  SGX-LKL ]] lkl_termination_thread(): Performed LKL syscall to get host task allocated (pid=36)
[[  SGX-LKL ]] lkl_start_init(): calling init_random()
[[  SGX-LKL ]] init_random(): Adding entropy to entropy pool
[    0.105936] random: crng init done
[[  SGX-LKL ]] init_enclave_clock(): Setting enclave realtime clock
[[  SGX-LKL ]] wg0 has public key quT14z9b7JSZU37M55ReMiTD9rf5CF21pUh93cQAVTE=
Azure Quote Provider: libdcap_quoteprov.so [ERROR]: Could not retreive environment variable for 'AZDCAP_DEBUG_LOG_LEVEL'
[    0.138647] virtio_blk virtio2: [vda] 819200 512-byte logical blocks (419 MB/400 MiB)
[[  SGX-LKL ]] lkl_mount_disk(): lkl_mount_disk(dev="/dev/vda", mnt="/mnt/vda", ro=0)
[    0.140323] EXT4-fs (vda): warning: mounting unchecked fs, running e2fsck is recommended
[    0.141452] EXT4-fs (vda): mounted filesystem without journal. Opts:
[[  SGX-LKL ]] lkl_mount_disks(): Set working directory: /
[[  SGX-LKL ]] libc_start_main_stage2(): Calling app main: /usr/bin/java
OpenJDK 64-Bit Server VM warning: Can't detect primordial thread stack location - find_vma failed
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00007f9abd065438, pid=36, tid=0x00007f9a80b56fb0
#
# JRE version: OpenJDK Runtime Environment (8.0_212-b04) (build 1.8.0_212-b04)
# Java VM: OpenJDK 64-Bit Server VM (25.212-b04 mixed mode linux-amd64 compressed oops)
# Derivative: IcedTea 3.12.0
# Distribution: Custom build (Sat May  4 17:33:35 UTC 2019)
# Problematic frame:
# J 643 C2 java.util.Arrays.equals([B[B)Z (54 bytes) @ 0x00007f9abd065438 [0x00007f9abd065420+0x18]
#
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
bad count while changing owner
[[  SGX-LKL ]] FAIL: Kernel panic! Aborting...
2020-06-10T16:01:49.000000Z [(H)ERROR] tid(0x7f9b117fa700) | :OE_ENCLAVE_ABORTING [/home/sean/openenclave-sgxlkl/host/calls.c:oe_call_enclave_function_by_table_id:91]
[   SGX-LKL  ] ethread (7: 19) [   SGX-LKL  ] FAIL: sgxlkl_ethread_init() failed (id=7 result=19 (OE_ENCLAVE_ABORTING))
Makefile:26: recipe for target 'run-hw' failed
make: *** [run-hw] Error 1

The segfault is caused by the network call in the Java program. I can recreate the error with this smaller program:

import java.io.*;
import java.net.*;

public class MainApp
{
        public static void main(String[] args) throws MalformedURLException {
                URL url = new URL("https://www.google.com/");
                try {
                    url.openStream();
                } catch (Exception e) {
                     System.out.println("x");
                }
        }
}

I've tested with 1 to 8 ETHREADS. Always the same result.

sgx-lkl commit: d3e0b9a
oe commit: 8fec3caf5acae75cd4657557d20f70d7e072f0ae

[SeanTAllen]

@davidchisnall @hukoyu can you try recreating locally when you have time and let me know if you get the same issue?

[hukoyu]

@SeanTAllen isn't this same issue with this one #245

[SeanTAllen]

Added the information I found to #245