Node hung up on downloading history buckets?

tlnagy

I'm basically following this tutorial https://galactictalk.org/d/20-setting-up-stellar-core-on-centos-7 but on ubuntu and my node is giving the following errors:

Mar 26 18:14:45 stellar-node stellar-core[26007]: 2018-03-26T18:14:45.155 GAKPP [Work WARNING] Scheduling retry #7/32 in 9 sec, for get-and-unzip-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 18:14:46 stellar-node stellar-core[26007]: 2018-03-26T18:14:46.664 GAKPP [Work WARNING] Scheduling retry #7/4294967295 in 54 sec, for ntp-work
Mar 26 18:14:54 stellar-node stellar-core[26007]: 2018-03-26T18:14:54.542 GAKPP [Process WARNING] process 26047 exited 22: curl -sf http://history.stellar.org/prd/core-live/core_live_003/bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz -o /var/stellar/buckets/tmp/repair-buckets-760052b9a9967061/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz.tmp
Mar 26 18:14:54 stellar-node stellar-core[26007]: 2018-03-26T18:14:54.543 GAKPP [Work WARNING] Reached retry limit 0 for get-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 18:14:54 stellar-node stellar-core[26007]: 2018-03-26T18:14:54.543 GAKPP [Work WARNING] Scheduling retry #8/32 in 151 sec, for get-and-unzip-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 18:17:25 stellar-node stellar-core[26007]: 2018-03-26T18:17:25.903 GAKPP [Process WARNING] process 26066 exited 22: curl -sf http://history.stellar.org/prd/core-live/core_live_003/bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz -o /var/stellar/buckets/tmp/repair-buckets-760052b9a9967061/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz.tmp
Mar 26 18:17:25 stellar-node stellar-core[26007]: 2018-03-26T18:17:25.904 GAKPP [Work WARNING] Reached retry limit 0 for get-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 18:17:25 stellar-node stellar-core[26007]: 2018-03-26T18:17:25.905 GAKPP [Work WARNING] Scheduling retry #9/32 in 434 sec, for get-and-unzip-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz

Here's my config file:

# This is an example config for setting up a validator.
# see https://www.stellar.org/developers/stellar-core/learn/admin.html#validating
# it is kept up to date based on https://github.com/stellar/docs/blob/master/validators.md

# run `stellar-core --genseed` to generate a public key and secret seed.
# Let us know the public key so we can add you to the validator list.
# set NODE_SEED below to the secret seed generated above.
NODE_SEED="... tamasnagy.com"# remove this if you are non-validating
NODE_IS_VALIDATOR=true

DATABASE="postgresql://dbname=core host=localhost user=stellar password=...."

#FAILURE_SAFETY is minimum number of nodes that are allowed to fail before you no longer have quorum
FAILURE_SAFETY=1

CATCHUP_RECENT=60480

NETWORK_PASSPHRASE="Public Global Stellar Network ; September 2015"

LOG_FILE_PATH="/var/log/stellar/stellar-core.log"
BUCKET_DIR_PATH="/var/stellar/buckets"


NODE_NAMES=[
"GDIQKLQVOCD5UD6MUI5D5PTPVX7WTP5TAPP5OBMOLENBBD5KG434KYQ2  stronghold1",
"GAOO3LWBC4XF6VWRP5ESJ6IBHAISVJMSBTALHOQM2EZG7Q477UWA6L7U  eno",
"GCJCSMSPIWKKPR7WEPIQG63PDF7JGGEENRC33OKVBSPUDIRL6ZZ5M7OO  tempo.eu.com",
"GC5SXLNAM3C4NMGK2PXK4R34B5GNZ47FYQ24ZIBFDFOCU6D4KBN4POAE  satoshipay",
"GCGB2S2KGYARPVIA37HYZXVRM2YZUEXA6S33ZU5BUDC6THSB62LZSTYH  sdf_watcher1",
"GCM6QMP3DLRPTAZW2UZPCPX2LF3SXWXKPMP3GKFZBDSF3QZGV2G5QSTK  sdf_watcher2",
"GABMKJM6I25XI4K7U6XWMULOUQIQ27BCTMLS6BYYSOWKTBUXVRJSXHYQ  sdf_watcher3",
"GAXEJOMEVVD5OAAGOOZ4SXTTNR46C4V23XROHWRNVEGOTGOABO3ZVH7Z  fairx",
"GAENPO2XRTTMAJXDWM3E3GAALNLG4HVMKJ4QF525TR25RI42YPEDULOW  ibm_uk"
]

KNOWN_PEERS=[
"core-live-a.stellar.org:11625",
"core-live-b.stellar.org:11625",
"core-live-c.stellar.org:11625",
"validator1.stellar.stronghold.co",
"stellar.256kw.com",
"stellar1.tempo.eu.com",
"stellar.satoshipay.io",
"uk.stellar.ibm.com",
"uswest.stellar.fairx.io"
]

[QUORUM_SET]
VALIDATORS=[
"$stronghold1", "$eno", "$tempo.eu.com", "$satoshipay", "$sdf_watcher1", "$sdf_watcher2", "$sdf_watcher3", "$fairx", "$ibm_uk"
]


# Stellar.org history store
[HISTORY.sdf1]
get="curl -sf http://history.stellar.org/prd/core-live/core_live_001/{0} -o {1}"

[HISTORY.sdf2]
get="curl -sf http://history.stellar.org/prd/core-live/core_live_002/{0} -o {1}"

[HISTORY.sdf3]
get="curl -sf http://history.stellar.org/prd/core-live/core_live_003/{0} -o {1}"

bkolobara

tlnagy This configuration file keeps changing rapidly. To get an up to date version I would always check out this one directly from git:

https://github.com/stellar/stellar-core/blob/master/docs/stellar-core_example.cfg

I think they changed the URL where they host the history try using this one instead:

[HISTORY.stellar]
get="curl http://history.stellar.org/{0} -o {1}"

[HISTORY.backup]
get="curl http://backupstore.blob.core.windows.net/backupstore/{0} -o {1}"

tlnagy

I added those lines instead of the previous ones and restarted the service, but I'm still having the same issue?

Mar 26 22:44:41 stellar-node stellar-core[27070]: 2018-03-26T22:44:41.445 GAKPP [Process WARNING] process 27102 exited 1: gzip -d /var/stellar/buckets/tmp/repair-buckets-87d1d3cbcfd5f0c9/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 22:44:41 stellar-node stellar-core[27070]: 2018-03-26T22:44:41.445 GAKPP [Work WARNING] Reached retry limit 0 for gunzip-file /var/stellar/buckets/tmp/repair-buckets-87d1d3cbcfd5f0c9/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 22:44:41 stellar-node stellar-core[27070]: 2018-03-26T22:44:41.446 GAKPP [Work WARNING] Scheduling retry #7/32 in 5 sec, for get-and-unzip-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 22:44:46 stellar-node stellar-core[27070]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Mar 26 22:44:46 stellar-node stellar-core[27070]:                                  Dload  Upload   Total   Spent    Left  Speed
Mar 26 22:44:46 stellar-node stellar-core[27070]: [158B blob data]
Mar 26 22:44:46 stellar-node stellar-core[27070]: gzip: /var/stellar/buckets/tmp/repair-buckets-87d1d3cbcfd5f0c9/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz: not in gzip format
Mar 26 22:44:46 stellar-node stellar-core[27070]: 2018-03-26T22:44:46.789 GAKPP [Process WARNING] process 27108 exited 1: gzip -d /var/stellar/buckets/tmp/repair-buckets-87d1d3cbcfd5f0c9/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 22:44:46 stellar-node stellar-core[27070]: 2018-03-26T22:44:46.789 GAKPP [Work WARNING] Reached retry limit 0 for gunzip-file /var/stellar/buckets/tmp/repair-buckets-87d1d3cbcfd5f0c9/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz
Mar 26 22:44:46 stellar-node stellar-core[27070]: 2018-03-26T22:44:46.789 GAKPP [Work WARNING] Scheduling retry #8/32 in 136 sec, for get-and-unzip-remote-file bucket/b7/2b/c2/bucket-b72bc26d469a3f5079510767e2ea4773e02da574dec72e2f32f5828b79e0af40.xdr.gz

bkolobara

tlnagy It looks like a different error. Try to dumping the database and clearing buckets, so you have a fresh start.

tlnagy

Ok cool. Looks like we're making some progress. I ran rm -rf on the buckets folder and then used stellar-core --newdb to reinitialize the database. I'm still having some issues with the history:

Mar 27 18:03:49 stellar-node stellar-core[320]: 2018-03-27T18:03:49.826 GAKPP [History INFO] Catching up: Awaiting checkpoint (ETA: 4 seconds)
Mar 27 18:03:53 stellar-node stellar-core[320]: 2018-03-27T18:03:53.677 GAKPP [Herder INFO] Quorum information for 17041186 : {"agree":7,"disagree":0,"fail_at":1,"hash":"def145","missing":2,"phase":"EXTERNALIZE"}
Mar 27 18:03:53 stellar-node stellar-core[320]: 2018-03-27T18:03:53.687 GAKPP [Ledger INFO] Got consensus: [seq=17041188, prev=64f5c9, tx_count=19, sv: [  txH: 48e57a, ct: 1522173813, upgrades: [ ] ]]
Mar 27 18:03:53 stellar-node stellar-core[320]: 2018-03-27T18:03:53.687 GAKPP [History INFO] Catching up: Awaiting checkpoint (ETA: 0 seconds)
Mar 27 18:03:53 stellar-node stellar-core[320]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Mar 27 18:03:53 stellar-node stellar-core[320]:                                  Dload  Upload   Total   Spent    Left  Speed
Mar 27 18:03:54 stellar-node stellar-core[320]: [237B blob data]
Mar 27 18:03:54 stellar-node stellar-core[320]: 2018-03-27T18:03:54.181 GAKPP [History ERROR] error loading history state: rapidjson internal assertion failure: IsObject() [GetHistoryArchiveStateWork.cpp:101]
Mar 27 18:03:54 stellar-node stellar-core[320]: 2018-03-27T18:03:54.182 GAKPP [Work WARNING] Scheduling retry #2/5 in 2 sec, for get-history-archive-state
Mar 27 18:03:56 stellar-node stellar-core[320]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Mar 27 18:03:56 stellar-node stellar-core[320]:                                  Dload  Upload   Total   Spent    Left  Speed
Mar 27 18:03:56 stellar-node stellar-core[320]: [158B blob data]
Mar 27 18:03:56 stellar-node stellar-core[320]: 2018-03-27T18:03:56.524 GAKPP [History ERROR] error loading history state: rapidjson internal assertion failure: IsObject() [GetHistoryArchiveStateWork.cpp:101]
Mar 27 18:03:56 stellar-node stellar-core[320]: 2018-03-27T18:03:56.525 GAKPP [Work WARNING] Scheduling retry #3/5 in 5 sec, for get-history-archive-state
Mar 27 18:03:58 stellar-node stellar-core[320]: 2018-03-27T18:03:58.955 GAKPP [Herder INFO] Quorum information for 17041187 : {"agree":7,"disagree":0,"fail_at":1,"hash":"def145","missing":2,"phase":"EXTERNALIZE"}
Mar 27 18:03:58 stellar-node stellar-core[320]: 2018-03-27T18:03:58.968 GAKPP [Ledger INFO] Got consensus: [seq=17041189, prev=7d6566, tx_count=1, sv: [  txH: 995bae, ct: 1522173820, upgrades: [ ] ]]
Mar 27 18:03:58 stellar-node stellar-core[320]: 2018-03-27T18:03:58.968 GAKPP [History INFO] Catching up: Awaiting checkpoint (ETA: 3 seconds)
Mar 27 18:04:01 stellar-node stellar-core[320]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Mar 27 18:04:01 stellar-node stellar-core[320]:                                  Dload  Upload   Total   Spent    Left  Speed
Mar 27 18:04:01 stellar-node stellar-core[320]: [158B blob data]
Mar 27 18:04:01 stellar-node stellar-core[320]: 2018-03-27T18:04:01.859 GAKPP [History ERROR] error loading history state: rapidjson internal assertion failure: IsObject() [GetHistoryArchiveStateWork.cpp:101]
Mar 27 18:04:01 stellar-node stellar-core[320]: 2018-03-27T18:04:01.859 GAKPP [Work WARNING] Scheduling retry #4/5 in 4 sec, for get-history-archive-state
Mar 27 18:04:02 stellar-node stellar-core[320]: 2018-03-27T18:04:02.257 GAKPP [Herder INFO] Quorum information for 17041188 : {"agree":7,"disagree":0,"fail_at":1,"hash":"def145","missing":2,"phase":"EXTERNALIZE"}
Mar 27 18:04:02 stellar-node stellar-core[320]: 2018-03-27T18:04:02.268 GAKPP [Ledger INFO] Got consensus: [seq=17041190, prev=d7a6fe, tx_count=4, sv: [  txH: 86c0f4, ct: 1522173824, upgrades: [ ] ]]
Mar 27 18:04:03 stellar-node stellar-core[320]: 2018-03-27T18:04:03.748 GAKPP [Herder INFO] Quorum information for 17041189 : {"agree":7,"disagree":0,"fail_at":1,"hash":"def145","missing":2,"phase":"EXTERNALIZE"}
Mar 27 18:04:03 stellar-node stellar-core[320]: 2018-03-27T18:04:03.758 GAKPP [Ledger INFO] Got consensus: [seq=17041191, prev=0b9440, tx_count=5, sv: [  txH: df490e, ct: 1522173829, upgrades: [ ] ]]
Mar 27 18:04:03 stellar-node stellar-core[320]: 2018-03-27T18:04:03.759 GAKPP [History INFO] Catching up: Awaiting checkpoint (ETA: 2 seconds)
Mar 27 18:04:05 stellar-node stellar-core[320]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Mar 27 18:04:05 stellar-node stellar-core[320]:                                  Dload  Upload   Total   Spent    Left  Speed
Mar 27 18:04:06 stellar-node stellar-core[320]: [237B blob data]
Mar 27 18:04:06 stellar-node stellar-core[320]: 2018-03-27T18:04:06.207 GAKPP [History ERROR] error loading history state: rapidjson internal assertion failure: IsObject() [GetHistoryArchiveStateWork.cpp:101]
Mar 27 18:04:06 stellar-node stellar-core[320]: 2018-03-27T18:04:06.207 GAKPP [Work WARNING] Scheduling retry #5/5 in 2 sec, for get-history-archive-state
Mar 27 18:04:06 stellar-node stellar-core[320]: 2018-03-27T18:04:06.916 GAKPP [Herder INFO] Quorum information for 17041190 : {"agree":7,"disagree":0,"fail_at":1,"hash":"def145","missing":2,"phase":"EXTERNALIZE"}
Mar 27 18:04:06 stellar-node stellar-core[320]: 2018-03-27T18:04:06.931 GAKPP [Ledger INFO] Got consensus: [seq=17041192, prev=f2f3d0, tx_count=10, sv: [  txH: 79032e, ct: 1522173835, upgrades: [ ] ]]
Mar 27 18:04:08 stellar-node stellar-core[320]:   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
Mar 27 18:04:08 stellar-node stellar-core[320]:                                  Dload  Upload   Total   Spent    Left  Speed
Mar 27 18:04:08 stellar-node stellar-core[320]: [158B blob data]
Mar 27 18:04:08 stellar-node stellar-core[320]: 2018-03-27T18:04:08.553 GAKPP [History ERROR] error loading history state: rapidjson internal assertion failure: IsObject() [GetHistoryArchiveStateWork.cpp:101]
Mar 27 18:04:08 stellar-node stellar-core[320]: 2018-03-27T18:04:08.553 GAKPP [Work WARNING] Reached retry limit 5 for get-history-archive-state
Mar 27 18:04:08 stellar-node stellar-core[320]: 2018-03-27T18:04:08.553 GAKPP [Work WARNING] Reached retry limit 0 for catchup
Mar 27 18:04:08 stellar-node stellar-core[320]: 2018-03-27T18:04:08.554 GAKPP [Ledger ERROR] Error catching up: Connection timed out [LedgerManagerImpl.cpp:536]
Mar 27 18:04:08 stellar-node stellar-core[320]: 2018-03-27T18:04:08.554 GAKPP [Ledger ERROR] Catchup will restart at next close. [LedgerManagerImpl.cpp:537]

Thanks for your help!

yulemata

Hi, did you find the issue about the History Error? I've got the same message

Dilidonka

Anybody found the problem ? Same problem with me "error loading history state: rapidjson internal assertion failure: IsObject()"

stellar-core: v9.2.0-213-g13d55680

Dilidonka

Problem resolved after updating History archives to

[HISTORY.sdf1]
get="curl -sf http://history.stellar.org/prd/core-live/core_live_001/{0} -o {1}"
#put="aws s3 cp {0} s3://sc-history.s3.amazonaws.com/core_live_001/{1}"

[HISTORY.sdf2]
get="curl -sf http://history.stellar.org/prd/core-live/core_live_002/{0} -o {1}"
#put="aws s3 cp {0} s3://sc-history.s3.amazonaws.com/core_live_002/{1}"

[HISTORY.sdf3]
get="curl -sf http://history.stellar.org/prd/core-live/core_live_003/{0} -o {1}"
#put="aws s3 cp {0} s3://sc-history.s3.amazonaws.com/core_live_003/{1}"