owfs / owfs

Home of the OWFS project source code
GNU General Public License v2.0
95 stars 43 forks source link

DS2408 writing to multiple outputs in quick succession #104

Open AnduriI opened 2 years ago

AnduriI commented 2 years ago

Hello,

I use owfs to controll a few modules with ds2408 in them. I wrote a python script to read the PIO.ALL and send it to mqtt. When a mqtt arrives it writes to the corresponding PIO.X (0-7). That works great as long as I don't send too much messages at once. I can see them all arrive and trying to be written, but I suppose the owfs can not handle writing them quickly and some get lost. When writing all 8 outputs 3-5 are fine and the rest just stays in their old state. Is that a limitation of owfs or can I somehow account for that? Up to know I optimized my script to only write changed bits and wait 0.5s after each write, but that's not great... maybe there is a better solution. I also thought about writing them all in one got, but that would mean to process them to a buffer and wait for incoming mqtts until they are written, which adds a huge amount of complexity to that script.

I hope someone can help or give some advice.

Thanks in advance, Anduril

miccoli commented 2 years ago

Which interface to OWFS are you using? Can you share an outline of your python code?

AnduriI commented 2 years ago

well I'm not that into the naming convention with this project, so I'm not sure what the interface is... but I'll explain my setup and hope you can ask more specific in case you need to know more. I run a raspberry pi connected to a DS2482 1-wire bus master. According to my apt I have installed owfs-common, owfs-fuse and owfs (all version 3.2p3) and mounted that file system to /home/pi/1-wire. I can see folders for the devices connected, one ds18b20 and 2 relay modules containing the ds2408.

~/1-wire $ ls
28.83755E070000  29.4E05981B0000  alarm  settings      structure
28.83755E070000  29.E397471B0000  bus.0  simultaneous  system
29.4E05981B0000  29.E397471B0000  bus.1  statistics    uncached

(by the way: is it normal that they appear doubled?) I told my script to react to incoming mqtt messages, decode module, number and state and write it to the corresponding file:

#!/usr/bin/python3
import os
import subprocess
import sh
import time
import psutil
import paho.mqtt.client as mqtt
import RPi.GPIO as GPIO

MOSQUITTO_HOST = 'IP'
MOSQUITTO_PORT = 1883
MOSQUITTO_USER = 'me'
MOSQUITTO_PWD  = 'mypassword'

Schalter1 = "/home/pi/1-wire/29.E397471B0000/PIO."
Schalter2 = "/home/pi/1-wire/29.4E05981B0000/PIO."

varSchalter1Value = (0,0,0,0,0,0,0,0,0)
varSchalter1Alt= (0,0,0,0,0,0,0,0,0)
varSchalter2Value = (0,0,0,0,0,0,0,0,0)
varSchalter2Alt= (0,0,0,0,0,0,0,0,0)
####################
def on_message(client, userdata, message):
    #
    # Read MQTT Sub
    #
    MqttTopic = message.topic[:14]
    Msg = int(message.payload.decode("utf-8"))
    Pause = 0.25
#    print(message.topic)
#    print(message.payload.decode("utf-8"))
    if MqttTopic == "ESERA/KG1/Schr":
        number= int(message.topic[20:]) - 1
        if varSchalter1Value[number] != Msg:
            f = open(Schalter1 + str(number), "w")
            f.write(str(Msg))
            f.close()
            time.sleep(Pause)
    elif MqttTopic == "ESERA/KG2/Schr":
        number= int(message.topic[20:]) - 1
        if varSchalter2Value[number] != Msg:
            f = open(Schalter2 + str(number), "w")
            f.write(str(message.payload.decode("utf-8")))
            f.close()
            time.sleep(Pause)
    elif MqttTopic == "ESERA/KG1/PING" and message.payload.decode("utf-8") == "0":
        mqttc.publish("ESERA/KG1/PING", 1, qos=2, retain=True)

####################

mqttc = mqtt.Client("1wire-daemon-KG")
mqttc.on_message=on_message
mqttc.username_pw_set(MOSQUITTO_USER,MOSQUITTO_PWD)
mqttc.connect(MOSQUITTO_HOST,MOSQUITTO_PORT);
mqttc.subscribe("ESERA/KG1/Schreiben/#",1)
mqttc.subscribe("ESERA/KG2/Schreiben/#",1)
mqttc.subscribe("ESERA/KG1/PING",1)
mqttc.publish("ESERA/Status", "Verbindung Keller erfolgreich")
time.sleep(.1)

of course it also reads back the status and does some other minor things (like querying a motion sensor on one of the GPIOs), but I don't think that will be a problem. Now I tried to send multiple commands in a row. I can see them all being transmitted via mqtt, but it seems the 1-wire bus can not keep up with the single writes and misses some of them. I have to add this pause after a write to make it more reliable. Is that always needed with owfs?

Regards, Anduril

miccoli commented 2 years ago

Please do not use owfs-fuse which is deprecated and not supported anymore. Moreover it is very likely that it is owfs-fuse that is the very source of your problems.

The preferred setup is using owserver as a backend, and then a language binding of your choice as front-end.

So my suggestion is

As what regards the python interface you can

I wrote pyownet. It's use is quite simple:

from pyownet import protocol

## save a single owproxy, to be used in the whole program
owproxy = protocol.proxy()

## later
owproxy.write(f"/29.E397471B0000/PIO.{number}", message.payload)

Here I'm assuming that message.payload is of type bytes.

AnduriI commented 2 years ago

Thank you for your help. I removed owfs-fuse and installed ow-shell (owserver was already, but missed it in my listing because of wrong search argument). I also already tweaked my python script to work with the new commands. I will try if the timing issue is solved now as soon as I have the time (and wifes approval) to get crazy on all lights...

AnduriI commented 2 years ago

well it very much looks like that pause is still needed, otherwise some of those commands are dropped. Is there something incorrect in my usage? Would be great if anyone can give me a hint.


#!/usr/bin/python3
import os
import subprocess
import sh
import time
import psutil
import paho.mqtt.client as mqtt
import RPi.GPIO as GPIO
from pyownet import protocol

## save a single owproxy, to be used in the whole program
owproxy = protocol.proxy()

# Deklaration des GPIO4 als Input
GPIO.setmode(GPIO.BCM)
Pin = 17
GPIO.setup(Pin,GPIO.IN)

# Zwischenvariablen
movement  = 0
active = 0

MOSQUITTO_HOST = 'IP'
MOSQUITTO_PORT = 1883
MOSQUITTO_USER = 'me'
MOSQUITTO_PWD  = 'mypassword'

Schalter1 = "/29.E397471B0000/PIO."
Schalter2 = "/29.4E05981B0000/PIO."

varSchalter1Value = (0,0,0,0,0,0,0,0,0)
varSchalter1Alt= (0,0,0,0,0,0,0,0,0)
varSchalter2Value = (0,0,0,0,0,0,0,0,0)
varSchalter2Alt= (0,0,0,0,0,0,0,0,0)
####################
def on_message(client, userdata, message):
    #
    # Read MQTT Sub
    #
    MqttTopic = message.topic[:14]
    Msg = int(message.payload.decode("utf-8"))
    Pause = 0.25
    if MqttTopic == "ESERA/KG1/Schr":
        number= int(message.topic[20:]) - 1
        if varSchalter1Value[number] != Msg:
            owproxy.write(f"{Schalter1}.{number}", bytes(message.payload))
            time.sleep(Pause)
        #varSchalter1Alt[1]=2
    elif MqttTopic == "ESERA/KG2/Schr":
        number= int(message.topic[20:]) - 1
        if varSchalter2Value[number] != Msg:
            owproxy.write(f"{Schalter2}.{number}", bytes(message.payload))
            time.sleep(Pause)
        #varSchalter2Alt[1]=2
    elif MqttTopic == "ESERA/KG1/PING" and message.payload.decode("utf-8") == "0":
        mqttc.publish("ESERA/KG1/PING", 1, qos=2, retain=True)

####################
def get_1wire_sensor(path):
    #
    # Function to read 1-Wire sensors using OWFS
    #
    time.sleep(.1)
    for attempt in range(10):
        try:
            text = str(owproxy.read(f"{path}.ALL"))[2:17]
            textSplit = text.split(",",8)
            mymap = map (int, textSplit)
            mylist = list(mymap)
            #print("erfolgreich")
            return mylist
        except:
            print(str(attempt + 1) + ". Versuch fehlgeschlagen")
    else:
        print("endgültig fehlgeschlagen")
        return [2,2,2,2,2,2,2,2]
####################
time.sleep(.5)
print("Starte")
mqttc = mqtt.Client("1wire-daemon-KG")
mqttc.on_message=on_message
mqttc.username_pw_set(MOSQUITTO_USER,MOSQUITTO_PWD)
mqttc.connect(MOSQUITTO_HOST,MOSQUITTO_PORT);
mqttc.subscribe("ESERA/KG1/Schreiben/#",1)
mqttc.subscribe("ESERA/KG2/Schreiben/#",1)
mqttc.subscribe("ESERA/KG1/PING",1)
mqttc.publish("ESERA/Status", "Verbindung Keller erfolgreich")
time.sleep(.1)

try:
    while (True):
        mqttc.loop_start()
        varSchalter1Value = get_1wire_sensor(Schalter1)
        time.sleep(.1)
        if varSchalter1Value[0] != 2 and varSchalter1Value !=varSchalter1Alt:
            mqttc.publish(publish new state); time.sleep(.1)
            varSchalter1Alt = varSchalter1Value
        varSchalter2Value = get_1wire_sensor(Schalter2)
        time.sleep(.1)
        if varSchalter2Value[0] != 2 and varSchalter2Value !=varSchalter2Alt:
            mqttc.publish(publish new state here); time.sleep(.1)
            varSchalter2Alt = varSchalter2Value
        time.sleep(.1)
        mqttc.loop_stop()
miccoli commented 2 years ago

It seems to me that your pyownet usage is basically correct, although a little bit unpythonic.

E.g. `str(owproxy.read(f"{path}.ALL"))[2:17]` should be `owproxy.read(f"{path}.ALL")).decode()`: try to avoid `str` and `bytes` functions but use `decode` and `encode` methods, which are much more explicit and readable. Also avoid catch-all clauses ``` try: ... except: print(str(attempt + 1) + ". Versuch fehlgeschlagen") ``` but use more specific and informative constructs ``` try: ... except protocol.Error as err print(f"{attempt + 1:d}. Versuch fehlgeschlagen: {err}") ```

If I got it right, your problem is that if you have multiple

owproxy.write(f"/29.xxxxxxxx0000/PIO.{number}", message.payload.encode())

calls in a tight loop, some commands are dropped.

There could be multiple causes:

  1. an owfs bug
  2. electrical problems on your 1-wire network
  3. ... (?)

In order to pinpoint the problem you should:

  1. describe your 1-wire network setup: which bus-mater are you using, etc.
  2. publish a copy of your /etc/owfs.config file
  3. run owserver in debug mode.

For running owserver in debug mode, the simplest approach is to stop owserver.service and to run from the command line (if necessary as root)

/usr/bin/owserver -c /etc/owfs.conf --foreground --debug

You will be inundated by a very verbose debug output, but maybe you can find a relevant error message.

I'm not very proficient into the details of 1-wire timing problems, so I think I will not be able to help you pinpointing this issue: but maybe someone more expert can help.

As a general suggestion, maybe instead of inserting a fixed time.sleep it is sufficient to add a read:

owproxy.write(f"/29.xxxxxxxx0000/PIO.{number}", message.payload.encode())
while True:
    if message.payload.encode() == int(owproxy.read(f"/29.xxxxxxxx0000/PIO.{number}"):
        break
    print("Write failed")
    time.sleep(Pause)
AnduriI commented 2 years ago

a little bit unpythonic.

That's a nice version of saying I don't know how to python 😄 well I just kinda picked various pieces from around the internet and made them do what I wanted. But I'm only a newbie in pthon and never learned how to do it properly. You exactly got the point of my problem. Now to the description of my setup: the RPi running this python is connected with I2C to a bare DS2482-100 chip mounted next to the pi. This 1-wire bus master is than connected to two relay modules containing the DS2408 chips with common ground and 1-wire, but the relay modules have a separate 12V power supply. I also have a second setup like this in my power distribution panel upstairs with the exact same behaviour.

  GNU nano 3.2                    /etc/owfs.conf                                

# Sample configuration file for the OWFS suite for Debian GNU/Linux.
#
#
# This is the main OWFS configuration file. You should read the
# owfs.conf(5) manual page in order to understand the options listed
# here.

######################## SOURCES ########################
#
# With this setup, any client (but owserver) uses owserver on the
# local machine...
#server: w1
! server: server = localhost:4304
#
# ...and owserver uses the real hardware, by default fake devices
# This part must be changed on real installation
#server: FAKE = DS18S20,DS2405
#
# USB device: DS9490
#server: usb = all
#
# Serial port: DS9097
server: device = /dev/i2c-1
#
# owserver tcp address
#server: server = 192.168.10.1:3131
#
# random simulated device
#server: FAKE = DS18S20,DS2405
#
######################### OWFS ##########################
#
#mountpoint = /home/pi/1-wire
#allow_other
#
####################### OWHTTPD #########################

#http: port = 2121

####################### OWFTPD ##########################

#ftp: port = 2120

####################### OWSERVER ########################

server: port = localhost:4304

For the debug: how do I completely shutdown owserver? with systemctl stop owserver and trying with your owserver call it says [Address already in use] Bind problem [localhost:4304]. I suppose there is still some component running on that port...

miccoli commented 2 years ago

For the debug: how do I completely shutdown owserver? with systemctl stop owserver and trying with your owserver call it says [Address already in use] Bind problem [localhost:4304]. I suppose there is still some component running on that port...

Probably you have the owserver.socket service enabled, which is responsible for the socket-based activation of owserver. This means that systemd is listening on socket :4304, preventing owserver from starting.

I would try

$ systemclt stop owserver.socket
$ systemclt stop owserver.service

you can then double check with ss state all sport :4304 -p that the socket is indeed free.

owfs.conf is OK for me. Unfortunately I have no experience with your setup, so my suggestion is to do a little experimentation and check if the debug log contains some clues on the reason for which the writes to the are unsuccessful.

AnduriI commented 2 years ago

running owserver with debug output gave quite some lines... First I run the original script without pausing and as expected some write dropped (in hardware). I tried to read the logs, but maybe you can see something I didn't. PIO.0 and PIO.3 wrote just fine, 1 and 2 failed. Hope I picked the right starting point.

  DEBUG: handler.c:(152) START handler /29.E397471B0000/PIO..0
   CALL: data.c:(103) DataHandler: parse path=/29.E397471B0000/PIO..0
  DEBUG: ow_parseobject.c:(163) /29.E397471B0000/PIO..0
   CALL: ow_parsename.c:(174) path=[/29.E397471B0000/PIO..0]
  DEBUG: ow_regex.c:(53) Not found
  DEBUG: ow_regex.c:(100) 0: 0->15 found <><29.E397471B0000><>
  DEBUG: ow_regex.c:(100) 1: 0->2 found <><29><.E397471B0000>
  DEBUG: ow_regex.c:(100) 2: 3->15 found <29.><E397471B0000><>
  DEBUG: ow_cache.c:(912) Looking for device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_cache.c:(1070) Search in cache sn 29 E3 97 47 1B 00 00 58 pointer=0xb6f78bb0 index=0 size=4
  DEBUG: ow_cache.c:(1086) Value found in cache. Remaining life: 77 seconds.
  DEBUG: ow_presence.c:(75) Found device on bus 1
  DEBUG: ow_regex.c:(100) 0: 3->4 found <PIO><.><.0>
  DEBUG: ow_regex.c:(100) 0: 4->6 found <PIO.><.0><>
   CALL: data.c:(149) Write message
  DEBUG: write.c:(50) WriteHandler: hd->sm.payload=25 hd->sm.size=1 hd->sm.offset=0 OWQ_size=1 OWQ_offset=0
OWQ OneWireQuery structure of /29.E397471B0000/PIO..0
    OneWireQuery size=1 offset=0, extension=0
Byte buffer OneWireQuery buffer, length=1
--000: 31
   <1>
    Cleanup = 0002    OneWireQuery I=1 U=1 F=4.94066E-324 Y=1 D=Thu Jan  1 01:00:01 1970

--- OneWireQuery done
  DEBUG: ow_write.c:(455) Write an aggregate element /29.E397471B0000/PIO..0
  DEBUG: ow_parseobject.c:(114) /29.E397471B0000/PIO..0 with extension -2
  DEBUG: ow_read.c:(333) file_length=12 offset=0 size=1
  DEBUG: ow_read.c:(401) Read an aggregate .BYTE /29.E397471B0000/PIO..0
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..0 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(184) CRC16 = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_read.c:(620) Read /29.E397471B0000/PIO..0 Extension -2 Gives result 0
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..0 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_cache.c:(1362) Delete from cache sn 29 E3 97 47 1B 00 00 58 in=0xb6f62f58 index=-2
  DEBUG: ow_write.c:(495) Write /29.E397471B0000/PIO..0 Extension -2 Gives result 0
  DEBUG: ow_write.c:(110) Successful write to /29.E397471B0000/PIO..0
  DEBUG: ow_parsename.c:(133) /29.E397471B0000/PIO..0
  DEBUG: data.c:(193) DataHandler: FS_ParsedName_destroy done
  DEBUG: data.c:(207) DataHandler: cm.ret=0
  DEBUG: to_client.c:(75) payload=0 size=1, ret=0, sg=0x0 offset=0 
  DEBUG: to_client.c:(84) No data
  DEBUG: data.c:(226) Finished with client request
  DEBUG: handler.c:(134) OWSERVER handler done
  DEBUG: ow_net_server.c:(259) Normal completion.
  DEBUG: ow_tcp_read.c:(63) attempt 24 bytes Time: 10.000000 seconds
  DEBUG: ow_tcp_read.c:(113) read: 24 - 0 = 24
  DEBUG: from_client.c:(65) FromClient payload=25 size=1 type=3 sg=0x0 offset=0
  DEBUG: from_client.c:(73) FromClient (no servermessage) payload=25 size=1 type=3 controlflags=0x0 offset=0
  DEBUG: ow_tcp_read.c:(63) attempt 25 bytes Time: 10.000000 seconds
  DEBUG: ow_tcp_read.c:(113) read: 25 - 0 = 25
  DEBUG: handler.c:(152) START handler /29.E397471B0000/PIO..1
   CALL: data.c:(103) DataHandler: parse path=/29.E397471B0000/PIO..1
  DEBUG: ow_parseobject.c:(163) /29.E397471B0000/PIO..1
   CALL: ow_parsename.c:(174) path=[/29.E397471B0000/PIO..1]
  DEBUG: ow_regex.c:(53) Not found
  DEBUG: ow_regex.c:(100) 0: 0->15 found <><29.E397471B0000><>
  DEBUG: ow_regex.c:(100) 1: 0->2 found <><29><.E397471B0000>
  DEBUG: ow_regex.c:(100) 2: 3->15 found <29.><E397471B0000><>
  DEBUG: ow_cache.c:(912) Looking for device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_cache.c:(1070) Search in cache sn 29 E3 97 47 1B 00 00 58 pointer=0xb6f78bb0 index=0 size=4
  DEBUG: ow_cache.c:(1086) Value found in cache. Remaining life: 77 seconds.
  DEBUG: ow_presence.c:(75) Found device on bus 1
  DEBUG: ow_regex.c:(100) 0: 3->4 found <PIO><.><.1>
  DEBUG: ow_regex.c:(100) 0: 4->6 found <PIO.><.1><>
   CALL: data.c:(149) Write message
  DEBUG: write.c:(50) WriteHandler: hd->sm.payload=25 hd->sm.size=1 hd->sm.offset=0 OWQ_size=1 OWQ_offset=0
OWQ OneWireQuery structure of /29.E397471B0000/PIO..1
    OneWireQuery size=1 offset=0, extension=1
Byte buffer OneWireQuery buffer, length=1
--000: 31
   <1>
    Cleanup = 0002    OneWireQuery I=1 U=1 F=4.94066E-324 Y=1 D=Thu Jan  1 01:00:01 1970

--- OneWireQuery done
  DEBUG: ow_write.c:(455) Write an aggregate element /29.E397471B0000/PIO..1
  DEBUG: ow_parseobject.c:(114) /29.E397471B0000/PIO..1 with extension -2
  DEBUG: ow_read.c:(333) file_length=12 offset=0 size=1
  DEBUG: ow_read.c:(401) Read an aggregate .BYTE /29.E397471B0000/PIO..1
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..1 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(184) CRC16 = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_read.c:(620) Read /29.E397471B0000/PIO..1 Extension -2 Gives result 0
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..1 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_cache.c:(1362) Delete from cache sn 29 E3 97 47 1B 00 00 58 in=0xb6f62f58 index=-2
  DEBUG: ow_write.c:(495) Write /29.E397471B0000/PIO..1 Extension -2 Gives result 0
  DEBUG: ow_write.c:(110) Successful write to /29.E397471B0000/PIO..1
  DEBUG: ow_parsename.c:(133) /29.E397471B0000/PIO..1
  DEBUG: data.c:(193) DataHandler: FS_ParsedName_destroy done
  DEBUG: data.c:(207) DataHandler: cm.ret=0
  DEBUG: to_client.c:(75) payload=0 size=1, ret=0, sg=0x0 offset=0 
  DEBUG: to_client.c:(84) No data
  DEBUG: data.c:(226) Finished with client request
  DEBUG: handler.c:(134) OWSERVER handler done
  DEBUG: ow_net_server.c:(259) Normal completion.
  DEBUG: ow_tcp_read.c:(63) attempt 24 bytes Time: 10.000000 seconds
  DEBUG: ow_tcp_read.c:(113) read: 24 - 0 = 24
  DEBUG: from_client.c:(65) FromClient payload=25 size=1 type=3 sg=0x0 offset=0
  DEBUG: from_client.c:(73) FromClient (no servermessage) payload=25 size=1 type=3 controlflags=0x0 offset=0
  DEBUG: ow_tcp_read.c:(63) attempt 25 bytes Time: 10.000000 seconds
  DEBUG: ow_tcp_read.c:(113) read: 25 - 0 = 25
  DEBUG: handler.c:(152) START handler /29.E397471B0000/PIO..2
   CALL: data.c:(103) DataHandler: parse path=/29.E397471B0000/PIO..2
  DEBUG: ow_parseobject.c:(163) /29.E397471B0000/PIO..2
   CALL: ow_parsename.c:(174) path=[/29.E397471B0000/PIO..2]
  DEBUG: ow_regex.c:(53) Not found
  DEBUG: ow_regex.c:(100) 0: 0->15 found <><29.E397471B0000><>
  DEBUG: ow_regex.c:(100) 1: 0->2 found <><29><.E397471B0000>
  DEBUG: ow_regex.c:(100) 2: 3->15 found <29.><E397471B0000><>
  DEBUG: ow_cache.c:(912) Looking for device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_cache.c:(1070) Search in cache sn 29 E3 97 47 1B 00 00 58 pointer=0xb6f78bb0 index=0 size=4
  DEBUG: ow_cache.c:(1086) Value found in cache. Remaining life: 77 seconds.
  DEBUG: ow_presence.c:(75) Found device on bus 1
  DEBUG: ow_regex.c:(100) 0: 3->4 found <PIO><.><.2>
  DEBUG: ow_regex.c:(100) 0: 4->6 found <PIO.><.2><>
   CALL: data.c:(149) Write message
  DEBUG: write.c:(50) WriteHandler: hd->sm.payload=25 hd->sm.size=1 hd->sm.offset=0 OWQ_size=1 OWQ_offset=0
OWQ OneWireQuery structure of /29.E397471B0000/PIO..2
    OneWireQuery size=1 offset=0, extension=2
Byte buffer OneWireQuery buffer, length=1
--000: 31
   <1>
    Cleanup = 0002    OneWireQuery I=1 U=1 F=4.94066E-324 Y=1 D=Thu Jan  1 01:00:01 1970

--- OneWireQuery done
  DEBUG: ow_write.c:(455) Write an aggregate element /29.E397471B0000/PIO..2
  DEBUG: ow_parseobject.c:(114) /29.E397471B0000/PIO..2 with extension -2
  DEBUG: ow_read.c:(333) file_length=12 offset=0 size=1
  DEBUG: ow_read.c:(401) Read an aggregate .BYTE /29.E397471B0000/PIO..2
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..2 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(184) CRC16 = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_read.c:(620) Read /29.E397471B0000/PIO..2 Extension -2 Gives result 0
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..2 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_cache.c:(1362) Delete from cache sn 29 E3 97 47 1B 00 00 58 in=0xb6f62f58 index=-2
  DEBUG: ow_write.c:(495) Write /29.E397471B0000/PIO..2 Extension -2 Gives result 0
  DEBUG: ow_write.c:(110) Successful write to /29.E397471B0000/PIO..2
  DEBUG: ow_parsename.c:(133) /29.E397471B0000/PIO..2
  DEBUG: data.c:(193) DataHandler: FS_ParsedName_destroy done
  DEBUG: data.c:(207) DataHandler: cm.ret=0
  DEBUG: to_client.c:(75) payload=0 size=1, ret=0, sg=0x0 offset=0 
  DEBUG: to_client.c:(84) No data
  DEBUG: data.c:(226) Finished with client request
  DEBUG: handler.c:(134) OWSERVER handler done
  DEBUG: ow_net_server.c:(259) Normal completion.
  DEBUG: ow_tcp_read.c:(63) attempt 24 bytes Time: 10.000000 seconds
  DEBUG: ow_tcp_read.c:(113) read: 24 - 0 = 24
  DEBUG: from_client.c:(65) FromClient payload=25 size=1 type=3 sg=0x0 offset=0
  DEBUG: from_client.c:(73) FromClient (no servermessage) payload=25 size=1 type=3 controlflags=0x0 offset=0
  DEBUG: ow_tcp_read.c:(63) attempt 25 bytes Time: 10.000000 seconds
  DEBUG: ow_tcp_read.c:(113) read: 25 - 0 = 25
  DEBUG: handler.c:(152) START handler /29.E397471B0000/PIO..3
   CALL: data.c:(103) DataHandler: parse path=/29.E397471B0000/PIO..3
  DEBUG: ow_parseobject.c:(163) /29.E397471B0000/PIO..3
   CALL: ow_parsename.c:(174) path=[/29.E397471B0000/PIO..3]
  DEBUG: ow_regex.c:(53) Not found
  DEBUG: ow_regex.c:(100) 0: 0->15 found <><29.E397471B0000><>
  DEBUG: ow_regex.c:(100) 1: 0->2 found <><29><.E397471B0000>
  DEBUG: ow_regex.c:(100) 2: 3->15 found <29.><E397471B0000><>
  DEBUG: ow_cache.c:(912) Looking for device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_cache.c:(1070) Search in cache sn 29 E3 97 47 1B 00 00 58 pointer=0xb6f78bb0 index=0 size=4
  DEBUG: ow_cache.c:(1086) Value found in cache. Remaining life: 77 seconds.
  DEBUG: ow_presence.c:(75) Found device on bus 1
  DEBUG: ow_regex.c:(100) 0: 3->4 found <PIO><.><.3>
  DEBUG: ow_regex.c:(100) 0: 4->6 found <PIO.><.3><>
   CALL: data.c:(149) Write message
  DEBUG: write.c:(50) WriteHandler: hd->sm.payload=25 hd->sm.size=1 hd->sm.offset=0 OWQ_size=1 OWQ_offset=0
OWQ OneWireQuery structure of /29.E397471B0000/PIO..3
    OneWireQuery size=1 offset=0, extension=3
Byte buffer OneWireQuery buffer, length=1
--000: 31
   <1>
    Cleanup = 0002    OneWireQuery I=1 U=1 F=4.94066E-324 Y=1 D=Thu Jan  1 01:00:01 1970

--- OneWireQuery done
  DEBUG: ow_write.c:(455) Write an aggregate element /29.E397471B0000/PIO..3
  DEBUG: ow_parseobject.c:(114) /29.E397471B0000/PIO..3 with extension -2
  DEBUG: ow_read.c:(333) file_length=12 offset=0 size=1
  DEBUG: ow_read.c:(401) Read an aggregate .BYTE /29.E397471B0000/PIO..3
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..3 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(184) CRC16 = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_read.c:(620) Read /29.E397471B0000/PIO..3 Extension -2 Gives result 0
  DEBUG: ow_select.c:(70) Selecting a path (and device) path=/29.E397471B0000/PIO..3 SN=29 E3 97 47 1B 00 00 58 last path=00 00 00 00 00 00 00 00
  DEBUG: ow_select.c:(84) Continuing root branch
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(620) DS2482 I2C bus /dev/i2c-1:18, channel 0/1 Any devices found on reset? Yes
  DEBUG: ow_select.c:(226) Selecting device 29 E3 97 47 1B 00 00 58
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_transaction.c:(90) select = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(112) send = 0
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_ds2482.c:(516) ok
  DEBUG: ow_transaction.c:(130) readin = 0
  DEBUG: ow_transaction.c:(207) end = 0
  DEBUG: ow_cache.c:(1362) Delete from cache sn 29 E3 97 47 1B 00 00 58 in=0xb6f62f58 index=-2
  DEBUG: ow_write.c:(495) Write /29.E397471B0000/PIO..3 Extension -2 Gives result 0
  DEBUG: ow_write.c:(110) Successful write to /29.E397471B0000/PIO..3
  DEBUG: ow_parsename.c:(133) /29.E397471B0000/PIO..3
  DEBUG: data.c:(193) DataHandler: FS_ParsedName_destroy done
  DEBUG: data.c:(207) DataHandler: cm.ret=0
  DEBUG: to_client.c:(75) payload=0 size=1, ret=0, sg=0x0 offset=0 
  DEBUG: to_client.c:(84) No data
  DEBUG: data.c:(226) Finished with client request
  DEBUG: handler.c:(134) OWSERVER handler done
  DEBUG: ow_net_server.c:(259) Normal completion.

With your intelligent read check I could get them all work, only one had to reread before passing. In case you need them I can also post this logs, but I might have missed some lines due to line history limitation in my console.

miccoli commented 2 years ago

running owserver with debug output gave quite some lines... First I run the original script without pausing and as expected some write dropped (in hardware). I tried to read the logs, but maybe you can see something I didn't. PIO.0 and PIO.3 wrote just fine, 1 and 2 failed.

Yes, debug output is very verbose... Sorry but I cannot help you here, since I'm not an expert in the inner workings of owfs and the 1-wire bus. (I just wrote the python interface, and do a minimal bookkeeping here for affection to this old but great project.)

Just adding the "to be investigated" label, in case someone with better understanding can help, to sort out if this is a OWFS issue or something different (e.g. an HW problem).

In the mean time I hope that the work-around will be sufficient for keeping your project working.