Switch to more flexible go-logging

This commit switches from loggo to the more flexible go-logging
framework. Logs of severity INFO or higher are now written to a separate
boardvoting.log file.

Errors during execution of mail templates are now logged.

A reasoning for the vote result is now logged and put into the mail
notification when a decision is closed.
debian
Jan Dittberner 7 years ago
parent eec8620e49
commit 4d23b6a48f

1
.gitignore vendored

@ -1,5 +1,6 @@
*.crt
*.key
*.log
*.pem
*.sqlite
.*.swp

@ -11,12 +11,13 @@ import (
"github.com/Masterminds/sprig"
"github.com/gorilla/sessions"
"github.com/jmoiron/sqlx"
"github.com/juju/loggo"
_ "github.com/mattn/go-sqlite3"
"github.com/op/go-logging"
"gopkg.in/yaml.v2"
"html/template"
"io/ioutil"
"net/http"
"os"
"strconv"
"strings"
"time"
@ -26,7 +27,7 @@ var config *Config
var store *sessions.CookieStore
var version = "undefined"
var build = "undefined"
var logger loggo.Logger
var log *logging.Logger
const sessionCookieName = "votesession"
@ -239,16 +240,16 @@ func getVoteFromRequest(r *http.Request) (vote VoteChoice, ok bool) {
type FlashMessageAction struct{}
func (a *FlashMessageAction) AddFlash(w http.ResponseWriter, r *http.Request, message interface{}, tags ...string) (err error) {
func (a *FlashMessageAction) AddFlash(w http.ResponseWriter, r *http.Request, message interface{}, tags ...string) {
session, err := store.Get(r, sessionCookieName)
if err != nil {
logger.Errorf("getting session failed: %s", err)
log.Errorf("getting session failed: %v", err)
return
}
session.AddFlash(message, tags...)
session.Save(r, w)
if err != nil {
logger.Errorf("saving session failed: %s", err)
log.Errorf("saving session failed: %v", err)
return
}
return
@ -282,17 +283,14 @@ func (a *withDrawMotionAction) Handle(w http.ResponseWriter, r *http.Request) {
decision.Status = voteStatusWithdrawn
decision.Modified = time.Now().UTC()
if err := decision.UpdateStatus(); err != nil {
logger.Errorf("withdrawing motion failed: %s", err)
log.Errorf("withdrawing motion failed: %v", err)
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
NotifyMailChannel <- NewNotificationWithDrawMotion(&(decision.Decision), voter)
if err := a.AddFlash(w, r, fmt.Sprintf("Motion %s has been withdrawn!", decision.Tag)); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
a.AddFlash(w, r, fmt.Sprintf("Motion %s has been withdrawn!", decision.Tag))
http.Redirect(w, r, "/motions/", http.StatusTemporaryRedirect)
default:
@ -335,17 +333,14 @@ func (h *newMotionHandler) Handle(w http.ResponseWriter, r *http.Request) {
data.Proposed = time.Now().UTC()
data.ProponentId = voter.Id
if err := data.Create(); err != nil {
logger.Errorf("saving motion failed: %s", err)
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
log.Errorf("saving motion failed: %v", err)
http.Error(w, "Saving motion failed", http.StatusInternalServerError)
return
}
NotifyMailChannel <- &NotificationCreateMotion{decision: *data, voter: *voter}
if err := h.AddFlash(w, r, "The motion has been proposed!"); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
h.AddFlash(w, r, "The motion has been proposed!")
http.Redirect(w, r, "/motions/", http.StatusMovedPermanently)
}
@ -400,17 +395,14 @@ func (a editMotionAction) Handle(w http.ResponseWriter, r *http.Request) {
} else {
data.Modified = time.Now().UTC()
if err := data.Update(); err != nil {
logger.Errorf("updating motion failed: %s", err)
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
log.Errorf("updating motion failed: %v", err)
http.Error(w, "Updating the motion failed.", http.StatusInternalServerError)
return
}
NotifyMailChannel <- NewNotificationUpdateMotion(*data, *voter)
if err := a.AddFlash(w, r, "The motion has been modified!"); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
a.AddFlash(w, r, "The motion has been modified!")
http.Redirect(w, r, "/motions/", http.StatusMovedPermanently)
}
@ -500,17 +492,14 @@ func (h *directVoteHandler) Handle(w http.ResponseWriter, r *http.Request) {
VoterId: voter.Id, Vote: vote, DecisionId: decision.Id, Voted: time.Now().UTC(),
Notes: fmt.Sprintf("Direct Vote\n\n%s", getPEMClientCert(r))}
if err := voteResult.Save(); err != nil {
logger.Errorf("Problem saving vote: %s", err)
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
log.Errorf("Problem saving vote: %v", err)
http.Error(w, "Problem saving vote", http.StatusInternalServerError)
return
}
NotifyMailChannel <- NewNotificationDirectVote(&decision.Decision, voter, voteResult)
if err := h.AddFlash(w, r, "Your vote has been registered."); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
h.AddFlash(w, r, "Your vote has been registered.")
http.Redirect(w, r, "/motions/", http.StatusMovedPermanently)
default:
@ -569,7 +558,7 @@ func (h *proxyVoteHandler) Handle(w http.ResponseWriter, r *http.Request) {
if valid, voter, data, justification := form.Validate(); !valid {
templateContext.Form = form
templateContext.Decision = decision
if voters, err := GetVotersForProxy(proxy, &decision.Decision); err != nil {
if voters, err := GetVotersForProxy(proxy); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
} else {
@ -584,17 +573,14 @@ func (h *proxyVoteHandler) Handle(w http.ResponseWriter, r *http.Request) {
proxy.Name, justification, getPEMClientCert(r))
if err := data.Save(); err != nil {
logger.Errorf("Error saving vote: %s", err)
log.Errorf("Error saving vote: %s", err)
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
NotifyMailChannel <- NewNotificationProxyVote(&decision.Decision, proxy, voter, data, justification)
if err := h.AddFlash(w, r, "The vote has been registered."); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
}
h.AddFlash(w, r, "The vote has been registered.")
http.Redirect(w, r, "/motions/", http.StatusMovedPermanently)
}
@ -602,7 +588,7 @@ func (h *proxyVoteHandler) Handle(w http.ResponseWriter, r *http.Request) {
default:
templateContext.Form = ProxyVoteForm{}
templateContext.Decision = decision
if voters, err := GetVotersForProxy(proxy, &decision.Decision); err != nil {
if voters, err := GetVotersForProxy(proxy); err != nil {
http.Error(w, http.StatusText(http.StatusInternalServerError), http.StatusInternalServerError)
return
} else {
@ -665,86 +651,147 @@ type Config struct {
} `yaml:"mail_server"`
}
func init() {
loggo.ConfigureLoggers("<root>=ERROR; boardvoting=INFO")
logger = loggo.GetLogger("boardvoting")
logger.Infof("Logger initialized")
func setupLogging(ctx context.Context) {
log = logging.MustGetLogger("boardvoting")
consoleLogFormat := logging.MustStringFormatter(`%{color}%{time:20060102 15:04:05.000-0700} %{longfile} ▶ %{level:s} %{id:05d}%{color:reset} %{message}`)
fileLogFormat := logging.MustStringFormatter(`%{time:20060102 15:04:05.000-0700} %{level:s} %{id:05d} %{message}`)
consoleBackend := logging.NewLogBackend(os.Stderr, "", 0)
logfile, err := os.OpenFile("boardvoting.log", os.O_CREATE|os.O_APPEND|os.O_WRONLY, os.FileMode(0640))
if err != nil {
panic("Could not open logfile")
}
fileBackend := logging.NewLogBackend(logfile, "", 0)
fileBackendLeveled := logging.AddModuleLevel(logging.NewBackendFormatter(fileBackend, fileLogFormat))
fileBackendLeveled.SetLevel(logging.INFO, "")
logging.SetBackend(fileBackendLeveled,
logging.NewBackendFormatter(consoleBackend, consoleLogFormat))
go func() {
for range ctx.Done() {
if err = logfile.Close(); err != nil {
fmt.Fprintf(os.Stderr, "Problem closing the log file: %v", err)
}
}
}()
log.Info("Setup logging")
}
func readConfig() {
source, err := ioutil.ReadFile("config.yaml")
if err != nil {
logger.Criticalf("Opening configuration file failed: %s", err)
panic(err)
log.Panicf("Opening configuration file failed: %v", err)
}
if err := yaml.Unmarshal(source, &config); err != nil {
logger.Criticalf("Loading configuration failed: %s", err)
panic(err)
log.Panicf("Loading configuration failed: %v", err)
}
cookieSecret, err := base64.StdEncoding.DecodeString(config.CookieSecret)
if err != nil {
logger.Criticalf("Decoding cookie secret failed: %s", err)
log.Panicf("Decoding cookie secret failed: %v", err)
panic(err)
}
if len(cookieSecret) < 32 {
logger.Criticalf("Cookie secret is less than 32 bytes long")
panic("Cookie secret too short")
log.Panic("Cookie secret is less than 32 bytes long")
}
store = sessions.NewCookieStore(cookieSecret)
logger.Infof("Read configuration")
log.Info("Read configuration")
}
db, err = sqlx.Open("sqlite3", config.DatabaseFile)
func setupDbConfig(ctx context.Context) {
database, err := sqlx.Open("sqlite3", config.DatabaseFile)
if err != nil {
logger.Criticalf("Opening database failed: %s", err)
panic(err)
log.Panicf("Opening database failed: %v", err)
}
logger.Infof("opened database connection")
}
db = NewDB(database)
func main() {
logger.Infof("CAcert Board Voting version %s, build %s", version, build)
go func() {
for range ctx.Done() {
if err := db.Close(); err != nil {
fmt.Fprintf(os.Stderr, "Problem closing the database: %v", err)
}
}
}()
defer db.Close()
log.Infof("opened database connection")
}
func setupNotifications(ctx context.Context) {
quitMailChannel := make(chan int)
go MailNotifier(quitMailChannel)
defer func() { quitMailChannel <- 1 }()
go func() {
for range ctx.Done() {
quitMailChannel <- 1
}
}()
}
func setupJobs(ctx context.Context) {
quitChannel := make(chan int)
go JobScheduler(quitChannel)
defer func() { quitChannel <- 1 }()
go func() {
for range ctx.Done() {
quitChannel <- 1
}
}()
}
func setupHandlers() {
http.Handle("/motions/", http.StripPrefix("/motions/", motionsHandler{}))
http.Handle("/newmotion/", motionsHandler{})
http.Handle("/proxy/", &decisionVoteHandler{})
http.Handle("/vote/", &decisionVoteHandler{})
http.Handle("/static/", http.FileServer(http.Dir(".")))
http.Handle("/", http.RedirectHandler("/motions/", http.StatusMovedPermanently))
}
func setupTLSConfig() (tlsConfig *tls.Config) {
// load CA certificates for client authentication
caCert, err := ioutil.ReadFile(config.ClientCACertificates)
if err != nil {
logger.Criticalf("Error reading client certificate CAs", err)
panic(err)
log.Panicf("Error reading client certificate CAs %v", err)
}
caCertPool := x509.NewCertPool()
if !caCertPool.AppendCertsFromPEM(caCert) {
logger.Criticalf("could not initialize client CA certificate pool")
panic("client certificate CA pool initialization failed")
log.Panic("could not initialize client CA certificate pool")
}
// setup HTTPS server
tlsConfig := &tls.Config{
tlsConfig = &tls.Config{
ClientCAs: caCertPool,
ClientAuth: tls.VerifyClientCertIfGiven,
}
tlsConfig.BuildNameToCertificate()
return
}
func main() {
var stopAll func()
executionContext, stopAll := context.WithCancel(context.Background())
setupLogging(executionContext)
readConfig()
setupDbConfig(executionContext)
setupNotifications(executionContext)
setupJobs(executionContext)
setupHandlers()
tlsConfig := setupTLSConfig()
defer stopAll()
log.Infof("CAcert Board Voting version %s, build %s", version, build)
server := &http.Server{
Addr: ":8443",
TLSConfig: tlsConfig,
}
logger.Infof("Launching application on https://localhost%s/", server.Addr)
log.Infof("Launching application on https://localhost%s/", server.Addr)
errs := make(chan error, 1)
go func() {
@ -754,12 +801,10 @@ func main() {
close(errs)
}()
if err = server.ListenAndServeTLS(config.ServerCert, config.ServerKey); err != nil {
logger.Criticalf("ListenAndServerTLS failed: %s", err)
panic(err)
if err := server.ListenAndServeTLS(config.ServerCert, config.ServerKey); err != nil {
log.Panicf("ListenAndServerTLS failed: %v", err)
}
if err := <-errs; err != nil {
logger.Criticalf("ListenAndServe failed: %s", err)
panic(err)
log.Panicf("ListenAndServe failed: %v", err)
}
}

@ -22,19 +22,19 @@ func JobScheduler(quitChannel chan int) {
JobIdCloseDecisions: NewCloseDecisionsJob(),
JobIdRemindVotersJob: NewRemindVotersJob(),
}
logger.Infof("started job scheduler")
log.Info("started job scheduler")
for {
select {
case jobId := <-rescheduleChannel:
job := jobs[jobId]
logger.Infof("reschedule job %s", job)
log.Infof("reschedule job %s", job)
job.Schedule()
case <-quitChannel:
for _, job := range jobs {
job.Stop()
}
logger.Infof("stop job scheduler")
log.Info("stop job scheduler")
return
}
}
@ -54,7 +54,7 @@ func (j *CloseDecisionsJob) Schedule() {
var nextDue *time.Time
nextDue, err := GetNextPendingDecisionDue()
if err != nil {
logger.Errorf("Could not get next pending due date")
log.Error("Could not get next pending due date")
if j.timer != nil {
j.timer.Stop()
j.timer = nil
@ -62,11 +62,11 @@ func (j *CloseDecisionsJob) Schedule() {
return
}
if nextDue == nil {
logger.Infof("no next planned execution of CloseDecisionsJob")
log.Info("no next planned execution of CloseDecisionsJob")
j.Stop()
} else {
nextDue := nextDue.Add(time.Minute)
logger.Infof("scheduling CloseDecisionsJob for %s", nextDue)
nextDue := nextDue.Add(time.Second)
log.Infof("scheduling CloseDecisionsJob for %s", nextDue)
when := nextDue.Sub(time.Now())
if j.timer != nil {
j.timer.Reset(when)
@ -84,10 +84,10 @@ func (j *CloseDecisionsJob) Stop() {
}
func (j *CloseDecisionsJob) Run() {
logger.Infof("running CloseDecisionsJob")
log.Debug("running CloseDecisionsJob")
err := CloseDecisions()
if err != nil {
logger.Errorf("closing decisions %s", err)
log.Errorf("closing decisions %v", err)
}
rescheduleChannel <- JobIdCloseDecisions
}
@ -109,7 +109,7 @@ func NewRemindVotersJob() *RemindVotersJob {
func (j *RemindVotersJob) Schedule() {
year, month, day := time.Now().UTC().Date()
nextExecution := time.Date(year, month, day, 0, 0, 0, 0, time.UTC).AddDate(0, 0, 3)
logger.Infof("scheduling RemindVotersJob for %s", nextExecution)
log.Infof("scheduling RemindVotersJob for %s", nextExecution)
when := nextExecution.Sub(time.Now())
if j.timer != nil {
j.timer.Reset(when)
@ -126,19 +126,19 @@ func (j *RemindVotersJob) Stop() {
}
func (j *RemindVotersJob) Run() {
logger.Infof("running RemindVotersJob")
log.Info("running RemindVotersJob")
defer func() { rescheduleChannel <- JobIdRemindVotersJob }()
voters, err := GetReminderVoters()
if err != nil {
logger.Errorf("problem getting voters %s", err)
log.Errorf("problem getting voters %v", err)
return
}
for _, voter := range *voters {
decisions, err := FindUnvotedDecisionsForVoter(&voter)
if err != nil {
logger.Errorf("problem getting unvoted decisions")
log.Errorf("problem getting unvoted decisions: %v", err)
return
}
if len(*decisions) > 0 {

@ -106,7 +106,7 @@ WHERE decisions.status=0 AND :now > due`,
SELECT due FROM decisions WHERE status=0 ORDER BY due LIMIT 1`,
sqlGetVotersForProxy: `
SELECT id, name, reminder
FROM voters WHERE enabled=1 AND id != $1 AND id NOT IN (SELECT voter FROM votes WHERE decision=$2)`,
FROM voters WHERE enabled=1 AND id != $1`,
sqlGetReminderVoters: `
SELECT id, name, reminder FROM voters WHERE enabled=1 AND reminder!='' AND reminder IS NOT NULL`,
sqlFindUnvotedDecisionsForVoter: `
@ -123,47 +123,6 @@ FROM votes
WHERE decision=$1 AND voter=$2`,
}
var db *sqlx.DB
func init() {
failed_statements := make([]string, 0)
for _, sqlStatement := range sqlStatements {
var stmt *sqlx.Stmt
stmt, err := db.Preparex(sqlStatement)
if err != nil {
logger.Criticalf("ERROR parsing statement %s: %s", sqlStatement, err)
failed_statements = append(failed_statements, sqlStatement)
}
stmt.Close()
}
if len(failed_statements) > 0 {
panic(fmt.Sprintf("%d statements failed", len(failed_statements)))
}
migrateConf := &goose.DBConf{
MigrationsDir: config.MigrationsPath,
Env: "production",
Driver: goose.DBDriver{
Name: "sqlite3",
OpenStr: config.DatabaseFile,
Import: "github.com/mattn/go-sqlite3",
Dialect: &goose.Sqlite3Dialect{},
},
}
latest, err := goose.GetMostRecentDBVersion(migrateConf.MigrationsDir)
if err != nil {
logger.Criticalf("getting the most recent database repository version failed: %s", err)
panic(err)
}
err = goose.RunMigrationsOnDb(migrateConf, migrateConf.MigrationsDir, latest, db.DB)
if err != nil {
logger.Criticalf("running database migration failed: %s", err)
panic(err)
}
}
type VoteType uint8
type VoteStatus int8
@ -282,30 +241,86 @@ type Vote struct {
Notes string
}
func (v *Vote) Save() (err error) {
insertVoteStmt, err := db.PrepareNamed(sqlStatements[sqlCreateVote])
type dbHandler struct {
db *sqlx.DB
}
var db *dbHandler
func NewDB(database *sqlx.DB) *dbHandler {
handler := &dbHandler{db: database}
failed_statements := make([]string, 0)
for _, sqlStatement := range sqlStatements {
var stmt *sqlx.Stmt
stmt, err := database.Preparex(sqlStatement)
if err != nil {
log.Criticalf("ERROR parsing statement %s: %s", sqlStatement, err)
failed_statements = append(failed_statements, sqlStatement)
}
stmt.Close()
}
if len(failed_statements) > 0 {
log.Panicf("%d statements failed to prepare", len(failed_statements))
}
migrateConf := &goose.DBConf{
MigrationsDir: config.MigrationsPath,
Env: "production",
Driver: goose.DBDriver{
Name: "sqlite3",
OpenStr: config.DatabaseFile,
Import: "github.com/mattn/go-sqlite3",
Dialect: &goose.Sqlite3Dialect{},
},
}
latest, err := goose.GetMostRecentDBVersion(migrateConf.MigrationsDir)
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
log.Panicf("getting the most recent database repository version failed: %v", err)
}
defer insertVoteStmt.Close()
_, err = insertVoteStmt.Exec(v)
err = goose.RunMigrationsOnDb(migrateConf, migrateConf.MigrationsDir, latest, database.DB)
if err != nil {
logger.Errorf("saving vote failed: %s", err)
return
log.Panicf("running database migration failed: %v", err)
}
return handler
}
func (d *dbHandler) Close() error {
return d.db.Close()
}
func (d *dbHandler) getPreparedNamedStatement(statementKey sqlKey) *sqlx.NamedStmt {
statement, err := d.db.PrepareNamed(sqlStatements[statementKey])
if err != nil {
log.Panicf("Preparing statement failed: %v", err)
}
return statement
}
getVoteStmt, err := db.Preparex(sqlStatements[sqlLoadVote])
func (d *dbHandler) getPreparedStatement(statementKey sqlKey) *sqlx.Stmt {
statement, err := d.db.Preparex(sqlStatements[statementKey])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
log.Panicf("Preparing statement failed: %v", err)
}
return statement
}
func (v *Vote) Save() (err error) {
insertVoteStmt := db.getPreparedNamedStatement(sqlCreateVote)
defer insertVoteStmt.Close()
if _, err = insertVoteStmt.Exec(v); err != nil {
log.Errorf("saving vote failed: %v", err)
return
}
getVoteStmt := db.getPreparedStatement(sqlLoadVote)
defer getVoteStmt.Close()
err = getVoteStmt.Get(v, v.DecisionId, v.VoterId)
if err != nil {
logger.Errorf("getting inserted vote failed: %s", err)
if err = getVoteStmt.Get(v, v.DecisionId, v.VoterId); err != nil {
log.Errorf("getting inserted vote failed: %v", err)
return
}
return
@ -333,6 +348,17 @@ func (v *VoteSums) Percent() int {
return v.Ayes * 100 / totalVotes
}
func (v *VoteSums) CalculateResult(quorum int, majority int) (status VoteStatus, reasoning string) {
if v.VoteCount() < quorum {
status, reasoning = voteStatusDeclined, fmt.Sprintf("Needed quorum of %d has not been reached.", quorum)
} else if (v.Ayes / v.TotalVotes()) < (majority / 100) {
status, reasoning = voteStatusDeclined, fmt.Sprintf("Needed majority of %d%% has not been reached.", majority)
} else {
status, reasoning = voteStatusApproved, "Quorum and majority have been reached"
}
return
}
type VoteForDisplay struct {
Vote
Name string
@ -346,11 +372,7 @@ type DecisionForDisplay struct {
}
func FindDecisionForDisplayByTag(tag string) (decision *DecisionForDisplay, err error) {
decisionStmt, err := db.Preparex(sqlStatements[sqlLoadDecisionByTag])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
decisionStmt := db.getPreparedStatement(sqlLoadDecisionByTag)
defer decisionStmt.Close()
decision = &DecisionForDisplay{}
@ -359,7 +381,8 @@ func FindDecisionForDisplayByTag(tag string) (decision *DecisionForDisplay, err
decision = nil
err = nil
} else {
logger.Errorf("getting motion %s failed: %v", tag, err)
log.Errorf("getting motion %s failed: %v", tag, err)
return
}
}
decision.VoteSums, err = decision.Decision.VoteSums()
@ -374,13 +397,9 @@ func FindDecisionForDisplayByTag(tag string) (decision *DecisionForDisplay, err
func FindDecisionsForDisplayOnPage(page int64, unvoted bool, voter *Voter) (decisions []*DecisionForDisplay, err error) {
var decisionsStmt *sqlx.Stmt
if unvoted && voter != nil {
decisionsStmt, err = db.Preparex(sqlStatements[sqlLoadUnvotedDecisions])
decisionsStmt = db.getPreparedStatement(sqlLoadUnvotedDecisions)
} else {
decisionsStmt, err = db.Preparex(sqlStatements[sqlLoadDecisions])
}
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
decisionsStmt = db.getPreparedStatement(sqlLoadDecisions)
}
defer decisionsStmt.Close()
@ -391,7 +410,7 @@ func FindDecisionsForDisplayOnPage(page int64, unvoted bool, voter *Voter) (deci
rows, err = decisionsStmt.Queryx(page - 1)
}
if err != nil {
logger.Errorf("loading motions for page %d failed: %v", page, err)
log.Errorf("loading motions for page %d failed: %v", page, err)
return
}
defer rows.Close()
@ -399,7 +418,7 @@ func FindDecisionsForDisplayOnPage(page int64, unvoted bool, voter *Voter) (deci
for rows.Next() {
var d DecisionForDisplay
if err = rows.StructScan(&d); err != nil {
logger.Errorf("loading motions for page %d failed: %v", page, err)
log.Errorf("loading motions for page %d failed: %v", page, err)
return
}
d.VoteSums, err = d.Decision.VoteSums()
@ -412,16 +431,12 @@ func FindDecisionsForDisplayOnPage(page int64, unvoted bool, voter *Voter) (deci
}
func (d *Decision) VoteSums() (sums *VoteSums, err error) {
votesStmt, err := db.Preparex(sqlStatements[sqlLoadVoteCountsForDecision])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
votesStmt := db.getPreparedStatement(sqlLoadVoteCountsForDecision)
defer votesStmt.Close()
voteRows, err := votesStmt.Queryx(d.Id)
if err != nil {
logger.Errorf("fetching vote sums for motion %s failed: %v", d.Tag, err)
log.Errorf("fetching vote sums for motion %s failed: %v", d.Tag, err)
return
}
defer voteRows.Close()
@ -431,7 +446,7 @@ func (d *Decision) VoteSums() (sums *VoteSums, err error) {
var vote VoteChoice
var count int
if err = voteRows.Scan(&vote, &count); err != nil {
logger.Errorf("fetching vote sums for motion %s failed: %v", d.Tag, err)
log.Errorf("fetching vote sums for motion %s failed: %v", d.Tag, err)
return
}
switch vote {
@ -447,39 +462,33 @@ func (d *Decision) VoteSums() (sums *VoteSums, err error) {
}
func (d *DecisionForDisplay) LoadVotes() (err error) {
votesStmt, err := db.Preparex(sqlStatements[sqlLoadVotesForDecision])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
votesStmt := db.getPreparedStatement(sqlLoadVotesForDecision)
defer votesStmt.Close()
err = votesStmt.Select(&d.Votes, d.Id)
if err != nil {
logger.Errorf("selecting votes for motion %s failed: %v", d.Tag, err)
log.Errorf("selecting votes for motion %s failed: %v", d.Tag, err)
return
}
return
}
func (d *Decision) OlderExists(unvoted bool, voter *Voter) (result bool, err error) {
var olderStmt *sqlx.Stmt
if unvoted && voter != nil {
olderStmt, err = db.Preparex(sqlStatements[sqlCountOlderThanUnvotedDecision])
} else {
olderStmt, err = db.Preparex(sqlStatements[sqlCountOlderThanDecision])
}
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
defer olderStmt.Close()
olderStmt := db.getPreparedStatement(sqlCountOlderThanUnvotedDecision)
defer olderStmt.Close()
if unvoted && voter != nil {
if err = olderStmt.Get(&result, d.Proposed, voter.Id); err != nil {
logger.Errorf("finding older motions than %s failed: %v", d.Tag, err)
log.Errorf("finding older motions than %s failed: %v", d.Tag, err)
return
}
} else {
olderStmt := db.getPreparedStatement(sqlCountOlderThanDecision)
defer olderStmt.Close()
if err = olderStmt.Get(&result, d.Proposed); err != nil {
logger.Errorf("finding older motions than %s failed: %v", d.Tag, err)
log.Errorf("finding older motions than %s failed: %v", d.Tag, err)
return
}
}
@ -487,76 +496,62 @@ func (d *Decision) OlderExists(unvoted bool, voter *Voter) (result bool, err err
}
func (d *Decision) Create() (err error) {
insertDecisionStmt, err := db.PrepareNamed(sqlStatements[sqlCreateDecision])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
insertDecisionStmt := db.getPreparedNamedStatement(sqlCreateDecision)
defer insertDecisionStmt.Close()
result, err := insertDecisionStmt.Exec(d)
if err != nil {
logger.Errorf("creating motion failed: %s", err)
log.Errorf("creating motion failed: %v", err)
return
}
lastInsertId, err := result.LastInsertId()
if err != nil {
logger.Errorf("getting id of inserted motion failed: %s", err)
log.Errorf("getting id of inserted motion failed: %v", err)
return
}
rescheduleChannel <- JobIdCloseDecisions
getDecisionStmt, err := db.Preparex(sqlStatements[sqlLoadDecisionById])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
getDecisionStmt := db.getPreparedStatement(sqlLoadDecisionById)
defer getDecisionStmt.Close()
err = getDecisionStmt.Get(d, lastInsertId)
if err != nil {
logger.Errorf("getting inserted motion failed: %s", err)
log.Errorf("getting inserted motion failed: %v", err)
return
}
return
}
func (d *Decision) LoadWithId() (err error) {
getDecisionStmt, err := db.Preparex(sqlStatements[sqlLoadDecisionById])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
getDecisionStmt := db.getPreparedStatement(sqlLoadDecisionById)
defer getDecisionStmt.Close()
err = getDecisionStmt.Get(d, d.Id)
if err != nil {
logger.Errorf("loading updated motion failed: %s", err)
log.Errorf("loading updated motion failed: %v", err)
return
}
return
}
func (d *Decision) Update() (err error) {
updateDecisionStmt, err := db.PrepareNamed(sqlStatements[sqlUpdateDecision])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
updateDecisionStmt := db.getPreparedNamedStatement(sqlUpdateDecision)
defer updateDecisionStmt.Close()
result, err := updateDecisionStmt.Exec(d)
if err != nil {
logger.Errorf("updating motion failed: %s", err)
log.Errorf("updating motion failed: %v", err)
return
}
affectedRows, err := result.RowsAffected()
if err != nil {
logger.Errorf("Problem determining the affected rows")
log.Error("Problem determining the affected rows")
return
} else if affectedRows != 1 {
logger.Warningf("wrong number of affected rows: %d (1 expected)", affectedRows)
log.Warningf("wrong number of affected rows: %d (1 expected)", affectedRows)
}
rescheduleChannel <- JobIdCloseDecisions
@ -565,24 +560,20 @@ func (d *Decision) Update() (err error) {
}
func (d *Decision) UpdateStatus() (err error) {
updateStatusStmt, err := db.PrepareNamed(sqlStatements[sqlUpdateDecisionStatus])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
updateStatusStmt := db.getPreparedNamedStatement(sqlUpdateDecisionStatus)
defer updateStatusStmt.Close()
result, err := updateStatusStmt.Exec(d)
if err != nil {
logger.Errorf("setting motion status failed: %s", err)
log.Errorf("setting motion status failed: %v", err)
return
}
affectedRows, err := result.RowsAffected()
if err != nil {
logger.Errorf("determining the affected rows failed: %s", err)
log.Errorf("determining the affected rows failed: %v", err)
return
} else if affectedRows != 1 {
logger.Warningf("wrong number of affected rows: %d (1 expected)", affectedRows)
log.Warningf("wrong number of affected rows: %d (1 expected)", affectedRows)
}
rescheduleChannel <- JobIdCloseDecisions
@ -595,17 +586,13 @@ func (d *Decision) String() string {
}
func FindVoterByAddress(emailAddress string) (voter *Voter, err error) {
findVoterStmt, err := db.Preparex(sqlStatements[sqlLoadEnabledVoterByEmail])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
findVoterStmt := db.getPreparedStatement(sqlLoadEnabledVoterByEmail)
defer findVoterStmt.Close()
voter = &Voter{}
if err = findVoterStmt.Get(voter, emailAddress); err != nil {
if err != sql.ErrNoRows {
logger.Errorf("getting voter for address %s failed: %v", emailAddress, err)
log.Errorf("getting voter for address %s failed: %v", emailAddress, err)
} else {
err = nil
voter = nil
@ -614,72 +601,56 @@ func FindVoterByAddress(emailAddress string) (voter *Voter, err error) {
return
}
func (d *Decision) Close() (err error) {
func (d *Decision) Close() error {
quorum, majority := d.VoteType.QuorumAndMajority()
voteSums, err := d.VoteSums()
if err != nil {
logger.Errorf("getting vote sums failed: %s", err)
return
}
votes := voteSums.VoteCount()
var voteSums *VoteSums
var err error
if votes < quorum {
d.Status = voteStatusDeclined
} else {
votes = voteSums.TotalVotes()
if (voteSums.Ayes / votes) > (majority / 100) {
d.Status = voteStatusApproved
} else {
d.Status = voteStatusDeclined
}
if voteSums, err = d.VoteSums(); err != nil {
log.Errorf("getting vote sums failed: %v", err)
return err
}
var reasoning string
d.Status, reasoning = voteSums.CalculateResult(quorum, majority)
closeDecisionStmt, err := db.PrepareNamed(sqlStatements[sqlUpdateDecisionStatus])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
closeDecisionStmt := db.getPreparedNamedStatement(sqlUpdateDecisionStatus)
defer closeDecisionStmt.Close()
result, err := closeDecisionStmt.Exec(d)
if err != nil {
logger.Errorf("closing vote failed: %s", err)
return
}
affectedRows, err := result.RowsAffected()
if err != nil {
logger.Errorf("getting affected rows failed: %s", err)
log.Errorf("closing vote failed: %v", err)
return err
}
if affectedRows != 1 {
logger.Warningf("wrong number of affected rows: %d (1 expected)", affectedRows)
if affectedRows, err := result.RowsAffected(); err != nil {
log.Errorf("getting affected rows failed: %v", err)
return err
} else if affectedRows != 1 {
log.Warningf("wrong number of affected rows: %d (1 expected)", affectedRows)
}
NotifyMailChannel <- NewNotificationClosedDecision(d, voteSums)
NotifyMailChannel <- NewNotificationClosedDecision(d, voteSums, reasoning)
return
log.Infof("decision %s closed with result %s: reasoning %s", d.Tag, d.Status, reasoning)
return nil
}
func CloseDecisions() (err error) {
getClosableDecisionsStmt, err := db.PrepareNamed(sqlStatements[sqlSelectClosableDecisions])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
getClosableDecisionsStmt := db.getPreparedNamedStatement(sqlSelectClosableDecisions)
defer getClosableDecisionsStmt.Close()
decisions := make([]*Decision, 0)
rows, err := getClosableDecisionsStmt.Queryx(struct{ Now time.Time }{time.Now().UTC()})
if err != nil {
logger.Errorf("fetching closable decisions failed: %s", err)
log.Errorf("fetching closable decisions failed: %v", err)
return
}
defer rows.Close()
for rows.Next() {
decision := &Decision{}
if err = rows.StructScan(decision); err != nil {
logger.Errorf("scanning row failed: %s", err)
log.Errorf("scanning row failed: %v", err)
return
}
decisions = append(decisions, decision)
@ -687,9 +658,9 @@ func CloseDecisions() (err error) {
rows.Close()
for _, decision := range decisions {
logger.Debugf("found closable decision %s", decision.Tag)
log.Debugf("found closable decision %s", decision.Tag)
if err = decision.Close(); err != nil {
logger.Errorf("closing decision %s failed: %s", decision.Tag, err)
log.Errorf("closing decision %s failed: %s", decision.Tag, err)
return
}
}
@ -698,41 +669,32 @@ func CloseDecisions() (err error) {
}
func GetNextPendingDecisionDue() (due *time.Time, err error) {
getNextPendingDecisionDueStmt, err := db.Preparex(sqlStatements[sqlGetNextPendingDecisionDue])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
getNextPendingDecisionDueStmt := db.getPreparedStatement(sqlGetNextPendingDecisionDue)
defer getNextPendingDecisionDueStmt.Close()
row := getNextPendingDecisionDueStmt.QueryRow()
var dueTimestamp time.Time
if err = row.Scan(&dueTimestamp); err != nil {
due = &time.Time{}
if err = row.Scan(due); err != nil {
if err == sql.ErrNoRows {
logger.Debugf("No pending decisions")
log.Debug("No pending decisions")
return nil, nil
}
logger.Errorf("parsing result failed: %s", err)
return
log.Errorf("parsing result failed: %v", err)
return nil, err
}
due = &dueTimestamp
return
}
func GetReminderVoters() (voters *[]Voter, err error) {
getReminderVotersStmt, err := db.Preparex(sqlStatements[sqlGetReminderVoters])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
getReminderVotersStmt := db.getPreparedStatement(sqlGetReminderVoters)
defer getReminderVotersStmt.Close()
voterSlice := make([]Voter, 0)
if err = getReminderVotersStmt.Select(&voterSlice); err != nil {
logger.Errorf("getting voters failed: %s", err)
log.Errorf("getting voters failed: %v", err)
return
}
voters = &voterSlice
@ -741,17 +703,13 @@ func GetReminderVoters() (voters *[]Voter, err error) {
}
func FindUnvotedDecisionsForVoter(voter *Voter) (decisions *[]Decision, err error) {
findUnvotedDecisionsForVoterStmt, err := db.Preparex(sqlStatements[sqlFindUnvotedDecisionsForVoter])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
findUnvotedDecisionsForVoterStmt := db.getPreparedStatement(sqlFindUnvotedDecisionsForVoter)
defer findUnvotedDecisionsForVoterStmt.Close()
decisionsSlice := make([]Decision, 0)
if err = findUnvotedDecisionsForVoterStmt.Select(&decisionsSlice, voter.Id); err != nil {
logger.Errorf("getting unvoted decisions failed: %s", err)
log.Errorf("getting unvoted decisions failed: %v", err)
return
}
decisions = &decisionsSlice
@ -760,34 +718,26 @@ func FindUnvotedDecisionsForVoter(voter *Voter) (decisions *[]Decision, err erro
}
func GetVoterById(id int64) (voter *Voter, err error) {
getVoterByIdStmt, err := db.Preparex(sqlStatements[sqlGetEnabledVoterById])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
getVoterByIdStmt := db.getPreparedStatement(sqlGetEnabledVoterById)
defer getVoterByIdStmt.Close()
voter = &Voter{}
if err = getVoterByIdStmt.Get(voter, id); err != nil {
logger.Errorf("getting voter failed: %s", err)
log.Errorf("getting voter failed: %v", err)
return
}
return
}
func GetVotersForProxy(proxy *Voter, decision *Decision) (voters *[]Voter, err error) {
getVotersForProxyStmt, err := db.Preparex(sqlStatements[sqlGetVotersForProxy])
if err != nil {
logger.Errorf("preparing statement failed: %s", err)
return
}
func GetVotersForProxy(proxy *Voter) (voters *[]Voter, err error) {
getVotersForProxyStmt := db.getPreparedStatement(sqlGetVotersForProxy)
defer getVotersForProxyStmt.Close()
votersSlice := make([]Voter, 0)
if err = getVotersForProxyStmt.Select(&votersSlice, proxy.Id, decision.Id); err != nil {
logger.Errorf("Error getting voters for proxy failed: %s", err)
if err = getVotersForProxyStmt.Select(&votersSlice, proxy.Id); err != nil {
log.Errorf("Error getting voters for proxy failed: %v", err)
return
}
voters = &votersSlice

@ -34,14 +34,14 @@ type NotificationMail interface {
var NotifyMailChannel = make(chan NotificationMail, 1)
func MailNotifier(quitMailNotifier chan int) {
logger.Infof("Launched mail notifier")
log.Info("Launched mail notifier")
for {
select {
case notification := <-NotifyMailChannel:
content := notification.GetNotificationContent()
mailText, err := buildMail(content.template, content.data)
if err != nil {
logger.Errorf("building mail failed: %s", err)
log.Errorf("building mail failed: %v", err)
continue
}
@ -58,10 +58,10 @@ func MailNotifier(quitMailNotifier chan int) {
d := gomail.NewDialer(config.MailServer.Host, config.MailServer.Port, "", "")
if err := d.DialAndSend(m); err != nil {
logger.Errorf("sending mail failed: %s", err)
log.Errorf("sending mail failed: %v", err)
}
case <-quitMailNotifier:
logger.Infof("Ending mail notifier")
log.Info("Ending mail notifier")
return
}
}
@ -75,7 +75,10 @@ func buildMail(templateName string, context interface{}) (mailText *bytes.Buffer
}
mailText = bytes.NewBufferString("")
t.Execute(mailText, context)
if err := t.Execute(mailText, context); err != nil {
log.Errorf("Failed to execute template %s with context %+v: %v", templateName, context, err)
return nil, err
}
return
}
@ -108,11 +111,12 @@ func (n *decisionReplyBase) getSubject() string {
type notificationClosedDecision struct {
notificationBase
decisionReplyBase
voteSums VoteSums
voteSums VoteSums
reasoning string
}
func NewNotificationClosedDecision(decision *Decision, voteSums *VoteSums) NotificationMail {
notification := &notificationClosedDecision{voteSums: *voteSums}
func NewNotificationClosedDecision(decision *Decision, voteSums *VoteSums, reasoning string) NotificationMail {
notification := &notificationClosedDecision{voteSums: *voteSums, reasoning: reasoning}
notification.decision = *decision
return notification
}
@ -123,7 +127,8 @@ func (n *notificationClosedDecision) GetNotificationContent() *notificationConte
data: struct {
*Decision
*VoteSums
}{&n.decision, &n.voteSums},
Reasoning string
}{&n.decision, &n.voteSums, n.reasoning},
subject: fmt.Sprintf("Re: %s - %s - finalised", n.decision.Tag, n.decision.Title),
headers: n.decisionReplyBase.getHeaders(),
recipients: []recipientData{n.notificationBase.getRecipient()},

@ -1,8 +1,10 @@
Dear Board,
{{ with .Decision }}The motion with the identifier {{.Tag}} has been {{.Status}}.
{{ with .Decision }}The motion with the identifier {{.Tag}} has been {{.Status}}.{{ end }}
Motion:
The reasoning for this result is: {{ .Reasoning }}
{{ with .Decision }}Motion:
{{.Title}}
{{.Content}}

Loading…
Cancel
Save