Author

Topic: stream logs from the crash point (Read 1759 times)

jr. member
Activity: 56
Merit: 1
June 23, 2011, 06:29:57 PM
#13
Mt gox has mentioned updating the backend, I hope it involves changing the way this all works. No one was able to get a buy order in during the crash because it was all "one order" being executed. Even with such a huge sell, I don't think it would have made it to $0.01 is people had been able to buy. I know I would have thrown everything I had at it as soon as it went under $5. I think enough people would have been there to keep it above $1.

I guess it all depends on how much cash people have in their mt gox accounts.
member
Activity: 84
Merit: 10
June 23, 2011, 06:21:57 PM
#12
Well, I think I got the trades as well (but my code just ignores them).  It was my working assumption initially that the ticker would be updated after each trade.  But, apparently that is not the case--it is only updated after an entire order is filled (and I presume only one order can be in the process of filling at a time).
sr. member
Activity: 410
Merit: 250
Proof-of-Skill - protoblock.com
June 22, 2011, 01:56:08 AM
#11
my stream didnt go down..

here are all the trades..

http://paste.pocoo.org/show/416783/
member
Activity: 84
Merit: 10
June 22, 2011, 01:44:07 AM
#10
The ticket showed the price reflected by completed trades as expected.

The websocket allowed you to see the order book get cleared out in real time

What is this 'ticket' you speak of?  Did you mean 'ticker'?  And, if so, the ticker is very much an integral part of the websocket stream.
full member
Activity: 154
Merit: 100
June 21, 2011, 01:27:06 PM
#9
The ticket showed the price reflected by completed trades as expected.

The websocket allowed you to see the order book get cleared out in real time
legendary
Activity: 2408
Merit: 1121
June 21, 2011, 01:23:15 PM
#8
Even in the major exchanges, quote dissemination is a problem. That is why major infrastructure is required to match trades, while a completely separate part spits out prices. Since both functions were on the same box/cluster/cpu, it makes sense the matching took priority over quotes getting streamed.

member
Activity: 84
Merit: 10
June 21, 2011, 01:19:36 PM
#7
Each time a buy order was filled it was announced. So you could see the price fall as buy orders got filled. Did the YouTube video show the time stamps on the trades? If I recall correctly every single buy order that got filled had the same time stamp.

Hmm, this makes sense.  But, I still think that the ticker should be updated after every trade.  Although this was one huge sell order, it was filled by many small buy orders.  From the perspective of the buyers, those were 'trades'.  Why should one end of a trade be given more priority over the other end with respect to the ticker?

Anyway, thanks for the responses.  I feel better about trading on Gox now.
full member
Activity: 126
Merit: 101
June 21, 2011, 01:05:49 PM
#6
Each time a buy order was filled it was announced. So you could see the price fall as buy orders got filled. Did the YouTube video show the time stamps on the trades? If I recall correctly every single buy order that got filled had the same time stamp.
member
Activity: 84
Merit: 10
June 21, 2011, 01:00:39 PM
#5
The sell off was one very very large sell order. The ticker did not update until the order was finished processing. I watched it get processed in real time on http://bitcoin.clarkmoody.com/time-sales/

The messages you got in between ticker updates were the many buy orders getting filled one by one.

I thought about this but...
If this is the case, how did that one guy produce a youtube video watching the price fall with commentary?  -or- rather, if i understand the purpose of clarkmoody:  how does clarkmoody get 'real time' information about the sale in progress when the websockets stream does not push it?
kjj
legendary
Activity: 1302
Merit: 1026
June 21, 2011, 12:52:15 PM
#4
I guess there is some interest in the inner workings of exchange markets, so I'm going to publicly post a PM exchange.  Note that I'm not affiliated with mtgox in any way.  I have an account there, but I've never funded it or done any trades.  But, I have designed and written software for exchange markets before.

This is conjecture on my part, but experienced conjecture.  I'm only posting it here to show that there are possible technical reasons why an exchange system might exhibit strange behavior during unusual events.  I'm not claiming to disprove any of the many conspiracy theories running around these forums, but I am showing that one is not necessary to explain what happened the other day.

Also, my mention of MySQL is not a claim that they are using it.  I have no idea what they are using.

It started with a PM about a comment I made on why the exchange didn't lock the order books while processing matches.

Quote from: REDACTED date=1308623551
Quote from: REDACTED date=1308621100
"This is a bad idea, but it isn't obvious to people that haven't written or worked with large exchange markets."

A quick explanation, or a reference to where I can find out more? This is interesting.

The short version is that you take a huge hit to performance to prevent something that can't really be prevented and almost no one cares about.

Unnecessary locking means that you need several times as much capacity to handle the same throughput.  There are schemes that can queue up orders before dumping them into the main databases between locked transactions, but this means that either orders get delayed, or the clearing code has to check two sets of tables (which means new delays).

Exchanges that get a lot of traffic are always coded with an order matcher that finds one match at a time before moving on.  They are simple and fast, or efficient, really.

And you could still simulate the same behavior by having the order matcher take extra steps for orders that matched, but didn't close out.  It just has to keep attention on that order until it fails to match once, and only look at opposed orders that are older than the time when the matching attempt started.

But no exchange does that, because people placing large orders benefit when other orders jump in front of the sale.  Serious participants would just write their trading bots to nibble instead of chomp, to give people (and other bots) time to reposition themselves to their mutual benefit.

So, it would have reduced confusion in this situation, which is very rare and unusual, but it would hindered operations the other 99.99999% of the time.

After sending my PM, I realized the beneficial implications for both the buyer and the seller as well as the likelihood of partitioning (nibbling) a sell off. Thanks for your response though!

Nonetheless, I still surmise that mtgox is likely small enough such that the infrastructure is managed quite similar to what I proposed, especially given the length of time for the sell off to complete.

Based on reports of the site's sluggishness during the rundown, I would suspect that their order matcher runs at full speed (and possibly high priority) until it is unable to find a match, and then it sleeps, allowing other processes use of the CPU and IO capacity.  I've had big orders clobber stout boxes before, and until it happens to you, the value of only matching a fixed number of transactions before yielding for a second isn't always obvious.

Keep in mind that while it isn't necessary to do much locking when adding an order, any time there is a match, both order tables must be locked, along with tables for balances, ledgers and logs.  Multiply that out by a couple thousand, and add flushes to disk after each transaction, and you can easily end up with 30-60 minutes of churn.  Their choice of database may also have been a factor in that.  Looks like they are using PHP, which usually goes hand in hand with MySQL which is awesome for a lot of stuff, but not necessarily for this.

If there had been a big single lock, either of the table or the whole database, it would have been much quicker, maybe only a few minutes, but anything involving the locked portion would have stalled for the entire duration.
full member
Activity: 126
Merit: 101
June 21, 2011, 12:30:20 PM
#3
The sell off was one very very large sell order. The ticker did not update until the order was finished processing. I watched it get processed in real time on http://bitcoin.clarkmoody.com/time-sales/

The messages you got in between ticker updates were the many buy orders getting filled one by one.
member
Activity: 84
Merit: 10
June 21, 2011, 12:00:09 PM
#2
So, does no one have an explanation for this that clears Gox's name?  If I don't hear a reasonable explanation for this, I'm done with Gox (and I would suggest that others be done as well).

This isn't the first 'coincidental' malfunction that has bitten me either.
member
Activity: 84
Merit: 10
June 21, 2011, 12:00:21 AM
#1
(2011-06-19 10:04:05.468347): ticker: high: 18.8766, low: 15.26, vol: 46513, buy: 17.6, sell: 17.6023, last: 17.6
(2011-06-19 10:05:44.141865): ticker: high: 18.8766, low: 15.26, vol: 46481, buy: 17.6, sell: 17.6023, last: 17.6
(2011-06-19 10:05:55.618395): ticker: high: 18.8766, low: 15.26, vol: 46486, buy: 17.5, sell: 17.6, last: 17.6
(2011-06-19 10:06:33.219817): ticker: high: 18.8766, low: 15.26, vol: 46498, buy: 17.4326, sell: 17.6, last: 17.6
(2011-06-19 10:06:42.185397): ticker: high: 18.8766, low: 15.26, vol: 46499, buy: 17.4326, sell: 17.6, last: 17.6
(2011-06-19 10:11:50.609492): ticker: high: 18.8766, low: 15.26, vol: 46454, buy: 17.51, sell: 17.5998, last: 17.51
(2011-06-19 10:13:17.852609): ticker: high: 18.8766, low: 15.26, vol: 46453, buy: 17.51, sell: 17.5998, last: 17.51
(2011-06-19 10:13:47.728668): ticker: high: 18.8766, low: 15.26, vol: 46454, buy: 17.51, sell: 17.5998, last: 17.51   <------ A
(2011-06-19 10:51:11.170474): ticker: high: 18.8766, low: 0.01, vol: 282353, buy: 0.003, sell: 0.01, last: 0.01          <------ B
read_websocket error: HTTP Error 500: Internal Server Error
Connected to Mt. Gox
(2011-06-19 10:51:14.020662): ticker: high: 18.8766, low: 0.01, vol: 282452, buy: 0.003, sell: 0.01, last: 0.01
read_websocket error: HTTP Error 500: Internal Server Error
Connected to Mt. Gox
(2011-06-19 10:51:39.629533): ticker: high: 18.8766, low: 0.01, vol: 544904, buy: 7.51, sell: 10, last: 10
(2011-06-19 10:51:52.364589): ticker: high: 18.8766, low: 0.01, vol: 545343, buy: 0.8, sell: 10, last: 0.8
(2011-06-19 10:52:05.648917): ticker: high: 18.8766, low: 0.01, vol: 545337, buy: 1, sell: 10, last: 10
(2011-06-19 10:52:12.799261): ticker: high: 18.8766, low: 0.01, vol: 545339, buy: 3, sell: 10, last: 10
(2011-06-19 10:52:17.080434): ticker: high: 18.8766, low: 0.01, vol: 545316, buy: 3, sell: 10, last: 10

====================

I have my program designed to only printout tickers when they actually change.  Also, there is a timeout on the socket.read of 40 seconds and if it expires we see additional output such as:
read_websocket error: Timeout exceeded waiting for data from Gox

So, between points A & B (a time period of almost 40 very critical minutes) we know that:

1 - I received some sort of message from Gox at least every 40 seconds.
2 - None of those messages (if of the ticker variety) differed from this:
ticker: high: 18.8766, low: 15.26, vol: 46454, buy: 17.51, sell: 17.5998, last: 17.51

Does that seem strange to anyone else?
Jump to: