You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cloudstack.apache.org by "KuasarCloud (via GitHub)" <gi...@apache.org> on 2025/07/17 16:31:11 UTC
[D] Recurrent errors in database on vm schedules [cloudstack]
GitHub user KuasarCloud created a discussion: Recurrent errors in database on vm schedules
Hey community!
After creating a schedule to start/stop vm_instances, a recurrent error appears in logs
025-07-17 11:29:19,383 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@614529765 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'65396330306236652d626463622d346430612d396162332d663466636136343536356130', 293, 120, NULL, 'STOP', '2025-07-18 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '120-2025-07-18 04:00:00' for key 'vm_schedule_id'
I have two management host running with ACS 4.20.1 with KVM Hypervisors. Any clue what is trying to insert it again in the database?
GitHub link: https://github.com/apache/cloudstack/discussions/11238
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud added a comment to the discussion: Recurrent errors in database on vm schedules
Hi @DaanHoogland
Please take a look, this all related to `logid:c3157b08`
`2025-07-17 11:29:19,360 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) VM scheduler.poll is being called at 2025-07-17T16:29:00+0000
2025-07-17 11:29:19,376 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@1276927238 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'36383332303139372d343331622d343964652d393866622d333830313831333934653730', 293, 118, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '118-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,377 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 3 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,379 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,383 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@614529765 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'65396330306236652d626463622d346430612d396162332d663466636136343536356130', 293, 120, NULL, 'STOP', '2025-07-18 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '120-2025-07-18 04:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,383 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,385 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,389 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@1815803217 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'30643861656165632d343234342d343835382d386363662d366161393337613734383536', 654, 122, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '122-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,389 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,391 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,395 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@1276268827 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'64313833353966382d333764322d343836632d383138632d356263663666393134303937', 654, 124, NULL, 'STOP', '2025-07-18 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '124-2025-07-18 04:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,396 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 3 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,398 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,401 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Got 0 scheduled jobs to be executed at 2025-07-17T16:29:00+0000
2025-07-17 11:29:19,404 INFO [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Cleaned up 0 VM scheduled job entries`
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13837727
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud edited a comment on the discussion: Recurrent errors in database on vm schedules
Hi @DaanHoogland
Please take a look, this all related to `logid:c3157b08`
```
2025-07-17 11:29:19,360 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) VM scheduler.poll is being called at 2025-07-17T16:29:00+0000
2025-07-17 11:29:19,376 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@1276927238 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'36383332303139372d343331622d343964652d393866622d333830313831333934653730', 293, 118, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '118-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,377 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 3 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,379 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,383 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@614529765 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'65396330306236652d626463622d346430612d396162332d663466636136343536356130', 293, 120, NULL, 'STOP', '2025-07-18 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '120-2025-07-18 04:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,383 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,385 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,389 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@1815803217 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'30643861656165632d343234342d343835382d386363662d366161393337613734383536', 654, 122, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '122-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,389 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,391 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,395 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@1276268827 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'64313833353966382d333764322d343836632d383138632d356263663666393134303937', 654, 124, NULL, 'STOP', '2025-07-18 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '124-2025-07-18 04:00:00' for key 'vm_schedule_id'
2025-07-17 11:29:19,396 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Rolling back the transaction: Time = 3 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-17 11:29:19,398 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Job is already scheduled.
2025-07-17 11:29:19,401 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Got 0 scheduled jobs to be executed at 2025-07-17T16:29:00+0000
2025-07-17 11:29:19,404 INFO [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) Cleaned up 0 VM scheduled job entries
```
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13837727
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "weizhouapache (via GitHub)" <gi...@apache.org>.
GitHub user weizhouapache closed the discussion with a comment: Recurrent errors in database on vm schedules
thanks @KuasarCloud
closing this
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-14296381
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud closed a discussion: Recurrent errors in database on vm schedules
Hey community!
After creating a schedule to start/stop vm_instances, a recurrent error appears in logs
025-07-17 11:29:19,383 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-d11d1302]) (logid:c3157b08) DB Exception on: HikariProxyPreparedStatement@614529765 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[6379]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'65396330306236652d626463622d346430612d396162332d663466636136343536356130', 293, 120, NULL, 'STOP', '2025-07-18 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '120-2025-07-18 04:00:00' for key 'vm_schedule_id'
I have two management host running with ACS 4.20.1 with KVM Hypervisors. Any clue what is trying to insert it again in the database?
GitHub link: https://github.com/apache/cloudstack/discussions/11238
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "DaanHoogland (via GitHub)" <gi...@apache.org>.
GitHub user DaanHoogland added a comment to the discussion: Recurrent errors in database on vm schedules
@KuasarCloud , thanks for investigating.
So you are saying that both MS are trying to *update* the same schedule, by creating the same task?
If so that seems a bug to me (or at least an improvement waiting for implementation ;) The scheduler should recognise that no work needs to done. One more question; Do these errors keep coming or do they stop after a couple of retries?
Can you provide a short description of the scenario and the excerpts from the logs of both MSses in [a new issue](https://github.com/apache/cloudstack/issues/new/choose)?
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-14044480
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud added a comment to the discussion: Recurrent errors in database on vm schedules
Hi @DaanHoogland, issue created at https://github.com/apache/cloudstack/issues/11564 and to answer your question, it keeps going forever, the only way to stop it is eliminating the rule
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-14289718
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "DaanHoogland (via GitHub)" <gi...@apache.org>.
GitHub user DaanHoogland added a comment to the discussion: Recurrent errors in database on vm schedules
@KuasarCloud are there any debug messages above, especially with the same logid or ctx-<value>.
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13806249
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud added a comment to the discussion: Recurrent errors in database on vm schedules
It appears to be a race condition error caused by multiple scheduler instances running concurrently. We have two ACS Server Manager nodes, and when a scheduled task is created on one node, the other node throws an error — and the same happens in reverse.
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-14037403
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud edited a comment on the discussion: Recurrent errors in database on vm schedules
Hi @DaanHoogland
this would be with the same ctx
```
2025-07-18 03:49:19,360 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) VM scheduler.poll is being called at 2025-07-18T08:49:00+0000
2025-07-18 03:49:19,370 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@898825417 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'34643731356134372d646163622d346534392d613466312d626663383834343337663336', 293, 118, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '118-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,371 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 4 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,373 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,376 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@2098749760 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'62343238303963342d326435342d346432612d386662342d623138666632616661646465', 293, 120, NULL, 'STOP', '2025-07-19 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '120-2025-07-19 04:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,377 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,379 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,382 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@1545630670 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'39613738316263302d653064612d343639352d383639622d333434666338633134343861', 654, 122, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '122-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,383 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,384 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,387 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@1736698952 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'34393765363563662d616635302d346666362d383736662d653239386563366164376330', 654, 124, NULL, 'STOP', '2025-07-19 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '124-2025-07-19 04:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,390 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 4 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,392 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,395 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Got 0 scheduled jobs to be executed at 2025-07-18T08:49:00+0000
2025-07-18 03:49:19,399 INFO [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Cleaned up 0 VM scheduled job entries
```
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13808623
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "DaanHoogland (via GitHub)" <gi...@apache.org>.
GitHub user DaanHoogland added a comment to the discussion: Recurrent errors in database on vm schedules
This is not what I am asking for @KuasarCloud , please grep for `logid:c3157b08` and for `ctx-d11d1302` and look far any reason the attempt to add it again was made.
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13811829
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "KuasarCloud (via GitHub)" <gi...@apache.org>.
GitHub user KuasarCloud added a comment to the discussion: Recurrent errors in database on vm schedules
Hi @DaanHoogland
this would be with the same ctx
`2025-07-18 03:49:19,360 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) VM scheduler.poll is being called at 2025-07-18T08:49:00+0000
2025-07-18 03:49:19,370 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@898825417 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'34643731356134372d646163622d346534392d613466312d626663383834343337663336', 293, 118, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '118-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,371 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 4 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,373 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,376 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@2098749760 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'62343238303963342d326435342d346432612d386662342d623138666632616661646465', 293, 120, NULL, 'STOP', '2025-07-19 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '120-2025-07-19 04:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,377 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,379 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,382 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@1545630670 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'39613738316263302d653064612d343639352d383639622d333434666338633134343861', 654, 122, NULL, 'START', '2025-07-18 11:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '122-2025-07-18 11:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,383 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 2 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,384 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,387 ERROR [o.a.c.v.s.d.VMScheduledJobDaoImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) DB Exception on: HikariProxyPreparedStatement@1736698952 wrapping com.mysql.cj.jdbc.ServerPreparedStatement[18104]: INSERT INTO vm_scheduled_job (vm_scheduled_job.uuid, vm_scheduled_job.vm_id, vm_scheduled_job.vm_schedule_id, vm_scheduled_job.async_job_id, vm_scheduled_job.action, vm_scheduled_job.scheduled_timestamp) VALUES (x'34393765363563662d616635302d346666362d383736662d653239386563366164376330', 654, 124, NULL, 'STOP', '2025-07-19 04:00:00') java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '124-2025-07-19 04:00:00' for key 'vm_schedule_id'
2025-07-18 03:49:19,390 DEBUG [c.c.u.d.T.Transaction] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Rolling back the transaction: Time = 4 Name = VMSchedulerPollTask; called by -TransactionLegacy.rollback:896-TransactionLegacy.removeUpTo:839-TransactionLegacy.close:663-TransactionContextInterceptor.invoke:36-ReflectiveMethodInvocation.proceed:175-ExposeInvocationInterceptor.invoke:97-ReflectiveMethodInvocation.proceed:186-JdkDynamicAopProxy.invoke:215-$Proxy373.persist:-1-VMSchedulerImpl.scheduleNextJob:167-VMSchedulerImpl.scheduleNextJobs:248-VMSchedulerImpl.poll:216
2025-07-18 03:49:19,392 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Job is already scheduled.
2025-07-18 03:49:19,395 DEBUG [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Got 0 scheduled jobs to be executed at 2025-07-18T08:49:00+0000
2025-07-18 03:49:19,399 INFO [o.a.c.v.s.VMSchedulerImpl] (VMSchedulerPollTask:[ctx-baef661e]) (logid:6169a69c) Cleaned up 0 VM scheduled job entries`
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13808623
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org
Re: [D] Recurrent errors in database on vm schedules [cloudstack]
Posted by "DaanHoogland (via GitHub)" <gi...@apache.org>.
GitHub user DaanHoogland added a comment to the discussion: Recurrent errors in database on vm schedules
Sorry @KuasarCloud , there is not enough information there to make even a guess. You will have to investigate the logs more.
GitHub link: https://github.com/apache/cloudstack/discussions/11238#discussioncomment-13851617
----
This is an automatically sent email for users@cloudstack.apache.org.
To unsubscribe, please send an email to: users-unsubscribe@cloudstack.apache.org