Multicast not starting

[Tom Elliott]

@gerald.stachl Can you post the /opt/fog/log/multicast.log file?

[Tom Elliott]

I’ve added some code to more dynamically get the master interface so we don’t continue to have these issues (hopefully).

Basically, what my latest commit does, FOG will no longer need the Storage Node interface being set properly for our multicast tasks to operate. It will attempt to figure out which interface to use based on the host/ip of the storage node master. With any luck, this will mean no more of the lost udp sessions, though I can’t be 100% sure it won’t still cause issues. I’m relatively certain this change should help us with at least not losing the process that performs the tasking.

[gerald.stachl]

@Tom-Elliott
multicast.log:
12:02:27.250206 Using mcast address 234.2.0.26
12:02:27.250265 UDP sender for /opt/fog/.fogsettings at 10.2.0.26 on eth0
12:02:27.250284 Broadcasting control to 224.0.0.1
12:03:27.018433 Starting transfer: 00000009
12:03:27.039993 Doubling slice size to 162
12:03:27.043873 Doubling slice size to 202
12:03:27.062477 Transfer complete.
12:03:27.062513 Disconnecting #0 (10.2.2.88)
12:03:27.062522 Disconnecting #1 (10.2.2.152)
12:03:27.062531

the entries are from my tests with upd-sender on the console. There are not antries from mutlicast sesssions from fog.

I did the update via git - still same situation.

Where are the main config files now? /opt/fog/services/etc/config.php has only a definition of WEBROOT

[Wayne Workman]

@gerald.stachl Just a basic question here, you know that when you do a git pull to update your fog installation files, you then need to re-run the installer correct? You can run it like this: ./installfog.sh -y

[gerald.stachl]

@Wayne-Workman
Yes. After “git pull” i did
./bin/installfog.sh
passwd fog (i use a different PW for the fog user)

[Sebastian Roth]

Do you actually see the FOG services running on the server? ps ax | grep FOG?

[gerald.stachl]

@Sebastian-Roth
root@imaging:~#
ps ax|grep FOG
49456 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGImageReplicator/FOGImageReplicator
49467 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGSnapinReplicator/FOGSnapinReplicator
49478 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGTaskScheduler/FOGTaskScheduler
49489 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGPingHosts/FOGPingHosts
49760 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGMulticastManager/FOGMulticastManager
52203 ? Z 0:00 [FOGMulticastMan] <defunct>
52267 pts/0 S+ 0:00 grep FOG

i killed ps 52203 and then i rebooted the server. After that i got:

2271 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGImageReplicator/FOGImageReplicator
2324 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGMulticastManager/FOGMulticastManager
2382 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGPingHosts/FOGPingHosts
2411 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGTaskScheduler/FOGTaskScheduler
2441 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGSnapinReplicator/FOGSnapinReplicator
4428 ? Z 0:00 [FOGMulticastMan] <defunct>
4429 ? Z 0:00 [FOGImageReplica] <defunct>
4430 ? Z 0:00 [FOGPingHosts] <defunct>
4431 ? Z 0:00 [FOGTaskSchedule] <defunct>
4432 ? Z 0:00 [FOGSnapinReplic] <defunct>
4444 pts/0 S+ 0:00 grep FOG

sometimes the zombie processes disappear:
2271 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGImageReplicator/FOGImageReplicator
2324 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGMulticastManager/FOGMulticastManager
2382 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGPingHosts/FOGPingHosts
2411 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGTaskScheduler/FOGTaskScheduler
2441 ? S 0:00 /usr/bin/php -q /opt/fog/service/FOGSnapinReplicator/FOGSnapinReplicator
4868 pts/0 S+ 0:00 grep FOG

then they appear again.

On this server, unicast imaging works fine. I had some problems with the FOG Client - i had to change back to the legacy client, because the domain join didn’t work with the new client (but it worked some weeks ago - but this might be a different problem)

[Tom Elliott]

@gerald.stachl is the OS this is installed using systemd or sysvinit? If systemctl can you get output of systemctl -l status FOGMulticastManager? If sysvinit can you get any information from the Apache error logs?

[gerald.stachl]

@Tom-Elliott

Yes, there are a lot of error messages. 10.2.2.83 is the IP of the client i try to multicast. Seems that there are problems with DB connections? - (Correction: i saw, that these errors are from yesterday: maybe when i truncated the mysql multicast and tasks tables?)
-> fogcontroller.class.php on line 197 ??

[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::select_db(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 38
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::select_db(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 38
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::select_db(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 38
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::select_db(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 38
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::select_db(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 38
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::select_db(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 38
[Sat May 14 16:24:12 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::query(): Couldn’t fetch mysqli in /var/www/fog/lib/db/mysql.class.php on line 50
[Sat May 14 16:24:15 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::mysqli(): MySQL server has gone away in /var/www/fog/lib/db/mysql.class.php on line 25
[Sat May 14 16:24:15 2016] [error] [client 10.2.2.83] PHP Warning: mysqli::mysqli(): MySQL server has gone away in /var/www/fog/lib/db/mysql.class.php on line 28
[Sat May 14 16:24:16 2016] [notice] caught SIGTERM, shutting down
[Sat May 14 16:25:13 2016] [notice] Apache/2.2.22 (Debian) PHP/5.6.21-1~dotdeb+7.1 mod_ssl/2.2.22 OpenSSL/1.0.1e configured – resuming normal operations
[Sat May 14 16:25:25 2016] [error] [client 10.2.0.26] PHP Warning: Cannot modify header information - headers already sent by (output started at /var/www/fog/lib/fog/schema.class.php:46) in /var/www/fog/lib/fog/reportmaker.class.php on line 98
[Sat May 14 16:29:05 2016] [error] [client 10.1.1.10] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197, referer: http://10.2.0.26/fog/management/index.php?node=group&sub=deploy&id=6&type=8
[Sat May 14 16:29:05 2016] [error] [client 10.1.1.10] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197, referer: http://10.2.0.26/fog/management/index.php?node=group&sub=deploy&id=6&type=8
[Sat May 14 16:29:05 2016] [error] [client 10.1.1.10] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197, referer: http://10.2.0.26/fog/management/index.php?node=group&sub=deploy&id=6&type=8
[Sat May 14 16:29:49 2016] [error] [client 10.2.2.83] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197
[Sat May 14 16:29:59 2016] [error] [client 10.2.2.83] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197
[Sun May 15 06:39:39 2016] [notice] caught SIGTERM, shutting down
[Sun May 15 06:40:15 2016] [notice] Apache/2.2.22 (Debian) PHP/5.6.21-1~dotdeb+7.1 mod_ssl/2.2.22 OpenSSL/1.0.1e configured – resuming normal operations
[Sun May 15 06:45:08 2016] [error] [client 10.1.1.10] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197, referer: http://10.2.0.26/fog/management/index.php?node=group&sub=deploy&id=6&type=8
[Sun May 15 06:45:08 2016] [error] [client 10.1.1.10] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197, referer: http://10.2.0.26/fog/management/index.php?node=group&sub=deploy&id=6&type=8
[Sun May 15 06:45:08 2016] [error] [client 10.1.1.10] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197, referer: http://10.2.0.26/fog/management/index.php?node=group&sub=deploy&id=6&type=8

[gerald.stachl]

@Tom-Elliott
i just found something in syslog:

• not sure if this is correct. The errors above come from samba, because SAMBA4 is also installed on this server.

[Tom Elliott]

@gerald.stachl rpc is nfs. tftp is well, tftp. Can you update to the latest, again, please.

[gerald.stachl]

@Tom-Elliott
Did the Update (7701)

At the moment there is an error in management interface

[Tom Elliott]

@gerald.stachl Update again, but also do a hard refresh on the page.

[gerald.stachl]

@Tom-Elliott
Did both, the error on the task management page is gone, but still the same error when trying to start multicast.

[Sebastian Roth]

@gerald-stachl said:

same error when trying to start multicast

Which error? The ones you posted from the apache log don’t seem to be related to multicast!

[gerald.stachl]

@Sebastian-Roth
I mean, that multicast is not starting. In apache error log there are lines like “[client 10.2.2.83] PHP Warning: array_map(): An error occurred while invoking the map callback in /var/www/fog/lib/fog/fogcontroller.class.php on line 197”
There is another thread with similar error in logs:
https://forums.fogproject.org/topic/7412/problems-with-multicast-task/23

[Sebastian Roth]

@gerald-stachl Ok, thanks for clarifying! I am calling @Tom-Elliott as I refuse to try to debug this kind of code (nested array_map calls). Sorry Tom, but this will be all yours…

[Tom Elliott]

@Sebastian-Roth Error throwing is due to array_map not being able to handle “throw new” from within. I’ve adjusted all functional programming within the fogcontroller.class.php file to array_walk in hopes to fix the issue. I don’t know if it will fix the “mutlicast not starting” issue.

[gerald.stachl]

@Tom-Elliott
The array_map() errors are gone now, but multicast is still not starting:

I can’t find any errors in apache logs now. I also wonder, why there is no multicast.log file? (i had a file, but this file was created during test with udp-sender on the console)
I cleared the folder /opt/fog/log and ran the installer again. After that the Service Master Logfile is created new, but all the other logfiles don’t exist:

in the Service Master Log i can see:
[05-19-16 4:40:11 am] FOGPingHosts child process (27579) exited with code 255.
[05-19-16 4:40:09 am] FOGTaskScheduler child process (27578) exited with code 255.
[05-19-16 4:40:07 am] FOGImageReplicator child process (27577) exited with code 255.
[05-19-16 4:40:05 am] FOGImageReplicator child process (27576) exited with code 255.
[05-19-16 4:40:03 am] FOGMulticastManager child process (27575) exited with code 255.

(is that OK?) - The timezone in the logfiles seems to be UTC, even if i correct the timezone settings in php.ini. The system time (date) also shows the correct time.

Any other debug options i could use?

[Sebastian Roth]

@gerald.stachl said in Multicast not starting:

exited with code 255.

Definitely does not sound too good. As well you should have other logs. Is this Ubuntu? Did you restart the whole system? There is a known issue with the services starting too early before the mysql DB is properly up. Please read Tom’s great post about this here: https://forums.fogproject.org/topic/3081/fog-1-1-0-multicast-sits-at-starting-to-restore-image-to-device-dev-sda1/78