Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Use logger directly (improvements) #138

Closed
wants to merge 2 commits into from
Closed

Use logger directly (improvements) #138

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
8008921
(WIP) Remove custom logger
inancgumus Nov 30, 2021
c0a5e36
(WIP) Fix logging calls
inancgumus Nov 30, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 9 additions & 8 deletions chromium/browser_type.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,11 +25,11 @@ import (
"errors"
"fmt"
"os"
"regexp"

"github.com/dop251/goja"
"github.com/grafana/xk6-browser/api"
"github.com/grafana/xk6-browser/common"
"github.com/sirupsen/logrus"
k6common "go.k6.io/k6/js/common"
k6lib "go.k6.io/k6/lib"
)
Expand Down Expand Up @@ -161,21 +161,22 @@ func (b *BrowserType) Name() string {
// makes an extension wide logger
func makeLogger(ctx context.Context, launchOpts *common.LaunchOptions) (*common.Logger, error) {
var (
k6Logger = k6lib.GetState(ctx).Logger
reCategoryFilter, _ = regexp.Compile(launchOpts.LogCategoryFilter)
logger = common.NewLogger(ctx, k6Logger, launchOpts.Debug, reCategoryFilter)
k6Logger = k6lib.GetState(ctx).Logger
logger = common.NewLogger(k6Logger)
)
// set the log level from the launch options (usually from a script's options).
if launchOpts.Debug {
_ = logger.SetLevel("debug")
logger.SetLevel(logrus.DebugLevel)
}
if el, ok := os.LookupEnv("XK6_BROWSER_LOG"); ok {
if err := logger.SetLevel(el); err != nil {
lvl, err := logrus.ParseLevel(el)
if err != nil {
return nil, err
}
logger.SetLevel(lvl)
}
if _, ok := os.LookupEnv("XK6_BROWSER_CALLER"); ok {
logger.ReportCaller()
if c := os.Getenv("XK6_BROWSER_CALLER"); c == "1" || c == "true" {
logger.EnableReportCaller()
}
return logger, nil
}
2 changes: 1 addition & 1 deletion common/barrier_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ func TestBarrier(t *testing.T) {
t.Run("should work", func(t *testing.T) {
ctx := context.Background()
timeoutSetings := NewTimeoutSettings(nil)
frameManager := NewFrameManager(ctx, nil, nil, timeoutSetings, NewLogger(ctx, NullLogger(), false, nil))
frameManager := NewFrameManager(ctx, nil, nil, timeoutSetings, NewLogger(NullLogger()))
frame := NewFrame(ctx, frameManager, nil, cdp.FrameID("frame_id_0123456789"))

barrier := NewBarrier()
Expand Down
54 changes: 27 additions & 27 deletions common/browser.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -108,7 +108,7 @@ func NewBrowser(ctx context.Context, cancelFn context.CancelFunc, browserProc *B
}

func (b *Browser) connect() error {
b.logger.Debugf("Browser:connect", "wsURL:%v", b.browserProc.WsURL())
b.logger.Debugf("Browser:connect wsURL:%v", b.browserProc.WsURL())
var err error
b.conn, err = NewConnection(b.ctx, b.browserProc.WsURL(), b.logger)
if err != nil {
Expand All @@ -123,7 +123,7 @@ func (b *Browser) connect() error {
}

func (b *Browser) disposeContext(id cdp.BrowserContextID) error {
b.logger.Debugf("Browser:disposeContext", "bctxid:%v", id)
b.logger.Debugf("Browser:disposeContext bctxid:%v", id)
action := target.DisposeBrowserContext(id)
if err := action.Do(cdp.WithExecutor(b.ctx, b.conn)); err != nil {
return fmt.Errorf("unable to dispose browser context %T: %w", action, err)
Expand Down Expand Up @@ -162,13 +162,13 @@ func (b *Browser) initEvents() error {
return
case event := <-chHandler:
if ev, ok := event.data.(*target.EventAttachedToTarget); ok {
b.logger.Debugf("Browser:initEvents:onAttachedToTarget", "sid:%v tid:%v", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:initEvents:onAttachedToTarget sid:%v tid:%v", ev.SessionID, ev.TargetInfo.TargetID)
go b.onAttachedToTarget(ev)
} else if ev, ok := event.data.(*target.EventDetachedFromTarget); ok {
b.logger.Debugf("Browser:initEvents:onDetachedFromTarget", "sid:%v", ev.SessionID)
b.logger.Debugf("Browser:initEvents:onDetachedFromTarget sid:%v", ev.SessionID)
go b.onDetachedFromTarget(ev)
} else if event.typ == EventConnectionClose {
b.logger.Debugf("Browser:initEvents:EventConnectionClose", "")
b.logger.Debugf("Browser:initEvents:EventConnectionClose")

b.connMu.Lock()
b.connected = false
Expand Down Expand Up @@ -203,13 +203,13 @@ func (b *Browser) onAttachedToTarget(ev *target.EventAttachedToTarget) {
if ok {
browserCtx = bctx
}
b.logger.Debugf("Browser:onAttachedToTarget", "sid:%v tid:%v bcid:%v bctx nil=%t", ev.SessionID, ev.TargetInfo.TargetID, ev.TargetInfo.BrowserContextID, bctx == nil)
b.logger.Debugf("Browser:onAttachedToTarget sid:%v tid:%v bcid:%v bctx nil=%t", ev.SessionID, ev.TargetInfo.TargetID, ev.TargetInfo.BrowserContextID, bctx == nil)
b.contextsMu.RUnlock()

// We're not interested in the top-level browser target, other targets or DevTools targets right now.
isDevTools := strings.HasPrefix(ev.TargetInfo.URL, "devtools://devtools")
if ev.TargetInfo.Type == "browser" || ev.TargetInfo.Type == "other" || isDevTools {
b.logger.Debugf("Browser:onAttachedToTarget", "sid:%v tid:%v, returns: devtools", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:onAttachedToTarget sid:%v tid:%v, returns: devtools", ev.SessionID, ev.TargetInfo.TargetID)
return
}

Expand All @@ -219,18 +219,18 @@ func (b *Browser) onAttachedToTarget(ev *target.EventAttachedToTarget) {
isRunning := atomic.LoadInt64(&b.state) == BrowserStateOpen && b.IsConnected() //b.conn.isConnected()
if _, ok := err.(*websocket.CloseError); !ok && !isRunning {
// If we're no longer connected to browser, then ignore WebSocket errors
b.logger.Debugf("Browser:onAttachedToTarget:background_page", "sid:%v tid:%v, returns: websocket err: %v",
b.logger.Debugf("Browser:onAttachedToTarget:background_page sid:%v tid:%v, returns: websocket err: %v",
ev.SessionID, ev.TargetInfo.TargetID, err)
return
}
k6Throw(b.ctx, "cannot create NewPage for background_page event: %w", err)
}
b.pagesMu.Lock()
b.logger.Debugf("Browser:onAttachedToTarget:background_page", "sid:%v tid:%v, adding tid", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:onAttachedToTarget:background_page sid:%v tid:%v, adding tid", ev.SessionID, ev.TargetInfo.TargetID)
b.pages[ev.TargetInfo.TargetID] = p
b.pagesMu.Unlock()
b.sessionIDtoTargetIDMu.Lock()
b.logger.Debugf("Browser:onAttachedToTarget:background_page", "sid:%v tid:%v, adding sid", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:onAttachedToTarget:background_page sid:%v tid:%v, adding sid", ev.SessionID, ev.TargetInfo.TargetID)
b.sessionIDtoTargetID[ev.SessionID] = ev.TargetInfo.TargetID
b.sessionIDtoTargetIDMu.Unlock()
} else if ev.TargetInfo.Type == "page" {
Expand All @@ -239,24 +239,24 @@ func (b *Browser) onAttachedToTarget(ev *target.EventAttachedToTarget) {
if t, ok := b.pages[ev.TargetInfo.OpenerID]; ok {
opener = t
}
b.logger.Debugf("Browser:onAttachedToTarget:page", "sid:%v tid:%v opener nil:%t", ev.SessionID, ev.TargetInfo.TargetID, opener == nil)
b.logger.Debugf("Browser:onAttachedToTarget:page sid:%v tid:%v opener nil:%t", ev.SessionID, ev.TargetInfo.TargetID, opener == nil)
b.pagesMu.RUnlock()
p, err := NewPage(b.ctx, b.conn.getSession(ev.SessionID), browserCtx, ev.TargetInfo.TargetID, opener, true, b.logger)
if err != nil {
isRunning := atomic.LoadInt64(&b.state) == BrowserStateOpen && b.IsConnected() //b.conn.isConnected()
if _, ok := err.(*websocket.CloseError); !ok && !isRunning {
// If we're no longer connected to browser, then ignore WebSocket errors
b.logger.Debugf("Browser:onAttachedToTarget:page", "sid:%v tid:%v, returns: websocket error", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:onAttachedToTarget:page sid:%v tid:%v, returns: websocket error", ev.SessionID, ev.TargetInfo.TargetID)
return
}
k6Throw(b.ctx, "cannot create NewPage for page event: %w", err)
}
b.pagesMu.Lock()
b.logger.Debugf("Browser:onAttachedToTarget:page", "sid:%v tid:%v, adding page as a target", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:onAttachedToTarget:page sid:%v tid:%v, adding page as a target", ev.SessionID, ev.TargetInfo.TargetID)
b.pages[ev.TargetInfo.TargetID] = p
b.pagesMu.Unlock()
b.sessionIDtoTargetIDMu.Lock()
b.logger.Debugf("Browser:onAttachedToTarget:page", "sid:%v tid:%v, changing sid to tid", ev.SessionID, ev.TargetInfo.TargetID)
b.logger.Debugf("Browser:onAttachedToTarget:page sid:%v tid:%v, changing sid to tid", ev.SessionID, ev.TargetInfo.TargetID)
b.sessionIDtoTargetID[ev.SessionID] = ev.TargetInfo.TargetID
b.sessionIDtoTargetIDMu.Unlock()
browserCtx.emit(EventBrowserContextPage, p)
Expand All @@ -266,18 +266,18 @@ func (b *Browser) onAttachedToTarget(ev *target.EventAttachedToTarget) {
func (b *Browser) onDetachedFromTarget(ev *target.EventDetachedFromTarget) {
b.sessionIDtoTargetIDMu.RLock()
targetID, ok := b.sessionIDtoTargetID[ev.SessionID]
b.logger.Debugf("Browser:onDetachedFromTarget", "sid:%v tid:%v", ev.SessionID, targetID)
b.logger.Debugf("Browser:onDetachedFromTarget sid:%v tid:%v", ev.SessionID, targetID)
b.sessionIDtoTargetIDMu.RUnlock()
if !ok {
b.logger.Debugf("Browser:onDetachedFromTarget", "sid:%v tid:%v, returns", ev.SessionID, targetID)
b.logger.Debugf("Browser:onDetachedFromTarget sid:%v tid:%v, returns", ev.SessionID, targetID)
// We don't track targets of type "browser", "other" and "devtools", so ignore if we don't recognize target.
return
}

b.pagesMu.Lock()
defer b.pagesMu.Unlock()
if t, ok := b.pages[targetID]; ok {
b.logger.Debugf("Browser:onDetachedFromTarget", "tid:%v, delete page", targetID)
b.logger.Debugf("Browser:onDetachedFromTarget tid:%v, delete page", targetID)
delete(b.pages, targetID)
t.didClose()
}
Expand All @@ -303,7 +303,7 @@ func (b *Browser) newPageInContext(id cdp.BrowserContextID) (*Page, error) {
func(data interface{}) bool {
mu.RLock()
defer mu.RUnlock()
b.logger.Debugf("Browser:newPageInContext", "tid:%v bcid:%v, createWaitForEventHandler", targetID, id)
b.logger.Debugf("Browser:newPageInContext tid:%v bcid:%v, createWaitForEventHandler", targetID, id)
return data.(*Page).targetID == targetID
},
)
Expand All @@ -314,20 +314,20 @@ func (b *Browser) newPageInContext(id cdp.BrowserContextID) (*Page, error) {
mu.Lock()
defer mu.Unlock()
localTargetID = targetID
b.logger.Debugf("Browser:newPageInContext", "tid:%v bcid:%v, CreateTarget(blank)", localTargetID, id)
b.logger.Debugf("Browser:newPageInContext tid:%v bcid:%v, CreateTarget(blank)", localTargetID, id)
if targetID, err = action.Do(cdp.WithExecutor(b.ctx, b.conn)); err != nil {
errCh <- fmt.Errorf("unable to execute %T: %w", action, err)
}
}()
select {
case <-b.ctx.Done():
b.logger.Debugf("Browser:newPageInContext:<-b.ctx.Done", "tid:%v bcid:%v", localTargetID, id)
b.logger.Debugf("Browser:newPageInContext:<-b.ctx.Done tid:%v bcid:%v", localTargetID, id)
case <-time.After(b.launchOpts.Timeout):
b.logger.Debugf("Browser:newPageInContext:timeout", "tid:%v bcid:%v timeout:%s", localTargetID, id, b.launchOpts.Timeout)
b.logger.Debugf("Browser:newPageInContext:timeout tid:%v bcid:%v timeout:%s", localTargetID, id, b.launchOpts.Timeout)
case c := <-ch:
b.logger.Debugf("Browser:newPageInContext:<-ch", "tid:%v bcid:%v, c:%v", localTargetID, id, c)
b.logger.Debugf("Browser:newPageInContext:<-ch tid:%v bcid:%v, c:%v", localTargetID, id, c)
case err := <-errCh:
b.logger.Debugf("Browser:newPageInContext:<-errCh", "tid:%v bcid:%v, err:%v", localTargetID, id, err)
b.logger.Debugf("Browser:newPageInContext:<-errCh tid:%v bcid:%v, err:%v", localTargetID, id, err)
return nil, err
}
b.pagesMu.RLock()
Expand All @@ -337,10 +337,10 @@ func (b *Browser) newPageInContext(id cdp.BrowserContextID) (*Page, error) {

// Close shuts down the browser
func (b *Browser) Close() {
b.logger.Debugf("Browser:Close", "")
b.logger.Debugf("Browser:Close")
if !atomic.CompareAndSwapInt64(&b.state, b.state, BrowserStateClosing) {
// If we're already in a closing state then no need to continue.
b.logger.Debugf("Browser:Close", "already in a closing state")
b.logger.Debugf("Browser:Close already in a closing state")
return
}
b.browserProc.GracefulClose()
Expand Down Expand Up @@ -376,7 +376,7 @@ func (b *Browser) IsConnected() bool {
func (b *Browser) NewContext(opts goja.Value) api.BrowserContext {
action := target.CreateBrowserContext().WithDisposeOnDetach(true)
browserContextID, err := action.Do(cdp.WithExecutor(b.ctx, b.conn))
b.logger.Debugf("Browser:NewContext", "browserContextID: %v", browserContextID)
b.logger.Debugf("Browser:NewContext browserContextID: %v", browserContextID)
if err != nil {
k6Throw(b.ctx, "unable to execute %T: %w", action, err)
}
Expand All @@ -388,7 +388,7 @@ func (b *Browser) NewContext(opts goja.Value) api.BrowserContext {

b.contextsMu.Lock()
defer b.contextsMu.Unlock()
b.logger.Debugf("Browser:NewContext", "NewBrowserContext: %v", browserContextID)
b.logger.Debugf("Browser:NewContext NewBrowserContext: %v", browserContextID)
browserCtx := NewBrowserContext(b.ctx, b.conn, b, browserContextID, browserCtxOpts, b.logger)
b.contexts[browserContextID] = browserCtx

Expand Down
28 changes: 14 additions & 14 deletions common/browser_context.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,7 +79,7 @@ func (b *BrowserContext) AddCookies(cookies goja.Value) {

// AddInitScript adds a script that will be initialized on all new pages.
func (b *BrowserContext) AddInitScript(script goja.Value, arg goja.Value) {
b.logger.Debugf("BrowserContext:AddInitScript", "")
b.logger.Debugf("BrowserContext:AddInitScript")

rt := k6common.GetRuntime(b.ctx)

Expand Down Expand Up @@ -165,7 +165,7 @@ func (b *BrowserContext) ExposeFunction(name string, callback goja.Callable) {

// GrantPermissions enables the specified permissions, all others will be disabled.
func (b *BrowserContext) GrantPermissions(permissions []string, opts goja.Value) {
b.logger.Debugf("BrowserContext:GrantPermissions", "")
b.logger.Debugf("BrowserContext:GrantPermissions")
rt := k6common.GetRuntime(b.ctx)
permsToProtocol := map[string]cdpbrowser.PermissionType{
"geolocation": cdpbrowser.PermissionTypeGeolocation,
Expand Down Expand Up @@ -216,7 +216,7 @@ func (b *BrowserContext) NewCDPSession() api.CDPSession {

// NewPage creates a new page inside this browser context.
func (b *BrowserContext) NewPage() api.Page {
b.logger.Debugf("BrowserContext:NewPage", "b.id:%v", b.id)
b.logger.Debugf("BrowserContext:NewPage b.id:%v", b.id)
p, err := b.browser.newPageInContext(b.id)
if err != nil {
rt := k6common.GetRuntime(b.ctx)
Expand Down Expand Up @@ -303,7 +303,7 @@ func (b *BrowserContext) Unroute(url goja.Value, handler goja.Callable) {
}

func (b *BrowserContext) WaitForEvent(event string, optsOrPredicate goja.Value) interface{} {
b.logger.Debugf("BrowserContext:WaitForEvent", "event:%q", event)
b.logger.Debugf("BrowserContext:WaitForEvent event:%q", event)
// TODO: This public API needs Promise support (as return value) to be useful in JS!

rt := k6common.GetRuntime(b.ctx)
Expand Down Expand Up @@ -340,16 +340,16 @@ func (b *BrowserContext) WaitForEvent(event string, optsOrPredicate goja.Value)
ch := make(chan interface{})

go func() {
b.logger.Debugf("BrowserContext:WaitForEvent:go()", "starts")
defer b.logger.Debugf("BrowserContext:WaitForEvent:go()", "returns")
b.logger.Debugf("BrowserContext:WaitForEvent:go() starts")
defer b.logger.Debugf("BrowserContext:WaitForEvent:go() returns")
for {
select {
case <-evCancelCtx.Done():
b.logger.Debugf("BrowserContext:WaitForEvent:go()", "evCancelCtx done")
b.logger.Debugf("BrowserContext:WaitForEvent:go() evCancelCtx done")
return
case ev := <-chEvHandler:
if ev.typ == EventBrowserContextClose {
b.logger.Debugf("BrowserContext:WaitForEvent:go()", "EventBrowserContextClose returns")
b.logger.Debugf("BrowserContext:WaitForEvent:go() EventBrowserContextClose returns")
ch <- nil
close(ch)

Expand All @@ -359,11 +359,11 @@ func (b *BrowserContext) WaitForEvent(event string, optsOrPredicate goja.Value)
return
}
if ev.typ == EventBrowserContextPage {
b.logger.Debugf("BrowserContext:WaitForEvent:go()", "EventBrowserContextPage")
b.logger.Debugf("BrowserContext:WaitForEvent:go() EventBrowserContextPage")
p := ev.data.(*Page)
exported := k6common.Bind(rt, p, &b.ctx)
if retVal, err := predicateFn(rt.ToValue(exported)); err == nil && retVal.ToBoolean() {
b.logger.Debugf("BrowserContext:WaitForEvent:go()", "EventBrowserContextPage returns")
b.logger.Debugf("BrowserContext:WaitForEvent:go() EventBrowserContextPage returns")
ch <- p
close(ch)

Expand All @@ -382,13 +382,13 @@ func (b *BrowserContext) WaitForEvent(event string, optsOrPredicate goja.Value)

select {
case <-b.ctx.Done():
b.logger.Debugf("BrowserContext:WaitForEvent", "b.ctx Done")
b.logger.Debugf("BrowserContext:WaitForEvent b.ctx Done")
case <-time.After(timeout):
b.logger.Debugf("BrowserContext:WaitForEvent", "timeout")
b.logger.Debugf("BrowserContext:WaitForEvent timeout")
case evData := <-ch:
b.logger.Debugf("BrowserContext:WaitForEvent", "evData")
b.logger.Debugf("BrowserContext:WaitForEvent evData")
return evData
}
b.logger.Debugf("BrowserContext:WaitForEvent", "nil return")
b.logger.Debugf("BrowserContext:WaitForEvent nil return")
return nil
}
4 changes: 2 additions & 2 deletions common/browser_process.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,13 +79,13 @@ func (p *BrowserProcess) didLoseConnection() {

// GracefulClose triggers a graceful closing of the browser process
func (p *BrowserProcess) GracefulClose() {
p.logger.Debugf("Browser:GracefulClose", "")
p.logger.Debugf("Browser:GracefulClose")
close(p.processIsGracefullyClosing)
}

// Terminate triggers the termination of the browser process
func (p *BrowserProcess) Terminate() {
p.logger.Debugf("Browser:Close", "browserProc terminate")
p.logger.Debugf("Browser:Close browserProc terminate")
p.cancel()
}

Expand Down
Loading