Skip to content
This repository has been archived by the owner on Jun 12, 2023. It is now read-only.

Issue with Opened File Descriptors when creating a checkpoint #1116

Open
andreiguzga opened this issue Oct 6, 2021 · 3 comments
Open

Issue with Opened File Descriptors when creating a checkpoint #1116

andreiguzga opened this issue Oct 6, 2021 · 3 comments

Comments

@andreiguzga
Copy link

I had 5 validators which went offline. After checking the logs I've seen that the number of Open File Descriptor has exceeded the 60k ulimit I had set up on the validator.

Below are the logs that I found on the validators. The logs are just from one validator but all 5 had the same type of logs.

2021-10-06 09:27:34.457 [warning] <0.2165.0>@blockchain_txn:separate_res:388 BUG: unexpected txn validation error format blockchain_txn_poc_receipts_v1 : {'EXIT',{{db_open,"IO error: While open a file for random read: /var/data/checkpoints/1041899/ledger.db-1633512434492386608/ledger.db/6469986.sst: No file descriptors available"},[{blockchain_ledger_v1,open_db_,6,[{file,"blockchain_ledger_v1.erl"},{line,4295}]},{blockchain_ledger_v1,new,3,[{file,"blockchain_ledger_v1.erl"},{line,406}]},{blockchain_ledger_v1,context_snapshot,1,[{file,"blockchain_ledger_v1.erl"},{line,814}]},{blockchain,'-fold_blocks/5-fun-1-',4,[{file,"blockchain.erl"},{line,589}]},{lists,foldl,3,[{file,"lists.erl"},{line,1267}]},{blockchain,ledger_at,3,[{file,"blockchain.erl"},{line,539}]},{blockchain_txn_poc_receipts_v1,check_is_valid_poc,2,[{file,"blockchain_txn_poc_receipts_v1.erl"},{line,274}]},{blockchain_txn_poc_receipts_v1,is_valid,2,[{file,"blockchain_txn_poc_receipts_v1.erl"},{line,189}]}]}} / type=poc_receipts_v1 hash="1JH5e1LAm2FzzWjjjAVHcq2v1EiEQCh28ocmAtkaNt9rsgq6Xe" challenger="shambolic-ivory-mandrill" onion="12kowuYhG3Qi3gVkCV6P3SBnaDFoRtiQtta5ifsxQxLwStWoC7B" path:

2021-10-06 09:27:31.552 [warning] <0.2172.0>@blockchain_ledger_v1:has_snapshot:922 couldn't find checkpoint dir? for 1041900 2021-10-06 09:27:31.552 [warning] <0.2172.0>@blockchain_ledger_v1:has_snapshot:922 couldn't find checkpoint dir? for 1041900 2021-10-06 09:27:31.552 [warning] <0.2172.0>@blockchain_ledger_v1:has_snapshot:922 couldn't find checkpoint dir? for 1041899 2021-10-06 09:27:31.965 [warning] <0.2173.0>@blockchain_ledger_v1:has_snapshot:922 couldn't find checkpoint dir? for 1041899

2021-10-06 09:29:39.628 [info] <0.2531.0>@blockchain_ledger_v1:context_snapshot:824 renamed checkpoint from "/var/data/checkpoints/1041896/ledger.db-1633512578873078916/ledger.db" to "/var/data/checkpoints/1041896/ledger.db" 2021-10-06 09:29:39.629 [info] <0.2531.0>@blockchain_ledger_v1:has_snapshot:892 loading checkpoint from disk with ledger mode delayed

Looking at the graphs for the Open File Descriptors I've noticed a spike on all validators that had this behaviour. I think in some circumstances the File Descriptors are not being closed which leads to a point where the opened file limit is being reached and the validator will come offline.

Bellow are the graphs for the spike in OFD.

https://ibb.co/SPqfDqz
https://ibb.co/f8YHZJz
https://ibb.co/jhdsJxC

@andreiguzga
Copy link
Author

After checking further I've noticed that when a checkpoint is being created FD are left open. By using lsof -a -p <beam.smp PID> I've noticed a lot of entries marked as deleted which still had a FD Open

beam.smp 3499023 root 7535r REG 252,1 56314 1300053 /var/data/checkpoints/1012312/ledger.db/000110.sst (deleted) beam.smp 3499023 root 7536r REG 252,1 1117 1301078 /var/data/checkpoints/1012312/ledger.db/000276.sst (deleted) beam.smp 3499023 root 7537r REG 252,1 73539 1301297 /var/data/checkpoints/1012312/ledger.db/000414.sst (deleted) beam.smp 3499023 root 7538r REG 252,1 38238 1300903 /var/data/checkpoints/1012312/ledger.db/000206.sst (deleted) beam.smp 3499023 root 7539r REG 252,1 991 1301394 /var/data/checkpoints/1012312/ledger.db/000478.sst (deleted) beam.smp 3499023 root 7540r REG 252,1 1199 1301378 /var/data/checkpoints/1012312/ledger.db/000469.sst (deleted) beam.smp 3499023 root 7541r REG 252,1 1006 1301352 /var/data/checkpoints/1012312/ledger.db/000451.sst (deleted) beam.smp 3499023 root 7542r REG 252,1 1727 1301047 /var/data/checkpoints/1012312/ledger.db/000263.sst (deleted) beam.smp 3499023 root 7543r REG 252,1 1137 1300947 /var/data/checkpoints/1012312/ledger.db/000225.sst (deleted) beam.smp 3499023 root 7544r REG 252,1 991 1301283 /var/data/checkpoints/1012312/ledger.db/000405.sst (deleted) beam.smp 3499023 root 7545r REG 252,1 1087 1301155 /var/data/checkpoints/1012312/ledger.db/000321.sst (deleted) beam.smp 3499023 root 7546r REG 252,1 1154 1301339 /var/data/checkpoints/1012312/ledger.db/000443.sst (deleted) beam.smp 3499023 root 7547r REG 252,1 1251 1301141 /var/data/checkpoints/1012312/ledger.db/000312.sst (deleted) beam.smp 3499023 root 7548r REG 252,1 1246 1300272 /var/data/checkpoints/1012312/ledger.db/000173.sst (deleted) beam.smp 3499023 root 7549r REG 252,1 4641833 1300055 /var/data/checkpoints/1012312/ledger.db/000112.sst (deleted) beam.smp 3499023 root 7550r REG 252,1 1057 1300974 /var/data/checkpoints/1012312/ledger.db/000234.sst (deleted) beam.smp 3499023 root 7551r REG 252,1 2406 1301128 /var/data/checkpoints/1012312/ledger.db/000302.sst (deleted) beam.smp 3499023 root 7552r REG 252,1 1073 1301171 /var/data/checkpoints/1012312/ledger.db/000330.sst (deleted) beam.smp 3499023 root 7553r REG 252,1 1260 1301213 /var/data/checkpoints/1012312/ledger.db/000359.sst (deleted) beam.smp 3499023 root 7554r REG 252,1 1566 1301186 /var/data/checkpoints/1012312/ledger.db/000340.sst (deleted) beam.smp 3499023 root 7555r REG 252,1 1057 1301229 /var/data/checkpoints/1012312/ledger.db/000368.sst (deleted) beam.smp 3499023 root 7556r REG 252,1 991 1300925 /var/data/checkpoints/1012312/ledger.db/000216.sst (deleted) beam.smp 3499023 root 7557r REG 252,1 1366 1301243 /var/data/checkpoints/1012312/ledger.db/000377.sst (deleted) beam.smp 3499023 root 7558r REG 252,1 1267 1301256 /var/data/checkpoints/1012312/ledger.db/000386.sst (deleted) beam.smp 3499023 root 7559r REG 252,1 3098019 1300128 /var/data/checkpoints/1012312/ledger.db/000120.sst (deleted) beam.smp 3499023 root 7560r REG 252,1 1184 1301298 /var/data/checkpoints/1012312/ledger.db/000415.sst (deleted) beam.smp 3499023 root 7561r REG 252,1 1072 1301306 /var/data/checkpoints/1012312/ledger.db/000424.sst (deleted) beam.smp 3499023 root 7562r REG 252,1 1362 1300328 /var/data/checkpoints/1012312/ledger.db/000197.sst (deleted) beam.smp 3499023 root 7563r REG 252,1 1367 1301322 /var/data/checkpoints/1012312/ledger.db/000433.sst (deleted) beam.smp 3499023 root 7564r REG 252,1 1284 1300906 /var/data/checkpoints/1012312/ledger.db/000207.sst (deleted) beam.smp 3499023 root 7565r REG 252,1 1121 1300162 /var/data/checkpoints/1012312/ledger.db/000129.sst (deleted) beam.smp 3499023 root 7566r REG 252,1 1057 1300226 /var/data/checkpoints/1012312/ledger.db/000155.sst (deleted) beam.smp 3499023 root 7567r REG 252,1 1121 1301267 /var/data/checkpoints/1012312/ledger.db/000396.sst (deleted) beam.smp 3499023 root 7568r REG 252,1 1120 1301114 /var/data/checkpoints/1012312/ledger.db/000293.sst (deleted) beam.smp 3499023 root 7569r REG 252,1 1265 1301198 /var/data/checkpoints/1012312/ledger.db/000349.sst (deleted) beam.smp 3499023 root 7570r REG 252,1 1057 1300189 /var/data/checkpoints/1012312/ledger.db/000138.sst (deleted) beam.smp 3499023 root 7571r REG 252,1 1163 1300249 /var/data/checkpoints/1012312/ledger.db/000164.sst (deleted) beam.smp 3499023 root 7572r REG 252,1 31822 1301395 /var/data/checkpoints/1012312/ledger.db/000479.sst (deleted) beam.smp 3499023 root 7573r REG 252,1 27780 1301257 /var/data/checkpoints/1012312/ledger.db/000387.sst (deleted) beam.smp 3499023 root 7574r REG 252,1 32739 1301244 /var/data/checkpoints/1012312/ledger.db/000378.sst (deleted) beam.smp 3499023 root 7575r REG 252,1 33869 1301379 /var/data/checkpoints/1012312/ledger.db/000470.sst (deleted) beam.smp 3499023 root 7576r REG 252,1 31034 1300288 /var/data/checkpoints/1012312/ledger.db/000181.sst (deleted) beam.smp 3499023 root 7577r REG 252,1 43869 1301099 /var/data/checkpoints/1012312/ledger.db/000285.sst (deleted) beam.smp 3499023 root 7578r REG 252,1 41803 1300948 /var/data/checkpoints/1012312/ledger.db/000226.sst (deleted) beam.smp 3499023 root 7579r REG 252,1 31937 1300191 /var/data/checkpoints/1012312/ledger.db/000139.sst (deleted) beam.smp 3499023 root 7580r REG 252,1 29187 1301027 /var/data/checkpoints/1012312/ledger.db/000255.sst (deleted) beam.smp 3499023 root 7581r REG 252,1 30330 1301268 /var/data/checkpoints/1012312/ledger.db/000397.sst (deleted) beam.smp 3499023 root 7582r REG 252,1 32431 1300926 /var/data/checkpoints/1012312/ledger.db/000217.sst (deleted) beam.smp 3499023 root 7583r REG 252,1 31162 1301367 /var/data/checkpoints/1012312/ledger.db/000460.sst (deleted) beam.smp 3499023 root 7584r REG 252,1 47570 1300910 /var/data/checkpoints/1012312/ledger.db/000208.sst (deleted) beam.smp 3499023 root 7585r REG 252,1 31129 1301299 /var/data/checkpoints/1012312/ledger.db/000416.sst (deleted) beam.smp 3499023 root 7586r REG 252,1 31889 1300205 /var/data/checkpoints/1012312/ledger.db/000147.sst (deleted) beam.smp 3499023 root 7587r REG 252,1 37768 1301199 /var/data/checkpoints/1012312/ledger.db/000350.sst (deleted) beam.smp 3499023 root 7588r REG 252,1 31152 1301323 /var/data/checkpoints/1012312/ledger.db/000434.sst (deleted) beam.smp 3499023 root 7589r REG 252,1 36189 1301048 /var/data/checkpoints/1012312/ledger.db/000264.sst (deleted) beam.smp 3499023 root 7590r REG 252,1 35060 1300250 /var/data/checkpoints/1012312/ledger.db/000165.sst (deleted) beam.smp 3499023 root 7591r REG 252,1 35012 1300132 /var/data/checkpoints/1012312/ledger.db/000121.sst (deleted) beam.smp 3499023 root 7592r REG 252,1 33885 1301353 /var/data/checkpoints/1012312/ledger.db/000452.sst (deleted) beam.smp 3499023 root 7593r REG 252,1 66997 1301142 /var/data/checkpoints/1012312/ledger.db/000313.sst (deleted) beam.smp 3499023 root 7594r REG 252,1 31563 1300273 /var/data/checkpoints/1012312/ledger.db/000174.sst (deleted) beam.smp 3499023 root 7595r REG 252,1 29164 1301284 /var/data/checkpoints/1012312/ledger.db/000406.sst (deleted) beam.smp 3499023 root 7596r REG 252,1 57752 1301156 /var/data/checkpoints/1012312/ledger.db/000322.sst (deleted) beam.smp 3499023 root 7597r REG 252,1 30414 1300329 /var/data/checkpoints/1012312/ledger.db/000198.sst (deleted) beam.smp 3499023 root 7598r REG 252,1 30407 1301340 /var/data/checkpoints/1012312/ledger.db/000444.sst (deleted) beam.smp 3499023 root 7599r REG 252,1 34988 1300227 /var/data/checkpoints/1012312/ledger.db/000156.sst (deleted) beam.smp 3499023 root 7600r REG 252,1 28453 1301308 /var/data/checkpoints/1012312/ledger.db/000425.sst (deleted) beam.smp 3499023 root 7601r REG 252,1 30379 1300308 /var/data/checkpoints/1012312/ledger.db/000189.sst (deleted) beam.smp 3499023 root 7602r REG 252,1 34934 1300163 /var/data/checkpoints/1012312/ledger.db/000130.sst (deleted) beam.smp 3499023 root 7603r REG 252,1 27031 1301004 /var/data/checkpoints/1012312/ledger.db/000248.sst (deleted) beam.smp 3499023 root 7604r REG 252,1 36709 1300976 /var/data/checkpoints/1012312/ledger.db/000235.sst (deleted) beam.smp 3499023 root 7605r REG 252,1 65745 1301115 /var/data/checkpoints/1012312/ledger.db/000294.sst (deleted) beam.smp 3499023 root 7606r REG 252,1 35685 1301079 /var/data/checkpoints/1012312/ledger.db/000277.sst (deleted) beam.smp 3499023 root 7607r REG 252,1 73787 1301129 /var/data/checkpoints/1012312/ledger.db/000303.sst (deleted) beam.smp 3499023 root 7608r REG 252,1 53146 1301172 /var/data/checkpoints/1012312/ledger.db/000331.sst (deleted) beam.smp 3499023 root 7609r REG 252,1 29173 1300993 /var/data/checkpoints/1012312/ledger.db/000242.sst (deleted) beam.smp 3499023 root 7610r REG 252,1 38098 1301214 /var/data/checkpoints/1012312/ledger.db/000360.sst (deleted) beam.smp 3499023 root 7611r REG 252,1 50473 1301187 /var/data/checkpoints/1012312/ledger.db/000341.sst (deleted) beam.smp 3499023 root 7612r REG 252,1 28616 1301230 /var/data/checkpoints/1012312/ledger.db/000369.sst (deleted) beam.smp 3499023 root 7613r REG 252,1 7001 1301396 /var/data/checkpoints/1012312/ledger.db/000480.sst (deleted) beam.smp 3499023 root 7614r REG 252,1 6772 1301380 /var/data/checkpoints/1012312/ledger.db/000471.sst (deleted) beam.smp 3499023 root 7615r REG 252,1 11230 1301285 /var/data/checkpoints/1012312/ledger.db/000407.sst (deleted) beam.smp 3499023 root 7616r REG 252,1 7352 1301269 /var/data/checkpoints/1012312/ledger.db/000398.sst (deleted) beam.smp 3499023 root 7617r REG 252,1 13075 1301258 /var/data/checkpoints/1012312/ledger.db/000388.sst (deleted) beam.smp 3499023 root 7618r REG 252,1 10351 1301245 /var/data/checkpoints/1012312/ledger.db/000379.sst (deleted) beam.smp 3499023 root 7619r REG 252,1 11641 1300274 /var/data/checkpoints/1012312/ledger.db/000175.sst (deleted) beam.smp 3499023 root 7620r REG 252,1 8940 1301368 /var/data/checkpoints/1012312/ledger.db/000461.sst (deleted) beam.smp 3499023 root 7621r REG 252,1 7752 1301324 /var/data/checkpoints/1012312/ledger.db/000435.sst (deleted) beam.smp 3499023 root 7622r REG 252,1 2625 1300330 /var/data/checkpoints/1012312/ledger.db/000199.sst (deleted) beam.smp 3499023 root 7623r REG 252,1 5551 1301100 /var/data/checkpoints/1012312/ledger.db/000286.sst (deleted) beam.smp 3499023 root 7624r REG 252,1 7886 1300192 /var/data/checkpoints/1012312/ledger.db/000140.sst (deleted) beam.smp 3499023 root 7625r REG 252,1 10726 1300949 /var/data/checkpoints/1012312/ledger.db/000227.sst (deleted) beam.smp 3499023 root 7626r REG 252,1 11400 1301028 /var/data/checkpoints/1012312/ledger.db/000256.sst (deleted) beam.smp 3499023 root 7627r REG 252,1 8660 1301143 /var/data/checkpoints/1012312/ledger.db/000314.sst (deleted) beam.smp 3499023 root 7628r REG 252,1 8242 1301341 /var/data/checkpoints/1012312/ledger.db/000445.sst (deleted) beam.smp 3499023 root 7629r REG 252,1 10362 1300911 /var/data/checkpoints/1012312/ledger.db/000209.sst (deleted) beam.smp 3499023 root 7630r REG 252,1 6553 1300133 /var/data/checkpoints/1012312/ledger.db/000122.sst (deleted) beam.smp 3499023 root 7631r REG 252,1 9888 1301300 /var/data/checkpoints/1012312/ledger.db/000417.sst (deleted) beam.smp 3499023 root 7632r REG 252,1 8224 1300252 /var/data/checkpoints/1012312/ledger.db/000166.sst (deleted) beam.smp 3499023 root 7633r REG 252,1 9334 1301354 /var/data/checkpoints/1012312/ledger.db/000453.sst (deleted) beam.smp 3499023 root 7634r REG 252,1 8422 1300927 /var/data/checkpoints/1012312/ledger.db/000218.sst (deleted)

On the validators with problems, I had around 7500 OFD. On a validator without any problems I had around 450 OFD.

@madninja
Copy link
Member

Did bumping max file descriptors up high stop this from happening? Not saying there's not a potential leak, but rocksdb can have a lot of file descriptors open while it compacts its database

@andreiguzga
Copy link
Author

It stopped the validator going offline but the issue is still replicating. I can still see OFD marked as deleted. If I restart the validators, those Descriptors will be cleared. Don't know exactly how rocksdb is working but I've seen different issues online regarding this behaviour. I think when checkpoints are being done and files are being renamed, the OFD for those files are not released and remain open until you restart the validator. Maybe this can help facebook/rocksdb#8041.

From what I can see, all OFD marked with deleted are related to checkpoints. I can't see any other OFD marked like that.

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

No branches or pull requests

2 participants