Debug all the things

go/worker/txnscheduler/service.go

@@ -22,6 +22,7 @@ func (w *Worker) SubmitTx(ctx context.Context, rq *api.SubmitTxRequest) (*api.Su
 	}
 
 	if w.checkTxEnabled {
+		w.logger.Debug("YYYYYY: Checking transaction!")
 		fmt.Print("\n\n\n*** CHECKING TRANSACTION! ***\n\n")
 
 		// Check transaction before queuing it.
@@ -34,24 +35,28 @@ func (w *Worker) SubmitTx(ctx context.Context, rq *api.SubmitTxRequest) (*api.Su
 		workerHost := runtime.GetWorkerHost()
 		if workerHost == nil {
 			fmt.Print("\n***     ERROR: Worker host not initialized!\n\n")
-			w.logger.Error("worker host not initialized")
+			w.logger.Error("YYYYYY: worker host not initialized")
 			return nil, api.ErrNotReady
 		}
 		resp, err := workerHost.Call(ctx, checkRq)
 		if err != nil {
 			fmt.Print("\n***     ERROR: Worker host call error: ", err, "\n\n")
+			w.logger.Debug("YYYYYY: Worker host call error", "err", err)
 			return nil, err
 		}
 		if resp == nil {
 			fmt.Print("\n***     ERROR: Worker host reponse is nil.\n\n")
+			w.logger.Debug("YYYYYY: Worker host response is nil.")
 			return nil, api.ErrCheckTxFailed
 		}
 		if resp.WorkerCheckTxBatchResponse.Results == nil {
 			fmt.Print("\n***     ERROR: Worker host reponse contains no results.\n\n")
+			w.logger.Debug("YYYYYY: Worker host response contains no results.")
 			return nil, api.ErrCheckTxFailed
 		}
 		if len(resp.WorkerCheckTxBatchResponse.Results) != 1 {
 			fmt.Print("\n***     ERROR: Worker host reponse doesn't contain exactly one result.\n\n")
+			w.logger.Debug("YYYYYY: Worker host response doesn't contain exactly one result.")
 			return nil, api.ErrCheckTxFailed
 		}
 
@@ -61,8 +66,10 @@ func (w *Worker) SubmitTx(ctx context.Context, rq *api.SubmitTxRequest) (*api.Su
 		cbor.MustUnmarshal(resultRaw, &result)
 		if result.Error != nil {
 			fmt.Print("\n***     ERROR: CheckTx returned error: ", result.Error, "\n\n")
+			w.logger.Debug("YYYYYY: CheckTx returned error", "err", result.Error)
 			return nil, errors.Wrap(api.ErrCheckTxFailed, *result.Error)
 		}
+		w.logger.Debug("YYYYYY: Transaction checked out OK!")
 		fmt.Print("\n*** TRANSACTION CHECKED OUT OK! ***\n\n\n\n")
 	}
 

go/worker/txnscheduler/worker.go

@@ -199,36 +199,44 @@ func newWorker(
 		var err error
 
 		// Create the runtime host worker.
+		w.logger.Debug("XXXXXX: Creating runtime host worker...")
 		w.RuntimeHostWorker, err = workerCommon.NewRuntimeHostWorker(commonWorker)
 		if err != nil {
 			return nil, err
 		}
+		w.logger.Debug("XXXXXX: Runtime host worker creation complete.")
 
 		// Use existing gRPC server passed from the node.
 		api.RegisterService(commonWorker.Grpc.Server(), w)
 
 		// Register all configured runtimes.
+		w.logger.Debug("XXXXXX: Registering configured runtimes...")
 		for _, rt := range commonWorker.GetRuntimes() {
 			if err = w.registerRuntime(rt); err != nil {
 				return nil, err
 			}
 		}
+		w.logger.Debug("XXXXXX: Runtime registration complete.")
 
 		// Register transaction scheduler worker role.
 		if err = w.registration.RegisterRole(node.RoleTransactionScheduler, func(n *node.Node) error {
 			if w.checkTxEnabled {
 				// Wait until all the runtimes are initialized.
+				w.logger.Debug("XXXXXX: Waiting for runtimes to initialize...")
 				for _, rt := range w.runtimes {
 					select {
 					case <-rt.Initialized():
 					case <-w.ctx.Done():
 						return w.ctx.Err()
 					}
 				}
+				w.logger.Debug("XXXXXX: Runtimes finished initializing.")
 
+				w.logger.Debug("XXXXXX: Obtaining runtime versions...")
 				for _, rt := range n.Runtimes {
 					var grr error
 
+					w.logger.Debug("XXXXXXXXX: Processing runtime...", "rt_id", rt.ID)
 					workerRT := w.runtimes[rt.ID]
 					if workerRT == nil {
 						continue
@@ -262,6 +270,7 @@ func newWorker(
 					}
 				}
 			}
+			w.logger.Debug("XXXXXX: Role initialization completed.")
 
 			return nil
 		}); err != nil {