From owner-freebsd-fs@freebsd.org Tue May 30 15:04:34 2017 Return-Path: Delivered-To: freebsd-fs@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 203AEB7EEB5 for ; Tue, 30 May 2017 15:04:34 +0000 (UTC) (envelope-from alex@nixd.org) Received: from mail.nixd.org (mail.nixd.org [95.211.160.151]) by mx1.freebsd.org (Postfix) with ESMTP id C3048656B6 for ; Tue, 30 May 2017 15:04:33 +0000 (UTC) (envelope-from alex@nixd.org) Received: from spamfilter (spamfilter.jail.localhost [192.168.1.4]) by mail.nixd.org (Postfix) with ESMTP id 28AAA2E8E for ; Tue, 30 May 2017 16:43:03 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=nixd.org; h= user-agent:message-id:organization:subject:subject:from:from :date:date:content-transfer-encoding:content-type:content-type :mime-version:received:received; s=default; t=1496155376; bh=pdf CwuRw2vmM/THh2kBFNQYVHdCRgeWkbeUuXqaLv1A=; b=fU6Mqkfg5nfY+X2NDhB RJKNRmtETyevoNv8mkCep/Af3Olo/s3ccnna9dfhGLjYvDxORjr+T2BTZEGEVPul 1P1/3jlF0eLSchuNoP9VCzUwg/x8yF/IERsDlH13dELvoO5fY2dLkC5TSn4oQ77H NDpKLRhLG5MI2QXASK7u1E4A= X-Virus-Scanned: amavisd-new at nixd.org Received: from mail.nixd.org ([192.168.1.2]) by spamfilter (nixd.org [192.168.1.4]) (amavisd-new, port 10024) with ESMTP id iBS3dTMSJ5nn for ; Tue, 30 May 2017 16:42:56 +0200 (CEST) Received: from nixd.org (webserver.jail.localhost [192.168.1.1]) by mail.nixd.org (Postfix) with ESMTPA id A70892E8D for ; Tue, 30 May 2017 16:42:56 +0200 (CEST) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII; format=flowed Content-Transfer-Encoding: 7bit Date: Tue, 30 May 2017 19:42:56 +0500 From: Alexander Morozov To: freebsd-fs@freebsd.org Subject: VFS vn_lock function makes system unresponsive when calling vn_fullpath Organization: NiXD Message-ID: <38666c423c33a5e1009c106c23aeb218@nixd.org> X-Sender: alex@nixd.org User-Agent: Roundcube Webmail/1.2.5 X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 30 May 2017 15:04:34 -0000 Hi, At the moment I am developing a kernel module based on MAC Framework which is invoking a vn_fullpath() from vfs_cache.c. Here is the thing: When the MAC Framework mpo_vnode_check_write procedure is called, the kernel module is trying to retrieve: the path on the disk for the curthread and the path of the file in which the curthread is attempting to write. At the point when the program execution reaches the vn_fullpath() for the resolution of the file's path, the terminal window 'freezes' (actually the whole system is not responding, the rest ttys stop responding after entering login credentials). For instance, after loading and initializing a MAC kernel module, I am opening a existing text file using vi to edit it. After inserting some random text I press ESC key on keyboard and terminal window 'freezes' (at that moment the mpo_vnode_check_write is called) ( the struct vnode * vp which is passed to the MAC procedure is valid (not NULL) and type (enum vtype) is VREG). I have investigated this issue and found out the following: The get_fullpath() is calling the get_fullpath1() where later the vn_vptocnp() is invoked. Retrieving the location for the curthread is successful (the full path returned). But when the kernel module is making attempt to retrieve the path for the vp (argument of the mpo_vnode_check_write) the function vn_lock(*vp, LK_SHARED | LK_RETRY) (line 2191) located in function vn_vptocnp() is grabbing control forever. Running the kernel in debug mode showed that (in the case with vi described above) the condition check if (ncp != NULL) (line 2167) fails, the ncp is NULL. In such case the program exec goes further, continuing from SDT_PROBE1(vfs, namecache, fullpath, miss, vp); (line 2188). When vn_lock (line 2191) is entered, it can't return from vn_lock for some reason. Referring to the DDB tracing, the code can't lock vp (vnode) and as a result loop this operation. It seems that LK_RETRY does not allow to return from function without locking vnode instance otherwise it would simply return error code. The trace: VOP_LOCK1__APV() _vn_lock() _vn_vptocnp_locked() (Sometimes the DDB stops breaking execution after requesting 's' single step and I can't investigate the problem any further, need to restart the VM. This time it stoped at VOP_LOCK_APV+0x11: testq %rdi, %rdi) I am trying to figure out why the system can't lock it. It seems that the file either does not exist, so there is nothing to lock or some exclusive lock was applied (I will check it later). Any ideas or comments on this problem are welcomed! The same problem when I am closing the the mc-light (midnight commander). The OS is running as the guest in the VrtualBox (single core, 1024MB RAM). uname -a FreeBSD 11.0-RELEASE-p10 FreeBSD 11.0-RELEASE-p10 #0 r318316M: Tue May 30 07:41:36 UTC 2017 root@:/usr/obj/usr/src/sys/MYKERN amd64 The kernel was rebuild with additional option (options DDB). Below I have copied and pasted the code which performers the path resolution and the MAC procedure handler: static int rw_retreive_data(struct thread * td, struct vnode *dvp, char ** rpath, char ** curpath, struct sandbox_rule_app ** rule_ptr) { ASSERT_NULL_R(dvp, -1); ASSERT_NULL_R(rpath, -1); ASSERT_NULL_R(curpath, -1); ASSERT_NULL_R(rule_ptr, -1); char * fpath = NULL; char * curfreepath = NULL; int error = 0; error = vn_fullpath(td, td->td_proc->p_textvp, curpath, &curfreepath); if (error != 0) { printf("sandbox: %s error! vn_fullback returned [%d]\r\n", __FUNCTION__, error); return -1; } uprintf("1: %s path: %s\r\n", __FUNCTION__, *curpath); uprintf("2: %s path: vtype %d v_iflag %u v_vflag %u\r\n", __FUNCTION__, dvp->v_type, dvp->v_iflag, dvp->v_vflag); error = vn_fullpath(td, dvp, rpath, &fpath); if (error != 0) { //handle errorno there before returning printf("sandbox: %s error! vn_fullback returned [%d]\r\n", __FUNCTION__, error); error = ENOENT; goto leave; } //uprintf("2: %s path: %s vtype %d v_iflag %u v_vflag %u\r\n", __FUNCTION__, *rpath, dvp->v_type, dvp->v_iflag, dvp->v_vflag); if (rules_lookup_app_rule_bypath(*curpath, rule_ptr) != 0) { //not found, return -1 because the exec path was found, but the operated file can not be found (cache purged???) printf("sandbox: %s Rule was not found in rule list for [%s].\r\n", __FUNCTION__, *curpath); error = -1; } leave: if (fpath != NULL) { KFREE((void*) fpath); } if (curfreepath != NULL) { KFREE((void*) curfreepath); } return error; } int sandbox_vnode_check_write(struct ucred *active_cred, struct ucred *file_cred, struct vnode *vp, struct label *vplabel) { IS_MODULE_INITED(0) ASSERT_NULL_R(vp, 0); struct sandbox_rule_app * rule_ptr = NULL; char * rpath = "-"; char * curpath = "-"; int error = 0; RWLOCK_BLOCK(&sandbox_rules_lock, RWLOCK_READ) { error = rw_retreive_data(curthread, vp, &rpath, &curpath, &rule_ptr); if (error == 0) { //printf("--> sandbox: debug, writing to %s\r\n", rpath); error = sandboxing_check_filewritedata(rule_ptr, rpath); } else { printf("debug_write %s %s\r\n", rpath, curpath); error = get_rule_notfound_policy(error); } } //RWLOCK_BLOCK return (error); } -- Kind Regards, Alexander Morozov