]> git.giacomolli.uk - onechat/blobdiff - whatsapp.go
Show an input prompt while the agent is idle
[onechat] / whatsapp.go
index 40729d83b044e8ca1303c2a1b08a10786d587e40..95e1d54ea01e80f8216f29e38d63a56a479cc07a 100644 (file)
@@ -4,7 +4,7 @@ import (
        "context"
        "errors"
        "fmt"
-       "log"
+       "log/slog"
        "net/url"
        "os"
        "path/filepath"
@@ -65,6 +65,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 +103,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 +116,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 +145,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)
        }
 
@@ -170,7 +179,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
@@ -187,6 +196,7 @@ type WhatsApp struct {
        own            []string
        notify         func(Event)
        connected      bool
+       retrying       bool
        connectedAt    time.Time
        disconnectedAt time.Time
        disconnections int
@@ -198,21 +208,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 +260,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 +277,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 +289,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 +327,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 +335,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
        }
 
@@ -396,22 +450,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 +538,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 +547,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 +567,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 +584,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 +595,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
        }
 
@@ -511,9 +621,11 @@ func (w *WhatsApp) unlink(ctx context.Context, l *TurnLoop, answer func(text str
 // its files.
 func (w *WhatsApp) removeSession() error {
        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 +646,7 @@ func (w *WhatsApp) removeSession() error {
        }
 
        var err error
+
        if container != nil {
                err = container.Close()
        }
@@ -563,6 +676,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 +695,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 +703,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 +719,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 +728,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 +743,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 +763,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
                }
        }
@@ -695,14 +816,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 +836,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 +863,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 +879,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 +912,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 +926,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 +943,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 +988,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 +1052,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)