Mailing List Archives

Authenticated access

 		[Computer Systems Lab]

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

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

I can no longer reproduce the error.  All I can think of is some race condition where the factory/condor werenât reconfigured/restarted correctly?  Iâve definitely restarted both several times now.  But hereâs a little more context to what Marco reported:

We had no issues with the install on sl6.  We reinstalled the machine as sl7 and used the same condor and glideinwms versions.  We did not change any configurations of the factory or condor during the installation.  I canât guarantee someone made some changes out of band for other things on the sl6 install but the condor configs and gwms configs are completely managed by puppet so you canât adjust settings outside of puppet.  

The ERROR msgs I saw showed up when running the command as root or in the logs, for example:
02/24/19 08:47:20 [86680] ERROR "Gahp Server (pid=86711) unresponsive for 120 seconds" at line 525 in file /slots/16/dir_3109781/userdir/.tmpVhmMVH/BUILD/condor-8.6.11/src/condor_gridmanager/gahp-client.cpp

Iâm still getting the gahp error but the one from running condor_q -g as root no longer shows up.  I no longer have the logs from the sl6 install so I have no idea if these gahp errors were there before or only after we moved to sl7.


On Feb 25, 2019, at 8:59 PM, Todd Tannenbaum <tannenba@xxxxxxxxxxx> wrote:

Hi Marco,

I think Steve was on the right track.

My guess is Steve wanted you to try:

  "condor_q -global -all"

In other words, try using "-all" flag in addition to the "-global" flag.

The deal is beginning in HTCondor v8.6, each schedd will try to 
authenticate the user issuing the condor_q command and only return jobs 
submitted by that same user.  So if user "marco" issues the condor_q, 
only jobs submitted by marco will be returned by default. If you include 
"-all", that tells the schedd to return all jobs regardless of who 
submitted them (and who is asking).

You can change the default back to how it was in HTCondor v8.5 and 
earlier via the following condor_config knob to False:

CONDOR_Q_ONLY_MY_JOBS
    A boolean value that, when True, causes condor_q to request that 
only the current user's jobs be queried unless the current user is a 
queue superuser. It also causes the condor_schedd to honor that request. 
The default value is True. A value of False in either condor_q or the 
condor_schedd will result in the old behavior of querying all jobs.

regards,
Todd


On 2/24/2019 3:32 PM, Marco Mambelli wrote:
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://urldefense.proofpoint.com/v2/url?u=https-3A__lists.cs.wisc.edu_mailman_listinfo_htcondor-2Dusers&d=DwIGaQ&c=gRgGjJ3BkIsb5y6s49QqsA&r=mJexXERGCKhKDmLAi9CMy5Qiwxk7cUYXIkq26-Rs1Xc&m=QFouSebgOX7hNPaI2nmOAWys5N4zb6bz06tOeocXeR0&s=dJulsnmBzaEYEusHaJRODDceeGATphwFnAABKe9-qqI&e=

The archives can be found at:
https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.cs.wisc.edu_archive_htcondor-2Dusers_&d=DwIGaQ&c=gRgGjJ3BkIsb5y6s49QqsA&r=mJexXERGCKhKDmLAi9CMy5Qiwxk7cUYXIkq26-Rs1Xc&m=QFouSebgOX7hNPaI2nmOAWys5N4zb6bz06tOeocXeR0&s=3BRxeuq2TXZPdxODCB7vL1eRWSuo61b3xiVGJB-bFL8&e=
_______________________________________________
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=


_______________________________________________
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=DwIGaQ&c=gRgGjJ3BkIsb5y6s49QqsA&r=mJexXERGCKhKDmLAi9CMy5Qiwxk7cUYXIkq26-Rs1Xc&m=QFouSebgOX7hNPaI2nmOAWys5N4zb6bz06tOeocXeR0&s=dJulsnmBzaEYEusHaJRODDceeGATphwFnAABKe9-qqI&e=

The archives can be found at:
https://urldefense.proofpoint.com/v2/url?u=https-3A__lists.cs.wisc.edu_archive_htcondor-2Dusers_&d=DwIGaQ&c=gRgGjJ3BkIsb5y6s49QqsA&r=mJexXERGCKhKDmLAi9CMy5Qiwxk7cUYXIkq26-Rs1Xc&m=QFouSebgOX7hNPaI2nmOAWys5N4zb6bz06tOeocXeR0&s=3BRxeuq2TXZPdxODCB7vL1eRWSuo61b3xiVGJB-bFL8&e=



-- 
Todd Tannenbaum <tannenba@xxxxxxxxxxx> University of Wisconsin-Madison
Center for High Throughput Computing   Department of Computer Sciences
HTCondor Technical Lead                1210 W. Dayton St. Rm #4257
Phone: (608) 263-7132                  Madison, WI 53706-1685