Backup success but no files in backup folders - and -1bytes file sizes

Hi!

Thanks for your dedication and effort, developers. You are great! I love your software, TRMM too!!

I also sit with the -1 bytes backup problem. Not only that, but also that backups complete with no files in the backup folders. We first thought Avast Business was blocking UrBackup (it was, but we added the exceptions, of course.)
((And this client PC also blocks our Tactical RMM agent…but it’s a topic for a different forum))

> UrBackup 2.5.27 server running on Linux
> Client running on Version 2.4.11 on a 
  Microsoft Windows 7 Professional Service Pack 1 (build 7601), 32-bit PC

For the record, I don’t have a schedule problem, such as the topic includes, only the size issue, and files not backing up, but the log indicates “success.”

I will come back to this…

We spun up a vm to simulate the problem again, Win10, and found that the VM does backup, but also shows -1 bytes for backups. (Avast installed, but disabled, yet, still get this “-1 bytes” backup sizes…

The VM backup logs indicate files are processed, hashed, linked, and transported via the electric current connecting the world wide WIIIDE wide (echo…) web.

Unlike the client that has no files in the backup, the VM has files in the backups folder, but the size on the server shows zero (0) or -1 bytes.

I have done several things to get the backups to run normal (Hope i can recall all)

  • Uninstalled and reinstalled,
  • Rebooted (I really did, several times)
  • Avast Business is disabled (As mentioned, on the VM)
  • …and uninstalled and reinstalled…again :sweat_smile:

I’m concluding that there is most likely (again) a problem bigger than my comprehension of the topic…

So, back to the initial faulty client: We found that:

  • Not a single file is backed up.
  • Sizes are technically correct for this client, since nothing backed up…
  • Don’t know what to do…
  • VSS is not a mentioned issue in the logs…
  • There are backup folders specified in settings

Please see imageS, and log below.

Client PC backup stats

The errors (from the Errors column) in the image are either one or more of the following… but are not present any more.

  • errorcode=2
  • Error 404
  • Errorcode: TIMEOUT (2)

Another thing reflecting in logs is
* Waiting for metadata download stream to finish (attempt 10, xxxxPc). 1m 50s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
This happens for a few minutes, and moves on…

Also…

In the server log, it states (an extract from server log, specifically the portion during the client backup) :

2023-01-04 16:13:39: Starting unscheduled full file backup...
2023-01-04 16:13:47: Selected no components to backup
2023-01-04 16:13:47: Indexing of "Users" done. 5 filesystem lookups 0 db lookups and 0 db updates
2023-01-04 16:13:47: SeanMPc: Loading file list...
2023-01-04 16:13:48: SeanMPc: Started loading files...
2023-01-04 16:13:48: Waiting for file transfers...
2023-01-04 16:13:50: Waiting for file hashing and copying threads...
2023-01-04 16:13:52: Waiting for metadata download stream to finish
2023-01-04 16:15:50: Encryption overhead: 192 bytes
2023-01-04 16:15:50: Writing new file list...
2023-01-04 16:15:50: All metadata was present
2023-01-04 16:15:51: Encryption overhead: 423 bytes
2023-01-04 16:15:51: Transferred 1.73633 KB - Average speed: 5.448 KBit/s
2023-01-04 16:15:51: (Before compression: 1.50781 KB ratio: 0.868391)
2023-01-04 16:15:51: Script output Line(1):   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
2023-01-04 16:15:51: Script output Line(2):                                  Dload  Upload   Total   Spent    Left  Speed
2023-01-04 16:15:51: Script output Line(3): ^M  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
2023-01-04 16:15:51: Script output Line(4):         <!DOCTYPE html>
2023-01-04 16:15:51: Script output Line(5):         <html>
2023-01-04 16:15:51: Script output Line(6):             <head>
2023-01-04 16:15:51: Script output Line(7):                 <meta charset="utf-8"/>
2023-01-04 16:15:51: Script output Line(8):                 <meta http-equiv="X-UA-Compatible" content="IE=edge,chrome=1"/>
2023-01-04 16:15:51: Script output Line(9):             <meta name="viewport" content="width=device-width, initial-scale=1, user-scalable=no"/>
2023-01-04 16:15:51: Script output Line(10):
2023-01-04 16:15:51: Script output Line(11):
2023-01-04 16:15:51: Script output Line(12):                 <title>Odoo</title>
2023-01-04 16:15:51: Script output Line(13):                 <link type="image/x-icon" rel="shortcut icon" href="/web/static/src/img/favicon.ico"/>
2023-01-04 16:15:51: Script output Line(14):             <link rel="preload" href="/web/static/lib/fontawesome/fonts/fontawesome-webfont.woff2?v=4.7.0" as="font" crossorigin=""/>
2023-01-04 16:15:51: Script output Line(15):             <link type="text/css" rel="stylesheet" href="/web/content/533-40a9856/web.assets_common.css" data-asset-xmlid="web.assets_common" data-asset-version="40a9856"/>
2023-01-04 16:15:51: Script output Line(16):             <link type="text/css" rel="stylesheet" href="/web/content/555-1bbb09a/web.assets_frontend.css" data-asset-xmlid="web.assets_frontend" data-asset-version="1bbb09a"/>
2023-01-04 16:15:51: Script output Line(17):
2023-01-04 16:15:51: Script output Line(18):
2023-01-04 16:15:51: Script output Line(19):                 <script id="web.layout.odooscript" type="text/javascript">
2023-01-04 16:15:51: Script output Line(20):                     var odoo = {
2023-01-04 16:15:51: Script output Line(21):                         csrf_token: "c95d46f4ab2990a687a8f41da038d51d7fde8436o1704377751",
2023-01-04 16:15:51: Script output Line(22):                         debug: "",
2023-01-04 16:15:51: Script output Line(23):                     };
2023-01-04 16:15:51: Script output Line(24):                 </script>
2023-01-04 16:15:51: Script output Line(25):             <script type="text/javascript">
2023-01-04 16:15:51: Script output Line(26):                 odoo.session_info = {"is_admin": false, "is_system": false, "is_website_user": false, "user_id": false, "is_frontend": true, "translationURL": "/website/translations", "c>
2023-01-04 16:15:51: Script output Line(27):                 if (!/(^|;\s)tz=/.test(document.cookie)) {
2023-01-04 16:15:51: Script output Line(28):                     const userTZ = Intl.DateTimeFormat().resolvedOptions().timeZone;
2023-01-04 16:15:51: Script output Line(29):                     document.cookie = `tz=${userTZ}; path=/`;
2023-01-04 16:15:51: Script output Line(30):                 }
2023-01-04 16:15:51: Script output Line(31):             </script>
2023-01-04 16:15:51: Script output Line(32):             <script defer="defer" type="text/javascript" src="/web/content/200-947fd35/web.assets_common_minimal_js.js" data-asset-xmlid="web.assets_common_minimal_js" data-asset-version>
2023-01-04 16:15:51: Script output Line(33):             <script defer="defer" type="text/javascript" src="/web/content/201-fc46a1e/web.assets_frontend_minimal_js.js" data-asset-xmlid="web.assets_frontend_minimal_js" data-asset-ver>
2023-01-04 16:15:51: Script output Line(34):
2023-01-04 16:15:51: Script output Line(35):
2023-01-04 16:15:51: Script output Line(36):
2023-01-04 16:15:51: Script output Line(37):             <script defer="defer" type="text/javascript" data-src="/web/content/556-f1a852a/web.assets_common_lazy.js" data-asset-xmlid="web.assets_common_lazy" data-asset-version="f1a85>
2023-01-04 16:15:51: Script output Line(38):             <script defer="defer" type="text/javascript" data-src="/web/content/557-3caa46b/web.assets_frontend_lazy.js" data-asset-xmlid="web.assets_frontend_lazy" data-asset-version="3
2023-01-04 16:15:51: Script output Line(39):
2023-01-04 16:15:51: Script output Line(40):
2023-01-04 16:15:51: Script output Line(41):
2023-01-04 16:15:51: Script output Line(42):             </head>
2023-01-04 16:15:51: Script output Line(43):             <body>
2023-01-04 16:15:51: Script output Line(44):                 <div id="wrapwrap" class="  ">
2023-01-04 16:15:51: Script output Line(45):                 <header id="top" data-anchor="true">
2023-01-04 16:15:51: Script output Line(46):                     <nav class="navbar navbar-expand navbar-light bg-light">
2023-01-04 16:15:51: Script output Line(47):                 <div class="container">
2023-01-04 16:15:51: Script output Line(48):                     <a href="/" class="navbar-brand logo">
2023-01-04 16:15:51: Script output Line(49):                         <img src="/logo.png?company=1" alt="Logo of YourCompany" title="YourCompany"/>
2023-01-04 16:15:51: Script output Line(50):                     </a>
2023-01-04 16:15:51: Script output Line(51):                     <ul id="top_menu" class="nav navbar-nav ml-auto">
2023-01-04 16:15:51: Script output Line(52):
2023-01-04 16:15:51: Script output Line(53):             <li class="nav-item o_no_autohide_item">
2023-01-04 16:15:51: Script output Line(54):                 <a href="/web/login" class="nav-link">Sign in</a>
2023-01-04 16:15:51: Script output Line(55):             </li>
2023-01-04 16:15:51: Script output Line(56):
2023-01-04 16:15:51: Script output Line(57):
2023-01-04 16:15:51: Script output Line(58):
2023-01-04 16:15:51: Script output Line(59):
2023-01-04 16:15:51: Script output Line(60):
2023-01-04 16:15:51: Script output Line(61):                     </ul>
2023-01-04 16:15:51: Script output Line(62):                 </div>
2023-01-04 16:15:51: Script output Line(63):             </nav>
2023-01-04 16:15:51: Script output Line(64):         </header>
2023-01-04 16:15:51: Script output Line(65):                 <main>
2023-01-04 16:15:51: Script output Line(66):
2023-01-04 16:15:51: Script output Line(67):
2023-01-04 16:15:51: Script output Line(68):
2023-01-04 16:15:51: Script output Line(69):             <div id="wrap">
2023-01-04 16:15:51: Script output Line(70):
2023-01-04 16:15:51: Script output Line(71):                 <div class="oe_structure oe_empty">
2023-01-04 16:15:51: Script output Line(72):                     <section class="pt128 pb104">
2023-01-04 16:15:51: Script output Line(73):                         <div class="container">
2023-01-04 16:15:51: Script output Line(74):                             <div class="row">
2023-01-04 16:15:51: Script output Line(75):                                 <div class="col-md-6 text-center text-md-right my-md-auto mb-5 mb-md-0">
2023-01-04 16:15:51: Script output Line(76):                                     <img class="img img-fluid" src="/http_routing/static/src/img/404.svg"/>
2023-01-04 16:15:51: Script output Line(77):                                 </div>
2023-01-04 16:15:51: Script output Line(78):                                 <div class="col-md-6 text-center text-md-left my-auto^M100  6628  100  6628    0     0  18883      0 --:--:-- --:--:-- --:--:-- 18883
2023-01-04 16:15:51: Script output Line(79): ">
2023-01-04 16:15:51: Script output Line(80):                                     <h1 class="sr-only">Error 404</h1>
2023-01-04 16:15:51: Script output Line(81):                                     <h2 class="mb16">We couldn't find the page you're looking for!</h2>
2023-01-04 16:15:51: Script output Line(82):                                     <p><b>Don't panic.</b> If you think it's our mistake, please send us a message on <a href="/contactus">this page</a>.</p>
2023-01-04 16:15:51: Script output Line(83):                                 </div>
2023-01-04 16:15:51: Script output Line(84):                                 <div class="col-12 pt40 pb24">
2023-01-04 16:15:51: Script output Line(85):                                     <hr/>
2023-01-04 16:15:51: Script output Line(86):                                 </div>
2023-01-04 16:15:51: Script output Line(87):                                 <div class="col-12">
2023-01-04 16:15:51: Script output Line(88):                                     <p class="text-center pt24">Maybe you were looking for one of these <b>popular pages?</b></p>
2023-01-04 16:15:51: Script output Line(89):                                     <ul class="list-inline text-center">
2023-01-04 16:15:51: Script output Line(90):                                         <li class="list-inline-item mb-2"><a href="/" class="btn btn-secondary">Home</a></li>
2023-01-04 16:15:51: Script output Line(91):                                     </ul>
2023-01-04 16:15:51: Script output Line(92):                                 </div>
2023-01-04 16:15:51: Script output Line(93):                             </div>
2023-01-04 16:15:51: Script output Line(94):                         </div>
2023-01-04 16:15:51: Script output Line(95):                     </section>
2023-01-04 16:15:51: Script output Line(96):                 </div>
2023-01-04 16:15:51: Script output Line(97):             </div>
2023-01-04 16:15:51: Script output Line(98):
2023-01-04 16:15:51: Script output Line(99):                 </main>
2023-01-04 16:15:51: Script output Line(100):                 <footer id="bottom" data-anchor="true" class="bg-light o_footer">
2023-01-04 16:15:51: Script output Line(101):                     <div id="footer"></div>
2023-01-04 16:15:51: Script output Line(102):                     <div class="o_footer_copyright">
2023-01-04 16:15:51: Script output Line(103):                         <div class="container py-3">
2023-01-04 16:15:51: Script output Line(104):                             <div class="row">
2023-01-04 16:15:51: Script output Line(105):                                 <div class="col-sm text-center text-sm-left text-muted">
2023-01-04 16:15:51: Script output Line(106):
2023-01-04 16:15:51: Script output Line(107):
2023-01-04 16:15:51: Script output Line(108):
2023-01-04 16:15:51: Script output Line(109):                                     <span class="o_footer_copyright_name mr-2">Copyright &copy; <span itemprop="name">YourCompany</span></span>
2023-01-04 16:15:51: Script output Line(110):
2023-01-04 16:15:51: Script output Line(111):
2023-01-04 16:15:51: Script output Line(112):
2023-01-04 16:15:51: Script output Line(113):
2023-01-04 16:15:51: Script output Line(114):
2023-01-04 16:15:51: Script output Line(115):
2023-01-04 16:15:51: Script output Line(116):                                 </div>
2023-01-04 16:15:51: Script output Line(117):                                 <div class="col-sm text-center text-sm-right">
2023-01-04 16:15:51: Script output Line(118):
2023-01-04 16:15:51: Script output Line(119):         <div class="o_brand_promotion">
2023-01-04 16:15:51: Script output Line(120):
2023-01-04 16:15:51: Script output Line(121):
2023-01-04 16:15:51: Script output Line(122):
2023-01-04 16:15:51: Script output Line(123):         Powered by
2023-01-04 16:15:51: Script output Line(124):             <a target="_blank" class="badge badge-light" href="http://www.odoo.com?utm_source=db&amp;utm_medium=portal">
2023-01-04 16:15:51: Script output Line(125):                 <img alt="Odoo" src="/web/static/src/img/odoo_logo_tiny.png" style="height: 1em; vertical-align: baseline;"/>
2023-01-04 16:15:51: Script output Line(126):             </a>
2023-01-04 16:15:51: Script output Line(127):
2023-01-04 16:15:51: Script output Line(128):
2023-01-04 16:15:51: Script output Line(129):         </div>
2023-01-04 16:15:51: Script output Line(130):
2023-01-04 16:15:51: Script output Line(131):                                 </div>
2023-01-04 16:15:51: Script output Line(132):                             </div>
2023-01-04 16:15:51: Script output Line(133):                         </div>
2023-01-04 16:15:51: Script output Line(134):                     </div>
2023-01-04 16:15:51: Script output Line(135):                 </footer>
2023-01-04 16:15:51: Script output Line(136):             </div>
2023-01-04 16:15:51: Script output Line(137):         </body>
2023-01-04 16:15:51: Script output Line(138):         </html>
2023-01-04 16:15:51: Script output Line(139):
2023-01-04 16:15:51: Script output Line(140):
2023-01-04 16:15:59: Time taken for backing up client SeanMPc: 2m 20s
2023-01-04 16:15:59: Backup succeeded
2023-01-04 16:16:00: server_prepare_hash Thread finished (exit)
2023-01-04 16:16:00: server_hash Thread finished - normal
2023-01-04 16:16:22: Authentication failed in InternetServiceConnector::ReceivePackets: Auth failed (Authkey/password wrong)
2023-01-04 16:18:15: Waiting for file transfers...
2023-01-04 16:18:18: Waiting for file hashing and copying threads...
2023-01-04 16:18:19: Writing new file list...
2023-01-04 16:18:19: All metadata was present
2023-01-04 16:18:19: Number of re-added file entries is 5846
2023-01-04 16:18:19: Number of copied file entries from last backup is 5765
2023-01-04 16:18:20: Transferred 190.998 MB - Average speed: 241.92 KBit/s
2023-01-04 16:18:20: (Before compression: 509.846 MB ratio: 2.66937)
2023-01-04 16:18:20: 114.21 MB of files were already present on the server and did not need to be transferred

I suspect they were from the Avast Antivirus… since we had not this issue the last 14 backup sessions. But still no files in the backup folders.

Log (client)

01/04/23 14:54  
INFO  
Starting unscheduled full file backup...
01/04/23 14:54  
DEBUG  
xxxxxxPc: Connecting for filelist...
01/04/23 14:54  
DEBUG  
xxxxxxPc: Waiting for filelist
01/04/23 14:54  
DEBUG  
xxxxxxPc: Connecting for filelist (async)...
01/04/23 14:55  
INFO  
Selected no components to backup
01/04/23 14:55  
INFO  
Indexing of "Users" done. 5 filesystem lookups 0 db lookups and 0 db updates
01/04/23 14:55  
DEBUG  
xxxxxxPc: Doing backup without hashed transfer...
01/04/23 14:55  
INFO  
xxxxxxPc: Loading file list...
01/04/23 14:55  
DEBUG  
Loading file "Users" (metadata only)
01/04/23 14:55  
INFO  
Waiting for file hashing and copying threads...
01/04/23 14:55  
INFO  
Waiting for metadata download stream to finish
01/04/23 14:55  
DEBUG  
Waiting for metadata download stream to finish (attempt 0, xxxxxxPc). 10s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:55  
DEBUG  
Waiting for metadata download stream to finish (attempt 1, xxxxxxPc). 20s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:55  
DEBUG  
Waiting for metadata download stream to finish (attempt 2, xxxxxxPc). 30s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:55  
DEBUG  
Waiting for metadata download stream to finish (attempt 3, xxxxxxPc). 40s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:56  
DEBUG  
Waiting for metadata download stream to finish (attempt 4, xxxxxxPc). 51s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:56  
DEBUG  
Waiting for metadata download stream to finish (attempt 5, xxxxxxPc). 1m 1s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:56  
DEBUG  
Waiting for metadata download stream to finish (attempt 6, xxxxxxPc). 1m 11s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:56  
DEBUG  
Waiting for metadata download stream to finish (attempt 7, xxxxxxPc). 1m 21s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:56  
DEBUG  
Waiting for metadata download stream to finish (attempt 8, xxxxxxPc). 1m 31s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:56  
DEBUG  
Waiting for metadata download stream to finish (attempt 9, xxxxxxPc). 1m 41s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:57  
DEBUG  
Waiting for metadata download stream to finish (attempt 10, xxxxxxPc). 1m 52s since last meta-data transfer. Forcefully shutting down after 2m 20s without transfer.
01/04/23 14:57  
DEBUG  
Loading "urbackup/FILE_METADATA|dEc8Tyu9yevPyZwaFfIC|1226". Loaded 0 bytes at 56 Bit/s
01/04/23 14:57  
INFO  
Writing new file list...
01/04/23 14:57  
INFO  
All metadata was present
01/04/23 14:57  
DEBUG  
Syncing file system...
01/04/23 14:57  
INFO  
Transferred 1.73633 KB - Average speed: 4.84 KBit/s
01/04/23 14:57  
INFO  
(Before compression: 1.50781 KB ratio: 0.868391)
01/04/23 14:57  
INFO  
Time taken for backing up client xxxxxxPc: 2m 21s
01/04/23 14:57  
INFO  
Backup succeeded

May I please ask for guidance here?

As mentioned, there are no backup files… yet, it seems from the log, that there must be files somewhere.

Feel free to move my topic according to your best practices, even delete, I will not mind doing it over, in a better way. I know you guys are very busy, and your time is precious.

Sterkte menere! Have a great day. Thank you in advance for sharing your brilliance.