Observing Instance Lifecycle on the Node Controller

Follow

Eucalyptus Versions:  3.4.x and Greater

Observing Instance Lifecycle on the Node Controller

There are certain situations where the cloud administrator needs to observe and provide logging information about an instance that has been launched on a given Node Controller.  There are two elements that can be used.  

  • The instance ID
  • The thread ID 

Obtaining the Instance ID

To obtain the instance ID, use the euca-describe-instances command to show all the instances that are associated with the Eucalyptus cloud.  To figure out which Node Controller (NC) to grab the instance lifecycle information, either of the following options can be used:

  1. Use euca_conf --list-nodes or euca-describe-nodes to list the Node Controller(s) registered.  These commands will also display what instances are running/pending on the associated Node Controller (NC).
  2. Search for the instance ID in the cc.log on the Cluster Controller (CC) component. The doRunInstances function will show what Node Controller (NC) the instance has been created.  For example:
[root@odc-d-31 ~]# grep i-B750412B /var/log/eucalyptus/cc.log* | grep INFO
/var/log/eucalyptus/cc.log.2:2014-05-22 06:47:28 INFO 000018840 print_abbreviated_instan | running 1 instance(s): i-B750412B
/var/log/eucalyptus/cc.log.2:2014-05-22 06:47:28 INFO 000018840 doRunInstances | scheduler decided to run instance i-B750412B on resource http://10.105.10.7:8775/axis2/services/EucalyptusNC, running count 0
/var/log/eucalyptus/cc.log.2:2014-05-22 06:47:28 INFO 000018840 find_or_alloc_sr | allocated new sensor resource i-B750412B
/var/log/eucalyptus/cc.log.2:2014-05-22 06:48:16 INFO 000018842 print_abbreviated_instan | terminating 1 instance(s): i-B750412B
/var/log/eucalyptus/cc.log.2:2014-05-22 06:48:16 INFO 000018842 print_abbreviated_instan | terminating 1 instance(s): i-B750412B
/var/log/eucalyptus/cc.log.2:2014-05-22 07:05:16 INFO 000018948 sensor_expire_cache_entr | expiring resource i-B750412B from sensor cache, no update in 1067 seconds, timeout is 1050 seconds

Utilizing the Instance ID on the Node Controller (NC)

To observe the full lifecycle of an instance, the log level on the Node Controller (NC) should be set to DEBUG [1].  Once the instance ID has been associated with the Node Controller, the cloud administrator can then search the nc.log file to see the life cycle of the instance.  For example:

[root@odc-c-07 ~]# grep i-B750412B /var/log/eucalyptus/nc.log | grep INFO
2014-05-22 06:47:28 INFO 000025688 doRunInstance | [i-B750412B] running instance cores=1 disk=10 memory=1024 vlan=992 net=36 priMAC=D0:0D:B7:50:41:2B privIp=172.18.247.164 plat=linux kernel=(null) ramdisk=(null)
2014-05-22 06:47:28 INFO 000031437 ensure_directories_exist | creating path /instances/work/AIDCKX4RYUMQCVMSMCPL2/i-B750412B
2014-05-22 06:47:29 INFO 000031437 walrus_creator | [i-B750412B] downloading http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:30 INFO 000025700 monitoring_thread | [i-B750412B] cleaning up state for instance
2014-05-22 06:47:30 INFO 000025700 monitoring_thread | [i-B750412B] stopping the network (vlan=992)
2014-05-22 06:50:32 INFO 000025700 monitoring_thread | [i-B750412B] forgetting about instance

Utilizing the Thread ID on the Node Controller (NC)

After using the instance ID to gather a specific view of the instance lifecycle, the thread ID can be used to get a more high level picture of the instance lifecycle.  The thread ID that should be used is the one associated with the startup_thread entry in the nc.log file.  For example:

2014-05-22 06:47:28 DEBUG 000031437 startup_thread           | [i-B750412B] spawning startup thread

Use grep [2] to gather all the information for the instance.  Here is an example:

[root@odc-c-07 ~]# grep 000031437 /var/log/eucalyptus/nc.log
2014-05-22 06:47:28 DEBUG 000031437 startup_thread | [i-B750412B] spawning startup thread
2014-05-22 06:47:28 DEBUG 000031437 vnetStartNetworkManaged | params: vnetconfig=0x7faa6fa2c010, vlan=992, uuid=UNSET, userName=UNSET, netName=UNSET
2014-05-22 06:47:28 INFO 000031437 ensure_directories_exist | creating path /instances/work/AIDCKX4RYUMQCVMSMCPL2/i-B750412B
2014-05-22 06:47:28 DEBUG 000031437 diskutil_ch | ch(own|mod) '/instances/work/AIDCKX4RYUMQCVMSMCPL2/i-B750412B' *.root 771
2014-05-22 06:47:28 DEBUG 000031437 vbr_alloc_tree | [i-B750412B] found 0 prereqs and 2 partitions in the VBR
2014-05-22 06:47:28 DEBUG 000031437 art_alloc | [i-B750412B] allocated artifact 025|i-B750412B size=-1 vbr=(nil) cache=0 file=0
2014-05-22 06:47:28 DEBUG 000031437 walrus_request_timeout | writing GET output to /tmp/walrus-digest-FRF3ft
2014-05-22 06:47:28 INFO 000031437 walrus_request_timeout | downloading http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:28 DEBUG 000031437 walrus_request_timeout | wrote 7041 byte(s) in 3 write(s)
2014-05-22 06:47:28 INFO 000031437 walrus_request_timeout | downloaded /tmp/walrus-digest-FRF3ft
2014-05-22 06:47:28 DEBUG 000031437 art_alloc | [i-B750412B] allocated artifact 026|emi-583B37BA-e9206036 size=2361393152 vbr=0x7faa87aa84e0 cache=1 file=0
2014-05-22 06:47:28 DEBUG 000031437 art_alloc | [i-B750412B] allocated artifact 027|emi-583B37BA-e9206036 size=2361393152 vbr=0x7faa87aa84e0 cache=0 file=0
2014-05-22 06:47:28 DEBUG 000031437 art_add_dep | [i-B750412B] added to artifact 027|emi-583B37BA-e9206036 artifact 026|emi-583B37BA-e9206036
2014-05-22 06:47:28 DEBUG 000031437 art_add_dep | [i-B750412B] added to artifact 025|i-B750412B artifact 027|emi-583B37BA-e9206036
2014-05-22 06:47:28 DEBUG 000031437 art_alloc | [i-B750412B] allocated artifact 028|prt-07988none-1d3b3a86 size=8376025088 vbr=0x7faa87aa6fb8 cache=1 file=0
2014-05-22 06:47:28 DEBUG 000031437 art_alloc | [i-B750412B] allocated artifact 029|prt-07988none-1d3b3a86 size=8376025088 vbr=0x7faa87aa6fb8 cache=0 file=0
2014-05-22 06:47:28 DEBUG 000031437 art_add_dep | [i-B750412B] added to artifact 029|prt-07988none-1d3b3a86 artifact 028|prt-07988none-1d3b3a86
2014-05-22 06:47:28 DEBUG 000031437 art_add_dep | [i-B750412B] added to artifact 025|i-B750412B artifact 029|prt-07988none-1d3b3a86
2014-05-22 06:47:28 DEBUG 000031437 art_print_tree | [i-B750412B] artifacts tree: 025|i-B750412B cache=0 file=0 creator=(nil) vbr=(nil)
2014-05-22 06:47:28 DEBUG 000031437 art_print_tree | [i-B750412B] artifacts tree: 027|emi-583B37BA-e9206036 cache=0 file=0 creator=0x7faa7f52c4b0 vbr=0x7faa87aa84e0
2014-05-22 06:47:28 DEBUG 000031437 art_print_tree | [i-B750412B] artifacts tree: 026|emi-583B37BA-e9206036 cache=1 file=0 creator=0x7faa7f52d590 vbr=0x7faa87aa84e0
2014-05-22 06:47:28 DEBUG 000031437 art_print_tree | [i-B750412B] artifacts tree: 029|prt-07988none-1d3b3a86 cache=0 file=0 creator=0x7faa7f52c4b0 vbr=0x7faa87aa6fb8
2014-05-22 06:47:28 DEBUG 000031437 art_print_tree | [i-B750412B] artifacts tree: 028|prt-07988none-1d3b3a86 cache=1 file=0 creator=0x7faa7f52d140 vbr=0x7faa87aa6fb8
2014-05-22 06:47:28 DEBUG 000031437 art_implement_tree | [i-B750412B] implementing artifact 025|i-B750412B
2014-05-22 06:47:28 DEBUG 000031437 art_implement_tree | [i-B750412B] implementing artifact 027|emi-583B37BA-e9206036
2014-05-22 06:47:28 DEBUG 000031437 find_or_create_artifact | [i-B750412B] checking work blobstore for 027|emi-583B37BA-e9206036 (do_create=0 ret=1)
2014-05-22 06:47:28 DEBUG 000031437 art_implement_tree | [i-B750412B] implementing artifact 026|emi-583B37BA-e9206036
2014-05-22 06:47:28 INFO 000031437 ensure_directories_exist | creating path /instances/cache/emi-583B37BA-e9206036
2014-05-22 06:47:28 DEBUG 000031437 diskutil_ch | ch(own|mod) '/instances/cache/emi-583B37BA-e9206036' *.* 771
2014-05-22 06:47:28 DEBUG 000031437 find_or_create_artifact | [i-B750412B] checking work blobstore for 026|emi-583B37BA-e9206036 (do_create=0 ret=2)
2014-05-22 06:47:28 INFO 000031437 ensure_directories_exist | creating path /instances/cache/emi-583B37BA-e9206036
2014-05-22 06:47:28 DEBUG 000031437 diskutil_ch | ch(own|mod) '/instances/cache/emi-583B37BA-e9206036' *.* 771
2014-05-22 06:47:29 DEBUG 000031437 diskutil_loop | attaching file /instances/cache/emi-583B37BA-e9206036/blocks
2014-05-22 06:47:29 DEBUG 000031437 diskutil_loop | to /dev/loop7 at offset 0
2014-05-22 06:47:29 DEBUG 000031437 art_implement_tree | [i-B750412B] created a blob for an artifact 026|emi-583B37BA-e9206036 on try 1
2014-05-22 06:47:29 INFO 000031437 walrus_creator | [i-B750412B] downloading http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:29 DEBUG 000031437 walrus_request_timeout | writing GET/GetDecryptedImage output
2014-05-22 06:47:29 DEBUG 000031437 walrus_request_timeout | from http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:29 DEBUG 000031437 walrus_request_timeout | to /instances/cache/emi-583B37BA-e9206036/blocks
2014-05-22 06:47:29 INFO 000031437 walrus_request_timeout | downloading http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:29 DEBUG 000031437 walrus_request_timeout | wrote 267 byte(s) in 1 write(s)
2014-05-22 06:47:29 ERROR 000031437 walrus_request_timeout | server responded with HTTP code 417 for http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:29 INFO 000031437 walrus_request_timeout | due to error, removing /instances/cache/emi-583B37BA-e9206036/blocks
2014-05-22 06:47:29 ERROR 000031437 walrus_creator | [i-B750412B] failed to download component http://10.104.10.11:8773/services/Walrus/utopic-server-x86_64-hvm/utopic-server-cloudimg-amd64-disk1.raw.manifest.xml
2014-05-22 06:47:29 ERROR 000031437 art_implement_tree | [i-B750412B] failed to create artifact emi-583B37BA-e9206036 (error=1, may retry) on try 1
2014-05-22 06:47:29 DEBUG 000031437 diskutil_unloop | detaching from loop device /dev/loop7
2014-05-22 06:47:29 DEBUG 000031437 art_implement_tree | [i-B750412B] failed to implement artifact 026|emi-583B37BA-e9206036 on try 1
2014-05-22 06:47:29 ERROR 000031437 art_implement_tree | [i-B750412B] failed to provision dependency emi-583B37BA-e9206036 for artifact emi-583B37BA-e9206036 (error=1) on try 1
2014-05-22 06:47:29 DEBUG 000031437 art_implement_tree | [i-B750412B] failed to implement artifact 027|emi-583B37BA-e9206036 on try 1
2014-05-22 06:47:29 ERROR 000031437 art_implement_tree | [i-B750412B] failed to provision dependency emi-583B37BA-e9206036 for artifact i-B750412B (error=1) on try 1
2014-05-22 06:47:29 DEBUG 000031437 art_implement_tree | [i-B750412B] failed to implement artifact 025|i-B750412B on try 1
2014-05-22 06:47:29 ERROR 000031437 create_instance_backing | [i-B750412B] failed to implement backing for instance
2014-05-22 06:47:29 ERROR 000031437 startup_thread | [i-B750412B] failed to prepare images for instance (error=1)
2014-05-22 06:47:29 DEBUG 000031437 change_state | [i-B750412B] state change for instance: Staging -> Shutoff (Pending)

Summary

When debugging an instance lifecycle, its helpful to gain both the specific and overall lifecycle of the instance.  Using the techniques above will help cloud administrators understand and diagnose issues associated with instances.

References

[1]  Eucalyptus Troubleshooting Guide - Log Files
[2]  GNU Grep 2.19

 

Have more questions? Submit a request

Comments

Powered by Zendesk