* Add a level 1 assertion to verify that request is non-empty

  #296

* Compute this at runtime not just eval
* Update the log analyzer to store assertions in the traces.

app/pkg/agent/agent.go

@@ -2,6 +2,7 @@ package agent
 
 import (
  "context"
+ "github.com/jlewi/foyle/app/pkg/runme/ulid"
  "io"
  "strings"
  "sync"
@@ -150,8 +151,9 @@ func (a *Agent) completeWithRetries(ctx context.Context, req *v1alpha1.GenerateR
  })
  }
  for try := 0; try < maxTries; try++ {
+ docText := t.Text()
  args := promptArgs{
- Document: t.Text(),
+ Document: docText,
  Examples: exampleArgs,
  }
 
@@ -174,6 +176,19 @@ func (a *Agent) completeWithRetries(ctx context.Context, req *v1alpha1.GenerateR
  return nil, errors.Wrapf(err, "CreateChatCompletion failed")
  }
 
+ // Level1 assertion that docText is a non-empty string
+ assertion := &v1alpha1.Assertion{
+ Name: logs.Level1Assertion,
+ Result: v1alpha1.AssertResult_PASSED,
+ Id: ulid.GenerateID(),
+ }
+
+ if len(strings.TrimSpace(docText)) == 0 {
+ assertion.Result = v1alpha1.AssertResult_FAILED
+ }
+
+ log.Info(logs.Level1Assertion, "assertion", assertion)
+
  return blocks, nil
  }
  err := errors.Errorf("Failed to generate a chat completion after %d tries", maxTries)

app/pkg/analyze/analyzer.go

@@ -742,12 +742,14 @@ func combineEntriesForTrace(ctx context.Context, entries []*api.LogEntry) (*logs
 }
 
 func combineGenerateTrace(ctx context.Context, entries []*api.LogEntry) (*logspb.Trace, error) {
+ log := logs.FromContext(ctx)
  gTrace := &logspb.GenerateTrace{}
  trace := &logspb.Trace{
  Data: &logspb.Trace_Generate{
  Generate: gTrace,
  },
- Spans: make([]*logspb.Span, 0, 10),
+ Spans: make([]*logspb.Span, 0, 10),
+ Assertions: make([]*v1alpha1.Assertion, 0),
  }
  evalMode := false
  for _, e := range entries {
@@ -764,6 +766,16 @@ func combineGenerateTrace(ctx context.Context, entries []*api.LogEntry) (*logspb
  }
  }
 
+ if e.Message() == logs.Level1Assertion {
+ assertion := &v1alpha1.Assertion{}
+ if !e.GetProto("assertion", assertion) {
+ log.Error(errors.New("Failed to decode assertion"), "Failed to decode assertion", "entry", e)
+ continue
+ }
+ trace.Assertions = append(trace.Assertions, assertion)
+ continue
+ }
+
  if gTrace.Request == nil && strings.HasSuffix(e.Function(), "agent.(*Agent).Generate") {
  raw := e.Request()
  if raw != nil {

app/pkg/analyze/analyzer_test.go

@@ -4,6 +4,9 @@ import (
  "context"
  "database/sql"
  "encoding/json"
+ "github.com/go-logr/logr"
+ "github.com/go-logr/zapr"
+ "github.com/jlewi/foyle/app/pkg/logs"
  "io"
  "os"
  "path/filepath"
@@ -403,18 +406,43 @@ func waitForBlock(t *testing.T, blockId string, numExpected int, blockProccessed
  }()
 }
 
+func assertHasAssertion(t *logspb.Trace) string {
+ if len(t.Assertions) == 0 {
+ return "Expected trace to have at least 1 assertion"
+ }
+ return ""
+}
+
+type assertTrace func(t *logspb.Trace) string
+
 func Test_CombineGenerateEntries(t *testing.T) {
  type testCase struct {
- name string
- linesFile string
+ name string
+ linesFile string
+ // Optional function to generate some logs to
+ logFunc func(log logr.Logger)
  expectedEvalMode bool
+
+ assertions []assertTrace
  }
 
  cases := []testCase{
  {
  name: "basic",
  linesFile: "generate_trace_lines.jsonl",
  expectedEvalMode: false,
+ logFunc: func(log logr.Logger) {
+ assertion := &v1alpha1.Assertion{
+ Name: "testassertion",
+ Result: v1alpha1.AssertResult_PASSED,
+ Detail: "",
+ Id: "1234",
+ }
+ log.Info(logs.Level1Assertion, "assertion", assertion)
+ },
+ assertions: []assertTrace{
+ assertHasAssertion,
+ },
  },
  {
  name: "evalMode",
@@ -430,21 +458,66 @@ func Test_CombineGenerateEntries(t *testing.T) {
  for _, c := range cases {
  t.Run(c.name, func(t *testing.T) {
  entries := make([]*api.LogEntry, 0, 10)
- testFile, err := os.Open(filepath.Join(cwd, "test_data", c.linesFile))
- if err != nil {
- t.Fatalf("Failed to open test file: %v", err)
+
+ logFiles := []string{
+ filepath.Join(cwd, "test_data", c.linesFile),
+ }
+
+ if c.logFunc != nil {
+ // Create a logger to write the logs to a file
+ f, err := os.CreateTemp("", "testlogs.jsonl")
+ if err != nil {
+ t.Fatalf("Failed to create temp file: %v", err)
+ }
+ logFile := f.Name()
+ if err := f.Close(); err != nil {
+ t.Fatalf("Failed to close file: %v", err)
+ }
+
+ t.Log("Log file:", logFile)
+
+ config := zap.NewProductionConfig()
+ // N.B. This needs to be kept in sync with the fields set in app.go otherwise our test won't use
+ // the same fields as in production.
+ config.OutputPaths = []string{f.Name()}
+ config.EncoderConfig.LevelKey = "severity"
+ config.EncoderConfig.TimeKey = "time"
+ config.EncoderConfig.MessageKey = "message"
+ // We attach the function key to the logs because that is useful for identifying the function that generated the log.
+ config.EncoderConfig.FunctionKey = "function"
+
+ logFiles = append(logFiles, logFile)
+
+ testLog, err := config.Build()
+ if err != nil {
+ t.Fatalf("Failed to create logger: %v", err)
+ }
+
+ zTestLog := zapr.NewLogger(testLog)
+
+ c.logFunc(zTestLog)
+
+ testLog.Sync()
+
  }
- d := json.NewDecoder(testFile)
- for {
- e := &api.LogEntry{}
- err := d.Decode(e)
+
+ for _, logFile := range logFiles {
+ testFile, err := os.Open(logFile)
  if err != nil {
- if err == io.EOF {
- break
+ t.Fatalf("Failed to open test file: %v", err)
+ }
+ d := json.NewDecoder(testFile)
+ for {
+ e := &api.LogEntry{}
+ err := d.Decode(e)
+ if err != nil {
+ if err == io.EOF {
+ break
+ }
+ t.Fatalf("Failed to unmarshal log entry: %v", err)
  }
- t.Fatalf("Failed to unmarshal log entry: %v", err)
+ entries = append(entries, e)
  }
- entries = append(entries, e)
  }
  trace, err := combineGenerateTrace(context.Background(), entries)
  if err != nil {
@@ -469,6 +542,12 @@ func Test_CombineGenerateEntries(t *testing.T) {
  if trace.EvalMode != c.expectedEvalMode {
  t.Errorf("Expected EvalMode to be %v but got %v", c.expectedEvalMode, trace.EvalMode)
  }
+
+ for _, assert := range c.assertions {
+ if msg := assert(trace); msg != "" {
+ t.Errorf(msg)
+ }
+ }
  })
  }
 }

app/pkg/logs/logs.go

@@ -21,6 +21,9 @@ const (
 
  // Debug is for debug verbosity level
  Debug = 1
+
+ // Level1Assertion Message denoting a level1 assertion
+ Level1Assertion = "Level1Assert"
 )
 
 // FromContext returns a logr.Logger from the context or an instance of the global logger

protos/foyle/logs/traces.proto

@@ -2,6 +2,7 @@ syntax = "proto3";
 
 import "foyle/logs/logs.proto";
 import "foyle/v1alpha1/agent.proto";
+import "foyle/v1alpha1/eval.proto";
 import "foyle/v1alpha1/providers.proto";
 import "foyle/v1alpha1/trainer.proto";
 import "foyle/logs/blocks.proto";
@@ -30,6 +31,10 @@ message Trace {
 
  repeated Span spans = 8;
 
+ // Assertions about this trace.
+ // Should these be properties of the spans? We'll cross that bridge if we come to it.
+ repeated Assertion assertions = 9;
+
  reserved 5,7;
 }
 

protos/foyle/v1alpha1/eval.proto

@@ -87,6 +87,11 @@ message Assertion {
  AssertResult result = 2;
  // Human readable detail of the assertion. If there was an error this should contain the error message.
  string detail = 3;
+
+ // id is a unique id of the assertion. This is needed for real time processing of the logs. Since our log
+ // processing guarantees at least once semantics, we may end up processing the same log entry about an assertion
+ // multiple times. By assigning a unique id to each assertion we can dedupe them.
+ string id = 4;
 }
 
 message EvalResultListRequest {