Mailing List Archives Public Access	UW Madison Computer Sciences Department Computer Systems Lab
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Condor-users] Requirements = MyAddress == ... / match but reject the job for unknown reasons

Date: Sat, 16 Jun 2007 17:44:25 -0400
From: BBrooks <brian.brooks@xxxxxxx>
Subject: [Condor-users] Requirements = MyAddress == ... / match but reject the job for unknown reasons
For a grid computing course, I'm developing some student exercises.
For demonstration purposes, I'd like to control the flocking done
between two condor pools.  I'm attempting to limit the flocking using
the ClassAd constraint "MyAddress".  I would have preferred to use the
ClassAd constraint "Name" but because of the DNS configuration, I'm
having to resort to IP addresses to fully qualify the job in a
flocking scenario.

I've run into the problem that although "MyAddress" convinces the
master machine to start the job on the correct execute machine, the
startd on the execute node is responding with

StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore: Command received
via TCP from host <130.218.245.28:42859>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore: received command
442 (REQUEST_CLAIM), calling handler (command_request_claim)
--snip--
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Schedd addr =
<130.218.245.28:42102>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Alive interval = 300
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Received ClaimId from
schedd (<192.168.3.254:36199>#1182022011#41#...)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Request to claim
resource refused.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Job requirements not satisfied.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: State change: claiming
protocol failed
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Changing state: Matched -> Owner

Any ideas on why the startd is refusing the resource claim?  Is there
a better constraint than MyAddress for IP addresses?

Below here are some details on the submit that is reproducing this
problem.  Originally, I was submitting a job from the 1st pool and
waiting for it to flock to the 2nd pool.  Through hours of debugging
I've isolated the problem to a single pool scenario.

[bbrook23@csgrid03 bb]$ cat submit
Universe   = vanilla
Executable = hostname
Arguments  =
Log        = simple.log
Output     = simple.out
Error      = simple.error
requirements = MyAddress == "<192.168.3.254:36199>"
Queue
[bbrook23@csgrid03 bb]$

[bbrook23@csgrid03 bb]$ condor_findhost -c "MyAddress ==
\"<192.168.3.254:36199>\""
vm1@xxxxxxxxxxxxxxxxx
[bbrook23@csgrid03 bb]$

The condor pools were originally setup using Rocks 4.2 and the Condor
6.8.0 Roll.  In an effort to resolve the issue, I upgraded to Condor
6.8.5 for RedHat Enterprise 4 Linux x86_64 (Opteron).  Also, so I
could get -better-analyze on x86_64.  Regrettably, better-analyze
isn't providing anymore insight.

[bbrook23@csgrid03 bb]$ condor_q -better-analyze
-- Submitter: csgrid03.kennesaw.edu : <130.218.245.28:42102> :
csgrid03.kennesaw.edu
---
010.000:  Run analysis summary.  Of 4 machines,
     0 are rejected by your job's requirements
     0 reject your job because of their own requirements
     0 match but are serving users with a better priority in the pool
     4 match but reject the job for unknown reasons
     0 match but will not currently preempt their existing job
     0 are available to run your job
       Last successful match: Sat Jun 16 17:13:16 2007
[bbrook23@csgrid03 bb]$

I've set DEBUG flags to the maximum on both the master and execute
machines (D_ALL).

csgrid03 Condor master (public eth1 130.218.245.28 / private eth0 192.168.3.1)
/home/condor/log/MatchLog:6/16 17:02:18 (fd:7) (pid:30292)
Matched 9.0 bbrook23@xxxxxxxxxxxx <130.218.245.28:42102> preempting
none <192.168.3.254:36199> vm1@xxxxxxxxxxxxxxxxx
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
CustomerName=Customer.bbrook23@xxxxxxxxxxxx , Old Priority=0.564 , New
Priority=0.565 , ResourcesUsed=2
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
RecentUsage=   2.000, UnchargedTime=0, AccumulatedUsage=24227.000,
BeginUsageTime=1181229160
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
(Accountant) Checking Matches
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) State
was Unclaimed - not claimed or matched
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Resource vm1@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199> was not claimed
by bbrook23@xxxxxxxxxxxx - removing match
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Accountant::RemoveMatch -
ResourceName=vm1@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
(ACCOUNTANT) Removed match between customer bbrook23@xxxxxxxxxxxx and
resource vm1@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) State
was Unclaimed - not claimed or matched
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Resource vm2@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199> was not claimed
by bbrook23@xxxxxxxxxxxx - removing match
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Accountant::RemoveMatch -
ResourceName=vm2@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
(ACCOUNTANT) Removed match between customer bbrook23@xxxxxxxxxxxx and
resource vm2@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) Phase
3:  Sorting submitter ads by priority ...
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) Phase
4.1:  Negotiating with schedds ...
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
NumStartdAds = 4
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
NormalFactor = 1.000000
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
MaxPrioValue = 0.565151
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
NumScheddAds = 1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Negotiating with bbrook23@xxxxxxxxxxxx at <130.218.245.28:42102>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) 0 seconds so far
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
NEGOTIATOR_IGNORE_USER_PRIORITIES is undefined, using default value of
False
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Calculating schedd limit with the following parameters
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
ScheddPrio       = 0.565151
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
ScheddPrioFactor = 1.000000
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
scheddShare      = 1.000000
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
scheddAbsShare   = 1.000000
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
ScheddUsage      = 0
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
scheddLimit      = 4
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
MaxscheddLimit   = 4
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) Socket
to <130.218.245.28:42102> already in cache, reusing
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Sending SEND_JOB_INFO/eom
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Getting reply from schedd ...
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfds=7
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfound=1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfds=7
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfound=1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Got JOB_INFO command; getting classad/eom
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Request 00009.00000:
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) Start
of sorting MatchList (len=4)
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Finished sorting MatchList
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
NEGOTIATOR_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) New
Daemon obj (startd) name: "NULL", pool: "NULL", addr:
"<192.168.3.254:36199>"
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Connecting to startd vm1@xxxxxxxxxxxxxxxxx at <192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
PRIV_ROOT --> PRIV_CONDOR at sock.C:532
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
STARTCOMMAND: starting 440 to <192.168.3.254:36199> on UDP port 49492.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: command 440 to <192.168.3.254:36199> on UDP port 49492
(non-blocking).
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: using session compute-0-0:22284:1182022253:0 for
{<192.168.3.254:36199>,<440>}.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: found cached session id compute-0-0:22284:1182022253:0 for
{<192.168.3.254:36199>,<440>}.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: Security Policy:
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: negotiating security for command 440.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: UDP, have_session == 1, can_neg == 1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: UDP has session compute-0-0:22284:1182022253:0.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: sending DC_AUTHENTICATE command
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: sending following classad:
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
SECMAN: startCommand succeeded.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
Sending MATCH_INFO/capability to vm1@xxxxxxxxxxxxxxxxx
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292)
(Capability is "<192.168.3.254:36199>#1182022011#41#..." )
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:10) (pid:30292) SEND
[611] <130.218.245.28:49492> <192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Destroying Daemon object:
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) Type:
4 (startd), Name: (null), Addr: <192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
FullHost: (null), Host: (null), Pool: (null), Port: -1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
IsLocal: N, IdStr: (null), Error: (null)
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)  ---
End of Daemon object info ---
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Sending PERMISSION, capability, startdAd to schedd
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Matched 9.0 bbrook23@xxxxxxxxxxxx <130.218.245.28:42102> preempting
none <192.168.3.254:36199> vm1@xxxxxxxxxxxxxxxxx
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Notifying the accountant
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
(ACCOUNTANT) Added match between customer bbrook23@xxxxxxxxxxxx and
resource vm1@xxxxxxxxxxxxxxxxx@<192.168.3.254:36199>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Successfully matched with vm1@xxxxxxxxxxxxxxxxx
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Sending SEND_JOB_INFO/eom
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Getting reply from schedd ...
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfds=7
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfound=1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfds=7
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
condor_read(): nfound=1
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Got NO_MORE_JOBS;  done negotiating
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Schedd bbrook23@xxxxxxxxxxxx got all it wants; removing it.
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
---------- Finished Negotiation Cycle ----------
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) in
DaemonCore NewTimer()
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292) In
cancel_timer(), id=7
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
Renewing timer id 7 for 120 secs
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> Timers
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> ~~~~~~
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 6, when = 1182027765, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 119, when = 1182027795, period = 0,
handler_descrip=<dc_touch_log_file>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 0, when = 1182027809, period = 120,
handler_descrip=<check_parent>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 7, when = 1182027858, period = 120,
handler_descrip=<Time to negotiate>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 2, when = 1182027915, period = 300,
handler_descrip=<check_session_cache>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 8, when = 1182027915, period = 300,
handler_descrip=<Update Collector>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 4, when = 1182027915, period = 240,
handler_descrip=<self_monitor>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 3, when = 1182029119, period = 1801,
handler_descrip=<handle_cookie_refresh>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore--> id = 5, when = 1182050714, period = 0,
handler_descrip=<DaemonCore::ReInit()>
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
leaving DaemonCore NewTimer, id=7
/home/condor/log/NegotiatorLog:6/16 17:02:18 (fd:7) (pid:30292)
DaemonCore Timeout() Complete, returning 27
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Calling
Handler <<Negotiator Command>> for Socket <<Negotiator Socket>>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Activity
on stashed negotiator socket
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Entered negotiate
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
NEGOTIATOR_TIMEOUT is undefined, using default value of 20
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) New Daemon
obj (negotiator) name: "NULL", pool: "NULL", addr: "NULL"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
COLLECTOR_HOST is set to "csgrid03.kennesaw.edu"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) New Daemon
obj (collector) name: "csgrid03.kennesaw.edu", pool: "NULL", addr:
"NULL"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
NONBLOCKING_COLLECTOR_UPDATE is undefined, using default value of True
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Using name
"csgrid03.kennesaw.edu" to find daemon
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Port not
specified, using default (9618)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Host info
"csgrid03.kennesaw.edu" is a hostname, finding IP address
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Trying to
find IP addr for "csgrid03.kennesaw.edu"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Calling
gethostbyname(csgrid03.kennesaw.edu)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Found IP
addr in hostent: 130.218.245.28
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Found IP
address and port <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Will use
UDP to update collector csgrid03.kennesaw.edu <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Trying to
query collector <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) New Daemon
obj (collector) name: "NULL", pool: "NULL", addr:
"<130.218.245.28:9618>"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Already
have address, no info to locate
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Address
"<130.218.245.28:9618>" specified but no name, looking up host info
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Trying to
find full hostname from hostent
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Main name
in hostent "csgrid03.kennesaw.edu" is fully qualified
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Querying
collector <130.218.245.28:9618> (csgrid03.kennesaw.edu) with classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)  --- End
of Query ClassAd ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) CONNECT
src=<130.218.245.28:42858> fd=12 dst=<130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
STARTCOMMAND: starting 50 to <130.218.245.28:9618> on TCP port 42858.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
command 50 to <130.218.245.28:9618> on TCP port 42858 (blocking).
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
using session csgrid03:30290:1182021915:4 for
{<130.218.245.28:9618>,<50>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
found cached session id csgrid03:30290:1182021915:4 for
{<130.218.245.28:9618>,<50>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
Security Policy:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
negotiating security for command 50.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending DC_AUTHENTICATE command
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending following classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
startCommand succeeded.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) CLOSE
<130.218.245.28:42858> fd=12
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Type: 5
(collector), Name: (null), Addr: <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) FullHost:
csgrid03.kennesaw.edu, Host: csgrid03, Pool: (null), Port: 9618
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Type: 5
(collector), Name: csgrid03.kennesaw.edu, Addr: <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) FullHost:
csgrid03.kennesaw.edu, Host: csgrid03, Pool: csgrid03.kennesaw.edu,
Port: 9618
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Found
NEGOTIATORIpAddr in ClassAd from collector, using
"<130.218.245.28:42103>"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Found
CondorVersion in ClassAd from collector, using "$CondorVersion: 6.8.5
May 17 2007 $"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Found
CondorPlatform in ClassAd from collector, using "$CondorPlatform:
X86_64-LINUX_RHEL3 $"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Using port
42103 based on address "<130.218.245.28:42103>"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Address
"<130.218.245.28:42103>" specified but no name, looking up host info
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Trying to
find full hostname from hostent
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Main name
in hostent "csgrid03.kennesaw.edu" is fully qualified
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Type: 6
(negotiator), Name: (null), Addr: <130.218.245.28:42103>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) FullHost:
csgrid03.kennesaw.edu, Host: csgrid03, Pool: (null), Port: 42103
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) ## 2.
Negotiating with CM
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) ***
SwapSpace = 1020116
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) ***
ReservedSwap = 5120
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) *** Shadow
Size Estimate = 1800
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) *** Start
Limit For Swap = 563
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) ***
Current num of active shadows = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
Negotiating for owner: bbrook23@xxxxxxxxxxxx
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
AutoCluster:config(JobUniverse,LastCheckpointPlatform,NumCkpts)
invoked
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Checking
consistency running and runnable jobs
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Tables are
consistent
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) removing
auto cluster id 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) removing
auto cluster id 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Sent job
9.0 (autocluster=2)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In case PERMISSION
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) ## 4.
Received ClaimId <192.168.3.254:36199>#1182022011#41#...
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Received match ad
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) ***
ClassAd of Matched Resource ***
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Entered
IpVerify::AddAllowHost(192.168.3.254, WRITE)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
IpVerify::AddAllowHost: Already have 192.168.3.254 with 32
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Entered
IpVerify::AddAllowHost(192.168.3.254, DAEMON)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
IpVerify::AddAllowHost: Already have 192.168.3.254 with 131072
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Enqueued
contactStartd startd=<192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) in
DaemonCore NewTimer()
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> Timers
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> ~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 227, when = 1182027738, period = 0,
handler_descrip=<checkContactQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 6, when = 1182027765, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 12, when = 1182027794, period = 60,
handler_descrip=<PeriodicExpr>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 226, when = 1182027795, period = 0,
handler_descrip=<dc_touch_log_file>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 0, when = 1182027809, period = 120,
handler_descrip=<check_parent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 2, when = 1182027915, period = 300,
handler_descrip=<check_session_cache>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 4, when = 1182027915, period = 240,
handler_descrip=<self_monitor>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 7, when = 1182027922, period = 0,
handler_descrip=<timeout>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 8, when = 1182027923, period = 0,
handler_descrip=<StartJobs>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 9, when = 1182027924, period = 300,
handler_descrip=<sendAlives>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 11, when = 1182029114, period = 3600,
handler_descrip=<CkptWallClock>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 3, when = 1182029119, period = 1801,
handler_descrip=<handle_cookie_refresh>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 5, when = 1182050714, period = 0,
handler_descrip=<DaemonCore::ReInit()>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 10, when = 1182108314, period = 86400,
handler_descrip=<CleanJobQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) leaving
DaemonCore NewTimer, id=227
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfds=11
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Out of
jobs - 1 jobs matched, 0 jobs idle, flock level = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) JobsRunning = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) JobsIdle = 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) JobsHeld = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) JobsRemoved = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
LocalUniverseJobsRunning = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
LocalUniverseJobsIdle = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SchedUniverseJobsRunning = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SchedUniverseJobsIdle = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) N_Owners = 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) MaxJobsRunning = 200
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
ENABLE_SOAP is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Trying to
update collector <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Attempting
to send update via UDP to collector csgrid03.kennesaw.edu
<130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
STARTCOMMAND: starting 1 to <130.218.245.28:9618> on UDP port 49492.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
command 1 to <130.218.245.28:9618> on UDP port 49492 (non-blocking).
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
using session csgrid03:30290:1182021915:1 for
{<130.218.245.28:9618>,<1>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
found cached session id csgrid03:30290:1182021915:1 for
{<130.218.245.28:9618>,<1>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
Security Policy:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
negotiating security for command 1.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
UDP, have_session == 1, can_neg == 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
UDP has session csgrid03:30290:1182021915:1.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending DC_AUTHENTICATE command
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending following classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
startCommand succeeded.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SEND
[1000] <130.218.245.28:49492> <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SEND [525]
<130.218.245.28:49492> <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Sent HEART
BEAT ad to 1 collectors. Number of submittors=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Attempting
to send update via UDP to collector csgrid02.kennesaw.edu
<130.218.245.27:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
STARTCOMMAND: starting 1 to <130.218.245.27:9618> on UDP port 49493.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
command 1 to <130.218.245.27:9618> on UDP port 49493 (non-blocking).
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
using session csgrid02:32534:1182022035:36 for
{<130.218.245.27:9618>,<1>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
found cached session id csgrid02:32534:1182022035:36 for
{<130.218.245.27:9618>,<1>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
Security Policy:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
negotiating security for command 1.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
UDP, have_session == 1, can_neg == 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
UDP has session csgrid02:32534:1182022035:36.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending DC_AUTHENTICATE command
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending following classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
startCommand succeeded.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SEND
[1000] <130.218.245.28:49493> <130.218.245.27:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SEND [526]
<130.218.245.28:49493> <130.218.245.27:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Changed
attribute: RunningJobs = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Changed
attribute: IdleJobs = 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Changed
attribute: HeldJobs = 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Changed
attribute: FlockedJobs = 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Changed
attribute: Name = "bbrook23@xxxxxxxxxxxx"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Sent ad to
central manager for bbrook23@xxxxxxxxxxxx
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Trying to
update collector <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Attempting
to send update via UDP to collector csgrid03.kennesaw.edu
<130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
STARTCOMMAND: starting 11 to <130.218.245.28:9618> on UDP port 49494.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
command 11 to <130.218.245.28:9618> on UDP port 49494 (non-blocking).
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
using session csgrid03:30290:1182021915:1 for
{<130.218.245.28:9618>,<11>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
found cached session id csgrid03:30290:1182021915:1 for
{<130.218.245.28:9618>,<11>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
Security Policy:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
negotiating security for command 11.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
UDP, have_session == 1, can_neg == 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
UDP has session csgrid03:30290:1182021915:1.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending DC_AUTHENTICATE command
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending following classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
startCommand succeeded.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SEND
[1000] <130.218.245.28:49494> <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SEND [493]
<130.218.245.28:49494> <130.218.245.28:9618>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Sent ad to
1 collectors for bbrook23@xxxxxxxxxxxx
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
============ Begin clean_shadow_recs =============
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
============ End clean_shadow_recs =============
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) New Daemon
obj (startd) name: "NULL", pool: "NULL", addr: "NULL"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SCHEDD_ASSUME_NEGOTIATOR_GONE is undefined, using default value of 480
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Type: 4
(startd), Name: (null), Addr: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) FullHost:
(null), Host: (null), Pool: (null), Port: -1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In
reset_timer(), id=7, time=300, period=0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) in
DaemonCore NewTimer()
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In
cancel_timer(), id=7
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Renewing
timer id 7 for 300 secs
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> Timers
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> ~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 227, when = 1182027738, period = 0,
handler_descrip=<checkContactQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 6, when = 1182027765, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 12, when = 1182027794, period = 60,
handler_descrip=<PeriodicExpr>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 226, when = 1182027795, period = 0,
handler_descrip=<dc_touch_log_file>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 0, when = 1182027809, period = 120,
handler_descrip=<check_parent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 2, when = 1182027915, period = 300,
handler_descrip=<check_session_cache>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 4, when = 1182027915, period = 240,
handler_descrip=<self_monitor>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 8, when = 1182027923, period = 0,
handler_descrip=<StartJobs>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 9, when = 1182027924, period = 300,
handler_descrip=<sendAlives>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 7, when = 1182028038, period = 0,
handler_descrip=<timeout>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 11, when = 1182029114, period = 3600,
handler_descrip=<CkptWallClock>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 3, when = 1182029119, period = 1801,
handler_descrip=<handle_cookie_refresh>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 5, when = 1182050714, period = 0,
handler_descrip=<DaemonCore::ReInit()>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 10, when = 1182108314, period = 86400,
handler_descrip=<CleanJobQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) leaving
DaemonCore NewTimer, id=7
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In
DaemonCore Timeout()
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> Timers
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> ~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 227, when = 1182027738, period = 0,
handler_descrip=<checkContactQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 6, when = 1182027765, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 12, when = 1182027794, period = 60,
handler_descrip=<PeriodicExpr>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 226, when = 1182027795, period = 0,
handler_descrip=<dc_touch_log_file>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 0, when = 1182027809, period = 120,
handler_descrip=<check_parent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 2, when = 1182027915, period = 300,
handler_descrip=<check_session_cache>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 4, when = 1182027915, period = 240,
handler_descrip=<self_monitor>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 8, when = 1182027923, period = 0,
handler_descrip=<StartJobs>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 9, when = 1182027924, period = 300,
handler_descrip=<sendAlives>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 7, when = 1182028038, period = 0,
handler_descrip=<timeout>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 11, when = 1182029114, period = 3600,
handler_descrip=<CkptWallClock>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 3, when = 1182029119, period = 1801,
handler_descrip=<handle_cookie_refresh>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 5, when = 1182050714, period = 0,
handler_descrip=<DaemonCore::ReInit()>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 10, when = 1182108314, period = 86400,
handler_descrip=<CleanJobQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore: Calling handler for Timer 227 (checkContactQueue)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In
checkContactQueue(), args = 0xb29920, host=<192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In
Scheduler::contactStartd()
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
<192.168.3.254:36199>#1182022011#41#... bbrook23@xxxxxxxxxxxx
<192.168.3.254:36199> 9.0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) New Daemon
obj (startd) name: "NULL", pool: "NULL", addr: "<192.168.3.254:36199>"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) Requesting
resource from <192.168.3.254:36199> ...
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
non-blocking CONNECT started fd=12 dst=<192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> Sockets Registered
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> ~~~~~~~~~~~~~~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 0: 8 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 1: 9 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 2: 5 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 3: 6 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 4: 10 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 5: 11 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 6: 12 <Startd Contact Socket> to startd
<192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Type: 4
(startd), Name: (null), Addr: <192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) FullHost:
(null), Host: (null), Pool: (null), Port: -1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) In
cancel_timer(), id=227
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) DaemonCore
Timeout() Complete, returning 27
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) CONNECT
src=<130.218.245.28:42859> fd=12 dst=<192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Calling
Handler <to startd <192.168.3.254:36199>> for Socket <<Startd Contact
Socket>>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) In
Scheduler::startdContactConnectHandler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Got mrec
data pointer 0xb09fa0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) New Daemon
obj (startd) name: "NULL", pool: "NULL", addr: "<192.168.3.254:36199>"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
STARTCOMMAND: starting 442 to <192.168.3.254:36199> on TCP port 42859.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
command 442 to <192.168.3.254:36199> on TCP port 42859 (blocking).
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
using session compute-0-0:22284:1182022253:1 for
{<192.168.3.254:36199>,<442>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
found cached session id compute-0-0:22284:1182022253:1 for
{<192.168.3.254:36199>,<442>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
Security Policy:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
negotiating security for command 442.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending DC_AUTHENTICATE command
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
sending following classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) SECMAN:
startCommand succeeded.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
Cancel_Socket: cancelled socket 6 <<Startd Contact Socket>> 0xb29960
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> Sockets Registered
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> ~~~~~~~~~~~~~~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 0: 8 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 1: 9 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 2: 5 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 3: 6 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 4: 10 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 5: 11 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> Sockets Registered
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> ~~~~~~~~~~~~~~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 0: 8 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 1: 9 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 2: 5 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 3: 6 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 4: 10 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 5: 11 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> 6: 12 <Startd Contact Socket> to startd
<192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Registered
startd contact socket.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Type: 4
(startd), Name: (null), Addr: <192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) FullHost:
(null), Host: (null), Pool: (null), Port: -1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) In
DaemonCore Timeout()
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) DaemonCore--> Timers
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) DaemonCore--> ~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 6, when = 1182027765, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 12, when = 1182027794, period = 60,
handler_descrip=<PeriodicExpr>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 226, when = 1182027795, period = 0,
handler_descrip=<dc_touch_log_file>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 0, when = 1182027809, period = 120,
handler_descrip=<check_parent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 2, when = 1182027915, period = 300,
handler_descrip=<check_session_cache>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 4, when = 1182027915, period = 240,
handler_descrip=<self_monitor>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 8, when = 1182027923, period = 0,
handler_descrip=<StartJobs>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 9, when = 1182027924, period = 300,
handler_descrip=<sendAlives>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 7, when = 1182028038, period = 0,
handler_descrip=<timeout>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 11, when = 1182029114, period = 3600,
handler_descrip=<CkptWallClock>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 3, when = 1182029119, period = 1801,
handler_descrip=<handle_cookie_refresh>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 5, when = 1182050714, period = 0,
handler_descrip=<DaemonCore::ReInit()>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
DaemonCore--> id = 10, when = 1182108314, period = 86400,
handler_descrip=<CleanJobQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) DaemonCore
Timeout() Complete, returning 27
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Calling
Handler <to startd <192.168.3.254:36199>> for Socket <<Startd Contact
Socket>>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) In
Scheduler::startdContactSockHandler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Got mrec
data pointer 0xb09fa0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
condor_read(): nfds=13
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
condor_read(): nfds=13
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291)
condor_read(): nfound=1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) (Request
was NOT accepted)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Called
send_vacate( <192.168.3.254:36199>, 443 )
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
PRIV_CONDOR --> PRIV_ROOT at sock.C:526
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) PRIV_ROOT
--> PRIV_CONDOR at sock.C:532
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
SCHEDD_TIMEOUT_MULTIPLIER is undefined, using default value of 0
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) New Daemon
obj (startd) name: "NULL", pool: "NULL", addr: "<192.168.3.254:36199>"
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
STARTCOMMAND: starting 443 to <192.168.3.254:36199> on UDP port 49495.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
command 443 to <192.168.3.254:36199> on UDP port 49495 (blocking).
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
using session compute-0-0:22284:1182022253:1 for
{<192.168.3.254:36199>,<443>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
found cached session id compute-0-0:22284:1182022253:1 for
{<192.168.3.254:36199>,<443>}.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)
SEC_DEBUG_PRINT_KEYS is undefined, using default value of False
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
Security Policy:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
negotiating security for command 443.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
UDP, have_session == 1, can_neg == 1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
UDP has session compute-0-0:22284:1182022253:1.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
sending DC_AUTHENTICATE command
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
sending following classad:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SECMAN:
startCommand succeeded.
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) SEND [659]
<130.218.245.28:49495> <192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) Sent
RELEASE_CLAIM to startd on <192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) Destroying
Daemon object:
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) Type: 4
(startd), Name: (null), Addr: <192.168.3.254:36199>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) FullHost:
(null), Host: (null), Pool: (null), Port: -1
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291) IsLocal:
N, IdStr: (null), Error: (null)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:14) (pid:30291)  --- End
of Daemon object info ---
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) Match
record (<192.168.3.254:36199>, 9, 0) deleted
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) ClaimId of
deleted match: <192.168.3.254:36199>#1182022011#41#...
/home/condor/log/SchedLog:6/16 17:02:18 (fd:13) (pid:30291) CLOSE
<130.218.245.28:42859> fd=12
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
Cancel_Socket: cancelled socket 6 <<Startd Contact Socket>> 0xb29960
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> Sockets Registered
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> ~~~~~~~~~~~~~~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> 0: 8 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> 1: 9 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> 2: 5 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> 3: 6 <NULL> DC Command Handler
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> 4: 10 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> 5: 11 <Negotiator Socket> <Negotiator Command>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) In
DaemonCore Timeout()
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> Timers
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore--> ~~~~~~
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 6, when = 1182027765, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 12, when = 1182027794, period = 60,
handler_descrip=<PeriodicExpr>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 226, when = 1182027795, period = 0,
handler_descrip=<dc_touch_log_file>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 0, when = 1182027809, period = 120,
handler_descrip=<check_parent>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 2, when = 1182027915, period = 300,
handler_descrip=<check_session_cache>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 4, when = 1182027915, period = 240,
handler_descrip=<self_monitor>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 8, when = 1182027923, period = 0,
handler_descrip=<StartJobs>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 9, when = 1182027924, period = 300,
handler_descrip=<sendAlives>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 7, when = 1182028038, period = 0,
handler_descrip=<timeout>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 11, when = 1182029114, period = 3600,
handler_descrip=<CkptWallClock>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 3, when = 1182029119, period = 1801,
handler_descrip=<handle_cookie_refresh>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 5, when = 1182050714, period = 0,
handler_descrip=<DaemonCore::ReInit()>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
DaemonCore--> id = 10, when = 1182108314, period = 86400,
handler_descrip=<CleanJobQueue>
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291)
/home/condor/log/SchedLog:6/16 17:02:18 (fd:12) (pid:30291) DaemonCore
Timeout() Complete, returning 27


compute-0-0 Condor Execute Node (192.168.3.254)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) RECV 611 bytes at
<192.168.3.254:36199> from <130.218.245.28:49492>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) 	Full msg [611 bytes]
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: received
UDP packet from <130.218.245.28:49492>.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: received
DC_AUTHENTICATE from <130.218.245.28:49492>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: received
following ClassAd:
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: resuming
session id compute-0-0:22284:1182022253:0 with return address
<130.218.245.28:42103>:
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: Cached Session:
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: setting
sock->decode()
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: allowing an
empty message for sock.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: Success.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore: Command received
via UDP from host <130.218.245.28:49492>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore: received command
440 (MATCH_INFO), calling handler (command_match_info)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) vm1: match_info called
StartLog:6/16 17:02:18 (fd:5) (pid:22284) vm1: Received match
<192.168.3.254:36199>#1182022011#41#...
StartLog:6/16 17:02:18 (fd:5) (pid:22284) in DaemonCore NewTimer()
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 301, when
= 1182027858, period = 0, handler_descrip=<match_timed_out>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) leaving DaemonCore NewTimer, id=301
StartLog:6/16 17:02:18 (fd:5) (pid:22284) vm1: Started match timer
(301) for 120 seconds.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) vm1: State change: match
notification protocol successful
StartLog:6/16 17:02:18 (fd:5) (pid:22284) vm1: Changing state:
Unclaimed -> Matched
StartLog:6/16 17:02:18 (fd:5) (pid:22284) in DaemonCore NewTimer()
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 302, when
= 1182027742, period = 0, handler_descrip=<do_update>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 301, when
= 1182027858, period = 0, handler_descrip=<match_timed_out>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) leaving DaemonCore NewTimer, id=302
StartLog:6/16 17:02:18 (fd:5) (pid:22284) In DaemonCore Timeout()
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 302, when
= 1182027742, period = 0, handler_descrip=<do_update>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 301, when
= 1182027858, period = 0, handler_descrip=<match_timed_out>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore Timeout()
Complete, returning 4
StartLog:6/16 17:02:18 (fd:6) (pid:22284) ACCEPT
from=<130.218.245.28:42859> newfd=5 to=<192.168.3.254:36199>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) in DaemonCore NewTimer()
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 302, when
= 1182027742, period = 0, handler_descrip=<do_update>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 301, when
= 1182027858, period = 0, handler_descrip=<match_timed_out>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 303, when
= 1182027938, period = 0,
handler_descrip=<DaemonCore::HandleReqSocketTimerHandler>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) leaving DaemonCore NewTimer, id=303
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> Sockets Registered
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> 0: 8 <NULL> DC
Command Handler
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> 1: 9 <NULL> DC
Command Handler
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> 2: 5 Incoming
command DaemonCore::HandleReqSocketHandler
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) In DaemonCore Timeout()
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 302, when
= 1182027742, period = 0, handler_descrip=<do_update>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 301, when
= 1182027858, period = 0, handler_descrip=<match_timed_out>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 303, when
= 1182027938, period = 0,
handler_descrip=<DaemonCore::HandleReqSocketTimerHandler>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore Timeout()
Complete, returning 4
StartLog:6/16 17:02:18 (fd:6) (pid:22284) Calling Handler
<DaemonCore::HandleReqSocketHandler> for Socket <Incoming command>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) In cancel_timer(), id=303
StartLog:6/16 17:02:18 (fd:6) (pid:22284) Cancel_Socket: cancelled
socket 2 <Incoming command> 0xab4ef0
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> Sockets Registered
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> ~~~~~~~~~~~~~~~~~~~
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> 0: 8 <NULL> DC
Command Handler
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore--> 1: 9 <NULL> DC
Command Handler
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfds=6
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfound=1
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfds=6
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfound=1
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfds=6
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfound=1
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: received
DC_AUTHENTICATE from <130.218.245.28:42859>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: received
following ClassAd:
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: resuming
session id compute-0-0:22284:1182022253:1 with return address
<130.218.245.28:42102>:
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: Cached Session:
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: not authenticating.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: setting
sock->decode()
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: allowing an
empty message for sock.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DC_AUTHENTICATE: Success.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore: Command received
via TCP from host <130.218.245.28:42859>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) DaemonCore: received command
442 (REQUEST_CLAIM), calling handler (command_request_claim)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfds=6
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfound=1
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfds=6
StartLog:6/16 17:02:18 (fd:6) (pid:22284) condor_read(): nfound=1
StartLog:6/16 17:02:18 (fd:6) (pid:22284) In cancel_timer(), id=301
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Canceled match timer (301)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Schedd addr =
<130.218.245.28:42102>
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Alive interval = 300
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Received ClaimId from
schedd (<192.168.3.254:36199>#1182022011#41#...)
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Request to claim
resource refused.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Job requirements not satisfied.
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: State change: claiming
protocol failed
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Changing state: Matched -> Owner
StartLog:6/16 17:02:18 (fd:6) (pid:22284)
STARTD_SHOULD_WRITE_CLAIM_ID_FILE is undefined, using default value of
True
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: State change: IS_OWNER is false
StartLog:6/16 17:02:18 (fd:6) (pid:22284) vm1: Changing state: Owner
-> Unclaimed
StartLog:6/16 17:02:18 (fd:6) (pid:22284) CLOSE <192.168.3.254:36199> fd=5
StartLog:6/16 17:02:18 (fd:5) (pid:22284) In DaemonCore Timeout()
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 302, when
= 1182027742, period = 0, handler_descrip=<do_update>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore Timeout()
Complete, returning 4
StartLog:6/16 17:02:18 (fd:5) (pid:22284) RECV 659 bytes at
<192.168.3.254:36199> from <130.218.245.28:49495>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) 	Full msg [659 bytes]
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: received
UDP packet from <130.218.245.28:49495>.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: received
DC_AUTHENTICATE from <130.218.245.28:49495>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: received
following ClassAd:
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: resuming
session id compute-0-0:22284:1182022253:1 with return address
<130.218.245.28:42102>:
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: Cached Session:
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: setting
sock->decode()
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: allowing an
empty message for sock.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DC_AUTHENTICATE: Success.
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore: Command received
via UDP from host <130.218.245.28:49495>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore: received command
443 (RELEASE_CLAIM), calling handler (command_release_claim)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) Warning: can't find resource
with ClaimId (<192.168.3.254:36199>#1182022011#41#...)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) SEND [8]
<192.168.3.254:36199> <130.218.245.28:49495>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) In DaemonCore Timeout()
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> Timers
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> ~~~~~~
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 302, when
= 1182027742, period = 0, handler_descrip=<do_update>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 4, when =
1182027782, period = 240, handler_descrip=<self_monitor>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 300, when
= 1182027782, period = 0, handler_descrip=<dc_touch_log_file>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 0, when =
1182027786, period = 120, handler_descrip=<check_parent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 6, when =
1182027872, period = 1170,
handler_descrip=<DaemonCore::SendAliveToParent>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 7, when =
1182028022, period = 300, handler_descrip=<eval_and_update_all>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 2, when =
1182028022, period = 300, handler_descrip=<check_session_cache>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 3, when =
1182029226, period = 1801, handler_descrip=<handle_cookie_refresh>
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore--> id = 5, when =
1182050811, period = 0, handler_descrip=<DaemonCore::ReInit()>
StartLog:6/16 17:02:18 (fd:5) (pid:22284)
StartLog:6/16 17:02:18 (fd:5) (pid:22284) DaemonCore Timeout()
Complete, returning 4

In case it helps, here are the ip tables for these two machines...

csgrid03 master machine
[root@csgrid03 ~]# iptables -L
Chain INPUT (policy ACCEPT)
target     prot opt source               destination
ACCEPT     all  --  anywhere             anywhere
ACCEPT     all  --  anywhere             anywhere
ACCEPT     tcp  --  anywhere             anywhere            state NEW
tcp dpt:ssh
ACCEPT     icmp --  anywhere             anywhere            icmp any
ACCEPT     all  --  anywhere             anywhere            state
RELATED,ESTABLISHED
REJECT     udp  --  anywhere             anywhere            udp
dpts:0:1024 reject-with icmp-port-unreachable
REJECT     tcp  --  anywhere             anywhere            tcp
dpts:0:1024 reject-with icmp-port-unreachable
REJECT     udp  --  anywhere             anywhere            udp
dpt:8649 reject-with icmp-port-unreachable

Chain FORWARD (policy DROP)
target     prot opt source               destination
ACCEPT     all  --  anywhere             anywhere            state
NEW,RELATED,ESTABLISHED
ACCEPT     all  --  anywhere             anywhere

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination

[root@csgrid03 ~]# iptables -t nat -L
Chain PREROUTING (policy ACCEPT)
target     prot opt source               destination

Chain POSTROUTING (policy ACCEPT)
target     prot opt source               destination
MASQUERADE  all  --  anywhere             anywhere

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination
[root@csgrid03 ~]#


compute-0-0 execute machine
[root@compute-0-0 log]# iptables -L
Chain INPUT (policy ACCEPT)
target     prot opt source               destination
ACCEPT     all  --  anywhere             anywhere
ACCEPT     all  --  anywhere             anywhere
ACCEPT     tcp  --  anywhere             anywhere            state NEW
tcp dpt:ssh
ACCEPT     icmp --  anywhere             anywhere            icmp any
ACCEPT     all  --  anywhere             anywhere            state
RELATED,ESTABLISHED
REJECT     udp  --  anywhere             anywhere            udp
dpts:0:1024 reject-with icmp-port-unreachable
REJECT     tcp  --  anywhere             anywhere            tcp
dpts:0:1024 reject-with icmp-port-unreachable
REJECT     udp  --  anywhere             anywhere            udp
dpt:8649 reject-with icmp-port-unreachable

Chain FORWARD (policy DROP)
target     prot opt source               destination

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination

[root@compute-0-0 log]# iptables -t nat -L
Chain PREROUTING (policy ACCEPT)
target     prot opt source               destination

Chain POSTROUTING (policy ACCEPT)
target     prot opt source               destination

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination
[root@compute-0-0 log]#

--
Brian Brooks
(770) 794-9850
brian.brooks@xxxxxxx / bbrook23@xxxxxxxxxxxxxxxxxxxxx
Follow-Ups:
- Re: [Condor-users] Requirements = MyAddress == ... / match but reject the job for unknown reasons
  - From: Daniel Forrest
Prev by Date: Re: [Condor-users] [?????]
Next by Date: Re: [Condor-users] Requirements = MyAddress == ... / match but reject the job for unknown reasons
Previous by thread: Re: [Condor-users] Problems when jobs are submitted through WebServices
Next by thread: Re: [Condor-users] Requirements = MyAddress == ... / match but reject the job for unknown reasons
Index(es):
- Date
- Thread
Mailing List Archives

Public Access

[Condor-users] Requirements = MyAddress == ... / match but reject the job for unknown reasons
