Closing unused descriptors

[Dan Williams]

On Thu, 2015-09-24 at 13:43 +0200, Jean-Christian de Rivaz wrote:
> Hi Aleksander,
> 
> Le 24. 09. 15 13:10, Aleksander Morgado a écrit :
> > On Thu, Sep 24, 2015 at 9:49 AM, Jean-Christian de Rivaz <jc at eclis.ch> wrote:
> >> While trying to reproduce a bug by power cycling a USB modem 4 time per
> >> hour, I faced this message from the kernel:
> >>
> >> cdc_acm 1-2:1.0: no more free acm devices
> >>
> >> I found the the problem is caused by ModemManager that still have file
> >> descriptors open on old ports that was deleted, preventing the kernel to
> >> recycle the port numbers:
> >>
> >> ls -al /proc/$(pgrep ModemManager)/fd
> >> total 0
> >> dr-x------ 2 root root  0 Sep 24 01:44 .
> >> dr-xr-xr-x 7 root root  0 Sep 24 01:44 ..
> >> lr-x------ 1 root root 64 Sep 24 01:44 0 -> /dev/null
> >> lrwx------ 1 root root 64 Sep 24 01:44 1 -> socket:[218296]
> >> lrwx------ 1 root root 64 Sep 24 01:44 10 -> /dev/ttyACM4 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 11 -> /dev/ttyACM5 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 12 -> /dev/ttyACM6 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 13 -> /dev/ttyACM7 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 14 -> /dev/ttyACM8 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 15 -> /dev/ttyACM11 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 16 -> /dev/ttyACM10 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 17 -> /dev/ttyACM12 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 18 -> /dev/ttyACM13 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 19 -> /dev/ttyACM14 (deleted)
> >> l-wx------ 1 root root 64 Sep 24 01:44 2 -> /dev/null
> >> lrwx------ 1 root root 64 Sep 24 01:44 20 -> /dev/ttyACM15 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 21 -> /dev/ttyACM16 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 22 -> /dev/ttyACM17 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 23 -> /dev/ttyACM18 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 24 -> /dev/ttyACM19 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 25 -> /dev/ttyACM20 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 26 -> /dev/ttyACM21 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 27 -> /dev/ttyACM23 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 28 -> /dev/ttyACM9 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 29 -> /dev/ttyACM24 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 3 -> anon_inode:[eventfd]
> >> lrwx------ 1 root root 64 Sep 24 01:44 30 -> /dev/ttyACM25 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 31 -> /dev/ttyACM26 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 32 -> /dev/ttyACM27 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 33 -> /dev/ttyACM28 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 04:35 34 -> /dev/ttyACM22 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 04:36 37 -> /dev/ttyACM30 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 04:49 38 -> /dev/ttyACM31 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 04:36 39 -> /dev/ttyACM29 (deleted)
> >> lrwx------ 1 root root 64 Sep 24 01:44 4 -> anon_inode:[eventfd]
> >> lrwx------ 1 root root 64 Sep 24 01:44 5 -> socket:[218298]
> >> lrwx------ 1 root root 64 Sep 24 01:44 6 -> socket:[218304]
> >> lrwx------ 1 root root 64 Sep 24 01:44 7 -> anon_inode:[eventfd]
> >> lrwx------ 1 root root 64 Sep 24 01:44 8 -> socket:[218306]
> >> lrwx------ 1 root root 64 Sep 24 01:44 9 -> /dev/ttyACM3 (deleted)
> >>
> >> To me it look like a ModemManager bug: it must close descriptors that it no
> >> longer use at all.
> >>
> >> This was tester with MM 1.4.0 from Debian Jessie with the generic driver.
> > Any chance you can retest with latest git master or latest 1.4.x?
> 
> I will try to compile it. This will take a long time on a ~0.5GHz 
> Cortex-A5 ...
> 
> > When you power cycle the modem 4 times per hour, do you just cut the
> > power to the modem externally?
> >
> 
> Yes, for 10 minutes before power it up again. The lsusb and dmesg 
> clearly show that all the CDC of the modem disconnected at the power 
> off. Probably the udev noticed the event too, I have not verified.

The kernel won't kill an open device node if MM is using it, so MM has
to be notified by either a TTY hangup, or by udev that the device has
disappeared.  So I'd be very curious what the udev event stream is when
you remove the device.

Dan