"404" messages but check reports everything ok

towerbr · 4 February 2021 23:17

A routine backup has just been performed (70M files on 190G storage):

INFO BACKUP_STATS All chunks: 152685 total, 186,912M bytes; 92 new, 125,054K bytes, 72,285K bytes uploaded
INFO BACKUP_STATS Total running time: 00:03:35

However, I noticed ~50 lines like these in the log:

BACKBLAZE_CALL [3] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/9d/a04f43c8e98cc0f292f66400c0ee978186ebde152b902c7e7b9ae72c86bec7' returned status code 404
BACKBLAZE_CALL [1] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/00/f0e7444e0063cd0eab437b64979fe2bd02d28295a24b9f81da7f6a5c97bc57' returned status code 404
BACKBLAZE_CALL [2] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/f2/5ee0e2bdbba777ad5f744df2c2ab9b733a148d4115aa57e6d6ff7be4e79485' returned status code 404
(...)

Strange this “404” messages. Whats is looking for?

The check reports everything is ok.

saspus · 5 February 2021 00:27

It checks if the specific chunk is present in the storage and if so — skip uploading it.

To confirm — check if any “missing” chunk from the log is now present in the storage after backup completed.

towerbr · 5 February 2021 01:27

Yes, I checked and the three chunks above are in storage.

But what I don’t understand is why these 404 messages appear after the backup ends:

(...)
2021-02-04 19:37:07.195 INFO UPLOAD_PROGRESS Uploaded chunk 134 size 3614195, 2.27MB/s 00:00:03 97.5%
2021-02-04 19:37:07.559 INFO UPLOAD_PROGRESS Uploaded chunk 119 size 1725811, 2.29MB/s 00:00:02 98.3%
2021-02-04 19:37:12.819 INFO UPLOAD_PROGRESS Uploaded chunk 178 size 3745008, 2.21MB/s 00:00:01 100.0%
2021-02-04 19:37:14.517 TRACE BACKBLAZE_CALL [3] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/9d/a04f43c8e98cc0f292f66400c0ee978186ebde152b902c7e7b9ae72c86bec7' returned status code 404
2021-02-04 19:37:14.540 TRACE BACKBLAZE_CALL [1] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/00/f0e7444e0063cd0eab437b64979fe2bd02d28295a24b9f81da7f6a5c97bc57' returned status code 404
2021-02-04 19:37:14.540 TRACE BACKBLAZE_CALL [2] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/f2/5ee0e2bdbba777ad5f744df2c2ab9b733a148d4115aa57e6d6ff7be4e79485' returned status code 404
(...)

gchen · 5 February 2021 01:40

These 3 chunks are metadata chunks, which are not reported by the UPLOAD_PROGRESS messages.

towerbr · 6 February 2021 23:36

Ok, when it comes to file chunks I understand the logic:

package the file
check if the chunk exists (404 messages)
does not exist? ok, so upload

2021-02-06 11:31:12.457 TRACE PACK_START Packing file_xxxx
2021-02-06 11:31:12.458 INFO PACK_END Packed file_xxxx
2021-02-06 11:31:12.571 TRACE BACKBLAZE_CALL [3] URL request 'HEAD https://f001.backblazeb2.com/file/xxxx/chunks/61/b90e9040dd7c0ece7efe14af07dc613f3acef80417ba81101052c7ba40f1e6' returned status code 404
2021-02-06 11:31:12.652 INFO UPLOAD_PROGRESS Uploaded chunk 2 size 290834, 5.92MB/s 00:00:02 84.0%

.
But I don’t understand why nothing is done after all these checks of metadata chunks at the end of the backup. They return messages of not found (404), and then there is no upload, only the final messages of the backup.

2021-02-06 11:31:19.281 INFO UPLOAD_PROGRESS Uploaded chunk 34 size 664858, 3.03MB/s 00:00:01 93.2%
2021-02-06 11:31:23.046 INFO UPLOAD_PROGRESS Uploaded chunk 1 size 3011150, 2.49MB/s 00:00:01 100.0%
2021-02-06 11:31:24.857 TRACE BACKBLAZE_CALL [1] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/e7/2c3fc3a9f74de87a2b47e59b84cbf94c72a0737560e5c5a840bb4afb3c543d' returned status code 404
2021-02-06 11:31:24.876 TRACE BACKBLAZE_CALL [0] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/81/3cb3a5968e404f24e55bbf693785b77b016557613c6a081b76d28c145c448e' returned status code 404
2021-02-06 11:31:24.882 TRACE BACKBLAZE_CALL [4] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/86/4262aaf84a0337e6f50061e46c2086b83b328a8731651b36c9d56b5ab5be05' returned status code 404
2021-02-06 11:31:24.985 TRACE BACKBLAZE_CALL [2] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/b0/96007937f993a657b599d32a6483f4a64ffe198fbeab2fc9e3365b6d5fe542' returned status code 404
2021-02-06 11:31:26.417 TRACE BACKBLAZE_CALL [3] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/f1/f3b13b14a9eb0a8551db0e9e44f57a9ec5be57aef02ea60c10d6a4761bf1e8' returned status code 404
2021-02-06 11:31:26.466 TRACE BACKBLAZE_CALL [5] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/52/fadee47fc6654485d09bd9977746543140a526c9fa854a21bc4edbb858139e' returned status code 404
2021-02-06 11:31:33.960 TRACE BACKBLAZE_CALL [7] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/82/304d0b16db057a4951c031c165a77b7967f5812945fe03ab990c26c819bc62' returned status code 404
2021-02-06 11:31:34.171 TRACE BACKBLAZE_CALL [8] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/46/bbf6278c2ce8353968a687ec7fd5836287ee80148f92d1a905228e9bc8c428' returned status code 404
2021-02-06 11:31:34.195 TRACE BACKBLAZE_CALL [6] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/3a/4ff227d8f205d9997ec07a59eac6c6ee88d5b5c97b940a11b92fba0e5be278' returned status code 404
2021-02-06 11:31:34.380 TRACE BACKBLAZE_CALL [9] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/a6/64b07aa22b4748b90f776171236a69c781da794ed6ee3a7cf5876fcfad9401' returned status code 404
2021-02-06 11:31:34.424 TRACE BACKBLAZE_CALL [0] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/81/b9ae9795e9740fe13f3b3d8e311e92c75a3fa557353d283a289604c1db679a' returned status code 404
2021-02-06 11:31:34.447 TRACE BACKBLAZE_CALL [2] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/85/56afe656fdd83f37033c3cdfc83f7dc67cb21ebab5d0458161f63d7326ecc4' returned status code 404
2021-02-06 11:31:34.492 TRACE BACKBLAZE_CALL [3] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/4e/d93e35579530581618a016b91c03c1382976fd99162572624d71ac1f0628b9' returned status code 404
2021-02-06 11:31:34.591 TRACE BACKBLAZE_CALL [4] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/f6/82c92542fc76dc20cebc70b2fb5714521dadcc1b780a1bec1dd9b04d25606e' returned status code 404
2021-02-06 11:31:34.617 TRACE BACKBLAZE_CALL [1] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/84/068d0cd27264ecae8856afe2b54ebe61c243ab2f78156754da498976051f57' returned status code 404
2021-02-06 11:31:34.922 TRACE BACKBLAZE_CALL [5] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/8b/c53fb84a1dc9d01c3ab1204910e2fcf275e7446accf258692fd24df27fd795' returned status code 404
2021-02-06 11:31:38.869 TRACE BACKBLAZE_CALL [9] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/0c/ad9935bef97b4fde32993f75e6993f72aa20298583e0acc6a56a68f41d5806' returned status code 404
2021-02-06 11:31:38.872 TRACE BACKBLAZE_CALL [0] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/1d/ef0e44b8567c7e38019791990df8250c762a2361b575de0e037be740f28e88' returned status code 404
2021-02-06 11:31:40.650 TRACE BACKBLAZE_CALL [7] URL request 'HEAD https://f001.backblazeb2.com/file/****/chunks/f1/3b683193b7fb9b88c0087b00e073d181eb9ed9c319b3b1fd4a9b2adf098f84' returned status code 404

Uploads of metadata chunks are made after that, just are not reported by UPLOAD_PROGRESS messages, as you mentioned?

gchen · 7 February 2021 03:23

This is correct…

saspus · 7 February 2021 03:30

Intentional? Or a bug? Arguably snapshot chunks are the most important ones.

gchen · 7 February 2021 04:13

This is just a by-product of how the backup engine is implemented. I expect this will be changed when the backup engine is re-written to reduce memory consumption.

towerbr · 17 February 2021 04:13

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.