Latest mm builds crash when sending messages over the socket

[lukechilds]

The latest builds of mm on both the jl777 and dev branch crash when I issue commands over the socket.

If I just remove the non zero queueid to make the requests normal HTTP requests it works fine.

Possibly caused from the changes in #740 #668?

[lukechilds]

And to clarify, by crash I mean the entire process dies, it doesn't just hang for a while.

[jl777]

backtrace?

does the fasttest script work? it seems the GUI might be invoking different timings that I missed

[lukechilds]

Where is the fasttest script?

Will try get a backtrace to you.

[jl777]

~/SuperNET/iguana/exchanges/fasttest

[lukechilds]

Yeah, fasttest appears to be working ok:

{"result":"success","status":"queued"}
{"bids":[],"numbids":0,"biddepth":0,"asks":[{"coin":"REVS","address":"RAzheh3L7QtBL7oNKByVa43CtgALht6bbT","price":1.51328015,"numutxos":64,"avevolume":0.45398404,"maxvolume":92.80947180,"depth":29.05497894,"pubkey":"50959696e9d954d5853b113b54bfd695f7dd1a272f01700b13d6cd7e4b9bc704","age":90,"zcredits":0}, {"coin":"REVS","address":"RQzkkncY8ehpRg8M4kvKmDMcbFxcJvohgk","price":1.51455832,"numutxos":68,"avevolume":0.18174699,"maxvolume":55.23594175,"depth":41.41377479,"pubkey":"30eb3d952f66eba2df0100b97d6707257cf91dc8c8b0237cfb7c3aa70dc52d4d","age":18,"zcredits":0}],"numasks":2,"askdepth":41.41377479,"base":"REVS","rel":"KMD","timestamp":1523000584,"netid":0}
{"bids":[],"numbids":0,"biddepth":0,"asks":[{"coin":"REVS","address":"RAzheh3L7QtBL7oNKByVa43CtgALht6bbT","price":1.51328015,"numutxos":64,"avevolume":0.45398404,"maxvolume":92.80947180,"depth":29.05497894,"pubkey":"50959696e9d954d5853b113b54bfd695f7dd1a272f01700b13d6cd7e4b9bc704","age":90,"zcredits":0}, {"coin":"REVS","address":"RQzkkncY8ehpRg8M4kvKmDMcbFxcJvohgk","price":1.51455832,"numutxos":68,"avevolume":0.18174699,"maxvolume":55.23594175,"depth":41.41377479,"pubkey":"30eb3d952f66eba2df0100b97d6707257cf91dc8c8b0237cfb7c3aa70dc52d4d","age":18,"zcredits":0}],"numasks":2,"askdepth":41.41377479,"base":"REVS","rel":"KMD","timestamp":1523000584,"netid":0}
{"result":"success","status":"queued"}

[lukechilds]

Oh, wait, sorry, that was with an old working mm, testing on latest now.

[jl777]

you should see the commands complete out of order

[lukechilds]

Yeah, it still passes on the current version.

[lukechilds]

It seems to be the electrum method that's killing it. Try this:

fastestfail

#!/bin/bash
source userpass
curl 'http://127.0.0.1:7783/' --data "{\"userpass\":\"$userpass\",\"queueid\":1,\"method\":\"electrum\",\"coin\":\"KMD\",\"ipaddr\":\"electrum1.cipig.net\",\"port\":10001}"

This consistently kills mm every time for me:

$ pgrep marketmaker | wc -l
1

$ ./fasttestfail
{"result":"success","status":"queued"}

$ pgrep marketmaker | wc -l
0

[jl777]

from a fresh ./client, you are saying just running that will kill things?

i cant reproduce any crash, it works fine for me. not sure why your system is having problems, it is happening on multiple different nodes?

[jl777]

if it is crashing, i need a backtrace to get any idea of what is going wrong

[lukechilds]

Will get a backtrace to you now.

[lukechilds]

Sorry, that wasn't a good reproduction, I was spawning mm from my GUI so there was some other stuff going on. I have now managed to make a pure cli repro.

It appears to just be too many things in the queue simultaneously causing the crash.

Try this:

queuetest

#!/bin/bash

./marketmaker '{"client":1,"passphrase":"passphrase","coins":[],"rpcport":63434}' &
sleep 5
echo
echo "maketmaker processes running: $(pgrep marketmaker | wc -l)"
curl 'http://127.0.0.1:63434/' --data '{"method":"getendpoint","port":63481,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":1,"method":"electrum","coin":"KMD","ipaddr":"electrum1.cipig.net","port":10001,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":2,"method":"electrum","coin":"KMD","ipaddr":"electrum2.cipig.net","port":10001,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":3,"method":"electrum","coin":"REVS","ipaddr":"electrum1.cipig.net","port":10003,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":4,"method":"electrum","coin":"REVS","ipaddr":"electrum2.cipig.net","port":10003,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":5,"method":"electrum","coin":"SUPERNET","ipaddr":"electrum1.cipig.net","port":10005,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":6,"method":"electrum","coin":"SUPERNET","ipaddr":"electrum2.cipig.net","port":10005,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":7,"method":"electrum","coin":"CHIPS","ipaddr":"electrum1.cipig.net","port":10053,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":8,"method":"electrum","coin":"CHIPS","ipaddr":"electrum2.cipig.net","port":10053,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":9,"method":"electrum","coin":"BTC","ipaddr":"electrum.hsmiths.com","port":50001,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":10,"method":"electrum","coin":"BTC","ipaddr":"helicarrier.bauerj.eu","port":50001,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":11,"method":"electrum","coin":"VTC","ipaddr":"173.212.225.176","port":50088,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":12,"method":"electrum","coin":"VTC","ipaddr":"136.243.45.140","port":50088,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":13,"method":"electrum","coin":"LTC","ipaddr":"173.212.225.176","port":50012,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
curl 'http://127.0.0.1:63434/' --data '{"queueid":14,"method":"electrum","coin":"LTC","ipaddr":"136.243.45.140","port":50012,"userpass":"1e089e3c5323ad80a90767bdd5907297b4138163f027097fd3bdbeab528d2d68"}'
sleep 0.5
echo "maketmaker processes running: $(pgrep marketmaker | wc -l)"

Run it in SuperNET/iguana like this:

$ pwd
/Users/lukechilds/dev/oss/SuperNET/iguana

$ git branch | grep \*
* jl777

$ ./m_mm
Already up to date.
Mac OSX

$ ./queuetest
RPCport.0 remoteport.-1, nanoports 7793 7803 7813
showwif.0 Marketmaker 0.1 27773 rsize.248 2063503901
BTC, cant open.(/root/Bitcoin/Bitcoin.conf)
BTC inactive.1523005655
KMD, cant open.(/root/Komodo/Komodo.conf)
privkey updates
RPCport.63434 remoteport.63433, nanoports 7793 7803 7813
default seed nodes for netid.0
connected to push.(tcp://5.9.253.195:7793) pushsock.0 valid.1  | connected to sub.(tcp://5.9.253.195:7803) subsock.1 valid.1 numactive.0
connected to push.(tcp://173.212.225.176:7793) pushsock.2 valid.1  | connected to sub.(tcp://173.212.225.176:7803) subsock.3 valid.1 numactive.0
connected to push.(tcp://136.243.45.140:7793) pushsock.4 valid.1  | connected to sub.(tcp://136.243.45.140:7803) subsock.5 valid.1 numactive.0
connected to push.(tcp://23.254.202.142:7793) pushsock.6 valid.1  | connected to sub.(tcp://23.254.202.142:7803) subsock.7 valid.1 numactive.0
connected to push.(tcp://45.32.19.196:7793) pushsock.8 valid.1  | connected to sub.(tcp://45.32.19.196:7803) subsock.9 valid.1 numactive.0
got 183.88.220.162, initpeers. LP_mypubsock.-1 pullsock.-1 RPC_port.63434 mypullport.7793 mypubport.7803
userpass.(bc6fbe1202c10eec783311a012a67fb45b01f20f11f8c7a005ed695c58ab6169)
Start stats_rpcloop.63434
start prices_loop
>>>>>>>>>> DEX stats 127.0.0.1:63434 bind sock.102 DEX stats API enabled at unixtime.1523005655 <<<<<<<<<

maketmaker processes running:        1
max rpc threads spawned and alive 0 <- 1
{"result":"success","endpoint":"ws://127.0.0.1:63481","socket":10,"sockopt":0}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
bindflag.0 iguana_socket mismatch (13.230.86.115) -> (electrum1.cipig.net)
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
{"result":"success","status":"queued"}
LP_dedicatedloop ep.0x102c8b000 sock.40 for electrum1.cipig.net:10001 num.1 0x102142494 KMD ht.0
queuetest: line 20: 93256 Segmentation fault: 11  ./marketmaker '{"client":1,"passphrase":"passphrase","coins":[],"rpcport":63434}'
maketmaker processes running:        0

[lukechilds]

I'm having issues creating backtrace because gdb won't run on the latest osx versions because it's not codesigned. Working on this for you.

[jl777]

I added IGUANA_MAXRPCTHREADS to ~/SuperNET/iguana/exchanges/stats.c at the top of the file
currently it is set to 1 so it will serialize all requests. to get overlaps change it to 2

[lukechilds]

The backtrace reported here: #668 (comment)

Is likely related to this issue.

[jl777]

I reverted the orderbook/portfolio change. Lets hope things stabilize. in jl777 branch