func (s *Server) LogReRun(nextRole string, curRole string) {
if nextRole == "root" {
var messg = s.Name() + " became root"
if curRole == "root" {
messg = s.Name() + " remained root"
}
go s.ConnectToLogger()
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "role_change",
}).Infoln(messg)
// log.Printf("role change: %p", s)
} else {
var messg = s.Name() + " remained regular"
if curRole == "root" {
messg = s.Name() + " became regular"
}
if curRole == "root" {
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "role_change",
}).Infoln(messg)
log.Printf("role change: %p", s)
}
}
}
func main() {
flag.Parse()
// connect with the logging server
if logger != "" && (amroot || debug) {
// blocks until we can connect to the logger
lh, err := logutils.NewLoggerHook(logger, hostname, app)
if err != nil {
log.WithFields(log.Fields{
"file": logutils.File(),
}).Fatalln("ERROR SETTING UP LOGGING SERVER:", err)
}
log.AddHook(lh)
}
//log.Println("IN FORKEXEC")
////log.SetOutput(ioutil.Discard)
////log.Println("Log Test")
////fmt.Println("exiting logger block")
//}
// log.Println("IN FORK EXEC")
// recombine the flags for exec to use
args := []string{
"-failures=" + strconv.Itoa(failures),
"-rfail=" + strconv.Itoa(rFail),
"-ffail=" + strconv.Itoa(fFail),
"-hostname=" + hostname,
"-config=" + configFile,
"-logger=" + logger,
"-app=" + app,
"-pprof=" + pprofaddr,
"-physaddr=" + physaddr,
"-rootwait=" + strconv.Itoa(rootwait),
"-debug=" + strconv.FormatBool(debug),
"-rounds=" + strconv.Itoa(rounds),
"-amroot=" + strconv.FormatBool(amroot),
"-test_connect=" + strconv.FormatBool(testConnect),
"-suite=" + suite,
}
cmd := exec.Command("./exec", args...)
cmd.Stdout = log.StandardLogger().Writer()
cmd.Stderr = log.StandardLogger().Writer()
// log.Println("running command:", cmd)
err := cmd.Run()
if err != nil {
log.Errorln("cmd run:", err)
}
// get CPU usage stats
st := cmd.ProcessState.SystemTime()
ut := cmd.ProcessState.UserTime()
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "forkexec",
"systime": st,
"usertime": ut,
}).Info("")
}
// Used for goconns
// should only be used if clients are created in batch
func (s *Server) ListenToClients() {
// log.Printf("LISTENING TO CLIENTS: %p", s, s.Clients)
for _, c := range s.Clients {
go func(c coconet.Conn) {
for {
tsm := TimeStampMessage{}
err := c.Get(&tsm)
if err == coconet.ErrClosed {
log.Errorf("%p Failed to get from client:", s, err)
s.Close()
return
}
if err != nil {
log.WithFields(log.Fields{
"file": logutils.File(),
}).Errorf("%p failed To get message:", s, err)
}
switch tsm.Type {
default:
log.Errorln("Message of unknown type")
case StampRequestType:
// log.Println("STAMP REQUEST")
s.mux.Lock()
READING := s.READING
s.Queue[READING] = append(s.Queue[READING],
MustReplyMessage{Tsm: tsm, To: c.Name()})
s.mux.Unlock()
}
}
}(c)
}
}
func (sn *Node) logTotalTime(totalTime time.Duration) {
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "root_challenge",
"round": sn.nRounds,
"time": totalTime,
}).Info("done with root challenge round " + strconv.Itoa(sn.nRounds))
}
func (sn *Node) logFirstPhase(firstRoundTime time.Duration) {
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "root_announce",
"round": sn.nRounds,
"time": firstRoundTime,
}).Info("done with root announce round " + strconv.Itoa(sn.nRounds))
}
func AggregateStats(buck, roundsAfter, times []int64) string {
muStats.Lock()
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "client_msg_stats",
"buck": removeTrailingZeroes(buck),
"roundsAfter": removeTrailingZeroes(roundsAfter),
"times": removeTrailingZeroes(times),
}).Info("")
muStats.Unlock()
return "Client Finished Aggregating Statistics"
}
func (s *Server) runAsRegular() string {
select {
case <-s.closeChan:
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "close",
}).Infoln("server" + s.Name() + "has closed")
return ""
case nextRole := <-s.ViewChangeCh():
return nextRole
}
}
func main() {
flag.Parse()
log.Println("Running Timestamper:", logger)
defer func() {
log.Errorln("TERMINATING HOST")
}()
// connect with the logging server
if logger != "" && (amroot || debug) {
// blocks until we can connect to the logger
log.Println("Connecting to Logger")
lh, err := logutils.NewLoggerHook(logger, hostname, app)
log.Println("Connected to Logger")
if err != nil {
log.WithFields(log.Fields{
"file": logutils.File(),
}).Fatalln("ERROR SETTING UP LOGGING SERVER:", err)
}
log.AddHook(lh)
//log.SetOutput(ioutil.Discard)
//fmt.Println("exiting logger block")
}
if physaddr == "" {
h, _, err := net.SplitHostPort(hostname)
if err != nil {
log.Fatal("improperly formatted hostname")
}
physaddr = h
}
// run an http server to serve the cpu and memory profiles
go func() {
_, port, err := net.SplitHostPort(hostname)
if err != nil {
log.Fatal("improperly formatted hostname: should be host:port")
}
p, _ := strconv.Atoi(port)
// uncomment if more fine grained memory debuggin is needed
//runtime.MemProfileRate = 1
log.Println(http.ListenAndServe(net.JoinHostPort(physaddr, strconv.Itoa(p+2)), nil))
}()
// log.Println("!!!!!!!!!!!!!!!Running timestamp with rFail and fFail: ", rFail, fFail)
timestamper.Run(hostname, cfg, app, rounds, rootwait, debug, testConnect, failures, rFail, fFail, logger, suite)
}
func (sn *Node) TryRootFailure(view, Round int) bool {
if sn.IsRoot(view) && sn.FailAsRootEvery != 0 {
if sn.RoundsAsRoot != 0 && sn.RoundsAsRoot%sn.FailAsRootEvery == 0 {
log.Errorln(sn.Name() + "was imposed root failure on round" + strconv.Itoa(Round))
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "root_failure",
"round": Round,
}).Info(sn.Name() + "Root imposed failure")
// It doesn't make sense to try view change twice
// what we essentially end up doing is double setting sn.ViewChanged
// it is up to our followers to time us out and go to the next leader
// sn.TryViewChange(view + 1)
return true
}
}
return false
}
func (sn *Node) TryFailure(view, Round int) error {
if sn.TryRootFailure(view, Round) {
return ErrImposedFailure
}
if !sn.IsRoot(view) && sn.FailAsFollowerEvery != 0 && Round%sn.FailAsFollowerEvery == 0 {
// when failure rate given fail with that probability
if (sn.FailureRate > 0 && sn.ShouldIFail("")) || (sn.FailureRate == 0) {
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "follower_failure",
"round": Round,
}).Info(sn.Name() + "Follower imposed failure")
return errors.New(sn.Name() + "was imposed follower failure on round" + strconv.Itoa(Round))
}
}
// doing this before annoucing children to avoid major drama
if !sn.IsRoot(view) && sn.ShouldIFail("commit") {
log.Warn(sn.Name(), "not announcing or commiting for round", Round)
return ErrImposedFailure
}
return nil
}
func Run(server string, nmsgs int, name string, rate int, debug bool) {
c := stamp.NewClient(name)
msgs := genRandomMessages(nmsgs + 20)
servers := strings.Split(server, ",")
// connect to all the servers listed
for _, s := range servers {
h, p, err := net.SplitHostPort(s)
if err != nil {
log.Fatal("improperly formatted host")
}
pn, _ := strconv.Atoi(p)
c.AddServer(s, coconet.NewTCPConn(net.JoinHostPort(h, strconv.Itoa(pn+1))))
}
// if rate specified send out one message every rate milliseconds
if rate > 0 {
// Stream time stamp requests
streamMessgs(c, servers, rate)
return
}
// rounds based messaging
r := 0
s := 0
// ROUNDS BASED IS DEPRECATED
log.Fatal("ROUNDS BASED RATE LIMITING DEPRECATED")
for {
//start := time.Now()
var wg sync.WaitGroup
for i := 0; i < nmsgs; i++ {
wg.Add(1)
go func(i, s int) {
defer wg.Done()
err := c.TimeStamp(msgs[i], servers[s])
if err == io.EOF {
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "client_msg_stats",
"buck": make([]int64, 0),
"roundsAfter": make([]int64, 0),
}).Info("")
log.Fatal("EOF: terminating time client")
}
}(i, s)
s = (s + 1) % len(servers)
}
wg.Wait()
//elapsed := time.Since(start)
log.Println("client done with round")
//log.WithFields(log.Fields{
//"file": logutils.File(),
//"type": "client_round",
//"round": r,
//"time": elapsed,
//}).Info("client round")
r++
}
}
func Run(hostname, cfg, app string, rounds int, rootwait int, debug, testConnect bool, failureRate, rFail, fFail int, logger, suite string) {
if debug {
coco.DEBUG = true
}
// fmt.Println("EXEC TIMESTAMPER: " + hostname)
if hostname == "" {
fmt.Println("hostname is empty")
log.Fatal("no hostname given")
}
// load the configuration
//log.Println("loading configuration")
var hc *oldconfig.HostConfig
var err error
s := GetSuite(suite)
opts := oldconfig.ConfigOptions{ConnType: "tcp", Host: hostname, Suite: s}
if failureRate > 0 || fFail > 0 {
opts.Faulty = true
}
hc, err = oldconfig.LoadConfig(cfg, opts)
if err != nil {
fmt.Println(err)
log.Fatal(err)
}
// set FailureRates
if failureRate > 0 {
for i := range hc.SNodes {
hc.SNodes[i].FailureRate = failureRate
}
}
// set root failures
if rFail > 0 {
for i := range hc.SNodes {
hc.SNodes[i].FailAsRootEvery = rFail
}
}
// set follower failures
// a follower fails on %ffail round with failureRate probability
for i := range hc.SNodes {
hc.SNodes[i].FailAsFollowerEvery = fFail
}
// run this specific host
// log.Println("RUNNING HOST CONFIG")
err = hc.Run(app != "sign", sign.MerkleTree, hostname)
if err != nil {
log.Fatal(err)
}
defer func(sn *sign.Node) {
log.Panicln("program has terminated:", hostname)
sn.Close()
}(hc.SNodes[0])
if app == "sign" {
//log.Println("RUNNING Node")
// if I am root do the announcement message
if hc.SNodes[0].IsRoot(0) {
time.Sleep(3 * time.Second)
start := time.Now()
iters := 10
for i := 0; i < iters; i++ {
start = time.Now()
//fmt.Println("ANNOUNCING")
hc.SNodes[0].LogTest = []byte("Hello World")
err = hc.SNodes[0].Announce(0,
&sign.AnnouncementMessage{
LogTest: hc.SNodes[0].LogTest,
Round: i})
if err != nil {
log.Println(err)
}
elapsed := time.Since(start)
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "root_announce",
"round": i,
"time": elapsed,
}).Info("")
}
} else {
// otherwise wait a little bit (hopefully it finishes by the end of this)
time.Sleep(30 * time.Second)
}
} else if app == "stamp" || app == "vote" {
// log.Println("RUNNING TIMESTAMPER")
stampers, _, err := hc.RunTimestamper(0, hostname)
// get rid of the hc information so it can be GC'ed
hc = nil
if err != nil {
log.Fatal(err)
}
for _, s := range stampers {
// only listen if this is the hostname specified
if s.Name() == hostname {
s.Logger = logger
s.Hostname = hostname
s.App = app
if s.IsRoot(0) {
log.Println("RUNNING ROOT SERVER AT:", hostname, rounds)
log.Printf("Waiting: %d s\n", rootwait)
// wait for the other nodes to get set up
time.Sleep(time.Duration(rootwait) * time.Second)
log.Println("STARTING ROOT ROUND")
s.Run("root", rounds)
// log.Println("\n\nROOT DONE\n\n")
} else if !testConnect {
log.Println("RUNNING REGULAR AT:", hostname)
s.Run("regular", rounds)
// log.Println("\n\nREGULAR DONE\n\n")
} else {
// testing connection
log.Println("RUNNING TEST_CONNNECT AT:", hostname)
s.Run("test_connect", rounds)
}
}
}
}
}
func (s *Server) runAsRoot(nRounds int) string {
// every 5 seconds start a new round
ticker := time.Tick(ROUND_TIME)
if s.LastRound()+1 > nRounds {
log.Errorln(s.Name(), "runAsRoot called with too large round number")
return "close"
}
log.Infoln(s.Name(), "running as root", s.LastRound(), int64(nRounds))
for {
select {
case nextRole := <-s.ViewChangeCh():
log.Println(s.Name(), "assuming next role")
return nextRole
// s.reRunWith(nextRole, nRounds, true)
case <-ticker:
start := time.Now()
log.Println(s.Name(), "is STAMP SERVER STARTING SIGNING ROUND FOR:", s.LastRound()+1, "of", nRounds)
var err error
if s.App == "vote" {
vote := &sign.Vote{
Type: sign.AddVT,
Av: &sign.AddVote{
Parent: s.Name(),
Name: "test-add-node"}}
err = s.StartVotingRound(vote)
} else {
err = s.StartSigningRound()
}
if err == sign.ChangingViewError {
// report change in view, and continue with the select
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "view_change",
}).Info("Tried to stary signing round on " + s.Name() + " but it reports view change in progress")
// skip # of failed round
time.Sleep(1 * time.Second)
break
} else if err != nil {
log.Errorln(err)
time.Sleep(1 * time.Second)
break
}
if s.LastRound()+1 >= nRounds {
log.Errorln(s.Name(), "reports exceeded the max round: terminating", s.LastRound()+1, ">=", nRounds)
return "close"
}
elapsed := time.Since(start)
log.WithFields(log.Fields{
"file": logutils.File(),
"type": "root_round",
"round": s.LastRound(),
"time": elapsed,
}).Info("root round")
}
}
}