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
