[BUG] Unable to sync after restarting while order cancelation pending

[ndorf]

Summary

After restarting Augur, I'm unable to sync any newer blocks. I'm guessing this is somehow caused by the fact that I had an order cancellation pending when I stopped it, and that transaction was confirmed before it started back up again.

Steps to reproduce

Unfortunately, I can't tell if this is even reproducible or not, because I haven't been able to get back to a synced state since this occurred. However, this is the sequence of events:

1. I canceled one or more orders in the Augur UI
2. While those cancel transaction(s) were still pending (unconfirmed by the Ethereum network), I stopped the Augur app (in order to upgrade to 1.8.6).
3. While the Augur app wasn't running, the cancellations were confirmed
4. After restarting, there is no progress in syncing. The last synced block never changes, but the current block and # of blocks behind do. The Augur app prints the same series of messages on the terminal, apparently indefinitely.
5. Among these errors printed on the terminal is one mentioning a specific orderId -- I don't know how to confirm whether or not that is one of the orders I canceled, though.

6. Downgrading to versions 1.8.5 and 1.8.3 had no effect, nor did switching from Local Light Node to Mainnet (Alchemy).

   Expected behavior

   Sync as normal.

   Screenshots

   The following sequence of message repeats indefinitely in the Augur app's terminal output:

   
   [18:07:18.301] [info] Starting Server
   [18:07:18.302] [info] 1000 3 2000
   connecting to augur-node: undefined
   connecting to ethereum-node: {"http":"https://eth-mainnet.alchemyapi.io/jsonrpc/<elided api key>","ws":""}
   connected to ethereum
   [18:07:19.559] [info] Found prior database: /home/ndorf/.augur/augur-1-2.db
   [18:07:19.560] [info] /home/ndorf/.augur/augur-1-2.db
   [18:07:19.776] [info] Sync with blockchain started.
   [18:07:19.777] [info] Starting websocket secure server on port 9002
   [18:07:19.779] [info] Starting websocket server on port 9001
   [18:07:20.081] [info] Getting Augur logs from block 6945332 to block 6965193
   got 367 logs in blocks { fromBlock: 6945332, toBlock: 6945752 }
   Fetching blocks details from 6945348 to 6945693
   got 43 logs in blocks { fromBlock: 6945753, toBlock: 6946472 }
   Fetching blocks details from 6945765 to 6946456
   got 58 logs in blocks { fromBlock: 6946473, toBlock: 6947192 }
   [18:07:21.707] [info] new block: 6945348, 1545669947 (Mon Dec 24 2018 09:45:47 GMT-0700 (MST))
   [18:07:21.722] [info] Processing 8 logs
   [18:07:21.748] [info] augur-node start: order not found, orderId: 0x<elided hex number> (0x<elided different hex number>)
   got 42 logs in blocks { fromBlock: 6947193, toBlock: 6947912 }
   Fetching blocks details from 6946476 to 6947165
   got 26 logs in blocks { fromBlock: 6947913, toBlock: 6948632 }
   got 45 logs in blocks { fromBlock: 6948633, toBlock: 6949352 }
   [18:07:23.303] [info] AugurNodeServer requestLatestSyncedBlock
   got 144 logs in blocks { fromBlock: 6949353, toBlock: 6950072 }
   got 24 logs in blocks { fromBlock: 6950073, toBlock: 6950792 }
   got 104 logs in blocks { fromBlock: 6950793, toBlock: 6951512 }
   got 94 logs in blocks { fromBlock: 6951513, toBlock: 6952232 }
   got 59 logs in blocks { fromBlock: 6952233, toBlock: 6952952 }
   got 25 logs in blocks { fromBlock: 6952953, toBlock: 6953672 }
   [18:07:26.749] [info] AugurNodeServer restartOnFailure
   [18:07:26.749] [info] Restarting Augur Node Server
   [18:07:26.749] [info] Shutdown Augur Node Server
   [18:07:26.749] [info] Calling Augur Node Controller Shutdown
   [18:07:26.750] [info] Stopping Augur Node Server
   got 52 logs in blocks { fromBlock: 6953673, toBlock: 6954392 }
   [18:07:27.752] [info] AugurNodeServer disconnectServerMessage
   [18:07:31.752] [info] Starting Server

Note that I elided the the hex numbers in the orderId message -- if these would be helpful, I'd prefer to provide them privately, if possible.

 ### Environment
- Operating system: Ubuntu 16.04.5
- Browser: Firefox 64.0

 ##### If using Augur App:
 - Augur App version: 1.8.6, 1.8.5 and 1.8.3
- Are you connecting with a pre-existing option from the dropdown list of networks? Yes
    - If so, which one? Originally "Local Light Node", now "Mainnet (Alchemy)" with same result

[nuevoalex]

Your individual actions won't have any effect on the syncing process since it currently syncs data for any and all transactions that take place.

The orderId message is indicating the problem that is occurring, which is that somehow during the syncing process a log was missed (The one that created the order). This is something we've seen on occasion though the remaining cases we haven't been able to nail down exactly how they may be happening.

To resolve this you'll need to reset your database (There is an option to do so in the app in the upper right along with some other options in a dropdown). Before you reset your database however if you could provide a copy of your database either by sending it to a developer in our discord or by providing a public link to download it that would be very helpful. You can find the DB in the location specific to your OS here: https://github.com/AugurProject/augur/tree/master/packages/augur-app#clearing-configuration-file as augur-1-2.db.

Additionally it would be helpful to know what your syncing behavior is like:

• Have you been running Augur app for a long time without issues?
• Do you restart the app commonly?
• What endpoints do you typically use?

Thanks very much for the help and the report!

[ndorf]

Thank you for the quick response.

The database is available here. It's compressed with xz and then encrypted with the PGP key found at https://www.augur.net/pgp.txt -- I hope that's acceptable. I have confirmed that restoring this DB file reproduces the problematic behavior.

As to the other questions:

• I've been using Augur regularly for a few months now. Mostly, but not entirely, without issues: the app seems to enter a bad state somewhat regularly, but that is cleared up by restarting the app, so I haven't paid much attention to those errors. The most common error state seems to be something about "failed to establish connection to SQLite3 database," which seems rather strange on the surface (since SQLite3 databases are just local files). As far as I can tell, everything looks correct after a restart, so I've been just letting it slide. Going forward I'll keep a closer eye on these and report them as necessary.

• Due to the above, I have to restart the app somewhat commonly -- once or twice per week. Occasionally, I leave it down for at most a few days if I have nothing to do until the next dispute window. Most of the time, though, I restart it immediately. Either way, it works fine afterwards.

• Does "endpoint" mean "Ethereum network connection" in this context? If so, I have been using "Local Light Node (experimental)" since gethnode stopped working a few weeks ago. I'm 95% sure this database was synced from scratch using that. It worked without any unusual issues until this problem arose a few days ago; after that I switched to "Mainnet (Alchemy)" with no apparent effect. (Afterwards, I reset the database and synced from scratch using Alchemy; that stalled twice and required a restart to proceed, but eventually fully synced and I've been back online since then with no new issues.)

[adrake33]

@ndorf This should be fixed in version 1.9.0 of Augur App. Can you please upgrade to this version and let us know if you are still seeing this issue?

Closing this ticket for now, but please feel free to reopen if you still see this issue.