Displaying #traffic-server/2015-10-28.log:

Wed Oct 28 01:31:45 2015  oag:I did ./configure --enable-debug --enable-cppapi (because I want to poke around with gdb.. I assume the debug build will make that possible)..
Wed Oct 28 01:32:07 2015  oag:but when I run the result I get this: FATAL: PluginVC.cc:296: failed assert `vio->mutex->thread_holding == this_ethread()`
Wed Oct 28 01:33:00 2015  oag:This is using 5.3.1 (I think) on a 64-bit Ubuntu VirtualBox VM.
Wed Oct 28 01:33:31 2015  oag:Is this a known problem with a known work-around by any chance?
Wed Oct 28 01:53:53 2015  oag:Looks rather like TS-1937 (and I can see the diff for the fix .. now if I can only figure out how that applies in the present case..)
Wed Oct 28 01:57:12 2015  kichan:Joined the channel
Wed Oct 28 02:21:59 2015  psp:Joined the channel
Wed Oct 28 02:50:38 2015  blattj:Joined the channel
Wed Oct 28 03:07:59 2015  blattj1:Joined the channel
Wed Oct 28 03:31:00 2015  gancho:Joined the channel
Wed Oct 28 03:36:36 2015  psp:Joined the channel
Wed Oct 28 03:38:18 2015  psp1:Joined the channel
Wed Oct 28 03:39:14 2015  gancho:Joined the channel
Wed Oct 28 03:46:33 2015  _klk_:Joined the channel
Wed Oct 28 05:09:33 2015  msekimura:Joined the channel
Wed Oct 28 08:54:55 2015  Lethalman:Joined the channel
Wed Oct 28 09:09:01 2015  bahumbug:Joined the channel
Wed Oct 28 10:23:45 2015  mturk:Joined the channel
Wed Oct 28 10:23:45 2015  mturk:Joined the channel
Wed Oct 28 12:04:50 2015  Amaryllis:so, with 'regex_remap https://(.*) http://$1' in remap.config, ATS caches http://example.com/ and https://example.com/ using the same cache key - any way around that?
Wed Oct 28 12:05:32 2015  dcarlin:do you have another remap?
Wed Oct 28 12:05:41 2015  dcarlin:should only match https://example.com to http origin
Wed Oct 28 12:06:01 2015  Amaryllis:no, that's the only remap
Wed Oct 28 12:06:17 2015  dcarlin:forward proxy?
Wed Oct 28 12:06:51 2015  Amaryllis:reverse proxy but with remap_required=0 - we send everything to origin using parent.config
Wed Oct 28 12:08:22 2015  dcarlin:what clients are hitting the proxy?
Wed Oct 28 12:08:34 2015  Amaryllis:curl
Wed Oct 28 12:09:40 2015  dcarlin:I would expect that remap not to work for http://example.com
Wed Oct 28 12:10:00 2015  dcarlin:requests for http://example.com shouldn't match that remap since it had https method specified
Wed Oct 28 12:10:22 2015  dcarlin:but I don't know how that interacts with remap_required=0
Wed Oct 28 12:11:09 2015  Amaryllis:right, it doesn't match, so it just goes directly to the parent
Wed Oct 28 12:11:51 2015  dcarlin:so same cache key because origin requests are indistinguishable
Wed Oct 28 12:11:57 2015  Amaryllis:https://dpaste.de/CGQO - maybe adding an explicit remap for http://.* would fix it... or put the port number in the remap key?
Wed Oct 28 12:12:20 2015  Amaryllis:(regex_remap https://(.*) http://$1:443/ ...)
Wed Oct 28 12:12:42 2015  dcarlin:maybe
Wed Oct 28 12:12:54 2015  dcarlin:if that doesn't work, you could try this plugin
Wed Oct 28 12:12:55 2015  dcarlin:http://trafficserver.readthedocs.org/en/latest/reference/plugins/cacheurl.en.html
Wed Oct 28 12:14:23 2015  dcarlin:maybe you could find some hack w/that plugin to have a different cache key
Wed Oct 28 12:14:49 2015  JSeymour:Joined the channel
Wed Oct 28 12:14:56 2015  dcarlin:I am trying to think if you could also Vary: the request so http vs https would be a different alternate of the same url
Wed Oct 28 12:15:20 2015  Amaryllis:does CacheURL work on the original request URI, rather than the remapped one?
Wed Oct 28 12:15:50 2015  Amaryllis:putting the port in the remap doesn't seem to work, it changes the actual port TS connects to...
Wed Oct 28 12:16:23 2015  Amaryllis:oh, or maybe it just confuses the origin, actually
Wed Oct 28 12:16:37 2015  dcarlin:so even though in both instances you connect to origin via http
Wed Oct 28 12:16:43 2015  dcarlin:the response from origin is different?
Wed Oct 28 12:16:59 2015  Amaryllis:yes, because for https:// it includes X-Forwarded-Proto: http
Wed Oct 28 12:17:03 2015  Amaryllis:er, : https
Wed Oct 28 12:18:56 2015  dcarlin:are you adding that with header_rewrite?
Wed Oct 28 12:19:23 2015  Amaryllis:yes
Wed Oct 28 12:20:18 2015  dcarlin:is there a unique header in the response indicating that its an https response that you could Vary on?
Wed Oct 28 12:21:03 2015  dcarlin:n/m that wouldn't work..
Wed Oct 28 12:21:28 2015  Amaryllis:would Vary: X-Forwarded-Proto work?
Wed Oct 28 12:21:34 2015  Amaryllis:it's set in READ_REQUEST_HDR_HOOK
Wed Oct 28 12:22:18 2015  dcarlin:i would try that
Wed Oct 28 12:22:31 2015  dcarlin:i'm just thinking about cached responses
Wed Oct 28 12:22:45 2015  dcarlin:but if its set at that hook it might
Wed Oct 28 12:22:57 2015  Amaryllis:ah, i added another remap: regex_map http://(.*) http://$1
Wed Oct 28 12:23:05 2015  Amaryllis:... and set remap_required=1, and now it seems to be working as expected
Wed Oct 28 12:23:13 2015  dcarlin:sure :)
Wed Oct 28 12:23:24 2015  Amaryllis:oh. no
Wed Oct 28 12:24:10 2015  dcarlin:no?
Wed Oct 28 12:24:10 2015  bahumbug:Joined the channel
Wed Oct 28 12:24:10 2015  bahumbug:Joined the channel
Wed Oct 28 12:24:29 2015  Amaryllis:i thought it had, but after caching the http version it's broken again
Wed Oct 28 12:24:34 2015  dcarlin:ah, since it remaps to the same thing
Wed Oct 28 12:24:50 2015  dcarlin:I would try the Vary: X-Forwarded-Proto in the response from origin and see what happens
Wed Oct 28 12:25:19 2015  dcarlin:I've only ever used header_rewrite as a remap plugin so i've not used those other hooks
Wed Oct 28 12:27:01 2015  dcarlin:as long as X-Forwarded-Proto added early enough I think you're OK
Wed Oct 28 12:29:02 2015  dcarlin:http://trafficserver.readthedocs.org/en/latest/sdk/http-hooks-and-transactions/adding-hooks.en.html?highlight=hooks
Wed Oct 28 12:29:09 2015  dcarlin:think READ_REQUEST_HDR_HOOK is good
Wed Oct 28 12:29:29 2015  dcarlin:"Called immediately after the request header is read from the client."
Wed Oct 28 12:36:54 2015  Amaryllis:well, i modified header_rewrite to add Vary: which seems to work, but it seems a bit ugly :)
Wed Oct 28 12:37:45 2015  Amaryllis:also it includes it in the response so it looks slightly odd
Wed Oct 28 12:37:47 2015  dcarlin:so what
Wed Oct 28 12:38:02 2015  dcarlin:so you add Vary with SEND_RESPONSE_HDR_HOOK
Wed Oct 28 12:38:12 2015  dcarlin:and add X-Forwarded-Proto with READ_REQUEST_HDR_HOOK ?
Wed Oct 28 12:38:55 2015  dcarlin:seems appropriate to me that Vary appears in the response
Wed Oct 28 12:39:40 2015  dcarlin:you have two different responses for same URL based on X-Forwarded-Proto
Wed Oct 28 12:41:10 2015  gancho:Joined the channel
Wed Oct 28 12:43:06 2015  dcarlin:at least its not Vary: Accept-Language where you have a bunch of different alts :)
Wed Oct 28 12:43:10 2015  dcarlin:should only be http/https
Wed Oct 28 12:43:39 2015  dcarlin:proxy.config.cache.limits.http.max_alts 4 should be default
Wed Oct 28 12:44:03 2015  dcarlin:default is actually 5
Wed Oct 28 12:49:40 2015  Amaryllis:well, it's not a massive problem, it just feels wrong to expose an implementation detail -- downstream proxies shouldn't vary on x-forwarded-proto because we remove it anyway
Wed Oct 28 12:49:47 2015  Amaryllis:(but it's highly unlikely any client will actually send that header, so...)
Wed Oct 28 12:53:53 2015  dcarlin:I wonder if you could add X-Fordwaded-Proto with READ_REQUEST_HDR_HOOK then add Vary with SEND_REQUEST_HDR_HOOK and then remove it with SEND_RESPONSE_HDR_HOOK so client doesn't see it? :)
Wed Oct 28 13:02:35 2015  Amaryllis:alternatively, cacheurl as a remap plugin with 'https://(.*) https://$1' seems to work as well
Wed Oct 28 13:10:38 2015  dcarlin:neat
Wed Oct 28 13:11:34 2015  shinrich1:Joined the channel
Wed Oct 28 13:14:08 2015  Amaryllis:now the only question is, why ATS is caching this response at all... https://dpaste.de/3mvg
Wed Oct 28 13:17:17 2015  dcarlin:that is interesting
Wed Oct 28 13:18:00 2015  dcarlin:doing anything in cache.config ?
Wed Oct 28 13:18:15 2015  Amaryllis:nope, empty
Wed Oct 28 13:18:18 2015  dcarlin:what is proxy.config.http.cache.allow_empty_doc set to? Though I would expect that to only apply to cachable objects
Wed Oct 28 13:20:18 2015  Amaryllis:proxy.config.http.cache.allow_empty_doc 1
Wed Oct 28 13:20:25 2015  Amaryllis:(although the response isn't empty anyway)
Wed Oct 28 13:20:53 2015  dcarlin:the 301 response has a body?
Wed Oct 28 13:20:57 2015  Amaryllis:yes
Wed Oct 28 13:21:05 2015  dcarlin:ah, yes I see it..
Wed Oct 28 13:22:22 2015  zwoop:Amaryllis what is your proxy.config.http.cache.required_headers ?
Wed Oct 28 13:23:04 2015  Amaryllis:proxy.config.http.cache.required_headers 2
Wed Oct 28 13:24:08 2015  zwoop:Hmm
Wed Oct 28 13:24:14 2015  zwoop:well, 301's are implicitly cacheable
Wed Oct 28 13:24:28 2015  shinrich2:Joined the channel
Wed Oct 28 13:24:35 2015  Amaryllis:that's true
Wed Oct 28 13:25:07 2015  zwoop:https://tools.ietf.org/html/rfc7231#section-6.4.2
Wed Oct 28 13:25:13 2015  zwoop:"A 301 response is cacheable by default; i.e., unless otherwise
Wed Oct 28 13:25:13 2015  zwoop: indicated by the method definition or explicit cache controls (see
Wed Oct 28 13:25:13 2015  zwoop: Section 4.2.2 of [RFC7234])."
Wed Oct 28 13:25:43 2015  zwoop:and, I remember checking the code for this before, we make a special case for 301's.
Wed Oct 28 13:26:12 2015  Amaryllis:ah. okay
Wed Oct 28 13:34:10 2015  esproul:Joined the channel
Wed Oct 28 13:36:25 2015  davet_:Joined the channel
Wed Oct 28 14:02:42 2015  Amaryllis:[Oct 28 14:02:13.735] Server {0x2b85de191700} NOTE: [ProcessManager::processEventQueue] Shutdown msg received, exiting
Wed Oct 28 14:02:43 2015  Amaryllis:[Oct 28 14:02:29.844] {0x2b7902952c80} STATUS: opened /var/log/trafficserver/diags.log
Wed Oct 28 14:02:55 2015  Amaryllis:this seems like an unusually long time to restart... 16 seconds?
Wed Oct 28 14:04:42 2015  zwoop:how did you restart ?
Wed Oct 28 14:04:48 2015  zwoop:and how large is your disk cache ?
Wed Oct 28 14:06:07 2015  Amaryllis:traffic-line -b, 16GB
Wed Oct 28 14:08:21 2015  zwoop:ah
Wed Oct 28 14:08:36 2015  zwoop:yeah, there's likely some delays when you go through the mgmt port
Wed Oct 28 14:08:41 2015  zwoop:try e.g.
Wed Oct 28 14:08:48 2015  zwoop:trafficserver stop && trafficserver start
Wed Oct 28 14:08:56 2015  zwoop:and look at the times
Wed Oct 28 14:31:32 2015  ibrezac:Joined the channel
Wed Oct 28 15:00:43 2015  bahumbug:Joined the channel
Wed Oct 28 15:19:59 2015  blattj:Joined the channel
Wed Oct 28 16:05:08 2015  reveller1:Joined the channel
Wed Oct 28 16:12:28 2015  msekimura:Joined the channel
Wed Oct 28 16:14:16 2015  shinrich1:Joined the channel
Wed Oct 28 16:14:33 2015  reveller:Joined the channel
Wed Oct 28 16:19:52 2015  _klk_:Joined the channel
Wed Oct 28 16:39:45 2015  gancho:Joined the channel
Wed Oct 28 17:04:14 2015  psp1:Joined the channel
Wed Oct 28 17:25:13 2015  bcall:PSUdaemon: didn't you make a change in ATS to not dump the ram cache when there is a coredump?
Wed Oct 28 17:26:07 2015  bcall:I was looking for the bug
Wed Oct 28 17:27:24 2015  PSUdaemon:yeah
Wed Oct 28 17:27:28 2015  PSUdaemon:but it doesn't work
Wed Oct 28 17:27:29 2015  PSUdaemon:heh
Wed Oct 28 17:27:32 2015  PSUdaemon:cause madvaise
Wed Oct 28 17:27:46 2015  PSUdaemon:there is an open bug for me to fix
Wed Oct 28 17:28:23 2015  dcarlin:know which one it is?
Wed Oct 28 17:28:43 2015  dcarlin:its relevant to my interests
Wed Oct 28 17:29:03 2015  PSUdaemon:TS-3883
Wed Oct 28 17:29:13 2015  dcarlin:thanks
Wed Oct 28 17:29:21 2015  PSUdaemon:TS-3417
Wed Oct 28 17:29:52 2015  dcarlin:linux 3.4
Wed Oct 28 17:30:23 2015  PSUdaemon:i think CentOS 6.x supports it
Wed Oct 28 17:30:27 2015  PSUdaemon:fwiw
Wed Oct 28 17:30:35 2015  PSUdaemon:i think they backported it
Wed Oct 28 17:30:40 2015  dcarlin:yeah I was just looking that up
Wed Oct 28 17:30:51 2015  blattj:Joined the channel
Wed Oct 28 17:30:54 2015  PSUdaemon:are you guys going to work on this?
Wed Oct 28 17:31:04 2015  PSUdaemon:it's very near the top of my stack
Wed Oct 28 17:31:13 2015  dcarlin:then probably not :)
Wed Oct 28 17:31:18 2015  PSUdaemon:but i will refrain if you want to take it
Wed Oct 28 17:31:35 2015  dcarlin:that not my call, but I get the impression there is too much on the plate already
Wed Oct 28 17:31:46 2015  bcall:we are looking at setting up the disk on some new servers and how much space we should leave for core files
Wed Oct 28 17:32:02 2015  dcarlin:yeah thats my immediate need, is partitioning scheme
Wed Oct 28 17:32:08 2015  dcarlin:so huge cores don't clobber everything else
Wed Oct 28 17:32:21 2015  dcarlin:so I'll continue as I was and revisit this later
Wed Oct 28 17:32:30 2015  bcall:yeah
Wed Oct 28 17:32:33 2015  PSUdaemon:we are deploying machines with larger memory and huge ram caches and need this more than we did before
Wed Oct 28 17:32:42 2015  PSUdaemon:k
Wed Oct 28 17:32:46 2015  jpeach:dcarlin: enhance traffic_crashlog so you never need a core :D
Wed Oct 28 17:32:47 2015  dcarlin:yeah we didn't have this problem with 32-bit YTS
Wed Oct 28 17:32:51 2015  bcall:yeah, we are cheap and don't spend money on ram :)
Wed Oct 28 17:33:06 2015  dcarlin:so cheap
Wed Oct 28 17:33:14 2015  dcarlin:jpeach: that would be ideal
Wed Oct 28 17:34:07 2015  bcall:you need a core if you want do dump data strutures
Wed Oct 28 17:35:01 2015  jpeach:well you can dump stuff from traffic_crashlog
Wed Oct 28 17:35:23 2015  jpeach:but obviously you might not get the specific info you want
Wed Oct 28 17:41:31 2015  es:Joined the channel
Wed Oct 28 17:45:53 2015  _klk_:Joined the channel
Wed Oct 28 18:02:05 2015  _klk_:Joined the channel
Wed Oct 28 18:05:13 2015  blattj:Joined the channel
Wed Oct 28 18:08:11 2015  _klk_:Joined the channel
Wed Oct 28 18:28:13 2015  zwoop:seems unlikely crashlog would ever be able to eliminate core files? I mean, how would you possibly "dump" enough info that you never need to do a manual gdb session?
Wed Oct 28 18:29:20 2015  Amaryllis:well, you could read /proc/self/maps, and find out where your memory is, and read it, and write it to a file and... oh, hang on, never mind.
Wed Oct 28 18:36:53 2015  _klk_:Joined the channel
Wed Oct 28 18:36:59 2015  zwoop:yeah, but that's not the same as being able to use a debugger to inspect memory
Wed Oct 28 18:37:16 2015  zwoop:and if you write the memory out, you are no better off than a core file anyways :)
Wed Oct 28 18:37:29 2015  zwoop:the answer is to fix TS-3883
Wed Oct 28 18:37:41 2015  zwoop:it sounded like an easy fix, but PSUdaemon had some concerns, which I'm not clear on ?
Wed Oct 28 18:40:45 2015  PSUdaemon:the concerns is that the memory needed to be aligned properly
Wed Oct 28 18:40:46 2015  jpeach:zwoop: ever? nope; in many cases? hopefully :)
Wed Oct 28 18:40:53 2015  PSUdaemon:and i wanted to just make sure everything was in order
Wed Oct 28 18:41:03 2015  jpeach:zwoop: see proxy/Crash.cc
Wed Oct 28 18:44:47 2015  reveller:Anyone have thoughts on what would cause this ATS to not start with this msg: ERROR: [bindProxyPort] Unable to bind socket: 443 : Permission denied
Wed Oct 28 18:44:55 2015  reveller:happening on one of my test servers
Wed Oct 28 18:47:47 2015  Becoming:Joined the channel
Wed Oct 28 18:50:33 2015  zwoop:reveller maybe you didn't compile with hwloc, maybe you didn't start as root, maybe something running on 443 already (but I'd expect a different error in that case)
Wed Oct 28 18:51:42 2015  reveller:netstat reports nothing on 443... started as root... running same binary as we have in production... there is something particular about this test box that is just not playing nice
Wed Oct 28 18:52:34 2015  blattj:Joined the channel
Wed Oct 28 18:53:00 2015  Becoming:it does bind the 8080:ipv4 connection, just not the 443:ssl:ipv4 connection.
Wed Oct 28 18:56:09 2015  _klk_:Joined the channel
Wed Oct 28 18:56:54 2015  _klk_:Joined the channel
Wed Oct 28 18:58:04 2015  _klk_:Joined the channel
Wed Oct 28 18:58:19 2015  zwoop:well, 8080 is not a privileged port, 443 is
Wed Oct 28 18:58:36 2015  zwoop:you have to be root, or have posix privileges to bind port 443
Wed Oct 28 19:02:56 2015  _klk_:Joined the channel
Wed Oct 28 19:56:32 2015  _klk_:Joined the channel
Wed Oct 28 20:10:46 2015  blattj:Joined the channel
Wed Oct 28 20:32:34 2015  blattj:Joined the channel
Wed Oct 28 20:46:53 2015  shinrich1:Joined the channel
Wed Oct 28 20:53:54 2015  shinrich1:Joined the channel
Wed Oct 28 20:58:38 2015  shinrich2:Joined the channel
Wed Oct 28 21:00:22 2015  shinrich1:Joined the channel
Wed Oct 28 21:04:30 2015  _klk_:Joined the channel
Wed Oct 28 21:06:15 2015  msekimura:Joined the channel
Wed Oct 28 21:09:42 2015  shinrich1:Joined the channel
Wed Oct 28 21:11:46 2015  blattj1:Joined the channel
Wed Oct 28 21:12:52 2015  shinrich2:Joined the channel
Wed Oct 28 21:14:46 2015  shinrich1:Joined the channel
Wed Oct 28 21:16:30 2015  shinrich3:Joined the channel
Wed Oct 28 21:26:16 2015  blattj:Joined the channel
Wed Oct 28 21:28:14 2015  Guss:Joined the channel
Wed Oct 28 21:30:53 2015  Guss:Left the channel
Wed Oct 28 21:31:26 2015  shinrich1:Joined the channel
Wed Oct 28 21:38:01 2015  msekimura:Joined the channel
Wed Oct 28 21:39:44 2015  blattj:Joined the channel
Wed Oct 28 21:44:17 2015  davet_:Left the channel
Wed Oct 28 21:44:42 2015  msekimura:Joined the channel
Wed Oct 28 22:04:52 2015  _klk_:Joined the channel
Wed Oct 28 22:09:28 2015  PSUdaemon:bcall: dcarlin: zwoop: anyone want to test a patch for me?
Wed Oct 28 22:20:57 2015  PSUdaemon:http://ur1.ca/o7lxx
Wed Oct 28 22:25:56 2015  _klk_:Joined the channel
Wed Oct 28 22:28:59 2015  jpeach:PSUdaemon: why remove the ink_assert?
Wed Oct 28 22:31:29 2015  PSUdaemon:everything in the freelist is now page aligned
Wed Oct 28 22:31:44 2015  PSUdaemon:but...i think after having looked at that more, that it per item
Wed Oct 28 22:31:51 2015  PSUdaemon:which should still be "alignment" aligned
Wed Oct 28 22:31:55 2015  PSUdaemon:so it might need to go back in
Wed Oct 28 22:32:02 2015  PSUdaemon:but can be tested as is
Wed Oct 28 23:02:02 2015  _klk_:Joined the channel

Comments