Hello Stefan,
Thanks for replying.
-
Does the line "[login-action] Waiting for messages, (timeout 00:0x:xx)" appear in logs? I guess yes.
I can see error "
Job error: auto-login-action timed out after 900 seconds"
"auto-login-action: Wait for prompt ['Linux version [0-9]'] (timeout 00:15:00)"
But I couldn't find "[login-action] Waiting for messages, (timeout 00:0x:xx)" in my logs.
-
Does the line "Matched prompt #xx: login:" and "Sending username root" appear? No
Please find the job details of the logs i shared earlier:
- boot:
timeout:
minutes: 15
method: qemu
media: tmpfs
prompts:
- 'Variant.....: XXXXX'
- 'HOST login:'
- 'root@HOST'
auto_login:
login_prompt: "HOST login:"
username: root
password_prompt: "Password:"
password: "root"
Also tried
- boot:
timeout:
minutes: 15
method: qemu
media: tmpfs
prompts:
- 'Variant.....: XXXXX'
- 'HOST login:'
- 'root@HOST'
auto_login:
login_prompt: "do[redacted]t login:"
username: root
password_prompt: "Password:"
password: "root"
Getting logs:
wait for prompt timed out
end: 2.2 auto-login-action (duration 00:12:03) [common]
boot-image-retry failed: 1 of 1 attempts. 'wait for prompt timed out'
wait for prompt timed out
end: 2 boot-image-retry (duration 00:12:03) [common]
Cleaning after the job
Cleaning up download directory: /var/lib/lava/dispatcher/tmp/226/deployimages-sfxemxh6/rootfs
start: 4.1 power-off (timeout 00:00:10) [common]
end: 4.1 power-off (duration 00:00:00) [common]
start: 4.2 read-feedback (timeout 00:05:00) [common]
Listened to connection for namespace 'common' for up to 1s
Finalising connection for namespace 'common'
Sending line: 'poweroff'
Already disconnected
device-mgmt login: poweroff
Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 173, in expect proc = super().expect(*args, **kw)
^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/spawnbase.py", line 343, in expect return self.expect_list(compiled_pattern_list, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/spawnbase.py",
line 372, in expect_list return exp.expect_loop(timeout) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/expect.py", line 181, in expect_loop return self.timeout(e) ^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/expect.py",
line 144, in timeout raise exc pexpect.exceptions.TIMEOUT: Timeout exceeded. <lava_dispatcher.shell.ShellCommand object at 0x7fc3ec2a43d0> command: /usr/bin/qemu-system-x86_64 args: [b'/usr/bin/qemu-system-x86_64', b'-cpu', b'host', b'-enable-kvm', b'-nographic',
b'-net', b'nic,model=virtio,macaddr=52:54:00:12:34:58', b'-net', b'user', b'-m', b'1024', b'-monitor', b'none', b'-global', b'ICH9-LPC.disable_s3=1', b'-global', b'isa-fdc.driveA=', b'-drive', b'if=pflash,format=raw,unit=0,readonly=on,file=/usr/share/OVMF/OVMF_CODE_4M.fd',
b'-drive', b'file=/var/lib/lava/dispatcher/tmp/226/deployimages-sfxemxh6/rootfs/XXXXX-qemu_amd64.wic,discard=unmap,if=none,id=disk,format=raw', b'-m', b'8G', b'-monitor', b'none', b'-serial', b'mon:stdio', b'-display', b'none', b'-cpu', b'qemu64', b'-smp',
b'4', b'-machine', b'q35,accel=kvm:tcg', b'-global', b'ICH9-LPC.noreboot=off', b'-device', b'ide-hd,drive=disk', b'-nographic', b'-chardev', b'socket,id=chrtpm,path=/tmp/swtpm.sock/qemu-swtpm.sock', b'-tpmdev', b'emulator,id=tpm0,chardev=chrtpm', b'-device',
b'tpm-tis,tpmdev=tpm0', b'-drive', b'format=qcow2,file=/var/lib/lava/dispatcher/tmp/226/apply-overlay-guest-_kawe9vb/lava-guest.qcow2,media=disk,if=ide,id=lavatest'] buffer (last 100 chars): 'and type "http://"\x1b[0m\r\r\n\r\r\nYou are currently connected
via: ttyS0 (115200)\r\r\n\r\r\nHOST login: ' before (last 100 chars): 'and type "http://"\x1b[0m\r\r\n\r\r\nYou are currently connected via: ttyS0 (115200)\r\r\n\r\r\nHOST login: ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus:
None flag_eof: False pid: 6170 child_fd: 10 closed: False timeout: 900 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: <lava_dispatcher.shell.ShellLogger object at 0x7fc3f188d190> logfile_send: <lava_dispatcher.shell.ShellLogger object
at 0x7fc3ec48bb10> maxread: 2000 ignorecase: False searchwindowsize: 4000 delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 1.0 searcher: searcher_re: 0: re.compile('Linux version [0-9]') During handling of the above exception, another exception
occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 301, in wait return self.raw_connection.expect(self.prompt_str, timeout=timeout) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 178, in expect raise TestError("ShellCommand command timed out.") lava_common.exceptions.TestError: ShellCommand command timed out. During handling of the above exception, another exception
occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/job.py", line 239, in run self._run() File "/usr/lib/python3/dist-packages/lava_dispatcher/job.py", line 229, in _run self.pipeline.run_actions(self.connection,
max_end_time) File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 249, in run_actions new_connection = action.run(connection, action_max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/logical.py",
line 62, in run connection = self.pipeline.run_actions(connection, max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 249, in run_actions new_connection
= action.run(connection, action_max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/actions/boot/__init__.py", line 328, in run res = self.wait(connection) ^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 943, in wait return connection.wait(max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 303, in wait raise
JobError("wait for prompt timed out") lava_common.exceptions.JobError: wait for prompt timed out During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py",
line 23, in _wrap_ptyprocess_err yield File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py", line 328, in close self.ptyproc.close(force=force) File "/usr/lib/python3/dist-packages/ptyprocess/ptyprocess.py", line 406, in close raise PtyProcessError('Could
not terminate the child.') ptyprocess.util.PtyProcessError: Could not terminate the child. During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py",
line 249, in run_actions new_connection = action.run(connection, action_max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/power.py", line 308, in run feedback[1].finalise()
File "/usr/lib/python3/dist-packages/lava_dispatcher/connections/serial.py", line 246, in finalise self.disconnect("closing") File "/usr/lib/python3/dist-packages/lava_dispatcher/connections/serial.py", line 253, in disconnect super().disconnect(reason)
File "/usr/lib/python3/dist-packages/lava_dispatcher/connection.py", line 153, in disconnect self.raw_connection.close(force=True) File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py", line 325, in close with _wrap_ptyprocess_err(): File "/usr/lib/python3.11/contextlib.py",
line 155, in __exit__ self.gen.throw(typ, value, traceback) File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py", line 25, in _wrap_ptyprocess_err raise ExceptionPexpect(*e.args) pexpect.exceptions.ExceptionPexpect: Could not terminate the child.
end: 4.2 read-feedback (duration 00:00:02) [common]
Failed to run 'finalize': Could not terminate the child.
Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 173, in expect proc = super().expect(*args, **kw)
^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/spawnbase.py", line 343, in expect return self.expect_list(compiled_pattern_list, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/spawnbase.py",
line 372, in expect_list return exp.expect_loop(timeout) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/expect.py", line 181, in expect_loop return self.timeout(e) ^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/pexpect/expect.py",
line 144, in timeout raise exc pexpect.exceptions.TIMEOUT: Timeout exceeded. <lava_dispatcher.shell.ShellCommand object at 0x7fc3ec2a43d0> command: /usr/bin/qemu-system-x86_64 args: [b'/usr/bin/qemu-system-x86_64', b'-cpu', b'host', b'-enable-kvm', b'-nographic',
b'-net', b'nic,model=virtio,macaddr=52:54:00:12:34:58', b'-net', b'user', b'-m', b'1024', b'-monitor', b'none', b'-global', b'ICH9-LPC.disable_s3=1', b'-global', b'isa-fdc.driveA=', b'-drive', b'if=pflash,format=raw,unit=0,readonly=on,file=/usr/share/OVMF/OVMF_CODE_4M.fd',
b'-drive', b'file=/var/lib/lava/dispatcher/tmp/226/deployimages-sfxemxh6/rootfs/XXXX-qemu_amd64.wic,discard=unmap,if=none,id=disk,format=raw', b'-m', b'8G', b'-monitor', b'none', b'-serial', b'mon:stdio', b'-display', b'none', b'-cpu', b'qemu64', b'-smp',
b'4', b'-machine', b'q35,accel=kvm:tcg', b'-global', b'ICH9-LPC.noreboot=off', b'-device', b'ide-hd,drive=disk', b'-nographic', b'-chardev', b'socket,id=chrtpm,path=/tmp/swtpm.sock/qemu-swtpm.sock', b'-tpmdev', b'emulator,id=tpm0,chardev=chrtpm', b'-device',
b'tpm-tis,tpmdev=tpm0', b'-drive', b'format=qcow2,file=/var/lib/lava/dispatcher/tmp/226/apply-overlay-guest-_kawe9vb/lava-guest.qcow2,media=disk,if=ide,id=lavatest'] buffer (last 100 chars): 'and type "http://"\x1b[0m\r\r\n\r\r\nYou are currently connected
via: ttyS0 (115200)\r\r\n\r\r\nHOST login: ' before (last 100 chars): 'and type "http://"\x1b[0m\r\r\n\r\r\nYou are currently connected via: ttyS0 (115200)\r\r\n\r\r\nHOST login: ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus:
None flag_eof: False pid: 6170 child_fd: 10 closed: False timeout: 900 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: <lava_dispatcher.shell.ShellLogger object at 0x7fc3f188d190> logfile_send: <lava_dispatcher.shell.ShellLogger object
at 0x7fc3ec48bb10> maxread: 2000 ignorecase: False searchwindowsize: 4000 delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 1.0 searcher: searcher_re: 0: re.compile('Linux version [0-9]') During handling of the above exception, another exception
occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 301, in wait return self.raw_connection.expect(self.prompt_str, timeout=timeout) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 178, in expect raise TestError("ShellCommand command timed out.") lava_common.exceptions.TestError: ShellCommand command timed out. During handling of the above exception, another exception
occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/job.py", line 239, in run self._run() File "/usr/lib/python3/dist-packages/lava_dispatcher/job.py", line 229, in _run self.pipeline.run_actions(self.connection,
max_end_time) File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 249, in run_actions new_connection = action.run(connection, action_max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/logical.py",
line 62, in run connection = self.pipeline.run_actions(connection, max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 249, in run_actions new_connection
= action.run(connection, action_max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/actions/boot/__init__.py", line 328, in run res = self.wait(connection) ^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 943, in wait return connection.wait(max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/shell.py", line 303, in wait raise
JobError("wait for prompt timed out") lava_common.exceptions.JobError: wait for prompt timed out During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py",
line 23, in _wrap_ptyprocess_err yield File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py", line 328, in close self.ptyproc.close(force=force) File "/usr/lib/python3/dist-packages/ptyprocess/ptyprocess.py", line 406, in close raise PtyProcessError('Could
not terminate the child.') ptyprocess.util.PtyProcessError: Could not terminate the child. During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py",
line 249, in run_actions new_connection = action.run(connection, action_max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/power.py", line 308, in run feedback[1].finalise()
File "/usr/lib/python3/dist-packages/lava_dispatcher/connections/serial.py", line 246, in finalise self.disconnect("closing") File "/usr/lib/python3/dist-packages/lava_dispatcher/connections/serial.py", line 253, in disconnect super().disconnect(reason)
File "/usr/lib/python3/dist-packages/lava_dispatcher/connection.py", line 153, in disconnect self.raw_connection.close(force=True) File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py", line 325, in close with _wrap_ptyprocess_err(): File "/usr/lib/python3.11/contextlib.py",
line 155, in __exit__ self.gen.throw(typ, value, traceback) File "/usr/lib/python3/dist-packages/pexpect/pty_spawn.py", line 25, in _wrap_ptyprocess_err raise ExceptionPexpect(*e.args) pexpect.exceptions.ExceptionPexpect: Could not terminate the child.
During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3/dist-packages/lava_dispatcher/power.py", line 341, in run connection = super().run(connection, max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py", line 848, in run return self.pipeline.run_actions(connection, max_end_time) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3/dist-packages/lava_dispatcher/action.py",
line 278, in run_actions raise LAVABug(str(exc)) lava_common.exceptions.LAVABug: Could not terminate the child.
Removing root tmp directory at /var/lib/lava/dispatcher/tmp/226
JobError: Your job cannot terminate cleanly.
Thanks,
Sweta
From: Stefan <lists.lavasoftware.org_23@green-sparklet.de>
Sent: Friday, October 25, 2024 1:17 PM
To: lava-users@lists.lavasoftware.org <lava-users@lists.lavasoftware.org>
Subject: [lava-users] Re: Auto login fails after adding banner message before login prompt
[Email from a non-Nagarro source: please exercise caution with links and attachments]
Hey Sweta,
thanks for the longer log, this sheds some more light on the issue - but still isn't enough to debug it.
First regarding the promt which Milosz already mentioned: You set it to "login:" - that most probably is wrong. Linux hosts usually have a prompt something like "username@hostname:" e.g. "root@example:". Please set yaml config to the promt your device really
uses.
Then regarding your logs:
Does the line "[login-action] Waiting for messages, (timeout 00:0x:xx)" appear in logs? I guess yes.
Does the line "Matched prompt #xx: login:" and "Sending username root" appear? At which line? If yes, the login prompt (or something earlier in your banner message) gets matched - and it's not LAVAs fault.
As we can see in your screenshot, your login prompt isn't just "login:" - it is "do[redacted]t login:". Set your yaml config "login_prompt" to this string, this will make detection of that login prompt less error prone.
Regarding your code point question: Just search the code for "login_prompt" and you will find
https://apc01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgitlab.com%2Flava%2Flava%2F-%2Fblob%2Fmaster%2Flava_dispatcher%2Factions%2Fboot%2F__init__.py%23L165&data=05%7C02%7Csweta.ghosh%40nagarro.com%7C3df52bd5f897484a6f6b08dcf4c94588%7Ca45fe71af4804e42ad5eaff33165aa35%7C0%7C0%7C638654392532105400%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C0%7C%7C%7C&sdata=sguGJPh7VUks2vAFa7XXzVZI%2F6CBZRIqCK2bEywRPM0%3D&reserved=0
As far as I can see there's just a time limit and no line limit for detecting the login prompt.
Best regards
Stefan
On 10/25/2024 8:40 AM, Sweta Ghosh wrote:
> Hello Milosz,
>
> Thanks for replying. I tried the changing the prompts by adding strings from welcome messages and login_prompt but it looks like it is not able to reach that point where my login prompt is displayed. My login prompt(circled) is displayed in logs only after
auto-login fails. Please find the screenshot attached. Is there is any limit to number of line it try to match the prompt?
>
> Could you please point me to the code that lava uses to detect the prompt.
> Thanks,
> Sweta
> ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> *From:* Milosz Wasilewski <milosz.wasilewski@foundries.io>
> *Sent:* Thursday, October 24, 2024 1:07 PM
> *To:* Sweta Ghosh <sweta.ghosh@nagarro.com>
> *Cc:* lava-users@lists.lavasoftware.org <lava-users@lists.lavasoftware.org>
> *Subject:* Re: [lava-users] Re: Auto login fails after adding banner message before login prompt
>
> [Email from a non-Nagarro source: please exercise caution with links and attachments]
>
>
> Sweta,
>
>
>
> On Thu, Oct 24, 2024 at 8:12 AM Sweta Ghosh <sweta.ghosh@nagarro.com> wrote:
> >
> > Hello Milosz,
> >
> > I couldn't understand what you mean by " Did you try to change the prompt to sth else?" . Could you please share an example , how can I do the same.
> >
>
> This part:
> > > prompts:
> > > - 'login:'
> >
> > I think this might be your issue. Did you try to change the prompt to sth else?
>
> Try changing the prompt and see if it helps.
>
> Best Regards,
> Milosz
>
> _______________________________________________
> lava-users mailing list -- lava-users@lists.lavasoftware.org
> To unsubscribe send an email to lava-users-leave@lists.lavasoftware.org
> %(web_page_url)slistinfo%(cgiext)s/%(_internal_name)s
_______________________________________________
lava-users mailing list -- lava-users@lists.lavasoftware.org
To unsubscribe send an email to lava-users-leave@lists.lavasoftware.org
%(web_page_url)slistinfo%(cgiext)s/%(_internal_name)s