3CX Management console service crash v18

[delis]

Hello all,

Since the last days on our instance, the 3CXPhoneSystemMC01 service crashes with no apparent reason and at random times.

We restart the service manualy by issuing the command systemctl start 3CXPhoneSystemMC01

The first logs showed problems with webrtc, that is why we enabled webrtc logs which are huge and we are waiting for the problem to appear.

Is anyone else here with the same problem? Also, do you know if there is any way to auto restart the service without human intervention?

Thank you.

 

[Saqqara]

Please provide info on your setup

https://www.3cx.com/community/threads/information-to-provide-when-requesting-help.67558/

 

[ChrisC_3CX]

Also, do you know if there is any way to auto restart the service without human intervention?

For this you would have to determine if it's possible to do on the OS level but I'd recommend focusing on identifying the cause for now.

In addition to the info requested above, please also let us know if the 3CX Instance at hand is compliant with our hardware specs recommendations and how it was deployed (3CX ISO, customer portal deployment wizard, hosting provider market place, etc)

 

[johnvam]

For this you would have to determine if it's possible to do on the OS level but I'd recommend focusing on identifying the cause for now.

In addition to the info requested above, please also let us know if the 3CX Instance at hand is compliant with our hardware specs recommendations and how it was deployed (3CX ISO, customer portal deployment wizard, hosting provider market place, etc)

3CX is hosted on AWS installed by marketplace with m4-2xlarge instance (8 cores, 32GB RAM, 300GB SSD)

 

[delis]

• 3CX Version, Enterprise Annual 18.0.237
• Server OS Debian 10
• Is the 3CX Server Hosted and where? AWS EC2
• IP Phone Make/Model/Firmware version, webclients only / No devices
• Provisioning Method: -
• Trunk Provider or VoIP Gateway Make/Model, Generic sip trunk
• Has the Firewall Checker passed: YES
• Are custom Phone Templates being used: No

Also the VM has 32GB RAM 8CPU

 

[ChrisC_3CX]

Could you do me a favor and check the following:

1. What do you see in /var/log/syslog at the time the service crashes? The line should start with something like:

3CXPhoneSystemMC01.service:

2. If you navigate to /var/lib/3cxpbx do you see a core file there? What are the timestamps if you run the "stat" command on the file? Do they match the last crash?

3. It might be a good idea to enable Verbose Logging mode if not already and when it crashes again, retrieve the 3CX Management Console log before restarting the service. The last lines of the log may shed some light on the matter.

 

[delis]

Hello Chris,

The pbx logs are already running in verbose mode since day 1.

The logs at the time of the failure indicate:

Nov 25 13:15:19 ip-10-130-0-190 kernel: [2200202.985000] .NET ThreadPool[2551]: segfault at ffffffffffffffe8 ip 00007f94b473eb65 sp 00007f930b285b60 error 5 in libVCEWebRTCHandler.so[7f94b4723000+32000]
Nov 25 13:15:19 ip-10-130-0-190 kernel: [2200202.996617] Code: 80 00 00 00 00 48 85 ff 74 5b 48 8b 07 48 85 c0 74 53 41 55 49 89 fd 41 54 41 89 f4 55 48 89 cd 53 89 d3 48 83 ec 08 48 8b 10 <48> 03 42 e8 48 89 c7 48 8b 00 ff 50 10 84 c0 74 32 49 8b 7d 00 0f
Nov 25 13:15:24 ip-10-130-0-190 dhclient[545]: XMT: Solicit on ens3, interval 113950ms.
Nov 25 13:15:31 ip-10-130-0-190 systemd[1]: 3CXPhoneSystemMC01.service: Main process exited, code=killed, status=11/SEGV
Nov 25 13:15:32 ip-10-130-0-190 systemd[1]: 3CXPhoneSystemMC01.service: Failed with result 'signal'.
Nov 25 13:17:01 ip-10-130-0-190 CRON[3052]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Nov 25 13:17:18 ip-10-130-0-190 dhclient[545]: XMT: Solicit on ens3, interval 129190ms.
Nov 25 13:19:27 ip-10-130-0-190 dhclient[545]: XMT: Solicit on ens3, interval 129770ms.
Nov 25 13:20:56 ip-10-130-0-190 systemd[1]: Created slice User Slice of UID 1000.
Nov 25 13:20:56 ip-10-130-0-190 systemd[1]: Starting User Runtime Directory /run/user/1000...
Nov 25 13:20:56 ip-10-130-0-190 systemd[1]: Started User Runtime Directory /run/user/1000.
Nov 25 13:20:56 ip-10-130-0-190 systemd[1]: Starting User Manager for UID 1000...
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Reached target Timers.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Listening on GnuPG network certificate management daemon.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Reached target Paths.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Reached target Sockets.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Reached target Basic System.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Reached target Default.
Nov 25 13:20:56 ip-10-130-0-190 systemd[3276]: Startup finished in 41ms.
Nov 25 13:20:56 ip-10-130-0-190 systemd[1]: Started User Manager for UID 1000.
Nov 25 13:20:56 ip-10-130-0-190 systemd[1]: Started Session 4373 of user admin.
Nov 25 13:21:37 ip-10-130-0-190 dhclient[545]: XMT: Solicit on ens3, interval 118880ms.
Nov 25 13:22:38 ip-10-130-0-190 systemd[1]: Starting 3CX PhoneSystem 01 Management Console...
Nov 25 13:22:43 ip-10-130-0-190 systemd[1]: Started 3CX PhoneSystem 01 Management Console.
Nov 25 13:23:10 ip-10-130-0-190 systemd-tmpfiles[3682]: Detected unsafe path transition /var/lib/3cxpbx → /var/lib/3cxpbx/InstanceManager during canonicalization of /var/lib/3cxpbx/InstanceManager.
Nov 25 13:23:10 ip-10-130-0-190 systemd-tmpfiles[3696]: Detected unsafe path transition /var/lib/3cxpbx → /var/lib/3cxpbx/InstanceManager during canonicalization of /var/lib/3cxpbx/InstanceManager.
Nov 25 13:23:10 ip-10-130-0-190 systemd[1]: Created slice User Slice of UID 1002.
Nov 25 13:23:10 ip-10-130-0-190 systemd[1]: Starting User Runtime Directory /run/user/1002...
Nov 25 13:23:10 ip-10-130-0-190 systemd[1]: Started User Runtime Directory /run/user/1002.
Nov 25 13:23:10 ip-10-130-0-190 systemd[1]: Starting User Manager for UID 1002...
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: gpgconf: running /usr/bin/gpg-agent failed (exitcode=2): General error
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: gpgconf: fatal error (exit status 1)
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Listening on GnuPG network certificate management daemon.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Reached target Paths.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Reached target Timers.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Reached target Sockets.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Reached target Basic System.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Reached target Default.
Nov 25 13:23:10 ip-10-130-0-190 systemd[3702]: Startup finished in 21ms.
Nov 25 13:23:10 ip-10-130-0-190 systemd[1]: Started User Manager for UID 1002.
Nov 25 13:23:10 ip-10-130-0-190 systemd[1]: Started Session c1 of user instancemanager.
Nov 25 13:23:17 ip-10-130-0-190 systemd[1]: session-c1.scope: Succeeded.
Nov 25 13:23:18 ip-10-130-0-190 systemd[1]: Reloading.
Nov 25 13:23:18 ip-10-130-0-190 systemd[1]: [email protected]: Current command vanished from the unit file, execution of the command list won't be resumed.
Nov 25 13:23:18 ip-10-130-0-190 systemd[1]: [email protected]: Current command vanished from the unit file, execution of the command list won't be resumed.
Nov 25 13:23:18 ip-10-130-0-190 systemd[1]: Reloading.
Nov 25 13:23:18 ip-10-130-0-190 systemd[1]: Reloading.
Nov 25 13:23:19 ip-10-130-0-190 systemd[1]: Started Instancemanager service.
Nov 25 13:23:22 ip-10-130-0-190 systemd[1]: Reloading.
Nov 25 13:23:22 ip-10-130-0-190 systemd[1]: Reloading.
Nov 25 13:23:23 ip-10-130-0-190 systemd-tmpfiles[7795]: Detected unsafe path transition /var/lib/3cxpbx → /var/lib/3cxpbx/InstanceManager during canonicalization of /var/lib/3cxpbx/InstanceManager.
Nov 25 13:23:23 ip-10-130-0-190 systemd[1]: Started Session c2 of user instancemanager.
Nov 25 13:23:30 ip-10-130-0-190 systemd[1]: session-c2.scope: Succeeded.
Nov 25 13:23:36 ip-10-130-0-190 dhclient[545]: XMT: Solicit on ens3, interval 113920ms.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: Stopping User Manager for UID 1002...
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Stopped target Default.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Stopped target Basic System.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Stopped target Paths.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Stopped target Sockets.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: gpg-agent.socket: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Closed GnuPG cryptographic agent and passphrase cache.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: dirmngr.socket: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Closed GnuPG network certificate management daemon.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: gpg-agent-ssh.socket: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: gpg-agent-extra.socket: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: gpg-agent-browser.socket: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Reached target Shutdown.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: systemd-exit.service: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Started Exit the Session.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Reached target Exit the Session.
Nov 25 13:23:40 ip-10-130-0-190 systemd[3702]: Stopped target Timers.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: [email protected]: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: Stopped User Manager for UID 1002.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: Stopping User Runtime Directory /run/user/1002...
Nov 25 13:23:40 ip-10-130-0-190 systemd[3276]: run-user-1002.mount: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: run-user-1002.mount: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: [email protected]: Succeeded.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: Stopped User Runtime Directory /run/user/1002.
Nov 25 13:23:40 ip-10-130-0-190 systemd[1]: Removed slice User Slice of UID 1002.

 

[ChrisC_3CX]

Did you happen to also check for the core files? Do the exist?

The first logs showed problems with webrtc, that is why we enabled webrtc logs which are huge and we are waiting for the problem to appear.

Also, just to clarify, what logs showed problems with webrtc, what exactly did you see and how did you enable the logs?

 

[delis]

Did you happen to also check for the core files? Do the exist?


Also, just to clarify, what logs showed problems with webrtc, what exactly did you see and how did you enable the logs?

We contacted 3cx support and they told us to enable parameters WEBRTC_EXTENDED_LOG_LEVEL and WEBRTC_EXTENDED_LOG

The core dump files exist , stat command shows

  File: core
  Size: 2172276736      Blocks: 4242736    IO Block: 4096   regular file
Device: 801h/2049d      Inode: 268838      Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1000/   delis)   Gid: ( 1000/   delis)
Access: 2021-11-25 13:15:22.000000000 +0200
Modify: 2021-11-25 13:15:22.000000000 +0200
Change: 2021-12-07 13:04:04.396543237 +0200
Birth: 2021-12-07 13:03:06.764693329 +0200

change and birth shows current date that the we copied the file from another system

 

[ChrisC_3CX]

If you've already contacted 3CX Support about this I highly recommend you stick with the support case. They should be able to determine what is happening if you provide them with the requested files one of which should be the core file.

In the meantime, I recommend you do not implement any configuration that would auto-restart services unless instructed to do so by our support team as this will cause the log files to be wiped and regenerated for those services resulting in loss of vital information.

 

[johnvam]

If you've already contacted 3CX Support about this I highly recommend you stick with the support case. They should be able to determine what is happening if you provide them with the requested files one of which should be the core file.

In the meantime, I recommend you do not implement any configuration that would auto-restart services unless instructed to do so by our support team as this will cause the log files to be wiped and regenerated for those services resulting in loss of vital information.

I fully understand that but you must also understand that this is a production PBX with a service running 24/7/365. So you must propose us a way to fetch log files without interrupting the service.
Thank you

 

[ChrisC_3CX]

If there's a way to avoid it then it's our support team who would know or be able to figure it out so I'd recommend that you bring this to their attention if you have not done so already.

 

[johnvam]

If there's a way to avoid it then it's our support team who would know or be able to figure it out so I'd recommend that you bring this to their attention if you have not done so already.

Great! Thank you

 

[ChrisC_3CX]

You're very welcome! Let us know how it goes!