422 introduce logged groups

.buildkite/steps/deploy-test.sh

@@ -52,7 +52,7 @@ function cleanup_docker {
     echo "\nRemoving temporary data volumes..."
     docker volume prune -f
 
-    if grep '\[E\] get_measurements' <measurements.log; then
+    if grep '\[ERROR\].*get_measurements' <measurements.log; then
         echo 'Failed to get measurements'
         exit 1
     fi

.dockerignore

@@ -9,6 +9,7 @@
 !run-test-faucet.sh
 !run-faucet.sh
 !run-airdropper.sh
+!log_cfg.json
 
 # Ignore __pycache__ directory
 proxy/__pycache__

Dockerfile

@@ -8,21 +8,22 @@ FROM neonlabsorg/evm_loader:${EVM_LOADER_REVISION} AS spl
 FROM ubuntu:20.04
 ARG PROXY_REVISION
 
-RUN apt update && \
-    DEBIAN_FRONTEND=noninteractive apt -y install \
-            software-properties-common openssl curl \
-            ca-certificates python3-pip python3-venv && \
-    rm -rf /var/lib/apt/lists/*
-
 COPY ./requirements.txt /opt
 COPY ./proxy/solana-py.patch /opt
+COPY ./log_cfg.json /opt
+
 WORKDIR /opt
 
-RUN python3 -m venv venv && \
+RUN apt update && \
+    DEBIAN_FRONTEND=noninteractive apt install -y git software-properties-common openssl curl \
+                                                  ca-certificates python3-pip python3-venv && \
+    python3 -m venv venv && \
     pip3 install --upgrade pip && \
     /bin/bash -c "source venv/bin/activate" && \
     pip install -r requirements.txt && \
-    pip install py-solc-x
+    apt remove -y git && \
+    pip install py-solc-x && \
+    rm -rf /var/lib/apt/lists/*
 
 COPY --from=cli /opt/solana/bin/solana \
                 /opt/solana/bin/solana-faucet \

log_cfg.json

@@ -0,0 +1,10 @@
+{
+  "format": "%(asctime)23s %(levelname)8s %(process)6d:%(threadName)-10s %(class)30s:%(class_id)-8s %(message)s",
+  "colored": false,
+  "logged_groups": {
+    "Indexer": "CRITICAL",
+    "Proxy": "DEBUG",
+    "Airdropper": "INFO",
+    "TestCases": "DEBUG"
+  }
+}

proxy/__main__.py

@@ -24,7 +24,6 @@
         wrapper_whitelist = os.environ['INDEXER_ERC20_WRAPPER_WHITELIST']
         if wrapper_whitelist != 'ANY':
             wrapper_whitelist = wrapper_whitelist.split(',')
-        log_level = os.environ['LOG_LEVEL']
         price_update_interval = int(os.environ.get('PRICE_UPDATE_INTERVAL', '60'))
         neon_decimals = int(os.environ.get('NEON_DECIMALS', '9'))
 
@@ -41,7 +40,6 @@
                        evm_loader_id,
                        faucet_url,
                        wrapper_whitelist,
-                       log_level,
                        price_update_interval,
                        neon_decimals,
                        start_slot)

proxy/common_neon/address.py

@@ -1,4 +1,3 @@
-import logging
 import random
 
 from eth_keys import keys as eth_keys
@@ -11,10 +10,6 @@
 from ..environment import neon_cli, ETH_TOKEN_MINT_ID, EVM_LOADER_ID
 from .constants import ACCOUNT_SEED_VERSION
 
-logger = logging.getLogger(__name__)
-logger.setLevel(logging.DEBUG)
-
-
 class EthereumAddress:
     def __init__(self, data, private=None):
         if isinstance(data, str):

proxy/common_neon/costs.py

@@ -1,9 +1,10 @@
 import base58
 import psycopg2
 
-from ..environment import EVM_LOADER_ID, WRITE_TRANSACTION_COST_IN_DB 
+from ..environment import EVM_LOADER_ID, WRITE_TRANSACTION_COST_IN_DB
 from ..indexer.sql_dict import POSTGRES_USER, POSTGRES_HOST, POSTGRES_DB, POSTGRES_PASSWORD
 
+
 class SQLCost():
     def __init__(self):
 

proxy/common_neon/emulator_interactor.py

@@ -1,23 +1,22 @@
 import json
-import logging
+from logged_groups import logged_group
 
 from typing import Optional, Dict, Any
 from .errors import EthereumError
 from ..environment import neon_cli, ETH_TOKEN_MINT_ID
 
-logger = logging.getLogger(__name__)
-logger.setLevel(logging.DEBUG)
 
-
-def call_emulated(contract_id, caller_id, data=None, value=None):
+@logged_group("Proxy")
+def call_emulated(contract_id, caller_id, data=None, value=None, *, logger):
     output = emulator(contract_id, caller_id, data, value)
     logger.debug(f"Call emulated. contract_id: {contract_id}, caller_id: {caller_id}, data: {data}, value: {value}, return: {output}")
     result = json.loads(output)
     check_emulated_exit_status(result)
     return result
 
 
-def check_emulated_exit_status(result: Dict[str, Any]):
+@logged_group("Proxy")
+def check_emulated_exit_status(result: Dict[str, Any], *, logger):
     exit_status = result['exit_status']
     if exit_status == 'revert':
         revert_data = result['result']
@@ -33,7 +32,8 @@ def check_emulated_exit_status(result: Dict[str, Any]):
         raise Exception("evm emulator error ", result)
 
 
-def decode_revert_message(data: str) -> Optional[str]:
+@logged_group("Proxy")
+def decode_revert_message(data: str, *, logger) -> Optional[str]:
     data_len = len(data)
     if data_len == 0:
         return None

proxy/common_neon/erc20_wrapper.py

@@ -12,10 +12,8 @@
 from solana.transaction import Transaction
 import spl.token.instructions as spl_token
 from typing import Union, Dict
-from logging import getLogger
 import struct
-
-logger = getLogger('__name__')
+from logged_groups import logged_group
 
 install_solc(version='0.7.6')
 from solcx import compile_source
@@ -78,6 +76,8 @@
 }
 '''
 
+
+@logged_group("Proxy")
 class ERC20Wrapper:
     proxy: Web3
     name: str
@@ -124,10 +124,10 @@ def deploy_wrapper(self):
         tx_constructor = erc20.constructor(self.name, self.symbol, bytes(self.token.pubkey)).buildTransaction(tx)
         tx_deploy = self.proxy.eth.account.sign_transaction(tx_constructor, self.admin.key)
         tx_deploy_hash = self.proxy.eth.send_raw_transaction(tx_deploy.rawTransaction)
-        logger.debug(f'tx_deploy_hash: {tx_deploy_hash.hex()}')
+        self.debug(f'tx_deploy_hash: {tx_deploy_hash.hex()}')
         tx_deploy_receipt = self.proxy.eth.wait_for_transaction_receipt(tx_deploy_hash)
-        logger.debug(f'tx_deploy_receipt: {tx_deploy_receipt}')
-        logger.debug(f'deploy status: {tx_deploy_receipt.status}')
+        self.debug(f'tx_deploy_receipt: {tx_deploy_receipt}')
+        self.debug(f'deploy status: {tx_deploy_receipt.status}')
         self.neon_contract_address = tx_deploy_receipt.contractAddress
         self.solana_contract_address = self.get_neon_account_address(self.neon_contract_address)
 

proxy/common_neon/neon_instruction.py

@@ -1,5 +1,4 @@
 import eth_utils
-import logging
 import struct
 
 from sha3 import keccak_256
@@ -11,17 +10,14 @@
 from spl.token.constants import ASSOCIATED_TOKEN_PROGRAM_ID, TOKEN_PROGRAM_ID
 from spl.token.instructions import transfer2, Transfer2Params
 from typing import Tuple
+from logged_groups import logged_group
 
 from .address import accountWithSeed, ether2program, getTokenAddr, EthereumAddress
 from .constants import SYSVAR_INSTRUCTION_PUBKEY, INCINERATOR_PUBKEY, KECCAK_PROGRAM, COLLATERALL_POOL_MAX
 from .layouts import CREATE_ACCOUNT_LAYOUT
 from ..environment import EVM_LOADER_ID, ETH_TOKEN_MINT_ID , COLLATERAL_POOL_BASE, NEW_USER_AIRDROP_AMOUNT
 
 
-logger = logging.getLogger(__name__)
-logger.setLevel(logging.DEBUG)
-
-
 obligatory_accounts = [
     AccountMeta(pubkey=EVM_LOADER_ID, is_signer=False, is_writable=False),
     AccountMeta(pubkey=TOKEN_PROGRAM_ID, is_signer=False, is_writable=False),
@@ -83,12 +79,12 @@ def make_keccak_instruction_data(check_instruction_index, msg_len, data_start):
     return data
 
 
+@logged_group("Proxy")
 class NeonInstruction:
     def __init__(self, operator):
         self.operator_account = operator
         self.operator_neon_address = getTokenAddr(self.operator_account)
 
-
     def init_eth_trx(self, eth_trx, eth_accounts, caller_token):
         self.eth_accounts = eth_accounts
         self.caller_token = caller_token
@@ -104,7 +100,6 @@ def init_eth_trx(self, eth_trx, eth_accounts, caller_token):
 
         return self
 
-
     def init_iterative(self, storage, holder, perm_accs_id):
         self.storage = storage
         self.holder = holder
@@ -118,10 +113,9 @@ def create_collateral_pool_address(collateral_pool_index):
         seed = COLLATERAL_SEED_PREFIX + str(collateral_pool_index)
         return accountWithSeed(PublicKey(COLLATERAL_POOL_BASE), str.encode(seed))
 
-
     def create_account_with_seed_trx(self, account, seed, lamports, space):
         seed_str = str(seed, 'utf8')
-        logger.debug("createAccountWithSeedTrx base(%s) account(%s) seed(%s)", type(self.operator_account),account, seed_str)
+        self.debug("createAccountWithSeedTrx base(%s) account(%s) seed(%s)", type(self.operator_account),account, seed_str)
         return TransactionInstruction(
             keys=[
                 AccountMeta(pubkey=self.operator_account, is_signer=True, is_writable=True),
@@ -132,11 +126,10 @@ def create_account_with_seed_trx(self, account, seed, lamports, space):
             data=create_account_with_seed_layout(self.operator_account, seed_str, lamports, space)
         )
 
-
     def make_create_eth_account_trx(self, eth_address: EthereumAddress, code_acc=None) -> Tuple[Transaction, PublicKey]:
         pda_account, nonce = ether2program(eth_address)
         neon_token_account = getTokenAddr(PublicKey(pda_account))
-        logger.debug(f'Create eth account: {eth_address}, sol account: {pda_account}, neon_token_account: {neon_token_account}, nonce: {nonce}')
+        self.debug(f'Create eth account: {eth_address}, sol account: {pda_account}, neon_token_account: {neon_token_account}, nonce: {nonce}')
 
         base = self.operator_account
         data = create_account_layout(0, 0, bytes(eth_address), nonce)
@@ -172,7 +165,6 @@ def make_create_eth_account_trx(self, eth_address: EthereumAddress, code_acc=Non
                 ]))
         return trx, neon_token_account
 
-
     def createERC20TokenAccountTrx(self, token_info) -> Transaction:
         trx = Transaction()
         trx.add(TransactionInstruction(
@@ -192,7 +184,6 @@ def createERC20TokenAccountTrx(self, token_info) -> Transaction:
 
         return trx
 
-
     def make_transfer_instruction(self, associated_token_account: PublicKey) -> TransactionInstruction:
         transfer_instruction = transfer2(Transfer2Params(
             source=self.operator_neon_address,
@@ -203,11 +194,10 @@ def make_transfer_instruction(self, associated_token_account: PublicKey) -> Tran
             mint=ETH_TOKEN_MINT_ID,
             program_id=TOKEN_PROGRAM_ID
         ))
-        logger.debug(f"Token transfer from token: {self.operator_neon_address}, owned by: {self.operator_account}, to token: "
+        self.debug(f"Token transfer from token: {self.operator_neon_address}, owned by: {self.operator_account}, to token: "
                     f"{associated_token_account}, owned by: {associated_token_account} , value: {NEW_USER_AIRDROP_AMOUNT}")
         return transfer_instruction
 
-
     def make_trx_with_create_and_airdrop(self, eth_account, code_acc=None) -> Transaction:
         trx = Transaction()
         create_trx, associated_token_account = self.make_create_eth_account_trx(eth_account, code_acc)
@@ -219,7 +209,6 @@ def make_trx_with_create_and_airdrop(self, eth_account, code_acc=None) -> Transa
 
         return trx
 
-
     def make_resize_instruction(self, acc_desc, code_account_new, seed) -> TransactionInstruction:
         return TransactionInstruction(
             program_id = EVM_LOADER_ID,
@@ -236,7 +225,6 @@ def make_resize_instruction(self, acc_desc, code_account_new, seed) -> Transacti
             ],
         )
 
-
     def make_write_transaction(self, offset: int, data: bytes) -> Transaction:
         return Transaction().add(TransactionInstruction(
             program_id=EVM_LOADER_ID,
@@ -247,7 +235,6 @@ def make_write_transaction(self, offset: int, data: bytes) -> Transaction:
             ]
         ))
 
-
     def make_keccak_instruction(self, check_instruction_index, msg_len, data_start) -> TransactionInstruction:
         return TransactionInstruction(
             program_id=KECCAK_PROGRAM,
@@ -257,7 +244,6 @@ def make_keccak_instruction(self, check_instruction_index, msg_len, data_start)
             ]
         )
 
-
     def make_05_call_instruction(self) -> TransactionInstruction:
         return TransactionInstruction(
             program_id = EVM_LOADER_ID,
@@ -273,14 +259,12 @@ def make_05_call_instruction(self) -> TransactionInstruction:
             ] + self.eth_accounts + obligatory_accounts
         )
 
-
     def make_noniterative_call_transaction(self, length_before: int = 0) -> Transaction:
         trx = Transaction()
         trx.add(self.make_keccak_instruction(length_before + 1, len(self.eth_trx.unsigned_msg()), 5))
         trx.add(self.make_05_call_instruction())
         return trx
 
-
     def make_cancel_transaction(self) -> Transaction:
         return Transaction().add(TransactionInstruction(
             program_id = EVM_LOADER_ID,
@@ -299,7 +283,6 @@ def make_cancel_transaction(self) -> Transaction:
             ] + obligatory_accounts
         ))
 
-
     def make_partial_call_or_continue_instruction(self, steps: int = 0) -> TransactionInstruction:
         data = bytearray.fromhex("0D") + self.collateral_pool_index_buf + steps.to_bytes(8, byteorder="little") + self.msg
         return TransactionInstruction(
@@ -321,14 +304,12 @@ def make_partial_call_or_continue_instruction(self, steps: int = 0) -> Transacti
             ] + obligatory_accounts
         )
 
-
     def make_partial_call_or_continue_transaction(self, steps: int = 0, length_before: int = 0) -> Transaction:
         trx = Transaction()
         trx.add(self.make_keccak_instruction(length_before + 1, len(self.eth_trx.unsigned_msg()), 13))
         trx.add(self.make_partial_call_or_continue_instruction(steps))
         return trx
 
-
     def make_partial_call_or_continue_from_account_data(self, steps, index=None) -> Transaction:
         data = bytearray.fromhex("0E") + self.collateral_pool_index_buf + steps.to_bytes(8, byteorder='little')
         if index: