#81 segfault in version 0.8.0

open
nobody
None
5
2012-03-14
2012-03-14
Chris Tucker
No

We can\'t see a pattern in when this segfault happens. Sometimes racoon runs for days with no problem, then we have two or three segfaults in five minutes. I have coredumps if these will help, but they are too large to upload as attachments. Here is a summary:
Core was generated by `racoon'.
Program terminated with signal 11, Segmentation fault.
#0 0xb77ca918 in quick_timeover_stub () from /usr/sbin/racoon
(gdb) bt
#0 0xb77ca918 in quick_timeover_stub () from /usr/sbin/racoon
#1 0xb77b36d5 in isakmp_ph2expire_stub () from /usr/sbin/racoon
#2 0xb77b622e in isakmp_ph2expire_stub () from /usr/sbin/racoon
#3 0xb77ad971 in main () from /usr/sbin/racoon
(gdb)

The segfault has always been in quick_timeover_stub().

Discussion

  • Chris Tucker
    Chris Tucker
    2012-03-14

    racoon.conf

     
    Attachments
  • Todd Blum
    Todd Blum
    2013-02-08

    I just had two racoon core dumps, two nights in a row.

    They both seem to coincide with ISP outages, the first night on my side, and the second night an ISP outage that affected at least 5 remote routers. racoon magically restarted itself twice on the first night, and not at all on the second.

    I was using pfSense 2.0.1 (since upgraded to 2.0.2), both of which run on FreeBSD 8.1 and use:

    Feb 5 00:13:33 racoon: INFO: @(#)ipsec-tools 0.8.0 (http://ipsec-tools.sourceforge.net)
    Feb 5 00:13:33 racoon: INFO: @(#)This product linked OpenSSL 0.9.8n 24 Mar 2010 (http://www.openssl.org/)
    ---
    Log exerpts are:

    Feb 5 00:09:36 192.168.116.250 racoon: [173.z.z.z] INFO: DPD: remote (ISAKMP-SA spi=2384af4f0ce1ea9c:98e4230c19058a5c) seems to be dea
    d.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: purging ISAKMP-SA spi=2384af4f0ce1ea9c:98e4230c19058a5c.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: purged IPsec-SA spi=194715026.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: purged IPsec-SA spi=66256580.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: purged ISAKMP-SA spi=2384af4f0ce1ea9c:98e4230c19058a5c.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: ISAKMP-SA deleted 204.x.x.x[500]-173.z.z.z[500] spi:2384af4f0ce1ea9c:98e4230c19058a5c
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: IPsec-SA request for 173.z.z.z queued due to no phase1 found.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: initiate new phase 1 negotiation: 204.x.x.x[500]<=>173.z.z.z[500]
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: begin Identity Protection mode.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: IPsec-SA request for 108.x.x.x queued due to no phase1 found.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: initiate new phase 1 negotiation: 204.x.x.x[500]<=>108.x.x.x[500]
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: begin Identity Protection mode.
    Feb 5 00:09:36 192.168.116.250 racoon: [70.x.x.x] INFO: DPD: remote (ISAKMP-SA spi=4723810f85f0bc34:099f2fc12d622f27) seems to be dead.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: purging ISAKMP-SA spi=4723810f85f0bc34:099f2fc12d622f27.
    Feb 5 00:09:36 192.168.116.250 racoon: INFO: purged IPsec-SA spi=133413478.
    Feb 5 00:09:36 192.168.x.x racoon: INFO: purged IPsec-SA spi=74597912.
    Feb 5 00:09:36 192.168.x.x racoon: INFO: purged ISAKMP-SA spi=4723810f85f0bc34:099f2fc12d622f27.
    Feb 5 00:09:36 192.168.x.x racoon: INFO: IPsec-SA request for 70.z.z.z queued due to no phase1 found.
    Feb 5 00:09:42 192.168.x.x pf: 00:00:00.967728 rule 1/0(match): block in on enc0: (tos 0x0, ttl 99, id 168, offset 0, flags [none], proto TCP (6), length 40)
    Feb 5 00:09:42 192.168.x.x pf: 192.168.Y.x.80 > 192.168.x.H.58823: Flags [.], cksum 0x8b43 (correct), ack 1, win 0, length 0
    Feb 5 00:09:42 192.168.x.x kernel: pid 38566 (racoon), uid 0: exited on signal 11 (core dumped)
    --
    Feb 5 00:15:12 192.168.x.x racoon: [24.x.x.x] ERROR: phase2 negotiation failed due to time up waiting for phase1. ESP 24.x.x.x[0]->204.x.x.x[0]
    Feb 5 00:15:12 192.168.x.x racoon: INFO: delete phase 2 handler.
    Feb 5 00:15:12 192.168.x.x racoon: NOTIFY: the packet is retransmitted by 168.x.x.x[500] (1).
    Feb 5 00:15:12 192.168.x.x racoon: NOTIFY: the packet is retransmitted by 72.x.x.x[500] (1).
    Feb 5 00:15:12 192.168.x.x racoon: ERROR: phase1 negotiation failed due to time up. 2922ae9fc607afdc:e8795f869a651ef4
    Feb 5 00:15:12 192.168.x.x kernel: pid 57409 (racoon), uid 0: exited on signal 11 (core dumped)
    --

    Feb 6 01:48:43 192.168.116.250 racoon: [107.z.z.z] INFO: request for establishing IPsec-SA was queued due to no phase1 found.
    Feb 6 01:48:43 192.168.116.250 racoon: INFO: IPsec-SA request for 209.z.z.z queued due to no phase1 found.
    Feb 6 01:48:43 192.168.116.250 racoon: INFO: initiate new phase 1 negotiation: 204.x.x.x[500]<=>209.z.z.z[500]
    Feb 6 01:48:43 192.168.116.250 racoon: INFO: begin Identity Protection mode.
    Feb 6 01:48:43 192.168.116.250 racoon: INFO: received Vendor ID: DPD
    Feb 6 01:48:44 192.168.116.250 racoon: [66.z.z.z] ERROR: unknown Informational exchange received.
    Feb 6 01:48:44 192.168.116.250 racoon: [66.z.z.z] ERROR: unknown Informational exchange received.
    Feb 6 01:48:44 192.168.116.250 racoon: [71.z.z.z] INFO: DPD: remote (ISAKMP-SA spi=23c4c715caf74e95:73eaf2d5863eb546) seems to be dead.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: purging ISAKMP-SA spi=23c4c715caf74e95:73eaf2d5863eb546.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: purged IPsec-SA spi=83395052.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: purged IPsec-SA spi=12868578.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: purged ISAKMP-SA spi=23c4c715caf74e95:73eaf2d5863eb546.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: ISAKMP-SA deleted 204.x.x.x[500]-71.z.z.z[500] spi:23c4c715caf74e95:73eaf2d5863eb546
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: ISAKMP-SA established 204.x.x.x[500]-209.z.z.z[500] spi:c3de808313e44848:6f35e2474512d
    cfb
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: IPsec-SA request for 64.z.z.z queued due to no phase1 found.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: initiate new phase 1 negotiation: 204.x.x.x[500]<=>64.z.z.z[500]
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: begin Identity Protection mode.
    Feb 6 01:48:44 192.168.116.250 racoon: [66.z.z.z] ERROR: unknown Informational exchange received.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: respond new phase 1 negotiation: 204.x.x.x[500]<=>66.z.z.z[500]
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: begin Identity Protection mode.
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: received Vendor ID: DPD
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: received Vendor ID: DPD
    Feb 6 01:48:44 192.168.116.250 racoon: INFO: ISAKMP-SA established 204.x.x.x[500]-64.z.z.z[500] spi:7271dcd00ea0731f:61f4c99af2710cf5
    Feb 6 01:48:44 192.168.116.250 pf: 00:00:00.949496 rule 1/0(match): block in on enc0: (tos 0x0, ttl 99, id 114, offset 0, flags [none], prot
    o TCP (6), length 40)
    Feb 6 01:48:44 192.168.x.x pf: 192.168.K.x.80 > 192.168.116.8.33150: Flags [.], cksum 0xf662 (correct), ack 1, win 0, length 0
    Feb 6 01:48:44 192.168.x.x racoon: INFO: initiate new phase 2 negotiation: 204.x.x.x[500]<=>209.x.x.x[500]
    Feb 6 01:48:44 192.168.x.x racoon: INFO: IPsec-SA established: ESP 204.x.x.x[500]->209.x.x.x[500] spi=234527522(0xdfa9b22)
    Feb 6 01:48:44 192.168.x.x racoon: INFO: IPsec-SA established: ESP 204.x.x.x[500]->209.x.x.x[500] spi=1266810441(0x4b81fe49)
    Feb 6 01:48:45 192.168.x.x racoon: [71.x.x.x] INFO: request for establishing IPsec-SA was queued due to no phase1 found.
    Feb 6 01:48:45 192.168.x.x kernel: pid 10622 (racoon), uid 0: exited on signal 11 (core dumped)
    --

    Found these similar reports here:

    http://forum.pfsense.org/index.php/topic,39383.0.html