1

I have output captured by following command:

$ strace -f -e trace=process,socketpair,open,close,dup,dup2,read,write -o rsync.log rsync -avcz --progress src/ dst/

it is a bit long so I've uploaded it here. Now I want to do some analysis on this file.

Following output shows spawned processes/threads using clone syscall:

# SPAWNED PROCESSES/THREADS
$ grep 'clone(' rsync.log | awk '{print $1 " -> " $NF}'
1399 -> 1400
1400 -> 1401

Following output shows that most times data were writen to file descriptor with number 4:

# PID, FD, NO OF CALLING WRITE SYSCALL
$ cat <(grep 'write(' rsync.log | egrep -v 'unfinished|resumed') <(paste <(grep write rsync.log | grep unfinished) <(grep write rsync.log | grep resumed)) | cut -d',' -f1 | sed 's%write(%%' | awk '{a[$0]++}END{print "PID  FD COUNT"; for(i in a){print i " " a[i]}}'
PID  FD COUNT
1399  4 1622
1400  1 7
1401  3 307
1401  4 7
1399  1 15

Following output shows that the 4 descriptor was never opened using open syscall (1 is STDOUT so I assume no need to open this FD):

# LIST OF FILE DESCRIPTORS THAT WAS OPEN
$ grep 'open(' rsync.log | awk 'BEGIN {FS=" = "} {print $NF}' | grep '^[0-9]\+$' | sort | uniq
0
3
6

Two questions:

I. If 4 descriptor was not opened where does those data go, and how is possible that rsync worked as expected?:

$ grep 'write(4' rsync.log | head
1399  write(4, "\37\0\0\0", 4 <unfinished ...>
1399  write(4, "I\0\0\7\5(\1.\0\0\0W}%i\360\220\261\177\21\370A\0\0\0\203\347\6vbox"..., 77 <unfinished ...>
1401  write(4, "\4\0\0\7\376\377\377\377", 8) = 8
1399  write(4, "\177\301\0\7\3\n\200\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\177\377\354\226C\214.\0\260"..., 49539) = 49539
1399  write(4, "\2\301\0\7\177\377a\353\35\2433\1\332m\301\330\266\315\216\3557\352\330\266m\333\366\33\333\266;v"..., 49414) = 49414
1399  write(4, "\21\302\0\7\177\377\236mTNG\356\304\376u\237\214\275\310\300*\317\264\221W\372\340\307\36\345%\330"..., 49685 <unfinished ...>
1399  write(4, "\360\300\0\7\177\377\27W\357\24$\f\23,\v\216\355\371\306\266m\333\266m\333\266m\333\266m\333\266"..., 49396 <unfinished ...>
1399  write(4, "\223\301\0\7\177\377D\214# D\304\2\25xA\fY\310U\201Q*e\25\235\20\213\v\320~\331"..., 49559 <unfinished ...>
1399  write(4, "\370\300\0\7\177\377l\275cs.\0\27$\30\334\330\266}c\333\266m\333\266\235<\261m\333\266m"..., 49404 <unfinished ...>
1399  write(4, "\20\301\0\7\177\377\25\255\252Q\223\340\244w3\247\252\322Z\235\310\2424g\330\274\354\3150\237B\26"..., 49428) = 49428

II. Can I somehow also get data (corresponding lines) that were transferred between processes e.g.: from 1399 to 1400 or from 1399 to 1401 etc. (if there are any)?

Thank you

  • 2
    You'll find 3 and 4 created by socketpair(PF_LOCAL, SOCK_STREAM, 0, [3, 4]) which return 2 file descriptors in the last arg. – meuh Jun 22 '16 at 17:20
0

Data written to a file descriptor that was never opened does not go anywhere. The write system call fails with EBADF (bad file descriptor).

But as meuh remarked, open is not the only way to open a file. There's also pipe to create a pair of pipe ends, socketpair to create a pair of sockets that talk to each other, socket and accept to create sockets that talk to a remote address, etc. (Not to mention file types that you can't write to, such as directories, inotify event queues, etc.)

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.