topic Re: Who is cluttering /var/tmp with char dev files rdskAAA* ? in Operating System - HP-UX

Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Wed, 08 Aug 2007 07:00:04 GMT

Hello,

it seems I have a berserk process that is creating character special files by the minute.
Since the devices are only one block in size we don't run into space limits that fast.
However, I am not sure about the inode count,
but assume, since it is an vxfs, this isn't hit either that soon.
Nevertheless, there had been accumulated over 100,000 device files.
They have all the major 203

# ll -rt /var/tmp/rdskAAA*|tail -3
crw------- 1 root root 203 0x001000 Aug 8 13:50 /var/tmp/rdskAAAa24366
crw------- 1 root root 203 0x001000 Aug 8 13:50 /var/tmp/rdskAAAa24379
crw------- 1 root root 203 0x001000 Aug 8 13:50 /var/tmp/rdskAAAa24389

# lsdev 203
Character Block Driver Class
203 -1 sctl ctl

First I suspected an OmniBack process to be the culprit,
and we killed that and removed all rdskAAA* files.

But when I now find for them again that many in quite a short period

# find /var/tmp -xdev -type c -name rdsk\*|wc -w
361

and since OmniBack has been killed there's only some stm proc accessing /var/tmp now

# lsof +d /var/tmp
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
sysstat_e 5771 root 8w REG 64,0x8 0 29107 /var/tmp/sysstat_em.fmt

# ps -fp 5771
UID PID PPID C STIME TTY TIME COMMAND
root 5771 1 0 Jul 5 ? 1:04 /usr/sbin/stm/uut/bin/tools/monitor/sysstat_em

I couldn't see fitting entries in syslog.log,
and the last event.log entry from EMS dates back to July 5th.

Can anyone tell me if it really is STM that creates them, and for what purpose?

On our other servers I cannot observe these strange character devices.

Regards

Ralph

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ivan Krastev — Wed, 08 Aug 2007 07:15:41 GMT

What is your OS version ?
For 11.00 here is recomendations:

"The Sep 2002/A.34.00 version of OnlineDiag/STM contains further changes
to support the exclusion of removable media devices from polling.
Therefore, a recommendation was made to install the Sep 2002/A.34.00
version of OnlineDiag/STM, along with the (required) EMS core patch,
PHSS_26871 or later. Doing so resolved the problem. "

regards,
ivan

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Wed, 08 Aug 2007 07:38:35 GMT

Hi Ivan,

the OS is B.11.11
For STM on it I only found PHSS_34085 (which isn't installed) when querying HPs' patch database for sysstat_em.
But in its Readme I couldn't see mention of the symptom that I observe.

http://www4.itrc.hp.com/service/patch/patchDetail.do?patchid=PHSS_34085&sel={hpux:11.11,}&BC=main|search|

I have applied the latest Support+ bundle on July 5th

# swlist -l bundle -a install_date -a title GOLD\* HW\* OnlineDiag
# Initializing...
# Contacting target "gomera"...
#
# Target: gomera:/
#

GOLDAPPS11i 200707050948.26 Applications Patches for HP-UX 11i v1, June 2007
GOLDBASE11i 200707050948.26 Base Patches for HP-UX 11i v1, June 2007
HWEnable11i 200707051008.59 Hardware Enablement Patches for HP-UX 11i v1, December 2006
OnlineDiag 200707051021.01 HPUX 11.11 Support Tools Bundle, June 2007

Could I have introduced a new bug with it?

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ivan Krastev — Wed, 08 Aug 2007 08:27:03 GMT

Use tusc - http://h21007.www2.hp.com/portal/site/dspp/PAGE.template/page.document?ciid=61086d6e1de021106d6e1de02110275d6e10RCRD

to see what is the exact process generating these files.

If this is the same (EMS) it's possible bug or misconfiguration due to removed hardware.

regards,
ivan

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

TwoProc — Wed, 08 Aug 2007 14:31:51 GMT

I've seen them on my 11.11 systems as well. It would be nice to know what they are...

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Todd McDaniel_1 — Wed, 08 Aug 2007 14:52:33 GMT

Ralph,

I would do 3 things first.

Stop and start STM a few times...and see if that clears it up.

# /sbin/init.d/diagnostic stop|start

If that doesnt help, then reload STM to the latest version or fall back to the last good version you had before the current one.

Upgrade OnlineDiag to the latest version.

If that doesn't do it, then I think you need to call HP.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Steven E. Protter — Wed, 08 Aug 2007 15:31:17 GMT

Shalom,

I think I recall NFS or Samba leaving files like this behind. I'd be leaning toward NFS.

Do they correspond with disk devices that are part of NFS shares?

SEP

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

TwoProc — Wed, 08 Aug 2007 17:39:56 GMT

Re: NFS shares.

Those devices are not involved in NFS shares on my servers, especially the worst one, which isn't an NFS server at all.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Sameer_Nirmal — Wed, 08 Aug 2007 17:54:14 GMT

The possiblity of a bug or re-introducation of previous bug couldn't be ruled out here. However I am curious to know what if you move /var/tmp/sysstat_em.fmt to somewhere else, would you get those rdskAAA* files created?

There was a known issue (JAGae59420)with sysstat_em earlier where sysstat_em should delete the /var/tmp/sysstat_em.fmt file after event generation and it was fixed in the Dec'04 release.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Thu, 09 Aug 2007 02:32:52 GMT

Ivan,

I am kind of despairing.
Whenever I issue an lsof on the directory /var/tmp (belongs to /var FS) I always get sysstat_em popping up as the only proc that has files open thereon.

# lsof +d /var/tmp
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
sysstat_e 5771 root 8w REG 64,0x8 0 29107 /var/tmp/sysstat_em.fmt

So I have been tusc-ing only open() and mknod() syscalls by this PID (also for possible sysstat_em forked children), because I don't know of any other syscall that could create a new char device.
But all I can see is that this proc seems to multiplex for pending input streams by a select() (probably on its listening socket),
then rereads its config file, then opens what looks like some lock file to me, and finaly opens its /dev/diag device, only to reenter the multiplex cycle.

# tusc -f -s open,mknod 5771
( Attached to process 5771 ("/usr/sbin/stm/uut/bin/tools/monitor/sysstat_em") [32-bit] )
select(2048, 0x77ff0cf4, 0x77ff0978, 0x77ff0a78, 0x77ff0f04) ............. [sleeping]
open("/var/stm/config/tools/monitor/sysstat_em.cfg", O_RDONLY, 0666) ..... = 7
open("/var/stm/data/.slicdata", O_RDWR, 0666) ............................ ERR#2 ENOENT
open("/dev/diag/diag2", O_RDONLY, 060100) ................................ = 9
select(2048, 0x77ff0cf4, 0x77ff0978, 0x77ff0a78, 0x77ff0f04) ............. [sleeping]

Please, could you tell how I can find out which process is creating these char devices?

Since yesterday over 3000 files have been created.
And they get created in rather short intervals as can be seen by this tail

# ll -rt /var/tmp/rdskAAA*|tail
crw------- 1 root root 203 0x001000 Aug 9 08:48 /var/tmp/rdskAAAa28188
crw------- 1 root root 203 0x001000 Aug 9 08:48 /var/tmp/rdskAAAa28197
crw------- 1 root root 203 0x001000 Aug 9 08:48 /var/tmp/rdskAAAa28210
crw------- 1 root root 203 0x001000 Aug 9 08:48 /var/tmp/rdskAAAa28220
crw------- 1 root root 203 0x001000 Aug 9 08:49 /var/tmp/rdskAAAa28233
crw------- 1 root root 203 0x001000 Aug 9 08:49 /var/tmp/rdskAAAa28242
crw------- 1 root root 203 0x001000 Aug 9 08:49 /var/tmp/rdskAAAa28260
crw------- 1 root root 203 0x001000 Aug 9 08:50 /var/tmp/rdskAAAa28269
crw------- 1 root root 203 0x001000 Aug 9 08:50 /var/tmp/rdskAAAa28282
crw------- 1 root root 203 0x001000 Aug 9 08:50 /var/tmp/rdskAAAa28292

SEP and John,

as for NFS (you both mentioned it),
this box neither exports nor mounts NFS shares.

Todd,

in /etc/opt/resmon/lbin/monconfig
(gosh, who thought up this arcane path for a utility?)
I shutdown EMS, and I also stopped diagmond by its init script

# /sbin/init.d/diagnostic stop;sleep 20;UNIX95= ps -C diagmond
PID TTY TIME CMD

Well, at least for the last half an hour since I executed these commands,
no new device files have been created.
But as soon as I restarted the diagnostic init script 7 new files were created.

I also attached tusc for open and mknod calls to the pid of diagmond and children,
but couldn't see any opens on /var/tmp.

So it really looks as if some frenzied STM proc is causing them.

Because I hadn't observed this before I applied the DIAGNOSTICS patch of last Support+ CD release last month,
I now suspect this to have introduced this behavior.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Dennis Handly — Thu, 09 Aug 2007 02:39:25 GMT

I have the same things, since 2002. But only 20 or so, about every month or so.

>Sameer: I am curious to know what if you move /var/tmp/sysstat_em.fmt

I don't have that.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Thu, 09 Aug 2007 02:43:35 GMT

Sameer,

I tentatively renamed systat_em.fmt
as you suggested.

# ps -fp $(fuser -u /var/tmp/sysstat_em.fmt 2>/dev/null)
UID PID PPID C STIME TTY TIME COMMAND
root 29200 1 0 09:04:18 ? 0:00 /usr/sbin/stm/uut/bin/tools/monitor/sysstat_em

# mv /var/tmp/sysstat_em.fmt /var/tmp/sysstat_em.fmt.moved

# ll /var/tmp/sysstat_em.fmt*
-rw-r--r-- 1 root root 0 Aug 9 09:25 /var/tmp/sysstat_em.fmt.moved

But this doesn't work as long as the agent systat_em his holding it open

# ps -fp $(fuser -u /var/tmp/sysstat_em.fmt.moved 2>/dev/null)
UID PID PPID C STIME TTY TIME COMMAND
root 29200 1 0 09:04:18 ? 0:00 /usr/sbin/stm/uut/bin/tools/monitor/sysstat_em

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Steven E. Protter — Thu, 09 Aug 2007 03:06:55 GMT

Shalom Ralph,

I share your pain.

The bottom line here is the files are owned by oracle and they should be cleaned up by the oracle application.

I fought with oracle to get them to do better testing on HP-UX after receiving an isntall script that didn't work on HP-UX that was clearly tested only on Solaris.

I was partially successful, because I refused to accept delivery on products not tested on HP-UX. Still, they leave messes and don't like to clean those messes up.

It's frustrating. I suggest making your unhappiness clear to your Oracle Rep the next time they ask for more money.

SEP

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Dennis Handly — Thu, 09 Aug 2007 03:27:04 GMT

>SEP: The bottom line here is the files are owned by oracle

Are you confusing this thread with "0 byte files created in /tmp"?
http://forums1.itrc.hp.com/service/forums/questionanswer.do?threadId=1151735

I don't have Oracle.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Duncan Edmonstone — Thu, 09 Aug 2007 03:38:23 GMT

Ralph,

I think you're looking at the wrong culprit here - I don't think there's a problem with sysstat_em at all.

I tried a quick experiment on my 11.11 system here which is also patched up to June 07.

My system is trusted, so I was able to enable the auditing subsystem and tune it to just look for mknod system calls.

Here's what I found:

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
070809 09:28:21 1632 S 14 1 0 0 0 0 0 ?????
[ Event=mknod; User=root; Real Grp=root; Eff.Grp=root; ]

RETURN_VALUE 1 = 0;
PARAM #1 (file path) = 0 (cnode);
0x40000008 (dev);
7 (inode);
(path) = /var/tmp/rdskUAAa01632
PARAM #2 (int) = 8576
PARAM #3 (int) = -888971264
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
070809 09:28:21 1632 S 14 1 0 0 0 0 0 ?????
[ Event=mknod; User=root; Real Grp=root; Eff.Grp=root; ]

RETURN_VALUE 1 = 0;
PARAM #1 (file path) = 0 (cnode);
0x40000008 (dev);
7 (inode);
(path) = /var/tmp/rdskVAAa01632
PARAM #2 (int) = 8576
PARAM #3 (int) = -888971264
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
# ps -ef | grep 1632
root 1632 1 0 09:22:30 ? 0:00 /usr/sbin/stm/uut/bin/tools/monitor/disk_em

That looks pretty similar to what you are seeing. The difference is on my system these files are being cleanup up straight away:

# ll /var/tmp/*dsk*
/var/tmp/*dsk* not found

So I would apply tusc to disc_em rather that sysstat_em

HTH

Duncan

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Duncan Edmonstone — Thu, 09 Aug 2007 03:55:32 GMT

... and looking at the files created, note that the end of the filename contains the PID of the process.

The fact that yours are incrementing whilst mine stays the same suggests that disk_em is in fact failing on your system.

I believe it is supposed to log to the logfiles found in /var/opt/resmon/log, so take a look there.

HTH

Duncan

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Thu, 09 Aug 2007 04:54:17 GMT

SEP and Dennis,

never mind, this well could be an Oracle issue.

Normally, this box serves as a test bed for the Oracle DBAs and the application developers.

For some reason there is currently no DB instance online.
These are the only oracle procs right now

# ps -u oracle
PID TTY TIME COMMAND
2589 ? 23:44 perl
2602 ? 60:53 emagent

Hm, being a bit of a Perl aficionado myself
that interests me, what they are running

# UNIX95= ps -x -o args -p 2589
COMMAND
/app/oracle/grid/agent10g/perl/bin/perl /app/oracle/grid/agent10g/bin/emwd.pl agent /app/oracle/grid/agent10g/sysman/log/emagent.nohup

So I looked at the agent Perl script which, according to its header, is an Oracle supplied piece, and was a bit shocked about lots of unperlish idioms or even deprecated Perl malpractices in the vein of "Pest Practices".

First thing that disqualifies it as production code for a piece that exceeds 100 lines (with crudely stripped comments)

# grep ^[^#] /app/oracle/grid/agent10g/bin/emwd.pl|wc -l
697

Where, the hack is the strict pragma?

# grep -c strict /app/oracle/grid/agent10g/bin/emwd.pl
0

Lets pick up a few pest lines (prepended line Nos.).

What a misnomer for an array:

216 my @COMMAND_STR=@ARGV;

This is C style indenting, isn't it.
Ok, its just a matter of style:

228 if ($NOHUP_FILE eq "")
229 {
230 if($COMMAND eq "iasconsole")

Bizarre quoting and concatting
(Mark Jason Dominus calls this "cave dwellers' Woodoo"):

257 $reqPkg = "$moduleName"."\.pm";

Useless use of parentheses and weird arithmetics:

315 my($NUM_COLS) = 2;
316 my($NUM_COMPONENTS) = (scalar(@components)/$NUM_COLS);

Clumsy initialization:

324 # marked all components as just started
325 my @compJustStarted;
326 for $i ( 0 .. ($NUM_COMPONENTS-1) )
327 {
328 $compJustStarted[$i] = 1;
329 }

Again, ugly C style looping:

355 for($i=0, $baseCtr=0; $i < $NUM_COMPONENTS; $i++, $baseCtr+=2)
356 {

Unclear local scoping:

367 # Reap the child .... returns an array.
368 # [0] : How the process exited [normal/signal/coredump].
369 # [1] : Exit code/Signal Code
370 local (*processExit) = reapChild( $pid, $name );

this is returned by reapChild():

926 else
927 {
928 printDebugMessage("ProcessStatus is $processStatus. Assuming normal exit.");
929 @status = ($PROCESS_EXIT_NORMAL, $processStatus);
930 }
931 }
932 return (\@status);
933 }

Btw, in this sub we suddenly take up Perl style indenting (must be due to different coders):

901 if($reaped == -1) {
902 # we lost the xit code. somebody else reaped it.
903 # we report normal exit as we don't want it restarted.
904 printMessage("Lost xit code. Assuming normal exit. processStatus=$processStatus
904 ");
905 @status = ($PROCESS_EXIT_NORMAL, 0);
906 } else {

Strange logic, and again ample use of parens:

425 # If the status is no_process or process_hang ...
426 if( ($rc == $STATUS_NO_SUCH_PROCESS) or
427 ($rc == $STATUS_PROCESS_HANG) or
428 ($rc == $STATUS_AGENT_ABNORMAL) or
429 ( $processExit[0] != $PROCESS_OK ) )
430 {

just few lines later unmotivated change to higher precedence operators:

434 if ( ($processExit[0] == $PROCESS_OK) &&
435 ( $rc == $STATUS_PROCESS_HANG ) || ( $rc == $STATUS_AGENT_ABNORMAL ) )
436 {

Strange typeglob assignment of our ubiquitious reapChild sub, which merely returns an array ref:

464 (*processExit) = reapChild( $pid, $name );

Again funny concatination (first by operator, later by double quotes interpolation):

491 my($tmpMsg) = $name." exited at ".localtime($currentCrashTime).
492 " with return value $processExit[1].";
493 printMessage($tmpMsg);

while here we relapse to a more palatable and readbable interpolation:

669 writeToEMAbbendFile("$EMHOME/sysman/log/agabend.log",
670 "$message");

Hard to read and obsolete sub dereferncing of array elem:

701 $tmp = &{$components[$baseCtr+$restart_offset]}();

Clumsy logic:

750 if($NUM_COMPONENTS == 0)
751 {
752 if($normalShutdown eq "FALSE")
753 {
754 printMessage("Exited due to Thrash.");
755 }
756 }

Why not better use sprintf or join?

798 my($appender) = $name."_".time();

Repitiion of queer assignments:

# grep -n '@status = ($PROCESS_OK, $PROCESS_OK);' /app/oracle/grid/agent10g/bin/emwd.pl
880: @status = ($PROCESS_OK, $PROCESS_OK);
894: @status = ($PROCESS_OK, $PROCESS_OK);
954: @status = ($PROCESS_OK, $PROCESS_OK);
970: @status = ($PROCESS_OK, $PROCESS_OK);

Well, this goes on and on.
I only had a very superficial look at it without caring at all about the program logic or trying to understand the code.
Maybe I have disparaged indisputable bits?
And altogether this code still is quite acceptable and not as bad as other vendor distributed I have seen (have a look at VCS entrypoints).
But if even a Perl rookie like me notices this then I wonder of what quality the code might be that they provide us only as binaries?

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Thu, 09 Aug 2007 05:13:30 GMT

Sorry for my ranting digression.

Duncan,

many thanks for pointing me to disk_em.

Well, as I think I have told, I already looked at the logs in /var/opt/resmon/log.
The only current one is event.log (the other files date back to April), and all entries later than July 5th (when the box was last rebooted due to Support+ patching) only inform about a restart of EMS today, which took place as I stopped it via monconfig.

I also noticed the trailing PIDs in the device files' names.
But these PIDs are all of processes in the past.

Actually, disk_em wasn't in the proc table while EMS was shut down by my monconfig intervention.
But yet, the device files were created as soon as diagmond was running.

I now restarted EMS via monconfig and attached another tusc to disk_em.

I think it is waiting for the master agent to fetch states because it lingers in a select call.

# UNIX95= ps -C disk_em
PID TTY TIME CMD
7425 ? 00:01 disk_em

# tusc -f -s open,mknod 7425
( Attached to process 7425 ("/usr/sbin/stm/uut/bin/tools/monitor/disk_em") [32-bit] )
select(2048, 0x77ff0b24, 0x77ff07a8, 0x77ff08a8, 0x77ff0d34) ............. [sleeping]

I will have to watch this for half an hour and come back.

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Duncan Edmonstone — Thu, 09 Aug 2007 05:26:12 GMT

Ralph,

Being an impatient type, I wasn't willing to wait for disk_em to do this itself, so I tried to force it. I found stopping/starting diagnostics caused disk_em to start running those mknods:

/sbin/init.d/diagnostic stop

... wait for a minute...

/sbin/init.d/diagnostic start

HTH

Duncan

Re: Who is cluttering /var/tmp with char dev files rdskAAA* ?

Ralph Grothe — Thu, 09 Aug 2007 05:48:11 GMT

Yes, that's what I also observed.

# /sbin/init.d/diagnostic stop

# UNIX95= ps -C diagmond
PID TTY TIME CMD

But running it directly through tusc rather than attaching to diagmond it aborts.

# tusc -f -s open,mknod /sbin/init.d/diagnostic start 2>&1|grep /var/tmp
open("/var/tmp/aaaa09909", O_WRONLY|O_CREAT|O_TRUNC|O_LARGEFILE, 0666) ....... = 3

# UNIX95= ps -C diagmond
PID TTY TIME CMD

But diagmond is really the culprit, as can be seen this way:

# /sbin/init.d/diagnostic start && sleep 10 && tusc -f -s open,mknod $(UNIX95= ps -C diagmond -o pid=) 2>&1|grep /var/tmp <
mknod("/var/tmp/rdskAAAa11454", S_IFCHR|0600, 3405848576) .................... = 0
open("/var/tmp/rdskAAAa11454", O_RDONLY, 014644) ............................. = 5
open("/var/tmp/rdskAAAa11454", O_RDWR, 0160100) .............................. = 6
mknod("/var/tmp/rdskAAAa11480", S_IFCHR|0600, 3405905920) .................... = 0
open("/var/tmp/rdskAAAa11480", O_RDONLY, 014644) ............................. = 5
open("/var/tmp/rdskAAAa11480", O_RDWR, 0170100) .............................. = 6
mknod("/var/tmp/rdskAAAa11486", S_IFCHR|0600, 3405914112) .................... = 0
open("/var/tmp/rdskAAAa11486", O_RDONLY, 014644) ............................. = 5
open("/var/tmp/rdskAAAa11486", O_RDWR, 0170100) .............................. = 6
open("/var/tmp/CCLOGD_TEST_DATA", O_RDONLY, 032) ............................. ERR#2 ENOENT

Ok, now how can this be fixed?

Do you think this is HP SW call worthy?