search

nextcloud / previewgenerator

Nextcloud app to do preview generation in the background.
https://apps.nextcloud.com/apps/previewgenerator
GNU Affero General Public License v3.0
466 stars 57 forks source link

preview:generate-all finishes without error but doesn't seem to process all files #349

Open kevenwyld opened 1 year ago

kevenwyld commented 1 year ago

I have a Nextcloud 25.0.3 installation using nextcloud/docker. I do not have any external storage. PHP memory limit is set relatively high: 3072M . The entire installation has about 40,000 images (maybe, I could get an exact number if it's important for this issue).

I've been having issues where some previews are missing which causes very high system load when a user decides to scroll through a large image directory. I attempted to run preview:generate-all which did work but I noticed it would appear to generate previews on each run, even when it finishes without error.

To troubleshoot I used inotify and set up a watcher on the preview directory with inotifywait -r -e create -m <path> and ran generate-all repeatedly. Each time it runs it scans all images on the installation, generating a few previews here and there, and then finishes without error. At the time of this writing and with no images added to the installation at all (easy since I only have 3 users) I have run it about 10 times and each time it generates previews for images it "missed" the last run. I'm running it with verbosity flags but there are no errors reported when the occ command completes, or that I can find anywhere in the output.

I would have expected one successful run of preview:generate-all to find all images and create all previews but it seems to be missing some that are found on the next run. Is this normal?

I did find some errors reported in the nextcloud log but they are not as far as I can tell not referencing the same images that the previews are being created for. It's a bit hard to make connections between previews on disk and actual files other than looking at them, but I did my best.

I cut down the log trace a bit with jq so it's easier to read and doesn't hit the github char limit. I also removed identifying information. If you need the whole thing let me now and I'll find another way to include it:

[
  "imagecreatefromstring(): One parameter to a memory allocation multiplication is negative or zero, failing operation gracefully\n at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): Passed data is not in \"WBMP\" format at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): Couldn't create GD Image Stream out of Data at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "file_put_contents(/var/www/html/data/appdata_<redacted>/preview/4/5/8/9/b/8/b/9815/2850-4096-max.jpg): Failed to open stream: No such file or directory at /var/www/html/lib/private/Files/Storage/Local.php#311",
  {
    "file": "/var/www/html/lib/private/Files/Storage/Local.php",
    "line": 311,
    "function": "file_put_contents",
    "args": [
      "/var/www/html/data/appdata_<redacted>/preview/4/5/8/9/b/8/b/9815/2850-4096-max.jpg",
      null
    ]
  },
  {
    "file": "/var/www/html/lib/private/Files/Storage/Wrapper/Wrapper.php",
    "line": 258,
    "function": "file_put_contents",
    "class": "OC\\Files\\Storage\\Local",
    "type": "->",
    "args": [
      "appdata_<redacted>/preview/4/5/8/9/b/8/b/9815/2850-4096-max.jpg",
      null
    ]
  }
]
[
  null,
  null,
  null
]
[
  "imagecreatefromstring(): One parameter to a memory allocation multiplication is negative or zero, failing operation gracefully\n at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): Passed data is not in \"WBMP\" format at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): Couldn't create GD Image Stream out of Data at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): One parameter to a memory allocation multiplication is negative or zero, failing operation gracefully\n at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): Passed data is not in \"WBMP\" format at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]
[
  "imagecreatefromstring(): Couldn't create GD Image Stream out of Data at /var/www/html/lib/private/legacy/OC_Image.php#758",
  {
    "file": "/var/www/html/lib/private/legacy/OC_Image.php",
    "line": 758,
    "function": "imagecreatefromstring",
    "args": [
      "*** sensitive parameters replaced ***"
    ]
  },
  {
    "file": "/var/www/html/lib/private/Preview/Image.php",
    "line": 52,
    "function": "loadFromFile",
    "class": "OC_Image",
    "type": "->",
    "args": [
      "/var/www/html/data/<redacted>/20131224_220303.jpg"
    ]
  }
]

Another interesting thing I noticed is that basically all of the images that are found on each run, which is about 100-150 each time, are some variation of the 1024 size. Here's some examples from the inotify output. Each repetition looks pretty much the same as this but with different paths:

./preview/1/f/8/9/8/8/5/11182/ CREATE 1024-683.jpg
./preview/5/b/b/c/7/c/c/11183/ CREATE 683-1024.jpg
./preview/3/d/3/6/2/1/c/11184/ CREATE 1024-683.jpg
./preview/5/1/e/1/2/8/6/11185/ CREATE 1024-683.jpg
./preview/5/1/6/2/4/e/d/11186/ CREATE 1024-683.jpg
./preview/4/2/1/b/9/f/f/11187/ CREATE 1024-683.jpg
./preview/b/9/0/c/4/6/9/11188/ CREATE 1024-683.jpg
./preview/3/0/f/9/8/5/e/11189/ CREATE 1024-683.jpg
./preview/e/8/1/f/1/e/4/11190/ CREATE 1024-683.jpg
./preview/e/e/7/a/f/8/8/11191/ CREATE 1024-683.jpg
./preview/3/7/9/1/2/2/6/11192/ CREATE 1024-683.jpg
./preview/7/b/7/9/1/6/d/11193/ CREATE 1024-683.jpg
./preview/a/c/6/d/3/3/0/11194/ CREATE 1024-683.jpg
./preview/e/9/c/8/0/6/4/11195/ CREATE 1024-683.jpg
./preview/0/9/7/3/3/d/d/11196/ CREATE 1024-683.jpg
./preview/e/c/4/7/9/5/1/11197/ CREATE 1024-683.jpg
./preview/6/9/3/4/4/5/6/11198/ CREATE 1024-683.jpg
./preview/8/d/b/d/b/f/0/11199/ CREATE 1024-683.jpg
./preview/e/d/d/4/7/b/a/11200/ CREATE 1024-683.jpg
./preview/d/c/1/d/3/c/b/11201/ CREATE 1024-683.jpg
./preview/b/d/e/d/c/4/c/1971521/ CREATE 768-1024.jpg
./preview/0/4/3/b/8/b/e/1971537/ CREATE 768-1024.jpg
./preview/d/6/2/1/9/2/c/1971553/ CREATE 768-1024.jpg
./preview/5/a/9/3/3/0/b/1971569/ CREATE 1024-768.jpg
./preview/0/9/1/4/b/2/f/1971584/ CREATE 768-1024.jpg
./preview/2/2/8/6/3/8/8/1971600/ CREATE 768-1024.jpg
./preview/1/f/4/1/5/a/0/1971615/ CREATE 768-1024.jpg
./preview/8/d/5/2/b/4/7/1971631/ CREATE 1024-768.jpg
./preview/6/c/4/7/e/2/5/1971645/ CREATE 768-1024.jpg
./preview/e/b/e/8/3/5/4/1971660/ CREATE 768-1024.jpg
./preview/e/9/f/b/4/d/5/1971674/ CREATE 1024-768.jpg
./preview/7/e/e/f/2/b/9/1971688/ CREATE 1024-768.jpg
./preview/2/f/2/a/e/f/b/1971701/ CREATE 1024-768.jpg
./preview/4/b/2/4/c/2/7/1971714/ CREATE 768-1024.jpg
./preview/0/5/0/1/6/f/d/1971730/ CREATE 768-1024.jpg
./preview/7/d/a/4/6/d/8/1971742/ CREATE 768-1024.jpg
./preview/9/5/1/2/4/6/2/1971756/ CREATE 768-1024.jpg
./preview/f/c/2/0/4/5/d/1971768/ CREATE 1024-768.jpg
./preview/d/2/f/3/f/a/e/1971778/ CREATE 1024-768.jpg
./preview/1/b/b/1/5/4/3/1971791/ CREATE 1024-768.jpg
./preview/f/e/9/9/8/b/4/11202/ CREATE 1024-683.jpg
./preview/c/2/4/c/6/5/2/11203/ CREATE 1024-683.jpg
./preview/0/f/0/e/1/3/2/11204/ CREATE 683-1024.jpg
./preview/0/0/2/c/3/a/4/11205/ CREATE 1024-683.jpg
./preview/1/a/c/9/7/8/c/11206/ CREATE 1024-683.jpg
./preview/5/7/8/1/a/2/6/11207/ CREATE 1024-683.jpg
./preview/b/e/a/5/b/8/3/11208/ CREATE 683-1024.jpg
./preview/5/a/d/4/f/7/3/11209/ CREATE 1024-683.jpg
./preview/d/e/1/b/8/f/4/11210/ CREATE 1024-683.jpg
./preview/6/8/d/f/f/f/2/11211/ CREATE 1024-683.jpg
./preview/8/2/6/8/0/b/f/11212/ CREATE 683-1024.jpg
./preview/2/6/7/e/b/3/2/11213/ CREATE 683-1024.jpg
./preview/5/2/f/4/6/9/1/11214/ CREATE 683-1024.jpg
./preview/d/8/1/d/6/5/8/11215/ CREATE 683-1024.jpg
./preview/f/6/e/2/5/1/7/11216/ CREATE 683-1024.jpg
./preview/4/4/5/b/6/9/4/11217/ CREATE 683-1024.jpg
./preview/5/6/8/2/2/1/2/11218/ CREATE 683-1024.jpg
./preview/d/7/0/1/2/f/5/11219/ CREATE 683-1024.jpg
./preview/9/7/5/a/1/c/8/11220/ CREATE 1024-683.jpg
./preview/0/e/1/0/5/9/4/11221/ CREATE 683-1024.jpg
./preview/4/a/b/4/6/f/0/1971803/ CREATE 1024-768.jpg
./preview/f/3/d/e/c/c/6/1971818/ CREATE 1024-768.jpg
./preview/5/8/1/4/2/c/f/1971831/ CREATE 1024-768.jpg
./preview/4/c/3/c/c/a/7/1972854/ CREATE 768-1024.jpg
./preview/3/7/4/4/f/6/8/1972869/ CREATE 768-1024.jpg
./preview/c/4/6/d/3/5/4/1973639/ CREATE 768-1024.jpg
./preview/9/f/f/f/f/1/1/1973658/ CREATE 768-1024.jpg
./preview/8/6/7/8/a/d/9/1973669/ CREATE 768-1024.jpg
./preview/e/9/d/f/3/a/4/1973701/ CREATE 768-1024.jpg
./preview/9/a/c/9/6/a/a/1974048/ CREATE 768-1024.jpg
./preview/5/6/c/e/1/0/6/1974063/ CREATE 768-1024.jpg
./preview/7/5/3/6/a/1/e/1974538/ CREATE 768-1024.jpg
./preview/4/9/0/d/a/6/2/1974547/ CREATE 768-1024.jpg
./preview/c/3/7/5/8/d/c/1974559/ CREATE 768-1024.jpg
./preview/8/d/2/7/a/1/9/1976001/ CREATE 768-1024.jpg
./preview/4/8/0/e/b/5/4/11222/ CREATE 683-1024.jpg
./preview/e/a/3/e/d/2/0/11223/ CREATE 1024-683.jpg
./preview/e/e/8/9/2/2/3/11224/ CREATE 1024-683.jpg
./preview/0/c/3/d/d/1/f/11225/ CREATE 683-1024.jpg
./preview/e/4/d/7/8/a/6/11226/ CREATE 683-1024.jpg
./preview/f/a/7/8/a/1/6/11227/ CREATE 683-1024.jpg
./preview/2/c/7/5/c/f/2/11228/ CREATE 683-1024.jpg
./preview/4/1/1/c/4/5/1/11229/ CREATE 683-1024.jpg
./preview/b/4/5/7/2/f/4/11230/ CREATE 683-1024.jpg
./preview/8/7/3/7/3/d/f/11231/ CREATE 683-1024.jpg
./preview/c/2/9/1/b/0/1/11232/ CREATE 683-1024.jpg
./preview/6/0/e/4/a/c/6/11233/ CREATE 683-1024.jpg
./preview/6/f/0/4/f/0/d/11234/ CREATE 683-1024.jpg
./preview/3/2/e/1/9/4/2/11235/ CREATE 683-1024.jpg
./preview/5/d/d/f/e/d/3/11236/ CREATE 683-1024.jpg
./preview/4/a/e/6/1/b/1/11237/ CREATE 683-1024.jpg
./preview/a/b/b/4/5/1/a/11238/ CREATE 683-1024.jpg
./preview/1/7/8/9/3/0/a/11239/ CREATE 683-1024.jpg
./preview/d/c/2/f/f/5/f/11240/ CREATE 683-1024.jpg
./preview/4/e/3/1/6/b/f/11241/ CREATE 683-1024.jpg
./preview/b/3/7/4/7/0/6/1976013/ CREATE 768-1024.jpg
./preview/2/d/9/6/8/0/5/1976527/ CREATE 768-1024.jpg
./preview/5/3/c/1/f/d/b/1976535/ CREATE 768-1024.jpg
./preview/9/e/8/4/0/3/e/1976543/ CREATE 768-1024.jpg
./preview/d/a/5/6/e/c/2/1976555/ CREATE 768-1024.jpg
./preview/e/2/2/0/d/a/f/1976564/ CREATE 768-1024.jpg
./preview/f/1/b/f/6/5/e/1976574/ CREATE 768-1024.jpg
./preview/0/d/c/5/f/9/7/1976582/ CREATE 768-1024.jpg
./preview/b/d/e/e/5/8/5/1976592/ CREATE 768-1024.jpg
./preview/7/e/b/5/2/a/f/1976625/ CREATE 768-1024.jpg
./preview/d/8/b/e/0/6/e/1976635/ CREATE 768-1024.jpg
./preview/7/0/e/e/7/9/9/1978997/ CREATE 768-1024.jpg
./preview/4/e/4/e/f/5/d/1979469/ CREATE 768-1024.jpg
./preview/9/b/7/5/f/0/7/1979488/ CREATE 768-1024.jpg
./preview/e/0/5/7/5/5/f/1979505/ CREATE 768-1024.jpg
./preview/7/e/b/0/d/c/9/1979516/ CREATE 768-1024.jpg
./preview/0/0/7/5/0/9/0/1979879/ CREATE 768-1024.jpg
./preview/d/d/a/0/b/3/2/1979889/ CREATE 768-1024.jpg
./preview/b/3/3/4/a/a/8/1979904/ CREATE 768-1024.jpg

Thanks in advance for any help anyone can provide. I appreciate all the work everyone has put into this extremely vital tool!

st3iny commented 1 year ago

Thanks for the report.

How do you determine previews being generated multiple times?

I see possibly two things happening here:

  1. The command logs files even if they already have previews (in which case the process for this completes quickly).
  2. If the generation fails, the image will be processed again next time and it might fail again. That is probably what you are experiencing and there is no way around it.

Point 2 Is usually not a big issue because you are supposed to run preview:pre-generate anyway. The preview:generate-all command should only be run once.

A flag could be added to files to track generation errors. However, invalidation of this flag would be tricky and the problem is likely solved by using preview:pre-generate anyway. Images are only enqueued on file writes.

Can you confirm that this also happens when you run preview:pre-generate?

kevenwyld commented 1 year ago

How do you determine previews being generated multiple times?

I did this with the inotifywait command I referenced above. However I think I didn't explain my self well. New previews are being generated every time the generate-all command is run, they are not duplicates. It's as if it doesn't find everything on the first run which seems to contradict it's intended purpose which is to generate all previews with a single run (as far as I understand, it's possible I'm misunderstanding that)

If the generation fails, the image will be processed again next time and it might fail again. That is probably what you are experiencing and there is no way around it.

That makes sense if the files were duplicates, but in this case they are not. I will do further testing though to be sure of this.

Can you confirm that this also happens when you run preview:pre-generate?

I will test this as soon as I can.

kevenwyld commented 1 year ago

OK, so running preview:pre-generate repeatedly does not create any new files in the preview directory. This is expected though since pre-generate only creates previews for files that have been written since the last run. In this case there are no new files.

However running preview:generate-all does create new files each time. Seemingly finding new images to make previews for on every run. No deletions or modifying existing files, just new files are created in the preview directory structure. I modified my inotify watcher to check for that just incase:

inotifywait -r -e create -e delete -e modify -m <path to appdata>/preview

I hope this helps. And thanks for responding so quickly.

kevenwyld commented 1 year ago

More weirdness I just noticed. If I visit the "apps" page as the admin user gigabytes of previews which were generated by the preview:generate-all command are deleted. Running generate-all again creates them all again but it takes forever. This seems to happen every time I visit the "apps" page.

https://user-images.githubusercontent.com/11936535/214948796-b789e8a3-efae-46aa-9470-d9147022e34c.mp4

I have no idea what's going on here and this seems like it might be unrelated to this issue, maybe I should open another one? It's hard to know if it's preview generator that's causing this or the standard preview part of nextcloud server.

EDIT: The bad gateway in the video is because the proxy times out. It didn't actually crash.

kevenwyld commented 1 year ago

So a little more info here. What seems to be happening (though I admit I'm not an expert here) is that OC\\Preview\\BackgroundCleanupJob is triggered along with a lot of other background stuff when visiting the list of apps as the admin user and that job is deleting thousands of legitimate previews generated by this app. It does not remove any previews generated the normal way, by browsing to the location and clicking on the image.

The same thing happens if I generate previews and then wait for the periodic cleanup job to run on it's own. I'm not sure what the interval is but it's not every day it seems.

Things I tried up to this point:

I also tried removing all previews with this method referenced in the README. I know this is unsupported but at the moment things are not right so I figured it can't hurt. Anyway I ran generate-all after this which took a few days but finished without error. It didn't fix the problem though, and visiting the apps page still deleted over 2GB of the previews I generated.

It appears that I seem to be the only one experiencing this specifically for now. There are some reports I saw in the issues here of missing previews (e.g. scrolling through an images directory results in some images taking a long time to "load") which seems to be a symptom of what I'm seeing here as well.

Anyway if anyone has any ideas they would be greatly appreciated. Thanks again for your time!

st3iny commented 1 year ago

I tried a bit to reproduce the issue but wasn't able to.

May I ask 2 question to further debug this:

kevenwyld commented 1 year ago

@st3iny Sorry for the delay.

Which database are you using (SQLite, Postgres, MariaDB, etc.)?

I'm using MariaDB

Are you using an exotic storage backend for your data directory (SAMBA, NFS etc.) or is it residing on your host filesystem?

It's all on the host filesystem

I'm running in docker using a pretty much vanilla docker-compose from here, and the underlying filesystem is btrfs.

I also did a bit more digging and fixed a few problems I had along the way but they didn't change any of the described behavior.

I also disabled cron and limited connections to make the logs cleaner and did the whole test again. This time the only background jobs that were for sure executed by clicking on the apps link was the following:

  Info     no app in context  Deprecated event type for OCA\Files::loadAdditionalScripts:   2023-02-23T18:53:01+00:00
                              Symfony\Component\EventDispatcher\GenericEvent is used

  Info     no app in context  Deprecated event type for                                     2023-02-23T18:53:01+00:00
                              \OCP\Collaboration\Resources::loadAdditionalScripts: null

I'm not sure how to get a list of what OCA\Files::loadAdditionalScripts is actually loading. I noticed a developer manual page about it which says that app developers can include scripts in apps to be run (I think). But that doesn't seem to apply here.

There is a whole list of javascript files that exist in the server it self but I don't know where to go with that.

Here's a list of steps to reproduce that outlines what I did:

EDIT: switched link to js files to point to stable25 since that's what is relevant here instead of some random commit.

sirdrakeistda commented 1 year ago

I think I have the same issue. I get following logs:

[PHP] Fehler: Error: imagecreatefromstring(): Data is not in a recognized format at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758 at <<closure>>

 0. <<closure>>
    OC\Log\ErrorHandler::onError()
 1. /var/www/nextcloud/lib/private/legacy/OC_Image.php line 758
    imagecreatefromstring("*** sensitive parameters replaced ***")
 2. /var/www/nextcloud/lib/private/Preview/Image.php line 52
    OC_Image->loadFromFile()
 3. /var/www/nextcloud/lib/private/Preview/GeneratorHelper.php line 65
    OC\Preview\Image->getThumbnail()
 4. /var/www/nextcloud/lib/private/Preview/Generator.php line 343
    OC\Preview\GeneratorHelper->getThumbnail()
 5. /var/www/nextcloud/lib/private/Preview/Generator.php line 162
    OC\Preview\Generator->getMaxPreview()
 6. /var/www/nextcloud/lib/private/Preview/Generator.php line 114
    OC\Preview\Generator->generatePreviews()
 7. /var/www/nextcloud/lib/private/PreviewManager.php line 185
    OC\Preview\Generator->getPreview()
 8. /var/www/nextcloud/apps/recognize/lib/Classifiers/Classifier.php line 255
    OC\PreviewManager->getPreview()
 9. /var/www/nextcloud/apps/recognize/lib/Classifiers/Classifier.php line 84
    OCA\Recognize\Classifiers\Classifier->getConvertedFilePath()
10. /var/www/nextcloud/apps/recognize/lib/Classifiers/Images/ImagenetClassifier.php line 47
    OCA\Recognize\Classifiers\Classifier->classifyFiles()
11. /var/www/nextcloud/apps/recognize/lib/BackgroundJobs/ClassifyImagenetJob.php line 41
    OCA\Recognize\Classifiers\Images\ImagenetClassifier->classify()
12. /var/www/nextcloud/apps/recognize/lib/BackgroundJobs/ClassifierJob.php line 70
    OCA\Recognize\BackgroundJobs\ClassifyImagenetJob->classify()
13. /var/www/nextcloud/apps/recognize/lib/BackgroundJobs/ClassifyImagenetJob.php line 33
    OCA\Recognize\BackgroundJobs\ClassifierJob->runClassifier()
14. /var/www/nextcloud/lib/public/BackgroundJob/Job.php line 78
    OCA\Recognize\BackgroundJobs\ClassifyImagenetJob->run()
15. /var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php line 103
    OCP\BackgroundJob\Job->start()
16. /var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php line 93
    OCP\BackgroundJob\TimedJob->start()
17. /var/www/nextcloud/cron.php line 152
    OCP\BackgroundJob\TimedJob->execute()

Is this the same issue? Recognize stopped working and I have some preview problems with memories. I think this is caused by this bug.

Skip75 commented 1 year ago

Same for me, my logs are flooded by this error.

ie:

{"reqId":"AL2kvi30uSgSZCNg6J1Y","level":3,"time":"2023-03-30T13:19:04+02:00","remoteAddr":"127.0.0.1","user":"Username","app":"PHP","method":"GET","url":"/apps/photos/api/v1/preview/514389?etag=20ffccf961ff701e6b25f1de287d45fa&x=64&y=64","message":"imagecreatefromstring(): one parameter to a memory allocation multiplication is negative or zero, failing operation gracefully\n at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/111.0","version":"25.0.5.1","exception":{"Exception":"Error","Message":"imagecreatefromstring(): one parameter to a memory allocation multiplication is negative or zero, failing operation gracefully\n at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758","Code":0,"Trace":[{"function":"onError","class":"OC\\Log\\ErrorHandler","type":"::"},{"file":"/var/www/nextcloud/lib/private/legacy/OC_Image.php","line":758,"function":"imagecreatefromstring","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/Preview/Image.php","line":52,"function":"loadFromFile","class":"OC_Image","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/GeneratorHelper.php","line":65,"function":"getThumbnail","class":"OC\\Preview\\Image","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":343,"function":"getThumbnail","class":"OC\\Preview\\GeneratorHelper","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":162,"function":"getMaxPreview","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":114,"function":"generatePreviews","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/lib/private/PreviewManager.php","line":185,"function":"getPreview","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/apps/photos/lib/Controller/PreviewController.php","line":162,"function":"getPreview","class":"OC\\PreviewManager","type":"->"},{"file":"/var/www/nextcloud/apps/photos/lib/Controller/PreviewController.php","line":128,"function":"fetchPreview","class":"OCA\\Photos\\Controller\\PreviewController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"index","class":"OCA\\Photos\\Controller\\PreviewController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/var/www/nextcloud/lib/base.php","line":1047,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/var/www/nextcloud/index.php","line":36,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/Log/ErrorHandler.php","Line":92,"CustomMessage":"--"},"id":"642570eb569c7"}

and

{"reqId":"AL2kvi30uSgSZCNg6J1Y","level":3,"time":"2023-03-30T13:19:04+02:00","remoteAddr":"127.0.0.1","user":"Username","app":"PHP","method":"GET","url":"/apps/photos/api/v1/preview/514389?etag=20ffccf961ff701e6b25f1de287d45fa&x=64&y=64","message":"imagecreatefromstring(): Passed data is not in 'WBMP' format at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/111.0","version":"25.0.5.1","exception":{"Exception":"Error","Message":"imagecreatefromstring(): Passed data is not in 'WBMP' format at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758","Code":0,"Trace":[{"function":"onError","class":"OC\\Log\\ErrorHandler","type":"::"},{"file":"/var/www/nextcloud/lib/private/legacy/OC_Image.php","line":758,"function":"imagecreatefromstring","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/Preview/Image.php","line":52,"function":"loadFromFile","class":"OC_Image","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/GeneratorHelper.php","line":65,"function":"getThumbnail","class":"OC\\Preview\\Image","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":343,"function":"getThumbnail","class":"OC\\Preview\\GeneratorHelper","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":162,"function":"getMaxPreview","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":114,"function":"generatePreviews","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/lib/private/PreviewManager.php","line":185,"function":"getPreview","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/apps/photos/lib/Controller/PreviewController.php","line":162,"function":"getPreview","class":"OC\\PreviewManager","type":"->"},{"file":"/var/www/nextcloud/apps/photos/lib/Controller/PreviewController.php","line":128,"function":"fetchPreview","class":"OCA\\Photos\\Controller\\PreviewController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"index","class":"OCA\\Photos\\Controller\\PreviewController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/var/www/nextcloud/lib/base.php","line":1047,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/var/www/nextcloud/index.php","line":36,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/Log/ErrorHandler.php","Line":92,"CustomMessage":"--"},"id":"642570eb56968"}

and

{"reqId":"AL2kvi30uSgSZCNg6J1Y","level":3,"time":"2023-03-30T13:19:04+02:00","remoteAddr":"127.0.0.1","user":"Username","app":"PHP","method":"GET","url":"/apps/photos/api/v1/preview/514389?etag=20ffccf961ff701e6b25f1de287d45fa&x=64&y=64","message":"imagecreatefromstring(): Couldn't create GD Image Stream out of Data at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/111.0","version":"25.0.5.1","exception":{"Exception":"Error","Message":"imagecreatefromstring(): Couldn't create GD Image Stream out of Data at /var/www/nextcloud/lib/private/legacy/OC_Image.php#758","Code":0,"Trace":[{"function":"onError","class":"OC\\Log\\ErrorHandler","type":"::"},{"file":"/var/www/nextcloud/lib/private/legacy/OC_Image.php","line":758,"function":"imagecreatefromstring","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/nextcloud/lib/private/Preview/Image.php","line":52,"function":"loadFromFile","class":"OC_Image","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/GeneratorHelper.php","line":65,"function":"getThumbnail","class":"OC\\Preview\\Image","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":343,"function":"getThumbnail","class":"OC\\Preview\\GeneratorHelper","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":162,"function":"getMaxPreview","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/lib/private/Preview/Generator.php","line":114,"function":"generatePreviews","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/lib/private/PreviewManager.php","line":185,"function":"getPreview","class":"OC\\Preview\\Generator","type":"->"},{"file":"/var/www/nextcloud/apps/photos/lib/Controller/PreviewController.php","line":162,"function":"getPreview","class":"OC\\PreviewManager","type":"->"},{"file":"/var/www/nextcloud/apps/photos/lib/Controller/PreviewController.php","line":128,"function":"fetchPreview","class":"OCA\\Photos\\Controller\\PreviewController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"index","class":"OCA\\Photos\\Controller\\PreviewController","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->"},{"file":"/var/www/nextcloud/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::"},{"file":"/var/www/nextcloud/lib/base.php","line":1047,"function":"match","class":"OC\\Route\\Router","type":"->"},{"file":"/var/www/nextcloud/index.php","line":36,"function":"handleRequest","class":"OC","type":"::"}],"File":"/var/www/nextcloud/lib/private/Log/ErrorHandler.php","Line":92,"CustomMessage":"--"},"id":"642570eb5690b"}

These 3 set of logs are appearing multiple times in my event log :/

kevenwyld commented 1 year ago

So, I promise I checked this about 10 times before I even considered posting it because it's so ridiculous. But I feel like I have to put it somewhere in case I am not the only one having this issue:

As previously posted, visiting https:///settings/apps is deleting huge volumes of previews. It is very repeatable. The procedure for doing so is:

  1. Run occ preview:generate-all
  2. Log in as admin user
  3. go to the apps admin page https:///settings/apps
  4. Nextcloud hangs, and while it hangs deletes thousands of preview images
  5. Run occ preview:generate-all again, which tries to recreate all the previews that were just deleted

The new information I have however is... odd

The action of visiting https:///settings/apps only deletes the preview directory 4. I looked back at all my previous debugging attempts and logs and this is consistent in every one of them. It is as though the file path nextcloud/data/appdata_<uid>/preview/preview/4 is somehow not added to the preview database and cleaned up by some background job. No other path is touched.

I did a one-liner to watch the sizes and number of files in each directory in the preview path. Here's the before and after:


[root@nextcloud01 preview]# for i in $(ls -1); do number=$(find $i |wc -l); size=$(du -s $i |awk '{print $1}') ; echo "$i has $number files and is $size bytes"; done
0 has 25060 files and is 940992 bytes
1 has 24765 files and is 947000 bytes
2 has 25283 files and is 904728 bytes
3 has 24509 files and is 894484 bytes
4 has 18137 files and is 701916 bytes
5 has 25195 files and is 944064 bytes
6 has 24493 files and is 925368 bytes
7 has 24134 files and is 957776 bytes
8 has 25451 files and is 982716 bytes
9 has 24960 files and is 939344 bytes
a has 24850 files and is 889080 bytes
b has 24799 files and is 931904 bytes
c has 23885 files and is 909852 bytes
d has 24636 files and is 906428 bytes
e has 25757 files and is 985396 bytes
f has 25147 files and is 966132 bytes

After:

[root@nextcloud01 preview]# for i in $(ls -1); do number=$(find $i |wc -l); size=$(du -s $i |awk '{print $1}') ; echo "$i has $number files and is $size bytes"; done
0 has 25060 files and is 940992 bytes
1 has 24765 files and is 947000 bytes
2 has 25283 files and is 904728 bytes
3 has 24509 files and is 894484 bytes
5 has 25195 files and is 944064 bytes
6 has 24493 files and is 925368 bytes
7 has 24134 files and is 957776 bytes
8 has 25451 files and is 982716 bytes
9 has 24960 files and is 939344 bytes
a has 24850 files and is 889080 bytes
b has 24799 files and is 931904 bytes
c has 23885 files and is 909852 bytes
d has 24636 files and is 906428 bytes
e has 25757 files and is 985396 bytes
f has 25147 files and is 966132 bytes
[root@nextcloud01 preview]# ls -l 4
ls: cannot access '4': No such file or directory

I'm so confused. I don't have a clue what to do here. I assume these long single letter file paths are generated by some kind of hash of the fileID. I poked around in the upstream preview generator code (here and here) but can't find exactly where this is done.

Since this is only happening when I generate previews with occ preview:generate-all and not with any of the on-demand previews generated by viewing images in the gallery, I still think this is the right place for this bug report. I do sincerely hope someone out there is can try the inotify watcher I've posted previously. It may be that this is happening to others as well but because the number of images I have is so large it is more noticeable for me. Who knows.

Anyway here's the inotify output as well, recorded while visiting https://<my_nc_domain>/settings/apps, if anyone is interested. It just confirms the file lists I have above but is much more verbose.

inotify_output_2023-04-05.txt

Also to those posting here about the errors in my logs that I found. I'm not certain that those errors are related to the actual bug I'm experiencing. I had memories and recognize installed previously during testing but have since removed them and am still experiencing mass deletion of previews and preview:generate-all regenerating them the next time it is run.

dbartlett92 commented 1 year ago

I am also getting the issue where the generate all command does not generate previews for all images, but has no errors. I’ve ran it 6 ish times so far and still generating new previews, I wonder how many it will take in total.

My set up is a little different, my Mac mini m2 runs UTM with an Ubuntu 22.04 LTS (ARM) image with NC installed. The storage for files is an external storage mounted in Ubuntu, then added in NC external storage section per user to be located in the root / folder (a separate folder exists on the storage for each user).

I do not believe I am seeing the issue with the ‘4’ folder.

fredfokan commented 1 year ago

Hi,

Having the same issue on a fresh install on debian 12 with php8.2 and restore of nexcloud data's to the new server. Having generates several times using preview but somehow files could not been displayed . Also the following "fixing" doc was closely applied : https://github.com/nextcloud/previewgenerator but still not working for me too

Also regenerating thumbnails I got the following error in my nexcloud log :

{"reqId":"XMtP0wKE0A2Xh6EdFeiS","level":3,"time":"October 13, 2023 13:08:48","remoteAddr":"","user":"--","app":"core","method":"","url":"--","message":"Movie preview generation failed Output: ffmpeg version 5.1.3-1 Copyright (c) 2000-2022 the FFmpeg developers\n built with gcc 12 (Debian 12.2.0-14)\n configuration: --prefix=/usr --extra-version=1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libdav1d --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libglslang --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librabbitmq --enable-librist --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libsrt --enable-libssh --enable-libsvtav1 --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzimg --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --disable-sndio --enable-libjxl --enable-pocketsphinx --enable-librsvg --enable-libmfx --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-chromaprint --enable-frei0r --enable-libx264 --enable-libplacebo --enable-librav1e --enable-shared\n libavutil 57. 28.100 / 57. 28.100\n libavcodec 59. 37.100 / 59. 37.100\n libavformat 59. 27.100 / 59. 27.100\n libavdevice 59. 7.100 / 59. 7.100\n libavfilter 8. 44.100 / 8. 44.100\n libswscale 6. 7.100 / 6. 7.100\n libswresample 4. 7.100 / 4. 7.100\n libpostproc 56. 6.100 / 56. 6.100\n/tmp/oc_tmp_STgUcg: Invalid data found when processing input","userAgent":"--","version":"27.1.2.1","data":{"app":"core"}}

From my point of view issue is purely related to ffmpeg for which " Invalid data found when processing input " seems well known ...

Will try to recompile ffmpeg from source as done on my previous nexcloud instance before those kind of troubles

even recompiling it doesnt fix the issue , so seems to come from parameters pushed by preview:generate all