Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Nextcloud 28] New metadata background job can trigger error on 32-bit systems #2185

Closed
MichaIng opened this issue Dec 9, 2023 · 5 comments · Fixed by #2186
Closed

[Nextcloud 28] New metadata background job can trigger error on 32-bit systems #2185

MichaIng opened this issue Dec 9, 2023 · 5 comments · Fixed by #2186
Assignees
Labels
0. Needs triage Pending approval or rejection. This issue is pending approval. 28-feedback bug Something isn't working php PHP related ticket

Comments

@MichaIng
Copy link
Member

MichaIng commented Dec 9, 2023

Describe the bug
I face an "Epoch doesn't fit in a PHP integer" error when the new metadata background job runs. It appears once only, so it is probably a faulty timestamp of a particular file, but probably good to verify/debug this.

To Reproduce
Steps to reproduce the behavior:

  1. Upgrade to NC 28 on a 32-bit system
  2. Wait for or trigger GenerateMetadataJob
  3. Check logs

Expected behavior
No errors when the job runs.

Additional context
The client is irrelevant, instead I give server infos here:

  • Nextcloud 28 RC4
  • Debian 13 Trixie
  • PHP 8.2

Nextcloud log entry:

{
  "reqId": "XmrngEf2IRWcpO7HXxdB",
  "level": 3,
  "time": "2023-12-08T21:25:04+01:00",
  "remoteAddr": "",
  "user": "--",
  "app": "core",
  "method": "",
  "url": "--",
  "message": "Error while running background job (class: OC\\Core\\BackgroundJobs\\GenerateMetadataJob, arguments: )",
  "userAgent": "--",
  "version": "28.0.0.10",
  "exception": {
    "Exception": "ValueError",
    "Message": "Epoch doesn't fit in a PHP integer",
    "Code": 0,
    "Trace": [
      {
        "file": "/var/www/nextcloud/apps/photos/lib/Listener/OriginalDateTimeMetadataProvider.php",
        "line": 68,
        "function": "getTimestamp",
        "class": "DateTime",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/private/EventDispatcher/ServiceEventListener.php",
        "line": 86,
        "function": "handle",
        "class": "OCA\\Photos\\Listener\\OriginalDateTimeMetadataProvider",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/3rdparty/symfony/event-dispatcher/EventDispatcher.php",
        "line": 230,
        "function": "__invoke",
        "class": "OC\\EventDispatcher\\ServiceEventListener",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/3rdparty/symfony/event-dispatcher/EventDispatcher.php",
        "line": 59,
        "function": "callListeners",
        "class": "Symfony\\Component\\EventDispatcher\\EventDispatcher",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/private/EventDispatcher/EventDispatcher.php",
        "line": 94,
        "function": "dispatch",
        "class": "Symfony\\Component\\EventDispatcher\\EventDispatcher",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/private/EventDispatcher/EventDispatcher.php",
        "line": 106,
        "function": "dispatch",
        "class": "OC\\EventDispatcher\\EventDispatcher",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/private/FilesMetadata/FilesMetadataManager.php",
        "line": 115,
        "function": "dispatchTyped",
        "class": "OC\\EventDispatcher\\EventDispatcher",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/core/BackgroundJobs/GenerateMetadataJob.php",
        "line": 105,
        "function": "refreshMetadata",
        "class": "OC\\FilesMetadata\\FilesMetadataManager",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/core/BackgroundJobs/GenerateMetadataJob.php",
        "line": 101,
        "function": "scanFolder",
        "class": "OC\\Core\\BackgroundJobs\\GenerateMetadataJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/core/BackgroundJobs/GenerateMetadataJob.php",
        "line": 101,
        "function": "scanFolder",
        "class": "OC\\Core\\BackgroundJobs\\GenerateMetadataJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/core/BackgroundJobs/GenerateMetadataJob.php",
        "line": 101,
        "function": "scanFolder",
        "class": "OC\\Core\\BackgroundJobs\\GenerateMetadataJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/core/BackgroundJobs/GenerateMetadataJob.php",
        "line": 90,
        "function": "scanFolder",
        "class": "OC\\Core\\BackgroundJobs\\GenerateMetadataJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/core/BackgroundJobs/GenerateMetadataJob.php",
        "line": 81,
        "function": "scanFilesForUser",
        "class": "OC\\Core\\BackgroundJobs\\GenerateMetadataJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/public/BackgroundJob/Job.php",
        "line": 81,
        "function": "run",
        "class": "OC\\Core\\BackgroundJobs\\GenerateMetadataJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php",
        "line": 102,
        "function": "start",
        "class": "OCP\\BackgroundJob\\Job",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php",
        "line": 92,
        "function": "start",
        "class": "OCP\\BackgroundJob\\TimedJob",
        "type": "->"
      },
      {
        "file": "/var/www/nextcloud/cron.php",
        "line": 152,
        "function": "execute",
        "class": "OCP\\BackgroundJob\\TimedJob",
        "type": "->"
      }
    ],
    "File": "/var/www/nextcloud/apps/photos/lib/Listener/OriginalDateTimeMetadataProvider.php",
    "Line": 68,
    "message": "Error while running background job (class: OC\\Core\\BackgroundJobs\\GenerateMetadataJob, arguments: )",
    "exception": {},
    "CustomMessage": "Error while running background job (class: OC\\Core\\BackgroundJobs\\GenerateMetadataJob, arguments: )"
  }
}
  • Checking the log/code, it is this line: https://github.com/nextcloud/photos/blob/v28.0.0rc4/lib/Listener/OriginalDateTimeMetadataProvider.php#L68
  • Particularly the getTimestamp call on the EXIF metadata.
  • The exception matches the documentation, a ValueError since I use PHP 8.2:

    If the timestamp cannot be represented as int, a DateRangeError is thrown. Prior to PHP 8.3.0, a ValueError is thrown. And, prior to PHP 8.0.0, false was returned in this case. Still, the timestamp can be retrieved as string by using DateTimeInterface::format() with the U format.

  • Since the date format is set with seconds precision, until 2038 any epoch timestamp should fit into a 32-bit integer.
  • So it all looks like a particular image has invalid EXIF data, resulting in a PHP error on 32-bit systems.
  • To verify, some debug code could be added to add the path of the processed image to the log?

In case I did conclude correctly above, it is probably more a question whether such case should be handled gracefully, not throwing an error but at best a debug or info log entry, since invalid EXIF data among large image galleries are probably not uncommon and no reason to worry about the Nextcloud instance or data itself. A daily error log however should concern any serious admin.

Another (probably OOT) question is whether really all files should be checked every day by this job (which is currently the case as far as I see)? On my Raspberry Pi 2 with quite a lot of data this took 1.5h of continuous disk reads. If I understood correctly, the conversion/generation of metadata from all files is basically a one-time step, and afterwards it only needs to be done for new files. Probably it could be handled similarly to the general files cache table: Scan/generate only for new files, but have a CLI command like files:scan --all => photos:scan --all to trigger a manual rescan in case files were added manually.

@MichaIng MichaIng added bug Something isn't working 0. Needs triage Pending approval or rejection. This issue is pending approval. php PHP related ticket labels Dec 9, 2023
@artonge
Copy link
Collaborator

artonge commented Dec 11, 2023

Thanks for the report @MichaIng

  1. It indeed looks like an invalid timestamp. I think we should wrap the line in a try/catch to handle timestamps incompatible with 32 bits. Would you have time to create a PR for that?
  2. The metadata generation is expected to be done only once, as you said. We do have a background job to generate the metadata for existing files. It is expected to stop once all files have been handled. Maybe it is badly configured: https://github.com/nextcloud/server/blob/a0ff998/core/BackgroundJobs/GenerateMetadataJob.php

@artonge
Copy link
Collaborator

artonge commented Dec 11, 2023

Reading the code again, I doubt that we can truly support 32 bit. Currently, the code expects an int, so any incompatible value will cause an issue. How do we handle incompatible mtime in our files code? @come-nc maybe?

@come-nc
Copy link
Contributor

come-nc commented Dec 11, 2023

Reading the code again, I doubt that we can truly support 32 bit. Currently, the code expects an int, so any incompatible value will cause an issue. How do we handle incompatible mtime in our files code? @come-nc maybe?

You have to catch the error and log in this case, you cannot do much more if the timestamp does not fit in an int. But for original date this should not happen until 2038.

I am not sure we handle that correctly in all places, but incorrect mtimes are rare, usually mtime is set by Nextcloud itself.

For calendar, we officially do not support events past 2038 on 32bits.

@MichaIng
Copy link
Member Author

It indeed looks like an invalid timestamp

It is 0000:00:00 00:00:00 on all affected files, or all tools fail to interpret it, including exiftool and show 0000:00:00 00:00:00 instead. If 2038 is too far after 1970, then year 0 indeed is a little too far before 😄.

The metadata generation is expected to be done only once, as you said.

I saw this error on every job execution because the job failed at the same point every time, right?

@artonge
Copy link
Collaborator

artonge commented Dec 13, 2023

I saw this error on every job execution because the job failed at the same point every time, right?

Good point. Here is a fix nextcloud/server#42198

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0. Needs triage Pending approval or rejection. This issue is pending approval. 28-feedback bug Something isn't working php PHP related ticket
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

5 participants