storage: miscellaneous replicate queue log improvements

Watching a test cluster, I found the replicate queue traces unsatisfying,
often lacking the crucial detail especially for failed replications.

storage/replica_command.go

@@ -3056,8 +3056,8 @@ func (r *Replica) ChangeReplicas(
 
 	descKey := keys.RangeDescriptorKey(desc.StartKey)
 
-	log.Trace(ctx, "starting txn")
 	if err := r.store.DB().Txn(func(txn *client.Txn) error {
+		log.Trace(ctx, "attempting txn")
 		txn.Proto.Name = replicaChangeTxnName
 		// TODO(tschottdorf): oldDesc is used for sanity checks related to #7224.
 		// Remove when that has been solved. The failure mode is likely based on
@@ -3068,7 +3068,7 @@ func (r *Replica) ChangeReplicas(
 		if err := txn.GetProto(descKey, oldDesc); err != nil {
 			return err
 		}
-		log.Infof("%s: change replicas of %d: read existing descriptor %+v", r, rangeID, oldDesc)
+		log.Infoc(ctx, "%s: change replicas of %d: read existing descriptor %+v", r, rangeID, oldDesc)
 
 		{
 			b := txn.NewBatch()
@@ -3111,6 +3111,7 @@ func (r *Replica) ChangeReplicas(
 				},
 			})
 			if err := txn.Run(b); err != nil {
+				log.Trace(ctx, err.Error())
 				return err
 			}
 		}
@@ -3123,6 +3124,7 @@ func (r *Replica) ChangeReplicas(
 		}
 		return nil
 	}); err != nil {
+		log.Trace(ctx, err.Error())
 		return errors.Wrapf(err, "change replicas of range %d failed", rangeID)
 	}
 	log.Trace(ctx, "txn complete")

util/log/structured.go

@@ -41,5 +41,6 @@ func makeMessage(format string, args []interface{}) string {
 func addStructured(ctx context.Context, s Severity, depth int, format string, args []interface{}) {
 	file, line, _ := caller.Lookup(depth + 1)
 	msg := makeMessage(format, args)
+	Trace(ctx, msg)
 	logging.outputLogEntry(s, file, line, msg)
 }