Join Log in
Score:0
x3nr0s avatar Server

Ubuntu VM SSH session crashes during a large unzip due to kauditd high CPU usage

wf flag
x3nr0s

I am having issues with an Ubuntu 18.08 VM on Azure. The issue seems to occur when I am unzipping a large file with unzip. My SSH session crashes out with send disconnect: Broken pipe, and I can no longer SSH onto the machine until I restart it on the Azure console.

I have checked disk space and it appears to be fine, I think the issue is due to a CPU lockup that I discovered in diagnostic logs:

[ 9574.275457] rcu: blocking rcu_node structures:
[ 9581.022803] watchdog: BUG: soft lockup - CPU#1 stuck for 23s! [kauditd:22]
[ 9609.022802] watchdog: BUG: soft lockup - CPU#1 stuck for 23s! [kauditd:22]
[ 9614.067067] audit: backlog limit exceeded
[ 9614.072016] audit: backlog limit exceeded
[ 9614.076728] audit: backlog limit exceeded
[ 9637.022802] watchdog: BUG: soft lockup - CPU#1 stuck for 23s! [kauditd:22]
[ 9665.022801] watchdog: BUG: soft lockup - CPU#1 stuck for 23s! [kauditd:22]
[ 9674.339074] audit: backlog limit exceeded
[ 9674.344825] audit: backlog limit exceeded
[ 9674.351922] audit: backlog limit exceeded
[ 9693.022802] watchdog: BUG: soft lockup - CPU#1 stuck for 23s! [kauditd:22]
[ 9721.022802] watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kauditd:22]
[ 9734.182947] audit: backlog limit exceeded
[ 9734.188086] audit: backlog limit exceeded
[ 9734.194938] audit: backlog limit exceeded
[ 9736.682801] rcu: INFO: rcu_sched self-detected stall on CPU
[ 9736.684975] rcu:     1-....: (509855 ticks this GP) idle=492/1/0x4000000000000002 softirq=1049753/1049838 fqs=254454 
[ 9754.486826] rcu: INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 1-... } 511745 jiffies s: 525 root: 0x2/.
[ 9754.497787] rcu: blocking rcu_node structures:
[ 9761.022802] watchdog: BUG: soft lockup - CPU#1 stuck for 22s! [kauditd:22]

In addition, I have tried monitoring top during the unzipping and just before I get booted out I see kauditd fly up from less than 0% CPU to 70%-100% CPU:

top - 12:00:01 up 21 min,  1 user,  load average: 1.34, 1.29, 0.98
top - 12:02:53 up 24 min,  2 users,  load average: 2.80, 1.87, 1.25
Tasks: 168 total,   4 running,  95 sleeping,   0 stopped,   0 zombie
%Cpu(s): 31.8 us, 48.8 sy,  0.0 ni,  0.0 id, 19.3 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  8149152 total,  2436876 free,   958672 used,  4753604 buff/cache
KiB Swap:        0 total,        0 free,        0 used.  6878804 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  22 root       20   0       0      0      0 R  79.3  0.0   0:02.92 kauditd                                                             
  299 root      20   0 1563540 153316  35416 S  73.4  1.9   1:40.58 ds_am                                                              
  29619 root    20   0   11528   5252   2088 S   3.6  0.1   0:14.03 unzip
  466 root      19  -1  144180  58788  57688 S   1.3  0.7   0:03.89 systemd-journal                                                    
  21596 root    20   0       0      0      0 I   0.7  0.0   0:00.65 kworker/u4:1-ev

What could be causing the kernel audit daemon to take up so much CPU so suddenly? It wasn't a gradual increase, but a snap up to 100% and then a freeze of the VM.

Anyone encountered this before?

82
0 + 0
anx avatar
fr flag
anx
Whats `ds_am`? Are you running some anti-malware snake oil that is quite intentionally using at least as much (own and kernel audit) resources as you are spending on the certainly I/O intensive unzip operation?
0
Reply
x3nr0s avatar
wf flag
x3nr0s
It's trend micro, so the answer is yes. But we need it for security accreditation purposes.
1
Reply
Score:0
avatar Server
ge flag
yield

I can't tell why. But I would suggest you use SCREEN or BYOB and unzip in the background.

While it unzip the file, juste close your SSH session, get back after a few minutes and VOILA !

0 + 0
x3nr0s avatar
wf flag
x3nr0s
Is there a reason why an intensive process such as zip uses way more resources when a user is actively SSH'd?
0
Reply
ge flag
yield
no, unless you run it like that: ~#ssh user@host unzip bigFile.zip as it could return the output in your terminal throw ssh session..... But I don't see why it would cause such ''crash''.... I would suggest you open a ticket to Azure.
0
Reply
ge flag
yield
Or you could limit the process time that unzip take. If you have a small VM, you might have limitation on that. Ex: sudo cpulimit --pid 17918 --limit 20. or use the ''nice'' command.
1
Reply
Score:0
anx avatar Server
fr flag
anx

I think this is caused by some component of Trend Micro software. Your top output shows 1:40.58 time spent on ds_am, a significant fraction of your uptime.

Software of that kind is also a likely candidate (though not the only) for setting up the kernel auditing facilities.

  1. Refer to documentation and/or contact the software vendor about the direct resource usage. Do however first check if any regular maintenance or upgrade tasks for that software is still pending.

  2. Determine the configuration of the kernel auditing framework and identify other software interfacing with it. (try auditctl)

0 + 0
x3nr0s avatar
wf flag
x3nr0s
After further investigation I don't think this is trend micro related. After few more tests the `top` output didn't show ds_agent with as high CPU. I also stopped the ds_agent temporarily. However kauditd was always at 100% after a large unzip.
0
Reply
anx avatar
fr flag
anx
@x3nr0s If it was not that software (stopping runtime components does neither confirm nor rule it out), someone else must have instructed the kernel to collect auditing information. Try to gather more information on what auditing rules are currently loaded in the kernel.
0
Reply
ธงชาติไทย
Elon Musk
I sit in a Tesla and translated this thread with Ai:

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.