Bug 495935 - s390x strace problems with 31-bit executables
Summary: s390x strace problems with 31-bit executables
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: strace
Version: 5.3
Hardware: s390x
OS: Linux
low
medium
Target Milestone: rc
: ---
Assignee: Jeff Law
QA Contact: BaseOS QE
URL:
Whiteboard:
Depends On:
Blocks: 809917
TreeView+ depends on / blocked
 
Reported: 2009-04-15 15:49 UTC by David Smith
Modified: 2013-01-08 07:01 UTC (History)
6 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Previously, strace on s390x architecture couldn't handle the 31-bit binaries correctly. This has been fixed so that now there is a strace32 binary, which correctly handles 31-bit binaries even on s390x architecture.
Clone Of:
: 809917 (view as bug list)
Environment:
Last Closed: 2013-01-08 07:01:53 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
test program (540 bytes, text/x-csrc)
2009-04-15 15:49 UTC, David Smith
no flags Details
output of strace on the 64-bit executable (1.86 KB, application/octet-stream)
2009-04-15 15:50 UTC, David Smith
no flags Details
output of strace on the 31-bit executable (2.26 KB, application/octet-stream)
2009-04-15 15:50 UTC, David Smith
no flags Details
Patch to make strace display correct syscall names (6.88 KB, patch)
2009-04-20 13:03 UTC, Denys Vlasenko
no flags Details | Diff
Patch to make strace display correct syscall names, truncate regs to 32 bits, and fix mmap display (8.54 KB, patch)
2009-04-20 13:56 UTC, Denys Vlasenko
no flags Details | Diff
Proposed patch for upstream strace (5.32 KB, patch)
2009-04-20 16:29 UTC, Denys Vlasenko
no flags Details | Diff


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2013:0010 0 normal SHIPPED_LIVE strace bug fix update 2013-01-07 15:30:12 UTC

Description David Smith 2009-04-15 15:49:21 UTC
Created attachment 339702 [details]
test program

Description of problem:

strace on s390x seems to work correctly on 64-bit executables.  However, on 31-bit executables, it reports incorrect values for mmap() and doesn't seem to understand the fstat() system call.

Version-Release number of selected component (if applicable):

kernel: 2.6.18-138.el5
strace version: 4.5.18-2.el5_3.3

How reproducible:

every time

Steps to Reproduce:
1. Compile a 64-bit version of the test program:

# gcc -m64 -o syscall_args64 syscall_args.c

2. Run strace on the 64-bit test program

# strace syscall_args64

3. Observe the output, looking at the mmap() calls and fstat() calls, which appear to match up with the test program

4. Compile a 31-bit version of the test program

# gcc -m31 -o syscall_args31 syscall_args.c

5. Run strace on the 31-bit test program

# strace syscall_args31

6. Observe the output.  The mmap() call information appears to be incorrect, with all arguments having bad values (sometimes the actual 2nd argument appears as the 1st argument).  Here's an example of the last mmap call the program makes:

64-bit exe output:

mmap(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0) = 0x20000001000

31-bit exe output:

mmap(0x406, 4294967297, PROT_NONE, MAP_FILE, 0, 0x7ffbf95800000000) = 0x77fff000

The output should be identical with the exception of the return value (and perhaps the file descriptor number).

The fstat() calls appear as SYS_197 in the 31-bit output.  This suggests that the system call is unknown to strace, which is a bit odd since the fstat() system call isn't an obscure one.

64-bit exe output:

fstat(3, {st_mode=S_IFREG|0600, st_size=1030, ...}) = 0

31-bit exe output:

SYS_197(0x3, 0x3ff7ffbf7e0, 0x3ff7ffbf950, 0x414c8b6a58, 0x4006dc, 0x7ffbfad8, 0x4c8b80d0, 0x3ff7ffbf950, 0x3, 0x3ff00000003, 0x414c8b5000, 0x4c88be20, 0x8040076e, 0x7ffbf780, 0x77feeac0000132f0, 0, 0, 0, 0, 0, 0, 0, 0x3, 0, 0x4040000000000000, 0, 0xbf76f6512a94ff00, 0, 0, 0, 0, 0) = 0
  
Actual results:

See above.

Expected results:

See above.

Additional info:

It is possible that this isn't an strace problem, but a kernel/ptrace problem.

Comment 1 David Smith 2009-04-15 15:50:26 UTC
Created attachment 339703 [details]
output of strace on the 64-bit executable

Comment 2 David Smith 2009-04-15 15:50:55 UTC
Created attachment 339705 [details]
output of strace on the 31-bit executable

Comment 3 Roland McGrath 2009-04-17 18:36:07 UTC
197 is __NR_fstat64 on s390-31.  In strace source it looks like it should be handled.

Comment 4 Denys Vlasenko 2009-04-20 13:02:51 UTC
Latest upstream strace has only one personality for s390x. In other words, it has no idea about 31-bit programs at all.

It turns out all 31-bit specific syscalls are unused in 64-bit more, they can be easily added to 64-bit syscall table in strace. This makes at least syscall names to appear correctly:

# ./strace ./syscall_args31
execve("./syscall_args31", ["./syscall_args31"], [/* 22 vars */]) = 0
brk(0)                                  = 0x402000
uname({sys="Linux", node="z203.z900.redhat.com", ...}) = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open(0xffffffff77ffaa66, O_RDONLY)      = 3
fstat64_31(0x3, 0x3ff7fd91060)          = 0
mmap(0xed8d, 4294967298, PROT_NONE, MAP_FILE, 0, 0) = 0x77fd4000
close(3)                                = 0
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, 0x3ff7fd911e4, 4393751544320)   = 512
fstat64_31(0x3, 0x3ff7fd910d8)          = 0

I added _31 suffix to such syscalls to make them visible.
As you see, parameters are still not decoded correctly.

open(0xffffffff77ffaa66, O_RDONLY) is decoded by strace this way
(this is a strace of strace itself):

ptrace(PTRACE_PEEKUSER, 6896, gpr2, [0x5]) = 0
ptrace(PTRACE_PEEKUSER, 6896, gpr2, [0x5]) = 0
ptrace(PTRACE_PEEKUSER, 6896, orig_gpr2, [0xffffffff77ffaa66]) = 0
ptrace(PTRACE_PEEKUSER, 6896, gpr3, [0x3ff00000000]) = 0
ptrace(PTRACE_PEEKUSER, 6896, gpr4, [0x3ff00000001]) = 0
ptrace(PTRACE_PEEKDATA, 6896, 0xffffffff77ffaa60, [0]) = -1 EIO (Input/output error)
write(2, "open(0xffffffff77ffaa66, O_RDONL"..., 33) = 33

I don't know whether it will be enough to just mask off
top 32 (33?) bits of every register to make it work.
But before I can test that, I need to find out how strace can figure out that traced process is a 31-bit one.

Comment 5 Denys Vlasenko 2009-04-20 13:03:32 UTC
Created attachment 340340 [details]
Patch to make strace display correct syscall names

Comment 6 Denys Vlasenko 2009-04-20 13:56:35 UTC
Created attachment 340344 [details]
Patch to make strace display correct syscall names, truncate regs to 32 bits, and fix mmap display

Slightly better version. Masking registers with 0xffffffff works and fixed decode of open etc. mmap requires another tweak. fstat is still decoded incorrectly.

Note: this is a gross hack (aka "proof of concept"), it makes strace unable to decode 64-bit apps.

Need to find out how to teach strace to differentiate 31 and 64 bit apps.

Comment 7 Denys Vlasenko 2009-04-20 16:29:17 UTC
Created attachment 340378 [details]
Proposed patch for upstream strace

This patch introduces proper support for 2 personalities in s390x.

It makes strace detect 31-bit processes in a crude way: when it sees invalid 64-bit syscall no. which is a valid 31-bit syscall no., it switches into personality 1. Since there are a lot of such syscalls, it happens quickly,
but before that moment syscalls may be wrongly decoded. Example:

...
open("foobar", O_WRONLY|O_CREAT|O_TRUNC, 077740000000600) = 3
lseek(3, 4393751544832, SEEK_SET)       = 1024
write(3, 0x3ff004604c0, 4393751543814)  = 6
close(3)                                = 0
open("foobar", O_RDONLY)                = 3
  ...and now strace sees "31-bit only" stat64 syscall:
[ Process PID=23321 runs in 31 bit mode. ]
stat64("/dev/root", {st_dev=makedev(0, 17), st_ino=907, st_mode=S_IFBLK|0600, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=0, st_rdev=makedev(253, 0), st_atime=2009/04/20-07:57:26, st_mtime=2009/04/20-07:57:17, st_ctime=2009/04/20-07:57:17}) = 0
fstat64(3, {st_dev=makedev(253, 0), st_ino=3684714, st_mode=S_IFREG|0600, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=16, st_size=1030, st_atime=2009/04/20-12:00:31, st_mtime=2009/04/20-12:22:08, st_ctime=2009/04/20-12:22:08}) = 0
   ... now all syscalls are decoded correctly:
mmap(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0) = 0x77fff000
...

Comment 8 Roland McGrath 2009-04-23 08:15:58 UTC
We have not put priority on biarch support in strace on arch's that never had it before.  We have not had strong customer demand for this, so it does not warrant the effort to work on and maintain the very crufty code required for this in strace.

Instead, on ppc64 we install an strace64 binary in the otherwise mostly 32-bit userland setup, that is just the 64-bit native build of strace for the machine.  Then users pick strace for 32-bit binaries and strace64 for 64-bit binaries.  It's not as good as biarch-supporting strace, but it has been good enough.

This support is trivial to enable for s390x in future builds by adding to strace64_arches in the strace.spec file.  That is plenty in the absence of really active customer demand for complete biarch support on s390x.

Comment 9 Jeff Law 2012-02-06 17:57:43 UTC
I'm in agreement with Roland here.  Installing separate 32 & 64 bit binaries for the s390/s390x architectures is sufficient.  I've added bits to make that happen for rhel7.  We can backport as desired for rhel5 and rhel6.

Comment 10 RHEL Program Management 2012-04-02 13:08:18 UTC
This request was evaluated by Red Hat Product Management for inclusion
in a Red Hat Enterprise Linux release.  Product Management has
requested further review of this request by Red Hat Engineering, for
potential inclusion in a Red Hat Enterprise Linux release for currently
deployed products.  This request is not yet committed for inclusion in
a release.

Comment 20 Jeff Law 2012-05-23 18:29:48 UTC
Michal,
The problem with having "strace.s390x" is that means we can not predict if /usr/bin/strace will trace 32bit or 64bit applications on s390x.  It would depend on the order of installation of strace.s390x vs strace.s390 package as they both want to install /usr/bin/strace.  Worse yet, if we did this for s390, we really should do the same for ppc.  But ppc is not documented as working that way.  It's documented as strace64 to be used for tracing 64bit apps.

While in an ideal world we'd use the solution i outlined in c#17, this is *far* from ideal.

PPC has the exact same problem.  To say this is a mess is an understatement.   Removing the strace.s390x and strace.ppc64 packages brings consistency and predictability to this situation.  "strace" will always trace 32 bit applications and "strace64" will always trace 64 bit applications on the s390 & ppc based platforms.

The upgrade path is already marked as an issue that must be resolved/waived by releng in errata tool.

Comment 21 Michal Nowak 2012-05-24 08:48:33 UTC
(In reply to comment #20)
> Michal,
> The problem with having "strace.s390x" is that means we can not predict if
> /usr/bin/strace will trace 32bit or 64bit applications on s390x.  It would
> depend on the order of installation of strace.s390x vs strace.s390 package
> as they both want to install /usr/bin/strace.

It seems multilib does not work like this. See:

.qa.[root@s390x-5s-v1 ~]# rpm -ivh http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390x/strace-4.5.18-11.el5_8.s390x.rpm 
Retrieving http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390x/strace-4.5.18-11.el5_8.s390x.rpm
Preparing...                ########################################### [100%]
   1:strace                 ########################################### [100%]

.qa.[root@s390x-5s-v1 ~]# rpm -ivh http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390/strace-4.5.18-11.el5_8.s390.rpm 
Retrieving http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390/strace-4.5.18-11.el5_8.s390.rpm
Preparing...                ########################################### [100%]
   1:strace                 ########################################### [100%]

.qa.[root@s390x-5s-v1 ~]# rpmquery strace
strace-4.5.18-11.el5_8.s390x
strace-4.5.18-11.el5_8.s390

.qa.[root@s390x-5s-v1 ~]# file /usr/bin/strace 
/usr/bin/strace: ELF 64-bit MSB executable, IBM S/390, version 1 (SYSV), for GNU/Linux 2.6.9, dynamically linked (uses shared libs), stripped

.qa.[root@s390x-5s-v1 ~]# rpmquery -f /usr/bin/strace 
strace-4.5.18-11.el5_8.s390x
strace-4.5.18-11.el5_8.s390

.qa.[root@s390x-5s-v1 ~]# rpm -e strace.s390 strace.s390x

.qa.[root@s390x-5s-v1 ~]# rpm -ivh http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390/strace-4.5.18-11.el5_8.s390.rpm 
Retrieving http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390/strace-4.5.18-11.el5_8.s390.rpm
Preparing...                ########################################### [100%]
   1:strace                 ########################################### [100%]

.qa.[root@s390x-5s-v1 ~]# file /usr/bin/strace 
/usr/bin/strace: ELF 32-bit MSB executable, IBM S/390, version 1 (SYSV), for GNU/Linux 2.6.9, dynamically linked (uses shared libs), stripped

.qa.[root@s390x-5s-v1 ~]# rpm -ivh http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390x/strace-4.5.18-11.el5_8.s390x.rpm 
Retrieving http://download.devel.redhat.com/brewroot/packages/strace/4.5.18/11.el5_8/s390x/strace-4.5.18-11.el5_8.s390x.rpm
Preparing...                ########################################### [100%]
   1:strace                 ########################################### [100%]

.qa.[root@s390x-5s-v1 ~]# file /usr/bin/strace 
/usr/bin/strace: ELF 64-bit MSB executable, IBM S/390, version 1 (SYSV), for GNU/Linux 2.6.9, dynamically linked (uses shared libs), stripped


But I have to admit I am not sure it changes anything.

So what if strace64.s390x provided "strace.s390x" so the update path is clean?

Comment 22 Jeff Law 2012-06-18 20:09:02 UTC
Michal,
It looks like you were testing with -11 which doesn't make much sense as it didn't have the proper fixes for this issue.  Testing with -17 would be much more useful.

Jeff

Comment 23 Jeff Law 2012-06-19 21:26:53 UTC
I'm looking at another approach for this problem.  It seems to be working if I provision a rhel5 beaker box, but mock seems to be unhappy.  Probably some missing package, but with the log stored in a file within the buildroot and not printed, I have to simply guess what's going on.

I'm going to build a PPC64 mock environment to see if I can track down what build dependencies are missing.

Comment 24 Michal Nowak 2012-06-20 07:50:38 UTC
(In reply to comment #23)
> It seems to be working if
> I provision a rhel5 beaker box, but mock seems to be unhappy.  Probably some
> missing package, but with the log stored in a file within the buildroot and
> not printed, I have to simply guess what's going on.

There's `--verbose' option for Mock printing pretty much everything. If that's what are you looking for.

Comment 27 Jeff Law 2012-07-20 20:26:58 UTC
?!?  Are you using strace32 vs strace64 correct?  It appears to me not.

/* First test, 64bit app using strace, last mmap call is what we want to verify as well as the 3 fstat calls, which all look correct */
[root@ibm-z10-15 ~]# gcc -m64 -o syscall_args64 syscall_args.c
[root@ibm-z10-15 ~]# strace ./syscall_args64 >& out
[root@ibm-z10-15 ~]# grep mmap out
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x20000000000
mmap(NULL, 66755, PROT_READ, MAP_PRIVATE, 3, 0) = 0x20000001000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x20000012000
mmap(0x47bf582000, 1584912, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x47bf582000
mmap(0x47bf6fc000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x179000) = 0x47bf6fc000
mmap(0x47bf701000, 16144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x47bf701000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x20000013000
mmap(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0) = 0x20000001000
[root@ibm-z10-15 ~]# grep fstat !$
grep fstat out
fstat(3, {st_mode=S_IFREG|0644, st_size=66755, ...}) = 0
fstat(3, {st_mode=S_IFREG|0755, st_size=1891640, ...}) = 0
fstat(3, {st_mode=S_IFREG|0600, st_size=1030, ...}) = 0

/* Second test, 64bit app using strace64, should be the same as the first test, again, last mmap call looks good as do all three strace calls*/
[root@ibm-z10-15 ~]# strace64 ./syscall_args64 >& out
[root@ibm-z10-15 ~]# grep mmap out
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x20000000000
mmap(NULL, 66755, PROT_READ, MAP_PRIVATE, 3, 0) = 0x20000001000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x20000012000
mmap(0x47bf582000, 1584912, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x47bf582000
mmap(0x47bf6fc000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x179000) = 0x47bf6fc000
mmap(0x47bf701000, 16144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x47bf701000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x20000013000
mmap(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0) = 0x20000001000
[root@ibm-z10-15 ~]# grep fstat out
fstat(3, {st_mode=S_IFREG|0644, st_size=66755, ...}) = 0
fstat(3, {st_mode=S_IFREG|0755, st_size=1891640, ...}) = 0
fstat(3, {st_mode=S_IFREG|0600, st_size=1030, ...}) = 0

/* Third test, this time 31/32 bit app using strace32 */
[root@ibm-z10-15 ~]# gcc -m31 -o syscall_args31 syscall_args.c
[root@ibm-z10-15 ~]# strace32 ./syscall_args31 >& out
[root@ibm-z10-15 ~]# grep mmap !$
grep mmap out
mmap(NULL, 66755, PROT_READ, MAP_PRIVATE, 3, 0x3) = 0x77fef000
mmap(0x48df8000, 1356636, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0x3) = 0x48df8000
mmap(0x48f3e000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14600000000003) = 0x48f3e000
mmap(0x48f41000, 9052, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0x3) = 0x48f41000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0x3) = 0x77fee000
mmap(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0x3) = 0x77fff000
[root@ibm-z10-15 ~]# grep fstat !$
grep fstat out
fstat64(3, {st_mode=S_IFREG|0644, st_size=66755, ...}) = 0
fstat64(3, {st_mode=S_IFREG|0755, st_size=1622916, ...}) = 0
fstat64(3, {st_mode=S_IFREG|0600, st_size=1030, ...}) = 0


Which also looks fine.

I would hazard a guess you were using the 64bit tracer on the 31/32 bit app.  That's simply not going to work and we never signaled that it would work.  THe s390 and ppc platforms work fundamentally different from x86/x86_64 in that on s390/ppc we are forced to have different strace executables to handle the differences between 31/32 and 64 bit applications.  x86/x86_64 is special because a single strace program can handle both 32 bit and 64bit applications.

Comment 28 Michal Nowak 2012-08-10 10:10:39 UTC
I was using 64bit tracer on 31bit app, because I couldn't find the strace32 package in s390x channel (found it on s390). I noted that with strace32.s390 it works fine. Thanks.

Comment 31 errata-xmlrpc 2013-01-08 07:01:53 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2013-0010.html


Note You need to log in before you can comment on or make changes to this bug.