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

Re: [Condor-users] Need help diagnosing flocking problems



Ben,

I've reproduced the problem you reported.

I haven't had time to fully understand what is going wrong. I did find that the following change in configuration made the problem go away:


SEC_DEFAULT_AUTHENTICATION_METHODS = FS,CLAIMTOBE,ANONYMOUS

-->

SEC_DEFAULT_AUTHENTICATION_METHODS = FS

Therefore, I have to eat my words that condor configuration alone can't cause the specific error. Therefore, I expect to find a bug, because this shouldn't be the case. I'll let you know what I find.

--Dan

On 2/23/12 2:11 PM, Ben Cotton wrote:
On Wed, Feb 22, 2012 at 5:16 PM, Steven Timm<timm@xxxxxxxx>  wrote:

If you could explain which machines carter-fe00, carter-adm,
and steele-cgf are it would be easier to debug.

carter-fe00 is the schedd host
carter-adm is carter-fe00's native collector and is otherwise
uninvolved in the process
steele-cgf is running the campus grid factory collector


On Wed, Feb 22, 2012 at 5:27 PM, Dan Bradley<dan@xxxxxxxxxxxx>  wrote:
What versions of condor are involved?
For all hosts:
$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $
$CondorPlatform: x86_64_rhap_5 $

On Wed, Feb 22, 2012 at 9:20 PM, Brian Bockelman<bbockelm@xxxxxxxxxxx>  wrote:
Can you turn on D_SECURITY and try again?  I'd be curious to see what security methods are being attempted.
Here you go. Nothing except logs follow this line.

#
# schedd log from carter-fe00
#
02/23/12 15:05:13 DC_AUTHENTICATE: received DC_AUTHENTICATE from
<128.210.9.99:34691>
02/23/12 15:05:13 DC_AUTHENTICATE: received following ClassAd:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "carter-fe00:17124:1329950454:569"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = ""
AuthMethods = "FS,CLAIMTOBE,ANONYMOUS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:42975>"
Integrity = "NO"
OutgoingNegotiation = "PREFERRED"
Command = 416
ValidCommands = "416,493,60007,1111,441,443,457,471"
SessionDuration = "86400"
CurrentTime = time()
User = "unauthenticated@unmapped"
MyRemoteUserName = "unauthenticated@unmapped"
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
SessionLease = 3600
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:13 DC_AUTHENTICATE: resuming session id
carter-fe00:17124:1329950454:569 with return address
<128.210.9.99:42975>:
02/23/12 15:05:13 DC_AUTHENTICATE: Cached Session:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "carter-fe00:17124:1329950454:569"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
AuthMethodsList = ""
ServerPid = 4765
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:42975>"
Integrity = "NO"
ParentUniqueID = "steele-cgf:4762:1329763152"
ValidCommands = "416,493,60007,1111,441,443,457,471"
SessionDuration = "86400"
CurrentTime = time()
User = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:13 SECMAN: other side is $CondorVersion: 7.6.4 Oct 20
2011 BuildID: 379441 $, NOT reauthenticating.
02/23/12 15:05:13 DC_AUTHENTICATE: not authenticating.
02/23/12 15:05:13 DC_AUTHENTICATE: Success.
02/23/12 15:05:13 PERMISSION GRANTED to unauthenticated@unmapped from
host 128.210.9.99 for command 416 (NEGOTIATE), access level
NEGOTIATOR: reason: cached result for NEGOTIATOR; see first case for
the full reason
02/23/12 15:05:13
02/23/12 15:05:13 Entered negotiate
02/23/12 15:05:13 Using negotiation protocol: NEGOTIATE
02/23/12 15:05:13 *** SwapSpace = 2147483647
02/23/12 15:05:13 *** ReservedSwap = 0
02/23/12 15:05:13 *** Shadow Size Estimate = 1800
02/23/12 15:05:13 *** Start Limit For Swap = 1193046
02/23/12 15:05:13 Negotiating for owner: bcotton@xxxxxxxxxxxxxxx
(flock level 1, pool steele-cgf.rcac.purdue.edu)
02/23/12 15:05:13
AutoCluster:config(JobUniverse,LastCheckpointPlatform,NumCkpts,cgf,Steele)
invoked
02/23/12 15:05:13 AutoCluster:config() significant attributes unchanged
02/23/12 15:05:13 Reusing prioritized runnable job list because
nothing has changed.
02/23/12 15:05:13 Job 1.0: is runnable
02/23/12 15:05:13 Sent job 1.0 (autocluster=1) to the negotiator
02/23/12 15:05:13 Can't receive ClaimId from negotiator
02/23/12 15:05:13 Failed to send NEGOTIATE to<128.210.9.99:34691>:
02/23/12 15:05:20 Evaluated periodic expressions in 0.000s, scheduling
next run in 60s




#
# Negotiator log from steele-cgf
#
02/23/12 15:05:08 enter Matchmaker::updateCollector
02/23/12 15:05:08 Trying to update collector<128.210.9.99:9618>
02/23/12 15:05:08 Attempting to send update via UDP to collector
steele-cgf.rcac.purdue.edu<128.210.9.99:9618>
02/23/12 15:05:08 SECMAN: command 49 UPDATE_NEGOTIATOR_AD to collector
steele-cgf.rcac.purdue.edu from UDP port 53528 (non-blocking).
02/23/12 15:05:08 SECMAN: using session
steele-cgf:4763:1330022426:13046 for {<128.210.9.99:9618>,<49>}.
02/23/12 15:05:08 SECMAN: found cached session id
steele-cgf:4763:1330022426:13046 for {<128.210.9.99:9618>,<49>}.
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330022426:13046"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 10
ValidCommands = "10,49,51,73,5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:08 SECMAN: Security Policy:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330022426:13046"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 10
ValidCommands = "10,49,51,73,5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:08 SECMAN: negotiating security for command 49.
02/23/12 15:05:08 SECMAN: UDP, m_have_session == 1
02/23/12 15:05:08 SECMAN: UDP has session steele-cgf:4763:1330022426:13046.
02/23/12 15:05:08 SECMAN: about to enable encryption.
02/23/12 15:05:08 SECMAN: successfully enabled encryption (but
encryption mode is off by default for this packet).
02/23/12 15:05:08 SECMAN: sending DC_AUTHENTICATE command
02/23/12 15:05:08 SECMAN: sending following classad:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330022426:13046"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:42975>"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 49
ValidCommands = "10,49,51,73,5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:08 Getting authenticated user from cached session:
unauthenticated@unmapped
02/23/12 15:05:08 SECMAN: startCommand succeeded.
02/23/12 15:05:08 Authorizing server 'unauthenticated@unmapped/128.210.9.99'.
02/23/12 15:05:08 exit Matchmaker::UpdateCollector
02/23/12 15:05:12 DC_AUTHENTICATE: received UDP packet from
<128.210.9.99:56948>.
02/23/12 15:05:12 DC_AUTHENTICATE: received DC_AUTHENTICATE from
<128.210.9.99:56948>
02/23/12 15:05:12 DC_AUTHENTICATE: received following ClassAd:
Enact = "YES"
Subsystem = "SCHEDD"
Sid = "steele-cgf:4765:1330022892:4"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:51812>"
Integrity = "NO"
OutgoingNegotiation = "PREFERRED"
ServerTime = 1330027512
Command = 421
AuthCommand = 421
ValidCommands = "60000,60008,60017,421,60004,60012,60007,451,457,463"
SessionDuration = "86400"
CurrentTime = time()
User = "unauthenticated@unmapped"
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
SessionLease = 3600
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 DC_AUTHENTICATE: resuming session id
steele-cgf:4765:1330022892:4 with return address<128.210.9.99:51812>:
02/23/12 15:05:12 DC_AUTHENTICATE: Cached Session:
Enact = "YES"
Subsystem = "SCHEDD"
Sid = "steele-cgf:4765:1330022892:4"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
ServerPid = 4764
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:51812>"
Integrity = "NO"
ParentUniqueID = "steele-cgf:4762:1329763152"
ValidCommands = "60000,60008,60017,421,60004,60012,60007,451,457,463"
SessionDuration = "86400"
CurrentTime = time()
User = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 DC_AUTHENTICATE: encryption enabled with session key
id steele-cgf:4765:1330022892:4 (but encryption mode is off by default
for this packet).
02/23/12 15:05:12 DC_AUTHENTICATE: Success.
02/23/12 15:05:12 PERMISSION GRANTED to
cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx from host 128.210.9.99 for command
421 (Reschedule), access level DAEMON: reason: cached result for
DAEMON; see first case for the full reason
02/23/12 15:05:12 ---------- Started Negotiation Cycle ----------
02/23/12 15:05:12 Phase 1:  Obtaining ads from collector ...
02/23/12 15:05:12   Getting all public ads ...
02/23/12 15:05:12 Trying to query collector<128.210.9.99:9618>
02/23/12 15:05:12 SECMAN: command 48 QUERY_ANY_ADS to collector at
<128.210.9.99:9618>  from TCP port 58867 (blocking).
02/23/12 15:05:12 SECMAN: using session
steele-cgf:4763:1330026260:13240 for {<128.210.9.99:9618>,<48>}.
02/23/12 15:05:12 SECMAN: found cached session id
steele-cgf:4763:1330026260:13240 for {<128.210.9.99:9618>,<48>}.
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330026260:13240"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 48
ValidCommands = "5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 SECMAN: Security Policy:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330026260:13240"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 48
ValidCommands = "5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 SECMAN: negotiating security for command 48.
02/23/12 15:05:12 SECMAN: sending DC_AUTHENTICATE command
02/23/12 15:05:12 SECMAN: sending following classad:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330026260:13240"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:42975>"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 48
ValidCommands = "5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 SECMAN: resume, other side is $CondorVersion: 7.6.4
Oct 20 2011 BuildID: 379441 $, NOT reauthenticating.
02/23/12 15:05:12 Getting authenticated user from cached session:
unauthenticated@unmapped
02/23/12 15:05:12 SECMAN: startCommand succeeded.
02/23/12 15:05:12 Authorizing server 'unauthenticated@unmapped/128.210.9.99'.
02/23/12 15:05:12   Sorting 10 ads ...
02/23/12 15:05:12 Ignoring submitter
cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx with no requested jobs
02/23/12 15:05:12   Getting startd private ads ...
02/23/12 15:05:12 Trying to query collector<128.210.9.99:9618>
02/23/12 15:05:12 SECMAN: command 10 QUERY_STARTD_PVT_ADS to collector
at<128.210.9.99:9618>  from TCP port 34931 (blocking).
02/23/12 15:05:12 SECMAN: using session
steele-cgf:4763:1330022426:13046 for {<128.210.9.99:9618>,<10>}.
02/23/12 15:05:12 SECMAN: found cached session id
steele-cgf:4763:1330022426:13046 for {<128.210.9.99:9618>,<10>}.
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330022426:13046"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 10
ValidCommands = "10,49,51,73,5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 SECMAN: Security Policy:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330022426:13046"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 10
ValidCommands = "10,49,51,73,5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 SECMAN: negotiating security for command 10.
02/23/12 15:05:12 SECMAN: sending DC_AUTHENTICATE command
02/23/12 15:05:12 SECMAN: sending following classad:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "steele-cgf:4763:1330022426:13046"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = "FS,CLAIMTOBE,ANONYMOUS"
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:42975>"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 10
ValidCommands = "10,49,51,73,5,6,7,9,12,43,46,48,50,56,62,65,68,71,74,60007,457"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "cgfsteel@xxxxxxxxxxxxxxxxxxxxxxxxxx"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:12 SECMAN: resume, other side is $CondorVersion: 7.6.4
Oct 20 2011 BuildID: 379441 $, NOT reauthenticating.
02/23/12 15:05:12 Getting authenticated user from cached session:
unauthenticated@unmapped
02/23/12 15:05:12 SECMAN: startCommand succeeded.
02/23/12 15:05:12 Authorizing server 'unauthenticated@unmapped/128.210.9.99'.
02/23/12 15:05:12 Got ads: 10 public and 2 private
02/23/12 15:05:12 Public ads include 1 submitter, 2 startd
02/23/12 15:05:12 Phase 2:  Performing accounting ...
02/23/12 15:05:12 Entering compute_significant_attrs()
02/23/12 15:05:12 Leaving compute_significant_attrs() -
result=JobUniverse,LastCheckpointPlatform,NumCkpts,cgf,Steele
02/23/12 15:05:12 Phase 3:  Sorting submitter ads by priority ...
02/23/12 15:05:12 Phase 4.1:  Negotiating with schedds ...
02/23/12 15:05:12     numSlots = 2
02/23/12 15:05:12     slotWeightTotal = 2.000000
02/23/12 15:05:12     pieLeft = 2.000
02/23/12 15:05:12     NormalFactor = 1.000000
02/23/12 15:05:12     MaxPrioValue = 0.776520
02/23/12 15:05:12     NumSubmitterAds = 1
02/23/12 15:05:12   Negotiating with bcotton@xxxxxxxxxxxxxxx at
<128.211.148.45:33757>
02/23/12 15:05:12 0 seconds so far
02/23/12 15:05:12   Calculating submitter limit with the following parameters
02/23/12 15:05:12     SubmitterPrio       = 0.776520
02/23/12 15:05:12     SubmitterPrioFactor = 1.000000
02/23/12 15:05:12     submitterShare      = 1.000000
02/23/12 15:05:12     submitterAbsShare   = 1.000000
02/23/12 15:05:12     submitterLimit    = 2.000000
02/23/12 15:05:12     submitterUsage    = 0.000000
02/23/12 15:05:12 Socket to bcotton@xxxxxxxxxxxxxxx
(<128.211.148.45:33757>) not in cache, creating one
02/23/12 15:05:12 SECMAN: command 416 NEGOTIATE to schedd
bcotton@xxxxxxxxxxxxxxx from TCP port 34691 (blocking).
02/23/12 15:05:12 SECMAN: using session
carter-fe00:17124:1329950454:569 for {<128.211.148.45:33757>,<416>}.
02/23/12 15:05:13 SECMAN: found cached session id
carter-fe00:17124:1329950454:569 for {<128.211.148.45:33757>,<416>}.
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "carter-fe00:17124:1329950454:569"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = ""
AuthMethods = "FS,CLAIMTOBE,ANONYMOUS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 416
ValidCommands = "416,493,60007,1111,441,443,457,471"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:13 SECMAN: Security Policy:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "carter-fe00:17124:1329950454:569"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = ""
AuthMethods = "FS,CLAIMTOBE,ANONYMOUS"
Encryption = "NO"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 416
ValidCommands = "416,493,60007,1111,441,443,457,471"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:13 SECMAN: negotiating security for command 416.
02/23/12 15:05:13 SECMAN: sending DC_AUTHENTICATE command
02/23/12 15:05:13 SECMAN: sending following classad:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "carter-fe00:17124:1329950454:569"
CryptoMethods = "3DES,BLOWFISH"
TriedAuthentication = true
UseSession = "YES"
AuthMethodsList = ""
AuthMethods = "FS,CLAIMTOBE,ANONYMOUS"
Encryption = "NO"
ServerCommandSock = "<128.210.9.99:42975>"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 416
ValidCommands = "416,493,60007,1111,441,443,457,471"
SessionDuration = "86400"
User = "unauthenticated@unmapped"
CurrentTime = time()
MyRemoteUserName = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.6.4 Oct 20 2011 BuildID: 379441 $"
AuthRequired = false
Authentication = "YES"
02/23/12 15:05:13 SECMAN: resume, other side is $CondorVersion: 7.6.4
Oct 20 2011 BuildID: 379441 $, NOT reauthenticating.
02/23/12 15:05:13 Getting authenticated user from cached session:
unauthenticated@unmapped
02/23/12 15:05:13 SECMAN: startCommand succeeded.
02/23/12 15:05:13 Authorizing server 'unauthenticated@unmapped/128.211.148.45'.
02/23/12 15:05:13 SocketCache:  Found unused slot 1
02/23/12 15:05:13     Sending SEND_JOB_INFO/eom
02/23/12 15:05:13     Getting reply from schedd ...
02/23/12 15:05:13     Got JOB_INFO command; getting classad/eom
02/23/12 15:05:13     Request 00001.00000:
02/23/12 15:05:13 matchmakingAlgorithm: limit 2.000000 used 0.000000
pieLeft 2.000000
02/23/12 15:05:13 Failed to evaluate NEGOTIATOR_POST_JOB_RANK
expression to a float.
02/23/12 15:05:13 Failed to evaluate NEGOTIATOR_POST_JOB_RANK
expression to a float.
02/23/12 15:05:13 Start of sorting MatchList (len=2)
02/23/12 15:05:13 Finished sorting MatchList
02/23/12 15:05:13       Sending PERMISSION, claim id, startdAd to schedd
02/23/12 15:05:13       Matched 1.0 bcotton@xxxxxxxxxxxxxxx
<128.211.148.45:33757>  preempting none
<172.18.25.143:57856?CCBID=128.210.9.99:9618#1050>
29735@xxxxxxxxxxxxxxxxxxxxxxxxxxx
02/23/12 15:05:13       Notifying the accountant
02/23/12 15:05:13       Successfully matched with
29735@xxxxxxxxxxxxxxxxxxxxxxxxxxx
02/23/12 15:05:13     Sending SEND_JOB_INFO/eom
02/23/12 15:05:13 condor_write(): Socket closed when trying to write
13 bytes to schedd bcotton@xxxxxxxxxxxxxxx, fd is 7
02/23/12 15:05:13 Buf::write(): condor_write() failed
02/23/12 15:05:13     Failed to send SEND_JOB_INFO/eom
02/23/12 15:05:13   Error: Ignoring submitter for this cycle
02/23/12 15:05:13  resources used by bcotton@xxxxxxxxxxxxxxx are 1.000000
02/23/12 15:05:13  resources used scheddUsed= 1.000000
02/23/12 15:05:13  negotiateWithGroup resources used scheddAds length 0
02/23/12 15:05:13 ---------- Finished Negotiation Cycle ----------