From owner-freebsd-current@freebsd.org Tue May 24 18:00:55 2016 Return-Path: Delivered-To: freebsd-current@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 3638AB47C93 for ; Tue, 24 May 2016 18:00:55 +0000 (UTC) (envelope-from gljennjohn@gmail.com) Received: from mailman.ysv.freebsd.org (unknown [127.0.1.3]) by mx1.freebsd.org (Postfix) with ESMTP id 15FB01E8A for ; Tue, 24 May 2016 18:00:55 +0000 (UTC) (envelope-from gljennjohn@gmail.com) Received: by mailman.ysv.freebsd.org (Postfix) id 15594B47C92; Tue, 24 May 2016 18:00:55 +0000 (UTC) Delivered-To: current@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 14FF2B47C91 for ; Tue, 24 May 2016 18:00:55 +0000 (UTC) (envelope-from gljennjohn@gmail.com) Received: from mail-wm0-x22b.google.com (mail-wm0-x22b.google.com [IPv6:2a00:1450:400c:c09::22b]) (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 9EAC51E86; Tue, 24 May 2016 18:00:54 +0000 (UTC) (envelope-from gljennjohn@gmail.com) Received: by mail-wm0-x22b.google.com with SMTP id n129so143452213wmn.1; Tue, 24 May 2016 11:00:54 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=date:from:to:cc:subject:message-id:in-reply-to:references:reply-to :mime-version:content-transfer-encoding; bh=c7M9vThX7cZXOy2LO8dms6B0NpQvafpOLaND9aGPAWU=; b=muy36uvqZ+/5jEy1QKQ9y7JsR4RK4aHkqaYwzW4HzPVF3gzamdCyNGPHvhhn3R34Na RX9UH9ii50nwQjwO/9nxugvNJokzDDAm3qCpgyYrfkhHi+ufMoKoq7gBU/U29WkHLfyh P+vvpevJHi21o34ZcAzBMpaVcfp9STBM4c1WRv6cq1oRcHiWOqAIEfmL47xNQs2OdbS7 SdGW8mQr21C666Op/rFV4Z74MAhaeUcSYZZqyI/bp/v1SmOrZNelI6lwzJQxLDzry1yL rutkojZonYw9wwZhSJd/duzBOD3MB4fQ+AdGmVjwoFKJ/tnm3RZPqNu8/CXxoaFcgRUu 5WhQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:date:from:to:cc:subject:message-id:in-reply-to :references:reply-to:mime-version:content-transfer-encoding; bh=c7M9vThX7cZXOy2LO8dms6B0NpQvafpOLaND9aGPAWU=; b=W2x2K7kHtHEASChJER+J9L/kAKsaQP3ak75653tPn2rLCrYpEZzEJ48T7LuEMg725P bDZ1XggIOGgZ44IrlL29cPBvBYBxpDsFhqmL/WQMQG3U5n5A2N4cPN8C9hsAQeIDrGyx J7fh7eBJoxj/ZZxxXsPa3CzoA6abzYWtDriKX1ESxKcoH2AIvpnb/mXLI59JcnQEFRJX yEGlSMwTWJghqWkr1ASQ/96NXim1gjpp4Vu0GCzCcClCSkx3syiF8rM8YlWjDpSp6xyt 7QlaoiESE/RuRE/O97ARbyuo/GPvvpfr62J43GixfNifl4aUkyf72iRoHvNlDQFSj0aV 9h5w== X-Gm-Message-State: ALyK8tIDLcfK8S1L7szO/+V9FXp7Wqjh8Bk6OGCHkozEBdt+Qj/6grlxaP0zujI8aTWOoQ== X-Received: by 10.28.230.87 with SMTP id d84mr20715553wmh.50.1464112852889; Tue, 24 May 2016 11:00:52 -0700 (PDT) Received: from ernst.home (p4FC0F663.dip0.t-ipconnect.de. [79.192.246.99]) by smtp.gmail.com with ESMTPSA id q125sm4914431wmd.19.2016.05.24.11.00.51 (version=TLS1_2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Tue, 24 May 2016 11:00:52 -0700 (PDT) Date: Tue, 24 May 2016 20:00:51 +0200 From: Gary Jennejohn To: "Kenneth D. Merry" Cc: current@freebsd.org Subject: Re: AHCI/ADA regression? Message-ID: <20160524200051.42d0e6cb@ernst.home> In-Reply-To: <20160524144125.GA66261@mithlond.kdm.org> References: <20160521100949.6179a697@ernst.home> <20160523175105.GA50102@mithlond.kdm.org> <20160524155828.7119d8a1@ernst.home> <20160524144125.GA66261@mithlond.kdm.org> Reply-To: gljennjohn@gmail.com X-Mailer: Claws Mail 3.13.2 (GTK+ 2.24.29; amd64-portbld-freebsd11.0) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.22 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: Tue, 24 May 2016 18:00:55 -0000 On Tue, 24 May 2016 10:41:25 -0400 "Kenneth D. Merry" wrote: > > The question in my mind is - why are "empty" multiplier ports being > > probed with the new code but not with the old code? > > If the HBA says that it supports port multipliers, the kernel should always > look for them. It probes the port multiplier first, before moving on to > look for regular targets. > > So, from that standpoint, it should not be any different. It sounds like > we're either getting further in the port multiplier probe process, or there > is something different about the way things are behaving. > > If you can determine which commands are timing out, that may give us an > idea about where it is in the probe process. > > Here is one way we may be able to track things down... Build a kernel with > these options: > > options CAMDEBUG > options CAM_DEBUG_FLAGS=CAM_DEBUG_PROBE > > If you build a kernel before and after the change with those options, it > will hopefully allow us to compare the probe sequence and get a clue about > where to look for the problem. > OK, both the old and new kernel versions do an extremely fast intial probe with these results (note: obtained with grep over dmesg.boot): (aprobe0:ahcich0:0:15:0): Probe started (aprobe0:ahcich0:0:15:0): Probe PROBE_INVALID to PROBE_RESET (aprobe1:ahcich1:0:15:0): Probe started (aprobe1:ahcich1:0:15:0): Probe PROBE_INVALID to PROBE_RESET (aprobe2:ahcich2:0:15:0): Probe started (aprobe2:ahcich2:0:15:0): Probe PROBE_INVALID to PROBE_RESET (aprobe3:ahcich3:0:15:0): Probe started (aprobe3:ahcich3:0:15:0): Probe PROBE_INVALID to PROBE_RESET (aprobe4:ahcich4:0:15:0): Probe started (aprobe4:ahcich4:0:15:0): Probe PROBE_INVALID to PROBE_RESET (aprobe5:ahcich5:0:15:0): Probe started (aprobe5:ahcich5:0:15:0): Probe PROBE_INVALID to PROBE_RESET (aprobe4:ahcich4:0:15:0): Probe PROBE_RESET to PROBE_RESET (aprobe4:ahcich4:0:15:0): Probe PROBE_RESET to PROBE_INVALID (aprobe4:ahcich4:0:15:0): Probe completed (aprobe4:ahcich4:0:0:0): Probe started (aprobe4:ahcich4:0:0:0): Probe PROBE_INVALID to PROBE_RESET (aprobe4:ahcich4:0:0:0): Probe PROBE_RESET to PROBE_INVALID (aprobe4:ahcich4:0:0:0): Probe completed (aprobe0:ahcich0:0:15:0): Probe PROBE_RESET to PROBE_RESET (aprobe2:ahcich2:0:15:0): Probe PROBE_RESET to PROBE_RESET (aprobe0:ahcich0:0:15:0): SIGNATURE: 0000 (aprobe0:ahcich0:0:15:0): Probe PROBE_RESET to PROBE_INVALID (aprobe0:ahcich0:0:15:0): Probe completed (aprobe2:ahcich2:0:15:0): SIGNATURE: 0000 (aprobe2:ahcich2:0:15:0): Probe PROBE_RESET to PROBE_INVALID (aprobe2:ahcich2:0:15:0): Probe completed (aprobe0:ahcich0:0:0:0): Probe started (aprobe0:ahcich0:0:0:0): Probe PROBE_INVALID to PROBE_RESET (aprobe2:ahcich2:0:0:0): Probe started (aprobe2:ahcich2:0:0:0): Probe PROBE_INVALID to PROBE_RESET (aprobe3:ahcich3:0:15:0): Probe PROBE_RESET to PROBE_RESET (aprobe5:ahcich5:0:15:0): Probe PROBE_RESET to PROBE_RESET (aprobe0:ahcich0:0:0:0): SIGNATURE: 0000 (aprobe0:ahcich0:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY (aprobe2:ahcich2:0:0:0): SIGNATURE: 0000 (aprobe2:ahcich2:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY (aprobe1:ahcich1:0:15:0): Probe PROBE_RESET to PROBE_RESET (aprobe3:ahcich3:0:15:0): SIGNATURE: 0000 (aprobe3:ahcich3:0:15:0): Probe PROBE_RESET to PROBE_INVALID (aprobe3:ahcich3:0:15:0): Probe completed (aprobe5:ahcich5:0:15:0): SIGNATURE: 0000 (aprobe5:ahcich5:0:15:0): Probe PROBE_RESET to PROBE_INVALID (aprobe5:ahcich5:0:15:0): Probe completed (aprobe1:ahcich1:0:15:0): SIGNATURE: eb14 (aprobe1:ahcich1:0:15:0): Probe PROBE_RESET to PROBE_INVALID (aprobe1:ahcich1:0:15:0): Probe completed (aprobe1:ahcich3:0:0:0): Probe started (aprobe1:ahcich3:0:0:0): Probe PROBE_INVALID to PROBE_RESET (aprobe3:ahcich5:0:0:0): Probe started (aprobe3:ahcich5:0:0:0): Probe PROBE_INVALID to PROBE_RESET (aprobe4:ahcich1:0:0:0): Probe started (aprobe4:ahcich1:0:0:0): Probe PROBE_INVALID to PROBE_RESET (aprobe1:ahcich3:0:0:0): SIGNATURE: 0000 (aprobe1:ahcich3:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY (aprobe3:ahcich5:0:0:0): SIGNATURE: 0000 (aprobe3:ahcich5:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY (aprobe4:ahcich1:0:0:0): SIGNATURE: eb14 (aprobe4:ahcich1:0:0:0): Probe PROBE_RESET to PROBE_IDENTIFY (aprobe0:ahcich0:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE (aprobe1:ahcich3:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE (aprobe3:ahcich5:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE (aprobe0:ahcich0:0:0:0): Probe PROBE_SETMODE to PROBE_SET_MULTI (aprobe1:ahcich3:0:0:0): Probe PROBE_SETMODE to PROBE_SETDMAAA (aprobe3:ahcich5:0:0:0): Probe PROBE_SETMODE to PROBE_SETDMAAA (aprobe0:ahcich0:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE (aprobe0:ahcich0:0:0:0): Probe completed (aprobe1:ahcich3:0:0:0): Probe PROBE_SETDMAAA to PROBE_SET_MULTI (aprobe4:ahcich1:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE (aprobe3:ahcich5:0:0:0): Probe PROBE_SETDMAAA to PROBE_SET_MULTI (aprobe1:ahcich3:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE (aprobe1:ahcich3:0:0:0): Probe completed (aprobe3:ahcich5:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE (aprobe3:ahcich5:0:0:0): Probe completed (aprobe2:ahcich2:0:0:0): Probe PROBE_IDENTIFY to PROBE_SETMODE (aprobe4:ahcich1:0:0:0): Probe PROBE_SETMODE to PROBE_INQUIRY (aprobe2:ahcich2:0:0:0): Probe PROBE_SETMODE to PROBE_SETDMAAA (aprobe2:ahcich2:0:0:0): Probe PROBE_SETDMAAA to PROBE_SET_MULTI (aprobe2:ahcich2:0:0:0): Probe PROBE_SET_MULTI to PROBE_DONE (aprobe2:ahcich2:0:0:0): Probe completed (aprobe4:ahcich1:0:0:0): Probe PROBE_INQUIRY to PROBE_FULL_INQUIRY (aprobe4:ahcich1:0:0:0): Probe PROBE_FULL_INQUIRY to PROBE_DONE (aprobe4:ahcich1:0:0:0): Probe completed it looks like the code is basically checking to see how many ports are on a multiplier since it looks at port 0 and port 15. [I don't have a dmesg.boot for the "broken" kernel, but I saw the probe messages going shooting past and it was obviuos that they were the same] The old code stops there. The new code starts probing for what appear to be random ports on a multiplier, like 0, 7, 20, 17, etc. These always result in timeouts. These probes always start with "Probe PROBE_INVALID to PROBE_IDENTIFY" Why the new code doesn't accept the PROBE_INVALID and skip over it I don't understand. After I noticed that the same ports had been probed several times on achich2 with no apparent end in sight I rebooted. This behavior is extremely poor. -- Gary Jennejohn