github.com/kaleido-io/firefly@v0.0.0-20210622132723-8b4b6aacb971/internal/events/event_dispatcher.go (about) 1 // Copyright © 2021 Kaleido, Inc. 2 // 3 // SPDX-License-Identifier: Apache-2.0 4 // 5 // Licensed under the Apache License, Version 2.0 (the "License"); 6 // you may not use this file except in compliance with the License. 7 // You may obtain a copy of the License at 8 // 9 // http://www.apache.org/licenses/LICENSE-2.0 10 // 11 // Unless required by applicable law or agreed to in writing, software 12 // distributed under the License is distributed on an "AS IS" BASIS, 13 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 14 // See the License for the specific language governing permissions and 15 // limitations under the License. 16 17 package events 18 19 import ( 20 "context" 21 "database/sql/driver" 22 "fmt" 23 "sync" 24 25 "github.com/kaleido-io/firefly/internal/config" 26 "github.com/kaleido-io/firefly/internal/i18n" 27 "github.com/kaleido-io/firefly/internal/log" 28 "github.com/kaleido-io/firefly/internal/retry" 29 "github.com/kaleido-io/firefly/pkg/database" 30 "github.com/kaleido-io/firefly/pkg/events" 31 "github.com/kaleido-io/firefly/pkg/fftypes" 32 ) 33 34 type ackNack struct { 35 id fftypes.UUID 36 isNack bool 37 offset int64 38 } 39 40 type eventDispatcher struct { 41 acksNacks chan ackNack 42 cancelCtx func() 43 closed chan struct{} 44 connID string 45 ctx context.Context 46 database database.Plugin 47 transport events.Plugin 48 elected bool 49 eventPoller *eventPoller 50 inflight map[fftypes.UUID]*fftypes.Event 51 eventDelivery chan *fftypes.EventDelivery 52 mux sync.Mutex 53 namespace string 54 readAhead int 55 subscription *subscription 56 } 57 58 func newEventDispatcher(ctx context.Context, ei events.Plugin, di database.Plugin, connID string, sub *subscription, en *eventNotifier) *eventDispatcher { 59 ctx, cancelCtx := context.WithCancel(ctx) 60 readAhead := int(config.GetUint(config.SubscriptionDefaultsReadAhead)) 61 ed := &eventDispatcher{ 62 ctx: log.WithLogField(log.WithLogField(ctx, 63 "role", fmt.Sprintf("ed[%s]", connID)), 64 "sub", fmt.Sprintf("%s/%s:%s", sub.definition.ID, sub.definition.Namespace, sub.definition.Name)), 65 database: di, 66 transport: ei, 67 connID: connID, 68 cancelCtx: cancelCtx, 69 subscription: sub, 70 namespace: sub.definition.Namespace, 71 inflight: make(map[fftypes.UUID]*fftypes.Event), 72 eventDelivery: make(chan *fftypes.EventDelivery, readAhead+1), 73 readAhead: readAhead, 74 acksNacks: make(chan ackNack), 75 closed: make(chan struct{}), 76 } 77 78 pollerConf := &eventPollerConf{ 79 eventBatchSize: config.GetInt(config.EventDispatcherBufferLength), 80 eventBatchTimeout: config.GetDuration(config.EventDispatcherBatchTimeout), 81 eventPollTimeout: config.GetDuration(config.EventDispatcherPollTimeout), 82 startupOffsetRetryAttempts: 0, // We need to keep trying to start indefinitely 83 retry: retry.Retry{ 84 InitialDelay: config.GetDuration(config.EventDispatcherRetryInitDelay), 85 MaximumDelay: config.GetDuration(config.EventDispatcherRetryMaxDelay), 86 Factor: config.GetFloat64(config.EventDispatcherRetryFactor), 87 }, 88 offsetType: fftypes.OffsetTypeSubscription, 89 offsetNamespace: sub.definition.Namespace, 90 offsetName: sub.definition.Name, 91 addCriteria: func(af database.AndFilter) database.AndFilter { 92 return af.Condition(af.Builder().Eq("namespace", sub.definition.Namespace)) 93 }, 94 queryFactory: database.EventQueryFactory, 95 getItems: ed.getEvents, 96 newEventsHandler: ed.bufferedDelivery, 97 ephemeral: sub.definition.Ephemeral, 98 firstEvent: sub.definition.Options.FirstEvent, 99 } 100 if sub.definition.Options.ReadAhead != nil { 101 ed.readAhead = int(*sub.definition.Options.ReadAhead) 102 } 103 104 ed.eventPoller = newEventPoller(ctx, di, en, pollerConf) 105 return ed 106 } 107 108 func (ed *eventDispatcher) start() { 109 go ed.electAndStart() 110 } 111 112 func (ed *eventDispatcher) electAndStart() { 113 defer close(ed.closed) 114 l := log.L(ed.ctx) 115 l.Debugf("Dispatcher attempting to become leader") 116 select { 117 case ed.subscription.dispatcherElection <- true: 118 l.Debugf("Dispatcher became leader") 119 case <-ed.ctx.Done(): 120 l.Debugf("Closed before we became leader") 121 return 122 } 123 // We're ready to go - not 124 ed.elected = true 125 go ed.deliverEvents() 126 go func() { 127 err := ed.eventPoller.start() 128 l.Debugf("Event dispatcher completed: %v", err) 129 }() 130 // Wait until we close 131 <-ed.eventPoller.closed 132 // Unelect ourselves on close, to let another dispatcher in 133 <-ed.subscription.dispatcherElection 134 } 135 136 func (ed *eventDispatcher) getEvents(ctx context.Context, filter database.Filter) ([]fftypes.LocallySequenced, error) { 137 events, err := ed.database.GetEvents(ctx, filter) 138 ls := make([]fftypes.LocallySequenced, len(events)) 139 for i, e := range events { 140 ls[i] = e 141 } 142 return ls, err 143 } 144 145 func (ed *eventDispatcher) enrichEvents(events []fftypes.LocallySequenced) ([]*fftypes.EventDelivery, error) { 146 // We need all the messages that match event references 147 refIDs := make([]driver.Value, len(events)) 148 for i, ls := range events { 149 e := ls.(*fftypes.Event) 150 if e.Reference != nil { 151 refIDs[i] = *e.Reference 152 } 153 } 154 155 mfb := database.MessageQueryFactory.NewFilter(ed.ctx) 156 msgFilter := mfb.And( 157 mfb.In("id", refIDs), 158 mfb.Eq("namespace", ed.namespace), 159 ) 160 msgs, err := ed.database.GetMessages(ed.ctx, msgFilter) 161 if err != nil { 162 return nil, err 163 } 164 165 dfb := database.DataQueryFactory.NewFilter(ed.ctx) 166 dataFilter := dfb.And( 167 dfb.In("id", refIDs), 168 dfb.Eq("namespace", ed.namespace), 169 ) 170 dataRefs, err := ed.database.GetDataRefs(ed.ctx, dataFilter) 171 if err != nil { 172 return nil, err 173 } 174 175 enriched := make([]*fftypes.EventDelivery, len(events)) 176 for i, ls := range events { 177 e := ls.(*fftypes.Event) 178 enriched[i] = &fftypes.EventDelivery{ 179 Event: *e, 180 Subscription: ed.subscription.definition.SubscriptionRef, 181 } 182 for _, msg := range msgs { 183 if *e.Reference == *msg.Header.ID { 184 enriched[i].Message = msg 185 break 186 } 187 } 188 for _, dr := range dataRefs { 189 if *e.Reference == *dr.ID { 190 enriched[i].Data = dr 191 break 192 } 193 } 194 } 195 196 return enriched, nil 197 198 } 199 200 func (ed *eventDispatcher) filterEvents(candidates []*fftypes.EventDelivery) []*fftypes.EventDelivery { 201 matchingEvents := make([]*fftypes.EventDelivery, 0, len(candidates)) 202 for _, event := range candidates { 203 filter := ed.subscription 204 if filter.eventMatcher != nil && !filter.eventMatcher.MatchString(string(event.Type)) { 205 continue 206 } 207 msg := event.Message 208 tag := "" 209 group := "" 210 var topics []string 211 if msg != nil { 212 tag = msg.Header.Tag 213 topics = msg.Header.Topics 214 if msg.Header.Group != nil { 215 group = msg.Header.Group.String() 216 } 217 } 218 if filter.tagFilter != nil && !filter.tagFilter.MatchString(tag) { 219 continue 220 } 221 if filter.topicsFilter != nil { 222 topicsMatch := false 223 for _, topic := range topics { 224 if filter.topicsFilter.MatchString(topic) { 225 topicsMatch = true 226 break 227 } 228 } 229 if !topicsMatch { 230 continue 231 } 232 } 233 if filter.groupFilter != nil && !filter.groupFilter.MatchString(group) { 234 continue 235 } 236 matchingEvents = append(matchingEvents, event) 237 } 238 return matchingEvents 239 } 240 241 func (ed *eventDispatcher) bufferedDelivery(events []fftypes.LocallySequenced) (bool, error) { 242 // At this point, the page of messages we've been given are loaded from the DB into memory, 243 // but we can only make them in-flight and push them to the client up to the maximum 244 // readahead (which is likely lower than our page size - 1 by default) 245 246 if len(events) == 0 { 247 return false, nil 248 } 249 highestOffset := events[len(events)-1].LocalSequence() 250 var lastAck int64 251 var nacks int 252 253 l := log.L(ed.ctx) 254 candidates, err := ed.enrichEvents(events) 255 if err != nil { 256 return false, err 257 } 258 259 matching := ed.filterEvents(candidates) 260 matchCount := len(matching) 261 dispatched := 0 262 263 // We stay here blocked until we've consumed all the messages in the buffer, 264 // or a reset event happens 265 for { 266 ed.mux.Lock() 267 var disapatchable []*fftypes.EventDelivery 268 inflightCount := len(ed.inflight) 269 maxDispatch := 1 + ed.readAhead - inflightCount 270 if maxDispatch >= len(matching) { 271 disapatchable = matching 272 matching = nil 273 } else if maxDispatch > 0 { 274 disapatchable = matching[0:maxDispatch] 275 matching = matching[maxDispatch:] 276 } 277 ed.mux.Unlock() 278 279 l.Debugf("Dispatcher event state: candidates=%d matched=%d inflight=%d queued=%d dispatched=%d dispatchable=%d lastAck=%d nacks=%d highest=%d", 280 len(candidates), matchCount, inflightCount, len(matching), dispatched, len(disapatchable), lastAck, nacks, highestOffset) 281 282 for _, event := range disapatchable { 283 ed.mux.Lock() 284 ed.inflight[*event.ID] = &event.Event 285 inflightCount = len(ed.inflight) 286 ed.mux.Unlock() 287 288 dispatched++ 289 ed.eventDelivery <- event 290 } 291 292 if inflightCount == 0 { 293 // We've cleared the decks. Time to look for more messages 294 break 295 } 296 297 // Block until we're closed, or woken due to a delivery response 298 select { 299 case <-ed.ctx.Done(): 300 return false, i18n.NewError(ed.ctx, i18n.MsgDispatcherClosing) 301 case an := <-ed.acksNacks: 302 if an.isNack { 303 nacks++ 304 ed.handleNackOffsetUpdate(an) 305 } else if nacks == 0 { 306 err := ed.handleAckOffsetUpdate(an) 307 if err != nil { 308 return false, err 309 } 310 lastAck = an.offset 311 } 312 } 313 } 314 if nacks == 0 && lastAck != highestOffset { 315 err := ed.eventPoller.commitOffset(ed.ctx, highestOffset) 316 if err != nil { 317 return false, err 318 } 319 } 320 return true, nil // poll again straight away for more messages 321 } 322 323 func (ed *eventDispatcher) handleNackOffsetUpdate(nack ackNack) { 324 ed.mux.Lock() 325 defer ed.mux.Unlock() 326 // If we're rejected, we need to redeliver all messages from this offset onwards, 327 // even if we've delivered messages after that. 328 // That means resetting the polling offest, and clearing out all our state 329 delete(ed.inflight, nack.id) 330 if ed.eventPoller.pollingOffset > nack.offset { 331 ed.eventPoller.rewindPollingOffset(nack.offset) 332 } 333 ed.inflight = map[fftypes.UUID]*fftypes.Event{} 334 } 335 336 func (ed *eventDispatcher) handleAckOffsetUpdate(ack ackNack) error { 337 oldOffset := ed.eventPoller.getPollingOffset() 338 ed.mux.Lock() 339 delete(ed.inflight, ack.id) 340 lowestInflight := int64(-1) 341 for _, inflight := range ed.inflight { 342 if lowestInflight < 0 || inflight.Sequence < lowestInflight { 343 lowestInflight = inflight.Sequence 344 } 345 } 346 ed.mux.Unlock() 347 if (lowestInflight == -1 || lowestInflight > ack.offset) && ack.offset > oldOffset { 348 // This was the lowest in flight, and we can move the offset forwards 349 return ed.eventPoller.commitOffset(ed.ctx, ack.offset) 350 } 351 return nil 352 } 353 354 func (ed *eventDispatcher) deliverEvents() { 355 for event := range ed.eventDelivery { 356 log.L(ed.ctx).Debugf("Dispatching event: %.10d/%s [%s]: ref=%s/%s", event.Sequence, event.ID, event.Type, event.Namespace, event.Reference) 357 err := ed.transport.DeliveryRequest(ed.connID, event) 358 if err != nil { 359 ed.deliveryResponse(&fftypes.EventDeliveryResponse{ID: event.ID, Rejected: true}) 360 } 361 } 362 } 363 364 func (ed *eventDispatcher) deliveryResponse(response *fftypes.EventDeliveryResponse) { 365 l := log.L(ed.ctx) 366 367 ed.mux.Lock() 368 var an ackNack 369 event, found := ed.inflight[*response.ID] 370 if found { 371 an.id = *response.ID 372 an.offset = event.Sequence 373 an.isNack = response.Rejected 374 } 375 ed.mux.Unlock() 376 377 // Do some extra logging and persistent actions now we're out of lock 378 if !found { 379 l.Warnf("Response for event not in flight: %s rejected=%t info='%s' (likely previous reject)", response.ID, response.Rejected, response.Info) 380 return 381 } 382 383 l.Debugf("Response for event: %.10d/%s [%s]: ref=%s/%s rejected=%t info='%s'", event.Sequence, event.ID, event.Type, event.Namespace, event.Reference, response.Rejected, response.Info) 384 // We don't do any meaningful work in this call, we just set things up so the right thing 385 // will happen when the poller wakes up. So we need to pass it over 386 select { 387 case ed.acksNacks <- an: 388 case <-ed.ctx.Done(): 389 l.Debugf("Delivery response will not be delivered: closing") 390 return 391 } 392 } 393 394 func (ed *eventDispatcher) close() { 395 log.L(ed.ctx).Infof("Dispatcher closing for conn=%s subscription=%s", ed.connID, ed.subscription.definition.ID) 396 ed.cancelCtx() 397 <-ed.closed 398 if ed.elected { 399 <-ed.eventPoller.closed 400 close(ed.eventDelivery) 401 ed.elected = false 402 } 403 }