`swapstatus` kills `marketmaker` when called after `buy`

[lukechilds]

If you call swapstatus directly after calling buy it completely kills the entire mm process.

This was causing issue with our GUI as we're polling swapstatus on the exchange page to give reliable, up to date swap history and current swap state.

However this is also reproducible via the CLI and nothing to do with the polling. It only occurs when the commands are called directly after each other. And obviously that's quite a common use case, after starting a trade order you're going to want to check the status.

# Setup coins in Electrum mode
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"electrum", "coin":"KMD", "ipaddr":"electrum1.cipig.net", "port":10001}' 
{"ipaddr":"electrum1.cipig.net","port":10001,"result":"success"}

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"electrum", "coin":"CHIPS", "ipaddr":"electrum1.cipig.net", "port":10053}'
{"ipaddr":"electrum1.cipig.net","port":10053,"result":"success"}

# Check the current order book to get an idea of a sensible price
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"orderbook", "base":"CHIPS", "rel":"KMD"}'
{"bids":[{"coin":"KMD","address":"RFNAyiSWrDavovUSLHU4tiwP1K3XR1qbuN","price":0.08777562,"numutxos":43,"avevolume":1.72800000,"maxvolume":15.41600000,"depth":74.30400000,"pubkey":"84896372344a408c5664fc5570cb19736f03f66a3e7f17a58cfa160468707c77","age":22,"zcredits":0}, {"coin":"KMD","address":"RQzkkncY8ehpRg8M4kvKmDMcbFxcJvohgk","price":0.08747055,"numutxos":255,"avevolume":2.06400000,"maxvolume":80,"depth":600.62400000,"pubkey":"30eb3d952f66eba2df0100b97d6707257cf91dc8c8b0237cfb7c3aa70dc52d4d","age":1,"zcredits":0}],"numbids":2,"biddepth":750.78000000,"asks":[{"coin":"CHIPS","address":"RQzkkncY8ehpRg8M4kvKmDMcbFxcJvohgk","price":0.09753523,"numutxos":55,"avevolume":0.26139442,"maxvolume":4.67466851,"depth":14.37669293,"pubkey":"30eb3d952f66eba2df0100b97d6707257cf91dc8c8b0237cfb7c3aa70dc52d4d","age":1,"zcredits":0}, {"coin":"CHIPS","address":"RXUF132uyPVTVUdLn16zCgvYoFXya3pyVb","price":0.09765861,"numutxos":81,"avevolume":0.28360061,"maxvolume":4.69776986,"depth":37.34834223,"pubkey":"825d0e1355117f6b76e7b3741f51c1827e72e25ddc688c0b20ad5b1ec7b28b4f","age":6,"zcredits":0}, {"coin":"CHIPS","address":"RAzheh3L7QtBL7oNKByVa43CtgALht6bbT","price":0.09819276,"numutxos":132,"avevolume":0.39119994,"maxvolume":11.19711667,"depth":88.98673580,"pubkey":"50959696e9d954d5853b113b54bfd695f7dd1a272f01700b13d6cd7e4b9bc704","age":2,"zcredits":0}, {"coin":"CHIPS","address":"RMdjuxKBhyr87yhKp6BLUg2p9673NMcPAu","price":0.09886392,"numutxos":84,"avevolume":0.47138318,"maxvolume":6.24424531,"depth":128.58292294,"pubkey":"040f1d2d5d12027afa2cec30477312e225b0d24c77cc4aa08d3fffe51277b904","age":7,"zcredits":0}],"numasks":4,"askdepth":160.72865368,"base":"CHIPS","rel":"KMD","timestamp":1519284386,"netid":0}

# Check swapstatus (succeeds)
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD"}'
[]

# Place buy order
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"buy", "base":"CHIPS", "rel":"KMD", "relvolume": 0.1, "price": 0.1})}'
{"result":"success","swaps":[],"netamounts":[],"pending":{"expiration":1519285404,"timeleft":360,"tradeid":redacted,"requestid":0,"quoteid":0,"bob":"CHIPS","base":"CHIPS","basevalue":1.00030019,"alice":"KMD","rel":"KMD","relvalue":0.10001000,"aliceid":redacted}}

# Check swapstatus (kills mm)
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD"}'
curl: (52) Empty reply from server

# mm is totally dead
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD"}'
curl: (7) Failed to connect to 127.0.0.1 port 7783: Connection refused

I've had this problem consistently for the last week and have been regularly updating mm, so it doesn't seem like anything that's been introduced recently. Swaps appear to go through ok if you place the buy order and leave it. It's checking the status directly after that's causing everything to break.

[lukechilds]

Also tested on both Linux and macOS so it's not a platform specific bug and not specific to my environment if that's any help.

[jl777]

to help with troubleshooting, what if you wait 10 seconds from the buy order before issuing the swapstatus? I am assuming it is a timing issue, ie. if you do some other call like getpeers after buy, it would still crash if you do the swapstatus all the same second?

In the meantime I will investigate this

[lukechilds]

Thanks.

I have previously tested calling buy, then portfolio, then swapstatus.

The portfolio command succeeded, it was only once the swapstatus was called that everything dies.

And I had also tested calling buy and then waiting for a while and the buy order filled successfully and I could issue commands to mm after waiting.

I know you store swap history in a file on disk, could it be that the buy command is still doing something with the text file while the swapstatus command is trying to read it? Or something along those lines?

[jl777]

what if you called swapstatus with the requestid and quoteid, instead of base and rel?

requestid/quoteid goes directly to just one set of swapfiles base/rel scans the entire list

needless to say requestid/quoteid is the lighest weight variant of swapstatus

[lukechilds]

requestid and quoteid were both returned as 0 from buy.

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"buy", "base":"CHIPS", "rel":"KMD", "relvolume": 0.1, "price": 0.1})}'
{"result":"success","swaps":[],"netamounts":[],"pending":{"expiration":1519285404,"timeleft":360,"tradeid":redacted,"requestid":0,"quoteid":0,"bob":"CHIPS","base":"CHIPS","basevalue":1.00030019,"alice":"KMD","rel":"KMD","relvalue":0.10001000,"aliceid":redacted}}

[jl777]

i think you want to issue recentswaps right after a buy to get the requestid/quoteid (will take some seconds to get this far if it indeed gets an ordermatch)

!/bin/bash

source userpass curl --url "http://127.0.0.1:7783" --data "{\"userpass\":\"$userpass\",\"method\":\"recentswaps\",\"limit\":100}"

it will return the most recent swap as pending and at first it wont have both requestid and quoteid, but it should have aliceid which will stay the same and can be used to verify that a requestid/quoteid is the same request by comparing aliceid

then once you get the requestid/quoteid to use that form of swapstatus.

[lukechilds]

So is it safe to call swapstatus with base/rel?

Because currently in our app, if the user is on the CHIPS/KMD trading pair then we call swapstatus with base/rel to show relevant trade history for that pair. Is that still going to kill mm if the user has called buy just before or will that be fixed?

Alternatively, is it possible to query recentswaps with aliceid if that's the only constant?

[jl777]

we tried to duplicate the crash but couldnt get it, any gdb backtrace would help us isolate the problem, it really shouldnt be crashing. I will fix it once we can duplicate it or have enough info via backtrace.

recentswaps returns the recentswaps, including the current pending one if any. Not sure how you would know the aliceid to call recentswaps with before the first call to recentswaps

[lukechilds]

Odd that you can't recreate the issue, when following the steps posted above it dies consistently for me across operating systems and across machines. Tested on Linux, macOS and Docker.

gdb backtrace:

(gdb) bt
#0  __GI___libc_free (mem=0x7d297d312e30) at malloc.c:2951
#1  0x0000000000492e08 in cJSON_freestr (str=0x7d297d312e30 <error: Cannot access memory at address 0x7d297d312e30>) at ../crypto777/cJSON.c:87
#2  0x0000000000492fc0 in cJSON_Delete (c=0x7fffe0515120) at ../crypto777/cJSON.c:135
#3  0x0000000000492f76 in cJSON_Delete (c=0x7fffe0515210) at ../crypto777/cJSON.c:133
#4  0x0000000000492f76 in cJSON_Delete (c=0x7fffe0514c80) at ../crypto777/cJSON.c:133
#5  0x0000000000492f76 in cJSON_Delete (c=0x7fffe0d180a0) at ../crypto777/cJSON.c:133
#6  0x0000000000497903 in free_json (item=0x7fffe0d180a0) at ../crypto777/cJSON.c:1195
#7  0x00000000004633d1 in basilisk_swapentries (refbase=0x7fffe0d17fa0 "CHIPS", refrel=0x7fffe0d18030 "KMD", limit=10) at exchanges/LP_remember.c:1818
#8  0x000000000048a7a3 in stats_JSON (ctx=0x7fffe0000d00, myipaddr=0x507acc "127.0.0.1", pubsock=-1, argjson=0x7fffe0d186e0, remoteaddr=0x7fffeb7f3740 "127.0.0.1", port=7783)
    at exchanges/LP_commands.c:336
#9  0x00000000004094d3 in stats_rpcparse (retbuf=0x7fffeb7f3e80 "", bufsize=4194816, jsonflagp=0x7fffeb7f36d0, postflagp=0x7fffeb7f36cc, 
    urlstr=0x7fffe0114970 "POST / HTTP/1.1", remoteaddr=0x7fffeb7f3740 "127.0.0.1", filetype=0x7fffeb7f3780 "", port=7783) at exchanges/stats.c:577
#10 0x00000000004099ec in LP_rpc_processreq (_ptr=0x7fffe0d185f0) at exchanges/stats.c:710
#11 0x0000000000409fd7 in stats_rpcloop (args=0x7ffff1d20c6c) at exchanges/stats.c:859
#12 0x00007ffff76fd6ba in start_thread (arg=0x7fffeb7fe700) at pthread_create.c:333
#13 0x00007ffff712a41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

[jl777]

Thanks! pushed fix

[lukechilds]

Hmmn, doesn't quite seem to be fixed. Just tested against the latest build and it seems like something else is causing it to die now:

*** Error in `/home/lukechilds/dev/SuperNET/iguana/marketmaker': free(): invalid pointer: 0x00007fffe4000078 ***

Thread 6 "marketmaker" received signal SIGBUS, Bus error.
[Switching to Thread 0x7fffeb7fe700 (LWP 2813)]
malloc_consolidate (av=av@entry=0x7fffe4000020) at malloc.c:4169
4169    malloc.c: No such file or directory.
(gdb) bt
#0  malloc_consolidate (av=av@entry=0x7fffe4000020) at malloc.c:4169
#1  0x00007ffff70a4cde in _int_malloc (av=av@entry=0x7fffe4000020, 
    bytes=bytes@entry=1182) at malloc.c:3450
#2  0x00007ffff70a7dca in __libc_calloc (n=<optimized out>, 
    elem_size=<optimized out>) at malloc.c:3236
#3  0x00007ffff7de2bf6 in _dl_new_object (
    realname=realname@entry=0x7fffe4118c30 "/lib/x86_64-linux-gnu/libgcc_s.so.1", libname=libname@entry=0x7ffff71af686 "libgcc_s.so.1", type=type@entry=2, 
    loader=loader@entry=0x0, mode=mode@entry=-1879048191, nsid=nsid@entry=0)
    at dl-object.c:75
#4  0x00007ffff7ddd50d in _dl_map_object_from_fd (
    name=name@entry=0x7ffff71af686 "libgcc_s.so.1", 
    origname=origname@entry=0x0, fd=32, fbp=fbp@entry=0x7fffeb7eaec0, 
    realname=0x7fffe4118c30 "/lib/x86_64-linux-gnu/libgcc_s.so.1", 
    loader=loader@entry=0x0, l_type=2, mode=-1879048191, 
    stack_endp=0x7fffeb7eaeb8, nsid=0) at dl-load.c:1028
#5  0x00007ffff7ddfc27 in _dl_map_object (loader=0x0, 
    loader@entry=0x7ffff7fdc4e0, 
    name=name@entry=0x7ffff71af686 "libgcc_s.so.1", type=type@entry=2, 
    trace_mode=trace_mode@entry=0, mode=mode@entry=-1879048191, 
    nsid=<optimized out>) at dl-load.c:2498
#6  0x00007ffff7dec577 in dl_open_worker (a=a@entry=0x7fffeb7eb480)
    at dl-open.c:237
#7  0x00007ffff7de7564 in _dl_catch_error (objname=objname@entry=0x7fffeb7eb470, 
    errstring=errstring@entry=0x7fffeb7eb478, mallocedp=mallocedp@entry=0x7fffeb7eb46f, 
    operate=operate@entry=0x7ffff7dec4d0 <dl_open_worker>, args=args@entry=0x7fffeb7eb480)
    at dl-error.c:187
#8  0x00007ffff7debda9 in _dl_open (file=0x7ffff71af686 "libgcc_s.so.1", 
    mode=-2147483647, caller_dlopen=0x7ffff7138a85 <init+21>, nsid=-2, 
    argc=<optimized out>, argv=<optimized out>, env=0x7fffffff8d70) at dl-open.c:660
#9  0x00007ffff71665ad in do_dlopen (ptr=ptr@entry=0x7fffeb7eb6a0) at dl-libc.c:87
#10 0x00007ffff7de7564 in _dl_catch_error (objname=0x7fffeb7eb690, 
    errstring=0x7fffeb7eb698, mallocedp=0x7fffeb7eb68f, 
    operate=0x7ffff7166570 <do_dlopen>, args=0x7fffeb7eb6a0) at dl-error.c:187
#11 0x00007ffff7166664 in dlerror_run (args=0x7fffeb7eb6a0, 
    operate=0x7ffff7166570 <do_dlopen>) at dl-libc.c:46
#12 __GI___libc_dlopen_mode (name=name@entry=0x7ffff71af686 "libgcc_s.so.1", 
    mode=mode@entry=-2147483647) at dl-libc.c:163
#13 0x00007ffff7138a85 in init () at ../sysdeps/x86_64/backtrace.c:52
#14 0x00007ffff7704a99 in __pthread_once_slow (once_control=0x7ffff73eb110 <once>, 
    init_routine=0x7ffff7138a70 <init>) at pthread_once.c:116
#15 0x00007ffff7138ba4 in __GI___backtrace (array=array@entry=0x7fffeb7eb760, 
    size=size@entry=64) at ../sysdeps/x86_64/backtrace.c:105
#16 0x00007ffff70429f5 in backtrace_and_maps (do_abort=<optimized out>, do_abort@entry=2, 
    written=<optimized out>, fd=fd@entry=31) at ../sysdeps/unix/sysv/linux/libc_fatal.c:47
#17 0x00007ffff709a7e5 in __libc_message (do_abort=do_abort@entry=2, 
    fmt=fmt@entry=0x7ffff71b3ed8 "*** Error in `%s': %s: 0x%s ***\n")
    at ../sysdeps/posix/libc_fatal.c:172
#18 0x00007ffff70a337a in malloc_printerr (ar_ptr=<optimized out>, ptr=<optimized out>, 
    str=0x7ffff71b0caf "free(): invalid pointer", action=3) at malloc.c:5006
#19 _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at malloc.c:3867
#20 0x00007ffff70a753c in __GI___libc_free (mem=<optimized out>) at malloc.c:2968
#21 0x0000000000492dec in cJSON_freestr (str=0x7fffe4000078 "p\330\316\344\377\177")
    at ../crypto777/cJSON.c:87
#22 0x0000000000492fa4 in cJSON_Delete (c=0x7fffe411cc00) at ../crypto777/cJSON.c:135
#23 0x0000000000492f5a in cJSON_Delete (c=0x7fffe4118be0) at ../crypto777/cJSON.c:133
#24 0x0000000000492f5a in cJSON_Delete (c=0x7fffe411d7e0) at ../crypto777/cJSON.c:133
#25 0x00000000004978e7 in free_json (item=0x7fffe411d7e0) at ../crypto777/cJSON.c:1195
#26 0x00000000004633a9 in basilisk_swapentries (refbase=0x7fffe4118810 "CHIPS", 
    refrel=0x7fffe41188a0 "KMD", limit=10) at exchanges/LP_remember.c:1818
#27 0x000000000048a787 in stats_JSON (ctx=0x7fffe4000d00, myipaddr=0x507aac "127.0.0.1", 
    pubsock=-1, argjson=0x7fffe411d610, remoteaddr=0x7fffeb7f3740 "127.0.0.1", port=7783)
    at exchanges/LP_commands.c:336
#28 0x00000000004094d3 in stats_rpcparse (retbuf=0x7fffeb7f3e80 "", bufsize=4194816, 
    jsonflagp=0x7fffeb7f36d0, postflagp=0x7fffeb7f36cc, 
    urlstr=0x7fffe44ed460 "POST / HTTP/1.1", remoteaddr=0x7fffeb7f3740 "127.0.0.1", 
    filetype=0x7fffeb7f3780 "", port=7783) at exchanges/stats.c:577
#29 0x00000000004099ec in LP_rpc_processreq (_ptr=0x7fffe411ce40) at exchanges/stats.c:710
#30 0x0000000000409fd7 in stats_rpcloop (args=0x7ffff1d20c6c) at exchanges/stats.c:859
#31 0x00007ffff76fd6ba in start_thread (arg=0x7fffeb7fe700) at pthread_create.c:333
#32 0x00007ffff712a41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

[jl777]

can you mv the DB/SWAPS dir so you start with a fresh DB/SWAPS, it just seems there is some strange data that is causing this. we cant duplicate the crash, so I am hoping with a fresh DB/SWAPS it will work around the issue for now

[lukechilds]

Yeah, I have been nuking the entire DB folder between tests to rule that out. In Docker it's a completely fresh image each time I run it.

However I think that latest test was just on Linux (not Docker) and I pulled a few commits to check your latest changes just rebuilt. So it may not have cleared it then.

I just deleted the DB folder and tested again and I'm still seeing the issue:

Thread 6 "marketmaker" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7fffeb7fe700 (LWP 3346)]
_int_free (av=0x7fffe0000020, p=0x7fffe01152d0, have_lock=0) at malloc.c:3984
3984    malloc.c: No such file or directory.
(gdb) bt
#0  _int_free (av=0x7fffe0000020, p=0x7fffe01152d0, have_lock=0) at malloc.c:3984
#1  0x00007ffff70a753c in __GI___libc_free (mem=<optimized out>) at malloc.c:2968
#2  0x0000000000492e0b in cJSON_freenode (item=0x7fffe01152e0) at ../crypto777/cJSON.c:92
#3  0x0000000000492fb0 in cJSON_Delete (c=0x7fffe01152e0) at ../crypto777/cJSON.c:136
#4  0x0000000000492f5a in cJSON_Delete (c=0x7fffe01183b0) at ../crypto777/cJSON.c:133
#5  0x0000000000492f5a in cJSON_Delete (c=0x7fffe011cd00) at ../crypto777/cJSON.c:133
#6  0x0000000000492f5a in cJSON_Delete (c=0x7fffe01149c0) at ../crypto777/cJSON.c:133
#7  0x00000000004978e7 in free_json (item=0x7fffe01149c0) at ../crypto777/cJSON.c:1195
#8  0x00000000004633a9 in basilisk_swapentries (refbase=0x7fffe0118cf0 "CHIPS", 
    refrel=0x7fffe0118d80 "KMD", limit=10) at exchanges/LP_remember.c:1818
#9  0x000000000048a787 in stats_JSON (ctx=0x7fffe0000d00, myipaddr=0x507aac "127.0.0.1", 
    pubsock=-1, argjson=0x7fffe011d080, remoteaddr=0x7fffeb7f3740 "127.0.0.1", port=7783)
    at exchanges/LP_commands.c:336
#10 0x00000000004094d3 in stats_rpcparse (retbuf=0x7fffeb7f3e80 "", bufsize=4194816, 
    jsonflagp=0x7fffeb7f36d0, postflagp=0x7fffeb7f36cc, 
    urlstr=0x7fffe04ed460 "POST / HTTP/1.1", remoteaddr=0x7fffeb7f3740 "127.0.0.1", 
    filetype=0x7fffeb7f3780 "", port=7783) at exchanges/stats.c:577
#11 0x00000000004099ec in LP_rpc_processreq (_ptr=0x7fffe0000cd0) at exchanges/stats.c:710
#12 0x0000000000409fd7 in stats_rpcloop (args=0x7ffff1d20c6c) at exchanges/stats.c:859
#13 0x00007ffff76fd6ba in start_thread (arg=0x7fffeb7fe700) at pthread_create.c:333
#14 0x00007ffff712a41d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:109

Are you following the exact steps I posted in my original message and not getting errors?

[jl777]

could it be docker specific? i guess we didnt try it in docker, just with actual unix

[jl777]

one useful test would be to comment out the free_json() call on line 1818 in LP_remember.c

[lukechilds]

could it be docker specific?

No, I've tested on Docker, Linux and macOS.

All the backtraces I've posted have been on Linux.

I'll test commenting that fn call out.

[lukechilds]

Commenting out that function stops mm dying however I'm getting some pretty weird behaviour. Not sure if this is expected without that call or if these are unrelated bugs in mm.

After commenting out free_json() and nuking the DB folder on Linux I set everything up:

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"electrum", "coin":"KMD", "ipaddr":"electrum1.cipig.net", "port":10001}' 
{"ipaddr":"electrum1.cipig.net","port":10001,"result":"success"}
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"electrum", "coin":"CHIPS", "ipaddr":"electrum1.cipig.net", "port":10053}'
{"ipaddr":"electrum1.cipig.net","port":10053,"result":"success"}

Then place the buy order:

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"buy", "base":"CHIPS", "rel":"KMD", "relvolume": 0.1, "price": 0.1})}'
{"result":"success","swaps":[],"netamounts":[],"pending":{"expiration":1519640305,"timeleft":60,"tradeid":3214521252,"requestid":0,"quoteid":0,"bob":"CHIPS","base":"CHIPS","basevalue":1.00030019,"alice":"KMD","rel":"KMD","relvalue":0.10001000,"aliceid":643930338339586048}}

Now the status commands don't kill mm, however they also don't show anything as pending:

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD"}'
[]
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD", "pending":1}'
[]
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"recentswaps"}'
{"result":"success","swaps":[],"netamounts":[]}

After quite a while recentswaps shows some data:

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"recentswaps"}'
{"result":"success","swaps":[[3393440784, 3857402660]],"netamounts":[]}

After a while later the swap is complete and recentswaps show more data but swapstatus still doesn't show anything even with the pending flag:

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD"}'
[]
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD", "pending":1}'
[]
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"recentswaps"}'
{"result":"success","swaps":[[3393440784, 3857402660, {"KMD":-0.27307615,"CHIPS":2.75604455,"price":10.09258608}]],"netamounts":[{"KMD":-0.27307615}, {"CHIPS":2.75604455}]}

So once a buy order had been placed it's just kind of in limbo and there's no way for us to get any reliable data on it from mm for an undetermined amount of time. This is not a good user experience from a GUI perspective, once they've placed an order they're going to want to know exactly what's going on.

Then once it's completed it doesn't show up in the swapstatus history, so we can't rely on that command to reliably show the history for a trade pair.

Also, this may be expected behaviour, I'm not sure, but notice in the above commands how I placed an order for 0.1 KMD and it ended up trading 0.27 KMD. Is that expected or a bug? I'm aware this works very differently to a traditional exchange and the exact rate/volume isn't guaranteed, but I assumed it would be very close. Definitely not over 2x the amount specified. Is that supposed to happen?

[jl777]

sometimes you get a lot better price than you asked for. the limitation is put on what you spend, not what you get. The assumption is if you are happy to get 0.1KMD for X, you are not upset to get 0.27KMD for X

something is definitely very strange...

can you just not use the base/rel version of swapstatus for now and just use recent swaps, also waiting some seconds after issuing the call might avoid the edge case you are hitting.

[lukechilds]

sometimes you get a lot better price than you asked for. the limitation is put on what you spend, not what you get. The assumption is if you are happy to get 0.1KMD for X, you are not upset to get 0.27KMD for X

But I wanted to buy 0.1 KMD worth of CHIPS and the trade spent 0.27 KMD. It spent more than I asked it to.

So mulitplying those values a bit, does that mean if a user had a portfolio worth $5,000 and placed an order to buy $1,000 worth of CHIPS with KMD, BarterDEX might purchase $2,700 worth of CHIPS with KMD? If so, that seems to me like something a user probably would get upset about. Even if they're happy with the rate they're getting.

can you just not use the base/rel version of swapstatus for now and just use recent swaps

But we want to show the relevant base/rel order history for any given trading pair on the exchange view.

So using recentswaps it sounds like we would have to query all the recent swaps, loop through them, issue a call to swapstatus with requestid/quoteid for each swap, then check the base/rel matches the current trading pair, and if so, include it in our list.

This seems very inefficient, especially since we're trying to keep the number of requests to mm as low as possible, and seems like we're basically re-implementing the base/rel functionality on our end. Is there no way to fix this in mm so it works as expected?

also waiting some seconds after issuing the call might avoid the edge case you are hitting.

I did, in the example above I was running:

$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD"}'
[]
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"swapstatus", "base":"CHIPS", "rel":"KMD", "pending":1}'
[]
$ curl 'http://127.0.0.1:7783' --data '{"userpass":"redacted", "method":"recentswaps"}'
{"result":"success","swaps":[],"netamounts":[]}

every few seconds. It took quite a while for the ids to show up. I don't know exactly how long but I'd say over a minute.

[jl777]

if it spent more coins that you wanted to that is a bug, but it is a separate issue.

I think you are misunderstanding about recentswaps. All you need to do is look to see if a "pending" object is present. If it is, that is the one that was just started. there is no need to iterate, etc. Also it might be that calling the base/rel method immediately after starting a swap is causing the problems, in any case base/rel swapstatus will scan ALL your historical swaps and that could take a very long time. That is why I keep suggesting that you dont use the really inefficient way of finding the swap that you might have just started.

If you want efficient:

1. issue trade
2. issue recentswaps
3. see if "pending" object is there, if it is, that is from 1. (unless 1 returned an error)

Why is it that you dont want to follow the recommendation? That will likely be efficient and avoid the crash.

As far as generating an exchange view with all historical swaps, it is a separate issue totally from the finding the most recently issued swap. It will take a while to do, using swapstatus and the serialized nature will likely make it impractical to use. For a performant realtime viewing you can update an internal list of DB/SWAPS. I know that is extra work, but for the best performance you can monitor the DB/SWAPS directory and generate an event when a new swap appears, tag the base/rel for each swap with pertinent details and then update the exchange view. I think doing anything else will just not be fast enough for what you want to do.

[lukechilds]

We just want a way to list all trades for a given pair, both historical and pending. The API docs say we can do that with just swapstatus so that's what I was trying to do.

I'll try implementing this by calling swapstatus once to get the historical trades and update our internal list with pending and then newer complete trades with recentswaps like you mentioned above.

Regarding looping over, the docs say we only get the requestid/quoteid from recentswaps, so I was assuming we would have to loop over all the swaps and issue a swapstatus with the requestid/quoteid for each swap in recent swaps to get the full information on the current state of the swap.

Are there any plans to make the base/rel swapstatus command more efficient? It seems over the top to make every single frontend implement their own low level file system logic for tracking trade history. If it could be implemented performantly once in mm then all front ends will get this without lots of extra duplicated code.

Also, we have an option to connect to a remote mm node. So power users can run mm on an always on secure server remotely and connect to it from the GUI via a secure channel. Then it can be trading for them while their GUI is offline. We won't be able to read the swaps off their filesystem if the node is remote.

[jl777]

sorry the docs didnt mention the pending object, I will have that updated.

you do realize this is a 1.0 release? of course we plan to improve performance across the board, but it wont be immediate, as in the 2.0 release will be designed for best performance of all aspects

For implementing advanced configurations it is expected that there will be some additional issues to be solved and the workload divided between the local node and remote node.

[lukechilds]

you do realize this is a 1.0 release? of course we plan to improve performance across the board, but it wont be immediate, as in the 2.0 release will be designed for best performance of all aspects

That's great, I'm just trying to work out if it really makes sense for us to spend time implementing all of this stuff (internal electrum handling/internal swap history) on our end if it's going to be provided for us via the API in v2. It's going to add a lot of development overhead that will be completely redundant once you've implemented it in mm.

[jl777]

likely 2.0 wont be until end of this year or even next year

[lukechilds]

I've refactored our exchange page to use recentswaps/swapstatus(requestid, quoteid) as suggested here: https://github.com/jl777/SuperNET/issues/600#issuecomment-367613936

However recentswaps doesn't seem to return reliable data and swapstatus(requestid, quoteid) causes mm to hang.

I don't want to pollute this issue any more as it was meant to track the swapstatus killing mm bug so I've opened separate issues for the new bugs so we can track them seperately:

• https://github.com/jl777/SuperNET/issues/626
• https://github.com/jl777/SuperNET/issues/627

[jl777]

thanks for splitting into new issues, that will help. also when you say hang, i think you mean "it takes way too long and looks like it is a permanent hang", what is happening is that the calling of swapstatus is triggering an attempt to complete the swap. I need to add a flag that says to just return current status and dont do any actual work to the swap status. I think that will solve the "hang" issue

but it does seem that the new method is not causing an actual crash, so with the addition of the "fastflag" at least this issue should be very close to solved.

[lukechilds]

Sorry yes thats correct, when I say hang I mean the request takes a long time to respond.

However it also blocks all other requests, i.e while the swapstatus command is taking a while to respond we can't check the current orderbook status, effectively causing our application to hang.

[lukechilds]

when you say hang, i think you mean "it takes way too long and looks like it is a permanent hang"

Just to clarify, I don't think it was a permanent hang, it was just for like 5-30 seconds. It's the fact that we can't make any other request to mm during that period that I referred to it as "hanging".

[jl777]

ok, just making sure it is not stuck in an infinite loop. so the fix of a fastflag will do the trick, I will get that out today and hopefully also solve the "limbo" issue for a new swap

[jl777]

pushed a version to jl777 branch that supports "fast":1 flag for swapstatus call with requestid/quoteid, it will limit itself to local file access and should never take more than time for at most 10 HDD file accesses

also, moved the adding to the "list" file before the "pending" object is cleared, so you might see recentswaps return the same swap in its list and in the "pending" object, but this avoids the limbo state

[jl777]

also, it doesnt matter so much to the new approach, but I finally fixed the original swapstatus base/rel crash

[jl777]

for some reason it takes a bit less than a second for fast:1 swaps, hopefully that is fast enough for now. I look forward to the event driven api spec (in a new issue)

[lukechilds]

Great, thanks for this, will test tomorrow.

Will work on an event driven api spec and submit a new issue as soon as it's ready

[jl777]

thanks again for your detailed feedback, it help isolate the cause for the slow performance

[lukechilds]

Just tested against the latest build and can confirm this issue is now resolved 🎉