]> git.immae.eu Git - perso/Immae/Projets/Cryptomonnaies/Cryptoportfolio/Trader.git/commitdiff
Add report store to store messages and logs
authorIsmaël Bouya <ismael.bouya@normalesup.org>
Sat, 24 Feb 2018 18:53:58 +0000 (19:53 +0100)
committerIsmaël Bouya <ismael.bouya@normalesup.org>
Sat, 24 Feb 2018 18:53:58 +0000 (19:53 +0100)
helper.py
portfolio.py
store.py
test.py

index 23b2d0be4654cc483b4c81eb756b25f3cbe7c7ef..87539f19e93f03cb0592e51b4b29a8d20f92d9ac 100644 (file)
--- 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")
 
 
index c3809f0533db32cc3b62ccbd6c64a5ff5c66e651..f9423b91d0736178fb4759016195e3d29ecd2499 100644 (file)
@@ -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)
index abbe5eef556eb88455aec50f12d07b041c0f5c67..dfadef22e1d2ad5e7591d5793bbaefbfc8105857 100644 (file)
--- 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 9fd058a0ad6d59c80798466d4cbf4ddace1ab6eb..0f1f13030b2539a91d56d665368e225ca6a70fb0 100644 (file)
--- 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"),