Capture Task Complete, Updating Database... 504 Gateway timeout
-
Hi everyone! I’m having some problem on a new installation of FOG 1.5.9 on a laptop with Fedora 25 (only distribution and version we could make it work!)
This laptop runs FOG DHCP server and starts PXE on other PCs/laptops on a separate lan. We are trying to test capturing an image from this laptop. Everything goes smoothly until it says “Updating Database…”, then it hangs for almost a minute then shows this error message:
Just as this error message is shown, files at “/images/dev/(laptop_mac_address)” disappear. They’re just gone!
Please, can anybody shine some light at what it may be happening? We tried everything from access rights to invalid credentials. Even dropping database did not help.
If anybody needs some other logs, just say so and we’ll provide.
Thanks!
-
@billvgn That error message means that php-fpm did not respond back to apache in a timely manner.
Lets look at the both the apache and php-fpm error logs in the /var/logs directory. I don’t know fedora so I can’t give you the exact location. But the error logs might give us a clue to why its doing that.
-
php-fpm/www-error.log
[26-Jul-2022 00:46:04 UTC] PHP Warning: ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 809 [26-Jul-2022 00:46:04 UTC] PHP Warning: ftp_put(/images/dev/c89cdcde0691): failed to open stream: No such file or directory in /var/www/html/fog/lib/fog/fogftp.class.php on line 709 [26-Jul-2022 19:29:14 UTC] PHP Warning: ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 809 [26-Jul-2022 19:29:14 UTC] PHP Warning: ftp_put(/images/dev/a01d48f49524): failed to open stream: No such file or directory in /var/www/html/fog/lib/fog/fogftp.class.php on line 709 [26-Jul-2022 20:20:17 UTC] PHP Warning: ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 809 [26-Jul-2022 20:20:17 UTC] PHP Warning: ftp_put(/images/dev/a01d48f49524): failed to open stream: No such file or directory in /var/www/html/fog/lib/fog/fogftp.class.php on line 709 [26-Jul-2022 20:58:01 UTC] PHP Warning: Invalid argument supplied for foreach() in /var/www/html/fog/status/mainversion.php on line 36 [26-Jul-2022 21:44:11 UTC] PHP Warning: ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 809 [26-Jul-2022 21:44:11 UTC] PHP Warning: ftp_put(/images/dev/a01d48f49524): failed to open stream: No such file or directory in /var/www/html/fog/lib/fog/fogftp.class.php on line 709 [26-Jul-2022 23:06:28 UTC] PHP Parse error: syntax error, unexpected 'var' (T_VAR) in /var/www/html/fog/lib/fog/config.class.php on line 84 [26-Jul-2022 23:13:06 UTC] PHP Warning: Invalid argument supplied for foreach() in /var/www/html/fog/lib/fog/fogpage.class.php on line 2677 [26-Jul-2022 23:49:55 UTC] PHP Warning: ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 809 [26-Jul-2022 23:49:55 UTC] PHP Warning: ftp_put(/images/dev/a01d48f49524): failed to open stream: No such file or directory in /var/www/html/fog/lib/fog/fogftp.class.php on line 709 [27-Jul-2022 21:15:43 UTC] PHP Warning: ftp_rename(): RNFR command failed. in /var/www/html/fog/lib/fog/fogftp.class.php on line 809 [27-Jul-2022 21:15:43 UTC] PHP Warning: ftp_put(/images/dev/a01d48f49524): failed to open stream: No such file or directory in /var/www/html/fog/lib/fog/fogftp.class.php on line 709php-fpm/error.log
[27-Jul-2022 01:29:23] NOTICE: [pool www] child 8414 started [27-Jul-2022 01:29:58] NOTICE: [pool www] child 805 exited with code 0 after 63588.540390 seconds from start [27-Jul-2022 01:29:58] NOTICE: [pool www] child 8487 started [27-Jul-2022 01:30:43] NOTICE: [pool www] child 900 exited with code 0 after 63568.553179 seconds from start [27-Jul-2022 01:30:43] NOTICE: [pool www] child 8530 started [27-Jul-2022 01:33:43] NOTICE: [pool www] child 1054 exited with code 0 after 63613.545195 seconds from start [27-Jul-2022 01:33:43] NOTICE: [pool www] child 8713 started [27-Jul-2022 06:06:43] NOTICE: [pool www] child 16820 exited with code 0 after 65443.546035 seconds from start [27-Jul-2022 06:06:43] NOTICE: [pool www] child 26215 started [27-Jul-2022 17:25:50] NOTICE: Terminating ... [27-Jul-2022 17:25:50] NOTICE: exiting, bye-bye! [27-Jul-2022 17:26:02] NOTICE: fpm is running, pid 7174 [27-Jul-2022 17:26:02] NOTICE: ready to handle connections [27-Jul-2022 17:26:02] NOTICE: systemd monitor interval set to 10000mshttpd/error_log
[Wed Jul 27 17:26:02.950622 2022] [mpm_prefork:notice] [pid 7173] AH00163: Apache/2.4.27 (Fedora) OpenSSL/1.0.2m-fips PHP/7.0.25 configured -- resuming normal operations [Wed Jul 27 17:26:02.950649 2022] [core:notice] [pid 7173] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND' [Wed Jul 27 17:33:41.943172 2022] [mpm_prefork:notice] [pid 7173] AH00170: caught SIGWINCH, shutting down gracefully [Wed Jul 27 17:33:50.639189 2022] [suexec:notice] [pid 11190] AH01232: suEXEC mechanism enabled (wrapper: /usr/sbin/suexec) [Wed Jul 27 17:33:50.659741 2022] [lbmethod_heartbeat:notice] [pid 11190] AH02282: No slotmem from mod_heartmonitor [Wed Jul 27 17:33:50.660197 2022] [http2:warn] [pid 11190] AH10034: The mpm module (prefork.c) is not supported by mod_http2. The mpm determines how things are processed in your server. HTTP/2 has more demands in this regard and the currently selected mpm will just not do. This is an advisory warning. Your server will continue to work, but the HTTP/2 protocol will be inactive. [Wed Jul 27 17:33:50.675581 2022] [mpm_prefork:notice] [pid 11190] AH00163: Apache/2.4.27 (Fedora) OpenSSL/1.0.2m-fips PHP/7.0.25 configured -- resuming normal operations [Wed Jul 27 17:33:50.675611 2022] [core:notice] [pid 11190] AH00094: Command line: '/usr/sbin/httpd -D FOREGROUND' [Wed Jul 27 18:14:29.976958 2022] [proxy_fcgi:error] [pid 11233] (70007)The timeout specified has expired: [client 10.2.108.193:41330] AH01075: Error dispatching request to : (polling) [Wed Jul 27 18:15:30.042077 2022] [proxy_fcgi:error] [pid 11264] (70007)The timeout specified has expired: [client 10.2.108.193:41332] AH01075: Error dispatching request to : (polling) -
@billvgn said in Capture Task Complete, Updating Database... 504 Gateway timeout:
php-fpm/www-error.log
OK this is the important error file. Its telling us where it fails.
So where FOG is at the moment is it has captured and transferred the image file to /images/dev/<mac_address> on the fog server. Then the fos engine (running on the target computer) connects to the FOG server over ftp and instructs the fog server to move the image file from
/images/dev/<mac_address>to/images/<image_name>This is the step where its failing. The fog server is saying it can’t find/images/dev/<mac_address>So lets run these commands.
ls -la /images/devThere should be some directories in there that look like mac addresses.
ls -la /imagesLets check to see if the file permissions are right.and finally lets look at
df -hto see what the disk structure looks like. There is something unexpected going on with your configuration. -
[dev]$ ls -la total 0 drwxrwxrwx. 3 fogproject root 46 jul 27 18:38 . drwxrwxrwx. 4 fogproject root 61 jul 27 18:39 .. -rwxrwxrwx. 1 fogproject root 0 jul 21 14:12 .mntcheck drwxrwxrwx. 2 fogproject root 26 jul 21 14:12 postinitscripts [images]$ ls -la total 4 drwxrwxrwx. 4 fogproject root 61 jul 27 18:39 . dr-xr-xr-x. 20 root root 4096 jul 27 17:34 .. drwxrwxrwx. 3 fogproject root 46 jul 27 18:38 dev -rwxrwxrwx. 1 fogproject root 0 jul 21 14:12 .mntcheck drwxrwxrwx. 2 fogproject root 30 jul 21 14:12 postdownloadscripts [images]$ df -h File System Size Used Avail. Usage% Mounted on devtmpfs 7,8G 0 7,8G 0% /dev tmpfs 7,8G 41M 7,8G 1% /dev/shm tmpfs 7,8G 1,8M 7,8G 1% /run tmpfs 7,8G 0 7,8G 0% /sys/fs/cgroup /dev/sda2 20G 5,5G 15G 28% / tmpfs 7,8G 2,1M 7,8G 1% /tmp /dev/sda1 976M 130M 780M 15% /boot /dev/sda5 895G 945M 894G 1% /images tmpfs 1,6G 52K 1,6G 1% /run/user/1000 /dev/sr0 1,9G 1,9G 0 100% /run/media/willian/Fedora-S-dvd-x86_64-25 tmpfs 1,6G 0 1,6G 0% /run/user/0 -
@george1421 The problem is: why da heck are those files getting deleted before any renaming or moving could happen?!
Yes, they really exist at some time period. Just before client gets stuck at “updating database…”
After that it’s just the same. Task gets “completed”, it is removed from active tasks on FOG server web interface. Then it retries to update database but task no longer exists, so it just fails…
-
^^^ Bump
UPDATES: I updated kernel image to latest (5.15.34 version bzimage and bzimage32 files) from github repository manually as automatic seems to be disabled per web interface warning message.
I updated mysql’s my.cnf with “bind-address” option. It didn’t have before so I added and set it to my servers IP. Did some successful remote connections to test if “updating database” failed because of it. Although it still fails as usual.
Can somebody point me to where on source files is “Updating Database…” being echoed so I can start my search for this error and what might be causing it?
Thanks!
-
@billvgn I’m trying to figure out the best way to debug this, because what is happening, shouldn’t be.
Is the issue with any model computer or only one specific model?
If we do a debug capture we might be able to catch it in the act of misbehaving.
Lets schedule another capture task, but before you hit the schedule task button, tick the debug checkbox.
Now pxe boot the target computer
after a few screens of text you will be dropped to the fos linux command prompt.
key infogto start single stepping through the image capture.
keep pressing enter until after the first partition is captured by FOG.At this point we should inspect the FOG server. In the /images/dev directory there should (better) be a directory with the name that appears like a mac address. Change into that directory and see if it has files. Right now don’t care how many file it has, only ensure that d1p1.img exists. It should be small since its just the efi boot partition. If its ok change up one directory, don’t stay in the capture directory or the capture will fail later at updating the database like you have.
now back on the target computer. If this is a standard windows image capture there should be 4 partitions, where the 3rd will be the largest and the 4th will be relative small since its just the recovery partition. Keep pressing enter until the 4th partclone upload is computer. Don’t press enter, but inspect the directory again make sure it has files / content but don’t go into that directory. The very next step should be the target computer will connect to the fog server using ftp and move the directory from /images/dev/<mac_address> to /images/<image_name>
Step by step single step through the capture while watching that /images/dev directory. That directory should disappear, but reappear in /images directory as the image name.
Somewhere in here its failing. Watch for an error message on the target computer.
-
Sorry to resurrect an old thread. I ran into this issue today and have found a resolution (at least in my case).
I had an image that was quite old that I wanted to update. The client I wanted to image was from a completely different system (a VM). I cloned over top the existing image with the VM. I got the same exact 504 error and it would eventually fail to update the database.
I created a new image in fog and assigned the new host that new image. Went through flawlessly.
It’s weird because I’ve done this in the past on multiple occasions and never had an issue. It was more than likely I created the older image (that I was just trying to clone over) on v1.5.9. I did update to v1.5.10 a couple months ago.
So if you have this same problem, try creating a new image if overwriting an old image fails with the 504 error.
