(cc back to list)
I've never used this ENET2 master, so I don't really know what to expect
from the communication, so hard to say what's happning.. Hopefully
someone else on the list have used it and might shed some light on it.
One thing which would be useful to add to owfs debug output is
timestamps or at least relative time since last msg... Would be useful
in log dumps like this :)
Johan
On 17/11/17 18:12, Andrew Brownsword wrote:
Well my usage of owcapi is just OW_get at the root, and then iterate across
each sensor and use OW_get again to retrieve its r_address, temperature,
humidity, vad, and vdd values. For sensors without a given quantity, OW_get
returns instantly, but for the quantities which actually exist there is a
lengthy delay and a lot of owserver output.
My 1-wire network does have some noise on it (mostly caused by an unfortunate
proximity to some wires carrying PWM signals driving LEDs), but the
OW-SERVER-ENET2’s built-in software does a good job of managing that — it reads
17-22 sensors on each iteration, and a different mixture each time so the net
effect is that a few of the sensors just update at a slower rate (up to 10
seconds instead of 1-2 seconds). At this point I’m leaning heavily toward
getting a second OW-SERVER-ENET2 and continuing to their CSV interface.
Bifurcating by 1-wire network should isolate the noise problem to sensors whose
update rate doesn’t matter as much.
A short run produce a few megabytes of debug output, but most of it is looks
like variations on this theme:
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: loop.c:(109) Taking too long, send a keep-alive pulse
DEBUG: to_client.c:(76) payload=-1 size=0, ret=0, sg=0x0 offset=0
DEBUG: to_client.c:(83) Send delay message (ping)
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_transaction.c:(373) pack=(U)DELAYS
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=2
DEBUG: ow_tcp_read.c:(63) attempt 4 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 4 - 0 = 4
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(465) unpacking #0 DELAY
DEBUG: ow_transaction.c:(425) unpacking #1 READ MODIFY
DEBUG: ow_1820.c:(1088) BUS_transaction done after 90ms
DEBUG: ow_transaction.c:(311) pack=SELECT
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(339) pack=MATCH MODIFY BLIND
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(323) pack=READ
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(369) pack=CRC*
DEBUG: ow_transaction.c:(251) Item added
DEBUG: ow_transaction.c:(274) Ship Packets=4
DEBUG: ow_select.c:(70) Selecting a path (and device)
path=/28.FF48573A0400/temperature12 SN=28 FF 48 57 3A 04 00 4E last path=00 00
00 00 00 00 00 00
DEBUG: ow_select.c:(74) Use adapter-specific select routine
DEBUG: ow_tcp_read.c:(63) attempt 3 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 3 - 0 = 3
DEBUG: ow_tcp_read.c:(63) attempt 3 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 3 - 0 = 3
DEBUG: ow_tcp_read.c:(63) attempt 22 bytes Time: 0.6000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 22 - 0 = 22
DEBUG: ow_transaction.c:(399) unpacking
DEBUG: ow_transaction.c:(481) unpacking #0 NOP or SELECT
DEBUG: ow_transaction.c:(417) unpacking #1 MATCH
DEBUG: ow_transaction.c:(425) unpacking #2 READ MODIFY
DEBUG: ow_transaction.c:(441) unpacking #3 CRC8
DEBUG: ow_read.c:(620) Read /28.FF48573A0400/temperature12 Extension 0 Gives
result 0
DEBUG: ow_cache.c:(384) Adding data for /28.FF48573A0400/temperature12
DEBUG: ow_cache.c:(421) 28 FF 48 57 3A 04 00 4E size=8
DEBUG: ow_cache.c:(635) Add to cache sn 28 FF 48 57 3A 04 00 4E
pointer=0x76f28a48 index=0 size=8
DEBUG: ow_parsename.c:(63) /28.FF48573A0400/temperature12
DEBUG: ow_read.c:(620) Read /28.FF48573A0400/temperature Extension 0 Gives
result 0
DEBUG: ow_cache.c:(384) Adding data for /28.FF48573A0400/temperature
DEBUG: ow_read.c:(253) return=0
Byte buffer OWQ_parse_output_offset_and_size, length=6
--000: 32 38 2E 36 32 35
<28.625>
DEBUG: ow_read.c:(263) After read is performed (bytes or error 6)
OWQ OneWireQuery structure of /28.FF48573A0400/temperature
OneWireQuery size=12 offset=0, extension=0
Byte buffer OneWireQuery buffer, length=12
--000: 32 38 2E 36 32 35 00 00 00 00 00 00
<28.625......>
Cleanup = 0006 OneWireQuery I=6 U=6 F=28.625 Y=6 D=Wed Dec 31 16:00:06
1969
--- OneWireQuery done
DEBUG: ow_read.c:(226) /28.FF48573A0400/temperature returns 6
DEBUG: ow_read.c:(103) /28.FF48573A0400/temperature return 6
DEBUG: read.c:(81) ReadHandler: FS_read_postparse read on
/28.FF48573A0400/temperature return = 6
OWQ OneWireQuery structure of /28.FF48573A0400/temperature
OneWireQuery size=12 offset=0, extension=0
Byte buffer OneWireQuery buffer, length=12
--000: 32 38 2E 36 32 35 00 00 00 00 00 00
<28.625......>
Cleanup = 0006 OneWireQuery I=6 U=6 F=28.625 Y=6 D=Wed Dec 31 16:00:06
1969
--- OneWireQuery done
DEBUG: read.c:(89) ReadHandler: FS_read_postparse ok size=6
DEBUG: read.c:(100) ReadHandler: To Client cm->payload=6 cm->size=6
cm->offset=0
Byte buffer Data returned to client, length=6
-- NULL buffer
DEBUG: data.c:(146) Read message done value=0x747122c8
DEBUG: ow_parsename.c:(63) /28.FF48573A0400/temperature
DEBUG: data.c:(193) DataHandler: FS_ParsedName_destroy done
DEBUG: data.c:(207) DataHandler: cm.ret=6
DEBUG: to_client.c:(76) payload=6 size=6, ret=6, sg=0x144 offset=0
DEBUG: data.c:(226) Finished with client request
DEBUG: handler.c:(132) OWSERVER tcp connection persistence -- reusing
connection now.
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:(66) FromClient payload=27 size=16 type=2 sg=0x144
offset=0
DEBUG: from_client.c:(74) FromClient (no servermessage) payload=27 size=16
type=2 controlflags=0x144 offset=0
DEBUG: ow_tcp_read.c:(63) attempt 27 bytes Time: 10.000000 seconds
DEBUG: ow_tcp_read.c:(113) read: 27 - 0 = 27
DEBUG: handler.c:(73) Persistence requested
DEBUG: handler.c:(153) START handler /28.FF18573A0400/r_address
CALL: data.c:(103) DataHandler: parse path=/28.FF18573A0400/r_address
DEBUG: ow_parseobject.c:(163) /28.FF18573A0400/r_address
CALL: ow_parsename.c:(104) path=[/28.FF18573A0400/r_address]
DEBUG: ow_regex.c:(154) Not found
DEBUG: ow_regex.c:(201) 0: 0->15 found <><28.FF18573A0400><>
DEBUG: ow_regex.c:(201) 1: 0->2 found <><28><.FF18573A0400>
DEBUG: ow_regex.c:(201) 2: 3->15 found <28.><FF18573A0400><>
DEBUG: ow_cache.c:(912) Looking for device 28 FF 18 57 3A 04 00 DB
DEBUG: ow_cache.c:(1070) Search in cache sn 28 FF 18 57 3A 04 00 DB
pointer=0x76f42d40 index=0 size=4
DEBUG: ow_cache.c:(1086) Value found in cache. Remaining life: 8 seconds.
DEBUG: ow_presence.c:(75) Found device on bus 2
DEBUG: ow_regex.c:(154) Not found
CALL: data.c:(144) Read message
DEBUG: read.c:(55) ReadHandler start
DEBUG: read.c:(61) ReadHandler: From Client sm->payload=27 sm->size=16
sm->offset=0
DEBUG: read.c:(79) ReadHandler: call FS_read_postparse on
/28.FF18573A0400/r_address
DEBUG: ow_read.c:(72) /28.FF18573A0400/r_address
DEBUG: ow_read.c:(204) /28.FF18573A0400/r_address
DEBUG: ow_read.c:(238) About to read </28.FF18573A0400/r_address>
extension=0 size=16 offset=0
DEBUG: ow_read.c:(333) file_length=16 offset=0 size=16
Byte buffer OWQ_parse_output_offset_and_size, length=16
--000: 44 42 30 30 30 34 33 41 35 37 31 38 46 46 32 38
<DB00043A5718FF28>
DEBUG: ow_read.c:(620) Read /28.FF18573A0400/r_address Extension 0 Gives
result 0
DEBUG: ow_cache.c:(374) Adding data for /28.FF18573A0400/r_address
DEBUG: ow_read.c:(253) return=0
OWQ OneWireQuery structure of /28.FF18573A0400/r_address
OneWireQuery size=16 offset=0, extension=0
Byte buffer OneWireQuery buffer, length=16
--000: 44 42 30 30 30 34 33 41 35 37 31 38 46 46 32 38
<DB00043A5718FF28>
Cleanup = 0006 OneWireQuery I=16 U=16 F=7.90505E-323 Y=16 D=Wed Dec 31
16:00:16 1969
--- OneWireQuery done
On Nov 17, 2017, at 8:27 AM, Johan Ström <jo...@stromnet.se> wrote:
On 17/11/17 16:10, Andrew Brownsword wrote:
Decided to try owcapi through owserver with my application (I had opted against
owserver because it seems quite flakey at startup when the system reboots),
just to see how it works. Unfortunately it appears to discover even fewer of
the sensors than the OW-SERVER-ENET2’s built-in code (varies from 12-17 of the
22 sensors on the 3 1-wire buses), and the rate at which owserver delivers
responses to my application is terrible — on the order of 1 per second.
That sounds like either a weird usage of owcapi, or bad 1-Wire network. Do you
experience the same issues when using shell tools owdir/owread etc?
If so, please run owserver with --debug --foreground and see if it says
something interesting.
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Owfs-developers mailing list
Owfs-developers@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/owfs-developers
