Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1342669

Summary: strace "-eread=<fd list>" / "-ewrite=<fd list>" are mutually exclusive but likely shouldn't be
Product: Red Hat Enterprise Linux 6 Reporter: Frank Hirtz <fhirtz>
Component: straceAssignee: DJ Delorie <dj>
Status: CLOSED ERRATA QA Contact: Michal Kolar <mkolar>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.7CC: bgollahe, cww, dj, law, ldv, mcermak, mkolar, mnewsome, nobody+bgollahe, ohudlick
Target Milestone: rcFlags: bgollahe: needinfo+
Target Release: ---   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: strace-4.8-11.el6 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-03-21 10:24:54 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1269194    

Description Frank Hirtz 2016-06-03 20:21:33 UTC
Description of problem:
For strace, the documentation says:

OPTIONS
[ ... ]
       -eread=set  Perform a full hexidecimal and ascii dump of all the
                   data read from file descriptors listed in the speci-
                   fied set.  For example, to see all input activity on
                   file descriptors 3 and 5 use read=3,5.

       -ewrite=set Perform a full hexidecimal and ascii dump of all the
                   data written to file descriptors listed in the spec-
                   ified set.  For example, to see all output  activity
                   on file descriptors 3 and 5 use read=3,5.

Specifying -ewrite=... alone:

 strace -etrace=read,write -ewrite=0,1 dd if=/dev/urandom of=/dev/zero bs=256 count=1
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\6\0\0\0\0\0\0"..., 832) = 832
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240!\0\0\0\0\0\0"..., 832) = 832
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\356\1\0\0\0\0\0"..., 832) = 832
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000^\0\0\0\0\0\0"..., 832) = 832
read(0, "\200&\31\314\354\204\233\31\257\337\220\36\2248\177Kd\6\0\2152\266\376\274J\032242\355\316\302"..., 256) = 256
write(1, "\200&\31\314\354\204\233\31\257\337\220\36\2248\177Kd\6\0\2152\266\376\274J\032242\355\316\302"..., 256) = 256
 | 00000  80 26 19 cc ec 84 9b 19  af df 90 1e 94 38 7f 4b  .&...........8.K |
 | 00010  64 06 00 8d 32 b6 fe bc  4a 1a 32 34 32 ed ce c2  d...2...J.242... |
 | 00020  75 e8 76 e5 72 f6 12 8e  85 e2 3e 32 33 42 ad e9  u.v.r.....>23B.. |
 | 00030  5c 90 40 48 0b dc 38 fb  2c a1 4a c4 f9 a7 04 65  \.@H..8.,.J....e |
 | 00040  e2 91 75 6f 27 95 65 29  61 2d 33 5e c7 a3 81 a0  ..uo'.e)a-3^.... |
 | 00050  e8 9d aa ae 3d 86 15 04  11 16 01 1f 91 b8 d3 bb  ....=........... |
 | 00060  3a 36 d7 e6 29 f2 de 46  e7 28 bf 57 0d 8a 39 73  :6..)..F.(.W..9s |
 | 00070  9b 05 b1 13 85 d4 dc a9  2d 4a 55 44 63 fe cc 3b  ........-JUDc..; |
 | 00080  11 1b 8e 87 5f 64 bc 7d  16 e7 f1 f0 2c e5 61 0e  ...._d.}....,.a. |
 | 00090  d7 64 4e b4 23 ee a4 2b  41 bc 3e f8 40 74 c1 c4  .dN.#..+A.>.@t.. |
 | 000a0  98 fe 73 3e 3e 95 9d 97  5c f3 fd 25 37 f1 3d dc  ..s>>...\..%7.=. |
 | 000b0  91 ee bb 60 d5 c0 43 24  76 16 60 4b 4a 43 eb f4  ...`..C$v.`KJC.. |
 | 000c0  ba 28 b9 c9 cd d8 ae 58  03 ec d9 fa d5 d9 d3 de  .(.....X........ |
 | 000d0  08 08 c8 f7 7d b1 2f 5b  5c 00 10 be 5b 71 31 b0  ....}./[\...[q1. |
 | 000e0  31 48 58 b1 6b b7 ca 0c  fa 93 ee 6d de 28 f0 1e  1HX.k......m.(.. |
 | 000f0  68 09 03 6f 10 ca 4e e1  94 92 5f e2 4d 28 70 1d  h..o..N..._.M(p. |
[ ... ]

Specifying _both_ -eread=.../-ewrite=... "swallows" the -ewrite=... though:

$ strace -etrace=read,write -ewrite=0,1 -eread=0,1 dd if=/dev/urandom of=/dev/zero bs=256 count=1
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\6\0\0\0\0\0\0"..., 832) = 832
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240!\0\0\0\0\0\0"..., 832) = 832
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\356\1\0\0\0\0\0"..., 832) = 832
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000^\0\0\0\0\0\0"..., 832) = 832
read(0, "@ D\215>%P\253\351\251\365T\336\360t\203\346R\323\346\312\310P\266\6\241\332\1\353\346>\265"..., 256) = 256
 | 00000  40 20 44 8d 3e 25 50 ab  e9 a9 f5 54 de f0 74 83  @ D.>%P....T..t. |
 | 00010  e6 52 d3 e6 ca c8 50 b6  06 a1 da 01 eb e6 3e b5  .R....P.......>. |
 | 00020  45 d2 eb 7d 5f 97 50 60  74 c8 e0 34 ce f4 23 e7  E..}_.P`t..4..#. |
 | 00030  6f ad 4a ec 16 c0 4e 1f  96 aa 32 48 50 cd 03 62  o.J...N...2HP..b |
 | 00040  7f 9b 1f 57 20 e1 e0 41  87 e7 42 82 6c 32 2e 69  ...W ..A..B.l2.i |
 | 00050  f3 c0 fb 9a 4b d1 27 c2  b8 2c c3 df 18 02 65 eb  ....K.'..,....e. |
 | 00060  37 5a 02 57 b4 0f 87 b3  dc 9b fa 03 c5 2a 6d a7  7Z.W.........*m. |
 | 00070  bb 2c d0 af 1e 6b f8 14  18 48 a3 4a 7e fa 59 a3  .,...k...H.J~.Y. |
 | 00080  50 2d 39 8e a1 7b 71 3d  9b 71 6e e4 07 6f 24 6b  P-9..{q=.qn..o$k |
 | 00090  3f 87 38 de 86 bd d7 4a  3a 19 a2 45 8d 09 08 07  ?.8....J:..E.... |
 | 000a0  10 db f1 5f fe 5a 09 d1  bd fd 94 0f 06 66 70 70  ..._.Z.......fpp |
 | 000b0  ad f1 df 08 21 65 15 0e  f4 b2 26 26 c0 df 1e 75  ....!e....&&...u |
 | 000c0  98 86 3f 1c bf b8 64 aa  48 5f b0 f1 9c 3c 3b 21  ..?...d.H_...<;! |
 | 000d0  b2 11 71 ea e9 70 79 a3  79 02 d5 ce 25 c3 6f 44  ..q..py.y...%.oD |
 | 000e0  00 4b 09 97 b0 0b 52 5b  6c 8a 3f 98 13 20 dd 5a  .K....R[l.?.. .Z |
 | 000f0  44 ba 27 aa 39 5f 18 b1  43 13 aa 1c 59 3e f5 d8  D.'.9_..C...Y>.. |
write(1, "@ D\215>%P\253\351\251\365T\336\360t\203\346R\323\346\312\310P\266\6\241\332\1\353\346>\265"..., 256) = 256
[ ... ]

When specifying both a verbose read/write fd list to strace, I expect to see full output for both reads and writes.

Where are you experiencing the behavior?  What environment?

RHEL6.

When does the behavior occur? Frequently?  Repeatedly?   At certain times?

100% repeatable.

What information can you provide around timeframes and urgency?

<snip>
The bug is in syscall.c, function dumpio():

   2459 static void
   2460 dumpio(struct tcb *tcp)
   2461 {
   2462     int (*func)();
   2463 
   2464     if (syserror(tcp))
   2465         return;
   2466     if ((unsigned long) tcp->u_arg[0] >= num_quals)
   2467         return;
   2468     func = tcp->s_ent->sys_func;
   2469     if (func == printargs)
   2470         return;
   2471     if (qual_flags[tcp->u_arg[0]] & QUAL_READ) {
   2472         if (func == sys_read ||
   2473             func == sys_pread ||
   2474             func == sys_recv ||
   2475             func == sys_recvfrom)
   2476             dumpstr(tcp, tcp->u_arg[1], tcp->u_rval);
   2477         else if (func == sys_readv)
   2478             dumpiov(tcp, tcp->u_arg[2], tcp->u_arg[1]);
   2479         return;
   2480     }
   2481     if (qual_flags[tcp->u_arg[0]] & QUAL_WRITE) {
   2482         if (func == sys_write ||
   2483             func == sys_pwrite ||
   2484             func == sys_send ||
   2485             func == sys_sendto)
   2486             dumpstr(tcp, tcp->u_arg[1], tcp->u_arg[2]);
   2487         else if (func == sys_writev)
   2488             dumpiov(tcp, tcp->u_arg[2], tcp->u_arg[1]);
   2489         return;
   2490     }
   2491 }
</snip>

Remove these two "return" instructions and it'll do the right thing.

The parsing was changed a bit in newer strace versions, and this case is handled properly so we're good on that front:

<snip>
[fmhirtz@x1 ~]$ strace -etrace=read,write -ewrite=0,1 -eread=0,1 dd if=/dev/urandom of=/dev/zero bs=256 count=1
read(4, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\6\2\0\0\0\0\0"..., 832) = 832
read(0, "\245\264\375\0278\256r\16\r\253L\373I\223\251\265\334\203\341\347\1\21\351)\33{\276!hI+\244"..., 256) = 256
 | 00000  a5 b4 fd 17 38 ae 72 0e  0d ab 4c fb 49 93 a9 b5  ....8.r...L.I... |
 | 00010  dc 83 e1 e7 01 11 e9 29  1b 7b be 21 68 49 2b a4  .......).{.!hI+. |
 | 00020  1a fe 23 78 ca f6 ad c1  4c 36 90 1a 12 c6 aa ec  ..#x....L6...... |
<snip>
 | 000d0  4c e5 d0 79 17 bc 9f a8  74 64 52 4d ab 9d 30 c6  L..y....tdRM..0. |
 | 000e0  c0 f5 9a 0c 9e bf 73 e1  c6 a0 7f 22 c4 a4 eb d0  ......s....".... |
 | 000f0  fb 81 9b 06 81 aa a3 19  9c 66 f1 69 17 c7 88 99  .........f.i.... |
write(1, "\245\264\375\0278\256r\16\r\253L\373I\223\251\265\334\203\341\347\1\21\351)\33{\276!hI+\244"..., 256) = 256
 | 00000  a5 b4 fd 17 38 ae 72 0e  0d ab 4c fb 49 93 a9 b5  ....8.r...L.I... |
 | 00010  dc 83 e1 e7 01 11 e9 29  1b 7b be 21 68 49 2b a4  .......).{.!hI+. |
 | 00020  1a fe 23 78 ca f6 ad c1  4c 36 90 1a 12 c6 aa ec  ..#x....L6...... |
<snip>
 | 00b90  36 32 30 0a 74 75 72 6b  69 73 68 20 20 20 20 20  620.turkish      |
 | 00ba0  20 20 20 20 74 72 5f 54  52 2e 49 53 4f 2d 38 38      tr_TR.ISO-88 |
 | 00bb0  35 39 2d 39 0a                                    59-9.            |
read(0, "", 4096)                       = 0
write(2, "1+0 records in\n1+0 records out\n", 311+0 records in
1+0 records out
) = 31
write(2, "256 bytes (256 B) copied", 24256 bytes (256 B) copied) = 24
write(2, ", 0.000975011 s, 263 kB/s\n", 26, 0.000975011 s, 263 kB/s
) = 26
+++ exited with 0 +++
</snip>

Comment 2 Dmitry V. Levin 2016-07-22 22:17:39 UTC
JFYI, this was fixed upstream by commit v4.10~147.

Comment 11 errata-xmlrpc 2017-03-21 10:24:54 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.

https://rhn.redhat.com/errata/RHBA-2017-0668.html