From 484dfd35cb7de2d13c755d959e95d906d66796f8 Mon Sep 17 00:00:00 2001 From: Ivan Krutov Date: Thu, 15 Nov 2018 16:33:48 +0300 Subject: [PATCH] Added ability to store session metadata (fixes #583) --- .travis.yml | 2 +- docs/index.adoc | 1 + docs/log-files.adoc | 1 + docs/metadata.adoc | 21 +++++++++++++++ event/event.go | 64 +++++++++++++++++++++++++++++++++++++++++++++ main.go | 3 --- metadata.go | 52 ++++++++++++++++++++++++++++++++++++ s3_test.go | 30 ++++++++++++--------- selenoid.go | 35 +++++++++++++------------ session/session.go | 61 ++++++++++++++++++++++++------------------ upload/s3.go | 21 ++++++++------- upload/uploader.go | 62 +++++++++++++++++++++++-------------------- utils_test.go | 40 ++++++++++++++++++++++++++++ 13 files changed, 296 insertions(+), 97 deletions(-) create mode 100644 docs/metadata.adoc create mode 100644 event/event.go create mode 100644 metadata.go diff --git a/.travis.yml b/.travis.yml index edca9509..a95de40f 100644 --- a/.travis.yml +++ b/.travis.yml @@ -9,7 +9,7 @@ services: script: - export GO111MODULE="on" - - go test -tags 's3' -v -race -coverprofile=coverage.txt -covermode=atomic -coverpkg github.com/aerokube/selenoid,github.com/aerokube/selenoid/session,github.com/aerokube/selenoid/config,github.com/aerokube/selenoid/protect,github.com/aerokube/selenoid/service,github.com/aerokube/selenoid/upload + - go test -tags 's3 metadata' -v -race -coverprofile=coverage.txt -covermode=atomic -coverpkg github.com/aerokube/selenoid,github.com/aerokube/selenoid/session,github.com/aerokube/selenoid/config,github.com/aerokube/selenoid/protect,github.com/aerokube/selenoid/service,github.com/aerokube/selenoid/upload - GOOS=linux GOARCH=amd64 CGO_ENABLED=0 go build -ldflags "-X main.buildStamp=`date -u '+%Y-%m-%d_%I:%M:%S%p'` -X main.gitRevision=`git describe --tags || git rev-parse HEAD` -s -w" - gox -os "linux darwin windows" -arch "amd64" -osarch="windows/386" -output "dist/{{.Dir}}_{{.OS}}_{{.Arch}}" -ldflags "-X main.buildStamp=`date -u '+%Y-%m-%d_%I:%M:%S%p'` -X main.gitRevision=`git describe --tags || git rev-parse HEAD` -s -w" diff --git a/docs/index.adoc b/docs/index.adoc index 6d00b4ae..ed2d71cd 100644 --- a/docs/index.adoc +++ b/docs/index.adoc @@ -31,6 +31,7 @@ include::timezone.adoc[leveloffset=+1] include::video.adoc[leveloffset=+1] include::logs.adoc[leveloffset=+1] include::s3.adoc[leveloffset=+1] +include::metadata.adoc[leveloffset=+1] include::docker-compose.adoc[leveloffset=+1] include::log-files.adoc[leveloffset=+1] include::cli-flags.adoc[leveloffset=+1] diff --git a/docs/log-files.adoc b/docs/log-files.adoc index 13086fbe..5d071664 100644 --- a/docs/log-files.adoc +++ b/docs/log-files.adoc @@ -61,6 +61,7 @@ The following statuses are available: | INIT | Server is starting | KILLED_VIDEO_CONTAINER | Waiting for video container to stop timed out and it was killed | LOG_ERROR | An error occurred when post-processing session logs +| METADATA | Metadata processing messages | NEW_REQUEST | New user request arrived and was placed to queue | NEW_REQUEST_ACCEPTED | Started processing new user request | PROCESS_STARTED | Driver process successfully started diff --git a/docs/metadata.adoc b/docs/metadata.adoc new file mode 100644 index 00000000..ed1ed492 --- /dev/null +++ b/docs/metadata.adoc @@ -0,0 +1,21 @@ +== Saving Session Metadata + +IMPORTANT: This feature only becomes available when Selenoid is compiled with `metadata` build tag (missing by default). + +Selenoid can save session metadata to a separate JSON file. Main use case is to somehow post-process session logs, e.g. send them to map-reduce cluster. No additional configuration is needed to enable this feature. When enabled and `-log-output-dir` flag is set - Selenoid will automatically save JSON files `/.json` with the following content: + +.Example metadata JSON file +[source,javascript] +---- +{ + "id": "62a4d82d-edf6-43d5-886f-895b77ff23b7", + "capabilities": { + "browserName": "chrome", + "version": "70.0", + "name": "MyCoolTest", + "screenResolution": "1920x1080x24" + }, + "started": "2018-11-15T16:23:12.440916+03:00", + "finished": "2018-11-15T16:23:12.480928+03:00" +} +---- diff --git a/event/event.go b/event/event.go new file mode 100644 index 00000000..e5fab7cb --- /dev/null +++ b/event/event.go @@ -0,0 +1,64 @@ +package event + +import "github.com/aerokube/selenoid/session" + +var ( + fileCreatedListeners []FileCreatedListener + sessionStoppedListeners []SessionStoppedListener +) + +type InitRequired interface { + Init() +} + +type Event struct { + RequestId uint64 + SessionId string + Session *session.Session +} + +type CreatedFile struct { + Event + Name string + Type string +} + +type FileCreatedListener interface { + OnFileCreated(createdFile CreatedFile) +} + +type StoppedSession struct { + Event +} + +type SessionStoppedListener interface { + OnSessionStopped(stoppedSession StoppedSession) +} + +func FileCreated(createdFile CreatedFile) { + for _, l := range fileCreatedListeners { + go l.OnFileCreated(createdFile) + } +} + +func InitIfNeeded(listener interface{}) { + if l, ok := listener.(InitRequired); ok { + l.Init() + } +} + +func AddFileCreatedListener(listener FileCreatedListener) { + InitIfNeeded(listener) + fileCreatedListeners = append(fileCreatedListeners, listener) +} + +func SessionStopped(stoppedSession StoppedSession) { + for _, l := range sessionStoppedListeners { + go l.OnSessionStopped(stoppedSession) + } +} + +func AddSessionStoppedListener(listener SessionStoppedListener) { + InitIfNeeded(listener) + sessionStoppedListeners = append(sessionStoppedListeners, listener) +} diff --git a/main.go b/main.go index 6559dbfd..ffb151d4 100644 --- a/main.go +++ b/main.go @@ -25,7 +25,6 @@ import ( "github.com/aerokube/selenoid/protect" "github.com/aerokube/selenoid/service" "github.com/aerokube/selenoid/session" - "github.com/aerokube/selenoid/upload" "github.com/aerokube/util" "github.com/aerokube/util/docker" "github.com/docker/docker/client" @@ -174,8 +173,6 @@ func init() { log.Printf("[-] [INIT] [Logs Dir: %s]", logOutputDir) } - upload.Init() - environment := service.Environment{ InDocker: inDocker, CPU: int64(cpu), diff --git a/metadata.go b/metadata.go new file mode 100644 index 00000000..7775bfd7 --- /dev/null +++ b/metadata.go @@ -0,0 +1,52 @@ +// +build metadata + +package main + +import ( + "encoding/json" + "github.com/aerokube/selenoid/event" + "github.com/aerokube/selenoid/session" + "io/ioutil" + "log" + "path/filepath" + "time" +) + +const metadataFileExtension = ".json" + +func init() { + mp := &MetadataProcessor{} + event.AddSessionStoppedListener(mp) +} + +type MetadataProcessor struct { +} + +func (mp *MetadataProcessor) OnSessionStopped(stoppedSession event.StoppedSession) { + if logOutputDir != "" { + meta := session.Metadata{ + ID: stoppedSession.SessionId, + Started: stoppedSession.Session.Started, + Finished: time.Now(), + Capabilities: stoppedSession.Session.Caps, + } + data, err := json.MarshalIndent(meta, "", " ") + if err != nil { + log.Printf("[%d] [METADATA] [%s] [Failed to marshal: %v]", stoppedSession.RequestId, stoppedSession.SessionId, err) + return + } + filename := filepath.Join(logOutputDir, stoppedSession.SessionId+metadataFileExtension) + err = ioutil.WriteFile(filename, data, 0644) + if err != nil { + log.Printf("[%d] [METADATA] [%s] [Failed to save to %s: %v]", stoppedSession.RequestId, stoppedSession.SessionId, filename, err) + return + } + log.Printf("[%d] [METADATA] [%s] [%s]", stoppedSession.RequestId, stoppedSession.SessionId, filename) + createdFile := event.CreatedFile{ + Event: stoppedSession.Event, + Name: filename, + Type: "metadata", + } + event.FileCreated(createdFile) + } +} diff --git a/s3_test.go b/s3_test.go index 0309a43e..099c0e01 100644 --- a/s3_test.go +++ b/s3_test.go @@ -5,6 +5,7 @@ package main import ( "context" . "github.com/aandryashin/matchers" + "github.com/aerokube/selenoid/event" "github.com/aerokube/selenoid/session" "github.com/aerokube/selenoid/upload" "io/ioutil" @@ -62,12 +63,14 @@ func TestS3Uploader(t *testing.T) { } uploader.Init() f, _ := ioutil.TempFile("", "some-file") - input := &upload.UploadRequest{ - Filename: f.Name(), - SessionId: "some-session-id", - Session: testSession, - Type: "log", - RequestId: 4342, + input := event.CreatedFile{ + Event: event.Event{ + RequestId: 4342, + SessionId: "some-session-id", + Session: testSession, + }, + Name: f.Name(), + Type: "log", } uploaded, err := uploader.Upload(input) AssertThat(t, err, Is{nil}) @@ -76,12 +79,15 @@ func TestS3Uploader(t *testing.T) { func TestGetKey(t *testing.T) { const testPattern = "$quota/$sessionId_$browserName_$browserVersion_$platformName/$fileType$fileExtension" - input := &upload.UploadRequest{ - Filename: "/path/to/some-file.txt", - SessionId: "some-session-id", - Session: testSession, - Type: "log", - RequestId: 12345, + input := event.CreatedFile{ + Event: event.Event{ + SessionId: "some-session-id", + Session: testSession, + RequestId: 12345, + }, + + Name: "/path/to/some-file.txt", + Type: "log", } key := upload.GetS3Key(testPattern, input) diff --git a/selenoid.go b/selenoid.go index 94a4ff1f..5b3fd370 100644 --- a/selenoid.go +++ b/selenoid.go @@ -8,6 +8,7 @@ import ( "encoding/hex" "encoding/json" "fmt" + "github.com/aerokube/selenoid/event" "io" "io/ioutil" "log" @@ -24,7 +25,6 @@ import ( "time" "github.com/aerokube/selenoid/session" - "github.com/aerokube/selenoid/upload" "github.com/aerokube/util" "github.com/docker/docker/api/types" "github.com/docker/docker/pkg/stdcopy" @@ -272,9 +272,16 @@ func create(w http.ResponseWriter, r *http.Request) { Timeout: sessionTimeout, TimeoutCh: onTimeout(sessionTimeout, func() { request{r}.session(s.ID).Delete(requestId) - })} + }), + Started: time.Now()} cancelAndRenameFiles := func() { cancel() + e := event.Event{ + RequestId: requestId, + SessionId: s.ID, + Session: sess, + } + event.SessionStopped(event.StoppedSession{e}) if browser.Caps.Video && !disableDocker { oldVideoName := filepath.Join(videoOutputDir, browser.Caps.VideoName) if finalVideoName == "" { @@ -285,14 +292,12 @@ func create(w http.ResponseWriter, r *http.Request) { if err != nil { log.Printf("[%d] [VIDEO_ERROR] [%s]", requestId, fmt.Sprintf("Failed to rename %s to %s: %v", oldVideoName, newVideoName, err)) } else { - input := &upload.UploadRequest{ - RequestId: requestId, - Filename: newVideoName, - SessionId: s.ID, - Session: sess, - Type: "video", + createdFile := event.CreatedFile{ + Event: e, + Name: newVideoName, + Type: "video", } - upload.Upload(input) + event.FileCreated(createdFile) } } if logOutputDir != "" { @@ -307,14 +312,12 @@ func create(w http.ResponseWriter, r *http.Request) { if err != nil { log.Printf("[%d] [LOG_ERROR] [%s]", requestId, fmt.Sprintf("Failed to rename %s to %s: %v", oldLogName, newLogName, err)) } else { - input := &upload.UploadRequest{ - RequestId: requestId, - Filename: newLogName, - SessionId: s.ID, - Session: sess, - Type: "log", + createdFile := event.CreatedFile{ + Event: e, + Name: newLogName, + Type: "log", } - upload.Upload(input) + event.FileCreated(createdFile) } } } diff --git a/session/session.go b/session/session.go index 8d015777..95102c61 100644 --- a/session/session.go +++ b/session/session.go @@ -9,32 +9,32 @@ import ( // Caps - user capabilities type Caps struct { - Name string `json:"browserName"` - DeviceName string `json:"deviceName"` - Version string `json:"version"` - W3CVersion string `json:"browserVersion"` - Platform string `json:"platform"` - W3CPlatform string `json:"platformName"` - ScreenResolution string `json:"screenResolution"` - Skin string `json:"skin"` - VNC bool `json:"enableVNC"` - Video bool `json:"enableVideo"` - VideoName string `json:"videoName"` - VideoScreenSize string `json:"videoScreenSize"` - VideoFrameRate uint16 `json:"videoFrameRate"` - VideoCodec string `json:"videoCodec"` - LogName string `json:"logName"` - TestName string `json:"name"` - TimeZone string `json:"timeZone"` - ContainerHostname string `json:"containerHostname"` - Env []string `json:"env"` - ApplicationContainers []string `json:"applicationContainers"` - HostsEntries []string `json:"hostsEntries"` - DNSServers []string `json:"dnsServers"` - Labels map[string]string `json:"labels"` - SessionTimeout string `json:"sessionTimeout"` - S3KeyPattern string `json:"s3KeyPattern"` - ExtensionCapabilities *Caps `json:"selenoid:options"` + Name string `json:"browserName,omitempty"` + DeviceName string `json:"deviceName,omitempty"` + Version string `json:"version,omitempty"` + W3CVersion string `json:"browserVersion,omitempty"` + Platform string `json:"platform,omitempty"` + W3CPlatform string `json:"platformName,omitempty"` + ScreenResolution string `json:"screenResolution,omitempty"` + Skin string `json:"skin,omitempty"` + VNC bool `json:"enableVNC,omitempty"` + Video bool `json:"enableVideo,omitempty"` + VideoName string `json:"videoName,omitempty"` + VideoScreenSize string `json:"videoScreenSize,omitempty"` + VideoFrameRate uint16 `json:"videoFrameRate,omitempty"` + VideoCodec string `json:"videoCodec,omitempty"` + LogName string `json:"logName,omitempty"` + TestName string `json:"name,omitempty"` + TimeZone string `json:"timeZone,omitempty"` + ContainerHostname string `json:"containerHostname,omitempty"` + Env []string `json:"env,omitempty"` + ApplicationContainers []string `json:"applicationContainers,omitempty"` + HostsEntries []string `json:"hostsEntries,omitempty"` + DNSServers []string `json:"dnsServers,omitempty"` + Labels map[string]string `json:"labels,omitempty"` + SessionTimeout string `json:"sessionTimeout,omitempty"` + S3KeyPattern string `json:"s3KeyPattern,omitempty"` + ExtensionCapabilities *Caps `json:"selenoid:options,omitempty"` } func (c *Caps) ProcessExtensionCapabilities() { @@ -66,6 +66,7 @@ type Session struct { Cancel func() Timeout time.Duration TimeoutCh chan struct{} + Started time.Time Lock sync.Mutex } @@ -125,3 +126,11 @@ func (m *Map) Len() int { defer m.l.RUnlock() return len(m.m) } + +// Metadata - session metadata saved to file +type Metadata struct { + ID string `json:"id"` + Capabilities Caps `json:"capabilities"` + Started time.Time `json:"started"` + Finished time.Time `json:"finished"` +} diff --git a/upload/s3.go b/upload/s3.go index 0bcf7be8..f774589b 100644 --- a/upload/s3.go +++ b/upload/s3.go @@ -5,6 +5,7 @@ package upload import ( "flag" "fmt" + "github.com/aerokube/selenoid/event" "github.com/aws/aws-sdk-go/aws" "github.com/aws/aws-sdk-go/aws/credentials" awssession "github.com/aws/aws-sdk-go/aws/session" @@ -29,7 +30,7 @@ func init() { flag.BoolVar(&(s3.KeepFiles), "s3-keep-files", false, "Do not remove uploaded files") flag.StringVar(&(s3.IncludeFiles), "s3-include-files", "", "Pattern used to match and include files") flag.StringVar(&(s3.ExcludeFiles), "s3-exclude-files", "", "Pattern used to match and exclude files") - uploader = s3 + AddUploader(s3) } type S3Uploader struct { @@ -65,18 +66,18 @@ func (s3 *S3Uploader) Init() { } } -func (s3 *S3Uploader) Upload(input *UploadRequest) (bool, error) { +func (s3 *S3Uploader) Upload(createdFile event.CreatedFile) (bool, error) { if s3.manager != nil { - filename := input.Filename + filename := createdFile.Name fileMatches, err := FileMatches(s3.IncludeFiles, s3.ExcludeFiles, filename) if err != nil { return false, fmt.Errorf("invalid pattern: %v", err) } if !fileMatches { - log.Printf("[%d] [SKIPPING_FILE] [%s] [Does not match specified patterns]", input.RequestId, input.Filename) + log.Printf("[%d] [SKIPPING_FILE] [%s] [Does not match specified patterns]", createdFile.RequestId, createdFile.Name) return false, nil } - key := GetS3Key(s3.KeyPattern, input) + key := GetS3Key(s3.KeyPattern, createdFile) file, err := os.Open(filename) defer file.Close() if err != nil { @@ -122,21 +123,21 @@ func FileMatches(includedFiles string, excludedFiles string, filename string) (b return fileIncluded && !fileExcluded, nil } -func GetS3Key(keyPattern string, input *UploadRequest) string { - sess := input.Session +func GetS3Key(keyPattern string, createdFile event.CreatedFile) string { + sess := createdFile.Session pt := keyPattern if sess.Caps.S3KeyPattern != "" { pt = sess.Caps.S3KeyPattern } - filename := input.Filename + filename := createdFile.Name key := strings.Replace(pt, "$fileName", strings.ToLower(filepath.Base(filename)), -1) key = strings.Replace(key, "$fileExtension", strings.ToLower(filepath.Ext(filename)), -1) key = strings.Replace(key, "$browserName", strings.ToLower(sess.Caps.Name), -1) key = strings.Replace(key, "$browserVersion", strings.ToLower(sess.Caps.Version), -1) key = strings.Replace(key, "$platformName", strings.ToLower(sess.Caps.Platform), -1) key = strings.Replace(key, "$quota", strings.ToLower(sess.Quota), -1) - key = strings.Replace(key, "$sessionId", strings.ToLower(input.SessionId), -1) - key = strings.Replace(key, "$fileType", strings.ToLower(input.Type), -1) + key = strings.Replace(key, "$sessionId", strings.ToLower(createdFile.SessionId), -1) + key = strings.Replace(key, "$fileType", strings.ToLower(createdFile.Type), -1) key = strings.Replace(key, "$date", time.Now().Format("2006-01-02"), -1) key = strings.Replace(key, " ", "-", -1) return key diff --git a/upload/uploader.go b/upload/uploader.go index 186d91da..057fcba3 100644 --- a/upload/uploader.go +++ b/upload/uploader.go @@ -1,47 +1,51 @@ package upload import ( - "github.com/aerokube/selenoid/session" + "github.com/aerokube/selenoid/event" "github.com/aerokube/util" "log" + "sync" "time" ) -type UploadRequest struct { - Filename string - RequestId uint64 - SessionId string - Session *session.Session - Type string -} +var ( + upl *Upload +) type Uploader interface { - Init() - Upload(input *UploadRequest) (bool, error) + Upload(createdFile event.CreatedFile) (bool, error) } -var ( - uploader Uploader -) +type Upload struct { + uploaders []Uploader + lock sync.Mutex +} -func Init() { - if uploader != nil { - uploader.Init() +func AddUploader(u Uploader) { + if upl == nil { + upl = &Upload{} + event.AddFileCreatedListener(upl) } + upl.lock.Lock() + defer upl.lock.Unlock() + event.InitIfNeeded(u) + upl.uploaders = append(upl.uploaders, u) } -func Upload(input *UploadRequest) { - if uploader != nil { - go func() { - s := time.Now() - uploaded, err := uploader.Upload(input) - if err != nil { - log.Printf("[%d] [UPLOADING_FILE] [%s] [Failed to upload: %v]", input.RequestId, input.Filename, err) - return - } - if uploaded { - log.Printf("[%d] [UPLOADED_FILE] [%s] [%.2fs]", input.RequestId, input.Filename, util.SecondsSince(s)) - } - }() +func (ul *Upload) OnFileCreated(createdFile event.CreatedFile) { + if len(ul.uploaders) > 0 { + for _, uploader := range ul.uploaders { + go func() { + s := time.Now() + uploaded, err := uploader.Upload(createdFile) + if err != nil { + log.Printf("[%d] [UPLOADING_FILE] [%s] [Failed to upload: %v]", createdFile.RequestId, createdFile.Name, err) + return + } + if uploaded { + log.Printf("[%d] [UPLOADED_FILE] [%s] [%.2fs]", createdFile.RequestId, createdFile.Name, util.SecondsSince(s)) + } + }() + } } } diff --git a/utils_test.go b/utils_test.go index ccc12f4d..78a282bb 100644 --- a/utils_test.go +++ b/utils_test.go @@ -1,9 +1,11 @@ package main import ( + "context" "encoding/json" "errors" "fmt" + "github.com/aerokube/selenoid/protect" "log" "net/http" "net/http/httptest" @@ -167,3 +169,41 @@ func TestProcessExtensionCapabilities(t *testing.T) { AssertThat(t, caps.Env, EqualTo{[]string{"LANG=de_DE.UTF-8"}}) AssertThat(t, caps.Labels, EqualTo{map[string]string{"key": "value"}}) } + +func TestSumUsedTotalGreaterThanPending(t *testing.T) { + queue := protect.New(2, false) + + hf := func(_ http.ResponseWriter, _ *http.Request) { + time.Sleep(50 * time.Millisecond) + } + queuedHandlerFunc := queue.Try(queue.Check(queue.Protect(hf))) + mux := http.NewServeMux() + mux.HandleFunc("/", queuedHandlerFunc) + + srv := httptest.NewServer(mux) + defer srv.Close() + u := srv.URL + "/" + + _, err := http.Get(u) + AssertThat(t, err, Is{nil}) + AssertThat(t, queue.Pending(), EqualTo{1}) + queue.Create() + AssertThat(t, queue.Pending(), EqualTo{0}) + AssertThat(t, queue.Used(), EqualTo{1}) + + _, err = http.Get(u) + AssertThat(t, err, Is{nil}) + AssertThat(t, queue.Pending(), EqualTo{1}) + queue.Create() + AssertThat(t, queue.Pending(), EqualTo{0}) + AssertThat(t, queue.Used(), EqualTo{2}) + + req, _ := http.NewRequest(http.MethodGet, u, nil) + ctx, _ := context.WithTimeout(context.Background(), 100*time.Millisecond) + req = req.WithContext(ctx) + + _, err = http.DefaultClient.Do(req) + AssertThat(t, err, Not{nil}) + AssertThat(t, queue.Pending(), EqualTo{0}) + AssertThat(t, queue.Used(), EqualTo{2}) +}