Golang logger.Error函數代碼示例

//poll ready tasks and push into workQueue
func (qm *ServerMgr) updateQueue() (err error) {
	for _, task := range qm.taskMap {
		if qm.isTaskReady(task) {
			if err := qm.taskEnQueue(task); err != nil {
				jobid, _ := GetJobIdByTaskId(task.Id)
				qm.SuspendJob(jobid, fmt.Sprintf("failed enqueuing task %s, err=%s", task.Id, err.Error()), task.Id)
			}
		}
	}
	for id, work := range qm.workQueue.workMap {
		if work == nil || work.Info == nil {
			jid, err := GetJobIdByWorkId(id)
			if err != nil {
				qm.workQueue.Delete(id)
				logger.Error(fmt.Sprintf("error: in updateQueue() workunit %s is nil, cannot get job id", id))
				continue
			}

			if work == nil {
				qm.workQueue.Delete(id)
				qm.SuspendJob(jid, fmt.Sprintf("workunit %s is nil", id), id)
				logger.Error(fmt.Sprintf("error: workunit %s is nil, deleted from queue", id))
			} else if work.Info == nil {
				qm.workQueue.Delete(id)
				qm.SuspendJob(jid, fmt.Sprintf("workunit %s has Info=nil", id), id)
				logger.Error(fmt.Sprintf("error: workunit %s has Info=nil, deleted from queue", id))
			}
		}
	}
	return
}

func launchAPI(control chan int, port int) {
	c := controller.NewServerController()
	goweb.ConfigureDefaultFormatters()
	r := &goweb.RouteManager{}
	r.Map("/job/{jid}/acl/{type}", c.JobAcl["typed"])
	r.Map("/job/{jid}/acl", c.JobAcl["base"])
	r.Map("/cgroup/{cgid}/acl/{type}", c.ClientGroupAcl["typed"])
	r.Map("/cgroup/{cgid}/acl", c.ClientGroupAcl["base"])
	r.Map("/cgroup/{cgid}/token", c.ClientGroupToken)
	r.MapRest("/job", c.Job)
	r.MapRest("/work", c.Work)
	r.MapRest("/cgroup", c.ClientGroup)
	r.MapRest("/client", c.Client)
	r.MapRest("/queue", c.Queue)
	r.MapRest("/logger", c.Logger)
	r.MapRest("/awf", c.Awf)
	r.MapFunc("*", controller.ResourceDescription, goweb.GetMethod)
	if conf.SSL_ENABLED {
		err := goweb.ListenAndServeRoutesTLS(fmt.Sprintf(":%d", conf.API_PORT), conf.SSL_CERT_FILE, conf.SSL_KEY_FILE, r)
		if err != nil {
			fmt.Fprintf(os.Stderr, "ERROR: api: %v\n", err)
			logger.Error("ERROR: api: " + err.Error())
		}
	} else {
		err := goweb.ListenAndServeRoutes(fmt.Sprintf(":%d", conf.API_PORT), r)
		if err != nil {
			fmt.Fprintf(os.Stderr, "ERROR: api: %v\n", err)
			logger.Error("ERROR: api: " + err.Error())
		}
	}
	control <- 1 //we are ending
}

func StartClientWorkers() {
	control := make(chan int)
	go heartBeater(control)
	go workStealer(control)
	go dataMover(control)
	go processor(control)
	go deliverer(control)
	for {
		who := <-control //block till someone dies and then restart it
		switch who {
		case ID_HEARTBEATER:
			go heartBeater(control)
			logger.Error("heartBeater died and restarted")
		case ID_WORKSTEALER:
			go workStealer(control)
			logger.Error("workStealer died and restarted")
		case ID_DATAMOVER:
			go dataMover(control)
			logger.Error("dataMover died and restarted")
		case ID_WORKER:
			go processor(control)
			logger.Error("worker died and restarted")
		case ID_DELIVERER:
			go deliverer(control)
			logger.Error("deliverer died and restarted")
		}
	}
}

// GET: /client/{id}
func (cr *ClientController) Read(id string, cx *goweb.Context) {
	// Gather query params
	query := &Query{Li: cx.Request.URL.Query()}

	if query.Has("heartbeat") { //handle heartbeat
		cg, err := request.AuthenticateClientGroup(cx.Request)
		if err != nil {
			if err.Error() == e.NoAuth || err.Error() == e.UnAuth || err.Error() == e.InvalidAuth {
				if conf.CLIENT_AUTH_REQ == true {
					cx.RespondWithError(http.StatusUnauthorized)
					return
				}
			} else {
				logger.Error("[email protected]: " + err.Error())
				cx.RespondWithError(http.StatusInternalServerError)
				return
			}
		}

		hbmsg, err := core.QMgr.ClientHeartBeat(id, cg)
		if err != nil {
			cx.RespondWithErrorMessage(err.Error(), http.StatusBadRequest)
		} else {
			cx.RespondWithData(hbmsg)
		}
		return
	}

	LogRequest(cx.Request) //skip heartbeat in access log

	// Try to authenticate user.
	u, err := request.Authenticate(cx.Request)
	if err != nil && err.Error() != e.NoAuth {
		cx.RespondWithErrorMessage(err.Error(), http.StatusUnauthorized)
		return
	}

	// If no auth was provided, and anonymous read is allowed, use the public user
	if u == nil {
		if conf.ANON_READ == true {
			u = &user.User{Uuid: "public"}
		} else {
			cx.RespondWithErrorMessage(e.NoAuth, http.StatusUnauthorized)
			return
		}
	}

	client, err := core.QMgr.GetClientByUser(id, u)
	if err != nil {
		if err.Error() == e.ClientNotFound {
			cx.RespondWithErrorMessage(e.ClientNotFound, http.StatusBadRequest)
		} else {
			logger.Error("Error in GET client:" + err.Error())
			cx.RespondWithError(http.StatusBadRequest)
		}
		return
	}
	cx.RespondWithData(client)
	return
}

// POST: /job
func (cr *JobController) Create(cx *goweb.Context) {
	// Log Request and check for Auth
	LogRequest(cx.Request)

	// Parse uploaded form
	params, files, err := ParseMultipartForm(cx.Request)

	if err != nil {
		if err.Error() == "request Content-Type isn't multipart/form-data" {
			cx.RespondWithErrorMessage("No job file is submitted", http.StatusBadRequest)
		} else {
			// Some error other than request encoding. Theoretically
			// could be a lost db connection between user lookup and parsing.
			// Blame the user, Its probaby their fault anyway.
			logger.Error("Error parsing form: " + err.Error())
			cx.RespondWithError(http.StatusBadRequest)
		}
		return
	}

	_, has_upload := files["upload"]
	_, has_awf := files["awf"]

	if !has_upload && !has_awf {
		cx.RespondWithErrorMessage("No job script or awf is submitted", http.StatusBadRequest)
		return
	}

	//send job submission request and get back an assigned job number (jid)
	var jid string
	jid, err = core.QMgr.JobRegister()
	if err != nil {
		logger.Error("[email protected]_Create:GetNextJobNum: " + err.Error())
		cx.RespondWithErrorMessage(err.Error(), http.StatusBadRequest)
		return
	}

	var job *core.Job
	job, err = core.CreateJobUpload(params, files, jid)
	if err != nil {
		logger.Error("[email protected]_Create:CreateJobUpload: " + err.Error())
		cx.RespondWithErrorMessage(err.Error(), http.StatusBadRequest)
		return
	}

	if token, err := request.RetrieveToken(cx.Request); err == nil {
		job.SetDataToken(token)
	}

	core.QMgr.EnqueueTasksByJobId(job.Id, job.TaskList())

	//log event about job submission (JB)
	logger.Event(event.JOB_SUBMISSION, "jobid="+job.Id+";jid="+job.Jid+";name="+job.Info.Name+";project="+job.Info.Project)
	cx.RespondWithData(job)
	return
}

func deliverer(control chan int) {
	fmt.Printf("deliverer lanched, client=%s\n", core.Self.Id)
	defer fmt.Printf("deliverer exiting...\n")
	for {
		processed := <-fromProcessor
		work := processed.workunit
		workmap[work.Id] = ID_DELIVERER
		perfstat := processed.perfstat

		//post-process for works computed successfully: push output data to Shock
		move_start := time.Now().Unix()
		if work.State == core.WORK_STAT_COMPUTED {
			if err := core.PushOutputData(work); err != nil {
				work.State = core.WORK_STAT_FAIL
				logger.Error("[email protected]: workid=" + work.Id + ", err=" + err.Error())
			} else {
				work.State = core.WORK_STAT_DONE
			}
		}
		move_end := time.Now().Unix()
		perfstat.DataOut = move_end - move_start
		perfstat.Deliver = move_end
		perfstat.ClientResp = perfstat.Deliver - perfstat.Checkout
		perfstat.ClientId = core.Self.Id

		//notify server the final process results
		if err := core.NotifyWorkunitProcessed(work, perfstat); err != nil {
			time.Sleep(3 * time.Second) //wait 3 seconds and try another time
			if err := core.NotifyWorkunitProcessed(work, perfstat); err != nil {
				fmt.Printf("!!!NotifyWorkunitDone returned error: %s\n", err.Error())
				logger.Error("[email protected]: workid=" + work.Id + ", err=" + err.Error())
				//mark this work in Current_work map as false, something needs to be done in the future
				//to clean this kind of work that has been proccessed but its result can't be sent to server!
				core.Self.Current_work[work.Id] = false //server doesn't know this yet
			}
		}
		//now final status report sent to server, update some local info
		if work.State == core.WORK_STAT_DONE {
			logger.Event(event.WORK_DONE, "workid="+work.Id)
			core.Self.Total_completed += 1

			if conf.AUTO_CLEAN_DIR {
				if err := work.RemoveDir(); err != nil {
					logger.Error("[email protected](): workid=" + work.Id + ", err=" + err.Error())
				}
			}
		} else {
			logger.Event(event.WORK_RETURN, "workid="+work.Id)
			core.Self.Total_failed += 1
		}
		delete(core.Self.Current_work, work.Id)
		delete(workmap, work.Id)

	}
	control <- ID_DELIVERER //we are ending
}

// POST: /user
// To create a new user make a empty POST to /user with user:password
// Basic Auth encoded in the header. Return new user object.
func (cr *UserController) Create(cx *goweb.Context) {
	// Log Request
	LogRequest(cx.Request)

	if _, ok := cx.Request.Header["Authorization"]; !ok {
		cx.RespondWithError(http.StatusUnauthorized)
		return
	}
	header := cx.Request.Header.Get("Authorization")
	tmpAuthArray := strings.Split(header, " ")

	authValues, err := base64.URLEncoding.DecodeString(tmpAuthArray[1])
	if err != nil {
		err = errors.New("Failed to decode encoded auth settings in http request.")
		cx.RespondWithError(http.StatusBadRequest)
		return
	}

	authValuesArray := strings.Split(string(authValues), ":")
	if conf.ANON_CREATEUSER == false && len(authValuesArray) != 4 {
		if len(authValuesArray) == 2 {
			cx.RespondWithErrorMessage(e.UnAuth, http.StatusUnauthorized)
			return
		} else {
			cx.RespondWithError(http.StatusBadRequest)
			return
		}
	}
	name := authValuesArray[0]
	passwd := authValuesArray[1]
	admin := false
	if len(authValuesArray) == 4 {
		if authValuesArray[2] != fmt.Sprint(conf.SECRET_KEY) {
			cx.RespondWithErrorMessage(e.UnAuth, http.StatusUnauthorized)
			return
		} else if authValuesArray[3] == "true" {
			admin = true
		}
	}

	u, err := user.New(name, passwd, admin)
	if err != nil {
		// Duplicate key check
		if e.MongoDupKeyRegex.MatchString(err.Error()) {
			logger.Error("[email protected]_Create: duplicate key error")
			cx.RespondWithErrorMessage("Username not available", http.StatusBadRequest)
			return
		} else {
			logger.Error("[email protected]_Create: " + err.Error())
			cx.RespondWithError(http.StatusInternalServerError)
			return
		}
	}
	cx.RespondWithData(u)
	return
}

func getMetaDataField(field string) (result string, err error) {
	var url = fmt.Sprintf("%s/%s", conf.OPENSTACK_METADATA_URL, field) // TODO this is not OPENSTACK, this is EC2
	logger.Debug(1, fmt.Sprintf("url=%s", url))

	for i := 0; i < 3; i++ {
		var res *http.Response
		c := make(chan error)
		go func() {
			res, err = http.Get(url)
			if err != nil {
				c <- err //we are ending with error
				return
			}

			defer res.Body.Close()
			bodybytes, err := ioutil.ReadAll(res.Body)
			if err != nil {
				c <- err //we are ending with error
				return
			}
			result = string(bodybytes[:])

			c <- nil //we are ending without error
		}()
		select {
		case err = <-c:
			//go ahead
		case <-time.After(conf.INSTANCE_METADATA_TIMEOUT): //GET timeout
			err = errors.New("timeout: " + url)
		}

		if err != nil {
			logger.Error(fmt.Sprintf("warning: (iteration=%d) %s \"%s\"", i, url, err.Error()))
			continue
		} else if result == "" {
			logger.Error(fmt.Sprintf("warning: (iteration=%d) %s empty result", i, url))
			continue
		}

		break

	}

	if err != nil {
		return "", err
	}

	if result == "" {
		return "", errors.New(fmt.Sprintf("metadata result empty, %s", url))
	}

	logger.Debug(1, fmt.Sprintf("Intance Metadata %s => \"%s\"", url, result))
	return
}

func (apr AppRegistry) GetAppPackage(app_package string) (ap *AppPackage, err error) {

	ap, ok := apr[app_package]
	if ok {
		return ap, nil
	}

	package_url := conf.APP_REGISTRY_URL + "/" + app_package + ".json"

	var new_app_package AppPackage

	for i := 0; i < 3; i++ {

		if i > 0 {
			time.Sleep(1000 * time.Millisecond)
		}
		logger.Debug(1, fmt.Sprintf("downloading app package \"%s\"", package_url))

		res, err := httpclient.GetTimeout(package_url, nil, nil, nil, 5000*time.Millisecond)

		if err != nil {
			logger.Error("warning: " + conf.APP_REGISTRY_URL + " " + err.Error())
			continue
		}

		app_package_json, err := ioutil.ReadAll(res.Body)
		if err != nil {
			logger.Error(fmt.Sprintf("warning, could not read app registry json: %s", err.Error()))
			continue
		}

		// transform json into go struct interface
		//var f map[string]interface{}
		err = json.Unmarshal(app_package_json, &new_app_package)

		if err != nil {
			logger.Error("error unmarshaling app package " + app_package + ", error=" + err.Error())
			continue
		}

		apr[app_package] = &new_app_package
		ap = &new_app_package

		logger.Debug(1, fmt.Sprintf("app package unmarshalled"))
		return ap, nil
	}

	ap = nil
	err = errors.New("could not get app package from " + package_url)
	return

}

func (qm *CQMgr) filterWorkByClient(clientid string) (ids []string) {
	client := qm.clientMap[clientid]
	for id, _ := range qm.workQueue.wait {
		if _, ok := qm.workQueue.workMap[id]; !ok {
			logger.Error(fmt.Sprintf("error: workunit %s is in wait queue but not in workMap", id))
			continue
		}
		work := qm.workQueue.workMap[id]

		// In case of edge case where pointer to workunit is in queue but workunit has been deleted
		// If work.Info is nil, this will cause errors in execution
		// These will be deleted by servermgr.updateQueue()
		if work == nil || work.Info == nil {
			continue
		}

		if client == nil {
			fmt.Fprintf(os.Stderr, "error: Skip_work for client %s is nil", clientid)
			logger.Error(fmt.Sprintf("error: client %s is nil", clientid))
			continue
		}

		if client.Skip_work == nil {
			fmt.Fprintf(os.Stderr, "error: Skip_work for client %s is nil", clientid)
			logger.Error(fmt.Sprintf("error: Skip_work for client %s is nil", clientid))
			continue
		}

		//skip works that are in the client's skip-list
		if contains(client.Skip_work, work.Id) {
			logger.Debug(2, fmt.Sprintf("2) contains(client.Skip_work, work.Id) %s", id))
			continue
		}
		//skip works that have dedicate client groups which this client doesn't belong to
		if len(work.Info.ClientGroups) > 0 {
			eligible_groups := strings.Split(work.Info.ClientGroups, ",")
			if !contains(eligible_groups, client.Group) {
				logger.Debug(2, fmt.Sprintf("3) !contains(eligible_groups, client.Group) %s", id))
				continue
			}
		}
		//append works whos apps are supported by the client
		if contains(client.Apps, work.Cmd.Name) || contains(client.Apps, conf.ALL_APP) {
			ids = append(ids, id)
		} else {
			logger.Debug(2, fmt.Sprintf("3) contains(client.Apps, work.Cmd.Name) || contains(client.Apps, conf.ALL_APP) %s", id))
		}
	}
	return ids
}

func (qm *ServerMgr) Handle() {
	for {
		select {
		case <-qm.jsReq:
			jid := qm.getNextJid()
			qm.jsAck <- jid
			logger.Debug(2, fmt.Sprintf("qmgr:receive a job submission request, assigned jid=%s\n", jid))

		case task := <-qm.taskIn:
			logger.Debug(2, fmt.Sprintf("qmgr:task recived from chan taskIn, id=%s\n", task.Id))
			qm.addTask(task)

		case coReq := <-qm.coReq:
			logger.Debug(2, fmt.Sprintf("qmgr: workunit checkout request received, Req=%v\n", coReq))
			works, err := qm.popWorks(coReq)
			ack := CoAck{workunits: works, err: err}
			qm.coAck <- ack

		case notice := <-qm.feedback:
			logger.Debug(2, fmt.Sprintf("qmgr: workunit feedback received, workid=%s, status=%s, clientid=%s\n", notice.WorkId, notice.Status, notice.ClientId))
			if err := qm.handleWorkStatusChange(notice); err != nil {
				logger.Error("handleWorkStatusChange(): " + err.Error())
			}

		case <-qm.reminder:
			logger.Debug(3, "time to update workunit queue....\n")
			qm.updateQueue()
			if conf.DEV_MODE {
				fmt.Println(qm.ShowStatus())
			}
		}
	}
}

func (qm *ServerMgr) ClientHandle() {
	for {
		select {
		case coReq := <-qm.coReq:
			logger.Debug(2, fmt.Sprintf("qmgr: workunit checkout request received, Req=%v", coReq))
			var ack CoAck
			if qm.suspendQueue {
				// queue is suspended, return suspend error
				ack = CoAck{workunits: nil, err: errors.New(e.QueueSuspend)}
			} else {
				qm.updateQueue()
				works, err := qm.popWorks(coReq)
				if err == nil {
					qm.UpdateJobTaskToInProgress(works)
				}
				ack = CoAck{workunits: works, err: err}
			}
			qm.coAck <- ack
		case notice := <-qm.feedback:
			logger.Debug(2, fmt.Sprintf("qmgr: workunit feedback received, workid=%s, status=%s, clientid=%s", notice.WorkId, notice.Status, notice.ClientId))
			if err := qm.handleWorkStatusChange(notice); err != nil {
				logger.Error("handleWorkStatusChange(): " + err.Error())
			}
			qm.updateQueue()
		}
	}
}

func resetTask(task *Task, info *Info) {
	task.Info = info
	task.State = TASK_STAT_PENDING
	task.RemainWork = task.TotalWork
	task.ComputeTime = 0
	task.CompletedDate = time.Time{}
	// reset all inputs with an origin
	for _, input := range task.Inputs {
		if input.Origin != "" {
			input.Node = "-"
			input.Url = ""
			input.Size = 0
		}
	}
	// reset / delete all outputs
	for _, output := range task.Outputs {
		if dataUrl, _ := output.DataUrl(); dataUrl != "" {
			// delete dataUrl if is shock node
			if strings.HasSuffix(dataUrl, shock.DATA_SUFFIX) {
				if err := shock.ShockDelete(output.Host, output.Node, output.DataToken); err == nil {
					logger.Debug(2, fmt.Sprintf("Deleted node %s from shock", output.Node))
				} else {
					logger.Error(fmt.Sprintf("resetTask: unable to deleted node %s from shock: %s", output.Node, err.Error()))
				}
			}
		}
		output.Node = "-"
		output.Url = ""
		output.Size = 0
	}
	// delete all workunit logs
	for _, log := range conf.WORKUNIT_LOGS {
		deleteStdLogByTask(task.Id, log)
	}
}

// GET: /work/{id}
// get a workunit by id, read-only
func (cr *WorkController) Read(id string, cx *goweb.Context) {
	LogRequest(cx.Request)

	// Gather query params
	query := &Query{Li: cx.Request.URL.Query()}

	if query.Has("datatoken") && query.Has("client") { //a client is requesting data token for this job
		//***insert code to authenticate and check ACL***
		clientid := query.Value("client")
		token, err := core.QMgr.FetchDataToken(id, clientid)
		if err != nil {
			cx.RespondWithErrorMessage("error in getting token for job "+id, http.StatusBadRequest)
		}
		cx.RespondWithData(token)
		return
	}

	// Load workunit by id
	workunit, err := core.QMgr.GetWorkById(id)

	if err != nil {
		if err.Error() != e.QueueEmpty {
			logger.Error("[email protected]_Read:core.QMgr.GetWorkById(): " + err.Error())
		}
		cx.RespondWithErrorMessage(err.Error(), http.StatusBadRequest)
		return
	}
	// Base case respond with workunit in json
	cx.RespondWithData(workunit)
	return
}

// GET: /client/{id}
func (cr *ClientController) Read(id string, cx *goweb.Context) {
	// Gather query params
	query := &Query{Li: cx.Request.URL.Query()}

	if query.Has("heartbeat") { //handle heartbeat
		hbmsg, err := core.QMgr.ClientHeartBeat(id)
		if err != nil {
			cx.RespondWithErrorMessage(err.Error(), http.StatusBadRequest)
		} else {
			cx.RespondWithData(hbmsg)
		}
		return
	}

	LogRequest(cx.Request) //skip heartbeat in access log

	client, err := core.QMgr.GetClient(id)
	if err != nil {
		if err.Error() == e.ClientNotFound {
			cx.RespondWithErrorMessage(e.ClientNotFound, http.StatusBadRequest)
		} else {
			logger.Error("Error in GET client:" + err.Error())
			cx.RespondWithError(http.StatusBadRequest)
		}
		return
	}
	cx.RespondWithData(client)
}