Can’t release Redis Mutex Lock

[siggelfredo]

What steps will reproduce the problem?

We have an issue during our Deployments regarding the Azure Cache for Redis.
Within our Kubernetes Cluster we trigger a migration job which acquires a mutex lock and releases this lock after the job is finished.

This is the library we use to connect to redis: https://github.com/yiisoft/yii2-redis
And here is the function that should release the lock: https://github.com/yiisoft/yii2-redis/blob/master/src/Mutex.php#L131

It seems like some kind of timeout is happening and the job is stuck several minutes during releasing the lock.

What's expected?

Executed successfully

What do you get instead?

Here is an output log of our application:

🔒 Acquiring lock ... done

Checking for pending Craft and plugin migrations ...

No new migrations found. Your system is up to date.

Applying changes from your project config files ...

Finished applying changes

Checking for pending content migrations ...

No new migrations found. Your system is up-to-date.

Error: Failed to read from socket.

Redis command was: EVAL if redis.call("GET",KEYS[1])==ARGV[1] then

    return redis.call("DEL",KEYS[1])
else
    return 0
end 1 39e163799360c1e938270ea668ec756fef1cb xiRbWU3NHCxPN3ucss92

PHP Fatal error:  Uncaught yii\redis\SocketException: Failed to write to socket. 0 of 201 bytes written.

Redis command was: *5
$4
EVAL
$101
if redis.call("GET",KEYS[1])==ARGV[1] then
    return redis.call("DEL",KEYS[1])
else
    return 0
end
$1
1
$37
39e163799360c1e938270ea668ec756fef1cb
$20
xiRbWU3NHCxPN3ucss92
in /app/vendor/yiisoft/yii2-redis/src/Connection.php:827

Additional info

Q	A
Yii version	2.0.45
PHP version	8.0.19
Craft Version	Craft Pro 3.7.41
Operating system	Linux 5.4.0-1068-azure

When does the issue occur?

Everytime when we start a seperate migrate job in a k8 azure environment deployment.

apiVersion: batch/v1 kind: Job metadata: name: {{ include "craftcms.fullname" . }}-migrate-{{ .Values.image.tag | default .Chart.AppVersion }} labels: {{- include "craftcms.labelsJob" . | nindent 4 }} spec: template: spec: automountServiceAccountToken: false containers: - name: craftcms-migrate image: "{{ .Values.image.repository }}:{{ .Values.image.tag | default .Chart.AppVersion }}" securityContext: allowPrivilegeEscalation: false # www-data user runAsUser: 82 command: ['/bin/sh'] args: - -c - >- ./craft migrate/all --interactive=0 && ./craft project-config/apply --interactive=0 && ./craft clear-caches/cp-resources --interactive=0

What do you see?

The Job seems to run forever. 10 min and up and shows the following stack trace:

`kubectl logs -n craftcms jobs.batch/craftcms-migrate-e1e86842eba4a3bf6d0fb0523804045e9646249f
Found 2 pods, using pod/craftcms-migrate-e1e86842eba4a3bf6d0fb0523804045e9646249f-czbcq
🔒 Acquiring lock ... done

Checking for pending Craft and plugin migrations ...
No new migrations found. Your system is up to date.

Applying changes from your project config files ...

• updating entryTypes.ff2b1278-c26d-4225-a123-d80c2064b102.fieldLayouts.2d0fe877-06a2-4a62-85b2-2dfa274ebaa5.tabs.0.elements.1 ...
  • updating entryTypes.ff2b1278-c26d-4225-a123-d80c2064b102 ... done
    done
• updating entryTypes.ff2b1278-c26d-4225-a123-d80c2064b102.fieldLayouts.2d0fe877-06a2-4a62-85b2-2dfa274ebaa5.tabs.0.elements.2 ... done
• updating entryTypes.ff2b1278-c26d-4225-a123-d80c2064b102.fieldLayouts.2d0fe877-06a2-4a62-85b2-2dfa274ebaa5.tabs.0.elements.3 ... done
• updating users.groups.1fef851a-bd46-4777-ae00-dae7421c481d.permissions ...
  • updating users.groups.1fef851a-bd46-4777-ae00-dae7421c481d ... done
  • updating users.groups.ff6ebfca-f4b6-4d1b-aac9-82fac548bbe3 ... done
    done
• updating users.groups.ff6ebfca-f4b6-4d1b-aac9-82fac548bbe3.permissions ... done
• updating dateModified ... done
• adding globalSets.c3b071a0-1d9a-4445-bf53-0b51ccd28fdb.fieldLayouts.844e1376-e27d-4c9e-8931-7aa5160f2964.tabs.0.elements.0 ...
  • adding globalSets.c3b071a0-1d9a-4445-bf53-0b51ccd28fdb ... done
    done
• adding globalSets.c3b071a0-1d9a-4445-bf53-0b51ccd28fdb.fieldLayouts.844e1376-e27d-4c9e-8931-7aa5160f2964.tabs.0 ... done
• updating meta.names ... done
  Finished applying changes

Checking for pending content migrations ...
No new migrations found. Your system is up-to-date.

Error: Failed to read from socket.
Redis command was: EVAL if redis.call("GET",KEYS[1])==ARGV[1] then
return redis.call("DEL",KEYS[1])
else
return 0
end 1 39e163799360c1e938270ea668ec756fef1cb 3gUUw52QXxS0QE_4vri1
PHP Fatal error: Uncaught yii\redis\SocketException: Failed to write to socket. 0 of 201 bytes written.
Redis command was: *5
$4
EVAL
$101
if redis.call("GET",KEYS[1])==ARGV[1] then
return redis.call("DEL",KEYS[1])
else
return 0
end
$1
1
$37
39e163799360c1e938270ea668ec756fef1cb
$20
3gUUw52QXxS0QE_4vri1
in /app/vendor/yiisoft/yii2-redis/src/Connection.php:827
Stack trace:
#0 /app/vendor/yiisoft/yii2-redis/src/Connection.php(796): yii\redis\Connection->sendRawCommand('*5\r\n$4\r\nEVAL\r\n$...', Array)
#1 /app/vendor/yiisoft/yii2-redis/src/Mutex.php(146): yii\redis\Connection->executeCommand('EVAL', Array)
#2 /app/vendor/yiisoft/yii2/mutex/Mutex.php(88): yii\redis\Mutex->releaseLock('craft-up')
#3 /app/vendor/craftcms/cms/src/mutex/Mutex.php(75): yii\mutex\Mutex->release('craft-up')
#4 /app/vendor/yiisoft/yii2/mutex/Mutex.php(88): craft\mutex\Mutex->releaseLock('craft-up')
#5 /app/vendor/craftcms/cms/src/mutex/MutexTrait.php(82): yii\mutex\Mutex->release('craft-up')
#6 /app/vendor/yiisoft/yii2/mutex/Mutex.php(57): craft\mutex\Mutex->release('craft-up')
#7 [internal function]: yii\mutex\Mutex->yii\mutex{closure}()
#8 {main}
Additional Information:
Array
(
)

thrown in /app/vendor/yiisoft/yii2-redis/src/Connection.php on line 827`

What was the expected result?

The Job should display a finish state and release the log: 🔓 Releasing lock ... %

[yii-bot]

Thanks for posting in our issue tracker.
In order to properly assist you, we need additional information:

• When does the issue occur?
• What do you see?
• What was the expected result?
• Can you supply us with a stacktrace? (optional)
• Do you have exact code to reproduce it? Maybe a PHPUnit tests that fails? (optional)

Thanks!

This is an automated comment, triggered by adding the label status:need more info.

[siggelfredo]

@samdark Additional Infos provided. Please review. Thanks

[samdark]

Well, your redis instance doesn't answer timely. No idea why. Is there anything in its logs?

[siggelfredo]

I talked to the DevOps from the clients Azure infrastructure team. Unfortunately there’s no dedicated Redis log file available. Therefore I can’t provide you any specific redis errors.
What we have discovered so far is a relation between the ./craft up and the Redis mutex lock.
We changed the migration job and replaced ./craft up with


              ./craft migrate/all --interactive=0 &&
              ./craft project-config/apply --interactive=0

Afterwards we triggered the clear all caches command manually and that worked without any problem. 
It’s seems to be a craft internal problem and not a specific Redis issue.

[samdark]

Then please create an issue in Craft repository. I'll close this one.

Thanks for update.