search

meshtastic / firmware

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

[Bug]: MQTT on "Portduino / Linux" Connection Cycles #4240

Open blu006 opened 3 months ago

blu006 commented 3 months ago

Category

Other

Hardware

DIY

Firmware Version

2.3.13.83f5ba0

Description

The MQTT connection configuration on Portduino only works through the Android app, and it continuously connection cycles on the public MQTT server at mqtt.meshtastic.org.

My device is an orangepione.

armbianmonitor -u reports the following:


### lsusb:

Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 005 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

/:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=musb-hdrc/1p, 480M
/:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ohci-platform/1p, 12M
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-platform/1p, 480M

### Group membership of brandon : brandon tty disk dialout sudo audio video plugdev games users systemd-journal input render netdev

### Userland generated with Armbian Build Framework:

PRETTY_NAME="Armbian 24.5.1 bookworm"
ARMBIAN_PRETTY_NAME="Armbian 24.5.1 bookworm"

### Installed packages:

ii  armbian-bsp-cli-orangepione-current 24.5.1                         armhf        Armbian CLI BSP for board 'orangepione' branch 'current'
ii  armbian-firmware                    24.5.1                         all          Armbian - Linux firmware
ii  linux-base                          4.9                            all          Linux image base package
ii  linux-dtb-current-sunxi             24.5.1                         armhf        Armbian Linux current DTBs in /boot/dtb-6.6.31-current-sunxi
ii  linux-image-current-sunxi           24.5.1                         armhf        Armbian Linux current kernel image 6.6.31-current-sunxi
ii  linux-libc-dev:armhf                6.1.94-1                       armhf        Linux support headers for userspace development
ii  linux-u-boot-orangepione-current    24.5.1                         armhf        Das U-Boot for orangepione

### Loaded modules:

Module                  Size  Used by
pps_ldisc              16384  2
bluetooth             528384  10
ecdh_generic           12288  1 bluetooth
ecc                    24576  1 ecdh_generic
rfkill                 20480  2 bluetooth
snd_soc_hdmi_codec     16384  1
lz4hc                  12288  0
sunxi_cedrus           40960  0
v4l2_mem2mem           20480  1 sunxi_cedrus
sun9i_hdmi_audio       12288  0
sun4i_gpadc_iio        12288  0
lima                   49152  0
lz4                    12288  0
videobuf2_dma_contig    16384  1 sunxi_cedrus
industrialio           57344  1 sun4i_gpadc_iio
gpu_sched              28672  1 lima
videobuf2_memops       16384  1 videobuf2_dma_contig
dw_hdmi_i2s_audio      12288  0
dw_hdmi_cec            12288  0
videobuf2_v4l2         16384  2 sunxi_cedrus,v4l2_mem2mem
drm_shmem_helper       12288  1 lima
sun8i_thermal          12288  0
videodev              184320  3 sunxi_cedrus,v4l2_mem2mem,videobuf2_v4l2
videobuf2_common       45056  5 sunxi_cedrus,videobuf2_dma_contig,videobuf2_memops,v4l2_mem2mem,videobuf2_v4l2
mc                     36864  5 sunxi_cedrus,videobuf2_common,videodev,v4l2_mem2mem,videobuf2_v4l2
display_connector      16384  0
pps_gpio               12288  2
cpufreq_dt             16384  0
binfmt_misc            16384  1
evdev                  16384  0
uio_pdrv_genirq        16384  0
uio                    16384  1 uio_pdrv_genirq
zram                   20480  3
dm_mod                 98304  0
ip_tables              20480  0
x_tables               24576  1 ip_tables
autofs4                36864  2
spidev                 16384  10
sunxi                  12288  0
phy_generic            16384  2 sunxi
gpio_keys              16384  0
ac200_phy              12288  1

### Current system health:

Time        CPU    load %cpu %sys %usr %nice %io %irq   Tcpu  C.St.
03:01:50  1296 MHz  0.02   2%   1%   1%   0%   0%   0%  48.8 °C  0/7
03:01:50  1296 MHz  0.02   4%   3%   0%   0%   0%   0%  49.0 °C  0/7
03:01:51  1296 MHz  0.02   4%   2%   0%   1%   0%   0%  47.8 °C  0/7
03:01:51  1296 MHz  0.02   4%   2%   0%   2%   0%   0%  47.3 °C  0/7
03:01:51  1296 MHz  0.02   4%   3%   0%   0%   0%   0%  46.5 °C  0/7
03:01:52   648 MHz  0.02   2%   1%   1%   0%   0%   0%  47.7 °C  0/7
03:01:52  1296 MHz  0.02   5%   4%   0%   0%   0%   0%  50.4 °C  0/7
03:01:53  1296 MHz  0.02   4%   4%   0%   0%   0%   0%  48.5 °C  0/7
03:01:53  1296 MHz  0.02   4%   4%   0%   0%   0%   0%  51.2 °C  0/7
03:01:53  1296 MHz  0.02   4%   2%   0%   1%   0%   0%  48.5 °C  0/7

### resolv.conf

-rw-r--r-- 1 root root 66 Jul  5 02:17 /etc/resolv.conf
# Generated by NetworkManager
search maglab
nameserver XXX.XXX.0.1

### Current sysinfo:

Linux 6.6.31-current-sunxi (george)     07/06/2024  _armv7l_    (4 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.04    0.00    1.17    0.02    0.00   97.76

Device             tps    kB_read/s    kB_wrtn/s    kB_dscd/s    kB_read    kB_wrtn    kB_dscd
ram0              0.00         0.00         0.00         0.00          0          0          0
ram1              0.00         0.00         0.00         0.00          0          0          0
ram2              0.00         0.00         0.00         0.00          0          0          0
ram3              0.00         0.00         0.00         0.00          0          0          0
mmcblk0           0.40         9.72         9.42         0.00     866221     839792          0
mmcblk0p1         0.40         9.69         9.42         0.00     863765     839792          0
zram0             0.35         0.58         0.84         0.00      51592      75268          0
zram1             0.33         0.04         1.90         0.00       3228     169768          0
zram2             0.00         0.00         0.00         0.00          0          0          0

--procs-- -----------------------memory---------------------- ---swap-- -----io---- -system-- ----------cpu----------
   r    b         swpd         free         buff        cache   si   so    bi    bo   in   cs  us  sy  id  wa  st  gu
   1    0         9216       123552        17448       252260    0    0     3     3   79   99   1   1  98   0   0   0

               total        used        free      shared  buff/cache   available
Mem:           490Mi       123Mi       120Mi       5.3Mi       263Mi       367Mi
Swap:          245Mi       9.0Mi       236Mi

NAME       ALGORITHM DISKSIZE  DATA  COMPR TOTAL STREAMS MOUNTPOINT
/dev/zram0 lzo-rle     245.3M  8.6M   3.1M  5.2M       4 [SWAP]
/dev/zram1 zstd           50M  7.2M 841.2K  1.6M       4 /var/log

 03:01:54 up 1 day, 45 min,  5 users,  load average: 0.02, 0.05, 0.00

[    1.686416] ehci-platform 1c1a000.usb: new USB bus registered, assigned bus number 1
[    1.686486] ehci-platform 1c1b000.usb: EHCI Host Controller
[    1.686520] ehci-platform 1c1b000.usb: new USB bus registered, assigned bus number 2
[    1.686612] sunxi-mmc 1c0f000.mmc: Got CD GPIO
[    1.687829] ohci-platform 1c1a400.usb: Generic Platform OHCI controller
[    1.687872] ohci-platform 1c1a400.usb: new USB bus registered, assigned bus number 3
[    1.688164] ohci-platform 1c1b400.usb: Generic Platform OHCI controller
[    1.688200] ohci-platform 1c1b400.usb: new USB bus registered, assigned bus number 4
[    1.688315] ohci-platform 1c1a400.usb: irq 147, io mem 0x01c1a400
[    1.688364] of_cfs_init
[    1.688494] of_cfs_init: OK
[    1.688567] clk: Disabling unused clocks
[    1.688700] ALSA device list:
[    1.688713]   No soundcards found.
[    1.689244] ohci-platform 1c1b400.usb: irq 148, io mem 0x01c1b400
[    1.689440] ehci-platform 1c1a000.usb: irq 145, io mem 0x01c1a000
[    1.689568] ehci-platform 1c1b000.usb: irq 146, io mem 0x01c1b000
[    1.706890] ehci-platform 1c1a000.usb: USB 2.0 started, EHCI 1.00
[    1.707282] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06
[    1.707300] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.707313] usb usb1: Product: EHCI Host Controller
[    1.707324] usb usb1: Manufacturer: Linux 6.6.31-current-sunxi ehci_hcd
[    1.707336] usb usb1: SerialNumber: 1c1a000.usb
[    1.708041] hub 1-0:1.0: USB hub found
[    1.708112] hub 1-0:1.0: 1 port detected
[    1.710897] sunxi-mmc 1c0f000.mmc: initialized, max. request size: 16384 KB
[    1.722885] ehci-platform 1c1b000.usb: USB 2.0 started, EHCI 1.00
[    1.723338] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06
[    1.723358] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.723371] usb usb2: Product: EHCI Host Controller
[    1.723382] usb usb2: Manufacturer: Linux 6.6.31-current-sunxi ehci_hcd
[    1.723393] usb usb2: SerialNumber: 1c1b000.usb
[    1.723981] hub 2-0:1.0: USB hub found
[    1.724043] hub 2-0:1.0: 1 port detected
[    1.751230] usb usb4: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.06
[    1.751254] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.751268] usb usb4: Product: Generic Platform OHCI controller
[    1.751279] usb usb4: Manufacturer: Linux 6.6.31-current-sunxi ohci_hcd
[    1.751290] usb usb4: SerialNumber: 1c1b400.usb
[    1.751937] hub 4-0:1.0: USB hub found
[    1.752004] hub 4-0:1.0: 1 port detected
[    1.752694] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 6.06
[    1.752713] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.752726] usb usb3: Product: Generic Platform OHCI controller
[    1.752737] usb usb3: Manufacturer: Linux 6.6.31-current-sunxi ohci_hcd
[    1.752748] usb usb3: SerialNumber: 1c1a400.usb
[    1.753362] hub 3-0:1.0: USB hub found
[    1.753434] hub 3-0:1.0: 1 port detected
[    1.760850] mmc0: host does not support reading read-only switch, assuming write-enable
[    1.762311] Freeing unused kernel image (initmem) memory: 1024K
[    1.762607] Run /init as init process
[    1.762620]   with arguments:
[    1.762630]     /init
[    1.762638]   with environment:
[    1.762646]     HOME=/
[    1.762654]     TERM=linux
[    1.762662]     splash=verbose
[    1.762670]     ubootpart=55a49b3e-01
[    1.762678]     ubootsource=mmc
[    1.762686]     sunxi_ve_mem_reserve=0
[    1.762694]     sunxi_g2d_mem_reserve=0
[    1.762703]     sunxi_fb_mem_reserve=16
[    1.762711]     cgroup_enable=memory
[    1.764091] mmc0: new high speed SDHC card at address aaaa
[    1.766082] mmcblk0: mmc0:aaaa SA32G 29.7 GiB
[    1.770487]  mmcblk0: p1
[    2.340624] input: gpio-keys as /devices/platform/gpio-keys/input/input0
[    2.401461] usb_phy_generic usb_phy_generic.3.auto: dummy supplies not allowed for exclusive requests
[    2.428014] musb-hdrc musb-hdrc.4.auto: MUSB HDRC host driver
[    2.428068] musb-hdrc musb-hdrc.4.auto: new USB bus registered, assigned bus number 5
[    2.429619] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06
[    2.429660] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.429675] usb usb5: Product: MUSB HDRC host driver
[    2.429687] usb usb5: Manufacturer: Linux 6.6.31-current-sunxi musb-hcd
[    2.429700] usb usb5: SerialNumber: musb-hdrc.4.auto
[    2.431674] hub 5-0:1.0: USB hub found
[    2.432559] hub 5-0:1.0: 1 port detected
[    2.475188] dwmac-sun8i 1c30000.ethernet end0: renamed from eth0
[    2.764478] EXT4-fs (mmcblk0p1): mounted filesystem 6bebeb07-080a-4548-99d8-fe3bb00a5ecc ro with writeback data mode. Quota mode: none.
[    3.533547] systemd[1]: Inserted module 'autofs4'
[    3.585748] systemd[1]: systemd 252.22-1~deb12u1 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[    3.585803] systemd[1]: Detected architecture arm.
[    3.603128] systemd[1]: Hostname set to <george>.
[    4.251714] systemd[1]: /lib/systemd/system/telegraf.service:12: Unknown key name 'ImportCredential' in section 'Service', ignoring.
[    4.708364] systemd[1]: Queued start job for default target graphical.target.
[    4.733356] systemd[1]: Created slice system-getty.slice - Slice /system/getty.
[    4.737054] systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe.
[    4.740378] systemd[1]: Created slice system-serial-getty.slice - Slice /system/serial-getty.
[    4.742499] systemd[1]: Created slice user.slice - User and Session Slice.
[    4.743480] systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch.
[    4.744204] systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch.
[    4.745857] systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point.
[    4.746339] systemd[1]: Expecting device dev-ttyS0.device - /dev/ttyS0...
[    4.746761] systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes.
[    4.747395] systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes.
[    4.748041] systemd[1]: Reached target paths.target - Path Units.
[    4.748553] systemd[1]: Reached target remote-fs.target - Remote File Systems.
[    4.748924] systemd[1]: Reached target slices.target - Slice Units.
[    4.749420] systemd[1]: Reached target swap.target - Swaps.
[    4.749817] systemd[1]: Reached target time-set.target - System Time Set.
[    4.750801] systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes.
[    4.752336] systemd[1]: Listening on syslog.socket - Syslog Socket.
[    4.753543] systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket.
[    4.754352] systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe.
[    4.756403] systemd[1]: Listening on systemd-journald-audit.socket - Journal Audit Socket.
[    4.757724] systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log).
[    4.759081] systemd[1]: Listening on systemd-journald.socket - Journal Socket.
[    4.762072] systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket.
[    4.763438] systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket.
[    4.764711] systemd[1]: dev-hugepages.mount - Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages).
[    4.787449] systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System...
[    4.794615] systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System...
[    4.802748] systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System...
[    4.815685] systemd[1]: Starting fake-hwclock.service - Restore / save the current clock...
[    4.825801] systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout...
[    4.834806] systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes...
[    4.844481] systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs...
[    4.854640] systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod...
[    4.865564] systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm...
[    4.877223] systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore...
[    4.888135] systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse...
[    4.898406] systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop...
[    4.899735] systemd[1]: systemd-fsck-root.service - File System Check on Root Device was skipped because of an unmet condition check (ConditionPathExists=!/run/initramfs/fsck-root).
[    4.923584] device-mapper: uevent: version 1.0.3
[    4.924636] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com
[    4.927743] systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules...
[    4.936910] systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems...
[    4.947212] systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices...
[    4.966732] systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System.
[    4.968532] systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System.
[    4.970028] systemd[1]: Mounted sys-kernel-tracing.mount - Kernel Trace File System.
[    4.972706] systemd[1]: Finished fake-hwclock.service - Restore / save the current clock.
[    4.975847] systemd[1]: Finished kmod-static-nodes.service - Create List of Static Device Nodes.
[    4.979381] systemd[1]: modprobe@configfs.service: Deactivated successfully.
[    4.980941] systemd[1]: Finished modprobe@configfs.service - Load Kernel Module configfs.
[    4.984569] systemd[1]: modprobe@dm_mod.service: Deactivated successfully.
[    4.986202] systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod.
[    4.990049] systemd[1]: modprobe@drm.service: Deactivated successfully.
[    4.991568] systemd[1]: Finished modprobe@drm.service - Load Kernel Module drm.
[    4.995281] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
[    4.997057] systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore.
[    5.000595] systemd[1]: modprobe@fuse.service: Deactivated successfully.
[    5.002050] systemd[1]: Finished modprobe@fuse.service - Load Kernel Module fuse.
[    5.006272] systemd[1]: modprobe@loop.service: Deactivated successfully.
[    5.007545] systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop.
[    5.009995] systemd[1]: Finished systemd-modules-load.service - Load Kernel Modules.
[    5.029832] EXT4-fs (mmcblk0p1): re-mounted 6bebeb07-080a-4548-99d8-fe3bb00a5ecc r/w. Quota mode: none.
[    5.043563] systemd[1]: Mounting sys-fs-fuse-connections.mount - FUSE Control File System...
[    5.051071] systemd[1]: Mounting sys-kernel-config.mount - Kernel Configuration File System...
[    5.052016] systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met.
[    5.060736] systemd[1]: Starting systemd-sysctl.service - Apply Kernel Variables...
[    5.073272] systemd[1]: Finished systemd-remount-fs.service - Remount Root and Kernel File Systems.
[    5.084850] systemd[1]: Mounted sys-fs-fuse-connections.mount - FUSE Control File System.
[    5.086176] systemd[1]: Mounted sys-kernel-config.mount - Kernel Configuration File System.
[    5.088065] systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
[    5.096362] systemd[1]: Starting systemd-random-seed.service - Load/Save Random Seed...
[    5.105589] systemd[1]: Starting systemd-sysusers.service - Create System Users...
[    5.148577] systemd[1]: Finished systemd-sysctl.service - Apply Kernel Variables.
[    5.203518] systemd[1]: Finished systemd-sysusers.service - Create System Users.
[    5.228062] systemd[1]: Starting systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev...
[    5.321377] systemd[1]: Finished systemd-tmpfiles-setup-dev.service - Create Static Device Nodes in /dev.
[    5.351867] systemd[1]: Starting systemd-udevd.service - Rule-based Manager for Device Events and Files...
[    5.387299] systemd[1]: Finished keyboard-setup.service - Set the console keyboard layout.
[    5.388671] systemd[1]: Reached target local-fs-pre.target - Preparation for Local File Systems.
[    5.407438] systemd[1]: Mounting tmp.mount - /tmp...
[    5.424042] systemd[1]: Mounted tmp.mount - /tmp.
[    5.425781] systemd[1]: Reached target local-fs.target - Local File Systems.
[    5.437579] systemd[1]: Starting armbian-zram-config.service - Armbian ZRAM config...
[    5.446819] systemd[1]: Starting console-setup.service - Set console font and keymap...
[    5.469905] systemd[1]: Starting systemd-binfmt.service - Set Up Additional Binary Formats...
[    5.511327] systemd[1]: Finished console-setup.service - Set console font and keymap.
[    5.513843] systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 297 (systemd-binfmt)
[    5.595948] systemd[1]: Finished systemd-udev-trigger.service - Coldplug All udev Devices.
[    5.673625] systemd[1]: Started systemd-udevd.service - Rule-based Manager for Device Events and Files.
[    5.887145] zram: Added device: zram0
[    5.971803] zram: Added device: zram1
[    5.995915] zram: Added device: zram2
[    6.019585] systemd[1]: Mounting proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System...
[    6.045978] systemd[1]: Found device dev-ttyS0.device - /dev/ttyS0.
[    6.121823] systemd[1]: Mounted proc-sys-fs-binfmt_misc.mount - Arbitrary Executable File Formats File System.
[    6.182970] random: crng init done
[    6.204227] systemd[1]: Finished systemd-binfmt.service - Set Up Additional Binary Formats.
[    6.252667] zram0: detected capacity change from 0 to 502296
[    6.273715] systemd[1]: Finished systemd-random-seed.service - Load/Save Random Seed.
[    6.281084] pps pps0: new PPS source pps@0.-1
[    6.281198] pps pps0: Registered IRQ 47 as PPS source
[    6.290327] systemd[1]: first-boot-complete.target - First Boot Complete was skipped because of an unmet condition check (ConditionFirstBoot=yes).
[    6.290709] systemd[1]: systemd-machine-id-commit.service - Commit a transient machine-id on disk was skipped because of an unmet condition check (ConditionPathIsMountPoint=/etc/machine-id).
[    6.329825] Adding 251144k swap on /dev/zram0.  Priority:5 extents:1 across:251144k SS
[    6.379496] mc: Linux media interface: v0.10
[    6.428303] systemd[1]: Reached target usb-gadget.target - Hardware activated USB gadget.
[    6.464793] videodev: Linux video capture interface: v2.00
[    6.524031] lima 1c40000.gpu: gp - mali400 version major 1 minor 1
[    6.524142] lima 1c40000.gpu: pp0 - mali400 version major 1 minor 1
[    6.524220] lima 1c40000.gpu: pp1 - mali400 version major 1 minor 1
[    6.524264] lima 1c40000.gpu: l2 cache 64K, 4-way, 64byte cache line, 64bit external bus
[    6.527095] lima 1c40000.gpu: bus rate = 200000000
[    6.527129] lima 1c40000.gpu: mod rate = 297000000
[    6.527790] lima 1c40000.gpu: Failed to register cooling device
[    6.535240] [drm] Initialized lima 1.1.0 20191231 for 1c40000.gpu on minor 1
[    6.543348] sunxi_cedrus: module is from the staging directory, the quality is unknown, you have been warned.
[    6.556852] cedrus 1c0e000.video-codec: Device registered as /dev/video0
[    6.750210] zram1: detected capacity change from 0 to 102400
[    6.867785] systemd[1]: Finished armbian-zram-config.service - Armbian ZRAM config.
[    6.869393] systemd[1]: dev-hugepages.mount - Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages).
[    6.896388] systemd[1]: Starting armbian-ramlog.service - Armbian memory supported logging...
[    6.909534] systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod...
[    6.920647] systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore...
[    6.930425] systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop...
[    6.931562] systemd[1]: systemd-machine-id-commit.service - Commit a transient machine-id on disk was skipped because of an unmet condition check (ConditionPathIsMountPoint=/etc/machine-id).
[    6.947344] systemd[1]: modprobe@dm_mod.service: Deactivated successfully.
[    6.948540] systemd[1]: Finished modprobe@dm_mod.service - Load Kernel Module dm_mod.
[    6.951716] systemd[1]: modprobe@efi_pstore.service: Deactivated successfully.
[    6.952847] systemd[1]: Finished modprobe@efi_pstore.service - Load Kernel Module efi_pstore.
[    6.955892] systemd[1]: modprobe@loop.service: Deactivated successfully.
[    6.957075] systemd[1]: Finished modprobe@loop.service - Load Kernel Module loop.
[    6.958920] systemd[1]: systemd-pstore.service - Platform Persistent Storage Archival was skipped because of an unmet condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
[    6.959213] systemd[1]: systemd-repart.service - Repartition Root Disk was skipped because no trigger condition checks were met.
[    6.992795] EXT4-fs (zram1): mounted filesystem 6257b51e-a1f1-4ab4-ba62-acaa38412231 r/w without journal. Quota mode: none.
[    9.767997] systemd[1]: Finished armbian-ramlog.service - Armbian memory supported logging.
[    9.808549] systemd[1]: Starting systemd-journald.service - Journal Service...
[   10.076493] systemd[1]: Started systemd-journald.service - Journal Service.
[   10.138815] systemd-journald[426]: Received client request to flush runtime journal.
[   12.091111] systemd-journald[426]: Received client request to relinquish /var/log/journal/ee970e1fd2e548b38b64075e8d9096ba access.
[   16.095134] Bluetooth: Core ver 2.22
[   16.095312] NET: Registered PF_BLUETOOTH protocol family
[   16.095327] Bluetooth: HCI device and connection manager initialized
[   16.095356] Bluetooth: HCI socket layer initialized
[   16.095369] Bluetooth: L2CAP socket layer initialized
[   16.095396] Bluetooth: SCO socket layer initialized
[   16.205552] dwmac-sun8i 1c30000.ethernet end0: Register MEM_TYPE_PAGE_POOL RxQ-0
[   16.273968] dwmac-sun8i 1c30000.ethernet end0: PHY [mdio_mux-0.1:01] driver [Allwinner AC200 EPHY] (irq=POLL)
[   16.274025] dwmac-sun8i 1c30000.ethernet end0: No Safety Features support found
[   16.274041] dwmac-sun8i 1c30000.ethernet end0: No MAC Management Counters available
[   16.274052] dwmac-sun8i 1c30000.ethernet end0: PTP not supported by HW
[   16.274688] dwmac-sun8i 1c30000.ethernet end0: configuring for phy/mii link mode
[   16.646555] pps_ldisc: PPS line discipline registered
[   16.648394] pps pps1: new PPS source serial3
[   16.648463] pps pps1: source "/dev/ttyS3" added
[   19.353180] dwmac-sun8i 1c30000.ethernet end0: Link is Up - 100Mbps/Full - flow control off
[   24.509779] systemd-journald[426]: Time jumped backwards, rotating.
[   28.133901] systemd[1062]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
[39525.769180] systemd-journald[426]: Data hash table of /run/log/journal/ee970e1fd2e548b38b64075e8d9096ba/system.journal has a fill level at 75.1 (1537 of 2047 items, 643072 file size, 418 bytes per hash table item), suggesting rotation.
[39525.769296] systemd-journald[426]: /run/log/journal/ee970e1fd2e548b38b64075e8d9096ba/system.journal: Journal header limits reached or header out-of-date, rotating.
[78229.443263] systemd-journald[426]: Received client request to flush runtime journal.
[78230.456406] systemd-journald[426]: Rotating system journal.
[78231.540696] systemd-journald[426]: Received client request to relinquish /var/log/journal/ee970e1fd2e548b38b64075e8d9096ba access.
[79133.982355] systemd-journald[426]: Received client request to flush runtime journal.
[79134.339890] systemd-journald[426]: Rotating system journal.
[79135.440776] systemd-journald[426]: Received client request to relinquish /var/log/journal/ee970e1fd2e548b38b64075e8d9096ba access.

vm.admin_reserve_kbytes = 8192
vm.compaction_proactiveness = 20
vm.compact_unevictable_allowed = 1
vm.dirty_background_bytes = 0
vm.dirty_background_ratio = 10
vm.dirty_bytes = 0
vm.dirty_expire_centisecs = 3000
vm.dirty_ratio = 20
vm.dirtytime_expire_seconds = 43200
vm.dirty_writeback_centisecs = 500
vm.extfrag_threshold = 500
vm.highmem_is_dirtyable = 0
vm.laptop_mode = 0
vm.legacy_va_layout = 0
vm.lowmem_reserve_ratio = 32    0   0
vm.max_map_count = 65530
vm.memfd_noexec = 0
vm.min_free_kbytes = 2802
vm.mmap_min_addr = 4096
vm.mmap_rnd_bits = 8
vm.oom_dump_tasks = 1
vm.oom_kill_allocating_task = 0
vm.overcommit_kbytes = 0
vm.overcommit_memory = 0
vm.overcommit_ratio = 50
vm.page-cluster = 0
vm.page_lock_unfairness = 5
vm.panic_on_oom = 0
vm.percpu_pagelist_high_fraction = 0
vm.stat_interval = 1
vm.swappiness = 100
vm.user_reserve_kbytes = 15173
vm.vfs_cache_pressure = 100
vm.watermark_boost_factor = 15000
vm.watermark_scale_factor = 10

### interrupts:
           CPU0       CPU1       CPU2       CPU3       
 25:          0          0          0          0     GICv2  50 Level     timer@1c20c00
 26:          0          0          0          0     GICv2  29 Level     arch_timer
 27:    5146509    4880128    4555013    4278135     GICv2  30 Level     arch_timer
 30:          0          0          0          0     GICv2 152 Level     arm-pmu
 31:          0          0          0          0     GICv2 153 Level     arm-pmu
 32:          0          0          0          0     GICv2 154 Level     arm-pmu
 33:          0          0          0          0     GICv2 155 Level     arm-pmu
 34:          4          0          0          0     GICv2  82 Level     1c02000.dma-controller
 35:    1013729          0          0          0     GICv2 114 Level     end0
 36:          0          0          0          0  sun6i-r-intc  40 Level     1f00000.rtc
 37:          0          0          0          0     GICv2 126 Level     sun8i-ce-ns
 47:      89132          0          0          0  sunxi_pio_edge   6 Edge      pps@0.-1
 85:          1          0          0          0  sunxi_pio_edge  44 Edge      usb0-id-det
109:          1          0          0          0  sunxi_pio_edge   3 Edge      sw4
138:          5          0          0          0     GICv2  32 Level     ttyS0
139:    1305651          0          0          0     GICv2  35 Level     ttyS3
140:          0          0          0          0     GICv2 118 Level     1c0c000.lcd-controller
141:          0          0          0          0     GICv2 119 Level     1c0d000.lcd-controller
142:          0          0          0          0     GICv2 120 Level     1ee0000.hdmi, dw-hdmi-cec
143:      62010          0          0          0     GICv2  97 Level     sun6i-spi
144:     184123          0          0          0     GICv2  92 Level     sunxi-mmc
145:          0          0          0          0     GICv2 104 Level     ehci_hcd:usb1
146:          0          0          0          0     GICv2 106 Level     ehci_hcd:usb2
147:          0          0          0          0     GICv2 105 Level     ohci_hcd:usb3
148:          0          0          0          0     GICv2 107 Level     ohci_hcd:usb4
149:          0          0          0          0     GICv2 103 Level     musb-hdrc.4.auto
150:     356743          0          0          0     GICv2  63 Level     ths
152:          0          0          0          0     GICv2 130 Level     gpmmu
153:          0          0          0          0     GICv2 132 Level     ppmmu0
154:          0          0          0          0     GICv2 135 Level     ppmmu1
155:          0          0          0          0     GICv2 129 Level     gp
156:          0          0          0          0     GICv2 131 Level     pp0
157:          0          0          0          0     GICv2 134 Level     pp1
158:          0          0          0          0     GICv2  90 Level     1c0e000.video-codec
IPI0:          0          0          0          0  CPU wakeup interrupts
IPI1:          0          0          0          0  Timer broadcast interrupts
IPI2:      55391      66132      59732      60189  Rescheduling interrupts
IPI3:    1201669    1627568    1432153    1533509  Function call interrupts
IPI4:          0          0          0          0  CPU stop interrupts
IPI5:      76391      83327      83979      73725  IRQ work interrupts
IPI6:          0          0          0          0  completion interrupts
Err:          0

My meshtasticd configuration is this:

### Define your devices here using Broadcom pin numbering
### Uncomment the block that corresponds to your hardware
### Including the "Module:" line!
---
Lora:
#  Module: sx1262  # Waveshare SX126X XXXM
#  DIO2_AS_RF_SWITCH: true
#  CS: 21
#  IRQ: 16
#  Busy: 20
#  Reset: 18

#  Module: sx1262  # Waveshare SX1302 LISTEN ONLY AT THIS TIME!
#  CS: 7
#  IRQ: 17
#  Reset: 22

#  Module: sx1262  # pinedio
#  CS: 0
#  IRQ: 10
#  Busy: 11
#  spidev: spidev0.1

#  Module: RF95  # Adafruit RFM9x
#  Reset: 25
#  CS: 7
#  IRQ: 22
#  Busy: 23

  Module: RF95  # Elecrow Lora RFM95 IOT https://www.elecrow.com/lora-rfm95-iot-board-for-rpi.html
  Reset: 2
  CS: 7
  IRQ: 21

#  Module: sx1280  # SX1280
#  CS: 21
#  IRQ: 16
#  Busy: 20
#  Reset: 18

#  Module: sx1268  # SX1268-based modules, tested with Ebyte E22 400M33S
#  CS: 21
#  IRQ: 16
#  Busy: 20
#  Reset: 18
#  TXen: 6
#  RXen: 12
#  DIO3_TCXO_VOLTAGE: true

#  DIO3_TCXO_VOLTAGE: true  # the Waveshare Core1262 and others are known to need this setting

#  TXen: x  # TX and RX enable pins
#  RXen: x

#  ch341_quirk: true # Uncomment this to use the chunked SPI transfer that seems to fix the ch341

### Set gpio chip to use in /dev/. Defaults to 0.
### Notably the Raspberry Pi 5 puts the GPIO header on gpiochip4
#  gpiochip: 4

### Specify the SPI device to use in /dev/. Defaults to spidev0.0
### Some devices, like the pinedio, may require spidev0.1 as a workaround.
#  spidev: spidev0.0

### Define GPIO buttons here:

GPIO:
#  User: 6

### Define GPS

GPS:
#  SerialPath: /dev/ttyS0

### Specify I2C device, or leave blank for none

I2C:
#  I2CDevice: /dev/i2c-1

### Set up SPI displays here. Note that I2C displays are generally auto-detected.

Display:

### Waveshare 2.8inch RPi LCD
#  Panel: ST7789
#  CS: 8
#  DC: 22        # Data/Command pin
#  Backlight: 18
#  Width: 240
#  Height: 320
#  Reset: 27
#  Rotate: true
#  Invert: true

### Waveshare 1.44inch LCD HAT
#  Panel: ST7735S
#  CS: 8         #Chip Select
#  DC: 25        # Data/Command pin
#  Backlight: 24
#  Width: 128
#  Height: 128
#  Reset: 27
#  OffsetX: 0
#  OffsetY: 0

### Adafruit PiTFT 2.8 TFT+Touchscreen
#  Panel: ILI9341
#  CS: 8
#  DC: 25
#  Width: 240
#  Height: 320
#  Rotate: true

Touchscreen:
### Note, at least for now, the touchscreen must have a CS pin defined, even if you let Linux manage the CS switching.

#  Module: STMPE610 # Option 1 for Adafruit PiTFT 2.8
#  CS: 7
#  IRQ: 24

#  Module: FT5x06 # Option 2 for Adafruit PiTFT 2.8
#  IRQ: 24
#  I2CAddr: 0x38

#  Module: XPT2046 # Waveshare 2.8inch
#  CS: 7
#  IRQ: 17

### Configure device for direct keyboard input

Input:
#  KeyboardDevice: /dev/input/by-id/usb-_Raspberry_Pi_Internal_Keyboard-event-kbd

###

Logging:
  LogLevel: debug # debug, info, warn, error

Webserver:
  Port: 443 # Port for Webserver & Webservices
  RootPath: /usr/share/doc/meshtasticd/web # Root Dir of WebServer

General:
  MaxNodes: 200

My MQTT configuration page looks like this: Screenshot_20240706-023824

I found the issue through a combination of reading the logs and meshexplorer. Meshexplorer toggles my node's online / offline status very quickly. Here are some of the logs from systemd:

Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 11 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 11 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 11 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 12 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 12 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 12 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 12 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 12 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 12 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 13 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 14 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 14 [mqtt] MQTT connected
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 14 [mqtt] published online=1
Jul 06 02:51:07 george meshtasticd[17641]: INFO  | ??:??:?? 14 [mqtt] Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, passw>

Relevant log output

No response

blu006 commented 3 months ago

If needed, I can also provide the schematic and design files between the OPi one and my RFM95, but I don't think those are necessary for this software issue.

jp-bennett commented 3 months ago

Looks like pubSub.loop() at https://github.com/meshtastic/firmware/blob/master/src/mqtt/MQTT.cpp#L413 is always returning false, even though it should be connected. Very possibly an issue with Portduino's fake WiFiClient implementation.

blu006 commented 3 months ago

I guess I could set up a vscode environment with platform io, place a debug statement, and try to crosscompile for armhf...

it also seems like good practice to put just a few more debugging printouts into the mqtt code so that we know what's going on

jp-bennett commented 3 months ago

@blu006 You could open a PR with some reasonable debug calls added. The CI will push out armhf and arm64 builds.

blu006 commented 3 months ago

@jp-bennett it seems to be as you expected (not surprised)

Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 96 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: MQTT connected
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 96 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: published online=1
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: DEBUG | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: Reconnecting MQTT because the PubSub loop returned false
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: MQTT connected
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: published online=1
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: DEBUG | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: Reconnecting MQTT because the PubSub loop returned false
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: MQTT connected
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: 
Jul 06 15:13:55 george meshtasticd[25790]: INFO  | ??:??:?? 97 [mqtt] 
Jul 06 15:13:55 george meshtasticd[25790]: published online=1
Jul 06 15:13:55 george meshtasticd[25790]:
jp-bennett commented 3 months ago

@blu006 We might be able to query pubsub's state() call to get the reason, as per https://pubsubclient.knolleary.net/api#state

blu006 commented 3 months ago

@jp-bennett I get some interesting results from this. It still looks like it's definitely a fake wifi issue. I'm wondering how the portduino code for all of this looks. 

Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: DEBUG | ??:??:?? 20 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: Reconnecting MQTT because the PubSub loop returned false:-3
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: INFO  | ??:??:?? 20 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: INFO  | ??:??:?? 20 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: MQTT connected
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: INFO  | ??:??:?? 20 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: published online=1
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: DEBUG | ??:??:?? 21 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: Reconnecting MQTT because the PubSub loop returned false:-3
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: INFO  | ??:??:?? 21 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: INFO  | ??:??:?? 21 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: MQTT connected
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: 
Jul 06 16:29:58 george meshtasticd[26864]: INFO  | ??:??:?? 21 [mqtt] 
Jul 06 16:29:58 george meshtasticd[26864]: published online=1
Jul 06 16:29:58 george meshtasticd[26864]:
Talie5in commented 3 months ago

@blu006 Part of your Issue says only Android can configure.

Is this meaning iOS App can't? What about the web client?

blu006 commented 3 months ago

@blu006 Part of your Issue says only Android can configure.

Is this meaning iOS App can't? What about the web client?

I could not configure it on the web client.

I do not have iOS

jp-bennett commented 2 months ago

@blu006 It looks to me like https://github.com/knolleary/pubsubclient/blob/2d228f2f862a95846c65a8518c79f48dfc8f188c/src/PubSubClient.cpp#L684 calls https://github.com/meshtastic/WiFi/blob/b885b9595d54ee6eae59696eeae98f631eb27a23/src/WiFiClient.cpp#L171 which is the spot in the fake wifi code that is returning not connected. Possibly related to https://github.com/meshtastic/WiFi/pull/1

My working theory is that on native, we loop through the MQTT check so fast, we're pulling all the bits from the socket, and the logic there is faulty when there are no bytes waiting to be read.

maybe addressed with https://github.com/meshtastic/WiFi/pull/2

blu006 commented 2 months ago

@jp-bennett I'm still looking for some way to cross-compile everything without the limitations from GitHub actions 😵‍💫

Is there a docker image that I can run under qemu or anything like that?

jp-bennett commented 2 months ago

@jp-bennett I'm still looking for some way to cross-compile everything without the limitations from GitHub actions 😵‍💫

Is there a docker image that I can run under qemu or anything like that

I'm sure there are ways. I've just been compiling on an arm32 install on a modern Pi. I'll see about getting a test build for you to try.

blu006 commented 2 months ago

@jp-bennett I'm interested.

jp-bennett commented 2 months ago

@blu006 Sorry for the delay. See if https://drive.google.com/file/d/16uXRGjITWo6D2dblD1LBiAHtIKFjiDFx/view?usp=sharing will work.

blu006 commented 2 months ago

@blu006 Sorry for the delay. See if https://drive.google.com/file/d/16uXRGjITWo6D2dblD1LBiAHtIKFjiDFx/view?usp=sharing will work.

it still connection cycles, but it seems slower this time (or my wifi sucks more). Let me see if I can get the logs.

Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 240 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: published online=1
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 270 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 270 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: MQTT connected
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 270 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: published online=1
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 285 [DeviceTelemetryModule] 
Jul 10 03:30:27 george meshtasticd[1884]: (Sending): air_util_tx=0.082417, channel_utilization=0.000000, battery_level=101, voltage=0.000000, uptime=285
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 285 [DeviceTelemetryModule] 
Jul 10 03:30:27 george meshtasticd[1884]: Sending packet to phone
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 285 
Jul 10 03:30:27 george meshtasticd[1884]: Telling client we have new packets 14
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 285 [ServerAPI] 
Jul 10 03:30:27 george meshtasticd[1884]: getFromRadio=STATE_SEND_PACKETS
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
\Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 300 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 300 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: MQTT connected
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 300 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: published online=1
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 330 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: Attempting to connect directly to MQTT server mqtt.meshtastic.org, port: 1883, username: meshdev, password: large4cats
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 330 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: MQTT connected
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: 
Jul 10 03:30:27 george meshtasticd[1884]: INFO  | ??:??:?? 330 [mqtt] 
Jul 10 03:30:27 george meshtasticd[1884]: published online=1
Jul 10 03:30:27 george meshtasticd[1884]:
blu006 commented 2 months ago

@jp-bennett are the debugging symbols retained in these pio files? they seem a bit small for that imo

i kind of want to put a breakpoint in it with gdb and see how things go