X-Git-Url: https://git.giacomolli.uk/onechat/blobdiff_plain/7088b82414bdf947a6f88918c0a7b2c7fb0c53ef..c3c7bc90eb73e83f48fbeac6be149ade95a726c0:/whatsapp.go diff --git a/whatsapp.go b/whatsapp.go index 40729d8..0c68a44 100644 --- a/whatsapp.go +++ b/whatsapp.go @@ -2,9 +2,10 @@ package main import ( "context" + "database/sql" "errors" "fmt" - "log" + "log/slog" "net/url" "os" "path/filepath" @@ -65,6 +66,13 @@ const ( // gets a notice. whatsappNoticeDelay = 10 * time.Minute + // whatsappRetryDelay is the first wait after a failed starting + // connection. + whatsappRetryDelay = 2 * time.Second + + // whatsappRetryLimit is the longest wait between starting connections. + whatsappRetryLimit = 5 * time.Minute + // whatsappRequests is the number of pair and unlink commands that can // wait for Run. whatsappRequests = 8 @@ -96,7 +104,7 @@ type WhatsAppClient interface { // the account, so a file that another user can read is an error. The clock // gives the times of the status, logger gets the failures, and newClient makes // the client of a device with its event handler. -func openWhatsApp(ctx context.Context, dir string, clock func() time.Time, logger *log.Logger, newClient func(device *store.Device, handle func(event any) bool) WhatsAppClient) (*WhatsApp, error) { +func openWhatsApp(ctx context.Context, dir string, clock func() time.Time, logger *slog.Logger, newClient func(device *store.Device, handle func(event any) bool) WhatsAppClient) (*WhatsApp, error) { w := &WhatsApp{ dir: filepath.Join(dir, whatsappDirName), clock: clock, @@ -109,6 +117,7 @@ func openWhatsApp(ctx context.Context, dir string, clock func() time.Time, logge } var err error + w.state, err = openWhatsAppState(filepath.Join(w.dir, whatsappStateFileName), whatsappBatchQuiet, whatsappBatchWindow) if err != nil { return nil, err @@ -137,6 +146,7 @@ func openWhatsApp(ctx context.Context, dir string, clock func() time.Time, logge if w.device.ID != nil { w.linked = true w.inbox.waitForCatchup() + w.own = whatsappOwnIDs(w.device.ID.User, w.device.LID.User) } @@ -154,7 +164,9 @@ func openWhatsApp(ctx context.Context, dir string, clock func() time.Time, logge // of the client that asked. A logout from the phone comes as an event of the // library, and Run deletes the session. The mutex protects the session, the // client, and the state of the connection, which the event handler of the -// library changes from its own goroutines. +// library changes from its own goroutines. The sessionMutex serializes session +// creation, close, removal, and snapshots. It is held before mutex, and stays +// held when removal releases mutex for client callbacks. // // The inbox puts the text messages into batches and logs them, and groups // holds the names of the groups. Both get a WhatsAppLink from link for each @@ -170,7 +182,7 @@ func openWhatsApp(ctx context.Context, dir string, clock func() time.Time, logge type WhatsApp struct { dir string clock func() time.Time - logger *log.Logger + logger *slog.Logger newClient func(device *store.Device, handle func(event any) bool) WhatsAppClient noticeDelay time.Duration requests chan WhatsAppRequest @@ -179,6 +191,7 @@ type WhatsApp struct { groups *WhatsAppGroups inbox *WhatsAppInbox + sessionMutex sync.Mutex mutex sync.Mutex container *sqlstore.Container device *store.Device @@ -187,6 +200,7 @@ type WhatsApp struct { own []string notify func(Event) connected bool + retrying bool connectedAt time.Time disconnectedAt time.Time disconnections int @@ -198,21 +212,51 @@ type WhatsApp struct { // Run connects a linked device, logs the closed batches in l, runs the pair and // unlink commands, and handles a logout from the phone, until ctx ends. Its // notes go to the log of l, and notify gets the notices for all clients. A -// failed first connection is logged, and the library tries again when the -// failure is one of the network. Run returns the error of a write of the log or -// of the state file, which stops the daemon, because then messages would be -// lost. +// failed first connection starts the same outage notice as a lost connection. A +// timer in the select retries it with a doubled wait from 2 seconds to 5 +// minutes, without a retry goroutine or a wait that blocks commands or the +// inbox. A connection, unlink, logout, or ctx end stops retries. The library +// owns retries after a connection opens. Run returns the error of a write of +// the log or of the state file, which stops the daemon, because then messages +// would be lost. func (w *WhatsApp) Run(ctx context.Context, l *TurnLoop, notify func(Event)) error { w.mutex.Lock() + w.notify = notify linked := w.linked + w.retrying = linked w.mutex.Unlock() - if linked { - w.connect(ctx) + timer := time.NewTimer(whatsappRetryDelay) + timer.Stop() + defer timer.Stop() + + var retry <-chan time.Time + + delay := whatsappRetryDelay + connect := func() { + retry = nil + if w.connect(ctx) { + timer.Reset(delay) + + retry = timer.C + delay = min(2*delay, whatsappRetryLimit) + } + } + + stopRetry := func() { + timer.Stop() + + retry = nil + + w.mutex.Lock() + + w.retrying = false + w.mutex.Unlock() } var pairing sync.WaitGroup + cancel := func() {} defer func() { cancel() @@ -220,6 +264,10 @@ func (w *WhatsApp) Run(ctx context.Context, l *TurnLoop, notify func(Event)) err w.close() }() + if linked { + connect() + } + for { err := w.inbox.deliver(ctx, l, w.link(), false) if err != nil { @@ -233,7 +281,11 @@ func (w *WhatsApp) Run(ctx context.Context, l *TurnLoop, notify func(Event)) err return err case <-w.inbox.wake: case <-w.inbox.due(): + case <-retry: + connect() case <-w.logouts: + stopRetry() + err = w.loggedOut(ctx, l) if err != nil { return err @@ -241,10 +293,13 @@ func (w *WhatsApp) Run(ctx context.Context, l *TurnLoop, notify func(Event)) err case request := <-w.requests: cancel() pairing.Wait() + cancel = func() {} switch { case request.unlink: + stopRetry() + err = w.unlink(ctx, l, request.answer) if err != nil { return err @@ -276,6 +331,7 @@ func (w *WhatsApp) Command(args string, answer func(text string)) { switch { case len(fields) == 1 && fields[0] == "status": answer(w.Status()) + return case len(fields) == 1 && fields[0] == "unlink": request.unlink = true @@ -283,12 +339,14 @@ func (w *WhatsApp) Command(args string, answer func(text string)) { phone, valid := whatsappPhone(strings.Join(fields[1:], "")) if !valid { answer("PHONE must be the number of your WhatsApp account with its country code: 7 to 15 digits, such as +15550001111.") + return } request.phone = phone default: answer(whatsappUsage) + return } @@ -320,8 +378,62 @@ func (w *WhatsApp) Status() string { } } +// BackupSession writes a consistent SQLite snapshot to path while the session +// cannot be created, closed, or removed. The source opens without creation +// permission. No session file means no linked state to copy. +func (w *WhatsApp) BackupSession(ctx context.Context, path string) (err error) { + w.sessionMutex.Lock() + defer w.sessionMutex.Unlock() + + w.mutex.Lock() + defer w.mutex.Unlock() + + _, err = os.Stat(w.sessionPath()) + if errors.Is(err, os.ErrNotExist) { + return nil + } + + if err != nil { + return fmt.Errorf("read session file: %w", err) + } + + err = os.MkdirAll(filepath.Dir(path), 0o700) + if err != nil { + return fmt.Errorf("create session snapshot directory: %w", err) + } + + address, err := whatsappSessionAddress(w.sessionPath()) + if err != nil { + return fmt.Errorf("find session database: %w", err) + } + + database, err := sql.Open("sqlite", address+"&mode=rw") + if err != nil { + return fmt.Errorf("open session snapshot source: %w", err) + } + + defer func() { + err = errors.Join(err, database.Close()) + }() + + _, err = database.ExecContext(ctx, "VACUUM INTO ?", path) + if err != nil { + return fmt.Errorf("snapshot session database: %w", err) + } + + err = os.Chmod(path, 0o600) + if err != nil { + return fmt.Errorf("set session snapshot mode: %w", err) + } + + return nil +} + // Close closes the session database. func (w *WhatsApp) Close() error { + w.sessionMutex.Lock() + defer w.sessionMutex.Unlock() + w.mutex.Lock() defer w.mutex.Unlock() @@ -396,22 +508,71 @@ func (w *WhatsApp) link() WhatsAppLink { } } -// connect makes the client of the linked device and connects it. -func (w *WhatsApp) connect(ctx context.Context) { +// connect tries the starting connection of the linked device with one client. +// It returns whether Run must retry. A failed call starts the shared outage +// state and logs its redacted cause once, because a returned ConnectContext +// error does not emit Disconnected. Connected logs recovery after +// authentication. +func (w *WhatsApp) connect(ctx context.Context) bool { w.mutex.Lock() - w.client = w.newClient(w.device, w.handle) + + if ctx.Err() != nil || !w.linked || !w.retrying || w.closed { + w.mutex.Unlock() + + return false + } + + if w.client == nil { + w.client = w.newClient(w.device, w.handle) + } + client := w.client w.mutex.Unlock() err := client.ConnectContext(ctx) - if err != nil { - w.logger.Printf("connect failed, restart to retry: %s", w.redact(err.Error())) + + w.mutex.Lock() + + if err == nil || ctx.Err() != nil || !w.retrying || !w.linked { + w.retrying = false + w.mutex.Unlock() + + return false } + + first := w.startOutage() + cause := whatsappRedact(w.own, err.Error()) + w.mutex.Unlock() + + if first { + w.logger.Warn("first connect failed, retrying", "err", cause) + } + + return true +} + +// startOutage starts the shared outage time and notice timer once. The caller +// holds the mutex. Its result tells whether this is the first failure. +func (w *WhatsApp) startOutage() bool { + first := w.linked && (w.connected || w.disconnectedAt.IsZero()) + if first { + w.disconnectedAt = w.clock() + w.disconnections++ + disconnections := w.disconnections + w.timer = time.AfterFunc(w.noticeDelay, func() { + w.disconnectedLong(disconnections) + }) + } + + w.connected = false + + return first } // close ends the connection and the timer of the notice, and stops all notices. func (w *WhatsApp) close() { w.mutex.Lock() + w.closed = true if w.timer != nil { w.timer.Stop() @@ -435,7 +596,8 @@ func (w *WhatsApp) loggedOut(ctx context.Context, l *TurnLoop) error { return nil } - w.logger.Print("logged out by the phone, run /whatsapp pair PHONE") + w.logger.Error("logged out by the phone, run /whatsapp pair PHONE") + err := w.inbox.deliver(ctx, l, w.link(), true) if err != nil { return err @@ -443,12 +605,12 @@ func (w *WhatsApp) loggedOut(ctx context.Context, l *TurnLoop) error { err = w.removeSession() if err != nil { - w.logger.Printf("session delete failed: %v", err) + w.logger.Error("session delete failed", "err", err) } err = l.note("WhatsApp was unlinked from the phone.") if err != nil { - w.logger.Printf("chat note failed: %v", err) + w.logger.Error("chat note failed", "err", err) } w.broadcast("WhatsApp was unlinked from the phone. Run /whatsapp pair PHONE to link it again.") @@ -463,12 +625,14 @@ func (w *WhatsApp) loggedOut(ctx context.Context, l *TurnLoop) error { // file. func (w *WhatsApp) unlink(ctx context.Context, l *TurnLoop, answer func(text string)) error { w.mutex.Lock() + linked := w.linked client := w.client w.mutex.Unlock() if !linked { answer("WhatsApp is not linked.") + return nil } @@ -478,6 +642,7 @@ func (w *WhatsApp) unlink(ctx context.Context, l *TurnLoop, answer func(text str } var logoutErr error + if client != nil { ctx, cancel := context.WithTimeout(ctx, whatsappLogoutTime) defer cancel() @@ -488,17 +653,20 @@ func (w *WhatsApp) unlink(ctx context.Context, l *TurnLoop, answer func(text str err = w.removeSession() if err != nil { answer("The unlink failed: " + w.redact(err.Error())) + return nil } - w.logger.Print("unlinked") + w.logger.Info("unlinked") + err = l.note("WhatsApp is unlinked.") if err != nil { - w.logger.Printf("chat note failed: %v", err) + w.logger.Error("chat note failed", "err", err) } if client == nil || logoutErr != nil { answer("WhatsApp is unlinked here, but the phone did not get the logout. In WhatsApp on your phone, open Linked devices and remove the device.") + return nil } @@ -508,12 +676,18 @@ func (w *WhatsApp) unlink(ctx context.Context, l *TurnLoop, answer func(text str } // removeSession ends the connection, closes the session database, and deletes -// its files. +// its files. The session lock covers the cleanup after mutex is released, so a +// snapshot or a new session cannot open files that cleanup removes. func (w *WhatsApp) removeSession() error { + w.sessionMutex.Lock() + defer w.sessionMutex.Unlock() + w.mutex.Lock() + client := w.client w.client = nil w.linked = false + w.retrying = false w.own = nil w.connected = false w.disconnectedAt = time.Time{} @@ -534,6 +708,7 @@ func (w *WhatsApp) removeSession() error { } var err error + if container != nil { err = container.Close() } @@ -563,6 +738,7 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, device, err := w.newDevice(ctx) if err != nil { answer("The pairing failed: " + err.Error()) + return } @@ -581,6 +757,7 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, if err != nil { answer("The connection to WhatsApp failed: " + err.Error()) + return } @@ -588,6 +765,7 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, case item, open := <-qr: if !open || item.Event != whatsmeow.QRChannelEventCode { answer("WhatsApp did not start the pairing. Try again later.") + return } case <-ctx.Done(): @@ -603,6 +781,7 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, code, err := client.PairPhone(ctx, phone, true, whatsmeow.PairClientChrome, "Chrome (Linux)") if err != nil { answer("WhatsApp refused the pairing: " + err.Error() + ". Check the phone number and run /whatsapp pair PHONE again.") + return } @@ -611,6 +790,7 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, for { var item whatsmeow.QRChannelItem + open := true select { case item, open = <-qr: @@ -625,17 +805,19 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, switch { case !open || item.Event == whatsmeow.QRChannelTimeout.Event: answer(whatsappPairExpired) + return case item.Event == whatsmeow.QRChannelEventCode: continue case item.Event == whatsmeow.QRChannelSuccess.Event: linked = true + w.linkedBy(client) - w.logger.Print("linked") + w.logger.Info("linked") err = l.note("WhatsApp is linked.") if err != nil { - w.logger.Printf("chat note failed: %v", err) + w.logger.Error("chat note failed", "err", err) } answer("WhatsApp is linked to +" + phone + ".") @@ -643,6 +825,7 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, return default: answer("The pairing failed: " + whatsappItemError(item) + ". Run /whatsapp pair PHONE again.") + return } } @@ -652,6 +835,9 @@ func (w *WhatsApp) pair(ctx, runCtx context.Context, l *TurnLoop, phone string, // directory and the file of the session first, with their modes, when they do // not exist. func (w *WhatsApp) newDevice(ctx context.Context) (*store.Device, error) { + w.sessionMutex.Lock() + defer w.sessionMutex.Unlock() + w.mutex.Lock() defer w.mutex.Unlock() @@ -695,14 +881,14 @@ func (w *WhatsApp) linkedBy(client WhatsAppClient) { // goes to the inbox. The names of the groups follow the events of the groups. A // connection starts a catch-up of the inbox, which ends at OfflineSyncCompleted // or after its catchupLimit. A disconnection keeps the time of its start while -// the library tries again. After noticeDelay of a disconnection, all clients -// get one notice, and they get one more when the connection comes back. A -// disconnection that the library does not try again gives a notice at once. +// Run or the library tries again. After noticeDelay of a disconnection, all +// clients get one notice, and they get one more when the connection comes back. +// A disconnection that the library does not try again gives a notice at once. // // The log of the daemon gets one line for each change of the connection of the // linked device: connected, a failed first connection, a lost connection, and -// connected again with the length of the outage. The retries of the library -// between them log nothing. +// connected again with the length of the outage. The retries of the library and +// Run between them log nothing. func (w *WhatsApp) handle(event any) bool { switch event := event.(type) { case *events.Message: @@ -715,16 +901,24 @@ func (w *WhatsApp) handle(event any) bool { return true case *events.JoinedGroup: w.groups.set(event.JID.String(), event.Name) + return true case *events.OfflineSyncCompleted: w.inbox.endCatchup() + return true case *events.Connected: w.inbox.startCatchup() } var notice, line string + + level := slog.LevelInfo + + var attrs []any + w.mutex.Lock() + switch event := event.(type) { case *events.PairSuccess: w.own = whatsappOwnIDs(event.ID.User, event.LID.User) @@ -734,10 +928,12 @@ func (w *WhatsApp) handle(event any) bool { case w.disconnectedAt.IsZero(): line = "connected" default: - line = "connected again after " + durationText(w.clock().Sub(w.disconnectedAt)) + line = "connected again" + attrs = append(attrs, "after", w.clock().Sub(w.disconnectedAt)) } w.connected = true + w.retrying = false w.connectedAt = w.clock() if w.timer != nil { w.timer.Stop() @@ -748,32 +944,29 @@ func (w *WhatsApp) handle(event any) bool { notice = "WhatsApp is connected again." } case *events.Disconnected: - if w.linked && (w.connected || w.disconnectedAt.IsZero()) { + connected := w.connected + if w.startOutage() { + level = slog.LevelWarn line = "disconnected, retrying" - if !w.connected { + if !connected { line = "first connect failed, retrying" } - - w.disconnectedAt = w.clock() - w.disconnections++ - disconnections := w.disconnections - w.timer = time.AfterFunc(w.noticeDelay, func() { - w.disconnectedLong(disconnections) - }) } - - w.connected = false case *events.LoggedOut: + w.retrying = false select { case w.logouts <- struct{}{}: default: } case events.PermanentDisconnect: + w.retrying = false if w.linked { w.connected = false w.noticed = true notice = "WhatsApp is disconnected and does not connect again by itself: " + event.PermanentDisconnectDescription() + ". Restart the daemon to try again." - line = "disconnected for good, restart to retry: " + whatsappRedact(w.own, event.PermanentDisconnectDescription()) + level = slog.LevelError + line = "disconnected for good, restart to retry" + attrs = append(attrs, "err", whatsappRedact(w.own, event.PermanentDisconnectDescription())) } } @@ -784,7 +977,7 @@ func (w *WhatsApp) handle(event any) bool { w.mutex.Unlock() if line != "" { - w.logger.Print(line) + w.logger.Log(context.Background(), level, line, attrs...) } if notice != "" { @@ -798,6 +991,7 @@ func (w *WhatsApp) handle(event any) bool { // disconnection with the number disconnections ended. func (w *WhatsApp) disconnectedLong(disconnections int) { w.mutex.Lock() + long := !w.closed && w.linked && !w.connected && !w.noticed && w.disconnections == disconnections if long { w.noticed = true @@ -814,6 +1008,7 @@ func (w *WhatsApp) disconnectedLong(disconnections int) { // broadcast gives text as a notice to all clients. func (w *WhatsApp) broadcast(text string) { w.mutex.Lock() + notify := w.notify closed := w.closed w.mutex.Unlock() @@ -858,16 +1053,18 @@ type WhatsAppRequest struct { // name OneChat and a desktop icon only when the platform type is known. func whatsappSetDeviceProps() { store.SetOSInfo("OneChat", [3]uint32{0, 1, 0}) + store.DeviceProps.PlatformType = waCompanionReg.DeviceProps_DESKTOP.Enum() } // whatsappNewClient returns the client of the library for device, with handle -// as its event handler. The client tries again after a failed first connection, -// acknowledges a message only after handle returns true, and downloads no old -// history. +// as its event handler. Run owns failed starting connections of linked devices, +// so only an unlinked device enables the initial retry of the library for +// pairing. The library still retries a lost connection. The client acknowledges +// a message only after handle returns true, and downloads no old history. func whatsappNewClient(device *store.Device, handle func(event any) bool) WhatsAppClient { client := whatsmeow.NewClient(device, waLog.Noop) - client.InitialAutoReconnect = true + client.InitialAutoReconnect = device.ID == nil client.SynchronousAck = true client.ManualHistorySyncDownload = true client.AddEventHandlerWithSuccessStatus(handle) @@ -920,6 +1117,7 @@ func whatsappContactName(ctx context.Context, device *store.Device, jid types.JI // whatsappOwnIDs returns the own number and the own LID that are not empty. func whatsappOwnIDs(ids ...string) []string { var own []string + for _, id := range ids { if id != "" { own = append(own, id)