From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Authentication-Results: lists.ozlabs.org; spf=pass (mailfrom) smtp.mailfrom=gmail.com (client-ip=2a00:1450:4864:20::334; helo=mail-wm1-x334.google.com; envelope-from=tajudheenk@gmail.com; receiver=) Authentication-Results: lists.ozlabs.org; dmarc=pass (p=none dis=none) header.from=gmail.com Authentication-Results: lists.ozlabs.org; dkim=pass (2048-bit key; unprotected) header.d=gmail.com header.i=@gmail.com header.b="hX4t1Afi"; dkim-atps=neutral Received: from mail-wm1-x334.google.com (mail-wm1-x334.google.com [IPv6:2a00:1450:4864:20::334]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by lists.ozlabs.org (Postfix) with ESMTPS id 44QBym1RsWzDqRm for ; Fri, 22 Mar 2019 03:27:26 +1100 (AEDT) Received: by mail-wm1-x334.google.com with SMTP id o10so2398763wmc.1 for ; Thu, 21 Mar 2019 09:27:26 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=fyXucGNKVCpDjc8tq3ZBJt/wdxXjPB2kUHMdqK8ogOw=; b=hX4t1AfiUQw2R/Zd5aNqOoC/RbYoSESquVQ+y8E/bIwnGSx+pDN04RuSNKVdqI5Sqx 7B6r1mYBGEYFPI1dKLRSfQwNeoWnaRMp5u5W+jgFifqBp6RAuq0Djw000v2UOMqA22u5 yU1/CB3JO0eb3wO/gtHfbjAdgUnJpTru2FNNYHqlYKPVs1oBzg4SeHoL3SP7RSjDcQEM U/RWmUCZGDDX+onVH437HC707eUb+nFXx6RqF1LXrftVYzN5NmdQHrVPAra2dhM/M8Zs xbbtArAf/PQ94xmcGM+5RO/E1Nae/A8CrAssav4LWnGUdAMXIJTNDUG8x/85WQXAqcGj L3jw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=fyXucGNKVCpDjc8tq3ZBJt/wdxXjPB2kUHMdqK8ogOw=; b=OTTQbR76afqV/IMJjCviNxl0EDHxJBy5/Ffsanq8f5aRwqG0uFu08Sv0cxUWXaVGfQ NLWetXwd/E8Om+J1LK1UzaUiQ3pzRF4JCqe8M7j4Vh2STUnE0Mk+JoxElngacUDzwxJG GSIQFF7HcDugrwDL8UvEzrj55K6sqwR/V8EhhGimyfBICeyO2Z0TxwzOKm+rTdp+UQJm VaGlJa6p7P3rmn0Ehc/XVlUWCwXea4zcAREFqzQpOvyi7RsIXNqaxGaBBgIu6NbdHaYv T2x7gZNGuo8A4CDSSHEV0jojhDch38P66OJEZphHqfoOPdYNA0AhGrMYNTD9dVwkl9if QhNw== X-Gm-Message-State: APjAAAUhJhXMTeSveibf1+P4xB1oMNcglEQ+LjpZ4s+xi3sWy2s/jXw3 3dCSgYkqgEi37hX49gGoxd4aONSM5IBobseJy9A= X-Google-Smtp-Source: APXvYqxXmoeU9GHLeNcLAu5SxOUP6vgZf2FMakqkx274BmdW3IDZRC2LBKRAcethAU4AYGRnoIVA8JweMHhp9EbBcnQ= X-Received: by 2002:a1c:5459:: with SMTP id p25mr99281wmi.20.1553185642715; Thu, 21 Mar 2019 09:27:22 -0700 (PDT) MIME-Version: 1.0 References: <2d44c252-94b6-6441-d3e8-a8200d89aaa5@linux.intel.com> <77cb1f2b-96c5-bd14-eab7-0da527343ce1@linux.intel.com> In-Reply-To: From: Thaju Date: Thu, 21 Mar 2019 21:57:10 +0530 Message-ID: Subject: Re: Does obmc-ikvm work with bmcweb? To: Jae Hyun Yoo Cc: Lei YU , xiuzhi <1450335857@qq.com>, openbmc , ed , Eddie James Content-Type: multipart/alternative; boundary="0000000000008121f505849d36be" X-BeenThere: openbmc@lists.ozlabs.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Development list for OpenBMC List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 21 Mar 2019 16:27:29 -0000 --0000000000008121f505849d36be Content-Type: text/plain; charset="UTF-8" Hi Jae, It works. Found one issue which is explained below. I have applied below 3 patches: https://gerrit.openbmc-project.xyz/c/openbmc/obmc-ikvm/+/19392 https://gerrit.openbmc-project.xyz/c/openbmc/obmc-ikvm/+/19433 https://gerrit.openbmc-project.xyz/c/openbmc/obmc-ikvm/+/19393 I can confirm that: 1. KVM video appears fine in webui 2. All keyboard characters works fine. 3. Both mouse buttons works fine (with patch) Now the issue is when host OS ( RHEL 7.5 in my case ) goes to power saving mode (black screen) after some N mins (depends on OS settings), looks like it does not accept the KVM HID events, it doesn't wake up from power saving mode through KVM. I see below error when this happens. Mar 21 09:31:43 obmc-ikvm[1408]: Failed to query timings Mar 21 09:31:43 kernel: aspeed-video 1e700000.video: Timed out; first mode detect Mar 21 09:31:44 kernel: aspeed-video 1e700000.video: Timed out when stopping streaming Mar 21 09:31:45 kernel: aspeed-video 1e700000.video: Timed out; first mode detect Mar 21 09:31:46 kernel: aspeed-video 1e700000.video: Timed out; first mode detect Mar 21 09:31:47 env[1408]: 21/03/2019 09:31:47 Sending rfbEncodingNewFBSize for resize to (640x480) Mar 21 09:31:48 obmc-ikvm[1408]: Failed to query timings Mar 21 09:31:49 kernel: aspeed-video 1e700000.video: Timed out; first mode detect Mar 21 09:31:50 obmc-ikvm[1408]: Failed to query timings Mar 21 09:31:51 kernel: aspeed-video 1e700000.video: Timed out; first mode detect Mar 21 09:31:52 obmc-ikvm[1408]: Failed to query timings Mar 21 09:31:53 kernel: aspeed-video 1e700000.video: Timed out; first mode detect On this state, I used physical keyboard on the host OS to bring it back from power saving mode and I see KVM also comes back. I have also tried setting the power saving timeout to "never". It works fine. To recreate this issue 1. Set power saving timeout to 1 min. (In RHEL 7.5, Settings > Power > Blank Screen) 2. Leave the host OS to idle for 1 min. 3. You will see screen goes black after 1 min and KVM stops responding. Hope you understood the issue. Thanks for your support. Regards, Thaj On Thu, Mar 21, 2019 at 9:49 PM Jae Hyun Yoo wrote: > Hi Lei, > > Are you using a web browser from Windows OS? It seems that there is an > issue of Windows websockify/novnc. Use a browser from OS other than > Windows til the issue is resolved. > > Did you test it using Tight VNC viewer after enabling external > connection? The reason why I suggested that is to identify whether > this issue comes from KVM web proxy or from KVM server. > > Need more information of your test environment. > Server platform: > BMC SoC: > Host OS: > > Regards, > Jae > > On 3/21/2019 12:02 AM, Lei YU wrote: > >> Check journal (journalctl -f) while you're testing KVM if there is any > >> suspicious error. In normal opration, you should see logs like below: > > > > I see the same logs as Thaj, only below logs show when the issue occurs. > > > > Mar 21 05:26:02 romulus env[1564]: 21/03/2019 05:26:02 Unable to > > establish connection with systemd socket > > Mar 21 05:26:02 romulus env[1564]: 21/03/2019 05:26:02 Listening for > > VNC connections on TCP port 5900 > > Mar 21 05:26:02 romulus env[1564]: 21/03/2019 05:26:02 Listening for > > VNC connections on TCP6 port 5900 > > Mar 21 05:26:06 romulus env[1564]: 21/03/2019 05:26:06 Got connection > > from client 127.0.0.1 > > Mar 21 05:26:06 romulus env[1564]: 21/03/2019 05:26:06 other clients: > > Mar 21 05:26:06 romulus env[1564]: 21/03/2019 05:26:06 Normal socket > connection > > > > And sometimes it works, then I see logs like: > > > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Normal socket > connection > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Client Protocol > > Version 3.8 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Protocol > > version sent 3.8, using 3.8 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 > > rfbProcessClientSecurityType: executing handler for type 1 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 > > rfbProcessClientSecurityType: returning securityResult for client rfb > > version >= 3.8 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Pixel format > > for client 192.168.10.11: > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 32 bpp, depth > > 24, little endian > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 true colour: > > max r 255 g 255 b 255, shift r 16 g 8 b 0 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using > > compression level 1 for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using image > > quality level 6 for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using JPEG > > subsampling 0, Q79 for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling > > X-style cursor updates for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling > > full-color cursor updates for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling cursor > > position updates for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling > > LastRect protocol extension for client 192.168.10.11 > > Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using tight > > encoding for client 192.168.10.11 > > > > It's found that the VNC server may work when the screen is changed, e.g. > > reboot the OS, or enter the OS. > > When OS is in idle, usually it will not work. > > > >> Also, try these two patches. I added one more patch. > >> https://gerrit.openbmc-project.xyz/c/openbmc/obmc-ikvm/+/19392 > >> https://gerrit.openbmc-project.xyz/c/openbmc/obmc-ikvm/+/19433 > > > > Tried the patches, still the same issue as above. > > > --0000000000008121f505849d36be Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
Hi Jae,

It works. Foun= d one issue which is explained below.

I have appli= ed below 3 patches:

I can confir= m that:
1. KVM video appears fine in webui
2. All keybo= ard characters works fine.
3. Both mouse buttons works fine (with= patch)

Now the issue is when host OS ( RHEL 7.5 i= n my case ) goes to power saving mode (black screen) after some N mins (dep= ends on OS settings), looks like it does not accept the KVM HID events, it = doesn't wake up from power saving mode through KVM. I see below error w= hen this happens.

Mar 21 09:31:43=C2=A0 obmc-= ikvm[1408]: Failed to query timings
Mar 21 09:31:43=C2=A0 kernel:= aspeed-video 1e700000.video: Timed out; first mode detect
Mar 21= 09:31:44=C2=A0 kernel: aspeed-video 1e700000.video: Timed out when stoppin= g streaming
Mar 21 09:31:45=C2=A0 kernel: aspeed-video 1e700000.v= ideo: Timed out; first mode detect
Mar 21 09:31:46=C2=A0 kernel: = aspeed-video 1e700000.video: Timed out; first mode detect
Mar 21 = 09:31:47=C2=A0 env[1408]: 21/03/2019 09:31:47 Sending rfbEncodingNewFBSize = for resize to (640x480)
Mar 21 09:31:48=C2=A0 obmc-ikvm[1408]: Fa= iled to query timings
Mar 21 09:31:49=C2=A0 kernel: aspeed-video = 1e700000.video: Timed out; first mode detect
Mar 21 09:31:50=C2= =A0 obmc-ikvm[1408]: Failed to query timings
Mar 21 09:31:51=C2= =A0 kernel: aspeed-video 1e700000.video: Timed out; first mode detect
=
Mar 21 09:31:52=C2=A0 obmc-ikvm[1408]: Failed to query timings
Mar 21 09:31:53=C2=A0 kernel: aspeed-video 1e700000.video: Timed out; fi= rst mode detect

On this state, I used physic= al keyboard on the host OS to bring it back from power saving mode and I se= e KVM also comes back. I have also tried setting the power saving timeout t= o "never". It works fine.

To recreate th= is issue
1. Set power saving timeout to 1 min. (In RHEL 7.5, Sett= ings > Power > Blank Screen)
2. Leave the host OS to idle f= or 1 min.
3. You will see screen goes black after 1 min and KVM s= tops responding.=C2=A0

Hope you understood the iss= ue. Thanks for your support.

Reg= ards,
Thaj

On Thu, Mar 21, 2019 at 9:49 PM Jae Hyun Yoo <= jae.hyun.yoo@linux.intel.co= m> wrote:
Hi Lei,

Are you using a web browser from Windows OS? It seems that there is an
issue of Windows websockify/novnc. Use a browser from OS other than
Windows til the issue is resolved.

Did you test it using Tight VNC viewer after enabling external
connection? The reason why I suggested that is to identify whether
this issue comes from KVM web proxy or from KVM server.

Need more information of your test environment.
Server platform:
BMC SoC:
Host OS:

Regards,
Jae

On 3/21/2019 12:02 AM, Lei YU wrote:
>> Check journal (journalctl -f) while you're testing KVM if ther= e is any
>> suspicious error. In normal opration, you should see logs like bel= ow:
>
> I see the same logs as Thaj, only below logs show when the issue occur= s.
>
> Mar 21 05:26:02 romulus env[1564]: 21/03/2019 05:26:02 Unable to
> establish connection with systemd socket
> Mar 21 05:26:02 romulus env[1564]: 21/03/2019 05:26:02 Listening for > VNC connections on TCP port 5900
> Mar 21 05:26:02 romulus env[1564]: 21/03/2019 05:26:02 Listening for > VNC connections on TCP6 port 5900
> Mar 21 05:26:06 romulus env[1564]: 21/03/2019 05:26:06 Got connection<= br> > from client 127.0.0.1
> Mar 21 05:26:06 romulus env[1564]: 21/03/2019 05:26:06=C2=A0 =C2=A0oth= er clients:
> Mar 21 05:26:06 romulus env[1564]: 21/03/2019 05:26:06 Normal socket c= onnection
>
> And sometimes it works, then I see logs like:
>
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Normal socket c= onnection
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Client Protocol=
> Version 3.8
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Protocol
> version sent 3.8, using 3.8
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12
> rfbProcessClientSecurityType: executing handler for type 1
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12
> rfbProcessClientSecurityType: returning securityResult for client rfb<= br> > version >=3D 3.8
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Pixel format > for client 192.168.10.11:
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12=C2=A0 =C2=A032 = bpp, depth
> 24, little endian
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12=C2=A0 =C2=A0tru= e colour:
> max r 255 g 255 b 255, shift r 16 g 8 b 0
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using
> compression level 1 for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using image
> quality level 6 for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using JPEG
> subsampling 0, Q79 for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling
> X-style cursor updates for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling
> full-color cursor updates for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling cursor=
> position updates for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Enabling
> LastRect protocol extension for client 192.168.10.11
> Mar 21 06:54:12 romulus env[1957]: 21/03/2019 06:54:12 Using tight
> encoding for client 192.168.10.11
>
> It's found that the VNC server may work when the screen is changed= , e.g.
> reboot the OS, or enter the OS.
> When OS is in idle, usually it will not work.
>
>> Also, try these two patches. I added one more patch.
>> https://gerrit.openbmc-projec= t.xyz/c/openbmc/obmc-ikvm/+/19392
>> https://gerrit.openbmc-projec= t.xyz/c/openbmc/obmc-ikvm/+/19433
>
> Tried the patches, still the same issue as above.
>
--0000000000008121f505849d36be--