Category Archives: MacOS

When all debugging routes have failed: network scans and/or code tracing

In the world of car, bike and motorbike mechanics there is a versatile tool which is something of a last resort: the vice-grips (sometimes referred to as the bodger’s tool, because of people’s tendency to shear bolts with them).  In the world of operating systems there are two tools I have found to be like vice-grips, but not potentially harmful: Network scanning and code tracing.

Network scanning

Most operating systems have a way of scanning the network:

  • Linux: tcpdump, Wireshark
  • Darwin (MacOS): tcpdump, Wireshark
  • Solaris: snoop, tcpdump, Wireshark
  • Windows: Wireshark (there is also a version of tcpdump for Windows)

So, why is network scanning useful?  Well consider the situation where you have installed the monitoring software, Xymon.  The server is already working and most of the clients are responding, but the server isn’t receiving data from one of the clients.  Xymon uses port 1984 so you can check to watch the traffic going to and from the server:

[root@host1 etc]# tcpdump port 1984
tcpdump: verbose output suppressed, use -v or for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
15:08:00.857457 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: S 1387852790:1387852790(0) win 5840 <mss 1460,sackOK,timestamp 119364978 0,nop,wscale 2>
15:08:00.864380 IP xymonserver.linuxtech.ie.1984 > host2.linuxtech.ie.32821: S 3491816971:3491816971(0) ack 1387852791 win 5792 <mss 1460,sackOK,timestamp 8108268 119364978,nop,wscale 0>
15:08:00.864553 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: . ack 1 win 1460 <nop,nop,timestamp 119364993 8108268>15:08:00.865187 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: . 1:1449(1448) ack 1 win 1460 <nop,nop,timestamp 119364993 8108268>
15:08:00.865419 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: . 1449:2897(1448) ack 1 win 1460 <nop,nop,timestamp 119364994 8108268>
15:08:00.867342 IP xymonserver.linuxtech.ie.1984 > host2.linuxtech.ie.32821: . ack 1449 win 8688 <nop,nop,timestamp 8108268 119364993>
15:08:00.867486 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: P 2897:4345(1448) ack 1 win 1460 <nop,nop,timestamp 119364996 8108268>
15:08:00.867684 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: . 4345:5793(1448) ack 1 win 1460 <nop,nop,timestamp 119364996 8108268>
15:08:00.868361 IP xymonserver.linuxtech.ie.1984 > host2.linuxtech.ie.32821: . ack 2897 win 11584 <nop,nop,timestamp 8108268 119364994>
15:08:00.869032 IP host2.linuxtech.ie.32821 > xymonserver.linuxtech.ie.1984: . 5793:7241(1448) ack 1 win 1460 <nop,nop,timestamp 119364997 8108268>

So in this example the traffic is going from host1 to the Xymon server’s port, so it looks like Xymon is receiving the data.  What’s wrong is that DNS knows this host as host2.linuxtech.ie not host1 so Xymon doesn’t realise it’s receiving data for host1.  So there are a few solutions, for example you can configure host1 to explicitly tell Xymon that it is host1.

Another example was when I was trying to get some commercial software working in a firewall, where the DNS servers were locked down to resolve only addresses we allowed them too.  The documentation said that it would need to be able to resolve, say, swcheck.sweet.ie, but it still wasn’t working.  So gave it just one DNS server and watched what addresses it asked for and sure enough it was asking for swcheck.sweet.ie, but also for, say, dwnld.sweet.ie.  So I needed to make sure that was added to the list of addresses it could resolve.

Another nice thing about tcpdump in particular is its data can be saved to a file which can be imported into Wireshark on another server.  This is very handy if you have a sensitive host where you can’t run the GUI of Wireshark.

There’s a lot to this subject but I hope this helps.

Code tracing

When I say code tracing, I mean tracing system and library calls.  Most operating systems have a way to do this:

  • Linux: strace, ltrace
  • Darwin: dtruss, dtrace (both require root/sudo)
  • Solaris: truss, dtrace
  • Windows: (none that I can find)

In my opinion Linux has the best implementation of code tracing.  (Darwin/FreeBSD/Solaris’s DTrace  and Linux’s SystemTap are exceedingly powerful, but beyond the scope of this post.)  Suppose you want to see what environment variables a program is using:

[admin2@centos6 ~]$ ltrace -e getenv -o /tmp/tmp.adm2.ltrace vi
[admin2@centos6 ~]$ ls -l /tmp/tmp.adm2.ltrace
-rw-rw-r--. 1 admin2 admin2 1777 Oct 2 05:08 /tmp/tmp.adm2.ltrace
[admin2@centos6 ~]$ vim /tmp/tmp.adm2.ltrace
[admin2@centos6 ~]$ cat /tmp/tmp.adm2.ltrace
(0, 0, 0, 0x7fcf69b6d918, 88) = 0x3b6ec21160
getenv("HOME") = "/home/admin2"
getenv("VIM_POSIX") = NULL
getenv("SHELL") = "/bin/bash"
getenv("TMPDIR") = NULL
getenv("TEMP") = NULL
getenv("TMP") = NULL
getenv("VIMRUNTIME") = NULL
getenv("VIM") = NULL
getenv("VIM") = NULL
getenv("VIMRUNTIME") = "/usr/share/vim/vim72"
getenv("VIM") = "/usr/share/vim"
getenv("TERM") = "xterm"
getenv("COLORFGBG") = NULL
getenv("VIMINIT") = NULL
getenv("HOME") = "/home/admin2"
getenv("EXINIT") = NULL
getenv("HOME") = "/home/admin2"
(0x3b6ec21160, 0, 0, 0x3b6ec21160, 0) = 140608
(0, 0, 0, 3, 0x963cf85) = 0x3b6ec21160
+++ exited (status 0) +++
[admin2@centos6 ~]$

So consider you have a program which is reading a configuration file from somewhere but you can’t figure out where.  The best thing is to check its open() (which will cover fopen() too), stat() and lstat().  stat and lstat check existence, permissions etc. of a closed file.  So this example uses vi (even though the esteemed Meneer Bram Moolenaar has so extensively documented vim this is a redundant example):

[admin2@centos6 ~]$ strace -e stat,lstat,open -o /tmp/tmp.adm2.strace vi
[admin2@centos6 ~]$ cat /tmp/tmp.adm2.strace
open("/etc/ld.so.cache", O_RDONLY) = 3
open("/lib64/libm.so.6", O_RDONLY) = 3
open("/lib64/libselinux.so.1", O_RDONLY) = 3
open("/lib64/libncurses.so.5", O_RDONLY) = 3
open("/lib64/libacl.so.1", O_RDONLY) = 3
open("/lib64/libc.so.6", O_RDONLY) = 3
open("/lib64/libtinfo.so.5", O_RDONLY) = 3
open("/lib64/libdl.so.2", O_RDONLY) = 3
open("/lib64/libattr.so.1", O_RDONLY) = 3
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
stat("/usr/share/vim/vim72", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/usr/share/vim", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/home/admin2/.terminfo", 0x7fff4b7dbb00) = -1 ENOENT (No such file or directory)
stat("/etc/terminfo", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat("/usr/share/terminfo", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
open("/usr/share/terminfo/x/xterm", O_RDONLY) = 3
open(".", O_RDONLY) = 3
stat("/etc/virc", {st_mode=S_IFREG|0644, st_size=1962, ...}) = 0
open("/etc/virc", O_RDONLY) = 3
open(".", O_RDONLY) = 3
stat("/home/admin2/.vimrc", 0x7fff4b7dd460) = -1 ENOENT (No such file or directory)
open("/home/admin2/.vimrc", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/home/admin2/_vimrc", O_RDONLY) = -1 ENOENT (No such file or directory)
open(".", O_RDONLY) = 3
stat("/home/admin2/.exrc", 0x7fff4b7dd460) = -1 ENOENT (No such file or directory)
open("/home/admin2/.exrc", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/etc/nsswitch.conf", O_RDONLY) = 3
open("/etc/ld.so.cache", O_RDONLY) = 3
open("/lib64/libnss_files.so.2", O_RDONLY) = 3
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 3
[admin2@centos6 ~]$

It is my belief that the true mastery of a skill is to take from the specific to the general and back to the specific again.  So these are specific examples of using these tools, which I hope gives you an insight into the general principles so you can apply them to your specific problems.

 

Mac OS temporary storage area for App Store installs

Mac OS uses a temporary storage area used for downloading apps before installing.  Apple made it very easy to find in Snow Leopard:

~/Library/Application Support/AppStore

Where ~ is your home directory.

However on Lion (and Mountain Lion) it decided to get creative, so trying to find the temporary files is a little trickier.  This is how I found the temporary storage for a download of iPhoto:

vger.local:~(84)+>- date ; sudo find /var/folders -name \*.pkg -mtime -1 -ls
Sat 22 Sep 2012 21:12:02 IST
6021879 50368 -rw-r--r-- 1 pkearns staff 25788416 22 Sep 21:12 /var/folders/n8/fcgpxxl55dgdwz6fphbd5f_40000gn/C/com.apple.appstore/408981381/mzm.ivjumeji.pkg
vger.local:~(85)+>- sudo ls -l /var/folders/n8/fcgpxxl55dgdwz6fphbd5f_40000gn/C/com.apple.appstore/408981381/
total 57368
-rw-r--r-- 1 pkearns staff 410345 22 Sep 16:00 flyingIcon
-rw-r--r-- 1 pkearns staff 28934144 22 Sep 21:12 mzm.ivjumeji.pkg
-rw-r--r-- 1 pkearns staff 13466 22 Sep 15:59 preflight.pfpkg
-rw-r--r-- 1 pkearns staff 4642 22 Sep 15:59 receipt
vger.local:~(86)+>-

It will be there only during the download.

Tracking what process is generating network traffic

Every now and again I’ve had situations where I see Internet traffic which doesn’t correspond to any obvious activity I’ve initiated.  Well on Linux and Unix (and hence MacOS) it’s easy enough to track down the offending process.

(The commands tcpdump and lsof must be run as root or under sudo.)  Doing a tcpdump (snoop in Solaris) I could see the traffic and it was obvious which was the source/destintation causing most of the traffic:

mistral:~(1)+>- tcpdump
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on en0, link-type EN10MB (Ethernet), capture size 65535 bytes
23:01:28.320299 IP 193.120.121.160.http > 10.1.1.183.49977: Flags [.], seq 2435402503:2435403911, ack 3052965256, win 4692, options [nop,nop,TS val 1326515797 ecr 324351108], length 1408
23:01:28.320923 IP 193.120.121.160.http > 10.1.1.183.49977: Flags [.], seq 1408:2816, ack 1, win 4692, options [nop,nop,TS val 1326515797 ecr 324351108], length 1408
23:01:28.321015 IP 10.1.1.183.49977 > 193.120.121.160.http: Flags [.], ack 2816, win 8104, options [nop,nop,TS val 324351161 ecr 1326515797], length 0
23:01:28.333327 IP 193.120.121.160.http > 10.1.1.183.49977: Flags [.], seq 2816:4224, ack 1, win 4692, options [nop,nop,TS val 1326515804 ecr 324351108], length 1408
[...]
23:01:32.717541 IP 10.1.1.183.49977 > 193.120.121.160.http: Flags [.], ack 767360, win 8104, options [nop,nop,TS val 324355362 ecr 1326520067], length 0
23:01:32.718204 IP 193.120.121.160.http > 10.1.1.183.49977: Flags [.], seq 767360:768768, ack 1, win 4692, options [nop,nop,TS val 1326520068 ecr 324355189], length 1408
23:01:32.718325 IP 10.1.1.183.49977 > 193.120.121.160.http: Flags [.], ack 768768, win 8192, options [nop,nop,TS val 324355363 ecr 1326520068], length 0
23:01:32.875095 IP 193.120.121.160.http > 10.1.1.183.49977: Flags [.], seq 768768:770176, ack 1, win 4692, options [nop,nop,TS val 1326520238 ecr 324355191], length 1408
^C
970 packets captured
1004 packets received by filter
0 packets dropped by kernel
mistral:~(2)+>-

In this example my local address is 10.1.1.183 and it can also be seen that the port of process which is talking to the Internet is 49977.  I used lsof to find out what process had that port open, and then used ps to show me the details of the process:

mistral:-(2)+>- lsof -i TCP:49977
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
SoftwareU 11684 _softwareupdate 15u IPv4 0x39d5096a0cd02d61 0t0 TCP 10.1.1.183:49977->193.120.121.160:http (ESTABLISHED)
mistral:~(3)+>- ps -lfp 11684
 UID PID PPID F CPU PRI NI SZ RSS WCHAN S ADDR TTY TIME CMD STIME
 200 11684 1 4004 0 63 0 3672308 135516 - Ss 0 ?? 0:28.45 /System/Library/ 10:58pm
mistral:~(4)+>- ps -fp 11684
 UID PID PPID C STIME TTY TIME CMD
 200 11684 1 0 10:58pm ?? 0:29.15 /System/Library/CoreServices/Software Update.app/Contents/Resources/SoftwareUpdateCheck -Check YES
mistral:~(5)+>- id
uid=0(root) gid=0(wheel) groups=0(wheel),404(com.apple.sharepoint.group.2),401(com.apple.access_screensharing),1(daemon),2(kmem),3(sys),4(tty),5(operator),8(procview),9(procmod),12(everyone),20(staff),29(certusers),33(_appstore),61(localaccounts),80(admin),98(_lpadmin),100(_lpoperator),204(_developer),403(com.apple.access_ssh)
mistral:~(6)+>-

And that’s it, the process was the automatic OS updater.