rbrito / usbmount

Simple set of scripts to automount removable devices for a Linux system
275 stars 86 forks source link

/proc/self/mounts has entry even after usb unmount #11

Closed krishnaclouds closed 6 years ago

krishnaclouds commented 6 years ago

Even after removing the usb, /proc/self/mounts is not being updated. It still holds the entries to the old mount points. After 8 successive usb insertions, new pen drive fails to mount.

mathieulj commented 6 years ago

Could you supply more information (ex. which distribution are you using, which version, what shows up in the logs) please? Otherwise it's pretty much a shot in the dark trying to figure out whats going wrong. Everything works on my Debian Stretch machines no mater how many times I cycle the connection. Logs that may help with debugging the issue are sudo dmesg -w, sudo journalctl -fu usbmount* and sudo tailf /var/log/messages.

krishnaclouds commented 6 years ago

sudo dmesg -w <---- After inserting pendrive---->

[ 555.778657] Indeed it is in host mode hprt0 = 00021501 [ 555.978577] usb 1-1: new high-speed USB device number 2 using dwc_otg [ 555.978786] Indeed it is in host mode hprt0 = 00001101 [ 556.209765] usb 1-1: New USB device found, idVendor=0781, idProduct=5567 [ 556.209783] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 [ 556.209791] usb 1-1: Product: Cruzer Blade [ 556.209815] usb 1-1: Manufacturer: SanDisk [ 556.209822] usb 1-1: SerialNumber: 4C531001511102119492 [ 556.214573] usb-storage 1-1:1.0: USB Mass Storage device detected [ 556.234009] scsi host0: usb-storage 1-1:1.0 [ 557.271555] scsi 0:0:0:0: Direct-Access SanDisk Cruzer Blade 1.00 PQ: 0 ANSI: 6 [ 557.278029] sd 0:0:0:0: [sda] 61341696 512-byte logical blocks: (31.4 GB/29.3 GiB) [ 557.287169] sd 0:0:0:0: [sda] Write Protect is off [ 557.287207] sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 [ 557.288341] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA [ 557.304817] sda: sda1 [ 557.311837] sd 0:0:0:0: [sda] Attached SCSI removable disk [ 557.374947] sd 0:0:0:0: Attached scsi generic sg0 type 0 [ 563.693560] FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.

<--- After removing pendrive---->

[ 571.080156] usb 1-1: USB disconnect, device number 2

**sudo journalctl -fu usbmount***

-- Logs begin at Thu 2016-11-03 22:46:44 IST. -- May 23 20:15:01 raspberrypi usbmount[6107]: acquired lock /var/run/usbmount/.mount.lock May 23 20:15:01 raspberrypi usbmount[6123]: dev/sdb1 contains filesystem type vfat May 23 20:15:01 raspberrypi usbmount[6127]: mountpoint /media/usb1 is available for dev/sdb1 May 23 20:15:01 raspberrypi usbmount[6128]: executing command: mount -tvfat -onoexec,nodev,noatime,nodiratime dev/sdb1 /media/usb1 May 23 20:15:02 raspberrypi usbmount[6136]: executing command: run-parts /etc/usbmount/mount.d May 23 20:15:02 raspberrypi sudo[6145]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo Device Mounted at /media/usb1 May 23 20:15:02 raspberrypi sudo[6145]: pam_unix(sudo:session): session opened for user root by (uid=0) May 23 20:15:02 raspberrypi sudo[6145]: pam_unix(sudo:session): session closed for user root May 23 20:15:02 raspberrypi usbmount[6154]: usbmount execution finished May 23 20:15:02 raspberrypi systemd[1]: Started usbmount@dev-sdb1.service.

May 23 20:16:06 raspberrypi systemd[1]: Stopped usbmount@dev-sdb1.service.

sudo tailf /var/log/messages

May 23 20:20:20 raspberrypi kernel: [ 1005.547789] Indeed it is in host mode hprt0 = 00021501 May 23 20:20:21 raspberrypi kernel: [ 1005.807660] usb 1-1: new high-speed USB device number 4 using dwc_otg May 23 20:20:21 raspberrypi kernel: [ 1005.807859] Indeed it is in host mode hprt0 = 00001101 May 23 20:20:21 raspberrypi kernel: [ 1006.058792] usb 1-1: New USB device found, idVendor=0781, idProduct=5567 May 23 20:20:21 raspberrypi kernel: [ 1006.058809] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 23 20:20:21 raspberrypi kernel: [ 1006.058817] usb 1-1: Product: Cruzer Blade May 23 20:20:21 raspberrypi kernel: [ 1006.058824] usb 1-1: Manufacturer: SanDisk May 23 20:20:21 raspberrypi kernel: [ 1006.058847] usb 1-1: SerialNumber: 4C531001511102119492 May 23 20:20:21 raspberrypi kernel: [ 1006.063417] usb-storage 1-1:1.0: USB Mass Storage device detected May 23 20:20:21 raspberrypi kernel: [ 1006.075933] scsi host2: usb-storage 1-1:1.0 May 23 20:20:21 raspberrypi mtp-probe: checking bus 1, device 4: "/sys/devices/platform/soc/20980000.usb/usb1/1-1" May 23 20:20:21 raspberrypi mtp-probe: bus: 1, device: 4 was not an MTP device May 23 20:20:22 raspberrypi kernel: [ 1007.133201] scsi 2:0:0:0: Direct-Access SanDisk Cruzer Blade 1.00 PQ: 0 ANSI: 6 May 23 20:20:22 raspberrypi kernel: [ 1007.141438] sd 2:0:0:0: Attached scsi generic sg0 type 0 May 23 20:20:22 raspberrypi kernel: [ 1007.142244] sd 2:0:0:0: [sdc] 61341696 512-byte logical blocks: (31.4 GB/29.3 GiB) May 23 20:20:22 raspberrypi kernel: [ 1007.143546] sd 2:0:0:0: [sdc] Write Protect is off May 23 20:20:22 raspberrypi kernel: [ 1007.144363] sd 2:0:0:0: [sdc] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA May 23 20:20:22 raspberrypi kernel: [ 1007.160730] sdc: sdc1 May 23 20:20:22 raspberrypi kernel: [ 1007.164160] sd 2:0:0:0: [sdc] Attached SCSI removable disk May 23 20:20:23 raspberrypi usbmount[8418]: dev/sdc does not contain a filesystem or disklabel

May 23 20:20:28 raspberrypi usbmount[8426]: executing command: mount -tvfat -onoexec,nodev,noatime,nodiratime dev/sdc1 /media/usb2 May 23 20:20:28 raspberrypi kernel: [ 1013.718591] FAT-fs (sdc1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. May 23 20:20:29 raspberrypi usbmount[8426]: executing command: run-parts /etc/usbmount/mount.d May 23 20:20:41 raspberrypi kernel: [ 1026.098478] usb 1-1: USB disconnect, device number 4 May 23 20:20:41 raspberrypi usbmount[8636]: executing command: umount -l /media/usb2 May 23 20:20:41 raspberrypi usbmount[8636]: 0

These are the logs!!

## System Details

OS PRETTY_NAME="Raspbian GNU/Linux 9 (stretch)" NAME="Raspbian GNU/Linux" VERSION_ID="9" VERSION="9 (stretch)" ID=raspbian ID_LIKE=debian

Hardware Linux raspberrypi 4.9.41+ #1023 Tue Aug 8 15:47:12 BST 2017 armv6l GNU/Linux

mathieulj commented 6 years ago

Seems like the umount -l /media/usb2 command is failing for some reason, whats the output if you manually run sudo umount -lv /media/usb2? Also, what does your sudo cat /proc/mounts look like before and after the USB is removed?

krishnaclouds commented 6 years ago

sudo cat /proc/mounts

Before Inserting usb

/dev/root / ext4 rw,noatime,data=ordered 0 0 devtmpfs /dev devtmpfs rw,relatime,size=217964k,nr_inodes=54491,mode=755 0 0 sysfs /sys sysfs rw,nosuid,nodev,noexec,relatime 0 0 proc /proc proc rw,relatime 0 0 tmpfs /dev/shm tmpfs rw,nosuid,nodev 0 0 devpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0 tmpfs /run tmpfs rw,nosuid,nodev,mode=755 0 0 tmpfs /run/lock tmpfs rw,nosuid,nodev,noexec,relatime,size=5120k 0 0 tmpfs /sys/fs/cgroup tmpfs ro,nosuid,nodev,noexec,mode=755 0 0 cgroup /sys/fs/cgroup/systemd cgroup rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd 0 0 cgroup /sys/fs/cgroup/memory cgroup rw,nosuid,nodev,noexec,relatime,memory 0 0 cgroup /sys/fs/cgroup/devices cgroup rw,nosuid,nodev,noexec,relatime,devices 0 0 cgroup /sys/fs/cgroup/net_cls cgroup rw,nosuid,nodev,noexec,relatime,net_cls 0 0 cgroup /sys/fs/cgroup/freezer cgroup rw,nosuid,nodev,noexec,relatime,freezer 0 0 cgroup /sys/fs/cgroup/blkio cgroup rw,nosuid,nodev,noexec,relatime,blkio 0 0 cgroup /sys/fs/cgroup/cpu,cpuacct cgroup rw,nosuid,nodev,noexec,relatime,cpu,cpuacct 0 0 systemd-1 /proc/sys/fs/binfmt_misc autofs rw,relatime,fd=26,pgrp=1,timeout=0,minproto=5,maxproto=5,direct 0 0 sunrpc /run/rpc_pipefs rpc_pipefs rw,relatime 0 0 mqueue /dev/mqueue mqueue rw,relatime 0 0 debugfs /sys/kernel/debug debugfs rw,relatime 0 0 configfs /sys/kernel/config configfs rw,relatime 0 0 tmpfs /Cubical/tmpfs tmpfs rw,nosuid,noatime,size=10240k,mode=777 0 0 tmpfs /Cubical/data/fstab/etmp tmpfs rw,nosuid,noatime,size=10240k,mode=777 0 0 /dev/mmcblk0p1 /boot vfat rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro 0 0 tmpfs /run/user/1000 tmpfs rw,nosuid,nodev,relatime,size=44452k,mode=700,uid=1000,gid=1000 0 0

After Removing usb

/dev/root / ext4 rw,noatime,data=ordered 0 0 devtmpfs /dev devtmpfs rw,relatime,size=217964k,nr_inodes=54491,mode=755 0 0 sysfs /sys sysfs rw,nosuid,nodev,noexec,relatime 0 0 proc /proc proc rw,relatime 0 0 tmpfs /dev/shm tmpfs rw,nosuid,nodev 0 0 devpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0 tmpfs /run tmpfs rw,nosuid,nodev,mode=755 0 0 tmpfs /run/lock tmpfs rw,nosuid,nodev,noexec,relatime,size=5120k 0 0 tmpfs /sys/fs/cgroup tmpfs ro,nosuid,nodev,noexec,mode=755 0 0 cgroup /sys/fs/cgroup/systemd cgroup rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd 0 0 cgroup /sys/fs/cgroup/memory cgroup rw,nosuid,nodev,noexec,relatime,memory 0 0 cgroup /sys/fs/cgroup/devices cgroup rw,nosuid,nodev,noexec,relatime,devices 0 0 cgroup /sys/fs/cgroup/net_cls cgroup rw,nosuid,nodev,noexec,relatime,net_cls 0 0 cgroup /sys/fs/cgroup/freezer cgroup rw,nosuid,nodev,noexec,relatime,freezer 0 0 cgroup /sys/fs/cgroup/blkio cgroup rw,nosuid,nodev,noexec,relatime,blkio 0 0 cgroup /sys/fs/cgroup/cpu,cpuacct cgroup rw,nosuid,nodev,noexec,relatime,cpu,cpuacct 0 0 systemd-1 /proc/sys/fs/binfmt_misc autofs rw,relatime,fd=26,pgrp=1,timeout=0,minproto=5,maxproto=5,direct 0 0 sunrpc /run/rpc_pipefs rpc_pipefs rw,relatime 0 0 mqueue /dev/mqueue mqueue rw,relatime 0 0 debugfs /sys/kernel/debug debugfs rw,relatime 0 0 configfs /sys/kernel/config configfs rw,relatime 0 0 tmpfs /Cubical/tmpfs tmpfs rw,nosuid,noatime,size=10240k,mode=777 0 0 tmpfs /Cubical/data/fstab/etmp tmpfs rw,nosuid,noatime,size=10240k,mode=777 0 0 /dev/mmcblk0p1 /boot vfat rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro 0 0 /dev/sda1 /media/usb0 vfat rw,nodev,noexec,noatime,nodiratime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro 0 0 tmpfs /run/user/1000 tmpfs rw,nosuid,nodev,relatime,size=44452k,mode=700,uid=1000,gid=1000 0 0

Doing this Manually umount -lv /media/usb0

umount: /media/usb0 (/dev/sda1) unmounted

And the entry in /proc/mounts is also being removed.

/dev/root / ext4 rw,noatime,data=ordered 0 0 devtmpfs /dev devtmpfs rw,relatime,size=217964k,nr_inodes=54491,mode=755 0 0 sysfs /sys sysfs rw,nosuid,nodev,noexec,relatime 0 0 proc /proc proc rw,relatime 0 0 tmpfs /dev/shm tmpfs rw,nosuid,nodev 0 0 devpts /dev/pts devpts rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000 0 0 tmpfs /run tmpfs rw,nosuid,nodev,mode=755 0 0 tmpfs /run/lock tmpfs rw,nosuid,nodev,noexec,relatime,size=5120k 0 0 tmpfs /sys/fs/cgroup tmpfs ro,nosuid,nodev,noexec,mode=755 0 0 cgroup /sys/fs/cgroup/systemd cgroup rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd 0 0 cgroup /sys/fs/cgroup/memory cgroup rw,nosuid,nodev,noexec,relatime,memory 0 0 cgroup /sys/fs/cgroup/devices cgroup rw,nosuid,nodev,noexec,relatime,devices 0 0 cgroup /sys/fs/cgroup/net_cls cgroup rw,nosuid,nodev,noexec,relatime,net_cls 0 0 cgroup /sys/fs/cgroup/freezer cgroup rw,nosuid,nodev,noexec,relatime,freezer 0 0 cgroup /sys/fs/cgroup/blkio cgroup rw,nosuid,nodev,noexec,relatime,blkio 0 0 cgroup /sys/fs/cgroup/cpu,cpuacct cgroup rw,nosuid,nodev,noexec,relatime,cpu,cpuacct 0 0 systemd-1 /proc/sys/fs/binfmt_misc autofs rw,relatime,fd=26,pgrp=1,timeout=0,minproto=5,maxproto=5,direct 0 0 sunrpc /run/rpc_pipefs rpc_pipefs rw,relatime 0 0 mqueue /dev/mqueue mqueue rw,relatime 0 0 debugfs /sys/kernel/debug debugfs rw,relatime 0 0 configfs /sys/kernel/config configfs rw,relatime 0 0 tmpfs /Cubical/tmpfs tmpfs rw,nosuid,noatime,size=10240k,mode=777 0 0 tmpfs /Cubical/data/fstab/etmp tmpfs rw,nosuid,noatime,size=10240k,mode=777 0 0 /dev/mmcblk0p1 /boot vfat rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro 0 0 tmpfs /run/user/1000 tmpfs rw,nosuid,nodev,relatime,size=44452k,mode=700,uid=1000,gid=1000 0 0

mathieulj commented 6 years ago

So umount seems to work manually but usbmount seems to terminate early. Maybe something to do with your systemd settings. Can you post the contents of your configuration? (cat /{etc,run,lib}/systemd/system.{conf,conf.d/*.conf}).

krishnaclouds commented 6 years ago

[Manager]

LogLevel=info

LogTarget=journal-or-kmsg

LogColor=yes

LogLocation=no

DumpCore=yes

ShowStatus=yes

CrashChangeVT=no

CrashShell=no

CrashReboot=no

CtrlAltDelBurstAction=reboot-force

CPUAffinity=1 2

JoinControllers=cpu,cpuacct net_cls,net_prio

RuntimeWatchdogSec=0

ShutdownWatchdogSec=10min

CapabilityBoundingSet=

SystemCallArchitectures=

TimerSlackNSec=

DefaultTimerAccuracySec=1min

DefaultStandardOutput=journal

DefaultStandardError=inherit

DefaultTimeoutStartSec=90s

DefaultTimeoutStopSec=90s

DefaultRestartSec=100ms

DefaultStartLimitIntervalSec=10s

DefaultStartLimitBurst=5

DefaultEnvironment=

DefaultCPUAccounting=no

DefaultIOAccounting=no

DefaultBlockIOAccounting=no

DefaultMemoryAccounting=no

DefaultTasksAccounting=yes

DefaultTasksMax=

DefaultLimitCPU=

DefaultLimitFSIZE=

DefaultLimitDATA=

DefaultLimitSTACK=

DefaultLimitCORE=

DefaultLimitRSS=

DefaultLimitNOFILE=

DefaultLimitAS=

DefaultLimitNPROC=

DefaultLimitMEMLOCK=

DefaultLimitLOCKS=

DefaultLimitSIGPENDING=

DefaultLimitMSGQUEUE=

DefaultLimitNICE=

DefaultLimitRTPRIO=

DefaultLimitRTTIME=

cat: '/etc/systemd/system.conf.d/.conf': No such file or directory cat: /run/systemd/system.conf: No such file or directory cat: '/run/systemd/system.conf.d/.conf': No such file or directory cat: /lib/systemd/system.conf: No such file or directory cat: '/lib/systemd/system.conf.d/*.conf': No such file or directory

krishnaclouds commented 6 years ago

@mathieulj Any Progress with the logs!!

mathieulj commented 6 years ago

I'm sorry but for the moment I'm a little stumped. I have not found a way to reproduce this issue and nothing in your configuration explains what we saw. The command works manually and the disconnect actually runs the command (we know so by the logs) yet it does not seem to be working when run by the disconnect. My only suspicion at the moment is that the log contained other entries between insertion and removal that may be pertinent. From the formatting it seems some entries were removed (I assume to keep them more brief and concise).

krishnaclouds commented 6 years ago

Actually no!! I haven't left any logs. Seems to be an issue only in Rasbian in my setup. Thanks for the help. Closing. Pingback, if you found anything. Just wrote a workaround to solve the bug.