search

usnistgov / jsip

JSIP: Java SIP specification Reference Implementation (moved from java.net)
Other
287 stars 131 forks source link

Exit SSL state machine loop if unwrap result in CLOSED #64

Closed andrey-vorobiev closed 3 years ago

andrey-vorobiev commented 3 years ago

Recently I have observed that jsip based service consumes 100% cpu when handling single WSS connection. This has been caused by continuous GC caused by DirectByteBuffer allocation. Switching log level to debug showed me the following:

2021-02-05 16:42:53,369 DEBUG - Unwrap result Status = CLOSED HandshakeStatus = NEED_WRAP
bytesConsumed = 0 bytesProduced = 0 buffers size 0 src=java.nio.HeapByteBuffer[pos=24 lim=24 cap=24] dst=java.nio.DirectByteBuffer[pos=0 lim=16704 cap=16704]
2021-02-05 16:42:53,369 DEBUG - Buffer cleared
2021-02-05 16:42:53,369 DEBUG - NonAppWrap result Status = OK HandshakeStatus = NEED_WRAP
bytesConsumed = 0 bytesProduced = 0 buffers size 0
2021-02-05 16:42:53,369 DEBUG - Unwrap src java.nio.HeapByteBuffer[pos=24 lim=24 cap=24] dst java.nio.DirectByteBuffer[pos=0 lim=16704 cap=16704]
2021-02-05 16:42:53,369 DEBUG - Unwrap result Status = CLOSED HandshakeStatus = NEED_WRAP
bytesConsumed = 0 bytesProduced = 0 buffers size 0 src=java.nio.HeapByteBuffer[pos=24 lim=24 cap=24] dst=java.nio.DirectByteBuffer[pos=0 lim=16704 cap=16704]
2021-02-05 16:42:53,369 DEBUG - Buffer cleared
2021-02-05 16:42:53,369 DEBUG - NonAppWrap result Status = OK HandshakeStatus = NEED_WRAP
bytesConsumed = 0 bytesProduced = 0 buffers size 0
2021-02-05 16:42:53,369 DEBUG - Unwrap src java.nio.HeapByteBuffer[pos=24 lim=24 cap=24] dst java.nio.DirectByteBuffer[pos=0 lim=16704 cap=16704]
...
repeated many times

So I looked into SSLStateMachine and noticed that CLOSED status is ignored which seems to be cause of infinite loop. So PR is here.

Still this fix solves problem described about I'm not sure if it valid at all, at least if checking for closed state should go before checking number of bytes produced. Also it worth while to check wrap logic.

vladimirralev commented 3 years ago

Thanks. I think this should do it, perhaps add in a log line in there so we would see something if it goes wrong. I'll see if I can spot something else around the close state. This may have something to do with renegotiating the SSL. Do you have any tips on reproducing the issue?