Subject: [netatalk-admins] ASIP works, Atalk doesn't

From: "Kevin Myer" <[email-masked]>
Date: Mon, 12 Jul 1999 17:34:19 -0400 (EDT)

Hi,

I have a bit of a problem that is baffling me.  Basically, I have a Linux
box running RedHat 5.2 with netatalk1.4b2+asun2.1.3/pre-4.  I recently
moved all my authentication for Samba and Unix (and consequently netatalk)
stuff to mechanisms involving LDAP - and they work.  Except if I try to
mount an Appleshare volume using Appletalk.  I can't figure out why and am
hoping someone has a brainstorm here.

First, netatalk is compiled with PAM enabled and it works fine.  If I use
afpovertcp, I can login, and mount anything I want.  I ran a sniffer on
this login and it behaves just like I would expect it to - it shows a the
server announcing what it supports, the login attempt from my machine to
the server, then the server going out to the LDAP server, the volumes
being shared, then the volume I chose being mounted.
(from /var/log/messages):

Jul 12 17:20:49 gneiss afpd[30084]: ASIP started on 172.20.0.99:548(1)
(1.4b2+asun2.1.4)
Jul 12 17:20:49 gneiss afpd[30084]: uam: uams_guest.so loaded
Jul 12 17:20:49 gneiss afpd[30084]: uam: uams_clrtxt.so loaded
Jul 12 17:20:49 gneiss afpd[30084]: uam: uams_dhx.so loaded
Jul 12 17:20:49 gneiss afpd[30084]: uam: "DHCAST128" available
Jul 12 17:20:49 gneiss afpd[30084]: uam: "Cleartxt Passwrd" available
Jul 12 17:20:49 gneiss afpd[30084]: uam: "No User Authent" available
Jul 12 17:20:52 gneiss afpd[30086]: ASIP session:548(1) from
172.20.20.25:2149(6
)
Jul 12 17:20:52 gneiss afpd[30084]: server_child[1] 30086 done
Jul 12 17:20:55 gneiss afpd[30087]: ASIP session:548(1) from
172.20.20.25:2150(6)
Jul 12 17:20:55 gneiss afpd[30087]: cleartext login: myer
Jul 12 17:20:56 gneiss afpd[30087]: login myer (uid 500, gid 1001)
Jul 12 17:20:56 gneiss afpd[30087]: afp_getsrvrparms: stat
/raid/lmc/MAS/MASFTE1_EBS: Permission denied
Jul 12 17:21:42 gneiss afpd[30087]: logout myer

Now, if I edit /etc/hosts.allow and disable access over IP to afpd, it
forces my machine to communicate using Appletalk.  I select the server in
the chooser, type in my username and password and sit and wait and wait.
Eventually, the connection times out.  One thing puzzles me - in my logs,
I show "dsi_getsess: No such file or directory".  I have no idea what file
or directory I don't have.  Nor does it seem like there is any way to
increase the verbosity of output of netatalk (the log level feature, for
example, of Samba, is what I would love to see so I can track down where
my errors are and what files I am missing).

Jul 12 17:04:22 gneiss afpd[29913]: ASIP started on 172.20.0.99:548(1)
(1.4b2+asun2.1.4)
Jul 12 17:04:22 gneiss afpd[29913]: uam: uams_guest.so loaded
Jul 12 17:04:22 gneiss afpd[29913]: uam: uams_clrtxt.so loaded
Jul 12 17:04:22 gneiss afpd[29913]: uam: uams_dhx.so loaded
Jul 12 17:04:22 gneiss afpd[29913]: uam: "DHCAST128" available
Jul 12 17:04:22 gneiss afpd[29913]: uam: "Cleartxt Passwrd" available
Jul 12 17:04:22 gneiss afpd[29913]: uam: "No User Authent" available
Jul 12 17:04:26 gneiss afpd[29913]: refused connect from 172.20.20.25
Jul 12 17:04:26 gneiss afpd[29913]: dsi_getsess: No such file or directory
Jul 12 17:04:30 gneiss afpd[29915]: session from 17151.117:246 on
17175.187:129
Jul 12 17:04:30 gneiss afpd[29915]: cleartext login: myer
Jul 12 17:04:41 gneiss afpd[29915]: atp_rresp: Connection timed out
Jul 12 17:04:47 gneiss afpd[29917]: session from 17151.117:246 on
17175.187:130
Jul 12 17:04:47 gneiss afpd[29917]: cleartext login: myer
Jul 12 17:04:51 gneiss afpd[29915]: afp_die: asp_shutdown: Connection
timed out
Jul 12 17:04:51 gneiss afpd[29915]: 0.04KB read, 5.18KB written
Jul 12 17:04:51 gneiss afpd[29913]: server_child[0] 29915 done
Jul 12 17:04:58 gneiss afpd[29917]: atp_rresp: Connection timed out
Jul 12 17:05:08 gneiss afpd[29917]: afp_die: asp_shutdown: Connection
timed out
Jul 12 17:05:08 gneiss afpd[29917]: 0.04KB read, 5.18KB written
Jul 12 17:05:08 gneiss afpd[29913]: server_child[0] 29917 done
Jul 12 17:05:19 gneiss afpd[29935]: session from 17151.117:246 on
17175.187:129
Jul 12 17:05:19 gneiss afpd[29913]: server_child[0] 29935 killed

Any ideas?  Obviously, when Appletalk is invoked instead of ASIP, there's
some sort of extra step thats going on that isn't completing.  What is
that extra step?

Thanks,

Kevin

-- 
     ~        Kevin M. Myer
    . .       Network/System Administrator
    /V\       ELANCO School District
   // \
  /(   )\
   ^`~'^

---

From: a sun <[email-masked]>
Date: Tue, 13 Jul 1999 11:22:22 -0700 (PDT)

the dsi_getsess message is being caused by the tcp wrapper
denial. it's normal. i'll change the errno to ECONNREFUSED to be less
ambiguous about what it means.

what happens if you just use the option key to select appletalk? both
that way and the /etc/hosts.deny way work fine on my machine.

-a

---

From: "Kevin Myer" <[email-masked]>
Date: Tue, 13 Jul 1999 16:01:53 -0400 (EDT)

>    Jul 12 17:04:47 gneiss afpd[29917]: session from 17151.117:246 on

Using the option key to select Appletalk on my machine (G3 running 8.1, OT
1.3.1), I logged in two times succesfully.  The third time, I can't.  The
same basic thing happens on an older machine running OS 7.6.1 and OT
1.1.2.  I can login once via Appletalk.  However, any further attempts to
use Appletalk fail, regardless of the machine I attempt to login from. Any
additional attempts to login over Appletalk result in an immediate kill of
the afpd child process.  ASIP continues to function as expected.

I put a little more effort into debugging this (should have before I
posted) and I found out where afpd is being killed - its immediately after
afpd opens /etc/passwd and reads in the root entry.  I am also 95% sure it
has to do with using nsswitch.conf to control that stuff because if I
disable services, networks,protocols, and ethers and just let it pull that
stuff out of files, it works.  The program bombs when it attempts to write
and that write causes a SIGPIPE.  I'm at the limits of my UNIX programming
as to what exactly is going on but here's the end of a strace of a failed
connection attempt:

1452  15:29:08.101970 open("/etc/passwd", O_RDONLY) = 0
1452  15:29:08.102270 fcntl(0, F_GETFD) = 0
1452  15:29:08.102434 fcntl(0, F_SETFD, FD_CLOEXEC) = 0
1452  15:29:08.102621 fstat(0, {st_mode=0, st_size=0, ...}) = 0
1452  15:29:08.102864 mmap(0, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4000d000
1452  15:29:08.103074 read(0,"root:XXXXXXXXXXXXX:0:0:root:/roo"..., 4096) = 522
1452  15:29:08.103451 read(0, "", 4096) = 0
1452  15:29:08.103708 close(0)          = 0
1452  15:29:08.103898 munmap(0x4000d000, 4096) = 0
1452  15:29:08.104149 getpid()          = 1452
1452  15:29:08.104672 write(2, "0\5\2\1\4B\0", 7) = -1 EPIPE (Broken pipe)
1452  15:29:08.104891 --- SIGPIPE (Broken pipe) ---

I've got straces on several good logins if they would help.  As a quick
and dirty work around, I'll just disable the nsswitch stuff that breaks
it.  If its a nss_ldap bug, I'll take it up with the folks at PADL
software.

Thanks,

Kevin (who has almost tamed the LDAP beast ;)