Operating system name and version: Ubuntu 10.10
Version of smsd: 3.1.10
Smsd installed from: package repository
Name and model of a modem / phone: Modem details are available at https://www.alibaba.com/product-detail/Alibaba-express-wholesale-bulk-sms-gsm_60073375060.html
Interface: USB

2016-07-26 07:35:08,2, smsd: Conflict with .LOCK file in the spooler: /var/spool/sms/outgoing/103461-20160726-052006.txt /var/spool/sms/MODEM1 2016-07-26 07:35:08,2, smsd: Fatal error: Cannot move /var/spool/sms/outgoing/103461-20160726-052006.txt to /var/spool/sms/MODEM1. Check file and dir permissions. 2016-07-26 07:35:08,2, smsd: Smsd mainprocess terminated abnormally. PID: 3664.

Daily total SMS number is around 2000. Huge number of the SMS's are dropped to SMSTools spool at 01:00 a.m. (around 1000-1300 files) I'm having this issue almost everyday if there is a huge queue. The time of crash is random. All I know is this crash happening while process of this huge queue.

Regarding to this topic (http://smstools3.kekekasvi.com/topic.php?id=557):
Is this problem solved in 3.1.15, should I upgrade or wait for 3.1.16?
Do I need to upgrade the OS?

Hello,

I installed Modem, New OS (Ubuntu server 16.04.1) and most recent SMSTools from repo (3.1.15-1.2) and still getting:

2016-08-26 00:04:14,2, smsd: Conflict with .LOCK file in the spooler: /var/spool/sms/outgoing/190687-20160826-000007.txt /var/spool/sms/ALL 2016-08-26 00:04:14,2, smsd: Fatal error: Cannot move /var/spool/sms/outgoing/190687-20160826-000007.txt to /var/spool/sms/ALL. Check file and dir permissions. 2016-08-26 00:04:14,2, smsd: Smsd mainprocess terminated abnormally. PID: 3056.

Is it possible to, I have conflict problem because of the all modems processing files in one directory?
Should I set separate directories for each modem and let them read files from it's own folder?

Here is my Configuration:

OK, I still can not get any answer but the problem still appearing with different form:

I made changes in the configuration. I disabled other modem instances except  MODEM0  for  ALL  queue.
I lost the "Conflict with .LOCK file" error but "smsd: Fatal error: Cannot move..." error still remaining. Here is my configuration and the last 50 lines of LOG:


2016-08-29 00:17:29,6, MODEM0: Used memory is 0 of 30 2016-08-29 00:17:29,6, MODEM0: No SMS received 2016-08-29 00:17:29,6, MODEM0: Sending SMS from to 491XXXXXXXXXX 2016-08-29 00:17:29,6, MODEM0: Checking if Modem is registered to the network 2016-08-29 00:17:29,5, smsd: Moved file /var/spool/sms/outgoing/198113-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:29,6, MODEM0: Modem is registered to the network 2016-08-29 00:17:30,5, smsd: Moved file /var/spool/sms/outgoing/198114-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:30,5, smsd: Moved file /var/spool/sms/outgoing/198115-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:31,5, smsd: Moved file /var/spool/sms/outgoing/198114-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:31,5, smsd: Moved file /var/spool/sms/outgoing/198116-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:32,5, smsd: Moved file /var/spool/sms/outgoing/198115-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:33,5, smsd: Moved file /var/spool/sms/outgoing/198116-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:33,5, MODEM0: SMS sent, Message_id: 89, To: 491XXXXXXXXXX, sending time 4 sec. 2016-08-29 00:17:33,6, MODEM0: Moved file /var/spool/sms/ALL/197954-20160829-000014.txt to /var/spool/sms/sent/197954-20160829-000014.txt 2016-08-29 00:17:33,6, MODEM0: I have to send 1 short message for /var/spool/sms/ALL/197957-20160829-000014.txt 2016-08-29 00:17:33,6, MODEM0: Checking device for incoming SMS 2016-08-29 00:17:33,6, MODEM0: Checking memory size 2016-08-29 00:17:33,5, smsd: Moved file /var/spool/sms/outgoing/198117-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:34,6, MODEM0: Used memory is 0 of 30 2016-08-29 00:17:34,6, MODEM0: No SMS received 2016-08-29 00:17:34,6, MODEM0: Sending SMS from to 491XXXXXXXXXX 2016-08-29 00:17:34,6, MODEM0: Checking if Modem is registered to the network 2016-08-29 00:17:34,5, smsd: Moved file /var/spool/sms/outgoing/198116-20160829-000024.txt to /var/spool/sms/ALL 2016-08-29 00:17:34,6, MODEM0: Modem is registered to the network 2016-08-29 00:17:34,5, smsd: Moved file /var/spool/sms/outgoing/198118-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:35,5, smsd: Moved file /var/spool/sms/outgoing/198117-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:35,5, smsd: Moved file /var/spool/sms/outgoing/198119-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:36,5, smsd: Moved file /var/spool/sms/outgoing/198118-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:37,5, smsd: Moved file /var/spool/sms/outgoing/198119-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:37,5, smsd: Moved file /var/spool/sms/outgoing/198120-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:38,5, smsd: Moved file /var/spool/sms/outgoing/198119-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:38,5, MODEM0: SMS sent, Message_id: 90, To: 491XXXXXXXXXX, sending time 4 sec. 2016-08-29 00:17:38,6, MODEM0: Moved file /var/spool/sms/ALL/197957-20160829-000014.txt to /var/spool/sms/sent/197957-20160829-000014.txt 2016-08-29 00:17:38,6, MODEM0: I have to send 1 short message for /var/spool/sms/ALL/197958-20160829-000014.txt 2016-08-29 00:17:38,6, MODEM0: Checking device for incoming SMS 2016-08-29 00:17:38,6, MODEM0: Checking memory size 2016-08-29 00:17:38,5, smsd: Moved file /var/spool/sms/outgoing/198121-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:39,6, MODEM0: Used memory is 0 of 30 2016-08-29 00:17:39,6, MODEM0: No SMS received 2016-08-29 00:17:39,6, MODEM0: Sending SMS from to 491XXXXXXXXXX 2016-08-29 00:17:39,6, MODEM0: Checking if Modem is registered to the network 2016-08-29 00:17:39,5, smsd: Moved file /var/spool/sms/outgoing/198120-20160829-000025.txt to /var/spool/sms/ALL 2016-08-29 00:17:39,6, MODEM0: Modem is registered to the network 2016-08-29 00:17:39,2, smsd: Fatal error: Cannot move /var/spool/sms/outgoing/198122-20160829-000025.txt to /var/spool/sms/ALL. Check file and dir permissions. 2016-08-29 00:17:39,2, smsd: Smsd mainprocess terminated abnormally. PID: 8147. 2016-08-29 00:17:39,3, MODEM0: The modem did not answer (expected OK). 2016-08-29 00:17:39,5, MODEM0: Waiting 10 sec. before retrying 2016-08-29 00:17:39,4, MODEM0: Sending SMS to 491XXXXXXXXXX failed, trying time 0 sec. Retries: 0. 2016-08-29 00:17:40,6, MODEM0: Moved file /var/spool/sms/ALL/197958-20160829-000014.txt to /var/spool/sms/failed/197958-20160829-000014.txt 2016-08-29 00:17:40,2, MODEM0: Modem handler 0 terminated. PID: 8148, was started 16-08-28 06:25:02.

I think the main process (one of the behaves like a queue router) is acting fast before my SMS File creator script finished his job with the file.
I'm guessing, while my script create and begin to write to file main SMSD script is trying to move file from outgoing to modem queue before my script closed and left the file alone.
Is there a prevention mechanism available for this behavior?

You could create a file with the extension ".LOCK". Smsd skips those files. After the file is complete and closed, rename the .LOCK extension away.

Also make sure that your script does not create a filename which was used right before, or it does not create the same file twice.

If a file was spooled, and some modem is currently sending it, the file is locked in the queue. If at the same time a file with the same name is going to be spooled again, it fails because of locking.

There is a global setting keep_filename = no available, it creates an unique name each time when a file is moved between directories. But first ensure that your feeding script is working properly.

Hello Keke,

I did not made the changes about .txt .LOCK file extension in my script yet.
But it seems the "Conflict with .LOCK" file issue has returned.

I'm still using one queue for one modem logic (The last configuration is still in use) But this morning I got that error again.

I'm still have no idea why? I thought if I separate the queues that could solve the problem, but it didn't.

Here is the smsd and trouble logs:
2016-08-31 05:23:22.317240,5, smsd: Moved file /var/spool/sms/outgoing/203307-20160831-052006.txt to /var/spool/sms/ALL 2016-08-31 05:23:22.348245,5, MODEM0: SMS sent, Message_id: 209, To: xxxxxxxxxxxxx, sending time 6 sec. 2016-08-31 05:23:22.868756,5, smsd: Moved file /var/spool/sms/outgoing/203308-20160831-052006.txt to /var/spool/sms/ALL 2016-08-31 05:23:23.429411,5, smsd: Moved file /var/spool/sms/outgoing/203309-20160831-052006.txt to /var/spool/sms/ALL 2016-08-31 05:23:23.988123,5, smsd: Moved file /var/spool/sms/outgoing/203310-20160831-052006.txt to /var/spool/sms/ALL 2016-08-31 05:23:26.825816,5, MODEM0: SMS sent, Message_id: 210, To: xxxxxxxxxxxxx, sending time 3 sec. 2016-08-31 05:23:30.540427,5, smsd: Moved file /var/spool/sms/outgoing/203313-20160831-052006.txt to /var/spool/sms/ALL 2016-08-31 05:23:31.085278,5, MODEM0: SMS sent, Message_id: 211, To: xxxxxxxxxxxxx, sending time 4 sec. 2016-08-31 05:23:36.338478,5, MODEM0: SMS sent, Message_id: 212, To: xxxxxxxxxxxxx, sending time 5 sec. 2016-08-31 05:23:40.557895,5, MODEM0: SMS sent, Message_id: 213, To: xxxxxxxxxxxxx, sending time 3 sec. 2016-08-31 05:23:45.085999,5, MODEM0: SMS sent, Message_id: 214, To: xxxxxxxxxxxxx, sending time 4 sec. 2016-08-31 05:23:49.413649,5, MODEM0: SMS sent, Message_id: 215, To: xxxxxxxxxxxxx, sending time 4 sec. 2016-08-31 05:23:54.153968,5, MODEM0: SMS sent, Message_id: 216, To: xxxxxxxxxxxxx, sending time 4 sec. 2016-08-31 05:23:59.590832,5, MODEM0: SMS sent, Message_id: 217, To: xxxxxxxxxxxxx, sending time 5 sec. 2016-08-31 05:24:01.098588,5, smsd: Moved file /var/spool/sms/outgoing/203327-20160831-052006.txt to /var/spool/sms/ALL 2016-08-31 05:24:10.882618,5, MODEM0: SMS sent, Message_id: 218, To: xxxxxxxxxxxxx, sending time 6 sec. 2016-08-31 05:24:46.668843,5, smsd: Moved file /var/spool/sms/outgoing/203346-20160831-052007.txt to /var/spool/sms/ALL 2016-08-31 05:24:50.170296,2, smsd: Conflict with .LOCK file in the spooler: /var/spool/sms/outgoing/203346-20160831-052007.txt /var/spool/sms/ALL 2016-08-31 05:24:50.170336,2, smsd: Fatal error: Cannot move /var/spool/sms/outgoing/203346-20160831-052007.txt to /var/spool/sms/ALL. Check file and dir permissions. 2016-08-31 05:24:50.170446,2, smsd: Smsd mainprocess terminated abnormally. PID: 6488. 2016-08-31 05:24:50.171342,2, MODEM1: Modem handler 1 terminated. PID: 6490, was started 16-08-30 11:29:50. 2016-08-31 05:24:50.171839,2, MODEM3: Modem handler 3 terminated. PID: 6492, was started 16-08-30 11:29:50. 2016-08-31 05:24:50.172089,2, MODEM2: Modem handler 2 terminated. PID: 6491, was started 16-08-30 11:29:50. 2016-08-31 05:24:50.259290,2, MODEM0: Modem handler 0 terminated. PID: 6489, was started 16-08-30 11:29:50. 2016-08-31 08:15:40.929063,2, smsd: Smsd v3.1.15 started.

2016-08-30 13:00:24.269950,6, MODEM0: Checking if modem is ready 2016-08-30 13:00:25.775569,5, MODEM0: Everything ok now. 2016-08-31 05:24:50.170318,2, smsd: Conflict with .LOCK file in the spooler: /var/spool/sms/outgoing/203346-20160831-052007.txt /var/spool/sms/ALL 2016-08-31 05:24:50.170346,2, smsd: Fatal error: Cannot move /var/spool/sms/outgoing/203346-20160831-052007.txt to /var/spool/sms/ALL. Check file and dir permissions. 2016-08-31 05:24:50.170472,2, smsd: Smsd mainprocess terminated abnormally. PID: 6488. 2016-08-31 05:24:49.903724,7, MODEM0: -> AT+CREG? 2016-08-31 05:24:49.907108,7, MODEM0: Command is sent, waiting for the answer 2016-08-31 05:24:50.170434,7, MODEM0: <- +CREG: 0,1 OK 2016-08-31 05:24:50.170457,6, MODEM0: Modem is registered to the network 2016-08-31 05:24:50.170466,6, MODEM0: Selecting PDU mode 2016-08-31 05:24:50.170495,7, MODEM0: -> AT+CMGF=0 2016-08-31 05:24:50.175110,7, MODEM0: Command is sent, waiting for the answer 2016-08-31 05:24:50.175189,7, MODEM0: put_command expected (OK)|(ERROR), timeout occurred. 1. 2016-08-31 05:24:50.175201,7, MODEM0: <- 2016-08-31 05:24:50.175235,7, MODEM0: -> AT+CMGF=0 2016-08-31 05:24:50.179177,7, MODEM0: Command is sent, waiting for the answer 2016-08-31 05:24:50.179219,7, MODEM0: <- OK 2016-08-31 05:24:50.179236,6, MODEM0: No SMS received 2016-08-31 05:24:50.179284,5, MODEM0: Everything ok now. 2016-08-31 05:24:50.179319,7, MODEM0: -> AT 2016-08-31 05:24:50.179732,7, MODEM0: Command is sent, waiting for the answer 2016-08-31 05:24:50.179811,7, MODEM0: put_command expected (OK)|(ERROR), timeout occurred. 1. 2016-08-31 05:24:50.179823,7, MODEM0: <- 2016-08-31 05:24:50.258543,5, MODEM0: Everything ok now. 2016-08-31 08:15:40.936388,5, smsd: Outgoing file checker has started. PID: 26816. 2016-08-31 08:15:40.936430,5, smsd: Everything ok now.

I am pretty sure about file names are distinct. Because we are using both timestamp and our own file counter within filename.
Also I have to say; the our script is creating the SMS files with ".txt" extension in separate server and than uploaded to server via ftp where smstools running. May be this information leads us to answer.

We made the modifications in our script.

Now I enabled other modems with it's own queue.
Our SMS feeder script is creating each SMS file with different queue sequentially and .LOCK extension.
Then upload each file to outgoing folder of the SMS server via FTP and then renamed to .txt right after 1 second when upload finished.

We will see, if I get the same error again.

It's happened again.

Ok, Let's see latest status:

Operating system name and version: Ubuntu 16.04.1 / Kernel version: Linux 4.4.0-36-generic #55-Ubuntu SMP x86_64 x86_64 x86_64 GNU/Linux
Version of smsd: 3.1.15-1.2
Smsd installed from: package repository
Name and model of a modem / phone: Future Technology Devices International, Ltd FT4232H Quad HS USB-UART/FIFO IC (with sierra wavecom Q24Plus modules)
Interface: USB

Our SMS feeder script is running on the different server.
The feeder script creates SMS text files with .LOCK extension in server where feeder script is running.
When file is created once SMS Feeder script is upload the file to /var/spor/sms/outgoing/ folder of the SMS server via FTP
When upload is finished, SMS feeder script waits for 1 second and rename the uploaded file .LOCK file extension to .txt
And then, smsd process moves the file to it's final destination according to queue written inside the file.

The final configuration is like this:


Here is the smsd.log:

Hidden private text.

And the smsd_trouble.log:

Hidden private text.

The file involved to crash has appeared in two different folder:
# find . -name MODEM2-205010-20160901-000011.txt ./sent/MODEM2-205010-20160901-000011.txt ./failed/MODEM2-205010-20160901-000011.txt # stat ./sent/MODEM2-205010-20160901-000011.txt File: './sent/MODEM2-205010-20160901-000011.txt' Size: 120 Blocks: 8 IO Block: 4096 regular file Device: 801h/2049d Inode: 7081319 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 111/ smsd) Gid: ( 117/ smsd) Access: 2016-09-01 07:52:34.641884205 +0200 Modify: 2016-09-01 07:52:34.641884205 +0200 Change: 2016-09-01 07:52:34.641884205 +0200 Birth: - # stat failed/MODEM2-205010-20160901-000011.txt File: 'failed/MODEM2-205010-20160901-000011.txt' Size: 242 Blocks: 8 IO Block: 4096 regular file Device: 801h/2049d Inode: 7078961 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 111/ smsd) Gid: ( 117/ smsd) Access: 2016-09-01 00:10:23.444926329 +0200 Modify: 2016-09-01 00:10:23.444926329 +0200 Change: 2016-09-01 00:10:23.444926329 +0200 Birth: -