Hello mbuni users and developers, Mbuni CVS 20100702 Modem: Sagem My300x
Purpose: Try to send MMS through MM1 GPRS modem but failed. I did not succeed to send a MMS through MM1 GPRS modem connection. When sending a MMS through mmsbox interface I do see the pppd process starting to connect to GPRS but fail the first time then succeed, but Mbuni says: WARNING: mmsbox_mm1.c:375 <handle_mm1> [mmsbox-mm1] [n/a] *failed to start GPRS connection. waiting... * Mbuni did not make a retry after the GPRS connection was established.* Find below: *- mmsbox.log - messages file (pppd message) - mmmsbox.conf* Questions: **- Did you ever experiment this situation ? - Do I have to use another process instead of pppd ? - Why Mbuni does not retry to send the MMS stored in pool ?** **- Problem of configuration ? of mbuni or routing issue to contact MMS-C** *- I saw an another post where a someone implement a delay (from Ben Hardill):* ------------------ **In order to get it all working I had to add a small delay after starting PPP as Mbuni was trying to send the post before the routing was all up and running properly, so I have added the following just after the call to start ppp in mmsbox_mm1.c if (mm1->gprs_on) pid = start_gprs(mm1->gprs_on, mm1->gprs_pid); gwthread_sleep(3); #<--- short pause to allow ppp to finish setting up the connection if (pid< 0) { mms_warning(0, "mmsbox-mm1", NULL,"failed to start GPRS connection. waiting...");* *-------------------------- * Starting log: mmsbox.log: ------------------- [r...@navette mbuni]# mmsbox /etc/mbuni/mmsbox.conf 2010-08-03 14:31:44 [3327] [0] INFO: Debug_lvl = -1, log_file = <none>, log_lvl = 0 2010-08-03 14:31:44 [3327] [0] INFO: Added logfile `/var/log/mbuni/mmsbox.log' with level `0'. 2010-08-03 14:31:44 [3327] [0] INFO: Started access logfile `/var/log/mbuni/mmsbox-access.log'. 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 1 (mmsbox_cdr.c:(void *)cdr_logger_func) 2010-08-03 14:31:44 [3327] [0] INFO: HTTP: Opening server at port 10002. 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 2 (gwlib/fdset.c:poller) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 3 (gwlib/http.c:server_thread) 2010-08-03 14:31:44 [3327] [1] DEBUG: Thread 1 (mmsbox_cdr.c:(void *)cdr_logger_func) maps to pid 3327. 2010-08-03 14:31:44 [3327] [0] INFO: mmsbox_cfg.c:578 <start_mmsc_from_conf> [mmsbox] [n/a] Loaded MMSC[modem], allow=[(null)], deny=[(null)] group_id=[modem] 2010-08-03 14:31:44 [3327] [0] INFO: HTTP: Opening server at port 3130. 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 4 (mmsbox_mm1.c:(gwthread_func_t *)handle_notify) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 5 (mmsbox_mm1.c:(gwthread_func_t *)handle_mm1) 2010-08-03 14:31:44 [3327] [0] INFO: mmsbox_cfg.c:529 <mmsbox_start_mmsc_conn> [mmsbox] [n/a] Startup for mmsc [modem] complete 2010-08-03 14:31:44 [3327] [2] DEBUG: Thread 2 (gwlib/fdset.c:poller) maps to pid 3327. 2010-08-03 14:31:44 [3327] [0] WARNING: mmsbox_cfg.c:459 <mms_load_mmsbox_settings> [mmsbox] [n/a] Empty or no password supplied for admin port. All requests will be allowed! 2010-08-03 14:31:44 [3327] [0] INFO: mmsbox.c:758 <main> [mmsbox] [n/a] ---------------------------------------- 2010-08-03 14:31:44 [3327] [0] INFO: mmsbox.c:759 <main> [mmsbox] [n/a] Mbuni MMSBox version cvs-20100702 starting 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 6 (mmsbox.c:(gwthread_func_t *)sendmms_func) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 7 (mmsbox.c:(gwthread_func_t *)mmsbox_outgoing_queue_runner) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 8 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 9 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 10 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 11 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [0] DEBUG: Started thread 12 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [5] DEBUG: Thread 5 (mmsbox_mm1.c:(gwthread_func_t *)handle_mm1) maps to pid 3327. 2010-08-03 14:31:44 [3327] [5] INFO: mmsbox_mm1.c:363 <handle_mm1> [mmsbox-mm1] [n/a] handle_mm1 started 2010-08-03 14:31:44 [3327] [4] DEBUG: Thread 4 (mmsbox_mm1.c:(gwthread_func_t *)handle_notify) maps to pid 3327. 2010-08-03 14:31:44 [3327] [3] DEBUG: Thread 3 (gwlib/http.c:server_thread) maps to pid 3327. 2010-08-03 14:31:44 [3327] [10] DEBUG: Thread 10 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [9] DEBUG: Thread 9 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [6] DEBUG: Thread 6 (mmsbox.c:(gwthread_func_t *)sendmms_func) maps to pid 3327. 2010-08-03 14:31:44 [3327] [11] DEBUG: Thread 11 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [8] DEBUG: Thread 8 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [7] DEBUG: Thread 7 (mmsbox.c:(gwthread_func_t *)mmsbox_outgoing_queue_runner) maps to pid 3327. 2010-08-03 14:31:44 [3327] [12] DEBUG: Thread 12 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [6] DEBUG: Started thread 13 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) 2010-08-03 14:31:44 [3327] [7] DEBUG: Started thread 14 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [6] DEBUG: Started thread 15 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) 2010-08-03 14:31:44 [3327] [7] DEBUG: Started thread 16 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [6] DEBUG: Started thread 17 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) 2010-08-03 14:31:44 [3327] [7] DEBUG: Started thread 18 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [6] DEBUG: Started thread 19 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) 2010-08-03 14:31:44 [3327] [7] DEBUG: Started thread 20 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [18] DEBUG: Thread 18 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [6] DEBUG: Started thread 21 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) 2010-08-03 14:31:44 [3327] [7] DEBUG: Started thread 22 (mms_queue.c:(gwthread_func_t *)tdeliver) 2010-08-03 14:31:44 [3327] [16] DEBUG: Thread 16 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [13] DEBUG: Thread 13 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) maps to pid 3327. 2010-08-03 14:31:44 [3327] [20] DEBUG: Thread 20 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [22] DEBUG: Thread 22 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. 2010-08-03 14:31:44 [3327] [17] DEBUG: Thread 17 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) maps to pid 3327. 2010-08-03 14:31:44 [3327] [19] DEBUG: Thread 19 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) maps to pid 3327. 2010-08-03 14:31:44 [3327] [21] DEBUG: Thread 21 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) maps to pid 3327. 2010-08-03 14:31:44 [3327] [15] DEBUG: Thread 15 (mmsbox.c:(gwthread_func_t *)dispatch_sendmms_recv) maps to pid 3327. 2010-08-03 14:31:44 [3327] [14] DEBUG: Thread 14 (mms_queue.c:(gwthread_func_t *)tdeliver) maps to pid 3327. MMS send through MMS interface of mmsbox: # lynx -dump " http://localhost:10002/?username=tester&password=foobar&mmsc=modem&to=%2B87773502/TYPE=PLMN&subject=Test&text=MMS-1 " Accepted: Mbuni-msg.7610.x1.24.85 mmsbox.log generated after the MMS: -------------------------------------------------------- 2010-08-03 14:53:30 [2324] [3] DEBUG: HTTP: Creating HTTPClient for `127.0.0.1'. 2010-08-03 14:53:30 [2324] [3] DEBUG: HTTP: Created HTTPClient area 0xb5700ab0. 2010-08-03 14:53:30 [2324] [18] DEBUG: WSP: Mapping `text/plain', WSP 1.2 to 0x0003. 2010-08-03 14:53:30 [2324] [18] INFO: mmsbox.c:1366 <make_and_queue_msg> [mmsbox] [n/a] MMSBox: Queued message from service [sendmms-user], [transid [Mbuni-msg.7610.x1.24.85]: q-qf7610.1.x324.69 2010-08-03 14:53:30 [2324] [18] DEBUG: HTTP: Destroying HTTPClient area 0xb5700ab0. 2010-08-03 14:53:30 [2324] [18] DEBUG: HTTP: Destroying HTTPClient for `127.0.0.1'. 2010-08-03 14:53:30 [2324] [18] INFO: mmsbox.c:1613 <dispatch_sendmms_recv> [mmsbox] [n/a] MMSBox.mmssend: u=tester, Queued [Accepted: Mbuni-msg.7610.x1.24.85] 2010-08-03 14:53:35 [2324] [7] DEBUG: Queued to thread 0 for /var/spool/mbuni/mmsbox_outgoing/q/qf7610.1.x324.69, sendt=1280807610, tnow=1280807615 arg 0: pppd arg 1: call arg 2: mobile-auth cat: /var/run/ppp0.pid: Aucun fichier ou dossier de ce type 2010-08-03 14:53:40 [2324] [5] INFO: mmsbox_mm1.c:659 <start_gprs> [mmsbox-mm1] [n/a] waiting for connection: 0, pid=2457 cpid=2457, ifexited=1, exitstatus=0 2010-08-03 14:53:40 [2324] [5] WARNING: mmsbox_mm1.c:375 <handle_mm1> [mmsbox-mm1] [n/a] *failed to start GPRS connection. waiting...* /var/log/messages: ---------------------------- Aug 3 14:53:35 navette kernel: PPP generic driver version 2.4.2 Aug 3 14:53:35 navette pppd[2462]: pppd 2.4.5 started by admin, uid 0 Aug 3 14:53:36 navette chat[2463]: abort on (BUSY) Aug 3 14:53:36 navette chat[2463]: abort on (NO CARRIER) Aug 3 14:53:36 navette chat[2463]: abort on (VOICE) Aug 3 14:53:36 navette chat[2463]: abort on (NO DIALTONE) Aug 3 14:53:36 navette chat[2463]: abort on (NO DIAL TONE) Aug 3 14:53:36 navette chat[2463]: abort on (NO ANSWER) Aug 3 14:53:36 navette chat[2463]: abort on (DELAYED) Aug 3 14:53:36 navette chat[2463]: report (CONNECT) Aug 3 14:53:36 navette chat[2463]: timeout set to 6 seconds Aug 3 14:53:36 navette chat[2463]: send (ATQ0^M) Aug 3 14:53:36 navette chat[2463]: expect (OK) Aug 3 14:53:36 navette chat[2463]: ^M Aug 3 14:53:36 navette chat[2463]: OK Aug 3 14:53:36 navette chat[2463]: -- got it Aug 3 14:53:36 navette chat[2463]: send (ATZ^M) Aug 3 14:53:37 navette chat[2463]: timeout set to 3 seconds Aug 3 14:53:37 navette chat[2463]: expect (OK) Aug 3 14:53:37 navette chat[2463]: ^M Aug 3 14:53:37 navette chat[2463]: ^M Aug 3 14:53:37 navette chat[2463]: OK Aug 3 14:53:37 navette chat[2463]: -- got it Aug 3 14:53:37 navette chat[2463]: send (AT^M) Aug 3 14:53:37 navette chat[2463]: expect (OK) Aug 3 14:53:37 navette chat[2463]: ^M Aug 3 14:53:40 navette chat[2463]: alarm Aug 3 14:53:40 navette chat[2463]: send (AT^M) Aug 3 14:53:40 navette chat[2463]: expect (OK) Aug 3 14:53:40 navette chat[2463]: AT^M^M Aug 3 14:53:40 navette chat[2463]: OK Aug 3 14:53:40 navette chat[2463]: -- got it Aug 3 14:53:40 navette chat[2463]: send (ATI^M) Aug 3 14:53:40 navette chat[2463]: expect (OK) Aug 3 14:53:40 navette chat[2463]: ^M Aug 3 14:53:40 navette chat[2463]: ATI^M^M Aug 3 14:53:40 navette chat[2463]: my300X GPRS^M Aug 3 14:53:40 navette chat[2463]: ^M Aug 3 14:53:40 navette chat[2463]: OK Aug 3 14:53:40 navette chat[2463]: -- got it Aug 3 14:53:40 navette chat[2463]: send (ATZ^M) Aug 3 14:53:40 navette chat[2463]: expect (OK) Aug 3 14:53:40 navette chat[2463]: ^M Aug 3 14:53:40 navette chat[2463]: ATZ^M^M Aug 3 14:53:40 navette chat[2463]: OK Aug 3 14:53:40 navette chat[2463]: -- got it Aug 3 14:53:40 navette chat[2463]: send (AT^M) Aug 3 14:53:40 navette chat[2463]: expect (OK) Aug 3 14:53:40 navette chat[2463]: ^M Aug 3 14:53:43 navette chat[2463]: alarm Aug 3 14:53:43 navette chat[2463]: send (AT^M) Aug 3 14:53:43 navette chat[2463]: expect (OK) Aug 3 14:53:43 navette chat[2463]: AT^M^M Aug 3 14:53:43 navette chat[2463]: OK Aug 3 14:53:43 navette chat[2463]: -- got it Aug 3 14:53:43 navette chat[2463]: send (AT+CGDCONT=1,"IP","mms"^M) Aug 3 14:53:43 navette chat[2463]: expect (OK) Aug 3 14:53:43 navette chat[2463]: ^M Aug 3 14:53:43 navette chat[2463]: AT+CGDCONT=1,"IP","mms"^M^M Aug 3 14:53:43 navette chat[2463]: OK Aug 3 14:53:43 navette chat[2463]: -- got it Aug 3 14:53:43 navette chat[2463]: send (ATDT*99***1#^M) Aug 3 14:53:43 navette chat[2463]: timeout set to 30 seconds Aug 3 14:53:43 navette chat[2463]: expect (CONNECT) Aug 3 14:53:43 navette chat[2463]: ^M Aug 3 14:53:44 navette chat[2463]: ATDT*99***1#^M^M Aug 3 14:53:44 navette chat[2463]: CONNECT Aug 3 14:53:44 navette chat[2463]: -- got it Aug 3 14:53:44 navette chat[2463]: send (^M) Aug 3 14:53:44 navette pppd[2462]: Serial connection established. Aug 3 14:53:44 navette pppd[2462]: Using interface ppp0 Aug 3 14:53:44 navette pppd[2462]: Connect: ppp0 <--> /dev/ttyACM0 Aug 3 14:53:44 navette pppd[2462]: PAP authentication succeeded Aug 3 14:53:44 navette kernel: PPP Deflate Compression module registered Aug 3 14:53:45 navette pppd[2462]: not replacing existing default route via 192.168.0.1 Aug 3 14:53:45 navette pppd[2462]: local IP address 10.152.149.196 Aug 3 14:53:45 navette pppd[2462]: remote IP address 192.168.254.254 and nothing after... # ifconfig: eth1 Link encap:Ethernet HWaddr 00:16:E6:4E:0C:2B inet adr:192.168.0.2 Bcast:192.168.0.255 Masque:255.255.255.0 adr inet6: fe80::216:e6ff:fe4e:c2b/64 Scope:Lien UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:1585 errors:0 dropped:0 overruns:0 frame:0 TX packets:1354 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 lg file transmission:1000 RX bytes:1349508 (1.2 MiB) TX bytes:283403 (276.7 KiB) Interruption:20 lo Link encap:Boucle locale inet adr:127.0.0.1 Masque:255.0.0.0 adr inet6: ::1/128 Scope:Hôte UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:177 errors:0 dropped:0 overruns:0 frame:0 TX packets:177 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 lg file transmission:0 RX bytes:12005 (11.7 KiB) TX bytes:12005 (11.7 KiB) ppp0 Link encap:Protocole Point-à-Point inet adr:10.152.149.196 P-t-P:192.168.254.254 Masque:255.255.255.255 UP POINTOPOINT RUNNING NOARP MULTICAST MTU:1500 Metric:1 RX packets:4 errors:0 dropped:0 overruns:0 frame:0 TX packets:5 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 lg file transmission:3 RX bytes:58 (58.0 b) TX bytes:76 (76.0 b) # netstat -rn Table de routage IP du noyau Destination Passerelle Genmask Indic MSS Fenêtre irtt Iface 192.168.254.254 0.0.0.0 255.255.255.255 UH 0 0 0 ppp0 192.168.0.0 0.0.0.0 255.255.255.0 U 0 0 0 eth1 169.254.0.0 0.0.0.0 255.255.0.0 U 0 0 0 eth1 0.0.0.0 192.168.0.1 0.0.0.0 UG 0 0 0 eth1 mmsbox.conf: --------------------- [r...@navette ~]# cat /etc/mbuni/mmsbox.conf group = core log-file = /var/log/mbuni/mmsbox.log access-log = /var/log/mbuni/mmsbox-access.log log-level = 0 group = mbuni storage-directory = /var/spool/mbuni max-send-threads = 5 maximum-send-attempts = 50 default-message-expiry = 360000 queue-run-interval = 5 send-attempt-back-off = 300 sendmms-port = 10002 #group = mmsc #id = local #mmsc-url = http://mbuni:t...@localhost:1982/soap #incoming-username = user #incoming-password = pass #incoming-port = 12345 #type = soap # Sample conf for MMSBox using a modem (MM1) group = mmsc id = modem type = custom custom-settings = "gprs-on=pppd call mobile-auth;gprs-pid=cat /var/run/ppp0.pid|head -1;port=3130;mmsc-url= http://mms.xxxxx.xx/mmsc;proxy=192.168.39.201;msisdn=100" mmsc-library = /usr/local/lib/libmmsbox_mm1.so group = mms-service name = me post-url = http://localhost/~bagyenda/test-mbuni.php<http://localhost/%7Ebagyenda/test-mbuni.php> catch-all = true http-post-parameters = fx=true&images[]=%i&text[]=%t&skip=1 accept-x-mbuni-headers = true pass-thro-headers = X-NOKIA-MMSC-Charging,X-NOKIA-MMSC-Charged-Party keyword = test omit-empty = no suppress-reply = true service-code = regular group = mms-service name = fullmessage get-url = http://localhost/images/apache_pb.gif # http-post-parameters = fx=true&image=%i&text=%t accept-x-mbuni-headers = true keyword = thixs group = send-mms-user username = tester password = foobar faked-sender = 100 Regards, -- Emmanuel
_______________________________________________ Users mailing list Users@mbuni.org http://lists.mbuni.org/mailman/listinfo/users