func dumpLeveldb(path string) error { db, err := leveldb.OpenFile(path, &opt.Options{ ErrorIfMissing: true, }) if err != nil { if _, ok := err.(*leveldb_errors.ErrCorrupted); !ok { return err } log.Printf("Database is corrupted, trying to recover\n") db, err = leveldb.RecoverFile(path, nil) if err != nil { return fmt.Errorf("Could not recover database: %v\n", err) } } defer db.Close() i := db.NewIterator(nil, nil) defer i.Release() var rlog raft.Log if i.Last() { for bytes.HasPrefix(i.Key(), []byte("stablestore-")) { i.Prev() } for { if err := json.Unmarshal(i.Value(), &rlog); err != nil { log.Fatalf("Corrupted database: %v\n", err) } if rlog.Type == raft.LogCommand { rmsg := types.NewRobustMessageFromBytes(rlog.Data) lastModified = time.Unix(0, rmsg.Id.Id) break } i.Prev() } } i.First() fmt.Printf(fmt.Sprintf("%%%ds", padding)+"\tValue\n", "Key") for i.Next() { if bytes.HasPrefix(i.Key(), []byte("stablestore-")) { // TODO: also dump the stablestore values } else { if err := json.Unmarshal(i.Value(), &rlog); err != nil { log.Fatalf("Corrupted database: %v\n", err) } dumpLog(binary.BigEndian.Uint64(i.Key()), &rlog) } } return nil }
func handleIrclog(w http.ResponseWriter, r *http.Request) { id, err := strconv.ParseInt(r.FormValue("sessionid"), 0, 64) if err != nil || id == 0 { http.Error(w, "Invalid session", http.StatusBadRequest) return } session := types.RobustId{Id: id} // TODO(secure): pagination var messages []*types.RobustMessage first, _ := ircStore.FirstIndex() last, _ := ircStore.LastIndex() for idx := first; idx <= last; idx++ { var elog raft.Log if err := ircStore.GetLog(idx, &elog); err != nil { // Not every message goes into the ircStore (e.g. raft peer change // messages do not). continue } if elog.Type != raft.LogCommand { continue } msg := types.NewRobustMessageFromBytes(elog.Data) if msg.Session.Id == session.Id { messages = append(messages, &msg) } output, ok := ircServer.Get(msg.Id) if ok { for _, msg := range output { if !msg.InterestingFor[session.Id] { continue } messages = append(messages, msg) } } } args := struct { Session types.RobustId Messages []*types.RobustMessage }{ session, messages, } if err := irclogTpl.Execute(w, args); err != nil { http.Error(w, err.Error(), http.StatusInternalServerError) return } }
func dumpLog(key uint64, rlog *raft.Log) { if rlog.Type != raft.LogCommand { // TODO: hexdump log.Printf("type == %d, data = %s\n", rlog.Type, string(rlog.Data)) return } unfilteredMsg := types.NewRobustMessageFromBytes(rlog.Data) rmsg := &unfilteredMsg if rmsg.Type == types.RobustIRCFromClient { rmsg = util.PrivacyFilterMsg(rmsg) } else if rmsg.Type == types.RobustState { state, err := base64.StdEncoding.DecodeString(rmsg.Data) if err != nil { log.Printf("Could not decode robuststate: %v", err) return } var snapshot pb.Snapshot if err := proto.Unmarshal(state, &snapshot); err != nil { log.Printf("Could not unmarshal proto: %v", err) return } snapshot = util.PrivacyFilterSnapshot(snapshot) var marshaler proto.TextMarshaler rmsg.Data = marshaler.Text(&snapshot) } msgtime := time.Unix(0, rmsg.Id.Id) timepassed := lastModified.Sub(msgtime) if !*onlyCompacted || timepassed > 7*24*time.Hour { fmt.Printf(format, key, rmsg.Type, rmsg.Id.String(), msgtime, timepassed, rmsg.Session.String(), rmsg.Data) } if rmsg.Id.Id < lastId { log.Printf("WARNING: message IDs not strictly monotonically increasing at %v\n", time.Unix(0, rmsg.Id.Id)) } lastId = rmsg.Id.Id }
func dumpLog(key uint64, rlog *raft.Log) { if rlog.Type != raft.LogCommand { // TODO: hexdump log.Printf("type == %d, data = %s\n", rlog.Type, string(rlog.Data)) return } unfilteredMsg := types.NewRobustMessageFromBytes(rlog.Data) rmsg := &unfilteredMsg if rmsg.Type == types.RobustIRCFromClient { rmsg = util.PrivacyFilterMsg(rmsg) } msgtime := time.Unix(0, rmsg.Id.Id) timepassed := lastModified.Sub(msgtime) if !*onlyCompacted || timepassed > 7*24*time.Hour { fmt.Printf(format, key, rmsg.Type, rmsg.Id.String(), msgtime, timepassed, rmsg.Session.String(), rmsg.Data) } if rmsg.Id.Id < lastId { log.Printf("WARNING: message IDs not strictly monotonically increasing at %v\n", time.Unix(0, rmsg.Id.Id)) } lastId = rmsg.Id.Id }
func handleStatus(res http.ResponseWriter, req *http.Request) { p, _ := peerStore.Peers() // robustirc-rollingrestart wants a machine-readable version of the status. if req.Header.Get("Accept") == "application/json" { type jsonStatus struct { State string Leader string Peers []string AppliedIndex uint64 CommitIndex uint64 LastContact time.Time ExecutableHash string CurrentTime time.Time } res.Header().Set("Content-Type", "application/json") leaderStr := node.Leader() stats := node.Stats() appliedIndex, err := strconv.ParseUint(stats["applied_index"], 0, 64) if err != nil { http.Error(res, err.Error(), http.StatusInternalServerError) return } commitIndex, err := strconv.ParseUint(stats["commit_index"], 0, 64) if err != nil { http.Error(res, err.Error(), http.StatusInternalServerError) return } if err := json.NewEncoder(res).Encode(jsonStatus{ State: node.State().String(), Leader: leaderStr, AppliedIndex: appliedIndex, CommitIndex: commitIndex, Peers: p, LastContact: node.LastContact(), ExecutableHash: executablehash, CurrentTime: time.Now(), }); err != nil { log.Printf("%v\n", err) http.Error(res, err.Error(), http.StatusInternalServerError) } return } lo, err := ircStore.FirstIndex() if err != nil { log.Printf("Could not get first index: %v", err) http.Error(res, "internal error", 500) return } hi, err := ircStore.LastIndex() if err != nil { log.Printf("Could not get last index: %v", err) http.Error(res, "internal error", 500) return } // Show the last 50 messages by default. if hi > 50 && hi-50 > lo { lo = hi - 50 } if offsetStr := req.FormValue("offset"); offsetStr != "" { offset, err := strconv.ParseInt(offsetStr, 0, 64) if err != nil { http.Error(res, err.Error(), http.StatusBadRequest) return } lo = uint64(offset) } if hi > lo+50 { hi = lo + 50 } var entries []*raft.Log if lo != 0 && hi != 0 { for i := lo; i <= hi; i++ { l := new(raft.Log) if err := ircStore.GetLog(i, l); err != nil { // Not every message goes into the ircStore (e.g. raft peer change // messages do not). continue } if l.Type == raft.LogCommand { msg := types.NewRobustMessageFromBytes(l.Data) msg.Data = msg.PrivacyFilter() l.Data, _ = json.Marshal(&msg) } entries = append(entries, l) } } prevOffset := int64(lo) - 50 if prevOffset < 0 { prevOffset = 1 } args := struct { Addr string State raft.RaftState Leader string Peers []string First uint64 Last uint64 Entries []*raft.Log Stats map[string]string Sessions map[types.RobustId]ircserver.Session GetMessageRequests map[string]GetMessageStats PrevOffset int64 NextOffset uint64 NetConfig config.Network }{ *peerAddr, node.State(), node.Leader(), p, lo, hi, entries, node.Stats(), ircServer.GetSessions(), GetMessageRequests, prevOffset, lo + 50, netConfig, } statusTpl.Execute(res, args) }
func canary(fsm raft.FSM, statePath string) { // Create a snapshot (only creates metadata) and persist it (does the // actual compaction). Afterwards we have access to |rs.parsed| (all // raft log entries, but parsed) and |rs.del| (all messages which were // just compacted). log.Printf("Compacting before dumping state\n") fsm.(*FSM).skipDeletionForCanary = true snapshot, err := fsm.Snapshot() if err != nil { log.Fatalf("fsm.Snapshot(): %v\n", err) } rs, ok := snapshot.(*robustSnapshot) if !ok { log.Fatalf("snapshot is not a robustSnapshot") } sink, err := raft.NewDiscardSnapshotStore().Create(rs.lastIndex, 1, []byte{}) if err != nil { log.Fatalf("DiscardSnapshotStore.Create(): %v\n", err) } if err := snapshot.Persist(sink); err != nil { log.Fatalf("snapshot.Persist(): %v\n", err) } sink.Close() // Dump the in-memory state into a file, to be read by robustirc-canary. f, err := os.Create(statePath) if err != nil { log.Fatal(err) } defer f.Close() log.Printf("Dumping state for robustirc-canary into %q\n", statePath) enc := json.NewEncoder(f) iterator := rs.store.GetBulkIterator(rs.firstIndex, rs.lastIndex+1) defer iterator.Release() available := iterator.First() for available { var nlog raft.Log if err := iterator.Error(); err != nil { glog.Errorf("Error while iterating through the log: %v", err) available = iterator.Next() continue } idx := binary.BigEndian.Uint64(iterator.Key()) value := iterator.Value() if err := json.Unmarshal(value, &nlog); err != nil { glog.Errorf("Skipping log entry %d because of a JSON unmarshaling error: %v", idx, err) continue } available = iterator.Next() // TODO: compact raft messages as well, so that peer changes are not kept forever if nlog.Type != raft.LogCommand { continue } nmsg := types.NewRobustMessageFromBytes(nlog.Data) if time.Unix(0, nmsg.Id.Id).Before(rs.compactionEnd) { continue } // TODO: come up with pseudo-values for createsession/deletesession if nmsg.Type != types.RobustIRCFromClient { continue } ircmsg := irc.ParseMessage(nmsg.Data) if ircmsg.Command == irc.PING || ircmsg.Command == irc.PONG { continue } vmsgs, _ := ircServer.Get(nmsg.Id) cm := canaryMessageState{ Id: idx, Session: nmsg.Session.Id, Input: util.PrivacyFilterIrcmsg(ircmsg).String(), Output: make([]canaryMessageOutput, len(vmsgs)), Compacted: false, } for idx, vmsg := range vmsgs { ifc := make(map[string]bool) for k, v := range vmsg.InterestingFor { ifc["0x"+strconv.FormatInt(k, 16)] = v } cm.Output[idx] = canaryMessageOutput{ Text: util.PrivacyFilterIrcmsg(irc.ParseMessage(vmsg.Data)).String(), InterestingFor: ifc, } } if err := enc.Encode(&cm); err != nil { log.Fatal(err) } } }
func (fsm *FSM) Apply(l *raft.Log) interface{} { // Skip all messages that are raft-related. if l.Type != raft.LogCommand { return nil } if err := fsm.ircstore.StoreLog(l); err != nil { log.Panicf("Could not persist message in irclogs/: %v", err) } msg := types.NewRobustMessageFromBytes(l.Data) log.Printf("Apply(msg.Type=%s)\n", msg.Type) defer func() { if msg.Type == types.RobustMessageOfDeath { return } if r := recover(); r != nil { // Panics in ircserver.ProcessMessage() are a problem, since // they will bring down the entire raft cluster and you cannot // bring up any raft node anymore without deleting the entire // log. // // Therefore, when we panic, we invalidate the log entry in // question before crashing. This doesn’t fix the underlying // bug, i.e. an IRC message will then go unhandled, but it // prevents RobustIRC from dying horribly in such a situation. msg.Type = types.RobustMessageOfDeath data, err := json.Marshal(msg) if err != nil { glog.Fatalf("Could not marshal message: %v", err) } l.Data = data if err := fsm.store.StoreLog(l); err != nil { glog.Fatalf("Could not store log while marking message as message of death: %v", err) } log.Printf("Marked %+v as message of death\n", l) glog.Fatalf("%v", r) } }() switch msg.Type { case types.RobustMessageOfDeath: // To prevent the message from being accepted again. ircServer.UpdateLastClientMessageID(&msg) log.Printf("Skipped message of death.\n") case types.RobustCreateSession: ircServer.CreateSession(msg.Id, msg.Data) case types.RobustDeleteSession: if _, err := ircServer.GetSession(msg.Session); err == nil { // TODO(secure): overwrite QUIT messages for services with an faq entry explaining that they are not robust yet. reply := ircServer.ProcessMessage(msg.Id, msg.Session, irc.ParseMessage("QUIT :"+string(msg.Data))) ircServer.SendMessages(reply, msg.Session, msg.Id.Id) } case types.RobustIRCFromClient: // Need to do this first, because ircserver.ProcessMessage could delete // the session, e.g. by using KILL or QUIT. if err := ircServer.UpdateLastClientMessageID(&msg); err != nil { log.Printf("Error updating the last message for session: %v\n", err) } else { reply := ircServer.ProcessMessage(msg.Id, msg.Session, irc.ParseMessage(string(msg.Data))) ircServer.SendMessages(reply, msg.Session, msg.Id.Id) } case types.RobustConfig: newCfg, err := config.FromString(string(msg.Data)) if err != nil { log.Printf("Skipping unexpectedly invalid configuration (%v)\n", err) } else { netConfig = newCfg ircServer.Config = netConfig.IRC } } appliedMessages.WithLabelValues(msg.Type.String()).Inc() return nil }
func (s *robustSnapshot) Persist(sink raft.SnapshotSink) error { log.Printf("Filtering and writing %d indexes\n", s.lastIndex-s.firstIndex) // Get a timestamp and keep it constant, so that we only compact messages // older than n days from compactionStart. If we used time.Since, new // messages would pour into the window on every compaction round, possibly // making the compaction never converge. compactionStart := time.Now() log.Printf("compactionStart %s\n", compactionStart.String()) if *canaryCompactionStart > 0 { compactionStart = time.Unix(0, *canaryCompactionStart) log.Printf("compactionStart %s (overridden with -canary_compaction_start)\n", compactionStart.String()) } sessions := make(map[types.RobustId]bool) // First pass: just parse all the messages for i := s.firstIndex; i <= s.lastIndex; i++ { var nlog raft.Log if err := s.store.GetLog(i, &nlog); err != nil { s.del[i] = true continue } // TODO: compact raft messages as well, so that peer changes are not kept forever if nlog.Type != raft.LogCommand { continue } parsed := types.NewRobustMessageFromBytes(nlog.Data) s.parsed[i] = &parsed if parsed.Type == types.RobustCreateSession { s.sliced[parsed.Id.Id] = append(s.sliced[parsed.Id.Id], &parsed) } if parsed.Type == types.RobustDeleteSession { s.sliced[parsed.Session.Id] = append(s.sliced[parsed.Session.Id], &parsed) } if parsed.Type == types.RobustIRCFromClient { // TODO: skip PING/PRIVMSG messages that are outside of the // compaction window to reduce the working set. should be a noop // since no relevant* function looks at PRIVMSG/PING. sessions[parsed.Session] = true vmsgs, _ := ircServer.Get(types.RobustId{Id: parsed.Id.Id}) onlyerrors := true for _, msg := range vmsgs { ircmsg := irc.ParseMessage(msg.Data) if ircmsg == nil { glog.Errorf("Output message not parsable\n") continue } if !errorCodes[ircmsg.Command] { onlyerrors = false } } if len(vmsgs) > 0 && onlyerrors { s.del[i] = true continue } // Kind of a hack: we need to keep track of which sessions are // services connections and which are not, so that we can look at // the correct relevant-function (e.g. server_NICK vs. NICK). ircmsg := irc.ParseMessage(parsed.Data) if ircmsg != nil && strings.ToUpper(ircmsg.Command) == "SERVER" { s.servers[parsed.Session.Id] = true } // Every session which is interested in at least one of the output // messages gets a pointer to the input message stored in s.sliced // so that we can easily iterate over all relevant input messages. for session := range sessions { interested := false for _, msg := range vmsgs { if msg.InterestingFor[session.Id] { interested = true break } } // All messages that would be delivered to a session are // interesting for compaction, but also just any message that a // specific session sent. if interested || (len(vmsgs) > 0 && session.Id == parsed.Session.Id) { s.sliced[session.Id] = append(s.sliced[session.Id], &parsed) } } // Some messages don’t result in output messages, such as a JOIN // command for a channel the user is already in. We mark these as // interesting at least to the session from which they originated, // so that they can be detected and deleted. // TODO: would it be okay to just mark them for deletion? i.e., do all messages that modify state return a result? if len(vmsgs) == 0 { s.sliced[parsed.Session.Id] = append(s.sliced[parsed.Session.Id], &parsed) } } } log.Printf("got %d sessions\n", len(sessions)) for session := range sessions { log.Printf("session 0x%x has %d messages\n", session.Id, len(s.sliced[session.Id])) } // We repeatedly compact, since the result of one compaction can affect the // result of other compactions (see compaction_test.go for examples). changed := true pass := 0 for changed { log.Printf("Compaction pass %d\n", pass) pass++ changed = false for i := s.firstIndex; i <= s.lastIndex; i++ { if i%1000 == 0 { log.Printf("message %d of %d (%.0f%%)\n", i, s.lastIndex, (float64(i)/float64(s.lastIndex))*100.0) } if s.del[i] { continue } msg, ok := s.parsed[i] if !ok { continue } if compactionStart.Sub(time.Unix(0, msg.Id.Id)) < 7*24*time.Hour { // If we ran outside the window, we don’t even need to look at // any newer messages anymore. break } session := msg.Session if msg.Type == types.RobustCreateSession { session = msg.Id } canCompact, slicedIdx, err := s.canCompact(session, msg, i) if err != nil { sink.Cancel() return err } if canCompact { s.del[i] = true if slicedIdx != -1 { s.sliced[session.Id][slicedIdx] = nil } changed = true } } } encoder := json.NewEncoder(sink) for i := s.firstIndex; i <= s.lastIndex; i++ { if s.del[i] { continue } var elog raft.Log if err := s.store.GetLog(i, &elog); err != nil { continue } if err := encoder.Encode(elog); err != nil { sink.Cancel() return err } } sink.Close() for idx, del := range s.del { if !del { continue } nmsg, ok := s.parsed[idx] // If the message was not found in parsed, then there was no message // with this index, hence there is nothing to delete. if !ok { continue } // TODO: Since outputstream uses a LevelDB database, we could be more // efficient and use batch deletions. if err := ircServer.Delete(nmsg.Id); err != nil { log.Panicf("Could not delete outputstream message: %v\n", err) } s.store.DeleteRange(idx, idx) } return nil }