Attachment 302806 Details for Bug 442955 – /var/log/secure showing failure to use null auth alg

/var/log/secure showing failure to use null auth alg

eal5.log (text/plain), 13.97 KB, created by IBM Bug Proxy on 2008-04-17 20:49:31 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: IBM Bug Proxy

Created: 2008-04-17 20:49:31 UTC

Size: 13.97 KB

patch

obsolete

>
>Apr 17 13:54:49 eal5 ipsec__plutorun: Starting Pluto subsystem...
>Apr 17 13:54:49 eal5 pluto[5064]: Starting Pluto (Openswan Version 2.6.11; Vendor ID OE^\177LyWKCETe) pid:5064
>Apr 17 13:54:49 eal5 pluto[5064]: Setting NAT-Traversal port-4500 floating to on
>Apr 17 13:54:49 eal5 pluto[5064]:    port floating activation criteria nat_t=1/port_float=1
>Apr 17 13:54:49 eal5 pluto[5064]:    including NAT-Traversal patch (Version 0.6c)
>Apr 17 13:54:49 eal5 pluto[5064]: | opening /dev/urandom
>Apr 17 13:54:49 eal5 pluto[5064]: using /dev/urandom as source of random entropy
>Apr 17 13:54:49 eal5 pluto[5064]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
>Apr 17 13:54:49 eal5 pluto[5064]: | event added at head of queue
>Apr 17 13:54:49 eal5 pluto[5064]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr 17 13:54:49 eal5 pluto[5064]: | event added at head of queue
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_enc(): Activating OAKLEY_BLOWFISH_CBC: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
>Apr 17 13:54:49 eal5 pluto[5064]: starting up 3 cryptographic helpers
>Apr 17 13:54:49 eal5 pluto[5064]: started helper pid=5076 (fd:7)
>Apr 17 13:54:49 eal5 pluto[5076]: | opening /dev/urandom
>Apr 17 13:54:49 eal5 pluto[5064]: started helper pid=5077 (fd:8)
>Apr 17 13:54:49 eal5 pluto[5077]: | opening /dev/urandom
>Apr 17 13:54:49 eal5 pluto[5076]: using /dev/urandom as source of random entropy
>Apr 17 13:54:49 eal5 pluto[5064]: started helper pid=5078 (fd:9)
>Apr 17 13:54:49 eal5 pluto[5078]: | opening /dev/urandom
>Apr 17 13:54:50 eal5 pluto[5077]: using /dev/urandom as source of random entropy
>Apr 17 13:54:50 eal5 pluto[5076]: ! helper 0 waiting on fd: 8
>Apr 17 13:54:50 eal5 pluto[5064]: Using Linux 2.6 IPsec interface code on 2.6.18-88.el5 (experimental code)
>Apr 17 13:54:50 eal5 pluto[5078]: using /dev/urandom as source of random entropy
>Apr 17 13:54:50 eal5 pluto[5077]: ! helper 1 waiting on fd: 9
>Apr 17 13:54:50 eal5 pluto[5064]: | process 5064 listening for PF_KEY_V2 on file descriptor 12
>Apr 17 13:54:50 eal5 pluto[5078]: ! helper 2 waiting on fd: 10
>Apr 17 13:54:50 eal5 pluto[5064]: | finish_pfkey_msg: SADB_REGISTER message 1 for AH 
>Apr 17 13:54:50 eal5 pluto[5064]: |   02 07 00 02  02 00 00 00  01 00 00 00  c8 13 00 00
>Apr 17 13:54:50 eal5 pluto[5064]: | pfkey_get: SADB_REGISTER message 1
>Apr 17 13:54:50 eal5 pluto[5064]: | AH registered with kernel.
>Apr 17 13:54:50 eal5 pluto[5064]: | finish_pfkey_msg: SADB_REGISTER message 2 for ESP 
>Apr 17 13:54:50 eal5 pluto[5064]: |   02 07 00 03  02 00 00 00  02 00 00 00  c8 13 00 00
>Apr 17 13:54:50 eal5 pluto[5064]: | pfkey_get: SADB_REGISTER message 2
>Apr 17 13:54:50 eal5 pluto[5064]: | alg_init():memset(0xdbda00, 0, 2016) memset(0xdbe1e0, 0, 2048) 
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=19 sadb_supported_len=56
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=14, alg_id=251
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[0], exttype=14, satype=3, alg_id=251, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=14, alg_id=2
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[1], exttype=14, satype=3, alg_id=2, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=14, alg_id=3
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[2], exttype=14, satype=3, alg_id=3, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=14, alg_id=5
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[3], exttype=14, satype=3, alg_id=5, alg_ivlen=0, alg_minbits=256, alg_maxbits=256, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=14, alg_id=8
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[4], exttype=14, satype=3, alg_id=8, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=14, alg_id=9
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[5], exttype=14, satype=3, alg_id=9, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=19 sadb_supported_len=80
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=11
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[6], exttype=15, satype=3, alg_id=11, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=2
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[7], exttype=15, satype=3, alg_id=2, alg_ivlen=8, alg_minbits=64, alg_maxbits=64, res=0, ret=1
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=3
>Apr 17 13:54:50 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[8], exttype=15, satype=3, alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=6
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[9], exttype=15, satype=3, alg_id=6, alg_ivlen=8, alg_minbits=40, alg_maxbits=128, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=7
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[10], exttype=15, satype=3, alg_id=7, alg_ivlen=8, alg_minbits=40, alg_maxbits=448, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=12
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[11], exttype=15, satype=3, alg_id=12, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=252
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[12], exttype=15, satype=3, alg_id=252, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=253
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[13], exttype=15, satype=3, alg_id=253, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_add():satype=3, exttype=15, alg_id=13
>Apr 17 13:54:51 eal5 pluto[5064]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[14], exttype=15, satype=3, alg_id=13, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr 17 13:54:51 eal5 pluto[5064]: | ESP registered with kernel.
>Apr 17 13:54:51 eal5 pluto[5064]: | finish_pfkey_msg: SADB_REGISTER message 3 for IPCOMP 
>Apr 17 13:54:51 eal5 pluto[5064]: |   02 07 00 09  02 00 00 00  03 00 00 00  c8 13 00 00
>Apr 17 13:54:51 eal5 pluto[5064]: | pfkey_get: SADB_REGISTER message 3
>Apr 17 13:54:51 eal5 pluto[5064]: | IPCOMP registered with kernel.
>Apr 17 13:54:51 eal5 pluto[5064]: Could not change to directory '/etc/ipsec.d/cacerts': /
>Apr 17 13:54:51 eal5 pluto[5064]: Could not change to directory '/etc/ipsec.d/aacerts': /
>Apr 17 13:54:51 eal5 pluto[5064]: Could not change to directory '/etc/ipsec.d/ocspcerts': /
>Apr 17 13:54:51 eal5 pluto[5064]: Could not change to directory '/etc/ipsec.d/crls'
>Apr 17 13:54:51 eal5 pluto[5064]: | inserting event EVENT_LOG_DAILY, timeout in 36309 seconds
>Apr 17 13:54:51 eal5 pluto[5064]: | event added after event EVENT_REINIT_SECRET
>Apr 17 13:54:51 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 118 seconds
>Apr 17 13:54:51 eal5 pluto[5064]: |  
>Apr 17 13:54:51 eal5 pluto[5064]: | *received whack message
>Apr 17 13:54:51 eal5 pluto[5064]: | Added new connection i386-i386 with policy PSK+ENCRYPT+TUNNEL+PFS+!IKEv1+IKEv2ALLOW+IKEv2Init
>Apr 17 13:54:51 eal5 pluto[5064]: | from whack: got --esp=aes128-null
>Apr 17 13:54:51 eal5 pluto[5064]: | alg_info_parse_str() ealg_buf=aes aalg_buf=nulleklen=128  aklen=0
>Apr 17 13:54:51 eal5 pluto[5064]: | enum_search_prefix () calling enum_search(0xda3f30, "ESP_AES")
>Apr 17 13:54:51 eal5 pluto[5064]: | parser_alg_info_add() ealg_getbyname("aes")=12
>Apr 17 13:54:51 eal5 pluto[5064]: | enum_search_prefix () calling enum_search(0xda0d28, "AUTH_ALGORITHM_HMAC_NULL")
>Apr 17 13:54:51 eal5 pluto[5064]: | enum_search_prefix () calling enum_search(0xda0d28, "AUTH_ALGORITHM_NULL")
>Apr 17 13:54:51 eal5 pluto[5064]: | esp string values: <NULL>
>Apr 17 13:54:51 eal5 pluto[5064]: esp string error: hash_alg not found, enc_alg="aes", auth_alg="null", modp=""
>Apr 17 13:54:51 eal5 pluto[5064]: | * processed 0 messages from cryptographic helpers 
>Apr 17 13:54:51 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 118 seconds
>Apr 17 13:54:51 eal5 pluto[5064]: |  
>Apr 17 13:54:52 eal5 pluto[5064]: | *received whack message
>Apr 17 13:54:52 eal5 pluto[5064]: listening for IKE messages
>Apr 17 13:54:52 eal5 pluto[5064]: | found lo with address 127.0.0.1
>Apr 17 13:54:52 eal5 pluto[5064]: | found eth0 with address 9.3.190.198
>Apr 17 13:54:52 eal5 pluto[5064]: adding interface eth0/eth0 9.3.190.198:500
>Apr 17 13:54:52 eal5 pluto[5064]: adding interface eth0/eth0 9.3.190.198:4500
>Apr 17 13:54:52 eal5 pluto[5064]: adding interface lo/lo 127.0.0.1:500
>Apr 17 13:54:52 eal5 pluto[5064]: adding interface lo/lo 127.0.0.1:4500
>Apr 17 13:54:52 eal5 pluto[5064]: | found eth0 with address fc00:0000:0000:0105:0000:0000:0000:0022
>Apr 17 13:54:52 eal5 pluto[5064]: | found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
>Apr 17 13:54:52 eal5 pluto[5064]: adding interface lo/lo ::1:500
>Apr 17 13:54:52 eal5 pluto[5064]: adding interface eth0/eth0 fc00::105:0:0:0:22:500
>Apr 17 13:54:52 eal5 pluto[5064]: loading secrets from "/etc/ipsec.secrets"
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: 9.3.190.198
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: 9.3.192.206
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: 9.3.192.210
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: 9.3.190.196
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: fc00::105:0:0:0:22
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: fc00::105:0:0:0:23
>Apr 17 13:54:52 eal5 pluto[5064]: | id type added to secret(0x8902cf0) 1: fc00::105:0:0:0:24
>Apr 17 13:54:52 eal5 pluto[5064]: | Processing PSK at line 1: passed
>Apr 17 13:54:52 eal5 pluto[5064]: | * processed 0 messages from cryptographic helpers 
>Apr 17 13:54:52 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 117 seconds
>Apr 17 13:55:01 eal5 pluto[5064]: |  
>Apr 17 13:55:01 eal5 pluto[5064]: | *received whack message
>Apr 17 13:55:01 eal5 pluto[5064]: initiating all conns with alias='i386-i386' 
>Apr 17 13:55:01 eal5 pluto[5064]: | * processed 0 messages from cryptographic helpers 
>Apr 17 13:55:01 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 108 seconds
>Apr 17 13:56:49 eal5 pluto[5064]: |  
>Apr 17 13:56:49 eal5 pluto[5064]: | *time to handle event
>Apr 17 13:56:49 eal5 pluto[5064]: | handling event EVENT_PENDING_PHASE2
>Apr 17 13:56:49 eal5 pluto[5064]: | event after this is EVENT_REINIT_SECRET in 3480 seconds
>Apr 17 13:56:49 eal5 pluto[5064]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr 17 13:56:49 eal5 pluto[5064]: | event added at head of queue
>Apr 17 13:56:49 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr 17 13:58:49 eal5 pluto[5064]: |  
>Apr 17 13:58:49 eal5 pluto[5064]: | *time to handle event
>Apr 17 13:58:49 eal5 pluto[5064]: | handling event EVENT_PENDING_PHASE2
>Apr 17 13:58:49 eal5 pluto[5064]: | event after this is EVENT_REINIT_SECRET in 3360 seconds
>Apr 17 13:58:49 eal5 pluto[5064]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr 17 13:58:49 eal5 pluto[5064]: | event added at head of queue
>Apr 17 13:58:49 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr 17 13:58:55 eal5 pluto[5064]: |  
>Apr 17 13:58:55 eal5 pluto[5064]: | *received whack message
>Apr 17 13:58:55 eal5 pluto[5064]: initiating all conns with alias='i386-i386' 
>Apr 17 13:58:55 eal5 pluto[5064]: | * processed 0 messages from cryptographic helpers 
>Apr 17 13:58:55 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 114 seconds
>Apr 17 14:00:49 eal5 pluto[5064]: |  
>Apr 17 14:00:49 eal5 pluto[5064]: | *time to handle event
>Apr 17 14:00:49 eal5 pluto[5064]: | handling event EVENT_PENDING_PHASE2
>Apr 17 14:00:49 eal5 pluto[5064]: | event after this is EVENT_REINIT_SECRET in 3240 seconds
>Apr 17 14:00:49 eal5 pluto[5064]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr 17 14:00:49 eal5 pluto[5064]: | event added at head of queue
>Apr 17 14:00:49 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr 17 14:02:49 eal5 pluto[5064]: |  
>Apr 17 14:02:49 eal5 pluto[5064]: | *time to handle event
>Apr 17 14:02:49 eal5 pluto[5064]: | handling event EVENT_PENDING_PHASE2
>Apr 17 14:02:49 eal5 pluto[5064]: | event after this is EVENT_REINIT_SECRET in 3120 seconds
>Apr 17 14:02:49 eal5 pluto[5064]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr 17 14:02:49 eal5 pluto[5064]: | event added at head of queue
>Apr 17 14:02:49 eal5 pluto[5064]: | next event EVENT_PENDING_PHASE2 in 120 seconds

Actions: View

Attachments on bug 442955: 302806 | 303965