[Errno 32] Broken pipe on Mac

Question

[Errno 32] Broken pipe on Mac

Closed this issue 2 years ago · 5 comments

abulka commented 2 years ago

Have you checked borgbackup docs, FAQ, and open GitHub issues?

Yes

Is this a BUG / ISSUE report or a QUESTION?

Perhaps a bug

System information. For client/server mode post info for both machines.

Your borg version (borg -V).

borg 1.2.2 on Mac (iMac late 2015, Intel i7)
borg 1.2.1 on Synology nas as installed by the borgomatic package

Operating system (distribution) and version.

macOS Monterey

Hardware / network configuration, and filesystems used.

Talking to Synology NAS

Created a user borg-backup etc on NAS with .ssh/authorized_keys containing command="/usr/local/bin/borg serve --restrict-to-path /volume1/BorgBackup/" ssh-rsa AAAA………….. the rest of the line with my public key …….

How much data is handled by borg?

100 or 200 GB

Full borg commandline that lead to the problem (leave away excludes and passwords)

/usr/local/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /var/folders/9s/bmb_wzs906x5v1w6h0mt5b2r0000gn/T/tmp7w0ys_bx bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-01-31-144330 /Volumes/SSD/Users/andy/Desktop /Volumes/SSD/Users/andy/Devel /Volumes/SSD/Users/andy/Documents /Volumes/SSD/Users/andy/Downloads /Volumes/SSD/Users/andy/Music/GarageBand /Volumes/SSD/Users/andy/Music/Logic /Volumes/SSD/Users/andy/Pictures /Volumes/SSD/Users/andy/.bash_aliases /Volumes/SSD/Users/andy/.bash_history /Volumes/SSD/Users/andy/.bash_profile /Volumes/SSD/Users/andy/.bash_prompt_andy /Volumes/SSD/Users/andy/.bash_prompt_andy2 /Volumes/SSD/Users/andy/.bash_prompt_ubuntu /Volumes/SSD/Users/andy/.bash_sessions /Volumes/SSD/Users/andy/.bashrc /Volumes/SSD/Users/andy/.gitconfig /Volumes/SSD/Users/andy/.gitignore /Volumes/SSD/Users/andy/.ssh /Volumes/SSD/Users/andy/.vimrc /Volumes/SSD/Users/andy/.vscode /private/etc/hosts

Describe the problem you're observing.

[Errno 32] Broken pipe

My initial borg backup via Vorta worked fine from my Mac Monterey machine, so did the second time a week later. But no longer.

Can you reproduce the problem? If so, describe how. If not, describe troubleshooting steps you took before opening the issue.

Running a backup from Vorta

I tried the ssh tweaks in #636 - which didn't help me.
Another 'official' reason for connection closed by remote / brokenpipe in the FAQ seems to be the mac sleeping, but I tested this and it happens when my Mac is awake.
I thought it might be a permissions issue so added my mac's /usr/local/bin/borg (and even the actual target of that symbolic link) to 'full disk access' - but that didn't help either. Adding vorta doesn't help either. Added cron and terminal to to 'full disk access' too.

Sigh... Not sure what to try next. Creating new repository and backing up some of the files in the logs (which have the broken pipe error beside them) works and the backup completes ok. So maybe its a size related thing or a time out?

Include any warning/errors/backtraces from the system logs

Click me - Error Logs


2023-02-01 10:11:06,067 - vorta.borg.borg_job - WARNING - Remote: client_loop: send disconnect: Broken pipe
2023-02-01 10:11:06,068 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/.DS_Store: read: [Errno 32] Broken pipe
2023-02-01 10:11:06,901 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/Lightroom/Lightroom Catalog - Main.lrcat: read: [Errno 32] Broken pipe
2023-02-01 10:11:06,965 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/Lightroom/Lightroom Catalog - Main Helper.lrdata/helper.db: read: [Errno 32] Broken pipe
2023-02-01 10:11:07,020 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/Lightroom/Lightroom Catalog - Main Previews.lrdata/previews.db: read: [Errno 32] Broken pipe
2023-02-01 10:11:07,112 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/Lightroom/Lightroom Catalog - Main Previews.lrdata/root-pixels.db: read: [Errno 32] Broken pipe
2023-02-01 10:11:07,154 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/Lightroom/Lightroom Catalog - Main Previews.lrdata/7/7051/7051D615-E5E5-4F69-B123-DEAC0E87F9F4-a4d6518b4380350ad19b40a269bc19e4.lrprev: read: [Errno 32] Broken pipe
2023-02-01 10:11:07,284 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Pictures/Lightroom/Lightroom Catalog - Main Previews.lrdata/7/7D6F/7D6F0827-BE18-4FDE-9296-F22B50CA0B9C-a4d6518b4380350ad19b40a269bc19e4.lrprev: read: [Errno 32] Broken pipe

perhaps its all of Pictures?

no, now its also

2023-02-01 11:08:20,384 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-01 11:08:20,386 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-05 10:17:56.061910
2023-02-01 11:19:17,628 - vorta.borg.borg_job - WARNING - Remote: client_loop: send disconnect: Broken pipe
2023-02-01 11:19:17,629 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_history: read: [Errno 32] Broken pipe
2023-02-01 11:19:17,636 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/287769E7-569F-44D4-A4B7-CDB8C3242B74.session: read: [Errno 32] Broken pipe
2023-02-01 11:19:17,638 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/287769E7-569F-44D4-A4B7-CDB8C3242B74.history: read: [Errno 32] Broken pipe


I tried adding /usr/local/bin/borg
ls -l /usr/local/bin/borg
lrwxr-xr-x  1 andy  admin  40 28 Dec 14:42 /usr/local/bin/borg -> ../Cellar/borgbackup-fuse/1.2.2/bin/borg
to full disk access

still crashes

2023-02-01 17:17:03,189 - vorta.borg.borg_job - WARNING - Remote: client_loop: send disconnect: Broken pipe
2023-02-01 17:17:03,190 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Downloads/Amphetamine Enhancer.dmg: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,985 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_history: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,994 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/287769E7-569F-44D4-A4B7-CDB8C3242B74.session: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,996 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/287769E7-569F-44D4-A4B7-CDB8C3242B74.history: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,998 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/345A7972-67A1-4490-AD36-E10CF866A8A0.session: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,000 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/345A7972-67A1-4490-AD36-E10CF866A8A0.history: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,017 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.ssh/known_hosts.old: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,018 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.ssh/known_hosts: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,020 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.ssh/config: read: [Errno 32] Broken pipe

here is a stacktrace

2023-02-01 16:40:54,886 - root - DEBUG - Command ipconfig getpacket bridge0 failed
2023-02-01 16:40:54,890 - vorta.borg.jobs_manager - DEBUG - Add job for site 4
2023-02-01 16:40:54,891 - vorta.borg.jobs_manager - DEBUG - Start job on site: 4
2023-02-01 16:40:54,900 - vorta.borg.borg_job - INFO - Running command /usr/local/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /var/folders/9s/bmb_wzs906x5v1w6h0mt5b2r0000gn/T/tmp8gs6ak6y bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-02-01-164054 /Volumes/SSD/Users/andy/Desktop /Volumes/SSD/Users/andy/Devel /Volumes/SSD/Users/andy/Documents /Volumes/SSD/Users/andy/Downloads /Volumes/SSD/Users/andy/Music/GarageBand /Volumes/SSD/Users/andy/Music/Logic /Volumes/SSD/Users/andy/Pictures /Volumes/SSD/Users/andy/.bash_aliases /Volumes/SSD/Users/andy/.bash_history /Volumes/SSD/Users/andy/.bash_profile /Volumes/SSD/Users/andy/.bash_prompt_andy /Volumes/SSD/Users/andy/.bash_prompt_andy2 /Volumes/SSD/Users/andy/.bash_prompt_ubuntu /Volumes/SSD/Users/andy/.bash_sessions /Volumes/SSD/Users/andy/.bashrc /Volumes/SSD/Users/andy/.gitconfig /Volumes/SSD/Users/andy/.gitignore /Volumes/SSD/Users/andy/.ssh /Volumes/SSD/Users/andy/.vimrc /Volumes/SSD/Users/andy/.vscode /private/etc/hosts
2023-02-01 16:41:01,192 - vorta.borg.borg_job - INFO - Creating archive at "bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-02-01-164054"
2023-02-01 16:42:43,664 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-02-01 16:42:43,666 - vorta.scheduler - DEBUG - Scheduler for profile 1 is disabled.
2023-02-01 16:42:43,669 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-01 16:42:43,670 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-05 16:40:54.891520
2023-02-01 16:42:43,672 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2023-02-01 17:12:32,108 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-02-01 17:12:32,110 - vorta.scheduler - DEBUG - Scheduler for profile 1 is disabled.
2023-02-01 17:12:32,112 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-01 17:12:32,113 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-05 16:40:54.891520
2023-02-01 17:12:32,115 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2023-02-01 17:17:03,189 - vorta.borg.borg_job - WARNING - Remote: client_loop: send disconnect: Broken pipe
2023-02-01 17:17:03,190 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/Downloads/Amphetamine Enhancer.dmg: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,985 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_history: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,994 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/287769E7-569F-44D4-A4B7-CDB8C3242B74.session: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,996 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/287769E7-569F-44D4-A4B7-CDB8C3242B74.history: read: [Errno 32] Broken pipe
2023-02-01 17:17:04,998 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/345A7972-67A1-4490-AD36-E10CF866A8A0.session: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,000 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.bash_sessions/345A7972-67A1-4490-AD36-E10CF866A8A0.history: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,017 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.ssh/known_hosts.old: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,018 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.ssh/known_hosts: read: [Errno 32] Broken pipe
2023-02-01 17:17:05,020 - vorta.borg.borg_job - WARNING - /Volumes/SSD/Users/andy/.ssh/config: read: [Errno 32] Broken pipe
2023-02-01 17:17:10,702 - vorta.borg.borg_job - ERROR - Local Exception
2023-02-01 17:17:10,703 - vorta.borg.borg_job - ERROR - Traceback (most recent call last):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 183, in wrapper
    return method(self, args, repository=repository, **kwargs)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 675, in do_create
    create_inner(archive, cache, fso)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 608, in create_inner
    self._rec_walk(path=path, parent_fd=parent_fd, name=name,
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 820, in _rec_walk
    self._rec_walk(
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 820, in _rec_walk
    self._rec_walk(
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 820, in _rec_walk
    self._rec_walk(
  [Previous line repeated 5 more times]
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 786, in _rec_walk
    status = self._process_any(path=path, parent_fd=parent_fd, name=name, st=st, fso=fso, cache=cache,
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 688, in _process_any
    return fso.process_file(path=path, parent_fd=parent_fd, name=name, st=st, cache=cache)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 1392, in process_file
    with self.create_helper(path, st, None) as (item, status, hardlinked, hardlink_master):  # no status yet
  File "/usr/local/Cellar/python@3.10/3.10.9/Frameworks/Python.framework/Versions/3.10/lib/python3.10/contextlib.py", line 142, in __exit__
    next(self.gen)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 1317, in create_helper
    self.add_item(item, stats=self.stats)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 600, in add_item
    self.items_buffer.add(item)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 357, in add
    self.flush()
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 385, in flush
    self.chunks.append(self.write_chunk(chunk))
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 402, in write_chunk
    self.cache.repository.async_response(wait=False)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 984, in async_response
    for resp in self.call_many('async_responses', calls=[], wait=True, async_wait=wait):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 781, in call_many
    send_buffer()  # Try to send data, as some cases (async_response) will never try to send data otherwise.
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 721, in send_buffer
    written = self.ratelimit.write(self.stdin_fd, self.to_send.peek_front())
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 417, in write
    written = os.write(fd, to_send)
BrokenPipeError: [Errno 32] Broken pipe

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 5159, in main
    exit_code = archiver.run(args)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 5090, in run
    return set_ec(func(args))
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 168, in wrapper
    with repository:
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 636, in __exit__
    self.rollback()
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 476, in do_rpc
    return self.call(f.__name__, named, **extra)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 711, in call
    for resp in self.call_many(cmd, [args], **kw):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 781, in call_many
    send_buffer()  # Try to send data, as some cases (async_response) will never try to send data otherwise.
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 721, in send_buffer
    written = self.ratelimit.write(self.stdin_fd, self.to_send.peek_front())
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 417, in write
    written = os.write(fd, to_send)
BrokenPipeError: [Errno 32] Broken pipe

Platform: Darwin Andys-iMac.local 21.6.0 Darwin Kernel Version 21.6.0: Sun Nov  6 23:31:16 PST 2022; root:xnu-8020.240.14~1/RELEASE_X86_64 x86_64
Borg: 1.2.2  Python: CPython 3.10.9 msgpack: 1.0.4 fuse: llfuse 1.4.2 [pyfuse3,llfuse]
PID: 5379  CWD: /
sys.argv: ['/usr/local/bin/borg', 'create', '--list', '--progress', '--info', '--log-json', '--json', '--filter=AM', '-C', 'lz4', '--exclude-from', '/var/folders/9s/bmb_wzs906x5v1w6h0mt5b2r0000gn/T/tmp8gs6ak6y', 'bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-02-01-164054', '/Volumes/SSD/Users/andy/Desktop', '/Volumes/SSD/Users/andy/Devel', '/Volumes/SSD/Users/andy/Documents', '/Volumes/SSD/Users/andy/Downloads', '/Volumes/SSD/Users/andy/Music/GarageBand', '/Volumes/SSD/Users/andy/Music/Logic', '/Volumes/SSD/Users/andy/Pictures', '/Volumes/SSD/Users/andy/.bash_aliases', '/Volumes/SSD/Users/andy/.bash_history', '/Volumes/SSD/Users/andy/.bash_profile', '/Volumes/SSD/Users/andy/.bash_prompt_andy', '/Volumes/SSD/Users/andy/.bash_prompt_andy2', '/Volumes/SSD/Users/andy/.bash_prompt_ubuntu', '/Volumes/SSD/Users/andy/.bash_sessions', '/Volumes/SSD/Users/andy/.bashrc', '/Volumes/SSD/Users/andy/.gitconfig', '/Volumes/SSD/Users/andy/.gitignore', '/Volumes/SSD/Users/andy/.ssh', '/Volumes/SSD/Users/andy/.vimrc', '/Volumes/SSD/Users/andy/.vscode', '/private/etc/hosts']
SSH_ORIGINAL_COMMAND: None

2023-02-01 17:17:10,859 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-01 17:17:10,860 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-05 09:27:30.422518
2023-02-01 17:17:10,860 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 4
2023-02-01 17:17:10,861 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 4
2023-02-01 17:27:32,104 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-02-01 17:27:32,106 - vorta.scheduler - DEBUG - Scheduler for profile 1 is disabled.
2023-02-01 17:27:32,108 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-01 17:27:32,109 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-05 09:27:30.422518
2023-02-01 17:27:32,110 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2023-02-01 17:42:32,100 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-02-01 17:42:32,102 - vorta.scheduler - DEBUG - Scheduler for profile 1 is disabled.
2023-02-01 17:42:32,104 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-01 17:42:32,105 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-05 09:27:30.422518
2023-02-01 17:42:32,108 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.

Answer 1 · 2023-02-02T00:34:26.000Z

Found a reddit post which suggested adding AddressFamily inet to the .ssh/config for my backup server. Amazingly it worked - both invoking borg on the command line and via Vorta.

Edit ~/.ssh/config

Host borg-backup
    Hostname <hostname>
    User <user>
    AddressFamily inet

Summary of solutions tried

ssh timeout tweaks on client and server - X
sleep issue - X
permissions of borg and cron etc - X
adding AddressFamily inet to ~/.ssh/config - WORKED for a while but see below

Answer 2 · 2023-02-02T00:37:45.000Z

OK, that translates to "IPv4 only". So maybe your v6 is broken.

Answer 3 · 2023-02-02T01:35:00.000Z

Dang - it just happened again.

Click me - Error Log

2023-02-02 11:17:04,103 - vorta.borg.borg_job - INFO - Running command /usr/local/bin/borg create --list --progress --info --log-json --json --filter=AM -C lz4 --exclude-from /var/folders/9s/bmb_wzs906x5v1w6h0mt5b2r0000gn/T/tmp_x4yecmv bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-02-02-111704 /Volumes/SSD/Users/andy/Desktop /Volumes/SSD/Users/andy/Devel /Volumes/SSD/Users/andy/Documents /Volumes/SSD/Users/andy/Downloads /Volumes/SSD/Users/andy/Music/GarageBand /Volumes/SSD/Users/andy/Music/Logic /Volumes/SSD/Users/andy/Pictures /Volumes/SSD/Users/andy/.bash_aliases /Volumes/SSD/Users/andy/.bash_history /Volumes/SSD/Users/andy/.bash_profile /Volumes/SSD/Users/andy/.bash_prompt_andy /Volumes/SSD/Users/andy/.bash_prompt_andy2 /Volumes/SSD/Users/andy/.bash_prompt_ubuntu /Volumes/SSD/Users/andy/.bash_sessions /Volumes/SSD/Users/andy/.bashrc /Volumes/SSD/Users/andy/.gitconfig /Volumes/SSD/Users/andy/.gitignore /Volumes/SSD/Users/andy/.ssh /Volumes/SSD/Users/andy/.vimrc /Volumes/SSD/Users/andy/.vscode /private/etc/hosts
2023-02-02 11:17:06,067 - vorta.borg.borg_job - INFO - Creating archive at "bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-02-02-111704"
2023-02-02 11:26:13,211 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-02-02 11:26:13,214 - vorta.scheduler - DEBUG - Scheduler for profile 1 is disabled.
2023-02-02 11:26:13,216 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-02 11:26:13,216 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-06 11:17:04.097999
2023-02-02 11:26:13,218 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2023-02-02 11:26:13,220 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2023-02-02 11:26:13,222 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2023-02-02 11:26:13,224 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2023-02-02 11:26:13,225 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2023-02-02 11:26:13,227 - vorta.scheduler - DEBUG - Scheduler for profile 8 is disabled.
2023-02-02 11:41:13,205 - vorta.scheduler - DEBUG - Refreshing all scheduler timers
2023-02-02 11:41:13,207 - vorta.scheduler - DEBUG - Scheduler for profile 1 is disabled.
2023-02-02 11:41:13,210 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-02 11:41:13,211 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-06 11:17:04.097999
2023-02-02 11:41:13,213 - vorta.scheduler - DEBUG - Scheduler for profile 3 is disabled.
2023-02-02 11:41:13,215 - vorta.scheduler - DEBUG - Scheduler for profile 4 is disabled.
2023-02-02 11:41:13,217 - vorta.scheduler - DEBUG - Scheduler for profile 5 is disabled.
2023-02-02 11:41:13,219 - vorta.scheduler - DEBUG - Scheduler for profile 6 is disabled.
2023-02-02 11:41:13,221 - vorta.scheduler - DEBUG - Scheduler for profile 7 is disabled.
2023-02-02 11:41:13,223 - vorta.scheduler - DEBUG - Scheduler for profile 8 is disabled.
2023-02-02 12:17:47,880 - vorta.borg.borg_job - WARNING - Remote: client_loop: send disconnect: Broken pipe
2023-02-02 12:17:48,261 - vorta.borg.borg_job - ERROR - Local Exception
2023-02-02 12:17:48,261 - vorta.borg.borg_job - ERROR - Traceback (most recent call last):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 183, in wrapper
    return method(self, args, repository=repository, **kwargs)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 675, in do_create
    create_inner(archive, cache, fso)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 608, in create_inner
    self._rec_walk(path=path, parent_fd=parent_fd, name=name,
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 820, in _rec_walk
    self._rec_walk(
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 820, in _rec_walk
    self._rec_walk(
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 820, in _rec_walk
    self._rec_walk(
  [Previous line repeated 5 more times]
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 786, in _rec_walk
    status = self._process_any(path=path, parent_fd=parent_fd, name=name, st=st, fso=fso, cache=cache,
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 688, in _process_any
    return fso.process_file(path=path, parent_fd=parent_fd, name=name, st=st, cache=cache)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 1434, in process_file
    self.process_file_chunks(item, cache, self.stats, self.show_progress, backup_io_iter(self.chunker.chunkify(None, fd)))
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 1261, in process_file_chunks
    item.chunks.append(chunk_processor(chunk))
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archive.py", line 1249, in chunk_processor
    chunk_entry = cache.add_chunk(chunk_id, data, stats, wait=False)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/cache.py", line 951, in add_chunk
    self.repository.put(id, data, wait=wait)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 476, in do_rpc
    return self.call(f.__name__, named, **extra)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 711, in call
    for resp in self.call_many(cmd, [args], **kw):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 828, in call_many
    raise ConnectionClosed()
borg.remote.ConnectionClosed: Connection closed by remote host

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 5159, in main
    exit_code = archiver.run(args)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 5090, in run
    return set_ec(func(args))
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/archiver.py", line 168, in wrapper
    with repository:
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 636, in __exit__
    self.rollback()
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 476, in do_rpc
    return self.call(f.__name__, named, **extra)
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 711, in call
    for resp in self.call_many(cmd, [args], **kw):
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 781, in call_many
    send_buffer()  # Try to send data, as some cases (async_response) will never try to send data otherwise.
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 721, in send_buffer
    written = self.ratelimit.write(self.stdin_fd, self.to_send.peek_front())
  File "/usr/local/Cellar/borgbackup-fuse/1.2.2/libexec/lib/python3.10/site-packages/borg/remote.py", line 417, in write
    written = os.write(fd, to_send)
BrokenPipeError: [Errno 32] Broken pipe

Platform: Darwin Andys-iMac.local 21.6.0 Darwin Kernel Version 21.6.0: Mon Dec 19 20:44:01 PST 2022; root:xnu-8020.240.18~2/RELEASE_X86_64 x86_64
Borg: 1.2.2  Python: CPython 3.10.9 msgpack: 1.0.4 fuse: llfuse 1.4.2 [pyfuse3,llfuse]
PID: 8861  CWD: /
sys.argv: ['/usr/local/bin/borg', 'create', '--list', '--progress', '--info', '--log-json', '--json', '--filter=AM', '-C', 'lz4', '--exclude-from', '/var/folders/9s/bmb_wzs906x5v1w6h0mt5b2r0000gn/T/tmp_x4yecmv', 'bb:/volume1/BorgBackup/iMac-main::Andys-iMac.local-2023-02-02-111704', '/Volumes/SSD/Users/andy/Desktop', '/Volumes/SSD/Users/andy/Devel', '/Volumes/SSD/Users/andy/Documents', '/Volumes/SSD/Users/andy/Downloads', '/Volumes/SSD/Users/andy/Music/GarageBand', '/Volumes/SSD/Users/andy/Music/Logic', '/Volumes/SSD/Users/andy/Pictures', '/Volumes/SSD/Users/andy/.bash_aliases', '/Volumes/SSD/Users/andy/.bash_history', '/Volumes/SSD/Users/andy/.bash_profile', '/Volumes/SSD/Users/andy/.bash_prompt_andy', '/Volumes/SSD/Users/andy/.bash_prompt_andy2', '/Volumes/SSD/Users/andy/.bash_prompt_ubuntu', '/Volumes/SSD/Users/andy/.bash_sessions', '/Volumes/SSD/Users/andy/.bashrc', '/Volumes/SSD/Users/andy/.gitconfig', '/Volumes/SSD/Users/andy/.gitignore', '/Volumes/SSD/Users/andy/.ssh', '/Volumes/SSD/Users/andy/.vimrc', '/Volumes/SSD/Users/andy/.vscode', '/private/etc/hosts']
SSH_ORIGINAL_COMMAND: None

2023-02-02 12:17:48,432 - vorta.scheduler - INFO - Setting timer for profile 2
2023-02-02 12:17:48,433 - vorta.scheduler - DEBUG - Scheduling next run for 2023-02-06 11:15:27.527527
2023-02-02 12:17:48,434 - vorta.borg.jobs_manager - DEBUG - Finish job for site: 4
2023-02-02 12:17:48,434 - vorta.borg.jobs_manager - DEBUG - No more jobs for site: 4

Answer 4 · 2023-02-02T09:42:01.000Z

Ok, am having success with more aggressive sleep management using a mac program called Amphetamine. I even reverted the ssh timeout tweaks and the ip4 ssh tweak and the backup ran ok several times in a row - as long as Amphetamine disabled sleep. Perhaps there are levels of sleep that Amphetamine awakens that I was not aware of.

Summary of solutions tried (updated)

ssh timeout tweaks on client and server - X (did't help)
sleep issue - YES use Amphetamine app to temporarily disable all levels of Mac sleep
permissions of borg and cron etc - X
adding AddressFamily inet to ~/.ssh/config - X

Its a shame I have to manually run Amphetamine to run a successful Borg backup, which precludes running Borg on a schedule. Sure, Amphetamine can detect particular apps running and can automatically disable sleep whilst they are running, but unfortunately doesn't seem to 'see' the Borg process.

Answer 5 · 2023-02-02T16:15:51.000Z

@abulka can you please edit the top post and add specifics about your mac hardware (kind of machine, intel or apple silicon).