Content

Added by Martin Meier almost 3 years ago

Hi everyone,

I have installed new Openproject instance on my Linux server (Ubuntu) and configured inbound emails to create tickets out of an email. I am following this explanation:

https://www.openproject.org/docs/installation-and-operations/configuration/incoming-emails/

Now, email works so far everything fine. But, any kind of attachment will not be forwarded into the ticket. This means when I send an email with an attachment to my Openproject, it is creating a ticket as it should, but the attachment stays missing.

Does anyone have an idea what I have maybe overlooked?

Please let me know.

thx a lot, Martin

OS: Linux Ubuntu, bulsey/sid / 5.13.0-27-generic #29~20.04.1-Ubuntu

Openproject: 12.0.5 / PostgreSQL 13.5

Replies (21)

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

Hi Martin

does the email inbox that you configured actually accept THAT attachment that you would like to be attached to a work package?

First of all lets exclude OpenProject from your test case and confirm that your email inbox with a normal email program sees that attachment inside the email.

When that is confirmed, we will need the logs when your cron job is running

so please deactivate the cron job and issue the mail collector script manually to pickup the mail with attachment

meanwhile read the logs that are generated

It should work according to the documentation

https://www.openproject.org/docs/installation-and-operations/configuration/incoming-emails/#attachments

Thank you

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

many thx for coming back to me.

Indeed, the mail box (gmail.com) is accepting the incoming email with attachment. When I send an email to this mailbox (gmail.com) the attachment is clearly visible and there.

my command which I use in crontab is as following:

openproject run bundle exec rake redmine:email:receive_imap unknown_user=accept no_permission_check=1 host='imap.gmail.com' username='<myusername>' password='<mypassword>' port=993 ssl=true allow_override=type,project project=test >/dev/null 2>&1

I was following the documentation which is btw really good help. which log-file is the correct one to further debug?

Thx a lot in advance for your support.

Best Regards, Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

Hi Martin

did you find this information about logs and debug logs?

as I stated the cron job shall be deactivated and ran manually from terminal to get more logs, too

https://www.openproject.org/docs/installation-and-operations/operation/monitoring/

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

thx for your information, I have tried to follow it accordingly and have identified a bit more information. When I execute rake command as following:

openproject run bundle exec rake redmine:email:receive_imap unknown_user=accept no_permission_check=1 host='imap.gmail.com' username='<myuser>' password='mypasswd' port=993 ssl=true allow_override=type,project project=<demo> --trace

I retrieve following output in console, out from --trace:

** Invoke redmine:email:receive_imap (first_time)
** Invoke environment (first_time)
** Execute environment
** Execute redmine:email:receive_imap
I, [2022-02-14T18:50:46.013454 #487697] INFO -- : [ActiveJob] Enqueued Notifications::WorkflowJob (Job ID: 94beb9d9-ae3d-4b4c-b3c8-af6af18b8b1b) to DelayedJob(default)
I, [2022-02-14T18:50:46.036263 #487697] INFO -- : [ActiveJob] Enqueued Journals::CompletedJob (Job ID: b6fe8129-e901-4f3c-8a99-1e829250009d) to DelayedJob(default) at 2022-02-14 17:55:46 UTC
I, [2022-02-14T18:50:46.325741 #487697] INFO -- : MailHandler: Failed to add attachment neo.matrix.net for [martin.meier@aon.at]: may not be accessed.
I, [2022-02-14T18:50:46.326275 #487697] INFO -- : MailHandler: work_package #59 created by Anonymous

It seems MailHandler failed here specifically. I furthermore debugged logs with sudo openproject logs --tail following output I could gain:

Feb 14 18:53:13 neo openproject-web-1.service[1972]: I, [2022-02-14T18:53:13.499128 #1972] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:53:13 +0100
Feb 14 18:53:13 neo openproject-web-1.service[1972]: I, [2022-02-14T18:53:13.591288 #1972] INFO -- : duration=87.17 db=38.73 view=48.44 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:53:13 neo openproject-web-1.service[1972]: I, [2022-02-14T18:53:13.937293 #1972] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:53:13 +0100
Feb 14 18:53:13 neo openproject-web-1.service[1972]: I, [2022-02-14T18:53:13.980669 #1972] INFO -- : duration=38.42 db=12.48 view=25.94 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:53:23 neo openproject-web-1.service[1978]: I, [2022-02-14T18:53:23.938462 #1978] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:53:23 +0100
Feb 14 18:53:24 neo openproject-web-1.service[1978]: I, [2022-02-14T18:53:24.032406 #1978] INFO -- : duration=89.04 db=38.45 view=50.59 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:53:33 neo openproject-web-1.service[1978]: I, [2022-02-14T18:53:33.940624 #1978] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:53:33 +0100
Feb 14 18:53:33 neo openproject-web-1.service[1978]: I, [2022-02-14T18:53:33.992487 #1978] INFO -- : duration=45.51 db=14.06 view=31.45 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:53:43 neo openproject-web-1.service[1978]: I, [2022-02-14T18:53:43.942997 #1978] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:53:43 +0100
Feb 14 18:53:43 neo openproject-web-1.service[1978]: I, [2022-02-14T18:53:43.992174 #1978] INFO -- : duration=42.48 db=13.61 view=28.87 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:53:53 neo openproject-web-1.service[1972]: I, [2022-02-14T18:53:53.943262 #1972] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:53:53 +0100
Feb 14 18:53:53 neo openproject-web-1.service[1972]: I, [2022-02-14T18:53:53.991647 #1972] INFO -- : duration=41.87 db=13.48 view=28.39 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:54:03 neo openproject-web-1.service[1972]: I, [2022-02-14T18:54:03.940026 #1972] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:54:03 +0100
Feb 14 18:54:03 neo openproject-web-1.service[1972]: I, [2022-02-14T18:54:03.987464 #1972] INFO -- : duration=42.14 db=13.72 view=28.42 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:54:13 neo openproject-web-1.service[1978]: I, [2022-02-14T18:54:13.943799 #1978] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:54:13 +0100
Feb 14 18:54:13 neo openproject-web-1.service[1978]: I, [2022-02-14T18:54:13.992866 #1978] INFO -- : duration=42.86 db=14.32 view=28.54 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5
Feb 14 18:54:23 neo openproject-web-1.service[1972]: I, [2022-02-14T18:54:23.940420 #1972] INFO -- : Started GET "/openproject/api/v3/notifications?pageSize=0&filters=%5B%7B%22readIAN%22%3A%7B%22operator%22%3A%22%3D%22%2C%22values%22%3A%5B%22f%22%5D%7D%7D%5D" for 192.168.1.166 at 2022-02-14 18:54:23 +0100
Feb 14 18:54:23 neo openproject-web-1.service[1972]: I, [2022-02-14T18:54:23.990307 #1972] INFO -- : duration=43.93 db=14.68 view=29.25 status=200 method=GET path=/openproject/api/v3/notifications params={"pageSize"=>"0", "filters"=>"[{\"readIAN\":{\"operator\":\"=\",\"values\":[\"f\"]}}]"} host=neo.matrix.net user=5

Here I was not able to see any further hint unfortunately to identify real root-cause.

I think it is stopping already at MailHandler: Failed to add attachment neo.matrix.net for [martin.meier@aon.at]: may not be accessed.

Is this error showing up due to different domain like *.matrix.net and *.aon.at?

Or can u give me please another hint?

many thx, Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

user@openproject:/$ find /var/db/openproject/files/attachment
/var/db/openproject/files/attachment
/var/db/openproject/files/attachment/file
/var/db/openproject/files/attachment/file/3
/var/db/openproject/files/attachment/file/3/image.png
/var/db/openproject/files/attachment/file/1
/var/db/openproject/files/attachment/file/1/demo_project_teaser.png
/var/db/openproject/files/attachment/file/2
/var/db/openproject/files/attachment/file/2/scrum_project_teaser.png
/var/db/openproject/files/attachment/file/4
/var/db/openproject/files/attachment/file/4/image.png
user@openproject:/$ ls -ltra /var/db/openproject/files/attachment
total 12
drwxr-xr-x 3 openproject openproject 4096 Nov 12 09:38 ..
drwxr-xr-x 3 openproject openproject 4096 Nov 12 09:38 .
drwxr-xr-x 6 openproject openproject 4096 Feb 15 07:34 file

could you please issue the two commands above and think about if the permissions are correct and openproject is running as user openproject

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

I see attachments in the respective directories, but all of them have been uploaded manually through the Openproject web-gui - please find below:

openproject@neo:/$ find /var/db/openproject/files/attachment/
/var/db/openproject/files/attachment/
/var/db/openproject/files/attachment/file
/var/db/openproject/files/attachment/file/14
/var/db/openproject/files/attachment/file/14/Bildschirmfoto_2022-01-26_um_07.53.45.png
/var/db/openproject/files/attachment/file/4
/var/db/openproject/files/attachment/file/4/tux-ninja_ronchon_tux.png
/var/db/openproject/files/attachment/file/12
/var/db/openproject/files/attachment/file/12/IMG_0503.jpg
/var/db/openproject/files/attachment/file/2
/var/db/openproject/files/attachment/file/2/scrum_project_teaser.png
/var/db/openproject/files/attachment/file/8
/var/db/openproject/files/attachment/file/8/Fragen_Loxone.pdf
/var/db/openproject/files/attachment/file/1
/var/db/openproject/files/attachment/file/1/demo_project_teaser.png
/var/db/openproject/files/attachment/file/9
/var/db/openproject/files/attachment/file/9/Anschließen_von_Komponenten.pdf
/var/db/openproject/files/attachment/file/13
/var/db/openproject/files/attachment/file/13/Re_608249___RGBW_24V_Dimmer_Tree_Authentifikation_fehlgeschlagen.pdf
/var/db/openproject/files/attachment/file/11
/var/db/openproject/files/attachment/file/11/RGBW_Tree_extension_Authentifikation_schlug_fehl.pdf
/var/db/openproject/files/attachment/file/5
/var/db/openproject/files/attachment/file/5/Loxone_Planung_Grundlagen.pdf
/var/db/openproject/files/attachment/file/15
/var/db/openproject/files/attachment/file/15/image001.png
/var/db/openproject/files/attachment/file/10
/var/db/openproject/files/attachment/file/10/Kabel_und_Beschaltung.pdf
/var/db/openproject/files/attachment/file/6
/var/db/openproject/files/attachment/file/6/Fragen_Stephan.pdf
/var/db/openproject/files/attachment/file/7
/var/db/openproject/files/attachment/file/7/Stephan_Winkler.pdf
/var/db/openproject/files/attachment/file/16
/var/db/openproject/files/attachment/file/16/Bildschirmfoto_2022-02-06_um_15.51.51.png
/var/db/openproject/files/attachment/file/3
/var/db/openproject/files/attachment/file/3/tux-ninja_ronchon_tux.png

2nd command to check user access rights is as following:

openproject@neo:/$ ls -lisahtr /var/db/openproject/files/attachment/
insgesamt 12K
6036838 4,0K drwxr-xr-x 3 openproject openproject 4,0K Jän 12 19:55 ..
6036845 4,0K drwxr-xr-x 3 openproject openproject 4,0K Jän 12 19:55 .
6167112 4,0K drwxr-xr-x 18 openproject openproject 4,0K Feb 6 15:51 file

I have furthermore x-checked and manually started openproject as user openproject with command

openproject@neo:/$ sudo openproject run web

After that I have tested to send anohter email with attachment, but received the same error in log like:

** Invoke redmine:email:receive_imap (first_time)
** Invoke environment (first_time)
** Execute environment
** Execute redmine:email:receive_imap
I, [2022-02-16T12:37:13.867311 #547099] INFO -- : [ActiveJob] Enqueued Notifications::WorkflowJob (Job ID: 78b8bc90-6f7c-45e1-9402-7a707cb6e2d6) to DelayedJob(default)
I, [2022-02-16T12:37:13.889622 #547099] INFO -- : [ActiveJob] Enqueued Journals::CompletedJob (Job ID: adeae50f-8ab0-4ec7-8b76-3fb1a2a7238c) to DelayedJob(default) at 2022-02-16 11:42:13 UTC
I, [2022-02-16T12:37:14.152828 #547099] INFO -- : MailHandler: Failed to add attachment neo.matrix.net for martin.meier@aon.at]: may not be accessed.
I, [2022-02-16T12:37:14.153335 #547099] INFO -- : MailHandler: work_package #60 created by Anonymous

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

Hi Martin

Maybe debug logs could be helpful here?

we see only INFO notices, but there could be DEBUG notices in the last for lines after ** Execute redmine:email:receive_imap

try to enable DEBUG logs with the command documented here:

https://www.openproject.org/docs/installation-and-operations/operation/monitoring/#raising-the-log-level

Thank you

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

many thx again for your help.

I have increased log level with openproject config:set OPENPROJECT_LOG__LEVEL="debug" and after restarting openproject I did another rake with following output:

** Invoke redmine:email:receive_imap (first_time)
** Invoke environment (first_time)
** Execute environment
D, [2022-02-17T11:57:24.454898 #582417] DEBUG -- : (2.4ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
D, [2022-02-17T11:57:24.826542 #582417] DEBUG -- : Increasing database pool size to 17 to match max threads
D, [2022-02-17T11:57:24.959154 #582417] DEBUG -- : (0.8ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-17T11:57:24.961282 #582417] DEBUG -- : (0.7ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-17T11:57:25.231155 #582417] DEBUG -- : (2.0ms) SELECT MAX("settings"."updated_at") FROM "settings"
D, [2022-02-17T11:57:25.234588 #582417] DEBUG -- : Dalli::Server#connect 127.0.0.1:11211
D, [2022-02-17T11:57:25.477579 #582417] DEBUG -- : Enabling Rack::Timeout (service=120s wait=10s)
D, [2022-02-17T11:57:27.092865 #582417] DEBUG -- : incoming webhook registered: github
D, [2022-02-17T11:57:32.455315 #582417] DEBUG -- : (0.7ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-17T11:57:32.474308 #582417] DEBUG -- : (2.7ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
** Execute redmine:email:receive_imap
openproject@neo:/$

To my observation, the debug log output stops right after ** Execute redmine:email:receive_imap is that usual? I don't think so right?

Best Regards, Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

Please could you use the cronjob type for debugging? it makes things much more easy

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

yes of course :-) sorry. Here is the complete debug from my cronjob. I have used a different mailbox (not gmail, I used gmx now for a test) - here is the log:

rake command from cronjob:

openproject run bundle exec rake redmine:email:receive_imap unknown_user=accept no_permission_check=1 host='imap.gmx.net' username='<myusername>' password='<mypasswd>' port=993 ssl=true allow_override=type,project project=<myproject> --trace

output

** Invoke redmine:email:receive_imap (first_time)
** Invoke environment (first_time)
** Execute environment
D, [2022-02-17T17:30:39.957212 #589558] DEBUG -- : (3.2ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
D, [2022-02-17T17:30:40.337766 #589558] DEBUG -- : Increasing database pool size to 17 to match max threads
D, [2022-02-17T17:30:40.477204 #589558] DEBUG -- : (0.8ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-17T17:30:40.479582 #589558] DEBUG -- : (0.7ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-17T17:30:40.761644 #589558] DEBUG -- : (2.2ms) SELECT MAX("settings"."updated_at") FROM "settings"
D, [2022-02-17T17:30:40.765148 #589558] DEBUG -- : Dalli::Server#connect 127.0.0.1:11211
D, [2022-02-17T17:30:41.013567 #589558] DEBUG -- : Enabling Rack::Timeout (service=120s wait=10s)
D, [2022-02-17T17:30:42.679587 #589558] DEBUG -- : incoming webhook registered: github
D, [2022-02-17T17:30:47.909441 #589558] DEBUG -- : (0.7ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-17T17:30:47.927627 #589558] DEBUG -- : (2.5ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
** Execute redmine:email:receive_imap
D, [2022-02-17T17:30:50.755409 #589558] DEBUG -- : User Load (4.1ms) SELECT "users".* FROM "users" WHERE "users"."type" = $1 AND (LOWER(mail) ~* 'gerald\.derflinger([\+][^@]+)*@aon\.at') ORDER BY "users"."id" ASC LIMIT $2 [["type", "User"], ["LIMIT", 1]]
D, [2022-02-17T17:30:50.767604 #589558] DEBUG -- : AnonymousUser Load (1.5ms) SELECT "users".* FROM "users" WHERE "users"."type" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["type", "AnonymousUser"], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.061125 #589558] DEBUG -- : Project Load (2.0ms) SELECT "projects".* FROM "projects" WHERE "projects"."identifier" = $1 LIMIT $2 [["identifier", "efh-winkler"], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.232830 #589558] DEBUG -- : Type Load (2.6ms) SELECT "types".* FROM "types" INNER JOIN "projects_types" ON "types"."id" = "projects_types"."type_id" WHERE "projects_types"."project_id" = $1 AND (lower(name) = 'task') ORDER BY position ASC, types.position LIMIT $2 [["project_id", 3], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.266656 #589558] DEBUG -- : Status Load (2.2ms) SELECT "statuses".* FROM "statuses" WHERE (lower(name) = 'new') ORDER BY "statuses"."position" ASC LIMIT $1 [["LIMIT", 1]]
D, [2022-02-17T17:31:03.367863 #589558] DEBUG -- : WorkPackageCustomField Load (1.6ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 [["type", "WorkPackageCustomField"]]
D, [2022-02-17T17:31:03.379877 #589558] DEBUG -- : TRANSACTION (0.7ms) BEGIN
D, [2022-02-17T17:31:03.400978 #589558] DEBUG -- : IssuePriority Load (2.1ms) SELECT "enumerations".* FROM "enumerations" WHERE "enumerations"."type" = $1 AND "enumerations"."id" = $2 ORDER BY enumerations.position ASC LIMIT $3 [["type", "IssuePriority"], ["id", 0], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.406026 #589558] DEBUG -- : IssuePriority Load (1.6ms) SELECT "enumerations".* FROM "enumerations" WHERE "enumerations"."type" = $1 AND "enumerations"."active" = $2 AND "enumerations"."is_default" = $3 ORDER BY enumerations.position ASC LIMIT $4 [["type", "IssuePriority"], ["active", true], ["is_default", true], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.454620 #589558] DEBUG -- : User Load (1.7ms) SELECT "users".* FROM "users" WHERE "users"."type" IN ($1, $2) AND "users"."id" = $3 LIMIT $4 [["type", "User"], ["type", "AnonymousUser"], ["id", 0], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.460817 #589558] DEBUG -- : Status Load (1.3ms) SELECT "statuses".* FROM "statuses" WHERE "statuses"."id" = $1 ORDER BY "statuses"."position" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.478162 #589558] DEBUG -- : Type Load (1.4ms) SELECT "types".* FROM "types" WHERE "types"."id" = $1 ORDER BY position ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.513791 #589558] DEBUG -- : WorkPackageCustomField Load (2.2ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 AND ("custom_fields"."is_for_all" = $2 OR "custom_fields"."id" IN (SELECT "custom_fields"."id" FROM "custom_fields" INNER JOIN "custom_fields_projects" ON "custom_fields"."id" = "custom_fields_projects"."custom_field_id" WHERE "custom_fields"."type" = $3 AND "custom_fields_projects"."project_id" = $4 ORDER BY custom_fields.position)) ORDER BY custom_fields.position [["type", "WorkPackageCustomField"], ["is_for_all", true], ["type", "WorkPackageCustomField"], ["project_id", 3]]
D, [2022-02-17T17:31:03.526896 #589558] DEBUG -- : WorkPackageCustomField Load (1.7ms) SELECT "custom_fields".* FROM "custom_fields" INNER JOIN "custom_fields_types" ON "custom_fields"."id" = "custom_fields_types"."custom_field_id" WHERE "custom_fields"."type" = $1 AND "custom_fields_types"."type_id" = $2 [["type", "WorkPackageCustomField"], ["type_id", 1]]
D, [2022-02-17T17:31:03.596557 #589558] DEBUG -- : Type Exists? (1.6ms) SELECT 1 AS one FROM "types" INNER JOIN "projects_types" ON "types"."id" = "projects_types"."type_id" WHERE "projects_types"."project_id" = $1 AND "types"."id" = $2 LIMIT $3 [["project_id", 3], ["id", 1], ["LIMIT", 1]]
D, [2022-02-17T17:31:03.619627 #589558] DEBUG -- : EnabledModule Load (1.5ms) SELECT "enabled_modules".* FROM "enabled_modules" WHERE "enabled_modules"."project_id" = $1 [["project_id", 3]]
D, [2022-02-17T17:31:03.641620 #589558] DEBUG -- : WorkPackageCustomField Load (1.9ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 AND ("custom_fields"."is_for_all" = $2 OR "custom_fields"."id" IN (SELECT "custom_fields"."id" FROM "custom_fields" INNER JOIN "custom_fields_projects" ON "custom_fields"."id" = "custom_fields_projects"."custom_field_id" WHERE "custom_fields"."type" = $3 AND "custom_fields_projects"."project_id" = $4 ORDER BY custom_fields.position)) ORDER BY custom_fields.position [["type", "WorkPackageCustomField"], ["is_for_all", true], ["type", "WorkPackageCustomField"], ["project_id", 3]]
D, [2022-02-17T17:31:03.671193 #589558] DEBUG -- : EnterpriseToken Load (2.2ms) SELECT "enterprise_tokens".* FROM "enterprise_tokens" ORDER BY created_at DESC LIMIT $1 [["LIMIT", 1]]
D, [2022-02-17T17:31:03.683142 #589558] DEBUG -- : WorkPackageCustomField Load (1.9ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 AND ("custom_fields"."is_for_all" = $2 OR "custom_fields"."id" IN (SELECT "custom_fields"."id" FROM "custom_fields" INNER JOIN "custom_fields_projects" ON "custom_fields"."id" = "custom_fields_projects"."custom_field_id" WHERE "custom_fields"."type" = $3 AND "custom_fields_projects"."project_id" = $4 ORDER BY custom_fields.position)) ORDER BY custom_fields.position [["type", "WorkPackageCustomField"], ["is_for_all", true], ["type", "WorkPackageCustomField"], ["project_id", 3]]
D, [2022-02-17T17:31:03.689183 #589558] DEBUG -- : WorkPackageCustomField Load (1.9ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 AND ("custom_fields"."is_for_all" = $2 OR "custom_fields"."id" IN (SELECT "custom_fields"."id" FROM "custom_fields" INNER JOIN "custom_fields_projects" ON "custom_fields"."id" = "custom_fields_projects"."custom_field_id" WHERE "custom_fields"."type" = $3 AND "custom_fields_projects"."project_id" = $4 ORDER BY custom_fields.position)) ORDER BY custom_fields.position [["type", "WorkPackageCustomField"], ["is_for_all", true], ["type", "WorkPackageCustomField"], ["project_id", 3]]
D, [2022-02-17T17:31:03.698350 #589558] DEBUG -- : WorkPackageCustomField Load (1.8ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 AND ("custom_fields"."is_for_all" = $2 OR "custom_fields"."id" IN (SELECT "custom_fields"."id" FROM "custom_fields" INNER JOIN "custom_fields_projects" ON "custom_fields"."id" = "custom_fields_projects"."custom_field_id" WHERE "custom_fields"."type" = $3 AND "custom_fields_projects"."project_id" = $4 ORDER BY custom_fields.position)) ORDER BY custom_fields.position [["type", "WorkPackageCustomField"], ["is_for_all", true], ["type", "WorkPackageCustomField"], ["project_id", 3]]
D, [2022-02-17T17:31:03.723975 #589558] DEBUG -- : WorkPackage Load (2.5ms) SELECT "work_packages".* FROM "work_packages" WHERE (project_id = 3 AND version_id = NULL AND type_id IN (NULL)) AND ("work_packages"."position" IS NOT NULL) ORDER BY "work_packages"."position" DESC LIMIT $1 [["LIMIT", 1]]
D, [2022-02-17T17:31:03.729598 #589558] DEBUG -- : WorkPackage Create (1.9ms) INSERT INTO "work_packages" ("type_id", "project_id", "subject", "description", "status_id", "priority_id", "author_id", "created_at", "updated_at", "position", "lock_version") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11) RETURNING "id" [["type_id", 1], ["project_id", 3], ["subject", "Test attach gmx"], ["description", "adfasdfsdfadsf"], ["status_id", 1], ["priority_id", 8], ["author_id", 4], ["created_at", "2022-02-17 16:31:03.716745"], ["updated_at", "2022-02-17 16:31:03.716745"], ["position", 1], ["lock_version", 0]]
D, [2022-02-17T17:31:03.784268 #589558] DEBUG -- : Relation Create (2.5ms) INSERT INTO "relations" ("from_id", "to_id", "count") VALUES ($1, $2, $3) RETURNING "id" [["from_id", 64], ["to_id", 64], ["count", 1]]
D, [2022-02-17T17:31:03.790771 #589558] DEBUG -- : Inserting new journal for WorkPackage #64
D, [2022-02-17T17:31:03.840715 #589558] DEBUG -- : (18.8ms) WITH max_journals AS (
SELECT
64 journable_id,
'WorkPackage' journable_type,
COALESCE(journals.version, fallback.version) AS version,
COALESCE(journals.id, 0) id,
COALESCE(journals.data_id, 0) data_id
FROM
journals
RIGHT OUTER JOIN
(SELECT 0 AS version) fallback
ON
journals.journable_id = 64
AND journals.journable_type = 'WorkPackage'
AND journals.version IN (SELECT MAX(version) FROM journals WHERE journable_id = 64 AND journable_type = 'WorkPackage')

), changes AS (
SELECT
*
FROM
(SELECT
work_packages.id journable_id
FROM
(SELECT * FROM work_packages LEFT OUTER JOIN
(
SELECT from_id parent_id, to_id FROM "relations" WHERE "relations"."hierarchy" != 0 AND "relations"."relates" = 0 AND "relations"."duplicates" = 0 AND "relations"."follows" = 0 AND "relations"."blocks" = 0 AND "relations"."includes" = 0 AND "relations"."requires" = 0 AND (hierarchy + relates + duplicates + follows + blocks + includes + requires = 1) AND "relations"."to_id" = 64 LIMIT 1
) parent_relation
ON
work_packages.id = parent_relation.to_id
) work_packages
LEFT JOIN
(SELECT * FROM max_journals
JOIN
work_package_journals
ON
work_package_journals.id = max_journals.data_id) work_package_journals
ON
work_packages.id = work_package_journals.journable_id
WHERE
work_packages.id = 64 AND ((work_packages.type_id != work_package_journals.type_id)
OR (work_packages.type_id IS NULL AND work_package_journals.type_id IS NOT NULL)
OR (work_packages.type_id IS NOT NULL AND work_package_journals.type_id IS NULL)
OR (work_packages.project_id != work_package_journals.project_id)
OR (work_packages.project_id IS NULL AND work_package_journals.project_id IS NOT NULL)
OR (work_packages.project_id IS NOT NULL AND work_package_journals.project_id IS NULL)
OR (work_packages.subject != work_package_journals.subject)
OR (work_packages.subject IS NULL AND work_package_journals.subject IS NOT NULL)
OR (work_packages.subject IS NOT NULL AND work_package_journals.subject IS NULL)
OR (work_packages.due_date != work_package_journals.due_date)
OR (work_packages.due_date IS NULL AND work_package_journals.due_date IS NOT NULL)
OR (work_packages.due_date IS NOT NULL AND work_package_journals.due_date IS NULL)
OR (work_packages.category_id != work_package_journals.category_id)
OR (work_packages.category_id IS NULL AND work_package_journals.category_id IS NOT NULL)
OR (work_packages.category_id IS NOT NULL AND work_package_journals.category_id IS NULL)
OR (work_packages.status_id != work_package_journals.status_id)
OR (work_packages.status_id IS NULL AND work_package_journals.status_id IS NOT NULL)
OR (work_packages.status_id IS NOT NULL AND work_package_journals.status_id IS NULL)
OR (work_packages.assigned_to_id != work_package_journals.assigned_to_id)
OR (work_packages.assigned_to_id IS NULL AND work_package_journals.assigned_to_id IS NOT NULL)
OR (work_packages.assigned_to_id IS NOT NULL AND work_package_journals.assigned_to_id IS NULL)
OR (work_packages.priority_id != work_package_journals.priority_id)
OR (work_packages.priority_id IS NULL AND work_package_journals.priority_id IS NOT NULL)
OR (work_packages.priority_id IS NOT NULL AND work_package_journals.priority_id IS NULL)
OR (work_packages.version_id != work_package_journals.version_id)
OR (work_packages.version_id IS NULL AND work_package_journals.version_id IS NOT NULL)
OR (work_packages.version_id IS NOT NULL AND work_package_journals.version_id IS NULL)
OR (work_packages.author_id != work_package_journals.author_id)
OR (work_packages.author_id IS NULL AND work_package_journals.author_id IS NOT NULL)
OR (work_packages.author_id IS NOT NULL AND work_package_journals.author_id IS NULL)
OR (work_packages.done_ratio != work_package_journals.done_ratio)
OR (work_packages.done_ratio IS NULL AND work_package_journals.done_ratio IS NOT NULL)
OR (work_packages.done_ratio IS NOT NULL AND work_package_journals.done_ratio IS NULL)
OR (work_packages.estimated_hours != work_package_journals.estimated_hours)
OR (work_packages.estimated_hours IS NULL AND work_package_journals.estimated_hours IS NOT NULL)
OR (work_packages.estimated_hours IS NOT NULL AND work_package_journals.estimated_hours IS NULL)
OR (work_packages.start_date != work_package_journals.start_date)
OR (work_packages.start_date IS NULL AND work_package_journals.start_date IS NOT NULL)
OR (work_packages.start_date IS NOT NULL AND work_package_journals.start_date IS NULL)
OR (work_packages.parent_id != work_package_journals.parent_id)
OR (work_packages.parent_id IS NULL AND work_package_journals.parent_id IS NOT NULL)
OR (work_packages.parent_id IS NOT NULL AND work_package_journals.parent_id IS NULL)
OR (work_packages.responsible_id != work_package_journals.responsible_id)
OR (work_packages.responsible_id IS NULL AND work_package_journals.responsible_id IS NOT NULL)
OR (work_packages.responsible_id IS NOT NULL AND work_package_journals.responsible_id IS NULL)
OR (work_packages.budget_id != work_package_journals.budget_id)
OR (work_packages.budget_id IS NULL AND work_package_journals.budget_id IS NOT NULL)
OR (work_packages.budget_id IS NOT NULL AND work_package_journals.budget_id IS NULL)
OR (work_packages.story_points != work_package_journals.story_points)
OR (work_packages.story_points IS NULL AND work_package_journals.story_points IS NOT NULL)
OR (work_packages.story_points IS NOT NULL AND work_package_journals.story_points IS NULL)
OR (work_packages.remaining_hours != work_package_journals.remaining_hours)
OR (work_packages.remaining_hours IS NULL AND work_package_journals.remaining_hours IS NOT NULL)
OR (work_packages.remaining_hours IS NOT NULL AND work_package_journals.remaining_hours IS NULL)
OR (work_packages.derived_estimated_hours != work_package_journals.derived_estimated_hours)
OR (work_packages.derived_estimated_hours IS NULL AND work_package_journals.derived_estimated_hours IS NOT NULL)
OR (work_packages.derived_estimated_hours IS NOT NULL AND work_package_journals.derived_estimated_hours IS NULL)
OR (work_packages.schedule_manually != work_package_journals.schedule_manually)
OR (work_packages.schedule_manually IS NULL AND work_package_journals.schedule_manually IS NOT NULL)
OR (work_packages.schedule_manually IS NOT NULL AND work_package_journals.schedule_manually IS NULL)
OR REGEXP_REPLACE(COALESCE(work_packages.description,''), '\r\n', '
', 'g') !=
REGEXP_REPLACE(COALESCE(work_package_journals.description,''), '\r\n', '
', 'g')
)
) data_changes
FULL JOIN
(SELECT
max_journals.journable_id
FROM
max_journals
LEFT OUTER JOIN
customizable_journals
ON
customizable_journals.journal_id = max_journals.id
FULL JOIN
(SELECT *
FROM custom_values
WHERE custom_values.customized_id = 64 AND custom_values.customized_type = 'WorkPackage') custom_values
ON
custom_values.custom_field_id = customizable_journals.custom_field_id
WHERE
(custom_values.value IS NULL AND customizable_journals.value IS NOT NULL)
OR (customizable_journals.value IS NULL AND custom_values.value IS NOT NULL AND custom_values.value != '')
OR (REGEXP_REPLACE(COALESCE(customizable_journals.value,''), '\r\n', '
', 'g') !=
REGEXP_REPLACE(COALESCE(custom_values.value,''), '\r\n', '
', 'g'))
) customizable_changes
ON
customizable_changes.journable_id = data_changes.journable_id
FULL JOIN
(SELECT
max_journals.journable_id
FROM
max_journals
LEFT OUTER JOIN
attachable_journals
ON
attachable_journals.journal_id = max_journals.id
FULL JOIN
(SELECT *
FROM attachments
WHERE attachments.container_id = 64 AND attachments.container_type = 'WorkPackage') attachments
ON
attachments.id = attachable_journals.attachment_id
WHERE
(attachments.id IS NULL AND attachable_journals.attachment_id IS NOT NULL)
OR (attachable_journals.attachment_id IS NULL AND attachments.id IS NOT NULL)
) attachable_changes
ON
attachable_changes.journable_id = data_changes.journable_id

), insert_data AS (
INSERT INTO
work_package_journals (
type_id, project_id, subject, due_date, category_id, status_id, assigned_to_id, priority_id, version_id, author_id, done_ratio, estimated_hours, start_date, parent_id, responsible_id, budget_id, story_points, remaining_hours, derived_estimated_hours, schedule_manually, description
)
SELECT
type_id, project_id, subject, due_date, category_id, status_id, assigned_to_id, priority_id, version_id, author_id, done_ratio, estimated_hours, start_date, parent_id, responsible_id, budget_id, story_points, remaining_hours, derived_estimated_hours, schedule_manually, REGEXP_REPLACE(COALESCE(description,''), '\r\n', '
', 'g')
FROM work_packages
LEFT OUTER JOIN
(
SELECT from_id parent_id, to_id FROM "relations" WHERE "relations"."hierarchy" != 0 AND "relations"."relates" = 0 AND "relations"."duplicates" = 0 AND "relations"."follows" = 0 AND "relations"."blocks" = 0 AND "relations"."includes" = 0 AND "relations"."requires" = 0 AND (hierarchy + relates + duplicates + follows + blocks + includes + requires = 1) AND "relations"."to_id" = 64 LIMIT 1
) parent_relation
ON
work_packages.id = parent_relation.to_id

WHERE
work_packages.id = 64
AND EXISTS (SELECT * FROM changes)
RETURNING *

), inserted_journal AS (
INSERT INTO
journals (
journable_id,
journable_type,
version,
activity_type,
user_id,
notes,
created_at,
updated_at,
data_id,
data_type
)
SELECT
64,
'WorkPackage',
COALESCE(max_journals.version, 0) + 1,
'work_packages',
4,
'',
'2022-02-17 16:31:03.716745',
'2022-02-17 16:31:03.716745',
insert_data.id,
'Journal::WorkPackageJournal'
FROM max_journals, insert_data
RETURNING *

), insert_attachable AS (
INSERT INTO
attachable_journals (
journal_id,
attachment_id,
filename
)
SELECT
(SELECT id FROM inserted_journal),
attachments.id,
attachments.file
FROM attachments
WHERE
EXISTS (SELECT * from inserted_journal)
AND attachments.container_id = 64
AND attachments.container_type = 'WorkPackage'

), insert_customizable AS (
INSERT INTO
customizable_journals (
journal_id,
custom_field_id,
value
)
SELECT
(SELECT id FROM inserted_journal),
custom_values.custom_field_id,
REGEXP_REPLACE(COALESCE(custom_values.value,''), '\r\n', '
', 'g')
FROM custom_values
WHERE
EXISTS (SELECT * from inserted_journal)
AND custom_values.customized_id = 64
AND custom_values.customized_type = 'WorkPackage'
AND custom_values.value IS NOT NULL
AND custom_values.value != ''

)

SELECT * from inserted_journal

D, [2022-02-17T17:31:03.925837 #589558] DEBUG -- : [ActiveJob] Delayed::Backend::ActiveRecord::Job Create (1.8ms) INSERT INTO "delayed_jobs" ("priority", "handler", "run_at", "created_at", "updated_at", "queue") VALUES ($1, $2, $3, $4, $5, $6) RETURNING "id" [["priority", 5], ["handler", "--- !ruby/object:ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper\njob_data:\n job_class: Notifications::WorkflowJob\n job_id: e805660e-bf75-4d26-b645-62e578b9f31f\n provider_job_id:\n queue_name: default\n priority: 5\n arguments:\n - _aj_serialized: ActiveJob::Serializers::SymbolSerializer\n value: create_notifications\n - _aj_globalid: gid://open-project/Journal/181\n - true\n executions: 0\n exception_executions: {}\n locale: en\n timezone: UTC\n enqueued_at: '2022-02-17T16:31:03Z'\n"], ["run_at", "2022-02-17 16:31:03.921616"], ["created_at", "2022-02-17 16:31:03.921819"], ["updated_at", "2022-02-17 16:31:03.921819"], ["queue", "default"]]
I, [2022-02-17T17:31:03.926806 #589558] INFO -- : [ActiveJob] Enqueued Notifications::WorkflowJob (Job ID: e805660e-bf75-4d26-b645-62e578b9f31f) to DelayedJob(default)
D, [2022-02-17T17:31:03.927691 #589558] DEBUG -- : [ActiveJob] Enqueuing background job #<Notifications::WorkflowJob:0x0000561d3a556178 @arguments=[:create_notifications, #<Journal id: 181, journable_type: "WorkPackage", journable_id: 64, user_id: 4, notes: "", created_at: "2022-02-17 16:31:03.716745000 +0000", version: 1, activity_type: "work_packages", updated_at: "2022-02-17 16:31:03.716745000 +0000", data_type: "Journal::WorkPackageJournal", data_id: 121>, true], @job_id="e805660e-bf75-4d26-b645-62e578b9f31f", @queue_name="default", @priority=5, @executions=0, @exception_executions={}, @timezone="UTC", @provider_job_id=375>
D, [2022-02-17T17:31:03.948862 #589558] DEBUG -- : [ActiveJob] Delayed::Backend::ActiveRecord::Job Create (1.4ms) INSERT INTO "delayed_jobs" ("priority", "handler", "run_at", "created_at", "updated_at", "queue") VALUES ($1, $2, $3, $4, $5, $6) RETURNING "id" [["priority", 5], ["handler", "--- !ruby/object:ActiveJob::QueueAdapters::DelayedJobAdapter::JobWrapper\njob_data:\n job_class: Journals::CompletedJob\n job_id: 72d96af1-ec71-4d2b-b3fc-05fac1938866\n provider_job_id:\n queue_name: default\n priority: 5\n arguments:\n - 181\n - true\n executions: 0\n exception_executions: {}\n locale: en\n timezone: UTC\n enqueued_at: '2022-02-17T16:31:03Z'\n"], ["run_at", "2022-02-17 16:36:03.937583"], ["created_at", "2022-02-17 16:31:03.945396"], ["updated_at", "2022-02-17 16:31:03.945396"], ["queue", "default"]]
I, [2022-02-17T17:31:03.949902 #589558] INFO -- : [ActiveJob] Enqueued Journals::CompletedJob (Job ID: 72d96af1-ec71-4d2b-b3fc-05fac1938866) to DelayedJob(default) at 2022-02-17 16:36:03 UTC
D, [2022-02-17T17:31:03.950125 #589558] DEBUG -- : [ActiveJob] Enqueuing background job #<Journals::CompletedJob:0x0000561d3b5748c0 @arguments=[181, true], @job_id="72d96af1-ec71-4d2b-b3fc-05fac1938866", @queue_name="default", @priority=5, @executions=0, @exception_executions={}, @timezone="UTC", @scheduled_at=1645115763.937584, @provider_job_id=376>
D, [2022-02-17T17:31:03.963689 #589558] DEBUG -- : WorkPackage Load (6.1ms) SELECT "work_packages".* FROM "work_packages" WHERE (id IN (WITH
RECURSIVE
to_schedule (id, manually) AS (
SELECT * FROM (VALUES(64, false)) AS t(id, manually)

UNION

SELECT
CASE
WHEN relations.to_id = to_schedule.id
THEN relations.from_id
ELSE relations.to_id
END id,
(work_packages.schedule_manually OR COALESCE(descendants.schedule_manually, false)) manually
FROM
to_schedule
JOIN
relations
ON NOT to_schedule.manually
AND ("relations"."relates" = 0 AND "relations"."duplicates" = 0 AND "relations"."blocks" = 0 AND "relations"."includes" = 0 AND "relations"."requires" = 0
AND (relations.hierarchy + relations.relates + relations.duplicates + relations.follows + relations.blocks + relations.includes + relations.requires = 1)
)
AND
((relations.to_id = to_schedule.id)
OR (relations.from_id = to_schedule.id AND relations.follows = 0))
LEFT JOIN work_packages
ON (CASE
WHEN relations.to_id = to_schedule.id
THEN relations.from_id
ELSE relations.to_id
END) = work_packages.id
LEFT JOIN (
SELECT
relations.from_id,
bool_and(COALESCE(work_packages.schedule_manually, false)) schedule_manually
FROM relations relations
JOIN work_packages
ON
work_packages.id = relations.to_id
AND relations.follows = 0 AND "relations"."relates" = 0 AND "relations"."duplicates" = 0 AND "relations"."blocks" = 0 AND "relations"."includes" = 0 AND "relations"."requires" = 0
AND (relations.hierarchy + relations.relates + relations.duplicates + relations.follows + relations.blocks + relations.includes + relations.requires >= 1)

GROUP BY relations.from_id
) descendants ON work_packages.id = descendants.from_id
)

SELECT id
FROM to_schedule
WHERE
NOT to_schedule.manually
)) AND "work_packages"."id" != $1 [["id", 64]]
D, [2022-02-17T17:31:03.979022 #589558] DEBUG -- : WorkPackageCustomField Load (1.9ms) SELECT "custom_fields".* FROM "custom_fields" WHERE "custom_fields"."type" = $1 AND ("custom_fields"."is_for_all" = $2 OR "custom_fields"."id" IN (SELECT "custom_fields"."id" FROM "custom_fields" INNER JOIN "custom_fields_projects" ON "custom_fields"."id" = "custom_fields_projects"."custom_field_id" WHERE "custom_fields"."type" = $3 AND "custom_fields_projects"."project_id" = $4 ORDER BY custom_fields.position)) ORDER BY custom_fields.position [["type", "WorkPackageCustomField"], ["is_for_all", true], ["type", "WorkPackageCustomField"], ["project_id", 3]]
D, [2022-02-17T17:31:03.987571 #589558] DEBUG -- : Inserting new journal for WorkPackage #64
D, [2022-02-17T17:31:04.009225 #589558] DEBUG -- : (11.1ms) WITH max_journals AS (
SELECT
64 journable_id,
'WorkPackage' journable_type,
COALESCE(journals.version, fallback.version) AS version,
COALESCE(journals.id, 0) id,
COALESCE(journals.data_id, 0) data_id
FROM
journals
RIGHT OUTER JOIN
(SELECT 0 AS version) fallback
ON
journals.journable_id = 64
AND journals.journable_type = 'WorkPackage'
AND journals.version IN (SELECT MAX(version) FROM journals WHERE journable_id = 64 AND journable_type = 'WorkPackage')

WHERE
work_packages.id = 64
AND EXISTS (SELECT * FROM changes)
RETURNING *

)

SELECT * from inserted_journal

D, [2022-02-17T17:31:04.021230 #589558] DEBUG -- : WorkPackage Load (2.5ms) SELECT DISTINCT "work_packages".* FROM "work_packages" INNER JOIN "relations" ON "work_packages"."id" = "relations"."from_id" WHERE "relations"."to_id" = $1 AND "relations"."hierarchy" != $2 AND "relations"."relates" = $3 AND "relations"."duplicates" = $4 AND "relations"."follows" = $5 AND "relations"."blocks" = $6 AND "relations"."includes" = $7 AND "relations"."requires" = $8 [["to_id", 64], ["hierarchy", 0], ["relates", 0], ["duplicates", 0], ["follows", 0], ["blocks", 0], ["includes", 0], ["requires", 0]]
D, [2022-02-17T17:31:04.022524 #589558] DEBUG -- : Ignoring setting journal notifications to 'false' as a parent block already set it to #<Concurrent::ThreadLocalVar:0x0000561d415a7030>"

D, [2022-02-17T17:31:04.064023 #589558] DEBUG -- : User Exists? (2.3ms) SELECT 1 AS one FROM "users" INNER JOIN "watchers" ON "users"."id" = "watchers"."user_id" WHERE "users"."type" IN ($1, $2, $3, $4) AND "watchers"."watchable_id" = $5 AND "watchers"."watchable_type" = $6 AND "users"."id" = $7 LIMIT $8 [["type", "User"], ["type", "AnonymousUser"], ["type", "SystemUser"], ["type", "DeletedUser"], ["watchable_id", 64], ["watchable_type", "WorkPackage"], ["id", 4], ["LIMIT", 1]]
D, [2022-02-17T17:31:04.068733 #589558] DEBUG -- : Watcher Exists? (1.4ms) SELECT 1 AS one FROM "watchers" WHERE "watchers"."user_id" = $1 AND "watchers"."watchable_type" = $2 AND "watchers"."watchable_id" = $3 LIMIT $4 [["user_id", 4], ["watchable_type", "WorkPackage"], ["watchable_id", 64], ["LIMIT", 1]]
D, [2022-02-17T17:31:04.115491 #589558] DEBUG -- : SQL (4.4ms) SELECT "roles"."id" AS t0_r0, "roles"."name" AS t0_r1, "roles"."position" AS t0_r2, "roles"."assignable" AS t0_r3, "roles"."builtin" AS t0_r4, "roles"."type" AS t0_r5, "roles"."created_at" AS t0_r6, "roles"."updated_at" AS t0_r7, "role_permissions"."id" AS t1_r0, "role_permissions"."permission" AS t1_r1, "role_permissions"."role_id" AS t1_r2, "role_permissions"."created_at" AS t1_r3, "role_permissions"."updated_at" AS t1_r4 FROM "roles" LEFT OUTER JOIN "role_permissions" ON "role_permissions"."role_id" = "roles"."id" WHERE "roles"."id" IN (SELECT "roles"."id" FROM "users" LEFT OUTER JOIN "members" ON "users"."id" = "members"."user_id" AND "members"."project_id" = 3 LEFT OUTER JOIN "member_roles" ON "members"."id" = "member_roles"."member_id" LEFT OUTER JOIN "roles" ON "roles"."id" = "member_roles"."role_id" WHERE "users"."id" = 4)
D, [2022-02-17T17:31:04.119579 #589558] DEBUG -- : TRANSACTION (2.4ms) COMMIT
D, [2022-02-17T17:31:04.132037 #589558] DEBUG -- : TRANSACTION (0.7ms) BEGIN
D, [2022-02-17T17:31:04.197163 #589558] DEBUG -- : User Load (1.4ms) SELECT "users".* FROM "users" WHERE "users"."type" IN ($1, $2, $3, $4) AND "users"."id" = $5 LIMIT $6 [["type", "User"], ["type", "AnonymousUser"], ["type", "SystemUser"], ["type", "DeletedUser"], ["id", 0], ["LIMIT", 1]]
D, [2022-02-17T17:31:04.204108 #589558] DEBUG -- : TRANSACTION (0.8ms) ROLLBACK
I, [2022-02-17T17:31:04.210742 #589558] INFO -- : MailHandler: Failed to add attachment neo.matrix.net for [martin.meier@aon.at]: may not be accessed.
I, [2022-02-17T17:31:04.211296 #589558] INFO -- : MailHandler: work_package #64 created by Anonymous
D, [2022-02-17T17:31:04.211426 #589558] DEBUG -- : Message 26 successfully received

Please excuse the long log :-) Still the MailHandler says: failed to add attachment -> can it be due to different domains? matrix.net vs. aon.at?

many thx in advance for your support,

Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

Thank you Martin

now we have first of all an exact log

second we do not see the email, so we need to see the email and the attachment, otherwise we would not know if the attachment can be the issue, or the email

the error messages seems to me to be caused by gmx... so maybe did you ask them already?

maybe register a free gmail address and test with gmail instead of gmx... i understood later you would like to run it on gmail

please show the email in a format that you could attach here, get inspired by the following link

screenshots from your email client would also help to understand what you are doing, please share the email

https://support.gmx.com/email/receiving-and-reading/header.html#indexlink_help_email_receiving-and-reading

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

OK understood - many thx. I have tried with a new mailbox from gmail now. Openproject is retrieving email but also via gmail account the attachment is not included in the created ticket. Please find attached the corresponding email (plain text). I have created this email directly in gmail webmail, and added a pdf file to it as a test (please see also screenshot).

Best Regards, Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

Hi Martin

I just retested the thing on my end

so here my command from crontab, this time i ran it manually with user root... (my mistake sorry)

root@antproject:/# openproject run bundle exec rake redmine:email:receive_imap host='imap.gmail.com' username='openproject@mydomain.tld' password='DELETED' port=993 ssl=true allow_override=type,project,status

my Attachment was called Fehlermeldung.pdf

i did a search on the complete openproject host:

root@antproject:/# find / | grep Fehlermeldung.pdf
/tmp/Fehlermeldung.pdf20220221-7806-1y8q2lw
/tmp/Fehlermeldung.pdf20220221-7806-1y8q2lw/Fehlermeldung.pdf
/var/db/openproject/files/attachment/file/5/Fehlermeldung.pdf

now i check the rights structures of all involved folders

please show your system accordingly with the same commands replacing the Fehlermeldung.pdf with Cube-Booster-German.pdf

root@antproject:/# find / | grep Fehlermeldung.pdf | xargs ls -laZ
-rw-r--r-- 1 openproject openproject ? 136252 Feb 21 08:35 /tmp/Fehlermeldung.pdf20220221-7806-1y8q2lw/Fehlermeldung.pdf
-rw-r--r-- 1 openproject openproject ? 136252 Feb 21 08:35 /var/db/openproject/files/attachment/file/5/Fehlermeldung.pdf

/tmp/Fehlermeldung.pdf20220221-7806-1y8q2lw:
total 152
drwxr-xr-x  2 openproject openproject ?   4096 Feb 21 08:35 .
drwxrwxrwt 16 root        root        ?  12288 Feb 21 08:35 ..
-rw-r--r--  1 openproject openproject ? 136252 Feb 21 08:35 Fehlermeldung.pdf

One additional question, what is your host system? CentOS / Redhat? Selinux maybe tricking you?

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

Hi Adam,

many thx for a test on your side :-)

I have reproduced it on my side - here are the results:

a) I tried based on your crontab command another test on my Linux:

root@neo:/# openproject run bundle exec rake redmine:email:receive_imap host='imap.gmail.com' username='MYMAILBOX' password='DELETED' port=993 ssl=true allow_override=type,project,status --trace
** Invoke redmine:email:receive_imap (first_time)
** Invoke environment (first_time)
** Execute environment
D, [2022-02-21T14:27:59.126616 #718916] DEBUG -- : (2.6ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
D, [2022-02-21T14:27:59.559137 #718916] DEBUG -- : Increasing database pool size to 17 to match max threads
D, [2022-02-21T14:27:59.723496 #718916] DEBUG -- : (1.0ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-21T14:27:59.726042 #718916] DEBUG -- : (0.9ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-21T14:28:00.084731 #718916] DEBUG -- : (2.2ms) SELECT MAX("settings"."updated_at") FROM "settings"
D, [2022-02-21T14:28:00.085884 #718916] DEBUG -- : Dalli::Server#connect 127.0.0.1:11211
D, [2022-02-21T14:28:00.351228 #718916] DEBUG -- : Enabling Rack::Timeout (service=120s wait=10s)
D, [2022-02-21T14:28:01.918321 #718916] DEBUG -- : incoming webhook registered: github
D, [2022-02-21T14:28:07.229502 #718916] DEBUG -- : (0.7ms) SET SESSION CHARACTERISTICS AS TRANSACTION ISOLATION LEVEL READ COMMITTED
D, [2022-02-21T14:28:07.248312 #718916] DEBUG -- : (2.6ms) SELECT "schema_migrations"."version" FROM "schema_migrations" ORDER BY "schema_migrations"."version" ASC
** Execute redmine:email:receive_imap
root@neo:/#

b) then I was looking for the .pdf location and checked access rights:

root@neo:/# find / | grep Cube-Booster-German.pdf | xargs ls -laZ
find: ‘/run/user/1000/gvfs’: Keine Berechtigung
find: ‘/data_500GB/.Spotlight-V100/Store-V2/387C1C4A-482C-4723-AD75-E866246CECFE’: Eingabe-/Ausgabefehler
-rw-rw-r-- 1 openproject openproject ? 5676261 Feb 18 10:15 /tmp/Cube-Booster-German.pdf20220218-623278-1dqqb0o/Cube-Booster-German.pdf
-rw-rw-r-- 1 openproject openproject ? 5676261 Feb 21 14:27 /tmp/Cube-Booster-German.pdf20220221-718889-13koxv8/Cube-Booster-German.pdf
-rw-r--r-- 1 openproject openproject ? 5676261 Feb 18 10:15 /tmp/op_uploaded_files/1645175746-623278-0001-8156/Cube-Booster-German.pdf
-rw-r--r-- 1 openproject openproject ? 5676261 Feb 21 14:27 /tmp/op_uploaded_files/1645450070-718889-0001-1441/Cube-Booster-German.pdf

/tmp/Cube-Booster-German.pdf20220218-623278-1dqqb0o:
insgesamt 5560
drwxrwxr-x 2 openproject openproject ? 4096 Feb 18 10:15 .
drwxrwxrwt 132 root root ? 12288 Feb 21 14:27 ..
-rw-rw-r-- 1 openproject openproject ? 5676261 Feb 18 10:15 Cube-Booster-German.pdf

/tmp/Cube-Booster-German.pdf20220221-718889-13koxv8:
insgesamt 5560
drwxrwxr-x 2 openproject openproject ? 4096 Feb 21 14:27 .
drwxrwxrwt 132 root root ? 12288 Feb 21 14:27 ..
-rw-rw-r-- 1 openproject openproject ? 5676261 Feb 21 14:27 Cube-Booster-German.pdf
root@neo:/#

So, compared with your output, I think I am missing a proper file (.pdf) in /var/db/openproject/files/attachment/

My hostsystem seems to be really a tricky one :-) it is an Ubuntu Linux (5.13.0-27-generic #29~20.04.1-Ubuntu)

Best Regards, Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

HI Martin

you see, please issue and share output

ls -laZ /var/db/openproject/files/attachment/

i run the same ubuntu :) so i would not state its tricky, its just a linux :)

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier over 2 years ago

Hi Adam,

here you find my output - you are right :-)

root@neo:/# ls -laZ /var/db/openproject/files/attachment/
insgesamt 12
drwxr-xr-x  3 openproject openproject ? 4096 Jän 12 19:55 .
drwxr-xr-x  3 openproject openproject ? 4096 Jän 12 19:55 ..
drwxr-xr-x 19 openproject openproject ? 4096 Feb 16 12:58 file
root@neo:/#

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

Hello Martin,

let's see who is the user who is running openproject...

did you not get any issues in the syslog during the mail collection?

I really suppose that this is be just another linux issue JALI :)

ant0n@antproject:~$ ps -aux | grep openproject
openpro+     834  0.0  8.8 480916 357800 ?       Sl   Feb20   0:59 puma 5.5.2 (tcp://127.0.0.1:6000) [openproject]
openpro+     842  0.1  9.7 546400 393200 ?       Sl   Feb20   2:44 /opt/openproject/vendor/bundle/ruby/2.7.0/bin/rake jobs:work
postgres    1106  0.0  0.4 217664 17156 ?        Ss   Feb20   0:00 postgres: 13/main: openproject openproject 127.0.0.1(33294) idle
postgres    1107  0.0  0.8 223292 32220 ?        Ss   Feb20   0:37 postgres: 13/main: openproject openproject 127.0.0.1(33296) idle
openpro+    1108  0.0  9.8 499608 395576 ?       Sl   Feb20   0:46 puma: cluster worker 0: 834 [openproject]
openpro+    1111  0.0  9.9 499608 399780 ?       Sl   Feb20   0:55 puma: cluster worker 1: 834 [openproject]
postgres   19117  0.0  0.5 218184 22012 ?        Ss   11:42   0:00 postgres: 13/main: openproject openproject 127.0.0.1(36180) idle
postgres   19183  0.0  0.5 218184 22012 ?        Ss   11:53   0:00 postgres: 13/main: openproject openproject 127.0.0.1(36214) idle
ant0n      19358  0.0  0.0   6432   668 pts/0    S+   11:59   0:00 grep --color=auto openproject

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier over 2 years ago

Hi Adam,

I do hope so :-)

please find below my shell output:

root@neo:/# ps -aux | grep openproject
openpro+  591716  0.0  4.8 541780 382868 ?       Sl   Feb17   1:54 puma 5.5.2 (tcp://127.0.0.1:6000) [openproject]
openpro+  591717  0.1  4.9 553512 388428 ?       Sl   Feb17  10:08 /opt/openproject/vendor/bundle/ruby/2.7.0/bin/rake jobs:work
postgres  591733  0.0  0.3 235000 30536 ?        Ss   Feb17   3:02 postgres: 13/main: openproject openproject 127.0.0.1(36524) idle
postgres  591734  0.0  0.2 229816 16028 ?        Ss   Feb17   0:00 postgres: 13/main: openproject openproject 127.0.0.1(36526) idle
openpro+  591735  0.0  5.3 560472 420720 ?       Sl   Feb17   1:47 puma: cluster worker 0: 591716 [openproject]
openpro+  591741  0.0  5.2 560352 419496 ?       Sl   Feb17   1:47 puma: cluster worker 1: 591716 [openproject]
root      746238  0.0  0.0  17692  2728 pts/0    S+   12:31   0:00 grep --color=auto openproject
root@neo:/#

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

Good day Martin

to sum up:

until now everything on your environment looks same like on my environment
the attachment is downloaded to the /tmp folder in both our cases
in your environment the attachment is not moved from /tmp to /var/db/openproject/files/attachment/
your log contains the following (interesting it is an INFO log not an ERROR so this is just for your kind information that you have not the right permissions)
i guess the issue may be that the user who writes the email is not allowed to add attachments to the project? could you check your access rights?

your log:

I, [2022-02-17T17:31:04.210742 #589558]  INFO -- : MailHandler: Failed to add attachment neo.matrix.net for [martin.meier@aon.at]: may not be accessed.
I, [2022-02-17T17:31:04.211296 #589558]  INFO -- : MailHandler: work_package #64 created by Anonymous

my log:

your first INFO line is missing in my DEBUG log
I, [2022-02-23T09:57:41.844903 #27840]  INFO -- : MailHandler: work_package #44 created by [MY NAME REMOVED]

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier over 2 years ago

Dear Adam!

a BIG THANK you for your continuous support. You have been right, the user rights have been set correct, but the "username" was wrong. Openproject was accepting emails from user "martinmeier@aon.at" -> the point between martin and meier was missing OMG....

I corrected it and perfect -> it is now working and attachments are in the ticket.

Again I really thank you for your gr8 help Adam!

all the best, Martin

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

You are very welcome Martin

Top Menu

Side Menu

Content

Replies (21)

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier almost 3 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier over 2 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier over 2 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago

RE: Configuring inbound emails - attachments are missing - Added by Martin Meier over 2 years ago

RE: Configuring inbound emails - attachments are missing - Added by Adam Szabo over 2 years ago