search

ventoy / PXE

The open source part of iVentoy.
464 stars 31 forks source link

iVentoy Crashing during client machine boot #18

Closed MintyRoma closed 1 year ago

MintyRoma commented 1 year ago

Hi there! I've installed iVentoy today in VM on my server. Setted up DHCP server on my Mikrotik. And when new guest VM trying to get file via tftp from iVentoy VM, program crashes. Logs are clear, without any errors.

Technical information

Network

Vendor: Mikrotik Model: RB951 Network: 172.16.0.0/24 Gateway: 172.16.0.1 DNS: 172.16.0.1 Next Server: 172.16.0.5 Boot File Name: iventoy_loader_16000

iVentoy 1.0.17

Type: VM CPU: 1 RAM: 2Gb Storage: 256Gb IP: 172.16.0.5 OS: Fedora Server 38 User: root Firewall: disabled DHCP Server Mode: External

Client Machine

Type: VM CPU: 1 RAM: 2Gb Storage: 32Gb IP: 172.16.0.15 (DHCP) BIOS: SeaBIOS

Logs

2023/07/27 22:35:21.007 [PXE]  ==========================================================
2023/07/27 22:35:21.007 [PXE]  ##########################################################
2023/07/27 22:35:21.007 [PXE]  ##################### IVENTOY RUN ########################
2023/07/27 22:35:21.007 [PXE]  ##########################################################
2023/07/27 22:35:21.007 [PXE]  ==========================================================
2023/07/27 22:35:21.064 [PXE]  ##################### IVENTOY [Linux 64] ################
2023/07/27 22:35:21.064 [PXE]  Module <Log> init start ...
2023/07/27 22:35:21.064 [PXE]  Module <Log> init OK ...
2023/07/27 22:35:21.064 [PXE]  Module <Plat> init start ...
2023/07/27 22:35:21.064 [UTIL] Old system max open files: [1024     524288]
2023/07/27 22:35:21.064 [UTIL] New system max open files: [32768    32768]
2023/07/27 22:35:21.064 [PXE]  Module <Plat> init OK ...
2023/07/27 22:35:21.064 [PXE]  Module <Cfg> init start ...
2023/07/27 22:35:21.064 [PXE]  Module <Cfg> init OK ...
2023/07/27 22:35:21.064 [PXE]  Module <MAC> init start ...
2023/07/27 22:35:21.065 [PXE]  mac addr db init ...
2023/07/27 22:35:21.221 [PXE]  mac addr db init OK, total 49002 records
2023/07/27 22:35:21.221 [PXE]  Module <MAC> init OK ...
2023/07/27 22:35:21.221 [PXE]  Module <Tarfs> init start ...
2023/07/27 22:35:21.287 [PXE]  iventoy.dat <8033336> <15042560> <1eb6c319>
2023/07/27 22:35:21.846 [PXE]  Extract iventoy.dat success.
2023/07/27 22:35:21.847 [PXE]  ======= iVentoy 1.0.17 ========
2023/07/27 22:35:21.847 [PXE]  tarfs find 179 files
2023/07/27 22:35:21.847 [PXE]  Module <Tarfs> init OK ...
2023/07/27 22:35:21.847 [PXE]  Module <OS> init start ...
2023/07/27 22:35:21.847 [PXE]  cpio buf:0x7f3a071a7410 len:4409344 fixoff:343888
2023/07/27 22:35:21.847 [PXE]  Module <OS> init OK ...
2023/07/27 22:35:21.847 [PXE]  Module <IMG> init start ...
2023/07/27 22:35:21.847 [PXE]  Scan iso directory for all image files ...
2023/07/27 22:35:21.847 [PXE]  Add ISO <iso/Rocky-8.5-x86_64-dvd1.iso> size:10716446720 type:0
2023/07/27 22:35:21.848 [PXE]  [1] Phase1 parse image <iso/Rocky-8.5-x86_64-dvd1.iso> <ISO> 0 starting...
2023/07/27 22:35:21.861 [PXE]  [1] img <iso/Rocky-8.5-x86_64-dvd1.iso> <ISO> OS type:Linux
2023/07/27 22:35:21.861 [PXE]  [1] Check linux arch type for <iso/Rocky-8.5-x86_64-dvd1.iso>
2023/07/27 22:35:21.861 [PXE]  [1] Find x86_64, </EFI/BOOT/grubx64.efi>
2023/07/27 22:35:21.861 [PXE]  [1] collect initrd for <iso/Rocky-8.5-x86_64-dvd1.iso> ...
2023/07/27 22:35:21.861 [PXE]  [1] parse loader cfg </isolinux/isolinux.cfg> for <iso/Rocky-8.5-x86_64-dvd1.iso> 
2023/07/27 22:35:21.861 [PXE]  [1] new isolinux initrd </isolinux/initrd.img>
2023/07/27 22:35:21.861 [PXE]  [1] isolinux cfg: </isolinux/initrd.img> DirentOffset:72378 FileOffset:738867200 FileSize:79894932
2023/07/27 22:35:21.861 [PXE]  [1] parse loader cfg </boot/grub/grub.cfg> for <iso/Rocky-8.5-x86_64-dvd1.iso> 
2023/07/27 22:35:21.861 [PXE]  [1] <boot/grub/grub.cfg> not found in ISO file.
2023/07/27 22:35:21.861 [PXE]  [1] parse loader cfg </EFI/BOOT/grub.cfg> for <iso/Rocky-8.5-x86_64-dvd1.iso> 
2023/07/27 22:35:21.861 [PXE]  [1] new grub2 initrd </images/pxeboot/initrd.img>
2023/07/27 22:35:21.861 [PXE]  [1] grub2 cfg: </images/pxeboot/initrd.img> DirentOffset:69962 FileOffset:738867200 FileSize:79894932
2023/07/27 22:35:21.861 [PXE]  [1] [INITRD 0] /isolinux/initrd.img
2023/07/27 22:35:21.861 [PXE]  [1] [INITRD 1] /images/pxeboot/initrd.img
2023/07/27 22:35:21.861 [PXE]  [1] collect initrd for <iso/Rocky-8.5-x86_64-dvd1.iso> finished.
2023/07/27 22:35:21.861 [PXE]  [1] Find <images/install.img> for <iso/Rocky-8.5-x86_64-dvd1.iso>
2023/07/27 22:35:21.862 [PXE]  [1] Phase1 parse image <iso/Rocky-8.5-x86_64-dvd1.iso> finished success
2023/07/27 22:35:21.862 [PXE]  ================= PXE IMG DUMP =================
2023/07/27 22:35:21.862 [PXE]  [1] <Rocky-8.5-x86_64-dvd1.iso> <10716446720> <ISO> <Linux> <x86_64> <Initrd:2>
2023/07/27 22:35:21.862 [PXE]  ================================================
2023/07/27 22:35:21.862 [PXE]  Module <IMG> init OK ...
2023/07/27 22:35:21.862 [PXE]  Module <DHCP> init start ...
2023/07/27 22:35:21.862 [PXE]  Module <DHCP> init OK ...
2023/07/27 22:35:21.862 [PXE]  Module <TFTP> init start ...
2023/07/27 22:35:21.862 [PXE]  Module <TFTP> init OK ...
2023/07/27 22:35:21.862 [PXE]  Module <HTTP> init start ...
2023/07/27 22:35:21.869 [HTTP] HTTP API service is running on 0.0.0.0:26000 ...
2023/07/27 22:35:21.920 [PXE]  Module <HTTP> init OK ...
2023/07/27 22:35:21.920 [PXE]  Module <NBD> init start ...
2023/07/27 22:35:21.920 [PXE]  Module <NBD> init OK ...
2023/07/27 22:35:21.920 [PXE]  <51323974625739754945745754534277636d396a5a584e7a6233493d>
2023/07/27 22:35:21.920 [PXE]  <4d32457a4e7a46684e7a41304e4759324e446b31597a686b4d446b354d6a63784d6d466d4f4463354d54673d>
2023/07/27 22:35:21.920 [PXE]  4efa4cf32f578e84155f56a779c90d035c6cd679b99444b31b185c38bddc1f17
2023/07/27 22:35:21.920 [PXE]  ====================== SYSTEM IP LIST ===================================
2023/07/27 22:35:21.920 [PXE]   [1] 172.16.0.5        255.255.255.0     172.16.0.1        ens18
2023/07/27 22:35:21.920 [PXE]  =========================================================================
2023/07/27 22:35:21.920 [PXE]  PXE cofigure recovery ...
2023/07/27 22:35:21.920 [PXE]  data/config.dat is valid, now recover data ...
2023/07/27 22:35:21.920 [PXE]  Recover: dhcp server mode 1
2023/07/27 22:35:21.920 [PXE]  Recover: boot background mode 1
2023/07/27 22:35:21.920 [PXE]  Recover: efi boot file 0
2023/07/27 22:35:21.920 [PXE]  Recover: boot resolution 1024 x 768
2023/07/27 22:35:21.920 [PXE]  Recover: ip:172.16.0.5 mask:255.255.255.0 gateway:172.16.0.1 pool:[172.16.0.200-172.16.0.219]
2023/07/27 22:35:21.920 [PXE]  Recover: HTTP port:16000 NBD port:10809 TFTP timeout:5 TFTP max-retransmit:3
2023/07/27 22:35:21.920 [PXE]  Recover filter [deny] mode
2023/07/27 22:35:21.920 [PXE]  =============== PXE cofigure recovery finished ===============
2023/07/27 22:35:21.920 [PXE]  iVentoy entering main loop ...
2023/07/27 22:35:25.977 [HTTP] API request: <{"method":"sysinfo"}>
2023/07/27 22:35:26.000 [HTTP] API request: <{"method":"sys_ip_list"}>
2023/07/27 22:35:26.005 [HTTP] API request: <{"method":"get_dhcp_mode"}>
2023/07/27 22:35:27.591 [HTTP] API request: <{"method":"get_config_all"}>
2023/07/27 22:35:29.101 [HTTP] API request: <{"method":"get_img_tree"}>
2023/07/27 22:35:30.194 [HTTP] API request: <{"method":"get_config_all"}>
2023/07/27 22:35:32.399 [HTTP] API request: <{"method":"sys_ip_list"}>
2023/07/27 22:35:32.408 [HTTP] API request: <{"method":"get_dhcp_mode"}>
2023/07/27 22:35:33.224 [HTTP] API request: <{"method":"start_server","ip":"172.16.0.5","mask":"255.255.255.0","gw":"172.16.0.1","pool_begin":"172.16.0.200","pool_end":"172.16.0.219","dns_server":""}>
2023/07/27 22:35:33.225 [PXE]  Update Mask[255.255.255.0 --> 255.255.255.0] GW[172.16.0.1 --> 172.16.0.1]
2023/07/27 22:35:33.225 [PXE]  iVentoy service is starting ...
2023/07/27 22:35:33.226 [PXE]  [1] Phase2 parse image <iso/Rocky-8.5-x86_64-dvd1.iso> <ISO> starting...
2023/07/27 22:35:33.226 [PXE]  [1] <iso/Rocky-8.5-x86_64-dvd1.iso> virt data cpiolen:4409344 extfiles:2048
2023/07/27 22:35:33.226 [PXE]  [1] Virt data ISO file size: 10716446720 10952208384
2023/07/27 22:35:33.226 [PXE]  [1] ================ OVERRIDE DUMP ================
2023/07/27 22:35:33.226 [PXE]  [1]  <0> [ 72378 - 72394 16 ]
2023/07/27 22:35:33.226 [PXE]  [1]  <1> [ 69962 - 69978 16 ]
2023/07/27 22:35:33.226 [PXE]  [1] ================ OVERRIDE DUMP ================
2023/07/27 22:35:33.226 [PXE]  [1] ================ VIRT RANGE DUMP ================
2023/07/27 22:35:33.226 [PXE]  [1]  <iso/Rocky-8.5-x86_64-dvd1.iso> WIM:2/2
2023/07/27 22:35:33.226 [PXE]  [1]  <01> [10716446720 - 10716448768 2048      ] iVentoy Param
2023/07/27 22:35:33.226 [PXE]  [1]  <02> [10716448768 - 10750003200 33554432  ] Zero
2023/07/27 22:35:33.227 [PXE]  [1]  <03> [10750003200 - 10754412544 4409344   ] Memory
2023/07/27 22:35:33.227 [PXE]  [1]  <04> [10754412544 - 10754414592 2048      ] Memory
2023/07/27 22:35:33.227 [PXE]  [1]  <05> [10754414592 - 10834309524 79894932  ] Remap
2023/07/27 22:35:33.227 [PXE]  [1]  <06> [10834311168 - 10834313216 2048      ] iVentoy Param
2023/07/27 22:35:33.227 [PXE]  [1]  <07> [10834313216 - 10867867648 33554432  ] Zero
2023/07/27 22:35:33.227 [PXE]  [1]  <08> [10867867648 - 10872276992 4409344   ] Memory
2023/07/27 22:35:33.227 [PXE]  [1]  <09> [10872276992 - 10872279040 2048      ] Memory
2023/07/27 22:35:33.227 [PXE]  [1]  <10> [10872279040 - 10952173972 79894932  ] Remap
2023/07/27 22:35:33.227 [PXE]  [1]  <11> [10952175616 - 10952208384 32768     ] Zero
2023/07/27 22:35:33.227 [PXE]  [1] ================ VIRT RANGE DUMP ================
2023/07/27 22:35:33.227 [PXE]  [1] Phase2 parse image <iso/Rocky-8.5-x86_64-dvd1.iso> finished success
2023/07/27 22:35:33.227 [PXE]  Update ipxe menu 1 ...
2023/07/27 22:35:33.227 [PXE]  ================= IMG TREE DUMP =================
2023/07/27 22:35:33.227 [PXE]  Rocky-8.5-x86_64-dvd1.iso [1] <images/install.img> <INITRD:2>
2023/07/27 22:35:33.227 [PXE]  ================================================
2023/07/27 22:35:33.228 [HTTP] HTTP PXE service starting ...
2023/07/27 22:35:33.228 [TFTP] TFTP service starting ...
2023/07/27 22:35:33.228 [DHCP] DHCP service starting ...
2023/07/27 22:35:33.228 [UTIL] Bind Socket(172.16.0.5) to Device ens18
2023/07/27 22:35:33.228 [NBD]  NBD service starting ...
2023/07/27 22:35:33.228 [PXE]  Now save iventoy config data ...
2023/07/27 22:35:33.229 [PXE]  iventoy config data (data/config.dat) save OK
2023/07/27 22:35:33.229 [PXE]  ===========================================================
2023/07/27 22:35:33.229 [PXE]         iVentoy 1.0.17 [Linux 64] is running now ...
2023/07/27 22:35:33.229 [PXE]  ===========================================================
2023/07/27 22:35:33.229 [HTTP] NBD service is running on 172.16.0.5:10809 ...
2023/07/27 22:35:33.229 [DHCP] DHCP service is running ...
2023/07/27 22:35:33.230 [TFTP] TFTP service is running ...
2023/07/27 22:35:33.230 [TFTP] TFTP write thread is running 28 ...
2023/07/27 22:35:33.230 [HTTP] HTTP PXE service is running on 172.16.0.5:16000 ...
2023/07/27 22:35:33.235 [HTTP] API request: <{"method":"query_status"}>
2023/07/27 22:35:33.250 [HTTP] API request: <{"method":"sys_ip_list"}>
2023/07/27 22:35:33.259 [HTTP] API request: <{"method":"get_dhcp_mode"}>
2023/07/27 22:35:45.362 [DHCP] Snooping 32-4b-54-8f-da-1a MSG:<DISCOVER> ARCH:<Intel x86PC> (nil)
2023/07/27 22:35:45.362 [DHCP] snopping add client 32-4b-54-8f-da-1a
2023/07/27 22:35:46.386 [DHCP] Snooping 32-4b-54-8f-da-1a MSG:<DISCOVER> ARCH:<Intel x86PC> 0x7f39e8001a00
2023/07/27 22:35:48.418 [DHCP] Snooping 32-4b-54-8f-da-1a MSG:<REQUEST> ARCH:<Intel x86PC> 0x7f39e8001a00
2023/07/27 22:35:48.477 [TFTP] Parse tftp option(blksize,1432)
2023/07/27 22:35:48.477 [TFTP] Parse tftp option(tsize,0)
2023/07/27 22:35:48.477 [TFTP] TFTP RRQ client 172.16.0.13:46546 download <iventoy_loader_16000> start ...
2023/07/27 22:35:48.477 [DHCP] snooping record found 172.16.0.13
2023/07/27 22:35:48.477 [TFTP] DHCP External client 172.16.0.13 should use loader ipxe.bios.0
2023/07/27 22:35:48.477 [TFTP] Start send file iventoy_loader_16000 to 172.16.0.13:46546 with blksize 1432, has oack 1
2023/07/27 22:35:48.494 [TFTP] Finished send file to 172.16.0.13:46546 with blksize 1432 blks 93
2023/07/27 22:35:48.770 [DHCP] Snooping 32-4b-54-8f-da-1a MSG:<DISCOVER> ARCH:<Intel x86PC> 0x7f39e8001a00
2023/07/27 22:35:49.791 [DHCP] Snooping 32-4b-54-8f-da-1a MSG:<DISCOVER> ARCH:<Intel x86PC> 0x7f39e8001a00
2023/07/27 22:35:51.824 [DHCP] Snooping 32-4b-54-8f-da-1a MSG:<REQUEST> ARCH:<Intel x86PC> 0x7f39e8001a00
MintyRoma commented 1 year ago

Found solution. iVentoy VM should have more than 2Gb of RAM and at least 2 cores.