[tbot] How to debug acquire_linux

[Harald Seiler]

Hi Stefano,

On Fri, 2018-11-23 at 13:04 +0100, Stefano Babic wrote:
> On 23/11/18 12:32, Harald Seiler wrote:
> > On Thu, 2018-11-22 at 19:24 +0100, Stefano Babic wrote:
> > > Hi,
> > > 
> > > I have a board that cannot be got in linux. It looks like that
> > > tbot.acquire_linux() hangs forever (can I set a tiimeout ?)
> > > 
> > > I ran a testcase that works fine for another board - I guess that the
> > > issue is due to the fact that this board has a lot of output in part
> > > caused by systemd and in part due to kernel messages that are printed to
> > > the console. When I start the testcase, tbot remains in <board>-linux. I
> > > can understand that board is up and works because software activates
> > > some relays, but it is not recognized by tbot.
> > > 
> > > The weird thing is that "interactive_linux" works.
> > 
> > I overlooked this previously ... `interactive_linux` works?  That's not
> > possible, it uses the *exact same* code-path ... Is this a consistent
> > observation?
> 
> That is was puzzle me. It worked - anyway, if I run 10 times the test
> with login_wait=1 (or 2) as I had at the beginning, at least once
> worked. So it seems there is a race, maybe because the shell (bash)
> takes more time as you supposed.
> 
> After I put login_wait=10, it works flawlessly.
> 
> > 
> > > How can I debug this? 
> > 
> > I pushed changes to the development branch that allow deeper introspection by showing
> > all data sent and received ...
> 
> Ok, I have installed it

Are you sure? The output still looks like the one from the old version ...
Does `tbot --version` say "0.6.2-dev"?

If not, checkout the development branch locally, pull and run

	python3 setup.py install --user

again please.

> and I ran again with -vvv and login_wait=1. It
> hangs as before (at least, it is reproducible). I see some kernel
> messages, but at a previous point during booting. But last entries are:
> 
> │   ├─'GTU-'
> │   ├─'0 login: '
> │   │    <> GTU-0 login: root
> │   ├─'root\n\x1b7\x1b[r\x1b[999;999H\x1b[6n'
> │   ├─'\x1b8'
> │   ├─'root at GTU-0:~# '
> 
> 
> and now tbot hangs forever.
> 
> When I run with login_wait=5, it works and it reports:
> 
> │   ├─'GTU-0 logi'
> │   ├─'n: '
> │   │    <> GTU-0 logilogin: root
> │   ├─'root\n\x1b7\x1b[r\x1b[999;999H\x1b[6n[   14.801206] socfpga-dwmac
> ff700000.ethernet eth0: Link is Up - 100Mbps/Full - flow control
> rx/tx\n[   14.810014] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes
> ready\nroot at GTU-0:~# '
> │   ├─'\n'
> │   ├─'root at G'
> │   ├─'TU-0:~# PROMPT_CO'
> │   ├─"MMAND=''\n"
> │   ├─'roo'
> │   ├─"t at GTU-0:~# PS1='TB"
> │   ├─'OT-VEJPVC1QUk9N'
> 
> ....
> 
> And it goes on until test completion.
> 
> Best regards,
> Stefano
> 
-- 
Harald

DENX Software Engineering GmbH,      Managing Director: Wolfgang Denk
HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
Phone: +49-8142-66989-62  Fax: +49-8142-66989-80   Email: hws at denx.de