Bug 2216877

Summary: When looking up included maps, sometimes autofs does not consult all the included files in order
Product: Red Hat Enterprise Linux 8 Reporter: Frank Sorenson <fsorenso>
Component: autofsAssignee: Ian Kent <ikent>
Status: CLOSED ERRATA QA Contact: Kun Wang <kunwan>
Severity: medium Docs Contact:
Priority: medium    
Version: 8.7CC: dwysocha, michael_shon, xzhou
Target Milestone: rcKeywords: CustomerScenariosInitiative, Triaged
Target Release: ---Flags: pm-rhel: mirror+
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: autofs-5.1.4-108.el8 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 2223236 (view as bug list) Environment:
Last Closed: 2023-11-14 15:48:36 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 2223236    
Attachments:
Description Flags
Patch - fix incorrect matching of cached wildcard key none

Description Frank Sorenson 2023-06-23 00:56:40 UTC
Description of problem:

Sometimes, autofs does not consult all the included maps in order.  This can lead to a failed lookup or the incorrect mount of a wildcard.


Version-Release number of selected component (if applicable):
autofs-5.1.4-104.el8.x86_64


How reproducible:
frequently


Steps to Reproduce:

/etc/auto.master:
/home1	/etc/auto.home

/etc/auto.home:
+/etc/auto.home.users
+/etc/auto.home.sysadmin
+/etc/auto.home.wildcard

/etc/auto.home.users:
user1    -bind,rw    :/homes/&
user2    -bind,rw    :/homes/&
user3    -bind,rw    :/homes/&

/etc/auto.home.sysadmin:
sysadmin	:/homes/&

/etc/auto.home.wildcard:
*	-bind,rw	:/homes/wildcard

# for dir in {user1,user2,user3,sysadmin,wildcard} ; do mkdir -p /homes/$dir ; touch /homes/$dir/file_in_$dir ; done

# systemctl restart autofs.service

# ls -al /home1/sysadmin/file*


Actual results:

# ls -al /home1/sysadmin/file*
-rw-r--r--. 1 root root 0 Jun 22 19:16 /home1/sysadmin/file_in_wildcard


Expected results:

# ls -al /home1/sysadmin/file*
-rw-r--r--. 1 root root 0 Jun 22 19:16 /home1/sysadmin/file_in_sysadmin


Additional info:

Comment 1 Frank Sorenson 2023-06-23 00:59:10 UTC
automount debug output:

When it works:

Jun 22 19:27:14 vm23 automount[1992185]: handle_packet: type = 3
Jun 22 19:27:14 vm23 automount[1992185]: handle_packet_missing_indirect: token 56409, name sysadmin, request pid 3204596
Jun 22 19:27:14 vm23 automount[1992185]: pidinfo requestor: failed to open /proc/3204596/status
Jun 22 19:27:14 vm23 automount[1992185]: attempting to mount entry /home1/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_one: lookup(file): lookup included map +/etc/auto.home.users
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_one: lookup(file): lookup included map +/etc/auto.home.sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): sysadmin -> -bind,rw#011:/homes/&
Jun 22 19:27:14 vm23 automount[1992185]: parse_mount: parse(sun): expanded entry: -bind,rw#011:/homes/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: parse_mount: parse(sun): gathered options: bind,rw
Jun 22 19:27:14 vm23 automount[1992185]: st_readmap: state 1 path /home1
Jun 22 19:27:14 vm23 automount[1992185]: parse_mount: parse(sun): dequote(":/homes/sysadmin") -> :/homes/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: parse_mount: parse(sun): core of entry: options=bind,rw, loc=:/homes/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: sun_mount: parse(sun): mounting root /home1, mountpoint sysadmin, what :/homes/sysadmin, fstype nfs, options bind,rw
Jun 22 19:27:14 vm23 automount[1992185]: mount(nfs): root=/home1 name=sysadmin what=:/homes/sysadmin, fstype=nfs, options=bind,rw
Jun 22 19:27:14 vm23 automount[1992185]: mount(nfs): nfs options="bind,rw", nobind=0, nosymlink=0, ro=0
Jun 22 19:27:14 vm23 automount[1992185]: mount_mount: mount(nfs): calling mkdir_path /home1/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: re-reading map for /home1
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home
Jun 22 19:27:14 vm23 automount[1992185]: mount_mount: mount(nfs): sysadmin is local, attempt bind mount
Jun 22 19:27:14 vm23 automount[1992185]: mount_mount: mount(bind): calling mkdir_path /home1/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_read_map: read included map +/etc/auto.home.users
Jun 22 19:27:14 vm23 automount[1992185]: mount(bind): calling mount --bind -o defaults /homes/sysadmin /home1/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home.users
Jun 22 19:27:14 vm23 automount[1992185]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:27:14 vm23 automount[1992185]: lookup_read_map: read included map +/etc/auto.home.sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home.sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home.users
Jun 22 19:27:14 vm23 automount[1992185]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:27:14 vm23 automount[1992185]: lookup_read_map: read included map +/etc/auto.home.wildcard
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home.wildcard
Jun 22 19:27:14 vm23 automount[1992185]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home.sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_nss_read_map: reading map file /etc/auto.home.users
Jun 22 19:27:14 vm23 automount[1992185]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:27:14 vm23 automount[1992185]: st_ready: st_ready(): state = 4 path /home1
Jun 22 19:27:14 vm23 automount[1992185]: mount_mount: mount(bind): mounted /homes/sysadmin type bind on /home1/sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: dev_ioctl_send_ready: token = 56409
Jun 22 19:27:14 vm23 automount[1992185]: mounted /home1/sysadmin

when it mounts the wildcard:

Jun 22 19:35:13 vm23 automount[1992473]: handle_packet: type = 3
Jun 22 19:35:13 vm23 automount[1992473]: handle_packet_missing_indirect: token 56417, name sysadmin, request pid 3204596
Jun 22 19:35:13 vm23 automount[1992473]: pidinfo requestor: failed to open /proc/3204596/status
Jun 22 19:35:13 vm23 automount[1992473]: attempting to mount entry /home1/sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: lookup_one: lookup(file): lookup included map +/etc/auto.home.users
Jun 22 19:35:13 vm23 automount[1992473]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: lookup_mount: lookup(file): sysadmin -> -bind,rw#011:/homes/wildcard
Jun 22 19:35:13 vm23 automount[1992473]: parse_mount: parse(sun): expanded entry: -bind,rw#011:/homes/wildcard
Jun 22 19:35:13 vm23 automount[1992473]: parse_mount: parse(sun): gathered options: bind,rw
Jun 22 19:35:13 vm23 automount[1992473]: parse_mount: parse(sun): dequote(":/homes/wildcard") -> :/homes/wildcard
Jun 22 19:35:13 vm23 automount[1992473]: parse_mount: parse(sun): core of entry: options=bind,rw, loc=:/homes/wildcard
Jun 22 19:35:13 vm23 automount[1992473]: sun_mount: parse(sun): mounting root /home1, mountpoint sysadmin, what :/homes/wildcard, fstype nfs, options bind,rw
Jun 22 19:35:13 vm23 automount[1992473]: mount(nfs): root=/home1 name=sysadmin what=:/homes/wildcard, fstype=nfs, options=bind,rw
Jun 22 19:35:13 vm23 automount[1992473]: mount(nfs): nfs options="bind,rw", nobind=0, nosymlink=0, ro=0
Jun 22 19:35:13 vm23 automount[1992473]: mount_mount: mount(nfs): calling mkdir_path /home1/sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: mount_mount: mount(nfs): sysadmin is local, attempt bind mount
Jun 22 19:35:13 vm23 automount[1992473]: mount_mount: mount(bind): calling mkdir_path /home1/sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: mount(bind): calling mount --bind -o defaults /homes/wildcard /home1/sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: mount_mount: mount(bind): mounted /homes/wildcard type bind on /home1/sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: dev_ioctl_send_ready: token = 56417
Jun 22 19:35:13 vm23 automount[1992473]: st_readmap: state 1 path /home1
Jun 22 19:35:13 vm23 automount[1992473]: mounted /home1/sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: re-reading map for /home1
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: lookup_read_map: read included map +/etc/auto.home.users
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home.users
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: lookup_read_map: read included map +/etc/auto.home.sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home.sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home.users
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: lookup_read_map: read included map +/etc/auto.home.wildcard
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home.wildcard
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home.sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: lookup_nss_read_map: reading map file /etc/auto.home.users
Jun 22 19:35:13 vm23 automount[1992473]: do_init: parse(sun): init gathered global options: (null)
Jun 22 19:35:13 vm23 automount[1992473]: st_ready: st_ready(): state = 4 path /home1


the difference appears to be in the following:
expected:
Jun 22 19:27:14 vm23 automount[1992185]: lookup_one: lookup(file): lookup included map +/etc/auto.home.users
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_one: lookup(file): lookup included map +/etc/auto.home.sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:27:14 vm23 automount[1992185]: lookup_mount: lookup(file): sysadmin -> -bind,rw#011:/homes/&
Jun 22 19:27:14 vm23 automount[1992185]: parse_mount: parse(sun): expanded entry: -bind,rw#011:/homes/sysadmin

vs actual:

Jun 22 19:35:13 vm23 automount[1992473]: lookup_one: lookup(file): lookup included map +/etc/auto.home.users
Jun 22 19:35:13 vm23 automount[1992473]: lookup_mount: lookup(file): looking up sysadmin
Jun 22 19:35:13 vm23 automount[1992473]: lookup_mount: lookup(file): sysadmin -> -bind,rw#011:/homes/wildcard
Jun 22 19:35:13 vm23 automount[1992473]: parse_mount: parse(sun): expanded entry: -bind,rw#011:/homes/wildcard

Comment 2 Ian Kent 2023-07-01 00:41:15 UTC
Created attachment 1973498 [details]
Patch - fix incorrect matching of cached wildcard key

It seems I didn't report my findings from investigating this before
my recent absence, oops!

I'll need to get back to this to apply the change.

Comment 3 Frank Sorenson 2023-07-03 16:56:48 UTC
Ian,

Thank you.  I've done some light testing, and the patch looks to fix the bug.  I've given our customer a TEST package for additional verification.

Comment 4 Ian Kent 2023-07-04 00:40:46 UTC
(In reply to Frank Sorenson from comment #3)
> Ian,
> 
> Thank you.  I've done some light testing, and the patch looks to fix the
> bug.  I've given our customer a TEST package for additional verification.

Thanks Frank, it did look fairly obvious so it should work ok.

Comment 6 Ian Kent 2023-07-06 06:52:49 UTC
(In reply to Ian Kent from comment #4)
> (In reply to Frank Sorenson from comment #3)
> > Ian,
> > 
> > Thank you.  I've done some light testing, and the patch looks to fix the
> > bug.  I've given our customer a TEST package for additional verification.
> 
> Thanks Frank, it did look fairly obvious so it should work ok.

While the cause is obvious there is a mistake in the patch and
it has a side effect.

So I am still working on it, sorry.

Comment 7 Ian Kent 2023-07-06 09:00:46 UTC
Created attachment 1974272 [details]
Patch - fix incorrect matching of cached wildcard key (updated)

Upstream patch to be back ported.

Comment 16 errata-xmlrpc 2023-11-14 15:48:36 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (autofs bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2023:7098