Yeah, coming at this cold the debug info isn’t especially useful. For me it’s moot now though — I just ordered a second enet2 box and that will give me up to 44 sensors via their nice, simple, compact and fast http query format. Since my software already handles this quite well, owfs is no longer needed. I suppose I’ll be dropping off this list shortly.
Somebody should fix the fact that OW_init_args() doesn’t call LibStart though — that seems like an outright bug?! > On Nov 17, 2017, at 11:50 AM, Johan Ström <jo...@stromnet.se> wrote: > > (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
