spacemanspiff2007 / HABApp

Easy home automation with MQTT and/or openHAB
Apache License 2.0
54 stars 23 forks source link

Filewatcher problem with rsync #441

Open Iture opened 3 months ago

Iture commented 3 months ago

Hi I use rsync to deploy configuration to production, and have habapp running in a docker container. Recently I found a strange behavior of filewatcher. After copying a new file using rsync, it removes any references to it. Probably it happens because rsync creates temporary file and then moves it to final location. Habapp sees this move and then interprets it as file removal. EDIT: Probably the answer is here: https://github.com/spacemanspiff2007/HABApp/blob/5ccb2d6f69e7917a766cac60ac25db5afa2919e6/src/HABApp/core/files/watcher/base_watcher.py#L55 and here: https://github.com/spacemanspiff2007/HABApp/blob/5ccb2d6f69e7917a766cac60ac25db5afa2919e6/src/HABApp/core/files/watcher/base_watcher.py#L61

You can see it in the logs (it's Loki, read from bottom):

  |   | 2024-03-13 12:02:39.232 | [2024-03-13 12:02:39,232] [             HABApp.files]    DEBUG \| Removed rules/presence/leave_arrival.py |  
-- | -- | -- | -- | --
  |   | 2024-03-13 12:02:39.231 | [2024-03-13 12:02:39,231] [             HABApp.files]    DEBUG \| rules/presence/leave_arrival.py changed to REMOVED |  
  |   | 2024-03-13 12:02:39.229 | [2024-03-13 12:02:39,228] [             HABApp.Rules]    DEBUG \| File rules/presence/leave_arrival.py successfully unloaded! |  
  |   | 2024-03-13 12:02:39.229 | [2024-03-13 12:02:39,228] [                   HABApp]    DEBUG \| Removed event listener for "presence_devices" (filter=ValueChangeEventFilter(value=OPEN)) |  
  |   | 2024-03-13 12:02:39.228 | [2024-03-13 12:02:39,228] [                   HABApp]    DEBUG \| Removed event listener for "presence_manual" (filter=ValueChangeEventFilter(value=OFF)) |  
  |   | 2024-03-13 12:02:39.228 | [2024-03-13 12:02:39,228] [                   HABApp]    DEBUG \| Removed event listener for "presence_devices" (filter=ValueChangeEventFilter(value=CLOSED)) |  
  |   | 2024-03-13 12:02:39.228 | [2024-03-13 12:02:39,227] [                   HABApp]    DEBUG \| Removed event listener for "presence_manual" (filter=ValueChangeEventFilter(value=ON)) |  
  |   | 2024-03-13 12:02:39.228 | [2024-03-13 12:02:39,227] [                   HABApp]    DEBUG \| Removed event listener for "presence_kids" (filter=ValueChangeEventFilter()) |  
  |   | 2024-03-13 12:02:39.228 | [2024-03-13 12:02:39,227] [                   HABApp]    DEBUG \| Removed event listener for "presence_devices" (filter=ValueChangeEventFilter(value=OPEN)) |  
  |   | 2024-03-13 12:02:39.223 | [2024-03-13 12:02:39,223] [             HABApp.Rules]    DEBUG \| Removing file: rules/presence/leave_arrival.py |  
  |   | 2024-03-13 12:02:38.618 | [2024-03-13 12:02:38,617] [       HABApp.file.events]    DEBUG \| DirModifiedEvent(src_path='/habapp/config/rules/presence', dest_path='', event_type='modified', is_directory=True, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.616 | [2024-03-13 12:02:38,616] [       HABApp.file.events]    DEBUG \| FileMovedEvent(src_path='/habapp/config/rules/presence/.leave_arrival.py.1upIJ8', dest_path='/habapp/config/rules/presence/leave_arrival.py', event_type='moved', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.616 | [2024-03-13 12:02:38,616] [       HABApp.file.events]    DEBUG \| FileModifiedEvent(src_path='/habapp/config/rules/presence/.leave_arrival.py.1upIJ8', dest_path='', event_type='modified', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.616 | [2024-03-13 12:02:38,615] [       HABApp.file.events]    DEBUG \| DirModifiedEvent(src_path='/habapp/config/rules/presence', dest_path='', event_type='modified', is_directory=True, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.615 | [2024-03-13 12:02:38,615] [       HABApp.file.events]    DEBUG \| FileClosedEvent(src_path='/habapp/config/rules/presence/.leave_arrival.py.1upIJ8', dest_path='', event_type='closed', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.615 | [2024-03-13 12:02:38,615] [       HABApp.file.events]    DEBUG \| FileModifiedEvent(src_path='/habapp/config/rules/presence/.leave_arrival.py.1upIJ8', dest_path='', event_type='modified', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.615 | [2024-03-13 12:02:38,614] [       HABApp.file.events]    DEBUG \| FileOpenedEvent(src_path='/habapp/config/rules/presence/.leave_arrival.py.1upIJ8', dest_path='', event_type='opened', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.614 | [2024-03-13 12:02:38,614] [       HABApp.file.events]    DEBUG \| DirModifiedEvent(src_path='/habapp/config/rules/presence', dest_path='', event_type='modified', is_directory=True, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.614 | [2024-03-13 12:02:38,614] [       HABApp.file.events]    DEBUG \| FileCreatedEvent(src_path='/habapp/config/rules/presence/.leave_arrival.py.1upIJ8', dest_path='', event_type='created', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.612 | [2024-03-13 12:02:38,612] [       HABApp.file.events]    DEBUG \| FileOpenedEvent(src_path='/habapp/config/rules/presence/leave_arrival.py', dest_path='', event_type='opened', is_directory=False, is_synthetic=False) |  
  |   | 2024-03-13 12:02:38.587 | [2024-03-13 12:02:38,585] [       HABApp.file.events]    DEBUG \| FileOpenedEvent(src_path='/habapp/config/rules/presence/leave_arrival.py', dest_path='', event_type='opened', is_directory=False, is_synthetic=False)
spacemanspiff2007 commented 3 months ago

Does the file get loaded again after the unload? If it's still there I would have expected that it gets unloaded and then immediately loaded again.

Iture commented 3 months ago

Nope, that's the full log. Habapp forgets about this file. What's interesting, when I copy files using scp, everythong works, rsync does it in some not compatible way. Another interesting thing: I tried to change behavior of rsync using --inplace flag, but it doesn't change anythong, habapp behaves in the same way. Ah, systems: rsync runs on OSX, copies files using ssh to Linux@arm (raspberry)

spacemanspiff2007 commented 3 months ago

I can't make sense of it. Could you additionally show me the corresponding file events from the HABApp events? They are on the event bus under HABApp.Files

Iture commented 3 months ago

You have everything in the first post, or is there anything more?

spacemanspiff2007 commented 3 months ago

No, the corresponding issued file events are missing. You typically find these in the HABApp_events.log under HABApp.Files

Iture commented 3 months ago

Ahh, I see. Unfortunately I have logging level set to WARN for events, and all is sent to Loki - as I mentioned, whole log is in the first post

spacemanspiff2007 commented 3 months ago

You can set the logging level for the event file to INFO, then do rsync and then set it back to warning again. It will be picked up on the fly.