山石網科-Hillstone-IPsec V_P_N常見故障debug排錯心得終結版

時間 2019-11-09

標籤山石 hillstone ipsec 常見故障 debug 排錯心得終結欄目 VPS 简体版

原文原文鏈接

嗨，各位好。算法

相信各位過來點開的時候會鄙視一句「這廝，又來搞山石了」，哈哈沒錯，此次確實又來了，不過此次帶了點排錯的心得過來，但願給將來在常見的配置過程中，不知道怎麼排錯時候有些幫助。安全

說句真心話，山石（hillstone）確實挺好用的，不行你能夠試試！！服務器

好了，廢話少說。直接上菜cookie

ipsec的拓撲圖，我臨時畫了一個，目的但願各位能有圖看到，否則各位內心冒出千萬個草泥馬「NO picture NO bb」。網絡

（這萬惡的水印）可有可無，今天的主題在倆臺firewall上面。此圖ipsec配置模式爲tunnel路由模式***。不過本文會把策略***和路由***的常見錯誤一塊兒帶過，請各位細心品味session

在咱們日常企業組網應用中，常常會遇到組建***網絡的需求，最基礎的就是site to site，稍微複雜一點的全網site to site ipsec *** 互聯，工做量頂大，不過安全。避免了那種hub-spoken的中心與分支的關係（雖然工做量小，但隱患很大）app

你們基本都知道ipsec-***協商有倆個階段，第一階段和第二階段，那麼第一階段和第二階段分別協商什麼呢？本身去看書。（:!!!!運維

直接上ipsec的配置中可能會到的幾個問題？ide

公網出接口選錯！以下圖，這個選錯就該抽鞭子！！

學習
共享密鑰填寫一些有爭議的字母好比（1和I、l（L）和一、O（大寫o）和0）等，致使項目溝通郵件過程當中，對端密鑰填寫錯誤！這種錯誤該扣工資！！！
第一階段connection type 手抖選錯type！這個通常不存在，不過我常常會把這裏改掉讓新進入團隊的兄弟們去排錯檢查，很鍛鍊人！！說真的
算法寫錯！這個我就不列舉了，直接扣工資。
PS：不瞞你們，我曾見過一家公司由於***配置倆天沒配好，結果我過去檢查了一下發現倆邊算法填錯了，當場對方的主管就把那運維工程師開除了。看得我好緊張！！！後面都不敢手滑！！
圖：（省略）
第二階段自動鏈接沒勾選！有部分其餘產商設備，此項沒有勾選會存在一些問題。
第二階段代理ID未填寫或填寫不對？若對端是山石同款，則勾選auto便可，如果其餘設備就要填寫代理id了。
記住，代理ID不是後期興趣流量的匹配定義，而是第二階段協商的參數之一，這個觀念不少入門級的「選手」都沒有弄清楚！！請格外注意。因此你在策略中去放行對應流量的同時須要控制進出興趣流量，切記嚴謹開放策略，不然就是any到any！！
第一階段和第二階段所有都up了，倆邊內網流量仍是沒法正常通訊！

此時就應該檢查下tunnel的路由寫過沒有？、snat的指定不轉換作了沒有？路由模式***的策略方向是否放行正確？策略模式***的security connection方向選錯沒有？

你們隨着我往下看，常見的配置錯誤以及思路簡單在上面介紹了一下。如今着重聊排錯環節？（訪客：「鋪墊這麼久才進入狀態，差評」！！！）

各位久等了，如下爲各位演示在以上出錯的狀況下，hillstone cli（命令行）debug *** 調試日誌的解讀技巧和我的排錯經典心得。

配菜，你們繼續開開胃。

客戶名稱：（···作網工仍是要有極強的保密意識，這關係到職業道德）省略
情景：撥通了L2TP-***，可是ping不一樣內網服務器

SSH進入hillstone底層使用debug命令：（語法以下）

debug dp filter src-ip 10.91.0.15 proto icmp 【該地址爲L2TP-虛擬獲取的地址】

debug dp filter dst-ip 10.10.0.1 proto icmp

debug dp basic

debug dp drop

debug self

A05-qujun-Fw[DBG](config)# clear logg debug

A05-qujun-Fw[DBG](config)# show logg debug

2015-12-17 11:23:53, DEBUG@FLOW: core 1 (sys up 0x1aa53c70a ms): Finish decap

Packet: 10.91.0.15 -> 10.9.1.1, id: 96, ip size 60, prot: 1(ICMP)

dp_prepare_pak_lookup srcip: 10.91.0.15, dstip: 10.9.1.1,prot 1

No session found, try to create session

-----------------First path creating new session-----------------

--------VR:trust-vr start--------

10.91.0.15:1->10.9.1.1:20876

NAT: ICMP protocol type/code 0800

No DNAT matches, skip DNAT

Get nexthop if_id: 9, flags: 22, nexthop: 103.20.248.1

Interface route

NAT: ICMP protocol type/code 0800

Matched source NAT: snat rule id:2

Matched source NAT: source port1->port22589

--------VR:trust-vr end--------

begin lookup predefine prot:1 port:20876

Identified as app PING (prot=1). timeout 6.

Pak src zone L2TP, dst zone untrust, prot 1, dst-port 20876.

No policy matches, default ===DENY=== 【數據沒有匹配，被防火牆drop了，思考~~~~~】

Dropped: Can't find policy/policy denied. Abort!!

deny session:flow0 src 10.91.0.15 --> dst 10.9.1.1 Deny session installed successfully

-----------------------First path over (session not created)

Droppped: failed to create session, drop the packet

仔細檢查下來，發現ping錯了，再次debug，數據正常轉發。呃，抽本身鞭子

A05-qujun-Fw[DBG](config)# show log debug

2015-12-17 11:32:39, DEBUG@FLOW: core 1 (sys up 0x1aa5bce54 ms): Finish decap

Packet: 10.91.0.15 -> 10.10.1.1, id: 100, ip size 60, prot: 1(ICMP)

dp_prepare_pak_lookup srcip: 10.91.0.15, dstip: 10.10.1.1,prot 1

No session found, try to create session

-----------------First path creating new session-----------------

--------VR:trust-vr start--------

10.91.0.15:1->10.10.1.1:20879

NAT: ICMP protocol type/code 0800

No DNAT matches, skip DNAT

Get nexthop if_id: 13, flags: 2, nexthop: 10.10.0.254

Interface route

NAT: ICMP protocol type/code 0800

No SNAT matches, or out of pool, skip SNAT

--------VR:trust-vr end--------

begin lookup predefine prot:1 port:20879

Identified as app PING (prot=1). timeout 6.

Pak src zone L2TP, dst zone dmz, prot 1, dst-port 20879.

Policy 6 matches, ===PERMIT===【數據匹配，後面就不說了，直接歡樂的轉發咯】

flow0 src 10.91.0.15 --> dst 10.10.1.1 with nexthop 10.10.0.254 ifindex 13

flow1 tunnel, id=153

flow1 src 10.10.1.1 --> dst 10.91.0.15 nexthop not lookup or invalid

flow0's next hop: 0.0.0.0 flow1's next hop: 10.10.0.254

······（省略）

***錯誤故障debug調試主菜①：***紅燒肉【注意筆者標紅的地方，公網地址已和諧】

***調試中使用的語法：【如下均爲此命令】

debug ***

debug *** filter ip x.x.x.x

clear logging debug

show logging debug

A05-qujun-Fw[DBG]# show log debug

2015-12-17 11:58:46, DEBUG@***: phase2 negotiation failed due to time up waiting for phase1.

2015-12-17 11:58:46, DEBUG@***: delete phase 2 handler.

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Resend phase1 packet d082f40cfa318a5c:481f7e4f1262f27a

2015-12-17 11:58:47, DEBUG@***:

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: ++++++++Phase 1 main mode third msg receive START+++++++

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Begin decryption ...

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: IV was saved for next processing:

2015-12-17 11:58:47, DEBUG@***: a73f0fe2 1742d5fe

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: with key:

2015-12-17 11:58:47, DEBUG@***: 7439a7fe b79997b9

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Decrypted payload by IV:

2015-12-17 11:58:47, DEBUG@***: 2bebedc2 c51b4e96

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Skip to trim padding

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Decrypted packet:

2015-12-17 11:58:47, DEBUG@***: d082f40c fa318a5c 481f7e4f 1262f27a 05100201 00000000 00000044 ba09b8b5

94a49bc2 2534d628 de147031 88bfe620 843272ae eac0e720 3e332165 099a3bab

4edd1f7c

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Decrypt packet sucessful!

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: ===============Receive===============

2015-12-17 11:58:47, DEBUG@***: ISAKMP Header Format:

2015-12-17 11:58:47, DEBUG@***: Initiator Cookie:3498243084 4197550684

2015-12-17 11:58:47, DEBUG@***: Responder Cookie:1210023503 308474490

2015-12-17 11:58:47, DEBUG@***: Next Payload Type:5

2015-12-17 11:58:47, DEBUG@***: Exchange Type:2

2015-12-17 11:58:47, DEBUG@***: Flags:1

2015-12-17 11:58:47, DEBUG@***: Message ID:0

2015-12-17 11:58:47, DEBUG@***: Length:68

2015-12-17 11:58:47, DEBUG@***: Payload Generic Header:

2015-12-17 11:58:47, DEBUG@***: Next Payload Type:186

2015-12-17 11:58:47, DEBUG@***: Length:47285

2015-12-17 11:58:47, DEBUG@***: Content:

2015-12-17 11:58:47, DEBUG@***: <Identification Payload>

2015-12-17 11:58:47, DEBUG@***: ================================

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: DUMP of above packet:

2015-12-17 11:58:47, DEBUG@***: d082f40c fa318a5c 481f7e4f 1262f27a 05100201 00000000 00000044 ba09b8b5

94a49bc2 2534d628 de147031 88bfe620 843272ae eac0e720 3e332165 099a3bab

4edd1f7c

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: Invalid payload or failed to malloc buffer(pre-share key may mismatch).【共享密鑰填寫錯誤，各位主管看着辦，扣工資的扣工資，抽鞭子的抽鞭子】

2015-12-17 11:58:47, DEBUG@***: [x.x.x.x]: ++++++++Phase 1 main mode third msg receive END+++++++

***錯誤故障debug調試主菜②：***涼拌西紅柿【注意筆者標紅的地方】

A05-qujun-Fw[DBG]# show log debug

2015-12-17 12:12:28, DEBUG@FLOW: core 1 (sys up 0x1aa8040d9 ms): Finish decap

Packet: 10.234.1.10 -> 10.10.1.1, id: 14819, ip size 60, prot: 1(ICMP)

dp_prepare_pak_lookup srcip: 10.234.1.10, dstip: 10.10.1.1,prot 1

No session found, try to create session

-----------------First path creating new session-----------------

--------VR:trust-vr start--------

10.234.1.10:1->10.10.1.1:24882

NAT: ICMP protocol type/code 0800

No DNAT matches, skip DNAT

Get nexthop if_id: 13, flags: 2, nexthop: 10.10.0.254

Interface route

Found the reverse route for force or prefer revs-route setting

NAT: ICMP protocol type/code 0800

No SNAT matches, or out of pool, skip SNAT

--------VR:trust-vr end--------

begin lookup predefine prot:1 port:24882

Identified as app PING (prot=1). timeout 6.

Pak src zone untrust, dst zone dmz, prot 1, dst-port 24882.【流量訪問正確】

No policy matches, default ===DENY===【策略沒匹配到，此時思考是否是策略***的policy沒有置頂，致使沒有匹配到被設備drop掉了】

Dropped: Can't find policy/policy denied. Abort!!

deny session:flow0 src 10.234.1.10 --> dst 10.10.1.1 Deny session installed successfully

-----------------------First path over (session not created)

Droppped: failed to create session, drop the packet

***錯誤故障debug調試主菜②：***蒜泥小龍蝦【注意筆者標紅的地方，公網地址已和諧】

A05-qujun-Fw[DBG]# show log debug

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Peer Main mode, try to find rmconf by IP and local if.

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Peer IP: x.x.x.x

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Local IP: 103.20.248.96

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Rmconf flag 80010121.

2015-12-17 21:40:38, DEBUG@***: 00020000 671577dc 00000000 00000000

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Get rmconf sucessful

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Begin to negotiate with found rmconf, name To WX-51IDC

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: respond new phase 1 negotiation: 103.20.248.96:500<=>x.x.x.x:500

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: begin Identity Protection mode.

2015-12-17 21:40:38, DEBUG@***:

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: ++++++++Phase 1 main mode first msg receive START.++++++++

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: ===============Receive===============

2015-12-17 21:40:38, DEBUG@***: ISAKMP Header Format:

2015-12-17 21:40:38, DEBUG@***: Initiator Cookie:307148809 2169817196

2015-12-17 21:40:38, DEBUG@***: Responder Cookie:0 0

2015-12-17 21:40:38, DEBUG@***: Next Payload Type:1

2015-12-17 21:40:38, DEBUG@***: Exchange Type:2

2015-12-17 21:40:38, DEBUG@***: Flags:0

2015-12-17 21:40:38, DEBUG@***: Message ID:0

2015-12-17 21:40:38, DEBUG@***: Length:124

2015-12-17 21:40:38, DEBUG@***: Payload Generic Header:

2015-12-17 21:40:38, DEBUG@***: Next Payload Type:13

2015-12-17 21:40:38, DEBUG@***: Length:56

2015-12-17 21:40:38, DEBUG@***: Content:

2015-12-17 21:40:38, DEBUG@***: <SA Info>

2015-12-17 21:40:38, DEBUG@***: Payload Generic Header:

2015-12-17 21:40:38, DEBUG@***: Next Payload Type:13

2015-12-17 21:40:38, DEBUG@***: Length:20

2015-12-17 21:40:38, DEBUG@***: Content:

2015-12-17 21:40:38, DEBUG@***: <Vender ID Payload>

2015-12-17 21:40:38, DEBUG@***: Vendor ID:

2015-12-17 21:40:38, DEBUG@***: Payload Generic Header:

2015-12-17 21:40:38, DEBUG@***: Next Payload Type:0

2015-12-17 21:40:38, DEBUG@***: Length:20

2015-12-17 21:40:38, DEBUG@***: Content:

2015-12-17 21:40:38, DEBUG@***: <Vender ID Payload>

2015-12-17 21:40:38, DEBUG@***: Vendor ID:

2015-12-17 21:40:38, DEBUG@***: ================================

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Dump of above packet:

2015-12-17 21:40:38, DEBUG@***: 124eb809 8154c86c 00000000 00000000 01100200 00000000 0000007c 0d000038

00000001 00000001 0000002c 01010001 00000024 01010000 800b0001 000c0004

00015180 80010005 80030001 80020001 80040002 0d000014 afcad713 68a1f1c9

6b8696fc 77570100 00000014 36665412 e8c59732 317454ee efef85b6

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: phase 1 (main mode): remote supports DPD

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Compared: DB:Peer【比較本端和對端協商參數】

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: (lifetime = 86400:86400)

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: (lifebyte = 0:0)

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: enctype = DES-CBC:3DES-CBC【opps，算法配錯了】

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: (encklen = 0:0)

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: hashtype = MD5:MD5

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: authmethod = pre-shared key:pre-shared key

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: dh_group = 1024-bit MODP group:1024-bit MODP group

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Rejected enctype: DB(prop#1:trns#1):Peer(prop#1:trns#1) = DES-CBC:3DES-CBC

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: No suitable proposal found【沒有合適的提議被發現，不說了，抽鞭子！！！！】

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Phase 1 (main mode): failed to get valid proposal!

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: ++++++++Phase 1 main mode first msg receive END.++++++++

2015-12-17 21:40:38, DEBUG@***:

2015-12-17 21:40:38, DEBUG@***: [x.x.x.x]: Failed to process packet.

而後本身細心的查看了倆邊的配置文件，以下圖：

SITE-A與SITE-B的第一階段配置文件show：

同時也證實了，第一階段確實有配置出入的地方~~~~~~

***錯誤故障debug調試主菜③：***外婆菜【注意筆者標紅的地方，公網地址已和諧】

A05-qujun-Fw[DBG]# show logg debug

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Receive Information.

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Begin decryption ...

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: IV was saved for next processing:

2015-12-17 21:50:22, DEBUG@***: bb648cbe 7dd114ad

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: with key:

2015-12-17 21:50:22, DEBUG@***: b13ee2ad 40c39cef

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Decrypted payload by IV:

2015-12-17 21:50:22, DEBUG@***: 9d8257e5 0e680b7d

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Skip to trim padding

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Decrypted packet:

2015-12-17 21:50:22, DEBUG@***: eef157b3 3b0f4a19 78058009 563e7e36 08100501 b05744e5 00000054 0b000014

709932fd 98e3b39c d23093f8 05f564f0 00000020 00000001 01108d28 eef157b3

3b0f4a19 78058009 563e7e36 00000041 0a51ae03

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Decrypt packet sucessful!

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Hash validated.

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: DPD R-U-There received

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Begin encryption ...

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: Encrypted successful!

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: received a valid R-U-THERE, ACK sent

2015-12-17 21:50:22, DEBUG@***: [x.x.x.x]: notification message 36136:36136, doi=1 proto_id=1 spi=eef157b33b0f4a19 78058009563e7

e36 (size=16).

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: DPD monitoring....

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Begin encryption ...

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Encrypted successful!

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: DPD R-U-There sent (0)

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: rescheduling send_r_u (10).

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Receive Information.

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Begin decryption ...

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: IV was saved for next processing:

2015-12-17 21:50:23, DEBUG@***: 29503bf1 0657c560

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: with key:

2015-12-17 21:50:23, DEBUG@***: b13ee2ad 40c39cef

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Decrypted payload by IV:

2015-12-17 21:50:23, DEBUG@***: ff76dc93 093f62f7

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Skip to trim padding

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Decrypted packet:

2015-12-17 21:50:23, DEBUG@***: eef157b3 3b0f4a19 78058009 563e7e36 08100501 fe48cae7 00000054 0b000014

120e019f 66e1fad1 1f9c2401 6ba98b8b 00000020 00000001 01108d29 eef157b3

3b0f4a19 78058009 563e7e36 00000771 fc7fdf03

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Decrypt packet sucessful!

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: Hash validated.

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: DPD R-U-There-Ack received

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: received an R-U-THERE-ACK

2015-12-17 21:50:23, DEBUG@***: [x.x.x.x]: notification message 36137:36137, doi=1 proto_id=1 spi=eef157b33b0f4a19 78058009563e7

（·············省略部分協商輸出日誌）

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: phase 2 (quick mode) : received IDci2:

2015-12-17 21:50:26, DEBUG@***: 04000000 0aea0100 ffffff00

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: phase 2 (quick mode) : received IDcr2:

2015-12-17 21:50:26, DEBUG@***: 04000000 0a0a0000 ffff0000

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: phase 2 (quick mode) : Begin to HASH(1) validate ...

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Phase 2 (quick mode) : HASH(1) matched.

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: phase2 handler negotiating already exists, ignore phase2 negotiation request

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Detect double p2handle, Kill p for it's responder.

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: get a src address from ID payload 10.234.1.0:0 prefixlen=24 ul_proto=255

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: get dst address from ID payload 10.10.0.0:0 prefixlen=16 ul_proto=255

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Suitable SP found:10.234.1.0:0/24[ 10.10.0.0:0/16[ proto=any dir=in

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel reqid=0:0)

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: (trns_id=DES encklen=0 authtype=hmac-md5)

2015-12-17 21:50:26, DEBUG@***: life duration was in TLV.

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Begin compare proposals

2015-12-17 21:50:26, DEBUG@***: prop#=1 prot-id=ESP spi-size=4 #trns=1 trns#=1 trns-id=DES

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Begin to compare my and peer's proposal ...

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Peer's single bundle:

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: (proto_id=ESP spisize=4 spi=4d804926 spi_p=00000000 encmode=Tunnel reqid=0:0)

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: (trns_id=DES encklen=0 authtype=hmac-md5)

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: My single bundle:

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel reqid=0:0)

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: (trns_id=DES encklen=0 authtype=hmac-md5)

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: pfs group mismatched: my:2 peer:0【第二階段pfs組不匹配，填寫錯誤！！】

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: Not matched

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: No suitable proposals found.

2015-12-17 21:50:26, DEBUG@***: [x.x.x.x]: ++++++++Phase 2 (quick mode) first msg receive END.++++++++

一樣，我在hillstone底層查看了第二階段的配置文件show圖以下：

PS：左邊可能還存在代理ID沒填寫的問題，請你們注意。

***錯誤故障debug調試主菜④：***鐵板魷魚【注意筆者標紅的地方，公網地址已和諧】

A05-qujun-Fw[DBG]# show logging debug

2015-12-17 22:06:27, DEBUG@***: cookie: -1, 0, -1, 0, 0

2015-12-17 22:06:27, DEBUG@***: IPC start (SA_GET_LIFESIZE)

2015-12-17 22:06:27, DEBUG@***: Sa index : 307

2015-12-17 22:06:27, DEBUG@***: Fpmsg_send_and_recv return ok

2015-12-17 22:06:27, DEBUG@***: 4505, 1170652208, 2096965600, 4637893, 4136288.

2015-12-17 22:06:27, DEBUG@***: dp's lifesize is 04613972

2015-12-17 22:06:27, DEBUG@***: SA 307 's lifesize is 4505

2015-12-17 22:06:27, DEBUG@***: IPC start (SA_GET_LIFESIZE)

2015-12-17 22:06:27, DEBUG@***: Sa index : 202

2015-12-17 22:06:27, DEBUG@***: Fpmsg_send_and_recv return ok

2015-12-17 22:06:27, DEBUG@***: 0, 96232, 118944, 1241, 1712.

2015-12-17 22:06:27, DEBUG@***: dp's lifesize is 00

2015-12-17 22:06:27, DEBUG@***: SA 202 's lifesize is 0

2015-12-17 22:06:28, DEBUG@***: cookie: -1, 0, -1, 0, 0

2015-12-17 22:06:28, DEBUG@***: IPC start (SA_GET_LIFESIZE)

2015-12-17 22:06:28, DEBUG@***: Sa index : 307

2015-12-17 22:06:28, DEBUG@***: Fpmsg_send_and_recv return ok

2015-12-17 22:06:28, DEBUG@***: 4506, 1170653088, 2096965840, 4637902, 4136293.

2015-12-17 22:06:28, DEBUG@***: dp's lifesize is 04615152

2015-12-17 22:06:28, DEBUG@***: SA 307 's lifesize is 4506

2015-12-17 22:06:28, DEBUG@***: IPC start (SA_GET_LIFESIZE)

2015-12-17 22:06:28, DEBUG@***: Sa index : 202

2015-12-17 22:06:28, DEBUG@***: Fpmsg_send_and_recv return ok

2015-12-17 22:06:28, DEBUG@***: 0, 96232, 118944, 1241, 1712.

2015-12-17 22:06:28, DEBUG@***: dp's lifesize is 00

2015-12-17 22:06:28, DEBUG@***: SA 202 's lifesize is 0

2015-12-17 22:06:57, DEBUG@***: [x.x.x.x]: IKE daemon start ike negotiation as initiator,with this sa index:202【security connection type 選擇有出入，總之仍然是配置錯誤！！！】

2015-12-17 22:06:57, DEBUG@***: [x.x.x.x]: Peer address not found or responder only connection-type

2015-12-17 22:06:57, DEBUG@***: [x.x.x.x]: Can not start negotiation as initiator

2015-12-17 22:07:23, DEBUG@***: cookie: -1, 0, -1, 0, 0

2015-12-17 22:07:23, DEBUG@***: IPC start (SA_GET_LIFESIZE)

2015-12-17 22:07:23, DEBUG@***: Sa index : 307

2015-12-17 22:07:23, DEBUG@***: Fpmsg_send_and_recv return ok

2015-12-17 22:07:23, DEBUG@***: 4555, 1170690240, 2096975856, 4638273, 4136501.

2015-12-17 22:07:23, DEBUG@***: dp's lifesize is 04664816

2015-12-17 22:07:23, DEBUG@***: SA 307 's lifesize is 4555

2015-12-17 22:07:23, DEBUG@***: IPC start (SA_GET_LIFESIZE)

2015-12-17 22:07:23, DEBUG@***: Sa index : 202

2015-12-17 22:07:23, DEBUG@***: Fpmsg_send_and_recv return ok