[06:10:44] 10Traffic, 06Operations, 06Community-Liaisons (Jul-Sep-2016): Help contact bot owners about the end of HTTP access to the API - https://phabricator.wikimedia.org/T136674#2343854 (10Dzahn) Brandon/Sherry asked me to contact user Paulis for his bot Fkraus because he speaks German. I mailed him in German about it. [07:30:49] just found https://github.com/varnishcache/varnish-cache/commit/36e8ac2fc77e8f8b63ea0a41b14d6555ea50433c [07:31:12] VUT seems to be in libvarnishapi (this is master though) [08:33:19] elukey: nice [08:35:15] this is uplex's approach to the varnishkafka problem, I'm not sure whether I mentioned it here or not https://code.uplex.de/uplex-varnish/trackrdrd [08:35:18] elukey: ^ [08:37:43] ema: I think I've read something posted by bblack.. Is it the one using the approach of logging everything via VCL? [08:39:33] elukey: right so you log the stuff you want to track from VCL [08:39:47] > VCL_Log entries result from use of the log() function provided by the standard vmod std distributed with Varnish. The log() call must include the prefix track, the XID and the data to be logged, or a sharding key. [08:40:15] that's a pretty nice idea [08:40:46] to solve the problem of what to output/how in vk we're essentially using the format string [08:41:53] yeah it looks good.. The only nice thing about having the format conf decoupled from Varnish is that a change wouldn't need a varnish restart [08:43:41] plus https://code.uplex.de/uplex-varnish/trackrdrd/tree/master/src/test \o/ [08:44:31] anyhow, I proposed to my team a long term goal to evaluate unit/functional/integration testing for vk [08:44:52] If we want to migrate to another tool (or test it) we can try to do it first [11:05:54] 10Traffic, 06Operations, 13Patch-For-Review: Investigate TCP Fast Open for tlsproxy - https://phabricator.wikimedia.org/T108827#2396050 (10ema) So, here are a few findings so far. tshark can be used to detect SYN packets with a TFO cookie request: tshark -f 'tcp[tcpflags] & tcp-syn != 0' -Y 'tcp.options.... [13:47:48] elukey: if VCL is formatting the string, it's not a varnish restart, just a runtime VCL reload (what puppet automates for us all the time) [13:48:21] ah nice :) [13:51:56] bblack: I found https://github.com/varnishcache/varnish-cache/blob/4.1/lib/libvarnishapi/vsl.c#L93 - the T_opt should be the VSL read timeout afaiu. Still trying to repro it on my vagrant VM with not luck. I added the -T option to vk but it is not working atm [13:52:18] VSL Begin -> End timeout, not read sorry [13:55:02] also found in https://github.com/varnishcache/varnish-cache/blob/a50c99f6b3883d1a58cedfe26511bfc0d30d50bb/lib/libvarnishapi/vsl_dispatch.c#L1337 [13:57:33] so there is a varnishd-side timeout where if it's been too long since a txn started, it will eventually flush a finished log to shm (which probably applies to cases like pipe that never really finish in reasonable time) [13:58:21] it's still not clear to me if varnishd writes the whole txn (all records) at that point in time at once, or if it actually writes part of the log records at the start, and finishes them on the timeout, and commonly other consuming tools just don't report txns until they're finished. [13:58:50] (which case things like pipe and long transfer times for large objects could have an impact on total shm buffer size. I wouldn't think they would do things that way, precisely so shm size doesn't get out of hand) [14:01:49] The null end timestamps seem to point to the first option, but I'll be sure once I'll find a repro :) [16:27:36] something I've been reading up on, it's been around a couple of years, but advice is scarce [16:27:49] tcp_notsent_lowat [16:28:01] there's a sysctl to set it for all sockets on the host, and a setsockopt() for per-socket [16:28:12] it's a confusing topic with few great info sources, but the gist is this: [16:28:45] the socket send buffer is really used for two kinds of send-buffering: un-acked data (out on the wire, BDP), and un-sent data (locally buffered on the host and not sent over the wire yet). [16:29:28] we tend to autotune/enlarge buffers to deal with BDP/unacked problems, but it oversizes how much data the app can cram into the buffer when there's still lots of unsent pending, too. [16:29:50] (the normal behavior is if the app has any data to send, and epoll() or similar indicates writability, keep filling that local buffer with unsent data) [16:30:29] tcp_notsent_lowat basically tells the kernel "don't indicate (via e.g. epoll()) that the socket is writeable until the amount of *unsent* data drops below this amount". it doesn't affect the unacked part. [16:30:51] so in essence it's local bufferbloat control on the sending server side of the TCP connection [16:31:20] the downside of setting it (at all, or setting it too small), is that the application is woken up to send writes more often in smaller amounts, increasing CPU waste [16:32:00] the upside of setting it is that we don't stack up megabytes of data in the local buffer, which apparently has important positive effects on things like head-of-line blocking, especially with HTTP/2 [16:32:47] e.g. if chrome is trying to do priotized channels over HTTP/2 and load certain content types before others and blah blah... if nginx already stuffed 26MB of data into the socket buffer there's no pulling back at that point to decide to send higher-priority data over thew lower-prio data already in the buffer [16:33:22] keeping the unsent buffer small and reducing that local queueing means priority changes can take effect more-immediately [16:33:52] ~128KB seems to be the advice, we could play with the number a bit. bad idea to set it below typical cwnd of course, or you risk occasionally starving the connection for data. [16:34:49] we could patch nginx to set it as as sockopt, but honestly it seems most flows benefit from it anyways, may as well set the sysctl. might be helpful elsewhere too (even down in application layer hosts and such), perhaps even as a default for jessies or whatever. [16:38:11] bblack: about the upside - we wouldn't stack too much data while keeping buffers big enough ? (for example, for unack data) [16:51:01] bblack: about the downside, we're usually not CPU bound, so happy times? [16:52:52] (on cp* hosts) [17:17:53] yeah that's what I think [17:18:02] I also want to raise our gzip compression level [17:18:10] (something else we can waste CPU on) [17:18:25] varnish default is 6, we could set it to 8 for when varnish does the gzipping [17:18:37] it's runtime-adjustable I think, so can experiment first [17:18:58] and then there's cloudflare's optimized zlib, if we want to bring cpu back down (it might not really be necc) [17:30:31] 10Traffic, 06Operations, 10Wikimedia-Logstash: Move logstash to an LVS service - https://phabricator.wikimedia.org/T132458#2397252 (10bd808) This might be something to look at doing as part of {T138328}. [17:36:56] 10Traffic, 06Operations, 10Wikimedia-Logstash: Move logstash to an LVS service - https://phabricator.wikimedia.org/T132458#2397273 (10bd808) Related: {T113104} [19:51:32] looks like it's possible tcp_notsent_lowat had a positive impact on firstpaint and maybe domcomplete, but kinda early to tell in all the usual graph noise [21:35:34] 10netops, 10Continuous-Integration-Infrastructure, 10Nodepool, 06Operations, and 3 others: Make sure phab can talk to gearman and nodepool instances can talk to phabricator - https://phabricator.wikimedia.org/T131375#2397825 (10greg)