swayok / alternative-laravel-cache

Replacements for Laravel's redis and file cache stores that properly implement tagging idea
MIT License
169 stars 26 forks source link

Laravel Telescope RedisWatcher not logging events when using this package with php-redis #30

Closed J5Dev closed 2 years ago

J5Dev commented 3 years ago

In short, when using this package with Redis, and the php-redis extension, the Laravel Telescope RedisWatcher will no longer register/log any events.

While this package itself works fine, it is of concern that this is happening, as the Telescope watcher only works by listening to Redis events being fire, so if it isn't logging anything, I am concerned it means the events aren't being fired.

Details:

PHP: v7.4 Laravel: v6.20.26 Telescope: v3.5.1

I have also tested this all the way up to Laravel 8 and Telescope 5, with the same outcome... when using this package in combination with the cache/redis-adapter), Redis events are no longer logged.

I haver done a good amount of digging around, but sadly not found the cause yet, so felt logging here might invoke the hive mind :)

swayok commented 3 years ago

@J5Dev, I was using Telescope for some time and it worked perfectly through predis library. But later I dropped Telescope and switched predis to php-redis extension. Maybe the reason is in php-redis. Can you switch to predis and test if Telescope works with it? Also if you haven't tried yet - test if Telescope works with Laravel's cache drivers. Let's eliminate some possibilities first before digging deeper.

J5Dev commented 3 years ago

Hi @swayok I have verified that the issue is not with php-redis, our app uses php-redis with a clustered Redis back-end.

Our app runs in its current form perfectly fine and all Telescopes features work without issue.

I have isolated it to these packages already, by doing the following:

From our fully working branch (master), I have included this repo, and added the required dependencies (ext-redis & cache/redis-adapter)... nothing else.

Once these are added, I restart our app Telescope no longer records any Redis events. If I undo the inclusion of these repos using composer, and restart my app, Telescope starts logging Redis events again.

Regarding what isn't running, I have so far narrowed it down to the following file/class within the Telescope package: Laravel\Telescope\Watchers\RedisWatcher

In this class there is the following function:

/**
     * Record a Redis command was executed.
     *
     * @param  \Illuminate\Redis\Events\CommandExecuted  $event
     * @return void
     */
    public function recordCommand(CommandExecuted $event)
    {
        if (! Telescope::isRecording() || $this->shouldIgnore($event)) {
            return;
        }

        Telescope::recordRedis(IncomingEntry::make([
            'connection' => $event->connectionName,
            'command' => $this->formatCommand($event->command, $event->parameters),
            'time' => number_format($event->time, 2),
        ]));
    }

When using this package, and its dependency of cache/redis-adapter, this function is never called (its originally registered to respond to the CommandExecuted event on line 19 of the same file, which comes from Illuminate\Redis\Events\CommandExecuted). However, when this package is not in use, this function fires.

Tested the function was being reached with some basic die dumping around the app... the one in here was never reached. So it seems that either the Event in question (CommandExecuted) is never fired, or the listener is not being registered... or of course something else lower down.

swayok commented 3 years ago

@J5Dev ok. I think I have a good idea where to start digging now.

swayok commented 3 years ago

@J5Dev I've found the issue and this one is quite a problem. In AlternativeRedisCacheStore->getConnection() method I return a low level \Redis client which is then passed to RedisCachePool in AlternativeRedisCacheStore->wrapConnection() mehod. Problem is that RedisCachePool expects exactly that client:

/**
 * @param \Redis|\RedisArray|\RedisCluster $cache
 */
public function __construct($cache)
{
    if (!$cache instanceof \Redis
        && !$cache instanceof \RedisArray
        && !$cache instanceof \RedisCluster
    ) {
        throw new CachePoolException(
            'Cache instance must be of type \Redis, \RedisArray, or \RedisCluster'
        );
    }

    $this->cache = $cache;
}

Unfortunately all events are fired by Laravel's PhpRedisConnection class. It seems like we need to make a wrapper over RedisCachePool to allow events to be fired. I already have some progress.

swayok commented 3 years ago

@J5Dev I've added wrappers for both php-redis and predis. Tests are working fine but there is one strange thing in Laravel's code in PhpRedisConnection:

public function lrem($key, $count, $value)
{
    return $this->command('lrem', [$key, $value, $count]);
}

As you can see - $count and $value arguments are messed up for some reason so I was forced to overwrite this method in order to make tests work. I don't like such surprises and it actually maybe not the only one.

Also I've got some strange behavior when I was running tests: some assertions were failing sometimes and after restart - it was ok again. Currently tests are not failing no matter how many times I run them. I don't know what was the reason of such behavior.

Events now should be called but it seems that my config does not provide events dispatcher so I cannot be sure it works.

I've pushed changes to redis-with-events branch for you to test in your project. Place debug breakpoint in \Illuminate\Redis\Connections->command() method to test if events are fired.

J5Dev commented 3 years ago

Thanks for the progress, will do some testing shortly and update here with my findings, thank you :)

swayok commented 2 years ago

Seems like it works fine. Closing.