multipass icon indicating copy to clipboard operation
multipass copied to clipboard

Using heredoc input with `exec` can consume much CPU time

Open townsend2010 opened this issue 5 years ago • 3 comments

In the conversation in #1217, it was brought up that when using heredoc input will consume much CPU time. Here is the example:

$ time multipass exec node1 -- /bin/bash << EOF
curl -fsSL https://get.docker.com | sh
EOF
...
real	6m21.030s
user	2m19.718s
sys	3m49.603s

I did some initial debugging and found the libssh is passing the curl | sh output to the host multipass client and then the client is passing that back into the instance's bash command. Two extra and unnecessary encrypt/decrypt trips between the host and instance as the output should really stay in the instance and be passed directly to bash.

townsend2010 avatar Jan 09 '20 14:01 townsend2010

Just to add some more observation evidence, I tripped on this too and was puzzled to see the qemu process taking ~200% of CPU when doing a top on the host (even thought the vm had only one cpu allocated to it). Following the enctrypt/decrypt explanation, I would have expected to see part of the work in the instance and part outside (ssh server and client). Also, a top inside the instance reported sshd using only 50% and nothing else significant.

ricab avatar Jan 10 '20 16:01 ricab

Could not reproduce the bug:

time multipass exec a -- /bin/bash << EOF
curl -fsSL https://get.docker.com | sh
EOF
...
multipass exec a -- /bin/bash <<<'curl -fsSL https://get.docker.com | sh'  0.03s user 0.02s system 0% cpu 22.282 total

It seems like a change in heredocs, libssh or on our side may have fixed this. Could you try to reproduce again @ricab?

tobe2098 avatar Nov 19 '25 10:11 tobe2098

Hi @tobe2098, I just tried (heredoc) and got:

real	0m22.582s
user	0m4.859s
sys	0m17.386s

Using a herestring:

real	0m24.630s
user	0m5.269s
sys	0m19.251s

Whereas, executing inside a multipass shell:

real	0m21.088s
user	0m0.060s
sys	0m0.029s

There appears to be a little overhead, but it is nothing like the initial report. Those 2 to 4s can't be explained by the initialization of SSH or the nested shells:

$ time multipass exec subtle-cat -- /bin/bash <<< "echo echo hello | sh"
hello

real	0m0.178s
user	0m0.052s
sys	0m0.036s

I don't know if there is still any undue back and forth. I would need to try many more times before I could exclude it being just coincidence.

I know heredocs would be parsed by the outer shell and subjected to parameter expansion, command substitution, and arithmetic expansion (from bash manual).

In any case, it is a small difference. Let's perhaps decrease priority and leave deeper investigation for another time.

ricab avatar Nov 19 '25 13:11 ricab