From mboxrd@z Thu Jan  1 00:00:00 1970
From: Ian Campbell <Ian.Campbell@citrix.com>
Subject: Re: Tracking down a boot speed issue
Date: Fri, 26 Oct 2012 19:38:38 +0100
Message-ID: <1351276718.12176.1.camel@dagon.hellion.org.uk>
References: <844D15D284C78547BB0DAEE12D33A1B67C212BB956@FTLPMAILBOX02.citrite.net>
	<844D15D284C78547BB0DAEE12D33A1B67C212BB958@FTLPMAILBOX02.citrite.net>
Mime-Version: 1.0
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: 7bit
Return-path: <xen-devel-bounces@lists.xen.org>
In-Reply-To: <844D15D284C78547BB0DAEE12D33A1B67C212BB958@FTLPMAILBOX02.citrite.net>
List-Unsubscribe: <http://lists.xen.org/cgi-bin/mailman/options/xen-devel>,
	<mailto:xen-devel-request@lists.xen.org?subject=unsubscribe>
List-Post: <mailto:xen-devel@lists.xen.org>
List-Help: <mailto:xen-devel-request@lists.xen.org?subject=help>
List-Subscribe: <http://lists.xen.org/cgi-bin/mailman/listinfo/xen-devel>,
	<mailto:xen-devel-request@lists.xen.org?subject=subscribe>
Sender: xen-devel-bounces@lists.xen.org
Errors-To: xen-devel-bounces@lists.xen.org
To: Roger Cruz <roger.cruz@citrix.com>
Cc: "xen-devel@lists.xen.org" <xen-devel@lists.xen.org>
List-Id: xen-devel@lists.xenproject.org

On Fri, 2012-10-26 at 18:30 +0100, Roger Cruz wrote:
> As you see from the timed samples below, the access can take anywhere
> from .6 to 1.2 secs (though I have seen it take 1.6 secs every single
> time with  Linux 3.2.16 and Xen 4.0.3).

Isn't this just because setting up the per-cpu shared info makes the
time available to printk. Note that the timestamp is zero beforehand
(a big hint that time isn't setup yet). Also see xen_clocksource_read().

IOW I think what is being measured here is the time from start of day
until the second printk, not the time between the two prints.

[...]
>             printk(KERN_ALERT "in cpu loop %d for shared info", cpu);
> ===>    per_cpu(xen_vcpu,cpu) = &HYPERVISOR_shared_info->vcpu_info[cpu];
>             printk(KERN_ALERT "in cpu loop %d computed shared info", cpu);
> 
> Oct 25 20:24:11 23445LU-PBBFMWY kernel: [    0.000000] in cpu loop 0 for shared info
> Oct 25 20:24:11 23445LU-PBBFMWY kernel: [    1.238877] in cpu loop 0 computed shared info
> 
> Oct 25 20:52:53 23445LU-PBBFMWY kernel: [    0.000000] in cpu loop 0 for shared info
> Oct 25 20:52:53 23445LU-PBBFMWY kernel: [    0.718365] in cpu loop 0 computed shared info
> 
> Oct 25 20:41:27 23445LU-PBBFMWY kernel: [    0.000000] in cpu loop 0 for shared info
> Oct 25 20:41:27 23445LU-PBBFMWY kernel: [    0.671690] in cpu loop 0 computed shared info
> 
> 
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xen.org
> http://lists.xen.org/xen-devel