Mailing List Archives

Public Access

 		[Computer Systems Lab]

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Condor-users] multiple VM problem
I am moving this over into condor-admin@xxxxxxxxxxxx I'll feed back a summary of what is found, if it seems of general interest. 

Cheers,
--Dan

On May 10, 2006, at 8:15 AM, Nagaraj Panyam wrote:


Hi,

I have these flags for STARTD_DEBUG
D_COMMAND D_FULLDEBUG D_MACHINE D_LOAD D_MATCH D_JOB D_ACCOUNTANT
About the ProcAPI error. Yes, its there. Here it a clip from the log. It 
is sporadic, and appears to occur in bunches, so I missed it untill you
asked.

/**
5/10 14:54:33 vm1: Computing percent CPU usage with pids: 5371 5373 5378 
5421 5424 5425 5631 5632
5/10 14:54:33 ProcAPI: pid 5421 does not exist.
5/10 14:54:33 ProcAPI::getProcSetInfo: Pid 5421 does not exist, ignoring. 
5/10 14:54:33 ProcAPI: pid 5424 does not exist.
5/10 14:54:33 ProcAPI::getProcSetInfo: Pid 5424 does not exist, ignoring. 
5/10 14:54:33 ProcAPI: pid 5425 does not exist.
5/10 14:54:33 ProcAPI::getProcSetInfo: Pid 5425 does not exist, ignoring. 
5/10 14:54:33 ProcAPI: pid 5631 does not exist.
5/10 14:54:33 ProcAPI::getProcSetInfo: Pid 5631 does not exist, ignoring. 
5/10 14:54:33 ProcAPI: pid 5632 does not exist.
5/10 14:54:33 ProcAPI::getProcSetInfo: Pid 5632 does not exist, ignoring. 
**/

I came across the same error in another context. Here is the log, but I
am not sure if these are relevant to the problem.

/**
5/2 18:08:21 Load avg: 0.00 0.00 0.01
5/2 18:08:21 vm1: Computing percent CPU usage with pids: 5976 5978 5983
6026 6029
5/2 18:08:21 vm1: Percent CPU usage for those pids is: 0.000000
5/2 18:08:21 vm1: LoadQueue: Adding 5 entries of value 0.000000
5/2 18:08:21 vm1: LoadQueue: 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.
00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 
5/2 18:08:21 vm1: LoadQueue: Size: 60  Avg value: 0.00  Share of system
load: 0.00
5/2 18:08:21 vm2: Computing percent CPU usage with pids: 5974 5975
5/2 18:08:21 vm2: Percent CPU usage for those pids is: 0.000000
5/2 18:08:21 vm2: LoadQueue: Adding 5 entries of value 0.000000
5/2 18:08:21 vm2: LoadQueue: 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.
00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 
5/2 18:08:21 vm2: LoadQueue: Size: 60  Avg value: 0.00  Share of system
load: 0.00
5/2 18:08:21 SystemLoad: 0.000  TotalCondorLoad: 0.000  TotalOwnerLoad:
0.000
5/2 18:08:21 vm1: SystemLoad: 0.00  CondorLoad: 0.00  OwnerLoad: 0.00
5/2 18:08:21 vm2: SystemLoad: 0.00  CondorLoad: 0.00  OwnerLoad: 0.00
5/2 18:08:21 vm2: State change: PREEMPT is TRUE
5/2 18:08:21 vm2: State change: WANT_VACATE is TRUE
5/2 18:08:21 vm2: In Starter::kill() with pid 5974, sig 101 (DC_SIGCONTINUE) 5/2 18:08:21 STARTD_TIMEOUT_MULTIPLIER is undefined, using default value 
of 0
5/2 18:08:21 SEC_DEBUG_PRINT_KEYS is undefined, using default value of False 
5/2 18:08:21 vm2: Canceled claim timer (134)
5/2 18:08:21 vm2: Changing state and activity: Claimed/Suspended ->
Preempting/Vacating
5/2 18:08:21 vm2: In Starter::kill() with pid 5974, sig 15 (SIGTERM)
5/2 18:08:21 STARTD_TIMEOUT_MULTIPLIER is undefined, using default value 
of 0
5/2 18:08:21 SEC_DEBUG_PRINT_KEYS is undefined, using default value of False 
5/2 18:08:21 DaemonCore: No more children processes to reap.
5/2 18:08:21 Starter pid 5974 exited with status 0
5/2 18:08:21 ProcAPI::buildFamily failed: parent 5974 not found on system. 
5/2 18:08:21 ProcAPI: pid 5974 does not exist.
5/2 18:08:21 ProcAPI: pid 5975 does not exist.
5/2 18:08:21 vm2: State change: starter exited
5/2 18:08:21 Entered vacate_client <192.168.55.100:34034>
mcf000.tifr-mcfarm...
5/2 18:08:21 STARTD_TIMEOUT_MULTIPLIER is undefined, using default value 
of 0
5/2 18:08:21 SEC_DEBUG_PRINT_KEYS is undefined, using default value of False 
5/2 18:08:21 vm2: State change: No preempting claim, returning to owner
5/2 18:08:21 vm2: Changing state and activity: Preempting/Vacating ->
Owner/Idle
5/2 18:08:21 vm2: State change: IS_OWNER is false
5/2 18:08:21 vm2: Changing state: Owner -> Unclaimed
5/2 18:08:21 DaemonCore: No more children processes to reap.
**/

I checked the list of pid's that appear in the startd log.
5/10 12:09:18 vm2: Computing percent CPU usage with pids: 23718 23720
23725 24346 24404 24405 24409 26504 27293 27294 27296 1238

/** clippings from "top"
23718 root      15   0  1964 1964  1552 S     0.0  0.0   0:10   0
condor_starter
23720 samgrid   25  10   272  272   228 S N   0.0  0.0   0:00   1 time
23725 samgrid   25  10  1068 1068   900 S N   0.0  0.0   0:00   1
sandbox_mgr
24346 samgrid   25  10  1104 1104   912 S N   0.0  0.0   0:00   1
jim_rapper.sh
24404 samgrid   25  10   344  344   288 S N   0.0  0.0   0:00   1 time
24405 samgrid   25  10  1136 1136   924 S N   0.0  0.0   0:00   1
mc_sam_rapper.s
24409 samgrid   29  10  1060 1060   904 S N   0.0  0.0   0:00   0
accelerator.sh
26504 samgrid 25 10 13684 13M 2248 S N 0.0 0.6 0:03 0 python 
27293 samgrid   25  10   988  988   852 S N   0.0  0.0   0:00   0 sh
27294 samgrid   25  10  1016 1016   876 S N   0.0  0.0   0:00   0
Tata20737488711
27296 samgrid 25 10 9272 9272 1744 S N 0.0 0.4 0:00 1 python 
 1238 samgrid   29  10   504  504   428 S N   0.0  0.0   0:00   0 sleep
**/
But I notice that the the pid's listed against vm2 (show above) are all 
related to the user process running on vm1. The one big user process
(shown below) that takes up 100% of vm1 is not
listed in the log against vm1

/**
27356 samgrid 35 10 156M 156M 28424 R N 50.0 7.7 600:31 1 d0gstar2.x 
**/

This does not seem to be OK. Because on the node with the older Linux,
the log shows about 20 pid's (for one user job) against the
corresponding vm. On the problem nodes, Condor seems to be watching
about half of the user processes that "top" lists.

I hope I am reporting all that is relevant, though this mail has become
rather long.
Thank you sincerely.

Nagaraj


Dan Bradley wrote:


Nagaraj,

Condor reads /proc/<pid>/stat to get the CPU utilization of a process.
I've observed that this works under Scientific Linux 3, so I don't know 
why it is reporting no load for your processes.

Looking at the code that reads /proc/<pid>/stat, I see that some
failures to read the file are only reported if you add D_FULLDEBUG to
your STARTD_DEBUG list.  Could you please do that and see if there are
errors containing the string "ProcAPI::getProcInfo()"?
Also, does the list of pids that it is checking make sense? In your log 
below, there is a message "Computing percent CPU usage with pids: 3559
3561 3566 3871 3929 3930 3934 4450 5239 5240 5242 12775".  Presumably
one or more of these was generating the cpu load. Can you please verify 
that?  The question I am wondering about is whether the problem is the
reading of process stat information or whether it is the list of pids
itself that is the trouble.  If there are pids associated with the job
that are generating cpu load but which are not in the list, that would
cause a problem similar to what you are observing.  If you just use
'top' to see the top few pids and verify that these are in the list
being watched by Condor, that should be enough to see if this is really 
the problem or not.

--Dan

Nagaraj Panyam wrote:




Hi Dan,
Yes, by "user process" I refer to job run by condor on behalf of a user. There is no other user process, because the nodes are dedicated compute 
nodes.
I did try the D_LOAD setting. But I could not make out much out of the 
output - but the load values dont seem to agree with the the
Claimed/Busy status. Here is a clipping from a node for which
condor_status reports "vm1 owner/idle loadav=1.000" and "vm2
claimed/busy loadav=0.000". I request you to have a look at the output 
and see if you find a clue, or please advise me what to look out for.


/****
5/9 11:34:33 Load avg: 1.00 1.00 0.96
5/9 11:34:33 vm1: LoadQueue: Adding 5 entries of value 0.000000
5/9 11:34:33 vm1: LoadQueue: 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.
00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 5/9 11:34:33 vm1: LoadQueue: Size: 60 Avg value: 0.00 Share of system 
load: 0.00
5/9 11:34:33 vm2: Computing percent CPU usage with pids: 3559 3561 3566 
3871 3929 3930 3934 4450 5239 5240 5242 12775
5/9 11:34:33 ProcAPI: new boottime = 1145611802; old_boottime =
1145611802; /proc/stat boottime = 1145611803; /proc/uptime boo
ttime = 1145611802
5/9 11:34:33 vm2: Percent CPU usage for those pids is: 0.000000
5/9 11:34:33 vm2: LoadQueue: Adding 5 entries of value 0.000000
5/9 11:34:33 vm2: LoadQueue: 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.
00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 
0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.0
0 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 5/9 11:34:33 vm2: LoadQueue: Size: 60 Avg value: 0.00 Share of system 
load: 0.00
5/9 11:34:33 SystemLoad: 1.000 TotalCondorLoad: 0.000 TotalOwnerLoad: 
1.000
5/9 11:34:33 vm1: SystemLoad: 1.00  CondorLoad: 0.00  OwnerLoad: 1.00
5/9 11:34:33 vm2: SystemLoad: 0.00  CondorLoad: 0.00  OwnerLoad: 0.00
***/
Just to summarize my earlier mail - something seems to have changed with 
an OS upgrade, because with the older OS, the same node (same
condor_config) a user process on each vm. Also, if I turn Hyperthreading 
on for the same node, two vm's run user process, and two are stuck in
the "claimed/busy" state.

Thanks a lot for helping me with this.

Nagaraj







Dan Bradley wrote:






Nagaraj,
Off the top of my head, I can't think of any reason for this change in behavior. When you say "user process" you are referring to a job run 
by Condor on behalf of a user, right?  You are not talking about
processes run by users outside of Condor.  Just want to be sure I
understand.
You could try adding D_LOAD in your STARTD_DEBUG settings. This will 
show extra information about what's going on while monitoring system
load.

--Dan

On May 8, 2006, at 12:46 PM, P. Nagaraj wrote:








Hi,
We have dual cpu nodes in our condor pool. Some of these run an older version of Linux (RH 7.1), and these take two user jobs as shown below There is a user process on each cpu here. CondorVersion is 6.6.5 and 
platforms are all Intel/Linux

vm1 Claimed/Busy/LoadAv=1.000/Mem=502
vm2 Claimed/Busy/loadAv=1.020/Mem=502
When I upgrade the nodes (Scientific Linux 3), the behaviour changes, condor_config being unchanged. The VM that is running the user process 
shows up as vm2 below, while the vm that has no LoadAv shows up as
Busy.

vm1  Claimed/Busy/LoadAv=0.000/Mem=500
vm2  Owner/Idle/LoadAv=1.000/Mem=500
Refering to the vm1 just above, its classads are as show here below. 

CpuBusy = ((LoadAvg - CondorLoadAvg) >= 0.500000)
CondorLoadAvg = 0.000000
LoadAvg = 0.000000
TotalLoadAvg = 1.000000 --this from the other vm which has LoadAv=1 
TotalCondorLoadAvg = 0.000000
CpuBusyTime = 0
CpuIsBusy = FALSE
State = "Claimed"
Activity = "Busy"
Start = (((LoadAvg - CondorLoadAvg) <= 0.300000) || (State !=
"Unclaimed"
&& State != "Owner"))
Requirements = START

Why is there this mismatch - CpuisBusy="FALSE" and Activity=Busy?
The Loadaverages indicate that a procss can start, but something makes 
the
Activity="Busy". How do I find out why one vm is always Busy, which was 
now so before the OS upgrade?
Similarly, if HT is enabled in BIOS, there are 4 vm's on a node. Two of 
these are Claimed/Busy (Loadav=0) and the other two are Owner/Idle
(doing
user process, LoadAv=1).

Thanks in advance for any help on this

Nagaraj
-- 
+----------------------------------
+--------------------------------------+
Nagaraj Panyam                     | Office tel: +91-22-22782610
Dept of High Energy Physics        | Office fax: +91-22-22804610
Tata Instt. of Fundamental Research| Home  tel : +91-22-22804936
Mumbai - 400 005, INDIA            | **Email** : pn@xxxxxxxxxxx
+----------------------------------
+--------------------------------------+
_______________________________________________
Condor-users mailing list
Condor-users@xxxxxxxxxxx
https://lists.cs.wisc.edu/mailman/listinfo/condor-users







_______________________________________________
Condor-users mailing list
Condor-users@xxxxxxxxxxx
https://lists.cs.wisc.edu/mailman/listinfo/condor-users












_______________________________________________
Condor-users mailing list
Condor-users@xxxxxxxxxxx
https://lists.cs.wisc.edu/mailman/listinfo/condor-users
-- +---------------------------------- +--------------------------------------+ 
Nagaraj Panyam                     | Office tel: +91-22-22782610
Dept of High Energy Physics        | Office fax: +91-22-22804610
Tata Instt. of Fundamental Research| Home  tel : +91-22-22804936
Mumbai - 400 005, INDIA            | **Email** : pn@xxxxxxxxxxx
+---------------------------------- +--------------------------------------+ 

_______________________________________________
Condor-users mailing list
Condor-users@xxxxxxxxxxx
https://lists.cs.wisc.edu/mailman/listinfo/condor-users