[SOLVED] Periodic VM actions only seem to run once?

Hello all – I seem to be running into an issue with recurring/periodic VM actions and before I dive to deeply into the code to try to resolve it, I’m wondering if I’m missing something obvious. I can schedule a recurring action (hourly in this case) via the CLI or Sunstone (FWIW in an unrelated note, Sunstone has an error when trying to set the end time to Never which is: [one.vm.update] Cannot update template. Error END_VALUE defined but not valid END_TYPE found), but the action only ever seems to occur once. I would expect it to occur every hour. Am I missing something?

root@lancelot-vm-debian:~# onevm show 3
VIRTUAL MACHINE 3 INFORMATION
ID : 3
NAME : testvm
USER : oneadmin
GROUP : oneadmin
STATE : ACTIVE
LCM_STATE : RUNNING
LOCK : None
RESCHED : No
HOST : localhost
CLUSTER ID : 0
CLUSTER : default
START TIME : 03/20 13:57:15
END TIME : -
DEPLOY ID : one-3

VIRTUAL MACHINE MONITORING
CPU : 1.0
MEMORY : 288.3M
NETTX : 0K
NETRX : 5K
DISKRDBYTES : 52521116
DISKRDIOPS : 3217
DISKWRBYTES : 0
DISKWRIOPS : 0

PERMISSIONS
OWNER : um-
GROUP : —
OTHER : —

VM DISKS
ID DATASTORE TARGET IMAGE SIZE TYPE SAVE
2 default sda CentOS 7 - KVM 198M/8G file NO
1 - hda CONTEXT 1M/- - -

VM NICS
ID NETWORK BRIDGE IP MAC PCI_ID
0 vnet minionebr 172.16.100.2 02:00:ac:10:64:02

SECURITY

NIC_ID NETWORK SECURITY_GROUPS
0 vnet 0

SECURITY GROUP TYPE PROTOCOL NETWORK RANGE
ID NAME VNET START SIZE
0 default OUTBOUND ALL
0 default INBOUND ALL

SNAPSHOTS
ID TIME NAME HYPERVISOR_ID
0 03/20 14:23 snapshot-0 snap-0

VIRTUAL MACHINE HISTORY
SEQ UID REQ HOST ACTION DS START TIME PROLOG
0 0 8896 localhost poweroff-h 0 03/20 13:57:18 0d 00h00m 0h00m01s
1 0 32 localhost poweroff-h 0 03/20 13:57:45 0d 00h00m 0h00m00s
2 - - localhost none 0 03/20 13:58:10 0d 16h55m 0h00m00s

SCHEDULED ACTIONS
ID ACTION SCHEDULED REPEAT END DONE MESSAGE
snapshot-create 03/20 13:30 Each 1 hours On 01/01/36 03/20 14:23

USER TEMPLATE
LOGO=“images/logos/centos.png”

VIRTUAL MACHINE TEMPLATE
AUTOMATIC_DS_REQUIREMENTS="(“CLUSTERS/ID” @> 0)"
AUTOMATIC_NIC_REQUIREMENTS="(“CLUSTERS/ID” @> 0)"
AUTOMATIC_REQUIREMENTS="(CLUSTER_ID = 0) & !(PUBLIC_CLOUD = YES)"
CONTEXT=[
DISK_ID=“1”,
ETH0_CONTEXT_FORCE_IPV4="",
ETH0_DNS=“172.16.100.1”,
ETH0_EXTERNAL="",
ETH0_GATEWAY=“172.16.100.1”,
ETH0_GATEWAY6="",
ETH0_IP=“172.16.100.2”,
ETH0_IP6="",
ETH0_IP6_PREFIX_LENGTH="",
ETH0_IP6_ULA="",
ETH0_MAC=“02:00:ac:10:64:02”,
ETH0_MASK="",
ETH0_MTU="",
ETH0_NETWORK="",
ETH0_SEARCH_DOMAIN="",
ETH0_VLAN_ID="",
ETH0_VROUTER_IP="",
ETH0_VROUTER_IP6="",
ETH0_VROUTER_MANAGEMENT="",
NETWORK=“YES”,
PASSWORD=“opennebula”,
SSH_PUBLIC_KEY=“ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDSDqqfVa2QvuI/I58pIW1oP0mRFLiWnGHm6fus+fNczO/SPbsZ/mamP4aoaDxlshOGGKN3BMI8AMW2Gzm70yigfy5InrL1KyYbJ00WEW9AXMQIKGN+g2gy3nPTEc95z3AXSnU87wiCDHzScjAoj/wegBzPbLdh71rEUVd0Nb8W/VtYtqF4PUj/PshmtnuIILComYEADIqSJuwRjsufSOI/O96xefjhdce8muLOuvbBI5Ij/B+REjhAKs9bn6B0hFkWw6yT6d8dNjs351Cd3kfylHZo+4Z5xUlMZGGuPrkILOpQTjBDaSSJYNqJbLg83inD3q2j3ofmGDA6jDye2vGB oneadmin@lancelot-vm-debian ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCk+8C9VyIcaSRWrQUxJx1bhDhPyfLD4HPT3UVpqiW8R2PU07W3q5XaGkfLEKKiYoaV7MGIOInsw3CQZOd0GI+IJS+tlA8TvjiAvKiVQOnXFzR9BeT8iohmdMoW/h3rx1cQ8wGb71/kpowG83qs/wPP57+unMPDIlUlIaQUpnwWmKE6YJrpU154hEleBUZHOn3syekohV7Nfju92PjlNnzq/1lHJCorq7o4qqKXilFAGwc2/M8oPTACLbX+a4B1si3ZSaMNjrU59IAUtAxfGufFuyi74lfDwsbeqEdSEoZp3bc1OluudwHDv/PPdxfdc7kYRglO6VAZnXsm3W54pFpF root@lancelot-vm-debian”,
TARGET=“hda” ]
CPU=“0.6”
GRAPHICS=[
LISTEN=“0.0.0.0”,
PORT=“5903”,
TYPE=“vnc” ]
MEMORY=“1024”
OS=[
ARCH=“x86_64” ]
TEMPLATE_ID=“0”
TM_MAD_SYSTEM=“qcow2”
VCPU=“6”
VMID=“3”

root@lancelot-vm-debian:/var/log/one# date
Thu Mar 21 06:54:41 CDT 2019
root@lancelot-vm-debian:/var/log/one# tail -20 sched.log

Wed Mar 20 13:55:08 2019 [Z0][VNET][D]: Discovered 1 vnets.
Wed Mar 20 13:55:08 2019 [Z0][SCHED][D]: Dispatching VMs to hosts:
VMID Priority Host System DS
--------------------------------------------------------------
2 0 0 0

Wed Mar 20 13:57:18 2019 [Z0][VM][D]: Found 1 pending/rescheduling VMs.
Wed Mar 20 13:57:18 2019 [Z0][HOST][D]: Discovered 1 enabled hosts.
Wed Mar 20 13:57:18 2019 [Z0][VM][D]: VMs in VMGroups:

Wed Mar 20 13:57:18 2019 [Z0][VNET][D]: Discovered 1 vnets.
Wed Mar 20 13:57:18 2019 [Z0][SCHED][D]: Dispatching VMs to hosts:
VMID Priority Host System DS
--------------------------------------------------------------
3 0 0 0

Wed Mar 20 14:23:30 2019 [Z0][VM][D]: VMs with scheduled actions:
3
Wed Mar 20 14:23:30 2019 [Z0][VM][I]: Executing action ‘snapshot-create’ for VM 3 : Success.

Hi @kvanals

First of all, thanks a lot for reporting the bug in Sunstone, I have opened an issue in our GitHub.

Then, could you please send me the complete sched log, oned log and the output of onevm show 3 -x? I will try to reproduce your issue.

Thanks!

Thank you for the reply!

I gathered up the requested logs regarding the periodic events not running more than one time. Unfortunately, I can’t upload the tarball to this forum, as I believe I’m below a certain threshold for uploading attachments. In lieu of that, I uploaded them to a web server on the internet and they are available here:
one-periodic-broken-logs.tar.bz2

At first glance from looking at the database, it looks like perhaps the next event gets scheduled at some date in the past, causing the scheduler to never trigger the next snapshot/event? I don’t see anything immediately obvious in src/vm_template/ScheduledAction.cc, but I’d think the issue would be there. I’ll look more deeply into it on Monday.

Thanks,
Kenny

Hi @kvanals

Thanks for the logs! I inspected them and I didn’t see anything wrong.

Could you try creating the sched action using the CLI? Tell me if it works or if you see the same behaviour.

Thanks!

Hello again @kvanals

It seems to be a bug, we are going to investigate it and fix it.

I can create a scheduled event with end period of “Never” just fine via the onevm CLI, however the event still only occurs once and never again, similarly to creating the event in Sunstone.

Thanks,
Kenny

Good morning @kvanals

I have opened an issue in GitHub, so you can track the fix of the bug. The bug has been fixed, I have to check that everything works, so it will be available in the next release of OpenNebula.

Thanks for your feedback and your patient!

1 Like

Thank you so much! This took you a lot less time to resolve than it would have taken me and it is greatly appreciated. I’m rebuilding my OpenNebula build right now and will test on my side as well.

Thanks,
Kenny

Perfect! Just let me know if you find any error.

Hello @ahuertas
I am working on XML-RPC methods and having following queries:

  1. one.vm.action method takes two parameters id and action, so how can we add scheduled action to it using XML-RPC call.
    CLI provides a command to do the same "onevm poweroff 0 --schedule “09/23 14:15” "
    How can we add scheduled time for action using API call?
  2. I want to update the running vm and add a custom var.
    one.vm.update method provides the field to update but I am not able to add a new custom vars(context=>custom vars)

Please suggest and guide on the above queries.
Looking for some solution approach as haven’t got much deep in any of the document for these queries.
Thanks in advance!!

Hello @ahuertas @rdiaz @ruben could you please help on the above query?

Hi @Rahul_Sharma,
it would be better to create a new topic for a new question.

Scheduled actions do not use one.vm.action API.

Since release 6.2 they use one.vm.schedadd, one.vm.schedupdate and one.vm.scheddelete. The schedadd expect as an argument template string in the form:

    SCHED_ACTION=[
      ACTION="suspend",
      ID="0",
      TIME="1379628000" ]

Prior to 6.2 one.vm.update is used, better with append flag, but you need to repeat all existing actions to add a new one.

1 Like