Golang logger.Debug函數代碼示例

func dockerImportImage(client *docker.Client, Dockerimage string, datatoken string) (err error) {

	_, download_url, err := findDockerImageInShock(Dockerimage, datatoken) // TODO get node

	if err != nil {
		return err
	}

	logger.Debug(1, fmt.Sprintf("docker image url=%s", download_url))

	// TODO import base image if needed

	// *** import image
	Dockerimage_array := strings.Split(Dockerimage, ":")
	Dockerimage_repo, Dockerimage_tag := Dockerimage_array[0], Dockerimage_array[1]

	logger.Debug(1, fmt.Sprintf("importing image..."))
	var buf bytes.Buffer
	opts := docker.ImportImageOptions{
		Source:       download_url,
		Repository:   Dockerimage_repo,
		Tag:          Dockerimage_tag,
		OutputStream: &buf,
	}

	err = client.ImportImage(opts)
	if err != nil {
		return errors.New(fmt.Sprintf("Error importing docker image, err=%s", err.Error()))
	}

	return
}

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) locateInputs(task *Task) (err error) {
	logger.Debug(2, "trying to locate Inputs of task "+task.Id)
	jobid := strings.Split(task.Id, "_")[0]
	for name, io := range task.Inputs {
		if io.Url == "" {
			preId := fmt.Sprintf("%s_%s", jobid, io.Origin)
			if preTask, ok := qm.taskMap[preId]; ok {
				if preTask.State == TASK_STAT_SKIPPED ||
					preTask.State == TASK_STAT_FAIL_SKIP {
					// For now we know that skipped tasks have
					// just one input and one output. So we know
					// that we just need to change one file (this
					// may change in the future)
					//locateSkippedInput(qm, preTask, io)
				} else {
					outputs := preTask.Outputs
					if outio, ok := outputs[name]; ok {
						io.Node = outio.Node
					}
				}
			}
		}
		io.DataUrl()
		if io.Node == "-" {
			return errors.New(fmt.Sprintf("error in locate input for task %s, %s", task.Id, name))
		}
		//need time out!
		if io.GetFileSize() < 0 {
			return errors.New(fmt.Sprintf("task %s: input file %s not available", task.Id, name))
		}
		logger.Debug(2, fmt.Sprintf("inputs located %s, %s\n", name, io.Node))
	}
	return
}

// was getDockerImageUrl(Dockerimage string) (download_url string, err error)
func findDockerImageInShock(Dockerimage string) (node *shock.ShockNode, download_url string, err error) {

	shock_docker_repo := shock.ShockClient{conf.SHOCK_DOCKER_IMAGE_REPOSITORY, ""}

	logger.Debug(1, fmt.Sprint("try to import docker image, Dockerimage=", Dockerimage))
	//query url = type=dockerimage&name=wgerlach/bowtie2:2.2.0"

	query_response_p, err := shock_docker_repo.Query(url.Values{"type": {"dockerimage"}, "name": {Dockerimage}})
	if err != nil {
		return nil, "", errors.New(fmt.Sprintf("shock node not found for image=%s, err=%s", Dockerimage, err.Error()))
	}
	logger.Debug(1, fmt.Sprintf("query result: %v", query_response_p))

	datalen := len((*query_response_p).Data)

	if datalen == 0 {
		return nil, "", errors.New(fmt.Sprintf("image %s not found in shocks docker repo", Dockerimage))
	} else if datalen > 1 {
		return nil, "", errors.New(fmt.Sprintf("more than one image %s found in shocks docker repo", Dockerimage))
	}

	node = &(*query_response_p).Data[0]
	logger.Debug(1, fmt.Sprintf("found SHOCK node for docker image: %s", node.Id))

	download_url, err = shock_docker_repo.Get_node_download_url(*node)
	if err != nil {
		return nil, "", errors.New(fmt.Sprintf("Could not create download url, err=%s", err.Error()))
	}

	return
}

// show functions used in debug
func (qm *CQMgr) ShowWorkQueue() {
	logger.Debug(1, fmt.Sprintf("current queuing workunits (%d)", qm.workQueue.Len()))
	for _, id := range qm.workQueue.List() {
		logger.Debug(1, fmt.Sprintf("workid=%s", id))
	}
	return
}

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 CreateContainer(create_args []string) (container_id string, err error) {

	//docker create [OPTIONS] IMAGE [COMMAND] [ARG...]
	// first line contains ID
	// must have "-t" to attach, this is not documented in docker.

	// prepend "create"
	create_args = append([]string{"create"}, create_args...)

	logger.Debug(1, fmt.Sprintf("(CreateContainer) cmd: %s %s", conf.DOCKER_BINARY, strings.Join(create_args, " ")))

	stdo, _, err := RunCommand(conf.DOCKER_BINARY, create_args...)

	if err != nil {
		logger.Debug(1, fmt.Sprintf("(CreateContainer) cmd.Wait returned error: %s", err.Error()))

		return "", err
	}

	// extract only first line
	endofline := bytes.IndexByte(stdo, '\n')

	stdout_line := ""
	if endofline >= 0 {
		stdout_line = string(stdo[0 : endofline-1])
	} else {
		err = errors.New("docker create returned empty string")
	}

	return stdout_line, err

}

//fetch input data
func MoveInputData(work *core.Workunit) (size int64, err error) {
	for _, io := range work.Inputs {
		inputname := io.FileName
		// skip if NoFile == true
		if !io.NoFile { // is file !
			dataUrl, uerr := io.DataUrl()
			if uerr != nil {
				return 0, uerr
			}
			inputFilePath := fmt.Sprintf("%s/%s", work.Path(), inputname)

			if work.Rank == 0 {
				if conf.CACHE_ENABLED && io.Node != "" {
					if file_path, err := StatCacheFilePath(io.Node); err == nil {
						//make a link in work dir from cached file
						linkname := fmt.Sprintf("%s/%s", work.Path(), inputname)
						fmt.Printf("input found in cache, making link: " + file_path + " -> " + linkname + "\n")
						err = os.Symlink(file_path, linkname)
						if err == nil {
							logger.Event(event.FILE_READY, "workid="+work.Id+";url="+dataUrl)
						}
						return 0, err
					}
				}
			} else {
				dataUrl = fmt.Sprintf("%s&index=%s&part=%s", dataUrl, work.IndexType(), work.Part())
			}
			logger.Debug(2, "mover: fetching input file from url:"+dataUrl)
			logger.Event(event.FILE_IN, "workid="+work.Id+";url="+dataUrl)

			// download file
			if datamoved, _, err := shock.FetchFile(inputFilePath, dataUrl, work.Info.DataToken, io.Uncompress, false); err != nil {
				return size, errors.New("shock.FetchFile returned: " + err.Error())
			} else {
				size += datamoved
			}
			logger.Event(event.FILE_READY, "workid="+work.Id+";url="+dataUrl)
		}

		// download node attributes if requested
		if io.AttrFile != "" {
			// get node
			node, err := shock.ShockGet(io.Host, io.Node, work.Info.DataToken)
			if err != nil {
				//return size, err
				return size, errors.New("shock.ShockGet (node attributes) returned: " + err.Error())
			}
			logger.Debug(2, "mover: fetching input attributes from node:"+node.Id)
			logger.Event(event.ATTR_IN, "workid="+work.Id+";node="+node.Id)
			// print node attributes
			attrFilePath := fmt.Sprintf("%s/%s", work.Path(), io.AttrFile)
			attr_json, _ := json.Marshal(node.Attributes)
			if err := ioutil.WriteFile(attrFilePath, attr_json, 0644); err != nil {
				return size, err
			}
			logger.Event(event.ATTR_READY, "workid="+work.Id+";path="+attrFilePath)
		}
	}
	return
}

func (qm *ServerMgr) createOutputNode(task *Task) (err error) {

	outputs := task.Outputs
	for _, io := range outputs {
		name := io.FileName
		if io.Type == "update" {
			// this an update output, it will update an existing shock node and not create a new one
			if (io.Node == "") || (io.Node == "-") {
				if io.Origin == "" {
					return errors.New(fmt.Sprintf("update output %s in task %s is missing required origin", name, task.Id))
				}
				nodeid, err := qm.locateUpdate(task.Id, name, io.Origin)
				if err != nil {
					return err
				}
				io.Node = nodeid
			}
			logger.Debug(2, fmt.Sprintf("outout %s in task %s is an update of node %s\n", name, task.Id, io.Node))
		} else {
			// POST empty shock node for this output
			logger.Debug(2, fmt.Sprintf("posting output Shock node for file %s in task %s\n", name, task.Id))
			nodeid, err := PostNodeWithToken(io, task.TotalWork, task.Info.DataToken)
			if err != nil {
				return err
			}
			io.Node = nodeid
			logger.Debug(2, fmt.Sprintf("task %s: output Shock node created, node=%s\n", task.Id, nodeid))
		}
	}
	return
}

func (appr AppRegistry) createIOnodes(job *Job) (err error) {

	// go over tasks

	taskid2task := make(map[string]*Task)
	taskid_processed := make(map[string]bool)

	// create taskid2task
	for _, task := range job.Tasks {

		taskid_split := strings.Split(task.Id, "_")
		taskid := taskid_split[1]
		_, ok := taskid2task[taskid]
		if ok {
			err = errors.New("error: task id not unique, id=" + taskid)
			return
		}
		taskid2task[taskid] = task
		logger.Debug(1, fmt.Sprintf("--------adding to taskid2task map: %s", taskid))
	}

	for _, task := range job.Tasks {

		err = appr.createIOnodes_forTask(job, task, taskid2task, taskid_processed)
		if err != nil {
			return errors.New(fmt.Sprintf("error in task %s: %s", task.App.Name, err.Error()))
		}
	}

	logger.Debug(1, fmt.Sprintf("+++ +++ createIONodesm finished"))
	return
}

func (acm AppCommandMode) Get_default_app_variables() (app_variables AppVariables, err error) {
	app_variables = make(AppVariables)
	// this function is called on the server

	// *** app input arguments (app definition)
	logger.Debug(1, fmt.Sprintf("Get_default_app_variables: size of acm.Input=%d", len(acm.Input)))
	time.Sleep(15 * time.Millisecond)
	for _, input_arg := range acm.Input {
		//logger.Debug(1, fmt.Sprintf("app input arg: %s", strings.Join(input_arg, ", ")))

		// save the defaults if available

		logger.Debug(1, fmt.Sprintf("from app-definition: variable \"%s\"", input_arg.Name))
		app_type, err := String2apptype(input_arg.Type)
		if err != nil {
			err = errors.New(fmt.Sprintf("error converting type, error=%s", err.Error()))
			return app_variables, err
		}
		logger.Debug(1, fmt.Sprintf("from app-definition: variable \"%s\" has type %s", input_arg.Name, apptype2string(app_type)))

		logger.Debug(1, fmt.Sprintf("from app-definition: write variable:\"%s\" - default value: \"%s\"", input_arg.Name, input_arg.DefaultValue))
		app_variables[input_arg.Name] = AppVariable{Key: input_arg.Name,
			Var_type: app_type,
			Value:    input_arg.DefaultValue,
			Option:   input_arg.Option,
			Optional: input_arg.Optional}

	}

	return
}

//fetch prerequisite data (e.g. reference dbs)
func movePreData(workunit *core.Workunit) (size int64, err error) {
	for name, io := range workunit.Predata {
		predata_directory := path.Join(conf.DATA_PATH, "predata")
		err = os.MkdirAll(predata_directory, 755)
		if err != nil {
			return 0, errors.New("error creating predata_directory: " + err.Error())
		}

		file_path := path.Join(predata_directory, name)
		if !isFileExisting(file_path) {

			size, err = shock.FetchFile(file_path, io.Url, workunit.Info.DataToken, io.Uncompress)
			if err != nil {
				return 0, errors.New("error in fetchFile:" + err.Error())
			}
		}

		use_symlink := false
		linkname := path.Join(workunit.Path(), name)
		if workunit.Cmd.Dockerimage != "" || strings.HasPrefix(workunit.Cmd.Name, "app:") { // TODO need more save way to detect use of docker

			use_symlink = false // TODO mechanism

			if use_symlink {
				file_path = path.Join(conf.DOCKER_WORKUNIT_PREDATA_DIR, name)
				// some tasks want to write in predata dir, thus need symlink
				logger.Debug(1, "dangling symlink:"+linkname+" -> "+file_path)

				// creation of dangling symlinks is not possible with with os.Symlink, thus use system ln
				link_out, err := exec.Command("ln", "-s", file_path, linkname).CombinedOutput()
				logger.Debug(1, fmt.Sprintf("ln returned %s", link_out))

				if err != nil {
					return 0, errors.New("error creating predata file symlink (dangling version): " + err.Error())
				}
			} else {
				// some programs do not accept symlinks (e.g. emirge), need to copy the file into the work directory
				// linkname refers to target file now.
				logger.Debug(1, "copy predata:"+file_path+" -> "+linkname)

				_, err := shock.CopyFile(file_path, linkname)
				if err != nil {
					return 0, fmt.Errorf("error copying file from %s to % s: ", file_path, linkname, err.Error())
				}
			}
		} else {

			//linkname := path.Join(workunit.Path(), name)
			logger.Debug(1, "symlink:"+linkname+" -> "+file_path)

			err = os.Symlink(file_path, linkname)
			if err != nil {
				return 0, errors.New("error creating predata file symlink: " + err.Error())
			}
		}

	}
	return
}

func InspectImage(client *docker.Client, dockerimage_id string) (image *docker.Image, err error) {
	logger.Debug(1, fmt.Sprintf("(InspectImage) %s:", dockerimage_id))
	if client == nil {
		// if image does not exists, return status 1 and text on stderr

		cmd := exec.Command(conf.DOCKER_BINARY, "inspect", dockerimage_id)

		stdout, err := cmd.StdoutPipe()
		if err != nil {
			return nil, err
		}

		stderr, err := cmd.StderrPipe()
		if err != nil {
			return nil, err
		}

		if err = cmd.Start(); err != nil {
			return nil, err
		}

		var image_array []docker.Image

		err_json := json.NewDecoder(stdout).Decode(&image_array)

		if err_json != nil {
			logger.Debug(1, fmt.Sprintf("(InspectImage) err_json: %s", err_json.Error()))
			image = nil
		}

		err = cmd.Wait() // wait just in case

		if err != nil {

			stderr_bytearray, err_read := ioutil.ReadAll(stderr)
			if err_read != nil {
				return nil, err_read
			}
			logger.Debug(1, fmt.Sprintf("(InspectImage) STDERR: %s", stderr_bytearray))
			return nil, err
		} else {
			err = err_json // in case that failed...
		}

		if len(image_array) == 1 {
			image = &image_array[0]
		} else {
			err = errors.New("error: inspect returned zero (or more than one) images")
		}

		return image, err
	} else {

		image, err = client.InspectImage(dockerimage_id)

	}
	return image, err
}

func (sc *ShockClient) Get_request(resource string, query url.Values, response interface{}) (err error) {

	logger.Debug(1, fmt.Sprint("string_url: ", sc.Host))

	myurl, err := url.ParseRequestURI(sc.Host)
	if err != nil {
		return err
	}

	(*myurl).Path = resource
	(*myurl).RawQuery = query.Encode()

	shockurl := myurl.String()

	logger.Debug(1, fmt.Sprint("shock request url: ", shockurl))

	if len(shockurl) < 5 {
		return errors.New("could not parse SHOCK_DOCKER_IMAGE_REPOSITORY")
	}

	var res *http.Response

	c := make(chan int, 1)
	go func() {
		res, err = httpclient.Get(shockurl, httpclient.Header{}, nil, nil)
		c <- 1 //we are ending
	}()
	select {
	case <-c:
	//go ahead
	case <-time.After(conf.SHOCK_TIMEOUT):
		return errors.New("timeout when getting node from shock, url=" + shockurl)
	}
	if err != nil {
		return
	}
	defer res.Body.Close()

	jsonstream, err := ioutil.ReadAll(res.Body)
	//logger.Debug(1, string(jsonstream))
	if err != nil {
		return err
	}

	//response := new(result)
	if err := json.Unmarshal(jsonstream, response); err != nil {
		return err
	}
	//if len(response.Errs) > 0 {
	//	return errors.New(strings.Join(response.Errs, ","))
	//}
	//node = &response.Data
	//if node == nil {
	//	err = errors.New("empty node got from Shock")
	//}
	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
}