search

humanmade / aws-xray

HM Platform AWS X-Ray Integration
23 stars 4 forks source link

Investigate `unable to write to socket [90]: Message too large` #80

Closed owaincuvelier closed 1 year ago

owaincuvelier commented 3 years ago

Seeing a lot of the following warning output.

PHP Warning: socket_sendto(): unable to write to socket [90]: Message too large in /usr/src/app/vendor/humanmade/aws-xray/inc/namespace.php on line 246

Acceptance criteria:

kovshenin commented 2 years ago

A UDP datagram can carry a maximum payload of 65507 bytes, so any message longer than that will cause this error. I noticed we're using mb_strlen() to calculate the message length in characters instead of bytes, although json_encode() should encode them into ASCII anyway, but it could definitely be contributing to the problem.

Related:

We also have logging in place so we should be able to see what the payload was that failed.

rmccue commented 2 years ago

although json_encode() should encode them into ASCII anyway, but it could definitely be contributing to the problem

That'd presumably make the message longer, as eg a three-byte Unicode character like ✅ (0xE2 0x9C 0x85) will be encoded as \u2705 (i.e. 6 bytes).

kovshenin commented 2 years ago

Right, but we're checking mb_strlen() on the encoded string, so in this case both mb_strlen() and strlen() should give identical results because it's all ASCII.

ivankristianto commented 2 years ago

This is happens on one of our project. To replicate the issue, send 4K lines of Post body through ajax. They (user) try to update the ads.txt (from Ads.txt Manager plugin). The content of this is 4K lines of ads.txt content.

This is the trace it try to send (before get flattened):

array(9) {
  ["name"]=>
  string(5) "local"
  ["id"]=>
  string(16) "e74923de3c7d5da4"
  ["trace_id"]=>
  string(35) "1-62d8d51f-de315ed2c7960683a6edfd28"
  ["start_time"]=>
  float(1658377503.7161)
  ["service"]=>
  array(1) {
    ["version"]=>
    string(3) "dev"
  }
  ["origin"]=>
  string(18) "AWS::EC2::Instance"
  ["http"]=>
  array(1) {
    ["request"]=>
    array(3) {
      ["method"]=>
      string(4) "POST"
      ["url"]=>
      string(49) "https://domain.altis.dev/wp-admin/admin-ajax.php"
      ["client_ip"]=>
      string(10) "172.19.0.1"
    }
  }
  ["in_progress"]=>
  bool(true)
  ["metadata"]=>
  array(5) {
    ["$_GET"]=>
    array(0) {
    }
    ["$_POST"]=>
    array(6) {
      ["post_id"]=>
      string(6) "281001"
      ["adstxt_type"]=>
      string(6) "adstxt"
      ["action"]=>
      string(11) "adstxt-save"
      ["_wpnonce"]=>
      string(10) "52deabdbb6"
      ["_wp_http_referer"]=>
      string(50) "/wp-admin/options-general.php?page=adstxt-settings"
      ["adstxt"]=>
      string(184577) "

      4K Lines of ADs.txt data truncated

      "
    }
    ["$_COOKIE"]=>
    array(26) {
      ["wordpress_test_cookie"]=>
      string(15) "WP Cookie check"
      ["cX_P"]=>
      string(16) "l1u5veainu9wsxsj"
      ["cX_S"]=>
      string(16) "l1u5vgl6x8d7ahhs"
      ["__pid"]=>
      string(10) ".altis.dev"
      ["deepbi_firstparty_cookie"]=>
      string(19) "cl1u6zxu11s3v7uc89f"
      ["__pat"]=>
      string(8) "28800000"
      ["pnespsdk_visitor"]=>
      string(60) "nbdzdKkqU1Tso2FtvVAh2UM2cMBp65GAbLUHrRechF3AbOCbRELr9OkAoJfA"
      ["wp-settings-6224"]=>
      string(21) "libraryContent=browse"
      ["wp-settings-time-6224"]=>
      string(10) "1656935527"
      ["ajs_anonymous_id"]=>
      string(8) "5bed7797"
      ["_ain_uid"]=>
      string(31) "1657532995890.667065102.0657748"
      ["_pc_deep_segment"]=>
      string(6) "fly-by"
      ["_ga"]=>
      string(26) "GA1.2.206522950.1657532995"
      ["deepbi_user_deepcookie"]=>
      string(16) "l5gkemp6-1ocks6r"
      ["_ga_GW9LBTZHCB"]=>
      string(34) "GS1.1.1657532994.1.1.1657533745.60"
      ["cX_G"]=>
      string(43) "cx:3vmr8dr6elh8u3gtk8eila2cq7:2dn8j96799zdv"
      ["__tac"]=>
      string(176) "{jax}R-Ulc4hjMSY-Vn8XIV1Fg7XshxJZTcoVV3tCXc03swhLH8liYdv_7EEPiPeOwOdnlu03HZN2DNLSBrVfvY4i_xnjwayUpmvyx5t9yZ6-GGHar0SuyIfM0qvtjMUu6gy16YPrujVW_a3GaVMcG3iySGFoIR0V7b_ZjZetoX_mLHY"
      ["__tae"]=>
      string(13) "1658289218035"
      ["xbc"]=>
      string(390) "{kpex}s_W435QDNFDTyuh1gBkXWX3iSA7RwrcYdjdPL2rST0s4UxXHnPoDYF6hto30HMj4Rhr0M9846QUAWtIXUsElTvv0zgef3tl-ahCy2O1B3qFOuQpoFQwc0SHirOcfXPqetnrti2_pM8GgQKhNjpY_Lz9obXuy_0NVCHRvK0xchjNLGq84bAZTLaTCrkpmsY0paTXfFPYmyoDVQEvfs7bhxFkYvHGITlSCsuG0qTdjkf8peNGpGgnlmYR75kcmrOjE6XW0We-OPxAMEDtSMy1UEcFS1E4mHobcpQjalSXS1Iq8yiUMREEKjFs_t5Xb2b0d5o3rGo34gWP0mG6jtan66LQ9FzNTMkg8CXcqMxu2IQYW8MuNxX6rhHhklwalmvK5"
      ["wordpress_sec_7f8d3d4302914327fb3f13fdf0465367"]=>
      string(124) "ivan|1658543421|mlnoDvwjWvMbw3SpEU7YLHmXMCeVAX05ZkczwMfF9VH|d81c0abb4811b8a8fa27bbd9c07633c3bf1b07d888702caff98be31185509b3e"
      ["wordpress_logged_in_7f8d3d4302914327fb3f13fdf0465367"]=>
      string(124) "ivan|1658543421|mlnoDvwjWvMbw3SpEU7YLHmXMCeVAX05ZkczwMfF9VH|5afa3b58425e346df81b7d050f93b076e61169c064b75cffc957e082f7f6d079"
      ["_pctx"]=>
      string(167) "{u}N4IgDghg5gpgagSxgdwJIBMQC4QBsCsArgGYAshyAnABy4DOALgF4DMMADCADQgBGATgHtkdGPwzY8ARkL4AbjAgIAdoUoiAHnQBW3EIVH862Vblw8DYgMoMIDAycJmedBAxgSclAEy+WLam8aagB2SikQ-GpwkABfIA"
      ["__pvi"]=>
      string(70) "{"id":"v-l5uf4uwp4yv584gz","domain":".altis.dev","time":1658370763897}"
      ["__utp"]=>
      string(491) "eyJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJodHRwczovL2lkLnBpYW5vLmlvIiwic3ViIjoiZmMzMjZhNjItMzI0Yy00NDE3LTkyOWQtNzAzY2U1YTMxYjY0IiwiYXVkIjoia2hCVzNoeFZzdSIsImxvZ2luX3RpbWVzdGFtcCI6IjE2NTc4MTAwNjEyNzgiLCJnaXZlbl9uYW1lIjoiSXZhbiIsImZhbWlseV9uYW1lIjoiSyIsImVtYWlsIjoiaXZhbkBpazIub3JnIiwiZW1haWxfY29uZmlybWF0aW9uX3JlcXVpcmVkIjpmYWxzZSwiZXhwIjoxNjYwNDM4MDYxLCJpYXQiOjE2NTc4MTAwNjEsImp0aSI6IlRJZjh4ckJ5ZHZyZjBtZmgiLCJwYXNzd29yZFR5cGUiOiJwYXNzd29yZCIsInIiOmZhbHNlfQ.QpvhJR8H8wP8hVH-hNmvpxvL386UOyhzd1WTuZOXajk"
      ["__tbc"]=>
      string(156) "{kpex}EyZ6HoELvmeAcZ6XNtUICWz43AsGRS7rNfTCIzGx3cyWl8guofHdvWWGpPLJNmCyeQnPRnVQPEKVlinw9-5C_p2vLRfpRt7xOC6qr-OKwzzStKIG8hx4iC5qigPpPUB5_5PvlkwQVZoc4OmowWf85A"
      ["pnespsdk_ssn"]=>
      string(36) "{"$s":1658370602012,"visitNumber":3}"
    }
    ["$_SERVER"]=>
    array(37) {
      ["HTTP_X_REQUESTED_WITH"]=>
      string(14) "XMLHttpRequest"
      ["HTTP_X_REAL_IP"]=>
      string(10) "172.19.0.1"
      ["HTTP_X_FORWARDED_SERVER"]=>
      string(12) "b8e12fa96eb4"
      ["HTTP_X_FORWARDED_PROTO"]=>
      string(5) "https"
      ["HTTP_X_FORWARDED_PORT"]=>
      string(3) "443"
      ["HTTP_X_FORWARDED_HOST"]=>
      string(17) "domain.altis.dev"
      ["HTTP_X_FORWARDED_FOR"]=>
      string(10) "172.19.0.1"
      ["HTTP_SEC_FETCH_SITE"]=>
      string(11) "same-origin"
      ["HTTP_SEC_FETCH_MODE"]=>
      string(4) "cors"
      ["HTTP_SEC_FETCH_DEST"]=>
      string(5) "empty"
      ["HTTP_SEC_CH_UA_PLATFORM"]=>
      string(7) ""macOS""
      ["HTTP_SEC_CH_UA_MOBILE"]=>
      string(2) "?0"
      ["HTTP_SEC_CH_UA"]=>
      string(57) ""Opera";v="89", "Chromium";v="103", "_Not:A-Brand";v="24""
      ["HTTP_REFERER"]=>
      string(75) "https://domain.altis.dev/wp-admin/options-general.php?page=adstxt-settings"
      ["HTTP_PRAGMA"]=>
      string(8) "no-cache"
      ["HTTP_ORIGIN"]=>
      string(25) "https://domain.altis.dev"
      ["HTTP_DNT"]=>
      string(1) "1"
      ["HTTP_COOKIE"]=>
      string(2598) "wordpress_test_cookie=WP%20Cookie%20check; cX_P=l1u5veainu9wsxsj; cX_S=l1u5vgl6x8d7ahhs; __pid=.altis.dev; deepbi_firstparty_cookie=cl1u6zxu11s3v7uc89f; __pat=28800000; pnespsdk_visitor=nbdzdKkqU1Tso2FtvVAh2UM2cMBp65GAbLUHrRechF3AbOCbRELr9OkAoJfA; wp-settings-6224=libraryContent%3Dbrowse; wp-settings-time-6224=1656935527; ajs_anonymous_id=5bed7797; _ain_uid=1657532995890.667065102.0657748; _pc_deep_segment=fly-by; _ga=GA1.2.206522950.1657532995; deepbi_user_deepcookie=l5gkemp6-1ocks6r; _ga_GW9LBTZHCB=GS1.1.1657532994.1.1.1657533745.60; cX_G=cx%3A3vmr8dr6elh8u3gtk8eila2cq7%3A2dn8j96799zdv; __tac=%7Bjax%7DR-Ulc4hjMSY-Vn8XIV1Fg7XshxJZTcoVV3tCXc03swhLH8liYdv_7EEPiPeOwOdnlu03HZN2DNLSBrVfvY4i_xnjwayUpmvyx5t9yZ6-GGHar0SuyIfM0qvtjMUu6gy16YPrujVW_a3GaVMcG3iySGFoIR0V7b_ZjZetoX_mLHY; __tae=1658289218035; xbc=%7Bkpex%7Ds_W435QDNFDTyuh1gBkXWX3iSA7RwrcYdjdPL2rST0s4UxXHnPoDYF6hto30HMj4Rhr0M9846QUAWtIXUsElTvv0zgef3tl-ahCy2O1B3qFOuQpoFQwc0SHirOcfXPqetnrti2_pM8GgQKhNjpY_Lz9obXuy_0NVCHRvK0xchjNLGq84bAZTLaTCrkpmsY0paTXfFPYmyoDVQEvfs7bhxFkYvHGITlSCsuG0qTdjkf8peNGpGgnlmYR75kcmrOjE6XW0We-OPxAMEDtSMy1UEcFS1E4mHobcpQjalSXS1Iq8yiUMREEKjFs_t5Xb2b0d5o3rGo34gWP0mG6jtan66LQ9FzNTMkg8CXcqMxu2IQYW8MuNxX6rhHhklwalmvK5; wordpress_sec_7f8d3d4302914327fb3f13fdf0465367=ivan%7C1658543421%7CmlnoDvwjWvMbw3SpEU7YLHmXMCeVAX05ZkczwMfF9VH%7Cd81c0abb4811b8a8fa27bbd9c07633c3bf1b07d888702caff98be31185509b3e; wordpress_logged_in_7f8d3d4302914327fb3f13fdf0465367=ivan%7C1658543421%7CmlnoDvwjWvMbw3SpEU7YLHmXMCeVAX05ZkczwMfF9VH%7C5afa3b58425e346df81b7d050f93b076e61169c064b75cffc957e082f7f6d079; _pctx=%7Bu%7DN4IgDghg5gpgagSxgdwJIBMQC4QBsCsArgGYAshyAnABy4DOALgF4DMMADCADQgBGATgHtkdGPwzY8ARkL4AbjAgIAdoUoiAHnQBW3EIVH862Vblw8DYgMoMIDAycJmedBAxgSclAEy%2BWLam8aagB2SikQ-GpwkABfIA; __pvi=%7B%22id%22%3A%22v-l5uf4uwp4yv584gz%22%2C%22domain%22%3A%22.altis.dev%22%2C%22time%22%3A1658370763897%7D; __utp=eyJhbGciOiJIUzI1NiJ9.eyJpc3MiOiJodHRwczovL2lkLnBpYW5vLmlvIiwic3ViIjoiZmMzMjZhNjItMzI0Yy00NDE3LTkyOWQtNzAzY2U1YTMxYjY0IiwiYXVkIjoia2hCVzNoeFZzdSIsImxvZ2luX3RpbWVzdGFtcCI6IjE2NTc4MTAwNjEyNzgiLCJnaXZlbl9uYW1lIjoiSXZhbiIsImZhbWlseV9uYW1lIjoiSyIsImVtYWlsIjoiaXZhbkBpazIub3JnIiwiZW1haWxfY29uZmlybWF0aW9uX3JlcXVpcmVkIjpmYWxzZSwiZXhwIjoxNjYwNDM4MDYxLCJpYXQiOjE2NTc4MTAwNjEsImp0aSI6IlRJZjh4ckJ5ZHZyZjBtZmgiLCJwYXNzd29yZFR5cGUiOiJwYXNzd29yZCIsInIiOmZhbHNlfQ.QpvhJR8H8wP8hVH-hNmvpxvL386UOyhzd1WTuZOXajk; __tbc=%7Bkpex%7DEyZ6HoELvmeAcZ6XNtUICWz43AsGRS7rNfTCIzGx3cyWl8guofHdvWWGpPLJNmCyeQnPRnVQPEKVlinw9-5C_p2vLRfpRt7xOC6qr-OKwzzStKIG8hx4iC5qigPpPUB5_5PvlkwQVZoc4OmowWf85A; pnespsdk_ssn=%7B%22%24s%22%3A1658370602012%2C%22visitNumber%22%3A3%7D"
      ["HTTP_CONTENT_TYPE"]=>
      string(48) "application/x-www-form-urlencoded; charset=UTF-8"
      ["HTTP_CACHE_CONTROL"]=>
      string(8) "no-cache"
      ["HTTP_ACCEPT_LANGUAGE"]=>
      string(14) "en-US,en;q=0.9"
      ["HTTP_ACCEPT_ENCODING"]=>
      string(17) "gzip, deflate, br"
      ["HTTP_ACCEPT"]=>
      string(46) "application/json, text/javascript, */*; q=0.01"
      ["HTTP_CONTENT_LENGTH"]=>
      string(6) "224979"
      ["HTTP_USER_AGENT"]=>
      string(139) "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.5060.114 Safari/537.36 OPR/89.0.4447.48"
      ["HTTP_HOST"]=>
      string(17) "domain.altis.dev"
      ["SERVER_ADDR"]=>
      string(11) "172.19.0.12"
      ["REMOTE_ADDR"]=>
      string(10) "172.19.0.1"
      ["REQUEST_URI"]=>
      string(24) "/wp-admin/admin-ajax.php"
      ["CONTENT_LENGTH"]=>
      string(6) "224979"
      ["CONTENT_TYPE"]=>
      string(48) "application/x-www-form-urlencoded; charset=UTF-8"
      ["REQUEST_METHOD"]=>
      string(4) "POST"
      ["QUERY_STRING"]=>
      string(0) ""
      ["HTTPS"]=>
      string(2) "on"
      ["PHP_SELF"]=>
      string(34) "/wordpress/wp-admin/admin-ajax.php"
      ["REQUEST_TIME_FLOAT"]=>
      float(1658377503.6417)
      ["REQUEST_TIME"]=>
      int(1658377503)
    }
    ["response"]=>
    array(0) {
    }
  }
}

I can assure inside the adstxt data there is no Non ASCII character.

kovshenin commented 2 years ago

Yeah, it doesn't look like we split or truncate the request data (post, cookies, headers) so a 64k body would very likely trigger this error. Might add php://input to metadata while we're at it as $_POST is only useful for multipart/form-data requests, so all of our REST API POST payloads are not being reported.

ivankristianto commented 2 years ago

@kovshenin Do you have any solution or eta for this issue?

kovshenin commented 2 years ago

@ivankristianto no ETA for this problem right now.

I guess if you already know the key that's causing the 64k limit breach, what you could do is use the aws_xray.redact_metadata filter and remove or truncate that specific key:

add_filter( 'aws_xray.redact_metadata', function( $data ) {
    if ( ! empty( $data['$_POST']['adstxt'] ) ) {
        $data['$_POST']['adstxt'] = substr( $data['$_POST']['adstxt'], 0, min( strlen( $data['$_POST']['adstxt'] ), 10000 ) );
    }
    return $data;
} );

Would that work?

roborourke commented 1 year ago

I just ran into this same issue, unfortunately @kovshenin because the plugin calls this before WP is bootstrapped the redact metadata filter isn't reliable:

send_trace_to_daemon( get_in_progress_trace() );

We need to allow setting the redacted meta keys early via a global variable, because it's not actually redacting anything on that initial request right now which isn't good.

That's a slightly separate issue because using redacted metadata is a workaround, though somewhat related.

roborourke commented 1 year ago

Got 2 PRs to help with this issue now. One for redacting data via a global var rather than the filter and one for truncating message metadata when it's too large. Would be great to get reviews on those @ivankristianto or @kovshenin