Skip to content

Commit

Permalink
[#651] Introduce logging for tezos voting wizard
Browse files Browse the repository at this point in the history 
Problem: Currently tezos-vote doesn't save any logs,
which could be useful for debugging.

Solution: Introduce logging of the error and steps taken by
the user.
  • Loading branch information
@krendelhoff2
krendelhoff2 committed Oct 19, 2023
1 parent 91facd9 commit 05b0dde
Showing 1 changed file with 47 additions and 9 deletions.
56 changes: 47 additions & 9 deletions baking/src/tezos_baking/tezos_voting_wizard.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@

import os, sys
import readline
import logging
import re

from tezos_baking.wizard_structure import *
Expand Down Expand Up @@ -74,6 +75,7 @@
# we don't need any data here, just a confirmation that a Tezos app is open
# `app_name` here can only be `"Wallet"` or `"Baking"`
def wait_for_ledger_app(app_name, client_dir):
logging.info(f"Waiting for the ledger {app_name} app to be opened")
print(f"Please make sure the Tezos {app_name} app is open on your ledger.")
print()
search_string = b"Found a Tezos " + bytes(app_name, "utf8")
Expand Down Expand Up @@ -203,22 +205,31 @@ def check_baking_service(self):
print("If there should be, you can run 'tezos-setup' to set it up.")
print()
self.config["is_local_baking_setup"] = False
finally:
running = self.config["is_local_baking_setup"]
logging.info(f"The baking services are {'' if running else 'not'} running")

def check_data_correctness(self):
logging.info("Querying data correctness")
print("Baker data detected is as follows:")
print(f"Data directory: {self.config['client_data_dir']}")
print(f"Node RPC endpoint: {self.config['node_rpc_endpoint']}")
print(f"Voter key: {self.config['baker_key_value']}")
return yes_or_no("Does this look correct? (Y/n) ", "yes")
answer = yes_or_no("Does this look correct? (Y/n) ", "yes")
logging.info(f"Answer is {answer}")
return answer

def search_client_config(self, field, default):
logging.info("Searching client config")
config_filepath = os.path.join(self.config["client_data_dir"], "config")
if not os.path.isfile(config_filepath):
return default
else:
return search_json_with_default(config_filepath, field, default)

def collect_baking_info(self):
logging.info("Collecting baking info")
logging.info("Checking the local baking services")
self.check_baking_service()
if self.config.get("is_local_baking_setup", False):
self.fill_baking_config()
Expand All @@ -234,6 +245,7 @@ def collect_baking_info(self):

network_dir = "/var/lib/tezos/client-" + self.config["network"]

logging.info("Creating the network dir")
proc_call(f"sudo -u tezos mkdir -p {network_dir}")

print("With no tezos-baking.service running, this wizard will use")
Expand Down Expand Up @@ -283,28 +295,30 @@ def get_baker_key(self):
value, _ = baker_key_value
self.config["baker_key_value"] = value
else: # if there is no key with this alias, query import
logging.info("No secret key found")
key_mode_query = get_key_mode_query(key_import_modes)
self.import_key(key_mode_query, "Wallet")

def get_network(self):
logging.info("Getting network")
if parsed_args.network in networks.keys():
self.config["network"] = parsed_args.network
else:
# TODO: maybe check/validate this
self.config["network"] = "custom@" + parsed_args.network

def fill_voting_period_info(self):
logging.info("Filling in voting period info")
logging.info("Getting voting period from octez-client")
voting_proc = get_proc_output(
f"sudo -u tezos {suppress_warning_text} octez-client "
f"{self.config['tezos_client_options']} show voting period"
)
if voting_proc.returncode == 0:
info = voting_proc.stdout
else:
print(
"Couldn't get the voting period info. Please check that the network",
"for voting has been set up correctly.",
)
print_and_log("Couldn't get the voting period info.", logging.error)
print("Please check that the network for voting has been set up correctly.")
raise KeyboardInterrupt

self.config["amendment_phase"] = (
Expand All @@ -315,13 +329,15 @@ def fill_voting_period_info(self):
]

def process_proposal_period(self):
logging.info("Processing proposal period")
self.query_step(get_proposal_period_hash(self.config["proposal_hashes"]))

hash_to_submit = self.config["chosen_hash"]
if hash_to_submit == "Specify new proposal hash":
self.query_step(new_proposal_query)
hash_to_submit = self.config["new_proposal_hash"]

logging.info("Submitting proposals")
result = get_proc_output(
f"sudo -u tezos {suppress_warning_text} octez-client {self.config['tezos_client_options']} "
f"submit proposals for {self.config['baker_alias']} {hash_to_submit}"
Expand All @@ -331,18 +347,23 @@ def process_proposal_period(self):
print()

if re.search(b"[Ii]nvalid proposal", result.stderr) is not None:
logging.error("The submitted proposal hash is invalid")
print(color("The submitted proposal hash is invalid.", color_red))
print("Check your custom submitted proposal hash and try again.")
self.process_proposal_period()
return
elif re.search(b"Unauthorized proposal", result.stderr) is not None:
logging.error("Cannot submit because of an unauthorized proposal.")
print(
color(
"Cannot submit because of an unauthorized proposal.", color_red
)
)
print("This means you are not present in the voting listings.")
elif re.search(b"Not in a proposal period", result.stderr) is not None:
logging.error(
"Cannot submit because the voting period is no longer 'proposal'."
)
print(
color(
"Cannot submit because the voting period is no longer 'proposal'.",
Expand All @@ -351,6 +372,7 @@ def process_proposal_period(self):
)
print("This means the voting period has already advanced.")
elif re.search(b"Too many proposals", result.stderr) is not None:
logging.error("Cannot submit because of too many proposals submitted.")
print(
color(
"Cannot submit because of too many proposals submitted.",
Expand All @@ -361,6 +383,7 @@ def process_proposal_period(self):
# No other "legitimate" proposal error ('empty_proposal', 'unexpected_proposal')
# should be possible with the wizard, so we just raise an error with the whole output.
else:
logging.error("Something went wrong when calling octez-client")
print(
"Something went wrong when calling octez-client. Please consult the logs."
)
Expand All @@ -369,13 +392,15 @@ def process_proposal_period(self):
print("Please check your baker data and possibly try again.")

def process_voting_period(self):
logging.info("Processing voting period")
print("The current proposal is:")
# there's only one in any voting (exploration/promotion) period
print(self.config["proposal_hashes"][0])
print()

self.query_step(ballot_outcome_query)

logging.info("Submitting ballot")
result = get_proc_output(
f"sudo -u tezos {suppress_warning_text} octez-client {self.config['tezos_client_options']} "
f"submit ballot for {self.config['baker_alias']} {self.config['proposal_hashes'][0]} "
Expand All @@ -388,6 +413,7 @@ def process_voting_period(self):
# both when the baker has already voted and when the baker was not in the voting listings
# in the first place, so it's difficult to distinguish between the two cases.
if re.search(b"Unauthorized ballot", result.stderr) is not None:
logging.error("Cannot vote because of an unauthorized ballot")
print()
print(
color("Cannot vote because of an unauthorized ballot.", color_red)
Expand All @@ -401,6 +427,9 @@ def process_voting_period(self):
re.search(b"Not in Exploration or Promotion period", result.stderr)
is not None
):
logging.error(
f"Cannot vote because the voting period is no longer '{self.config['amendment_phase']}'"
)
print()
print(
color("Cannot vote because the voting period is", color_red),
Expand All @@ -412,6 +441,7 @@ def process_voting_period(self):
# No other "legitimate" voting error ('invalid_proposal', 'unexpected_ballot')
# should be possible with the wizard, so we just raise an error with the whole output.
else:
logging.error("Something went wrong when calling octez-client")
print(
"Something went wrong when calling octez-client. Please consult the logs."
)
Expand All @@ -434,7 +464,7 @@ def run_voting(self):
# process 'tezos-client show voting period'
self.fill_voting_period_info()

print(
print_and_log(
f"The amendment is currently in the {self.config['amendment_phase']} period."
)
if self.config["amendment_phase"] == "proposal":
Expand All @@ -452,15 +482,15 @@ def run_voting(self):
print()
self.process_voting_period()
else:
print("Voting isn't possible at the moment.")
print("Exiting the Tezos Voting Wizard.")
print_and_log("Voting isn't possible at the moment.")
print_and_log("Exiting the Tezos Voting Wizard.")

# if a ledger was used for baking on this machine, ask to open Tezos Baking app on it,
# then restart the relevant baking service (due to issue: tezos/#4486)
if self.config.get("is_local_baking_setup", False) and self.check_ledger_use():
wait_for_ledger_app("Baking", self.config["client_data_dir"])
net = self.config["network"]
print(f"Restarting local {net} baking setup")
print_and_log(f"Restarting local {net} baking setup")
proc_call(f"sudo systemctl restart tezos-baking-{net}.service")

print()
Expand All @@ -472,16 +502,24 @@ def main():
readline.set_completer_delims(" ")

try:
setup_logger("tezos-vote.log")
logging.info("Starting the Tezos Voting Wizard.")
setup = Setup()
setup.run_voting()
except KeyboardInterrupt:
print("Exiting the Tezos Voting Wizard.")
logging.info(f"Received keyboard interrupt.")
logging.info("Exiting the Tezos Voting Wizard.")
sys.exit(1)
except EOFError:
print("Exiting the Tezos Voting Wizard.")
logging.error(f"Reached EOF.")
logging.info("Exiting the Tezos Voting Wizard.")
sys.exit(1)
except Exception as e:
print("Error in Tezos Voting Wizard, exiting.")
logging.error(f"{str(e)}")
logging.info("Exiting the Tezos Voting Wizard.")
logfile = "tezos_vote.log"
with open(logfile, "a") as f:
f.write(str(e) + "\n")
Expand Down

0 comments on commit 05b0dde

Please sign in to comment.