Clean up logs and move some functions

libgm/client.go

@@ -123,7 +123,7 @@ func (c *Client) Connect() error {
 	if bugleErr != nil {
 		return fmt.Errorf("failed to check bugle default: %w", err)
 	}
-	c.Logger.Debug().Any("isBugle", bugleRes.Success).Msg("IsBugleDefault")
+	c.Logger.Debug().Bool("bugle_default", bugleRes.Success).Msg("Got is bugle default response on connect")
 	sessionErr := c.SetActiveSession()
 	if sessionErr != nil {
 		return fmt.Errorf("failed to set active session: %w", err)
@@ -145,6 +145,20 @@ func (c *Client) StartLogin() (string, error) {
 	return qr, nil
 }
 
+func (c *Client) GenerateQRCodeData(pairingKey []byte) (string, error) {
+	urlData := &binary.URLData{
+		PairingKey: pairingKey,
+		AESKey:     c.AuthData.RequestCrypto.AESKey,
+		HMACKey:    c.AuthData.RequestCrypto.HMACKey,
+	}
+	encodedURLData, err := proto.Marshal(urlData)
+	if err != nil {
+		return "", err
+	}
+	cData := base64.StdEncoding.EncodeToString(encodedURLData)
+	return util.QRCodeURLBase + cData, nil
+}
+
 func (c *Client) Disconnect() {
 	c.rpc.CloseConnection()
 	c.http.CloseIdleConnections()
@@ -165,10 +179,10 @@ func (c *Client) Reconnect() error {
 	}
 	err := c.Connect()
 	if err != nil {
-		c.Logger.Err(err).Any("tachyonAuthToken", c.AuthData.TachyonAuthToken).Msg("Failed to reconnect")
+		c.Logger.Err(err).Msg("Failed to reconnect")
 		return err
 	}
-	c.Logger.Debug().Any("tachyonAuthToken", c.AuthData.TachyonAuthToken).Msg("Successfully reconnected to server")
+	c.Logger.Debug().Msg("Successfully reconnected to server")
 	return nil
 }
 
@@ -190,9 +204,9 @@ func (c *Client) DownloadMedia(mediaID string, key []byte) ([]byte, error) {
 			ConfigVersion:    util.ConfigMessage,
 		},
 	}
-	downloadMetadataBytes, err2 := proto.Marshal(downloadMetadata)
+	downloadMetadataBytes, err := proto.Marshal(downloadMetadata)
-	if err2 != nil {
+	if err != nil {
-		return nil, err2
+		return nil, err
 	}
 	downloadMetadataEncoded := base64.StdEncoding.EncodeToString(downloadMetadataBytes)
 	req, err := http.NewRequest("GET", util.UploadMediaURL, nil)
@@ -204,13 +218,11 @@ func (c *Client) DownloadMedia(mediaID string, key []byte) ([]byte, error) {
 	if reqErr != nil {
 		return nil, reqErr
 	}
-	c.Logger.Info().Any("url", util.UploadMediaURL).Any("headers", res.Request.Header).Msg("Decrypt Image Headers")
 	defer res.Body.Close()
-	encryptedBuffImg, err3 := io.ReadAll(res.Body)
+	encryptedBuffImg, err := io.ReadAll(res.Body)
-	if err3 != nil {
+	if err != nil {
-		return nil, err3
+		return nil, err
 	}
-	c.Logger.Debug().Any("key", key).Any("encryptedLength", len(encryptedBuffImg)).Msg("Attempting to decrypt image")
 	cryptor, err := crypto.NewImageCryptor(key)
 	if err != nil {
 		return nil, err
@@ -257,7 +269,7 @@ func (c *Client) diffVersionFormat(curr *binary.ConfigVersion, latest *binary.Co
 }
 
 func (c *Client) updateWebEncryptionKey(key []byte) {
-	c.Logger.Debug().Any("key", key).Msg("Updated WebEncryptionKey")
+	c.Logger.Debug().Msg("Updated WebEncryptionKey")
 	c.AuthData.WebEncryptionKey = key
 }
 
@@ -269,14 +281,19 @@ func (c *Client) updateTachyonAuthToken(t []byte, validFor int64) {
 	}
 	c.AuthData.TachyonExpiry = time.Now().UTC().Add(time.Microsecond * time.Duration(validFor))
 	c.AuthData.TachyonTTL = validForDuration.Microseconds()
-	c.Logger.Debug().Time("tachyon_expiry", c.AuthData.TachyonExpiry).Int64("valid_for", validFor).Msg("Updated tachyon token")
+	c.Logger.Debug().
+		Time("tachyon_expiry", c.AuthData.TachyonExpiry).
+		Int64("valid_for", validFor).
+		Msg("Updated tachyon token")
 }
 
 func (c *Client) refreshAuthToken() error {
 	if c.AuthData.Browser == nil || time.Until(c.AuthData.TachyonExpiry) > RefreshTachyonBuffer {
 		return nil
 	}
-	c.Logger.Debug().Time("tachyon_expiry", c.AuthData.TachyonExpiry).Msg("Refreshing auth token")
+	c.Logger.Debug().
+		Time("tachyon_expiry", c.AuthData.TachyonExpiry).
+		Msg("Refreshing auth token")
 	jwk := c.AuthData.RefreshKey
 	requestID := uuid.NewString()
 	timestamp := time.Now().UnixMilli() * 1000

libgm/event_handler.go

@@ -77,11 +77,6 @@ func (r *RPC) HandleRPCMsg(msg *binary.InternalMessage) {
 		}
 		r.client.handleUpdatesEvent(response)
 	default:
-		r.client.Logger.Debug().Any("res", response).Msg("Got unknown bugleroute")
+		r.client.Logger.Debug().Any("res", response).Msg("Got unknown bugle route")
 	}
-
-}
-
-func (r *RPC) HandleByLength(data []byte) {
-	r.client.Logger.Debug().Any("byteLength", len(data)).Any("corrupt raw", string(data)).Msg("RPC Corrupt json")
 }

libgm/media_processor.go

@@ -1,146 +0,0 @@
-package libgm
-
-import (
-	"bytes"
-	"encoding/base64"
-	"errors"
-	"io"
-	"net/http"
-	"strconv"
-
-	"github.com/google/uuid"
-	"google.golang.org/protobuf/proto"
-
-	"go.mau.fi/mautrix-gmessages/libgm/binary"
-	"go.mau.fi/mautrix-gmessages/libgm/util"
-)
-
-type StartGoogleUpload struct {
-	UploadID         string
-	UploadURL        string
-	UploadStatus     string
-	ChunkGranularity int64
-	ControlURL       string
-	MimeType         string
-
-	EncryptedMediaBytes []byte
-}
-
-type MediaUpload struct {
-	MediaID     string
-	MediaNumber int64
-}
-
-var (
-	errStartUploadMedia    = errors.New("failed to start uploading media")
-	errFinalizeUploadMedia = errors.New("failed to finalize uploading media")
-)
-
-func (c *Client) FinalizeUploadMedia(upload *StartGoogleUpload) (*MediaUpload, error) {
-	encryptedImageSize := strconv.Itoa(len(upload.EncryptedMediaBytes))
-
-	finalizeUploadHeaders := util.NewMediaUploadHeaders(encryptedImageSize, "upload, finalize", "0", upload.MimeType, "")
-	req, reqErr := http.NewRequest("POST", upload.UploadURL, bytes.NewBuffer(upload.EncryptedMediaBytes))
-	if reqErr != nil {
-		return nil, reqErr
-	}
-
-	req.Header = *finalizeUploadHeaders
-
-	res, resErr := c.http.Do(req)
-	if resErr != nil {
-		panic(resErr)
-	}
-
-	statusCode := res.StatusCode
-	if statusCode != 200 {
-		return nil, errFinalizeUploadMedia
-	}
-
-	defer res.Body.Close()
-
-	rHeaders := res.Header
-	googleResponse, err3 := io.ReadAll(base64.NewDecoder(base64.StdEncoding, res.Body))
-	if err3 != nil {
-		return nil, err3
-	}
-
-	uploadStatus := rHeaders.Get("x-goog-upload-status")
-	c.Logger.Debug().Str("upload_status", uploadStatus).Msg("Upload complete")
-
-	mediaIDs := &binary.UploadMediaResponse{}
-	err3 = proto.Unmarshal(googleResponse, mediaIDs)
-	if err3 != nil {
-		return nil, err3
-	}
-	return &MediaUpload{
-		MediaID:     mediaIDs.Media.MediaID,
-		MediaNumber: mediaIDs.Media.MediaNumber,
-	}, nil
-}
-
-func (c *Client) StartUploadMedia(encryptedImageBytes []byte, mime string) (*StartGoogleUpload, error) {
-	encryptedImageSize := strconv.Itoa(len(encryptedImageBytes))
-
-	startUploadHeaders := util.NewMediaUploadHeaders(encryptedImageSize, "start", "", mime, "resumable")
-	startUploadPayload, buildPayloadErr := c.buildStartUploadPayload()
-	if buildPayloadErr != nil {
-		return nil, buildPayloadErr
-	}
-
-	req, reqErr := http.NewRequest("POST", util.UploadMediaURL, bytes.NewBuffer([]byte(startUploadPayload)))
-	if reqErr != nil {
-		return nil, reqErr
-	}
-
-	req.Header = *startUploadHeaders
-
-	res, resErr := c.http.Do(req)
-	if resErr != nil {
-		panic(resErr)
-	}
-
-	statusCode := res.StatusCode
-	if statusCode != 200 {
-		return nil, errStartUploadMedia
-	}
-
-	rHeaders := res.Header
-
-	chunkGranularity, convertErr := strconv.Atoi(rHeaders.Get("x-goog-upload-chunk-granularity"))
-	if convertErr != nil {
-		return nil, convertErr
-	}
-
-	uploadResponse := &StartGoogleUpload{
-		UploadID:         rHeaders.Get("x-guploader-uploadid"),
-		UploadURL:        rHeaders.Get("x-goog-upload-url"),
-		UploadStatus:     rHeaders.Get("x-goog-upload-status"),
-		ChunkGranularity: int64(chunkGranularity),
-		ControlURL:       rHeaders.Get("x-goog-upload-control-url"),
-		MimeType:         mime,
-
-		EncryptedMediaBytes: encryptedImageBytes,
-	}
-	return uploadResponse, nil
-}
-
-func (c *Client) buildStartUploadPayload() (string, error) {
-	protoData := &binary.StartMediaUploadPayload{
-		ImageType: 1,
-		AuthData: &binary.AuthMessage{
-			RequestID:        uuid.NewString(),
-			TachyonAuthToken: c.AuthData.TachyonAuthToken,
-			ConfigVersion:    util.ConfigMessage,
-		},
-		Mobile: c.AuthData.Mobile,
-	}
-
-	protoDataBytes, err := proto.Marshal(protoData)
-	if err != nil {
-		return "", err
-	}
-	protoDataEncoded := base64.StdEncoding.EncodeToString(protoDataBytes)
-
-	return protoDataEncoded, nil
-}

libgm/pair.go

@@ -34,12 +34,10 @@ func (c *Client) RegisterPhoneRelay() (*binary.RegisterPhoneRelayResponse, error
 		},
 	})
 	if err != nil {
-		c.Logger.Err(err)
 		return nil, err
 	}
 	relayResponse, reqErr := c.MakeRelayRequest(util.RegisterPhoneRelayURL, body)
 	if reqErr != nil {
-		c.Logger.Err(reqErr)
 		return nil, err
 	}
 	responseBody, err := io.ReadAll(relayResponse.Body)

libgm/pairing_handler.go

@@ -11,9 +11,8 @@ import (
 
 func (c *Client) handlePairingEvent(response *pblite.Response) {
 	pairEventData, ok := response.Data.Decrypted.(*binary.PairEvents)
-
 	if !ok {
-		c.Logger.Error().Any("pairEventData", pairEventData).Msg("failed to assert response into PairEvents")
+		c.Logger.Error().Type("decrypted_type", response.Data.Decrypted).Msg("Unexpected data type in pair event")
 		return
 	}
 
@@ -21,10 +20,9 @@ func (c *Client) handlePairingEvent(response *pblite.Response) {
 	case *binary.PairEvents_Paired:
 		c.completePairing(evt.Paired)
 	case *binary.PairEvents_Revoked:
-		c.Logger.Debug().Any("data", evt).Msg("Revoked Device")
 		c.triggerEvent(evt.Revoked)
 	default:
-		c.Logger.Debug().Any("response", response).Any("evt", evt).Msg("Invalid PairEvents type")
+		c.Logger.Debug().Any("evt", evt).Msg("Unknown pair event type")
 	}
 }
 

libgm/qr.go

@@ -1,24 +0,0 @@
-package libgm
-
-import (
-	"encoding/base64"
-
-	"google.golang.org/protobuf/proto"
-
-	"go.mau.fi/mautrix-gmessages/libgm/binary"
-	"go.mau.fi/mautrix-gmessages/libgm/util"
-)
-
-func (c *Client) GenerateQRCodeData(pairingKey []byte) (string, error) {
-	urlData := &binary.URLData{
-		PairingKey: pairingKey,
-		AESKey:     c.AuthData.RequestCrypto.AESKey,
-		HMACKey:    c.AuthData.RequestCrypto.HMACKey,
-	}
-	encodedURLData, err := proto.Marshal(urlData)
-	if err != nil {
-		return "", err
-	}
-	cData := base64.StdEncoding.EncodeToString(encodedURLData)
-	return util.QRCodeURLBase + cData, nil
-}

libgm/rpc.go

@@ -155,7 +155,7 @@ func (r *RPC) startReadingData(rc io.ReadCloser) {
 		}
 		accumulatedData = append(accumulatedData, chunk...)
 		if !json.Valid(accumulatedData) {
-			r.client.Logger.Debug().Str("data", string(chunk)).Msg("Invalid JSON")
+			r.client.Logger.Trace().Bytes("data", chunk).Msg("Invalid JSON, reading next chunk")
 			continue
 		}
 		currentBlock := accumulatedData

libgm/updates_handler.go

@@ -12,7 +12,7 @@ func (c *Client) handleUpdatesEvent(res *pblite.Response) {
 	case binary.ActionType_GET_UPDATES:
 		data, ok := res.Data.Decrypted.(*binary.UpdateEvents)
 		if !ok {
-			c.Logger.Error().Any("res", res).Msg("failed to assert ActionType_GET_UPDATES event into UpdateEvents")
+			c.Logger.Error().Type("data_type", res.Data.Decrypted).Msg("Unexpected data type in GET_UPDATES event")
 			return
 		}
 
@@ -40,17 +40,16 @@ func (c *Client) handleUpdatesEvent(res *pblite.Response) {
 		case *binary.UpdateEvents_TypingEvent:
 			c.rpc.logContent(res)
 			c.triggerEvent(evt.TypingEvent.GetData())
-		default:
-			c.Logger.Debug().Any("evt", evt).Any("res", res).Msg("Got unknown event type")
-		}
 
+		default:
+			c.Logger.Trace().Any("evt", evt).Msg("Got unknown event type")
+		}
 	default:
-		c.Logger.Error().Any("response", res).Msg("ignoring response.")
+		c.Logger.Trace().Any("response", res).Msg("Got unexpected response")
 	}
 }
 
 func (c *Client) handleClientReady(newSessionId string) {
-	c.Logger.Info().Any("sessionId", newSessionId).Msg("Client is ready!")
 	conversations, convErr := c.ListConversations(25, binary.ListConversationsPayload_INBOX)
 	if convErr != nil {
 		panic(convErr)
@@ -67,13 +66,13 @@ func (c *Client) handleUserAlertEvent(res *pblite.Response, data *binary.UserAle
 	alertType := data.AlertType
 	switch alertType {
 	case binary.AlertType_BROWSER_ACTIVE:
-		newSessionId := res.Data.RequestID
+		newSessionID := res.Data.RequestID
-		c.Logger.Info().Any("sessionId", newSessionId).Msg("[NEW_BROWSER_ACTIVE] Opened new browser connection")
+		c.Logger.Debug().Any("session_id", newSessionID).Msg("Got browser active notification")
-		if newSessionId != c.sessionHandler.sessionID {
+		if newSessionID != c.sessionHandler.sessionID {
-			evt := events.NewBrowserActive(newSessionId)
+			evt := events.NewBrowserActive(newSessionID)
 			c.triggerEvent(evt)
 		} else {
-			go c.handleClientReady(newSessionId)
+			go c.handleClientReady(newSessionID)
 		}
 	default:
 		c.triggerEvent(data)

libgm/upload.go

@@ -1,10 +1,20 @@
 package libgm
 
 import (
+	"bytes"
+	"encoding/base64"
+	"errors"
+	"io"
+	"net/http"
+	"strconv"
 	"strings"
 
+	"github.com/google/uuid"
+	"google.golang.org/protobuf/proto"
+
 	"go.mau.fi/mautrix-gmessages/libgm/binary"
 	"go.mau.fi/mautrix-gmessages/libgm/crypto"
+	"go.mau.fi/mautrix-gmessages/libgm/util"
 )
 
 type MediaType struct {
@@ -107,3 +117,133 @@ func (c *Client) UploadMedia(data []byte, fileName, mime string) (*binary.MediaC
 		DecryptionKey: decryptionKey,
 	}, nil
 }
+
+type StartGoogleUpload struct {
+	UploadID         string
+	UploadURL        string
+	UploadStatus     string
+	ChunkGranularity int64
+	ControlURL       string
+	MimeType         string
+
+	EncryptedMediaBytes []byte
+}
+
+type MediaUpload struct {
+	MediaID     string
+	MediaNumber int64
+}
+
+var (
+	errStartUploadMedia    = errors.New("failed to start uploading media")
+	errFinalizeUploadMedia = errors.New("failed to finalize uploading media")
+)
+
+func (c *Client) FinalizeUploadMedia(upload *StartGoogleUpload) (*MediaUpload, error) {
+	encryptedImageSize := strconv.Itoa(len(upload.EncryptedMediaBytes))
+
+	finalizeUploadHeaders := util.NewMediaUploadHeaders(encryptedImageSize, "upload, finalize", "0", upload.MimeType, "")
+	req, reqErr := http.NewRequest("POST", upload.UploadURL, bytes.NewBuffer(upload.EncryptedMediaBytes))
+	if reqErr != nil {
+		return nil, reqErr
+	}
+
+	req.Header = *finalizeUploadHeaders
+
+	res, resErr := c.http.Do(req)
+	if resErr != nil {
+		panic(resErr)
+	}
+
+	statusCode := res.StatusCode
+	if statusCode != 200 {
+		return nil, errFinalizeUploadMedia
+	}
+
+	defer res.Body.Close()
+
+	rHeaders := res.Header
+	googleResponse, err3 := io.ReadAll(base64.NewDecoder(base64.StdEncoding, res.Body))
+	if err3 != nil {
+		return nil, err3
+	}
+
+	uploadStatus := rHeaders.Get("x-goog-upload-status")
+	c.Logger.Debug().Str("upload_status", uploadStatus).Msg("Upload complete")
+
+	mediaIDs := &binary.UploadMediaResponse{}
+	err3 = proto.Unmarshal(googleResponse, mediaIDs)
+	if err3 != nil {
+		return nil, err3
+	}
+	return &MediaUpload{
+		MediaID:     mediaIDs.Media.MediaID,
+		MediaNumber: mediaIDs.Media.MediaNumber,
+	}, nil
+}
+
+func (c *Client) StartUploadMedia(encryptedImageBytes []byte, mime string) (*StartGoogleUpload, error) {
+	encryptedImageSize := strconv.Itoa(len(encryptedImageBytes))
+
+	startUploadHeaders := util.NewMediaUploadHeaders(encryptedImageSize, "start", "", mime, "resumable")
+	startUploadPayload, buildPayloadErr := c.buildStartUploadPayload()
+	if buildPayloadErr != nil {
+		return nil, buildPayloadErr
+	}
+
+	req, reqErr := http.NewRequest("POST", util.UploadMediaURL, bytes.NewBuffer([]byte(startUploadPayload)))
+	if reqErr != nil {
+		return nil, reqErr
+	}
+
+	req.Header = *startUploadHeaders
+
+	res, resErr := c.http.Do(req)
+	if resErr != nil {
+		panic(resErr)
+	}
+
+	statusCode := res.StatusCode
+	if statusCode != 200 {
+		return nil, errStartUploadMedia
+	}
+
+	rHeaders := res.Header
+
+	chunkGranularity, convertErr := strconv.Atoi(rHeaders.Get("x-goog-upload-chunk-granularity"))
+	if convertErr != nil {
+		return nil, convertErr
+	}
+
+	uploadResponse := &StartGoogleUpload{
+		UploadID:         rHeaders.Get("x-guploader-uploadid"),
+		UploadURL:        rHeaders.Get("x-goog-upload-url"),
+		UploadStatus:     rHeaders.Get("x-goog-upload-status"),
+		ChunkGranularity: int64(chunkGranularity),
+		ControlURL:       rHeaders.Get("x-goog-upload-control-url"),
+		MimeType:         mime,
+
+		EncryptedMediaBytes: encryptedImageBytes,
+	}
+	return uploadResponse, nil
+}
+
+func (c *Client) buildStartUploadPayload() (string, error) {
+	protoData := &binary.StartMediaUploadPayload{
+		ImageType: 1,
+		AuthData: &binary.AuthMessage{
+			RequestID:        uuid.NewString(),
+			TachyonAuthToken: c.AuthData.TachyonAuthToken,
+			ConfigVersion:    util.ConfigMessage,
+		},
+		Mobile: c.AuthData.Mobile,
+	}
+
+	protoDataBytes, err := proto.Marshal(protoData)
+	if err != nil {
+		return "", err
+	}
+	protoDataEncoded := base64.StdEncoding.EncodeToString(protoDataBytes)
+
+	return protoDataEncoded, nil
+}