X-Git-Url: https://git.giacomolli.uk/onechat/blobdiff_plain/8d9547f6e7ffa1e95ad25d9f8f2e7cfd23d992d0..871743f6ab20d68dcede1673a9764730fda38308:/whatsapp.go?ds=sidebyside diff --git a/whatsapp.go b/whatsapp.go index 2c1b6cb..95e1d54 100644 --- a/whatsapp.go +++ b/whatsapp.go @@ -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("WhatsApp messages do not come, because the connection failed, and it is tried again only at a restart of the daemon: %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("WhatsApp messages stop, because the phone logged out this device (run /whatsapp pair PHONE to link it again)") + 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("the session of the logged out device stays on the disk, because its 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("the chat has no note of the logout, because its write 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("WhatsApp messages stop, because the user unlinked WhatsApp") + w.logger.Info("unlinked") + err = l.note("WhatsApp is unlinked.") if err != nil { - w.logger.Printf("the chat has no note of the unlink, because its write 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("WhatsApp is linked") + w.logger.Info("linked") err = l.note("WhatsApp is linked.") if err != nil { - w.logger.Printf("the chat has no note of the link, because its write 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) @@ -732,12 +861,14 @@ func (w *WhatsApp) handle(event any) bool { switch { case !w.linked || w.connected: case w.disconnectedAt.IsZero(): - line = "WhatsApp is connected, and new messages come in" + line = "connected" default: - line = "WhatsApp is 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()) { - line = "new WhatsApp messages wait, because the connection is lost (the next try is automatic)" - if !w.connected { - line = "new WhatsApp messages wait, because the first connection failed (the next try is automatic)" + connected := w.connected + if w.startOutage() { + level = slog.LevelWarn + line = "disconnected, retrying" + 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 = "WhatsApp messages do not come, because the connection is lost and it is tried again only at a restart of the daemon: " + 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)