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

Re: [HTCondor-users] schedds not returning the jobs correctly



Thanks Steve,
I think authentication is OK. Krista can chime in if she changed anything.
It is on the same host and using FS authentication and gives AUTHORIZED.

condor_q -all works OK.
$ condor_q -all

-- Schedd: myhost.fnal.gov : <131.225.X.X:9615?... @ 02/24/19 10:07:49
OWNER       BATCH_NAME                 SUBMITTED   DONE   RUN    IDLE  TOTAL JOB_IDS
cmstier0_1  CMD: glidein_startup.sh   2/15 10:31     24    123    169    316 166.9 ... 28956.0
cmsglobal_1 CMD: glidein_startup.sh   2/16 07:08    634    250    651   1535 2485.1 ... 28954.0
cmsglobal_2 CMD: glidein_startup.sh   2/21 08:19    664    582    254   1510 19267.0 ... 28927.9
cmstier0_2  CMD: glidein_startup.sh   2/23 00:44     26    287    119    432 24518.0 ... 28812.5

2445 jobs; 0 completed, 10 removed, 1193 idle, 1242 running, 0 held, 0 suspended


$ _CONDOR_TOOL_DEBUG="D_FULLDEBUG  D_SECURITY" condor_q -debug -g 2> /tmp/cq_dbg.txt
$ cat /tmp/cq_dbg.txt
02/24/19 15:30:12 KEYCACHE: created: 0x1249a40
02/24/19 15:30:12 Result of reading /etc/issue:  \S

02/24/19 15:30:12 Result of reading /etc/redhat-release:  Scientific Linux release 7.5 (Nitrogen)

02/24/19 15:30:12 Using IDs: 16 processors, 8 CPUs, 8 HTs
02/24/19 15:30:12 Reading condor configuration from '/etc/condor/condor_config'
02/24/19 15:30:12 Enumerating interfaces: lo 127.0.0.1 up
02/24/19 15:30:12 Enumerating interfaces: eth2 131.225.205.7 up
02/24/19 15:30:12 WARNING: Config source is empty: /etc/condor/config.d/90_condor_test
02/24/19 15:30:12 Will use TCP to update collector cmsgwms-factory.fnal.gov <131.225.205.7:9618>
02/24/19 15:30:12 Trying to query collector <131.225.205.7:9618>
02/24/19 15:30:12 SECMAN: command 6 QUERY_SCHEDD_ADS to collector at <131.225.205.7:9618> from TCP port 24674 (blocking).
02/24/19 15:30:12 SECMAN: no cached key for {<131.225.205.7:9618>,<6>}.
02/24/19 15:30:12 SECMAN: Security Policy:
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: negotiating security for command 6.
02/24/19 15:30:12 SECMAN: sending DC_AUTHENTICATE command
02/24/19 15:30:12 SECMAN: sending following classad:
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
Command = 6
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: server responded with:
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,GSI"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "NO"
SessionDuration = "60"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
Enact = "YES"
02/24/19 15:30:12 SECMAN: received post-auth classad:
User = "unauthenticated@unmapped"
Sid = "cmsgwms-factory:41971:1551043812:91585"
ValidCommands = "60007,457,60020,68,5,6,7,9,12,43,20,46,78,50,56,62,65,48,71,74"
ReturnCode = "AUTHORIZED"
02/24/19 15:30:12 SECMAN: policy to be cached:
User = "unauthenticated@unmapped"
ValidCommands = "60007,457,60020,68,5,6,7,9,12,43,20,46,78,50,56,62,65,48,71,74"
Sid = "cmsgwms-factory:41971:1551043812:91585"
MyRemoteUserName = "unauthenticated@unmapped"
UseSession = "YES"
AuthMethodsList = "FS,GSI"
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "NO"
Encryption = "NO"
Integrity = "NO"
Subsystem = "TOOL"
Enact = "YES"
Command = 6
AuthMethods = "FS"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: added session cmsgwms-factory:41971:1551043812:91585 to cache for 60 seconds (3600s lease).
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<60007>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<457>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<60020>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<68>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<5>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<6>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<7>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<9>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<12>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<43>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<20>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<46>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<78>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<50>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<56>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<62>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<65>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<48>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<71>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9618>,<74>} mapped to session cmsgwms-factory:41971:1551043812:91585.
02/24/19 15:30:12 SECMAN: startCommand succeeded.
02/24/19 15:30:12 Authorizing server 'unauthenticated@unmapped/131.225.205.7'.
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission ALLOW
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission READ
02/24/19 15:30:12 ipverify: READ optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission WRITE
02/24/19 15:30:12 ipverify: WRITE optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission NEGOTIATOR
02/24/19 15:30:12 ipverify: NEGOTIATOR optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission ADMINISTRATOR
02/24/19 15:30:12 ipverify: ADMINISTRATOR optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission OWNER
02/24/19 15:30:12 ipverify: OWNER optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission CONFIG
02/24/19 15:30:12 ipverify: CONFIG optimized to deny everyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission DAEMON
02/24/19 15:30:12 ipverify: DAEMON optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission SOAP
02/24/19 15:30:12 ipverify: SOAP optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission DEFAULT
02/24/19 15:30:12 ipverify: DEFAULT optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission CLIENT
02/24/19 15:30:12 IPVERIFY: deny CLIENT: anonymous@* (from config value DENY_CLIENT)
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission ADVERTISE_STARTD
02/24/19 15:30:12 ipverify: ADVERTISE_STARTD optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission ADVERTISE_SCHEDD
02/24/19 15:30:12 ipverify: ADVERTISE_SCHEDD optimized to allow anyone
02/24/19 15:30:12 IPVERIFY: Subsystem TOOL
02/24/19 15:30:12 IPVERIFY: Permission ADVERTISE_MASTER
02/24/19 15:30:12 ipverify: ADVERTISE_MASTER optimized to allow anyone
02/24/19 15:30:12 Initialized the following authorization table:
02/24/19 15:30:12 Authorizations yet to be resolved:
02/24/19 15:30:12 deny CLIENT:  anonymous@*/*
02/24/19 15:30:12 IPVERIFY: checking cmsgwms-factory.fnal.gov against 131.225.205.7 addrs are:
	131.225.205.7
02/24/19 15:30:12 IPVERIFY: for cmsgwms-factory.fnal.gov matched 131.225.205.7 to 131.225.205.7
02/24/19 15:30:12 IPVERIFY: checking cmsgwms-factory against 131.225.205.7 addrs are:
	131.225.205.7
02/24/19 15:30:12 IPVERIFY: for cmsgwms-factory matched 131.225.205.7 to 131.225.205.7
02/24/19 15:30:12 IPVERIFY: unauthenticated@unmapped at <131.225.205.7:9618> not matched to deny list, so allowing.
02/24/19 15:30:12 Adding to resolved authorization table: unauthenticated@unmapped/131.225.205.7: CLIENT
02/24/19 15:30:12 SharedPortClient: sent connection request to schedd at <131.225.205.7:9615> for shared port id 41892_018c_9
02/24/19 15:30:12 SECMAN: command 519 QUERY_JOB_ADS_WITH_AUTH to schedd at <131.225.205.7:9615> from TCP port 26265 (blocking).
02/24/19 15:30:12 SECMAN: no cached key for {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<519>}.
02/24/19 15:30:12 SECMAN: Security Policy:
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: negotiating security for command 519.
02/24/19 15:30:12 SECMAN: sending DC_AUTHENTICATE command
02/24/19 15:30:12 SECMAN: sending following classad:
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
Command = 519
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: server responded with:
ServerTime = 1551043812
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,GSI"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "YES"
SessionDuration = "60"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
Enact = "YES"
02/24/19 15:30:12 SECMAN: new session, doing initial authentication.
02/24/19 15:30:12 SECMAN: authenticating RIGHT NOW.
02/24/19 15:30:12 SECMAN: AuthMethodsList: FS,GSI
02/24/19 15:30:12 SECMAN: Auth methods: FS,GSI
02/24/19 15:30:12 AUTHENTICATE: setting timeout for <131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9> to 20.
02/24/19 15:30:12 AUTHENTICATE: in authenticate( addr == '<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>', methods == 'FS,GSI')
02/24/19 15:30:12 AUTHENTICATE: can still try these methods: FS,GSI
02/24/19 15:30:12 HANDSHAKE: in handshake(my_methods = 'FS,GSI')
02/24/19 15:30:12 HANDSHAKE: handshake() - i am the client
02/24/19 15:30:12 HANDSHAKE: sending (methods == 36) to server
02/24/19 15:30:12 HANDSHAKE: server replied (method = 4)
02/24/19 15:30:12 AUTHENTICATE: will try to use 4 (FS)
02/24/19 15:30:12 AUTHENTICATE: do_authenticate is 1.
02/24/19 15:30:12 AUTHENTICATE_FS: used dir /tmp/FS_XXXs7Ztf1, status: 1
02/24/19 15:30:12 AUTHENTICATE: auth_status == 4 (FS)
02/24/19 15:30:12 Authentication was a Success.
02/24/19 15:30:12 ZKM: setting default map to (null)
02/24/19 15:30:12 ZKM: name to map is null, not mapping.
02/24/19 15:30:12 ZKM: post-map: current user is '(null)'
02/24/19 15:30:12 ZKM: post-map: current domain is '(null)'
02/24/19 15:30:12 ZKM: post-map: current FQU is '(null)'
02/24/19 15:30:12 AUTHENTICATE: Exchanging keys with remote side.
02/24/19 15:30:12 AUTHENTICATE: Result of end of authenticate is 1.
02/24/19 15:30:12 SECMAN: received post-auth classad:
ServerTime = 1551043812
User = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
Sid = "cmsgwms-factory:41984:1551043812:88392"
TriedAuthentication = true
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
ReturnCode = "AUTHORIZED"
02/24/19 15:30:12 SECMAN: policy to be cached:
TriedAuthentication = true
User = "unauthenticated@unmapped"
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
Sid = "cmsgwms-factory:41984:1551043812:88392"
MyRemoteUserName = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
UseSession = "YES"
AuthMethodsList = "FS,GSI"
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
CryptoMethods = "3DES"
OutgoingNegotiation = "PREFERRED"
Authentication = "YES"
Encryption = "NO"
Integrity = "NO"
Subsystem = "TOOL"
Enact = "YES"
Command = 519
AuthMethods = "FS"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: added session cmsgwms-factory:41984:1551043812:88392 to cache for 60 seconds (3600s lease).
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<60007>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<457>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<60020>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<443>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<441>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<6>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<12>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<515>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<516>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<519>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<1111>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_9>,<471>} mapped to session cmsgwms-factory:41984:1551043812:88392.
02/24/19 15:30:12 SECMAN: startCommand succeeded.
02/24/19 15:30:12 Authorizing server 'unauthenticated@unmapped/131.225.205.7'.
02/24/19 15:30:12 Sent classad to schedd
02/24/19 15:30:12 Got classad from schedd.
02/24/19 15:30:12 Ad was last one from schedd.
02/24/19 15:30:12 SharedPortClient: sent connection request to schedd at <131.225.205.7:9615> for shared port id 41892_018c_5
02/24/19 15:30:12 SECMAN: command 519 QUERY_JOB_ADS_WITH_AUTH to schedd at <131.225.205.7:9615> from TCP port 7176 (blocking).
02/24/19 15:30:12 SECMAN: no cached key for {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<519>}.
02/24/19 15:30:12 SECMAN: Security Policy:
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: negotiating security for command 519.
02/24/19 15:30:12 SECMAN: sending DC_AUTHENTICATE command
02/24/19 15:30:12 SECMAN: sending following classad:
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
Command = 519
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: server responded with:
ServerTime = 1551043812
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,GSI"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "YES"
SessionDuration = "60"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
Enact = "YES"
02/24/19 15:30:12 SECMAN: new session, doing initial authentication.
02/24/19 15:30:12 SECMAN: authenticating RIGHT NOW.
02/24/19 15:30:12 SECMAN: AuthMethodsList: FS,GSI
02/24/19 15:30:12 SECMAN: Auth methods: FS,GSI
02/24/19 15:30:12 AUTHENTICATE: setting timeout for <131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5> to 20.
02/24/19 15:30:12 AUTHENTICATE: in authenticate( addr == '<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>', methods == 'FS,GSI')
02/24/19 15:30:12 AUTHENTICATE: can still try these methods: FS,GSI
02/24/19 15:30:12 HANDSHAKE: in handshake(my_methods = 'FS,GSI')
02/24/19 15:30:12 HANDSHAKE: handshake() - i am the client
02/24/19 15:30:12 HANDSHAKE: sending (methods == 36) to server
02/24/19 15:30:12 HANDSHAKE: server replied (method = 4)
02/24/19 15:30:12 AUTHENTICATE: will try to use 4 (FS)
02/24/19 15:30:12 AUTHENTICATE: do_authenticate is 1.
02/24/19 15:30:12 AUTHENTICATE_FS: used dir /tmp/FS_XXX9QjUHi, status: 1
02/24/19 15:30:12 AUTHENTICATE: auth_status == 4 (FS)
02/24/19 15:30:12 Authentication was a Success.
02/24/19 15:30:12 ZKM: setting default map to (null)
02/24/19 15:30:12 ZKM: name to map is null, not mapping.
02/24/19 15:30:12 ZKM: post-map: current user is '(null)'
02/24/19 15:30:12 ZKM: post-map: current domain is '(null)'
02/24/19 15:30:12 ZKM: post-map: current FQU is '(null)'
02/24/19 15:30:12 AUTHENTICATE: Exchanging keys with remote side.
02/24/19 15:30:12 AUTHENTICATE: Result of end of authenticate is 1.
02/24/19 15:30:12 SECMAN: received post-auth classad:
ServerTime = 1551043812
User = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
Sid = "cmsgwms-factory:41974:1551043812:88289"
TriedAuthentication = true
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
ReturnCode = "AUTHORIZED"
02/24/19 15:30:12 SECMAN: policy to be cached:
TriedAuthentication = true
User = "unauthenticated@unmapped"
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
Sid = "cmsgwms-factory:41974:1551043812:88289"
MyRemoteUserName = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
UseSession = "YES"
AuthMethodsList = "FS,GSI"
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
CryptoMethods = "3DES"
OutgoingNegotiation = "PREFERRED"
Authentication = "YES"
Encryption = "NO"
Integrity = "NO"
Subsystem = "TOOL"
Enact = "YES"
Command = 519
AuthMethods = "FS"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: added session cmsgwms-factory:41974:1551043812:88289 to cache for 60 seconds (3600s lease).
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<60007>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<457>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<60020>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<443>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<441>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<6>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<12>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<515>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<516>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<519>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<1111>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_5>,<471>} mapped to session cmsgwms-factory:41974:1551043812:88289.
02/24/19 15:30:12 SECMAN: startCommand succeeded.
02/24/19 15:30:12 Authorizing server 'unauthenticated@unmapped/131.225.205.7'.
02/24/19 15:30:12 Sent classad to schedd
02/24/19 15:30:12 Got classad from schedd.
02/24/19 15:30:12 Ad was last one from schedd.
02/24/19 15:30:12 SharedPortClient: sent connection request to schedd at <131.225.205.7:9615> for shared port id 41892_018c_6
02/24/19 15:30:12 SECMAN: command 519 QUERY_JOB_ADS_WITH_AUTH to schedd at <131.225.205.7:9615> from TCP port 14362 (blocking).
02/24/19 15:30:12 SECMAN: no cached key for {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<519>}.
02/24/19 15:30:12 SECMAN: Security Policy:
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: negotiating security for command 519.
02/24/19 15:30:12 SECMAN: sending DC_AUTHENTICATE command
02/24/19 15:30:12 SECMAN: sending following classad:
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
Command = 519
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: server responded with:
ServerTime = 1551043812
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,GSI"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "YES"
SessionDuration = "60"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
Enact = "YES"
02/24/19 15:30:12 SECMAN: new session, doing initial authentication.
02/24/19 15:30:12 SECMAN: authenticating RIGHT NOW.
02/24/19 15:30:12 SECMAN: AuthMethodsList: FS,GSI
02/24/19 15:30:12 SECMAN: Auth methods: FS,GSI
02/24/19 15:30:12 AUTHENTICATE: setting timeout for <131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6> to 20.
02/24/19 15:30:12 AUTHENTICATE: in authenticate( addr == '<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>', methods == 'FS,GSI')
02/24/19 15:30:12 AUTHENTICATE: can still try these methods: FS,GSI
02/24/19 15:30:12 HANDSHAKE: in handshake(my_methods = 'FS,GSI')
02/24/19 15:30:12 HANDSHAKE: handshake() - i am the client
02/24/19 15:30:12 HANDSHAKE: sending (methods == 36) to server
02/24/19 15:30:12 HANDSHAKE: server replied (method = 4)
02/24/19 15:30:12 AUTHENTICATE: will try to use 4 (FS)
02/24/19 15:30:12 AUTHENTICATE: do_authenticate is 1.
02/24/19 15:30:12 AUTHENTICATE_FS: used dir /tmp/FS_XXXTD8lYO, status: 1
02/24/19 15:30:12 AUTHENTICATE: auth_status == 4 (FS)
02/24/19 15:30:12 Authentication was a Success.
02/24/19 15:30:12 ZKM: setting default map to (null)
02/24/19 15:30:12 ZKM: name to map is null, not mapping.
02/24/19 15:30:12 ZKM: post-map: current user is '(null)'
02/24/19 15:30:12 ZKM: post-map: current domain is '(null)'
02/24/19 15:30:12 ZKM: post-map: current FQU is '(null)'
02/24/19 15:30:12 AUTHENTICATE: Exchanging keys with remote side.
02/24/19 15:30:12 AUTHENTICATE: Result of end of authenticate is 1.
02/24/19 15:30:12 SECMAN: received post-auth classad:
ServerTime = 1551043812
User = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
Sid = "cmsgwms-factory:41975:1551043812:87485"
TriedAuthentication = true
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
ReturnCode = "AUTHORIZED"
02/24/19 15:30:12 SECMAN: policy to be cached:
TriedAuthentication = true
User = "unauthenticated@unmapped"
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
Sid = "cmsgwms-factory:41975:1551043812:87485"
MyRemoteUserName = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
UseSession = "YES"
AuthMethodsList = "FS,GSI"
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
CryptoMethods = "3DES"
OutgoingNegotiation = "PREFERRED"
Authentication = "YES"
Encryption = "NO"
Integrity = "NO"
Subsystem = "TOOL"
Enact = "YES"
Command = 519
AuthMethods = "FS"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: added session cmsgwms-factory:41975:1551043812:87485 to cache for 60 seconds (3600s lease).
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<60007>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<457>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<60020>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<443>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<441>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<6>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<12>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<515>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<516>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<519>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<1111>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_6>,<471>} mapped to session cmsgwms-factory:41975:1551043812:87485.
02/24/19 15:30:12 SECMAN: startCommand succeeded.
02/24/19 15:30:12 Authorizing server 'unauthenticated@unmapped/131.225.205.7'.
02/24/19 15:30:12 Sent classad to schedd
02/24/19 15:30:12 Got classad from schedd.
02/24/19 15:30:12 Ad was last one from schedd.
02/24/19 15:30:12 SharedPortClient: sent connection request to schedd at <131.225.205.7:9615> for shared port id 41892_018c_7
02/24/19 15:30:12 SECMAN: command 519 QUERY_JOB_ADS_WITH_AUTH to schedd at <131.225.205.7:9615> from TCP port 9505 (blocking).
02/24/19 15:30:12 SECMAN: no cached key for {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<519>}.
02/24/19 15:30:12 SECMAN: Security Policy:
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: negotiating security for command 519.
02/24/19 15:30:12 SECMAN: sending DC_AUTHENTICATE command
02/24/19 15:30:12 SECMAN: sending following classad:
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
Command = 519
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: server responded with:
ServerTime = 1551043812
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,GSI"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "YES"
SessionDuration = "60"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
Enact = "YES"
02/24/19 15:30:12 SECMAN: new session, doing initial authentication.
02/24/19 15:30:12 SECMAN: authenticating RIGHT NOW.
02/24/19 15:30:12 SECMAN: AuthMethodsList: FS,GSI
02/24/19 15:30:12 SECMAN: Auth methods: FS,GSI
02/24/19 15:30:12 AUTHENTICATE: setting timeout for <131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7> to 20.
02/24/19 15:30:12 AUTHENTICATE: in authenticate( addr == '<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>', methods == 'FS,GSI')
02/24/19 15:30:12 AUTHENTICATE: can still try these methods: FS,GSI
02/24/19 15:30:12 HANDSHAKE: in handshake(my_methods = 'FS,GSI')
02/24/19 15:30:12 HANDSHAKE: handshake() - i am the client
02/24/19 15:30:12 HANDSHAKE: sending (methods == 36) to server
02/24/19 15:30:12 HANDSHAKE: server replied (method = 4)
02/24/19 15:30:12 AUTHENTICATE: will try to use 4 (FS)
02/24/19 15:30:12 AUTHENTICATE: do_authenticate is 1.
02/24/19 15:30:12 AUTHENTICATE_FS: used dir /tmp/FS_XXXaYEzdk, status: 1
02/24/19 15:30:12 AUTHENTICATE: auth_status == 4 (FS)
02/24/19 15:30:12 Authentication was a Success.
02/24/19 15:30:12 ZKM: setting default map to (null)
02/24/19 15:30:12 ZKM: name to map is null, not mapping.
02/24/19 15:30:12 ZKM: post-map: current user is '(null)'
02/24/19 15:30:12 ZKM: post-map: current domain is '(null)'
02/24/19 15:30:12 ZKM: post-map: current FQU is '(null)'
02/24/19 15:30:12 AUTHENTICATE: Exchanging keys with remote side.
02/24/19 15:30:12 AUTHENTICATE: Result of end of authenticate is 1.
02/24/19 15:30:12 SECMAN: received post-auth classad:
ServerTime = 1551043812
User = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
Sid = "cmsgwms-factory:41978:1551043812:79289"
TriedAuthentication = true
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
ReturnCode = "AUTHORIZED"
02/24/19 15:30:12 SECMAN: policy to be cached:
TriedAuthentication = true
User = "unauthenticated@unmapped"
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
Sid = "cmsgwms-factory:41978:1551043812:79289"
MyRemoteUserName = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
UseSession = "YES"
AuthMethodsList = "FS,GSI"
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
CryptoMethods = "3DES"
OutgoingNegotiation = "PREFERRED"
Authentication = "YES"
Encryption = "NO"
Integrity = "NO"
Subsystem = "TOOL"
Enact = "YES"
Command = 519
AuthMethods = "FS"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: added session cmsgwms-factory:41978:1551043812:79289 to cache for 60 seconds (3600s lease).
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<60007>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<457>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<60020>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<443>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<441>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<6>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<12>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<515>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<516>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<519>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<1111>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_7>,<471>} mapped to session cmsgwms-factory:41978:1551043812:79289.
02/24/19 15:30:12 SECMAN: startCommand succeeded.
02/24/19 15:30:12 Authorizing server 'unauthenticated@unmapped/131.225.205.7'.
02/24/19 15:30:12 Sent classad to schedd
02/24/19 15:30:12 Got classad from schedd.
02/24/19 15:30:12 Ad was last one from schedd.
02/24/19 15:30:12 SharedPortClient: sent connection request to schedd at <131.225.205.7:9615> for shared port id 41892_018c_8
02/24/19 15:30:12 SECMAN: command 519 QUERY_JOB_ADS_WITH_AUTH to schedd at <131.225.205.7:9615> from TCP port 13724 (blocking).
02/24/19 15:30:12 SECMAN: no cached key for {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<519>}.
02/24/19 15:30:12 SECMAN: Security Policy:
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: negotiating security for command 519.
02/24/19 15:30:12 SECMAN: sending DC_AUTHENTICATE command
02/24/19 15:30:12 SECMAN: sending following classad:
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
NewSession = "YES"
CryptoMethods = "3DES,BLOWFISH"
OutgoingNegotiation = "PREFERRED"
Authentication = "OPTIONAL"
Encryption = "OPTIONAL"
ServerPid = 491937
Integrity = "OPTIONAL"
Subsystem = "TOOL"
Enact = "NO"
Command = 519
AuthMethods = "FS,GSI"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: server responded with:
ServerTime = 1551043812
Encryption = "NO"
Integrity = "NO"
AuthMethodsList = "FS,GSI"
AuthMethods = "FS"
CryptoMethods = "3DES,BLOWFISH"
Authentication = "YES"
SessionDuration = "60"
SessionLease = 3600
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
Enact = "YES"
02/24/19 15:30:12 SECMAN: new session, doing initial authentication.
02/24/19 15:30:12 SECMAN: authenticating RIGHT NOW.
02/24/19 15:30:12 SECMAN: AuthMethodsList: FS,GSI
02/24/19 15:30:12 SECMAN: Auth methods: FS,GSI
02/24/19 15:30:12 AUTHENTICATE: setting timeout for <131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8> to 20.
02/24/19 15:30:12 AUTHENTICATE: in authenticate( addr == '<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>', methods == 'FS,GSI')
02/24/19 15:30:12 AUTHENTICATE: can still try these methods: FS,GSI
02/24/19 15:30:12 HANDSHAKE: in handshake(my_methods = 'FS,GSI')
02/24/19 15:30:12 HANDSHAKE: handshake() - i am the client
02/24/19 15:30:12 HANDSHAKE: sending (methods == 36) to server
02/24/19 15:30:12 HANDSHAKE: server replied (method = 4)
02/24/19 15:30:12 AUTHENTICATE: will try to use 4 (FS)
02/24/19 15:30:12 AUTHENTICATE: do_authenticate is 1.
02/24/19 15:30:12 AUTHENTICATE_FS: used dir /tmp/FS_XXXaLAjeM, status: 1
02/24/19 15:30:12 AUTHENTICATE: auth_status == 4 (FS)
02/24/19 15:30:12 Authentication was a Success.
02/24/19 15:30:12 ZKM: setting default map to (null)
02/24/19 15:30:12 ZKM: name to map is null, not mapping.
02/24/19 15:30:12 ZKM: post-map: current user is '(null)'
02/24/19 15:30:12 ZKM: post-map: current domain is '(null)'
02/24/19 15:30:12 ZKM: post-map: current FQU is '(null)'
02/24/19 15:30:12 AUTHENTICATE: Exchanging keys with remote side.
02/24/19 15:30:12 AUTHENTICATE: Result of end of authenticate is 1.
02/24/19 15:30:12 SECMAN: received post-auth classad:
ServerTime = 1551043812
User = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
Sid = "cmsgwms-factory:41980:1551043812:92791"
TriedAuthentication = true
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
ReturnCode = "AUTHORIZED"
02/24/19 15:30:12 SECMAN: policy to be cached:
TriedAuthentication = true
User = "unauthenticated@unmapped"
ValidCommands = "60007,457,60020,443,441,6,12,515,516,519,1111,471"
Sid = "cmsgwms-factory:41980:1551043812:92791"
MyRemoteUserName = "cmsgwmsfactory@xxxxxxxxxxxxxxxxxxxxxxxx"
UseSession = "YES"
AuthMethodsList = "FS,GSI"
RemoteVersion = "$CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $"
SessionLease = 3600
CryptoMethods = "3DES"
OutgoingNegotiation = "PREFERRED"
Authentication = "YES"
Encryption = "NO"
Integrity = "NO"
Subsystem = "TOOL"
Enact = "YES"
Command = 519
AuthMethods = "FS"
SessionDuration = "60"
02/24/19 15:30:12 SECMAN: added session cmsgwms-factory:41980:1551043812:92791 to cache for 60 seconds (3600s lease).
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<60007>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:12 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<457>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<60020>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<443>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<441>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<6>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<12>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<515>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<516>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<519>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<1111>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: command {<131.225.205.7:9615?addrs=131.225.205.7-9615&noUDP&sock=41892_018c_8>,<471>} mapped to session cmsgwms-factory:41980:1551043812:92791.
02/24/19 15:30:13 SECMAN: startCommand succeeded.
02/24/19 15:30:13 Authorizing server 'unauthenticated@unmapped/131.225.205.7'.
02/24/19 15:30:13 Sent classad to schedd
02/24/19 15:30:13 Got classad from schedd.
02/24/19 15:30:13 Ad was last one from schedd.
02/24/19 15:30:13 KEYCACHEENTRY: deleted: 0x12df310
02/24/19 15:30:13 KEYCACHEENTRY: deleted: 0x1266070
02/24/19 15:30:13 KEYCACHEENTRY: deleted: 0x12dce30
02/24/19 15:30:13 KEYCACHEENTRY: deleted: 0x12e0040
02/24/19 15:30:13 KEYCACHEENTRY: deleted: 0x12dce70
02/24/19 15:30:13 KEYCACHEENTRY: deleted: 0x12baab0
02/24/19 15:30:13 KEYCACHE: deleted: 0x1249a40

Thanks,
Marco





> On Feb 22, 2019, at 5:47 PM, Steven C Timm <timm@xxxxxxxx> wrote:
> 
> Is your Authentication ok.?
> 
> Also what happens when you do condor_q -all?
> 
> 
> Strve 
> From: HTCondor-users <htcondor-users-bounces@xxxxxxxxxxx> on behalf of Marco Mambelli <marcom@xxxxxxxx>
> Sent: Friday, February 22, 2019 11:46:27 AM
> To: HTCondor-Users Mail List
> Cc: Krista Majewski
> Subject: [HTCondor-users] schedds not returning the jobs correctly
>  
> The schedds on a GlideinWMS factory seem not to work correctly:
> - there are jobs running and queued and they are visible via condor_status -schedd
> - condor_q -g returns nothing, not even "All queues are empty"
> 
> 
> $ condor_q -g -xml
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> 
> $ condor_q -g
> 
> $ condor_status -schedd
> Name                                      Machine                  RunningJobs   IdleJobs   HeldJobs
> 
> cmsgwms-factory.fnal.gov                  cmsgwms-factory.fnal.gov        1174       1001          0
> schedd_glideins2@myhost                  myhost        1635        831         22
> schedd_glideins3@myhost                 myhost         285        812         22
> schedd_glideins4@myhost                 myhost        1794        997          1
> schedd_glideins5@myhost                 myhost        2007       1074          8
> 
>                       TotalRunningJobs      TotalIdleJobs      TotalHeldJobs
> 
> 
>                Total              6895               4715                 53
> 
> 
> [I replaced the hostname w/ "myhost" here, it was correct]
> $ condor_q -version
> $CondorVersion: 8.6.11 May 10 2018 BuildID: 440910 $
> $CondorPlatform: x86_64_RedHat7 $
> 
> The schedd logs are all unusually flat, a bunch of "Number of Active Workers 0" lines (rarely w/ N<>0) and with a strange line
> "Can't find address for startd myhost"  
> There is no startd on the factory host, it is not in the daemon list
> 
> 02/22/19 11:20:18 (pid:41978) Number of Active Workers 0
> 02/22/19 11:20:19 (pid:41978) Number of Active Workers 0
> 02/22/19 11:20:19 (pid:41978) TransferQueueManager stats: active up=0/100 down=0/100; waiting up=0 down=0; wait time up=0s down=0s
> 02/22/19 11:20:19 (pid:41978) TransferQueueManager upload 1m I/O load: 0 bytes/s  0.000 disk load  0.000 net load
> 02/22/19 11:20:19 (pid:41978) TransferQueueManager download 1m I/O load: 0 bytes/s  0.000 disk load  0.000 net load
> 02/22/19 11:20:19 (pid:41978) Started condor_gmanager for owner cmsglobal_1 pid=1423401
> 02/22/19 11:20:19 (pid:41978) Can't find address for startd myhost
> 02/22/19 11:20:20 (pid:41978) Number of Active Workers 0
> 
> 
> Something is wrong but I cannot understand what.
> 
> condor_config_val seems to return the correct spool and address files, also querying directly w/ -address
> d_fulldebug is not much of help:
> 
>  _CONDOR_TOOL_DEBUG="D_FULLDEBUG" condor_q -debug -g
> 02/22/19 11:39:51 Result of reading /etc/issue:  \S
> 
> 02/22/19 11:39:51 Result of reading /etc/redhat-release:  Scientific Linux release 7.5 (Nitrogen)
> 
> 02/22/19 11:39:51 Using IDs: 16 processors, 8 CPUs, 8 HTs
> 02/22/19 11:39:51 Reading condor configuration from '/etc/condor/condor_config'
> 02/22/19 11:39:51 Enumerating interfaces: lo 127.0.0.1 up
> 02/22/19 11:39:51 Enumerating interfaces: eth2 131.225.X.X up
> 02/22/19 11:39:51 WARNING: Config source is empty: /etc/condor/config.d/90_condor_test
> 02/22/19 11:39:51 Will use TCP to update collector cmsgwms-factory.fnal.gov <131.225.X.X:9618>
> 02/22/19 11:39:51 Trying to query collector <131.225.X.X:9618>
> 02/22/19 11:39:51 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_9
> 02/22/19 11:39:51 Sent classad to schedd
> 02/22/19 11:39:51 Got classad from schedd.
> 02/22/19 11:39:51 Ad was last one from schedd.
> 02/22/19 11:39:51 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_5
> 02/22/19 11:39:51 Sent classad to schedd
> 02/22/19 11:39:51 Got classad from schedd.
> 02/22/19 11:39:51 Ad was last one from schedd.
> 02/22/19 11:39:51 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_6
> 02/22/19 11:39:51 Sent classad to schedd
> 02/22/19 11:39:51 Got classad from schedd.
> 02/22/19 11:39:51 Ad was last one from schedd.
> 02/22/19 11:39:51 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_7
> 02/22/19 11:39:51 Sent classad to schedd
> 02/22/19 11:39:52 Got classad from schedd.
> 02/22/19 11:39:52 Ad was last one from schedd.
> 02/22/19 11:39:52 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_8
> 02/22/19 11:39:52 Sent classad to schedd
> 02/22/19 11:39:52 Got classad from schedd.
> 02/22/19 11:39:52 Ad was last one from schedd.
> 
> $ _CONDOR_TOOL_DEBUG="D_FULLDEBUG" condor_q -debug -g -xml
> 02/22/19 11:42:45 Result of reading /etc/issue:  \S
> 
> 02/22/19 11:42:45 Result of reading /etc/redhat-release:  Scientific Linux release 7.5 (Nitrogen)
> 
> 02/22/19 11:42:45 Using IDs: 16 processors, 8 CPUs, 8 HTs
> 02/22/19 11:42:45 Reading condor configuration from '/etc/condor/condor_config'
> 02/22/19 11:42:45 Enumerating interfaces: lo 127.0.0.1 up
> 02/22/19 11:42:45 Enumerating interfaces: eth2 131.225.X.X up
> 02/22/19 11:42:45 WARNING: Config source is empty: /etc/condor/config.d/90_condor_test
> 02/22/19 11:42:45 Will use TCP to update collector cmsgwms-factory.fnal.gov <131.225.X.X:9618>
> 02/22/19 11:42:45 Trying to query collector <131.225.X.X:9618>
> 02/22/19 11:42:45 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_9
> 02/22/19 11:42:45 Sent classad to schedd
> 02/22/19 11:42:45 Got classad from schedd.
> 02/22/19 11:42:45 Ad was last one from schedd.
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> 02/22/19 11:42:45 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_5
> 02/22/19 11:42:45 Sent classad to schedd
> 02/22/19 11:42:45 Got classad from schedd.
> 02/22/19 11:42:45 Ad was last one from schedd.
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> 02/22/19 11:42:45 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_6
> 02/22/19 11:42:45 Sent classad to schedd
> 02/22/19 11:42:45 Got classad from schedd.
> 02/22/19 11:42:45 Ad was last one from schedd.
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> 02/22/19 11:42:45 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_7
> 02/22/19 11:42:45 Sent classad to schedd
> 02/22/19 11:42:45 Got classad from schedd.
> 02/22/19 11:42:45 Ad was last one from schedd.
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> 02/22/19 11:42:45 SharedPortClient: sent connection request to schedd at <131.225.X.X:9615> for shared port id 41892_018c_8
> 02/22/19 11:42:45 Sent classad to schedd
> 02/22/19 11:42:45 Got classad from schedd.
> 02/22/19 11:42:45 Ad was last one from schedd.
> <?xml version="1.0"?>
> <!DOCTYPE classads SYSTEM "classads.dtd">
> <classads>
> </classads>
> 
> Krista saw also:
> ERROR "Assertion ERROR on (!(pjr->flags & 0x0004))" at line 4319 in file /slots/16/dir_3109781/userdir/.tmpVhmMVH/BUILD/condor-8.6.11/src/condor_q.V6/queue.cpp
> 
> 
> Any suggestion about what is wrong?
> Thanks you,
> Marco
> 
> 
> _______________________________________________
> HTCondor-users mailing list
> To unsubscribe, send a message to htcondor-users-request@xxxxxxxxxxx with a
> subject: Unsubscribe
> You can also unsubscribe by visiting
> https://lists.cs.wisc.edu/mailman/listinfo/htcondor-users
> 
> The archives can be found at:
> https://lists.cs.wisc.edu/archive/htcondor-users/
> _______________________________________________
> HTCondor-users mailing list
> To unsubscribe, send a message to htcondor-users-request@xxxxxxxxxxx with a
> subject: Unsubscribe
> You can also unsubscribe by visiting
> https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.cs.wisc.edu_mailman_listinfo_htcondor-2Dusers&d=DwICAg&c=gRgGjJ3BkIsb5y6s49QqsA&r=EF06-Wh4L9CNLgD8bnIjNQ&m=LLThFt5zVyRgnhEaJy3f7kZm9aANkYCB_IFrjHcDH8M&s=SHBxZ6Otmr1TbH79ipsQlHeM8f3D5jdq65sIxK2LUqQ&e=
> 
> The archives can be found at:
> https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.cs.wisc.edu_archive_htcondor-2Dusers_&d=DwICAg&c=gRgGjJ3BkIsb5y6s49QqsA&r=EF06-Wh4L9CNLgD8bnIjNQ&m=LLThFt5zVyRgnhEaJy3f7kZm9aANkYCB_IFrjHcDH8M&s=6xHhbsVm0AcQ8XCXn308bDdJ557B0YM6W1GwsDYUr0w&e=