09/21/12 10:28:02 (fd:11) (pid:5221) Now in new log file /var/condor/log/NegotiatorLog
09/21/12 10:28:02 (fd:11) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:11) (pid:5221) IPVERIFY: checking grovsl82 against 163.104.9.160
09/21/12 10:28:02 (fd:11) (pid:5221) IPVERIFY: matched 163.104.9.160 to 163.104.9.160
09/21/12 10:28:02 (fd:11) (pid:5221) IPVERIFY: ip found is 1
09/21/12 10:28:02 (fd:11) (pid:5221) get_full_hostname() failed for address 163.104.9.16009/21/12 10:28:02 (fd:11) (pid:5221) Querying collector <163.104.9.160:9618> ((null)) with classad:
TargetType = "Any"
CurrentTime = time()
MyType = "Query"
Requirements = ( ( ( MyType == "Scheduler" ) || ( MyType == "Submitter" ) ) || ( ( MyType == "Machine" ) ) )
09/21/12 10:28:02 (fd:11) (pid:5221)  --- End of Query ClassAd ---
09/21/12 10:28:02 (fd:11) (pid:5221) Guess address string for host = <163.104.9.160:9618>, port = 0
09/21/12 10:28:02 (fd:11) (pid:5221) it was sinful string. ip = 163.104.9.160, port = 9618
09/21/12 10:28:02 (fd:11) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:11) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:12) (pid:5221) OUT_LOWPORT is undefined, using default value of 0
09/21/12 10:28:02 (fd:12) (pid:5221) LOWPORT is undefined, using default value of 0
09/21/12 10:28:02 (fd:12) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) CONNECT bound to <163.104.9.160:54325> fd=11 peer=<163.104.9.160:9618>
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: command 48 QUERY_ANY_ADS to collector at <163.104.9.160:9618> from TCP port 54325 (blocking).
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: using session grovsl82:5216:1348215398:1 for {<163.104.9.160:9618>,<48>}.
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: found cached session id grovsl82:5216:1348215398:1 for {<163.104.9.160:9618>,<48>}.
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "grovsl82:5216:1348215398:1"
CryptoMethods = "3DES,BLOWFISH"
UseSession = "YES"
AuthMethodsList = "FS,KERBEROS,GSI"
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 = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.8.3 Sep 04 2012 BuildID: 62667 $"
Authentication = "NO"
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: Security Policy:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "grovsl82:5216:1348215398:1"
CryptoMethods = "3DES,BLOWFISH"
UseSession = "YES"
AuthMethodsList = "FS,KERBEROS,GSI"
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 = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.8.3 Sep 04 2012 BuildID: 62667 $"
Authentication = "NO"
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: negotiating security for command 48.
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: sending DC_AUTHENTICATE command
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: sending following classad:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "grovsl82:5216:1348215398:1"
CryptoMethods = "3DES,BLOWFISH"
UseSession = "YES"
AuthMethodsList = "FS,KERBEROS,GSI"
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<163.104.9.160:45215>"
OutgoingNegotiation = "PREFERRED"
Integrity = "NO"
Command = 48
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 = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.8.3 Sep 04 2012 BuildID: 62667 $"
Authentication = "NO"
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_write(fd=11 collector at <163.104.9.160:9618>,,size=627,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Getting authenticated user from cached session: unauthenticated@unmapped
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: startCommand succeeded.
09/21/12 10:28:02 (fd:12) (pid:5221) Authorizing server 'unauthenticated@unmapped/163.104.9.160'.
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_write(fd=11 collector at <163.104.9.160:9618>,,size=168,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=5,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=4091,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=5,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=4091,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=5,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=4091,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=5,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=4091,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=5,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=1315,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 adding fd 11 (socket:[2649804488])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) CLOSE <163.104.9.160:54325> fd=11
09/21/12 10:28:02 (fd:11) (pid:5221) Destroying Daemon object:
09/21/12 10:28:02 (fd:11) (pid:5221) Type: 5 (collector), Name: (null), Addr: <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221) FullHost: (null), Host: (null), Pool: (null), Port: 9618
09/21/12 10:28:02 (fd:11) (pid:5221) IsLocal: N, IdStr: collector at <163.104.9.160:9618>, Error: can't find host info for <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221)  --- End of Daemon object info ---
09/21/12 10:28:02 (fd:11) (pid:5221)   Sorting 5 ads ...
09/21/12 10:28:02 (fd:11) (pid:5221)   Getting startd private ads ...
09/21/12 10:28:02 (fd:11) (pid:5221) Trying to query collector <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221) TIMEOUT_MULTIPLIER is undefined, using default value of 0
09/21/12 10:28:02 (fd:11) (pid:5221) NEGOTIATOR_TIMEOUT_MULTIPLIER is undefined, using default value of 0
09/21/12 10:28:02 (fd:11) (pid:5221) *** TIMEOUT_MULTIPLIER :: 0
09/21/12 10:28:02 (fd:11) (pid:5221) validate <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221) success
09/21/12 10:28:02 (fd:11) (pid:5221) New Daemon obj (collector) name: "NULL", pool: "NULL", addr: "<163.104.9.160:9618>"
09/21/12 10:28:02 (fd:11) (pid:5221) validate <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221) success
09/21/12 10:28:02 (fd:11) (pid:5221) validate <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221) success
09/21/12 10:28:02 (fd:11) (pid:5221) Already have address, no info to locate
09/21/12 10:28:02 (fd:11) (pid:5221) Address "<163.104.9.160:9618>" specified but no name, looking up host info
09/21/12 10:28:02 (fd:11) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:11) (pid:5221) IPVERIFY: checking grovsl82 against 163.104.9.160
09/21/12 10:28:02 (fd:11) (pid:5221) IPVERIFY: matched 163.104.9.160 to 163.104.9.160
09/21/12 10:28:02 (fd:11) (pid:5221) IPVERIFY: ip found is 1
09/21/12 10:28:02 (fd:11) (pid:5221) get_full_hostname() failed for address 163.104.9.16009/21/12 10:28:02 (fd:11) (pid:5221) Querying collector <163.104.9.160:9618> ((null)) with classad:
TargetType = "Machine"
CurrentTime = time()
MyType = "Query"
Requirements = true
09/21/12 10:28:02 (fd:11) (pid:5221)  --- End of Query ClassAd ---
09/21/12 10:28:02 (fd:11) (pid:5221) Guess address string for host = <163.104.9.160:9618>, port = 0
09/21/12 10:28:02 (fd:11) (pid:5221) it was sinful string. ip = 163.104.9.160, port = 9618
09/21/12 10:28:02 (fd:11) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:11) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:12) (pid:5221) OUT_LOWPORT is undefined, using default value of 0
09/21/12 10:28:02 (fd:12) (pid:5221) LOWPORT is undefined, using default value of 0
09/21/12 10:28:02 (fd:12) (pid:5221) ENABLE_IPV6 is undefined, using default value of False
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8500 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) CONNECT bound to <163.104.9.160:44486> fd=11 peer=<163.104.9.160:9618>
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: command 10 QUERY_STARTD_PVT_ADS to collector at <163.104.9.160:9618> from TCP port 44486 (blocking).
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: using session grovsl82:5216:1348215398:1 for {<163.104.9.160:9618>,<10>}.
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: found cached session id grovsl82:5216:1348215398:1 for {<163.104.9.160:9618>,<10>}.
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "grovsl82:5216:1348215398:1"
CryptoMethods = "3DES,BLOWFISH"
UseSession = "YES"
AuthMethodsList = "FS,KERBEROS,GSI"
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 = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.8.3 Sep 04 2012 BuildID: 62667 $"
Authentication = "NO"
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: Security Policy:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "grovsl82:5216:1348215398:1"
CryptoMethods = "3DES,BLOWFISH"
UseSession = "YES"
AuthMethodsList = "FS,KERBEROS,GSI"
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 = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.8.3 Sep 04 2012 BuildID: 62667 $"
Authentication = "NO"
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: negotiating security for command 10.
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: sending DC_AUTHENTICATE command
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: sending following classad:
Enact = "YES"
Subsystem = "NEGOTIATOR"
Sid = "grovsl82:5216:1348215398:1"
CryptoMethods = "3DES,BLOWFISH"
UseSession = "YES"
AuthMethodsList = "FS,KERBEROS,GSI"
AuthMethods = "FS"
Encryption = "NO"
ServerCommandSock = "<163.104.9.160:45215>"
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 = "unauthenticated@unmapped"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 7.8.3 Sep 04 2012 BuildID: 62667 $"
Authentication = "NO"
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_write(fd=11 collector at <163.104.9.160:9618>,,size=627,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8180 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Getting authenticated user from cached session: unauthenticated@unmapped
09/21/12 10:28:02 (fd:12) (pid:5221) SECMAN: startCommand succeeded.
09/21/12 10:28:02 (fd:12) (pid:5221) Authorizing server 'unauthenticated@unmapped/163.104.9.160'.
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_write(fd=11 collector at <163.104.9.160:9618>,,size=87,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8530 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [send] in condor_rw.cpp:373 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [send] in condor_rw.cpp:375 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=5,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac8520 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 resetting
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(fd=11 collector at <163.104.9.160:9618>,,size=935,timeout=60,flags=0)
09/21/12 10:28:02 (fd:12) (pid:5221) selector 0x7fff40ac84f0 adding fd 11 (socket:[2649804494])
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): fd=11
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [select] in selector.cpp:319 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) condor_read(): select returned 1
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe start [recv] in condor_rw.cpp:156 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Entering thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) Leaving thread safe stop [recv] in condor_rw.cpp:158 unknown()
09/21/12 10:28:02 (fd:12) (pid:5221) CLOSE <163.104.9.160:44486> fd=11
09/21/12 10:28:02 (fd:11) (pid:5221) Destroying Daemon object:
09/21/12 10:28:02 (fd:11) (pid:5221) Type: 5 (collector), Name: (null), Addr: <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221) FullHost: (null), Host: (null), Pool: (null), Port: 9618
09/21/12 10:28:02 (fd:11) (pid:5221) IsLocal: N, IdStr: collector at <163.104.9.160:9618>, Error: can't find host info for <163.104.9.160:9618>
09/21/12 10:28:02 (fd:11) (pid:5221)  --- End of Daemon object info ---
09/21/12 10:28:02 (fd:11) (pid:5221) Got ads: 5 public and 2 private
09/21/12 10:28:02 (fd:11) (pid:5221) Public ads include 1 submitter, 2 startd
09/21/12 10:28:02 (fd:11) (pid:5221) Phase 2:  Performing accounting ...
09/21/12 10:28:02 (fd:11) (pid:5221) Entering compute_significant_attrs()
09/21/12 10:28:02 (fd:11) (pid:5221) Leaving compute_significant_attrs() - result=JobUniverse,LastCheckpointPlatform,NumCkpts,_condor_RequestCpus,_condor_RequestDisk,_condor_RequestMemory,RequestCpus,RequestDisk,RequestMemory,RemoteGroup,SubmitterGroup
09/21/12 10:28:03 (fd:11) (pid:5221) (ACCOUNTANT) Updating priorities - AgingFactor=   1.000 , TimePassed=20
09/21/12 10:28:03 (fd:11) (pid:5221) CustomerName=Customer.slimamar@grovsl82 , Old Priority=0.500 , New Priority=0.500 , ResourcesUsed=0 , WeightedResourcesUsed=0.000000
09/21/12 10:28:03 (fd:11) (pid:5221) RecentUsage=   0.000 (unweighted    0.000), UnchargedTime=   0.000 (unweighted 0), AccumulatedUsage=13536.000 (unweighted 2037.000), BeginUsageTime=1347975052
09/21/12 10:28:03 (fd:11) (pid:5221) CustomerName=Customer.slimamar@grovsl83 , Old Priority=0.817 , New Priority=0.817 , ResourcesUsed=0 , WeightedResourcesUsed=0.000000
09/21/12 10:28:03 (fd:11) (pid:5221) RecentUsage=   0.000 (unweighted    0.000), UnchargedTime=   0.000 (unweighted 0), AccumulatedUsage=124228.000 (unweighted 15743.000), BeginUsageTime=1347974891
09/21/12 10:28:03 (fd:11) (pid:5221) CustomerName=Customer.<none> , Old Priority=0.817 , New Priority=0.817 , ResourcesUsed=0 , WeightedResourcesUsed=0.000000
09/21/12 10:28:03 (fd:11) (pid:5221) RecentUsage=   0.000 (unweighted    0.000), UnchargedTime=   0.000 (unweighted 0), AccumulatedUsage=137764.000 (unweighted 17780.000), BeginUsageTime=1347974891
09/21/12 10:28:03 (fd:11) (pid:5221) (Accountant) Checking Matches
09/21/12 10:28:03 (fd:11) (pid:5221) Previous Limits --
09/21/12 10:28:03 (fd:11) (pid:5221) Current Limits --
09/21/12 10:28:03 (fd:11) (pid:5221) Phase 3:  Sorting submitter ads by priority ...
09/21/12 10:28:03 (fd:11) (pid:5221) Phase 4.1:  Negotiating with schedds ...
09/21/12 10:28:03 (fd:11) (pid:5221)     numSlots = 2
09/21/12 10:28:03 (fd:11) (pid:5221)     slotWeightTotal = 32.000000
09/21/12 10:28:03 (fd:11) (pid:5221)     pieLeft = 32.000
09/21/12 10:28:03 (fd:11) (pid:5221)     NormalFactor = 1.000000
09/21/12 10:28:03 (fd:11) (pid:5221)     MaxPrioValue = 0.817210
09/21/12 10:28:03 (fd:11) (pid:5221)     NumSubmitterAds = 1
09/21/12 10:28:03 (fd:11) (pid:5221)   Negotiating with slimamar@grovsl83 skipped because no idle jobs
09/21/12 10:28:03 (fd:11) (pid:5221)   Submitter slimamar@grovsl83 got all it wants; removing it.
09/21/12 10:28:03 (fd:11) (pid:5221)  resources used by slimamar@grovsl83 are 0.000000
09/21/12 10:28:03 (fd:11) (pid:5221)  resources used scheddUsed= 0.000000
09/21/12 10:28:03 (fd:11) (pid:5221)  negotiateWithGroup resources used scheddAds length 0 
09/21/12 10:28:03 (fd:11) (pid:5221) ---------- Finished Negotiation Cycle ----------
09/21/12 10:28:03 (fd:11) (pid:5221) Return from Timer handler 8 (Time to negotiate)
09/21/12 10:28:03 (fd:11) (pid:5221) DaemonCore Timeout() Complete, returning 5 
09/21/12 10:28:03 (fd:11) (pid:5221) selector 0x7fff40ac94b0 resetting
09/21/12 10:28:03 (fd:11) (pid:5221) selector 0x7fff40ac94b0 adding fd 9 (socket:[2649787938])
09/21/12 10:28:03 (fd:11) (pid:5221) selector 0x7fff40ac94b0 adding fd 10 (socket:[2649787939])
09/21/12 10:28:03 (fd:11) (pid:5221) selector 0x7fff40ac94b0 adding fd 5 (pipe:[2649787966])
09/21/12 10:28:03 (fd:11) (pid:5221) PERF: entering select
09/21/12 10:28:03 (fd:11) (pid:5221) Entering thread safe start [select] in selector.cpp:313 unknown()
09/21/12 10:28:03 (fd:11) (pid:5221) Leaving thread safe start [select] in selector.cpp:313 unknown()
