Läuft: Heizung mit eBus-Schnittstelle

[lewej]

Hallo Zusammen,

ich habe eine Vaillant geotherm VWL 81/3. Ich lese die Anlage per ebus Platine 2.0 aus.
Funktioniert und er findet auch einige Sache. Ich bekomme jedoch die bai nicht aufgelistet, sprich die ganzen Informationen der Ausseneinheit.

ebusconfig:

Code Auswählen Erweitern

EBUSD_OPTS3="-d /dev/ebuswpusb -p 8890 --loglevel=info --pidfile=/var/run/ebusdgeothermusb.pid --logfile=/var/log/ebusd/ebusdgeothermusb -c http://cfg.ebusd.eu/ --scanconfig=full --pollinterval=300 --mqtthost=localhost --mqttport=1883  --mqttjson --mqtttopic=ebusd/%circuit/%name"

Code Auswählen Erweitern

localhost: scan result
08;Vaillant;EHP00;0412;7201;??;??;??;??????????;????;??????;??
15;Vaillant;UIH00;0362;6901;21;10;29;0020101780;0907;005256;N5
23;Vaillant;EHP00;0412;7201;??;??;??;??????????;????;??????;??
25;Vaillant;EHP00;0412;7201;??;??;??;??????????;????;??????;??
50;Vaillant;EHP00;0412;7201;??;??;??;??????????;????;??????;??

Den Full Scan habe ich schon bei laufender Außeneinheit ausgeführt, er findet diese aber nicht.

Hat jemand erfolgreich seine Ausseneinheit ausgelesen und hat jemand ein Idee, was ich evtl. tun kann?

@john30: Hast du einen Tipp, was ich da noch machen kann?

Gruß

[Wolpertinger]

Servus,

warum bai?
Gleiche Anlage läuft bei mir mit 08.ehp.csv

[Wolpertinger]

Servus,

meine Vaillant VWL wurde vor einiger Zeit resettet.
Wie bekomme ich den alten Zählerstand wieder in die Anlage.
15.uih.csv wäre es YieldSum zum auslesen, das geht auch, aber wie kann ich den alten Wert setzen?

[lewej]

Servus,

warum bai?
Gleiche Anlage läuft bei mir mit 08.ehp.csv

Hi,
Wie kannst du den die Ausseneinheit auslesen. Lüfterdrehzahl der Anlage wäre interessant.
In der ehp hab ich dazu nichts gefunden.

Gruss

[theotherhalf]

Ich habe vor, meine beiden USB Anschlüsse (Vaillant Therme und Vaillant VRS620) auf einen neuen Raspi mit frischem Debian (Bullseye) zu übertragen.
Zur Info: Da ich keine Standardinstallation (Heizung) habe, sind Therme und Regler nicht über ein und denselben Ebus zu erreichen und dürfen das auch nicht, da sie sich sonst falsche Sollwerte zuwerfen.
Jedes Gerät hat einen eigenen Konverter V2.0

Neueste Version ebus ist nun installiert, ein Gerät ist angebunden.

Code Auswählen Erweitern

pi@raspberrypi:~ $ ebusctl info
version: ebusd 23.1.23.1
device: /dev/ttyUSB0
signal: acquired
symbol rate: 41
max symbol rate: 195
min arbitration micros: 508
max arbitration micros: 1764
min symbol latency: 4
max symbol latency: 6
reconnects: 0
masters: 3
messages: 538
conditional: 9
poll: 0
update: 10
address 10: master #2
address 15: slave #2, scanned "MF=Vaillant;ID=UI   ;SW=0324;HW=6201", loaded "vaillant/15.ui.csv"
address 23: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0306;HW=6301", loaded "vaillant/23.solsy.cc.csv"
address 25: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0306;HW=6301", loaded "vaillant/25.solsy.hwc.csv"
address 26: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0306;HW=6301", loaded "vaillant/26.solsy.hc.csv"
address 31: master #8, ebusd
address 36: slave #8, ebusd
address 3f: master #23
address 44: slave #23, scanned "MF=Vaillant;ID=SOLSY;SW=0306;HW=6301"
address 50: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0306;HW=6301", loaded "vaillant/50.solsy.mc.csv"
address ec: slave, scanned "MF=Vaillant;ID=SOLSY;SW=0306;HW=6301", loaded "vaillant/ec.solsy.sc.csv"

Der Anschluss bei einem Gerät klappt also und wird gefunden, die Werte erhalte ich auch in FHEM.

Folgende /etc/default/ebusd Konfiguration ist in Benutzung:

Code Auswählen Erweitern

# /etc/default/ebusd:
# config file for ebusd service.

# Options to pass to ebusd (run "ebusd -?" for more info):
# EBUSD_OPTS="--scanconfig"

EBUSD_OPTS="-d /dev/ttyUSB0 -p 8888 -l /var/log/ebusd.log  --scanconfig --latency=20000 --receivetimeout=50000"

# MULTIPLE EBUSD INSTANCES WITH SYSV
# In order to run multiple ebusd instances on a SysV enabled system, simply
# define several EBUSD_OPTS with a unique suffix for each. Recommended is to
# use a number as suffix for all EBUSD_OPTS settings. That number will then be
# taken as additional "instance" parameter to the init.d script in order to
# start/stop an individual ebusd instance instead of all instances.
# Example: (uncomment the EBUSD_OPTS above)
#EBUSD_OPTS1="--scanconfig -d /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A50285BI-if00-port0 -p 8888 -l /var/log/ebusd1.log"
#EBUSD_OPTS2="--scanconfig -d /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A900acTF-if00-port0 -p 8889 -l /var/log/ebusd2.log"
#EBUSD_OPTS3="--scanconfig -d /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A900beCG-if00-port0 -p 8890 -l /var/log/ebusd3.log"

# MULTIPLE EBUSD INSTANCES WITH SYSTEMD
# In order to run muiltiple ebusd instances on a systemd enabled system, just
# copy the /lib/systemd/system/ebusd.service file to /etc/systemd/system/
# with a different name (e.g. ebusd-2.service), remove the line starting with
# 'EnvironmentFile=', and replace the '$EBUSD_OPTS' with the options for that
# particular ebusd instance.

Um nun den zweiten ebus/USB Anschluss auszulesen, verstehe ich es richtig, das ich einfach 2 der Zeilen unten einrücke und dem oberen einen # voranstelle oder muss an anderer Stelle in anderen Dateien/Verzeichnissen auch noch editiert werden? 

Schnittstellenabfrage gibt mir folgendes (zweiter Konverter ist noch nicht angeschlossen, hängt noch auf dem alten Raspi):

Code Auswählen Erweitern

pi@raspberrypi:~ $ sudo dmesg | grep -i tty
[    0.000000] Kernel command line: coherent_pool=1M snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=Composite-1:720x480@60i vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyAMA0,115200 console=tty1 root=PARTUUID=e39fdea4-02 rootfstype=ext4 fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
[    0.000655] printk: console [tty1] enabled
[    2.976504] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 114, base_baud = 0) is a PL011 rev2
[    2.976911] printk: console [ttyAMA0] enabled
[    6.348494] systemd[1]: Created slice system-getty.slice.
[    6.352946] systemd[1]: Created slice system-serial\x2dgetty.slice.
[   10.653008] usb 1-1.4: cp210x converter now attached to ttyUSB0


[john30]

Um nun den zweiten ebus/USB Anschluss auszulesen, verstehe ich es richtig, das ich einfach 2 der Zeilen unten einrücke und dem oberen einen # voranstelle oder muss an anderer Stelle in anderen Dateien/Verzeichnissen auch noch editiert werden? 

einfach EBUSD_OPTS behalten und zusätzlich EBUSD_OPTS1 konfigurieren (sofern das OS nicht systemd basiert ist)

[tremichl]

Hallo!
Heizgräte von Vaillant und auch anderer Hersteller sind wohl Smart Grid Ready (SG-Ready). Wie ich das verstehe, nimmt diese "Smart Grid Schnittstelle" nur einen trockenen Kontakt entgegen und in der Heizanlage wird dann z.B. der Speicher höher aufgeheizt wenn PV-Überschuss oder ein günstiger Stromtarif zur Verfügung steht.
Meine Frage daher: Gibt es einen Wert dafür am ebus (Vaillant Wärmepumpe) bzw. wie könnte ich den finden? Es wäre schon elegant wenn man SG über ebus ansteuern könnte und nicht nebenher aus FHEM ein Relais schalten müsste welches dann die SG Information an die Heizung liefert.
Danke, Michael

[UvG]

Hallo zusammen,
habe eine Vaillant ecoTEC plus mit VCR710 und internet VR921.
ebus ist installiert auf rpi 3 mit externem ebus Adapter usb.
Der ebus scheint zu laufen und ich bekomme auch Daten über MQTT (Status01,Status02.....)
ebusctl i liefert:

Code Auswählen Erweitern

version: ebusd 23.1.23.1-8-g9c0af7b9
update check: revision 23.1 available
device: /dev/ttyUSB0
access: *
signal: acquired
symbol rate: 23
max symbol rate: 114
min arbitration micros: 334
max arbitration micros: 562
min symbol latency: 5
max symbol latency: 13
reconnects: 1
masters: 3
messages: 225
conditional: 3
poll: 0
update: 10
address 00: master #1
address 03: master #11
address 08: slave #11, scanned "MF=Vaillant;ID=BAI00;SW=1002;HW=7603", loaded "vaillant/bai.308523.inc", "vaillant/08.bai.csv"
address 31: master #8, ebusd
address 36: slave #8, ebusd, scanning

Ich wollte jetzt noch das Zeitprogramm abfragen, das gelinkt nicht da er die Parameter nicht kennt.
Habe ich bei der Instalation etwas vergessen oder wie kann ich ihm beibrigen diese Daten zu holen?

Mit der App auf dem Handy funktioniert das problemlos und der VR921 hängt ja auch am ebus.

für einen Hinweis wäre ich sehr dankbar.

Gruß
Ulrich

[Beni]

@UvG

welche config hast du und welchen eBus-Adapter?

LG
Ben

[UvG]

Hallo Ben

Als Adapter verwende ich den ESERA eBus Koppler USB.

config:

Code Auswählen Erweitern

# /etc/default/ebusd:
# config file for ebusd service.

# Options to pass to ebusd (run "ebusd -?" for more info):
#EBUSD_OPTS="--scanconfig"
EBUSD_OPTS="--scanconfig=full -p 8888 -l /var/log/ebusd.log -d /dev/ttyUSB0 --latency=20 --httpport=8081 --mqttjson --mqtttopic=ebusd/%circuit/%name --configpath=http://cfg.ebusd.eu  --mqtthost=192.168.188.39 --mqttport=1883 --mqttuser=<MQTT-USERNAME> --mqttpass=<MQTT-PASSWORT> --accesslevel=* --scanconfig=full"

# MULTIPLE EBUSD INSTANCES WITH SYSV
# In order to run multiple ebusd instances on a SysV enabled system, simply
# define several EBUSD_OPTS with a unique suffix for each. Recommended is to
# use a number as suffix for all EBUSD_OPTS settings. That number will then be
# taken as additional "instance" parameter to the init.d script in order to
# start/stop an individual ebusd instance instead of all instances.
# Example: (uncomment the EBUSD_OPTS above)
#EBUSD_OPTS1="--scanconfig -d /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A50285BI-if00-port0 -p 8888 -l /var/log/ebusd1.log"
#EBUSD_OPTS2="--scanconfig -d /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A900acTF-if00-port0 -p 8889 -l /var/log/ebusd2.log"
#EBUSD_OPTS3="--scanconfig -d /dev/serial/by-id/usb-FTDI_FT232R_USB_UART_A900beCG-if00-port0 -p 8890 -l /var/log/ebusd3.log"

# MULTIPLE EBUSD INSTANCES WITH SYSTEMD
# In order to run muiltiple ebusd instances on a systemd enabled system, just
# copy the /lib/systemd/system/ebusd.service file to /etc/systemd/system/
# with a different name (e.g. ebusd-2.service), remove the line starting with
# 'EnvironmentFile=', and replace the '$EBUSD_OPTS' with the options for that
# particular ebusd instance.

[Prof. Dr. Peter Henning]

Nach neun Jahren klagloser Dienstleistung hat jetzt der allererste selbst zusammengelötete EBUS-Adapter, mit dem ich diesen Thread begonnen habe, seinen Geist aufgegeben. Ich steige deshalb jetzt auf einen EBUS-Adapter 2.2 um, der direkt auf die Schnittstelle des Raspberry Pi aufgesetzt wird.

Das erste, was ich feststellte: Der Link im FHEMWiki auf die neueren Informationen lief ins Leere, habe ich gleich ausgebessert.

Ansonsten finde ich es eigentlich sehr befriedigend, was aus dieser Sache geworden ist...

LG

pah

[Prof. Dr. Peter Henning]

Das sieht so aus, als ob die Synchronisation mit den Signalen auf dem Bus nicht richtig funktioniert. Ich kenne die Technik hinter dieser Adapter-Version nicht, aber die scheint außer Takt zu geraten.

Bei meinen allerersten Versuchen 2014 trat Ähnliches auf, weil der Raspberry Pi (Model 1, also Steinzeit) seine serielle Schnittstelle nur emuliert.

LG

pah

[john30]

Ich habe ständig Fehler auf dem Bus mit dem neuen Adapter V5. Das ist natürlich sehr unzuverlässig, da Werte fehlen um eine Grafik zu erzeugen, gerade wenn sich Werte schnell ändern. Sollte mit dem neuen Adapter nicht alles besser werden ?
Der Adapter hängt im WLAN, kann es sein, dass das zum Problem führt ?

Auch werden oft Werte per MQTT nicht geschrieben - ist der Bus überlastet ?

Die ebusd.log ist nach 1,5h bereits 250k groß, macht am Tag 4MB !!!

Der Fehler "[bus error] poll 470 YieldThisYear failed" tritt mit dem neuen Adapter V5 sehr viel häufiger auf, als mit dem TTL-Adapter (Poti-Version)

die WIFI Anbindung ist von je her schwierig, weil du für einen vernünftigen Betrieb Latenzzeiten unter 20ms bräuchtest. Das ist je nach Überlagerung benachbarter Netze oder mit entsprechender Auslastung des eigenen flott mal unmöglich.

[Prof. Dr. Peter Henning]

Hier ist ja gar nichts mehr los !

Nicht doch. Das ist eher ein Zeichen dafür, dass die Dinge problemlos laufen und gut dokumentiert sind.

pah

[psifactory]

Hallo Zusammen,

ich habe aktuell ein Problem meinen eBusd zum Laufen zu bringen.
Ich verstehe aktuell, dass mein Gateway wohl nicht schreiben kann? Ist der Ansatz richtig? Was kann ich hier dann tun um das Problem zu lösen?


Folgendes Setup:

• Esera Eco ECO305_MCU3 Ebus Gateway
• ebusd auf Ubuntu (ebusd 23.2.23.2-71-g53fcc90f)
• Vaillant Gas Hybrid Heizungssystem mit:
• - Vaillant AroTherm 125/5 WP
• - Vaillant EcoVit VKK 476/4 Gasheizung
• - Vaillant VR71 Mischermodul

Meine Ebusd Settings in /etc/default/ebusd

Code Auswählen Erweitern

EBUSD_OPTS="--configpath=http://cfg.ebusd.eu -d 10.0.0.83:5001 -p 8888 --logareas all --loglevel debug -l /var/log/ebusd.log  --scanconfig=full  --httpport=8889 --htmlpath=/var/ebusd/html"
ebusctl info

Code Auswählen Erweitern

version: ebusd 23.2.23.2-71-g53fcc90f
device: 10.0.0.83:5001, TCP
signal: acquired
symbol rate: 113
max symbol rate: 184
min arbitration micros: 1
max arbitration micros: 340
min symbol latency: 23
max symbol latency: 42
scan: finished, some messages pending
reconnects: 0
masters: 1
messages: 11
conditional: 0
poll: 0
update: 4
address 31: master #8, ebusd
address 36: slave #8, ebusd, scanning
Logfile nach Start des Ebusd

Code Auswählen Erweitern

2023-12-25 10:09:47.078 [bus notice] device status: transport opened
2023-12-25 10:09:47.079 [main info] registering data handlers
2023-12-25 10:09:47.079 [main info] registered data handlers
2023-12-25 10:09:47.079 [main notice] ebusd 23.2.23.2-71-g53fcc90f started with full scan on device: 10.0.0.83:5001, TCP
2023-12-25 10:09:47.079 [main info] loading configuration files from http://cfg.ebusd.eu/
2023-12-25 10:09:47.107 [main info] reading templates /
2023-12-25 10:09:47.135 [main info] read templates in /
2023-12-25 10:09:47.135 [main info] reading file broadcast.csv
2023-12-25 10:09:47.161 [main info] successfully read file broadcast.csv
2023-12-25 10:09:47.161 [main info] reading file memory.csv
2023-12-25 10:09:47.190 [main info] successfully read file memory.csv
2023-12-25 10:09:47.190 [main info] read config files, got 11 messages
2023-12-25 10:09:47.190 [bus notice] bus started with own address 31/36
2023-12-25 10:09:47.191 [bus notice] signal acquired
2023-12-25 10:09:47.729 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:48.207 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:48.842 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:49.337 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:49.438 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:09:49.810 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:49.812 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:49.823 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:49.919 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:50.050 [bus notice] max. symbols per second: 133
2023-12-25 10:09:50.132 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:50.138 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:50.407 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:50.502 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:50.757 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:51.008 [bus notice] max. symbols per second: 156
2023-12-25 10:09:51.026 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:51.136 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:51.386 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:51.389 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:51.495 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:51.583 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:51.586 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:51.807 [bus debug] ERR: read timeout during receive command CRC, switching to skip
2023-12-25 10:09:52.006 [bus notice] max. symbols per second: 184
2023-12-25 10:09:52.015 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:52.019 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:52.184 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:52.300 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:52.547 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:52.733 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:52.845 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:53.096 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:53.279 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:53.819 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:53.945 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:53.951 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:54.631 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:55.569 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:09:57.191 [main debug] performing regular tasks
2023-12-25 10:09:57.191 [main notice] starting initial full scan
2023-12-25 10:09:57.191 [bus info] scan 02 cmd: 3102070400
2023-12-25 10:09:57.367 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:57.371 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:57.375 [bus debug] start request 31
2023-12-25 10:09:57.375 [bus debug] arbitration start with 31
2023-12-25 10:09:57.444 [bus debug] arbitration won
2023-12-25 10:09:57.444 [bus debug] arbitration delay 1 micros
2023-12-25 10:09:57.444 [bus info] arbitration delay 1 - 1 micros
2023-12-25 10:09:57.444 [bus debug] switching from ready to send command
2023-12-25 10:09:57.471 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:09:57.471 [bus info] send/receive symbol latency 27 - 27 ms
2023-12-25 10:09:57.499 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:09:57.525 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:09:57.525 [bus info] send/receive symbol latency 25 - 27 ms
2023-12-25 10:09:57.553 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:09:57.553 [bus info] send/receive symbol latency 25 - 28 ms
2023-12-25 10:09:57.553 [bus debug] switching from send command to send command CRC
2023-12-25 10:09:57.580 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:09:57.580 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:09:57.645 [bus debug] notify request: ERR: read timeout
2023-12-25 10:09:57.645 [bus info] scan 04 cmd: 3104070400
2023-12-25 10:09:57.645 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:09:58.083 [bus debug] start request 31
2023-12-25 10:09:58.083 [bus debug] arbitration start with 31
2023-12-25 10:09:58.152 [bus debug] arbitration won
2023-12-25 10:09:58.152 [bus debug] arbitration delay 1 micros
2023-12-25 10:09:58.152 [bus debug] switching from ready to send command
2023-12-25 10:09:58.179 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:09:58.206 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:09:58.231 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:09:58.231 [bus info] send/receive symbol latency 24 - 28 ms
2023-12-25 10:09:58.256 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:09:58.256 [bus debug] switching from send command to send command CRC
2023-12-25 10:09:58.281 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:09:58.281 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:09:58.289 [bus debug] switching from receive command ACK to receive response
2023-12-25 10:09:58.380 [bus debug] notify request: ERR: read timeout
2023-12-25 10:09:58.380 [bus info] scan 05 cmd: 3105070400
2023-12-25 10:09:58.380 [bus debug] ERR: read timeout during receive response, switching to skip
2023-12-25 10:09:58.789 [bus debug] start request 31
2023-12-25 10:09:58.789 [bus debug] arbitration start with 31
2023-12-25 10:09:58.874 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:09:58.879 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:09:58.932 [bus debug] arbitration won
2023-12-25 10:09:58.932 [bus debug] arbitration delay 2 micros
2023-12-25 10:09:58.932 [bus info] arbitration delay 1 - 2 micros
2023-12-25 10:09:58.932 [bus debug] switching from ready to send command
2023-12-25 10:09:58.958 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:09:58.984 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:09:59.009 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:09:59.035 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:09:59.035 [bus debug] switching from send command to send command CRC
2023-12-25 10:09:59.061 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:09:59.061 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:09:59.066 [bus debug] switching from receive command ACK to receive response
2023-12-25 10:09:59.157 [bus debug] notify request: ERR: read timeout
2023-12-25 10:09:59.157 [bus info] scan 06 cmd: 3106070400
2023-12-25 10:09:59.157 [bus debug] ERR: read timeout during receive response, switching to skip
2023-12-25 10:09:59.157 [bus debug] start request 31
2023-12-25 10:09:59.157 [bus debug] arbitration start with 31
2023-12-25 10:09:59.576 [bus debug] arbitration lost
2023-12-25 10:09:59.576 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:09:59.664 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:09:59.664 [bus debug] start request 31
2023-12-25 10:09:59.664 [bus debug] arbitration start with 31
2023-12-25 10:10:00.110 [bus debug] arbitration lost
2023-12-25 10:10:00.110 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:00.199 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:00.199 [bus debug] start request 31
2023-12-25 10:10:00.199 [bus debug] arbitration start with 31
2023-12-25 10:10:00.667 [bus debug] arbitration won
2023-12-25 10:10:00.667 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:00.667 [bus debug] switching from ready to send command
2023-12-25 10:10:00.693 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:00.728 [bus debug] send/receive symbol latency 35 ms
2023-12-25 10:10:00.728 [bus info] send/receive symbol latency 24 - 35 ms
2023-12-25 10:10:00.754 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:00.779 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:00.779 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:00.829 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:00.829 [bus info] scan 08 cmd: 3108070400
2023-12-25 10:10:00.829 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:00.829 [bus debug] start request 31
2023-12-25 10:10:00.829 [bus debug] arbitration start with 31
2023-12-25 10:10:01.288 [bus debug] arbitration lost
2023-12-25 10:10:01.288 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:01.377 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:01.377 [bus debug] start request 31
2023-12-25 10:10:01.377 [bus debug] arbitration start with 31
2023-12-25 10:10:01.847 [bus debug] arbitration won
2023-12-25 10:10:01.847 [bus debug] arbitration delay 1 micros
2023-12-25 10:10:01.847 [bus debug] switching from ready to send command
2023-12-25 10:10:01.873 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:01.900 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:01.925 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:01.951 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:01.951 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:02.001 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:02.001 [bus info] scan 09 cmd: 3109070400
2023-12-25 10:10:02.001 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:02.002 [bus debug] start request 31
2023-12-25 10:10:02.002 [bus debug] arbitration start with 31
2023-12-25 10:10:02.460 [bus debug] arbitration lost
2023-12-25 10:10:02.460 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:02.563 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:10:02.564 [bus debug] start request 31
2023-12-25 10:10:02.564 [bus debug] arbitration start with 31
2023-12-25 10:10:02.609 [bus debug] arbitration lost
2023-12-25 10:10:02.610 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:02.702 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:03.141 [bus debug] start request 31
2023-12-25 10:10:03.141 [bus debug] arbitration start with 31
2023-12-25 10:10:03.248 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:10:03.272 [bus debug] arbitration won
2023-12-25 10:10:03.272 [bus debug] arbitration delay 301 micros
2023-12-25 10:10:03.273 [bus info] arbitration delay 1 - 301 micros
2023-12-25 10:10:03.273 [bus debug] switching from ready to send command
2023-12-25 10:10:03.302 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:10:03.332 [bus debug] send/receive symbol latency 30 ms
2023-12-25 10:10:03.359 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:03.385 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:03.385 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:03.435 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:03.435 [bus info] scan 0a cmd: 310a070400
2023-12-25 10:10:03.435 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:03.435 [bus debug] start request 31
2023-12-25 10:10:03.435 [bus debug] arbitration start with 31
2023-12-25 10:10:03.920 [bus debug] arbitration won
2023-12-25 10:10:03.920 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:03.920 [bus debug] switching from ready to send command
2023-12-25 10:10:03.947 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:03.972 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:03.998 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:04.023 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:04.023 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:04.052 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:10:04.052 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:04.117 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:04.117 [bus info] scan 0b cmd: 310b070400
2023-12-25 10:10:04.117 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:10:04.117 [bus debug] start request 31
2023-12-25 10:10:04.117 [bus debug] arbitration start with 31
2023-12-25 10:10:04.661 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:10:04.666 [bus debug] arbitration lost
2023-12-25 10:10:04.666 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:04.758 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:04.758 [bus debug] start request 31
2023-12-25 10:10:04.758 [bus debug] arbitration start with 31
2023-12-25 10:10:05.229 [bus debug] arbitration won
2023-12-25 10:10:05.229 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:05.229 [bus debug] switching from ready to send command
2023-12-25 10:10:05.254 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:05.281 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:05.308 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:05.339 [bus debug] send/receive symbol latency 29 ms
2023-12-25 10:10:05.339 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:05.365 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:05.365 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:05.430 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:05.430 [bus info] scan 0c cmd: 310c070400
2023-12-25 10:10:05.430 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:10:05.431 [bus debug] start request 31
2023-12-25 10:10:05.431 [bus debug] arbitration start with 31
2023-12-25 10:10:05.971 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:10:05.998 [bus debug] arbitration won
2023-12-25 10:10:05.998 [bus debug] arbitration delay 76 micros
2023-12-25 10:10:05.998 [bus debug] switching from ready to send command
2023-12-25 10:10:06.023 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:06.048 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:06.074 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:06.101 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:06.101 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:06.128 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:06.128 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:06.193 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:06.193 [bus info] scan 0d cmd: 310d070400
2023-12-25 10:10:06.193 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:10:06.193 [bus debug] start request 31
2023-12-25 10:10:06.193 [bus debug] arbitration start with 31
2023-12-25 10:10:06.655 [bus debug] arbitration won
2023-12-25 10:10:06.655 [bus debug] arbitration delay 1 micros
2023-12-25 10:10:06.655 [bus debug] switching from ready to send command
2023-12-25 10:10:06.686 [bus debug] send/receive symbol latency 31 ms
2023-12-25 10:10:06.721 [bus debug] send/receive symbol latency 34 ms
2023-12-25 10:10:06.746 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:06.772 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:06.772 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:06.797 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:06.797 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:06.862 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:06.863 [bus info] scan 0e cmd: 310e070400
2023-12-25 10:10:06.863 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:10:06.863 [bus debug] start request 31
2023-12-25 10:10:06.863 [bus debug] arbitration start with 31
2023-12-25 10:10:07.191 [main debug] performing regular tasks
2023-12-25 10:10:07.305 [bus debug] arbitration lost
2023-12-25 10:10:07.305 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:07.388 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:07.388 [bus debug] start request 31
2023-12-25 10:10:07.388 [bus debug] arbitration start with 31
2023-12-25 10:10:07.840 [bus debug] arbitration lost
2023-12-25 10:10:07.840 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:07.922 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:10:07.925 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:10:07.925 [bus debug] start request 31
2023-12-25 10:10:07.925 [bus debug] arbitration start with 31
2023-12-25 10:10:07.967 [bus debug] arbitration lost
2023-12-25 10:10:07.967 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:08.096 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:08.096 [bus debug] start request 31
2023-12-25 10:10:08.096 [bus debug] arbitration start with 31
2023-12-25 10:10:08.560 [bus debug] arbitration won
2023-12-25 10:10:08.560 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:08.560 [bus debug] switching from ready to send command
2023-12-25 10:10:08.586 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:08.613 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:08.639 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:08.665 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:08.665 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:08.715 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:08.715 [bus info] scan 12 cmd: 3112070400
2023-12-25 10:10:08.715 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:08.715 [bus debug] start request 31
2023-12-25 10:10:08.715 [bus debug] arbitration start with 31
2023-12-25 10:10:09.171 [bus debug] arbitration lost
2023-12-25 10:10:09.171 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:09.254 [bus debug] ERR: read timeout during receive command, switching to skip
2023-12-25 10:10:09.254 [bus debug] start request 31
2023-12-25 10:10:09.254 [bus debug] arbitration start with 31
2023-12-25 10:10:09.735 [bus debug] arbitration won
2023-12-25 10:10:09.735 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:09.735 [bus debug] switching from ready to send command
2023-12-25 10:10:09.759 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:09.787 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:09.816 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:10:09.843 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:09.843 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:09.893 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:09.893 [bus info] scan 14 cmd: 3114070400
2023-12-25 10:10:09.893 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:09.893 [bus debug] start request 31
2023-12-25 10:10:09.893 [bus debug] arbitration start with 31
2023-12-25 10:10:10.348 [bus debug] arbitration lost
2023-12-25 10:10:10.349 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:10.426 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:10:10.431 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:10:10.431 [bus debug] start request 31
2023-12-25 10:10:10.431 [bus debug] arbitration start with 31
2023-12-25 10:10:10.484 [bus debug] arbitration won
2023-12-25 10:10:10.484 [bus debug] arbitration delay 3 micros
2023-12-25 10:10:10.484 [bus debug] switching from ready to send command
2023-12-25 10:10:10.510 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:10.538 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:10:10.565 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:10.592 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:10.592 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:10.642 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:10.642 [bus info] scan 15 cmd: 3115070400
2023-12-25 10:10:10.642 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:10.642 [bus debug] start request 31
2023-12-25 10:10:10.642 [bus debug] arbitration start with 31
2023-12-25 10:10:11.120 [bus debug] arbitration won
2023-12-25 10:10:11.120 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:11.120 [bus debug] switching from ready to send command
2023-12-25 10:10:11.147 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:11.179 [bus debug] send/receive symbol latency 31 ms
2023-12-25 10:10:11.206 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:11.231 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:11.232 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:11.282 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:11.282 [bus info] scan 16 cmd: 3116070400
2023-12-25 10:10:11.282 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:11.282 [bus debug] start request 31
2023-12-25 10:10:11.282 [bus debug] arbitration start with 31
2023-12-25 10:10:11.761 [bus debug] arbitration won
2023-12-25 10:10:11.762 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:11.762 [bus debug] switching from ready to send command
2023-12-25 10:10:11.787 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:11.814 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:11.839 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:11.864 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:11.864 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:11.893 [bus debug] send/receive symbol latency 29 ms
2023-12-25 10:10:11.893 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:11.958 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:11.959 [bus info] scan 18 cmd: 3118070400
2023-12-25 10:10:11.959 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:10:11.959 [bus debug] start request 31
2023-12-25 10:10:11.959 [bus debug] arbitration start with 31
2023-12-25 10:10:12.399 [bus debug] arbitration lost
2023-12-25 10:10:12.399 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:12.471 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:10:12.477 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:10:12.477 [bus debug] start request 31
2023-12-25 10:10:12.477 [bus debug] arbitration start with 31
2023-12-25 10:10:12.484 [bus debug] ERR: SYN received during receive command, switching to ready
2023-12-25 10:10:12.488 [bus debug] arbitration lost
2023-12-25 10:10:12.488 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:12.564 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:10:12.570 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:10:12.570 [bus debug] start request 31
2023-12-25 10:10:12.570 [bus debug] arbitration start with 31
2023-12-25 10:10:12.640 [bus debug] arbitration won
2023-12-25 10:10:12.640 [bus debug] arbitration delay 1 micros
2023-12-25 10:10:12.640 [bus debug] switching from ready to send command
2023-12-25 10:10:12.666 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:12.693 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:12.727 [bus debug] send/receive symbol latency 33 ms
2023-12-25 10:10:12.754 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:12.754 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:12.782 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:12.782 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:12.786 [bus debug] switching from receive command ACK to receive response
2023-12-25 10:10:12.830 [bus debug] switching from receive response to receive response CRC
2023-12-25 10:10:12.834 [bus debug] notify request: ERR: CRC error
2023-12-25 10:10:12.834 [bus info] scan 19 cmd: 3119070400
2023-12-25 10:10:12.834 [bus debug] ERR: CRC error during receive response CRC, switching to send response ACK
2023-12-25 10:10:12.926 [bus debug] ERR: read timeout during send response ACK, switching to skip
2023-12-25 10:10:12.926 [bus debug] start request 31
2023-12-25 10:10:12.926 [bus debug] arbitration start with 31
2023-12-25 10:10:13.370 [bus debug] arbitration won
2023-12-25 10:10:13.370 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:13.370 [bus debug] switching from ready to send command
2023-12-25 10:10:13.400 [bus debug] send/receive symbol latency 29 ms
2023-12-25 10:10:13.425 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:13.450 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:13.479 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:10:13.479 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:13.504 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:13.504 [bus debug] switching from send command CRC to receive command ACK
2023-12-25 10:10:13.570 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:13.570 [bus info] scan 1a cmd: 311a070400
2023-12-25 10:10:13.570 [bus debug] ERR: read timeout during receive command ACK, switching to skip
2023-12-25 10:10:13.570 [bus debug] start request 31
2023-12-25 10:10:13.570 [bus debug] arbitration start with 31
2023-12-25 10:10:14.036 [bus debug] arbitration won
2023-12-25 10:10:14.036 [bus debug] arbitration delay 1 micros
2023-12-25 10:10:14.036 [bus debug] switching from ready to send command
2023-12-25 10:10:14.064 [bus debug] send/receive symbol latency 27 ms
2023-12-25 10:10:14.089 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:14.114 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:14.143 [bus debug] send/receive symbol latency 29 ms
2023-12-25 10:10:14.143 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:14.194 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:14.194 [bus info] scan 1b cmd: 311b070400
2023-12-25 10:10:14.194 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:14.194 [bus debug] start request 31
2023-12-25 10:10:14.194 [bus debug] arbitration start with 31
2023-12-25 10:10:14.647 [bus debug] arbitration lost
2023-12-25 10:10:14.648 [bus debug] ERR: arbitration lost during ready, retry
2023-12-25 10:10:14.730 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:10:14.736 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:10:14.736 [bus debug] start request 31
2023-12-25 10:10:14.736 [bus debug] arbitration start with 31
2023-12-25 10:10:14.854 [bus debug] ERR: CRC error during receive command CRC, switching to receive command ACK
2023-12-25 10:10:14.859 [bus debug] ERR: ACK error during receive command ACK, switching to skip
2023-12-25 10:10:14.890 [bus debug] arbitration won
2023-12-25 10:10:14.890 [bus debug] arbitration delay 3 micros
2023-12-25 10:10:14.890 [bus debug] switching from ready to send command
2023-12-25 10:10:14.916 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:14.941 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:14.967 [bus debug] send/receive symbol latency 25 ms
2023-12-25 10:10:14.992 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:14.992 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:15.042 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:15.042 [bus info] scan 1c cmd: 311c070400
2023-12-25 10:10:15.042 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:15.042 [bus debug] start request 31
2023-12-25 10:10:15.042 [bus debug] arbitration start with 31
2023-12-25 10:10:15.518 [bus debug] arbitration won
2023-12-25 10:10:15.518 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:15.518 [bus debug] switching from ready to send command
2023-12-25 10:10:15.543 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:15.572 [bus debug] send/receive symbol latency 29 ms
2023-12-25 10:10:15.602 [bus debug] send/receive symbol latency 30 ms
2023-12-25 10:10:15.628 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:15.629 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:15.679 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:15.679 [bus info] scan 1d cmd: 311d070400
2023-12-25 10:10:15.679 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:15.679 [bus debug] start request 31
2023-12-25 10:10:15.679 [bus debug] arbitration start with 31
2023-12-25 10:10:16.154 [bus debug] arbitration won
2023-12-25 10:10:16.154 [bus debug] arbitration delay 2 micros
2023-12-25 10:10:16.154 [bus debug] switching from ready to send command
2023-12-25 10:10:16.179 [bus debug] send/receive symbol latency 24 ms
2023-12-25 10:10:16.209 [bus debug] send/receive symbol latency 30 ms
2023-12-25 10:10:16.235 [bus debug] send/receive symbol latency 26 ms
2023-12-25 10:10:16.264 [bus debug] send/receive symbol latency 28 ms
2023-12-25 10:10:16.264 [bus debug] switching from send command to send command CRC
2023-12-25 10:10:16.314 [bus debug] notify request: ERR: read timeout
2023-12-25 10:10:16.314 [bus info] scan 1e cmd: 311e070400
2023-12-25 10:10:16.314 [bus debug] ERR: read timeout during send command CRC, switching to skip
2023-12-25 10:10:16.314 [bus debug] start request 31
2023-12-25 10:10:16.314 [bus debug] arbitration start with 31
2023-12-25 10:10:16.770 [bus debug] arbitration lost