Middleware starts CTI server before FreePBX is ready

[Stell0]

During restore, nethcti-server.service is started too early by nethcti-middleware.service. The CTI server reaches start-limit-hit before FreePBX has completed its reconfiguration.

The intended flow seems to enable nethcti-server.service without starting it, wait for FreePBX readiness, and start/restart CTI later. However, nethcti-middleware.service has Wants=nethcti-server.service, so starting the middleware pulls the CTI server into the same systemd transaction.

The same issue can also happen during first configuration, but it is usually hidden because the CTI server is started again at the end of the wizard.

Steps to reproduce

1. Restore a system with NethCTI enabled.
2. Let the restore process start nethcti-middleware.service.
3. Check the status or logs of nethcti-server.service before FreePBX finishes reconfiguration.

Expected behavior

nethcti-server.service should start only after FreePBX is ready and the wizard/restore gate allows it.

Actual behavior

nethcti-middleware.service starts nethcti-server.service too early through Wants=nethcti-server.service, causing the CTI server to fail with:

nethcti-server.service: Start request repeated too quickly.
nethcti-server.service: Failed with result 'start-limit-hit'.
Failed to start NethCTI server daemon.

See also

https://mattermost.nethesis.it/nethesis/pl/5s6384ox83yj3eow31u839y1jo

[Stell0]

Test case: NethCTI services start at the correct time

Preliminary check

1. Install or update NethVoice using the image built from PR nethesis/ns8-nethvoice#914.
2. Enter the NethVoice module environment.
3. Check the middleware unit:

systemctl --user cat nethcti-middleware.service

Expected result:

• nethcti-middleware.service does not contain Wants=nethcti-server.service.
• nethcti-server.service is not pulled in just by starting nethcti-middleware.service.

First installation

1. Install a new NethVoice instance.
2. Start the first configuration wizard but do not complete it.
3. Check CTI services while the wizard is still running:

systemctl --user is-active nethcti-server.service nethcti-middleware.service
journalctl --user -u nethcti-server.service -u nethcti-middleware.service

Expected result:

• nethcti-server.service is not active before wizard completion.
• nethcti-middleware.service is not active before wizard completion.
• There are no early startup failures for nethcti-server.service.

4. Complete the wizard.
5. Check the CTI services again:

systemctl --user is-active nethcti-server.service nethcti-middleware.service
journalctl --user -u nethcti-server.service -u nethcti-middleware.service

Expected result:

• Both nethcti-server.service and nethcti-middleware.service are started at the end of the wizard.
• Both services are active.
• The logs do not contain:

start-limit-hit
Start request repeated too quickly
Failed to start NethCTI server daemon

Backup restore

1. Restore a backup of a configured NethVoice instance from the testing package.
2. Follow the restore task logs.
3. Check when CTI services are started:

journalctl --user -u nethcti-server.service -u nethcti-middleware.service

Expected result:

• nethcti-server.service and nethcti-middleware.service are not started early by configure-module/80start_services.
• Both services are started by restore-module/72reload_services.
• Both services are active after restore.
• The logs do not contain start-limit-hit or repeated start failures.

[Stell0]

QA result

Status: pass
Target: NethServer/dev#8096
Package tested: ghcr.io/nethesis/nethvoice:pr-914.403-1.b5aaa5b
Install/update path: update existing instance + fresh install + backup/restore
Environment: *** via SSH as root, Rocky Linux 9.8, NS8 single-node cluster

Acceptance criteria checked
- nethcti-middleware.service no longer pulls nethcti-server.service through Wants=
- On first configuration, CTI services stay inactive before wizard completion
- On restore, CTI services are started by restore-module/72reload_services, not early by configure-module
- No start-limit-hit
- No Start request repeated too quickly
- No Failed to start NethCTI server daemon

Steps performed
1. Read issue NethServer/dev#8096 and PR nethesis/ns8-nethvoice#914
2. Identified latest PR image from PR comments:
   - ghcr.io/nethesis/nethvoice:pr-914.403-1.b5aaa5b
3. Connected to *** over SSH using the configured private key
4. Updated existing instance nethvoice20 to the PR image
5. Verified the installed middleware unit on nethvoice20
6. Installed a fresh temporary instance nethvoice21 from the PR image
7. Ran configure-module on nethvoice21
8. Verified CTI services stayed inactive after first configuration
9. Backed up nethvoice21
10. Removed nethvoice21
11. Restored that backup as nethvoice22
12. Verified restore timing and CTI startup sequence from journal logs
13. Cleaned up temporary test objects (nethvoice21, nethvoice22, backup id 4)

Commands / checks

Check: PR image discovery
Command or method: PR comment on nethesis/ns8-nethvoice#914
Result: pass
────────────────────────────────────────
Check: Update existing instance
Command or method: api-cli run update-module --data
  '{"module_url":"ghcr.io/nethesis/nethvoice:pr-914.403-1
  .b5aaa5b","instances":["nethvoice20"]}'
Result: pass
────────────────────────────────────────
Check: Updated version
Command or method: api-cli run list-installed-modules for nethvoice20
Result: pass (pr-914.403-1.b5aaa5b)
────────────────────────────────────────
Check: Middleware unit dependency
Command or method: runagent -m nethvoice20 ... systemctl --user cat
  nethcti-middleware.service
Result: pass (Wants=nethcti-server.service absent)
────────────────────────────────────────
Check: Fresh install
Command or method: api-cli run add-module --data
  '{"image":"ghcr.io/nethesis/nethvoice:pr-914.403-1.b5aa a5b","node":1}'
Result: pass (nethvoice21)
────────────────────────────────────────
Check: First configuration
Command or method: api-cli run module/nethvoice21/configure-module --data
  ...
Result: pass
────────────────────────────────────────
Check: CTI inactive before wizard completion
Command or method: api-cli run module/nethvoice21/get-status
Result: pass (freepbx active, nethcti-server inactive, nethcti-middleware
  inactive)
────────────────────────────────────────
Check: Backup temp instance
Command or method: api-cli run add-backup ..., api-cli run run-backup
  --data '{"id":4}'
Result: pass
────────────────────────────────────────
Check: Restore temp backup
Command or method: api-cli run restore-module --data
  '{"repository":"86d1a8ac-ef89-557a-8e19-8582ab86b7c4","
  path":"nethvoice/fdc9cb65-70e8-4032-abcd-04e1edae7e7b",
  "snapshot":"7b452580aa2fcba66fd915fa7ef856dcd136839d1c5
  e9d88319587bde8779b95","node":1}'
Result: pass (nethvoice22)
────────────────────────────────────────
Check: Restore timing
Command or method: host journal for UID of nethvoice22
Result: pass
────────────────────────────────────────
Check: Final restored service state
Command or method: api-cli run module/nethvoice22/get-status
Result: pass

Evidence
- After update, nethvoice20 reported:
  - version: pr-914.403-1.b5aaa5b
- Middleware unit on the updated package contained:
  - After=nethcti-server.service mariadb.service
  - Requires=mariadb.service
  - and did not contain Wants=nethcti-server.service
- Fresh install check on nethvoice21 after configure-module:
  - freepbx: active
  - nethcti-server: inactive
  - nethcti-middleware: inactive
- Restore check on nethvoice22 from journal:
  - 09:56:58 configure-module/95service_adjust is starting
  - 09:56:59 action "configure-module" status is "completed" (0)
  - 09:57:29 restore-module/72reload_services is starting
  - 09:57:38 Starting NethCTI server daemon...
  - 09:57:39 Started NethCTI server daemon.
  - 09:57:39 Starting NethCTI middleware daemon...
  - 09:57:41 Started NethCTI middleware daemon.
  - 09:57:41 action "restore-module" status is "completed" (0)
- Negative checks:
  - No start-limit-hit
  - No Start request repeated too quickly
  - No Failed to start NethCTI server daemon

Findings
- The specific issue described in #8096 appears fixed:
  - nethcti-middleware.service no longer has the Wants= dependency
  - on fresh configuration, CTI services stay inactive until later
  - on restore, CTI services are started by restore-module/72reload_services, not early during configure-module
- I observed one transient post-restore reload failure:
  - podman exec nethcti-server node /app/nethcti-cli reload
  - error: connect ENOENT /run/nethvoice/nethcti.sock
  - this happened during adjust-services
  - the service recovered automatically afterward, and final status was healthy
- This transient reload error did not reproduce the original start-limit-hit failure from #8096

Cleanup
- Removed temporary module instance: nethvoice21
- Removed restored temporary module instance: nethvoice22
- Removed temporary backup definition: id 4

Residual risk
- I did not test the browser wizard interactively; I validated the pre-wizard state through configure-module and service/journal state over SSH
- I observed a transient nethcti-server reload failure during restore recovery, although final state was healthy