Saturday, June 30, 2018
grimoire@muc.metronome.im
June
Mon Tue Wed Thu Fri Sat Sun
        1
2
3
4 5 6
7
8 9 10
11
12
13
14 15
16
17
18
19 20
21
22
23
24
25
26
27
28 29 30
 
             
Metronome IM "cook" book room | Support and Dev talk about the Metronome XMPP server.

Latest stable version build is: 4.0.3

For more information you can visit: https://metronome.im

Room logs can be found here: https://muc.metronome.im/logs/grimoire/

* Links *
<==========================================================>
- Building & Installation:
https://metronome.im/building
- Documentation:
https://metronome.im/documentation
- Issues Tracker:
https://github.com/maranda/metronome/issues
<==========================================================>

[11:51:25] <zinid> Maranda, here?
[11:51:56] <Maranda> zinid: yes
[11:52:02] <Maranda> Sort of
[11:52:05] <Maranda> 😋
[11:52:12] <zinid> ready to test?
[11:52:15] <zinid> or later?
[11:53:20] <Maranda> zinid: not home better wait a hour, if it's not a problem
[11:53:28] <zinid> sure, not a problem at all
[11:54:00] <Maranda> 👍
[13:09:56] <Maranda> zinid, ok here :P
[13:11:13] <Maranda> zinid, ready whenever you're
[13:35:39] <Maranda> hmmm
[13:35:55] <Maranda> and well guess the environment is not very clean but well :P
[13:36:08] <Maranda> the most that may happen is OOM kill
[14:10:59] <Maranda> ok I'll be doing some other stuff, send a ping when you want to start zinid. afk.
[17:35:17] <Maranda> @ping
[17:35:17] *Echo1 replies Maranda with an ICMP type 3.
[17:36:22] <Maranda> zinid: i take no go today too 🤸‍♂️😜?
[17:38:32] <zinid> 😝
[18:36:34] <Maranda> @ping
[18:36:34] *Echo1 replies Maranda with an ICMP type 3.
[18:36:36] <Maranda> @pong
[18:36:36] <Echo1> Maranda: ping
[18:43:39] <Maranda> .
[18:50:08] <Echo1> maranda committed --
mod_muc_limits: add missing fix for #388.
-> https://github.com/maranda/metronome/commit/e6ae1babbe8e63980d1ef12db9ad10dd44c4f433
[18:50:09] <Echo1> maranda committed --
mod_muc_log: fix typo.
-> https://github.com/maranda/metronome/commit/54b73b8c3cfb4d41f038b9096c49a6ddb45540ad
[19:35:09] <Echo1> maranda committed --
metronome.release: set version to 3.9.10.
-> https://github.com/maranda/metronome/commit/bb9901ae02029d763e85230128b048feee26dbf4
[19:50:08] <Echo1> maranda committed --
mod_pastebin: yet another missing #388 fix.
-> https://github.com/maranda/metronome/commit/948994ed8b1c236a125758b36b10c0aa1a41106d
[19:50:09] <Echo1> maranda committed --
mod_admin_telnet: add description for muc commands.
-> https://github.com/maranda/metronome/commit/26dc624eb70741cddcf8e664c750e005da37f25f
[19:56:27] <Maranda> Lorem ipsum dolor sit amet, consectetur adipiscing elit. Aenean massa est, porttitor id nulla vitae, porta bibendum leo. Interdum et malesuada fames ac ante ipsum primis in faucibus. Mauris quis ligula a nisi fringilla viverra eu nec orci. Nulla facilisi. Etiam tortor velit, porttitor sit amet euismod eu, posuere at elit. Proin augue velit, volutpat vel ipsum vel, aliquam consequat eros. Donec dignissim ligula in egestas feugiat. Nulla lobortis, risus a tristique ornare, enim orci condimentum metus, eget mollis lectus mi quis velit. Donec commodo urna non nulla hendrerit, sollicitudin vehicula ex lacinia. Sed molestie ut eros sit amet fringilla. Mauris nec neque at magna mollis bibendum. Fusce dui libero, dapibus vel elit vitae, imperdiet consequat libero.
[20:01:01] <zinid> 😀
[20:01:36] <Maranda> zinid, was testing if I broke the pastebin module
[20:01:39] <Maranda> brb
[20:04:03] <zinid> so I'm starting bencharking you
[20:04:13] <zinid> will start with 1k
[20:04:17] <Maranda> !
[20:04:35] <Maranda> Ok ready
[20:04:36] <Maranda> :O
[20:04:54] <zinid> arg
[20:05:00] <zinid> you don't have http upload..
[20:05:07] <zinid> let me comment that code
[20:05:08] <Echo1> maranda committed --
mod_admin_telnet: add missing section in main help.
-> https://github.com/maranda/metronome/commit/55708648e1d28a31ee70be8cea371b867613acab
[20:05:30] <Maranda> zinid, you said you didn't have that code yet :P
[20:05:37] <Maranda> (at the time)
[20:05:38] <zinid> I already have
[20:06:06] <Maranda> zinid, well you better comment it, it's a rather inefficent bit :P
[20:06:27] <Maranda> That will most likely cause a meltdown
[20:06:28] <zinid> yeah, I commented now it's crashing, just a second 🙂
[20:08:42] <zinid> started
[20:09:43] <zinid> hum
[20:10:02] <Maranda> something wrong?
[20:10:07] <Maranda> I see the connections
[20:11:03] <zinid> it's very slow
[20:11:07] <zinid> not sure why
[20:11:12] <Maranda> they connect and dc immediatly after doing some IQs/mam
[20:11:22] <Maranda> looking at the tail
[20:11:42] <zinid> let me remove binding addresses
[20:14:51] <zinid> okay, better now
[20:14:52] <Maranda> 81%
[20:15:07] <Maranda> 87%
[20:15:40] <Maranda> 84%
[20:15:44] <Maranda> 82%
[20:15:58] <Maranda> https://meaveen.lightwitch.org/server-status/
[20:16:27] <Maranda> still around that cpu usage
[20:16:37] <Maranda> 90% and 6%
[20:16:40] <Maranda> 3%
[20:16:51] <zinid> 3 what?
[20:17:02] <Maranda> cpu
[20:17:05] <zinid> should drop now
[20:17:08] <Maranda> now at 10%
[20:17:10] <zinid> all connected
[20:17:12] <Maranda> 3%
[20:17:15] <Maranda> https://meaveen.lightwitch.org/server-status/
[20:17:20] <zinid> yeah, connecting is the hardest part
[20:17:28] <zinid> Maranda, your server-status doesn't report CPU
[20:17:29] <Maranda> steady at 3%-6%
[20:17:38] <Maranda> infact I'm reporting you
[20:17:41] <Maranda> :P
[20:17:46] <Maranda> that's for memory usage
[20:18:40] <Maranda> 10-15% with the CSI flushing
[20:18:47] <zinid> yeah
[20:19:06] <zinid> so what, let's go 5k?
[20:19:09] <zinid> or 2k first?
[20:19:27] <Maranda> go with 3k then we will see then
[20:19:41] <zinid> ok
[20:19:55] <zinid> stopped
[20:20:35] <zinid> started
[20:20:36] <Maranda> still connected due of SM :P
[20:20:41] <zinid> yeah
[20:22:07] <Maranda> 92%
[20:22:15] <zinid> hehe
[20:22:32] <zinid> yeah, connecting stuff is the hardest part, when everything is connected it's much easier
[20:23:35] <zinid> regarding http upload: you can set max-size to some small number, like 1Mb
[20:24:06] <zinid> if your service reports it (via 'max-file-size' xdata field) then my benchmark will send files of 1..Max bytes
[20:24:26] <Maranda> zinid, we best leave that for another time, it's still terribly inefficent even with 1MB
[20:24:34] <Maranda> not on the upload but on the serving
[20:24:34] <zinid> okay
[20:24:44] <zinid> but http upload is important nowadays 😀
[20:25:38] <Maranda> I know but it doesn't make LuaSocket any less horrible when buffering chunks, and there's little I can do about it.
[20:25:56] <zinid> crap
[20:26:09] <zinid> I have sendfile(2) wrapper in erlang!
[20:27:07] <zinid> looks like everything is connected
[20:27:17] <Maranda> 19%-30% average on flushing
[20:27:23] <Maranda> some 60% peak
[20:27:41] <zinid> that's ok for a single core
[20:27:49] <zinid> I have the same in ejabberd on a single core
[20:28:23] <Maranda> https://meaveen.lightwitch.org/server-status/
[20:29:04] <Maranda> 20-50% average
[20:29:14] <zinid> should we go 5k after all?
[20:29:30] <zinid> should handle that
[20:30:05] <Maranda> zinid, yep
[20:30:16] <zinid> stopped
[20:30:49] <zinid> started
[20:31:42] <Maranda> 94% it's replacing sessions me thinks
[20:32:18] <zinid> if you can drop them we can start from scratch if you like
[20:32:41] <zinid> according to my stats everything is ok so far
[20:32:48] <Maranda> no need me thinks
[20:33:22] <Maranda> the server just has some latency on the login flood
[20:33:51] <zinid> yeah...
[20:35:53] <zinid> http://52.22.32.97:8091/
[20:36:23] <zinid> your server-status is lagging
[20:37:23] <Maranda> Noticed
[20:37:47] <Maranda> well I'm lagging a bit too :P
[20:37:57] <Maranda> 92% cpu
[20:38:42] <zinid> ping
[20:38:42] <zinid> I see errors
[20:39:40] <zinid> Resumption failed: item-not-found: 1
Stream closed by us: Stream negotiation timeout (connection-timeout): 1458
[20:39:51] <Maranda> Jun 30 20:38:57 metronome.im:saslauth debug sasl reply: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
Jun 30 20:38:57 c2s17adb2e0 debug Invalid opening stream header
Jun 30 20:38:57 c2s17adb2e0 debug Disconnecting client, <stream:error> is: <stream:error><invalid-namespace xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error>
Jun 30 20:38:57 c2s17adb2e0 info c2s stream for <52.22.32.97> closed: invalid-namespace
Jun 30 20:38:57 c2s17adb2e0 debug Destroying session for (unknown) (zinid3845@metronome.im): invalid-namespace

[20:40:19] <zinid> laaaaaaggggssss
[20:40:33] <Maranda> I see invalid namespace errors
[20:40:55] <zinid> wut?
[20:41:10] <zinid> seems like your server is having cancer now
[20:41:10] <zinid> it dropped 3k sessions
[20:41:41] <zinid> Stream negotiation timeout (connection-timeout): 4842
[20:41:48] <Maranda> something is odd i see a lot of invalid namespace errors
[20:42:12] <Maranda> on stream opening
[20:42:29] <zinid> ok I stop
[20:42:44] <zinid> or you want to debug?
[20:43:21] <zinid> why it doesn't reply anything? I send stream header and ... nothing
[20:43:48] <Maranda> in theory it's disconnecting
[20:43:49] <zinid> also:
Connection failed: timeout: 1206
[20:44:13] <Maranda> stop it a moment I'll clear out the sessions
[20:44:26] <zinid> whole stats:
Connection failed: timeout: 1539
Resumption failed: item-not-found: 1
Stream closed by us: Stream negotiation timeout (connection-timeout): 9354
[20:44:26] <zinid> ok
[20:44:30] <zinid> stopped
[20:46:39] <Maranda> zinid, I'm not sure what caused the errors
[20:47:04] <Maranda> zinid, something in the stream headers sent by the benchmark triggered invalid ns
[20:47:15] <Maranda> zinid, shall we restart with the 5000?
[20:47:52] <zinid> we can try 4k
[20:48:18] <Maranda> zinid, no try 5k, whatever it was, was caused by hibernated sessions me think
[20:48:28] <zinid> okay
[20:48:55] <zinid> started
[20:49:18] <Maranda> zinid, even because session number wasn't rising and was diminishing instead.
[20:50:18] <Maranda> zinid, so they were retrying to connect very fast and bounced again, basically you DDoSed me hahahahahaha
[20:50:35] <Maranda> 1k
[20:50:52] <zinid> well, I have a random timeout between 1 and 100 seconds, so not strictly speaking ddos 😀
[20:51:10] <zinid> I can increase it
[20:51:32] <Maranda> no it's ok, i think it shouldn't happen now.
[20:51:47] <zinid> yeah, seems like no lags
[20:52:14] <zinid> for the record, I didn't notice in ejabberd any session resume footprint
[20:52:19] <zinid> strange you have it
[20:52:26] <zinid> maybe something needs optimizing?
[20:52:53] <zinid> actually when everything is connected and I restart the benchmark then CPU load drops
[20:53:00] <zinid> because a lot of stuff is cached
[20:53:25] <zinid> everything actually cached except mam
[20:53:29] <zinid> fucking mam...
[20:53:36] <Maranda> zinid, the problem wasn't exactly SM, it was that Metronome was bouncing connections due to invalid-namespace stream error.
[20:53:47] <zinid> ah
[20:54:21] <Maranda> so it could be some shenanigan in the parser but hard to debug now :P
[20:54:58] <Maranda> 3k
[20:55:08] <zinid> if you at least can bounce your <invalid-namespace/> stream error back to me I can try to catch it using runtime introspector
[20:56:16] <zinid> I'm just having stream timeouts... no stream errors
[20:56:39] <Maranda> 🤔
[20:56:54] <zinid> current stats:
Resumption failed: item-not-found: 5
Stream closed by us: Stream negotiation timeout (connection-timeout): 1
[20:56:54] <zinid> looks okayish
[20:57:17] <zinid> that "Resumption failed" is normal, I have a special case to try to resume outdated session 😀
[20:57:24] <Maranda> 95%
[20:57:40] <zinid> ah
[20:57:40] <zinid> cancer again
[20:57:50] <Maranda> there we go the ns error begin again
[20:57:51] <zinid> Stream closed by us: Stream negotiation timeout (connection-timeout): 813
[20:58:17] <zinid> ok, I stop
[20:58:30] <zinid> this is not recoverable
[20:59:07] <Maranda> So that's it 3k
[20:59:23] <Maranda> 🤔 🤷‍♂
[20:59:50] <zinid> well, there is still room to improve: to find and ditch those invalid-namespace errors
[21:00:41] <zinid> can you just add some `printf` when you see you're trying to send invalid-namespace error?
[21:00:53] <Maranda> zinid, what was the transfer rate? You know it could be some throttling on my VPS' ISP end
[21:01:14] <zinid> Maranda, hard to say... I don't have stats
[21:01:24] <zinid> I mean I don't have stats for the raw traffic
[21:02:31] <Maranda> hmmm I have 2000 Mbps Network Out
[21:02:48] <zinid> that should be enough frankly
[21:03:09] <zinid> 2000 Mbps???
[21:03:15] <zinid> that's 2Gbps?
[21:04:09] <Maranda> zinid, yeah
[21:04:24] <zinid> Maranda, if you want to debug something, let me know, otherwise I'm stopping the machines, we can proceed tomorrow
[21:04:39] <Maranda> zinid, oh just stop 'em np
[21:04:45] <zinid> ok
[21:05:05] <Maranda> I'll try to figure the invalid-namespace, it happened right at 3500 or so.
[21:05:16] <Maranda> and if you got timeouts on your end
[21:05:34] <Maranda> I somehow think it could be due to my ISP doing some rate limiting as well.
[21:06:19] <zinid> I can give you access to our AWS machine to rule this out
[21:06:24] <Maranda> zinid, so maybe we could try a slower buildup tomorrow and see what happens if you want
[21:06:26] <zinid> so you can install metronome there
[21:08:06] <Maranda> zinid, if you like, but not this evening I'm rather tired already, I'll just grep the tail a bit and see if I can figure something out of it ;)
[21:08:18] <zinid> sure, not today
[21:08:25] <zinid> I'm already drunk as fuck 😀
[21:09:40] <Maranda> although upto 3k no issues that's more than I hoped using a heavy feature set
[21:10:12] <zinid> no muc and http upload
[21:10:37] <zinid> for the former I don't have tests so far
[21:11:06] <Maranda> zinid, well muc doesn't scale for sure, how did ejabberd do on that?
[21:11:18] <zinid> pretty bad 😀
[21:11:49] <zinid> well, of course if you put 1000 cores into that, than you can handle 1000 rooms very good 😀
[21:12:17] <zinid> 95% of the time is consumed by presence routing anyways
[21:12:22] <zinid> stupid muc design
[21:12:49] <Maranda> Jun 30 20:57:32 c2sbfbea60 info Client connected
Jun 30 20:57:37 c2sbfbea60 debug Client sent opening <stream:stream> to metronome.im
Jun 30 20:57:37 c2sbfbea60 debug Sent reply <stream:stream> to client
Jun 30 20:57:45 c2sbfbea60 debug Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Jun 30 20:57:45 c2sbfbea60 debug TLS negotiation started for c2s_unauthed...
Jun 30 20:58:17 c2sbfbea60 debug Client sent opening <stream:stream> to metronome.im
Jun 30 20:58:17 c2sbfbea60 debug Sent reply <stream:stream> to client
Jun 30 20:58:17 c2sbfbea60 debug Invalid client certificate chain detected
Jun 30 20:58:17 c2sbfbea60 debug 1: self signed certificate
Jun 30 20:58:29 c2sbfbea60 debug Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Jun 30 20:58:30 c2sbfbea60 info Authenticated as zinid4660@metronome.im
Jun 30 20:58:30 c2sbfbea60 debug Invalid opening stream header
Jun 30 20:58:30 c2sbfbea60 debug Disconnecting client, <stream:error> is: <stream:error><invalid-namespace xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error>
Jun 30 20:58:30 c2sbfbea60 info c2s stream for <52.22.32.97> closed: invalid-namespace
Jun 30 20:58:30 c2sbfbea60 debug Destroying session for (unknown) (zinid4660@metronome.im): invalid-namespace
Jun 30 20:58:30 c2sbfbea60 debug Received[c2s_destroyed]: <connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 debug Received[c2s_destroyed]: <text xmlns='urn:ietf:params:xml:ns:xmpp-streams' xml:lang='en'>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 debug Received </stream:stream>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 debug Received </stream:stream>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 info Client disconnected: connection closed

[21:12:53] <Maranda> hmm
[21:13:41] <zinid> Jun 30 20:58:30 c2sbfbea60 debug Disconnecting client, <stream:error> is: <stream:error><invalid-namespace xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error>
Jun 30 20:58:30 c2sbfbea60 info c2s stream for <52.22.32.97> closed: invalid-namespace
Jun 30 20:58:30 c2sbfbea60 debug Destroying session for (unknown) (zinid4660@metronome.im): invalid-namespace
Jun 30 20:58:30 c2sbfbea60 debug Received[c2s_destroyed]: <connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'>
[21:13:53] <zinid> I think I know what's happening
[21:14:03] <zinid> metronome reacts to my <connection-timeout/>
[21:14:31] <Maranda> actually that was received after
[21:14:40] <Maranda> when the session was destroyed already
[21:14:49] <zinid> but it's strange the timestamp is the same
[21:14:49] *Maranda scratches forehead.
[21:15:01] <zinid> that's hell of a coincidence 😀
[21:16:03] <Maranda> You authenticated, then boom
[21:16:14] <Maranda> zinid, so whatever it is happened on stream restart
[21:17:01] <zinid> still sounds strange, why it goes in pair with <connection-timeout/>?
[21:17:11] <Maranda> It doesn't
[21:17:19] <zinid> but the timestamp is the same
[21:18:00] <Maranda> zinid, yes but it could be time after (ms?)
[21:18:12] <Maranda> zinid, is there a timeout on the stream restart?
[21:18:15] <zinid> do you have other sample?
[21:18:41] <zinid> no, the timeout is set once connection is performed, then the timer is only canceled when binding is done
[21:18:43] <Maranda> I mean, does the BM has some timeout waiting for the server response on stream restart?
[21:18:53] <Maranda> hm
[21:19:09] <Maranda> and you said you received no stream response.
[21:19:14] <zinid> yep
[21:19:17] <zinid> no response
[21:19:23] <Maranda> zinid, after authentication?
[21:19:29] <zinid> cannot say
[21:19:33] <zinid> I don't track that
[21:19:41] <Maranda> That's very weird...
[21:19:52] <Maranda> Jun 30 20:57:32 c2sbfbea60 info Client connected
Jun 30 20:57:37 c2sbfbea60 debug Client sent opening <stream:stream> to metronome.im
Jun 30 20:57:37 c2sbfbea60 debug Sent reply <stream:stream> to client
Jun 30 20:57:45 c2sbfbea60 debug Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Jun 30 20:57:45 c2sbfbea60 debug TLS negotiation started for c2s_unauthed...
Jun 30 20:58:17 c2sbfbea60 debug Client sent opening <stream:stream> to metronome.im
Jun 30 20:58:17 c2sbfbea60 debug Sent reply <stream:stream> to client
Jun 30 20:58:17 c2sbfbea60 debug Invalid client certificate chain detected
Jun 30 20:58:17 c2sbfbea60 debug 1: self signed certificate
Jun 30 20:58:29 c2sbfbea60 debug Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Jun 30 20:58:30 c2sbfbea60 info Authenticated as zinid4660@metronome.im
Jun 30 20:58:30 c2sbfbea60 debug Invalid opening stream header
Jun 30 20:58:30 c2sbfbea60 debug Disconnecting client, <stream:error> is: <stream:error><invalid-namespace xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error>
Jun 30 20:58:30 c2sbfbea60 info c2s stream for <52.22.32.97> closed: invalid-namespace
Jun 30 20:58:30 c2sbfbea60 debug Destroying session for (unknown) (zinid4660@metronome.im): invalid-namespace
Jun 30 20:58:30 c2sbfbea60 debug Received[c2s_destroyed]: <connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 debug Received[c2s_destroyed]: <text xmlns='urn:ietf:params:xml:ns:xmpp-streams' xml:lang='en'>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 debug Received </stream:stream>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 debug Received </stream:stream>
Jun 30 20:58:30 c2sbfbea60 debug Attempt to close already-closed session
Jun 30 20:58:30 c2sbfbea60 info Client disconnected: connection closed

[21:20:07] <Maranda> ^ here it connected, starttls'ed then authed even
[21:20:17] <Maranda> 🤔 🤔 🤔 🤔 🤔
[21:20:20] <zinid> do you have other sample for other user?
[21:20:26] <zinid> you should have a ton of them
[21:20:29] <Maranda> yup
[21:20:35] <zinid> show please
[21:20:49] <Maranda> zinid one valid or invalid-namespace?
[21:20:57] <zinid> invalid
[21:21:16] <zinid> or just say does it go in pair with <connection-timeout/>?
[21:21:28] <zinid> if it does then it's definitely related
[21:21:36] <Maranda> Jun 30 20:57:32 c2s222dd0b0 info Client connected
Jun 30 20:57:37 c2s222dd0b0 debug Client sent opening <stream:stream> to metronome.im
Jun 30 20:57:37 c2s222dd0b0 debug Sent reply <stream:stream> to client
Jun 30 20:57:44 c2s222dd0b0 debug Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Jun 30 20:57:44 c2s222dd0b0 debug TLS negotiation started for c2s_unauthed...
Jun 30 20:58:17 c2s222dd0b0 debug Client sent opening <stream:stream> to metronome.im
Jun 30 20:58:17 c2s222dd0b0 debug Sent reply <stream:stream> to client
Jun 30 20:58:17 c2s222dd0b0 debug Invalid client certificate chain detected
Jun 30 20:58:17 c2s222dd0b0 debug 1: self signed certificate
Jun 30 20:58:26 c2s222dd0b0 debug Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Jun 30 20:58:26 c2s222dd0b0 info Authenticated as zinid4654@metronome.im
Jun 30 20:58:26 c2s222dd0b0 debug Invalid opening stream header
Jun 30 20:58:26 c2s222dd0b0 debug Disconnecting client, <stream:error> is: <stream:error><invalid-namespace xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error>
Jun 30 20:58:26 c2s222dd0b0 info c2s stream for <52.22.32.97> closed: invalid-namespace
Jun 30 20:58:26 c2s222dd0b0 debug Destroying session for (unknown) (zinid4654@metronome.im): invalid-namespace
Jun 30 20:58:26 c2s222dd0b0 debug Received[c2s_destroyed]: <connection-timeout xmlns='urn:ietf:params:xml:ns:xmpp-streams'>
Jun 30 20:58:26 c2s222dd0b0 debug Attempt to close already-closed session
Jun 30 20:58:26 c2s222dd0b0 debug Received[c2s_destroyed]: <text xmlns='urn:ietf:params:xml:ns:xmpp-streams' xml:lang='en'>
Jun 30 20:58:26 c2s222dd0b0 debug Attempt to close already-closed session
Jun 30 20:58:26 c2s222dd0b0 debug Received </stream:stream>
Jun 30 20:58:26 c2s222dd0b0 debug Attempt to close already-closed session
Jun 30 20:58:26 c2s222dd0b0 debug Received </stream:stream>
Jun 30 20:58:26 c2s222dd0b0 debug Attempt to close already-closed session
Jun 30 20:58:30 c2s222dd0b0 info Client disconnected: connection closed

[21:21:36] <zinid> it cannot be a coincidence again
[21:21:51] <zinid> yeah, same shit
[21:22:45] <zinid> Jun 30 20:58:17 c2s222dd0b0 debug Sent reply <stream:stream> to client
Jun 30 20:58:17 c2s222dd0b0 debug Invalid client certificate chain detected
Jun 30 20:58:17 c2s222dd0b0 debug 1: self signed certificate
Jun 30 20:58:26 c2s222dd0b0 debug Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
[21:22:50] <zinid> so huge delay
[21:22:53] <zinid> almost 10 seconds
[21:23:18] <Maranda> Jun 30 16:22:27 c2s46b9880 info Client connected
Jun 30 16:22:27 c2s46b9880 debug Invalid opening stream header
Jun 30 16:22:27 c2s46b9880 debug Disconnecting client, <stream:error> is: <stream:error><invalid-namespace xmlns='urn:ietf:params:xml:ns:xmpp-streams'/></stream:error>
Jun 30 16:22:27 c2s46b9880 info c2s stream for <40.135.65.82> closed: invalid-namespace
Jun 30 16:22:27 c2s46b9880 debug Destroying session for (unknown) ((unknown)@(unknown)): invalid-namespace
Jun 30 16:22:27 c2s46b9880 debug Received </stream:stream>
Jun 30 16:22:27 c2s46b9880 debug Attempt to close already-closed session
Jun 30 16:22:27 c2s46b9880 info Client disconnected: connection closed

[21:23:30] <Maranda> well this doesn't matter nm
[21:23:49] <Maranda> zinid, hmm yeah
[21:24:44] <Maranda> zinid, do they start the tests as soon as connected right?
[21:24:55] <zinid> yes
[21:26:09] <Maranda> zinid, so I guess that the server starts having huge latency due to cpu capping after 3k and then
[21:26:39] <Maranda> and the timeout causes the invalid ns
[21:26:42] <zinid> tomorrow we can increase the arrival rate to test this hypothesis
[21:26:55] <zinid> currently it's 100ms between connections
[21:27:06] <zinid> we can start with 200ms to see what happens
[21:27:25] <zinid> well, let's continue tomorrow
[21:27:37] <Maranda> ok 👌
[21:27:40] <Maranda> thanks :P
[21:27:59] <zinid> I want only to note that it depends whether our sysadmins be available or not 😀
[21:28:16] <zinid> I need to ask him to start the machines, I don't have access myself
[21:28:25] <zinid> if not, then only on monday
[21:28:34] <Maranda> That's ok
[21:28:54] <zinid> ok, I stopped
[21:28:59] <zinid> (very expensive crap)
[21:29:17] <Maranda> 🤣
[21:29:34] <zinid> it's 64core x 200Gb or something
[21:29:52] <zinid> when I start the benchark for you it consumes 1% 😀
[21:30:00] <zinid> barely can see it in `top` 😀
[21:30:43] <Maranda> haha
[21:31:29] <zinid> btw, a personal question if you don't mind
[21:31:39] <zinid> why don't you just develop prosody?
[21:31:49] <zinid> I'm really curious 😀
[21:33:20] <Maranda> Mainly, because honestly I don't agree at all, on how the project is mantained (and with reason as you can see).
[21:33:36] <zinid> yeah...
[21:35:59] <Maranda> secondly because I got very annoyed when I didn't get a single credit line on getting 0.9 to work, because s2s was broken and one of the idiots who spent countless hours figuring out why was guess who.
[21:36:21] <zinid> zash?
[21:36:24] <zinid> 😀
[21:36:27] <Maranda> >.>
[21:36:52] <Maranda> zinid, don't get me started it's all logged lol.
[21:37:02] <zinid> nononono
[21:38:27] <zinid> ok, I need to go sleeping, it's almost 1 AM here
[21:39:02] <Maranda> zinid, but basically I didn't agree how things were done, I could fork and sublicense cause of MIT and I just did :P
[21:39:13] <Maranda> zinid, ok niteeeee :P
[21:39:19] <zinid> thanks 😛