From nobody Tue Sep 27 19:11:19 2022 X-Original-To: freebsd-usb@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id 4McTkP4Vy8z4cgwK for ; Tue, 27 Sep 2022 19:11:25 +0000 (UTC) (envelope-from frank@harz2022.behrens.de) Received: from post.behrens.de (post.behrens.de [IPv6:2a01:170:1023::1:2]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (4096 bits) client-digest SHA256) (Client CN "post.behrens.de", Issuer "R3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4McTkN0z0Gz45r4 for ; Tue, 27 Sep 2022 19:11:23 +0000 (UTC) (envelope-from frank@harz2022.behrens.de) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d= harz2022.behrens.de; h=message-id:date:mime-version:subject:to :references:from:in-reply-to:content-type :content-transfer-encoding; s=pinky2; bh=79wwcH3i+ueFdnj6aj/KAcV 8fuJY5iwo0yyrja9i4vY=; b=kJ6j3r59t1iKPdtMibdnWl6YkL6rgY0ti900WlY tXB3xIRAgtzv9ft8YUrs1xkRx9nVFKzHfWZeyLljrkP2KaDO269o7Bsf1PSL45ZZ D52jowzOgpuV5O689+aGuQQZkMPAtwndqIAIXoV7p7K3mi2BBilJEHpreVBwuINS 9jCY= Received: from [IPV6:fdfb:1999:428:bb80:28a1:f8b0:4279:f242] ([IPv6:fdfb:1999:428:bb80:28a1:f8b0:4279:f242]) (authenticated bits=0) by post.behrens.de (8.17.1/8.17.1) with ESMTPSA(MSP) id 28RJBJJQ055872 (version=TLSv1.3 cipher=TLS_AES_256_GCM_SHA384 bits=256 verify=NO cn=); Tue, 27 Sep 2022 21:11:19 +0200 (CEST) (envelope-from frank@harz2022.behrens.de) Message-ID: <6a883585-187e-d33d-b815-7bce374d1755@harz2022.behrens.de> Date: Tue, 27 Sep 2022 21:11:19 +0200 List-Id: FreeBSD List-Archive: https://lists.freebsd.org/archives/freebsd-usb List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-usb@freebsd.org X-BeenThere: freebsd-usb@freebsd.org MIME-Version: 1.0 User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:102.0) Gecko/20100101 Thunderbird/102.3.0 Subject: Re: USV control with repeated USB disconnects To: Hans Petter Selasky , "freebsd-usb@FreeBSD.org" References: <62bff2db-ac3e-934e-a7fe-438ef6969391@selasky.org> From: Frank Behrens Content-Language: en-GB In-Reply-To: <62bff2db-ac3e-934e-a7fe-438ef6969391@selasky.org> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit X-Rspamd-Queue-Id: 4McTkN0z0Gz45r4 X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=harz2022.behrens.de header.s=pinky2 header.b=kJ6j3r59; dmarc=none; spf=pass (mx1.freebsd.org: domain of frank@harz2022.behrens.de designates 2a01:170:1023::1:2 as permitted sender) smtp.mailfrom=frank@harz2022.behrens.de X-Spamd-Result: default: False [-3.49 / 15.00]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; NEURAL_HAM_SHORT(-1.00)[-0.999]; NEURAL_HAM_LONG(-0.99)[-0.991]; R_SPF_ALLOW(-0.20)[+mx]; R_DKIM_ALLOW(-0.20)[harz2022.behrens.de:s=pinky2]; MIME_GOOD(-0.10)[text/plain]; RCPT_COUNT_TWO(0.00)[2]; TO_DN_EQ_ADDR_SOME(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; MLMMJ_DEST(0.00)[freebsd-usb@FreeBSD.org]; ASN(0.00)[asn:8820, ipnet:2a01:170:1000::/36, country:DE]; MIME_TRACE(0.00)[0:+]; DKIM_TRACE(0.00)[harz2022.behrens.de:+]; ARC_NA(0.00)[]; RCVD_COUNT_TWO(0.00)[2]; MID_RHS_MATCH_FROM(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; TO_MATCH_ENVRCPT_SOME(0.00)[]; FROM_HAS_DN(0.00)[]; DMARC_NA(0.00)[behrens.de]; TO_DN_SOME(0.00)[]; RCVD_TLS_ALL(0.00)[] X-ThisMailContainsUnwantedMimeParts: N Hans Petter, thank you very much for your support! With your hints I could connect my USV. Am 27.09.2022 um 19:41 schrieb Hans Petter Selasky: > sysctl hw.usb.uhub.debug=15 > > This will show if the device initiates the disconnect or not. I could not read the disconnect reason from the log (if interested there is also a full usb dump in the debug log archive mentioned in my 1st email): Sep 27 19:53:08 moon kernel: ugen6.2: at usbus6 Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe008cefadb0 Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028cc000 addr=1 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0303, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe00841c4db0 Sep 27 19:53:09 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028ce000 addr=1 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe008cd64db0 Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe000ff5fdb0 Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe0083e9bdb0 Sep 27 19:53:09 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:09 moon syslogd: last message repeated 1 times Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028cb000 addr=1 Sep 27 19:53:09 moon kernel: usb_needs_explore: Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028d4000 addr=1 Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff80002912000 addr=1 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe0083d00db0 Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe008d090cd8 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:09 moon syslogd: last message repeated 1 times Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028c9000 addr=1 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028d3000 addr=1 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 3, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 4, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 5, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 6, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: usb_bus_powerd: bus=0xfffffe0084031cd8 Sep 27 19:53:09 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:09 moon kernel: uhub_explore: udev=0xfffff800028cd000 addr=1 Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 3, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 4, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 5, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:09 moon kernel: uhub_read_port_status: port 6, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe008cefadb0 Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028cc000 addr=1 Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0303, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe00841c4db0 Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028ce000 addr=1 Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe000ff5fdb0 Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe0083e9bdb0 Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe008cd64db0 Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe0083d00db0 Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028d4000 addr=1 Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: usb_needs_explore: Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028d3000 addr=1 Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff80002912000 addr=1 Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028cb000 addr=1 Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe0084031cd8 Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: usb_bus_powerd: bus=0xfffffe008d090cd8 Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028cd000 addr=1 Sep 27 19:53:13 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_explore: udev=0xfffff800028c9000 addr=1 Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 3, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 4, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 5, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 6, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 3, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 4, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 5, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:13 moon kernel: uhub_read_port_status: port 6, wPortStatus=0x0500, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:16 moon kernel: usb_needs_explore: Sep 27 19:53:16 moon kernel: usb_bus_powerd: bus=0xfffffe008cefadb0 Sep 27 19:53:16 moon kernel: usb_bus_powerd: Recomputing power masks Sep 27 19:53:16 moon kernel: uhub_explore: udev=0xfffff800028cc000 addr=1 Sep 27 19:53:16 moon kernel: uhub_read_port_status: port 1, wPortStatus=0x0100, wPortChange=0x0000, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:16 moon kernel: uhub_read_port_status: port 2, wPortStatus=0x0100, wPortChange=0x0003, err=USB_ERR_NORMAL_COMPLETION Sep 27 19:53:16 moon kernel: uhub_reattach_port: reattaching port 2 Sep 27 19:53:16 moon kernel: ugen6.2: at usbus6 (disconnected) > Please also read this thread: > "Flickering connection to UPS (again, but now I'm sure it is Ok under > Windows)" on this list. In this thread is the same behavior described. With these hints I could connect the NUT driver and the usb device did not disconnect further. To record the solution: 1. I don't know the reason of usb disconnect on OS level. 2. The nut/usbhid-ups driver does not use 'root' permissions, even when started as this user. It switches by default to 'uucp'. 3. With some permission changes I could connect the nut/usbhid-ups driver during the time the device was visible (devfs rules to enable access for 'uucp' to usb device). These articles brought me closer to the solution: https://forums.freebsd.org/threads/nut-port-configuration-no-such-file.35205/ https://thr3ads.net/nut-upsuser/2012/12/2163459-Blazer_usb-Permissions-problem-Input-output-error Thanks again for your fast und useful help! Best regards,    Frank -- Frank Behrens Osterwieck, Germany