feat(sync): Implement comprehensive sync fixes and optimizations as of February 8, 2026

- Fixed initial sync logic to respect actual timestamps, preventing unwanted overwrites.
- Introduced exponential backoff for retry logic, with auto-reset for permanently failed entities.
- Added validation checks to ensure data consistency during sync processes.
- Corrected hash calculation to only include sync-relevant communications.
- Resolved issues with empty slots ignoring user inputs and improved conflict handling.
- Enhanced handling of Var4 and Var6 entries during sync conflicts.
- Documented changes and added new fields required in EspoCRM for improved sync management.

Also added a detailed analysis of syncStatus values in EspoCRM CBeteiligte, outlining responsibilities and ensuring robust sync mechanisms.
This commit is contained in:
2026-02-08 22:59:47 +00:00
parent 440ad506b8
commit 89fc657d47
16 changed files with 1464 additions and 2290 deletions

View File

@@ -0,0 +1,532 @@
# Sync-Code Fixes & Optimierungen - 8. Februar 2026
> **📚 Aktuelle Archiv-Datei**: Diese Datei dokumentiert die durchgeführten Fixes vom 8. Februar 2026.
> **📌 Aktuelle Referenz**: Siehe [SYNC_CODE_ANALYSIS.md](SYNC_CODE_ANALYSIS.md) für die finale Code-Bewertung.
## Übersicht
Behebung kritischer Sync-Probleme die bei umfassender Code-Analyse identifiziert wurden.
---
## 🔴 **Problem #11: Initial Sync Logic** - FIXED ✅
### Problem
Initial Sync bevorzugte blind EspoCRM, auch wenn Advoware Entity bereits existierte und neuer war.
### Fix
```python
# 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
```python
# 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
```python
# Bei permanently_failed:
auto_reset_time = now_utc + timedelta(hours=24)
update_data['syncAutoResetAt'] = auto_reset_time
```
#### 3. Cron Auto-Reset
```python
# 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
```python
# 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
```python
# 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
```python
# 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
```python
# 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)**:
```python
# 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()
```python
# 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()
```python
# 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
```python
# 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
```python
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'
```python
# 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()
```python
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'):
```python
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:
```json
{
"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