diff --git a/app/pkg/analyze/analyzer.go b/app/pkg/analyze/analyzer.go index 88fba7c..6f151ae 100644 --- a/app/pkg/analyze/analyzer.go +++ b/app/pkg/analyze/analyzer.go @@ -67,7 +67,7 @@ type Analyzer struct { watcher *fsnotify.Watcher - learnNotifier PostBlockEvent + learnNotifier PostSessionEvent handleLogFileIsDone sync.WaitGroup handleBlocksIsDone sync.WaitGroup @@ -152,13 +152,13 @@ type blockItem struct { id string } -// PostBlockEvent interface for functions to post block events. -type PostBlockEvent func(id string) error +// PostSessionEvent interface for functions to post session events. +type PostSessionEvent func(id string) error // Run runs the analyzer; continually processing logs. // learnNotifier is an optional function that will be called when a block is updated. // This should be non blocking. -func (a *Analyzer) Run(ctx context.Context, logDirs []string, learnNotifier PostBlockEvent) error { +func (a *Analyzer) Run(ctx context.Context, logDirs []string, learnNotifier PostSessionEvent) error { a.learnNotifier = learnNotifier // Find all the current files jsonFiles, err := findLogFilesInDirs(ctx, logDirs) @@ -276,7 +276,7 @@ func (a *Analyzer) processLogFile(ctx context.Context, path string) error { } // Add the entry to a session if it should be. - a.sessBuilder.processLogEntry(entry) + a.sessBuilder.processLogEntry(entry, a.learnNotifier) if matchers.IsLogEvent(entry.Function()) { a.processLogEvent(ctx, entry) diff --git a/app/pkg/analyze/session_builder.go b/app/pkg/analyze/session_builder.go index 249a082..3351666 100644 --- a/app/pkg/analyze/session_builder.go +++ b/app/pkg/analyze/session_builder.go @@ -29,12 +29,12 @@ func NewSessionBuilder(sessions *SessionsManager) (*sessionBuilder, error) { // n.b. processLogEntry doesn't return a error because we expect errors to be ignored and for processing to continue. // I'm not sure that's a good idea but we'll see. -func (p *sessionBuilder) processLogEntry(entry *api.LogEntry) { +func (p *sessionBuilder) processLogEntry(entry *api.LogEntry, notifier PostSessionEvent) { // We need to use HasPrefix because the logging statement is nested inside an anonymous function so there // will be a suffix like "func1" if matchers.IsLogEvent(entry.Function()) { // TODO(Jeremy): There is also Analyzer.processLogEvent - p.processLogEvent(entry) + p.processLogEvent(entry, notifier) } if matchers.IsLLMUsage(entry.Function()) { @@ -50,7 +50,7 @@ func (p *sessionBuilder) processLogEntry(entry *api.LogEntry) { } } -func (p *sessionBuilder) processLogEvent(entry *api.LogEntry) { +func (p *sessionBuilder) processLogEvent(entry *api.LogEntry, notifier PostSessionEvent) { log := zapr.NewLogger(zap.L()) event := &v1alpha1.LogEvent{} @@ -71,6 +71,13 @@ func (p *sessionBuilder) processLogEvent(entry *api.LogEntry) { if err := p.sessions.Update(context.Background(), event.GetContextId(), updateFunc); err != nil { log.Error(err, "Failed to update session", "event", event) + return + } + + if event.Type == v1alpha1.LogEventType_SESSION_END { + if err := notifier(event.GetContextId()); err != nil { + log.Error(err, "Failed to send session process event") + } } } diff --git a/app/pkg/analyze/session_builder_test.go b/app/pkg/analyze/session_builder_test.go index e6b7f1f..0d442bb 100644 --- a/app/pkg/analyze/session_builder_test.go +++ b/app/pkg/analyze/session_builder_test.go @@ -3,6 +3,7 @@ package analyze import ( "context" "database/sql" + "fmt" "os" "path/filepath" "testing" @@ -70,6 +71,12 @@ func setup() (testTuple, error) { }, nil } +// Process the log entry +func testNotifier(contextId string) error { + fmt.Printf("Received session end event for context: %v", contextId) + return nil +} + func Test_ProcessLogEvent(t *testing.T) { tuple, err := setup() if err != nil { @@ -101,8 +108,7 @@ func Test_ProcessLogEvent(t *testing.T) { "event": logs.ZapProto("event", event).Interface, } - // Process the log entry - tuple.p.processLogEvent(entry) + tuple.p.processLogEvent(entry, testNotifier) s, err := tuple.sessions.Get(context.Background(), event.GetContextId()) if err != nil { @@ -154,7 +160,7 @@ func Test_ProcessStreamGenerate(t *testing.T) { } // Process the log entry - tuple.p.processLogEntry(entry) + tuple.p.processLogEntry(entry, testNotifier) s, err := tuple.sessions.Get(context.Background(), contextId) if err != nil { diff --git a/app/pkg/application/app.go b/app/pkg/application/app.go index 92417c3..d47d811 100644 --- a/app/pkg/application/app.go +++ b/app/pkg/application/app.go @@ -411,7 +411,7 @@ func (a *App) SetupLearner() (*learn.Learner, error) { if err != nil { return nil, err } - return learn.NewLearner(*a.Config, client, a.LockingBlocksDB) + return learn.NewLearner(*a.Config, client, a.sessionsManager) } func (a *App) createComponents() error { diff --git a/app/pkg/learn/learner.go b/app/pkg/learn/learner.go index 0a2a254..fc8dc9e 100644 --- a/app/pkg/learn/learner.go +++ b/app/pkg/learn/learner.go @@ -7,6 +7,11 @@ import ( "strings" "sync" + "github.com/jlewi/foyle/app/pkg/analyze" + "github.com/jlewi/foyle/app/pkg/runme/converters" + logspb "github.com/jlewi/foyle/protos/go/foyle/logs" + parserv1 "github.com/stateful/runme/v3/pkg/api/gen/proto/go/runme/parser/v1" + "github.com/jlewi/foyle/app/pkg/docs" "github.com/prometheus/client_golang/prometheus" @@ -15,11 +20,8 @@ import ( "github.com/jlewi/monogo/files" "github.com/jlewi/monogo/helpers" - "github.com/jlewi/foyle/app/pkg/dbutil" "k8s.io/client-go/util/workqueue" - logspb "github.com/jlewi/foyle/protos/go/foyle/logs" - "github.com/jlewi/foyle/app/pkg/config" "github.com/jlewi/foyle/app/pkg/logs" "github.com/jlewi/foyle/app/pkg/oai" @@ -39,10 +41,10 @@ var ( Help: "Total number of enqueued blocks", }) - cellsProcessed = promauto.NewCounterVec( + sessProcessed = promauto.NewCounterVec( prometheus.CounterOpts{ - Name: "learner_blocks_processed", - Help: "Number of blocks processed by the learner", + Name: "learner_sessions_processed", + Help: "Number of sessions processed by the learner", }, []string{"status"}, ) @@ -54,7 +56,7 @@ var ( type Learner struct { Config config.Config client *openai.Client - blocksDB *dbutil.LockingDB[*logspb.BlockLog] + sessions *analyze.SessionsManager queue workqueue.DelayingInterface postFunc PostLearnEvent eventLoopIsDone sync.WaitGroup @@ -62,16 +64,20 @@ type Learner struct { vectorizer *oai.Vectorizer } -func NewLearner(cfg config.Config, client *openai.Client, blocksDB *dbutil.LockingDB[*logspb.BlockLog]) (*Learner, error) { +func NewLearner(cfg config.Config, client *openai.Client, sessions *analyze.SessionsManager) (*Learner, error) { if client == nil { return nil, errors.New("OpenAI client is required") } + if sessions == nil { + return nil, errors.New("SessionsManager is required") + } + vectorizer := oai.NewVectorizer(client) return &Learner{ Config: cfg, client: client, - blocksDB: blocksDB, + sessions: sessions, queue: workqueue.NewDelayingQueue(), factory: &files.Factory{}, vectorizer: vectorizer, @@ -142,87 +148,133 @@ func (l *Learner) Shutdown(ctx context.Context) error { return nil } -// Reconcile learns from the block with the given id +// Reconcile learns from the session with the given id func (l *Learner) Reconcile(ctx context.Context, id string) error { log := logs.FromContext(ctx) - b, err := l.blocksDB.Get(id) + session, err := l.sessions.Get(ctx, id) if err != nil { - return errors.Wrapf(err, "Failed to retrieve block %s", id) + sessProcessed.WithLabelValues("nosession").Inc() + return errors.Wrapf(err, "Unable to learn from session %s; failed to retrieve session", id) } - if b.ExecutedBlock == nil { - // Skip unexecuted block - cellsProcessed.WithLabelValues("unexecuted").Inc() - return nil + // Make sure there is a cell execution log event. + // Right now we rely on the cell execution log event to get the actual cell content. + // So we can't learn from sessions without cell execution events. TN013 has some ideas for how we could + // learn in the event of non cell execution events. + var execEvent *v1alpha1.LogEvent + for _, event := range session.LogEvents { + if event.GetType() != v1alpha1.LogEventType_EXECUTE { + continue + } + + // We don't want to learn from failed events. + if event.ExecuteStatus != v1alpha1.LogEvent_SUCCEEDED { + continue + } + + // We want to learn from the final successful event. + execEvent = event } - if b.GeneratedBlock == nil { - // Block wasn't the result of AI generation - cellsProcessed.WithLabelValues("notgenerated").Inc() + if execEvent == nil { + // Since the cell wasn't successfully executed we don't learn from it + sessProcessed.WithLabelValues("noexec").Inc() return nil } - if b.EvalMode { - log.V(logs.Debug).Info("Skipping block which was created as part of an eval", "id", b.GetId()) - cellsProcessed.WithLabelValues("eval").Inc() - return nil + if session.GetFullContext() == nil { + sessProcessed.WithLabelValues("nocontext").Inc() + return errors.Errorf("Unable to learn from session %s; session has no context", session.GetContextId()) + } + + if session.GetFullContext().GetNotebook() == nil { + sessProcessed.WithLabelValues("nonotebook").Inc() + return errors.Errorf("Unable to learn from session %s; session has no notebook", session.GetContextId()) } - // TODO(jeremy): Should we use some sort of distance metric? e.g. edit distance? We could potentially - // Use the metric used for eval. - if strings.TrimSpace(b.ExecutedBlock.GetContents()) == strings.TrimSpace(b.GeneratedBlock.GetContents()) { - log.V(logs.Debug).Info("Skipping executed block which matches generated block", "id", b.GetId()) - cellsProcessed.WithLabelValues("nochange").Inc() + if session.GetFullContext().GetSelected() == 0 { + // If its the first cell we can't learn from it because what would we use as context to predict it? + sessProcessed.WithLabelValues("firstcell").Inc() return nil } - cellsProcessed.WithLabelValues("learn").Inc() - expectedFiles := l.getExampleFiles(b.GetId()) + sessProcessed.WithLabelValues("learn").Inc() + expectedFiles := l.getExampleFiles(session.GetContextId()) - log.Info("Found new training example", "blockId", b.GetId()) + log.Info("Found new training example", "sessionId", session.GetContextId()) if len(expectedFiles) == 0 { - cellsProcessed.WithLabelValues("noExampleFiles").Inc() - log.Error(err, "No training files found", "blockId", b.GetId()) - return errors.Wrapf(err, "No training files found for example %s", b.GetId()) + sessProcessed.WithLabelValues("noExampleFiles").Inc() + log.Error(err, "No training files found", "sessionId", session.GetContextId()) + return errors.Wrapf(err, "No training files found for example %s", session.GetContextId()) } - // TODO(jeremy): Should we take into account execution status when looking for mistakes? + var executedCell *parserv1.Cell + var execID string + for _, c := range execEvent.Cells { + execID = converters.GetCellID(c) + if execID == "" { + // I don't think this should happen + sessProcessed.WithLabelValues("cellnoid").Inc() + continue + } + if execID == execEvent.GetSelectedId() { + executedCell = c + } + } - // Deep copy the original message - newBlock := proto.Clone(b.ExecutedBlock).(*v1alpha1.Block) - answer := []*v1alpha1.Block{newBlock} + if executedCell == nil { + sessProcessed.WithLabelValues("noexeccell").Inc() + return errors.Errorf("Could not learn from session %s; the executed cell couldn't be found in the session", session.GetContextId()) + } - req := &v1alpha1.GenerateRequest{ - Doc: b.Doc, - SelectedIndex: int32(len(b.Doc.Blocks) - 1), + executedBlock, err := converters.CellToBlock(executedCell) + if err != nil { + log.Error(err, "Failed to convert cell to block", "sessionId", session.GetContextId(), "cellId", execID) + return errors.Wrapf(err, "Could not learn from session: %s; Could not convert cell to block", session.GetContextId()) } - queryBlocks, err := docs.CreateQuery(ctx, req) - newDoc := &v1alpha1.Doc{ - Blocks: queryBlocks, + // Make sure the executed block is not the empty string + executedBlock.Contents = strings.TrimSpace(executedBlock.Contents) + + if executedBlock.Contents == "" { + sessProcessed.WithLabelValues("emptyblock").Inc() + return errors.Errorf("Could not learn from session %s; the executed block is empty", session.GetContextId()) } + req, err := sessionToQuery(session) + if err != nil { + return errors.Wrapf(err, "Could not learn from session %s; Could not convert session to query", session.GetContextId()) + } + + queryBlocks, err := docs.CreateQuery(ctx, req) + if err != nil { - log.Error(err, "Failed to create query", "exampleId", b.GetId()) - return errors.Wrapf(err, "Failed to create query for example %s", b.GetId()) + log.Error(err, "Failed to create query", "exampleId", session.GetContextId()) + return errors.Wrapf(err, "Failed to create query for example %s", session.GetContextId()) + } + + newDoc := &v1alpha1.Doc{ + Blocks: queryBlocks, } example := &v1alpha1.Example{ - Id: b.GetId(), + Id: session.GetContextId(), Query: newDoc, - Answer: answer, + Answer: []*v1alpha1.Block{executedBlock}, } + exampleId := session.GetContextId() + if err := l.computeEmbeddings(ctx, example); err != nil { - return errors.Wrapf(err, "Failed to compute embeddings for example %s", b.GetId()) + return errors.Wrapf(err, "Failed to compute embeddings for example %s", exampleId) } encoded, err := proto.Marshal(example) if err != nil { - log.Error(err, "Failed to serialize doc", "id", b.GetId()) - return errors.Wrapf(err, "Failed to serialize doc %s", b.GetId()) + log.Error(err, "Failed to serialize doc", "id", exampleId) + return errors.Wrapf(err, "Failed to serialize doc %s", exampleId) } writeErrors := &helpers.ListOfErrors{} @@ -237,27 +289,27 @@ func (l *Learner) Reconcile(ctx context.Context, id string) error { } w, err := helper.NewWriter(expectedFile) if err != nil { - return errors.Wrapf(err, "Failed to create writer for example %s; to file %s", b.GetId(), expectedFile) + return errors.Wrapf(err, "Failed to create writer for example %s; to file %s", exampleId, expectedFile) } if closer, ok := w.(io.Closer); ok { defer closer.Close() } if _, err := w.Write(encoded); err != nil { - return errors.Wrapf(err, "Failed to write example %s; to file %s", b.GetId(), expectedFile) + return errors.Wrapf(err, "Failed to write example %s; to file %s", exampleId, expectedFile) } return nil }() if writeErr != nil { // We need to log the individual error here so that its stack trace gets logged - log.Error(err, "Failed to write example", "id", b.GetId(), "file", expectedFile) + log.Error(err, "Failed to write example", "id", exampleId, "file", expectedFile) writeErrors.AddCause(writeErr) continue } // All post a single file because we don't need to read it multiple times if !posted && l.postFunc != nil { if err := l.postFunc(expectedFile); err != nil { - return errors.Wrapf(err, "Failed to post learn event for example %s", b.GetId()) + return errors.Wrapf(err, "Failed to post learn event for example %s", exampleId) } posted = true } @@ -276,7 +328,7 @@ func (l *Learner) getExampleFiles(id string) []string { for _, d := range l.Config.GetTrainingDirs() { h, err := l.factory.GetDirHelper(d) if err != nil { - log.Error(err, "Unable to DirHelper", "dir", d) + log.Error(err, "Unable to get DirHelper", "dir", d) continue } paths = append(paths, h.Join(d, fmt.Sprintf("%s%s", id, fileSuffix))) @@ -307,3 +359,33 @@ func (l *Learner) computeEmbeddings(ctx context.Context, example *v1alpha1.Examp example.Embedding = qVec return nil } + +func sessionToQuery(session *logspb.Session) (*v1alpha1.GenerateRequest, error) { + if session.GetFullContext() == nil { + return nil, errors.Errorf("Unable to learn from session %s; session has no context", session.GetContextId()) + } + if session.GetFullContext().GetNotebook() == nil { + return nil, errors.Errorf("Unable to learn from session %s; session has no notebook", session.GetContextId()) + } + + doc, err := converters.NotebookToDoc(session.GetFullContext().GetNotebook()) + if err != nil { + return nil, errors.Wrapf(err, "Could not learn from session %s; Could not convert notebook to doc", session.GetContextId()) + } + + // We need to truncate the doc to only include the blocks up to the selected index + if session.GetFullContext().GetSelected() == 0 { + return nil, errors.Errorf("Unable to learn from session %s; because the selected cell is the first in the doc", session.GetContextId()) + } + + // We need to remove the last block from the doc. Because the last block in the doc i.e. the selected block + // is actually what we want to predict + doc.Blocks = doc.Blocks[:session.GetFullContext().GetSelected()] + selectedIndex := len(doc.Blocks) - 1 + req := &v1alpha1.GenerateRequest{ + Doc: doc, + SelectedIndex: int32(selectedIndex), + } + + return req, nil +} diff --git a/app/pkg/learn/learner_test.go b/app/pkg/learn/learner_test.go index 6272e92..67ecb04 100644 --- a/app/pkg/learn/learner_test.go +++ b/app/pkg/learn/learner_test.go @@ -2,10 +2,18 @@ package learn import ( "context" + "database/sql" "os" "testing" - "github.com/cockroachdb/pebble" + "github.com/google/go-cmp/cmp" + "github.com/google/go-cmp/cmp/cmpopts" + "github.com/jlewi/foyle/app/pkg/testutil" + logspb "github.com/jlewi/foyle/protos/go/foyle/logs" + "github.com/jlewi/foyle/protos/go/foyle/v1alpha1" + "github.com/jlewi/monogo/helpers" + parserv1 "github.com/stateful/runme/v3/pkg/api/gen/proto/go/runme/parser/v1" + "github.com/jlewi/foyle/app/pkg/analyze" "github.com/jlewi/foyle/app/pkg/config" @@ -30,26 +38,86 @@ func Test_Learner(t *testing.T) { } cfg := config.GetConfig() - blocksDB, err := pebble.Open(cfg.GetBlocksDBDir(), &pebble.Options{}) + // If the directory doesn't exit opening the SQLLite database will fail. + sessionsDBFile := cfg.GetSessionsDB() + db, err := sql.Open(analyze.SQLLiteDriver, sessionsDBFile) + defer helpers.DeferIgnoreError(db.Close) if err != nil { - t.Fatalf("could not open blocks database %+v", cfg.GetBlocksDBDir()) + t.Fatalf("Failed to open database: %v", cfg.GetSessionsDB()) + } + sessions, err := analyze.NewSessionsManager(db) + if err != nil { + t.Fatalf("Error creating sessions manager; %v", err) } - defer blocksDB.Close() - - lockingBlocksDB := analyze.NewLockingBlocksDB(blocksDB) client, err := oai.NewClient(*cfg) if err != nil { t.Fatalf("Error creating OpenAI client; %v", err) } - l, err := NewLearner(*cfg, client, lockingBlocksDB) + l, err := NewLearner(*cfg, client, sessions) if err != nil { t.Fatalf("Error creating learner; %v", err) } - id := "01J02Q18HFMGVY1H50H79BN7X6" + id := "01JD88ZCBD72YPBKVH8CAMC3MT" if err := l.Reconcile(context.Background(), id); err != nil { t.Fatalf("Error reconciling; %v", err) } } + +func Test_sessionToQuery(t *testing.T) { + type testCase struct { + name string + session *logspb.Session + expected *v1alpha1.GenerateRequest + } + + testCases := []testCase{ + { + // We want to make sure the selected cell isn't in the query + name: "simple", + session: &logspb.Session{ + FullContext: &v1alpha1.FullContext{ + Notebook: &parserv1.Notebook{ + Cells: []*parserv1.Cell{ + { + Value: "Cell 1", + Kind: parserv1.CellKind_CELL_KIND_MARKUP, + }, + { + Value: "Cell 2", + Kind: parserv1.CellKind_CELL_KIND_MARKUP, + }, + }, + }, + Selected: 1, + }, + }, + expected: &v1alpha1.GenerateRequest{ + Doc: &v1alpha1.Doc{ + Blocks: []*v1alpha1.Block{ + { + Kind: v1alpha1.BlockKind_MARKUP, + Contents: "Cell 1", + Outputs: []*v1alpha1.BlockOutput{}, + }, + }, + }, + SelectedIndex: 0, + }, + }, + } + + for _, c := range testCases { + t.Run(c.name, func(t *testing.T) { + actual, err := sessionToQuery(c.session) + if err != nil { + t.Fatalf("Error: %v", err) + } + if d := cmp.Diff(c.expected, actual, testutil.DocComparer, cmpopts.IgnoreUnexported(v1alpha1.GenerateRequest{})); d != "" { + t.Fatalf("Diff:\n%v", d) + } + }) + } +} diff --git a/docs/content/en/docs/operator-manual/troubleshoot_learning.md b/docs/content/en/docs/operator-manual/troubleshoot_learning.md index 640d26a..8175672 100644 --- a/docs/content/en/docs/operator-manual/troubleshoot_learning.md +++ b/docs/content/en/docs/operator-manual/troubleshoot_learning.md @@ -26,109 +26,33 @@ If there aren't any then no examples have been learned. ## Trigger Learning -Foyle's learning is triggered by the following sequence of actions: +Foyle's learning is triggered whenever a cell is successfully executed. -1. Foyle generates a suggested cell which is added to the notebook as a Ghost Cell -2. You accept the suggested cell by putting the focus on the cell -3. You edit the cell -4. You execute the cell +Every time you switch the cell in focus, Foyle creates a new session. +The current session ID is displayed in the lower right hand context window +in vscode. -When you execute the cell, the execution is logged to Foyle. For each executed cell Foyle checks +You can use the session ID to track whether learning occured. -1. Was that cell generated by Foyle -2. If the cell was generated by Foyle did the actual command executed differ from the suggested command -3. If the cell was changed by the user than Foyle attempts to learn from that execution +## Did The Session Get Created -Crucially, every cell created by Foyle is assigned an ID. This ID can be used to track how the cell was generated and if learning occurred. - -To get the cell ID for a given cell - -1. Open the raw markdown file by right clicking on it in VSCode and selecting `Open With` -> `Text Editor` -2. Find code block containing your cell -3. Your cell will contain metadata which contains the ID e.g. - -```sh -` ` `bash {"id":"01J6DG428ER427GJNTKC15G6JM"} -echo hello world -` ` ` -``` - -## Did Block Logs Get Created - -* Get the block logs for the cell -* Change the cell ID to the ULID of the cell (you can view this in the markdown) -* The cell should be one that was generated by the AI and you think learning should have occurred on +* Check the session log ```bash -CELLID=01J7S3QZMS5F742JFPWZDCTVRG -curl -X POST http://localhost:8877/api/foyle.logs.LogsService/GetBlockLog -H "Content-Type: application/json" -d "{\"id\": \"${CELLID}\"}" | jq . +CONTEXTID=01J7S3QZMS5F742JFPWZDCTVRG +curl -s -X POST https://foyle.gateway.admin-0s.internal.api.openai.org/api/foyle.logs.SessionsService/GetSession -H "Content-Type: application/json" -d "{\"contextId\": \"${CONTEXTID}\"}" | jq. ``` -* If this returns not found then no log was created for this cell and there is a problem with Log Processing -* The correct output should look like the following - -```json -{ - "blockLog": { - "id": "01J7KQPBYCT9VM2KFBY48JC7J0", - "genTraceId": "0376c6dc6309bcd5d61e7b56e41d6411", - "doc": { - ... - }, - "generatedBlock": { - "kind": "CODE", - "language": "bash", - "contents": "jq -c 'select(.severity == \"error\" or .level == \"error\")' ${LASTLOG}", - "id": "01J7KQPBYCT9VM2KFBY48JC7J0" - }, - "executedBlock": { - "kind": "CODE", - "contents": "CELLID=01J7KQPBYCT9VM2KFBY48JC7J0\ncurl -X POST http://localhost:8877/api/foyle.logs.LogsService/GetBlockLog -H \"Content-Type: application/json\" -d \"{\\\"id\\\": \\\"${CELLID}\\\"}\" | jq .", - "id": "01J7KQPBYCT9VM2KFBY48JC7J0" - }, - "resourceVersion": "34d933d8-abe6-4ad3-b9cf-5a2392f34abb" - } -} -``` - -* Notably the output should include the following fields - - * **generatedBlock** - This is the block that was generated by the AI - * **executedBlock** - This is the block that the user actually executed - -* If the **generatedBlock** and **executedBlock** are the same then no learning occured -* If the **generatedBlock** is missing then this means the block wasn't generated by Foyle and learning won't occur +* If this returns not found then no log was created for this sessions and there is a problem with Log Processing +* +* The output should include - * This can happen if you insert a blank cell and manually enter a command + * LogEvent for cell execution + * LogEvent for session end + * FullContext containing a notebook -* If the **executedBlock** is missing then this means the block wasn't executed and learning won't occur +* Ensure the cells all have IDs -## Was a cell executed? - -* If a block is missing the **executedBlock** then we should check the logs to see if there is an event for cell execution - -```bash -export LASTLOG=~/.foyle/logs/raw/$(ls -t ~/.foyle/logs/raw | head -n 1 ) -echo "Last log file: ${LASTLOG}" -jq -c "select(.selectedCellId == \"01J7KQPBYCT9VM2KFBY48JC7J0\")" ${LASTLOG} -``` - -* If there are no execution events then the cell was never executed -* If you executed the cell but there are no log events then there is most likely a bug and please open an issue in [GitHub](https://github.com/jlewi/foyle/issues) - -## Check the logs associated with that cell - -* We can search for all logs associated with that cell - -```bash -export LASTLOG=~/.foyle/logs/raw/$(ls -t ~/.foyle/logs/raw | head -n 1 ) -echo "Last log file: ${LASTLOG}" -jq -c "select(.blockId == \"${CELLID}\")" ${LASTLOG} -``` - -* Check for any errors processing the block -* Note that the above command will only process the most recent log file -* Each time Foyle is restarted it will create a new log file. ### Did we try to create an example from any cells? @@ -161,14 +85,6 @@ jq -c 'select(.level == "error" and .message == "Failed to write example")' ${LA jq -c 'select(.message == "Building block log")' ${LASTLOG} ``` -## Are there any errors in the logs - -* The query below should show you any errors in the logs. - -```bash -jq -c 'select(.severity == "error")' ${LASTLOG} -``` - # Check Prometheus counters Check to make sure blocks are being enqueued for learner processing @@ -182,8 +98,8 @@ curl -s http://localhost:8877/metrics | grep learner_enqueued_total Check the metrics for post processing of blocks ```bash -curl -s http://localhost:8877/metrics | grep learner_blocks_processed +curl -s http://localhost:8877/metrics | grep learner_sessions_processed ``` -* The value of `learner_blocks_processed{status="learn"}` is the number of blocks that contributed to learning -* The value of `learner_blocks_processed{status="unexecuted"}` is the number of blocks that were ignored because they were not executed +* The value of `learner_sessions_processed{status="learn"}` is the number of blocks that contributed to learning +* The value of `learner_sessions_processed{status="unexecuted"}` is the number of blocks that were ignored because they were not executed diff --git a/docs/content/en/docs/tech-notes/tn013_learnmore.md b/docs/content/en/docs/tech-notes/tn013_learnmore.md new file mode 100644 index 0000000..89e2662 --- /dev/null +++ b/docs/content/en/docs/tech-notes/tn013_learnmore.md @@ -0,0 +1,105 @@ +--- +author: '[Jeremy Lewi](https://lewi.us/about)' +date: 2024-10-20T00:00:00Z +description: Improve Learning +status: Published +title: TN013 Improve Learning +weight: 13 +--- + + +## Objective + +* Learn from all executed cells not just generated cells + +## TL;DR + +Today, learning only occurs in a small fraction of cases. In particular, the +following must be true for learning to occur + +* Code cell was generated from AI +* User edited the code cell + +This limitation was the result of relying on the GenerateRequest to log +the notebook to be used as input. + +We now have the LogEvents API and log the full notebook each time the +cell focus changes. We also LogEvents corresponding to cell executions. +This means we can use any cell execution (regardless of how it was generated) +to learn. We also log the cell execution status so we can avoid learning +from failed executions. + + +## Background + +### How does learning work today + +The Analyzer is a stream processor for the logs that produces blocklogs. When the Analyzer, +encounters an Execute event it enqueues the BlockLog for processing in the learner +([here](https://github.com/jlewi/foyle/blob/d63d18b57293010ceb0a0b1f35254aa0f5ce90aa/app/pkg/analyze/analyzer.go#L472)). + +The [Learner](https://github.com/jlewi/foyle/blob/d63d18b57293010ceb0a0b1f35254aa0f5ce90aa/app/pkg/learn/learner.go#L149) +then checks whether the BlockLog meets various criterion for learning e.g. +* Was the block generated via AI? +* Is the generated block different from the text that was actually executed? + +Importantly, in order to do learning we need to know the block (cell) that was produced and the +cells that preceded it which should be considered the input to the AI. + +Currently, the context is obtained via the GenerateRequest. The analyzer builds a GenerateTrace. +For each block that gets produced by the trace, the corresponding block log is updated with the ID +of the trace. + +[Analyzer.buildBlockLog](https://github.com/jlewi/foyle/blob/d63d18b57293010ceb0a0b1f35254aa0f5ce90aa/app/pkg/analyze/analyzer.go#L686) +fetches the Generate trace and uses it to populate [BlockLog.Doc](https://github.com/jlewi/foyle/blob/d63d18b57293010ceb0a0b1f35254aa0f5ce90aa/app/pkg/analyze/analyzer.go#L708) +with the cells that preceded the doc. + +When we originally implemented learning, the GenerateRequest was the only mechanism we had for recording the doc. This was +one of the reasons we could only do learning if the cell was generated by AI. Learning was originally implemented +before we had ghost cells and were automatically requesting completions. In this case, a generate request had to be explicitly +triggered by the user. + +We now have the [LogEvents](https://github.com/jlewi/foyle/blob/d63d18b57293010ceb0a0b1f35254aa0f5ce90aa/protos/foyle/v1alpha1/agent.proto#L57) +RPC which sends a session start event whenever we activate a cell. This will include the full context. A session also +contains events for cell execution. Cell execution events [include](https://github.com/stateful/vscode-runme/blob/14e944066ad55ece40af2ab12d9cfe6583715093/src/extension/ai/events.ts#L95) + +* Actual cell executed +* Cell execution status + + +All sessions should include a session end event. The session end event however doesn't include any cells. + +I believe the motivation for only learning if the user edited an AI suggestion was to improve RAG. +If the model was already accurately predicting a cell, then there was no reason to add another example of +it to our database. + + +## Proposal: Learn Based on Sessions + +The [SessionProto](https://github.com/jlewi/foyle/blob/d63d18b57293010ceb0a0b1f35254aa0f5ce90aa/protos/foyle/logs/sessions.proto#L14) has +most of the data we need. A session corresponds to all the edits of a cell. For a code cell + +* FullContext provides a full copy of the notebook when focus was placed on a cell +* Execution event will contain the executed cell +* To test if the cell was AI generated we could fetch the BlockLog for the cell + + +For a markdown cell + +* FullContext provides a full copy of the notebook when focus was placed on a cell +* We don't have a copy of the cell but we could obtain it a couple ways + * The sesion that starts next will have the full context which includes the final version of the cell + * The [LogEvent](https://github.com/stateful/vscode-runme/blob/14e944066ad55ece40af2ab12d9cfe6583715093/src/extension/ai/sessions.ts#L73) + reports session end and start in the same event so we could link sessions on the backend + + +In the case of AI generated cells, we no longer require the user to have edited the cell in order to trigger learning. +Dropping this restriction simplifies the learning logic since we don't have to check whether a cell was AI generated and +whether it was edited. + +## Future Directions + +In the future we'd like to extend learning to work for non-code cells. + + +