disk_em is using a lot of cpu

[Karin Willems]

Hi, as you can see in the print below, disk_em is using (several times a day) a lot of CPU. The system was last rebooted Aug 21 at 15:22. What can cause this excessive use?

System: hpx3 Tue Aug 29 08:52:51 2006
Load averages: 1.15, 1.17, 1.23
369 processes: 354 sleeping, 15 running
Cpu states:
CPU LOAD USER NICE SYS IDLE BLOCK SWAIT INTR SSYS
0 1.11 48.3% 0.0% 50.7% 1.0% 0.0% 0.0% 0.0% 0.0%
1 1.15 50.1% 0.0% 49.3% 0.6% 0.0% 0.0% 0.0% 0.0%
2 1.18 45.1% 0.0% 52.7% 2.2% 0.0% 0.0% 0.0% 0.0%
--- ---- ----- ----- ----- ----- ----- ----- ----- -----
avg 1.15 47.8% 0.0% 50.8% 1.4% 0.0% 0.0% 0.0% 0.0%

Memory: 4490448K (3166156K) real, 5098636K (3635468K) virtual, 1400176K free Pa
ge# 1/37

CPU TTY PID USERNAME PRI NI SIZE RES STATE TIME %WCPU %CPU COMMAND
2 ? 24798 root 212 20 4488K 1628K run 431:55 17.60 17.56 disk_em
0 ? 18065 tbwtdds 154 20 2608K 252K sleep 7:16 2.13 2.12 ksh
1 ? 6020 root 154 20 2300K 392K sleep 0:00 1.75 1.49 registrar
2 ? 7443 tgwsdds 158 20 2608K 252K sleep 4:43 1.39 1.39 ksh
0 ? 7008 root 154 20 2276K 340K sleep 40:07 1.15 1.15 p_client
1 ? 40 root 152 20 9600K 9600K run 342:08 0.82 0.81 vxfsd
2 ? 2321 root 152 20 219M 28252K run 41:58 0.59 0.59 java
2 ? 1 root 168 20 492K 204K sleep 55:23 0.53 0.53 init
0 ? 2651 root 154 20 11432K 1644K sleep 36:34 0.36 0.36 ARMServer

[spex]

Hi Karin,

disk_em is an event monitor for disk drives. It's a component of EMS (Event Monitoring Services).

Something happening in your enclosure/array is piquing its interest. Does anything show up in syslog?

# man disk_em
for more info.

PCS

[Karin Willems]

Hi spex,

In the syslog.log I can only find the following message (occurs once), which I think is a little strange, but this array has been connected since May, 3th and had no problems :

Aug 29 11:36:32 hpx3 syslog: HP Advanced Disk Array serial number 0000000F49C3:
Multi-initiator lock obtained: Product Revision: HP62: Product ID: C5447A

Recently a diskarray 2405 had been attached to the system. Since that time I noticed that disk_em was very active several times a day.

I've looked in several files and noticed the following:
api.log - repeated message

-------------------Start Event--------------------
User event occurred at Tue Aug 29 13:09:52.908868 2006
Process ID: 5553 (/usr/sbin/stm/uut/bin/.../dm_chassis) Log Level: Error
The chassis code monitor (dm_chassis) cannot run on this machine. Either the m:
superdome
S-class
-------------------End Event----------------------

client.log - repeated message
-------------------Start Event--------------------
User event occurred at Tue Aug 29 04:23:40.947136 2006
Process ID: 7008 (/etc/opt/resmon/lbin/p_client) Log Level: Audit
Object Type = RM_MONITOR_REPLY_OBJECT
Resource Name = "/storage/events/disk^A/default/0_0_1_1.2.0"
Dictionary Name =
Translation Name =
Message Tag = 0
Operation Type = RM_REGISTER
Request ID = 0.0
Lifetime Options = RM_NON_PERSISTENT_REQUEST
Client Name Length = 0
User Data Length = 0
Request Notification Data Length = 0
Polling Interval = 30
Operator = RM_CHANGE
Resource Type = 0
Threshold Type = 0
Threshold Value = None

Notification Options = 0:
No options are set
:$
Target Port = 0

Flags Word = 0:
No options are set

OV Severity = RM_NOT_APPLICABLE
Minimum Polling Interval = 0
Password Length = 0
Client Configuration File =

-------------------End Event----------------------


registrar.log - repeated message

-------------------Start Event--------------------
Event 1180 occurred at Tue Aug 29 11:58:19.858397 2006
Process ID: 3742 (/etc/opt/resmon/lbin/registrar) Log Level: Error
process_subclass_request: Cannot find monitor file (/release/FUTURE_1111/11.11/u
sr/sbin/stm/uut/bin/tools/monitor/dm_fc_hub) to exec
-------------------End Event----------------------

-------------------Start Event--------------------
Event 1352 occurred at Tue Aug 29 11:58:19.862705 2006
Process ID: 3742 (/etc/opt/resmon/lbin/registrar) Log Level: Error
process_event: An error occurred processing the last event: error code = 0: No e
rror
-------------------End Event----------------------


When I take a look with STM, all disks seems to be OK. Some disk have non-medium errors, but they passed the exercise, information and verify were also OK. May be you can tell me where I can find additional logfiles to examine this case, it drives me nuts by now ;-)

bye, Karin

[Karin Willems]

Hi,

I forgot to mention that two PCI-X cards are not recognized by the system (RP5470). They were built in to connect a SAN, but at the moment, notting is connected.

greetz,

Karin

[Andrew Merritt_2]

Hi Karin,
Are there any events from disk_em that are logged in the event.log file? (/var/opt/resmon/log).

Has 'ioscan' been run, or the system rebooted, since the DS2405 devices were removed? If not, try running 'ioscan' without the -k option.

Do you have a recent version of the OnlineDiags installed? If not, get the latest version from http://h20293.www2.hp.com/portal/swdepot/displayProductInfo.do?productNumber=B6191AAE . (Actually, I'm guessing you have A.52.00; is that right?)

Can you characterise the behaviour more exactly? How often does disk_em use a lot of CPU, and how long for? If it's every hour, then it's most likely trying to access disks on the system (and may be having problems if there are entries for disks that are no longer present). How many disk devices are there on the system? If it's not that regular, then it may be dealing with events being logged by disk devices. In the latter case, you'd expect to see disk device errors logged in 'logtool' in STM, even if no EMS events get logged in event.log.

Andrew