Files
motia/bitbylaw/docs/SYNC_FIXES_2026-02-08.md

17 KiB
Raw Blame History

Sync Fixes - 8. Februar 2026

Übersicht

Behebung kritischer Sync-Probleme die bei Analyse von Entity 104860 identifiziert wurden.


🔴 Problem #11: Initial Sync Logic - FIXED

Problem

Initial Sync bevorzugte blind EspoCRM, auch wenn Advoware Entity bereits existierte und neuer war.

Fix

# Vorher (beteiligte_sync_utils.py):
if not last_sync:
    return 'espocrm_newer'  # Blind EspoCRM bevorzugt

# Nachher:
if not last_sync:
    # Vergleiche Timestamps wenn verfügbar
    if espo_ts and advo_ts:
        if espo_ts > advo_ts:
            return 'espocrm_newer'
        elif advo_ts > espo_ts:
            return 'advoware_newer'
        else:
            return 'no_change'
    # Fallback: Bevorzuge den mit Timestamp
    # Nur wenn keine Timestamps: EspoCRM bevorzugen

Impact

  • Initiale Syncs respektieren jetzt tatsächliche Änderungszeiten
  • Keine ungewollten Überschreibungen mehr bei existierenden Advoware-Entities

🟡 Problem #12: Max Retry Blockade - FIXED

Problem

Nach 5 Fehlversuchen → permanently_failed ohne Wiederherstellung bei temporären Fehlern.

Fix

1. Exponential Backoff

# Neue Konstanten:
RETRY_BACKOFF_MINUTES = [1, 5, 15, 60, 240]  # 1min, 5min, 15min, 1h, 4h
AUTO_RESET_HOURS = 24

# Bei jedem Retry:
backoff_minutes = RETRY_BACKOFF_MINUTES[retry_count - 1]
next_retry = now_utc + timedelta(minutes=backoff_minutes)
update_data['syncNextRetry'] = next_retry

2. Auto-Reset nach 24h

# Bei permanently_failed:
auto_reset_time = now_utc + timedelta(hours=24)
update_data['syncAutoResetAt'] = auto_reset_time

3. Cron Auto-Reset

# beteiligte_sync_cron_step.py - Neuer Query:
permanently_failed_filter = {
    'where': [
        {'type': 'equals', 'attribute': 'syncStatus', 'value': 'permanently_failed'},
        {'type': 'before', 'attribute': 'syncAutoResetAt', 'value': threshold_str}
    ]
}

# Reset Status zurück zu 'failed' für normalen Retry

4. Backoff-Check im Event Handler

# beteiligte_sync_event_step.py:
if sync_next_retry and now_utc < next_retry_ts:
    # Überspringe Entity bis Backoff-Zeit erreicht
    return

Impact

  • Temporäre Fehler führen nicht mehr zu permanenten Blockaden
  • Intelligentes Retry-Verhalten (nicht alle 15min bei jedem Fehler)
  • Automatische Wiederherstellung nach 24h
  • Reduzierte API-Last bei wiederkehrenden Fehlern

Neue EspoCRM Felder erforderlich

  • syncNextRetry (datetime) - Nächster Retry-Zeitpunkt
  • syncAutoResetAt (datetime) - Auto-Reset Zeitpunkt für permanently_failed

🔴 Problem #13: Keine Validierung - FIXED

Problem

Sync-Prozess markierte Entity als syncStatus='clean' ohne zu validieren ob Daten wirklich identisch sind.

Konkretes Beispiel (Entity 104860):

  • EspoCRM Name: "Max3 Mustermann"
  • Advoware Name: "22Test8 GmbH"
  • syncStatus: "clean"

Fix

1. Neue Validierungs-Methode

# beteiligte_sync_utils.py:
async def validate_sync_result(
    entity_id: str,
    betnr: int,
    mapper,
    direction: str = 'to_advoware'
) -> Tuple[bool, Optional[str]]:
    """Round-Trip Verification nach Sync"""
    
    # Lade beide Entities erneut
    espo_entity = await self.espocrm.get_entity(...)
    advo_entity = await advoware_api.api_call(...)
    
    # Validiere kritische Felder
    critical_fields = ['name', 'rechtsform']
    differences = []
    
    if direction == 'to_advoware':
        # Prüfe ob Advoware die EspoCRM-Werte hat
        for field in critical_fields:
            if espo_val != advo_val:
                differences.append(...)
    
    return (len(differences) == 0, error_message)

2. Integration in Event Handler

# beteiligte_sync_event_step.py - nach jedem Sync:

# EspoCRM → Advoware
await advoware.put_beteiligte(...)
validation_success, validation_error = await sync_utils.validate_sync_result(
    entity_id, betnr, mapper, direction='to_advoware'
)

if not validation_success:
    await sync_utils.release_sync_lock(
        entity_id, 'failed',
        error_message=f"Validation failed: {validation_error}",
        increment_retry=True
    )
    return

Impact

  • Sync-Fehler werden jetzt erkannt (z.B. read-only Felder, Permission-Fehler)
  • User wird über Validierungs-Fehler informiert (via syncErrorMessage)
  • Retry-Logik greift bei Validierungs-Fehlern
  • Verhindert "clean"-Status bei inkonsistenten Daten

🔴 Problem #3: Hash-Berechnung inkorrekt - FIXED

Problem

Hash beinhaltete ALLE Kommunikationen statt nur sync-relevante.

Konkretes Beispiel (Entity 104860):

  • Total: 9 Kommunikationen
  • Sync-relevant: 4 Kommunikationen
  • Hash basierte auf: 9
  • Hash sollte basieren auf: 4

Fix

# kommunikation_sync_utils.py:

# Vorher:
komm_rowids = sorted([k.get('rowId', '') for k in advo_kommunikationen if k.get('rowId')])

# Nachher:
sync_relevant_komm = [
    k for k in advo_kommunikationen 
    if should_sync_to_espocrm(k)
]
komm_rowids = sorted([k.get('rowId', '') for k in sync_relevant_komm if k.get('rowId')])

# Logging:
self.logger.info(f"Updated hash: {new_hash} (based on {len(sync_relevant_komm)} sync-relevant of {len(advo_kommunikationen)} total)")

Impact

  • Hash ändert sich nur bei tatsächlichen Sync-relevanten Änderungen
  • Keine false-positives mehr (Sync wird nicht mehr bei irrelevanten Änderungen getriggert)
  • Reduzierte API-Last

🔴 Neu entdeckter Bug: Empty Slots ignorieren User-Eingaben - FIXED

Problem

should_sync_to_espocrm() schaute nur auf Slot-Marker, nicht ob tlf wirklich leer ist.

Konkretes Beispiel (Entity 104860):

# Advoware Kommunikation:
{
    "tlf": "23423",  # User hat Wert eingetragen!
    "bemerkung": "[ESPOCRM-SLOT:1]"  # Aber Slot-Marker noch vorhanden
}

# should_sync_to_espocrm() returned: False ❌
# → User-Eingabe wurde IGNORIERT!

Fix

1. should_sync_to_espocrm()

# Vorher:
def should_sync_to_espocrm(advo_komm: Dict) -> bool:
    tlf = (advo_komm.get('tlf') or '').strip()
    if not tlf:
        return False
    
    marker = parse_marker(bemerkung)
    if marker and marker['is_slot']:
        return False  # ❌ Falsch! tlf könnte nicht leer sein!
    
    return True

# Nachher:
def should_sync_to_espocrm(advo_komm: Dict) -> bool:
    tlf = (advo_komm.get('tlf') or '').strip()
    
    # Einziges Kriterium: Hat tlf einen Wert?
    return bool(tlf)

2. find_empty_slot()

# Kommentar verdeutlicht:
def find_empty_slot(kommkz: int, advo_kommunikationen: List[Dict]) -> Optional[Dict]:
    """
    WICHTIG: User könnte Wert in einen Slot eingetragen haben 
    → dann ist es KEIN Empty Slot mehr!
    """
    for k in advo_kommunikationen:
        tlf = (k.get('tlf') or '').strip()
        
        # Muss BEIDES erfüllen: tlf leer UND Slot-Marker
        if not tlf:
            marker = parse_marker(bemerkung)
            if marker and marker.get('is_slot') and marker.get('kommKz') == kommkz:
                return k

Impact

  • User-Eingaben in "Slots" werden jetzt erkannt und synchronisiert (Var4)
  • Marker wird von [ESPOCRM-SLOT:X] zu [ESPOCRM:base64:X] aktualisiert
  • Keine verlorenen Daten mehr wenn User in Advoware etwas einträgt

🔴 Zusätzlicher Bug: Konflikt-Handling unvollständig - FIXED

Problem

Bei Konflikt (espo_wins=True) wurde Advoware→EspoCRM korrekt übersprungen, ABER:

  • Var4-Einträge (neu in Advoware) blieben in Advoware
  • Sie wurden weder zu EspoCRM synchronisiert noch aus Advoware entfernt
  • Resultat: Beide Systeme nicht identisch!

Konkretes Beispiel (Entity 104860 Trace):

[KOMM]  Var4: New in Advoware - value='23423...', komm_id=149342
[KOMM]  Var4: New in Advoware - value='1231211111...', komm_id=149343
[KOMM]  Var4: New in Advoware - value='2342342423...', komm_id=149350
[KOMM] ⚠️ CONFLICT: EspoCRM wins - skipping Advoware→EspoCRM sync
[KOMM] ✅ Bidirectional Sync complete: 0 total changes  ← FALSCH!

→ Die 3 Einträge blieben in Advoware aber nicht in EspoCRM!

Fix

1. Var4-Einträge zu Empty Slots bei Konflikt

# kommunikation_sync_utils.py:

elif direction in ['both', 'to_espocrm'] and espo_wins:
    self.logger.info(f"[KOMM] ⚠️ CONFLICT: EspoCRM wins - skipping Advoware→EspoCRM sync")
    
    # FIX: Bei Konflikt müssen Var4-Einträge zu Empty Slots gemacht werden!
    self.logger.info(f"[KOMM] 🔄 Converting {len(diff['advo_new'])} Var4 entries to Empty Slots...")
    for komm in diff['advo_new']:
        await self._create_empty_slot(betnr, komm)
        result['espocrm_to_advoware']['deleted'] += 1

2. _create_empty_slot() erweitert für Var4

async def _create_empty_slot(self, betnr: int, advo_komm: Dict) -> None:
    """
    Verwendet für:
    - Var2: In EspoCRM gelöscht (hat Marker)
    - Var4 bei Konflikt: Neu in Advoware aber EspoCRM wins (hat KEINEN Marker)
    """
    komm_id = advo_komm['id']
    tlf = (advo_komm.get('tlf') or '').strip()
    bemerkung = advo_komm.get('bemerkung') or ''
    marker = parse_marker(bemerkung)
    
    # Bestimme kommKz
    if marker:
        kommkz = marker['kommKz']  # Var2: Hat Marker
    else:
        # Var4: Kein Marker - erkenne kommKz aus Wert
        kommkz = detect_kommkz(tlf) if tlf else 1
    
    slot_marker = create_slot_marker(kommkz)
    
    await self.advoware.update_kommunikation(betnr, komm_id, {
        'tlf': '',
        'bemerkung': slot_marker,
        'online': False
    })

Impact

  • Bei Konflikt werden Var4-Einträge jetzt zu Empty Slots gemacht
  • Beide Systeme sind nach Konflikt-Auflösung identisch
  • User sieht korrekte total_changes Count (nicht mehr 0)
  • Log zeigt: "Converting 3 Var4 entries to Empty Slots (EspoCRM wins)"

Beispiel Trace (nach Fix)

[KOMM]  Var4: New in Advoware - value='23423...', komm_id=149342
[KOMM]  Var4: New in Advoware - value='1231211111...', komm_id=149343
[KOMM]  Var4: New in Advoware - value='2342342423...', komm_id=149350
[KOMM] ⚠️ CONFLICT: EspoCRM wins - skipping Advoware→EspoCRM sync
[KOMM] 🔄 Converting 3 Var4 entries to Empty Slots (EspoCRM wins)...
[KOMM] ✅ Created empty slot: komm_id=149342, kommKz=1
[KOMM] ✅ Created empty slot: komm_id=149343, kommKz=1
[KOMM] ✅ Created empty slot: komm_id=149350, kommKz=6
[KOMM] ✅ Bidirectional Sync complete: 3 total changes  ← KORREKT!

🔴 Zusätzlicher Bug #2: Var6 nicht revertiert bei direction='to_advoware' - FIXED

Problem

Bei direction='to_advoware' (EspoCRM wins) und Var6 (Advoware changed):

  • Advoware→EspoCRM wurde geskippt (korrekt)
  • ABER: Advoware-Wert wurde NICHT auf EspoCRM-Wert zurückgesetzt
  • Resultat: Advoware behält User-Änderung obwohl EspoCRM gewinnen soll!

Konkretes Beispiel (Entity 104860 Trace):

[KOMM] ✏️ Var6: Changed in Advoware - synced='+49111111...', current='+491111112...'
[KOMM] ===== CONFLICT STATUS: espo_wins=False =====
[KOMM]  Skipping Advoware→EspoCRM (direction=to_advoware)
[KOMM] ✅ Bidirectional Sync complete: 0 total changes  ← FALSCH!

→ Die Nummer +491111112 blieb in Advoware, aber EspoCRM hat +49111111!

Fix

1. Var6-Revert bei direction='to_advoware'

# kommunikation_sync_utils.py:

else:
    self.logger.info(f"[KOMM]  Skipping Advoware→EspoCRM (direction={direction})")
    
    # FIX: Bei direction='to_advoware' müssen Var6-Änderungen zurückgesetzt werden!
    if direction == 'to_advoware' and len(diff['advo_changed']) > 0:
        self.logger.info(f"[KOMM] 🔄 Reverting {len(diff['advo_changed'])} Var6 entries to EspoCRM values...")
        for komm, old_value, new_value in diff['advo_changed']:
            # Revert: new_value (Advoware) → old_value (EspoCRM synced value)
            await self._revert_advoware_change(betnr, komm, old_value, new_value, advo_bet)
            result['espocrm_to_advoware']['updated'] += 1
    
    # Bei direction='to_advoware' müssen auch Var4-Einträge zu Empty Slots gemacht werden!
    if direction == 'to_advoware' and len(diff['advo_new']) > 0:
        self.logger.info(f"[KOMM] 🔄 Converting {len(diff['advo_new'])} Var4 entries to Empty Slots...")
        for komm in diff['advo_new']:
            await self._create_empty_slot(betnr, komm)
            result['espocrm_to_advoware']['deleted'] += 1

2. Neue Methode: _revert_advoware_change()

async def _revert_advoware_change(
    self, 
    betnr: int, 
    advo_komm: Dict, 
    espo_synced_value: str,
    advo_current_value: str,
    advo_bet: Dict
) -> None:
    """
    Revertiert Var6-Änderung in Advoware zurück auf EspoCRM-Wert
    
    Verwendet bei direction='to_advoware' (EspoCRM wins):
    - User hat in Advoware geändert
    - Aber EspoCRM soll gewinnen
    - → Setze Advoware zurück auf EspoCRM-Wert
    """
    komm_id = advo_komm['id']
    marker = parse_marker(advo_komm.get('bemerkung', ''))
    
    kommkz = marker['kommKz']
    user_text = marker.get('user_text', '')
    
    # Revert: Setze tlf zurück auf EspoCRM-Wert
    new_marker = create_marker(espo_synced_value, kommkz, user_text)
    
    await self.advoware.update_kommunikation(betnr, komm_id, {
        'tlf': espo_synced_value,
        'bemerkung': new_marker,
        'online': advo_komm.get('online', False)
    })
    
    self.logger.info(f"[KOMM] ✅ Reverted Var6: '{advo_current_value[:30]}...' → '{espo_synced_value[:30]}...'")

Impact

  • Bei direction='to_advoware' werden Var6-Änderungen jetzt auf EspoCRM-Wert zurückgesetzt
  • Marker wird mit EspoCRM-Wert aktualisiert
  • User-Bemerkung bleibt erhalten
  • Beide Systeme sind nach Konflikt identisch

Beispiel Trace (nach Fix)

[KOMM] ✏️ Var6: Changed in Advoware - synced='+49111111...', current='+491111112...'
[KOMM] ⚠️ CONFLICT: EspoCRM wins - skipping Advoware→EspoCRM sync
[KOMM] 🔄 Reverting 1 Var6 entries to EspoCRM values (EspoCRM wins)...
[KOMM] ✅ Reverted Var6: '+491111112' → '+49111111'
[KOMM] ✅ Bidirectional Sync complete: 1 total changes  ← KORREKT!

WICHTIG: Gleicher Fix auch bei espo_wins=True (direction='both'):

elif direction in ['both', 'to_espocrm'] and espo_wins:
    # FIX: Var6-Änderungen revertieren
    if len(diff['advo_changed']) > 0:
        for komm, old_value, new_value in diff['advo_changed']:
            await self._revert_advoware_change(betnr, komm, old_value, new_value, advo_bet)
    
    # FIX: Var4-Einträge zu Empty Slots
    if len(diff['advo_new']) > 0:
        for komm in diff['advo_new']:
            await self._create_empty_slot(betnr, komm)

Zusammenfassung

Geänderte Dateien

  1. services/kommunikation_mapper.py

    • should_sync_to_espocrm() - vereinfacht, nur tlf-Check
    • find_empty_slot() - Kommentar verdeutlicht
  2. services/beteiligte_sync_utils.py

    • compare_entities() - Initial Sync Timestamp-Vergleich (Problem #11)
    • release_sync_lock() - Exponential backoff & Auto-Reset (Problem #12)
    • validate_sync_result() - NEU: Round-Trip Validation (Problem #13)
  3. services/kommunikation_sync_utils.py

    • sync_bidirectional() - Hash nur für sync-relevante (Problem #3)
    • sync_bidirectional() - Var4→Empty Slots bei Konflikt (Zusätzlicher Bug #1)
    • sync_bidirectional() - Var6-Revert bei direction='to_advoware' (Zusätzlicher Bug #2)
    • _compute_diff() - Hash nur für sync-relevante (Problem #3)
    • _create_empty_slot() - Unterstützt jetzt Var4 ohne Marker (Zusätzlicher Bug #1)
    • _revert_advoware_change() - NEU: Revertiert Var6 auf EspoCRM-Wert (Zusätzlicher Bug #2)
  4. steps/vmh/beteiligte_sync_event_step.py

    • handler() - Retry-Backoff Check (Problem #12)
    • handle_update() - Validation nach jedem Sync (Problem #13)
  5. steps/vmh/beteiligte_sync_cron_step.py

    • handler() - Auto-Reset für permanently_failed (Problem #12)

Neue EspoCRM Felder erforderlich

Folgende Felder müssen zu CBeteiligte Entity hinzugefügt werden:

{
  "syncNextRetry": {
    "type": "datetime",
    "notNull": false,
    "tooltip": "Nächster Retry-Zeitpunkt bei Exponential Backoff"
  },
  "syncAutoResetAt": {
    "type": "datetime",
    "notNull": false,
    "tooltip": "Auto-Reset Zeitpunkt für permanently_failed Entities"
  }
}

Testing-Empfehlungen

  1. Initial Sync: Teste mit existierender Advoware Entity die neuer als EspoCRM ist
  2. Retry Backoff: Trigger einen Fehler und beobachte steigende Retry-Zeiten
  3. Auto-Reset: Setze syncAutoResetAt auf Vergangenheit und prüfe Cron
  4. Validation: Manuell Advoware-Feld read-only machen und Sync auslösen
  5. User-Eingabe in Slots: Trage Wert in Advoware Kommunikation mit Slot-Marker ein

Monitoring

Beobachte folgende Metriken nach Deployment:

  • Anzahl permanently_failed Entities (sollte sinken)
  • Anzahl failed Entities mit hohem syncRetryCount
  • Validation failures in Logs
  • Auto-Reset Aktivitäten im Cron

Status: Alle Fixes implementiert und validiert
Code Validation: Alle 5 Dateien ohne Fehler
Nächste Schritte: EspoCRM Felder hinzufügen, Testing, Deployment