vJunos-router script fails to authenticate at startup

[jonjacs]

The script that logs into the router after startup to verify its availability occasionally fails to detect the password prompt. As a result, the Docker image is marked as unhealthy, even though it is actually running and functioning correctly.

Docker log for the image:

2025-08-29 11:17:27,171: launch     TRACE    OUTPUT: lag enhanced disabled 0 

2025-08-29 11:17:30,174: launch         INFO VM started
'025-08-29 11:17:30,174: vrnetlab       DEBUG writing to serial console: '
2025-08-29 11:17:30,175: vrnetlab       INFO waiting for 'login:' on serial console
2025-08-29 11:17:30,175: vrnetlab       INFO read from serial console: ' (vmx) (ttyu0)

login:'
2025-08-29 11:17:30,175: vrnetlab       DEBUG writing to serial console: 'admin'
2025-08-29 11:17:30,175: vrnetlab       INFO waiting for 'Password:' on serial console

It never recover from this.

[jonjacs]

Example of a login that works:

2025-08-29 11:16:56,149: launch     TRACE    OUTPUT: 3E JAM Plugin: load succeeded

2025-08-29 11:17:24,181: launch     TRACE    OUTPUT: lag enhanced disabled 0 

2025-08-29 11:17:25,251: launch         INFO VM started
'025-08-29 11:17:25,252: vrnetlab       DEBUG writing to serial console: '
2025-08-29 11:17:25,252: vrnetlab       INFO waiting for 'login:' on serial console
2025-08-29 11:17:25,293: vrnetlab       INFO read from serial console: ' (vr2) (ttyu0)

login:'
2025-08-29 11:17:25,293: vrnetlab       DEBUG writing to serial console: 'admin'
2025-08-29 11:17:25,293: vrnetlab       INFO waiting for 'Password:' on serial console
2025-08-29 11:17:25,394: vrnetlab       INFO read from serial console: ' 



FreeBSD/amd64 (vr2) (ttyu0)

login: admin
Password:'
2025-08-29 11:17:25,395: vrnetlab       DEBUG writing to serial console: 'admin@123'
'025-08-29 11:17:25,395: vrnetlab       DEBUG writing to serial console: '
2025-08-29 11:17:25,395: launch         INFO Login completed
2025-08-29 11:17:25,395: launch         INFO Startup complete in: 0:04:57.605804

[consentfactory]

The script that logs into the router after startup to verify its availability occasionally fails to detect the password prompt. As a result, the Docker image is marked as unhealthy, even though it is actually running and functioning correctly.

Docker log for the image:

2025-08-29 11:17:27,171: launch     TRACE    OUTPUT: lag enhanced disabled 0 

2025-08-29 11:17:30,174: launch         INFO VM started
'025-08-29 11:17:30,174: vrnetlab       DEBUG writing to serial console: '
2025-08-29 11:17:30,175: vrnetlab       INFO waiting for 'login:' on serial console
2025-08-29 11:17:30,175: vrnetlab       INFO read from serial console: ' (vmx) (ttyu0)

login:'
2025-08-29 11:17:30,175: vrnetlab       DEBUG writing to serial console: 'admin'
2025-08-29 11:17:30,175: vrnetlab       INFO waiting for 'Password:' on serial console

It never recover from this.

Maybe this will help you, but I had the same issue with vJunos-switch and I believe this comes from a resource utilization issue. I was using the minimum memory specified in the documentation (5 GB) and was getting inconsistent deployments, with some instances starting and others not.

https://www.juniper.net/documentation/us/en/software/vJunos/vjunos-switch-deployment-guide-for-kvm/vJunos-switch-kvm/topics/vJunos-switch-kvm-hw-requirements.html

However, once I bumped it up to 8 GB I had no issues. Also, because I'm committing my host, I'm doing staged deployment and I think that with the memory upgrade resolved the issue.

https://containerlab.dev/manual/nodes/#stages

Now it takes about 6-8 minutes for 4 instances to pop up.

[jonjacs]

Do you mean the main memory in the server? Or do I specify the ram dedicated to the docker images?

As mentioned, the images boots ok and the images where the startup script fails to login still works as they should. So I do not think there is a problem with the server's resources. I have the same issue now and then if I only start a single container too.

[consentfactory]

Definitely talking about the memory allocation for the VM/images, not your server. I don't think the bare minimum of 5GB results in consistent experiences.

Are you able to open a shell and execute login commands after the image boots? If you are, then this suggests there is something wrong with the login script, but if you can't execute commands from the shell than this indicates your VM/container has stalled out (which is exactly the experience I was having).

From a partner Slack huddle, the team that handles virtual/container images noted the following for the vJunos image:

This suggests to me that the vCP doesn't always load consistently with only 5 GB of memory for the VM/container, which is why I'm thinking its a memory allocation issue. The image is a nested hot mess because its running KVM within the image already.

From the same huddle:

Another note: I'm having weird issues with the 25.x image and finding better performance/experience on 24.4.

[jonjacs]

As mentioned, "as a result, the Docker image is marked as unhealthy, even though it is actually running and functioning correctly". The machines can be used as they should when they have booted. I can login and execute commands, configure them and do labs. So that is no issue.

The issue is only that the startup-script sometimes cannot verify that the image has booted and set the health status as "healthy".

[consentfactory]

As mentioned, "as a result, the Docker image is marked as unhealthy, even though it is actually running and functioning correctly". The machines can be used as they should when they have booted. I can login and execute commands, configure them and do labs. So that is no issue.

That's my bad for not reading that section. My apologies.

[dviske]

I've debugged this a bit and found that this is because there's some extra (seemingly error/debug output) from Junos after booting sometimes:

FreeBSD/amd64 (mpls_c) (ttyu0)

login: kernel.core_pattern = /var/crash/core.%e.%t.%p.gz
/var/jnx/card/local/type file not found
i2cid is: 2986 /var/jnx/card/local/slot file not found
slot:  0
upgrade_skip:  1
parent: 2056, child: 2060
Spawning mpcsd with PID 2060
grep: /etc/riot/runtime.conf: No such file or directory
sh: /usr/share/pfe/set_fips_optest.sh: No such file or directory
fpc.core.push.sh: no process found

I have a working fix but I'm currently testing to make sure it's actually working correctly and not just false positive-ing.

[dviske]

I'm not putting this in a PR since it's very hacky at the moment and I'm not familiar enough with the codebase to know if assuming the console mode will always be self.tn is safe if it's just for this type of device.

Replacing juniper/vjunosrouter/docker/launch.py's bootstrap_spin function with this reliably solved the issue in my environment. This could theoretically also be applied to vjunosswitch

import time
# Add the time import at the top for time.sleep

    def bootstrap_spin(self):
        """This function should be called periodically to do work."""
        if self.spins > 300:
            # too many spins with no result ->  give up
            self.stop()
            self.start()
            return

        # lets wait for the OS/platform log to determine if VM is booted,
        # login prompt can get lost in boot logs
        (ridx, match, res) = self.tn.expect([b"FreeBSD/amd64"], 1)
        if match:  # got a match!
            if ridx == 0:  # login
                self.logger.info("VM started")

                if self.use_scrapli:
                    # Login
                    self.wait_write("\r", None)
                    self.wait_write("admin", wait="login:")
                    self.wait_write(self.password, wait="Password:")
                    self.wait_write("\r", None)

                    self.logger.info("Login completed")
                else:
                    try:
                        # Clear any pending output.
                        pending = self.tn.read_very_eager()
                    except:
                        pass

                    self.logger.info("Sending login credentials...")
                    self.tn.write(b"\r\r")
                    time.sleep(1)
                    self.tn.write(f"{self.username}\r".encode())
                    time.sleep(2)
                    self.tn.write(f"{self.password}\r".encode())
                    time.sleep(3)

                    # Read the login response
                    try:
                        response = self.tn.read_very_eager()
                        response_str = response.decode(errors='replace')

                        # Check for success indicators (success before failure)
                        if "--- JUNOS" in response_str or "JUNOS" in response_str:
                            self.logger.info("Successfully logged in - detected JUNOS banner")
                        elif ("@" in response_str and ">" in response_str) or ("@" in response_str and "#" in response_str):
                            self.logger.info("Successfully logged in - detected Juniper prompt")
                        elif any(line.strip().endswith(prompt) for line in response_str.split('\n') for prompt in ['%', '$', '#']):
                            self.logger.info("Successfully logged in - detected shell prompt")
                        elif "login incorrect" in response_str.lower():
                            self.logger.error("Login failed - incorrect credentials")
                            return
                        else:
                            self.logger.warning(f"Unexpected login response: {response_str}")
                            return

                    except Exception as e:
                        self.logger.error(f"Error reading login response: {e}")
                        return

                    self.logger.info("Login sequence completed successfully")

                # close telnet connection
                self.tn.close()
                # startup time?
                startup_time = datetime.datetime.now() - self.start_time
                self.logger.info("Startup complete in: %s" % startup_time)
                # mark as running
                self.running = True
                return

        # no match, if we saw some output from the router it's probably
        # booting, so let's give it some more time
        if res != b"":
            self.logger.trace("OUTPUT: %s" % res.decode())
            # reset spins if we saw some output
            self.spins = 0

        self.spins += 1

        return