Crashed during nearly 3d print, now wont restart

Ch3vr0n · December 26, 2020, 11:21am

Some time into a nearly 3d print Octoprint crashed (probably because i left the webcam stream open on my laptop and had it up on my phone as well to monitor). The print itself kept running because it completed a few hours ago. However when trying to access it via ip (or octoprint.local) i get the service not running.

Putty can login, SmarTTY can't (cannot access .ssh directory)
Network is fine (because as said i can connect it just shows service not running) and pinging works

What i tried so far:

pi@octopi:~ ps -ef | grep -i octoprint | grep -i python pi@octopi:~ vi ~/.octoprint/logs/octoprint.log

results in

E297: Write error in swap file
E303: Unable to open swap file for "/home/pi/.octoprint/logs/octoprint.log", recovery impossible
"~/.octoprint/logs/octoprint.log" 0 lines, 898964 characters

pi@octopi:~ df :! pi@octopi:~ ls /dev/root
ls: cannot access '/dev/root': No such file or directory
pi@octopi:~ cd /.dev -bash: cd: /.dev: No such file or directory pi@octopi:~ cd /dev
pi@octopi:/dev ls autofs cuse gpiochip1 loop1 mapper net ram10 ram4 rfkill stderr tty12 tty2 tty27 tty34 tty41 tty49 tty56 tty63 urandom vcs3 vcsa4 vcsu3 video12 block disk gpiomem loop2 media0 null ram11 ram5 rpivid-h264mem stdin tty13 tty20 tty28 tty35 tty42 tty5 tty57 tty7 v4l vcs4 vcsa5 vcsu4 video13 btrfs-control dma_heap hwrng loop3 media1 port ram12 ram6 rpivid-hevcmem stdout tty14 tty21 tty29 tty36 tty43 tty50 tty58 tty8 vchiq vcs5 vcsa6 vcsu5 video14 bus dri initctl loop4 mem ppp ram13 ram7 rpivid-intcmem tty tty15 tty22 tty3 tty37 tty44 tty51 tty59 tty9 vcio vcs6 vcsm vcsu6 video15 cachefiles fd input loop5 mmcblk0 ptmx ram14 ram8 rpivid-vp9mem tty0 tty16 tty23 tty30 tty38 tty45 tty52 tty6 ttyAMA0 vc-mem vcsa vcsm-cma vga_arbiter video16 char full kmsg loop6 mmcblk0p1 pts ram15 ram9 serial1 tty1 tty17 tty24 tty31 tty39 tty46 tty53 tty60 ttyprintk vcs vcsa1 vcsu vhci watchdog console fuse log loop7 mmcblk0p2 ram0 ram2 random shm tty10 tty18 tty25 tty32 tty4 tty47 tty54 tty61 uhid vcs1 vcsa2 vcsu1 video10 watchdog0 cpu_dma_latency gpiochip0 loop0 loop-control mqueue ram1 ram3 raw snd tty11 tty19 tty26 tty33 tty40 tty48 tty55 tty62 uinput vcs2 vcsa3 vcsu2 video11 zero pi@octopi:/ sudo service octoprint restart
pi@octopi:/ $ ps -ef | grep -i octoprint | grep -i python

Can't post the log because of the double error above, so i can't find out what's causing it. Can't fix it myself cause i'm a complete linux noob and will need step by step commandline instructions. I hope not having to wipe as i'd love to know if the timelapse of that 3d build will have been succesful.

Can't get into safemode as the commands don't work (or i'm doing it wrong)

pi@octopi:~ octoprint config set --bool server.startOnceInSafeMode true -bash: octoprint: command not found pi@octopi:~ sudo octoprint config set --bool server.startOnceInSafeMode true
[sudo] password for pi:
sudo: octoprint: command not found

pi@octopi:~ $ df -h
Filesystem Size Used Avail Use% Mounted on
/dev/root 59G 59G 0 100% /
devtmpfs 1.8G 0 1.8G 0% /dev
tmpfs 1.9G 0 1.9G 0% /dev/shm
tmpfs 1.9G 8.5M 1.9G 1% /run
tmpfs 5.0M 4.0K 5.0M 1% /run/lock
tmpfs 1.9G 0 1.9G 0% /sys/fs/cgroup
/dev/mmcblk0p1 253M 54M 199M 22% /boot
tmpfs 378M 0 378M 0% /run/user/1000

browsed through the forum trying to debug commands. This is the first one that might shed a clue

pi@octopi:~ $ ~/oprint/bin/octoprint serve --debug
2020-12-26 11:17:54,171 - octoprint.settings - ERROR - Could not write test file to /home/pi/.octoprint/logs
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/octoprint/settings.py", line 2211, in _validate_folder
f.write("test")
IOError: [Errno 28] No space left on device
2020-12-26 11:17:54,173 - octoprint.startup - CRITICAL - Could not initialize settings manager: Folder at /home/pi/.octoprint/logs doesn't appear to be writable, please fix its permissions
2020-12-26 11:17:54,173 - octoprint.startup - CRITICAL - There was a fatal error starting up OctoPrint.
Could not initialize settings manager: Folder at /home/pi/.octoprint/logs doesn't appear to be writable, please fix its permissions
There was a fatal error starting up OctoPrint.

Can't force reinstall either

pi@octopi:~ $ ~/oprint/bin/pip install --force-reinstall OctoPrint==1.4.2
DEPRECATION: Python 2.7 will reach the end of its life on January 1st, 2020. Please upgrade your Python as Python 2.7 won't be maintained after that date. A future version of pip will drop support for Python 2.7. More details about Python 2 support in pip, can be found at https://pip.pypa.io/en/latest/development/release-process/#python-2-support
ERROR: Exception:
Traceback (most recent call last):
File "/home/pi/oprint/local/lib/python2.7/site-packages/pip/_internal/cli/base_command.py", line 153, in _main
status = self.run(options, args)
File "/home/pi/oprint/local/lib/python2.7/site-packages/pip/_internal/commands/install.py", line 338, in run
wheel_cache = WheelCache(options.cache_dir, options.format_control)
File "/home/pi/oprint/local/lib/python2.7/site-packages/pip/_internal/cache.py", line 219, in init
self._ephem_cache = EphemWheelCache(format_control)
File "/home/pi/oprint/local/lib/python2.7/site-packages/pip/_internal/cache.py", line 195, in init
self._temp_dir = TempDirectory(kind="ephem-wheel-cache")
File "/home/pi/oprint/local/lib/python2.7/site-packages/pip/_internal/utils/temp_dir.py", line 57, in init
path = self._create(kind)
File "/home/pi/oprint/local/lib/python2.7/site-packages/pip/_internal/utils/temp_dir.py", line 90, in _create
tempfile.mkdtemp(prefix="pip-{}-".format(kind))
File "/usr/lib/python2.7/tempfile.py", line 331, in mkdtemp
dir = gettempdir()
File "/usr/lib/python2.7/tempfile.py", line 275, in gettempdir
tempdir = _get_default_tempdir()
File "/usr/lib/python2.7/tempfile.py", line 217, in _get_default_tempdir
("No usable temporary directory found in %s" % dirlist))
IOError: [Errno 2] No usable temporary directory found in ['/tmp', '/var/tmp', '/usr/tmp', '/home/pi']

I'd appreciate any help getting things back working (without losing all data obviously)

Charlie_Powell · December 26, 2020, 11:59am

You ran the df command, that along with the logs saying it is out of space, shows that there is no space left on the SD card.

The question is what has taken up this space? Now I guess you'll have to go on a hunt to find out. It's possible, that it's timelapses or log files.

Try ls -lh /var/log, to check there is nothing large there. You could also check your timelapse folder, ls -lh ~/.octoprint/timelapse.

There is a command that will list the largest files on the disk, I can't remember it now but maybe I'll find it later.

Ch3vr0n · December 26, 2020, 12:25pm

ls -lh /var/log
total 56G
-rw-r--r-- 1 root root 13K Dec 19 17:59 alternatives.log
drwxr-xr-x 2 root root 4.0K Dec 19 18:01 apt
-rw-r----- 1 root adm 27K Dec 26 12:21 auth.log
-rw-r----- 1 root adm 57K Dec 19 23:17 auth.log.1
-rw-r--r-- 1 root root 0 Sep 26 2019 bootstrap.log
-rw-rw---- 1 root utmp 1.2K Dec 26 10:35 btmp
-rw-r----- 1 root adm 604K Dec 26 12:21 daemon.log
-rw-r----- 1 root adm 1.3M Dec 20 00:00 daemon.log.1
-rw-r----- 1 root adm 19K Dec 26 11:42 debug
-rw-r----- 1 root adm 46K Dec 19 18:02 debug.1
-rw-r--r-- 1 root root 217K Dec 19 18:01 dpkg.log
-rw-r--r-- 1 root root 2.6K Oct 29 2019 faillog
-rw-r--r-- 1 root root 538 Oct 29 2019 fontconfig.log
-rw-r----- 1 root adm 1.5K Dec 26 11:42 haproxy.log
-rw-r----- 1 root adm 243 Dec 25 07:17 haproxy.log.1
-rw-r----- 1 root adm 400 Dec 15 18:33 haproxy.log.10.gz
-rw-r----- 1 root adm 256 Dec 23 17:39 haproxy.log.2.gz
-rw-r----- 1 root adm 364 Dec 22 20:17 haproxy.log.3.gz
-rw-r----- 1 root adm 241 Dec 21 17:30 haproxy.log.4.gz
-rw-r----- 1 root adm 310 Dec 20 20:57 haproxy.log.5.gz
-rw-r----- 1 root adm 870 Dec 19 18:02 haproxy.log.6.gz
-rw-r----- 1 root adm 213 Dec 18 17:58 haproxy.log.7.gz
-rw-r----- 1 root adm 213 Dec 17 16:06 haproxy.log.8.gz
-rw-r----- 1 root adm 311 Dec 16 22:17 haproxy.log.9.gz
-rw-r----- 1 root adm 28G Dec 26 11:43 kern.log
-rw-r----- 1 root adm 926K Dec 19 18:02 kern.log.1
-rw-rw-r-- 1 root utmp 286K Dec 26 12:21 lastlog
-rw-r----- 1 root adm 589K Dec 26 11:43 messages
-rw-r----- 1 root adm 1.1M Dec 20 00:00 messages.1
drwx------ 2 root root 4.0K Sep 26 2019 private
-rw-r--r-- 1 root root 61 Sep 26 2019 regenerate_ssh_host_keys.log
-rw-r----- 1 root adm 418K Dec 26 12:21 syslog
-rw-r----- 1 root adm 28G Dec 26 09:41 syslog.1
-rw-r----- 1 root adm 2.8K Dec 25 00:00 syslog.2.gz
-rw-r----- 1 root adm 40K Dec 24 00:00 syslog.3.gz
-rw-r----- 1 root adm 58K Dec 23 17:16 syslog.4.gz
-rw-r----- 1 root adm 31K Dec 22 17:32 syslog.5.gz
-rw-r----- 1 root adm 18K Dec 21 16:19 syslog.6.gz
-rw-r----- 1 root adm 282K Dec 20 00:00 syslog.7.gz
-rw-r----- 1 root adm 46K Dec 26 11:42 user.log
-rw-r----- 1 root adm 159K Dec 19 19:46 user.log.1
-rw-rw-r-- 1 root utmp 150K Dec 26 12:21 wtmp

If i'm reading that correctly (again total noob here, i'm a windows guy) there's a 28gig kern.log (probably a kernel panic due to trying 2 webcams trying to access the server) and another 28gig one syslog.l so it looks to be logfiles being the cause.

no clue if it's safe to remove them, or how to pull them

pi@octopi:~ $ ls -lh ~/.octoprint/timelapse
total 36K
drwxr-xr-x 2 pi pi 32K Dec 25 08:06 tmp

Charlie_Powell · December 26, 2020, 2:34pm

You can open them and see what's inside, my suspicion is that it is wifi related - sometimes the wifi on the Pi can be unstable and cause a huge amount of logging. Not entirely sure how to solve that as such, but you can try reading the last 100 lines by using tail -n 100 /var/syslog or tail -n /var/kern.log. Not sure you will necessarily find anything, but maybe there is an indication. Or it will be full of messages that it is out of storage. Use https://pastebin.com or similar to upload them if you do.

From my googling, it is not recommended to just delete them in case something is writing to then. You can empty them by running:

cd /var/log
> syslog
> kern.log

Maybe someone with better linux knowledge than me will know better about this, but I usually listen to what google tells me

Be sure to monitor the disk usage carefully after you have cleared them (might want to reboot after, highly likely other things than OctoPrint have crashed). If it creates these logs again (you'd know pretty quickly, previous ones are in the KB range) then investigate further. It's likely there's a problem somewhere, they probably hold the key but it can be difficult to work with such large files.

Maybe empty them, then give it an hour or so, then tail them again to see if there is anything that look suspicious.

Ch3vr0n · December 26, 2020, 2:54pm

Wifi has been working perfectly otherwise.

pi@octopi:~ cd /var/log pi@octopi:/var/log > syslog
-bash: syslog: Permission denied
pi@octopi:/var/log $ > kern.log
-bash: kern.log: Permission denied

pi@octopi:/var/log $ tail Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:53 octopi kernel: [ Dec 26 11:42:54 octopi kernel: [ Dec 26 11:42:54 octopi kernel: [ Dec 26 11:42:54 octopi kernel: [ Dec 26 11:42:54 octopi kernel: [ Dec 26 11:42:59 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ Dec 26 11:43:01 octopi kernel: [ -n 100 /var/log/kern.log
1.253541] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
1.255300] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
1.263046] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
1.266113] of_cfs_init
1.266248] of_cfs_init: OK
1.267291] Waiting for root device PARTUUID=6c586e13-02...
1.301595] random: fast init done
1.331632] mmc1: new high speed SDIO card at address 0001
1.388141] mmc0: new ultra high speed DDR50 SDXC card at address aaaa
1.389105] mmcblk0: mmc0:aaaa BBAAB 59.5 GiB
1.394165] mmcblk0: p1 p2
1.441940] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
1.441979] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
1.514522] usb 1-1: new high-speed USB device number 2 using xhci_hcd
1.595195] EXT4-fs (mmcblk0p2): recovery complete
1.598368] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
1.598470] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
1.606644] devtmpfs: mounted
1.615313] Freeing unused kernel memory: 2048K
1.615626] Run /sbin/init as init process
1.697160] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
1.697204] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
1.697236] usb 1-1: Product: USB2.0 Hub
1.699160] hub 1-1:1.0: USB hub found
1.699571] hub 1-1:1.0: 4 ports detected
2.361486] NET: Registered protocol family 10
2.362824] Segment Routing with IPv6
3.524619] random: systemd: uninitialized urandom read (16 bytes read)
3.538525] random: systemd: uninitialized urandom read (16 bytes read)
3.542563] random: systemd: uninitialized urandom read (16 bytes read)
4.327594] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
5.048983] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
5.049476] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
5.049915] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
5.050376] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
5.131016] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
5.133663] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
5.133684] [vc_sm_connected_init]: start
5.142888] mc: Linux media interface: v0.10
5.157436] [vc_sm_connected_init]: installed successfully
5.234986] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
5.235673] videodev: Linux video capture interface: v2.00
5.253680] bcm2835_audio bcm2835_audio: card created with 8 channels
5.336656] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
5.338968] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
5.360607] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
5.370221] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
5.392588] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
5.432728] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0
5.519786] cfg80211: Loading compiled-in X.509 certificates for regulatory database
5.537219] [drm] No displays found. Consider forcing hotplug if HDMI is attached
5.537339] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
5.537370] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
5.537385] [drm] No driver support for vblank timestamp query.
5.537398] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL
5.541135] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 1
5.637281] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
5.730471] brcmfmac: F1 signature read @0x18000000=0x15264345
5.746033] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
5.746509] usbcore: registered new interface driver brcmfmac
5.783316] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2
5.999571] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
5.999629] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
5.999854] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
6.000780] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
6.001391] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
6.001962] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
6.001987] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
6.002010] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
6.002031] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
6.002051] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
6.002229] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
6.013204] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
6.013246] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
6.014059] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
6.017797] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
6.017855] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
6.031977] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar 23 2020 02:19:54 version 7.45.206 (r725000 CY) FWID 01-88ee44ea
7.770186] uart-pl011 fe201000.serial: no DMA platform data
7.838432] random: crng init done
7.838449] random: 7 urandom warning(s) missed due to ratelimiting
8.032030] 8021q: 802.1Q VLAN Support v1.8
8.467005] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
8.897576] bcmgenet: Skipping UMAC reset
8.899414] bcmgenet fd580000.ethernet: configuring instance for external RGMII
8.899651] bcmgenet fd580000.ethernet eth0: Link is Down
14.135968] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
15.461119] Bluetooth: Core ver 2.22
15.461186] NET: Registered protocol family 31
15.461195] Bluetooth: HCI device and connection manager initialized
15.461216] Bluetooth: HCI socket layer initialized
15.461229] Bluetooth: L2CAP socket layer initialized
15.461250] Bluetooth: SCO socket layer initialized
15.472906] Bluetooth: HCI UART driver ver 2.3
15.472919] Bluetooth: HCI UART protocol H4 registered
15.472980] Bluetooth: HCI UART protocol Three-wire (H5) registered
15.474824] Bluetooth: HCI UART protocol Broadcom registered
15.699946] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
15.699954] Bluetooth: BNEP filters: protocol multicast
15.699967] Bluetooth: BNEP socket layer initialized

pi@octopi:/var/log tail -n 100 var/log/syslog.l tail: cannot open 'var/log/syslog.l' for reading: No such file or directory pi@octopi:/var/log tail -n 100 var/log/syslog.log
tail: cannot open 'var/log/syslog.log' for reading: No such file or directory
pi@octopi:/var/log tail -n 100 var/log/syslog.1 tail: cannot open 'var/log/syslog.1' for reading: No such file or directory pi@octopi:/var/log tail -n 100 var/log/syslog
tail: cannot open 'var/log/syslog' for reading: No such file or directory
pi@octopi:/var/log tail -n 100 var/log/syslog.log tail: cannot open 'var/log/syslog.log' for reading: No such file or directory pi@octopi:/var/log

pi@octopi:/var/log rm kern.log rm: remove write-protected regular file 'kern.log'? y rm: cannot remove 'kern.log': Permission denied pi@octopi:/var/log rm syslog.l
rm: cannot remove 'syslog.l': No such file or directory
pi@octopi:/var/log $

Charlie_Powell · December 26, 2020, 3:02pm

Oops, you'll have to put sudo in there for those ones, since they are all owned by root:

cd /var/log
sudo > kern.log

(slight adjustment to this command, since your screenshot shows it is actually `syslog.1 that is large)

sudo rm syslog.1

When typing these commands, watch that you type them exactly, with the correct leading slashes etc.

The other thing, when you post the paste from the terminal could you format it either using the </> button (preformatted text) or 3 backticks: ``` around it ``` so it appears like this:

pi@octopi:/var/log $ tail -n 100 /var/log/kern.log
Dec 26 11:42:53 octopi kernel: [ 1.253541] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
Dec 26 11:42:53 octopi kernel: [ 1.255300] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
Dec 26 11:42:53 octopi kernel: [ 1.263046] mmc0: SDHCI controller on fe340000.emmc2

Ch3vr0n · December 26, 2020, 3:11pm

Installed diskinternals linux reader. let me pull the contents of the ext4 partition logslogs.zip (78.6 KB)

the command with > didn't work but i was able to remove both logs with sudo rm kern.log and sudo rm syslog.1

After that the raspberry booted up and octoprint is back up and running. So i'm curious what the actual problem was. Hopefully the logs are helpful

Charlie_Powell · December 26, 2020, 3:28pm

This is the line that is repeated lots:

Dec 25 05:06:14 octopi kernel: [126745.734125] brcmfmac: brcmf_sdio_htclk: HT Avail request error: -5

Which is something failing in the wifi stuff failing, as I suspected.

My google-fu tells me that it is commonly caused by undervoltage problems, that the wifi interface is not really very good at coping with it. Do you have any undervoltage warnings? These should either be reported within OctoPrint's UI / octoprint.log, or by running the command vcgencmd get_throttled. Any response other than 0x0 indicates that there is some kind of problem about.

I did also come across this:

The underlying issue was apparently fixed in December 2019. However, this is actually after the OctoPi 0.17 image was built, so it won't be there. Your two options:

sudo apt update && sudo apt upgrade
If you haven't run this one before, it will take hours. The packages are almost a year out of date at this point. Also I'm not actually sure if this will upgrade the firmware, might need sudo rpi-update for that. But, that has been known to break things as well as fix them.
Download & install the OctoPi 0.18 release candidate. This one is built based on an image from August, so has a newer kernel, firmware etc. This is probably the route I would go, unless I had a lot of customisation outside OctoPrint that couldn't be restored with the built in backup/restore function.

Ch3vr0n · December 26, 2020, 3:46pm

Undervoltage warnings? No idea how to see those (as i said, total noob) but the only thing connected to the rpi is a usb webcam (currently testing the Sandberg USB Webcam Pro) and the CR10 Max itself. That's it.

Attached are the octoprint logs from around the time of print only had logs for 23/24th which sounds about right. Was nearly a 3d printjob
octoprint.log.zip (1.3 MB)

Hah hours he sais, it was done in less than a minute. Apparently i had already ran that before. can i flash 0.18 over the top somehow without losing settings?

Charlie_Powell · December 26, 2020, 4:19pm

The logs show no undervoltage warnings, and they are very obvious.

The way to flash 0.18 is to create a backup in OctoPrint first, then flash it (which erases everything on the card) then restore the backup on the new flash.

Other than those, I have no idea what is causing the issue. It could have been a one off, if it comes back then you'll have to find some other help, I don't have any further suggestions

Ch3vr0n · December 26, 2020, 6:58pm

Ugh RC1 won't recognise my 0.17 backup. complains my 0.17 backup is NEWER than the 0.18 RC1 lol

Charlie_Powell · December 26, 2020, 7:51pm

You might have to update 0.18 to OctoPrint 1.5.2, it comes with 1.4.2 by default. Set it up, then update it & try again

Ch3vr0n · December 26, 2020, 8:07pm

That might have been it. But had it already setup from scratch again before OP promted for an update. Thanks for the assist overall none-the-less though. Back up and running!

stephen_s · December 30, 2020, 8:21am

Good information thanks for sharing
vmware

waalge · February 12, 2021, 6:12pm

Hello.
Just wanna say that I've had the following problem a few times:

On set up everything is fine. Wifi good, octoprint behaving, prints going well.
Everything fine for a few days including some turning the machine off and on.
And suddenly nothing: the lights blink, but there's no wifi connection.

Previously I've just started from square one, simply reflashing the sd and pretending nothing ever happened. I thought maybe i needed to shut the server down through the web interface or that it was a power issue but multiple variants lead to the same outcome.

This time I tried to debug a little more.

I found I could ssh via Ethernet. But wifi was weird. It could still scan, and see the access point i should have been connecting to, and ifconfig would have wlan0 listed but it wouldn't connect and other commands would return "no known interface" (I don't know what that really meant - except something is bad).

I'm here cos i got a hit on the same dmesg error (in part)
Mine:

$dmesg | grep error
[   19.363420] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2

Really odd filename imho.

Anyway, total shot in the dark I put this in the directory /usr/lib/firmware/brcm

cd /usr/lib/firmware/brcm/; sudo wget https://raw.githubusercontent.com/openwrt/cypress-nvram/master/brcmfmac43455-sdio.raspberrypi%2C4-model-b.txt

On reboot there was no dmesg error message and I have wifi again.
I have no firm insights into what went wrong, and I cannot say if this is a long term solution.

But maybe this helps someone. At the very least some company by "I also have this issue".