dvtirol / pynetinstall

Module to perform Mikrotik Routerboard Netinstall via Etherboot
GNU General Public License v3.0
62 stars 8 forks source link

Error when omitting config #4

Open etfz opened 2 months ago

etfz commented 2 months ago

Hello,

The documentation says to remove the config line from pynetinstall.ini in order to skip uploading a configuration. However, when doing so I received the following error when attempting the netinstall:

bild

I built the image from the 1.0.2 tag.

Relatedly, when I did include the config parameter and uploaded an empty configuration file, I instead received the following error, due to its zero length:

bild

uedvt359 commented 2 months ago

oh, i see what the problem is.

i fixed this here, can you please try this out? https://github.com/dvtirol/pynetinstall/compare/master...fix_nodefaultconfig

i guess it would be easiest if you run /container shell 0 and edit the file by hand.

etfz commented 2 months ago

Thanks for the quick response!

I... think it works. The first time it did not, but the second time it did, so maybe the container had to be restarted.

I got the following after the installation was complete and it rebooted, but it seems to work fine:

2024-04-18 09:51:55,988 - [ERROR] -> Flashing failed: Device did not respond
uedvt359 commented 2 months ago

yes, a container restart is necessary here. i know about that error; it's wrong. if no default config is sent, the routerboard exits the netinstall mode early (and reboots) and we wait for a response that never comes. here's the relevant debug log:

13:05:47 container,info,debug 2024-04-18 11:05:47,580 - [DEBUG] -> Done with the Firmware 
13:05:47 container,info,debug 2024-04-18 11:05:47,582 - [DEBUG] -> Executing the b'' command 
13:05:47 container,info,debug 2024-04-18 11:05:47,584 - [DEBUG] -> Waiting for the Response b'RETR'
13:05:47 container,info,debug 2024-04-18 11:05:47,650 - [DEBUG] -> Done with the Configuration File
13:05:47 container,info,debug 2024-04-18 11:05:47,652 - [DEBUG] -> Installation Done 
13:05:47 container,info,debug 2024-04-18 11:05:47,653 - [DEBUG] -> Executing the b'FILE\n' command 
13:05:47 container,info,debug 2024-04-18 11:05:47,655 - [DEBUG] -> Waiting for the Response b'WTRM'
13:05:48 interface,info ether2 link down 
13:05:57 interface,info ether2 link up (speed 1G, full duplex)  
13:06:27 interface,info ether2 link down 
13:06:29 interface,info ether2 link up (speed 1G, full duplex)
13:06:41 dhcp,info dhcpInstall deassigned 192.168.30.252 for 78:9A:18:00:00:00
13:06:42 dhcp,info dhcpInstall assigned 192.168.30.150 for 78:9A:18:00:00:00 MikroTik
13:06:47 container,info,debug 2024-04-18 11:06:47,712 - [ERROR] -> Flashing failed: Device did not respond

i need to capture a netinstall session with the official tool to figure out what we should do differently, but no time right now. possibly we are sending too many empty commands or something.

just ignore that error, if you don't give a config file.

uedvt359 commented 2 months ago

well, i fixed it (i needed to deploy a device today anyways):

13:52:27 container,info,debug 2024-04-18 11:52:27,014 - [DEBUG] -> Done with the Firmware 
13:52:27 container,info,debug 2024-04-18 11:52:27,016 - [DEBUG] -> Installation Done 
13:52:27 container,info,debug 2024-04-18 11:52:27,017 - [DEBUG] -> Executing the b'FILE\n' command 
13:52:27 container,info,debug 2024-04-18 11:52:27,019 - [DEBUG] -> Waiting for the Response b'WTRM' 
13:52:27 container,info,debug 2024-04-18 11:52:27,085 - [DEBUG] -> Received Response b'WTRM' 
13:52:27 container,info,debug 2024-04-18 11:52:27,087 - [DEBUG] -> Rebooting the Board 
13:52:27 container,info,debug 2024-04-18 11:52:27,088 - [DEBUG] -> Executing the b'TERM\nInstallation successful\n' command 
13:52:27 container,info,debug 2024-04-18 11:52:27,091 - [INFO ] -> 78:9a:18:00:00:00 was successfully flashed. 
13:52:27 container,info,debug 2024-04-18 11:52:27,092 - [DEBUG] -> Initialization of a new Flasher object 
13:52:27 container,info,debug 2024-04-18 11:52:27,101 - [DEBUG] -> The Plugin (<class 'dvt.DVTPlugin'>) is successfully imported 
13:52:27 container,info,debug 2024-04-18 11:52:27,103 - [INFO ] -> Waiting for devices... 
13:52:27 container,info,debug 2024-04-18 11:52:27,104 - [DEBUG] -> Searching for a Interface... 
13:52:27 container,info,debug 2024-04-18 11:52:27,105 - [DEBUG] -> Searching for a Interface... 
13:52:28 interface,info ether2 link down 

same link as above, please try it out and i'll cut a new release.

etfz commented 2 months ago

Seems to work fine.

Btw, do you have a preferred channel for submitted questions and feedback?

uedvt359 commented 2 months ago

this channel (github tickets) works for me

etfz commented 2 months ago

Wait, now I think the "Device did not respond" error is raised when I do provide a configuration file instead.

uedvt359 commented 2 months ago

it works for me, but please post a debug output ("-vv")

etfz commented 2 months ago
 13:30:33 container,info,debug 2024-04-23 11:30:33,703 - [DEBUG] -> A New UDPConnection is created on ('0.0.0.0', 5000)
 13:30:33 container,info,debug 2024-04-23 11:30:33,705 - [DEBUG] -> The MAC-Address of the Interface eth0 is b'\xb2\x85\xf1\x96e\xe2'
 13:30:33 container,info,debug 2024-04-23 11:30:33,706 - [DEBUG] -> Initialization of a new Flasher object
 13:30:33 container,info,debug 2024-04-23 11:30:33,710 - [DEBUG] -> The Plugin (<class 'pynetinstall.plugins.simple.Plugin'>) is successfully imported
 13:30:33 container,info,debug 2024-04-23 11:30:33,711 - [INFO ] -> Waiting for devices...
 13:30:33 container,info,debug 2024-04-23 11:30:33,713 - [DEBUG] -> Searching for a Interface...
 13:30:46 interface,info ether6 link down
 13:30:46 interface,info ether8 link down
 13:30:57 interface,info ether6 link up (speed 100M, full duplex)
 13:30:57 interface,info ether8 link up (speed 100M, full duplex)
 13:31:05 interface,info ether6 link down
 13:31:05 interface,info ether8 link down
 13:31:14 interface,info ether6 link up (speed 100M, full duplex)
 13:31:14 interface,info ether8 link up (speed 100M, full duplex)
 13:31:29 interface,info ether6 link down
 13:31:29 interface,info ether6 link up (speed 100M, full duplex)
 13:31:33 container,info,debug 2024-04-23 11:31:33,768 - [DEBUG] -> Searching for a Interface...
 13:31:37 interface,info ether6 link down
 13:31:38 interface,info ether8 link down
 13:31:39 interface,info ether6 link up (speed 100M, full duplex)
 13:31:39 interface,info ether8 link up (speed 100M, full duplex)
 13:31:42 container,info,debug 2024-04-23 11:31:42,008 - [DEBUG] -> Interface Found: CC:2D:E0:08:0C:49
 13:31:42 container,info,debug 2024-04-23 11:31:42,009 - [INFO ] -> Device found! mac=cc:2d:e0:08:0c:49, model=RB750r2, arch=mips
 13:31:42 container,info,debug 2024-04-23 11:31:42,011 - [DEBUG] -> Resolved File-Data from the BufferedReader
 13:31:42 container,info,debug 2024-04-23 11:31:42,012 - [DEBUG] -> Sending the offer to flash
 13:31:42 container,info,debug 2024-04-23 11:31:42,012 - [DEBUG] -> Executing the b'OFFR\n\n' command
 13:31:42 container,info,debug 2024-04-23 11:31:42,013 - [DEBUG] -> Waiting for the Response b'YACK\n'
 13:31:42 container,info,debug 2024-04-23 11:31:42,014 - [DEBUG] -> Received Response b'YACK\n'
 13:31:42 container,info,debug 2024-04-23 11:31:42,015 - [INFO ] -> Formatting cc:2d:e0:08:0c:49 ...
 13:31:42 container,info,debug 2024-04-23 11:31:42,016 - [DEBUG] -> Executing the b'' command
 13:31:42 container,info,debug 2024-04-23 11:31:42,017 - [DEBUG] -> Waiting for the Response b'STRT'
 13:32:12 container,info,debug 2024-04-23 11:32:12,145 - [DEBUG] -> Received Response b'STRT'
 13:32:12 container,info,debug 2024-04-23 11:32:12,146 - [DEBUG] -> Waiting until the Board is ready to receive the file
 13:32:12 container,info,debug 2024-04-23 11:32:12,147 - [DEBUG] -> Executing the b'' command
 13:32:12 container,info,debug 2024-04-23 11:32:12,148 - [DEBUG] -> Waiting for the Response b'RETR'
 13:32:12 container,info,debug 2024-04-23 11:32:12,149 - [DEBUG] -> Received Response b'RETR'
 13:32:12 container,info,debug 2024-04-23 11:32:12,150 - [DEBUG] -> Sending the Files to the Board
 13:32:12 container,info,debug 2024-04-23 11:32:12,151 - [DEBUG] -> Resolved File-Data from the BufferedReader
 13:32:12 container,info,debug 2024-04-23 11:32:12,152 - [DEBUG] -> Executing the b'FILE\nrouteros.npk\n10383672\n' command
 13:32:12 container,info,debug 2024-04-23 11:32:12,152 - [DEBUG] -> Waiting for the Response b'RETR'
 13:32:12 container,info,debug 2024-04-23 11:32:12,154 - [DEBUG] -> Received Response b'RETR'
 13:32:12 container,info,debug 2024-04-23 11:32:12,154 - [INFO ] -> Uploading routeros-7.14.2-mipsbe.npk
 13:32:18 container,info,debug 2024-04-23 11:32:18,307 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 10%
 13:32:24 container,info,debug 2024-04-23 11:32:24,804 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 20%
 13:32:31 container,info,debug 2024-04-23 11:32:31,288 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 30%
 13:32:37 container,info,debug 2024-04-23 11:32:37,756 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 40%
 13:32:44 container,info,debug 2024-04-23 11:32:44,242 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 50%
 13:32:50 container,info,debug 2024-04-23 11:32:50,712 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 60%
 13:32:57 container,info,debug 2024-04-23 11:32:57,225 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 70%
 13:33:03 container,info,debug 2024-04-23 11:33:03,739 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 80%
 13:33:10 container,info,debug 2024-04-23 11:33:10,199 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 90%
 13:33:16 container,info,debug 2024-04-23 11:33:16,571 - [INFO ] ->     routeros-7.14.2-mipsbe.npk: 100%
 13:33:16 container,info,debug 2024-04-23 11:33:16,923 - [DEBUG] -> Executing the b'' command
 13:33:16 container,info,debug 2024-04-23 11:33:16,925 - [DEBUG] -> Waiting for the Response b'RETR'
 13:33:17 container,info,debug 2024-04-23 11:33:17,036 - [DEBUG] -> Received Response b'RETR'
 13:33:17 container,info,debug 2024-04-23 11:33:17,037 - [DEBUG] -> Done with the Firmware
 13:33:17 container,info,debug 2024-04-23 11:33:17,038 - [DEBUG] -> Resolved File-Data from the BufferedReader
 13:33:17 container,info,debug 2024-04-23 11:33:17,039 - [DEBUG] -> Executing the b'FILE\nautorun.scr\n0\n' command
 13:33:17 container,info,debug 2024-04-23 11:33:17,040 - [DEBUG] -> Waiting for the Response b'RETR'
 13:33:17 container,info,debug 2024-04-23 11:33:17,041 - [DEBUG] -> Received Response b'RETR'
 13:33:17 container,info,debug 2024-04-23 11:33:17,041 - [INFO ] -> Uploading config.rsc
 13:33:17 container,info,debug 2024-04-23 11:33:17,063 - [DEBUG] -> Executing the b'' command
 13:33:17 container,info,debug 2024-04-23 11:33:17,065 - [DEBUG] -> Waiting for the Response b'RETR'
 13:33:17 container,info,debug 2024-04-23 11:33:17,090 - [DEBUG] -> Done with the Configuration File
 13:33:17 container,info,debug 2024-04-23 11:33:17,091 - [DEBUG] -> Installation Done
 13:33:17 container,info,debug 2024-04-23 11:33:17,092 - [DEBUG] -> Executing the b'FILE\n' command
 13:33:17 container,info,debug 2024-04-23 11:33:17,093 - [DEBUG] -> Waiting for the Response b'WTRM'
 13:33:18 interface,info ether6 link down
 13:33:18 interface,info ether8 link down
 13:33:19 interface,info ether6 link up (speed 100M, full duplex)
 13:33:19 interface,info ether8 link up (speed 100M, full duplex)
 13:33:36 interface,info ether6 link down
 13:33:36 interface,info ether8 link down
 13:33:38 interface,info ether6 link up (speed 100M, full duplex)
 13:33:38 interface,info ether8 link up (speed 100M, full duplex)
 13:34:17 container,info,debug 2024-04-23 11:34:17,148 - [ERROR] -> Flashing failed: Device did not respond
 13:34:17 container,info,debug 2024-04-23 11:34:17,149 - [DEBUG] -> Initialization of a new Flasher object
 13:34:17 container,info,debug 2024-04-23 11:34:17,152 - [DEBUG] -> The Plugin (<class 'pynetinstall.plugins.simple.Plugin'>) is successfully imported
 13:34:17 container,info,debug 2024-04-23 11:34:17,153 - [INFO ] -> Waiting for devices...
 13:34:17 container,info,debug 2024-04-23 11:34:17,154 - [DEBUG] -> Searching for a Interface...
etfz commented 2 months ago

It seems to be an issue of the provided configuration file being empty. It still works, however, and the configuration does get cleared.

uedvt359 commented 2 months ago

are you uploading a zero-byte config.rsc? if you add a single space into the file (making it 1byte large), does the error go away? i guess, the routerboard is rejecting your config file. does your board have a physical serial port? if so, do you see any errors printed over serial?

if you don't mind me asking, why? seems like a good way to brick a device; how do you access it afterwards?

etfz commented 2 months ago

No serial interface on this device, unfortunately, but adding an empty line seems to work.

I always do this when installing new devices. I then run an interactive script for configuring it. The device is accessible via MAC WinBox. I hope to build a more integrated onboarding solution some day!