Global code ovehaul - remove CAS and other, add 15 minute greet check

- Remove CAS, as it no longer works for us
- Remove other checks
- Implement 15 minute greet timeout check
- Fix chat logos
- Ditch thirdparty logger, use stdlib log facility wrapper for logging

internal/elog/clock.go

@@ -0,0 +1,14 @@
+package elog
+
+import "time"
+
+// nowUTC is the single clock every path and timestamp derives from.
+//
+// It is not time.Now at each call site: a log line stamped in local time beside a
+// directory named for UTC is a bug report waiting to happen, and a file that rolls
+// over at midnight local time while its lines are stamped UTC is worse.
+func nowUTC() time.Time {
+	return time.Now().UTC()
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/format.go

@@ -0,0 +1,78 @@
+package elog
+
+// The value formatters: small conversions shared by the write path (which builds
+// path components) and the renderer (which builds inline fields). They are shared
+// by two topics, so they get a file of their own rather than living in one of them
+// and making the other look in the wrong place.
+
+import (
+	"strconv"
+	"strings"
+)
+
+// field renders "key=value", or empty when the value is empty. Empty fields are
+// omitted: a bare "username=@" is worse than nothing.
+//
+// It lives here rather than in render.go because sizeField, a formatter, is one of
+// its callers — and a helper two topics use belongs to neither.
+func field(key string, value string) string {
+	if value == "" {
+		return ""
+	}
+
+	return key + "=" + value
+}
+
+// joinFields drops empty fragments and joins the rest with single spaces.
+func joinFields(parts []string) string {
+	kept := make([]string, 0, len(parts))
+
+	for _, p := range parts {
+		if p != "" {
+			kept = append(kept, p)
+		}
+	}
+
+	return strings.Join(kept, " ")
+}
+
+// itoa renders an int64 for a path component or an inline field.
+func itoa(v int64) string {
+	return strconv.FormatInt(v, 10)
+}
+
+// itoaInt renders an int for a rendered field.
+func itoaInt(v int) string {
+	return strconv.Itoa(v)
+}
+
+// itoaFloat renders a float for a rendered field.
+func itoaFloat(v float64) string {
+	return strconv.FormatFloat(v, 'g', -1, 64)
+}
+
+// atUsername renders a username with the conventional @ prefix, or empty.
+func atUsername(name string) string {
+	if name == "" {
+		return ""
+	}
+
+	return "@" + name
+}
+
+// seconds renders a duration in seconds with its unit.
+func seconds(n int) string {
+	return itoaInt(n) + "s"
+}
+
+// sizeField renders a byte count, omitted when unknown. A size of 0 means
+// Telegram did not tell us, not that the file was empty.
+func sizeField(n int64) string {
+	if n <= 0 {
+		return ""
+	}
+
+	return field("size", itoa(n))
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/globals.go

@@ -0,0 +1,59 @@
+package elog
+
+import (
+	"errors"
+	"sync"
+	"time"
+)
+
+const (
+	// chatLockIdleTimeout is how long a chat's lock entry may sit unused before it
+	// is evicted. Without it the registry grows by one entry per chat ever seen.
+	chatLockIdleTimeout = time.Hour
+
+	// stampLayout is the per-line timestamp. GMT+0 with millisecond precision.
+	stampLayout = "15:04:05.000"
+
+	// logFilePerm is the mode for a newly created chat log file.
+	logFilePerm = 0o644
+
+	// logDirPerm is the mode for the chat, year and month directories.
+	//
+	// It is deliberately not logFilePerm. A directory needs the execute bit to
+	// be traversable, and 0o644 has none, so creating the tree with the file mode
+	// makes every subsequent open inside it fail with EACCES rather than ENOENT
+	// — a failure reportFailure would swallow, leaving chat logging to silently
+	// produce no files at all.
+	//
+	// The two live in one block on purpose: they are a pair that must never be
+	// confused with each other, and keeping them adjacent is what makes confusing
+	// them hard. They are here, in globals.go, because that is where every
+	// package-level const belongs — the pair argument was weighed against rule 2
+	// and rule 2 won, once, on the record.
+	logDirPerm = 0o755
+)
+
+var (
+	// errNotDirectory marks a chat_logs path that exists but is a regular file.
+	errNotDirectory = errors.New("chat_logs path is not a directory")
+
+	// root is the configured chat-logs directory. Empty means chat logging is
+	// disabled and every Log* call is a no-op.
+	root string
+
+	// failing records that a write error has been reported and not yet cleared,
+	// so a persistent failure (a full disk) logs once instead of once per event.
+	failing bool
+
+	// stateMu guards root and failing.
+	stateMu sync.RWMutex
+
+	// registryMu guards locks. It is never held while a chat lock is acquired,
+	// or the whole logger would serialise.
+	registryMu sync.Mutex
+
+	// locks is the per-chat lock registry.
+	locks = map[int64]*chatLock{}
+)
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/init.go

@@ -0,0 +1,46 @@
+package elog
+
+import (
+	"fmt"
+	"os"
+)
+
+// Init switches chat logging on.
+//
+// An empty root disables it, and every Log* call becomes a no-op — chat logging
+// is optional. A non-empty root must already exist: a path that does not is a
+// typo, and silently logging nowhere is the worst possible response to one, so
+// this returns an error and moon.ParseConfig treats it as fatal.
+func Init(rootDir string) error {
+	if rootDir == "" {
+		setRoot("")
+
+		return nil
+	}
+
+	info, err := os.Stat(rootDir)
+	if err != nil {
+		return fmt.Errorf("chat_logs directory %s is not usable: %w", rootDir, err)
+	}
+
+	if !info.IsDir() {
+		return fmt.Errorf("%w: %s", errNotDirectory, rootDir)
+	}
+
+	setRoot(rootDir)
+
+	return nil
+}
+
+// Close disables chat logging.
+//
+// Nothing is held open between lines, so there are no handles to close; this
+// exists so shutdown has a symmetric counterpart to Init and so a misbehaving
+// caller can stop writing.
+func Close() error {
+	setRoot("")
+
+	return nil
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/message.go

@@ -0,0 +1,127 @@
+package elog
+
+import (
+	"github.com/NicoNex/echotron/v3"
+)
+
+// LogMessage records a chat message.
+//
+// It handles both ordinary messages — text, media, captions, replies — and the
+// service messages Telegram delivers as a Message with a field set instead of
+// text: joins, leaves, title changes, pins, migrations, forum topics. A message
+// with nothing describable is skipped rather than logged as noise.
+func LogMessage(msg *echotron.Message) {
+	logMessage(msg, "")
+}
+
+// LogEditedMessage records an edited message. The line is marked "edited" so a
+// reader can tell it apart from the original.
+func LogEditedMessage(msg *echotron.Message) {
+	logMessage(msg, "edited ")
+}
+
+// logMessage is the shared body of LogMessage and LogEditedMessage.
+func logMessage(msg *echotron.Message, prefix string) {
+	if _, on := chatLogRoot(); !on || msg == nil {
+		return
+	}
+
+	for _, body := range describeMessage(msg) {
+		appendLine(msg.Chat.ID, prefix+renderLine(msg.Chat, msg.From, body))
+	}
+}
+
+// describeMessage returns one rendered body per line to write. It returns more
+// than one only for a multi-member join, where one line per newcomer keeps each
+// fact greppable instead of cramming every newcomer onto one line.
+func describeMessage(msg *echotron.Message) []string {
+	if bodies := describeService(msg); len(bodies) > 0 {
+		return bodies
+	}
+
+	body := describePayload(msg)
+	if body == "" {
+		return nil
+	}
+
+	if msg.ReplyToMessage != nil {
+		body += " reply_to=" + itoaInt(msg.ReplyToMessage.ID)
+	}
+
+	return []string{body}
+}
+
+// describeService renders the service-message fields, newest-first, and returns
+// nil when the message is not a service message.
+func describeService(msg *echotron.Message) []string {
+	var bodies []string
+
+	// A join with N newcomers writes N lines.
+	for _, u := range msg.NewChatMembers {
+		if u == nil {
+			continue
+		}
+
+		bodies = append(bodies, describeReference(u)+" joined the chat")
+	}
+
+	if msg.LeftChatMember != nil {
+		bodies = append(bodies, describeReference(msg.LeftChatMember)+" left the chat")
+	}
+
+	if msg.NewChatTitle != "" {
+		bodies = append(bodies, "chat title changed to "+msg.NewChatTitle)
+	}
+
+	if len(msg.NewChatPhoto) > 0 {
+		bodies = append(bodies, "chat photo changed")
+	}
+
+	if msg.PinnedMessage != nil {
+		bodies = append(bodies, "pinned message "+itoaInt(msg.PinnedMessage.ID))
+	}
+
+	if msg.GroupChatCreated {
+		bodies = append(bodies, "group chat created")
+	}
+
+	if msg.MigrateToChatID != 0 {
+		bodies = append(bodies, "chat migrated to "+itoa(int64(msg.MigrateToChatID)))
+	}
+
+	if msg.MigrateFromChatID != 0 {
+		bodies = append(bodies, "chat migrated from "+itoa(int64(msg.MigrateFromChatID)))
+	}
+
+	if msg.ConnectedWebsite != "" {
+		bodies = append(bodies, "connected website "+msg.ConnectedWebsite)
+	}
+
+	if msg.ForumTopicCreated != nil {
+		bodies = append(bodies, "forum topic "+msg.ForumTopicCreated.Name+" created")
+	}
+
+	if msg.ForumTopicClosed != nil {
+		bodies = append(bodies, "forum topic closed")
+	}
+
+	if msg.ForumTopicReopened != nil {
+		bodies = append(bodies, "forum topic reopened")
+	}
+
+	if msg.GeneralForumTopicHidden != nil {
+		bodies = append(bodies, "general forum topic hidden")
+	}
+
+	if msg.GeneralForumTopicUnhidden != nil {
+		bodies = append(bodies, "general forum topic unhidden")
+	}
+
+	if msg.VideoChatScheduled != nil {
+		bodies = append(bodies, "video chat scheduled")
+	}
+
+	return bodies
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/render.go

@@ -0,0 +1,248 @@
+package elog
+
+import (
+	"fmt"
+	"strings"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// renderLine assembles one log line:
+//
+//	21:33:07.123 in chat -1001 (title=…) user 42 (first_name=…) says …
+//
+// Empty field groups are dropped entirely rather than printed as empty parens.
+func renderLine(chat echotron.Chat, user *echotron.User, body string) string {
+	var b strings.Builder
+
+	b.WriteString(nowUTC().Format(stampLayout))
+	b.WriteString(" in chat ")
+	b.WriteString(itoa(chat.ID))
+
+	if desc := describeChat(&chat); desc != "" {
+		b.WriteString(" (")
+		b.WriteString(desc)
+		b.WriteString(")")
+	}
+
+	if user != nil {
+		b.WriteString(" user ")
+		b.WriteString(itoa(user.ID))
+
+		if desc := describeUser(user); desc != "" {
+			b.WriteString(" (")
+			b.WriteString(desc)
+			b.WriteString(")")
+		}
+	}
+
+	if body != "" {
+		b.WriteString(" ")
+		b.WriteString(body)
+	}
+
+	return b.String()
+}
+
+// describeChat renders a chat's identity fields. Type is deliberately omitted:
+// the user-specified format has no slot for it, and which of title / first_name
+// is present already distinguishes group from private chat.
+func describeChat(c *echotron.Chat) string {
+	if c == nil {
+		return ""
+	}
+
+	return joinFields([]string{
+		field("title", c.Title),
+		field("username", atUsername(c.Username)),
+		field("first_name", c.FirstName),
+		field("last_name", c.LastName),
+	})
+}
+
+// describeUser renders a user's identity fields.
+func describeUser(u *echotron.User) string {
+	if u == nil {
+		return ""
+	}
+
+	return joinFields([]string{
+		field("first_name", u.FirstName),
+		field("last_name", u.LastName),
+		field("username", atUsername(u.Username)),
+	})
+}
+
+// describePayload renders what a message carries: media first, then a caption,
+// because "post photo (…) caption" reads better than the reverse.
+func describePayload(m *echotron.Message) string {
+	kind, details := describeMedia(m)
+
+	var b strings.Builder
+
+	if kind != "" {
+		b.WriteString("post ")
+		b.WriteString(kind)
+
+		if details != "" {
+			b.WriteString(" (")
+			b.WriteString(details)
+			b.WriteString(")")
+		}
+	}
+
+	// A caption accompanies the media rather than replacing it: "post photo (…)"
+	// alone loses what the user actually said.
+	if m.Text != "" {
+		if b.Len() > 0 {
+			b.WriteString(" ")
+		}
+
+		b.WriteString("says ")
+		b.WriteString(m.Text)
+	}
+
+	return b.String()
+}
+
+// describeMedia returns the media kind and its key info. The first media field
+// set on the message wins, in the order listed in the SPEC.
+func describeMedia(m *echotron.Message) (string, string) {
+	switch {
+	case len(m.Photo) > 0:
+		// The array is ordered smallest first, so the last entry is the largest.
+		best := m.Photo[len(m.Photo)-1]
+
+		return "photo", joinFields([]string{
+			dims(best.Width, best.Height),
+			sizeField(int64(best.FileSize)),
+		})
+
+	case m.Video != nil:
+		return "video", joinFields([]string{
+			field("file_name", m.Video.FileName),
+			field("mime", m.Video.MimeType),
+			dims(m.Video.Width, m.Video.Height),
+			field("duration", seconds(m.Video.Duration)),
+			sizeField(m.Video.FileSize),
+		})
+
+	case m.Animation != nil:
+		return "animation", joinFields([]string{
+			field("file_name", m.Animation.FileName),
+			field("mime", m.Animation.MimeType),
+			dims(m.Animation.Width, m.Animation.Height),
+			field("duration", seconds(m.Animation.Duration)),
+			sizeField(m.Animation.FileSize),
+		})
+
+	case m.Audio != nil:
+		return "audio", joinFields([]string{
+			field("title", m.Audio.Title),
+			field("file_name", m.Audio.FileName),
+			field("mime", m.Audio.MimeType),
+			field("duration", seconds(m.Audio.Duration)),
+			sizeField(m.Audio.FileSize),
+		})
+
+	case m.Voice != nil:
+		return "voice", joinFields([]string{
+			field("mime", m.Voice.MimeType),
+			field("duration", seconds(m.Voice.Duration)),
+			sizeField(m.Voice.FileSize),
+		})
+
+	case m.VideoNote != nil:
+		return "video_note", joinFields([]string{
+			dims(m.VideoNote.Length, m.VideoNote.Length),
+			field("duration", seconds(m.VideoNote.Duration)),
+			sizeField(int64(m.VideoNote.FileSize)),
+		})
+
+	case m.Sticker != nil:
+		return "sticker", joinFields([]string{
+			field("emoji", m.Sticker.Emoji),
+			field("set", m.Sticker.SetName),
+			dims(m.Sticker.Width, m.Sticker.Height),
+			field("video", itoaBool(m.Sticker.IsVideo)),
+			field("animated", itoaBool(m.Sticker.IsAnimated)),
+		})
+
+	case m.Document != nil:
+		return "document", joinFields([]string{
+			field("file_name", m.Document.FileName),
+			field("mime", m.Document.MimeType),
+			sizeField(m.Document.FileSize),
+		})
+
+	case m.Contact != nil:
+		return "contact", joinFields([]string{
+			field("phone", m.Contact.PhoneNumber),
+			field("first_name", m.Contact.FirstName),
+			field("last_name", m.Contact.LastName),
+			field("user_id", itoaInt(m.Contact.UserID)),
+		})
+
+	case m.Location != nil:
+		return "location", joinFields([]string{
+			field("lat", itoaFloat(m.Location.Latitude)),
+			field("lon", itoaFloat(m.Location.Longitude)),
+		})
+
+	case m.Venue != nil:
+		parts := []string{
+			field("title", m.Venue.Title),
+			field("address", m.Venue.Address),
+		}
+
+		if m.Venue.Location != nil {
+			parts = append(parts,
+				field("lat", itoaFloat(m.Venue.Location.Latitude)),
+				field("lon", itoaFloat(m.Venue.Location.Longitude)))
+		}
+
+		return "venue", joinFields(parts)
+
+	case m.Dice != nil:
+		return "dice", joinFields([]string{
+			field("emoji", m.Dice.Emoji),
+			field("value", itoaInt(m.Dice.Value)),
+		})
+	}
+
+	return "", ""
+}
+
+// dims renders "WxH", or empty when the dimensions are unknown.
+func dims(w int, h int) string {
+	if w <= 0 || h <= 0 {
+		return ""
+	}
+
+	return itoaInt(w) + "x" + itoaInt(h)
+}
+
+// itoaBool renders a boolean for an inline field.
+func itoaBool(b bool) string {
+	if b {
+		return "true"
+	}
+
+	return "false"
+}
+
+// describeReference renders "user 42 (first_name=Ann)", used for the newcomer in
+// a service message and for the member in a status change.
+func describeReference(u *echotron.User) string {
+	if u == nil {
+		return "user unknown"
+	}
+
+	if desc := describeUser(u); desc != "" {
+		return fmt.Sprintf("user %d (%s)", u.ID, desc)
+	}
+
+	return fmt.Sprintf("user %d", u.ID)
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/retraction.go

@@ -0,0 +1,24 @@
+package elog
+
+import (
+	"github.com/NicoNex/echotron/v3"
+)
+
+// LogGreetingRetracted records that we deleted a greeting of our own — one the
+// addressed member never answered, because they were banned for the silence.
+//
+// The log is append-only, so the question's original line stays where it was and
+// this line says what became of it. A reader must be able to tell that the room
+// asked a question and later removed it, rather than finding a line that
+// describes a message which no longer exists.
+func LogGreetingRetracted(chat *echotron.Chat, user *echotron.User, messageID int) {
+	if _, on := chatLogRoot(); !on || chat == nil {
+		return
+	}
+
+	body := "greeting " + itoaInt(messageID) + " retracted, member banned without answering"
+
+	appendLine(chat.ID, renderLine(*chat, user, body))
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/root.go

@@ -0,0 +1,44 @@
+package elog
+
+// The chat-logs root: where the tree lives, and whether logging is on at all.
+//
+// The state itself is in globals.go with the rest of the package-level variables;
+// this file holds only the accessors, because "is it on and where" is one question
+// with one answer and must not be asked in two pieces.
+
+// ChatLoggingEnabled reports whether chat logging is currently switched on.
+//
+// Exported so another package can assert the post-shutdown state instead of
+// inferring it from the absence of files.
+func ChatLoggingEnabled() (string, bool) {
+	return chatLogRoot()
+}
+
+// chatLogRoot returns the configured root and reports whether chat logging is
+// on, in a *single* read.
+//
+// The two must not be asked separately: a Close landing between an enabled()
+// check and a rootDir() read would leave the caller with an empty root, and
+// filepath.Join("", ...) silently yields a path relative to the working
+// directory — chat logs would be written wherever the supervisor happened to
+// start the process.
+func chatLogRoot() (string, bool) {
+	stateMu.RLock()
+	defer stateMu.RUnlock()
+
+	return root, root != ""
+}
+
+// setRoot switches chat logging on or off.
+func setRoot(dir string) {
+	stateMu.Lock()
+	defer stateMu.Unlock()
+
+	root = dir
+
+	if dir == "" {
+		failing = false
+	}
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/status.go

@@ -0,0 +1,63 @@
+package elog
+
+import (
+	"strings"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// LogUserStatus records a change to a chat member's status — join, leave, ban,
+// promote, demote, restrict — as carried by Update.ChatMember.
+func LogUserStatus(ev *echotron.ChatMemberUpdated) {
+	if _, on := chatLogRoot(); !on || ev == nil {
+		return
+	}
+
+	who := ev.NewChatMember.User
+	if who == nil {
+		who = ev.OldChatMember.User
+	}
+
+	var b strings.Builder
+
+	// The subject is already rendered by renderLine's "user <id> (<desc>)"
+	// prefix, so the body starts at the transition itself.
+	b.WriteString("status ")
+	b.WriteString(orUnknown(ev.OldChatMember.Status))
+	b.WriteString(" -> ")
+	b.WriteString(orUnknown(ev.NewChatMember.Status))
+
+	if ev.NewChatMember.CustomTitle != "" {
+		b.WriteString(" custom_title=")
+		b.WriteString(ev.NewChatMember.CustomTitle)
+	}
+
+	b.WriteString(" by ")
+	b.WriteString(describeUserRef(&ev.From))
+
+	appendLine(ev.Chat.ID, renderLine(ev.Chat, who, b.String()))
+}
+
+// describeUserRef renders a value-type User reference.
+func describeUserRef(u *echotron.User) string {
+	if u == nil {
+		return "user unknown"
+	}
+
+	if desc := describeUser(u); desc != "" {
+		return "user " + itoa(u.ID) + " (" + desc + ")"
+	}
+
+	return "user " + itoa(u.ID)
+}
+
+// orUnknown renders a status, or a placeholder when Telegram sent none.
+func orUnknown(status string) string {
+	if status == "" {
+		return "unknown"
+	}
+
+	return status
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/types.go

@@ -0,0 +1,21 @@
+package elog
+
+import (
+	"sync"
+	"time"
+)
+
+// chatLock serialises writes for one chat so that two goroutines cannot splice
+// their lines into the same file.
+type chatLock struct {
+	mu sync.Mutex
+
+	// refs counts goroutines holding or waiting for this entry. It is only
+	// ever read or written while registryMu is held, which is what makes it a
+	// usable proof of "nobody is holding this" during eviction.
+	refs int
+
+	lastUsed time.Time
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/elog/write.go

@@ -0,0 +1,148 @@
+package elog
+
+import (
+	"os"
+	"path/filepath"
+	"time"
+
+	"bunny-bot/internal/mylog"
+)
+
+// acquire returns the chat's lock with this goroutine holding a reference.
+func acquire(chatID int64) *chatLock {
+	registryMu.Lock()
+
+	l, ok := locks[chatID]
+	if !ok {
+		l = &chatLock{}
+		locks[chatID] = l
+	}
+
+	l.refs++
+	l.lastUsed = time.Now()
+
+	evictIdleLocked()
+
+	registryMu.Unlock()
+
+	l.mu.Lock()
+
+	return l
+}
+
+// release drops this goroutine's reference and unlocks the chat.
+func release(l *chatLock) {
+	l.mu.Unlock()
+
+	registryMu.Lock()
+
+	l.refs--
+	l.lastUsed = time.Now()
+
+	registryMu.Unlock()
+}
+
+// evictIdleLocked drops registry entries nobody is holding and that have been
+// idle for longer than chatLockIdleTimeout.
+//
+// Safety rests on refs: it is only ever changed while registryMu is held, so
+// observing refs == 0 here is a proof that no goroutine holds the entry, not a
+// guess. Evicting a held entry would let a second writer take a *different*
+// mutex for the same chat, which is precisely the interleaving the lock exists
+// to prevent. The caller must hold registryMu.
+func evictIdleLocked() {
+	cutoff := time.Now().Add(-chatLockIdleTimeout)
+
+	for id, l := range locks {
+		if l.refs == 0 && l.lastUsed.Before(cutoff) {
+			delete(locks, id)
+		}
+	}
+}
+
+// appendLine writes one line to the chat's log for the day containing now.
+//
+// The whole protocol is set_mutex -> MkdirAll -> open|create -> write -> close,
+// with unset_mutex deferred. Nothing is held open between lines.
+func appendLine(chatID int64, line string) {
+	// One read of both the root and whether logging is on, so a Close racing
+	// this call can never leave us with an empty root and a relative path.
+	dir, on := chatLogRoot()
+	if !on {
+		return
+	}
+
+	lock := acquire(chatID)
+
+	defer release(lock)
+
+	// One clock for both the path and the line: using Message.Date for one and
+	// time.Now() for the other would let a line carry a date its own path
+	// disagrees with.
+	now := nowUTC()
+
+	dayDir := filepath.Join(dir, itoa(chatID), now.Format("2006"), now.Format("01"))
+	path := filepath.Join(dayDir, now.Format("02")+".txt")
+
+	// MkdirAll creates every missing parent, so this covers the chat directory
+	// and the year too. No need to pre-create anything.
+	if err := os.MkdirAll(dayDir, logDirPerm); err != nil {
+		reportFailure(err)
+
+		return
+	}
+
+	f, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, logFilePerm)
+	if err != nil {
+		reportFailure(err)
+
+		return
+	}
+
+	_, writeErr := f.WriteString(line + "\n")
+	closeErr := f.Close()
+
+	if writeErr != nil {
+		reportFailure(writeErr)
+
+		return
+	}
+
+	if closeErr != nil {
+		reportFailure(closeErr)
+
+		return
+	}
+
+	reportRecovered()
+}
+
+// reportFailure sends a write failure to the main log, but only the first one
+// until a write succeeds again. A full disk would otherwise produce one error
+// per chat event and drown the very log meant to explain it.
+func reportFailure(err error) {
+	stateMu.Lock()
+	already := failing
+	failing = true
+	stateMu.Unlock()
+
+	if already {
+		return
+	}
+
+	mylog.Errorf("CHAT LOG WRITE FAILED, further failures suppressed until a write succeeds: %s", err)
+}
+
+// reportRecovered clears the suppression after a successful write.
+func reportRecovered() {
+	stateMu.Lock()
+	was := failing
+	failing = false
+	stateMu.Unlock()
+
+	if was {
+		mylog.Info("Chat logging recovered")
+	}
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/animation.go

@@ -1,28 +0,0 @@
-package moon
-
-import (
-	"fmt"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-// animation parses message with animation.
-func animation(msg *echotron.Update) {
-	if Cfg.LogChats {
-		ChatLog(
-			msg.Message.Chat.ID,
-			fmt.Sprintf(
-				"User %s %s (username = %s, id = %d) sent animation to chat %s %s (%d)",
-				msg.Message.From.FirstName,
-				msg.Message.From.LastName,
-				msg.Message.From.Username,
-				msg.Message.From.ID,
-				msg.Message.Chat.Type,
-				msg.Message.Chat.Title,
-				msg.Message.Chat.ID,
-			),
-		)
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/casChatAPI.go

@@ -1,100 +0,0 @@
-package moon
-
-import (
-	"encoding/json"
-	"fmt"
-	"io"
-	"net/http"
-	"time"
-
-	"github.com/hjson/hjson-go"
-)
-
-// CasCheckID check given telegram user id vs CAS spammers base.
-// https://api.cas.chat/check?user_id=821871410
-func CasCheckID(id int64) (bool, error) {
-	var (
-		result bool
-		err    error
-		url    = fmt.Sprintf("https://api.cas.chat/check?user_id=%d", id)
-		c      = &http.Client{
-			Timeout: 15 * time.Second,
-		}
-		banned    CasTrue
-		notBanned CasFalse
-	)
-
-	resp, err := c.Get(url) //nolint: bodyclose, noctx
-
-	if err != nil {
-		return result, fmt.Errorf("unable to query api.cas.chat, %w", err)
-	}
-
-	// Looks like we should clse body as it it recommends in docs: https://pkg.go.dev/net/http .
-	defer func(Body io.ReadCloser) {
-		err := Body.Close()
-
-		if err != nil {
-			Log.Errorf("Unable to close response body for request to %s: %s", url, err)
-		}
-	}(resp.Body)
-
-	// Client should not return with http status code other than 200.
-	if resp.StatusCode > 200 {
-		return result, fmt.Errorf( //nolint: err113
-			"api.cas.chat returns non-200 http status code: %d %s",
-			resp.StatusCode, resp.Status)
-	}
-
-	body, err := io.ReadAll(resp.Body)
-
-	if err != nil {
-		return result, fmt.Errorf("unable to read response from api.cas.chat, %w", err)
-	}
-
-	// looks like go native json decoder is pretty shitty, so we'll take hjson as less restrictive parser, parse json
-	// encode it back to struct, then parse struct as encode/json
-
-	var tmp map[string]any
-	err = hjson.Unmarshal(body, &tmp)
-
-	// Не удалось распарсить.
-	if err != nil {
-		return result, fmt.Errorf("unable to parse response from api.cas.chat via hjson: %w", err)
-	}
-
-	tmpjson, err := json.Marshal(tmp)
-
-	// Не удалось преобразовать map-ку в json.
-	if err != nil {
-		return result, fmt.Errorf(
-			"unable to parse back to json response from api.cas.chat parsed by hjson: %w", err)
-	}
-
-	if err := json.Unmarshal(tmpjson, &notBanned); err == nil {
-		// if ok field in json == false, then user is not in ban. (records about id not found)
-		if !notBanned.Ok {
-			return false, err
-		}
-	} // At this point we just ignore err != nil, because it *can be* other json type.
-
-	if err := json.Unmarshal(body, &banned); err == nil {
-		// if ok field in json == true, then user is banned. (records about id are found)
-		if banned.Ok {
-			Log.Debugf(
-				"api.cas.chat reported user with id=%d as banned: offences=%d ban_time=%s",
-				id,
-				banned.Result.Offenses,
-				banned.Result.TimeAdded,
-			)
-
-			return true, err
-		}
-
-		return result, fmt.Errorf("api.cas.chat returns strange structure: %s", string(body)) //nolint: err113
-	} // At this point we can't ignore err != nil because we do not know (yet?) other forms of json reply from cas api.
-
-	return result, fmt.Errorf("unable to parse response from api.cas.chat: %s", string(body)) //nolint: err113
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/chatMemberUpdated.go

@@ -1,208 +0,0 @@
-package moon
-
-import (
-	"fmt"
-	"slices"
-	"time"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-// newChatMember parses one of types ChatMemberUpdated event.
-// https://core.telegram.org/bots/api#chatmemberupdated
-func chatMemberUpdated(msg *echotron.Update) {
-	AddChat(&msg.ChatMember.Chat)
-	AddUser(msg.ChatMember.NewChatMember.User)
-
-	Log.Infof(
-		"User %s %s (username = %s, id = %d) in chat %s %s (%d) now %s was %s",
-		msg.ChatMember.NewChatMember.User.FirstName,
-		msg.ChatMember.NewChatMember.User.LastName,
-		msg.ChatMember.NewChatMember.User.Username,
-		msg.ChatMember.NewChatMember.User.ID,
-		msg.ChatMember.Chat.Type,
-		msg.ChatMember.Chat.Title,
-		msg.ChatMember.Chat.ID,
-		msg.ChatMember.NewChatMember.Status,
-		msg.ChatMember.OldChatMember.Status,
-	)
-
-	Log.Debugf(
-		"Add %s %s (%d) to list of known chats",
-		msg.ChatMember.Chat.Type,
-		msg.ChatMember.Chat.Title,
-		msg.ChatMember.Chat.ID,
-	)
-
-	ChatList = append(ChatList, msg.ChatMember.Chat.ID)
-	slices.Sort(ChatList)
-	ChatList = slices.Compact(ChatList)
-
-	// Check some other attributes.
-	switch {
-	case msg.ChatMember.OldChatMember.Status == "left" && msg.ChatMember.NewChatMember.Status == "member":
-		Log.Infof(
-			"Getting info about user %s %s (username = %s, id = %d) in chat %s %s (%d) from LeftMembers DB",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-		)
-
-		leftTimestampString := Cfg.GetValue(
-			"LeftMembers",
-			fmt.Sprintf("%d", msg.ChatMember.Chat.ID),
-			fmt.Sprintf("%d", msg.ChatMember.NewChatMember.User.ID),
-		)
-
-		// Yes, this member definitely left chat at some point, we have no question to him/her.
-		if leftTimestampString != "" {
-			Log.Infof(
-				"User %s %s (username = %s, id = %d) in chat %s %s (%d) found in from LeftMembers DB",
-				msg.ChatMember.NewChatMember.User.FirstName,
-				msg.ChatMember.NewChatMember.User.LastName,
-				msg.ChatMember.NewChatMember.User.Username,
-				msg.ChatMember.NewChatMember.User.ID,
-				msg.ChatMember.Chat.Type,
-				msg.ChatMember.Chat.Title,
-				msg.ChatMember.Chat.ID,
-			)
-
-			return
-		}
-
-		Log.Infof(
-			"User %s %s (username = %s, id = %d) in chat %s %s (%d) not found in LeftMembers DB",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-		)
-
-		// Spam bots come with these attributes.
-		// msg.ChatMember.NewChatMember.Status = "member"
-		// msg.ChatMember.OldChatMember.User != nil
-		// msg.ChatMember.OldChatMember.Status = "left"
-
-		casBanned, err := CasCheckID(msg.ChatMember.NewChatMember.User.ID)
-
-		if err != nil {
-			Log.Errorf(
-				"Unable to check user %s %s (username = %s, id = %d) in chat %s %s (%d): %s",
-				msg.ChatMember.NewChatMember.User.FirstName,
-				msg.ChatMember.NewChatMember.User.LastName,
-				msg.ChatMember.NewChatMember.User.Username,
-				msg.ChatMember.NewChatMember.User.ID,
-				msg.ChatMember.Chat.Type,
-				msg.ChatMember.Chat.Title,
-				msg.ChatMember.Chat.ID,
-				err,
-			)
-		} else if casBanned {
-			// Ban user if cas report it as banned.
-			Log.Infof(
-				"Ban user %s %s (username = %s, id = %d) in chat %s %s (%d) by CAS blacklist",
-				msg.ChatMember.NewChatMember.User.FirstName,
-				msg.ChatMember.NewChatMember.User.LastName,
-				msg.ChatMember.NewChatMember.User.Username,
-				msg.ChatMember.NewChatMember.User.ID,
-				msg.ChatMember.Chat.Type,
-				msg.ChatMember.Chat.Title,
-				msg.ChatMember.Chat.ID,
-			)
-
-			squash(
-				msg.ChatMember.Chat.ID,
-				msg.ChatMember.NewChatMember.User.ID,
-			)
-
-			return
-		}
-
-		Log.Infof(
-			"Storing info about user %s %s (username = %s, id = %d) in chat %s %s (%d) to AppearedMember DB",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-		)
-
-		key := fmt.Sprintf("%d+%d", msg.ChatMember.Chat.ID, msg.ChatMember.NewChatMember.User.ID)
-		AppearedMembers.Set(key, time.Now().Unix(), 1*time.Minute)
-		PendingCASMembers.Set(key, time.Now().Unix(), 30*time.Minute)
-
-	case msg.ChatMember.OldChatMember.Status == "member" && msg.ChatMember.NewChatMember.Status == "kicked":
-		Log.Infof(
-			"User %s %s (username = %s, id = %d) in chat %s %s (%d) was banned",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-		)
-
-		key := fmt.Sprintf("%d+%d", msg.ChatMember.Chat.ID, msg.ChatMember.NewChatMember.User.ID)
-
-		Log.Debugf(
-			"Put user %s %s (username = %s, id = %d) in %s %s (%d) into SquashedMembers to debounce ban.",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-		)
-
-		SquashedMembers.Set(key, true, 30*time.Second)
-
-		Log.Debugf(
-			"Storing info about user %s %s (username = %s, id = %d) in chat %s %s (%d) to BannedMembers DB",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-		)
-
-		if err := Cfg.SaveKeyValue(
-			"BannedMembers",
-			fmt.Sprintf("%d", msg.ChatMember.Chat.ID),
-			fmt.Sprintf("%d", msg.ChatMember.NewChatMember.User.ID),
-			fmt.Sprintf("%d", time.Now().Unix()),
-		); err != nil {
-			Log.Error(err)
-		} else {
-			Log.Infof("Info about banned userid %d saved to BannedMembers DB", msg.ChatMember.Chat.ID)
-		}
-
-	default:
-		Log.Infof(
-			"User %s %s (username = %s, id = %d) in chat %s %s (%d) now %s was %s",
-			msg.ChatMember.NewChatMember.User.FirstName,
-			msg.ChatMember.NewChatMember.User.LastName,
-			msg.ChatMember.NewChatMember.User.Username,
-			msg.ChatMember.NewChatMember.User.ID,
-			msg.ChatMember.Chat.Type,
-			msg.ChatMember.Chat.Title,
-			msg.ChatMember.Chat.ID,
-			msg.ChatMember.NewChatMember.Status,
-			msg.ChatMember.OldChatMember.Status,
-		)
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/chatlog.go

@@ -1,49 +0,0 @@
-package moon
-
-import (
-	"fmt"
-	"os"
-	"path/filepath"
-	"strconv"
-	"time"
-
-	"github.com/rs/zerolog"
-	"github.com/rs/zerolog/log"
-)
-
-// ChatLog logs message to separate file, placed in basedir(Cfg.LogFile).
-func ChatLog(chatid int64, message string) {
-	var (
-		filename string
-	)
-
-	if Cfg.LogFile != "" {
-		filename = fmt.Sprintf("%s/%s", filepath.Dir(Cfg.LogFile), strconv.FormatInt(chatid, 10))
-	} else {
-		filename = os.DevNull
-	}
-
-	f, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0644)
-
-	if err != nil {
-		fmt.Printf("Unable to open file %s for logging: %s", filename, err)
-
-		// TODO: Should we try harder?
-		return
-	}
-
-	defer f.Close()
-
-	log.Logger = log.Output(
-		zerolog.ConsoleWriter{
-			Out:        f,
-			NoColor:    true,
-			TimeFormat: time.DateTime,
-			PartsOrder: []string{"time", "message"},
-		},
-	)
-
-	log.Info().Msg(message)
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/config.go

@@ -5,10 +5,11 @@ import (
 	"fmt"
 	"os"
 	"path/filepath"
-	"strings"
+
+	"bunny-bot/internal/elog"
+	"bunny-bot/internal/mylog"
 
 	"github.com/hjson/hjson-go"
-	"go.uber.org/zap/zapcore"
 )
 
 // parseConfig разбирает и валидирует даденный конфиг.
@@ -66,34 +67,27 @@ func ParseConfig(path string) (MyConfig, error) {
 		return MyConfig{}, fmt.Errorf("token field in config file %s must be set", path) //nolint: err113
 	}
 
-	if _, err := zapcore.ParseLevel(sampleConfig.LogLevel); err != nil {
+	if _, err := mylog.ParseLevel(sampleConfig.LogLevel); err != nil {
 		sampleConfig.LogLevel = "info"
 	}
 
+	// Chat logs are optional, but a configured path that does not exist is a
+	// typo and must stop startup rather than silently disable logging.
+	//
+	// A relative chat_logs is resolved against the directory holding the config
+	// file, not the process working directory: a daemon's cwd is wherever its
+	// supervisor happened to start it, so a relative path there would move the
+	// log directory on every restart under a different supervisor.
+	if sampleConfig.ChatLogs != "" && !filepath.IsAbs(sampleConfig.ChatLogs) {
+		sampleConfig.ChatLogs = filepath.Join(filepath.Dir(path), sampleConfig.ChatLogs)
+	}
+
+	if err := elog.Init(sampleConfig.ChatLogs); err != nil {
+		return MyConfig{}, fmt.Errorf("chat_logs field in config file %s is invalid: %w", path, err)
+	}
+
 	// sampleConfig.Log = "" if not set
 
-	if sampleConfig.CSign == "" {
-		err := fmt.Errorf("csign field in config file %s must be set", path) //nolint: err113
-
-		return MyConfig{}, err
-	}
-
-	if sampleConfig.DataDir == "" {
-		return MyConfig{}, fmt.Errorf("data_dir field in config file %s must be set", path) //nolint: err113
-	}
-
-	if strings.Split(sampleConfig.DataDir, "")[0] != "/" {
-		executablePath, err := os.Executable()
-
-		if err != nil {
-			err := fmt.Errorf("unable to get current executable path: %w", err)
-
-			return MyConfig{}, err
-		}
-
-		sampleConfig.DataDir = fmt.Sprintf("%s/%s", filepath.Dir(executablePath), sampleConfig.DataDir)
-	}
-
 	return sampleConfig, err
 }
 

internal/moon/db.go

@@ -1,141 +0,0 @@
-package moon
-
-import (
-	"crypto/sha256"
-	"errors"
-	"fmt"
-	"io/fs"
-	"os"
-
-	"github.com/cockroachdb/errors/oserror"
-	"github.com/cockroachdb/pebble"
-)
-
-// StoreKV saves given  key and value in given db.
-func StoreKV(db *pebble.DB, key string, value string) error {
-	var (
-		kArray = []byte(key)
-		vArray = []byte(value)
-	)
-
-	err := db.Set(kArray, vArray, pebble.Sync)
-
-	if err != nil {
-		return err
-	}
-
-	err = db.Flush()
-
-	return err
-}
-
-// FetchV gets value by given key from given db.
-func FetchV(db *pebble.DB, key string) (string, error) {
-	var (
-		kArray = []byte(key)
-
-		vArray      []byte
-		valueString = ""
-	)
-
-	vArray, closer, err := db.Get(kArray)
-
-	if err != nil {
-		return valueString, err
-	}
-
-	valueString = string(vArray)
-	err = closer.Close()
-
-	return valueString, err
-}
-
-// GetValue gets setting for chat from given db name.
-// TODO: should return string, error and should not log error internally.
-func (cfg *MyConfig) GetValue(dataBaseName string, chatID string, setting string) string {
-	var err error
-
-	chatHash := sha256.Sum256([]byte(chatID))
-	dataBaseDir := fmt.Sprintf("%s/db/%s/%x", cfg.DataDir, dataBaseName, chatHash)
-
-	// If db descriptor is not open yet, open it.
-	if _, ok := DB[dataBaseDir]; !ok {
-		var options pebble.Options
-		/*
-		 * By default limit set on megs of data, but not on amount of files thus with defaults we have tons of
-		 * files. Default limit on tomporary files is 500, lets cut it down to 8.
-		 */
-		options.L0CompactionFileThreshold = 8
-
-		if err := os.MkdirAll(dataBaseDir, os.ModePerm); err != nil {
-			Log.Errorf("Unable to create db dir %s: %s", dataBaseDir, err)
-
-			return ""
-		}
-
-		DB[dataBaseDir], err = pebble.Open(dataBaseDir, &options)
-
-		if err != nil {
-			Log.Errorf("Unable to open db, %s: %s\n", dataBaseDir, err)
-
-			return ""
-		}
-	}
-
-	value, err := FetchV(DB[dataBaseDir], setting)
-
-	// If db returns nothing for some reason, just return ampty string.
-	if err != nil {
-		switch {
-		case errors.Is(err, pebble.ErrNotFound):
-			Log.Debugf("Unable to get value for %s: no record found in db %s", setting, dataBaseDir)
-		case errors.Is(err, fs.ErrNotExist):
-			Log.Debugf("Unable to get value for %s: db dir %s does not exist", setting, dataBaseDir)
-		case errors.Is(err, oserror.ErrNotExist):
-			Log.Debugf("Unable to get value for %s: db dir %s does not exist", setting, dataBaseDir)
-		default:
-			Log.Errorf("Unable to get value for %s in db dir %s: %s", setting, dataBaseDir, err)
-		}
-
-		return ""
-	}
-
-	return value
-}
-
-// SaveSetting saves setting name and its value to given db name.
-func (cfg *MyConfig) SaveKeyValue(dataBaseName string, chatID string, setting string, value string) error {
-	var (
-		chatHash    = sha256.Sum256([]byte(chatID))
-		dataBaseDir = fmt.Sprintf("%s/db/%s/%x", cfg.DataDir, dataBaseName, chatHash)
-		err         error
-	)
-
-	// If db descriptor is not open yet, open it.
-	if _, ok := DB[dataBaseDir]; !ok {
-		var options pebble.Options
-		/*
-		 * By default limit set on megs of data, but not on amount of files thus with defaults we have tons of
-		 * files. Default limit on tomporary files is 500, lets cut it down to 8.
-		 */
-		options.L0CompactionFileThreshold = 8
-
-		if err := os.MkdirAll(dataBaseDir, os.ModePerm); err != nil {
-			return fmt.Errorf("unable to create db dir %s: %w", dataBaseDir, err)
-		}
-
-		DB[dataBaseDir], err = pebble.Open(dataBaseDir, &options)
-
-		if err != nil {
-			return fmt.Errorf("unable to open settings db, %s: %w", dataBaseDir, err)
-		}
-	}
-
-	if err := StoreKV(DB[dataBaseDir], setting, value); err != nil {
-		return fmt.Errorf("unable to save setting %s in database %s: %w", setting, dataBaseDir, err)
-	}
-
-	return nil
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/editedMessage.go

@@ -1,50 +0,0 @@
-package moon
-
-import (
-	"fmt"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-// editedMessage handles editedMessage type of update.
-func editedMessage(msg *echotron.Update) {
-	AddUser(msg.EditedMessage.From)
-	AddChat(&msg.EditedMessage.Chat)
-
-	// Edited message can contain all kinds of edited attributes that telegram allows to change in message.
-	// Not sure is we should handle all of them.
-	if Cfg.LogChats {
-		if msg.EditedMessage.Text != "" {
-			ChatLog(
-				msg.EditedMessage.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) in %s %s (%d) edited message: %s",
-					msg.EditedMessage.From.FirstName,
-					msg.EditedMessage.From.LastName,
-					msg.EditedMessage.From.Username,
-					msg.EditedMessage.From.ID,
-					msg.EditedMessage.Chat.Type,
-					msg.EditedMessage.Chat.Title,
-					msg.EditedMessage.Chat.ID,
-					msg.EditedMessage.Text,
-				),
-			)
-		} else {
-			ChatLog(
-				msg.EditedMessage.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) in %s %s (%d) edited message",
-					msg.EditedMessage.From.FirstName,
-					msg.EditedMessage.From.LastName,
-					msg.EditedMessage.From.Username,
-					msg.EditedMessage.From.ID,
-					msg.EditedMessage.Chat.Type,
-					msg.EditedMessage.Chat.Title,
-					msg.EditedMessage.Chat.ID,
-				),
-			)
-		}
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/entityGuard.go

@@ -0,0 +1,130 @@
+package moon
+
+import (
+	"bunny-bot/internal/mylog"
+
+	"github.com/NicoNex/echotron/v3"
+	"github.com/davecgh/go-spew/spew"
+)
+
+// The Bot API always returns a User/Chat carrying its id, and echotron validates
+// nothing: lclient.dispatch (network.go:138) is json.Unmarshal plus a check() that
+// reads only the ok/error_code envelope (helpers.go:37). An entity that arrives
+// without an id therefore reaches us as a silent zero, with no layer below to
+// complain about it. These predicates are the whole of our defence.
+//
+// They are SILENT. A refusal is a fact, not an incident: reporting happens once, at
+// the ingress, where the offending update can be dumped whole. A predicate that logs
+// would make one broken update produce one line per entity that happens to meet it.
+
+// usableUser reports whether a user entity is one we can actually address.
+//
+// The test is against zero and not against zero-or-less on purpose: a chat id is
+// legitimately negative for a group or supergroup, so a positivity check would
+// refuse every group chat in the project.
+func usableUser(u *echotron.User) bool {
+	return u != nil && u.ID != 0
+}
+
+// usableChat reports whether a chat entity is one we can actually address, with the
+// same reasoning and the same zero-not-positive rule.
+func usableChat(c *echotron.Chat) bool {
+	return c != nil && c.ID != 0
+}
+
+// usableUpdate reports whether an update is worth dispatching at all.
+//
+// Its branches mirror telegramMsgParser's, in the same order and under the same
+// conditions, so a branch added to one and not the other is visible by reading. That
+// is not tidiness: the alternative is a validator shaped differently from the
+// dispatcher, whose coverage nobody can check by eye.
+//
+// nil is tolerated only where absence is normal. A message with no author is a
+// channel post or a service message, and refusing those would disable chat logging
+// for channels. A nil element inside NewChatMembers is different — the array asserts
+// a newcomer exists — and so is a nil NewChatMember.User, which asserts who changed.
+// A nil OldChatMember.User is tolerated: some transitions have no previous member.
+func usableUpdate(u *echotron.Update) bool {
+	if u == nil {
+		return false
+	}
+
+	switch {
+	case u.ChatMember != nil:
+		return usableChatMember(u.ChatMember)
+	case u.Message != nil:
+		return usableMessage(u.Message)
+	case u.EditedMessage != nil:
+		return usableMessage(u.EditedMessage)
+	default:
+		// Nothing we act on. The dispatcher's spew fallback is where this belongs.
+		return true
+	}
+}
+
+// usableChatMember checks a membership change.
+//
+// Its entities are values, not pointers: ChatMemberUpdated.Chat, .From and both
+// ChatMember structs can never be nil, so there is no nil test to fall back on and
+// the id check is the only thing that can catch a malformed one.
+func usableChatMember(cm *echotron.ChatMemberUpdated) bool {
+	return usableChat(&cm.Chat) &&
+		usableUser(cm.NewChatMember.User) &&
+		(cm.OldChatMember.User == nil || usableUser(cm.OldChatMember.User)) &&
+		usableUser(&cm.From)
+}
+
+// usableMessage checks a message, or an edit of one — the two carry the same fields
+// and are treated the same way.
+//
+// Message.Chat is a value: a zero chat id would otherwise reach elog, which builds
+// chat_logs/<id>/yyyy/mm/dd.txt from it and would silently create a chat_logs/0
+// directory and write every malformed update into it.
+func usableMessage(m *echotron.Message) bool {
+	if !usableChat(&m.Chat) {
+		return false
+	}
+
+	if m.From != nil && !usableUser(m.From) {
+		return false
+	}
+
+	if m.LeftChatMember != nil && !usableUser(m.LeftChatMember) {
+		return false
+	}
+
+	for _, member := range m.NewChatMembers {
+		if !usableUser(member) {
+			return false
+		}
+	}
+
+	// One level deep, and the nested chat only. The nested author is never rendered,
+	// so a zero there is cosmetic; the level bound exists to keep the work constant.
+	if m.PinnedMessage != nil && !usableChat(&m.PinnedMessage.Chat) {
+		return false
+	}
+
+	if m.ReplyToMessage != nil && !usableChat(&m.ReplyToMessage.Chat) {
+		return false
+	}
+
+	return true
+}
+
+// reportBrokenUpdate records an update we are refusing, in the terms it deserves:
+// this is not a user being difficult and not a transient API error, it is an
+// upstream that broke its own contract.
+//
+// The whole update is dumped, once. The dump is the point — the condition is
+// unreproducible and unqueryable, since there is no id to ask Telegram about — and a
+// partial dump of one field out of four would not be evidence of anything.
+func reportBrokenUpdate(u *echotron.Update) {
+	mylog.Error(
+		"Telegram sent an update with an entity carrying no id, refusing it: nothing in it can be greeted, recorded or banned, and an API that sends one is broken",
+	)
+
+	mylog.Error(spew.Sdump(u))
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/exitCode.go

@@ -0,0 +1,25 @@
+package moon
+
+import "os"
+
+// ExitCode reports the status the process should leave with on a clean return
+// from run(). It is zero while the bot is running normally, and 128 + the
+// signal's number once a termination signal has begun the shutdown — the Unix
+// convention a supervisor can use to tell "stopped with a signal" from "stopped
+// cleanly", which D33 left permanently 0 before it.
+//
+// It never reports an error status: a failed shutdown still returns an error
+// from run(), and main exits 1 over that, the same as before.
+func ExitCode() int {
+	return int(exitCode.Load())
+}
+
+// recordExitCode stores the status the given terminating signal should leave.
+// Only the first termination signal matters — the handler goroutine returns
+// after one — so a later write cannot pass either.
+func recordExitCode(s os.Signal) {
+	// The value is one of a fixed table of 128+n, never a caller-supplied int.
+	exitCode.Store(int32(exitCodeFor(s))) //nolint:gosec // G115: exitCodeFor returns only 130, 131, 143 or 0.
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/exitCode_unix.go

@@ -0,0 +1,28 @@
+//go:build !windows
+
+package moon
+
+import (
+	"os"
+	"syscall"
+)
+
+// exitCodeFor maps one terminating signal to the status a stopped process
+// should carry: 128 + the signal's number on Unix.
+func exitCodeFor(s os.Signal) int {
+	switch s {
+	case syscall.SIGINT:
+		return signalExitBase + 2
+
+	case syscall.SIGTERM:
+		return signalExitBase + 15
+
+	case syscall.SIGQUIT:
+		return signalExitBase + 3
+
+	default:
+		return 0
+	}
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/exitCode_windows.go

@@ -0,0 +1,18 @@
+//go:build windows
+
+package moon
+
+import "os"
+
+// exitCodeFor maps one terminating signal to the status a stopped process
+// should carry. Windows has no signal numbers to follow, so it imitates the
+// Unix convention: Ctrl+C is an interrupt, and an interrupt is 130.
+func exitCodeFor(s os.Signal) int {
+	if s == os.Interrupt {
+		return signalExitBase + 2
+	}
+
+	return 0
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/globals.go

@@ -2,48 +2,143 @@ package moon
 
 import (
 	"os"
+	"strings"
+	"sync"
+	"sync/atomic"
 	"time"
 
 	"github.com/NicoNex/echotron/v3"
 	"github.com/akyoto/cache"
-	"github.com/cockroachdb/pebble"
-	"go.uber.org/zap"
+)
+
+const (
+	// greetCacheTTL is how long a join event or a chat message is retained. It
+	// is deliberately larger than greetReplyWindow so that a sweep occurring at
+	// the far end of the window still has the data it needs to decide.
+	greetCacheTTL = 17 * time.Minute
+
+	// greetReplyWindow is how long a newcomer has to answer the greeting before
+	// being treated as a spammer.
+	greetReplyWindow = 15 * time.Minute
+
+	// greetSweepInterval is how often the sweeper runs.
+	greetSweepInterval = 1 * time.Minute
+)
+
+// signalExitBase is the offset a signal's exit status is derived from. The Unix
+// convention is 128 + n, where n is the signal number, so SIGINT is 130, SIGTERM
+// is 143 and SIGQUIT is 131 — what a shell reports for a process killed by a
+// signal, which is exactly what these statuses imitate.
+const signalExitBase = 128
+
+// The outcomes of a squash attempt. Names state what happened, not how it was
+// detected, so callers never have to reinterpret them.
+const (
+	// banApplied means Telegram accepted the ban.
+	banApplied banOutcome = iota
+
+	// banSuppressed means we did not call the API at all: the debounce already
+	// holds this user, i.e. we banned them moments ago and they are already out.
+	banSuppressed
+
+	// banFailed means we called the API and it refused. The user is still in the
+	// chat and was not retried.
+	banFailed
+)
+
+// The outcomes of retracting a greeting a banned member never answered. The three
+// cases are distinct because "nothing to delete" and "tried and failed" call for
+// different log lines, and only the second is worth an operator's attention.
+const (
+	// nothingToRetract means no remembered greeting id was greater than zero, so
+	// the API was never called.
+	nothingToRetract retractOutcome = iota
+
+	// greetingRetracted means every remembered greeting was deleted.
+	greetingRetracted
+
+	// greetingRetractFailed means at least one deletion was refused by Telegram.
+	// The others still went: a failure never aborts the rest.
+	greetingRetractFailed
 )
 
 var (
+	// htmlReplacer escapes the three characters HTML requires, all three pairs at
+	// once so no ordering can be got wrong: "&" is never re-escaped by the "<" or
+	// ">" rules. Created once because a Replacer is immutable and safe to share.
+	htmlReplacer = strings.NewReplacer("&", "&amp;", "<", "&lt;", ">", "&gt;")
+
 	Cfg     MyConfig
 	SigChan = make(chan os.Signal, 1)
-	Log     *zap.SugaredLogger
-	Tg      echotron.API
+	Tg      tgClient
 
-	// Мапка с открытыми дескрипторами баз настроек.
-	DB = make(map[string]*pebble.DB)
+	// allowedUpdates is the set of update types Telegram is asked to deliver.
+	//
+	// It lives here, not inline in Telegram(), because it must stay in step with
+	// the branches of telegramMsgParser: a type missing from this list makes its
+	// branch unreachable, and nothing at compile time or in the test suite says
+	// so. TestEveryDispatchedUpdateTypeIsRequested exists to catch exactly that.
+	//
+	// chat_join_request is deliberately absent. The community is open and join
+	// requests are not moderated; Telegram auto-approves them when the type is
+	// not requested, which is the intended behaviour.
+	allowedUpdates = []echotron.UpdateType{
+		"message",
+		"edited_message",
+		"chat_member",
+	}
 
-	// SquashedMembers struct with banned members.
+	// SquashedMembers holds members recently banned by us, used as a ban debounce.
 	SquashedMembers = cache.New(1 * time.Minute)
 
-	// NewMembers struct with new members appeared via message with new_chat_members field set.
-	NewMembers = cache.New(1 * time.Minute)
+	// PendingGreetings holds recorded joins keyed by join timestamp in
+	// microseconds. Used by the greeting sweeper to find newcomers who never
+	// answered, and to retract the greetings we asked them.
+	PendingGreetings = newEventCache[pendingGreeting](1 * time.Minute)
 
-	// AppearedMembers struct with new members appeared via ChatMemberUpdated event.
-	AppearedMembers = cache.New(60 * time.Minute)
+	// GreetAnswers holds text messages keyed by message timestamp in
+	// microseconds. Used by the greeting sweeper to find proof that a newcomer
+	// answered the greeting.
+	GreetAnswers = newEventCache[*echotron.Message](1 * time.Minute)
 
-	// PendingCASMembers contains newly comed members that pass first cas check, but still waiting second cas check.
-	PendingCASMembers = cache.New(60 * time.Minute)
+	// closeOnce guards closeCaches: cache.Cache.Close() sends on an unbuffered
+	// channel and therefore must be called exactly once per cache; calling it
+	// twice deadlocks. Each cache is guarded so a failure partway through cannot
+	// turn into a hang on the second attempt.
+	closeOnce sync.Once
 
-	// GreetPending contains people that should answer to bot greet.
-	GreetPending = cache.New(1 * time.Minute)
+	// stopRequested is closed once, by shutdown, to ask every goroutine that
+	// loops to return. One signal for all of them, rather than one per worker:
+	// several workers can come and go (and tests start them deliberately), and
+	// a per-worker channel would have to be closed exactly once each, which is a
+	// panic waiting to happen.
+	stopRequested = make(chan struct{})
 
-	// NoMessagePeople contains people that are never say something in chat.
-	NoMessagePeople = cache.New(1 * time.Minute)
+	// workers counts the running background goroutines — the update listener and
+	// the greeting sweeper. shutdown waits on it, so no worker can be touching a
+	// cache, the logs or the API while the teardown closes them.
+	workers sync.WaitGroup
 
-	// People cache with users info.
-	People = cache.New(8 * time.Hour)
+	// workersMu guards workers and stopping. A worker must register before
+	// shutdown starts waiting, and a goroutine that tries to start afterwards is
+	// refused instead of racing WaitGroup.Add against Wait.
+	workersMu sync.Mutex
+	stopping  bool
 
-	// Groups cache with groups info.
-	Groups = cache.New(8 * time.Hour)
+	// runningWorkers counts registered, not-yet-finished workers, so a caller
+	// can tell "nothing started yet" from "started and still going".
+	runningWorkers atomic.Int32
 
-	ChatList = make([]int64, 0)
+	// exitCode carries the status the process should exit with on a clean
+	// return from run(): zero while the bot is running and sleeping normally,
+	// 128 + signal number once a termination signal has begun the shutdown.
+	// It is an atomic because the handler goroutine writes it and main reads
+	// it, and plain avoids any question of which goroutine wins.
+	exitCode atomic.Int32
+
+	// shutdownOnce guards shutdown so two termination signals arriving together
+	// cannot run the sequence twice.
+	shutdownOnce sync.Once
 )
 
 /* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/greet.go

@@ -0,0 +1,98 @@
+package moon
+
+import (
+	"bunny-bot/internal/mylog"
+	"math/rand/v2"
+	"strings"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// greetings are the templates used to greet a newly joined member. The single
+// verb is replaced with the newcomer's computed display name. The fourth one is
+// intentionally kept verbatim despite looking like a typo.
+var greetings = []string{
+	"Дарована, %s. Представьтес, пожалуйста, и расскажите, что вас сюда привело.",
+	"Добро пожаловать в наше скромное коммунити, %s. Представьтес, пожалуйста, и расскажите, что вас сюда привело.",
+	"Доброе утро, день или вечер, %s. Представьтес, пожалуйста, и расскажите, что вас сюда привело.",
+	"Наше вам с кисточкой тут, на канальчике, %s. Представьтес, пожалуйста, и расскажите, что вас сюда привело.",
+}
+
+// displayName builds the name substituted into a greeting for the given user.
+// Preference order: "FirstName LastName", then LastName alone, then FirstName
+// alone, then the username.
+func displayName(u *echotron.User) string {
+	if u == nil {
+		return ""
+	}
+
+	name := strings.TrimSpace(strings.Join([]string{u.FirstName, u.LastName}, " "))
+
+	if name != "" {
+		return name
+	}
+
+	return u.Username
+}
+
+// sendGreeting sends a randomly chosen greeting for the given newcomer into the chat.
+//
+// It returns the id of the greeting it sent and whether it was actually
+// delivered. Both matter: a newcomer who never received the question must not be
+// judged on their silence, and a newcomer who is banned later must have the
+// question taken back down.
+//
+// The mention makes the greeting a clickable link to the newcomer, and the
+// message is sent in HTML mode because that is the only mode in which an
+// arbitrary display name can be embedded safely — see greetMention.
+func sendGreeting(chatid int64, u *echotron.User) (int, bool) {
+	// Everything below dereferences u, including the error paths that name the
+	// user, so an entity with no id is refused here rather than crashing later.
+	if !usableUser(u) {
+		return 0, false
+	}
+
+	// math/rand is sufficient here: we pick one of four static templates, not a
+	// secret or a security-relevant value.
+	greeting := greetings[rand.IntN(len(greetings))] //nolint: gosec // G404
+
+	text := strings.Replace(greeting, "%s", greetingAddressee(u), 1)
+
+	res, err := Tg.SendMessage(text, chatid, &echotron.MessageOptions{
+		ParseMode: echotron.HTML,
+	})
+	if err != nil {
+		mylog.Errorf("GREETING NOT DELIVERED to user %d in chat %d: %s", u.ID, chatid, err)
+
+		return 0, false
+	}
+
+	mylog.Debugf("Greeted user %d in chat %d", u.ID, chatid)
+
+	// A response carrying no message still means the greeting was delivered; we
+	// simply have no id to retract later.
+	return sentMessageID(res), true
+}
+
+// greetingAddressee is the name the template's %s is replaced with: a mention of
+// the newcomer when they can be mentioned, and their plain display name when they
+// cannot, so an unmentionable user is still greeted rather than skipped.
+func greetingAddressee(u *echotron.User) string {
+	if mention := greetMention(u); mention != "" {
+		return mention
+	}
+
+	return displayName(u)
+}
+
+// sentMessageID pulls the id out of a send response, tolerating a response that
+// carries no message at all.
+func sentMessageID(res echotron.APIResponseMessage) int {
+	if res.Result == nil {
+		return 0
+	}
+
+	return res.Result.ID
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/greetCache.go

@@ -0,0 +1,52 @@
+package moon
+
+import (
+	"time"
+
+	"github.com/akyoto/cache"
+)
+
+// newEventCache creates an eventCache whose expired entries are swept every
+// cleaningInterval.
+func newEventCache[T any](cleaningInterval time.Duration) *eventCache[T] {
+	return &eventCache[T]{cache: cache.New(cleaningInterval)}
+}
+
+// Set stores value under the microsecond key with the given TTL.
+func (m *eventCache[T]) Set(micros int64, value T, ttl time.Duration) {
+	m.cache.Set(micros, value, ttl)
+}
+
+// Snapshot returns a typed copy of all non-expired entries keyed by their
+// microsecond timestamp. Callers can range over the returned map without
+// performing any interface{} conversions.
+func (m *eventCache[T]) Snapshot() map[int64]T {
+	out := make(map[int64]T)
+
+	m.cache.Range(
+		func(k, v any) bool {
+			key, ok := k.(int64)
+			if !ok {
+				return true
+			}
+
+			value, ok := v.(T)
+			if !ok {
+				return true
+			}
+
+			out[key] = value
+
+			return true
+		},
+	)
+
+	return out
+}
+
+// Delete removes the entry stored under the given microsecond key.
+func (m *eventCache[T]) Delete(micros int64) {
+	m.cache.Delete(micros)
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/greetMention.go

@@ -0,0 +1,81 @@
+package moon
+
+import (
+	"strconv"
+	"strings"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// greetMention renders a clickable mention of a newcomer for use inside a
+// greeting, or "" when the user cannot be mentioned at all.
+//
+// The mode is HTML, not markdown, and that is a correctness decision rather than
+// a preference: the label is a name Telegram gave us, and MarkdownV2 requires
+// escaping eighteen characters — "-" among them — so an ordinary "Анна-Мария"
+// would be rejected with a 400. A rejected greeting makes newChatMembers delete
+// the join event, which is how one hyphen would disable the only detector. HTML
+// needs "&", "<" and ">" escaped, and those essentially never occur in a name.
+//
+// The mention works without a @username, which is the common case for someone who
+// has only just joined a public group.
+func greetMention(u *echotron.User) string {
+	if u == nil || u.ID <= 0 {
+		return ""
+	}
+
+	var b strings.Builder
+
+	b.WriteString(`<a href="tg://user?id=`)
+	b.WriteString(strconv.FormatInt(u.ID, 10))
+	b.WriteString(`">`)
+
+	for _, r := range mentionLabel(u) {
+		switch r {
+		case '&':
+			b.WriteString("&amp;")
+		case '<':
+			b.WriteString("&lt;")
+		case '>':
+			b.WriteString("&gt;")
+		default:
+			b.WriteRune(r)
+		}
+	}
+
+	b.WriteString("</a>")
+
+	return b.String()
+}
+
+// escapeHTML escapes the three characters HTML requires. It exists for callers
+// that assemble markup themselves; the greeting path uses greetMention's own
+// single pass so the anchor and the label cannot drift apart.
+func escapeHTML(s string) string {
+	return htmlReplacer.Replace(s)
+}
+
+// mentionLabel is the text shown inside the mention link, in the preference order
+// a reader expects: full name, then either name alone, then the @username, and
+// finally the bare id so the link is never empty.
+func mentionLabel(u *echotron.User) string {
+	if name := strings.TrimSpace(u.FirstName + " " + u.LastName); name != "" {
+		return name
+	}
+
+	if u.LastName != "" {
+		return u.LastName
+	}
+
+	if u.FirstName != "" {
+		return u.FirstName
+	}
+
+	if u.Username != "" {
+		return "@" + u.Username
+	}
+
+	return strconv.FormatInt(u.ID, 10)
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/greetSweep.go

@@ -0,0 +1,206 @@
+package moon
+
+import (
+	"bunny-bot/internal/mylog"
+	"time"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// SweepGreetings runs until a termination signal stops it. Every
+// greetSweepInterval it looks at join events that are at least greetReplyWindow
+// old and decides whether each newcomer ever answered the greeting:
+//
+//   - answered (a message from that user exists after the join, within the
+//     reply window) -> newcomer is legitimate, drop the join event(s);
+//   - not answered -> newcomer is a spammer, ban them and drop the join
+//     event(s).
+//
+// A user may appear in PendingGreetings more than once (rejoins). For every user we
+// re-query both caches so that a single answer rescues all of their join events
+// and a single unanswered join bans them once.
+//
+// The stop is checked between passes and never during one, so a sweep in
+// progress always finishes and can never be running while the caches are being
+// closed underneath it.
+func SweepGreetings() {
+	if !startWorker() {
+		return
+	}
+
+	defer stopWorker()
+
+	timer := time.NewTimer(greetSweepInterval)
+	defer timer.Stop()
+
+	for {
+		select {
+		case <-stopRequested:
+			mylog.Info("Greeting sweeper stopped")
+
+			return
+
+		case <-timer.C:
+			sweepGreetings()
+
+			timer.Reset(greetSweepInterval)
+		}
+	}
+}
+
+// sweepGreetings performs a single sweep pass against the current wall clock.
+func sweepGreetings() {
+	sweepGreetingsAt(time.Now())
+}
+
+// sweepGreetingsAt performs a single sweep pass as of now. Taking the clock as
+// a parameter is what makes the reply-window boundary testable without sleeping
+// for 15 minutes.
+func sweepGreetingsAt(now time.Time) {
+	joins := PendingGreetings.Snapshot()
+	messages := GreetAnswers.Snapshot()
+
+	windowMicros := greetReplyWindow.Microseconds()
+	nowMicros := now.UnixMicro()
+
+	// Group stale join events per (chat, user). A user is a distinct identity in
+	// every chat: being silent in one chat says nothing about another, and
+	// answering in one chat must not rescue them in another.
+	staleByMember := make(map[chatUser][]joinRef)
+
+	for joinMicros, recorded := range joins {
+		join := recorded.join
+
+		// Not stale yet.
+		if nowMicros-joinMicros <= windowMicros {
+			continue
+		}
+
+		// A join event carries the newcomer's user in NewChatMembers.
+		if join == nil || len(join.NewChatMembers) == 0 {
+			continue
+		}
+
+		user := join.NewChatMembers[0]
+
+		// An entity with no id cannot be banned, and the dump has already been
+		// taken. Drop the join rather than keeping it: re-reporting the same
+		// broken update every minute for the rest of its TTL is noise that
+		// teaches an operator to ignore this log.
+		if !usableUser(user) {
+			PendingGreetings.Delete(joinMicros)
+
+			continue
+		}
+
+		member := chatUser{chatID: join.Chat.ID, userID: user.ID}
+		staleByMember[member] = append(staleByMember[member], joinRef{
+			micros:     joinMicros,
+			chat:       join.Chat,
+			user:       user,
+			greetingID: recorded.greetingID,
+		})
+	}
+
+	for member, refs := range staleByMember {
+		// A single answer rescues every join this user has *in this chat*, no
+		// matter which join the reply was actually answering.
+		answered := false
+
+		for _, ref := range refs {
+			if userAnswered(member.chatID, member.userID, ref.micros, windowMicros, messages) {
+				answered = true
+
+				break
+			}
+		}
+
+		if answered {
+			mylog.Debugf(
+				"User %d answered the greeting in chat %d, not banning",
+				member.userID,
+				member.chatID,
+			)
+		} else {
+			mylog.Infof(
+				"User %d did not answer the greeting in chat %d within %s, banning as spammer",
+				member.userID,
+				member.chatID,
+				greetReplyWindow,
+			)
+
+			// squash already logs every outcome at the level it deserves: a
+			// ban that landed is a debug line and a duplicate we deliberately
+			// suppressed is an info line. Only a refused ban needs anything
+			// added here, because it is the one case where the user is still
+			// in the chat and will never be re-judged.
+			outcome := squash(&refs[0].chat, refs[0].user)
+			if outcome == banFailed {
+				mylog.Errorf(
+					"BAN FAILED for user %d in chat %d — they stayed in the chat and were not re-judged",
+					member.userID,
+					member.chatID,
+				)
+			} else {
+				// The user is out of the chat, so every question we asked them
+				// is a leftover. That includes the debounced repeat: they are
+				// banned either way, and the room must not be left asking a
+				// question nobody can answer.
+				retractAskedGreetings(refs)
+			}
+		}
+
+		// Drop every join event of this user *in this chat* so the next pass
+		// does not re-decide them. Joins in their other chats are untouched.
+		forgetPendingGreetings(member.chatID, member.userID)
+	}
+}
+
+// userAnswered reports whether a message authored by userID in chatID exists
+// in messages with a timestamp in (joinMicros, joinMicros+windowMicros].
+//
+// Both the chat and the author must match: the newcomer must answer in the same
+// chat they were greeted in. Messages sent before the join do not count either,
+// because the greeting is only sent in response to the join.
+func userAnswered(
+	chatID int64,
+	userID int64,
+	joinMicros int64,
+	windowMicros int64,
+	messages map[int64]*echotron.Message,
+) bool {
+	for msgMicros, msg := range messages {
+		if msg == nil || msg.From == nil {
+			continue
+		}
+
+		if msg.From.ID != userID || msg.Chat.ID != chatID {
+			continue
+		}
+
+		if msgMicros > joinMicros && msgMicros <= joinMicros+windowMicros {
+			return true
+		}
+	}
+
+	return false
+}
+
+// forgetPendingGreetings removes every PendingGreetings entry whose newcomer is userID in the
+// given chat. Joins by the same user in other chats are deliberately preserved:
+// those are independent memberships with their own greetings and their own
+// verdicts.
+func forgetPendingGreetings(chatID int64, userID int64) {
+	for joinMicros, recorded := range PendingGreetings.Snapshot() {
+		join := recorded.join
+		if join == nil || join.Chat.ID != chatID || len(join.NewChatMembers) == 0 {
+			continue
+		}
+
+		if join.NewChatMembers[0] != nil && join.NewChatMembers[0].ID == userID {
+			PendingGreetings.Delete(joinMicros)
+		}
+	}
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/leftChatMember.go

@@ -1,37 +0,0 @@
-package moon
-
-import (
-	"fmt"
-	"time"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-// leftChatMember handles left_chat_member event.
-func leftChatMember(msg *echotron.Update) {
-	Log.Infof(
-		"User %s %s (username = %s, id = %d) left %s %s (%d)",
-		msg.Message.LeftChatMember.FirstName,
-		msg.Message.LeftChatMember.LastName,
-		msg.Message.LeftChatMember.Username,
-		msg.Message.LeftChatMember.ID,
-		msg.Message.Chat.Type,
-		msg.Message.Chat.Title,
-		msg.Message.Chat.ID,
-	)
-
-	// Save people that left chat to pebbledb. To preserve their state.
-	// Left folks can eventually return and in chat_mamber_updated event their state will be left->member.
-	if err := Cfg.SaveKeyValue(
-		"LeftMembers",
-		fmt.Sprintf("%d", msg.Message.Chat.ID),
-		fmt.Sprintf("%d", msg.Message.LeftChatMember.ID),
-		fmt.Sprintf("%d", time.Now().Unix()),
-	); err != nil {
-		Log.Error(err)
-	} else {
-		Log.Infof("Info about left userid %d saved to left users db", msg.Message.LeftChatMember.ID)
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/logOnlyMessage.go

@@ -0,0 +1,24 @@
+package moon
+
+import (
+	"bunny-bot/internal/elog"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// logOnlyMessage writes a message to the chat log and nothing else.
+//
+// It handles the messages the greeting detector must NOT count as answers: a photo with no
+// caption, a sticker, a location, a leave, a title change. They are real events in the room
+// and belong in the log — which is also what makes a later ban diagnosable, since a moderator
+// can read what the member actually replied with — but a reply with no text is not an
+// introduction, and recording it in GreetAnswers would let any attachment rescue a spammer
+// from the ban.
+//
+// The dispatcher has already established that this is neither a join nor a text message; it
+// is not re-checked here.
+func logOnlyMessage(msg *echotron.Update) {
+	elog.LogMessage(msg.Message)
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/newChatMembers.go

@@ -1,31 +1,61 @@
 package moon
 
 import (
-	"fmt"
-	"slices"
 	"time"
 
+	"bunny-bot/internal/elog"
+	"bunny-bot/internal/mylog"
+
 	"github.com/NicoNex/echotron/v3"
 )
 
 // newChatMembers parses NewChatMember event.
 func newChatMembers(msg *echotron.Update) {
-	// If there is no such chatid, means that no such cache too.
-	Log.Debugf(
-		"Add %s %s (%d) to list of known chats",
-		msg.Message.Chat.Type,
-		msg.Message.Chat.Title,
-		msg.Message.Chat.ID,
-	)
+	// Telegram normally reports one newcomer per service message. If that ever
+	// stops being true, the sweeper would only judge the first member, so make it
+	// visible in the logs rather than silently ignoring the rest.
+	if len(msg.Message.NewChatMembers) > 1 {
+		mylog.Warnf(
+			"MULTI-MEMBER JOIN in chat %d: %d newcomers in one event, only the first is moderated",
+			msg.Message.Chat.ID,
+			len(msg.Message.NewChatMembers),
+		)
+	}
 
-	ChatList = append(ChatList, msg.Message.Chat.ID)
-	slices.Sort(ChatList)
-	ChatList = slices.Compact(ChatList)
-
-	AddChat(&msg.Message.Chat)
+	// Keep only the newcomers we can actually address. In production the ingress has
+	// already refused such an update; this filter is the nil-safety that keeps a
+	// direct caller from recording somebody we cannot name.
+	newcomers := make([]*echotron.User, 0, len(msg.Message.NewChatMembers))
 
 	for _, user := range msg.Message.NewChatMembers {
-		Log.Infof(
+		if !usableUser(user) {
+			continue
+		}
+
+		newcomers = append(newcomers, user)
+	}
+
+	if len(newcomers) == 0 {
+		return
+	}
+
+	// Remember the join so the greeting sweeper can tell later whether this
+	// newcomer answered, and so a ban can retract the greeting we sent.
+	//
+	// The join is recorded before the greeting exists, so the greeting id starts
+	// at zero and is filled in once the send returns. A join whose greeting was
+	// never delivered therefore carries zero, which is exactly the marker
+	// retractGreetings skips.
+	joinMicros := time.Now().UnixMicro()
+	PendingGreetings.Set(joinMicros, pendingGreeting{join: msg.Message}, greetCacheTTL)
+
+	// Record the join in the chat log before anything else, so the arrival is on
+	// record even if the greeting later fails. elog writes one line per newcomer
+	// itself, so this is called once for the whole event rather than per user.
+	elog.LogMessage(msg.Message)
+
+	for _, user := range newcomers {
+		mylog.Infof(
 			"User %s %s (username = %s, id = %d) joined %s %s (%d)",
 			user.FirstName,
 			user.LastName,
@@ -36,60 +66,23 @@ func newChatMembers(msg *echotron.Update) {
 			msg.Message.Chat.ID,
 		)
 
-		AddUser(user)
+		// Greet the newcomer, so that a spammer who never answers becomes
+		// detectable. If the greeting could not be delivered the newcomer never
+		// saw the question, so they must not be judged on their silence.
+		greetingID, delivered := sendGreeting(msg.Message.Chat.ID, user)
+		if !delivered {
+			PendingGreetings.Delete(joinMicros)
 
-		casBanned, err := CasCheckID(user.ID)
-
-		if err != nil {
-			Log.Error(err)
+			return
 		}
 
-		// Ban user if cas report it as banned.
-		if casBanned {
-			Log.Infof(
-				"Ban user %s %s (username = %s, id = %d) in %s %s (%d) by CAS blacklist",
-				user.FirstName,
-				user.LastName,
-				user.Username,
-				user.ID,
-				msg.Message.Chat.Type,
-				msg.Message.Chat.Title,
-				msg.Message.Chat.ID,
-			)
-
-			squash(
-				msg.Message.Chat.ID,
-				user.ID,
-			)
-		}
-
-		// Do not return on prev. step.
-
-		Log.Infof(
-			"Skip banning user %s %s (username = %s, id = %d) in %s %s (%d) because it was not found in CAS blacklist",
-			user.FirstName,
-			user.LastName,
-			user.Username,
-			user.ID,
-			msg.Message.Chat.Type,
-			msg.Message.Chat.Title,
-			msg.Message.Chat.ID,
-		)
-
-		Log.Infof(
-			"Add user %s %s (username = %s, id = %d) in %s %s (%d) to NewMember DB",
-			user.FirstName,
-			user.LastName,
-			user.Username,
-			user.ID,
-			msg.Message.Chat.Type,
-			msg.Message.Chat.Title,
-			msg.Message.Chat.ID,
-		)
-
-		key := fmt.Sprintf("%d+%d", msg.Message.Chat.ID, user.ID)
-		NewMembers.Set(key, time.Now().Unix(), 1*time.Minute)
-		PendingCASMembers.Set(key, time.Now().Unix(), 30*time.Minute)
+		// Re-record the join carrying the greeting's id. A member who joined
+		// twice has one recorded join per greeting, so each id is retracted
+		// separately.
+		PendingGreetings.Set(joinMicros, pendingGreeting{
+			join:       msg.Message,
+			greetingID: greetingID,
+		}, greetCacheTTL)
 	}
 }
 

internal/moon/photo.go

@@ -1,50 +0,0 @@
-package moon
-
-import (
-	"fmt"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-// photo handles messages with photos.
-func photo(msg *echotron.Update) {
-	AddChat(&msg.Message.Chat)
-	AddUser(msg.Message.From)
-
-	if Cfg.LogChats {
-		if msg.Message.Text != "" {
-			ChatLog(
-				msg.Message.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) sent %d photos to %s %s (%d) with text: %s",
-					msg.Message.From.FirstName,
-					msg.Message.From.LastName,
-					msg.Message.From.Username,
-					msg.Message.From.ID,
-					len(msg.Message.Photo),
-					msg.Message.Chat.Type,
-					msg.Message.Chat.Title,
-					msg.Message.Chat.ID,
-					msg.Message.Text,
-				),
-			)
-		} else {
-			ChatLog(
-				msg.Message.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) sent %d photos to %s %s (%d)",
-					msg.Message.From.FirstName,
-					msg.Message.From.LastName,
-					msg.Message.From.Username,
-					msg.Message.From.ID,
-					len(msg.Message.Photo),
-					msg.Message.Chat.Type,
-					msg.Message.Chat.Title,
-					msg.Message.Chat.ID,
-				),
-			)
-		}
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/reaction.go

@@ -1,68 +0,0 @@
-package moon
-
-import (
-	"fmt"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-func reaction(msg *echotron.Update) {
-	AddChat(&msg.MessageReaction.Chat)
-	AddUser(&msg.MessageReaction.User)
-
-	if Cfg.LogChats {
-		var reactionString string
-
-		for _, item := range msg.MessageReaction.NewReaction {
-			switch item.Type {
-			case "Emoji":
-				reactionString += item.Emoji
-			case "CustomEmoji":
-				reactionString += item.CustomEmoji
-			}
-		}
-
-		if reactionString != "" {
-			ChatLog(
-				msg.MessageReaction.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) set reaction %s to chat %s %s (%d)",
-					msg.MessageReaction.User.FirstName,
-					msg.MessageReaction.User.LastName,
-					msg.MessageReaction.User.Username,
-					msg.MessageReaction.User.ID,
-					reactionString,
-					msg.MessageReaction.Chat.Type,
-					msg.MessageReaction.Chat.Title,
-					msg.MessageReaction.Chat.ID,
-				),
-			)
-		} else {
-			for _, item := range msg.MessageReaction.OldReaction {
-				switch item.Type {
-				case "Emoji":
-					reactionString += item.Emoji
-				case "CustomEmoji":
-					reactionString += item.CustomEmoji
-				}
-			}
-
-			ChatLog(
-				msg.MessageReaction.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) removed reaction %s to chat %s %s (%d)",
-					msg.MessageReaction.User.FirstName,
-					msg.MessageReaction.User.LastName,
-					msg.MessageReaction.User.Username,
-					msg.MessageReaction.User.ID,
-					reactionString,
-					msg.MessageReaction.Chat.Type,
-					msg.MessageReaction.Chat.Title,
-					msg.MessageReaction.Chat.ID,
-				),
-			)
-		}
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/reactionCount.go

@@ -1,24 +0,0 @@
-package moon
-
-import (
-	"fmt"
-
-	"github.com/NicoNex/echotron/v3"
-	"github.com/davecgh/go-spew/spew"
-)
-
-// reactionCount handles reactionCount event.
-func reactionCount(msg *echotron.Update) {
-	ChatLog(
-		msg.MessageReaction.Chat.ID,
-		fmt.Sprintf(
-			"Reaction count event in %s %s (%d): %s",
-			msg.MessageReaction.Chat.Type,
-			msg.MessageReaction.Chat.Title,
-			msg.MessageReaction.Chat.ID,
-			spew.Sdump(msg),
-		),
-	)
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/retractGreeting.go

@@ -0,0 +1,119 @@
+package moon
+
+import (
+	"bunny-bot/internal/elog"
+	"bunny-bot/internal/mylog"
+
+	"github.com/NicoNex/echotron/v3"
+)
+
+// retractGreetings deletes the greetings we sent to a member who has just been
+// banned for never answering them, so the room is not left asking a question of
+// someone who no longer has access.
+//
+// Ids <= 0 mean "no greeting was ever sent for that join" and are skipped
+// silently. A deletion Telegram refuses is logged and the pass continues: the
+// greeting is not worth abandoning the rest over, and a failed retraction never
+// changes the ban that has already landed.
+func retractGreetings(chat *echotron.Chat, user *echotron.User, greetingIDs []int) retractOutcome {
+	retracted, failed := 0, 0
+
+	for _, id := range greetingIDs {
+		if id <= 0 {
+			continue
+		}
+
+		if _, err := Tg.DeleteMessage(chat.ID, id); err != nil {
+			failed++
+
+			reportRetractFailure(chat, user, id, err)
+
+			continue
+		}
+
+		retracted++
+
+		elog.LogGreetingRetracted(chat, user, id)
+	}
+
+	return retractOutcomeFor(retracted, failed)
+}
+
+// reportRetractFailure logs a refused deletion. It is a WARN rather than an ERROR
+// because the ban it followed already succeeded and nothing depends on the
+// greeting being gone.
+func reportRetractFailure(chat *echotron.Chat, user *echotron.User, id int, err error) {
+	mylog.Warnf(
+		"Left an unanswered greeting in place: cannot delete message %d in chat %d for user %d: %s",
+		id,
+		chat.ID,
+		userIDOf(user),
+		err,
+	)
+}
+
+// retractAskedGreetings takes down the questions this member was asked and never
+// answered. One id per recorded join, so a member who joined twice had two
+// greetings and both go.
+func retractAskedGreetings(refs []joinRef) {
+	ids := make([]int, 0, len(refs))
+	for _, ref := range refs {
+		ids = append(ids, ref.greetingID)
+	}
+
+	chat, user := refs[0].chat, refs[0].user
+
+	switch retractGreetings(&chat, user, ids) {
+	case greetingRetracted:
+		mylog.Debugf(
+			"Deleted %d unanswered greeting(s) asked of user %d in chat %d",
+			countNamedGreetings(ids),
+			user.ID,
+			chat.ID,
+		)
+	case greetingRetractFailed:
+		mylog.Warnf(
+			"Banned user %d in chat %d, but could not delete every greeting we asked them",
+			user.ID,
+			chat.ID,
+		)
+	case nothingToRetract:
+	}
+}
+
+// countNamedGreetings counts the ids that actually named a message; the rest
+// mean no greeting was ever delivered.
+func countNamedGreetings(ids []int) int {
+	n := 0
+
+	for _, id := range ids {
+		if id > 0 {
+			n++
+		}
+	}
+
+	return n
+}
+
+// retractOutcomeFor collapses the two counts into the single value callers act on.
+func retractOutcomeFor(retracted int, failed int) retractOutcome {
+	switch {
+	case retracted > 0 && failed == 0:
+		return greetingRetracted
+	case failed > 0:
+		return greetingRetractFailed
+	default:
+		return nothingToRetract
+	}
+}
+
+// userIDOf names a user in a log line without dereferencing a possibly nil one.
+func userIDOf(user *echotron.User) int64 {
+	if user == nil {
+		return 0
+	}
+
+	return user.ID
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/runAndBan.go

@@ -1,293 +0,0 @@
-package moon
-
-import (
-	"fmt"
-	"slices"
-	"strconv"
-	"strings"
-	"time"
-)
-
-func RunAndBan() {
-	for {
-		var (
-			ListAppearedMembers, ListNewMembers []string
-		)
-
-		AppearedMembers.Range(
-			func(k, _ any) bool {
-				ListAppearedMembers = append(ListAppearedMembers, k.(string))
-
-				return true
-			},
-		)
-
-		NewMembers.Range(
-			func(k, _ any) bool {
-				ListNewMembers = append(ListNewMembers, k.(string))
-
-				return true
-			},
-		)
-
-		for _, AppearedMember := range ListAppearedMembers {
-			for _, NewMember := range ListNewMembers {
-				if AppearedMember == NewMember {
-					AppearedMembers.Delete(AppearedMember)
-					NewMembers.Delete(NewMember)
-				}
-			}
-		}
-
-		currentTime := time.Now().Unix()
-
-		ListAppearedMembers = ListAppearedMembers[:0]
-		ListNewMembers = ListNewMembers[:0]
-		ListAppearedMembers = slices.Clip(ListAppearedMembers)
-		ListNewMembers = slices.Clip(ListNewMembers)
-
-		AppearedMembers.Range(
-			func(k, _ any) bool {
-				ListAppearedMembers = append(ListAppearedMembers, k.(string))
-
-				return true
-			},
-		)
-
-		NewMembers.Range(
-			func(k, _ any) bool {
-				ListNewMembers = append(ListNewMembers, k.(string))
-
-				return true
-			},
-		)
-
-		for _, AppearedMember := range ListAppearedMembers {
-			eventTimestamp, found := AppearedMembers.Get(AppearedMember)
-
-			if !found {
-				continue
-			}
-
-			eventTimeDelta := currentTime - eventTimestamp.(int64)
-
-			// Spammer?
-			if eventTimeDelta > 10 {
-				item := strings.Split(AppearedMember, "+")
-				chatid, err := strconv.ParseInt(item[0], 10, 64)
-
-				if err != nil {
-					Log.Errorf("Got broken key in AppearedMembers cache: %s", AppearedMember)
-
-					continue
-				}
-
-				userid, err := strconv.ParseInt(item[1], 10, 64)
-
-				if err != nil {
-					Log.Errorf("Got broken key in AppearedMembers cache: %s", AppearedMember)
-
-					continue
-				}
-
-				user := GetUser(userid)
-				chat := GetChat(chatid)
-
-				Log.Infof(
-					"Ban user %s %s (username = %s, id = %d) in chat %s %s (%d) that have no newChatMember message since chatMemberUpdated for more than 10 seconds",
-					user.FirstName,
-					user.LastName,
-					user.Username,
-					userid,
-					chat.Type,
-					chat.Title,
-					chatid,
-				)
-
-				squash(chatid, userid)
-
-				AppearedMembers.Delete(AppearedMember)
-			}
-		}
-
-		for _, NewMember := range ListNewMembers {
-			eventTimestamp, found := NewMembers.Get(NewMember)
-
-			if !found {
-				continue
-			}
-
-			eventTimeDelta := currentTime - eventTimestamp.(int64)
-
-			// Spammer?
-			if eventTimeDelta > 10 {
-				item := strings.Split(NewMember, "+")
-				chatid, err := strconv.ParseInt(item[0], 10, 64)
-
-				if err != nil {
-					Log.Errorf("Got broken key in AppearedMembers cache: %s", NewMember)
-
-					continue
-				}
-
-				userid, err := strconv.ParseInt(item[1], 10, 64)
-
-				if err != nil {
-					Log.Errorf("Got broken key in AppearedMembers cache: %s", NewMember)
-
-					continue
-				}
-
-				user := GetUser(userid)
-				chat := GetChat(chatid)
-
-				Log.Debugf("Clean newChatMember event record older than 10 seconds for user user %s %s (username = %s, id = %d) in chat %s %s (%d)",
-					user.FirstName,
-					user.LastName,
-					user.Username,
-					userid,
-					chat.Type,
-					chat.Title,
-					chatid,
-				)
-
-				NewMembers.Delete(NewMember)
-			}
-		}
-
-		time.Sleep(10 * time.Second)
-	}
-}
-
-func PeriodicCASCheck() {
-	for {
-		var (
-			ListPendingMembers []string
-		)
-
-		PendingCASMembers.Range(
-			func(k, _ any) bool {
-				ListPendingMembers = append(ListPendingMembers, k.(string))
-
-				return true
-			},
-		)
-
-		currentTime := time.Now().Unix()
-
-		for _, PendingMember := range ListPendingMembers {
-			eventTimestamp, found := PendingCASMembers.Get(PendingMember)
-
-			if !found {
-				continue
-			}
-
-			eventTimeDelta := currentTime - eventTimestamp.(int64)
-
-			// It's time to check for second time this id if it was banned in CAS.
-			if eventTimeDelta > 300 {
-				item := strings.Split(PendingMember, "+")
-				chatid, err := strconv.ParseInt(item[0], 10, 64)
-
-				if err != nil {
-					Log.Errorf("Got broken key in PendingMembers cache: %s", PendingMember)
-
-					continue
-				}
-
-				userid, err := strconv.ParseInt(item[1], 10, 64)
-
-				if err != nil {
-					Log.Errorf("Got broken key in PendingMembers cache: %s", PendingMember)
-
-					continue
-				}
-
-				value := Cfg.GetValue(
-					"BannedMembers",
-					fmt.Sprintf("%d", chatid),
-					fmt.Sprintf("%d", userid),
-				)
-
-				user := GetUser(userid)
-				chat := GetChat(chatid)
-
-				if value != "" {
-					Log.Debugf("User %s %s (username = %s, id = %d) in %s %s (%d) is already banned, skip cas check.",
-						user.FirstName,
-						user.LastName,
-						user.Username,
-						userid,
-						chat.Type,
-						chat.Title,
-						chatid,
-					)
-
-					Log.Debugf(
-						"Remove user %s %s (username = %s, id = %d) in %s %s (%d) from PendingCASMembers",
-						user.FirstName,
-						user.LastName,
-						user.Username,
-						userid,
-						chat.Type,
-						chat.Title,
-						chatid,
-					)
-
-					key := fmt.Sprintf("%d+%d", chatid, userid)
-					PendingCASMembers.Delete(key)
-
-					return
-				}
-
-				Log.Debugf("Checking user %s %s (username = %s, id = %d) in %s %s (%d) for second time in CAS",
-					user.FirstName,
-					user.LastName,
-					user.Username,
-					userid,
-					chat.Type,
-					chat.Title,
-					chatid,
-				)
-
-				banned, err := CasCheckID(userid)
-
-				if err != nil {
-					Log.Error(err)
-				}
-
-				if banned {
-					Log.Infof(
-						"Ban user %s %s (username = %s, id = %d) in %s %s (%d) by CAS blacklist",
-						user.FirstName,
-						user.LastName,
-						user.Username,
-						userid,
-						chat.Type,
-						chat.Title,
-						chatid,
-					)
-
-					squash(chatid, userid)
-				}
-
-				Log.Debugf(
-					"Remove user %s %s (username = %s, id = %d) in %s %s (%d) from PendingCASMembers",
-					user.FirstName,
-					user.LastName,
-					user.Username,
-					userid,
-					chat.Type,
-					chat.Title,
-					chatid,
-				)
-
-				PendingCASMembers.Delete(PendingMember)
-			}
-		}
-
-		time.Sleep(10 * time.Minute)
-	}
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/shutdown.go

@@ -0,0 +1,97 @@
+package moon
+
+import (
+	"bunny-bot/internal/elog"
+	"bunny-bot/internal/mylog"
+	"fmt"
+
+	"github.com/akyoto/cache"
+)
+
+// closeCaches shuts down every cache sweeper goroutine.
+//
+// Safe only once the update listener and the greeting sweeper have stopped:
+// cache.Close() reassigns the underlying sync.Map, which is a data race against
+// any concurrent reader. shutdown() enforces that order.
+func closeCaches() {
+	closeOnce.Do(func() {
+		for _, c := range []*cache.Cache{
+			SquashedMembers,
+			PendingGreetings.cache, GreetAnswers.cache,
+		} {
+			c.Close()
+		}
+	})
+}
+
+// Shutdown performs the ordered teardown, waits for it to finish, and reports
+// whether every stage of it succeeded.
+//
+// main calls it after Telegram returns, for two reasons. The listener returning is
+// not by itself a finished shutdown — a signal handler may be halfway through the
+// sequence at that moment, and main returning would end the process underneath it,
+// skipping stages and closing the log twice. And if the listener stopped for any
+// other reason, nobody would run the sequence at all.
+//
+// It is safe to call from both goroutines: sync.Once runs the body once and blocks
+// every other caller until that run completes, so both callers see the same result.
+func Shutdown() error {
+	return shutdown()
+}
+
+// shutdown stops everything in dependency order and waits for each stage.
+//
+// The order is not cosmetic. Every stage waits for the previous one to have
+// finished, so no goroutine is ever using a resource that the next stage is
+// closing:
+//
+//  1. the Telegram update listener — nothing else may add work;
+//  2. the greeting sweeper — the last periodic user of the caches;
+//  3. the caches — cache.Close() both signals the sweeper goroutines and
+//     reassigns the underlying sync.Map, so it must run with nothing else
+//     touching them;
+//  4. chat logging, then 5. the main log — so the last log lines, which
+//     describe stages 1 to 3, still have somewhere to go.
+//
+// Stages 1 and 2 share one stop signal and one WaitGroup, so a worker that has
+// not started costs nothing and a worker that starts late is refused rather than
+// racing the wait.
+//
+// The main log's own failure is reported ahead of the chat log's, because it happened
+// last: a chat-log failure may no longer have been writable either.
+func shutdown() error {
+	var result error
+
+	shutdownOnce.Do(func() {
+		// Refuse new workers before signalling, so nothing can register between
+		// the signal and the wait below.
+		workersMu.Lock()
+		stopping = true
+		workersMu.Unlock()
+
+		// Ask every loop to return, then wait for all of them. Nothing may be
+		// using a cache, a log or the API once the next stages start closing.
+		close(stopRequested)
+		workers.Wait()
+
+		closeCaches()
+
+		// Chat logging first: it writes to the main log, so it must be closed
+		// before the main log is.
+		chatErr := elog.Close()
+
+		// Since we shutting down, we have noting to do with log sync.
+		logErr := mylog.Close()
+
+		switch {
+		case logErr != nil:
+			result = fmt.Errorf("main log: %w", logErr)
+		case chatErr != nil:
+			result = fmt.Errorf("chat log: %w", chatErr)
+		}
+	})
+
+	return result
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/sighandler.go

@@ -2,39 +2,89 @@ package moon
 
 import (
 	"os"
-	"syscall"
+	"os/signal"
+
+	"bunny-bot/internal/mylog"
 )
 
-// SigHandler.handles signals. Mainly closes persistent dbs and quits for good.
-func SigHandler() {
-	for {
-		var s = <-SigChan
-		switch s {
-		case syscall.SIGINT:
-			Log.Infoln("Got SIGINT, quitting")
-		case syscall.SIGTERM:
-			Log.Infoln("Got SIGTERM, quitting")
-		case syscall.SIGQUIT:
-			Log.Infoln("Got SIGQUIT, quitting")
+// InstallSignalHandler registers every signal the bot cares about and starts the
+// handler goroutine. The signal sets differ per platform, so the knowledge lives
+// behind terminationSignals and reopenSignals rather than leaking into main.
+func InstallSignalHandler() {
+	signal.Notify(SigChan, terminationSignals()...)
+	signal.Notify(SigChan, reopenSignals()...)
 
-		// Make new iteration since we 've got signal we not interested in.
-		default:
+	go SigHandler()
+}
+
+// SigHandler handles signals until one asks the process to quit.
+//
+// It stops the program; it does not end it. os.Exit here would skip main's
+// deferred cleanup, and would report success whether or not the teardown actually
+// worked — a service manager told "clean shutdown" over a log nobody can write to
+// again is worse than one told to restart us. So the handler runs the teardown and
+// returns; main decides the exit status from its own call to Shutdown.
+func SigHandler() {
+	for s := range SigChan {
+		if !handleSignal(s) {
 			continue
 		}
 
-		if len(DB) > 0 {
-			Log.Debug("Closing runtime bot settings db")
-
-			for _, db := range DB {
-				_ = db.Close()
-			}
+		if err := shutdown(); err != nil {
+			// The main log is already closed by now, so this is the last line we
+			// get to write; main still exits non-zero over the same failure.
+			mylog.Errorf("Shutdown did not complete cleanly: %s", err)
 		}
 
-		// Since we shutting down, we have noting to do with log sync.
-		_ = Log.Sync()
-
-		os.Exit(0)
+		return
 	}
 }
 
+// handleSignal applies one signal and reports whether it means "shut down".
+//
+// Reopen signals re-open the log file, which is what a log rotation tool needs
+// after it has moved the file aside. Neither of them is expected on Windows,
+// and an unrecognised signal is ignored rather than treated as a quit.
+func handleSignal(s os.Signal) bool {
+	if containsSignal(reopenSignals(), s) {
+		mylog.Infof("Got %s, re-opening the log file", s)
+
+		if err := mylog.ReOpen(); err != nil {
+			// Reopening can legitimately fail — the destination may not be a
+			// file at all, or the logger may already be closed. Logging is
+			// best-effort here because the log is exactly what just broke.
+			mylog.Errorf("Unable to re-open the log file on %s: %s", s, err)
+		} else {
+			mylog.Info("Log file re-opened")
+		}
+
+		return false
+	}
+
+	if !containsSignal(terminationSignals(), s) {
+		// Make new iteration since we 've got signal we not interested in.
+		return false
+	}
+
+	// The status has to be recorded here, before the teardown runs: main reads
+	// it after Shutdown returns, and neither of them can reconstruct which
+	// signal triggered all of this by then.
+	recordExitCode(s)
+
+	mylog.Infof("Got %s, quitting", s)
+
+	return true
+}
+
+// containsSignal reports whether sig is in the set.
+func containsSignal(set []os.Signal, sig os.Signal) bool {
+	for _, s := range set {
+		if s == sig {
+			return true
+		}
+	}
+
+	return false
+}
+
 /* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/signals_unix.go

@@ -0,0 +1,25 @@
+//go:build !windows
+
+package moon
+
+import (
+	"os"
+	"syscall"
+)
+
+// terminationSignals are the signals that ask the bot to shut down.
+func terminationSignals() []os.Signal {
+	return []os.Signal{syscall.SIGINT, syscall.SIGTERM, syscall.SIGQUIT}
+}
+
+// reopenSignals are the signals that ask the bot to re-open its log file.
+//
+// SIGHUP is the conventional daemon signal for "re-read your configuration and
+// re-open your logs"; SIGUSR1 is the other common choice for log re-opening
+// alone. Both are accepted so the bot fits either convention an operator's
+// logrotate configuration expects.
+func reopenSignals() []os.Signal {
+	return []os.Signal{syscall.SIGHUP, syscall.SIGUSR1}
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/signals_windows.go

@@ -0,0 +1,22 @@
+//go:build windows
+
+package moon
+
+import "os"
+
+// terminationSignals are the signals that ask the bot to shut down.
+func terminationSignals() []os.Signal {
+	return []os.Signal{os.Interrupt}
+}
+
+// reopenSignals is empty on Windows.
+//
+// SIGHUP and SIGUSR1 are Unix signals that Windows never delivers — SIGUSR1 does
+// not even exist in the syscall package there — so there is nothing to re-open
+// the log for. The empty set keeps handleSignal platform-agnostic: a Windows
+// service restarts to rotate its logs instead of signalling.
+func reopenSignals() []os.Signal {
+	return nil
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/squash.go

@@ -1,32 +1,47 @@
 package moon
 
 import (
+	"bunny-bot/internal/mylog"
 	"fmt"
-	"slices"
 	"time"
 
 	"github.com/NicoNex/echotron/v3"
 )
 
-// TODO: refactor to return bool, error
-
-// squash bans given chat member.
-func squash(chatid int64, userid int64) {
-	banUntilDate := time.Now().Unix() + 10
-
-	user := GetUser(userid)
-	chat := GetChat(chatid)
-
-	// If there is no such chatid, means that no such cache too.
-	if len(ChatList) == 0 || !slices.Contains(ChatList, chatid) {
-		Log.Debugf("Add %s %s (%d) to list of known chats", chat.Type, chat.Title, chat.ID)
-
-		ChatList = append(ChatList, chatid)
+// squash bans the given chat member and reports what it actually did.
+//
+// The three outcomes are deliberately distinct. A debounced call is not a
+// failure: the user is already banned, which is the outcome we wanted, and the
+// caller must not report it as an error.
+//
+// The user and chat come from the join event that triggered the judgement
+// rather than from a cache. That event already carries both in full, so a cache
+// would only ever be a second, staler copy of data we are holding — and a miss
+// in it would produce a ban logged with blank names.
+func squash(chat *echotron.Chat, user *echotron.User) banOutcome {
+	// A chat or user with no id is an entity we cannot address, not a ban that
+	// failed. In production the ingress has already refused such an update, so
+	// reaching here means a caller handed us one directly; the guard is the
+	// nil-safety that keeps that from becoming a call against chat 0.
+	if !usableChat(chat) {
+		return banFailed
 	}
 
+	if !usableUser(user) {
+		return banFailed
+	}
+
+	// Telegram treats any ban shorter than 30 seconds (and longer than 1 year)
+	// as permanent, so this deliberately short offset produces a permanent ban.
+	// Do not "fix" it into a longer duration.
+	banUntilDate := time.Now().Unix() + 10
+
+	chatid, userid := chat.ID, user.ID
+
 	key := fmt.Sprintf("%d+%d", chatid, userid)
+
 	if _, exist := SquashedMembers.Get(key); exist {
-		Log.Infof(
+		mylog.Infof(
 			"Skip banning user %s %s (username = %s, id = %d) in %s %s (%d), already banned",
 			user.FirstName,
 			user.LastName,
@@ -37,17 +52,18 @@ func squash(chatid int64, userid int64) {
 			chat.ID,
 		)
 
-		return
+		return banSuppressed
 	}
 
-	if res, err := Tg.BanChatMember(
+	res, err := Tg.BanChatMember(
 		chatid,
 		userid,
 		&echotron.BanOptions{
 			UntilDate: int(banUntilDate),
 		},
-	); err != nil {
-		Log.Errorf(
+	)
+	if err != nil {
+		mylog.Errorf(
 			"Unable to ban user user %s %s (username = %s, id = %d) in %s %s (%d): %s",
 			user.FirstName,
 			user.LastName,
@@ -56,85 +72,53 @@ func squash(chatid int64, userid int64) {
 			chat.Type,
 			chat.Title,
 			chat.ID,
+			err,
+		)
+
+		return banFailed
+	}
+
+	if !res.Ok {
+		mylog.Errorf(
+			"Unable to ban user %s %s (username = %s, id = %d) in %s %s (%d): %s",
+			user.FirstName,
+			user.LastName,
+			user.Username,
+			user.ID,
+			chat.Type,
+			chat.Title,
+			chat.ID,
 			res.Description,
 		)
-	} else {
-		if !res.Ok {
-			Log.Errorf(
-				"Unable to ban user %s %s (username = %s, id = %d) in %s %s (%d): %s",
-				user.FirstName,
-				user.LastName,
-				user.Username,
-				user.ID,
-				chat.Type,
-				chat.Title,
-				chat.ID,
-				res.Description,
-			)
-		} else {
-			Log.Debugf(
-				"Banned user %s %s (username = %s, id = %d) in %s %s (%d).",
-				user.FirstName,
-				user.LastName,
-				user.Username,
-				user.ID,
-				chat.Type,
-				chat.Title,
-				chat.ID,
-			)
 
-			key := fmt.Sprintf("%d+%d", chatid, userid)
-
-			Log.Debugf(
-				"Put user %s %s (username = %s, id = %d) in %s %s (%d) into SquashedMembers to debounce ban.",
-				user.FirstName,
-				user.LastName,
-				user.Username,
-				user.ID,
-				chat.Type,
-				chat.Title,
-				chat.ID,
-			)
-
-			SquashedMembers.Set(key, true, 30*time.Second)
-
-			Log.Debugf(
-				"Remove user %s %s (username = %s, id = %d) in %s %s (%d) from NewMembers.",
-				user.FirstName,
-				user.LastName,
-				user.Username,
-				user.ID,
-				chat.Type,
-				chat.Title,
-				chat.ID,
-			)
-
-			NewMembers.Delete(key)
-
-			Log.Debugf(
-				"Remove user %s %s (username = %s, id = %d) in %s %s (%d) from AppearedMembers.",
-				user.FirstName,
-				user.LastName,
-				user.Username,
-				user.ID,
-				chat.Type,
-				chat.Title,
-				chat.ID,
-			)
-			AppearedMembers.Delete(key)
-
-			if err := Cfg.SaveKeyValue(
-				"BannedMembers",
-				fmt.Sprintf("%d", chatid),
-				fmt.Sprintf("%d", userid),
-				fmt.Sprintf("%d", time.Now().Unix()),
-			); err != nil {
-				Log.Error(err)
-			} else {
-				Log.Infof("Info about banned userid %d saved to BannedMembers db", userid)
-			}
-		}
+		return banFailed
 	}
+
+	mylog.Debugf(
+		"Banned user %s %s (username = %s, id = %d) in %s %s (%d).",
+		user.FirstName,
+		user.LastName,
+		user.Username,
+		user.ID,
+		chat.Type,
+		chat.Title,
+		chat.ID,
+	)
+
+	mylog.Debugf(
+		"Put user %s %s (username = %s, id = %d) in %s %s (%d) into SquashedMembers to debounce ban.",
+		user.FirstName,
+		user.LastName,
+		user.Username,
+		user.ID,
+		chat.Type,
+		chat.Title,
+		chat.ID,
+	)
+
+	SquashedMembers.Set(key, true, 30*time.Second)
+
+	return banApplied
 }
 
 /* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/telegram.go

@@ -1,74 +1,110 @@
 package moon
 
 import (
+	"bunny-bot/internal/elog"
+	"bunny-bot/internal/mylog"
+
 	"github.com/NicoNex/echotron/v3"
 	"github.com/davecgh/go-spew/spew"
 )
 
 // Telegram main goroutine that implements bot.
+//
+// It blocks until a termination signal stops it, so the update listener can be
+// shut down in a defined order rather than simply abandoned when the process
+// exits.
 func Telegram(cfg MyConfig) {
+	// A signal can arrive during startup; then this must not start at all.
+	if !startWorker() {
+		mylog.Info("Telegram not started: shutdown already in progress")
+
+		return
+	}
+
+	defer stopWorker()
+
 	Tg = echotron.NewAPI(cfg.Token)
 
-	Log.Infof("Starting api update poller loop")
+	mylog.Info("Starting api update poller loop")
 
-	for u := range echotron.PollingUpdatesOptions(cfg.Token, true, echotron.UpdateOptions{
-		AllowedUpdates: []echotron.UpdateType{
-			"message",
-			"edited_message",
-			"channel_post",
-			"edited_channel_post",
-			"message_reaction",
-			"message_reaction_count",
-			"inline_query",
-			"chosen_inline_result",
-			"callback_query",
-			"poll",
-			"poll_answer",
-			"my_chat_member",
-			"chat_member",
-			"chat_join_request",
-			"chat_boost",
-			"removed_chat_boost",
-		},
-	}) {
-		telegramMsgParser(u)
+	// The sweeper calls the API too, so it may only start once Tg exists.
+	mylog.Info("Starting greeting sweeper periodic task")
+
+	go SweepGreetings()
+
+	updates := echotron.PollingUpdatesOptions(cfg.Token, true, echotron.UpdateOptions{
+		AllowedUpdates: allowedUpdates,
+	})
+
+	for {
+		select {
+		// Stop between updates, never inside one: the handler currently running
+		// finishes, so nothing is left half-processed when we return.
+		case <-stopRequested:
+			mylog.Info("Telegram update listener stopped")
+
+			return
+
+		case u, ok := <-updates:
+			if !ok {
+				mylog.Info("Telegram update poller ended")
+
+				return
+			}
+
+			telegramMsgParser(u)
+		}
 	}
 }
 
 // telegramMsgParser parses events generated by echotron.
 func telegramMsgParser(msg *echotron.Update) {
+	// The one place an update enters the program, and therefore the one place an
+	// entity with no id is caught. Everything downstream — the caches, the sweeper,
+	// the bans — may then assume the ids it holds are real.
+	if !usableUpdate(msg) {
+		reportBrokenUpdate(msg)
+
+		return
+	}
+
 	switch {
-	case msg.Message != nil && msg.Message.Text != "":
-		textMessage(msg)
-
-	case msg.EditedMessage != nil:
-		editedMessage(msg)
-
+	// Membership status changes: joins, leaves, bans, promotions. Logged only —
+	// moderation is the sweeper's job, on a timer, not the dispatcher's.
+	//
+	// This also catches the membership updates caused by our own bans, so every
+	// ban leaves a second record in the chat log.
 	case msg.ChatMember != nil:
-		chatMemberUpdated(msg)
+		elog.LogUserStatus(msg.ChatMember)
 
-	// New members entered to chat.
+	// New members entered to chat. Checked before the text case so that a
+	// join service message is never mistaken for ordinary chatter.
 	case msg.Message != nil && msg.Message.NewChatMembers != nil:
 		newChatMembers(msg)
 
-	// Chat member leaves chat.
-	case msg.Message != nil && msg.Message.LeftChatMember != nil:
-		leftChatMember(msg)
+	// Ordinary text messages, used as greeting answers.
+	case msg.Message != nil && msg.Message.Text != "":
+		textMessage(msg)
 
-	case msg.Message != nil && msg.Message.Animation != nil:
-		animation(msg)
+	// Everything else that is still a message: a photo with no caption, a
+	// sticker, a location, a leave, a title change. Logged, and deliberately NOT
+	// recorded as a greeting answer — an attachment is not an introduction, and
+	// letting one satisfy the detector would be a one-key bypass for a spammer.
+	//
+	// The condition is deliberately just "there is a message": elog already
+	// renders every media and service field, and already writes nothing for a
+	// message with no describable content, so emptiness is its decision to make.
+	// Testing for a field being non-empty here is what lost these messages.
+	case msg.Message != nil:
+		logOnlyMessage(msg)
 
-	case msg.MessageReaction != nil:
-		reaction(msg)
-
-	case msg.MessageReactionCount != nil:
-		reactionCount(msg)
-
-	case msg.Message != nil && msg.Message.Photo != nil:
-		photo(msg)
+	// An edit revises a message already recorded, so it is a chat-log event
+	// rather than a moderation one.
+	case msg.EditedMessage != nil:
+		elog.LogEditedMessage(msg.EditedMessage)
 
 	default:
-		Log.Debug(spew.Sdump(msg))
+		mylog.Debug(spew.Sdump(msg))
 	}
 }
 

internal/moon/textMessage.go

@@ -1,58 +1,27 @@
 package moon
 
 import (
-	"fmt"
+	"time"
+
+	"bunny-bot/internal/elog"
 
 	"github.com/NicoNex/echotron/v3"
 )
 
-// textMessage handles text message events.
+// textMessage handles plain text messages. It does not moderate anything; it
+// only records the message so the greeting sweeper can tell that a newcomer
+// answered their greeting.
 func textMessage(msg *echotron.Update) {
-	AddChat(&msg.Message.Chat)
-	AddUser(msg.Message.From)
-
-	// Not sure if we must handle all kinds of these events.
-	if Cfg.LogChats {
-		switch {
-		// Just log it, it seems later here should be ban/mute command set.
-		case msg.Message != nil && msg.Message.ReplyToMessage == nil:
-			ChatLog(
-				msg.Message.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) in %s %s (%d) says: %s",
-					msg.Message.From.FirstName,
-					msg.Message.From.LastName,
-					msg.Message.From.Username,
-					msg.Message.From.ID,
-					msg.Message.Chat.Type,
-					msg.Message.Chat.Title,
-					msg.Message.Chat.ID,
-					msg.Message.Text,
-				),
-			)
-
-		case msg.Message != nil && msg.Message.ReplyToMessage != nil:
-			ChatLog(
-				msg.Message.Chat.ID,
-				fmt.Sprintf(
-					"User %s %s (username = %s, id = %d) in %s %s (%d) replies to message %d by %s %s (username = %s, id = %d): %s",
-					msg.Message.From.FirstName,
-					msg.Message.From.LastName,
-					msg.Message.From.Username,
-					msg.Message.From.ID,
-					msg.Message.Chat.Type,
-					msg.Message.Chat.Title,
-					msg.Message.Chat.ID,
-					msg.Message.ReplyToMessage.ID,
-					msg.Message.ReplyToMessage.From.FirstName,
-					msg.Message.ReplyToMessage.From.LastName,
-					msg.Message.ReplyToMessage.From.Username,
-					msg.Message.ReplyToMessage.From.ID,
-					msg.Message.Text,
-				),
-			)
-		}
+	if msg.Message == nil || msg.Message.Text == "" {
+		return
 	}
+
+	// Remember the message so the greeting sweeper can find the answer to a
+	// greeting.
+	GreetAnswers.Set(time.Now().UnixMicro(), msg.Message, greetCacheTTL)
+
+	// And record it in the chat's own log, which outlives the cache.
+	elog.LogMessage(msg.Message)
 }
 
 /* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/types.go

@@ -1,40 +1,82 @@
 package moon
 
 import (
-	"os"
-	"time"
+	"github.com/NicoNex/echotron/v3"
+	"github.com/akyoto/cache"
 )
 
 // MyConfig describes bot config file format.
 type MyConfig struct {
-	Name     string `json:"name,omitempty"`
 	Token    string `json:"token,omitempty"`
 	LogLevel string `json:"loglevel,omitempty"`
 	LogFile  string `json:"logfile,omitempty"`
-	LogChats bool   `json:"logchats,omitempty"`
-	CSign    string `json:"csign,omitempty"`
-	DataDir  string `json:"datadir,omitempty"`
+
+	// ChatLogs is the directory for per-chat, per-day chat event logs. Empty
+	// disables chat logging. If set, the directory must already exist: a path
+	// that does not is a typo, and silently logging nowhere is the worst
+	// possible response to one.
+	ChatLogs string `json:"chat_logs,omitempty"`
 }
 
-// CasFalse describes response from api.cas.chat when user is not blacklisted.
-type CasFalse struct {
-	Ok          bool   `json:"ok"`
-	Description string `json:"description"`
+// tgClient is the subset of the Telegram API that bunny-bot actually calls.
+// It exists so tests can substitute a fake; echotron.API satisfies it.
+type tgClient interface {
+	SendMessage(text string, chatID int64, opts *echotron.MessageOptions) (echotron.APIResponseMessage, error)
+	BanChatMember(chatID int64, userID int64, opts *echotron.BanOptions) (echotron.APIResponseBool, error)
+	DeleteMessage(chatID int64, messageID int) (echotron.APIResponseBase, error)
 }
 
-// CasFalse describes response from api.cas.chat when user is blacklisted.
-type CasTrue struct {
-	Ok     bool `json:"ok"`
-	Result struct {
-		Reasons   []int     `json:"reasons"`
-		Offenses  int       `json:"offenses"`
-		TimeAdded time.Time `json:"time_added"`
-	} `json:"result"`
+// chatUser identifies a user's membership of one specific chat. The same user is
+// a different identity in every chat: being silent in one says nothing about
+// another, and answering in one must not rescue them in another.
+type chatUser struct {
+	chatID int64
+	userID int64
 }
 
-type Chatlog struct {
-	LogFilePath string
-	File        *os.File
+// banOutcome is what a squash attempt actually did. The three cases are distinct
+// on purpose: a duplicate ban is a success, not a failure, and reporting it as
+// one makes a working ban look broken in the logs.
+type banOutcome int
+
+// eventCache is a typed wrapper over akyoto/cache.Cache that stores values of
+// type T keyed by a Unix timestamp in microseconds. It hides the underlying
+// sync.Map so callers never deal with interface{} keys/values or per-access type
+// conversions.
+type eventCache[T any] struct {
+	cache *cache.Cache
 }
 
+// joinRef is one stale join, kept together with everything the verdict and the
+// retraction need so neither has to look anything up.
+type joinRef struct {
+	micros int64
+
+	// chat and user come from the join event itself, so a ban can be logged with
+	// the newcomer's real name and the chat's real title instead of a cache
+	// lookup that may have expired or never been populated.
+	chat echotron.Chat
+	user *echotron.User
+
+	// greetingID is the question we asked them, deleted once they are banned for
+	// never answering it. Zero means we never managed to ask.
+	greetingID int
+}
+
+// pendingGreeting is one recorded join: the message that announced it, and the
+// id of the greeting we sent in reply.
+//
+// The greeting id lives here rather than in a second cache, so that recording,
+// forgetting and retracting are all one lookup on one key. A zero greeting id
+// means "no greeting was ever delivered for this join" — never a failure.
+type pendingGreeting struct {
+	join       *echotron.Message
+	greetingID int
+}
+
+// retractOutcome is what a retraction pass actually achieved. The three cases are
+// distinct because "nothing to delete" and "tried and failed" call for different
+// log lines, and only the second is worth an operator's attention.
+type retractOutcome int
+
 /* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/usersGroups.go

@@ -1,76 +0,0 @@
-package moon
-
-import (
-	"encoding/json"
-	"time"
-
-	"github.com/NicoNex/echotron/v3"
-)
-
-// AddUser remebers user info in People cache.
-func AddUser(u *echotron.User) {
-	bytes, err := json.Marshal(u)
-
-	if err != nil {
-		Log.Errorf("Unable to encode user info to json string: %s", err)
-	}
-
-	People.Set(u.ID, bytes, 24*time.Hour)
-}
-
-// GetUser returns user info structure.
-func GetUser(id int64) *echotron.User {
-	var u *echotron.User
-
-	bytes, ok := People.Get(id)
-
-	if !ok {
-		return u
-	}
-
-	err := json.Unmarshal(bytes.([]byte), &u)
-
-	if err != nil {
-		Log.Errorf("Unable to decode user info json: %s", err)
-
-		return u
-	}
-
-	return u
-}
-
-// AddChat remebers chat info in Groups cache.
-func AddChat(c *echotron.Chat) {
-	bytes, err := json.Marshal(c)
-
-	if err != nil {
-		Log.Errorf("Unable to encode chat info to json string: %s", err)
-	}
-
-	Groups.Set(c.ID, bytes, 24*time.Hour)
-}
-
-// GetChat returns chat info structure.
-func GetChat(id int64) *echotron.Chat {
-	var c *echotron.Chat
-
-	bytes, ok := Groups.Get(id)
-
-	if !ok {
-		Log.Errorf("No group %d in Groups cache", id)
-
-		return c
-	}
-
-	err := json.Unmarshal(bytes.([]byte), &c)
-
-	if err != nil {
-		Log.Errorf("Unable to decode chat info json: %s", err)
-
-		return c
-	}
-
-	return c
-}
-
-/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/moon/worker.go

@@ -0,0 +1,36 @@
+package moon
+
+// The worker registry: how a background goroutine joins the shutdown sequence,
+// and how it leaves it. The state itself lives in globals.go with the rest of the
+// package-level variables; this file holds only what a goroutine does with it.
+
+// stopWorker unregisters a background goroutine that has finished.
+func stopWorker() {
+	runningWorkers.Add(-1)
+	workers.Done()
+}
+
+// workerRunning reports whether any registered worker is still running.
+func workerRunning() bool {
+	return runningWorkers.Load() > 0
+}
+
+// startWorker registers a background goroutine with the shutdown sequence and
+// reports whether it may run. It returns false once shutdown has begun, in
+// which case the caller must return without starting: the stop signal is
+// already closed and the teardown may already have closed what it would use.
+func startWorker() bool {
+	workersMu.Lock()
+	defer workersMu.Unlock()
+
+	if stopping {
+		return false
+	}
+
+	workers.Add(1)
+	runningWorkers.Add(1)
+
+	return true
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/globals.go

@@ -0,0 +1,71 @@
+package mylog
+
+import (
+	"errors"
+	"io"
+	"os"
+	"sync"
+)
+
+const (
+	// levelTrace is the most verbose level, below DEBUG.
+	levelTrace Level = iota
+	levelDebug
+	levelInfo
+	levelWarn
+	levelError
+	levelFatal
+)
+
+const (
+	// stampLayout is the timestamp layout. Sub-second precision is kept on
+	// purpose: the greeting sweeper reasons over 15-minute windows measured in
+	// microseconds, and the previous zap configuration truncated to whole
+	// seconds, which made window-edge debugging needlessly hard.
+	stampLayout = "2006-01-02 15:04:05.000"
+
+	// calldepth is reported to the stdlib logger. mylog never prints caller
+	// information, so the value only has to be consistent.
+	calldepth = 2
+
+	// filePerm is the mode for a newly created log file.
+	filePerm = 0o644
+)
+
+var (
+	// errClosed is returned when ReOpen is called on a closed logger.
+	errClosed = errors.New("cannot reopen a closed logger")
+
+	// errUnknownLevel is returned for a log level name mylog does not know.
+	errUnknownLevel = errors.New("unknown log level")
+
+	// levelNames renders each level as the uppercase token written to the log.
+	levelNames = map[Level]string{
+		levelTrace: "TRACE",
+		levelDebug: "DEBUG",
+		levelInfo:  "INFO",
+		levelWarn:  "WARN",
+		levelError: "ERROR",
+		levelFatal: "FATAL",
+	}
+
+	// exit is os.Exit, indirected so tests can observe the fatal path.
+	exit = os.Exit
+
+	// lock guards the package-global logger state. It is held for reading across
+	// the actual write, so that a concurrent Init cannot close the destination
+	// between the level check and the write.
+	lock sync.RWMutex
+
+	// current is the active logger. It is deliberately never nil: it is created
+	// working at package initialisation, writing to stderr at INFO. A nil logger
+	// would be the defect M2 in this codebase, and a valid default removes the
+	// state entirely rather than guarding against it.
+	current = newState(levelInfo, io.Writer(os.Stderr), "", nil, false)
+
+	// standard is the singleton Logger handed to modules that expect a
+	// *log.Logger. It is stateless; the package-global current does the work.
+	standard Logger = &adapter{}
+)
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/level.go

@@ -0,0 +1,59 @@
+package mylog
+
+// The level vocabulary: what a level is called, how a name in free-form config
+// text becomes a Level, and how the configured threshold is changed without
+// reopening the destination.
+
+import (
+	"fmt"
+	"strings"
+)
+
+// ParseLevel maps a level name to a Level. Parsing is case-insensitive and
+// tolerates surrounding whitespace, because the level comes from free-form user
+// text in the config file. An unknown name is an error: Init and SetLevel are
+// programming-level calls where a typo should be loud.
+func ParseLevel(s string) (Level, error) {
+	switch strings.ToUpper(strings.TrimSpace(s)) {
+	case "TRACE":
+		return levelTrace, nil
+	case "DEBUG":
+		return levelDebug, nil
+	case "INFO":
+		return levelInfo, nil
+	case "WARN":
+		return levelWarn, nil
+	case "ERROR":
+		return levelError, nil
+	case "FATAL":
+		return levelFatal, nil
+	default:
+		return levelInfo, fmt.Errorf("%w %q, want one of trace, debug, info, warn, error, fatal", errUnknownLevel, s)
+	}
+}
+
+// SetLevel changes the level without reopening the destination.
+func SetLevel(loglevel string) error {
+	lvl, err := ParseLevel(loglevel)
+	if err != nil {
+		return err
+	}
+
+	lock.Lock()
+	defer lock.Unlock()
+
+	current.level = lvl
+
+	return nil
+}
+
+// name returns the uppercase token for the level.
+func (l Level) name() string {
+	if n, ok := levelNames[l]; ok {
+		return n
+	}
+
+	return "UNKNOWN"
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/log.go

@@ -0,0 +1,118 @@
+package mylog
+
+// The destination lifecycle: opening the log, re-opening it for rotation, and
+// closing it for good. The level vocabulary lives in level.go, the state in
+// state.go, and the act of writing a line in write.go.
+
+import (
+	"fmt"
+	"io"
+	stdlog "log"
+	"os"
+)
+
+// Init opens the log destination and sets the level.
+//
+// An empty filepath selects stderr. A non-empty path is opened appending, so
+// an existing log is never truncated.
+//
+// Init is re-entrant: any previously open file is closed first, so repeated
+// calls do not leak descriptors. If the new destination cannot be opened, Init
+// returns an error and leaves the previous destination and level untouched —
+// it deliberately does not fall back to stderr, because a silent fallback
+// hides a broken log path from the operator.
+func Init(loglevel string, filepath string) error {
+	lvl, err := ParseLevel(loglevel)
+	if err != nil {
+		return err
+	}
+
+	lock.Lock()
+	defer lock.Unlock()
+
+	dest, owned := io.Writer(os.Stderr), (*os.File)(nil)
+
+	if filepath != "" {
+		// The path comes from the operator's own config file, not from a
+		// network peer, and opening it is this function's entire purpose.
+		file, err := os.OpenFile(filepath, os.O_CREATE|os.O_APPEND|os.O_WRONLY, filePerm) //nolint: gosec // G703
+		if err != nil {
+			return fmt.Errorf("unable to open log file %s: %w", filepath, err)
+		}
+
+		dest, owned = file, file
+	}
+
+	swapLocked(lvl, dest, filepath, owned)
+
+	// Keep the standard library's default logger pointed at the same
+	// destination, so third-party stdlib logging does not bypass our file.
+	stdlog.SetFlags(0)
+	stdlog.SetOutput(dest)
+
+	return nil
+}
+
+// ReOpen closes and re-opens the current log file, keeping its level. It exists
+// for external rotation: the rotation tool moves the file aside, and ReOpen
+// makes the logger pick up the new one.
+//
+// ReOpen on a closed logger is an error rather than a silent reopen, and on a
+// stderr destination it is a no-op, since there is no file to re-open.
+func ReOpen() error {
+	lock.RLock()
+	closed, path, lvl := current.closed, current.path, current.level
+	lock.RUnlock()
+
+	switch {
+	case closed:
+		return errClosed
+	case path == "":
+		return nil
+	default:
+		return Init(lvl.name(), path)
+	}
+}
+
+// Close closes the log destination. It is idempotent, and it is safe when the
+// destination is stderr — stderr is not ours to close.
+//
+// After Close, logging calls are silently dropped rather than panicking or
+// resurrecting the file: Close is terminal.
+func Close() error {
+	lock.Lock()
+	defer lock.Unlock()
+
+	if current.closed {
+		return nil
+	}
+
+	current.closed = true
+
+	if current.owned == nil {
+		return nil
+	}
+
+	// The stdlib Logger has no Close — it does not own its writer — so the file
+	// we opened ourselves is closed directly.
+	file := current.owned
+	current.owned = nil
+
+	if file == nil {
+		return nil
+	}
+
+	return file.Close()
+}
+
+// swapLocked installs a new state, closing any file we previously owned.
+// The caller must hold the write lock.
+func swapLocked(lvl Level, dest io.Writer, path string, owned *os.File) {
+	if current.owned != nil {
+		_ = current.owned.Close()
+	}
+
+	current = newState(lvl, dest, path, owned, false)
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/standard.go

@@ -0,0 +1,28 @@
+package mylog
+
+// The standard-library-compatible Logger: what a module receives instead of
+// depending on *log.Logger itself, and where its messages end up.
+
+import "strings"
+
+// Standard returns the Logger for modules that would otherwise depend on the
+// standard library's *log.Logger. Messages passed to it are logged at debug
+// level into the already-open destination.
+//
+// Returning the interface rather than the concrete *adapter is the whole point:
+// it is the type such modules declare, so hiding it would defeat the
+// substitution it exists for.
+func Standard() Logger { //nolint:ireturn // deliberate public interface
+	return standard
+}
+
+// Output implements Logger, logging at debug level. The trailing newline of the
+// standard library convention is trimmed so that mylog does not append a blank
+// line to every message.
+func (a *adapter) Output(_ int, s string) error {
+	write(levelDebug, strings.TrimRight(s, "\r\n"))
+
+	return nil
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/state.go

@@ -0,0 +1,52 @@
+package mylog
+
+// The logger state: the one struct every write goes through, how a new one is
+// built, and the two accessors that read and replace it under the package lock.
+// The state itself lives in globals.go with the rest of the package-level
+// variables; this file holds only what a caller does with it.
+
+import (
+	"io"
+	stdlog "log"
+	"os"
+)
+
+// newState builds a state whose stdlib logger writes to dest.
+func newState(lvl Level, dest io.Writer, path string, owned *os.File, closed bool) *state {
+	return &state{
+		level:  lvl,
+		dest:   dest,
+		slog:   newStdLogger(dest),
+		path:   path,
+		owned:  owned,
+		closed: closed,
+	}
+}
+
+// newStdLogger wraps a writer in a standard library logger. Flags are zeroed
+// because the line format is rendered by mylog itself.
+func newStdLogger(dest io.Writer) *stdLogger {
+	l := stdlog.New(dest, "", 0)
+	l.SetFlags(0)
+
+	return l
+}
+
+// getState returns the active logger state.
+func getState() *state {
+	lock.RLock()
+	defer lock.RUnlock()
+
+	return current
+}
+
+// setState replaces the active state wholesale. Tests use it to restore the
+// documented before-Init default.
+func setState(s *state) {
+	lock.Lock()
+	defer lock.Unlock()
+
+	current = s
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/types.go

@@ -0,0 +1,43 @@
+package mylog
+
+// Types only. The level constants, the name table and Level.name live in
+// globals.go and level.go respectively, because a file named "types" must hold
+// nothing that is not a type.
+
+import (
+	"io"
+	stdlog "log"
+	"os"
+)
+
+// Level is the severity of a log message. Levels are ordered, and a message is
+// written when its own level is at or above the configured level.
+type Level int
+
+// stdLogger is the standard library logger doing the actual writing.
+type stdLogger = stdlog.Logger
+
+// Logger is the interface for modules that would otherwise depend on the
+// standard library's *log.Logger. It is deliberately the smallest method set
+// that *log.Logger satisfies, so widening a module's parameter type from
+// *log.Logger to Logger keeps existing callers compiling.
+type Logger interface {
+	Output(calldepth int, s string) error
+}
+
+// adapter is the Logger handed to such modules. Messages arrive through
+// Output and are logged at debug level into the already-open destination.
+type adapter struct{}
+
+// state is everything the logger needs to write a line. It is held behind a
+// lock so that a concurrent Init cannot close a destination mid-write.
+type state struct {
+	level  Level
+	dest   io.Writer
+	slog   *stdLogger
+	path   string
+	owned  *os.File
+	closed bool
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/wrappers.go

@@ -0,0 +1,63 @@
+package mylog
+
+import (
+	"fmt"
+)
+
+// Trace logs at the most verbose level, below DEBUG.
+func Trace(args ...any) { write(levelTrace, fmt.Sprint(args...)) }
+
+// Tracef logs a formatted message at the most verbose level, below DEBUG.
+func Tracef(format string, args ...any) { write(levelTrace, fmt.Sprintf(format, args...)) }
+
+// Debug logs at debug level.
+func Debug(args ...any) { write(levelDebug, fmt.Sprint(args...)) }
+
+// Debugf logs a formatted message at debug level.
+func Debugf(format string, args ...any) { write(levelDebug, fmt.Sprintf(format, args...)) }
+
+// Info logs at info level.
+func Info(args ...any) { write(levelInfo, fmt.Sprint(args...)) }
+
+// Infof logs a formatted message at info level.
+func Infof(format string, args ...any) { write(levelInfo, fmt.Sprintf(format, args...)) }
+
+// Warn logs at warn level.
+func Warn(args ...any) { write(levelWarn, fmt.Sprint(args...)) }
+
+// Warnf logs a formatted message at warn level.
+func Warnf(format string, args ...any) { write(levelWarn, fmt.Sprintf(format, args...)) }
+
+// Error logs at error level.
+func Error(args ...any) { write(levelError, fmt.Sprint(args...)) }
+
+// Errorf logs a formatted message at error level.
+func Errorf(format string, args ...any) { write(levelError, fmt.Sprintf(format, args...)) }
+
+// Fatal logs at fatal level, then exits the process with status 1.
+//
+// The destination is closed before exiting. os.Exit does not run deferred
+// functions, so without this an explicit close a buffered tail could be lost —
+// which is precisely the case where the message matters most.
+func Fatal(args ...any) {
+	write(levelFatal, fmt.Sprint(args...))
+
+	exitAfterClose(1)
+}
+
+// Fatalf logs a formatted message at fatal level, then exits the process with
+// status 1. The destination is closed first; see Fatal.
+func Fatalf(format string, args ...any) {
+	write(levelFatal, fmt.Sprintf(format, args...))
+
+	exitAfterClose(1)
+}
+
+// exitAfterClose closes the logger and then exits, in that order.
+func exitAfterClose(code int) {
+	_ = Close()
+
+	exit(code)
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */

internal/mylog/write.go

@@ -0,0 +1,28 @@
+package mylog
+
+// The one-line emit path: decide whether the line is wanted, render it, write
+// it. Everything else in the package exists to reach these two functions.
+
+import "time"
+
+// write renders and writes one line if the level passes the filter and the
+// logger is open. The read lock is held across the write so that a concurrent
+// Init cannot close the destination underneath us.
+func write(lvl Level, msg string) {
+	lock.RLock()
+	defer lock.RUnlock()
+
+	if current.closed || lvl < current.level {
+		return
+	}
+
+	_ = current.slog.Output(calldepth, render(lvl, msg))
+}
+
+// render builds one log line: a GMT+0 timestamp, the uppercase level, and the
+// message verbatim, separated by exactly one space each.
+func render(lvl Level, msg string) string {
+	return time.Now().UTC().Format(stampLayout) + " " + lvl.name() + " " + msg
+}
+
+/* vim: set ft=go noet ai ts=4 sw=4 sts=4: */