Re: NetBSD-current Time issues on RPI3

To: Ryo Shimizu <ryo%nerv.org@localhost>
Subject: Re: NetBSD-current Time issues on RPI3
From: Sad Clouds <cryintothebluesky%gmail.com@localhost>
Date: Sat, 11 May 2019 08:10:56 +0100
On Tue, 07 May 2019 02:47:06 +0900
Ryo Shimizu <ryo%nerv.org@localhost> wrote:

> 
> >Well, I got FreeBSD running and I've been building ports for a few
> >hours now and not seen any issues. Looks like not a hardware bug but
> >a NetBSD one. I can help with debugging if anyone can give ideas on
> >where to look.
> 
> 
> I don't know the cause yet, but when I put in a quick hack like below,
> I found that the cntvct value was rolled back.
> When cntvct rolls back, the clockhandler stops because the cntv_cval
> is still there and will not occur until the next timer interrupt is
> much later.
> 
> The association is unknown, but it seems to be more likely to occur
> under high load.
> 
> It has never happened with a pinebook.
> 
> 
> 
> Index: gtmr.c
> ===================================================================
> RCS file: /src/cvs/cvsroot-netbsd/src/sys/arch/arm/cortex/gtmr.c,v
> retrieving revision 1.39
> diff -a -u -p -r1.39 gtmr.c
> --- gtmr.c	30 Jan 2019 02:01:58 -0000	1.39
> +++ gtmr.c	30 Jan 2019 20:45:23 -0000
> @@ -322,6 +322,34 @@ gtmr_intr(void *arg)
>  	return 1;
>  }
>  
> +void gtmr_fixup(void);
> +
> +void
> +gtmr_fixup(void)
> +{
> +	struct gtmr_softc * const sc = &gtmr_sc;
> +	uint64_t now;
> +	int s;
> +
> +	if (sc->sc_autoinc == 0)
> +		return;
> +
> +	s = splclock();
> +
> +	now = gtmr_read_cntvct(sc);
> +	if (now < curcpu()->ci_lastintr) {
> +		printf("cpu%d: detect cntvc was rollbacked: "
> +		    "0x%"PRIx64" -> 0x%"PRIx64" (%+"PRId64"). fixup
> \n",
> +		    curcpu()->ci_index,
> +		    curcpu()->ci_lastintr, now, now - curcpu
> ()->ci_lastintr); +
> +		curcpu()->ci_lastintr = now;
> +		gtmr_cntv_tval_write(sc->sc_autoinc);
> +	}
> +
> +	splx(s);
> +}
> +
>  void
>  setstatclockrate(int newhz)
>  {
> @@ -332,5 +360,6 @@ gtmr_get_timecount(struct timecounter *t
>  {
>  	struct gtmr_softc * const sc = tc->tc_priv;
>  	arm_isb();	// we want the time NOW, not some
> instructions later.
> +	gtmr_fixup();
>  	return (u_int) gtmr_read_cntvct(sc);
>  }
> 

Hi, I'm trying out your hack, but now I'm hitting a new issue. When
unpacking pkgsrc.tar.gz I got a panic, not sure if this is related to
your patch or something new I haven't yet seen.

May 11 06:55:35 arm64 /netbsd: [ 1062.1949804] panic: kernel diagnostic assertion "xfer->ux_state == XFER_BUSY" failed: file "/netbsd_build/netbsd-current-src/sys/dev/usb/usbdi.c", line 1039 xfer 0xffff00003aceacc0 state is 9e
May 11 06:55:35 arm64 /netbsd: [ 1062.2149788] cpu3: Begin traceback...
May 11 06:55:35 arm64 /netbsd: [ 1062.2149788] trace fp ffffffc0335e76a0
May 11 06:55:35 arm64 /netbsd: [ 1062.2249784] fp ffffffc0335e76c0 vpanic() at ffffffc00048d8f8 netbsd:vpanic+0x198
May 11 06:55:35 arm64 /netbsd: [ 1062.2349864] fp ffffffc0335e7720 kern_assert() at ffffffc0005ce13c netbsd:kern_assert+0x5c
May 11 06:55:35 arm64 /netbsd: [ 1062.2349864] fp ffffffc0335e77b0 usb_insert_transfer() at ffffffc0000c6930 netbsd:usb_insert_transfer+0xe0
May 11 06:55:35 arm64 /netbsd: [ 1062.2449790] fp ffffffc0335e77d0 dwc2_device_bulk_transfer() at ffffffc000341698 netbsd:dwc2_device_bulk_transfer+0x28
May 11 06:55:35 arm64 /netbsd: [ 1062.2549791] fp ffffffc0335e77f0 usbd_transfer() at ffffffc0000c55c8 netbsd:usbd_transfer+0x98
May 11 06:55:35 arm64 /netbsd: [ 1062.2649800] fp ffffffc0335e7820 mue_start() at ffffffc0001034b4 netbsd:mue_start+0x274
May 11 06:55:35 arm64 /netbsd: [ 1062.2749793] fp ffffffc0335e78a0 if_transmit() at ffffffc00051d190 netbsd:if_transmit+0x150
May 11 06:55:35 arm64 /netbsd: [ 1062.2849784] fp ffffffc0335e78e0 ether_output() at ffffffc000529a70 netbsd:ether_output+0x440
May 11 06:55:35 arm64 /netbsd: [ 1062.2949798] fp ffffffc0335e7940 ip_if_output() at ffffffc00022054c netbsd:ip_if_output+0xac
May 11 06:55:35 arm64 /netbsd: [ 1062.3049782] fp ffffffc0335e7980 ip_output() at ffffffc000221d88 netbsd:ip_output+0x10d8
May 11 06:55:35 arm64 /netbsd: [ 1062.3149785] fp ffffffc0335e7b40 tcp_output() at ffffffc00022d3fc netbsd:tcp_output+0x166c
May 11 06:55:35 arm64 /netbsd: [ 1062.3249776] fp ffffffc0335e7c60 tcp_send_wrapper() at ffffffc000233984 netbsd:tcp_send_wrapper+0x94
May 11 06:55:35 arm64 /netbsd: [ 1062.3349795] fp ffffffc0335e7cc0 sosend() at ffffffc0004c5214 netbsd:sosend+0x674
May 11 06:55:35 arm64 /netbsd: [ 1062.3449781] fp ffffffc0335e7da0 dofilewrite() at ffffffc00049b0dc netbsd:dofilewrite+0x7c
May 11 06:55:35 arm64 /netbsd: [ 1062.3449781] fp ffffffc0335e7e20 syscall() at ffffffc000074d9c netbsd:syscall+0x19c
May 11 06:55:35 arm64 /netbsd: [ 1062.3549805] tf ffffffc0335e7ed0 el0_trap() at ffffffc000073398 netbsd:el0_trap
May 11 06:55:35 arm64 /netbsd: [ 1062.3649777] ---- trapframe 0xffffffc0335e7ed0 (304 bytes) ----
May 11 06:55:35 arm64 /netbsd: [ 1062.3749786]     pc=0000f8d153308360,   spsr=0000000020000000
May 11 06:55:35 arm64 /netbsd: [ 1062.3749786]    esr=0000000056000004,    far=ffffffc0325b0000
May 11 06:55:35 arm64 /netbsd: [ 1062.3849778]     x0=0000000000000004,     x1=0000f8d1536fbf00
May 11 06:55:35 arm64 /netbsd: [ 1062.3849778]     x2=00000000000002f4,     x3=0000000000000000
May 11 06:55:35 arm64 /netbsd: [ 1062.3949765]     x4=0000000000000000,     x5=0000000000000004
May 11 06:55:35 arm64 /netbsd: [ 1062.3949765]     x6=0000f8d153ac74c0,     x7=0000000000000000
May 11 06:55:35 arm64 /netbsd: [ 1062.4049765]     x8=000000000000000f,     x9=0000000000000006
May 11 06:55:35 arm64 /netbsd: [ 1062.4149765]    x10=0000000000000040,    x11=000000000000003f
May 11 06:55:35 arm64 /netbsd: [ 1062.4149765]    x12=000003e3454f47d8,    x13=000003e3454f47dc
May 11 06:55:35 arm64 /netbsd: [ 1062.4249762]    x14=0000000000000000,    x15=0000f8d153d8f04c
May 11 06:55:35 arm64 /netbsd: [ 1062.4249762]    x16=0000f8d153b206a8,    x17=0000f8d15330835c
May 11 06:55:35 arm64 /netbsd: [ 1062.4349756]    x18=0000f8d1533d4160,    x19=00000000000002f4
May 11 06:55:35 arm64 /netbsd: [ 1062.4449758]    x20=0000000000000004,    x21=0000f8d152fcf000
May 11 06:55:35 arm64 /netbsd: [ 1062.4449758]    x22=000000020013a668,    x23=000000020015b000
May 11 06:55:35 arm64 /netbsd: [ 1062.4549753]    x24=0000000000000000,    x25=0000000000000010
May 11 06:55:35 arm64 /netbsd: [ 1062.4549753]    x26=0000000000000000,    x27=0000000000000001
May 11 06:55:35 arm64 /netbsd: [ 1062.4649754]    x28=0000000000000004, fp=x29=0000000000000000
May 11 06:55:35 arm64 /netbsd: [ 1062.4649754] lr=x30=0000f8d153ab93e0,     sp=0000ffffff97ed90
May 11 06:55:35 arm64 /netbsd: [ 1062.4749752] ------------------------------------------------
May 11 06:55:35 arm64 /netbsd: [ 1062.4849752] cpu3: End traceback...
May 11 06:55:35 arm64 /netbsd: 
May 11 06:55:35 arm64 /netbsd: [ 1062.4849752] dump to dev 92,1 not possible
May 11 06:55:35 arm64 /netbsd: [ 1067.6948558] rebooting...
May 11 06:55:35 arm64 /netbsd: [   1.0000000] ------------------------------------------
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kern_vtopdiff         = 0xffffffbfffe00000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] physical_start        = 0x0000000000001000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kernel_start_phys     = 0x0000000000200000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kernel_end_phys       = 0x0000000000f6e000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] msgbuf                = 0x000000003b3f0000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] physical_end          = 0x000000003b400000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] VM_MIN_KERNEL_ADDRESS = 0xffffffc000000000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kernel_start_l2       = 0xffffffc000000000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kernel_start          = 0xffffffc000000000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kernel_end            = 0xffffffc000d6e000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] pagetables            = 0xffffffc000d6e000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] pagetables_end        = 0xffffffc000d76000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] kernel_end_l2         = 0xffffffc000e00000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] module_start          = 0xffffffc000e00000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] module_end            = 0xffffffc002e00000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] (kernel va area)
May 11 06:55:35 arm64 /netbsd: [   1.0000000] (devmap va area)      = 0xfffffffff0000000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] VM_MAX_KERNEL_ADDRESS = 0xffffffffffe00000
May 11 06:55:35 arm64 /netbsd: [   1.0000000] ------------------------------------------
References:
- Re: NetBSD-current Time issues on RPI3
  - From: Sad Clouds
- Re: NetBSD-current Time issues on RPI3
  - From: Ryo Shimizu
Prev by Date: Re: System and CPU hanging on RPi
Next by Date: Re: System and CPU hanging on RPi
Previous by Thread: Re: NetBSD-current Time issues on RPI3
Next by Thread: Re: NetBSD-current Time issues on RPI3
Indexes:
Home | Main Index | Thread Index | Old Index