From owner-freebsd-current@freebsd.org Sun Feb 18 23:17:56 2018 Return-Path: Delivered-To: freebsd-current@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 88612F0F57D for ; Sun, 18 Feb 2018 23:17:56 +0000 (UTC) (envelope-from wlosh@bsdimp.com) Received: from mailman.ysv.freebsd.org (mailman.ysv.freebsd.org [IPv6:2001:1900:2254:206a::50:5]) by mx1.freebsd.org (Postfix) with ESMTP id 042277244E for ; Sun, 18 Feb 2018 23:17:56 +0000 (UTC) (envelope-from wlosh@bsdimp.com) Received: by mailman.ysv.freebsd.org (Postfix) id BC5E1F0F57B; Sun, 18 Feb 2018 23:17:55 +0000 (UTC) Delivered-To: current@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 78972F0F57A for ; Sun, 18 Feb 2018 23:17:55 +0000 (UTC) (envelope-from wlosh@bsdimp.com) Received: from mail-it0-x22d.google.com (mail-it0-x22d.google.com [IPv6:2607:f8b0:4001:c0b::22d]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 0B8A27244A for ; Sun, 18 Feb 2018 23:17:55 +0000 (UTC) (envelope-from wlosh@bsdimp.com) Received: by mail-it0-x22d.google.com with SMTP id p204so7274719itc.4 for ; Sun, 18 Feb 2018 15:17:55 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=bsdimp-com.20150623.gappssmtp.com; s=20150623; h=mime-version:sender:in-reply-to:references:from:date:message-id :subject:to:cc; bh=MHC0zu3y3HECoORRQ2v/XXu0HGilXOyUPpVp21cPDJc=; b=daLV6UXH6CJItN0WlW9Bsuz0mt9HNh5MQWenu5e/AzNBuKGz4y/OtRnjq8dj3mkKp8 /mGyG5LeQqdELnKzVidW6BeKF7PnONb+KmSp1sTh9ANIjwg/8pXZHjE69fw8oFYjaQ17 55z0ixX0QDNjF9QyeKEdunzbK6puLSkUG1ktlpKTDZOSO6Ugz1eR4+h95/GqAe93CIcw 6jFtSRnsl0/EblGy6KPV35fCh7sUylBcE6NXuAqYVQ2hrGBH1i8KhHTAr31f4ju9rwAS qAat9XPCiRXeMrf9wfS/SpTV+SIFlgc4RtRqAlTImRemgtmTisnwprOntPymjg/4IzNN Bf7A== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:sender:in-reply-to:references:from :date:message-id:subject:to:cc; bh=MHC0zu3y3HECoORRQ2v/XXu0HGilXOyUPpVp21cPDJc=; b=W8zenqBlimTH78GKWsbpHAGrbS2UWN2o/NlrgDu/Ebr9ZMoDG1cJKk+Ant5u2K5eay SGHllwqDHpKc+d5e/d0UTtaoUGXvrUnBqXzs4SZ9Du2uI97adpG7WgjZzZsqeErSYkhT MfKxrUp2czS6dlwPe35xJCB8i3P76u+0xtuyDoGq1L3aumOAsB4WGj3bsi/mZE9lMicp Pp1mVNeqS8ep6dS2DbzKvnsXSL8T32oFQJSFvkOfKWm8acRbqRHbnURltRJjU+hNFDZF q23oy+/cEOFiYnd4F8xQfnUTE3gUgVKKCQ687wC0VLwj+Me6lF1Ofyayo8H6X0qnH00A IC5Q== X-Gm-Message-State: APf1xPCPn0Blk3E+7XK2yJD4ht2Y3SpydZFqCeW+eQyPNo4YU86mo82J p/nR4w3oQpQ9AFTs2K8TRl5Pr2Ktt2DSN3yamSmSEyFv X-Google-Smtp-Source: AH8x225lInES2zjY/s+KDOoK9jlgHRTiAcnqBhrfiFcLmqhRgvGshquuz/g9bmCnK4ydbkLZzE+gMmmddBOR6XundLw= X-Received: by 10.36.111.4 with SMTP id x4mr9316165itb.51.1518995874079; Sun, 18 Feb 2018 15:17:54 -0800 (PST) MIME-Version: 1.0 Sender: wlosh@bsdimp.com Received: by 10.79.201.67 with HTTP; Sun, 18 Feb 2018 15:17:53 -0800 (PST) X-Originating-IP: [2603:300b:6:5100:18a2:a4f7:170:8dd9] In-Reply-To: <0a0f8471-87e4-0048-aebc-a84014a9faee@capeaugusta.com> References: <2c5d435c-54b1-fbd8-f695-de3dcc6259f1@capeaugusta.com> <0a0f8471-87e4-0048-aebc-a84014a9faee@capeaugusta.com> From: Warner Losh Date: Sun, 18 Feb 2018 16:17:53 -0700 X-Google-Sender-Auth: 1xKFT6zoxJx5r7qD2g8fY5oX1yo Message-ID: Subject: Re: r329501 devd doesn't find USB devices To: Ian FREISLICH Cc: FreeBSD Current , Warner Losh Content-Type: text/plain; charset="UTF-8" X-Content-Filtered-By: Mailman/MimeDel 2.1.25 X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 18 Feb 2018 23:17:56 -0000 On Sun, Feb 18, 2018 at 4:12 PM, Ian FREISLICH < ian.freislich@capeaugusta.com> wrote: > On 02/18/18 15:09, Warner Losh wrote: > > On Sat, Feb 17, 2018 at 9:14 PM, Ian FREISLICH < > ian.freislich@capeaugusta.com> wrote: > >> On 02/17/18 22:48, Warner Losh wrote: >> >> On Feb 17, 2018 8:24 PM, "Ian FREISLICH" >> wrote: >> >> Hi >> >> Since devmatch some of my USB devices no longer get their drivers >> loaded. It's not clear from UPDATING whether I needed to do anything >> beyond building and installing kernel and world as well as updating >> /etc. There was reference to removing /etc/devd/usb.conf in another >> thread but its presence or lack thereof makes no difference. >> >> >> I assume you've fully updated including /etc. >> >> >> In as much as 'mergemaster -Ui' fully updates /etc >> >> If you can uncomment the devd lines in syslog.conf, touch >> /var/log/devd.log and reboot. Once you are up again, please send me >> /var/log/devd.conf. >> >> >> Assuming you mean these lines: >> >> !devd >> *.>=notice /var/log/devd.log >> >> devd produced zero logs on reboot and restart. >> > > There should be a lot of output... one line per device that's attached... > Did you create /var/log/devd.log before reboot? Is your /dev/log persistent > across boots? > > > Lots of output after I changed the priority from 'notice' to 'debug' in > syslogd.conf. Might want to fix that in src/etc/syslogd.conf. > > 1. Startup: > > Feb 18 17:43:44 zen devd: Pushing table > Feb 18 17:43:44 zen devd: Parsing /etc/devd.conf > Feb 18 17:43:44 zen devd: Parsing files in /etc/devd > Feb 18 17:43:44 zen devd: Parsing /etc/devd/devmatch.conf > Feb 18 17:43:44 zen devd: Parsing /etc/devd/asus.conf > Feb 18 17:43:44 zen devd: Parsing /etc/devd/hyperv.conf > Feb 18 17:43:44 zen devd: Parsing /etc/devd/uath.conf > Feb 18 17:43:44 zen devd: Parsing /etc/devd/ulpt.conf > Feb 18 17:43:44 zen devd: Parsing /etc/devd/usb.conf > Feb 18 17:43:44 zen devd: Parsing /etc/devd/zfs.conf > Feb 18 17:43:44 zen devd: Parsing files in /usr/local/etc/devd > Feb 18 17:43:44 zen devd: Parsing /usr/local/etc/devd/cups.conf > Feb 18 17:43:44 zen devd: Parsing /usr/local/etc/devd/webcamd.conf > Feb 18 17:43:44 zen devd: Calling daemon > > > 2. Inserting the USB-C NIC: > > Feb 18 18:05:53 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.0' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=ugen0.6' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.1' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.2' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.3' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '!system=USB subsystem=DEVICE > type=ATTACH ugen=ugen0.6 cdev=ugen0.6 vendor=0x0bda product=0x8153 > devclass=0x00 devsubclass=0x00 sernum="000001" release=0x3000 mode=host > port=13 parent=ugen0.1' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '!system=USB > subsystem=INTERFACE type=ATTACH ugen=ugen0.6 cdev=ugen0.6 vendor=0x0bda > product=0x8153 devclass=0x00 devsubclass=0x00 sernum="000001" > release=0x3000 mode=host interface=0 endpoints=3 intclass=0xff > intsubclass=0xff intprotocol=0x00' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing notify event > Feb 18 18:05:53 zen devd: Executing '/usr/local/etc/rc.d/webcamd start > ugen0.6' > Feb 18 18:05:53 zen devd: Popping table > Feb 18 18:05:53 zen devd: Processing event '? at bus=0 hubaddr=1 port=13 > devaddr=6 interface=0 ugen=ugen0.6 vendor=0x0bda product=0x8153 > devclass=0x00 devsubclass=0x00 devproto=0x00 sernum="000001" release=0x3000 > mode=host intclass=0xff intsubclass=0xff intprotocol=0x00 on uhub0' > Feb 18 18:05:53 zen devd: Pushing table > Feb 18 18:05:53 zen devd: Processing nomatch event > Feb 18 18:05:53 zen devd: Executing '/etc/rc.d/devmatch start '? at bus=0 > hubaddr=1 port=13 devaddr=6 interface=0 ugen=ugen0.6 vendor=0x0bda > product=0x8153 devclass=0x00 devsubclass=0x00 devproto=0x00 sernum="000001" > release=0x3000 mode=host intclass=0xff intsubclass=0xff intprotocol=0x00 on > uhub0'' > Feb 18 18:05:53 zen devd: Popping table > > > 3. Insert USB-3 drive: > > Feb 18 18:09:38 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.0' > Feb 18 18:09:38 zen devd: Pushing table > Feb 18 18:09:38 zen devd: Processing notify event > Feb 18 18:09:38 zen devd: Popping table > Feb 18 18:09:38 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=ugen0.6' > Feb 18 18:09:38 zen devd: Pushing table > Feb 18 18:09:38 zen devd: Processing notify event > Feb 18 18:09:38 zen devd: Popping table > Feb 18 18:09:38 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.1' > Feb 18 18:09:38 zen devd: Pushing table > Feb 18 18:09:38 zen devd: Processing notify event > Feb 18 18:09:38 zen devd: Popping table > Feb 18 18:09:38 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.2' > Feb 18 18:09:38 zen devd: Pushing table > Feb 18 18:09:38 zen devd: Processing notify event > Feb 18 18:09:38 zen devd: Popping table > Feb 18 18:09:38 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.3' > Feb 18 18:09:38 zen devd: Pushing table > Feb 18 18:09:38 zen devd: Processing notify event > Feb 18 18:09:38 zen devd: Popping table > Feb 18 18:09:38 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.6.4' > Feb 18 18:09:38 zen devd: Pushing table > Feb 18 18:09:38 zen devd: Processing notify event > Feb 18 18:09:38 zen devd: Popping table > Feb 18 18:09:40 zen devd: Processing event '!system=USB subsystem=DEVICE > type=ATTACH ugen=ugen0.6 cdev=ugen0.6 vendor=0x0bc2 product=0xab24 > devclass=0x00 devsubclass=0x00 sernum="NA7W30KM" release=0x0100 mode=host > port=13 parent=ugen0.1' > Feb 18 18:09:40 zen devd: Pushing table > Feb 18 18:09:40 zen devd: Processing notify event > Feb 18 18:09:40 zen devd: Popping table > Feb 18 18:09:40 zen devd: Processing event '!system=USB > subsystem=INTERFACE type=ATTACH ugen=ugen0.6 cdev=ugen0.6 vendor=0x0bc2 > product=0xab24 devclass=0x00 devsubclass=0x00 sernum="NA7W30KM" > release=0x0100 mode=host interface=0 endpoints=2 intclass=0x08 > intsubclass=0x06 intprotocol=0x50' > Feb 18 18:09:40 zen devd: Pushing table > Feb 18 18:09:40 zen devd: Processing notify event > Feb 18 18:09:40 zen devd: Popping table > Feb 18 18:09:40 zen devd: Processing event '? at bus=0 hubaddr=1 port=13 > devaddr=6 interface=0 ugen=ugen0.6 vendor=0x0bc2 product=0xab24 > devclass=0x00 devsubclass=0x00 devproto=0x00 sernum="NA7W30KM" > release=0x0100 mode=host intclass=0x08 intsubclass=0x06 intprotocol=0x50 on > uhub0' > Feb 18 18:09:40 zen devd: Pushing table > Feb 18 18:09:40 zen devd: Processing nomatch event > Feb 18 18:09:40 zen devd: Executing '/etc/rc.d/devmatch start '? at bus=0 > hubaddr=1 port=13 devaddr=6 interface=0 ugen=ugen0.6 vendor=0x0bc2 > product=0xab24 devclass=0x00 devsubclass=0x00 devproto=0x00 > sernum="NA7W30KM" release=0x0100 mode=host intclass=0x08 intsubclass=0x06 > intprotocol=0x50 on uhub0'' > Feb 18 18:09:40 zen devd: Popping table > > > 4. Inserting the keyboard/mouse: > > Feb 18 18:11:04 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.5.0' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=ugen0.5' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.5.1' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '!system=DEVFS subsystem=CDEV > type=CREATE cdev=usb/0.5.2' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '!system=USB subsystem=DEVICE > type=ATTACH ugen=ugen0.5 cdev=ugen0.5 vendor=0x24ae product=0x2000 > devclass=0x00 devsubclass=0x00 sernum="" release=0x1001 mode=host port=2 > parent=ugen0.1' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '!system=USB > subsystem=INTERFACE type=ATTACH ugen=ugen0.5 cdev=ugen0.5 vendor=0x24ae > product=0x2000 devclass=0x00 devsubclass=0x00 sernum="" release=0x1001 > mode=host interface=0 endpoints=1 intclass=0x03 intsubclass=0x01 > intprotocol=0x01' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '!system=USB > subsystem=INTERFACE type=ATTACH ugen=ugen0.5 cdev=ugen0.5 vendor=0x24ae > product=0x2000 devclass=0x00 devsubclass=0x00 sernum="" release=0x1001 > mode=host interface=1 endpoints=1 intclass=0x03 intsubclass=0x01 > intprotocol=0x02' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing notify event > Feb 18 18:11:04 zen devd: Popping table > Feb 18 18:11:04 zen devd: Processing event '? at bus=0 hubaddr=1 port=2 > devaddr=5 interface=0 ugen=ugen0.5 vendor=0x24ae product=0x2000 > devclass=0x00 devsubclass=0x00 devproto=0x00 sernum="" release=0x1001 > mode=host intclass=0x03 intsubclass=0x01 intprotocol=0x01 on uhub0' > Feb 18 18:11:04 zen devd: Pushing table > Feb 18 18:11:04 zen devd: Processing nomatch event > Feb 18 18:11:04 zen devd: Executing '/etc/rc.d/devmatch start '? at bus=0 > hubaddr=1 port=2 devaddr=5 interface=0 ugen=ugen0.5 vendor=0x24ae > product=0x2000 devclass=0x00 devsubclass=0x00 devproto=0x00 sernum="" > release=0x1001 mode=host intclass=0x03 intsubclass=0x01 intprotocol=0x01 on > uhub0'' > Feb 18 18:11:04 zen devd: Popping table > > That's better... I think you might be hitting the same bug I've been hitting on my system... It looks like we're calling devmatch, but it isn't seeing the modules to load. There's still a mismatch between things in the USB code (likely my fault, I thought I'd fixed them all: either I missed one or broke something). Try running with r329538 (it's just a new devmatch, so all you need to do is install just it). Warner