Add print commands and logging for investigation

grafana · Apr 8, 2024 · 019ac1c · 019ac1c
1 parent 3405f11
commit 019ac1c
Show file tree

Hide file tree

Showing 7 changed files with 23 additions and 15 deletions.
diff --git a/browser/registry.go b/browser/registry.go
@@ -280,6 +280,7 @@ func (r *browserRegistry) handleIterEvents( //nolint:funlen
 
 		switch e.Type { //nolint:exhaustive
 		case k6event.IterStart:
+			fmt.Println(">>>>>>: iteration has started")
 			// Because VU.State is nil when browser registry is initialized,
 			// we have to initialize traces registry on the first VU iteration
 			// so we can get access to the k6 TracerProvider.
@@ -301,6 +302,7 @@ func (r *browserRegistry) handleIterEvents( //nolint:funlen
 			}
 			r.setBrowser(data.Iteration, b)
 		case k6event.IterEnd:
+			fmt.Println(">>>>>>: iteration has ended")
 			r.deleteBrowser(data.Iteration)
 			r.tr.endIterationTrace(data.Iteration)
 		default:

diff --git a/common/connection.go b/common/connection.go
@@ -453,17 +453,17 @@ func (c *Connection) send(ctx context.Context, msg *cdproto.Message, recvCh chan
 	select {
 	case c.sendCh <- msg:
 	case err := <-c.errorCh:
-		c.logger.Debugf("Connection:send:<-c.errorCh", "wsURL:%q sid:%v, err:%v", c.wsURL, msg.SessionID, err)
+		c.logger.Infof("Connection:send:<-c.errorCh", "wsURL:%q sid:%v, err:%v", c.wsURL, msg.SessionID, err)
 		return fmt.Errorf("sending a message to browser: %w", err)
 	case code := <-c.closeCh:
-		c.logger.Debugf("Connection:send:<-c.closeCh", "wsURL:%q sid:%v, websocket code:%v", c.wsURL, msg.SessionID, code)
+		c.logger.Infof("Connection:send:<-c.closeCh", "wsURL:%q sid:%v, websocket code:%v", c.wsURL, msg.SessionID, code)
 		_ = c.close(code)
 		return fmt.Errorf("closing communication with browser: %w", &websocket.CloseError{Code: code})
 	case <-ctx.Done():
-		c.logger.Debugf("Connection:send:<-ctx.Done", "wsURL:%q sid:%v err:%v", c.wsURL, msg.SessionID, c.ctx.Err())
+		c.logger.Infof("Connection:send:<-ctx.Done", "wsURL:%q sid:%v err:%v", c.wsURL, msg.SessionID, c.ctx.Err())
 		return nil
 	case <-c.done:
-		c.logger.Debugf("Connection:send:<-c.done", "wsURL:%q sid:%v", c.wsURL, msg.SessionID)
+		c.logger.Infof("Connection:send:<-c.done", "wsURL:%q sid:%v", c.wsURL, msg.SessionID)
 		return nil
 	}
 
@@ -482,28 +482,28 @@ func (c *Connection) send(ctx context.Context, msg *cdproto.Message, recvCh chan
 		}
 		switch {
 		case msg == nil:
-			c.logger.Debugf("Connection:send", "wsURL:%q, err:ErrChannelClosed", c.wsURL)
+			c.logger.Infof("Connection:send", "wsURL:%q, err:ErrChannelClosed", c.wsURL)
 			return ErrChannelClosed
 		case msg.Error != nil:
-			c.logger.Debugf("Connection:send", "sid:%v tid:%v wsURL:%q, msg err:%v", sid, tid, c.wsURL, msg.Error)
+			c.logger.Infof("Connection:send", "sid:%v tid:%v wsURL:%q, msg err:%v", sid, tid, c.wsURL, msg.Error)
 			return msg.Error
 		case res != nil:
 			return easyjson.Unmarshal(msg.Result, res)
 		}
 	case err := <-c.errorCh:
-		c.logger.Debugf("Connection:send:<-c.errorCh #2", "sid:%v tid:%v wsURL:%q, err:%v", msg.SessionID, tid, c.wsURL, err)
+		c.logger.Infof("Connection:send:<-c.errorCh #2", "sid:%v tid:%v wsURL:%q, err:%v", msg.SessionID, tid, c.wsURL, err)
 		return err
 	case code := <-c.closeCh:
-		c.logger.Debugf("Connection:send:<-c.closeCh #2", "sid:%v tid:%v wsURL:%q, websocket code:%v", msg.SessionID, tid, c.wsURL, code)
+		c.logger.Infof("Connection:send:<-c.closeCh #2", "sid:%v tid:%v wsURL:%q, websocket code:%v", msg.SessionID, tid, c.wsURL, code)
 		_ = c.close(code)
 		return &websocket.CloseError{Code: code}
 	case <-c.done:
-		c.logger.Debugf("Connection:send:<-c.done #2", "sid:%v tid:%v wsURL:%q", msg.SessionID, tid, c.wsURL)
+		c.logger.Infof("Connection:send:<-c.done #2", "sid:%v tid:%v wsURL:%q", msg.SessionID, tid, c.wsURL)
 	case <-ctx.Done():
-		c.logger.Debugf("Connection:send:<-ctx.Done()", "sid:%v tid:%v wsURL:%q err:%v", msg.SessionID, tid, c.wsURL, c.ctx.Err())
+		c.logger.Infof("Connection:send:<-ctx.Done()", "sid:%v tid:%v wsURL:%q err:%v", msg.SessionID, tid, c.wsURL, ctx.Err())
 		return ctx.Err()
 	case <-c.ctx.Done():
-		c.logger.Debugf("Connection:send:<-c.ctx.Done()", "sid:%v tid:%v wsURL:%q err:%v", msg.SessionID, tid, c.wsURL, c.ctx.Err())
+		c.logger.Infof("Connection:send:<-c.ctx.Done()", "sid:%v tid:%v wsURL:%q err:%v", msg.SessionID, tid, c.wsURL, c.ctx.Err())
 		return c.ctx.Err()
 	}
 	return nil

diff --git a/common/context.go b/common/context.go
@@ -2,6 +2,7 @@ package common
 
 import (
 	"context"
+	"fmt"
 )
 
 type ctxKey int
@@ -78,7 +79,9 @@ func contextWithDoneChan(ctx context.Context, done chan struct{}) context.Contex
 		defer cancel()
 		select {
 		case <-done:
+			// fmt.Println(">>>>>>: done closed")
 		case <-ctx.Done():
+			fmt.Println(">>>>>>: ctx.Done closed")
 		}
 	}()
 	return ctx

diff --git a/common/frame_session.go b/common/frame_session.go
@@ -741,7 +741,7 @@ func (fs *FrameSession) onFrameAttached(frameID cdp.FrameID, parentFrameID cdp.F
 }
 
 func (fs *FrameSession) onFrameDetached(frameID cdp.FrameID, reason cdppage.FrameDetachedReason) {
-	fs.logger.Debugf("FrameSession:onFrameDetached",
+	fs.logger.Infof("FrameSession:onFrameDetached",
 		"sid:%v tid:%v fid:%v reason:%s",
 		fs.session.ID(), fs.targetID, frameID, reason)
 

diff --git a/common/js_handle.go b/common/js_handle.go
@@ -79,7 +79,9 @@ func (h *BaseJSHandle) AsElement() *ElementHandle {
 
 // Dispose releases the remote object.
 func (h *BaseJSHandle) Dispose() {
+	fmt.Println(">>>>>>: BaseJSHandler Dispose")
 	if err := h.dispose(); err != nil {
+		fmt.Println(">>>>>>: BaseJSHandler Dispose error", err)
 		k6ext.Panic(h.ctx, "dispose: %w", err)
 	}
 }

diff --git a/common/page.go b/common/page.go
@@ -657,7 +657,8 @@ func (p *Page) Click(selector string, opts *FrameClickOptions) error {
 
 // Close closes the page.
 func (p *Page) Close(_ goja.Value) error {
-	p.logger.Debugf("Page:Close", "sid:%v", p.sessionID())
+	p.logger.Infof("Page:Close", "sid:%v", p.sessionID())
+	defer fmt.Println(">>>>>>: page has closed")
 	_, span := TraceAPICall(p.ctx, p.targetID.String(), "page.close")
 	defer span.End()
 

diff --git a/common/session.go b/common/session.go
@@ -108,7 +108,7 @@ func (s *Session) readLoop() {
 
 // Execute implements the cdp.Executor interface.
 func (s *Session) Execute(ctx context.Context, method string, params easyjson.Marshaler, res easyjson.Unmarshaler) error {
-	s.logger.Debugf("Session:Execute", "sid:%v tid:%v method:%q", s.id, s.targetID, method)
+	s.logger.Infof("Session:Execute", "sid:%v tid:%v method:%q", s.id, s.targetID, method)
 	if s.crashed {
 		s.logger.Debugf("Session:Execute:return", "sid:%v tid:%v method:%q crashed", s.id, s.targetID, method)
 		return ErrTargetCrashed
@@ -144,7 +144,7 @@ func (s *Session) Execute(ctx context.Context, method string, params easyjson.Ma
 	s.onAll(evCancelCtx, chEvHandler)
 	defer evCancelFn() // Remove event handler
 
-	s.logger.Debugf("Session:Execute:s.conn.send", "sid:%v tid:%v method:%q", s.id, s.targetID, method)
+	s.logger.Infof("Session:Execute:s.conn.send", "sid:%v tid:%v method:%q", s.id, s.targetID, method)
 
 	var buf []byte
 	if params != nil {