meshtastic / firmware

Meshtastic device firmware
https://meshtastic.org
GNU General Public License v3.0
3.36k stars 821 forks source link

[Bug]: RP2040-Zero serial console/client stop working after the first transmission #3087

Closed vidalperezbohoyo closed 8 months ago

vidalperezbohoyo commented 8 months ago

Category

Serial

Hardware

Other

Firmware Version

2.2.18 said on the version.properties (latest on master)

Description

First of all, I am using a RP2040 Zero and SX1276 module. (Firmware built from source).

Although it transmits well and does not freeze, the serial stops working after the first lora transmission (after approximately 30 seconds). As soon as it is turned on it usually works but then it doesn't. (Althoug still receives messages).

This is the --noproto output:

WARNING file:mesh_interface.py _sendToRadio line:681 Not sending packet because protocol use is disabled by noProto
Connected to radio
WARNING file:mesh_interface.py _sendToRadio line:681 Not sending packet because protocol use is disabled by noProto
WARNING file:mesh_interface.py _sendPacket line:531 Not sending packet because protocol use is disabled by noProto
INFO  | ??:??:?? 3

//\ E S H T /\ S T / C

DEBUG | ??:??:?? 3 Filesystem files:
DEBUG | ??:??:?? 3  channels.proto (53 Bytes)
lfs_file_close: fd=0x20013714
DEBUG | ??:??:?? 3  config.proto (91 Bytes)
lfs_file_close: fd=0x20013714
DEBUG | ??:??:?? 3  db.proto (116 Bytes)
lfs_file_close: fd=0x20013714
DEBUG | ??:??:?? 3  module.proto (95 Bytes)
lfs_file_close: fd=0x20013714
INFO  | ??:??:?? 3 Scanning for i2c devices...
DEBUG | ??:??:?? 3 Scanning for i2c devices on port 1
DEBUG | ??:??:?? 3 I2C device found at address 0x3c
DEBUG | ??:??:?? 3 0x5 subtype probed in 2 tries
INFO  | ??:??:?? 3 1 I2C devices found
DEBUG | ??:??:?? 3 acc_info = 0
INFO  | ??:??:?? 3 Meshtastic hwvendor=47, swver=2.2.18.ea651c2f
INFO  | ??:??:?? 3 Initializing NodeDB
INFO  | ??:??:?? 3 Loading /prefs/db.proto
lfs_file_close: fd=0x200134b4
INFO  | ??:??:?? 3 Loaded saved devicestate version 22
INFO  | ??:??:?? 3 Loading /prefs/config.proto
lfs_file_close: fd=0x200134b4
INFO  | ??:??:?? 3 Loaded saved config version 22
INFO  | ??:??:?? 3 Loading /prefs/module.proto
lfs_file_close: fd=0x200134b4
INFO  | ??:??:?? 3 Loaded saved moduleConfig version 22
INFO  | ??:??:?? 3 Loading /prefs/channels.proto
lfs_file_close: fd=0x200134b4
INFO  | ??:??:?? 3 Loaded saved channelFile version 22
LittleFSDirImpl::openFile: rc=-2 fd=0x200134b4 path=`/oem/oem.proto` openMode=0 accessMode=1 err=-2
INFO  | ??:??:?? 3 No /oem/oem.proto preferences found
DEBUG | ??:??:?? 3 cleanupMeshDB purged 0 entries
WARN  | ??:??:?? 3 Using nodenum 0xa7604532
DEBUG | ??:??:?? 3 Expanding short PSK #1
INFO  | ??:??:?? 3 Wanted region 3, using EU_868
DEBUG | ??:??:?? 3 region=3, NODENUM=0xa7604532, dbsize=1
DEBUG | ??:??:?? 3 Read RTC time as 2444
DEBUG | ??:??:?? 3 Running without GPS.
DEBUG | ??:??:?? 3 NeighborInfoModule is disabled
INFO  | ??:??:?? 3 External Notification Module Disabled
INFO  | ??:??:?? 3 Turning on screen
DEBUG | ??:??:?? 3 Module wants a UI Frame
WARN  | ??:??:?? 3 RF95Interface(cs=3, irq=27, rst=15, busy=29)
INFO  | ??:??:?? 3 Starting meshradio init...
DEBUG | ??:??:?? 3 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=0, time 231 ms
DEBUG | ??:??:?? 3 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=253, time 2115 ms
INFO  | ??:??:?? 3 Radio freq=869.525, config.lora.frequency_offset=0.000
INFO  | ??:??:?? 3 Set radio: region=EU_868, name=LongFast, config=0, ch=0, power=27
INFO  | ??:??:?? 3 Radio myRegion->freqStart -> myRegion->freqEnd: 869.400024 -> 869.650024 (0.250000 mhz)
INFO  | ??:??:?? 3 Radio myRegion->numChannels: 1 x 250.000kHz
INFO  | ??:??:?? 3 Radio channel_num: 1
INFO  | ??:??:?? 3 Radio frequency: 869.525024
INFO  | ??:??:?? 3 Slot time: 42 msec
INFO  | ??:??:?? 3 Set radio: final power level=20
DEBUG | ??:??:?? 3 Current limit set to 100.000000
DEBUG | ??:??:?? 3 Current limit set result 0
INFO  | ??:??:?? 3 RF95 init result 0
INFO  | ??:??:?? 3 Frequency set to 869.525024
INFO  | ??:??:?? 3 Bandwidth set to 250.000000
INFO  | ??:??:?? 3 Power output set to 20
INFO  | ??:??:?? 3 RF95 Radio init succeeded, using RF95 radio
DEBUG | ??:??:?? 3 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=237, time 2000 ms
DEBUG | ??:??:?? 3 LoRA bitrate = 118.500000 bytes / sec
INFO  | ??:??:?? 3 PowerFSM init, USB power=1
DEBUG | ??:??:?? 3 Enter state: BOOT
DEBUG | ??:??:?? 3 [Screen] Screen: Started...
INFO  | ??:??:?? 8 [Screen] Done with boot screen...
DEBUG | ??:??:?? 8 [Screen] showing standard frames
DEBUG | ??:??:?? 8 [Screen] Showing 0 module frames
DEBUG | ??:??:?? 8 [Screen] Total frame count: 103
DEBUG | ??:??:?? 8 [Screen] Added modules.  numframes: 0
DEBUG | ??:??:?? 8 [Screen] Finished building frames. numframes: 2
DEBUG | ??:??:?? 8 [Screen] LastScreenTransition exceeded 8751ms transitioning to next frame
DEBUG | ??:??:?? 10 [Screen] LastScreenTransition exceeded 2067ms transitioning to next frame
DEBUG | ??:??:?? 12 [Screen] LastScreenTransition exceeded 2062ms transitioning to next frame
DEBUG | ??:??:?? 14 [Screen] LastScreenTransition exceeded 2067ms transitioning to next frame
DEBUG | ??:??:?? 17 [Screen] LastScreenTransition exceeded 2062ms transitioning to next frame
DEBUG | ??:??:?? 19 [Screen] LastScreenTransition exceeded 2067ms transitioning to next frame
DEBUG | ??:??:?? 21 [Screen] LastScreenTransition exceeded 2062ms transitioning to next frame
DEBUG | ??:??:?? 23 [Screen] LastScreenTransition exceeded 2067ms transitioning to next frame
DEBUG | ??:??:?? 25 [Screen] LastScreenTransition exceeded 2062ms transitioning to next frame
DEBUG | ??:??:?? 27 [Screen] LastScreenTransition exceeded 2067ms transitioning to next frame
DEBUG | ??:??:?? 29 [Screen] LastScreenTransition exceeded 2063ms transitioning to next frame
DEBUG | ??:??:?? 31 [Screen] LastScreenTransition exceeded 2067ms transitioning to next frame
INFO  | ??:??:?? 33 [NodeInfoModule] Sending our nodeinfo to mesh (wantReplies=1)
INFO  | ??:??:?? 33 [NodeInfoModule] sending owner !a7604532/Meshtastic 4532/4532
DEBUG | ??:??:?? 33 [NodeInfoModule] Initial packet id 1882287364, numPacketId 4294967295
DEBUG | ??:??:?? 33 [NodeInfoModule] Update DB node 0xa7604532, rx_time=0, channel=0
DEBUG | ??:??:?? 33 [NodeInfoModule] handleReceived(LOCAL) (id=0x70316d06 fr=0x32 to=0xff, WantAck=0, HopLim=3 Ch=0x0 Portnum=4 WANTRESP priority=10)
DEBUG | ??:??:?? 33 [NodeInfoModule] No modules interested in portnum=4, src=LOCAL
DEBUG | ??:??:?? 33 [NodeInfoModule] localSend to channel 0
DEBUG | ??:??:?? 33 [NodeInfoModule] Add packet record (id=0x70316d06 fr=0x32 to=0xff, WantAck=0, HopLim=3 Ch=0x0 Portnum=4 WANTRESP priority=10)
DEBUG | ??:??:?? 33 [NodeInfoModule] Expanding short PSK #1
DEBUG | ??:??:?? 33 [NodeInfoModule] Using AES128 key!
DEBUG | ??:??:?? 33 [NodeInfoModule] Installing AES128 key!
DEBUG | ??:??:?? 33 [NodeInfoModule] enqueuing for send (id=0x70316d06 fr=0x32 to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted priority=10)
DEBUG | ??:??:?? 33 [NodeInfoModule] txGood=0,rxGood=0,rxBad=0
DEBUG | ??:??:?? 33 [RadioIf] Starting low level send (id=0x70316d06 fr=0x32 to=0xff, WantAck=0, HopLim=3 Ch=0x8 encrypted priority=10)

After that no more lines appears.

If I execute the same command without unplug the USB cable:

Traceback (most recent call last):
  File "meshtastic\__main__.py", line 1373, in <module>
  File "meshtastic\__main__.py", line 1354, in main
  File "meshtastic\__main__.py", line 956, in common
  File "meshtastic\serial_interface.py", line 55, in __init__
  File "serial\serialwin32.py", line 33, in __init__
  File "serial\serialutil.py", line 244, in __init__
  File "serial\serialwin32.py", line 80, in open
  File "serial\serialwin32.py", line 222, in _reconfigure_port
serial.serialutil.SerialException: Cannot configure port, something went wrong. Original message: PermissionError(13, 'Uno de los dispositivos conectados al sistema no funciona.', None, 31)
[2728] Failed to execute script '__main__' due to unhandled exception!

The same "serial issue" is on the Android app via USB cable.

Relevant log output

No response

shodan8192 commented 8 months ago

Hello, I've seen this before, but using RP2040 and SIM7080G LTE-M modem working on B20 band (800MHz). After some transmits, my program still was running but stops printing on USB serial. Capturing USB transmission with Wireshark when this occurred, revealed many of URB errors. It took me a while to figure out whats happening - it was caused by LTE antenna lying close to USB cable and board.

You can try :

Some info from Adafruit :

The RP2040 USB lines are very sensitive to RF noise - that means that if you are using the radio module at full power and you have the antenna near the board, say because you are using a spring-coil or plain-wire antenna, you may see the USB subsystem disconnect or act flaky.

vidalperezbohoyo commented 8 months ago

Ou, thanks! Really good answer. Yes may be for that reason. As soon as I get home I'll try it.
The Usb cable is the typical Xiaomi charger cable. But my antenna is so close to the board and the cable. How much distance should there be between the antenna and the MCU (and usb cable)? As soon as possible reply to this issue with test results.

shodan8192 commented 8 months ago

In my case, distance about 20cm was sufficient, with an omni antenna set a few cm above board plane to not radiate into it.

vidalperezbohoyo commented 8 months ago

Thanks for your help. You were right about everything, I tried lowering the power to 10db and the disconnection no longer occurred. I have also tried putting an aluminum sheet screen at the default 27db and with this screen nothing happens anymore. Clearly it was an interference problem. Thanks again for your help. IMG_20240120_212641

vidalperezbohoyo commented 8 months ago

My goal is to design a pcb that incorporates this assembly and this may become a problem for me. I have to see how to make a pcb that somehow protects the MCU and moves the connector as far away from the antenna as I can move it 4cm away at most...

shodan8192 commented 8 months ago

It's good that we are confident about cause. If setup from your photo works, then it seems like the USB cable is the one picking up most of interference. You can try to wrap this aluminium foil around USB cable to see if it's sufficient.

GUVWAF commented 8 months ago

Glad to hear you figured out what the problem was. This is really useful to know. I opened a PR to the documentation to add this: https://github.com/meshtastic/meshtastic/pull/941

Will close this issue now.

shodan8192 commented 8 months ago

Sorry for messing after closing this, but in the meantime I've made some tests because it was bothered me, and a result is surprising and denying quote from Adafruit which I've wrote earlier :

The RP2040 USB lines are very sensitive to RF noise

I have setup ESP32 + E22-900M30S at 30dBm(1W) + 2.8dBi antenna as a interference source, and Pi Pico running simple counter printing program at 1ms interval as a interference receiver.

20240124_104308

At any distance, including lying right on antenna during transmission, Pi Pico never stopped printing. That was lead me to conclusion that it's not problem with USB data lines as they are differential, twisted pair and any RF noise should be cancelled at USB receiver, but that the power line is affected.

Waveshare RP2040-Zero uses RT9013-33, Adafruit Feather RP2040 RFM95 uses RT9080-33. Looking at their load transient response and rejection ratio at high frequencies it might be possible that when transmission start and additional RF noise is feeded into cable there is a voltage drop on 3.3V line by 0.165V or more. While this not seems too much, the RP2040 datasheet (page 156) state :

USB PHY does not meet specification at voltages below 3.135V

My further tests was to control E22 module from ESP32 but power it from Pico's 3.3V and VSYS. In both cases USB operations were not affected. Pi Pico has buck-boost converter RT6150B-33GQW, which can be much more immune to fast load transients and RF noise.

While I'm not entirely sure for my findings, I think that conclusion and the note for RP2040 based circuits should be that depending on 3.3V line voltage regulator that powers MCU and radio, with proximity of its antenna can cause incorrect USB PHY operation by lowering USB_VDD voltage below 3.135V.

vidalperezbohoyo commented 8 months ago

In my case the antenna was 90 degrees to the usb cable. With the aluminum wrapped around the cable it worked well without covering anything on the plate itself. Is it induced in the 5v cable of the cable USB? The voltage drop could it not have been produced by the Lora consumption of the module itself at the time of transmitting? There is any differences on the usb traces on the rp2040 zero and the pico? Zero is more sensible?

shodan8192 commented 8 months ago

I don't have any of suspected board, but I found my Waveshare RP2040-Plus with SIM7080 modem, which causes me trouble in the past. Tomorrow I'm gonna to power E22 module from RP2040-Plus and try to make interference. I will share all details, results and thoughts.

Regarding your questions, for now I can answer only about Lora current consumption - yes, it can cause voltage drop caused by LDO response to load transients, when transmission start or ends.

shodan8192 commented 8 months ago

I've done test with Waveshare RP2040-Plus, it has TPS63000 buck-boost converter. If it's close to antenna during transmission, like on the picture - USB serial printing stops.

PicoPlus

Voltage on 3V3 line was 3.2V, oscilloscope showed no drops. During second test, when E22 was powered from RP2040-Plus instead of ESP32 result was the same. If antenna lying close to USB cable nothing bad happens. I've tested again original Pi Pico and it also hangs, but only if its bottom layer is faced to antenna and distance is ~2.5cm or less.

None of my boards does not have problem with voltage drops, both has picked up interference by USB traces. My previous thoughts should be revised and tested on RP2040-Zero using oscilloscope to confirm or negate them.