Hi, I am currently debugging a problem that the radosgw keystone token cache seems not to work properly. Or at all. I tried to debug it and attached the rgw_debug log set to 10. I've truncated to only show the part from "No stored secret string, cache miss" until the request is done.
The failed request hits a rate limit on the keystone which currently takes around 2k answered requests per minute. Any ideas what I did wrong? * All requests were done within 10 seconds and were only an ls to show buckets. * This particular RGW only took my requests during testing. * We didn't set any timeouts or special cache configs in ceph * system time is correct First request worked instantly: req 8122732607072897744 0.106001295s s3:list_buckets No stored secret string, cache miss [4.0K blob data] req 8122732607072897744 0.315003842s s3:list_buckets s3 keystone: validated token: 8144848695793469:user-9XGYcbFNUVTQ expires: 1762266594 req 8122732607072897744 0.315003842s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.uid+a13f0472be744104ad1f64bb2855cdee$a13f0472be744104ad1f64bb2855cdee : hit (negative entry) req 8122732607072897744 0.315003842s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.uid+a13f0472be744104ad1f64bb2855cdee : hit (requested=0x13, cached=0x13) req 8122732607072897744 0.315003842s s3:list_buckets normalizing buckets and tenants req 8122732607072897744 0.315003842s s->object=<NULL> s->bucket= req 8122732607072897744 0.315003842s s3:list_buckets init permissions req 8122732607072897744 0.315003842s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.uid+a13f0472be744104ad1f64bb2855cdee : hit (requested=0x13, cached=0x13) req 8122732607072897744 0.315003842s s3:list_buckets recalculating target req 8122732607072897744 0.315003842s s3:list_buckets reading permissions req 8122732607072897744 0.315003842s s3:list_buckets init op req 8122732607072897744 0.315003842s s3:list_buckets verifying op mask req 8122732607072897744 0.315003842s s3:list_buckets verifying op permissions req 8122732607072897744 0.315003842s s3:list_buckets verifying op params req 8122732607072897744 0.315003842s s3:list_buckets pre-executing req 8122732607072897744 0.315003842s s3:list_buckets check rate limiting req 8122732607072897744 0.315003842s s3:list_buckets executing req 8122732607072897744 0.315003842s s3:list_buckets completing req 8122732607072897744 0.315003842s cache get: name=eu-central-lz.rgw.log++script.postrequest. : hit (negative entry) req 8122732607072897744 0.315003842s s3:list_buckets op status=0 req 8122732607072897744 0.315003842s s3:list_buckets http status=200 ====== req done req=0x74659e51b6f0 op status=0 http_status=200 latency=0.315003842s ====== 2nd request failed req 10422983006485317789 0.061000749s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.keys+05917cf2ee9d4fdea8baf6a3348ca33a : hit (negative entry) req 10422983006485317789 0.061000749s s3:list_buckets error reading user info, uid=05917cf2ee9d4fdea8baf6a3348ca33a can't authenticate req 10422983006485317789 0.061000749s s3:list_buckets Failed the auth strategy, reason=-5 failed to authorize request WARNING: set_req_state_err err_no=5 resorting to 500 req 10422983006485317789 0.061000749s cache get: name=eu-central-lz.rgw.log++script.postrequest. : hit (negative entry) req 10422983006485317789 0.061000749s s3:list_buckets op status=0 req 10422983006485317789 0.061000749s s3:list_buckets http status=500 ====== req done req=0x74659e51b6f0 op status=0 http_status=500 latency=0.061000749s ====== 3rd requests went through again req 13123970335019889535 0.000000000s s3:list_buckets No stored secret string, cache miss [250B blob data] req 13123970335019889535 0.204002500s s3:list_buckets s3 keystone: validated token: 8144848695793469:user-9XGYcbFNUVTQ expires: 1762266602 req 13123970335019889535 0.204002500s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.uid+a13f0472be744104ad1f64bb2855cdee$a13f0472be744104ad1f64bb2855cdee : hit (negative entry) req 13123970335019889535 0.204002500s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.uid+a13f0472be744104ad1f64bb2855cdee : hit (requested=0x13, cached=0x13) req 13123970335019889535 0.204002500s s3:list_buckets normalizing buckets and tenants req 13123970335019889535 0.204002500s s->object=<NULL> s->bucket= req 13123970335019889535 0.204002500s s3:list_buckets init permissions req 13123970335019889535 0.204002500s s3:list_buckets cache get: name=eu-central-lz.rgw.meta+users.uid+a13f0472be744104ad1f64bb2855cdee : hit (requested=0x13, cached=0x13) req 13123970335019889535 0.204002500s s3:list_buckets recalculating target req 13123970335019889535 0.204002500s s3:list_buckets reading permissions req 13123970335019889535 0.204002500s s3:list_buckets init op req 13123970335019889535 0.204002500s s3:list_buckets verifying op mask req 13123970335019889535 0.204002500s s3:list_buckets verifying op permissions req 13123970335019889535 0.204002500s s3:list_buckets verifying op params req 13123970335019889535 0.204002500s s3:list_buckets pre-executing req 13123970335019889535 0.204002500s s3:list_buckets check rate limiting req 13123970335019889535 0.204002500s s3:list_buckets executing req 13123970335019889535 0.204002500s s3:list_buckets completing req 13123970335019889535 0.204002500s cache get: name=eu-central-lz.rgw.log++script.postrequest. : hit (negative entry) req 13123970335019889535 0.204002500s s3:list_buckets op status=0 req 13123970335019889535 0.204002500s s3:list_buckets http status=200 ====== req done req=0x74659e51b6f0 op status=0 http_status=200 latency=0.204002500s ====== -- Die Selbsthilfegruppe "UTF-8-Probleme" trifft sich diesmal abweichend im groüen Saal. _______________________________________________ ceph-users mailing list -- [email protected] To unsubscribe send an email to [email protected]
