Re: [Xen-devel] Bug: Windows 2003 fails to install on xen-unstable tip

[George Dunlap <george.dunlap@xxxxxxxxxxxxx>]

On 22/04/13 12:05, Jan Beulich wrote:
> > > > On 19.04.13 at 15:51, George Dunlap <george.dunlap@xxxxxxxxxxxxx> wrote:
> > (XEN) HVM1: Booting from DVD/CD...
> > (XEN) HVM1: Booting from 0000:7c00
> > (XEN) HVM1: pnp call arg1=0
> > [   75.071460] xenbr0: port 3(vif1.0-emu) entering forwarding state
> > (XEN) pt on: 10
> > (XEN) B=42 [A:2a B:02 C:50 pt:10/0]
> > (XEN) C=50 pt=10/0
> > (XEN) C=c0 pt=10/0
> > (XEN) C=00 pt=10/0
> > (XEN) C=c0 pt=10/0
> > (XEN) C=00 pt=10/0
> > (XEN) pt off @87
> Odd - both the fact that apparently two to four interrupt instances
> arrive, and the fact that REG_C gets read two times when
> supposedly there was no interrupt. The latter may be indicative of
> a re-read near the end of the interrupt handler (i.e. checking
> whether more work is to do), which is why I added time stamps in
> the new version of the patch.
>
> The time stamps should also help understanding whether turning
> off the periodic timer really happens with due distance to the last
> interrupt instance (also increasing the gap from 10 to 250). Plus
> the patch now adds tracking of when the last RTC interrupt got
> triggered.
>
> I also retained the NetBSD fixes in here, as I don't think they
> would harm Windows, and ultimately we want them committed
> unless we need to do some sort of revert.
>
> Jan
>
> --- a/xen/arch/x86/hvm/rtc.c
> +++ b/xen/arch/x86/hvm/rtc.c
> @@ -50,6 +50,23 @@ static void rtc_set_time(RTCState *s);
>   static inline int from_bcd(RTCState *s, int a);
>   static inline int convert_hour(RTCState *s, int hour);
>   
> +#include <xen/symbols.h>//temp
> +#define LOGIDX_MASK 0xf//temp
> +static struct {//temp
> + s_time_t time;
> + void*caller;
> +} log[LOGIDX_MASK + 1];
> +static unsigned logidx;//temp
> +static void pt_off(int line) {//temp
> + unsigned i, idx = logidx;
> + printk("pt off #%d @%"PRIx64"\n", line, NOW());
> + for(i = idx; i <= idx + LOGIDX_MASK; ++i) {
> +  if(!log[i & LOGIDX_MASK].caller) continue;
> +  printk("pt irq @%"PRIx64, log[i & LOGIDX_MASK].time);
> +  print_symbol(" (%s)\n", (unsigned long)log[i & LOGIDX_MASK].caller);
> + }
> +}
> +
>   static void rtc_update_irq(RTCState *s)
>   {
>       struct domain *d = vrtc_domain(s);
> @@ -68,6 +85,7 @@ static void rtc_update_irq(RTCState *s)
>   
>       hvm_isa_irq_deassert(d, RTC_IRQ);
>       if ( irqf )
> +log[logidx & LOGIDX_MASK].time = NOW(), log[logidx++ & LOGIDX_MASK].caller = 
> __builtin_return_address(0),//temp
>           hvm_isa_irq_assert(d, RTC_IRQ);
>   }
>   
> @@ -81,12 +99,14 @@ void rtc_periodic_interrupt(void *opaque
>           s->hw.cmos_data[RTC_REG_C] |= RTC_PF;
>           rtc_update_irq(s);
>       }
> -    else if ( ++(s->pt_dead_ticks) >= 10 )
> +    else if ( ++(s->pt_dead_ticks) >= 250 )
>       {
>           /* VM is ignoring its RTC; no point in running the timer */
> +pt_off(__LINE__);//temp
>           destroy_periodic_time(&s->pt);
>           s->pt_code = 0;
>       }
> +else if(s->pt_code) rtc_update_irq(s);//todo?
>       spin_unlock(&s->lock);
>   }
>   
> @@ -114,6 +134,7 @@ static void rtc_timer_update(RTCState *s
>           {
>               if ( period_code != s->pt_code )
>               {
> +printk("pt on: %d @%"PRIx64"\n", period_code, NOW());//temp
>                   s->pt_code = period_code;
>                   period = 1 << (period_code - 1); /* period in 32 Khz cycles */
>                   period = DIV_ROUND(period * 1000000000ULL, 32768); /* in ns */
> @@ -125,6 +146,7 @@ static void rtc_timer_update(RTCState *s
>           }
>           /* fall through */
>       default:
> +pt_off(__LINE__);//temp
>           destroy_periodic_time(&s->pt);
>           s->pt_code = 0;
>           break;
> @@ -451,6 +473,9 @@ static int rtc_ioport_write(void *opaque
>               rtc_timer_update(s);
>           break;
>       case RTC_REG_B:
> +printk("B=%02x [A:%02x B:%02x C:%02x pt:%d/%d] @%"PRIx64"\n",//temp
> +       data, s->hw.cmos_data[RTC_REG_A], orig, 
> s->hw.cmos_data[RTC_REG_C],//temp
> +       s->pt_code, s->pt_dead_ticks, NOW());//temp
>           if ( data & RTC_SET )
>           {
>               /* set mode: reset UIP mode */
> @@ -474,6 +499,7 @@ static int rtc_ioport_write(void *opaque
>            */
>           rtc_update_irq(s);
>           s->hw.cmos_data[RTC_REG_B] = data;
> +if((data & RTC_PIE) && !(orig & RTC_PIE)) rtc_timer_update(s);//todo?
>           if ( (data ^ orig) & RTC_SET )
>               check_update_timer(s);
>           if ( (data ^ orig) & (RTC_24H | RTC_DM_BINARY | RTC_SET) )
> @@ -629,6 +655,7 @@ static uint32_t rtc_ioport_read(RTCState
>       case RTC_REG_C:
>           ret = s->hw.cmos_data[s->hw.cmos_index];
>           s->hw.cmos_data[RTC_REG_C] = 0x00;
> +printk("C=%02x pt=%d/%d @%"PRIx64"\n", ret, s->pt_code, s->pt_dead_ticks, 
> NOW());//temp
>           rtc_update_irq(s);
>           check_update_timer(s);
>           alarm_timer_update(s);
> @@ -730,6 +757,8 @@ void rtc_reset(struct domain *d)
>       destroy_periodic_time(&s->pt);
>       s->pt_code = 0;
>       s->pt.source = PTSRC_isa;
> +s->hw.cmos_data[RTC_REG_B] &= ~(RTC_PIE|RTC_AIE|RTC_UIE);//todo?
> +s->hw.cmos_data[RTC_REG_C] = 0;//todo?
>   }
>   
>   void rtc_init(struct domain *d)
(XEN) pt on: 10 @14fd4b61ef^M
(XEN) B=42 [A:2a B:02 C:50 pt:10/0] @14fd6f73d9^M
(XEN) C=50 pt=10/0 @14fdb032f8^M
(XEN) C=c0 pt=10/6 @14fddabc31^M
(XEN) C=00 pt=10/0 @14fe04d583^M
(XEN) C=c0 pt=10/0 @14feaa9978^M
(XEN) C=00 pt=10/0 @14fed2ae4b^M
(XEN) C=c0 pt=10/0 @14ff98fe90^M
(XEN) C=00 pt=10/0 @14ffc0fbc1^M
(XEN) irq.c:270: Dom1 PCI link 0 changed 5 -> 0^M
(XEN) irq.c:270: Dom1 PCI link 1 changed 10 -> 0^M
(XEN) irq.c:270: Dom1 PCI link 2 changed 11 -> 0^M
(XEN) irq.c:270: Dom1 PCI link 3 changed 5 -> 0^M
(XEN) pt off #105 @15e95c8ff8^M
(XEN) pt irq @15da75fb9c (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15db644b09 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15dc53074a (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15dd41309b (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15de2f93db (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15df1e6232 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e00c3c2f (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e0faca4c (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e1e94f41 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e2d7b303 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e3c61780 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e4b4cd99 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e5a33c65 (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e690a53a (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e77f1d0f (rtc_periodic_interrupt+0x81/0x93)^M
(XEN) pt irq @15e86d876a (rtc_periodic_interrupt+0x81/0x93)^M

Full log attached...

 -George

Attachment: kodo2.log
Description: Text Data

_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel