[netatalk-admins] rand2num, reboot, "broken v1 header" and error -50???


Subject: [netatalk-admins] rand2num, reboot, "broken v1 header" and error -50???
From: Jamie Biggar (jamie@scifi.com)
Date: Thu Mar 11 1999 - 11:11:37 EST


(potentially unnecessary history at the beginning; potentially telling
error messages at the end; this might all be due to using pre-asun2.1.2-7
and/or there might be more than one problem here; sorry for the long
message, but I think brevity often causes confusion and leads to more
e-mail traffic)

Hi all,
  I've been running netatalk basically without problem for 2 years now,
but I just ran into my first real snag on a PII with a 32GB RAID 5 running
RH5.2.

  On Monday night, one of my users complained about not being able to open
a 2-year-old PhotoShop document off the file server -- PS complained about
"not being able to open this type of document" or something. On the file
server, I ran 'gimp' and the document opened without a hitch.
  My first thought was CRLF trouble (at one point when I first upgraded to
asun 2.1.1, I forgot to turn it off, though ". BINA UNIX" was always set
in AppleVolumes.system, so that seemed pretty unlikely for a binary file.
Indeed it had both CRs and LFs in it and swapping them back and forth
didn't fix anything.
  Then I suspected .AppleDouble weirdness and tried duplicating the file
without duplicating its .AppleDouble half. That didn't help and having
never messed with .AppleDouble files at the byte level before, took the
alternate route of using gimp to convert the PSD to a TIFF which the Mac
user opened just fine.
  There was nothing in the afpd syslog related to any of this trouble.

  Not really thinking anything of it, I went ahead with my Tuesday morning
plans to switch from cleartxt to rand2num/setpassword. I also rebooted
the server for the first time in a couple of weeks. Somehow previous to
the prior boot, the HOSTNAME="" line in /etc/sysconfig/network had an
extra character put into it which I removed before the Tuesday morning
reboot. The point being I effectively renamed the server in the process.
  The switch-over went fine -- rand2num and setpassword both work fine --
but, although I didn't notice it until later, the logs very quickly (1
second after the first rand2num login), started filling up with what I
take to be .AppleDouble error messages:

Mar 9 07:44:29 zippy afpd[336]: Zippy:AFPServer@* started on 65280.73:128 (1.4b2+asun2.1.2)
Mar 9 07:44:29 zippy afpd[336]: ASIP started on 192.168.0.11:548(2) (1.4b2+asun2.1.2)
Mar 9 07:44:51 zippy afpd[432]: ASIP session:548(2) from 192.168.0.15:2057(0)
Mar 9 07:44:51 zippy afpd[336]: server_child[1] 432 done
Mar 9 07:45:44 zippy afpd[433]: ASIP session:548(2) from 192.168.0.15:2058(0)
Mar 9 07:45:44 zippy afpd[433]: randnum/rand2num login: jamie
Mar 9 07:45:44 zippy afpd[433]: login jamie (uid 101, gid 101)
Mar 9 07:45:45 zippy afpd[433]: warning: fixing up broken v1 header.
Mar 9 07:45:45 zippy afpd[433]: warning: fixing up broken v1 header.
Mar 9 07:45:51 zippy afpd[434]: ASIP session:548(2) from 192.168.0.15:2059(0)
Mar 9 07:45:51 zippy afpd[336]: server_child[1] 434 done
Mar 9 07:45:51 zippy afpd[435]: ASIP session:548(2) from 192.168.0.15:2060(0)
Mar 9 07:45:51 zippy afpd[336]: server_child[1] 435 done
Mar 9 07:46:27 zippy afpd[433]: changing password for <jamie>.
Mar 9 07:46:27 zippy afpd[433]: password changed succeeded
Mar 9 07:46:27 zippy afpd[433]: warning: fixing up broken v1 header.
Mar 9 07:46:27 zippy afpd[433]: warning: fixing up broken v1 header.
Mar 9 07:46:33 zippy afpd[433]: logout
Mar 9 07:46:33 zippy afpd[433]: 1.13KB read, 1.44KB written

(names & IPs changed to protect the innocent -- all IPs are manually
configured, not DHCP, there's only one ethernet interface on the server)

None of these errors have ever appeared in our syslog before (at least
going back to February 7th, the oldest syslog we still have on disk).

Later in the day when regular users started logging in, other errors
started showing up:

Mar 9 09:06:06 zippy afpd[636]: ASIP session:548(2) from 192.168.0.24:2220(0)
Mar 9 09:06:06 zippy afpd[636]: randnum/rand2num login: steve
Mar 9 09:06:06 zippy afpd[636]: login steve (uid 144, gid 101)
Mar 9 09:06:06 zippy afpd[636]: warning: fixing up broken v1 header.
Mar 9 09:06:15 zippy afpd[636]: ad_refresh: can't parse AppleDouble header.
Mar 9 09:06:15 zippy afpd[636]: warning: fixing up broken v1 header.
Mar 9 09:06:15 zippy afpd[636]: ad_refresh: can't parse AppleDouble header.
Mar 9 09:06:16 zippy afpd[636]: ad_refresh: can't parse AppleDouble header.
Mar 9 09:06:16 zippy afpd[636]: warning: fixing up broken v1 header.
Mar 9 09:06:16 zippy afpd[636]: ad_refresh: can't parse AppleDouble header.
Mar 9 09:06:16 zippy afpd[636]: warning: fixing up broken v1 header.

There was also one user who complained that trying to copy certain files
would produce the same "disk error -50" that was mentioned in that
symlink-to-large-volume e-mail a couple of days ago.

There didn't seem to be any permissions problems related to any of these
problems.

Again, the *only* things that had changed from the previous night were the
addition of -rand2num -setpassword in afpd.conf, the removal of -cleartxt,
a reboot, and a new server name.

At the time, we were running pre-asun2.1.2-7 (I installed it on Feb 9th
when Adrian was working with me through my -setpasswd [sic] problems and
it seemed to work without any problem or complaint so I never took the
time to upgrade to real 2.1.2). Thinking that might have been the
problem, I upgraded to asun2.1.3 this morning. It *seems* like the
messages have calmed down a bit, though both messages still appear. In
particular there are many fewer "warning: fixing up broken v1 header"
messages (maybe the "fix" is actually working with 2.1.3?), though there
are still a good number of "ad_refresh: can't parse AppleDouble header."
messages.

Any ideas why this only showed up after rand2num, a server rename and a
reboot? Any ideas how to fix this for good? Might 2.1.2-7 somehow have
started installing v2 AD headers? Looking at source, that seems unlikely.
include/atalk/adouble.h for both pre-2.1.2-7 and the current 2.1.3 have
"#define AD_VERSION AD_VERSION1". Might using adv1tov2 and recompiling to
AD_VERSION2 fix this in any case?

Thanks for any thoughts,

Jamie



This archive was generated by hypermail 2b28 : Sat Dec 18 1999 - 16:16:25 EST