Error Downloading Attachments

[dzaikos]

Running 4.4.2 (issue began with this version) and when I click an attachment in a transaction I get the following error:

Type error: Return value of FireflyIII\Repositories\Attachment\AttachmentRepository::getContent() must be of the type string, boolean returned

This error does not occur for every attachment, but it does occur for quite a few. Version 4.4.2 introduced the new "has x attachments" trigger in rules but I don't know if it's related.

The actual attachment files saved to the server might be corrupt as the affected ones are only 188 B - 192 B (actual bytes, not kilobytes).

Can confirm the issue exists in 4.5.0.

[JC5]

I've expanded the code in the repository to log an error and return a string, as it is supposed to. However, it is difficult to debug why the file was not uploaded properly. Do you see a connection between the failed files? Are they of a specific type, of a specific size (before upload)?

[dzaikos]

All attachments are PDFs, however not all PDFs fail like this. I think the issue is somewhere during the upload process since a 4 MB PDF is being saved as a 192 B file.

If a PDF fails, it will always fail. I can delete and re-upload it repeatedly and attempts to download it will always result in this error (I might be able to email you one that I know doesn't work; let me know).

Some PDFs I get from others, many I just create on my Mac (macOS Sierra) by printing to PDF.

I cannot confirm if size is an issue as I don't use this feature a lot, but all files that have failed are over 512 KB. The largest is just under 4 MB.

Is there an easy way to decrypt on of the failed uploads? I'd be curious to see the contents of the file since the file size is so dramatically different.

[JC5]

File size should be caught beforehand but it could be an issue. The file upload box should say how big the files can become. Are they bigger than that?

[dzaikos]

I recently updated my PHP and Nginx settings to allow 32 MB uploads. I noticed the issue began around that time, however the upload form clearly shows 32 MB as the limit. The conf changes were also made when I updated to 4.4.2 (though I'm now running 4.5.0).

Largest file upload is 4 MB.

Is there an easy way to decrypt on of the failed uploads? I'd be curious to see the contents of the file since the file size is so dramatically different.

[JC5]

edit: sorry, this won't work. Probably the encryption routine fails completely so it's impossible to say.

[JC5]

Oh, add this to your nginx config:

http {
	#...
        client_max_body_size 100m;
	#...
}

[dzaikos]

client_max_body_size is already 32m so it's more than enough (I originally made PHP and Nginx changes because Nginx was throwing an error about body size being too large).

I've done a bunch of tests and as near as I can tell, there is some element of the PDF files that's causing the failure. I can take an image and "print to PDF" and it works. I can print to PDF a word processing document and it works. I can also upload images. But just those handful of PDFs fail so I'm guessing whatever is parsing the document when it's uploaded is choking on something in the file.

Can I send you one of the PDFs that's failing by email?

[JC5]

Of course, send it to thegrumpydictator@gmail.com. If you wish to use PGP, use this key.

[dzaikos]

Sent.

[JC5]

I've added some debug information to AttachmentHelper.php.

See also the commit. If you replace your version of that file, a log entry should appear. In my case it seems to work, and the result is this:

[2017-06-12 17:57:53] local.DEBUG: Created attachment: {"user_id":1,"attachable_id":590,"attachable_type":"FireflyIII\\Models\\TransactionJournal","md5":"f48c6f034ad8b7096833b13ae38422ce","filename":"x","mime":"application/pdf","size":2340204,"uploaded":false,"updated_at":"2017-06-12 00:00:00","created_at":"2017-06-12 00:00:00","id":6,"user":{"id":1,"created_at":"2017-06-12 15:12:15","updated_at":"2017-06-12 15:12:15","email":"thegrumpydictator@gmail.com","reset":null,"blocked":0,"blocked_code":null},"attachable":{"id":590,"created_at":"2017-06-12 00:00:00","updated_at":"2017-06-12 00:00:00","deleted_at":null,"user_id":1,"transaction_type_id":1,"bill_id":null,"transaction_currency_id":1,"description":"More groceriesX","date":"2017-06-11 00:00:00","interest_date":null,"book_date":null,"process_date":null,"order":0,"tag_count":0,"completed":true,"transaction_type":{"id":1,"created_at":"2017-06-12 00:00:00","updated_at":"2017-06-12 00:00:00","deleted_at":null,"type":"Withdrawal"},"user":{"id":1,"created_at":"2017-06-12 15:12:15","updated_at":"2017-06-12 15:12:15","email":"thegrumpydictator@gmail.com","reset":null,"blocked":0,"blocked_code":null}}} 
[2017-06-12 17:57:53] local.DEBUG: Full file length is 2340204 and upload size is 2340204.  
[2017-06-12 17:57:53] local.DEBUG: Encrypted content is 4224820  

Take note of the MD5 and the content lengths. Are they the same?

[dzaikos]

Replaced the file; however, nothing about the attachment is being logged. (Made sure .env was set to debug (APP_DEBUG=true and APP_LOG_LEVEL=debug).)

[JC5]

Alright then the file doesn't "arrive" at FF and we need to get a closer look. Open "app/Http/Controllers/Transaction/SingleController" and find the following line. It should be there twice.

/** @var array $files */

Enter the following on the line above (two times):

Log::debug('Content of files array: ', $_FILES);
Log::debug('Content of request: ', $request->file('attachments'));

This should give you some debugging information on the actual input received.

[dzaikos]

I'm still not getting anything logged. Is there a cache I need to clear? (I've already disabled Opcache, though it was still set to stat files for changes anyway.)

[JC5]

Darn, that makes it difficult. Yes, try these commands to clear some logs:

php artisan cache:clear
php artisan config:clear
php artisan route:clear
php artisan twig:clean
php artisan view:clear

What does APP_LOG=daily say in your installation? Does it say daily as well?

Open the folder storage/logs. I take it those files do log other things?

[dzaikos]

Yes, .env contains APP_LOG=daily and storage/logs is logging information. I ran the php artisan stuff above and now I'm getting logged information from the AttachmentHelper class. My information is mostly the same as what you posted in your above comment (with the initial debug attempt) with the exception of the encrypted content:

[2017-06-23 17:48:14] production.DEBUG: Created attachment: {"user_id":1,"attachable_id":460,"attachable_type":"FireflyIII\\Models\\TransactionJournal","md5":"f48c6f034ad8b7096833b13ae38422ce","filename":"x","mime":"application/pdf","size":2340204,"uploaded":false,"updated_at":"2017-06-23 00:00:00" [...]
[2017-06-23 17:48:14] production.DEBUG: Full file length is 2340204 and upload size is 2340204.  
[2017-06-23 17:48:14] production.DEBUG: Encrypted content is 192  

So the uploaded file is making it to Firefly, but I'm guessing at some point with encryption it's failing. But only on some files, most work. mcrypt module is installed and enabled per your site's requirements (though mcrypt is deprecated as of PHP 7, which is what I'm running).

(This really feels like a platform issue--I'm running this in a FreeBSD 10 jail--but I'd still like to resolve it.)

[JC5]

MCrypt can be removed. It is decrepated as you mention and the docs should no longer talk about it. It might just be the problem.

The encrypt routine uses openSSL in the background. An exception should be raised when the content cannot be encrypted but this exception may not make it to the front-end.

[dzaikos]

I removed MCrypt. Tried the upload again. Issue persists. OpenSSL PHP library was always installed.

[dzaikos]

Edit: Ignore this comment's original content; I messed up the redirects in the terminal. :)

I took one of the failed uploads (e.g. at-##.dat files) and ran it through cat in the terminal. It was base64 encoded (of course). So I decoded it and the contents of the failed upload is a serialized array of iv, value, mac. The value field is base64 encoded but rather small, so I decoded it and it's binary data (albeit, not much; and I assume encrypted).

[JC5]

Damn. I'll see if I can write a small decryption routine this weekend, it may aid in finding out what it says.

[JC5]

Alright so I completely forgot about this. There is a new command that you may use to decrypt files and store the result somewhere. It uses the same routines as the original download button does so it might fail as badly as the attachment download routine, but it can be edited (by me) to be more manual.

That way, I hope you can extract the content of the files and see what's wrong.

vagrant@vagrant:/sites/FF3/firefly-iii$ php artisan help firefly:decrypt
Usage:
  firefly:decrypt-attachment <id:The ID of the attachment.> <name:The file name of the attachment.> <directory:Where the file must be stored.>

Arguments:
  id:The ID of the attachment.
  name:The file name of the attachment.
  directory:Where the file must be stored.

Help:
  Decrypts an attachment and dumps the content in a file in the given directory.

And an example

vagrant@vagrant:/sites/FF3/firefly-iii$ php artisan firefly:decrypt 4 file.png storage

Going to write content for attachment #4 into file "/sites/FF3/firefly-iii/storage/file.png"
29118 bytes written. Exiting now..

[JC5]

The next release will include this routine. This release will require PHP7.1

[JC5]

The new release is live!

[dzaikos]

My apologies for not following up sooner.

Back in the summer I attempted to debug this thoroughly. I put debug code in all the way up to the actual PHP command to encrypt the file. Everything works right up to the point where OpenSSL is asked to encrypt; the file it spits out after that is corrupt (just a few bytes in size). I'm certain this means the issue not with Firefly at all but rather the openssl PHP module being used in FreeBSD 10.

I also setup a test environment using Debian 9, Nginx, MariaDB and PHP 7.1. I imported my production database and attempted to upload one of the files that always failed (same one I emailed you previously). It worked without issue.

So as far as I'm concerned this issue is outside the scope of your application. I'm just going to switch my install to Debian and be done with it.

Thanks for all your help along the way.

[JC5]

Alright, thanks for the follow-up, don't worry about it. I'm "glad" its outside of FF3. ;).

If you have any more issues, with encryption or otherwise, you know where to find me 👍