database consistency

[PPisz]

Is there a way to check the consistency of the CS database? For some time now, no usage_job process has completed successfully, and I don't know why.

[DaanHoogland]

@PPisz , any errors in the usage.log?
The only related consistency problem I can think of is that a sequence may be out of order (destroy at the same time or before create of some entity)

[PPisz]

@DaanHoogland
We enabled sanity check and got this alert:

Error: Found 187 usage records with raw_usage > 24
Error: Found 68 Vm usage records which are created after Vm is destroyed

Is there any way to fix these errors?

[DaanHoogland]

the second one are an example of what I described above. fixing timestamps on the events and re-running the usage may resolve that. the first one I am not sure of but it sounds like there are too many usage records per day (24 hrs?)

[PPisz]

@DaanHoogland We can't seem to figure this out. Is it possible to find the query that generates this alert somewhere in the CS source code? This would make it easier for us to find and fix invalid records.

SELECT ce.* FROM cloud.usage_event ce JOIN (SELECT resource_id, MAX(created) AS destroy_date FROM cloud.usage_event WHERE type = 'VM.DESTROY' GROUP BY resource_id) AS de ON ce.resource_id = de.resource_id WHERE ce.created > de.destroy_date AND ce.type LIKE 'VM.%';

The example query returns nothing, but we're probably doing it wrong.

[DaanHoogland]

@PPisz , I do not understand your query. It seems you are looking for events on a resource after a DESTROY event, is that right?

maybe the part ce.created > de.destroy_date should be ce.created >= de.created?

[PPisz]

@DaanHoogland Ok, based on these queries:

cloudstack/usage/src/main/java/com/cloud/usage/UsageSanityChecker.java

Line 41 in 15c2e50

public class UsageSanityChecker {

We managed to track down one VM that was deleted in January and events are logged for it every day at 11:59 PM:

select * from usage_event where resource_id = 1790 and type like 'VM.%';
+-------+------------+------------+---------------------+---------+-------------+-----------------------+-------------+-------------+------+---------------+-----------+--------------+
| id | type | account_id | created | zone_id | resource_id | resource_name | offering_id | template_id | size | resource_type | processed | virtual_size |
+-------+------------+------------+---------------------+---------+-------------+-----------------------+-------------+-------------+------+---------------+-----------+--------------+
| 62870 | VM.CREATE | 83 | 2025-01-21 20:56:09 | 1 | 1790 | meritus-dev-control-2 | 71 | 316 | NULL | KVM | 0 | NULL |
| 62897 | VM.DESTROY | 83 | 2025-01-21 20:56:10 | 1 | 1790 | meritus-dev-control-2 | 71 | 316 | NULL | KVM | 0 | NULL |
+-------+------------+------------+---------------------+---------+-------------+-----------------------+-------------+-------------+------+---------------+-----------+--------------+
2 rows in set (0.574 sec)

Events:

select vm.id, vm.name, vm.removed, cu.* from
-> cloud_usage.cloud_usage cu
-> inner join cloud.vm_instance vm
-> where vm.type = 'User'
-> and cu.usage_type in (1 , 2)
-> and cu.usage_id = vm.id and cu.start_date > vm.removed;
+------+-----------------------+---------------------+---------+---------+------------+-----------+-----------------------------------------------------------------------+---------------+------------+--------------------+----------------+-----------------------+-------------+-------------+----------+------+------+------------+---------------------+---------------------+--------------+-----------+-----------+--------+------------------+-----------+-------+
| id | name | removed | id | zone_id | account_id | domain_id | description | usage_display | usage_type | raw_usage | vm_instance_id | vm_name | offering_id | template_id | usage_id | type | size | network_id | start_date | end_date | virtual_size | cpu_speed | cpu_cores | memory | quota_calculated | is_hidden | state |
+------+-----------------------+---------------------+---------+---------+------------+-----------+-----------------------------------------------------------------------+---------------+------------+--------------------+----------------+-----------------------+-------------+-------------+----------+------+------+------------+---------------------+---------------------+--------------+-----------+-----------+--------+------------------+-----------+-------+
| 1790 | meritus-dev-control-2 | 2025-01-22 14:17:24 | 7578010 | 1 | 83 | 20 | meritus-dev-control-2 allocated (ServiceOffering: 71) (Template: 316) | 24 Hrs | 2 | 24 | 1790 | meritus-dev-control-2 | 71 | 316 | 1790 | KVM | NULL | NULL | 2025-10-27 00:00:00 | 2025-10-27 23:59:59 | NULL | NULL | 4 | 8192 | 0 | 0 | NULL |
| 1790 | meritus-dev-control-2 | 2025-01-22 14:17:24 | 7836640 | 1 | 83 | 20 | meritus-dev-control-2 allocated (ServiceOffering: 71) (Template: 316) | 24 Hrs | 2 | 24 | 1790 | meritus-dev-control-2 | 71 | 316 | 1790 | KVM | NULL | NULL | 2025-10-27 00:00:00 | 2025-10-27 23:59:59 | NULL | NULL | 4 | 8192 | 0 | 0 | NULL |
| 1790 | meritus-dev-control-2 | 2025-01-22 14:17:24 | 7842127 | 1 | 83 | 20 | meritus-dev-control-2 allocated (ServiceOffering: 71) (Template: 316) | 24 Hrs | 2 | 24 | 1790 | meritus-dev-control-2 | 71 | 316 | 1790 | KVM | NULL | NULL | 2025-10-28 00:00:00 | 2025-10-28 23:59:59 | NULL | NULL | 4 | 8192 | 0 | 0 | NULL |
| 1790 | meritus-dev-control-2 | 2025-01-22 14:17:24 | 8100760 | 1 | 83 | 20 | meritus-dev-control-2 allocated (ServiceOffering: 71) (Template: 316) | 24 Hrs | 2 | 24 | 1790 | meritus-dev-control-2 | 71 | 316 | 1790 | KVM | NULL | NULL | 2025-10-27 00:00:00 | 2025-10-27 23:59:59 | NULL | NULL | 4 | 8192 | 0 | 0 | NULL |
| 1790 | meritus-dev-control-2 | 2025-01-22 14:17:24 | 8106247 | 1 | 83 | 20 | meritus-dev-control-2 allocated (ServiceOffering: 71) (Template: 316) | 24 Hrs | 2 | 24 | 1790 | meritus-dev-control-2 | 71 | 316 | 1790 | KVM | NULL | NULL | 2025-10-28 00:00:00 | 2025-10-28 23:59:59 | NULL | NULL | 4 | 8192 | 0 | 0 | NULL |
|

We've checked several resources and they appear to have valid deletion dates. We're continuing our investigation, but any suggestions on what might be generating these events?

[DaanHoogland]

| 62870 | VM.CREATE | 83 | 2025-01-21 20:56:09 | 1 | 1790 | meritus-dev-control-2 | 71 | 316 | NULL | KVM | 0 | NULL |
| 62897 | VM.DESTROY | 83 | 2025-01-21 20:56:10 | 1 | 1790 | meritus-dev-control-2 | 71 | 316 | NULL | KVM | 0 | NULL |

these should not be a problem the destroy is neatly one second after the create. Are there any start/stop events after the destroy?

[PPisz]

After upgrading CS to 4.22, the problem is practically solved, the usage_job is executed, and sanity check has no errors.