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

script hangs when script runs while script is running. #425

Open
bumbacoin opened this issue Nov 20, 2020 · 3 comments
Open

script hangs when script runs while script is running. #425

bumbacoin opened this issue Nov 20, 2020 · 3 comments

Comments

@bumbacoin
Copy link

bumbacoin commented Nov 20, 2020

updated for clarity.
very occasionally with 5 minute 'index update' using cronjobs, the running process seems to hang in such a way that later update processes fail to fail, seeming to result in many index/update processes hanging

i recently encountered a v1.7.4 explorer displaying a 31 hour old block, and >10 node processes running.
there was evidence of an unclean shutdown of the wallet at the displayed block, this implies the sudden shutdown somehow effected the explorers updating process.
given the 31 hour break, over 350 instances of update should have been run, i did not consider this and have no idea of what particular (or even exactly how many) instances were running at the time.

this method seems to result in the same behaviour, or, how to replicate,
using two remote sessions, i ran
rm tmp/index.pid; node scripts/sync.js index update
then quickly on other session also run it.

output from first instance -

# rm tmp/index.pid; node scripts/sync.js index update
rm: cannot remove 'tmp/index.pid': No such file or directory
script launched with pid: 654526

output from second instance -

# rm tmp/index.pid; node scripts/sync.js index update
rm: cannot remove 'tmp/index.pid': No such file or directory
Script already running..

at this point, the first process was borken, resulting in further update processes also being borken.
output from third instance -

# rm tmp/index.pid; node scripts/sync.js index update
script launched with pid: 654604

ctrl+c closes each process as expected, including allowing further updates to run normally if the initial process is closed.
however running processes in background causes multiple update processes to run simultaneously

@uaktags
Copy link
Collaborator

uaktags commented Nov 20, 2020

Why are we running further instances in consecutively?

The output from the 2nd instance can be summed up to the fact that the time between the removal of the index.pid and the creation of the lock allowed time for instance 3 or instance 1 in that case to create a lock (which is why "script already running" occurs). (This as well can occur because the cronjob fired in this void period.)

No aside from that question, what is the definition here of "continue to hang"? How long are these allowed to sit before you're exiting them, are these in separate sessions/screens or are they being Ctrl-C'd after X time? How far down the process are they making it before "hanging"? (ie: I see they make it to line 131, but are they making it to "db.update_db", "db.update_heavy" if heavy, is it making it to "db.update_tx_db"?)

If it's making it to update_tx_db, then understand that lines 729-731 (of database.js) is a taxing job. it's starting from the starting height and going until the end, just adding the block heights to an array "blocks_to_scan". So i'd fully expect if there are thousands of blocks, that this will take time before we finally get to 739 and start getting blockhashes.

Unlike 1.6.x, we no longer use the "Express" version of the nodeapi, so we no longer get output in the main "npm start" instance. Alot of it is just all behind the scenes now.

@bumbacoin
Copy link
Author

bumbacoin commented Nov 20, 2020

this was an effort to replicate a situation i have very occasionally come across in the wild.
today i discovered an explorer (v1.7.4) with the display stuck on a block 31 hours previous, (the wallet debug did show a sudden stop at the stuck height, then restart). a cursory glance at running processes using top, showed >10 node processes running.
over 350 'index updates' would've been triggered during the 31 hours, but i have no idea of the particular pids running before i stopped them.

my method above was done using two remote sessions.
update # 1 and # 2 were done very closely together, this was enough to trigger the issue,
so # 3 could be run at any time afterwards (as long as # 1 was still running)

ctrl+c closed each process as expected, but if run as background then they continue to accumulate.
eg

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                             
    717 root      20   0  962820 114256      0 S  18.3   5.4  33:05.70 /usr/bin/node /root/explorer/bin/cluster                                                            
    716 root      20   0  963264 120164      0 S  15.9   5.7  33:54.21 /usr/bin/node /root/explorer/bin/cluster                                                            
    718 root      20   0  962720 133512      0 R  15.9   6.4  33:38.91 /usr/bin/node /root/explorer/bin/cluster                                                            
 659758 root      20   0  946936  63664   1352 S  14.6   3.0   0:12.92 node scripts/sync.js index update                                                                   
 659790 root      20   0  949900  56452      0 S  14.0   2.7   0:17.08 node scripts/sync.js index update                                                                   
 659774 root      20   0  945816  64544   3056 R  13.0   3.1   0:15.31 node scripts/sync.js index update                                                                   
 659655 root      20   0  948252  81876   1316 S  10.6   3.9   0:44.93 node scripts/sync.js index update                                                                   
    704 root      20   0  609652   9572   1252 S   4.0   0.5   5:44.05 /usr/bin/node /root/explorer/bin/cluster                                                            
    436 root      20   0  597880  12556      0 S   2.0   0.6   2:15.46 /usr/bin/node /usr/local/lib/node_modules/forever/bin/monitor bin/cluster r 

i did happen to leave the extra console output from your suggestion in #400 and each process triggers this output, but this is as far as my checking has gone.
in sync.js line 189
console.log("Coin: %s. Last stats: %s. Current BlockCount: %s",settings.coin, stats.last, stats.count);

i created this issue to see if it was known before i spent a few hours more on it. i had initially assumed the explorer was a candidate for #400 so i'd spent some time testing it in regards to that, so my apologies for not explaining this more fully.
i'll do some more testing next day or two.

@uaktags
Copy link
Collaborator

uaktags commented Nov 20, 2020

Unfortunately i suspect that the best way to nail down what is causing the issue for you is to traverse down and place the output comments to find out where is it going and how much time its spending on that topic. I'm only aware of the how slow the process can be to get up and going in its current form (and that there's no much for verbose output anymore). So I think we may need an instance of digging deeper with console.logs to track down what can be improved and what cant

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants