Seeing "Could not create new lock" messages after migrating lists from old Sympa to new Sympa server

UAProfessorProton commented 3 months ago

I'm getting multiple lines below and I suspect these come from the lists I just moved from an older sympa server.

wwsympa[2041]: err main::#1562 > main::do_create_list_request#9638 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock

I would like to know how I can identify the lists that are causing theses messages to appear. All lists are owned by sympa:sympa and have 755 permissions.

Version

Sympa 6.2.72

Installation method

rpm method

Expected behavior

I'm not supposed to see the following messages: wwsympa[2041]: err main::#1562 > main::do_create_list_request#9638 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock

Actual behavior

I'm getting multiple lines below and I suspect these come from the lists I just moved from an older sympa server.

wwsympa[2041]: err main::#1562 > main::do_create_list_request#9638 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock

I would like to know how I can identify the lists that are causing theses messages to appear. All lists are owned by sympa:sympa and have 755 permissions.

Additional information

/sympa/list_data is mounted from NFS. there's only node mounting this filesystem.

Attempt to resolve the issue

Stopped sympa services
Ran "find /sympa/list_data -name "lock" -exec rm {} \;" to remove potential lock files.
Started services
Same messages start to appear when I start creating a list from the web console.

What should be the required permissions and ownerships?

UAProfessorProton commented 3 months ago

Also seeing these when it comes to tasks:

Mar 27 15:36:55 sympa-i-0709b02d07d5596dc task_manager[1442]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock Mar 27 15:36:55 sympa-i-0709b02d07d5596dc task_manager[1442]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock Mar 27 15:36:56 sympa-i-0709b02d07d5596dc task_manager[1442]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock Mar 27 15:36:56 sympa-i-0709b02d07d5596dc task_manager[1442]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4668 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock

ikedas commented 3 months ago

Hi @UAProfessorProton , What is the type of storage you are mounting through NFS?

UAProfessorProton commented 3 months ago

Hi @ikedas

Yes /sympa is an NFS mount.

127.0.0.1:/ on /sympa type nfs4 (rw,relatime,vers=4.1,rsize=1048576,wsize=1048576,namlen=255,hard,noresvport,proto=tcp,port=20557,timeo=600,retrans=2,sec=sys,clientaddr=127.0.0.1,local_lock=none,addr=127.0.0.1,_netdev)

ikedas commented 3 months ago

I understand that your Sympa accesses filesystem with NFS mount. What I want to know is that, what is the type of the remote storage that you are mounting through the NFS?

UAProfessorProton commented 3 months ago

@ikedas thank you for your response. We are using cloud storage (Amazon EFS) to mount /sympa via NFS. The sympa server belong in the same VPC as the EFS server.

ikedas commented 3 months ago

If the operating system is RHEL or its clone, have you disabled SELinux?

UAProfessorProton commented 3 months ago

Hi @ikedas, yes SELINUX is already disabled

[root@sympa-i-0709b02d07d5596dc log]# getenforceDisabled [root@sympa-i-0709b02d07d5596dc log]# uname -a;dateLinux sympa-i-0709b02d07d5596dc 5.10.210-201.852.amzn2.x86_64 #1 SMP Tue Feb 27 17:09:32 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux Mon Apr 1 08:39:27 MST 2024.

Apr 1 04:14:14 sympa-i-0709b02d07d5596dc task_manager[1442]: err main::#148 > Sympa::Spindle::spin#83 > Sympa::Spindle::ProcessTask::_twist#74 > Sympa::Spindle::ProcessTask::_execute#140 > Sympa::Spindle::ProcessTask::_cmd_process#174> Sympa::Spindle::ProcessTask::do_sync_include#1347 > Sympa::List::sync_include#4156 > Sympa::Spindle::spin#95 > Sympa::Request::Handler::include::_twist#213 > Sympa::Request::Handler::include::_update_users#387 > Sympa::DataSource::open#112 > Sympa::DataSource::List::_open#60 > Sympa::List::new#181 > Sympa::List::load#707 Could not create new lock

Even tasks are having errors. I'm running this on Amazon Linux 2. Is there a way to identify the path where it is trying to create the locked file? I tried to set to log_level=4 but the path is still not provided.

ikedas commented 2 months ago

Please apply this patch, try again and show what you see in the log.

UAProfessorProton commented 2 months ago

Thank you for your response. I would like to ask if this patch will also apply if Sympa was installed from the EPEL yum repo. The lib files are located in /usr/share/sympa/lib/Sympa.

ikedas commented 2 months ago

Yes, it will apply. If you want to confirm, run patch -p2 -d /usr/share/sympa --dry-run < patchfile Then omit --dry-run option when you will really apply it.

UAProfessorProton commented 2 months ago

Thank you for the patch, I attempted to recreate the issue and found the following messages. Looks like it's saying permission-related but doesn't say the path...

Apr 9 08:22:36 sympa-i-0709b02d07d5596dc wwsympa[31475]: err main::#1562 > main::do_lists#4169 > Sympa::List::get_lists#4684 > Sympa::List::new#181 > Sympa::List::load#719 Could not create new lock: Permission denied Apr 9 08:22:37 sympa-i-0709b02d07d5596dc task_manager[31476]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4684 >Sympa::List::new#181 > Sympa::List::load#719 Could not create new lock: Permission denied Apr 9 08:22:37 sympa-i-0709b02d07d5596dc wwsympa[31475]: err main::#1562 > main::do_lists#4169 > Sympa::List::get_lists#4684 > Sympa::List::new#181 > Sympa::List::load#719 Could not create new lock: Permission denied Apr 9 08:22:37 sympa-i-0709b02d07d5596dc task_manager[31476]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4684 >Sympa::List::new#181 > Sympa::List::load#719 Could not create new lock: Permission denied Apr 9 08:22:37 sympa-i-0709b02d07d5596dc wwsympa[31475]: err main::#1562 > main::do_lists#4169 > Sympa::List::get_lists#4684 > Sympa::List::new#181 > Sympa::List::load#719 Could not create new lock: Permission denied Apr 9 08:22:37 sympa-i-0709b02d07d5596dc task_manager[31476]: err main::#148 > Sympa::Spindle::spin#78 > Sympa::Spool::next#124 > Sympa::Spool::Task::_load#57 > Sympa::Spool::Task::_create_all_tasks#93 > Sympa::List::get_lists#4684 >Sympa::List::new#181 > Sympa::List::load#719 Could not create new lock: Permission denied [root@sympa-i-0709b02d07d5596dc sympa]#

I made sure that the spool directory is owned by sympa and have 775 permissions:

[root@sympa-i-0709b02d07d5596dc sympa]# find /sympa/spool -type d -exec ls -ld {} \; drwxrwxr-x 8 sympa sympa 6144 Feb 15 14:22 /sympa/spool drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:07 /sympa/spool/digest drwxrwxr-x 9 sympa sympa 6144 Feb 9 17:07 /sympa/spool/us-west-2a drwxrwxr-x 3 sympa sympa 6144 Mar 26 15:25 /sympa/spool/us-west-2a/outgoing drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:08 /sympa/spool/us-west-2a/outgoing/bad drwxrwxr-x 3 sympa sympa 6144 Feb 9 17:08 /sympa/spool/us-west-2a/bounce drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:08 /sympa/spool/us-west-2a/bounce/bad drwxrwxr-x 2 sympa sympa 137216 Apr 9 07:59 /sympa/spool/us-west-2a/task drwxrwxr-x 3 sympa sympa 6144 Feb 9 17:08 /sympa/spool/us-west-2a/automatic drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:08 /sympa/spool/us-west-2a/automatic/bad drwxrwxr-x 4 sympa sympa 6144 Mar 27 10:48 /sympa/spool/us-west-2a/msg drwxrwxr-x 2 sympa sympa 6144 Mar 27 10:48 /sympa/spool/us-west-2a/msg/moved drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:08 /sympa/spool/us-west-2a/msg/bad drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:07 /sympa/spool/us-west-2a/distribute drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:07 /sympa/spool/us-west-2a/topic drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:07 /sympa/spool/subscribe drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:07 /sympa/spool/auth drwxrwxr-x 2 sympa sympa 6144 Feb 9 17:07 /sympa/spool/moderation drwxrwxr-x 9 sympa sympa 6144 Feb 15 14:22 /sympa/spool/us-west-2b drwxrwxr-x 3 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/outgoing drwxrwxr-x 2 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/outgoing/bad drwxrwxr-x 3 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/bounce drwxrwxr-x 2 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/bounce/bad drwxrwxr-x 2 sympa sympa 6144 Mar 14 09:08 /sympa/spool/us-west-2b/task drwxrwxr-x 3 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/automatic drwxrwxr-x 2 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/automatic/bad drwxrwxr-x 3 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/msg drwxrwxr-x 2 sympa sympa 6144 Feb 15 14:23 /sympa/spool/us-west-2b/msg/bad drwxrwxr-x 2 sympa sympa 6144 Feb 15 14:22 /sympa/spool/us-west-2b/distribute drwxrwxr-x 2 sympa sympa 6144 Feb 15 14:22 /sympa/spool/us-west-2b/topic

This applies to list_data as well

[root@sympa-i-0709b02d07d5596dc sympa]# find /sympa/list_data -type d -exec ls -ld {} \; drwxrwxr-x 11907 sympa sympa 677888 Mar 26 20:03 /sympa/list_data drwxrwxr-x 4 sympa sympa 6144 Mar 27 15:06 /sympa/list_data/new_envs_majors_ay2023 drwxrwxr-x 2 sympa sympa 6144 Aug 13 2019 /sympa/list_data/new_envs_majors_ay2023/archives drwxrwxr-x 2 sympa sympa 6144 Jun 14 2019 /sympa/list_data/new_envs_majors_ay2023/shared drwxrwxr-x 4 sympa sympa 6144 Mar 27 09:20 /sympa/list_data/tap_computation_data drwxrwxr-x 2 sympa sympa 6144 Oct 20 2021 /sympa/list_data/tap_computation_data/archives drwxrwxr-x 2 sympa sympa 6144 May 29 2020 /sympa/list_data/tap_computation_data/shared

Configuration:

wwsympa.fcgi process is owned by sympa

[root@sympa-i-0709b02d07d5596dc sympa]# ps -ef | grep -i wwsympa | grep -v grep sympa 31475 1 15 08:00 ? 00:03:41 /usr/bin/perl /usr/libexec/sympa/wwsympa.fcgi [root@sympa-i-0709b02d07d5596dc sympa]#

[root@sympa-i-0709b02d07d5596dc sympa]# grep -i ^home /etc/sympa/sympa.conf home /sympa/list_data [root@sympa-i-0709b02d07d5596dc sympa]# date Tue Apr 9 08:26:13 MST 2024

[root@sympa-i-0709b02d07d5596dc sympa]# grep -i spool /etc/sympa/sympa.conf spool /sympa/spool/us-west-2a queue /sympa/spool/us-west-2a/msg queuebounce /sympa/spool/us-west-2a/bounce queuedistribute /sympa/spool/us-west-2a/distribute queueautomatic /sympa/spool/us-west-2a/automatic queuedigest /sympa/spool/digest queuemod /sympa/spool/moderation queuetopic /sympa/spool/us-west-2a/topic queueauth /sympa/spool/auth queueoutgoing /sympa/spool/us-west-2a/outgoing queuetask /sympa/spool/us-west-2a/task queuesubscribe /sympa/spool/subscribe

Appreciate your help on this.

ikedas commented 2 months ago

Please check NFS and mounted file system. Is it configured to allow writing? This seems not a problem of Sympa but of AWS.

UAProfessorProton commented 2 months ago

@ikedas, I looked into this further, the problem seem to have disappeared after I deleted all the mailing lists under /sympa/list_data. I have no issues creating mailing lists after that. I suspect some nfs lock files might have been migrated over the old sympa server since the mailing lists were also copied from NFS, while the sympa service was running. I cannot find it in the documentation or most probably missed it, the naming convention of the lock files being created. Are the lock files created end with .lock file extension names?

ikedas commented 2 months ago

The extension is ,lock instead of .lock.

https://github.com/sympa-community/sympa/blob/4f62c3a6c4d0156d02273f49ab7fd16e9d0d371a/src/lib/Sympa/LockedFile.pm#L40

However it is unlikely that the stale lock was preventing creation of new lock, and something with NFS might cause the problem.

UAProfessorProton commented 2 months ago

This issue is now resolved, thank you for your support.

sympa-community / sympa