ReportOverThreshold | Search |
NowSMS Support Forums ⬆ NowSMS Support - SMS Issues ⬆ Archive through May 19, 2016 ⬆ |
◄ ► |
Author | Message | |||
Edmund New member Username: Edmund Post Number: 1 Registered: 12-2015 |
Hi, I am facing a problem with 2-way HTTP processing. I submitted 5 identical SMSes 1 second after another in the same minute (04:00:01 to 04:00:05). The first SMS gets processed in the same second (04:00:01). However, the second to fifth SMSes were only processed in the next minute all together (all at 04:01:00). This happens consistently regardless of message content or time of the day. Hence, I took a look at SMSDEBUG.LOG and saw this: 04:00:01:974 [11] GetProgramToExecute: http://localhost/processSMS.php 04:00:01:974 [11] ReportOverThreshold: Debug 04:00:01:981 [37] WaitForSocketClose: WinSock reported ioctlsocket complete 04:00:01:981 [37] ThreadProcessInboundConnection: Request processing complete 04:00:01:998 [6] WaitForSocketClose: WinSock reported ioctlsocket complete 04:01:00:001 [11] ThreadProcessInboundSMS: Executing http://localhost/processSMS.php In my first SMS, the "ReportOverThreshold: Debug" was not present, and the PHP was executed real-time. In my second SMS, "ReportOverThreshold: Debug" happened, and the execution was postponed to the following minute. Are you able to help please? | |||
Edmund New member Username: Edmund Post Number: 2 Registered: 12-2015 |
Figured I'll post more details. I sent 3 SMSes in these order: [22:13:18] aaa [22:13:24] bbb [22:13:31] ccc However, the messages were only processed at these timing, in the following order: [22:13:18] aaa [22:14:00] ccc [22:14:00] bbb As seen in the log, bbb and ccc were delayed, and swapped around. How can I ensure all SMSes are processed real-time and in the right order? -----------------SMSDEBUG.log ------------------- 22:12:53:952 [0] UseRouteCache: Yes 22:12:55:970 [0] main: Before InitStatCounters 22:12:56:036 [0] main: After InitStatCounters 22:12:56:086 [0] main: Before CheckDatabaseIntegrity 22:12:56:086 [0] main: After CheckDatabaseIntegrity 22:12:56:086 [0] LoadPreferredSenderList: Reload 22:12:56:086 [0] LoadPreferredSender: preferred sender = +6588888888,NowSMSModem - 192.168.0.118 22:12:58:102 [0] main: Now SMS/MMS Gateway v2014.06.30 Web server started on port number 8800 22:12:58:106 [29] ThreadScanAlerts: Before CheckDatabaseIntegrity 22:12:58:107 [29] ThreadScanAlerts: After CheckDatabaseIntegrity 22:12:58:108 [36] ThreadProcessModem: NowSMSModem - 192.168.0.118 22:12:58:176 [36] InetServerConnect: Connected to 192.168.0.118 (192.168.0.118:8990) 22:12:58:176 [36] ThreadProcessModem: GET /init HTTP/1.0 Accept: */* Connection: close Host: nowsmsmodem_192.168.0.118 X-NowSMS-ReceiveSMS: Yes X-NowSMS-ReceiveSMSPort: 8990 X-NowSMS-ReceiveMMS: No 22:12:58:238 [36] HttpResponseWait: Ok 22:12:58:239 [36] ThreadProcessModem: HTTP/1.0 200 OK X-NowSMS-MCCMNC: 52501 X-NowSMS-MMSURL: http://mms.singtel.com:10021/mmsc X-NowSMS-MMSProxy: 165.21.42.84:8080 X-NowSMS-DeviceID: 860499029850347 X-NowSMS-DeviceName: Huawei Content-Type: text/html Date: Fri, 01 Jan 2016 14:13:00 GMT Content-Length: 53 Connection: close <html><head></head><body><p>INIT OK</p></body></html> 22:12:58:239 [36] WaitForSocketClose: WinSock reported ioctlsocket complete 22:13:04:113 [0] UseRouteCache: Yes 22:13:18:349 [2] ThreadListenForInboundConnections: Before accept 22:13:18:350 [2] ThreadListenForInboundConnections: After accept 22:13:18:350 [37] ThreadProcessInboundConnection: Processing connection from 192.168.0.118:20455... 22:13:18:353 [37] ProcessInboundRequest: POST /InboundSMS/NowSMSModem HTTP/1.1 X-NowSMS-DeviceID: 860499029850347 X-NowSMS-DeviceName: Huawei User-Agent: NowSMS Modem Connection: close Content-Type: application/x-nowsms-inboundmessage-sms Content-Length: 27 Host: 192.168.0.122:8990 Ð}dêÓJ‘?;39;;>($$Q&0+zwk\ 22:13:18:353 [37] ProcessInboundRequest: Huawei 22:13:18:353 [37] ProcessInboundRequest: 860499029850347 22:13:18:353 [37] ProcessInboundRequest: From 22:13:18:353 [37] ProcessInboundRequest: +6599999999 22:13:18:353 [37] ProcessInboundRequest: Text 22:13:18:353 [37] ProcessInboundRequest: aaa 22:13:18:353 [37] ProcessInboundRequest: NowSMSModem - 192.168.0.118 22:13:18:387 [11] ThreadProcessInboundSMS: Processing 5682A369.in... 22:13:18:387 [11] GetProgramToExecute: Found 2-way command prefix match * 22:13:18:387 [11] GetProgramToExecute: Best match so far for 2-way command prefix * 22:13:18:388 [11] GetProgramToExecute: http://localhost/processSMS.php?gatewayID=@@MESSAGEID@@&recvDate=@@MSGDATE@@&rec vTime=@@MSGTIME@@&sender=@@SENDER@@&payload=@@FULLSMS@@ 22:13:18:388 [11] GetProgramToExecute: http://localhost/processSMS.php?gatewayID=5682A369.in&recvDate=20160101&recvTime =221318&sender=%2B6599999999&payload=aaa 22:13:18:388 [11] ThreadProcessInboundSMS: Executing http://localhost/processSMS.php?gatewayID=5682A369.in&recvDate=20160101&recvTime =221318&sender=%2B6599999999&payload=aaa 22:13:18:388 [11] RetrieveURL: Retrieving http://localhost/processSMS.php?gatewayID=5682A369.in&recvDate=20160101&recvTime =221318&sender=%2B6599999999&payload=aaa 22:13:18:391 [11] InetServerConnect: Connected to localhost (127.0.0.1:80) 22:13:18:391 [11] RetrieveURL: Retrieving processSMS.php?gatewayID=5682A369.in&recvDate=20160101&recvTime=221318&sender=%2 B6599999999&payload=aaa 22:13:18:391 [11] RetrieveURL: GET /processSMS.php?gatewayID=5682A369.in&recvDate=20160101&recvTime=221318&sender=% 2B6599999999&payload=aaa HTTP/1.1 User-Agent: Now SMS/MMS Gateway v2014.06.30 Accept: */* Host: localhost 22:13:18:400 [37] WaitForSocketClose: WinSock reported ioctlsocket complete 22:13:18:400 [37] ThreadProcessInboundConnection: Request processing complete 22:13:18:411 [11] HttpResponseWait: Ok 22:13:18:411 [11] RetrieveURL: HTTP/1.1 200 OK Date: Fri, 01 Jan 2016 14:13:18 GMT Server: Apache/2.4.9 (Win64) PHP/5.5.12 X-Powered-By: PHP/5.5.12 Content-Length: 157 Content-Type: text/html YAY! SMS received via PHP request. 22:13:18:411 [11] RetrieveURL: Saving keep-alive socket 22:13:18:411 [11] RetrieveURL: got success response 22:13:18:411 [11] RetrieveURL: text/html 22:13:18:411 [11] ThreadProcessInboundSMS: HTTP/1.1 200 OK Date: Fri, 01 Jan 2016 14:13:18 GMT Server: Apache/2.4.9 (Win64) PHP/5.5.12 X-Powered-By: PHP/5.5.12 Content-Length: 157 Content-Type: text/html YAY! SMS 'aaa' received via PHP request. 22:13:18:411 [11] GetProgramToExecute: Found 2-way command prefix match * 22:13:18:411 [11] GetProgramToExecute: Best match so far for 2-way command prefix * 22:13:18:412 [11] ThreadProcessInboundSMS: Processing complete 5682A369.in... 22:13:24:091 [2] ThreadListenForInboundConnections: Before accept 22:13:24:091 [2] ThreadListenForInboundConnections: After accept 22:13:24:092 [37] ThreadProcessInboundConnection: Processing connection from 192.168.0.118:20711... 22:13:24:100 [37] ProcessInboundRequest: POST /InboundSMS/NowSMSModem HTTP/1.1 X-NowSMS-DeviceID: 860499029850347 X-NowSMS-DeviceName: Huawei User-Agent: NowSMS Modem Connection: close Content-Type: application/x-nowsms-inboundmessage-sms Content-Length: 27 Host: 192.168.0.122:8990 Ó~gêÓJ‘?;39;;>($$Q&0+zwk\ 22:13:24:100 [37] ProcessInboundRequest: Huawei 22:13:24:100 [37] ProcessInboundRequest: 860499029850347 22:13:24:100 [37] ProcessInboundRequest: From 22:13:24:100 [37] ProcessInboundRequest: +6599999999 22:13:24:100 [37] ProcessInboundRequest: Text 22:13:24:100 [37] ProcessInboundRequest: bbb 22:13:24:100 [37] ProcessInboundRequest: NowSMSModem - 192.168.0.118 22:13:24:106 [17] ThreadProcessInboundSMS: Processing 5682A36A.in... 22:13:24:106 [17] GetProgramToExecute: Found 2-way command prefix match * 22:13:24:106 [17] GetProgramToExecute: Best match so far for 2-way command prefix * 22:13:24:107 [17] GetProgramToExecute: http://localhost/processSMS.php?gatewayID=@@MESSAGEID@@&recvDate=@@MSGDATE@@&rec vTime=@@MSGTIME@@&sender=@@SENDER@@&payload=@@FULLSMS@@ 22:13:24:107 [17] GetProgramToExecute: http://localhost/processSMS.php?gatewayID=5682A36A.in&recvDate=20160101&recvTime =221324&sender=%2B6599999999&payload=bbb 22:13:24:108 [17] ReportOverThreshold: Debug 22:13:24:121 [37] WaitForSocketClose: WinSock reported ioctlsocket complete 22:13:24:121 [37] ThreadProcessInboundConnection: Request processing complete 22:13:24:413 [11] WaitForSocketClose: WinSock reported ioctlsocket complete 22:13:31:355 [2] ThreadListenForInboundConnections: Before accept 22:13:31:356 [2] ThreadListenForInboundConnections: After accept 22:13:31:356 [37] ThreadProcessInboundConnection: Processing connection from 192.168.0.118:20967... 22:13:31:357 [37] ProcessInboundRequest: POST /InboundSMS/NowSMSModem HTTP/1.1 X-NowSMS-DeviceID: 860499029850347 X-NowSMS-DeviceName: Huawei User-Agent: NowSMS Modem Connection: close Content-Type: application/x-nowsms-inboundmessage-sms Content-Length: 27 Host: 192.168.0.122:8990 ÒfêÓJ‘?;39;;>($$Q&0+zwk\ 22:13:31:357 [37] ProcessInboundRequest: Huawei 22:13:31:357 [37] ProcessInboundRequest: 860499029850347 22:13:31:358 [37] ProcessInboundRequest: From 22:13:31:358 [37] ProcessInboundRequest: +6599999999 22:13:31:358 [37] ProcessInboundRequest: Text 22:13:31:358 [37] ProcessInboundRequest: ccc 22:13:31:358 [37] ProcessInboundRequest: NowSMSModem - 192.168.0.118 22:13:31:366 [13] ThreadProcessInboundSMS: Processing 5682A36B.in... 22:13:31:366 [13] GetProgramToExecute: Found 2-way command prefix match * 22:13:31:366 [13] GetProgramToExecute: Best match so far for 2-way command prefix * 22:13:31:368 [13] GetProgramToExecute: http://localhost/processSMS.php?gatewayID=@@MESSAGEID@@&recvDate=@@MSGDATE@@&rec vTime=@@MSGTIME@@&sender=@@SENDER@@&payload=@@FULLSMS@@ 22:13:31:369 [13] GetProgramToExecute: http://localhost/processSMS.php?gatewayID=5682A36B.in&recvDate=20160101&recvTime =221331&sender=%2B6599999999&payload=ccc 22:13:31:375 [37] WaitForSocketClose: WinSock reported ioctlsocket complete 22:13:31:375 [37] ThreadProcessInboundConnection: Request processing complete 22:14:00:000 [17] ThreadProcessInboundSMS: Executing http://localhost/processSMS.php?gatewayID=5682A36A.in&recvDate=20160101&recvTime =221324&sender=%2B6599999999&payload=bbb 22:14:00:000 [13] ThreadProcessInboundSMS: Executing http://localhost/processSMS.php?gatewayID=5682A36B.in&recvDate=20160101&recvTime =221331&sender=%2B6599999999&payload=ccc 22:14:00:000 [17] RetrieveURL: Retrieving http://localhost/processSMS.php?gatewayID=5682A36A.in&recvDate=20160101&recvTime =221324&sender=%2B6599999999&payload=bbb 22:14:00:000 [13] RetrieveURL: Retrieving http://localhost/processSMS.php?gatewayID=5682A36B.in&recvDate=20160101&recvTime =221331&sender=%2B6599999999&payload=ccc 22:14:00:002 [13] InetServerConnect: Connected to localhost (127.0.0.1:80) 22:14:00:002 [17] InetServerConnect: Connected to localhost (127.0.0.1:80) 22:14:00:002 [13] RetrieveURL: Retrieving processSMS.php?gatewayID=5682A36B.in&recvDate=20160101&recvTime=221331&sender=%2 B6599999999&payload=ccc 22:14:00:002 [17] RetrieveURL: Retrieving processSMS.php?gatewayID=5682A36A.in&recvDate=20160101&recvTime=221324&sender=%2 B6599999999&payload=bbb 22:14:00:002 [13] RetrieveURL: GET /processSMS.php?gatewayID=5682A36B.in&recvDate=20160101&recvTime=221331&sender=% 2B6599999999&payload=ccc HTTP/1.1 User-Agent: Now SMS/MMS Gateway v2014.06.30 Accept: */* Host: localhost 22:14:00:002 [17] RetrieveURL: GET /processSMS.php?gatewayID=5682A36A.in&recvDate=20160101&recvTime=221324&sender=% 2B6599999999&payload=bbb HTTP/1.1 User-Agent: Now SMS/MMS Gateway v2014.06.30 Accept: */* Host: localhost 22:14:00:046 [17] HttpResponseWait: Ok 22:14:00:046 [13] HttpResponseWait: Ok 22:14:00:046 [17] RetrieveURL: HTTP/1.1 200 OK Date: Fri, 01 Jan 2016 14:14:00 GMT Server: Apache/2.4.9 (Win64) PHP/5.5.12 X-Powered-By: PHP/5.5.12 Content-Length: 157 Content-Type: text/html YAY! SMS received via PHP request. 22:14:00:046 [13] RetrieveURL: HTTP/1.1 200 OK Date: Fri, 01 Jan 2016 14:14:00 GMT Server: Apache/2.4.9 (Win64) PHP/5.5.12 X-Powered-By: PHP/5.5.12 Content-Length: 157 Content-Type: text/html YAY! SMS received via PHP request. 22:14:00:046 [17] RetrieveURL: Saving keep-alive socket 22:14:00:046 [13] RetrieveURL: Saving keep-alive socket 22:14:00:046 [17] RetrieveURL: got success response 22:14:00:046 [13] RetrieveURL: got success response 22:14:00:046 [17] RetrieveURL: text/html 22:14:00:046 [13] RetrieveURL: text/html 22:14:00:046 [17] ThreadProcessInboundSMS: HTTP/1.1 200 OK Date: Fri, 01 Jan 2016 14:14:00 GMT Server: Apache/2.4.9 (Win64) PHP/5.5.12 X-Powered-By: PHP/5.5.12 Content-Length: 157 Content-Type: text/html YAY! SMS 'ccc' received via PHP request. 22:14:00:046 [13] ThreadProcessInboundSMS: HTTP/1.1 200 OK Date: Fri, 01 Jan 2016 14:14:00 GMT Server: Apache/2.4.9 (Win64) PHP/5.5.12 X-Powered-By: PHP/5.5.12 Content-Length: 157 Content-Type: text/html YAY! SMS 'bbb' received via PHP request. 22:14:00:046 [17] GetProgramToExecute: Found 2-way command prefix match * 22:14:00:046 [13] GetProgramToExecute: Found 2-way command prefix match * 22:14:00:046 [17] GetProgramToExecute: Best match so far for 2-way command prefix * 22:14:00:046 [13] GetProgramToExecute: Best match so far for 2-way command prefix * 22:14:00:047 [13] ThreadProcessInboundSMS: Processing complete 5682A36B.in... 22:14:00:047 [17] ThreadProcessInboundSMS: Processing complete 5682A36A.in... 22:14:06:050 [13] WaitForSocketClose: WinSock reported ioctlsocket complete 22:14:06:050 [17] WaitForSocketClose: WinSock reported ioctlsocket complete | |||
Des - NowSMS Support Board Administrator Username: Desosms Post Number: 5548 Registered: 08-2008 |
Hi Edmund, Sorry for the delay in response, we were closed over the holiday weekend. For the first issue...the minute delay... Did you download NowSMS from this website, or from another site? Is this a trial version or a purchased license? The symptom of NowSMS sending only 1 message per minute is usually the result of an invalid serial number. Make sure you have not installed one of the various license cracks that float around the internet. Or if you downloaded NowSMS from a web site other than ours, it might have even been included in the install. If you are encountering this problem, I would suggest going to the "Serial #" page of the configuration dialog, and removing any listed serial numbers. A trial installation will not show any serial numbers in the list. If you remove a serial number, restart the service to get it back to trial mode. If NowSMS was download from another web site, it may also be necessary to uninstall and reinstall using the version at http://www.nowsms.com/download-free-trial For the second issue...the sequence of message processing... This issue is kind of related to the first. Multiple messages have been received, and are pending for processing, but being held because of the licensing issue. Multiple threads are allocated (I'm guessing you are using a 2WaySMSThreadCount setting), and waiting, and it is somewhat random which gets released first. If you used 2WaySMSThreadCount=1, this would not happen, but you'd only get 1 message per minute until the licensing issue is fixed. Side note: If you want to know the date and time that the message was a received by NowSMS, use @@MSGDATE@@ and @@MSGTME@@ in your 2-way command string. -- Des NowSMS Support |