search

gemu2015 / Sonoff-Tasmota

Tasmota Fork TCS34725,PN532_i2,ccc1101 Moritz support,m5stack 4,7 epaper, hotplug drivers
GNU General Public License v3.0
24 stars 19 forks source link

Scripting SPI issues #46

Closed pkkrusty closed 9 months ago

pkkrusty commented 1 year ago

PROBLEM DESCRIPTION

A clear and concise description of what the problem is.

  1. I've been continuing work on the LTC6802-1 BMS, and am still having issues with anything newer than 12.0.2. I can use the same user_config_override, same pin definitions, and same script, and 12.0.2 will communicate correctly, but anything newer will not.
  2. I must be missing something in how to define SPI scripting in ESP32. I cannot get ESP32 to communicate with the chip. With 8266 I define the hardware pins (spi(0 14 13 12)) in script and in configuration, and things work. But I do that same thing in ESP32 and it doesn't work.

REQUESTED INFORMATION

Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!

- [ ] If using rules, provide the output of this command: `Backlog Rule1; Rule2; Rule3`:

Rules output here:

- [ ] Provide the output of this command: `Status 0`:

03:49:16.864 MQT: pkkrusty_E56B00/stat/STATUS = {"Status":{"Module":1,"DeviceName":"Tasmota","FriendlyName":["Tasmota"],"Topic":"pkkrusty_E56B00","ButtonTopic":"0","Power":0,"PowerOnState":3,"LedState":1,"LedMask":"FFFF","SaveData":1,"SaveState":0,"SwitchTopic":"0","SwitchMode":[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],"ButtonRetain":0,"SwitchRetain":0,"SensorRetain":0,"PowerRetain":0,"InfoRetain":0,"StateRetain":0,"StatusRetain":0}} 03:49:16.905 MQT: pkkrusty_E56B00/stat/STATUS1 = {"StatusPRM":{"Baudrate":115200,"SerialConfig":"8N1","GroupTopic":"tasmotas","OtaUrl":"http://ota.tasmota.com/tasmota32/release/tasmota32.bin","RestartReason":"Vbat power on reset","Uptime":"0T00:06:13","StartupUTC":"2023-03-28T03:43:03","Sleep":50,"CfgHolder":4802,"BootCount":3,"BCResetTime":"2023-03-28T02:55:10","SaveCount":8}} 03:49:16.944 MQT: pkkrusty_E56B00/stat/STATUS2 = {"StatusFWR":{"Version":"12.4.0.4(tasmota32)","BuildDateTime":"2023-03-28T02:53:47","Core":"2_0_7","SDK":"4.4.4.20230218","CpuFrequency":240,"Hardware":"ESP32-D0WD-V3 rev.3","CR":"433/699"}} 03:49:16.960 MQT: pkkrusty_E56B00/stat/STATUS3 = {"StatusLOG":{"SerialLog":3,"WebLog":3,"MqttLog":0,"SysLog":0,"LogHost":"192.168.3.48","LogPort":514,"SSId":["beersheba","pkkrusty"],"TelePeriod":60,"Resolution":"558181C0","SetOption":["00208008","2805320001000600003C5A00192800000000","000200C9","00006000","00004000","00000000"]}} 03:49:17.002 MQT: pkkrusty_E56B00/stat/STATUS4 = {"StatusMEM":{"ProgramSize":987,"Free":1856,"Heap":169,"StackLowMark":2,"PsrMax":0,"PsrFree":0,"ProgramFlashSize":4096,"FlashSize":4096,"FlashChipId":"1640D8","FlashFrequency":40,"FlashMode":"DIO","Features":["00000809","0520048E","00080121","00000043","00000400","40000810","00000080","40200000","00000000","00000000"],"Drivers":"1,2,4,9,10,13,29,38,50,56","Sensors":"1,2,5,54,127","I2CDriver":"4,26,35"}} 03:49:17.043 MQT: pkkrusty_E56B00/stat/STATUS5 = {"StatusNET":{"Hostname":"pkkrusty-E56B00-2816","IPAddress":"192.168.3.75","Gateway":"192.168.2.1","Subnetmask":"255.255.254.0","DNSServer1":"192.168.2.1","DNSServer2":"0.0.0.0","Mac":"C0:49:EF:E5:6B:00","IP6Global":"","IP6Local":"fe80::c249:efff:fee5:6b00","Webserver":2,"HTTP_API":1,"WifiConfig":4,"WifiPower":17.0}} 03:49:17.082 MQT: pkkrustyE56B00/stat/STATUS6 = {"StatusMQT":{"MqttHost":"192.168.3.48","MqttPort":1883,"MqttClientMask":"pkkrusty%06X","MqttClient":"pkkrusty_E56B00","MqttUser":"pkkrusty","MqttCount":1,"MAX_PACKET_SIZE":1200,"KEEPALIVE":30,"SOCKET_TIMEOUT":16}} 03:49:17.110 MQT: pkkrusty_E56B00/stat/STATUS7 = {"StatusTIM":{"UTC":"2023-03-28T03:49:17","Local":"2023-03-28T03:49:17","StartDST":"2023-03-26T02:00:00","EndDST":"2023-10-29T03:00:00","Timezone":"+00:00"}} 03:49:17.129 MQT: pkkrusty_E56B00/stat/STATUS10 = {"StatusSNS":{"Time":"2023-03-28T03:49:17"}} 03:49:17.137 MQT: pkkrusty_E56B00/stat/STATUS11 = {"StatusSTS":{"Time":"2023-03-28T03:49:17","Uptime":"0T00:06:14","UptimeSec":374,"Heap":166,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":1,"Wifi":{"AP":1,"SSId":"beersheba","BSSId":"68:7F:74:BB:BB:B8","Channel":6,"Mode":"11n","RSSI":86,"Signal":-57,"LinkCount":1,"Downtime":"0T00:00:04"}}}

- [ ] Provide the output of the Console log output when you experience your issue; if applicable:
  _(Please use_ `weblog 4` _for more debug information)_

Console output here:



### TO REPRODUCE
_Steps to reproduce the behavior:_

### EXPECTED BEHAVIOUR
_A clear and concise description of what you expected to happen._

### SCREENSHOTS
_If applicable, add screenshots to help explain your problem._

### ADDITIONAL CONTEXT
_Add any other context about the problem here._

**(Please, remember to close the issue when the problem has been addressed)**
gemu2015 commented 1 year ago

there have been many changes in scripting but only one in spi (transfer mode 4) i guess there may be an issue beside SPI with newer versions.

could you please create a very basic script just reading one value from BMS and compare versions. and provide the script and the logs from initialization

pkkrusty commented 1 year ago

OK, did some work this afternoon to narrow down the problem. It seems once I go past 12.0.2, I can't write to variables/arrays correctly, and that affects the SPI comms. (the initialization command never gets sent, and thus it never responds).

So here's a basic script that works on 12.0.2 but not anything newer. Only difference I can see is heap getting smaller. user_config_override is exactly the same.

>D 48
SB=4096
IP=192.168.1.127
m:cvr=0 19
m:cfr=0 7
m:wcfr=0 7
m:cv=0 12
m:cmnd=0 1
dcc=0
dccread=0
dcchold=1
cvhold=0
cntr=0
min=4
max=0
minc=0
maxc=0
numcells=4  
mci=0
wcfg=0
avg=0
cmcntr=0
vuv=125
vov=167
maxdiscnct=4
maxrecnct=3.95
mindiscnct=3.2
minrecnct=3.3
res=0
vstr=""
rslt=""
blncstrt=3.9
sfty=0
curr=0
expc=0

>B
cvr[0]=0
cfr[0]=0
cfr[1]=2
wcfr[0]=0
wcfr[1]=1
wcfr[2]=97
wcfr[3]=0
wcfr[4]=240
wcfr[5]=255
wcfr[6]=125
wcfr[7]=167
wcfg=1
cmnd[0]=0
print %0heap%,%wcfg%,%wcfr[1]%,%wcfr[2]%,%wcfr[3]%,%wcfr[4]%,%wcfr[5]%,%wcfr[6]%,%wcfr[7]%
res=spi(0 14 13 12)
res=spi(1 1 15)
delay(5)
;debug first spi command
res=spi(2 1 wcfr 7 1)
mci=4095 ; mask all cells

>S
;prep cell voltage array with command and zero rest of array
cvr[1]=0x04
for cntr 2 19 1
    cvr[cntr]=0
next

;prep tempAD command
cmnd[1]=0x30 ; TempAD conversion

;prep config register read and zero rest of array
cfr[1]=2
for cntr 2 7 1
    cfr[cntr]=0
next

; if discharge tribble changes or every minute, re-write config array
if ((dcchold!=dcc and upsecs%10==0) or upsecs%60==0) {
    wcfg=1
}
wcfg=1
print %0heap%,%wcfg%,%wcfr[1]%,%wcfr[2]%,%wcfr[3]%,%wcfr[4]%,%wcfr[5]%,%wcfr[6]%,%wcfr[7]%
if (wcfg==1) {
    wcfr[1]=1
    wcfr[2]=97
    wcfr[3]=(dcc&255)
    wcfr[4]=((dcc>>8)|(mci<<4&240))
    wcfr[5]=(mci>>4)
    wcfr[6]=vuv
    wcfr[7]=vov
    print %wcfg%,%wcfr[1]%,%wcfr[2]%,%wcfr[3]%,%wcfr[4]%,%wcfr[5]%,%wcfr[6]%,%wcfr[7]%

    ; first SPI command brings BMS out of standby, needs comms every 2.5 seconds
    res=spi(2 1 wcfr 7 1)
    wcfg=0
}

delay(5)
res=spi(2 1 cmnd 1 1) ; TempAD conversion
delay(22)
cmnd[1]=0x10
res=spi(2 1 cmnd 1 1) ; VoltageAD conversion
delay(22)
res=spi(2 1 cvr 19 1) ; Read cell voltages
delay(2)
res=spi(2 1 cfr 7 1) ; Read config register
dccread=(cfr[4]&15)<<8|cfr[3]

sfty=cfr[2]&128
if (sfty==128) {
print lost comms
}
else {
print ok
}

; calculate average cell value
avg=0
for cntr 1 numcells 1
    avg+=cv[cntr]
next
avg/=numcells

vstr=""
; convert register to cell voltages in cv array
for cntr 1 (numcells-1) 2
    cv[cntr]=((cvr[cntr*1.5+1.5]%16)<<8)|(cvr[(cntr*1.5+0.5)]&255)*.0015
next

for cntr 2 (numcells) 2
    cv[cntr]=(cvr[(cntr*1.5+1)]*16)|((cvr[(cntr*1.5)]>>4)&15)*.0015
next

; calc max/min cell
for cntr 1 numcells 1
    if (cntr==1) {
        min=cv[cntr]
        max=cv[cntr]
    }
    if (cv[cntr]>=max) {
        max=cv[cntr]
        maxc=cntr
    }
    if (cv[cntr]<=min) {
        min=cv[cntr]
        minc=cntr
    }
next

dcchold=dcc
dcc=0

; calculate discharge/balance tribble
for cntr 1 numcells 1
    cvhold=cv[cntr]-0.01
    if ((cvhold>avg) and (cv[cntr]>blncstrt)) {
        vstr+="d"
        dcc=dcc|(1<<(cntr-1))
    }
    else { 
        if (cv[cntr]<=avg) {
            dcc=dcc&(4095-(1<<(cntr-1)))
        }
        vstr+="r"
    }
next

And here's the log on script start (12.4.0.4):

17:59:29.860 Script: nv=30, tv=2, vns=188, vmem=924, smem=8192
17:59:29.866 9568,0.00,0.00,0.00,0.00,0.00,0.00,0.00,0.00
17:59:29.867 warning: pins already used
17:59:29.869 warning: pins already used
17:59:30.495 14304,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
17:59:30.554 lost comms
17:59:31.476 14304,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
17:59:31.534 lost comms
17:59:32.506 14304,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00

You can see that wcfg never gets set to 1 even though it's in the script. Here's the same script in 12.0.2:

18:05:53.701 Script: nv=30, tv=2, vns=188, vmem=860, smem=8192
18:05:53.709 11448,1.00,1.00,97.00,0.00,240.00,255.00,125.00,167.00
18:05:53.711 warning: pins already used
18:05:53.712 warning: pins already used
18:05:54.488 16184,1.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:05:54.493 1.00,1.00,97.00,0.00,240.00,255.00,125.00,167.00
18:05:54.551 lost comms
18:05:55.474 16184,1.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:05:55.479 1.00,1.00,97.00,0.00,240.00,255.00,125.00,167.00
18:05:55.536 lost comms
18:05:56.459 16184,1.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:05:56.464 1.00,1.00,97.00,0.00,240.00,255.00,125.00,167.00
18:05:56.522 lost comms
18:05:57.444 16184,1.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:05:57.449 1.00,1.00,97.00,0.00,240.00,255.00,125.00,167.00

So between releases, the core is using 2k more RAM, maybe that's the difference? I re-compiled 12.4.0.4 with minimal requirements and tried again:

18:14:10.957 Script: nv=30, tv=2, vns=188, vmem=924, smem=8192
18:14:10.962 11472,0.00,0.00,0.00,0.00,0.00,0.00,0.00,0.00
18:14:10.963 warning: pins already used
18:14:10.965 warning: pins already used
18:14:11.227 15904,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:14:11.284 lost comms
18:14:12.207 16208,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:14:12.265 lost comms
18:14:13.234 16208,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:14:13.292 lost comms
18:14:14.211 16208,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00
18:14:14.268 lost comms
18:14:15.236 16208,0.00,255.00,255.00,255.00,255.00,255.00,255.00,255.00

That got me back my 2k of RAM, but still can't write to certain arrays or variables.

Let me know what I should do to help troubleshoot.

gemu2015 commented 1 year ago

wcs and wcf are reserved words in scripter (special web commands) and interfere with variable definition

normally a variable definition should override the command definition

will check what causes this to fail now.

as a workaround you may rename your variables (wcfr and wcfg) and it should work as expected

gemu2015 commented 1 year ago

ok fixed , try my fork

pkkrusty commented 1 year ago

Awesome thanks. I figured it was something simple.

pkkrusty commented 1 year ago

Also discovered that adding a pullup resistor to the MISO line helped receive data from the SPI bus. Was there a change between 12.0.2 and 12.4 that changed default internal pullup behavior in SPI pin definitions?