Restic slice bounds out of range?

Getting Help
#39

@MichaelEischer thanks for the reply, so what i did copy the restic file and put in the location

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

re ran the backup and got this

panic: runtime error: slice bounds out of range [:4294967283] with capacity 524288

goroutine 96 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc015b94000, 0xc01f380000, 0x0, 0x800000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/root/restic/chunker/chunker.go:303 +0xdc0
github.com/restic/restic/internal/archiver.(*FileSaver).saveFile(0xc015f30840, 0xed4640, 0xc00d8f8340, 0xc015b94000, 0xc0222169b0, 0x49, 0xeddb20, 0xc020d14580, 0xed9860, 0xc000871c70, ...)
	/root/restic/internal/archiver/file_saver.go:167 +0x39d
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc015f30840, 0xed4640, 0xc00d8f8340, 0xc015cd2b40)
	/root/restic/internal/archiver/file_saver.go:235 +0x2e5
github.com/restic/restic/internal/archiver.NewFileSaver.func2(0x0, 0x0)
	/root/restic/internal/archiver/file_saver.go:88 +0x7a
gopkg.in/tomb%2ev2.(*Tomb).run(0xc0001bd9f0, 0xc015f308a0)
	/root/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tomb.go:163 +0x38
created by gopkg.in/tomb%2ev2.(*Tomb).Go
	/root/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tomb.go:159 +0xba

WARNING!
[backup] failed; exit code 2
1 Like
#40

Could you modify

https://github.com/restic/restic/blob/7e72d638dfc4a159a8a454f16b1819d18c6c153b/chunker/chunker.go#L269

and replace line 269

if n < 0 {

with

if n > cap(buf) {

and test again?

I think that the negative length was a red herring: 0xfffffff3 would be uint32(-13). However, the read length and the slice offset are stored in a 64-bit integer on amd64. Thus it looks like the read syscall reported a read length of 0xfffffff3 (probably after messing up a -13).

Low-level details of what happens to the read length

I’ve followed the internals of io.ReadFull in order to find an explanation for the chunker crash: The file from which the chunker reads, was opened via arch.FS.OpenFile, so we’ve got a normal go file object. The loop in ReadFull -> ReadAtLeast can only leave with a negative n if the call to Read did so too. To return a negative n the loop in ReadAtLeast must also terminate early, which is only possible if Read returns an error. The actual read happens in go/internal/poll/fd_unix.go. That FD.Read can either return a non-zero length or an error. The returned length is exactly the length returned by the read syscall. To get the negative length and the early termination would require two calls of the read syscall which must return a negative length first, followed by an error on the second invocation -> that is the only way to get n < 0 is the have err != nil.

There’s another hurdle to take: The only way to prevent the chunker code from returning with an error, while at the same time having ReadFull return an error is that ReadFull returns ErrUnexpectedEOF. The complication there is that the only way to get that error, is to fulfill n > 0 && err == EOF in ReadAtLeast (I’ve grepped through the go standard library). Remember that earlier on we’ve established that n < 0 requires err != nil. Even if err == EOF, then it could not be replaced with ErrUnexpectedEOF as that only happens for n > 0 which conflicts with n < 0. So in summary it is probably impossible to get a negative length.

An alternative would be that the read syscall already returns uint32(-13) = 0xfffffff3. In that case the length would simply be backpropagated to the chunker. On 64-bit platforms Go actually uses 64-bit indices for slices. 0xfffffff3 would be -13 when interpreted as a 32-bit number, but int and uint are 64-bit for amd64 so that doesn’t happen. In case n were negative (e.g. -13), it’d have a value of 0xfffffffffffffff3 or 18446744073709551603. The latter was obviously not printed when the chunker crashed.

So to sum up: There’s only one thing that could have happened and that is that the read syscall reported a read length of 0xfffffff3 (probably after messing up a -13).

2 Likes
#41

Thanks for the reply, so i was heading a lot of thought and found something very odd i dont know why restic was backing up also in another folder it was very odd so what i did is create another repo so far everything seems good, might of been that issue

8a621c57  2020-01-19 21:05:03  prometheus2              /media/servers/ad/shares
692a5191  2020-01-20 21:05:05  prometheus2              /media/servers/ad/shares
3b9026be  2020-01-21 21:05:04  prometheus2              /media/servers/ad/shares
a6fb2827  2020-01-22 21:05:06  prometheus2              /media/servers/ad/shares
daf3c13d  2020-01-23 21:05:04  prometheus2              /media/servers/ad/shares
d2c797d9  2020-04-08 19:18:43  prometheus7              /media/servers/ad/shares
b54e6f31  2020-04-13 22:22:16  prometheus7              /media/servers/ad/shares
8dc90ffe  2020-04-16 20:24:31  prometheus7              /media/servers/ad/shares
5d29de0f  2020-04-23 19:31:18  prometheus7              /media/servers/ad/shares
527f2223  2020-04-29 21:51:05  prometheus7              /media/servers/ad/shares
--------------------------------------------------------------------------------



6b973856  2020-04-09 16:10:01  prometheus7              /media/servers/ad/shares
205f334a  2020-04-10 16:10:12  prometheus7              /media/servers/ad/shares
4366014d  2020-04-11 16:10:01  prometheus7              /media/servers/ad/shares
eaa4c821  2020-04-12 16:10:01  prometheus7              /media/servers/ad/shares
6077c21f  2020-04-17 16:10:01  prometheus7              /media/servers/ad/shares
1b6811a8  2020-04-18 16:10:02  prometheus7              /media/servers/ad/shares
a9a55ba1  2020-04-19 16:10:02  prometheus7              /media/servers/ad/shares
e7f040d6  2020-04-22 17:10:02  prometheus7              /media/servers/ad/shares
14fbb2e4  2020-04-25 17:10:01  prometheus7              /media/servers/ad/shares
b03d0530  2020-04-26 17:10:14  prometheus7              /media/servers/ad/shares
313cd051  2020-04-27 18:06:47  prometheus7              /media/servers/ad/shares
ea0eff35  2020-05-01 17:10:01  prometheus7              /media/servers/ad/shares
#42

hmm… very odd again

panic: runtime error: slice bounds out of range [:4294967283] with capacity 524288

goroutine 94 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc0169c8000, 0xc0150bc000, 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(0xc0000ca230, 0xf20fe0, 0xc0108c8800, 0xc0169c8000, 0xc01e0d5310, 0x4a, 0xf2b6a0, 0xc00012d188, 0xf26e40, 0xc00e948a90, ...)
	/restic/internal/archiver/file_saver.go:176 +0x39e
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc0000ca230, 0xf20fe0, 0xc0108c8800, 0xc016750d80)
	/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(0xc0000ca1e0, 0xc0167549c0)
	/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
#43

I’m pretty confident that this issue is caused by the underlying file system, which seems to mix up 32 bit and 64 bit integers. It tries to return a negative 32 bit value, which is interpreted as a 64 bit integer, so it becomes positive. All the behavior we see is explained by my hypothesis.

@killmasta93 can you tell us which file system you’re using? Do you run restic on a NAS or similar embedded device?

#44

thanks for the reply, currently running restic on proxmox debian 9 which cifs mounts the windows smb share then also mount the NAS share and uses restic on proxmox to backup, so the issue could be the NAS?

#45

so i tried starting from zero again and the storage i put in proxmox itself to remove the NAS variable but got this error

uploaded intermediate index e3e5bf26
uploaded intermediate index e69d4f29
uploaded intermediate index dc75175a
uploaded intermediate index 9f59f302
panic: runtime error: slice bounds out of range

goroutine 59 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc0002c0000, 0xc00a81c000, 0x0, 0x800000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /restic/vendor/github.com/restic/chunker/chunker.go:292 +0xcb4
github.com/restic/restic/internal/archiver.(*FileSaver).saveFile(0xc000396320, 0xf84780, 0xc0001aa040, 0xc0002c0000, 0xc0127c6820, 0x4a, 0xf8f6c0, 0xc00000f560, 0xf8aa40, 0xc011f780d0, ...)
        /restic/internal/archiver/file_saver.go:176 +0x3cc
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc000396320, 0xf84780, 0xc0001aa040, 0xc00003cde0)
        /restic/internal/archiver/file_saver.go:244 +0x2e6
github.com/restic/restic/internal/archiver.NewFileSaver.func2(0x0, 0xc00020ffc0)
        /restic/internal/archiver/file_saver.go:92 +0x7a
gopkg.in/tomb%2ev2.(*Tomb).run(0xc000396190, 0xc00037ed50)
        /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 +0xb7

WARNING!
[backup] failed; exit code 2
#46

Just to make sure I understand your setup correctly: The backup source is on a CIFS share and the backup repository is stored on the host itself/the NAS?

Could you test my proposed modifications to the debug-chunker branch? These should be enough to tell which file is the culprit:

#47

Thanks for the reply, so what i did is change the backup source is on a CIFS share but changed the backup repo to another server to see if that was the issue so i created a new repo on proxmox host which the first 2 backup works
but then i got this

scan finished in 2338.189s: 1496471 files, 748.084 GiB
panic: runtime error: slice bounds out of range

goroutine 120 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc00a5ec000, 0xc048000000, 0x0, 0x800                                                                                        000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /restic/vendor/github.com/restic/chunker/chunker.go:292 +0xcb4
github.com/restic/restic/internal/archiver.(*FileSaver).saveFile(0xc00016e280, 0                                                                                        xf84780, 0xc003db6000, 0xc00a5ec000, 0xc02ca86410, 0x4a, 0xf8f6c0, 0xc03b6a0000,                                                                                         0xf8aa40, 0xc03b6a4000, ...)
        /restic/internal/archiver/file_saver.go:176 +0x3cc
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc00016e280, 0xf                                                                                        84780, 0xc003db6000, 0xc0003f12c0)
        /restic/internal/archiver/file_saver.go:244 +0x2e6
github.com/restic/restic/internal/archiver.NewFileSaver.func2(0xfae3b27e37e060c3                                                                                        , 0x356a32ef104c2c81)
        /restic/internal/archiver/file_saver.go:92 +0x7a
gopkg.in/tomb%2ev2.(*Tomb).run(0xc00016e230, 0xc00038b8f0)
        /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 +0xb7

WARNING!
[backup] failed; exit code 2

as for the above test would i need to patch again on the other server?
Thank you

#48

To test my modifications you need to checkout the debug-chunker branch, modifie the line I asked you to, then build the restic binary and use that binary for the next backup runs.

#49

Thanks for the reply, so this is what i did

git clone https://github.com/restic/restic
cd restic/cmd/restic
git checkout debug-chunker
go build

then edit

nano restic/chunker/chunker.go

changed the file

//if n < 0 {
                        if n > cap(buf) {
                                return Chunk{}, fmt.Errorf("ReadFull returned negative number of bytes read: %v", n)
                        }

and reran rescript and for some odd reason this time it worked i guess im going to wait tomorrow and run again

this is the output

root@prometheus2:/media# sh fileserver.sh
mount.cifs kernel mount options: ip=192.168.3.209,unc=\\192.168.3.209\discod$,ve                                                                                        rs=2.1,nouser_xattr,user=administrador,pass=********
================================================================================
                                STARTING SCRIPT
================================================================================
Date and Time: Sun May 17 2020 09:23:16 PM
System: Debian GNU/Linux 9
Hostname: prometheus2
Repository Location: /media/backupnas
Restic Version: 0.9.6-dev
--------------------------------------------------------------------------------
[Taking a Snapshot...]
open repository
lock repository
load index files
using parent snapshot 7dc9819a
start scan on [/media/servers/ad/shares]
start backup on [/media/servers/ad/shares]
scan: Readdirnames /media/servers/ad/shares/System Volume Information failed: readdirent: permission denied
scan: Readdirnames /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL
scan finished in 1911.467s: 1496565 files, 748.251 GiB
uploaded intermediate index cd339de5
error: open /media/servers/ad/shares/Ingenieria/Carlos.Rodriguez/Inventor/MPOS1.0/Imported Components/jrb006-480-carbon-/£ힿ6.6.ipt: no such file or directory
uploaded intermediate index 83475287
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA BICICLETAS/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/.DS_Store: permission
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA BICICLETAS/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/INSTRUCTIVO  PARA REAission denied
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA BICICLETAS/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/Instructivo varios te
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA BICICLETAS/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/PDF ANTIOQUIA EJE CAF
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA BICICLETAS/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/cartilla Regional ant
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA BICICLETAS/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/generar certificados
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/.DS_Store: p
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/INSTRUCTIVO ocx: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/Instructivo
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/PDF ANTIOQUI
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/cartilla Reg
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/generar cert
error: Readdirnames /media/servers/ad/shares/System Volume Information failed: readdirent: permission denied
uploaded intermediate index 24c752d7
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas
error: Readdirnames /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINA
uploaded intermediate index 3ace46a5

Files:         115 new,   135 changed, 1496289 unmodified
Dirs:            0 new,     3 changed,     0 unmodified
Data Blobs:    769 new
Tree Blobs:      4 new
Added to the repo: 787.030 MiB

processed 1496539 files, 748.183 GiB in 1:57:42
snapshot 7ee2f519 saved
There are 6 exclusion rules...
--------------------------------------------------------------------------------
[Snapshots List...]
ID        Time                 Host         Tags
--------------------------------------------------
35c5748f  2020-05-14 22:32:20  prometheus2
7dc9819a  2020-05-15 18:46:44  prometheus2
7ee2f519  2020-05-17 21:23:16  prometheus2
--------------------------------------------------
3 snapshots
--------------------------------------------------------------------------------
Next cleanup and check in 4 days, 9 hours and 41 minutes...
--------------------------------------------------------------------------------
Summarized Info                    Restore Size          Deduplicated Size
--------------------------------------------------------------------------------
Latest Snapshot                     748.183 GiB                517.261 GiB
All Snapshots                       748.636 GiB                519.056 GiB
--------------------------------------------------------------------------------
End: Sun May 17 2020 11:26:09 PM
Duration: 2 hours, 2 minutes and 53 seconds
================================================================================
                                  SCRIPT ENDED
================================================================================

=============================
  Sending Output to Zabbix
=============================

[Running discovery of rescript repos]
info from server: "processed: 1; failed: 0; total: 1; seconds spent: 0.000073"
sent: 1; skipped: 0; total: 1

Extracting from:  /root/.rescript/logs/fileserver-log-2020-05-17-21:23.log
Repository:       fileserver
Checksum:         562253777

[Capture Restic Backup]
Snapshot ID:      7ee2f519
Bytes Added:      825260769
Time Processed:   7062
Bytes Processed:  7062
#50

Wait, you need to build restic after you’ve changed the chunker.go file.

#51

Thanks for the reply, so after changing the chunker.go i would rerun ?

cd restic/cmd/restic
git checkout debug-chunker
go build
#52

No, just go build.

#53

thanks just rebuild it and reran restic lets wait to see what happens ill post back again thank you

#54

so got this error not sure if this will help out

Logfile: /root/.rescript/logs/fileserver-log-2020-05-18-17:19.log 
 ================================================================================
                                STARTING SCRIPT
================================================================================
Date and Time: Mon May 18 2020 05:19:01 PM
System: Debian GNU/Linux 9
Hostname: prometheus2
Repository Location: /media/backupnas
Restic Version: 0.9.6-dev
--------------------------------------------------------------------------------
[Taking a Snapshot...]
open repository
lock repository
load index files
using parent snapshot 7ee2f519
start scan on [/media/servers/ad/shares]
start backup on [/media/servers/ad/shares]
scan: Readdirnames /media/servers/ad/shares/System Volume Information failed: readdirent: permission denied
scan: Readdirnames /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /CAMBIOS failed: readdirent: no such file or directory
scan finished in 2369.002s: 1496975 files, 749.026 GiB
panic: runtime error: slice bounds out of range [:4294967291] with capacity 524288

goroutine 86 [running]:
github.com/restic/chunker.(*Chunker).Next(0xc0001d9300, 0xc04aa80000, 0x0, 0x800000, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/root/restic/chunker/chunker.go:303 +0xdc0
github.com/restic/restic/internal/archiver.(*FileSaver).saveFile(0xc000198a20, 0xed4640, 0xc0176a0c80, 0xc0001d9300, 0xc02c5e2050, 0x4a, 0xeddb20, 0xc03c61c938, 0xed9860, 0xc002d58340, ...)
	/root/restic/internal/archiver/file_saver.go:167 +0x39d
github.com/restic/restic/internal/archiver.(*FileSaver).worker(0xc000198a20, 0xed4640, 0xc0176a0c80, 0xc017cb4060)
	/root/restic/internal/archiver/file_saver.go:235 +0x2e5
github.com/restic/restic/internal/archiver.NewFileSaver.func2(0x0, 0x0)
	/root/restic/internal/archiver/file_saver.go:88 +0x7a
gopkg.in/tomb%2ev2.(*Tomb).run(0xc0001c0140, 0xc000198ae0)
	/root/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tomb.go:163 +0x38
created by gopkg.in/tomb%2ev2.(*Tomb).Go
	/root/go/pkg/mod/gopkg.in/tomb.v2@v2.0.0-20161208151619-d5d1b5820637/tomb.go:159 +0xba

WARNING!
[backup] failed; exit code 2
--------------------------------------------------------------------------------
End: Mon May 18 2020 06:11:07 PM
Duration: 52 minutes and 6 seconds
================================================================================
                                  BACKUP ENDED
================================================================================
#55

Are you sure that you’ve used that binary that includes the additional chunker.go change? We previously saw exactly the same crash for if n < 0 {. And as that variant of the check didn’t match previously, if n > cap(buf) should match instead and result in a different error.

#56

Thanks for the reply, well i changed the chunker.go file then re ran

cd restic/cmd/restic
go build

and then ran restic not sure if thats the correct procedure?

Thank you

#57

That procedure seems to be correct (assuming that you copied/moved the newly built binary to wherever it needs to be in order to be used by the backup script).

Could you check again whether the chunker.go file contains the modification and whether for _, b := range buf[c.bpos:c.bmax] { is at line 303? I just want to be sure that the backup run did not accidentally use an older binary.

#58

Thank you so much for the reply, this is what i got, but whats funny so far its been 4 days and the issue has not happened again the only thing odd is that the backup takes like 11 hours which i dont know why this is the log

image
image1075×486 46.1 KB

mount.cifs kernel mount options: ip=192.168.3.209,unc=\\192.168.3.209\discod$,vers=2.1,nouser_xattr,user=administrador,pass=********
================================================================================
                                STARTING SCRIPT
================================================================================
e[33mDate and Time:e[0m Fri May 22 2020 06:10:01 PM
e[33mSystem:e[0m Debian GNU/Linux 9
e[33mHostname:e[0m prometheus5
e[33mRepository Location:e[0m /media/bakfileserver
e[33mRestic Version:e[0m 0.9.6-dev
--------------------------------------------------------------------------------
e[33m[Taking a Snapshot...]e[0m
open repository
lock repository
load index files
using parent snapshot d06af92e
start scan on [/media/servers/ad/shares]
start backup on [/media/servers/ad/shares]
scan: Readdirnames /media/servers/ad/shares/System Volume Information failed: readdirent: permission denied
scan: Readdirnames /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /CAMBIOS failed: readdirent: no such file or directory
scan finished in 12843.854s: 1498617 files, 750.396 GiB
uploaded intermediate index b0ff60c8
uploaded intermediate index c211994d
error: lstat /media/servers/ad/shares/Comercio Exterior/edwin.calle/Outlook/~archive.pst.tmp: no such file or directory
uploaded intermediate index 261428bc
uploaded intermediate index b26b68be
uploaded intermediate index 08629b31
uploaded intermediate index e6552a77
uploaded intermediate index 7edd7c03
error: open /media/servers/ad/shares/Ingenieria/Carlos.Rodriguez/Inventor/MPOS1.0/Imported Components/jrb006-480-carbon-/£ힿ6.6.ipt: no such file or directory
uploaded intermediate index 4911bc82
uploaded intermediate index 1de93930
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/.DS_Store: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/INSTRUCTIVO  PARA REALIZR LAS INSCRIPCIONES POR SERVICIOS EN LINEA VERSION 2016.docx: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/Instructivo varios temas para un trabajador.pdf: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/PDF ANTIOQUIA EJE CAFETERO 20163.pdf: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/cartilla Regional antioquia.xls: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/blanca.gonzalez/HA/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquiadd/generar certificados 2016.docx: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/.DS_Store: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/INSTRUCTIVO  PARA REALIZR LAS INSCRIPCIONES POR SERVICIOS EN LINEA VERSION 2016.docx: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/Instructivo varios temas para un trabajador.pdf: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/PDF ANTIOQUIA EJE CAFETERO 2016.pdf: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/cartilla Regional antioquia.xls: permission denied
error: open /media/servers/ad/shares/Recursos Humanos/compartido/GH-MG-01  Manual de Funciones/GESTION DE CALIDAD/PROGRAMAS/PSV/Cartilla Regional Antioquia/generar certificados 2016.docx: permission denied
uploaded intermediate index 35ede91c
error: Readdirnames /media/servers/ad/shares/System Volume Information failed: readdirent: permission denied
uploaded intermediate index 8f107a2b
uploaded intermediate index bdbcf89d
uploaded intermediate index 64919f41
uploaded intermediate index 18572cf1
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /._AF·Caja Gafas GW.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /._AF·Gafas DG CARDENAL.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /._AF·Gafas DG COMANCHE.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /._AF·Gafas DG CRUCEROai.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /._AF·Gafas DG DESIERTO.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /._AF·Gafas DG MAYA.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /AF·Caja Gafas GW.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /AF·Gafas DG CARDENAL.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /AF·Gafas DG COMANCHE.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /AF·Gafas DG CRUCEROai.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /AF·Gafas DG DESIERTO.pdf: no such file or directory
error: open /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /AF·Gafas DG MAYA.pdf: no such file or directory
error: Readdirnames /media/servers/ad/shares/Ventas/ropa/GW BIKE APPAREL - VENTAS INTERNACIONALES/29-01-2019/ROPA/PROVEEDORES/JQ/ORDERS/GAFAS/ORDER 2019/PLANTILLAS/FINAL/Gafas GW /CAMBIOS failed: readdirent: no such file or directory
uploaded intermediate index 3f8b6d8e
uploaded intermediate index 3294acba
uploaded intermediate index e8d2c0df

Files:         422 new,   345 changed, 1497818 unmodified
Dirs:            0 new,     3 changed,     0 unmodified
Data Blobs:   1641 new
Tree Blobs:      4 new
Added to the repo: 1021.525 MiB

processed 1498585 files, 750.325 GiB in 11:16:04
snapshot cd496767 saved
e[33mThere are 6 exclusion rules...e[0m
--------------------------------------------------------------------------------
e[33m[Snapshots List...]e[0m
ID        Time                 Host         Tags
--------------------------------------------------
14a1377c  2020-05-10 20:07:44  prometheus5
1070cc2a  2020-05-12 18:23:24  prometheus5
c144f7cb  2020-05-13 18:10:02  prometheus5
77a81e3c  2020-05-19 18:00:44  prometheus5
69878268  2020-05-19 22:03:41  prometheus5
677f3a96  2020-05-20 18:10:02  prometheus5
d06af92e  2020-05-21 18:10:02  prometheus5
cd496767  2020-05-22 18:10:02  prometheus5
--------------------------------------------------
8 snapshots
--------------------------------------------------------------------------------
e[33m[Cleaning Repo...]e[0m
Applying Policy: keep the last 90 snapshots snapshots and all snapshots with tags [[archive]]
keep 8 snapshots:
ID        Time                 Host         Tags        Reasons        Paths
-----------------------------------------------------------------------------------------------
14a1377c  2020-05-10 20:07:44  prometheus5              last snapshot  /media/servers/ad/shares
1070cc2a  2020-05-12 18:23:24  prometheus5              last snapshot  /media/servers/ad/shares
c144f7cb  2020-05-13 18:10:02  prometheus5              last snapshot  /media/servers/ad/shares
77a81e3c  2020-05-19 18:00:44  prometheus5              last snapshot  /media/servers/ad/shares
69878268  2020-05-19 22:03:41  prometheus5              last snapshot  /media/servers/ad/shares
677f3a96  2020-05-20 18:10:02  prometheus5              last snapshot  /media/servers/ad/shares
d06af92e  2020-05-21 18:10:02  prometheus5              last snapshot  /media/servers/ad/shares
cd496767  2020-05-22 18:10:02  prometheus5              last snapshot  /media/servers/ad/shares
-----------------------------------------------------------------------------------------------
8 snapshots

counting files in repo
building new index for repo
[28:43] 100.00%  115425 / 115425 packs

repository contains 115425 packs (1477819 blobs) with 529.070 GiB
processed 1477819 blobs: 0 duplicate blobs, 0 B duplicate
load all snapshots
find data that is still in use for 8 snapshots
[1:37] 100.00%  8 / 8 snapshots

found 1477819 of 1477819 data blobs still in use, removing 0 blobs
will remove 0 invalid files
will delete 0 packs and rewrite 0 packs, this frees 0 B
counting files in repo
[28:45] 100.00%  115425 / 115425 packs

finding old index files
saved new indexes as [7ee7bfc4 a114968b 01fb7e65 4d1ecb8e 58fb4d21 23571cfe f5b5f955 b92bbb20 c3187948 2399ddb5 db826a4f 156b543f 3d216003 724c6763 3ce68359 2cfde00a 408234c4 0380883b d4b2f6cc bf587662 8e62791c 8bd9c0eb 994879c8 02798a88 9d1c4ac7 0183b1f2 8b1f370d 1e2181d2 8665b52d 50559a15 dcaa209c 725ce783 fd2410d3 87572d78 51a3e66d 1af21a5f 2859b243 9ef417e6 3647df3f]
remove 75 old index files
done
--------------------------------------------------------------------------------
e[33m[Checking for Errors in Repo...]e[0m
using temporary cache in /tmp/restic-check-cache-242871920
created new cache in /tmp/restic-check-cache-242871920
create exclusive lock for repository
load indexes
check all packs
check snapshots, trees and blobs
no errors were found
--------------------------------------------------------------------------------
e[33m[Done Cleaning; Next Cleanup and Check Will Be Done in 1 days...]e[0m
--------------------------------------------------------------------------------
Processing stats              : [####----------------](20%)
Processing stats              : [########------------](40%)
Processing stats              : [############--------](60%)
Processing stats              : [################----](80%)
Processing stats              : [####################](100%)
Summarized Info                    Restore Size          Deduplicated Size
--------------------------------------------------------------------------------
Latest Snapshot                     750.325 GiB                519.384 GiB
All Snapshots                       755.659 GiB                528.971 GiB
--------------------------------------------------------------------------------
e[33mEnd:e[0m Sat May 23 2020 06:42:38 AM
e[33mDuration:e[0m 12 hours, 32 minutes and 37 seconds
================================================================================
                                  SCRIPT ENDED
================================================================================