* Mountpoint string corruption in autofs5.0.3-3?
@ 2009-04-23 23:07 Thomas Connell
2009-04-26 3:47 ` Ian Kent
0 siblings, 1 reply; 4+ messages in thread
From: Thomas Connell @ 2009-04-23 23:07 UTC (permalink / raw)
To: autofs
Hi;
I'm having a problem that I've attempted to debug and google on my own, but have reached my limits of understanding. I'm hoping
the list may be able to provide some insight.
Some back story:
I inherited this setup, which was discussed in this list, a little while ago:
http://linux.kernel.org/pipermail/autofs/2009-February/005575.html
As that link provided, I was able to backport debian 5.0 autofs5 to debian 4.0 with the little patch. My testing seemed to
indicate it was working fine.
When I started to roll it out, the automounter process started working the CPU really hard, and some automounts that were
mounting before were not.
Here are the verbose logs from when the first access attempts to hit the mountpoint. I apologize for not obscuring the domain
name that is also the mount point, but since that is what is corrupted, I don't see a way not to post it:
Apr 23 14:27:21 web6 automount[31779]: handle_packet: type = 3
Apr 23 14:27:21 web6 automount[31779]: handle_packet_missing_indirect: token 5106, name federalhousingtaxcredit.com, request pid
14419
Apr 23 14:27:21 web6 automount[31779]: attempting to mount entry /domains/f/federalhousingtaxcredit.com
Apr 23 14:27:21 web6 automount[31779]: lookup_mount: lookup(ldap): looking up federalhousingtaxcredit.com
Apr 23 14:27:21 web6 automount[31779]: do_bind: lookup(ldap): ldap anonymous bind returned 0
Apr 23 14:27:21 web6 automount[31779]: lookup_one: lookup(ldap): searching for
"(&(objectclass=automount)(|(cn=federalhousingtaxcredit.com)(cn=/)(cn=\2A)))" under
"ou=domains,ou=jails,ou=Mounts,dc=modwest,dc=com"
Apr 23 14:27:22 web6 automount[31779]: lookup_one: lookup(ldap): getting first entry for cn="federalhousingtaxcredit.com"
Apr 23 14:27:22 web6 automount[31779]: lookup_one: lookup(ldap): examining first entry
Apr 23 14:27:22 web6 automount[31779]: lookup_one: lookup(ldap): examining first entry
Apr 23 14:27:22 web6 automount[31779]: lookup_mount: lookup(ldap): federalhousingtaxcredit.com -> /
:/www/vhosts/f/federalhousingtaxcredit.com /.renv :/mnt/jail
Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): expanded entry: / :/www/vhosts/f/federalhousingtaxcredit.com
/.renv :/mnt/jail
Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): gathered options: vd,strict
Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): dequote("/") -> /
Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): gathered options: vd,strict
Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): dequote(":/www/vhosts/f/federalhousingtaxcredit.com") ->
:/www/vhosts/f/federalhousingtaxcredit.com
Apr 23 14:27:22 web6 automount[31779]: add_offset_entry: parse(sun): added multi-mount offset / -> -vd,strict
:/www/vhosts/f/federalhousingtaxcredit.com
Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): dequote("/.renv") -> /.renv
Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): gathered options: vd,strict
Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): dequote(":/mnt/jail") -> :/mnt/jail
Apr 23 14:27:22 web6 automount[31779]: add_offset_entry: parse(sun): added multi-mount offset /.renv -> -vd,strict :/mnt/jail
Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): gathered options: vd,strict
Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): dequote(":/www/vhosts/f/federalhousingtaxcredit.com") ->
:/www/vhosts/f/federalhousingtaxcredit.com
Apr 23 14:27:22 web6 automount[31779]: sun_mount: parse(sun): mounting root /domains/f/federalhousingtaxcredit.com, mountpoint
/, what :/www/vhosts/f/federalhousingtaxcredit.com, fstype nfs, options vd
Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): root=/domains/f/federalhousingtaxcredit.com name=/
what=:/www/vhosts/f/federalhousingtaxcredit.com, fstype=nfs, options=vd
Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): nfs options="vd", nosymlink=0, ro=0
Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): calling mkdir_path /domains/f/federalhousingtaxcredit.com
Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): / is local, attempt bind mount
Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(bind): calling mkdir_path /domains/f/federalhousingtaxcred���om
Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(bind): calling mount --bind -s -o defaults
/www/vhosts/f/federalhousingtaxcredit.com /domains/f/federalhousingtaxcred���
Apr 23 14:27:22 web6 automount[31779]: >> mount: mount point /domains/f/federalhousingtaxcred��� does not exist
Apr 23 14:27:22 web6 automount[31779]: mount(nfs): nfs: mount failure :/www/vhosts/f/federalhousingtaxcredit.com on
/domains/f/federalhousingtaxcredit.com
Apr 23 14:27:22 web6 automount[31779]: mount_multi_triggers: mount offset /domains/f/federalhousingtaxcredit.com/.renv
Apr 23 14:27:22 web6 automount[31779]: mount_autofs_offset: calling mount -t autofs -s -o
fd=96,pgrp=31779,minproto=5,maxproto=5,offset automount /domains/f/federalhousingtaxcredit.com/.renv
Apr 23 14:27:22 web6 automount[31779]: mount_autofs_offset: mounted trigger /domains/f/federalhousingtaxcredit.com/.renv
Apr 23 14:27:22 web6 automount[31779]: send_fail: token = 5106
Apr 23 14:27:22 web6 automount[31779]: failed to mount /domains/f/federalhousingtaxcredit.com
This causes the CPU load because automounter itself winds up accessing the garbled directory, spurring another attempt at
mounting, so on and so forth.
Here is a strace for the same period of time:
[pid 31827] clone(Process 32051 attached
child_stack=0xb57244c4,
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID|CLONE_DETACHED,
parent_tidptr=0xb5724bf8, {entry_number:6, base_addr:0xb5724bb0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0,
limit_in_pages:1, seg_not_present:0, useable:1}, child_tidptr=0xb5724bf8) = 32051
[pid 32051] futex(0x8006064c, FUTEX_WAKE, 1 <unfinished ...>
[pid 32051] <... futex resumed> ) = 0
[pid 32051] futex(0x80060648, FUTEX_WAKE, 1 <unfinished ...>
[pid 32051] <... futex resumed> ) = 0
[pid 32051] lstat64("/domains/f/federalhousingtaxcredit.com", <unfinished ...>
[pid 32051] <... lstat64 resumed> 0xb57243a4) = -1 ENOENT (No such file or directory)
[pid 32051] time( <unfinished ...>
[pid 32051] <... time resumed> [1240518441]) = 1240518441
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<30>Apr 23 14:27:21 automount[31"..., 102, MSG_NOSIGNAL) = 102
[pid 32051] sched_yield() = 0
[pid 32051] time([1240518441]) = 1240518441
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:21 automount[31"..., 104, MSG_NOSIGNAL) = 104
[pid 32051] time(NULL) = 1240518441
[pid 32051] time(NULL) = 1240518441
[pid 32051] socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 4
[pid 32051] setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
[pid 32051] fcntl64(4, F_GETFL) = 0x2 (flags O_RDWR)
[pid 32051] fcntl64(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 32051] connect(4, {sa_family=AF_INET, sin_port=htons(389), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 EINPROGRESS
(Operation now in progress)
[pid 32051] select(1024, NULL, [4], NULL, {8, 0}) = 1 (out [4], left {8, 0})
[pid 32051] getpeername(4, {sa_family=AF_INET, sin_port=htons(389), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
[pid 32051] fcntl64(4, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 32051] fcntl64(4, F_SETFL, O_RDWR) = 0
[pid 32051] getpeername(4, {sa_family=AF_INET, sin_port=htons(389), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
[pid 32051] uname({sys="Linux", node="web6", ...}) = 0
[pid 32051] time(NULL) = 1240518441
[pid 32051] write(4, "0\f\2\1\1`\7\2\1\3\4\0\200\0", 14) = 14
[pid 32051] select(1024, [4], [], NULL, NULL) = 1 (in [4])
[pid 32051] read(4, "0\f\2\1\1a\7\n", 8) = 8
[pid 32051] read(4, "\1\0\4\0\4\0", 6) = 6
[pid 32051] time(NULL) = 1240518441
[pid 32051] time([1240518441]) = 1240518441
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:21 automount[31"..., 91, MSG_NOSIGNAL) = 91
[pid 32051] time([1240518441]) = 1240518441
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:21 automount[31"..., 211, MSG_NOSIGNAL) = 211
[pid 32051] time(NULL) = 1240518441
[pid 32051] write(4, "0\201\265\2\1\2c\201\257\4/ou=domains,ou=jails,o"..., 184) = 184
[pid 32051] select(1024, [4], [], NULL, NULL) = 1 (in [4])
[pid 32051] read(4, "0\201\327\2\1\2d\201", 8) = 8
[pid 32051] read(4, "\321\4Ncn=federalhousingtaxcredit.co"..., 210) = 210
[pid 32051] select(1024, [4], [], NULL, NULL) = 1 (in [4])
[pid 32051] read(4, "0\201\204\2\1\2d\177", 8) = 8
[pid 32051] read(4, "\0044cn=/,ou=domains,ou=jails,ou=Mo"..., 127) = 127
[pid 32051] select(1024, [4], [], NULL, NULL) = 1 (in [4])
[pid 32051] read(4, "0\f\2\1\2e\7\n", 8) = 8
[pid 32051] read(4, "\1\0\4\0\4\0", 6) = 6
[pid 32051] time(NULL) = 1240518442
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 120, MSG_NOSIGNAL) = 120
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 85, MSG_NOSIGNAL) = 85
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 85, MSG_NOSIGNAL) = 85
[pid 32051] write(4, "0\5\2\1\3B\0", 7) = 7
[pid 32051] shutdown(4, 2 /* send and receive */) = 0
[pid 32051] close(4) = 0
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 159, MSG_NOSIGNAL) = 159
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 141, MSG_NOSIGNAL) = 141
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 90, MSG_NOSIGNAL) = 90
[pid 32051] time(NULL) = 1240518442
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 80, MSG_NOSIGNAL) = 80
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 91, MSG_NOSIGNAL) = 91
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 163, MSG_NOSIGNAL) = 163
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 151, MSG_NOSIGNAL) = 151
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 90, MSG_NOSIGNAL) = 90
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 91, MSG_NOSIGNAL) = 91
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 99, MSG_NOSIGNAL) = 99
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 124, MSG_NOSIGNAL) = 124
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 91, MSG_NOSIGNAL) = 91
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 163, MSG_NOSIGNAL) = 163
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 200, MSG_NOSIGNAL) = 200
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 185, MSG_NOSIGNAL) = 185
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 98, MSG_NOSIGNAL) = 98
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 120, MSG_NOSIGNAL) = 120
[pid 32051] stat64("/domains", {st_mode=S_IFDIR|0555, st_size=4096, ...}) = 0
[pid 32051] stat64("/domains/f", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 32051] stat64("/domains/f/federalhousingtaxcredit.com", 0xb5720a18) = -1 ENOENT (No such file or directory)
[pid 32051] statfs64("/domains/f", 84, {f_type=0x187, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0,
f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
[pid 32051] mkdir("/domains/f/federalhousingtaxcredit.com", 0555) = 0
[pid 32051] open("/etc/mtab", O_RDONLY) = 4
[pid 32051] fstat64(4, {st_mode=S_IFREG|0644, st_size=771, ...}) = 0
[pid 32051] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fa9000
[pid 32051] read(4, "/dev/hda3 / ext3 rw,noatime,erro"..., 4096) = 771
[pid 32051] read(4, "", 4096) = 0
[pid 32051] close(4) = 0
[pid 32051] munmap(0xb7fa9000, 4096) = 0
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 93, MSG_NOSIGNAL) = 93
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 121, MSG_NOSIGNAL) = 121
[pid 32051] stat64("/domains", {st_mode=S_IFDIR|0555, st_size=4096, ...}) = 0
[pid 32051] stat64("/domains/f", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 32051] stat64("/domains/f/federalhousingtaxcred���om", 0xb57208d8) = -1 ENOENT (No such file or directory)
[pid 32051] statfs64("/domains/f", 84, {f_type=0x187, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0,
f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
[pid 32051] mkdir("/domains/f/federalhousingtaxcred���om", 0555) = 0
[pid 32051] open("/etc/mtab", O_RDONLY) = 4
[pid 32051] fstat64(4, {st_mode=S_IFREG|0644, st_size=771, ...}) = 0
[pid 32051] mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fa9000
[pid 32051] read(4, "/dev/hda3 / ext3 rw,noatime,erro"..., 4096) = 771
[pid 32051] read(4, "", 4096) = 0
[pid 32051] close(4) = 0
[pid 32051] munmap(0xb7fa9000, 4096) = 0
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 179, MSG_NOSIGNAL) = 179
[pid 32051] pipe([4, 221]) = 0
[pid 32051] rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], ~[KILL STOP RTMIN RT_1], 8) = 0
[pid 32051] clone(Process 32052 attached
[pid 32051] rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
[pid 32051] close(221) = 0
[pid 32051] read(4, <unfinished ...>
[pid 32051] <... read resumed> "mount: mount point /domains/f/fe"..., 2047) = 71
[pid 32051] time( <unfinished ...>
[pid 32051] <... time resumed> [1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<28>Apr 23 14:27:22 automount[31"..., 111, MSG_NOSIGNAL) = 111
[pid 32051] read(4, "", 2047) = 0
[pid 32051] close(4) = 0
[pid 32051] waitpid(32052, [{WIFEXITED(s) && WEXITSTATUS(s) == 32}], 0) = 32052
[pid 32051] rt_sigprocmask(SIG_SETMASK, ~[KILL STOP RTMIN RT_1], NULL, 8) = 0
[pid 32051] time([1240518442]) = 1240518442
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=877, ...}) = 0
[pid 32051] send(3, "<30>Apr 23 14:27:22 automount[31"..., 153, MSG_NOSIGNAL) = 153
[pid 32051] lstat64("/domains/f/federalhousingtaxcredit.com", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
[pid 32051] statfs64("/domains/f/federalhousingtaxcredit.com", 84, {f_type=0x187, f_bsize=4096, f_blocks=0, f_bfree=0,
f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
[pid 32051] rmdir("/domains/f/federalhousingtaxcredit.com") = 0
[pid 32051] lstat64("/domains/f", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
[pid 32051] statfs64("/domains/f", 84, {f_type=0x187, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0,
f_fsid={0, 0}, f_namelen=255, f_frsize=4096}) = 0
[pid 32051] rmdir("/domains/f") = -1 EBUSY (Device or resource busy)
...
Some mountpoints have this problem, other mount just fine. I'm out of my depth, so don't know exactly what information you may
need to help be troubleshoot. Let me know if I can provide any other information!
Thanks,
--
Thomas Connell
Modwest.com
Need Answers? http://www.modwest.com/help
_______________________________________________
autofs mailing list
autofs@linux.kernel.org
http://linux.kernel.org/mailman/listinfo/autofs
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: Mountpoint string corruption in autofs5.0.3-3?
2009-04-23 23:07 Mountpoint string corruption in autofs5.0.3-3? Thomas Connell
@ 2009-04-26 3:47 ` Ian Kent
2009-04-26 16:36 ` Thomas Connell
0 siblings, 1 reply; 4+ messages in thread
From: Ian Kent @ 2009-04-26 3:47 UTC (permalink / raw)
To: Thomas Connell; +Cc: autofs
On Thu, Apr 23, 2009 at 05:07:00PM -0600, Thomas Connell wrote:
> Hi;
>
> I'm having a problem that I've attempted to debug and google on my own, but have reached my limits of understanding. I'm hoping
> the list may be able to provide some insight.
>
> Some back story:
>
> I inherited this setup, which was discussed in this list, a little while ago:
> http://linux.kernel.org/pipermail/autofs/2009-February/005575.html
>
> As that link provided, I was able to backport debian 5.0 autofs5 to debian 4.0 with the little patch. My testing seemed to
> indicate it was working fine.
>
> When I started to roll it out, the automounter process started working the CPU really hard, and some automounts that were
> mounting before were not.
>
>
> Here are the verbose logs from when the first access attempts to hit the mountpoint. I apologize for not obscuring the domain
> name that is also the mount point, but since that is what is corrupted, I don't see a way not to post it:
>
>
> Apr 23 14:27:21 web6 automount[31779]: handle_packet: type = 3
> Apr 23 14:27:21 web6 automount[31779]: handle_packet_missing_indirect: token 5106, name federalhousingtaxcredit.com, request pid
> 14419
> Apr 23 14:27:21 web6 automount[31779]: attempting to mount entry /domains/f/federalhousingtaxcredit.com
> Apr 23 14:27:21 web6 automount[31779]: lookup_mount: lookup(ldap): looking up federalhousingtaxcredit.com
> Apr 23 14:27:21 web6 automount[31779]: do_bind: lookup(ldap): ldap anonymous bind returned 0
> Apr 23 14:27:21 web6 automount[31779]: lookup_one: lookup(ldap): searching for
> "(&(objectclass=automount)(|(cn=federalhousingtaxcredit.com)(cn=/)(cn=\2A)))" under
> "ou=domains,ou=jails,ou=Mounts,dc=modwest,dc=com"
> Apr 23 14:27:22 web6 automount[31779]: lookup_one: lookup(ldap): getting first entry for cn="federalhousingtaxcredit.com"
> Apr 23 14:27:22 web6 automount[31779]: lookup_one: lookup(ldap): examining first entry
> Apr 23 14:27:22 web6 automount[31779]: lookup_one: lookup(ldap): examining first entry
> Apr 23 14:27:22 web6 automount[31779]: lookup_mount: lookup(ldap): federalhousingtaxcredit.com -> /
> :/www/vhosts/f/federalhousingtaxcredit.com /.renv :/mnt/jail
> Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): expanded entry: / :/www/vhosts/f/federalhousingtaxcredit.com
> /.renv :/mnt/jail
> Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): gathered options: vd,strict
> Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): dequote("/") -> /
> Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): gathered options: vd,strict
> Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): dequote(":/www/vhosts/f/federalhousingtaxcredit.com") ->
> :/www/vhosts/f/federalhousingtaxcredit.com
> Apr 23 14:27:22 web6 automount[31779]: add_offset_entry: parse(sun): added multi-mount offset / -> -vd,strict
> :/www/vhosts/f/federalhousingtaxcredit.com
> Apr 23 14:27:22 web6 automount[31779]: parse_mount: parse(sun): dequote("/.renv") -> /.renv
> Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): gathered options: vd,strict
> Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): dequote(":/mnt/jail") -> :/mnt/jail
> Apr 23 14:27:22 web6 automount[31779]: add_offset_entry: parse(sun): added multi-mount offset /.renv -> -vd,strict :/mnt/jail
> Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): gathered options: vd,strict
> Apr 23 14:27:22 web6 automount[31779]: parse_mapent: parse(sun): dequote(":/www/vhosts/f/federalhousingtaxcredit.com") ->
> :/www/vhosts/f/federalhousingtaxcredit.com
> Apr 23 14:27:22 web6 automount[31779]: sun_mount: parse(sun): mounting root /domains/f/federalhousingtaxcredit.com, mountpoint
> /, what :/www/vhosts/f/federalhousingtaxcredit.com, fstype nfs, options vd
> Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): root=/domains/f/federalhousingtaxcredit.com name=/
> what=:/www/vhosts/f/federalhousingtaxcredit.com, fstype=nfs, options=vd
> Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): nfs options="vd", nosymlink=0, ro=0
> Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): calling mkdir_path /domains/f/federalhousingtaxcredit.com
> Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(nfs): / is local, attempt bind mount
> Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(bind): calling mkdir_path /domains/f/federalhousingtaxcred���om
> Apr 23 14:27:22 web6 automount[31779]: mount_mount: mount(bind): calling mount --bind -s -o defaults
> /www/vhosts/f/federalhousingtaxcredit.com /domains/f/federalhousingtaxcred���
> Apr 23 14:27:22 web6 automount[31779]: >> mount: mount point /domains/f/federalhousingtaxcred��� does not exist
Is this string corruption really present in the log?
I can't see how that corruption can occur looking at the code.
If this really is in the log so you will need to narrow down where this
corruption is happening.
Adding a debug logging patch to the Debian build to log what is received
by modules/mount_bind.c:mount_mount() would be the first thing to do. A
debug log statement similar to the one at the top of
modules/mount_nfs.c:mount_mount() would be enough to tell if this happens
before the call to perform bind mount, or after.
Ian
_______________________________________________
autofs mailing list
autofs@linux.kernel.org
http://linux.kernel.org/mailman/listinfo/autofs
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: Mountpoint string corruption in autofs5.0.3-3?
2009-04-26 3:47 ` Ian Kent
@ 2009-04-26 16:36 ` Thomas Connell
2009-04-28 4:52 ` Ian Kent
0 siblings, 1 reply; 4+ messages in thread
From: Thomas Connell @ 2009-04-26 16:36 UTC (permalink / raw)
To: Ian Kent; +Cc: autofs
Ian Kent wrote:
> Is this string corruption really present in the log?
It is.
> If this really is in the log so you will need to narrow down where this
> corruption is happening.
I gave it a shot; I am largely a complete C novice, but:
Following the debugging from the nfs module, the log shows:
Apr 26 09:49:30 web6 automount[3920]: mount_mount: mount(bind): root=/domains/f/federalhousingtaxcredit.com name=/
what=/www/vhosts/f/federalhousingtaxcredit.com, fstype=bind, options=
Which all looks right to me.
Since I could see in the logs that fullpath was garbled, I was wondering if maybe alloca wasn't getting the right length. I did
a bit of trial and error, and it seems consistent that fullpaths of 33 or over become garbled.
So, in mount_bind.c, I added:
debug(ap->logopt, MODPREFIX "name_len=%d", name_len);
right after
int i, rlen;
and
debug(ap->logopt, MODPREFIX "name_len=%d rlen=%d", name_len, rlen);
right after
rlen = strlen(root);
The logs show:
Apr 26 10:05:46 web6 automount[7353]: mount_mount: mount(bind): name_len=0
Apr 26 10:05:46 web6 automount[7353]: mount_mount: mount(bind): name_len=0 rlen=0
which looks wrong to me! (even though it happens the same for the domains that worked before, and those that did not.)
I would expect name_len == 1 so that the program enters this block:
/* Root offset of multi-mount */
if (*name == '/' && name_len == 1) {
rlen = strlen(root);
name_len = 0;
instead of, right after it:
} else if (*name == '/')
rlen = 0;
If I set alloca to an arbitrarily high number, the previously garbled mounts mount correctly, without corruption. It seems like
for this style of mount, name_len should be 1, not 0.
By the way, the automount map looks like:
# federalhousingtaxcredit.com, domains, jails, Mounts, modwest.com
dn: cn=federalhousingtaxcredit.com,ou=domains,ou=jails,ou=Mounts,dc=modwest,dc=com
objectClass: automount
cn: federalhousingtaxcredit.com
automountInformation: / :/www/vhosts/f/federalhousingtaxcredit.com /.renv :/mnt/jail
For now, I guess I can just waste some memory by setting alloca() arbitrarily high, but that doesn't seem the correct solution.
I hope this reconnaissance was helpful.
Thanks,
Thomas Connell
^ permalink raw reply [flat|nested] 4+ messages in thread* Re: Mountpoint string corruption in autofs5.0.3-3?
2009-04-26 16:36 ` Thomas Connell
@ 2009-04-28 4:52 ` Ian Kent
0 siblings, 0 replies; 4+ messages in thread
From: Ian Kent @ 2009-04-28 4:52 UTC (permalink / raw)
To: Thomas Connell; +Cc: autofs
On Sun, Apr 26, 2009 at 10:36:28AM -0600, Thomas Connell wrote:
>
> I gave it a shot; I am largely a complete C novice, but:
Right, and I find working with the Debian packaging system a bit of a
nightmare. That's why I was hoping you would do this for me.
>
> Following the debugging from the nfs module, the log shows:
> Apr 26 09:49:30 web6 automount[3920]: mount_mount: mount(bind):
> root=/domains/f/federalhousingtaxcredit.com name=/
> what=/www/vhosts/f/federalhousingtaxcredit.com, fstype=bind, options=
>
> Which all looks right to me.
Me too, but it isn't, as we now see from your effort.
>
> Since I could see in the logs that fullpath was garbled, I was wondering
> if maybe alloca wasn't getting the right length. I did a bit of trial
> and error, and it seems consistent that fullpaths of 33 or over become
> garbled.
>
> So, in mount_bind.c, I added:
>
> debug(ap->logopt, MODPREFIX "name_len=%d", name_len);
>
> right after
>
> int i, rlen;
>
> and
>
> debug(ap->logopt, MODPREFIX "name_len=%d rlen=%d", name_len, rlen);
>
> right after
>
> rlen = strlen(root);
>
>
> The logs show:
>
> Apr 26 10:05:46 web6 automount[7353]: mount_mount: mount(bind): name_len=0
> Apr 26 10:05:46 web6 automount[7353]: mount_mount: mount(bind): name_len=0 rlen=0
That is wrong.
It's due to improper use of name_len in modules/mount_nfs.c:mount_mount()
as, in 5.0.3, name_len is set to 0 prior to the call to perform the bind
mount.
The problem now is that this has been fixed in 5.0.4 as part of a much
larger patch.
The hunk in that patch, which should stand alone anyway, is:
diff --git a/modules/mount_nfs.c b/modules/mount_nfs.c
index d7f42a7..0b253d8 100644
--- a/modules/mount_nfs.c
+++ b/modules/mount_nfs.c
@@ -64,7 +64,7 @@ int mount_mount(struct autofs_point *ap, const char *root, const char *name, int
struct host *this, *hosts = NULL;
unsigned int vers;
char *nfsoptions = NULL;
- int len, rlen, status, err, existed = 1;
+ int len, status, err, existed = 1;
int nosymlink = 0;
int ro = 0; /* Set if mount bind should be read-only */
@@ -146,30 +146,18 @@ int mount_mount(struct autofs_point *ap, const char *root, const char *name, int
/* Construct and perhaps create mount point directory */
/* Root offset of multi-mount */
- if (*name == '/' && name_len == 1) {
- rlen = strlen(root);
- name_len = 0;
+ len = strlen(root);
+ if (root[len - 1] == '/') {
+ fullpath = alloca(len);
+ len = snprintf(fullpath, len, "%s", root);
/* Direct mount name is absolute path so don't use root */
- } else if (*name == '/')
- rlen = 0;
- else
- rlen = strlen(root);
-
- fullpath = alloca(rlen + name_len + 2);
- if (!fullpath) {
- char *estr = strerror_r(errno, buf, MAX_ERR_BUF);
- logerr(MODPREFIX "alloca: %s", estr);
- free_host_list(&hosts);
- return 1;
- }
-
- if (name_len) {
- if (rlen)
- len = sprintf(fullpath, "%s/%s", root, name);
- else
- len = sprintf(fullpath, "%s", name);
- } else
+ } else if (*name == '/') {
+ fullpath = alloca(len + 1);
len = sprintf(fullpath, "%s", root);
+ } else {
+ fullpath = alloca(len + name_len + 2);
+ len = sprintf(fullpath, "%s/%s", root, name);
+ }
fullpath[len] = '\0';
debug(ap->logopt, MODPREFIX "calling mkdir_path %s", fullpath);
^ permalink raw reply related [flat|nested] 4+ messages in thread
end of thread, other threads:[~2009-04-28 4:52 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2009-04-23 23:07 Mountpoint string corruption in autofs5.0.3-3? Thomas Connell
2009-04-26 3:47 ` Ian Kent
2009-04-26 16:36 ` Thomas Connell
2009-04-28 4:52 ` Ian Kent
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.