add debug logs

bindings/fileTransfer.go

@@ -172,13 +172,11 @@ func InitFileTransfer(e2eID int, receiveFileCallback ReceiveFileCallback,
 		return nil, err
 	}
 
-	jww.INFO.Printf("[FT] Before AddService")
 	// Add file transfer processes to API services tracking
 	err = user.api.AddService(m.StartProcesses)
 	if err != nil {
 		return nil, err
 	}
-	jww.INFO.Printf("[FT] After AddService")
 
 	// Return wrapped manager
 	return &FileTransfer{w: w}, nil
@@ -211,6 +209,7 @@ func (f *FileTransfer) Send(payload, recipientID []byte, retry float32,
 
 	p := time.Millisecond * time.Duration(period)
 
+	jww.INFO.Printf("** FileTransfer.Send before building CB")
 	// Wrap transfer progress callback to be passed to fileTransfer layer
 	cb := func(completed bool, arrived, total uint16,
 		st fileTransfer.SentTransfer, t fileTransfer.FilePartTracker, err error) {
@@ -229,19 +228,22 @@ func (f *FileTransfer) Send(payload, recipientID []byte, retry float32,
 	}
 
 	// Unmarshal payload
-	fs := &FileSend{}
-	err = json.Unmarshal(payload, fs)
-	if err != nil {
+	jww.INFO.Printf("** FileTransfer.Send before unmarshal FileSend")
+	var fs FileSend
+	if err = json.Unmarshal(payload, &fs); err != nil {
 		return nil, err
 	}
 
 	// Send file
-	ftID, err := f.w.Send(recipient, fs.Name, fs.Type, fs.Contents, retry, fs.Preview, cb, p)
+	jww.INFO.Printf("** FileTransfer.Send before send")
+	ftID, err := f.w.Send(
+		recipient, fs.Name, fs.Type, fs.Contents, retry, fs.Preview, cb, p)
 	if err != nil {
 		return nil, err
 	}
 
 	// Return Transfer ID
+	jww.INFO.Printf("** FileTransfer.Send before return")
 	return ftID.Bytes(), nil
 }
 

fileTransfer/e2e/wrapper.go

@@ -8,6 +8,7 @@
 package e2e
 
 import (
+	jww "github.com/spf13/jwalterweatherman"
 	"gitlab.com/elixxir/client/catalog"
 	"gitlab.com/elixxir/client/e2e"
 	"gitlab.com/elixxir/client/e2e/receive"
@@ -90,12 +91,15 @@ func (w *Wrapper) Send(recipient *id.ID, fileName, fileType string,
 	progressCB ft.SentProgressCallback, period time.Duration) (
 	*ftCrypto.TransferID, error) {
 
+	jww.INFO.Printf("** Wrapper.Send before SendNew creation")
 	sendNew := func(transferInfo []byte) error {
 		return sendNewFileTransferMessage(recipient, transferInfo, w.e2e)
 	}
 
+	jww.INFO.Printf("** Wrapper.Send before addEndMessageToCallback")
 	modifiedProgressCB := w.addEndMessageToCallback(progressCB)
 
+	jww.INFO.Printf("** Wrapper.Send before send")
 	return w.ft.Send(recipient, fileName, fileType, fileData, retry, preview,
 		modifiedProgressCB, period, sendNew)
 }
@@ -115,9 +119,13 @@ func (w *Wrapper) RegisterSentProgressCallback(tid *ftCrypto.TransferID,
 // message is not sent.
 func (w *Wrapper) addEndMessageToCallback(
 	progressCB ft.SentProgressCallback) ft.SentProgressCallback {
+	jww.INFO.Printf("** Wrapper.addEndMessageToCallback before !w.p.NotifyUponCompletion")
 	if !w.p.NotifyUponCompletion {
+		jww.INFO.Printf("** Wrapper.addEndMessageToCallback after !w.p.NotifyUponCompletion")
 		return progressCB
 	}
+
+	jww.INFO.Printf("** Wrapper.addEndMessageToCallback before return")
 	return func(completed bool, arrived, total uint16,
 		st ft.SentTransfer, t ft.FilePartTracker, err error) {
 

fileTransfer/manager.go

@@ -270,6 +270,10 @@ func (m *manager) Send(recipient *id.ID, fileName, fileType string,
 	progressCB SentProgressCallback, period time.Duration, sendNew SendNew) (
 	*ftCrypto.TransferID, error) {
 
+	jww.INFO.Printf(
+		"** Sending file transfer %q to %s. fileType:%s retry:%f preview:%q",
+		fileName, recipient, fileType, retry, preview)
+
 	// Return an error if the file name is too long
 	if len(fileName) > FileNameMaxLen {
 		return nil, errors.Errorf(errFileNameSize, len(fileName), FileNameMaxLen)
@@ -291,17 +295,21 @@ func (m *manager) Send(recipient *id.ID, fileName, fileType string,
 	}
 
 	// Return an error if the network is not healthy
+	jww.INFO.Printf("** manager.Send before IsHealthy")
 	if !m.cmix.IsHealthy() {
 		return nil, errors.Errorf(errSendNetworkHealth, fileName)
 	}
 
 	// Generate new transfer key and transfer ID
+	jww.INFO.Printf("** manager.Send before GetStream")
 	rng := m.rng.GetStream()
+	jww.INFO.Printf("** manager.Send before NewTransferKey")
 	key, err := ftCrypto.NewTransferKey(rng)
 	if err != nil {
 		rng.Close()
 		return nil, errors.Errorf(errNewKey, err)
 	}
+	jww.INFO.Printf("** manager.Send before NewTransferID")
 	tid, err := ftCrypto.NewTransferID(rng)
 	if err != nil {
 		rng.Close()
@@ -310,15 +318,18 @@ func (m *manager) Send(recipient *id.ID, fileName, fileType string,
 	rng.Close()
 
 	// Generate transfer MAC
+	jww.INFO.Printf("** manager.Send before CreateTransferMAC")
 	mac := ftCrypto.CreateTransferMAC(fileData, key)
 
 	// Get size of each part and partition file into equal length parts
+	jww.INFO.Printf("** manager.Send before NewPartMessage")
 	partMessage := fileMessage.NewPartMessage(m.cmix.GetMaxMessageLength())
 	parts := partitionFile(fileData, partMessage.GetPartSize())
 	numParts := uint16(len(parts))
 	fileSize := uint32(len(fileData))
 
 	// Send the initial file transfer message over E2E
+	jww.INFO.Printf("** manager.Send before TransferInfo")
 	info := &TransferInfo{
 		fileName, fileType, key, mac, numParts, fileSize, retry, preview}
 	transferInfo, err := info.Marshal()
@@ -334,6 +345,7 @@ func (m *manager) Send(recipient *id.ID, fileName, fileType string,
 	}
 
 	// Calculate the number of fingerprints to generate
+	jww.INFO.Printf("** manager.Send before calcNumberOfFingerprints")
 	numFps := calcNumberOfFingerprints(len(parts), retry)
 
 	// Create new sent transfer
@@ -355,9 +367,11 @@ func (m *manager) Send(recipient *id.ID, fileName, fileType string,
 	for _, p := range st.GetUnsentParts() {
 		m.batchQueue <- p
 	}
+	jww.INFO.Printf("** manager.Send before registerSentProgressCallback")
 
 	// Register the progress callback
 	m.registerSentProgressCallback(st, progressCB, period)
+	jww.INFO.Printf("** manager.Send before return")
 
 	return &tid, nil
 }