[OpenAFS] Update time loses 67 seconds on new volume

Kristen Webb kwebb@teradactyl.com
Thu, 3 Jan 2019 12:54:12 -0700


--0000000000001165df057e932134
Content-Type: text/plain; charset="UTF-8"

This is an old issue that is cropping up in a different way, so I wanted to
share this before I attempt to perform any sort of repair that might lose
state.

A client moved a volume and currently the .backup volume copy date does not
match the rw volume copy date.  As far as I can tell, the version of
openafs was
1.8.2 (I am confirming this now).

Here are some current time stamps:

# vos ex test.volume
    Copy        Thu Nov 29 15:10:47 2018

# vos ex test.volume.backup
    Copy        Fri Nov 30 02:38:44 2018

When I try to manually update the .backup volume the Copy time
is unchanged and still different from the rw volume.

My next step is to remove the .backup volume and recreate it.
This may or may not correct the issue.

Is there anything else we can gather about this situation
that may help diagnose the issue?

Also, the way this was picked up is our backup process reported some files
as missing.  It is interesting to note that the timestamp on the files
fluctuated
around the time of the copy as well:

a. Currently the vnode/uniq for index has a time stamp of:
FILE                 5224        Wed May 23 13:27:15 2018  index

b. The last full backup (note, this was a new network full taken just after
the move operation, about 4:00 a.m. the next day)
FILE                 5224       Thu Nov 29 15:46:33 2018  index

c. From a previous full backup taken before the move the timestamp is the
same as it is currently
FILE                 5224        Wed May 23 13:27:15 2018  index

Kris



On Fri, Aug 10, 2018 at 4:49 PM Benjamin Kaduk <kaduk@mit.edu> wrote:

> On Fri, Aug 10, 2018 at 02:21:19PM -0600, Kristen Webb wrote:
> > I found this situation at a client site and though it was worth brining
> up:
> >
> > The client is running openafs 1.8.0-1~ppa0~ubuntu14.04.1-debian, but
> > I cannot yet vouch for the server versions.
> >
> > This is a new volume and here are some times from vos exa
> >
> >     Creation    Thu Aug  9 09:21:40 2018
> >     Copy        Fri Aug 10 09:58:29 2018
> >     Backup      Fri Aug 10 10:31:08 2018
> >     Last Access Fri Aug 10 14:38:59 2018
> >     Last Update Thu Aug  9 18:29:23 2018
> >
> > Last night, our parts generator for afs took a snapshot of the vldb/file
> > servers
> > about 11:15 p.m. and reported a more recent update time for the volume
> on a
> > different file server:
> >
> > Thu Aug  9 18:30:30 2018
> >
> > Which is, interestingly, 67 seconds into the future.
> >
> > I noted that the volume was copied this a.m. but after the parts
> generator
> > ran and
> > after our software noticed the discrepancy about 6:00 a.m. this morning.
> >
> > I have not confirmed if the volume was copied some time earlier.
> >
> > The volume is about 200GB.
> >
> > I'm curious if there is a reasonable explanation for this type of
> behavior.
> > I do not recall ever catching something like this before.  I am currently
> > mining our archive logs to see if I can find another instance.
>
> The server version is probably relevant; we did make some changes in this
> area for 1.8, such as modifying updateDate after salvage, and preserving
> more timestamps across volume-level operations (things like
> restore/clone/etc., though I forget the details offhand).
>
> -Ben
>


-- 
This message is NOT encrypted
--------------------------------
Mr. Kristen J. Webb
Chief Technology Officer
Teradactyl LLC.
2450 Baylor Dr. S.E.
Albuquerque, New Mexico 87106
Phone: 1-505-338-6000
Email: kwebb@teradactyl.com
Web: http://www.teradactyl.com



Providers of Scalable Backup Solutions
   for Unique Data Environments

--------------------------------
NOTICE TO RECIPIENTS: Any information contained in or attached to this
message is intended solely for the use of the intended recipient(s). If
you are not the intended recipient of this transmittal, you are hereby
notified that you received this transmittal in error, and we request
that you please delete and destroy all copies and attachments in your
possession, notify the sender that you have received this communication
in error, and note that any review or dissemination of, or the taking of
any action in reliance on, this communication is expressly prohibited.


Regular internet e-mail transmission cannot be guaranteed to be secure
or error-free. Therefore, we do not represent that this information is
complete or accurate, and it should not be relied upon as such. If you
prefer to communicate with Teradactyl LLC. using secure (i.e., encrypted
and/or digitally signed) e-mail transmission, please notify the sender.
Otherwise, you will be deemed to have consented to communicate with
Teradactyl via regular internet e-mail transmission. Please note that
Teradactyl reserves the right to intercept, monitor, and retain all
e-mail messages (including secure e-mail messages) sent to or from its
systems as permitted by applicable law

--0000000000001165df057e932134
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">This is an old issue that is cropping up in a different wa=
y, so I wanted to<div>share this before I attempt to perform any sort of re=
pair that might lose state.</div><div><br></div><div>A client moved a volum=
e and currently the .backup volume copy date does not</div><div>match the r=
w volume copy date.=C2=A0 As far as I can tell, the version of openafs was<=
/div><div>1.8.2 (I am confirming this now).</div><div><br></div><div>Here a=
re some current time stamps:</div><div><br></div><div><div># vos ex test.vo=
lume</div><div>=C2=A0 =C2=A0 Copy=C2=A0 =C2=A0 =C2=A0 =C2=A0 Thu Nov 29 15:=
10:47 2018<br></div><div><br></div><div># vos ex test.volume.backup</div></=
div><div>=C2=A0 =C2=A0 Copy=C2=A0 =C2=A0 =C2=A0 =C2=A0 Fri Nov 30 02:38:44 =
2018<br></div><div><br></div><div>When I try to manually update the .backup=
 volume the Copy time</div><div>is unchanged and still different from the r=
w volume.</div><div><br></div><div>My next step is to remove the .backup vo=
lume and recreate it.</div><div>This may or may not correct the issue.</div=
><div><br></div><div>Is there anything else we can gather about this situat=
ion</div><div>that may help diagnose the issue?</div><div><br></div><div>Al=
so, the way this was picked up is our backup process reported some files</d=
iv><div>as missing.=C2=A0 It is interesting to note that the timestamp on t=
he files fluctuated</div><div>around the time of the copy as well:</div><di=
v><br></div><div><div>a. Currently the vnode/uniq for index has a time stam=
p of:</div><div>FILE=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0=
 =C2=A05224=C2=A0 =C2=A0 =C2=A0 =C2=A0 Wed May 23 13:27:15 2018=C2=A0 index=
<br></div><div><br></div><div>b. The last full backup (note, this was a new=
 network full taken just after the move operation, about 4:00 a.m. the next=
 day)</div><div><div>FILE=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A05224=C2=A0 =C2=A0 =C2=A0 =C2=A0Thu Nov 29 15:46:33 2018=C2=A0 =
index</div><div><br></div><div>c. From a previous full backup taken before =
the move the timestamp is the same as it is currently</div><div>FILE=C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A05224=C2=A0 =C2=A0 =
=C2=A0 =C2=A0 Wed May 23 13:27:15 2018=C2=A0 index</div></div></div><div><b=
r></div><div>Kris</div><div><br></div><div><br></div></div><br><div class=
=3D"gmail_quote"><div dir=3D"ltr">On Fri, Aug 10, 2018 at 4:49 PM Benjamin =
Kaduk &lt;<a href=3D"mailto:kaduk@mit.edu" target=3D"_blank">kaduk@mit.edu<=
/a>&gt; wrote:<br></div><blockquote class=3D"gmail_quote" style=3D"margin:0=
px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">O=
n Fri, Aug 10, 2018 at 02:21:19PM -0600, Kristen Webb wrote:<br>
&gt; I found this situation at a client site and though it was worth brinin=
g up:<br>
&gt; <br>
&gt; The client is running openafs 1.8.0-1~ppa0~ubuntu14.04.1-debian, but<b=
r>
&gt; I cannot yet vouch for the server versions.<br>
&gt; <br>
&gt; This is a new volume and here are some times from vos exa<br>
&gt; <br>
&gt;=C2=A0 =C2=A0 =C2=A0Creation=C2=A0 =C2=A0 Thu Aug=C2=A0 9 09:21:40 2018=
<br>
&gt;=C2=A0 =C2=A0 =C2=A0Copy=C2=A0 =C2=A0 =C2=A0 =C2=A0 Fri Aug 10 09:58:29=
 2018<br>
&gt;=C2=A0 =C2=A0 =C2=A0Backup=C2=A0 =C2=A0 =C2=A0 Fri Aug 10 10:31:08 2018=
<br>
&gt;=C2=A0 =C2=A0 =C2=A0Last Access Fri Aug 10 14:38:59 2018<br>
&gt;=C2=A0 =C2=A0 =C2=A0Last Update Thu Aug=C2=A0 9 18:29:23 2018<br>
&gt; <br>
&gt; Last night, our parts generator for afs took a snapshot of the vldb/fi=
le<br>
&gt; servers<br>
&gt; about 11:15 p.m. and reported a more recent update time for the volume=
 on a<br>
&gt; different file server:<br>
&gt; <br>
&gt; Thu Aug=C2=A0 9 18:30:30 2018<br>
&gt; <br>
&gt; Which is, interestingly, 67 seconds into the future.<br>
&gt; <br>
&gt; I noted that the volume was copied this a.m. but after the parts gener=
ator<br>
&gt; ran and<br>
&gt; after our software noticed the discrepancy about 6:00 a.m. this mornin=
g.<br>
&gt; <br>
&gt; I have not confirmed if the volume was copied some time earlier.<br>
&gt; <br>
&gt; The volume is about 200GB.<br>
&gt; <br>
&gt; I&#39;m curious if there is a reasonable explanation for this type of =
behavior.<br>
&gt; I do not recall ever catching something like this before.=C2=A0 I am c=
urrently<br>
&gt; mining our archive logs to see if I can find another instance.<br>
<br>
The server version is probably relevant; we did make some changes in this<b=
r>
area for 1.8, such as modifying updateDate after salvage, and preserving<br=
>
more timestamps across volume-level operations (things like<br>
restore/clone/etc., though I forget the details offhand).<br>
<br>
-Ben<br>
</blockquote></div><br clear=3D"all"><div><br></div>-- <br><div dir=3D"ltr"=
 class=3D"gmail-m_7701019251894104009gmail-m_-3126082601382171349gmail_sign=
ature"><div dir=3D"ltr"><div><div dir=3D"ltr">This message is NOT encrypted
<br>--------------------------------
<br>Mr. Kristen J. Webb
<br>Chief Technology Officer
<br>Teradactyl LLC.
<br>2450 Baylor Dr. S.E.
<br>Albuquerque, New Mexico 87106
<br>Phone: 1-<span style=3D"display:inline;font-size:inherit;padding:0pt;co=
lor:rgb(80,80,80)">505-338-6000</span>
<br>Email: <a href=3D"mailto:kwebb@teradactyl.com" target=3D"_blank">kwebb@=
teradactyl.com</a>
<br>Web: <a href=3D"http://www.teradactyl.com" target=3D"_blank">http://www=
.teradactyl.com</a>
<br>
<br><img src=3D"https://drive.google.com/a/teradactyl.com/uc?id=3D1AtTRUbNs=
HoJJEO8vs4zd6D2oON5Evwq4&amp;export=3Ddownload"><br><br>Providers of Scalab=
le Backup Solutions
<br>=C2=A0=C2=A0 for Unique Data Environments
<br>
<br>--------------------------------
<br>NOTICE TO RECIPIENTS: Any information contained in or attached to this
<br>message is intended solely for the use of the intended recipient(s). If
<br>you are not the intended recipient of this transmittal, you are hereby
<br>notified that you received this transmittal in error, and we request
<br>that you please delete and destroy all copies and attachments in your
<br>possession, notify the sender that you have received this communication
<br>in error, and note that any review or dissemination of, or the taking o=
f
<br>any action in reliance on, this communication is expressly prohibited.
<br>
<br>
<br>Regular internet e-mail transmission cannot be guaranteed to be secure
<br>or error-free. Therefore, we do not represent that this information is
<br>complete or accurate, and it should not be relied upon as such. If you
<br>prefer to communicate with Teradactyl LLC. using secure (i.e., encrypte=
d
<br>and/or digitally signed) e-mail transmission, please notify the sender.
<br>Otherwise, you will be deemed to have consented to communicate with
<br>Teradactyl via regular internet e-mail transmission. Please note that
<br>Teradactyl reserves the right to intercept, monitor, and retain all
<br>e-mail messages (including secure e-mail messages) sent to or from its
<br>systems as permitted by applicable law
</div></div></div></div>

--0000000000001165df057e932134--