Restic slice bounds out of range?

So posting back again did it on another clean server debian 9 the backup location on the NAS and restic on debian 9

Date and Time: Wed Jun 17 2020 10:33:19 PM
System: Debian GNU/Linux 9
Hostname: prometheus4
Repository Location: /media/backupnas
Restic Version: 0.9.6
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
[Taking a Snapshot...]
open repository
lock repository
load index files
using parent snapshot d31c0c73
start scan on [/media/servers/ad/shares]
start backup on [/media/servers/ad/shares]

scan finished in 5556.733s: 1508435 files, 766.208 GiB
panic: runtime error: slice bounds out of range [:4294967291] with capacity 524288

goroutine 98 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc000165300, 0xc01a66a000, 0x0, 0x800000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /restic/vendor/github.com/restic/chunker/chunker.go:292 +0xc89
github.com/restic/restic/internal/archiver.(*FileSaver).saveFile(0xc0000ca1e0, 0xf20fe0, 0xc000099a80, 0xc000165300, 0xc025676b90, 0x4a, 0xf2b6a0, 0xc00021b8d8, 0xf26e40, 0xc00ab95ba0, ...)
        /restic/internal/archiver/file_saver.go:176 +0x39e
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc0000ca1e0, 0xf20fe0, 0xc000099a80, 0xc002f5c3c0)
        /restic/internal/archiver/file_saver.go:244 +0x2e5
github.com/restic/restic/internal/archiver.NewFileSaver.func2(0x0, 0x0)
        /restic/internal/archiver/file_saver.go:92 +0x7a
gopkg.in/tomb%2ev2.(*Tomb).run(0xc0000ca190, 0xc0001fdad0)
        /restic/vendor/gopkg.in/tomb.v2/tomb.go:163 +0x2b
created by gopkg.in/tomb%2ev2.(*Tomb).Go
        /restic/vendor/gopkg.in/tomb.v2/tomb.go:159 +0xc7

WARNING!
[backup] failed; exit code 2
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
End: Thu Jun 18 2020 12:37:57 AM
Duration: 2 hours, 4 minutes and 38 seconds

The error is not surprising at all. Running the standard restic binary over and over again won’t help, it will just crash each time for the same reason.

Unless you build and use a restic version with the changes I asked for in Restic slice bounds out of range? , we won’t get any closer to identifying which file causes the crash. With that information we could try to find out what makes this files so special that it causes the chunker crash.

1 Like

@killmasta93 Do you think you can get that patch wrapped up in a binary of restic that you can run? If you need help, just let us know. If you want/trust us we can build a binary for you with the patches, as long as you are fine with running something that someone else compiled for you.

Hi there sure thing i would gladly take the help, if you can help me compile i can re run and see if the error still occurs.
well not sure if this helps but i reran running restic manually

restic -r /mnt/pve/baks/baksfileserver/ backup -vv /media/servers/ad/shares/


082 KiB added)ad/shares/Recursos Humanos/rxxx/NOMINA/bak outlook/nomin
modified  /media/servers/ad/shares/Recursos Humanos/rxxx/NOMINA/bak outlo                                                                                                                                                             ok/nomina@xxxx(1).metadata, saved in 0.171s (0 B added)look/nomin
modified  /media/servers/ad/shares/Recursos Humanos/rxx/NOMINA/bak outlo                                                                                                                                                             ok/nomina@xxxmetadata, saved in 0.175s (0 B added) outlook/nomin
modified  /media/servers/ad/shares/Recursos Humanos/rxxx/NOMINA/bak outlo                                                                                                                                                             ok/nomina@xxx (1).pst, saved in 32.020s (1.713 MiB added)ok/nomin
panic: runtime error: slice bounds out of range [:4294967291] with capacity 5242                                                                                                                                                             88edia/servers/ad/shares/Recursos Humanos/xxx/NOMINA/bak outlook/nomin
/media/servers/ad/shares/Recursos Humanos/rxxx/NOMINA/nomina@xxx
goroutine 113 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc008220000, 0xc035384000, 0x0, 0x800                                                                                                                                                             000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /root/restic/chunker/chunker.go:303 +0xdc0
github.com/restic/restic/internal/archiver.(*FileSaver).saveFile(0xc00021cde0, 0                                                                                                                                                             xed4640, 0xc008155c00, 0xc008220000, 0xc000339d40, 0x58, 0xeddb20, 0xc00cbb87a8,                                                                                                                                                              0xed9860, 0xc002900f70, ...)
        /root/restic/internal/archiver/file_saver.go:167 +0x39d
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc00021cde0, 0xe                                                                                                                                                             d4640, 0xc008155c00, 0xc0101c5500)
        /root/restic/internal/archiver/file_saver.go:235 +0x2e5
github.com/restic/restic/internal/archiver.NewFileSaver.func2(0x1, 0x0)
        /root/restic/internal/archiver/file_saver.go:88 +0x7a
gopkg.in/tomb%2ev2.(*Tomb).run(0xc0000b6320, 0xc00021ce10)
        /root/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tom                                                                                                                                                             b.go:163 +0x38
created by gopkg.in/tomb%2ev2.(*Tomb).Go
        /root/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tom                                                                                                                                                             b.go:159 +0xba

Thank you

It should be sufficient to run the following commands again and use the resulting restic binary.

cd restic/cmd/restic
go build

The screenshot in this reply Restic slice bounds out of range? , looks like you’ve already made the necessary source code modifications. So just compile restic again and then use the new binary (maybe delete the restic binary in restic/cmd/restic before just to be sure).

Thanks for the reply, so re complied again going to run restic again to see what happens

this is the version that is going to run

root@prometheus4:~/restic/cmd/restic# restic version
restic 0.9.6-dev (compiled manually) compiled with go1.14.2 on linux/amd64

The version could be correct or maybe it’s a dev binary we’ve built earlier? restic version calls the binary from your PATH. You might want to tweak the version string in restic to mark the dev version to which a certain binary corresponds.

For that modify cmd/restic/global.go line 42:
From var version = "0.9.6-dev (compiled manually)" to var version = "0.9.6-dev-chunker-max (compiled manually)". Then compile again and check that the output of restic version prints the modified version string.

thanks for the reply, just wanted to say so far so good been 3 days working
only odd thing i found on the log was this

error: ReadFull returned negative number of bytes read: 4294967291

uploaded intermediate index 467186a6

Files:        2095 new,   450 changed, 1522754 unmodified
Dirs:            0 new,     3 changed,     0 unmodified
Data Blobs:   2737 new
Tree Blobs:      4 new
Added to the repo: 2.638 GiB

processed 1525299 files, 741.658 GiB in 1:43:42
snapshot 1c11b1da saved
There are 6 exclusion rules...
--------------------------------------------------------------------------------
[Snapshots List...]
ID        Time                 Host         Tags
--------------------------------------------------
addd110e  2020-07-12 18:26:03  prometheus4
2f7aefaf  2020-07-14 17:36:01  prometheus4
212a180e  2020-07-15 17:36:02  prometheus4
7bdb0f7a  2020-07-16 17:36:01  prometheus4
1c11b1da  2020-07-17 17:36:02  prometheus4
--------------------------------------------------
5 snapshots
--------------------------------------------------------------------------------
Next cleanup and check in 3 days, 20 hours and 6 minutes...
--------------------------------------------------------------------------------
Summarized Info                    Restore Size          Deduplicated Size
--------------------------------------------------------------------------------
Latest Snapshot                     741.658 GiB                524.637 GiB
All Snapshots                       780.875 GiB                566.766 GiB
--------------------------------------------------------------------------------
End: Fri Jul 17 2020 07:27:32 PM
Duration: 1 hour, 51 minutes and 31 seconds
================================================================================
                                  SCRIPT ENDED
================================================================================

@killmasta93 That’s exactly the error message we’ve been searching for. The modified code now returns an error instead of restic crashing. However, it looks like I forgot that the chunker error itself doesn’t contain the filename, sorry for that. To also report the filename in the error message, please make another small modification to the already patched restic source code: Replace line 176 in internal/archiver/file_saver.go which currently contains return saveFileResponse{err: err} with return saveFileResponse{err: errors.Wrapf(err, "file %v", f.Name())}. Don’t forget to build the binary again afterwards and use that instead.

Thanks for the reply, so if i understood correctly i find the line

  if err != nil {
                _ = f.Close()
                return saveFileResponse{err: err}
        }

and make it like this?

  if err != nil {
                _ = f.Close()
               return saveFileResponse{err: errors.Wrapf(err, "file %v", f.Name())}
        }

Correct. Then build it like you did before and make sure that you run the newly built restic binary when trying the backups again.

@MichaelEischer So far no error has appeared again lets wait this week and ill report back

@MichaelEischer so everything is running good no crashes so far but was checking the logs found this

scan finished in 1991.276s: 1530439 files, 791.383 GiB
error: ReadFull returned negative number of bytes read: 4294967291
error: ReadFull returned negative number of bytes read: 4294967291
error: ReadFull returned negative number of bytes read: 4294967291

@killmasta93 That looks like you’ve still used the binary without the modification to print the problematic file path.

Thanks for the reply,
well the steps i took

nano restic/internal/archiver/file_saver.go

inside of that file i made this line into this

  if err != nil {
                _ = f.Close()
               return saveFileResponse{err: errors.Wrapf(err, "file %v", f.Name())}
        }
cd restic/cmd/restic/
go build
 cp restic /usr/bin/

i re did it just to make sure the new restic is complied of today

ls -l -h /usr/bin/restic 
-rwxr-xr-x 1 root root 23M Jul 25 13:54 /usr/bin/restic

Ill post back later today

ls -l -h /usr/bin/restic 
-rwxr-xr-x 1 root root 23M Jul 25 13:54 /usr/bin/restic

So how’s it going? Any news?

Thanks for the reply, well it seems that adding the changes from what @MichaelEischer and from @fd0 seemed to fix the issue havent got any more error or issues 1 month clear

Files:         871 new, 60693 changed, 1476064 unmodified
Dirs:            0 new,     3 changed,     0 unmodified
Data Blobs:   2828 new
Tree Blobs:      4 new
Added to the repo: 1.933 GiB

processed 1537628 files, 768.266 GiB in 1:45:47
snapshot ec999624 saved
There are 6 exclusion rules...
--------------------------------------------------------------------------------
[Snapshots List...]
ID        Time                 Host         Tags
--------------------------------------------------
addd110e  2020-07-12 18:26:03  prometheus4
2f7aefaf  2020-07-14 17:36:01  prometheus4
212a180e  2020-07-15 17:36:02  prometheus4
7bdb0f7a  2020-07-16 17:36:01  prometheus4
1c11b1da  2020-07-17 17:36:02  prometheus4
b584b9ae  2020-07-18 17:36:02  prometheus4
e88f326f  2020-07-19 17:36:02  prometheus4
cbf36d4f  2020-07-20 17:36:02  prometheus4
4a4e4632  2020-07-21 17:36:02  prometheus4
edee7b24  2020-07-22 17:36:02  prometheus4
acfb7687  2020-07-23 17:36:02  prometheus4
6fe8901e  2020-07-24 17:36:02  prometheus4
1b1cb2db  2020-07-25 17:36:02  prometheus4
83c9e4e0  2020-07-26 17:36:02  prometheus4
262495a3  2020-07-27 17:36:02  prometheus4
94df706c  2020-07-28 17:36:02  prometheus4
43176e87  2020-07-29 17:36:02  prometheus4
d593e4c8  2020-07-30 17:36:01  prometheus4
a17c974a  2020-07-31 17:36:02  prometheus4
f6714a74  2020-08-01 17:36:02  prometheus4
f4f5f0c6  2020-08-02 17:36:02  prometheus4
e6a09569  2020-08-03 17:36:02  prometheus4
22e38200  2020-08-04 17:36:01  prometheus4
9f7c7cde  2020-08-05 17:36:01  prometheus4
c6dae1cb  2020-08-06 17:36:02  prometheus4
a717071f  2020-08-07 17:36:02  prometheus4
6eb57afa  2020-08-08 17:36:02  prometheus4
ef5c1438  2020-08-09 17:36:02  prometheus4
5397bc02  2020-08-10 17:36:02  prometheus4
ec999624  2020-08-11 17:36:02  prometheus4
--------------------------------------------------
30 snapshots
--------------------------------------------------------------------------------
Next cleanup and check in 2 days and 39 minutes...
--------------------------------------------------------------------------------
Summarized Info                    Restore Size          Deduplicated Size
--------------------------------------------------------------------------------
Latest Snapshot                     768.266 GiB                537.108 GiB
All Snapshots                       851.251 GiB                622.902 GiB
--------------------------------------------------------------------------------
End: Tue Aug 11 2020 07:51:51 PM
Duration: 2 hours, 15 minutes and 49 seconds
================================================================================
                                  SCRIPT ENDED
================================================================================

Thank you

1 Like

If the ReadFull returned negative number of bytes read error message does not appear in the log, then there’s also no reason why the normal restic version would crash.
Or the other way round: the changes from @fd0 and me only convert the crash into an error message. If that error message doesn’t show up, then the root cause of the crash is no longer triggered.

1 Like

well thats whats odd haven’t seen the ReadFull returned negative number of bytes read
appear again but really happy it got fixed i was struggling for months

As the ReadFull returned negative number of bytes read message no longer seems to be triggered, this means that whatever was causing this either is no longer triggered or has been fixed. And that this “fix” must be something external to restic.

That also means that restic v0.9.6 should work fine now. So you could try to use the normal release version of restic again and keep an eye on whether the error shows up again.

2 Likes