← Back to branch summary

~ubuntu-branches/ubuntu/wily/trafficserver/wily

« back to all changes in this revision

Viewing changes to proxy/http/HttpSM.cc

  • Committer: Package Import Robot
  • Author(s): Adam Conrad
  • Date: 2012-12-17 22:28:16 UTC
  • mfrom: (5.1.8 raring-proposed)
  • Revision ID: package-import@ubuntu.com-20121217222816-7xwjsx5k76zkb63d
Tags: 3.2.0-1ubuntu1
* Revert FreeBSD strerror_r() fixes that give errors with glibc 2.16.
* Apply patch from Konstantinos Margaritis to define barriers on ARM.

Show diffs side-by-side

added added

removed removed

Lines of Context:
proxy/http/HttpSM.cc
37
37
#include "PluginVC.h"
38
38
#include "ReverseProxy.h"
39
39
#include "RemapProcessor.h"
 
40
#include "Transform.h"
40
41
 
41
42
#include "HttpPages.h"
42
43
 
87
88
static uint16_t to[MAX_SCATTER_LEN];
88
89
static int scat_count = 0;
89
90
 
 
91
static const char bound[] = "RANGE_SEPARATOR";
 
92
static char const cont_type[] = "Content-type: ";
 
93
static char const cont_range[] = "Content-range: bytes ";
 
94
static const int sub_header_size = sizeof(cont_type) - 1 + 2 + sizeof(cont_range) - 1 + 4;
 
95
static const int boundary_size = 2 + sizeof(bound) - 1 + 2;
90
96
 
91
97
/**
92
98
 * Takes two milestones and returns the difference.
275
281
#define __REMEMBER(x)  #x
276
282
#define _REMEMBER(x)   __REMEMBER(x)
277
283
 
278
 
#if defined(_WIN32)
279
 
// Proper macro expansion is beyond Visual C++
280
 
#define RECORD_FILE_LINE() \
281
 
history[pos].fileline = __FILE__; \
282
 
history[pos].line = __LINE__;
283
 
#else
284
284
#define RECORD_FILE_LINE() \
285
285
history[pos].fileline = __FILE__ ":" _REMEMBER (__LINE__);
286
 
#endif
287
286
 
288
287
#define REMEMBER(e,r) \
289
288
{ if (REMEMBER_EVENT_FILTER(e)) { \
290
289
    add_history_entry(__FILE__ ":" _REMEMBER (__LINE__), e, r); }}
291
290
 
 
291
#define DebugSM(tag, ...) DebugSpecific(debug_on, tag, __VA_ARGS__)
 
292
 
292
293
#ifdef STATE_ENTER
293
294
#undef STATE_ENTER
294
295
#endif
295
296
#define STATE_ENTER(state_name, event) { \
296
297
    /*ink_debug_assert (magic == HTTP_SM_MAGIC_ALIVE); */ REMEMBER (event, reentrancy_count);  \
297
 
        Debug("http", "[%" PRId64 "] [%s, %s]", sm_id, \
 
298
        DebugSM("http", "[%" PRId64 "] [%s, %s]", sm_id, \
298
299
        #state_name, HttpDebugNames::get_event_name(event)); }
299
300
 
300
301
#define HTTP_SM_SET_DEFAULT_HANDLER(_h) \
310
311
  : Continuation(NULL), sm_id(-1), magic(HTTP_SM_MAGIC_DEAD),
311
312
    //YTS Team, yamsat Plugin
312
313
    enable_redirection(false), api_enable_redirection(true), redirect_url(NULL), redirect_url_len(0), redirection_tries(0), transfered_bytes(0),
313
 
    post_failed(false),
 
314
    post_failed(false), debug_on(false),
314
315
    plugin_tunnel_type(HTTP_NO_PLUGIN_TUNNEL),
315
316
    plugin_tunnel(NULL), reentrancy_count(0),
316
317
    history_pos(0), tunnel(), ua_entry(NULL),
324
325
    server_request_hdr_bytes(0), server_request_body_bytes(0),
325
326
    server_response_hdr_bytes(0), server_response_body_bytes(0),
326
327
    client_response_hdr_bytes(0), client_response_body_bytes(0),
 
328
    cache_response_hdr_bytes(0), cache_response_body_bytes(0),
327
329
    pushed_response_hdr_bytes(0), pushed_response_body_bytes(0),
328
330
    hooks_set(0), cur_hook_id(TS_HTTP_LAST_HOOK), cur_hook(NULL),
329
331
    cur_hooks(0), callout_state(HTTP_API_NO_CALLOUT), terminate_sm(false), kill_this_async_done(false)
360
362
    delete second_cache_sm;
361
363
  }
362
364
  magic = HTTP_SM_MAGIC_DEAD;
 
365
  debug_on = false;
363
366
}
364
367
 
365
368
void
478
481
    if (result == false) {
479
482
      t_state.cache_info.action = HttpTransact::CACHE_DO_NO_ACTION;
480
483
    } else
481
 
      Debug("http_cache_write", "[%" PRId64 "] cache write decide to use URL %s", sm_id, s_url->string_get(&t_state.arena));
 
484
      DebugSM("http_cache_write", "[%" PRId64 "] cache write decide to use URL %s", sm_id, s_url->string_get(&t_state.arena));
482
485
  }
483
486
 
484
487
  return result;
588
591
 
589
592
  ua_session = client_vc;
590
593
  mutex = client_vc->mutex;
 
594
  if (ua_session->debug_on) debug_on = true;
591
595
 
592
596
  start_sub_sm();
593
597
 
599
603
 
600
604
  NetVConnection* netvc = client_vc->get_netvc();
601
605
 
602
 
  t_state.client_info.ip = netvc->get_remote_ip();
 
606
  ats_ip_copy(&t_state.client_info.addr, netvc->get_remote_addr());
603
607
  t_state.client_info.port = netvc->get_local_port();
604
608
  t_state.client_info.is_transparent = netvc->get_is_transparent();
605
609
  t_state.backdoor_request = client_vc->backdoor_connect;
606
 
  memset(&(t_state.client_info.addr), 0, sizeof(t_state.client_info.addr));
607
 
  t_state.client_info.addr = *client_vc->get_netvc()->get_remote_addr();
608
 
  t_state.client_info.port_attribute = (HttpPortTypes) netvc->attributes;
 
610
  t_state.client_info.port_attribute = static_cast<HttpProxyPort::TransportType>(netvc->attributes);
609
611
 
610
612
  HTTP_INCREMENT_DYN_STAT(http_current_client_transactions_stat);
611
613
 
671
673
  int bytes_used = 0;
672
674
  ink_assert(ua_entry->eos == false);
673
675
 
674
 
 
675
676
  switch (event) {
676
 
  case VC_EVENT_EOS:
677
 
    ua_entry->eos = true;
678
 
    // Fall through
679
677
  case VC_EVENT_READ_READY:
680
678
  case VC_EVENT_READ_COMPLETE:
681
679
    // More data to parse
682
680
    break;
683
681
 
 
682
  case VC_EVENT_EOS:
 
683
    ua_entry->eos = true;
 
684
    if (client_request_hdr_bytes !=0)
 
685
      break;
 
686
    // Fall through
684
687
  case VC_EVENT_ERROR:
685
688
  case VC_EVENT_INACTIVITY_TIMEOUT:
686
689
  case VC_EVENT_ACTIVE_TIMEOUT:
718
721
 
719
722
  // Check to see if we are over the hdr size limit
720
723
  if (client_request_hdr_bytes > t_state.http_config_param->request_hdr_max_size) {
721
 
    Debug("http", "client header bytes were over max header size; treating as a bad request");
 
724
    DebugSM("http", "client header bytes were over max header size; treating as a bad request");
722
725
    state = PARSE_ERROR;
723
726
  }
724
727
  // Check to see if we are done parsing the header
730
733
 
731
734
  switch (state) {
732
735
  case PARSE_ERROR:
733
 
    Debug("http", "[%" PRId64 "] error parsing client request header", sm_id);
 
736
    DebugSM("http", "[%" PRId64 "] error parsing client request header", sm_id);
734
737
 
735
738
    // Disable further I/O on the client
736
739
    ua_entry->read_vio->nbytes = ua_entry->read_vio->ndone;
740
743
 
741
744
  case PARSE_CONT:
742
745
    if (ua_entry->eos) {
743
 
      Debug("http_seq", "[%" PRId64 "] EOS before client request parsing finished", sm_id);
 
746
      DebugSM("http_seq", "[%" PRId64 "] EOS before client request parsing finished", sm_id);
744
747
      set_ua_abort(HttpTransact::ABORTED, event);
745
748
 
746
749
      // Disable further I/O on the client
753
756
      return VC_EVENT_CONT;
754
757
    }
755
758
  case PARSE_DONE:
756
 
    Debug("http", "[%" PRId64 "] done parsing client request header", sm_id);
 
759
    DebugSM("http", "[%" PRId64 "] done parsing client request header", sm_id);
757
760
 
758
761
    if (ua_session->m_active == false) {
759
762
      ua_session->m_active = true;
865
868
        //  where the tunnel is not active
866
869
        HttpTunnelConsumer *c = tunnel.get_consumer(ua_session);
867
870
        if (c && c->alive) {
868
 
          Debug("http", "[%" PRId64 "] [watch_for_client_abort] "
 
871
          DebugSM("http", "[%" PRId64 "] [watch_for_client_abort] "
869
872
                "forwarding event %s to tunnel", sm_id, HttpDebugNames::get_event_name(event));
870
873
          tunnel.handleEvent(event, c->write_vio);
871
874
          return 0;
883
886
      terminate_sm = true;
884
887
      break;
885
888
    }
 
889
  case VC_EVENT_READ_COMPLETE:
 
890
    // XXX Work around for TS-1233.
886
891
  case VC_EVENT_READ_READY:
887
892
    //  Ignore.  Could be a pipelined request.  We'll get to  it
888
893
    //    when we finish the current transaction
1021
1026
 
1022
1027
  switch (state) {
1023
1028
  case PARSE_ERROR:
1024
 
    Debug("http", "[%" PRId64 "] error parsing push response header", sm_id);
 
1029
    DebugSM("http", "[%" PRId64 "] error parsing push response header", sm_id);
1025
1030
    call_transact_and_set_next_state(HttpTransact::HandleBadPushRespHdr);
1026
1031
    break;
1027
1032
 
1030
1035
    return VC_EVENT_CONT;
1031
1036
 
1032
1037
  case PARSE_DONE:
1033
 
    Debug("http", "[%" PRId64 "] done parsing push response header", sm_id);
 
1038
    DebugSM("http", "[%" PRId64 "] done parsing push response header", sm_id);
1034
1039
    call_transact_and_set_next_state(HttpTransact::HandlePushResponseHdr);
1035
1040
    break;
1036
1041
  default:
1365
1370
          plugin_lock = false;
1366
1371
        }
1367
1372
 
1368
 
        Debug("http", "[%" PRId64 "] calling plugin on hook %s at hook 0x%X",
 
1373
        DebugSM("http", "[%" PRId64 "] calling plugin on hook %s at hook %p",
1369
1374
              sm_id, HttpDebugNames::get_api_hook_name(cur_hook_id), cur_hook);
1370
1375
 
1371
1376
        APIHook *hook = cur_hook;
1486
1491
{
1487
1492
  switch (t_state.api_next_action) {
1488
1493
  case HttpTransact::HTTP_API_SM_START:
1489
 
    if (t_state.client_info.port_attribute == SERVER_PORT_BLIND_TUNNEL) {
 
1494
    if (t_state.client_info.port_attribute == HttpProxyPort::TRANSPORT_BLIND_TUNNEL) {
1490
1495
      setup_blind_tunnel_port();
1491
1496
    } else {
1492
1497
      setup_client_read_request_header();
1596
1601
int
1597
1602
HttpSM::state_http_server_open(int event, void *data)
1598
1603
{
1599
 
  Debug("http_track", "entered inside state_http_server_open");
 
1604
  DebugSM("http_track", "entered inside state_http_server_open");
1600
1605
  STATE_ENTER(&HttpSM::state_http_server_open, event);
1601
1606
  // TODO decide whether to uncomment after finish testing redirect
1602
1607
  // ink_assert(server_entry == NULL);
1606
1611
 
1607
1612
  switch (event) {
1608
1613
  case NET_EVENT_OPEN:
1609
 
    session = THREAD_ALLOC_INIT(httpServerSessionAllocator, mutex->thread_holding);
 
1614
    session = (2 == t_state.txn_conf->share_server_sessions) ? 
 
1615
      THREAD_ALLOC_INIT(httpServerSessionAllocator, mutex->thread_holding) :
 
1616
      httpServerSessionAllocator.alloc();
 
1617
    session->share_session = t_state.txn_conf->share_server_sessions;
 
1618
 
1610
1619
    // If origin_max_connections or origin_min_keep_alive_connections is
1611
1620
    // set then we are metering the max and or min number
1612
1621
    // of connections per host.  Set enable_origin_connection_limiting
1614
1623
    // the connection count.
1615
1624
    if (t_state.txn_conf->origin_max_connections > 0 ||
1616
1625
        t_state.http_config_param->origin_min_keep_alive_connections > 0) {
1617
 
      Debug("http_ss", "[%" PRId64 "] max number of connections: %u", sm_id, t_state.txn_conf->origin_max_connections);
 
1626
      DebugSM("http_ss", "[%" PRId64 "] max number of connections: %"PRIu64, sm_id, t_state.txn_conf->origin_max_connections);
1618
1627
      session->enable_origin_connection_limiting = true;
1619
1628
    }
1620
1629
    /*UnixNetVConnection * vc = (UnixNetVConnection*)(ua_session->client_vc);
1621
1630
       UnixNetVConnection *server_vc = (UnixNetVConnection*)data;
1622
1631
       printf("client fd is :%d , server fd is %d\n",vc->con.fd,
1623
1632
       server_vc->con.fd); */
1624
 
    session->server_ip = t_state.current.server->ip;
 
1633
    ats_ip_copy(&session->server_ip, &t_state.current.server->addr);
1625
1634
    session->new_connection((NetVConnection *) data);
1626
 
    session->server_port = t_state.current.server->port;
 
1635
    ats_ip_port_cast(&session->server_ip) = htons(t_state.current.server->port);
1627
1636
    session->state = HSS_ACTIVE;
1628
1637
 
1629
1638
    attach_server_session(session);
1766
1775
      }
1767
1776
 
1768
1777
      if (allow_error == false) {
1769
 
        Debug("http_seq", "Error parsing server response header");
 
1778
        DebugSM("http_seq", "Error parsing server response header");
1770
1779
        t_state.current.state = HttpTransact::PARSE_ERROR;
1771
1780
 
1772
1781
        // If the server closed prematurely on us, use the
1782
1791
      // FALLTHROUGH (since we are allowing the parse error)
1783
1792
    }
1784
1793
  case PARSE_DONE:
1785
 
    Debug("http_seq", "Done parsing server response header");
 
1794
    DebugSM("http_seq", "Done parsing server response header");
1786
1795
 
1787
1796
    // Now that we know that we have all of the origin server
1788
1797
    // response headers, we can reset the client inactivity
1932
1941
void
1933
1942
HttpSM::process_srv_info(HostDBInfo * r)
1934
1943
{
1935
 
  Debug("dns_srv", "beginning process_srv_info");
 
1944
  DebugSM("dns_srv", "beginning process_srv_info");
1936
1945
 
1937
1946
  SRVHosts s(r);                /* handled by conversion constructor */
1938
1947
  char new_host[MAXDNAME];
1939
1948
 
1940
1949
  /* we didnt get any SRV records, continue w normal lookup */
1941
1950
  if (!r->srv_count) {
1942
 
    Debug("dns_srv", "No SRV records were available, continuing to lookup %s", t_state.dns_info.lookup_name);
1943
 
    strncpy(&new_host[0], t_state.dns_info.lookup_name, MAXDNAME);
1944
 
    new_host[MAXDNAME - 1] = '\0';
 
1951
    DebugSM("dns_srv", "No SRV records were available, continuing to lookup %s", t_state.dns_info.lookup_name);
 
1952
    ink_strlcpy(new_host, t_state.dns_info.lookup_name, sizeof(new_host));
1945
1953
    goto lookup;
1946
1954
  }
1947
1955
 
1948
1956
  s.getWeightedHost(&new_host[0]);
1949
1957
 
1950
1958
  if (*new_host == '\0') {
1951
 
    Debug("dns_srv", "Weighted host returned was NULL or blank!, using %s as origin", t_state.dns_info.lookup_name);
1952
 
    strncpy(&new_host[0], t_state.dns_info.lookup_name, MAXDNAME);
1953
 
    new_host[MAXDNAME - 1] = '\0';
 
1959
    DebugSM("dns_srv", "Weighted host returned was NULL or blank!, using %s as origin", t_state.dns_info.lookup_name);
 
1960
    ink_strlcpy(new_host, t_state.dns_info.lookup_name, sizeof(new_host));
1954
1961
  } else {
1955
 
    Debug("dns_srv", "Weighted host now: %s", new_host);
 
1962
    DebugSM("dns_srv", "Weighted host now: %s", new_host);
1956
1963
  }
1957
1964
 
1958
 
  Debug("dns_srv", "ending process_srv_info SRV stuff; moving on to lookup origin host");
 
1965
  DebugSM("dns_srv", "ending process_srv_info SRV stuff; moving on to lookup origin host");
1959
1966
 
1960
1967
lookup:
1961
 
  Debug("http_seq", "[HttpStateMachineGet::process_srv_info] Doing DNS Lookup based on SRV %s", new_host);
 
1968
  DebugSM("http_seq", "[HttpStateMachineGet::process_srv_info] Doing DNS Lookup based on SRV %s", new_host);
1962
1969
 
1963
1970
  int server_port = t_state.current.server ? t_state.current.server->port : t_state.server_info.port;
1964
1971
 
1965
1972
  HTTP_SM_SET_DEFAULT_HANDLER(&HttpSM::state_hostdb_lookup);
1966
1973
 
1967
1974
  if (t_state.api_txn_dns_timeout_value != -1) {
1968
 
    Debug("http_timeout", "beginning DNS lookup. allowing %d mseconds for DNS", t_state.api_txn_dns_timeout_value);
 
1975
    DebugSM("http_timeout", "beginning DNS lookup. allowing %d mseconds for DNS", t_state.api_txn_dns_timeout_value);
1969
1976
  }
1970
1977
 
1971
1978
  Action *dns_lookup_action_handle = hostDBProcessor.getbyname_imm(this,
1999
2006
    t_state.dns_info.lookup_success = true;
2000
2007
 
2001
2008
    if (r->round_robin) {
2002
 
      // Since the time elapsed between current time and
2003
 
      // client_request_time may be very large, we cannot use
2004
 
      // client_request_time
2005
 
      // to approximate current time when calling select_best_http().
2006
 
      rr = r->rr()->select_best_http(t_state.client_info.ip, ink_cluster_time(), (int) t_state.txn_conf->down_server_timeout);
 
2009
      // Since the time elapsed between current time and client_request_time
 
2010
      // may be very large, we cannot use client_request_time to approximate
 
2011
      // current time when calling select_best_http().
 
2012
      rr = r->rr()->select_best_http(&t_state.client_info.addr.sa, ink_cluster_time(), (int) t_state.txn_conf->down_server_timeout);
2007
2013
      t_state.dns_info.round_robin = true;
2008
2014
    } else {
2009
2015
      rr = r;
2013
2019
//                  m_s.host_db_info = m_updated_host_db_info = *rr;
2014
2020
      t_state.host_db_info = *rr;
2015
2021
      ink_release_assert(!t_state.host_db_info.reverse_dns);
2016
 
      ink_release_assert(t_state.host_db_info.ip() > 0);
 
2022
      ink_release_assert(ats_is_ip(t_state.host_db_info.ip()));
2017
2023
    }
2018
2024
  } else {
2019
 
    Debug("http", "[%" PRId64 "] DNS lookup failed for '%s'", sm_id, t_state.dns_info.lookup_name);
 
2025
    DebugSM("http", "[%" PRId64 "] DNS lookup failed for '%s'", sm_id, t_state.dns_info.lookup_name);
2020
2026
 
2021
2027
    t_state.dns_info.lookup_success = false;
2022
2028
    t_state.dns_info.round_robin = false;
2029
2035
  if (is_debug_tag_set("http_timeout")) {
2030
2036
    if (t_state.api_txn_dns_timeout_value != -1) {
2031
2037
      int foo = (int) (milestone_difference_msec(milestones.dns_lookup_begin, milestones.dns_lookup_end));
2032
 
      Debug("http_timeout", "DNS took: %d msec", foo);
 
2038
      DebugSM("http_timeout", "DNS took: %d msec", foo);
2033
2039
    }
2034
2040
  }
2035
2041
}
2082
2088
    if (data) {
2083
2089
      t_state.request_data.hostname_str = ((HostDBInfo *) data)->hostname();
2084
2090
    } else {
2085
 
      Debug("http", "[%" PRId64 "] reverse DNS lookup failed for '%s'", sm_id, t_state.dns_info.lookup_name);
 
2091
      DebugSM("http", "[%" PRId64 "] reverse DNS lookup failed for '%s'", sm_id, t_state.dns_info.lookup_name);
2086
2092
    }
2087
2093
    call_transact_and_set_next_state(NULL);
2088
2094
    break;
2111
2117
      ink_assert(t_state.current.server != NULL);
2112
2118
      ink_assert(t_state.current.request_to == HttpTransact::ORIGIN_SERVER);
2113
2119
      if (t_state.current.server) {
2114
 
        mark_down = r->rr()->find_ip(t_state.current.server->ip);
 
2120
        mark_down = r->rr()->find_ip(&t_state.current.server->addr.sa);
2115
2121
      }
2116
2122
    } else {
2117
2123
      // No longer a round robin, check to see if our address is the same
2118
 
      if (t_state.host_db_info.ip() == r->ip()) {
 
2124
      if (ats_ip_addr_eq(t_state.host_db_info.ip(), r->ip())) {
2119
2125
        mark_down = r;
2120
2126
      }
2121
2127
    }
2145
2151
    if (data) {
2146
2152
      StatPageData *spd = (StatPageData *) data;
2147
2153
      t_state.internal_msg_buffer = spd->data;
2148
 
      t_state.internal_msg_buffer_type = spd->type;
 
2154
      if (spd->type)
 
2155
        t_state.internal_msg_buffer_type = spd->type;
 
2156
      else
 
2157
        t_state.internal_msg_buffer_type = ats_strdup("text/html");
2149
2158
      t_state.internal_msg_buffer_size = spd->length;
2150
2159
      t_state.internal_msg_buffer_fast_allocator_size = -1;
2151
2160
    }
2222
2231
 
2223
2232
  switch (event) {
2224
2233
  case ICP_LOOKUP_FOUND:
2225
 
    Debug("http", "ICP says ICP_LOOKUP_FOUND");
 
2234
 
 
2235
    DebugSM("http", "ICP says ICP_LOOKUP_FOUND");
2226
2236
    t_state.icp_lookup_success = true;
2227
2237
    t_state.icp_ip_result = *(struct sockaddr_in *) data;
2228
2238
 
2234
2244
*  // inhibit bad ICP looping behavior
2235
2245
*  if (t_state.icp_ip_result.sin_addr.s_addr ==
2236
2246
*    t_state.client_info.ip) {
2237
 
*      Debug("http","Loop in ICP config, bypassing...");
 
2247
*      DebugSM("http","Loop in ICP config, bypassing...");
2238
2248
*        t_state.icp_lookup_success = false;
2239
2249
*  }
2240
2250
*/
2241
2251
    break;
2242
2252
 
2243
2253
  case ICP_LOOKUP_FAILED:
2244
 
    Debug("http", "ICP says ICP_LOOKUP_FAILED");
 
2254
    DebugSM("http", "ICP says ICP_LOOKUP_FAILED");
2245
2255
    t_state.icp_lookup_success = false;
2246
2256
    break;
2247
2257
  default:
2362
2372
    {
2363
2373
      pending_action = NULL;
2364
2374
 
2365
 
      Debug("http", "[%" PRId64 "] cache_open_read - CACHE_EVENT_OPEN_READ", sm_id);
 
2375
      DebugSM("http", "[%" PRId64 "] cache_open_read - CACHE_EVENT_OPEN_READ", sm_id);
2366
2376
 
2367
2377
      /////////////////////////////////
2368
2378
      // lookup/open is successfull. //
2381
2391
  case CACHE_EVENT_OPEN_READ_FAILED:
2382
2392
    pending_action = NULL;
2383
2393
 
2384
 
    if (diags->on()) {
2385
 
      DebugOn("http", "[%" PRId64 "] cache_open_read - " "CACHE_EVENT_OPEN_READ_FAILED", sm_id);
2386
 
      DebugOn("http", "[state_cache_open_read] open read failed.");
2387
 
    }
 
2394
    DebugSM("http", "[%" PRId64 "] cache_open_read - " "CACHE_EVENT_OPEN_READ_FAILED", sm_id);
 
2395
    DebugSM("http", "[state_cache_open_read] open read failed.");
2388
2396
    // Inform HttpTransact somebody else is updating the document
2389
2397
    // HttpCacheSM already waited so transact should go ahead.
2390
2398
    if (data == (void *) -ECACHE_DOC_BUSY)
2416
2424
 
2417
2425
  // Don't use the state enter macro since it uses history
2418
2426
  //  space that we don't care about
2419
 
  Debug("http", "[%" PRId64 "] [HttpSM::main_handler, %s]", sm_id, HttpDebugNames::get_event_name(event));
 
2427
  DebugSM("http", "[%" PRId64 "] [HttpSM::main_handler, %s]", sm_id, HttpDebugNames::get_event_name(event));
2420
2428
 
2421
2429
  HttpVCTableEntry *vc_entry = NULL;
2422
2430
 
2590
2598
      // if the server closed while sending the
2591
2599
      //    100 continue header, handle it here so we
2592
2600
      //    don't assert later
2593
 
      Debug("http", "[%" PRId64 "] tunnel_handler_100_continue - server already " "closed, terminating connection", sm_id);
 
2601
      DebugSM("http", "[%" PRId64 "] tunnel_handler_100_continue - server already " "closed, terminating connection", sm_id);
2594
2602
 
2595
2603
      // Since 100 isn't a final (loggable) response header
2596
2604
      //   kill the 100 continue header and create an empty one
2692
2700
  int64_t cl = t_state.hdr_info.server_response.get_content_length();
2693
2701
 
2694
2702
  if (cl != UNDEFINED_COUNT && cl > server_response_body_bytes) {
2695
 
    Debug("http", "[%" PRId64 "] server eos after %d.  Expected %d", sm_id, cl, server_response_body_bytes);
 
2703
    DebugSM("http", "[%" PRId64 "] server eos after %"PRId64".  Expected %"PRId64, sm_id, cl, server_response_body_bytes);
2696
2704
    return true;
2697
2705
  } else {
2698
2706
    return false;
2704
2712
{
2705
2713
  STATE_ENTER(&HttpSM::tunnel_handler_server, event);
2706
2714
 
2707
 
  server_response_body_bytes += p->bytes_read;
2708
2715
  milestones.server_close = ink_get_hrtime();
2709
2716
 
2710
2717
  bool close_connection = false;
2744
2751
 
2745
2752
    ink_assert(p->vc_type == HT_HTTP_SERVER);
2746
2753
    if (is_http_server_eos_truncation(p)) {
2747
 
      Debug("http", "[%" PRId64 "] [HttpSM::tunnel_handler_server] aborting cache writes due to server truncation", sm_id);
 
2754
      DebugSM("http", "[%" PRId64 "] [HttpSM::tunnel_handler_server] aborting cache writes due to server truncation", sm_id);
2748
2755
      tunnel.abort_cache_write_finish_others(p);
2749
2756
      t_state.current.server->abort = HttpTransact::ABORTED;
2750
2757
      t_state.client_info.keep_alive = HTTP_NO_KEEPALIVE;
2848
2855
    // If the client is still around, attach the server session
2849
2856
    // to so the next ka request can use it.  We bind privately to the
2850
2857
    // client to add some degree of affinity to the system.  However,
2851
 
    // we turn off private binding when outbound conenctions are being
 
2858
    // we turn off private binding when outbound connections are being
2852
2859
    // limit since it makes it too expensive to initiate a purge of idle
2853
2860
    // server keep-alive sessions
2854
2861
    if (ua_session && t_state.client_info.keep_alive == HTTP_KEEPALIVE &&
2905
2912
 
2906
2913
  // There must be another consumer for it to worthwhile to
2907
2914
  //  set up a background fill
2908
 
  if (c->producer->num_consumers > 1 && c->producer->vc_type == HT_HTTP_SERVER && c->producer->alive == true) {
 
2915
  if (c->producer->num_consumers > 1 &&
 
2916
      (c->producer->vc_type == HT_HTTP_SERVER  || c->producer->vc_type == HT_TRANSFORM) &&
 
2917
      c->producer->alive == true) {
2909
2918
    // If threshold is 0.0 or negative then do background
2910
2919
    //   fill regardless of the content length.  Since this
2911
2920
    //   is floating point just make sure the number is near zero
2925
2934
      if (pDone <= 1.0 && pDone > t_state.http_config_param->background_fill_threshold) {
2926
2935
        return true;
2927
2936
      } else {
2928
 
        Debug("http", "[%" PRId64 "] no background.  Only %%%f done", sm_id, pDone);
 
2937
        DebugSM("http", "[%" PRId64 "] no background.  Only %%%f done", sm_id, pDone);
2929
2938
      }
2930
2939
 
2931
2940
    }
2958
2967
    set_ua_abort(HttpTransact::ABORTED, event);
2959
2968
 
2960
2969
    if (is_bg_fill_necessary(c)) {
2961
 
      Debug("http", "[%" PRId64 "] Initiating background fill", sm_id);
 
2970
      DebugSM("http", "[%" PRId64 "] Initiating background fill", sm_id);
2962
2971
      background_fill = BACKGROUND_FILL_STARTED;
2963
2972
      HTTP_INCREMENT_DYN_STAT(http_background_fill_current_count_stat);
2964
2973
 
3015
3024
  if (client_response_body_bytes < 0)
3016
3025
    client_response_body_bytes = 0;
3017
3026
 
 
3027
  // attribute the size written to the client from various sources
 
3028
  // NOTE: responses that go through a range transform are attributed
 
3029
  // to their original sources
 
3030
  // all other transforms attribute the total number of input bytes
 
3031
  // to a source in HttpSM::tunnel_handler_transform_write
 
3032
  //
 
3033
  HttpTransact::Source_t original_source = t_state.source;
 
3034
  if (HttpTransact::SOURCE_TRANSFORM == original_source &&
 
3035
      t_state.range_setup != HttpTransact::RANGE_NONE) {
 
3036
    original_source = t_state.pre_transform_source;
 
3037
  }
 
3038
 
 
3039
  switch (original_source) {
 
3040
  case HttpTransact::SOURCE_HTTP_ORIGIN_SERVER:
 
3041
    server_response_body_bytes = client_response_body_bytes;
 
3042
    break;
 
3043
  case HttpTransact::SOURCE_CACHE:
 
3044
    cache_response_body_bytes = client_response_body_bytes;
 
3045
    break;
 
3046
  default:
 
3047
    break;
 
3048
  }
 
3049
 
3018
3050
  ink_assert(ua_entry->vc == c->vc);
3019
3051
  if (close_connection) {
3020
3052
    // If the client could be pipelining or is doing a POST, we need to
3141
3173
    c->vc->do_io_close(EHTTP_ERROR);
3142
3174
 
3143
3175
    HTTP_INCREMENT_TRANS_STAT(http_cache_write_errors);
3144
 
    Debug("http", "[%" PRId64 "] aborting cache write due %s event from cache", sm_id, HttpDebugNames::get_event_name(event));
 
3176
    DebugSM("http", "[%" PRId64 "] aborting cache write due %s event from cache", sm_id, HttpDebugNames::get_event_name(event));
3145
3177
    break;
3146
3178
  case VC_EVENT_WRITE_COMPLETE:
3147
3179
    // if we've never initiated a cache write
3538
3570
    ink_release_assert(0);
3539
3571
  }
3540
3572
 
 
3573
  // attribute the size written to the transform from various sources
 
3574
  // NOTE: the range transform is excluded from this accounting and
 
3575
  // is instead handled in HttpSM::tunnel_handler_ua
 
3576
  //
 
3577
  // the reasoning is that the range transform is internal functionality
 
3578
  // in support of HTTP 1.1 compliance, therefore part of "normal" operation
 
3579
  // all other transforms are plugin driven and the difference between
 
3580
  // source data and final data should represent the transformation delta
 
3581
  //
 
3582
  if (t_state.range_setup == HttpTransact::RANGE_NONE) {
 
3583
    switch (t_state.pre_transform_source) {
 
3584
    case HttpTransact::SOURCE_HTTP_ORIGIN_SERVER:
 
3585
      server_response_body_bytes = client_response_body_bytes;
 
3586
      break;
 
3587
    case HttpTransact::SOURCE_CACHE:
 
3588
      cache_response_body_bytes = client_response_body_bytes;
 
3589
      break;
 
3590
    default:
 
3591
      break;
 
3592
    }
 
3593
  }
 
3594
 
3541
3595
  return 0;
3542
3596
}
3543
3597
 
3626
3680
  case EVENT_REMAP_COMPLETE:
3627
3681
    {
3628
3682
      pending_action = NULL;
3629
 
      Debug("url_rewrite", "completed processor-based remapping request for [%" PRId64 "]", sm_id);
 
3683
      DebugSM("url_rewrite", "completed processor-based remapping request for [%" PRId64 "]", sm_id);
3630
3684
      t_state.url_remap_success = remapProcessor.finish_remap(&t_state);
3631
3685
      call_transact_and_set_next_state(NULL);
3632
3686
      break;
3643
3697
void
3644
3698
HttpSM::do_remap_request(bool run_inline)
3645
3699
{
3646
 
  Debug("http_seq", "[HttpSM::do_remap_request] Remapping request");
3647
 
  Debug("url_rewrite", "Starting a possible remapping for request [%" PRId64 "]", sm_id);
 
3700
  DebugSM("http_seq", "[HttpSM::do_remap_request] Remapping request");
 
3701
  DebugSM("url_rewrite", "Starting a possible remapping for request [%" PRId64 "]", sm_id);
3648
3702
 
3649
3703
  bool ret = remapProcessor.setup_for_remap(&t_state);
3650
3704
 
3655
3709
  t_state.pristine_url.copy(t_state.hdr_info.client_request.url_get());
3656
3710
 
3657
3711
  if (!ret) {
3658
 
    Debug("url_rewrite", "Could not find a valid remapping entry for this request [%" PRId64 "]", sm_id);
 
3712
    DebugSM("url_rewrite", "Could not find a valid remapping entry for this request [%" PRId64 "]", sm_id);
3659
3713
    if (!run_inline) {
3660
3714
      handleEvent(EVENT_REMAP_COMPLETE, NULL);
3661
3715
    }
3662
3716
    return;
3663
3717
  }
3664
3718
 
3665
 
  Debug("url_rewrite", "Found a remap map entry for [%" PRId64 "], attempting to remap request and call any plugins", sm_id);
 
3719
  DebugSM("url_rewrite", "Found a remap map entry for [%" PRId64 "], attempting to remap request and call any plugins", sm_id);
3666
3720
  Action *remap_action_handle = remapProcessor.perform_remap(this, &t_state);
3667
3721
 
3668
3722
  if (remap_action_handle != ACTION_RESULT_DONE) {
3669
 
    Debug("url_rewrite", "Still more remapping needed for [%" PRId64 "]", sm_id);
 
3723
    DebugSM("url_rewrite", "Still more remapping needed for [%" PRId64 "]", sm_id);
3670
3724
    ink_debug_assert(!pending_action);
3671
3725
    historical_action = pending_action = remap_action_handle;
3672
3726
  }
3698
3752
  if (use_srv_records) {
3699
3753
    char* d = t_state.dns_info.srv_hostname;
3700
3754
 
3701
 
    memcpy(d, "_http._tcp.", 11);
3702
 
    ink_strncpy(d+11, t_state.server_info.name, MAXDNAME - 11);
3703
 
    d[MAXDNAME - 1] = '\0'; // Just to be sure it's NULL terminated in case of truncation
 
3755
    memcpy(d, "_http._tcp.", 11); // don't copy '\0'
 
3756
    ink_strlcpy(d + 11, t_state.server_info.name, sizeof(d) - 11 ); // all in the name of performance!
3704
3757
 
3705
 
    Debug("dns_srv", "Beginning lookup of SRV records for origin %s", d);
 
3758
    DebugSM("dns_srv", "Beginning lookup of SRV records for origin %s", d);
3706
3759
    HTTP_SM_SET_DEFAULT_HANDLER(&HttpSM::state_srv_lookup);
3707
3760
 
3708
3761
    Action *srv_lookup_action_handle =
3716
3769
    }
3717
3770
    return;
3718
3771
  } else {                      /* we arent using SRV stuff... */
3719
 
    Debug("http_seq", "[HttpStateMachineGet::do_hostdb_lookup] Doing DNS Lookup");
 
3772
    DebugSM("http_seq", "[HttpStateMachineGet::do_hostdb_lookup] Doing DNS Lookup");
3720
3773
 
3721
3774
    // If there is not a current server, we must be looking up the origin
3722
3775
    //  server at the beginning of the transaction
3723
3776
    int server_port = t_state.current.server ? t_state.current.server->port : t_state.server_info.port;
3724
3777
 
3725
3778
    if (t_state.api_txn_dns_timeout_value != -1) {
3726
 
      Debug("http_timeout", "beginning DNS lookup. allowing %d mseconds for DNS lookup",
 
3779
      DebugSM("http_timeout", "beginning DNS lookup. allowing %d mseconds for DNS lookup",
3727
3780
            t_state.api_txn_dns_timeout_value);
3728
3781
    }
3729
3782
 
3759
3812
  ink_assert(t_state.dns_info.lookup_name != NULL);
3760
3813
  ink_assert(pending_action == NULL);
3761
3814
 
3762
 
  Debug("http_seq", "[HttpSM::do_hostdb_reverse_lookup] Doing reverse DNS Lookup");
 
3815
  DebugSM("http_seq", "[HttpSM::do_hostdb_reverse_lookup] Doing reverse DNS Lookup");
3763
3816
 
3764
 
  uint32_t addr = ink_inet_addr(t_state.dns_info.lookup_name);
3765
 
  Action *dns_lookup_action_handle = hostDBProcessor.getbyaddr_re(this, addr);
 
3817
  IpEndpoint addr;
 
3818
  ats_ip_pton(t_state.dns_info.lookup_name, &addr.sa);
 
3819
  Action *dns_lookup_action_handle = hostDBProcessor.getbyaddr_re(this, &addr.sa);
3766
3820
 
3767
3821
  if (dns_lookup_action_handle != ACTION_RESULT_DONE) {
3768
3822
    ink_assert(!pending_action);
3783
3837
  }
3784
3838
  // If we failed back over to the origin server, we don't have our
3785
3839
  //   hostdb information anymore which means we shouldn't update the hostdb
3786
 
  if (t_state.current.server->ip != t_state.host_db_info.ip()) {
3787
 
    Debug("http", "[%" PRId64 "] skipping hostdb update due to server failover", sm_id);
 
3840
  if (!ats_ip_addr_eq(&t_state.current.server->addr.sa, t_state.host_db_info.ip())) {
 
3841
    DebugSM("http", "[%" PRId64 "] skipping hostdb update due to server failover", sm_id);
3788
3842
    return;
3789
3843
  }
3790
3844
 
3810
3864
  } else {
3811
3865
    if (t_state.host_db_info.app.http_data.last_failure != 0) {
3812
3866
      t_state.host_db_info.app.http_data.last_failure = 0;
 
3867
      ats_ip_port_cast(&t_state.current.server->addr) = htons(t_state.current.server->port);
3813
3868
      issue_update |= 1;
3814
 
      Debug("http", "[%" PRId64 "] hostdb update marking IP: %u.%u.%u.%u (port %d) as up",
 
3869
      char addrbuf[INET6_ADDRPORTSTRLEN];
 
3870
      DebugSM("http", "[%" PRId64 "] hostdb update marking IP: %s as up",
3815
3871
            sm_id,
3816
 
            ((unsigned char *) &t_state.current.server->ip)[0],
3817
 
            ((unsigned char *) &t_state.current.server->ip)[1],
3818
 
            ((unsigned char *) &t_state.current.server->ip)[2],
3819
 
            ((unsigned char *) &t_state.current.server->ip)[3], t_state.current.server->port);
 
3872
            ats_ip_nptop(&t_state.current.server->addr.sa, addrbuf, sizeof(addrbuf)));
3820
3873
    }
3821
3874
  }
3822
3875
 
3823
3876
  if (issue_update) {
3824
 
    hostDBProcessor.setby(t_state.current.server->name, 0,
3825
 
                          t_state.current.server->port, t_state.current.server->ip, &t_state.host_db_info.app);
 
3877
    hostDBProcessor.setby(t_state.current.server->name,
 
3878
      strlen(t_state.current.server->name),
 
3879
      &t_state.current.server->addr.sa,
 
3880
      &t_state.host_db_info.app
 
3881
    );
3826
3882
  }
3827
3883
 
 
3884
  char addrbuf[INET6_ADDRPORTSTRLEN];
 
3885
  DebugSM("http", "server info = %s", ats_ip_nptop(&t_state.current.server->addr.sa, addrbuf, sizeof(addrbuf)));
3828
3886
  return;
3829
3887
}
3830
3888
 
3831
 
 
3832
 
// this function first checks if cached response has Accept-Ranges and
3833
 
// Content-Length header and is HTTP/1.1. && There is no other plugins
3834
 
// hooked to TS_HTTP_RESPONSE_TRANSFORM_HOOK.
3835
 
// Then setup Range transformation if necessary
 
3889
void
 
3890
HttpSM::parse_range_and_compare(MIMEField *field, int64_t content_length)
 
3891
{
 
3892
  // note: unsatisfiable_range is initialized to true in constructor
 
3893
  int prev_good_range = -1;
 
3894
  const char *value;
 
3895
  int value_len;
 
3896
  int n_values;
 
3897
  int nr = 0; // number of valid ranges, also index to range array.
 
3898
  HdrCsvIter csv;
 
3899
  const char *s, *e;
 
3900
 
 
3901
  if (content_length <= 0)
 
3902
    return;
 
3903
 
 
3904
  ink_assert(field != NULL);
 
3905
 
 
3906
  n_values = 0;
 
3907
  value = csv.get_first(field, &value_len);
 
3908
  while (value) {
 
3909
    ++n_values;
 
3910
    value = csv.get_next(&value_len);
 
3911
  }
 
3912
 
 
3913
  if (n_values <= 0)
 
3914
    return;
 
3915
 
 
3916
  value = csv.get_first(field, &value_len);
 
3917
 
 
3918
  // Currently HTTP/1.1 only defines bytes Range
 
3919
  if (ptr_len_ncmp(value, value_len, "bytes=", 6) == 0) {
 
3920
    t_state.ranges = NEW(new RangeRecord[n_values]);
 
3921
    value += 6; // skip leading 'bytes='
 
3922
    value_len -= 6;
 
3923
 
 
3924
    while (value) {
 
3925
      bool valid = true; // found valid range.
 
3926
      // If delimiter '-' is missing
 
3927
      if (!(e = (const char *) memchr(value, '-', value_len))) {
 
3928
        t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
 
3929
        t_state.num_range_fields = -1;
 
3930
        return;
 
3931
      }
 
3932
 
 
3933
      /* [amc] We should do a much better job of checking the values
 
3934
         from mime_parse_int64 to detect invalid range values (e.g.
 
3935
         non-numeric). Those need to be handled differently than
 
3936
         missing values. My reading of the spec is that ATS should go to
 
3937
         RANGE_NONE in such a case.
 
3938
      */
 
3939
      s = value;
 
3940
      t_state.ranges[nr]._start = ((s==e)?-1:mime_parse_int64(s, e));
 
3941
 
 
3942
      ++e;
 
3943
      s = e;
 
3944
      e = value + value_len;
 
3945
      if ( e && *(e-1) == '-') { //open-ended Range: bytes=10-\r\n\r\n should be supported
 
3946
        t_state.ranges[nr]._end = -1;
 
3947
      }
 
3948
      else {
 
3949
        t_state.ranges[nr]._end = mime_parse_int64(s, e);
 
3950
      }
 
3951
 
 
3952
      // check and change if necessary whether this is a right entry
 
3953
      if (t_state.ranges[nr]._start >= content_length) {
 
3954
          valid = false;
 
3955
      } 
 
3956
      // open start
 
3957
      else if (t_state.ranges[nr]._start == -1 && t_state.ranges[nr]._end > 0) {
 
3958
        if (t_state.ranges[nr]._end > content_length)
 
3959
          t_state.ranges[nr]._end = content_length;
 
3960
 
 
3961
        t_state.ranges[nr]._start = content_length - t_state.ranges[nr]._end;
 
3962
        t_state.ranges[nr]._end = content_length - 1;
 
3963
      }
 
3964
      // open end
 
3965
      else if (t_state.ranges[nr]._start >= 0 && t_state.ranges[nr]._end == -1) {
 
3966
          t_state.ranges[nr]._end = content_length - 1;
 
3967
      }
 
3968
      // "normal" Range - could be wrong if _end<_start
 
3969
      else if (t_state.ranges[nr]._start >= 0 && t_state.ranges[nr]._end >= 0) {
 
3970
        if (t_state.ranges[nr]._start > t_state.ranges[nr]._end)
 
3971
          // [amc] My reading of the spec is that this should cause a change
 
3972
          // to RANGE_NONE because it is syntatically invalid.
 
3973
          valid = false;
 
3974
        else if (t_state.ranges[nr]._end >= content_length)
 
3975
          t_state.ranges[nr]._end = content_length - 1;
 
3976
      }
 
3977
      // Syntactically invalid range, fail.
 
3978
      else {
 
3979
        // [amc] My reading of the spec is that this should cause a change
 
3980
        // to RANGE_NONE because it is syntatically invalid.
 
3981
        t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
 
3982
        t_state.num_range_fields = -1;
 
3983
        return;
 
3984
      }
 
3985
 
 
3986
      // this is a good Range entry
 
3987
      if (valid) {
 
3988
        if (t_state.unsatisfiable_range) {
 
3989
          t_state.unsatisfiable_range = false;
 
3990
          // initialize t_state.current_range to the first good Range
 
3991
          t_state.current_range = nr;
 
3992
        }
 
3993
        // currently we don't handle out-of-order Range entry
 
3994
        else if (prev_good_range >= 0 && t_state.ranges[nr]._start <= t_state.ranges[prev_good_range]._end) {
 
3995
          t_state.not_handle_range = true;
 
3996
          break;
 
3997
        }
 
3998
 
 
3999
        prev_good_range = nr;
 
4000
        ++nr;
 
4001
      }
 
4002
      value = csv.get_next(&value_len);
 
4003
    }
 
4004
  }
 
4005
  // Fail if we didn't find any valid ranges.
 
4006
  if (nr < 1) {
 
4007
    t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
 
4008
    t_state.num_range_fields = -1;
 
4009
  } else {
 
4010
    t_state.num_range_fields = nr;
 
4011
  }
 
4012
}
 
4013
 
 
4014
void
 
4015
HttpSM::calculate_output_cl(int64_t content_length, int64_t num_chars)
 
4016
{
 
4017
  int i;
 
4018
 
 
4019
  if (t_state.unsatisfiable_range)
 
4020
    return;
 
4021
 
 
4022
  if (t_state.num_range_fields == 1) {
 
4023
    t_state.range_output_cl = t_state.ranges[0]._end - t_state.ranges[0]._start + 1;
 
4024
  }
 
4025
  else {
 
4026
    for (i = 0; i < t_state.num_range_fields; i++) {
 
4027
      if (t_state.ranges[i]._start >= 0) {
 
4028
        t_state.range_output_cl += boundary_size;
 
4029
        t_state.range_output_cl += sub_header_size + content_length;
 
4030
        t_state.range_output_cl += num_chars_for_int(t_state.ranges[i]._start)
 
4031
          + num_chars_for_int(t_state.ranges[i]._end) + num_chars + 2;
 
4032
        t_state.range_output_cl += t_state.ranges[i]._end - t_state.ranges[i]._start + 1;
 
4033
        t_state.range_output_cl += 2;
 
4034
      }
 
4035
    }
 
4036
 
 
4037
    t_state.range_output_cl += boundary_size + 2;
 
4038
  }
 
4039
 
 
4040
  Debug("http_range", "Pre-calculated Content-Length for Range response is %"PRId64, t_state.range_output_cl);
 
4041
}
 
4042
 
 
4043
void
 
4044
HttpSM::do_range_parse(MIMEField *range_field)
 
4045
{
 
4046
 
 
4047
  //bool res = false;
 
4048
  
 
4049
  int64_t content_length   = t_state.cache_info.object_read->object_size_get();
 
4050
  int64_t num_chars_for_cl = num_chars_for_int(content_length);
 
4051
  
 
4052
  parse_range_and_compare(range_field, content_length);
 
4053
  calculate_output_cl(content_length, num_chars_for_cl);
 
4054
  
 
4055
  if (t_state.unsatisfiable_range) {
 
4056
    t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
 
4057
    return;
 
4058
  }
 
4059
 
 
4060
  if (t_state.not_handle_range) {
 
4061
    t_state.range_setup = HttpTransact::RANGE_NOT_HANDLED;
 
4062
    return;
 
4063
  }
 
4064
 
 
4065
  t_state.range_setup = HttpTransact::RANGE_REQUESTED;
 
4066
}
 
4067
 
 
4068
// this function looks for any Range: headers, parses them and either
 
4069
// sets up a transform processor to handle the request OR defers to the 
 
4070
// HttpTunnel
3836
4071
void
3837
4072
HttpSM::do_range_setup_if_necessary()
3838
4073
{
3839
4074
  MIMEField *field;
3840
4075
  INKVConnInternal *range_trans;
3841
 
  bool res = false;
3842
 
 
 
4076
  int field_content_type_len = -1;
 
4077
  const char * content_type;
 
4078
  
3843
4079
  ink_assert(t_state.cache_info.object_read != NULL);
3844
 
 
 
4080
  
3845
4081
  field = t_state.hdr_info.client_request.field_find(MIME_FIELD_RANGE, MIME_LEN_RANGE);
3846
4082
  ink_assert(field != NULL);
3847
 
 
 
4083
  
3848
4084
  t_state.range_setup = HttpTransact::RANGE_NONE;
3849
4085
  if (t_state.method == HTTP_WKSIDX_GET && t_state.hdr_info.client_request.version_get() == HTTPVersion(1, 1)) {
3850
 
    if (api_hooks.get(TS_HTTP_RESPONSE_TRANSFORM_HOOK) == NULL) {
3851
 
      // We may still not do Range if it is out of order Range.
3852
 
      range_trans = transformProcessor.range_transform(mutex, field,
3853
 
                                                       t_state.cache_info.object_read,
3854
 
                                                       &t_state.hdr_info.transform_response, res);
3855
 
      if (range_trans != NULL) {
3856
 
        api_hooks.append(TS_HTTP_RESPONSE_TRANSFORM_HOOK, range_trans);
3857
 
        t_state.range_setup = HttpTransact::RANGE_TRANSFORM;
3858
 
      } else if (res)
3859
 
        t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
3860
 
      else
3861
 
        t_state.range_setup = HttpTransact::RANGE_NOT_HANDLED;
 
4086
    do_range_parse(field);
 
4087
    
 
4088
    if (t_state.range_setup == HttpTransact::RANGE_REQUESTED && 
 
4089
        t_state.num_range_fields > 1 &&
 
4090
        api_hooks.get(TS_HTTP_RESPONSE_TRANSFORM_HOOK) == NULL
 
4091
       ) 
 
4092
    {
 
4093
          Debug("http_trans", "Handling multiple Range: requests");
 
4094
          content_type = t_state.cache_info.object_read->response_get()->value_get(MIME_FIELD_CONTENT_TYPE, MIME_LEN_CONTENT_TYPE, &field_content_type_len);
 
4095
          //create a Range: transform processor for requests of type Range: bytes=1-2,4-5,10-100 (eg. multiple ranges)
 
4096
          range_trans = transformProcessor.range_transform(mutex, 
 
4097
                  t_state.ranges,
 
4098
                  t_state.unsatisfiable_range, 
 
4099
                  t_state.num_range_fields, 
 
4100
                  &t_state.hdr_info.transform_response,
 
4101
                  content_type,
 
4102
                  field_content_type_len,
 
4103
                  t_state.cache_info.object_read->object_size_get()
 
4104
                  );
 
4105
          if (range_trans != NULL) {
 
4106
            api_hooks.append(TS_HTTP_RESPONSE_TRANSFORM_HOOK, range_trans);
 
4107
            t_state.range_setup = HttpTransact::RANGE_REQUESTED;
 
4108
          }
 
4109
          else { //we couldnt append the transform to our API hooks so bailing
 
4110
            t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
 
4111
          } 
 
4112
    }
 
4113
    else if (t_state.range_setup == HttpTransact::RANGE_REQUESTED && t_state.num_range_fields == 1) {
 
4114
      Debug("http_trans", "Handling single Range: request");
 
4115
      //no op, we will handle this later in the HttpTunnel
 
4116
    }
 
4117
    else {
 
4118
      t_state.range_setup = HttpTransact::RANGE_NOT_SATISFIABLE;
3862
4119
    }
3863
4120
  }
3864
4121
}
3885
4142
  else
3886
4143
    c_url = t_state.cache_info.lookup_url;
3887
4144
 
3888
 
  Debug("http_seq", "[HttpSM::do_cache_lookup_and_read] [%" PRId64 "] Issuing cache lookup for URL %s",  sm_id, c_url->string_get(&t_state.arena));
 
4145
  DebugSM("http_seq", "[HttpSM::do_cache_lookup_and_read] [%" PRId64 "] Issuing cache lookup for URL %s",  sm_id, c_url->string_get(&t_state.arena));
3889
4146
  Action *cache_action_handle = cache_sm.open_read(c_url,
3890
4147
                                                   &t_state.hdr_info.client_request,
3891
4148
                                                   &(t_state.cache_info.config),
3921
4178
  ink_assert(md5a == md5b || t_state.txn_conf->maintain_pristine_host_hdr);
3922
4179
#endif
3923
4180
 
3924
 
  Debug("http_seq", "[HttpSM::do_cache_delete_all_alts] Issuing cache delete for %s",
 
4181
  DebugSM("http_seq", "[HttpSM::do_cache_delete_all_alts] Issuing cache delete for %s",
3925
4182
        t_state.cache_info.lookup_url->string_get_ref());
3926
4183
 
3927
4184
  Action *cache_action_handle = NULL;
4021
4278
  }
4022
4279
 
4023
4280
  ink_debug_assert(s_url != NULL && s_url->valid());
4024
 
  Debug("http_cache_write", "[%" PRId64 "] writing to cache with URL %s", sm_id, s_url->string_get(&t_state.arena));
 
4281
  DebugSM("http_cache_write", "[%" PRId64 "] writing to cache with URL %s", sm_id, s_url->string_get(&t_state.arena));
4025
4282
  Action *cache_action_handle = c_sm->open_write(s_url, &t_state.hdr_info.client_request,
4026
4283
                                                 object_read_info,
4027
4284
                                                 (time_t) ((t_state.cache_control.pin_in_cache_for < 0) ?
4044
4301
void
4045
4302
HttpSM::do_http_server_open(bool raw)
4046
4303
{
4047
 
  Debug("http_track", "entered inside do_http_server_open");
 
4304
  DebugSM("http_track", "entered inside do_http_server_open");
 
4305
  int ip_family = t_state.current.server->addr.sa.sa_family;
4048
4306
 
4049
4307
  ink_assert(server_entry == NULL);
4050
4308
 
4056
4314
             t_state.req_flavor == HttpTransact::REQ_FLAVOR_REVPROXY);
4057
4315
 
4058
4316
  ink_assert(pending_action == NULL);
4059
 
  ink_assert(t_state.current.server->port > 0);
4060
4317
 
4061
4318
  HSMresult_t shared_result;
4062
 
  NetVCOptions opt;
4063
 
  opt.f_blocking_connect = false;
4064
 
  opt.set_sock_param(t_state.txn_conf->sock_recv_buffer_size_out,
4065
 
                     t_state.txn_conf->sock_send_buffer_size_out,
4066
 
                     t_state.txn_conf->sock_option_flag_out);
4067
4319
 
4068
 
  if (t_state.txn_conf->outgoing_ip_to_bind_saddr) {
4069
 
    opt.addr_binding = NetVCOptions::INTF_ADDR;
4070
 
    opt.local_addr = t_state.txn_conf->outgoing_ip_to_bind_saddr;
4071
 
  } else if (t_state.server_info.is_transparent) {
4072
 
    opt.addr_binding = NetVCOptions::FOREIGN_ADDR;
4073
 
    opt.local_addr = t_state.client_info.ip;
 
4320
  if (false == t_state.api_server_addr_set) {
 
4321
    ink_assert(t_state.current.server->port > 0);
 
4322
    t_state.current.server->addr.port() = htons(t_state.current.server->port);
 
4323
  } else {
 
4324
    ink_assert(ats_ip_port_cast(&t_state.current.server->addr) != 0);
4074
4325
  }
4075
4326
 
4076
 
  Debug("http", "[%" PRId64 "] open connection to %s: %u.%u.%u.%u",
4077
 
        sm_id, t_state.current.server->name, PRINT_IP(t_state.current.server->ip));
 
4327
  char addrbuf[INET6_ADDRPORTSTRLEN];
 
4328
  DebugSM("http", "[%" PRId64 "] open connection to %s: %s",
 
4329
        sm_id, t_state.current.server->name, 
 
4330
        ats_ip_nptop(&t_state.current.server->addr.sa, addrbuf, sizeof(addrbuf)));
4078
4331
 
4079
4332
  if (plugin_tunnel) {
4080
4333
    PluginVCCore *t = plugin_tunnel;
4086
4339
    return;
4087
4340
  }
4088
4341
 
4089
 
  Debug("http_seq", "[HttpSM::do_http_server_open] Sending request to server");
 
4342
  DebugSM("http_seq", "[HttpSM::do_http_server_open] Sending request to server");
4090
4343
 
4091
4344
  milestones.server_connect = ink_get_hrtime();
4092
4345
  if (milestones.server_first_connect == 0) {
4119
4372
  // to do this but as far I can tell the code that prevented keep-alive if
4120
4373
  // there is a request body has been removed.
4121
4374
 
4122
 
  if (raw == false && t_state.http_config_param->share_server_sessions &&
 
4375
  if (raw == false && t_state.txn_conf->share_server_sessions &&
4123
4376
      (t_state.txn_conf->keep_alive_post_out == 1 || t_state.hdr_info.request_content_length == 0) &&
4124
4377
      ua_session != NULL) {
4125
4378
    shared_result = httpSessionManager.acquire_session(this,    // state machine
4126
 
                                                       t_state.current.server->ip,      // host_op
4127
 
                                                       t_state.current.server->port,    // host_port
 
4379
                                                       &t_state.current.server->addr.sa,    // ip + port
4128
4380
                                                       t_state.current.server->name,    // hostname
4129
4381
                                                       ua_session,      // has ptr to bound ua sessions
4130
4382
                                                       this     // sm
4149
4401
  // This bug was due to when share_server_sessions is set to 0
4150
4402
  // and we have keep-alive, we are trying to open a new server session
4151
4403
  // when we already have an attached server session.
4152
 
  else if ((!t_state.http_config_param->share_server_sessions) && (ua_session != NULL)) {
 
4404
  else if ((!t_state.txn_conf->share_server_sessions) && (ua_session != NULL)) {
4153
4405
    HttpServerSession *existing_ss = ua_session->get_server_session();
4154
4406
 
4155
4407
    if (existing_ss) {
4156
 
      if (existing_ss->server_ip == t_state.current.server->ip
4157
 
          && existing_ss->server_port == t_state.current.server->port) {
 
4408
      // [amc] Is this OK? Should we compare ports? (not done by ats_ip_addr_cmp)
 
4409
      if (ats_ip_addr_cmp(&existing_ss->server_ip.sa, &t_state.current.server->addr.sa) == 0) {
4158
4410
        ua_session->attach_server_session(NULL);
4159
4411
        existing_ss->state = HSS_ACTIVE;
4160
4412
        this->attach_server_session(existing_ss);
4203
4455
  if (t_state.txn_conf->origin_max_connections > 0) {
4204
4456
    ConnectionCount *connections = ConnectionCount::getInstance();
4205
4457
 
4206
 
    if (connections->getCount((t_state.current.server->ip)) >= t_state.txn_conf->origin_max_connections) {
4207
 
      Debug("http", "[%" PRId64 "] over the number of connection for this host: %u", sm_id, t_state.current.server->ip);
 
4458
    char addrbuf[INET6_ADDRSTRLEN];
 
4459
    if (connections->getCount((t_state.current.server->addr)) >= t_state.txn_conf->origin_max_connections) {
 
4460
      DebugSM("http", "[%" PRId64 "] over the number of connection for this host: %s", sm_id,
 
4461
        ats_ip_ntop(&t_state.current.server->addr.sa, addrbuf, sizeof(addrbuf)));
4208
4462
      ink_debug_assert(pending_action == NULL);
4209
4463
      pending_action = eventProcessor.schedule_in(this, HRTIME_MSECONDS(100));
4210
4464
      return;
4213
4467
 
4214
4468
  // We did not manage to get an exisiting session
4215
4469
  //  and need to open a new connection
4216
 
  unsigned int srv_ip = t_state.current.server->ip;
4217
 
  int srv_port = t_state.current.server->port;
4218
 
 
4219
4470
  Action *connect_action_handle;
4220
4471
 
 
4472
  NetVCOptions opt;
 
4473
  opt.f_blocking_connect = false;
 
4474
  opt.set_sock_param(t_state.txn_conf->sock_recv_buffer_size_out,
 
4475
                     t_state.txn_conf->sock_send_buffer_size_out,
 
4476
                     t_state.txn_conf->sock_option_flag_out,
 
4477
                     t_state.txn_conf->sock_packet_mark_out,
 
4478
                     t_state.txn_conf->sock_packet_tos_out);
 
4479
 
 
4480
  opt.ip_family = ip_family;
 
4481
 
 
4482
  if (ua_session) {
 
4483
    opt.local_port = ua_session->outbound_port;
 
4484
 
 
4485
    IpAddr& outbound_ip = AF_INET6 == ip_family ? ua_session->outbound_ip6 : ua_session->outbound_ip4;
 
4486
    if (outbound_ip.isValid()) {
 
4487
      opt.addr_binding = NetVCOptions::INTF_ADDR;
 
4488
      opt.local_ip = outbound_ip;
 
4489
    } else if (ua_session->f_outbound_transparent) {
 
4490
      opt.addr_binding = NetVCOptions::FOREIGN_ADDR;
 
4491
      opt.local_ip = t_state.client_info.addr;
 
4492
 
 
4493
      /* If the connection is server side transparent, we can bind to the
 
4494
         port that the client chose instead of randomly assigning one at
 
4495
         the proxy.  This is controlled by the 'use_client_source_port'
 
4496
         configuration parameter.
 
4497
      */
 
4498
 
 
4499
      NetVConnection *client_vc = ua_session->get_netvc();
 
4500
      if (t_state.http_config_param->use_client_source_port && NULL != client_vc) {
 
4501
        opt.local_port = client_vc->get_remote_port();
 
4502
      }
 
4503
    }
 
4504
  }
 
4505
 
4221
4506
  if (t_state.scheme == URL_WKSIDX_HTTPS) {
4222
 
    Debug("http", "calling sslNetProcessor.connect_re");
 
4507
    DebugSM("http", "calling sslNetProcessor.connect_re");
4223
4508
    connect_action_handle = sslNetProcessor.connect_re(this,    // state machine
4224
 
                                                       srv_ip,  // host_op
4225
 
                                                       srv_port,        // host_port
 
4509
                                                       &t_state.current.server->addr.sa,    // addr + port
4226
4510
                                                       &opt);
4227
4511
  } else {
4228
4512
    if (t_state.method != HTTP_WKSIDX_CONNECT) {
4229
 
      Debug("http", "calling netProcessor.connect_re");
 
4513
      DebugSM("http", "calling netProcessor.connect_re");
4230
4514
      connect_action_handle = netProcessor.connect_re(this,     // state machine
4231
 
                                                      srv_ip,   // host_op
4232
 
                                                      srv_port, // host_port
 
4515
                                                      &t_state.current.server->addr.sa,    // addr + port
4233
4516
                                                      &opt);
4234
4517
    } else {
4235
4518
      // Setup the timeouts
4247
4530
        else
4248
4531
          connect_timeout = t_state.txn_conf->connect_attempts_timeout;
4249
4532
      }
4250
 
      Debug("http", "calling netProcessor.connect_s");
 
4533
      DebugSM("http", "calling netProcessor.connect_s");
4251
4534
      connect_action_handle = netProcessor.connect_s(this,      // state machine
4252
 
                                                     srv_ip,    // host_op
4253
 
                                                     srv_port,  // host_port
 
4535
                                                     &t_state.current.server->addr.sa,    // addr + port
4254
4536
                                                     connect_timeout, &opt);
4255
4537
    }
4256
4538
  }
4390
4672
void
4391
4673
HttpSM::mark_host_failure(HostDBInfo * info, time_t time_down)
4392
4674
{
 
4675
  char addrbuf[INET6_ADDRPORTSTRLEN];
 
4676
 
4393
4677
  if (info->app.http_data.last_failure == 0) {
4394
4678
    char *url_str = t_state.hdr_info.client_request.url_string_get(&t_state.arena, 0);
4395
 
    Log::error("CONNECT: could not connect to %u.%u.%u.%u "
 
4679
    Log::error("CONNECT: could not connect to %s "
4396
4680
               "for '%s' (setting last failure time)",
4397
 
               ((unsigned char *) &t_state.current.server->ip)[0],
4398
 
               ((unsigned char *) &t_state.current.server->ip)[1],
4399
 
               ((unsigned char *) &t_state.current.server->ip)[2],
4400
 
               ((unsigned char *) &t_state.current.server->ip)[3],
 
4681
               ats_ip_ntop(&t_state.current.server->addr.sa, addrbuf, sizeof(addrbuf)),
4401
4682
               url_str ? url_str : "<none>"
4402
4683
    );
4403
4684
    if (url_str)
4411
4692
  ink_assert(ink_cluster_time() + t_state.txn_conf->down_server_timeout > time_down);
4412
4693
#endif
4413
4694
 
4414
 
  Debug("http", "[%" PRId64 "] hostdb update marking IP: %u.%u.%u.%u (port %d) as down",
 
4695
  DebugSM("http", "[%" PRId64 "] hostdb update marking IP: %s as down",
4415
4696
        sm_id,
4416
 
        ((unsigned char *) &t_state.current.server->ip)[0],
4417
 
        ((unsigned char *) &t_state.current.server->ip)[1],
4418
 
        ((unsigned char *) &t_state.current.server->ip)[2],
4419
 
        ((unsigned char *) &t_state.current.server->ip)[3], t_state.current.server->port);
 
4697
        ats_ip_nptop(&t_state.current.server->addr.sa, addrbuf, sizeof(addrbuf)));
4420
4698
}
4421
4699
 
4422
4700
void
4475
4753
      // Check to see if client waited for the threshold
4476
4754
      //  to declare the origin server as down
4477
4755
      ink_hrtime wait = ink_get_hrtime() - milestones.server_first_connect;
4478
 
      ink_assert(wait >= 0);
 
4756
      if (wait < 0) {
 
4757
        wait = 0;
 
4758
      }
4479
4759
      if (ink_hrtime_to_sec(wait) > t_state.txn_conf->client_abort_threshold) {
4480
4760
        t_state.current.server->connect_failure = true;
4481
4761
        do_hostdb_update_if_necessary();
4578
4858
void
4579
4859
HttpSM::handle_http_server_open()
4580
4860
{
 
4861
  // [bwyatt] applying per-transaction OS netVC options here
 
4862
  //          IFF they differ from the netVC's current options.
 
4863
  //          This should keep this from being redundant on a
 
4864
  //          server session's first transaction.
 
4865
  if (NULL != server_session) {
 
4866
    NetVConnection *vc = server_session->get_netvc();
 
4867
    if (vc != NULL &&
 
4868
        (vc->options.sockopt_flags != t_state.txn_conf->sock_option_flag_out ||
 
4869
         vc->options.packet_mark != t_state.txn_conf->sock_packet_mark_out ||
 
4870
         vc->options.packet_tos != t_state.txn_conf->sock_packet_tos_out )) {
 
4871
      vc->options.sockopt_flags = t_state.txn_conf->sock_option_flag_out;
 
4872
      vc->options.packet_mark = t_state.txn_conf->sock_packet_mark_out;
 
4873
      vc->options.packet_tos = t_state.txn_conf->sock_packet_tos_out;
 
4874
      vc->apply_options();
 
4875
    }
 
4876
  }
 
4877
 
4581
4878
  if (t_state.pCongestionEntry != NULL) {
4582
4879
    if (t_state.congestion_connection_opened == 0) {
4583
4880
      t_state.congestion_connection_opened = 1;
4612
4909
 
4613
4910
  if (tunnel.is_tunnel_active()) {
4614
4911
    ink_assert(server_entry->read_vio == data);
4615
 
    Debug("http", "[%" PRId64 "] [handle_server_setup_error] "
 
4912
    DebugSM("http", "[%" PRId64 "] [handle_server_setup_error] "
4616
4913
          "forwarding event %s to post tunnel", sm_id, HttpDebugNames::get_event_name(event));
4617
4914
    HttpTunnelConsumer *c = tunnel.get_consumer(server_entry->vc);
4618
4915
    // it is possible only user agent post->post transform is set up
4871
5168
void
4872
5169
HttpSM::perform_transform_cache_write_action()
4873
5170
{
4874
 
  Debug("http", "[%" PRId64 "] perform_transform_cache_write_action %s", sm_id,
 
5171
  DebugSM("http", "[%" PRId64 "] perform_transform_cache_write_action %s", sm_id,
4875
5172
        HttpDebugNames::get_cache_action_name(t_state.cache_info.action));
4876
5173
 
4877
5174
  if (t_state.range_setup)
4911
5208
void
4912
5209
HttpSM::perform_cache_write_action()
4913
5210
{
4914
 
  Debug("http", "[%" PRId64 "] perform_cache_write_action %s",
 
5211
  DebugSM("http", "[%" PRId64 "] perform_cache_write_action %s",
4915
5212
        sm_id, HttpDebugNames::get_cache_action_name(t_state.cache_info.action));
4916
5213
 
4917
5214
  switch (t_state.cache_info.action) {
5039
5336
  server_session->mutex = this->mutex;
5040
5337
 
5041
5338
  HTTP_INCREMENT_DYN_STAT(http_current_server_transactions_stat);
5042
 
  s->server_trans_stat++;
 
5339
  ++s->server_trans_stat;
5043
5340
 
5044
5341
  // Record the VC in our table
5045
5342
  server_entry = vc_table.new_entry();
5137
5434
 
5138
5435
  // the plugin decided to append a message to the request
5139
5436
  if (api_set) {
5140
 
    Debug("http", "[%" PRId64 "] appending msg of %d bytes to request %s", sm_id, msg_len, t_state.internal_msg_buffer);
 
5437
    DebugSM("http", "[%" PRId64 "] appending msg of %"PRId64" bytes to request %s", sm_id, msg_len, t_state.internal_msg_buffer);
5141
5438
    hdr_length += server_entry->write_buffer->write(t_state.internal_msg_buffer, msg_len);
5142
5439
    server_request_body_bytes = msg_len;
5143
5440
  }
5253
5550
  // Now dump the header into the buffer
5254
5551
  ink_assert(t_state.hdr_info.client_response.status_get() != HTTP_STATUS_NOT_MODIFIED);
5255
5552
  client_response_hdr_bytes = hdr_size = write_response_header_into_buffer(&t_state.hdr_info.client_response, buf);
 
5553
  cache_response_hdr_bytes = client_response_hdr_bytes;
 
5554
 
5256
5555
 
5257
5556
  HTTP_SM_SET_DEFAULT_HANDLER(&HttpSM::tunnel_handler);
5258
5557
 
5283
5582
  ink_assert(transform_info.vc != NULL);
5284
5583
  ink_assert(transform_info.entry->vc == transform_info.vc);
5285
5584
 
 
5585
  // grab this here
 
5586
  cache_response_hdr_bytes = t_state.hdr_info.cache_response.length_get();
 
5587
 
5286
5588
  doc_size = t_state.cache_info.object_read->object_size_get();
5287
5589
  alloc_index = buffer_size_to_index(doc_size);
5288
5590
  MIOBuffer *buf = new_MIOBuffer(alloc_index);
5303
5605
  transform_info.entry->in_tunnel = true;
5304
5606
  cache_sm.cache_read_vc = NULL;
5305
5607
 
5306
 
  // We need to copy to header cached request header since the
5307
 
  //   cache read may finish before we do an open write to
5308
 
  //   write the transformed copy to the cache
5309
 
  t_state.hdr_info.transform_cached_request.create(HTTP_TYPE_REQUEST);
5310
 
  t_state.hdr_info.transform_cached_request.copy(t_state.cache_info.object_read->request_get());
5311
 
 
5312
5608
  return p;
5313
5609
}
5314
5610
 
5386
5682
    t_state.api_next_action = HttpTransact::HTTP_API_SEND_REPONSE_HDR;
5387
5683
    do_api_callout();
5388
5684
  } else {
5389
 
    Debug("http", "[setup_error_transfer] Now closing connection ...");
 
5685
    DebugSM("http", "[setup_error_transfer] Now closing connection ...");
5390
5686
    vc_table.cleanup_entry(ua_entry);
5391
5687
    ua_entry = NULL;
5392
5688
    ua_session = NULL;
5413
5709
                                                 MIME_LEN_CONTENT_TYPE,
5414
5710
                                                 t_state.internal_msg_buffer_type,
5415
5711
                                                 strlen(t_state.internal_msg_buffer_type));
5416
 
      xfree(t_state.internal_msg_buffer_type);
 
5712
      ats_free(t_state.internal_msg_buffer_type);
5417
5713
      t_state.internal_msg_buffer_type = NULL;
5418
5714
    }
5419
5715
  } else {
5537
5833
  // Next order of business if copy the remaining data from the
5538
5834
  //  header buffer into new buffer.
5539
5835
 
5540
 
  server_response_body_bytes =
 
5836
  int64_t server_response_pre_read_bytes =
5541
5837
#ifdef WRITE_AND_TRANSFER
5542
5838
    /* relinquish the space in server_buffer and let
5543
5839
       the tunnel use the trailing space
5546
5842
#else
5547
5843
    buf->write(server_buffer_reader, to_copy);
5548
5844
#endif
5549
 
  server_buffer_reader->consume(server_response_body_bytes);
 
5845
  server_buffer_reader->consume(server_response_pre_read_bytes);
5550
5846
 
5551
5847
  //  If we know the length & copied the entire body
5552
5848
  //   of the document out of the header buffer make
5553
5849
  //   sure the server isn't screwing us by having sent too
5554
5850
  //   much.  If it did, we want to close the server connection
5555
 
  if (server_response_body_bytes == to_copy && server_buffer_reader->read_avail() > 0) {
 
5851
  if (server_response_pre_read_bytes == to_copy && server_buffer_reader->read_avail() > 0) {
5556
5852
    t_state.current.server->keep_alive = HTTP_NO_KEEPALIVE;
5557
5853
  }
5558
5854
#ifdef LAZY_BUF_ALLOC
5936
6232
    if (second_cache_sm)
5937
6233
      second_cache_sm->end_both();
5938
6234
    transform_cache_sm.end_both();
5939
 
    tunnel.deallocate_buffers();
5940
6235
    vc_table.cleanup_all();
 
6236
    tunnel.deallocate_buffers();
5941
6237
 
5942
6238
    // It possible that a plugin added transform hook
5943
6239
    //   but the hook never executed due to a client abort
6007
6303
    HTTP_SM_SET_DEFAULT_HANDLER(NULL);
6008
6304
 
6009
6305
    if (redirect_url != NULL) {
6010
 
      xfree(redirect_url);
 
6306
      ats_free(redirect_url);
6011
6307
      redirect_url = NULL;
6012
6308
      redirect_url_len = 0;
6013
6309
    }
6018
6314
    ink_mutex_release(&debug_sm_list_mutex);
6019
6315
#endif
6020
6316
 
6021
 
    Debug("http", "[%" PRId64 "] dellocating sm", sm_id);
 
6317
    DebugSM("http", "[%" PRId64 "] dellocating sm", sm_id);
6022
6318
//    authAdapter.destroyState();
6023
6319
    destroy();
6024
6320
  }
6030
6326
  milestones.sm_finish = ink_get_hrtime();
6031
6327
 
6032
6328
  if (t_state.cop_test_page && !t_state.http_config_param->record_cop_page) {
6033
 
    Debug("http_seq", "Skipping cop heartbeat logging & stats due to config");
 
6329
    DebugSM("http_seq", "Skipping cop heartbeat logging & stats due to config");
6034
6330
    return;
6035
6331
  }
6036
6332
 
6037
6333
  //////////////
6038
6334
  // Log Data //
6039
6335
  //////////////
6040
 
  Debug("http_seq", "[HttpStateMachineGet::update_stats] Logging transaction");
 
6336
  DebugSM("http_seq", "[HttpStateMachineGet::update_stats] Logging transaction");
6041
6337
  if (Log::transaction_logging_enabled() && t_state.api_info.logging_enabled) {
6042
6338
    LogAccessHttp accessor(this);
6043
6339
 
6044
6340
    int ret = Log::access(&accessor);
6045
6341
 
6046
6342
    if (ret & Log::FULL) {
6047
 
      Debug("http", "[update_stats] Logging system indicates FULL.");
 
6343
      DebugSM("http", "[update_stats] Logging system indicates FULL.");
6048
6344
    }
6049
6345
    if (ret & Log::FAIL) {
6050
6346
      Log::error("failed to log transaction for at least one log object");
6087
6383
    ua_write_time = -1;
6088
6384
  }
6089
6385
 
6090
 
/*   Debug("ARMStatsCache", "ua_begin_write: %d ua_close: %d ua_write_time:%d",
 
6386
/*   DebugSM("ARMStatsCache", "ua_begin_write: %d ua_close: %d ua_write_time:%d",
6091
6387
     (int) ink_hrtime_to_msec(milestones.ua_begin_write),
6092
6388
     (int) ink_hrtime_to_msec(milestones.ua_close),
6093
6389
     (int) ink_hrtime_to_msec(ua_write_time));
6134
6430
      ink_hrtime_from_msec(t_state.http_config_param->slow_log_threshold) < total_time) {
6135
6431
    // get the url to log
6136
6432
    URL *url = t_state.hdr_info.client_request.url_get();
6137
 
    char url_string[256];
 
6433
    char url_string[256] = "";
6138
6434
    if (url != NULL && url->valid()) {
6139
 
      url->string_get_buf(url_string, 256);
6140
 
    } else {
6141
 
      strncpy(url_string, "", sizeof(url_string));
 
6435
      url->string_get_buf(url_string, sizeof(url_string));
6142
6436
    }
6143
6437
 
6144
6438
    // unique id
6145
 
    char unique_id_string[128];
 
6439
    char unique_id_string[128] = "";
6146
6440
    if (url != NULL && url->valid()) {
6147
6441
      int length = 0;
6148
6442
      const char *field = t_state.hdr_info.client_request.value_get(MIME_FIELD_X_ID, MIME_LEN_X_ID, &length);
6149
6443
      if (field != NULL) {
6150
 
        if ((int)sizeof(unique_id_string) < length)
6151
 
          length =  (int)sizeof(unique_id_string);
6152
 
        strncpy(unique_id_string, field, length);
6153
 
        unique_id_string[length] = '\0';
6154
 
      } else {
6155
 
        strncpy(unique_id_string, "", sizeof(unique_id_string));
 
6444
        ink_strlcpy(unique_id_string, field, sizeof(unique_id_string));
6156
6445
      }
6157
 
    } else {
6158
 
      strncpy(unique_id_string, "", sizeof(unique_id_string));
6159
6446
    }
6160
6447
 
6161
6448
    // set the fd for the request
6242
6529
  for (int i = 0; i < hist_size; i++) {
6243
6530
    int r = history[i].reentrancy;
6244
6531
    int e = history[i].event;
6245
 
#if defined(_WIN32)
6246
 
    // Visual C++ preprocessor is unable to stringify __LINE__
6247
 
    //   so we have to waste a ton a memory and store it
6248
 
    //   as an integer
6249
 
    Error("%d   %d   %s:%d", e, r, history[i].fileline, history[i].line);
6250
 
#else
6251
6532
    Error("%d   %d   %s", e, r, history[i].fileline);
6252
 
#endif
6253
6533
  }
6254
6534
 
6255
6535
  // Dump the via string
6271
6551
  // Dump the client request if available
6272
6552
  if (h->valid()) {
6273
6553
    int l = h->length_get();
6274
 
    char *hdr_buf = (char *) xmalloc(l + 1);
 
6554
    char *hdr_buf = (char *)ats_malloc(l + 1);
6275
6555
    int index = 0;
6276
6556
    int offset = 0;
6277
6557
 
6279
6559
 
6280
6560
    hdr_buf[l] = '\0';
6281
6561
    Error("  ----  %s [%" PRId64 "] ----\n%s\n", s, sm_id, hdr_buf);
6282
 
    xfree(hdr_buf);
 
6562
    ats_free(hdr_buf);
6283
6563
  }
6284
6564
}
6285
6565
 
6323
6603
    f(&t_state);
6324
6604
  }
6325
6605
 
6326
 
  Debug("http", "[%" PRId64 "] State Transition: %s -> %s",
 
6606
  DebugSM("http", "[%" PRId64 "] State Transition: %s -> %s",
6327
6607
        sm_id, HttpDebugNames::get_action_name(last_action), HttpDebugNames::get_action_name(t_state.next_action));
6328
6608
 
6329
6609
  set_next_state();
6374
6654
    {
6375
6655
      if (!remapProcessor.using_separate_thread()) {
6376
6656
        do_remap_request(true); /* run inline */
6377
 
        Debug("url_rewrite", "completed inline remapping request for [%" PRId64 "]", sm_id);
 
6657
        DebugSM("url_rewrite", "completed inline remapping request for [%" PRId64 "]", sm_id);
6378
6658
        t_state.url_remap_success = remapProcessor.finish_remap(&t_state);
6379
6659
        call_transact_and_set_next_state(NULL);
6380
6660
      } else {
6386
6666
  
6387
6667
  case HttpTransact::DNS_LOOKUP:
6388
6668
    {
6389
 
      uint32_t addr;
 
6669
      sockaddr const* addr;
6390
6670
 
6391
 
      if (url_remap_mode == 2 && t_state.first_dns_lookup) {
6392
 
        Debug("cdn", "Skipping DNS Lookup");
 
6671
      if (t_state.api_server_addr_set) {
 
6672
        /* If the API has set the server address before the OS DNS lookup
 
6673
         * then we can skip the lookup
 
6674
         */
 
6675
        ip_text_buffer ipb;
 
6676
        DebugSM("dns", "[HttpTransact::HandleRequest] Skipping DNS lookup for API supplied target %s.\n", ats_ip_ntop(&t_state.server_info.addr, ipb, sizeof(ipb)));
 
6677
        // this seems wasteful as we will just copy it right back
 
6678
        ats_ip_copy(t_state.host_db_info.ip(), &t_state.server_info.addr);
 
6679
        t_state.dns_info.lookup_success = true;
 
6680
        call_transact_and_set_next_state(NULL);
 
6681
        break;
 
6682
      } else if (url_remap_mode == 2 && t_state.first_dns_lookup) {
 
6683
        DebugSM("cdn", "Skipping DNS Lookup");
6393
6684
        // skip the DNS lookup
6394
 
        // Debug("cdn","If HandleFiltering has already been called.");
6395
6685
        t_state.first_dns_lookup = false;
6396
6686
        call_transact_and_set_next_state(HttpTransact::HandleFiltering);
6397
6687
        break;
6398
6688
      } else  if (t_state.http_config_param->use_client_target_addr
6399
6689
        && !t_state.url_remap_success
6400
6690
        && t_state.client_info.is_transparent
6401
 
        && 0 != (addr = t_state.state_machine->ua_session->get_netvc()->get_local_ip())
 
6691
        && ats_is_ip(addr = t_state.state_machine->ua_session->get_netvc()->get_local_addr())
6402
6692
      ) {
 
6693
        ip_text_buffer ipb;
6403
6694
        /* If the connection is client side transparent and the URL
6404
6695
           was not remapped, we can use the client destination IP
6405
6696
           address instead of doing a DNS lookup. This is controlled
6406
6697
           by the 'use_client_target_addr' configuration parameter.
6407
6698
        */
6408
 
        Debug("dns", "[HttpTransact::HandleRequest] Skipping DNS lookup for client supplied target %u.%u.%u.%u.\n", PRINT_IP(addr));
6409
 
        t_state.host_db_info.ip() = addr;
 
6699
        DebugSM("dns", "[HttpTransact::HandleRequest] Skipping DNS lookup for client supplied target %s.\n", ats_ip_ntop(addr, ipb, sizeof(ipb)));
 
6700
        ats_ip_copy(t_state.host_db_info.ip(), addr);
6410
6701
        t_state.dns_info.lookup_success = true;
6411
6702
        call_transact_and_set_next_state(NULL);
6412
6703
        break;
6413
6704
      } else if (t_state.parent_result.r == PARENT_UNDEFINED && t_state.dns_info.lookup_success) {
6414
6705
        // Already set, and we don't have a parent proxy to lookup
6415
 
        ink_assert(t_state.host_db_info.ip());
6416
 
        Debug("dns", "[HttpTransact::HandleRequest] Skipping DNS lookup, provided by plugin");
 
6706
        ink_assert(ats_is_ip(t_state.host_db_info.ip()));
 
6707
        DebugSM("dns", "[HttpTransact::HandleRequest] Skipping DNS lookup, provided by plugin");
 
6708
        call_transact_and_set_next_state(NULL);
 
6709
        break;
 
6710
      } else if (t_state.dns_info.looking_up == HttpTransact::ORIGIN_SERVER &&
 
6711
                 t_state.http_config_param->no_dns_forward_to_parent){
 
6712
 
 
6713
        if (t_state.cop_test_page)
 
6714
          ats_ip_copy(t_state.host_db_info.ip(), t_state.state_machine->ua_session->get_netvc()->get_local_addr());
 
6715
 
 
6716
        t_state.dns_info.lookup_success = true;
6417
6717
        call_transact_and_set_next_state(NULL);
6418
6718
        break;
6419
6719
      }
6523
6823
      if (transform_info.vc) {
6524
6824
        ink_assert(t_state.hdr_info.client_response.valid() == 0);
6525
6825
        ink_assert((t_state.hdr_info.transform_response.valid()? true : false) == true);
 
6826
        t_state.hdr_info.cache_response.create(HTTP_TYPE_RESPONSE);
 
6827
        t_state.hdr_info.cache_response.copy(&t_state.hdr_info.transform_response);
 
6828
 
6526
6829
        HttpTunnelProducer *p = setup_cache_transfer_to_transform();
6527
6830
        perform_cache_write_action();
6528
6831
        tunnel.tunnel_run(p);
6529
6832
      } else {
6530
6833
        ink_assert((t_state.hdr_info.client_response.valid()? true : false) == true);
 
6834
        t_state.hdr_info.cache_response.create(HTTP_TYPE_RESPONSE);
 
6835
        t_state.hdr_info.cache_response.copy(&t_state.hdr_info.client_response);
 
6836
 
6531
6837
        perform_cache_write_action();
6532
6838
        t_state.api_next_action = HttpTransact::HTTP_API_SEND_REPONSE_HDR;
6533
6839
        if (hooks_set) {
6791
7097
void
6792
7098
HttpSM::do_redirect()
6793
7099
{
6794
 
  Debug("http_redirect", "[HttpSM::do_redirect]");
 
7100
  DebugSM("http_redirect", "[HttpSM::do_redirect]");
6795
7101
  if (enable_redirection == false || redirection_tries > (HttpConfig::m_master.number_of_redirections)) {
6796
7102
    tunnel.deallocate_redirect_postdata_buffers();
6797
7103
    return;
6823
7129
        int ret = Log::access(&accessor);
6824
7130
 
6825
7131
        if (ret & Log::FULL) {
6826
 
          Debug("http", "[update_stats] Logging system indicates FULL.");
 
7132
          DebugSM("http", "[update_stats] Logging system indicates FULL.");
6827
7133
        }
6828
7134
        if (ret & Log::FAIL) {
6829
7135
          Log::error("failed to log transaction for at least one log object");
6832
7138
 
6833
7139
      if (redirect_url != NULL) {
6834
7140
        redirect_request(redirect_url, redirect_url_len);
6835
 
        xfree(redirect_url);
 
7141
        ats_free(redirect_url);
6836
7142
        redirect_url = NULL;
6837
7143
        redirect_url_len = 0;
6838
7144
        HTTP_INCREMENT_DYN_STAT(http_total_x_redirect_stat);
6857
7163
void
6858
7164
HttpSM::redirect_request(const char *redirect_url, const int redirect_len)
6859
7165
{
6860
 
  Debug("http_redirect", "[HttpSM::redirect_request]");
 
7166
  DebugSM("http_redirect", "[HttpSM::redirect_request]");
6861
7167
  // get a reference to the client request header and client url and check to see if the url is valid
6862
7168
  HTTPHdr & clientRequestHeader = t_state.hdr_info.client_request;
6863
7169
  URL & clientUrl = *clientRequestHeader.url_get();
6910
7216
#if defined(__GNUC__)
6911
7217
      char buf[host_len + 7];
6912
7218
#else
6913
 
      char *buf = (char *)xmalloc(host_len + 7);
 
7219
      char *buf = (char *)ats_malloc(host_len + 7);
6914
7220
#endif
6915
 
      strncpy(buf, host, host_len);
 
7221
      ink_strlcpy(buf, host, host_len);
6916
7222
      host_len += snprintf(buf + host_len, sizeof(buf) - host_len, ":%d", port);
6917
7223
      t_state.hdr_info.client_request.value_set(MIME_FIELD_HOST, MIME_LEN_HOST, buf, host_len);
6918
7224
#if !defined(__GNUC__)
6919
 
      xfree(buf);
 
7225
      ats_free(buf);
6920
7226
#endif
6921
7227
    } else {
6922
7228
      // the client request didn't have a host, so remove it from the headers
6928
7234
  DUMP_HEADER("http_hdrs", &t_state.hdr_info.client_request, sm_id, "Framed Client Request..checking");
6929
7235
}
6930
7236
 
6931
 
void HttpSM::set_http_schedule(Continuation *contp)
 
7237
void
 
7238
HttpSM::set_http_schedule(Continuation *contp)
6932
7239
{
6933
7240
  HTTP_SM_SET_DEFAULT_HANDLER(&HttpSM::get_http_schedule);
6934
7241
  schedule_cont = contp;
6935
7242
}
6936
7243
 
6937
 
int HttpSM::get_http_schedule(int event, void * data)
 
7244
int
 
7245
HttpSM::get_http_schedule(int event, void * data)
6938
7246
{
6939
7247
  NOWARN_UNUSED(data);
6940
7248
  bool plugin_lock;
6961
7269
 
6962
7270
  return 0;
6963
7271
}
 
7272
 
 
7273
bool
 
7274
HttpSM::set_server_session_private(bool private_session)
 
7275
{
 
7276
  if (server_session != NULL) {
 
7277
    server_session->private_session = private_session;
 
7278
    return true;
 
7279
  }
 
7280
  return false;
 
7281
}
 
7282