hellt / vrnetlab

Make VM-based Network OSes run in Containerlab
https://containerlab.dev
MIT License
124 stars 85 forks source link

vMX vFP failed to boot #63

Closed vireakouk closed 2 years ago

vireakouk commented 3 years ago

hello all, I have followed the instruction of building the image for vmx. I wonder if I missed any step. I got vmx vCP boot up fine, but can't seems to get vFPC booted up. Any help would be greatly appreciated. I'm using Ubuntu 20.04 vm on a virtualbox with nested virtualization.

admin@vmx> show interfaces ge-0/0/0
error: device ge-0/0/0 not found

admin@vmx>
admin@vmx> ping 128.0.0.16 routing-instance __juniper_private1__
PING 128.0.0.16 (128.0.0.16): 56 data bytes
ping: sendto: No route to host
ping: sendto: No route to host
ping: sendto: No route to host
ping: sendto: No route to host
^C
--- 128.0.0.16 ping statistics ---
4 packets transmitted, 0 packets received, 100% packet loss

Thanks.

hellt commented 3 years ago

Hi @vireakouk quite likely something went wrong during the installation step

when you do make for your vmx image it first undergoes the installation step where the image boots first and does some steps. Then it shuts down and vrnetlab commits the image which you later use to run.

So I assume something went wrong during the installation, maybe installation logs which are outputted to the console may reveal the issue

vireakouk commented 3 years ago

Hi Roman, Thanks for your response. I attach the installation log. Some steps 4 to 6 appears to be missing. The image I downloaded from Juniper official site vMX KVM image. I tried the same version vmx-bundle-20.2R1.10.tgz that was successfully tested in the README file.

installation_log.txt

hellt commented 3 years ago

@vireakouk

I just tested the following lab on my machine and it works

name: vmx

topology:
  nodes:
    srl:
      kind: srl
      image: ghcr.io/nokia/srlinux
    vmx:
      kind: vr-vmx
      image: registry.srlinux.dev/pub/vr-vmx:20.4R1.12

  links:
    - endpoints: ["srl:e1-1", "vmx:eth1"]

Do check that the lab that you deployed had the endpoints section with at least one interface for vmx.

admin@vmx> show interfaces ge-0/0/0 
Physical interface: ge-0/0/0, Enabled, Physical link is Up
  Interface index: 149, SNMP ifIndex: 527
  Link-level type: Ethernet, MTU: 1514, MRU: 1522, LAN-PHY mode,
  Speed: 1000mbps, BPDU Error: None, Loop Detect PDU Error: None,
  Ethernet-Switching Error: None, MAC-REWRITE Error: None,
  Loopback: Disabled, Source filtering: Disabled,
  Flow control: Enabled, Auto-negotiation: Enabled,
  Remote fault: Online
  Pad to minimum frame size: Disabled
  Device flags   : Present Running
  Interface flags: SNMP-Traps Internal: 0x4000
  Link flags     : None
  CoS queues     : 8 supported, 8 maximum usable queues
  Current address: 52:54:00:88:7c:01, Hardware address: 52:54:00:88:7c:01
  Last flapped   : 2021-09-24 07:21:45 UTC (00:37:53 ago)
  Input rate     : 0 bps (0 pps)
  Output rate    : 0 bps (0 pps)        
  Active alarms  : None
  Active defects : None
  PCS statistics                      Seconds
    Bit errors                             0
    Errored blocks                         0
  Ethernet FEC statistics              Errors
    FEC Corrected Errors                    0
    FEC Uncorrected Errors                  0
    FEC Corrected Errors Rate               0
    FEC Uncorrected Errors Rate             0
  Interface transmit statistics: Disabled

  Logical interface ge-0/0/0.16386 (Index 332) (SNMP ifIndex 548)
    Flags: Up SNMP-Traps 0x4004000 Encapsulation: ENET2
    Input packets : 2
    Output packets: 0

here is my log of the vmx node of this lab

❯ docker logs -f clab-vmx-vmx
2021-09-24 07:09:26,380: launch     DEBUG    acting flags: username 'admin', password 'admin@123', install 'False', connection-mode 'tc'
2021-09-24 07:09:26,380: launch     DEBUG    Environment variables: environ({'PATH': '/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'HOSTNAME': 'vmx', 'TERM': 'xterm', 'CONNECTION_MODE': 'tc', 'DOCKER_NET_V4_ADDR': '172.20.20.0/24', 'CLAB_INTFS': '1', 'DOCKER_NET_V6_ADDR': '2001:172:20:20::/64', 'USERNAME': 'admin', 'PASSWORD': 'admin@123', 'DEBIAN_FRONTEND': 'noninteractive', 'HOME': '/root', 'LC_CTYPE': 'C.UTF-8'})
2021-09-24 07:09:26,382: vrnetlab   DEBUG    Creating overlay disk image
2021-09-24 07:09:26,449: vrnetlab   DEBUG    Creating overlay disk image
2021-09-24 07:09:26,488: vrnetlab   DEBUG    Starting vrnetlab VMX
2021-09-24 07:09:26,489: vrnetlab   DEBUG    VMs: [<__main__.VMX_vcp object at 0x7f874b855880>, <__main__.VMX_vfpc object at 0x7f874b855b20>]
2021-09-24 07:09:26,496: vrnetlab   DEBUG    VM not started; starting!
2021-09-24 07:09:26,496: vrnetlab   INFO     Starting VMX_vcp
2021-09-24 07:09:26,497: vrnetlab   DEBUG    ['qemu-system-x86_64', '-enable-kvm', '-display', 'none', '-machine', 'pc', '-monitor', 'tcp:0.0.0.0:4000,server,nowait', '-m', '2048', '-serial', 'telnet:0.0.0.0:5000,server,nowait', '-drive', 'if=ide,file=/vmx/junos-vmx-x86-64-20.4R1.12-overlay-overlay.qcow2', '-drive', 'if=ide,file=/vmx/vmxhdd.img', '-usb', '-drive', 'id=my_usb_disk,media=disk,format=raw,file=/vmx/metadata-usb-re.img,if=none', '-device', 'usb-storage,drive=my_usb_disk', '-smbios', '"type=0,vendor=Juniper"', '-smbios', '"type=1,manufacturer=VMX,product=VM-vcp_vmx2-161-re-0,version=0.1.0"', '-device', 'e1000,netdev=p00,mac=52:54:00:ac:e7:00', '-netdev', 'user,id=p00,net=10.0.0.0/24,tftp=/tftpboot,hostfwd=tcp::2022-10.0.0.15:22,hostfwd=udp::2161-10.0.0.15:161,hostfwd=tcp::2830-10.0.0.15:830,hostfwd=tcp::2080-10.0.0.15:80,hostfwd=tcp::2443-10.0.0.15:443,hostfwd=tcp::17400-10.0.0.15:57400', '-device', 'virtio-net-pci,netdev=vcp-int,mac=52:54:00:59:13:01', '-netdev', 'tap,ifname=vcp-int,id=vcp-int,script=no,downscript=no']
2021-09-24 07:09:26,497: vrnetlab   DEBUG    joined cmd: qemu-system-x86_64 -enable-kvm -display none -machine pc -monitor tcp:0.0.0.0:4000,server,nowait -m 2048 -serial telnet:0.0.0.0:5000,server,nowait -drive if=ide,file=/vmx/junos-vmx-x86-64-20.4R1.12-overlay-overlay.qcow2 -drive if=ide,file=/vmx/vmxhdd.img -usb -drive id=my_usb_disk,media=disk,format=raw,file=/vmx/metadata-usb-re.img,if=none -device usb-storage,drive=my_usb_disk -smbios "type=0,vendor=Juniper" -smbios

Booting from Junos volume ...
/
2021-09-24 07:09:32,521: vrnetlab   DEBUG    VM not started; starting!
2021-09-24 07:09:32,521: vrnetlab   INFO     Starting VMX_vfpc
2021-09-24 07:09:32,523: vrnetlab   DEBUG    ['qemu-system-x86_64', '-enable-kvm', '-display', 'none', '-machine', 'pc', '-monitor', 'tcp:0.0.0.0:4001,server,nowait', '-m', '4096', '-serial', 'telnet:0.0.0.0:5001,server,nowait', '-drive', 'if=ide,file=/vmx/vfpc-overlay.img', '-cpu', 'SandyBridge', '-M', 'pc', '-smp', '3', '-usb', '-drive', 'id=fpc_usb_disk,media=disk,format=raw,file=/vmx/metadata-usb-fpc0.img,if=none', '-device', 'usb-storage,drive=fpc_usb_disk', '-device', 'pci-bridge,chassis_nr=1,id=pci.1', '-device', 'pci-bridge,chassis_nr=2,id=pci.2', '-device', 'pci-bridge,chassis_nr=3,id=pci.3', '-device', 'pci-bridge,chassis_nr=4,id=pci.4', '-device', 'virtio-net-pci,netdev=mgmt,mac=52:54:00:f3:e1:00', '-netdev', 'user,id=mgmt,net=10.0.0.0/24', '-device', 'virtio-net-pci,netdev=vfpc-int,mac=52:54:00:a2:e6:00', '-netdev', 'tap,ifname=vfpc-int,id=vfpc-int,script=no,downscript=no', '-device', 'virtio-net-pci,netdev=dummy,mac=52:54:00:6b:e3:00', '-netdev', 'tap,ifname=vfpc-dummy,id=dummy,script=no,downscript=no', '-device', 'virtio-net-pci,netdev=p01,mac=52:54:00:88:7c:01,bus=pci.1,addr=0x2', '-netdev', 'tap,id=p01,ifname=tap1,script=/etc/tc-tap-ifup,downscript=no']
2021-09-24 07:09:32,524: vrnetlab   DEBUG    joined cmd: qemu-system-x86_64 -enable-kvm -display none -machine pc -monitor tcp:0.0.0.0:4001,server,nowait -m 4096 -serial telnet:0.0.0.0:5001,server,nowait -drive if=ide,file=/vmx/vfpc-overlay.img -cpu SandyBridge -M pc -smp 3 -usb -drive id=fpc_usb_disk,media=disk,format=raw,file=/vmx/metadata-usb-fpc0.img,if=none -device usb-storage,drive=fpc_usb_disk -device pci-bridge,chassis_nr=1,id=pci.1 -device pci-bridge,chassis_nr=2,id=pci.2 -device pci-bridge,chassis_nr=3,id=pci.3 -device pci-bridge,chassis_nr=4,id=pci.4 -device virtio-net-pci,netdev=mgmt,mac=52:54:00:f3:e1:00 -netdev user,id=mgmt,net=10.0.0.0/24 -device virtio-net-pci,netdev=vfpc-int,mac=52:54:00:a2:e6:00 -netdev tap,ifname=vfpc-int,id=vfpc-int,script=no,downscript=no -device virtio-net-pci,netdev=dummy,mac=52:54:00:6b:e3:00 -netdev tap,ifname=vfpc-dummy,id=dummy,script=no,downscript=no -device virtio-net-pci,netdev=p01,mac=52:54:00:88:7c:01,bus=pci.1,addr=0x2 -netdev tap,id=p01,ifname=tap1,script=/etc/tc-tap-ifup,downscript=no
2021-09-24 07:09:40,540: launch     TRACE    OUTPUT VCP: Verified /boot/manifest signed by PackageProductionECP256_2020
Verified /boot/loader.rc
Verified /boot/support.4th
Verified /boot/load-dtb.4th
Verified /boot/platform.4th
Verified /boot/platform-load-dtb.4th
|
Verified /packages/sets/active/boot/os-kernel/../manifest signed by PackageProductionECP256_2020
Verified /packages/sets/active/boot/os-crypto/../manifest signed by PackageProductionECP256_2020
\
2021-09-24 07:09:44,548: launch     TRACE    OUTPUT VCP: Verified /packages/sets/active/boot/netstack/../manifest signed by PackageProductionECP256_2020
Verified /packages/sets/active/boot/netstack/init.4th
Verified /packages/sets/active/boot/junos-net-platform/../manifest signed by PackageProductionECP256_2020
\
2021-09-24 07:09:48,552: launch     TRACE    OUTPUT VCP: Verified /packages/sets/active/boot/junos-modules/../manifest signed by PackageProductionECP256_2020
Verified /packages/sets/active/boot/junos-modules/init.4th
|
2021-09-24 07:09:52,555: launch     TRACE    OUTPUT VCP: Verified /packages/sets/active/boot/junos-modules-platform/../manifest signed by PackageProductionECP256_2020
Verified /packages/sets/active/boot/os-vmguest/../manifest signed by PackageProductionECP256_2020
Verified /packages/sets/active/boot/os-vmguest/init.4th
/
2021-09-24 07:09:56,560: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:09:57,579: launch     INFO     vFPC successfully started
2021-09-24 07:09:59,582: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:10:02,586: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:10:05,589: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:10:08,593: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:10:11,596: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:10:14,600: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:10:17,604: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:10:20,608: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:10:23,612: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/kernel text=0x470a68 /
2021-09-24 07:10:26,614: launch     TRACE    OUTPUT VCP: data=0x84cf8+0x30d0a8 syms=[0x8+0x98778+0x8+0x84bc8]
Verified /packages/sets/active/boot/os-kernel/kernel
-
2021-09-24 07:10:29,618: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:10:32,622: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/contents.izo 
2021-09-24 07:10:35,625: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:10:38,628: launch     TRACE    OUTPUT VCP: size=0x8b8400
Verified /packages/sets/active/boot/os-kernel/contents.izo
/
2021-09-24 07:10:41,631: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:10:44,634: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:10:47,637: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/miibus.ko size 0x3fc08 at 0x15d9000
Verified /packages/sets/active/boot/os-kernel/miibus.ko
loading required module 'netstack'
/
2021-09-24 07:10:50,641: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:10:53,645: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:10:56,648: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:10:59,649: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/netstack/netstack.ko -
2021-09-24 07:11:02,653: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:11:05,657: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:11:08,661: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:11:11,664: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:11:14,667: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:11:17,671: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:11:20,674: launch     TRACE    OUTPUT VCP: size 0x170bf90 at 0x1619000
Verified /packages/sets/active/boot/netstack/netstack.ko
loading required module 'crypto'
-
2021-09-24 07:11:23,676: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:11:26,679: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:11:29,683: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:11:32,686: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:11:35,689: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-crypto/crypto.ko size 0x43e28 at 0x2d25000
Verified /packages/sets/active/boot/os-crypto/crypto.ko
/packages/sets/active
2021-09-24 07:11:38,691: launch     TRACE    OUTPUT VCP: /boot/os-kernel/coretemp.ko size 0x4ed8 at 0x2d69000
Verified /packages/sets/active/boot/os-kernel/coretemp.ko
/packages/sets/active/boot/os-kernel/ichwd.ko size 0x7d90 at 0x2d6e000
Verified /packages/sets/active/boot/os-kernel/ichwd.ko
|
2021-09-24 07:11:41,695: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/if_em.ko size 0x7f858 at 0x2d76000
Verified /packages/sets/active/boot/os-kernel/if_em.ko
/packages/sets/active/boot/os-kernel/if_fxp.ko size 0x13668 at 0x2df6000
Verified /packages/sets/active/boot/os-kernel/if_fxp.ko
-
2021-09-24 07:11:44,697: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/if_igb.ko size 0x6b888 at 0x2e0a000
Verified /packages/sets/active/boot/os-kernel/if_igb.ko
\
2021-09-24 07:11:47,700: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/if_ixlv1211k.ko size 0x34050 at 0x2e76000
Verified /packages/sets/active/boot/os-kernel/if_ixlv1211k.ko
/packages/sets/active/boot/os-kernel/ismt.ko size 0x6968 at 0x2eab000
Verified /packages/sets/active/boot/os-kernel/ismt.ko
loading required module 'smbus'
\
2021-09-24 07:11:50,703: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:11:53,707: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:11:56,711: launch     TRACE    OUTPUT VCP: /
2021-09-24 07:11:59,714: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:12:02,717: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:12:05,721: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/smbus.ko size 0x3320 at 0x2eb2000
Verified /packages/sets/active/boot/os-kernel/smbus.ko
\
2021-09-24 07:12:08,724: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-kernel/smb.ko size 0x51b0 at 0x2eb6000
Verified /packages/sets/active/boot/os-kernel/smb.ko
-
2021-09-24 07:12:11,728: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/netstack/acb.ko size 0x6f5f0 at 0x2ebc000
Verified /packages/sets/active/boot/netstack/acb.ko
loading required module 'mtx_re'
-
2021-09-24 07:12:14,731: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:12:17,733: launch     TRACE    OUTPUT VCP: \
2021-09-24 07:12:20,736: launch     TRACE    OUTPUT VCP: -
2021-09-24 07:12:23,739: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-net-platform/mtx_re.ko size 0x2e1f28 at 0x2f2c000
Verified /packages/sets/active/boot/junos-net-platform/mtx_re.ko
loading required module 'pvi_db'
\
2021-09-24 07:12:26,742: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:12:29,744: launch     TRACE    OUTPUT VCP: |
2021-09-24 07:12:32,748: launch     TRACE    OUTPUT VCP:-
2021-09-24 07:12:35,751: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/netstack/pvi_db.ko size 0x68e0 at 0x320e000
Verified /packages/sets/active/boot/netstack/pvi_db.ko
\
2021-09-24 07:12:38,755: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/netstack/ptxfabsw.ko size 0x6228 at 0x3215000
Verified /packages/sets/active/boot/netstack/ptxfabsw.ko
-
2021-09-24 07:12:41,759: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules/fips_core.ko size 0x62d8 at 0x321c000
Verified /packages/sets/active/boot/junos-modules/fips_core.ko
\
2021-09-24 07:12:44,762: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules/hmac_drbg.ko size 0x9530 at 0x3223000
Verified /packages/sets/active/boot/junos-modules/hmac_drbg.ko
/
2021-09-24 07:12:47,764: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules/random_dyce.ko size 0x70b8 at 0x322d000
Verified /packages/sets/active/boot/junos-modules/random_dyce.ko
/packages/sets/active/boot/junos-modules/mac_sdk.ko size 0x12fb8 at 0x3235000
Verified /packages/sets/active/boot/junos-modules/mac_sdk.ko
/
2021-09-24 07:12:50,768: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules/sdk_core.ko size 0x26438 at 0x3248000
Verified /packages/sets/active/boot/junos-modules/sdk_core.ko
-
2021-09-24 07:12:53,771: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules/junosprocfs.ko size 0x5858 at 0x326f000
Verified /packages/sets/active/boot/junos-modules/junosprocfs.ko
|
2021-09-24 07:12:56,774: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules/mac_fips.ko size 0x57a8 at 0x3275000
Verified /packages/sets/active/boot/junos-modules/mac_fips.ko
/packages/sets/active/boot/junos-modules-platform/fxpci.ko size 0xca50 at 0x327b000
Verified /packages/sets/active/boot/junos-modules-platform/fxpci.ko
-
2021-09-24 07:12:59,776: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/junos-modules-platform/pcidev.ko size 0x8318 at 0x3288000
Verified /packages/sets/active/boot/junos-modules-platform/pcidev.ko
-
2021-09-24 07:13:02,779: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-vmguest/virtio.ko size 0x58b8 at 0x3291000
Verified /packages/sets/active/boot/os-vmguest/virtio.ko
/packages/sets/active/boot/os-vmguest/virtio_blk.ko size 0x7c68 at 0x3297000
Verified /packages/sets/active/boot/os-vmguest/virtio_blk.ko
-
2021-09-24 07:13:05,782: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-vmguest/virtio_pci.ko size 0x7318 at 0x329f000
Verified /packages/sets/active/boot/os-vmguest/virtio_pci.ko
/packages/sets/active/boot/os-vmguest/virtio_random.ko size 0x28b8 at 0x32a7000
Verified /packages/sets/active/boot/os-vmguest/virtio_random.ko
-
2021-09-24 07:13:08,785: launch     TRACE    OUTPUT VCP:/packages/sets/active/boot/os-vmguest/virtio_scsi.ko size 0xc760 at 0x32aa000
Verified /packages/sets/active/boot/os-vmguest/virtio_scsi.ko
|
2021-09-24 07:13:11,788: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-vmguest/virtio_9pnet.ko size 0xfbf0 at 0x32b7000
Verified /packages/sets/active/boot/os-vmguest/virtio_9pnet.ko
/packages/sets/active/boot/os-vmguest/virtio_9pfs.ko size 0x109c0 at 0x32c7000
Verified /packages/sets/active/boot/os-vmguest/virtio_9pfs.ko
-
2021-09-24 07:13:14,791: launch     TRACE    OUTPUT VCP: /packages/sets/active/boot/os-vmguest/if_vtnet.ko size 0x13488 at 0x32d8000
Verified /packages/sets/active/boot/os-vmguest/if_vtnet.ko
/packages/sets/active/boot/os-vmguest/if_vmx.ko size 0x121f8 at 0x32ec000
Verified /packages/sets/active/boot/os-vmguest/if_vmx.ko
Booting [/packages/sets/active/boot/os-kernel/kernel]...               

2021-09-24 07:13:17,794: launch     TRACE    OUTPUT VCP: GDB: debug ports: uart
GDB: current port: uart
KDB: debugger backends: ddb gdb ndb
KDB: current backend: ddb
Copyright (c) 1992-2017 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
        The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD JNPR-11.0-20201028.e1cef1d_builder_stable_11 #0 r356482+e1cef1de378(HEAD): Wed Oct 28 10:27:16 PDT 2020
    builder@feyrith.juniper.net:/volume/build/junos/occam/llvm-5.0/sandbox-20201009/freebsd/stable_11/20201009.192557_builder_stable_11.e1cef1d/obj/amd64/juniper/kernels/JNPR-AMD64-PRD/kernel amd64
Juniper clang version 5.0.2  (based on LLVM 5.0.2)
VT(vga): text 80x25

2021-09-24 07:13:20,798: launch     TRACE    OUTPUT VCP: CPU: QEMU Virtual CPU version 2.5+ (2394.67-MHz K8-class CPU)
  Origin="GenuineIntel"  Id=0x663  Family=0x6  Model=0x6  Stepping=3
  Features=0x783fbfd<FPU,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,MMX,FXSR,SSE,SSE2>
  Features2=0x80202001<SSE3,CX16,x2APIC,HV>
  AMD Features=0x20100800<SYSCALL,NX,LM>
  AMD Features2=0x1<LAHF>
  TSC: P-state invariant
Hypervisor: Origin = "KVMKVMKVM"
real memory  = 2147483648 (2048 MB)
avail memory = 2021408768 (1927 MB)
Event timer "LAPIC" quality 100
ACPI APIC Table: <BOCHS  BXPCAPIC>
mtx_platform_early_bootinit: M/T/EX/SRX Series Early Boot Initialization
mtx_platform_set_vm_retype: sysinfo_product=VM-vcp_vmx2-161-re-0
mtx_platform_set_re_type: vm_retype :RE-VMX
mtx_platform_set_re_type: Found RE type 160 RE-VMX
random: entropy device external interface
random: <Fortuna> initialized
Security policy loaded: MAC/veriexec (mac_veriexec)
Security policy loaded: Junos MAC/SDK (mac_sdk)
Security policy loaded: JUNOS MAC/privcheck (mac_privcheck)
Security policy loaded: Junos MAC/fips (mac_fips)
MAC/veriexec fingerprint module loaded: SHA256
MAC/veriexec fingerprint module loaded: SHA384
2021-09-24 07:13:23,801: launch     TRACE    OUTPUT VCP: 
MAC/veriexec fingerprint module loaded: SHA1
ioapic0 <Version 1.1> irqs 0-23 on motherboard
netisr_init: forcing maxthreads from 4 to 1
Creating PCI Scan thread
pcidev module loaded, 0 (null)
Initializing M/T/EX platform properties ..
nexus0
vtvga0: <VT VGA driver> on motherboard
cryptosoft0: <software crypto> on motherboard
acpi0: <BOCHS BXPCRSDT> on motherboard
acpi0: Power Button (fixed)
cpu0: <ACPI CPU> on acpi0
atrtc0: <AT realtime clock> port 0x70-0x71,0x72-0x77 irq 8 on acpi0
atrtc0: registered as a time-of-day clock, resolution 1.000000s
Event timer "RTC" frequency 32768 Hz quality 0
hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
Timecounter "HPET" frequency 100000000 Hz quality 950
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x608-0x60b on acpi0
2021-09-24 07:13:26,804: launch     TRACE    OUTPUT VCP: 
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
pci0: <ACPI PCI bus> on pcib0
isab0: <PCI-ISA bridge> at device 1.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <Intel PIIX3 WDMA2 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xc080-0xc08f at device 1.1 on pci0
ata0: <ATA channel> at channel 0 on atapci0
ata1: <ATA channel> at channel 1 on atapci0
uhci0: <Intel 82371SB (PIIX3) USB controller> port 0xc040-0xc05f irq 11 at device 1.2 on pci0
usbus0 on uhci0
smb0: <Intel 82371AB SMB controller> irq 9 at device 1.3 on pci0
vgapci0: <VGA-compatible display> mem 0xfd000000-0xfdffffff,0xfebb0000-0xfebb0fff at device 2.0 on pci0
vgapci0: Boot video device
em0: <Intel(R) PRO/1000 Legacy Network Connection 1.1.0> port 0xc000-0xc03f mem 0xfeb80000-0xfeb9ffff irq 11 at device 3.0 on pci0
if_initname: em

2021-09-24 07:13:29,807: launch     TRACE    OUTPUT VCP: virtio_pci0: <VirtIO PCI Network adapter> port 0xc060-0xc07f mem 0xfebb1000-0xfebb1fff,0xfe000000-0xfe003fff irq 11 at device 4.0 on pci0
vtnet0: <VirtIO Networking Adapter> on virtio_pci0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
atkbd0: [GIANT-LOCKED]
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 on acpi0
uart0: console (9600,n,8,1)
uart0: [GIANT-LOCKED]
orm0: <ISA Option ROM> at iomem 0xe9800-0xeffff on isa0
jnx_product_set_vplatform: vchassis_type is 161
VPlatform: Setting product model to unknown for product type 161 
virtual chassis member-id = 255
virtual chassis mode      = 0
virtual chassis fpc-slots = 255
virtual chassis effective fpc-slots = 12
virtual chassis ifstate revert      = 1
Initializing Kernel PVIDB.
Unified Services mode is turned off(0)
Initializing product: 161 ..
pfe_peer_smp_chk_product_supp: jnx_product_type: 161 mp_ncpus: 1 rts_shared_bitvector_ifstate_infra: 0 jpf_tcp_ppt_ifs_smp_support: 0 support: 0
2021-09-24 07:13:32,810: launch     TRACE    OUTPUT VCP: 
rts_ifstate_chk_product_supp: jnx_product_type: 161 mp_ncpus: 1 rts_shared_bitvector_ifstate_infra: 0 jpf_tcp_ppt_ifs_smp_support: 0 support: 0
Setting up M/T interface operations and attributes
platform_set_re_misc_properties_common: vm_guest=5
platform_set_re_misc_properties_common: vm_retype: 'RE-VMX'
platform_set_re_misc_properties_common: renaming em0 -> fxp0
JUNOS procfs is initialized.
Timecounters tick every 1.000 msec
md0: Preloaded image </packages/sets/active/boot/os-kernel/contents.izo> 9143296 bytes at 0xffffffff80d200f0
tcp_ip_smp_supp_chk_product: jnx_product_type: 161 support: 0 
Registering tcp_platform_dependent = tcp_handle_special_ports
usbus0: 12Mbps Full Speed USB v1.0
ugen0.1: <Intel UHCI root HUB> at usbus0
uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0

2021-09-24 07:13:35,813: launch     TRACE    OUTPUT VCP: ada0 at ata0 bus 0 scbus0 target 0 lun 0
cd0 at ata1 bus 0 scbus1 target 0 lun 0
uhub0: 2 ports with 2 removable, self powered
cd0: <QEMU QEMU DVD-ROM 2.5+> Removable CD-ROM SCSI device
cd0: Serial Number QM00003
cd0: 16.700MB/s transfers (WDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present
ada0: <QEMU HARDDISK 2.5+> ATA-7 device
ada0: Serial Number QM00001
ada0: 16.700MB/s transfers (WDMA2, PIO 8192bytes)
ada0: 27649MB (56625152 512 byte sectors)
ada1 at ata0 bus 0 scbus0 target 1 lun 0
ada1: <QEMU HARDDISK 2.5+> ATA-7 device
ada1: Serial Number QM00002
ada1: 16.700MB/s transfers (WDMA2, PIO 8192bytes)
ada1: 8192MB (16777216 512 byte sectors)
Timecounter "TSC-low" frequency 1197334195 Hz quality 1000
Trying to mount root from cd9660:/dev/md0.uzip []...

2021-09-24 07:13:38,818: launch     TRACE    OUTPUT VCP: ugen0.2: <QEMU QEMU USB HARDDRIVE> at usbus0
umass0 on uhub0
umass0: <QEMU QEMU USB HARDDRIVE, class 0/0, rev 2.00/0.00, addr 2> on usbus0
da0 at umass-sim0 bus 0 scbus2 target 0 lun 0
da0: <QEMU QEMU HARDDISK 2.5+> Fixed Direct Access SPC-3 SCSI device
da0: Serial Number 1-00000001.2-1
da0: 1.000MB/s transfers
da0: 10MB (20480 512 byte sectors)
da0: quirks=0x2<NO_6_BYTE>

2021-09-24 07:14:35,886: launch     TRACE    OUTPUT VCP: random: unblocking device.

2021-09-24 07:17:45,106: launch     TRACE    OUTPUT VCP: Loading JUNOS chassis module
chassis_init_hw_chassis_startup_time: chassis startup time 0.000000, shared: 0x7ffffffff300, base: 0x7ffffffff000, offset: 0x300
IPsec: Initialized Security Association Processing.

2021-09-24 07:17:48,111: launch     TRACE    OUTPUT VCP: fuse-freebsd: version 0.4.4, FUSE ABI 7.8

pci-hgcomdev module loadedLoading the CHMIC module
Loading POS driver
 Loading Aggregate sonet driver
Loading the IMA Group Media Layer; Attaching to media services layer
Loading the IMA Link Media Layer; Attaching to media services layer
Loading the SONET Media Layer; Attaching to media services layer
Loading the Protobuf-C module
Loading the JAM-Core module
Loading the JAM-Core module - succeeded
Loading Multilink Services PICs module.
Loading the M&T Platform NETPFE module
MTX Platform JAM-Core module - load success
MPC NG 2E/3E JAM Plugin: load succeeded

2021-09-24 07:17:51,115: launch     TRACE    OUTPUT VCP: Timecounter "KVMCLOCK" frequency 1000000000 Hz quality 2000

2021-09-24 07:18:15,141: launch     TRACE    OUTPUT VCP: Failed to rename ... 
        old_ifname to jnx_re_host_ifd_name, error 2
Failed to rename ... 
        old_ifname to jnx_re_host_ifd_name, error 2

2021-09-24 07:18:18,144: launch     TRACE    OUTPUT VCP: lag enhanced disabled 0 

2021-09-24 07:18:41,171: launch     INFO     matched login prompt
2021-09-24 07:18:41,171: launch     DEBUG    writing to serial console: root
2021-09-24 07:18:43,174: launch     INFO     matched login prompt
2021-09-24 07:18:43,174: launch     DEBUG    writing to serial console: root
2021-09-24 07:18:45,177: launch     DEBUG    writing to serial console: cli
2021-09-24 07:18:45,177: launch     TRACE    Waiting for > before writing edit exclusive
2021-09-24 07:19:09,849: launch     TRACE    Read: root>
2021-09-24 07:19:09,849: launch     DEBUG    writing to serial console: edit exclusive
2021-09-24 07:19:09,849: launch     TRACE    Waiting for # before writing delete chassis auto-image-upgrade
2021-09-24 07:19:10,201: launch     TRACE    Read:  edit exclusive 
warning: uncommitted changes will be discarded on exit
Entering configuration mode

[edit]
root#
2021-09-24 07:19:10,201: launch     DEBUG    writing to serial console: delete chassis auto-image-upgrade
2021-09-24 07:19:10,201: launch     TRACE    Waiting for # before writing commit
2021-09-24 07:19:10,676: launch     TRACE    Read:  delete chassis auto-image-upgrade 
warning: statement not found

[edit]
root#
2021-09-24 07:19:10,677: launch     DEBUG    writing to serial console: commit
2021-09-24 07:19:10,677: launch     TRACE    Waiting for # before writing set chassis fpc 0 pic 0 number-of-ports 96
2021-09-24 07:19:15,783: launch     TRACE    Read:  commit 
commit complete

[edit]
root#
2021-09-24 07:19:15,783: launch     DEBUG    writing to serial console: set chassis fpc 0 pic 0 number-of-ports 96
2021-09-24 07:19:15,783: launch     TRACE    Waiting for # before writing set system host-name vmx
2021-09-24 07:19:15,852: launch     TRACE    Read:  set chassis fpc 0 pic 0 number-of-ports 96 

[edit]
root#
2021-09-24 07:19:15,852: launch     DEBUG    writing to serial console: set system host-name vmx
2021-09-24 07:19:15,852: launch     TRACE    Waiting for # before writing set system services ssh
2021-09-24 07:19:15,893: launch     TRACE    Read:  set system host-name vmx 

[edit]
root#
2021-09-24 07:19:15,893: launch     DEBUG    writing to serial console: set system services ssh
2021-09-24 07:19:15,893: launch     TRACE    Waiting for # before writing set system services netconf ssh
2021-09-24 07:19:15,943: launch     TRACE    Read:  set system services ssh 

[edit]
root#
2021-09-24 07:19:15,943: launch     DEBUG    writing to serial console: set system services netconf ssh
2021-09-24 07:19:15,943: launch     TRACE    Waiting for # before writing set system services netconf rfc-compliant
2021-09-24 07:19:15,964: launch     TRACE    Read:  set system services netconf ssh 

[edit]
root#
2021-09-24 07:19:15,964: launch     DEBUG    writing to serial console: set system services netconf rfc-compliant
2021-09-24 07:19:15,964: launch     TRACE    Waiting for # before writing set system services extension-service request-response grpc clear-text port 57400
2021-09-24 07:19:15,988: launch     TRACE    Read:  set system services netconf rfc-compliant 

[edit]
root#
2021-09-24 07:19:15,988: launch     DEBUG    writing to serial console: set system services extension-service request-response grpc clear-text port 57400
2021-09-24 07:19:15,989: launch     TRACE    Waiting for # before writing set system services extension-service request-response grpc max-connections 4
2021-09-24 07:19:16,039: launch     TRACE    Read:  set system serviroot#xtension-service request-response grpc clear-te
2021-09-24 07:19:16,039: launch     DEBUG    writing to serial console: set system services extension-service request-response grpc max-connections 4
2021-09-24 07:19:16,039: launch     TRACE    Waiting for # before writing set system login user admin class super-user authentication plain-text-password
2021-09-24 07:19:16,039: launch     TRACE    Read:  ...ension-service request-response grpc clear-text port 57400          

[edit]
root#
2021-09-24 07:19:16,039: launch     DEBUG    writing to serial console: set system login user admin class super-user authentication plain-text-password
2021-09-24 07:19:16,039: launch     TRACE    Waiting for New password: before writing admin@123
2021-09-24 07:19:16,148: launch     TRACE    Read:  set system serviroot# ...ension-service request-response grpc max-conne             ctions 4 

[edit]
root# set system login user admin class super-user authentication plroot# ...dmin class super-user authentication plain-tex             t-password 
New password:
2021-09-24 07:19:16,148: launch     DEBUG    writing to serial console: admin@123
2021-09-24 07:19:16,148: launch     TRACE    Waiting for Retype new password: before writing admin@123
2021-09-24 07:19:16,195: launch     TRACE    Read: 
Retype new password:
2021-09-24 07:19:16,195: launch     DEBUG    writing to serial console: admin@123
2021-09-24 07:19:16,195: launch     TRACE    Waiting for # before writing set system root-authentication plain-text-password
2021-09-24 07:19:16,222: launch     TRACE    Read: 

[edit]
root#
2021-09-24 07:19:16,222: launch     DEBUG    writing to serial console: set system root-authentication plain-text-password
2021-09-24 07:19:16,223: launch     TRACE    Waiting for New password: before writing admin@123
2021-09-24 07:19:16,248: launch     TRACE    Read:  set system root-authentication plain-text-password 
New password:
2021-09-24 07:19:16,248: launch     DEBUG    writing to serial console: admin@123
2021-09-24 07:19:16,248: launch     TRACE    Waiting for Retype new password: before writing admin@123
2021-09-24 07:19:16,291: launch     TRACE    Read: 
Retype new password:
2021-09-24 07:19:16,291: launch     DEBUG    writing to serial console: admin@123
2021-09-24 07:19:16,291: launch     TRACE    Waiting for # before writing set interfaces fxp0 unit 0 family inet address 10.0.0.15/24
2021-09-24 07:19:16,306: launch     TRACE    Read: 

[edit]
root#
2021-09-24 07:19:16,306: launch     DEBUG    writing to serial console: set interfaces fxp0 unit 0 family inet address 10.0.0.15/24
2021-09-24 07:19:16,306: launch     TRACE    Waiting for # before writing delete interfaces fxp0 unit 0 family inet dhcp
2021-09-24 07:19:16,370: launch     TRACE    Read:  set interfaces fxp0 unit 0 family inet address 10.0.0.15/24 

[edit]
root#
2021-09-24 07:19:16,370: launch     DEBUG    writing to serial console: delete interfaces fxp0 unit 0 family inet dhcp
2021-09-24 07:19:16,370: launch     TRACE    Waiting for # before writing delete system processes dhcp-service
2021-09-24 07:19:16,419: launch     TRACE    Read:  delete interfaces fxp0 unit 0 family inet dhcp 

[edit]
root#
2021-09-24 07:19:16,419: launch     DEBUG    writing to serial console: delete system processes dhcp-service
2021-09-24 07:19:16,419: launch     TRACE    Waiting for # before writing commit
2021-09-24 07:19:16,449: launch     TRACE    Read:  delete system processes dhcp-service 

[edit]
root#
2021-09-24 07:19:16,449: launch     DEBUG    writing to serial console: commit
2021-09-24 07:19:16,449: launch     TRACE    Waiting for # before writing exit
2021-09-24 07:19:40,495: launch     TRACE    Read:  commit 
Generating RSA2 key /etc/ssh/ssh_host_rsa_key
Generating public/private rsa key pair.
Your identification has been saved in /config/ssh_host_rsa_key.
Your public key has been saved in /config/ssh_host_rsa_key.pub.
The key fingerprint is:
SHA256:OFAKYnLBAqBMpIquof00SMU1hmgRw1tk6bzH6XcOpLY root@vmx
The key's randomart image is:
+---[RSA 2048]----+
|O*B*oo=          |
|Oo==+= .         |
|o+ ==            |
|o ..o. .         |
|o .  oo.S        |
|.. .. ++         |
|... ooo .        |
|oo . o.....      |
|o ... E. o.      |
+----[SHA256]-----+
Generating ECDSA key /etc/ssh/ssh_host_ecdsa_key
Generating public/private ecdsa key pair.
Your identification has been saved in /config/ssh_host_ecdsa_key.
Your public key has been saved in /config/ssh_host_ecdsa_key.pub.
The key fingerprint is:
SHA256:Ajh7WGtf4+R6ryDHtECUpWYXTvUNIn7OR74Uyh0y/kc root@vmx
The key's randomart image is:
+---[ECDSA 256]---+
|    .o=.o .      |
|   o.= o o o     |
|  o B + + = .    |
|   O + * B o     |
|  o = o S = E    |
|   o = B = o     |
|    . * o o .    |
|     o o.  .     |
|      ...o.      |
+----[SHA256]-----+
Generating ED25519 key /etc/ssh/ssh_host_ed25519_key
Generating public/private ed25519 key pair.
Your identification has been saved in /config/ssh_host_ed25519_key.
Your public key has been saved in /config/ssh_host_ed25519_key.pub.
The key fingerprint is:
SHA256:IMxXe/PM/XrKYJ4+2yP9FkX9sUXlvrbvILLoAno8Emo root@vmx
The key's randomart image is:
+--[ED25519 256]--+
|        .      .=|
|   o   . .     o+|
|    + o . o    .*|
|     o . . = . oo|
|        S   + . o|
|  . .          o.|
| . + .    . +..oo|
|.Eo + .  . =o*+o+|
|.  o . oo ..=+=O=|
+----[SHA256]-----+
commit complete

[edit]
root@vmx#
2021-09-24 07:19:40,496: launch     DEBUG    writing to serial console: exit
2021-09-24 07:19:40,496: launch     TRACE    Waiting for > before writing exit
2021-09-24 07:19:41,516: launch     TRACE    Read:  exit 
Exiting configuration mode

root@vmx>
2021-09-24 07:19:41,516: launch     DEBUG    writing to serial console: exit
2021-09-24 07:19:41,517: launch     INFO     Startup complete in: 0:10:15.020659

So I am not sure what is the problem with your setup unfortunately, as it seems it is related more to the host system...

vireakouk commented 3 years ago

Thanks @hellt. Yes I think it's something to do with my virtualbox VM. My logs never showed the "Starting vrnetlab vMX" part. I will try a different machine when I got a chance. Thanks for your help as always.