[asterisk-users] Xorcom Bri and asterisk crashes

Tzafrir Cohen tzafrir.cohen at xorcom.com
Mon Jul 9 04:50:07 CDT 2007


On Mon, Jul 09, 2007 at 04:02:06PM +1000, Nathan Dennis wrote:
> Thanks for the input, but I still don't seem to have any luck with the
> devices locking up. 

The trace you posted before mentioned tasklets. Those are not in use in
the Astribank driver code (unless you set the optional parameter
pcm_tasklet of the driver xpp, which is almost always discourged) and
IIRC are not used in the main zaptel code. Some other zaptel drivers use
tasklets, and also ztdummy uses them. But I still suspect that the error
is elsewhere.

Again, oops / BUG() traces would be helpful to trace the issue.

> I've even rebuilt a new system on new hardware and a
> new xorcom device but still no good. Once the device locks up that's it
> the only way to get zaptel and asterisk back up is to turn them off and
> restart the server. The command you have me
>  
> rmmod xpp_usb; /usr/share/zaptel/xpp_fxloader reset
> Works great and will reload the firmware as long as the devices are
> frozen. Once they lock up this command will not reload the firmware and
> brings up the following errors.
> 
> 'xpp_fxloader'[16065]: Resetting FPGA Firmware on /dev/bus/usb/005/016

Here xpp_fxloader has identified that the device 005 016 has an
Astribank that could use resetting. It calls fpga_load:

> 'xpp_fxloader'[16067]: /usr/sbin/fpga_load: ERROR (247): bulk_write
> failed: error reaping URB: No such device

fpga_load has managed to open the device, but has failed to write. I'm
not sure if this is the first write or not.

> 'xpp_fxloader'[16067]: /usr/sbin/fpga_load: ERROR (810): Renumeration to
> default failed: errno=-19
> 'xpp_fxloader'[16067]: /usr/sbin/fpga_load: ERROR (203): Releasing
> interface: usb: could not release intf 0: No such device
> 'xpp_fxloader'[16342]: fpga_load failed remoivng with status 237
> 
> 
> I'm running Fedora 7, Kernel 2.6.21-1.3194.fc7
> 
> Will hopefully be upgrading the kernel tonight if I can get some
> downtime to do so.
> 
> As for more traces, I can do that, but being reasonably new to this I
> will need some help getting them for you.
> 
> 
> 
>  
> 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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> '
> > Jul  4 11:56:54 DEBUG[20042] chan_sip.c: Stopping retransmission on
> > '6eeb52b53a414a6975facbc22ca10686 at 192.168.10.12
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ' 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
> <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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> 
> > Jul  4 11:56:55 VERBOSE[20298] logger.c:     -- Executing
> > Set("Local/700 at callagents-bc5a
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,2",
> "Extension=700") in new stack
> > Jul  4 11:56:55 VERBOSE[20298] logger.c:     -- Executing
> > Set("Local/700 at callagents-bc5a
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,2",
> > "__ALERT_INFO=<http://www.example.com <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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ' 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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ' 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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,1 is ringing
> > Jul  4 11:56:56 DEBUG[20042] chan_sip.c: Auto destroying call
> > '4c2e1191399110af402dcc5b2c48303a at 192.168.10.12
> <http://lists.digium.com/mailman/listinfo/asterisk-users> '
> > 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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ' 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
> <http://lists.digium.com/mailman/listinfo/asterisk-users>
> :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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> ,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
> <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
> <http://lists.digium.com/mailman/listinfo/asterisk-users> 
> > <mailto:nathan.dennis at i-solutions.net.au
> <http://lists.digium.com/mailman/listinfo/asterisk-users> > 
> > Web Site: www.i-solutions.net.au <http://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--
> <http://www.api-digital.com--/> 
> > 
> > asterisk-users mailing list
> > To UNSUBSCRIBE or update options visit:
> >    http://lists.digium.com/mailman/listinfo/asterisk-users
> <http://lists.digium.com/mailman/listinfo/asterisk-users> 
> 
> -- 
>                Tzafrir Cohen       
> icq#16849755                    jabber:tzafrir at jabber.org
> <http://lists.digium.com/mailman/listinfo/asterisk-users> 
> +972-50-7952406           mailto:tzafrir.cohen at xorcom.com
> <http://lists.digium.com/mailman/listinfo/asterisk-users>        
> http://www.xorcom.com <http://www.xorcom.com/>   iax:guest at
> local.xorcom.com
> <http://lists.digium.com/mailman/listinfo/asterisk-users> /tzafrir
> 
> 
> Nathan Dennis 
> 
> 
> _______________________________________________
> --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