Better rollbar logging and path invariance test upgrades (#1252)

1. Interactive hyperdrive has parameter that allows logs to rollbar
2. Adding log level when crash reporting in interactive hyperdrive
3. Path independence allows for failed paths, logging failures as info
to rollbar
4. Adds optional ticker to interactive hyperdrive crash reports
5. Adds optional message prefix to rollbar logs
6. Catching and printing unexpected errors in run all fuzz tests

lib/agent0/agent0/hyperdrive/crash_report/crash_report.py

@@ -186,6 +186,7 @@ def log_hyperdrive_crash_report(
     crash_report_to_file: bool = True,
     crash_report_file_prefix: str | None = None,
     log_to_rollbar: bool = False,
+    rollbar_log_prefix: str | None = None,
     rollbar_data: dict | None = None,
 ) -> None:
     # pylint: disable=too-many-arguments
@@ -207,6 +208,8 @@ def log_hyperdrive_crash_report(
     log_to_rollbar: bool, optional
         If enabled, logs errors to the rollbar service.
         Defaults to False.
+    rollbar_log_prefix: str | None, optional
+        The prefix to prepend to rollbar exception messages
     rollbar_data: dict | None, optional
         Optional dictionary of data to use for the the rollbar report.
         If not provided, will default to logging all of the crash report to rollbar.
@@ -306,7 +309,7 @@ def log_hyperdrive_crash_report(
 
         # Format data
         rollbar_data = json.loads(json.dumps(rollbar_data, indent=2, cls=ExtendedJSONEncoder))
-        log_rollbar_exception(trade_result.exception, log_level, rollbar_data)
+        log_rollbar_exception(trade_result.exception, log_level, rollbar_data, rollbar_log_prefix=rollbar_log_prefix)
 
 
 def _hyperdrive_wallet_to_dict(wallet: HyperdriveWallet | None) -> dict[str, Any]:

lib/agent0/agent0/hyperdrive/interactive/interactive_hyperdrive.py

@@ -2,6 +2,7 @@
 from __future__ import annotations
 
 import asyncio
+import logging
 import os
 import time
 from dataclasses import asdict, dataclass
@@ -15,8 +16,9 @@
 from chainsync import PostgresConfig
 from chainsync.dashboard.usernames import build_user_mapping
 from chainsync.db.base import add_addr_to_username, get_addr_to_username, get_username_to_user, initialize_session
+from chainsync.db.hyperdrive import get_checkpoint_info
+from chainsync.db.hyperdrive import get_current_wallet as chainsync_get_current_wallet
 from chainsync.db.hyperdrive import (
-    get_checkpoint_info,
     get_latest_block_number_from_analysis_table,
     get_pool_analysis,
     get_pool_config,
@@ -26,7 +28,6 @@
     get_wallet_deltas,
     get_wallet_pnl,
 )
-from chainsync.db.hyperdrive import get_current_wallet as chainsync_get_current_wallet
 from chainsync.exec import acquire_data, data_analysis
 from eth_account.account import Account
 from eth_typing import BlockNumber, ChecksumAddress
@@ -95,6 +96,14 @@ class Config:
             The timeout for the data pipeline. Defaults to 60 seconds.
         preview_before_trade: bool, optional
             Whether to preview the position before executing a trade. Defaults to False.
+        log_to_rollbar: bool, optional
+            Whether to log crash reports to rollbar. Defaults to False.
+        rollbar_log_prefix: str | None, optional
+            The prefix to prepend to rollbar exception messages
+        crash_log_level: int, optional
+            The log level to log crashes at. Defaults to critical.
+        crash_log_ticker: bool | None, optional
+            Whether to log the trade ticker in crash reports. Defaults to False.
         rng_seed: int | None, optional
             The seed for the random number generator. Defaults to None.
         rng: Generator | None, optional
@@ -140,6 +149,10 @@ class Config:
         # Environment variables
         data_pipeline_timeout: int = 60
         preview_before_trade: bool = False
+        log_to_rollbar: bool = False
+        rollbar_log_prefix: str | None = None
+        crash_log_level: int = logging.CRITICAL
+        crash_log_ticker: bool = False
         # Random generators
         rng_seed: int | None = None
         rng: Generator | None = None
@@ -254,6 +267,10 @@ def __init__(self, chain: Chain, config: Config | None = None):
             self._run_blocking_data_pipeline()
 
         self.rng = config.rng
+        self.log_to_rollbar = config.log_to_rollbar
+        self.rollbar_log_prefix = config.rollbar_log_prefix
+        self.crash_log_level = config.crash_log_level
+        self.crash_log_ticker = config.crash_log_ticker
 
     def _launch_data_pipeline(self, start_block: int | None = None):
         """Launches the data pipeline in background threads.
@@ -946,9 +963,20 @@ def _handle_trade_result(self, trade_results: list[TradeResult] | TradeResult) -
             # We only get anvil state dump here, since it's an on chain call
             # and we don't want to do it when e.g., slippage happens
             trade_result.anvil_state = get_anvil_state_dump(self.hyperdrive_interface.web3)
+            if self.crash_log_ticker:
+                if trade_result.additional_info is None:
+                    trade_result.additional_info = {"ticker": self.get_ticker()}
+                else:
+                    trade_result.additional_info["ticker"] = self.get_ticker()
+
             # Defaults to CRITICAL
             log_hyperdrive_crash_report(
-                trade_result, crash_report_to_file=True, crash_report_file_prefix="interactive_hyperdrive"
+                trade_result,
+                log_level=self.crash_log_level,
+                crash_report_to_file=True,
+                crash_report_file_prefix="interactive_hyperdrive",
+                log_to_rollbar=self.log_to_rollbar,
+                rollbar_log_prefix=self.rollbar_log_prefix,
             )
             raise trade_result.exception
 

lib/agent0/agent0/interactive_fuzz/fuzz_long_short_maturity_values.py

@@ -70,7 +70,9 @@ def fuzz_long_short_maturity_values(
     # set a large block time so i can manually control when it ticks
     # TODO: set block time really high after contracts deployed:
     # chain_config = LocalChain.Config(block_time=1_000_000)
-    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(log_filename, chain_config, log_to_stdout)
+    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(
+        log_filename, chain_config, log_to_stdout, rollbar_log_prefix="fuzz_long_short_maturity_values"
+    )
     signer = interactive_hyperdrive.init_agent(eth=FixedPoint(100))
 
     # Advance time to ensure current time is in the middle of a checkpoint

lib/agent0/agent0/interactive_fuzz/fuzz_path_independence.py

@@ -33,6 +33,8 @@
 from typing import Any, NamedTuple, Sequence
 
 import pandas as pd
+import rollbar
+from ethpy.base.errors import ContractCallException
 from fixedpointmath import FixedPoint
 
 from agent0.hyperdrive.crash_report import build_crash_trade_result, log_hyperdrive_crash_report
@@ -89,7 +91,16 @@ def fuzz_path_independence(
     # pylint: disable=too-many-statements
     # pylint: disable=too-many-arguments
     log_filename = ".logging/fuzz_path_independence.log"
-    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(log_filename, chain_config, log_to_stdout, fees=False)
+    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(
+        log_filename,
+        chain_config,
+        log_to_stdout,
+        # Trade crashes in this file have expected failures, hence we log interactive
+        # hyperdrive crashes as info instead of critical.
+        crash_log_level=logging.INFO,
+        fees=False,
+        rollbar_log_prefix="fuzz_path_independence",
+    )
 
     # Open some trades
     logging.info("Open random trades...")
@@ -120,6 +131,8 @@ def fuzz_path_independence(
     check_data: dict[str, Any] | None = None
     first_run_state_dump_dir: str | None = None
     first_run_ticker: pd.DataFrame | None = None
+    invariance_checked: bool = False
+    latest_error: Exception | None = None
     for iteration in range(num_paths_checked):
         print(f"{iteration=}")
         logging.info("iteration %s out of %s", iteration, num_paths_checked - 1)
@@ -130,7 +143,13 @@ def fuzz_path_independence(
         # guarantee closing trades within the same checkpoint by getting the checkpoint id before
         # and after closing trades, then asserting they're the same
         starting_checkpoint_id = interactive_hyperdrive.hyperdrive_interface.calc_checkpoint_id()
-        close_random_trades(trade_events, rng)
+        try:
+            close_random_trades(trade_events, rng)
+        except ContractCallException:
+            # Trades can fail here due to invalid order, we ignore and move on
+            # These trades get logged as info
+            continue
+
         ending_checkpoint_id = interactive_hyperdrive.hyperdrive_interface.calc_checkpoint_id()
         assert starting_checkpoint_id == ending_checkpoint_id
 
@@ -154,6 +173,7 @@ def fuzz_path_independence(
 
         # On subsequent run, check against the saved final state
         else:
+            invariance_checked = True
             # Sanity check, ensure checkpoint id is the same after all runs
             assert ending_checkpoint_id == check_data["curr_checkpoint_id"]
 
@@ -197,8 +217,19 @@ def fuzz_path_independence(
                     log_to_rollbar=True,
                     rollbar_data=rollbar_data,
                 )
-                chain.cleanup()
-                raise error
+                latest_error = error
+
+    # If the number of successful paths < 2, we print and log a warning
+    if not invariance_checked:
+        warning_message = "No invariance checks were performed due to failed paths."
+        logging.warning(warning_message)
+        rollbar.report_message(warning_message, "warning")
+
+    # If any of the path checks broke, we throw an exception at the very end
+    if latest_error is not None:
+        chain.cleanup()
+        raise latest_error
+
     chain.cleanup()
     logging.info("Test passed!")
 

lib/agent0/agent0/interactive_fuzz/fuzz_present_value.py

@@ -65,7 +65,13 @@ def fuzz_present_value(
         Defaults to False.
     """
     log_filename = ".logging/fuzz_present_value.log"
-    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(log_filename, chain_config, log_to_stdout, fees=False)
+    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(
+        log_filename,
+        chain_config,
+        log_to_stdout,
+        fees=False,
+        rollbar_log_prefix="fuzz_present_value",
+    )
 
     initial_pool_state = interactive_hyperdrive.hyperdrive_interface.current_pool_state
     check_data: dict[str, Any] = {

lib/agent0/agent0/interactive_fuzz/fuzz_profit_check.py

@@ -61,7 +61,9 @@ def fuzz_profit_check(chain_config: LocalChain.Config | None = None, log_to_stdo
 
     # Setup the environment
     log_filename = ".logging/fuzz_profit_check.log"
-    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(log_filename, chain_config, log_to_stdout)
+    chain, random_seed, rng, interactive_hyperdrive = setup_fuzz(
+        log_filename, chain_config, log_to_stdout, rollbar_log_prefix="fuzz_profit_check"
+    )
 
     # Get a random trade amount
     long_trade_amount = FixedPoint(

lib/agent0/agent0/interactive_fuzz/helpers/setup_fuzz.py

@@ -1,6 +1,8 @@
 """Setup an interactive enfironment for fuzz testing."""
 from __future__ import annotations
 
+import logging
+
 import numpy as np
 from fixedpointmath import FixedPoint
 from hyperlogs import setup_logging
@@ -13,6 +15,9 @@ def setup_fuzz(
     log_filename: str,
     chain_config: LocalChain.Config | None = None,
     log_to_stdout: bool = False,
+    log_to_rollbar: bool = True,
+    crash_log_level: int | None = None,
+    rollbar_log_prefix: str | None = None,
     fees=True,
     var_interest=None,
 ) -> tuple[LocalChain, int, Generator, InteractiveHyperdrive]:
@@ -28,6 +33,12 @@ def setup_fuzz(
     log_to_stdout: bool, optional
         If True, log to stdout in addition to a file.
         Defaults to False.
+    log_to_rollbar: bool, optional
+        If True, log errors rollbar. Defaults to True.
+    crash_log_level: int | None, optional
+        The log level to log crashes at. Defaults to critical.
+    rollbar_log_prefix: str | None, optional
+        The prefix to prepend to rollbar exception messages
     fees: bool, optional
         If False, will turn off fees when deploying hyperdrive. Defaults to True.
     var_interest: FixedPoint | None, optional
@@ -47,6 +58,7 @@ def setup_fuzz(
             interactive_hyperdrive: InteractiveHyperdrive
                 An instantiated InteractiveHyperdrive object.
     """
+    # pylint: disable=too-many-arguments
     setup_logging(
         log_filename=log_filename,
         delete_previous_logs=False,
@@ -63,7 +75,17 @@ def setup_fuzz(
 
     # Parameters for pool initialization.
     # Using a day for checkpoint duration to speed things up
-    initial_pool_config = InteractiveHyperdrive.Config(preview_before_trade=True, checkpoint_duration=86400)
+    if crash_log_level is None:
+        crash_log_level = logging.CRITICAL
+
+    initial_pool_config = InteractiveHyperdrive.Config(
+        preview_before_trade=True,
+        checkpoint_duration=86400,
+        log_to_rollbar=log_to_rollbar,
+        rollbar_log_prefix=rollbar_log_prefix,
+        crash_log_level=crash_log_level,
+        crash_log_ticker=True,
+    )
     if not fees:
         initial_pool_config.curve_fee = FixedPoint(0)
         initial_pool_config.flat_fee = FixedPoint(0)

lib/agent0/agent0/interactive_fuzz/run_all_fuzz_tests.py

@@ -30,7 +30,7 @@ def main(argv: Sequence[str] | None = None):
     initialize_rollbar("interactivefuzz")
 
     num_trades = 10
-    num_paths_checked = 10
+    num_paths_checked = 20
 
     num_checks = 0
     while True:
@@ -40,6 +40,10 @@ def main(argv: Sequence[str] | None = None):
             fuzz_long_short_maturity_values(num_trades, chain_config)
         except FuzzAssertionException:
             pass
+        # We catch other exceptions here, for some reason rollbar needs to be continuously running in order
+        # to log.
+        except Exception:  # pylint: disable=broad-except
+            print("Unexpected error:", sys.exc_info()[0])
 
         try:
             print("Running path independence test")
@@ -51,13 +55,16 @@ def main(argv: Sequence[str] | None = None):
             )
         except FuzzAssertionException:
             pass
+        # No need to catch other exceptions here, the test itself catches them
 
         try:
             print("Running fuzz profit test")
             chain_config = LocalChain.Config(db_port=5436, chain_port=10003)
             fuzz_profit_check(chain_config)
         except FuzzAssertionException:
             pass
+        except Exception:  # pylint: disable=broad-except
+            print("Unexpected error:", sys.exc_info()[0])
 
         try:
             print("Running fuzz present value test")
@@ -66,6 +73,9 @@ def main(argv: Sequence[str] | None = None):
             fuzz_present_value(test_epsilon=present_value_epsilon, chain_config=chain_config)
         except FuzzAssertionException:
             pass
+        except Exception:  # pylint: disable=broad-except
+            print("Unexpected error:", sys.exc_info()[0])
+
         num_checks += 1
         if parsed_args.number_of_runs > 0 and num_checks >= parsed_args.number_of_runs:
             break

lib/hyperlogs/hyperlogs/rollbar_utilities.py

@@ -6,10 +6,10 @@
 import logging
 import os
 import platform
-import sys
 
 import rollbar
 from dotenv import load_dotenv
+from ethpy.base.errors import ContractCallException
 
 load_dotenv("rollbar.env")
 ROLLBAR_API_KEY = os.getenv("ROLLBAR_API_KEY")
@@ -67,7 +67,9 @@ def log_rollbar_message(message: str, log_level: int, extra_data: dict | None =
     rollbar.report_message(message, log_level_name, extra_data=extra_data)
 
 
-def log_rollbar_exception(exception: Exception, log_level: int, extra_data: dict | None = None):
+def log_rollbar_exception(
+    exception: Exception, log_level: int, extra_data: dict | None = None, rollbar_log_prefix: str | None = None
+):
     """Logs an exception to the rollbar service.
 
     Arguments
@@ -78,9 +80,15 @@ def log_rollbar_exception(exception: Exception, log_level: int, extra_data: dict
         The logging level enum value.
     extra_data: dict, optional.
         Extra data to send to rollbar. This usually contains the custom crash report json
+    rollbar_log_prefix: str, optional
+        The prefix to prepend to rollbar exception messages
     """
-    log_level_name = logging.getLevelName(log_level)
-    try:
-        raise exception
-    except Exception:  # pylint: disable=broad-exception-caught
-        rollbar.report_exc_info(sys.exc_info(), log_level_name, extra_data=extra_data)
+    log_level_name = logging.getLevelName(log_level).lower()
+    if rollbar_log_prefix is None:
+        log_message = ""
+    else:
+        log_message = rollbar_log_prefix + ": "
+    log_message += repr(exception)
+    if isinstance(exception, ContractCallException):
+        log_message += ": " + repr(exception.orig_exception)
+    rollbar.report_message(log_message, log_level_name, extra_data=extra_data)