signalmeow/web/GetAttachment: use structured logging

Signed-off-by: Sumner Evans <[email protected]>

pkg/signalmeow/attachments.go

@@ -57,12 +57,12 @@ func getAttachmentPath(id uint64, key string, cdnNumber uint32) (string, error)
 // ErrInvalidMACForAttachment signals that the downloaded attachment has an invalid MAC.
 var ErrInvalidMACForAttachment = errors.New("invalid MAC for attachment")
 
-func fetchAndDecryptAttachment(a *signalpb.AttachmentPointer) ([]byte, error) {
+func fetchAndDecryptAttachment(ctx context.Context, a *signalpb.AttachmentPointer) ([]byte, error) {
  path, err := getAttachmentPath(a.GetCdnId(), a.GetCdnKey(), a.GetCdnNumber())
  if err != nil {
  return nil, err
  }
- resp, err := web.GetAttachment(path, a.GetCdnNumber(), nil)
+ resp, err := web.GetAttachment(ctx, path, a.GetCdnNumber(), nil)
  if err != nil {
  return nil, err
  }
@@ -134,7 +134,7 @@ func encryptAndUploadAttachment(ctx context.Context, device *Device, body []byte
  return nil, err
  }
  var uploadAttributes attachmentV3UploadAttributes
- err = web.DecodeHTTPResponseBody(&uploadAttributes, resp)
+ err = web.DecodeHTTPResponseBody(ctx, &uploadAttributes, resp)
  if err != nil {
  log.Err(err).Msg("Error decoding response body fetching upload attributes")
  return nil, err

pkg/signalmeow/keys.go

@@ -314,7 +314,7 @@ func FetchAndProcessPreKey(ctx context.Context, device *Device, theirUuid string
  return err
  }
  var prekeyResponse prekeyResponse
- err = web.DecodeHTTPResponseBody(&prekeyResponse, resp)
+ err = web.DecodeHTTPResponseBody(ctx, &prekeyResponse, resp)
  if err != nil {
  zlog.Err(err).Msg("Fetching prekeys, error with response body")
  return err

pkg/signalmeow/receiving.go

@@ -550,7 +550,7 @@ func (d *Device) incomingAPIMessageHandler(ctx context.Context, req *signalpb.We
  zlog.Debug().Msgf("Recieved sync message contacts")
  blob := content.SyncMessage.Contacts.Blob
  if blob != nil {
- contactsBytes, err := fetchAndDecryptAttachment(blob)
+ contactsBytes, err := fetchAndDecryptAttachment(ctx, blob)
  if err != nil {
  zlog.Err(err).Msg("Contacts Sync fetchAndDecryptAttachment error")
  }
@@ -830,7 +830,7 @@ func incomingDataMessage(ctx context.Context, device *Device, dataMessage *signa
  // If there's attachements, handle them (one at a time for now)
  if dataMessage.Attachments != nil {
  for index, attachmentPointer := range dataMessage.Attachments {
- bytes, err := fetchAndDecryptAttachment(attachmentPointer)
+ bytes, err := fetchAndDecryptAttachment(ctx, attachmentPointer)
  if err != nil {
  zlog.Err(err).Msg("fetchAndDecryptAttachment error")
  continue
@@ -891,7 +891,7 @@ func incomingDataMessage(ctx context.Context, device *Device, dataMessage *signa
 
  // if a sticker and has data, send it
  if dataMessage.Sticker != nil && dataMessage.Sticker.Data != nil {
- bytes, err := fetchAndDecryptAttachment(dataMessage.Sticker.Data)
+ bytes, err := fetchAndDecryptAttachment(ctx, dataMessage.Sticker.Data)
  if err != nil {
  zlog.Error().Err(err).Msgf("failed to decrypt sticker: %v", dataMessage.Sticker.Data)
  } else {

pkg/signalmeow/sending.go

@@ -39,7 +39,7 @@ import (
 type SignalContent signalpb.Content
 type AttachmentPointer signalpb.AttachmentPointer
 
-func senderCertificate(d *Device) (*libsignalgo.SenderCertificate, error) {
+func senderCertificate(ctx context.Context, d *Device) (*libsignalgo.SenderCertificate, error) {
  if d.Connection.SenderCertificate != nil {
  // TODO: check for expired certificate
  return d.Connection.SenderCertificate, nil
@@ -56,7 +56,7 @@ func senderCertificate(d *Device) (*libsignalgo.SenderCertificate, error) {
  if err != nil {
  return nil, err
  }
- err = web.DecodeHTTPResponseBody(&r, resp)
+ err = web.DecodeHTTPResponseBody(ctx, &r, resp)
  if err != nil {
  return nil, err
  }
@@ -247,7 +247,7 @@ func buildAuthedMessageToSend(ctx context.Context, d *Device, recipientAddress *
 }
 
 func buildSSMessageToSend(ctx context.Context, d *Device, recipientAddress *libsignalgo.Address, paddedMessage []byte) (envelopeType int, encryptedPayload []byte, err error) {
- cert, err := senderCertificate(d)
+ cert, err := senderCertificate(ctx, d)
  if err != nil {
  return 0, nil, err
  }

pkg/signalmeow/web/web.go

@@ -18,10 +18,12 @@ package web
 
 import (
  "bytes"
+ "context"
  "crypto/tls"
  "crypto/x509"
  "encoding/json"
  "fmt"
+ "io"
  "net/http"
  "net/url"
  "os"
@@ -170,16 +172,17 @@ func SendHTTPRequest(method string, path string, opt *HTTPReqOpt) (*http.Respons
 }
 
 // DecodeHTTPResponseBody checks status code, reads an http.Response's Body and decodes it into the provided interface.
-func DecodeHTTPResponseBody(out any, resp *http.Response) error {
+func DecodeHTTPResponseBody(ctx context.Context, out any, resp *http.Response) error {
  defer resp.Body.Close()
 
  // Check if status code indicates success
  if resp.StatusCode < 200 || resp.StatusCode >= 300 {
  // Read the whole body and log it
- buf := new(bytes.Buffer)
- buf.ReadFrom(resp.Body)
- body := buf.String()
- zlog.Debug().Msgf("Response body: %v", body)
+ body, _ := io.ReadAll(resp.Body)
+ zerolog.Ctx(ctx).Debug().
+ Str("body", string(body)).
+ Int("status_code", resp.StatusCode).
+ Msg("unexpected status code")
  return fmt.Errorf("Unexpected status code: %d %s", resp.StatusCode, resp.Status)
  }
 
@@ -192,7 +195,12 @@ func DecodeHTTPResponseBody(out any, resp *http.Response) error {
 }
 
 // Download an attachment from the CDN
-func GetAttachment(path string, cdnNumber uint32, opt *HTTPReqOpt) (*http.Response, error) {
+func GetAttachment(ctx context.Context, path string, cdnNumber uint32, opt *HTTPReqOpt) (*http.Response, error) {
+ log := zerolog.Ctx(ctx).With().
+ Str("action", "get_attachment").
+ Str("path", path).
+ Uint32("cdn_number", cdnNumber).
+ Logger()
  if opt == nil {
  opt = &HTTPReqOpt{}
  }
@@ -207,21 +215,33 @@ func GetAttachment(path string, cdnNumber uint32, opt *HTTPReqOpt) (*http.Respon
  opt.Host = CDNHosts[cdnNumber]
  } else {
  opt.Host = CDNHosts[0]
- zlog.Warn().Msgf("Invalid CDN index %v, using %s", cdnNumber, opt.Host)
+ log.Warn().Msg("Invalid CDN index")
  }
  }
+ log.Debug().Str("host", opt.Host).Msg("getting attachment")
  urlStr := "https://" + opt.Host + path
- req, err := http.NewRequest("GET", urlStr, nil)
+ req, err := http.NewRequest(http.MethodGet, urlStr, nil)
+ if err != nil {
+ return nil, err
+ }
 
  //const SERVICE_REFLECTOR_HOST = "europe-west1-signal-cdn-reflector.cloudfunctions.net"
  //req.Header.Add("Host", SERVICE_REFLECTOR_HOST)
  req.Header.Add("Content-Type", "application/octet-stream")
 
  httpReqCounter++
- zlog.Debug().Msgf("Sending Attachment HTTP request %v, url: %s", httpReqCounter, urlStr)
+ log = log.With().
+ Int("request_number", httpReqCounter).
+ Str("url", urlStr).
+ Logger()
+
+ log.Debug().Msg("Sending Attachment HTTP request")
  client := proxiedHTTPClient()
  resp, err := client.Do(req)
- zlog.Debug().Msgf("Received Attachment HTTP response %v, status: %v", httpReqCounter, resp.StatusCode)
+ if err != nil {
+ return nil, err
+ }
+ log.Debug().Msg("Received Attachment HTTP response")
 
  return resp, err
 }