Fix misrouted notifications from SQLite lock contention

send_message silently fell back to the default conversation whenever the
plan-time or slack-channel lookup errored, because the query error was
ignored. A transient "database is locked" (from the channel-creation/sync
routine holding the write lock while making slow Slack API calls) thus
misrouted a service notification to the admin DM instead of the event
channel.

- api.go: capture lookup errors and only treat gorm.ErrRecordNotFound as
  "no service / no channel"; on any other error, fail so the caller retries
  rather than posting to the wrong conversation.
- database.go: open SQLite with WAL journaling and a 10s busy timeout so
  reads proceed alongside the sync writer instead of locking.
- Bump version to 0.2.2.

.gitignore

@@ -1,3 +1,4 @@
 config.yaml
 service-notifications
-service-notifications.db
+service-notifications.db
+sync.sh

README.md

@@ -110,6 +110,7 @@ Get Slack API token by creating an app at https://api.slack.com/apps then go to
 
 Get Planning Center API secrets at https://api.planningcenteronline.com/oauth/applications by creating a personal access token.
 
+You can get a slack user ID by viewing the profile and under the 3 dot menu choose Copy member ID.
 
 ```yaml
 ---
@@ -122,6 +123,9 @@ planning_center:
 
 slack:
     api_token: SLACK_API_TOKEN
-    admin_id: SLACK_UID
+    create_from_weekday: 3
+    default_conversation: SLACK_UID
+    sticky_users:
+        - SLACK_UID
 
 ```

api.go

@@ -2,12 +2,14 @@ package main
 
 import (
 	"encoding/json"
+	"errors"
 	"log"
 	"net/http"
 	"time"
 
 	"github.com/gorilla/mux"
 	"github.com/slack-go/slack"
+	"gorm.io/gorm"
 )
 
 // Commonly used strings.
@@ -96,15 +98,36 @@ func (s *HTTPServer) RegisterAPIRoutes(r *mux.Router) {
 
 		// Get current time and default conversation.
 		now := time.Now().UTC()
-		conversation := app.config.Slack.AdminID
+		conversation := app.config.Slack.DefaultConversation
 
-		// Find plan times that are occuring right now.
+		// Find plan times that are occuring right now. A 60-minute buffer
+		// is applied past ends_at so services that run long still resolve
+		// to their event channel instead of falling back to the default.
+		// Order by starts_at DESC so the most recent active service wins
+		// when a later service's window overlaps an earlier service's buffer.
 		var planTime PlanTimes
-		app.db.Where("time_type='service' AND starts_at < ? AND ends_at > ?", now, now).First(&planTime)
+		err = app.db.Where("time_type='service' AND starts_at < ? AND ends_at > ?", now, now.Add(-60*time.Minute)).Order("starts_at DESC").First(&planTime).Error
+		// A "record not found" simply means no service is occuring right now, in
+		// which case we fall back to the default conversation. Any other error
+		// (e.g. "database is locked") must NOT be swallowed: treating it as "no
+		// service" would silently misroute the message to the default
+		// conversation instead of the event channel. Fail so the caller retries.
+		if err != nil && !errors.Is(err, gorm.ErrRecordNotFound) {
+			log.Println("Error looking up plan time:", err)
+			s.APISendGeneralResp(w, APIERR, "Error looking up plan time")
+			return
+		}
 		if planTime.Plan != 0 {
 			// If plan found, check for the slack channel.
 			var channel SlackChannels
-			app.db.Where("pc_plan = ?", planTime.Plan).First(&channel)
+			err = app.db.Where("pc_plan = ?", planTime.Plan).First(&channel).Error
+			// As above, only "record not found" is a benign result here. On any
+			// other error we must not fall through to the default conversation.
+			if err != nil && !errors.Is(err, gorm.ErrRecordNotFound) {
+				log.Println("Error looking up slack channel:", err)
+				s.APISendGeneralResp(w, APIERR, "Error looking up slack channel")
+				return
+			}
 			if channel.ID != "" {
 				// If slack channel found, update the conversation to the channel ID.
 				conversation = channel.ID

config.go

@@ -35,9 +35,11 @@ type PlanningCenterConfig struct {
 
 // Configurations relating to Slack API/channel creation.
 type SlackConfig struct {
+	CreateFromWeekday   int           `fig:"create_from_weekday"`   // Create ahead from this weekday. -1 value is default and will instead create from the current time of operation.
 	CreateChannelsAhead time.Duration `fig:"create_channels_ahead"` // Amount of time of future services to create channels head for. Defaults to 8 days head.
 	APIToken            string        `fig:"api_token"`
-	AdminID             string        `fig:"admin_id"` // Slack user that administers this app.
+	StickyUsers         []string      `fig:"sticky_users"`         // Users to add to every channel.
+	DefaultConversation string        `fig:"default_conversation"` // Slack user that administers this app.
 }
 
 // Configuration Structure.
@@ -86,6 +88,7 @@ func (a *App) ReadConfig() {
 			Connection: "service-notifications.db",
 		},
 		Slack: SlackConfig{
+			CreateFromWeekday:   -1,
 			CreateChannelsAhead: time.Hour * 24 * 8,
 		},
 	}

database.go

@@ -2,6 +2,7 @@ package main
 
 import (
 	"log"
+	"strings"
 	"time"
 
 	"gorm.io/driver/mysql"
@@ -126,7 +127,21 @@ func (a *App) InitDB() {
 	}
 	// Depending on connection configuration, open the database.
 	if a.config.DB.Type == "sqlite3" {
-		a.db, err = gorm.Open(sqlite.Open(a.config.DB.Connection), dbConfig)
+		// Enable WAL journaling and a busy timeout. Without WAL, a single
+		// long-running writer (e.g. the channel-creation/sync routine, which
+		// interleaves slow Slack API calls with its writes) blocks all readers,
+		// causing "database is locked" on concurrent reads such as the
+		// send_message channel lookup. WAL lets reads proceed alongside the
+		// writer, and the busy timeout makes any remaining contention wait
+		// rather than fail immediately. Append as DSN pragmas, preserving any
+		// query string already present in the configured connection.
+		conn := a.config.DB.Connection
+		sep := "?"
+		if strings.Contains(conn, "?") {
+			sep = "&"
+		}
+		conn += sep + "_journal_mode=WAL&_busy_timeout=10000"
+		a.db, err = gorm.Open(sqlite.Open(conn), dbConfig)
 	} else if a.config.DB.Type == "mysql" {
 		a.db, err = gorm.Open(mysql.Open(a.config.DB.Connection), dbConfig)
 	} else if a.config.DB.Type == "postgres" {

main.go

@@ -13,7 +13,7 @@ import (
 const (
 	serviceName        = "service-notifications"
 	serviceDescription = "Notifications for church services"
-	serviceVersion     = "0.1"
+	serviceVersion     = "0.2.2"
 )
 
 // App is the global application structure for communicating between servers and storing information.

update.go

@@ -13,6 +13,19 @@ import (
 
 // Update planning center database tables with data from PC API.
 func UpdatePCData() {
+	// We don't need to update the archive if we already have data from the past,
+	// as such we get the current time and see if we already have an entry in the future.
+	// Its possible that some people only schedule services once a week, so we check with
+	// the current date subtracted by 14 days.
+	var updateFrom time.Time
+	now := time.Now().UTC()
+	var futurePlan Plans
+	app.db.Where("first_time_at >= ?", now.Add(time.Hour*24*14*-1)).Order("first_time_at ASC").First(&futurePlan)
+	if futurePlan.ID != 0 {
+		// If a future plan exists, we update from past 30 days.
+		updateFrom = now.Add(time.Hour * 24 * 30 * -1)
+	}
+
 	// Get all people.
 	allPeople, err := PCGetAll("/services/v2/people")
 	if err != nil {
@@ -97,7 +110,8 @@ func UpdatePCData() {
 		// Get the plans for this service type.
 		allPlans, err := PCGetAll(fmt.Sprintf("/services/v2/service_types/%d/plans", serviceTypeID))
 		if err != nil {
-			log.Fatalln(err)
+			log.Println("Error getting plans for service type:", serviceTypeID, err)
+			continue
 		}
 		// For each plan, update data in database and pull other plan releated items for updates.
 		for _, data := range allPlans {
@@ -118,6 +132,13 @@ func UpdatePCData() {
 			p.MultiDay = attributes.GetBool("multi_day")
 			p.Dates = attributes.GetString("dates")
 
+			// If either updated at or first time at for the plan is before the update from date,
+			// we can process the update of data. Otherwise, we ignore this service as we do not care
+			// about updating historic data. Updating historic data causes more API traffic than needed.
+			if p.UpdatedAt.Before(updateFrom) && p.FirstTimeAt.Before(updateFrom) {
+				continue
+			}
+
 			// If plan wasn't already created, create it.
 			if p.ID == 0 {
 				p.ID = planID
@@ -132,7 +153,8 @@ func UpdatePCData() {
 			// Get all times for this plan.
 			allPlanTimes, err := PCGetAll(fmt.Sprintf("/services/v2/service_types/%d/plans/%d/plan_times", serviceTypeID, planID))
 			if err != nil {
-				log.Fatalln(err)
+				log.Println("Error getting plan times for plan:", planID, err)
+				continue
 			}
 			// With each time, save it to the database.
 			for _, data := range allPlanTimes {
@@ -168,7 +190,8 @@ func UpdatePCData() {
 			// Get all members of the plan.
 			allTeamMembers, err := PCGetAll(fmt.Sprintf("/services/v2/service_types/%d/plans/%d/team_members", serviceTypeID, planID))
 			if err != nil {
-				log.Fatalln(err)
+				log.Println("Error getting team members for plan:", planID, err)
+				continue
 			}
 			// With each member, update the database.
 			for _, data := range allTeamMembers {
@@ -206,11 +229,13 @@ func UpdateSlackData() {
 	// Get all users from Slack.
 	users, err := app.slack.GetUsers()
 	if err != nil {
-		log.Fatalln(err)
+		log.Println("Error getting Slack users:", err)
+		return
 	}
 	// If no users returned, error as we should have some...
 	if len(users) == 0 {
-		log.Fatalln("No users found in Slack.")
+		log.Println("No users found in Slack.")
+		return
 	}
 	// With each user, update the database.
 	for _, user := range users {
@@ -291,13 +316,41 @@ func UpdateSlackData() {
 	}
 }
 
+/*
+
+Delay on channel descript/topic may not be long enough.
+
+*/
+
 // Create slack channels for upcoming services.
 func CreateSlackChannels() {
-	// For now, we're using the start time of now. I want to update this later to allow
-	// setting a day of the week for slack channels to be created on.
-	// Doing a day of the week will allow for channels to be created ahead of time, then
-	// if people are added to the plan later on, they can be added at the next cron run.
-	startDate := time.Now().UTC()
+	// Start at now.
+	now := time.Now().UTC()
+	startDate := now
+	// If create from weekday is a valid weekday, attempt to turn back the clock to the
+	// most recently past weekday. Use that day as the stating point so we do not
+	// create channels in the future past the date we expect to have channels.
+	// This is useful if you want to run the cron every day to keep channel title
+	// and members up to date, but only want so many channels ahead of a certain weekday.
+	if app.config.Slack.CreateFromWeekday != -1 && app.config.Slack.CreateFromWeekday <= 6 {
+		// Get the current weekday and set the days to subtract to 0.
+		thisWeekday := int(now.Weekday())
+		var daysSub int = 0
+
+		// If this weekday is the day we intend to create from, or if the weekday is
+		// after. We want to just subtract this weekday from create form weekday which
+		// should get us back to the most recent weekday.
+		if thisWeekday >= app.config.Slack.CreateFromWeekday {
+			daysSub = app.config.Slack.CreateFromWeekday - thisWeekday
+		} else {
+			// Otherwise, we have started a new week from that weekday and we need to
+			// add 7 days to the current weekday in our subtraction. This will bring us
+			// not to the next weekday, but the past weekday.
+			daysSub = app.config.Slack.CreateFromWeekday - (thisWeekday + 7)
+		}
+		// Subtract the number of days calculated to bring us to the weekday to create form.
+		startDate = now.Add(time.Hour * 24 * time.Duration(daysSub))
+	}
 	// Last date is start date plus duration of create channels ahead.
 	lastDate := startDate.Add(app.config.Slack.CreateChannelsAhead)
 
@@ -306,7 +359,8 @@ func CreateSlackChannels() {
 	app.db.Where("time_type='service' AND starts_at > ? AND starts_at < ?", startDate, lastDate).Find(&planTimes)
 	// If no plan times matched, exit here.
 	if len(planTimes) == 0 {
-		log.Fatalln("No services found for this time frame.")
+		log.Println("No services found for this time frame.")
+		return
 	}
 
 	// With each plan time found, create a slack channel.
@@ -384,22 +438,28 @@ func CreateSlackChannels() {
 			log.Println("Creating channel:", channel.Name)
 			schan, err := app.slack.CreateConversation(channelInfo)
 			if err != nil {
-				log.Fatalln("Failed to create channel:", err)
+				log.Println("Failed to create channel:", err)
+				continue
 			}
 
 			// If topic is defined, set the topic and purpose.
 			if topic != "" {
-				// Sleep before, as it takes time for Slack APIs
-				// to recongize the channel was created.
-				time.Sleep(10 * time.Second)
-				_, err = app.slack.SetTopicOfConversation(channel.ID, topic)
+				// Keep count of failures so we can try again.
+				failed := 0
+				_, err = app.slack.SetTopicOfConversation(schan.ID, topic)
 				if err != nil {
+					failed++
 					log.Println("Failed to set topic:", err)
 				}
-				_, err = app.slack.SetPurposeOfConversation(channel.ID, topic)
+				_, err = app.slack.SetPurposeOfConversation(schan.ID, topic)
 				if err != nil {
+					failed++
 					log.Println("Failed to set purpose:", err)
 				}
+				// If it failed, make topic empty so we can try again next run.
+				if failed != 0 {
+					topic = ""
+				}
 			}
 
 			// Save the channel to the database.
@@ -421,6 +481,31 @@ func CreateSlackChannels() {
 		// Keep a list of users we need to invite as they are new.
 		var usersToInvite []string
 
+		// For each sticky user, invite them.
+		for _, stickyUser := range app.config.Slack.StickyUsers {
+			// Check if they were already invited.
+			alreadyInvited := false
+			for _, uid := range invited {
+				if uid == stickyUser {
+					alreadyInvited = true
+					break
+				}
+			}
+
+			// Make sure they were not already added to the list of users.
+			for _, uid := range usersToInvite {
+				if uid == stickyUser {
+					alreadyInvited = true
+					break
+				}
+			}
+
+			// If not already invited, add to the list of users to invite.
+			if !alreadyInvited {
+				usersToInvite = append(usersToInvite, stickyUser)
+			}
+		}
+
 		// For each person on the plan, see if we need to invite them.
 		for _, personOnPlan := range peopleOnPlan {
 			// Find the slack user for the planning center person.