Make a request to our local webserver:
$ curl -v 127.0.0.1:3000/index.html
* About to connect() to 127.0.0.1 port 3000 (#0)
* Trying 127.0.0.1... connected
* Connected to 127.0.0.1 (127.0.0.1) port 3000 (#0)
> GET /index.html HTTP/1.1
> User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.18 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
> Host: 127.0.0.1:3000
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Type: application/octet-stream
< Accept-Ranges: bytes
< Content-Length: 12
< Date: Tue, 12 Apr 2016 22:42:18 GMT
< Server: foobar
<
hi
* Connection #0 to host 127.0.0.1 left intact
* Closing connection #0
Huh? Why is the server name 'foobar'?
< Server: foobar
What bytes of output does that correspond to?
$ curl -v 127.0.0.1:3000/index.html 2> curl_stderr.txt
hi
$ fold -w1 curl_stderr.txt | cat -n
...
479 S
480 e
481 r
482 v
483 e
484 r
485 :
486
487 f
488 o
489 o
490 b
491 a
492 r
...
We want to know why curl printed 'foobar', which corresponds to STDERR
bytes 486 through 491 (`cat -n` starts counting at 1).
Time to run the DTA tool. Start the server:
$ pin -t follow_io.so -- lighttpd -D -f server.conf
Then re-issue the curl request:
$ pin -t follow_io.so -- curl -v localhost:3000/index.html
Let's check the trace produced for curl:
$ cat out.ldj | ./trace2fs.js -o fs_curl_light.json
$ ./filter_fs.js fs_curl_light.json
...
135 '2:475'
136 '2:478'
137 '2:479'
138 '2:480'
139 '2:481'
140 '2:482'
141 '2:483'
142 '2:484'
143 '2:485'
144 '2:486'
145 '2:487'
146 '2:488'
147 '2:489'
148 '2:490'
149 '2:491'
150 '2:492'
151 '2:493'
152 '2:496'
153 '2:497'
154 '1:0'
155 '1:1'
156 '1:2'
157 '1:3'
158 '1:4'
159 '1:5'
160 '1:6'
...
Column 1 corresponds to an input byte (offset), and column 2 is the I/O it flowed to (fd:offset).
STDERR bytes 486-491 came from the network: it received bytes 144-149 on
a socket, which flowed to 486-491 of STDERR.
Now it's time to see where those came from in the server. After stopping the
server, we check the trace:
$ cat out.ldj | ./trace2fs.js -o fs_light.json
$ ./filter_fs.js fs_light.json
69 '6:144'
70 '6:145'
71 '6:146'
72 '6:147'
73 '6:148'
74 '6:149'
The bytes that lighttpd sent curl that we are interested in are 144-149.
This shows that those bytes came from bytes 69-74 of the config file:
$ cat server.conf
server.document-root = "/tmp/www/"
server.port = 3000
server.tag = "foobar"
$ sed 's/\(.\)/\1\n/g' server.conf | cat -n
...
69 "
70 f
71 o
72 o
73 b
74 a
75 r
76 "
...
Sure enough, bytes 69-74 in the config file correspond to 'foobar'. We
traced those bytes backwards, from STDERR to curl, across the network,
through lighttpd, from the file it read from disk, and finally to the
specific bytes within the file.