[unison-users] Fatal error: End_of_file exception raised in loading archive (this indicates a bug!)

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

Hello; I am having this very rare bug; Google does not help much.

Bug happens on only oneguest out of 15.


l3# unison-2.40 -auto -batch -times -logfile /var/log/unison.log -prefer
/srv/doublehp -addversionno -forcepartial "BelowPath bin -> /srv/doublehp"
-forcepartial "BelowPath etc -> /srv/doublehp" -forcepartial "BelowPath
local -> /srv/doublehp" -forcepartial "BelowPath share -> /srv/doublehp"
-forcepartial "BelowPath src -> /srv/doublehp" -ignore "BelowPath
local/opi-01-serveur" -ignore "BelowPath local/*/private" /srv/doublehp
ssh://***@s2//srv/doublehp
Contacting server...
Connected [//l3//srv/doublehp -> //s2//srv/doublehp]
Looking for changes
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)

[Alan Schmitt [e-mail] [unison-users]]

Post by Benoît-Pierre DEMAINE ***@demaine.info [unison-users]
Hello; I am having this very rare bug; Google does not help much.
Bug happens on only oneguest out of 15.
l3# unison-2.40 -auto -batch -times -logfile /var/log/unison.log -prefer
/srv/doublehp -addversionno -forcepartial "BelowPath bin -> /srv/doublehp"
-forcepartial "BelowPath etc -> /srv/doublehp" -forcepartial "BelowPath
local -> /srv/doublehp" -forcepartial "BelowPath share -> /srv/doublehp"
-forcepartial "BelowPath src -> /srv/doublehp" -ignore "BelowPath
local/opi-01-serveur" -ignore "BelowPath local/*/private" /srv/doublehp
Contacting server...
Connected [//l3//srv/doublehp -> //s2//srv/doublehp]
Looking for changes
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)

Other may confirm this, but I'm afraid this is because the archive is
corrupted
 You could always delete it and start from scratch (in the
sense of recording what is synchronised), but you need to be careful if
both roots are not already synchronised, as Unison will consider every
file present on only one host as newly created.

Best,

Alan

['Benjamin C. Pierce' [e-mail] [unison-users]]

Is this behavior repeatable?

- B

Post by Alan Schmitt ***@polytechnique.org [unison-users]

Post by Benoît-Pierre DEMAINE ***@demaine.info [unison-users]
Hello; I am having this very rare bug; Google does not help much.
Bug happens on only oneguest out of 15.
l3# unison-2.40 -auto -batch -times -logfile /var/log/unison.log -prefer
/srv/doublehp -addversionno -forcepartial "BelowPath bin -> /srv/doublehp"
-forcepartial "BelowPath etc -> /srv/doublehp" -forcepartial "BelowPath
local -> /srv/doublehp" -forcepartial "BelowPath share -> /srv/doublehp"
-forcepartial "BelowPath src -> /srv/doublehp" -ignore "BelowPath
local/opi-01-serveur" -ignore "BelowPath local/*/private" /srv/doublehp
Contacting server...
Connected [//l3//srv/doublehp -> //s2//srv/doublehp]
Looking for changes
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)

Other may confirm this, but I'm afraid this is because the archive is
corrupted
 You could always delete it and start from scratch (in the
sense of recording what is synchronised), but you need to be careful if
both roots are not already synchronised, as Unison will consider every
file present on only one host as newly created.
Best,
Alan
--
OpenPGP Key ID : 040D0A3B4ED2E5C7
Monthly Athmospheric CO₂, Mauna Loa Obs. 2018-02: 408.35, 2017-02: 406.42

['Benjamin C. Pierce' [e-mail] [unison-users]]

Post by 'Benjamin C. Pierce' ***@cis.upenn.edu [unison-users]
Is this behavior repeatable?


 meaning: If you delete the archives and resynchronize (carefully, as Alan notes), does it happen again?

Post by 'Benjamin C. Pierce' ***@cis.upenn.edu [unison-users]
- B

Post by Alan Schmitt ***@polytechnique.org [unison-users]

Post by Benoît-Pierre DEMAINE ***@demaine.info [unison-users]
Hello; I am having this very rare bug; Google does not help much.
Bug happens on only oneguest out of 15.
l3# unison-2.40 -auto -batch -times -logfile /var/log/unison.log -prefer
/srv/doublehp -addversionno -forcepartial "BelowPath bin -> /srv/doublehp"
-forcepartial "BelowPath etc -> /srv/doublehp" -forcepartial "BelowPath
local -> /srv/doublehp" -forcepartial "BelowPath share -> /srv/doublehp"
-forcepartial "BelowPath src -> /srv/doublehp" -ignore "BelowPath
local/opi-01-serveur" -ignore "BelowPath local/*/private" /srv/doublehp
Contacting server...
Connected [//l3//srv/doublehp -> //s2//srv/doublehp]
Looking for changes
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)

Other may confirm this, but I'm afraid this is because the archive is
corrupted
 You could always delete it and start from scratch (in the
sense of recording what is synchronised), but you need to be careful if
both roots are not already synchronised, as Unison will consider every
file present on only one host as newly created.
Best,
Alan
--
OpenPGP Key ID : 040D0A3B4ED2E5C7
Monthly Athmospheric CO₂, Mauna Loa Obs. 2018-02: 408.35, 2017-02: 406.42

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

Post by 'Benjamin C. Pierce' ***@cis.upenn.edu [unison-users]

Post by 'Benjamin C. Pierce' ***@cis.upenn.edu [unison-users]
Is this behavior repeatable?


 meaning: If you delete the archives and resynchronize (carefully, as
Alan notes), does it happen again?

Did not try yet to remove the whole tree.

Only removed .unison on target for now.

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

Post by 'Benjamin C. Pierce' ***@cis.upenn.edu [unison-users]
Is this behavior repeatable?

yes

[Alan Schmitt [e-mail] [unison-users]]

(I'm putting back the list in CC.)

If I rm -rf .unison on target, can I then remove the whole unison tree,
without fearing the server to backport the deletion ?

If you remove the archive, then yes, you can remove the whole
synchronised tree without having the deletion backported. *But I would
not do it*.

First, you don't need to remove the whole .unison directory, you can
simply remove the archive (on both hosts). To find it, go to the unison
folder, and do a "head -n 3 ar*". This will give you the roots for each
archive, as well as when it was last synchronised. I would then do a
manual synchronisation, keeping the data as-is, to recreate a new
archive with the current state of things. Doing it manually (without
batch nor force) lets you check data goes in the correct direction,
without having to retransfer all the data already there.

I don't have critical data on s2; I am fine with deleting all of it, and
redoing the sync from l3.

This is possible, but I think it's better to do it as proposed above.

Otherwise, please be more specific, what is corupted ? a file ? the
manifest ? on which machine (local l3, or target s2)? Does it reveal a
storage issue (bad block ) ? broken filesystem ?

The archive file is probably corrupted. I don't know the reason. If it
can be reproduced after recreating an archive, it might either be a
unison bug, or a file system issue.

I am also fine in removing .unison from l3, because there are very few
recent changes; I should not suffer any data loss.

I would strongly advise against that, as you will lose the
synchronisation state with the other machines. Just removing the one
archive file should be enough.

Best,

Alan

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

on target s2:

rm -rf .unison
rm -rf /mnt/unison

resync, still got the issue.

To remove the proper archive from the master ( l3 ) :
cd .unison
head -n 3 ar* | grep s2 -B2 | head -n1

Remove that file.

Run sync again ... still got bug.

*** full debug:

[startup] Preferences:
ui = graphic
host =
server = false
prefsdocs = false
doc =
version = false
silent = false
dumbtty = false
testserver = false
rest = ssh://***@s2//mnt/unison
rest = /mnt/unison
showprev = false
selftest = false
confirmmerge = false
retry = 0
repeat =
contactquietly = false
key =
label =
expert = false
height = 15
auto = true
maxthreads = 0
prefer = /mnt/unison
forcepartial = BelowPath src -> /mnt/unison
forcepartial = BelowPath share -> /mnt/unison
forcepartial = BelowPath local -> /mnt/unison
forcepartial = BelowPath etc -> /mnt/unison
forcepartial = BelowPath bin -> /mnt/unison
force =
sortnewfirst = false
sortbysize = false
keeptempfilesaftermerge = false
diff = diff -u CURRENT2 CURRENT1
backupdir =
maxbackups = 2
backups = false
backupsuffix =
backupprefix = .bak.$VERSION.
backuploc = central
copymax = 1
copyquoterem = default
copythreshold = -1
copyprogrest = rsync --partial --append-verify --compress
copyprog = rsync --partial --inplace --compress
rsync = true
fastcheck = default
ignorelocks = false
dumparchives = false
ignorearchives = false
showarchive = false
rootsName =
fat = false
allHostsAreRunningWindows = false
someHostIsRunningWindows = false
ignore = BelowPath local/*/private
ignore = BelowPath local/s2
ignore = Name .*.swp
ignore = Name .*~
confirmbigdel = true
batch = true
root = ssh://***@s2//mnt/unison
root = /mnt/unison
killserver = false
halfduplex = false
stream = true
addversionno = true
servercmd =
sshargs =
rshargs =
rshcmd = rsh
sshcmd = ssh
xferbycopying = true
sshversion =
ignoreinodenumbers = false
links-aux = true
links = default
times = true
group = false
owner = false
numericids = false
dontchmod = false
perms = 1023
rsrc-aux = false
rsrc = default
maxerrors = 1
unicodeCS = false
unicodeEnc = false
unicode = default
someHostIsInsensitive = false
ignorecase = default
timers = false
terse = false
logfile = /var/log/unison.log
log = true
debugtimes = false
debug = all
addprefsto =
[recon] root2direction called to choose /mnt/unison from /mnt/unison and
ssh://***@s2//mnt/unison
[recon] root2direction called to choose /mnt/unison from /mnt/unison and
ssh://***@s2//mnt/unison
[recon] root2direction called to choose /mnt/unison from /mnt/unison and
ssh://***@s2//mnt/unison
[recon] root2direction called to choose /mnt/unison from /mnt/unison and
ssh://***@s2//mnt/unison
[recon] root2direction called to choose /mnt/unison from /mnt/unison and
ssh://***@s2//mnt/unison
[recon] root2direction called to choose /mnt/unison from /mnt/unison and
ssh://***@s2//mnt/unison
Contacting server...
[remote] Shell connection: ssh (ssh, -l, root, s2, -e, none, unison-2.40,
-server)
[globals] Checking path '' for expansions
Connected [//l3//mnt/unison -> //s2//mnt/unison]
[startup] Roots:
/mnt/unison
ssh://***@s2//mnt/unison
i.e.
/mnt/unison
ssh://***@s2//mnt/unison
i.e. (in canonical order)
/mnt/unison
//s2//mnt/unison

[props] Setting permission mask to 1777 (1777 and 7777)
[stasher] initBackupsLocal
[stasher] d = /
[stasher] Prefix and suffix regexps for backup filenames have been updated
[server: stasher] initBackupsLocal
[server: stasher] d = /
[server: stasher] Prefix and suffix regexps for backup filenames have been
updated
Looking for changes
[update] Loading archive from /root/.unison/ar2c1d703ec0ff7f254880d799168c3104
[exn] Converting an End_of_file to Fatal:
End_of_file exception raised in loading archive (this indicates a bug!)
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)
[server: update] Loading archive from
/root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
Contacting server...
[server: update] Archive /root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
not found
[server: remote] Connection closed by the client
Fatal error: Server: Cannot find canonical name of /mnt/unison/local/s2:
unable to cd either to it

(/mnt/unison/local/s2: No such file or directory)
or to its parent /mnt/unison/local
(/mnt/unison/local: No such file or directory)

[Alan Schmitt [e-mail] [unison-users]]

rm -rf .unison
rm -rf /mnt/unison
resync, still got the issue.
cd .unison
head -n 3 ar* | grep s2 -B2 | head -n1
Remove that file.
Run sync again ... still got bug.




batch = true

You should not use batch for that first sync, as it's going to ask you
if you really want to synchronise as it's the first synchronisation.

[update] Loading archive from /root/.unison/ar2c1d703ec0ff7f254880d799168c3104
End_of_file exception raised in loading archive (this indicates a bug!)
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)
[server: update] Loading archive from
/root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
Contacting server...
[server: update] Archive /root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
not found
[server: remote] Connection closed by the client

The archive is not there (as expected, you deleted it). What happens if
you try with batch=false?

Best,

Alan

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

It's more than one year I have written my script, and, really, I have not
touched the unison options since the first days. I have fixed many bugs in
my script, but the core part is compeltely stable for me.

This script is working "as is" for all hosts:
- new hosts freshly installed
- working hosts
- reinstalled machines

My best surprise is that reinstalled machines recover their files, dispite
the relative complexity of my setup. Some servers have full access over
the whole unison directory (classic bidirectionnal sync between servers);
most clients have read only access (they can write on the local copy, but,
on the next hours, it's overwritten by the server version: unidirectionnal
sync), except a subdiretory that every client can write in ... but that is
read only for other clients, except a sub-sub dir that is readable only by
the client (and R-W by server only, not visible to other clients).

After re-installing a client, it recovers all data it had before the crash
disk, even data in the directory only this client can write. Unison
handles this case wonderfully well. Better than I was hoping. I was really
expecting glitches; I was fearing to need to spend days on digging this
aspect. And the magic point is that, as soon as a client have lost it's
/root/.unison folder, then, only the server version of /mnt/unison maters.

And similarly, if by mistake I damage a file on a server (bad rm, bad vim,
bad mv ... ), I just need to "rm -rf /root/.unison" before the next sync,
and other servers will cancel the mistake.

My sync script is executed hourly, and blindly, by cron. I never get
emaild the output; it's completely non interactive. I have set all non
interactive options, so that cron always does something.

I have watchdogs (munin) to warn me when 4 consecutive sync go wrong, or
when a client is broken. Then, I run the sync script manually to read the
error message (my script is also able to automatically fix some common
problems: in some case, it may automatically erase .unison, or archives
files, so that when an archive is broke, it fixes the issue by itself non
interactively in 3 runs).

=> you may dislike my script, or the options I have set in there; but keep
in mind that this script allows me to keep 25 hosts perfectly sync since
over one year without any human interaction. All I have to do is to add a
hostname in an env variable.

That's why I have batch flag set. First sync or not.

This script works fine even for first sync on freshly installed machines.
I have never done the first sync manually; I just add the hostname of new
client in some variable, and 1h later, it's sync (I don't even install
unison; my script installs the package if it's missing).

I had a hard time fixing collisions between the various versions of
unison; some hosts have 2.40, other have 2.48; plus, there are two
versions of 2.48 depending on some system lib (forgot which one; there is
a bug open about it, not by me). (
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=880449 )

Post by Alan Schmitt ***@polytechnique.org [unison-users]
You should not use batch for that first sync, as it's going to ask you
if you really want to synchronise as it's the first synchronisation.

The message I get does not look like this.

Post by Alan Schmitt ***@polytechnique.org [unison-users]
The archive is not there (as expected, you deleted it). What happens if
you try with batch=false? Best, Alan

That's a good question.

....

batch = false

....


Looking for changes
[update] Loading archive from /root/.unison/ar2c1d703ec0ff7f254880d799168c3104
[exn] Converting an End_of_file to Fatal:
End_of_file exception raised in loading archive (this indicates a bug!)
Fatal error: End_of_file exception raised in loading archive (this
indicates a bug!)
[server: update] Loading archive from
/root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
[server: update] Archive /root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
not found

.... so, roughly the same message.

I have never removed .unison from my main server.

Server has
unison version 2.40.61
unison version 2.48.3

target has
2.40.65
2.40.102
2.48.3

.... all combinations fail with the same message.

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

Post by Benoît-Pierre DEMAINE ***@demaine.info [unison-users]
[server: update] Loading archive from
/root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
[server: update] Archive /root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3
not found
... so, roughly the same message.
I have never removed .unison from my main server.
Server has
unison version 2.40.61
unison version 2.48.3
target has
2.40.65
2.40.102
2.48.3
... all combinations fail with the same message.

If I follow correctly, the [server] from the logs correspond to what you
call the target. Do you confirm that the file
/root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3 exists? If it doesn't,
it might be the problem.
Best,
Alan

No; languages are sometimes difficult.

What I call servers (masters) are the machines that have autority, and
that run cron, and initiate unison cessions, and run my script. Called L3
in previous messages.

What I call unison clients (targets) are the machines receiving unison
requests, that are in fact "ssh servers". S2 in previous messages.

File /root/.unison/ara1d6d2823d0ccd837b7ecd333ca2c3c3 does not exist on
any machine. Unison usually recreates missing files.

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

At last, I found a fix. I did not find the root cause; but this fixed my
network:

on the master:
rm /root/.unison/ar2c1d703ec0ff7f254880d799168c3104

Then, my script had new different errors; removed again those two new files:

Contacting server...
Connected [//l3//srv/doublehp -> //s2//srv/doublehp]
Looking for changes
Fatal error: Warning: the archives are locked.
If no other instance of unison is running, the locks should be removed.
The file /root/.unison/lk2c1d703ec0ff7f254880d799168c3104 on host l3
should be deleted
The file /root/.unison/lka1d6d2823d0ccd837b7ecd333ca2c3c3 on host s2
should be deleted
Please delete lock files as appropriate and try again.
Contacting server...
Fatal error: Server: Cannot find canonical name of /srv/doublehp/local/s2:
unable to cd either to it

removed them, and then, my script worked again.

Closed for me.

[Alan Schmitt [e-mail] [unison-users]]

Post by Benoît-Pierre DEMAINE ***@demaine.info [unison-users]
At last, I found a fix. I did not find the root cause; but this fixed my
rm /root/.unison/ar2c1d703ec0ff7f254880d799168c3104
Contacting server...
Connected [//l3//srv/doublehp -> //s2//srv/doublehp]
Looking for changes
Fatal error: Warning: the archives are locked.
If no other instance of unison is running, the locks should be removed.
The file /root/.unison/lk2c1d703ec0ff7f254880d799168c3104 on host l3
should be deleted
The file /root/.unison/lka1d6d2823d0ccd837b7ecd333ca2c3c3 on host s2
should be deleted
Please delete lock files as appropriate and try again.
Contacting server...
unable to cd either to it
removed them, and then, my script worked again.
Closed for me.

This is good to know. I'm curious about what happened and why it was not
working before.

Best,

Alan

[Benoît-Pierre DEMAINE [e-mail] [unison-users]]

I have been thinking about everything I have in my head (probably a small
pea). I have tried to scp binary unison from other hosts using similar
architecture.

The issue may not be unison, but the ssh layer ... ? Is there a way to ask
unison to provide extra verbose logs ?

- about ssh communication

- running unison on the target with strace ?

- IPv4 vs IPv6 resolution/communication ? ping and ssh work fine; but is
it enough ?