XMPP upgrade - mongodb not running - letschat 100% cpu

Distro Discussion & Help
1

I have just tried to upgrade my FreePBX system (13.0.191.11). This includes upgrading XMPP from 13.0.14 to 13.0.16.9 after performing this update the result is the FreePBX system is 100% busy, the process letschat is cpu bound.

Investigating the issue I found that letschat was attempting to connect to local port 27017 (this is reported in the xmpp logs), and that it looked like mongodb was not running.

So I reverted to a snapshot (this is a VM Installation) and stepped forward one update at a time. The problem occurs at the point that I install XMPP. I performed the XMPP installation manually so that I could capture the information, this is attached below.

The strange thing is that I have two VM systems running FreePBX, and I thought that these systems are identical, yet the other system installed the updates correctly and does not have this problem.

Does anyone have any clue as to what the problem is, or how I fix it?

Thanks,
Tim

[root@localhost ~]# fwconsole ma install xmpp
Removing Prosody....Done
Installing/Updating MongoDB...................................................................................................................Done
Installing/Updating Required Libraries. This may take a while...The following messages are ONLY FOR DEBUGGING. Ignore anything that says 'WARN' or is just a warning
[npm-cache] [INFO] using /home/asterisk/.package_cache as cache directory
[npm-cache] [INFO] [composer] Dependency config file /var/www/html/admin/modules/xmpp/node/composer.json does not exist. Skipping install
[npm-cache] [INFO] [npm] config file exists
[npm-cache] [INFO] [npm] cli exists
[npm-cache] [INFO] [npm] hash of /var/www/html/admin/modules/xmpp/node/package.json: 7d021ac34087d85e31949de3fbf0786c
[npm-cache] [INFO] [npm] running [npm install]...
npm WARN engine [email protected]: wanted: {"node":"0.8.x"} (current: {"node":"0.12.18","npm":"2.15.11"})
npm WARN deprecated [email protected]: not actively maintained anymore
npm WARN deprecated [email protected]: use @xmpp/jid package <https://www.npmjs.com/package/@xmpp/jid>
npm WARN engine [email protected]: wanted: {"node":">=4"} (current: {"node":"0.12.18","npm":"2.15.11"})
npm WARN engine [email protected]: wanted: {"node":">=5.0.0"} (current: {"node":"0.12.18","npm":"2.15.11"})
npm WARN optional dep failed, continuing [email protected]

> [email protected] preinstall /var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/i18n/node_modules/messageformat/node_modules/watchr/node_modules/extendr/node_modules/typechecker
> node ./cyclic.js


> [email protected] preinstall /var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/i18n/node_modules/messageformat/node_modules/watchr/node_modules/extract-opts/node_modules/typechecker
> node ./cyclic.js


> [email protected] install /var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/node-xmpp-server/node_modules/ws/node_modules/utf-8-validate
> node-gyp rebuild

make: Entering directory `/var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/node-xmpp-server/node_modules/ws/node_modules/utf-8-validate/build'
  CXX(target) Release/obj.target/validation/src/validation.o
In file included from ../src/validation.cc:8:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘void node::FatalException(const v8::TryCatch&)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:273: warning: ‘void node::FatalException(v8::Isolate*, const v8::TryCatch&)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:270)
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘v8::Local<v8::Value> node::Encode(const void*, size_t, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:282: warning: ‘v8::Local<v8::Value> node::Encode(v8::Isolate*, const void*, size_t, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:278)
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘ssize_t node::DecodeBytes(v8::Handle<v8::Value>, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:294: warning: ‘ssize_t node::DecodeBytes(v8::Isolate*, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:291)
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘ssize_t node::DecodeWrite(char*, size_t, v8::Handle<v8::Value>, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:307: warning: ‘ssize_t node::DecodeWrite(v8::Isolate*, char*, size_t, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:302)
In file included from ../src/validation.cc:10:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::New(v8::Handle<v8::String>, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:55: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, v8::Handle<v8::String>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:52)
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::New(const char*, size_t)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:65: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, const char*, size_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:62)
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::New(char*, size_t, void (*)(char*, void*), void*)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:75: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, char*, size_t, void (*)(char*, void*), void*)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:70)
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::Use(char*, uint32_t)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:88: warning: ‘v8::Local<v8::Object> node::Buffer::Use(v8::Isolate*, char*, uint32_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:85)
In file included from ../src/validation.cc:15:
../node_modules/nan/nan.h: In function ‘Nan::MaybeLocal<v8::Object> Nan::NewBuffer(char*, size_t, void (*)(char*, void*), void*)’:
../node_modules/nan/nan.h:685: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, char*, size_t, void (*)(char*, void*), void*)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:70)
../node_modules/nan/nan.h: In function ‘Nan::MaybeLocal<v8::Object> Nan::CopyBuffer(const char*, uint32_t)’:
../node_modules/nan/nan.h:701: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, const char*, size_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:62)
../node_modules/nan/nan.h: In function ‘Nan::MaybeLocal<v8::Object> Nan::NewBuffer(char*, uint32_t)’:
../node_modules/nan/nan.h:729: warning: ‘v8::Local<v8::Object> node::Buffer::Use(v8::Isolate*, char*, uint32_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:85)
../node_modules/nan/nan.h: In function ‘void Nan::FatalException(const Nan::TryCatch&)’:
../node_modules/nan/nan.h:850: warning: ‘void node::FatalException(v8::Isolate*, const v8::TryCatch&)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:270)
../node_modules/nan/nan.h: In function ‘v8::Local<v8::Value> Nan::Encode(const void*, size_t, Nan::Encoding)’:
../node_modules/nan/nan.h:1760: warning: ‘v8::Local<v8::Value> node::Encode(v8::Isolate*, const void*, size_t, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:278)
../node_modules/nan/nan.h: In function ‘ssize_t Nan::DecodeBytes(v8::Local<v8::Value>, Nan::Encoding)’:
../node_modules/nan/nan.h:1776: warning: ‘ssize_t node::DecodeBytes(v8::Isolate*, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:291)
../node_modules/nan/nan.h: In function ‘ssize_t Nan::DecodeWrite(char*, size_t, v8::Local<v8::Value>, Nan::Encoding)’:
../node_modules/nan/nan.h:1798: warning: ‘ssize_t node::DecodeWrite(v8::Isolate*, char*, size_t, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:302)
  SOLINK_MODULE(target) Release/obj.target/validation.node
  COPY Release/validation.node
make: Leaving directory `/var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/node-xmpp-server/node_modules/ws/node_modules/utf-8-validate/build'

> [email protected] install /var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/node-xmpp-server/node_modules/ws/node_modules/bufferutil
> node-gyp rebuild

make: Entering directory `/var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/node-xmpp-server/node_modules/ws/node_modules/bufferutil/build'
  CXX(target) Release/obj.target/bufferutil/src/bufferutil.o
In file included from ../src/bufferutil.cc:8:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘void node::FatalException(const v8::TryCatch&)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:273: warning: ‘void node::FatalException(v8::Isolate*, const v8::TryCatch&)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:270)
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘v8::Local<v8::Value> node::Encode(const void*, size_t, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:282: warning: ‘v8::Local<v8::Value> node::Encode(v8::Isolate*, const void*, size_t, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:278)
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘ssize_t node::DecodeBytes(v8::Handle<v8::Value>, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:294: warning: ‘ssize_t node::DecodeBytes(v8::Isolate*, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:291)
/home/asterisk/.node-gyp/0.12.18/include/node/node.h: In function ‘ssize_t node::DecodeWrite(char*, size_t, v8::Handle<v8::Value>, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node.h:307: warning: ‘ssize_t node::DecodeWrite(v8::Isolate*, char*, size_t, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:302)
In file included from ../src/bufferutil.cc:10:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::New(v8::Handle<v8::String>, node::encoding)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:55: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, v8::Handle<v8::String>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:52)
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::New(const char*, size_t)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:65: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, const char*, size_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:62)
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::New(char*, size_t, void (*)(char*, void*), void*)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:75: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, char*, size_t, void (*)(char*, void*), void*)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:70)
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h: In function ‘v8::Local<v8::Object> node::Buffer::Use(char*, uint32_t)’:
/home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:88: warning: ‘v8::Local<v8::Object> node::Buffer::Use(v8::Isolate*, char*, uint32_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:85)
In file included from ../src/bufferutil.cc:16:
../node_modules/nan/nan.h: In function ‘Nan::MaybeLocal<v8::Object> Nan::NewBuffer(char*, size_t, void (*)(char*, void*), void*)’:
../node_modules/nan/nan.h:694: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, char*, size_t, void (*)(char*, void*), void*)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:70)
../node_modules/nan/nan.h: In function ‘Nan::MaybeLocal<v8::Object> Nan::CopyBuffer(const char*, uint32_t)’:
../node_modules/nan/nan.h:709: warning: ‘v8::Local<v8::Object> node::Buffer::New(v8::Isolate*, const char*, size_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:62)
../node_modules/nan/nan.h: In function ‘Nan::MaybeLocal<v8::Object> Nan::NewBuffer(char*, uint32_t)’:
../node_modules/nan/nan.h:735: warning: ‘v8::Local<v8::Object> node::Buffer::Use(v8::Isolate*, char*, uint32_t)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node_buffer.h:85)
../node_modules/nan/nan.h: In function ‘void Nan::FatalException(const Nan::TryCatch&)’:
../node_modules/nan/nan.h:870: warning: ‘void node::FatalException(v8::Isolate*, const v8::TryCatch&)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:270)
../node_modules/nan/nan.h: In function ‘v8::Local<v8::Value> Nan::Encode(const void*, size_t, Nan::Encoding)’:
../node_modules/nan/nan.h:1788: warning: ‘v8::Local<v8::Value> node::Encode(v8::Isolate*, const void*, size_t, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:278)
../node_modules/nan/nan.h: In function ‘ssize_t Nan::DecodeBytes(v8::Local<v8::Value>, Nan::Encoding)’:
../node_modules/nan/nan.h:1804: warning: ‘ssize_t node::DecodeBytes(v8::Isolate*, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:291)
../node_modules/nan/nan.h: In function ‘ssize_t Nan::DecodeWrite(char*, size_t, v8::Local<v8::Value>, Nan::Encoding)’:
../node_modules/nan/nan.h:1826: warning: ‘ssize_t node::DecodeWrite(v8::Isolate*, char*, size_t, v8::Handle<v8::Value>, node::encoding)’ is deprecated (declared at /home/asterisk/.node-gyp/0.12.18/include/node/node.h:302)
  SOLINK_MODULE(target) Release/obj.target/bufferutil.node
  COPY Release/bufferutil.node
make: Leaving directory `/var/www/html/admin/modules/xmpp/node/node_modules/lets-chat/node_modules/node-xmpp-server/node_modules/ws/node_modules/bufferutil/build'
npm WARN engine [email protected]: wanted: {"node":">= 4"} (current: {"node":"0.12.18","npm":"2.15.11"})
npm WARN engine [email protected]: wanted: {"node":">=4"} (current: {"node":"0.12.18","npm":"2.15.11"})
npm WARN engine [email protected]: wanted: {"node":">=4"} (current: {"node":"0.12.18","npm":"2.15.11"})
[email protected] node_modules/lets-chat
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected]
├── [email protected] ([email protected])
├── [email protected] ([email protected])
├── [email protected] ([email protected])
├── [email protected] ([email protected])
├── [email protected] ([email protected], [email protected], [email protected])
├── [email protected] ([email protected])
├── [email protected] ([email protected], [email protected])
├── [email protected]
├── [email protected] ([email protected])
├── [email protected] ([email protected], [email protected])
├── [email protected] ([email protected], [email protected])
├── [email protected] ([email protected], [email protected])
├── [email protected]
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected])
├── [email protected] ([email protected], [email protected])
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected]
├── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
├── [email protected]
└── [email protected] ([email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected], [email protected])
[npm-cache] [INFO] [npm] installed npm dependencies, now archiving
[npm-cache] [INFO] [npm] archiving dependencies from /var/www/html/admin/modules/xmpp/node/node_modules
[npm-cache] [INFO] [bower] Dependency config file /var/www/html/admin/modules/xmpp/node/bower.json does not exist. Skipping install
[npm-cache] [INFO] [npm] installed and archived dependencies
[npm-cache] [INFO] successfully installed all dependencies

Finished updating libraries!
Starting new Xmpp Process...Started with PID 3737!
Generating CSS...Done
Module xmpp successfully installed
Updating Hooks...Done
[root@localhost ~]#
1 Like
2

I think that I have just “solved” this problem.

I have located the mongodb logs in /var/log/mongodb and the problem is a lack of free disk space.

mongo wants at least 844MB of free space on the drive, and won’t start due to lack of free space.

The log file says:

Sat Apr 29 12:15:38.857 [initandlisten] Please make at least 844MB available in /var/lib/mongodb/journal or use --smallfiles

So, it looks like my fault for having VMs with insufficient disk space (6GB).

Simple solution at this stage is to increase the disk space.

It looks like a large wack of disk space for this function!

Tim

3

You can uninstall xmpp if you don’t need it.

4

Hi Andrew,

Yes, I should have mentioned that in my 2nd post. If you uninstall XMPP the problem goes away. Although when I tested this it looked like I also had to restart. The uninstall did not reliably terminate the letschat process.

Since these are test systems that I use to check updates I prefer to leave them in the ‘factory’ configuration just so that I encounter issue like this.

Thanks for the rapid response.
Tim

5

OK, so now I am stumped.

I elected to increase the disk space - no problems there.

However, I am unable to get mongodb to start when FreePBX starts. I have tried:

  • uninstall xmpp, install xmpp
  • uninstall xmpp, locate the yum mongodb install, use yum to reverse the mongodb install, install xmpp

I have no idea what is actually starting mongodb on my working FreePBX VM, but nothing starts mongodb on the system that had the low disk space problem at the time of 1st installation of xmpp. I have searched high and low and can’t work out why mongodb does not start automatically.

I can start mongod using:

service mongod start

Running chkconfig tells me that mongod is ‘off’ for all run-levels, and this is the same on both FreePBX systems. Yet on the ‘working’ system mongod is running, and on the other it isn’t. I have checked all file ownerships and permissions I can find.

It just looks like whatever is supposed to start mongod isn’t doing it.

Does anyone know what actually starts mongod in FreePBX?

Thanks,
Tim

6

XMPP. Specifically a script in the hooks folder of the module. Do note that to actually finish starting xmpp mongodb has to be running, eg it checks the running service. Which leads me to speculate that it is running and then it immediately crashes.

7

Many thanks - armed with that information:

  1. I determined that the mongod-start hook script was never being called. So at least that explained why mongod was not running.

  2. I uninstalled, removed, downloaded, installed xmpp that made no difference.

  3. I then noticed that letschat was actually a child process of the PM2 daemon. So on a hunch I did this:

uninstall and remove: xmpp ucpnode pm2
download and install: pm2 xmpp ucpnode

and voila! mongod is started, and everything looks fine again.

I hope that helps anyone who gets stuck in the same situation - which you won’t if you have enough disk space.

Tim

1 Like
8

Thanks for the pointers! My xmpp failed to update, then system ran out of memory. I restarted it, then found letschat using a significant amount of memory. Ok, not huge, but I’m on a hosted virtual server so over 1G is pretty big.

Going to follow the earlier suggestion and disable xmpp as I don’t use it.

Also, on reboot, found iSymphony Server started. I had disabled in modules, but it was still in the init.d services startup list.

9

I just had a look at the letschat process and you are correct it is using quite a lot of memory. The introduction of the pm2 module appears to add quite significantly to both the memory and disk requirements for FreePBX.

My VM with 1G of vRAM is now using swap, which it never used to - and this is a system that is doing ‘nothing’. My 2G of vRAM VM, which has a few lines and extensions, is not swapping.

Which all suggests that removing xmpp (and possibly other associated modules if you are not using them) could well save on disk and memory resources.

10

The pm2 module does not add any more to disk or ram it’s a process manager. Much the same as forever which we used to use. You are confusing the pm2 process with xmpp. Which does use more ram and disk space.

You can view ram usage by running:
fwconsole pm2 --list

You can also remove the xmpp process if it’s not for you. I’d recommend not removing the pm2 process and furthermore the pm2 process itself doesn’t use very many resources.