[Openswan Users] PAYLOAD_MALFORMED
openswan at thefeds.net
openswan at thefeds.net
Thu Dec 18 09:47:31 EST 2008
I am experimenting with 12 Centos servers and Openswan. Mostly they work
fine, however I am running into occasional problems with always include
PAYLOAD_MALFORMED in the log messages. Often the logs point to unknown
hash payloads or non zero bytes.
The servers are all running CentOS 5.0 x86_64 and Openswan 2.6.19 which I
compiled from source via the included spec file. These servers are running
kernel kernel-2.6.18-92.el5 and Openswan is using the kernel Netkey.
I have a full mesh of ipsec SAs between the 12 servers which are located
in pairs at 6 sites around the world. There is no pattern to the errors, I
have seen them occurring between servers in all of the 6 sites. It is
usually only one server at a site that is affected, although I have seen
the errors happening between 2 servers on one site. The servers on one
site are each connected to a Cisco switch and there is a trunk between the
switches.
There is a lot of live network traffic running over the same
infrastructure (Gb/s, not Mb/s) and I am not seeing any problems with the
other traffic or errors on interfaces so I do not believe that traffic is
being corrupted at the network layer. I have also performed pings of 1500
bytes, with a custom padding and there are no reports of damaged packets.
Here is an example of what I am seeing repeated in /var/log/secure:
Dec 13 07:49:33 vpn01j pluto[3004]: "tun01j02j" #1887: next payload type
of ISAKMP Hash Payload has an unknown value: 167
Dec 13 07:49:33 vpn01j pluto[3004]: "tun01j02j" #1887: malformed payload
in packet
Dec 13 07:49:33 vpn01j pluto[3004]: | payload malformed after IV
Dec 13 07:49:33 vpn01j pluto[3004]: | c5 28 17 c8 55 7c 46 63 01 8e 9b
f7 cd 3c e0 c4
Dec 13 07:49:33 vpn01j pluto[3004]: "tun01j02j" #1887: sending
notification PAYLOAD_MALFORMED to <hidden ip>:500
Dec 18 11:12:40 vpn01m pluto[32445]: "tun02j01m" #662: malformed message:
not a multiple of encryption blocksize
Dec 18 11:12:40 vpn01m pluto[32445]: | payload malformed after IV
Dec 18 11:12:40 vpn01m pluto[32445]: | b0 6c 17 f9 5b 1e 78 3d 53 4a
d6 8f 81 fa 2f fa
Dec 18 11:12:40 vpn01m pluto[32445]: "tun02j01m" #662: sending
notification PAYLOAD_MALFORMED to <hidden ip>:500
Dec 17 13:26:27 vpn02d pluto[30773]: "tun02d02m" #39: byte 2 of ISAKMP
Hash Payload must be zero, but is not
Dec 17 13:26:27 vpn02d pluto[30773]: "tun02d02m" #39: malformed payload in
packet
Dec 17 13:26:27 vpn02d pluto[30773]: | payload malformed after IV
Dec 17 13:26:27 vpn02d pluto[30773]: | 7a e9 7c 76 b6 18 1e 61 bf ad
10 23 ef 02 25 da
Dec 17 13:26:27 vpn02d pluto[30773]: "tun02d02m" #39: sending notification
PAYLOAD_MALFORMED to <hidden ip>:500
Here is an lsmod:
Module Size Used by
ah6 39745 0
ah4 39617 0
esp6 42049 0
esp4 42177 31
xfrm4_tunnel 35649 0
xfrm4_mode_tunnel 35905 0
xfrm4_mode_transport 35137 31
xfrm6_mode_transport 35265 0
xfrm6_mode_tunnel 35777 0
ipcomp 41165 0
ipcomp6 41677 0
xfrm6_tunnel 42721 1 ipcomp6
af_key 101333 0
chainiv 37825 31
authenc 39873 31
hmac 37825 31
cryptomgr 36801 0
ip_gre 47329 0
ipmi_devintf 44753 2
ipmi_si 77453 1
ipmi_msghandler 72985 2 ipmi_devintf,ipmi_si
dell_rbu 41569 0
deflate 37057 0
zlib_deflate 52825 1 deflate
ccm 43201 0
serpent 51905 0
blowfish 41921 0
twofish 74945 0
ecb 36673 0
xcbc 39105 0
crypto_hash 35393 2 hmac,xcbc
cbc 37441 31
crypto_blkcipher 48449 5 chainiv,authenc,ccm,ecb,cbc
md5 37312 0
sha256 41793 0
sha512 38209 0
des 49729 0
aes_generic 59393 0
aes_x86_64 58601 31
xfrm6_esp 39105 1 esp6
xfrm4_esp 39233 1 esp4
aead 42049 4 esp6,esp4,authenc,ccm
crypto_algapi 52929 10
chainiv,authenc,hmac,cryptomgr,ccm,ecb,xcbc,cbc,crypto_blkcipher,aead
tunnel4 36553 1 xfrm4_tunnel
tunnel6 36681 1 xfrm6_tunnel
ipv6 420481 49
ah6,esp6,xfrm6_mode_transport,ipcomp6,xfrm6_tunnel,xfrm6_esp,tunnel6
xfrm_nalgo 43845 7 ah6,ah4,esp6,esp4,xfrm6_esp,xfrm4_esp,ipv6
crypto_api 42177 10
ah6,ah4,esp6,esp4,authenc,ccm,crypto_blkcipher,aead,crypto_algapi,xfrm_nalgo
dm_mirror 60617 0
dm_mod 99736 1 dm_mirror
video 53197 0
sbs 49921 0
backlight 39873 1 video
i2c_ec 38593 1 sbs
i2c_core 56129 1 i2c_ec
button 40545 0
battery 43849 0
asus_acpi 50917 0
acpi_memhotplug 40133 0
ac 38729 0
parport_pc 62313 0
lp 47121 0
parport 73165 2 parport_pc,lp
joydev 43969 0
ata_piix 55109 0
libata 192601 1 ata_piix
sr_mod 50789 0
sg 69993 0
shpchp 70765 0
pcspkr 36289 0
ide_cd 73697 0
serio_raw 40517 0
cdrom 68713 2 sr_mod,ide_cd
i5000_edac 42177 0
bnx2 173917 0
edac_mc 60193 1 i5000_edac
e1000e 133889 0
usb_storage 116769 0
megaraid_sas 71677 7
sd_mod 56257 6
scsi_mod 189177 6
libata,sr_mod,sg,usb_storage,megaraid_sas,sd_mod
ext3 167889 3
jbd 94129 1 ext3
ehci_hcd 65741 0
ohci_hcd 54493 0
uhci_hcd 57433 0
Here is my ipsec.conf:
version 2.0 # conforms to second version of ipsec.conf specification
# basic configuration
config setup
# NAT-TRAVERSAL support, see README.NAT-Traversal
nat_traversal=no
# On CentOS 5 there appears to be a problem identifying the
protocol stack
# to use. So we give it a clue.
protostack=netkey
# turn ip_forward on and off depending on whether we have any VPNs
forwardcontrol=yes
# Add connections here
include /etc/vpn/ipsec/*.conf
And here is an example .conf for one tunnel from /etc/vpn/ipsec.conf :
conn tun02j01m
left=<hidden ip>
right=<hidden ip>
leftnexthop=<hidden ip>
rightnexthop=<hidden ip>
leftupdown=/etc/vpn/_updown
rightupdown=/etc/vpn/_updown
authby=secret
pfs=yes
esp=aes256-sha1
ike=aes256-sha1
#pfsgroup=modp1536
type=transport
dpddelay=2
dpdtimeout=10
dpdaction=restart
auto=start
I also have a .secret file for each tunnel with a PSK. /etc/ipsec.secrets
includes these. The _updown script is the Openswan one with some logging
and GRE config added to uproute() and downroute().
Does anyone have any idea how I can go about debugging this problem?
Thanks
Tim
More information about the Users
mailing list