Uploaded image for project: 'Artifactory Binary Repository'
  1. Artifactory Binary Repository
  2. RTFACT-7455

Unable to login with Crowd users

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Done
    • Resolution: Not a Bug
    • Affects Version/s: 3.3.0
    • Fix Version/s: None
    • Component/s: Crowd
    • Labels:
    • Severity:
      Medium

      Description

      I've integrated a fresh installation of Artifactory with a Crowd server but only internal users can access the application.

      Crowd users are redirected to the login page with any kind of message displayed.

      After changing the logging options to DEBUG I can see the following in the logs when a Crowd user is attempting to log in:

      artifactory.log
      2015-05-07 09:23:39,968 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.CrowdHttpAuthenticator:236) - Crowd token key: 'crowd.token_key', domain: '.domain.com', isSecure: 'true'
      2015-05-07 09:23:39,969 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users WHERE username = 'acerezo''.
      2015-05-07 09:23:39,971 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.84 millis : 'SELECT * FROM users WHERE username = 'acerezo''
      2015-05-07 09:23:39,971 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users_groups WHERE user_id = 2001'.
      2015-05-07 09:23:39,973 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.19 millis : 'SELECT * FROM users_groups WHERE user_id = 2001'
      2015-05-07 09:23:39,973 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM groups WHERE group_id = 28'.
      2015-05-07 09:23:39,975 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.25 millis : 'SELECT * FROM groups WHERE group_id = 28'
      2015-05-07 09:23:40,005 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.ArtifactoryCrowdClientImpl:263) - Loading Crowd groups
      2015-05-07 09:23:40,043 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM groups WHERE realm IS NOT NULL AND realm != 'artifactory''.
      2015-05-07 09:23:40,045 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.75 millis : 'SELECT * FROM groups WHERE realm IS NOT NULL AND realm != 'artifactory''
      2015-05-07 09:23:40,046 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.ArtifactoryCrowdClientImpl:265) - Finished Loading Crowd groups
      2015-05-07 09:23:40,046 [http-bio-8081-exec-10] [DEBUG] (o.a.s.RealmAwareAuthenticationManager:76) - Authentication 'org.springframework.security.authentication.UsernamePasswordAuthenticationToken@b00443c0: Principal: acerezo; Credentials: [PROTECTED]; Authenticated: false; Details: org.artifactory.UiAuthenticationDetails@b364: RemoteIpAddress: 10.159.53.97; SessionId: 3F779B0135DEE17BE3A8FBF9C8CAEB51; Not granted
      any authorities' has realm 'crowd'
      2015-05-07 09:23:40,046 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users WHERE username = 'acerezo''.
      2015-05-07 09:23:40,049 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 2.06 millis : 'SELECT * FROM users WHERE username = 'acerezo''
      2015-05-07 09:23:40,049 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users_groups WHERE user_id = 2001'.
      2015-05-07 09:23:40,051 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.19 millis : 'SELECT * FROM users_groups WHERE user_id = 2001'
      2015-05-07 09:23:40,051 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM groups WHERE group_id = 28'.
      2015-05-07 09:23:40,052 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.19 millis : 'SELECT * FROM groups WHERE group_id = 28'
      2015-05-07 09:23:40,055 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users WHERE username = 'acerezo''.
      2015-05-07 09:23:40,056 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.06 millis : 'SELECT * FROM users WHERE username = 'acerezo''
      2015-05-07 09:23:40,057 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users_groups WHERE user_id = 2001'.
      2015-05-07 09:23:40,058 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.23 millis : 'SELECT * FROM users_groups WHERE user_id = 2001'
      2015-05-07 09:23:40,059 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM groups WHERE group_id = 28'.
      2015-05-07 09:23:40,060 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.18 millis : 'SELECT * FROM groups WHERE group_id = 28'
      2015-05-07 09:23:40,071 [art-exec-4] [DEBUG] (o.a.s.f.l.a.LockingAdvice:40) - Creating locking advice interceptor
      2015-05-07 09:23:40,071 [art-exec-4] [DEBUG] (o.a.s.f.l.a.LockingAdvice:59) - Activating locking interceptor on public abstract void org.artifactory.api.security.SecurityService.updateUserLastLogin(java.lang.String,java.lang.String,long) with create tx true
      2015-05-07 09:23:40,072 [art-exec-4] [DEBUG] (o.a.s.f.l.a.LockingAdvice:63) - Tx init by: public abstract void org.artifactory.api.security.SecurityService.updateUserLastLogin(java.lang.String,java.lang.String,long)
      2015-05-07 09:23:40,072 [art-exec-4] [DEBUG] (o.a.s.f.l.a.LockingAdvice:93) - Locking interceptor has Tx advice org.springframework.transaction.interceptor.TransactionInterceptor@9e533f2
      2015-05-07 09:23:40,072 [art-exec-4] [DEBUG] (o.a.s.d.s.DbTransactionManager:367) - Creating new transaction with name [org.artifactory.security.SecurityServiceImpl.updateUserLastLogin]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
      2015-05-07 09:23:40,072 [art-exec-4] [DEBUG] (o.a.s.d.s.DbTransactionManager:206) - Acquired Connection [ProxyConnection[PooledConnection[org.postgresql.jdbc4.Jdbc4Connection@7b5f5e8]]] for JDBC transaction
      2015-05-07 09:23:40,072 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users WHERE username = 'acerezo''.
      2015-05-07 09:23:40,073 [art-exec-2] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT COUNT(*) FROM nodes WHERE node_type = 1'.
      2015-05-07 09:23:40,078 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 5.94 millis : 'SELECT * FROM users WHERE username = 'acerezo''
      2015-05-07 09:23:40,079 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users_groups WHERE user_id = 2001'.
      2015-05-07 09:23:40,081 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 2.17 millis : 'SELECT * FROM users_groups WHERE user_id = 2001'
      2015-05-07 09:23:40,082 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM groups WHERE group_id = 28'.
      2015-05-07 09:23:40,084 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 2.02 millis : 'SELECT * FROM groups WHERE group_id = 28'
      2015-05-07 09:23:40,084 [art-exec-4] [DEBUG] (o.a.s.f.l.a.LockingAdvice:59) - Activating locking interceptor on public abstract void org.artifactory.storage.security.service.UserGroupStoreService.updateUser(org.artifactory.security.MutableUserInfo) with create tx false
      2015-05-07 09:23:40,084 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users WHERE username = 'acerezo''.
      2015-05-07 09:23:40,085 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 456261 nanos : 'SELECT * FROM users WHERE username = 'acerezo''
      2015-05-07 09:23:40,085 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users_groups WHERE user_id = 2001'.
      2015-05-07 09:23:40,088 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 2.25 millis : 'SELECT * FROM users_groups WHERE user_id = 2001'
      2015-05-07 09:23:40,088 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM groups WHERE group_name = 'readers''.
      2015-05-07 09:23:40,089 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 450455 nanos : 'SELECT * FROM groups WHERE group_name = 'readers''
      2015-05-07 09:23:40,089 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'UPDATE users SET  password = NULL, salt = NULL, email = 'acerezo@domain.com', gen_password_key = NULL, admin = 1, enabled = 1, updatable_profile = 1, realm = 'crowd', private_key = NULL, public_key = NULL, last_login_time = 1431015820060, last_login_ip = '10.159.53.97', last_access_time = 0, last_access_ip = NULL, bintray_auth = NULL WHERE user_id = 2001 AND username = 'acerezo''.
      2015-05-07 09:23:40,092 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:135) - Query returned with 1 results in 2.69 millis : 'UPDATE users SET  password = NULL, salt = NULL, email = 'acerezo@domain.com', gen_password_key = NULL, admin = 1, enabled = 1, updatable_profile = 1, realm = 'crowd', private_key = NULL, public_key = NULL, last_login_time = 1431015820060, last_login_ip = '10.159.53.97', last_access_time = 0, last_access_ip = NULL, bintray_auth = NULL WHERE user_id = 2001 AND username = 'acerezo''
      2015-05-07 09:23:40,093 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'DELETE FROM users_groups WHERE user_id = 2001'.
      2015-05-07 09:23:40,105 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:135) - Query returned with 1 results in 11.51 millis : 'DELETE FROM users_groups WHERE user_id = 2001'
      2015-05-07 09:23:40,105 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'INSERT INTO users_groups VALUES (2001, 28, 'artifactory')'.
      2015-05-07 09:23:40,106 [art-exec-4] [DEBUG] (o.a.s.d.u.JdbcHelper:135) - Query returned with 1 results in 804936 nanos : 'INSERT INTO users_groups VALUES (2001, 28, 'artifactory')'
      2015-05-07 09:23:40,106 [art-exec-4] [DEBUG] (o.a.s.d.s.SessionSynchronization:73) - Saving session: org.artifactory.storage.db.fs.session.SqlStorageSession@7ddceba7 .
      2015-05-07 09:23:40,106 [art-exec-4] [DEBUG] (o.a.s.d.s.DbTransactionManager:755) - Initiating transaction commit
      2015-05-07 09:23:40,107 [art-exec-4] [DEBUG] (o.a.s.d.s.DbTransactionManager:266) - Committing JDBC transaction on Connection [ProxyConnection[PooledConnection[org.postgresql.jdbc4.Jdbc4Connection@7b5f5e8]]]
      2015-05-07 09:23:40,117 [http-bio-8081-exec-10] [DEBUG] (o.a.w.s.RepoFilter  :183) - Exiting request POST (10.159.53.97) /webapp/login.html0-2.IFormSubmitListener-loginBorder-loginBorder_body-loginForm
      2015-05-07 09:23:40,120 [art-exec-4] [DEBUG] (o.a.s.d.s.DbTransactionManager:324) - Releasing JDBC Connection [ProxyConnection[PooledConnection[org.postgresql.jdbc4.Jdbc4Connection@7b5f5e8]]] after transaction
      2015-05-07 09:23:40,140 [art-exec-2] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 67.26 millis : 'SELECT COUNT(*) FROM nodes WHERE node_type = 1'
      2015-05-07 09:23:40,608 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.a.h.ArtifactoryHttpSsoAuthenticationFilter:152) - Entering ArtifactorySsoAuthenticationFilter.getRemoteUserName
      2015-05-07 09:23:40,609 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.ArtifactoryCrowdClientImpl:141) - No valid Crowd SSO token, found: null
      2015-05-07 09:23:40,611 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.ArtifactoryCrowdClientImpl:141) - No valid Crowd SSO token, found: null
      2015-05-07 09:23:40,611 [http-bio-8081-exec-10] [DEBUG] (o.a.w.s.AccessFilter:297) - No filter or entry just chain
      2015-05-07 09:23:40,611 [http-bio-8081-exec-10] [DEBUG] (o.a.w.s.RepoFilter  :92) - Entering request GET (10.159.53.97) /webapp/home.html1.
      2015-05-07 09:23:40,613 [http-bio-8081-exec-10] [DEBUG] (o.a.w.s.RepoFilter  :183) - Exiting request GET (10.159.53.97) /webapp/home.html1
      2015-05-07 09:23:40,946 [http-bio-8081-exec-10] [DEBUG] (o.a.a.s.ArtifactoryCrowdClientImpl:141) - No valid Crowd SSO token, found: null
      2015-05-07 09:23:40,946 [http-bio-8081-exec-10] [DEBUG] (o.a.w.s.AccessFilter:297) - No filter or entry just chain
      2015-05-07 09:23:40,946 [http-bio-8081-exec-10] [DEBUG] (o.a.w.s.RepoFilter  :92) - Entering request GET (10.159.53.97) /webapp/login.html.
      2015-05-07 09:23:40,952 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users WHERE username = 'admin''.
      2015-05-07 09:23:40,956 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 3.75 millis : 'SELECT * FROM users WHERE username = 'admin''
      2015-05-07 09:23:40,956 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:224) - Executing SQL: 'SELECT * FROM users_groups WHERE user_id = 26'.
      2015-05-07 09:23:40,958 [http-bio-8081-exec-10] [DEBUG] (o.a.s.d.u.JdbcHelper:98) - Query returned in 1.4 millis : 'SELECT * FROM users_groups WHERE user_id = 26'
      
      access.log
      2015-05-07 09:23:40,053 [ACCEPTED LOGIN]  for acerezo/10.159.53.97.

        Attachments

          Activity

              People

              Assignee:
              Unassigned
              Reporter:
              acerezo Antonio Cerezo Iglesias (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved:

                  Sync Status

                  Connection: RTFACT Sync
                  RTMID-7455 -
                  SYNCHRONIZED
                  • Last Sync Date: