thr3ads.net - libvirt users - Re: Unable to decode message length [Jul 2020]

If this information is useful, please help other people find it:
Share via:

Valentin David

2020-Jul-14 17:42 UTC

Unable to decode message length

Hello all,

I have been trying to get libvirtd to work but when I connect to it 
with virsh, I get "error : virNetMessageDecodeLength:131 : Unable to 
decode message length"

This happens with libvirt 6.1.0, libtirpc 1.2.6, rpcsvc-proto 1.4.1. I 
have tried with other versions, but I still get the same error.

If anybody has any tip on what to try next, that would be helpful. 
Thank you in advance.

Here is the debug log of libvirtd when I try to connect with virsh:

2020-07-14 16:29:58.220+0000: 5352: info : 
virEventGLibHandleDispatch:116 : EVENT_GLIB_DISPATCH_HANDLE: watch=2 
events=1 cb=0x7f7b55b86c50 opaque=0x556fbcf8b8a0
2020-07-14 16:29:58.220+0000: 5352: info : virObjectNew:250 : 
OBJECT_NEW: obj=0x556fbcf8d770 classname=virNetSocket
2020-07-14 16:29:58.220+0000: 5352: info : virNetSocketNew:278 : 
RPC_SOCKET_NEW: sock=0x556fbcf8d770 fd=18 errfd=-1 pid=0 
localAddr=127.0.0.1;0, remoteAddr=127.0.0.1;0
2020-07-14 16:29:58.220+0000: 5352: info : virObjectNew:250 : 
OBJECT_NEW: obj=0x556fbcf8da50 classname=virNetServerClient
2020-07-14 16:29:58.220+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8d770
2020-07-14 16:29:58.220+0000: 5352: info : virEventGLibTimeoutAdd:341 : 
EVENT_GLIB_ADD_TIMEOUT: timer=1 interval=-1 cb=0x7f7b55b8d490 
opaque=0x556fbcf8da50 ff=(nil)
2020-07-14 16:29:58.220+0000: 5352: info : 
virNetServerClientNewInternal:421 : RPC_SERVER_CLIENT_NEW: 
client=0x556fbcf8da50 sock=0x556fbcf8d770
2020-07-14 16:29:58.220+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8da50
2020-07-14 16:29:58.220+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8d770
2020-07-14 16:29:58.220+0000: 5352: info : virEventGLibHandleAdd:160 : 
EVENT_GLIB_ADD_HANDLE: watch=11 fd=18 events=1 cb=0x7f7b55b86c50 
opaque=0x556fbcf8d770 ff=0x7f7b55b86c00
2020-07-14 16:29:58.220+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8da50
2020-07-14 16:29:58.220+0000: 5352: info : virNetServerCheckLimits:280 
: Re-enabling services
2020-07-14 16:29:58.220+0000: 5352: info : virEventGLibHandleUpdate:194 
: EVENT_GLIB_UPDATE_HANDLE: watch=2 events=1
2020-07-14 16:29:58.220+0000: 5352: info : virObjectNew:250 : 
OBJECT_NEW: obj=0x556fbcf8e330 classname=virKeepAlive
2020-07-14 16:29:58.220+0000: 5352: info : virKeepAliveNew:208 : 
RPC_KEEPALIVE_NEW: ka=0x556fbcf8e330 client=0x556fbcf8da50
2020-07-14 16:29:58.220+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8da50
2020-07-14 16:29:58.220+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8da50
2020-07-14 16:29:58.220+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8d770
2020-07-14 16:29:58.220+0000: 5352: info : 
virEventGLibHandleDispatch:116 : EVENT_GLIB_DISPATCH_HANDLE: watch=11 
events=1 cb=0x7f7b55b86c50 opaque=0x556fbcf8d770
2020-07-14 16:29:58.220+0000: 5352: error : 
virNetMessageDecodeLength:131 : Unable to decode message length
2020-07-14 16:29:58.220+0000: 5352: info : virKeepAliveStop:300 : 
RPC_KEEPALIVE_STOP: ka=0x556fbcf8e330 client=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8e330
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:349 : 
OBJECT_DISPOSE: obj=0x556fbcf8e330
2020-07-14 16:29:58.221+0000: 5352: info : virKeepAliveDispose:221 : 
RPC_KEEPALIVE_DISPOSE: ka=0x556fbcf8e330
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virObjectRef:385 : 
OBJECT_REF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virEventGLibHandleRemove:261 
: EVENT_GLIB_REMOVE_HANDLE: watch=11
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8d770
2020-07-14 16:29:58.221+0000: 5352: info : virNetServerCheckLimits:280 
: Re-enabling services
2020-07-14 16:29:58.221+0000: 5352: info : virEventGLibHandleUpdate:194 
: EVENT_GLIB_UPDATE_HANDLE: watch=2 events=1
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : 
virEventGLibHandleRemoveIdle:242 : EVENT_GLIB_REMOVE_HANDLE_IDLE: 
watch=11 ff=0x7f7b55b86c00 opaque=0x556fbcf8d770
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:349 : 
OBJECT_DISPOSE: obj=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : 
virNetServerClientDispose:976 : RPC_SERVER_CLIENT_DISPOSE: 
client=0x556fbcf8da50
2020-07-14 16:29:58.221+0000: 5352: info : 
virEventGLibTimeoutRemove:437 : EVENT_GLIB_REMOVE_TIMEOUT: timer=1
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:347 : 
OBJECT_UNREF: obj=0x556fbcf8d770
2020-07-14 16:29:58.221+0000: 5352: info : virObjectUnref:349 : 
OBJECT_DISPOSE: obj=0x556fbcf8d770
2020-07-14 16:29:58.221+0000: 5352: info : virNetSocketDispose:1332 : 
RPC_SOCKET_DISPOSE: sock=0x556fbcf8d770
2020-07-14 16:29:58.221+0000: 5352: info : 
virEventGLibTimeoutRemoveIdle:417 : EVENT_GLIB_REMOVE_TIMEOUT_IDLE: 
timer=1 ff=(nil) opaque=0x556fbcf8da50

Michal Privoznik

2020-Jul-15 14:02 UTC

head link

Re: Unable to decode message length

On 7/14/20 7:42 PM, Valentin David wrote:> Hello all,
> 
> I have been trying to get libvirtd to work but when I connect to it with 
> virsh, I get "error : virNetMessageDecodeLength:131 : Unable to decode
> message length"
> 
> This happens with libvirt 6.1.0, libtirpc 1.2.6, rpcsvc-proto 1.4.1. I 
> have tried with other versions, but I still get the same error.
> 
> If anybody has any tip on what to try next, that would be helpful. Thank 
> you in advance.
> 
> Here is the debug log of libvirtd when I try to connect with virsh:
> 
> 2020-07-14 16:29:58.220+0000: 5352: error : 
> virNetMessageDecodeLength:131 : Unable to decode message length
This is interesting. The error message is reported when xdr_u_int() 
fails. It is trying to decode first 4 bytes of incoming message to see 
how long it is. I can think of two possible reasons for this:

1) the client did not send 4 bytes
2) the rpcgen generated some wrong code that libtirpc is unable to decode.

I suggest using wireshark to check what data is send (don't forget to 
use plain TCP transport in URI, for instance 'virsh -c 
qemu+tcp://localhost/system'). The first call that virsh does is 
AUTH_LIST procedure and it should look like this:

0000   00 00 00 00 00 00 00 00 00 00 00 00 86 dd 60 04
0010   52 cc 00 3c 06 40 00 00 00 00 00 00 00 00 00 00
0020   00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00
0030   00 00 00 00 00 01 df 6c 40 7d fd e7 38 94 09 92
0040   bf 48 80 18 02 00 00 44 00 00 01 01 08 0a c9 4f
0050   f4 f2 c9 4f f4 f2 00 00 00 1c 20 00 80 86 00 00
0060   00 01 00 00 00 42 00 00 00 00 00 00 00 00 00 00
0070   00 00

bytes 0x56-0x59 contain 0x1c (= 28) which is the length of the packet 
(28 bytes). This is how our dissector decodes it:

Libvirt
     length: 28
     program: REMOTE (0x20008086)
     version: 1
     procedure: AUTH_LIST (66)
     type: CALL (0)
     serial: 0
     status: OK (0)


Michal

Valentin David

2020-Jul-16 09:48 UTC

head link

Re: Unable to decode message length

Thank you for the help. But here I get exactly the same data as you. So 
I suppose the issue is on the server side only. I will try with gdb now.

On Wed, Jul 15, 2020 at 16:02, Michal Privoznik <mprivozn@redhat.com> 
wrote:> On 7/14/20 7:42 PM, Valentin David wrote:
>> Hello all,
>> 
>> I have been trying to get libvirtd to work but when I connect to it 
>> with virsh, I get "error : virNetMessageDecodeLength:131 : Unable 
>> to decode message length"
>> 
>> This happens with libvirt 6.1.0, libtirpc 1.2.6, rpcsvc-proto 1.4.1. 
>> I have tried with other versions, but I still get the same error.
>> 
>> If anybody has any tip on what to try next, that would be helpful. 
>> Thank you in advance.
>> 
>> Here is the debug log of libvirtd when I try to connect with virsh:
>> 
> 
>> 2020-07-14 16:29:58.220+0000: 5352: error : 
>> virNetMessageDecodeLength:131 : Unable to decode message length
> 
> This is interesting. The error message is reported when xdr_u_int() 
> fails. It is trying to decode first 4 bytes of incoming message to 
> see how long it is. I can think of two possible reasons for this:
> 
> 1) the client did not send 4 bytes
> 2) the rpcgen generated some wrong code that libtirpc is unable to 
> decode.
> 
> I suggest using wireshark to check what data is send (don't forget to 
> use plain TCP transport in URI, for instance 'virsh -c 
> qemu+tcp://localhost/system'). The first call that virsh does is 
> AUTH_LIST procedure and it should look like this:
> 
> 0000   00 00 00 00 00 00 00 00 00 00 00 00 86 dd 60 04
> 0010   52 cc 00 3c 06 40 00 00 00 00 00 00 00 00 00 00
> 0020   00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00
> 0030   00 00 00 00 00 01 df 6c 40 7d fd e7 38 94 09 92
> 0040   bf 48 80 18 02 00 00 44 00 00 01 01 08 0a c9 4f
> 0050   f4 f2 c9 4f f4 f2 00 00 00 1c 20 00 80 86 00 00
> 0060   00 01 00 00 00 42 00 00 00 00 00 00 00 00 00 00
> 0070   00 00
> 
> bytes 0x56-0x59 contain 0x1c (= 28) which is the length of the packet 
> (28 bytes). This is how our dissector decodes it:
> 
> Libvirt
>     length: 28
>     program: REMOTE (0x20008086)
>     version: 1
>     procedure: AUTH_LIST (66)
>     type: CALL (0)
>     serial: 0
>     status: OK (0)
> 
> 
> Michal
> 
>

Apparently Analagous Threads

Search for more seemingly similar threads

libvirt users - Jul 2020 - Re: Unable to decode message length

Unable to decode message length

Re: Unable to decode message length

Re: Unable to decode message length

Apparently Analagous Threads