StrategiesBug2.txt

[May 12 18:49:21.363] traffic_server DEBUG: <HttpConfig.cc:129 (load_server_session_sharing_match)> (http_config) enum mask value both
[May 12 18:49:21.363] traffic_server DEBUG: <HttpConfig.cc:82 (http_config_enum_search)> (http_config) enum element both
[May 12 18:49:21.363] traffic_server DEBUG: <HttpConfig.cc:82 (http_config_enum_search)> (http_config) enum element thread
[May 12 18:49:21.374] traffic_server DEBUG: <DNS.cc:1810 (ink_dns_init)> (dns) ink_dns_init: called with init_called = 0
[May 12 18:49:21.403] traffic_server DEBUG: <DNS.cc:287 (dns_init)> (dns) localhost=d761696b8abf
[May 12 18:49:21.403] traffic_server DEBUG: <DNS.cc:288 (dns_init)> (dns) Round-robin nameservers = 1
[May 12 18:49:21.403] traffic_server DEBUG: <DNS.cc:294 (dns_init)> (dns) Nameserver list specified "127.0.0.1:61001"
[May 12 18:49:21.403] traffic_server DEBUG: <DNS.cc:301 (dns_init)> (dns) Nameserver list - parsing "127.0.0.1:61001"
[May 12 18:49:21.404] traffic_server DEBUG: <DNS.cc:341 (dns_init)> (dns) Adding nameserver 127.0.0.1:61001 to nameserver list
[May 12 18:49:21.404] [ET_NET 0] DEBUG: <DNS.cc:550 (startEvent)> (dns) DNSHandler::startEvent: on thread 0
[May 12 18:49:21.404] [ET_NET 0] DEBUG: <DNS.cc:495 (open_con)> (dns) open_con: opening connection 127.0.0.1:61001
[May 12 18:49:21.404] [ET_NET 0] DEBUG: <DNSConnection.cc:147 (connect)> (dns) random port = 0.0.0.0:29688
[May 12 18:49:21.404] [ET_NET 0] DEBUG: <DNS.cc:523 (open_con)> (dns) opening connection 127.0.0.1:61001 SUCCEEDED for 0
[May 12 18:49:21.404] [ET_NET 0] DEBUG: <DNS.cc:579 (startEvent)> (dns_pas) opened connection to 127.0.0.1:61001, n_con = 1
[May 12 18:49:21.510] traffic_server DEBUG: <NextHopSelectionStrategy.cc:52 (NextHopSelectionStrategy)> (next_hop) Using a selection strategy of type NH_CONSISTENT_HASH, max_retriers: 2
[May 12 18:49:21.510] traffic_server DEBUG: <NextHopSelectionStrategy.cc:61 (Init)> (next_hop) calling Init()
[May 12 18:49:21.512] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo0:0 into host_map
[May 12 18:49:21.512] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo0:61002 into host_map
[May 12 18:49:21.512] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo1:0 into host_map
[May 12 18:49:21.512] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo1:61006 into host_map
[May 12 18:49:21.512] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo2:0 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo2:61010 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo3:0 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo3:61014 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo4:0 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo4:61018 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo5:0 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo5:61022 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo6:0 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo6:61026 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo7:0 into host_map
[May 12 18:49:21.513] traffic_server DEBUG: <NextHopHealthStatus.cc:37 (insert)> (next_hop) inserting foo7:61030 into host_map
[May 12 18:49:21.515] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 0, name: foo0, hostname: foo0, stategy: the-strategy
[May 12 18:49:21.517] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 1, name: foo1, hostname: foo1, stategy: the-strategy
[May 12 18:49:21.520] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 2, name: foo2, hostname: foo2, stategy: the-strategy
[May 12 18:49:21.524] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 3, name: foo3, hostname: foo3, stategy: the-strategy
[May 12 18:49:21.526] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 4, name: foo4, hostname: foo4, stategy: the-strategy
[May 12 18:49:21.529] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 5, name: foo5, hostname: foo5, stategy: the-strategy
[May 12 18:49:21.531] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 6, name: foo6, hostname: foo6, stategy: the-strategy
[May 12 18:49:21.533] traffic_server DEBUG: <NextHopConsistentHash.cc:116 (Init)> (next_hop) Loading hash rings - ring: 0, host record: 7, name: foo7, hostname: foo7, stategy: the-strategy
[May 12 18:49:21.541] traffic_server DEBUG: <traffic_server.cc:2172 (main)> (http_listen) Not delaying listen
[May 12 18:49:21.728] [ET_NET 3] DEBUG: <ProtocolProbeSessionAccept.cc:187 (mainEvent)> (http) probe needs data, read..
[May 12 18:49:21.728] [ET_NET 3] DEBUG: <HttpSessionAccept.cc:49 (accept)> (http_seq) [HttpSessionAccept:mainEvent 0x7fca8401fc20] accepted connection from 127.0.0.1:51136 transport type = 1
[May 12 18:49:21.729] [ET_NET 3] DEBUG: <Http1ClientSession.cc:185 (new_connection)> (http_cs) [0] session born, netvc 0x7fca8401fc20
[May 12 18:49:21.729] [ET_NET 3] DEBUG: <Http1ClientSession.cc:411 (release)> (http_cs) [0] data already in buffer, starting new transaction
[May 12 18:49:21.736] [ET_NET 3] DEBUG: <HttpSM.h:213 (PostDataBuffers)> (http_redirect) [PostDataBuffers::PostDataBuffers]
[May 12 18:49:21.736] [ET_NET 3] DEBUG: <ProxyTransaction.cc:49 (new_transaction)> (http_txn) [0] Starting transaction 1 using sm [0]
[May 12 18:49:21.736] [ET_NET 3] DEBUG: <HttpSM.cc:2681 (main_handler)> (http) [0] [HttpSM::main_handler, VC_EVENT_READ_READY/TS_EVENT_VCONN_READ_READY]
[May 12 18:49:21.736] [ET_NET 3] DEBUG: <HttpSM.cc:697 (state_read_client_request_header)> (http) [0] [&HttpSM::state_read_client_request_header, VC_EVENT_READ_READY/TS_EVENT_VCONN_READ_READY]
[May 12 18:49:21.736] [ET_NET 3] DEBUG: <HttpSM.cc:849 (state_read_client_request_header)> (http) [0] done parsing client request header
[May 12 18:49:21.736] [ET_NET 3] DEBUG: <HttpTransact.cc:1360 (ModifyRequest)> (http_trans) [0] START HttpTransact::ModifyRequest
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HttpTransact.cc:1434 (ModifyRequest)> (http_trans) [0] END HttpTransact::ModifyRequest
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HttpTransact.cc:1436 (ModifyRequest)> (http_trans) Next action SM_ACTION_API_READ_REQUEST_HDR; HttpTransact::StartRemapRequest
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_UNDEFINED -> SM_ACTION_API_READ_REQUEST_HDR
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HttpTransact.cc:971 (StartRemapRequest)> (http_trans) [0] START HttpTransact::StartRemapRequest
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HttpTransact.cc:991 (StartRemapRequest)> (http_trans) [0] Before Remapping:
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) HTTP_HEADER 0x7fcad81da888: [T: 3, L:   48, OBJFLAGS: 0]  
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HTTP.cc:546 (http_hdr_describe)> (http) [TYPE: REQ, V: 0101, URL: 0x7fcad81dab08, METHOD: "GET", METHOD_LEN: 3, FIELDS: 0x7fcad81da8b8]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) URL 0x7fcad81dab08: [T: 2, L:  112, OBJFLAGS: 0]  
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1678 (url_describe)> (http) [URLTYPE: 1, SWKSIDX: 99,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1680 (url_describe)> (http) 	SCHEME: "http", SCHEME_LEN: 4,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1681 (url_describe)> (http) 	USER: "", USER_LEN: 0,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1683 (url_describe)> (http) 	PASSWORD: "", PASSWORD_LEN: 0,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1684 (url_describe)> (http) 	HOST: "dummy.com", HOST_LEN: 9,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1686 (url_describe)> (http) 	PORT: "", PORT_LEN: 0, PORT_NUM: 0
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1687 (url_describe)> (http) 	PATH: "obj", PATH_LEN: 3,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1689 (url_describe)> (http) 	PARAMS: "", PARAMS_LEN: 0,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1691 (url_describe)> (http) 	QUERY: "", QUERY_LEN: 0,
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <URL.cc:1693 (url_describe)> (http) 	FRAGMENT: "", FRAGMENT_LEN: 0]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) MIME_HEADER 0x7fcad81da8b8: [T: 4, L:  592, OBJFLAGS: 0]  
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2633 (mime_hdr_describe)> (http) 	[PBITS: 0x0008010001000001, SLACC: 0xFFFFFFF2FFFFFFFF3FFFFFFFFFF1FFFF, HEADBLK: 0x7fcad81da8f8, TAILBLK: 0x7fcad81da8f8]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2638 (mime_hdr_describe)> (http) 	[CBITS: 0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) FIELD_BLOCK 0x7fcad81da8f8: [T: 5, L:  528, OBJFLAGS: 0]  
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2654 (mime_field_block_describe)> (http) [FREETOP: 4, NEXTBLK: (nil)]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 0 (0x7fcad81da908), LIVE    
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Host", N_LEN: 4, N_IDX: 30, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "dummy.com", V_LEN: 9, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 17, F: 1]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 1 (0x7fcad81da928), LIVE    
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "User-Agent", N_LEN: 10, N_IDX: 64, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "curl/7.66.0-DEV", V_LEN: 15, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 29, F: 1]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 2 (0x7fcad81da948), LIVE    
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Accept", N_LEN: 6, N_IDX: 4, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "*/*", V_LEN: 3, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 13, F: 1]
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 3 (0x7fcad81da968), LIVE    
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Proxy-Connection", N_LEN: 16, N_IDX: 50, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "Keep-Alive", V_LEN: 10, 
[May 12 18:49:21.737] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 30, F: 1]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
+++++++++ Incoming Request +++++++++
-- State Machine Id: 0
GET http://dummy.com/obj HTTP/1.1
Host: dummy.com
User-Agent: curl/7.66.0-DEV
Accept: */*
Proxy-Connection: Keep-Alive

[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1003 (StartRemapRequest)> (http_trans) [0] END HttpTransact::StartRemapRequest
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1005 (StartRemapRequest)> (http_trans) [0] Checking if transaction wants to upgrade
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1012 (StartRemapRequest)> (http_trans) Next action SM_ACTION_API_PRE_REMAP; HttpTransact::PerformRemap
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_API_READ_REQUEST_HDR -> SM_ACTION_API_PRE_REMAP
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1018 (PerformRemap)> (http_trans) [0] Inside PerformRemap
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1019 (PerformRemap)> (http_trans) Next action SM_ACTION_REMAP_REQUEST; HttpTransact::EndRemapRequest
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_API_PRE_REMAP -> SM_ACTION_REMAP_REQUEST
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpSM.cc:4155 (do_remap_request)> (http_seq) [HttpSM::do_remap_request] Remapping request
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1025 (EndRemapRequest)> (http_trans) [0] START HttpTransact::EndRemapRequest
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1031 (EndRemapRequest)> (http_trans) [0] EndRemapRequest host is foo_org
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1169 (EndRemapRequest)> (http_trans) [0] After Remapping:
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) HTTP_HEADER 0x7fcad81da888: [T: 3, L:   48, OBJFLAGS: 0]  
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HTTP.cc:546 (http_hdr_describe)> (http) [TYPE: REQ, V: 0101, URL: 0x7fcad81dab08, METHOD: "GET", METHOD_LEN: 3, FIELDS: 0x7fcad81da8b8]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) URL 0x7fcad81dab08: [T: 2, L:  112, OBJFLAGS: 0]  
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1678 (url_describe)> (http) [URLTYPE: 1, SWKSIDX: 99,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1680 (url_describe)> (http) 	SCHEME: "http", SCHEME_LEN: 4,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1681 (url_describe)> (http) 	USER: "", USER_LEN: 0,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1683 (url_describe)> (http) 	PASSWORD: "", PASSWORD_LEN: 0,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1684 (url_describe)> (http) 	HOST: "foo_org", HOST_LEN: 7,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1686 (url_describe)> (http) 	PORT: "61034", PORT_LEN: 5, PORT_NUM: 61034
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1687 (url_describe)> (http) 	PATH: "obj", PATH_LEN: 3,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1689 (url_describe)> (http) 	PARAMS: "", PARAMS_LEN: 0,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1691 (url_describe)> (http) 	QUERY: "", QUERY_LEN: 0,
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <URL.cc:1693 (url_describe)> (http) 	FRAGMENT: "", FRAGMENT_LEN: 0]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) MIME_HEADER 0x7fcad81da8b8: [T: 4, L:  592, OBJFLAGS: 0]  
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2633 (mime_hdr_describe)> (http) 	[PBITS: 0x0008010001000001, SLACC: 0xFFFFFFF2FFFFFFFF3FFFFFFFFFF1FFFF, HEADBLK: 0x7fcad81da8f8, TAILBLK: 0x7fcad81da8f8]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2638 (mime_hdr_describe)> (http) 	[CBITS: 0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) FIELD_BLOCK 0x7fcad81da8f8: [T: 5, L:  528, OBJFLAGS: 0]  
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2654 (mime_field_block_describe)> (http) [FREETOP: 4, NEXTBLK: (nil)]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 0 (0x7fcad81da908), LIVE    
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Host", N_LEN: 4, N_IDX: 30, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "foo_org:61034", V_LEN: 13, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 0, RAWLEN: 21, F: 1]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 1 (0x7fcad81da928), LIVE    
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "User-Agent", N_LEN: 10, N_IDX: 64, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "curl/7.66.0-DEV", V_LEN: 15, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 29, F: 1]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 2 (0x7fcad81da948), LIVE    
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Accept", N_LEN: 6, N_IDX: 4, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "*/*", V_LEN: 3, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 13, F: 1]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 3 (0x7fcad81da968), LIVE    
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Proxy-Connection", N_LEN: 16, N_IDX: 50, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "Keep-Alive", V_LEN: 10, 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 30, F: 1]
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1188 (EndRemapRequest)> (http_trans) [0] END HttpTransact::EndRemapRequest
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpTransact.cc:1194 (EndRemapRequest)> (http_trans) Next action SM_ACTION_API_POST_REMAP; HttpTransact::HandleRequest
[May 12 18:49:21.738] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_REMAP_REQUEST -> SM_ACTION_API_POST_REMAP
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HttpTransact.cc:1473 (HandleRequest)> (http_trans) [0] START HttpTransact::HandleRequest
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HttpTransact.cc:5379 (check_request_validity)> (http_trans) [0] [init_stat_vars_from_req] set req cont length to -1
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HttpTransact.cc:6364 (is_request_valid)> (http_trans) [0] [is_request_valid] no request header errors
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HttpTransact.cc:1495 (HandleRequest)> (http_seq) [0] [HttpTransact::HandleRequest] request valid.
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) HTTP_HEADER 0x7fcad81da888: [T: 3, L:   48, OBJFLAGS: 0]  
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HTTP.cc:546 (http_hdr_describe)> (http) [TYPE: REQ, V: 0101, URL: 0x7fcad81dab08, METHOD: "GET", METHOD_LEN: 3, FIELDS: 0x7fcad81da8b8]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) URL 0x7fcad81dab08: [T: 2, L:  112, OBJFLAGS: 0]  
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1678 (url_describe)> (http) [URLTYPE: 1, SWKSIDX: 99,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1680 (url_describe)> (http) 	SCHEME: "http", SCHEME_LEN: 4,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1681 (url_describe)> (http) 	USER: "", USER_LEN: 0,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1683 (url_describe)> (http) 	PASSWORD: "", PASSWORD_LEN: 0,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1684 (url_describe)> (http) 	HOST: "foo_org", HOST_LEN: 7,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1686 (url_describe)> (http) 	PORT: "61034", PORT_LEN: 5, PORT_NUM: 61034
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1687 (url_describe)> (http) 	PATH: "obj", PATH_LEN: 3,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1689 (url_describe)> (http) 	PARAMS: "", PARAMS_LEN: 0,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1691 (url_describe)> (http) 	QUERY: "", QUERY_LEN: 0,
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <URL.cc:1693 (url_describe)> (http) 	FRAGMENT: "", FRAGMENT_LEN: 0]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) MIME_HEADER 0x7fcad81da8b8: [T: 4, L:  592, OBJFLAGS: 0]  
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2633 (mime_hdr_describe)> (http) 	[PBITS: 0x0008010001000001, SLACC: 0xFFFFFFF2FFFFFFFF3FFFFFFFFFF1FFFF, HEADBLK: 0x7fcad81da8f8, TAILBLK: 0x7fcad81da8f8]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2638 (mime_hdr_describe)> (http) 	[CBITS: 0x00000000, T_MAXAGE: 0, T_SMAXAGE: 0, T_MAXSTALE: 0, T_MINFRESH: 0, PNO$: 0]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <HdrHeap.cc:55 (obj_describe)> (http) FIELD_BLOCK 0x7fcad81da8f8: [T: 5, L:  528, OBJFLAGS: 0]  
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2654 (mime_field_block_describe)> (http) [FREETOP: 4, NEXTBLK: (nil)]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 0 (0x7fcad81da908), LIVE    
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Host", N_LEN: 4, N_IDX: 30, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "foo_org:61034", V_LEN: 13, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 0, RAWLEN: 21, F: 1]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 1 (0x7fcad81da928), LIVE    
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "User-Agent", N_LEN: 10, N_IDX: 64, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "curl/7.66.0-DEV", V_LEN: 15, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 29, F: 1]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 2 (0x7fcad81da948), LIVE    
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Accept", N_LEN: 6, N_IDX: 4, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "*/*", V_LEN: 3, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 13, F: 1]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2658 (mime_field_block_describe)> (http) 	SLOT # 3 (0x7fcad81da968), LIVE    
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2667 (mime_field_block_describe)> (http) [N: "Proxy-Connection", N_LEN: 16, N_IDX: 50, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2668 (mime_field_block_describe)> (http) V: "Keep-Alive", V_LEN: 10, 
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2670 (mime_field_block_describe)> (http) NEXTDUP: (nil), RAW: 1, RAWLEN: 30, F: 1]
[May 12 18:49:21.739] [ET_NET 3] DEBUG: <MIME.cc:2673 (mime_field_block_describe)> (http) 
[May 12 18:49:21.740] [ET_NET 3] DEBUG: <HttpTransact.cc:2658 (CallOSDNSLookup)> (http) [0] [HttpTransact::callos] foo_org 
[May 12 18:49:21.740] [ET_NET 3] DEBUG: <HttpTransact.cc:2672 (CallOSDNSLookup)> (http_trans) Next action SM_ACTION_DNS_LOOKUP; OSDNSLookup
[May 12 18:49:21.740] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_API_POST_REMAP -> SM_ACTION_DNS_LOOKUP
[May 12 18:49:21.740] [ET_NET 3] DEBUG: <HttpSM.cc:4234 (do_hostdb_lookup)> (http_seq) [HttpSM::do_hostdb_lookup] Doing DNS Lookup
[May 12 18:49:21.740] [ET_NET 3] DEBUG: <HostDB.cc:696 (getby)> (hostdb) delaying (force=0) answer for foo_org [timeout 0]
[May 12 18:49:21.759] [ET_NET 3] DEBUG: <HostDB.cc:1576 (do_dns)> (hostdb) DNS foo_org
[May 12 18:49:21.759] [ET_NET 3] DEBUG: <DNS.cc:1258 (getby)> (dns) received query foo_org type = 1, timeout = 0
[May 12 18:49:21.760] [ET_NET 0] DEBUG: <DNS.cc:1224 (mainEvent)> (dns) enqueuing query foo_org
[May 12 18:49:21.760] [ET_NET 0] DEBUG: <DNS.cc:1230 (mainEvent)> (dns) adding first to collapsing queue
[May 12 18:49:21.760] [ET_NET 0] DEBUG: <DNS.cc:1142 (write_dns_event)> (dns) send query (qtype=1) for foo_org to fd 24
[May 12 18:49:21.760] [ET_NET 0] DEBUG: <DNS.cc:1176 (write_dns_event)> (dns) sent qname = foo_org, id = 7753, nameserver = 0
[May 12 18:49:21.760] [ET_NET 0] DEBUG: <P_DNSProcessor.h:197 (sent_one)> (dns) sent_one: failover_number for resolver 0 is 1
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:884 (recv_dns)> (dns) DNSHandler::recv_dns res = [41]
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:908 (recv_dns)> (dns) received packet size = 41
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:911 (recv_dns)> (dns) round-robin: nameserver 0 DNS response code = 0
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:1539 (dns_process)> (dns) Got 1 DNS records for [foo_org]
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:1753 (dns_process)> (dns) received A name = foo_org
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:1770 (dns_process)> (dns) received A = 127.0.0.1
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:1791 (dns_process)> (dns) Returning 1 DNS records for [foo_org]
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:1359 (dns_result)> (dns) SUCCESS result for foo_org = 127.0.0.1 retry 0
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <DNS.cc:1448 (postOneEvent)> (dns) called back continuation for foo_org
[May 12 18:49:21.764] [ET_NET 0] DEBUG: <DNS.cc:884 (recv_dns)> (dns) DNSHandler::recv_dns res = [-11]
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HostDB.cc:1213 (dnsEvent)> (hostdb) allocating 8 bytes for foo_org with 0 RR records at [0x7fcac803bf80]
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HostDB.cc:1018 (lookup_done)> (hostdb) done 127.0.0.1 TTL 300
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpSM.cc:2681 (main_handler)> (http) [0] [HttpSM::main_handler, EVENT_HOST_DB_LOOKUP/TS_EVENT_HOST_LOOKUP]
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpSM.cc:2337 (state_hostdb_lookup)> (http) [0] [&HttpSM::state_hostdb_lookup, EVENT_HOST_DB_LOOKUP/TS_EVENT_HOST_LOOKUP]
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpTransact.cc:1923 (OSDNSLookup)> (http_trans) [0] [HttpTransact::OSDNSLookup]
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpTransact.cc:1960 (OSDNSLookup)> (http_seq) [0] [HttpTransact::OSDNSLookup] DNS Lookup successful
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpTransact.cc:2001 (OSDNSLookup)> (http_trans) [0] [OSDNSLookup] DNS lookup for O.S. successful IP: 127.0.0.1
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpTransact.cc:2096 (HandleRequestAuthorized)> (http_trans) Next action SM_ACTION_API_OS_DNS; HttpTransact::DecideCacheLookup
[May 12 18:49:21.764] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_DNS_LOOKUP -> SM_ACTION_API_OS_DNS
[May 12 18:49:21.765] [ET_NET 3] DEBUG: <HttpTransact.cc:2175 (DecideCacheLookup)> (http_trans) [0] [DecideCacheLookup] Will NOT do cache lookup.
[May 12 18:49:21.765] [ET_NET 3] DEBUG: <HttpTransact.cc:2176 (DecideCacheLookup)> (http_seq) [0] [DecideCacheLookup] Will NOT do cache lookup
[May 12 18:49:21.765] [ET_NET 3] DEBUG: <HttpTransact.cc:2200 (DecideCacheLookup)> (http_trans) Next action SM_ACTION_API_CACHE_LOOKUP_COMPLETE; LookupSkipOpenServer
[May 12 18:49:21.765] [ET_NET 3] DEBUG: <HttpSM.cc:7337 (call_transact_and_set_next_state)> (http) [0] State Transition: SM_ACTION_API_OS_DNS -> SM_ACTION_API_CACHE_LOOKUP_COMPLETE
[May 12 18:49:21.765] [ET_NET 3] DEBUG: <NextHopConsistentHash.cc:239 (findNextHop)> (next_hop) [0] firstcall, line_number: -1, result: PARENT_UNDEFINED
[May 12 18:49:21.765] [ET_NET 3] DEBUG: <NextHopConsistentHash.cc:290 (findNextHop)> (next_hop) [0] Initial parent lookups: 1
Fatal: NextHopConsistentHash.cc:403: failed assertion `result->port != 0`
traffic_server: received signal 6 (Aborted)
traffic_server - STACK TRACE: 
Traffic Server 10.0.0 May  5 2021 16:10:20 d761696b8abf
traffic_server: using root directory '/Users/wkaras/REPOS/TS2/tests/_sandbox/strategies_ch/ts'
Parent Selection Config
	RetryTime 300
	No Default Parent
  Control Matcher Table: [ParentSelection]
traffic_server(_Z19crash_logger_invokeiP9siginfo_tPv+0xc3)[0x674367]
/lib64/libpthread.so.0(+0xf680)[0x7fcadd73f680]
/lib64/libc.so.6(gsignal+0x37)[0x7fcadc976207]
/lib64/libc.so.6(abort+0x148)[0x7fcadc9778f8]
/Users/wkaras/TSX/TS2/lib/libtscore.so.10(_Z11ink_warningPKcz+0x0)[0x7fcadef2268f]
/Users/wkaras/TSX/TS2/lib/libtscore.so.10(_Z17ats_base64_encodePKhmPcmPm+0x0)[0x7fcadef1e287]
traffic_server(_ZN21NextHopConsistentHash11findNextHopEP13tsapi_httptxnPvl+0x156a)[0x7dfd5a]
traffic_server[0x749599]
traffic_server[0x74bb00]
traffic_server(_ZN12HttpTransact20LookupSkipOpenServerEPNS_5StateE+0x1b)[0x759745]
traffic_server(_ZN6HttpSM32call_transact_and_set_next_stateEPFvPN12HttpTransact5StateEE+0x76)[0x733836]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x175)[0x717a4b]
traffic_server(_ZN6HttpSM14do_api_calloutEv+0x40)[0x73d6d2]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x60)[0x733a7e]
traffic_server(_ZN6HttpSM32call_transact_and_set_next_stateEPFvPN12HttpTransact5StateEE+0x235)[0x7339f5]
traffic_server(_ZN6HttpSM17handle_api_returnEv+0x175)[0x717a4b]
traffic_server(_ZN6HttpSM14do_api_calloutEv+0x40)[0x73d6d2]
traffic_server(_ZN6HttpSM14set_next_stateEv+0x60)[0x733a7e]
traffic_server(_ZN6HttpSM32call_transact_and_set_next_stateEPFvPN12HttpTransact5StateEE+0x235)[0x7339f5]
traffic_server(_ZN6HttpSM19state_hostdb_lookupEiPv+0x28f)[0x71b75d]
traffic_server(_ZN6HttpSM12main_handlerEiPv+0x3d3)[0x71d875]
traffic_server(_ZN12Continuation11handleEventEiPv+0xc9)[0x67a5ad]
traffic_server[0x888010]
traffic_server(_ZN18HostDBContinuation8dnsEventEiP7HostEnt+0x1837)[0x88d3a9]
traffic_server(_ZN12Continuation11handleEventEiPv+0xc9)[0x67a5ad]
traffic_server(_ZN8DNSEntry12postOneEventEiP5Event+0x141)[0x8a6771]
traffic_server(_ZN12Continuation11handleEventEiPv+0xc9)[0x67a5ad]
traffic_server(_ZN7EThread13process_eventEP5Eventi+0x143)[0x9e83d1]
traffic_server(_ZN7EThread13process_queueEP5QueueI5EventNS1_9Link_linkEEPiS5_+0xd3)[0x9e85f9]
traffic_server(_ZN7EThread15execute_regularEv+0x1db)[0x9e8899]
traffic_server(_ZN7EThread7executeEv+0x107)[0x9e8cbf]
traffic_server[0x9e74c0]
/lib64/libpthread.so.0(+0x7dd5)[0x7fcadd737dd5]
/lib64/libc.so.6(clone+0x6d)[0x7fcadca3eb3d]