I’ve started testing of file hash calculation feature on version 6.0.3
And I got some strange behavior related to libnss functionality.
I’m testing an environment with Napatech NIC however, I believe the specific adapter type does not matter.
Analyzed traffic contains quite a big amount of plain HTTP with file transactions. It’s processed fine until hash calculating is enabled.
If it’s not enabled then CPU load shown by e.g. htop is big but it’s reasonably big. And packet drop ratio is virtually zero.
If file hash calculation is enabled then CPU load becomes low, at the same time packet drop ratio is unacceptable, more than 90%.
Well, I made brief research and found that almost all processing threads are trying to acquire a specific mutex somewhere inside libnss3.
I’m definitely not an expert in this libnss however, it’s either not properly used or not suitable for our almost real-time needs.
An example of the stack trace. Please note almost all threads are waiting for this mutex required by PR_Lock() from libnss.
Thread 70 (Thread 0x7fe572eb2700 (LWP 59856)): #0 0x00007fe576a2454d in __lll_lock_wait () from /lib64/libpthread.so.0 #1 0x00007fe576a1fed1 in _L_lock_1093 () from /lib64/libpthread.so.0 #2 0x00007fe576a1fe72 in pthread_mutex_lock () from /lib64/libpthread.so.0 #3 0x00007fe576c54eb9 in PR_Lock () from /lib64/libnspr4.so #4 0x00007fe5759570fb in sftk_SessionFromHandle () from /lib64/libsoftokn3.so #5 0x00007fe57594b2a8 in sftk_GetContext () from /lib64/libsoftokn3.so #6 0x00007fe57594de15 in NSC_DigestUpdate () from /lib64/libsoftokn3.so #7 0x00007fe5774e23a6 in PK11_DigestOp () from /lib64/libnss3.so #8 0x00000000005bcc92 in FileAppendDataDo (ff=0x7fe1a0eb24d0, data=0x7fe1a14d04f0 '*' <repeats 200 times>..., data_len=2920) at util-file.c:680 #9 0x00000000004d83c2 in HTPFileStoreChunk (s=s@entry=0x7fe1a0ca9a10, data=data@entry=0x7fe1a14d04f0 '*' <repeats 200 times>..., data_len=data_len@entry=2920, direction=direction@entry=8 '\b') at app-layer-htp-file.c:295 #10 0x00000000004d67ee in HtpResponseBodyHandle (data_len=2920, data=0x7fe1a14d04f0 '*' <repeats 200 times>..., tx=0x7fe1a0c3bdf0, htud=0x7fe1a0c7b840, hstate=0x7fe1a0ca9a10) at app-layer-htp.c:1777 #11 HTPCallbackResponseBodyData (d=<optimized out>) at app-layer-htp.c:1975 #12 0x00007fe579f0b17a in htp_hook_run_all (hook=0xebf680, user_data=user_data@entry=0x7fe572eaf5a0) at htp_hooks.c:127 #13 0x00007fe579f18229 in htp_res_run_hook_body_data (connp=<optimized out>, d=d@entry=0x7fe572eaf5a0) at htp_util.c:2327 #14 0x00007fe579f13434 in htp_tx_res_process_body_data_ex (tx=0x7fe1a0c3bdf0, data=0x7fe1a14d04f0, len=<optimized out>) at htp_transaction.c:1007 #15 0x00007fe579f0f8fb in htp_connp_RES_BODY_IDENTITY_CL_KNOWN (connp=0x7fe1a0ca9a80) at htp_response.c:487 #16 0x00007fe579f11325 in htp_connp_res_data (connp=0x7fe1a0ca9a80, timestamp=timestamp@entry=0x7fe572eaf650, data=<optimized out>, len=len@entry=2920) at htp_response.c:1327 #17 0x00000000004d6093 in HTPHandleResponseData (f=<optimized out>, htp_state=0x7fe1a0ca9a10, pstate=0x7fe1a0ca99d0, input=<optimized out>, input_len=2920,