historysync.go 26 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705
  1. // mautrix-whatsapp - A Matrix-WhatsApp puppeting bridge.
  2. // Copyright (C) 2021 Tulir Asokan
  3. //
  4. // This program is free software: you can redistribute it and/or modify
  5. // it under the terms of the GNU Affero General Public License as published by
  6. // the Free Software Foundation, either version 3 of the License, or
  7. // (at your option) any later version.
  8. //
  9. // This program is distributed in the hope that it will be useful,
  10. // but WITHOUT ANY WARRANTY; without even the implied warranty of
  11. // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  12. // GNU Affero General Public License for more details.
  13. //
  14. // You should have received a copy of the GNU Affero General Public License
  15. // along with this program. If not, see <https://www.gnu.org/licenses/>.
  16. package main
  17. import (
  18. "fmt"
  19. "time"
  20. waProto "go.mau.fi/whatsmeow/binary/proto"
  21. "go.mau.fi/whatsmeow/types"
  22. "maunium.net/go/mautrix"
  23. "maunium.net/go/mautrix/appservice"
  24. "maunium.net/go/mautrix/event"
  25. "maunium.net/go/mautrix/id"
  26. "maunium.net/go/mautrix-whatsapp/config"
  27. "maunium.net/go/mautrix-whatsapp/database"
  28. )
  29. // region User history sync handling
  30. type wrappedInfo struct {
  31. *types.MessageInfo
  32. Type database.MessageType
  33. Error database.MessageErrorType
  34. MediaKey []byte
  35. ExpirationStart uint64
  36. ExpiresIn uint32
  37. }
  38. func (user *User) handleHistorySyncsLoop() {
  39. if !user.bridge.Config.Bridge.HistorySync.Backfill {
  40. return
  41. }
  42. reCheckQueue := make(chan bool, 1)
  43. // Start the backfill queue.
  44. user.BackfillQueue = &BackfillQueue{
  45. BackfillQuery: user.bridge.DB.Backfill,
  46. ImmediateBackfillRequests: make(chan *database.Backfill, 1),
  47. DeferredBackfillRequests: make(chan *database.Backfill, 1),
  48. ReCheckQueue: make(chan bool, 1),
  49. log: user.log.Sub("BackfillQueue"),
  50. }
  51. reCheckQueue = user.BackfillQueue.ReCheckQueue
  52. // Immediate backfills can be done in parallel
  53. for i := 0; i < user.bridge.Config.Bridge.HistorySync.Immediate.WorkerCount; i++ {
  54. go user.handleBackfillRequestsLoop(user.BackfillQueue.ImmediateBackfillRequests)
  55. }
  56. // Deferred backfills should be handled synchronously so as not to
  57. // overload the homeserver. Users can configure their backfill stages
  58. // to be more or less aggressive with backfilling at this stage.
  59. go user.handleBackfillRequestsLoop(user.BackfillQueue.DeferredBackfillRequests)
  60. go user.BackfillQueue.RunLoop(user)
  61. // Always save the history syncs for the user. If they want to enable
  62. // backfilling in the future, we will have it in the database.
  63. for evt := range user.historySyncs {
  64. user.handleHistorySync(reCheckQueue, evt.Data)
  65. }
  66. }
  67. func (user *User) handleBackfillRequestsLoop(backfillRequests chan *database.Backfill) {
  68. for req := range backfillRequests {
  69. user.log.Infofln("Handling backfill request %s", req)
  70. conv := user.bridge.DB.HistorySync.GetConversation(user.MXID, req.Portal)
  71. if conv == nil {
  72. user.log.Debugfln("Could not find history sync conversation data for %s", req.Portal.String())
  73. continue
  74. }
  75. portal := user.GetPortalByJID(conv.PortalKey.JID)
  76. // Update the client store with basic chat settings.
  77. if conv.MuteEndTime.After(time.Now()) {
  78. user.Client.Store.ChatSettings.PutMutedUntil(conv.PortalKey.JID, conv.MuteEndTime)
  79. }
  80. if conv.Archived {
  81. user.Client.Store.ChatSettings.PutArchived(conv.PortalKey.JID, true)
  82. }
  83. if conv.Pinned > 0 {
  84. user.Client.Store.ChatSettings.PutPinned(conv.PortalKey.JID, true)
  85. }
  86. if conv.EphemeralExpiration != nil && portal.ExpirationTime != *conv.EphemeralExpiration {
  87. portal.ExpirationTime = *conv.EphemeralExpiration
  88. portal.Update()
  89. }
  90. user.backfillInChunks(req, conv, portal)
  91. }
  92. }
  93. func (user *User) backfillInChunks(req *database.Backfill, conv *database.HistorySyncConversation, portal *Portal) {
  94. portal.backfillLock.Lock()
  95. defer portal.backfillLock.Unlock()
  96. if !user.shouldCreatePortalForHistorySync(conv, portal) {
  97. return
  98. }
  99. var forwardPrevID id.EventID
  100. if req.BackfillType == database.BackfillForward {
  101. // TODO this overrides the TimeStart set when enqueuing the backfill
  102. // maybe the enqueue should instead include the prev event ID
  103. lastMessage := portal.bridge.DB.Message.GetLastInChat(portal.Key)
  104. forwardPrevID = lastMessage.MXID
  105. start := lastMessage.Timestamp.Add(1 * time.Second)
  106. req.TimeStart = &start
  107. } else {
  108. firstMessage := portal.bridge.DB.Message.GetFirstInChat(portal.Key)
  109. if firstMessage != nil && (req.TimeEnd == nil || firstMessage.Timestamp.Before(*req.TimeEnd)) {
  110. end := firstMessage.Timestamp.Add(-1 * time.Second)
  111. req.TimeEnd = &end
  112. user.log.Debugfln("Limiting backfill to end at %v", end)
  113. }
  114. }
  115. allMsgs := user.bridge.DB.HistorySync.GetMessagesBetween(user.MXID, conv.ConversationID, req.TimeStart, req.TimeEnd, req.MaxTotalEvents)
  116. sendDisappearedNotice := false
  117. // If expired messages are on, and a notice has not been sent to this chat
  118. // about it having disappeared messages at the conversation timestamp, send
  119. // a notice indicating so.
  120. if len(allMsgs) == 0 && conv.EphemeralExpiration != nil && *conv.EphemeralExpiration > 0 {
  121. lastMessage := portal.bridge.DB.Message.GetLastInChat(portal.Key)
  122. if lastMessage == nil || !conv.LastMessageTimestamp.Equal(lastMessage.Timestamp) {
  123. sendDisappearedNotice = true
  124. }
  125. }
  126. if !sendDisappearedNotice && len(allMsgs) == 0 {
  127. user.log.Debugfln("Not backfilling %s: no bridgeable messages found", portal.Key.JID)
  128. return
  129. }
  130. if len(portal.MXID) == 0 {
  131. user.log.Debugln("Creating portal for", portal.Key.JID, "as part of history sync handling")
  132. err := portal.CreateMatrixRoom(user, nil, true, false)
  133. if err != nil {
  134. user.log.Errorfln("Failed to create room for %s during backfill: %v", portal.Key.JID, err)
  135. return
  136. }
  137. }
  138. if sendDisappearedNotice {
  139. user.log.Debugfln("Sending notice to %s that there are disappeared messages ending at %v", portal.Key.JID, conv.LastMessageTimestamp)
  140. resp, err := portal.sendMessage(portal.MainIntent(), event.EventMessage, &event.MessageEventContent{
  141. MsgType: event.MsgNotice,
  142. Body: portal.formatDisappearingMessageNotice(),
  143. }, nil, conv.LastMessageTimestamp.UnixMilli())
  144. if err != nil {
  145. portal.log.Errorln("Error sending disappearing messages notice event")
  146. return
  147. }
  148. msg := portal.bridge.DB.Message.New()
  149. msg.Chat = portal.Key
  150. msg.MXID = resp.EventID
  151. msg.JID = types.MessageID(resp.EventID)
  152. msg.Timestamp = conv.LastMessageTimestamp
  153. msg.Sent = true
  154. msg.Insert()
  155. return
  156. }
  157. user.log.Infofln("Backfilling %d messages in %s, %d messages at a time (queue ID: %d)", len(allMsgs), portal.Key.JID, req.MaxBatchEvents, req.QueueID)
  158. toBackfill := allMsgs[0:]
  159. var insertionEventIds []id.EventID
  160. for len(toBackfill) > 0 {
  161. var msgs []*waProto.WebMessageInfo
  162. if len(toBackfill) <= req.MaxBatchEvents || req.MaxBatchEvents < 0 {
  163. msgs = toBackfill
  164. toBackfill = nil
  165. } else {
  166. msgs = toBackfill[:req.MaxBatchEvents]
  167. toBackfill = toBackfill[req.MaxBatchEvents:]
  168. }
  169. if len(msgs) > 0 {
  170. time.Sleep(time.Duration(req.BatchDelay) * time.Second)
  171. user.log.Debugfln("Backfilling %d messages in %s (queue ID: %d)", len(msgs), portal.Key.JID, req.QueueID)
  172. resp := portal.backfill(user, msgs, req.BackfillType == database.BackfillForward, forwardPrevID)
  173. if resp != nil {
  174. insertionEventIds = append(insertionEventIds, resp.BaseInsertionEventID)
  175. }
  176. }
  177. }
  178. user.log.Debugfln("Finished backfilling %d messages in %s (queue ID: %d)", len(allMsgs), portal.Key.JID, req.QueueID)
  179. if len(insertionEventIds) > 0 {
  180. portal.sendPostBackfillDummy(
  181. time.Unix(int64(allMsgs[0].GetMessageTimestamp()), 0),
  182. insertionEventIds[0])
  183. }
  184. user.log.Debugfln("Deleting %d history sync messages after backfilling (queue ID: %d)", len(allMsgs), req.QueueID)
  185. err := user.bridge.DB.HistorySync.DeleteMessages(user.MXID, conv.ConversationID, allMsgs)
  186. if err != nil {
  187. user.log.Warnfln("Failed to delete %d history sync messages after backfilling (queue ID: %d): %v", len(allMsgs), req.QueueID, err)
  188. }
  189. if !conv.MarkedAsUnread && conv.UnreadCount == 0 {
  190. user.markSelfReadFull(portal)
  191. }
  192. }
  193. func (user *User) shouldCreatePortalForHistorySync(conv *database.HistorySyncConversation, portal *Portal) bool {
  194. if len(portal.MXID) > 0 {
  195. user.log.Debugfln("Portal for %s already exists, ensuring user is invited", portal.Key.JID)
  196. portal.ensureUserInvited(user)
  197. // Portal exists, let backfill continue
  198. return true
  199. } else if !user.bridge.Config.Bridge.HistorySync.CreatePortals {
  200. user.log.Debugfln("Not creating portal for %s: creating rooms from history sync is disabled", portal.Key.JID)
  201. } else {
  202. // Portal doesn't exist, but should be created
  203. return true
  204. }
  205. // Portal shouldn't be created, reason logged above
  206. return false
  207. }
  208. func (user *User) handleHistorySync(reCheckQueue chan bool, evt *waProto.HistorySync) {
  209. if evt == nil || evt.SyncType == nil || evt.GetSyncType() == waProto.HistorySync_INITIAL_STATUS_V3 || evt.GetSyncType() == waProto.HistorySync_PUSH_NAME {
  210. return
  211. }
  212. description := fmt.Sprintf("type %s, %d conversations, chunk order %d, progress: %d", evt.GetSyncType(), len(evt.GetConversations()), evt.GetChunkOrder(), evt.GetProgress())
  213. user.log.Infoln("Storing history sync with", description)
  214. for _, conv := range evt.GetConversations() {
  215. jid, err := types.ParseJID(conv.GetId())
  216. if err != nil {
  217. user.log.Warnfln("Failed to parse chat JID '%s' in history sync: %v", conv.GetId(), err)
  218. continue
  219. } else if jid.Server == types.BroadcastServer {
  220. user.log.Debugfln("Skipping broadcast list %s in history sync", jid)
  221. continue
  222. }
  223. portal := user.GetPortalByJID(jid)
  224. historySyncConversation := user.bridge.DB.HistorySync.NewConversationWithValues(
  225. user.MXID,
  226. conv.GetId(),
  227. &portal.Key,
  228. getConversationTimestamp(conv),
  229. conv.GetMuteEndTime(),
  230. conv.GetArchived(),
  231. conv.GetPinned(),
  232. conv.GetDisappearingMode().GetInitiator(),
  233. conv.GetEndOfHistoryTransferType(),
  234. conv.EphemeralExpiration,
  235. conv.GetMarkedAsUnread(),
  236. conv.GetUnreadCount())
  237. historySyncConversation.Upsert()
  238. for _, rawMsg := range conv.GetMessages() {
  239. // Don't store messages that will just be skipped.
  240. wmi := rawMsg.GetMessage()
  241. msg := wmi.GetMessage()
  242. if msg.GetEphemeralMessage().GetMessage() != nil {
  243. msg = msg.GetEphemeralMessage().GetMessage()
  244. }
  245. if msg.GetViewOnceMessage().GetMessage() != nil {
  246. msg = msg.GetViewOnceMessage().GetMessage()
  247. }
  248. msgType := getMessageType(msg)
  249. if msgType == "unknown" || msgType == "ignore" || msgType == "unknown_protocol" {
  250. continue
  251. }
  252. // Don't store unsupported messages.
  253. if !containsSupportedMessage(msg) {
  254. continue
  255. }
  256. message, err := user.bridge.DB.HistorySync.NewMessageWithValues(user.MXID, conv.GetId(), wmi.GetKey().GetId(), rawMsg)
  257. if err != nil {
  258. user.log.Warnfln("Failed to save message %s in %s. Error: %+v", wmi.GetKey().Id, conv.GetId(), err)
  259. continue
  260. }
  261. message.Insert()
  262. }
  263. }
  264. // If this was the initial bootstrap, enqueue immediate backfills for the
  265. // most recent portals. If it's the last history sync event, start
  266. // backfilling the rest of the history of the portals.
  267. if user.bridge.Config.Bridge.HistorySync.Backfill {
  268. if evt.GetSyncType() != waProto.HistorySync_INITIAL_BOOTSTRAP && evt.GetProgress() < 98 {
  269. return
  270. }
  271. nMostRecent := user.bridge.DB.HistorySync.GetNMostRecentConversations(user.MXID, user.bridge.Config.Bridge.HistorySync.MaxInitialConversations)
  272. if len(nMostRecent) > 0 {
  273. // Find the portals for all of the conversations.
  274. portals := []*Portal{}
  275. for _, conv := range nMostRecent {
  276. jid, err := types.ParseJID(conv.ConversationID)
  277. if err != nil {
  278. user.log.Warnfln("Failed to parse chat JID '%s' in history sync: %v", conv.ConversationID, err)
  279. continue
  280. }
  281. portals = append(portals, user.GetPortalByJID(jid))
  282. }
  283. switch evt.GetSyncType() {
  284. case waProto.HistorySync_INITIAL_BOOTSTRAP:
  285. // Enqueue immediate backfills for the most recent messages first.
  286. user.EnqueueImmedateBackfills(portals)
  287. case waProto.HistorySync_FULL, waProto.HistorySync_RECENT:
  288. user.EnqueueForwardBackfills(portals)
  289. // Enqueue deferred backfills as configured.
  290. user.EnqueueDeferredBackfills(portals)
  291. }
  292. // Tell the queue to check for new backfill requests.
  293. reCheckQueue <- true
  294. }
  295. }
  296. }
  297. func getConversationTimestamp(conv *waProto.Conversation) uint64 {
  298. convTs := conv.GetConversationTimestamp()
  299. if convTs == 0 && len(conv.GetMessages()) > 0 {
  300. convTs = conv.Messages[0].GetMessage().GetMessageTimestamp()
  301. }
  302. return convTs
  303. }
  304. func (user *User) EnqueueImmedateBackfills(portals []*Portal) {
  305. for priority, portal := range portals {
  306. maxMessages := user.bridge.Config.Bridge.HistorySync.Immediate.MaxEvents
  307. initialBackfill := user.bridge.DB.Backfill.NewWithValues(user.MXID, database.BackfillImmediate, priority, &portal.Key, nil, nil, maxMessages, maxMessages, 0)
  308. initialBackfill.Insert()
  309. }
  310. }
  311. func (user *User) EnqueueDeferredBackfills(portals []*Portal) {
  312. numPortals := len(portals)
  313. for stageIdx, backfillStage := range user.bridge.Config.Bridge.HistorySync.Deferred {
  314. for portalIdx, portal := range portals {
  315. var startDate *time.Time = nil
  316. if backfillStage.StartDaysAgo > 0 {
  317. startDaysAgo := time.Now().AddDate(0, 0, -backfillStage.StartDaysAgo)
  318. startDate = &startDaysAgo
  319. }
  320. backfillMessages := user.bridge.DB.Backfill.NewWithValues(
  321. user.MXID, database.BackfillDeferred, stageIdx*numPortals+portalIdx, &portal.Key, startDate, nil, backfillStage.MaxBatchEvents, -1, backfillStage.BatchDelay)
  322. backfillMessages.Insert()
  323. }
  324. }
  325. }
  326. func (user *User) EnqueueForwardBackfills(portals []*Portal) {
  327. for priority, portal := range portals {
  328. lastMsg := user.bridge.DB.Message.GetLastInChat(portal.Key)
  329. if lastMsg == nil {
  330. continue
  331. }
  332. backfill := user.bridge.DB.Backfill.NewWithValues(
  333. user.MXID, database.BackfillForward, priority, &portal.Key, &lastMsg.Timestamp, nil, -1, -1, 0)
  334. backfill.Insert()
  335. }
  336. }
  337. // endregion
  338. // region Portal backfilling
  339. var (
  340. PortalCreationDummyEvent = event.Type{Type: "fi.mau.dummy.portal_created", Class: event.MessageEventType}
  341. PreBackfillDummyEvent = event.Type{Type: "fi.mau.dummy.pre_backfill", Class: event.MessageEventType}
  342. BackfillEndDummyEvent = event.Type{Type: "fi.mau.dummy.backfill_end", Class: event.MessageEventType}
  343. HistorySyncMarker = event.Type{Type: "org.matrix.msc2716.marker", Class: event.MessageEventType}
  344. )
  345. func (portal *Portal) backfill(source *User, messages []*waProto.WebMessageInfo, isForward bool, prevEventID id.EventID) *mautrix.RespBatchSend {
  346. var req mautrix.ReqBatchSend
  347. var infos []*wrappedInfo
  348. if !isForward {
  349. if portal.FirstEventID != "" || portal.NextBatchID != "" {
  350. req.PrevEventID = portal.FirstEventID
  351. req.BatchID = portal.NextBatchID
  352. } else {
  353. portal.log.Warnfln("Can't backfill %d messages through %s to chat: first event ID not known", len(messages), source.MXID)
  354. return nil
  355. }
  356. } else {
  357. req.PrevEventID = prevEventID
  358. }
  359. beforeFirstMessageTimestampMillis := (int64(messages[len(messages)-1].GetMessageTimestamp()) * 1000) - 1
  360. req.StateEventsAtStart = make([]*event.Event, 0)
  361. addedMembers := make(map[id.UserID]struct{})
  362. addMember := func(puppet *Puppet) {
  363. if _, alreadyAdded := addedMembers[puppet.MXID]; alreadyAdded {
  364. return
  365. }
  366. mxid := puppet.MXID.String()
  367. content := event.MemberEventContent{
  368. Membership: event.MembershipJoin,
  369. Displayname: puppet.Displayname,
  370. AvatarURL: puppet.AvatarURL.CUString(),
  371. }
  372. inviteContent := content
  373. inviteContent.Membership = event.MembershipInvite
  374. req.StateEventsAtStart = append(req.StateEventsAtStart, &event.Event{
  375. Type: event.StateMember,
  376. Sender: portal.MainIntent().UserID,
  377. StateKey: &mxid,
  378. Timestamp: beforeFirstMessageTimestampMillis,
  379. Content: event.Content{Parsed: &inviteContent},
  380. }, &event.Event{
  381. Type: event.StateMember,
  382. Sender: puppet.MXID,
  383. StateKey: &mxid,
  384. Timestamp: beforeFirstMessageTimestampMillis,
  385. Content: event.Content{Parsed: &content},
  386. })
  387. addedMembers[puppet.MXID] = struct{}{}
  388. }
  389. portal.log.Infofln("Processing history sync with %d messages (forward: %t)", len(messages), isForward)
  390. // The messages are ordered newest to oldest, so iterate them in reverse order.
  391. for i := len(messages) - 1; i >= 0; i-- {
  392. webMsg := messages[i]
  393. msg := webMsg.GetMessage()
  394. if msg.GetEphemeralMessage().GetMessage() != nil {
  395. msg = msg.GetEphemeralMessage().GetMessage()
  396. }
  397. if msg.GetViewOnceMessage().GetMessage() != nil {
  398. msg = msg.GetViewOnceMessage().GetMessage()
  399. }
  400. msgType := getMessageType(msg)
  401. if msgType == "unknown" || msgType == "ignore" || msgType == "unknown_protocol" {
  402. if msgType != "ignore" {
  403. portal.log.Debugfln("Skipping message %s with unknown type in backfill", webMsg.GetKey().GetId())
  404. }
  405. continue
  406. }
  407. info := portal.parseWebMessageInfo(source, webMsg)
  408. if info == nil {
  409. continue
  410. }
  411. if webMsg.GetPushName() != "" && webMsg.GetPushName() != "-" {
  412. existingContact, _ := source.Client.Store.Contacts.GetContact(info.Sender)
  413. if !existingContact.Found || existingContact.PushName == "" {
  414. changed, _, err := source.Client.Store.Contacts.PutPushName(info.Sender, webMsg.GetPushName())
  415. if err != nil {
  416. source.log.Errorfln("Failed to save push name of %s from historical message in device store: %v", info.Sender, err)
  417. } else if changed {
  418. source.log.Debugfln("Got push name %s for %s from historical message", webMsg.GetPushName(), info.Sender)
  419. }
  420. }
  421. }
  422. puppet := portal.getMessagePuppet(source, info)
  423. intent := puppet.IntentFor(portal)
  424. if intent.IsCustomPuppet && !portal.bridge.Config.CanDoublePuppetBackfill(puppet.CustomMXID) {
  425. intent = puppet.DefaultIntent()
  426. }
  427. converted := portal.convertMessage(intent, source, info, msg, true)
  428. if converted == nil {
  429. portal.log.Debugfln("Skipping unsupported message %s in backfill", info.ID)
  430. continue
  431. }
  432. if !intent.IsCustomPuppet && !portal.bridge.StateStore.IsInRoom(portal.MXID, puppet.MXID) {
  433. addMember(puppet)
  434. }
  435. // TODO this won't work for history
  436. if len(converted.ReplyTo) > 0 {
  437. portal.SetReply(converted.Content, converted.ReplyTo)
  438. }
  439. err := portal.appendBatchEvents(converted, info, webMsg.GetEphemeralStartTimestamp(), &req.Events, &infos)
  440. if err != nil {
  441. portal.log.Errorfln("Error handling message %s during backfill: %v", info.ID, err)
  442. }
  443. }
  444. portal.log.Infofln("Made %d Matrix events from messages in batch", len(req.Events))
  445. if len(req.Events) == 0 {
  446. return nil
  447. }
  448. if len(req.BatchID) == 0 || isForward {
  449. portal.log.Debugln("Sending a dummy event to avoid forward extremity errors with backfill")
  450. _, err := portal.MainIntent().SendMessageEvent(portal.MXID, PreBackfillDummyEvent, struct{}{})
  451. if err != nil {
  452. portal.log.Warnln("Error sending pre-backfill dummy event:", err)
  453. }
  454. }
  455. resp, err := portal.MainIntent().BatchSend(portal.MXID, &req)
  456. if err != nil {
  457. portal.log.Errorln("Error batch sending messages:", err)
  458. return nil
  459. } else {
  460. portal.finishBatch(resp.EventIDs, infos)
  461. portal.NextBatchID = resp.NextBatchID
  462. portal.Update()
  463. if portal.bridge.Config.Bridge.HistorySync.MediaRequests.AutoRequestMedia {
  464. go portal.requestMediaRetries(source, resp.EventIDs, infos)
  465. }
  466. return resp
  467. }
  468. }
  469. func (portal *Portal) requestMediaRetries(source *User, eventIDs []id.EventID, infos []*wrappedInfo) {
  470. for i, info := range infos {
  471. if info != nil && info.Error == database.MsgErrMediaNotFound && info.MediaKey != nil {
  472. switch portal.bridge.Config.Bridge.HistorySync.MediaRequests.RequestMethod {
  473. case config.MediaRequestMethodImmediate:
  474. err := source.Client.SendMediaRetryReceipt(info.MessageInfo, info.MediaKey)
  475. if err != nil {
  476. portal.log.Warnfln("Failed to send post-backfill media retry request for %s: %v", info.ID, err)
  477. } else {
  478. portal.log.Debugfln("Sent post-backfill media retry request for %s", info.ID)
  479. }
  480. case config.MediaRequestMethodLocalTime:
  481. req := portal.bridge.DB.MediaBackfillRequest.NewMediaBackfillRequestWithValues(source.MXID, &portal.Key, eventIDs[i])
  482. req.Upsert()
  483. }
  484. }
  485. }
  486. }
  487. func (portal *Portal) parseWebMessageInfo(source *User, webMsg *waProto.WebMessageInfo) *types.MessageInfo {
  488. info := types.MessageInfo{
  489. MessageSource: types.MessageSource{
  490. Chat: portal.Key.JID,
  491. IsFromMe: webMsg.GetKey().GetFromMe(),
  492. IsGroup: portal.Key.JID.Server == types.GroupServer,
  493. },
  494. ID: webMsg.GetKey().GetId(),
  495. PushName: webMsg.GetPushName(),
  496. Timestamp: time.Unix(int64(webMsg.GetMessageTimestamp()), 0),
  497. }
  498. var err error
  499. if info.IsFromMe {
  500. info.Sender = source.JID.ToNonAD()
  501. } else if portal.IsPrivateChat() {
  502. info.Sender = portal.Key.JID
  503. } else if webMsg.GetParticipant() != "" {
  504. info.Sender, err = types.ParseJID(webMsg.GetParticipant())
  505. } else if webMsg.GetKey().GetParticipant() != "" {
  506. info.Sender, err = types.ParseJID(webMsg.GetKey().GetParticipant())
  507. }
  508. if info.Sender.IsEmpty() {
  509. portal.log.Warnfln("Failed to get sender of message %s (parse error: %v)", info.ID, err)
  510. return nil
  511. }
  512. return &info
  513. }
  514. func (portal *Portal) appendBatchEvents(converted *ConvertedMessage, info *types.MessageInfo, expirationStart uint64, eventsArray *[]*event.Event, infoArray *[]*wrappedInfo) error {
  515. mainEvt, err := portal.wrapBatchEvent(info, converted.Intent, converted.Type, converted.Content, converted.Extra)
  516. if err != nil {
  517. return err
  518. }
  519. if converted.Caption != nil {
  520. captionEvt, err := portal.wrapBatchEvent(info, converted.Intent, converted.Type, converted.Caption, nil)
  521. if err != nil {
  522. return err
  523. }
  524. *eventsArray = append(*eventsArray, mainEvt, captionEvt)
  525. *infoArray = append(*infoArray, &wrappedInfo{info, database.MsgNormal, converted.Error, converted.MediaKey, expirationStart, converted.ExpiresIn}, nil)
  526. } else {
  527. *eventsArray = append(*eventsArray, mainEvt)
  528. *infoArray = append(*infoArray, &wrappedInfo{info, database.MsgNormal, converted.Error, converted.MediaKey, expirationStart, converted.ExpiresIn})
  529. }
  530. if converted.MultiEvent != nil {
  531. for _, subEvtContent := range converted.MultiEvent {
  532. subEvt, err := portal.wrapBatchEvent(info, converted.Intent, converted.Type, subEvtContent, nil)
  533. if err != nil {
  534. return err
  535. }
  536. *eventsArray = append(*eventsArray, subEvt)
  537. *infoArray = append(*infoArray, nil)
  538. }
  539. }
  540. return nil
  541. }
  542. const backfillIDField = "fi.mau.whatsapp.backfill_msg_id"
  543. func (portal *Portal) wrapBatchEvent(info *types.MessageInfo, intent *appservice.IntentAPI, eventType event.Type, content *event.MessageEventContent, extraContent map[string]interface{}) (*event.Event, error) {
  544. if extraContent == nil {
  545. extraContent = map[string]interface{}{}
  546. }
  547. extraContent[backfillIDField] = info.ID
  548. if intent.IsCustomPuppet {
  549. extraContent[doublePuppetKey] = doublePuppetValue
  550. }
  551. wrappedContent := event.Content{
  552. Parsed: content,
  553. Raw: extraContent,
  554. }
  555. newEventType, err := portal.encrypt(&wrappedContent, eventType)
  556. if err != nil {
  557. return nil, err
  558. }
  559. if newEventType == event.EventEncrypted {
  560. // Clear other custom keys if the event was encrypted, but keep the double puppet identifier
  561. wrappedContent.Raw = map[string]interface{}{backfillIDField: info.ID}
  562. if intent.IsCustomPuppet {
  563. wrappedContent.Raw[doublePuppetKey] = doublePuppetValue
  564. }
  565. }
  566. return &event.Event{
  567. Sender: intent.UserID,
  568. Type: newEventType,
  569. Timestamp: info.Timestamp.UnixMilli(),
  570. Content: wrappedContent,
  571. }, nil
  572. }
  573. func (portal *Portal) finishBatch(eventIDs []id.EventID, infos []*wrappedInfo) {
  574. if len(eventIDs) != len(infos) {
  575. portal.log.Errorfln("Length of event IDs (%d) and message infos (%d) doesn't match! Using slow path for mapping event IDs", len(eventIDs), len(infos))
  576. infoMap := make(map[types.MessageID]*wrappedInfo, len(infos))
  577. for _, info := range infos {
  578. infoMap[info.ID] = info
  579. }
  580. for _, eventID := range eventIDs {
  581. if evt, err := portal.MainIntent().GetEvent(portal.MXID, eventID); err != nil {
  582. portal.log.Warnfln("Failed to get event %s to register it in the database: %v", eventID, err)
  583. } else if msgID, ok := evt.Content.Raw[backfillIDField].(string); !ok {
  584. portal.log.Warnfln("Event %s doesn't include the WhatsApp message ID", eventID)
  585. } else if info, ok := infoMap[types.MessageID(msgID)]; !ok {
  586. portal.log.Warnfln("Didn't find info of message %s (event %s) to register it in the database", msgID, eventID)
  587. } else {
  588. portal.finishBatchEvt(info, eventID)
  589. }
  590. }
  591. } else {
  592. for i := 0; i < len(infos); i++ {
  593. portal.finishBatchEvt(infos[i], eventIDs[i])
  594. }
  595. portal.log.Infofln("Successfully sent %d events", len(eventIDs))
  596. }
  597. }
  598. func (portal *Portal) finishBatchEvt(info *wrappedInfo, eventID id.EventID) {
  599. if info == nil {
  600. return
  601. }
  602. portal.markHandled(nil, info.MessageInfo, eventID, true, false, info.Type, info.Error)
  603. if info.ExpiresIn > 0 {
  604. if info.ExpirationStart > 0 {
  605. remainingSeconds := time.Unix(int64(info.ExpirationStart), 0).Add(time.Duration(info.ExpiresIn) * time.Second).Sub(time.Now()).Seconds()
  606. portal.log.Debugfln("Disappearing history sync message: expires in %d, started at %d, remaining %d", info.ExpiresIn, info.ExpirationStart, int(remainingSeconds))
  607. portal.MarkDisappearing(eventID, uint32(remainingSeconds), true)
  608. } else {
  609. portal.log.Debugfln("Disappearing history sync message: expires in %d (not started)", info.ExpiresIn)
  610. portal.MarkDisappearing(eventID, info.ExpiresIn, false)
  611. }
  612. }
  613. }
  614. func (portal *Portal) sendPostBackfillDummy(lastTimestamp time.Time, insertionEventId id.EventID) {
  615. // TODO remove after clients stop using this
  616. _, _ = portal.MainIntent().SendMessageEvent(portal.MXID, BackfillEndDummyEvent, struct{}{})
  617. resp, err := portal.MainIntent().SendMessageEvent(portal.MXID, HistorySyncMarker, map[string]interface{}{
  618. "org.matrix.msc2716.marker.insertion": insertionEventId,
  619. //"m.marker.insertion": insertionEventId,
  620. })
  621. if err != nil {
  622. portal.log.Errorln("Error sending post-backfill dummy event:", err)
  623. return
  624. }
  625. msg := portal.bridge.DB.Message.New()
  626. msg.Chat = portal.Key
  627. msg.MXID = resp.EventID
  628. msg.JID = types.MessageID(resp.EventID)
  629. msg.Timestamp = lastTimestamp.Add(1 * time.Second)
  630. msg.Sent = true
  631. msg.Insert()
  632. }
  633. // endregion