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)"[cid:1bdaa9d2-2de6-4b9e-92d2-d8c289e454fb] 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] definition: lavahttps://lava.debian.in/results/226/lava/auto-login-action namespace: commonhttps://lava.debian.in/results/226/lava/auto-login-action case: auto-login-actionhttps://lava.debian.in/results/226/lava/auto-login-action level: 2.2https://lava.debian.in/results/226/lava/auto-login-action duration: 722.85https://lava.debian.in/results/226/lava/auto-login-action result: failhttps://lava.debian.in/results/226/lava/auto-login-action extra: ...https://lava.debian.in/results/226/lava/auto-login-action 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] definition: lavahttps://lava.debian.in/results/226/lava/boot-image-retry namespace: commonhttps://lava.debian.in/results/226/lava/boot-image-retry case: boot-image-retryhttps://lava.debian.in/results/226/lava/boot-image-retry level: 2https://lava.debian.in/results/226/lava/boot-image-retry duration: 722.86https://lava.debian.in/results/226/lava/boot-image-retry result: failhttps://lava.debian.in/results/226/lava/boot-image-retry extra: ...https://lava.debian.in/results/226/lava/boot-image-retry 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' 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://%22%5Cx1b%5B0m%5Cr%5Cr%5Cn%5Cr%5Cr%5CnYou are currently connected via: ttyS0 (115200)\r\r\n\r\r\nHOST login: ' before (last 100 chars): 'and type "http://%22%5Cx1b%5B0m%5Cr%5Cr%5Cn%5Cr%5Cr%5CnYou 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] definition: lavahttps://lava.debian.in/results/226/lava/read-feedback namespace: commonhttps://lava.debian.in/results/226/lava/read-feedback case: read-feedbackhttps://lava.debian.in/results/226/lava/read-feedback level: 4.2https://lava.debian.in/results/226/lava/read-feedback duration: 1.70https://lava.debian.in/results/226/lava/read-feedback result: failhttps://lava.debian.in/results/226/lava/read-feedback extra: ...https://lava.debian.in/results/226/lava/read-feedback 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://%22%5Cx1b%5B0m%5Cr%5Cr%5Cn%5Cr%5Cr%5CnYou are currently connected via: ttyS0 (115200)\r\r\n\r\r\nHOST login: ' before (last 100 chars): 'and type "http://%22%5Cx1b%5B0m%5Cr%5Cr%5Cn%5Cr%5Cr%5CnYou 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. definition: lavahttps://lava.debian.in/results/226/lava/job case: jobhttps://lava.debian.in/results/226/lava/job result: failhttps://lava.debian.in/results/226/lava/job error_msg: wait for prompt timed outhttps://lava.debian.in/results/226/lava/job error_type: Jobhttps://lava.debian.in/results/226/lava/job
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...https://gitlab.com/lava/lava/-/blob/master/lava_dispatcher/actions/boot/__init__.py#L165 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
