Created attachment 821917 [details] openstack setup log Description of problem: when running packstack and ceilometer is enabled in the answer file. it fails the first time. i have to run it a 2nd time for it to be succesful. the error message is ERROR : Error appeared during Puppet run: 192.168.122.254_ceilometer.pp Error: /Stage[main]/Ceilometer::Db/Exec[ceilometer-dbsync]: Failed to call refresh: ceilometer-dbsync --config-file=/etc/ceilometer/ceilometer.conf returned 1 instead of one of [0] did this on 2 fresh installs Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info:
Created attachment 821918 [details] packstack answer file
Hi I had a few queries about the setup: Did you run it in all-in-one configuration? Was the configuration setup on Fedora or RHEL? Rushil
Hi Can you also please attach the error log file with this bug? I tried running the same on an all in one file and it worked fine for me. This happens sometimes when sync_db is run before MongoDB service starts. First time MongoDB starts it's slower because of DB initialization. Rushil
rushil i can reproduce it at will. however, i _JUST_ finally managed to get my openstack instace working and do not want to delete it just yet. so to reproduce it this is my packstack answer file edits: https://raw.github.com/marafa/openstack/master/openstack-notes.sh in particular: #####modify ~/packstack.answer sed -i 's/CONFIG_NTP_SERVERS=/CONFIG_NTP_SERVERS=0.pool.ntp.org,1.pool.ntp.org,2.pool.ntp.org/g' ~/packstack.answer sed -i 's/CONFIG_HORIZON_SSL=n/CONFIG_HORIZON_SSL=y/g' ~/packstack.answer sed -i 's/PW=.*/PW=password/g' ~/packstack.answer sed -i 's/CONFIG_SWIFT_INSTALL=n/CONFIG_SWIFT_INSTALL=y/g' ~/packstack.answer sed -i 's/CONFIG_CINDER_VOLUMES_SIZE=20G/CONFIG_CINDER_VOLUMES_SIZE=5G/g' ~/packstack.answer sed -i 's,CONFIG_NOVA_NETWORK_FLOATRANGE=10.3.4.0/22,CONFIG_NOVA_NETWORK_FLOATRANGE=192.168.0.0/24,g' ~/packstack.answer sed -i 's/CONFIG_PROVISION_DEMO=n/CONFIG_PROVISION_DEMO=y/g' ~/packstack.answer sed -i 's,CONFIG_PROVISION_DEMO_FLOATRANGE=172.24.4.224/28,CONFIG_PROVISION_DEMO_FLOATRANGE=192.168.0.0/24,g' ~/packstack.answer ####vlan support sed -i 's/CONFIG_NEUTRON_OVS_TENANT_NETWORK_TYPE=local/CONFIG_NEUTRON_OVS_TENANT_NETWORK_TYPE=vlan/g' ~/packstack.answer sed -i 's/CONFIG_NEUTRON_OVS_VLAN_RANGES=/CONFIG_NEUTRON_OVS_VLAN_RANGES=physnet1:1000:2999/g' ~/packstack.answer sed -i 's/CONFIG_NEUTRON_OVS_BRIDGE_MAPPINGS=/CONFIG_NEUTRON_OVS_BRIDGE_MAPPINGS=physnet1:br-eth0:1/g' ~/packstack.answer and it was on centos6.4 fully patched before installing packstack
hi again i see i attached the packstack answer file previously thanks
ERROR : Error appeared during Puppet run: 192.168.122.254_ceilometer.pp Error: /Stage[main]/Ceilometer::Db/Exec[ceilometer-dbsync]: Failed to call refresh: ceilometer-dbsync --config-file=/etc/ceilometer/ceilometer.conf returned 1 instead of one of [0] [root@openstack ~]# packstack --allinone --nagios-install=n i changed the parameters of packstack and yet i got the same issue. fresh install
Hi Mohammed, Can you also attach your /var/log/mongodb/mongodb.log? (specifically the log fragment from around the time that the problem was encountered) Thanks, Eoghan
[root@openstack mongodb]# cat mongodb.log Fri Nov 22 06:45:15.320 [initandlisten] MongoDB starting : pid=2146 port=27017 dbpath=/var/lib/mongodb 64-bit host=openstack.marafa.vm Fri Nov 22 06:45:15.321 [initandlisten] db version v2.4.6 Fri Nov 22 06:45:15.321 [initandlisten] git version: nogitversion Fri Nov 22 06:45:15.321 [initandlisten] build info: Linux buildvm-09.phx2.fedoraproject.org 3.10.9-200.fc19.x86_64 #1 SMP Wed Aug 21 19:27:58 UTC 2013 x86_64 BOOST_LIB_VERSION=1_41 Fri Nov 22 06:45:15.321 [initandlisten] allocator: tcmalloc Fri Nov 22 06:45:15.321 [initandlisten] options: { bind_ip: "127.0.0.1", command: [ "run" ], config: "/etc/mongodb.conf", dbpath: "/var/lib/mongodb", fork: "true", journal: "true", logpath: "/var/log/mongodb/mongodb.log", nohttpinterface: "true", pidfilepath: "/var/run/mongodb/mongodb.pid", port: 27017, quiet: true } Fri Nov 22 06:45:15.323 [initandlisten] Fri Nov 22 06:45:15.323 [initandlisten] ** WARNING: Readahead for /var/lib/mongodb is set to 512KB Fri Nov 22 06:45:15.323 [initandlisten] ** We suggest setting it to 256KB (512 sectors) or less Fri Nov 22 06:45:15.323 [initandlisten] ** http://dochub.mongodb.org/core/readahead Fri Nov 22 06:45:15.344 [initandlisten] journal dir=/var/lib/mongodb/journal Fri Nov 22 06:45:15.345 [initandlisten] recover : no journal files present, no recovery needed Fri Nov 22 06:45:15.345 [initandlisten] Fri Nov 22 06:45:15.345 [initandlisten] ERROR: Insufficient free space for journal files Fri Nov 22 06:45:15.345 [initandlisten] Please make at least 3379MB available in /var/lib/mongodb/journal or use --smallfiles Fri Nov 22 06:45:15.345 [initandlisten] Fri Nov 22 06:45:15.345 [initandlisten] exception in initAndListen: 15926 Insufficient free space for journals, terminating Fri Nov 22 06:45:15.345 dbexit: Fri Nov 22 06:45:15.345 [initandlisten] shutdown: going to close listening sockets... Fri Nov 22 06:45:15.345 [initandlisten] shutdown: going to flush diaglog... Fri Nov 22 06:45:15.345 [initandlisten] shutdown: going to close sockets... Fri Nov 22 06:45:15.345 [initandlisten] shutdown: waiting for fs preallocator... Fri Nov 22 06:45:15.345 [initandlisten] shutdown: lock for final commit... Fri Nov 22 06:45:15.345 [initandlisten] shutdown: final commit... Fri Nov 22 06:45:15.345 [initandlisten] shutdown: closing all files... Fri Nov 22 06:45:15.345 [initandlisten] closeAllFiles() finished Fri Nov 22 06:45:15.345 [initandlisten] journalCleanup... Fri Nov 22 06:45:15.345 [initandlisten] removeJournalFiles Fri Nov 22 06:45:15.354 [initandlisten] shutdown: removing fs lock... Fri Nov 22 06:45:15.354 dbexit: really exiting now [root@openstack mongodb]# df Filesystem 1K-blocks Used Available Use% Mounted on /dev/mapper/vg_openstack-lv_root 3874440 1768316 1909312 49% / tmpfs 4029800 0 4029800 0% /dev/shm /dev/vda1 495844 87373 382871 19% /boot /srv/loopback-device/device1 982936 34056 896452 4% /srv/node/device1 [root@openstack mongodb]# df -h Filesystem Size Used Avail Use% Mounted on /dev/mapper/vg_openstack-lv_root 3.7G 1.7G 1.9G 49% / tmpfs 3.9G 0 3.9G 0% /dev/shm /dev/vda1 485M 86M 374M 19% /boot /srv/loopback-device/device1 960M 34M 876M 4% /srv/node/device1
Created attachment 827701 [details] mongo
Created attachment 827702 [details] mongo
Created attachment 827703 [details] mongo
Hi Mohammed, So here's your problem I think: ERROR: Insufficient free space for journal files Note that mongodb by default eagerly preallocates journal files. Are you installing openstack in a highly resource-constrained environment, such as on a small-flavor VM without significant disk space? The time taken by mongodb startup in such an environment may also be problematic. You can work-around these issues by pre-installing mongo as follows, setting the --smallfiles option to reduce the initial file size to 512Mb, and also increase the startup timeout: # pre-install mongodb sudo yum install -y mongodb-server mongodb # use smaller initial file size sudo sed -i '/--smallfiles/!s/OPTIONS=\"/OPTIONS=\"--smallfiles /' /etc/sysconfig/mongod # increase the start-up timeout sudo sed -i '/^\[Service\]$/ a\ TimeoutStartSec=360' /usr/lib/systemd/system/mongod.service # fire up the mongodb service initially to force the journal pre-allocation sudo service mongod start sudo service mongod status sudo service mongod stop Cheers, Eoghan
so ..the journal wanted 3.x GB of free space is required? or else use --smallfiles ? the logic of it escapes me. however, i have another question now, how will having mongodb preinstalled (most likely with a password) affect the packstack installation process?
Hi Mohammed, The logic of mongodb journal file pre-allocation is an aspect of mongodb that's outside our control, other than via the config options referred to above. Preinstallation of mongodb will not cause a problem for packstack. Given the above information, are you happy for me to close off this issue? (You would of course be welcome to file another bug if you other related issue crops up for you). Cheers, Eoghan
thanks eoghan
I'm re-opening this, I think we should default to --smallfiles to alleviate this somewhat - I'm also cloning to RHOS and the associated documentation components to ensure we note this in the up front requirements.
Hmm we might have a race here too. I tried openstack-packstack-2013.2.1-0.27.dev936 on Fedora 20, and the first time ceilometer errored out with mongodb not running. I've loads of space, and a separate mongodb service start command worked, after which a subsequent packstack run proceeded without issue.
this may be related to https://bugzilla.redhat.com/show_bug.cgi?id=1040573
On F20, I'm seeing the same error from Puppet: ERROR : Error appeared during Puppet run: 192.168.20.1_ceilometer.pp Error: Could not start Service[mongodb]: Execution of '/sbin/service mongod start' returned 1: You will find full trace in log /var/tmp/packstack/20140108-141702-KxiKGp/manifests/192.168.20.1_ceilometer.pp.log Please check log file /var/tmp/packstack/20140108-141702-KxiKGp/openstack-setup.log for more information And in /var/tmp/packstack/20140108-141702-KxiKGp/manifests/192.168.20.1_ceilometer.pp.log: Error: Could not start Service[mongodb]: Execution of '/sbin/service mongod start' returned 1: Error: /Stage[main]/Mongodb/Service[mongodb]/ensure: change from stopped to running failed: Could not start Service[mongodb]: Execution of '/sbin/service mongod start' returned 1: Notice: /Stage[main]/Mongodb/Service[mongodb]/ensure: ensure changed 'stopped' to 'running' Notice: /Stage[main]/Mongodb/Service[mongodb]/enable: enable changed 'false' to 'true' Notice: /Stage[main]/Mongodb/Service[mongodb]: Triggered 'refresh' from 1 events But after packstack exits, mongod is actually running: # systemctl status mongod mongod.service - High-performance, schema-free document-oriented database Loaded: loaded (/usr/lib/systemd/system/mongod.service; enabled) Active: active (running) since Wed 2014-01-08 14:41:58 UTC; 15min ago Process: 18504 ExecStart=/usr/bin/mongod $OPTIONS run (code=exited, status=0/SUCCESS) Main PID: 18506 (mongod) CGroup: /system.slice/mongod.service └─18506 /usr/bin/mongod --quiet -f /etc/mongodb.conf run So I'm unclear on what is actually causing the error in Puppet. The mongod log file does not contain any errors: Wed Jan 8 14:41:58.797 [initandlisten] MongoDB starting : pid=18506 port=27017 dbpath=/var/lib/mongodb 64-bit host=os-api.novalocal Wed Jan 8 14:41:58.797 [initandlisten] db version v2.4.6 Wed Jan 8 14:41:58.797 [initandlisten] git version: nogitversion Wed Jan 8 14:41:58.797 [initandlisten] build info: Linux buildvm-12.phx2.fedoraproject.org 3.10.9-200.fc19.x86_64 #1 SMP Wed Aug 21 19:27:58 UTC 2013 x86_64 BOOST_LIB_VERSION=1_54 Wed Jan 8 14:41:58.797 [initandlisten] allocator: tcmalloc Wed Jan 8 14:41:58.797 [initandlisten] options: { bind_ip: "127.0.0.1", command: [ "run" ], config: "/etc/mongodb.conf", dbpath: "/var/lib/mongodb", fork: "true", journal: "true", logpath: "/var/log/mongodb/mongodb.log", nohttpinterface: "true", pidfilepath: "/var/run/mongodb/mongodb.pid", port: 27017, quiet: true } Wed Jan 8 14:41:58.800 [initandlisten] journal dir=/var/lib/mongodb/journal Wed Jan 8 14:41:58.800 [initandlisten] recover : no journal files present, no recovery needed Wed Jan 8 14:41:58.809 [initandlisten] waiting for connections on port 27017
I had this error too. Simply starting mongodb manually, then rerunning packstack --answer-file ... fixed it, so it didn't seem to have anything to do with disk space (and besides this is a physical server with gigabytes of free space).
There could be other causes that might let packstack fail the installation on the first round: 1) Slow internet connection 2) Package installation took more than 300 seconds to install (can be tuned with the parameter -t) 3) Some repository that was temporarily unavailable If one of those conditions is met, the result is that you need to re execute packstack with the answer file.
I'd assume that in any case we should let the user know what happened. Just failing without an error isn't good enough. Eg: - ERROR: Timeout while download foobar.tgz - ERROR: Timeout installing packages x, y and z
So, using smallfiles definitely helps with the original problem stated by Mohammed (eg. mongodb is not starting at all with not enough disk space ... I reproduced it and the patch fixed it for me), which means patch posted by Francesco fixes original issue. But still mongod did not start at first run when I then used patched packstack on clean VM. I had following in mongod.log: Wed Jan 22 07:25:54.222 [initandlisten] MongoDB starting : pid=21919 port=27017 dbpath=/var/lib/mongodb 64-bit host=localhost.localdomain Wed Jan 22 07:25:54.222 [initandlisten] db version v2.4.6 Wed Jan 22 07:25:54.222 [initandlisten] git version: nogitversion Wed Jan 22 07:25:54.222 [initandlisten] build info: Linux buildvm-12.phx2.fedoraproject.org 3.10.9-200.fc19.x86_64 #1 SMP Wed Aug 21 19:27:58 UTC 2013 x86_64 BOOST_LIB_VERSION=1_54 Wed Jan 22 07:25:54.222 [initandlisten] allocator: tcmalloc Wed Jan 22 07:25:54.222 [initandlisten] options: { bind_ip: "127.0.0.1", command: [ "run" ], config: "/etc/mongodb.conf", dbpath: "/var/lib/mongodb", fork: "true", journal: "true", logappend: "true", logpath: "/var/log/mongodb/mongodb.log", noauth: "true", pidfilepath: "/var/run/mongodb/mongodb.pid", port: 27017, quiet: true, smallfiles: "true" } Wed Jan 22 07:25:54.222 [initandlisten] Wed Jan 22 07:25:54.223 [initandlisten] ** WARNING: Readahead for /var/lib/mongodb is set to 4096KB Wed Jan 22 07:25:54.223 [initandlisten] ** We suggest setting it to 256KB (512 sectors) or less Wed Jan 22 07:25:54.223 [initandlisten] ** http://dochub.mongodb.org/core/readahead Wed Jan 22 07:25:55.511 [initandlisten] journal dir=/var/lib/mongodb/journal Wed Jan 22 07:25:55.512 [initandlisten] recover : no journal files present, no recovery needed Wed Jan 22 07:26:14.765 [initandlisten] preallocateIsFaster=true 300.7 Wed Jan 22 07:26:57.498 [initandlisten] preallocateIsFaster=true 443.82 Wed Jan 22 07:27:21.406 [initandlisten] preallocateIsFaster=true 278.24 Wed Jan 22 07:27:21.407 [initandlisten] preallocateIsFaster check took 85.894 secs Wed Jan 22 07:27:21.412 [initandlisten] preallocating a journal file /var/lib/mongodb/journal/prealloc.0 Wed Jan 22 07:27:30.690 [initandlisten] File Preallocator Progress: 104857600/134217728 78% Wed Jan 22 07:27:30.698 [signalProcessingThread] got signal 15 (Terminated), will terminate after current cmd ends Wed Jan 22 07:27:30.920 [signalProcessingThread] now exiting Wed Jan 22 07:27:36.331 dbexit: Wed Jan 22 07:27:36.331 [signalProcessingThread] shutdown: going to close listening sockets... Wed Jan 22 07:27:36.331 [signalProcessingThread] shutdown: going to flush diaglog... Wed Jan 22 07:27:36.331 [signalProcessingThread] shutdown: going to close sockets... Wed Jan 22 07:27:36.332 [signalProcessingThread] shutdown: waiting for fs preallocator... Wed Jan 22 07:27:36.332 [signalProcessingThread] shutdown: lock for final commit... Wed Jan 22 07:27:36.332 [signalProcessingThread] shutdown: final commit... Wed Jan 22 07:27:36.332 [signalProcessingThread] shutdown: closing all files... Wed Jan 22 07:27:36.334 [signalProcessingThread] closeAllFiles() finished Wed Jan 22 07:27:36.335 [signalProcessingThread] journalCleanup... Wed Jan 22 07:27:36.335 [signalProcessingThread] removeJournalFiles Wed Jan 22 07:27:37.003 [initandlisten] preallocating a journal file /var/lib/mongodb/journal/prealloc.1 Wed Jan 22 07:27:38.649 [signalProcessingThread] shutdown: removing fs lock... Wed Jan 22 07:27:42.672 [initandlisten] File Preallocator Progress: 52428800/134217728 39% Wed Jan 22 07:27:43.026 dbexit: really exiting now Eoghan, any hints what's wrong now? I have no idea what could happen that mongod was terminated by the signal 15
> Wed Jan 22 07:27:21.407 [initandlisten] preallocateIsFaster check took > 85.894 secs Default timeout on systemd for a service to start is 90 seconds. After that the service is killed with a SIGTERM. This is exactly what happens to me in bz#1040573
Thanks Gabriele!
(In reply to Gabriele Cerami from comment #24) > > Wed Jan 22 07:27:21.407 [initandlisten] preallocateIsFaster check took > > 85.894 secs > > Default timeout on systemd for a service to start is 90 seconds. After that > the service is killed with a SIGTERM. > This is exactly what happens to me in bz#1040573 FYI I encountered this problem when installing Open Stack on an Intel Xeon (baremetal) with 8GB of RAM and local hard disks, so I doubt it's anything to do with speed or virtualization (although 90s does seem a bit short).
The issue still exists on RHEL7. Can we patch the mongod.service file when running packstack? It is annoying that it is not possible to successfully run packstack on a virtual testing environment at the moment. --- /usr/lib/systemd/system/mongod.service.orig 2014-11-26 15:55:27.334642931 +0000 +++ /usr/lib/systemd/system/mongod.service 2014-11-26 15:55:36.959615632 +0000 @@ -10,6 +10,7 @@ ExecStart=/usr/bin/mongod $OPTIONS run PrivateTmp=true LimitNOFILE=64000 +TimeoutStartSec=240 [Install] WantedBy=multi-user.target
The timeout is not the issue. It looks like the PID file differs. The module puppetlabs-mongodb uses /var/run/mongodb/mongodb.pid by default, but at least RHEL uses /var/run/mongodb/mongod.pid in the unit file of systemd. Fedora uses /var/run/mongodb/mongodb.pid.
https://review.openstack.org/137440 fixes this issue for me.
This bug was accidentally moved from POST to MODIFIED via an error in automation, please see mmccune with any questions
So looks like this was fixed back in 2014. Can someone please close this?
Anyone can close bugs.
Hi Richard, (In reply to Richard W.M. Jones from comment #34) > Anyone can close bugs. Nope, otherwise I wouldn't have bothered you. Perhaps anyone @redhat.com can?
Possibly. You cannot change the "Status:" field?
(In reply to Richard W.M. Jones from comment #36) > Possibly. You cannot change the "Status:" field? You got it. I'm just reviewing old RDO bugs, trying to clear out the cruft and seeing if there are any I can help out with. I used to possibly have greater permissions when I helped out with the Fedora project as a packager but now I can do very little except NEEDINFO. If you, or someone you know, can change something to allow me to manipulate RDO category bugs, then great.