From mboxrd@z Thu Jan 1 00:00:00 1970 From: =?ISO-8859-1?Q?Roger_Pau_Monn=E9?= Subject: PV timer issues in FreeBSD Date: Fri, 19 Apr 2013 20:20:37 +0200 Message-ID: <51718AF5.1040001@citrix.com> Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="------------060305040302000801030006" Return-path: List-Unsubscribe: , List-Post: List-Help: List-Subscribe: , Sender: xen-devel-bounces@lists.xen.org Errors-To: xen-devel-bounces@lists.xen.org To: xen-devel Cc: "Justin T. Gibbs" , "will@FreeBSD.org" List-Id: xen-devel@lists.xenproject.org --------------060305040302000801030006 Content-Type: text/plain; charset="ISO-8859-1" Content-Transfer-Encoding: 7bit Hello, While trying to get PV timers on FreeBSD to work, we found that when the system is under stress sometimes FreeBSD would stop receiving timer interrupts on certain vCPUs. I've added some trace points to Xen in order to see what was happening with this timers and got the following trace. I'm also attaching the crappy changes I've did to Xen in order to add the trace points, maybe I didn't put the trace points in the right position and that's why I'm seeing this: 169.097952305 |..x.... d32768v3 d32768 fire timer vCPU3: 1204944804808 169.097966813 |..x.... d32768v3 d32768 set timer vCPU3: 1204946614221 169.097977454 |..x.... d32768v3 d32768 set timer vCPU3: 1204963746273 169.103410517 |..x.... d32768v3 d32768 set timer vCPU3: 1204952682637 169.103429902 |..x.... d32768v3 d32768 set timer vCPU3: 1205000356797 169.124982369 |..x.... d32768v3 d32768 set timer vCPU3: 1204976302984 169.124988972 |..x.... d32768v3 d32768 set timer vCPU3: 1205000356855 169.128470252 |..x.... d32768v3 d32768 set timer vCPU3: 1204976300693 169.128639545 |..x.... d32768v3 d32768 set timer vCPU3: 1205000356796 169.136240633 |..x.... d32768v3 d32768 set timer vCPU3: 1204984176928 169.136246955 |..x.... d32768v3 d32768 set timer vCPU3: 1205000357030 169.139729248 |..x.... d32768v3 d32768 set timer vCPU3: 1204992115770 169.139892831 |..x.... d32768v3 d32768 set timer vCPU3: 1205032863201 169.151133497 |..x.... d32768v3 d32768 set timer vCPU3: 1204999923870 169.151137341 |..x.... d32768v3 d32768 set timer vCPU3: 1205032863121 169.352765068 |..x.... d32768v3 d32768 set timer vCPU3: 1205204647080 169.352769008 |..x.... d32768v3 d32768 set timer vCPU3: 1205633794418 176.818699597 |..x.... d32768v3 d32768 set timer vCPU3: 1212676613211 176.818702670 |..x.... d32768v3 d32768 set timer vCPU3: 1213055669298 318.489693649 |..x.... d32768v3 d32768 set timer vCPU3: 1354464489030 < 318.489698326 |..x.... d32768v3 d32768 set timer vCPU3: 1354766606923 318.491853105 |..x.... d32768v3 d32768 set timer vCPU3: 1354464489183 318.491857363 |..x.... d32768v3 d32768 set timer vCPU3: 1354766606862 318.494243541 |..x.... d32768v3 d32768 set timer vCPU3: 1354466611397 318.494253173 |..x.... d32768v3 d32768 set timer vCPU3: 1354766607167 318.497005208 |..x.... d32768v3 d32768 set timer vCPU3: 1354472363654 318.497009517 |..x.... d32768v3 d32768 set timer vCPU3: 1354766606858 As it can be seen above, the vCPU was expecting a timer to fire at 1213055669298, but as far as I can tell the timer never reached the guest, neither Xen called execute_timer to fire the timer. Then in order to reset the timer I've started some other task that probably sends an IPI to the stuck processor and it tries to set the timer again (this time successfully). Is there any reason that could prevent the timer from being fired? Thanks, Roger. --------------060305040302000801030006 Content-Type: text/plain; charset="UTF-8"; x-mac-type=0; x-mac-creator=0; name="trace_timer.patch" Content-Transfer-Encoding: 7bit Content-Disposition: attachment; filename="trace_timer.patch" diff --git a/xen/common/domain.c b/xen/common/domain.c index 64ee29d..ac59452 100644 --- a/xen/common/domain.c +++ b/xen/common/domain.c @@ -937,18 +937,27 @@ long do_vcpu_op(int cmd, int vcpuid, XEN_GUEST_HANDLE_PARAM(void) arg) { struct vcpu_set_singleshot_timer set; - if ( v != current ) + if ( v != current ) { + TRACE_1D(TRC_PV_TIMER_FAIL, 1); return -EINVAL; + } - if ( copy_from_guest(&set, arg, 1) ) + if ( copy_from_guest(&set, arg, 1) ) { + TRACE_1D(TRC_PV_TIMER_FAIL, 2); return -EFAULT; + } if ( (set.flags & VCPU_SSHOTTMR_future) && - (set.timeout_abs_ns < NOW()) ) + (set.timeout_abs_ns < NOW()) ) { + TRACE_1D(TRC_PV_TIMER_FAIL, 3); return -ETIME; + } migrate_timer(&v->singleshot_timer, smp_processor_id()); + v->singleshot_timer.debug = 1; set_timer(&v->singleshot_timer, set.timeout_abs_ns); + TRACE_2D(TRC_PV_SET_TIMER, (uint32_t)set.timeout_abs_ns, + (uint32_t)(set.timeout_abs_ns >> 32)); break; } @@ -958,6 +967,8 @@ long do_vcpu_op(int cmd, int vcpuid, XEN_GUEST_HANDLE_PARAM(void) arg) return -EINVAL; stop_timer(&v->singleshot_timer); + TRACE_2D(TRC_PV_STOP_TIMER, (uint32_t)v->singleshot_timer.expires, + (uint32_t)(v->singleshot_timer.expires >> 32)); break; diff --git a/xen/common/timer.c b/xen/common/timer.c index 9ed74e9..61e4383 100644 --- a/xen/common/timer.c +++ b/xen/common/timer.c @@ -21,6 +21,7 @@ #include #include #include +#include #include #include #include @@ -421,6 +422,9 @@ static void execute_timer(struct timers *ts, struct timer *t) list_add(&t->inactive, &ts->inactive); ts->running = t; + if (t->debug) + TRACE_2D(TRC_PV_FIRE_TIMER, (uint32_t)t->expires, + (uint32_t)(t->expires >> 32)); spin_unlock_irq(&ts->lock); (*fn)(data); spin_lock_irq(&ts->lock); diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h index e2f60a6..4571d74 100644 --- a/xen/include/public/trace.h +++ b/xen/include/public/trace.h @@ -122,6 +122,7 @@ #define TRC_PV_ENTRY 0x00201000 /* Hypervisor entry points for PV guests. */ #define TRC_PV_SUBCALL 0x00202000 /* Sub-call in a multicall hypercall */ +#define TRC_PV_TIMER 0x00208000 /* PV timer */ #define TRC_PV_HYPERCALL (TRC_PV_ENTRY + 1) #define TRC_PV_TRAP (TRC_PV_ENTRY + 3) @@ -136,6 +137,10 @@ #define TRC_PV_PTWR_EMULATION_PAE (TRC_PV_ENTRY + 12) #define TRC_PV_HYPERCALL_V2 (TRC_PV_ENTRY + 13) #define TRC_PV_HYPERCALL_SUBCALL (TRC_PV_SUBCALL + 14) +#define TRC_PV_SET_TIMER (TRC_PV_TIMER + 15) +#define TRC_PV_FIRE_TIMER (TRC_PV_TIMER + 16) +#define TRC_PV_TIMER_FAIL (TRC_PV_TIMER + 17) +#define TRC_PV_STOP_TIMER (TRC_PV_TIMER + 18) /* * TRC_PV_HYPERCALL_V2 format diff --git a/xen/include/xen/timer.h b/xen/include/xen/timer.h index 9531800..b69ae20 100644 --- a/xen/include/xen/timer.h +++ b/xen/include/xen/timer.h @@ -43,6 +43,7 @@ struct timer { #define TIMER_STATUS_in_heap 3 /* In use; on timer heap. */ #define TIMER_STATUS_in_list 4 /* In use; on overflow linked list. */ uint8_t status; + uint8_t debug; }; /* --------------060305040302000801030006 Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Content-Disposition: inline _______________________________________________ Xen-devel mailing list Xen-devel@lists.xen.org http://lists.xen.org/xen-devel --------------060305040302000801030006--