Golang util.Log函数代码示例

// Sends a "new_server" or "confirm_new_server" message to target.
//  header: "new_server" or "confirm_new_server"
//  target: e.g. 1.2.3.4:20081
func Send_new_server(header string, target string) {
	keys := db.ServerKeys(target)
	if len(keys) == 0 {
		util.Log(0, "ERROR! Send_new_server: No key known for %v", target)
		return
	}

	msg := xml.NewHash("xml", "header", header)
	msg.Add(header)
	msg.Add("source", config.ServerSourceAddress)
	msg.Add("macaddress", config.MAC)
	msg.Add("loaded_modules", "gosaTriggered")
	msg.Add("loaded_modules", "siTriggered")
	msg.Add("loaded_modules", "logHandling")
	msg.Add("loaded_modules", "databases")
	msg.Add("loaded_modules", "server_server_com")
	msg.Add("loaded_modules", "clMessages")
	msg.Add("loaded_modules", "goSusi")
	msg.Add("key", keys[0])
	msg.Add("target", target)

	serverpackageskey := config.ModuleKey["[ServerPackages]"]

	util.Log(2, "DEBUG! Sending %v to %v encrypted with key %v", header, target, serverpackageskey)
	Peer(target).Tell(msg.String(), serverpackageskey)
}

// Updates the list of all releases
func FAIReleasesListUpdate() {
	all_releases_mutex.Lock()
	defer all_releases_mutex.Unlock()

	all_releases = map[string]bool{}

	// NOTE: config.UnitTagFilter is not used here because unit tag filtering is done
	// in the FAIClasses() query.
	x, err := xml.LdifToHash("fai", true, ldapSearchBase(config.FAIBase, "objectClass=FAIbranch", "dn"))
	if err != nil {
		util.Log(0, "ERROR! LDAP error while trying to determine list of FAI releases: %v", err)
		return
	}

	for fai := x.First("fai"); fai != nil; fai = fai.Next() {
		dn := fai.Text("dn")
		release := extractReleaseFromFAIClassDN("ou=foo,ou=disk," + dn)
		if release == "" {
			continue
		}
		all_releases[release] = true
	}

	util.Log(1, "INFO! FAIReleasesListUpdate() found the following releases: %v", all_releases)
}

// Tries to send a WOL to the given MAC. Returns true if one or more WOL packets were sent
// or false if no subnet for the MAC is known or reachable.
// NOTE: That this function returns true does not mean that the WOL has reached its target.
func TriggerWake(macaddress string) bool {
	wake_target := []string{}
	if system := db.ServerWithMAC(macaddress); system != nil {
		wake_target = append(wake_target, strings.Split(system.Text("source"), ":")[0])
	}
	if system := db.ClientWithMAC(macaddress); system != nil {
		wake_target = append(wake_target, strings.Split(system.Text("client"), ":")[0])
	}
	if system := db.SystemFullyQualifiedNameForMAC(macaddress); system != "none" {
		wake_target = append(wake_target, system)
	}

	woken := false
	for i := range wake_target {
		if err := util.Wake(macaddress, wake_target[i]); err == nil {
			util.Log(1, "INFO! Sent Wake-On-LAN for MAC %v to %v", macaddress, wake_target[i])
			woken = true
			// We do not break here, because the data in the serverDB or clientDB may
			// be stale and since we're sending UDP packets, there's no guarantee
			// that util.Wake() will fail even if the system is no longer there.
			// Since the WOL packets include the MAC address it can't hurt to
			// send more than necessary.
		} else {
			util.Log(0, "ERROR! Could not send Wake-On-LAN for MAC %v to %v: %v", macaddress, wake_target[i], err)
		}
	}

	return woken
}

// Handles the message "CLMSG_PROGRESS".
//  xmlmsg: the decrypted and parsed message
func clmsg_progress(xmlmsg *xml.Hash) {
	macaddress := xmlmsg.Text("macaddress")
	progress := xmlmsg.Text("CLMSG_PROGRESS")

	// ATTENTION! The CLMSG_PROGRESS message may be generated by clmsg_save_fai_log()!
	//            In that case fields <header> and <source> are missing!

	util.Log(1, "INFO! Progress info from client %v with MAC %v: %v", xmlmsg.Text("source"), macaddress, progress)
	// Because we don't know what kind of job the progress is for, we update
	// all local jobs in status processing for the client's MAC.
	// In theory only one job should be in status processing for a single client at
	// any given time, but sometimes jobs get "lost", typically through manual
	// intervention. Progressing all jobs in lockstep has the nice side effect of
	// taking such old stuck jobs along.
	all_processing_jobs_for_mac := xml.FilterSimple("siserver", config.ServerSourceAddress,
		"status", "processing",
		"macaddress", macaddress)
	// the additional comparisons with "0" and "100" are there to allow overwriting
	// non-numerical progress values such as "hardware-detection".
	do_not_run_progress_backwards := xml.FilterOr([]xml.HashFilter{xml.FilterRel("progress", progress, -1, -1), xml.FilterRel("progress", "0", -1, -1), xml.FilterRel("progress", "100", 1, 1)})
	filter := xml.FilterAnd([]xml.HashFilter{all_processing_jobs_for_mac, do_not_run_progress_backwards})
	db.JobsModifyLocal(filter, xml.NewHash("job", "progress", progress))
	if progress == "100" {
		util.Log(1, "INFO! Progress 100%% => Setting status \"done\" for client %v with MAC %v", xmlmsg.Text("source"), macaddress)
		db.JobsModifyLocal(all_processing_jobs_for_mac, xml.NewHash("job", "status", "done"))
		// Setting faistate => "localboot" is done in action/process_act.go in reaction
		// to the removal of the job.
	}
}

// Initializes serverDB with data from the file config.ServerDBPath if it exists,
// as well as the list of peer servers from DNS and [ServerPackages]/address.
// Not an init() because main() needs to set up some things first.
func ServersInit() {
	db_storer := &LoggingFileStorer{xml.FileStorer{config.ServerDBPath}}
	var delay time.Duration = config.DBPersistDelay
	serverDB = xml.NewDB("serverdb", db_storer, delay)
	if !config.FreshDatabase {
		xmldata, err := xml.FileToHash(config.ServerDBPath)
		if err != nil {
			if os.IsNotExist(err) {
				/* File does not exist is not an error that needs to be reported */
			} else {
				util.Log(0, "ERROR! ServersInit reading '%v': %v", config.ServerDBPath, err)
			}
		} else {
			serverDB.Init(xmldata)
		}
	}

	if config.DNSLookup {
		addServersFromDNS()
	} else {
		util.Log(1, "INFO! DNS lookup disabled. Will not add peer servers from DNS.")
	}
	addServersFromConfig()
	util.Log(1, "INFO! All known peer addresses with duplicates removed: %v", ServerAddresses())
}

func FAIReboot(job *xml.Hash) {
	macaddress := job.Text("macaddress")

	util.Log(0, "INFO! Aborting all running install and softupdate jobs for %v", macaddress)

	delete_system := false
	faistate := "error:fiddledidoo:-1:crit:Job aborted by admin. System in unknown state."
	sys, err := db.SystemGetAllDataForMAC(macaddress, false)
	if err != nil {
		util.Log(0, "ERROR! FAIReboot(): %v", err)
		// do not abort. Killing jobs may still work.
	} else {
		// If the system is in incoming, delete it because faimond-ldap does not
		// cope well with incomplete LDAP objects and tries to boot them from local disk.
		dnparts := strings.SplitN(sys.Text("dn"), ",", 2)
		if len(dnparts) > 1 && strings.HasPrefix(dnparts[1], config.IncomingOU) {
			delete_system = true
		}
	}

	db.SystemForceFAIState(macaddress, faistate)

	if delete_system {
		util.Log(1, "INFO! System %v is in %v => Deleting LDAP entry", macaddress, config.IncomingOU)
		err = db.SystemReplace(sys, nil)
		if err != nil {
			util.Log(0, "ERROR! LDAP error while deleting %v: %v", macaddress, err)
		}
	}
}

// Accepts TCP connections on listener and sends them on the channel tcp_connections.
func acceptConnections(listener *net.TCPListener, tcp_connections chan<- *net.TCPConn) {
	for {
		message := true
		for { // if we've reached the maximum number of connections, wait
			if atomic.AddInt32(&ActiveConnections, 1) <= config.MaxConnections {
				break
			}
			atomic.AddInt32(&ActiveConnections, -1)
			if message {
				util.Log(0, "WARNING! Maximum number of %v active connections reached => Throttling", config.MaxConnections)
				message = false
			}
			time.Sleep(100 * time.Millisecond)
		}
		tcpConn, err := listener.AcceptTCP()
		if err != nil {
			if Shutdown {
				return
			}
			util.Log(0, "ERROR! AcceptTCP: %v", err)
		} else {
			tcp_connections <- tcpConn
		}
	}
}

// Handles all messages of the form "new_*_config" by calling config.NewConfigHookPath.
//  xmlmsg: the decrypted and parsed message
func new_foo_config(xmlmsg *xml.Hash) {
	target := xmlmsg.Text("target")
	if target != "" && target != config.ServerSourceAddress {
		// See https://code.google.com/p/go-susi/issues/detail?id=126
		util.Log(0, "WARNING! Ignoring message with incorrect target: %v", xmlmsg)
		return
	}

	header := xmlmsg.Text("header")
	env := config.HookEnvironment()
	for _, tag := range xmlmsg.Subtags() {
		if tag == header {
			continue
		}
		env = append(env, tag+"="+strings.Join(xmlmsg.Get(tag), "\n"))
	}
	env = append(env, header+"=1")

	cmd := exec.Command(config.NewConfigHookPath)
	cmd.Env = append(env, os.Environ()...)
	util.Log(1, "INFO! Running %v with parameters %v", config.NewConfigHookPath, env)
	out, err := cmd.CombinedOutput()
	if err != nil {
		util.Log(0, "ERROR! Error executing %v: %v (%v)", config.NewConfigHookPath, err, string(out))
	}
}

// Sets the selected system's faistate and removes all running install and update
// jobs affecting the system.
//
// ATTENTION! This function takes a while to complete because it tries multiple
// times if necessary and verifies that the faistate has actually been set.
func SystemForceFAIState(macaddress, faistate string) {
	util.Log(1, "INFO! Forcing faiState for %v to %v", macaddress, faistate)

	// retry for 30s
	endtime := time.Now().Add(30 * time.Second)

	for time.Now().Before(endtime) {
		SystemSetState(macaddress, "faiState", faistate)

		// remove softupdate and install jobs ...
		job_types_to_kill := xml.FilterOr(
			[]xml.HashFilter{xml.FilterSimple("headertag", "trigger_action_reinstall"),
				xml.FilterSimple("headertag", "trigger_action_update")})
		// ... that are already happening or scheduled within the next 5 minutes ...
		timeframe := xml.FilterRel("timestamp", util.MakeTimestamp(time.Now().Add(5*time.Minute)), -1, 0)
		// ... that affect the machine for which we force the faistate
		target := xml.FilterSimple("macaddress", macaddress)
		filter := xml.FilterAnd([]xml.HashFilter{job_types_to_kill,
			timeframe,
			target})
		JobsRemove(filter)

		// Wait a little and see if the jobs are gone
		time.Sleep(3 * time.Second)
		if JobsQuery(filter).FirstChild() == nil { // if all jobs are gone
			// set state again just in case the job removal raced with something that set faistate
			SystemSetState(macaddress, "faiState", faistate)
			return // we're done
		} // else if some jobs remained

		util.Log(1, "INFO! ForceFAIState(%v, %v): Some install/softupdate jobs remain => Retrying", macaddress, faistate)
	}

	util.Log(0, "ERROR! ForceFAIState(%v, %v): Some install/softupdate jobs could not be removed.", macaddress, faistate)
}

// Returns the IP address (IPv4 if possible) for the machine with the given name.
// The name may or may not include a domain.
// Returns "none" if the IP address could not be determined.
//
// ATTENTION! This function accesses a variety of external sources
// and may therefore take a while. If possible you should use it asynchronously.
func SystemIPAddressForName(host string) string {
	ip, err := util.Resolve(host, config.IP)
	if err != nil {
		// if host already contains a domain, give up
		if strings.Index(host, ".") >= 0 {
			util.Log(0, "ERROR! Resolve(\"%v\"): %v", host, err)
			return "none"
		}

		// if host does not contain a domain the DNS failure may simple be
		// caused by the machine being in a different subdomain. Try to
		// work around this by searching LDAP for the machine and use its
		// ipHostNumber if it is accurate.
		util.Log(1, "INFO! Could not resolve short name %v (error: %v). Trying LDAP.", host, err)
		var system *xml.Hash
		system, err = xml.LdifToHash("", true, ldapSearch(fmt.Sprintf("(&(objectClass=GOhard)(|(cn=%v)(cn=%v.*))%v)", LDAPFilterEscape(host), LDAPFilterEscape(host), config.UnitTagFilter), "ipHostNumber"))
		// the search may give multiple results. Use reverse lookup of ipHostNumber to
		// find the correct one (if there is one)
		for ihn := system.First("iphostnumber"); ihn != nil; ihn = ihn.Next() {
			ip := ihn.Text()
			fullname := SystemNameForIPAddress(ip)
			if strings.HasPrefix(fullname, host+".") {
				util.Log(1, "INFO! Found \"%v\" with IP %v in LDAP", fullname, ip)
				// use forward lookup for the full name to be sure we get the proper address
				return SystemIPAddressForName(fullname)
			}
		}
		util.Log(0, "ERROR! Could not get reliable IP address for %v from LDAP", host)
		return "none"
	}

	return ip
}

// Handles the message "gosa_show_log_files_by_date_and_mac".
//  xmlmsg: the decrypted and parsed message
// Returns:
//  unencrypted reply
func gosa_show_log_files_by_date_and_mac(xmlmsg *xml.Hash) *xml.Hash {
	macaddress := xmlmsg.Text("mac")
	lmac := strings.ToLower(macaddress)
	subdir := xmlmsg.Text("date")

	if !macAddressRegexp.MatchString(macaddress) {
		emsg := fmt.Sprintf("Illegal or missing <mac> element in message: %v", xmlmsg)
		util.Log(0, "ERROR! %v", emsg)
		return ErrorReplyXML(emsg)
	}

	// As a precaution, make sure subdir contains no slashes.
	subdir = strings.Replace(subdir, "/", "_", -1)

	if subdir == "" {
		emsg := fmt.Sprintf("Missing or empty <date> element in message: %v", xmlmsg)
		util.Log(0, "ERROR! %v", emsg)
		return ErrorReplyXML(emsg)
	}

	header := "show_log_files_by_date_and_mac"
	x := xml.NewHash("xml", "header", header)
	x.Add(header)

	logdir := path.Join(config.FAILogPath, lmac, subdir)

	util.Log(2, "DEBUG! Listing log files from %v", logdir)

	names := []string{}

	dir, err := os.Open(logdir)
	if err == nil || !os.IsNotExist(err.(*os.PathError).Err) {
		if err != nil {
			util.Log(0, "ERROR! gosa_show_log_files_by_date_and_mac: %v", err)
		} else {
			defer dir.Close()

			fi, err := dir.Readdir(0)
			if err != nil {
				util.Log(0, "ERROR! gosa_show_log_files_by_date_and_mac: %v", err)
			} else {
				for _, info := range fi {
					// only list ordinary files
					if info.Mode()&^os.ModePerm == 0 {
						names = append(names, info.Name())
					}
				}
				sort.Strings(names)
				for _, n := range names {
					x.Add(header, n)
				}
			}
		}
	}

	x.Add("source", config.ServerSourceAddress)
	x.Add("target", "GOSA")
	x.Add("session_id", "1")
	return x
}

// Accepts UDP connections for TFTP requests on listen_address, serves read requests
// for path P based on request_re and reply as follows:
//
// request_re and reply have to be lists of
// equal length. Let request_re[i] be the first entry in request_re that
// matches P, then reply[i] specifies the data to return for the request.
// If reply[i] == "", then a file not found error is returned to the requestor.
// If reply[i] starts with the character '|', the remainder is taken as the path
// of a hook to execute and its stdout is returned to the requestor.
// Otherwise reply[i] is taken as the path of the file whose contents to send to
// the requestor.
//
// When executing a hook, an environment variable called "tftp_request"
// is passed containing P. If request_re[i] has a capturing
// group named "macaddress", the captured substring will be converted to
// a MAC address by converting to lowercase, removing all characters
// except 0-9a-f, left-padding to length 12 with 0s or truncating to length 12
// and inserting ":"s. The result will be added to
// the hook environment in a variable named "macaddress" and if there
// is an LDAP object for that macaddress, its attributes will be added
// to the environment, too.
//
// Named subexpressions in request_re[i] other than "macaddress" will be
// exported to the hook verbatim in like-named environment variables.
func ListenAndServe(listen_address string, request_re []*regexp.Regexp, reply []string) {
	for i := range request_re {
		util.Log(1, "INFO! TFTP: %v -> %v", request_re[i], reply[i])
	}

	udp_addr, err := net.ResolveUDPAddr("udp", listen_address)
	if err != nil {
		util.Log(0, "ERROR! Cannot start TFTP server: %v", err)
		return
	}

	udp_conn, err := net.ListenUDP("udp", udp_addr)
	if err != nil {
		util.Log(0, "ERROR! ListenUDP(): %v", err)
		return
	}
	defer udp_conn.Close()

	readbuf := make([]byte, 16384)
	for {
		n, return_addr, err := udp_conn.ReadFromUDP(readbuf)
		if err != nil {
			util.Log(0, "ERROR! ReadFromUDP(): %v", err)
			continue
		}

		// Make a copy of the buffer BEFORE starting the goroutine to prevent subsequent requests from
		// overwriting the buffer.
		payload := string(readbuf[:n])

		go util.WithPanicHandler(func() { handleConnection(return_addr, payload, request_re, reply) })

	}
}

// Tries to re-establish communication with a client/server at the given IP,
// by
//   1) sending here_i_am to the server where we are registered. We do this
//      even if config.RunServer (i.e. we are registered at ourselves) because
//      this will trigger new_foreign_client messages sent to peers so that other
//      servers that may believe they own us correct their data.
//   2) sending (if config.RunServer) new_server messages to all known servers
//      we find for the IP in our servers database.
//   3) if config.RunServer and in 2) we did not find a server at that IP,
//      maybe it's a client that thinks we are its server. Send "deregistered" to
//      all ClientPorts in that case to cause re-registration.
func tryToReestablishCommunicationWith(ip string) {
	// Wait a little to limit the rate of spam wars between
	// 2 machines that can't re-establish communication (e.g. because of changed
	// keys in server.conf).
	mapIP2ReestablishDelay_mutex.Lock()
	var delay time.Duration
	var ok bool
	if delay, ok = mapIP2ReestablishDelay[ip]; !ok {
		delay = 1 * time.Minute
	}
	mapIP2ReestablishDelay[ip] = 2 * delay
	mapIP2ReestablishDelay_mutex.Unlock()

	// if the delay exceeds 24h this means that we got multiple
	// reestablish requests while we're still waiting to begin one
	// in that case, bail out.
	if delay > 24*time.Hour {
		return
	}

	util.Log(0, "WARNING! Will try to re-establish communication with %v after waiting %v", ip, delay)
	time.Sleep(delay)

	// if we actually completed a 10h wait, reset the timer to 1 minute
	if delay >= 10*time.Hour {
		mapIP2ReestablishDelay_mutex.Lock()
		mapIP2ReestablishDelay[ip] = 1 * time.Minute
		mapIP2ReestablishDelay_mutex.Unlock()
	}

	util.Log(0, "WARNING! Will try to re-establish communication with %v", ip)
	ConfirmRegistration() // 1)

	ip, err := util.Resolve(ip, config.IP)
	if err != nil {
		util.Log(0, "ERROR! Resolve(): %v", err)
	}

	if config.RunServer { // 2)
		sendmuell := true
		for _, server := range db.ServerAddresses() {
			if strings.HasPrefix(server, ip) {
				sendmuell = false
				srv := server
				go util.WithPanicHandler(func() { Send_new_server("new_server", srv) })
			}
		}

		if sendmuell {
			for _, port := range config.ClientPorts {
				addr := ip + ":" + port
				if addr != config.ServerSourceAddress { // never send "deregistered" to our own server
					dereg := "<xml><header>deregistered</header><source>" + config.ServerSourceAddress + "</source><target>" + addr + "</target></xml>"
					go security.SendLnTo(addr, dereg, "", false)
				}
			}
		}
	}
}

func handle_tlsconn(conn *tls.Conn, context *Context) bool {
	conn.SetDeadline(time.Now().Add(config.TimeoutTLS))
	err := conn.Handshake()
	if err != nil {
		util.Log(0, "ERROR! [SECURITY] TLS Handshake: %v", err)
		return false
	}

	var no_deadline time.Time
	conn.SetDeadline(no_deadline)

	state := conn.ConnectionState()
	if len(state.PeerCertificates) == 0 {
		util.Log(0, "ERROR! [SECURITY] TLS peer has no certificate")
		return false
	}
	cert := state.PeerCertificates[0] // docs are unclear about this but I think leaf certificate is the first entry because that's as it is in tls.Certificate

	if util.LogLevel >= 2 { // because creating the dump is expensive
		util.Log(2, "DEBUG! [SECURITY] Peer certificate presented by %v:\n%v", conn.RemoteAddr(), CertificateInfo(cert))
	}

	for _, cacert := range config.CACert {
		err = cert.CheckSignatureFrom(cacert)
		if err == nil {
			if string(cacert.RawSubject) != string(cert.RawIssuer) {
				err = fmt.Errorf("Certificate was issued by wrong CA: \"%v\" instead of \"%v\"", cacert.Subject, cert.Issuer)
			} else {
				break // stop checking if we found a match for a CA. err == nil here!
			}
		}
	}

	if err != nil {
		util.Log(0, "ERROR! [SECURITY] TLS peer presented certificate not signed by trusted CA: %v", err)
		return false
	}

	for _, e := range cert.Extensions {
		if len(e.Id) == 4 && e.Id[0] == 2 && e.Id[1] == 5 && e.Id[2] == 29 && e.Id[3] == 17 {
			parseSANExtension(e.Value, context)
		} else if len(e.Id) == 9 && e.Id[0] == 1 && e.Id[1] == 3 && e.Id[2] == 6 && e.Id[3] == 1 && e.Id[4] == 4 && e.Id[5] == 1 && e.Id[6] == 45753 && e.Id[7] == 1 {
			switch e.Id[8] {
			case 5:
				err = parseConnectionLimits(e.Value, context)
				if err != nil {
					util.Log(0, "ERROR! [SECURITY] GosaConnectionLimits: %v", err)
				}
			case 6: //err = parseAccessControl(e.Value, context)
				//if err != nil { util.Log(0, "ERROR! [SECURITY] GosaAccessControl: %v", err) }
			}

		}
	}

	context.TLS = true

	return true
}

// Tells this connection if its peer
// advertises <loaded_modules>goSusi</loaded_modules>.
func (conn *PeerConnection) SetGoSusi(is_gosusi bool) {
	if is_gosusi {
		util.Log(1, "INFO! Peer %v uses go-susi protocol", conn.addr)
	} else {
		util.Log(1, "INFO! Peer %v uses old gosa-si protocol", conn.addr)
	}
	conn.is_gosusi = is_gosusi
}