[ARVADOS] created: 8a504ad561c1ffbafee8a7bc8da551f9d4b9a29e
git at public.curoverse.com
git at public.curoverse.com
Fri Feb 13 17:01:45 EST 2015
at 8a504ad561c1ffbafee8a7bc8da551f9d4b9a29e (commit)
commit 8a504ad561c1ffbafee8a7bc8da551f9d4b9a29e
Merge: b7bd673 1128f6e
Author: Tom Clegg <tom at curoverse.com>
Date: Fri Feb 13 17:02:16 2015 -0500
Merge branch 'master' into 3408-production-datamanager
commit b7bd673a45ec3de02fdf846f4a9ebe2638c546cc
Author: mishaz <misha at curoverse.com>
Date: Tue Feb 10 02:39:39 2015 +0000
Added different event types for started, partially complete and final log entries.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index e6e1ed6..e7bc8d1 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -1,9 +1,8 @@
// Logger periodically writes a log to the Arvados SDK.
//
// This package is useful for maintaining a log object that is updated
-// over time. Every time the object is updated, it will be written to
-// the log. Writes will be throttled to no more frequent than
-// WriteInterval.
+// over time. This log object will be periodically written to the log,
+// as specified by WriteInterval in the Params.
//
// This package is safe for concurrent use as long as:
// The maps passed to a LogMutator are not accessed outside of the
@@ -26,10 +25,16 @@ import (
"time"
)
+const (
+ startSuffix = "-start"
+ partialSuffix = "-partial"
+ finalSuffix = "-final"
+)
+
type LoggerParams struct {
- Client arvadosclient.ArvadosClient // The client we use to write log entries
- EventType string // The event type to assign to the log entry.
- WriteInterval time.Duration // Wait at least this long between log writes
+ Client arvadosclient.ArvadosClient // The client we use to write log entries
+ EventTypePrefix string // The prefix we use for the event type in the log entry
+ WriteInterval time.Duration // Wait at least this long between log writes
}
// A LogMutator is a function which modifies the log entry.
@@ -57,6 +62,7 @@ type Logger struct {
modified bool // Has this data been modified since the last write?
workToDo chan LogMutator // Work to do in the worker thread.
writeTicker *time.Ticker // On each tick we write the log data to arvados, if it has been modified.
+ hasWritten bool // Whether we've written at all yet.
writeHooks []LogMutator // Mutators we call before each write.
}
@@ -67,8 +73,8 @@ func NewLogger(params LoggerParams) *Logger {
if ¶ms.Client == nil {
log.Fatal("Nil arvados client in LoggerParams passed in to NewLogger()")
}
- if params.EventType == "" {
- log.Fatal("Empty event type in LoggerParams passed in to NewLogger()")
+ if params.EventTypePrefix == "" {
+ log.Fatal("Empty event type prefix in LoggerParams passed in to NewLogger()")
}
l := &Logger{data: make(map[string]interface{}),
@@ -119,11 +125,9 @@ func (l *Logger) FinalUpdate(mutator LogMutator) {
// Apply the final update
l.workToDo <- mutator
- // Perform the write and signal that we can return.
+ // Perform the final write and signal that we can return.
l.workToDo <- func(p map[string]interface{}, e map[string]interface{}) {
- // TODO(misha): Add a boolean arg to write() to indicate that it's
- // final so that we can set the appropriate event type.
- l.write()
+ l.write(true)
done <- true
}
@@ -146,7 +150,7 @@ func (l *Logger) work() {
select {
case <-l.writeTicker.C:
if l.modified {
- l.write()
+ l.write(false)
l.modified = false
}
case mutator := <-l.workToDo:
@@ -157,16 +161,22 @@ func (l *Logger) work() {
}
// Actually writes the log entry.
-func (l *Logger) write() {
+func (l *Logger) write(isFinal bool) {
// Run all our hooks
for _, hook := range l.writeHooks {
hook(l.properties, l.entry)
}
- // Update the event type in case it was modified or is missing.
- // TODO(misha): Fix this to write different event types.
- l.entry["event_type"] = l.params.EventType
+ // Update the event type.
+ if isFinal {
+ l.entry["event_type"] = l.params.EventTypePrefix + finalSuffix
+ } else if l.hasWritten {
+ l.entry["event_type"] = l.params.EventTypePrefix + partialSuffix
+ } else {
+ l.entry["event_type"] = l.params.EventTypePrefix + startSuffix
+ }
+ l.hasWritten = true
// Write the log entry.
// This is a network write and will take a while, which is bad
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index bd68db1..2c5c36d 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -15,15 +15,15 @@ import (
)
var (
- logEventType string
+ logEventTypePrefix string
logFrequencySeconds int
)
func init() {
- flag.StringVar(&logEventType,
- "log-event-type",
- "experimental-data-manager-report",
- "event_type to use in our arvados log entries. Set to empty to turn off logging")
+ flag.StringVar(&logEventTypePrefix,
+ "log-event-type-prefix",
+ "experimental-data-manager",
+ "Prefix to use in the event_type of our arvados log entries. Set to empty to turn off logging")
flag.IntVar(&logFrequencySeconds,
"log-frequency-seconds",
20,
@@ -45,9 +45,9 @@ func main() {
}
var arvLogger *logger.Logger
- if logEventType != "" {
+ if logEventTypePrefix != "" {
arvLogger = logger.NewLogger(logger.LoggerParams{Client: arv,
- EventType: logEventType,
+ EventTypePrefix: logEventTypePrefix,
WriteInterval: time.Second * time.Duration(logFrequencySeconds)})
}
commit 43538243995267c417983360d226d6e8eb181139
Author: mishaz <misha at curoverse.com>
Date: Tue Feb 10 02:11:34 2015 +0000
Moved some logging code from datamananager to loggerutil.
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index f63f462..bd68db1 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -9,9 +9,8 @@ import (
"git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/collection"
"git.curoverse.com/arvados.git/services/datamanager/keep"
+ "git.curoverse.com/arvados.git/services/datamanager/loggerutil"
"log"
- "os"
- "runtime"
"time"
)
@@ -52,23 +51,9 @@ func main() {
WriteInterval: time.Second * time.Duration(logFrequencySeconds)})
}
+ loggerutil.LogRunInfo(arvLogger)
if arvLogger != nil {
- now := time.Now()
- arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
- runInfo := make(map[string]interface{})
- runInfo["time_started"] = now
- runInfo["args"] = os.Args
- hostname, err := os.Hostname()
- if err != nil {
- runInfo["hostname_error"] = err.Error()
- } else {
- runInfo["hostname"] = hostname
- }
- runInfo["pid"] = os.Getpid()
- p["run_info"] = runInfo
- })
-
- arvLogger.AddWriteHook(LogMemoryAlloc)
+ arvLogger.AddWriteHook(loggerutil.LogMemoryAlloc)
}
collectionChannel := make(chan collection.ReadCollections)
@@ -96,11 +81,3 @@ func main() {
})
}
}
-
-// TODO(misha): Consider moving this to loggerutil
-func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
- runInfo := properties["run_info"].(map[string]interface{})
- var memStats runtime.MemStats
- runtime.ReadMemStats(&memStats)
- runInfo["alloc_bytes_in_use"] = memStats.Alloc
-}
diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
index c19a7ab..1514922 100644
--- a/services/datamanager/loggerutil/loggerutil.go
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -5,9 +5,42 @@ package loggerutil
import (
"git.curoverse.com/arvados.git/sdk/go/logger"
"log"
+ "os"
+ "runtime"
"time"
)
+// Useful to call at the begining of execution to log info about the
+// current run.
+func LogRunInfo(arvLogger *logger.Logger) {
+ if arvLogger != nil {
+ now := time.Now()
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ runInfo := make(map[string]interface{})
+ runInfo["time_started"] = now
+ runInfo["args"] = os.Args
+ hostname, err := os.Hostname()
+ if err != nil {
+ runInfo["hostname_error"] = err.Error()
+ } else {
+ runInfo["hostname"] = hostname
+ }
+ runInfo["pid"] = os.Getpid()
+ p["run_info"] = runInfo
+ })
+ }
+}
+
+// A LogMutator that records the current memory usage. This is most useful as a logger write hook.
+//
+// Assumes we already have a map named "run_info" in properties. LogRunInfo() can create such a map for you if you call it.
+func LogMemoryAlloc(p map[string]interface{}, e map[string]interface{}) {
+ runInfo := p["run_info"].(map[string]interface{})
+ var memStats runtime.MemStats
+ runtime.ReadMemStats(&memStats)
+ runInfo["alloc_bytes_in_use"] = memStats.Alloc
+}
+
func FatalWithMessage(arvLogger *logger.Logger, message string) {
if arvLogger != nil {
arvLogger.FinalUpdate(func(p map[string]interface{}, e map[string]interface{}) {
commit 3a1face2e3bc02e1fb9c53a2268095811b2e069d
Author: mishaz <misha at curoverse.com>
Date: Tue Feb 10 01:55:37 2015 +0000
Updated logger to do all work in a dedicated goroutine, so we don't need to worry about locking. Small changes to calling code.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index a53ab3c..e6e1ed6 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -2,8 +2,8 @@
//
// This package is useful for maintaining a log object that is updated
// over time. Every time the object is updated, it will be written to
-// the log. Writes will be throttled to no more than one every
-// WriteFrequencySeconds
+// the log. Writes will be throttled to no more frequent than
+// WriteInterval.
//
// This package is safe for concurrent use as long as:
// The maps passed to a LogMutator are not accessed outside of the
@@ -23,14 +23,13 @@ package logger
import (
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"log"
- "sync"
"time"
)
type LoggerParams struct {
- Client arvadosclient.ArvadosClient // The client we use to write log entries
- EventType string // The event type to assign to the log entry.
- MinimumWriteInterval time.Duration // Wait at least this long between log writes
+ Client arvadosclient.ArvadosClient // The client we use to write log entries
+ EventType string // The event type to assign to the log entry.
+ WriteInterval time.Duration // Wait at least this long between log writes
}
// A LogMutator is a function which modifies the log entry.
@@ -52,13 +51,12 @@ type Logger struct {
entry map[string]interface{} // Convenience shortcut into data
properties map[string]interface{} // Convenience shortcut into data
- lock sync.Locker // Synchronizes access to this struct
params LoggerParams // Parameters we were given
- // Variables used to determine when and if we write to the log.
- nextWriteAllowed time.Time // The next time we can write, respecting MinimumWriteInterval
- modified bool // Has this data been modified since the last write?
- writeScheduled bool // Is a write been scheduled for the future?
+ // Variables to coordinate updating and writing.
+ modified bool // Has this data been modified since the last write?
+ workToDo chan LogMutator // Work to do in the worker thread.
+ writeTicker *time.Ticker // On each tick we write the log data to arvados, if it has been modified.
writeHooks []LogMutator // Mutators we call before each write.
}
@@ -74,91 +72,88 @@ func NewLogger(params LoggerParams) *Logger {
}
l := &Logger{data: make(map[string]interface{}),
- lock: &sync.Mutex{},
params: params}
l.entry = make(map[string]interface{})
l.data["log"] = l.entry
l.properties = make(map[string]interface{})
l.entry["properties"] = l.properties
- return l
-}
-// Updates the log data and then writes it to the api server. If the
-// log has been recently written then the write will be postponed to
-// respect MinimumWriteInterval and this function will return before
-// the write occurs.
-func (l *Logger) Update(mutator LogMutator) {
- l.lock.Lock()
+ l.workToDo = make(chan LogMutator, 10)
+ l.writeTicker = time.NewTicker(params.WriteInterval)
- mutator(l.properties, l.entry)
- l.modified = true // We assume the mutator modified the log, even though we don't know for sure.
+ // Start the worker goroutine.
+ go l.work()
- l.considerWriting()
-
- l.lock.Unlock()
+ return l
}
-// Similar to Update(), but forces a write without respecting the
-// MinimumWriteInterval. This is useful if you know that you're about
-// to quit (e.g. if you discovered a fatal error, or you're finished),
-// since go will not wait for timers (including the pending write
-// timer) to go off before exiting.
-func (l *Logger) ForceUpdate(mutator LogMutator) {
- l.lock.Lock()
+// Exported functions will be called from other goroutines, therefore
+// all they are allowed to do is enqueue work to be done in the worker
+// goroutine.
- mutator(l.properties, l.entry)
- l.modified = true // We assume the mutator modified the log, even though we don't know for sure.
-
- l.write()
- l.lock.Unlock()
-}
-
-// Adds a hook which will be called every time this logger writes an entry.
-func (l *Logger) AddWriteHook(hook LogMutator) {
- l.lock.Lock()
- l.writeHooks = append(l.writeHooks, hook)
- // TODO(misha): Consider setting modified and attempting a write.
- l.lock.Unlock()
+// Enqueues an update. This will happen in another goroutine after
+// this method returns.
+func (l *Logger) Update(mutator LogMutator) {
+ l.workToDo <- mutator
}
-// This function is called on a timer when we have something to write,
-// but need to schedule the write for the future to respect
-// MinimumWriteInterval.
-func (l *Logger) acquireLockConsiderWriting() {
- l.lock.Lock()
+// Similar to Update(), but writes the log entry as soon as possible
+// (ignoring MinimumWriteInterval) and blocks until the entry has been
+// written. This is useful if you know that you're about to quit
+// (e.g. if you discovered a fatal error, or you're finished), since
+// go will not wait for timers (including the pending write timer) to
+// go off before exiting.
+func (l *Logger) FinalUpdate(mutator LogMutator) {
+ // Block on this channel until everything finishes
+ done := make(chan bool)
+
+ // TODO(misha): Consider not accepting any future updates somehow,
+ // since they won't get written if they come in after this.
+
+ // Stop the periodic write ticker. We'll perform the final write
+ // before returning from this function.
+ l.workToDo <- func(p map[string]interface{}, e map[string]interface{}) {
+ l.writeTicker.Stop()
+ }
- // We are the scheduled write, so there are no longer future writes
- // scheduled.
- l.writeScheduled = false
+ // Apply the final update
+ l.workToDo <- mutator
- l.considerWriting()
+ // Perform the write and signal that we can return.
+ l.workToDo <- func(p map[string]interface{}, e map[string]interface{}) {
+ // TODO(misha): Add a boolean arg to write() to indicate that it's
+ // final so that we can set the appropriate event type.
+ l.write()
+ done <- true
+ }
- l.lock.Unlock()
+ // Wait until we've performed the write.
+ <-done
}
-// The above methods each acquire the lock and release it.
-// =======================================================
-// The below methods all assume we're holding a lock.
-
-// Check whether we have anything to write. If we do, then either
-// write it now or later, based on what we're allowed.
-func (l *Logger) considerWriting() {
- if !l.modified {
- // Nothing to write
- } else if l.writeAllowedNow() {
- l.write()
- } else if l.writeScheduled {
- // A future write is already scheduled, we don't need to do anything.
- } else {
- writeAfter := l.nextWriteAllowed.Sub(time.Now())
- time.AfterFunc(writeAfter, l.acquireLockConsiderWriting)
- l.writeScheduled = true
+// Adds a hook which will be called every time this logger writes an entry.
+func (l *Logger) AddWriteHook(hook LogMutator) {
+ // We do the work in a LogMutator so that it happens in the worker
+ // goroutine.
+ l.workToDo <- func(p map[string]interface{}, e map[string]interface{}) {
+ l.writeHooks = append(l.writeHooks, hook)
}
}
-// Whether writing now would respect MinimumWriteInterval
-func (l *Logger) writeAllowedNow() bool {
- return l.nextWriteAllowed.Before(time.Now())
+// The worker loop
+func (l *Logger) work() {
+ for {
+ select {
+ case <-l.writeTicker.C:
+ if l.modified {
+ l.write()
+ l.modified = false
+ }
+ case mutator := <-l.workToDo:
+ mutator(l.properties, l.entry)
+ l.modified = true
+ }
+ }
}
// Actually writes the log entry.
@@ -170,24 +165,20 @@ func (l *Logger) write() {
}
// Update the event type in case it was modified or is missing.
+ // TODO(misha): Fix this to write different event types.
l.entry["event_type"] = l.params.EventType
// Write the log entry.
// This is a network write and will take a while, which is bad
- // because we're holding a lock and all other goroutines will back
- // up behind it.
+ // because we're blocking all the other work on this goroutine.
//
// TODO(misha): Consider rewriting this so that we can encode l.data
- // into a string, release the lock, write the string, and then
- // acquire the lock again to note that we succeeded in writing. This
- // will be tricky and will require support in the client.
+ // into a string, and then perform the actual write in another
+ // routine. This will be tricky and will require support in the
+ // client.
err := l.params.Client.Create("logs", l.data, nil)
if err != nil {
log.Printf("Attempted to log: %v", l.data)
log.Fatalf("Received error writing log: %v", err)
}
-
- // Update stats.
- l.nextWriteAllowed = time.Now().Add(l.params.MinimumWriteInterval)
- l.modified = false
}
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 424db83..9a7a838 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -65,15 +65,6 @@ func init() {
"File to write the heap profiles to. Leave blank to skip profiling.")
}
-// // Methods to implement util.SdkListResponse Interface
-// func (s SdkCollectionList) NumItemsAvailable() (numAvailable int, err error) {
-// return s.ItemsAvailable, nil
-// }
-
-// func (s SdkCollectionList) NumItemsContained() (numContained int, err error) {
-// return len(s.Items), nil
-// }
-
// Write the heap profile to a file for later review.
// Since a file is expected to only contain a single heap profile this
// function overwrites the previously written profile, so it is safe
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 398c877..f63f462 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -48,14 +48,15 @@ func main() {
var arvLogger *logger.Logger
if logEventType != "" {
arvLogger = logger.NewLogger(logger.LoggerParams{Client: arv,
- EventType: logEventType,
- MinimumWriteInterval: time.Second * time.Duration(logFrequencySeconds)})
+ EventType: logEventType,
+ WriteInterval: time.Second * time.Duration(logFrequencySeconds)})
}
if arvLogger != nil {
+ now := time.Now()
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
runInfo := make(map[string]interface{})
- runInfo["time_started"] = time.Now()
+ runInfo["time_started"] = now
runInfo["args"] = os.Args
hostname, err := os.Hostname()
if err != nil {
@@ -90,7 +91,7 @@ func main() {
// Log that we're finished. We force the recording, since go will
// not wait for the timer before exiting.
if arvLogger != nil {
- arvLogger.ForceUpdate(func(p map[string]interface{}, e map[string]interface{}) {
+ arvLogger.FinalUpdate(func(p map[string]interface{}, e map[string]interface{}) {
p["run_info"].(map[string]interface{})["time_finished"] = time.Now()
})
}
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 20a5931..dcd6c49 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -69,15 +69,6 @@ type KeepServiceList struct {
KeepServers []ServerAddress `json:"items"`
}
-// Methods to implement util.SdkListResponse Interface
-func (k KeepServiceList) NumItemsAvailable() (numAvailable int, err error) {
- return k.ItemsAvailable, nil
-}
-
-func (k KeepServiceList) NumItemsContained() (numContained int, err error) {
- return len(k.KeepServers), nil
-}
-
var (
// Don't access the token directly, use getDataManagerToken() to
// make sure it's been read.
@@ -244,10 +235,11 @@ func GetServerStatus(arvLogger *logger.Logger,
keepServer.Port)
if arvLogger != nil {
+ now := time.Now()
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := make(map[string]interface{})
- serverInfo["time_status_request_sent"] = time.Now()
+ serverInfo["time_status_request_sent"] = now
keepInfo[keepServer.String()] = serverInfo
})
@@ -274,10 +266,11 @@ func GetServerStatus(arvLogger *logger.Logger,
}
if arvLogger != nil {
+ now := time.Now()
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- serverInfo["time_status_response_processed"] = time.Now()
+ serverInfo["time_status_response_processed"] = now
serverInfo["status"] = keepStatus
})
}
@@ -289,10 +282,11 @@ func CreateIndexRequest(arvLogger *logger.Logger,
log.Println("About to fetch keep server contents from " + url)
if arvLogger != nil {
+ now := time.Now()
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- serverInfo["time_index_request_sent"] = time.Now()
+ serverInfo["time_index_request_sent"] = now
})
}
@@ -319,11 +313,11 @@ func ReadServerResponse(arvLogger *logger.Logger,
}
if arvLogger != nil {
+ now := time.Now()
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
-
- serverInfo["time_index_response_received"] = time.Now()
+ serverInfo["time_index_response_received"] = now
})
}
@@ -393,11 +387,12 @@ func ReadServerResponse(arvLogger *logger.Logger,
numSizeDisagreements)
if arvLogger != nil {
+ now := time.Now()
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- serverInfo["time_processing_finished"] = time.Now()
+ serverInfo["time_processing_finished"] = now
serverInfo["lines_received"] = numLines
serverInfo["duplicates_seen"] = numDuplicates
serverInfo["size_disagreements_seen"] = numSizeDisagreements
diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
index fa876d4..c19a7ab 100644
--- a/services/datamanager/loggerutil/loggerutil.go
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -8,12 +8,9 @@ import (
"time"
)
-// Assumes you haven't already called arvLogger.Edit()!
-// If you have called arvLogger.Edit() this method will hang waiting
-// for the lock you're already holding.
func FatalWithMessage(arvLogger *logger.Logger, message string) {
if arvLogger != nil {
- arvLogger.ForceUpdate(func(p map[string]interface{}, e map[string]interface{}) {
+ arvLogger.FinalUpdate(func(p map[string]interface{}, e map[string]interface{}) {
p["FATAL"] = message
p["run_info"].(map[string]interface{})["time_finished"] = time.Now()
})
commit 75f4b70625086aaa8ecf8daed23e4d151e54949f
Author: mishaz <misha at curoverse.com>
Date: Fri Jan 30 01:32:31 2015 +0000
Renamed timestamp fields to begin with "time_"
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index cbdae6e..398c877 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -55,7 +55,7 @@ func main() {
if arvLogger != nil {
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
runInfo := make(map[string]interface{})
- runInfo["start_time"] = time.Now()
+ runInfo["time_started"] = time.Now()
runInfo["args"] = os.Args
hostname, err := os.Hostname()
if err != nil {
@@ -91,7 +91,7 @@ func main() {
// not wait for the timer before exiting.
if arvLogger != nil {
arvLogger.ForceUpdate(func(p map[string]interface{}, e map[string]interface{}) {
- p["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ p["run_info"].(map[string]interface{})["time_finished"] = time.Now()
})
}
}
diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
index 20b7f18..fa876d4 100644
--- a/services/datamanager/loggerutil/loggerutil.go
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -15,7 +15,7 @@ func FatalWithMessage(arvLogger *logger.Logger, message string) {
if arvLogger != nil {
arvLogger.ForceUpdate(func(p map[string]interface{}, e map[string]interface{}) {
p["FATAL"] = message
- p["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ p["run_info"].(map[string]interface{})["time_finished"] = time.Now()
})
}
commit e5840cee519c5ff8b88e37e14160f9e4e12908ec
Author: mishaz <misha at curoverse.com>
Date: Fri Jan 30 01:25:11 2015 +0000
Now fetch Keep Server Status and record it to the log. Renamed some fields and added a comment for a potential improvement to decrease lock contention.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index ca344be..a53ab3c 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -173,6 +173,14 @@ func (l *Logger) write() {
l.entry["event_type"] = l.params.EventType
// Write the log entry.
+ // This is a network write and will take a while, which is bad
+ // because we're holding a lock and all other goroutines will back
+ // up behind it.
+ //
+ // TODO(misha): Consider rewriting this so that we can encode l.data
+ // into a string, release the lock, write the string, and then
+ // acquire the lock again to note that we succeeded in writing. This
+ // will be tricky and will require support in the client.
err := l.params.Client.Create("logs", l.data, nil)
if err != nil {
log.Printf("Attempted to log: %v", l.data)
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 39ac30a..20a5931 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -4,6 +4,7 @@ package keep
import (
"bufio"
+ "encoding/json"
"flag"
"fmt"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
@@ -223,6 +224,8 @@ func GetServerContents(arvLogger *logger.Logger,
keepServer ServerAddress,
client http.Client) (response ServerResponse) {
+ GetServerStatus(arvLogger, keepServer, client)
+
req := CreateIndexRequest(arvLogger, keepServer)
resp, err := client.Do(req)
if err != nil {
@@ -233,6 +236,53 @@ func GetServerContents(arvLogger *logger.Logger,
return ReadServerResponse(arvLogger, keepServer, resp)
}
+func GetServerStatus(arvLogger *logger.Logger,
+ keepServer ServerAddress,
+ client http.Client) {
+ url := fmt.Sprintf("http://%s:%d/status.json",
+ keepServer.Host,
+ keepServer.Port)
+
+ if arvLogger != nil {
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := p["keep_info"].(map[string]interface{})
+ serverInfo := make(map[string]interface{})
+ serverInfo["time_status_request_sent"] = time.Now()
+
+ keepInfo[keepServer.String()] = serverInfo
+ })
+ }
+
+ resp, err := client.Get(url)
+ if err != nil {
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Error getting keep status from %s: %v", url, err))
+ } else if resp.StatusCode != 200 {
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Received error code %d in response to request "+
+ "for %s status: %s",
+ resp.StatusCode, url, resp.Status))
+ }
+
+ var keepStatus map[string]interface{}
+ decoder := json.NewDecoder(resp.Body)
+ decoder.UseNumber()
+ err = decoder.Decode(&keepStatus)
+ if err != nil {
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Error decoding keep status from %s: %v", url, err))
+ }
+
+ if arvLogger != nil {
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := p["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+ serverInfo["time_status_response_processed"] = time.Now()
+ serverInfo["status"] = keepStatus
+ })
+ }
+}
+
func CreateIndexRequest(arvLogger *logger.Logger,
keepServer ServerAddress) (req *http.Request) {
url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
@@ -241,10 +291,8 @@ func CreateIndexRequest(arvLogger *logger.Logger,
if arvLogger != nil {
arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
keepInfo := p["keep_info"].(map[string]interface{})
- serverInfo := make(map[string]interface{})
- serverInfo["request_sent"] = time.Now()
-
- keepInfo[keepServer.String()] = serverInfo
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+ serverInfo["time_index_request_sent"] = time.Now()
})
}
@@ -275,7 +323,7 @@ func ReadServerResponse(arvLogger *logger.Logger,
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- serverInfo["response_received"] = time.Now()
+ serverInfo["time_index_response_received"] = time.Now()
})
}
@@ -349,7 +397,7 @@ func ReadServerResponse(arvLogger *logger.Logger,
keepInfo := p["keep_info"].(map[string]interface{})
serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- serverInfo["processing_finished"] = time.Now()
+ serverInfo["time_processing_finished"] = time.Now()
serverInfo["lines_received"] = numLines
serverInfo["duplicates_seen"] = numDuplicates
serverInfo["size_disagreements_seen"] = numSizeDisagreements
commit e88d1643f64e70e984b2c7943e5ce6569e7e2d37
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 27 01:27:37 2015 +0000
Improved erorr message to make it clear what's a size and what's a timestamp.
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index cf6803a..39ac30a 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -302,7 +302,7 @@ func ReadServerResponse(arvLogger *logger.Logger,
numSizeDisagreements += 1
// TODO(misha): Consider failing here.
message := fmt.Sprintf("Saw different sizes for the same block "+
- "on %s: %v %v",
+ "on %s: %+v %+v",
keepServer.String(),
storedBlock,
blockInfo)
commit 6db8f01ae7f8d30f48a88caa351004ea446b33b3
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 27 01:06:21 2015 +0000
Renamed BlockDigest's ToString() to String() to implement fmt.Stringer() interface so that we get more readable error messages when structs contain BlockDigests.
diff --git a/sdk/go/blockdigest/blockdigest.go b/sdk/go/blockdigest/blockdigest.go
index 0742839..9b818d3 100644
--- a/sdk/go/blockdigest/blockdigest.go
+++ b/sdk/go/blockdigest/blockdigest.go
@@ -15,7 +15,7 @@ type BlockDigest struct {
l uint64
}
-func (d *BlockDigest) ToString() (s string) {
+func (d BlockDigest) String() string {
return fmt.Sprintf("%016x%016x", d.h, d.l)
}
diff --git a/sdk/go/blockdigest/blockdigest_test.go b/sdk/go/blockdigest/blockdigest_test.go
index 9081bb8..068a138 100644
--- a/sdk/go/blockdigest/blockdigest_test.go
+++ b/sdk/go/blockdigest/blockdigest_test.go
@@ -1,6 +1,7 @@
package blockdigest
import (
+ "fmt"
"strings"
"testing"
)
@@ -13,8 +14,8 @@ func expectValidDigestString(t *testing.T, s string) {
expected := strings.ToLower(s)
- if expected != bd.ToString() {
- t.Fatalf("Expected %s to be returned by FromString(%s).ToString() but instead we received %s", expected, s, bd.ToString())
+ if expected != bd.String() {
+ t.Fatalf("Expected %s to be returned by FromString(%s).String() but instead we received %s", expected, s, bd.String())
}
}
@@ -43,3 +44,36 @@ func TestBlockDigestWorksAsMapKey(t *testing.T) {
bd := AssertFromString("01234567890123456789abcdefabcdef")
m[bd] = 5
}
+
+func TestBlockDigestGetsPrettyPrintedByPrintf(t *testing.T) {
+ input := "01234567890123456789abcdefabcdef"
+ prettyPrinted := fmt.Sprintf("%v", AssertFromString(input))
+ if prettyPrinted != input {
+ t.Fatalf("Expected blockDigest produced from \"%s\" to be printed as " +
+ "\"%s\", but instead it was printed as %s",
+ input, input, prettyPrinted)
+ }
+}
+
+func TestBlockDigestGetsPrettyPrintedByPrintfInNestedStructs(t *testing.T) {
+ input := "01234567890123456789abcdefabcdef"
+ value := 42
+ nested := struct{
+ // Fun trivia fact: If this field was called "digest" instead of
+ // "Digest", then it would not be exported and String() would
+ // never get called on it and our output would look very
+ // different.
+ Digest BlockDigest
+ value int
+ }{
+ AssertFromString(input),
+ value,
+ }
+ prettyPrinted := fmt.Sprintf("%+v", nested)
+ expected := fmt.Sprintf("{Digest:%s value:%d}", input, value)
+ if prettyPrinted != expected {
+ t.Fatalf("Expected blockDigest produced from \"%s\" to be printed as " +
+ "\"%s\", but instead it was printed as %s",
+ input, expected, prettyPrinted)
+ }
+}
commit 4df1175e30c21850af394fcd60c9bb7ca3d981a5
Author: mishaz <misha at curoverse.com>
Date: Sat Jan 24 02:22:01 2015 +0000
A bunch of changes, most in response to Peter's review.
Logger:
Edit() and Record() have been replaced with the single Update() method which takes a function as input (suggested by Tom).
lastWrite replaced by nextWriteAllowed, for cleaner logic
Added writeScheduled to reduce the number of writes scheduled and attempted, thereby reducing lock contention
Added sanity-checking of params
A bunch of overdue cleanup
Update documentation to reflect the above changes
Manifest:
Renamed ManifestLine to ManifestStream
Util:
Deleted a lot of crap that proved less useful than I thought.
Moved collection.NumberCollectionsAvailable() to util.NumberItemsAvailable() and made it more generic.
collection:
Just cleanup in response to changes in above packages.
keep:
Switched Mtime from int to int64 to avoid y2038 problems.
Switched approach for avoiding keep proxy from using "accessible" to filtering on service_type = disk.
Cleanup in response to changes in above packages.
loggerutil:
Cleanup in response to changes in logger.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index 11c6b53..ca344be 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -1,27 +1,23 @@
// Logger periodically writes a log to the Arvados SDK.
//
-// This package is useful for maintaining a log object that is built
-// up over time. Every time the object is modified, it will be written
-// to the log. Writes will be throttled to no more than one every
+// This package is useful for maintaining a log object that is updated
+// over time. Every time the object is updated, it will be written to
+// the log. Writes will be throttled to no more than one every
// WriteFrequencySeconds
//
// This package is safe for concurrent use as long as:
-// 1. The maps returned by Edit() are only edited in the same routine
-// that called Edit()
-// 2. Those maps not edited after calling Record()
-// An easy way to assure this is true is to place the call to Edit()
-// within a short block as shown below in the Usage Example:
+// The maps passed to a LogMutator are not accessed outside of the
+// LogMutator
//
// Usage:
// arvLogger := logger.NewLogger(params)
-// {
-// properties, entry := arvLogger.Edit() // This will block if others are using the logger
+// arvLogger.Update(func(properties map[string]interface{},
+// entry map[string]interface{}) {
// // Modifiy properties and entry however you want
// // properties is a shortcut for entry["properties"].(map[string]interface{})
// // properties can take any values you want to give it,
// // entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
-// }
-// arvLogger.Record() // This triggers the actual log write
+// })
package logger
import (
@@ -51,24 +47,32 @@ type LogMutator func(map[string]interface{}, map[string]interface{})
// A Logger is used to build up a log entry over time and write every
// version of it.
type Logger struct {
- // The Data we write
+ // The data we write
data map[string]interface{} // The entire map that we give to the api
entry map[string]interface{} // Convenience shortcut into data
properties map[string]interface{} // Convenience shortcut into data
- lock sync.Locker // Synchronizes editing and writing
+ lock sync.Locker // Synchronizes access to this struct
params LoggerParams // Parameters we were given
- // TODO(misha): replace lastWrite with nextWriteAllowed
- lastWrite time.Time // The last time we wrote a log entry
- modified bool // Has this data been modified since the last write
+ // Variables used to determine when and if we write to the log.
+ nextWriteAllowed time.Time // The next time we can write, respecting MinimumWriteInterval
+ modified bool // Has this data been modified since the last write?
+ writeScheduled bool // Is a write been scheduled for the future?
- writeHooks []LogMutator
+ writeHooks []LogMutator // Mutators we call before each write.
}
// Create a new logger based on the specified parameters.
func NewLogger(params LoggerParams) *Logger {
- // TODO(misha): Add some params checking here.
+ // sanity check parameters
+ if ¶ms.Client == nil {
+ log.Fatal("Nil arvados client in LoggerParams passed in to NewLogger()")
+ }
+ if params.EventType == "" {
+ log.Fatal("Empty event type in LoggerParams passed in to NewLogger()")
+ }
+
l := &Logger{data: make(map[string]interface{}),
lock: &sync.Mutex{},
params: params}
@@ -79,68 +83,85 @@ func NewLogger(params LoggerParams) *Logger {
return l
}
-// Get access to the maps you can edit. This will hold a lock until
-// you call Record. Do not edit the maps in any other goroutines or
-// after calling Record.
-// You don't need to edit both maps,
-// properties can take any values you want to give it,
-// entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
-// properties is a shortcut for entry["properties"].(map[string]interface{})
-func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]interface{}) {
+// Updates the log data and then writes it to the api server. If the
+// log has been recently written then the write will be postponed to
+// respect MinimumWriteInterval and this function will return before
+// the write occurs.
+func (l *Logger) Update(mutator LogMutator) {
l.lock.Lock()
- l.modified = true // We don't actually know the caller will modifiy the data, but we assume they will.
- return l.properties, l.entry
+ mutator(l.properties, l.entry)
+ l.modified = true // We assume the mutator modified the log, even though we don't know for sure.
+
+ l.considerWriting()
+
+ l.lock.Unlock()
}
-// function to test new api, replacing Edit() and Record()
-func (l *Logger) MutateLog(mutator LogMutator) {
- mutator(l.Edit())
- l.Record()
+// Similar to Update(), but forces a write without respecting the
+// MinimumWriteInterval. This is useful if you know that you're about
+// to quit (e.g. if you discovered a fatal error, or you're finished),
+// since go will not wait for timers (including the pending write
+// timer) to go off before exiting.
+func (l *Logger) ForceUpdate(mutator LogMutator) {
+ l.lock.Lock()
+
+ mutator(l.properties, l.entry)
+ l.modified = true // We assume the mutator modified the log, even though we don't know for sure.
+
+ l.write()
+ l.lock.Unlock()
}
// Adds a hook which will be called every time this logger writes an entry.
-// The hook takes properties and entry as arguments, in that order.
-// This is useful for stuff like memory profiling.
-// This must be called between Edit() and Record() (e.g. while holding the lock)
func (l *Logger) AddWriteHook(hook LogMutator) {
- // TODO(misha): Acquire lock here! and erase comment about edit.
+ l.lock.Lock()
l.writeHooks = append(l.writeHooks, hook)
- // TODO(misha): consider flipping the dirty bit here.
+ // TODO(misha): Consider setting modified and attempting a write.
+ l.lock.Unlock()
+}
+
+// This function is called on a timer when we have something to write,
+// but need to schedule the write for the future to respect
+// MinimumWriteInterval.
+func (l *Logger) acquireLockConsiderWriting() {
+ l.lock.Lock()
+
+ // We are the scheduled write, so there are no longer future writes
+ // scheduled.
+ l.writeScheduled = false
+
+ l.considerWriting()
+
+ l.lock.Unlock()
}
-// Write the log entry you've built up so far. Do not edit the maps
-// returned by Edit() after calling this method.
-// If you have already written within MinimumWriteInterval, then this
-// will schedule a future write instead.
-// In either case, the lock will be released before Record() returns.
-func (l *Logger) Record() {
- if l.writeAllowedNow() {
- // We haven't written in the allowed interval yet, try to write.
+// The above methods each acquire the lock and release it.
+// =======================================================
+// The below methods all assume we're holding a lock.
+
+// Check whether we have anything to write. If we do, then either
+// write it now or later, based on what we're allowed.
+func (l *Logger) considerWriting() {
+ if !l.modified {
+ // Nothing to write
+ } else if l.writeAllowedNow() {
l.write()
+ } else if l.writeScheduled {
+ // A future write is already scheduled, we don't need to do anything.
} else {
- // TODO(misha): Only allow one outstanding write to be scheduled.
- nextTimeToWrite := l.lastWrite.Add(l.params.MinimumWriteInterval)
- writeAfter := nextTimeToWrite.Sub(time.Now())
+ writeAfter := l.nextWriteAllowed.Sub(time.Now())
time.AfterFunc(writeAfter, l.acquireLockConsiderWriting)
+ l.writeScheduled = true
}
- l.lock.Unlock()
}
-// Similar to Record, but forces a write without respecting the
-// MinimumWriteInterval. This is useful if you know that you're about
-// to quit (e.g. if you discovered a fatal error).
-func (l *Logger) ForceRecord() {
- l.write()
- l.lock.Unlock()
-}
-
-// Whether enough time has elapsed since the last write.
+// Whether writing now would respect MinimumWriteInterval
func (l *Logger) writeAllowedNow() bool {
- return l.lastWrite.Add(l.params.MinimumWriteInterval).Before(time.Now())
+ return l.nextWriteAllowed.Before(time.Now())
}
-// Actually writes the log entry. This method assumes we're holding the lock.
+// Actually writes the log entry.
func (l *Logger) write() {
// Run all our hooks
@@ -159,15 +180,6 @@ func (l *Logger) write() {
}
// Update stats.
- l.lastWrite = time.Now()
+ l.nextWriteAllowed = time.Now().Add(l.params.MinimumWriteInterval)
l.modified = false
}
-
-func (l *Logger) acquireLockConsiderWriting() {
- l.lock.Lock()
- if l.modified && l.writeAllowedNow() {
- // We have something new to write and we're allowed to write.
- l.write()
- }
- l.lock.Unlock()
-}
diff --git a/sdk/go/manifest/manifest.go b/sdk/go/manifest/manifest.go
index c9f9018..f6698c6 100644
--- a/sdk/go/manifest/manifest.go
+++ b/sdk/go/manifest/manifest.go
@@ -26,7 +26,8 @@ type BlockLocator struct {
Hints []string
}
-type ManifestLine struct {
+// Represents a single line from a manifest.
+type ManifestStream struct {
StreamName string
Blocks []string
Files []string
@@ -59,7 +60,7 @@ func ParseBlockLocator(s string) (b BlockLocator, err error) {
return
}
-func parseManifestLine(s string) (m ManifestLine) {
+func parseManifestStream(s string) (m ManifestStream) {
tokens := strings.Split(s, " ")
m.StreamName = tokens[0]
tokens = tokens[1:]
@@ -74,8 +75,8 @@ func parseManifestLine(s string) (m ManifestLine) {
return
}
-func (m *Manifest) LineIter() <-chan ManifestLine {
- ch := make(chan ManifestLine)
+func (m *Manifest) StreamIter() <-chan ManifestStream {
+ ch := make(chan ManifestStream)
go func(input string) {
// This slice holds the current line and the remainder of the
// manifest. We parse one line at a time, to save effort if we
@@ -85,7 +86,7 @@ func (m *Manifest) LineIter() <-chan ManifestLine {
lines = strings.SplitN(lines[1], "\n", 2)
if len(lines[0]) > 0 {
// Only parse non-blank lines
- ch <- parseManifestLine(lines[0])
+ ch <- parseManifestStream(lines[0])
}
if len(lines) == 1 {
break
@@ -101,8 +102,8 @@ func (m *Manifest) LineIter() <-chan ManifestLine {
// the same block multiple times.
func (m *Manifest) BlockIterWithDuplicates() <-chan BlockLocator {
blockChannel := make(chan BlockLocator)
- go func(lineChannel <-chan ManifestLine) {
- for m := range lineChannel {
+ go func(streamChannel <-chan ManifestStream) {
+ for m := range streamChannel {
for _, block := range m.Blocks {
if b, err := ParseBlockLocator(block); err == nil {
blockChannel <- b
@@ -112,6 +113,6 @@ func (m *Manifest) BlockIterWithDuplicates() <-chan BlockLocator {
}
}
close(blockChannel)
- }(m.LineIter())
+ }(m.StreamIter())
return blockChannel
}
diff --git a/sdk/go/manifest/manifest_test.go b/sdk/go/manifest/manifest_test.go
index f8641ce..c1bfb14 100644
--- a/sdk/go/manifest/manifest_test.go
+++ b/sdk/go/manifest/manifest_test.go
@@ -57,7 +57,7 @@ func expectStringSlicesEqual(t *testing.T, actual []string, expected []string) {
}
}
-func expectManifestLine(t *testing.T, actual ManifestLine, expected ManifestLine) {
+func expectManifestStream(t *testing.T, actual ManifestStream, expected ManifestStream) {
expectEqual(t, actual.StreamName, expected.StreamName)
expectStringSlicesEqual(t, actual.Blocks, expected.Blocks)
expectStringSlicesEqual(t, actual.Files, expected.Files)
@@ -108,9 +108,9 @@ func TestLocatorPatternBasic(t *testing.T) {
expectLocatorPatternFail(t, "12345678901234567890123456789012+12345+A+B2")
}
-func TestParseManifestLineSimple(t *testing.T) {
- m := parseManifestLine(". 365f83f5f808896ec834c8b595288735+2310+K at qr1hi+Af0c9a66381f3b028677411926f0be1c6282fe67c@542b5ddf 0:2310:qr1hi-8i9sb-ienvmpve1a0vpoi.log.txt")
- expectManifestLine(t, m, ManifestLine{StreamName: ".",
+func TestParseManifestStreamSimple(t *testing.T) {
+ m := parseManifestStream(". 365f83f5f808896ec834c8b595288735+2310+K at qr1hi+Af0c9a66381f3b028677411926f0be1c6282fe67c@542b5ddf 0:2310:qr1hi-8i9sb-ienvmpve1a0vpoi.log.txt")
+ expectManifestStream(t, m, ManifestStream{StreamName: ".",
Blocks: []string{"365f83f5f808896ec834c8b595288735+2310+K at qr1hi+Af0c9a66381f3b028677411926f0be1c6282fe67c@542b5ddf"},
Files: []string{"0:2310:qr1hi-8i9sb-ienvmpve1a0vpoi.log.txt"}})
}
@@ -126,24 +126,24 @@ func TestParseBlockLocatorSimple(t *testing.T) {
"Af0c9a66381f3b028677411926f0be1c6282fe67c at 542b5ddf"}})
}
-func TestLineIterShortManifestWithBlankLines(t *testing.T) {
+func TestStreamIterShortManifestWithBlankStreams(t *testing.T) {
content, err := ioutil.ReadFile("testdata/short_manifest")
if err != nil {
t.Fatalf("Unexpected error reading manifest from file: %v", err)
}
manifest := Manifest{string(content)}
- lineIter := manifest.LineIter()
+ streamIter := manifest.StreamIter()
- firstLine := <-lineIter
- expectManifestLine(t,
- firstLine,
- ManifestLine{StreamName: ".",
+ firstStream := <-streamIter
+ expectManifestStream(t,
+ firstStream,
+ ManifestStream{StreamName: ".",
Blocks: []string{"b746e3d2104645f2f64cd3cc69dd895d+15693477+E2866e643690156651c03d876e638e674dcd79475 at 5441920c"},
Files: []string{"0:15893477:chr10_band0_s0_e3000000.fj"}})
- received, ok := <- lineIter
+ received, ok := <- streamIter
if ok {
- t.Fatalf("Expected lineIter to be closed, but received %v instead.",
+ t.Fatalf("Expected streamIter to be closed, but received %v instead.",
received)
}
}
diff --git a/sdk/go/util/util.go b/sdk/go/util/util.go
index 4505db6..6bc8625 100644
--- a/sdk/go/util/util.go
+++ b/sdk/go/util/util.go
@@ -3,40 +3,9 @@
package util
import (
- "errors"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
- "log"
)
-type SdkListResponse interface {
- NumItemsAvailable() (int, error)
- NumItemsContained() (int, error)
-}
-
-type UnstructuredSdkListResponse map[string]interface{}
-
-func (m UnstructuredSdkListResponse) NumItemsAvailable() (numAvailable int, err error) {
- if itemsAvailable, ok := m["items_available"]; !ok {
- err = errors.New("Could not find \"items_available\" field in " +
- "UnstructuredSdkListResponse that NumItemsAvailable was called on.")
- } else {
- // TODO(misha): Check whether this assertion will work before casting
- numAvailable = int(itemsAvailable.(float64))
- }
- return
-}
-
-func (m UnstructuredSdkListResponse) NumItemsContained() (numContained int, err error) {
- if value, ok := m["items"]; ok {
- // TODO(misha): check whether this assertion will work before casting
- numContained = len(value.([]interface{}))
- } else {
- err = errors.New(`Could not find "items" field in ` +
- "UnstructuredSdkListResponse that NumItemsContained was called on.")
- }
- return
-}
-
func UserIsAdmin(arv arvadosclient.ArvadosClient) (is_admin bool, err error) {
type user struct {
IsAdmin bool `json:"is_admin"`
@@ -46,38 +15,20 @@ func UserIsAdmin(arv arvadosclient.ArvadosClient) (is_admin bool, err error) {
return u.IsAdmin, err
}
-// TODO(misha): Consider returning an error here instead of fatal'ing
-func ContainsAllAvailableItems(response SdkListResponse) (containsAll bool, numContained int, numAvailable int) {
- var err error
- numContained, err = response.NumItemsContained()
- if err != nil {
- log.Fatalf("Error retrieving number of items contained in SDK response: %v",
- err)
- }
- numAvailable, err = response.NumItemsAvailable()
- if err != nil {
- log.Fatalf("Error retrieving number of items available from "+
- "SDK response: %v",
- err)
+// Returns the total count of a particular type of resource
+//
+// resource - the arvados resource to count
+// return
+// count - the number of items of type resource the api server reports, if no error
+// err - error accessing the resource, or nil if no error
+func NumberItemsAvailable(client arvadosclient.ArvadosClient, resource string) (count int, err error) {
+ var response struct {
+ ItemsAvailable int `json:"items_available"`
}
- containsAll = numContained == numAvailable
- return
-}
-
-func IterateSdkListItems(response map[string]interface{}) (c <-chan map[string]interface{}, err error) {
- if value, ok := response["items"]; ok {
- ch := make(chan map[string]interface{})
- c = ch
- items := value.([]interface{})
- go func() {
- for _, item := range items {
- ch <- item.(map[string]interface{})
- }
- close(ch)
- }()
- } else {
- err = errors.New("Could not find \"items\" field in response " +
- "passed to IterateSdkListItems()")
+ sdkParams := arvadosclient.Dict{"limit": 0}
+ err = client.List(resource, sdkParams, &response)
+ if err == nil {
+ count = response.ItemsAvailable
}
return
}
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 73115f5..424db83 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -9,6 +9,7 @@ import (
"git.curoverse.com/arvados.git/sdk/go/blockdigest"
"git.curoverse.com/arvados.git/sdk/go/logger"
"git.curoverse.com/arvados.git/sdk/go/manifest"
+ "git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/loggerutil"
"log"
"os"
@@ -101,10 +102,13 @@ func GetCollectionsAndSummarize(params GetCollectionsParams) (results ReadCollec
ComputeSizeOfOwnedCollections(&results)
if params.Logger != nil {
- properties, _ := params.Logger.Edit()
- collectionInfo := properties["collection_info"].(map[string]interface{})
- collectionInfo["owner_to_collection_size"] = results.OwnerToCollectionSize
- params.Logger.Record()
+ params.Logger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ collectionInfo := p["collection_info"].(map[string]interface{})
+ // Since maps are shallow copied, we run a risk of concurrent
+ // updates here. By copying results.OwnerToCollectionSize into
+ // the log, we're assuming that it won't be updated.
+ collectionInfo["owner_to_collection_size"] = results.OwnerToCollectionSize
+ })
}
log.Printf("Uuid to Size used: %v", results.OwnerToCollectionSize)
@@ -143,7 +147,12 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
sdkParams["limit"] = params.BatchSize
}
- initialNumberOfCollectionsAvailable := NumberCollectionsAvailable(params.Client)
+ initialNumberOfCollectionsAvailable, err :=
+ util.NumberItemsAvailable(params.Client, "collections")
+ if err != nil {
+ loggerutil.FatalWithMessage(params.Logger,
+ fmt.Sprintf("Error querying collection count: %v", err))
+ }
// Include a 1% margin for collections added while we're reading so
// that we don't have to grow the map in most cases.
maxExpectedCollections := int(
@@ -151,12 +160,12 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
results.UuidToCollection = make(map[string]Collection, maxExpectedCollections)
if params.Logger != nil {
- properties, _ := params.Logger.Edit()
- collectionInfo := make(map[string]interface{})
- collectionInfo["num_collections_at_start"] = initialNumberOfCollectionsAvailable
- collectionInfo["batch_size"] = params.BatchSize
- properties["collection_info"] = collectionInfo
- params.Logger.Record()
+ params.Logger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ collectionInfo := make(map[string]interface{})
+ collectionInfo["num_collections_at_start"] = initialNumberOfCollectionsAvailable
+ collectionInfo["batch_size"] = params.BatchSize
+ p["collection_info"] = collectionInfo
+ })
}
// These values are just for getting the loop to run the first time,
@@ -196,13 +205,13 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
maxManifestSize, totalManifestSize)
if params.Logger != nil {
- properties, _ := params.Logger.Edit()
- collectionInfo := properties["collection_info"].(map[string]interface{})
- collectionInfo["collections_read"] = totalCollections
- collectionInfo["latest_modified_date_seen"] = sdkParams["filters"].([][]string)[0][2]
- collectionInfo["total_manifest_size"] = totalManifestSize
- collectionInfo["max_manifest_size"] = maxManifestSize
- params.Logger.Record()
+ params.Logger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ collectionInfo := p["collection_info"].(map[string]interface{})
+ collectionInfo["collections_read"] = totalCollections
+ collectionInfo["latest_modified_date_seen"] = sdkParams["filters"].([][]string)[0][2]
+ collectionInfo["total_manifest_size"] = totalManifestSize
+ collectionInfo["max_manifest_size"] = maxManifestSize
+ })
}
}
@@ -282,17 +291,6 @@ func ProcessCollections(arvLogger *logger.Logger,
return
}
-func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) int {
- var collections SdkCollectionList
- sdkParams := arvadosclient.Dict{"limit": 0}
- err := client.List("collections", sdkParams, &collections)
- if err != nil {
- log.Fatalf("error querying collections for items available: %v", err)
- }
-
- return collections.ItemsAvailable
-}
-
func ComputeSizeOfOwnedCollections(readCollections *ReadCollections) {
readCollections.OwnerToCollectionSize = make(map[string]int)
for _, coll := range readCollections.UuidToCollection {
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 97c911d..cbdae6e 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -53,8 +53,7 @@ func main() {
}
if arvLogger != nil {
- arvLogger.MutateLog(func(properties map[string]interface{},
- entry map[string]interface{}) {
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
runInfo := make(map[string]interface{})
runInfo["start_time"] = time.Now()
runInfo["args"] = os.Args
@@ -65,12 +64,10 @@ func main() {
runInfo["hostname"] = hostname
}
runInfo["pid"] = os.Getpid()
- properties["run_info"] = runInfo
+ p["run_info"] = runInfo
})
- arvLogger.Edit()
arvLogger.AddWriteHook(LogMemoryAlloc)
- arvLogger.Record()
}
collectionChannel := make(chan collection.ReadCollections)
@@ -86,19 +83,20 @@ func main() {
readCollections := <-collectionChannel
- // Make compiler happy.
+ // TODO(misha): Use these together to verify replication.
_ = readCollections
_ = keepServerInfo
- // Log that we're finished
+ // Log that we're finished. We force the recording, since go will
+ // not wait for the timer before exiting.
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
- // Force the recording, since go will not wait for the timer before exiting.
- arvLogger.ForceRecord()
+ arvLogger.ForceUpdate(func(p map[string]interface{}, e map[string]interface{}) {
+ p["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ })
}
}
+// TODO(misha): Consider moving this to loggerutil
func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
runInfo := properties["run_info"].(map[string]interface{})
var memStats runtime.MemStats
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 97bbf9d..cf6803a 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -6,12 +6,10 @@ import (
"bufio"
"flag"
"fmt"
- //"git.curoverse.com/arvados.git/sdk/go/keepclient"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/blockdigest"
"git.curoverse.com/arvados.git/sdk/go/logger"
"git.curoverse.com/arvados.git/sdk/go/manifest"
- "git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/loggerutil"
"io/ioutil"
"log"
@@ -31,14 +29,14 @@ type ServerAddress struct {
type BlockInfo struct {
Digest blockdigest.BlockDigest
Size int
- Mtime int // TODO(misha): Replace this with a timestamp.
+ Mtime int64 // TODO(misha): Replace this with a timestamp.
}
// Info about a specified block given by a server
type BlockServerInfo struct {
ServerIndex int
Size int
- Mtime int // TODO(misha): Replace this with a timestamp.
+ Mtime int64 // TODO(misha): Replace this with a timestamp.
}
type ServerContents struct {
@@ -137,47 +135,39 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
"contain a valid ArvadosClient, but instead it is nil.")
}
- sdkParams := arvadosclient.Dict{}
+ sdkParams := arvadosclient.Dict{
+ "filters": [][]string{[]string{"service_type", "=", "disk"}},
+ }
if params.Limit > 0 {
sdkParams["limit"] = params.Limit
}
var sdkResponse KeepServiceList
- err := params.Client.Call("GET", "keep_services", "", "accessible", sdkParams, &sdkResponse)
+ err := params.Client.List("keep_services", sdkParams, &sdkResponse)
if err != nil {
loggerutil.FatalWithMessage(params.Logger,
fmt.Sprintf("Error requesting keep disks from API server: %v", err))
}
- // TODO(misha): Rewrite this block, stop using ContainsAllAvailableItems()
- {
- var numReceived, numAvailable int
- results.ReadAllServers, numReceived, numAvailable =
- util.ContainsAllAvailableItems(sdkResponse)
-
- if !results.ReadAllServers {
- log.Printf("ERROR: Did not receive all keep server addresses.")
- }
- log.Printf("Received %d of %d available keep server addresses.",
- numReceived,
- numAvailable)
- }
-
if params.Logger != nil {
- properties, _ := params.Logger.Edit()
- keepInfo := make(map[string]interface{})
-
- keepInfo["num_keep_servers_available"] = sdkResponse.ItemsAvailable
- keepInfo["num_keep_servers_received"] = len(sdkResponse.KeepServers)
- keepInfo["keep_servers"] = sdkResponse.KeepServers
+ params.Logger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := make(map[string]interface{})
- properties["keep_info"] = keepInfo
+ keepInfo["num_keep_servers_available"] = sdkResponse.ItemsAvailable
+ keepInfo["num_keep_servers_received"] = len(sdkResponse.KeepServers)
+ keepInfo["keep_servers"] = sdkResponse.KeepServers
- params.Logger.Record()
+ p["keep_info"] = keepInfo
+ })
}
- log.Printf("Received keep services list: %v", sdkResponse)
+ log.Printf("Received keep services list: %+v", sdkResponse)
+
+ if len(sdkResponse.KeepServers) < sdkResponse.ItemsAvailable {
+ loggerutil.FatalWithMessage(params.Logger,
+ fmt.Sprintf("Did not receive all available keep servers: %+v", sdkResponse))
+ }
results.KeepServerIndexToAddress = sdkResponse.KeepServers
results.KeepServerAddressToIndex = make(map[ServerAddress]int)
@@ -249,14 +239,13 @@ func CreateIndexRequest(arvLogger *logger.Logger,
log.Println("About to fetch keep server contents from " + url)
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- keepInfo := properties["keep_info"].(map[string]interface{})
- serverInfo := make(map[string]interface{})
- serverInfo["request_sent"] = time.Now()
-
- keepInfo[keepServer.String()] = serverInfo
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := p["keep_info"].(map[string]interface{})
+ serverInfo := make(map[string]interface{})
+ serverInfo["request_sent"] = time.Now()
- arvLogger.Record()
+ keepInfo[keepServer.String()] = serverInfo
+ })
}
req, err := http.NewRequest("GET", url, nil)
@@ -282,13 +271,12 @@ func ReadServerResponse(arvLogger *logger.Logger,
}
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- keepInfo := properties["keep_info"].(map[string]interface{})
- serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
-
- serverInfo["response_received"] = time.Now()
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := p["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- arvLogger.Record()
+ serverInfo["response_received"] = time.Now()
+ })
}
response.Address = keepServer
@@ -320,16 +308,16 @@ func ReadServerResponse(arvLogger *logger.Logger,
blockInfo)
log.Println(message)
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- keepInfo := properties["keep_info"].(map[string]interface{})
- serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
- var error_list []string
- read_error_list, has_list := serverInfo["error_list"]
- if has_list {
- error_list = read_error_list.([]string)
- } // If we didn't have the list, error_list is already an empty list
- serverInfo["error_list"] = append(error_list, message)
- arvLogger.Record()
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := p["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+ var error_list []string
+ read_error_list, has_list := serverInfo["error_list"]
+ if has_list {
+ error_list = read_error_list.([]string)
+ } // If we didn't have the list, error_list is already an empty list
+ serverInfo["error_list"] = append(error_list, message)
+ })
}
}
// Keep the block that is bigger, or the block that's newer in
@@ -357,16 +345,15 @@ func ReadServerResponse(arvLogger *logger.Logger,
numSizeDisagreements)
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- keepInfo := properties["keep_info"].(map[string]interface{})
- serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
-
- serverInfo["processing_finished"] = time.Now()
- serverInfo["lines_received"] = numLines
- serverInfo["dupicates_seen"] = numDuplicates
- serverInfo["size_disagreements_seen"] = numSizeDisagreements
-
- arvLogger.Record()
+ arvLogger.Update(func(p map[string]interface{}, e map[string]interface{}) {
+ keepInfo := p["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+
+ serverInfo["processing_finished"] = time.Now()
+ serverInfo["lines_received"] = numLines
+ serverInfo["duplicates_seen"] = numDuplicates
+ serverInfo["size_disagreements_seen"] = numSizeDisagreements
+ })
}
}
resp.Body.Close()
@@ -392,7 +379,7 @@ func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err err
return
}
- blockInfo.Mtime, err = strconv.Atoi(tokens[1])
+ blockInfo.Mtime, err = strconv.ParseInt(tokens[1], 10, 64)
if err != nil {
return
}
diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
index f97f7c1..20b7f18 100644
--- a/services/datamanager/loggerutil/loggerutil.go
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -13,10 +13,10 @@ import (
// for the lock you're already holding.
func FatalWithMessage(arvLogger *logger.Logger, message string) {
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- properties["FATAL"] = message
- properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
- arvLogger.ForceRecord()
+ arvLogger.ForceUpdate(func(p map[string]interface{}, e map[string]interface{}) {
+ p["FATAL"] = message
+ p["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ })
}
log.Fatalf(message)
commit c2b8ab7045886b62963feb0cd8f9b9291ce1a8b7
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 21 01:34:29 2015 +0000
Added comment, ran gofmt.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index 2a4a962..11c6b53 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -59,6 +59,7 @@ type Logger struct {
lock sync.Locker // Synchronizes editing and writing
params LoggerParams // Parameters we were given
+ // TODO(misha): replace lastWrite with nextWriteAllowed
lastWrite time.Time // The last time we wrote a log entry
modified bool // Has this data been modified since the last write
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index deeea5d..97c911d 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -55,18 +55,18 @@ func main() {
if arvLogger != nil {
arvLogger.MutateLog(func(properties map[string]interface{},
entry map[string]interface{}) {
- runInfo := make(map[string]interface{})
- runInfo["start_time"] = time.Now()
- runInfo["args"] = os.Args
- hostname, err := os.Hostname()
- if err != nil {
- runInfo["hostname_error"] = err.Error()
- } else {
- runInfo["hostname"] = hostname
- }
- runInfo["pid"] = os.Getpid()
- properties["run_info"] = runInfo
- })
+ runInfo := make(map[string]interface{})
+ runInfo["start_time"] = time.Now()
+ runInfo["args"] = os.Args
+ hostname, err := os.Hostname()
+ if err != nil {
+ runInfo["hostname_error"] = err.Error()
+ } else {
+ runInfo["hostname"] = hostname
+ }
+ runInfo["pid"] = os.Getpid()
+ properties["run_info"] = runInfo
+ })
arvLogger.Edit()
arvLogger.AddWriteHook(LogMemoryAlloc)
commit 17800e7d4a9574035dd48b71ec4247f70525d45e
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 21 01:31:17 2015 +0000
Added Logger.MutateLog() on Tom's suggestion. Tried it out in one instance to make sure it works.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index ea0be33..2a4a962 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -37,6 +37,17 @@ type LoggerParams struct {
MinimumWriteInterval time.Duration // Wait at least this long between log writes
}
+// A LogMutator is a function which modifies the log entry.
+// It takes two maps as arguments, properties is the first and entry
+// is the second
+// properties is a shortcut for entry["properties"].(map[string]interface{})
+// properties can take any values you want to give it.
+// entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
+// properties and entry are only safe to access inside the LogMutator,
+// they should not be stored anywhere, otherwise you'll risk
+// concurrent access.
+type LogMutator func(map[string]interface{}, map[string]interface{})
+
// A Logger is used to build up a log entry over time and write every
// version of it.
type Logger struct {
@@ -51,7 +62,7 @@ type Logger struct {
lastWrite time.Time // The last time we wrote a log entry
modified bool // Has this data been modified since the last write
- writeHooks []func(map[string]interface{}, map[string]interface{})
+ writeHooks []LogMutator
}
// Create a new logger based on the specified parameters.
@@ -81,13 +92,20 @@ func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]int
return l.properties, l.entry
}
+// function to test new api, replacing Edit() and Record()
+func (l *Logger) MutateLog(mutator LogMutator) {
+ mutator(l.Edit())
+ l.Record()
+}
+
// Adds a hook which will be called every time this logger writes an entry.
// The hook takes properties and entry as arguments, in that order.
// This is useful for stuff like memory profiling.
// This must be called between Edit() and Record() (e.g. while holding the lock)
-func (l *Logger) AddWriteHook(hook func(map[string]interface{},
- map[string]interface{})) {
+func (l *Logger) AddWriteHook(hook LogMutator) {
+ // TODO(misha): Acquire lock here! and erase comment about edit.
l.writeHooks = append(l.writeHooks, hook)
+ // TODO(misha): consider flipping the dirty bit here.
}
// Write the log entry you've built up so far. Do not edit the maps
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index e73bdb9..deeea5d 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -53,21 +53,23 @@ func main() {
}
if arvLogger != nil {
- properties, _ := arvLogger.Edit()
- runInfo := make(map[string]interface{})
- runInfo["start_time"] = time.Now()
- runInfo["args"] = os.Args
- hostname, err := os.Hostname()
- if err != nil {
- runInfo["hostname_error"] = err.Error()
- } else {
- runInfo["hostname"] = hostname
- }
- runInfo["pid"] = os.Getpid()
- properties["run_info"] = runInfo
-
+ arvLogger.MutateLog(func(properties map[string]interface{},
+ entry map[string]interface{}) {
+ runInfo := make(map[string]interface{})
+ runInfo["start_time"] = time.Now()
+ runInfo["args"] = os.Args
+ hostname, err := os.Hostname()
+ if err != nil {
+ runInfo["hostname_error"] = err.Error()
+ } else {
+ runInfo["hostname"] = hostname
+ }
+ runInfo["pid"] = os.Getpid()
+ properties["run_info"] = runInfo
+ })
+
+ arvLogger.Edit()
arvLogger.AddWriteHook(LogMemoryAlloc)
-
arvLogger.Record()
}
@@ -98,7 +100,6 @@ func main() {
}
func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
- _ = entry // keep the compiler from complaining
runInfo := properties["run_info"].(map[string]interface{})
var memStats runtime.MemStats
runtime.ReadMemStats(&memStats)
commit 7924fe7d6b4cee88035046005425ce19260c09e9
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 14 01:40:50 2015 +0000
Finished adding logging to keep.GetServerContents but have not tested fully yet.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index ff57127..ea0be33 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -100,6 +100,7 @@ func (l *Logger) Record() {
// We haven't written in the allowed interval yet, try to write.
l.write()
} else {
+ // TODO(misha): Only allow one outstanding write to be scheduled.
nextTimeToWrite := l.lastWrite.Add(l.params.MinimumWriteInterval)
writeAfter := nextTimeToWrite.Sub(time.Now())
time.AfterFunc(writeAfter, l.acquireLockConsiderWriting)
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 6e97f57..97bbf9d 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -19,6 +19,7 @@ import (
"strconv"
"strings"
"sync"
+ "time"
)
type ServerAddress struct {
@@ -235,7 +236,8 @@ func GetServerContents(arvLogger *logger.Logger,
req := CreateIndexRequest(arvLogger, keepServer)
resp, err := client.Do(req)
if err != nil {
- log.Fatalf("Error fetching %s: %v", req.URL.String(), err)
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Error fetching %s: %v", req.URL.String(), err))
}
return ReadServerResponse(arvLogger, keepServer, resp)
@@ -243,13 +245,24 @@ func GetServerContents(arvLogger *logger.Logger,
func CreateIndexRequest(arvLogger *logger.Logger,
keepServer ServerAddress) (req *http.Request) {
- // Create and send request.
url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
log.Println("About to fetch keep server contents from " + url)
+ if arvLogger != nil {
+ properties, _ := arvLogger.Edit()
+ keepInfo := properties["keep_info"].(map[string]interface{})
+ serverInfo := make(map[string]interface{})
+ serverInfo["request_sent"] = time.Now()
+
+ keepInfo[keepServer.String()] = serverInfo
+
+ arvLogger.Record()
+ }
+
req, err := http.NewRequest("GET", url, nil)
if err != nil {
- log.Fatalf("Error building http request for %s: %v", url, err)
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Error building http request for %s: %v", url, err))
}
req.Header.Add("Authorization",
@@ -262,8 +275,20 @@ func ReadServerResponse(arvLogger *logger.Logger,
resp *http.Response) (response ServerResponse) {
if resp.StatusCode != 200 {
- log.Fatalf("Received error code %d in response to request for %s index: %s",
- resp.StatusCode, keepServer.String(), resp.Status)
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Received error code %d in response to request "+
+ "for %s index: %s",
+ resp.StatusCode, keepServer.String(), resp.Status))
+ }
+
+ if arvLogger != nil {
+ properties, _ := arvLogger.Edit()
+ keepInfo := properties["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+
+ serverInfo["response_received"] = time.Now()
+
+ arvLogger.Record()
}
response.Address = keepServer
@@ -275,9 +300,11 @@ func ReadServerResponse(arvLogger *logger.Logger,
numLines++
blockInfo, err := parseBlockInfoFromIndexLine(scanner.Text())
if err != nil {
- log.Fatalf("Error parsing BlockInfo from index line received from %s: %v",
- keepServer.String(),
- err)
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Error parsing BlockInfo from index line "+
+ "received from %s: %v",
+ keepServer.String(),
+ err))
}
if storedBlock, ok := response.Contents.BlockDigestToInfo[blockInfo.Digest]; ok {
@@ -286,10 +313,24 @@ func ReadServerResponse(arvLogger *logger.Logger,
if storedBlock.Size != blockInfo.Size {
numSizeDisagreements += 1
// TODO(misha): Consider failing here.
- log.Printf("Saw different sizes for the same block on %s: %v %v",
+ message := fmt.Sprintf("Saw different sizes for the same block "+
+ "on %s: %v %v",
keepServer.String(),
storedBlock,
blockInfo)
+ log.Println(message)
+ if arvLogger != nil {
+ properties, _ := arvLogger.Edit()
+ keepInfo := properties["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+ var error_list []string
+ read_error_list, has_list := serverInfo["error_list"]
+ if has_list {
+ error_list = read_error_list.([]string)
+ } // If we didn't have the list, error_list is already an empty list
+ serverInfo["error_list"] = append(error_list, message)
+ arvLogger.Record()
+ }
}
// Keep the block that is bigger, or the block that's newer in
// the case of a size tie.
@@ -303,9 +344,10 @@ func ReadServerResponse(arvLogger *logger.Logger,
}
}
if err := scanner.Err(); err != nil {
- log.Fatalf("Received error scanning index response from %s: %v",
- keepServer.String(),
- err)
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Received error scanning index response from %s: %v",
+ keepServer.String(),
+ err))
} else {
log.Printf("%s index contained %d lines with %d duplicates with "+
"%d size disagreements",
@@ -313,6 +355,19 @@ func ReadServerResponse(arvLogger *logger.Logger,
numLines,
numDuplicates,
numSizeDisagreements)
+
+ if arvLogger != nil {
+ properties, _ := arvLogger.Edit()
+ keepInfo := properties["keep_info"].(map[string]interface{})
+ serverInfo := keepInfo[keepServer.String()].(map[string]interface{})
+
+ serverInfo["processing_finished"] = time.Now()
+ serverInfo["lines_received"] = numLines
+ serverInfo["dupicates_seen"] = numDuplicates
+ serverInfo["size_disagreements_seen"] = numSizeDisagreements
+
+ arvLogger.Record()
+ }
}
resp.Body.Close()
return
commit 3f74a7584760a83539b6c0ba01ffd5078d8858cf
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 14 00:50:21 2015 +0000
ran gofmt
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 87ec861..6e97f57 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -93,7 +93,7 @@ func init() {
"File with the API token we should use to contact keep servers.")
}
-func (s ServerAddress) String() (string) {
+func (s ServerAddress) String() string {
return fmt.Sprintf("%s:%d", s.Host, s.Port)
}
commit 6221a5005318304a2f05f1fa3c9d897ed71d5676
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 14 00:49:31 2015 +0000
Broke keep.GetServerContents() into smaller functions.
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index de4cbd4..87ec861 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -93,6 +93,10 @@ func init() {
"File with the API token we should use to contact keep servers.")
}
+func (s ServerAddress) String() (string) {
+ return fmt.Sprintf("%s:%d", s.Host, s.Port)
+}
+
func getDataManagerToken(arvLogger *logger.Logger) string {
readDataManagerToken := func() {
if dataManagerTokenFile == "" {
@@ -224,11 +228,21 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
return
}
-// TODO(misha): Break this function apart into smaller, easier to
-// understand functions.
func GetServerContents(arvLogger *logger.Logger,
keepServer ServerAddress,
client http.Client) (response ServerResponse) {
+
+ req := CreateIndexRequest(arvLogger, keepServer)
+ resp, err := client.Do(req)
+ if err != nil {
+ log.Fatalf("Error fetching %s: %v", req.URL.String(), err)
+ }
+
+ return ReadServerResponse(arvLogger, keepServer, resp)
+}
+
+func CreateIndexRequest(arvLogger *logger.Logger,
+ keepServer ServerAddress) (req *http.Request) {
// Create and send request.
url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
log.Println("About to fetch keep server contents from " + url)
@@ -240,16 +254,16 @@ func GetServerContents(arvLogger *logger.Logger,
req.Header.Add("Authorization",
fmt.Sprintf("OAuth2 %s", getDataManagerToken(arvLogger)))
+ return
+}
- resp, err := client.Do(req)
- if err != nil {
- log.Fatalf("Error fetching %s: %v", url, err)
- }
+func ReadServerResponse(arvLogger *logger.Logger,
+ keepServer ServerAddress,
+ resp *http.Response) (response ServerResponse) {
- // Process response.
if resp.StatusCode != 200 {
- log.Fatalf("Received error code %d in response to request for %s: %s",
- resp.StatusCode, url, resp.Status)
+ log.Fatalf("Received error code %d in response to request for %s index: %s",
+ resp.StatusCode, keepServer.String(), resp.Status)
}
response.Address = keepServer
@@ -262,7 +276,7 @@ func GetServerContents(arvLogger *logger.Logger,
blockInfo, err := parseBlockInfoFromIndexLine(scanner.Text())
if err != nil {
log.Fatalf("Error parsing BlockInfo from index line received from %s: %v",
- url,
+ keepServer.String(),
err)
}
@@ -273,7 +287,7 @@ func GetServerContents(arvLogger *logger.Logger,
numSizeDisagreements += 1
// TODO(misha): Consider failing here.
log.Printf("Saw different sizes for the same block on %s: %v %v",
- url,
+ keepServer.String(),
storedBlock,
blockInfo)
}
@@ -289,11 +303,13 @@ func GetServerContents(arvLogger *logger.Logger,
}
}
if err := scanner.Err(); err != nil {
- log.Fatalf("Received error scanning response from %s: %v", url, err)
+ log.Fatalf("Received error scanning index response from %s: %v",
+ keepServer.String(),
+ err)
} else {
- log.Printf("%s contained %d lines with %d duplicates with "+
+ log.Printf("%s index contained %d lines with %d duplicates with "+
"%d size disagreements",
- url,
+ keepServer.String(),
numLines,
numDuplicates,
numSizeDisagreements)
commit 2415e93fcd6a24b3bfbc319c139737f550835e36
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 13 23:56:05 2015 +0000
Removed channel awareness from keep.GetServerContents().
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index b9e6df0..de4cbd4 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -188,7 +188,17 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
// Send off all the index requests concurrently
responseChan := make(chan ServerResponse)
for _, keepServer := range sdkResponse.KeepServers {
- go GetServerContents(params.Logger, keepServer, client, responseChan)
+ // The above keepsServer variable is reused for each iteration, so
+ // it would be shared across all goroutines. This would result in
+ // us querying one server n times instead of n different servers
+ // as we intended. To avoid this we add it as an explicit
+ // parameter which gets copied. This bug and solution is described
+ // in https://golang.org/doc/effective_go.html#channels
+ go func(keepServer ServerAddress) {
+ responseChan <- GetServerContents(params.Logger,
+ keepServer,
+ client)
+ }(keepServer)
}
results.ServerToContents = make(map[ServerAddress]ServerContents)
@@ -218,8 +228,7 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
// understand functions.
func GetServerContents(arvLogger *logger.Logger,
keepServer ServerAddress,
- client http.Client,
- responseChan chan<- ServerResponse) {
+ client http.Client) (response ServerResponse) {
// Create and send request.
url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
log.Println("About to fetch keep server contents from " + url)
@@ -243,7 +252,6 @@ func GetServerContents(arvLogger *logger.Logger,
resp.StatusCode, url, resp.Status)
}
- response := ServerResponse{}
response.Address = keepServer
response.Contents.BlockDigestToInfo =
make(map[blockdigest.BlockDigest]BlockInfo)
@@ -291,7 +299,7 @@ func GetServerContents(arvLogger *logger.Logger,
numSizeDisagreements)
}
resp.Body.Close()
- responseChan <- response
+ return
}
func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err error) {
commit 2d2f3bed79f9504d15503277056feb394c12dd7c
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 13 23:27:05 2015 +0000
gofmt'd all my source code. No other changes.
diff --git a/sdk/go/blockdigest/blockdigest.go b/sdk/go/blockdigest/blockdigest.go
index 5225af6..0742839 100644
--- a/sdk/go/blockdigest/blockdigest.go
+++ b/sdk/go/blockdigest/blockdigest.go
@@ -28,9 +28,13 @@ func FromString(s string) (dig BlockDigest, err error) {
var d BlockDigest
d.h, err = strconv.ParseUint(s[:16], 16, 64)
- if err != nil {return}
+ if err != nil {
+ return
+ }
d.l, err = strconv.ParseUint(s[16:], 16, 64)
- if err != nil {return}
+ if err != nil {
+ return
+ }
dig = d
return
}
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index 294ba92..ff57127 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -32,33 +32,33 @@ import (
)
type LoggerParams struct {
- Client arvadosclient.ArvadosClient // The client we use to write log entries
- EventType string // The event type to assign to the log entry.
- MinimumWriteInterval time.Duration // Wait at least this long between log writes
+ Client arvadosclient.ArvadosClient // The client we use to write log entries
+ EventType string // The event type to assign to the log entry.
+ MinimumWriteInterval time.Duration // Wait at least this long between log writes
}
// A Logger is used to build up a log entry over time and write every
// version of it.
type Logger struct {
// The Data we write
- data map[string]interface{} // The entire map that we give to the api
- entry map[string]interface{} // Convenience shortcut into data
- properties map[string]interface{} // Convenience shortcut into data
+ data map[string]interface{} // The entire map that we give to the api
+ entry map[string]interface{} // Convenience shortcut into data
+ properties map[string]interface{} // Convenience shortcut into data
- lock sync.Locker // Synchronizes editing and writing
- params LoggerParams // Parameters we were given
+ lock sync.Locker // Synchronizes editing and writing
+ params LoggerParams // Parameters we were given
- lastWrite time.Time // The last time we wrote a log entry
- modified bool // Has this data been modified since the last write
+ lastWrite time.Time // The last time we wrote a log entry
+ modified bool // Has this data been modified since the last write
- writeHooks []func(map[string]interface{},map[string]interface{})
+ writeHooks []func(map[string]interface{}, map[string]interface{})
}
// Create a new logger based on the specified parameters.
func NewLogger(params LoggerParams) *Logger {
// TODO(misha): Add some params checking here.
l := &Logger{data: make(map[string]interface{}),
- lock: &sync.Mutex{},
+ lock: &sync.Mutex{},
params: params}
l.entry = make(map[string]interface{})
l.data["log"] = l.entry
@@ -70,13 +70,13 @@ func NewLogger(params LoggerParams) *Logger {
// Get access to the maps you can edit. This will hold a lock until
// you call Record. Do not edit the maps in any other goroutines or
// after calling Record.
-// You don't need to edit both maps,
+// You don't need to edit both maps,
// properties can take any values you want to give it,
// entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
// properties is a shortcut for entry["properties"].(map[string]interface{})
func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]interface{}) {
l.lock.Lock()
- l.modified = true // We don't actually know the caller will modifiy the data, but we assume they will.
+ l.modified = true // We don't actually know the caller will modifiy the data, but we assume they will.
return l.properties, l.entry
}
@@ -120,7 +120,6 @@ func (l *Logger) writeAllowedNow() bool {
return l.lastWrite.Add(l.params.MinimumWriteInterval).Before(time.Now())
}
-
// Actually writes the log entry. This method assumes we're holding the lock.
func (l *Logger) write() {
@@ -144,7 +143,6 @@ func (l *Logger) write() {
l.modified = false
}
-
func (l *Logger) acquireLockConsiderWriting() {
l.lock.Lock()
if l.modified && l.writeAllowedNow() {
diff --git a/sdk/go/manifest/manifest.go b/sdk/go/manifest/manifest.go
index 1227f49..c9f9018 100644
--- a/sdk/go/manifest/manifest.go
+++ b/sdk/go/manifest/manifest.go
@@ -21,20 +21,20 @@ type Manifest struct {
}
type BlockLocator struct {
- Digest blockdigest.BlockDigest
- Size int
- Hints []string
+ Digest blockdigest.BlockDigest
+ Size int
+ Hints []string
}
type ManifestLine struct {
- StreamName string
- Blocks []string
- Files []string
+ StreamName string
+ Blocks []string
+ Files []string
}
func ParseBlockLocator(s string) (b BlockLocator, err error) {
if !LocatorPattern.MatchString(s) {
- err = fmt.Errorf("String \"%s\" does not match BlockLocator pattern " +
+ err = fmt.Errorf("String \"%s\" does not match BlockLocator pattern "+
"\"%s\".",
s,
LocatorPattern.String())
@@ -45,9 +45,13 @@ func ParseBlockLocator(s string) (b BlockLocator, err error) {
// We expect both of the following to succeed since LocatorPattern
// restricts the strings appropriately.
blockDigest, err = blockdigest.FromString(tokens[0])
- if err != nil {return}
+ if err != nil {
+ return
+ }
blockSize, err = strconv.ParseInt(tokens[1], 10, 0)
- if err != nil {return}
+ if err != nil {
+ return
+ }
b.Digest = blockDigest
b.Size = int(blockSize)
b.Hints = tokens[2:]
@@ -92,7 +96,6 @@ func (m *Manifest) LineIter() <-chan ManifestLine {
return ch
}
-
// Blocks may appear mulitple times within the same manifest if they
// are used by multiple files. In that case this Iterator will output
// the same block multiple times.
diff --git a/sdk/go/util/util.go b/sdk/go/util/util.go
index 9b0fe21..4505db6 100644
--- a/sdk/go/util/util.go
+++ b/sdk/go/util/util.go
@@ -56,7 +56,7 @@ func ContainsAllAvailableItems(response SdkListResponse) (containsAll bool, numC
}
numAvailable, err = response.NumItemsAvailable()
if err != nil {
- log.Fatalf("Error retrieving number of items available from " +
+ log.Fatalf("Error retrieving number of items available from "+
"SDK response: %v",
err)
}
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index fbdec15..73115f5 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -21,44 +21,44 @@ var (
heap_profile_filename string
// globals for debugging
totalManifestSize uint64
- maxManifestSize uint64
+ maxManifestSize uint64
)
type Collection struct {
- Uuid string
- OwnerUuid string
- ReplicationLevel int
+ Uuid string
+ OwnerUuid string
+ ReplicationLevel int
BlockDigestToSize map[blockdigest.BlockDigest]int
- TotalSize int
+ TotalSize int
}
type ReadCollections struct {
- ReadAllCollections bool
- UuidToCollection map[string]Collection
+ ReadAllCollections bool
+ UuidToCollection map[string]Collection
OwnerToCollectionSize map[string]int
}
type GetCollectionsParams struct {
- Client arvadosclient.ArvadosClient
- Logger *logger.Logger
+ Client arvadosclient.ArvadosClient
+ Logger *logger.Logger
BatchSize int
}
type SdkCollectionInfo struct {
- Uuid string `json:"uuid"`
- OwnerUuid string `json:"owner_uuid"`
- Redundancy int `json:"redundancy"`
- ModifiedAt time.Time `json:"modified_at"`
- ManifestText string `json:"manifest_text"`
+ Uuid string `json:"uuid"`
+ OwnerUuid string `json:"owner_uuid"`
+ Redundancy int `json:"redundancy"`
+ ModifiedAt time.Time `json:"modified_at"`
+ ManifestText string `json:"manifest_text"`
}
type SdkCollectionList struct {
- ItemsAvailable int `json:"items_available"`
- Items []SdkCollectionInfo `json:"items"`
+ ItemsAvailable int `json:"items_available"`
+ Items []SdkCollectionInfo `json:"items"`
}
func init() {
- flag.StringVar(&heap_profile_filename,
+ flag.StringVar(&heap_profile_filename,
"heap-profile",
"",
"File to write the heap profiles to. Leave blank to skip profiling.")
@@ -96,13 +96,12 @@ func WriteHeapProfile() {
}
}
-
func GetCollectionsAndSummarize(params GetCollectionsParams) (results ReadCollections) {
results = GetCollections(params)
ComputeSizeOfOwnedCollections(&results)
if params.Logger != nil {
- properties,_ := params.Logger.Edit()
+ properties, _ := params.Logger.Edit()
collectionInfo := properties["collection_info"].(map[string]interface{})
collectionInfo["owner_to_collection_size"] = results.OwnerToCollectionSize
params.Logger.Record()
@@ -136,8 +135,8 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
"modified_at"}
sdkParams := arvadosclient.Dict{
- "select": fieldsWanted,
- "order": []string{"modified_at ASC"},
+ "select": fieldsWanted,
+ "order": []string{"modified_at ASC"},
"filters": [][]string{[]string{"modified_at", ">=", "1900-01-01T00:00:00Z"}}}
if params.BatchSize > 0 {
@@ -152,7 +151,7 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
results.UuidToCollection = make(map[string]Collection, maxExpectedCollections)
if params.Logger != nil {
- properties,_ := params.Logger.Edit()
+ properties, _ := params.Logger.Edit()
collectionInfo := make(map[string]interface{})
collectionInfo["num_collections_at_start"] = initialNumberOfCollectionsAvailable
collectionInfo["batch_size"] = params.BatchSize
@@ -181,23 +180,23 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
// Process collection and update our date filter.
sdkParams["filters"].([][]string)[0][2] =
ProcessCollections(params.Logger,
- collections.Items,
- results.UuidToCollection).Format(time.RFC3339)
+ collections.Items,
+ results.UuidToCollection).Format(time.RFC3339)
// update counts
previousTotalCollections = totalCollections
totalCollections = len(results.UuidToCollection)
- log.Printf("%d collections read, %d new in last batch, " +
+ log.Printf("%d collections read, %d new in last batch, "+
"%s latest modified date, %.0f %d %d avg,max,total manifest size",
totalCollections,
- totalCollections - previousTotalCollections,
+ totalCollections-previousTotalCollections,
sdkParams["filters"].([][]string)[0][2],
float32(totalManifestSize)/float32(totalCollections),
maxManifestSize, totalManifestSize)
if params.Logger != nil {
- properties,_ := params.Logger.Edit()
+ properties, _ := params.Logger.Edit()
collectionInfo := properties["collection_info"].(map[string]interface{})
collectionInfo["collections_read"] = totalCollections
collectionInfo["latest_modified_date_seen"] = sdkParams["filters"].([][]string)[0][2]
@@ -216,7 +215,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
return
}
-
// StrCopy returns a newly allocated string.
// It is useful to copy slices so that the garbage collector can reuse
// the memory of the longer strings they came from.
@@ -224,22 +222,21 @@ func StrCopy(s string) string {
return string([]byte(s))
}
-
func ProcessCollections(arvLogger *logger.Logger,
receivedCollections []SdkCollectionInfo,
uuidToCollection map[string]Collection) (latestModificationDate time.Time) {
for _, sdkCollection := range receivedCollections {
collection := Collection{Uuid: StrCopy(sdkCollection.Uuid),
- OwnerUuid: StrCopy(sdkCollection.OwnerUuid),
- ReplicationLevel: sdkCollection.Redundancy,
+ OwnerUuid: StrCopy(sdkCollection.OwnerUuid),
+ ReplicationLevel: sdkCollection.Redundancy,
BlockDigestToSize: make(map[blockdigest.BlockDigest]int)}
if sdkCollection.ModifiedAt.IsZero() {
loggerutil.FatalWithMessage(arvLogger,
fmt.Sprintf(
- "Arvados SDK collection returned with unexpected zero " +
- "modifcation date. This probably means that either we failed to " +
- "parse the modification date or the API server has changed how " +
+ "Arvados SDK collection returned with unexpected zero "+
+ "modifcation date. This probably means that either we failed to "+
+ "parse the modification date or the API server has changed how "+
"it returns modification dates: %v",
collection))
}
@@ -256,11 +253,10 @@ func ProcessCollections(arvLogger *logger.Logger,
if manifestSize > maxManifestSize {
maxManifestSize = manifestSize
}
-
+
blockChannel := manifest.BlockIterWithDuplicates()
for block := range blockChannel {
- if stored_size, stored := collection.BlockDigestToSize[block.Digest];
- stored && stored_size != block.Size {
+ if stored_size, stored := collection.BlockDigestToSize[block.Digest]; stored && stored_size != block.Size {
message := fmt.Sprintf(
"Collection %s contains multiple sizes (%d and %d) for block %s",
collection.Uuid,
@@ -286,8 +282,7 @@ func ProcessCollections(arvLogger *logger.Logger,
return
}
-
-func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) (int) {
+func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) int {
var collections SdkCollectionList
sdkParams := arvadosclient.Dict{"limit": 0}
err := client.List("collections", sdkParams, &collections)
@@ -298,7 +293,6 @@ func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) (int) {
return collections.ItemsAvailable
}
-
func ComputeSizeOfOwnedCollections(readCollections *ReadCollections) {
readCollections.OwnerToCollectionSize = make(map[string]int)
for _, coll := range readCollections.UuidToCollection {
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index d7d926e..e73bdb9 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -16,16 +16,16 @@ import (
)
var (
- logEventType string
+ logEventType string
logFrequencySeconds int
)
func init() {
- flag.StringVar(&logEventType,
+ flag.StringVar(&logEventType,
"log-event-type",
"experimental-data-manager-report",
"event_type to use in our arvados log entries. Set to empty to turn off logging")
- flag.IntVar(&logFrequencySeconds,
+ flag.IntVar(&logFrequencySeconds,
"log-frequency-seconds",
20,
"How frequently we'll write log entries in seconds.")
@@ -48,7 +48,7 @@ func main() {
var arvLogger *logger.Logger
if logEventType != "" {
arvLogger = logger.NewLogger(logger.LoggerParams{Client: arv,
- EventType: logEventType,
+ EventType: logEventType,
MinimumWriteInterval: time.Second * time.Duration(logFrequencySeconds)})
}
@@ -73,22 +73,24 @@ func main() {
collectionChannel := make(chan collection.ReadCollections)
- go func() { collectionChannel <- collection.GetCollectionsAndSummarize(
- collection.GetCollectionsParams{
- Client: arv, Logger: arvLogger, BatchSize: 50}) }()
+ go func() {
+ collectionChannel <- collection.GetCollectionsAndSummarize(
+ collection.GetCollectionsParams{
+ Client: arv, Logger: arvLogger, BatchSize: 50})
+ }()
keepServerInfo := keep.GetKeepServersAndSummarize(
keep.GetKeepServersParams{Client: arv, Logger: arvLogger, Limit: 1000})
readCollections := <-collectionChannel
- // Make compiler happy.
+ // Make compiler happy.
_ = readCollections
_ = keepServerInfo
// Log that we're finished
if arvLogger != nil {
- properties,_ := arvLogger.Edit()
+ properties, _ := arvLogger.Edit()
properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
// Force the recording, since go will not wait for the timer before exiting.
arvLogger.ForceRecord()
@@ -96,7 +98,7 @@ func main() {
}
func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
- _ = entry // keep the compiler from complaining
+ _ = entry // keep the compiler from complaining
runInfo := properties["run_info"].(map[string]interface{})
var memStats runtime.MemStats
runtime.ReadMemStats(&memStats)
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 8b46066..b9e6df0 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -13,8 +13,8 @@ import (
"git.curoverse.com/arvados.git/sdk/go/manifest"
"git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/loggerutil"
- "log"
"io/ioutil"
+ "log"
"net/http"
"strconv"
"strings"
@@ -23,21 +23,21 @@ import (
type ServerAddress struct {
Host string `json:"service_host"`
- Port int `json:"service_port"`
+ Port int `json:"service_port"`
}
// Info about a particular block returned by the server
type BlockInfo struct {
- Digest blockdigest.BlockDigest
- Size int
- Mtime int // TODO(misha): Replace this with a timestamp.
+ Digest blockdigest.BlockDigest
+ Size int
+ Mtime int // TODO(misha): Replace this with a timestamp.
}
// Info about a specified block given by a server
type BlockServerInfo struct {
ServerIndex int
Size int
- Mtime int // TODO(misha): Replace this with a timestamp.
+ Mtime int // TODO(misha): Replace this with a timestamp.
}
type ServerContents struct {
@@ -45,28 +45,28 @@ type ServerContents struct {
}
type ServerResponse struct {
- Address ServerAddress
+ Address ServerAddress
Contents ServerContents
}
type ReadServers struct {
- ReadAllServers bool
- KeepServerIndexToAddress []ServerAddress
- KeepServerAddressToIndex map[ServerAddress]int
- ServerToContents map[ServerAddress]ServerContents
- BlockToServers map[blockdigest.BlockDigest][]BlockServerInfo
- BlockReplicationCounts map[int]int
+ ReadAllServers bool
+ KeepServerIndexToAddress []ServerAddress
+ KeepServerAddressToIndex map[ServerAddress]int
+ ServerToContents map[ServerAddress]ServerContents
+ BlockToServers map[blockdigest.BlockDigest][]BlockServerInfo
+ BlockReplicationCounts map[int]int
}
type GetKeepServersParams struct {
Client arvadosclient.ArvadosClient
Logger *logger.Logger
- Limit int
+ Limit int
}
type KeepServiceList struct {
- ItemsAvailable int `json:"items_available"`
- KeepServers []ServerAddress `json:"items"`
+ ItemsAvailable int `json:"items_available"`
+ KeepServers []ServerAddress `json:"items"`
}
// Methods to implement util.SdkListResponse Interface
@@ -81,20 +81,20 @@ func (k KeepServiceList) NumItemsContained() (numContained int, err error) {
var (
// Don't access the token directly, use getDataManagerToken() to
// make sure it's been read.
- dataManagerToken string
- dataManagerTokenFile string
- dataManagerTokenFileReadOnce sync.Once
+ dataManagerToken string
+ dataManagerTokenFile string
+ dataManagerTokenFileReadOnce sync.Once
)
func init() {
- flag.StringVar(&dataManagerTokenFile,
+ flag.StringVar(&dataManagerTokenFile,
"data-manager-token-file",
"",
"File with the API token we should use to contact keep servers.")
}
-func getDataManagerToken(arvLogger *logger.Logger) (string) {
- readDataManagerToken := func () {
+func getDataManagerToken(arvLogger *logger.Logger) string {
+ readDataManagerToken := func() {
if dataManagerTokenFile == "" {
flag.Usage()
loggerutil.FatalWithMessage(arvLogger,
@@ -151,7 +151,7 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
results.ReadAllServers, numReceived, numAvailable =
util.ContainsAllAvailableItems(sdkResponse)
- if (!results.ReadAllServers) {
+ if !results.ReadAllServers {
log.Printf("ERROR: Did not receive all keep server addresses.")
}
log.Printf("Received %d of %d available keep server addresses.",
@@ -160,7 +160,7 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
}
if params.Logger != nil {
- properties,_ := params.Logger.Edit()
+ properties, _ := params.Logger.Edit()
keepInfo := make(map[string]interface{})
keepInfo["num_keep_servers_available"] = sdkResponse.ItemsAvailable
@@ -196,8 +196,8 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
// Read all the responses
for i := range sdkResponse.KeepServers {
- _ = i // Here to prevent go from complaining.
- response := <- responseChan
+ _ = i // Here to prevent go from complaining.
+ response := <-responseChan
log.Printf("Received channel response from %v containing %d files",
response.Address,
len(response.Contents.BlockDigestToInfo))
@@ -207,7 +207,7 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
results.BlockToServers[blockInfo.Digest] = append(
results.BlockToServers[blockInfo.Digest],
BlockServerInfo{ServerIndex: serverIndex,
- Size: blockInfo.Size,
+ Size: blockInfo.Size,
Mtime: blockInfo.Mtime})
}
}
@@ -219,7 +219,7 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
func GetServerContents(arvLogger *logger.Logger,
keepServer ServerAddress,
client http.Client,
- responseChan chan<- ServerResponse) () {
+ responseChan chan<- ServerResponse) {
// Create and send request.
url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
log.Println("About to fetch keep server contents from " + url)
@@ -273,7 +273,7 @@ func GetServerContents(arvLogger *logger.Logger,
// the case of a size tie.
if storedBlock.Size < blockInfo.Size ||
(storedBlock.Size == blockInfo.Size &&
- storedBlock.Mtime < blockInfo.Mtime) {
+ storedBlock.Mtime < blockInfo.Mtime) {
response.Contents.BlockDigestToInfo[blockInfo.Digest] = blockInfo
}
} else {
@@ -283,7 +283,7 @@ func GetServerContents(arvLogger *logger.Logger,
if err := scanner.Err(); err != nil {
log.Fatalf("Received error scanning response from %s: %v", url, err)
} else {
- log.Printf("%s contained %d lines with %d duplicates with " +
+ log.Printf("%s contained %d lines with %d duplicates with "+
"%d size disagreements",
url,
numLines,
@@ -297,7 +297,7 @@ func GetServerContents(arvLogger *logger.Logger,
func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err error) {
tokens := strings.Fields(indexLine)
if len(tokens) != 2 {
- err = fmt.Errorf("Expected 2 tokens per line but received a " +
+ err = fmt.Errorf("Expected 2 tokens per line but received a "+
"line containing %v instead.",
tokens)
}
@@ -307,7 +307,7 @@ func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err err
return
}
if len(locator.Hints) > 0 {
- err = fmt.Errorf("Block locator in index line should not contain hints " +
+ err = fmt.Errorf("Block locator in index line should not contain hints "+
"but it does: %v",
locator)
return
diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
index e4a53c2..f97f7c1 100644
--- a/services/datamanager/loggerutil/loggerutil.go
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -13,7 +13,7 @@ import (
// for the lock you're already holding.
func FatalWithMessage(arvLogger *logger.Logger, message string) {
if arvLogger != nil {
- properties,_ := arvLogger.Edit()
+ properties, _ := arvLogger.Edit()
properties["FATAL"] = message
properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
arvLogger.ForceRecord()
@@ -21,4 +21,3 @@ func FatalWithMessage(arvLogger *logger.Logger, message string) {
log.Fatalf(message)
}
-
commit 144e23888d46d68c5e32fea9f66a8903e05a3526
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 13 01:15:34 2015 +0000
Started logging in keep.go. More work to be done.
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 9b1f6d6..d7d926e 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -78,7 +78,7 @@ func main() {
Client: arv, Logger: arvLogger, BatchSize: 50}) }()
keepServerInfo := keep.GetKeepServersAndSummarize(
- keep.GetKeepServersParams{Client: arv, Limit: 1000})
+ keep.GetKeepServersParams{Client: arv, Logger: arvLogger, Limit: 1000})
readCollections := <-collectionChannel
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 413e1be..8b46066 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -9,8 +9,10 @@ import (
//"git.curoverse.com/arvados.git/sdk/go/keepclient"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/blockdigest"
+ "git.curoverse.com/arvados.git/sdk/go/logger"
"git.curoverse.com/arvados.git/sdk/go/manifest"
"git.curoverse.com/arvados.git/sdk/go/util"
+ "git.curoverse.com/arvados.git/services/datamanager/loggerutil"
"log"
"io/ioutil"
"net/http"
@@ -58,6 +60,7 @@ type ReadServers struct {
type GetKeepServersParams struct {
Client arvadosclient.ArvadosClient
+ Logger *logger.Logger
Limit int
}
@@ -90,17 +93,19 @@ func init() {
"File with the API token we should use to contact keep servers.")
}
-func getDataManagerToken() (string) {
+func getDataManagerToken(arvLogger *logger.Logger) (string) {
readDataManagerToken := func () {
if dataManagerTokenFile == "" {
flag.Usage()
- log.Fatalf("Data Manager Token needed, but data manager token file not specified.")
+ loggerutil.FatalWithMessage(arvLogger,
+ "Data Manager Token needed, but data manager token file not specified.")
} else {
rawRead, err := ioutil.ReadFile(dataManagerTokenFile)
if err != nil {
- log.Fatalf("Unexpected error reading token file %s: %v",
- dataManagerTokenFile,
- err)
+ loggerutil.FatalWithMessage(arvLogger,
+ fmt.Sprintf("Unexpected error reading token file %s: %v",
+ dataManagerTokenFile,
+ err))
}
dataManagerToken = strings.TrimSpace(string(rawRead))
}
@@ -136,11 +141,11 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
err := params.Client.Call("GET", "keep_services", "", "accessible", sdkParams, &sdkResponse)
if err != nil {
- log.Fatalf("Error requesting keep disks from API server: %v", err)
+ loggerutil.FatalWithMessage(params.Logger,
+ fmt.Sprintf("Error requesting keep disks from API server: %v", err))
}
- log.Printf("Received keep services list: %v", sdkResponse)
-
+ // TODO(misha): Rewrite this block, stop using ContainsAllAvailableItems()
{
var numReceived, numAvailable int
results.ReadAllServers, numReceived, numAvailable =
@@ -154,6 +159,21 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
numAvailable)
}
+ if params.Logger != nil {
+ properties,_ := params.Logger.Edit()
+ keepInfo := make(map[string]interface{})
+
+ keepInfo["num_keep_servers_available"] = sdkResponse.ItemsAvailable
+ keepInfo["num_keep_servers_received"] = len(sdkResponse.KeepServers)
+ keepInfo["keep_servers"] = sdkResponse.KeepServers
+
+ properties["keep_info"] = keepInfo
+
+ params.Logger.Record()
+ }
+
+ log.Printf("Received keep services list: %v", sdkResponse)
+
results.KeepServerIndexToAddress = sdkResponse.KeepServers
results.KeepServerAddressToIndex = make(map[ServerAddress]int)
for i, address := range results.KeepServerIndexToAddress {
@@ -168,7 +188,7 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
// Send off all the index requests concurrently
responseChan := make(chan ServerResponse)
for _, keepServer := range sdkResponse.KeepServers {
- go GetServerContents(keepServer, client, responseChan)
+ go GetServerContents(params.Logger, keepServer, client, responseChan)
}
results.ServerToContents = make(map[ServerAddress]ServerContents)
@@ -196,7 +216,8 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
// TODO(misha): Break this function apart into smaller, easier to
// understand functions.
-func GetServerContents(keepServer ServerAddress,
+func GetServerContents(arvLogger *logger.Logger,
+ keepServer ServerAddress,
client http.Client,
responseChan chan<- ServerResponse) () {
// Create and send request.
@@ -209,7 +230,7 @@ func GetServerContents(keepServer ServerAddress,
}
req.Header.Add("Authorization",
- fmt.Sprintf("OAuth2 %s", getDataManagerToken()))
+ fmt.Sprintf("OAuth2 %s", getDataManagerToken(arvLogger)))
resp, err := client.Do(req)
if err != nil {
commit e0889a8f6997327fd9b4d826237c8166cf909741
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 13 00:49:53 2015 +0000
Created loggerutil to hold common datamanager logger code. Moved FatalWithMessage to it.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index f9e2a3d..fbdec15 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -9,6 +9,7 @@ import (
"git.curoverse.com/arvados.git/sdk/go/blockdigest"
"git.curoverse.com/arvados.git/sdk/go/logger"
"git.curoverse.com/arvados.git/sdk/go/manifest"
+ "git.curoverse.com/arvados.git/services/datamanager/loggerutil"
"log"
"os"
"runtime"
@@ -173,7 +174,7 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
var collections SdkCollectionList
err := params.Client.List("collections", sdkParams, &collections)
if err != nil {
- fatalWithMessage(params.Logger,
+ loggerutil.FatalWithMessage(params.Logger,
fmt.Sprintf("Error querying collections: %v", err))
}
@@ -234,7 +235,7 @@ func ProcessCollections(arvLogger *logger.Logger,
BlockDigestToSize: make(map[blockdigest.BlockDigest]int)}
if sdkCollection.ModifiedAt.IsZero() {
- fatalWithMessage(arvLogger,
+ loggerutil.FatalWithMessage(arvLogger,
fmt.Sprintf(
"Arvados SDK collection returned with unexpected zero " +
"modifcation date. This probably means that either we failed to " +
@@ -266,7 +267,7 @@ func ProcessCollections(arvLogger *logger.Logger,
stored_size,
block.Size,
block.Digest)
- fatalWithMessage(arvLogger, message)
+ loggerutil.FatalWithMessage(arvLogger, message)
}
collection.BlockDigestToSize[block.Digest] = block.Size
}
@@ -307,18 +308,3 @@ func ComputeSizeOfOwnedCollections(readCollections *ReadCollections) {
return
}
-
-
-// Assumes you haven't already called arvLogger.Edit()!
-// If you have called arvLogger.Edit() this method will hang waiting
-// for the lock you're already holding.
-func fatalWithMessage(arvLogger *logger.Logger, message string) {
- if arvLogger != nil {
- properties,_ := arvLogger.Edit()
- properties["FATAL"] = message
- properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
- arvLogger.ForceRecord()
- }
-
- log.Fatalf(message)
-}
diff --git a/services/datamanager/loggerutil/loggerutil.go b/services/datamanager/loggerutil/loggerutil.go
new file mode 100644
index 0000000..e4a53c2
--- /dev/null
+++ b/services/datamanager/loggerutil/loggerutil.go
@@ -0,0 +1,24 @@
+/* Datamanager-specific logging methods. */
+
+package loggerutil
+
+import (
+ "git.curoverse.com/arvados.git/sdk/go/logger"
+ "log"
+ "time"
+)
+
+// Assumes you haven't already called arvLogger.Edit()!
+// If you have called arvLogger.Edit() this method will hang waiting
+// for the lock you're already holding.
+func FatalWithMessage(arvLogger *logger.Logger, message string) {
+ if arvLogger != nil {
+ properties,_ := arvLogger.Edit()
+ properties["FATAL"] = message
+ properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ arvLogger.ForceRecord()
+ }
+
+ log.Fatalf(message)
+}
+
commit 2ee024868c8152903a43a8c6f5dce601305e99e2
Author: mishaz <misha at curoverse.com>
Date: Tue Jan 13 00:23:17 2015 +0000
Moved some logic from datamanager.go to keep.go.
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 6bd9ee8..9b1f6d6 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -77,10 +77,14 @@ func main() {
collection.GetCollectionsParams{
Client: arv, Logger: arvLogger, BatchSize: 50}) }()
- RunKeep(keep.GetKeepServersParams{Client: arv, Limit: 1000})
+ keepServerInfo := keep.GetKeepServersAndSummarize(
+ keep.GetKeepServersParams{Client: arv, Limit: 1000})
readCollections := <-collectionChannel
- _ = readCollections // Make compiler happy.
+
+ // Make compiler happy.
+ _ = readCollections
+ _ = keepServerInfo
// Log that we're finished
if arvLogger != nil {
@@ -91,20 +95,6 @@ func main() {
}
}
-func RunKeep(params keep.GetKeepServersParams) {
- readServers := keep.GetKeepServers(params)
-
- log.Printf("Returned %d keep disks", len(readServers.ServerToContents))
-
- blockReplicationCounts := make(map[int]int)
- for _, infos := range readServers.BlockToServers {
- replication := len(infos)
- blockReplicationCounts[replication] += 1
- }
-
- log.Printf("Replication level distribution: %v", blockReplicationCounts)
-}
-
func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
_ = entry // keep the compiler from complaining
runInfo := properties["run_info"].(map[string]interface{})
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 91af201..413e1be 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -48,11 +48,12 @@ type ServerResponse struct {
}
type ReadServers struct {
- ReadAllServers bool
- KeepServerIndexToAddress []ServerAddress
- KeepServerAddressToIndex map[ServerAddress]int
- ServerToContents map[ServerAddress]ServerContents
- BlockToServers map[blockdigest.BlockDigest][]BlockServerInfo
+ ReadAllServers bool
+ KeepServerIndexToAddress []ServerAddress
+ KeepServerAddressToIndex map[ServerAddress]int
+ ServerToContents map[ServerAddress]ServerContents
+ BlockToServers map[blockdigest.BlockDigest][]BlockServerInfo
+ BlockReplicationCounts map[int]int
}
type GetKeepServersParams struct {
@@ -109,6 +110,17 @@ func getDataManagerToken() (string) {
return dataManagerToken
}
+func GetKeepServersAndSummarize(params GetKeepServersParams) (results ReadServers) {
+ results = GetKeepServers(params)
+ log.Printf("Returned %d keep disks", len(results.ServerToContents))
+
+ ComputeBlockReplicationCounts(&results)
+ log.Printf("Replication level distribution: %v",
+ results.BlockReplicationCounts)
+
+ return
+}
+
func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
if ¶ms.Client == nil {
log.Fatalf("params.Client passed to GetKeepServers() should " +
@@ -288,3 +300,11 @@ func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err err
blockInfo.Size = locator.Size
return
}
+
+func ComputeBlockReplicationCounts(readServers *ReadServers) {
+ readServers.BlockReplicationCounts = make(map[int]int)
+ for _, infos := range readServers.BlockToServers {
+ replication := len(infos)
+ readServers.BlockReplicationCounts[replication] += 1
+ }
+}
commit 4879e0e2f75fd387720b4f4b58ca6ae48a798c98
Author: mishaz <misha at curoverse.com>
Date: Mon Jan 12 23:20:50 2015 +0000
Started reading collections and keep data in parallel. Moved some logic from datamanager.go to collections.go. Added logging to end of run.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index d8352db..f9e2a3d 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -34,6 +34,7 @@ type Collection struct {
type ReadCollections struct {
ReadAllCollections bool
UuidToCollection map[string]Collection
+ OwnerToCollectionSize map[string]int
}
type GetCollectionsParams struct {
@@ -95,6 +96,31 @@ func WriteHeapProfile() {
}
+func GetCollectionsAndSummarize(params GetCollectionsParams) (results ReadCollections) {
+ results = GetCollections(params)
+ ComputeSizeOfOwnedCollections(&results)
+
+ if params.Logger != nil {
+ properties,_ := params.Logger.Edit()
+ collectionInfo := properties["collection_info"].(map[string]interface{})
+ collectionInfo["owner_to_collection_size"] = results.OwnerToCollectionSize
+ params.Logger.Record()
+ }
+
+ log.Printf("Uuid to Size used: %v", results.OwnerToCollectionSize)
+ log.Printf("Read and processed %d collections",
+ len(results.UuidToCollection))
+
+ // TODO(misha): Add a "readonly" flag. If we're in readonly mode,
+ // lots of behaviors can become warnings (and obviously we can't
+ // write anything).
+ // if !readCollections.ReadAllCollections {
+ // log.Fatalf("Did not read all collections")
+ // }
+
+ return
+}
+
func GetCollections(params GetCollectionsParams) (results ReadCollections) {
if ¶ms.Client == nil {
log.Fatalf("params.Client passed to GetCollections() should " +
@@ -272,6 +298,17 @@ func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) (int) {
}
+func ComputeSizeOfOwnedCollections(readCollections *ReadCollections) {
+ readCollections.OwnerToCollectionSize = make(map[string]int)
+ for _, coll := range readCollections.UuidToCollection {
+ readCollections.OwnerToCollectionSize[coll.OwnerUuid] =
+ readCollections.OwnerToCollectionSize[coll.OwnerUuid] + coll.TotalSize
+ }
+
+ return
+}
+
+
// Assumes you haven't already called arvLogger.Edit()!
// If you have called arvLogger.Edit() this method will hang waiting
// for the lock you're already holding.
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 87a71a9..6bd9ee8 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -71,30 +71,24 @@ func main() {
arvLogger.Record()
}
- // TODO(misha): Read Collections and Keep Contents concurrently as goroutines.
- // This requires waiting on them to finish before you let main() exit.
+ collectionChannel := make(chan collection.ReadCollections)
- RunCollections(collection.GetCollectionsParams{
- Client: arv, Logger: arvLogger, BatchSize: 50})
+ go func() { collectionChannel <- collection.GetCollectionsAndSummarize(
+ collection.GetCollectionsParams{
+ Client: arv, Logger: arvLogger, BatchSize: 50}) }()
RunKeep(keep.GetKeepServersParams{Client: arv, Limit: 1000})
-}
-
-func RunCollections(params collection.GetCollectionsParams) {
- readCollections := collection.GetCollections(params)
- UserUsage := ComputeSizeOfOwnedCollections(readCollections)
- log.Printf("Uuid to Size used: %v", UserUsage)
+ readCollections := <-collectionChannel
+ _ = readCollections // Make compiler happy.
- // TODO(misha): Add a "readonly" flag. If we're in readonly mode,
- // lots of behaviors can become warnings (and obviously we can't
- // write anything).
- // if !readCollections.ReadAllCollections {
- // log.Fatalf("Did not read all collections")
- // }
-
- log.Printf("Read and processed %d collections",
- len(readCollections.UuidToCollection))
+ // Log that we're finished
+ if arvLogger != nil {
+ properties,_ := arvLogger.Edit()
+ properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ // Force the recording, since go will not wait for the timer before exiting.
+ arvLogger.ForceRecord()
+ }
}
func RunKeep(params keep.GetKeepServersParams) {
@@ -111,15 +105,6 @@ func RunKeep(params keep.GetKeepServersParams) {
log.Printf("Replication level distribution: %v", blockReplicationCounts)
}
-func ComputeSizeOfOwnedCollections(readCollections collection.ReadCollections) (
- results map[string]int) {
- results = make(map[string]int)
- for _, coll := range readCollections.UuidToCollection {
- results[coll.OwnerUuid] = results[coll.OwnerUuid] + coll.TotalSize
- }
- return
-}
-
func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
_ = entry // keep the compiler from complaining
runInfo := properties["run_info"].(map[string]interface{})
commit 5bcba288077488791daa43a15d5fd5fb0c6e653c
Merge: 95cbdf5 61fdce2
Author: mishaz <misha at curoverse.com>
Date: Sun Jan 11 18:29:13 2015 +0000
Merge branch 'master' of git.curoverse.com:arvados into 3408-production-datamanager
Conflicts resolved:
services/api/Gemfile
services/api/Gemfile.lock
commit 95cbdf59eb5326c393ae91f243f596984cba7fa7
Author: mishaz <misha at curoverse.com>
Date: Fri Jan 9 04:53:42 2015 +0000
Added recording of fatal errors to logger.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index dd37377..d8352db 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -4,6 +4,7 @@ package collection
import (
"flag"
+ "fmt"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/blockdigest"
"git.curoverse.com/arvados.git/sdk/go/logger"
@@ -146,17 +147,15 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
var collections SdkCollectionList
err := params.Client.List("collections", sdkParams, &collections)
if err != nil {
- if params.Logger != nil {
- properties,_ := params.Logger.Edit()
- properties["FATAL"] = err.Error()
- params.Logger.Record()
- }
- log.Fatalf("error querying collections: %+v", err)
+ fatalWithMessage(params.Logger,
+ fmt.Sprintf("Error querying collections: %v", err))
}
// Process collection and update our date filter.
sdkParams["filters"].([][]string)[0][2] =
- ProcessCollections(collections.Items, results.UuidToCollection).Format(time.RFC3339)
+ ProcessCollections(params.Logger,
+ collections.Items,
+ results.UuidToCollection).Format(time.RFC3339)
// update counts
previousTotalCollections = totalCollections
@@ -199,7 +198,8 @@ func StrCopy(s string) string {
}
-func ProcessCollections(receivedCollections []SdkCollectionInfo,
+func ProcessCollections(arvLogger *logger.Logger,
+ receivedCollections []SdkCollectionInfo,
uuidToCollection map[string]Collection) (latestModificationDate time.Time) {
for _, sdkCollection := range receivedCollections {
collection := Collection{Uuid: StrCopy(sdkCollection.Uuid),
@@ -208,13 +208,15 @@ func ProcessCollections(receivedCollections []SdkCollectionInfo,
BlockDigestToSize: make(map[blockdigest.BlockDigest]int)}
if sdkCollection.ModifiedAt.IsZero() {
- log.Fatalf(
- "Arvados SDK collection returned with unexpected zero modifcation " +
- "date. This probably means that either we failed to parse the " +
- "modification date or the API server has changed how it returns " +
- "modification dates: %v",
- collection)
+ fatalWithMessage(arvLogger,
+ fmt.Sprintf(
+ "Arvados SDK collection returned with unexpected zero " +
+ "modifcation date. This probably means that either we failed to " +
+ "parse the modification date or the API server has changed how " +
+ "it returns modification dates: %v",
+ collection))
}
+
if sdkCollection.ModifiedAt.After(latestModificationDate) {
latestModificationDate = sdkCollection.ModifiedAt
}
@@ -232,12 +234,13 @@ func ProcessCollections(receivedCollections []SdkCollectionInfo,
for block := range blockChannel {
if stored_size, stored := collection.BlockDigestToSize[block.Digest];
stored && stored_size != block.Size {
- log.Fatalf(
+ message := fmt.Sprintf(
"Collection %s contains multiple sizes (%d and %d) for block %s",
collection.Uuid,
stored_size,
block.Size,
block.Digest)
+ fatalWithMessage(arvLogger, message)
}
collection.BlockDigestToSize[block.Digest] = block.Size
}
@@ -267,3 +270,18 @@ func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) (int) {
return collections.ItemsAvailable
}
+
+
+// Assumes you haven't already called arvLogger.Edit()!
+// If you have called arvLogger.Edit() this method will hang waiting
+// for the lock you're already holding.
+func fatalWithMessage(arvLogger *logger.Logger, message string) {
+ if arvLogger != nil {
+ properties,_ := arvLogger.Edit()
+ properties["FATAL"] = message
+ properties["run_info"].(map[string]interface{})["end_time"] = time.Now()
+ arvLogger.ForceRecord()
+ }
+
+ log.Fatalf(message)
+}
commit b14bc80d764b85a6ddfed32198b2144b5adf2637
Author: mishaz <misha at curoverse.com>
Date: Fri Jan 9 04:11:29 2015 +0000
Added ForceRecord() method to enable writing remaining log changes before exiting.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index 038482d..294ba92 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -107,6 +107,13 @@ func (l *Logger) Record() {
l.lock.Unlock()
}
+// Similar to Record, but forces a write without respecting the
+// MinimumWriteInterval. This is useful if you know that you're about
+// to quit (e.g. if you discovered a fatal error).
+func (l *Logger) ForceRecord() {
+ l.write()
+ l.lock.Unlock()
+}
// Whether enough time has elapsed since the last write.
func (l *Logger) writeAllowedNow() bool {
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 7e94a11..dd37377 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -58,7 +58,7 @@ func init() {
flag.StringVar(&heap_profile_filename,
"heap-profile",
"",
- "File to write the heap profiles to.")
+ "File to write the heap profiles to. Leave blank to skip profiling.")
}
// // Methods to implement util.SdkListResponse Interface
@@ -146,6 +146,11 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
var collections SdkCollectionList
err := params.Client.List("collections", sdkParams, &collections)
if err != nil {
+ if params.Logger != nil {
+ properties,_ := params.Logger.Edit()
+ properties["FATAL"] = err.Error()
+ params.Logger.Record()
+ }
log.Fatalf("error querying collections: %+v", err)
}
commit 4851f29ac730aa09dcb3489a3a6e7479e7b82fb6
Author: mishaz <misha at curoverse.com>
Date: Fri Jan 9 04:00:40 2015 +0000
Switched Logger edit hooks to write hooks so they'll trigger less often.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index fd40cce..038482d 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -51,7 +51,7 @@ type Logger struct {
lastWrite time.Time // The last time we wrote a log entry
modified bool // Has this data been modified since the last write
- editHooks []func(map[string]interface{},map[string]interface{})
+ writeHooks []func(map[string]interface{},map[string]interface{})
}
// Create a new logger based on the specified parameters.
@@ -78,23 +78,16 @@ func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]int
l.lock.Lock()
l.modified = true // We don't actually know the caller will modifiy the data, but we assume they will.
- // Run all our hooks
- for _, hook := range l.editHooks {
- hook(l.properties, l.entry)
- }
-
return l.properties, l.entry
}
-// Adds a hook which will be called everytime Edit() is called.
+// Adds a hook which will be called every time this logger writes an entry.
// The hook takes properties and entry as arguments, in that order.
// This is useful for stuff like memory profiling.
-// This must be called between Edit() and Record().
-// For convenience AddEditHook will call hook when it is added as well.
-func (l *Logger) AddEditHook(hook func(map[string]interface{},
+// This must be called between Edit() and Record() (e.g. while holding the lock)
+func (l *Logger) AddWriteHook(hook func(map[string]interface{},
map[string]interface{})) {
- l.editHooks = append(l.editHooks, hook)
- hook(l.properties, l.entry)
+ l.writeHooks = append(l.writeHooks, hook)
}
// Write the log entry you've built up so far. Do not edit the maps
@@ -123,13 +116,23 @@ func (l *Logger) writeAllowedNow() bool {
// Actually writes the log entry. This method assumes we're holding the lock.
func (l *Logger) write() {
+
+ // Run all our hooks
+ for _, hook := range l.writeHooks {
+ hook(l.properties, l.entry)
+ }
+
// Update the event type in case it was modified or is missing.
l.entry["event_type"] = l.params.EventType
+
+ // Write the log entry.
err := l.params.Client.Create("logs", l.data, nil)
if err != nil {
log.Printf("Attempted to log: %v", l.data)
log.Fatalf("Received error writing log: %v", err)
}
+
+ // Update stats.
l.lastWrite = time.Now()
l.modified = false
}
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 92dd9c5..87a71a9 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -66,7 +66,7 @@ func main() {
runInfo["pid"] = os.Getpid()
properties["run_info"] = runInfo
- arvLogger.AddEditHook(LogMemoryAlloc)
+ arvLogger.AddWriteHook(LogMemoryAlloc)
arvLogger.Record()
}
commit 3d63bc278174d245edc4fa06ed88971a2589e080
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 23:22:09 2015 +0000
Switched batch size to 50. Added logging of batch size.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 212e33f..7e94a11 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -127,6 +127,7 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
properties,_ := params.Logger.Edit()
collectionInfo := make(map[string]interface{})
collectionInfo["num_collections_at_start"] = initialNumberOfCollectionsAvailable
+ collectionInfo["batch_size"] = params.BatchSize
properties["collection_info"] = collectionInfo
params.Logger.Record()
}
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index bf98902..92dd9c5 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -75,7 +75,7 @@ func main() {
// This requires waiting on them to finish before you let main() exit.
RunCollections(collection.GetCollectionsParams{
- Client: arv, Logger: arvLogger, BatchSize: 100})
+ Client: arv, Logger: arvLogger, BatchSize: 50})
RunKeep(keep.GetKeepServersParams{Client: arv, Limit: 1000})
}
commit 970095751e2e836ed296152ae3e9ccb6caa62f62
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 23:17:52 2015 +0000
Added memory alloc in use to stats exported to log. Also added EditHooks to Logger, enabling users to add functions to get called on each Edit() call.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index 80cb627..fd40cce 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -50,6 +50,8 @@ type Logger struct {
lastWrite time.Time // The last time we wrote a log entry
modified bool // Has this data been modified since the last write
+
+ editHooks []func(map[string]interface{},map[string]interface{})
}
// Create a new logger based on the specified parameters.
@@ -75,9 +77,26 @@ func NewLogger(params LoggerParams) *Logger {
func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]interface{}) {
l.lock.Lock()
l.modified = true // We don't actually know the caller will modifiy the data, but we assume they will.
+
+ // Run all our hooks
+ for _, hook := range l.editHooks {
+ hook(l.properties, l.entry)
+ }
+
return l.properties, l.entry
}
+// Adds a hook which will be called everytime Edit() is called.
+// The hook takes properties and entry as arguments, in that order.
+// This is useful for stuff like memory profiling.
+// This must be called between Edit() and Record().
+// For convenience AddEditHook will call hook when it is added as well.
+func (l *Logger) AddEditHook(hook func(map[string]interface{},
+ map[string]interface{})) {
+ l.editHooks = append(l.editHooks, hook)
+ hook(l.properties, l.entry)
+}
+
// Write the log entry you've built up so far. Do not edit the maps
// returned by Edit() after calling this method.
// If you have already written within MinimumWriteInterval, then this
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index c64160c..212e33f 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -168,7 +168,7 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
properties,_ := params.Logger.Edit()
collectionInfo := properties["collection_info"].(map[string]interface{})
collectionInfo["collections_read"] = totalCollections
- collectionInfo["latest_modified_date"] = sdkParams["filters"].([][]string)[0][2]
+ collectionInfo["latest_modified_date_seen"] = sdkParams["filters"].([][]string)[0][2]
collectionInfo["total_manifest_size"] = totalManifestSize
collectionInfo["max_manifest_size"] = maxManifestSize
params.Logger.Record()
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index dc6a431..bf98902 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -11,6 +11,7 @@ import (
"git.curoverse.com/arvados.git/services/datamanager/keep"
"log"
"os"
+ "runtime"
"time"
)
@@ -64,6 +65,9 @@ func main() {
}
runInfo["pid"] = os.Getpid()
properties["run_info"] = runInfo
+
+ arvLogger.AddEditHook(LogMemoryAlloc)
+
arvLogger.Record()
}
@@ -71,7 +75,7 @@ func main() {
// This requires waiting on them to finish before you let main() exit.
RunCollections(collection.GetCollectionsParams{
- Client: arv, Logger: arvLogger, BatchSize: 500})
+ Client: arv, Logger: arvLogger, BatchSize: 100})
RunKeep(keep.GetKeepServersParams{Client: arv, Limit: 1000})
}
@@ -115,3 +119,11 @@ func ComputeSizeOfOwnedCollections(readCollections collection.ReadCollections) (
}
return
}
+
+func LogMemoryAlloc(properties map[string]interface{}, entry map[string]interface{}) {
+ _ = entry // keep the compiler from complaining
+ runInfo := properties["run_info"].(map[string]interface{})
+ var memStats runtime.MemStats
+ runtime.ReadMemStats(&memStats)
+ runInfo["alloc_bytes_in_use"] = memStats.Alloc
+}
commit 1c87e0d76265bb64b717289015181e41e0cbe2f3
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 22:35:37 2015 +0000
Added structure to data manager log entries, grouping similar fields.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index b2fcd5c..c64160c 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -125,7 +125,9 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
if params.Logger != nil {
properties,_ := params.Logger.Edit()
- properties["num_collections_at_start"] = initialNumberOfCollectionsAvailable
+ collectionInfo := make(map[string]interface{})
+ collectionInfo["num_collections_at_start"] = initialNumberOfCollectionsAvailable
+ properties["collection_info"] = collectionInfo
params.Logger.Record()
}
@@ -164,10 +166,11 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
if params.Logger != nil {
properties,_ := params.Logger.Edit()
- properties["collections_read"] = totalCollections
- properties["latest_modified_date"] = sdkParams["filters"].([][]string)[0][2]
- properties["total_manifest_size"] = totalManifestSize
- properties["max_manifest_size"] = maxManifestSize
+ collectionInfo := properties["collection_info"].(map[string]interface{})
+ collectionInfo["collections_read"] = totalCollections
+ collectionInfo["latest_modified_date"] = sdkParams["filters"].([][]string)[0][2]
+ collectionInfo["total_manifest_size"] = totalManifestSize
+ collectionInfo["max_manifest_size"] = maxManifestSize
params.Logger.Record()
}
}
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index b0ce1a7..dc6a431 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -53,14 +53,17 @@ func main() {
if arvLogger != nil {
properties, _ := arvLogger.Edit()
- properties["start_time"] = time.Now()
- properties["args"] = os.Args
+ runInfo := make(map[string]interface{})
+ runInfo["start_time"] = time.Now()
+ runInfo["args"] = os.Args
hostname, err := os.Hostname()
if err != nil {
- properties["hostname_error"] = err.Error()
+ runInfo["hostname_error"] = err.Error()
} else {
- properties["hostname"] = hostname
+ runInfo["hostname"] = hostname
}
+ runInfo["pid"] = os.Getpid()
+ properties["run_info"] = runInfo
arvLogger.Record()
}
commit e7ef642ff70bb7e6c281f4dd1d353f7fb2b3f5ce
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 22:24:00 2015 +0000
Added ability to turn off logging by passing an empty string as the event type.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 1c0c1e6..b2fcd5c 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -123,11 +123,11 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
float64(initialNumberOfCollectionsAvailable) * 1.01)
results.UuidToCollection = make(map[string]Collection, maxExpectedCollections)
- {
+ if params.Logger != nil {
properties,_ := params.Logger.Edit()
properties["num_collections_at_start"] = initialNumberOfCollectionsAvailable
+ params.Logger.Record()
}
- params.Logger.Record()
// These values are just for getting the loop to run the first time,
// afterwards they'll be set to real values.
@@ -162,14 +162,14 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
float32(totalManifestSize)/float32(totalCollections),
maxManifestSize, totalManifestSize)
- {
+ if params.Logger != nil {
properties,_ := params.Logger.Edit()
properties["collections_read"] = totalCollections
properties["latest_modified_date"] = sdkParams["filters"].([][]string)[0][2]
properties["total_manifest_size"] = totalManifestSize
properties["max_manifest_size"] = maxManifestSize
+ params.Logger.Record()
}
- params.Logger.Record()
}
// Just in case this lowers the numbers reported in the heap profile.
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 4c12c45..b0ce1a7 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -23,7 +23,7 @@ func init() {
flag.StringVar(&logEventType,
"log-event-type",
"experimental-data-manager-report",
- "event_type to use in our arvados log entries.")
+ "event_type to use in our arvados log entries. Set to empty to turn off logging")
flag.IntVar(&logFrequencySeconds,
"log-frequency-seconds",
20,
@@ -44,11 +44,14 @@ func main() {
log.Fatalf("Current user is not an admin. Datamanager can only be run by admins.")
}
- arvLogger := logger.NewLogger(logger.LoggerParams{Client: arv,
- EventType: logEventType,
- MinimumWriteInterval: time.Second * time.Duration(logFrequencySeconds)})
+ var arvLogger *logger.Logger
+ if logEventType != "" {
+ arvLogger = logger.NewLogger(logger.LoggerParams{Client: arv,
+ EventType: logEventType,
+ MinimumWriteInterval: time.Second * time.Duration(logFrequencySeconds)})
+ }
- {
+ if arvLogger != nil {
properties, _ := arvLogger.Edit()
properties["start_time"] = time.Now()
properties["args"] = os.Args
@@ -58,8 +61,8 @@ func main() {
} else {
properties["hostname"] = hostname
}
+ arvLogger.Record()
}
- arvLogger.Record()
// TODO(misha): Read Collections and Keep Contents concurrently as goroutines.
// This requires waiting on them to finish before you let main() exit.
commit 367a6fbc62b4b20af9f5724359fb0d0e423dc718
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 22:16:49 2015 +0000
Started using Logger in data manager and collections.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index e9a36f2..1c0c1e6 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -6,8 +6,8 @@ import (
"flag"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/blockdigest"
+ "git.curoverse.com/arvados.git/sdk/go/logger"
"git.curoverse.com/arvados.git/sdk/go/manifest"
- //"git.curoverse.com/arvados.git/sdk/go/util"
"log"
"os"
"runtime"
@@ -37,6 +37,7 @@ type ReadCollections struct {
type GetCollectionsParams struct {
Client arvadosclient.ArvadosClient
+ Logger *logger.Logger
BatchSize int
}
@@ -115,9 +116,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
sdkParams["limit"] = params.BatchSize
}
- // MISHA UNDO THIS TEMPORARY HACK TO FIND BUG!
- sdkParams["limit"] = 50
-
initialNumberOfCollectionsAvailable := NumberCollectionsAvailable(params.Client)
// Include a 1% margin for collections added while we're reading so
// that we don't have to grow the map in most cases.
@@ -125,6 +123,12 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
float64(initialNumberOfCollectionsAvailable) * 1.01)
results.UuidToCollection = make(map[string]Collection, maxExpectedCollections)
+ {
+ properties,_ := params.Logger.Edit()
+ properties["num_collections_at_start"] = initialNumberOfCollectionsAvailable
+ }
+ params.Logger.Record()
+
// These values are just for getting the loop to run the first time,
// afterwards they'll be set to real values.
previousTotalCollections := -1
@@ -157,6 +161,15 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
sdkParams["filters"].([][]string)[0][2],
float32(totalManifestSize)/float32(totalCollections),
maxManifestSize, totalManifestSize)
+
+ {
+ properties,_ := params.Logger.Edit()
+ properties["collections_read"] = totalCollections
+ properties["latest_modified_date"] = sdkParams["filters"].([][]string)[0][2]
+ properties["total_manifest_size"] = totalManifestSize
+ properties["max_manifest_size"] = maxManifestSize
+ }
+ params.Logger.Record()
}
// Just in case this lowers the numbers reported in the heap profile.
@@ -199,7 +212,9 @@ func ProcessCollections(receivedCollections []SdkCollectionInfo,
manifest := manifest.Manifest{sdkCollection.ManifestText}
manifestSize := uint64(len(sdkCollection.ManifestText))
- totalManifestSize += manifestSize
+ if _, alreadySeen := uuidToCollection[collection.Uuid]; !alreadySeen {
+ totalManifestSize += manifestSize
+ }
if manifestSize > maxManifestSize {
maxManifestSize = manifestSize
}
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 7b79f0f..4c12c45 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -5,12 +5,31 @@ package main
import (
"flag"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+ "git.curoverse.com/arvados.git/sdk/go/logger"
"git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/collection"
"git.curoverse.com/arvados.git/services/datamanager/keep"
"log"
+ "os"
+ "time"
)
+var (
+ logEventType string
+ logFrequencySeconds int
+)
+
+func init() {
+ flag.StringVar(&logEventType,
+ "log-event-type",
+ "experimental-data-manager-report",
+ "event_type to use in our arvados log entries.")
+ flag.IntVar(&logFrequencySeconds,
+ "log-frequency-seconds",
+ 20,
+ "How frequently we'll write log entries in seconds.")
+}
+
func main() {
flag.Parse()
@@ -25,27 +44,51 @@ func main() {
log.Fatalf("Current user is not an admin. Datamanager can only be run by admins.")
}
+ arvLogger := logger.NewLogger(logger.LoggerParams{Client: arv,
+ EventType: logEventType,
+ MinimumWriteInterval: time.Second * time.Duration(logFrequencySeconds)})
+
+ {
+ properties, _ := arvLogger.Edit()
+ properties["start_time"] = time.Now()
+ properties["args"] = os.Args
+ hostname, err := os.Hostname()
+ if err != nil {
+ properties["hostname_error"] = err.Error()
+ } else {
+ properties["hostname"] = hostname
+ }
+ }
+ arvLogger.Record()
+
// TODO(misha): Read Collections and Keep Contents concurrently as goroutines.
+ // This requires waiting on them to finish before you let main() exit.
+
+ RunCollections(collection.GetCollectionsParams{
+ Client: arv, Logger: arvLogger, BatchSize: 500})
- // readCollections := collection.GetCollections(
- // collection.GetCollectionsParams{
- // Client: arv, BatchSize: 500})
+ RunKeep(keep.GetKeepServersParams{Client: arv, Limit: 1000})
+}
- // UserUsage := ComputeSizeOfOwnedCollections(readCollections)
- // log.Printf("Uuid to Size used: %v", UserUsage)
+func RunCollections(params collection.GetCollectionsParams) {
+ readCollections := collection.GetCollections(params)
- // // TODO(misha): Add a "readonly" flag. If we're in readonly mode,
- // // lots of behaviors can become warnings (and obviously we can't
- // // write anything).
- // // if !readCollections.ReadAllCollections {
- // // log.Fatalf("Did not read all collections")
- // // }
+ UserUsage := ComputeSizeOfOwnedCollections(readCollections)
+ log.Printf("Uuid to Size used: %v", UserUsage)
- // log.Printf("Read and processed %d collections",
- // len(readCollections.UuidToCollection))
+ // TODO(misha): Add a "readonly" flag. If we're in readonly mode,
+ // lots of behaviors can become warnings (and obviously we can't
+ // write anything).
+ // if !readCollections.ReadAllCollections {
+ // log.Fatalf("Did not read all collections")
+ // }
+
+ log.Printf("Read and processed %d collections",
+ len(readCollections.UuidToCollection))
+}
- readServers := keep.GetKeepServers(
- keep.GetKeepServersParams{Client: arv, Limit: 1000})
+func RunKeep(params keep.GetKeepServersParams) {
+ readServers := keep.GetKeepServers(params)
log.Printf("Returned %d keep disks", len(readServers.ServerToContents))
commit 1a68b00bcb3dd92f597de72274a56ed4a1144c2b
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 21:06:49 2015 +0000
Added support for MinimumWriteInterval.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index a3d2f30..80cb627 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -1,4 +1,4 @@
-// Periodically writes a log to the Arvados SDK.
+// Logger periodically writes a log to the Arvados SDK.
//
// This package is useful for maintaining a log object that is built
// up over time. Every time the object is modified, it will be written
@@ -22,7 +22,6 @@
// // entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
// }
// arvLogger.Record() // This triggers the actual log write
-
package logger
import (
@@ -41,11 +40,16 @@ type LoggerParams struct {
// A Logger is used to build up a log entry over time and write every
// version of it.
type Logger struct {
+ // The Data we write
data map[string]interface{} // The entire map that we give to the api
- entry map[string]interface{} // convenience shortcut into data
- properties map[string]interface{} // convenience shortcut into data
- lock sync.Locker // Synchronizes editing and writing
- params LoggerParams // parameters we were given
+ entry map[string]interface{} // Convenience shortcut into data
+ properties map[string]interface{} // Convenience shortcut into data
+
+ lock sync.Locker // Synchronizes editing and writing
+ params LoggerParams // Parameters we were given
+
+ lastWrite time.Time // The last time we wrote a log entry
+ modified bool // Has this data been modified since the last write
}
// Create a new logger based on the specified parameters.
@@ -53,8 +57,6 @@ func NewLogger(params LoggerParams) *Logger {
// TODO(misha): Add some params checking here.
l := &Logger{data: make(map[string]interface{}),
lock: &sync.Mutex{},
- // TODO(misha): Consider copying the params so they're not
- // modified after creation.
params: params}
l.entry = make(map[string]interface{})
l.data["log"] = l.entry
@@ -72,17 +74,35 @@ func NewLogger(params LoggerParams) *Logger {
// properties is a shortcut for entry["properties"].(map[string]interface{})
func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]interface{}) {
l.lock.Lock()
+ l.modified = true // We don't actually know the caller will modifiy the data, but we assume they will.
return l.properties, l.entry
}
-// Write the log entry you've built up so far. Do not edit the maps returned by Edit() after calling this method.
+// Write the log entry you've built up so far. Do not edit the maps
+// returned by Edit() after calling this method.
+// If you have already written within MinimumWriteInterval, then this
+// will schedule a future write instead.
+// In either case, the lock will be released before Record() returns.
func (l *Logger) Record() {
- // TODO(misha): Add a check (and storage) to make sure we respect MinimumWriteInterval
- l.write()
+ if l.writeAllowedNow() {
+ // We haven't written in the allowed interval yet, try to write.
+ l.write()
+ } else {
+ nextTimeToWrite := l.lastWrite.Add(l.params.MinimumWriteInterval)
+ writeAfter := nextTimeToWrite.Sub(time.Now())
+ time.AfterFunc(writeAfter, l.acquireLockConsiderWriting)
+ }
l.lock.Unlock()
}
-// Actually writes the log entry.
+
+// Whether enough time has elapsed since the last write.
+func (l *Logger) writeAllowedNow() bool {
+ return l.lastWrite.Add(l.params.MinimumWriteInterval).Before(time.Now())
+}
+
+
+// Actually writes the log entry. This method assumes we're holding the lock.
func (l *Logger) write() {
// Update the event type in case it was modified or is missing.
l.entry["event_type"] = l.params.EventType
@@ -91,4 +111,16 @@ func (l *Logger) write() {
log.Printf("Attempted to log: %v", l.data)
log.Fatalf("Received error writing log: %v", err)
}
+ l.lastWrite = time.Now()
+ l.modified = false
+}
+
+
+func (l *Logger) acquireLockConsiderWriting() {
+ l.lock.Lock()
+ if l.modified && l.writeAllowedNow() {
+ // We have something new to write and we're allowed to write.
+ l.write()
+ }
+ l.lock.Unlock()
}
commit 0cf4805d979615190f38ce1d01f1b2d0e8927988
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 20:14:10 2015 +0000
Fixed bugs in logger, changed interface some, added documentation.
Still need to add support for MinimunWriteInterval.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
index 6835750..a3d2f30 100644
--- a/sdk/go/logger/logger.go
+++ b/sdk/go/logger/logger.go
@@ -5,13 +5,23 @@
// to the log. Writes will be throttled to no more than one every
// WriteFrequencySeconds
//
-// This package is safe for concurrent use.
+// This package is safe for concurrent use as long as:
+// 1. The maps returned by Edit() are only edited in the same routine
+// that called Edit()
+// 2. Those maps not edited after calling Record()
+// An easy way to assure this is true is to place the call to Edit()
+// within a short block as shown below in the Usage Example:
//
// Usage:
// arvLogger := logger.NewLogger(params)
-// logData := arvLogger.Acquire() // This will block if others are using the logger
-// // Modify the logObject however you want here ..
-// logData = arvLogger.Release() // This triggers the actual write, and replaces logObject with a nil pointer so you don't try to modify it when you're no longer holding the lock
+// {
+// properties, entry := arvLogger.Edit() // This will block if others are using the logger
+// // Modifiy properties and entry however you want
+// // properties is a shortcut for entry["properties"].(map[string]interface{})
+// // properties can take any values you want to give it,
+// // entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
+// }
+// arvLogger.Record() // This triggers the actual log write
package logger
@@ -22,58 +32,63 @@ import (
"time"
)
-const (
- eventTypeLabel string = "event-type"
- propertiesLabel string = "properties"
-)
-
type LoggerParams struct {
Client arvadosclient.ArvadosClient // The client we use to write log entries
EventType string // The event type to assign to the log entry.
MinimumWriteInterval time.Duration // Wait at least this long between log writes
}
+// A Logger is used to build up a log entry over time and write every
+// version of it.
type Logger struct {
- data map[string]interface{}
- lock sync.Locker
- params LoggerParams
+ data map[string]interface{} // The entire map that we give to the api
+ entry map[string]interface{} // convenience shortcut into data
+ properties map[string]interface{} // convenience shortcut into data
+ lock sync.Locker // Synchronizes editing and writing
+ params LoggerParams // parameters we were given
}
+// Create a new logger based on the specified parameters.
func NewLogger(params LoggerParams) *Logger {
+ // TODO(misha): Add some params checking here.
l := &Logger{data: make(map[string]interface{}),
lock: &sync.Mutex{},
// TODO(misha): Consider copying the params so they're not
// modified after creation.
params: params}
- l.data[propertiesLabel] = make(map[string]interface{})
+ l.entry = make(map[string]interface{})
+ l.data["log"] = l.entry
+ l.properties = make(map[string]interface{})
+ l.entry["properties"] = l.properties
return l
}
-func (l *Logger) Acquire() map[string]interface{} {
+// Get access to the maps you can edit. This will hold a lock until
+// you call Record. Do not edit the maps in any other goroutines or
+// after calling Record.
+// You don't need to edit both maps,
+// properties can take any values you want to give it,
+// entry will only take the fields listed at http://doc.arvados.org/api/schema/Log.html
+// properties is a shortcut for entry["properties"].(map[string]interface{})
+func (l *Logger) Edit() (properties map[string]interface{}, entry map[string]interface{}) {
l.lock.Lock()
- return l.data[propertiesLabel].(map[string]interface{})
+ return l.properties, l.entry
}
-func (l *Logger) Release() map[string]interface{} {
+// Write the log entry you've built up so far. Do not edit the maps returned by Edit() after calling this method.
+func (l *Logger) Record() {
// TODO(misha): Add a check (and storage) to make sure we respect MinimumWriteInterval
l.write()
l.lock.Unlock()
- return nil
}
+// Actually writes the log entry.
func (l *Logger) write() {
// Update the event type in case it was modified or is missing.
- // l.data[eventTypeLabel] = l.params.EventType
- // m := make(map[string]interface{})
- // m["body"] = l.data
- // //err := l.params.Client.Create("logs", l.data, nil)
- // //err := l.params.Client.Create("logs", m, nil)
- // var results map[string]interface{}
- err := l.params.Client.Create("logs",
- arvadosclient.Dict{"log": arvadosclient.Dict{
- eventTypeLabel: l.params.EventType,
- propertiesLabel: l.data}}, nil)
+ l.entry["event_type"] = l.params.EventType
+ err := l.params.Client.Create("logs", l.data, nil)
if err != nil {
+ log.Printf("Attempted to log: %v", l.data)
log.Fatalf("Received error writing log: %v", err)
}
}
diff --git a/sdk/go/logger/main/testlogger.go b/sdk/go/logger/main/testlogger.go
index 5a12352..6cd7dfb 100644
--- a/sdk/go/logger/main/testlogger.go
+++ b/sdk/go/logger/main/testlogger.go
@@ -10,11 +10,6 @@ import (
"log"
)
-const (
- eventType string = "experimental-logger-testing"
-)
-
-
func main() {
arv, err := arvadosclient.MakeArvadosClient()
if err != nil {
@@ -22,11 +17,13 @@ func main() {
}
l := logger.NewLogger(logger.LoggerParams{Client: arv,
- EventType: eventType,
+ EventType: "experimental-logger-testing",
// No minimum write interval
})
- logData := l.Acquire()
- logData["Ninja"] = "Misha"
- logData = l.Release()
+ {
+ properties, _ := l.Edit()
+ properties["Ninja"] = "Misha"
+ }
+ l.Record()
}
commit 3594ad790c998c1b1711ea65057fcae9477986d4
Author: mishaz <misha at curoverse.com>
Date: Thu Jan 8 01:47:51 2015 +0000
Added logger to write log messages that grow over time. Not working yet.
diff --git a/sdk/go/logger/logger.go b/sdk/go/logger/logger.go
new file mode 100644
index 0000000..6835750
--- /dev/null
+++ b/sdk/go/logger/logger.go
@@ -0,0 +1,79 @@
+// Periodically writes a log to the Arvados SDK.
+//
+// This package is useful for maintaining a log object that is built
+// up over time. Every time the object is modified, it will be written
+// to the log. Writes will be throttled to no more than one every
+// WriteFrequencySeconds
+//
+// This package is safe for concurrent use.
+//
+// Usage:
+// arvLogger := logger.NewLogger(params)
+// logData := arvLogger.Acquire() // This will block if others are using the logger
+// // Modify the logObject however you want here ..
+// logData = arvLogger.Release() // This triggers the actual write, and replaces logObject with a nil pointer so you don't try to modify it when you're no longer holding the lock
+
+package logger
+
+import (
+ "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+ "log"
+ "sync"
+ "time"
+)
+
+const (
+ eventTypeLabel string = "event-type"
+ propertiesLabel string = "properties"
+)
+
+type LoggerParams struct {
+ Client arvadosclient.ArvadosClient // The client we use to write log entries
+ EventType string // The event type to assign to the log entry.
+ MinimumWriteInterval time.Duration // Wait at least this long between log writes
+}
+
+type Logger struct {
+ data map[string]interface{}
+ lock sync.Locker
+ params LoggerParams
+}
+
+func NewLogger(params LoggerParams) *Logger {
+ l := &Logger{data: make(map[string]interface{}),
+ lock: &sync.Mutex{},
+ // TODO(misha): Consider copying the params so they're not
+ // modified after creation.
+ params: params}
+ l.data[propertiesLabel] = make(map[string]interface{})
+ return l
+}
+
+func (l *Logger) Acquire() map[string]interface{} {
+ l.lock.Lock()
+ return l.data[propertiesLabel].(map[string]interface{})
+}
+
+func (l *Logger) Release() map[string]interface{} {
+ // TODO(misha): Add a check (and storage) to make sure we respect MinimumWriteInterval
+ l.write()
+ l.lock.Unlock()
+ return nil
+}
+
+func (l *Logger) write() {
+ // Update the event type in case it was modified or is missing.
+ // l.data[eventTypeLabel] = l.params.EventType
+ // m := make(map[string]interface{})
+ // m["body"] = l.data
+ // //err := l.params.Client.Create("logs", l.data, nil)
+ // //err := l.params.Client.Create("logs", m, nil)
+ // var results map[string]interface{}
+ err := l.params.Client.Create("logs",
+ arvadosclient.Dict{"log": arvadosclient.Dict{
+ eventTypeLabel: l.params.EventType,
+ propertiesLabel: l.data}}, nil)
+ if err != nil {
+ log.Fatalf("Received error writing log: %v", err)
+ }
+}
diff --git a/sdk/go/logger/main/testlogger.go b/sdk/go/logger/main/testlogger.go
new file mode 100644
index 0000000..5a12352
--- /dev/null
+++ b/sdk/go/logger/main/testlogger.go
@@ -0,0 +1,32 @@
+// This binary tests the logger package.
+// It's not a standard unit test. Instead it writes to the actual log
+// and you have to clean up after it.
+
+package main
+
+import (
+ "git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+ "git.curoverse.com/arvados.git/sdk/go/logger"
+ "log"
+)
+
+const (
+ eventType string = "experimental-logger-testing"
+)
+
+
+func main() {
+ arv, err := arvadosclient.MakeArvadosClient()
+ if err != nil {
+ log.Fatalf("Error setting up arvados client %v", err)
+ }
+
+ l := logger.NewLogger(logger.LoggerParams{Client: arv,
+ EventType: eventType,
+ // No minimum write interval
+ })
+
+ logData := l.Acquire()
+ logData["Ninja"] = "Misha"
+ logData = l.Release()
+}
commit 08fbba821251a58cc99921cb477fbbc076a1bfee
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 7 04:16:40 2015 +0000
Started focusing on Keep Server responses again. Switched to using blockdigest instead of strings. Added per block info so that we can track block replication across servers.
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 6393787..7b79f0f 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -7,7 +7,7 @@ import (
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/collection"
-// "git.curoverse.com/arvados.git/services/datamanager/keep"
+ "git.curoverse.com/arvados.git/services/datamanager/keep"
"log"
)
@@ -27,29 +27,35 @@ func main() {
// TODO(misha): Read Collections and Keep Contents concurrently as goroutines.
- readCollections := collection.GetCollections(
- collection.GetCollectionsParams{
- Client: arv, BatchSize: 500})
+ // readCollections := collection.GetCollections(
+ // collection.GetCollectionsParams{
+ // Client: arv, BatchSize: 500})
- //log.Printf("Read Collections: %v", readCollections)
+ // UserUsage := ComputeSizeOfOwnedCollections(readCollections)
+ // log.Printf("Uuid to Size used: %v", UserUsage)
- UserUsage := ComputeSizeOfOwnedCollections(readCollections)
- log.Printf("Uuid to Size used: %v", UserUsage)
+ // // TODO(misha): Add a "readonly" flag. If we're in readonly mode,
+ // // lots of behaviors can become warnings (and obviously we can't
+ // // write anything).
+ // // if !readCollections.ReadAllCollections {
+ // // log.Fatalf("Did not read all collections")
+ // // }
- // TODO(misha): Add a "readonly" flag. If we're in readonly mode,
- // lots of behaviors can become warnings (and obviously we can't
- // write anything).
- // if !readCollections.ReadAllCollections {
- // log.Fatalf("Did not read all collections")
- // }
+ // log.Printf("Read and processed %d collections",
+ // len(readCollections.UuidToCollection))
- log.Printf("Read and processed %d collections",
- len(readCollections.UuidToCollection))
+ readServers := keep.GetKeepServers(
+ keep.GetKeepServersParams{Client: arv, Limit: 1000})
- // readServers := keep.GetKeepServers(
- // keep.GetKeepServersParams{Client: arv, Limit: 1000})
+ log.Printf("Returned %d keep disks", len(readServers.ServerToContents))
- // log.Printf("Returned %d keep disks", len(readServers.AddressToContents))
+ blockReplicationCounts := make(map[int]int)
+ for _, infos := range readServers.BlockToServers {
+ replication := len(infos)
+ blockReplicationCounts[replication] += 1
+ }
+
+ log.Printf("Replication level distribution: %v", blockReplicationCounts)
}
func ComputeSizeOfOwnedCollections(readCollections collection.ReadCollections) (
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index e600c4a..91af201 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -8,6 +8,7 @@ import (
"fmt"
//"git.curoverse.com/arvados.git/sdk/go/keepclient"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+ "git.curoverse.com/arvados.git/sdk/go/blockdigest"
"git.curoverse.com/arvados.git/sdk/go/manifest"
"git.curoverse.com/arvados.git/sdk/go/util"
"log"
@@ -23,14 +24,22 @@ type ServerAddress struct {
Port int `json:"service_port"`
}
+// Info about a particular block returned by the server
type BlockInfo struct {
- Digest string
+ Digest blockdigest.BlockDigest
Size int
Mtime int // TODO(misha): Replace this with a timestamp.
}
+// Info about a specified block given by a server
+type BlockServerInfo struct {
+ ServerIndex int
+ Size int
+ Mtime int // TODO(misha): Replace this with a timestamp.
+}
+
type ServerContents struct {
- BlockDigestToInfo map[string]BlockInfo
+ BlockDigestToInfo map[blockdigest.BlockDigest]BlockInfo
}
type ServerResponse struct {
@@ -40,7 +49,10 @@ type ServerResponse struct {
type ReadServers struct {
ReadAllServers bool
- AddressToContents map[ServerAddress]ServerContents
+ KeepServerIndexToAddress []ServerAddress
+ KeepServerAddressToIndex map[ServerAddress]int
+ ServerToContents map[ServerAddress]ServerContents
+ BlockToServers map[blockdigest.BlockDigest][]BlockServerInfo
}
type GetKeepServersParams struct {
@@ -130,6 +142,14 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
numAvailable)
}
+ results.KeepServerIndexToAddress = sdkResponse.KeepServers
+ results.KeepServerAddressToIndex = make(map[ServerAddress]int)
+ for i, address := range results.KeepServerIndexToAddress {
+ results.KeepServerAddressToIndex[address] = i
+ }
+
+ log.Printf("Got Server Addresses: %v", results)
+
// This is safe for concurrent use
client := http.Client{}
@@ -139,7 +159,8 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
go GetServerContents(keepServer, client, responseChan)
}
- results.AddressToContents = make(map[ServerAddress]ServerContents)
+ results.ServerToContents = make(map[ServerAddress]ServerContents)
+ results.BlockToServers = make(map[blockdigest.BlockDigest][]BlockServerInfo)
// Read all the responses
for i := range sdkResponse.KeepServers {
@@ -148,7 +169,15 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
log.Printf("Received channel response from %v containing %d files",
response.Address,
len(response.Contents.BlockDigestToInfo))
- results.AddressToContents[response.Address] = response.Contents
+ results.ServerToContents[response.Address] = response.Contents
+ serverIndex := results.KeepServerAddressToIndex[response.Address]
+ for _, blockInfo := range response.Contents.BlockDigestToInfo {
+ results.BlockToServers[blockInfo.Digest] = append(
+ results.BlockToServers[blockInfo.Digest],
+ BlockServerInfo{ServerIndex: serverIndex,
+ Size: blockInfo.Size,
+ Mtime: blockInfo.Mtime})
+ }
}
return
}
@@ -183,7 +212,8 @@ func GetServerContents(keepServer ServerAddress,
response := ServerResponse{}
response.Address = keepServer
- response.Contents.BlockDigestToInfo = make(map[string]BlockInfo)
+ response.Contents.BlockDigestToInfo =
+ make(map[blockdigest.BlockDigest]BlockInfo)
scanner := bufio.NewScanner(resp.Body)
numLines, numDuplicates, numSizeDisagreements := 0, 0, 0
for scanner.Scan() {
commit 9cf25951c6b64449fe24ff9965e7dabe85c8ff4e
Author: mishaz <misha at curoverse.com>
Date: Wed Jan 7 01:45:55 2015 +0000
Fixed heap profile writing so that we overwrite previous heap profiles rather than adding to them. Minor cleanup too.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 48121cd..e9a36f2 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -10,13 +10,16 @@ import (
//"git.curoverse.com/arvados.git/sdk/go/util"
"log"
"os"
+ "runtime"
"runtime/pprof"
"time"
)
var (
heap_profile_filename string
- heap_profile *os.File
+ // globals for debugging
+ totalManifestSize uint64
+ maxManifestSize uint64
)
type Collection struct {
@@ -66,21 +69,35 @@ func init() {
// return len(s.Items), nil
// }
-func GetCollections(params GetCollectionsParams) (results ReadCollections) {
- if ¶ms.Client == nil {
- log.Fatalf("params.Client passed to GetCollections() should " +
- "contain a valid ArvadosClient, but instead it is nil.")
- }
-
- // TODO(misha): move this code somewhere better and make sure it's
- // only run once
+// Write the heap profile to a file for later review.
+// Since a file is expected to only contain a single heap profile this
+// function overwrites the previously written profile, so it is safe
+// to call multiple times in a single run.
+// Otherwise we would see cumulative numbers as explained here:
+// https://groups.google.com/d/msg/golang-nuts/ZyHciRglQYc/2nh4Ndu2fZcJ
+func WriteHeapProfile() {
if heap_profile_filename != "" {
- var err error
- heap_profile, err = os.Create(heap_profile_filename)
+
+ heap_profile, err := os.Create(heap_profile_filename)
+ if err != nil {
+ log.Fatal(err)
+ }
+
+ defer heap_profile.Close()
+
+ err = pprof.WriteHeapProfile(heap_profile)
if err != nil {
log.Fatal(err)
}
}
+}
+
+
+func GetCollections(params GetCollectionsParams) (results ReadCollections) {
+ if ¶ms.Client == nil {
+ log.Fatalf("params.Client passed to GetCollections() should " +
+ "contain a valid ArvadosClient, but instead it is nil.")
+ }
fieldsWanted := []string{"manifest_text",
"owner_uuid",
@@ -101,19 +118,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
// MISHA UNDO THIS TEMPORARY HACK TO FIND BUG!
sdkParams["limit"] = 50
- // {
- // var numReceived, numAvailable int
- // results.ReadAllCollections, numReceived, numAvailable =
- // util.ContainsAllAvailableItems(collections)
-
- // if (!results.ReadAllCollections) {
- // log.Printf("ERROR: Did not receive all collections.")
- // }
- // log.Printf("Received %d of %d available collections.",
- // numReceived,
- // numAvailable)
- // }
-
initialNumberOfCollectionsAvailable := NumberCollectionsAvailable(params.Client)
// Include a 1% margin for collections added while we're reading so
// that we don't have to grow the map in most cases.
@@ -129,12 +133,7 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
// We're still finding new collections
// Write the heap profile for examining memory usage
- if heap_profile != nil {
- err := pprof.WriteHeapProfile(heap_profile)
- if err != nil {
- log.Fatal(err)
- }
- }
+ WriteHeapProfile()
// Get next batch of collections.
var collections SdkCollectionList
@@ -152,19 +151,19 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
totalCollections = len(results.UuidToCollection)
log.Printf("%d collections read, %d new in last batch, " +
- "%s latest modified date",
+ "%s latest modified date, %.0f %d %d avg,max,total manifest size",
totalCollections,
totalCollections - previousTotalCollections,
- sdkParams["filters"].([][]string)[0][2])
+ sdkParams["filters"].([][]string)[0][2],
+ float32(totalManifestSize)/float32(totalCollections),
+ maxManifestSize, totalManifestSize)
}
+ // Just in case this lowers the numbers reported in the heap profile.
+ runtime.GC()
+
// Write the heap profile for examining memory usage
- if heap_profile != nil {
- err := pprof.WriteHeapProfile(heap_profile)
- if err != nil {
- log.Fatal(err)
- }
- }
+ WriteHeapProfile()
return
}
@@ -198,6 +197,13 @@ func ProcessCollections(receivedCollections []SdkCollectionInfo,
latestModificationDate = sdkCollection.ModifiedAt
}
manifest := manifest.Manifest{sdkCollection.ManifestText}
+ manifestSize := uint64(len(sdkCollection.ManifestText))
+
+ totalManifestSize += manifestSize
+ if manifestSize > maxManifestSize {
+ maxManifestSize = manifestSize
+ }
+
blockChannel := manifest.BlockIterWithDuplicates()
for block := range blockChannel {
if stored_size, stored := collection.BlockDigestToSize[block.Digest];
commit fbfd3b4c049d4b3d24b22bfb5462f098c73596aa
Author: mishaz <misha at curoverse.com>
Date: Wed Dec 24 20:26:38 2014 +0000
Added string copying to try to reduce memory usage, didn't seem to work. Cleaned up logging (and logging logic) so that we only see one line per batch.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index fac4d1a..48121cd 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -93,8 +93,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
"select": fieldsWanted,
"order": []string{"modified_at ASC"},
"filters": [][]string{[]string{"modified_at", ">=", "1900-01-01T00:00:00Z"}}}
- // MISHA UNDO THIS TEMPORARY HACK TO FIND BUG!
- //"filters": [][]string{[]string{"modified_at", ">=", "2014-11-05T20:44:50Z"}}}
if params.BatchSize > 0 {
sdkParams["limit"] = params.BatchSize
@@ -123,13 +121,12 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
float64(initialNumberOfCollectionsAvailable) * 1.01)
results.UuidToCollection = make(map[string]Collection, maxExpectedCollections)
+ // These values are just for getting the loop to run the first time,
+ // afterwards they'll be set to real values.
previousTotalCollections := -1
- for len(results.UuidToCollection) > previousTotalCollections {
+ totalCollections := 0
+ for totalCollections > previousTotalCollections {
// We're still finding new collections
- log.Printf("previous, current: %d %d", previousTotalCollections, len(results.UuidToCollection))
-
- // update count
- previousTotalCollections = len(results.UuidToCollection)
// Write the heap profile for examining memory usage
if heap_profile != nil {
@@ -141,7 +138,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
// Get next batch of collections.
var collections SdkCollectionList
- log.Printf("Running with SDK Params: %v", sdkParams)
err := params.Client.List("collections", sdkParams, &collections)
if err != nil {
log.Fatalf("error querying collections: %+v", err)
@@ -150,9 +146,17 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
// Process collection and update our date filter.
sdkParams["filters"].([][]string)[0][2] =
ProcessCollections(collections.Items, results.UuidToCollection).Format(time.RFC3339)
- log.Printf("Latest date seen %s", sdkParams["filters"].([][]string)[0][2])
+
+ // update counts
+ previousTotalCollections = totalCollections
+ totalCollections = len(results.UuidToCollection)
+
+ log.Printf("%d collections read, %d new in last batch, " +
+ "%s latest modified date",
+ totalCollections,
+ totalCollections - previousTotalCollections,
+ sdkParams["filters"].([][]string)[0][2])
}
- log.Printf("previous, current: %d %d", previousTotalCollections, len(results.UuidToCollection))
// Write the heap profile for examining memory usage
if heap_profile != nil {
@@ -166,11 +170,19 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
}
+// StrCopy returns a newly allocated string.
+// It is useful to copy slices so that the garbage collector can reuse
+// the memory of the longer strings they came from.
+func StrCopy(s string) string {
+ return string([]byte(s))
+}
+
+
func ProcessCollections(receivedCollections []SdkCollectionInfo,
uuidToCollection map[string]Collection) (latestModificationDate time.Time) {
for _, sdkCollection := range receivedCollections {
- collection := Collection{Uuid: sdkCollection.Uuid,
- OwnerUuid: sdkCollection.OwnerUuid,
+ collection := Collection{Uuid: StrCopy(sdkCollection.Uuid),
+ OwnerUuid: StrCopy(sdkCollection.OwnerUuid),
ReplicationLevel: sdkCollection.Redundancy,
BlockDigestToSize: make(map[blockdigest.BlockDigest]int)}
commit 2ccc3eda37cd728d6526804c228d7383dc8960a9
Author: mishaz <misha at curoverse.com>
Date: Wed Dec 24 19:29:08 2014 +0000
Started parsing modification date as a timestamp instead of leaving it as a string.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 927b888..fac4d1a 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -11,6 +11,7 @@ import (
"log"
"os"
"runtime/pprof"
+ "time"
)
var (
@@ -37,11 +38,11 @@ type GetCollectionsParams struct {
}
type SdkCollectionInfo struct {
- Uuid string `json:"uuid"`
- OwnerUuid string `json:"owner_uuid"`
- Redundancy int `json:"redundancy"`
- ModifiedAt string `json:"modified_at"`
- ManifestText string `json:"manifest_text"`
+ Uuid string `json:"uuid"`
+ OwnerUuid string `json:"owner_uuid"`
+ Redundancy int `json:"redundancy"`
+ ModifiedAt time.Time `json:"modified_at"`
+ ManifestText string `json:"manifest_text"`
}
type SdkCollectionList struct {
@@ -147,7 +148,8 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
}
// Process collection and update our date filter.
- sdkParams["filters"].([][]string)[0][2] = ProcessCollections(collections.Items, results.UuidToCollection)
+ sdkParams["filters"].([][]string)[0][2] =
+ ProcessCollections(collections.Items, results.UuidToCollection).Format(time.RFC3339)
log.Printf("Latest date seen %s", sdkParams["filters"].([][]string)[0][2])
}
log.Printf("previous, current: %d %d", previousTotalCollections, len(results.UuidToCollection))
@@ -165,16 +167,22 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
func ProcessCollections(receivedCollections []SdkCollectionInfo,
- uuidToCollection map[string]Collection) (latestModificationDate string) {
+ uuidToCollection map[string]Collection) (latestModificationDate time.Time) {
for _, sdkCollection := range receivedCollections {
collection := Collection{Uuid: sdkCollection.Uuid,
OwnerUuid: sdkCollection.OwnerUuid,
ReplicationLevel: sdkCollection.Redundancy,
BlockDigestToSize: make(map[blockdigest.BlockDigest]int)}
- // log.Printf("Seeing modification date, owner_uuid: %s %s",
- // sdkCollection.ModifiedAt,
- // sdkCollection.OwnerUuid)
- if sdkCollection.ModifiedAt > latestModificationDate {
+
+ if sdkCollection.ModifiedAt.IsZero() {
+ log.Fatalf(
+ "Arvados SDK collection returned with unexpected zero modifcation " +
+ "date. This probably means that either we failed to parse the " +
+ "modification date or the API server has changed how it returns " +
+ "modification dates: %v",
+ collection)
+ }
+ if sdkCollection.ModifiedAt.After(latestModificationDate) {
latestModificationDate = sdkCollection.ModifiedAt
}
manifest := manifest.Manifest{sdkCollection.ManifestText}
commit d7f6013f1e728a3a7b42d6736b78cc81ac7de127
Author: mishaz <misha at curoverse.com>
Date: Wed Dec 24 01:36:43 2014 +0000
Switched from strings to BlockDigests to hold block digests more efficiently. Started clearing out manifest text once we finished with it. Made profiling conitional on flag (before it crashed if not provided). Added final heap profile once collections were finished.
Runs to completion!
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 159b568..927b888 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -5,6 +5,7 @@ package collection
import (
"flag"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+ "git.curoverse.com/arvados.git/sdk/go/blockdigest"
"git.curoverse.com/arvados.git/sdk/go/manifest"
//"git.curoverse.com/arvados.git/sdk/go/util"
"log"
@@ -21,7 +22,7 @@ type Collection struct {
Uuid string
OwnerUuid string
ReplicationLevel int
- BlockDigestToSize map[string]int
+ BlockDigestToSize map[blockdigest.BlockDigest]int
TotalSize int
}
@@ -80,10 +81,6 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
}
}
-
-
-
-
fieldsWanted := []string{"manifest_text",
"owner_uuid",
"uuid",
@@ -134,7 +131,7 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
previousTotalCollections = len(results.UuidToCollection)
// Write the heap profile for examining memory usage
- {
+ if heap_profile != nil {
err := pprof.WriteHeapProfile(heap_profile)
if err != nil {
log.Fatal(err)
@@ -155,6 +152,14 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
}
log.Printf("previous, current: %d %d", previousTotalCollections, len(results.UuidToCollection))
+ // Write the heap profile for examining memory usage
+ if heap_profile != nil {
+ err := pprof.WriteHeapProfile(heap_profile)
+ if err != nil {
+ log.Fatal(err)
+ }
+ }
+
return
}
@@ -165,7 +170,7 @@ func ProcessCollections(receivedCollections []SdkCollectionInfo,
collection := Collection{Uuid: sdkCollection.Uuid,
OwnerUuid: sdkCollection.OwnerUuid,
ReplicationLevel: sdkCollection.Redundancy,
- BlockDigestToSize: make(map[string]int)}
+ BlockDigestToSize: make(map[blockdigest.BlockDigest]int)}
// log.Printf("Seeing modification date, owner_uuid: %s %s",
// sdkCollection.ModifiedAt,
// sdkCollection.OwnerUuid)
@@ -191,6 +196,11 @@ func ProcessCollections(receivedCollections []SdkCollectionInfo,
collection.TotalSize += size
}
uuidToCollection[collection.Uuid] = collection
+
+ // Clear out all the manifest strings that we don't need anymore.
+ // These hopefully form the bulk of our memory usage.
+ manifest.Text = ""
+ sdkCollection.ManifestText = ""
}
return
commit dab166a0e63d256b2ccfd209493a35696f88726f
Author: mishaz <misha at curoverse.com>
Date: Wed Dec 24 00:24:07 2014 +0000
Changes to manifest that I forgot to add to previous checking.
diff --git a/sdk/go/manifest/manifest.go b/sdk/go/manifest/manifest.go
index d7b5eb5..1227f49 100644
--- a/sdk/go/manifest/manifest.go
+++ b/sdk/go/manifest/manifest.go
@@ -6,6 +6,7 @@ package manifest
import (
"fmt"
+ "git.curoverse.com/arvados.git/sdk/go/blockdigest"
"log"
"regexp"
"strconv"
@@ -20,7 +21,7 @@ type Manifest struct {
}
type BlockLocator struct {
- Digest string
+ Digest blockdigest.BlockDigest
Size int
Hints []string
}
@@ -40,14 +41,16 @@ func ParseBlockLocator(s string) (b BlockLocator, err error) {
} else {
tokens := strings.Split(s, "+")
var blockSize int64
- // We expect ParseInt to succeed since LocatorPattern restricts
- // tokens[1] to contain exclusively digits.
+ var blockDigest blockdigest.BlockDigest
+ // We expect both of the following to succeed since LocatorPattern
+ // restricts the strings appropriately.
+ blockDigest, err = blockdigest.FromString(tokens[0])
+ if err != nil {return}
blockSize, err = strconv.ParseInt(tokens[1], 10, 0)
- if err == nil {
- b.Digest = tokens[0]
- b.Size = int(blockSize)
- b.Hints = tokens[2:]
- }
+ if err != nil {return}
+ b.Digest = blockDigest
+ b.Size = int(blockSize)
+ b.Hints = tokens[2:]
}
return
}
diff --git a/sdk/go/manifest/manifest_test.go b/sdk/go/manifest/manifest_test.go
index 7a0a641..f8641ce 100644
--- a/sdk/go/manifest/manifest_test.go
+++ b/sdk/go/manifest/manifest_test.go
@@ -1,6 +1,7 @@
package manifest
import (
+ "git.curoverse.com/arvados.git/sdk/go/blockdigest"
"io/ioutil"
"runtime"
"testing"
@@ -119,7 +120,7 @@ func TestParseBlockLocatorSimple(t *testing.T) {
if err != nil {
t.Fatalf("Unexpected error parsing block locator: %v", err)
}
- expectBlockLocator(t, b, BlockLocator{Digest: "365f83f5f808896ec834c8b595288735",
+ expectBlockLocator(t, b, BlockLocator{Digest: blockdigest.AssertFromString("365f83f5f808896ec834c8b595288735"),
Size: 2310,
Hints: []string{"K at qr1hi",
"Af0c9a66381f3b028677411926f0be1c6282fe67c at 542b5ddf"}})
@@ -158,7 +159,7 @@ func TestBlockIterLongManifest(t *testing.T) {
firstBlock := <-blockChannel
expectBlockLocator(t,
firstBlock,
- BlockLocator{Digest: "b746e3d2104645f2f64cd3cc69dd895d",
+ BlockLocator{Digest: blockdigest.AssertFromString("b746e3d2104645f2f64cd3cc69dd895d"),
Size: 15693477,
Hints: []string{"E2866e643690156651c03d876e638e674dcd79475 at 5441920c"}})
blocksRead := 1
@@ -171,7 +172,7 @@ func TestBlockIterLongManifest(t *testing.T) {
expectBlockLocator(t,
lastBlock,
- BlockLocator{Digest: "f9ce82f59e5908d2d70e18df9679b469",
+ BlockLocator{Digest: blockdigest.AssertFromString("f9ce82f59e5908d2d70e18df9679b469"),
Size: 31367794,
Hints: []string{"E53f903684239bcc114f7bf8ff9bd6089f33058db at 5441920c"}})
}
commit 25d58aaf041ac109ff76db5168c193272958d454
Author: mishaz <misha at curoverse.com>
Date: Tue Dec 23 23:55:12 2014 +0000
Added blockdigest class to store digests more efficiently. This has the nice side effect of reducing how many string slices we use from the SDK, so the large string can get garbage collected once we remove other usages.
diff --git a/sdk/go/blockdigest/blockdigest.go b/sdk/go/blockdigest/blockdigest.go
new file mode 100644
index 0000000..5225af6
--- /dev/null
+++ b/sdk/go/blockdigest/blockdigest.go
@@ -0,0 +1,45 @@
+/* Stores a Block Locator Digest compactly. Can be used as a map key. */
+
+package blockdigest
+
+import (
+ "fmt"
+ "log"
+ "strconv"
+)
+
+// Stores a Block Locator Digest compactly, up to 128 bits.
+// Can be used as a map key.
+type BlockDigest struct {
+ h uint64
+ l uint64
+}
+
+func (d *BlockDigest) ToString() (s string) {
+ return fmt.Sprintf("%016x%016x", d.h, d.l)
+}
+
+// Will create a new BlockDigest unless an error is encountered.
+func FromString(s string) (dig BlockDigest, err error) {
+ if len(s) != 32 {
+ err = fmt.Errorf("Block digest should be exactly 32 characters but this one is %d: %s", len(s), s)
+ return
+ }
+
+ var d BlockDigest
+ d.h, err = strconv.ParseUint(s[:16], 16, 64)
+ if err != nil {return}
+ d.l, err = strconv.ParseUint(s[16:], 16, 64)
+ if err != nil {return}
+ dig = d
+ return
+}
+
+// Will fatal with the error if an error is encountered
+func AssertFromString(s string) BlockDigest {
+ d, err := FromString(s)
+ if err != nil {
+ log.Fatalf("Error creating BlockDigest from %s: %v", s, err)
+ }
+ return d
+}
diff --git a/sdk/go/blockdigest/blockdigest_test.go b/sdk/go/blockdigest/blockdigest_test.go
new file mode 100644
index 0000000..9081bb8
--- /dev/null
+++ b/sdk/go/blockdigest/blockdigest_test.go
@@ -0,0 +1,45 @@
+package blockdigest
+
+import (
+ "strings"
+ "testing"
+)
+
+func expectValidDigestString(t *testing.T, s string) {
+ bd, err := FromString(s)
+ if err != nil {
+ t.Fatalf("Expected %s to produce a valid BlockDigest but instead got error: %v", s, err)
+ }
+
+ expected := strings.ToLower(s)
+
+ if expected != bd.ToString() {
+ t.Fatalf("Expected %s to be returned by FromString(%s).ToString() but instead we received %s", expected, s, bd.ToString())
+ }
+}
+
+func expectInvalidDigestString(t *testing.T, s string) {
+ _, err := FromString(s)
+ if err == nil {
+ t.Fatalf("Expected %s to be an invalid BlockDigest, but did not receive an error", s)
+ }
+}
+
+func TestValidDigestStrings(t *testing.T) {
+ expectValidDigestString(t, "01234567890123456789abcdefabcdef")
+ expectValidDigestString(t, "01234567890123456789ABCDEFABCDEF")
+ expectValidDigestString(t, "01234567890123456789AbCdEfaBcDeF")
+}
+
+func TestInvalidDigestStrings(t *testing.T) {
+ expectInvalidDigestString(t, "01234567890123456789abcdefabcdeg")
+ expectInvalidDigestString(t, "01234567890123456789abcdefabcde")
+ expectInvalidDigestString(t, "01234567890123456789abcdefabcdefa")
+ expectInvalidDigestString(t, "g1234567890123456789abcdefabcdef")
+}
+
+func TestBlockDigestWorksAsMapKey(t *testing.T) {
+ m := make(map[BlockDigest]int)
+ bd := AssertFromString("01234567890123456789abcdefabcdef")
+ m[bd] = 5
+}
commit fb62ab318be2202b9d403e65d6dc86a9d7e72a3a
Author: mishaz <misha at curoverse.com>
Date: Tue Dec 23 19:33:07 2014 +0000
Long overdue checkin of data manager. Current code runs, but uses way too much memory and eventually crashes. This checkin includes heap profiling to track down memory usage.
diff --git a/sdk/go/manifest/manifest_test.go b/sdk/go/manifest/manifest_test.go
index b108870..7a0a641 100644
--- a/sdk/go/manifest/manifest_test.go
+++ b/sdk/go/manifest/manifest_test.go
@@ -115,7 +115,7 @@ func TestParseManifestLineSimple(t *testing.T) {
}
func TestParseBlockLocatorSimple(t *testing.T) {
- b, err := parseBlockLocator("365f83f5f808896ec834c8b595288735+2310+K at qr1hi+Af0c9a66381f3b028677411926f0be1c6282fe67c@542b5ddf")
+ b, err := ParseBlockLocator("365f83f5f808896ec834c8b595288735+2310+K at qr1hi+Af0c9a66381f3b028677411926f0be1c6282fe67c@542b5ddf")
if err != nil {
t.Fatalf("Unexpected error parsing block locator: %v", err)
}
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index 07e8b7e..159b568 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -3,10 +3,18 @@
package collection
import (
+ "flag"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/manifest"
- "git.curoverse.com/arvados.git/sdk/go/util"
+ //"git.curoverse.com/arvados.git/sdk/go/util"
"log"
+ "os"
+ "runtime/pprof"
+)
+
+var (
+ heap_profile_filename string
+ heap_profile *os.File
)
type Collection struct {
@@ -24,14 +32,14 @@ type ReadCollections struct {
type GetCollectionsParams struct {
Client arvadosclient.ArvadosClient
- Limit int
- LogEveryNthCollectionProcessed int // 0 means don't report any
+ BatchSize int
}
type SdkCollectionInfo struct {
Uuid string `json:"uuid"`
OwnerUuid string `json:"owner_uuid"`
Redundancy int `json:"redundancy"`
+ ModifiedAt string `json:"modified_at"`
ManifestText string `json:"manifest_text"`
}
@@ -40,14 +48,21 @@ type SdkCollectionList struct {
Items []SdkCollectionInfo `json:"items"`
}
-// Methods to implement util.SdkListResponse Interface
-func (s SdkCollectionList) NumItemsAvailable() (numAvailable int, err error) {
- return s.ItemsAvailable, nil
+func init() {
+ flag.StringVar(&heap_profile_filename,
+ "heap-profile",
+ "",
+ "File to write the heap profiles to.")
}
-func (s SdkCollectionList) NumItemsContained() (numContained int, err error) {
- return len(s.Items), nil
-}
+// // Methods to implement util.SdkListResponse Interface
+// func (s SdkCollectionList) NumItemsAvailable() (numAvailable int, err error) {
+// return s.ItemsAvailable, nil
+// }
+
+// func (s SdkCollectionList) NumItemsContained() (numContained int, err error) {
+// return len(s.Items), nil
+// }
func GetCollections(params GetCollectionsParams) (results ReadCollections) {
if ¶ms.Client == nil {
@@ -55,46 +70,108 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
"contain a valid ArvadosClient, but instead it is nil.")
}
+ // TODO(misha): move this code somewhere better and make sure it's
+ // only run once
+ if heap_profile_filename != "" {
+ var err error
+ heap_profile, err = os.Create(heap_profile_filename)
+ if err != nil {
+ log.Fatal(err)
+ }
+ }
+
+
+
+
+
fieldsWanted := []string{"manifest_text",
"owner_uuid",
"uuid",
// TODO(misha): Start using the redundancy field.
- "redundancy"}
-
- sdkParams := arvadosclient.Dict{"select": fieldsWanted}
- if params.Limit > 0 {
- sdkParams["limit"] = params.Limit
- }
-
- var collections SdkCollectionList
- err := params.Client.List("collections", sdkParams, &collections)
- if err != nil {
- log.Fatalf("error querying collections: %v", err)
+ "redundancy",
+ "modified_at"}
+
+ sdkParams := arvadosclient.Dict{
+ "select": fieldsWanted,
+ "order": []string{"modified_at ASC"},
+ "filters": [][]string{[]string{"modified_at", ">=", "1900-01-01T00:00:00Z"}}}
+ // MISHA UNDO THIS TEMPORARY HACK TO FIND BUG!
+ //"filters": [][]string{[]string{"modified_at", ">=", "2014-11-05T20:44:50Z"}}}
+
+ if params.BatchSize > 0 {
+ sdkParams["limit"] = params.BatchSize
}
- {
- var numReceived, numAvailable int
- results.ReadAllCollections, numReceived, numAvailable =
- util.ContainsAllAvailableItems(collections)
+ // MISHA UNDO THIS TEMPORARY HACK TO FIND BUG!
+ sdkParams["limit"] = 50
+
+ // {
+ // var numReceived, numAvailable int
+ // results.ReadAllCollections, numReceived, numAvailable =
+ // util.ContainsAllAvailableItems(collections)
+
+ // if (!results.ReadAllCollections) {
+ // log.Printf("ERROR: Did not receive all collections.")
+ // }
+ // log.Printf("Received %d of %d available collections.",
+ // numReceived,
+ // numAvailable)
+ // }
+
+ initialNumberOfCollectionsAvailable := NumberCollectionsAvailable(params.Client)
+ // Include a 1% margin for collections added while we're reading so
+ // that we don't have to grow the map in most cases.
+ maxExpectedCollections := int(
+ float64(initialNumberOfCollectionsAvailable) * 1.01)
+ results.UuidToCollection = make(map[string]Collection, maxExpectedCollections)
+
+ previousTotalCollections := -1
+ for len(results.UuidToCollection) > previousTotalCollections {
+ // We're still finding new collections
+ log.Printf("previous, current: %d %d", previousTotalCollections, len(results.UuidToCollection))
+
+ // update count
+ previousTotalCollections = len(results.UuidToCollection)
+
+ // Write the heap profile for examining memory usage
+ {
+ err := pprof.WriteHeapProfile(heap_profile)
+ if err != nil {
+ log.Fatal(err)
+ }
+ }
- if (!results.ReadAllCollections) {
- log.Printf("ERROR: Did not receive all collections.")
+ // Get next batch of collections.
+ var collections SdkCollectionList
+ log.Printf("Running with SDK Params: %v", sdkParams)
+ err := params.Client.List("collections", sdkParams, &collections)
+ if err != nil {
+ log.Fatalf("error querying collections: %+v", err)
}
- log.Printf("Received %d of %d available collections.",
- numReceived,
- numAvailable)
+
+ // Process collection and update our date filter.
+ sdkParams["filters"].([][]string)[0][2] = ProcessCollections(collections.Items, results.UuidToCollection)
+ log.Printf("Latest date seen %s", sdkParams["filters"].([][]string)[0][2])
}
+ log.Printf("previous, current: %d %d", previousTotalCollections, len(results.UuidToCollection))
- results.UuidToCollection = make(map[string]Collection)
- for i, sdkCollection := range collections.Items {
- count := i + 1
- if m := params.LogEveryNthCollectionProcessed; m >0 && (count % m) == 0 {
- log.Printf("Processing collection #%d", count)
- }
+ return
+}
+
+
+func ProcessCollections(receivedCollections []SdkCollectionInfo,
+ uuidToCollection map[string]Collection) (latestModificationDate string) {
+ for _, sdkCollection := range receivedCollections {
collection := Collection{Uuid: sdkCollection.Uuid,
OwnerUuid: sdkCollection.OwnerUuid,
ReplicationLevel: sdkCollection.Redundancy,
BlockDigestToSize: make(map[string]int)}
+ // log.Printf("Seeing modification date, owner_uuid: %s %s",
+ // sdkCollection.ModifiedAt,
+ // sdkCollection.OwnerUuid)
+ if sdkCollection.ModifiedAt > latestModificationDate {
+ latestModificationDate = sdkCollection.ModifiedAt
+ }
manifest := manifest.Manifest{sdkCollection.ManifestText}
blockChannel := manifest.BlockIterWithDuplicates()
for block := range blockChannel {
@@ -113,8 +190,20 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
for _, size := range collection.BlockDigestToSize {
collection.TotalSize += size
}
- results.UuidToCollection[collection.Uuid] = collection
+ uuidToCollection[collection.Uuid] = collection
}
return
}
+
+
+func NumberCollectionsAvailable(client arvadosclient.ArvadosClient) (int) {
+ var collections SdkCollectionList
+ sdkParams := arvadosclient.Dict{"limit": 0}
+ err := client.List("collections", sdkParams, &collections)
+ if err != nil {
+ log.Fatalf("error querying collections for items available: %v", err)
+ }
+
+ return collections.ItemsAvailable
+}
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index cd3e010..6393787 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -7,7 +7,7 @@ import (
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
"git.curoverse.com/arvados.git/sdk/go/util"
"git.curoverse.com/arvados.git/services/datamanager/collection"
- "git.curoverse.com/arvados.git/services/datamanager/keep"
+// "git.curoverse.com/arvados.git/services/datamanager/keep"
"log"
)
@@ -29,9 +29,9 @@ func main() {
readCollections := collection.GetCollections(
collection.GetCollectionsParams{
- Client: arv, Limit: 50, LogEveryNthCollectionProcessed: 10})
+ Client: arv, BatchSize: 500})
- log.Printf("Read Collections: %v", readCollections)
+ //log.Printf("Read Collections: %v", readCollections)
UserUsage := ComputeSizeOfOwnedCollections(readCollections)
log.Printf("Uuid to Size used: %v", UserUsage)
@@ -46,10 +46,10 @@ func main() {
log.Printf("Read and processed %d collections",
len(readCollections.UuidToCollection))
- readServers := keep.GetKeepServers(
- keep.GetKeepServersParams{Client: arv, Limit: 1000})
+ // readServers := keep.GetKeepServers(
+ // keep.GetKeepServersParams{Client: arv, Limit: 1000})
- log.Printf("Returned %d keep disks", len(readServers.AddressToContents))
+ // log.Printf("Returned %d keep disks", len(readServers.AddressToContents))
}
func ComputeSizeOfOwnedCollections(readCollections collection.ReadCollections) (
commit af550e54c034136e5fcb187e7f81e3d82170f9c8
Author: mishaz <misha at curoverse.com>
Date: Sat Nov 22 00:57:40 2014 +0000
Added reporting of disk usage. This is the Collection Storage of each user as described here: https://arvados.org/projects/arvados/wiki/Data_Manager_Design_Doc#Reports-Produced
But it does not include the size of projects owned by the user (projects and subprojects are each reported as their own users)
Report is just logged to screen for now.
diff --git a/services/datamanager/collection/collection.go b/services/datamanager/collection/collection.go
index bf76dd8..07e8b7e 100644
--- a/services/datamanager/collection/collection.go
+++ b/services/datamanager/collection/collection.go
@@ -14,6 +14,7 @@ type Collection struct {
OwnerUuid string
ReplicationLevel int
BlockDigestToSize map[string]int
+ TotalSize int
}
type ReadCollections struct {
@@ -108,6 +109,10 @@ func GetCollections(params GetCollectionsParams) (results ReadCollections) {
}
collection.BlockDigestToSize[block.Digest] = block.Size
}
+ collection.TotalSize = 0
+ for _, size := range collection.BlockDigestToSize {
+ collection.TotalSize += size
+ }
results.UuidToCollection[collection.Uuid] = collection
}
diff --git a/services/datamanager/datamanager.go b/services/datamanager/datamanager.go
index 64073af..cd3e010 100644
--- a/services/datamanager/datamanager.go
+++ b/services/datamanager/datamanager.go
@@ -25,12 +25,17 @@ func main() {
log.Fatalf("Current user is not an admin. Datamanager can only be run by admins.")
}
+ // TODO(misha): Read Collections and Keep Contents concurrently as goroutines.
+
readCollections := collection.GetCollections(
collection.GetCollectionsParams{
Client: arv, Limit: 50, LogEveryNthCollectionProcessed: 10})
log.Printf("Read Collections: %v", readCollections)
+ UserUsage := ComputeSizeOfOwnedCollections(readCollections)
+ log.Printf("Uuid to Size used: %v", UserUsage)
+
// TODO(misha): Add a "readonly" flag. If we're in readonly mode,
// lots of behaviors can become warnings (and obviously we can't
// write anything).
@@ -46,3 +51,12 @@ func main() {
log.Printf("Returned %d keep disks", len(readServers.AddressToContents))
}
+
+func ComputeSizeOfOwnedCollections(readCollections collection.ReadCollections) (
+ results map[string]int) {
+ results = make(map[string]int)
+ for _, coll := range readCollections.UuidToCollection {
+ results[coll.OwnerUuid] = results[coll.OwnerUuid] + coll.TotalSize
+ }
+ return
+}
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index e3d3387..e600c4a 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -196,7 +196,7 @@ func GetServerContents(keepServer ServerAddress,
}
if storedBlock, ok := response.Contents.BlockDigestToInfo[blockInfo.Digest]; ok {
- // This server is reporting multiple copies of the same block.
+ // This server returned multiple lines containing the same block digest.
numDuplicates += 1
if storedBlock.Size != blockInfo.Size {
numSizeDisagreements += 1
commit 9684e729ae3ebf438fd2c1c440bb0d8c45ca25af
Author: mishaz <misha at curoverse.com>
Date: Thu Oct 16 20:57:06 2014 +0000
Started reading index from keep servers.
Added lots of code to handle unexpected results from keep server.
diff --git a/sdk/go/manifest/manifest.go b/sdk/go/manifest/manifest.go
index d3316ff..d7b5eb5 100644
--- a/sdk/go/manifest/manifest.go
+++ b/sdk/go/manifest/manifest.go
@@ -31,7 +31,7 @@ type ManifestLine struct {
Files []string
}
-func parseBlockLocator(s string) (b BlockLocator, err error) {
+func ParseBlockLocator(s string) (b BlockLocator, err error) {
if !LocatorPattern.MatchString(s) {
err = fmt.Errorf("String \"%s\" does not match BlockLocator pattern " +
"\"%s\".",
@@ -98,7 +98,7 @@ func (m *Manifest) BlockIterWithDuplicates() <-chan BlockLocator {
go func(lineChannel <-chan ManifestLine) {
for m := range lineChannel {
for _, block := range m.Blocks {
- if b, err := parseBlockLocator(block); err == nil {
+ if b, err := ParseBlockLocator(block); err == nil {
blockChannel <- b
} else {
log.Printf("ERROR: Failed to parse block: %v", err)
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index f3706d8..e3d3387 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -8,10 +8,12 @@ import (
"fmt"
//"git.curoverse.com/arvados.git/sdk/go/keepclient"
"git.curoverse.com/arvados.git/sdk/go/arvadosclient"
+ "git.curoverse.com/arvados.git/sdk/go/manifest"
"git.curoverse.com/arvados.git/sdk/go/util"
"log"
"io/ioutil"
"net/http"
+ "strconv"
"strings"
"sync"
)
@@ -21,8 +23,19 @@ type ServerAddress struct {
Port int `json:"service_port"`
}
+type BlockInfo struct {
+ Digest string
+ Size int
+ Mtime int // TODO(misha): Replace this with a timestamp.
+}
+
type ServerContents struct {
- BlockDigestToSize map[string]int
+ BlockDigestToInfo map[string]BlockInfo
+}
+
+type ServerResponse struct {
+ Address ServerAddress
+ Contents ServerContents
}
type ReadServers struct {
@@ -96,7 +109,8 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
}
var sdkResponse KeepServiceList
- err := params.Client.List("keep_services", sdkParams, &sdkResponse)
+ err := params.Client.Call("GET", "keep_services", "", "accessible", sdkParams, &sdkResponse)
+
if err != nil {
log.Fatalf("Error requesting keep disks from API server: %v", err)
}
@@ -118,45 +132,129 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
// This is safe for concurrent use
client := http.Client{}
-
- // TODO(misha): Do these in parallel
+
+ // Send off all the index requests concurrently
+ responseChan := make(chan ServerResponse)
for _, keepServer := range sdkResponse.KeepServers {
- url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
- log.Println("About to fetch keep server contents from " + url)
+ go GetServerContents(keepServer, client, responseChan)
+ }
- req, err := http.NewRequest("GET", url, nil)
- if err != nil {
- log.Fatalf("Error building http request for %s: %v", url, err)
- }
+ results.AddressToContents = make(map[ServerAddress]ServerContents)
+
+ // Read all the responses
+ for i := range sdkResponse.KeepServers {
+ _ = i // Here to prevent go from complaining.
+ response := <- responseChan
+ log.Printf("Received channel response from %v containing %d files",
+ response.Address,
+ len(response.Contents.BlockDigestToInfo))
+ results.AddressToContents[response.Address] = response.Contents
+ }
+ return
+}
+
+// TODO(misha): Break this function apart into smaller, easier to
+// understand functions.
+func GetServerContents(keepServer ServerAddress,
+ client http.Client,
+ responseChan chan<- ServerResponse) () {
+ // Create and send request.
+ url := fmt.Sprintf("http://%s:%d/index", keepServer.Host, keepServer.Port)
+ log.Println("About to fetch keep server contents from " + url)
+
+ req, err := http.NewRequest("GET", url, nil)
+ if err != nil {
+ log.Fatalf("Error building http request for %s: %v", url, err)
+ }
- req.Header.Add("Authorization",
- fmt.Sprintf("OAuth2 %s", getDataManagerToken()))
+ req.Header.Add("Authorization",
+ fmt.Sprintf("OAuth2 %s", getDataManagerToken()))
- resp, err := client.Do(req)
+ resp, err := client.Do(req)
+ if err != nil {
+ log.Fatalf("Error fetching %s: %v", url, err)
+ }
+
+ // Process response.
+ if resp.StatusCode != 200 {
+ log.Fatalf("Received error code %d in response to request for %s: %s",
+ resp.StatusCode, url, resp.Status)
+ }
+
+ response := ServerResponse{}
+ response.Address = keepServer
+ response.Contents.BlockDigestToInfo = make(map[string]BlockInfo)
+ scanner := bufio.NewScanner(resp.Body)
+ numLines, numDuplicates, numSizeDisagreements := 0, 0, 0
+ for scanner.Scan() {
+ numLines++
+ blockInfo, err := parseBlockInfoFromIndexLine(scanner.Text())
if err != nil {
- log.Fatalf("Error fetching %s: %v", url, err)
+ log.Fatalf("Error parsing BlockInfo from index line received from %s: %v",
+ url,
+ err)
}
- if resp.StatusCode != 200 {
- log.Printf("%v", req)
- log.Fatalf("Received error code %d in response to request for %s: %s",
- resp.StatusCode, url, resp.Status)
- }
- scanner := bufio.NewScanner(resp.Body)
- numLines := 0
- for scanner.Scan() {
- numLines++
- if numLines == 1 {
- log.Printf("First line from %s is %s", url, scanner.Text())
+ if storedBlock, ok := response.Contents.BlockDigestToInfo[blockInfo.Digest]; ok {
+ // This server is reporting multiple copies of the same block.
+ numDuplicates += 1
+ if storedBlock.Size != blockInfo.Size {
+ numSizeDisagreements += 1
+ // TODO(misha): Consider failing here.
+ log.Printf("Saw different sizes for the same block on %s: %v %v",
+ url,
+ storedBlock,
+ blockInfo)
+ }
+ // Keep the block that is bigger, or the block that's newer in
+ // the case of a size tie.
+ if storedBlock.Size < blockInfo.Size ||
+ (storedBlock.Size == blockInfo.Size &&
+ storedBlock.Mtime < blockInfo.Mtime) {
+ response.Contents.BlockDigestToInfo[blockInfo.Digest] = blockInfo
}
- }
- if err := scanner.Err(); err != nil {
- log.Fatalf("Received error scanning response from %s: %v", url, err)
} else {
- log.Printf("Read %d lines from %s.", numLines, url)
+ response.Contents.BlockDigestToInfo[blockInfo.Digest] = blockInfo
}
- resp.Body.Close()
+ }
+ if err := scanner.Err(); err != nil {
+ log.Fatalf("Received error scanning response from %s: %v", url, err)
+ } else {
+ log.Printf("%s contained %d lines with %d duplicates with " +
+ "%d size disagreements",
+ url,
+ numLines,
+ numDuplicates,
+ numSizeDisagreements)
+ }
+ resp.Body.Close()
+ responseChan <- response
+}
+
+func parseBlockInfoFromIndexLine(indexLine string) (blockInfo BlockInfo, err error) {
+ tokens := strings.Fields(indexLine)
+ if len(tokens) != 2 {
+ err = fmt.Errorf("Expected 2 tokens per line but received a " +
+ "line containing %v instead.",
+ tokens)
+ }
+
+ var locator manifest.BlockLocator
+ if locator, err = manifest.ParseBlockLocator(tokens[0]); err != nil {
+ return
+ }
+ if len(locator.Hints) > 0 {
+ err = fmt.Errorf("Block locator in index line should not contain hints " +
+ "but it does: %v",
+ locator)
+ return
}
+ blockInfo.Mtime, err = strconv.Atoi(tokens[1])
+ if err != nil {
+ return
+ }
+ blockInfo.Digest = locator.Digest
+ blockInfo.Size = locator.Size
return
}
commit a224de262c6e94c592eb8c9a2f909954d24b7c9c
Author: mishaz <misha at curoverse.com>
Date: Wed Oct 15 20:53:53 2014 +0000
Started reading response from keep server.
diff --git a/services/datamanager/keep/keep.go b/services/datamanager/keep/keep.go
index 507e5f6..f3706d8 100644
--- a/services/datamanager/keep/keep.go
+++ b/services/datamanager/keep/keep.go
@@ -3,6 +3,7 @@
package keep
import (
+ "bufio"
"flag"
"fmt"
//"git.curoverse.com/arvados.git/sdk/go/keepclient"
@@ -141,6 +142,20 @@ func GetKeepServers(params GetKeepServersParams) (results ReadServers) {
log.Fatalf("Received error code %d in response to request for %s: %s",
resp.StatusCode, url, resp.Status)
}
+ scanner := bufio.NewScanner(resp.Body)
+ numLines := 0
+ for scanner.Scan() {
+ numLines++
+ if numLines == 1 {
+ log.Printf("First line from %s is %s", url, scanner.Text())
+ }
+ }
+ if err := scanner.Err(); err != nil {
+ log.Fatalf("Received error scanning response from %s: %v", url, err)
+ } else {
+ log.Printf("Read %d lines from %s.", numLines, url)
+ }
+ resp.Body.Close()
}
return
commit 63cb5c235ccacdc1665a89560bc8c16fcbefd8d6
Merge: 74dba22 61790a8
Author: Tom Clegg <tom at curoverse.com>
Date: Fri Feb 13 16:22:55 2015 -0500
Merge branch 'master' of git.curoverse.com:arvados into 3408-production-datamanager
-----------------------------------------------------------------------
hooks/post-receive
--
More information about the arvados-commits
mailing list