Page MenuHomeVyOS Platform

Add ipsec peer-name to log to simplifies grepping and troubleshooting
Closed, ResolvedPublicFEATURE REQUEST

Description

Strongswan allows us to use charon.syslog.<facility>.ike_name which can help more faster find peer info for troubleshooting.
When we change /etc/strongswan.d/charon-logging.conf and add ike_name = yes

charon {
    syslog {
        # prefix for each log message
        identifier = charon
        # use default settings to log to the LOG_DAEMON facility
        daemon {
            default = 1
            ike_name = yes
        }
   }
}

This adds the possibility grepping/matching peers what we need.

vyos@vyos# run show log vpn ipsec | match 100.64.0.1
Jun 19 14:03:54 vyos charon: 12[IKE] <peer-100.64.0.1-tunnel-0|1> initiating Main Mode IKE_SA peer-100.64.0.1-tunnel-0[1] to 100.64.0.1
Jun 19 14:03:54 vyos charon: 12[ENC] <peer-100.64.0.1-tunnel-0|1> generating ID_PROT request 0 [ SA V V V V V ]
Jun 19 14:03:54 vyos charon: 12[NET] <peer-100.64.0.1-tunnel-0|1> sending packet: from 100.64.0.2[500] to 100.64.0.1[500] (180 bytes)
Jun 19 14:03:54 vyos charon: 07[NET] <peer-100.64.0.1-tunnel-0|1> received packet: from 100.64.0.1[500] to 100.64.0.2[500] (56 bytes)
Jun 19 14:03:54 vyos charon: 07[ENC] <peer-100.64.0.1-tunnel-0|1> parsed INFORMATIONAL_V1 request 3793066263 [ N(NO_PROP) ]
Jun 19 14:03:54 vyos charon: 07[IKE] <peer-100.64.0.1-tunnel-0|1> received NO_PROPOSAL_CHOSEN error notify

Details

Difficulty level
Unknown (require assessment)
Version
-
Why the issue appeared?
Will be filled on close
Is it a breaking change?
Unspecified (possibly destroys the router)

Event Timeline

PR https://github.com/vyos/vyos-build/pull/169

Jun  8 00:59:20 r1-roll ipsec_starter[2373]: charon (2374) started after 400 ms
Jun  8 00:59:20 r1-roll charon: 05[CFG] received stroke: add connection 'peer-192.0.2.2-tunnel-0'
Jun  8 00:59:20 r1-roll charon: 05[CFG] added configuration 'peer-192.0.2.2-tunnel-0'
Jun  8 00:59:20 r1-roll charon: 07[CFG] received stroke: initiate 'peer-192.0.2.2-tunnel-0'
Jun  8 00:59:20 r1-roll charon: 07[IKE] <peer-192.0.2.2-tunnel-0|1> initiating Main Mode IKE_SA peer-192.0.2.2-tunnel-0[1] to 192.0.2.2
Jun  8 00:59:20 r1-roll charon: 07[ENC] <peer-192.0.2.2-tunnel-0|1> generating ID_PROT request 0 [ SA V V V V V ]
Jun  8 00:59:20 r1-roll charon: 07[NET] <peer-192.0.2.2-tunnel-0|1> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (180 bytes)
Jun  8 00:59:20 r1-roll charon: 09[NET] <peer-192.0.2.2-tunnel-0|1> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (160 bytes)
Jun  8 00:59:20 r1-roll charon: 09[ENC] <peer-192.0.2.2-tunnel-0|1> parsed ID_PROT response 0 [ SA V V V V ]
Jun  8 00:59:20 r1-roll charon: 09[IKE] <peer-192.0.2.2-tunnel-0|1> received XAuth vendor ID
Jun  8 00:59:20 r1-roll charon: 09[IKE] <peer-192.0.2.2-tunnel-0|1> received DPD vendor ID
Jun  8 00:59:20 r1-roll charon: 09[IKE] <peer-192.0.2.2-tunnel-0|1> received FRAGMENTATION vendor ID
Jun  8 00:59:20 r1-roll charon: 09[IKE] <peer-192.0.2.2-tunnel-0|1> received NAT-T (RFC 3947) vendor ID
Jun  8 00:59:20 r1-roll charon: 09[CFG] <peer-192.0.2.2-tunnel-0|1> selected proposal: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
Jun  8 00:59:20 r1-roll charon: 09[ENC] <peer-192.0.2.2-tunnel-0|1> generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Jun  8 00:59:20 r1-roll charon: 09[NET] <peer-192.0.2.2-tunnel-0|1> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (244 bytes)
Jun  8 00:59:20 r1-roll charon: 10[NET] <peer-192.0.2.2-tunnel-0|1> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (244 bytes)
Jun  8 00:59:20 r1-roll charon: 10[ENC] <peer-192.0.2.2-tunnel-0|1> parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Jun  8 00:59:20 r1-roll charon: 10[ENC] <peer-192.0.2.2-tunnel-0|1> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Jun  8 00:59:20 r1-roll charon: 10[NET] <peer-192.0.2.2-tunnel-0|1> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (108 bytes)
Jun  8 00:59:20 r1-roll charon: 11[NET] <peer-192.0.2.2-tunnel-0|1> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (76 bytes)
Jun  8 00:59:20 r1-roll charon: 11[ENC] <peer-192.0.2.2-tunnel-0|1> parsed ID_PROT response 0 [ ID HASH ]
Jun  8 00:59:20 r1-roll charon: 11[IKE] <peer-192.0.2.2-tunnel-0|1> IKE_SA peer-192.0.2.2-tunnel-0[1] established between 192.0.2.1[192.0.2.1]...192.0.2.2[192.0.2.2]
Jun  8 00:59:20 r1-roll charon: 11[IKE] <peer-192.0.2.2-tunnel-0|1> scheduling rekeying in 2720s
Jun  8 00:59:20 r1-roll charon: 11[IKE] <peer-192.0.2.2-tunnel-0|1> maximum IKE_SA lifetime 3260s
Jun  8 00:59:20 r1-roll charon: 11[ENC] <peer-192.0.2.2-tunnel-0|1> generating QUICK_MODE request 3783917425 [ HASH SA No KE ID ID ]
Jun  8 00:59:20 r1-roll charon: 11[NET] <peer-192.0.2.2-tunnel-0|1> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (316 bytes)
Jun  8 00:59:20 r1-roll charon: 12[NET] <peer-192.0.2.2-tunnel-0|1> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (316 bytes)
Jun  8 00:59:20 r1-roll charon: 12[ENC] <peer-192.0.2.2-tunnel-0|1> parsed QUICK_MODE response 3783917425 [ HASH SA No KE ID ID ]
Jun  8 00:59:20 r1-roll charon: 12[CFG] <peer-192.0.2.2-tunnel-0|1> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Jun  8 00:59:20 r1-roll charon: 12[IKE] <peer-192.0.2.2-tunnel-0|1> CHILD_SA peer-192.0.2.2-tunnel-0{1} established with SPIs c4d940b7_i c9a69e83_o and TS 10.1.0.0/24 === 10.2.3.0/24
Jun  8 00:59:20 r1-roll charon: 12[ENC] <peer-192.0.2.2-tunnel-0|1> generating QUICK_MODE request 3783917425 [ HASH ]
Jun  8 00:59:20 r1-roll charon: 12[NET] <peer-192.0.2.2-tunnel-0|1> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (60 bytes)
Viacheslav changed the task status from Open to Needs testing.Jun 8 2021, 9:14 AM
Viacheslav claimed this task.

VyOS 1.3-beta-202106081558
Works as expected.

Jun  9 19:57:38 r4-1 charon: 13[CFG] no IKE_SA named 'peer-192.0.2.2-tunnel-0' found
Jun  9 19:57:38 r4-1 charon: 14[CFG] received stroke: initiate 'peer-192.0.2.2-tunnel-0'
Jun  9 19:57:38 r4-1 charon: 06[IKE] <peer-192.0.2.2-tunnel-0|4> initiating Main Mode IKE_SA peer-192.0.2.2-tunnel-0[4] to 192.0.2.2
Jun  9 19:57:38 r4-1 charon: 06[ENC] <peer-192.0.2.2-tunnel-0|4> generating ID_PROT request 0 [ SA V V V V V ]
Jun  9 19:57:38 r4-1 charon: 06[NET] <peer-192.0.2.2-tunnel-0|4> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (180 bytes)
Jun  9 19:57:38 r4-1 charon: 07[NET] <peer-192.0.2.2-tunnel-0|4> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (160 bytes)
Jun  9 19:57:38 r4-1 charon: 07[ENC] <peer-192.0.2.2-tunnel-0|4> parsed ID_PROT response 0 [ SA V V V V ]
Jun  9 19:57:38 r4-1 charon: 07[IKE] <peer-192.0.2.2-tunnel-0|4> received XAuth vendor ID
Jun  9 19:57:38 r4-1 charon: 07[IKE] <peer-192.0.2.2-tunnel-0|4> received DPD vendor ID
Jun  9 19:57:38 r4-1 charon: 07[IKE] <peer-192.0.2.2-tunnel-0|4> received FRAGMENTATION vendor ID
Jun  9 19:57:38 r4-1 charon: 07[IKE] <peer-192.0.2.2-tunnel-0|4> received NAT-T (RFC 3947) vendor ID
Jun  9 19:57:38 r4-1 charon: 07[CFG] <peer-192.0.2.2-tunnel-0|4> selected proposal: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
Jun  9 19:57:38 r4-1 charon: 07[ENC] <peer-192.0.2.2-tunnel-0|4> generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
Jun  9 19:57:38 r4-1 charon: 07[NET] <peer-192.0.2.2-tunnel-0|4> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (244 bytes)
Jun  9 19:57:38 r4-1 charon: 05[NET] <peer-192.0.2.2-tunnel-0|4> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (244 bytes)
Jun  9 19:57:38 r4-1 charon: 05[ENC] <peer-192.0.2.2-tunnel-0|4> parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
Jun  9 19:57:38 r4-1 charon: 05[ENC] <peer-192.0.2.2-tunnel-0|4> generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
Jun  9 19:57:38 r4-1 charon: 05[NET] <peer-192.0.2.2-tunnel-0|4> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (108 bytes)
Jun  9 19:57:38 r4-1 charon: 08[NET] <peer-192.0.2.2-tunnel-0|4> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (76 bytes)
Jun  9 19:57:38 r4-1 charon: 08[ENC] <peer-192.0.2.2-tunnel-0|4> parsed ID_PROT response 0 [ ID HASH ]
Jun  9 19:57:38 r4-1 charon: 08[IKE] <peer-192.0.2.2-tunnel-0|4> IKE_SA peer-192.0.2.2-tunnel-0[4] established between 192.0.2.1[192.0.2.1]...192.0.2.2[192.0.2.2]
Jun  9 19:57:38 r4-1 charon: 08[IKE] <peer-192.0.2.2-tunnel-0|4> scheduling reauthentication in 2524s
Jun  9 19:57:38 r4-1 charon: 08[IKE] <peer-192.0.2.2-tunnel-0|4> maximum IKE_SA lifetime 3064s
Jun  9 19:57:38 r4-1 charon: 08[ENC] <peer-192.0.2.2-tunnel-0|4> generating QUICK_MODE request 364019988 [ HASH SA No KE ID ID ]
Jun  9 19:57:38 r4-1 charon: 08[NET] <peer-192.0.2.2-tunnel-0|4> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (316 bytes)
Jun  9 19:57:38 r4-1 charon: 09[NET] <peer-192.0.2.2-tunnel-0|4> received packet: from 192.0.2.2[500] to 192.0.2.1[500] (316 bytes)
Jun  9 19:57:38 r4-1 charon: 09[ENC] <peer-192.0.2.2-tunnel-0|4> parsed QUICK_MODE response 364019988 [ HASH SA No KE ID ID ]
Jun  9 19:57:38 r4-1 charon: 09[CFG] <peer-192.0.2.2-tunnel-0|4> selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/MODP_1024/NO_EXT_SEQ
Jun  9 19:57:38 r4-1 charon: 09[IKE] <peer-192.0.2.2-tunnel-0|4> CHILD_SA peer-192.0.2.2-tunnel-0{1} established with SPIs cb0aa83a_i c728156c_o and TS 10.1.0.0/24 === 10.2.3.0/24
Jun  9 19:57:38 r4-1 charon: 09[ENC] <peer-192.0.2.2-tunnel-0|4> generating QUICK_MODE request 364019988 [ HASH ]
Jun  9 19:57:38 r4-1 charon: 09[NET] <peer-192.0.2.2-tunnel-0|4> sending packet: from 192.0.2.1[500] to 192.0.2.2[500] (60 bytes)
vyos@r4-1.3:~$
Viacheslav moved this task from Backport Candidates to Finished on the VyOS 1.3 Equuleus board.
Viacheslav moved this task from Needs Triage to Finished on the VyOS 1.2 Crux (VyOS 1.2.8) board.