NSX는 보안을 위한 Firewall로 Gateway Firewall과 Distributed Firewall(DFW) 기능을 제공하고 있습니다.
이 중 Distributed Firewall이 동작하는 방식과 문제 증상을 Troubleshooting 하기 위해 필요한 자료 수집을 알아보겠습니다.
우선 Distributed Firewall을 사용하면, 실제 Firewall 기능이 동작하는 부분은 각 Hypervisor에 위치한 VM vNIC의 Filter에 적용됩니다.
NSX DFW가 적용되는 Hypervisor의 vNIC의 dvfilter는 아래 그림과 같이 VM의 vNIC과 Vritutal Switch 사이에 위치합니다.
VM의 vNIC와 Virtual Switch 사이의 Traffic은 여러 종류의 Slot에 의해서 Filtering 되며 Slot 종류는 다음과 같습니다.
- Slot 0 : DVFilter(Distributed Virtual Filter), vNIC에서 ingress/egress traffic을 모니터링 하고, Stateless Filtering과 ACL 수행
- Slot 1 : vmware-swsec,(Switch Security Module), VM의 IP/MAC Address를 Learning하고, VM으로부터 DHCP Ack와 ARP Broadcast Packet을 Capture
- Slot 2 : vmware-sfw(NSX Distributed Firewall), DFW Rule(Firewall Rule과 Connection Table) 적용
- Slot 3 : Reserved
- Slot 4~12 : 3rd party service, 3rd party service로 traffic이 redirect 되는 위치, NSX는 Service Insertion을 위해 Slot 12를 사용
- Slot13~14 : Reserved
- Slot 15 : Distributed Network Encryption
이제 간단하게 DFW Rule을 생성해보면서, Hypervisor에는 어떤 로그가 남는지 살펴보겠습니다.
NSX Manager > Security > Distributed Firewall > Application > Add Policy
Add Rule
테스트를 위해서 Action을 Drop으로 설정하여 Rule을 생성하고 외부에서 NSX 환경의 VM으로 Ping을 시도하면, 실패하는 것을 볼 수 있습니다.
| C:\>ping 172.31.1.30 -t Pinging 172.31.1.30 with 32 bytes of data: Reply from 172.31.1.30: bytes=32 time=3ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Reply from 172.31.1.30: bytes=32 time=3ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Reply from 172.31.1.30: bytes=32 time=4ms TTL=61 Request timed out. Request timed out. Request timed out. Request timed out. Request timed out. |
Hypervisor에서 /var/run/log/nsx-syslog.log 로그를 통해서, DFW Rule 생성 시점에 어떠한 내용들이 기재되는지 볼 수 있습니다.
| 2024-01-26T05:00:09.712Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] MsgDispatcher: dispatching object to component L3CACHE (delta update) ID 157 2024-01-26T05:00:09.712Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] l3: send barrier version 2401 2024-01-26T05:00:09.712Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] MsgDispatcher: dispatching object to component DFW (delta update) ID 157 2024-01-26T05:00:09.712Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] dfw: DfwMsgCache: Start to update, fullSync: false, msgs size: 3 ### <-- !! 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] dfw: DfwMsgCache: updated barrier number 2401 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] dfw: DfwMsgCache: msg to update: sect(1, 0), rule(1, 0), cont(0, 0), group(0, 0) 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] dfw: DfwMsgCache: added section. uuid: 63e96a67-04a3-4fc6-94fc-1b7bc555178b 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] dfw: DfwMsgCache: added rule. id: 1004, section uuid: 63e96a67-04a3-4fc6-94fc-1b7bc555178b ### <-- !! Rule ID 확인 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] dfw: DfwMsgCache: Update done. 4 sections, 6 rules, 0 containers, 3 lsp group relations 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] MsgDispatcher: dispatching object to component IDS (delta update) ID 157 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] ids: IDSMsgCache::UpdateDesiredState: Start to update idsMsgCache, fullSync: false, msgs size: 2 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] ids: IDSMsgCache: got a rule, type: 2, op: 1, ID: 00000000-0000-0000-0000-0000000003ec 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="228B3700" level="info"] ids: IDSMsgCache: Updating nestdb barrier: id { left: 0 right: 0 } desired_state_version: 2401 , ID: 00000000-0000-0000-0000-000000000000 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: process loop wakes up to process request 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: feature flags: 0 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="2242A700" level="info"] ids: IDSApp::processRequest: Successfully processed config changes in 0.051000 ms 2024-01-26T05:00:09.713Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="2242A700" level="info"] ids: IDSApp::processRequest: Updated the processed barrier number to nestdb: 2401 2024-01-26T05:00:09.714Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: build dfw object cache succeed 2024-01-26T05:00:09.714Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Apply global address set config (checkRef: false) 2024-01-26T05:00:09.714Z nestdb-server[1053452]: NSX 1053452 - [nsx@6876 comp="nsx-esx" subcomp="nsx-nestdb" tid="1053452" level="INFO"] Modify: TransactionID='709' Client ID=cfg-agent 2024-01-26T05:00:09.714Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Collected 5 l3 rules and 1 l2 rules for vif 78b179f7-cb81-4478-9f10-147575d506ee 2024-01-26T05:00:09.714Z nestdb-server[1053452]: NSX 1053452 - [nsx@6876 comp="nsx-esx" subcomp="nsx-nestdb" tid="1053452" level="INFO"] Notifying updates to 1 clients 2024-01-26T05:00:09.715Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Set vif 78b179f7-cb81-4478-9f10-147575d506ee mac address to 00:50:56:a6:c6:4b 2024-01-26T05:00:09.716Z nestdb-server[1053452]: NSX 1053452 - [nsx@6876 comp="nsx-esx" subcomp="nsx-nestdb" tid="1053452" level="INFO"] Modify: TransactionID='710' Client ID=cfg-agent 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Applied rule config to filter nic-2620907-eth0-vmware-sfw.2 of vif 78b179f7-cb81-4478-9f10-147575d506ee ### <-- !! 적용 VM의 vNIC의 vmware-sfw Slot 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: apply config done (dirty cache) 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Clean global address set config (checkRef: true) 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: update the processed barrier number to nestdb: 2401 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: update the processed barrier number to nestdb: 2401 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Successfully processed request ### <-- !! 2024-01-26T05:00:09.716Z cfgAgent[1053527]: NSX 1053527 - [nsx@6876 comp="nsx-controller" subcomp="cfgAgent" tid="220A3700" level="info"] dfw: Time took to process request: 3 ms |
DFW Rule의 Match 여부에 대해 Log로 확인할 수 있는데 기본적으로 DFW Logging은 비활성화 되어 있기 때문에 이를 활성화 한 후에 Hypervisor의 /var/run/log/dfwpktlogs.log 로그를 통해서 확인할 수 있습니다.
아래는 DFW Logging을 활성화 한 후, 테스트 VM으로 Ping 시도를 할 때 Packet이 Rule에 의해서 Drop 되는 것을 로그 상으로 확인할 수 있습니다.
| 2024-01-26T05:09:53.019Z 75d506ee INET match DROP 1004 IN 60 TCP 172.31.1.254/2944->172.31.1.30/80 S 2024-01-26T05:09:53.019Z 75d506ee INET match DROP 1004 IN 60 TCP 172.31.1.254/2934->172.31.1.30/80 S |
DROP Action으로 정의되어 있던 Rule을 Allow로 변경하여, 기록되는 로그를 보면 다음과 같습니다.
| 2024-01-26T05:12:38.054Z 75d506ee INET match PASS 1004 IN 60 TCP 172.31.1.254/3744->172.31.1.30/80 S 2024-01-26T05:12:38.054Z 75d506ee INET match PASS 1004 IN 60 TCP 172.31.1.254/3740->172.31.1.30/80 S |
DFW Rule이 각 VM의 vNIC에 설정되기 때문에, Interface 확인 및 Interface에 설정된 Rule 확인하는 방법을 살펴보겠습니다.
summarize-dvfilter 명령어를 사용하면, 현재 Hypervisor의 dvfilter에 등록된 Interface들을 볼 수 있습니다.
| [root@esxi-comp-01:~] summarize-dvfilter Fastpaths: agent: vmware-si, refCount: 1, rev: 0x1010000, apiRev: 0x1010000, module: nsxt-vsip-22104635 agent: vmware-sfw, refCount: 5, rev: 0x1010000, apiRev: 0x1010000, module: nsxt-vsip-22104635 agent: nsx_bridgelearningfilter, refCount: 1, rev: 0x1010000, apiRev: 0x1010000, module: nsxt-vdrb-22104635 agent: ESXi-Firewall, refCount: 5, rev: 0x1010000, apiRev: 0x1010000, module: esxfw agent: dvfilter-generic-vmware, refCount: 1, rev: 0x1010000, apiRev: 0x1010000, module: dvfilter-generic-fastpath agent: dvfilter-faulter, refCount: 1, rev: 0x1010000, apiRev: 0x1010000, module: dvfilter ServiceVMs: serviceVM: 1, agent vmware-sfw, refCount: 1, rev: 0x4, apiRev: 0x4, capabilities: csum,tso serviceVM: 2, agent vmware-sfw, refCount: 2, rev: 0x4, apiRev: 0x4, capabilities: csum,tso Filters: world 0 <no world> port 67108872 vmk0 vNic slot 0 name: nic-0-eth4294967295-ESXi-Firewall.0 agentName: ESXi-Firewall state: IOChain Attached vmState: Detached failurePolicy: failOpen serviceVMID: none filter source: Invalid moduleName: esxfw port 100663310 vmk10 vNic slot 0 name: nic-0-eth4294967295-ESXi-Firewall.0 agentName: ESXi-Firewall state: IOChain Attached vmState: Detached failurePolicy: failOpen serviceVMID: none filter source: Invalid moduleName: esxfw port 100663311 vmk11 vNic slot 0 name: nic-0-eth4294967295-ESXi-Firewall.0 agentName: ESXi-Firewall state: IOChain Attached vmState: Detached failurePolicy: failOpen serviceVMID: none filter source: Invalid moduleName: esxfw port 100663312 vmk50 vNic slot 0 name: nic-0-eth4294967295-ESXi-Firewall.0 agentName: ESXi-Firewall state: IOChain Attached vmState: Detached failurePolicy: failOpen serviceVMID: none filter source: Invalid moduleName: esxfw world 2620907 vmm0:centos7 vcUuid:'50 26 6b b3 18 0a 84 ed-0f 91 e0 49 9d 97 cd 53' port 67108894 centos7 vNic slot 2 name: nic-2620907-eth1-vmware-sfw.2 agentName: vmware-sfw state: IOChain Attached vmState: Detached failurePolicy: failClosed serviceVMID: none filter source: Dynamic Filter Creation moduleName: nsxt-vsip-22104635 port 100663325 centos7.eth0 vNic slot 2 name: nic-2620907-eth0-vmware-sfw.2 ### <-- !! 우리가 봐야하는 Interface의 Slot agentName: vmware-sfw ### <-- !! state: IOChain Attached vmState: Attached failurePolicy: failClosed serviceVMID: 2 filter source: Dynamic Filter Creation moduleName: nsxt-vsip-22104635 |
위에서 확인한 Interface를 이용하여, 해당 Interface에 등록된 Rule 및 Rule에 Hit된 통계치 값도 살펴볼 수 있습니다.
| [root@esxi-comp-01:~] vsipioctl getrules -f nic-2620907-eth0-vmware-sfw.2 ruleset mainrs { # generation number: 0 # realization time : 2024-01-26T05:12:36 # FILTER (APP Category) rules rule 1004 at 1 inout protocol any from any to any accept with log; ### <-- !! 수동으로 추가한 DFW Rule rule 3 at 2 inout inet6 protocol ipv6-icmp icmptype 136 from any to any accept; rule 3 at 3 inout inet6 protocol ipv6-icmp icmptype 135 from any to any accept; rule 4 at 4 inout protocol udp from any to any port {67, 68} accept; rule 2 at 5 inout protocol any from any to any accept; } ruleset mainrs_L2 { # generation number: 0 # realization time : 2024-01-26T05:12:36 # FILTER rules rule 1 at 1 inout ethertype any stateless from any to any accept; } [root@esxi-comp-01:~] vsipioctl getrules -f nic-2620907-eth0-vmware-sfw.2 -s ruleset mainrs { # FILTER (APP Category) rules rule 1004 at 1, 1020 evals, 1011 hits, 734 sessions, in 1661 out 1326 pkts, in 99524 out 66128 bytes rule 3 at 2, 0 evals, 0 hits, 0 sessions, in 0 out 0 pkts, in 0 out 0 bytes rule 3 at 3, 0 evals, 0 hits, 0 sessions, in 0 out 0 pkts, in 0 out 0 bytes rule 4 at 4, 510 evals, 0 hits, 0 sessions, in 0 out 0 pkts, in 0 out 0 bytes rule 2 at 5, 510 evals, 146317 hits, 146284 sessions, in 813034 out 482059 pkts, in 46002345 out 353746133 bytes } ruleset mainrs_L2 { # FILTER rules rule 1 at 1, 0 evals, 0 hits, 0 sessions, in 0 out 0 pkts, in 0 out 0 bytes } |
DFW Rule에 설정된 Source/Destination Address에 대한 정보를 확인하기 위해서 테스트로 IP Address Group을 만들어서 DFW Rule에 추가하고 나서 명령어로 조회하면 DFW Rule에 설정한 IP Address 정보를 확인할 수 있습니다.
| [root@esxi-comp-01:~] vsipioctl getaddrset -f nic-2620907-eth0-vmware-sfw.2 addrset is shared for this filter global addrset addrset f43da74a-7dc9-48a3-b9c9-b1de30f79846 { ip 172.31.1.30, } local addrset No address sets. |
DFW Rule에 의한 Packet Drop 여부를 추정하기 위해서는 최초 dvfilter가 위치한 그림에서 보이듯이 vNIC으로 Packet이 들어오고 나가는 구간에 위치해있기 때문에, dvfilter 전/후에서 Packet을 수집해봐야 합니다.
dvfilter 전/후에 Packet을 수집하기 위해서는 pktcap-uw 도구를 이용합니다.
| ## filter 전 [root@esxi-comp-01:~] pktcap-uw -c 5 --capture PreDVFilter --dvfilter nic-2620907-eth0-vmware-sfw.2 -o - | tcpdump-uw -enr - To capture 5 packets. The session capture point is PreDVFilter. The name of the dvfilter is nic-2620907-eth0-vmware-sfw.2. pktcap: The output file is -. pktcap: No server port specifed, select 17145 as the port. pktcap: Local CID 2. pktcap: Listen on port 17145. pktcap: Main thread: 489746348928. pktcap: Dump Thread: 489746884352. pktcap: Recv Thread: 489747412736. pktcap: Accept... pktcap: Vsock connection from port 1029 cid 2. reading from file -, link-type EN10MB (Ethernet) 06:01:02.602395 02:50:56:56:44:52 > 00:50:56:a6:c6:4b, ethertype IPv4 (0x0800), length 74: 192.168.1.2 > 172.31.1.30: ICMP echo request, id 1, seq 10021, length 40 06:01:02.602705 00:50:56:a6:c6:4b > 02:50:56:56:44:52, ethertype IPv4 (0x0800), length 74: 172.31.1.30 > 192.168.1.2: ICMP echo reply, id 1, seq 10021, length 40 06:01:03.606055 02:50:56:56:44:52 > 00:50:56:a6:c6:4b, ethertype IPv4 (0x0800), length 74: 192.168.1.2 > 172.31.1.30: ICMP echo request, id 1, seq 10022, length 40 pktcap: Receive thread exiting... pktcap: Dump thread exiting... 06:01:03.606346 00:50:56:a6:c6:4b > 02:50:56:56:44:52, ethertype IPv4 (0x0800), length 74: 172.31.1.30 > 192.168.1.2: ICMP echo reply, id 1, seq 10022, length 40 06:01:03.712764 02:50:56:00:30:00 > 00:50:56:a6:c6:4b, ethertype IPv4 (0x0800), length 74: 172.31.1.254.3504 > 172.31.1.30.80: Flags [S], seq 1119789484, win 64240, options [mss 1460,sackOK,TS val 2281931899 ecr 0,nop,wscale 8], length 0 pktcap: Destroying session 3. pktcap: pktcap: Dumped 5 packet to file -, dropped 0 packets. pktcap: Done. ## filter 후 [root@esxi-comp-01:~] pktcap-uw -c 5 --capture PostDVFilter --dvfilter nic-2620907-eth0-vmware-sfw.2 -o - | tcpdump-uw -enr - To capture 5 packets. The session capture point is PostDVFilter. The name of the dvfilter is nic-2620907-eth0-vmware-sfw.2. pktcap: The output file is -. pktcap: No server port specifed, select 16998 as the port. pktcap: Local CID 2. pktcap: Listen on port 16998. pktcap: Main thread: 211474324352. pktcap: Dump Thread: 211474859776. pktcap: Recv Thread: 211475388160. pktcap: Accept... pktcap: Vsock connection from port 1028 cid 2. reading from file -, link-type EN10MB (Ethernet) 06:01:01.584931 02:50:56:56:44:52 > 00:50:56:a6:c6:4b, ethertype IPv4 (0x0800), length 74: 192.168.1.2 > 172.31.1.30: ICMP echo request, id 1, seq 10020, length 40 06:01:01.585271 00:50:56:a6:c6:4b > 02:50:56:56:44:52, ethertype IPv4 (0x0800), length 74: 172.31.1.30 > 192.168.1.2: ICMP echo reply, id 1, seq 10020, length 40 06:01:02.602422 02:50:56:56:44:52 > 00:50:56:a6:c6:4b, ethertype IPv4 (0x0800), length 74: 192.168.1.2 > 172.31.1.30: ICMP echo request, id 1, seq 10021, length 40 06:01:02.602729 00:50:56:a6:c6:4b > 02:50:56:56:44:52, ethertype IPv4 (0x0800), length 74: 172.31.1.30 > 192.168.1.2: ICMP echo reply, id 1, seq 10021, length 40 pktcap: Receive thread exiting... pktcap: Dump thread exiting... 06:01:03.606083 02:50:56:56:44:52 > 00:50:56:a6:c6:4b, ethertype IPv4 (0x0800), length 74: 192.168.1.2 > 172.31.1.30: ICMP echo request, id 1, seq 10022, length 40 pktcap: Destroying session 2. pktcap: pktcap: Dumped 5 packet to file -, dropped 0 packets. pktcap: Done. |
관련 로그
NSX Manager
- /var/log/policy.log
- /var/log/policy/localhost_access_log.txt
- /var/log/proton/nsxapi.log
ESXi Transport Node
- /var/run/log/vmkernel.log
- /var/run/log/dfwpktlogs.log ## NSX Manager에서 Rule Logging이 활성화 되어 있는 경우
- /var/run/log/nsx-syslog.log ## Keyword로 dfw 사용
'Networking' 카테고리의 다른 글
| [NSX] Failed to bring up one of vNICs after vMotion of VM edge (0) | 2024.02.13 |
|---|---|
| [NSX] Gateway Firewall (0) | 2024.01.28 |
| [NSX] BGP Basic Check (0) | 2024.01.20 |
| [NSX] Logical Routing (1) | 2024.01.15 |
| [NSX] Basic Check #3 (1) | 2023.12.11 |
