-
Type:
Bug
-
Status: Done
-
Priority:
2 - Critical
-
Resolution: Done
-
Affects Version/s: 6.5.9, 6.11.3
-
Component/s: Access Tokens, High Availability
-
Labels:
-
Severity:Critical
Symptoms: An Access export times out when called by Artifactory. The logs indicate the "exporting tokens" is the cause of the delay, not users, groups, or permissions.
This is a problem because long-running Artifactory HA clusters can have tens of thousands of tokens generated by the system. In one Artifactory cluster, the "access_tokens" table was observed to have 200,000 tokens, with 200 generated every day.
Artifactory can fail to start if an Access Export times out.
The workaround if Artifactory fails to start is to keep the .deleteForSecurityMarker file in the $ART_HOME/data or $CLUSTER_HOME/ha-data folder.
Steps to reproduce:
1.Deploy this debug logger to the $ART_HOME/etc/logback.xml:
<logger name="org.artifactory.addon.ha">
<level value="debug" />
</logger>
2. Create a repository on a secondary HA node, or make any other config descriptor change
3. Observe that at least 2 new Access tokens are created in the database, and are never cleaned up:
MySQL [artdb]> select count
from access_tokens;
----------
| count |
----------
| 46 |
----------
1 row in set (0.01 sec)
[...]
MySQL [artdb]> select count from access_tokens;
----------
| count |
----------
| 50 |
----------
------------------------------------------------------------------------------------++++----------------------------------------------------------------------------------------------------------------------------------------------------
| token_id | subject | owner | created | expiry | refresh_token | scope |
------------------------------------------------------------------------------------++++----------------------------------------------------------------------------------------------------------------------------------------------------
[...]
| RESTRICTED_TOKEN1 | jfrt@01dhagrfexsvww1f5nn8xv1zyz/nodes/primary | jfrt@01dhagrfexsvww1f5nn8xv1zyz | 1564795101416 | 0 | NULL | NULL |
| RESTRICTED_TOKEN2 | jfrt@01dhagrfexsvww1f5nn8xv1zyz/nodes/secondary | jfrt@01dhagrfexsvww1f5nn8xv1zyz | 1564795042467 | 0 | NULL | NULL |
Debug logs:
2019-08-03 01:28:45,426 [http-nio-8081-exec-6] [INFO ] (o.a.u.r.s.a.c.r.CreateRepositoryConfigService:97) - Creating repository asdf5
2019-08-03 01:28:45,433 [http-nio-8081-exec-6] [INFO ] (o.a.c.CentralConfigServiceImpl:615) - Reloading configuration... old revision 17, new revision 18
2019-08-03 01:28:45,503 [http-nio-8081-exec-6] [INFO ] (o.a.c.CentralConfigServiceImpl:374) - New configuration with revision 18 saved.
2019-08-03 01:28:45,505 [http-nio-8081-exec-6] [INFO ] (o.a.s.ArtifactoryApplicationContext:515) - Artifactory application context set to NOT READY by reload
2019-08-03 01:28:45,578 [http-nio-8081-exec-6] [INFO ] (o.a.s.BaseTaskServiceDescriptorHandler:51) - No Replication configured. Replication is disabled.
2019-08-03 01:28:45,608 [http-nio-8081-exec-6] [DEBUG] (o.a.a.h.p.HaPropagationServiceImpl:553) - Created new token: Bearer
2019-08-03 01:28:45,625 [http-nio-8081-exec-6] [INFO ] (o.a.s.ArtifactoryApplicationContext:515) - Artifactory application context set to READY by reload
2019-08-03 01:28:45,626 [http-nio-8081-exec-6] [INFO ] (o.a.c.CentralConfigServiceImpl:633) - Configuration reloaded.
2019-08-03 01:28:45,629 [http-nio-8081-exec-6] [DEBUG] (o.a.a.h.p.HaPropagationServiceImpl:270) - Propagation started for [primary]
2019-08-03 01:28:45,630 [art-exec-171] [DEBUG] (o.a.a.h.p.HaPropagationServiceImpl:328) - Propagating 'central config change' to 'primary (http://172.20.9.4:8081/artifactory/api/ha/descriptor/change/)'
2019-08-03 01:28:45,630 [art-exec-171] [DEBUG] (o.a.a.h.p.HaPropagationServiceImpl:438) - Added token to header: X-Artifactory-HA-Security-Token
2019-08-03 01:28:45,676 [art-exec-171] [DEBUG] (o.a.a.h.p.HaPropagationServiceImpl:345) - Successfully propagate event 'central config change' to 'primary'