apache / apache/mina-sshd

high CPU usage

Open
#625 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
1.1k
Forks
400
Avg merge
5d 1h
Merged PRs (30d)
1

Description

### Version

2.10.0

### Bug description

I deployed a microservice on linux system ( arm ) and there is a timer task in this service, which will create sftp connection to fetch files from another node( one day one time. almost 14k files every time ).

after this process running for almost 4 months, it occurs that the node CPU high alarm on the timer task running. and I checked the top -Hp result, the sshd-client single thread is occuping most CPU resources (30~40%), and due to several mina-sshd threads exsits, the CPU high reached 300% and more. after timer task finished, there's no sshd thread, the CPU back to slow.

And which confused me that after I restart the service, the timer task won't cost such high CPU. Did anyone meet the similar case with me?

### Actual behavior

here's the stack result (kill -3 pid) :

"sshd-SshClient[70197f5]-nio2-thread-3" #20186890 daemon prio=5 os_prio=0 cpu=265.07ms elapsed=0.35s tid=0x0000aaaaf8ac1800 nid=0x2cb36 runnable [0x0000ffff78200000]
java.lang.Thread.State: RUNNABLE
at java.math.BigInteger.implMulAdd(BigInteger.java:3049)
at java.math.BigInteger.mulAdd(BigInteger.java:3020)
at java.math.BigInteger.implSquareToLen(BigInteger.java:2093)
at java.math.BigInteger.squareToLen(BigInteger.java:2014)
at java.math.BigInteger.implMontgomerySquare(BigInteger.java:2715)
at java.math.BigInteger.montgomerySquare(BigInteger.java:2674)
at java.math.BigInteger.oddModPow(BigInteger.java:2942)
at java.math.BigInteger.modPow(BigInteger.java:2605)
at org.bouncycastle.crypto.generators.DHKeyGeneratorHelper.calculatePublic(Unknown Source)
at org.bouncycastle.crypto.generators.DHBasicKeyPairGenerator.generateKeyPair(Unknown Source)
at org.bouncycastle.jcajce.provider.asymmetric.dh.KeyPairGeneratorSpi.generateKeyPair(Unknown Source)
at org.apache.sshd.common.kex.DHG.calculateE(DHG.java:66)
at org.apache.sshd.common.kex.AbstractDH.getE(AbstractDH.java:60)
at org.apache.sshd.client.kex.DHGEXClient.next(DHGEXClient.java:177)
at org.apache.sshd.common.session.helpers.AbstractSession.handleKexMessage(AbstractSession.java:772)
at org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:632)
at org.apache.sshd.common.session.helpers.AbstractSession.lambda$handleMessage$0(AbstractSession.java:556)
at org.apache.sshd.common.session.helpers.AbstractSession$$Lambda$1102/1920761910.call(Unknown Source)
at org.apache.sshd.common.util.threads.ThreadUtils.runAsInternal(ThreadUtils.java:68)
at org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:555)
at org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1701)
at org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:516)
- locked <0x000000008237a978> (a java.lang.Object)
at org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:64)
at org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:407)
at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:380)
at org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:375)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$$Lambda$1090/1581151621.run(Unknown Source)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)
at sun.nio.ch.Invoker$2.run(Invoker.java:218)
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:750)

top -Hp result:

top - 02:23:32 up 130 days, 1:56, 1 user, load average: 13.50, 15.05, 12.79
Threads: 191 total, 4 running, 187 sleeping, 0 stopped, 0 zombie
%Cpu(s): 80.1 us, 15.4 sy, 0.0 ni, 1.5 id, 0.7 wa, 0.7 hi, 1.5 si, 0.0 st
MiB Mem : 59875.7 total, 1793.8 free, 28438.8 used, 29643.1 buff/cache
MiB Swap: 32768.0 total, 28537.2 free, 4230.8 used. 31035.2 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
81023 ossuser 20 0 3178316 760084 8836 R 47.1 1.2 0:00.21 sshd-SshClient[
80957 ossuser 20 0 3178316 760084 8836 R 29.4 1.2 0:00.28 sshd-SshClient[
81051 ossuser 20 0 3178316 760084 8836 R 29.4 1.2 0:00.15 sshd-SshClient[
XXXXXX...

### Expected behavior

how can I find why the CPU high

### Relevant log output

_No response_

### Other information

_No response_

Contributor guide

No contributing guide indexed for this repository

Research direction

Start with the reported Java stack, especially DHGEXClient.next, DHG.calculateE, and AbstractSession.handleKexMessage, while reproducing the ARM/Linux SFTP workload from version 2.10.0. Compare a fresh service with the four-month state and capture whether repeated key exchange explains the CPU; done means a reproducible cause and verified behavior.

Written by the indexing model from the issue text.

Assessment

Tech stack
java, linux
Domain
networking, security
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.