pfSense Gold Subscription

Author Topic: racoon stops without any cause  (Read 10738 times)

0 Members and 1 Guest are viewing this topic.

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
racoon stops without any cause
« on: July 28, 2011, 03:55:19 am »
Dear friends.
I have a netgate pfsense device and has the latest version 2.0 RC3(i386) in nanobsd (2g) previously it was version 1.2.3
I have site to site ipsec vpn between various site.
And my problem is the racoon service automatically stops and i really can't analyze the logs.
could any of you with better experience in pfsense help me sort out this issue.
Thanks

logs
Jul 28 14:29:08    racoon: INFO: begin Identity Protection mode.
Jul 28 14:29:08    racoon: [PAL-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.50.88[500]
Jul 28 14:29:08    racoon: INFO: received Vendor ID: DPD
Jul 28 14:29:08    racoon: INFO: begin Identity Protection mode.
Jul 28 14:29:08    racoon: [IDP-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.209[500]
Jul 28 14:29:08    racoon: INFO: received Vendor ID: DPD
Jul 28 14:29:08    racoon: INFO: begin Identity Protection mode.
Jul 28 14:29:08    racoon: [ISP-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.197[500]
Jul 28 14:29:07    racoon: [ISP-LINK]: INFO: respond new phase 2 negotiation: 202.79.51.215[500]<=>202.79.54.197[500]
Jul 28 14:29:07    racoon: [ISP-LINK]: INFO: ISAKMP-SA established 202.79.51.215[500]-202.79.54.197[500] spi:c9668f61143ead2b:dd373386b1530cb4
Jul 28 14:29:06    racoon: INFO: received Vendor ID: DPD
Jul 28 14:29:06    racoon: INFO: begin Identity Protection mode.
Jul 28 14:29:06    racoon: [ISP-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.197[500]
Jul 28 14:29:05    racoon: [ISP-LINK]: [202.79.54.197] ERROR: unknown Informational exchange received.
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.96.0/24[0] 10.49.32.0/24[0] proto=any dir=in
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.0/24[0] 10.49.96.0/24[0] proto=any dir=out
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.104.0/24[0] 10.49.32.0/24[0] proto=any dir=in
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.0/24[0] 10.49.104.0/24[0] proto=any dir=out
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.64.0/24[0] 10.49.32.0/24[0] proto=any dir=in
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.0/24[0] 10.49.64.0/24[0] proto=any dir=out
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.48.0/24[0] 10.49.32.0/24[0] proto=any dir=in
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.0/24[0] 10.49.48.0/24[0] proto=any dir=out
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.80.0/24[0] 10.49.32.0/24[0] proto=any dir=in
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.0/24[0] 10.49.80.0/24[0] proto=any dir=out
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.0/24[0] 10.49.32.250/32[0] proto=any dir=in
Jul 28 14:29:05    racoon: ERROR: such policy already exists. anyway replace it: 10.49.32.250/32[0] 10.49.32.0/24[0] proto=any dir=out
Jul 28 14:29:05    racoon: INFO: unsupported PF_KEY message REGISTER
Jul 28 14:29:05    racoon: [Self]: INFO: 202.79.51.215[500] used as isakmp port (fd=15)
Jul 28 14:29:05    racoon: [Self]: INFO: 202.79.51.215[500] used for NAT-T
Jul 28 14:29:05    racoon: [Self]: INFO: 202.79.51.215[4500] used as isakmp port (fd=14)
Jul 28 14:29:05    racoon: [Self]: INFO: 202.79.51.215[4500] used for NAT-T
Jul 28 14:29:05    racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Jul 28 14:29:05    racoon: INFO: @(#)This product linked OpenSSL 0.9.8n 24 Mar 2010 (http://www.openssl.org/)
Jul 28 14:29:05    racoon: INFO: @(#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)
Jul 28 14:18:41    racoon: INFO: received Vendor ID: DPD
Jul 28 14:18:41    racoon: INFO: begin Identity Protection mode.
Jul 28 14:18:41    racoon: [ISP-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.197[500]
Jul 28 14:18:41    racoon: INFO: received Vendor ID: DPD
Jul 28 14:18:41    racoon: INFO: begin Identity Protection mode.
Jul 28 14:18:41    racoon: [ISP-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.197[500]
Jul 28 14:18:29    racoon: ERROR: phase1 negotiation failed due to time up. db61f37232cbf32d:0e731f4ac2bef957
Jul 28 14:18:16    racoon: [IDP-LINK]: INFO: ISAKMP-SA deleted 202.79.51.215[500]-202.79.54.209[500] spi:82fb2f394cce0120:4be51a22afd7af2d
Jul 28 14:18:16    racoon: INFO: purged ISAKMP-SA spi=82fb2f394cce0120:4be51a22afd7af2d.
Jul 28 14:18:16    racoon: INFO: purged IPsec-SA spi=193719387.
Jul 28 14:18:16    racoon: INFO: purged IPsec-SA spi=3617941230.
Jul 28 14:18:16    racoon: INFO: purging ISAKMP-SA spi=82fb2f394cce0120:4be51a22afd7af2d.
Jul 28 14:18:16    racoon: [IDP-LINK]: [202.79.54.209] INFO: DPD: remote (ISAKMP-SA spi=82fb2f394cce0120:4be51a22afd7af2d) seems to be dead.
Jul 28 14:18:16    racoon: [ISP-LINK]: INFO: ISAKMP-SA deleted 202.79.51.215[500]-202.79.54.197[500] spi:8cb99ce857e55435:dc92ac3a5ef480b4
Jul 28 14:18:16    racoon: INFO: purged ISAKMP-SA spi=8cb99ce857e55435:dc92ac3a5ef480b4.
Jul 28 14:18:16    racoon: INFO: purged IPsec-SA spi=137051439.

Jul 28 14:19:19  Thankyou so much
i love pfsense because i love open source.

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
logs in debug mode
« Reply #1 on: July 28, 2011, 04:15:39 am »
hi friends i tried Prefer older IPsec SAs but still the same problem
please help me find the bug here is the log in debug mode
thanks
Code: [Select]
Jul 28 14:55:10 racoon: [PAL-LINK]: [202.79.50.88] DEBUG: delete payload for protocol ISAKMP
Jul 28 14:55:10 racoon: DEBUG: succeed.
Jul 28 14:55:10 racoon: DEBUG: seen nptype=12(delete)
Jul 28 14:55:10 racoon: DEBUG: begin.
Jul 28 14:55:10 racoon: DEBUG: receive Information.
Jul 28 14:55:10 racoon: DEBUG: 2ce8a54f 59a6a3fc 00000000 00000000 0c100500 00000000 00000038 0000001c 00000001 01100001 2ce8a54f 59a6a3fc 00000000 00000000
Jul 28 14:55:10 racoon: DEBUG: 56 bytes message received from 202.79.50.88[500] to 202.79.51.215[500]
Jul 28 14:55:10 racoon: DEBUG: ===
Jul 28 14:55:10 racoon: DEBUG: received an R-U-THERE-ACK
Jul 28 14:55:10 racoon: [IDP-LINK]: [202.79.54.209] DEBUG: DPD R-U-There-Ack received
Jul 28 14:55:10 racoon: DEBUG: succeed.
Jul 28 14:55:10 racoon: DEBUG: seen nptype=11(notify)
Jul 28 14:55:10 racoon: DEBUG: seen nptype=8(hash)
Jul 28 14:55:10 racoon: DEBUG: begin.
Jul 28 14:55:10 racoon: DEBUG: hash validated.
Jul 28 14:55:10 racoon: DEBUG: 93482783 97d2f351 9edc12f9 ac85b919
Jul 28 14:55:10 racoon: DEBUG: HASH computed:
Jul 28 14:55:10 racoon: DEBUG: hmac(hmac_md5)
Jul 28 14:55:10 racoon: DEBUG: c963a88c 00000020 00000001 01108d29 7712a9ba 69d8354d bd4f6069 6e10babf 00000cde
Jul 28 14:55:10 racoon: DEBUG: HASH with:
Jul 28 14:55:10 racoon: DEBUG: IV freed
Jul 28 14:55:10 racoon: DEBUG: 7712a9ba 69d8354d bd4f6069 6e10babf 08100501 c963a88c 00000054 0b000014 93482783 97d2f351 9edc12f9 ac85b919 00000020 00000001 01108d29 7712a9ba 69d8354d bd4f6069 6e10babf 00000cde 00000000
Jul 28 14:55:10 racoon: DEBUG: decrypted.
Jul 28 14:55:10 racoon: DEBUG: skip to trim padding.
Jul 28 14:55:10 racoon: DEBUG: padding len=1
Jul 28 14:55:10 racoon: DEBUG: 0b000014 93482783 97d2f351 9edc12f9 ac85b919 00000020 00000001 01108d29 7712a9ba 69d8354d bd4f6069 6e10babf 00000cde 00000000
Jul 28 14:55:10 racoon: DEBUG: decrypted payload, but not trimed.
Jul 28 14:55:10 racoon: DEBUG: 8d162b58 37dddac0
Jul 28 14:55:10 racoon: DEBUG: decrypted payload by IV:
Jul 28 14:55:10 racoon: DEBUG: 839aeaa9 cc9ae7c1 34d235f4 e9a598ae be16f229 14bd9910
Jul 28 14:55:10 racoon: DEBUG: with key:
Jul 28 14:55:10 racoon: DEBUG: encryption(3des)
Jul 28 14:55:10 racoon: DEBUG: a122a052 fc9ced4a
Jul 28 14:55:10 racoon: DEBUG: IV was saved for next processing:
Jul 28 14:55:10 racoon: DEBUG: encryption(3des)
Jul 28 14:55:10 racoon: DEBUG: begin decryption.
Jul 28 14:55:10 racoon: DEBUG: 8d162b58 37dddac0
Jul 28 14:55:10 racoon: DEBUG: phase2 IV computed:
Jul 28 14:55:10 racoon: DEBUG: encryption(3des)
Jul 28 14:55:10 racoon: DEBUG: hash(md5)
Jul 28 14:55:10 racoon: DEBUG: 63f8b4f7 c96f91d9 c963a88c
Jul 28 14:55:10 racoon: DEBUG: phase1 last IV:
Jul 28 14:55:10 racoon: DEBUG: compute IV for phase2
Jul 28 14:55:10 racoon: DEBUG: receive Information.
Jul 28 14:55:10 racoon: DEBUG: 7712a9ba 69d8354d bd4f6069 6e10babf 08100501 c963a88c 00000054 5d592fb9 b8c21bae 8fe02cb2 23cbac6d 7b32e099 3f00bba8 ee808857 4c00e988 6c61aad4 23f93379 520e2ef8 23f1aba2 a122a052 fc9ced4a
Jul 28 14:55:10 racoon: DEBUG: 84 bytes message received from 202.79.54.209[500] to 202.79.51.215[500]
Jul 28 14:55:10 racoon: DEBUG: ===
Jul 28 14:55:10 racoon: DEBUG: resend phase1 packet 2ce8a54f59a6a3fc:954de0a9871abce8
Jul 28 14:55:10 racoon: DEBUG: 2ce8a54f 59a6a3fc 954de0a9 871abce8 01100200 00000000 00000054 00000038 00000001 00000001 0000002c 01010001 00000024 01010000 80040002 80030001 80010005 80020001 800b0001 000c0004 00007080
Jul 28 14:55:10 racoon: DEBUG: 1 times of 84 bytes message will be sent to 202.79.50.88[500]
i love pfsense because i love open source.

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
Re: racoon stops without any cause
« Reply #2 on: July 30, 2011, 09:24:59 am »
There are no PPTP Tunnels Either  :-\
i love pfsense because i love open source.

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
Re: racoon stops without any cause
« Reply #3 on: August 02, 2011, 03:06:57 am »
after chaning the below mentioned things it works for a little longer but after 1-2 hours it again stops i.e. the racoon service
Quote
pfs key group ->off
DPD->off
prefer old SA's->ticked
by the way i have a mix up of devices 3 is Trendnet and 1 is pfsense nanobsd RC.02
i'm quite sure there's something that i have missed.
any helping hands is greatly appreciated
thanks

i love pfsense because i love open source.

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
Re: racoon stops without any cause
« Reply #4 on: August 03, 2011, 04:17:57 am »
i really can't figure out why racoon is stopping after running for few hours.


please help me pfsense gods and gurus
:)
i love pfsense because i love open source.

Offline Metu69salemi

  • Hero Member
  • *****
  • Posts: 1564
  • Karma: +2/-0
    • View Profile
Re: racoon stops without any cause
« Reply #5 on: August 03, 2011, 04:25:51 am »
Then you can count me off  ;)

Do you happen to have logs at this occurance time. It would be great to have also logs from another side of ipsec. If there could be answers

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
Re: racoon stops without any cause
« Reply #6 on: August 03, 2011, 04:58:49 am »
Thanks Metu69salemi
The other side has Trendnet VPN router firelwall and the log at trendnet says
Quote
[15:40:31]**** SENT OUT  FIRST MESSAGE OF MAIN MODE ****
[15:40:31] PAYLOADS: SA,PROP,TRANS,VID
In my opinion the problem lies in my pfsense. The racoon just automatically stops and ipsec is down as soon as i start the racoon service , everything is back to normal.
preety annoyed
thanks
kalu
i love pfsense because i love open source.

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
log report
« Reply #7 on: August 03, 2011, 05:00:56 am »
hi here is the log file of my pfsense device
Quote
Aug 3 15:43:07    racoon: INFO: begin Identity Protection mode.
Aug 3 15:43:07    racoon: [IBP-LINK]: INFO: initiate new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.135[500]
Aug 3 15:43:07    racoon: [IBP-LINK]: INFO: IPsec-SA request for 202.79.54.135 queued due to no phase1 found.
Aug 3 15:42:52    racoon: INFO: delete phase 2 handler.
Aug 3 15:42:52    racoon: [IBP-LINK]: [202.79.54.135] ERROR: phase2 negotiation failed due to time up waiting for phase1 [Remote Side not responding]. ESP 202.79.54.135[0]->202.79.51.215[0]
Aug 3 15:42:24    racoon: ERROR: phase1 negotiation failed due to time up. 051917376d09ef4c:0000000000000000
Aug 3 15:42:21    racoon: [IBP-LINK]: [202.79.54.135] INFO: request for establishing IPsec-SA was queued due to no phase1 found.
Aug 3 15:42:05    racoon: INFO: delete phase 2 handler.
Aug 3 15:42:05    racoon: [IBP-LINK]: [202.79.54.135] ERROR: phase2 negotiation failed due to time up waiting for phase1 [Remote Side not responding]. ESP 202.79.54.135[0]->202.79.51.215[0]
Aug 3 15:41:59    racoon: INFO: purged IPsec-SA proto_id=ESP spi=4008569731.
Aug 3 15:41:56    racoon: INFO: purged IPsec-SA proto_id=ESP spi=3485435869.
Aug 3 15:41:34    racoon: INFO: begin Identity Protection mode.
Aug 3 15:41:34    racoon: [IBP-LINK]: INFO: initiate new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.135[500]
Aug 3 15:41:34    racoon: [IBP-LINK]: INFO: IPsec-SA request for 202.79.54.135 queued due to no phase1 found.
Aug 3 15:41:29    racoon: [ISP-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.54.197[500] spi=3507038995(0xd1092b13)
Aug 3 15:41:29    racoon: [ISP-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.54.197[500] spi=256939600(0xf509650)
Aug 3 15:41:29    racoon: [ISP-LINK]: INFO: respond new phase 2 negotiation: 202.79.51.215[500]<=>202.79.54.197[500]
Aug 3 15:41:28    racoon: [PAL-LINK]: INFO: ISAKMP-SA deleted 202.79.51.215[500]-202.79.50.88[500] spi:f5c9058ac6c52ffa:ddf88b39fda1db1a
Aug 3 15:41:28    racoon: [PAL-LINK]: INFO: ISAKMP-SA expired 202.79.51.215[500]-202.79.50.88[500] spi:f5c9058ac6c52ffa:ddf88b39fda1db1a
Aug 3 15:41:27    racoon: INFO: purged IPsec-SA proto_id=ESP spi=2417358319.
Aug 3 15:41:27    racoon: [PAL-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.50.88[500] spi=3172222795(0xbd14474b)
Aug 3 15:41:27    racoon: [PAL-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.50.88[500] spi=40673213(0x26c9fbd)
Aug 3 15:41:27    racoon: [PAL-LINK]: INFO: respond new phase 2 negotiation: 202.79.51.215[500]<=>202.79.50.88[500]
Aug 3 15:41:27    racoon: [PAL-LINK]: INFO: ISAKMP-SA established 202.79.51.215[500]-202.79.50.88[500] spi:f5c9058ac6c52ffa:ddf88b39fda1db1a
Aug 3 15:41:26    racoon: INFO: begin Identity Protection mode.
Aug 3 15:41:26    racoon: [PAL-LINK]: INFO: respond new phase 1 negotiation: 202.79.51.215[500]<=>202.79.50.88[500]
Aug 3 15:41:18    racoon: INFO: delete phase 2 handler.
Aug 3 15:41:18    racoon: [IBP-LINK]: [202.79.54.135] ERROR: phase2 negotiation failed due to time up waiting for phase1 [Remote Side not responding]. ESP 202.79.54.135[0]->202.79.51.215[0]
Aug 3 15:40:59    racoon: [ISP-LINK]: INFO: IPsec-SA expired: ESP/Tunnel 202.79.54.197[500]->202.79.51.215[500] spi=42990396(0x28ffb3c)
Aug 3 15:40:59    racoon: [ISP-LINK]: INFO: IPsec-SA expired: ESP 202.79.51.215[500]->202.79.54.197[500] spi=4008569731(0xeeedeb83)
Aug 3 15:40:58    racoon: ERROR: phase1 negotiation failed due to time up. f8d07fc084134232:0000000000000000
Aug 3 15:40:57    racoon: [PAL-LINK]: INFO: IPsec-SA expired: ESP/Tunnel 202.79.50.88[500]->202.79.51.215[500] spi=39787469(0x25f1bcd)
Aug 3 15:40:57    racoon: [PAL-LINK]: INFO: IPsec-SA expired: ESP 202.79.51.215[500]->202.79.50.88[500] spi=3485435869(0xcfbf87dd)
Aug 3 15:40:47    racoon: [IBP-LINK]: [202.79.54.135] INFO: request for establishing IPsec-SA was queued due to no phase1 found.
Aug 3 15:40:46    racoon: NOTIFY: the packet is retransmitted by 202.79.54.209[500] (1).
Aug 3 15:40:41    racoon: NOTIFY: the packet is retransmitted by 202.79.54.209[500] (1).
Aug 3 15:40:39    racoon: INFO: delete phase 2 handler.
Aug 3 15:40:39    racoon: [IBP-LINK]: [202.79.54.135] ERROR: phase2 negotiation failed due to time up waiting for phase1 [Remote Side not responding]. ESP 202.79.54.135[0]->202.79.51.215[0]
Aug 3 15:40:36    racoon: NOTIFY: the packet is retransmitted by 202.79.54.209[500] (1).
Aug 3 15:40:32    racoon: [IDP-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.54.209[500] spi=4090473567(0xf3cfac5f)
Aug 3 15:40:32    racoon: [IDP-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.54.209[500] spi=108652071(0x679e627)
Aug 3 15:40:32    racoon: INFO: received RESPONDER-LIFETIME: 300 seconds
Aug 3 15:40:32    racoon: [IDP-LINK]: INFO: initiate new phase 2 negotiation: 202.79.51.215[500]<=>202.79.54.209[500]
Aug 3 15:40:32    racoon: [IDP-LINK]: INFO: IPsec-SA expired: ESP/Tunnel 202.79.54.209[500]->202.79.51.215[500] spi=89231451(0x551905b)
Aug 3 15:40:27    racoon: [IDP-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.54.209[500] spi=2299975968(0x8916d920)
Aug 3 15:40:27    racoon: [IDP-LINK]: INFO: IPsec-SA established: ESP 202.79.51.215[500]->202.79.54.209[500] spi=190570987(0xb5be1eb)
Aug 3 15:40:27    racoon: [IDP-LINK]: INFO: respond new phase 2 negotiation: 202.79.51.215[500]<=>202.79.54.209[500]
Aug 3 15:40:08    racoon: INFO: begin Identity Protection mode.
Aug 3 15:40:08    racoon: [IBP-LINK]: INFO: initiate new phase 1 negotiation: 202.79.51.215[500]<=>202.79.54.135[500]
Aug 3 15:40:08    racoon: [IBP-LINK]: INFO: IPsec-SA request for 202.79.54.135 queued due to no phase1 found.
i love pfsense because i love open source.

Offline Metu69salemi

  • Hero Member
  • *****
  • Posts: 1564
  • Karma: +2/-0
    • View Profile
Re: racoon stops without any cause
« Reply #8 on: August 03, 2011, 05:11:31 am »
Log just repeats, that phase 1 isn't correct nor found. have you triplechecked every single settings?

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
Re: racoon stops without any cause
« Reply #9 on: August 03, 2011, 05:31:37 am »
hi Metu69salemi
Yes i've checked and double checked the settings.
It works preety fine until racoon stops .
thanks
kalu
i love pfsense because i love open source.

Offline Metu69salemi

  • Hero Member
  • *****
  • Posts: 1564
  • Karma: +2/-0
    • View Profile
Re: racoon stops without any cause
« Reply #10 on: August 03, 2011, 05:34:39 am »
Is there system logs at the time?

Offline kalu

  • Full Member
  • ***
  • Posts: 132
  • Karma: +1/-0
    • View Profile
Re: racoon stops without any cause
« Reply #11 on: August 03, 2011, 05:46:34 am »
The IPSec VPN link is running fine now after starting racoon again
don't know when will it get down by it self
Hi Metu69salemi
here is the system log
Quote
Aug 3 10:40:47    check_reload_status: Reloading filter
Aug 3 10:40:41    check_reload_status: Syncing firewall
Aug 3 10:40:37    check_reload_status: Syncing firewall
Aug 3 10:40:29    check_reload_status: Syncing firewall
Aug 3 10:40:27    check_reload_status: Syncing firewall
Aug 3 10:39:00    check_reload_status: Reloading filter
Aug 3 10:35:54    check_reload_status: Reloading filter
Aug 3 16:20:44    apinger: alarm canceled: WAN_GW(202.79.51.193) *** delay ***
Aug 3 10:35:12    check_reload_status: Reloading filter
Aug 3 16:20:02    apinger: ALARM: WAN_GW(202.79.51.193) *** delay ***
Aug 3 16:15:42    kernel: pid 10457 (racoon), uid 0: exited on signal 11 (core dumped)
Aug 3 10:24:23    check_reload_status: Syncing firewall
Aug 3 16:09:22    php: /vpn_ipsec_phase2.php: Reloading IPsec tunnel 'ISP-LINK'. Previous IP '202.79.54.197', current IP '202.79.54.197'. Reloading policy
Aug 3 16:06:17    php: /index.php: Successful webConfigurator login for user 'admin' from 10.49.32.162
Aug 3 16:06:17    php: /index.php: Successful webConfigurator login for user 'admin' from 10.49.32.162
Aug 3 16:04:48    php: /index.php: User logged out for user 'admin' from: 10.49.32.162
Aug 3 10:18:42    check_reload_status: Reloading filter
Aug 3 10:18:35    check_reload_status: Syncing firewall
Aug 3 16:03:35    php: /vpn_ipsec_phase2.php: Reloading IPsec tunnel 'IDP-LINK'. Previous IP '202.79.54.209', current IP '202.79.54.209'. Reloading policy
Aug 3 09:45:05    check_reload_status: Reloading filter
Aug 3 09:44:56    check_reload_status: Reloading filter
Aug 3 15:29:55    apinger: alarm canceled: WAN_GW(202.79.51.193) *** delay ***
Aug 3 15:29:46    apinger: ALARM: WAN_GW(202.79.51.193) *** delay ***
Aug 3 15:28:18    php: /status_services.php: Forcefully reloading IPsec racoon daemon
Aug 3 15:06:37    kernel: pid 60568 (racoon), uid 0: exited on signal 11 (core dumped)
Aug 3 15:05:17    php: /status_services.php: Forcefully reloading IPsec racoon daemon
Aug 3 15:03:42    kernel: pid 19710 (racoon), uid 0: exited on signal 11 (core dumped)
Aug 3 15:03:33    php: /status_services.php: Forcefully reloading IPsec racoon daemon
Aug 3 09:16:18    check_reload_status: Reloading filter
Aug 3 15:01:08    apinger: alarm canceled: WAN_GW(202.79.51.193) *** delay ***
Aug 3 09:16:05    check_reload_status: Reloading filter
Aug 3 15:00:55    apinger: ALARM: WAN_GW(202.79.51.193) *** delay ***
Aug 3 14:41:47    kernel: pid 33505 (racoon), uid 0: exited on signal 11 (core dumped)
Aug 3 14:38:44    sshlockout[27588]: sshlockout/webConfigurator v3.0 starting up
Aug 3 14:38:44    sshd[20376]: Accepted keyboard-interactive/pam for admin from 10.49.32.162 port 2498 ssh2
Aug 3 14:37:53    syslogd: kernel boot file is /boot/kernel/kernel
Aug 3 14:37:53    syslogd: exiting on signal 15
Aug 3 14:37:39    syslogd: kernel boot file is /boot/kernel/kernel
Aug 3 14:37:39    syslogd: exiting on signal 15
Aug 3 14:37:37    syslogd: kernel boot file is /boot/kernel/kernel
Aug 3 14:37:37    syslogd: exiting on signal 15
Aug 3 14:34:00    kernel: pid 46139 (racoon), uid 0: exited on signal 11 (core dumped)
Aug 3 14:33:48    kernel: arp: unknown hardware address format (0x1100)
Aug 3 14:27:46    kernel: arp: unknown hardware address format (0x4500)
Aug 3 14:23:14    php: /status_services.php: Forcefully reloading IPsec racoon daemon
Aug 3 14:22:05    apinger: /usr/local/bin/rrdtool respawning too fast, waiting 300s.
Aug 3 08:36:38    check_reload_status: Reloading filter
Aug 3 14:21:29    kernel: vr2: link state changed to DOWN
Aug 3 08:36:29    check_reload_status: Linkup starting vr2
Aug 3 14:21:28    apinger: alarm canceled: WAN_GW(202.79.51.193) *** delay ***
i love pfsense because i love open source.

Offline Metu69salemi

  • Hero Member
  • *****
  • Posts: 1564
  • Karma: +2/-0
    • View Profile
Re: racoon stops without any cause
« Reply #12 on: August 31, 2011, 11:12:35 pm »
Kalu:
if you're sure that p1 & p2 settings are right, then this log doesn't say anything to me.
It just shows that it's not liking how the racoon itself works(or not) by killing that process. maybe some developers could help reading this log

Offline stemond

  • Jr. Member
  • **
  • Posts: 38
  • Karma: +0/-0
    • View Profile
Re: racoon stops without any cause
« Reply #13 on: September 08, 2011, 03:11:24 am »
i have same issue :(
Racoon stop withou causes and drops all IPSEC tunnels.

i am using Pfsense 2.0 RC3 and it happens without PPTP tunnel

this is my log, have you any hint ???

Code: [Select]
Sep 8 09:58:48 php: /status_services.php: Forcefully reloading IPsec racoon daemon
[b]Sep 8 09:52:28 kernel: pid 23362 (racoon), uid 0: exited on signal 11 (core dumped)[/b]
Sep 8 09:50:04 kernel: arp: 192.168.126.13 moved from 00:01:02:f9:ea:55 to 00:08:02:45:32:42 on le0
Sep 8 09:30:04 kernel: arp: 192.168.126.13 moved from 00:01:02:f9:ea:55 to 00:08:02:45:32:42 on le0
Sep 8 09:30:04 kernel: arp: 192.168.126.13 moved from 00:08:02:45:32:42 to 00:01:02:f9:ea:55 on le0
Sep 8 09:10:04 kernel: arp: 192.168.126.13 moved from 00:01:02:f9:ea:55 to 00:08:02:45:32:42 on le0

S.

Offline TheBlast

  • Newbie
  • *
  • Posts: 20
  • Karma: +0/-0
    • View Profile
Re: racoon stops without any cause
« Reply #14 on: September 17, 2011, 09:57:21 am »
Hi there,
same issue for me : ~160 ipsec tunnels get stopped after some hours.
Could someone just paste the magic script to restart racoon if it's stopped (cron inside) ?

edit : error message
Sep 17 08:33:49 pfsense kernel: pid 2238 (racoon), uid 0: exited on signal 11 (core dumped)

Edit 2: new crash
System log message : Sep 17 19:07:56    kernel: pid 10333 (racoon), uid 0: exited on signal 11 (core dumped)
Ipsec error message : Sep 17 19:07:56    racoon: [xxx]: [yyy.yyy.yyy.yyy] ERROR: phase1 negotiation failed.

Edit 3 : no crash since I disabled badly configured tunnel ... will keep you informed and check with V2 Release this week.

So a badly configured tunnel seems to kill racoon ... Will this help ?
« Last Edit: September 18, 2011, 03:00:01 pm by TheBlast »