#trilema | 2019-08-19

!!v F67E486876EF654FC1DEB5684A6A8BE1F24B58C4D4F2E925FC580CD2328866CC

00:43

Invoiced BingoBoingo 0.051 << Buy order # 1055: 500 WFF

~ 23 minutes ~

01:07

lobbes: i'ma try your proggy tomorrow. ideally time finally came to eat all of the back-archives.

01:09

lobbes: possibly it can even be used to bake a phf-style refill/sync system that eats znc.

~ 11 hours 33 minutes ~

12:43

lobbes: http://blog.lobbesblog.com/2019/08/znc2tmsr_etckvvpatch/comment-page-1/#comment-59

~ 1 hours 1 minutes ~

13:44

so there's still a totally unknown but significant delay on logger, weird stuff

13:49

diana_alt: there defo is. i've measured up to 0.6s (and all outside of the py proggy per se, i.e. vanishes if accessed at localhost )

13:50

diana_alt: fwiw i was not, to date, able to rule out mp's 'overworked pipe' hypothesis .

13:50

when someone sets up this logger outside of piz, i suppose will tell us sumthing re subj.

13:51

asciilifeform: hm, does it vanish if accessed from other-machine-at-pizarro too?

13:52

diana_alt: i do not currently know, atm i only have access to 1 piz machine. if you have time, plz try from yours and share result.

13:52

diana_alt: however, if accessed from localhost on ~public port~ (80) then yes same delay

13:52

so i suspect you will find same

13:53

asciilifeform: atm all my auth except this travel key are in various degrees of deep freeze but if it's not tested until I get back to my usual terminal, I'll try it out

13:53

delay disappears when accessed on localhost at the 'high' (nonpublic) port where the py proggy itself is answering

13:53

interesting at least in re pipe I suppose

13:54

pipe delay ( piz <-> asciilifeform's chair , cannot be generalized to entire planet ) varies from 0.2-0.4s (for revvup of tcp pipe, that is)

13:55

!!v BF1BCFCD9C0BCE3C6F04BEF6CBC214090B75361B39BE8EEF670BFB6EA52FE42F

13:55

BingoBoingo paid lobbes invoice 6

13:56

diana_alt: if you press the vtree and set up the logger on own box, where you happen to be, and import the daily db dump, can then observe the 'native' speed of the thing.

13:57

i get (and on rather slow machine) load time for the 'heavy' example page comparable to the time it takes for the mouse button to go up an' down.

14:04

diana_alt: i have plan to move the box to traditional apache, but yet not figured out how to do so w/out unacceptably long disruption of service .

14:06

( at one pt, long ago, when baked phuctor, asciilifeform had a preference for nginx, but it turned out to be ill-founded . currently both phuctor and log www are served by a nginx . )

14:08

neither phuctor nor logger is written in such a way as to force the choice of either nginx or apache as the front-side proxy, will eat either just the same. simply requires the appropriate config.

14:13

the reason why i currently suspect nginx as the culprit, is that i observed very similar delay when loading static (e.g. FG photograph) files via same.

14:13

previously i chalked this up to 'slow pipe'. now suspect also the proxying proggy.

14:14

( had not, prior to folx observing 'logger is slow, say wai' , taken the sweat to properly monitor where in the typical page load is time spent and on what )

14:15

ah, I *was* wondering re nginx as my only recollection of it was BingoBoingo trying it out and ending up with more trouble than it's worth

14:16

BingoBoingo: plz perform the simple experiment suggested by diana_alt and tell result.

14:16

Logged on 2019-08-19 13:53:04 diana_alt: asciilifeform: atm all my auth except this travel key are in various degrees of deep freeze but if it's not tested until I get back to my usual terminal, I'll try it out

14:20

spyked: I don't recall and can't see at http://thetarpit.org/posts/y05/081-feedbot-manual.html - is feedbot for L1 only or does it work for anyone with positive ratings or regardless of rating or what?

14:20

ah, nm, now I saw it in the footnote - it is L1 only

14:24

diana_alt: reasons to suspect the pipe, include this: i have stood up temporarily a raw flask on port 33. try time curl "http://logs.nosuchlabs.com:33/log" > /dev/null

14:25

diana_alt: I never managed to deploy anything that worked as needed on nginx. I managed things that almost work on lighttpd, but it simply lacks the good stuff apache offers for blogs.

14:25

( diana_alt lemme know after tried, i'ma switch it off, it's an unhygienic thing )

14:26

in my own test, there is no substantial detectable diff

14:28

asciilifeform: http://p.bvulpes.com/pastes/0I7Gg/?raw=true

14:28

asciilifeform: http://p.bvulpes.com/pastes/kYos2/?raw=true

14:28

( keep in mind that the links in the loaded page still point to the original )

14:29

diana_alt: do 3-4 shots via each (main vs 33) and paste plox

14:33

asciilifeform: http://p.bvulpes.com/pastes/kUEXH/?raw=true

14:33

asciilifeform: from Pizarro machine http://p.bvulpes.com/pastes/6jrpH/?raw=true

14:34

ty diana_alt , BingoBoingo . (i'ma switch off the 2nd logger for nao, will run it again if anyone requests, later)

14:35

BingoBoingo's output is pretty interesting -- how is it that he gets >2x the wait from ~local~ machine than diana_alt from europistan.

14:36

( possibly BingoBoingo's is under load ?? )

14:36

Possible, don't have ssh into any cabinet machines that aren't serving things

14:36

diana_alt's, on other hand, is very similar to mine, i.e. no substantial diff b/w main and 'naked'

14:39

asciilifeform: meanwhile trying on other machine seems solved for the right reason "rl: (6) Could not resolve host: logs.nosuchlabs.com"

14:40

BingoBoingo: naked ip also worx (lemme know if you want the 2nd logger on 33 switched on , to try moar )

14:41

the logger does not depend on dnsism to work ( can set the domain in /etc/hosts like e.g. mp does )

14:43

asciilifeform: I don't think that will be needed http://p.bvulpes.com/pastes/05a8I/?raw=true

14:44

"real 0m 0.01s"

14:44

BingoBoingo: the 33 logger is off atm

14:45

right, these are tests on the one that's running

14:47

From other machine time goes up a smidge: "real 0m0.035s"

14:56

BingoBoingo: that loox realistic.

14:56

( and imho further suggests that pipe is culprit )

14:56

'go to war with the pipe you have, not the pipe you wish you had'(tm)(r)

15:05

piz pipe is not gonna set any speed records. (however, is extremely reliable, e.g. asciilifeform gets ssh sessions that last 3-4 months)

15:06

... and typically they die on acct of connectivity pause on asciilifeform's end, rather than piz

15:06

!quptime

15:06

asciilifeform: time since my last reconnect : 3d 4h 43m

15:07

^ the log bot itself, for instance, thus far has only reconnected when asciilifeform manually cycled it, to update to new ver (last such time, to put phf's uniturd pill in production)

~ 1 hours 3 minutes ~

16:10

<asciilifeform> ( and imho further suggests that pipe is culprit ) << My desk offers "0m0.073s" suggesting geography may be at play

16:10

interesting.

16:13

I remember a thread from last year where trinque saw long pings doing something at the same time MP was enjoying incredibly fast ping to Eulora server

~ 23 minutes ~

16:36

oook here's an experiment : asciilifeform set up a mirror of the logotron on a cheap heathen host. ( one of the most rubbish hosters known, lulazon's . hence cannot in fact stand up copy of bot there, fleanode bans conns from it unless sslized. but the db is current. )

16:37

time curl http://54.209.217.34/log > /dev/null from my chair yields 0.063s.

16:38

other folx welcome to try. e.g. the 'heavy page' : curl http://54.209.217.34/log/trilema/2018-04-18#1802801 > /dev/null

16:38

... from here eats 0.268s.

↖ ↖

16:38

deliberately this setup uses nginx and same (as far as could replicate on the heathen box) stack of proggies as the orig.

16:39

this suggests that culprit of 'mystery delay' is in fact piz pipe.

16:40

errybody's welcome to play with the mirror ( it's a '1st month -- phreeee!' pseudo-machine , i'ma leave it up for a spell, tho it will , obv., grow no new log lines )

16:41

i suppose for completeness will mention an alt-hypothesis -- somehow nic on dulap is culprit.

16:42

*

asciilifeform did not bother to sync the clock, so times on shit mirror will vary vs. dulap's

16:50

all knobs aside from 'download snapshot' work, so feel free to e.g. walk the 'random' pages etc.

16:52

this experiment also reveals that asciilifeform's logotron will in fact stand up, with no modifications, on a python, flask, pg, etc. plucked out of arbitrary rubbish bin.

16:55

i'ma switch this thing off in coupla days, once errybody's taken the offered measurement and is satisfied ( i dun want a 'fossilized' logger sitting for idiots to find and think 'they're dead' )

16:57

BingoBoingo, diana_coman, et al ^ as time permits , plox to post load times of this ^ log.

16:57

*

asciilifeform brb,teatime

17:02

asciilifeform: My chair gives "real 0m0.524s"

17:03

From the rack gives 0m0.561s

~ 32 minutes ~

17:35

BingoBoingo: hard to say for fact, but seems to add up to a picture where's there's a ~0.5s bottleneck b/w south amer. and errywhere else.

17:36

( in the mirror example, we get it in the reverse direction, but seems to be that same ~0.5s ! )

17:38

other folx btw are encouraged to perform similar experiment ; whole thing took me approx 35min of meat time, from revving up heathen pseudo-box to posting link here.

17:39

( of which ~8m spent downloading db snapshot from piz )

17:40

( the rest -- largely, hand-copying configs )

17:42

http://logs.nosuchlabs.com/log/trilema/2019-08-19#1929694 << this is worth expanding on. asciilifeform also gets very fast pings ( never moar than 200msec, to date ) and fast udp. what i suspect is, usg's snoop gear that sits as parasitic toad on south amer's pipe, specifically slows down tcp.

17:42

Logged on 2019-08-19 16:13:02 BingoBoingo: I remember a thread from last year where trinque saw long pings doing something at the same time MP was enjoying incredibly fast ping to Eulora server

17:57

feedbot

http://qntra.net/2019/08/200-us-ceos-sign-pantsuit-pledge-declaring-primacy-of-social-and-political-goals-after-other-us-ceo-confirms-usg-malice-pursuing-said-goals/ << Qntra -- 200 US CEOs Sign Pantsuit Pledge Declaring Primacy Of Social And Political Goals After Other US CEO Confirms USG Malice Pursuing Said Goals

~ 19 minutes ~

18:16

!!invoice bvt 0.002 Shared Hosting Monthly

18:16

Get your OTP: http://p.bvulpes.com/pastes/SUH6v/?raw=true

18:17

!!v 05D3990D06D8604953F6C828348B6956D7C82A6BF7375DC138C40FC84F3712A7

18:17

Invoiced bvt 0.002 << Shared Hosting Monthly

18:17

!!invoice diana_coman 0.10429931 Rockchip w/ FUCKGOATS, Annual, Through July 2020

18:17

Get your OTP: http://p.bvulpes.com/pastes/Uf5wc/?raw=true

18:18

!!v 0E9B87B89855B52F22131F73CD3112CEB038FAC0F821A59E81B19AB9CB0635FA

18:18

Invoiced diana_coman 0.10429931 << Rockchip w/ FUCKGOATS, Annual, Through July 2020

18:18

!!invoice jurov 0.01445328 TBF Colocation August 2019

18:18

Get your OTP: http://p.bvulpes.com/pastes/W1gQ3/?raw=true

18:19

!!v 605B8E12B4D1074B3A8451A03A52D9DE223EAFCCA51DB6B4AE77EBAB9DB1A3B5

18:19

Invoiced jurov 0.01445328 << TBF Colocation August 2019

18:19

!!invoice lobbes 0.02894981 Rockchip and Shared Hosting Quarterly

18:19

Get your OTP: http://p.bvulpes.com/pastes/EIf2i/?raw=true

18:20

!!v FA9AF8DAE08C5B74E08025B8F0657CFEB8CF38B393BD5D77B2956CEC87B5EAB7

18:20

Invoiced lobbes 0.02894981 << Rockchip and Shared Hosting Quarterly

18:20

!!invoice trinque 0.01645328 Colocation + Shared August 2019

18:20

Get your OTP: http://p.bvulpes.com/pastes/5HYsI/?raw=true

18:21

!!v F8F948D9C87A8961B10AACDAAA84CAD85170F00682E89051933F7285937831B5

18:21

Invoiced trinque 0.01645328 << Colocation + Shared August 2019

~ 1 hours 3 minutes ~

19:24

http://logs.nosuchlabs.com/log/trilema/2019-08-19#1929696 << from my chair here in North Carolina Usgistan, my 'real' is 0m0.227s

19:24

Logged on 2019-08-19 16:37:04 asciilifeform: time curl http://54.209.217.34/log > /dev/null from my chair yields 0.063s.

19:32

from my EDIS VPS (in Austria iirc) I get 0m0.376s ; from piz rockchip I get 0m0.579s

19:46

Numbers for the 'heavy log' as follows: NC chair 0m1.055s ; Euro VPS 0m0.971s ; Piz Rkchp 0m1.435s

~ 56 minutes ~

20:43

!!v 86AC694AC6B7EB77DB8570DBD1566EB3A30F5D5BFCA6BF47CE01B409A968F55C

~ 22 minutes ~

21:06

trinque: ^ I may have been too quick on the draw when deedbot came back online. plox to lemme know if I should re-issue the above !!v

21:06

*

lobbes bbl

21:09

ty for the timings lobbes . seems to match up with asciilifeform's and BingoBoingo's pictures

21:09

( i.e. pretty fast connection reich <-> reich ; palpably slower piz <-> reich )

21:18

BingoBoingo, lobbes , et al : i'ma leave the rubbish box to run until further notice, and give it cron job that eats db from dulap erry day .

21:20

ftr gets ~80kB/s avg. from dulap, there.

21:24

keep in mind that bot will not echo log lines cited from rubbish mirror. it is fit strictly for timing experimentation.

21:27

the 'db snapshot' link nao worx. this box will do duty as an (unauthoritative!) 'fast' mirror of db snapshot also, until someone comes up with better.

21:28

for n00bz : the cron job script which powers this ; the cron job itself .

~ 15 minutes ~

21:44

BingoBoingo: this remains a mystery. i gotta wonder if there's something peculiar re our routing, which gives this effect.

21:44

Logged on 2019-08-19 13:52:44 asciilifeform: diana_alt: however, if accessed from localhost on ~public port~ (80) then yes same delay

21:51

BingoBoingo: from this pt i'ma follow the prescription mp gave during last 'wai slow' thrd -- leave it alone, there aint much to be done re to speed it up ( as imho conclusively showed that the pipe is to blame ). will move on to other matters ( import of historic logs ; fix of reported catastrophic bugs, incl. the resync of numeration mp asked for ; and then to get back to ffa ! )

21:52

rly what we oughta have is 7+ ~active~ bots/logotrons on 7 continents, then no one will have to grumble 'wai slow'

21:55

i expect at some pt mp will say to anyone in l1 who aint running a logger, 'партбилет на стол!'(tm)(r)

22:09

btw for thread-completeness, heavy page loaded locally on the shitbox consumes avg. of 0.2s.

22:09

Logged on 2019-08-19 16:38:17 asciilifeform: other folx welcome to try. e.g. the 'heavy page' : curl http://54.209.217.34/log/trilema/2018-04-18#1802801 > /dev/null

22:09

(i.e. all on top of this, is transmission delay from east amerireich, where thing sits.)

22:11

i.e. takes ~0.068s to travel the 50km or so to asciilifeform's chair from said pseudobox.

22:11

Logged on 2019-08-19 16:38:26 asciilifeform: ... from here eats 0.268s.

22:13

meanwhile, loox like lobbes reproduced asciilifeform's orig. observation.

22:14