Migration tool throws Fatal error: Uncaught exception 'RequestException'

Discussion in 'Plugins/Modules/Addons' started by linus, Jan 7, 2021.

  1. linus

    linus Member

    The first migration attempt worked well, but at the resync it failed 10s of times (I restarted).
    When I reinstalled debian 10 at destination server from scratch with Ispconfig 3.2.2 I was able to run the migration successfully. But when I need to migrate the data again it again fails numerous times.

    Executing the latest migration tool on Debian 8. It breaks on different website processing every time. This is the ./migrate output:
    Code:
    ...
    Starting API calls.
    [158/158] <Client> processing customer.name (1123)
    [488/488] <Domain> processing sub.example.com
    [88/295] <Website> processing sub.example.com with autosub none
    Fatal error: Uncaught exception 'RequestException' with message 'cURL error: [52] Empty reply from server' in /root/migration/v56/includes/liburl.inc.php:237
    Stack trace:
    #0 /root/migration/v56/includes/importer.inc.php(398): Request:: post('https://remote...', '{"cron_id":{"pa...', true)
    #1 /root/migration/v56/includes/importer.inc.php(1169): ispconfig3_importer->api_call('sites_cron_get', Array)
    #2 /root/migration/v56/migrate.php(1770): ispconfig3_importer->storeWebDomain('4', Array, '', 88, 295)
    #3 {main}
      thrown in /root/migration/v56/includes/liburl.inc.php on line 237
    This is the migrate.log:
    Code:
    ...
    2021-01-07 07:04:29 - [INFO] Found 0 invoice sepa xml export entries.
    2021-01-07 07:04:33 - [INFO] Successfully executed command PHP=$(which php) && $PHP -r "print PHP_VERSION;"
    2021-01-07 07:04:43 - [INFO] Successfully executed command mysql -h 'localhost' -u 'root' -p'xxx' -e "SELECT VERSION();"
    2021-01-07 07:04:44 - [INFO] Successfully executed command mysql -h 'localhost' -u 'root' -p'xxx' -s -e "SELECT @@max_allowed_packet;"
    2021-01-07 07:04:44 - [INFO] Config file saved.
    2021-01-07 07:04:44 - [INFO] Directory /etc/letsencrypt exists.
    2021-01-07 07:04:45 - [INFO] Successfully executed command rsync --version 2>/dev/null
    2021-01-07 07:05:03 - [INFO] Rsync copy from /etc/letsencrypt/ to /etc/letsencrypt/ successful.
    This is the apache2/error.log at the destination:
    Code:
    ...
     2021-01-07 09:59:03.8705 11458/7f2dd0ae4700 Ser/Server.h:817 ]: [ServerThr.5] Freed 128 spare client objects
    [ 2021-01-07 09:59:03.8706 11458/7f2dd0ae4700 Ser/Server.h:464 ]: [ServerThr.5] Shutdown finished
    [ 2021-01-07 09:59:03.8708 11465/7f39bb060700 age/Ust/UstRouterMain.cpp:422 ]: Signal received. Gracefully shutting down... (send signal 2 more time(s) to force shutdown)
    [ 2021-01-07 09:59:03.8710 11465/7f39bb15f980 age/Ust/UstRouterMain.cpp:492 ]: Received command to shutdown gracefully. Waiting until all clients have disconnected...
    [ 2021-01-07 09:59:03.8715 11465/7f39ba7de700 Ser/Server.h:817 ]: [UstRouterApiServer] Freed 0 spare client objects
    [ 2021-01-07 09:59:03.8716 11465/7f39ba7de700 Ser/Server.h:464 ]: [UstRouterApiServer] Shutdown finished
    [ 2021-01-07 09:59:03.8718 11458/7f2d9bfff700 Ser/Server.h:817 ]: [ServerThr.6] Freed 128 spare client objects
    [ 2021-01-07 09:59:03.8719 11458/7f2d9bfff700 Ser/Server.h:464 ]: [ServerThr.6] Shutdown finished
    [ 2021-01-07 09:59:03.8719 11465/7f39bb060700 Ser/Server.h:464 ]: [UstRouter] Shutdown finished
    [ 2021-01-07 09:59:03.8730 11458/7f2d9b7fe700 Ser/Server.h:817 ]: [ServerThr.7] Freed 128 spare client objects
    [ 2021-01-07 09:59:03.8732 11458/7f2d9b7fe700 Ser/Server.h:464 ]: [ServerThr.7] Shutdown finished
    [ 2021-01-07 09:59:03.8741 11458/7f2d9affd700 Ser/Server.h:817 ]: [ServerThr.8] Freed 128 spare client objects
    [ 2021-01-07 09:59:03.8742 11458/7f2d9affd700 Ser/Server.h:464 ]: [ServerThr.8] Shutdown finished
    [ 2021-01-07 09:59:03.8755 11458/7f2d9a7fc700 Ser/Server.h:817 ]: [ApiServer] Freed 0 spare client objects
    [ 2021-01-07 09:59:03.8755 11458/7f2d9a7fc700 Ser/Server.h:464 ]: [ApiServer] Shutdown finished
    [ 2021-01-07 09:59:03.8758 11465/7f39bb15f980 age/Ust/UstRouterMain.cpp:523 ]: Passenger UstRouter shutdown finished
    [Thu Jan 07 09:59:03.894771 2021] [fcgid:emerg] [pid 11505] (22)Invalid argument: [client 84.248.221.26:61028] mod_fcgid: can't lock process table in pid 11505, referer: https://newserver:8080/index.php
    [Thu Jan 07 09:59:03.945939 2021] [fcgid:emerg] [pid 11497] (22)Invalid argument: [client 84.248.221.26:60880] mod_fcgid: can't lock process table in pid 11497, referer: https://newserver:8080/
    [ 2021-01-07 09:59:03.9757 11458/7f2dd37e1980 age/Cor/CoreMain.cpp:967 ]: Passenger core shutdown finished
    [Thu Jan 07 09:59:04.767803 2021] [fcgid:emerg] [pid 11496] (22)Invalid argument: [client clientip:38620] mod_fcgid: can't lock process table in pid 11496
    [ 2021-01-07 09:59:05.3177 12258/7f53b61dd980 age/Wat/WatchdogMain.cpp:1291 ]: Starting Passenger watchdog...
    [ 2021-01-07 09:59:05.3406 12261/7f4821b53980 age/Cor/CoreMain.cpp:982 ]: Starting Passenger core...
    [ 2021-01-07 09:59:05.3408 12261/7f4821b53980 age/Cor/CoreMain.cpp:235 ]: Passenger core running in multi-application mode.
    [ 2021-01-07 09:59:05.3767 12261/7f4821b53980 age/Cor/CoreMain.cpp:732 ]: Passenger core online, PID 12261
    [ 2021-01-07 09:59:05.4005 12269/7facbf092980 age/Ust/UstRouterMain.cpp:529 ]: Starting Passenger UstRouter...
    [ 2021-01-07 09:59:05.4035 12269/7facbf092980 age/Ust/UstRouterMain.cpp:342 ]: Passenger UstRouter online, PID 12269
    [Thu Jan 07 09:59:05.522975 2021] [ssl:warn] [pid 11452] AH01909: vxx:8080:0 server certificate does NOT include an ID which matches the server name
    [Thu Jan 07 09:59:05.523739 2021] [ssl:warn] [pid 11452] AH01909: xxt:8081:0 server certificate does NOT include an ID which matches the server name
    [Thu Jan 07 09:59:05.532184 2021] [mpm_prefork:notice] [pid 11452] AH00163: Apache/2.4.38 (Debian) mod_fcgid/2.3.9 Phusion_Passenger/5.0.30 OpenSSL/1.1.1i configured -- resuming normal operations
    [Thu Jan 07 09:59:05.532378 2021] [core:notice] [pid 11452] AH00094: Command line: '/usr/sbin/apache2'
    [Thu Jan 07 09:59:05.532499 2021] [mpm_prefork:warn] [pid 11452] AH00167: long lost child came home! (pid 11453)


    I have sent the support this issue, but I haven't been able to solve it by looking at the logs.
    Is this something that could be the cause?
    Code:
    [Thu Jan 07 09:59:04.767803 2021] [fcgid:emerg] [pid 11496] (22)Invalid argument: [client 185.35.513.17:38620] mod_fcgid: can't lock process table in pid 11496 

    I also tried to edit /root/migration/v56/includes/liburl.inc.php:237 to add some kind of fallback for the remote server's empty response or retry it, but I think it was coded in a way to prevent customization.
     
    Last edited: Jan 7, 2021
  2. Th0m

    Th0m ISPConfig Developer Staff Member ISPConfig Developer

  3. linus

    linus Member

    Thank you, yes, I've been in contact with the support the last few days, and I was adviced to review the logs, but I'm not able to come to any conclusions. I don't know what to and I was hoping if anyone here would be able to help. I would add a fallback in the script for the empty response, but I cant.

    Also, is there a way to run the migration with the latest answers instead of having to hit enter and fill the php options? The syncjobs does something, but is there a way to run all clients etc, a full run?

    Could it have to be a bad timing when the apache restarts every now and then?
     
  4. till

    till Super Moderator Staff Member ISPConfig Developer

    I doubt that this would really help as the import would be incomplete if you leave out items.

    No.

    Not very likely as this would mean that the same issue would happen on other systems as well, but that's not the case. Check your new server to ensure that it does not run out of memory during migration. If it runs out of memory, tra adding a swap partition or file.
     
  5. linus

    linus Member

    Thank you. Yes, it worked both the first times when I had installed the complete system, but not after resyncing.
    In htop I see the server's memory is used 2.88G / 29.4G. Could apache have been assigned too little memory by default? I have used servisys automatic installer successfully for years.
    Does the script retry at all? Is any kind of timeout limits too low?
    A minute ago it quit at the MailUser processing, after it had successfully gone through Client, domain, website, maildomain.

    This was the end of the destination's ispconfig log:
    Code:
    07.01.2021-12:57 - DEBUG - safe_exec cmd: chattr -i '/var/www/php-fcgi-scripts/web42/.php-fcgi-starter' - return code: 0
    07.01.2021-12:57 - DEBUG - Creating fastcgi starter script: /var/www/php-fcgi-scripts/web42/.php-fcgi-starter
    07.01.2021-12:57 - DEBUG - safe_exec cmd: chattr +i '/var/www/php-fcgi-scripts/web42/.php-fcgi-starter' - return code: 0
    07.01.2021-12:57 - DEBUG - Writing the vhost file: /etc/apache2/sites-available/site.com.vhost
    07.01.2021-12:57 - DEBUG - Processed datalog_id 13567
    07.01.2021-12:57 - DEBUG - Calling function 'restartHttpd' from module 'web_module'.
    07.01.2021-12:57 - DEBUG - Restarting httpd: systemctl reload apache2.service
    07.01.2021-12:57 - DEBUG - Remove Lock: /usr/local/ispconfig/server/temp/.ispconfig_lock
    
     
    Last edited: Jan 7, 2021
  6. Th0m

    Th0m ISPConfig Developer Staff Member ISPConfig Developer

    Just a note: There is a official autoinstaller that we maintain: https://git.ispconfig.org/ispconfig/ispconfig-autoinstaller
    The script from servisys works but also has some flaws and there is no active development as far as I can tell.

    Maybe your source server can't handle the load, or your internet connection is unstable?
     
  7. till

    till Super Moderator Staff Member ISPConfig Developer

    Or have you installed a webserver module like mod_evasive or a firewall that might block the connection when too many requests occur?
     
  8. linus

    linus Member

    Thank you for your answers. I opened up the iptables completely for the test's sake.
    I wasn't able to find evasive from the modules:

    Code:
     apache2ctl -t -D DUMP_MODULES
    AH00548: NameVirtualHost has no effect and will be removed in the next release /etc/apache2/sites-enabled/000-ispconfig.vhost:7
    Loaded Modules:
     core_module (static)
     so_module (static)
     watchdog_module (static)
     http_module (static)
     log_config_module (static)
     logio_module (static)
     version_module (static)
     unixd_module (static)
     access_compat_module (shared)
     actions_module (shared)
     alias_module (shared)
     auth_basic_module (shared)
     auth_digest_module (shared)
     authn_core_module (shared)
     authn_file_module (shared)
     authz_core_module (shared)
     authz_host_module (shared)
     authz_user_module (shared)
     autoindex_module (shared)
     cgi_module (shared)
     dav_module (shared)
     dav_fs_module (shared)
     deflate_module (shared)
     dir_module (shared)
     env_module (shared)
     fcgid_module (shared)
     filter_module (shared)
     headers_module (shared)
     include_module (shared)
     mime_module (shared)
     mpm_prefork_module (shared)
     negotiation_module (shared)
     passenger_module (shared)
     php7_module (shared)
     proxy_module (shared)
     proxy_fcgi_module (shared)
     reqtimeout_module (shared)
     rewrite_module (shared)
     setenvif_module (shared)
     socache_shmcb_module (shared)
     ssl_module (shared)
     status_module (shared)
     suexec_module (shared)
    
    It still failed :\

    Code:
    [273/295] <Website> processing domain.com with autosub www
    Fatal error: Uncaught exception 'RequestException' with message 'cURL error: [52] Empty reply from server' in /root/migration/v56/includes/liburl.inc.php:237
    Stack trace:
    #0 /root/migration/v56/includes/importer.inc.php(398): Request::post('https://server...', '{"client_id":"1...', true)
    #1 /root/migration/v56/includes/importer.inc.php(1159): ispconfig3_importer->api_call('sites_web_domai...', Array)
    #2 /root/migration/v56/migrate.php(1770): ispconfig3_importer->storeWebDomain('131', Array, '', 273, 295)
    #3 {main}
      thrown in /root/migration/v56/includes/liburl.inc.php on line 237
    
    I'm running htop in the destination and there's very little load. 0,35 with 8 cores and 3G/30G memory.
    The connection is open so I'm looking at both servers with putty.
     
  9. linus

    linus Member

    The excellent support sent me a migration script with a empty response retry fix and it's been working very well. Thank you for everyone's attention and help!
     
    rickconn and till like this.

Share This Page