Bug#758115: Disabled wait state X'32EE' on IPL of zIPL

[Stephen Powell]

Here are the last few instructions prior to the failure on the failing
version, thanks to the CP TRACE facility under z/VM on a real IBM z/890:

0000000000002A78 STG E310F0A80024 >> 000000000000FEB0 CC 2
0000000000002A7E LG E32030000004 00000000000001B0 CC 2
0000000000002A84 LG E31030080004 00000000000001B8 CC 2
0000000000002A8A STG E34030000024 >> 00000000000001B0 CC 2
0000000000002A90 LA 4140F0A0 = 000000000000FEA8 CC 2
0000000000002A94 LARL C0500000000B CC 2
0000000000002A9A STG E35040080024 >> 000000000000FEB0 CC 2
0000000000002AA0 STG E35030080024 >> 00000000000001B8 CC 2
0000000000002AA6 LPSWE B2B2F0A0 000000000000FEA8 CC 0
0000000000002AAA LMG EBDFF0B00004 ???????????????? CC 0
0000000000002AB0 STG E32030000024 >> 00000000000001B0 CC 0
0000000000002AB6 STG E31030080024 >> 00000000000001B8 CC 0
0000000000002ABC BR 07FE -> 00000000000032E6 CC 0
-> 00000000000032E6 LH 48100086 0000000000000086 CC 0
00000000000032EA BRU A7F40001 -> 00000000000032EC CC 0
-> 00000000000032EC ???? 0001
*** 00000000000032EC PROG 0001 -> 00000000000039A8

And here is what appears to be the equivalent code on the working
version, compiled under wheezy:

0000000000002A38 STG E310F0A80024 >> 000000000000FEA0 CC 2
0000000000002A3E LG E32030000004 00000000000001B0 CC 2
0000000000002A44 LG E31030080004 00000000000001B8 CC 2
0000000000002A4A STG E34030000024 >> 00000000000001B0 CC 2
0000000000002A50 LA 4140F0A0 = 000000000000FE98 CC 2
0000000000002A54 LARL C0500000000B CC 2
0000000000002A5A STG E35040080024 >> 000000000000FEA0 CC 2
0000000000002A60 STG E35030080024 >> 00000000000001B8 CC 2
0000000000002A66 LPSWE B2B2F0A0 000000000000FE98 CC 0
0000000000002A6A LMG EBDFF0B00004 ???????????????? CC 0
0000000000002A70 STG E32030000024 >> 00000000000001B0 CC 0
0000000000002A76 STG E31030080024 >> 00000000000001B8 CC 0
0000000000002A7C BR 07FE -> 00000000000032C0 CC 0
-> 00000000000032C0 LLGH E31000860091 0000000000000086 CC 0
00000000000032C6 CHI A71E1004 CC 2
00000000000032CA BRZ A784000A 00000000000032DE CC 2
...

And on we go from there. The BRU instruction in the first sequence
is clearly bad. In assembler language format, the equivalent instruction
would be "BRU *+2". This is a bad branch. The instruction branches
into the middle of itself, picking up "0001" as the next machine instruction,
which causes an operation exception. Since the failing "instruction"
starts at storage address 32EC, and is two bytes long, that means that
the updated instruction address in the PSW at the time of the program
interruption will be 32EE, which is the value used in the disabled wait
PSW.
--
.''`. Stephen Powell
: :' :
`. `'`
`-

[Michael Holzheu]

On Thu, 21 Aug 2014 19:26:44 -0400 (EDT)

Post by Stephen Powell
Here are the last few instructions prior to the failure on the failing
0000000000002A78 STG E310F0A80024 >> 000000000000FEB0 CC 2
0000000000002A7E LG E32030000004 00000000000001B0 CC 2
0000000000002A84 LG E31030080004 00000000000001B8 CC 2
0000000000002A8A STG E34030000024 >> 00000000000001B0 CC 2
0000000000002A90 LA 4140F0A0 = 000000000000FEA8 CC 2
0000000000002A94 LARL C0500000000B CC 2
0000000000002A9A STG E35040080024 >> 000000000000FEB0 CC 2
0000000000002AA0 STG E35030080024 >> 00000000000001B8 CC 2
0000000000002AA6 LPSWE B2B2F0A0 000000000000FEA8 CC 0
0000000000002AAA LMG EBDFF0B00004 ???????????????? CC 0
0000000000002AB0 STG E32030000024 >> 00000000000001B0 CC 0
0000000000002AB6 STG E31030080024 >> 00000000000001B8 CC 0
0000000000002ABC BR 07FE -> 00000000000032E6 CC 0
-> 00000000000032E6 LH 48100086 0000000000000086 CC 0
00000000000032EA BRU A7F40001 -> 00000000000032EC CC 0
-> 00000000000032EC ???? 0001
*** 00000000000032EC PROG 0001 -> 00000000000039A8
And here is what appears to be the equivalent code on the working
0000000000002A38 STG E310F0A80024 >> 000000000000FEA0 CC 2
0000000000002A3E LG E32030000004 00000000000001B0 CC 2
0000000000002A44 LG E31030080004 00000000000001B8 CC 2
0000000000002A4A STG E34030000024 >> 00000000000001B0 CC 2
0000000000002A50 LA 4140F0A0 = 000000000000FE98 CC 2
0000000000002A54 LARL C0500000000B CC 2
0000000000002A5A STG E35040080024 >> 000000000000FEA0 CC 2
0000000000002A60 STG E35030080024 >> 00000000000001B8 CC 2
0000000000002A66 LPSWE B2B2F0A0 000000000000FE98 CC 0
0000000000002A6A LMG EBDFF0B00004 ???????????????? CC 0
0000000000002A70 STG E32030000024 >> 00000000000001B0 CC 0
0000000000002A76 STG E31030080024 >> 00000000000001B8 CC 0
0000000000002A7C BR 07FE -> 00000000000032C0 CC 0
-> 00000000000032C0 LLGH E31000860091 0000000000000086 CC 0
00000000000032C6 CHI A71E1004 CC 2
00000000000032CA BRZ A784000A 00000000000032DE CC 2
...
And on we go from there. The BRU instruction in the first sequence
is clearly bad. In assembler language format, the equivalent instruction
would be "BRU *+2". This is a bad branch. The instruction branches
into the middle of itself, picking up "0001" as the next machine instruction,
which causes an operation exception. Since the failing "instruction"
starts at storage address 32EC, and is two bytes long, that means that
the updated instruction address in the PSW at the time of the program
interruption will be 32EE, which is the value used in the disabled wait
PSW.

Hi Stephen,

You can get a disassembly for the eckd boot loader code when you go
to s390-tools/zipl/boot and:

1) make
2) objdump -S eckd2.exec > eckd2.list

I think the corresponding code in zipl is load_wait_psw() in libc.c:

__attribute__ ((noinline)) void load_wait_psw(uint64_t psw_mask, struct psw_t *psw)
{
struct psw_t wait_psw = { .mask = psw_mask, .addr = 0 };
2df6: e3 20 f0 a0 00 24 stg %r2,160(%r15)
struct psw_t old_psw, *wait_psw_ptr = &wait_psw;
unsigned long addr;

old_psw = *psw;
psw->mask = 0x0000000180000000ULL;
2dfc: e3 10 30 00 00 24 stg %r1,0(%r3)
asm volatile(
2e02: 41 20 f0 a0 la %r2,160(%r15)
{
struct psw_t wait_psw = { .mask = psw_mask, .addr = 0 };
struct psw_t old_psw, *wait_psw_ptr = &wait_psw;
unsigned long addr;

old_psw = *psw;
2e06: e3 10 30 08 00 04 lg %r1,8(%r3)
psw->mask = 0x0000000180000000ULL;
asm volatile(
2e0c: c0 50 00 00 00 0b larl %r5,2e22 <load_wait_psw+0x5a>
2e12: e3 50 20 08 00 24 stg %r5,8(%r2)
2e18: e3 50 30 08 00 24 stg %r5,8(%r3)
2e1e: b2 b2 f0 a0 lpswe 160(%r15)
".Lwait: \n"
: [addr] "=&d" (addr)
: [wait_psw] "Q" (wait_psw), [wait_psw_ptr] "a" (wait_psw_ptr),
[psw] "a" (psw)
: "cc", "memory");
*psw = old_psw;
2e22: e3 40 30 00 00 24 stg %r4,0(%r3)
2e28: e3 10 30 08 00 24 stg %r1,8(%r3)
}
2e2e: eb df f0 b0 00 04 lmg %r13,%r15,176(%r15)
2e34: 07 fe br %r14

load_wait_psw() is called from wait():

static inline int wait(void)
{
do {
load_wait_psw(0x0102000180000000ULL, &S390_lowcore.external_new_psw);
33d0: e3 20 d0 00 00 04 lg %r2,0(%r13)
33d6: a7 39 01 b0 lghi %r3,432
33da: c0 e5 ff ff fc f7 brasl %r14,2dc8 <load_wait_psw>
if (S390_lowcore.ext_int_code == 0x1004)
33e0: e3 10 00 86 00 91 llgh %r1,134
33e6: a7 1e 10 04 chi %r1,4100
33ea: a7 74 00 06 jne 33f6 <sclp_wait_for_int+0x9a>
33ee: a7 28 00 02 lhi %r2,2
33f2: a7 f4 00 08 j 3402 <sclp_wait_for_int+0xa6>
return ETIMEOUT;
} while (S390_lowcore.ext_int_code != 0x2401);
33f6: a7 1e 24 01 chi %r1,9217
33fa: a7 74 ff eb jne 33d0 <sclp_wait_for_int+0x74>
33fe: a7 28 00 00 lhi %r2,0

Would be interesting how the disassembly looks on your system.

Michael

[Stephen Powell]

Post by Michael Holzheu
You can get a disassembly for the eckd boot loader code when you go
1) make
2) objdump -S eckd2.exec > eckd2.list
...
static inline int wait(void)
{
do {
load_wait_psw(0x0102000180000000ULL, &S390_lowcore.external_new_psw);
33d0: e3 20 d0 00 00 04 lg %r2,0(%r13)
33d6: a7 39 01 b0 lghi %r3,432
33da: c0 e5 ff ff fc f7 brasl %r14,2dc8 <load_wait_psw>
if (S390_lowcore.ext_int_code == 0x1004)
33e0: e3 10 00 86 00 91 llgh %r1,134
33e6: a7 1e 10 04 chi %r1,4100
33ea: a7 74 00 06 jne 33f6 <sclp_wait_for_int+0x9a>
33ee: a7 28 00 02 lhi %r2,2
33f2: a7 f4 00 08 j 3402 <sclp_wait_for_int+0xa6>
return ETIMEOUT;
} while (S390_lowcore.ext_int_code != 0x2401);
33f6: a7 1e 24 01 chi %r1,9217
33fa: a7 74 ff eb jne 33d0 <sclp_wait_for_int+0x74>
33fe: a7 28 00 00 lhi %r2,0
Would be interesting how the disassembly looks on your system.

Indeed. Here is what I got:

-----

static inline int wait(void)
{
do {
load_wait_psw(0x0102000180000000ULL, &S390_lowcore.external_new_psw);
32d6: a7 39 01 b0 lghi %r3,432
32da: e3 20 d0 00 00 04 lg %r2,0(%r13)
32e0: c0 e5 ff ff fb b8 brasl %r14,2a50 <load_wait_psw>
if (S390_lowcore.ext_int_code == 0x1004)
32e6: 48 10 00 86 lh %r1,134
32ea: a7 f4 00 01 j 32ec <sclp_wait_for_int+0x84>
32ee: 07 07 nopr %r7

-----

Obviously bad code. Something is terribly wrong here. The complete eckd2.list
file is available for download at

http://users.wowway.com/~zlinuxman/zipl/eckd2.list

It was compiled with gcc version 4.9.1 (Debian 4.9.1-4) on a Debian jessie system.
--
.''`. Stephen Powell
: :' :
`. `'`
`-

[Bastian Blank]

Post by Stephen Powell
32ea: a7 f4 00 01 j 32ec <sclp_wait_for_int+0x84>
32ee: 07 07 nopr %r7

gcc 4.9 decides that this must never happen and adds a trap in this
location, so this a is deliberate way to stop the process.

I found the culprit: The tree-isolate-paths pass in gcc 4.9. If I

And -fno-delete-null-pointer-checks seems to be the correct option.

Bastian

[Bastian Blank]

On Sun, 24 Aug 2014 20:43:30 +0200

Post by Bastian Blank
And -fno-delete-null-pointer-checks seems to be the correct option.

-fdelete-null-pointer-checks
In some environments, this assumption is not true, and programs can safely dereference null
pointers. Use -fno-delete-null-pointer-checks to disable this optimization for programs which
depend on that behavior.
So we should add this Option to CFLAGS in zipl/boot/Makefile?

Yes.

Why we have not seen this problem under RHEL and SLES up to now?

Can you show a RHEL or SLES that uses gcc 4.9? Or any
Redhat/Fedora/SUSE with support for s390* that uses it? RHEL 7 uses 4.8
(see https://git.centos.org/summary/?r=rpms/gcc.git).

Maybe you should ask the gcc people why they enable this check on the
freestanding implementation (-ffreestanding).

Bastian

[Michael Holzheu]

On Mon, 25 Aug 2014 18:38:35 +0200
Bastian Blank <***@debian.org> wrote:

[snip]

Post by Bastian Blank

Why we have not seen this problem under RHEL and SLES up to now?

Can you show a RHEL or SLES that uses gcc 4.9?

Sorry, I missed that part.

So they enabled that "feature" by default with gcc 4.9, ok.

Michael

[Philipp Kern]

Post by Bastian Blank

Post by Stephen Powell
32ea: a7 f4 00 01 j 32ec <sclp_wait_for_int+0x84>
32ee: 07 07 nopr %r7

gcc 4.9 decides that this must never happen and adds a trap in this
location, so this a is deliberate way to stop the process.

I found the culprit: The tree-isolate-paths pass in gcc 4.9. If I

And -fno-delete-null-pointer-checks seems to be the correct option.

Thanks! I uploaded that to replace the gcc-4.8 build dependency.

Kind regards
Philipp Kern