[Asterisk-Dev] TE410 problem

Chee Foong cheefoong at ip-vox.com
Wed Oct 5 03:53:18 MST 2005


Hello,

I have a * server with a TE410 card installed. It has 3 active E1 link
connected to an avaya pbx. * is set to be the master while avay is slave. *
is the latest CVS head
It's been running fine for 2 weeks. However, yesterday all 3 of the E1 link
was down.  Looking at the log, I found an error at 11:18:15 log time which
show

Oct  3 11:18:15 VERBOSE[11393] logger.c: Write to 141 failed: Unknown error
500
Oct  3 11:18:15 VERBOSE[11393] logger.c: Short write: 0/15 (Unknown error
500)

After seeing this error, I was suspecting that the signalling between * and
avaya was not synchronized correctly, therefore I stop * and restarted
zaptel and wct4xxp. but that doesn't work. I finally have to reboot the *
server and all are working fine for 3 hours and the problem happened again.
Log file showing the same error message. I rebooted the server and has not
seen it happend for about a day and still monitoring.

Any one know what could have cause this?

I have attached a portion of the logs. look at time 11:18:15, that's where
zaptel starts to fail.


Oct  3 11:18:13 VERBOSE[11688] logger.c:     -- SIP/10.223.51.173-ba9a is
making progress passing it to Zap/32-1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/4 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/9 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/12 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/14 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/15 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/19 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/22 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/24 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/29 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/30 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26334] logger.c:     -- B-channel 0/31 successfully
restarted on span 1
Oct  3 11:18:13 VERBOSE[26340] logger.c:     -- Got SIP response 503
"Service Unavailable" back from 10.223.51.173
Oct  3 11:18:13 VERBOSE[11688] logger.c:     -- SIP/10.223.51.173-ba9a is
circuit-busy
Oct  3 11:18:13 VERBOSE[11688] logger.c:   == Everyone is busy/congested at
this time (1:0/1/0)
Oct  3 11:18:13 VERBOSE[11688] logger.c:   == Auto fallthrough, channel
'Zap/32-1' status is 'CONGESTION'
Oct  3 11:18:13 VERBOSE[26336] logger.c:     -- Accepting call from '301057'
to '006732234087' on channel 0/7, span 3
Oct  3 11:18:13 VERBOSE[11702] logger.c:     -- Executing Dial("Zap/69-1",
"SIP/006732234087 at 10.223.51.173") in new stack
Oct  3 11:18:13 VERBOSE[11702] logger.c:     -- Called
006732234087 at 10.223.51.173
Oct  3 11:18:14 VERBOSE[11704] logger.c:     -- Executing
Dial("SIP/10.223.51.173-0834c048", "ZAP/r1/300007") in new stack
Oct  3 11:18:14 VERBOSE[11704] logger.c:     -- Requested transfer
capability: 0x00 - SPEECH
Oct  3 11:18:14 VERBOSE[11704] logger.c:     -- Called r1/300007
Oct  3 11:18:14 VERBOSE[11704] logger.c:     -- Zap/51-1 is proceeding
passing it to SIP/10.223.51.173-0834c048
Oct  3 11:18:14 VERBOSE[11704] logger.c:     -- Zap/51-1 is ringing
Oct  3 11:18:15 VERBOSE[11393] logger.c: Write to 141 failed: Unknown error
500
Oct  3 11:18:15 VERBOSE[11393] logger.c: Short write: 0/15 (Unknown error
500)
Oct  3 11:18:15 WARNING[11393] chan_zap.c: Detected alarm on channel 92: Red
Alarm
Oct  3 11:18:15 VERBOSE[11393] logger.c:     -- Hungup 'Zap/92-1'
Oct  3 11:18:15 VERBOSE[11376] logger.c: Write to 141 failed: Unknown error
500
Oct  3 11:18:15 VERBOSE[11376] logger.c: Short write: 0/15 (Unknown error
500)
Oct  3 11:18:15 WARNING[11376] chan_zap.c: Detected alarm on channel 87: Red
Alarm
Oct  3 11:18:15 VERBOSE[11376] logger.c:     -- Hungup 'Zap/87-1'
Oct  3 11:18:15 VERBOSE[11373] logger.c: Write to 141 failed: Unknown error
500
Oct  3 11:18:15 VERBOSE[11373] logger.c: Short write: 0/15 (Unknown error
500)
Oct  3 11:18:15 WARNING[11373] chan_zap.c: Detected alarm on channel 86: Red
Alarm
Oct  3 11:18:15 VERBOSE[11373] logger.c:     -- Hungup 'Zap/86-1'
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 72: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 72
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 73: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 73
Oct  3 11:18:15 VERBOSE[11393] logger.c:   == Spawn extension (out-route,
300004, 1) exited non-zero on 'SIP/10.223.51.173-0846f8d8'
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 74: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 74
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 75: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 75
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 76: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 76
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 77: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 77
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 80: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 80
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 81: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 81
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 82: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 82
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 85: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 85
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 88: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 88
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 89: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 89
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 91: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 91
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Detected alarm on channel 93: Red
Alarm
Oct  3 11:18:15 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 93
Oct  3 11:18:15 VERBOSE[11376] logger.c:   == Spawn extension (out-route,
300009, 1) exited non-zero on 'SIP/10.223.51.173-08415868'
Oct  3 11:18:15 WARNING[26336] chan_zap.c: No D-channels available!  Using
Primary channel 78 as D-channel anyway!
Oct  3 11:18:15 WARNING[11649] chan_zap.c: Detected alarm on channel 63: Red
Alarm
Oct  3 11:18:15 VERBOSE[11649] logger.c:   == Spawn extension (in-route,
0392862222, 1) exited non-zero on 'Zap/63-1'
Oct  3 11:18:15 VERBOSE[11373] logger.c:   == Spawn extension (out-route,
300003, 1) exited non-zero on 'SIP/10.223.51.173-0842b348'
Oct  3 11:18:15 WARNING[10248] chan_zap.c: Detected alarm on channel 70: Red
Alarm
Oct  3 11:18:15 VERBOSE[10248] logger.c:   == Spawn extension (in-route,
0061424645482, 1) exited non-zero on 'Zap/70-1'
Oct  3 11:18:15 WARNING[11384] chan_zap.c: Detected alarm on channel 90: Red
Alarm
Oct  3 11:18:15 VERBOSE[11384] logger.c:     -- Hungup 'Zap/90-1'
Oct  3 11:18:15 VERBOSE[11384] logger.c:   == Spawn extension (out-route,
300012, 1) exited non-zero on 'SIP/10.223.51.173-083258e8'
Oct  3 11:18:15 WARNING[11693] chan_zap.c: Detected alarm on channel 64: Red
Alarm
Oct  3 11:18:15 WARNING[11702] chan_zap.c: Detected alarm on channel 69: Red
Alarm
Oct  3 11:18:15 WARNING[10375] chan_zap.c: Detected alarm on channel 65: Red
Alarm
Oct  3 11:18:15 WARNING[11350] chan_zap.c: Detected alarm on channel 83: Red
Alarm
Oct  3 11:18:15 WARNING[9953] chan_zap.c: Detected alarm on channel 66: Red
Alarm
Oct  3 11:18:15 WARNING[11233] chan_zap.c: Detected alarm on channel 71: Red
Alarm
Oct  3 11:18:15 WARNING[11583] chan_zap.c: Detected alarm on channel 68: Red
Alarm
Oct  3 11:18:15 WARNING[10827] chan_zap.c: Detected alarm on channel 67: Red
Alarm
Oct  3 11:18:15 WARNING[10620] chan_zap.c: Detected alarm on channel 84: Red
Alarm
Oct  3 11:18:15 VERBOSE[11649] logger.c:     -- Hungup 'Zap/63-1'
Oct  3 11:18:15 WARNING[11333] chan_zap.c: Detected alarm on channel 79: Red
Alarm
Oct  3 11:18:15 VERBOSE[11702] logger.c:   == Spawn extension (in-route,
006732234087, 1) exited non-zero on 'Zap/69-1'
Oct  3 11:18:15 VERBOSE[11333] logger.c:     -- Hungup 'Zap/79-1'
Oct  3 11:18:15 VERBOSE[11333] logger.c:   == Spawn extension (out-route,
300010, 1) exited non-zero on 'SIP/10.223.51.173-082f3d30'
Oct  3 11:18:15 VERBOSE[10375] logger.c:   == Spawn extension (in-route,
0125596847, 1) exited non-zero on 'Zap/65-1'
Oct  3 11:18:15 VERBOSE[9953] logger.c:   == Spawn extension (in-route,
0199493443, 1) exited non-zero on 'Zap/66-1'
Oct  3 11:18:15 VERBOSE[11233] logger.c:   == Spawn extension (in-route,
00914425202939, 1) exited non-zero on 'Zap/71-1'
Oct  3 11:18:15 VERBOSE[10827] logger.c:   == Spawn extension (in-route,
00886932225538, 1) exited non-zero on 'Zap/67-1'
Oct  3 11:18:15 VERBOSE[10620] logger.c:     -- Hungup 'Zap/84-1'
Oct  3 11:18:15 VERBOSE[10620] logger.c:   == Spawn extension (out-route,
300004, 1) exited non-zero on 'SIP/10.223.51.173-083f9fc0'
Oct  3 11:18:15 VERBOSE[10248] logger.c:     -- Hungup 'Zap/70-1'
Oct  3 11:18:15 VERBOSE[11350] logger.c:     -- Hungup 'Zap/83-1'
Oct  3 11:18:15 VERBOSE[11693] logger.c:     -- Hungup 'Zap/64-1'
Oct  3 11:18:15 VERBOSE[11583] logger.c:   == Spawn extension (in-route,
0123695919, 1) exited non-zero on 'Zap/68-1'
Oct  3 11:18:15 VERBOSE[11702] logger.c:     -- Hungup 'Zap/69-1'
Oct  3 11:18:15 VERBOSE[11233] logger.c:     -- Hungup 'Zap/71-1'
Oct  3 11:18:15 VERBOSE[10375] logger.c:     -- Hungup 'Zap/65-1'
Oct  3 11:18:15 VERBOSE[9953] logger.c:     -- Hungup 'Zap/66-1'
Oct  3 11:18:15 VERBOSE[11583] logger.c:     -- Hungup 'Zap/68-1'
Oct  3 11:18:15 VERBOSE[10827] logger.c:     -- Hungup 'Zap/67-1'
Oct  3 11:18:15 VERBOSE[11350] logger.c:   == Spawn extension (out-route,
300002, 1) exited non-zero on 'SIP/10.223.51.173-084022a0'
Oct  3 11:18:15 VERBOSE[26335] logger.c:     -- Channel 0/15, span 2 got
hangup request
Oct  3 11:18:15 VERBOSE[26335] logger.c:     -- Channel 0/28, span 2 got
hangup request
Oct  3 11:18:15 VERBOSE[10346] logger.c:     -- Hungup 'Zap/46-1'
Oct  3 11:18:15 VERBOSE[10346] logger.c:   == Spawn extension (out-route,
300007, 1) exited non-zero on 'SIP/10.223.51.173-083c26f8'
Oct  3 11:18:15 VERBOSE[26335] logger.c:     -- Channel 0/4, span 2 got
hangup request
Oct  3 11:18:15 VERBOSE[26335] logger.c:     -- Channel 0/3, span 2 got
hangup request
Oct  3 11:18:15 VERBOSE[11400] logger.c:   == Spawn extension (in-route,
0162663538, 1) exited non-zero on 'Zap/35-1'
Oct  3 11:18:15 VERBOSE[26335] logger.c:     -- Channel 0/9, span 2 got
hangup request
Oct  3 11:18:15 VERBOSE[11400] logger.c:     -- Hungup 'Zap/35-1'
Oct  3 11:18:15 VERBOSE[11415] logger.c:   == Spawn extension (in-route,
0126761942, 1) exited non-zero on 'Zap/40-1'
Oct  3 11:18:15 VERBOSE[11415] logger.c:     -- Hungup 'Zap/40-1'
Oct  3 11:18:15 VERBOSE[26335] logger.c:     -- Channel 0/12, span 2 got
hangup request
Oct  3 11:18:15 VERBOSE[26334] logger.c:     -- Channel 0/8, span 1 got
hangup request
Oct  3 11:18:15 VERBOSE[26334] logger.c:     -- Channel 0/23, span 1 got
hangup request
Oct  3 11:18:15 VERBOSE[11189] logger.c:     -- Hungup 'Zap/59-1'
Oct  3 11:18:15 VERBOSE[11189] logger.c:   == Spawn extension (out-route, 30
0011, 1) exited non-zero on 'SIP/10.223.51.173-083dc0f0'
Oct  3 11:18:15 VERBOSE[26334] logger.c:     -- Channel 0/10, span 1 got
hangup request
Oct  3 11:18:15 VERBOSE[10647] logger.c:   == Spawn extension (in-route,
0082113362720, 1) exited non-zero on 'Zap/10-1'
Oct  3 11:18:15 VERBOSE[10647] logger.c:     -- Hungup 'Zap/10-1'
Oct  3 11:18:15 VERBOSE[10195] logger.c:     -- Hungup 'Zap/23-1'
Oct  3 11:18:15 VERBOSE[10195] logger.c:   == Spawn extension (out-route,
300009, 1) exited non-zero on 'SIP/10.223.51.173-08374170'
Oct  3 11:18:15 VERBOSE[10749] logger.c:     -- Hungup 'Zap/8-1'
Oct  3 11:18:15 VERBOSE[10749] logger.c:   == Spawn extension (out-route,
300006, 1) exited non-zero on 'SIP/10.223.51.173-0846b390'
Oct  3 11:18:15 VERBOSE[11398] logger.c:   == Spawn extension (in-route,
085419085, 1) exited non-zero on 'Zap/34-1'
Oct  3 11:18:15 VERBOSE[11440] logger.c:   == Spawn extension (in-route,
062835806, 1) exited non-zero on 'Zap/43-1'
Oct  3 11:18:15 VERBOSE[11398] logger.c:     -- Hungup 'Zap/34-1'
Oct  3 11:18:15 VERBOSE[11440] logger.c:     -- Hungup 'Zap/43-1'
Oct  3 11:18:16 VERBOSE[26335] logger.c:     -- Channel 0/1, span 2 got
hangup request
Oct  3 11:18:16 VERBOSE[11688] logger.c:     -- Hungup 'Zap/32-1'
Oct  3 11:18:17 VERBOSE[11704] logger.c:     -- Zap/51-1 answered
SIP/10.223.51.173-0834c048
Oct  3 11:18:17 VERBOSE[26334] logger.c:     -- Accepting call from '301068'
to '0062352461071' on channel 0/4, span 1
Oct  3 11:18:17 VERBOSE[11758] logger.c:     -- Executing Dial("Zap/4-1",
"SIP/0062352461071 at 10.223.51.173") in new stack
Oct  3 11:18:17 VERBOSE[11758] logger.c:     -- Called
0062352461071 at 10.223.51.173
Oct  3 11:18:18 VERBOSE[26336] logger.c:   == Primary D-Channel on span 3
down
Oct  3 11:18:18 WARNING[26336] chan_zap.c: No D-channels available!  Using
Primary channel 78 as D-channel anyway!
Oct  3 11:18:21 VERBOSE[11758] logger.c:     -- SIP/10.223.51.173-8226 is
making progress passing it to Zap/4-1
Oct  3 11:18:26 VERBOSE[26334] logger.c:     -- Accepting call from '301065'
to '006281360233468' on channel 0/8, span 1
Oct  3 11:18:26 VERBOSE[11761] logger.c:     -- Executing Dial("Zap/8-1",
"SIP/006281360233468 at 10.223.51.173") in new stack
Oct  3 11:18:26 VERBOSE[11761] logger.c:     -- Called
006281360233468 at 10.223.51.173
Oct  3 11:18:30 VERBOSE[26334] logger.c:     -- Accepting call from '301018'
to '0126955470' on channel 0/9, span 1
Oct  3 11:18:30 VERBOSE[11763] logger.c:     -- Executing Dial("Zap/9-1",
"SIP/0126955470 at 10.223.51.173") in new stack
Oct  3 11:18:30 VERBOSE[11763] logger.c:     -- Called
0126955470 at 10.223.51.173
Oct  3 11:18:32 VERBOSE[11761] logger.c:     -- SIP/10.223.51.173-69f3 is
ringing
Oct  3 11:18:34 VERBOSE[11758] logger.c:     -- SIP/10.223.51.173-8226
answered Zap/4-1
Oct  3 11:18:36 VERBOSE[26335] logger.c:     -- Accepting call from '301041'
to '065293932' on channel 0/1, span 2
Oct  3 11:18:36 VERBOSE[11768] logger.c:     -- Executing Dial("Zap/32-1",
"SIP/065293932 at 10.223.51.173") in new stack
Oct  3 11:18:36 VERBOSE[11768] logger.c:     -- Called
065293932 at 10.223.51.173
Oct  3 11:18:36 VERBOSE[11763] logger.c:     -- SIP/10.223.51.173-2727 is
ringing
Oct  3 11:18:38 VERBOSE[11768] logger.c:     -- SIP/10.223.51.173-d23a is
ringing
Oct  3 11:18:40 VERBOSE[11763] logger.c:     -- SIP/10.223.51.173-2727
answered Zap/9-1
Oct  3 11:18:49 WARNING[26336] chan_zap.c: No D-channels available!  Using
Primary channel 78 as D-channel anyway!
Oct  3 11:18:50 VERBOSE[11761] logger.c:     -- SIP/10.223.51.173-69f3
answered Zap/8-1
Oct  3 11:18:50 VERBOSE[26334] logger.c:     -- Channel 0/18, span 1 got
hangup request
Oct  3 11:18:50 VERBOSE[11481] logger.c:   == Spawn extension (in-route,
0320708833, 1) exited non-zero on 'Zap/18-1'
Oct  3 11:18:50 VERBOSE[11481] logger.c:     -- Hungup 'Zap/18-1'
Oct  3 11:18:51 VERBOSE[26336] logger.c:   == Primary D-Channel on span 3 up
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/3 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/4 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/5 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/6 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/26 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/27 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/28 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/29 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/1 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/2 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/30 restarted on
span 3
Oct  3 11:18:51 VERBOSE[26336] logger.c:     -- B-channel 0/31 restarted on
span 3
Oct  3 11:18:51 WARNING[26336] chan_zap.c: No D-channels available!  Using
Primary channel 78 as D-channel anyway!
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Detected alarm on channel 63: Red
Alarm
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 63
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Detected alarm on channel 64: Red
Alarm
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 64
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Detected alarm on channel 65: Red
Alarm
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Unable to disable echo
cancellation on channel 65
Oct  3 11:18:51 WARNING[26338] chan_zap.c: Detected alarm on channel 66: Red
Alarm

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-dev/attachments/20051005/6703c5ed/attachment.htm


More information about the asterisk-dev mailing list