线上带宽跑满分析

介绍下背景，公司办公室到 IDC 走的 200M 的专用带宽，最近运维监控图上，一到上班时间就跑满了，而且客服部也经常反馈，网速特别慢。之前客服走的是和其他部门的 40M 专线的，自从客服量上来后，也经常打满，于是接入办公网了，但是没多久，就出现一开始的情况。

接下来就是分析，哪个环节大量占用带宽。运维通过监测，发现客服 IP 出口带宽一天带宽平均 2G 多，接下来就是更加细化的分析了，是哪个业务占了带宽。客服一般就是接电话、打电话，但是语音服务器都在 IDC 那儿，听录音，也就是几个主管可以做的，而且也不是经常听，同时一通电话大概也就是占不到 1M 的大小，基本忽略，于是就得沉下去日志的数据了。

分析日志，首先生产环境的 WEB 服务器 Apache ，看了下是否有日志记录

LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
CustomLog logs/access_log combined

发现有，于是把日志下载到本地，开始切割，选择 0903 号周一工作日

<?php

$file = fopen("access_log","r");
$new_file = 'access_log_20180903';
$count = 0;
while(!feof($file))
{
    $content = fgets($file, 4096);
    if (strpos($content, '03/Sep/2018') !== false) {
        file_put_contents($new_file, $content.PHP_EOL, FILE_APPEND);
    }
}

fclose($file);

打开日志后，发现一共 869152 行，同时依据 apache 日志记录格式

10.255.140.8 - - [03/Sep/2018:23:59:18 +0800] "GET /project/web/strip/monitor/data?_=1535940421926 HTTP/1.1" 302 388 "http://10.255.140.92/project/web/agent/monitor" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.140 Safari/537.36 Edge/17.17134"

简单分析了下流量

ini_set('memory_limit', '-1');

$file = fopen("access_log_20180903","r");
$arr = [];
$ipArr = [];
$count = 0;
while(!feof($file))
{
    $str = fgets($file, 4096);
    $arr = explode(' ', $str);
    $count += intval(isset($arr[9]) ? $arr[9] : 0);
    if (!isset($ipArr[$arr[0]])) {
        $ipArr[$arr[0]] = $arr[0];
    }
}

$arr = [];
echo getSize($count);
foreach ($ipArr as $k => $v) {
    if (strpos($v, '10.255') !== false) {
        $arr[] = $v;
    }
}
print_r($arr);
fclose($file);

function getSize($filesize) {
    if($filesize >= 1073741824) {
        $filesize = round($filesize / 1073741824 * 100) / 100 . ' GB';
    } elseif($filesize >= 1048576) {
        $filesize = round($filesize / 1048576 * 100) / 100 . ' MB';
    } elseif($filesize >= 1024) {
        $filesize = round($filesize / 1024 * 100) / 100 . ' KB';
    } else {
        $filesize = $filesize . ' 字节';
    }
    return $filesize;
}

发现一天 153.3GB，IP 特征数为 67，二者相除为 2.283582089552239 和上面运维的统计数据一致。为了简单直观统计，接着创建张表

CREATE TABLE `log_stat` (
  `id` int(11) unsigned NOT NULL AUTO_INCREMENT,
  `host` varchar(25) NOT NULL DEFAULT '' COMMENT '主机',
  `identd` varchar(32) NOT NULL DEFAULT '' COMMENT '远端登录名',
  `remote_username` varchar(32) NOT NULL DEFAULT '' COMMENT '远程用户名',
  `time` datetime DEFAULT NULL COMMENT '时间',
  `method` varchar(32) NOT NULL DEFAULT '' COMMENT 'get/post',
  `api` varchar(500) NOT NULL DEFAULT '' COMMENT 'api 接口',
  `status` varchar(3) NOT NULL DEFAULT '' COMMENT '状态',
  `len` int(11) unsigned NOT NULL DEFAULT '0' COMMENT '返回值大小',
  `referer` varchar(500) NOT NULL DEFAULT '' COMMENT '引用',
  `agent` varchar(500) NOT NULL DEFAULT '' COMMENT '代理头',
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COMMENT='统计表';

同时，为了方便写入 MySQL 表，进一步把切割的日志表优化了下

ini_set('memory_limit', '-1');

$file = fopen("access_log_20180903","r");
$newFile = 'access_log_20180903_load';
$count = 0;
while(!feof($file))
{
    $str = fgets($file, 4096);
    if (strlen(trim($str)) < 5)
        continue;
    preg_match('/(\S+)\s+(-)\s+(-)\s+\[(\S+\s\S+)\]\s+("[^"]+")\s+(\S+)\s+(\S+)\s+"(\S+)"\s+("[^"]+")/', $str, $matches);
    $_tmp = [];
    if (isset($matches[5])) {
        $_tmp = explode(' ', trim($matches[5], '""'));
    file_put_contents($newFile, (++$count) ."\t{$matches[1]}\t{$matches[2]}\t{$matches[3]}\t" . (date('Y-m-d H:i:s', strtotime($matches[4]))) . "\t" . (isset($_tmp[0]) ? $_tmp[0] : '') . "\t" . (isset($_tmp[1]) ? $_tmp[1] : '') . "\t{$matches[6]}\t{$matches[7]}\t{$matches[8]}\t" . (trim($matches[9], '"')) . PHP_EOL, FILE_APPEND);
    }
}

运行后，大体数据为

1	10.255.251.83	-	-	2018-09-03 00:00:01	POST	/sync_service/sservice/rpcserv.php	200	317	-	PHPRPC Client 3.0 for PHP

然后 LOAD DATA LOCAL INFILE 'access_log_20180903_load' INTO TABLE log_stat; 入库，接下来便统计下各个调用链接占用的带宽

SELECT sum(len) as size,api FROM `log_stat` GROUP BY api ORDER BY size desc;

一查，嚯，便发现了端倪

size			api
163355547042    /project/index.php?d=project&c=knowledge_base&m=get_horse_race_lamp

163355547042 这个数据不直观，转换下为 152.14GB，占了总带宽的 99%。于是找到对应的项目，发现这是个跑马灯请求，每 5 秒请求一次，看了下一次请求带宽占 450K，这样再算一下 12 * 0.45 * 60 * 9 = 2.916GB，大致和上面的每台机子占用带宽相等（注，上面的为均值，具体到每台机子不同）。同时查看了下后台代码，发现每次请求都会把整张表的数据拿出来。既然查到了源头，优化也就简单了，问了下相关产品，把请求频率由 5 秒改为 1 分钟，同时只拿出符合条件指定的数据。这样一下来，看了下，每次请求大小为 11KB，再算一下 1 * 0.011 * 60 * 9 = 5.94MB（注，1 分钟占用带宽 0.011 乘以 1 个小时再乘以上班的 9 个小时），这样就基本上可以忽略不计了。

至此，这次带宽跑满的案例就分析完毕了，一条线下来，发现还是日志起了至关重要的作用，所以，平时除了写代码，日志记录也不能少，当然了，还是业务也需要严谨，否则一个不起眼的疏忽就造成堤坝奔溃的源头，古语就叫“千里之堤，毁于蚁穴”。