Uploaded image for project: 'Traffic Server'
  1. Traffic Server
  2. TS-4911

ATS restarts when ts_lua plugin is used with collapsed_forwarding plugin and write lock error was encountered (thundering herd problem)

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 6.2.1, 7.0.0, 7.1.0
    • Fix Version/s: 6.2.1, 7.0.0
    • Component/s: Lua, Plugins
    • Labels:
      None

      Description

      ATS (ts_lua plugin is used along with collapsed_forwarding plugin) got restarted due to “FATAL: InkAPI.cc:3800: failed assert `sdk_sanity_check_http_hdr_handle(obj) == TS_SUCCESS`” when write lock error was encountered (thundering herd problem). The ATS restart is due to ts.client_response.get_status() function call in TS_LUA_HOOK_SEND_RESPONSE_HDR hook function when re-direct is enabled on 502 error.

      == error when ts_lua plugin is used with collapsed_forwarding plugin ==
      map http://testurl.com/ http://origin.com/ @plugin=tslua.so @pparam=/opt/trafficserver/etc/trafficserver/lua/test.lua @plugin=collapsed_forwarding.so @pparam=-delay=10 @pparam=-retries=5

      test.lua:
      =======
      function _init_()
      local FUNCTION = '_init_(): '
      ts.debug(FUNCTION .. 'Entering..')

      return 0
      end

      function responseHook()

      local FUNCTION = 'responseHook(): '

      ts.debug(FUNCTION .. 'Entering..')
      local c_code = tostring(ts.client_response.get_status())
      ts.debug(FUNCTION .. 'Original client_response_code: ' .. c_code)
      if string.find(c_code, "^[45]") then
      ts.debug(FUNCTION .. 'client response code is now set to 500')
      ts.client_response.set_status(500)
      end
      return 0

      end

      function do_remap()
      local FUNCTION = 'do_remap(): '

      ts.debug(FUNCTION .. 'Entering..')
      ts.hook(TS_LUA_HOOK_SEND_RESPONSE_HDR, responseHook)
      return 0
      end
      ========================================================

      The log…

      [Sep 20 19:53:43.746] Server

      {0x2ad69673e700} DEBUG: (http) [148] State Transition: SM_ACTION_AP_CACHE_LOOKUP_COMPLETE -> SM_ACTION_SERVE_FROM_CACHE
      [Sep 20 19:53:43.746] Server {0x2ad69673e700}

      DEBUG: (http) [148] perform_cache_write_action CACE_DO_SERVE
      [Sep 20 19:53:43.746] Server

      {0x2ad69673e700} DEBUG: (http_redirect) is_redirect_required 1
      [Sep 20 19:53:43.746] Server {0x2ad69673e700}

      DEBUG: (http) [148] calling plugin on hook TS_HTTPSEND_RESPONSE_HDR_HOOK at hook 0x1832bc0
      [Sep 20 19:53:43.746] Server

      {0x2ad69673e700}

      DIAG: (ts_lua) responseHook(): Entering..
      FATAL: InkAPI.cc:3800: failed assert `sdk_sanity_check_http_hdr_handle(obj) == TS_SUCCESS`
      traffic_server: using root directory '/opt/trafficserver'
      validate_filter_args: "action=deny"
      -----------------------------------------------------------------------------------------
      Filter "<NONAME>" status: allow_flag=false, src_ip_valid=false, in_ip_valid=false, internal=false active_queue_flag=0
      standard methods=nonstandard methods=
      src_ip_cnt=0
      in_ip_cnt=0

      URL Rewrite table with 3 entries
      Reverse Proxy is On
      Forward Mapping Table with 3 entries
      http:/// => http://127.0.0.1/ <> [plugins not enabled; running with 0 plugins]
      http://xx.xx.xx.xx/ => http://xx.xx.xx.xx/ <> [plugins are enabled; running with plugins]
      http://testurl.com/ => http://origin.com// <> [plugins are enabled; running with 2 plugins]
      Reverse Mapping Table with 0 entries
      Permanent Redirect Mapping Table with 0 entries
      Temporary Redirect Mapping Table with 0 entries
      Forward Mapping With Recv Port Table with 0 entries
      Referer filter default redirect URL: "http://www.example.com/"
      traffic_server: Aborted (Signal sent by tkill() 129399 99)
      traffic_server - STACK TRACE:
      /opt/trafficserver/bin/traffic_server(_Z19crash_logger_invokeiP9siginfo_tPv+0x8e)[0x4ab5ee]
      /lib64/libpthread.so.0(+0xf100)[0x2ad67f3eb100]
      /lib64/libc.so.6(gsignal+0x37)[0x2ad6803bb5f7]
      /lib64/libc.so.6(abort+0x148)[0x2ad6803bcce8]
      /opt/trafficserver/lib/libtsutil.so.6(+0x28668)[0x2ad67d927668]
      /opt/trafficserver/lib/libtsutil.so.6(+0x286fc)[0x2ad67d9276fc]
      /opt/trafficserver/lib/libtsutil.so.6(+0x269e5)[0x2ad67d9259e5]
      /opt/trafficserver/bin/traffic_server[0x4c7973]
      /opt/trafficserver/libexec/trafficserver/tslua.so(+0x9aeb)[0x2ad695821aeb]
      /opt/trafficserver/bin/traffic_server[0x5834e6]

      ========================================================

      It appears, the following code in ts_lua [ts_lua_client_response.c] plugin causes the sdk_sanity check failed.
      #define TS_LUA_CHECK_CLIENT_RESPONSE_HDR(http_ctx) \
      do { \
      if (!http_ctx->client_response_hdrp) { \
      if (TSHttpTxnClientRespGet(http_ctx->txnp, &http_ctx->client_response_bufp, &http_ctx->client_response_hdrp) != \
      TS_SUCCESS)

      { \ return 0; \ }

      \
      } \
      } while (0)
      ….
      ….
      static int
      ts_lua_client_response_get_status(lua_State *L)
      {
      int status;
      ts_lua_http_ctx *http_ctx;

      GET_HTTP_CONTEXT(http_ctx, L);

      TS_LUA_CHECK_CLIENT_RESPONSE_HDR(http_ctx);

      status = TSHttpHdrStatusGet(http_ctx->client_response_bufp, http_ctx->client_response_hdrp);

      lua_pushinteger(L, status);

      return 1;
      }
      ….

        Attachments

          Activity

            People

            • Assignee:
              kichan Kit Chan
              Reporter:
              rkishore Rajendra Kishore Bonumahanti
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Time Tracking

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0h
                0h
                Logged:
                Time Spent - 4h 20m
                4h 20m