This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Droped outbound IPSec packets; :500 failed in main_outI1. Errno 1 Operation not permitted

Hello,

 

I'm having a hard time trying to establish a new VPN tunnel from my UTM 220 (Firmware version: 9.508-10) to an ASA 5525.

We have many IPSec tunnels, which are working on this device... but not the latter.

I get the following ERROR: "S_UT**" #41: sendto on eth2 to 196.****:500 failed in main_outI1. Errno 1: Operation not permitted

I triple checked all IKE parameters, PSK, etc and they're ok.

All the interfaces in question (remote network, remote gateway) are not bound to a specific interface. (left with "any')

On the UTM side we NAT to a public IP.

The thing is that we receive the remote peer's packets (as seen on debugging_log), but the outbound packets get dropped by the firewall.

ulogd[5464]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="60003" outitf="eth1" srcmac="00:1a::):f0:f3:41" srcip="9.XXXXX" dstip="196.XXXXXX" proto="17" length="288" tos="0x00" prec="0x00" ttl="64" srcport="500" dstport="500"

I attached firewall and IP-Sec logs

I don't understand where is the problem... what is blocking the packets.

 

Thank you!



This thread was automatically locked due to age.
Parents
  • Salut Gery and welcome to the UTM Community!

    Alone among the logs, the Firewall Live Log presents abbreviated information in a format easier to read quickly.  Usually, you can't troubleshoot without looking at the corresponding line from the full Firewall log file.  Please post the line corresponding to that above.

    Instead of pictures, please copy the log lines into here.  Obfuscate private information like 50.x.y.101, 10.x.y.23 and domain.com.

    Also for the IPsec log:

    1. Confirm that Debug is not enabled.
    2. Disable the IPsec Connection.
    3. Start the IPsec Live Log and wait for it to begin to populate.
    4. Enable the IPsec Connection.
    5. Show us about 60 lines from enabling through the error.

    Is anti-replay enabled on the ASA?  That's a non-starter with the UTM's IPsec implementation.

    Make sure that the DPD and NAT-T settings are both on in both the UTM and the ASA.

    Cheers - Bob

     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • Hi Bob,

     

    The corresponding line from the full Firewall log is below:

    2018:04:16-12:43:24 -1 ulogd[5464]: id="2001" severity="info" sys="SecureNet" sub="packetfilter" name="Packet dropped" action="drop" fwrule="60003" outitf="eth1" 
    srcmac="00:1a:)):f0:f3:41" srcip="91.x.y.13" dstip="196.x.y.35" proto="17" length="288" tos="0x00" prec="0x00" ttl="64" srcport="500" dstport="500"


    and the IPsec log wo debug

    2018:04:16-12:43:22 fw1-2 pluto[26255]: forgetting secrets

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loading secrets from "/etc/ipsec.secrets"

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loaded PSK secret for 91.x.y.3 196.x.y.35

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loaded PSK secret for 91.x.y.3 91.x.y.6

    2018:04:16-12:43:22 fw1-2 pluto[26255]: HA System: not master, won't listen for IKE messages

    2018:04:16-12:43:22 fw1-2 pluto[26255]: forgetting secrets

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loading secrets from "/etc/ipsec.secrets"

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loaded PSK secret for 91.x.y.3 5.x.y.66

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loaded PSK secret for 91.x.y.3 196.x.y.35

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loaded PSK secret for 91.x.y.3 91.x.y.6

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loading ca certificates from '/etc/ipsec.d/cacerts'

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loading aa certificates from '/etc/ipsec.d/aacerts'

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'

    2018:04:16-12:43:22 fw1-2 pluto[26255]: loading attribute certificates from '/etc/ipsec.d/acerts'

    2018:04:16-12:43:22 fw1-2 pluto[26255]: Changing to directory '/etc/ipsec.d/crls'

    2018:04:16-12:43:22 fw1-2 pluto[26255]: added connection description "S_I"

    2018:04:16-12:43:23 fw1-1 pluto[5746]: forgetting secrets

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loading secrets from "/etc/ipsec.secrets"

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.3 196.x.y.35

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.3 91.x.y.6

    2018:04:16-12:43:23 fw1-1 pluto[5746]: listening for IKE messages

    2018:04:16-12:43:23 fw1-1 pluto[5746]: forgetting secrets

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loading secrets from "/etc/ipsec.secrets"

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.3 94.x.y.149

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.3 196.x.y.35

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.3 91.x.y.6

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loading ca certificates from '/etc/ipsec.d/cacerts'

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loading aa certificates from '/etc/ipsec.d/aacerts'

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'

    2018:04:16-12:43:23 fw1-1 pluto[5746]: loading attribute certificates from '/etc/ipsec.d/acerts'

    2018:04:16-12:43:23 fw1-1 pluto[5746]: Changing to directory '/etc/ipsec.d/crls'

    2018:04:16-12:43:23 fw1-1 pluto[5746]: added connection description "S_I"

    2018:04:16-12:43:23 fw1-1 pluto[5746]: "S_I" #3397: initiating Main Mode

    2018:04:16-12:43:23 fw1-1 pluto[5746]: ERROR: "S_I" #3397: sendto on eth2 to 196.x.y.35:500 failed in main_outI1. Errno 1: Operation not permitted

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: ignoring Vendor ID payload [FRAGMENTATION c0000000]

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: ignoring Vendor ID payload [Cisco-Unity]

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: received Vendor ID payload [XAUTH]

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: ignoring Vendor ID payload [c4e63313bf33cb39c0f79eed66412d51]

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: ignoring Vendor ID payload [Cisco VPN 3000 Series]

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: received Vendor ID payload [Dead Peer Detection]

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: Peer ID is ID_IPV4_ADDR: '196.x.y.35'

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: Dead Peer Detection (RFC 3706) enabled

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3397: ISAKMP SA established

    2018:04:16-12:43:33 fw1-1 pluto[5746]: "S_I" #3398: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#3397}

    2018:04:16-12:43:34 fw1-1 pluto[5746]: "S_I" #3397: ignoring informational payload, type NO_PROPOSAL_CHOSEN

    2018:04:16-12:43:34 fw1-1 pluto[5746]: "S_I" #3397: received Delete SA payload: deleting ISAKMP State #3397

    2018:04:16-12:43:40 fw1-1 pluto[5746]: packet from 62.x.y.234:500: ignoring informational payload, type NO_PROPOSAL_CHOSEN

     

    DPD and NAT-T are both enabled.

    I will check the anti-replay as well.

     

    Thank you.

  • here is another one with both DPD and NAT-T enabled

    also anti-replay is disabled on the ASA

     

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.13 91.x.y.6

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading ca certificates from '/etc/ipsec.d/cacerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading aa certificates from '/etc/ipsec.d/aacerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading attribute certificates from '/etc/ipsec.d/acerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: Changing to directory '/etc/ipsec.d/crls'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: added connection description "S_I"

    2018:04:16-17:22:49 fw1-1 pluto[5746]: "S_I" #3721: initiating Main Mode

    2018:04:16-17:22:49 fw1-1 pluto[5746]: ERROR: "S_I" #3721: sendto on eth2 to 196.x.y.x5:500 failed in main_outI1. Errno 1: Operation not permitted

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: received Vendor ID payload [RFC 3947]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [FRAGMENTATION c0000000]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: enabling possible NAT-traversal with method 3

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [Cisco-Unity]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: received Vendor ID payload [XAUTH]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [3da22b408681559536162d208a140ed1]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [Cisco VPN 3000 Series]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: NAT-Traversal: Result using RFC 3947: no NAT detected

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: received Vendor ID payload [Dead Peer Detection]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: | protocol/port in Phase 1 ID Payload is 17/0. accepted with port_floating NAT-T

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: Peer ID is ID_IPV4_ADDR: '196.x.y.35'

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: Dead Peer Detection (RFC 3706) enabled

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ISAKMP SA established

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3722: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#3721}

    2018:04:16-17:23:00 fw1-1 pluto[5746]: "S_I" #3721: ignoring informational payload, type NO_PROPOSAL_CHOSEN

    2018:04:16-17:23:00 fw1-1 pluto[5746]: "S_I" #3721: received Delete SA payload: deleting ISAKMP State #3721

     

    Gery. 

Reply
  • here is another one with both DPD and NAT-T enabled

    also anti-replay is disabled on the ASA

     

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loaded PSK secret for 91.x.y.13 91.x.y.6

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading ca certificates from '/etc/ipsec.d/cacerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading aa certificates from '/etc/ipsec.d/aacerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: loading attribute certificates from '/etc/ipsec.d/acerts'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: Changing to directory '/etc/ipsec.d/crls'

    2018:04:16-17:22:49 fw1-1 pluto[5746]: added connection description "S_I"

    2018:04:16-17:22:49 fw1-1 pluto[5746]: "S_I" #3721: initiating Main Mode

    2018:04:16-17:22:49 fw1-1 pluto[5746]: ERROR: "S_I" #3721: sendto on eth2 to 196.x.y.x5:500 failed in main_outI1. Errno 1: Operation not permitted

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: received Vendor ID payload [RFC 3947]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [FRAGMENTATION c0000000]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: enabling possible NAT-traversal with method 3

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [Cisco-Unity]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: received Vendor ID payload [XAUTH]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [3da22b408681559536162d208a140ed1]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ignoring Vendor ID payload [Cisco VPN 3000 Series]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: NAT-Traversal: Result using RFC 3947: no NAT detected

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: received Vendor ID payload [Dead Peer Detection]

    2018:04:16-17:22:59 fw1-1 pluto[5746]: | protocol/port in Phase 1 ID Payload is 17/0. accepted with port_floating NAT-T

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: Peer ID is ID_IPV4_ADDR: '196.x.y.35'

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: Dead Peer Detection (RFC 3706) enabled

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3721: ISAKMP SA established

    2018:04:16-17:22:59 fw1-1 pluto[5746]: "S_I" #3722: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#3721}

    2018:04:16-17:23:00 fw1-1 pluto[5746]: "S_I" #3721: ignoring informational payload, type NO_PROPOSAL_CHOSEN

    2018:04:16-17:23:00 fw1-1 pluto[5746]: "S_I" #3721: received Delete SA payload: deleting ISAKMP State #3721

     

    Gery. 

Children
No Data