Scan doesn’t start, or stops after seeming random time

  • Resolved CGS Web Designs

    (@cgscomputers)


    2 years, 4 months ago

    I’m having an issue where scans are frequently never starting, or they stopping partially the way through. It seems to be different every time. I’ve been using Wordfence for years on this host with 30+ sites and never had this issue before, over the past month, I see it on multiple sites (not all) and the behavior is very intermittent.

    • I’ve ensured there is proper memory available
    • whitelisted server IP in Cloudflare (pausing Cloudflare entirely does not help – so that’s not the issue anyway)
    • Set the max execution time for each scan step to 20 and again at 30 (my php max is 90)
    • All diagnostic tests read fine

      • Under debugging mode, there is no indication of failure – it just stops (marked cronkeys as REDACTED):

      [Jul 24 09:41:59] Forking during malware scan (4) to ensure continuity.
[Jul 24 09:41:59] Entered fork()
[Jul 24 09:41:59] Calling startScan(true)
[Jul 24 09:41:59] Got value from wf config maxExecutionTime: 30
[Jul 24 09:41:59] getMaxExecutionTime() returning config value: 30
[Jul 24 09:41:59] Test result of scan start URL fetch: array ( 'headers' => Requests_Utility_CaseInsensitiveDictionary::__set_state(array( 'data' => array ( 'date' => 'Sun, 24 Jul 2022 13:41:59 GMT', 'content-type' => 'text/html; charset=UTF-8', 'x-robots-tag' => 'noindex', 'x-content-type-options' => 'nosniff', 'expires' => 'Wed, 11 Jan 1984 05:00:00 GMT', 'cache-control' => 'no-cache, must-revalidate, max-age=0', 'referrer-policy' => 'strict-origin-when-cross-origin', 'x-frame-options' => 'SAMEORIGIN', 'x-litespeed-cache-control' => 'no-cache', 'vary' => 'Accept-Encoding', 'x-turbo-charged-by' => 'LiteSpeed', 'cf-cache-status' => 'DYNAMIC', 'expect-ct' => 'max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"', 'report-to' => '{"endpoints":[{"url":"https:\\/\\/a.nel.cloudflare.com\\/report\\/v3?s=MIeKFwSW4dN0rnllSRj2AVDYibxEQw6OW82WqlpvfMNVN5Iccmp8Qi7gRE0Q9w%2BBkrjOzB8AA
[Jul 24 09:41:59] Starting cron with normal ajax at URL https://cgscomputer.com/wp-admin/admin-ajax.php?action=wordfence_doScan&isFork=1&scanMode=custom&cronKey=REDACTED
[Jul 24 09:42:00] Scan engine received request.
[Jul 24 09:42:00] Verifying start request signature.
[Jul 24 09:42:00] Fetching stored cronkey for comparison.
[Jul 24 09:42:00] Checking cronkey: REDACTED (expecting REDACTED)
[Jul 24 09:42:00] Checking saved cronkey against cronkey param
[Jul 24 09:42:00] Requesting max memory
[Jul 24 09:42:00] Setting up error handling environment
[Jul 24 09:42:00] Setting up scanRunning and starting scan
[Jul 24 09:42:00] Got a true deserialized value back from 'wfsd_engine' with type: object
[Jul 24 09:42:00] Scanning contents: wp-content/plugins/updraftplus/vendor/paragonie/random_compat/lib/byte_safe_strings.php (Size: 6.17 KB Mem: 28 MB)
[Jul 24 09:42:00] Resuming malware scan at rule 4.
[Jul 24 09:42:00] Scan process ended after forking.
[Jul 24 09:42:00] Scanned contents of 9062 additional files at 37.61 per second
[Jul 24 09:42:00] Scanning contents: wp-content/plugins/updraftplus/vendor/paragonie/random_compat/lib/cast_to_int.php (Size: 2.66 KB Mem: 30 MB)
[Jul 24 09:42:00] Scanning contents: wp-content/plugins/updraftplus/vendor/paragonie/random_compat/lib/error_polyfill.php (Size: 1.62 KB Mem: 28 MB)
[Jul 24 09:42:00] Scanning contents: wp-content/plugins/updraftplus/vendor/paragonie/random_compat/lib/random.php (Size: 7.79 KB Mem: 28 MB)
[Jul 24 09:42:01] Scanning contents: wp-content/plugins/updraftplus/vendor/paragonie/random_compat/lib/random_bytes_com_dotnet.php (Size: 2.94 KB Mem: 30 MB)
[Jul 24 09:42:01] Scanning contents: wp-content/plugins/updraftplus/vendor/paragonie/random_compat/lib/random_bytes_dev_urandom.php (Size: 6.3 KB Mem: 28 MB)

      In situations where the scan never even starts the log looks like this (marked cronkeys as REDACTED):

      [Jul 24 09:53:43] Calling Wordfence API v2.26:https://noc1.wordfence.com/stats.json
[Jul 24 09:53:48] Ajax request received to start scan.
[Jul 24 09:53:48] Entering start scan routine
[Jul 24 09:53:48] Got value from wf config maxExecutionTime: 30
[Jul 24 09:53:48] getMaxExecutionTime() returning config value: 30
[Jul 24 09:53:48] Test result of scan start URL fetch: array ( 'headers' => Requests_Utility_CaseInsensitiveDictionary::__set_state(array( 'data' => array ( 'date' => 'Sun, 24 Jul 2022 13:53:48 GMT', 'content-type' => 'text/html; charset=UTF-8', 'x-robots-tag' => 'noindex', 'x-content-type-options' => 'nosniff', 'expires' => 'Wed, 11 Jan 1984 05:00:00 GMT', 'cache-control' => 'no-cache, must-revalidate, max-age=0', 'referrer-policy' => 'strict-origin-when-cross-origin', 'x-frame-options' => 'SAMEORIGIN', 'x-litespeed-cache-control' => 'no-cache', 'vary' => 'Accept-Encoding', 'alt-svc' => 'h3=":443"; ma=86400, h3-29=":443"; ma=86400', 'x-turbo-charged-by' => 'LiteSpeed', 'cf-cache-status' => 'DYNAMIC', 'expect-ct' => 'max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"', 'report-to' => '{"endpoints":[{"url":"https:\\/\\/a.nel.cloudflare.com\\/report\\/v3?s=UihTXSkZG
[Jul 24 09:53:48] Starting cron with normal ajax at URL https://cgscomputer.com/wp-admin/admin-ajax.php?action=wordfence_doScan&isFork=0&scanMode=custom&cronKey=REDACTED
[Jul 24 09:53:49] Scan engine received request.
[Jul 24 09:53:49] Verifying start request signature.
[Jul 24 09:53:49] Fetching stored cronkey for comparison.
[Jul 24 09:53:49] Checking cronkey: REDACTED (expecting REDACTED)
[Jul 24 09:53:49] Checking saved cronkey against cronkey param
[Jul 24 09:53:49] Checking if scan is already running
[Jul 24 09:53:49] Requesting max memory
[Jul 24 09:53:49] Setting up error handling environment
[Jul 24 09:53:49] Setting up scanRunning and starting scan
[Jul 24 09:53:49] Contacting Wordfence to initiate scan
[Jul 24 09:53:49] Calling Wordfence API v2.26:https://noc1.wordfence.com/v2.26/?k=0aaef08fda124b3a70b1d1acfb2e39998e4f922f091fe01d76c3ab1743409377a175ba1559dd6eb76760dd374de0d50beec341a1cf99e83fe7802d12d8641b73f646381dd59a351b22391e04c884b3e9&s=eyJ3cCI6IjYuMC4xIiwid2YiOiI3LjUuMTEiLCJtcyI6ZmFsc2UsImgiOiJodHRwczpcL1wvY2dzY29tcHV0ZXIuY29tIiwic3NsdiI6MjY5NDg4NDE1LCJwdiI6IjguMC4yMSIsInB0IjoibGl0ZXNwZWVkIiwiY3YiOiI3Ljg0LjAiLCJjcyI6Ik9wZW5TU0xcLzEuMS4xcSIsInN2IjoiTGl0ZVNwZWVkIiwiZHYiOiIxMC4yLjQ0LU1hcmlhREIiLCJsYW5nIjoiIn0&betaFeed=0&action=log_scan
[Jul 24 09:53:49] Scan process ended after forking.

      I am also seeing these messages in the logs – not sure if they are indicative of a root cause or symptom:

      [Jul 24 09:57:20] Scan engine received request.
[Jul 24 09:57:20] Verifying start request signature.
[Jul 24 09:57:20] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
[Jul 24 09:57:21] Scan engine received request.
[Jul 24 09:57:21] Verifying start request signature.
[Jul 24 09:57:21] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
[Jul 24 09:57:27] Scan engine received request.
[Jul 24 09:57:27] Verifying start request signature.
[Jul 24 09:57:27] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
[Jul 24 09:57:28] Scan engine received request.
[Jul 24 09:57:28] Verifying start request signature.
[Jul 24 09:57:28] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
[Jul 24 09:57:28] Scan engine received request.
[Jul 24 09:57:28] Verifying start request signature.
[Jul 24 09:57:28] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
[Jul 24 09:57:28] Scan engine received request.
[Jul 24 09:57:28] Verifying start request signature.
[Jul 24 09:57:28] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
[Jul 24 09:57:34] Scan engine received request.
[Jul 24 09:57:34] Verifying start request signature.
[Jul 24 09:57:34] Scan Engine Error: The signature on the request to start a scan is invalid. Please try again.
    • This topic was modified 2 years, 4 months ago by CGS Web Designs. Reason: Additional log entry
Viewing 2 replies - 1 through 2 (of 2 total)
  • Plugin Support wfpeter

    (@wfpeter)

    Hi @cgscomputers, thanks for getting in touch!

    Sorry to see you’re having scan issues. The only thing that jumps out at me from your detailed explanation above is that we don’t recommend to set PHP’s timeout to a number any larger than 60. max_execution_time in your php.ini could be changed to the 60 we recommend, and wp_memory_limit in wp-config.php should be set to 128M or 256M. Your PHP memory_limit value should be large enough to accommodate this change, too.

    Have you also attempted our troubleshooting tips already around scan issues?: https://www.wordfence.com/help/scan/troubleshooting/? Very often, starting scans remotely will help. You can also try using a smaller number like 10 for each scan stage.

    If you’ve exhausted the possibilities there, by all means drop us a site diagnostic report so we can take a closer look. Can you send it to wftest @ wordfence . com? You can find the link to do so at the top of the Wordfence > Tools > Diagnostics page. Then click on “Send Report by Email”. Please add your forum username where indicated and respond here after you have sent it.

    NOTE: It should look as follows – Screenshot of Tools > Diagnostic > Send by Email

    Thanks,

    Peter.

    Thread Starter CGS Web Designs

    (@cgscomputers)

    Hi, I’m going to mark this as resolved. While I don’t know for certain the cause (possibly litespeed abort but didn’t have enough time to fully test), my hosting company just migrated to a new server overnight and the scans are now working.

Viewing 2 replies - 1 through 2 (of 2 total)
  • The topic ‘Scan doesn’t start, or stops after seeming random time’ is closed to new replies.