Kernel Update fails ... Oh no, not again!

[george1421]

@sebastian-roth FWIW I did get the same thing on my product server 1.4.4, in my case I attributed it to my fog server not having direct internet access. Then I did some stuff and it downloaded a 0 byte file for bzImage so I just updated it by hand. I did ensure that the linux user fog had access to the ipxe directory. I was going to play a bit this weekend to see if I could figure something else.

[Sebastian Roth]

@jstephen @george1421 @sudburr Can you all please try the following by hand:

shell> sudo cp /var/www/fog/service/ipxe/bzImage /var/www/fog/service/ipxe/testfile
shell> sudo chown fog:apache /var/www/fog/service/ipxe/testfile
shell> sudo chmod 644 var/www/fog/service/ipxe/testfile
shell> sudo apt-get install ftp
shell> ftp
ftp> open 127.0.0.1
Connected to 127.0.0.1.
220 (vsFTPd 3.0.3)
Name (127.0.0.1:roth): fog
331 Please specify the password.
Password:
230 Login successful.
Remote system type is UNIX.
Using binary mode to transfer files.
ftp> pwd
257 "/home/fog" is the current directory
ftp> mkdir /var/www/fog/service/ipxe/backup
257 "/var/www/fog/service/ipxe/backup" created
ftp> rename /var/www/fog/service/ipxe/testfile /var/www/fog/service/ipxe/backup/testfile
350 Ready for RNTO.
250 Rename successful.
ftp> quit

[george1421]

@sebastian-roth

Auto update via fog-gui works on FOG-Pi server (raspbian) that has direct internet access.

Production fog server does not work even after making sure directory permissions are set. bzImage created by zero bytes.

The create directory failed when executing on production server. The backup directory already existed. Peeking inside it has content.

reviewing the apache error log netted this info.

[Sat Feb 03 08:28:25.466950 2018] [:error] [pid 21617:tid 139862824957696] [client 10.96.151.50:62795] PHP Warning:  ftp_mkdir(): Create directory operation failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 492, referer: http://192.168.1.53/fog/management/index.php?node=about&sub=kernel&file=aHR0cHM6Ly9mb2dwcm9qZWN0Lm9yZy9rZXJuZWxzL0tlcm5lbC5Ub21FbGxpb3R0LjQuMTMuNC42NA==&arch=64
[Sat Feb 03 08:28:25.475420 2018] [:error] [pid 21617:tid 139862824957696] [client 10.96.151.50:62795] PHP Warning:  ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 769, referer: http://192.168.1.53/fog/management/index.php?node=about&sub=kernel&file=aHR0cHM6Ly9mb2dwcm9qZWN0Lm9yZy9rZXJuZWxzL0tlcm5lbC5Ub21FbGxpb3R0LjQuMTMuNC42NA==&arch=64

The backup directory now contains

-rwxr-xr-x 1 fog fog    0 Feb  3 08:10 bzImage_20180203_082824

The ipxe directory now contains

-rwxr-xr-x 1 fog  fog         0 Feb  3 08:28 bzImage

Now may issue may be that the production fog server doesn’t have direct internet access but must pass through a proxy server.

Observations executing the script.

1. Of course kernel updates on raspbian.
2. On raspbian the ower of the file is fog:www-data not fog:apache that may cause problems for others executing the script based on the FOG server’s OS.
3. On raspbian /var/www/fog/service/ipxe is correct on centos the correct path is /var/www/html/fog/service/ipxe.
4. With corrections the script executed correctly on both raspbian and centos.

[Sebastian Roth]

@george1421 said in Kernel Update fails ... Oh no, not again!:

Now may issue may be that the production fog server doesn’t have direct internet access but must pass through a proxy server.

But the code should actually use proxy settings made in the web UI (code ref) so I am wondering what goes wrong here as it does not seem to return 4xx HTTP code and therefore the kernel update page does not notice something went wrong. Do you have access to the proxy logs?

On the other hand I wondered about the zero bytes file size as there is a check in the code. Unfortunately there was an issue with the file size check which I just fixed in the current working branch (ref).

... ftp_mkdir(): Create directory operation failed...

As well I wonder about why you all see this. There is a check before mkdir that should prevent from trying so if the directory already exists. From my point of view that should work correctly.

On raspbian /var/www/fog/service/ipxe is correct on centos the correct path is /var/www/html/fog/service/ipxe.

Thanks for pointing that out. I should have made my test commands not specific to debian/ubuntu without mentioning.

[sudburr]

@sebastian-roth sestatus results

SELinux status:                 enabled
SELinuxfs mount:                /sys/fs/selinux
SELinux root directory:         /etc/selinux
Loaded policy name:             targeted
Current mode:                   permissive
Mode from config file:          permissive
Policy MLS status:              enabled
Policy deny_unknown status:     allowed
Max kernel policy version:      28

This is the same as on all of our other fog servers.

[sudburr]

@sebastian-roth said in Kernel Update fails ... Oh no, not again!:

rename /var/www/fog/service/ipxe/testfile /var/www/fog/service/ipxe/backup/testfile

Completed the ftp steps detailed and update via GUI continues to fail.

[george1421]

@sudburr if selinux is enabled, then you will have issues capturing images for sure. You need to configure selinux to permissive. On centos its in /etc/selinux and there is a config file in there you need to edit so it says permissive. Then reboot your FOG server.

# This file controls the state of SELinux on the system.
# SELINUX= can take one of these three values:
#     enforcing - SELinux security policy is enforced.
#     permissive - SELinux prints warnings instead of enforcing.
#     disabled - No SELinux policy is loaded.
SELINUX=permissive
# SELINUXTYPE= can take one of three two values:
#     targeted - Targeted processes are protected,
#     minimum - Modification of targeted policy. Only selected processes are protected.
#     mls - Multi Level Security protection.
SELINUXTYPE=targeted

[sudburr]

SELinux is already configured and functions properly for all servers. Imaging is not the problem. The problem is updating the kernel on 2 of 18 physical servers.

[jstephen]

@sebastian-roth Following your steps, I get this:

ftp> mkdir /var/www/fog/service/ipxe/backup
550 Create directory operation failed.

It seems that I am able to rename the files though.

I also notice that all of the other files in the ipxe folder are owned by fog:www-data; however, the files the Fog is trying to create for the new kernel are owned by fog:fog. Could this be part of the problem?

One more observation: the fog GUI is reporting that the operation failed to ftp_mkdir and ftp_rename, however the file exists in the ipxe directory and has 8069680 bytes which is probably about right, right? Is the file being copied elsewhere also and failing there? Or, is the GUI error… in error?

[Sebastian Roth]

@sudburr said in Kernel Update fails ... Oh no, not again!:

Completed the ftp steps detailed and update via GUI continues to fail.

Can you please post a listing or picture of the commands and output?

@jstephen said:

ftp> mkdir /var/www/fog/service/ipxe/backup
550 Create directory operation failed.

This might be due to the fact that the directory already exists. See with ls -al /var/www/fog/service/ipxe on the command line.

[sudburr]

@sebastian-roth Aside from changing your

chmod 644 var/www/fog/service/ipxe/testfile

to

chmod 644 /var/www/fog/service/ipxe/testfile

The commands and results were word for word identical to what you posted.

[Sebastian Roth]

@sudburr Are you behind a proxy server by any chance? Do you still see the very same ftp_* messages in the apache error log?

[sudburr]

@sebastian-roth No proxy server. The error message has changed one one server at /var/log/httpd/error_log.

PHP Warning:  ftp_login(): Login incorrect. in /var/www/html/fog/lib/fog/fogftp.class.php on line 463, referer: http://xyzfog/fog/management/index.php?node=about&sub=kernel&file=aHR0cHM6Ly9mb2dwcm9qZWN0Lm9yZy9rZXJuZWxzL0tlcm5lbC5Ub21FbGxpb3R0LjQuMTMuNC42NA==&arch=64

The value for “Fog Configuration / Fog Settings / TFTP Server / FOG_TFTP_FTP_PASSWORD” changed. It now does not match the password as found in “/opt/fog/.fogsettings” or “Storage Management / Management Password”. I changed it to match, then ran the kernel update again and it worked!

The other server has exhibited no change in errors or passwords.

[Wayne Workman]

Cross-linking these threads as I think they are related.

https://forums.fogproject.org/topic/11375/kernel-update-fails-oh-no-not-again
https://forums.fogproject.org/topic/11409/newer-to-fog-need-a-little-assistance

[Sebastian Roth]

@sudburr said in Kernel Update fails ... Oh no, not again!:

I changed it to match, then ran the kernel update again and it worked!

Kind of weird. Well, good to know it works now. Marking as solved.

[sudburr]

@sebastian-roth It’s solved for one server, but not the other.

[sudburr]

Something to look at from the FTP logs.

Wed Feb  7 12:37:04 2018 [pid 15591] CONNECT: Client "<FOGIP>"
Wed Feb  7 12:37:04 2018 [pid 15591] FTP response: Client "<FOGIP>", "220 (vsFTPd 3.0.2)"
Wed Feb  7 12:37:05 2018 [pid 15591] FTP command: Client "<FOGIP>", "USER fog"
Wed Feb  7 12:37:05 2018 [pid 15591] [fog] FTP response: Client "<FOGIP>", "331 Please specify the password."
Wed Feb  7 12:37:05 2018 [pid 15591] [fog] FTP command: Client "<FOGIP>", "PASS <password>"
Wed Feb  7 12:37:05 2018 [pid 15590] [fog] OK LOGIN: Client "<FOGIP>"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "230 Login successful."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "PASV"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "227 Entering Passive Mode (<FOGIP>,209,195)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "TYPE A"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "200 Switching to ASCII mode."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "LIST -a //var/www/html/fogservice/ipxe"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "150 Here comes the directory listing."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "226 Transfer done (but failed to open directory)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "MKD //var/www/html/fogservice/ipxe/backup/"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "550 Create directory operation failed."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FAIL MKDIR: Client "<FOGIP>", "//var/www/html/fo[Wed Feb 07 12:37:05.182303 2018] [:error] [pid 1410] [client <CLIENT_IP>:45345] PHP Warning:  ftp_mkdir(): Create directory operation failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 492, referer: http://xyzfog/fog/management/index.php?node=about&sub=kernel&file=aHR0cHM6Ly9mb2dwcm9qZWN0Lm9yZy9rZXJuZWxzL0tlcm5lbC5Ub21FbGxpb3R0LjQuMTMuNC42NA==&arch=64
gservice/ipxe/backup/"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "PASV"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "227 Entering Passive Mode (<FOGIP>,96,38)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "LIST -a /var/www/html/fogservice/ipxe"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "150 Here comes the directory listing."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "226 Transfer done (but failed to open directory)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "PASV"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "227 Entering Passive Mode (<FOGIP>,232,42)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "LIST -a /var/www/html/fogservice/ipxe"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "150 Here comes the directory listing."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "226 Transfer done (but failed to open directory)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "RNFR /tmp/bzImage"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "550 RNFR command failed."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FAIL RENAME: Client "<FOGIP>", "/tmp/bzImage"
[Wed Feb 07 12:37:05.184327 2018] [:error] [pid 1410] [client <CLIENT_IP>:45345] PHP Warning:  ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 769, referer: http://xyzfog/fog/management/index.php?node=about&sub=kernel&file=aHR0cHM6Ly9mb2dwcm9qZWN0Lm9yZy9rZXJuZWxzL0tlcm5lbC5Ub21FbGxpb3R0LjQuMTMuNC42NA==&arch=64
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "TYPE I"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "200 Switching to Binary mode."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "PASV"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "227 Entering Passive Mode (<FOGIP>,47,255)."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "STOR /var/www/html/fogservice/ipxe/bzImage"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "553 Could not create file."
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FAIL UPLOAD: Client "<FOGIP>", "/var/www/html/fogservice/ipxe/bzImage", 0.00Kbyte/sec
[Wed Feb 07 12:37:05.185077 2018] [:error] [pid 1410] [client <CLIENT_IP>:45345] PHP Warning:  ftp_put(): Could not create file. in /var/www/html/fog/lib/fog/fogftp.class.php on line 707, referer: http://xyzfog/fog/management/index.php?node=about&sub=kernel&file=aHR0cHM6Ly9mb2dwcm9qZWN0Lm9yZy9rZXJuZWxzL0tlcm5lbC5Ub21FbGxpb3R0LjQuMTMuNC42NA==&arch=64
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP command: Client "<FOGIP>", "QUIT"
Wed Feb  7 12:37:05 2018 [pid 15595] [fog] FTP response: Client "<FOGIP>", "221 Goodbye."

[Sebastian Roth]

@sudburr Great log file you posted. See the path is /var/www/html/fogservice/ipxe and I reckon there is a slash missing. Check TFTP_PXE_KERNEL_DIR in the FOG web UI -> FOG Configuration -> FOG Settings -> TFTP Server - should be /var/www/html/fog/service/ipxe/

[sudburr]

@sebastian-roth That did the trick! That server can now update its kernel.

It’s interesting to see how two different causes have similar results.