Featured Sysadmin zcat compressed access log processing benchmarks

I am working on a new zcat compressed access log benchmarking routine to eventually be added to my centminmodbench.sh script. If you use log analysis tools like ngxtop, then you would need to use zcat to inspect and pipe to ngxtop many gz compressed Nginx access logs using zcat. So knowing how well your server can perform for zcat operations is important

zcat is basically same as cat command just it works on gzip compressed files instead of uncompressed files.

zcat benchmark code

• The benchmarking code is currently posted on a standalone Github repo at https://github.com/centminmod/fake-access-log which outlines both manual and scripted test.sh methods of running zcat and multi-threaded pzcat (using pigz instead of gzip) to test how fast your server is able inspect a set of 3x gzip compressed access.log files which each contains 1 million lines of fake dummy generated HTTP requests and using wc command calculate the number of lines within that gzip compressed access.log.
• This will test the speed of the cpu in how fast it can uncompress on the fly the gzip compressed access logs and calculate the number of lines contained within the log files combined which should result in 3 million log lines calculated. It also tests the speed of your underlying disk system as well.

To test for yourself to see how fast your server can process the compressed logs you can use the test.sh script

Code (Text):

yum -y install git-lfs
mkdir -p /root/tools
cd /root/tools
git clone https://github.com/centminmod/fake-access-logs
cd fake-access-logs
git lfs install
git lfs pull
git lfs ls-files
./test.sh

To update the test.sh code when updates occur

Code (Text):

cd /root/tools/fake-access-logs
git stash
git pull
git lfs pull

Only 2 command options test with zcat and if you have more than 2 cpu threads, test with pzcat

Code (Text):

./test.sh

./test.sh {zcat|pzcat}

zcat test completed in 3.66 seconds

Code (Text):

./test.sh zcat      
zcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 3.66s user: 3.36s sys: 0.15s cpu: 96% maxmem: 1320 KB cswaits: 1
3000000

pzcat multi-threaded test completed in 2.68 seconds and is 26.8% faster than zcat

Code (Text):

./test.sh pzcat
pzcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 2.68s user: 2.28s sys: 0.35s cpu: 98% maxmem: 1320 KB cswaits: 81475
3000000

run both zcat and pzcat tests using all flag

Code (Text):

./test.sh all              
zcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 3.60s user: 3.33s sys: 0.16s cpu: 97% maxmem: 1320 KB cswaits: 10
3000000

pzcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 2.67s user: 2.23s sys: 0.40s cpu: 98% maxmem: 1320 KB cswaits: 81973
3000000

Above tests were done on 2GB HostUS.us OpenVZ VPS server with 2 cpu threads running on Intel Xeon E5-1650v2 @3.50Ghz

---

 

Tests on dedicated server with Intel Xeon E3-1270v1 with 4 core & 8 cpu threads at 3.40Ghz and 1x 240GB SSD

zcat single threaded

Code (Text):

./test.sh zcat
zcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 3.55s user: 3.32s sys: 0.13s cpu: 97% maxmem: 1416 KB cswaits: 18
3000000

pzcat multi-threaded is 51.5% faster than zcat

Code (Text):

./test.sh pzcat
pzcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 1.72s user: 2.30s sys: 0.32s cpu: 152% maxmem: 1420 KB cswaits: 44425
3000000

run both zcat and pzcat tests using all flag

Code (Text):

./test.sh all
zcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 3.47s user: 3.33s sys: 0.12s cpu: 99% maxmem: 1420 KB cswaits: 17
3000000

pzcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 1.70s user: 2.32s sys: 0.28s cpu: 152% maxmem: 1416 KB cswaits: 44434
3000000

Tests on dedicated server with Intel Core i7 4790K with 4 core & 8 cpu threads @4.0Ghz and 2x 240GB SSD raid 1

zcat single threaded

Code (Text):

./test.sh zcat
zcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 2.72s user: 2.56s sys: 0.15s cpu: 99% maxmem: 1448 KB cswaits: 23
3000000

pzcat multi-threaded is 50.7% faster than zcat

Code (Text):

./test.sh pzcat
pzcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 1.34s user: 1.78s sys: 0.22s cpu: 149% maxmem: 1448 KB cswaits: 44389
3000000

run both zcat and pzcat tests using all flag

Code (Text):

./test.sh all
zcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 2.65s user: 2.54s sys: 0.10s cpu: 99% maxmem: 1444 KB cswaits: 17
3000000

pzcat access_log_20180428-234724.log.gz access_log_20180429-005239.log.gz access_log_20180429-012648.log.gz | wc -l
real: 1.33s user: 1.78s sys: 0.20s cpu: 149% maxmem: 1448 KB cswaits: 44405
3000000