Import CSV does not Trigger Rules - With Trigger Rule Option Active

[soloam]

Bug description
I am running Firefly III version 5.0.0, and I tried to import CSV file with the apply rules active, and no rules ara applied. I know that the import system is being revised, but I decided to report this because this is a really drawback, to manually force running all the rules

Steps to reproduce
Try to import a csv file with the apply rules activated, if the problem is common to all instances of firefly, the rules should be ignored.

Extra info
I was not able to replicate in the demo, because in the demo there is no Impor CSV option

Thank You

[JC5]

I'm sorry, I'm not able to trigger this issue in a test environment. When I configure the import to apply rules, this happens as expected:

The log files reflect the same thing:

[2020-01-22 18:26:19] local.NOTICE: Done storing. Firefly III has stored 1 transactions.  
[2020-01-22 18:26:19] local.DEBUG: Set status of job "YFABi7RCLS1A" to "stored_data"  
[2020-01-22 18:26:19] local.DEBUG: Set status of job "YFABi7RCLS1A" to "linking_to_tag"  
[2020-01-22 18:26:19] local.DEBUG: Created tag #7 ("Import with key 'YFABi7RCLS1A'")  
[2020-01-22 18:26:19] local.DEBUG: Looping groups...  
[2020-01-22 18:26:19] local.DEBUG: Looping journals in group #600  
[2020-01-22 18:26:19] local.DEBUG: Linking journal #605 to tag #7...  
[2020-01-22 18:26:19] local.INFO: Linked 1 journals to tag #7 ("Import with key 'YFABi7RCLS1A'")  
[2020-01-22 18:26:19] local.DEBUG: Set status of job "YFABi7RCLS1A" to "linked_to_tag"  
[2020-01-22 18:26:19] local.DEBUG: Set status of job "YFABi7RCLS1A" to "applying_rules"  
[2020-01-22 18:26:19] local.DEBUG: Found 6 user rules.  
[2020-01-22 18:26:19] local.DEBUG: Going to apply rule #1 to group 600. 

Could you share some log files as well?

[JC5]

Hi! This is a canned reply that tells you how to get more debug details.

1. Please collect some log files. Go to storage/logs and open the latest log file. It should be called something like "ff3-fpm-fcgi-*.log". In it, you should be able to find the error along with its "stacktrace": this will tell me where Firefly III broke down. If you run Docker, use docker logs <container>.
2. You may also enable debug mode to make sure the log files catch everything and try again.
3. Make sure you clear your browser cookies and clear Firefly III's cache files by running php artisan cache:clear or by visiting /flush on your installation.

If you do not want to share log files or other details on GitHub, please send them to me over (encrypted) email.

[soloam]

Hello, I tried to collect the debug, did all the steps, enabled debug as stated, deleted all the files in logs and cleared browser and ffIII cache... I tried again but the log file only haves local.INFO User visits homepage. I added the "APP_DEBUG=true" and the "APP_LOG_LEVEL=debug"

What I'm doing wrong?

[soloam]

I also tried to restart the server/jail

[JC5]

I think I know! Sorry for not realizing this earlier. Try adding LOG_CHANNEL=daily as an environment variable. Another log file should appear.

[soloam]

Ok, hera is the logs:

It looks like he tried to apply the first rule of the first group, but I have it to "Stop processing", that should only stop processing to this group if true, correct? In this case it's not true, so it should try the next rule, but it seams that it stopped the group and all the other rules.

[2020-01-23 16:48:05] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "has_prereq"  
[2020-01-23 16:48:05] local.DEBUG: Redirect to configuration.  
[2020-01-23 16:48:05] local.DEBUG: Now in JobConfigurationController::index()  
[2020-01-23 16:48:05] local.DEBUG: Now in JobConfigurationController::index() with job "1qrAVjDyj3KM" and status "has_prereq"  
[2020-01-23 16:48:05] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:28] local.DEBUG: Now in postConfigure() {"job":"1qrAVjDyj3KM"} 
[2020-01-23 16:48:28] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:28] local.ERROR: Could not decrypt data of attachment #14: The payload is invalid.  
[2020-01-23 16:48:28] local.ERROR: Could not decrypt data of attachment #15: The payload is invalid.  
[2020-01-23 16:48:28] local.ERROR: Could not decrypt data of attachment #15: The payload is invalid.  
[2020-01-23 16:48:28] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:28] local.ERROR: Could not decrypt data of attachment #15: The payload is invalid.  
[2020-01-23 16:48:28] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:28] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:28] local.DEBUG: Now in JobConfigurationController::index()  
[2020-01-23 16:48:28] local.DEBUG: Now in JobConfigurationController::index() with job "1qrAVjDyj3KM" and status "has_prereq"  
[2020-01-23 16:48:28] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:28] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:35] local.DEBUG: Now in postConfigure() {"job":"1qrAVjDyj3KM"} 
[2020-01-23 16:48:35] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:35] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:35] local.DEBUG: Now in JobConfigurationController::index()  
[2020-01-23 16:48:35] local.DEBUG: Now in JobConfigurationController::index() with job "1qrAVjDyj3KM" and status "has_prereq"  
[2020-01-23 16:48:35] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:35] local.ERROR: Could not decrypt data of attachment #14: The payload is invalid.  
[2020-01-23 16:48:35] local.DEBUG: Detected file headers: ["Data Operação","Data valor","Descrição","Montante","Saldo Contabilístico"] 
[2020-01-23 16:48:35] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:40] local.DEBUG: Now in postConfigure() {"job":"1qrAVjDyj3KM"} 
[2020-01-23 16:48:40] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:40] local.DEBUG: Column 0 has been given role date-transaction (mapping: false)  
[2020-01-23 16:48:40] local.DEBUG: Column 1 has been given role _ignore (mapping: false)  
[2020-01-23 16:48:40] local.DEBUG: Column 2 has been given role description (mapping: false)  
[2020-01-23 16:48:40] local.DEBUG: Column 3 has been given role amount (mapping: false)  
[2020-01-23 16:48:40] local.DEBUG: Column 4 has been given role external-id (mapping: false)  
[2020-01-23 16:48:40] local.DEBUG: Updating configuration...  
[2020-01-23 16:48:40] local.DEBUG: Now in JobConfigurationController::index()  
[2020-01-23 16:48:40] local.DEBUG: Now in JobConfigurationController::index() with job "1qrAVjDyj3KM" and status "has_prereq"  
[2020-01-23 16:48:40] local.DEBUG: Going to create class "FireflyIII\Import\JobConfiguration\FileJobConfiguration"  
[2020-01-23 16:48:40] local.DEBUG: Config is complete, set status to ready_to_run.  
[2020-01-23 16:48:40] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "ready_to_run"  
[2020-01-23 16:48:43] local.INFO: Now in JobStatusController::start  
[2020-01-23 16:48:43] local.DEBUG: Created class of type FireflyIII\Import\Routine\FileRoutine  
[2020-01-23 16:48:43] local.DEBUG: Try to call FireflyIII\Import\Routine\FileRoutine:run()  
[2020-01-23 16:48:43] local.DEBUG: Now in run() for file routine with status: ready_to_run  
[2020-01-23 16:48:43] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "running"  
[2020-01-23 16:48:43] local.DEBUG: Now in setImportJob()  
[2020-01-23 16:48:43] local.DEBUG: Now in CSVProcessor() run  
[2020-01-23 16:48:43] local.DEBUG: Now in getReader()  
[2020-01-23 16:48:43] local.ERROR: Could not decrypt data of attachment #14: The payload is invalid.  
[2020-01-23 16:48:43] local.DEBUG: now in getLines()  
[2020-01-23 16:48:43] local.DEBUG: Start converging process.  
[2020-01-23 16:48:43] local.DEBUG: Now converging line 1 out of 1.  
[2020-01-23 16:48:43] local.DEBUG: Now at column #0 (date-transaction), value "22-01-2020"  
[2020-01-23 16:48:43] local.DEBUG: Column #0 with role "date-transaction" is not mapped.  
[2020-01-23 16:48:43] local.DEBUG: Now at column #1 (_ignore), value "21-01-2020"  
[2020-01-23 16:48:43] local.DEBUG: Now at column #2 (description), value "Teste"  
[2020-01-23 16:48:43] local.DEBUG: Column #2 with role "description" is not mapped.  
[2020-01-23 16:48:43] local.DEBUG: Now at column #3 (amount), value "-6,56"  
[2020-01-23 16:48:43] local.DEBUG: Column #3 with role "amount" is not mapped.  
[2020-01-23 16:48:43] local.DEBUG: Now at column #4 (external-id), value "xxx3"  
[2020-01-23 16:48:43] local.DEBUG: Column #4 with role "external-id" is not mapped.  
[2020-01-23 16:48:43] local.DEBUG: Now in validateMappedValues()  
[2020-01-23 16:48:43] local.DEBUG: Now going to check role "description".  
[2020-01-23 16:48:43] local.DEBUG: Now going to check role "original_source".  
[2020-01-23 16:48:43] local.DEBUG: Role "original_source" is in allowed meta roles, so store its value "csv-import-v5.0.0".  
[2020-01-23 16:48:43] local.DEBUG: Going to convert 1 import transactions  
[2020-01-23 16:48:43] local.DEBUG: Now going to parse importable 1 of 1  
[2020-01-23 16:48:43] local.DEBUG: Description is: "Teste"  
[2020-01-23 16:48:43] local.DEBUG: ImportTransaction holds no foreign amount info.  
[2020-01-23 16:48:43] local.DEBUG: Now in importTransaction->calculateAmount()  
[2020-01-23 16:48:43] local.DEBUG: Amount value is not NULL, assume this is the correct value.  
[2020-01-23 16:48:43] local.DEBUG: Converter class is FireflyIII\Import\Converter\Amount  
[2020-01-23 16:48:43] local.DEBUG: Start with amount "-6,56"  
[2020-01-23 16:48:43] local.DEBUG: Stripped "-6,56" away to "-6,56"  
[2020-01-23 16:48:43] local.DEBUG: Decimal character in "-6,56" seems to be a comma.  
[2020-01-23 16:48:43] local.DEBUG: Converted amount from "-6,56" to "-6.56".  
[2020-01-23 16:48:43] local.DEBUG: Final NUMERIC value is: "-6.56"  
[2020-01-23 16:48:43] local.DEBUG: First attempt to convert gives "-6.56"  
[2020-01-23 16:48:43] local.DEBUG: After modifiers the result is: "-6.56"  
[2020-01-23 16:48:43] local.DEBUG: All meta data:  {"original_source":"csv-import-v5.0.0"} 
[2020-01-23 16:48:43] local.DEBUG: Now in AssetAccountMapper::map(0) {"iban":null,"name":null,"number":null,"bic":null} 
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for iban. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for number. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Found nothing. Will return default account.  
[2020-01-23 16:48:43] local.DEBUG: Return default account "My Account" (#77). Return it!  
[2020-01-23 16:48:43] local.DEBUG: Now in OpposingAccountMapper::map(0, "-6.56") {"iban":null,"name":null,"number":null,"bic":null} 
[2020-01-23 16:48:43] local.DEBUG: Going to search for accounts of type Expense account  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for iban. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for number. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for iban. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for number. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for iban. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for number. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for iban. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for number. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for iban. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for number. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Will try to store a new account:  {"name":"(no name)","iban":null,"account_number":null,"account_type_id":null,"account_type":"Expense account","active":true,"BIC":null} 
[2020-01-23 16:48:43] local.DEBUG: No account type found by ID, continue search for "Expense account".  
[2020-01-23 16:48:43] local.DEBUG: Found account type based on 0 and "Expense account": "Expense account"  
[2020-01-23 16:48:43] local.DEBUG: Data array is as follows {"name":"(no name)","iban":null,"account_number":null,"account_type_id":null,"account_type":"Expense account","active":true,"BIC":null} 
[2020-01-23 16:48:43] local.DEBUG: Now in CurrencyMapper::map()  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for code. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for symbol. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: Now in CurrencyMapper::map()  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for code. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for symbol. Continue  
[2020-01-23 16:48:43] local.DEBUG: Array does not contain a value for name. Continue  
[2020-01-23 16:48:43] local.DEBUG: "My Account" (#77) is source and "(no name)" (#5) is destination.  
[2020-01-23 16:48:43] local.DEBUG: Source is Asset account, destination is Expense account, so this is a Withdrawal.  
[2020-01-23 16:48:43] local.DEBUG: Now in CurrencyMapper::map()  
[2020-01-23 16:48:43] local.DEBUG: Found currency EUR based on ID, return it.  
[2020-01-23 16:48:43] local.DEBUG: Source is an asset account, and has currency preference EUR  
[2020-01-23 16:48:43] local.DEBUG: createFromFormat: Turning "22-01-2020" into "2020-01-22 00:00:00" using "d-m-Y"  
[2020-01-23 16:48:43] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "provider_finished"  
[2020-01-23 16:48:43] local.INFO: Now finished with JobStatusController::start  
[2020-01-23 16:48:43] local.INFO: Now in JobStatusController::store  
[2020-01-23 16:48:43] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "storing_data"  
[2020-01-23 16:48:43] local.DEBUG: Now in countTransfers()  
[2020-01-23 16:48:43] local.DEBUG: Count of transfers in import array is 0.  
[2020-01-23 16:48:43] local.DEBUG: Constructed ImportArrayStorage()  
[2020-01-23 16:48:43] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "storing_data"  
[2020-01-23 16:48:43] local.NOTICE: Will now store the groups. Count of groups is 1.  
[2020-01-23 16:48:43] local.NOTICE: Going to store...  
[2020-01-23 16:48:43] local.DEBUG: Now store #1  
[2020-01-23 16:48:43] local.DEBUG: Going to store entry #1  
[2020-01-23 16:48:43] local.DEBUG: Now in duplicateDetected(0)  
[2020-01-23 16:48:43] local.DEBUG: The hash is: b7b7eb74152b36e8558becdc98a7c3cd2cf4c43bc66661e74243e335cd6f7345 {"user":1,"type":"withdrawal","date":"2020-01-22 00:00:00","order":0,"currency_id":1,"currency_code":null,"foreign_currency_id":0,"foreign_currency_code":null,"amount":"-6.56","foreign_amount":"","description":"Teste","source_id":77,"source_name":null,"destination_id":5,"destination_name":null,"budget_id":0,"budget_name":null,"category_id":0,"category_name":null,"bill_id":0,"bill_name":null,"piggy_bank_id":null,"piggy_bank_name":null,"reconciled":false,"notes":"","tags":[],"internal_reference":null,"external_id":"xxx3","sepa_cc":null,"sepa_ct_op":null,"sepa_ct_id":null,"sepa_db":null,"sepa_country":null,"sepa_ep":null,"sepa_ci":null,"sepa_batch_id":null,"interest_date":null,"book_date":null,"process_date":null,"due_date":null,"payment_date":null,"invoice_date":null} 
[2020-01-23 16:48:43] local.DEBUG: JSON encoded hash is: "b7b7eb74152b36e8558becdc98a7c3cd2cf4c43bc66661e74243e335cd6f7345"  
[2020-01-23 16:48:43] local.DEBUG: Hash of hash is: 1b003fd4a42c8ed39d7a740eba7d79db9bd9e114fde1f3f350c928024530fb4c  
[2020-01-23 16:48:43] local.DEBUG: Result is null  
[2020-01-23 16:48:43] local.DEBUG: Found no transactions with hash b7b7eb74152b36e8558becdc98a7c3cd2cf4c43bc66661e74243e335cd6f7345.  
[2020-01-23 16:48:43] local.DEBUG: Start of TransactionJournalFactory::create()  
[2020-01-23 16:48:43] local.DEBUG: Now creating journal 1/1  
[2020-01-23 16:48:43] local.DEBUG: Going to call createJournal {"user":1,"type":"withdrawal","date":"2020-01-22 00:00:00","order":0,"currency_id":1,"currency_code":null,"foreign_currency_id":0,"foreign_currency_code":null,"amount":"-6.56","foreign_amount":"","description":"Teste","source_id":77,"source_name":null,"destination_id":5,"destination_name":null,"budget_id":0,"budget_name":null,"category_id":0,"category_name":null,"bill_id":0,"bill_name":null,"piggy_bank_id":null,"piggy_bank_name":null,"reconciled":false,"notes":"","tags":[],"internal_reference":null,"external_id":"xxx3","original_source":null,"sepa_cc":null,"sepa_ct_op":null,"sepa_ct_id":null,"sepa_db":null,"sepa_country":null,"sepa_ep":null,"sepa_ci":null,"sepa_batch_id":null,"interest_date":null,"book_date":null,"process_date":null,"due_date":null,"payment_date":null,"invoice_date":null} 
[2020-01-23 16:48:43] local.DEBUG: The hash is: b7b7eb74152b36e8558becdc98a7c3cd2cf4c43bc66661e74243e335cd6f7345  
[2020-01-23 16:48:43] local.DEBUG: Now looking for a transaction type.  
[2020-01-23 16:48:43] local.DEBUG: Tried to search for "withdrawal", came up with "Withdrawal". Will return it.  
[2020-01-23 16:48:43] local.DEBUG: Now in findCurrencyNull()  
[2020-01-23 16:48:43] local.DEBUG: Final result: EUR  
[2020-01-23 16:48:43] local.DEBUG: Now in findCurrencyNull()  
[2020-01-23 16:48:43] local.DEBUG: Searching for currency with code ...  
[2020-01-23 16:48:43] local.DEBUG: Found nothing  
[2020-01-23 16:48:43] local.DEBUG: Currency is #1 (EUR)  
[2020-01-23 16:48:43] local.DEBUG: Transaction type for validator is now Withdrawal  
[2020-01-23 16:48:43] local.DEBUG: Now in AccountValidator::validateSource(77, "")  
[2020-01-23 16:48:43] local.DEBUG: Now in validateWithdrawalSource(77, "")  
[2020-01-23 16:48:43] local.DEBUG: Source seems valid.  
[2020-01-23 16:48:43] local.DEBUG: Now in AccountValidator::validateDestination(5, "")  
[2020-01-23 16:48:43] local.DEBUG: Now in validateWithdrawalDestination(5, "")  
[2020-01-23 16:48:43] local.DEBUG: Source info: {"id":77,"name":null,"iban":null,"number":null,"bic":null} 
[2020-01-23 16:48:43] local.DEBUG: Destination info: {"id":5,"name":null,"iban":null,"number":null,"bic":null} 
[2020-01-23 16:48:43] local.DEBUG: Now in getAccount(source) {"id":77,"name":null,"iban":null,"number":null,"bic":null} 
[2020-01-23 16:48:43] local.DEBUG: Based on the fact that the transaction is a Withdrawal, the source account should be in: Asset account, Loan, Debt, Mortgage  
[2020-01-23 16:48:43] local.DEBUG: Found "account_id" object  for source: #77, "My Account" of type Asset account  
[2020-01-23 16:48:43] local.DEBUG: Now in getAccount(destination) {"id":5,"name":null,"iban":null,"number":null,"bic":null} 
[2020-01-23 16:48:43] local.DEBUG: Based on the fact that the transaction is a Withdrawal, the destination account should be in: Expense account, Cash account, Loan, Debt, Mortgage  
[2020-01-23 16:48:43] local.DEBUG: Found "account_id" object  for destination: #5, "(no name)" of type Expense account  
[2020-01-23 16:48:43] local.DEBUG: Currency is now #1 (EUR) because of account #77 (My Account)  
[2020-01-23 16:48:44] local.DEBUG: Created new journal #322: "Teste"  
[2020-01-23 16:48:44] local.DEBUG: Created transaction #643 (EUR -6.56, account My Account), part of journal #322  
[2020-01-23 16:48:44] local.DEBUG: Created transaction #644 (EUR 6.560000000000, account (no name)), part of journal #322  
[2020-01-23 16:48:44] local.DEBUG: Now in findBudget()  
[2020-01-23 16:48:44] local.DEBUG: Searching for budget with ID #0...  
[2020-01-23 16:48:44] local.DEBUG: Found result is null? true  
[2020-01-23 16:48:44] local.DEBUG: Now in findCategory()  
[2020-01-23 16:48:44] local.DEBUG: Searching for category with ID #0...  
[2020-01-23 16:48:44] local.DEBUG: Searching for category with name ...  
[2020-01-23 16:48:44] local.DEBUG: Found category result is null? true  
[2020-01-23 16:48:44] local.DEBUG: Will now store piggy event.  
[2020-01-23 16:48:44] local.DEBUG: Journal is not a transfer, do nothing.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_cc", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_ct_op", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_ct_id", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_db", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_country", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_ep", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_ci", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "sepa_batch_id", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "interest_date", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "book_date", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "process_date", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "due_date", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "payment_date", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "invoice_date", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "recurrence_id", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "internal_reference", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "bunq_payment_id", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "import_hash", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "import_hash_v2", with value "b7b7eb74152b36e8558becdc98a7c3cd2cf4c43bc66661e74243e335cd6f7345".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Will create new object.  
[2020-01-23 16:48:44] local.DEBUG: Going to create new meta-data entry to store "import_hash_v2".  
[2020-01-23 16:48:44] local.DEBUG: Will update value and return.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "external_id", with value "xxx3".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Will create new object.  
[2020-01-23 16:48:44] local.DEBUG: Going to create new meta-data entry to store "external_id".  
[2020-01-23 16:48:44] local.DEBUG: Will update value and return.  
[2020-01-23 16:48:44] local.DEBUG: Going to store meta-field "original_source", with value "".  
[2020-01-23 16:48:44] local.DEBUG: In updateOrCreate()  
[2020-01-23 16:48:44] local.DEBUG: Is an empty string.  
[2020-01-23 16:48:44] local.DEBUG: Stored as group #322  
[2020-01-23 16:48:44] local.NOTICE: Done storing. Firefly III has stored 1 transactions.  
[2020-01-23 16:48:44] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "stored_data"  
[2020-01-23 16:48:44] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "linking_to_tag"  
[2020-01-23 16:48:44] local.DEBUG: Created tag #27 ("Import with key '1qrAVjDyj3KM'")  
[2020-01-23 16:48:44] local.DEBUG: Looping groups...  
[2020-01-23 16:48:44] local.DEBUG: Looping journals in group #322  
[2020-01-23 16:48:44] local.DEBUG: Linking journal #322 to tag #27...  
[2020-01-23 16:48:44] local.INFO: Linked 1 journals to tag #27 ("Import with key '1qrAVjDyj3KM'")  
[2020-01-23 16:48:44] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "linked_to_tag"  
[2020-01-23 16:48:44] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "applying_rules"  
[2020-01-23 16:48:44] local.DEBUG: Found 80 user rules.  
[2020-01-23 16:48:44] local.DEBUG: Going to apply rule #8 to group 322.  
[2020-01-23 16:48:44] local.DEBUG: Making new rule from Rule 8  
[2020-01-23 16:48:44] local.DEBUG: Rule is strict: true  
[2020-01-23 16:48:44] local.DEBUG: Push trigger 303  
[2020-01-23 16:48:44] local.DEBUG: self::getTriggerClass("user_action") = "FireflyIII\TransactionRules\Triggers\UserAction"  
[2020-01-23 16:48:44] local.DEBUG: FireflyIII\TransactionRules\Triggers\UserAction::makeFromTriggerValue(store-journal) = object of class "FireflyIII\TransactionRules\Triggers\UserAction"  
[2020-01-23 16:48:44] local.DEBUG: Push trigger 304  
[2020-01-23 16:48:44] local.DEBUG: self::getTriggerClass("description_is") = "FireflyIII\TransactionRules\Triggers\DescriptionIs"  
[2020-01-23 16:48:44] local.DEBUG: FireflyIII\TransactionRules\Triggers\DescriptionIs::makeFromTriggerValue(DÉBITO DIRETO-CETELEM-75141101954) = object of class "FireflyIII\TransactionRules\Triggers\DescriptionIs"  
[2020-01-23 16:48:44] local.DEBUG: handleTransactionJournal for journal 322  
[2020-01-23 16:48:44] local.DEBUG: start of Processor::triggered()  
[2020-01-23 16:48:44] local.DEBUG: Found triggers starts at 0  
[2020-01-23 16:48:44] local.DEBUG: Now checking trigger FireflyIII\TransactionRules\Triggers\UserAction with value store-journal  
[2020-01-23 16:48:44] local.DEBUG: RuleTrigger UserAction for journal 322 always triggers.  
[2020-01-23 16:48:44] local.DEBUG: Is a match!  
[2020-01-23 16:48:44] local.DEBUG: Now checking trigger FireflyIII\TransactionRules\Triggers\DescriptionIs with value DÉBITO DIRETO-CETELEM-75141101954  
[2020-01-23 16:48:44] local.DEBUG: RuleTrigger DescriptionIs for journal #322: "teste" is NOT "dÉbito direto-cetelem-75141101954", return false.  
[2020-01-23 16:48:44] local.DEBUG: Result of triggered() {"hitTriggers":1,"foundTriggers":2,"result":false} 
[2020-01-23 16:48:44] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "rules_applied"  
[2020-01-23 16:48:44] local.DEBUG: In event RequestedReportOnJournals.  
[2020-01-23 16:48:44] local.DEBUG: In reportJournals.  
[2020-01-23 16:48:44] local.DEBUG: Trying to mail...  
[2020-01-23 16:48:44] local.DEBUG: Going to try to decrypt users currency preference.  
[2020-01-23 16:48:44] local.DEBUG: Could not decrypt "EUR". The payload is invalid.  
[2020-01-23 16:48:46] local.DEBUG: Done!  
[2020-01-23 16:48:46] local.DEBUG: Set status of job "1qrAVjDyj3KM" to "storage_finished"  
[2020-01-23 16:48:46] local.INFO: Now finished with JobStatusController::start  

Thank You

[soloam]

Was the log useful? Do you need any more information?

Thank You

[JC5]

This is fine, thanks. Stay tuned.

[JC5]

This should be fixed in the next release. 5.0.2 or possibly 5.1.0. I could use your help verifying this once it's out :)

[soloam]

I don't understand is it fixed? Will it go in the next release (5.0.1)? Or there is still work to do? Whenever is ready I'll be here to make the final test in my system!

Thank you for your help and time!

[JC5]

Yes it is fixed. Not in the current release (I meant to say 5.0.2).

When the next release comes I’ll let you know :)

[soloam]

Thank you @JC5