ops-jrz1/docs/issues/2025-11-01-maubot-sync-not-delivering-events.md

Maubot Sync Not Delivering Events to Instagram Bot

Status: OPEN Severity: HIGH Date Opened: 2025-11-01 Reporter: Claude (session continuation) Affected Component: maubot Matrix client sync loop Related Worklog: docs/worklogs/2025-11-01-maubot-instagram-bot-deployment-and-sync-investigation.org

Problem Statement

The Instagram bot plugin deployed to maubot appears correctly configured at all layers (service, client, instance, room membership) but is not receiving Matrix events. Messages sent to the bot's configured room (!dT40EUcemb8e6bPiig:clarun.xyz) do not trigger the plugin's event handler, and the client's next_batch token remains stuck at 40267 despite multiple messages sent.

Symptoms

1. No event handler execution: Plugin's handle_message() method never called
2. Stuck next_batch: Client sync token remains at 40267 across multiple checks
3. Silent failure: No errors in maubot service logs
4. Successful initialization: Plugin logs "SocialMediaBot initialized" on startup
5. Correct configuration: All database verification queries show expected state

Environment

• Server: clarun.xyz (45.77.205.49)
• OS: NixOS (unstable)
• Matrix Homeserver: conduwuit (http://127.0.0.1:8008)
• Maubot Version: (from nixpkgs-unstable)
• Bot User: @instagram-bot:clarun.xyz
• Test Room: !dT40EUcemb8e6bPiig:clarun.xyz
• Plugin: sna-instagram-bot v1.0.0 (6946 bytes)
• Database: /var/lib/maubot/bot.db (SQLite)

Evidence Collected

Database State Verification

Client Configuration

SELECT id, homeserver, user_id, sync, autojoin, enabled,
       length(access_token) as token_len, next_batch
FROM client WHERE id = 'instagram-bot';

Result:

• id: instagram-bot
• homeserver: http://127.0.0.1:8008
• user_id: @instagram-bot:clarun.xyz
• sync: 1 (enabled)
• autojoin: 1 (enabled)
• enabled: 1 (enabled)
• access_token: 32 bytes (valid)
• next_batch: 40267 (NOT UPDATING)

Verified twice with 5-second gap: next_batch remained at 40267.

Instance Configuration

SELECT id, enabled, config FROM instance WHERE id = 'instagram-bot-1';

Result:

• id: instagram-bot-1
• enabled: 1
• config: {"enabled": true, "max_file_size": 50000000, "allowed_rooms": ["!dT40EUcemb8e6bPiig:clarun.xyz"]}

Configuration correct with DM room ID in allowed_rooms list.

Room Membership

SELECT * FROM room_state WHERE room_id = '!dT40EUcemb8e6bPiig:clarun.xyz';

Result: Bot confirmed in room.

Service Logs

Maubot Service Status

ssh root@45.77.205.49 'systemctl status maubot'

• Service: active (running)
• No errors reported

Startup Logs

ssh root@45.77.205.49 'journalctl -u maubot -n 50'

Observed:

• "SocialMediaBot initialized" message appears
• No initialization errors
• No configuration errors
• No authentication errors

Live Monitoring During Message Test

ssh root@45.77.205.49 'journalctl -u maubot -f'

Test: User sends message to room !dT40EUcemb8e6bPiig:clarun.xyz

Result: No log entries appear. Expected "Received message in room..." (INFO level) did not occur.

Homeserver Verification

Conduwuit Accessibility

ssh root@45.77.205.49 'curl -s http://127.0.0.1:8008/_matrix/client/versions | jq .'

Result: Successfully returns Matrix client API versions. Homeserver responsive.

Other Matrix Functionality

• Slack bridge (mautrix-slack) functioning normally
• Bidirectional message flow working
• ~50 portal rooms syncing successfully
• Element client can send/receive messages normally

Conclusion: Conduwuit homeserver operational; issue specific to maubot client.

Web UI Verification

Access: SSH tunnel to http://localhost:29316

Observations:

• Bot instance shows as "started"
• Client shows as enabled
• Configuration visible and correct
• No error indicators in UI

Code Verification

Event Handler Registration

@event.on(EventType.ROOM_MESSAGE)
async def handle_message(self, event: MessageEvent) -> None:
    self.log.info(f"Received message in room {event.room_id}")
    # ... rest of handler

Analysis: Decorator syntax correct, matches maubot patterns used in other plugins.

Config Class Registration

@classmethod
def get_config_class(cls):
    return Config

Analysis: Present and correct (added during session to fix config loading).

What Has Been Ruled Out

❌ Configuration Issues

• Config not loaded (fixed with get_config_class())
• Null config in event handler (fixed with null checks)
• Empty allowed_rooms (updated to include test room)
• Wrong room ID (verified against Element client URL)
• Bot not in room (database shows room membership)

❌ Authentication Issues

• Invalid access token (32 bytes, confirmed in database)
• Homeserver unreachable (curl test successful)
• Client disabled (database shows enabled=1)
• Sync disabled (database shows sync=1)

❌ Code Issues

• Plugin crashes on startup (logs show successful init)
• Event handler syntax error (no Python errors in logs)
• Missing dependencies (plugin loads successfully)
• Plugin not deployed (correct file size and timestamp)

❌ Service Issues

• Maubot service not running (systemctl shows active)
• Service crashes on message (no crash logs observed)
• Database locked (other queries succeed)
• File permissions (service has correct access)

❌ Matrix Server Issues

• Homeserver down (curl test succeeds, Slack bridge works)
• Room doesn't exist (Element shows room, user can send messages)
• Encryption preventing delivery (room not encrypted)

Hypotheses

Hypothesis 1: Maubot Client Sync Loop Not Starting

Likelihood: MEDIUM

Evidence For:

• next_batch not updating
• No sync activity in logs
• No events delivered despite correct config

Evidence Against:

• No errors in logs
• Service shows as running
• Plugin initialization succeeds

Test: Check maubot internal state for sync loop status (no known command for this).

Hypothesis 2: Appservice Registration Issue

Likelihood: LOW

Evidence For:

• Events might not be routed to this specific bot
• Other appservices (Slack bridge) working suggests different registration

Evidence Against:

• Maubot manages registration automatically
• No errors about appservice registration
• Plugin loaded successfully

Test: Manually verify appservice registration file exists and is correct.

Hypothesis 3: Race Condition in Client Initialization

Likelihood: MEDIUM

Evidence For:

• Sync might start before plugin fully ready
• next_batch stuck at initialization value

Evidence Against:

• Multiple service restarts didn't fix
• Configuration updates didn't trigger re-sync

Test: Delete client and recreate via web UI (fresh start).

Hypothesis 4: Maubot Bug with Multiple Clients

Likelihood: LOW

Evidence For:

• No other maubot bots tested on this server
• Could be resource contention or state corruption

Evidence Against:

• Only one maubot instance running
• Database not corrupted (queries succeed)

Test: Create minimal test plugin to verify maubot sync working at all.

Hypothesis 5: Conduwuit Appservice Event Filtering

Likelihood: LOW-MEDIUM

Evidence For:

• Events might not be sent to all appservices
• Could be namespacing or user_id filtering issue

Evidence Against:

• Slack bridge receives events fine
• No errors in conduwuit logs about failed delivery

Test: Check conduwuit logs for appservice event delivery attempts.

Hypothesis 6: Client Sync Token Corruption

Likelihood: MEDIUM

Evidence For:

• next_batch stuck at specific value (40267)
• Might be invalid token causing sync to fail silently

Evidence Against:

• No errors about invalid sync token
• Value looks reasonable (numeric, not obviously corrupt)

Test: Reset next_batch to null or empty string, force fresh sync.

Investigation Steps (Ordered by Priority)

Step 1: Test with Minimal Plugin ⚡ HIGH PRIORITY

Goal: Determine if maubot sync works at all on this server.

Actions:

1. Create minimal test plugin:

   from maubot import Plugin
   from maubot.handlers import event
   from mautrix.types import EventType, MessageEvent
   
   class TestBot(Plugin):
       @event.on(EventType.ROOM_MESSAGE)
       async def handle(self, evt: MessageEvent) -> None:
           self.log.info(f"TEST BOT GOT MESSAGE: {evt.content.body}")
           await evt.respond("pong")
   

2. Deploy as new instance

3. Send test message

4. Check if handler executes

Expected Outcome:

• If minimal bot works: Issue specific to Instagram bot plugin
• If minimal bot fails: Systemic maubot sync issue

Step 2: Reset Client next_batch Token ⚡ HIGH PRIORITY

Goal: Force fresh sync from current state.

Actions:

ssh root@45.77.205.49 "sqlite3 /var/lib/maubot/bot.db \"UPDATE client SET next_batch = '' WHERE id = 'instagram-bot';\""
ssh root@45.77.205.49 'systemctl restart maubot'

Expected Outcome:

• next_batch should update to new value after sync
• Events might start delivering

Risk: Might cause duplicate events if sync was partially working.

Step 3: Recreate Bot Client via Web UI

Goal: Fresh client state, eliminate corruption.

Actions:

1. SSH tunnel: ssh -L 29316:localhost:29316 root@45.77.205.49
2. Access http://localhost:29316
3. Delete existing client "instagram-bot"
4. Create new client with same credentials
5. Update instance to use new client
6. Test message delivery

Expected Outcome:

• Fresh client initialization might fix sync startup
• New access token might help if token was issue

Step 4: Check Conduwuit Logs for Event Delivery

Goal: Verify homeserver attempting to deliver events to maubot appservice.

Actions:

ssh root@45.77.205.49 'journalctl -u matrix-continuwuity --since "5 minutes ago" | grep -i maubot'
ssh root@45.77.205.49 'journalctl -u matrix-continuwuity --since "5 minutes ago" | grep -i appservice'

Look for:

• POST requests to maubot appservice endpoint
• Event delivery attempts
• Errors or timeouts

Expected Outcome:

• If delivery attempts present: Maubot not processing them
• If no delivery attempts: Conduwuit not routing to maubot

Step 5: Verify Appservice Registration

Goal: Ensure maubot properly registered as appservice with conduwuit.

Actions:

# Check maubot registration file
ssh root@45.77.205.49 'cat /var/lib/maubot/registration.yaml'

# Check conduwuit knows about it
ssh root@45.77.205.49 'cat /var/lib/matrix-continuwuity/continuwuity.toml' | grep -A 10 appservice

Look for:

• Registration file exists with correct namespace
• Tokens match between maubot and conduwuit config
• URL accessible from conduwuit

Step 6: Enable Maubot Debug Logging

Goal: Get more visibility into sync loop operation.

Actions:

1. Edit maubot config to enable debug logging
2. Restart service
3. Monitor logs during test message
4. Look for sync loop activity

Expected Information:

• Sync request/response cycle
• Event processing pipeline
• Any silent failures

Step 7: Review Maubot Source Code

Goal: Understand sync loop initialization and failure modes.

Actions:

1. Find maubot package in nix store: nix-store -q --references $(which maubot) | grep maubot
2. Read client sync implementation
3. Look for conditions that prevent sync from starting
4. Check for silent failure paths

Expected Outcome:

• Identify potential bug or misconfiguration
• Find undocumented requirements

Step 8: Compare with Working Bot

Goal: Identify configuration differences.

Actions: If Slack bridge bot uses maubot (it doesn't, but if another working bot exists):

1. Compare database client entries
2. Compare initialization logs
3. Compare registration files
4. Identify what working bot does differently

Workarounds

Workaround 1: Direct Matrix Client Library

Status: NOT ATTEMPTED

Instead of using maubot, implement bot using matrix-nio or mautrix-python directly.

Pros:

• Full control over sync loop
• Better debugging visibility
• No maubot abstraction layer

Cons:

• More code to write
• Lose maubot plugin infrastructure
• Need to implement own config management

Workaround 2: Webhook-Based Bot

Status: NOT ATTEMPTED

Use Matrix webhook events instead of client-server sync.

Pros:

• No sync loop needed
• Push-based event delivery
• Potentially more reliable

Cons:

• Requires appservice registration
• More complex setup
• Different architecture

Related Issues

• None currently tracked (first occurrence of this issue)

Resources

Documentation

• Matrix Client-Server API: https://spec.matrix.org/latest/client-server-api/
• Maubot plugin development: https://docs.mau.fi/maubot/dev/getting-started.html
• mautrix-python sync protocol: https://github.com/mautrix/python

Similar Issues (External)

• Search maubot GitHub issues for "sync not working"
• Search Matrix spec issues for client sync failures

Internal References

• Worklog: docs/worklogs/2025-11-01-maubot-instagram-bot-deployment-and-sync-investigation.org
• Maubot module: modules/maubot.nix
• Plugin source: ~/proj/sna/instagram_bot.py
• Previous maubot worklog: docs/worklogs/2025-10-26-maubot-planning-session.org

Timeline

• 2025-11-01 ~12:00: Deployed Instagram bot plugin to maubot
• 2025-11-01 ~12:30: Fixed config loading bugs (get_config_class, null checks)
• 2025-11-01 ~13:00: Updated allowed_rooms configuration via database
• 2025-11-01 ~13:30: Added INFO logging to plugin
• 2025-11-01 ~14:00: Discovered sync not delivering events (next_batch stuck)
• 2025-11-01 ~15:00: Verified all configuration via database and web UI
• 2025-11-01 ~15:30: Created worklog and this investigation document

Next Actions

Immediate (Today):

1. ⚡ Step 1: Deploy minimal test plugin
2. ⚡ Step 2: Reset next_batch token
3. ⚡ Step 3: Recreate client via web UI

Short-term (This Week): 4. Step 4: Check conduwuit event delivery logs 5. Step 5: Verify appservice registration 6. Step 6: Enable maubot debug logging

Long-term (If Unresolved): 7. Step 7: Review maubot source code 8. Step 8: Consider direct Matrix client library implementation 9. Report bug to maubot project if confirmed

Contact

Assignee: TBD (user decision on next steps) Reviewer: TBD Related Stakeholders: Matrix platform users awaiting Instagram bot functionality

---

Last Updated: 2025-11-01 15:42 PST Next Review: After attempting Steps 1-3