I looked for all messages that contain self.cached_fields.
/var/log/syslog.2.gz:Jan 30 16:51:45 LokalWiki weewx[1003818] DEBUG
user.MQTTSubscribe: (Service) TopicManager self.cached_fields is {}
/var/log/syslog.2.gz:Jan 30 17:07:40 LokalWiki weewx[1004756] DEBUG
user.MQTTSubscribe: (Service) TopicManager self.cached_fields is {}
/var/log/syslog.2.gz:Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG
user.MQTTSubscribe: (Service) TopicManager self.cached_fields is {}
/var/log/syslog:Feb 1 21:15:42 LokalWiki weewx[1121713] DEBUG
user.MQTTSubscribe: (Service) TopicManager self.cached_fields is
{'pegel/566055/W_cm': {'expires_after': 4000.0}, 'pegel/566055/Q':
{'expires_after': 4000.0}, 'pegel/567470/W_cm': {'expires_after': 4000.0},
'pegel/567470/Q': {'expires_after': 4000.0}}
I guess the only difference in configuration is setting that
use_topic_as_fieldname option.
Much more occurences are for archive_field_cache_dict is None:
/var/log/syslog:Feb 1 17:11:37 LokalWiki weewx[1111752] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog:Feb 1 17:57:17 LokalWiki weewx[1113838] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog:Feb 1 21:15:42 LokalWiki weewx[1121713] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.1:Jan 31 18:51:39 LokalWiki weewx[1062223] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 11:41:20 LokalWiki weewx[991980] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 16:22:32 LokalWiki weewx[1002371] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 16:37:01 LokalWiki weewx[1002967] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 16:48:04 LokalWiki weewx[1003591] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 16:51:45 LokalWiki weewx[1003818] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 16:52:35 LokalWiki weewx[1003948] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 16:56:06 LokalWiki weewx[1004173] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 17:01:36 LokalWiki weewx[1004468] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 17:07:40 LokalWiki weewx[1004756] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 17:09:27 LokalWiki weewx[1004999] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 17:32:18 LokalWiki weewx[1005876] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.2.gz:Jan 30 17:32:58 LokalWiki weewx[1005993] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.4.gz:Jan 28 18:25:57 LokalWiki weewx[900457] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.4.gz:Jan 28 18:45:57 LokalWiki weewx[901356] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.4.gz:Jan 28 20:52:33 LokalWiki weewx[906158] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.4.gz:Jan 28 20:53:26 LokalWiki weewx[906292] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.4.gz:Jan 28 21:10:49 LokalWiki weewx[907158] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.6.gz:Jan 26 18:09:00 LokalWiki weewx[781417] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.7.gz:Jan 25 20:14:15 LokalWiki weewx[731916] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.7.gz:Jan 25 20:28:52 LokalWiki weewx[732569] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
/var/log/syslog.7.gz:Jan 25 20:35:33 LokalWiki weewx[732893] INFO
user.MQTTSubscribe: (Service) archive_field_cache_dict is None
Most of the time I commented out "logging_level = DEBUG", because it
produces lots of logging messages. So I switched it on when testing, only.
[email protected] schrieb am Sonntag, 31. Januar 2021 um 22:53:21 UTC+1:
> Karen,
> I think a couple of things are going on.
> In your log snippet I see:
> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
> (Service) TopicManager *self.cached_fields is {}*
> Is this set in your second run? If so, what are the values? I’d expect it
> is now set, but but the key is wrong - so there is never a cache hit.
> Let me know what you see and I can get a fix done.
> -rich
> ps. - yes the ‘use_topic_as_fieldname’ is confusing. Working on
> eliminating it in v2.
> On Sunday, 31 January 2021 at 14:01:41 UTC-5 [email protected] wrote:
>
>> The use_topic_as_fieldname option worked. (Nevertheless, I find it
>> confusing to set the option to "true" to _not_ using the topic as field
>> name in WeeWX.)
>>
>> Unfortunately it does not cache. If I see the value for one archive
>> interval, it is gone for the next. It shows the parameter name enclosed in
>> question marks then, only.
>>
>> [email protected] schrieb am Samstag, 30. Januar 2021 um 22:39:47 UTC+1:
>>
>>> The subscription to the ‘wind’ topic is just some code that needs to be
>>> cleaned up. Tracking via #119
>>> <https://github.com/bellrichm/WeeWX-MQTTSubscribe/issues/119>.
>>>
>>> You also need the ‘use_topic_as_fieldname = True’ option. Additional
>>> information is here
>>> <https://github.com/bellrichm/WeeWX-MQTTSubscribe/wiki/Configuring-additional-options#use_topic_as_fieldname>.
>>>
>>> So it would look something like this.
>>> [[topics]]
>>> unit_system=METRIC
>>> use_server_datatime=True
>>> ignore_start_time=True
>>> ignore_end_time=True
>>> use_topic_as_fieldname = True
>>> [[[pegel/567470/W_cm]]]
>>> name=W567470v
>>> conversion_type=float
>>> expires_after=4000
>>>
>>> I think “archive_field_cache_dict is None" is some errant logging. The
>>> cache is at the archive record level, not the loop. So, you need to wait
>>> for at least one archive record that has no loop packets with the data (and
>>> of course a previous archive record had to have the value, cache can’t have
>>> expired, etc). On the second archive record, there should be some logging
>>> about updating the archive record.
>>>
>>> On Saturday, 30 January 2021 at 11:48:11 UTC-5 [email protected] wrote:
>>>
>>>> I want to receive data from MQTT, I tried lots of options by now, but
>>>> to no success.
>>>>
>>>> Special: Data are published to MQTT once in a quarter of an hour, only.
>>>>
>>>> When data is published through MQTT and received by the MQTTSubscribe
>>>> service, the first loop packet after that contains the data. So I guess
>>>> the
>>>> configuration is not completely wrong.
>>>>
>>>> But subsequent loop records do not.
>>>>
>>>> There seems to be noch caching.
>>>>
>>>> I see in the log: "archive_field_cache_dict is None". Maybe that has
>>>> some importance. I did not find an option to set it.
>>>>
>>>> And it ignores the name I set for the field.
>>>>
>>>> Additionally I see something "winddir-windgust" in the log. I did not
>>>> subscribe to such messages.
>>>>
>>>> weewx.conf contains:
>>>>
>>>> [[topics]]
>>>> unit_system=METRIC
>>>> use_server_datatime=True
>>>> ignore_start_time=True
>>>> ignore_end_time=True
>>>> [[[pegel/567470/W_cm]]]
>>>> name=W567470v
>>>> conversion_type=float
>>>> expires_after=4000
>>>> etc.
>>>>
>>>> The log says:
>>>>
>>>> Jan 30 17:08:02 LokalWiki weewx[1004756] DEBUG user.MQTTSubscribe:
>>>> (Service) TopicManager data-> outgoing accumulated pegel/567470/W_cm:
>>>> dateTime: 1612022883, usUnits: 1, W_cm: 130.0
>>>>
>>>> Jan 30 17:08:02 LokalWiki weewx[1004756] DEBUG user.MQTTSubscribe:
>>>> (Service) data-> final packet is 2021-01-30 17:08:03 CET (1612022883):
>>>> dateTime: 1612022883, Q: 62.6, rain: 0.0, rainRate: 0.0, usUnits: 1, W_cm:
>>>> 130.0, windDir: 46, windSpeed: 2.0
>>>> Jan 30 17:08:05 LokalWiki weewx[1004756] DEBUG user.MQTTSubscribe:
>>>> (Service) data-> final packet is 2021-01-30 17:08:05 CET (1612022885):
>>>> dateTime: 1612022885, rain: 0.0, rainRate: 0.0, usUnits: 1, windDir: 46,
>>>> windSpeed: 2.0
>>>>
>>>> If I look to the start section of the log it says (tried again some
>>>> minutes later):
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Using weewx version 4.2.0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Using Python 3.8.5 (default, Jul 28 2020, 12:59:40) #012[GCC
>>>> 9.3.0]
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Platform Linux-5.4.0-60-generic-x86_64-with-glibc2.29
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Locale is 'de_DE.UTF-8'
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Version is 1.6.2
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Log level: 10
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Log debug setting: 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Log console: False
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Log file: None
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) sanitized configuration removed ['password']
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSUBscriber sanitized_service_dict is {'host': 'xxxxxxxxx',
>>>> 'log': 'True', 'username': 'pegel', 'enable': 'True', 'message_callback':
>>>> {'type': 'individual'}, 'logging_level': 'DEBUG', 'binding': 'loop',
>>>> 'keepalive': '60', 'port': '1883', 'topics': {'unit_system': 'METRIC',
>>>> 'use_server_datatime': 'True', 'ignore_start_time': 'True',
>>>> 'ignore_end_time': 'True', 'pegel/566055/W_cm': {'name': 'W566055v',
>>>> 'conversion_type': 'float', 'expires_after': '4000'}, 'pegel/566055/Q':
>>>> {'name': 'Q566055v', 'conversion_type': 'float', 'expires_after': '4000'},
>>>> 'pegel/567470/W_cm': {'name': 'W567470v', 'conversion_type': 'float',
>>>> 'expires_after': '4000'}, 'pegel/567470/Q': {'name': 'Q567470v',
>>>> 'conversion_type': 'float', 'expires_after': '4000'}}}
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) overlap is 0.0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) TopicManager self.subscribed_topics is {'pegel/566055/W_cm':
>>>> {'type': 'normal', 'unit_system': 16, 'msg_id_field': None, 'qos': 0,
>>>> 'use_server_datetime': False, 'ignore_start_time': True,
>>>> 'ignore_end_time':
>>>> True, 'adjust_start_time': 1.0, 'adjust_end_time': 0.0, 'datetime_format':
>>>> None, 'offset_format': None, 'ignore': False, 'max_queue':
>>>> 9223372036854775807, 'queue': deque([]), 'fields': {},
>>>> 'ignore_msg_id_field': []}, 'pegel/566055/Q': {'type': 'normal',
>>>> 'unit_system': 16, 'msg_id_field': None, 'qos': 0, 'use_server_datetime':
>>>> False, 'ignore_start_time': True, 'ignore_end_time': True,
>>>> 'adjust_start_time': 1.0, 'adjust_end_time': 0.0, 'datetime_format': None,
>>>> 'offset_format': None, 'ignore': False, 'max_queue': 9223372036854775807,
>>>> 'queue': deque([]), 'fields': {}, 'ignore_msg_id_field': []},
>>>> 'pegel/567470/W_cm': {'type': 'normal', 'unit_system': 16, 'msg_id_field':
>>>> None, 'qos': 0, 'use_server_datetime': False, 'ignore_start_time': True,
>>>> 'ignore_end_time': True, 'adjust_start_time': 1.0, 'adjust_end_time': 0.0,
>>>> 'datetime_format': None, 'offset_format': None, 'ignore': False,
>>>> 'max_queue': 9223372036854775807, 'queue': deque([]), 'fields': {},
>>>> 'ignore_msg_id_field': []}, 'pegel/567470/Q': {'type': 'normal',
>>>> 'unit_system': 16, 'msg_id_field': None, 'qos': 0, 'use_server_datetime':
>>>> False, 'ignore_start_time': True, 'ignore_end_time': True,
>>>> 'adjust_start_time': 1.0, 'adjust_end_time': 0.0, 'datetime_format': None,
>>>> 'offset_format': None, 'ignore': False, 'max_queue': 9223372036854775807,
>>>> 'queue': deque([]), 'fields': {}, 'ignore_msg_id_field': []},
>>>> '1612024338.424195-windGust-windGustDir-windDir-windSpeed': {'type':
>>>> 'collector', 'unit_system': 16, 'qos': 0, 'use_server_datetime': False,
>>>> 'ignore_start_time': True, 'ignore_end_time': True, 'adjust_start_time':
>>>> 1.0, 'adjust_end_time': 0.0, 'datetime_format': None, 'offset_format':
>>>> None, 'max_queue': 9223372036854775807, 'queue': deque([])}}
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) TopicManager self.cached_fields is {}
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) message_callback_provider_name is
>>>> user.MQTTSubscribe.MessageCallbackProvider
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) clientid is MQTTSubscribe-7610
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) client_session is True
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) host is xxxxxxxxxx
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) port is 1883
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) keepalive is 60
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) username is pegel
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) password is set
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Archive topic is None
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MessageCallbackProvider self.fields is {}
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Sending CONNECT (u1, p1, wr0, wq0, wf0, c1,
>>>> k60) client_id=b'MQTTSubscribe-7610'
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) binding is loop
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) archive_field_cache_dict is None
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Starting loop
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Received CONNACK (0, 0)
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Connected with result code 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Connected flags {'session present': 0}
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Sending SUBSCRIBE (d0, m1)
>>>> [(b'pegel/566055/W_cm', 0)]
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Subscribing to pegel/566055/W_cm has a mid 1 and rc 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Sending SUBSCRIBE (d0, m2)
>>>> [(b'pegel/566055/Q', 0)]
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Subscribing to pegel/566055/Q has a mid 2 and rc 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Sending SUBSCRIBE (d0, m3)
>>>> [(b'pegel/567470/W_cm', 0)]
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Subscribing to pegel/567470/W_cm has a mid 3 and rc 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Sending SUBSCRIBE (d0, m4)
>>>> [(b'pegel/567470/Q', 0)]
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Subscribing to pegel/567470/Q has a mid 4 and rc 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Sending SUBSCRIBE (d0, m5)
>>>> [(b'1612024338.424195-windGust-windGustDir-windDir-windSpeed', 0)]
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) Subscribing to
>>>> 1612024338.424195-windGust-windGustDir-windDir-windSpeed has a mid 5 and
>>>> rc
>>>> 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Received SUBACK
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Subscribed to mid: 1 is size 1 has a QOS of 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Received SUBACK
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Subscribed to mid: 2 is size 1 has a QOS of 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Received SUBACK
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Subscribed to mid: 3 is size 1 has a QOS of 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Received SUBACK
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Subscribed to mid: 4 is size 1 has a QOS of 0
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] DEBUG user.MQTTSubscribe:
>>>> (Service) MQTTSubscribe MQTT: Received SUBACK
>>>> Jan 30 17:32:18 LokalWiki weewx[1005876] INFO user.MQTTSubscribe:
>>>> (Service) Subscribed to mid: 5 is size 1 has a QOS of 0
>>>>
>>>>
--
You received this message because you are subscribed to the Google Groups
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/d/msgid/weewx-user/1ee891bf-dd26-4e9b-bb02-ea7e7aa835d4n%40googlegroups.com.
