// Like GosaDecrypt() but operates in-place on buf. // Returns true if decryption successful and false if not. // If false is returned, the buffer contents may be destroyed, but only // if further decryption attempts with other keys would be pointless anyway, // because of some fatal condition (such as the data not being a multiple of // the cipher's block size). func GosaDecryptBuffer(buf *bytes.Buffer, key string) bool { buf.TrimSpace() if buf.Len() < 11 { return false } // minimum length of unencrypted <xml></xml> data := buf.Bytes() if string(data[0:5]) == "<xml>" { return true } // Fixes the following: // * gosa-si bug in the following line: // if( $client_answer =~ s/session_id=(\d+)$// ) { // This leaves the "." before "session_id" which breaks base64 // * new gosa-si protocol has ";IP:PORT" appended to message // which also breaks base64 for semicolon_period := 0; semicolon_period < len(data); semicolon_period++ { if data[semicolon_period] == ';' || data[semicolon_period] == '.' { buf.Trim(0, semicolon_period) data = buf.Bytes() break } } aescipher, _ := aes.NewCipher([]byte(util.Md5sum(key))) crypter := cipher.NewCBCDecrypter(aescipher, config.InitializationVector) cryptotest := make([]byte, (((3*aes.BlockSize)+2)/3)<<2) n := copy(cryptotest, data) cryptotest = cryptotest[0:n] cryptotest = util.Base64DecodeInPlace(cryptotest) n = (len(cryptotest) / aes.BlockSize) * aes.BlockSize cryptotest = cryptotest[0:n] crypter.CryptBlocks(cryptotest, cryptotest) if !strings.Contains(string(cryptotest), "<xml>") { return false } data = util.Base64DecodeInPlace(data) buf.Trim(0, len(data)) data = buf.Bytes() if buf.Len()%aes.BlockSize != 0 { // this condition is fatal => further decryption attempts are pointless buf.Reset() return false } crypter = cipher.NewCBCDecrypter(aescipher, config.InitializationVector) crypter.CryptBlocks(data, data) buf.TrimSpace() // removes 0 padding, too return true }
func faiConnection(conn *net.TCPConn) { defer conn.Close() var err error err = conn.SetKeepAlive(true) if err != nil { util.Log(0, "ERROR! SetKeepAlive: %v", err) } var buf bytes.Buffer defer buf.Reset() readbuf := make([]byte, 4096) n := 1 for n != 0 { n, err = conn.Read(readbuf) if err != nil && err != io.EOF { util.Log(0, "ERROR! Read: %v", err) } if n == 0 && err == nil { util.Log(0, "ERROR! Read 0 bytes but no error reported") } // Find complete lines terminated by '\n' and process them. for start := 0; ; { eol := start for ; eol < n; eol++ { if readbuf[eol] == '\n' { break } } // no \n found, append to buf and continue reading if eol == n { buf.Write(readbuf[start:n]) break } // append to rest of line to buffered contents buf.Write(readbuf[start:eol]) start = eol + 1 buf.TrimSpace() util.Log(2, "DEBUG! FAI monitor message from %v: %v", conn.RemoteAddr(), buf.String()) buf.Reset() } } if buf.Len() != 0 { util.Log(2, "DEBUG! Incomplete FAI monitor message (i.e. not terminated by \"\\n\") from %v: %v", conn.RemoteAddr(), buf.String()) } }
// Replaces the contents of buf with the base64 representation of the data // after encryption with the given key. // The key is a word as used in gosa-si.conf whose md5sum will be used as // the actual AES key. buf is empty, it won't be changed. func GosaEncryptBuffer(buf *bytes.Buffer, key string) { datalen := buf.Len() if datalen == 0 { return } ciph, _ := aes.NewCipher([]byte(util.Md5sum(key))) crypter := cipher.NewCBCEncrypter(ciph, config.InitializationVector) cryptpad := (aes.BlockSize - datalen%aes.BlockSize) &^ aes.BlockSize cryptlen := cryptpad + datalen b64len := ((cryptlen + 2) / 3) << 2 for i := datalen; i < b64len; i++ { buf.WriteByte(0) } data := buf.Bytes() copy(data[b64len-datalen:], data) // move data back idx := b64len - cryptlen copy(data[idx:], make([]byte, cryptpad)) // insert 0s in front crypter.CryptBlocks(data[idx:], data[idx:]) util.Base64EncodeInPlace(data, idx) }
// Handles the message "gosa_get_log_file_by_date_and_mac". // xmlmsg: the decrypted and parsed message // Returns: // unencrypted reply func gosa_get_log_file_by_date_and_mac(xmlmsg *xml.Hash) *xml.Hash { macaddress := xmlmsg.Text("mac") lmac := strings.ToLower(macaddress) subdir := xmlmsg.Text("date") log_file := xmlmsg.Text("log_file") header := "get_log_file_by_date_and_mac" x := xml.NewHash("xml", "header", header) x.Add(header) x.Add("source", config.ServerSourceAddress) x.Add("target", "GOSA") x.Add("session_id", "1") 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 and log_file contain no slashes. subdir = strings.Replace(subdir, "/", "_", -1) log_file = strings.Replace(log_file, "/", "_", -1) if subdir == "" { // When you open the installation logs in GOsa for the first time, GOsa sends // a broken request that is characterized by an empty <date> and log_file==0. // If we return an error, GOsa presents it to the user which // gives a bad experience. So we instead return an empty reply in this special case. if log_file == "0" { return x } emsg := fmt.Sprintf("Missing or empty <date> element in message: %v", xmlmsg) util.Log(0, "ERROR! %v", emsg) return ErrorReplyXML(emsg) } if log_file == "" { emsg := fmt.Sprintf("Missing or empty <log_file> element in message: %v", xmlmsg) util.Log(0, "ERROR! %v", emsg) return ErrorReplyXML(emsg) } f, err := os.Open(path.Join(config.FAILogPath, lmac, subdir, log_file)) if err != nil { emsg := fmt.Sprintf("gosa_get_log_file_by_date_and_mac: %v", err) util.Log(0, "ERROR! %v", emsg) return ErrorReplyXML(emsg) } defer f.Close() var b bytes.Buffer defer b.Reset() buffy := make([]byte, 65536) for { n, err := f.Read(buffy) b.Write(buffy[0:n]) if err == io.EOF { break } if err != nil { emsg := fmt.Sprintf("gosa_get_log_file_by_date_and_mac: %v", err) util.Log(0, "ERROR! %v", emsg) return ErrorReplyXML(emsg) } if n == 0 { util.Log(0, "WARNING! Read returned 0 bytes but no error. Assuming EOF") break } } idx := (((b.Len() + 2) / 3) << 2) - b.Len() b.Write0(idx) data := b.Bytes() copy(data[idx:], data) data = util.Base64EncodeInPlace(data, idx) data_element := x.Add(log_file) // To reduce memory leak potential, we append in pieces rather than as one large string end := xml.MaxFragmentLength for ; end < len(data); end += xml.MaxFragmentLength { data_element.AppendString(string(data[end-xml.MaxFragmentLength : end])) } data_element.AppendString(string(data[end-xml.MaxFragmentLength:])) return x }
// Executes program and reads from its standard output log files to transfer to // the target server. See fai-savelog-hook in the manual. func Send_clmsg_save_fai_log(target string, program string) { var buffy bytes.Buffer defer buffy.Reset() clientpackageskey := config.ModuleKey["[ClientPackages]"] // If [ClientPackages]/key missing, take the last key in the list // (We don't take the 1st because that would be "dummy-key"). if clientpackageskey == "" { clientpackageskey = config.ModuleKeys[len(config.ModuleKeys)-1] } util.Log(1, "INFO! Launching fai-savelog-hook %v", program) start := time.Now() env := config.HookEnvironment() cmd := exec.Command(program) cmd.Env = append(env, os.Environ()...) out, err := cmd.StdoutPipe() if err != nil { util.Log(0, "ERROR! Could not get stdout pipe for %v: %v", program, err) return } defer out.Close() in, err := cmd.StdinPipe() if err != nil { util.Log(0, "ERROR! Could not get stdin pipe for %v: %v", program, err) return } defer in.Close() err = cmd.Start() if err != nil { util.Log(0, "ERROR! Could not launch %v: %v", program, err) return } buffy.WriteString("<xml><header>CLMSG_save_fai_log</header><source>") buffy.WriteString(config.ServerSourceAddress) buffy.WriteString("</source>") buffy.WriteString("<target>") buffy.WriteString(target) buffy.WriteString("</target>") buffy.WriteString("<macaddress>") buffy.WriteString(config.MAC) buffy.WriteString("</macaddress>") buffy.WriteString("<CLMSG_save_fai_log>") reader := bufio.NewReader(out) fai_action := "" for { line, err := reader.ReadString('\n') if err != nil { util.Log(0, "ERROR! Error reading stdout from %v: %v", program, err) return } line = strings.TrimSpace(line) if line == "install" || line == "softupdate" { fai_action = line break } buffy.WriteString(line) } util.Log(1, "INFO! Received %v bytes in %v from fai-savelog-hook", buffy.Len(), time.Since(start)) buffy.WriteString("</CLMSG_save_fai_log>") buffy.WriteString("<fai_action>") buffy.WriteString(fai_action) buffy.WriteString("</fai_action>") buffy.WriteString("</xml>") util.Log(1, "INFO! Sending %v bytes of log files to %v", buffy.Len(), target) security.SendLnTo(target, buffy.String(), clientpackageskey, false) in.Write([]byte{'\n'}) // notify hook that transfer is complete }
func testBuffer() { var b bytes.Buffer check(b.String(), "") // String() on fresh variable b.Reset() // Reset() on fresh variable check(b.String(), "") // String() after Reset() b.Reset() // Reset() after Reset() check(b.String(), "") check(b.Len(), 0) // same tests as above with pointer b2 := &bytes.Buffer{} check(b2.String(), "") b2.Reset() check(b2.String(), "") b2.Reset() check(b2.String(), "") check(b2.Len(), 0) b2.WriteString("Dies ist ein Test!") check(b2.String(), "Dies ist ein Test!") check(b2.Len(), 18) n, err := b.Write(nil) check(n, 0) check(err, nil) check(b.String(), "") n, err = b.Write([]byte{}) check(n, 0) check(err, nil) check(b.String(), "") check(b.Pointer(), nil) check(b.Capacity(), 0) check(b.Len(), 0) func() { defer func() { check(recover(), bytes.ErrTooLarge) }() b.Grow(-1) }() n, err = b.Write([]byte{'a'}) check(n, 1) check(err, nil) check(b.String(), "a") check(b.Capacity() >= 1, true) check(b.Len(), 1) check(b.Pointer() != nil, true) check(b.Grow(11), 1) check(b.Capacity() >= 12, true) c := b.Capacity() p := b.Pointer() check(b.Grow(11), 1) // should not cause actual growth check(b.Pointer(), p) check(b.Capacity(), c) check(b.Len(), 1) ((*[2]byte)(b.Pointer()))[1] = 'z' check(b.Contains("z"), false) n, err = b.WriteString("Hallo") check(n, 5) check(err, nil) check(b.String(), "aHallo") check(b.Pointer(), p) check(b.Capacity(), c) check(b.Len(), 6) b.Reset() check(b.String(), "") check(b.Pointer(), nil) check(b.Capacity(), 0) check(b.Contains(""), true) check(b.Contains("a"), false) b.WriteString("Hallo") b.WriteByte(' ') b.Write([]byte{'d', 'i', 'e', 's'}) b.WriteByte(' ') b.WriteString("ist ") b.WriteString("ein ") b.Write([]byte("Test")) check(b.String(), "Hallo dies ist ein Test") check(b.Contains("Hallo dies ist ein Test"), true) check(b.Contains("Test"), true) check(b.Contains("Hallo"), true) check(b.Contains("allo"), true) check(b.Contains(""), true) check(b.Split(" "), []string{"Hallo", "dies", "ist", "ein", "Test"}) check(b.Split("X"), []string{"Hallo dies ist ein Test"}) check(b.Split("Hallo dies ist ein Test"), []string{"", ""}) check(b.Split("H"), []string{"", "allo dies ist ein Test"}) check(b.Split("Test"), []string{"Hallo dies ist ein ", ""}) check(b.Split("es"), []string{"Hallo di", " ist ein T", "t"}) b.Reset() b.WriteString(" \n\t Hallo \t\v\n") check(b.Len(), 15) p = b.Pointer() b.TrimSpace() check(b.String(), "Hallo") check(b.Len(), 5) check(b.Pointer(), p) b.Reset() b.WriteString(" \n\t \t\v\n") check(b.Len(), 10) b.TrimSpace() check(b.Pointer(), nil) check(b.Len(), 0) check(b.Capacity(), 0) b.TrimSpace() check(b.Pointer(), nil) check(b.Len(), 0) check(b.Capacity(), 0) b.Reset() b.WriteString(" \n\t Hallo") check(b.Len(), 10) p = b.Pointer() b.TrimSpace() check(b.String(), "Hallo") check(b.Len(), 5) check(b.Pointer(), p) b.Reset() b.WriteString("Hallo \t\v\n") check(b.Len(), 10) p = b.Pointer() b.TrimSpace() check(b.String(), "Hallo") check(b.Len(), 5) check(b.Pointer(), p) b.Reset() b.WriteString(" ") check(b.Len(), 1) b.TrimSpace() check(b.Pointer(), nil) check(b.Len(), 0) check(b.Capacity(), 0) b.Reset() b.WriteString("Der Cottbuser Postkutscher kotzt in den Cottbuser Postkotzkasten") n = b.Len() c = b.Capacity() p = b.Pointer() b.Trim(-10, 2000) check(b.Len(), n) check(b.Capacity(), c) check(b.Pointer(), p) b.Trim(2000, -10) check(b.Len(), 0) check(b.Capacity(), 0) check(b.Pointer(), nil) b.WriteString("Der Cottbuser Postkutscher kotzt in den Cottbuser Postkotzkasten") b.Trim(4, 4) check(b.Len(), 0) check(b.Capacity(), 0) check(b.Pointer(), nil) b.WriteString("Der Cottbuser Postkutscher kotzt in den Cottbuser Postkotzkasten") n = b.Len() c = b.Capacity() p = b.Pointer() b.Trim(0, b.Len()-6) check(b.Len(), n-6) check(b.Capacity(), c) check(b.Pointer(), p) check(b.String(), "Der Cottbuser Postkutscher kotzt in den Cottbuser Postkotz") b.Trim(27, b.Len()) check(b.Len(), n-6-27) check(b.Capacity(), c) check(b.Pointer(), p) check(b.String(), "kotzt in den Cottbuser Postkotz") b.Trim(1, b.Len()-1) check(b.Len(), n-6-27-2) check(b.Capacity(), c) check(b.Pointer(), p) check(b.String(), "otzt in den Cottbuser Postkot") b.Reset() b.Write0(-1) b.Write0(-100) b.Write0(0) check(b.Len(), 0) check(b.Capacity(), 0) check(b.Pointer(), nil) b.Write0(1) check(b.Len(), 1) check(b.Capacity(), 1) check(b.Bytes(), []byte{0}) b.WriteByte(111) b.Write0(1) b.WriteByte(222) b.Write0(2) b.WriteByte(99) check(b.Len(), 7) check(b.Bytes(), []byte{0, 111, 0, 222, 0, 0, 99}) b2.Reset() slices := [][]byte{} total := 0 numfakeerrs := 0 for total < 100000 { c = rand.Intn(30000) total += c sl := make([]byte, c) for i := range sl { sl[i] = byte(rand.Intn(256)) } slices = append(slices, sl) b2.Write(sl) if total/30000 > numfakeerrs { slices = append(slices, nil) numfakeerrs++ } } check(numfakeerrs, 3) slcopy := make([][]byte, len(slices)) copy(slcopy, slices) slret := &sliceReturner{Slices: slcopy} b.Reset() check(b.Capacity(), 0) check(b.Len(), 0) check(b.Pointer(), nil) n = 0 for i := 0; i < numfakeerrs; i++ { n64, err := b.ReadFrom(slret) n += int(n64) check(err, FakeError) } n64, err := b.ReadFrom(slret) n += int(n64) check(err, nil) check(n, total) check(b.Capacity() > b.Len(), true) check(b.Len(), total) contents := b.Bytes() contents2 := b2.Bytes() check(len(contents), len(contents2)) n = 0 for i := range contents { if contents[i] != contents2[i] { break } n++ } check(n, total) b2.Reset() for i := range slices { for k := range slices[i] { slices[i][k] = 11 } n, err = b.Read(slices[i]) check(n, len(slices[i])) check(err, nil) b2.Write(slices[i]) } check(b2.Len(), total) n, err = b.Read(slices[0]) check(n, 0) check(err, io.EOF) contents = b.Bytes() contents2 = b2.Bytes() check(len(contents), len(contents2)) n = 0 for i := range contents { if contents[i] != contents2[i] { break } n++ } check(n, total) b.WriteString("foo") foo := make([]byte, 10) n, err = b.Read(foo) check(n, 3) check(err, nil) check(string(foo[0:3]), "foo") n64, err = b.Seek(6700, 0) check(n64, 6700) check(err, nil) n64, err = b.Seek(-6000, 1) check(n64, 700) check(err, nil) n64, err = b.Seek(815, 1) check(n64, 1515) check(err, nil) n, err = b.Read(foo) check(n, len(foo)) check(err, nil) check(foo, b2.Bytes()[1515:1515+len(foo)]) n64, err = b.Seek(-3, 2) check(n64, total) check(err, nil) n, err = b.Read(foo) check(n, 3) check(err, nil) check(string(foo[0:3]), "foo") n64, err = b.Seek(999999, 0) check(n64, b.Len()) check(err, nil) n64, err = b.Seek(-3, 1) check(n64, total) check(err, nil) n, err = b.Read(foo) check(n, 3) check(err, nil) check(string(foo[0:3]), "foo") n64, err = b.Seek(-815, 0) check(n64, 0) check(err, nil) n, err = b.Read(foo) check(n, len(foo)) check(err, nil) check(foo, b2.Bytes()[0:len(foo)]) }
// Reads the output from the program config.PackageListHookPath (LDIF) and // uses it to replace packagedb. // debconf is passed as PackageListDebconf environment var to the hook. // See manual section on package-list-hook for more info. func PackageListHook(debconf string) { start := time.Now() timestamp := util.MakeTimestamp(start) cmd := exec.Command(config.PackageListHookPath) cmd.Env = append(config.HookEnvironment(), os.Environ()...) fairepos := []string{} for repo := FAIServers().First("repository"); repo != nil; repo = repo.Next() { fairepos = append(fairepos, fmt.Sprintf("%v||%v|%v", repo.Text("server"), repo.Text("repopath"), repo.Text("sections"))) } package_list_params := []string{"PackageListDebconf=" + debconf, "PackageListCacheDir=" + config.PackageCacheDir, "PackageListFAIrepository=" + strings.Join(fairepos, " ")} cmd.Env = append(cmd.Env, package_list_params...) util.Log(1, "INFO! Running package-list-hook: %v %v", strings.Join(package_list_params, " "), config.PackageListHookPath) var outbuf bytes.Buffer defer outbuf.Reset() var errbuf bytes.Buffer defer errbuf.Reset() cmd.Stdout = &outbuf cmd.Stderr = &errbuf err := cmd.Run() if err != nil { util.Log(0, "ERROR! package-list-hook %v: %v (%v)", config.PackageListHookPath, err, errbuf.String()) return } else if errbuf.Len() != 0 { // if the command prints to stderr but does not return non-0 exit status (which // would result in err != nil), we just log a WARNING, but use the stdout data // anyway. util.Log(0, "WARNING! package-list-hook %v: %v", config.PackageListHookPath, errbuf.String()) } plist, err := xml.LdifToHash("pkg", true, outbuf.Bytes(), packageListFormat...) if err != nil { util.Log(0, "ERROR! package-list-hook %v: %v", config.PackageListHookPath, err) return } if plist.First("pkg") == nil { util.Log(0, "ERROR! package-list-hook %v returned no data", config.PackageListHookPath) return } util.Log(1, "INFO! Finished package-list-hook. Running time: %v", time.Since(start)) start = time.Now() plist.Rename("packagedb") new_mapRepoPath2FAIrelease := map[string]string{} accepted := 0 total := 0 for pkg := plist.FirstChild(); pkg != nil; pkg = pkg.Next() { total++ p := pkg.Element() release := p.First("distribution") // packageListFormat translates "release" => "distribution" if release == nil { util.Log(0, "ERROR! package-list-hook %v returned entry without \"Release\": %v", config.PackageListHookPath, p) pkg.Remove() continue } for repopath := p.First("repository"); repopath != nil; repopath = repopath.Next() { new_mapRepoPath2FAIrelease[repopath.Text()] = release.Text() } pkgname := p.Get("package") if len(pkgname) == 0 { if p.First("repository") == nil { // Release/Repository groups without Package are okay, so only log error if there is no Repository util.Log(0, "ERROR! package-list-hook %v returned entry without \"Package\": %v", config.PackageListHookPath, p) } pkg.Remove() continue } if len(pkgname) > 1 { util.Log(0, "ERROR! package-list-hook %v returned entry with multiple \"Package\" values: %v", config.PackageListHookPath, p) pkg.Remove() continue } version := p.First("version") if version == nil { util.Log(0, "WARNING! package-list-hook %v returned entry for \"%v\" without \"Version\". Assuming \"1.0\"", config.PackageListHookPath, pkgname[0]) p.Add("version", "1.0") } section := p.First("section") if section == nil { util.Log(0, "WARNING! package-list-hook %v returned entry for \"%v\" without \"Section\". Assuming \"main\"", config.PackageListHookPath, pkgname[0]) p.Add("section", "main") } p.FirstOrAdd("timestamp").SetText(timestamp) description := p.First("description") if description == nil { description = p.Add("description", pkgname[0]) description.EncodeBase64() } // add empty <template></template> if there is no <template> element. if p.First("template") == nil { p.Add("template") } accepted++ } if accepted == 0 { util.Log(0, "ERROR! package-list-hook %v returned no valid entries", config.PackageListHookPath) } else { util.Log(1, "INFO! package-list-hook: %v/%v entries accepted into database. Processing time: %v", accepted, total, time.Since(start)) packagedb.Init(plist) mapRepoPath2FAIrelease_mutex.Lock() defer mapRepoPath2FAIrelease_mutex.Unlock() mapRepoPath2FAIrelease = new_mapRepoPath2FAIrelease util.Log(1, "INFO! Repository path => FAI release %v", mapRepoPath2FAIrelease) } }
// Takes a possibly encrypted message in buf and processes it, returning a reply. // context is the security context. // Returns: // buffer containing the reply to return (MUST BE FREED BY CALLER VIA Reset()!) // disconnect == true if connection should be terminated due to error // // NOTE: buf IS NOT FREED BY THIS FUNCTION BUT ITS CONTENTS ARE CHANGED! func ProcessEncryptedMessage(buf *bytes.Buffer, context *security.Context) (reply *bytes.Buffer, disconnect bool) { if buf.Len() > 4096 { util.Log(2, "DEBUG! Processing LONG message: (truncated)%v\n.\n.\n.\n%v", string(buf.Bytes()[0:2048]), string(buf.Bytes()[buf.Len()-2048:])) } else { util.Log(2, "DEBUG! Processing message: %v", buf.String()) } for attempt := 0; attempt < 4; attempt++ { if attempt != 0 && config.TLSRequired { util.Log(1, "INFO! [SECURITY] TLS-only mode => Decryption with old protocol will not be attempted") //NOTE: This prevents the last ditch attempt to decrypt with all known // server and client keys. This attempt might still have produced a // result in case the connecting party is pre-TLS and we happen to // have its key in our database (from a time before our server was // configured to be TLS-only). However if the admin configured our // server to be TLS-only (by not putting any keys // in the config) we assume that he does not want pre-TLS // parties to connect. break } var keys_to_try []string switch attempt { case 0: keys_to_try = config.ModuleKeys case 1: host := context.PeerID.IP.String() { keys_to_try = append(db.ServerKeys(host), db.ClientKeys(host)...) if host == "127.0.0.1" { // make sure we find the key even if registered under our external IP address keys_to_try = append(db.ServerKeys(config.IP), db.ClientKeys(config.IP)...) } } case 2: util.Log(1, "INFO! Last resort attempt to decrypt message from %v with all server keys", context.PeerID.IP) keys_to_try = db.ServerKeysForAllServers() case 3: util.Log(1, "INFO! Last resort attempt to decrypt message from %v with all client keys", context.PeerID.IP) keys_to_try = db.ClientKeysForAllClients() } for _, key := range keys_to_try { if security.GosaDecryptBuffer(buf, key) { if buf.Len() > 4096 { util.Log(2, "DEBUG! Decrypted LONG message from %v with key %v: (truncated)%v\n.\n.\n.\n%v", context.PeerID.IP, key, string(buf.Bytes()[0:2048]), string(buf.Bytes()[buf.Len()-2048:])) } else { util.Log(2, "DEBUG! Decrypted message from %v with key %v: %v", context.PeerID.IP, key, buf.String()) } // special case for CLMSG_save_fai_log because this kind of message // is so large and parsing it to XML doesn't really gain us anything. if buf.Contains("<CLMSG_save_fai_log>") { if handleServerMessage() { clmsg_save_fai_log(buf) } return &bytes.Buffer{}, false } xml, err := xml.StringToHash(buf.String()) if err != nil { util.Log(0, "ERROR! %v", err) return ErrorReplyBuffer(err), true } // At this point we have successfully decrypted and parsed the message return ProcessXMLMessage(xml, context, key) } } } // This part is only reached if none of the keys opened the message util.Log(0, "ERROR! Could not decrypt message from %v", context.PeerID.IP) // Maybe we got out of sync with the sender's encryption key // (e.g. by missing a new_key message). Try to re-establish communcation. ip := context.PeerID.IP.To4() if ip == nil { util.Log(0, "ERROR! Cannot convert sender address to IPv4 address: %v", context.PeerID.IP) } else { go tryToReestablishCommunicationWith(ip.String()) } return ErrorReplyBuffer("Could not decrypt message"), true }
// Handles one or more messages received over conn. Each message is a single // line terminated by \n. The message may be encrypted as by security.GosaEncrypt(). func handle_request(tcpconn *net.TCPConn) { defer tcpconn.Close() defer atomic.AddInt32(&ActiveConnections, -1) // defer util.Log(2, "DEBUG! Connection to %v closed", tcpconn.RemoteAddr()) // util.Log(2, "DEBUG! Connection from %v", tcpconn.RemoteAddr()) var err error err = tcpconn.SetKeepAlive(true) if err != nil { util.Log(0, "ERROR! SetKeepAlive: %v", err) } var buf bytes.Buffer defer buf.Reset() readbuf := make([]byte, 4096) var conn net.Conn conn = tcpconn n := 1 if config.TLSServerConfig != nil { // If TLS is required, we need to see a STARTTLS before the timeout. // If TLS is optional we need to accept idle connections for backwards compatibility if config.TLSRequired { conn.SetDeadline(time.Now().Add(config.TimeoutTLS)) } for i := range starttls { n, err = conn.Read(readbuf[0:1]) if n == 0 { if i != 0 { // Do not log an error for a port scan that just opens a connection and closes it immediately util.Log(0, "ERROR! Read error while looking for STARTTLS from %v: %v", conn.RemoteAddr(), err) } return } buf.Write(readbuf[0:1]) if readbuf[0] == '\r' && starttls[i] == '\n' { // Read the \n that must follow \r (we don't support lone CR line endings) conn.Read(readbuf[0:1]) // ignore error. It will pop up again further down the line. } if readbuf[0] != starttls[i] { if config.TLSRequired { util.Log(0, "ERROR! No STARTTLS from %v, but TLS is required", conn.RemoteAddr()) util.WriteAll(conn, []byte(message.ErrorReply("STARTTLS is required to connect"))) return } break } if readbuf[0] == '\n' { buf.Reset() // purge STARTTLS\n from buffer conn = tls.Server(conn, config.TLSServerConfig) } } } context := security.ContextFor(conn) if context == nil { return } for n != 0 { //util.Log(2, "DEBUG! Receiving from %v", conn.RemoteAddr()) n, err = conn.Read(readbuf) if err != nil && err != io.EOF { util.Log(0, "ERROR! Read: %v", err) } if err == io.EOF { util.Log(2, "DEBUG! Connection closed by %v", conn.RemoteAddr()) } if n == 0 && err == nil { util.Log(0, "ERROR! Read 0 bytes but no error reported") } // Find complete lines terminated by '\n' and process them. for start := 0; ; { eol := start for ; eol < n; eol++ { if readbuf[eol] == '\n' { break } } // no \n found, append to buf and continue reading if eol == n { buf.Write(readbuf[start:n]) break } // append to rest of line to buffered contents buf.Write(readbuf[start:eol]) start = eol + 1 buf.TrimSpace() // process the message and get a reply (if applicable) if buf.Len() > 0 { // ignore empty lines request_start := time.Now() reply, disconnect := message.ProcessEncryptedMessage(&buf, context) buf.Reset() request_time := time.Since(request_start) RequestProcessingTimes.Push(request_time) request_time -= RequestProcessingTimes.Next().(time.Duration) atomic.AddInt64(&message.RequestProcessingTime, int64(request_time)) if reply.Len() > 0 { util.Log(2, "DEBUG! Sending %v bytes reply to %v", reply.Len(), conn.RemoteAddr()) var deadline time.Time // zero value means "no deadline" if config.Timeout >= 0 { deadline = time.Now().Add(config.Timeout) } conn.SetWriteDeadline(deadline) _, err := util.WriteAll(conn, reply.Bytes()) if err != nil { util.Log(0, "ERROR! WriteAll: %v", err) } reply.Reset() util.WriteAll(conn, []byte{'\r', '\n'}) } if disconnect { util.Log(1, "INFO! Forcing disconnect of %v because of error", conn.RemoteAddr()) return } if Shutdown { util.Log(1, "INFO! Forcing disconnect of %v because of go-susi shutdown", conn.RemoteAddr()) return } } } } if buf.Len() != 0 { util.Log(0, "ERROR! Incomplete message from %v (i.e. not terminated by \"\\n\") of %v bytes: %v", conn.RemoteAddr(), buf.Len(), buf.String()) } }