[asterisk-users] Xorcom Bri and asterisk crashes
Tzafrir Cohen
tzafrir.cohen at xorcom.com
Wed Jul 4 22:28:42 CDT 2007
On Thu, Jul 05, 2007 at 09:14:12AM +1000, Nathan Dennis wrote:
> We have recently install an asterisk solution with about 60 physical
> extensions. While the system is running it runs reasonably well (Still
> have a few teething problems) but twice now they have experienced a
> degradation in voice quality and dropped calls and then finally asterisk
> completely crashes out. Restarting asterisk will work for a little while
> and it will crash again, each time less time will pass before a crash
> out. The first time I didn't have much logging so I didn't get anything
> to work with. I have since turned on debugging and following is the logs
> from the time of the last crash. Can anyone point out where the problem
> may lay, suggested updates or changes?
>
>
> Jul 4 11:56:51 DEBUG[20042] chan_sip.c: Auto destroying call
> 'aca7e8d7fc914018 at 192.168.12.164'
> Jul 4 11:56:54 DEBUG[20042] chan_sip.c: Stopping retransmission on
> '6eeb52b53a414a6975facbc22ca10686 at 192.168.10.12' of Request 102: Match
> Found
> Jul 4 11:56:55 VERBOSE[20050] logger.c: -- Accepting voice call
> from '' to '40312688' on channel 0/2, span 5
> Jul 4 11:56:55 DEBUG[20050] chan_zap.c: Enabled echo cancellation on
> channel 14
> Jul 4 11:56:55 DEBUG[20295] pbx.c: Function result is 'CID withheld'
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> Set("Zap/14-1", "CALLERID(name)=Old Main Line:CID withheld") in new
> stack
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> Goto("Zap/14-1", "mainq|q|1") in new stack
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Goto (mainq,q,1)
> Jul 4 11:56:55 DEBUG[20295] pbx.c: Function result is 'false'
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> Set("Zap/14-1", "NightMode=false") in new stack
> Jul 4 11:56:55 DEBUG[20295] pbx.c: Expression result is '0'
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> GotoIf("Zap/14-1", "0?afterhoursq|q|1") in new stack
> Jul 4 11:56:55 DEBUG[20295] pbx.c: Not taking any branch
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> GotoIfTime("Zap/14-1", "8:00-17:30|mon-fri|*|*|?businesshours") in new
> stack
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Goto (mainq,q,5)
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> Set("Zap/14-1", "__ALERT_INFO=<http://www.example.com>;info=MainQ") in
> new stack
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Executing
> Queue("Zap/14-1", "mainq1|twr|||10") in new stack
> Jul 4 11:56:55 DEBUG[20295] chan_zap.c: Requested indication 3 on
> channel Zap/14-1
> Jul 4 11:56:55 VERBOSE[20295] logger.c: -- Called
> Local/700 at callagents
> Jul 4 11:56:55 VERBOSE[20298] logger.c: -- Executing
> Set("Local/700 at callagents-bc5a,2", "Extension=700") in new stack
> Jul 4 11:56:55 VERBOSE[20298] logger.c: -- Executing
> Set("Local/700 at callagents-bc5a,2",
> "__ALERT_INFO=<http://www.example.com>;info=MainQ") in new stack
> Jul 4 11:56:55 VERBOSE[20298] logger.c: -- Executing
> Dial("Local/700 at callagents-bc5a,2", "SIP/700||tw") in new stack
> Jul 4 11:56:55 DEBUG[20298] chan_sip.c: Setting NAT on RTP to 524288
> Jul 4 11:56:55 DEBUG[20298] chan_sip.c: Setting NAT on VRTP to 524288
> Jul 4 11:56:55 DEBUG[20298] chan_sip.c: Outgoing Call for 700
> Jul 4 11:56:55 VERBOSE[20298] logger.c: -- Called 700
> Jul 4 11:56:55 DEBUG[20042] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '1dc479bd153590ff41b7f77817106b18 at 192.168.0.12' Request 102: Found
> Jul 4 11:56:55 DEBUG[20042] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '1dc479bd153590ff41b7f77817106b18 at 192.168.0.12' Request 102: Found
> Jul 4 11:56:55 VERBOSE[20298] logger.c: -- SIP/700-09530a90 is
> ringing
> Jul 4 11:56:55 VERBOSE[20295] logger.c: --
> Local/700 at callagents-bc5a,1 is ringing
> Jul 4 11:56:56 DEBUG[20042] chan_sip.c: Auto destroying call
> '4c2e1191399110af402dcc5b2c48303a at 192.168.10.12'
> Jul 4 11:56:59 DEBUG[20042] chan_sip.c: Acked pending invite 102
> Jul 4 11:56:59 DEBUG[20042] chan_sip.c: Stopping retransmission on
> '1dc479bd153590ff41b7f77817106b18 at 192.168.0.12' of Request 102: Match
> Found
> Jul 4 11:56:59 DEBUG[20042] chan_sip.c: build_route: Contact hop:
> <sip:700 at 192.168.0.64:5060;transport=udp;user=phone>
> Jul 4 11:56:59 DEBUG[20027] channel.c: Avoiding initial deadlock for
> 'SIP/700-09530a90'
> Jul 4 11:56:59 VERBOSE[20298] logger.c: -- SIP/700-09530a90
> answered Local/700 at callagents-bc5a,2
> Jul 4 11:56:59 DEBUG[20295] app_queue.c: Dunno what to do with control
> type -1
> Jul 4 11:56:59 VERBOSE[20295] logger.c: --
> Local/700 at callagents-bc5a,1 answered Zap/14-1
> Jul 4 11:56:59 DEBUG[20295] chan_zap.c: Set option TONE VERIFY, mode:
> MUTECONF(1) on Zap/14-1
> Jul 4 11:56:59 DEBUG[20295] chan_zap.c: No echo training requested
> Jul 4 11:56:59 DEBUG[20298] channel.c: Planning to masquerade channel
> SIP/700-09530a90 into the structure of Local/700 at callagents-bc5a,1
> Jul 4 11:56:59 DEBUG[20298] channel.c: Done planning to masquerade
> channel SIP/700-09530a90 into the structure of
> Local/700 at callagents-bc5a,1
> Jul 4 11:56:59 DEBUG[20295] channel.c: Got clone lock for masquerade on
> 'SIP/700-09530a90' at 0x952ab64
> Jul 4 11:56:59 DEBUG[20298] chan_local.c: Not posting to queue since
> already masked on 'Local/700 at callagents-bc5a,2'
> Jul 4 11:56:59 DEBUG[20295] channel.c: Putting channel SIP/700-09530a90
> in 64/64 formats
> Jul 4 11:56:59 DEBUG[20295] channel.c: Released clone lock on
> 'Local/700 at callagents-bc5a,1<ZOMBIE>'
> Jul 4 11:56:59 DEBUG[20295] channel.c: Done Masquerading
> SIP/700-09530a90 (6)
>
> The last entry was just before the crash.
>
> We also have this in dmesg (Not sure if its related)
>
> NOTICE-xpd_bri: XBUS-01/XPD-10: D-Chan RX Bad checksum: [FE:28=FC] (252)
> NOTICE-xpd_bri: XBUS-01/XPD-10: Multibyte Drop: errno=-71
> BUG: warning at kernel/softirq.c:138/local_bh_enable() (Not tainted)
> [<c042b0cf>] local_bh_enable+0x45/0x92
> [<c06002bd>] cond_resched_softirq+0x2c/0x42
> [<c059adf3>] release_sock+0x4f/0x9d
> [<c05c670d>] tcp_sendmsg+0x90b/0x9f9
> [<c059adb6>] release_sock+0x12/0x9d
> [<c05c7755>] tcp_recvmsg+0x8d2/0x9de
> [<c04808dc>] core_sys_select+0x218/0x2f3
> [<c05dec95>] inet_sendmsg+0x3b/0x45
> [<c0598731>] sock_aio_write+0xf6/0x102
> [<c045da36>] get_page_from_freelist+0x23b/0x2a5
> [<c04754ee>] do_sync_write+0xc7/0x10a
> [<c0436e71>] autoremove_wake_function+0x0/0x35
> [<c0475d47>] vfs_write+0xbc/0x154
> [<c0476342>] sys_write+0x41/0x67
> [<c0404f70>] syscall_call+0x7/0xb
This stack trace is from the networking area.
Any chance you could get a more complete trace?
A quick search brings out the following Fedora bug:
https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=240982
So if this is a Fedora system, maybe try latest kernel. That bug is
marked "closed" there.
> =======================
> NOTICE-xpd_bri: XBUS-01/XPD-08: D-Chan RX Bad checksum: [FA:FA=FC] (252)
> NOTICE-xpd_bri: XBUS-01/XPD-08: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-00: D-Chan RX Bad checksum: [78:3A=FD] (253)
> NOTICE-xpd_bri: XBUS-00/XPD-00: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-00: D-Chan RX Bad checksum: [55:55=FD] (253)
> NOTICE-xpd_bri: XBUS-00/XPD-00: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-00: D-Chan RX Bad checksum: [55:55=FD] (253)
> NOTICE-xpd_bri: XBUS-00/XPD-00: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-00: D-Chan RX Bad checksum: [55:55=FD] (253)
> NOTICE-xpd_bri: XBUS-00/XPD-00: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-00: D-Chan RX Bad checksum: [AA:AA=FD] (253)
> NOTICE-xpd_bri: XBUS-00/XPD-00: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-10: D-Chan RX Bad checksum: [35:22=FC] (252)
> NOTICE-xpd_bri: XBUS-00/XPD-10: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-10: D-Chan RX short frame (idx=3)
> NOTICE-xpd_bri: XBUS-00/XPD-10: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-10: D-Chan RX Bad checksum: [35:22=FC] (252)
> NOTICE-xpd_bri: XBUS-00/XPD-10: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-10: D-Chan RX Bad checksum: [22:22=FC] (252)
> NOTICE-xpd_bri: XBUS-00/XPD-10: Multibyte Drop: errno=-71
> NOTICE-xpd_bri: XBUS-00/XPD-10: D-Chan RX Bad checksum: [55:02=FC] (252)
> NOTICE-xpd_bri: XBUS-00/XPD-10: Multibyte Drop: errno=-71
> zaptel Disabled echo canceller because of tone (rx) on channel 4
> NOTICE-xpd_bri: XBUS-00/XPD-00: D-Chan RX Bad checksum: [94:2D=FD] (253)
> NOTICE-xpd_bri: XBUS-00/XPD-00: Multibyte Drop: errno=-71
I believe that those messages can also be caused by Asterisk suddenly
dropping out with parts of the driver still working. But I'm not sure.
>
>
> Once the system becomes unstable the only way to get it up again is to
> shutdown (not restart) pull the power and USB on the Xorcom Bri 4
> devices.
Are you sure a reset of the Astribank is needed?
And if so: can you try:
rmmod xpp_usb; /usr/share/zaptel/xpp_fxloader reset
instead?
> Then plug them back in and start the system up.
> If the power and USB is not disconnected a the devices may look like
> they are working fine but zaptel will not start stating that it can not
> find span ** what ever it happens to fail on.
>
>
> We are running the following versions
> Asterisk - Asterisk 1.2.18-BRIstuffed-0.3.0-PRE-1y-g
> Zaptel - zaptel-1.2.18
> XPP - version: trunk-r3965
> srcversion: 723B8A27A7E9750BB039D00
What distribution? What kernel version?
>
> If you need any more information please let me know.
>
>
>
>
> Nathan Dennis
> __________________________________________________________
> Integrated Solutions (QLD)P/L Phone: +61 (7) 4044 0300
> Direct: +61 (7) 4044
> 0302
> 124 Spence Street Fax: +61 (7) 4041 6600
> CAIRNS QLD 4868 Mobile: 0418 608609
>
> Australia
>
> E-mail: nathan.dennis at i-solutions.net.au
> <mailto:nathan.dennis at i-solutions.net.au>
> Web Site: www.i-solutions.net.au <http://www.i-solutions.net.au/>
>
> Offices and agents in Cairns - Brisbane - Melbourne -- Adelaide --
> Sydney
> __________________________________________________________
> The information transmitted is intended only for the person or entity to
> which
> it is addressed and may contain confidential and/or privileged material.
>
> Any review, retransmission, dissemination or other use of, or taking of
> any
> action in reliance upon, this information by persons or entities other
> than the
> intended recipient is prohibited. If you received this in error, please
> contact
> the sender and delete the material from any computer.
>
> _______________________________________________
> --Bandwidth and Colocation Provided by http://www.api-digital.com--
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
> http://lists.digium.com/mailman/listinfo/asterisk-users
--
Tzafrir Cohen
icq#16849755 jabber:tzafrir at jabber.org
+972-50-7952406 mailto:tzafrir.cohen at xorcom.com
http://www.xorcom.com iax:guest at local.xorcom.com/tzafrir
More information about the asterisk-users
mailing list