From 3d0247f944d7510943dfaa64eeb0e15a43b6c989 Mon Sep 17 00:00:00 2001 From: =?utf8?q?Isma=C3=ABl=20Bouya?= Date: Sat, 24 Feb 2018 19:53:58 +0100 Subject: [PATCH] Add report store to store messages and logs --- helper.py | 81 +++-- portfolio.py | 107 +++++-- store.py | 224 +++++++++++++- test.py | 850 ++++++++++++++++++++++++++++++++++++++++++--------- 4 files changed, 1041 insertions(+), 221 deletions(-) diff --git a/helper.py b/helper.py index 23b2d0b..87539f1 100644 --- a/helper.py +++ b/helper.py @@ -4,6 +4,8 @@ from store import * def move_balances(market, debug=False): needed_in_margin = {} + moving_to_margin = {} + for currency in BalanceStore.all: if BalanceStore.all[currency].margin_free != 0: needed_in_margin[currency] = 0 @@ -14,18 +16,16 @@ def move_balances(market, debug=False): needed_in_margin[trade.value_to.currency] += abs(trade.value_to) for currency, needed in needed_in_margin.items(): current_balance = BalanceStore.all[currency].margin_free - delta = (needed - current_balance).value - # FIXME: don't remove too much if there are open margin position + moving_to_margin[currency] = (needed - current_balance) + delta = moving_to_margin[currency].value + if debug: + ReportStore.log_debug_action("Moving {} from exchange to margin".format(moving_to_margin[currency])) + continue if delta > 0: - if debug: - print("market.transfer_balance({}, {}, 'exchange', 'margin')".format(currency, delta)) - else: - market.transfer_balance(currency, delta, "exchange", "margin") + market.transfer_balance(currency, delta, "exchange", "margin") elif delta < 0: - if debug: - print("market.transfer_balance({}, {}, 'margin', 'exchange')".format(currency, -delta)) - else: - market.transfer_balance(currency, -delta, "margin", "exchange") + market.transfer_balance(currency, -delta, "margin", "exchange") + ReportStore.log_move_balances(needed_in_margin, moving_to_margin, debug) BalanceStore.fetch_balances(market) @@ -73,6 +73,7 @@ def fetch_fees(market): return fees_cache[market.__class__] def prepare_trades(market, base_currency="BTC", liquidity="medium", compute_value="average", debug=False): + ReportStore.log_stage("prepare_trades") BalanceStore.fetch_balances(market) values_in_base = BalanceStore.in_currency(base_currency, market, compute_value=compute_value) total_base_value = sum(values_in_base.values()) @@ -82,6 +83,7 @@ def prepare_trades(market, base_currency="BTC", liquidity="medium", compute_valu TradeStore.compute_trades(values_in_base, new_repartition, market=market, debug=debug) def update_trades(market, base_currency="BTC", liquidity="medium", compute_value="average", only=None, debug=False): + ReportStore.log_stage("update_trades") BalanceStore.fetch_balances(market) values_in_base = BalanceStore.in_currency(base_currency, market, compute_value=compute_value) total_base_value = sum(values_in_base.values()) @@ -89,91 +91,76 @@ def update_trades(market, base_currency="BTC", liquidity="medium", compute_value TradeStore.compute_trades(values_in_base, new_repartition, only=only, market=market, debug=debug) def prepare_trades_to_sell_all(market, base_currency="BTC", compute_value="average", debug=False): + ReportStore.log_stage("prepare_trades_to_sell_all") BalanceStore.fetch_balances(market) values_in_base = BalanceStore.in_currency(base_currency, market, compute_value=compute_value) total_base_value = sum(values_in_base.values()) new_repartition = BalanceStore.dispatch_assets(total_base_value, repartition={ base_currency: (1, "long") }) TradeStore.compute_trades(values_in_base, new_repartition, market=market, debug=debug) -def follow_orders(verbose=True, sleep=None): +def follow_orders(sleep=None): if sleep is None: sleep = 7 if TradeStore.debug else 30 + if TradeStore.debug: + ReportStore.log_debug_action("Set follow_orders tick to {}s".format(sleep)) tick = 0 + ReportStore.log_stage("follow_orders_begin") while len(TradeStore.all_orders(state="open")) > 0: time.sleep(sleep) tick += 1 - for order in TradeStore.all_orders(state="open"): + open_orders = TradeStore.all_orders(state="open") + ReportStore.log_stage("follow_orders_tick_{}".format(tick)) + ReportStore.log_orders(open_orders, tick=tick) + for order in open_orders: if order.get_status() != "open": - if verbose: - print("finished {}".format(order)) + ReportStore.log_order(order, tick, finished=True) else: order.trade.update_order(order, tick) - if verbose: - print("All orders finished") + ReportStore.log_stage("follow_orders_end") def print_orders(market, base_currency="BTC"): + ReportStore.log_stage("print_orders") prepare_trades(market, base_currency=base_currency, compute_value="average", debug=True) TradeStore.prepare_orders(compute_value="average") - for currency, balance in BalanceStore.all.items(): - print(balance) - TradeStore.print_all_with_order() def print_balances(market, base_currency="BTC"): BalanceStore.fetch_balances(market) - for currency, balance in BalanceStore.all.items(): - print(balance) if base_currency is not None: - print("total:") - print(sum(BalanceStore.in_currency(base_currency, market).values())) + ReportStore.print_log("total:") + ReportStore.print_log(sum(BalanceStore.in_currency(base_currency, market).values())) def process_sell_needed__1_sell(market, liquidity="medium", base_currency="BTC", debug=False): + ReportStore.log_stage("process_sell_needed__1_sell_begin") prepare_trades(market, liquidity=liquidity, base_currency=base_currency, debug=debug) TradeStore.prepare_orders(compute_value="average", only="dispose") - print("------------------") - for currency, balance in BalanceStore.all.items(): - print(balance) - print("------------------") - TradeStore.print_all_with_order() - print("------------------") TradeStore.run_orders() follow_orders() + ReportStore.log_stage("process_sell_needed__1_sell_end") def process_sell_needed__2_buy(market, liquidity="medium", base_currency="BTC", debug=False): + ReportStore.log_stage("process_sell_needed__2_buy_begin") update_trades(market, base_currency=base_currency, liquidity=liquidity, debug=debug, only="acquire") TradeStore.prepare_orders(compute_value="average", only="acquire") - print("------------------") - for currency, balance in BalanceStore.all.items(): - print(balance) - print("------------------") - TradeStore.print_all_with_order() - print("------------------") move_balances(market, debug=debug) TradeStore.run_orders() follow_orders() + ReportStore.log_stage("process_sell_needed__2_buy_end") def process_sell_all__1_all_sell(market, base_currency="BTC", debug=False, liquidity="medium"): + ReportStore.log_stage("process_sell_all__1_all_sell_begin") prepare_trades_to_sell_all(market, base_currency=base_currency, debug=debug) TradeStore.prepare_orders(compute_value="average") - print("------------------") - for currency, balance in BalanceStore.all.items(): - print(balance) - print("------------------") - TradeStore.print_all_with_order() - print("------------------") TradeStore.run_orders() follow_orders() + ReportStore.log_stage("process_sell_all__1_all_sell_end") def process_sell_all__2_all_buy(market, base_currency="BTC", debug=False, liquidity="medium"): + ReportStore.log_stage("process_sell_all__2_all_buy_begin") prepare_trades(market, liquidity=liquidity, base_currency=base_currency, debug=debug) TradeStore.prepare_orders(compute_value="average") - print("------------------") - for currency, balance in BalanceStore.all.items(): - print(balance) - print("------------------") - TradeStore.print_all_with_order() - print("------------------") move_balances(market, debug=debug) TradeStore.run_orders() follow_orders() + ReportStore.log_stage("process_sell_all__2_all_buy_end") diff --git a/portfolio.py b/portfolio.py index c3809f0..f9423b9 100644 --- a/portfolio.py +++ b/portfolio.py @@ -3,6 +3,7 @@ from datetime import datetime, timedelta from decimal import Decimal as D, ROUND_DOWN # Put your poloniex api key in market.py from json import JSONDecodeError +from simplejson.errors import JSONDecodeError as SimpleJSONDecodeError from ccxt import ExchangeError, ExchangeNotAvailable import requests import helper as h @@ -33,11 +34,14 @@ class Portfolio: def get_cryptoportfolio(cls): try: r = requests.get(cls.URL) - except Exception: + ReportStore.log_http_request(r.request.method, + r.request.url, r.request.body, r.request.headers, r) + except Exception as e: + ReportStore.log_error("get_cryptoportfolio", exception=e) return try: cls.data = r.json(parse_int=D, parse_float=D) - except JSONDecodeError: + except (JSONDecodeError, SimpleJSONDecodeError): cls.data = None @classmethod @@ -126,6 +130,12 @@ class Amount: else: raise Exception("This asset is not available in the chosen market") + def as_json(self): + return { + "currency": self.currency, + "value": round(self).value.normalize(), + } + def __round__(self, n=8): return Amount(self.currency, self.value.quantize(D(1)/D(10**n), rounding=ROUND_DOWN)) @@ -216,12 +226,13 @@ class Amount: return "Amount({:.8f} {} -> {})".format(self.value, self.currency, repr(self.linked_to)) class Balance: + base_keys = ["total", "exchange_total", "exchange_used", + "exchange_free", "margin_total", "margin_borrowed", + "margin_free"] def __init__(self, currency, hash_): self.currency = currency - for key in ["total", - "exchange_total", "exchange_used", "exchange_free", - "margin_total", "margin_borrowed", "margin_free"]: + for key in self.base_keys: setattr(self, key, Amount(currency, hash_.get(key, 0))) self.margin_position_type = hash_.get("margin_position_type") @@ -236,6 +247,9 @@ class Balance: ]: setattr(self, key, Amount(base_currency, hash_.get(key, 0))) + def as_json(self): + return dict(map(lambda x: (x, getattr(self, x).as_json()["value"]), self.base_keys)) + def __repr__(self): if self.exchange_total > 0: if self.exchange_free > 0 and self.exchange_used > 0: @@ -318,23 +332,34 @@ class Trade: def update_order(self, order, tick): new_order = None if tick in [0, 1, 3, 4, 6]: - print("{}, tick {}, waiting".format(order, tick)) + update = "waiting" + compute_value = None elif tick == 2: + update = "adjusting" + compute_value = 'lambda x, y: (x[y] + x["average"]) / 2' new_order = self.prepare_order(compute_value=lambda x, y: (x[y] + x["average"]) / 2) - print("{}, tick {}, cancelling and adjusting to {}".format(order, tick, new_order)) elif tick ==5: + update = "adjusting" + compute_value = 'lambda x, y: (x[y]*2 + x["average"]) / 3' new_order = self.prepare_order(compute_value=lambda x, y: (x[y]*2 + x["average"]) / 3) - print("{}, tick {}, cancelling and adjusting to {}".format(order, tick, new_order)) elif tick >= 7: - if tick == 7: - print("{}, tick {}, fallbacking to market value".format(order, tick)) if (tick - 7) % 3 == 0: new_order = self.prepare_order(compute_value="default") - print("{}, tick {}, market value, cancelling and adjusting to {}".format(order, tick, new_order)) + update = "market_adjust" + compute_value = "default" + else: + update = "waiting" + compute_value = None + if tick == 7: + update = "market_fallback" + + ReportStore.log_order(order, tick, update=update, + compute_value=compute_value, new_order=new_order) if new_order is not None: order.cancel() new_order.run() + ReportStore.log_order(order, tick, new_order=new_order) def prepare_order(self, compute_value="default"): if self.action is None: @@ -405,7 +430,7 @@ class Trade: close_if_possible = (self.value_to == 0) if delta <= 0: - print("Less to do than already filled: {}".format(delta)) + ReportStore.log_error("prepare_order", message="Less to do than already filled: {}".format(delta)) return None order = Order(self.order_action(inverted), @@ -414,6 +439,15 @@ class Trade: self.orders.append(order) return order + def as_json(self): + return { + "action": self.action, + "from": self.value_from.as_json()["value"], + "to": self.value_to.as_json()["value"], + "currency": self.currency, + "base_currency": self.base_currency, + } + def __repr__(self): return "Trade({} -> {} in {}, {})".format( self.value_from, @@ -421,12 +455,12 @@ class Trade: self.currency, self.action) - def print_with_order(self): - print(self) + def print_with_order(self, ind=""): + ReportStore.print_log("{}{}".format(ind, self)) for order in self.orders: - print("\t", order, sep="") + ReportStore.print_log("{}\t{}".format(ind, order)) for mouvement in order.mouvements: - print("\t\t", mouvement, sep="") + ReportStore.print_log("{}\t\t{}".format(ind, mouvement)) class Order: def __init__(self, action, amount, rate, base_currency, trade_type, market, @@ -445,6 +479,20 @@ class Order: self.id = None self.fetch_cache_timestamp = None + def as_json(self): + return { + "action": self.action, + "trade_type": self.trade_type, + "amount": self.amount.as_json()["value"], + "currency": self.amount.as_json()["currency"], + "base_currency": self.base_currency, + "rate": self.rate, + "status": self.status, + "close_if_possible": self.close_if_possible, + "id": self.id, + "mouvements": list(map(lambda x: x.as_json(), self.mouvements)) + } + def __repr__(self): return "Order({} {} {} at {} {} [{}]{})".format( self.action, @@ -480,7 +528,7 @@ class Order: amount = round(self.amount, self.market.order_precision(symbol)).value if TradeStore.debug: - print("market.create_order('{}', 'limit', '{}', {}, price={}, account={})".format( + ReportStore.log_debug_action("market.create_order('{}', 'limit', '{}', {}, price={}, account={})".format( symbol, self.action, amount, self.rate, self.account)) self.results.append({"debug": True, "id": -1}) else: @@ -493,16 +541,15 @@ class Order: return except Exception as e: self.status = "error" - print("error when running market.create_order('{}', 'limit', '{}', {}, price={}, account={})".format( - symbol, self.action, amount, self.rate, self.account)) - self.error_message = str("{}: {}".format(e.__class__.__name__, e)) - print(self.error_message) + action = "market.create_order('{}', 'limit', '{}', {}, price={}, account={})".format(symbol, self.action, amount, self.rate, self.account) + ReportStore.log_error(action, exception=e) return self.id = self.results[0]["id"] self.status = "open" def get_status(self): if TradeStore.debug: + ReportStore.log_debug_action("Getting {} status".format(self)) return self.status # other states are "closed" and "canceled" if not self.finished: @@ -513,13 +560,17 @@ class Order: def mark_finished_order(self): if TradeStore.debug: + ReportStore.log_debug_action("Mark {} as finished".format(self)) return if self.status == "closed": if self.trade_type == "short" and self.action == "buy" and self.close_if_possible: self.market.close_margin_position(self.amount.currency, self.base_currency) def fetch(self, force=False): - if TradeStore.debug or (not force and self.fetch_cache_timestamp is not None + if TradeStore.debug: + ReportStore.log_debug_action("Fetching {}".format(self)) + return + if (not force and self.fetch_cache_timestamp is not None and time.time() - self.fetch_cache_timestamp < 10): return self.fetch_cache_timestamp = time.time() @@ -566,6 +617,7 @@ class Order: def cancel(self): if TradeStore.debug: + ReportStore.log_debug_action("Mark {} as cancelled".format(self)) self.status = "canceled" return self.market.cancel_order(self.id) @@ -587,6 +639,17 @@ class Mouvement: # rate * total = total_in_base self.total_in_base = Amount(base_currency, hash_.get("total", 0)) + def as_json(self): + return { + "fee_rate": self.fee_rate, + "date": self.date, + "action": self.action, + "total": self.total.value, + "currency": self.currency, + "total_in_base": self.total_in_base.value, + "base_currency": self.base_currency + } + def __repr__(self): if self.fee_rate > 0: fee_rate = " fee: {}%".format(self.fee_rate * 100) diff --git a/store.py b/store.py index abbe5ee..dfadef2 100644 --- a/store.py +++ b/store.py @@ -1,6 +1,181 @@ import portfolio +import simplejson as json +from decimal import Decimal as D, ROUND_DOWN +from datetime import date, datetime -__all__ = ["BalanceStore", "TradeStore"] +__all__ = ["BalanceStore", "ReportStore", "TradeStore"] + +class ReportStore: + logs = [] + verbose_print = True + + @classmethod + def print_log(cls, message): + message = str(message) + if cls.verbose_print: + print(message) + + @classmethod + def add_log(cls, hash_): + hash_["date"] = datetime.now() + cls.logs.append(hash_) + + @classmethod + def to_json(cls): + def default_json_serial(obj): + if isinstance(obj, (datetime, date)): + return obj.isoformat() + raise TypeError ("Type %s not serializable" % type(obj)) + return json.dumps(cls.logs, default=default_json_serial) + + @classmethod + def set_verbose(cls, verbose_print): + cls.verbose_print = verbose_print + + @classmethod + def log_stage(cls, stage): + cls.print_log("-" * (len(stage) + 8)) + cls.print_log("[Stage] {}".format(stage)) + + cls.add_log({ + "type": "stage", + "stage": stage, + }) + + @classmethod + def log_balances(cls, market): + cls.print_log("[Balance]") + for currency, balance in BalanceStore.all.items(): + cls.print_log("\t{}".format(balance)) + + cls.add_log({ + "type": "balance", + "balances": BalanceStore.as_json() + }) + + @classmethod + def log_tickers(cls, market, amounts, other_currency, + compute_value, type): + values = {} + rates = {} + for currency, amount in amounts.items(): + values[currency] = amount.as_json()["value"] + rates[currency] = amount.rate + cls.add_log({ + "type": "tickers", + "compute_value": compute_value, + "balance_type": type, + "currency": other_currency, + "balances": values, + "rates": rates, + "total": sum(amounts.values()).as_json()["value"] + }) + + @classmethod + def log_dispatch(cls, amount, amounts, liquidity, repartition): + cls.add_log({ + "type": "dispatch", + "liquidity": liquidity, + "repartition_ratio": repartition, + "total_amount": amount.as_json(), + "repartition": { k: v.as_json()["value"] for k, v in amounts.items() } + }) + + @classmethod + def log_trades(cls, matching_and_trades, only, debug): + trades = [] + for matching, trade in matching_and_trades: + trade_json = trade.as_json() + trade_json["skipped"] = not matching + trades.append(trade_json) + + cls.add_log({ + "type": "trades", + "only": only, + "debug": debug, + "trades": trades + }) + + @classmethod + def log_orders(cls, orders, tick=None, only=None, compute_value=None): + cls.print_log("[Orders]") + TradeStore.print_all_with_order(ind="\t") + cls.add_log({ + "type": "orders", + "only": only, + "compute_value": compute_value, + "tick": tick, + "orders": [order.as_json() for order in orders if order is not None] + }) + + @classmethod + def log_order(cls, order, tick, finished=False, update=None, + new_order=None, compute_value=None): + if finished: + cls.print_log("[Order] Finished {}".format(order)) + elif update == "waiting": + cls.print_log("[Order] {}, tick {}, waiting".format(order, tick)) + elif update == "adjusting": + cls.print_log("[Order] {}, tick {}, cancelling and adjusting to {}".format(order, tick, new_order)) + elif update == "market_fallback": + cls.print_log("[Order] {}, tick {}, fallbacking to market value".format(order, tick)) + elif update == "market_adjust": + cls.print_log("[Order] {}, tick {}, market value, cancelling and adjusting to {}".format(order, tick, new_order)) + + cls.add_log({ + "type": "order", + "tick": tick, + "update": update, + "order": order.as_json(), + "compute_value": compute_value, + "new_order": new_order.as_json() if new_order is not None else None + }) + + @classmethod + def log_move_balances(cls, needed, moving, debug): + cls.add_log({ + "type": "move_balances", + "debug": debug, + "needed": { k: v.as_json()["value"] if isinstance(v, portfolio.Amount) else v for k, v in needed.items() }, + "moving": { k: v.as_json()["value"] if isinstance(v, portfolio.Amount) else v for k, v in moving.items() }, + }) + + @classmethod + def log_http_request(cls, method, url, body, headers, response): + cls.add_log({ + "type": "http_request", + "method": method, + "url": url, + "body": body, + "headers": headers, + "status": response.status_code, + "response": response.text + }) + + @classmethod + def log_error(cls, action, message=None, exception=None): + cls.print_log("[Error] {}".format(action)) + if exception is not None: + cls.print_log(str("\t{}: {}".format(exception.__class__.__name__, exception))) + if message is not None: + cls.print_log("\t{}".format(message)) + + cls.add_log({ + "type": "error", + "action": action, + "exception_class": exception.__class__.__name__ if exception is not None else None, + "exception_message": str(exception) if exception is not None else None, + "message": message, + }) + + @classmethod + def log_debug_action(cls, action): + cls.print_log("[Debug] {}".format(action)) + + cls.add_log({ + "type": "debug_action", + "action": action, + }) class BalanceStore: all = {} @@ -16,6 +191,8 @@ class BalanceStore: other_currency_amount = getattr(balance, type)\ .in_currency(other_currency, market, compute_value=compute_value) amounts[currency] = other_currency_amount + ReportStore.log_tickers(market, amounts, other_currency, + compute_value, type) return amounts @classmethod @@ -25,6 +202,7 @@ class BalanceStore: if balance["exchange_total"] != 0 or balance["margin_total"] != 0 or \ currency in cls.all: cls.all[currency] = portfolio.Balance(currency, balance) + ReportStore.log_balances(market) @classmethod def dispatch_assets(cls, amount, liquidity="medium", repartition=None): @@ -38,14 +216,20 @@ class BalanceStore: amounts[currency] = - amounts[currency] if currency not in BalanceStore.all: cls.all[currency] = portfolio.Balance(currency, {}) + ReportStore.log_dispatch(amount, amounts, liquidity, repartition) return amounts + @classmethod + def as_json(cls): + return { k: v.as_json() for k, v in cls.all.items() } + class TradeStore: all = [] debug = False @classmethod def compute_trades(cls, values_in_base, new_repartition, only=None, market=None, debug=False): + computed_trades = [] cls.debug = cls.debug or debug base_currency = sum(values_in_base.values()).currency for currency in BalanceStore.currencies(): @@ -55,41 +239,49 @@ class TradeStore: value_to = new_repartition.get(currency, portfolio.Amount(base_currency, 0)) if value_from.value * value_to.value < 0: - cls.add_trade_if_matching( + computed_trades.append(cls.trade_if_matching( value_from, portfolio.Amount(base_currency, 0), - currency, only=only, market=market) - cls.add_trade_if_matching( + currency, only=only, market=market)) + computed_trades.append(cls.trade_if_matching( portfolio.Amount(base_currency, 0), value_to, - currency, only=only, market=market) + currency, only=only, market=market)) else: - cls.add_trade_if_matching(value_from, value_to, - currency, only=only, market=market) + computed_trades.append(cls.trade_if_matching( + value_from, value_to, + currency, only=only, market=market)) + for matching, trade in computed_trades: + if matching: + cls.all.append(trade) + ReportStore.log_trades(computed_trades, only, cls.debug) @classmethod - def add_trade_if_matching(cls, value_from, value_to, currency, + def trade_if_matching(cls, value_from, value_to, currency, only=None, market=None): trade = portfolio.Trade(value_from, value_to, currency, market=market) - if only is None or trade.action == only: - cls.all.append(trade) - return True - return False + matching = only is None or trade.action == only + return [matching, trade] @classmethod def prepare_orders(cls, only=None, compute_value="default"): + orders = [] for trade in cls.all: if only is None or trade.action == only: - trade.prepare_order(compute_value=compute_value) + orders.append(trade.prepare_order(compute_value=compute_value)) + ReportStore.log_orders(orders, only, compute_value) @classmethod - def print_all_with_order(cls): + def print_all_with_order(cls, ind=""): for trade in cls.all: - trade.print_with_order() + trade.print_with_order(ind=ind) @classmethod def run_orders(cls): - for order in cls.all_orders(state="pending"): + orders = cls.all_orders(state="pending") + for order in orders: order.run() + ReportStore.log_stage("run_orders") + ReportStore.log_orders(orders) @classmethod def all_orders(cls, state=None): diff --git a/test.py b/test.py index 9fd058a..0f1f130 100644 --- a/test.py +++ b/test.py @@ -27,6 +27,8 @@ class WebMockTestCase(unittest.TestCase): self.wm.start() self.patchers = [ + mock.patch.multiple(portfolio.ReportStore, + logs=[], verbose_print=True), mock.patch.multiple(portfolio.BalanceStore, all={},), mock.patch.multiple(portfolio.TradeStore, @@ -63,7 +65,8 @@ class PortfolioTest(WebMockTestCase): self.wm.get(portfolio.Portfolio.URL, text=self.json_response) - def test_get_cryptoportfolio(self): + @mock.patch("portfolio.ReportStore") + def test_get_cryptoportfolio(self, report_store): self.wm.get(portfolio.Portfolio.URL, [ {"text":'{ "foo": "bar" }', "status_code": 200}, {"text": "System Error", "status_code": 500}, @@ -74,17 +77,28 @@ class PortfolioTest(WebMockTestCase): self.assertEqual("bar", portfolio.Portfolio.data["foo"]) self.assertTrue(self.wm.called) self.assertEqual(1, self.wm.call_count) + report_store.log_error.assert_not_called() + report_store.log_http_request.assert_called_once() + report_store.log_http_request.reset_mock() portfolio.Portfolio.get_cryptoportfolio() self.assertIsNone(portfolio.Portfolio.data) self.assertEqual(2, self.wm.call_count) + report_store.log_error.assert_not_called() + report_store.log_http_request.assert_called_once() + report_store.log_http_request.reset_mock() + portfolio.Portfolio.data = "Foo" portfolio.Portfolio.get_cryptoportfolio() self.assertEqual("Foo", portfolio.Portfolio.data) self.assertEqual(3, self.wm.call_count) + report_store.log_error.assert_called_once_with("get_cryptoportfolio", + exception=mock.ANY) + report_store.log_http_request.assert_not_called() - def test_parse_cryptoportfolio(self): + @mock.patch("portfolio.ReportStore") + def test_parse_cryptoportfolio(self, report_store): portfolio.Portfolio.parse_cryptoportfolio() self.assertListEqual( @@ -121,15 +135,22 @@ class PortfolioTest(WebMockTestCase): self.assertDictEqual(expected, liquidities["medium"][date]) self.assertEqual(portfolio.datetime(2018, 1, 15), portfolio.Portfolio.last_date) + report_store.log_http_request.assert_called_once_with("GET", + portfolio.Portfolio.URL, None, mock.ANY, mock.ANY) + report_store.log_http_request.reset_mock() + # It doesn't refetch the data when available portfolio.Portfolio.parse_cryptoportfolio() + report_store.log_http_request.assert_not_called() self.assertEqual(1, self.wm.call_count) portfolio.Portfolio.parse_cryptoportfolio(refetch=True) self.assertEqual(2, self.wm.call_count) + report_store.log_http_request.assert_called_once() - def test_repartition(self): + @mock.patch("portfolio.ReportStore") + def test_repartition(self, report_store): expected_medium = { 'BTC': (D("1.1102e-16"), "long"), 'USDT': (D("0.1"), "long"), @@ -163,6 +184,8 @@ class PortfolioTest(WebMockTestCase): portfolio.Portfolio.repartition(refetch=True) self.assertEqual(2, self.wm.call_count) + report_store.log_http_request.assert_called() + self.assertEqual(2, report_store.log_http_request.call_count) @mock.patch.object(portfolio.time, "sleep") @mock.patch.object(portfolio.Portfolio, "repartition") @@ -434,6 +457,17 @@ class AmountTest(WebMockTestCase): amount2.linked_to = amount3 self.assertEqual("Amount(32.00000000 BTX -> Amount(12000.00000000 USDT -> Amount(0.10000000 BTC)))", repr(amount1)) + def test_as_json(self): + amount = portfolio.Amount("BTX", 32) + self.assertEqual({"currency": "BTX", "value": D("32")}, amount.as_json()) + + amount = portfolio.Amount("BTX", "1E-10") + self.assertEqual({"currency": "BTX", "value": D("0")}, amount.as_json()) + + amount = portfolio.Amount("BTX", "1E-5") + self.assertEqual({"currency": "BTX", "value": D("0.00001")}, amount.as_json()) + self.assertEqual("0.00001", str(amount.as_json()["value"])) + @unittest.skipUnless("unit" in limits, "Unit skipped") class BalanceTest(WebMockTestCase): def test_values(self): @@ -497,6 +531,18 @@ class BalanceTest(WebMockTestCase): "margin_borrowed": 1, "exchange_free": 2, "exchange_total": 2}) self.assertEqual("Balance(BTX Exch: [✔2.00000000 BTX] Margin: [borrowed 1.00000000 BTX] Total: [0.00000000 BTX])", repr(balance)) + def test_as_json(self): + balance = portfolio.Balance("BTX", { "exchange_free": 2, "exchange_total": 2 }) + as_json = balance.as_json() + self.assertEqual(set(portfolio.Balance.base_keys), set(as_json.keys())) + self.assertEqual(D(0), as_json["total"]) + self.assertEqual(D(2), as_json["exchange_total"]) + self.assertEqual(D(2), as_json["exchange_free"]) + self.assertEqual(D(0), as_json["exchange_used"]) + self.assertEqual(D(0), as_json["margin_total"]) + self.assertEqual(D(0), as_json["margin_free"]) + self.assertEqual(D(0), as_json["margin_borrowed"]) + @unittest.skipUnless("unit" in limits, "Unit skipped") class HelperTest(WebMockTestCase): def test_get_ticker(self): @@ -575,7 +621,9 @@ class HelperTest(WebMockTestCase): @mock.patch.object(portfolio.Portfolio, "repartition") @mock.patch.object(helper, "get_ticker") @mock.patch.object(portfolio.TradeStore, "compute_trades") - def test_prepare_trades(self, compute_trades, get_ticker, repartition): + @mock.patch("store.ReportStore") + @mock.patch("helper.ReportStore") + def test_prepare_trades(self, report_store_h, report_store, compute_trades, get_ticker, repartition): repartition.return_value = { "XEM": (D("0.75"), "long"), "BTC": (D("0.25"), "long"), @@ -614,11 +662,15 @@ class HelperTest(WebMockTestCase): self.assertEqual(D("0.01"), call[0][0]["XVG"].value) self.assertEqual(D("0.2525"), call[0][1]["BTC"].value) self.assertEqual(D("0.7575"), call[0][1]["XEM"].value) + report_store_h.log_stage.assert_called_once_with("prepare_trades") + report_store.log_balances.assert_called_once_with(market) @mock.patch.object(portfolio.Portfolio, "repartition") @mock.patch.object(helper, "get_ticker") @mock.patch.object(portfolio.TradeStore, "compute_trades") - def test_update_trades(self, compute_trades, get_ticker, repartition): + @mock.patch("store.ReportStore") + @mock.patch("helper.ReportStore") + def test_update_trades(self, report_store_h, report_store, compute_trades, get_ticker, repartition): repartition.return_value = { "XEM": (D("0.75"), "long"), "BTC": (D("0.25"), "long"), @@ -657,11 +709,15 @@ class HelperTest(WebMockTestCase): self.assertEqual(D("0.01"), call[0][0]["XVG"].value) self.assertEqual(D("0.2525"), call[0][1]["BTC"].value) self.assertEqual(D("0.7575"), call[0][1]["XEM"].value) + report_store_h.log_stage.assert_called_once_with("update_trades") + report_store.log_balances.assert_called_once_with(market) @mock.patch.object(portfolio.Portfolio, "repartition") @mock.patch.object(helper, "get_ticker") @mock.patch.object(portfolio.TradeStore, "compute_trades") - def test_prepare_trades_to_sell_all(self, compute_trades, get_ticker, repartition): + @mock.patch("store.ReportStore") + @mock.patch("helper.ReportStore") + def test_prepare_trades_to_sell_all(self, report_store_h, report_store, compute_trades, get_ticker, repartition): def _get_ticker(c1, c2, market): if c1 == "USDT" and c2 == "BTC": return { "average": D("0.0001") } @@ -694,16 +750,17 @@ class HelperTest(WebMockTestCase): self.assertEqual(1, call[0][0]["USDT"].value) self.assertEqual(D("0.01"), call[0][0]["XVG"].value) self.assertEqual(D("1.01"), call[0][1]["BTC"].value) + report_store_h.log_stage.assert_called_once_with("prepare_trades_to_sell_all") + report_store.log_balances.assert_called_once_with(market) @mock.patch.object(portfolio.time, "sleep") @mock.patch.object(portfolio.TradeStore, "all_orders") def test_follow_orders(self, all_orders, time_mock): - for verbose, debug, sleep in [ - (True, False, None), (False, False, None), - (True, True, None), (True, False, 12), - (True, True, 12)]: - with self.subTest(sleep=sleep, debug=debug, verbose=verbose), \ - mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + for debug, sleep in [ + (False, None), (True, None), + (False, 12), (True, 12)]: + with self.subTest(sleep=sleep, debug=debug), \ + mock.patch("helper.ReportStore") as report_store: portfolio.TradeStore.debug = debug order_mock1 = mock.Mock() order_mock2 = mock.Mock() @@ -729,7 +786,7 @@ class HelperTest(WebMockTestCase): order_mock2.trade = mock.Mock() order_mock3.trade = mock.Mock() - helper.follow_orders(verbose=verbose, sleep=sleep) + helper.follow_orders(sleep=sleep) order_mock1.trade.update_order.assert_any_call(order_mock1, 1) order_mock1.trade.update_order.assert_any_call(order_mock1, 2) @@ -743,25 +800,43 @@ class HelperTest(WebMockTestCase): order_mock3.trade.update_order.assert_any_call(order_mock3, 2) self.assertEqual(1, order_mock3.trade.update_order.call_count) self.assertEqual(2, order_mock3.get_status.call_count) + report_store.log_stage.assert_called() + calls = [ + mock.call("follow_orders_begin"), + mock.call("follow_orders_tick_1"), + mock.call("follow_orders_tick_2"), + mock.call("follow_orders_tick_3"), + mock.call("follow_orders_end"), + ] + report_store.log_stage.assert_has_calls(calls) + report_store.log_orders.assert_called() + self.assertEqual(3, report_store.log_orders.call_count) + calls = [ + mock.call([order_mock1, order_mock2], tick=1), + mock.call([order_mock1, order_mock3], tick=2), + mock.call([order_mock1, order_mock3], tick=3), + ] + report_store.log_orders.assert_has_calls(calls) + calls = [ + mock.call(order_mock1, 3, finished=True), + mock.call(order_mock3, 3, finished=True), + ] + report_store.log_order.assert_has_calls(calls) if sleep is None: if debug: + report_store.log_debug_action.assert_called_with("Set follow_orders tick to 7s") time_mock.assert_called_with(7) else: time_mock.assert_called_with(30) else: time_mock.assert_called_with(sleep) - if verbose: - self.assertNotEqual("", stdout_mock.getvalue()) - else: - self.assertEqual("", stdout_mock.getvalue()) - @mock.patch.object(portfolio.BalanceStore, "fetch_balances") def test_move_balance(self, fetch_balances): for debug in [True, False]: with self.subTest(debug=debug),\ - mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + mock.patch("helper.ReportStore") as report_store: value_from = portfolio.Amount("BTC", "1.0") value_from.linked_to = portfolio.Amount("ETH", "10.0") value_to = portfolio.Amount("BTC", "10.0") @@ -788,8 +863,11 @@ class HelperTest(WebMockTestCase): helper.move_balances(market, debug=debug) fetch_balances.assert_called_with(market) + report_store.log_move_balances.assert_called_once() + if debug: - self.assertRegex(stdout_mock.getvalue(), "market.transfer_balance") + report_store.log_debug_action.assert_called() + self.assertEqual(3, report_store.log_debug_action.call_count) else: market.transfer_balance.assert_any_call("BTC", 3, "exchange", "margin") market.transfer_balance.assert_any_call("USDT", 50, "margin", "exchange") @@ -797,9 +875,8 @@ class HelperTest(WebMockTestCase): @mock.patch.object(helper, "prepare_trades") @mock.patch.object(portfolio.TradeStore, "prepare_orders") - @mock.patch.object(portfolio.TradeStore, "print_all_with_order") - @mock.patch('sys.stdout', new_callable=StringIO) - def test_print_orders(self, stdout_mock, print_all_with_order, prepare_orders, prepare_trades): + @mock.patch.object(portfolio.ReportStore, "log_stage") + def test_print_orders(self, log_stage, prepare_orders, prepare_trades): market = mock.Mock() portfolio.BalanceStore.all = { "BTC": portfolio.Balance("BTC", { @@ -817,13 +894,12 @@ class HelperTest(WebMockTestCase): prepare_trades.assert_called_with(market, base_currency="BTC", compute_value="average", debug=True) prepare_orders.assert_called_with(compute_value="average") - print_all_with_order.assert_called() - self.assertRegex(stdout_mock.getvalue(), "Balance") + log_stage.assert_called_with("print_orders") @mock.patch.object(portfolio.BalanceStore, "fetch_balances") @mock.patch.object(portfolio.BalanceStore, "in_currency") - @mock.patch('sys.stdout', new_callable=StringIO) - def test_print_balances(self, stdout_mock, in_currency, fetch_balances): + @mock.patch.object(helper.ReportStore, "print_log") + def test_print_balances(self, print_log, in_currency, fetch_balances): market = mock.Mock() portfolio.BalanceStore.all = { "BTC": portfolio.Balance("BTC", { @@ -843,18 +919,18 @@ class HelperTest(WebMockTestCase): } helper.print_balances(market) fetch_balances.assert_called_with(market) - self.assertRegex(stdout_mock.getvalue(), "Balance") - self.assertRegex(stdout_mock.getvalue(), "0.95000000 BTC") + print_log.assert_has_calls([ + mock.call("total:"), + mock.call(portfolio.Amount("BTC", "0.95")), + ]) @mock.patch.object(helper, "prepare_trades") @mock.patch.object(helper, "follow_orders") @mock.patch.object(portfolio.TradeStore, "prepare_orders") - @mock.patch.object(portfolio.TradeStore, "print_all_with_order") @mock.patch.object(portfolio.TradeStore, "run_orders") - @mock.patch('sys.stdout', new_callable=StringIO) - def test_process_sell_needed__1_sell(self, stdout_mock, run_orders, - print_all_with_order, prepare_orders, follow_orders, - prepare_trades): + @mock.patch.object(portfolio.ReportStore, "log_stage") + def test_process_sell_needed__1_sell(self, log_stage, run_orders, + prepare_orders, follow_orders, prepare_trades): market = mock.Mock() portfolio.BalanceStore.all = { "BTC": portfolio.Balance("BTC", { @@ -873,20 +949,18 @@ class HelperTest(WebMockTestCase): liquidity="medium", debug=False) prepare_orders.assert_called_with(compute_value="average", only="dispose") - print_all_with_order.assert_called() run_orders.assert_called() follow_orders.assert_called() - self.assertRegex(stdout_mock.getvalue(), "Balance") + log_stage.assert_called_with("process_sell_needed__1_sell_end") @mock.patch.object(helper, "update_trades") @mock.patch.object(helper, "follow_orders") @mock.patch.object(helper, "move_balances") @mock.patch.object(portfolio.TradeStore, "prepare_orders") - @mock.patch.object(portfolio.TradeStore, "print_all_with_order") @mock.patch.object(portfolio.TradeStore, "run_orders") - @mock.patch('sys.stdout', new_callable=StringIO) - def test_process_sell_needed__2_buy(self, stdout_mock, run_orders, - print_all_with_order, prepare_orders, move_balances, + @mock.patch.object(portfolio.ReportStore, "log_stage") + def test_process_sell_needed__2_buy(self, log_stage, run_orders, + prepare_orders, move_balances, follow_orders, update_trades): market = mock.Mock() portfolio.BalanceStore.all = { @@ -906,21 +980,18 @@ class HelperTest(WebMockTestCase): debug=False, liquidity="medium", only="acquire") prepare_orders.assert_called_with(compute_value="average", only="acquire") - print_all_with_order.assert_called() move_balances.assert_called_with(market, debug=False) run_orders.assert_called() follow_orders.assert_called() - self.assertRegex(stdout_mock.getvalue(), "Balance") + log_stage.assert_called_with("process_sell_needed__2_buy_end") @mock.patch.object(helper, "prepare_trades_to_sell_all") @mock.patch.object(helper, "follow_orders") @mock.patch.object(portfolio.TradeStore, "prepare_orders") - @mock.patch.object(portfolio.TradeStore, "print_all_with_order") @mock.patch.object(portfolio.TradeStore, "run_orders") - @mock.patch('sys.stdout', new_callable=StringIO) - def test_process_sell_all__1_sell(self, stdout_mock, run_orders, - print_all_with_order, prepare_orders, follow_orders, - prepare_trades_to_sell_all): + @mock.patch.object(portfolio.ReportStore, "log_stage") + def test_process_sell_all__1_sell(self, log_stage, run_orders, + prepare_orders, follow_orders, prepare_trades_to_sell_all): market = mock.Mock() portfolio.BalanceStore.all = { "BTC": portfolio.Balance("BTC", { @@ -938,21 +1009,19 @@ class HelperTest(WebMockTestCase): prepare_trades_to_sell_all.assert_called_with(market, base_currency="BTC", debug=False) prepare_orders.assert_called_with(compute_value="average") - print_all_with_order.assert_called() run_orders.assert_called() follow_orders.assert_called() - self.assertRegex(stdout_mock.getvalue(), "Balance") + log_stage.assert_called_with("process_sell_all__1_all_sell_end") @mock.patch.object(helper, "prepare_trades") @mock.patch.object(helper, "follow_orders") @mock.patch.object(helper, "move_balances") @mock.patch.object(portfolio.TradeStore, "prepare_orders") - @mock.patch.object(portfolio.TradeStore, "print_all_with_order") @mock.patch.object(portfolio.TradeStore, "run_orders") - @mock.patch('sys.stdout', new_callable=StringIO) - def test_process_sell_all__2_all_buy(self, stdout_mock, run_orders, - print_all_with_order, prepare_orders, move_balances, - follow_orders, prepare_trades): + @mock.patch.object(portfolio.ReportStore, "log_stage") + def test_process_sell_all__2_all_buy(self, log_stage, run_orders, + prepare_orders, move_balances, follow_orders, + prepare_trades): market = mock.Mock() portfolio.BalanceStore.all = { "BTC": portfolio.Balance("BTC", { @@ -970,18 +1039,18 @@ class HelperTest(WebMockTestCase): prepare_trades.assert_called_with(market, base_currency="BTC", liquidity="medium", debug=False) prepare_orders.assert_called_with(compute_value="average") - print_all_with_order.assert_called() move_balances.assert_called_with(market, debug=False) run_orders.assert_called() follow_orders.assert_called() - self.assertRegex(stdout_mock.getvalue(), "Balance") + log_stage.assert_called_with("process_sell_all__2_all_buy_end") @unittest.skipUnless("unit" in limits, "Unit skipped") class TradeStoreTest(WebMockTestCase): @mock.patch.object(portfolio.BalanceStore, "currencies") - @mock.patch.object(portfolio.TradeStore, "add_trade_if_matching") - def test_compute_trades(self, add_trade_if_matching, currencies): + @mock.patch.object(portfolio.TradeStore, "trade_if_matching") + @mock.patch.object(portfolio.ReportStore, "log_trades") + def test_compute_trades(self, log_trades, trade_if_matching, currencies): currencies.return_value = ["XMR", "DASH", "XVG", "BTC", "ETH"] values_in_base = { @@ -996,96 +1065,89 @@ class TradeStoreTest(WebMockTestCase): "BTC": portfolio.Amount("BTC", D("0.4")), "ETH": portfolio.Amount("BTC", D("0.3")), } + side_effect = [ + (True, 1), + (False, 2), + (False, 3), + (True, 4), + (True, 5) + ] + trade_if_matching.side_effect = side_effect portfolio.TradeStore.compute_trades(values_in_base, new_repartition, only="only", market="market") - self.assertEqual(5, add_trade_if_matching.call_count) - add_trade_if_matching.assert_any_call( - portfolio.Amount("BTC", D("0.9")), - portfolio.Amount("BTC", 0), - "XMR", only="only", market="market" - ) - add_trade_if_matching.assert_any_call( - portfolio.Amount("BTC", D("0.4")), - portfolio.Amount("BTC", D("0.5")), - "DASH", only="only", market="market" - ) - add_trade_if_matching.assert_any_call( - portfolio.Amount("BTC", D("-0.5")), - portfolio.Amount("BTC", D("0")), - "XVG", only="only", market="market" - ) - add_trade_if_matching.assert_any_call( - portfolio.Amount("BTC", D("0")), - portfolio.Amount("BTC", D("0.1")), - "XVG", only="only", market="market" - ) - add_trade_if_matching.assert_any_call( - portfolio.Amount("BTC", D("0")), - portfolio.Amount("BTC", D("0.3")), - "ETH", only="only", market="market" - ) + self.assertEqual(5, trade_if_matching.call_count) + self.assertEqual(3, len(portfolio.TradeStore.all)) + self.assertEqual([1, 4, 5], portfolio.TradeStore.all) + log_trades.assert_called_with(side_effect, "only", False) - def test_add_trade_if_matching(self): - result = portfolio.TradeStore.add_trade_if_matching( + def test_trade_if_matching(self): + result = portfolio.TradeStore.trade_if_matching( portfolio.Amount("BTC", D("0")), portfolio.Amount("BTC", D("0.3")), "ETH", only="nope", market="market" ) - self.assertEqual(0, len(portfolio.TradeStore.all)) - self.assertEqual(False, result) + self.assertEqual(False, result[0]) + self.assertIsInstance(result[1], portfolio.Trade) portfolio.TradeStore.all = [] - result = portfolio.TradeStore.add_trade_if_matching( + result = portfolio.TradeStore.trade_if_matching( portfolio.Amount("BTC", D("0")), portfolio.Amount("BTC", D("0.3")), "ETH", only=None, market="market" ) - self.assertEqual(1, len(portfolio.TradeStore.all)) - self.assertEqual(True, result) + self.assertEqual(True, result[0]) portfolio.TradeStore.all = [] - result = portfolio.TradeStore.add_trade_if_matching( + result = portfolio.TradeStore.trade_if_matching( portfolio.Amount("BTC", D("0")), portfolio.Amount("BTC", D("0.3")), "ETH", only="acquire", market="market" ) - self.assertEqual(1, len(portfolio.TradeStore.all)) - self.assertEqual(True, result) + self.assertEqual(True, result[0]) portfolio.TradeStore.all = [] - result = portfolio.TradeStore.add_trade_if_matching( + result = portfolio.TradeStore.trade_if_matching( portfolio.Amount("BTC", D("0")), portfolio.Amount("BTC", D("0.3")), "ETH", only="dispose", market="market" ) - self.assertEqual(0, len(portfolio.TradeStore.all)) - self.assertEqual(False, result) + self.assertEqual(False, result[0]) - def test_prepare_orders(self): + @mock.patch.object(portfolio.ReportStore, "log_orders") + def test_prepare_orders(self, log_orders): trade_mock1 = mock.Mock() trade_mock2 = mock.Mock() + trade_mock1.prepare_order.return_value = 1 + trade_mock2.prepare_order.return_value = 2 + portfolio.TradeStore.all.append(trade_mock1) portfolio.TradeStore.all.append(trade_mock2) portfolio.TradeStore.prepare_orders() trade_mock1.prepare_order.assert_called_with(compute_value="default") trade_mock2.prepare_order.assert_called_with(compute_value="default") + log_orders.assert_called_once_with([1, 2], None, "default") + + log_orders.reset_mock() portfolio.TradeStore.prepare_orders(compute_value="bla") trade_mock1.prepare_order.assert_called_with(compute_value="bla") trade_mock2.prepare_order.assert_called_with(compute_value="bla") + log_orders.assert_called_once_with([1, 2], None, "bla") trade_mock1.prepare_order.reset_mock() trade_mock2.prepare_order.reset_mock() + log_orders.reset_mock() trade_mock1.action = "foo" trade_mock2.action = "bar" portfolio.TradeStore.prepare_orders(only="bar") trade_mock1.prepare_order.assert_not_called() trade_mock2.prepare_order.assert_called_with(compute_value="default") + log_orders.assert_called_once_with([2], "bar", "default") def test_print_all_with_order(self): trade_mock1 = mock.Mock() @@ -1099,8 +1161,10 @@ class TradeStoreTest(WebMockTestCase): trade_mock2.print_with_order.assert_called() trade_mock3.print_with_order.assert_called() + @mock.patch.object(portfolio.ReportStore, "log_stage") + @mock.patch.object(portfolio.ReportStore, "log_orders") @mock.patch.object(portfolio.TradeStore, "all_orders") - def test_run_orders(self, all_orders): + def test_run_orders(self, all_orders, log_orders, log_stage): order_mock1 = mock.Mock() order_mock2 = mock.Mock() order_mock3 = mock.Mock() @@ -1112,6 +1176,10 @@ class TradeStoreTest(WebMockTestCase): order_mock2.run.assert_called() order_mock3.run.assert_called() + log_stage.assert_called_with("run_orders") + log_orders.assert_called_with([order_mock1, order_mock2, + order_mock3]) + def test_all_orders(self): trade_mock1 = mock.Mock() trade_mock2 = mock.Mock() @@ -1150,6 +1218,7 @@ class TradeStoreTest(WebMockTestCase): order_mock2.get_status.assert_called() order_mock3.get_status.assert_called() + @unittest.skipUnless("unit" in limits, "Unit skipped") class BalanceStoreTest(WebMockTestCase): def setUp(self): @@ -1184,7 +1253,8 @@ class BalanceStoreTest(WebMockTestCase): } @mock.patch.object(helper, "get_ticker") - def test_in_currency(self, get_ticker): + @mock.patch("portfolio.ReportStore.log_tickers") + def test_in_currency(self, log_tickers, get_ticker): portfolio.BalanceStore.all = { "BTC": portfolio.Balance("BTC", { "total": "0.65", @@ -1208,16 +1278,26 @@ class BalanceStoreTest(WebMockTestCase): self.assertEqual("BTC", amounts["ETH"].currency) self.assertEqual(D("0.65"), amounts["BTC"].value) self.assertEqual(D("0.30"), amounts["ETH"].value) + log_tickers.assert_called_once_with(market, amounts, "BTC", + "average", "total") + log_tickers.reset_mock() amounts = portfolio.BalanceStore.in_currency("BTC", market, compute_value="bid") self.assertEqual(D("0.65"), amounts["BTC"].value) self.assertEqual(D("0.27"), amounts["ETH"].value) + log_tickers.assert_called_once_with(market, amounts, "BTC", + "bid", "total") + log_tickers.reset_mock() amounts = portfolio.BalanceStore.in_currency("BTC", market, compute_value="bid", type="exchange_used") self.assertEqual(D("0.30"), amounts["BTC"].value) self.assertEqual(0, amounts["ETH"].value) + log_tickers.assert_called_once_with(market, amounts, "BTC", + "bid", "exchange_used") + log_tickers.reset_mock() - def test_fetch_balances(self): + @mock.patch.object(portfolio.ReportStore, "log_balances") + def test_fetch_balances(self, log_balances): market = mock.Mock() market.fetch_all_balances.return_value = self.fetch_balance @@ -1231,20 +1311,24 @@ class BalanceStoreTest(WebMockTestCase): portfolio.BalanceStore.fetch_balances(market) self.assertEqual(0, portfolio.BalanceStore.all["ETC"].total) self.assertListEqual(["USDT", "XVG", "XMR", "ETC"], list(portfolio.BalanceStore.currencies())) + log_balances.assert_called_with(market) @mock.patch.object(portfolio.Portfolio, "repartition") - def test_dispatch_assets(self, repartition): + @mock.patch.object(portfolio.ReportStore, "log_balances") + @mock.patch("store.ReportStore.log_dispatch") + def test_dispatch_assets(self, log_dispatch, log_balances, repartition): market = mock.Mock() market.fetch_all_balances.return_value = self.fetch_balance portfolio.BalanceStore.fetch_balances(market) self.assertNotIn("XEM", portfolio.BalanceStore.currencies()) - repartition.return_value = { + repartition_hash = { "XEM": (D("0.75"), "long"), "BTC": (D("0.26"), "long"), "DASH": (D("0.10"), "short"), } + repartition.return_value = repartition_hash amounts = portfolio.BalanceStore.dispatch_assets(portfolio.Amount("BTC", "11.1")) repartition.assert_called_with(liquidity="medium") @@ -1252,6 +1336,9 @@ class BalanceStoreTest(WebMockTestCase): self.assertEqual(D("2.6"), amounts["BTC"].value) self.assertEqual(D("7.5"), amounts["XEM"].value) self.assertEqual(D("-1.0"), amounts["DASH"].value) + log_balances.assert_called_with(market) + log_dispatch.assert_called_once_with(portfolio.Amount("BTC", + "11.1"), amounts, "medium", repartition_hash) def test_currencies(self): portfolio.BalanceStore.all = { @@ -1268,6 +1355,23 @@ class BalanceStoreTest(WebMockTestCase): } self.assertListEqual(["BTC", "ETH"], list(portfolio.BalanceStore.currencies())) + def test_as_json(self): + balance_mock1 = mock.Mock() + balance_mock1.as_json.return_value = 1 + + balance_mock2 = mock.Mock() + balance_mock2.as_json.return_value = 2 + + portfolio.BalanceStore.all = { + "BTC": balance_mock1, + "ETH": balance_mock2, + } + + as_json = portfolio.BalanceStore.as_json() + self.assertEqual(1, as_json["BTC"]) + self.assertEqual(2, as_json["ETH"]) + + @unittest.skipUnless("unit" in limits, "Unit skipped") class ComputationTest(WebMockTestCase): def test_compute_value(self): @@ -1426,7 +1530,8 @@ class TradeTest(WebMockTestCase): Order.assert_not_called() get_ticker.return_value = { "inverted": False } - with self.subTest(desc="Already filled"), mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with self.subTest(desc="Already filled"),\ + mock.patch("portfolio.ReportStore") as report_store: filled_amount.return_value = portfolio.Amount("FOO", "100") compute_value.return_value = D("0.125") @@ -1441,7 +1546,7 @@ class TradeTest(WebMockTestCase): filled_amount.assert_called_with(in_base_currency=False) compute_value.assert_called_with(get_ticker.return_value, "sell", compute_value="default") self.assertEqual(0, len(trade.orders)) - self.assertRegex(stdout_mock.getvalue(), "Less to do than already filled: ") + report_store.log_error.assert_called_with("prepare_order", message=mock.ANY) Order.assert_not_called() with self.subTest(action="dispose", inverted=False): @@ -1554,77 +1659,110 @@ class TradeTest(WebMockTestCase): prepare_order.return_value = new_order_mock for i in [0, 1, 3, 4, 6]: - with self.subTest(tick=i), mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with self.subTest(tick=i),\ + mock.patch.object(portfolio.ReportStore, "log_order") as log_order: trade.update_order(order_mock, i) order_mock.cancel.assert_not_called() new_order_mock.run.assert_not_called() - self.assertRegex(stdout_mock.getvalue(), "tick {}, waiting".format(i)) + log_order.assert_called_once_with(order_mock, i, + update="waiting", compute_value=None, new_order=None) order_mock.reset_mock() new_order_mock.reset_mock() trade.orders = [] - with mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with mock.patch.object(portfolio.ReportStore, "log_order") as log_order: trade.update_order(order_mock, 2) order_mock.cancel.assert_called() new_order_mock.run.assert_called() prepare_order.assert_called() - self.assertRegex(stdout_mock.getvalue(), "tick 2, cancelling and adjusting") + log_order.assert_called() + self.assertEqual(2, log_order.call_count) + calls = [ + mock.call(order_mock, 2, update="adjusting", + compute_value='lambda x, y: (x[y] + x["average"]) / 2', + new_order=new_order_mock), + mock.call(order_mock, 2, new_order=new_order_mock), + ] + log_order.assert_has_calls(calls) order_mock.reset_mock() new_order_mock.reset_mock() trade.orders = [] - with mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with mock.patch.object(portfolio.ReportStore, "log_order") as log_order: trade.update_order(order_mock, 5) order_mock.cancel.assert_called() new_order_mock.run.assert_called() prepare_order.assert_called() - self.assertRegex(stdout_mock.getvalue(), "tick 5, cancelling and adjusting") + self.assertEqual(2, log_order.call_count) + log_order.assert_called() + calls = [ + mock.call(order_mock, 5, update="adjusting", + compute_value='lambda x, y: (x[y]*2 + x["average"]) / 3', + new_order=new_order_mock), + mock.call(order_mock, 5, new_order=new_order_mock), + ] + log_order.assert_has_calls(calls) order_mock.reset_mock() new_order_mock.reset_mock() trade.orders = [] - with mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with mock.patch.object(portfolio.ReportStore, "log_order") as log_order: trade.update_order(order_mock, 7) order_mock.cancel.assert_called() new_order_mock.run.assert_called() prepare_order.assert_called_with(compute_value="default") - self.assertRegex(stdout_mock.getvalue(), "tick 7, fallbacking to market value") - self.assertRegex(stdout_mock.getvalue(), "tick 7, market value, cancelling and adjusting to") + log_order.assert_called() + self.assertEqual(2, log_order.call_count) + calls = [ + mock.call(order_mock, 7, update="market_fallback", + compute_value='default', + new_order=new_order_mock), + mock.call(order_mock, 7, new_order=new_order_mock), + ] + log_order.assert_has_calls(calls) order_mock.reset_mock() new_order_mock.reset_mock() trade.orders = [] for i in [10, 13, 16]: - with self.subTest(tick=i), mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with self.subTest(tick=i), mock.patch.object(portfolio.ReportStore, "log_order") as log_order: trade.update_order(order_mock, i) order_mock.cancel.assert_called() new_order_mock.run.assert_called() prepare_order.assert_called_with(compute_value="default") - self.assertNotRegex(stdout_mock.getvalue(), "tick {}, fallbacking to market value".format(i)) - self.assertRegex(stdout_mock.getvalue(), "tick {}, market value, cancelling and adjusting to".format(i)) + log_order.assert_called() + self.assertEqual(2, log_order.call_count) + calls = [ + mock.call(order_mock, i, update="market_adjust", + compute_value='default', + new_order=new_order_mock), + mock.call(order_mock, i, new_order=new_order_mock), + ] + log_order.assert_has_calls(calls) order_mock.reset_mock() new_order_mock.reset_mock() trade.orders = [] for i in [8, 9, 11, 12]: - with self.subTest(tick=i), mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + with self.subTest(tick=i), mock.patch.object(portfolio.ReportStore, "log_order") as log_order: trade.update_order(order_mock, i) order_mock.cancel.assert_not_called() new_order_mock.run.assert_not_called() - self.assertEqual("", stdout_mock.getvalue()) + log_order.assert_called_once_with(order_mock, i, update="waiting", + compute_value=None, new_order=None) order_mock.reset_mock() new_order_mock.reset_mock() trade.orders = [] - @mock.patch('sys.stdout', new_callable=StringIO) - def test_print_with_order(self, mock_stdout): + @mock.patch.object(portfolio.ReportStore, "print_log") + def test_print_with_order(self, print_log): value_from = portfolio.Amount("BTC", "0.5") value_from.linked_to = portfolio.Amount("ETH", "10.0") value_to = portfolio.Amount("BTC", "1.0") @@ -1651,12 +1789,13 @@ class TradeTest(WebMockTestCase): trade.print_with_order() - out = mock_stdout.getvalue().split("\n") - self.assertEqual("Trade(0.50000000 BTC [10.00000000 ETH] -> 1.00000000 BTC in ETH, acquire)", out[0]) - self.assertEqual("\tMock 1", out[1]) - self.assertEqual("\tMock 2", out[2]) - self.assertEqual("\t\tMouvement 1", out[3]) - self.assertEqual("\t\tMouvement 2", out[4]) + print_log.assert_called() + calls = print_log.mock_calls + self.assertEqual("Trade(0.50000000 BTC [10.00000000 ETH] -> 1.00000000 BTC in ETH, acquire)", str(calls[0][1][0])) + self.assertEqual("\tMock 1", str(calls[1][1][0])) + self.assertEqual("\tMock 2", str(calls[2][1][0])) + self.assertEqual("\t\tMouvement 1", str(calls[3][1][0])) + self.assertEqual("\t\tMouvement 2", str(calls[4][1][0])) def test__repr(self): value_from = portfolio.Amount("BTC", "0.5") @@ -1666,6 +1805,19 @@ class TradeTest(WebMockTestCase): self.assertEqual("Trade(0.50000000 BTC [10.00000000 ETH] -> 1.00000000 BTC in ETH, acquire)", str(trade)) + def test_as_json(self): + value_from = portfolio.Amount("BTC", "0.5") + value_from.linked_to = portfolio.Amount("ETH", "10.0") + value_to = portfolio.Amount("BTC", "1.0") + trade = portfolio.Trade(value_from, value_to, "ETH") + + as_json = trade.as_json() + self.assertEqual("acquire", as_json["action"]) + self.assertEqual(D("0.5"), as_json["from"]) + self.assertEqual(D("1.0"), as_json["to"]) + self.assertEqual("ETH", as_json["currency"]) + self.assertEqual("BTC", as_json["base_currency"]) + @unittest.skipUnless("unit" in limits, "Unit skipped") class OrderTest(WebMockTestCase): def test_values(self): @@ -1693,6 +1845,27 @@ class OrderTest(WebMockTestCase): close_if_possible=True) self.assertEqual("Order(buy long 10.00000000 ETH at 0.1 BTC [pending] ✂)", repr(order)) + def test_as_json(self): + order = portfolio.Order("buy", portfolio.Amount("ETH", 10), + D("0.1"), "BTC", "long", "market", "trade") + mouvement_mock1 = mock.Mock() + mouvement_mock1.as_json.return_value = 1 + mouvement_mock2 = mock.Mock() + mouvement_mock2.as_json.return_value = 2 + + order.mouvements = [mouvement_mock1, mouvement_mock2] + as_json = order.as_json() + self.assertEqual("buy", as_json["action"]) + self.assertEqual("long", as_json["trade_type"]) + self.assertEqual(10, as_json["amount"]) + self.assertEqual("ETH", as_json["currency"]) + self.assertEqual("BTC", as_json["base_currency"]) + self.assertEqual(D("0.1"), as_json["rate"]) + self.assertEqual("pending", as_json["status"]) + self.assertEqual(False, as_json["close_if_possible"]) + self.assertIsNone(as_json["id"]) + self.assertEqual([1, 2], as_json["mouvements"]) + def test_account(self): order = portfolio.Order("buy", portfolio.Amount("ETH", 10), D("0.1"), "BTC", "long", "market", "trade") @@ -1728,7 +1901,8 @@ class OrderTest(WebMockTestCase): self.assertTrue(order.finished) @mock.patch.object(portfolio.Order, "fetch") - def test_cancel(self, fetch): + @mock.patch("portfolio.ReportStore") + def test_cancel(self, report_store, fetch): market = mock.Mock() portfolio.TradeStore.debug = True order = portfolio.Order("buy", portfolio.Amount("ETH", 10), @@ -1737,6 +1911,8 @@ class OrderTest(WebMockTestCase): order.cancel() market.cancel_order.assert_not_called() + report_store.log_debug_action.assert_called_once() + report_store.log_debug_action.reset_mock() self.assertEqual("canceled", order.status) portfolio.TradeStore.debug = False @@ -1748,6 +1924,7 @@ class OrderTest(WebMockTestCase): order.cancel() market.cancel_order.assert_called_with(42) fetch.assert_called_once() + report_store.log_debug_action.assert_not_called() def test_dust_amount_remaining(self): order = portfolio.Order("buy", portfolio.Amount("ETH", 10), @@ -1824,7 +2001,8 @@ class OrderTest(WebMockTestCase): order.fetch_mouvements() self.assertEqual(0, len(order.mouvements)) - def test_mark_finished_order(self): + @mock.patch("portfolio.ReportStore") + def test_mark_finished_order(self, report_store): market = mock.Mock() order = portfolio.Order("buy", portfolio.Amount("ETH", 10), D("0.1"), "BTC", "short", market, "trade", @@ -1870,9 +2048,11 @@ class OrderTest(WebMockTestCase): order.mark_finished_order() market.close_margin_position.assert_not_called() + report_store.log_debug_action.assert_called_once() @mock.patch.object(portfolio.Order, "fetch_mouvements") - def test_fetch(self, fetch_mouvements): + @mock.patch("portfolio.ReportStore") + def test_fetch(self, report_store, fetch_mouvements): time = self.time.time() with mock.patch.object(portfolio.time, "time") as time_mock: market = mock.Mock() @@ -1883,10 +2063,14 @@ class OrderTest(WebMockTestCase): portfolio.TradeStore.debug = True order.fetch() time_mock.assert_not_called() + report_store.log_debug_action.assert_called_once() + report_store.log_debug_action.reset_mock() order.fetch(force=True) time_mock.assert_not_called() market.fetch_order.assert_not_called() fetch_mouvements.assert_not_called() + report_store.log_debug_action.assert_called_once() + report_store.log_debug_action.reset_mock() self.assertIsNone(order.fetch_cache_timestamp) with self.subTest(debug=False): @@ -1924,16 +2108,19 @@ class OrderTest(WebMockTestCase): order.fetch() market.fetch_order.assert_called_once() fetch_mouvements.assert_called_once() + report_store.log_debug_action.assert_not_called() @mock.patch.object(portfolio.Order, "fetch") @mock.patch.object(portfolio.Order, "mark_finished_order") - def test_get_status(self, mark_finished_order, fetch): + @mock.patch("portfolio.ReportStore") + def test_get_status(self, report_store, mark_finished_order, fetch): with self.subTest(debug=True): portfolio.TradeStore.debug = True order = portfolio.Order("buy", portfolio.Amount("ETH", 10), D("0.1"), "BTC", "long", "market", "trade") self.assertEqual("pending", order.get_status()) fetch.assert_not_called() + report_store.log_debug_action.assert_called_once() with self.subTest(debug=False, finished=False): portfolio.TradeStore.debug = False @@ -1968,13 +2155,13 @@ class OrderTest(WebMockTestCase): market.order_precision.return_value = 4 with self.subTest(debug=True),\ - mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + mock.patch('portfolio.ReportStore') as report_store: portfolio.TradeStore.debug = True order = portfolio.Order("buy", portfolio.Amount("ETH", 10), D("0.1"), "BTC", "long", market, "trade") order.run() market.create_order.assert_not_called() - self.assertEqual("market.create_order('ETH/BTC', 'limit', 'buy', 10.0000, price=0.1, account=exchange)\n", stdout_mock.getvalue()) + report_store.log_debug_action.assert_called_with("market.create_order('ETH/BTC', 'limit', 'buy', 10.0000, price=0.1, account=exchange)") self.assertEqual("open", order.status) self.assertEqual(1, len(order.results)) self.assertEqual(-1, order.id) @@ -1992,7 +2179,7 @@ class OrderTest(WebMockTestCase): market.create_order.reset_mock() with self.subTest(exception=True),\ - mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + mock.patch('portfolio.ReportStore') as report_store: order = portfolio.Order("buy", portfolio.Amount("ETH", 10), D("0.1"), "BTC", "long", market, "trade") market.create_order.side_effect = Exception("bouh") @@ -2000,8 +2187,7 @@ class OrderTest(WebMockTestCase): market.create_order.assert_called_once() self.assertEqual(0, len(order.results)) self.assertEqual("error", order.status) - self.assertRegex(stdout_mock.getvalue(), "error when running market.create_order") - self.assertRegex(stdout_mock.getvalue(), "Exception: bouh") + report_store.log_error.assert_called_once() market.create_order.reset_mock() with self.subTest(dust_amount_exception=True),\ @@ -2050,6 +2236,7 @@ class MouvementTest(WebMockTestCase): "amount": "10", "total": "1" }) self.assertEqual("Mouvement(2017-12-30 12:00:12 ; buy 10.00000000 ETH (1.00000000 BTC) fee: 0.1500%)", repr(mouvement)) + mouvement = portfolio.Mouvement("ETH", "BTC", { "tradeID": 42, "type": "buy", "date": "garbage", "rate": "0.1", @@ -2057,10 +2244,401 @@ class MouvementTest(WebMockTestCase): }) self.assertEqual("Mouvement(No date ; buy 10.00000000 ETH (1.00000000 BTC))", repr(mouvement)) + def test_as_json(self): + mouvement = portfolio.Mouvement("ETH", "BTC", { + "tradeID": 42, "type": "buy", "fee": "0.0015", + "date": "2017-12-30 12:00:12", "rate": "0.1", + "amount": "10", "total": "1" + }) + as_json = mouvement.as_json() + + self.assertEqual(D("0.0015"), as_json["fee_rate"]) + self.assertEqual(portfolio.datetime(2017, 12, 30, 12, 0, 12), as_json["date"]) + self.assertEqual("buy", as_json["action"]) + self.assertEqual(D("10"), as_json["total"]) + self.assertEqual(D("1"), as_json["total_in_base"]) + self.assertEqual("BTC", as_json["base_currency"]) + self.assertEqual("ETH", as_json["currency"]) + +@unittest.skipUnless("unit" in limits, "Unit skipped") +class ReportStoreTest(WebMockTestCase): + def test_add_log(self): + portfolio.ReportStore.add_log({"foo": "bar"}) + + self.assertEqual({"foo": "bar", "date": mock.ANY}, portfolio.ReportStore.logs[0]) + + def test_set_verbose(self): + with self.subTest(verbose=True): + portfolio.ReportStore.set_verbose(True) + self.assertTrue(portfolio.ReportStore.verbose_print) + + with self.subTest(verbose=False): + portfolio.ReportStore.set_verbose(False) + self.assertFalse(portfolio.ReportStore.verbose_print) + + def test_print_log(self): + with self.subTest(verbose=True),\ + mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + portfolio.ReportStore.set_verbose(True) + portfolio.ReportStore.print_log("Coucou") + portfolio.ReportStore.print_log(portfolio.Amount("BTC", 1)) + self.assertEqual(stdout_mock.getvalue(), "Coucou\n1.00000000 BTC\n") + + with self.subTest(verbose=False),\ + mock.patch('sys.stdout', new_callable=StringIO) as stdout_mock: + portfolio.ReportStore.set_verbose(False) + portfolio.ReportStore.print_log("Coucou") + portfolio.ReportStore.print_log(portfolio.Amount("BTC", 1)) + self.assertEqual(stdout_mock.getvalue(), "") + + def test_to_json(self): + portfolio.ReportStore.logs.append({"foo": "bar"}) + self.assertEqual('[{"foo": "bar"}]', portfolio.ReportStore.to_json()) + portfolio.ReportStore.logs.append({"date": portfolio.datetime(2018, 2, 24)}) + self.assertEqual('[{"foo": "bar"}, {"date": "2018-02-24T00:00:00"}]', portfolio.ReportStore.to_json()) + portfolio.ReportStore.logs.append({"amount": portfolio.Amount("BTC", 1)}) + with self.assertRaises(TypeError): + portfolio.ReportStore.to_json() + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_stage(self, add_log, print_log): + portfolio.ReportStore.log_stage("foo") + print_log.assert_has_calls([ + mock.call("-----------"), + mock.call("[Stage] foo"), + ]) + add_log.assert_called_once_with({'type': 'stage', 'stage': 'foo'}) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + @mock.patch("store.BalanceStore") + def test_log_balances(self, balance_store, add_log, print_log): + balance_store.as_json.return_value = "json" + balance_store.all = { "FOO": "bar", "BAR": "baz" } + + portfolio.ReportStore.log_balances("market") + print_log.assert_has_calls([ + mock.call("[Balance]"), + mock.call("\tbar"), + mock.call("\tbaz"), + ]) + add_log.assert_called_once_with({'type': 'balance', 'balances': 'json'}) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_tickers(self, add_log, print_log): + market = mock.Mock() + amounts = { + "BTC": portfolio.Amount("BTC", 10), + "ETH": portfolio.Amount("BTC", D("0.3")) + } + amounts["ETH"].rate = D("0.1") + + portfolio.ReportStore.log_tickers(market, amounts, "BTC", "default", "total") + print_log.assert_not_called() + add_log.assert_called_once_with({ + 'type': 'tickers', + 'compute_value': 'default', + 'balance_type': 'total', + 'currency': 'BTC', + 'balances': { + 'BTC': D('10'), + 'ETH': D('0.3') + }, + 'rates': { + 'BTC': None, + 'ETH': D('0.1') + }, + 'total': D('10.3') + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_dispatch(self, add_log, print_log): + amount = portfolio.Amount("BTC", "10.3") + amounts = { + "BTC": portfolio.Amount("BTC", 10), + "ETH": portfolio.Amount("BTC", D("0.3")) + } + portfolio.ReportStore.log_dispatch(amount, amounts, "medium", "repartition") + print_log.assert_not_called() + add_log.assert_called_once_with({ + 'type': 'dispatch', + 'liquidity': 'medium', + 'repartition_ratio': 'repartition', + 'total_amount': { + 'currency': 'BTC', + 'value': D('10.3') + }, + 'repartition': { + 'BTC': D('10'), + 'ETH': D('0.3') + } + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_trades(self, add_log, print_log): + trade_mock1 = mock.Mock() + trade_mock2 = mock.Mock() + trade_mock1.as_json.return_value = { "trade": "1" } + trade_mock2.as_json.return_value = { "trade": "2" } + + matching_and_trades = [ + (True, trade_mock1), + (False, trade_mock2), + ] + portfolio.ReportStore.log_trades(matching_and_trades, "only", "debug") + + print_log.assert_not_called() + add_log.assert_called_with({ + 'type': 'trades', + 'only': 'only', + 'debug': 'debug', + 'trades': [ + {'trade': '1', 'skipped': False}, + {'trade': '2', 'skipped': True} + ] + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + @mock.patch.object(portfolio.TradeStore, "print_all_with_order") + def test_log_orders(self, print_all_with_order, add_log, print_log): + order_mock1 = mock.Mock() + order_mock2 = mock.Mock() + + order_mock1.as_json.return_value = "order1" + order_mock2.as_json.return_value = "order2" + + orders = [order_mock1, order_mock2] + + portfolio.ReportStore.log_orders(orders, tick="tick", + only="only", compute_value="compute_value") + + print_log.assert_called_once_with("[Orders]") + print_all_with_order.assert_called_once_with(ind="\t") + + add_log.assert_called_with({ + 'type': 'orders', + 'only': 'only', + 'compute_value': 'compute_value', + 'tick': 'tick', + 'orders': ['order1', 'order2'] + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_order(self, add_log, print_log): + order_mock = mock.Mock() + order_mock.as_json.return_value = "order" + new_order_mock = mock.Mock() + new_order_mock.as_json.return_value = "new_order" + order_mock.__repr__ = mock.Mock() + order_mock.__repr__.return_value = "Order Mock" + new_order_mock.__repr__ = mock.Mock() + new_order_mock.__repr__.return_value = "New order Mock" + + with self.subTest(finished=True): + portfolio.ReportStore.log_order(order_mock, 1, finished=True) + print_log.assert_called_once_with("[Order] Finished Order Mock") + add_log.assert_called_once_with({ + 'type': 'order', + 'tick': 1, + 'update': None, + 'order': 'order', + 'compute_value': None, + 'new_order': None + }) + + add_log.reset_mock() + print_log.reset_mock() + + with self.subTest(update="waiting"): + portfolio.ReportStore.log_order(order_mock, 1, update="waiting") + print_log.assert_called_once_with("[Order] Order Mock, tick 1, waiting") + add_log.assert_called_once_with({ + 'type': 'order', + 'tick': 1, + 'update': 'waiting', + 'order': 'order', + 'compute_value': None, + 'new_order': None + }) + + add_log.reset_mock() + print_log.reset_mock() + with self.subTest(update="adjusting"): + portfolio.ReportStore.log_order(order_mock, 3, + update="adjusting", new_order=new_order_mock, + compute_value="default") + print_log.assert_called_once_with("[Order] Order Mock, tick 3, cancelling and adjusting to New order Mock") + add_log.assert_called_once_with({ + 'type': 'order', + 'tick': 3, + 'update': 'adjusting', + 'order': 'order', + 'compute_value': "default", + 'new_order': 'new_order' + }) + + add_log.reset_mock() + print_log.reset_mock() + with self.subTest(update="market_fallback"): + portfolio.ReportStore.log_order(order_mock, 7, + update="market_fallback", new_order=new_order_mock) + print_log.assert_called_once_with("[Order] Order Mock, tick 7, fallbacking to market value") + add_log.assert_called_once_with({ + 'type': 'order', + 'tick': 7, + 'update': 'market_fallback', + 'order': 'order', + 'compute_value': None, + 'new_order': 'new_order' + }) + + add_log.reset_mock() + print_log.reset_mock() + with self.subTest(update="market_adjusting"): + portfolio.ReportStore.log_order(order_mock, 17, + update="market_adjust", new_order=new_order_mock) + print_log.assert_called_once_with("[Order] Order Mock, tick 17, market value, cancelling and adjusting to New order Mock") + add_log.assert_called_once_with({ + 'type': 'order', + 'tick': 17, + 'update': 'market_adjust', + 'order': 'order', + 'compute_value': None, + 'new_order': 'new_order' + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_move_balances(self, add_log, print_log): + needed = { + "BTC": portfolio.Amount("BTC", 10), + "USDT": 1 + } + moving = { + "BTC": portfolio.Amount("BTC", 3), + "USDT": -2 + } + portfolio.ReportStore.log_move_balances(needed, moving, True) + print_log.assert_not_called() + add_log.assert_called_once_with({ + 'type': 'move_balances', + 'debug': True, + 'needed': { + 'BTC': D('10'), + 'USDT': 1 + }, + 'moving': { + 'BTC': D('3'), + 'USDT': -2 + } + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_http_request(self, add_log, print_log): + response = mock.Mock() + response.status_code = 200 + response.text = "Hey" + + portfolio.ReportStore.log_http_request("method", "url", "body", + "headers", response) + print_log.assert_not_called() + add_log.assert_called_once_with({ + 'type': 'http_request', + 'method': 'method', + 'url': 'url', + 'body': 'body', + 'headers': 'headers', + 'status': 200, + 'response': 'Hey' + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_error(self, add_log, print_log): + with self.subTest(message=None, exception=None): + portfolio.ReportStore.log_error("action") + print_log.assert_called_once_with("[Error] action") + add_log.assert_called_once_with({ + 'type': 'error', + 'action': 'action', + 'exception_class': None, + 'exception_message': None, + 'message': None + }) + + print_log.reset_mock() + add_log.reset_mock() + with self.subTest(message="Hey", exception=None): + portfolio.ReportStore.log_error("action", message="Hey") + print_log.assert_has_calls([ + mock.call("[Error] action"), + mock.call("\tHey") + ]) + add_log.assert_called_once_with({ + 'type': 'error', + 'action': 'action', + 'exception_class': None, + 'exception_message': None, + 'message': "Hey" + }) + + print_log.reset_mock() + add_log.reset_mock() + with self.subTest(message=None, exception=Exception("bouh")): + portfolio.ReportStore.log_error("action", exception=Exception("bouh")) + print_log.assert_has_calls([ + mock.call("[Error] action"), + mock.call("\tException: bouh") + ]) + add_log.assert_called_once_with({ + 'type': 'error', + 'action': 'action', + 'exception_class': "Exception", + 'exception_message': "bouh", + 'message': None + }) + + print_log.reset_mock() + add_log.reset_mock() + with self.subTest(message="Hey", exception=Exception("bouh")): + portfolio.ReportStore.log_error("action", message="Hey", exception=Exception("bouh")) + print_log.assert_has_calls([ + mock.call("[Error] action"), + mock.call("\tException: bouh"), + mock.call("\tHey") + ]) + add_log.assert_called_once_with({ + 'type': 'error', + 'action': 'action', + 'exception_class': "Exception", + 'exception_message': "bouh", + 'message': "Hey" + }) + + @mock.patch.object(portfolio.ReportStore, "print_log") + @mock.patch.object(portfolio.ReportStore, "add_log") + def test_log_debug_action(self, add_log, print_log): + portfolio.ReportStore.log_debug_action("Hey") + + print_log.assert_called_once_with("[Debug] Hey") + add_log.assert_called_once_with({ + 'type': 'debug_action', + 'action': 'Hey' + }) + @unittest.skipUnless("acceptance" in limits, "Acceptance skipped") class AcceptanceTest(WebMockTestCase): @unittest.expectedFailure def test_success_sell_only_necessary(self): + # FIXME: catch stdout + portfolio.ReportStore.verbose_print = False fetch_balance = { "ETH": { "exchange_free": D("1.0"), -- 2.41.0