Firmware release 1.7.1.b1

livius

Is it happening inside an interrupt callback?

I do not use in this project callbacks and threads

i have tried to create minimal code to reproduce but still without success.
Maybe this help somehow - but probably not:
In normal case with 1.6.13 when it start this is the log

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0x00
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:QIO, clock div:2
load:0x3fff9010,len:8
load:0x3fff9018,len:248
load:0x40078000,len:4056
load:0x4009fc00,len:920
entry 0x4009fde4
I (1557) wifi: wifi firmware version: 90b1b8b
I (1558) wifi: config NVS flash: disabled
I (1558) wifi: config nano formating: disabled
I (1573) wifi: Init dynamic tx buffer num: 32
I (1574) wifi: wifi driver task: 3ffd55f8, prio:23, stack:3584
I (1574) wifi: Init static rx buffer num: 10
I (1576) wifi: Init dynamic rx buffer num: 0
I (1580) wifi: Init rx ampdu len mblock:7
I (1584) wifi: Init lldesc rx ampdu entry mblock:4
I (1588) wifi: wifi power manager task: 0x3ffda9b4 prio: 21 stack: 2560
I (1595) wifi: sleep disable
I (2584) wifi: wifi timer task: 3ffdba30, prio:22, stack:3584
I (2606) wifi: Init ampdu: 0
I (2607) wifi: mode : softAP (24:0a:c4:00:6e:c3)
boot
29.31876 100463.6 262.9624
main
free 47904
konfig.config_wifi=1
wifi_sta
I (3439) wifi: Init ampdu: 0
I (3439) wifi: mode : sta (24:0a:c4:00:6e:c2) + softAP (24:0a:c4:00:6e:c3)
I (3440) wifi: sleep disable
<WLAN>
[(ssid='vnet-509F64', bssid=b'pT\xd2b\xc4\xda', sec=4, channel=1, rssi=-38), (ssid='livius', bssid=b'\x000O\x8b\x0c\x08', sec=4, channel=9, rssi=-40), (ssid='UPC0838976', bssid=b'\x8c\x04\xff\xf5\xae\x8a', sec=4, channel=11, rssi=-60), (ssid='UPC Wi-Free', bssid=b'\x8e\x04\xff\xf5\xae\x8c', sec=5, channel=11, rssi=-60), (ssid='UPC77A39D9', bssid=b'\x90\\Dt\x81\x7f', sec=4, channel=6, rssi=-69), (ssid='UPC Wi-Free', bssid=b'\x92\\\x14t\x81\x7f', sec=5, channel=6, rssi=-70), (ssid='TP-LINK_9A6D1E', bssid=b'\xb0Hz\x9am\x1e', sec=3, channel=6, rssi=-73), (ssid='keke', bssid=b'\xb0Hz\xbe\xf6\xa4', sec=3, channel=4, rssi=-75), (ssid='2.4G-Vectra-WiFi-B7C11C', bssid=b'\x84\x00-  <', sec=4, channel=1, rssi=-76), (ssid='2.4G-vnet-1C0A58', bssid=b't\x85*3 \xd7', sec=4, channel=1, rssi=-76), (ssid='DIRECT-y6-BRAVIA', bssid=b':\xb1\xdb\x83\xd7\x89', sec=3, channel=6, rssi=-85), (ssid='2.4G-vnet-08CC4C', bssid=b'\x00q\xc2C|\x94', sec=4, channel=1, rssi=-86), (ssid='UPC1334070', bssid=b'D2\xc8\x9c6\x0c', sec=4, channel=1, rssi=-87), (ssid='UPC Wi-Free', bssid=b'\x92\\\x14\xceh\x95', sec=5, channel=6, rssi=-88), (ssid='UPC Wi-Free', bssid=b'F2\xc8\x9c6\x0e', sec=5, channel=1, rssi=-89), (ssid='UPC5F267D4', bssid=b'\x90\\D\xceh\x95', sec=4, channel=6, rssi=-89), (ssid='UPC248781946', bssid=b'\xfco\xb7=fT', sec=3, channel=11, rssi=-91), (ssid='vnet-EC0D8E', bssid=b'T\xbe\xf7\nEN', sec=4, channel=11, rssi=-91), (ssid='UPC0040392', bssid=b'\x00&$>\xaa\x99', sec=4, channel=1, rssi=-94), (ssid='UPC Wi-Free', bssid=b'\x02&$>\xaa\x9b', sec=5, channel=1, rssi=-94)]
vnet-509F64
livius
UPC0838976
UPC Wi-Free
UPC77A39D9
UPC Wi-Free
TP-LINK_9A6D1E
keke
2.4G-Vectra-WiFi-B7C11C
2.4G-vnet-1C0A58
DIRECT-y6-BRAVIA
2.4G-vnet-08CC4C
UPC1334070
UPC Wi-Free
UPC Wi-Free
UPC5F267D4
UPC248781946
vnet-EC0D8E
UPC0040392
UPC Wi-Free
I (7133) wifi: ap channel adjust o:1,1 n:9,2
I (7133) wifi: n:9 2, o:1 0, ap:9 2, sta:9 2, prof:1
I (8130) wifi: state: init -> auth (b0)
I (8135) wifi: state: auth -> assoc (0)
I (8139) wifi: state: assoc -> run (10)
I (8155) wifi: connected with livius, channel 9
WLAN connection to the router succeeded!
connected to socket
wifi_imported
konfig.config_czas=1
---RTC---
(1970, 1, 1, 0, 0, 8, 383520, None)
(2017, 6, 2, 21, 31, 15, 563, None)
konfig.config_LCD=1
konfig.config_termometr=1
---DS18X20---
---termometr---
---termometr: bytearray(b'(\xff;\x17\x83\x16\x04\xa3')

but with 1.7.1

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0x00
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:QIO, clock div:2
load:0x3fff9010,len:12
ho 0 tail 12 room 4
load:0x3fff9020,len:388
load:0x40078000,len:11412
load:0x4009fc00,len:848
entry 0x4009fd9c
boot
28.58889 100493.7 260.5683
main
free 41424
konfig.config_wifi=1
wifi_imported
konfig.config_czas=1
---RTC---
Traceback (most recent call last):
  File "main.py", line 13, in <module>
  File "/flash/lib/calosc.py", line 23, in <module>
  File "/flash/lib/czas.py", line 49, in <module>
AttributeError: 'module' object has no attribute 'wlan'
MicroPython v1.8.6-640-g585ac892 on 2017-06-02; WiPy with ESP32
Type "help()" for more information.
>>>

czas.py have

import wifi

and inside wifi.py is

import machine
import time
from machine import Timer
from network import WLAN
import socket
import binascii
import struct
import funkcje
from machine import Pin
import os

print('wifi_sta')
funkcje.Led(0x00ff00, 100)

wlan = WLAN(mode=WLAN.STA_AP)
adr = socket.getaddrinfo('192.168.1.102', 9456)
sok = None
print(wlan)
..........other lines of code

and i use in czas.py e.g.
wifi.wlan.isconnected()

and i got then error that wlan not exists

jmarcelino

@mcook
not sure if it helps but the latest toolchain is actually https://dl.espressif.com/dl/xtensa-esp32-elf-osx-1.22.0-61-gab8375a-5.2.0.tar.gz

livius

@daniel
i have found problem :) And now have question.

Is name wifi registered as reserved unit name?
i have in my lib folder wifi.py

but i see that when i call dir it list me some system objects?

>>> dir(wifi)
['Wifi', 'WLAN', '__name__', 'hexlify', 'sleep', 'Timer', 'exc_info', 'start_new_thread']

after changing wifi.py to different name and all its references
all work ok

jmarcelino

@livius
Weird I didn't get any wifi.py on my lib and also nothing after os.mkfs("/flash") Wondering how you got it...

jmarcelino

@daniel
I was just reading this post about the 4MB pSRAM support https://www.esp32.com/viewtopic.php?f=13&t=2031

As Jeroen explains do we need to build the toolchain from the xtensa-1.22.x-ext_ram_patch branch to compile the Pycom source correctly for the W01/L01 modules?

All seems a bit cutting edge :-) but to get 4MB RAM wow...

livius

@jmarcelino
This is my custom file.
And it worked ok in previous firmware.
but now this name is registered by system for something. I see nothing about in docs and i do not see it in pycom sources, but maybe i miss something in pycom sources

jmarcelino

@livius
ha sorry misunderstood your comment. But if I do dir(wifi) as you showed I get nothing.

livius

@jmarcelino
what you got when you do?

import wifi
dir(wifi)

if above raise error
try to create empty wifi.py file in lib and back with result - i am really interested :)

livius

@jmarcelino
i tested this self
and whithout file wifi.py anywhere
i have interesting result

>>> import wifi
>>> dir(wifi)
['Wifi', 'WLAN', '__name__', 'hexlify', 'sleep', 'Timer', 'exc_info', 'start_new_thread']
>>>

can someone confirm this?
And maybe @daniel can bring light about purpose of that module

mcook

@jmarcelino

Thank you. I downloaded the latest compiler, removed all of my old stuff and re-installed it all, and now it builds fine.

Mike

robert-hh

@livius I created a brand new firmware, and loaded that: no module wifi.
BUT: If I update via the pycom updater, there is a module wifi included.
So it's sneaking in via the "official" image.

daniel

@livius and @robert-hh thanks for the help. We found the offending file and a release without the problem will be out within 1 hour.

robert-hh

@daniel I have another problem with the github distro:

It worked fine after I did an initial build an upload yesterday night, Both the MP repository and and esp IDF were freshly cloned. No own history whatsoever.
The (in the hunt for wifi.py) iI used the updater, and that worked.
After trying to reflash the firmware with my own build, the device would not start again.
I erased flash and reflashed it with my freshly build image.
Now the device boots again, BUT does not execute boot.py or main.py. It seems to believe, that it is in safeboot mode.
The image loaded via the updater tool runs main.py and boot.py
Steps 2 & 3 can be repeated. I cannot switch between the versions w/o an erase.

daniel

@robert-hh there were changes in the partition table on the latest release hence the need to erase. The updater tool only erases the necessary blocks of flash in order to remove any left over of the previous partition info. After erasing manually and flashing your own built image things should work as normal too. Is that not the case?

daniel

Hello,

1.7.1.b2 is now released. It removes the unwanted wifi.py script. Thanks.

Cheers,
Daniel

robert-hh

@daniel Sorry, no, that is not the case. After erasing flash and reloading my own image, that image boots, but does not execute main.py or boot.py. It behaves like in safeboot mode. If I comment out line 180 (the line below) of mptask.c, main.py and boot.py run.
safeboot = boot_info.safeboot;
It looks as if boot_info is set wrong. Nothing is connected to the Lopy, and with the standard image, main.py and boot.py are executed.

Update 1: I should add that the own built firmware now also does not print the version number on boot or Ctrl-B anymore. The message is:
MicroPython 88419a4-dirty on 2017-06-03; LoPy with ESP32
Manually adding a tag in with git fixed that, but not the main.py skip.

Update 2: Why are the partition tables of updater images and the github executables different. That's confusing & error prone.

this.wiederkehr

There are multiple issues with this release:

1. RTC time sync with ntp is not working correctly anymore with this release:

(sysname='LoPy', nodename='LoPy', release='1.7.1.b2', version='v1.8.6-642-g84447452 on 2017-06-03', machine='LoPy with ESP32', lorawan='1.0.0')

With the 1.6.XX I could easily sync with ntp server, e.g. rtc.ntp_sync("pool.ntp.org"). Some time after this call rtc.now() would return the current time. Now this is not happening any more time does not get synced at all even after minutes. No Idea why. There is also no way to know what is wrong...

2. Guru Mediation Error Load Prohibited

After a few minutes of running my app I get around 30 of the following exceptions with different backtrace and the board resets:

Guru Meditation Error of type LoadProhibited occurred on core  0. Exception was unhandled.
Register dump:
PC      : 0x400875b9  PS      : 0x00060033  A0      : 0x40088c47  A1      : 0x3ffbd5d0  
A2      : 0x00050023  A3      : 0x00000000  A4      : 0x00000001  A5      : 0x3ffc3dc8  
A6      : 0x000ee81c  A7      : 0x3ffc0df4  A8      : 0x00000005  A9      : 0x00000001  
A10     : 0x3ffc3e34  A11     : 0x00000000  A12     : 0x3ffc3e34  A13     : 0x00000000  
A14     : 0x00000000  A15     : 0x00000000  SAR     : 0x00000016  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000048  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

Backtrace: 0x400875b9:0x3ffbd5d0 0x40088c47:0x3ffbd5f0 0x40088c01:0x3ffbd630 0x4013d1d7:0x000ee81c

3. Freeze The title says it all and I cant add any more information as on freeze it does not provide any more information ....

Please, please, please get out something which is stable!!! Right now this is not usable for anything more than doing TESTS!

daniel

@this-wiederkehr thanks for your post. I'm sorry about your frustration. We only release new software when all our automatic tests (more than 400) are passing. I'll check asap what's happening with the NTP sync and fix it, but if you can provide a minimal example to reproduce the crash I will appreciate it very much.

Thanks again.

Cheers,
Daniel

this.wiederkehr

@daniel indeed this is frustrating.. Thanks for showing interest in solving the issues:

Issue1: NTP SYNC

This is straight forward:

import utime

from machine import RTC
from network import WLAN

wl = WLAN()
wl.mode(WLAN.STA)

wl.connect('XX', auth=(X, 'XX'))



rtc = RTC()
rtc.init()
rtc.ntp_sync('pool.ntp.ort')

while True:
    print(rtc.now())
    print(wl.isconnected())
    utime.sleep_ms(1000)

What it does: Prints time tuple but stays in year 1970. :

(1970, 1, 1, 0, 25, 56, 158744, None)
True
...

I also saw examples where it jumped to a year far in the future: (62236, 1, 19, 7, 16, 53, 555967, None)
While on it: It would be great if the api for the rtc could be extended in order to know if a sync took place. something like last_synced which should return the time elapsed since the last sync or none if a sync never succeeded.

Actually it is not as easy for the second and third issue to provide a minimal example as the issue does not happen each time the same code path runs but arbitrarily, read on...

Something about my setup:

I'm using the expansion board with an sd-card populated
I'm using P10, P11 and P12 for spi communication and additionally P9 for CS (chip select) attached is an acceleration sensor with a fifo buffer
Several times a second I read the data from the fifo through spi and dump it to the a file on the sd card and call flush to persist the changes in a file.
Issue 2 and 3 both happen around flushing the write to the sd-card, either just during flushing or nearly after, however they do not happen each time! The app runs for as little as a few seconds before issue 2 or 3 occur or as long as about 20 minutes. However I did not see much longer durations.

dummy code:

f = open(file_on_sd, 'a')
f.write(data)
print('about to flush')
f.flush() # <-- Both issues are located here or right after that call
print('flushed') # <-- Sometimes even this line is printed and freeze occurs afterward

Issue 3: Freeze on sd flush
Issue 3 occurs during or right after flushing
I read the issue https://github.com/espressif/esp-idf/issues/569 which is about a race condition on reused pins for sd-card and something else. So I thought that the freeze is related to this and I probably should not use P9 for CS of the SPI device. Switching from P9 to P14 for CS seemes to solve the problem with freezing, still this seems like a workaround which should not be required in the first place.

While playing I found how you can make the interpreter freeze reproducible at that line, though this might be totally different issue or even expected:

import machine
import os

sd = machine.SD()
os.mount(sd, '/sd')

f = open('/sd/test', 'a')

while True:
    f.write('blabla')
    print('about to disable irq')
    machine.disable_irq()
    print('about to flush to file')
    f.flush() # <-- freezes reproducible at that call
    print('about to enable irq')
    machine.enable_irq()
    print("I'm done")

Issue 2: Load prohibited
Occurrence of this error is at the same location as the the freeze issue, however I did not have time to dig into it. It might be easier for you anyway by using the stack trace.

I also noticed freezes during gc collect but these seems quite rare.

livius

@this.wiederkehr said in Firmware release 1.7.1.b1:

pool.ntp.ort

is this sample or you have really this wrong address? ort but should be org

Explore Pybytes | Official Documentation | Report a Firmware Bug/Issue | GitHub

Firmware release 1.7.1.b1

Pycom on Twitter