1. The code for setting and retrieving the cache is as follows:
const TAG_THEME_EDITOR = 'theme_editor'; // 缓存标签：主题编辑
const THEME_EDITOR_SESSION_PREFIX = 'theme_editor_session:'; // 缓存前缀：主题编辑会话
const TTL = 86400; // 缓存的过期时间(秒)
public static function saveSessionMetadata(string $sessionId, array $data): bool
{
return Cache::tags([
ThemePreviewInterface::TAG_THEME_EDITOR,
ThemePreviewInterface::TAG_THEME_EDITOR . '_' . $sessionId]
)
->put(ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX . $sessionId, json_encode($data), ThemePreviewInterface::TTL);
}
public static function getSessionMetadata(string $sessionId): array
{
$data = Cache::tags([
ThemePreviewInterface::TAG_THEME_EDITOR,
ThemePreviewInterface::TAG_THEME_EDITOR . '_' . $sessionId
])
->get(ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX . $sessionId);
if (empty($data)) {
return [];
}
return JsonDecoder::jsonToArray($data);
}
2. The cache expiration time (in seconds) is 86400, but in the production environment, there is a very low probability that it expires in less than 24 hours. In some cases, the cache cannot be retrieved after only a few hours. Printing $data returns a value of NULL.
3. I decided to rule out external factors first and start the analysis from the program itself. My initial suspicion was that an operation within the program cleared the cache.
4. The cache-related configuration in .env is as follows:
CACHE_DRIVER=redis
REDIS_CLIENT=phpredis
5. Printing the configuration items shows database.reids.client=phpredis; cache.default=redis. See Figure 1.
/object # php artisan tinker
Psy Shell v0.9.12 (PHP 7.4.26 — cli) by Justin Hileman
>>> echo config('database.redis.client');
>>> echo config('database.redis.client');
phpredis⏎
>>> echo config('cache.default');
redis⏎
>>>
6. The configuration in /config/cache.php is as follows:
'stores' => [
'redis' => [
'driver' => 'redis',
'connection' => 'cache',
],
],
7. The configuration in /config/database.php is as follows:
'redis' => [
'client' => env('REDIS_CLIENT', 'phpredis'),
'options' => [
'cluster' => env('REDIS_CLUSTER', 'predis'),
],
'cache' => [
'prefix' => env('REDIS_PREFIX', Str::slug(env('APP_NAME', 'laravel'), '_') . '_database_'),
'url' => env('REDIS_URL'),
'host' => env('REDIS_HOST', '127.0.0.1'),
'password' => env('REDIS_PASSWORD', null),
'port' => env('REDIS_PORT', 6379),
'database' => env('REDIS_CACHE_DB', 1),
'persistent'=>env('REDIS_PERSISTENT', true),
'persistent_id'=>env('REDIS_PERSISTENT_ID', 'cache'),
'retry_interval'=>env('REDIS_PERSISTENT_RETRY', 3000),
],
],
8. In the aliases section of the /config/app.php configuration file, the Illuminate \ Support \ Facades \ Redis facade alias was not renamed. However, no exception was thrown: Please remove or rename the Redis facade alias in your “app” configuration file in order to avoid collision with the PHP Redis extension. I decided to temporarily ignore this issue.
'aliases' => [
'Redis' => Illuminate\Support\Facades\Redis::class,
],
9. I still decided to rename it to something else, such as RedisManager, to avoid conflicts with the Redis class.
'aliases' => [
'RedisManager' => Illuminate\Support\Facades\Redis::class,
],
10. I decided to log into Redis to verify, first checking the sequence of executed commands in the local environment. See Figure 2.
127.0.0.1:1>GET object_cache:tag:theme_editor_48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb:key
"s:22:"631ae7ba62b83808649247";"
127.0.0.1:1>SMEMBERS object_cache:631ae7ba62b83808649247:standard_ref
1) "object_cache:c613daaf6b394e496382fd07bc808ea8a497556f:theme_editor_session:9734e008-f539-4f76-9e9f-d8037334b968:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb:product_detail"
2) "object_cache:c613daaf6b394e496382fd07bc808ea8a497556f:theme_editor_session:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb"
127.0.0.1:1>GET object_cache:c613daaf6b394e496382fd07bc808ea8a497556f:theme_editor_session:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb
"s:9329:"{"id":372}";"
127.0.0.1:1>
11. I decided to log into Redis to verify based on the Tinker query. Following the command sequence above, I confirmed whether the corresponding keys existed in the local environment. See Figure 3.
PS E:\wwwroot\object> php artisan tinker
Psy Shell v0.9.12 (PHP 7.4.27 — cli) by Justin Hileman
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->get('object_cache:tag:theme_
editor_48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb:key'));
string(30) "s:22:"631ae7ba62b83808649247";"
=> null
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->SMEMBERS('object_cache:631ae
7ba62b83808649247:standard_ref'));
array(2) {
[0]=>
string(186) "object_cache:c613daaf6b394e496382fd07bc808ea8a497556f:theme_editor_session:9734e008-f539-4f76-9e9f-d8037334b968:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb:product_detail"
[1]=>
string(134) "object_cache:c613daaf6b394e496382fd07bc808ea8a497556f:theme_editor_session:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb"
}
=> null
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->GET('object_cache:c613daaf6b
394e496382fd07bc808ea8a497556f:theme_editor_session:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb'));
string(9339) "s:9329:"{"id":372}";"
=> null
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->TTL('object_cache:c613daaf6b
394e496382fd07bc808ea8a497556f:theme_editor_session:48wJgWKHnabdr3AznlDhP5onmEVedTz67ULb'));
int(81060)
=> null
>>>
12. The TTL command returns the remaining time to live (TTL) of a given key in seconds. One key was generated at 2022/09/09 15:14. The current time is 2022/09/09 16:44. 1 hour and 30 minutes have passed. 86400 – 1 * 3600 – 30 * 60 = 81000. The remaining time to live in seconds is: int(81060). This matches expectations. See Figure 4.
13. I decided to regenerate one in the production environment and then check the remaining time to live in seconds. The remaining time to live in seconds for a newly generated key is: int(85730). This matches expectations. See Figure 5.
14. I decided to log into Redis to verify based on the Tinker query. Following the command sequence above, I confirmed whether the corresponding keys existed in the production environment. I confirmed that the corresponding keys had not been completely cleared. If Cache::tags(ThemePreviewInterface::TAG_THEME_EDITOR . ‘_’ . $sessionId)->flush() or Cache::flush() had been executed, running the query var_dump(\Illuminate\Support\Facades\Redis::connection(‘cache’)->get(‘arrest9_cache:tag:theme_editor_Uq6BLXO7GsbWHQovCXQAshX8SdaS6BXh2lWE:key’)); would return null, but right now it has a value. See Figure 6 and Figure 6.1.
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->get('arrest9_cache:tag:theme_editor_Uq6BLXO7GsbWHQovCXQAshX8SdaS6BXh2lWE:key'));
string(30) "s:22:"63243db5c01db958165221";
=> null
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->TTL('arrest9_cache:tag:theme_editor_Uq6BLXO7GsbWHQovCXQAshX8SdaS6BXh2lWE:key'));
int(-1)
=> null
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->SMEMBERS('arrest9_cache:63243db5c01db958165221:standard_ref'));
array(0) {
}
=> null
>>>
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->get('object_cache:tag:theme_
editor_ERo5GoALUnDuxcMtW3yPYPKsjwci8DVZR2ij:key'));
NULL
=> null
>>> var_dump(\Illuminate\Support\Facades\Redis::connection('cache')->SMEMBERS('object_cache:632a7
fda56e94065934346:standard_ref'));
array(0) {
}
=> null
>>>
15. I decided to add appropriate logs based on event listeners. I created a listener file /app/Listeners/Cache/LogKeyWrittenListener.php for when a key is written.
key, ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX) !== false) {
Log::debug('theme_editor_session_key_written', [
'key' => $event->key,
'tags' => $event->tags,
'value' => $event->value,
'seconds' => $event->seconds
]);
}
}
}
16. The generated log information is as follows. See Figure 7.
[2022-09-15 17:26:05] local.DEBUG: theme_editor_session_key_written {
"key": "theme_editor_session:7JivgR1WqXVeE4hsyA335ILc60k153yTynIN",
"tags": [
"theme_editor",
"theme_editor_7JivgR1WqXVeE4hsyA335ILc60k153yTynIN"
],
"value": "",
"seconds": 86400
}
17. I created a listener file /app/Listeners/Cache/LogCacheHitListener.php for when a key is hit.
/**
* 处理事件
*
* @param CacheHit $event
* @return void
*/
public function handle(CacheHit $event)
{
if (config('app.debug') === true && strpos($event->key, ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX) !== false) {
Log::debug('theme_editor_session_cache_hit', [
'key' => $event->key,
'tags' => $event->tags,
'value' => $event->value
]);
}
}
[2022-09-15 18:09:08] local.DEBUG: theme_editor_session_cache_hit {
"key": "theme_editor_session:KrV0Nf5rMOiS5ZdF6i2uDandZZZWPPpXcQ4D",
"tags": [
"theme_editor",
"theme_editor_KrV0Nf5rMOiS5ZdF6i2uDandZZZWPPpXcQ4D"
],
"value": ""
}
18. I created a listener file /app/Listeners/Cache/LogCacheMissedListener.php for when a key is missed.
/**
* 处理事件
*
* @param CacheMissed $event
* @return void
*/
public function handle(CacheMissed $event)
{
if (config('app.debug') === true && strpos($event->key, ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX) !== false) {
Log::debug('theme_editor_session_cache_missed', [
'key' => $event->key,
'tags' => $event->tags
]);
}
}
[2022-09-15 18:10:15] local.DEBUG: theme_editor_session_cache_missed {
"key": "theme_editor_session:KrV0Nf5rMOiS5ZdF6i2uDandZZZWPPpXcQ4D",
"tags": [
"theme_editor",
"theme_editor_KrV0Nf5rMOiS5ZdF6i2uDandZZZWPPpXcQ4D"
]
}
19. However, when removing tagged cache data using Cache::tags(ThemePreviewInterface::TAG_THEME_EDITOR . ‘_’ . $sessionId)->flush();, the listener /app/Listeners/Cache/LogKeyForgottenListener.php did not generate a log when the key was cleared.
/**
* 处理事件
*
* @param KeyForgotten $event
* @return void
*/
public function handle(KeyForgotten $event)
{
if (config('app.debug') === true && strpos($event->key, ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX) !== false) {
Log::debug('theme_editor_session_key_forgotten', [
'key' => $event->key,
'tags' => $event->tags
]);
}
}
20. I decided to use the flush method to clear all caches, Cache::flush();. This confirmed whether the key clearing event would be triggered, and it was not. However, after executing the operation to clear all caches, the tagged cache data could no longer be retrieved. All cache data was cleared, whether tagged or not. See Figure 8.
21. So even with 4 cache log listeners, it is still difficult to determine when a key is cleared. I could only log the relevant information in the places where it was expected to be cleared first.
22. Regarding step 16, I decided to consult the operations colleagues. Sometimes they run a Python script to manually clean up dead keys in Redis. Therefore, I decided to simulate and reproduce the same Python script in the local environment. Executed: python batch-remove-rediskey.py /tmp. It did not reproduce locally, but after analyzing the script, it might reproduce in the production environment. However, the operations team confirmed that they had not manually run this script during the recent period when the issue occurred. See Figure 9.
PS E:\wwwroot\object> python batch-remove-rediskey.py /tmp
/tmp*
All done
23. Because 2 tags were set, the number of keys under one of the tags would continuously increase, potentially reaching thousands or even tens of thousands within a week. I finally decided to set only 1 tag. The code for setting and retrieving the cache is as follows:
const TAG_THEME_EDITOR = 'theme_editor'; // 缓存标签：主题编辑
const THEME_EDITOR_SESSION_PREFIX = 'theme_editor_session:'; // 缓存前缀：主题编辑会话
const TTL = 86400; // 缓存的过期时间(秒)
public static function saveSessionMetadata(string $sessionId, array $data): bool
{
return Cache::tags([
ThemePreviewInterface::TAG_THEME_EDITOR . '_' . $sessionId]
)
->put(ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX . $sessionId, json_encode($data), ThemePreviewInterface::TTL);
}
public static function getSessionMetadata(string $sessionId): array
{
$data = Cache::tags([
ThemePreviewInterface::TAG_THEME_EDITOR . '_' . $sessionId
])
->get(ThemePreviewInterface::THEME_EDITOR_SESSION_PREFIX . $sessionId);
if (empty($data)) {
return [];
}
return JsonDecoder::jsonToArray($data);
}
24. After setting only 1 tag, with the number of keys under this tag generally maintained at around 20, the cache no longer experienced missed hits, and the overall operation returned to normal. The preliminary analysis concludes that when using Cache::tags, the number of tags should not be too large, and it is recommended to set only 1. Specifically, the number of keys under each tag should also not be too large, and it is recommended not to exceed 100.