[batch] maybe reduce average JVMJob "connecting to jvm" time #13870

danking · 2023-10-20T05:04:40Z

No description provided.

danking · 2023-10-20T05:06:14Z

batch/batch/worker/worker.py


    async def recreate_jvm(self, jvm: JVM):
-        self._jvms.remove(jvm)


I think this is a latent bug; the JVM is still owned by the job when recreate_jvm is called, it won't be in this array. If this every happened it would fail.

danking · 2023-10-20T05:07:55Z

batch/batch/worker/worker.py

@@ -2984,8 +3004,9 @@ async def shutdown(self):
        log.info('Worker.shutdown')
        self._jvm_initializer_task.cancel()
        async with AsyncExitStack() as cleanup:
-            for jvm in self._jvms:


this seems a bit odd; the JVMs might still be held by jobs, right?

This reverts commit 44a2d4e.

danking · 2023-10-20T15:30:03Z

It takes about 1.3s to start a JVM.

INFO 2023-10-20T05:19:41.171496149Z [resource.labels.instanceId: 5522146237091918701] JVM-0: trying to establish connection; elapsed time: 0.0 seconds
INFO 2023-10-20T05:19:42.258313605Z [resource.labels.instanceId: 5522146237091918701] listening on /host/jvm-4ed4369f8e4241a69ad5aa4ddbbc94ac/socket
INFO 2023-10-20T05:19:42.426801136Z [resource.labels.instanceId: 5522146237091918701] negotiating start up with worker
INFO 2023-10-20T05:19:42.465000271Z [resource.labels.instanceId: 5522146237091918701] JVM-1: trying to establish connection; elapsed time: 0.0 seconds
INFO 2023-10-20T05:19:43.492820485Z [resource.labels.instanceId: 5522146237091918701] listening on /host/jvm-d674ae13bb154cd59e8a0ef0f36ee890/socket
INFO 2023-10-20T05:19:43.722434655Z [resource.labels.instanceId: 5522146237091918701] negotiating start up with worker
INFO 2023-10-20T05:19:43.759994063Z [resource.labels.instanceId: 5522146237091918701] JVM-2: trying to establish connection; elapsed time: 0.0 seconds
INFO 2023-10-20T05:19:44.860396159Z [resource.labels.instanceId: 5522146237091918701] listening on /host/jvm-9cee668d601a4b7cb272b21c9b14fa19/socket
INFO 2023-10-20T05:19:45.021762412Z [resource.labels.instanceId: 5522146237091918701] negotiating start up with worker
INFO 2023-10-20T05:19:45.060262301Z [resource.labels.instanceId: 5522146237091918701] JVM-3: trying to establish connection; elapsed time: 0.0 seconds
INFO 2023-10-20T05:19:46.169876471Z [resource.labels.instanceId: 5522146237091918701] listening on /host/jvm-65900a48075b423796c4d2bbdaf16845/socket
INFO 2023-10-20T05:19:46.319864345Z [resource.labels.instanceId: 5522146237091918701] negotiating start up with worker

jigold · 2023-10-20T18:59:30Z

batch/batch/worker/worker.py

+                    n_cores = self._jvm_waiters.get_nowait()
+                    jvmqueue = self._jvms_by_cores[n_cores]
+                    jvmqueue.queue.put_nowait(await JVM.create(global_jvm_index, n_cores, self))
+                    jvmqueue.total += 1


I'm having a hard time following this code and why the outer queue of jvm_waiters is necessary.

danking · 2023-10-20T20:28:42Z

batch/batch/worker/worker.py

+
+        assert self._waiting_for_jvm_with_n_cores.empty()
+        assert all(jvmpool.full() for jvmpool in self._jvmpools_by_cores.values())
+        log.info(f'JVMs initialized {self._jvmpools_by_cores}')


@jigold Thanks for pushing back! What do you think of it now?

To directly answer your question: one queue (jvmpool.queue) is a place for a consumer to borrow a JVM, the other queue (waiting_for_jvm_with_n_cores) is a place for a producer to learn that a consumer is waiting.

Without waiting_for_jvm_with_n_cores, _initialize_jvms has no way to be told that someone is waiting for a JVM. asyncio.Queue doesn't expose a method like has_waiters().

x

jigold · 2023-10-23T15:03:31Z

Much better! I understand what's going on now. Just to make sure I understand where the performance improvements are, we don't wait for all JVMs to be intitialized before accepting JVM jobs and the queue is FIFO so we reuse the same JVMs that are warm already?

jigold

See comment.

danking · 2023-10-23T15:58:04Z

we don't wait for all JVMs to be intitialized before accepting JVM jobs and the queue is FIFO so we reuse the same JVMs that are warm already?

No. We have no way to accept only JVM jobs or only Batch jobs, so we either accept all jobs or no jobs. In main, we accept jobs before the JVMs have initialized. We wait for all JVMs to initialize before giving JVMs to any JVM Job. So, concretely, in main and in this PR we accept jobs before JVMs are ready; however, in this PR we don't wait for all JVMs to initialize before running jobs.

There are two improvements in this PR:

If a JVM with the requested number of cores is available, allow the requesting JVMJob to start before the remaining JVMs are initialized.
Rather than starting all the JVMs in parallel, start JVMs serially and also start them in the order that they are requested. If we have three waiting JVM Jobs two requesting 1 core and one requesting 4 cores, prefer to start JVMs with 1 and 4 cores to JVMs with 2 or 8 cores.

(2) might sound slower (why start serially when we can stat in parallel?) but it appears that 30 JVMs competing for CPU time dramatically slows down average start up time. In both main and this PR it takes about ~25s for all JVMs to be ready; however, in this PR, some jobs can start much sooner than 25s b/c their JVMs are started first.

x

danking assigned jigold Oct 20, 2023

danking force-pushed the batch-reduce-connecting-to-jvm-time branch from f2145c4 to d550af9 Compare October 20, 2023 05:05

danking commented Oct 20, 2023

View reviewed changes

danking force-pushed the batch-reduce-connecting-to-jvm-time branch 2 times, most recently from 0b6d075 to ba7204c Compare October 20, 2023 05:07

danking commented Oct 20, 2023

View reviewed changes

danking force-pushed the batch-reduce-connecting-to-jvm-time branch from ba7204c to 7767141 Compare October 20, 2023 05:08

[batch] maybe reduce average JVMJob "connecting to jvm" time

92bf566

danking force-pushed the batch-reduce-connecting-to-jvm-time branch from 7767141 to 92bf566 Compare October 20, 2023 05:09

Dan King added 5 commits October 20, 2023 09:19

wip

44a2d4e

wip

996fdab

Revert "wip"

922a501

This reverts commit 44a2d4e.

more debug info

9fcf0c4

fix setup

b3a52d5

jigold previously requested changes Oct 20, 2023

View reviewed changes

Dan King added 2 commits October 20, 2023 15:59

use explicit conversion flag

0b2e4b7

maybe simpler?

3464c29

danking commented Oct 20, 2023

View reviewed changes

Dan King added 3 commits October 20, 2023 16:30

slight nit

1d9776f

bad type name

4d8fdef

fix pyright issues

3dfbd86

f string without placeholders

5894a99

jigold previously requested changes Oct 23, 2023

View reviewed changes

blacken

9e9e504

jigold approved these changes Oct 25, 2023

View reviewed changes

danking merged commit 2f69f8a into hail-is:main Oct 25, 2023
8 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[batch] maybe reduce average JVMJob "connecting to jvm" time #13870

[batch] maybe reduce average JVMJob "connecting to jvm" time #13870

danking commented Oct 20, 2023

danking Oct 20, 2023

danking Oct 20, 2023

danking commented Oct 20, 2023

jigold Oct 20, 2023

danking Oct 20, 2023

jigold commented Oct 23, 2023

jigold left a comment

danking commented Oct 23, 2023 •

edited

Loading


		async def recreate_jvm(self, jvm: JVM):
		self._jvms.remove(jvm)

[batch] maybe reduce average JVMJob "connecting to jvm" time #13870

[batch] maybe reduce average JVMJob "connecting to jvm" time #13870

Conversation

danking commented Oct 20, 2023

danking Oct 20, 2023

Choose a reason for hiding this comment

danking Oct 20, 2023

Choose a reason for hiding this comment

danking commented Oct 20, 2023

jigold Oct 20, 2023

Choose a reason for hiding this comment

danking Oct 20, 2023

Choose a reason for hiding this comment

jigold commented Oct 23, 2023

jigold left a comment

Choose a reason for hiding this comment

danking commented Oct 23, 2023 • edited Loading

danking commented Oct 23, 2023 •

edited

Loading