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: VERIFIED --- 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: ---   
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: 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.