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  }