Solved High top usage on 11.1-RELEASE ??

PacketMan

PacketMan

I have never noticed this on any of my 10.x-RELEASE machines, but occasional see ( EDIT > top(1) showing ) over 100% usage on my only 11.1-RELEASE machine. Also notice the CPU line shows all zeros. I am running top -C -s 5 and I see top(1) like this every few minutes. I'm guessing its normal, but why in 11.1 and not in the 10.x (RELEASE) releases? Anyone else notice this?

Code: 
CPU:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
Mem: 193M Active, 2845M Inact, 64M Laundry, 702M Wired, 388M Buf, 57M Free
Swap: 3852M Total, 72M Used, 3780M Free, 1% Inuse

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME     CPU COMMAND
16931 ******     1  20    0 20160K  3544K CPU0    0   0:00 114.09% top


A few minutes later......
Code: 
last pid: 16951;  load averages:  0.39,  0.52,  0.56                         up 2+06:29:13  11:39:59
26 processes:  1 running, 25 sleeping
CPU:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
Mem: 191M Active, 2864M Inact, 64M Laundry, 702M Wired, 388M Buf, 40M Free
Swap: 3852M Total, 72M Used, 3780M Free, 1% Inuse

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME     CPU COMMAND
16951 ******     1  20    0 20160K  3544K CPU1    1   0:00 116.25% top

Just curious.

EDIT I should add, even though the top shows 0% idle, at that moment of time the machine does not in any way seem bogged/pinned down, it seems as it normally does - hardly busy at all.
 
I'm wondering why top(1) itself is using more than 110% CPU. It should barely register any CPU utilization for itself.

Try running top -SP instead. The -S will show some system processes and -P will split up the CPU usage for each core individually.
 
That's my question, why does top show itself with high usage. I've only noticed it on this one machine that now runs 11.1-RELEASE. When this same machine ran 10.x-RELEASE, and other machines that still run 10.x (all 10.3 or 10.4 currently) I don't see it. And it shows CPU 0% idle, yet all other line items are also 0%.
 
Hmmmm, it doesn't seem to be happening when I use SSH inside my house. But using SSH from another location, which means two instances of NAT/firewall, over at least a few Internet routers, it seems that is when it occurs.
 
Switch from displaying CPU statistics to disk I/O using the m switch. Do you see anything unusual from top's process?

What happens if you run top in a while-loop in batch mode, while :; do top -bd1; sleep 1; done? Does it ever hit 100% CPU usage?
 
Last edited:
PacketMan said:
Hmmmm, it doesn't seem to be happening when I use SSH inside my house. But using SSH from another location, which means two instances of NAT/firewall, over at least a few Internet routers, it seems that is when it occurs.
Click to expand...
It won't matter where you come from or how many hops you need to cross. That's completely irrelevant. What I can image though is that you're not ending up on the server you think you are connected to.
 
Might not be related to your issue, but I occasionally observed similar phenomena when there were programs that hanged so completely that only killing by the OS (-9/SIGKILL) removed them.
 
SirDice said:
It won't matter where you come from or how many hops you need to cross. That's completely irrelevant. What I can image though is that you're not ending up on the server you think you are connected to.
Click to expand...

Not sure I follow you. I am connecting to my home NAS; how can I not be sure that I am on the right server? Where I come from and number of hops is completely relevant I agree, but what if somehow there is an issue with one of the NAT/firewalls or internet connection, and somehow the ssh session is momentarily freezing, maybe say right when top has a new 'refreshed' screen to send? I'm really am guessing at the moment but I need to do more testing/observation. I will say this though, last night (I was trying to record a TV show, and Plex transcoder process kept locking up or something, causing heavy swapping.) I kept top running watching it, and I can say after hours (of trying to figure out what is awry with Plex (code issue I think now)) that top never once showed those numbers as I posted above.

Stayed tuned.
 
PacketMan said:
Not sure I follow you. I am connecting to my home NAS; how can I not be sure that I am on the right server?
Click to expand...
Because you're traversing two NATs. It's possible one of them isn't pointing to the correct IP address, so you end up on Server2 instead of Server1 for example. Just something that has happened to me. I mistakenly thought the redirection was still correct when it wasn't.
 
SirDice said:
Because you're traversing two NATs. It's possible one of them isn't pointing to the correct IP address, so you end up on Server2 instead of Server1 for example.
Click to expand...

Sorry I wasn't clear. One of the two NATs would be outbound not inbound. My SSH targets a public IP address, which hits the other NAT, which points it to my home server. Anyway I have pretty much confirmed the pattern. From within my home LAN I do not see this issue, but from at least one outside location, the issue (as shown at the beginning of this thread) occurs: Top occasionally shows its own process with high cpu usage, and the CPU line(s) show all zeros, regardless of actual cpu loading.

SirDice I think this is what you asked for:

top -CSP -s 5
Code: 
last pid:  5842;  load averages:  0.61,  0.54,  0.52           up 0+14:15:41  07:44:09
47 processes:  2 running, 44 sleeping, 1 waiting
CPU 0:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
CPU 1:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
Mem: 116M Active, 2892M Inact, 80M Laundry, 692M Wired, 388M Buf, 81M Free
Swap: 8852M Total, 14M Used, 8838M Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME     CPU COMMAND
 5824 *****     1  20    0 20160K  3516K CPU1    1   0:00 110.87% top
  670 btsync        7  20    0   201M   107M uwait   0 328:39  57.83% btsync
   11 root          2 155 ki31     0K    32K CPU0    0  22.3H  14.93% idle
 5619 *****     1  20    0 85228K  8224K select  1   0:00  13.74% sshd
   12 root         17 -60    -     0K   272K WAIT    0   5:36   5.50% intr
    4 root          2 -16    -     0K    32K -       0   3:27   2.87% cam
    0 root         15 -16    -     0K   240K swapin  1   4:21   0.48% kernel
  655 plex         18  20    0   253M 87208K uwait   0   9:41   0.00% Plex Media Server
   20 root          1  20    -     0K    16K -       0   2:44   0.00% bufspacedaemon
   16 root          3 -16    -     0K    48K psleep  0   1:18   0.00% pagedaemon
  767 plex         13  52   15   175M 60376K piperd  0   1:07   0.00% Plex Script Host
   21 root          1  16    -     0K    16K syncer  0   0:58   0.00% syncer
   19 root          3 -16    -     0K    48K psleep  0   0:46   0.00% bufdaemon
   15 root          1 -16    -     0K    16K -       1   0:13   0.00% rand_harvestq
  406 root          1  20    0  9560K   724K select  0   0:03   0.00% devd
   22 root          1  20    -     0K    16K vlruwt  1   0:03   0.00% vnlru
  632 root          1  20    0 20564K 12472K select  1   0:02   0.00% ntpd
  772 plex         11  20    0 76472K  8940K usem    0   0:02   0.00% Plex Tuner Service
   14 root         35 -68    -     0K   560K -       0   0:01   0.00% usb
  550 root          1  20    0 10500K  2140K select  0   0:01   0.00% syslogd
  705 root          1  20    0 20636K  5168K select  0   0:01   0.00% sendmail
  750 root          1  20    0 27732K  2400K select  1   0:00   0.00% ftpd

top -CSP -s 5
Code: 
last pid:  5892;  load averages:  0.52,  0.53,  0.51           up 0+14:18:44  07:47:12
47 processes:  2 running, 44 sleeping, 1 waiting
CPU 0:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
CPU 1:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
Mem: 110M Active, 2912M Inact, 80M Laundry, 692M Wired, 388M Buf, 67M Free
Swap: 8852M Total, 14M Used, 8838M Free

  PID USERNAME    THR PRI NICE   SIZE    RES STATE   C   TIME     CPU COMMAND
   11 root          2 155 ki31     0K    32K CPU0    0  22.4H 130.32% idle
 5824 *****     1  20    0 20160K  3516K CPU1    1   0:00 114.81% top
 5619 *****     1  20    0 85228K  8224K select  0   0:00  12.13% sshd
    0 root         15 -16    -     0K   240K swapin  0   4:21   0.56% kernel
  670 btsync        7  20    0   203M   111M uwait   1 329:38   0.00% btsync
  655 plex         18  20    0   253M 88744K uwait   0   9:41   0.00% Plex Media Server
   12 root         17 -60    -     0K   272K WAIT    1   5:37   0.00% intr
    4 root          2 -16    -     0K    32K -       1   3:27   0.00% cam
   20 root          1  20    -     0K    16K -       0   2:44   0.00% bufspacedaemon
   16 root          3 -16    -     0K    48K psleep  0   1:18   0.00% pagedaemon
  767 plex         13  52   15   175M 60376K piperd  0   1:07   0.00% Plex Script Host
   21 root          1  16    -     0K    16K syncer  0   0:59   0.00% syncer
   19 root          3 -16    -     0K    48K psleep  0   0:47   0.00% bufdaemon
   15 root          1 -16    -     0K    16K -       0   0:13   0.00% rand_harvestq
  406 root          1  20    0  9560K   724K select  0   0:03   0.00% devd
   22 root          1  20    -     0K    16K vlruwt  1   0:03   0.00% vnlru
  632 root          1  20    0 20564K 12472K select  1   0:02   0.00% ntpd
  772 plex         11  20    0 76472K  8940K usem    0   0:02   0.00% Plex Tuner Service
   14 root         35 -68    -     0K   560K -       0   0:01   0.00% usb
  550 root          1  20    0 10500K  2140K select  1   0:01   0.00% syslogd
  705 root          1  20    0 20636K  5168K select  0   0:01   0.00% sendmail
  750 root          1  20    0 27732K  2400K select  1   0:00   0.00% ftpd
  712 root          1  20    0 12592K  2176K nanslp  0   0:00   0.00% cron
 
linux->bsd said:
Switch from displaying CPU statistics to disk I/O using the m switch. Do you see anything unusual from top's process?
Click to expand...

Looks similar. The CPU lines show all zeros, but the top process shows 0.00% like most other processes.


top -CSP -m io -s 5
Code: 
last pid:  6024;  load averages:  0.42,  0.48,  0.49           up 0+14:27:07  07:55:35
47 processes:  2 running, 44 sleeping, 1 waiting
CPU 0:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
CPU 1:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
Mem: 107M Active, 2939M Inact, 77M Laundry, 692M Wired, 388M Buf, 45M Free
Swap: 8852M Total, 14M Used, 8838M Free

  PID USERNAME     VCSW  IVCSW   READ  WRITE  FAULT  TOTAL PERCENT COMMAND
   11 root            0      2      0      0      0      0   0.00% idle
 5915 ******       0      0      0      0      0      0   0.00% top
 5619 ******       1      0      0      0      0      0   0.00% sshd
    0 root            1      0      0      0      0      0   0.00% kernel
  670 btsync          0      0      0      0      0      0   0.00% btsync
  655 plex            0      0      0      0      0      0   0.00% Plex Media Server
   12 root            0      0      0      0      0      0   0.00% intr
    4 root            0      0      0      0      0      0   0.00% cam
   20 root            0      0      0      0      0      0   0.00% bufspacedaemon

top -CSP -m io -s 5
Code: 
last pid:  6024;  load averages:  0.46,  0.46,  0.47           up 0+14:30:11  07:58:39
47 processes:  3 running, 43 sleeping, 1 waiting
CPU 0:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
CPU 1:  0.0% user,  0.0% nice,  0.0% system,  0.0% interrupt,  0.0% idle
Mem: 107M Active, 2949M Inact, 77M Laundry, 692M Wired, 389M Buf, 35M Free
Swap: 8852M Total, 14M Used, 8838M Free

  PID USERNAME     VCSW  IVCSW   READ  WRITE  FAULT  TOTAL PERCENT COMMAND
 5915 ******       0      0      0      0      0      0   0.00% top
  670 btsync          3      4      0      0      0      0   0.00% btsync
    0 root            2      0      0      0      0      0   0.00% kernel
   11 root            0      0      0      0      0      0   0.00% idle
  655 plex            0      0      0      0      0      0   0.00% Plex Media Server
   12 root            0      0      0      0      0      0   0.00% intr
    4 root            0      0      0      0      0      0   0.00% cam
   20 root            0      0      0      0      0      0   0.00% bufspacedaemon
   16 root            0      0      0      0      0      0   0.00% pagedaemon
  767 plex            0      0      0      0      0      0   0.00% Plex Script Host
   21 root            0      0      0      0      0      0   0.00% syncer
   19 root            0      0      0      0      0      0   0.00% bufdaemon
   15 root            0      0      0      0      0      0   0.00% rand_harvestq
  406 root            0      0      0      0      0      0   0.00% devd
   22 root            0      0      0      0      0      0   0.00% vnlru
  632 root            0      0      0      0      0      0   0.00% ntpd
  772 plex            0      0      0      0      0      0   0.00% Plex Tuner Service
   14 root            0      0      0      0      0      0   0.00% usb
 
Update! I can now trigger the issue at will, discovered it by accident. All I have to do is resize my SSH client window just a tiny amount. The instant I release my mouse left button held click, top will show what we see above. So that brings to be something else I should have clued into. At this location I use SecureCRT on a latop. At home I use the native cli window on my wife's Linux laptop. So I should take the SecureCRT laptop home and fart around and see what happens.

So, during normal use and I am not resizing my SecureCRT window, it just may be somehow SecureCRT is 'freezing' the ssh session occasionally; triggering this issue if its even an 'issue'.
 
I found the trigger to this. It has nothing to do with NAT, SecureCRT, etc. It does have to do with a setting I configured in the SecureCRT session for this server. I like to watch a folder and observe the file count.

Code: 
\r\r\ ls | wc -l \r\r
is configured in my anti-idle send string option. When I turn this off the issue goes way, and if I configure the anti-idle for 10 seconds I see the reported issue every 10 seconds.

Normally I would just 'cd' into that folder and be done with it. In 10.x-RELEASE running top was never an issue, and I honestly thought top keep the session 'fresh' so this command never ran. But in 11.x-RELEASE I see now that is not the case, that this anti-idle string does get sent, and when it gets sent it causes top to display as shown above. I have had this anti-idle string configured ever since I have been using FreeBSD (version 10.1-RELEASE I do believe) so it seems to be something has changed in the 11.X-RELEASE release.

Anyway, if anyone considers this a 'bug' they can go ahead and file a bug case. I see bigger problems in the world to be fixed so will spend my energy there. :D
 
You must log in or register to reply here.
Back
Top