[ovirt-users] vdsm ssl errors

Mon Jul 25 16:18:40 UTC 2016

On Mon, Jul 25, 2016 at 6:22 PM, C. Handel <ovirt at macht-blau.org> wrote:
> two nodes (x.x.138.208, x.x.138.210), hosted-engine on x.x.139.240.
>
> the vdsm logs are from x.x.138.208 and the connection is from the node
> itself.
>
>> Running tcpdump it is a connect from the node to itself. I can't figure
>> out what is wrong. Can someone ?> give me a hint?
>
> so i know they are coming from the node itself. The process connecting is
> terminating too fast. the moment i see it in tcpdump, it is gone from the
> process table.

I think this is ovirt hosted agent - check its logs, you will probably find that
it make some request in the same time you see the errors in your logs.

Adding Martin, maintaining this project.

These are the interesting events in the logs:

$ grep 37678 vdsm.log
JsonRpc (StompReactor)::ERROR::2016-07-25
13:48:58,074::betterAsyncore::113::vds.dispatcher::(recv) SSL error
during reading data from <yajsonrpc.betterAsyncore.Dispatcher
connected ('::ffff:140.181.138.208', 37678, 0, 0) at 0x42c9b90>:
unexpected eof

$ grep 37684 vdsm.log
Reactor thread::INFO::2016-07-25
13:49:00,205::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
Accepting connection from ::ffff:140.181.138.208:37684
Reactor thread::INFO::2016-07-25
13:49:00,211::protocoldetector::121::ProtocolDetector.Detector::(handle_read)
Detected protocol stomp from ::ffff:140.181.138.208:37684
Reactor thread::DEBUG::2016-07-25
13:49:00,211::stompreactor::492::protocoldetector.StompDetector::(handle_socket)
Stomp detected from ('::ffff:140.181.138.208', 37684)
JsonRpc (StompReactor)::ERROR::2016-07-25
13:49:01,824::betterAsyncore::113::vds.dispatcher::(recv) SSL error
during reading data from <yajsonrpc.betterAsyncore.Dispatcher
connected ('::ffff:140.181.138.208', 37684, 0, 0) at 0x42b0758>:
unexpected eof

The log is too small, we see only one full request.

Pitor, can you understand from this log what the request coming from
::ffff:140.181.138.208:37684
is doing?

>
> Greetings
>    Christoph
>
> On Mon, Jul 25, 2016 at 4:53 PM, Piotr Kliczewski
> <piotr.kliczewski at gmail.com> wrote:
>>
>> Christoph,
>>
>> In log snippets you provided I can see 2 occurrences of the log entry.
>> There is 3 seconds between the calls.
>>
>> Each time I see calls to Host.getStats and Host.getHardwareInfo both
>> from x.x.138.208.
>> I do not see any log entries in the engine log so it not engine who
>> connected.
>>
>> What host is it?
>>
>> Thanks,
>> Piotr
>>
>>
>> On Mon, Jul 25, 2016 at 3:45 PM, C. Handel <ovirt at macht-blau.org> wrote:
>> > patch applied, The connection is from the node itself.
>> >
>> > logfiles with the last 100k (hope this is enough, the error happens
>> > every
>> > few seconds) of data attached.
>> >
>> > Greetings
>> >   Christoph
>> >
>> > On Mon, Jul 25, 2016 at 12:07 PM, Nir Soffer <nsoffer at redhat.com> wrote:
>> >>
>> >> On Thu, Jul 21, 2016 at 10:00 AM, C. Handel <ovirt at macht-blau.org>
>> >> wrote:
>> >> > longer logs attached, excerpts:
>> >> >
>> >> > ---+ vdsm
>> >> >
>> >> > Reactor thread::INFO::2016-07-21
>> >> >
>> >> >
>> >> > 08:01:19,544::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept)
>> >> > Accepting connection from ::ffff:140.181.138.208:59502
>> >> > Reactor thread::DEBUG::2016-07-21
>> >> >
>> >> >
>> >> > 08:01:19,551::protocoldetector::85::ProtocolDetector.Detector::(__init__)
>> >> > Using required_size=11
>> >> > Reactor thread::INFO::2016-07-21
>> >> >
>> >> >
>> >> > 08:01:19,553::protocoldetector::121::ProtocolDetector.Detector::(handle_read)
>> >> > Detected protocol stomp from ::ffff:140.181.138.208:59502
>> >> > Reactor thread::INFO::2016-07-21
>> >> > 08:01:19,553::stompreactor::101::Broker.StompAdapter::(_cmd_connect)
>> >> > Processing CONNECT request
>> >> > Reactor thread::DEBUG::2016-07-21
>> >> >
>> >> >
>> >> > 08:01:19,554::stompreactor::492::protocoldetector.StompDetector::(handle_socket)
>> >> > Stomp detected from ('::ffff:140.181.138.208', 59502)
>> >> > JsonRpc (StompReactor)::INFO::2016-07-21
>> >> >
>> >> > 08:01:19,554::stompreactor::128::Broker.StompAdapter::(_cmd_subscribe)
>> >> > Subscribe command received
>> >> > ...
>> >> >
>> >> > JsonRpc (StompReactor)::ERROR::2016-07-21
>> >> > 08:01:21,411::betterAsyncore::113::vds.dispatcher::(recv) SSL error
>> >> > during
>> >> > reading data: unexpected eof
>> >>
>> >> This log is not very useful as is, we must show the relevant remote
>> >> address.
>> >>
>> >> Should be improved in
>> >> https://gerrit.ovirt.org/61303
>> >>
>> >> Can you try this patch and share the log?
>> >>
>> >> >
>> >> >
>> >> > ---+ engine
>> >> >
>> >> >
>> >> > 2016-07-20 08:00:48,445 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler1) [1cff1b56] Fetched 7 VMs from VDS
>> >> > 'a46f9de2-4b79-45d4-bed5-f4f472eb8361'
>> >> > 2016-07-20 08:01:03,460 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler3) [78d8aa89] Fetched 0 VMs from VDS
>> >> > '6f7a9201-e753-4875-b89d-024120067687'
>> >> > 2016-07-20 08:01:03,473 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler2) [71a27a96] Fetched 7 VMs from VDS
>> >> > 'a46f9de2-4b79-45d4-bed5-f4f472eb8361'
>> >> > 2016-07-20 08:01:18,488 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler2) [71a27a96] Fetched 0 VMs from VDS
>> >> > '6f7a9201-e753-4875-b89d-024120067687'
>> >> > 2016-07-20 08:01:18,500 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler9) [47c419da] Fetched 7 VMs from VDS
>> >> > 'a46f9de2-4b79-45d4-bed5-f4f472eb8361'
>> >> > 2016-07-20 08:01:33,514 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler8) [735789] Fetched 0 VMs from VDS
>> >> > '6f7a9201-e753-4875-b89d-024120067687'
>> >> > 2016-07-20 08:01:33,527 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler3) [78d8aa89] Fetched 7 VMs from VDS
>> >> > 'a46f9de2-4b79-45d4-bed5-f4f472eb8361'
>> >> > 2016-07-20 08:01:48,543 INFO
>> >> > [org.ovirt.engine.core.vdsbroker.monitoring.VmsStatisticsFetcher]
>> >> > (DefaultQuartzScheduler8) [735789] Fetched 0 VMs from VDS
>> >> > '6f7a9201-e753-4875-b89d-024120067687'
>> >> >
>> >> >
>> >> > Greetings
>> >> >    Christoph
>> >> >
>> >> > On Thu, Jul 21, 2016 at 8:47 AM, Yaniv Kaul <ykaul at redhat.com> wrote:
>> >> >>
>> >> >> Can you share engine and VDSM logs please?
>> >> >> TIA,
>> >> >> Y.
>> >> >>
>> >> >> On Thu, Jul 21, 2016 at 9:22 AM, C. Handel <ovirt at macht-blau.org>
>> >> >> wrote:
>> >> >>>
>> >> >>> i have an ovirt 4.0.1 installation on two nodes. Hosted Engine. San
>> >> >>> storage backend.
>> >> >>>
>> >> >>> For some reason the vdsmd on the nodes is logging an error every
>> >> >>> few
>> >> >>> seconds:
>> >> >>>
>> >> >>>
>> >> >>> vdsm vds.dispatcher ERROR SSL error during reading data: unexpected
>> >> >>> eof
>> >> >>>
>> >> >>>
>> >> >>> Running tcpdump it is a connect from the node to itself. I can't
>> >> >>> figure
>> >> >>> out what is wrong. Can someone give me a hint?
>> >> >>>
>> >> >>> Greetings
>> >> >>>    Christoph
>> >> >>>
>> >> >>> _______________________________________________
>> >> >>> Users mailing list
>> >> >>> Users at ovirt.org
>> >> >>> http://lists.ovirt.org/mailman/listinfo/users
>> >> >>>
>> >> >>
>> >> >
>> >> >
>> >> > _______________________________________________
>> >> > Users mailing list
>> >> > Users at ovirt.org
>> >> > http://lists.ovirt.org/mailman/listinfo/users
>> >> >
>> >
>> >
>> >
>> > _______________________________________________
>> > Users mailing list
>> > Users at ovirt.org
>> > http://lists.ovirt.org/mailman/listinfo/users
>> >
>
>
>
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>