Bug #783 Chaum Pederson Bug (#784)

* get ballots with individual queries and with retry logic

* more logging

* More UI status updates when loading ballots

* fix linting in mongo-init

* Be more defensive while deserializing ballots

* Better UI on decryption error

* fix linting issues

Author: lprichar

src/electionguard_db/mongo-init.js

@@ -5,10 +5,10 @@ db.createCollection("ballot_uploads");
 db.createCollection("decryptions");
 db.createCollection("db_deltas", { capped: true, size: 100000 });
 db.db_deltas.insert({ type: "init" });
-db.ballot_uploads.createIndex({election_id: 1});
-db.ballot_uploads.createIndex({election_id: 1, object_id: 1});
-db.decryptions.createIndex({decryption_name: 1});
-db.decryptions.createIndex({election_id: 1});
-db.decryptions.createIndex({completed_at: 1});
-db.key_ceremonies.createIndex({completed_at: 1});
-db.key_ceremonies.createIndex({key_ceremony_name: 1});
+db.ballot_uploads.createIndex({ election_id: 1 });
+db.ballot_uploads.createIndex({ election_id: 1, object_id: 1 });
+db.decryptions.createIndex({ decryption_name: 1 });
+db.decryptions.createIndex({ election_id: 1 });
+db.decryptions.createIndex({ completed_at: 1 });
+db.key_ceremonies.createIndex({ completed_at: 1 });
+db.key_ceremonies.createIndex({ key_ceremony_name: 1 });

src/electionguard_gui/__init__.py

@@ -93,6 +93,7 @@
     KeyCeremonyStateService,
     MODE_KEY,
     PORT_KEY,
+    RetryException,
     ServiceBase,
     VersionService,
     announce_guardians,
@@ -140,7 +141,6 @@
     service_base,
     status_descriptions,
     to_ballot_share_raw,
-    update_decrypt_status,
     verification_to_dict,
     version_service,
 )
@@ -194,6 +194,7 @@
     "MODE_KEY",
     "MainApp",
     "PORT_KEY",
+    "RetryException",
     "ServiceBase",
     "UploadBallotsComponent",
     "VersionService",
@@ -273,7 +274,6 @@
     "start",
     "status_descriptions",
     "to_ballot_share_raw",
-    "update_decrypt_status",
     "update_upload_status",
     "upload_ballots_component",
     "utc_to_str",

src/electionguard_gui/components/export_election_record_component.py

@@ -59,7 +59,9 @@ def export_election_record(
         manifest = election.get_manifest()
         constants = get_constants()
         encryption_devices = election.get_encryption_devices()
-        submitted_ballots = self._ballot_upload_service.get_ballots(db, election.id)
+        submitted_ballots = self._ballot_upload_service.get_ballots(
+            db, election.id, lambda x: None
+        )
         plaintext_tally = decryption.get_plaintext_tally()
         spoiled_ballots = decryption.get_plaintext_spoiled_ballots()
         lagrange_coefficients = decryption.get_lagrange_coefficients()

src/electionguard_gui/services/__init__.py

@@ -24,6 +24,7 @@
 )
 from electionguard_gui.services.ballot_upload_service import (
     BallotUploadService,
+    RetryException,
 )
 from electionguard_gui.services.configuration_service import (
     ConfigurationService,
@@ -58,7 +59,6 @@
     decryption_s2_announce_service,
     decryption_stage_base,
     get_tally,
-    update_decrypt_status,
 )
 from electionguard_gui.services.directory_service import (
     DOCKER_MOUNT_DIR,
@@ -149,6 +149,7 @@
     "KeyCeremonyStateService",
     "MODE_KEY",
     "PORT_KEY",
+    "RetryException",
     "ServiceBase",
     "VersionService",
     "announce_guardians",
@@ -196,7 +197,6 @@
     "service_base",
     "status_descriptions",
     "to_ballot_share_raw",
-    "update_decrypt_status",
     "verification_to_dict",
     "version_service",
 ]

src/electionguard_gui/services/ballot_upload_service.py

@@ -1,4 +1,6 @@
 from datetime import datetime
+from time import sleep
+from typing import Callable
 from pymongo.database import Database
 from electionguard.ballot import SubmittedBallot
 from electionguard.serialize import from_raw
@@ -76,19 +78,81 @@ def any_ballot_exists(self, db: Database, election_id: str, object_id: str) -> b
             > 0
         )
 
-    def get_ballots(self, db: Database, election_id: str) -> list[SubmittedBallot]:
+    def get_ballots(
+        self, db: Database, election_id: str, report_status: Callable[[str], None]
+    ) -> list[SubmittedBallot]:
         self._log.debug(f"getting ballots for {election_id}")
-        ballot_uploads = db.ballot_uploads.find(
-            {"election_id": election_id, "file_contents": {"$exists": True}}
+        ballot_uploads = list(
+            db.ballot_uploads.find(
+                {"election_id": election_id, "file_contents": {"$exists": True}},
+                projection={"_id": 1, "file_contents": 0},
+            )
         )
         ballots = []
-        for ballot_obj in ballot_uploads:
-            ballot_str = ballot_obj["file_contents"]
+        total_ballots = len(ballot_uploads)
+        ballot_num = 1
+        for ballot_id_obj in ballot_uploads:
+            ballot_id = ballot_id_obj["_id"]
+            report_status(f"Loading ballot {ballot_num}/{total_ballots}")
             try:
-                ballot = from_raw(SubmittedBallot, ballot_str)
+                ballot = self.get_submitted_ballot_with_retry(db, ballot_id)
                 ballots.append(ballot)
             # pylint: disable=broad-except
             except Exception as e:
-                self._log.error("error deserializing ballot: {ballot_obj}", e)
+                self._log.error(
+                    f"Error deserializing ballot {ballot_id}. "
+                    + "Skipping ballot, but this may cause Chaum Pederson errors later.",
+                    e,
+                )
                 # per RC 8/15/22 log errors and continue processing even if it makes numbers incorrect
+            ballot_num += 1
         return ballots
+
+    def get_submitted_ballot_with_retry(
+        self, db: Database, ballot_upload_id: str
+    ) -> SubmittedBallot:
+        retry_num = 0
+        max_retries = 3
+        while retry_num < max_retries:
+            try:
+                return self.get_submitted_ballot(db, ballot_upload_id)
+            except RetryException:
+                self._log.warn(
+                    f"retrying get ballot {ballot_upload_id} in {retry_num + 1} second(s). Retry #{retry_num + 1}"
+                )
+                # wait 1 second before retrying in case network was slow
+                sleep(retry_num + 1)
+            retry_num += 1
+        raise Exception(
+            f"Failed to get ballot {ballot_upload_id} after {max_retries} retries"
+        )
+
+    def get_submitted_ballot(
+        self, db: Database, ballot_upload_id: str
+    ) -> SubmittedBallot:
+        self._log.trace(f"getting submitted ballot {ballot_upload_id}")
+        ballot_obj = None
+        try:
+            ballot_obj = db.ballot_uploads.find_one(
+                {"_id": ballot_upload_id}, projection={"file_contents": 1}
+            )
+        except Exception as e:
+            self._log.error(f"mongo error getting ballot {ballot_upload_id}", e)
+            raise RetryException from e
+        if ballot_obj is None:
+            raise Exception(f"Ballot {ballot_upload_id} not found")
+        ballot_str = ballot_obj["file_contents"]
+        # if ballot_str ends with a }
+        if not ballot_str[-1] == "}":
+            self._log.warn(f"ballot {ballot_upload_id} is missing a closing bracket")
+            raise RetryException
+        try:
+            ballot = from_raw(SubmittedBallot, ballot_str)
+        except Exception as e:
+            self._log.error(f"error deserializing ballot {ballot_upload_id}", e)
+            raise RetryException from e
+        return ballot
+
+
+class RetryException(Exception):
+    """An exception to notify the caller to retry"""

src/electionguard_gui/services/decryption_stages/__init__.py

@@ -7,7 +7,6 @@
 )
 from electionguard_gui.services.decryption_stages.decryption_s2_announce_service import (
     DecryptionS2AnnounceService,
-    update_decrypt_status,
 )
 from electionguard_gui.services.decryption_stages.decryption_stage_base import (
     DecryptionStageBase,
@@ -22,5 +21,4 @@
     "decryption_s2_announce_service",
     "decryption_stage_base",
     "get_tally",
-    "update_decrypt_status",
 ]

src/electionguard_gui/services/decryption_stages/decryption_s1_join_service.py

@@ -13,7 +13,7 @@ class DecryptionS1JoinService(DecryptionStageBase):
     """Responsible for the 1st stage during a decryption were guardians join the decryption"""
 
     def run(self, db: Database, decryption: DecryptionDto) -> None:
-        update_decrypt_status("Starting tally")
+        _update_decrypt_status("Starting tally")
         current_user_id = self._auth_service.get_required_user_id()
         self._log.info(f"S1: {current_user_id} decrypting  {decryption.decryption_id}")
         election = self._election_service.get(db, decryption.election_id)
@@ -23,14 +23,19 @@ def run(self, db: Database, decryption: DecryptionDto) -> None:
         guardian = self._guardian_service.load_guardian_from_decryption(
             current_user_id, decryption
         )
-        ballots = self._ballot_upload_service.get_ballots(db, election.id)
-        update_decrypt_status("Calculating tally")
+        ballots = self._ballot_upload_service.get_ballots(
+            db, election.id, _update_decrypt_status
+        )
+        _update_decrypt_status("Calculating tally")
+        self._log.debug(f"getting tally for {len(ballots)} ballots")
         ciphertext_tally = get_tally(manifest, context, ballots, False)
+        self._log.debug("computing tally share")
         decryption_share = guardian.compute_tally_share(ciphertext_tally, context)
         if decryption_share is None:
             raise Exception("No decryption_shares found")
 
-        update_decrypt_status("Calculating spoiled ballots")
+        _update_decrypt_status("Calculating spoiled ballots")
+        self._log.debug("decrypting spoiled ballots")
         spoiled_ballots = [
             ballot for ballot in ballots if ballot.state == BallotBoxState.SPOILED
         ]
@@ -39,7 +44,7 @@ def run(self, db: Database, decryption: DecryptionDto) -> None:
             raise Exception("No ballot shares found")
         guardian_key = guardian.share_key()
 
-        update_decrypt_status("Finalizing tally")
+        _update_decrypt_status("Finalizing tally")
         self._decryption_service.append_guardian_joined(
             db,
             decryption.decryption_id,
@@ -48,9 +53,10 @@ def run(self, db: Database, decryption: DecryptionDto) -> None:
             ballot_shares,
             guardian_key,
         )
+        self._log.debug("Completed tally")
         self._decryption_service.notify_changed(db, decryption.decryption_id)
 
 
-def update_decrypt_status(status: str) -> None:
+def _update_decrypt_status(status: str) -> None:
     # pylint: disable=no-member
     eel.update_decrypt_status(status)

src/electionguard_gui/services/decryption_stages/decryption_s2_announce_service.py

@@ -20,7 +20,7 @@ def should_run(self, db: Database, decryption: DecryptionDto) -> bool:
         return is_admin and all_guardians_joined and not is_completed
 
     def run(self, db: Database, decryption: DecryptionDto) -> None:
-        update_decrypt_status("Starting tally")
+        _update_decrypt_status("Starting tally")
         self._log.info(f"S2: Announcing decryption {decryption.decryption_id}")
         election = self._election_service.get(db, decryption.election_id)
         context = election.get_context()
@@ -33,7 +33,7 @@ def run(self, db: Database, decryption: DecryptionDto) -> None:
         share_count = len(decryption_shares)
         current_share = 1
         for decryption_share_dict in decryption_shares:
-            update_decrypt_status(f"Calculating share {current_share}/{share_count}")
+            _update_decrypt_status(f"Calculating share {current_share}/{share_count}")
             self._log.debug(f"announcing {decryption_share_dict.guardian_id}")
             guardian_sequence_number = election.get_guardian_sequence_order(
                 decryption_share_dict.guardian_id
@@ -48,12 +48,15 @@ def run(self, db: Database, decryption: DecryptionDto) -> None:
             )
             current_share += 1
 
-        update_decrypt_status("Decrypting spoiled ballots")
         manifest = election.get_manifest()
-        ballots = self._ballot_upload_service.get_ballots(db, election.id)
+        ballots = self._ballot_upload_service.get_ballots(
+            db, election.id, _update_decrypt_status
+        )
         spoiled_ballots = [
             ballot for ballot in ballots if ballot.state == BallotBoxState.SPOILED
         ]
+        _update_decrypt_status("Calculating tally")
+        self._log.debug(f"getting tally for {len(ballots)} ballots")
         ciphertext_tally = get_tally(manifest, context, ballots, False)
         self._log.debug("getting plaintext tally")
         plaintext_tally = decryption_mediator.get_plaintext_tally(
@@ -62,13 +65,14 @@ def run(self, db: Database, decryption: DecryptionDto) -> None:
         if plaintext_tally is None:
             raise Exception("No plaintext tally found")
         self._log.debug("getting plaintext spoiled ballots")
+        _update_decrypt_status("Processing spoiled ballots")
         plaintext_spoiled_ballots = decryption_mediator.get_plaintext_ballots(
             spoiled_ballots, manifest
         )
         if plaintext_spoiled_ballots is None:
             raise Exception("No plaintext spoiled ballots found")
 
-        update_decrypt_status("Finalizing tally")
+        _update_decrypt_status("Finalizing tally")
 
         lagrange_coefficients = _get_lagrange_coefficients(decryption_mediator)
 
@@ -91,6 +95,6 @@ def _get_lagrange_coefficients(
     return LagrangeCoefficientsRecord(decryption_mediator.get_lagrange_coefficients())
 
 
-def update_decrypt_status(status: str) -> None:
+def _update_decrypt_status(status: str) -> None:
     # pylint: disable=no-member
     eel.update_decrypt_status(status)

src/electionguard_gui/web/components/admin/view-decryption-admin-component.js

@@ -35,6 +35,9 @@ export default {
       } else {
         console.error(result.message);
         this.error = true;
+        this.loading = false;
+        this.status = null;
+        this.decryption = null;
       }
     },
     get_decryption: async function (is_refresh) {
@@ -45,17 +48,17 @@ export default {
           this.decryptionId,
           is_refresh
         )();
+        console.log("get_decryption complete", result);
         this.error = !result.success;
-        if (result.success) {
-          this.decryption = result.result;
-        }
+        this.decryption = result.success ? result.result : null;
+      } catch (error) {
+        console.error(error);
       } finally {
         this.loading = false;
         this.status = null;
       }
     },
     updateDecryptStatus: function (status) {
-      console.log("updateDecryptStatus", status);
       this.status = status;
     },
   },
@@ -75,7 +78,7 @@ export default {
   },
   template: /*html*/ `
     <div v-if="error">
-      <p class="alert alert-danger" role="alert">An error occurred. Check the logs and try again.</p>
+      <p class="alert alert-danger" role="alert">An error occurred. Check the logs and/or <a href="javascript:history.back()">try again</a>.</p>
     </div>
     <div v-if="decryption">
       <div class="text-end">