feat: add quotas (#4779)

adds possibilities to cap authenticated requests and execution seconds of actions on a defined intervall

internal/actions/actions.go

@@ -6,6 +6,8 @@ import (
 	"fmt"
 
 	"github.com/dop251/goja_nodejs/require"
+	"github.com/sirupsen/logrus"
+
 	z_errs "github.com/zitadel/zitadel/internal/errors"
 	"github.com/zitadel/zitadel/internal/query"
 )
@@ -14,15 +16,45 @@ type Config struct {
 	HTTP HTTPConfig
 }
 
-var (
-	ErrHalt = errors.New("interrupt")
-)
+var ErrHalt = errors.New("interrupt")
 
 type jsAction func(fields, fields) error
 
-func Run(ctx context.Context, ctxParam contextFields, apiParam apiFields, script, name string, opts ...Option) error {
-	config, err := prepareRun(ctx, ctxParam, apiParam, script, opts)
-	if err != nil {
+const (
+	actionStartedMessage   = "action run started"
+	actionSucceededMessage = "action run succeeded"
+)
+
+func actionFailedMessage(err error) string {
+	return fmt.Sprintf("action run failed: %s", err.Error())
+}
+
+func Run(ctx context.Context, ctxParam contextFields, apiParam apiFields, script, name string, opts ...Option) (err error) {
+	config := newRunConfig(ctx, append(opts, withLogger(ctx))...)
+	if config.functionTimeout == 0 {
+		return z_errs.ThrowInternal(nil, "ACTIO-uCpCx", "Errrors.Internal")
+	}
+
+	remaining := logstoreService.Limit(ctx, config.instanceID)
+	config.cutTimeouts(remaining)
+
+	config.logger.Log(actionStartedMessage)
+	if remaining != nil && *remaining == 0 {
+		return z_errs.ThrowResourceExhausted(nil, "ACTIO-f19Ii", "Errors.Quota.Execution.Exhausted")
+	}
+
+	defer func() {
+		if err != nil {
+			config.logger.log(actionFailedMessage(err), logrus.ErrorLevel, true)
+		} else {
+			config.logger.log(actionSucceededMessage, logrus.InfoLevel, true)
+		}
+		if config.allowedToFail {
+			err = nil
+		}
+	}()
+
+	if err := executeScript(config, ctxParam, apiParam, script); err != nil {
 		return err
 	}
 
@@ -31,12 +63,11 @@ func Run(ctx context.Context, ctxParam contextFields, apiParam apiFields, script
 	if jsFn == nil {
 		return errors.New("function not found")
 	}
-	err = config.vm.ExportTo(jsFn, &fn)
-	if err != nil {
+	if err := config.vm.ExportTo(jsFn, &fn); err != nil {
 		return err
 	}
 
-	t := config.Start()
+	t := config.StartFunction()
 	defer func() {
 		t.Stop()
 	}()
@@ -44,12 +75,8 @@ func Run(ctx context.Context, ctxParam contextFields, apiParam apiFields, script
 	return executeFn(config, fn)
 }
 
-func prepareRun(ctx context.Context, ctxParam contextFields, apiParam apiFields, script string, opts []Option) (config *runConfig, err error) {
-	config = newRunConfig(ctx, opts...)
-	if config.timeout == 0 {
-		return nil, z_errs.ThrowInternal(nil, "ACTIO-uCpCx", "Errrors.Internal")
-	}
-	t := config.Prepare()
+func executeScript(config *runConfig, ctxParam contextFields, apiParam apiFields, script string) (err error) {
+	t := config.StartScript()
 	defer func() {
 		t.Stop()
 	}()
@@ -67,7 +94,6 @@ func prepareRun(ctx context.Context, ctxParam contextFields, apiParam apiFields,
 	for name, loader := range config.modules {
 		registry.RegisterNativeModule(name, loader)
 	}
-
 	// overload error if function panics
 	defer func() {
 		r := recover()
@@ -76,29 +102,31 @@ func prepareRun(ctx context.Context, ctxParam contextFields, apiParam apiFields,
 			return
 		}
 	}()
+
 	_, err = config.vm.RunString(script)
-	return config, err
+	return err
 }
 
 func executeFn(config *runConfig, fn jsAction) (err error) {
 	defer func() {
 		r := recover()
-		if r != nil && !config.allowedToFail {
-			var ok bool
-			if err, ok = r.(error); ok {
-				return
-			}
-
-			e, ok := r.(string)
-			if ok {
-				err = errors.New(e)
-				return
-			}
-			err = fmt.Errorf("unknown error occured: %v", r)
+		if r == nil {
+			return
 		}
+		var ok bool
+		if err, ok = r.(error); ok {
+			return
+		}
+
+		e, ok := r.(string)
+		if ok {
+			err = errors.New(e)
+			return
+		}
+		err = fmt.Errorf("unknown error occurred: %v", r)
 	}()
-	err = fn(config.ctxParam.fields, config.apiParam.fields)
-	if err != nil && !config.allowedToFail {
+
+	if err = fn(config.ctxParam.fields, config.apiParam.fields); err != nil {
 		return err
 	}
 	return nil

internal/actions/actions_test.go

@@ -7,9 +7,11 @@ import (
 	"time"
 
 	"github.com/dop251/goja"
+	"github.com/zitadel/zitadel/internal/logstore"
 )
 
 func TestRun(t *testing.T) {
+	SetLogstoreService(logstore.New(nil, nil, nil))
 	type args struct {
 		timeout time.Duration
 		api     apiFields

internal/actions/config.go

@@ -23,13 +23,14 @@ func WithAllowedToFail() Option {
 
 type runConfig struct {
 	allowedToFail bool
-	timeout,
-	prepareTimeout time.Duration
-	modules map[string]require.ModuleLoader
-
-	vm       *goja.Runtime
-	ctxParam *ctxConfig
-	apiParam *apiConfig
+	functionTimeout,
+	scriptTimeout time.Duration
+	modules    map[string]require.ModuleLoader
+	logger     *logger
+	instanceID string
+	vm         *goja.Runtime
+	ctxParam   *ctxConfig
+	apiParam   *apiConfig
 }
 
 func newRunConfig(ctx context.Context, opts ...Option) *runConfig {
@@ -42,10 +43,10 @@ func newRunConfig(ctx context.Context, opts ...Option) *runConfig {
 	vm.SetFieldNameMapper(goja.UncapFieldNameMapper())
 
 	config := &runConfig{
-		timeout:        time.Until(deadline),
-		prepareTimeout: maxPrepareTimeout,
-		modules:        map[string]require.ModuleLoader{},
-		vm:             vm,
+		functionTimeout: time.Until(deadline),
+		scriptTimeout:   maxPrepareTimeout,
+		modules:         map[string]require.ModuleLoader{},
+		vm:              vm,
 		ctxParam: &ctxConfig{
 			FieldConfig: FieldConfig{
 				Runtime: vm,
@@ -64,23 +65,37 @@ func newRunConfig(ctx context.Context, opts ...Option) *runConfig {
 		opt(config)
 	}
 
-	if config.prepareTimeout > config.timeout {
-		config.prepareTimeout = config.timeout
+	if config.scriptTimeout > config.functionTimeout {
+		config.scriptTimeout = config.functionTimeout
 	}
 
 	return config
 }
 
-func (c *runConfig) Start() *time.Timer {
+func (c *runConfig) StartFunction() *time.Timer {
 	c.vm.ClearInterrupt()
-	return time.AfterFunc(c.timeout, func() {
+	return time.AfterFunc(c.functionTimeout, func() {
 		c.vm.Interrupt(ErrHalt)
 	})
 }
 
-func (c *runConfig) Prepare() *time.Timer {
+func (c *runConfig) StartScript() *time.Timer {
 	c.vm.ClearInterrupt()
-	return time.AfterFunc(c.prepareTimeout, func() {
+	return time.AfterFunc(c.scriptTimeout, func() {
 		c.vm.Interrupt(ErrHalt)
 	})
 }
+
+func (c *runConfig) cutTimeouts(remainingSeconds *uint64) {
+	if remainingSeconds == nil {
+		return
+	}
+
+	remainingDur := time.Duration(*remainingSeconds) * time.Second
+	if c.functionTimeout > remainingDur {
+		c.functionTimeout = remainingDur
+	}
+	if c.scriptTimeout > remainingDur {
+		c.scriptTimeout = remainingDur
+	}
+}

internal/actions/fields_test.go

@@ -5,9 +5,11 @@ import (
 	"testing"
 
 	"github.com/dop251/goja"
+	"github.com/zitadel/zitadel/internal/logstore"
 )
 
 func TestSetFields(t *testing.T) {
+	SetLogstoreService(logstore.New(nil, nil, nil))
 	primitveFn := func(a string) { fmt.Println(a) }
 	complexFn := func(*FieldConfig) interface{} {
 		return primitveFn

internal/actions/http_module_test.go

@@ -11,9 +11,11 @@ import (
 
 	"github.com/dop251/goja"
 	"github.com/zitadel/zitadel/internal/errors"
+	"github.com/zitadel/zitadel/internal/logstore"
 )
 
 func Test_isHostBlocked(t *testing.T) {
+	SetLogstoreService(logstore.New(nil, nil, nil))
 	var denyList = []AddressChecker{
 		mustNewIPChecker(t, "192.168.5.0/24"),
 		mustNewIPChecker(t, "127.0.0.1"),

internal/actions/log_module.go

@@ -1,30 +1,83 @@
 package actions
 
 import (
-	"github.com/zitadel/logging"
+	"context"
+	"time"
 
 	"github.com/dop251/goja"
 	"github.com/dop251/goja_nodejs/console"
+	"github.com/sirupsen/logrus"
+
+	"github.com/zitadel/zitadel/internal/api/authz"
+	"github.com/zitadel/zitadel/internal/logstore"
+	"github.com/zitadel/zitadel/internal/logstore/emitters/execution"
 )
 
-var ServerLog *logrus
+var (
+	logstoreService *logstore.Service
+	_               console.Printer = (*logger)(nil)
+)
 
-type logrus struct{}
-
-func (*logrus) Log(s string) {
-	logging.WithFields("message", s).Info("log from action")
-}
-func (*logrus) Warn(s string) {
-	logging.WithFields("message", s).Info("warn from action")
-}
-func (*logrus) Error(s string) {
-	logging.WithFields("message", s).Info("error from action")
+func SetLogstoreService(svc *logstore.Service) {
+	logstoreService = svc
 }
 
-func WithLogger(logger console.Printer) Option {
+type logger struct {
+	ctx        context.Context
+	started    time.Time
+	instanceID string
+}
+
+// newLogger returns a *logger instance that should only be used for a single action run.
+// The first log call sets the started field for subsequent log calls
+func newLogger(ctx context.Context, instanceID string) *logger {
+	return &logger{
+		ctx:        ctx,
+		started:    time.Time{},
+		instanceID: instanceID,
+	}
+}
+
+func (l *logger) Log(msg string) {
+	l.log(msg, logrus.InfoLevel, false)
+}
+
+func (l *logger) Warn(msg string) {
+	l.log(msg, logrus.WarnLevel, false)
+}
+
+func (l *logger) Error(msg string) {
+	l.log(msg, logrus.ErrorLevel, false)
+}
+
+func (l *logger) log(msg string, level logrus.Level, last bool) {
+	ts := time.Now()
+	if l.started.IsZero() {
+		l.started = ts
+	}
+
+	record := &execution.Record{
+		LogDate:    ts,
+		InstanceID: l.instanceID,
+		Message:    msg,
+		LogLevel:   level,
+	}
+
+	if last {
+		record.Took = ts.Sub(l.started)
+	}
+
+	logstoreService.Handle(l.ctx, record)
+}
+
+func withLogger(ctx context.Context) Option {
+	instance := authz.GetInstance(ctx)
+	instanceID := instance.InstanceID()
 	return func(c *runConfig) {
+		c.logger = newLogger(ctx, instanceID)
+		c.instanceID = instanceID
 		c.modules["zitadel/log"] = func(runtime *goja.Runtime, module *goja.Object) {
-			console.RequireWithPrinter(logger)(runtime, module)
+			console.RequireWithPrinter(c.logger)(runtime, module)
 		}
 	}
 }