PfSense –> Fortinet



  • I'm trying to create a VPN tunnel between my pfSense (2.0.3) and Fortinet 100C (4.0). I've matched the phase 1 and 2 settings, tried the German Guide (http://doc.pfsense.org/index.php/PfSense_to_Fortigate_IPsec), but I keep getting a failure.

    On pfSense:

    INFO: IPsec-SA request for x.x.x.x queued due to no phase1 found.
    INFO: initiate new phase 1 negotiation: x.x.x.x[500]<=>x.x.x.x[500]
    racoon: INFO: begin Identity Protection mode.
    racoon: [RemoteTest]: [x.x.x.x] ERROR: phase2 negotiation failed due to time up waiting for phase1 [Remote Side not responding]. ESP x.x.x.x[0]->x.x.x.x[0]
    racoon: INFO: delete phase 2 handler.
    racoon: ERROR: phase1 negotiation failed due to time up. 46bcc06de00f7bbb:0000000000000000

    On the Fortinet:
    IPsec phase 2 error
    negotiate_error
    no matching gateway for new request

    I'm hoping it's something silly, but I'm about to pull my hair out.

    Thanks



  • Something seems to be wrong in your P1 obviously…
    Please login to your pfSense over SSH & start racoon in debug mode:

    racoon -d -v -F -f /var/etc/racoon.conf
    

    Post the output of that command here & then we might be able to tell you more.



  • Here is my log file, hope you see something I've missed:

    
    # 1 "log.txt"
    # 1 "<built-in>"
    # 1 "<command-line>"
    # 1 "log.txt"
    Foreground mode.
    2013-06-06 09:18:47: INFO: @(#)ipsec-tools 0.8.0 (http:
    2013-06-06 09:18:47: INFO: @(#)This product linked OpenSSL 0.9.8y 5 Feb 2013 (http:
    2013-06-06 09:18:47: INFO: Reading configuration from "/var/etc/racoon.conf"
    2013-06-06 09:18:47: DEBUG: call pfkey_send_register for AH
    2013-06-06 09:18:47: DEBUG: call pfkey_send_register for ESP
    2013-06-06 09:18:47: DEBUG: call pfkey_send_register for IPCOMP
    2013-06-06 09:18:47: DEBUG: reading config file /var/etc/racoon.conf
    2013-06-06 09:18:47: DEBUG: no check of compression algorithm; not supported in sadb message.
    2013-06-06 09:18:47: DEBUG: getsainfo params: loc='192.168.10.0/24' rmt='10.10.1.0/24' peer='NULL' client='NULL' id=1
    2013-06-06 09:18:47: DEBUG: open /var/db/racoon/racoon.sock as racoon management.
    2013-06-06 09:18:47: INFO: X.X.X.133[4500] used for NAT-T
    2013-06-06 09:18:47: INFO: X.X.X.133[4500] used as isakmp port (fd=7)
    2013-06-06 09:18:47: INFO: X.X.X.133[500] used for NAT-T
    2013-06-06 09:18:47: INFO: X.X.X.133[500] used as isakmp port (fd=8)
    2013-06-06 09:18:47: DEBUG: pk_recv: retry[0] recv()
    2013-06-06 09:18:47: DEBUG: got pfkey X_SPDDUMP message
    2013-06-06 09:18:47: DEBUG: pk_recv: retry[0] recv()
    2013-06-06 09:18:47: DEBUG: got pfkey X_SPDDUMP message
    2013-06-06 09:18:47: DEBUG: sub:0xbfbfe654: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in
    2013-06-06 09:18:47: DEBUG: db :0x2854b148: 192.168.10.0/24[0] 192.168.10.1/32[0] proto=any dir=in
    2013-06-06 09:18:47: DEBUG: pk_recv: retry[0] recv()
    2013-06-06 09:18:47: DEBUG: got pfkey X_SPDDUMP message
    2013-06-06 09:18:47: DEBUG: sub:0xbfbfe654: 192.168.10.1/32[0] 192.168.10.0/24[0] proto=any dir=out
    2013-06-06 09:18:47: DEBUG: db :0x2854b148: 192.168.10.0/24[0] 192.168.10.1/32[0] proto=any dir=in
    2013-06-06 09:18:47: DEBUG: sub:0xbfbfe654: 192.168.10.1/32[0] 192.168.10.0/24[0] proto=any dir=out
    2013-06-06 09:18:47: DEBUG: db :0x2854b288: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in
    2013-06-06 09:18:47: DEBUG: pk_recv: retry[0] recv()
    2013-06-06 09:18:47: DEBUG: got pfkey X_SPDDUMP message
    2013-06-06 09:18:47: DEBUG: sub:0xbfbfe654: 192.168.10.0/24[0] 10.10.1.0/24[0] proto=any dir=out
    2013-06-06 09:18:47: DEBUG: db :0x2854b148: 192.168.10.0/24[0] 192.168.10.1/32[0] proto=any dir=in
    2013-06-06 09:18:47: DEBUG: sub:0xbfbfe654: 192.168.10.0/24[0] 10.10.1.0/24[0] proto=any dir=out
    2013-06-06 09:18:47: DEBUG: db :0x2854b288: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in
    2013-06-06 09:18:47: DEBUG: sub:0xbfbfe654: 192.168.10.0/24[0] 10.10.1.0/24[0] proto=any dir=out
    2013-06-06 09:18:47: DEBUG: db :0x2854b508: 192.168.10.1/32[0] 192.168.10.0/24[0] proto=any dir=out
    2013-06-06 09:19:32: DEBUG: pk_recv: retry[0] recv()
    2013-06-06 09:19:32: DEBUG: got pfkey ACQUIRE message
    2013-06-06 09:19:32: DEBUG: suitable outbound SP found: 192.168.10.0/24[0] 10.10.1.0/24[0] proto=any dir=out.
    2013-06-06 09:19:32: DEBUG: sub:0xbfbfe658: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in
    2013-06-06 09:19:32: DEBUG: db :0x2854b148: 192.168.10.0/24[0] 192.168.10.1/32[0] proto=any dir=in
    2013-06-06 09:19:32: DEBUG: sub:0xbfbfe658: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in
    2013-06-06 09:19:32: DEBUG: db :0x2854b288: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in
    2013-06-06 09:19:32: DEBUG: suitable inbound SP found: 10.10.1.0/24[0] 192.168.10.0/24[0] proto=any dir=in.
    2013-06-06 09:19:32: DEBUG: new acquire 192.168.10.0/24[0] 10.10.1.0/24[0] proto=any dir=out
    2013-06-06 09:19:32: [X.X.X.130] DEBUG: configuration "X.X.X.130[500]" selected.
    2013-06-06 09:19:32: DEBUG: getsainfo params: loc='192.168.10.0/24' rmt='10.10.1.0/24' peer='NULL' client='NULL' id=1
    2013-06-06 09:19:32: DEBUG: evaluating sainfo: loc='192.168.10.0/24', rmt='10.10.1.0/24', peer='ANY', id=1
    2013-06-06 09:19:32: DEBUG: check and compare ids : values matched (IPv4_subnet)
    2013-06-06 09:19:32: DEBUG: cmpid target: '192.168.10.0/24'
    2013-06-06 09:19:32: DEBUG: cmpid source: '192.168.10.0/24'
    2013-06-06 09:19:32: DEBUG: check and compare ids : values matched (IPv4_subnet)
    2013-06-06 09:19:32: DEBUG: cmpid target: '10.10.1.0/24'
    2013-06-06 09:19:32: DEBUG: cmpid source: '10.10.1.0/24'
    2013-06-06 09:19:32: DEBUG: selected sainfo: loc='192.168.10.0/24', rmt='10.10.1.0/24', peer='ANY', id=1
    2013-06-06 09:19:32: DEBUG: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Tunnel reqid=16388:16387)
    2013-06-06 09:19:32: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha)
    2013-06-06 09:19:32: DEBUG: in post_acquire
    2013-06-06 09:19:32: [X.X.X.130] DEBUG: configuration "X.X.X.130[500]" selected.
    2013-06-06 09:19:32: INFO: IPsec-SA request for X.X.X.130 queued due to no phase1 found.
    2013-06-06 09:19:32: DEBUG: ===
    2013-06-06 09:19:32: INFO: initiate new phase 1 negotiation: X.X.X.133[500]<=>X.X.X.130[500]
    2013-06-06 09:19:32: INFO: begin Identity Protection mode.
    2013-06-06 09:19:32: DEBUG: new cookie:
    2f7d78998fba1117
    2013-06-06 09:19:32: DEBUG: add payload of len 48, next type 13
    2013-06-06 09:19:32: DEBUG: add payload of len 16, next type 13
    2013-06-06 09:19:32: DEBUG: add payload of len 16, next type 13
    2013-06-06 09:19:32: DEBUG: add payload of len 16, next type 13
    2013-06-06 09:19:32: DEBUG: add payload of len 16, next type 13
    2013-06-06 09:19:32: DEBUG: add payload of len 20, next type 13
    2013-06-06 09:19:32: DEBUG: add payload of len 16, next type 0
    2013-06-06 09:19:32: DEBUG: 204 bytes from X.X.X.133[500] to X.X.X.130[500]
    2013-06-06 09:19:32: DEBUG: sockname X.X.X.133[500]
    2013-06-06 09:19:32: DEBUG: send packet from X.X.X.133[500]
    2013-06-06 09:19:32: DEBUG: send packet to X.X.X.130[500]
    2013-06-06 09:19:32: DEBUG: 1 times of 204 bytes message will be sent to X.X.X.130[500]
    2013-06-06 09:19:32: DEBUG:
    2f7d7899 8fba1117 00000000 00000000 01100200 00000000 000000cc 0d000034
    00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c3840
    80010005 80030001 80020002 80040002 0d000014 4a131c81 07035845 5c5728f2
    0e95452f 0d000014 cd604643 35df21f8 7cfdb2fc 68b6a448 0d000014 90cb8091
    3ebb696e 086381b5 ec427b1f 0d000014 4485152d 18b6bbcd 0be8a846 9579ddcc
    0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713
    68a1f1c9 6b8696fc 77570100
    2013-06-06 09:19:32: DEBUG: resend phase1 packet 2f7d78998fba1117:0000000000000000
    2013-06-06 09:19:42: DEBUG: 204 bytes from X.X.X.133[500] to X.X.X.130[500]
    2013-06-06 09:19:42: DEBUG: sockname X.X.X.133[500]
    2013-06-06 09:19:42: DEBUG: send packet from X.X.X.133[500]
    2013-06-06 09:19:42: DEBUG: send packet to X.X.X.130[500]
    2013-06-06 09:19:42: DEBUG: 1 times of 204 bytes message will be sent to X.X.X.130[500]
    2013-06-06 09:19:42: DEBUG:
    2f7d7899 8fba1117 00000000 00000000 01100200 00000000 000000cc 0d000034
    00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c3840
    80010005 80030001 80020002 80040002 0d000014 4a131c81 07035845 5c5728f2
    0e95452f 0d000014 cd604643 35df21f8 7cfdb2fc 68b6a448 0d000014 90cb8091
    3ebb696e 086381b5 ec427b1f 0d000014 4485152d 18b6bbcd 0be8a846 9579ddcc
    0d000018 4048b7d5 6ebce885 25e7de7f 00d6c2d3 80000000 00000014 afcad713
    68a1f1c9 6b8696fc 77570100
    2013-06-06 09:19:42: DEBUG: resend phase1 packet 2f7d78998fba1117:0000000000000000
    2013-06-06 09:19:47: INFO: caught signal 2
    2013-06-06 09:19:47: INFO: racoon process 53748 shutdown</command-line></built-in> 
    


  • I have finally found my issues.
    First, you have to have all the routing and firewall configuration in place or the Fortinet box will not respond properly.
    Second, you have to fill the quick mode selector in the phase 2 on the Fortinet or the sa credentials will not match up.

    I do wish all the IPSEC VPN naming was consistent across platforms. It would make this easier for everyone.



  • Hi, SoloIT

    Please could you explain how did you configured quick mode selector on Fortigate?

    Thank you



  • I just had to put the sub-net address in the quick selector configuration for source and destination. Let me know if I can be of any more assistance.



  • I have no luck, iam very frustrated because i hve the same error
    racoon: ERROR: phase1 negotiation failed due to time up. dacc1ad7e688fb70:5b061c7c04c2cc93

    bu i cannot fix it…

    Could you look at this captures of my config?, maybe i am doing somethinh wrong
    One thing on quick mode selector after selecting the alias of networks and clic OK, radio buttons are gone again but I can see the config with cli as set...

    Also I have added firewall rules on both firewall to allow all ipsec traffic

    Or if you are so kind to show me your config i would really appreciate it

    Thank you in advance










  • Sorry, I don't see anything wrong. I do use the perfect forward secrecy (PFS), but since both your's are disabled, I don't think that's an issue. Also, I used specific address in the quick select rather than alias. You should try putting in the ip address here. Though it should not make a difference, these settings can be picky. Lastly, double check your all your IP address and ensure there is not a typo or mismatched sub net.

    Hope you find the problem



  • @SoloIT:

    I have finally found my issues.
    First, you have to have all the routing and firewall configuration in place or the Fortinet box will not respond properly.
    Second, you have to fill the quick mode selector in the phase 2 on the Fortinet or the sa credentials will not match up.

    I do wish all the IPSEC VPN naming was consistent across platforms. It would make this easier for everyone.

    Ugh.. Can't stand Fortigate.  Have 4 remote dentist offices with 50 and 60A's nailed to a pfsense 2.03 FW via ipsec.  It works I guess.. but kludgey pay-for-everything interface bugs, and so does their overheating hardware.  Can't wait to drop in some pfsense replacements.  Yes.  I'm complaining about 13 year old hardware.  :0p



  • Hi,

    We have created the tunnel between source - pfsense and destination - fortigate firewall. From Destination- Fortigate LAN users are able to reach pfsense LAN.

    But, From pfsense LAN not able to Fortigate LAN,

    Can any one please help me, what rule need to be create in pfsense to access destination fortigate LAN network

    Regards,
    Ramar V
    09538162193



  • Did you create a firewall rule on the pFsense on the IPSec tab?


Log in to reply