xargs and race conditions

I tend to use xargs as a quick paralleling tool. It works great. However, you may notice that due to the multiple processes running, output from one process will overlap with another process creating an unreadable mess.  As an example, I want to ping 6 addresses at the same time. I can do it serially at 1 ping/sec for a total of 6 seconds. Linear growth or O(n):

	$ time for ip in $(< /tmp/pinglist); do ping -c 2 $ip; echo; done
	PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
	64 bytes from 127.0.0.1: icmp_req=1 ttl=64 time=0.115 ms
	64 bytes from 127.0.0.1: icmp_req=2 ttl=64 time=0.031 ms
	--- 127.0.0.1 ping statistics ---
	2 packets transmitted, 2 received, 0% packet loss, time 999ms
	rtt min/avg/max/mdev = 0.031/0.073/0.115/0.042 ms
	PING 127.0.0.2 (127.0.0.2) 56(84) bytes of data.
	64 bytes from 127.0.0.2: icmp_req=1 ttl=64 time=0.089 ms
	64 bytes from 127.0.0.2: icmp_req=2 ttl=64 time=0.033 ms
	--- 127.0.0.2 ping statistics ---
	2 packets transmitted, 2 received, 0% packet loss, time 999ms
	rtt min/avg/max/mdev = 0.033/0.061/0.089/0.028 ms
	PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data.
	64 bytes from 192.168.122.1: icmp_req=1 ttl=64 time=0.031 ms
	64 bytes from 192.168.122.1: icmp_req=2 ttl=64 time=0.077 ms
	--- 192.168.122.1 ping statistics ---
	2 packets transmitted, 2 received, 0% packet loss, time 1001ms
	rtt min/avg/max/mdev = 0.031/0.054/0.077/0.023 ms
	PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
	64 bytes from 192.168.100.1: icmp_req=1 ttl=64 time=0.076 ms
	64 bytes from 192.168.100.1: icmp_req=2 ttl=64 time=0.075 ms
	--- 192.168.100.1 ping statistics ---
	2 packets transmitted, 2 received, 0% packet loss, time 999ms
	rtt min/avg/max/mdev = 0.075/0.075/0.076/0.008 ms
	PING 192.168.127.120 (192.168.127.120) 56(84) bytes of data.
	64 bytes from 192.168.127.120: icmp_req=1 ttl=64 time=0.028 ms
	64 bytes from 192.168.127.120: icmp_req=2 ttl=64 time=0.076 ms
	--- 192.168.127.120 ping statistics ---
	2 packets transmitted, 2 received, 0% packet loss, time 999ms
	rtt min/avg/max/mdev = 0.028/0.052/0.076/0.024 ms
	PING 10.10.10.50 (10.10.10.50) 56(84) bytes of data.
	From 41.223.35.4 icmp_seq=1 Time to live exceeded
	From 41.223.35.4 icmp_seq=2 Time to live exceeded
	--- 10.10.10.50 ping statistics ---
	2 packets transmitted, 0 received, +2 errors, 100% packet loss, time 1001ms
	real 0m6.067s
	user 0m0.004s
	sys 0m0.004s

view raw gistfile1.sh hosted with ❤ by GitHub

How do you get around it? We can run everything in parallel using xargs

	$ time cat /tmp/pinglist | xargs --max-args=1 --max-procs=10 -IZ ping -c 1 Z
	PING 127.0.0.2 (127.0.0.2) 56(84) bytes of data.
	PING 192.168.127.120 (192.168.127.120) 56(84) bytes of data.
	PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data.
	PING 10.10.10.50 (10.10.10.50) 56(84) bytes of data.
	64 bytes from 192.168.127.120: icmp_req=1 ttl=64 time=0.043 ms
	--- 192.168.127.120 ping statistics ---
	64 bytes from 192.168.122.1: icmp_req=1 ttl=64 time=0.034 ms
	64 bytes from 127.0.0.2: icmp_req=1 ttl=64 time=0.043 ms
	PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
	--- 192.168.122.1 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.034/0.034/0.034/0.000 ms
	PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	--- 127.0.0.2 ping statistics ---
	64 bytes from 192.168.100.1: icmp_req=1 ttl=64 time=0.074 ms
	rtt min/avg/max/mdev = 0.043/0.043/0.043/0.000 ms
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	64 bytes from 127.0.0.1: icmp_req=1 ttl=64 time=0.077 ms
	--- 127.0.0.1 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.077/0.077/0.077/0.000 ms
	rtt min/avg/max/mdev = 0.043/0.043/0.043/0.000 ms
	--- 192.168.100.1 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.074/0.074/0.074/0.000 ms
	From 41.223.35.4 icmp_seq=1 Time to live exceeded
	--- 10.10.10.50 ping statistics ---
	1 packets transmitted, 0 received, +1 errors, 100% packet loss, time 0ms
	real 0m0.047s
	user 0m0.000s
	sys 0m0.000s

view raw gistfile1.sh hosted with ❤ by GitHub

Note that the time taken is markedly reduced but.. Output from each process is interleaved with other commands.

How do you get around that? Well, locking.. Luckily, the shell has a nifty locking utility that is just perfect for this. Enter flock..

	$ time cat /tmp/pinglist | xargs --max-args=1 --max-procs=10 -IZ flock -x /tmp/pinglist -c "ping -c 1 Z; echo"
	PING 127.0.0.1 (127.0.0.1) 56(84) bytes of data.
	64 bytes from 127.0.0.1: icmp_req=1 ttl=64 time=0.096 ms
	--- 127.0.0.1 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.096/0.096/0.096/0.000 ms
	PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data.
	64 bytes from 192.168.122.1: icmp_req=1 ttl=64 time=0.091 ms
	--- 192.168.122.1 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.091/0.091/0.091/0.000 ms
	PING 192.168.127.120 (192.168.127.120) 56(84) bytes of data.
	64 bytes from 192.168.127.120: icmp_req=1 ttl=64 time=0.105 ms
	--- 192.168.127.120 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.105/0.105/0.105/0.000 ms
	PING 127.0.0.2 (127.0.0.2) 56(84) bytes of data.
	64 bytes from 127.0.0.2: icmp_req=1 ttl=64 time=0.126 ms
	--- 127.0.0.2 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.126/0.126/0.126/0.000 ms
	PING 192.168.100.1 (192.168.100.1) 56(84) bytes of data.
	64 bytes from 192.168.100.1: icmp_req=1 ttl=64 time=0.089 ms
	--- 192.168.100.1 ping statistics ---
	1 packets transmitted, 1 received, 0% packet loss, time 0ms
	rtt min/avg/max/mdev = 0.089/0.089/0.089/0.000 ms
	PING 10.10.10.50 (10.10.10.50) 56(84) bytes of data.
	From 41.223.35.4 icmp_seq=1 Time to live exceeded
	--- 10.10.10.50 ping statistics ---
	1 packets transmitted, 0 received, +1 errors, 100% packet loss, time 0ms
	real 0m0.105s
	user 0m0.008s
	sys 0m0.012s

view raw gistfile1.txt hosted with ❤ by GitHub

Still as fast and neater. Man flock for more awesomeness. The flock utility uses the flock syscall to acquire a lock on a file structure. In the example above, I show that you can use a file that you are reading as a lock file. flock doesn't prevent you from conducting other file ops on your fd.