Merge pull request #111 in YUNIONIO/onecloud from ~QIUJIAN/onecloud:hotfix/qj-aliyun-vm-auto-start-fail to release/2.0.0

* commit '122c1d63f298da1dd8800a29e3e83d48b946e021':
  bugfixs for aliyun server create/delete
  remove some debug log
  修正：阿里云主机创建后自动启动失败

pkg/cloudcommon/cronman/cronman.go

@@ -9,6 +9,7 @@ import (
 
 	"yunion.io/x/log"
 
+	"yunion.io/x/onecloud/pkg/appctx"
 	"yunion.io/x/onecloud/pkg/mcclient"
 	"yunion.io/x/onecloud/pkg/mcclient/auth"
 )
@@ -89,6 +90,7 @@ func runJob(name string, job func(ctx context.Context, userCred mcclient.TokenCr
 	}()
 
 	ctx := context.Background()
+	ctx = context.WithValue(ctx, appctx.APP_CONTEXT_KEY_APPNAME, "Region-Corn-Service")
 	userCred := auth.AdminCredential()
 	job(ctx, userCred)
 }

pkg/cloudcommon/db/db_dispatcher.go

@@ -524,7 +524,7 @@ func (dispatcher *DBModelDispatcher) tryGetModelProperty(ctx context.Context, pr
 }
 
 func (dispatcher *DBModelDispatcher) Get(ctx context.Context, idStr string, query jsonutils.JSONObject) (jsonutils.JSONObject, error) {
-	log.Debugf("Get %s", idStr)
+	// log.Debugf("Get %s", idStr)
 	userCred := fetchUserCredential(ctx)
 
 	data, err := dispatcher.tryGetModelProperty(ctx, idStr, query)
@@ -541,7 +541,7 @@ func (dispatcher *DBModelDispatcher) Get(ctx context.Context, idStr string, quer
 	} else if err != nil {
 		return nil, err
 	}
-	log.Debugf("Get found %s", model)
+	// log.Debugf("Get found %s", model)
 	if !model.AllowGetDetails(ctx, userCred, query) {
 		return nil, httperrors.NewForbiddenError("Not allow to get details")
 	}

pkg/cloudcommon/db/taskman/tasks.go

@@ -246,17 +246,21 @@ func (manager *STaskManager) NewParallelTask(ctx context.Context, taskName strin
 }
 
 func (manager *STaskManager) fetchTask(idStr string) *STask {
-	task, err := db.NewModelObject(manager)
+	iTask, err := db.NewModelObject(manager)
 	if err != nil {
 		log.Errorf("New task object fail: %s", err)
 		return nil
 	}
-	err = manager.Query().Equals("id", idStr).First(task)
+	err = manager.Query().Equals("id", idStr).First(iTask)
 	if err != nil {
 		log.Errorf("GetTask %s fail: %s", idStr, err)
 		return nil
 	}
-	return task.(*STask)
+	task := iTask.(*STask)
+	if task.Params == nil {
+		task.Params = jsonutils.NewDict()
+	}
+	return task
 }
 
 func (manager *STaskManager) execTask(taskId string, data jsonutils.JSONObject) {
@@ -285,20 +289,21 @@ func (manager *STaskManager) execTask(taskId string, data jsonutils.JSONObject)
 	}
 }
 
-func execITask(taskValue reflect.Value, task *STask, data jsonutils.JSONObject, isMulti bool) {
+func execITask(taskValue reflect.Value, task *STask, odata jsonutils.JSONObject, isMulti bool) {
 	var err error
 	ctxData := task.GetRequestContext()
 	ctx := ctxData.GetContext()
 
 	taskFailed := false
 
+	data := odata
 	if data != nil {
 		taskStatus, _ := data.GetString("__status__")
 		if len(taskStatus) > 0 && taskStatus != "OK" {
 			taskFailed = true
 			data, err = data.Get("__reason__")
 			if err != nil {
-				data = jsonutils.NewString("Task failed due to unknown remote errors!")
+				data = jsonutils.NewString(fmt.Sprintf("Task failed due to unknown remote errors! %s", odata))
 			}
 		}
 	} else {
@@ -320,7 +325,13 @@ func execITask(taskValue reflect.Value, task *STask, data jsonutils.JSONObject,
 
 		if !funcValue.IsValid() || funcValue.IsNil() {
 			msg := fmt.Sprintf("Stage %s not found", stageName)
-			log.Errorf(msg)
+			if taskFailed {
+				// failed handler is optional, ignore the error
+				log.Warningf(msg)
+				msg, _ = data.GetString()
+			} else {
+				log.Errorf(msg)
+			}
 			task.SetStageFailed(ctx, msg)
 			task.SaveRequestContext(&ctxData)
 			return
@@ -408,9 +419,11 @@ func (self *STask) GetParentTask() *STask {
 
 func (self *STask) GetRequestContext() appctx.AppContextData {
 	ctxData := appctx.AppContextData{}
-	ctxJson, _ := self.Params.Get(REQUEST_CONTEXT_KEY)
-	if ctxJson != nil {
-		ctxJson.Unmarshal(&ctxData)
+	if self.Params != nil {
+		ctxJson, _ := self.Params.Get(REQUEST_CONTEXT_KEY)
+		if ctxJson != nil {
+			ctxJson.Unmarshal(&ctxData)
+		}
 	}
 	return ctxData
 }

pkg/cloudcommon/db/virtualresource.go

@@ -161,16 +161,16 @@ func (model *SVirtualResourceBase) AllowPerformMetadata(ctx context.Context, use
 }
 
 func (model *SVirtualResourceBase) GetTenantCache(ctx context.Context) (*STenant, error) {
-	log.Debugf("Get tenant by Id %s", model.ProjectId)
+	// log.Debugf("Get tenant by Id %s", model.ProjectId)
 	return TenantCacheManager.FetchTenantById(ctx, model.ProjectId)
 }
 
 func (model *SVirtualResourceBase) getMoreDetails(ctx context.Context, userCred mcclient.TokenCredential, query jsonutils.JSONObject, extra *jsonutils.JSONDict) *jsonutils.JSONDict {
 	if userCred.IsSystemAdmin() {
-		log.Debugf("GetCustomizeColumns")
+		// log.Debugf("GetCustomizeColumns")
 		tobj, err := model.GetTenantCache(ctx)
 		if err == nil {
-			log.Debugf("GetTenantFromCache %s", jsonutils.Marshal(tobj))
+			// log.Debugf("GetTenantFromCache %s", jsonutils.Marshal(tobj))
 			extra.Add(jsonutils.NewString(tobj.GetName()), "tenant")
 		} else {
 			log.Errorf("GetTenantCache fail %s", err)

pkg/compute/guestdrivers/aliyun.go

@@ -125,10 +125,11 @@ type SDiskInfo struct {
 func (self *SAliyunGuestDriver) RequestDeployGuestOnHost(ctx context.Context, guest *models.SGuest, host *models.SHost, task taskman.ITask) error {
 	config := guest.GetDeployConfigOnHost(ctx, host, task.GetParams())
 
-	onfinish, err := config.GetString("on_finish")
+	/* onfinish, err := config.GetString("on_finish")
 	if err != nil {
 		return err
-	}
+	} */
+	
 	action, err := config.GetString("action")
 	if err != nil {
 		return err
@@ -170,12 +171,12 @@ func (self *SAliyunGuestDriver) RequestDeployGuestOnHost(ctx context.Context, gu
 			return nil, err
 		}
 
-		if onfinish == "none" {
+		/* if onfinish == "none" {
 			err = iVM.StartVM()
 			if err != nil {
 				return nil, err
 			}
-		}
+		} */
 
 		encpasswd, err := utils.EncryptAESBase64(guest.Id, passwd)
 		if err != nil {

pkg/compute/guestdrivers/base.go

@@ -54,13 +54,13 @@ func (self *SBaseGuestDriver) StartGuestCreateTask(guest *models.SGuest, ctx con
 }
 
 func (self *SBaseGuestDriver) OnGuestCreateTaskComplete(ctx context.Context, guest *models.SGuest, task taskman.ITask) error {
-	//if jsonutils.QueryBoolean(task.GetParams(), "auto_start", false) {
-	//	task.SetStage("on_auto_start_guest", nil)
-	//	return guest.StartGueststartTask(ctx, task.GetUserCred(), nil, task.GetTaskId())
-	//} else {
-	task.SetStage("on_sync_status_complete", nil)
-	return guest.StartSyncstatus(ctx, task.GetUserCred(), task.GetTaskId())
-	//}
+	if jsonutils.QueryBoolean(task.GetParams(), "auto_start", false) {
+		task.SetStage("on_auto_start_guest", nil)
+		return guest.StartGueststartTask(ctx, task.GetUserCred(), nil, task.GetTaskId())
+	} else {
+		task.SetStage("on_sync_status_complete", nil)
+		return guest.StartSyncstatus(ctx, task.GetUserCred(), task.GetTaskId())
+	}
 }
 
 func (self *SBaseGuestDriver) StartDeleteGuestTask(guest *models.SGuest, ctx context.Context, userCred mcclient.TokenCredential, params *jsonutils.JSONDict, parentTaskId string) error {

pkg/compute/models/guestnetworks.go

@@ -19,6 +19,7 @@ import (
 	"yunion.io/x/onecloud/pkg/cloudcommon/db"
 	"yunion.io/x/onecloud/pkg/cloudcommon/db/lockman"
 	"yunion.io/x/onecloud/pkg/compute/options"
+	"database/sql"
 )
 
 const (
@@ -332,6 +333,22 @@ func (manager *SGuestnetworkManager) DeleteGuestNics(ctx context.Context, guest
 	return nil
 }
 
+func (manager *SGuestnetworkManager) getGuestNicByIP(ip string) (*SGuestnetwork, error) {
+	gn := SGuestnetwork{}
+	q := manager.Query()
+	q = q.Equals("ip_addr", ip)
+	err := q.First(&gn)
+	if err != nil {
+		if err != sql.ErrNoRows {
+			log.Errorf("getGuestNicByIP fail %s", err)
+			return nil, err
+		}
+		return nil, nil
+	}
+	gn.SetModelManager(manager)
+	return &gn, nil
+}
+
 func (self *SGuestnetwork) LogDetachEvent(userCred mcclient.TokenCredential, guest *SGuest, network *SNetwork) {
 	if network == nil {
 		netTmp, _ := NetworkManager.FetchById(self.NetworkId)

pkg/compute/models/guests.go

@@ -1429,7 +1429,20 @@ func (self *SGuest) SyncVMNics(ctx context.Context, userCred mcclient.TokenCrede
 		if add.net == nil {
 			continue // cannot determine which network it attached to
 		}
-		err := self.Attach2Network(ctx, userCred, add.net, nil, add.nic.GetIP(),
+		// check if the IP has been occupied, if yes, release the IP
+		gn, err := GuestnetworkManager.getGuestNicByIP(add.nic.GetIP())
+		if err != nil {
+			result.AddError(err)
+			continue
+		}
+		if gn != nil {
+			err = gn.Detach(ctx, userCred)
+			if err != nil {
+				result.AddError(err)
+				continue
+			}
+		}
+		err = self.Attach2Network(ctx, userCred, add.net, nil, add.nic.GetIP(),
 			add.nic.GetMAC(), add.nic.GetDriver(), 0, false, -1, add.reserve, IPAllocationDefault, true)
 		if err != nil {
 			result.AddError(err)
@@ -2110,9 +2123,9 @@ func (self *SGuest) AllowDeleteItem(ctx context.Context, userCred mcclient.Token
 func (self *SGuest) CustomizeDelete(ctx context.Context, userCred mcclient.TokenCredential, query jsonutils.JSONObject, data jsonutils.JSONObject) error {
 	overridePendingDelete := false
 	purge := false
-	if data != nil {
-		overridePendingDelete = jsonutils.QueryBoolean(data, "override_pending_delete", false)
-		purge = jsonutils.QueryBoolean(data, "purge", false)
+	if query != nil {
+		overridePendingDelete = jsonutils.QueryBoolean(query, "override_pending_delete", false)
+		purge = jsonutils.QueryBoolean(query, "purge", false)
 	}
 	return self.StartDeleteGuestTask(ctx, userCred, "", purge, overridePendingDelete)
 }

pkg/compute/tasks/guest_delete_task.go

@@ -4,12 +4,14 @@ import (
 	"context"
 
 	"yunion.io/x/jsonutils"
+	"yunion.io/x/log"
+	"yunion.io/x/pkg/utils"
+
 	"yunion.io/x/onecloud/pkg/cloudcommon/db"
 	"yunion.io/x/onecloud/pkg/cloudcommon/db/taskman"
 	"yunion.io/x/onecloud/pkg/cloudcommon/notifyclient"
 	"yunion.io/x/onecloud/pkg/compute/models"
 	"yunion.io/x/onecloud/pkg/compute/options"
-	"yunion.io/x/pkg/utils"
 )
 
 type GuestDeleteTask struct {
@@ -31,6 +33,7 @@ func (self *GuestDeleteTask) OnGuestStopComplete(ctx context.Context, obj db.ISt
 	if options.Options.EnablePendingDelete && !guest.PendingDeleted &&
 		!jsonutils.QueryBoolean(self.Params, "purge", false) &&
 		!jsonutils.QueryBoolean(self.Params, "override_pending_delete", false) {
+		log.Debugf("XXXXXXX Do guest pending delete... XXXXXXX")
 		guestStatus, _ := self.Params.GetString("guest_status")
 		if !utils.IsInStringArray(guestStatus, []string{models.VM_SCHEDULE_FAILED, models.VM_NETWORK_FAILED, models.VM_DISK_FAILED,
 			models.VM_CREATE_FAILED, models.VM_DEVICE_FAILED}) {
@@ -38,6 +41,7 @@ func (self *GuestDeleteTask) OnGuestStopComplete(ctx context.Context, obj db.ISt
 			return
 		}
 	}
+	log.Debugf("XXXXXXX Do real delete on guest ... XXXXXXX")
 	self.OnGuestStopCompleteFailed(ctx, guest, data)
 }
 

pkg/compute/tasks/guest_start_task.go

@@ -72,6 +72,7 @@ func (self *GuestStartTask) OnStartCompleteFailed(ctx context.Context, obj db.IS
 }
 
 func (self *GuestStartTask) onStartGuestFailed(ctx context.Context, guest *models.SGuest, err error) {
+	guest.SetStatus(self.UserCred, models.VM_START_FAILED, err.Error())
 	self.SetStageFailed(ctx, err.Error())
 	self.OnStartCompleteFailed(ctx, guest, jsonutils.NewString(err.Error()))
 }

pkg/mcclient/auth/auth.go

@@ -103,7 +103,7 @@ func (c *TokenCacheVerify) Verify(cli *mcclient.Client, adminToken, token string
 	if err != nil {
 		return nil, fmt.Errorf("Add %s credential to cache: %#v", cred.GetTokenString(), err)
 	}
-	log.Infof("Add token: %s", cred)
+	// log.Debugf("Add token: %s", cred)
 	return cred, nil
 }
 

pkg/util/aliyun/aliyun.go

@@ -3,6 +3,7 @@ package aliyun
 import (
 	"github.com/aliyun/alibaba-cloud-sdk-go/sdk"
 	"github.com/aliyun/alibaba-cloud-sdk-go/sdk/requests"
+
 	"yunion.io/x/jsonutils"
 	"yunion.io/x/log"
 	"yunion.io/x/onecloud/pkg/cloudprovider"

pkg/util/aliyun/errors.go

@@ -0,0 +1,13 @@
+package aliyun
+
+import (
+	aliyunerrors "github.com/aliyun/alibaba-cloud-sdk-go/sdk/errors"
+)
+
+func isError(err error, code string) bool {
+	aliyunErr, ok := err.(aliyunerrors.Error)
+	if ! ok {
+		return false
+	}
+	return aliyunErr.ErrorCode() == code
+}

pkg/util/aliyun/instance.go

@@ -397,7 +397,10 @@ func (self *SRegion) doStopVM(instanceId string, isForce bool) error {
 }
 
 func (self *SRegion) doDeleteVM(instanceId string) error {
-	return self.instanceOperation(instanceId, "DeleteInstance", nil)
+	params := make(map[string]string)
+	params["TerminateSubscription"] = "false"
+	params["Force"] = "true"
+	return self.instanceOperation(instanceId, "DeleteInstance", params)
 }
 
 /*func (self *SRegion) waitInstanceStatus(instanceId string, target string, interval time.Duration, timeout time.Duration) error {
@@ -420,7 +423,11 @@ func (self *SInstance) waitStatus(target string, interval time.Duration, timeout
 }*/
 
 func (self *SRegion) StartVM(instanceId string) error {
-	status, _ := self.GetInstanceStatus(instanceId)
+	status, err := self.GetInstanceStatus(instanceId)
+	if err != nil {
+		log.Errorf("Fail to get instance status on StartVM: %s", err)
+		return err
+	}
 	if status != InstanceStatusStopped {
 		log.Errorf("StartVM: vm status is %s expect %s", status, InstanceStatusStopped)
 		return cloudprovider.ErrInvalidStatus
@@ -433,7 +440,11 @@ func (self *SRegion) StartVM(instanceId string) error {
 }
 
 func (self *SRegion) StopVM(instanceId string, isForce bool) error {
-	status, _ := self.GetInstanceStatus(instanceId)
+	status, err := self.GetInstanceStatus(instanceId)
+	if err != nil {
+		log.Errorf("Fail to get instance status on StopVM: %s", err)
+		return err
+	}
 	if status != InstanceStatusRunning {
 		log.Errorf("StopVM: vm status is %s expect %s", status, InstanceStatusRunning)
 		return cloudprovider.ErrInvalidStatus
@@ -447,14 +458,13 @@ func (self *SRegion) StopVM(instanceId string, isForce bool) error {
 
 func (self *SRegion) DeleteVM(instanceId string) error {
 	status, err := self.GetInstanceStatus(instanceId)
-	if status == InstanceStatusRunning {
-		err = self.StopVM(instanceId, true)
-		if err != nil {
-			return err
-		}
-	} else if status != InstanceStatusStopped {
-		log.Errorf("DeleteVM: vm status is %s expect %s", status, InstanceStatusStopped)
-		return cloudprovider.ErrInvalidStatus
+	if err != nil {
+		log.Errorf("Fail to get instance status on DeleteVM: %s", err)
+		return err
+	}
+	log.Debugf("Instance status on delete is %s", status)
+	if status != InstanceStatusStopped {
+		log.Warningf("DeleteVM: vm status is %s expect %s", status, InstanceStatusStopped)
 	}
 	return self.doDeleteVM(instanceId)
 	// if err != nil {
@@ -487,9 +497,18 @@ func (self *SInstance) StopVM(isForce bool) error {
 }
 
 func (self *SInstance) DeleteVM() error {
-	err := self.host.zone.region.DeleteVM(self.InstanceId)
-	if err != nil {
-		return err
+	for {
+		err := self.host.zone.region.DeleteVM(self.InstanceId)
+		if err != nil {
+			if isError(err, "IncorrectInstanceStatus.Initializing") {
+				log.Infof("The instance is initializing, try later ...")
+				time.Sleep(10*time.Second)
+			} else {
+				return err
+			}
+		}else {
+			break
+		}
 	}
 	return cloudprovider.WaitDeleted(self, 10*time.Second, 300*time.Second) // 5minutes
 }