購入する または契約更新する
購入する または契約更新する
キャンセル
提案をオンにする
自動提案では、入力時に可能な一致が提案されるので検索結果を素早く絞り込むことができます。
次の結果を表示 
次の代わりに検索 
もしかして: 
cancel
新しい記事を作成する
184
閲覧回数
1
いいね！
0
コメント

SNA: (7.4.2) フロー検索に関する問題のトラブルシューティング

taknakam
Cisco Employee
Cisco Employee

‎2024-07-29 08:48 AM

 

 

 

はじめに

SMC の WebUI にはデータベースに格納されているフローデータを検索する機能があり、この検索機能においてフローが表示されないという不具合が発生することがあります。本ドキュメントでは、フロー検索実行時の内部動作と問題発生時のトラブルシューティング方法について説明します。

本ドキュメントの内容は SNA のバージョン 7.4.2 の環境を使用して確認しています。また、フローデータが Flow Collector のデータベースに格納されている DDS 構成を前提としています。

 

 

DBにフローデータが存在するか確認

フロー検索機能でフローが表示されるには、Flow Collector のデータベースにフローデータが入っている必要があります。Flow Collector の CLI において以下のコマンドを実行すると、DB内のフローデータの数を出力します。カウント数が０の場合、フローが入っていないことを意味します。

/opt/vertica/bin/vsql -U dbadmin -w lan1cope -c "select count(*) from flow_stats;"

 

実行例を以下に示します。

fc742:~# /opt/vertica/bin/vsql -U dbadmin -w lan1cope -c "select count(*) from flow_stats;"
 count
--------
 351327
(1 row)

 

以下コマンドでは過去24時間分のフローデータをカウントします。

fc742:~# /opt/vertica/bin/vsql -U dbadmin -w lan1cope -c "select count(*) from flow_stats where start_time > (getdate() - INTERVAL '1 day');"
 cou
-------
     0
(1 row)

 

フローが存在する場合は条件無しでフロー検索をすれば何らかのフローデータが表示されるはずです。フローデータが無い場合は、Exporter から Netflow が送られてきているかどうか、Flow Collector が受信した Netflow を正しく処理し、データベースに格納する処理が正しく動作しているかを確認してください。

フローが存在するのにフロー検索でフローが表示されない場合は、以降で説明する方法で切り分けを行います。

 

 

フロー検索機能の実行

処理を順を追って確認していきます。
CLIにてデータベースに記録されているフローの数を確認する方法を説明しましたが、確実にフローが存在する期間を条件に指定して検索を実行します。確実に引っ掛かるようにするため、それ以外の条件は指定しません。

検索を実行すると、SMC の Nginx 経由で Tomcat 上のアプリケーションにリクエストが渡されます。

最初に Nginx のアクセスログ (/lancope/var/nginx/logs/access.log) に検索機能を実行するリクエストが記録されます。

192.168.0.150 - - [26/Jul/2024:10:45:15 +0000] "POST /smc/rest/domains/301/searches HTTP/1.1" 200 846 "https://192.168.0.167/lc-landing-page/smc.html" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36"

 

次に Nginx 経由で Tomcat 上のアプリケーションのログ(/lancope/var/smc/log/smc-core.log) に検索機能実行のログが記録されます。

2024-07-26 10:45:15,653 INFO  [SearchJobServiceImpl] ***Performance : Throttled Search Job Flow on 7/26/2024 at 7:44 PM-66a37e3be7085659cd6
c6171 submitted for execution at @ 2024-07-26T10:45:15.653+0000
2024-07-26 10:45:15,653 INFO  [SearchJobServiceImpl] Throttled executor service status: java.util.concurrent.ThreadPoolExecutor@29a7d204[Ru
nning, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]
2024-07-26 10:45:15,752 INFO  [FlowAnalysisExecutor] ***Performance : Job Flow on 7/26/2024 at 7:44 PM-66a37e3be7085659cd6c6171 Started @ F
ri Jul 26 10:45:15 +0000 2024
2024-07-26 10:45:16,670 INFO  [FlowExecutorChunker] Executing job [Flow on 7/26/2024 at 7:44 PM-66a37e3be7085659cd6c6171], chunked into [73
]

 


フロー検索実行時のログは、report.log (/lancope/var/smc/log/report.log)にも出力されます。このログには、検索機能の実行と結果のステータスが出力されています。以下の出力例では検索１回分しか示していませんが、検索期間が長い場合は自動的に期間を分割して複数回検索を実行する動作になっていますので、from と to を変えながら複数回ログが記録されます。"COMPLETE" と出力されていれば、検索処理自体は完了しています。検索の結果、フローが得られれば Count が０より大きくなります。Duration は検索処理の完了までにかかった時間です。

2024-07-26 12:26:46,901 INFO  FLOWS query status: COMPLETE, query id: dds-8b2c1f8d-4005-4059-8a6b-3d1aaf2d519d, Duration: 729 ms
2024-07-26 12:26:46,901 INFO   |- COMPLETE, dds-8b2c1f8d-4005-4059-8a6b-3d1aaf2d519d, Device 301, Count 0, Duration 0s
2024-07-26 12:26:47,064 INFO  *** flows/jobs Filter by admin:
{
  "maxRecords" : 2000,
  "deviceIds" : [ 301 ],
  "absolute" : {
    "from" : "2024-07-25T12:26:35.106Z",
    "to" : "2024-07-25T18:55:35.107Z"
  },
  "connection" : {
    "flowsDirection" : "BOTH",
    "includeInterfaceData" : false
  },
  "domainId" : 301,
  "object" : {
    "orientation" : "EITHER"
  }
}

 

 

svc-data-service サービス

Tomcat 上で動作しているアプリケーションは、検索実行のリクエストを、同じ SMC 上で動作している svc-data-service に投げます。このサービスが停止していると、Tomcat 上のアプリケーションから svc-data-service にリクエストを送ることができず、smc-core.log に何らかのエラーメッセージが出力されます。

以下は svc-data-service サービスを停止した状態でフロー検索を実行した際に smc-core.log に出力されたエラーです。

2024-07-26 14:22:26,453 INFO  [FlowExecutorChunker] Executing job [Flow on 7/26/2024 at 10:23 PM-66a3b122e7085659cd6c78a2], chunked into [2]
2024-07-26 14:22:26,509 INFO  [FlowExecutorChunker] Error in REST Client
com.lancope.sws.smc.swa.restds.DataServiceException: Error in REST Client
	at com.lancope.sws.smc.swa.restds.DataServiceHelper.doStartQuery(DataServiceHelper.java:182) ~[classes/:?]
	at com.lancope.sws.smc.swa.restds.DataServiceHelper.doCompleteQuery(DataServiceHelper.java:135) ~[classes/:?]

 

svc-data-service はリクエストを受け取ると、今度は Flow Collector 宛にリクエストを送信します。

svc-data-service のログは以下にあります。

/lancope/var/logs/containers/svc-data-service.log

 

検索実行から完了までに svc-data-service.log に出力されるメッセージの例を以下に示します。詳細は割愛しますが、この例では検索開始から結果を取得する処理までが記録されていることが確認できます。検索結果が０だったため "no result found" の出力が WARN になっていますが、それ以外は INFO のメッセージであるため、正常であると判断できます。

Jul 26 13:24:42 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-248] c.l.c.DataController:66 - Starting query for flows
Jul 26 13:24:42 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-248] c.l.s.DefaultDistributedServiceMgr:103 - Start new query: dds-320e0972-5ee0-4ab3-9091-8b697de830ee
Jul 26 13:24:42 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-248] c.l.m.DistributedChannelRequest:31 - start to send query for flows to 192.168.0.168
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.c.DataController:105 - Checking flows query status for dds-320e0972-5ee0-4ab3-9091-8b697de830ee
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.m.DistributedChannelRequest:42 - start to get status for flows from 192.168.0.168
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.c.DataController:131 - Retrieving flows query result for dds-320e0972-5ee0-4ab3-9091-8b697de830ee
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.s.DefaultDistributedServiceMgr:193 - query Result: dds-320e0972-5ee0-4ab3-9091-8b697de830ee
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.m.DistributedChannelRequest:52 - start to get result for flows from 192.168.0.168
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.d.QueryServiceRepositoryImpl:122 - no data returned
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: WARN  [qtp635739314-234] c.l.s.DefaultDistributedServiceMgr:217 - no result found
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.c.DataController:138 - flows request dds-320e0972-5ee0-4ab3-9091-8b697de830ee start: 2024-07-26T13:24:43.022Z, end: 2024-07-26T13:24:43.738Z, duration: 716 ms, rows: 0
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.c.DataController:66 - Starting query for flows
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.s.DefaultDistributedServiceMgr:103 - Start new query: dds-07ca1048-95e8-45d4-bf1a-da534c4fe214
Jul 26 13:24:43 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.m.DistributedChannelRequest:31 - start to send query for flows to 192.168.0.168
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.c.DataController:105 - Checking flows query status for dds-07ca1048-95e8-45d4-bf1a-da534c4fe214
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-234] c.l.m.DistributedChannelRequest:42 - start to get status for flows from 192.168.0.168
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.c.DataController:131 - Retrieving flows query result for dds-07ca1048-95e8-45d4-bf1a-da534c4fe214
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.s.DefaultDistributedServiceMgr:193 - query Result: dds-07ca1048-95e8-45d4-bf1a-da534c4fe214
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.m.DistributedChannelRequest:52 - start to get result for flows from 192.168.0.168
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.d.QueryServiceRepositoryImpl:122 - no data returned
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: WARN  [qtp635739314-253] c.l.s.DefaultDistributedServiceMgr:217 - no result found
Jul 26 13:24:44 smc742 docker/svc-data-service[1390]: INFO  [qtp635739314-253] c.l.c.DataController:138 - flows request dds-07ca1048-95e8-45d4-bf1a-da534c4fe214 start: 2024-07-26T13:24:43.915Z, end: 2024-07-26T13:24:44.642Z, duration: 727 ms, rows: 0

 

 

svc-data-service から Flow Collector の Nginx へ

フローデータは Flow Collector 上のデータベースに格納されているため、SMC 上の svc-data-service は Flow Collector に対して検索実行のリクエストを送ります。これはアプライアンス間の HTTPS のチャネルで送られます。
Flow Collector の Nginx のアクセスログを見ると、以下のように SMC (192.168.0.167) からのフロー検索に関するリクエストが記録されています。以下のログではリクエストが３行記録されていますが、１行目はリクエストの実行処理、２行目は検索処理のステータス確認（非同期で動作しているため）、３行目は検索結果の取得処理のリクエストです。

192.168.0.167 - - [26/Jul/2024:23:53:39 +0000] "POST /data_service/v1/flows/jobs HTTP/1.1" 201 93 "-" "Apache-HttpClient/4.5.13 (Java/11.0.14)"
192.168.0.167 - - [26/Jul/2024:23:53:40 +0000] "GET /data_service/v1/flows/jobs/491f9bdd-7c05-47f8-885d-b8abeab59566 HTTP/1.1" 200 160 "-" "Apache-HttpClient/4.5.13 (Java/11.0.14)"
192.168.0.167 - - [26/Jul/2024:23:53:40 +0000] "GET /data_service/v1/flows/jobs/491f9bdd-7c05-47f8-885d-b8abeab59566/results HTTP/1.1" 204 0 "-" "Apache-HttpClient/4.5.13 (Java/11.0.14)"


前述しましたが、検索処理は指定した期間のデータを一気に取得するのではなく、細かい期間に分割して実行されます。そのため、SMC の report.log や Nginx のアクセスログには検索処理を複数回実行している様子が記録されています。

 

 

Nginx から svc-query-service へ

Flow Collector は SMC (svc-data-servcie) から受け取ったリクエストを、同じ Flow Collector 上の svc-query-service にプロキシします。
svc-query-service のログは以下にあります。

/lancope/var/logs/containers/svc-query-service.log

 

以下は svc-query-service.log からの抜粋です。SMC の report.log や svc-data-service.log 等と同じように、検索開始から検索結果を取得する様子までが記録されています。

Jul 27 00:11:21 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-20] c.l.c.DataController:66 - Starting query for flows
Jul 27 00:11:21 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-20] c.l.s.FlowQueryServiceImpl:39 - Start new flows query for: 3628a772-5f37-4352-9831-4392c9c64eb7
Jul 27 00:11:21 fc742 docker/svc-query-service[1367]: INFO  [newThreadPoolExecutorFactoryBean-12000] c.l.d.ResultFileHandler:84 - flows-3628a772-5f37-4352-9831-4392c9c64eb7 query is done. Count: 0, Start: 2024-07-27T00:11:21.338Z, End: 2024-07-27T00:11:21.445Z, Elapsed time: 107 ms
Jul 27 00:11:21 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-15] c.l.c.DataController:105 - Checking flows query status for 3628a772-5f37-4352-9831-4392c9c64eb7
Jul 27 00:11:21 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-15] c.l.s.AbstractQueryService:87 - Get flows query status for: 3628a772-5f37-4352-9831-4392c9c64eb7
Jul 27 00:11:22 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-16] c.l.c.DataController:131 - Retrieving flows query result for 3628a772-5f37-4352-9831-4392c9c64eb7
Jul 27 00:11:22 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-16] c.l.s.AbstractQueryService:104 - Get flows query result for: 3628a772-5f37-4352-9831-4392c9c64eb7
Jul 27 00:11:22 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-16] c.l.s.AbstractQueryService:117 - No record found for 3628a772-5f37-4352-9831-4392c9c64eb7.
Jul 27 00:11:22 fc742 docker/svc-query-service[1367]: INFO  [qtp935818862-16] c.l.c.DataController:138 - flows request 3628a772-5f37-4352-9831-4392c9c64eb7 start: 2024-07-27T00:11:21.338Z, end: 2024-07-27T00:11:22.084Z, duration: 746 ms, rows: 0

 

 

 

svc-query-service から vertica へ

ここでようやくデータベース（vertica）へのアクセスが行われます。svc-query-service がデータベースへのアクセスのクライアントとして動作します。svc-query-service から vertica にアクセスがあると vertica のログに記録されます。
vertica のログは以下にあります。

/lancope/var/database/dbs/sw/v_sw_node0001_catalog/vertica.log

 

フロー検索を実行すると、vertica.log に検索に使用した SQL 文が出力されます。

2024-07-27 00:20:10.840 Init Session:0x7f94347db700-a0000000243d17 [Txn] <INFO> Begin Txn: a0000000243d17 'WITH temp_flow_stats_id AS ....

 

svc-query-service と vertica との間には通常複数本のセッションが事前に張られており、それを使用してフロー検索時に vertica に対して SQL クエリを送ります。netstat で確認すると、vertica と java プロセス（svc-query-service）との間で TCPセッションが確立されていることが確認できます。

fc742:/# netstat -anp | grep 5433 | grep ESTAB
tcp        0      0 127.0.0.1:35212         127.0.0.1:5433          ESTABLISHED 3406191/java
tcp        0      0 127.0.0.1:41170         127.0.0.1:5433          ESTABLISHED 10698/java
tcp        0      0 127.0.0.1:5433          127.0.0.1:35144         ESTABLISHED 1769/vertica
tcp        0      0 127.0.0.1:5433          127.0.0.1:35736         ESTABLISHED 1769/vertica
...

 

svc-query-service と vertica 間のセッション確立の様子は vertica.log に記録されています。TCP セッションが確立されているか、SSL/TLS ネゴシエーションが成功しているかどうか、接続後の認証が成功しているかを確認します。

2024-07-27 00:28:25.755 Init Session:0x7f9445be7700 <LOG> @v_sw_node0001: 00000/2705: Connection received: host=127.0.0.1 port=59018 (connCnt 4)
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700 <LOG> @v_sw_node0001: 00000/4540: Received SSL negotiation startup packet
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700 <LOG> @v_sw_node0001: 00000/4691: Sending SSL negotiation response 'N'
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700 <LOG> @v_sw_node0001: 00000/4686: Authentication - sendAuthRequest: user=dbadmin database=sw host=127.0.0.1 authType=66048
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700-a0000000243dac [Txn] <INFO> Begin Txn: a0000000243dac 'check_login_history'
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700-a0000000243dac [Txn] <INFO> Rollback Txn: a0000000243dac 'check_login_history'
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700 <LOG> @v_sw_node0001: 00000/4686: Authentication - sendAuthRequest: user=dbadmin database=sw host=127.0.0.1 authType=0
2024-07-27 00:28:25.755 Init Session:0x7f9445be7700 <LOG> @v_sw_node0001: 00000/2703: Connection authenticated: user=dbadmin database=sw host=127.0.0.1
ラベル：
Getting Started

検索バーにキーワード、フレーズ、または質問を入力し、お探しのものを見つけましょう

シスコ コミュニティをいち早く使いこなしていただけるよう役立つリンクをまとめました。みなさんのジャーニーがより良いものとなるようお手伝いします

Customers Also Viewed These Support Documents