feat: Adding logging and sink support

config/config.go

@@ -0,0 +1,91 @@
+/*
+ * ECAL
+ *
+ * Copyright 2020 Matthias Ladkau. All rights reserved.
+ *
+ * This Source Code Form is subject to the terms of the MIT
+ * License, If a copy of the MIT License was not distributed with this
+ * file, You can obtain one at https://opensource.org/licenses/MIT.
+ */
+
+package config
+
+import (
+	"fmt"
+	"strconv"
+
+	"devt.de/krotik/common/errorutil"
+)
+
+// Global variables
+// ================
+
+/*
+ProductVersion is the current version of ECAL
+*/
+const ProductVersion = "1.0.0"
+
+/*
+Known configuration options for ECAL
+*/
+const (
+	WorkerCount = "WorkerCount"
+)
+
+/*
+DefaultConfig is the defaut configuration
+*/
+var DefaultConfig = map[string]interface{}{
+	WorkerCount: 1,
+}
+
+/*
+Config is the actual config which is used
+*/
+var Config map[string]interface{}
+
+/*
+Initialise the config
+*/
+func init() {
+	data := make(map[string]interface{})
+	for k, v := range DefaultConfig {
+		data[k] = v
+	}
+
+	Config = data
+}
+
+// Helper functions
+// ================
+
+/*
+Str reads a config value as a string value.
+*/
+func Str(key string) string {
+	return fmt.Sprint(Config[key])
+}
+
+/*
+Int reads a config value as an int value.
+*/
+func Int(key string) int {
+	ret, err := strconv.ParseInt(fmt.Sprint(Config[key]), 10, 64)
+
+	errorutil.AssertTrue(err == nil,
+		fmt.Sprintf("Could not parse config key %v: %v", key, err))
+
+	return int(ret)
+}
+
+/*
+Bool reads a config value as a boolean value.
+*/
+func Bool(key string) bool {
+	ret, err := strconv.ParseBool(fmt.Sprint(Config[key]))
+
+	errorutil.AssertTrue(err == nil,
+		fmt.Sprintf("Could not parse config key %v: %v", key, err))
+
+	return ret
+}

config/config_test.go

@@ -0,0 +1,33 @@
+/*
+ * ECAL
+ *
+ * Copyright 2020 Matthias Ladkau. All rights reserved.
+ *
+ * This Source Code Form is subject to the terms of the MIT
+ * License, If a copy of the MIT License was not distributed with this
+ * file, You can obtain one at https://opensource.org/licenses/MIT.
+ */
+
+package config
+
+import (
+	"testing"
+)
+
+func TestConfig(t *testing.T) {
+
+	if res := Str(WorkerCount); res != "1" {
+		t.Error("Unexpected result:", res)
+		return
+	}
+
+	if res := Bool(WorkerCount); !res {
+		t.Error("Unexpected result:", res)
+		return
+	}
+
+	if res := Int(WorkerCount); res != 1 {
+		t.Error("Unexpected result:", res)
+		return
+	}
+}

ecal.md

@@ -29,6 +29,10 @@ foobar.doSomething()
 
 Event Sinks
 --
+TODO:
+
+- How ECAL provides concurrency support
+
 Sinks are should have unique names which identify them and the following attributes:
 
 Attribute | Description

engine.md

@@ -20,7 +20,15 @@ After an event is injected the Processor first checks if anything triggers on th
 
 After the first triggering check passed, the event is handed over to a task which runs in the thread pool. The task uses the rule index to determine all triggering rules. After filtering rules which are out of scope or which are suppressed by other rules, the remaining rules are sorted by their priority and then their action is executed.
 
-A rule action can inject new events into the processor which starts the processing cycle again.
+A rule action can inject new events into the processor which starts the processing cycle again. The processor supports two modes of execution for rule sequences (rules triggered by an event in order of priority):
+
+1. Do not fail on errors: all rules in a trigger sequence for a specific event
+are executed.
+
+2. Fail on first error: the first rule which returns an error will stop
+the trigger sequence. Events which have been added by the failing rule are still processed.
+
+Failing on the first error can be useful in scenarios where authorization is required. High priority rules can block lower priority rules from being executed.
 
 
 Monitor
@@ -116,6 +124,24 @@ rootm.SetFinishHandler(func(p Processor) { // Handler for end of event cascade
 proc.AddEvent(e, rootm)
 ```
 
+- The event is processed as follows:
+
+	- The event is injected into the procesor with or without a parent monitor.
+
+		- Quick (not complete!) check if the event triggers any rules. This is to avoid unnecessary computation.
+			- Check that the event kind is not too general (e.g. the rule is for a.b.c event is for a.b)
+			- Check if 	at least one rule matches the kind. At least on rule should either be triggering on all kinds or triggering on the specific kind of the event.
+
+		- Create a new root monitor if no parent monitor has been given.
+
+		- Add a task to the thread pool of the processor (containing the event, parent/root monitor and processor).
+
+	- Thread pool of the processor takes the next task according to the highest priority.
+
+		- Determine the triggering rules (matching via kind, state and scope without suppressed rules).
+
+		- Execute the action of each triggering rule according to their priority.
+
 - The processor can run as long as needed and can be finished when the application should be terminated.
 
 ```

engine/monitor.go

@@ -202,9 +202,10 @@ Skip finishes this monitor without activation.
 func (mb *monitorBase) Skip(e *Event) {
 	errorutil.AssertTrue(!mb.finished, "Cannot skip a finished monitor")
 	errorutil.AssertTrue(!mb.activated, "Cannot skip an active monitor")
+
 	mb.event = e
 	mb.activated = true
-	mb.finished = true
+	mb.Finish()
 }
 
 /*

engine/processor.go

@@ -83,6 +83,20 @@ type Processor interface {
 	*/
 	SetRootMonitorErrorObserver(func(rm *RootMonitor))
 
+	/*
+		SetFailOnFirstErrorInTriggerSequence sets the behavior when rules return errors.
+		If set to false (default) then all rules in a trigger sequence for a specific event
+		are executed. If set to true then the first rule which returns an error will stop
+		the trigger sequence. Events which have been added by the failing rule are still processed.
+	*/
+	SetFailOnFirstErrorInTriggerSequence(bool)
+
+	/*
+	   AddEventAndWait adds a new event to the processor and waits for the resulting event cascade
+	   to finish. If a monitor is passed then it must be a RootMonitor.
+	*/
+	AddEventAndWait(event *Event, monitor *RootMonitor) (Monitor, error)
+
 	/*
 	   AddEvent adds a new event to the processor. Returns the monitor if the event
 	   triggered a rule and nil if the event was skipped.
@@ -119,6 +133,7 @@ type eventProcessor struct {
 	id                  uint64                // Processor ID
 	pool                *pools.ThreadPool     // Thread pool of this processor
 	workerCount         int                   // Number of threads for this processor
+	failOnFirstError    bool                  // Stop rule execution on first error in an event trigger sequence
 	ruleIndex           RuleIndex             // Container for loaded rules
 	triggeringCache     map[string]bool       // Cache which remembers which events are triggering
 	triggeringCacheLock sync.Mutex            // Lock for triggeringg cache
@@ -132,7 +147,7 @@ NewProcessor creates a new event processor with a given number of workers.
 func NewProcessor(workerCount int) Processor {
 	ep := flowutil.NewEventPump()
 	return &eventProcessor{newProcID(), pools.NewThreadPoolWithQueue(NewTaskQueue(ep)),
-		workerCount, NewRuleIndex(), nil, sync.Mutex{}, ep, nil}
+		workerCount, false, NewRuleIndex(), nil, sync.Mutex{}, ep, nil}
 }
 
 /*
@@ -252,6 +267,16 @@ func (p *eventProcessor) SetRootMonitorErrorObserver(rmErrorObserver func(rm *Ro
 	p.rmErrorObserver = rmErrorObserver
 }
 
+/*
+SetFailOnFirstErrorInTriggerSequence sets the behavior when rules return errors.
+If set to false (default) then all rules in a trigger sequence for a specific event
+are executed. If set to true then the first rule which returns an error will stop
+the trigger sequence. Events which have been added by the failing rule are still processed.
+*/
+func (p *eventProcessor) SetFailOnFirstErrorInTriggerSequence(v bool) {
+	p.failOnFirstError = v
+}
+
 /*
 Notify the root monitor error observer that an error occurred.
 */
@@ -261,11 +286,51 @@ func (p *eventProcessor) notifyRootMonitorErrors(rm *RootMonitor) {
 	}
 }
 
+/*
+AddEventAndWait adds a new event to the processor and waits for the resulting event cascade
+to finish. If a monitor is passed then it must be a RootMonitor.
+*/
+func (p *eventProcessor) AddEventAndWait(event *Event, monitor *RootMonitor) (Monitor, error) {
+	var wg sync.WaitGroup
+	wg.Add(1)
+
+	if monitor == nil {
+		monitor = p.NewRootMonitor(nil, nil)
+	}
+
+	p.messageQueue.AddObserver(MessageRootMonitorFinished, monitor,
+		func(event string, eventSource interface{}) {
+
+			// Everything has finished
+
+			wg.Done()
+
+			p.messageQueue.RemoveObservers(event, eventSource)
+		})
+
+	resMonitor, err := p.AddEvent(event, monitor)
+
+	if resMonitor == nil {
+
+		// Event was not added
+
+		p.messageQueue.RemoveObservers(MessageRootMonitorFinished, monitor)
+
+	} else {
+
+		// Event was added now wait for it to finish
+
+		wg.Wait()
+	}
+
+	return resMonitor, err
+}
+
 /*
 AddEvent adds a new event to the processor. Returns the monitor if the event
 triggered a rule and nil if the event was skipped.
 */
-func (p *eventProcessor) AddEvent(event *Event, parentMonitor Monitor) (Monitor, error) {
+func (p *eventProcessor) AddEvent(event *Event, eventMonitor Monitor) (Monitor, error) {
 
 	// Check that the thread pool is running
 
@@ -281,8 +346,8 @@ func (p *eventProcessor) AddEvent(event *Event, parentMonitor Monitor) (Monitor,
 
 		EventTracer.record(event, "eventProcessor.AddEvent", "Event was skipped")
 
-		if parentMonitor != nil {
-			parentMonitor.Skip(event)
+		if eventMonitor != nil {
+			eventMonitor.Skip(event)
 		}
 
 		return nil, nil
@@ -290,11 +355,11 @@ func (p *eventProcessor) AddEvent(event *Event, parentMonitor Monitor) (Monitor,
 
 	// Check if we need to construct a new root monitor
 
-	if parentMonitor == nil {
-		parentMonitor = p.NewRootMonitor(nil, nil)
+	if eventMonitor == nil {
+		eventMonitor = p.NewRootMonitor(nil, nil)
 	}
 
-	if rootMonitor, ok := parentMonitor.(*RootMonitor); ok {
+	if rootMonitor, ok := eventMonitor.(*RootMonitor); ok {
 		p.messageQueue.AddObserver(MessageRootMonitorFinished, rootMonitor,
 			func(event string, eventSource interface{}) {
 
@@ -308,15 +373,15 @@ func (p *eventProcessor) AddEvent(event *Event, parentMonitor Monitor) (Monitor,
 			})
 	}
 
-	parentMonitor.Activate(event)
+	eventMonitor.Activate(event)
 
 	EventTracer.record(event, "eventProcessor.AddEvent", "Adding task to thread pool")
 
 	// Kick off event processing (see Processor.processEvent)
 
-	p.pool.AddTask(&Task{p, parentMonitor, event})
+	p.pool.AddTask(&Task{p, eventMonitor, event})
 
-	return parentMonitor, nil
+	return eventMonitor, nil
 }
 
 /*
@@ -397,6 +462,9 @@ func (p *eventProcessor) ProcessEvent(event *Event, parent Monitor) map[string]e
 		if err := rule.Action(p, parent, event); err != nil {
 			errors[rule.Name] = err
 		}
+		if p.failOnFirstError && len(errors) > 0 {
+			break
+		}
 	}
 
 	parent.Finish()

engine/processor_test.go

@@ -687,6 +687,10 @@ func TestProcessorSimpleErrorHandling(t *testing.T) {
 		recordedErrors = len(rm.AllErrors()[0].ErrorMap)
 	})
 
+	// First test will always execute all rules and collect all errors
+
+	proc.SetFailOnFirstErrorInTriggerSequence(false)
+
 	proc.Start()
 
 	// Push a root event
@@ -739,4 +743,105 @@ InitialEvent -> event2 -> event3 -> TestRule3 : testerror2]` {
 		t.Error("Unexpected errors:", errs)
 		return
 	}
+
+	// Second test will fail on the first failed rule in an event trigger sequence
+
+	proc.SetFailOnFirstErrorInTriggerSequence(true)
+
+	proc.Start()
+
+	mon, err = proc.AddEvent(&Event{
+		"InitialEvent",
+		[]string{"core", "main", "event1"},
+		map[interface{}]interface{}{"name": "foo", "test": "123"},
+	}, nil)
+	rmon, ok = mon.(*RootMonitor)
+	if !ok {
+		t.Error("Root monitor expected:", mon, err)
+		return
+	}
+	proc.Finish()
+
+	errs = rmon.AllErrors()
+
+	if len(errs) != 2 {
+		t.Error("Unexpected number of errors:", len(errs))
+		return
+	}
+
+	if fmt.Sprint(errs) != `[Taskerror:
+InitialEvent -> TestRule1 : testerror Taskerror:
+InitialEvent -> event2 -> event3 -> TestRule3 : testerror2]` {
+		t.Error("Unexpected errors:", errs)
+		return
+	}
+
+	if recordedErrors != 1 {
+		t.Error("Unexpected number of recorded errors:", recordedErrors)
+		return
+	}
+
+	// Now test AddEventAndWait
+
+	proc.SetFailOnFirstErrorInTriggerSequence(false)
+	proc.Start()
+
+	mon, err = proc.AddEventAndWait(&Event{
+		"InitialEvent1",
+		[]string{"core", "main", "event5"},
+		map[interface{}]interface{}{"name": "foo", "test": "123"},
+	}, nil)
+
+	if mon != nil {
+		t.Error("Nothing should have triggered")
+		return
+	}
+
+	// Push a root event
+
+	mon, err = proc.AddEventAndWait(&Event{
+		"InitialEvent",
+		[]string{"core", "main", "event1"},
+		map[interface{}]interface{}{"name": "foo", "test": "123"},
+	}, nil)
+
+	rmon, ok = mon.(*RootMonitor)
+	if !ok {
+		t.Error("Root monitor expected:", mon, err)
+		return
+	}
+
+	if fmt.Sprint(mon) != "Monitor 10 (parent: <nil> priority: 0 activated: true finished: true)" {
+		t.Error("Unexpected result:", mon)
+		return
+	}
+
+	if proc.Stopped() {
+		t.Error("Processor should not be stopped at this point")
+		return
+	}
+
+	errs = rmon.AllErrors()
+
+	if len(errs) != 3 {
+		t.Error("Unexpected number of errors:", len(errs))
+		return
+	}
+
+	if recordedErrors != 3 {
+		t.Error("Unexpected number of recorded errors:", recordedErrors)
+		return
+	}
+
+	if fmt.Sprint(errs) != `[Taskerrors:
+InitialEvent -> TestRule1 : testerror
+InitialEvent -> TestRule1Copy : testerror
+InitialEvent -> TestRule3 : testerror2 Taskerror:
+InitialEvent -> event2 -> event3 -> TestRule3 : testerror2 Taskerror:
+InitialEvent -> event2 -> event3 -> TestRule3 : testerror2]` {
+		t.Error("Unexpected errors:", errs)
+		return
+	}
+
+	proc.Finish()
 }

interpreter/func_provider.go

@@ -13,7 +13,9 @@ package interpreter
 import (
 	"fmt"
 	"strconv"
+	"strings"
 
+	"devt.de/krotik/ecal/engine"
 	"devt.de/krotik/ecal/parser"
 	"devt.de/krotik/ecal/scope"
 	"devt.de/krotik/ecal/util"
@@ -23,13 +25,16 @@ import (
 inbuildFuncMap contains the mapping of inbuild functions.
 */
 var inbuildFuncMap = map[string]util.ECALFunction{
-	"range":   &rangeFunc{&inbuildBaseFunc{}},
-	"new":     &newFunc{&inbuildBaseFunc{}},
-	"len":     &lenFunc{&inbuildBaseFunc{}},
-	"del":     &delFunc{&inbuildBaseFunc{}},
-	"add":     &addFunc{&inbuildBaseFunc{}},
-	"concat":  &concatFunc{&inbuildBaseFunc{}},
-	"dumpenv": &dumpenvFunc{&inbuildBaseFunc{}},
+	"range":           &rangeFunc{&inbuildBaseFunc{}},
+	"new":             &newFunc{&inbuildBaseFunc{}},
+	"len":             &lenFunc{&inbuildBaseFunc{}},
+	"del":             &delFunc{&inbuildBaseFunc{}},
+	"add":             &addFunc{&inbuildBaseFunc{}},
+	"concat":          &concatFunc{&inbuildBaseFunc{}},
+	"dumpenv":         &dumpenvFunc{&inbuildBaseFunc{}},
+	"sinkError":       &sinkerror{&inbuildBaseFunc{}},
+	"addEvent":        &addevent{&inbuildBaseFunc{}},
+	"addEventAndWait": &addeventandwait{&addevent{&inbuildBaseFunc{}}},
 }
 
 /*
@@ -471,3 +476,181 @@ DocString returns a descriptive string.
 func (rf *dumpenvFunc) DocString() (string, error) {
 	return "Dumpenv returns the current variable environment as a string.", nil
 }
+
+// sinkerror
+// =========
+
+/*
+sinkerror returns a sink error object which indicates that the sink execution failed.
+This error can be used to break trigger sequences of sinks if
+FailOnFirstErrorInTriggerSequence is set.
+*/
+type sinkerror struct {
+	*inbuildBaseFunc
+}
+
+/*
+Run executes this function.
+*/
+func (rf *sinkerror) Run(instanceID string, vs parser.Scope, is map[string]interface{}, args []interface{}) (interface{}, error) {
+	var msg string
+
+	if len(args) > 0 {
+		msg = fmt.Sprint(args...)
+	}
+
+	return nil, &sinkError{msg}
+}
+
+/*
+DocString returns a descriptive string.
+*/
+func (rf *sinkerror) DocString() (string, error) {
+	return "Sinkerror returns a sink error object which indicates that the sink execution failed.", nil
+}
+
+// addEvent
+// ========
+
+/*
+addevent adds an event to trigger sinks. This function will return immediately
+and not wait for the event cascade to finish. Use this function for event cascades.
+*/
+type addevent struct {
+	*inbuildBaseFunc
+}
+
+/*
+Run executes this function.
+*/
+func (rf *addevent) Run(instanceID string, vs parser.Scope, is map[string]interface{}, args []interface{}) (interface{}, error) {
+	return rf.addEvent(func(proc engine.Processor, event *engine.Event, scope *engine.RuleScope) (interface{}, error) {
+		var monitor engine.Monitor
+
+		parentMonitor, ok := is["monitor"]
+
+		if scope != nil || !ok {
+			monitor = proc.NewRootMonitor(nil, scope)
+		} else {
+			monitor = parentMonitor.(engine.Monitor).NewChildMonitor(0)
+		}
+
+		_, err := proc.AddEvent(event, monitor)
+		return nil, err
+	}, is, args)
+}
+
+func (rf *addevent) addEvent(addFunc func(engine.Processor, *engine.Event, *engine.RuleScope) (interface{}, error),
+	is map[string]interface{}, args []interface{}) (interface{}, error) {
+
+	var res interface{}
+	var stateMap map[interface{}]interface{}
+
+	erp := is["erp"].(*ECALRuntimeProvider)
+	proc := erp.Processor
+
+	if proc.Stopped() {
+		proc.Start()
+	}
+
+	err := fmt.Errorf("Need at least three parameters: name, kind and state")
+
+	if len(args) > 2 {
+
+		if stateMap, err = rf.AssertMapParam(3, args[2]); err == nil {
+			var scope *engine.RuleScope
+
+			event := engine.NewEvent(
+				fmt.Sprint(args[0]),
+				strings.Split(fmt.Sprint(args[1]), "."),
+				stateMap,
+			)
+
+			if len(args) > 3 {
+				var scopeMap = map[interface{}]interface{}{}
+
+				// Add optional scope - if not specified it is { "": true }
+
+				if scopeMap, err = rf.AssertMapParam(4, args[3]); err == nil {
+					var scopeData = map[string]bool{}
+
+					for k, v := range scopeMap {
+						b, _ := strconv.ParseBool(fmt.Sprint(v))
+						scopeData[fmt.Sprint(k)] = b
+					}
+
+					scope = engine.NewRuleScope(scopeData)
+				}
+			}
+
+			if err == nil {
+				res, err = addFunc(proc, event, scope)
+			}
+		}
+	}
+
+	return res, err
+}
+
+/*
+DocString returns a descriptive string.
+*/
+func (rf *addevent) DocString() (string, error) {
+	return "AddEvent adds an event to trigger sinks. This function will return " +
+		"immediately and not wait for the event cascade to finish.", nil
+}
+
+// addEventAndWait
+// ===============
+
+/*
+addeventandwait adds an event to trigger sinks. This function will return once
+the event cascade has finished and return all errors.
+*/
+type addeventandwait struct {
+	*addevent
+}
+
+/*
+Run executes this function.
+*/
+func (rf *addeventandwait) Run(instanceID string, vs parser.Scope, is map[string]interface{}, args []interface{}) (interface{}, error) {
+	return rf.addEvent(func(proc engine.Processor, event *engine.Event, scope *engine.RuleScope) (interface{}, error) {
+		var res []interface{}
+		rm := proc.NewRootMonitor(nil, scope)
+		m, err := proc.AddEventAndWait(event, rm)
+
+		if m != nil {
+			allErrors := m.(*engine.RootMonitor).AllErrors()
+
+			for _, e := range allErrors {
+
+				errors := map[interface{}]interface{}{}
+				for k, v := range e.ErrorMap {
+					errors[k] = v.Error()
+				}
+
+				item := map[interface{}]interface{}{
+					"event": map[interface{}]interface{}{
+						"name":  e.Event.Name(),
+						"kind":  strings.Join(e.Event.Kind(), "."),
+						"state": e.Event.State(),
+					},
+					"errors": errors,
+				}
+
+				res = append(res, item)
+			}
+		}
+
+		return res, err
+	}, is, args)
+}
+
+/*
+DocString returns a descriptive string.
+*/
+func (rf *addeventandwait) DocString() (string, error) {
+	return "AddEventAndWait adds an event to trigger sinks. This function will " +
+		"return once the event cascade has finished.", nil
+}

interpreter/main_test.go

@@ -17,6 +17,7 @@ import (
 	"testing"
 
 	"devt.de/krotik/common/datautil"
+	"devt.de/krotik/ecal/engine"
 	"devt.de/krotik/ecal/parser"
 	"devt.de/krotik/ecal/scope"
 	"devt.de/krotik/ecal/util"
@@ -49,11 +50,19 @@ var usedNodes = map[string]bool{
 	parser.NodeEOF: true,
 }
 
+// Last used logger
+//
+var testlogger *util.MemoryLogger
+
+// Last used processor
+//
+var testprocessor engine.Processor
+
 func UnitTestEval(input string, vs parser.Scope) (interface{}, error) {
 	return UnitTestEvalAndAST(input, vs, "")
 }
 func UnitTestEvalAndAST(input string, vs parser.Scope, expectedAST string) (interface{}, error) {
-	return UnitTestEvalAndASTAndImport(input, vs, "", nil)
+	return UnitTestEvalAndASTAndImport(input, vs, expectedAST, nil)
 }
 
 func UnitTestEvalAndASTAndImport(input string, vs parser.Scope, expectedAST string, importLocator util.ECALImportLocator) (interface{}, error) {
@@ -72,8 +81,12 @@ func UnitTestEvalAndASTAndImport(input string, vs parser.Scope, expectedAST stri
 
 	// Parse the input
 
-	ast, err := parser.ParseWithRuntime("ECALEvalTest", input,
-		NewECALRuntimeProvider("ECALTestRuntime", importLocator))
+	erp := NewECALRuntimeProvider("ECALTestRuntime", importLocator, nil)
+
+	testlogger = erp.Logger.(*util.MemoryLogger)
+	testprocessor = erp.Processor
+
+	ast, err := parser.ParseWithRuntime("ECALEvalTest", input, erp)
 	if err != nil {
 		return nil, err
 	}
@@ -102,7 +115,7 @@ addLogFunction adds a simple log function to a given Scope.
 */
 func addLogFunction(vs parser.Scope) *datautil.RingBuffer {
 	buf := datautil.NewRingBuffer(20)
-	vs.SetValue("log", &TestLogger{buf})
+	vs.SetValue("testlog", &TestLogger{buf})
 	return buf
 }
 

interpreter/provider.go

@@ -16,6 +16,11 @@
 package interpreter
 
 import (
+	"os"
+	"path/filepath"
+
+	"devt.de/krotik/ecal/config"
+	"devt.de/krotik/ecal/engine"
 	"devt.de/krotik/ecal/parser"
 	"devt.de/krotik/ecal/util"
 )
@@ -78,17 +83,15 @@ var providerMap = map[string]ecalRuntimeNew{
 
 	parser.NodeIMPORT: importRuntimeInst,
 
-	/*
+	// Sink definition
 
-		// Sink definition
+	parser.NodeSINK:       sinkRuntimeInst,
+	parser.NodeKINDMATCH:  kindMatchRuntimeInst,
+	parser.NodeSCOPEMATCH: scopeMatchRuntimeInst,
+	parser.NodeSTATEMATCH: stateMatchRuntimeInst,
+	parser.NodePRIORITY:   priorityRuntimeInst,
+	parser.NodeSUPPRESSES: suppressesRuntimeInst,
 
-		parser.NodeSINK
-		parser.NodeKINDMATCH
-		parser.NodeSCOPEMATCH
-		parser.NodeSTATEMATCH
-		parser.NodePRIORITY
-		parser.NodeSUPPRESSES
-	*/
 	// Function definition
 
 	parser.NodeFUNC:   funcRuntimeInst,
@@ -131,13 +134,37 @@ ECALRuntimeProvider is the factory object producing runtime objects for ECAL AST
 type ECALRuntimeProvider struct {
 	Name          string                 // Name to identify the input
 	ImportLocator util.ECALImportLocator // Locator object for imports
+	Logger        util.Logger            // Logger object for log messages
+	Processor     engine.Processor       // Processor of the ECA engine
 }
 
 /*
 NewECALRuntimeProvider returns a new instance of a ECAL runtime provider.
 */
-func NewECALRuntimeProvider(name string, importLocator util.ECALImportLocator) *ECALRuntimeProvider {
-	return &ECALRuntimeProvider{name, importLocator}
+func NewECALRuntimeProvider(name string, importLocator util.ECALImportLocator, logger util.Logger) *ECALRuntimeProvider {
+
+	if importLocator == nil {
+
+		// By default imports are located in the current directory
+
+		importLocator = &util.FileImportLocator{filepath.Dir(os.Args[0])}
+	}
+
+	if logger == nil {
+
+		// By default we just have a memory logger
+
+		logger = util.NewMemoryLogger(100)
+	}
+
+	proc := engine.NewProcessor(config.Int(config.WorkerCount))
+
+	// By default ECAL should stop the triggering sequence of sinks after the
+	// first sink that returns a sinkerror.
+
+	proc.SetFailOnFirstErrorInTriggerSequence(true)
+
+	return &ECALRuntimeProvider{name, importLocator, logger, proc}
 }
 
 /*

interpreter/rt_func.go

@@ -175,6 +175,9 @@ func (f *function) Run(instanceID string, vs parser.Scope, is map[string]interfa
 	}
 
 	if err == nil {
+
+		scope.SetParentOfScope(fvs, vs)
+
 		res, err = body.Runtime.Eval(fvs, make(map[string]interface{}))
 
 		// Check for return value (delivered as error object)

interpreter/rt_func_test.go

@@ -180,6 +180,29 @@ statements
 	}
 }
 
+func TestFunctionScoping(t *testing.T) {
+
+	vs := scope.NewScope(scope.GlobalScope)
+
+	res, err := UnitTestEval(`
+c := 1
+foo := func (a, b=1) {
+  return a + b + c
+}
+
+result1 := foo(3, 2)
+`, vs)
+
+	if vsRes := vs.String(); err != nil || res != nil || vsRes != `GlobalScope {
+    c (float64) : 1
+    foo (*interpreter.function) : ecal.function:  (Line 3, Pos 8)
+    result1 (float64) : 6
+}` {
+		t.Error("Unexpected result: ", vsRes, res, err)
+		return
+	}
+}
+
 func TestObjectInstantiation(t *testing.T) {
 
 	vs := scope.NewScope(scope.GlobalScope)

interpreter/rt_general_test.go

@@ -21,7 +21,7 @@ import (
 func TestGeneralErrorCases(t *testing.T) {
 
 	n, _ := parser.Parse("a", "a")
-	inv := &invalidRuntime{newBaseRuntime(NewECALRuntimeProvider("a", nil), n)}
+	inv := &invalidRuntime{newBaseRuntime(NewECALRuntimeProvider("a", nil, nil), n)}
 
 	if err := inv.Validate().Error(); err != "ECAL error in a: Invalid construct (Unknown node: identifier) (Line:1 Pos:1)" {
 		t.Error("Unexpected result:", err)
@@ -66,3 +66,39 @@ statements
 		return
 	}
 }
+
+func TestLogging(t *testing.T) {
+
+	vs := scope.NewScope(scope.GlobalScope)
+
+	_, err := UnitTestEvalAndAST(
+		`
+log("Hello")
+debug("foo")
+error("bar")
+`, vs,
+		`
+statements
+  identifier: log
+    funccall
+      string: 'Hello'
+  identifier: debug
+    funccall
+      string: 'foo'
+  identifier: error
+    funccall
+      string: 'bar'
+`[1:])
+
+	if err != nil {
+		t.Error("Unexpected result: ", err)
+		return
+	}
+
+	if testlogger.String() != `Hello
+debug: foo
+error: bar` {
+		t.Error("Unexpected result: ", testlogger.String())
+		return
+	}
+}

interpreter/rt_identifier.go

@@ -125,23 +125,31 @@ resolveFunction execute function calls and return the result.
 func (rt *identifierRuntime) resolveFunction(astring string, vs parser.Scope, is map[string]interface{},
 	node *parser.ASTNode, result interface{}, err error) (interface{}, error) {
 
+	is["erp"] = rt.erp // All functions have access to the ECAL Runtime Provider
+
 	for _, funccall := range node.Children {
 
 		if funccall.Name == parser.NodeFUNCCALL {
+			var funcObj util.ECALFunction
 
-			funcObj, ok := result.(util.ECALFunction)
+			ok := astring == "log" || astring == "error" || astring == "debug"
 
 			if !ok {
 
-				// Check for inbuild function
-
-				funcObj, ok = inbuildFuncMap[astring]
+				funcObj, ok = result.(util.ECALFunction)
 
 				if !ok {
 
 					// Check for stdlib function
 
 					funcObj, ok = stdlib.GetStdlibFunc(astring)
+
+					if !ok {
+
+						// Check for inbuild function
+
+						funcObj, ok = inbuildFuncMap[astring]
+					}
 				}
 			}
 
@@ -161,22 +169,31 @@ func (rt *identifierRuntime) resolveFunction(astring string, vs parser.Scope, is
 
 				if err == nil {
 
-					// Execute the function and
+					if astring == "log" {
+						rt.erp.Logger.LogInfo(args...)
+					} else if astring == "error" {
+						rt.erp.Logger.LogError(args...)
+					} else if astring == "debug" {
+						rt.erp.Logger.LogDebug(args...)
+					} else {
 
-					result, err = funcObj.Run(rt.instanceID, vs, is, args)
+						// Execute the function and
 
-					if _, ok := err.(*util.RuntimeError); err != nil && !ok {
+						result, err = funcObj.Run(rt.instanceID, vs, is, args)
 
-						// Convert into a proper runtime error if necessary
+						if _, ok := err.(*util.RuntimeError); err != nil && !ok {
 
-						rerr := rt.erp.NewRuntimeError(util.ErrRuntimeError,
-							err.Error(), node).(*util.RuntimeError)
+							// Convert into a proper runtime error if necessary
 
-						if err == util.ErrIsIterator || err == util.ErrEndOfIteration || err == util.ErrContinueIteration {
-							rerr.Type = err
-						}
+							rerr := rt.erp.NewRuntimeError(util.ErrRuntimeError,
+								err.Error(), node).(*util.RuntimeError)
 
-						err = rerr
+							if err == util.ErrIsIterator || err == util.ErrEndOfIteration || err == util.ErrContinueIteration {
+								rerr.Type = err
+							}
+
+							err = rerr
+						}
 					}
 				}
 

interpreter/rt_sink.go

@@ -0,0 +1,321 @@
+/*
+ * ECAL
+ *
+ * Copyright 2020 Matthias Ladkau. All rights reserved.
+ *
+ * This Source Code Form is subject to the terms of the MIT
+ * License, If a copy of the MIT License was not distributed with this
+ * file, You can obtain one at https://opensource.org/licenses/MIT.
+ */
+
+package interpreter
+
+import (
+	"fmt"
+	"math"
+	"strings"
+
+	"devt.de/krotik/ecal/engine"
+	"devt.de/krotik/ecal/parser"
+	"devt.de/krotik/ecal/scope"
+	"devt.de/krotik/ecal/util"
+)
+
+/*
+sinkRuntime is the runtime for sink declarations.
+*/
+type sinkRuntime struct {
+	*baseRuntime
+}
+
+/*
+sinkRuntimeInst returns a new runtime component instance.
+*/
+func sinkRuntimeInst(erp *ECALRuntimeProvider, node *parser.ASTNode) parser.Runtime {
+	return &sinkRuntime{newBaseRuntime(erp, node)}
+}
+
+/*
+Validate this node and all its child nodes.
+*/
+func (rt *sinkRuntime) Validate() error {
+	err := rt.baseRuntime.Validate()
+
+	if err == nil {
+
+		nameNode := rt.node.Children[0]
+
+		// Make sure there is a constant as a name
+
+		if _, ok := nameNode.Runtime.(*identifierRuntime); !ok {
+			return rt.erp.NewRuntimeError(util.ErrInvalidConstruct,
+				"Must have an identifier as sink name", rt.node)
+		}
+
+		// Check that all children are valid
+
+		for _, child := range rt.node.Children[1:] {
+			switch child.Name {
+			case parser.NodeKINDMATCH:
+			case parser.NodeSCOPEMATCH:
+			case parser.NodeSTATEMATCH:
+			case parser.NodePRIORITY:
+			case parser.NodeSUPPRESSES:
+			case parser.NodeSTATEMENTS:
+				continue
+			default:
+				err = rt.erp.NewRuntimeError(util.ErrInvalidConstruct,
+					fmt.Sprintf("Unknown expression in sink declaration %v", child.Token.Val),
+					child)
+			}
+
+			if err != nil {
+				break
+			}
+		}
+	}
+
+	return err
+}
+
+/*
+Eval evaluate this runtime component.
+*/
+func (rt *sinkRuntime) Eval(vs parser.Scope, is map[string]interface{}) (interface{}, error) {
+	var kindMatch, scopeMatch, suppresses []string
+	var stateMatch map[string]interface{}
+	var priority int
+	var statements *parser.ASTNode
+	var err error
+
+	// Create default scope
+
+	scopeMatch = []string{}
+
+	// Get the name of the sink
+
+	name := rt.node.Children[0].Token.Val
+
+	// Create helper function
+
+	makeStringList := func(child *parser.ASTNode) ([]string, error) {
+		var ret []string
+
+		val, err := child.Runtime.Eval(vs, is)
+
+		if err == nil {
+			for _, v := range val.([]interface{}) {
+				ret = append(ret, fmt.Sprint(v))
+			}
+		}
+
+		return ret, err
+	}
+
+	// Collect values from children
+
+	for _, child := range rt.node.Children[1:] {
+
+		switch child.Name {
+
+		case parser.NodeKINDMATCH:
+			kindMatch, err = makeStringList(child)
+			break
+
+		case parser.NodeSCOPEMATCH:
+			scopeMatch, err = makeStringList(child)
+			break
+
+		case parser.NodeSTATEMATCH:
+			var val interface{}
+			stateMatch = make(map[string]interface{})
+
+			if val, err = child.Runtime.Eval(vs, is); err == nil {
+				for k, v := range val.(map[interface{}]interface{}) {
+					stateMatch[fmt.Sprint(k)] = v
+				}
+			}
+			break
+
+		case parser.NodePRIORITY:
+			var val interface{}
+
+			if val, err = child.Runtime.Eval(vs, is); err == nil {
+				priority = int(math.Floor(val.(float64)))
+			}
+			break
+
+		case parser.NodeSUPPRESSES:
+			suppresses, err = makeStringList(child)
+			break
+
+		case parser.NodeSTATEMENTS:
+			statements = child
+			break
+		}
+
+		if err != nil {
+			break
+		}
+	}
+
+	if err == nil && statements != nil {
+		var desc string
+
+		sinkName := fmt.Sprint(name)
+
+		if len(rt.node.Meta) > 0 &&
+			(rt.node.Meta[0].Type() == parser.MetaDataPreComment ||
+				rt.node.Meta[0].Type() == parser.MetaDataPostComment) {
+			desc = strings.TrimSpace(rt.node.Meta[0].Value())
+		}
+
+		rule := &engine.Rule{
+			Name:            sinkName,   // Name
+			Desc:            desc,       // Description
+			KindMatch:       kindMatch,  // Kind match
+			ScopeMatch:      scopeMatch, // Match on event cascade scope
+			StateMatch:      stateMatch, // No state match
+			Priority:        priority,   // Priority of the rule
+			SuppressionList: suppresses, // List of suppressed rules by this rule
+			Action: func(p engine.Processor, m engine.Monitor, e *engine.Event) error { // Action of the rule
+
+				// Create a new root variable scope
+
+				sinkVS := scope.NewScope(fmt.Sprintf("sink: %v", sinkName))
+
+				// Create a new instance state with the monitor - everything called
+				// by the rule will have access to the current monitor.
+
+				sinkIs := map[string]interface{}{
+					"monitor": m,
+				}
+
+				err = sinkVS.SetValue("event", map[interface{}]interface{}{
+					"name":  e.Name(),
+					"kind":  strings.Join(e.Kind(), engine.RuleKindSeparator),
+					"state": e.State(),
+				})
+
+				if err == nil {
+					scope.SetParentOfScope(sinkVS, vs)
+
+					_, err = statements.Runtime.Eval(sinkVS, sinkIs)
+
+					if err != nil {
+						if _, ok := err.(*sinkError); !ok {
+							err = fmt.Errorf("%v\nEnvironment:\n%v", err.Error(), sinkVS.String())
+						}
+					}
+				}
+
+				return err
+			},
+		}
+
+		if err = rt.erp.Processor.AddRule(rule); err != nil {
+			err = rt.erp.NewRuntimeError(util.ErrInvalidState, err.Error(), rt.node)
+		}
+	}
+
+	return nil, err
+}
+
+/*
+sinkError is a special error which indicates that a sink has failed.
+*/
+type sinkError struct {
+	msg string
+}
+
+/*
+Eval evaluate this runtime component.
+*/
+func (se *sinkError) Error() string {
+	return se.msg
+}
+
+// Sink child nodes
+// ================
+
+/*
+sinkDetailRuntime is the runtime for sink detail declarations.
+*/
+type sinkDetailRuntime struct {
+	*baseRuntime
+	valType string
+}
+
+/*
+Eval evaluate this runtime component.
+*/
+func (rt *sinkDetailRuntime) Eval(vs parser.Scope, is map[string]interface{}) (interface{}, error) {
+
+	ret, err := rt.node.Children[0].Runtime.Eval(vs, is)
+
+	if err == nil {
+
+		// Check value is of expected type
+
+		if rt.valType == "list" {
+			if _, ok := ret.([]interface{}); !ok {
+				return nil, rt.erp.NewRuntimeError(util.ErrInvalidConstruct,
+					fmt.Sprintf("Expected a list as value"),
+					rt.node)
+			}
+
+		} else if rt.valType == "map" {
+
+			if _, ok := ret.(map[interface{}]interface{}); !ok {
+				return nil, rt.erp.NewRuntimeError(util.ErrInvalidConstruct,
+					fmt.Sprintf("Expected a map as value"),
+					rt.node)
+			}
+
+		} else if rt.valType == "int" {
+
+			if _, ok := ret.(float64); !ok {
+				return nil, rt.erp.NewRuntimeError(util.ErrInvalidConstruct,
+					fmt.Sprintf("Expected a number as value"),
+					rt.node)
+			}
+		}
+	}
+
+	return ret, err
+}
+
+/*
+kindMatchRuntimeInst returns a new runtime component instance.
+*/
+func kindMatchRuntimeInst(erp *ECALRuntimeProvider, node *parser.ASTNode) parser.Runtime {
+	return &sinkDetailRuntime{newBaseRuntime(erp, node), "list"}
+}
+
+/*
+scopeMatchRuntimeInst returns a new runtime component instance.
+*/
+func scopeMatchRuntimeInst(erp *ECALRuntimeProvider, node *parser.ASTNode) parser.Runtime {
+	return &sinkDetailRuntime{newBaseRuntime(erp, node), "list"}
+}
+
+/*
+stateMatchRuntimeInst returns a new runtime component instance.
+*/
+func stateMatchRuntimeInst(erp *ECALRuntimeProvider, node *parser.ASTNode) parser.Runtime {
+	return &sinkDetailRuntime{newBaseRuntime(erp, node), "map"}
+}
+
+/*
+priorityRuntimeInst returns a new runtime component instance.
+*/
+func priorityRuntimeInst(erp *ECALRuntimeProvider, node *parser.ASTNode) parser.Runtime {
+	return &sinkDetailRuntime{newBaseRuntime(erp, node), "int"}
+}
+
+/*
+suppressesRuntimeInst returns a new runtime component instance.
+*/
+func suppressesRuntimeInst(erp *ECALRuntimeProvider, node *parser.ASTNode) parser.Runtime {
+	return &sinkDetailRuntime{newBaseRuntime(erp, node), "list"}
+}

interpreter/rt_sink_test.go

@@ -0,0 +1,132 @@
+/*
+ * ECAL
+ *
+ * Copyright 2020 Matthias Ladkau. All rights reserved.
+ *
+ * This Source Code Form is subject to the terms of the MIT
+ * License, If a copy of the MIT License was not distributed with this
+ * file, You can obtain one at https://opensource.org/licenses/MIT.
+ */
+
+package interpreter
+
+import (
+	"fmt"
+	"testing"
+
+	"devt.de/krotik/ecal/scope"
+)
+
+func TestEventProcessing(t *testing.T) {
+
+	vs := scope.NewScope(scope.GlobalScope)
+
+	_, err := UnitTestEvalAndAST(
+		`
+/*
+My cool rule
+*/
+sink rule1
+    kindmatch [ "core.*" ],
+	scopematch [ "data.write" ],
+	statematch { "val" : NULL },
+	priority 10,
+	suppresses [ "rule2" ]
+	{
+        log("rule1 < ", event)
+	}
+`, vs,
+		`
+sink # 
+My cool rule
+
+  identifier: rule1
+  kindmatch
+    list
+      string: 'core.*'
+  scopematch
+    list
+      string: 'data.write'
+  statematch
+    map
+      kvp
+        string: 'val'
+        null
+  priority
+    number: 10
+  suppresses
+    list
+      string: 'rule2'
+  statements
+    identifier: log
+      funccall
+        string: 'rule1 < '
+        identifier: event
+`[1:])
+
+	if err != nil {
+		t.Error(err)
+		return
+	}
+
+	// Nothing defined in the global scope
+
+	if vs.String() != `
+GlobalScope {
+}`[1:] {
+		t.Error("Unexpected result: ", vs)
+		return
+	}
+
+	if res := fmt.Sprint(testprocessor.Rules()["rule1"]); res !=
+		`Rule:rule1 [My cool rule] (Priority:10 Kind:[core.*] Scope:[data.write] StateMatch:{"val":null} Suppress:[rule2])` {
+		t.Error("Unexpected result:", res)
+		return
+	}
+
+	_, err = UnitTestEval(
+		`
+sink rule1
+    kindmatch [ "web.page.index" ],
+	scopematch [ "request.read" ],
+	{
+        log("rule1 > Handling request: ", event.kind)
+        addEvent("Rule1Event1", "not_existing", event.state)
+        addEvent("Rule1Event2", "web.log", event.state)
+	}
+
+sink rule2
+    kindmatch [ "web.page.*" ],
+    priority 1,  # Ensure this rule is always executed after rule1
+	{
+        log("rule2 > Tracking user:", event.state.user)
+	}
+
+sink rule3
+    kindmatch [ "web.log" ],
+	{
+        log("rule3 > Logging user:", event.state.user)
+	}
+
+res := addEventAndWait("request", "web.page.index", {
+	"user" : "foo"
+}, {
+	"request.read" : true
+})
+log("ErrorResult:", res, len(res) == 0)
+`, vs)
+
+	if err != nil {
+		t.Error(err)
+		return
+	}
+
+	if testlogger.String() != `
+rule1 > Handling request: web.page.index
+rule2 > Tracking user:foo
+rule3 > Logging user:foo
+ErrorResult:[] true`[1:] {
+		t.Error("Unexpected result:", testlogger.String())
+		return
+	}
+}

interpreter/rt_statements_test.go

@@ -197,7 +197,7 @@ a := 10
 
 for a > 0 {
 
-	log("Info: ", "-> ", a)
+	testlog("Info: ", "-> ", a)
 	a := a - 1
 }
 `, vs,
@@ -212,7 +212,7 @@ statements
         identifier: a
         number: 0
     statements
-      identifier: log
+      identifier: testlog
         funccall
           string: 'Info: '
           string: '-> '
@@ -232,7 +232,7 @@ statements
 	if vs.String() != `
 GlobalScope {
     a (float64) : 0
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:4 Pos:1) {
     }
 }`[1:] {
@@ -261,7 +261,7 @@ Info: -> 1`[1:] {
 	_, err = UnitTestEvalAndAST(
 		`
 	   for a in range(2, 10, 1) {
-           log("Info", "->", a)
+           testlog("Info", "->", a)
 	   }
 	   `, vs,
 		`
@@ -274,7 +274,7 @@ loop
         number: 10
         number: 1
   statements
-    identifier: log
+    identifier: testlog
       funccall
         string: 'Info'
         string: '->'
@@ -288,7 +288,7 @@ loop
 
 	if vs.String() != `
 GlobalScope {
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:2 Pos:5) {
         a (float64) : 10
     }
@@ -317,7 +317,7 @@ Info->10`[1:] {
 	_, err = UnitTestEvalAndAST(
 		`
 for a in range(10, 3, -3) {
-  log("Info", "->", a)
+  testlog("Info", "->", a)
 }
 	   `, vs,
 		`
@@ -331,7 +331,7 @@ loop
         minus
           number: 3
   statements
-    identifier: log
+    identifier: testlog
       funccall
         string: 'Info'
         string: '->'
@@ -345,7 +345,7 @@ loop
 
 	if vs.String() != `
 GlobalScope {
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:2 Pos:1) {
         a (float64) : 4
     }
@@ -371,7 +371,7 @@ Info->4`[1:] {
 		`
 for a in range(10, 3, -3) {
   for b in range(1, 3, 1) {
-    log("Info", "->", a, b)
+    testlog("Info", "->", a, b)
   }
 }
 	   `, vs,
@@ -395,7 +395,7 @@ loop
             number: 3
             number: 1
       statements
-        identifier: log
+        identifier: testlog
           funccall
             string: 'Info'
             string: '->'
@@ -410,7 +410,7 @@ loop
 
 	if vs.String() != `
 GlobalScope {
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:2 Pos:1) {
         a (float64) : 4
         block: loop (Line:3 Pos:3) {
@@ -444,7 +444,7 @@ Info->4 3`[1:] {
 	_, err = UnitTestEvalAndAST(
 		`
 for a in range(1, 10, 1) {
-  log("Info", "->", a)
+  testlog("Info", "->", a)
   if a == 3 {
     break
   }
@@ -459,7 +459,7 @@ loop
         number: 10
         number: 1
   statements
-    identifier: log
+    identifier: testlog
       funccall
         string: 'Info'
         string: '->'
@@ -480,7 +480,7 @@ loop
 
 	if vs.String() != `
 GlobalScope {
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:2 Pos:1) {
         a (float64) : 3
         block: if (Line:4 Pos:3) {
@@ -510,7 +510,7 @@ for a in range(1, 10, 1) {
   if a > 3 and a < 6  {
     continue
   }
-  log("Info", "->", a)
+  testlog("Info", "->", a)
 }`, vs,
 		`
 loop
@@ -533,7 +533,7 @@ loop
             number: 6
       statements
         continue
-    identifier: log
+    identifier: testlog
       funccall
         string: 'Info'
         string: '->'
@@ -547,7 +547,7 @@ loop
 
 	if vs.String() != `
 GlobalScope {
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:2 Pos:1) {
         a (float64) : 10
         block: if (Line:3 Pos:3) {
@@ -580,7 +580,7 @@ Info->10`[1:] {
 		`
 for a in [1,2] {
   for b in [1,2,3,"Hans", 4] {
-    log("Info", "->", a, "-", b)
+    testlog("Info", "->", a, "-", b)
   }
 }
 	   `, vs,
@@ -602,7 +602,7 @@ loop
           string: 'Hans'
           number: 4
       statements
-        identifier: log
+        identifier: testlog
           funccall
             string: 'Info'
             string: '->'
@@ -618,7 +618,7 @@ loop
 
 	if vs.String() != `
 GlobalScope {
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:2 Pos:1) {
         a (float64) : 2
         block: loop (Line:3 Pos:3) {
@@ -652,12 +652,12 @@ Info->2-4`[1:] {
 		`
 l := [1,2,3,4]
 for a in range(0, 3, 1) {
-  log("Info", "-a>", a, "-", l[a])
+  testlog("Info", "-a>", a, "-", l[a])
 }
 for a in range(0, 3, 1) {
-  log("Info", "-b>", a, "-", l[-a])
+  testlog("Info", "-b>", a, "-", l[-a])
 }
-log("Info", "xxx>", l[-1])
+testlog("Info", "xxx>", l[-1])
 	   `, vs,
 		`
 statements
@@ -677,7 +677,7 @@ statements
           number: 3
           number: 1
     statements
-      identifier: log
+      identifier: testlog
         funccall
           string: 'Info'
           string: '-a>'
@@ -695,7 +695,7 @@ statements
           number: 3
           number: 1
     statements
-      identifier: log
+      identifier: testlog
         funccall
           string: 'Info'
           string: '-b>'
@@ -705,7 +705,7 @@ statements
             compaccess
               minus
                 identifier: a
-  identifier: log
+  identifier: testlog
     funccall
       string: 'Info'
       string: 'xxx>'
@@ -723,7 +723,7 @@ statements
 	if vs.String() != `
 GlobalScope {
     l ([]interface {}) : [1,2,3,4]
-    log (*interpreter.TestLogger) : TestLogger
+    testlog (*interpreter.TestLogger) : TestLogger
     block: loop (Line:3 Pos:1) {
         a (float64) : 3
     }
@@ -758,7 +758,7 @@ Infoxxx>4`[1:] {
 		`
 x := { "c": 0, "a":2, "b":4}
 for [a, b] in x {
-  log("Info", "->", a, "-", b)
+  testlog("Info", "->", a, "-", b)
 }
 	   `, vs,
 		`
@@ -782,7 +782,7 @@ statements
         identifier: b
       identifier: x
     statements
-      identifier: log
+      identifier: testlog
         funccall
           string: 'Info'
           string: '->'

scope/varsscope.go

@@ -44,7 +44,19 @@ NewScopeWithParent creates a new variable scope with a parent. This can be
 used to create scope structures without children links.
 */
 func NewScopeWithParent(name string, parent parser.Scope) parser.Scope {
-	return &varsScope{name, parent, nil, make(map[string]interface{}), sync.RWMutex{}}
+	res := &varsScope{name, nil, nil, make(map[string]interface{}), sync.RWMutex{}}
+	SetParentOfScope(res, parent)
+	return res
+}
+
+/*
+SetParentOfScope sets the parent of a given scope. This assumes that the given scope
+is a varsScope.
+*/
+func SetParentOfScope(scope parser.Scope, parent parser.Scope) {
+	if vs, ok := scope.(*varsScope); ok {
+		vs.parent = parent
+	}
 }
 
 /*

util/logging.go

@@ -37,21 +37,21 @@ func NewMemoryLogger(size int) *MemoryLogger {
 /*
 LogError adds a new error log message.
 */
-func (ml *MemoryLogger) LogError(p *Processor, m ...interface{}) {
+func (ml *MemoryLogger) LogError(m ...interface{}) {
 	ml.RingBuffer.Add(fmt.Sprintf("error: %v", fmt.Sprint(m...)))
 }
 
 /*
 LogInfo adds a new info log message.
 */
-func (ml *MemoryLogger) LogInfo(p *Processor, m ...interface{}) {
-	ml.RingBuffer.Add(fmt.Sprintf("info: %v", fmt.Sprint(m...)))
+func (ml *MemoryLogger) LogInfo(m ...interface{}) {
+	ml.RingBuffer.Add(fmt.Sprintf("%v", fmt.Sprint(m...)))
 }
 
 /*
 LogDebug adds a new debug log message.
 */
-func (ml *MemoryLogger) LogDebug(p *Processor, m ...interface{}) {
+func (ml *MemoryLogger) LogDebug(m ...interface{}) {
 	ml.RingBuffer.Add(fmt.Sprintf("debug: %v", fmt.Sprint(m...)))
 }
 
@@ -105,22 +105,22 @@ func NewStdOutLogger() *StdOutLogger {
 /*
 LogError adds a new error log message.
 */
-func (sl *StdOutLogger) LogError(p *Processor, m ...interface{}) {
+func (sl *StdOutLogger) LogError(m ...interface{}) {
 	sl.stdlog(fmt.Sprintf("error: %v", fmt.Sprint(m...)))
 }
 
 /*
 LogInfo adds a new info log message.
 */
-func (sl *StdOutLogger) LogInfo(p *Processor, m ...interface{}) {
-	sl.stdlog(fmt.Sprintf("error: %v", fmt.Sprint(m...)))
+func (sl *StdOutLogger) LogInfo(m ...interface{}) {
+	sl.stdlog(fmt.Sprintf("%v", fmt.Sprint(m...)))
 }
 
 /*
 LogDebug adds a new debug log message.
 */
-func (sl *StdOutLogger) LogDebug(p *Processor, m ...interface{}) {
-	sl.stdlog(fmt.Sprintf("error: %v", fmt.Sprint(m...)))
+func (sl *StdOutLogger) LogDebug(m ...interface{}) {
+	sl.stdlog(fmt.Sprintf("debug: %v", fmt.Sprint(m...)))
 }
 
 /*
@@ -139,17 +139,17 @@ func NewNullLogger() *NullLogger {
 /*
 LogError adds a new error log message.
 */
-func (nl *NullLogger) LogError(p *Processor, m ...interface{}) {
+func (nl *NullLogger) LogError(m ...interface{}) {
 }
 
 /*
 LogInfo adds a new info log message.
 */
-func (nl *NullLogger) LogInfo(p *Processor, m ...interface{}) {
+func (nl *NullLogger) LogInfo(m ...interface{}) {
 }
 
 /*
 LogDebug adds a new debug log message.
 */
-func (nl *NullLogger) LogDebug(p *Processor, m ...interface{}) {
+func (nl *NullLogger) LogDebug(m ...interface{}) {
 }

util/logging_test.go

@@ -19,23 +19,23 @@ func TestLogging(t *testing.T) {
 
 	ml := NewMemoryLogger(5)
 
-	ml.LogDebug(nil, "test")
-	ml.LogInfo(nil, "test")
+	ml.LogDebug("test")
+	ml.LogInfo("test")
 
 	if ml.String() != `debug: test
-info: test` {
+test` {
 		t.Error("Unexpected result:", ml.String())
 		return
 	}
 
-	if res := fmt.Sprint(ml.Slice()); res != "[debug: test info: test]" {
+	if res := fmt.Sprint(ml.Slice()); res != "[debug: test test]" {
 		t.Error("Unexpected result:", res)
 		return
 	}
 
 	ml.Reset()
 
-	ml.LogError(nil, "test1")
+	ml.LogError("test1")
 
 	if res := fmt.Sprint(ml.Slice()); res != "[error: test1]" {
 		t.Error("Unexpected result:", res)