x/ref/services: convert more services to context based logging.
Change-Id: I156933edb15b10f9b8f238188a1cc3caccfd0780
diff --git a/services/wspr/browsprd/main_nacl.go b/services/wspr/browsprd/main_nacl.go
index 4d07423..7e0b2bd 100644
--- a/services/wspr/browsprd/main_nacl.go
+++ b/services/wspr/browsprd/main_nacl.go
@@ -15,9 +15,11 @@
"runtime/ppapi"
"v.io/v23"
+ "v.io/v23/logging"
"v.io/v23/security"
"v.io/v23/vdl"
"v.io/x/lib/vlog"
+ "v.io/x/ref/internal/logger"
vsecurity "v.io/x/ref/lib/security"
_ "v.io/x/ref/runtime/factories/chrome"
"v.io/x/ref/runtime/internal/lib/websocket"
@@ -39,13 +41,14 @@
fs ppapi.FileSystem
browspr *browspr.Browspr
channel *channel_nacl.Channel
+ logger logging.Logger
}
var _ ppapi.InstanceHandlers = (*browsprInstance)(nil)
func newBrowsprInstance(inst ppapi.Instance) ppapi.InstanceHandlers {
runtime.GOMAXPROCS(4)
- browsprInst := &browsprInstance{Instance: inst}
+ browsprInst := &browsprInstance{Instance: inst, logger: logger.Global()}
browsprInst.initFileSystem()
// Give the websocket interface the ppapi instance.
@@ -80,15 +83,15 @@
const browsprDir = "/browspr/data"
func (inst *browsprInstance) loadKeyFromStorage(browsprKeyFile string) (*ecdsa.PrivateKey, error) {
- vlog.VI(1).Infof("Attempting to read key from file %v", browsprKeyFile)
+ inst.logger.VI(1).Infof("Attempting to read key from file %v", browsprKeyFile)
rFile, err := inst.fs.Open(browsprKeyFile)
if err != nil {
- vlog.VI(1).Infof("Key not found in file %v", browsprKeyFile)
+ inst.logger.VI(1).Infof("Key not found in file %v", browsprKeyFile)
return nil, err
}
- vlog.VI(1).Infof("Attempting to load cached browspr ecdsaPrivateKey in file %v", browsprKeyFile)
+ inst.logger.VI(1).Infof("Attempting to load cached browspr ecdsaPrivateKey in file %v", browsprKeyFile)
defer rFile.Release()
key, err := vsecurity.LoadPEMKey(rFile, nil)
if err != nil {
@@ -107,10 +110,10 @@
if ecdsaKey, err := inst.loadKeyFromStorage(browsprKeyFile); err == nil {
return ecdsaKey, nil
} else {
- vlog.VI(1).Infof("inst.loadKeyFromStorage(%v) failed: %v", browsprKeyFile, err)
+ inst.logger.VI(1).Infof("inst.loadKeyFromStorage(%v) failed: %v", browsprKeyFile, err)
}
- vlog.VI(1).Infof("Generating new browspr ecdsaPrivateKey")
+ inst.logger.VI(1).Infof("Generating new browspr ecdsaPrivateKey")
// Generate new keys and store them.
var ecdsaKey *ecdsa.PrivateKey
@@ -163,7 +166,7 @@
principal, err := inst.newPrincipal(ecdsaKey, blessingRootsData, blessingRootsSig, blessingStoreData, blessingStoreSig)
if err != nil {
- vlog.VI(1).Infof("inst.newPrincipal(%v, %v, %v, %v, %v) failed: %v", ecdsaKey, blessingRootsData, blessingRootsSig, blessingStoreData, blessingStoreSig)
+ inst.logger.VI(1).Infof("inst.newPrincipal(%v, %v, %v, %v, %v) failed: %v", ecdsaKey, blessingRootsData, blessingRootsSig, blessingStoreData, blessingStoreSig)
// Delete the files and try again.
for _, file := range []string{blessingRootsData, blessingRootsSig, blessingStoreData, blessingStoreSig} {
@@ -184,7 +187,7 @@
}
func (inst *browsprInstance) HandleStartMessage(val *vdl.Value) (*vdl.Value, error) {
- vlog.VI(1).Info("Starting Browspr")
+ inst.logger.VI(1).Info("Starting Browspr")
var msg browspr.StartMessage
if err := vdl.Convert(&msg, val); err != nil {
return nil, fmt.Errorf("HandleStartMessage did not receive StartMessage, received: %v, %v", val, err)
@@ -209,10 +212,10 @@
return nil, fmt.Errorf("invalid IdentitydBlessingRoot: Names is empty")
}
- vlog.VI(1).Infof("Using blessing roots for identity with key %v and names %v", msg.IdentitydBlessingRoot.PublicKey, msg.IdentitydBlessingRoot.Names)
+ inst.logger.VI(1).Infof("Using blessing roots for identity with key %v and names %v", msg.IdentitydBlessingRoot.PublicKey, msg.IdentitydBlessingRoot.Names)
key, err := decodeAndUnmarshalPublicKey(msg.IdentitydBlessingRoot.PublicKey)
if err != nil {
- vlog.Fatalf("decodeAndUnmarshalPublicKey(%v) failed: %v", msg.IdentitydBlessingRoot.PublicKey, err)
+ inst.logger.Fatalf("decodeAndUnmarshalPublicKey(%v) failed: %v", msg.IdentitydBlessingRoot.PublicKey, err)
}
for _, name := range msg.IdentitydBlessingRoot.Names {
@@ -227,7 +230,7 @@
}
}
} else {
- vlog.VI(1).Infof("IdentitydBlessingRoot.PublicKey is empty. Will allow browspr blessing to be shareable with all principals.")
+ inst.logger.VI(1).Infof("IdentitydBlessingRoot.PublicKey is empty. Will allow browspr blessing to be shareable with all principals.")
// Set our blessing as shareable with all peers.
if _, err := principal.BlessingStore().Set(blessing, security.AllPrincipals); err != nil {
return nil, fmt.Errorf("principal.BlessingStore().Set(%v, %v) failed: %v", blessing, security.AllPrincipals, err)
@@ -243,8 +246,11 @@
return nil, err
}
+ // TODO(cnicolaou): provide a means of configuring logging that
+ // doesn't depend on vlog - e.g. ConfigureFromArgs(args []string) to
+ // pair with ConfigureFromFlags(). See v.io/i/556
// Configure logger with level and module from start message.
- vlog.VI(1).Infof("Configuring vlog with v=%v, modulesSpec=%v", msg.LogLevel, msg.LogModule)
+ inst.logger.VI(1).Infof("Configuring vlog with v=%v, modulesSpec=%v", msg.LogLevel, msg.LogModule)
moduleSpec := vlog.ModuleSpec{}
moduleSpec.Set(msg.LogModule)
if err := vlog.Log.Configure(vlog.OverridePriorConfiguration(true), vlog.Level(msg.LogLevel), moduleSpec); err != nil {
@@ -259,7 +265,7 @@
listenSpec := v23.GetListenSpec(ctx)
listenSpec.Proxy = msg.Proxy
- vlog.VI(1).Infof("Starting browspr with config: proxy=%q mounttable=%q identityd=%q identitydBlessingRoot=%q ", msg.Proxy, msg.NamespaceRoot, msg.Identityd, msg.IdentitydBlessingRoot)
+ inst.logger.VI(1).Infof("Starting browspr with config: proxy=%q mounttable=%q identityd=%q identitydBlessingRoot=%q ", msg.Proxy, msg.NamespaceRoot, msg.Identityd, msg.IdentitydBlessingRoot)
inst.browspr = browspr.NewBrowspr(ctx,
inst.BrowsprOutgoingPostMessage,
&listenSpec,
@@ -305,7 +311,7 @@
return fmt.Errorf("Invalid message: %v", err)
}
- vlog.VI(1).Infof("Calling browspr's HandleMessage: instanceId %d origin %s message %s", instanceId, origin, msg)
+ inst.logger.VI(1).Infof("Calling browspr's HandleMessage: instanceId %d origin %s message %s", instanceId, origin, msg)
if err := inst.browspr.HandleMessage(instanceId, origin, msg); err != nil {
return fmt.Errorf("Error while handling message in browspr: %v", err)
}
@@ -329,23 +335,23 @@
// HandleBrowsprRpc handles two-way rpc messages of the type "browsprRpc"
// sending them to the channel's handler.
func (inst *browsprInstance) HandleBrowsprRpc(instanceId int32, origin string, message ppapi.Var) error {
- vlog.VI(1).Infof("Got to HandleBrowsprRpc: instanceId: %d origin %s", instanceId, origin)
+ inst.logger.VI(1).Infof("Got to HandleBrowsprRpc: instanceId: %d origin %s", instanceId, origin)
inst.channel.HandleMessage(message)
return nil
}
// handleGoError handles error returned by go code.
func (inst *browsprInstance) handleGoError(err error) {
- vlog.VI(2).Info(err)
+ inst.logger.VI(2).Info(err)
inst.LogString(ppapi.PP_LOGLEVEL_ERROR, fmt.Sprintf("Error in go code: %v", err.Error()))
- vlog.Error(err)
+ inst.logger.Error(err)
}
// HandleMessage receives messages from Javascript and uses them to perform actions.
// A message is of the form {"type": "typeName", "body": { stuff here }},
// where the body is passed to the message handler.
func (inst *browsprInstance) HandleMessage(message ppapi.Var) {
- vlog.VI(2).Infof("Got to HandleMessage")
+ inst.logger.VI(2).Infof("Got to HandleMessage")
instanceId, err := message.LookupIntValuedKey("instanceId")
if err != nil {
inst.handleGoError(err)
@@ -383,38 +389,38 @@
}
func (inst browsprInstance) DidCreate(args map[string]string) bool {
- vlog.VI(2).Infof("Got to DidCreate")
+ inst.logger.VI(2).Infof("Got to DidCreate")
return true
}
-func (*browsprInstance) DidDestroy() {
- vlog.VI(2).Infof("Got to DidDestroy()")
+func (inst *browsprInstance) DidDestroy() {
+ inst.logger.VI(2).Infof("Got to DidDestroy()")
}
-func (*browsprInstance) DidChangeView(view ppapi.View) {
- vlog.VI(2).Infof("Got to DidChangeView(%v)", view)
+func (inst *browsprInstance) DidChangeView(view ppapi.View) {
+ inst.logger.VI(2).Infof("Got to DidChangeView(%v)", view)
}
-func (*browsprInstance) DidChangeFocus(has_focus bool) {
- vlog.VI(2).Infof("Got to DidChangeFocus(%v)", has_focus)
+func (inst *browsprInstance) DidChangeFocus(has_focus bool) {
+ inst.logger.VI(2).Infof("Got to DidChangeFocus(%v)", has_focus)
}
-func (*browsprInstance) HandleDocumentLoad(url_loader ppapi.Resource) bool {
- vlog.VI(2).Infof("Got to HandleDocumentLoad(%v)", url_loader)
+func (inst *browsprInstance) HandleDocumentLoad(url_loader ppapi.Resource) bool {
+ inst.logger.VI(2).Infof("Got to HandleDocumentLoad(%v)", url_loader)
return true
}
-func (*browsprInstance) HandleInputEvent(event ppapi.InputEvent) bool {
- vlog.VI(2).Infof("Got to HandleInputEvent(%v)", event)
+func (inst *browsprInstance) HandleInputEvent(event ppapi.InputEvent) bool {
+ inst.logger.VI(2).Infof("Got to HandleInputEvent(%v)", event)
return true
}
-func (*browsprInstance) Graphics3DContextLost() {
- vlog.VI(2).Infof("Got to Graphics3DContextLost()")
+func (inst *browsprInstance) Graphics3DContextLost() {
+ inst.logger.VI(2).Infof("Got to Graphics3DContextLost()")
}
-func (*browsprInstance) MouseLockLost() {
- vlog.VI(2).Infof("Got to MouseLockLost()")
+func (inst *browsprInstance) MouseLockLost() {
+ inst.logger.VI(2).Infof("Got to MouseLockLost()")
}
func varToMessage(v ppapi.Var) (app.Message, error) {
diff --git a/services/wspr/internal/account/account.go b/services/wspr/internal/account/account.go
index 0289534..7d977d6 100644
--- a/services/wspr/internal/account/account.go
+++ b/services/wspr/internal/account/account.go
@@ -14,7 +14,6 @@
"v.io/v23/context"
"v.io/v23/rpc"
"v.io/v23/security"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/principal"
)
@@ -82,7 +81,7 @@
return am.accounts
}
-func (am *AccountManager) AssociateAccount(origin, account string, cavs []Caveat) error {
+func (am *AccountManager) AssociateAccount(ctx *context.T, origin, account string, cavs []Caveat) error {
caveats, expirations, err := constructCaveats(cavs)
if err != nil {
return fmt.Errorf("failed to construct caveats: %v", err)
@@ -91,7 +90,7 @@
if err := am.principalManager.AddOrigin(origin, account, caveats, expirations); err != nil {
return fmt.Errorf("failed to associate account: %v", err)
}
- vlog.VI(1).Infof("Associated origin %v with account %v and cavs %v", origin, account, caveats)
+ ctx.VI(1).Infof("Associated origin %v with account %v and cavs %v", origin, account, caveats)
return nil
}
diff --git a/services/wspr/internal/app/app.go b/services/wspr/internal/app/app.go
index 0d72c34..a504463 100644
--- a/services/wspr/internal/app/app.go
+++ b/services/wspr/internal/app/app.go
@@ -27,7 +27,6 @@
"v.io/v23/verror"
"v.io/v23/vom"
"v.io/v23/vtrace"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/lib"
"v.io/x/ref/services/wspr/internal/namespace"
"v.io/x/ref/services/wspr/internal/principal"
@@ -317,8 +316,8 @@
}
// Cleanup cleans up any outstanding rpcs.
-func (c *Controller) Cleanup() {
- vlog.VI(0).Info("Cleaning up controller")
+func (c *Controller) Cleanup(ctx *context.T) {
+ ctx.VI(0).Info("Cleaning up controller")
c.Lock()
for _, request := range c.outstandingRequests {
@@ -359,11 +358,11 @@
// SendOnStream writes data on id's stream. The actual network write will be
// done asynchronously. If there is an error, it will be sent to w.
-func (c *Controller) SendOnStream(id int32, data string, w lib.ClientWriter) {
+func (c *Controller) SendOnStream(ctx *context.T, id int32, data string, w lib.ClientWriter) {
c.Lock()
request := c.outstandingRequests[id]
if request == nil || request.stream == nil {
- vlog.Errorf("unknown stream: %d", id)
+ ctx.Errorf("unknown stream: %d", id)
c.Unlock()
return
}
@@ -498,15 +497,15 @@
// HandleCaveatValidationResponse handles the response to caveat validation
// requests.
-func (c *Controller) HandleCaveatValidationResponse(id int32, data string) {
+func (c *Controller) HandleCaveatValidationResponse(ctx *context.T, id int32, data string) {
c.Lock()
server, ok := c.flowMap[id].(*server.Server)
c.Unlock()
if !ok {
- vlog.Errorf("unexpected result from JavaScript. No server found matching id %d.", id)
+ ctx.Errorf("unexpected result from JavaScript. No server found matching id %d.", id)
return // ignore unknown server
}
- server.HandleCaveatValidationResponse(id, data)
+ server.HandleCaveatValidationResponse(ctx, id, data)
}
// HandleVeyronRequest starts a vanadium rpc and returns before the rpc has been completed.
@@ -526,7 +525,7 @@
w.Error(verror.Convert(verror.ErrInternal, ctx, err))
return
}
- vlog.VI(2).Infof("Rpc: %s.%s(..., streaming=%v)", msg.Name, msg.Method, msg.IsStreaming)
+ ctx.VI(2).Infof("Rpc: %s.%s(..., streaming=%v)", msg.Name, msg.Method, msg.IsStreaming)
spanName := fmt.Sprintf("<wspr>%q.%s", msg.Name, msg.Method)
ctx, span := vtrace.WithContinuedTrace(ctx, spanName, msg.TraceRequest)
ctx = i18n.WithLangID(ctx, i18n.LangID(msg.Context.Language))
@@ -578,7 +577,7 @@
// HandleVeyronCancellation cancels the request corresponding to the
// given id if it is still outstanding.
-func (c *Controller) HandleVeyronCancellation(id int32) {
+func (c *Controller) HandleVeyronCancellation(ctx *context.T, id int32) {
c.Lock()
defer c.Unlock()
if request, ok := c.outstandingRequests[id]; ok && request.cancel != nil {
@@ -587,14 +586,14 @@
}
// CloseStream closes the stream for a given id.
-func (c *Controller) CloseStream(id int32) {
+func (c *Controller) CloseStream(ctx *context.T, id int32) {
c.Lock()
defer c.Unlock()
if request, ok := c.outstandingRequests[id]; ok && request.stream != nil {
request.stream.end()
return
}
- vlog.Errorf("close called on non-existent call: %v", id)
+ ctx.Errorf("close called on non-existent call: %v", id)
}
func (c *Controller) maybeCreateServer(serverId uint32, opts ...rpc.ServerOpt) (*server.Server, error) {
@@ -613,37 +612,37 @@
// HandleLookupResponse handles the result of a Dispatcher.Lookup call that was
// run by the Javascript server.
-func (c *Controller) HandleLookupResponse(id int32, data string) {
+func (c *Controller) HandleLookupResponse(ctx *context.T, id int32, data string) {
c.Lock()
server, ok := c.flowMap[id].(*server.Server)
c.Unlock()
if !ok {
- vlog.Errorf("unexpected result from JavaScript. No channel "+
+ ctx.Errorf("unexpected result from JavaScript. No channel "+
"for MessageId: %d exists. Ignoring the results.", id)
//Ignore unknown responses that don't belong to any channel
return
}
- server.HandleLookupResponse(id, data)
+ server.HandleLookupResponse(ctx, id, data)
}
// HandleAuthResponse handles the result of a Authorizer.Authorize call that was
// run by the Javascript server.
-func (c *Controller) HandleAuthResponse(id int32, data string) {
+func (c *Controller) HandleAuthResponse(ctx *context.T, id int32, data string) {
c.Lock()
server, ok := c.flowMap[id].(*server.Server)
c.Unlock()
if !ok {
- vlog.Errorf("unexpected result from JavaScript. No channel "+
+ ctx.Errorf("unexpected result from JavaScript. No channel "+
"for MessageId: %d exists. Ignoring the results.", id)
//Ignore unknown responses that don't belong to any channel
return
}
- server.HandleAuthResponse(id, data)
+ server.HandleAuthResponse(ctx, id, data)
}
// Serve instructs WSPR to start listening for calls on behalf
// of a javascript server.
-func (c *Controller) Serve(_ *context.T, _ rpc.ServerCall, name string, serverId uint32, rpcServerOpts []RpcServerOption) error {
+func (c *Controller) Serve(ctx *context.T, _ rpc.ServerCall, name string, serverId uint32, rpcServerOpts []RpcServerOption) error {
opts, err := c.serverOpts(rpcServerOpts)
if err != nil {
@@ -653,7 +652,7 @@
if err != nil {
return verror.Convert(verror.ErrInternal, nil, err)
}
- vlog.VI(2).Infof("serving under name: %q", name)
+ ctx.VI(2).Infof("serving under name: %q", name)
if err := server.Serve(name); err != nil {
return verror.Convert(verror.ErrInternal, nil, err)
}
@@ -706,17 +705,17 @@
// HandleServerResponse handles the completion of outstanding calls to JavaScript services
// by filling the corresponding channel with the result from JavaScript.
-func (c *Controller) HandleServerResponse(id int32, data string) {
+func (c *Controller) HandleServerResponse(ctx *context.T, id int32, data string) {
c.Lock()
server, ok := c.flowMap[id].(*server.Server)
c.Unlock()
if !ok {
- vlog.Errorf("unexpected result from JavaScript. No channel "+
+ ctx.Errorf("unexpected result from JavaScript. No channel "+
"for MessageId: %d exists. Ignoring the results.", id)
//Ignore unknown responses that don't belong to any channel
return
}
- server.HandleServerResponse(id, data)
+ server.HandleServerResponse(ctx, id, data)
}
// getSignature uses the signature manager to get and cache the signature of a remote server.
@@ -837,12 +836,12 @@
}
// HandleGranterResponse handles the result of a Granter request.
-func (c *Controller) HandleGranterResponse(id int32, data string) {
+func (c *Controller) HandleGranterResponse(ctx *context.T, id int32, data string) {
c.Lock()
granterStr, ok := c.flowMap[id].(*granterStream)
c.Unlock()
if !ok {
- vlog.Errorf("unexpected result from JavaScript. Flow was not a granter "+
+ ctx.Errorf("unexpected result from JavaScript. Flow was not a granter "+
"stream for MessageId: %d exists. Ignoring the results.", id)
//Ignore unknown responses that don't belong to any channel
return
@@ -850,12 +849,12 @@
granterStr.Send(data)
}
-func (c *Controller) HandleTypeMessage(data string) {
+func (c *Controller) HandleTypeMessage(ctx *context.T, data string) {
c.typeReader.Add(data)
}
func (c *Controller) RemoteBlessings(ctx *context.T, _ rpc.ServerCall, name, method string) ([]string, error) {
- vlog.VI(2).Infof("requesting remote blessings for %q", name)
+ ctx.VI(2).Infof("requesting remote blessings for %q", name)
cctx, cancel := context.WithTimeout(ctx, 5*time.Second)
defer cancel()
@@ -886,7 +885,7 @@
id := c.lastGeneratedId
c.lastGeneratedId += 2
if err := c.writerCreator(id).Send(lib.ResponseBlessingsCacheMessage, messages); err != nil {
- vlog.Errorf("unexpected error sending blessings cache message: %v", err)
+ c.ctx.Errorf("unexpected error sending blessings cache message: %v", err)
}
}
diff --git a/services/wspr/internal/app/app_test.go b/services/wspr/internal/app/app_test.go
index 69cc32e..11e1793 100644
--- a/services/wspr/internal/app/app_test.go
+++ b/services/wspr/internal/app/app_test.go
@@ -176,9 +176,9 @@
}
go func() {
for _, value := range testCase.streamingInputs {
- controller.SendOnStream(0, lib.HexVomEncodeOrDie(value, nil), &writer)
+ controller.SendOnStream(ctx, 0, lib.HexVomEncodeOrDie(value, nil), &writer)
}
- controller.CloseStream(0)
+ controller.CloseStream(ctx, 0)
}()
}
@@ -306,11 +306,12 @@
}
type typeEncoderWriter struct {
- c *Controller
+ c *Controller
+ ctx *context.T
}
func (t *typeEncoderWriter) Write(p []byte) (int, error) {
- t.c.HandleTypeMessage(hex.EncodeToString(p))
+ t.c.HandleTypeMessage(t.ctx, hex.EncodeToString(p))
return len(p), nil
}
@@ -356,7 +357,7 @@
}
v23.GetNamespace(controller.Context()).SetRoots(mtName)
- typeStream := &typeEncoderWriter{c: controller}
+ typeStream := &typeEncoderWriter{c: controller, ctx: controller.Context()}
typeEncoder := vom.NewTypeEncoder(typeStream)
req, err := makeRequest(typeEncoder, RpcRequest{
Name: "__controller",
@@ -420,6 +421,7 @@
controllerReady: sync.RWMutex{},
flowCount: 2,
typeReader: lib.NewTypeReader(),
+ ctx: ctx,
}
mock.typeDecoder = vom.NewTypeDecoder(mock.typeReader)
rt, err := serveServer(ctx, mock, func(controller *Controller) {
@@ -428,7 +430,7 @@
mock.typeEncoder = rt.typeEncoder
defer rt.proxyShutdown()
- defer rt.controller.Cleanup()
+ defer rt.controller.Cleanup(ctx)
if err != nil {
t.Fatalf("could not serve server %v", err)
diff --git a/services/wspr/internal/app/messaging.go b/services/wspr/internal/app/messaging.go
index aa9c05a..5389996 100644
--- a/services/wspr/internal/app/messaging.go
+++ b/services/wspr/internal/app/messaging.go
@@ -10,10 +10,10 @@
"path/filepath"
"runtime"
+ "v.io/v23/context"
"v.io/v23/verror"
"v.io/v23/vom"
"v.io/v23/vtrace"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/lib"
)
@@ -106,28 +106,28 @@
case VeyronRequestMessage:
c.HandleVeyronRequest(ctx, msg.Id, msg.Data, w)
case CancelMessage:
- go c.HandleVeyronCancellation(msg.Id)
+ go c.HandleVeyronCancellation(ctx, msg.Id)
case StreamingValueMessage:
// SendOnStream queues up the message to be sent, but doesn't do the send
// on this goroutine. We need to queue the messages synchronously so that
// the order is preserved.
- c.SendOnStream(msg.Id, msg.Data, w)
+ c.SendOnStream(ctx, msg.Id, msg.Data, w)
case StreamCloseMessage:
- c.CloseStream(msg.Id)
+ c.CloseStream(ctx, msg.Id)
case ServerResponseMessage:
- go c.HandleServerResponse(msg.Id, msg.Data)
+ go c.HandleServerResponse(ctx, msg.Id, msg.Data)
case LookupResponseMessage:
- go c.HandleLookupResponse(msg.Id, msg.Data)
+ go c.HandleLookupResponse(ctx, msg.Id, msg.Data)
case AuthResponseMessage:
- go c.HandleAuthResponse(msg.Id, msg.Data)
+ go c.HandleAuthResponse(ctx, msg.Id, msg.Data)
case CaveatValidationResponse:
- go c.HandleCaveatValidationResponse(msg.Id, msg.Data)
+ go c.HandleCaveatValidationResponse(ctx, msg.Id, msg.Data)
case GranterResponseMessage:
- go c.HandleGranterResponse(msg.Id, msg.Data)
+ go c.HandleGranterResponse(ctx, msg.Id, msg.Data)
case TypeMessage:
// These messages need to be handled in order so they are done in line.
- c.HandleTypeMessage(msg.Data)
+ c.HandleTypeMessage(ctx, msg.Data)
default:
w.Error(verror.New(errUnknownMessageType, ctx, msg.Type))
}
@@ -152,11 +152,11 @@
// FormatAsVerror formats an error as a verror.
// This also logs the error.
-func FormatAsVerror(err error) error {
+func FormatAsVerror(ctx *context.T, err error) error {
verr := verror.Convert(verror.ErrUnknown, nil, err)
// Also log the error but write internal errors at a more severe log level
- var logLevel vlog.Level = 2
+ logLevel := 2
logErr := fmt.Sprintf("%v", verr)
// Prefix the message with the code locations associated with verr,
@@ -178,7 +178,7 @@
if verror.ErrorID(verr) == verror.ErrInternal.ID {
logLevel = 2
}
- vlog.VI(logLevel).Info(logErr)
+ ctx.VI(logLevel).Info(logErr)
return verr
}
diff --git a/services/wspr/internal/app/mock_jsServer_test.go b/services/wspr/internal/app/mock_jsServer_test.go
index 196b119..b9c60ee 100644
--- a/services/wspr/internal/app/mock_jsServer_test.go
+++ b/services/wspr/internal/app/mock_jsServer_test.go
@@ -13,6 +13,7 @@
"sync"
"testing"
+ "v.io/v23/context"
"v.io/v23/vdl"
"v.io/v23/vdlroot/signature"
"v.io/v23/verror"
@@ -50,22 +51,24 @@
typeDecoder *vom.TypeDecoder
typeEncoder *vom.TypeEncoder
+
+ ctx *context.T
}
func (m *mockJSServer) Send(responseType lib.ResponseType, msg interface{}) error {
switch responseType {
case lib.ResponseDispatcherLookup:
- return m.handleDispatcherLookup(msg)
+ return m.handleDispatcherLookup(m.ctx, msg)
case lib.ResponseAuthRequest:
- return m.handleAuthRequest(msg)
+ return m.handleAuthRequest(m.ctx, msg)
case lib.ResponseServerRequest:
- return m.handleServerRequest(msg)
+ return m.handleServerRequest(m.ctx, msg)
case lib.ResponseValidate:
- return m.handleValidationRequest(msg)
+ return m.handleValidationRequest(m.ctx, msg)
case lib.ResponseStream:
- return m.handleStream(msg)
+ return m.handleStream(m.ctx, msg)
case lib.ResponseStreamClose:
- return m.handleStreamClose(msg)
+ return m.handleStreamClose(m.ctx, msg)
case lib.ResponseFinal:
if m.receivedResponse != nil {
return fmt.Errorf("Two responses received. First was: %#v. Second was: %#v", m.receivedResponse, msg)
@@ -117,7 +120,7 @@
func (m *mockJSServer) handleTypeMessage(v interface{}) {
m.typeReader.Add(hex.EncodeToString(v.([]byte)))
}
-func (m *mockJSServer) handleDispatcherLookup(v interface{}) error {
+func (m *mockJSServer) handleDispatcherLookup(ctx *context.T, v interface{}) error {
defer func() {
m.flowCount += 2
}()
@@ -126,12 +129,12 @@
msg, err := normalize(v)
if err != nil {
- m.controller.HandleLookupResponse(m.flowCount, internalErr(err, m.typeEncoder))
+ m.controller.HandleLookupResponse(ctx, m.flowCount, internalErr(err, m.typeEncoder))
return nil
}
expected := map[string]interface{}{"serverId": 0.0, "suffix": "adder"}
if !reflect.DeepEqual(msg, expected) {
- m.controller.HandleLookupResponse(m.flowCount, internalErr(fmt.Sprintf("got: %v, want: %v", msg, expected), m.typeEncoder))
+ m.controller.HandleLookupResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("got: %v, want: %v", msg, expected), m.typeEncoder))
return nil
}
lookupReply := lib.HexVomEncodeOrDie(server.LookupReply{
@@ -139,7 +142,7 @@
Signature: m.serviceSignature,
HasAuthorizer: m.hasAuthorizer,
}, m.typeEncoder)
- m.controller.HandleLookupResponse(m.flowCount, lookupReply)
+ m.controller.HandleLookupResponse(ctx, m.flowCount, lookupReply)
return nil
}
@@ -147,57 +150,57 @@
return ep != ""
}
-func (m *mockJSServer) handleAuthRequest(v interface{}) error {
+func (m *mockJSServer) handleAuthRequest(ctx *context.T, v interface{}) error {
defer func() {
m.flowCount += 2
}()
m.hasCalledAuth = true
if !m.hasAuthorizer {
- m.controller.HandleAuthResponse(m.flowCount, internalErr("unexpected auth request", m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr("unexpected auth request", m.typeEncoder))
return nil
}
var msg server.AuthRequest
if err := lib.HexVomDecode(v.(string), &msg, m.typeDecoder); err != nil {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("error decoding %v:", err), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("error decoding %v:", err), m.typeEncoder))
return nil
}
if msg.Handle != 0 {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected handled: %v", msg.Handle), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected handled: %v", msg.Handle), m.typeEncoder))
return nil
}
call := msg.Call
if field, got, want := "Method", call.Method, lib.LowercaseFirstCharacter(m.method); got != want {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
return nil
}
if field, got, want := "Suffix", call.Suffix, "adder"; got != want {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
return nil
}
// We expect localBlessings and remoteBlessings to be a non-zero id
if call.LocalBlessings == 0 {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("bad local blessing: %v", call.LocalBlessings), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("bad local blessing: %v", call.LocalBlessings), m.typeEncoder))
return nil
}
if call.RemoteBlessings == 0 {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("bad remote blessing: %v", call.RemoteBlessings), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("bad remote blessing: %v", call.RemoteBlessings), m.typeEncoder))
return nil
}
// We expect endpoints to be set
if !validateEndpoint(call.LocalEndpoint) {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("bad endpoint:%v", call.LocalEndpoint), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("bad endpoint:%v", call.LocalEndpoint), m.typeEncoder))
return nil
}
if !validateEndpoint(call.RemoteEndpoint) {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("bad endpoint:%v", call.RemoteEndpoint), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("bad endpoint:%v", call.RemoteEndpoint), m.typeEncoder))
return nil
}
@@ -205,33 +208,33 @@
Err: m.authError,
}, m.typeEncoder)
- m.controller.HandleAuthResponse(m.flowCount, authReply)
+ m.controller.HandleAuthResponse(ctx, m.flowCount, authReply)
return nil
}
-func (m *mockJSServer) handleServerRequest(v interface{}) error {
+func (m *mockJSServer) handleServerRequest(ctx *context.T, v interface{}) error {
defer func() {
m.flowCount += 2
}()
if m.hasCalledAuth != m.hasAuthorizer {
- m.controller.HandleServerResponse(m.flowCount, internalErr("authorizer hasn't been called yet", m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.flowCount, internalErr("authorizer hasn't been called yet", m.typeEncoder))
return nil
}
var msg server.ServerRpcRequest
if err := lib.HexVomDecode(v.(string), &msg, m.typeDecoder); err != nil {
- m.controller.HandleServerResponse(m.flowCount, internalErr(err, m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.flowCount, internalErr(err, m.typeEncoder))
return nil
}
if field, got, want := "Method", msg.Method, lib.LowercaseFirstCharacter(m.method); got != want {
- m.controller.HandleServerResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
return nil
}
if field, got, want := "Handle", msg.Handle, int32(0); got != want {
- m.controller.HandleServerResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
return nil
}
@@ -242,23 +245,23 @@
}
}
if field, got, want := "Args", vals, m.inArgs; !reflectutil.DeepEqual(got, want, &reflectutil.DeepEqualOpts{SliceEqNilEmpty: true}) {
- m.controller.HandleServerResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
return nil
}
call := msg.Call.SecurityCall
if field, got, want := "Suffix", call.Suffix, "adder"; got != want {
- m.controller.HandleServerResponse(m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("unexpected value for %s: got %v, want %v", field, got, want), m.typeEncoder))
return nil
}
// We expect localBlessings and remoteBlessings to be a non-zero id
if call.LocalBlessings == 0 {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("bad local blessing: %v", call.LocalBlessings), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("bad local blessing: %v", call.LocalBlessings), m.typeEncoder))
return nil
}
if call.RemoteBlessings == 0 {
- m.controller.HandleAuthResponse(m.flowCount, internalErr(fmt.Sprintf("bad remote blessing: %v", call.RemoteBlessings), m.typeEncoder))
+ m.controller.HandleAuthResponse(ctx, m.flowCount, internalErr(fmt.Sprintf("bad remote blessing: %v", call.RemoteBlessings), m.typeEncoder))
return nil
}
@@ -266,11 +269,11 @@
// We don't return the final response until the stream is closed.
m.sender.Add(1)
- go m.sendServerStream()
+ go m.sendServerStream(ctx)
return nil
}
-func (m *mockJSServer) handleValidationRequest(v interface{}) error {
+func (m *mockJSServer) handleValidationRequest(ctx *context.T, v interface{}) error {
defer func() {
m.flowCount += 2
}()
@@ -283,21 +286,21 @@
res := lib.HexVomEncodeOrDie(resp, m.typeEncoder)
m.controllerReady.RLock()
- m.controller.HandleCaveatValidationResponse(m.flowCount, res)
+ m.controller.HandleCaveatValidationResponse(ctx, m.flowCount, res)
m.controllerReady.RUnlock()
return nil
}
-func (m *mockJSServer) sendServerStream() {
+func (m *mockJSServer) sendServerStream(ctx *context.T) {
defer m.sender.Done()
m.controllerReady.RLock()
for _, v := range m.serverStream {
- m.controller.SendOnStream(m.rpcFlow, lib.HexVomEncodeOrDie(v, m.typeEncoder), m)
+ m.controller.SendOnStream(ctx, m.rpcFlow, lib.HexVomEncodeOrDie(v, m.typeEncoder), m)
}
m.controllerReady.RUnlock()
}
-func (m *mockJSServer) handleStream(msg interface{}) error {
+func (m *mockJSServer) handleStream(ctx *context.T, msg interface{}) error {
smsg, ok := msg.(string)
if !ok || len(m.expectedClientStream) == 0 {
m.t.Errorf("unexpected stream message: %v", msg)
@@ -312,7 +315,7 @@
return nil
}
-func (m *mockJSServer) handleStreamClose(msg interface{}) error {
+func (m *mockJSServer) handleStreamClose(ctx *context.T, msg interface{}) error {
m.sender.Wait()
reply := lib.ServerRpcReply{
Results: []*vdl.Value{m.finalResponse},
@@ -320,7 +323,7 @@
}
m.controllerReady.RLock()
- m.controller.HandleServerResponse(m.rpcFlow, lib.HexVomEncodeOrDie(reply, m.typeEncoder))
+ m.controller.HandleServerResponse(ctx, m.rpcFlow, lib.HexVomEncodeOrDie(reply, m.typeEncoder))
m.controllerReady.RUnlock()
return nil
}
diff --git a/services/wspr/internal/browspr/browspr.go b/services/wspr/internal/browspr/browspr.go
index 8971fc3..409ea62 100644
--- a/services/wspr/internal/browspr/browspr.go
+++ b/services/wspr/internal/browspr/browspr.go
@@ -15,7 +15,6 @@
"v.io/v23/rpc"
"v.io/v23/vdl"
"v.io/v23/vtrace"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/account"
"v.io/x/ref/services/wspr/internal/app"
"v.io/x/ref/services/wspr/internal/principal"
@@ -42,10 +41,10 @@
identd string,
wsNamespaceRoots []string) *Browspr {
if listenSpec.Proxy == "" {
- vlog.Fatalf("a vanadium proxy must be set")
+ ctx.Fatalf("a vanadium proxy must be set")
}
if identd == "" {
- vlog.Fatalf("an identd server must be set")
+ ctx.Fatalf("an identd server must be set")
}
browspr := &Browspr{
@@ -60,7 +59,7 @@
var err error
p := v23.GetPrincipal(ctx)
if browspr.principalManager, err = principal.NewPrincipalManager(p, &principal.InMemorySerializer{}); err != nil {
- vlog.Fatalf("principal.NewPrincipalManager failed: %s", err)
+ ctx.Fatalf("principal.NewPrincipalManager failed: %s", err)
}
browspr.accountManager = account.NewAccountManager(identd, browspr.principalManager)
@@ -122,7 +121,7 @@
// We must unlock the mutex before calling cleanunp, otherwise
// browspr deadlocks.
b.mu.Unlock()
- pipe.cleanup()
+ pipe.cleanup(b.ctx)
b.mu.Lock()
delete(b.activeInstances, msg.InstanceId)
@@ -159,8 +158,8 @@
if err := vdl.Convert(&msg, val); err != nil {
return nil, fmt.Errorf("HandleAuthAssociateAccountRpc did not receive AssociateAccountMessage, received: %v, %v", val, err)
}
-
- if err := b.accountManager.AssociateAccount(msg.Origin, msg.Account, msg.Caveats); err != nil {
+ ctx, _ := vtrace.WithNewTrace(b.ctx)
+ if err := b.accountManager.AssociateAccount(ctx, msg.Origin, msg.Account, msg.Caveats); err != nil {
return nil, err
}
return nil, nil
diff --git a/services/wspr/internal/browspr/browspr_test.go b/services/wspr/internal/browspr/browspr_test.go
index 5841efa..20b1466 100644
--- a/services/wspr/internal/browspr/browspr_test.go
+++ b/services/wspr/internal/browspr/browspr_test.go
@@ -178,7 +178,7 @@
if err := browspr.principalManager.AddAccount(accountName, bp.BlessingStore().Default()); err != nil {
t.Fatalf("Failed to add account: %v", err)
}
- if err := browspr.accountManager.AssociateAccount(msgOrigin, accountName, nil); err != nil {
+ if err := browspr.accountManager.AssociateAccount(ctx, msgOrigin, accountName, nil); err != nil {
t.Fatalf("Failed to associate account: %v", err)
}
diff --git a/services/wspr/internal/browspr/pipe.go b/services/wspr/internal/browspr/pipe.go
index 34280b4..3086761 100644
--- a/services/wspr/internal/browspr/pipe.go
+++ b/services/wspr/internal/browspr/pipe.go
@@ -5,7 +5,7 @@
package browspr
import (
- "v.io/x/lib/vlog"
+ "v.io/v23/context"
"v.io/x/ref/services/wspr/internal/app"
"v.io/x/ref/services/wspr/internal/lib"
)
@@ -31,16 +31,16 @@
// TODO(nlacasse, bjornick): This code should go away once we
// start requiring authentication. At that point, we should
// just return an error to the client.
- vlog.Errorf("No principal associated with origin %v, creating a new principal with self-signed blessing from browspr: %v", origin, err)
+ b.ctx.Errorf("No principal associated with origin %v, creating a new principal with self-signed blessing from browspr: %v", origin, err)
dummyAccount, err := b.principalManager.DummyAccount()
if err != nil {
- vlog.Errorf("principalManager.DummyAccount() failed: %v", err)
+ b.ctx.Errorf("principalManager.DummyAccount() failed: %v", err)
return nil
}
- if err := b.accountManager.AssociateAccount(origin, dummyAccount, nil); err != nil {
- vlog.Errorf("accountManager.AssociateAccount(%v, %v, %v) failed: %v", origin, dummyAccount, nil, err)
+ if err := b.accountManager.AssociateAccount(b.ctx, origin, dummyAccount, nil); err != nil {
+ b.ctx.Errorf("accountManager.AssociateAccount(%v, %v, %v) failed: %v", origin, dummyAccount, nil, err)
return nil
}
p, err = b.accountManager.LookupPrincipal(origin)
@@ -63,7 +63,7 @@
pipe.controller, err = app.NewController(b.ctx, pipe.createWriter, &listenSpec, namespaceRoots, p)
if err != nil {
- vlog.Errorf("Could not create controller: %v", err)
+ b.ctx.Errorf("Could not create controller: %v", err)
return nil
}
@@ -77,9 +77,9 @@
}
}
-func (p *pipe) cleanup() {
- vlog.VI(0).Info("Cleaning up pipe")
- p.controller.Cleanup()
+func (p *pipe) cleanup(ctx *context.T) {
+ ctx.VI(0).Info("Cleaning up pipe")
+ p.controller.Cleanup(ctx)
}
func (p *pipe) handleMessage(msg app.Message) error {
diff --git a/services/wspr/internal/browspr/writer.go b/services/wspr/internal/browspr/writer.go
index ed4fc66..47db65f 100644
--- a/services/wspr/internal/browspr/writer.go
+++ b/services/wspr/internal/browspr/writer.go
@@ -25,5 +25,5 @@
}
func (w *postMessageWriter) Error(err error) {
- w.Send(lib.ResponseError, app.FormatAsVerror(err))
+ w.Send(lib.ResponseError, app.FormatAsVerror(w.p.browspr.ctx, err))
}
diff --git a/services/wspr/internal/rpc/server/dispatcher.go b/services/wspr/internal/rpc/server/dispatcher.go
index 1b49fea..96573c9 100644
--- a/services/wspr/internal/rpc/server/dispatcher.go
+++ b/services/wspr/internal/rpc/server/dispatcher.go
@@ -7,11 +7,11 @@
import (
"sync"
+ "v.io/v23/context"
"v.io/v23/rpc"
"v.io/v23/security"
"v.io/v23/vdlroot/signature"
"v.io/v23/verror"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/lib"
)
@@ -118,14 +118,14 @@
return invoker, auth, nil
}
-func (d *dispatcher) handleLookupResponse(id int32, data string) {
+func (d *dispatcher) handleLookupResponse(ctx *context.T, id int32, data string) {
d.mu.Lock()
ch := d.outstandingLookups[id]
d.mu.Unlock()
if ch == nil {
d.flowFactory.cleanupFlow(id)
- vlog.Errorf("unknown invoke request for flow: %d", id)
+ ctx.Errorf("unknown invoke request for flow: %d", id)
return
}
@@ -133,7 +133,7 @@
if err := lib.HexVomDecode(data, &lookupReply, d.vomHelper.TypeDecoder()); err != nil {
err2 := verror.Convert(verror.ErrInternal, nil, err)
lookupReply = LookupReply{Err: err2}
- vlog.Errorf("unmarshaling invoke request failed: %v, %s", err, data)
+ ctx.Errorf("unmarshaling invoke request failed: %v, %s", err, data)
}
ch <- lookupReply
diff --git a/services/wspr/internal/rpc/server/dispatcher_test.go b/services/wspr/internal/rpc/server/dispatcher_test.go
index b58bc80..5e60164 100644
--- a/services/wspr/internal/rpc/server/dispatcher_test.go
+++ b/services/wspr/internal/rpc/server/dispatcher_test.go
@@ -16,6 +16,7 @@
"v.io/v23/vdlroot/signature"
"v.io/v23/verror"
"v.io/v23/vom"
+ "v.io/x/ref/internal/logger"
"v.io/x/ref/services/wspr/internal/lib"
"v.io/x/ref/services/wspr/internal/lib/testwriter"
)
@@ -90,6 +91,9 @@
}
func TestSuccessfulLookup(t *testing.T) {
+ ctx, cancel := context.RootContext()
+ defer cancel()
+ ctx = context.WithLogger(ctx, logger.Global())
flowFactory := &mockFlowFactory{}
d := newDispatcher(0, flowFactory, mockInvokerFactory{}, mockAuthorizerFactory{}, mockVomHelper{})
expectedSig := []signature.Interface{
@@ -105,7 +109,7 @@
HasAuthorizer: false,
Signature: expectedSig,
}
- d.handleLookupResponse(0, lib.HexVomEncodeOrDie(reply, nil))
+ d.handleLookupResponse(ctx, 0, lib.HexVomEncodeOrDie(reply, nil))
}()
invoker, auth, err := d.Lookup("a/b")
@@ -139,6 +143,9 @@
}
func TestSuccessfulLookupWithAuthorizer(t *testing.T) {
+ ctx, cancel := context.RootContext()
+ defer cancel()
+ ctx = context.WithLogger(ctx, logger.Global())
flowFactory := &mockFlowFactory{}
d := newDispatcher(0, flowFactory, mockInvokerFactory{}, mockAuthorizerFactory{}, mockVomHelper{})
expectedSig := []signature.Interface{
@@ -154,7 +161,7 @@
HasAuthorizer: true,
Signature: expectedSig,
}
- d.handleLookupResponse(0, lib.HexVomEncodeOrDie(reply, nil))
+ d.handleLookupResponse(ctx, 0, lib.HexVomEncodeOrDie(reply, nil))
}()
invoker, auth, err := d.Lookup("a/b")
@@ -188,6 +195,9 @@
}
func TestFailedLookup(t *testing.T) {
+ ctx, cancel := context.RootContext()
+ defer cancel()
+ ctx = context.WithLogger(ctx, logger.Global())
flowFactory := &mockFlowFactory{}
d := newDispatcher(0, flowFactory, mockInvokerFactory{}, mockAuthorizerFactory{}, mockVomHelper{})
go func() {
@@ -198,7 +208,7 @@
reply := LookupReply{
Err: verror.New(verror.ErrNoExist, nil),
}
- d.handleLookupResponse(0, lib.HexVomEncodeOrDie(reply, nil))
+ d.handleLookupResponse(ctx, 0, lib.HexVomEncodeOrDie(reply, nil))
}()
_, _, err := d.Lookup("a/b")
diff --git a/services/wspr/internal/rpc/server/server.go b/services/wspr/internal/rpc/server/server.go
index 2488069..6205d91 100644
--- a/services/wspr/internal/rpc/server/server.go
+++ b/services/wspr/internal/rpc/server/server.go
@@ -23,7 +23,6 @@
"v.io/v23/verror"
"v.io/v23/vom"
"v.io/v23/vtrace"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/lib"
"v.io/x/ref/services/wspr/internal/principal"
)
@@ -95,6 +94,8 @@
// statusClose will be closed when the server is shutting down, this will
// cause the status poller to exit.
statusClose chan struct{}
+
+ ctx *context.T
}
type serverContextKey struct{}
@@ -114,6 +115,7 @@
if server.server, err = v23.NewServer(ctx, opts...); err != nil {
return nil, err
}
+ server.ctx = ctx
return server, nil
}
@@ -181,7 +183,7 @@
return errHandler(err)
}
- vlog.VI(3).Infof("calling method %q with args %v, MessageID %d assigned\n", methodName, args, flow.ID)
+ ctx.VI(3).Infof("calling method %q with args %v, MessageID %d assigned\n", methodName, args, flow.ID)
// Watch for cancellation.
go func() {
@@ -285,7 +287,7 @@
return errHandler(err)
}
- vlog.VI(3).Infof("calling method 'Glob__' with args %v, MessageID %d assigned\n", []interface{}{pattern}, flow.ID)
+ ctx.VI(3).Infof("calling method 'Glob__' with args %v, MessageID %d assigned\n", []interface{}{pattern}, flow.ID)
// Watch for cancellation.
go func() {
@@ -322,7 +324,7 @@
return
}
}
- vlog.VI(1).Infof("Error reading from stream: %v\n", err)
+ s.ctx.VI(1).Infof("Error reading from stream: %v\n", err)
s.outstandingRequestLock.Lock()
_, found := s.outstandingServerRequests[flow.ID]
s.outstandingRequestLock.Unlock()
@@ -387,7 +389,7 @@
}()
if err := flow.Writer.Send(lib.ResponseValidate, req); err != nil {
- vlog.VI(2).Infof("Failed to send validate response: %v", err)
+ ctx.VI(2).Infof("Failed to send validate response: %v", err)
replyChan <- makeListOfErrors(len(cavs), err)
}
@@ -404,7 +406,7 @@
return makeListOfErrors(len(cavs), NewErrCaveatValidationTimeout(ctx))
case reply := <-replyChan:
if len(reply) != len(cavs) {
- vlog.VI(2).Infof("Wspr caveat validator received %d results from javascript but expected %d", len(reply), len(cavs))
+ ctx.VI(2).Infof("Wspr caveat validator received %d results from javascript but expected %d", len(reply), len(cavs))
return makeListOfErrors(len(cavs), NewErrInvalidValidationResponseFromJavascript(ctx))
}
@@ -551,7 +553,7 @@
Language: string(i18n.GetLangID(ctx)),
},
}
- vlog.VI(0).Infof("Sending out auth request for %v, %v", flow.ID, message)
+ ctx.VI(0).Infof("Sending out auth request for %v, %v", flow.ID, message)
vomMessage, err := lib.HexVomEncode(message, s.helper.TypeEncoder())
if err != nil {
@@ -561,7 +563,7 @@
}
err = <-replyChan
- vlog.VI(0).Infof("going to respond with %v", err)
+ ctx.VI(0).Infof("going to respond with %v", err)
s.outstandingRequestLock.Lock()
delete(s.outstandingAuthRequests, flow.ID)
s.outstandingRequestLock.Unlock()
@@ -632,10 +634,10 @@
return ch
}
-func (s *Server) HandleServerResponse(id int32, data string) {
+func (s *Server) HandleServerResponse(ctx *context.T, id int32, data string) {
ch := s.popServerRequest(id)
if ch == nil {
- vlog.Errorf("unexpected result from JavaScript. No channel "+
+ ctx.Errorf("unexpected result from JavaScript. No channel "+
"for MessageId: %d exists. Ignoring the results.", id)
// Ignore unknown responses that don't belong to any channel
return
@@ -647,7 +649,7 @@
reply.Err = err
}
- vlog.VI(0).Infof("response received from JavaScript server for "+
+ ctx.VI(0).Infof("response received from JavaScript server for "+
"MessageId %d with result %v", id, reply)
s.helper.CleanupFlow(id)
if reply.Err != nil {
@@ -657,16 +659,16 @@
ch <- &reply
}
-func (s *Server) HandleLookupResponse(id int32, data string) {
- s.dispatcher.handleLookupResponse(id, data)
+func (s *Server) HandleLookupResponse(ctx *context.T, id int32, data string) {
+ s.dispatcher.handleLookupResponse(ctx, id, data)
}
-func (s *Server) HandleAuthResponse(id int32, data string) {
+func (s *Server) HandleAuthResponse(ctx *context.T, id int32, data string) {
s.outstandingRequestLock.Lock()
ch := s.outstandingAuthRequests[id]
s.outstandingRequestLock.Unlock()
if ch == nil {
- vlog.Errorf("unexpected result from JavaScript. No channel "+
+ ctx.Errorf("unexpected result from JavaScript. No channel "+
"for MessageId: %d exists. Ignoring the results(%s)", id, data)
// Ignore unknown responses that don't belong to any channel
return
@@ -678,7 +680,7 @@
reply = AuthReply{Err: err}
}
- vlog.VI(0).Infof("response received from JavaScript server for "+
+ ctx.VI(0).Infof("response received from JavaScript server for "+
"MessageId %d with result %v", id, reply)
s.helper.CleanupFlow(id)
// A nil verror.E does not result in an nil error. Instead, we have create
@@ -691,12 +693,12 @@
ch <- err
}
-func (s *Server) HandleCaveatValidationResponse(id int32, data string) {
+func (s *Server) HandleCaveatValidationResponse(ctx *context.T, id int32, data string) {
s.outstandingRequestLock.Lock()
ch := s.outstandingValidationRequests[id]
s.outstandingRequestLock.Unlock()
if ch == nil {
- vlog.Errorf("unexpected result from JavaScript. No channel "+
+ ctx.Errorf("unexpected result from JavaScript. No channel "+
"for validation response with MessageId: %d exists. Ignoring the results(%s)", id, data)
// Ignore unknown responses that don't belong to any channel
return
@@ -704,7 +706,7 @@
var reply CaveatValidationResponse
if err := lib.HexVomDecode(data, &reply, s.helper.TypeDecoder()); err != nil {
- vlog.Errorf("failed to decode validation response %q: error %v", data, err)
+ ctx.Errorf("failed to decode validation response %q: error %v", data, err)
ch <- []error{}
return
}
diff --git a/services/wspr/wsprlib/pipe.go b/services/wspr/wsprlib/pipe.go
index c8fe142..90c98a3 100644
--- a/services/wspr/wsprlib/pipe.go
+++ b/services/wspr/wsprlib/pipe.go
@@ -12,7 +12,7 @@
"time"
"v.io/v23"
- "v.io/x/lib/vlog"
+ "v.io/v23/context"
"v.io/x/ref/services/wspr/internal/app"
"v.io/x/ref/services/wspr/internal/lib"
@@ -51,13 +51,13 @@
if creator == nil {
creator = func(id int32) lib.ClientWriter {
- return &websocketWriter{p: pipe, id: id}
+ return &websocketWriter{p: pipe, id: id, ctx: wspr.ctx}
}
}
pipe.writerCreator = creator
origin := req.Header.Get("Origin")
if origin == "" {
- vlog.Errorf("Could not read origin from the request")
+ wspr.ctx.Errorf("Could not read origin from the request")
http.Error(w, "Could not read origin from the request", http.StatusBadRequest)
return nil
}
@@ -65,13 +65,13 @@
p, err := wspr.principalManager.Principal(origin)
if err != nil {
p = v23.GetPrincipal(wspr.ctx)
- vlog.Errorf("no principal associated with origin %s: %v", origin, err)
+ wspr.ctx.Errorf("no principal associated with origin %s: %v", origin, err)
// TODO(bjornick): Send an error to the client when all of the principal stuff is set up.
}
pipe.controller, err = app.NewController(wspr.ctx, creator, wspr.listenSpec, wspr.namespaceRoots, p)
if err != nil {
- vlog.Errorf("Could not create controller: %v", err)
+ wspr.ctx.Errorf("Could not create controller: %v", err)
http.Error(w, fmt.Sprintf("Failed to create controller: %v", err), http.StatusInternalServerError)
return nil
}
@@ -81,9 +81,9 @@
}
// cleans up any outstanding rpcs.
-func (p *pipe) cleanup() {
- vlog.VI(0).Info("Cleaning up websocket")
- p.controller.Cleanup()
+func (p *pipe) cleanup(ctx *context.T) {
+ ctx.VI(0).Info("Cleaning up websocket")
+ p.controller.Cleanup(ctx)
p.ws.Close()
p.wspr.CleanUpPipe(p.req)
}
@@ -97,15 +97,15 @@
for {
msg, ok := <-p.writeQueue
if !ok {
- vlog.Errorf("write queue was closed")
+ p.wspr.ctx.Errorf("write queue was closed")
return
}
if msg.messageType == websocket.PingMessage {
- vlog.Infof("sending ping")
+ p.wspr.ctx.Infof("sending ping")
}
if err := p.ws.WriteMessage(msg.messageType, msg.buf); err != nil {
- vlog.Errorf("failed to write bytes: %s", err)
+ p.wspr.ctx.Errorf("failed to write bytes: %s", err)
}
}
}
@@ -117,7 +117,7 @@
return
} else if err != nil {
http.Error(w, "Internal Error", 500)
- vlog.Errorf("websocket upgrade failed: %s", err)
+ p.wspr.ctx.Errorf("websocket upgrade failed: %s", err)
return
}
@@ -132,13 +132,13 @@
func (p *pipe) pingLoop() {
for {
time.Sleep(pingInterval)
- vlog.VI(2).Info("ws: ping")
+ p.wspr.ctx.VI(2).Info("ws: ping")
p.writeQueue <- wsMessage{messageType: websocket.PingMessage, buf: []byte{}}
}
}
func (p *pipe) pongHandler(msg string) error {
- vlog.VI(2).Infof("ws: pong")
+ p.wspr.ctx.VI(2).Infof("ws: pong")
p.ws.SetReadDeadline(time.Now().Add(pongTimeout))
return nil
}
@@ -151,19 +151,19 @@
break
}
if err != nil {
- vlog.VI(1).Infof("websocket receive: %s", err)
+ p.wspr.ctx.VI(1).Infof("websocket receive: %s", err)
break
}
if op != websocket.TextMessage {
- vlog.Errorf("unexpected websocket op: %v", op)
+ p.wspr.ctx.Errorf("unexpected websocket op: %v", op)
}
var msg app.Message
decoder := json.NewDecoder(r)
if err := decoder.Decode(&msg); err != nil {
errMsg := fmt.Sprintf("can't unmarshall JSONMessage: %v", err)
- vlog.Error(errMsg)
+ p.wspr.ctx.Error(errMsg)
p.writeQueue <- wsMessage{messageType: websocket.TextMessage, buf: []byte(errMsg)}
continue
}
@@ -171,5 +171,5 @@
ww := p.writerCreator(msg.Id)
p.controller.HandleIncomingMessage(msg, ww)
}
- p.cleanup()
+ p.cleanup(p.wspr.ctx)
}
diff --git a/services/wspr/wsprlib/writer.go b/services/wspr/wsprlib/writer.go
index ea65970..8c1fabe 100644
--- a/services/wspr/wsprlib/writer.go
+++ b/services/wspr/wsprlib/writer.go
@@ -9,8 +9,8 @@
"path/filepath"
"runtime"
+ "v.io/v23/context"
"v.io/v23/verror"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/app"
"v.io/x/ref/services/wspr/internal/lib"
@@ -25,8 +25,9 @@
// Implements clientWriter interface for sending messages over websockets.
type websocketWriter struct {
- p *pipe
- id int32
+ p *pipe
+ id int32
+ ctx *context.T
}
func (w *websocketWriter) Send(messageType lib.ResponseType, data interface{}) error {
@@ -44,7 +45,7 @@
verr := verror.Convert(verror.ErrUnknown, nil, err)
// Also log the error but write internal errors at a more severe log level
- var logLevel vlog.Level = 2
+ logLevel := 2
logErr := fmt.Sprintf("%v", verr)
// Prefix the message with the code locations associated with verr,
@@ -66,7 +67,7 @@
if verror.ErrorID(verr) == verror.ErrInternal.ID {
logLevel = 2
}
- vlog.VI(logLevel).Info(logErr)
+ w.ctx.VI(logLevel).Info(logErr)
w.Send(lib.ResponseError, verr)
}
diff --git a/services/wspr/wsprlib/wspr.go b/services/wspr/wsprlib/wspr.go
index 0544575..d626ed5 100644
--- a/services/wspr/wsprlib/wspr.go
+++ b/services/wspr/wsprlib/wspr.go
@@ -20,7 +20,6 @@
"v.io/v23"
"v.io/v23/context"
"v.io/v23/rpc"
- "v.io/x/lib/vlog"
"v.io/x/ref/services/wspr/internal/account"
"v.io/x/ref/services/wspr/internal/principal"
@@ -60,10 +59,10 @@
addr := fmt.Sprintf("127.0.0.1:%d", wspr.httpPort)
ln, err := net.Listen("tcp", addr)
if err != nil {
- vlog.Fatalf("Listen failed: %s", err)
+ wspr.ctx.Fatalf("Listen failed: %s", err)
}
wspr.ln = ln.(*net.TCPListener)
- vlog.VI(1).Infof("Listening at %s", ln.Addr().String())
+ wspr.ctx.VI(1).Infof("Listening at %s", ln.Addr().String())
return ln.Addr()
}
@@ -96,7 +95,7 @@
http.Handle("/", http.NotFoundHandler())
if err := http.Serve(tcpKeepAliveListener{wspr.ln}, nil); err != nil {
- vlog.Fatalf("Serve failed: %s", err)
+ wspr.ctx.Fatalf("Serve failed: %s", err)
}
}
@@ -113,7 +112,7 @@
// Creates a new WebSocket Proxy object.
func NewWSPR(ctx *context.T, httpPort int, listenSpec *rpc.ListenSpec, identdEP string, namespaceRoots []string) *WSPR {
if listenSpec.Proxy == "" {
- vlog.Fatalf("a vanadium proxy must be set")
+ ctx.Fatalf("a vanadium proxy must be set")
}
wspr := &WSPR{
@@ -128,7 +127,7 @@
p := v23.GetPrincipal(ctx)
var err error
if wspr.principalManager, err = principal.NewPrincipalManager(p, &principal.InMemorySerializer{}); err != nil {
- vlog.Fatalf("principal.NewPrincipalManager failed: %s", err)
+ ctx.Fatalf("principal.NewPrincipalManager failed: %s", err)
}
wspr.accountManager = account.NewAccountManager(identdEP, wspr.principalManager)
@@ -137,7 +136,7 @@
}
func (wspr *WSPR) logAndSendBadReqErr(w http.ResponseWriter, msg string) {
- vlog.Error(msg)
+ wspr.ctx.Error(msg)
http.Error(w, msg, http.StatusBadRequest)
return
}
@@ -149,7 +148,7 @@
http.Error(w, "Method not allowed.", http.StatusMethodNotAllowed)
return
}
- vlog.VI(0).Info("Creating a new websocket")
+ wspr.ctx.VI(0).Info("Creating a new websocket")
p := newPipe(w, r, wspr, nil)
if p == nil {
