Tunnel down with many SAD table entries



  • I have a randomly recurring problem (ain't those the best!)

    My IPSec tunnel to a Linksys BEFVP41 router goes down on me after a while with dozens of entries in the SAD table. When I look at the IPSec log file I see loads of entries like these repeating every 30 seconds or so:
    (NOTE - local and remote used in place of my real IPs)

    ========================================

    Apr 18 15:39:35 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP local[0]->remote[0] spi=2215712033(0x84111521)
    Apr 18 15:39:35 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP remote[0]->local[0] spi=166608929(0x9ee4021)
    Apr 18 15:39:35 racoon: [to_hempstead]: INFO: respond new phase 2 negotiation: local[0]<=>remote[0]
    Apr 18 15:39:34 racoon: [to_hempstead]: INFO: ISAKMP-SA established local[500]-remote[500] spi:30c6711de8c69c14:ddaf1692daf23ff0
    Apr 18 15:39:34 racoon: INFO: begin Identity Protection mode.
    Apr 18 15:39:34 racoon: [to_hempstead]: INFO: respond new phase 1 negotiation: local[500]<=>remote[500]
    Apr 18 15:38:34 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP local[0]->remote[0] spi=1978531947(0x75ee006b)
    Apr 18 15:38:34 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP remote[0]->local[0] spi=5750318(0x57be2e)
    Apr 18 15:38:34 racoon: [to_hempstead]: INFO: respond new phase 2 negotiation: local[0]<=>remote[0]
    Apr 18 15:38:34 racoon: [to_hempstead]: INFO: ISAKMP-SA established local[500]-remote[500] spi:7205637fd9426190:51794a64b623647d
    Apr 18 15:38:33 racoon: INFO: begin Identity Protection mode.
    Apr 18 15:38:33 racoon: [to_hempstead]: INFO: respond new phase 1 negotiation: local[500]<=>remote[500]
    Apr 18 15:37:34 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP local[0]->remote[0] spi=3036263550(0xb4f9b47e)
    Apr 18 15:37:34 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP remote[0]->local[0] spi=77912038(0x4a4d7e6)
    Apr 18 15:37:34 racoon: [to_hempstead]: INFO: respond new phase 2 negotiation: local[0]<=>remote[0]
    Apr 18 15:37:34 racoon: [to_hempstead]: INFO: ISAKMP-SA established local[500]-remote[500] spi:37acf28d2ed2d19d:d84e5eba3c9cca5b
    Apr 18 15:37:34 racoon: INFO: begin Identity Protection mode.
    Apr 18 15:37:34 racoon: [to_hempstead]: INFO: respond new phase 1 negotiation: local[500]<=>remote[500]
    Apr 18 15:37:04 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP local[0]->remote[0] spi=2159154306(0x80b21482)
    Apr 18 15:37:04 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP remote[0]->local[0] spi=21607017(0x149b269)
    Apr 18 15:37:04 racoon: [to_hempstead]: INFO: respond new phase 2 negotiation: local[0]<=>remote[0]
    Apr 18 15:37:04 racoon: [to_hempstead]: INFO: ISAKMP-SA established local[500]-remote[500] spi:8df5d585bc709889:b82e5493a8135625
    Apr 18 15:37:04 racoon: INFO: begin Identity Protection mode.
    Apr 18 15:37:04 racoon: [to_hempstead]: INFO: respond new phase 1 negotiation: local[500]<=>remote[500]
    Apr 18 15:36:54 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP local[0]->remote[0] spi=2900939091(0xace8d153)
    Apr 18 15:36:54 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP remote[0]->local[0] spi=138401863(0x83fd847)
    Apr 18 15:36:54 racoon: [to_hempstead]: INFO: respond new phase 2 negotiation: local[0]<=>remote[0]
    Apr 18 15:25:05 racoon: [to_hempstead]: INFO: IPsec-SA expired: ESP/Tunnel remote[0]->local[0] spi=189670690(0xb4e2522)
    Apr 18 15:25:05 racoon: [to_hempstead]: INFO: IPsec-SA expired: ESP local[0]->remote[0] spi=2687302083(0xa02cf9c3)
    Apr 18 14:37:04 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP local[0]->remote[0] spi=2687302083(0xa02cf9c3)
    Apr 18 14:37:04 racoon: [to_hempstead]: INFO: IPsec-SA established: ESP remote[0]->local[0] spi=189670690(0xb4e2522)
    Apr 18 14:37:04 racoon: [to_hempstead]: INFO: respond new phase 2 negotiation: local[0]<=>remote[0]
    Apr 18 14:25:15 racoon: [to_hempstead]: INFO: IPsec-SA expired: ESP/Tunnel remote[0]->local[0] spi=207077908(0xc57c214)
    Apr 18 14:25:15 racoon: [to_hempstead]: INFO: IPsec-SA expired: ESP local[0]->remote[0] spi=2791923(0x2a99f3)

    ========================================

    It seems that racoon gets into a vicious cycle and continuously generates SPI entries in the SAD table. If I restart the IPSec service the SAD table is wiped clean and the VPN gets up and running just fine. It stays that way through none or many phase negotiations and then for whatever reason, goes bananas and starts creating loads of SPI entries all over again.

    Has anyone else seen this behavior before?

    Other thread references:
    http://forum.pfsense.org/index.php/topic,27344.0.html
    http://forum.pfsense.org/index.php/topic,32385.0.html

    BTW - I'm using pfSense 1.2.3-RELEASE

    Thanks,
    Jason



  • As a follow-up to my own post…

    By enabling the " Prefer old IPsec SAs " my problem has been resolved. The IPSec connection still tries for multiple SAD entries but falls back to the proper number, two.

    This config option can be found, in version 1.2.3, in the System menu, under Advanced, in the Miscellaneous config options.

    Jason


Locked