文档章节

【原创】源码解析 packetbeat 之 responsetime 计算问题

摩云飞
 摩云飞
发布于 2017/04/01 10:37
字数 4404
阅读 274
收藏 0

问题

使用 packetbeat 进行抓包分析的主要目的之一就是确定 request 和 response 之间 latency 时间;而 responsetime 值对应的就是这个时间,因此该值的计算方式,以及准确性在实际使用中非常重要;

表现

在基于 packetbeat 的分析报告中,经常可以看到如下输出内容

responsetime(193 microseconds)	==>    No.<1>
----
{"@timestamp":"2017-03-29T08:52:01.965Z","beat":{"hostname":"sunfeideMacBook-Pro.local","name":"sunfeideMacBook-Pro.local","version":"6.0.0-alpha1"},"bytes_in":51,"bytes_out":4,"client_ip":"10.0.58.183","client_port":26776,"client_proc":"","client_server":"","ip":"10.0.10.58","method":"SMEMBERS","port":7602,"proc":"","query":"SMEMBERS restaurant:326200:contents","redis":{"return_value":"[]"},"resource":"restaurant:326200:contents","responsetime":193,"server":"","status":"OK","type":"redis"}


responsetime(193 microseconds)	==>    No.<2>
----
{"@timestamp":"2017-03-29T08:52:01.965Z","beat":{"hostname":"sunfeideMacBook-Pro.local","name":"sunfeideMacBook-Pro.local","version":"6.0.0-alpha1"},"bytes_in":57,"bytes_out":4,"client_ip":"10.0.58.183","client_port":26776,"client_proc":"","client_server":"","ip":"10.0.10.58","method":"SMEMBERS","port":7602,"proc":"","query":"SMEMBERS food_restaurant:2186309:contents","redis":{"return_value":"[]"},"resource":"food_restaurant:2186309:contents","responsetime":193,"server":"","status":"OK","type":"redis"}

从中可以看到几个数值相同的地方:

  • <1> 和 <2> 的 "@timestamp" 数值相同;
  • <1> 和 <2> 的 "responsetime" 数值相同;
  • <1> 和 <2> 的 "client_port" 和 "port" 相同;

不同点在于:

  • "query" 的内容不同;

看起来似乎是在同一个时间发出了不同 query 请求,但在获取相应的时间时,得到了相同的值;其实这个是由于 pipeline 的原因,如下图所示:

redis pipeline 对 packetbeat 分析的影响

还存在另外一种情况:即 response 大到需要在 TCP 协议层面分包发送;

日志如下:

{"@timestamp":"2017-03-29T08:52:06.501Z","beat":{"hostname":"sunfeideMacBook-Pro.local","name":"sunfeideMacBook-Pro.local","version":"6.0.0-alpha1"},"bytes_in":52,"bytes_out":13507,"client_ip":"10.0.58.183","client_port":26776,"client_proc":"","client_server":"","ip":"10.0.10.58","method":"GET","port":7602,"proc":"","query":"GET search_area_restaurant_id:wwmthp","redis":{"return_value":"(lp1\nI500232\naI1777849\naI619754\naI1403142\naI523501\naI2350975\naI151675482\naI1505143\naI1069044\naI614157\naI1406283\naI571267\naI2069336\naI151695752\naI147163644\naI2239901\naI2256112\naI451580\naI1217250\naI381736\naI528265\naI634537\naI767398\naI475421\naI1505027\naI400907\naI152107900\naI491118\naI416144\naI150970671\naI484445\naI150058323\naI1048628\naI317081\naI552229\naI519132\naI1962390\naI2262288\naI150899176\naI1509387\naI1551358\naI994255\naI151004498\naI324628\naI871239\naI2020650\naI2059480\naI921549\naI343032\naI2251490\naI192074\naI305984\naI1333436\naI1559413\naI151691503\naI578980\naI2359311\naI1069859\naI551534\naI688005\naI1090091\naI147502706\naI2060663\naI1189870\naI1810063\naI150162189\naI1053551\naI1881428\naI1265721\naI2349741\naI429957\naI401978\naI2113721\naI956012\naI150969522\naI216694\naI752204\naI1913280\naI408229\naI489046\naI1973669\naI150973128\naI907450\naI1858036\naI2047470\naI2310933\naI1420537\naI396459\naI147508072\naI314288\naI1467056\naI150897864\naI1500140\naI295317\naI1260075\naI202927\naI150101723\naI1051636\naI901363\naI1126673\naI1148076\naI959501\naI421094\naI453764\naI1012326\naI604775\naI602103\naI2132709\naI150160637\naI150851767\naI85240\naI525522\naI1147925\naI150883092\naI1897103\naI1048713\naI456792\naI2235222\naI396450\naI2224988\naI150972019\naI1519190\naI1425052\naI150855322\naI151642336\naI1915130\naI2164310\naI2174705\naI729864\naI671254\naI1291063\naI2028744\naI1107294\naI52027\naI556973\naI150992786\naI200796\naI1035913\naI648504\naI150052844\naI1972231\naI1904258\naI1304882\naI792645\naI150136030\naI2308724\naI2308727\naI648695\naI951796\naI753048\naI1536919\naI1469356\naI497237\naI2020502\naI676226\naI2195107\naI952901\naI2267803\naI1024375\naI2203394\naI1321801\naI1906374\naI558568\naI394262\naI1988030\naI1056855\naI168082\naI675100\naI2247914\naI800164\naI944599\naI1522307\naI151694252\naI652848\naI1866111\naI1866441\naI852980\naI1783720\naI1148100\naI283750\naI1148102\naI1001539\naI1823360\naI572147\naI1119549\naI384890\naI434975\naI2173503\naI446636\naI202961\naI901370\naI635638\naI2174591\naI2199680\naI1385546\naI1001902\naI1900579\naI497519\naI1885574\naI1028157\naI1397383\naI150879109\naI223911\naI1935449\naI1147851\naI376707\naI151704231\naI943972\naI1974773\naI1866233\naI886223\naI659015\naI1860886\naI1085306\naI1050226\naI143482230\naI448164\naI429877\naI2367972\naI147587877\naI983749\naI1181122\naI1304339\naI150967237\naI626696\naI479785\naI1936405\naI509876\naI1524715\naI151003408\naI1872271\naI2188925\naI1337903\naI1768761\naI2140255\naI142942425\naI2055240\naI1060960\naI150135720\naI777810\naI570124\naI2055160\naI693420\naI71235\naI1785398\naI1048273\naI402562\naI2026673\naI660297\naI2083100\naI143688\naI1435957\naI2246665\naI2061987\naI1924181\naI893305\naI614226\naI150879529\naI151682687\naI1393682\naI630763\naI797508\naI1875434\naI1838449\naI694343\naI1049983\naI1863797\naI1192097\naI150895097\naI685287\naI381696\naI147523922\naI951867\naI1476534\naI1277845\naI2147422\naI150140415\naI1908701\naI1880458\naI2330461\naI1438015\naI150068727\naI1148535\naI1371845\naI2216946\naI150162011\naI1115466\naI1824764\naI1098816\naI144028081\naI1784923\naI2231055\naI2004869\naI150893394\naI2242511\naI1050045\naI150135634\naI150039604\naI1491841\naI1469786\naI143157238\naI1418345\naI151690609\naI1148089\naI662320\naI1461795\naI772502\naI552200\naI2238979\naI150156167\naI812167\naI1781115\naI706669\naI2221035\naI150093078\naI620689\naI732740\naI713059\naI1534419\naI150852898\naI525515\naI643672\naI707182\naI1185116\naI1276811\naI143325050\naI1423488\naI1842657\naI1053962\naI329073\naI777222\naI1469234\naI1547042\naI150898598\naI390550\naI672301\naI893121\naI1322086\naI461795\naI948080\naI497499\naI729717\naI662143\naI1157222\naI1306601\naI1157224\naI2256341\naI283716\naI1047991\naI1289969\naI150136007\naI723735\naI417641\naI280016\naI996864\naI144036295\naI1424001\naI1398126\naI1143989\naI1524495\naI565435\naI1054112\naI1767947\naI1965142\naI2160880\naI341681\naI1395098\naI145354205\naI679137\naI2355156\naI1350456\naI552106\naI478414\naI150884935\naI720549\naI630986\naI360173\naI1800584\naI1880122\naI2004524\naI150007275\naI620424\naI1350075\naI150024231\naI2132708\naI867622\naI150140660\naI1420923\naI1003837\naI1964620\naI1820812\naI495095\naI1181000\naI800117\naI602382\naI221984\naI925799\naI152107221\naI498411\naI1325055\naI550321\naI2100070\naI58897\naI679554\naI143845525\naI1220700\naI1847426\naI1879887\naI419552\naI274958\naI2003755\naI1933054\naI1055687\naI629928\naI638178\naI2374015\naI150160469\naI1339305\naI130659\naI220632\naI1052448\naI471485\naI150160459\naI1885033\naI1421051\naI2195803\naI150029456\naI150092202\naI637098\naI1047981\naI2162072\naI464591\naI143256668\naI542556\naI536273\naI926974\naI788329\naI1881438\naI494837\naI1253964\naI150989212\naI451522\naI1284806\naI873353\naI2054650\naI2242292\naI276741\naI1417938\naI1396276\naI1443248\naI150079414\naI1066834\naI683853\naI626558\naI457793\naI428432\naI1001827\naI1464245\naI298016\naI380131\naI2160210\naI536458\naI2174707\naI2051611\naI150966081\naI1067887\naI150067266\naI608775\naI1098366\naI1837891\naI1827507\naI1381659\naI1149100\naI1821182\naI150879305\naI1152394\naI656282\naI496122\naI514804\naI533571\naI1123881\naI558671\naI150024444\naI755494\naI151662814\naI426455\naI1985884\naI471419\naI579043\naI2124227\naI1490239\naI456483\naI620809\naI1934159\naI1543154\naI150888013\naI1808925\naI713226\naI614201\naI1333292\naI2057721\naI1253144\naI360189\naI348638\naI151636426\naI1053108\naI799261\naI1324794\naI1842691\naI1022858\naI672220\naI448048\naI1541355\naI151683261\naI617650\naI2240294\naI2229025\naI451145\naI2240115\naI1806621\naI2184379\naI676192\naI658865\naI500572\naI676211\naI666345\naI1818646\naI922398\naI147052169\naI479322\naI2244452\naI1821377\naI2343223\naI1254061\naI396443\naI454991\naI1861471\naI1120789\naI1188818\naI610802\naI2004597\naI1853586\naI1112393\naI1299379\naI1370283\naI1813328\naI1078572\naI367661\naI150133914\naI447617\naI1077576\naI2054832\naI1032223\naI2102191\naI2253138\naI791040\naI1045991\naI948613\naI615745\naI2253132\naI151683465\naI151707518\naI380665\naI199861\naI1966008\naI2004054\naI150136220\naI483411\naI197235\naI150078347\naI915311\naI421109\naI2279256\naI150141084\naI1196413\naI1215552\naI2369100\naI1886360\naI921051\naI1097079\naI150007781\naI605442\naI1500050\naI2248761\naI907720\naI658246\naI610859\naI1813130\naI1288854\naI729814\naI150970802\naI151670783\naI2016618\naI1858932\naI789864\naI499203\naI150985266\naI1982418\naI2106702\naI637196\naI959500\naI1276176\naI1500557\naI151000765\naI57969\naI1364294\naI1075231\naI150073222\naI2175437\naI1845454\naI207160\naI955251\naI1138334\naI55705\naI202172\naI150089181\naI150139956\naI359096\naI617227\naI989813\naI1867526\naI621501\naI2348033\naI150162018\naI905604\naI2292926\naI151662658\naI152107844\naI328440\naI1821535\naI368639\naI1106025\naI677161\naI366731\naI2226896\naI531886\naI1048248\naI1049833\naI2357301\naI150150866\naI150099687\naI641518\naI1174347\naI1957091\naI151679723\naI2081725\naI150068838\naI257966\naI289441\naI1882009\naI218485\naI150024394\naI478977\naI1491754\naI2087363\naI2347699\naI721296\naI1316540\naI1443575\naI2218745\naI323250\naI150109759\naI1400617\naI2373502\naI394691\naI57686\naI1414771\naI150004574\naI150102397\naI1782540\naI151712258\naI2038578\naI676424\naI1993215\naI612635\naI1371027\naI1434385\naI1302470\naI1542764\naI151683300\naI1050053\naI1529323\naI1148099\naI717827\naI1448545\naI785482\naI2173945\naI570713\naI1025750\naI809994\naI1205771\naI784084\naI712907\naI1985263\naI512910\naI1173373\naI841288\naI273179\naI384885\naI600419\naI1399431\naI2226946\naI2191208\naI578678\naI676515\naI2238494\naI1879484\naI1402987\naI2012441\naI370658\naI418394\naI150004665\naI2266752\naI435620\naI1860900\naI413669\naI2308756\naI328663\naI384868\naI151683232\naI1869389\naI774433\naI297542\naI2046073\naI858550\naI759652\naI554559\naI1169765\naI1470289\naI2080256\naI2090113\naI497154\naI996872\naI150136155\naI615166\naI1842073\naI151679514\naI1293568\naI328215\naI1175437\naI749192\naI531905\naI150882586\naI151663533\naI167537\naI932042\naI2063648\naI145393219\naI1466974\naI150984297\naI1388025\naI532442\naI362636\naI884993\naI1867993\naI147549414\naI150129972\naI1867995\naI545072\naI216906\naI2189184\naI782273\naI1305176\naI1206399\naI455922\naI2233420\naI1002643\naI755143\naI737823\naI1332995\naI150892727\naI2167871\naI421918\naI1414027\naI147651946\naI1056793\naI1513903\naI1379788\naI994975\naI1152776\naI2039877\naI1557870\naI151683126\naI1317057\naI439482\naI35325\naI1322148\naI355783\naI1838127\naI1859018\naI626642\naI943778\naI208830\naI1366083\naI1475461\naI618566\naI1820765\naI1338247\naI1303853\naI935574\naI491523\naI2178325\naI1111881\naI1272411\naI1325140\naI1392442\naI649651\naI141579384\naI1525734\naI1403058\naI1465204\naI546832\naI2254955\naI1173177\naI1076866\naI2209499\naI331891\naI2188309\naI1925129\naI1305245\naI150134117\naI1785724\naI1944078\naI1946664\naI399100\naI670855\naI1176588\naI1942753\naI1794204\naI2227381\naI712981\naI2176077\naI569305\naI150980547\naI2193913\naI741997\naI1856591\naI638611\naI1162751\naI485564\naI1516439\naI1255933\naI1857106\naI1174011\naI2265903\naI151636628\naI2195613\naI2219470\naI662611\naI1372031\naI1247859\naI151652973\naI783700\naI1395397\naI2238353\naI622844\naI602088\naI2238450\naI1260114\naI1815571\naI1564527\naI809230\naI2133829\naI1270021\naI359044\naI1136642\naI151634049\naI330320\naI1825270\naI285120\naI267630\naI714188\naI566835\naI1966124\naI601700\naI1772909\naI150972132\naI998163\naI805082\naI898863\naI1869570\naI394814\naI613504\naI2041701\naI2001764\naI390516\naI1316955\naI150024601\naI2043598\naI258071\naI1914875\naI978998\naI1452829\naI719080\naI1404611\naI317955\naI2089165\naI223957\naI339261\naI519314\naI1851371\naI1858589\naI666339\naI1818802\naI523669\naI151663446\naI1533500\naI2179881\naI2377997\naI2298903\naI1054228\naI1041235\naI327366\naI1976317\naI339278\naI647800\naI1906311\naI813834\naI225214\naI2231023\naI618254\naI1465965\naI1857893\naI900666\naI1805900\naI2237497\naI150851519\naI1446111\naI1857898\naI898013\naI1497468\naI2199972\naI1933647\naI150141413\naI1926405\naI200768\naI150966752\naI1282212\naI857924\naI150980614\naI2172785\naI706749\naI1053603\naI177314\naI225075\naI1863568\naI1771211\naI150135633\naI626607\naI330335\naI1832935\naI279430\naI1333337\naI150966796\naI2005155\naI150888694\naI2050029\naI784911\naI1122413\naI150988760\naI320563\naI1394481\naI606281\naI57393\naI1468519\naI622743\naI612483\naI1148094\naI1857768\naI784648\naI1868928\naI944849\naI1856543\naI2204655\naI428818\naI456441\naI748116\naI1907084\naI2212366\naI1321855\naI609517\naI1329921\naI1215803\naI656643\naI1547623\naI357128\naI2244308\naI150165363\naI1165552\naI1050969\naI2106914\naI939705\naI2049688\naI1086084\naI1023165\naI1936128\naI1904726\naI965410\naI151001009\naI362675\naI920031\naI1421282\naI54570\naI258185\naI698196\naI150108068\naI1946519\naI150034097\naI1322070\naI2198525\naI2198526\naI2009080\naI147507115\naI54051\naI1945546\naI991733\naI150893426\naI636849\naI1339899\naI1856490\naI2189372\naI2090110\naI2090111\naI660961\naI787181\naI1949161\naI1829284\naI2056224\naI496540\naI773141\naI1309476\naI1889967\naI485248\naI150162602\naI480865\naI572349\naI339116\naI150136695\naI151714099\naI1829831\naI150971024\naI269169\naI2235781\naI2205327\naI1245152\naI238003\naI198287\naI855455\naI623930\naI1875202\naI2330255\naI917337\naI732241\naI1052018\naI2349708\naI283259\naI443866\naI1248911\naI1876012\naI1261266\naI1863009\naI1343452\naI1874074\naI1244761\naI1938299\naI649981\naI613222\naI1068186\naI944756\naI612629\naI151683709\naI1937674\naI150034266\naI274892\naI611258\naI1842080\naI1426464\naI541439\naI638909\naI1433685\naI1317638\naI1148930\naI490118\naI1419329\naI1177524\naI2257506\naI2105111\naI152108886\naI1400714\naI1174452\naI1005571\naI899310\naI152104409\naI47448\naI196265\naI2164303\naI150966364\naI1542749\naI713875\naI200854\naI407144\naI2164305\naI1162156\naI2324055\naI2164309\naI2295121\naI151682794\naI2351043\naI203232\naI390423\naI190336\naI1110604\naI465501\naI2026146\naI1959486\naI1354504\naI1053950\naI658906\naI2011321\naI1477804\naI2197602\naI2236115\naI2298036\naI878545\naI2178983\naI2086242\naI1220802\naI2356896\naI152108081\naI151707402\naI230068\naI1181241\naI1380481\naI150032823\naI473258\naI405156\naI403191\naI524847\naI328788\naI150971061\naI1915322\naI547008\naI867583\naI1868637\naI1548366\naI150140102\naI996318\naI634682\naI210867\naI1514239\naI1418155\naI1857605\naI505297\naI1962977\naI1254704\naI2073935\naI2226523\naI289075\naI151667185\naI2282406\naI1106490\naI1902768\naI379118\naI674623\naI614070\naI433844\naI150033684\naI1535551\naI728631\naI1138833\naI1307109\naI787553\naI463688\naI2015953\naI150875420\naI150873232\naI150968591\naI1395974\naI712563\naI2188039\naI1813663\naI1856766\naI1913141\naI1469190\naI797620\naI366960\naI2109018\naI1943583\naI2102899\naI1383634\naI150970023\naI1015789\naI1184390\naI897598\naI59161\naI952004\naI1332569\naI1158370\naI2026064\naI1413104\naI150135346\naI150982721\naI732833\naI1370455\naI2037717\naI2043718\naI435226\naI691659\naI2354555\naI2354554\naI1966236\naI1869965\naI677799\naI429777\naI1139016\naI977382\naI332043\naI475394\naI1077561\naI1805940\naI1942808\naI1978120\naI1047990\naI1190998\naI150139931\naI460184\naI533970\naI2234331\naI329184\naI150973110\naI1381733\naI147488840\naI409588\naI150973116\naI2086570\naI2191636\naI1062603\naI380129\naI1946614\naI229546\naI2178332\naI355922\naI150089063\naI1180129\naI1404468\naI150985390\naI150149768\naI602099\naI1107362\naI2217805\naI1897139\naI150112867\naI1491212\naI535619\naI1148091\naI463418\naI1888342\naI2010299\naI1215656\naI1315160\naI2343038\naI150140135\naI1166089\naI1280165\naI564822\naI1772911\naI672616\naI1443806\naI1517057\naI621559\naI1516445\naI376757\naI622188\naI794910\naI341425\naI1464453\naI1152680\naI1561181\naI2189680\naI1016760\naI515629\naI1996001\naI1350972\naI2308759\naI2226916\naI727937\naI510318\naI1002441\naI390505\naI1768488\naI1398064\naI2072954\naI1189578\naI563770\naI2111156\naI1457398\naI150972260\naI150975571\naI2157094\naI1517461\naI1439153\naI150989348\naI1426962\naI724826\naI251140\naI1390352\naI1131843\naI676173\naI150989343\naI250395\naI569255\naI1419796\naI151634810\naI150966846\naI398792\naI2246706\naI1930974\naI1821394\naI485302\naI547068\naI785830\naI449683\naI1196943\naI1330514\naI1945109\naI408240\naI1053952\naI633621\naI2114207\naI985237\naI1051644\naI1262175\naI1191641\naI1857737\naI150062089\naI500613\naI859798\naI366888\naI1148095\naI147505499\naI2226562\naI908486\naI1560595\naI2218291\naI1219422\naI666360\naI699300\naI1395870\naI2366838\naI481986\naI2366835\naI1047996\naI150843500\naI521293\naI1470026\naI1179539\naI2164307\naI2231689\naI390223\naI2010243\naI1860783\naI1882430\naI2081663\naI2183166\na."},"resource":"search_area_restaurant_id:wwmthp","responsetime":31,"server":"","status":"OK","type":"redis"}

可以看到:

  • 应用层协议:request 占了 52 字节("bytes_in":52),response 占了 13507 字节("bytes_out":13507);
  • "responsetime" 仅为 31ms ;

抓包截图如下:

redis response 需要 TCP 分包发送时对 packetbeat 分析的影响

由此可知:

  • packetbeat 计算 "responsetime" 时是基于首个 TCP segment 计算的(在该抓包中,response 的最后一个 segment 和 request 之间的时间差为 54ms);
  • "bytes_in" 和 "bytes_out" 的计算则是计算的全部 TCP segment 总和(应用协议数据长度);

深入

  • 确定产生上述日志的代码
func (redis *redisPlugin) newTransaction(requ, resp *redisMessage) common.MapStr {
    ...
	responseTime := int32(resp.ts.Sub(requ.ts).Nanoseconds() / 1e3)

	event := common.MapStr{
		"@timestamp":   common.Time(requ.ts),  // requ.ts 即 request 包的时间戳
		"type":         "redis",
		"status":       error,
		"responsetime": responseTime, // response 包的时间戳 - request 包的时间戳
		"redis":        returnValue,
		"method":       common.NetString(bytes.ToUpper(requ.method)),
		"resource":     requ.path,
		"query":        requ.message,
		"bytes_in":     uint64(requ.size),
		"bytes_out":    uint64(resp.size),
		"src":          src,
		"dst":          dst,
	}
    ...
}
  • request 和 response 的关联方式
// 将 request 和 response 进行关联
func (redis *redisPlugin) correlate(conn *redisConnectionData) {
    ...
    // merge requests with responses into transactions
	for !conn.responses.empty() && !conn.requests.empty() {
		requ := conn.requests.pop()
		resp := conn.responses.pop()

		if redis.results != nil {
			// 将匹配的 request 和 response 封装成 transaction event
			event := redis.newTransaction(requ, resp)
			// 将 transaction event 发布出去(比如写出到 stdout 或 file 等)
			redis.results.PublishTransaction(event)
		}
	} 
    ...
}

这里其实存在一个问题:上述实现中由于采用的是 FIFO 原则,因此必须确保 request 和 response 是正确匹配的,但在 redis 协议的 master 和 slave 之间进行命令同步相关协议通信时,不满足该要求,会导致匹配错误产生;

  • 将 redis 协议中的 request 和 response 分类保存和匹配
func (redis *redisPlugin) handleRedis(
	conn *redisConnectionData,
	m *redisMessage,
	tcptuple *common.TCPTuple,
	dir uint8,
) {
    ...

	if m.isRequest {
		conn.requests.append(m) // wait for response
	} else {
		conn.responses.append(m)
		redis.correlate(conn)
	}
}
  • 设置 request 或 response 时间戳的地方
func (redis *redisPlugin) doParse(
	conn *redisConnectionData,
	pkt *protos.Packet,
	tcptuple *common.TCPTuple,
	dir uint8,
) *redisConnectionData {

	// 基于当前 tcp 流的数据流向进行选择处理
	st := conn.streams[dir]
	if st == nil {
		// 新建 stream 时,为当前 redis 消息指定时间戳,即新 request 或 response 
		st = newStream(pkt.Ts, tcptuple)   -- 1
		conn.streams[dir] = st
		if isDebug {
			debugf("new stream: %p (dir=%v, len=%v)", st, dir, len(pkt.Payload))
		}
	}
	...
	for st.Buf.Len() > 0 {
		if st.parser.message == nil {
			// 为新的一条 redis 消息指定时间戳,即新 request 或 response
			st.parser.message = newMessage(pkt.Ts)  -- 2
		}
   ...
   redis.handleRedis(conn, msg, tcptuple, dir)
   ...
}

可以看到时间戳的指定是在收到 redis 协议 request 或 response 的第一个 pkt 时进行的;

  • TCP 协议包到应用层协议包的处理
// 将 tcp 协议层面的数据包添加到
func (stream *TCPStream) addPacket(pkt *protos.Packet, tcphdr *layers.TCP) {
    ...
	if len(pkt.Payload) > 0 {
		// 调用各协议模块定义的 Parse 函数
		conn.data = mod.Parse(pkt, &conn.tcptuple, stream.dir, conn.data)
	}
    ...
}
  • 将 pkt 分配到不同的 TCP stream
func (tcp *TCP) Process(id *flows.FlowID, tcphdr *layers.TCP, pkt *protos.Packet) {
    ...
	// 基于 pkt 确定 TCP stream
	stream, created := tcp.getStream(pkt)
	...
	stream.addPacket(pkt, tcphdr)
}
  • 针对基于 gopacket 从底层收上来的 packet 进行协议的逐层解析
func (d *Decoder) OnPacket(data []byte, ci *gopacket.CaptureInfo) {
    ...
	// Ethernet 层给出的类型
	currentType := d.linkLayerType
	
	// NOTE: 这里就是为每个 packet 设置时间戳的位置
	//       可以看到时间戳实际上是来自 gopacket 中给的值
	packet := protos.Packet{Ts: ci.Timestamp}
    ...
    for len(data) > 0 {
        ...
		// 根据 packet 所属的 layerType 触发相应的回调函数(ICMP/UDP/TCP)
		processed, err = d.process(&packet, currentType)
        ...
    }
}
...
// 根据 packet 所属的 layerType 触发相应的回调函数(ICMP/UDP/TCP)
func (d *Decoder) process(
	packet *protos.Packet,
	layerType gopacket.LayerType,
) (bool, error) {
    ...
	case layers.LayerTypeTCP:
		debugf("TCP packet")
		d.onTCP(packet)
		return true, nil
	}
    ...   
}
...
func (d *Decoder) onTCP(packet *protos.Packet) {
    ...
	d.tcpProc.Process(id, &d.tcp, packet)
}
  • sniffer 根据配置 DataSource 读取数据包
func (sniffer *SnifferSetup) Run() error {
    ...
	for sniffer.isAlive {
	    ...
		// 从指定数据源(live interface 或者 pcap 文件)中获取下一个存在的 packet 
		//  data:  The bytes of an individual packet.
	    //  ci:  Metadata about the capture
		data, ci, err := sniffer.DataSource.ReadPacketData()
		...
		sniffer.worker.OnPacket(data, &ci)
	}
    ...
}

由上下文可知,时间戳是从 ci 中得到的,因此 DataSource 使用哪种是关键;

  • 数据源 DataSource 的选择
func (sniffer *SnifferSetup) setFromConfig(config *config.InterfacesConfig) error {
    ...
	switch sniffer.config.Type {
	case "pcap":
	    ...
	    sniffer.DataSource = gopacket.PacketDataSource(sniffer.pcapHandle)
	case "af_packet":
	    ...
	    sniffer.DataSource = gopacket.PacketDataSource(sniffer.afpacketHandle)
	case "pfring", "pf_ring":
	    ...
	    sniffer.DataSource = gopacket.PacketDataSource(sniffer.pfringHandle)
	default:
		return fmt.Errorf("Unknown sniffer type: %s", sniffer.config.Type)
	}
	...
}

对应测试中的实际情况而言,此处只考虑 pcap 对应的情况;

  • ci 中时间戳的设置

pcap.go 中有

func (p *Handle) ReadPacketData() (data []byte, ci gopacket.CaptureInfo, err error) {
    ...
	err = p.getNextBufPtrLocked(&ci)
    ...
}
...
func (p *Handle) getNextBufPtrLocked(ci *gopacket.CaptureInfo) error {
    ...
    // 设置 ci 中时间戳的位置
	ci.Timestamp = time.Unix(int64(p.pkthdr.ts.tv_sec),
		int64(p.pkthdr.ts.tv_usec)*1000) // convert micros to nanos
	ci.CaptureLength = int(p.pkthdr.caplen)
	ci.Length = int(p.pkthdr.len)
    ...
}

可以看到,时间戳是从 p.pkthdr.ts.tv_secp.pkthdr.ts.tv_usec 两个值得到的,而 pkthdr 的定义如下:

type Handle struct {
	// cptr is the handle for the actual pcap C object.
	cptr         *C.pcap_t
	blockForever bool
	device       string
	mu           sync.Mutex
	// Since pointers to these objects are passed into a C function, if
	// they're declared locally then the Go compiler thinks they may have
	// escaped into C-land, so it allocates them on the heap.  This causes a
	// huge memory hit, so to handle that we store them here instead.
	pkthdr  *C.struct_pcap_pkthdr
	buf_ptr *C.u_char
}

由此可知,要想知道 pkthdr.ts 的值是如何得到的,则需要研究 libpcap 代码了;

展开

在 《Timestamps》中,有如下说明:

Wireshark just gets its timestamp from libpcap/WinPcap, and libpcap/WinPcap gets it from the packet capture mechanism it uses; Wireshark itself doesn't generate the timestamp so there's nothing Wireshark can do about it.

How the timestamp works is OS dependent. In some UNIXes that code is in the network drivers; it's higher up in the networking code path in other UNIXes. In Windows, with WinPcap, timestamping is done by the WinPcap driver.

Another issue might be if the OS delivers multiple packets per interrupt. This can be because the OS does "polling" or otherwise arranges that one interrupt be delivered for a batch of packets to reduce interrupt-handling overhead. If that's the case, the timestamps might be the same for multiple packets, at least to the resolution of the timestamping routine.

Note also that the timestamp on a packet isn't a high-accuracy measurement of when the first bit or the last bit of the packet arrived at the network adapter; there's a delay between the arrival of that last bit and the interrupt for the packet and a delay between the start of interrupt handling and the point in the code path where the timestamp is attached to the packet.

  • Resolution

The timestamp has the resolution of whatever clock is being used. The clock might not be the "PC clock" because it might not be running on a "PC", either in the sense of machines sold as "personal computers" or in the sense of "IBM-compatible personal computer". Some of those machines might have better high-resolution timers than IBM-compatible PCs do - at least some OSes on more modern IBM-compatible PC's use the RDTSC instruction, if present on the processor, to get higher-precision timestamps.

There's precision and accuracy; a clock with picosecond resolution, set to a time that's 1 1/2 hours off, is very precise and very inaccurate.

  • Discussion

That's the usual discussion about this might be / this could be / this will be / and so on.

Please put some hard facts here ...

Just simply add measurement values (and the hard facts on the environment) on a specific platform so others can participate ...

在《gettimeofday() should never be used to measure time》中,有如下说明:

The pcap_pkthdr struct (the “received packet” struct) contains a struct timeval ts that ruins our ability to measure the time it takes for the reply you get for some query you sent. They tell me the kernel supplies the timestamp, so it’s not really libpcaps fault.

Calling clock_gettime() when libpcap gives you a packet has turned out to be useless, as the time difference between packet reception and the delivery to your program is too long and unstable. You’re stuck with this wall-clock time until you fix all the kernels in the world and break binary compatibility with old libpcap programs.

在《how to understand the capture time!》中,有如下精彩讨论:

  • [Ask #1]

Hi, Dear All,

The webpages about pcap says that the "pcap_pkthdr" structure contains the information about when the packet was sniffed, that is:

struct pcap_pkthdr{ 
    struct timeval ts;
    bpf_u_int32 caplen;
    bpf_u_int32 len;
} 

I wonder whether the "ts" is just the time when the pcap captured the packet? Whether Ethereal use this data for the time when a packet was captured?

Ethereal display the captured packets like:

Frame 1 
Arrival time: Jun 13, 2002 12:00:00.1234546789 
¡¡ ... 

How Ethereal gets this arrival time? from the pcap_pkthdr mentioned upper? the datum "123456789" come directly from the "tv_usec" part in the timeval strcuture?

  • [Answer #1]

What "ts" means depends on the operating system on which you're capturing packets.

On most operating systems, it's the time at which the driver for the network interface gave the packet to the OS's packet capture mechanism; On some OSes where the operating system doesn't itself put a timestamp on the packet, it's the time at which the libpcap library read the packet from the OS kernel.

I.e., the time isn't necessarily the time when the packet arrived on the machine running tcpdump/Ethereal/whatever sniffer program you're using - it may be a later time (although it probably won't be much later).

The answers to all these questions are "YES":

  • Whether Ethereal use this data for the time when a packet was captured?
  • How Ethereal gets this arrival time? from the pcap_pkthdr mentioned upper?
  • the datum "123456789" come directly from the "tv_usec" part in the timeval strcuture?

Note that not all OSes necessarily provide high-precision timestamps; they might, for example, provide timestamps with 1 millisecond or 10 millisecond resolution.

  • [Ask #2]

However, I still don't understand the capture time Ethereal display. for example, when I capture the icmp packet produced by "ping host B" on host A, it shows the same capture time of echo request and echo reply, as the following:

1 0.000000 A B ICMP Echo(ping) request 
Arrival Time: Jun 14,2002 12:00:00.123456789 
... 
2 0.000000 B A ICMP Echo(ping) reply 
Arrival Time: Jun 14,2002 12:00:00.123456789 
...

I wonder why the set of icmp packets arrive at the same time? since A ping B, and B returns a echo reply, it shouldn't produce at the same time!

More ever, I captured the "A ping B" echo request packet on host B, and I want to compute the transmit time for the packet.(A and B have been synchronized by NTP time server)

But transmit = "the arrvial time on host B" subtract "the time of the echo request produced on host A"

the transmit seems much different from the "round-trip time"/2 displayed by "ping", I mean, it seems they are not in the same quantity scale. So I feel confused. Would you like to give me some suggestion?

  • [Answer #2]

You're assuming they did arrive at the same time; that may not be the case.

Perhaps the OS on which you're running the program on which you're capturing packets doesn't timestamp the packets with a sufficiently high-resolution time stamp, and doesn't try to give packets unique time stamps, either.

If, for example, the reply was received .1 milliseconds after the request was sent, but the timer the OS uses to time-stamp the packets has only a 1-millisecond resolution, the two packets might be given the same time stamp even though the request was sent at a different time from when the reply arrived.

There's nothing Ethereal can do about that; it just displays the times libpcap gave it (or gave whatever program wrote the capture file).

There's probably not much libpcap can do about that, either; it just gets the times that the OS provides.

在《[tcpdump-workers] Monotonic clock timestamp on packets 》中,提到

  • [Ask #1]

Has anyone looked into timestamping the captured packets using clock_gettime(CLOCK_MONOTONIC, ...)?

I'm thinking adding a struct timespec to struct pcap_pkthdr and filling that in addition to the struct timeval.

For a request-reply situation a monotonic clock is much more reliable than gettimeofday().

  • [Answer #1]

pcap_pkthdr is in a file. You cannot add ANYTHING to it without breaking compatibility; you'd have to introduce a new magic number.

BTW, note that if you call clock_gettime(), there is NO guarantee that the time it returns has anything to do with the time the packe arrived; it tells you the time when it's called, not the time when the packet arrived.

The only platforms on which libpcap uses gettimeofday() are:

  • DLPI platforms - where the DLPI module doesn't supply the time stamp (e.g., HP-UX);
  • DOS;
  • Septel devices;
  • USB capturing on Linux if you're not using the memory-mapped interface.

On all other platforms - i.e., on most of the platforms where libpcap is used - the time stamps are supplied to userland by the kernel, so if you want to use a different timer, you'll have to modify the kernel. (*BSD, Mac OS X, Linux, Solaris, etc.)

  • [Ask #2]

Exactly. That's why I asked if anyone has taken a look at it. Because calling it from the application at pcap_dispatch time would be useless. Just like calling it from libpcap an arbitrary time too late would be useless.

So if the underlying systems don't provide a monotonic clock for packet arrival time then that's that.

结论:

  • 在有些系统上,这个时间戳对应的是网卡驱动将数据交付 OS 内核的时间;
  • 在另外一些系统上,这个时间戳对应的是负责 sniffer 的东东(例如 libpcap)从 OS 内核读取数据包的时间;
  • 应该认为这个时间戳并非准确的,尤其是在系统压力比较大的情况下;

其他

© 著作权归作者所有

摩云飞
粉丝 375
博文 534
码字总数 952694
作品 0
徐汇
程序员
私信 提问
CentOS7下Elastic Stack 5.0日志分析系统搭建

一、概述 Elasticsearch是个开源分布式搜索引擎,它的特点有:分布式,零配置,自动发现,索引自动分片,索引副本机制,restful风格接口,多数据源,自动搜索负载等。 Logstash是一个开源的用...

结束的伤感
2016/12/01
0
0
Redis监控调研

1 调研目的 主要的目的是想调研各大云平台有关Redis监控功能的实现,但是最后我发现各大云平台提供的监控功能都比较基础,比如我想看诸如、等指标,它们都没有提供,一部分Redis监控的开源工...

yangbodong22011
2017/11/15
0
0
简单使用packetbeat

在前面两篇文章中记录了使用logstash来收集mysql的慢查询日志,然后通过kibana以web的方式展示出来,但在生产环境中,需求会更复杂一些,而且通过logstash写正则,实在是个费时费劲的事。例如...

ylw6006
2015/12/14
0
0
Spark MLlib LDA 源码解析

版权声明:本文为博主原创文章,遵循 CC 4.0 BY-SA 版权协议,转载请附上原文出处链接和本声明。 https://blog.csdn.net/sunbow0/article/details/47662603 1、Spark MLlib LDA源码解析 Spar...

sunbow0
2015/08/14
0
0
应用监控和包跟踪系统--packetbeat

Packetbeat 是开源应用监控和包跟踪系统。Packetbeat 是通过嗅探应用服务的传输来运行的,关联他们到事物,并且使用 Elasticsearch 来分析,然后进行 ad-hoc 查询。 Packetbeat 包括了 Pack...

叶秀兰
2014/09/22
3.1K
0

没有更多内容

加载失败,请刷新页面

加载更多

iptables删除命令中的相关问题

最近在做一个中间件的配置工作,在配置iptables的时候,当用户想删除EIP(即释放当前连接),发现使用iptables的相关命令会提示错误。iptables: Bad rule (does a matching rule exist in t...

xiangyunyan
44分钟前
2
0
IT兄弟连 HTML5教程 HTML5表单 新增的表单属性1

HTML5 Input表单为<form>和<input>标签添加了几个新属性,属性如表1。 1 autocomplete属性 autocomplete属性规定form或input域应该拥有自动完成功能,当用户在自动完成域中开始输入时,浏览器...

老码农的一亩三分地
今天
7
0
OSChina 周五乱弹 —— 葛优理论+1

Osc乱弹歌单(2019)请戳(这里) 【今日歌曲】 @这次装个文艺青年吧 :#今日歌曲推荐# 分享米津玄師的单曲《LOSER》: mv中的舞蹈诡异却又美丽,如此随性怕是难再跳出第二次…… 《LOSER》-...

小小编辑
今天
1K
21
nginx学习笔记

中间件位于客户机/ 服务器的操作系统之上,管理计算机资源和网络通讯。 是连接两个独立应用程序或独立系统的软件。 web请求通过中间件可以直接调用操作系统,也可以经过中间件把请求分发到多...

码农实战
今天
5
0
Spring Security 实战干货:玩转自定义登录

1. 前言 前面的关于 Spring Security 相关的文章只是一个预热。为了接下来更好的实战,如果你错过了请从 Spring Security 实战系列 开始。安全访问的第一步就是认证(Authentication),认证...

码农小胖哥
今天
16
0

没有更多内容

加载失败,请刷新页面

加载更多

返回顶部
顶部