microk8s icon indicating copy to clipboard operation
microk8s copied to clipboard

Frequent 'database is locked error' 500 on lease update

Open cs-dsmyth opened this issue 5 months ago • 16 comments

Summary

Seeing as below whereby a small number of lease updates in k8s results in a large number of duplicate update queries in k8s-dqlite.

This issue is observed in v1.32 and v1.33 microk8s, not seen in a previous version used v1.29 so suspect some change has introduced the behaviour.

Example below 1 lease update for kube-controller-manager

kubectl get leases --all-namespaces --watch | grep kube-controller-manager

2025-07-21 15:04:50.475  pods    kube-system       kube-controller-manager                                     dailybuild4-host1_53ce2bb9-14e4-46af-83c0-bde7007e05c3                      9h

Debug logging turned up in '/var/snap/microk8s/current/args/k8s-dqlite' this results in 327 of these update queries in one second. For some reason that same update is getting fired many times internally.

labuser@dailybuild4-host1:~$ sudo journalctl -u snap.microk8s.daemon-k8s-dqlite | grep '15:04:50' | grep kube-controller-manager | grep INSERT | wc -l 327

Jul 21 15:04:50 dailybuild4-host1 microk8s.daemon-k8s-dqlite[971627]: time="2025-07-21T15:04:50+01:00" level=debug msg="EXEC (try: 499) [/registry/leases/kube-system/kube-controller-manager 0 [107 56 115 0 10 31 10 22 99 111 111 114 100 105 110 97 116 105 111 110 46 107 56 115 46 105 111 47 118 49 18 5 76 101 97 115 101 18 253 2 10 160 2 10 23 107 117 98 101 45 99 111 110 116 114 111 108 108 101 114 45 109 97 110 97 103 101 114 18 0 26 11 107 117 98 101 45 115 121 115 116 101 109 34 0 42 36 100 99 52 101 100 101 101 98 45 51 97 99 51 45 52 98 55 101 45 98 102 49 54 45 101 102 55 51 97 97 51 98 55 52 51 50 50 0 56 0 66 8 8 245 138 247 195 6 16 0 138 1 190 1 10 8 107 117 98 101 108 105 116 101 18 6 85 112 100 97 116 101 26 22 99 111 111 114 100 105 110 97 116 105 111 110 46 107 56 115 46 105 111 47 118 49 34 8 8 129 146 249 195 6 16 0 50 8 70 105 101 108 100 115 86 49 58 124 10 122 123 34 102 58 115 112 101 99 34 58 123 34 102 58 97 99 113 117 105 114 101 84 105 109 101 34 58 123 125 44 34 102 58 104 111 108 100 101 114 73 100 101 110 116 105 116 121 34 58 123 125 44 34 102 58 108 101 97 115 101 68 117 114 97 116 105 111 110 83 101 99 111 110 100 115 34 58 123 125 44 34 102 58 108 101 97 115 101 84 114 97 110 115 105 116 105 111 110 115 34 58 123 125 44 34 102 58 114 101 110 101 119 84 105 109 101 34 58 123 125 125 125 66 0 18 88 10 54 100 97 105 108 121 98 117 105 108 100 52 45 104 111 115 116 49 95 53 51 99 101 50 98 98 57 45 49 52 101 52 45 52 54 97 102 45 56 51 99 48 45 98 100 101 55 48 48 55 101 48 53 99 51 16 60 26 12 8 188 198 248 195 6 16 248 236 250 173 3 34 12 8 129 146 249 195 6 16 128 173 136 153 3 40 6 26 0 34 0] /registry/leases/kube-system/kube-controller-manager 202186] :  INSERT INTO kine(name, created, deleted, create_revision, prev_revision, lease, value, old_value) SELECT ? AS name, 0 AS created, 0 AS deleted, CASE WHEN kine.created THEN id ELSE create_revision END AS create_revision, id AS prev_revision, ? AS lease, ? AS value, value AS old_value FROM kine WHERE id = (SELECT MAX(id) FROM kine WHERE name = ?) AND deleted = 0 AND id = ?"

The result is the following error in syslog, and the action fails.

Jul 21 15:04:50 dailybuild4-host1 microk8s.daemon-kubelite[283598]: E0721 15:04:50.129980  283598 status.go:71] "Unhandled Error" err="apiserver received an error that is not an metav1.Status: &status.Error{s:(*status.Status)(0xc01fcd4378)}: rpc error: code = Unknown desc = exec (try: 500): database is locked"
Jul 21 15:04:50 dailybuild4-host1 microk8s.daemon-kubelite[283598]: E0721 15:04:50.132155  283598 leaderelection.go:429] Failed to update lock optimistically: rpc error: code = Unknown desc = exec (try: 500): database is locked, falling back to slow path
Jul 21 15:04:50 dailybuild4-host1 microk8s.daemon-k8s-dqlite[971627]: time="2025-07-21T15:04:50+01:00" level=error msg="failed to update key" error="exec (try: 500): database is locked"
Jul 21 15:04:50 dailybuild4-host1 microk8s.daemon-k8s-dqlite[971627]: time="2025-07-21T15:04:50+01:00" level=debug msg="UPDATE /registry/leases/kube-system/kube-controller-manager, value=425, rev=202186, lease=0 => rev=0, updated=false, err=exec (try: 500): database is locked"
Jul 21 15:04:50 dailybuild4-host1 microk8s.daemon-k8s-dqlite[971627]: time="2025-07-21T15:04:50+01:00" level=error msg="error in txn: exec (try: 500): database is locked"

Seen on a single node microk8s and also 3 node cluster. Introducing disk i/o provokes the issue further, assuming due to queries taking longer to run and therefore more likely to hit a lock condition. Not particular to this one lease update event, happens for multiple different pods in the deployment. Function being called in k8s-dqlite looks to be 'updateSQL' in pkg/backend/sqlite/driver.go. Is there some situation in microk8s that this gets retried in quick succession or there is a very short timeout value for retry?

Happy to provide further logs if needed.

What Should Happen Instead?

No database is locked errors. This causes other k8s actions to fail.

Reproduction Steps

I can reproduce by introducing some disk load on the microk8s server eg by running

while true; do dd if=/dev/zero of=test1.img bs=40G count=1 oflag=dsync; done

cs-dsmyth avatar Jul 24 '25 16:07 cs-dsmyth

Attaching log file for example in report snap.microk8s.daemon-k8s-dqlite.log.tar.gz

Also attaching another instance where the lease renewals are counted alongside the number of INSERT actions towards DQLite as seen in microk8s.daemon-k8s-dqlite logs with debug enabled ( 229 lease updates result in 14,164 INSERTs) Example_insert_counts_vs_lease_updates.txt

cs-dsmyth avatar Jul 24 '25 16:07 cs-dsmyth

Hi @cs-dsmyth,

thank you for filing your issue and attaching the logs.

You are currently hitting a limitation of what your disk can handle. When introducing additional load on the disk of your microk8s cluster k8s-dqlite fails to make progress. Transactions, such as the lease update fail and are retried in quick succession (up to 500 times).

We've been working on addressing this issue. Retries are being moved to the database side (Dqlite) and we are reducing the number of transactions per second from Kubernetes (by using batching) which reduces the pressure on the disk.

In the meantime, while we are working on addressing this issue, you can use microk8s with an external etcd or try a candidate build (1.33-classic/candidate) of the k8s-snap with managed etcd.

Many thanks again for your feedback!

louiseschmidtgen avatar Jul 25 '25 07:07 louiseschmidtgen

Thanks for the info on this issue @louiseschmidtgen it's much appreciated. Good to know I'm not the only one seeing it :)

Is there another issue #ID that I can follow for the progress on addressing this as you mention it is a known problem.

Thanks, David

cs-dsmyth avatar Jul 25 '25 13:07 cs-dsmyth

Hi, I have been facing the same issue in all the environments from Proxmox where I have been testing MicroK8s. Clearly, the error is pointing to the workload consumed on the disk caused by the dqlite issue/bug. Also, I found that this could also be related to the type of storage used, where the Kubernetes servers are hosted. I tested the same on Ceph storage with around 12 OSDs per Proxmox node for the storage synchronization, and the error blows up too frequently in the /var/log/syslog. But if I use LINSTOR storage as a Ceph replacement, the error occasionally appears in the log file. It is a very big difference.

Could you please explain what the prerequisites would be to install a functional cluster using K8s instead of MicroK8s, in terms of the number of master nodes, CPU, RAM, and so on?

Is the K8s alternative already including etcd instead of dqlite, or what are the benefits to installing MicroK8s with an etcd cluster externally?

Any direction to this would be much appreciated.

Thanks a lot in advance!

nelsinchi avatar Jul 28 '25 20:07 nelsinchi

Hi @cs-dsmyth,

The issues have surfaced mostly internally, therefore I don't have another issue ID for you. You may keep this issue open until we've addressed it.

On a happy note, we now have a release from the Dqlite team and are working on bringing these changes into the next Microk8s release.

Best regards, Louise

louiseschmidtgen avatar Jul 29 '25 06:07 louiseschmidtgen

Hi @nelsinchi,

the issue boils down to the fact that you are not getting sufficient disk performance on your ceph with Dqlite set-up. The factors that apply here are too high disk latency and/or in a multi-node scenario you could see the same symptoms due to a slow network. Both don't allow Dqlite and therefore k8s to make progress at the necessary rate. We will be releasing fixes that will reduce the occurrence of this error significantly (unless your issue is due to a slow network).

You have a few options: wait on the fixes released with a newer Dqlite, use a disk with lower latency or consider the etcd alternative. The k8s-snap alternative (in candidate) has etcd backed into the snap whereas Microk8s only supports the external etcd set-up - meaning that it is managed by you. For resource requirements with etcd please consult their upstream docs. The high availability requirements are the same across Dqlite and etcd as both build on the raft consensus algorithm. We recommend using three control plane nodes allowing for the fault tolerance of one node.

I hope this helps you in making a better choice to fit your needs.

Best regards, Louise

louiseschmidtgen avatar Jul 29 '25 08:07 louiseschmidtgen

Thank you very much, everyone, for your hard work in addressing this issue. We hope to have a permanent fix in the next MicroK8s release version :wink:.

nelsinchi avatar Jul 29 '25 14:07 nelsinchi

thanks - seeing this also vmware VMs on fairly well spec'd hosts across multiple environments. These were fine on 1.29. Will there be a patch to 1.32, which is our current deployment? Is there an ETA for the next release? Thanks again.

kcarson77 avatar Jul 29 '25 14:07 kcarson77

Hi @kcarson77,

Currently, there is no plan to patch 1.32 as we generally don't back-port new features. The next release will depend on a new release of Dqlite and multiple larger changes on the layer between k8s and Dqlite.

While this is probably not the answer you were hoping for, you should consider upgrading your cluster to take advantage of the new performance improvements.

Best regards, Louise

louiseschmidtgen avatar Jul 31 '25 07:07 louiseschmidtgen

OK, thanks. Do you mean next release of 1.33, or mean next release as in 1.34 at end of August?

kcarson77 avatar Aug 01 '25 07:08 kcarson77

Hi @kcarson77,

the improvements will be part of the 1.34 MiroK8s release.

louiseschmidtgen avatar Aug 01 '25 08:08 louiseschmidtgen

Hi @louiseschmidtgen,

Please, do you have an estimated time when we could upgrade to the 1.34 version and test the issue?

Thanks a lot in advance!

nelsinchi avatar Aug 04 '25 15:08 nelsinchi

Hi @nelsinchi,

Microk8s 1.34 will be released shortly after upstream Kubernetes 1.34 is released.

HomayoonAlimohammadi avatar Aug 05 '25 13:08 HomayoonAlimohammadi

https://kubernetes.io/blog/2025/08/27/kubernetes-v1-34-release/

sibelius avatar Aug 28 '25 14:08 sibelius

Hello! Please, can someone give an answer, does this problem fixed in MK8s 1.34? Thanks in advance!

MonkzCode avatar Sep 29 '25 12:09 MonkzCode

@MonkzCode Yes 1.34 looks much better. I still see the err500 database is locked on odd occasion - but instances are in the single digits at times of load vs thousands of these errors over a few seconds with previous releases.

cs-dsmyth avatar Sep 30 '25 10:09 cs-dsmyth