Date: Sun, 08 Nov 2015 17:32:18 +0000 From: Mark Cave-Ayland <mark.cave-ayland@ilande.co.uk> To: Marius Strobl <marius@alchemy.franken.de> Cc: Alexey Dokuchaev <danfe@FreeBSD.org>, "freebsd-sparc64@freebsd.org" <freebsd-sparc64@freebsd.org> Subject: Re: PCI range checking under qemu-system-sparc64 Message-ID: <563F8722.9050503@ilande.co.uk> In-Reply-To: <20150922221404.GA81100@alchemy.franken.de> References: <20150913180126.GC7862@alchemy.franken.de> <55F89861.1030107@ilande.co.uk> <20150916031030.GA6711@FreeBSD.org> <55F9C2B8.7030605@ilande.co.uk> <20150916211914.GD18789@alchemy.franken.de> <20150917082817.GA71811@FreeBSD.org> <55FBB662.4080708@ilande.co.uk> <20150919211420.GK18789@alchemy.franken.de> <55FDEA3C.1010804@ilande.co.uk> <20150920043630.GA36162@FreeBSD.org> <20150922221404.GA81100@alchemy.franken.de>
next in thread | previous in thread | raw e-mail | index | archive | help
On 22/09/15 23:14, Marius Strobl wrote:
Hi Marius,
I know it has been a while, fortunately I'm starting to get some more
time to look at this once again.
> On Sun, Sep 20, 2015 at 04:36:31AM +0000, Alexey Dokuchaev wrote:
>> On Sun, Sep 20, 2015 at 12:05:32AM +0100, Mark Cave-Ayland wrote:
>>> [...]
>>> While I don't have any insight on the CPU tick interrupt yet, my initial
>>> feeling is that the ATA hang could be related to the PCI interrupt
>>> clearing issue that I started looking into a while back. Although it
>>> isn't a complete fix, does the attached patch against QEMU help at all?
>>
>> Did not help; putting back "device scbus+da+cd" hangs with patched QEMU.
>>
>
> Actually, it does make a bit of a difference; with a QEMU 2.4.0
> built with apb-no-clear.patch applied the number of interrupts
> seen for the emulated CMD646U2 at the point of the hang decreases
> from reliably 5 to reliably 4. Now whether that is a relevant
> functional change or what's the appropriate number of interrupts
> at that point in time I don't know, though.
>
> I tried to look into the tick interrupt problem, as that seems
> more relevant. Apparently, writes to %tick and %tick_cmpr are
> hooked up to cpu_tick_set_count() and cpu_tick_set_limit() (in
> hw/sparc64/sun4u.c) respectively in target-sparc/translate.c
> by a detour via target-sparc/helper.c. Likewise for %{h,}stick
> and %{h,}stick_cpmr. So at first I just enabled DEBUG_TIMER,
> which yields:
> marius@enigma:/home/marius > qemu-system-sparc64 -nographic -cdrom FreeBSD-11.0-CURRENT-sparc64-bootonly.iso -boot d
> TIMER: tick set_limit limit=0x0000000000000000 (disabled) p=0x803a29810 called with limit=0x8000000000000000 at 0x0000000000004c97 (delta=0x0000000000000000)
> TIMER: tick set_limit limit=ZERO - not starting timer
> TIMER: tick get_count count=0x000000000005df82 (disabled) p=0x803a29810
> TIMER: tick set_limit limit=0x00000000001521c2 (enabled) p=0x803a29810 called with limit=0x00000000001521c2 at 0x000000000005e0e9 (delta=0x00000000000f40d8)
> OpenBIOS for Sparc64
> <...>
>
> The first invocation of cpu_tick_set_count() is here:
> TIMER: tick set_count count=0x0000000000000000 (enabled) p=0x803a29810
> TIMER: tick set_limit limit=0x0000000000000000 (disabled) p=0x803a29810 called with limit=0x8000000000000000 at 0x0000000000000e73 (delta=0x0000000000000000)
> TIMER: tick set_limit limit=ZERO - not starting timer
> GDB: no debug ports present
> KDB: debugger backends: ddb
> KDB: current backend: ddb
> Copyright (c) 1992-2015 The FreeBSD Project.
>
> I don't know where that write to %tick is coming from but it's not
> performed by either the FreeBSD loader or kernel.
I've traced this through using QEMU's gdbstub and the first write to
%tick is coming from tick_clear() which is called from sparc64_init().
> However, the write
> to %tick_cmpr seems right as we do a `wrpr (1L << 63), 0, %tick_cmpr`
> very early in the kernel in order to prevent foot-shooting from
> firmware variants that leave the tick counter enabled.
Yes, that seems to be the subsequent call to tick_stop() just after the
call to tick_clear().
> There's no other call of cpu_tick_set_count() but the next one to
> cpu_tick_set_limit() is when the kernel enables the tick counter:
> Timecounter "tick" frequency 100000000 Hz quality 1000
> TIMER: tick get_count count=0x0000000006ead320 (disabled) p=0x803a29810
> TIMER: tick get_count count=0x0000000006ead7da (disabled) p=0x803a29810
> Event timer "tick" frequency 100000000 Hz quality 1000
> TIMER: tick get_count count=0x0000000006ec9b12 (disabled) p=0x803a29810
> TIMER: tick set_limit limit=0x0000000006ed5e61 (disabled) p=0x803a29810 called with limit=0x8000000006ed5e61 at 0x0000000006eca6e5 (delta=0x000000000000b77b)
> TIMER: (null) disabled
> Timecounters tick every 1.000 msec^M^M
>
> The "called with limit=0x8000000006ed5e61" is a plain lie! We
> simply do not set (1L << 63) when writing the future tick value
> to %tick_cmpr for the tick interrupt to go off.
Stepping this through I can see the problem is caused as an accidental
side-effect of the existing QEMU timer code. What happens is that in
tick_et_start() the existing %tick value is used as a base before being
written to %tick_cmpr - but since the timer is internally marked as
disabled then QEMU's cpu_tick_get_count() sets (1L << 63) which is
wrong. In other words, this is a side-effect of the same timer bug you
already found.
> So I tried with
> a hack to cpu_tick_set_limit():
> void cpu_tick_set_limit(CPUTimer *timer, uint64_t limit)
> {
> int64_t now = qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL);
>
> uint64_t real_limit = limit & ~timer->disabled_mask;
> timer->disabled = (limit & timer->disabled_mask) ? 1 : 0;
> timer->disabled = limit == 0;
>
> Not that this shouldn't make any difference as it just special-
> cases the fact that apart from (1L << 63), FreeBSD writes a 0
> value to %tick_cmpr for disabling the tick interrupt. Moreover,
> limit == 0 implies that (1L << 63) isn't set either, so if the
> kernel really would set (1L << 63) in the case in question,
> this change shouldn't cause a difference in behavior, but it
> in fact it does:
> Timecounter "tick" frequency 100000000 Hz quality 1000
> Event timer "tick" frequency 100000000 Hz quality 1000
> Timecounters tick every 1.000 msec
> IPsec: Initialized Security Association Processing.
> cd0 at ata3 bus 0 scbus1 target 0 lun 0
> cd0: <QEMU QEMU DVD-ROM 2.4.> Removable CD-ROM SCSI device
> cd0: Serial Number QM00003
> cd0: 13.300MB/s transfers (WDMA1, ATAPI 12bytes, PIO 65534bytes)
> cd0: cd present [103200 x 2048 byte records]
> WARNING: WITNESS option enabled, expect reduced performance.
> Trying to mount root from cd9660:/dev/iso9660/11_0_CURRENT_SPARC64_BO [ro]...
> [ thread pid 1 tid 100002 ]
> Stopped at tl1_trap+0x24: stx %o0, [%sp + 0x997]
> db>
>
> So apparently (1L << 63) in %tick_cmpr somehow is sticky
> within QEMU but I didn't manage to spot a bug in that
> regard. There actually are several obvious bugs in QEMU
> when it comes to %{hs,s,}tick and %{hs,s,}tick_cmpr
> handling, though. First off, both cpu_tick_set_count()
> and cpu_tick_set_limit() test for the disabled_mask being
> set in the value written to the register in question.
> This is wrong as only the %{s,}tick_cmpr registers have
> (1L << 63) as disable bit, in %{s,}tick (1L << 63) serves
> as NPT (Non-Privilege Trap) bit. The NPT bit causes an
> unprivileged read of %{s,}tick to trap when set (with
> real hardware that is). QEMU seems to re-invent and
> side-step that logic via CONFIG_USER_ONLY. I don't have
> documentation for %hstick and %hstick_cmpr at hand but
> they likely work the same way. Moreover, cpu_devinit()
> in hw/sparc64/sun4u.c seems to totally confuse NPT
> and disable bit in the first place:
> env->tick = cpu_timer_create("tick", cpu, tick_irq,
> tick_frequency, TICK_NPT_MASK);
>
> env->stick = cpu_timer_create("stick", cpu, stick_irq,
> stick_frequency, TICK_INT_DIS);
>
> env->hstick = cpu_timer_create("hstick", cpu, hstick_irq,
> hstick_frequency, TICK_INT_DIS);
>
> Depending on what "disabled" is supposed to mean, that
> should be either all TICK_INT_DIS or all TICK_NPT_MASK,
> but certainly not mixed.
>
> As for the panic I get with my hack applied, the back-
> trace is:
> Trying to mount root from cd9660:/dev/iso9660/11_0_CURRENT_SPARC64_BO [ro]...
> [ thread pid 1 tid 100002 ]
> Stopped at tl1_trap+0x24: stx %o0, [%sp + 0x997]
> db> bt
> Tracing pid 1 tid 100002 td 0xfffff800015e84d0
> KDB: reentering
> KDB: stack backtrace:
> kdb_reenter() at kdb_reenter+0x5c
> trap() at trap+0x2fc
> -- kernel stack fault %o7=0xc0570d40 --
> sched_clock() at sched_clock+0x94
> KDB: reentering
> KDB: stack backtrace:
> kdb_reenter() at kdb_reenter+0x5c
> trap() at trap+0x2fc
> -- kernel stack fault %o7=0xc011a050 --
> db_read_bytes() at db_read_bytes+0x44
> KDB: reentering
> KDB: stack backtrace:
> kdb_reenter() at kdb_reenter+0x5c
> trap() at trap+0x2fc
> -- kernel stack fault %o7=0xc011a050 --
> db_read_bytes() at db_read_bytes+0x44
> KDB: reentering
> KDB: stack backtrace:
> kdb_reenter() at kdb_reenter+0x5c
> trap() at trap+0x2fc
> -- kernel stack fault %o7=0xc011a050 --
> db_read_bytes() at db_read_bytes+0x44
> <continues seemingly endlessly with db_read_bytes()>
>
> So this is a trap while inside the kernel and a
> seemingly serious stack corruption. I have no idea
> how to even debug QEMU in that regard or where to
> start looking for that bug in QEMU. However, as
> long as the bug of (1L << 63) being corrupted in
> %tick_cmpr isn't fixed, i. e. its cause unknown,
> it likely also doesn't make much sense to dig
> further into that stack corruption.
I now have a small patchset for QEMU git master that fixes the timer
issues (as well as implementing the NPT bit properly) and it gets to the
same point as you did above, so that's progress :)
QEMU is currently in freeze in preparation for the next release, so
while the timer work won't be there for 2.5 in the meantime I shall tidy
them up and push to github. I should add that the ebus enumeration
patches related to the device tree properties (minus the addition of the
keyboard device that crashes Linux) are already upstream and will appear
in 2.5.
> Err, what operating systems is qemu-system-sparc64
> already able to successfully host again? :)
Apparently most of all the others ;) Thanks again for all your pointers
and the time you've put into this so far - I'm sure there will be more
questions coming this way soon...
ATB,
Mark.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?563F8722.9050503>