project Betfair, part 6

Table of Contents

Introduction

Previously on project Betfair, we spent some time tuning our market making bot and trying to make it make money in simulation. Today, we'll use coding and algorithms to make (and lose) us some money in real life.

Meet Azura

Scala is amazing. At the very least, it can be written like a better Java (with neat features like allowing multiple classes in one file) and then that can evolve into never having to worry about NullPointerExceptions and the ability to write blog posts about monads.

And strictly typed languages are fun! There's something very empowering about being able to easily refactor code and rename, extract, push and pull methods around, whilst being mostly confident that the compiler is going to stop you from doing stupid things. Unlike, say, Python, where you have to write (and maintain) a massive test suite to make sure every line of your code gets executed, here proper typing can replace a whole class of unit tests.

Hence (and because I kind of wanted to relearn Scala) I decided to write the live trading version of my Betfair market-making bot I called Azura in Scala.

This will mostly be a series of random tales, code snippets, war stories and postmortems describing its development.

Build/deploy process

The actual design of the bot (common between the research Python version and the production Scala version) is described here.

In terms of libraries, I didn't have to use many: the biggest one was probably the JSON parser from the Play! framework. I used SBT (Simple Build Tool ("never have I seen something so misnamed" — coworker, though I didn't have problems with it)) to manage dependencies and build the bot.

I didn't really have a clever deploy procedure: I would log onto the "production" box, pull the code and use

sbt assembly

to create a so-called uber-jar, a Java archive that has all of the project's dependencies packaged inside of it. So executing it with the Java Virtual Machine would be simply a matter of

java -Dazura.dry_run=false -jar target/scala-2.12/azura-assembly-0.1.jar arguments

Disadvantages: this takes up space and possibly duplicates libraries that already exist on the target machine. Advantages: we don't depend on the target machine having the right library versions or the Java classpath set up correctly: the machine only needs to have the right version of the JVM.

Parsing the stream messages

object MarketData {
  def parseMarketChangeMessage(message: JsValue): JsResult[MarketChangeMessage] = message.validate[MarketChangeMessage](marketChangeMessageReads)

	case class RunnerChange(runnerId: Int, backUpdates: Map[Odds, Int],
							layUpdates: Map[Odds, Int],
							tradedUpdates: Map[Odds, Int])

	case class MarketChange(marketId: String, runnerChanges: Seq[RunnerChange], isImage: Boolean)

	implicit val oddsReads: Reads[Odds] = JsPath.read[Double].map(Odds.apply)
	implicit val orderBookLineReads: Reads[Map[Odds, Int]] = JsPath.read[Seq[(Odds, Double)]].map(
	  _.map { case (p, v) => (p, (v * 100D).toInt) }.toMap)
	implicit val runnerChangeReads: Reads[RunnerChange] = (
	  (JsPath \ "id").read[Int] and
	  (JsPath \ "atb").readNullable[Map[Odds, Int]].map(_.getOrElse(Map.empty)) and
	  (JsPath \ "atl").readNullable[Map[Odds, Int]].map(_.getOrElse(Map.empty)) and
	  (JsPath \ "trd").readNullable[Map[Odds, Int]].map(_.getOrElse(Map.empty))) (RunnerChange.apply _)
	implicit val marketChangeReads: Reads[MarketChange] = (
	  (JsPath \ "id").read[String] and
	  (JsPath \ "rc").read[Seq[RunnerChange]] and
	  (JsPath \ "img").readNullable[Boolean].map(_.getOrElse(false))) (MarketChange.apply _)
	implicit val marketChangeMessageReads: Reads[MarketChangeMessage] = (
	  (JsPath \ "pt").read[Long].map(new Timestamp(_)) and
	  (JsPath \ "mc").readNullable[Seq[MarketChange]].map(_.getOrElse(Seq.empty))) (MarketChangeMessage.apply _)
	case class MarketChangeMessage(timestamp: Timestamp, marketChanges: Seq[MarketChange])
  }

This might take some time to decipher. The problem was converting a JSON-formatted order book message into a data structure used inside the bot to represent the order book — and there, of course, can be lots of edge cases. What if the message isn't valid JSON? What if the structure of the JSON isn't exactly what we expected it to be (e.g. a subentry is missing)? What if the type of something isn't what we expected it to be (instead of a UNIX timestamp we get an ISO-formatted datetime)?

The Play! JSON module kind of helps us solve this by providing a DSL that allows to specify the expected structure of the JSON object by combining smaller building blocks. For example, marketChangeReads shows how to parse a message containing changes to the whole market order book (MarketChangeMessage). We first need to read a string containing the market ID at "id", then a sequence of changes to each runner (RunnerChange) located at "rc" and then a Boolean value at "img" that says whether it's a full image (as in we need to flush our cache and replace it with this message) or not.

To read a RunnerChange (runnerChangeReads), we need to read an integer containing the runner's ID and the changes to its available to back, lay and traded odds. To read those changes (orderBookLineReads), we want to parse a sequence of tuples of odds and doubles, convert the doubles (represending pound amounts available to bet or traded) into integer penny values and finally turn that into a map.

Finally, parsing the odds is simply a matter of creating an Odds object from the double value representing the odds (which rounds the odds to the neearest ones allowed by Betfair).

Core of the Scala CAFBotV2

  override def getTargetMarket(orderBook: OrderBook, runnerOrders: RunnerOrders): (Map[Odds, Int], Map[Odds, Int]) = {
	val logger: Logger = Logger[CAFStrategyV2]

	val exposure = OrderBookUtils.getPlayerExposure(runnerOrders).net
	val exposureFraction = exposure / offeredExposure.toDouble
	logger.info(s"Net exposure $exposure, fraction of offer: $exposureFraction")

	if (orderBook.availableToBack.isEmpty || orderBook.availableToLay.isEmpty) {
	  logger.warn("One half of the book is empty, doing nothing")
	  return (Map.empty, Map.empty)
	}

	logger.info(s"Best back: ${orderBook.bestBack()}, Best lay: ${orderBook.bestLay()}")
	val imbalance = (orderBook.bestBack()._2 - orderBook.bestLay()._2) / (orderBook.bestBack()._2 + orderBook.bestLay()._2).toDouble
	logger.info(s"Order book imbalance: $imbalance")

	// Offer a back -- i.e. us laying
	val backs: Map[Odds, Int] = if (exposureFraction >= -2) {
	  val start = Odds.toTick(orderBook.bestBack()._1) +
		(if (exposureFraction >= -exposureThreshold && imbalance >= -imbalanceThreshold) 0 else -1) - levelBase
	  (start until (start - levels) by -1).map { p: Int => Odds.fromTick(p) -> (offeredExposure / Odds.fromTick(p).odds).toInt }.toMap
	} else Map.empty

	val lays: Map[Odds, Int] = if (exposureFraction <= 2) {
	  val start = Odds.toTick(orderBook.bestLay()._1) +
		(if (exposureFraction <= exposureThreshold && imbalance <= imbalanceThreshold) 0 else 1) + levelBase
	  (start until start + levels).map { p: Int => Odds.fromTick(p) -> (offeredExposure / Odds.fromTick(p).odds).toInt }.toMap
	} else Map.empty

	(backs, lays)
  }

The core is actually fairly simple and similar to the research version of CAFBotV2. Here, exposure really means inventory, as in amount of one-pound contracts the bot is holding. Instead of absolute inventory values for its limits (like 30 contracts in the previous post), the bot operates with fractions of amount of contracts it offers over its position (say, the previous limit of 30 contracts would have been represented here as 30/10 = 3).

After calculating the fraction and the order book imbalance, the bot calculates the back and lay bets it wishes to maintain in the book: first, the tick number it wishes to start on (the best back/lay or one level below/above if the order book imbalance or inventory is too negative/positive) and then each odds level counting down/up from that point. Finally, it divides the amount of contracts it wishes to offer by the actual odds in order to output the bet (in pounds) it wishes the be maintained at each price level.

There's also a custom levelBase parameter that allows to control how far from the best back/lay the market is made: with a levelBase of zero, the bot would place its bets at the best back/lay, with levelBase of one the bets would be 1 tick below/above best back/lay etc.

First messages on the stream and a dummy run

I sadly do not any more have the old logs back from when I managed to receive (and parse!) the first few messages from the Stream API, so here's a dramatic reconstruction.

20:46:58.093 [main] INFO main - Starting Azura...
20:46:58.096 [main] INFO main - Getting market suspend time...
20:46:58.648 [main] INFO main - {"filter":{"marketIds":["1.134156568"]},"marketProjection":["MARKET_START_TIME"],"maxResults":1}
20:46:59.793 [main] INFO main - [{"marketId":"1.134156568","marketName":"R9 6f Claim","marketStartTime":"2017-09-13T21:15:00.000Z","totalMatched":0.0}]
20:46:59.966 [main] INFO main - 2017-09-13T21:15
20:46:59.966 [main] INFO main - Initializing the subscription...
20:47:00.056 [main] INFO streaming.SubscriptionManager - {"op":"connection","connectionId":"100-130917204700-67655"}
20:47:00.077 [main] INFO streaming.SubscriptionManager - {"op":"status","id":1,"statusCode":"SUCCESS","connectionClosed":false}
20:47:00.081 [main] INFO main - Subscribing to the streams...
20:47:00.119 [main] INFO streaming.SubscriptionManager - {
  "op" : "status",
  "id" : 1,
  "statusCode" : "SUCCESS",
  "connectionClosed" : false
}
20:47:00.160 [main] INFO streaming.SubscriptionManager - {
  "op" : "status",
  "id" : 2,
  "statusCode" : "SUCCESS",
  "connectionClosed" : false
}
20:47:00.207 [main] INFO streaming.SubscriptionManager - {
  "op" : "mcm",
  "id" : 1,
  "initialClk" : "yxmUlZaPE8sZsOergBPLGYz/ipIT",
  "clk" : "AAAAAAAA",
  "conflateMs" : 0,
  "heartbeatMs" : 5000,
  "pt" : 1505335620115,
  "ct" : "SUB_IMAGE",
  "mc" : [ {
	"id" : "1.134156568",
	"rc" : [ {
	  "atb" : [ [ 5.1, 2.5 ], [ 1.43, 250 ], [ 1.01, 728.58 ], [ 1.03, 460 ], [ 5, 20 ], [ 1.02, 500 ], [ 1.13, 400 ] ],
	  "atl" : [ [ 24, 0.74 ], [ 25, 3.55 ], [ 26, 1.96 ], [ 29, 4.2 ], [ 900, 0.02 ] ],
	  "trd" : [ [ 5.3, 3.96 ], [ 5.1, 6.03 ] ],
	  "id" : 13531617
	}, ... ],
	"img" : true
  } ]
}
20:47:00.322 [main] INFO main - Initializing harness for runner 13531618
20:47:00.326 [main] INFO streaming.SubscriptionManager - {
  "op" : "ocm",
  "id" : 2,
  "initialClk" : "VeLnh9sEsAa1t/neBHeqxJ3aBG7YuYDbBNYGuqHD1AQ=",
  "clk" : "AAAAAAAAAAAAAA==",
  "conflateMs" : 0,
  "heartbeatMs" : 5000,
  "pt" : 1505335620130,
  "ct" : "SUB_IMAGE"
}
20:47:00.341 [main] INFO strategy.StrategyHarness - Exposures (GBX): Back 0, Lay 0, cash 0
20:47:00.342 [main] INFO strategy.StrategyHarness - Net exposure: 0
20:47:00.343 [main] INFO strategy.CAFStrategyV2 - Net exposure 0, fraction of offer: 0.0
20:47:00.343 [main] INFO strategy.CAFStrategyV2 - Best back: (Odds(3.45),198), Best lay: (Odds(6.6),472)
20:47:00.344 [main] INFO strategy.CAFStrategyV2 - Order book imbalance: -0.408955223880597
20:47:00.351 [main] INFO strategy.StrategyHarness - Strategy wants atb, atl (Map(Odds(3.3) -> 454, Odds(3.25) -> 461),Map(Odds(7.2) -> 208, Odds(7.4) -> 202)), current outstanding orders are back, lay (Map(),Map())
20:47:00.952 [main] INFO streaming.SubscriptionManager - {
  "op" : "mcm",
  "id" : 1,
  "clk" : "ADQAFQAI",
  "pt" : 1505335620944,
  "mc" : [ {
	"id" : "1.134156568",
	"rc" : [ {
	  "atl" : [ [ 990, 0 ] ],
	  "id" : 13531618
	} ]
  } ]
}
20:47:00.955 [main] INFO strategy.StrategyHarness - Exposures (GBX): Back 0, Lay 0, cash 0
20:47:00.955 [main] INFO strategy.StrategyHarness - Net exposure: 0
20:47:00.955 [main] INFO strategy.CAFStrategyV2 - Net exposure 0, fraction of offer: 0.0
20:47:00.955 [main] INFO strategy.CAFStrategyV2 - Best back: (Odds(3.45),198), Best lay: (Odds(6.6),472)
20:47:00.956 [main] INFO strategy.CAFStrategyV2 - Order book imbalance: -0.408955223880597
20:47:00.956 [main] INFO strategy.StrategyHarness - Strategy wants atb, atl (Map(Odds(3.3) -> 454, Odds(3.25) -> 461),Map(Odds(7.2) -> 208, Odds(7.4) -> 202)),...

Essentially, at the start the bot subscribes to the data stream for a given market and its own order status stream. At 20:47:00.207 it receives the first message from the market data stream: the initial order book image for all runners in that market.

Before subscribing to the streams, though, the bot also gets the market metadata to find out when the race actually begins. If it receives a message and it's timestamped less than 5 minutes away from the race start, it starts market making (well, pretending to, since at that point I hadn't implemented bet placement) on the favourite at that time by polling the strategy core and just returning the bets it wants to maintain on both sides of the order book.

Every time there's an update on the market book stream, the strategy is polled again to make sure it still wants the same bets to be maintained. If there's a change, then the harness performs cancellations/placements as needed.

Bet placement: order and book stream synchronization

The first problem I noticed when trying to implement bet placement was that the order book, order status streams and the API-NG aren't synchronized. In essence, if a bet is placed via API-NG, it takes a while for it to appear on the order status stream (showing whether or not it has been executed) or be reflected in the market order book. Since the core of the bot is supposed to be stateless, this could have caused this sort of an issue:

  • the core wants to offer £2 to back at 2.00
  • the data on the order status stream implies we don't have any outstanding bets
  • hence a bet of £2 at 2.00 is submitted via a REST call (that returns a successful response containing the bet ID and some other metadata
  • a new update to the order status stream arrives that doesn't yet contain the new bet
  • the core is polled again, it still wants to offer £2 at 2.00
  • since we haven't seen our bet on the status stream, we submit another bet
  • we now have 2 unmatched bets

This could get ugly quickly and there were several ways to solve it. One could be applying the bet that had just been submitted to a local copy of the order status stream and then ignoring the real Betfair message containing that bet when it does appear on the stream, but that would mean needing to reconcile our local cache with the Betfair stream: what if the bet doesn't appear or turns out to have been invalidated? I went with a simpler approach: get the bet ID returned by the REST API when a bet is placed and then stop polling the bot and placing bets until a bet with that ID is seen on the order status stream, since only then the bot would be in a consistent state.

The resultant timings are not HFT-like at all. From looking at the logs, a normal sequence is something like:

  • T: executor submits a bet (HTTP REST request)
  • T+120ms: receive a REST response with the bet ID
  • T+190ms: timestamp of the bet according to Betfair
  • T+200ms: bet appears on the order status stream (timestamped 10ms ago)

This could be partially mitigated by doing order submissions in a separate thread (in essence applying the order to our outstanding orders cache even before we receive a message from Betfair with its bet ID) but there would still be the issue of Betfair apparently taking about 190ms to put the bet into its order book. And I didn't want to bother for now, since I just wanted to get the bot into a shape where it could place live bets.

Live trading!

I was now ready to unleash the bot onto some real markets. I chose greyhound racing and, for safety, decided to do a test with making a market several ticks away from the current best lay/back, the reasoning being that while it would test the whole system end-to-end (in terms of maintaining outstanding orders), these bets would have little chance of getting matched and even if they did, it would be far enough from the current market for me to have time to quickly liquidate them manually and not lose money.

Attempt 0

Well, before that it had some very embarrassing false starts. Remember how I operated with penny amounts throughout the codebase to avoid floating point rounding errors? I completely forgot to change pennies to pounds again when submitting the bets, which meant that instead of a £2 bet I tried to submit a £200 bet. Luckily, I didn't have that much in my account so I just got lots of INSUFFICIENT_FUNDS errors.

Speaking of funding the account, Betfair doesn't do margin calls and requires all bets to be fully funded: so say for a lay of £2 at 1.5 you need to have at least (1.5 * £2) - £2 = £1 and for a back of £2 at 1.5 you need to have £2. Backs and lays can be offset against each other: so if we've backed a runner for £2 and now have £0 available to bet, we can still "green up" by placing a lay (as long as it doesn't make us short the runner).

For unmatched bets, it gets slightly more weird: if there's both an unmatched back and a lay in the order book, the amount available to bet is reduced by the maximum of the liabilities of the two: since either one of them can be matched, Betfair takes the worst-case scenario.

Attempt 1

So I started the bot in actual live mode, with real money (it would place 15 contracts on both sides, resulting in bets of about £5 at odds 3.0) and, well, the placement actually worked! On the Betfair website I saw several unmatched bets attributed to me which would change as the market moved.

20:47:01.059 [main] INFO strategy.StrategyHarness - Exposures (GBX): Back 0, Lay 0, cash 0
20:47:01.059 [main] INFO strategy.StrategyHarness - Net exposure: 0
20:47:01.059 [main] INFO strategy.CAFStrategyV2 - Net exposure 0, fraction of offer: 0.0
20:47:01.060 [main] INFO strategy.CAFStrategyV2 - Best back: (Odds(3.45),198), Best lay: (Odds(6.4),170)
20:47:01.060 [main] INFO strategy.CAFStrategyV2 - Order book imbalance: 0.07608695652173914
20:47:01.061 [main] INFO strategy.StrategyHarness - Strategy wants atb, atl (Map(Odds(3.3) -> 454, Odds(3.25) -> 461),Map(Odds(7.0) -> 214, Odds(7.2) -> 208)), current outstanding orders are back, lay (Map(Odds(7.4) -> 202, Odds(7.2) -> 208),Map(Odds(3.25) -> 461, Odds(3.3) -> 454))
20:47:01.068 [main] INFO execution.ExecutionUtils - Trying to submit 1 placements and 1 cancellations
20:47:01.069 [main] INFO execution.ExecutionUtils - Available to bet according to us: 97919
20:47:01.073 [main] INFO execution.ExecutionUtils - Submitting cancellations: {"marketId":"1.134156568","instructions":[{"betId":102464716465,"sizeReduction":null}]}
20:47:01.191 [main] INFO execution.ExecutionUtils - Result: 200
20:47:01.192 [main] INFO execution.ExecutionUtils - {
  "status" : "SUCCESS",
  "marketId" : "1.134156568",
  "instructionReports" : [ {
	"status" : "SUCCESS",
	"instruction" : {
	  "betId" : "102464716465"
	},
	"sizeCancelled" : 2.02,
	"cancelledDate" : "2017-09-13T20:47:01.000Z"
  } ]
}
20:47:01.192 [main] INFO execution.ExecutionUtils - Submitting placements: {"marketId":"1.134156568","instructions":[{"orderType":"LIMIT","selectionId":13531618,"side":"BACK","limitOrder":{"size":2.14,"price":7,"persistenceType":"LAPSE"}}]}
20:47:01.308 [main] INFO execution.ExecutionUtils - Result: 200
20:47:01.309 [main] INFO execution.ExecutionUtils - {
  "status" : "SUCCESS",
  "marketId" : "1.134156568",
  "instructionReports" : [ {
	"status" : "SUCCESS",
	"instruction" : {
	  "selectionId" : 13531618,
	  "limitOrder" : {
		"size" : 2.14,
		"price" : 7,
		"persistenceType" : "LAPSE"
	  },
	  "orderType" : "LIMIT",
	  "side" : "BACK"
	},
	"betId" : "102464717112",
	"placedDate" : "2017-09-13T20:47:01.000Z",
	"averagePriceMatched" : 0,
	"sizeMatched" : 0,
	"orderStatus" : "EXECUTABLE"
  } ]
}
20:47:01.310 [main] INFO streaming.SubscriptionManager - {
  "op" : "mcm",
  "id" : 1,
  "clk" : "AEUAIgAR",
  "pt" : 1505335621264,
  "mc" : [ {
	"id" : "1.134156568",
	"rc" : [ {
	  "atl" : [ [ 7.4, 0 ] ],
	  "id" : 13531618
	} ]
  } ]
}
20:47:01.311 [main] INFO main - Some bet IDs unseen by the order status cache, not doing anything...
20:47:01.313 [main] INFO streaming.SubscriptionManager - {
  "op" : "ocm",
  "id" : 2,
  "clk" : "ACEAFgAJABgACw==",
  "pt" : 1505335621269,
  "oc" : [ {
	"id" : "1.134156568",
	"orc" : [ {
	  "id" : 13531618,
	  "uo" : [ {
		"id" : "102464716465",
		"p" : 7.4,
		"s" : 2.02,
		"side" : "B",
		"status" : "EC",
		"pt" : "L",
		"ot" : "L",
		"pd" : 1505335620000,
		"sm" : 0,
		"sr" : 0,
		"sl" : 0,
		"sc" : 2.02,
		"sv" : 0,
		"rac" : "",
		"rc" : "REG_GGC",
		"rfo" : "",
		"rfs" : ""
	  } ]
	} ]
  } ]
}
20:47:01.314 [main] INFO main - Some bet IDs unseen by the order status cache, not doing anything...
20:47:01.376 [main] INFO streaming.SubscriptionManager - {
  "op" : "mcm",
  "id" : 1,
  "clk" : "AEsAIwAR",
  "pt" : 1505335621369,
  "mc" : [ {
	"id" : "1.134156568",
	"rc" : [ {
	  "atl" : [ [ 7, 2.14 ] ],
	  "id" : 13531618
	} ]
  } ]
}
20:47:01.378 [main] INFO main - Some bet IDs unseen by the order status cache, not doing anything...
20:47:01.380 [main] INFO streaming.SubscriptionManager - {
  "op" : "ocm",
  "id" : 2,
  "clk" : "ACMAFwALABoADA==",
  "pt" : 1505335621372,
  "oc" : [ {
	"id" : "1.134156568",
	"orc" : [ {
	  "id" : 13531618,
	  "uo" : [ {
		"id" : "102464717112",
		"p" : 7,
		"s" : 2.14,
		"side" : "B",
		"status" : "E",
		"pt" : "L",
		"ot" : "L",
		"pd" : 1505335621000,
		"sm" : 0,
		"sr" : 2.14,
		"sl" : 0,
		"sc" : 0,
		"sv" : 0,
		"rac" : "",
		"rc" : "REG_GGC",
		"rfo" : "",
		"rfs" : ""
	  } ]
	} ]
  } ]
}
20:47:01.382 [main] INFO strategy.StrategyHarness - Exposures (GBX): Back 0, Lay 0, cash 0
20:47:01.382 [main] INFO strategy.StrategyHarness - Net exposure: 0
20:47:01.382 [main] INFO strategy.CAFStrategyV2 - Net exposure 0, fraction of offer: 0.0

So as intended:

  • the market moved to 3.45 / 6.40 best back/lay
  • the bot had backs at 7.4 and 7.2 and lays at 3.25 and 3.3, but wanted backs at 7.2 and 7.0
  • so it cancelled the back at 7.4 and then placed one at 7.0...
  • ...and then waited until the cancelled bet and the new bet appeared on the order status stream (20:47:01.313 and 20:47:01.380, respectively) before proceeding.

And indeed, the bot managed to maintain its bets far enough from the action in order to not get matched.

I ran it again, on a different market:

20:54:19.217 [main] INFO strategy.CAFStrategyV2 - Best back: (Odds(3.15),3474), Best lay: (Odds(3.2),18713)
20:54:19.217 [main] INFO strategy.CAFStrategyV2 - Order book imbalance: -0.6868436471807815
20:54:19.218 [main] INFO strategy.StrategyHarness - Strategy wants atb, atl (Map(Odds(2.98) -> 503, Odds(2.96) -> 506),Map(Odds(3.35) -> 447, Odds(3.4) -> 441)), current outstanding orders are back, lay (Map(Odds(3.6) -> 416, Odds(3.65) -> 409),Map(Odds(3.25) -> 461, Odds(3.2) -> 468))
20:54:19.219 [main] INFO execution.ExecutionUtils - Trying to submit 4 placements and 4 cancellations
20:54:19.219 [main] INFO execution.ExecutionUtils - Available to bet according to us: 97934
20:54:19.220 [main] INFO execution.ExecutionUtils - Submitting cancellations: {"marketId":"1.134151928","instructions":[{"betId":102464926664,"sizeReduction":null},{"betId":102464926665,"sizeReduction":null},{"betId":102464926548,"sizeReduction":null},{"betId":102464926666,"sizeReduction":null}]}
20:54:19.324 [main] INFO execution.ExecutionUtils - Result: 200
20:54:19.324 [main] INFO execution.ExecutionUtils - {
  "status" : "PROCESSED_WITH_ERRORS",
  "errorCode" : "PROCESSED_WITH_ERRORS",
  "marketId" : "1.134151928",
  "instructionReports" : [ {
	"status" : "SUCCESS",
	"instruction" : {
	  "betId" : "102464926664"
	},
	"sizeCancelled" : 4.16,
	"cancelledDate" : "2017-09-13T20:54:19.000Z"
  }, {
	"status" : "SUCCESS",
	"instruction" : {
	  "betId" : "102464926665"
	},
	"sizeCancelled" : 4.1,
	"cancelledDate" : "2017-09-13T20:54:19.000Z"
  }, {
	"status" : "FAILURE",
	"errorCode" : "BET_TAKEN_OR_LAPSED",
	"instruction" : {
	  "betId" : "102464926548"
	}
  }, {
	"status" : "FAILURE",
	"errorCode" : "BET_TAKEN_OR_LAPSED",
	"instruction" : {
	  "betId" : "102464926666"
	}
  } ]
}
20:54:19.325 [main] ERROR execution.ExecutionUtils - Cancellation unsuccessful. Aborting.
20:54:19.325 [main] ERROR main - Execution failure.

Oh boy. I quickly alt-tabbed to the Betfair web interface, and yep, I had an outstanding bet that had been matched and wasn't closed. I managed to close my position manually (by submitting some offsetting bets on the other side) and in fact managed to make about £1 from the trade, but what on earth happened here?

Looking at the logs, it seems like the bot wanted to move its bets once again: the market suddenly dropped from best back/lay 3.4/3.45 down to 3.15/3.2, whereas the bot had bets at 3.2, 3.25/3.6, 3.65. So the bot needed to cancel all 4 of its outstanding bets and move them down as well.

But wait: how come the best back was at 3.15 and the bot had a lay bet (meaning that bet was available to back) at 3.2? Why wasn't an offer to back at higher odds (3.2 vs 3.15) at the top of the book instead?

In fact, those two bets had been matched and that hadn't yet been reflected on the order status feed. So when the bot tried to cancel all of its bets, two cancellations failed because the bets had already been matched. The odds soon recovered back and I managed to submit a back bet at higher odds than the bot had laid (which ended up in a profit), but the order status and the order book stream being desynchronized was a bigger problem.

I decided to just ignore errors where cancellations were failing: eventually the bot would receive an update saying that the bet got matched and would stop trying to cancel it.

Attempt 2

How did we get here?

10:08:52.623 [main] INFO strategy.StrategyHarness - Exposures (GBX): Back 4599, Lay 0, cash -1501
10:08:52.623 [main] INFO strategy.StrategyHarness - Net exposure: 4599
10:08:52.623 [main] INFO strategy.CAFStrategyV2 - Net exposure 4599, fraction of offer: 3.066
10:08:52.623 [main] INFO strategy.CAFStrategyV2 - Best back: (Odds(2.74),1000), Best lay: (Odds(2.8),1021)
10:08:52.623 [main] INFO strategy.CAFStrategyV2 - Order book imbalance: -0.010390895596239486
10:08:52.624 [main] INFO strategy.StrategyHarness - Strategy wants atb, atl (Map(Odds(2.68) -> 559, Odds(2.66) -> 563),Map(Odds(2.88) -> 520, Odds(2.9) -> 517)), current outstanding orders are back, lay (Map(),Map(Odds(2.66) -> 563, Odds(2.68) -> 559))
10:08:52.624 [main] INFO execution.ExecutionUtils - Trying to submit 2 placements and 0 cancellations
10:08:52.624 [main] INFO execution.ExecutionUtils - Available to bet according to us: 96626
10:08:52.624 [main] INFO execution.ExecutionUtils - Submitting placements: {"marketId":"1.134190324","instructions":[{"orderType":"LIMIT","selectionId":12743977,"side":"BACK","limitOrder":{"size":5.2,"price":2.88,"persistenceType":"LAPSE"}},{"orderType":"LIMIT","selectionId":12743977,"side":"BACK","limitOrder":{"size":5.17,"price":2.9,"persistenceType":"LAPSE"}}]}
10:08:52.769 [main] INFO execution.ExecutionUtils - Result: 200
10:08:52.769 [main] INFO execution.ExecutionUtils - {
  "status" : "SUCCESS",
  "marketId" : "1.134190324",
  "instructionReports" : [ {
	"status" : "SUCCESS",
	"instruction" : {
	  "selectionId" : 12743977,
	  "limitOrder" : {
		"size" : 5.2,
		"price" : 2.88,
		"persistenceType" : "LAPSE"
	  },
	  "orderType" : "LIMIT",
	  "side" : "BACK"
	},
	"betId" : "102489084350",
	"placedDate" : "2017-09-14T10:08:52.000Z",
	"averagePriceMatched" : 2.9,
	"sizeMatched" : 5.2,
	"orderStatus" : "EXECUTION_COMPLETE"
  }, {
	"status" : "SUCCESS",
	"instruction" : {
	  "selectionId" : 12743977,
	  "limitOrder" : {
		"size" : 5.17,
		"price" : 2.9,
		"persistenceType" : "LAPSE"
	  },
	  "orderType" : "LIMIT",
	  "side" : "BACK"
	},
	"betId" : "102489084351",
	"placedDate" : "2017-09-14T10:08:52.000Z",
	"averagePriceMatched" : 2.9,
	"sizeMatched" : 5.17,
	"orderStatus" : "EXECUTION_COMPLETE"
  } ]
}
...
10:08:52.789 [main] INFO strategy.StrategyHarness - Exposures (GBX): Back 7606, Lay 0, cash -2538
10:08:52.789 [main] INFO strategy.StrategyHarness - Net exposure: 7606
10:08:52.789 [main] INFO strategy.StrategyHarness - Max exposure reached, liquidating
10:08:52.789 [main] INFO strategy.StrategyHarness - Strategy wants atb, atl (Map(Odds(2.96) -> 7606),Map()), current outstanding orders are back, lay (Map(),Map(Odds(2.66) -> 563, Odds(2.68) -> 559))
10:08:52.790 [main] INFO execution.ExecutionUtils - Trying to submit 1 placements and 2 cancellations
10:08:52.790 [main] INFO execution.ExecutionUtils - Available to bet according to us: 95589
10:08:52.790 [main] INFO execution.ExecutionUtils - Submitting cancellations: {"marketId":"1.134190324","instructions":[{"betId":102489083069,"sizeReduction":null},{"betId":102489083236,"sizeReduction":null}]}
10:08:52.873 [main] INFO execution.ExecutionUtils - Result: 200
10:08:52.873 [main] INFO execution.ExecutionUtils - {
  "status" : "SUCCESS",
  "marketId" : "1.134190324",
  "instructionReports" : [ {
	"status" : "SUCCESS",
	"instruction" : {
	  "betId" : "102489083069"
	},
	"sizeCancelled" : 5.63,
	"cancelledDate" : "2017-09-14T10:08:52.000Z"
  }, {
	"status" : "SUCCESS",
	"instruction" : {
	  "betId" : "102489083236"
	},
	"sizeCancelled" : 5.59,
	"cancelledDate" : "2017-09-14T10:08:52.000Z"
  } ]
}
10:08:52.873 [main] INFO execution.ExecutionUtils - Submitting placements: {"marketId":"1.134190324","instructions":[{"orderType":"LIMIT","selectionId":12743977,"side":"LAY","limitOrder":{"size":76.06,"price":2.96,"persistenceType":"LAPSE"}}]}
10:08:52.895 [main] INFO execution.ExecutionUtils - Result: 200
10:08:52.895 [main] INFO execution.ExecutionUtils - {
  "status" : "FAILURE",
  "errorCode" : "INSUFFICIENT_FUNDS",
  "marketId" : "1.134190324",
  "instructionReports" : [ {
	"status" : "FAILURE",
	"errorCode" : "ERROR_IN_ORDER",
	"instruction" : {
	  "selectionId" : 12743977,
	  "limitOrder" : {
		"size" : 76.06,
		"price" : 2.96,
		"persistenceType" : "LAPSE"
	  },
	  "orderType" : "LIMIT",
	  "side" : "LAY"
	}
  } ]
}
10:08:52.895 [main] ERROR execution.ExecutionUtils - Placement unsuccessful. Aborting.

This led to another scramble with me frantically trying to close the position. In the end, I managed to make about £6 of profit from that market (accidentally going short just before it kicked off with that runner losing in the end).

As you'll find out later, this will be the most money that project Betfair will make.

So what happened here? First, the bot's back bets were being matched disproportionately often: at 10:08:52.623 it held 45.99 contracts. It was still below its maximum exposure level, so it placed a couple more back bets far away from the market at 10:08:52.769. Those immediately got matched (see "orderStatus" : "EXECUTION_COMPLETE" in the REST response), bringing the bot's exposure to above 75 contracts, so at 10:08:52.789 it decided to completely liquidate its position.

What happened next was dumb: instead of placing a lay bet of £76.06 / 2.96 (number of contracts divided by the odds), it placed a bet of £76.06. This would have made the bot have a massive short on the runner, but it didn't have enough money to do so, so instead Betfair came back with an INSUFFICIENT_FUNDS error.

Interestingly enough, if the bot did manage to close its position, it would have made money (but less): the Back 7606, Lay 0, cash -2538 part basically says it had paid £25.38 for 76.06 contracts, implying average odds of 3.00, so with a lower lay of 2.96 it would get £25.69 back, leaving it with a profit of £0.31.

Attempts 3, 4, 5...

After fixing those bugs I encountered a few more: for example, since the bot couldn't place orders below £2, it would sometimes end up with a small residual exposure at the end of trading which it couldn't get rid of. There were other issues, for example, the bot wasn't incorporating instant matches (as in when the bet placement REST request came back saying the bet had gotten immediately matched). After a couple more runs I managed to accidentally lose most of the £7 I had accidentally made and decided to stop there for now.

What I was also interested in was the fact that despite my assumptions, offers as far as 3 Betfair ticks away from the market would get matched. This was partially because the bot was slower than when I simulated it and partially because matching in greyhound markets indeed happened in jumps, but that gave me a different idea: what if I did actually simulate making a market further away from the best bid/offer?

And later on, I would come across a different and simpler idea that would mean market making would get put on hold.

Conclusion

Next time on project Betfair, we'll tinker with our simulation some more and then start looking at our data from a different perspective.

As usual, posts in this series will be available at https://kimonote.com/@mildbyte:betfair or on this RSS feed. Alternatively, follow me on twitter.com/mildbyte.

Interested in this blogging platform? It's called Kimonote, it focuses on minimalism, ease of navigation and control over what content a user follows. Try the demo here and/or follow it on Twitter as well at twitter.com/kimonote!