Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error reading "last" property during reindex. #335

Closed
DigitalCoin1 opened this issue Dec 31, 2019 · 25 comments
Closed

Error reading "last" property during reindex. #335

DigitalCoin1 opened this issue Dec 31, 2019 · 25 comments

Comments

@DigitalCoin1
Copy link

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

$ nodejs --stack-size=15000 scripts/sync.js index reindex

script launched with pid: 29188
events.js:183
      throw er; // Unhandled 'error' event
      ^

TypeError: Cannot read property 'last' of undefined
    at /home/spero/explorer/lib/database.js:767:31
    at /home/spero/explorer/node_modules/mongoose/lib/model.js:4599:16
    at model.Query.Query._findAndModify (/home/spero/explorer/node_modules/mongoose/lib/query.js:3461:16)
    at model.Query.<anonymous> (/home/spero/explorer/node_modules/mongoose/lib/query.js:3001:8)
    at model.Query._wrappedThunk [as _findOneAndUpdate] (/home/spero/explorer/node_modules/mongoose/lib/helpers/query/wrapThunk.js:16:8)
    at process.nextTick (/home/spero/explorer/node_modules/kareem/index.js:369:33)
    at _combinedTickCallback (internal/process/next_tick.js:132:7)
    at process._tickCallback (internal/process/next_tick.js:181:9)
@TheHolyRoger

This comment has been minimized.

Copy link
Collaborator

@TheHolyRoger TheHolyRoger commented Dec 31, 2019

@DigitalCoin1 which branch are you using? This was fixed in this commit 4881f77

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

4881f77 appears to be what brought this error.
Last on line 767 is from the new_stats. I too get this sometimes, though haven't tracked down why/where from. But i'd be willing to bet if he console.log'd new_stats, it will be empty rather than returning from the findOneAndUpdate.

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

We may also want to do something about the unused err, just to check to make sure that no issue was found when doing the Stats.findOneAndUpdate

@DigitalCoin1

This comment has been minimized.

Copy link
Author

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

@DigitalCoin1 which branch are you using? This was fixed in this commit 4881f77

I clone the current Iquidus repository(https://github.com/DigitalCoin1/explorer) and just changed the configuration file.
I upgraded my MongoDB to version 4.2.2 and the error continued even eliminating the entire DB and redoing it.

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

@DigitalCoin1 try changing your settings.supply to balances or getinfo

If that doesn't work, can you let me know what coin you're using?

@DigitalCoin1

This comment has been minimized.

Copy link
Author

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

@DigitalCoin1 try changing your settings.supply to balances or getinfo

If that doesn't work, can you let me know what coin you're using?

I always use GETINFO.
My Coin is PoW+PoS

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

DigitalCoin "DGC" or SperoCoin (see the username is spero)?

To test an idea, can you try changing line 767 in database.js to this:

last: (new_stats.last ? new_stats.last : 0)});
@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Basically the thought process is, the coin was never ran before, so there's no .last because it was never grabbed before, so it's null/non-existent.

@DigitalCoin1

This comment has been minimized.

Copy link
Author

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

DigitalCoin "DGC" or SperoCoin (see the username is spero)?

To test an idea, can you try changing line 767 in database.js to this:

last: (new_stats.last ? new_stats.last : 0)});

DigitalCoin is the company behind SperoCoin (SPERO).
I changed the line, but the error remains.

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

More testing:

}, function(err, new_stats) {
            if(new_stats){
            }else{
              new_stats = {
                last: 0
              }
            }
            return cb({coin: coin,
              count : count,
              supply: supply,
              connections: connections,
              last: (new_stats.last ? new_stats.last : 0)});
          });
@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Basically, I only get around this issue naturally with BALANCES with the way the current master is, but can't put my finger on why the supply has anything to do with this last value

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Indeed, so using Sperocoin I can get around this issue with BALANCES rather than getinfo. So the issue is definitely in the logic of sync.

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Easier change may be do change up "create_stats" to look like this:

create_stats: function(coin, cb) {
    var newStats = new Stats({
      coin: coin,
      last: 0 /// newly added to fix issue #335
    });

    newStats.save(function(err) {
      if (err) {
        console.log(err);
        return cb();
      } else {
        console.log("initial stats entry created for %s", coin);
        //console.log(newStats);
        return cb();
      }
    });
  },
@uaktags uaktags changed the title throw er; // Unhandled 'error' event Error reading "last" property during reindex. Dec 31, 2019
uaktags added a commit to uaktags/explorer that referenced this issue Dec 31, 2019
uaktags added a commit to uaktags/explorer that referenced this issue Dec 31, 2019
@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

@DigitalCoin1

This comment has been minimized.

Copy link
Author

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

Possibly resolved in https://github.com/uaktags/explorer/tree/dev-test-parallel

$ node --stack-size=15000 scripts/sync.js index reindex

script launched with pid: 5181
TXs cleared.
Addresses cleared.
Address TXs cleared.
index cleared (reindex)
Error:  { name: 'SyntaxError',
  message: 'Duplicate key "time"',
  at: 810,
  text: '[{"result":{"hex":"010000006501c959010000000000000000000000000000000000000000000000000000000000000000ffffffff0351010affffffff02005039278c0400001976a9149e06718d1dee28b8f4847f90a7de04b1dd4eef4888ac00000000000000000000000000","txid":"f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f","version":1,"time":1506345317,"locktime":0,"vin":[{"coinbase":"51010a","sequence":4294967295}],"vout":[{"value":50000.00000000,"n":0,"scriptPubKey":{"asm":"OP_DUP OP_HASH160 9e06718d1dee28b8f4847f90a7de04b1dd4eef48 OP_EQUALVERIFY OP_CHECKSIG","reqSigs":1,"type":"pubkeyhash","addresses":["SbhZWrgXnEK4RVSLSjDAdbf4LgpzkWuuh1"]}},{"value":0.00000000,"n":1,"scriptPubKey":{"asm":"","type":"nonstandard"}}],"blockhash":"00000fff3b93a589e494558ef101a61ca0d3e66f6e5639eb4711ee16db45d265","confirmations":442423,"time":1506345416,"blocktime":1506345416},"error":null,"id":"1577817713854-0"}]\n' }

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Awesome, so we can see the errors in the update script when trying to add the transactions. Closer to a more stable setup

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Okay, so your issue now is the duplicate "time" property that your coin's rawtransaction api returns:

[
	{
		"hex" :  "010000006501c959010000000000000000000000000000000000000000000000000000000000000000ffffffff0351010affffffff02005039278c0400001976a9149e06718d1dee28b8f4847f90a7de04b1dd4eef4888ac00000000000000000000000000",
		"txid":"f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f",
		"version":1,
		"time":1506345317,
		"locktime":0,
		"vin":[
			{
				"coinbase":"51010a",
				"sequence":4294967295
			}
		],
		"vout":[
			{
				"value":50000.00000000,
				"n":0,
				"scriptPubKey":{
					"asm":"OP_DUP OP_HASH160 9e06718d1dee28b8f4847f90a7de04b1dd4eef48 OP_EQUALVERIFY OP_CHECKSIG",
					"reqSigs":1,
					"type":"pubkeyhash",
					"addresses":["SbhZWrgXnEK4RVSLSjDAdbf4LgpzkWuuh1"]
				}
			},{
				"value":0.00000000,
				"n":1,
				"scriptPubKey":{
					"asm":"",
					"type":"nonstandard"
				}
			}
		],
		"blockhash":"00000fff3b93a589e494558ef101a61ca0d3e66f6e5639eb4711ee16db45d265",
		"confirmations":442423,
		"time":1506345416,
		"blocktime":1506345416
	}
]

I would happen to guess that this is something that bitcoin_node_api did and filtered when getting the results, as I don't see this duplication here: https://explorer.sperocoin.org/api/getrawtransaction?txid=f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f&decrypt=1

@DigitalCoin1

This comment has been minimized.

Copy link
Author

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

Okay, so your issue now is the duplicate "time" property that your coin's rawtransaction api returns:

[
	{
		"hex" :  "010000006501c959010000000000000000000000000000000000000000000000000000000000000000ffffffff0351010affffffff02005039278c0400001976a9149e06718d1dee28b8f4847f90a7de04b1dd4eef4888ac00000000000000000000000000",
		"txid":"f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f",
		"version":1,
		"time":1506345317,
		"locktime":0,
		"vin":[
			{
				"coinbase":"51010a",
				"sequence":4294967295
			}
		],
		"vout":[
			{
				"value":50000.00000000,
				"n":0,
				"scriptPubKey":{
					"asm":"OP_DUP OP_HASH160 9e06718d1dee28b8f4847f90a7de04b1dd4eef48 OP_EQUALVERIFY OP_CHECKSIG",
					"reqSigs":1,
					"type":"pubkeyhash",
					"addresses":["SbhZWrgXnEK4RVSLSjDAdbf4LgpzkWuuh1"]
				}
			},{
				"value":0.00000000,
				"n":1,
				"scriptPubKey":{
					"asm":"",
					"type":"nonstandard"
				}
			}
		],
		"blockhash":"00000fff3b93a589e494558ef101a61ca0d3e66f6e5639eb4711ee16db45d265",
		"confirmations":442423,
		"time":1506345416,
		"blocktime":1506345416
	}
]

I would happen to guess that this is something that bitcoin_node_api did and filtered when getting the results, as I don't see this duplication here: https://explorer.sperocoin.org/api/getrawtransaction?txid=f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f&decrypt=1

I am actually using another server to upload this updated version. Once everything is ok, I will go up to the main explorer.
I am using this:
http://52.67.138.144:3001/

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

That's fine, I'm just pointing out that there seems to be a difference between how the getrawtransaction returns data between 1.6.1 (your old version at sperocoin.org) vs the 1.7.2 (at your test server). You can see this by comparing that link I posted with:

http://52.67.138.144:3001/api/getrawtransaction?txid=f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f&decrypt=1 or by bringing up the debug console on your sperocoin wallet (or use cli) and running a "getrawtransaction f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f 1"

Basically, we're no longer capturing and parsing out that redundant time property (and i'm not sure why/where it was before).

I think I'm going to hit the pause for a little and see if @TheHolyRoger can notice what I'm missing.

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

One thing you can try, if you'd like, is set "use_rpc: false" in your settings.json. This removes the bitcoin-core npm and uses the old bitcoin-node-api, but nothing that i can see tells me why that would change anything. Looking at bitcoin-node-api doesn't return any results that I can see that specifically parses this any differently

@DigitalCoin1

This comment has been minimized.

Copy link
Author

@DigitalCoin1 DigitalCoin1 commented Dec 31, 2019

One thing you can try, if you'd like, is set "use_rpc: false" in your settings.json. This removes the bitcoin-core npm and uses the old bitcoin-node-api, but nothing that i can see tells me why that would change anything. Looking at bitcoin-node-api doesn't return any results that I can see that specifically parses this any differently

Using "use_rpc": false, , I had the following return:

$ nodejs --stack-size=15000 scripts/sync.js index reindex
tx not found: f77fa1330e3018254f701fe465e62272e45b64699f4a685140ae6625e8f4121f
tx not found: 1101bf3681af78816fda1c82c3a4260ae0f44987edfa6cd1bdcdca8924fa30d7
tx not found: e396497ca5ae198ada74484410084775753475548b517eeea58b4ac1cc210c81
tx not found: 87c478ee5debc9fb7a305d57c8e382c75457a068595327f4c22372c6d4ee8609
tx not found: a93b93159dccbe6db036f0c9e9f6c85c5d52297674f54a71274b32518255a981
tx not found: 166eef1078728b36e4736584a28b1b010213460894697229865074188c7fb487
tx not found: db26653b04af9ded9f3361d282bb9de6cbbe5cb5f768176125d223099f303cc1
tx not found: 6d074b6b9fe2b54f31d53f9b98765f14255b20ad689ae44bd2eed42ddcec36ac
tx not found: df0bbaf444ac9da5897024614eda324d2adcfb2f330f95574b2960488efd566e
tx not found: 6b28a1f92102d3432748b051bca201882a72336becd6dcf744869d902ec4fa0e
tx not found: 7eebf4016afdae1caf037427e258504fddc16913c41f6e7c73e8c449f0a13886

Other:

$ nodejs --stack-size=15000 scripts/sync.js index update
script launched with pid: 7764
/home/spero/explorer/lib/explorer.js:582
    module.exports.syncLoop(tx.vin.length, function (loop) {
                                   ^

TypeError: Cannot read property 'length' of undefined
    at Object.prepare_vin (/home/spero/explorer/lib/explorer.js:582:36)
    at /home/spero/explorer/lib/database.js:128:11
    at Request._callback (/home/spero/explorer/lib/explorer.js:212:16)
    at Request.self.callback (/home/spero/explorer/node_modules/request/request.js:185:22)
    at emitTwo (events.js:126:13)
    at Request.emit (events.js:214:7)
    at Request.<anonymous> (/home/spero/explorer/node_modules/request/request.js:1161:10)
    at emitOne (events.js:116:13)
    at Request.emit (events.js:211:7)
    at IncomingMessage.<anonymous> (/home/spero/explorer/node_modules/request/request.js:1083:12)
    at Object.onceWrapper (events.js:313:30)
    at emitNone (events.js:111:20)
    at IncomingMessage.emit (events.js:208:7)
    at endReadableNT (_stream_readable.js:1064:12)
    at _combinedTickCallback (internal/process/next_tick.js:139:11)
    at process._tickCallback (internal/process/next_tick.js:181:9)
@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Very interesting. So we just have a boat load of issues, regardless of how we go about this. You could always pull an earlier commit (perhaps 1.6.2's or just before the PR's merged, so maybe c198c70) but I have spero running and seeing the same issues. Atleast I have a local test bed.

Okay, looking at this from the RPC standpoint, the issue is clearly that bitcoin-core doesn't seem to want to handle duplicate keys (because js doesn't support duplicate keys in its objects). Not sure why/what is different between Node-api's api.js doing a client.command and us, but something is totally being missed here.

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Dec 31, 2019

Actually, hmm. with even use_rpc: false it still fails for the same reason:

GET /api/getblock?hash=0000009a7e564492c30499c178ef4d4c9e2c729a6fff23ae2196fa7919aa7911 200 5.032 ms - 770
{ name: 'SyntaxError',
  message: 'Duplicate key "time"',
  at: 814,
  text: '[{"result":{"hex":"010000005473c959010000000000000000000000000000000000000000000000000000000000000000ffffffff05026e010107ffffffff0200c2eb0b000000001976a914f5ee8cce283bcb7c00aa4d776610c0b86f08f10788ac00000000000000000000000000","txid":"d7bd08c8e5058b3bd8a3940e089fbc78c0864e87f7222a83f272ff9ce1e008b4","version":1,"time":1506374484,"locktime":0,"vin":[{"coinbase":"026e010107","sequence":4294967295}],"vout":[{"value":2.00000000,"n":0,"scriptPubKey":{"asm":"OP_DUP OP_HASH160 f5ee8cce283bcb7c00aa4d776610c0b86f08f107 OP_EQUALVERIFY OP_CHECKSIG","reqSigs":1,"type":"pubkeyhash","addresses":["SjiNMaxY58sL8FZ1HV9XpbPdHi9EwaTnmq"]}},{"value":0.00000000,"n":1,"scriptPubKey":{"asm":"","type":"nonstandard"}}],"blockhash":"00000863c9cff4cefcede1a3b8f2a6007296fc4d1c261e20c90f8b0f4f3b8e06","confirmations":442173,"time":1506374528,"blocktime":1506374528},"error":null,"id":"1577822247543-0"}]\n' }
GET /api/getrawtransaction?txid=d7bd08c8e5058b3bd8a3940e089fbc78c0864e87f7222a83f272ff9ce1e008b4&decrypt=1 200 10.201 ms - 39
GET /api/getrawtransaction?txid=617e4d6676bf1184e3614c64bdcd43d657a821961e29cdffe18642ef18ea5a4e&decrypt=1 - - ms - -
@TheHolyRoger

This comment has been minimized.

Copy link
Collaborator

@TheHolyRoger TheHolyRoger commented Jan 1, 2020

I think the time key issue should be resolved in their coin RPC, but we'll get the initial setting of "last" merged into the branches

@uaktags

This comment has been minimized.

Copy link
Collaborator

@uaktags uaktags commented Jan 2, 2020

This issue was introduced by the maintainers of bitcoin-core npm project.
https://github.com/ruimarinho/bitcoin-core/blob/c035b34aefa65164857f521a75f356e65448b9e6/dist/src/parser.js#L79

Basically in 2.0 they went ahead and used the "parse" command rather than the older way which worked (or using JSON.parse). I've confirmed that if I use ^1.2.0 of bitcoin-core then the issue is resolved on SPEROCOIN with a duplicate time.

Unfortunately, I don't really like the idea of requiring such an old version (current version is 3.0) One thing I can perhaps do, for the time being, is update the bitcoin-node-api project to use the old version. That way anyone who continues to have "use_rpc: false" can get the old functionality working (if it worked on iquidus 1.6.1 then it'll work now) but you'll lose out on alot of the speed improvements, and eventually we'll be dropping the old method soon. So your upward trajectory with it will be limited.

Ultimately, I have to agree with HolyRoger that the issue lies in the coin's sourcecode itself. It shouldn't have time listed twice and that definitely seems like an error.
For reference:
https://github.com/DigitalCoin1/SperoCoin/blob/c93a8c0f23c63e2261cd1062276071b34e59ec47/src/rpcrawtransaction.cpp#L106
and
https://github.com/DigitalCoin1/SperoCoin/blob/c93a8c0f23c63e2261cd1062276071b34e59ec47/src/rpcrawtransaction.cpp#L61 is where the issue lies. A transaction should only ever have 1 time, the time that the transaction took place. If there's separate times, then one has to ask, what happens if the times are different for whatever reason.

For this reason, I'm going to close this for now.

@uaktags uaktags closed this Jan 2, 2020
TheHolyRoger added a commit that referenced this issue Jan 3, 2020
TheHolyRoger added a commit that referenced this issue Jan 3, 2020
TheHolyRoger added a commit that referenced this issue Jan 3, 2020
TheHolyRoger added a commit that referenced this issue Jan 3, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
3 participants
You can’t perform that action at this time.