I tried to run Java 12 on OSv and simple apps like java-example and
java-httpserver work. But more complicated like spring-boot-example or
jetty seem to hang early on.
Here is the output:
./scripts/build image=openjdk12-zulu,jetty fs=rofs
./scripts/run.py -V -c 1
OSv v0.53.0-53-ge9ef51b2
1 CPUs detected
Firmware vendor: SeaBIOS
bsd: initializing - done
VFS: mounting ramfs at /
VFS: mounting devfs at /dev
net: initializing - done
vga: Add VGA device instance
eth0: ethernet address: 52:54:00:12:34:56
virtio-blk: Add blk device instances 0 as vblk0, devsize=75520512
random: virtio-rng registered as a source.
random: intel drng, rdrand registered as a source.
random: <Software, Yarrow> initialized
VFS: unmounting /dev
VFS: mounting rofs at /rofs
VFS: mounting devfs at /dev
VFS: mounting procfs at /proc
VFS: mounting ramfs at /tmp
[I/27 dhcp]: Broadcasting DHCPDISCOVER message with xid: [662656670]
[I/27 dhcp]: Waiting for IP...
[I/35 dhcp]: Received DHCPOFFER message from DHCP server: 192.168.122.1
regarding offerred IP address: 192.168.122.15
[I/35 dhcp]: Broadcasting DHCPREQUEST message with xid: [662656670] to
SELECT offered IP: 192.168.122.15
[I/35 dhcp]: Received DHCPACK message from DHCP server: 192.168.122.1
regarding offerred IP address: 192.168.122.15
[I/35 dhcp]: Server acknowledged IP 192.168.122.15 for interface eth0 with
time to lease in seconds: 86400
eth0: 192.168.122.15
[I/35 dhcp]: Configuring eth0: ip 192.168.122.15 subnet mask 255.255.255.0
gateway 192.168.122.1 MTU 1500
Booted up in 152.21 ms
java.so: Starting JVM app using: io/osv/nonisolated/RunNonIsolatedJvmApp
java.so: Setting Java system classloader to NonIsolatingOsvSystemClassLoader
random: device unblocked.
and gdb threads and the initial thread stacktrace I get after connecting
with gdb:
(gdb) bt
#0 0x00000000403e1acc in lockfree::mutex::lock
(this=this@entry=0xffffa0000431b410)
at /usr/include/c++/8/bits/atomic_base.h:512
#1 0x00000000403e36a0 in std::lock_guard<lockfree::mutex>::lock_guard
(__m=..., this=<synthetic pointer>)
at /usr/include/c++/8/bits/std_mutex.h:161
#2 lock_guard_for_with_lock<lockfree::mutex>::lock_guard_for_with_lock
(lock=..., this=<synthetic pointer>)
at include/osv/mutex.h:89
#3 semaphore::trywait (this=0xffffa0000431b400, units=units@entry=1) at
core/semaphore.cc:64
#4 0x00000000404656c1 in sem_trywait (s=<optimized out>) at
/usr/include/c++/8/bits/unique_ptr.h:342
#5 0x00001000012feb22 in PosixSemaphore::trywait() ()
#6 0x0000100000e19de4 in VM_HandshakeAllThreads::doit() ()
#7 0x0000100001575fd7 in VM_Operation::evaluate() ()
#8 0x000010000157bdb6 in VMThread::evaluate_operation(VM_Operation*)
[clone .constprop.67] ()
#9 0x000010000157c50a in VMThread::loop() ()
#10 0x000010000157c6e3 in VMThread::run() ()
#11 0x000010000150479f in Thread::call_run() ()
#12 0x000010000122cbae in thread_native_entry(Thread*) ()
#13 0x000000004045edb6 in pthread_private::pthread::<lambda()>::operator()
(__closure=0xffffa00002ca9d00)
at libc/pthread.cc:114
#14 std::_Function_handler<void(), pthread_private::pthread::pthread(void*
(*)(void*), void*, sigset_t, const
pthread_private::thread_attr*)::<lambda()> >::_M_invoke(const
std::_Any_data &) (__functor=...)
at /usr/include/c++/8/bits/std_function.h:297
#15 0x0000000040401117 in sched::thread_main_c (t=0xffff800003175040) at
arch/x64/arch-switch.hh:271
#16 0x00000000403a7083 in thread_main () at arch/x64/entry.S:113
1 (0xffff80000000c040) reclaimer cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 4.3944e-25
2 (0xffff800000050040) page-access-sca cpu0 status::waiting
pagecache::access_scanner::run() at core/pagecache.cc:593 vruntime
127576
timers: 63.727309402
3 (0xffff800000068040) page_pool_l2 cpu0 status::waiting
memory::page_pool::l2::fill_thread() at core/mempool.cc:1346 vruntime
6.05067e-21
4 (0xffff800000085040) itimer-real cpu? status::unstarted ?? at
arch/x64/entry.S:112 vruntime 0
5 (0xffff80000008b040) itimer-virt cpu? status::unstarted ?? at
arch/x64/entry.S:112 vruntime 0
6 (0xffff80000013f040) balancer0 cpu0 status::waiting ?? at
arch/x64/entry.S:113 vruntime 1414.8
timers: 63.807163741
7 (0xffff800000156040) rcu0 cpu0 status::waiting
osv::rcu::cpu_quiescent_state_thread::do_work() at core/rcu.cc:178
vruntime 5.29913e-25
8 (0xffff80000016d040) page_pool_l1_0 cpu0 status::waiting
memory::page_pool::l1::fill_thread() at core/mempool.cc:1258 vruntime
5.84375e-21
9 (0xffff800000184040) percpu0 cpu0 status::waiting
workman::call_of_duty() at core/percpu-worker.cc:92 vruntime 4.65289e-25
10 (0xffff80000019b040) async_worker0 cpu0 status::waiting
async::async_worker::run() at core/async.cc:158 vruntime 3.87741e-25
11 (0xffff8000001b2040) idle0 cpu0 status::queued
std::_Function_handler<void(), sched::cpu::init_idle_thread()::<lambda()>
>::_M_invoke(const std::_Any_data &) at
/usr/include/c++/8/bits/std_function.h:297 vruntime inf
12 (0xffff800000afa040) >init cpu0 status::waiting
std::_Function_handler<void (),
osv::acpi_interrupt::acpi_interrupt(unsigned int, unsigned int (*)(void*),
void*)::{lambda()#1}>::_M_invoke(std::_Any_data const&) at
/usr/include/c++/8/bits/std_function.h:297 vruntime 5.95829e-24
13 (0xffff800000b11040) >init cpu0 status::waiting
std::_Function_handler<void(), sched::thread::reaper::reaper()::<lambda()>
>::_M_invoke(const std::_Any_data &) at
/usr/include/c++/8/bits/std_function.h:297 vruntime 5.88074e-24
14 (0xffff800000b28040) thread taskq cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 6.04876e-24
15 (0xffff800000b33040) callout cpu0 status::waiting
_callout_thread() at bsd/porting/callout.cc:138 vruntime 936.234
timers: 63.807143836
16 (0xffff800000b4c040) system_taskq_0 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 6.00998e-24
17 (0xffff800000b57040) system_taskq_1 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 5.82904e-24
18 (0xffff800000b62040) system_taskq_2 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 5.82904e-24
19 (0xffff800000b6d040) system_taskq_3 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 5.80319e-24
20 (0xffff800000b78040) system_taskq_4 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 5.85489e-24
21 (0xffff800000b83040) system_taskq_5 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at bs
22 (0xffff800000b8e040) system_taskq_6 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 5.84196e-24
23 (0xffff800000b99040) system_taskq_7 cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 5.82904e-24
24 (0xffff800000fe8040) solthread-0x402 cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 22.707
timers: 64.002825055
25 (0xffff800000ff3040) solthread-0x402 cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 2.35645
timers: 64.002826619
26 (0xffff80000101a040) netisr cpu0 status::waiting
netisr_osv_thread_wrapper(void (*)(void*), void*) at
bsd/sys/net/netisr1.cc:26 vruntime 1.68797e-23
27 (0xffff800001181040) >init cpu0 status::waiting
sched::thread::join() at core/sched.cc:1311 vruntime 6.39851e-20
joining on <optimized out>
28 (0xffff80000119b040) virtio-net-rx cpu0 status::waiting
virtio::virtio_driver::wait_for_queue(virtio::vring*, bool
(virtio::vring::*)() const) at drivers/virtio.cc:160 vruntime 2.39361e-28
29 (0xffff8000011c3040) virtio-tx-0 cpu0 status::waiting
sched::thread::do_wait_until<sched::noninterruptible,
sched::thread::dummy_lock, osv::xmitter<virtio::net::txq, 4096u,
std::function<bool ()>,
boost::iterators::function_output_iterator<osv::xmitter_functor<virtio::net::txq>
> >::poll_until()::{lambda()#1}>(sched::thread::dummy_lock&,
osv::xmitter<virtio::net::txq, 4096u, std::function<bool ()>,
boost::iterators::function_output_iterator<osv::xmitter_functor<virtio::net::txq>
> >::poll_until()::{lambda()#1}) at
/usr/include/c++/8/bits/atomic_base.h:390 vruntime 9.29284e-29
30 (0xffff8000012dd040) virtio-blk cpu0 status::waiting
virtio::virtio_driver::wait_for_queue(virtio::vring*, bool
(virtio::vring::*)() const) at drivers/virtio.cc:160 vruntime 4.61277e-21
31 (0xffff8000012f4040) virtio-rng cpu0 status::waiting
virtio::virtio_driver::wait_for_queue(virtio::vring*, bool
(virtio::vring::*)() const) at drivers/virtio.cc:160 vruntime 0.941162
32 (0xffff80000130e040) isa-serial-inpu cpu0 status::waiting
console::LineDiscipline::read_poll(console::console_driver*) at
drivers/line-discipline.cc:86 vruntime 1.38294e-23
33 (0xffff800001325040) kbd-input cpu0 status::waiting
console::LineDiscipline::read_poll(console::console_driver*) at
drivers/line-discipline.cc:86 vruntime 1.40233e-23
34 (0xffff800001347040) rand_harvestq cpu0 status::waiting
synch_port::_msleep(void*, mtx*, int, char const*, int) at
bsd/porting/synch.cc:101 vruntime 4507
timers: 63.730925282
35 (0xffff800001367040) dhcp cpu0 status::waiting
dhcp::dhcp_worker::dhcp_worker_fn() at core/dhcp.cc:828 vruntime
7.61456e-21
36 (0xffff8000014b3040) java.so cpu0 status::waiting
sched::thread::join() at core/sched.cc:1311 vruntime 1.39354e-22
joining on <optimized out>
37 (0xffff8000014b9040) >java.so cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 4.15911e-19
38 (0xffff800003175040) VM Thread cpu0 status::running
lockfree::mutex::lock() at /usr/include/c++/8/bits/atomic_base.h:512
vruntime 1.12722e+07
39 (0xffff800003480040) Reference Handl cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 2.93597e-22
40 (0xffff80000358f040) Finalizer cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 2.90547e-22
41 (0xffff80000372e040) Signal Dispatch cpu0 status::waiting
semaphore::wait(unsigned int, sched::timer*) at core/semaphore.cc:46
vruntime 1.49254e-22
42 (0xffff800003834040) C2 CompilerThre cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 6.14524e-05
timers: 65.498438192
43 (0xffff800003a55040) C1 CompilerThre cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 6.00219e-05
timers: 65.501513376
44 (0xffff800003b7f040) Sweeper thread cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 1.0315e-20
45 (0xffff80000425f040) Common-Cleaner cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 0.000185609
timers: 120.420613278
46 (0xffff8000045cd040) Service Thread cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 3.28391e-22
47 (0xffff8000046dc040) VM Periodic Tas cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 2725.28
timers: 63.727339031
48 (0xffff800004a5b040) Thread-1 cpu0 status::waiting
condvar::wait(lockfree::mutex*, sched::timer*) at core/condvar.cc:43
vruntime 4.80877e-20
Number of threads: 48
This smells like a deadlock, somewhere early in JIT compiler (C1/C2
compiler threads). Any suggestions on how to debug it further? Enable some
tracepoints?
The same app (jetty in this case) works fine with previous Java 11.
Waldek
--
You received this message because you are subscribed to the Google Groups "OSv
Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to osv-dev+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/osv-dev/4ab29228-2890-4236-a730-461671ed2a45%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
